diff --git a/lib/sentry.ex b/lib/sentry.ex index 3b5e3d76..63237c83 100644 --- a/lib/sentry.ex +++ b/lib/sentry.ex @@ -155,13 +155,18 @@ defmodule Sentry do ## Crashing Callbacks - If a `:before_send`, `:after_send_event`, `:filter`, `:before_send_log`, - `:before_send_metric`, or `:traces_sampler` callback raises, throws, or exits, Sentry catches - the failure and logs it at the `:error` level instead of letting it reach the code that was - reporting the event. The log carries the `:sentry` logger domain, so the SDK never reports - its own callback failure as an event. + When a callback you configure raises, throws, or exits, Sentry catches the failure and logs + it at the `:error` level instead of letting it reach the code that was reporting the event + or serving the request. The log carries the `:sentry` logger domain, so the SDK never + reports its own callback failure as an event. + + What happens next depends on where the callback runs. - The item being handled is then dropped: + ### Event Callbacks + + If a `:before_send`, `:after_send_event`, `:filter`, `:before_send_log`, + `:before_send_metric`, or `:traces_sampler` callback fails, the item being handled is + dropped: * A `:before_send` callback that crashes is treated like one that returned `false`. The event or transaction is not sent, and the capture function returns `:excluded`. @@ -184,6 +189,31 @@ defmodule Sentry do dropped and the child spans of that trace inherit that decision instead of calling the failing sampler again. + ### Request Callbacks + + The callbacks that `Sentry.PlugContext`, `Sentry.PlugCapture`, and `Sentry.LiveViewHook` + accept run inside your request or LiveView process, where a failure of theirs would break + your application rather than just the report. It cannot: the request is served, and the + LiveView keeps running, exactly as they would have without Sentry. `Sentry.PlugCapture` + additionally re-raises your application's original exception unchanged, whatever fails + while it is capturing it. + + Nothing is dropped either. The event is still reported, and only the field the failing + callback was responsible for degrades: + + | Callback | Value reported after a crash | + | --- | --- | + | `Sentry.PlugContext`'s `:body_scrubber`, `:header_scrubber`, `:cookie_scrubber`, or `:url_scrubber` | the SDK's own default scrubber for that field | + | `Sentry.PlugContext`'s `:remote_address_reader` | the address the SDK's default reader produces | + | `Sentry.PlugCapture`'s `:scrubber` | the connection scrubbed by `Sentry.Scrubber.scrub/1` | + | `Sentry.LiveViewHook`'s `:scrubber` | redacted breadcrumb data, that is, an empty map | + + > #### A crashed scrubber reports more, not less {: .warning} + > + > Apart from `Sentry.LiveViewHook`, which redacts the data outright, falling back to the + > SDK's default scrubber means that data only your custom scrubber was dropping is sent to + > Sentry for as long as that scrubber keeps failing. The error-level log is the only signal. + ## Reporting Source Code Sentry supports reporting the source code of (and around) the line that diff --git a/lib/sentry/callback.ex b/lib/sentry/callback.ex index 76b8f3d7..04a922a8 100644 --- a/lib/sentry/callback.ex +++ b/lib/sentry/callback.ex @@ -4,7 +4,7 @@ defmodule Sentry.Callback do alias Sentry.ClientReport alias Sentry.LoggerUtils - @type spec() :: (... -> term()) | {module(), atom()} + @type spec() :: (... -> term()) | {module(), atom()} | {module(), atom(), [term()]} @spec run(atom(), (-> result), result, keyword()) :: result when result: var def run(name, fun, fallback, opts \\ []) when is_list(opts) do @@ -19,14 +19,16 @@ defmodule Sentry.Callback do end @spec run(atom(), (-> result)) :: {:ok, result} | :failed when result: var - def run(name, fun) when is_atom(name) and is_function(fun, 0) do + def run(name, fun) when is_atom(name) do + guard("#{inspect(name)} callback failed", fun) + end + + @spec guard(String.t(), (-> result)) :: {:ok, result} | :failed when result: var + def guard(description, fun) when is_binary(description) and is_function(fun, 0) do {:ok, fun.()} catch kind, reason -> - LoggerUtils.error( - "#{inspect(name)} callback failed: " <> - Exception.format(kind, reason, __STACKTRACE__) - ) + LoggerUtils.error(description <> ": " <> Exception.format(kind, reason, __STACKTRACE__)) :failed end @@ -40,6 +42,9 @@ defmodule Sentry.Callback do {mod, fun} when is_atom(mod) and is_atom(fun) -> fn -> apply(mod, fun, args) end + {mod, fun, extra_args} when is_atom(mod) and is_atom(fun) and is_list(extra_args) -> + fn -> apply(mod, fun, args ++ extra_args) end + other -> raise ArgumentError, "#{inspect(name)} must be an anonymous function or a {module, function} tuple, " <> diff --git a/lib/sentry/live_view_hook.ex b/lib/sentry/live_view_hook.ex index bbfcbaf8..6d875524 100644 --- a/lib/sentry/live_view_hook.ex +++ b/lib/sentry/live_view_hook.ex @@ -73,12 +73,22 @@ if Code.ensure_loaded?(Phoenix.LiveView) do The scrubber is resolved once at `on_mount` time and applies to every breadcrumb recorded for the lifetime of the LiveView process. + ## Crashing Callbacks + + The `:scrubber` runs in the LiveView process, where a failure of its own + would crash the LiveView. It cannot: if it raises, throws, exits, or returns + anything other than a map, Sentry catches the failure and logs it at the + `:error` level with the `:sentry` logger domain, so the SDK never reports its + own callback failure as an event. The breadcrumb is then recorded with + redacted data - an empty map - rather than with data that was never scrubbed. + """ @moduledoc since: "10.5.0" import Phoenix.LiveView, only: [attach_hook: 4, get_connect_info: 2] + alias Sentry.Callback alias Sentry.Context alias Sentry.LoggerUtils @@ -129,34 +139,16 @@ if Code.ensure_loaded?(Phoenix.LiveView) do end defp scrub(data) when is_map(data) do - {mod, fun, args} = - Process.get(@scrubber_pdict_key, {__MODULE__, :default_scrubber, []}) - - try do - case apply(mod, fun, [data | args]) do - result when is_map(result) -> - result - - other -> - LoggerUtils.error( - "Sentry.LiveViewHook scrubber returned non-map value: #{inspect(other)}; " <> - "falling back to redacted data", - event_source: :logger - ) - - %{} - end - catch - # We must NEVER raise an error in a hook, as it will crash the LiveView process - # and we don't want Sentry to be responsible for that. - kind, reason -> - LoggerUtils.error( - "Sentry.LiveViewHook scrubber raised an error: #{Exception.format(kind, reason)}; " <> - "falling back to redacted data", - event_source: :logger - ) - - %{} + scrubber = Process.get(@scrubber_pdict_key, {__MODULE__, :default_scrubber, []}) + + # We must NEVER raise an error in a hook, as it will crash the LiveView process + # and we don't want Sentry to be responsible for that. + with {:ok, scrubbed} <- + Callback.run(:scrubber, Callback.to_fun(:scrubber, scrubber, [data])), + {:ok, scrubbed} <- Callback.validate(:scrubber, scrubbed, &is_map/1, "a map") do + scrubbed + else + _ -> %{} end end diff --git a/lib/sentry/plug_capture.ex b/lib/sentry/plug_capture.ex index 8f6c8e27..ad6a2a33 100644 --- a/lib/sentry/plug_capture.ex +++ b/lib/sentry/plug_capture.ex @@ -73,7 +73,9 @@ defmodule Sentry.PlugCapture do will be invoked to scrub sensitive data from `Plug.Conn` structs. The `Plug.Conn` struct is prepended to `args` before invoking the function, so that the final function will be called as `apply(module, function, [conn | args])`. - The function must return a `Plug.Conn` struct. By default, the built-in + The function must return a `Plug.Conn` struct; if it returns anything else, + or if it crashes, scrubbing falls back to the built-in scrubber (see + *Crashing Callbacks* below). By default, the built-in scrubber delegates to `Sentry.Scrubber.scrub/1`, which honors any `:body_scrubber`, `:header_scrubber`, `:cookie_scrubber`, or `:url_scrubber` opts configured on `Sentry.PlugContext` for the current @@ -95,6 +97,32 @@ defmodule Sentry.PlugCapture do everything else (notably the decoded session under `:plug_session`); configurable via the `scrubber: [conn_private_allow_list: ...]` option + ## Crashing Callbacks + + This module captures the application's exception from inside `c:Plug.call/2`, + where a failure of its own would replace the error the application raised. It + cannot: if anything in the capture path raises, throws, or exits - the + `:scrubber` callback, the scrubbing of the exception, or the reporting + itself - Sentry catches the failure and re-raises **the application's + original exception, unchanged**. The failure is logged at the `:error` level + with the `:sentry` logger domain, so the SDK never reports its own failure as + an event. + + Only the reporting degrades, and only as far as the failure forces: + + | Failure | What Sentry still reports | + | --- | --- | + | The `:scrubber` crashes, or returns something other than a `Plug.Conn` | The event, with the conn scrubbed by the built-in scrubber, `Sentry.Scrubber.scrub/1` | + | Scrubbing a `Phoenix.ActionClauseError` fails for any other reason | The event, with each of the exception's arguments scrubbed on its own, without mirroring the conn's scrubbed params onto the action's params argument | + | Capturing the event itself fails | Nothing - the log is the only record of the error | + + > #### A crashed scrubber reports more, not less {: .warning} + > + > The fallback redacts the keys listed in `Sentry.Scrubber.default_param_keys/0` + > and `Sentry.Scrubber.default_header_keys/0`, and nothing more. Data that only + > a custom `:scrubber` was dropping is sent to Sentry for as long as that + > scrubber keeps failing, and the error-level log is the only signal. + """ defmacro __using__(opts) do quote do @@ -142,7 +170,7 @@ defmodule Sentry.PlugCapture do kind, reason -> message = "Uncaught #{kind} - #{inspect(reason)}" stack = __STACKTRACE__ - _ = Sentry.capture_message(message, stacktrace: stack, event_source: :plug) + :ok = Sentry.PlugCapture.__capture_message__(message, stack) :erlang.raise(kind, reason, stack) end end @@ -151,50 +179,83 @@ defmodule Sentry.PlugCapture do @doc false def __capture_exception__(exception, stacktrace, scrubber) do - # `Phoenix.ActionClauseError` is the one error whose args we know the shape of — - # a controller action is invoked as `apply(controller, action, [conn, conn.params])`. - # We handle it explicitly: `StacktraceScrubber` does the generic per-arg scrubbing, - # and we instruct it (via the callback) to scrub the conn through the configured - # `:scrubber` and mirror the conn's scrubbed params onto the standalone params arg. - exception = - if is_struct(exception, Phoenix.ActionClauseError) do - Sentry.Scrubber.StacktraceScrubber.scrub( - exception, - &scrub_action_clause_args(&1, scrubber) + _ = + Sentry.Callback.guard("Sentry failed to capture an exception from Plug", fn -> + Sentry.capture_exception(scrub_exception(exception, scrubber), + stacktrace: stacktrace, + event_source: :plug, + handled: false ) - else - exception - end + end) + :ok + end + + @doc false + def __capture_message__(message, stacktrace) do _ = - Sentry.capture_exception(exception, - stacktrace: stacktrace, - event_source: :plug, - handled: false - ) + Sentry.Callback.guard("Sentry failed to capture a message from Plug", fn -> + Sentry.capture_message(message, stacktrace: stacktrace, event_source: :plug) + end) :ok end + # `Phoenix.ActionClauseError` is the one error whose args we know the shape of - + # a controller action is invoked as `apply(controller, action, [conn, conn.params])`. + # We handle it explicitly: `StacktraceScrubber` does the generic per-arg scrubbing, + # and we instruct it (via the callback) to scrub the conn through the configured + # `:scrubber` and mirror the conn's scrubbed params onto the standalone params arg. + defp scrub_exception(exception, scrubber) do + if is_struct(exception, Phoenix.ActionClauseError) do + case Sentry.Callback.guard("Sentry failed to scrub a Phoenix.ActionClauseError", fn -> + Sentry.Scrubber.StacktraceScrubber.scrub( + exception, + &scrub_action_clause_args(&1, scrubber) + ) + end) do + {:ok, scrubbed} -> scrubbed + :failed -> Sentry.Scrubber.StacktraceScrubber.scrub(exception) + end + else + exception + end + end + defp scrub_action_clause_args(args, scrubber) do - conn = Enum.find(args, &is_struct(&1, Plug.Conn)) - scrubbed_conn = apply_scrubber(conn, scrubber) - params = conn.params - - Enum.map(args, fn - ^conn -> scrubbed_conn - ^params -> scrubbed_conn.params - other -> Sentry.Scrubber.scrub(other) - end) + case Enum.find(args, &is_struct(&1, Plug.Conn)) do + nil -> + Sentry.Scrubber.StacktraceScrubber.scrub_args(args) + + conn -> + scrubbed_conn = apply_scrubber(conn, scrubber) + params = conn.params + + Enum.map(args, fn + ^conn -> scrubbed_conn + ^params -> scrubbed_conn.params + other -> Sentry.Scrubber.scrub(other) + end) + end end @doc false def default_scrubber(conn), do: Sentry.Scrubber.scrub(conn) - defp apply_scrubber(conn, {mod, fun, args} = _scrubber) do - case apply(mod, fun, [conn | args]) do - conn when is_struct(conn, Plug.Conn) -> conn - other -> raise ":scrubber function must return a Plug.Conn struct, got: #{inspect(other)}" + defp apply_scrubber(conn, scrubber) do + invocation = Sentry.Callback.to_fun(:scrubber, scrubber, [conn]) + + with {:ok, scrubbed} <- Sentry.Callback.run(:scrubber, invocation), + {:ok, scrubbed} <- + Sentry.Callback.validate( + :scrubber, + scrubbed, + &is_struct(&1, Plug.Conn), + "a Plug.Conn struct" + ) do + scrubbed + else + _ -> default_scrubber(conn) end end end diff --git a/lib/sentry/plug_context.ex b/lib/sentry/plug_context.ex index d5240f0d..98f09ea9 100644 --- a/lib/sentry/plug_context.ex +++ b/lib/sentry/plug_context.ex @@ -164,6 +164,39 @@ defmodule Sentry.PlugContext do The `:remote_address_reader` option must be a function that accepts a `Plug.Conn` returns a `t:String.t/0` IP, or a `{module, function}` tuple, where `module.function/1` takes a `Plug.Conn` and returns a `t:String.t/0` IP. + + ## Crashing Callbacks + + Every callback this plug accepts runs in the request process. If one raises, + throws, or exits, Sentry catches the failure rather than letting it reach the + rest of your pipeline, so **the request itself is unaffected** and is served + exactly as it would have been. The failure is logged at the `:error` level with + the `:sentry` logger domain, so the SDK never reports its own callback failure + as an event. + + Only the field that callback was responsible for degrades, and it degrades to + the SDK's own default for that field: + + | Option | Value reported after a crash | + | --- | --- | + | `:body_scrubber` | `default_body_scrubber/1` | + | `:header_scrubber` | `default_header_scrubber/1` | + | `:cookie_scrubber` | `default_cookie_scrubber/1` | + | `:url_scrubber` | `default_url_scrubber/1` | + | `:remote_address_reader` | the `x-forwarded-for` header, falling back to `conn.remote_ip` | + + The other fields are still produced by their own callbacks, and the event is + still sent. + + > #### A crashed scrubber reports more, not less {: .warning} + > + > The fallback is the SDK default, which redacts the keys listed in + > `Sentry.Scrubber.default_param_keys/0` and `Sentry.Scrubber.default_header_keys/0` + > and nothing more. A custom scrubber that dropped a field the default keeps - + > an internal identifier, a request body the default has no rule for - stops + > dropping it for as long as it keeps failing, and that data is sent to Sentry. + > The error-level log is the only signal, so alert on it rather than treating a + > custom scrubber as a guarantee. """ if Code.ensure_loaded?(Plug) do @@ -196,9 +229,6 @@ defmodule Sentry.PlugContext do @doc false @spec build_request_interface_data(Plug.Conn.t(), keyword()) :: Sentry.Context.request_context() def build_request_interface_data(conn, opts) do - remote_address_reader = - Keyword.get(opts, :remote_address_reader, {__MODULE__, :default_remote_address_reader}) - request_id_header = Keyword.get(opts, :request_id_header, @default_plug_request_id_header) conn = @@ -215,7 +245,7 @@ defmodule Sentry.PlugContext do cookies: scrubbed.cookies, headers: Map.new(scrubbed.req_headers), env: %{ - "REMOTE_ADDR" => apply_fun_with_conn(conn, remote_address_reader, %{}), + "REMOTE_ADDR" => remote_address(conn, opts), "REMOTE_PORT" => remote_port(conn), "SERVER_NAME" => conn.host, "SERVER_PORT" => conn.port, @@ -264,9 +294,23 @@ defmodule Sentry.PlugContext do end end - defp apply_fun_with_conn(_conn, _function = nil, default), do: default - defp apply_fun_with_conn(conn, {module, fun}, _default), do: apply(module, fun, [conn]) - defp apply_fun_with_conn(conn, fun, _default) when is_function(fun, 1), do: fun.(conn) + defp remote_address(conn, opts) do + case Keyword.fetch(opts, :remote_address_reader) do + :error -> + default_remote_address_reader(conn) + + {:ok, nil} -> + %{} + + {:ok, reader} -> + invocation = Sentry.Callback.to_fun(:remote_address_reader, reader, [conn]) + + case Sentry.Callback.run(:remote_address_reader, invocation) do + {:ok, address} -> address + :failed -> default_remote_address_reader(conn) + end + end + end @doc """ Scrubs sensitive query parameters from the request URL. diff --git a/lib/sentry/scrubber.ex b/lib/sentry/scrubber.ex index 49b90fe2..d3db2bed 100644 --- a/lib/sentry/scrubber.ex +++ b/lib/sentry/scrubber.ex @@ -126,6 +126,8 @@ defmodule Sentry.Scrubber do @moduledoc since: "13.1.0" + alias Sentry.Callback + @scrubbed_value "*********" @scrubber_pdict_key {__MODULE__, :scrubber} @scrubber_names [:body_scrubber, :header_scrubber, :cookie_scrubber, :url_scrubber] @@ -440,49 +442,34 @@ defmodule Sentry.Scrubber do pass_through(field) {:ok, {m, f, args}} when is_atom(m) and is_atom(f) and is_list(args) -> - {m, f, args} |> mfa_to_fun() |> wrap_custom_scrubber(field) + {m, f, args} |> mfa_to_fun() |> wrap_custom_scrubber(opt_name, field) {:ok, {m, f}} when is_atom(m) and is_atom(f) -> - {m, f, []} |> mfa_to_fun() |> wrap_custom_scrubber(field) + {m, f, []} |> mfa_to_fun() |> wrap_custom_scrubber(opt_name, field) {:ok, fun} when is_function(fun, 1) -> - wrap_custom_scrubber(fun, field) + wrap_custom_scrubber(fun, opt_name, field) end end - defp wrap_custom_scrubber(scrubber, :url) do + defp wrap_custom_scrubber(scrubber, opt_name, field) do fn conn -> - case call_url_scrubber(scrubber, conn) do - {:ok, url} when is_binary(url) -> - url - - {:ok, _other} -> - Sentry.LoggerUtils.warning( - "url_scrubber function returned a non-binary value; falling back to the default URL scrubber" - ) - - scrub(conn, :url) - - {:error, error} -> - Sentry.LoggerUtils.warning( - "url_scrubber function failed: #{inspect(error)}; falling back to the default URL scrubber" - ) - - scrub(conn, :url) + case Callback.run(opt_name, fn -> scrubber.(conn) end) do + {:ok, value} -> validate_scrubbed(field, value, conn, opt_name) + :failed -> scrub(conn, field) end end end - defp wrap_custom_scrubber(scrubber, _field), do: scrubber - - defp call_url_scrubber(scrubber, conn) do - try do - {:ok, scrubber.(conn)} - rescue - error -> {:error, error} + defp validate_scrubbed(:url, url, conn, opt_name) do + case Callback.validate(opt_name, url, &is_binary/1, "a binary") do + {:ok, url} -> url + :invalid -> scrub(conn, :url) end end + defp validate_scrubbed(_field, value, _conn, _opt_name), do: value + defp pass_through(:url), do: fn conn -> Plug.Conn.request_url(conn) end defp pass_through(_field), do: fn _conn -> %{} end diff --git a/test/plug_capture_test.exs b/test/plug_capture_test.exs index 9c8a46ba..ed82e06f 100644 --- a/test/plug_capture_test.exs +++ b/test/plug_capture_test.exs @@ -3,6 +3,7 @@ defmodule Sentry.PlugCaptureTest do @moduletag send_result: :none + import ExUnit.CaptureLog import Plug.Test import Sentry.Test.Assertions @@ -18,6 +19,25 @@ defmodule Sentry.PlugCaptureTest do def throw(_conn, _params), do: throw(:test) def action_clause_error(conn, %{"required_param" => true}), do: conn def assigns(conn, _params), do: _test = conn.assigns2.test + + def unreportable_attachment(_conn, _params) do + Sentry.Context.add_attachment(%Sentry.Attachment{ + filename: "broken.txt", + data: :not_a_binary + }) + + raise "PhoenixError" + end + + def action_clause_error_without_conn(_conn, _params) do + raise Phoenix.ActionClauseError, + module: __MODULE__, + function: :action_clause_error_without_conn, + arity: 2, + args: [%{"password" => "secret"}], + clauses: nil, + kind: :def + end end defmodule PhoenixRouter do @@ -27,7 +47,13 @@ defmodule Sentry.PlugCaptureTest do get "/exit_route", PhoenixController, :exit get "/throw_route", PhoenixController, :throw get "/action_clause_error", PhoenixController, :action_clause_error + + get "/action_clause_error_without_conn", + PhoenixController, + :action_clause_error_without_conn + get "/assigns_route", PhoenixController, :assigns + get "/unreportable_attachment_route", PhoenixController, :unreportable_attachment get "/reset_password/:token", PhoenixController, :action_clause_error get "/verify/:secret", PhoenixController, :action_clause_error end @@ -62,6 +88,22 @@ defmodule Sentry.PlugCaptureTest do plug PhoenixRouter end + defmodule FailingScrubber do + def scrub_conn(_conn), do: raise("scrubber bug") + end + + defmodule PhoenixEndpointWithFailingScrubber do + use Sentry.PlugCapture, scrubber: {FailingScrubber, :scrub_conn, []} + use Phoenix.Endpoint, otp_app: :sentry + use Plug.Debugger, otp_app: :sentry + + json_mod = if Code.ensure_loaded?(JSON), do: JSON, else: Jason + + plug Plug.Parsers, parsers: [:json], pass: ["*/*"], json_decoder: json_mod + plug Sentry.PlugContext + plug PhoenixRouter + end + defmodule CustomBodyScrubber do def scrub(_conn), do: %{"scrubbed_by" => "custom_body_scrubber"} end @@ -190,6 +232,24 @@ defmodule Sentry.PlugCaptureTest do assert exception.value == "PhoenixError" end + @tag send_result: :sync + test "raises the application's exception unchanged when capturing it fails", %{bypass: bypass} do + ref = SentryTest.setup_bypass_envelope_collector(bypass) + + log = + capture_sentry_log(fn -> + assert_raise RuntimeError, "PhoenixError", fn -> + conn(:get, "/unreportable_attachment_route") + |> call_phoenix_endpoint() + end + end) + + refute_receive {:bypass_envelope, ^ref, _body}, 200 + + assert log =~ + ~r/domain=(\w+\.)*sentry \[error\]\s+Sentry failed to capture an exception from Plug/ + end + test "reports exits" do catch_exit(conn(:get, "/exit_route") |> call_phoenix_endpoint()) @@ -328,6 +388,52 @@ defmodule Sentry.PlugCaptureTest do refute arg2 =~ "123-45-6789", "ssn leaked through the non-conn params arg: #{arg2}" end + test "raises the application's exception when the :scrubber fails" do + Application.put_env(:sentry, PhoenixEndpointWithFailingScrubber, + render_errors: [view: Sentry.ErrorView, accepts: ~w(html)] + ) + + pid = start_supervised!(PhoenixEndpointWithFailingScrubber) + Process.link(pid) + + log = + capture_sentry_log(fn -> + assert_raise Phoenix.ActionClauseError, fn -> + conn(:get, "/action_clause_error?password=secret") + |> Plug.run([{PhoenixEndpointWithFailingScrubber, []}]) + end + end) + + event = + assert_sentry_report(:event, + culprit: "Sentry.PlugCaptureTest.PhoenixController.action_clause_error/2" + ) + + assert [exception] = event.exception + assert exception.type == "Phoenix.ActionClauseError" + assert exception.value =~ ~s(params: %{"password" => "*********"}) + refute exception.value =~ ~s(query_string: "password=secret") + + assert log =~ ~r/domain=(\w+\.)*sentry \[error\]\s+:scrubber callback failed/ + end + + test "scrubs the args of an action clause error that holds no conn" do + assert_raise Phoenix.ActionClauseError, fn -> + conn(:get, "/action_clause_error_without_conn") + |> call_phoenix_endpoint() + end + + event = + assert_sentry_report(:event, + culprit: "Sentry.PlugCaptureTest.PhoenixController.action_clause_error_without_conn/2" + ) + + assert [exception] = event.exception + assert exception.type == "Phoenix.ActionClauseError" + assert exception.value =~ ~s(%{"password" => "*********"}) + refute exception.value =~ "secret" + end + test "can render feedback form in Phoenix ErrorView" do conn = conn(:get, "/error_route") @@ -461,4 +567,6 @@ defmodule Sentry.PlugCaptureTest do defp call_plug_app(conn), do: Plug.run(conn, [{Sentry.ExamplePlugApplication, []}]) defp call_phoenix_endpoint(conn), do: Plug.run(conn, [{PhoenixEndpoint, []}]) + + defp capture_sentry_log(fun), do: capture_log([metadata: [:domain]], fun) end diff --git a/test/sentry/live_view_hook_test.exs b/test/sentry/live_view_hook_test.exs index 7f6c6297..60d012c5 100644 --- a/test/sentry/live_view_hook_test.exs +++ b/test/sentry/live_view_hook_test.exs @@ -291,7 +291,8 @@ defmodule Sentry.LiveViewHookTest do view end) - assert log =~ "Sentry.LiveViewHook scrubber raised an error" + assert log =~ ":scrubber callback failed" + assert log =~ "scrubber crashed!" assert log =~ ~r/domain=(\w+\.)*sentry/ [event_breadcrumb | _] = get_sentry_context(view).breadcrumbs @@ -299,7 +300,7 @@ defmodule Sentry.LiveViewHookTest do assert event_breadcrumb.data == %{} end - test "logs error and uses empty data when scrubber returns a non-map", %{conn: conn} do + test "logs a warning and uses empty data when scrubber returns a non-map", %{conn: conn} do {view, log} = ExUnit.CaptureLog.with_log([metadata: [:domain]], fn -> {:ok, view, _html} = live(conn, "/non_map_scrubber") @@ -307,8 +308,8 @@ defmodule Sentry.LiveViewHookTest do view end) - assert log =~ "Sentry.LiveViewHook scrubber returned non-map value" - assert log =~ ~r/domain=(\w+\.)*sentry/ + assert log =~ ":scrubber callback returned an invalid value: expected a map" + assert log =~ ~r/domain=(\w+\.)*sentry \[warning\]/ [event_breadcrumb | _] = get_sentry_context(view).breadcrumbs assert event_breadcrumb.category == "web.live_view.event" diff --git a/test/sentry/plug_context_test.exs b/test/sentry/plug_context_test.exs index 1f06039b..16cb3d18 100644 --- a/test/sentry/plug_context_test.exs +++ b/test/sentry/plug_context_test.exs @@ -1,5 +1,6 @@ defmodule Sentry.PlugContextTest do use Sentry.Case, async: false + import ExUnit.CaptureLog import Plug.Conn import Plug.Test @@ -157,13 +158,81 @@ defmodule Sentry.PlugContextTest do test "falls back to the default URL scrubber when a custom scrubber raises" do conn = conn(:get, "/test?password=hunter2&hello=world") - call(conn, url_scrubber: fn _conn -> raise "custom scrubber bug" end) + + log = + capture_sentry_log(fn -> + call(conn, url_scrubber: fn _conn -> raise "custom scrubber bug" end) + end) assert "http://www.example.com/test?password=#{Sentry.Scrubber.scrubbed_value()}&hello=world" == Sentry.Context.get_all().request.url assert "password=#{Sentry.Scrubber.scrubbed_value()}&hello=world" == Sentry.Context.get_all().request.query_string + + assert log =~ ~r/domain=(\w+\.)*sentry \[error\]\s+:url_scrubber callback failed/ + end + + test "falls back to the default URL scrubber when a custom scrubber throws" do + conn = conn(:get, "/test?password=hunter2&hello=world") + + log = capture_sentry_log(fn -> call(conn, url_scrubber: fn _conn -> throw(:boom) end) end) + + assert "http://www.example.com/test?password=#{Sentry.Scrubber.scrubbed_value()}&hello=world" == + Sentry.Context.get_all().request.url + + assert log =~ ~r/domain=(\w+\.)*sentry \[error\]\s+:url_scrubber callback failed/ + end + + test "falls back to the default body scrubber when a custom scrubber fails" do + conn = conn(:post, "/error_route", %{"password" => "hunter2", "count" => 334}) + + log = + capture_sentry_log(fn -> + call(conn, body_scrubber: fn _conn -> raise "custom scrubber bug" end) + end) + + assert %{"password" => Sentry.Scrubber.scrubbed_value(), "count" => 334} == + Sentry.Context.get_all().request.data + + assert log =~ ~r/domain=(\w+\.)*sentry \[error\]\s+:body_scrubber callback failed/ + end + + test "falls back to the default header scrubber when a custom scrubber fails", %{conn: conn} do + log = + capture_sentry_log(fn -> + conn + |> put_req_header("authorization", "secrets") + |> put_req_header("content-type", "application/json") + |> call(header_scrubber: fn _conn -> throw(:boom) end) + end) + + assert %{"content-type" => "application/json"} == Sentry.Context.get_all().request.headers + assert log =~ ~r/domain=(\w+\.)*sentry \[error\]\s+:header_scrubber callback failed/ + end + + test "falls back to the default cookie scrubber when a custom scrubber fails", %{conn: conn} do + log = + capture_sentry_log(fn -> + conn + |> put_req_cookie("not-secret", "value") + |> call(cookie_scrubber: fn _conn -> exit(:boom) end) + end) + + assert %{} == Sentry.Context.get_all().request.cookies + assert log =~ ~r/domain=(\w+\.)*sentry \[error\]\s+:cookie_scrubber callback failed/ + end + + test "falls back to the default remote address reader when a custom reader fails", %{conn: conn} do + log = + capture_sentry_log(fn -> + conn + |> put_req_header("x-forwarded-for", "10.0.0.1") + |> call(remote_address_reader: fn _conn -> raise "custom reader bug" end) + end) + + assert %{"REMOTE_ADDR" => "10.0.0.1"} = Sentry.Context.get_all().request.env + assert log =~ ~r/domain=(\w+\.)*sentry \[error\]\s+:remote_address_reader callback failed/ end test "falls back to the default URL scrubber when a custom scrubber returns a non-binary" do @@ -312,4 +381,6 @@ defmodule Sentry.PlugContextTest do defp call(conn, opts) do Plug.run(conn, [{Sentry.PlugContext, opts}]) end + + defp capture_sentry_log(fun), do: capture_log([metadata: [:domain]], fun) end diff --git a/test/sentry/scrubber_test.exs b/test/sentry/scrubber_test.exs index 783e2915..ece40512 100644 --- a/test/sentry/scrubber_test.exs +++ b/test/sentry/scrubber_test.exs @@ -21,11 +21,15 @@ defmodule Sentry.ScrubberTest do end test "uses the given per-field scrubber and defaults the rest" do - marker = fn _conn -> %{"marker" => "custom"} end - scrubber = Scrubber.new(body_scrubber: marker) + conn = %Plug.Conn{ + params: %{"password" => "hunter2"}, + req_headers: [{"authorization", "Bearer x"}, {"x-keep", "yes"}] + } + + scrubber = Scrubber.new(body_scrubber: fn _conn -> %{"marker" => "custom"} end) - assert scrubber.body_scrubber == marker - assert is_function(scrubber.header_scrubber, 1) + assert scrubber.body_scrubber.(conn) == %{"marker" => "custom"} + assert scrubber.header_scrubber.(conn) == [{"x-keep", "yes"}] end test "does not register the scrubber for the process" do