Fixes missing Rauthy error message closes #289 #427

Merged
carla merged 7 commits from bug/289_rauthy_error_message into main 2026-02-23 15:32:00 +01:00
2 changed files with 168 additions and 14 deletions
Showing only changes of commit b5fc03e94f - Show all commits

View file

@ -45,9 +45,7 @@ defmodule MvWeb.AuthController do
- Generic authentication failures
"""
def failure(conn, activity, reason) do
Logger.warning(
"Authentication failure - Activity: #{inspect(activity)}, Reason: #{inspect(reason)}"
)
log_failure_safely(activity, reason)
case {activity, reason} do
{{:rauthy, _action}, reason} ->
@ -63,6 +61,63 @@ defmodule MvWeb.AuthController do
end
end
# Log authentication failures safely, avoiding sensitive data for {:rauthy, _} activities
defp log_failure_safely({:rauthy, _action} = activity, reason) do
# For Assent errors, use safe_assent_meta to avoid logging tokens/URLs with query params
case reason do
%Assent.ServerUnreachableError{} = err ->
meta = safe_assent_meta(err)
message = format_safe_log_message("Authentication failure", activity, meta)
Logger.warning(message)
%Assent.InvalidResponseError{} = err ->
meta = safe_assent_meta(err)
message = format_safe_log_message("Authentication failure", activity, meta)
Logger.warning(message)
_ ->
# For other rauthy errors, log only error type, not full details
error_type = get_error_type(reason)
Logger.warning(
"Authentication failure - Activity: #{inspect(activity)}, Error type: #{error_type}"
)
end
end
defp log_failure_safely(activity, reason) do
# For non-rauthy activities, safe to log full reason
Logger.warning(
"Authentication failure - Activity: #{inspect(activity)}, Reason: #{inspect(reason)}"
)
end
# Extract safe error type identifier without sensitive data
defp get_error_type(%struct{}), do: "#{struct}"
defp get_error_type(atom) when is_atom(atom), do: inspect(atom)
defp get_error_type(_other), do: "[redacted]"
# Format safe log message with metadata included in the message string
defp format_safe_log_message(base_message, activity, meta) when is_list(meta) do
activity_str = "Activity: #{inspect(activity)}"
meta_str = format_meta_string(meta)
"#{base_message} - #{activity_str}#{meta_str}"
end
defp format_meta_string([]), do: ""
defp format_meta_string(meta) when is_list(meta) do
parts =
Enum.map(meta, fn
{:request_url, url} -> "Request URL: #{url}"
{:status, status} -> "Status: #{status}"
{:http_adapter, adapter} -> "HTTP Adapter: #{inspect(adapter)}"
_ -> nil
end)
|> Enum.filter(&(&1 != nil))
if Enum.empty?(parts), do: "", else: " - " <> Enum.join(parts, ", ")
end
# Handle all Rauthy (OIDC) authentication failures
defp handle_rauthy_failure(conn, %Ash.Error.Invalid{errors: errors}) do
handle_oidc_email_collision(conn, errors)
@ -83,9 +138,9 @@ defmodule MvWeb.AuthController do
end
# Handle Assent server unreachable errors (network/connectivity issues)
defp handle_rauthy_failure(conn, %Assent.ServerUnreachableError{} = err) do
# Use warning level: server unreachable is often transient, not a critical system error
Logger.warning("OIDC authentication server unreachable", safe_assent_meta(err))
defp handle_rauthy_failure(conn, %Assent.ServerUnreachableError{} = _err) do
# Logging already done safely in failure/3 via log_failure_safely/2
# No need to log again here to avoid duplicate logs
conn
|> put_flash(
@ -96,9 +151,9 @@ defmodule MvWeb.AuthController do
end
# Handle Assent invalid response errors (configuration or malformed responses)
defp handle_rauthy_failure(conn, %Assent.InvalidResponseError{} = err) do
# Use warning level: configuration errors are operational issues, not critical failures
Logger.warning("OIDC authentication invalid response", safe_assent_meta(err))
defp handle_rauthy_failure(conn, %Assent.InvalidResponseError{} = _err) do
# Logging already done safely in failure/3 via log_failure_safely/2
# No need to log again here to avoid duplicate logs
conn
|> put_flash(
@ -109,8 +164,9 @@ defmodule MvWeb.AuthController do
end
# Catch-all clause for any other error types
defp handle_rauthy_failure(conn, reason) do
Logger.warning("Unhandled Rauthy failure reason: #{inspect(reason)}")
defp handle_rauthy_failure(conn, _reason) do
# Logging already done safely in failure/3 via log_failure_safely/2
# No need to log again here to avoid duplicate logs
conn
|> put_flash(:error, gettext("Unable to authenticate with OIDC. Please try again."))

View file

@ -2,6 +2,7 @@ defmodule MvWeb.AuthControllerTest do
use MvWeb.ConnCase, async: true
import Phoenix.LiveViewTest
import Phoenix.ConnTest
import ExUnit.CaptureLog
# Helper to create an unauthenticated conn (preserves sandbox metadata)
defp build_unauthenticated_conn(authenticated_conn) do
@ -269,7 +270,7 @@ defmodule MvWeb.AuthControllerTest do
assert redirected_to(conn) == ~p"/sign-in"
assert get_flash(conn, :error) ==
assert Phoenix.Flash.get(conn.assigns.flash, :error) ==
"The authentication server is currently unavailable. Please try again later."
end
@ -291,7 +292,7 @@ defmodule MvWeb.AuthControllerTest do
assert redirected_to(conn) == ~p"/sign-in"
assert get_flash(conn, :error) ==
assert Phoenix.Flash.get(conn.assigns.flash, :error) ==
"Authentication configuration error. Please contact the administrator."
end
@ -305,8 +306,105 @@ defmodule MvWeb.AuthControllerTest do
assert redirected_to(conn) == ~p"/sign-in"
assert get_flash(conn, :error) ==
assert Phoenix.Flash.get(conn.assigns.flash, :error) ==
"Unable to authenticate with OIDC. Please try again."
end
end
# Logging security tests - ensure no sensitive data is logged
describe "failure/3 logging security" do
test "does not log full URL with query params for Assent.ServerUnreachableError", %{
conn: authenticated_conn
} do
conn = build_unauthenticated_conn(authenticated_conn)
error = %Assent.ServerUnreachableError{
http_adapter: Assent.HTTPAdapter.Finch,
request_url: "https://auth.example.com/callback?token=secret123&code=abc456",
reason: %Mint.TransportError{reason: :econnrefused}
}
log =
capture_log(fn ->
MvWeb.AuthController.failure(conn, {:rauthy, :callback}, error)
end)
# Should log redacted URL (only scheme and host)
assert log =~ "https://auth.example.com"
# Should NOT log query parameters or tokens
refute log =~ "token=secret123"
refute log =~ "code=abc456"
refute log =~ "callback?token"
end
test "does not log sensitive data for Assent.InvalidResponseError", %{
conn: authenticated_conn
} do
conn = build_unauthenticated_conn(authenticated_conn)
error = %Assent.InvalidResponseError{
response: %Assent.HTTPAdapter.HTTPResponse{
status: 400,
headers: [],
body: "invalid_request"
}
}
log =
capture_log(fn ->
MvWeb.AuthController.failure(conn, {:rauthy, :callback}, error)
end)
# Should log error type but not full error details
assert log =~ "Authentication failure"
assert log =~ "rauthy"
# Should not log full error struct with inspect
refute log =~ "Assent.InvalidResponseError"
end
test "does not log full reason for unknown rauthy errors", %{
conn: authenticated_conn
} do
conn = build_unauthenticated_conn(authenticated_conn)
# Simulate an error that might contain sensitive data
error_with_sensitive_data = %{
token: "secret_token_123",
url: "https://example.com/callback?access_token=abc123",
error: :something_went_wrong
}
log =
capture_log(fn ->
MvWeb.AuthController.failure(conn, {:rauthy, :callback}, error_with_sensitive_data)
end)
# Should log error type but not full error details
assert log =~ "Authentication failure"
assert log =~ "rauthy"
# Should NOT log sensitive data
refute log =~ "secret_token_123"
refute log =~ "access_token=abc123"
refute log =~ "callback?access_token"
end
test "logs full reason for non-rauthy activities (password auth)", %{
conn: authenticated_conn
} do
conn = build_unauthenticated_conn(authenticated_conn)
reason = %AshAuthentication.Errors.AuthenticationFailed{
caused_by: %Ash.Error.Forbidden{errors: []}
}
log =
capture_log(fn ->
MvWeb.AuthController.failure(conn, {:password, :sign_in}, reason)
end)
# For non-rauthy activities, full reason is safe to log
assert log =~ "Authentication failure"
assert log =~ "password"
assert log =~ "AuthenticationFailed"
end
end
end