diff --git a/lib/sentry.ex b/lib/sentry.ex index 63237c83..fc9899a4 100644 --- a/lib/sentry.ex +++ b/lib/sentry.ex @@ -214,6 +214,37 @@ defmodule Sentry do > 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. + ### Oban Callbacks + + The callbacks the Oban integration accepts run inside `:telemetry` handlers, and + `:telemetry` permanently detaches a handler that fails. Sentry's two Oban handlers + therefore catch every failure in their own body, so a callback of yours that keeps failing + never stops later jobs from being reported or checked in. + + No Oban item is dropped because one of these callbacks failed. The two that only return a + decision fail open, and the three that customize an item fall back to what the SDK derived + on its own: + + | Callback | Behavior after a crash | + | --- | --- | + | `:should_report_error_callback` | the job error is reported | + | `:should_report_error_check_in_callback` | the failed check-in is reported | + | `:oban_tags_to_sentry_tags` | the event carries the SDK's own Oban tags (`oban_worker`, `oban_queue`, and `oban_state`) and none of yours | + | `:monitor_slug_generator` | the check-in uses the slug derived from the worker name | + | `c:Sentry.Integrations.Oban.Cron.sentry_check_in_configuration/1` | the check-in uses the slug and monitor config the integration inferred, with nothing merged in | + + > #### A crashing check-in customization sends the check-in elsewhere {: .warning} + > + > A check-in whose `:monitor_slug_generator` or `sentry_check_in_configuration/1` failed is + > still sent, but under the SDK's default slug rather than the one you configured. For as + > long as the callback keeps failing, the monitor you meant to check in to receives nothing + > and looks idle, while a monitor under the default slug receives the check-ins instead. The + > error-level log is the only signal. + + If a failure happens elsewhere in one of the handlers, the check-in or error event it was + about to send is lost. That loss is counted in client reports under `internal_sdk_error` + rather than passing silently. + ## 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 04a922a8..0922b708 100644 --- a/lib/sentry/callback.ex +++ b/lib/sentry/callback.ex @@ -7,29 +7,28 @@ defmodule Sentry.Callback do @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 - case run(name, fun) do - {:ok, result} -> - result - - :failed -> - record_discard(Keyword.get(opts, :discard)) - fallback + def run(name, fun, fallback, opts \\ []) when is_atom(name) and is_list(opts) do + case guard(describe_failure(name, Keyword.get(opts, :context)), fun, opts) do + {:ok, result} -> result + :failed -> fallback end end @spec run(atom(), (-> result)) :: {:ok, result} | :failed when result: var def run(name, fun) when is_atom(name) do - guard("#{inspect(name)} callback failed", fun) + guard(describe_failure(name, nil), 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 + @spec guard(String.t(), (-> result), keyword()) :: {:ok, result} | :failed when result: var + def guard(description, fun, opts \\ []) + when is_binary(description) and is_function(fun, 0) and is_list(opts) do {:ok, fun.()} catch kind, reason -> LoggerUtils.error(description <> ": " <> Exception.format(kind, reason, __STACKTRACE__)) + record_discard(Keyword.get(opts, :discard)) + :failed end @@ -75,4 +74,7 @@ defmodule Sentry.Callback do _ = ClientReport.Sender.record_discarded_events(reason, event_or_data_category) :ok end + + defp describe_failure(name, nil), do: "#{inspect(name)} callback failed" + defp describe_failure(name, context), do: "#{inspect(name)} callback failed #{context}" end diff --git a/lib/sentry/config.ex b/lib/sentry/config.ex index 1ad5bee1..60b2ac98 100644 --- a/lib/sentry/config.ex +++ b/lib/sentry/config.ex @@ -76,6 +76,12 @@ defmodule Sentry.Config do This example transforms all Oban job tags into Sentry tags prefixed with `oban_tags.` and with a value of `true`. *Available since 12.0.0*. + + If the function crashes, the failure is logged at the `:error` level and the event is + still reported, carrying only the tags the integration adds itself (`oban_worker`, + `oban_queue`, and `oban_state`). A return value that is not a map is logged at the + `:warning` level and falls back to those same tags. See the + [*Crashing Callbacks*](#module-crashing-callbacks) section below for more information. """ ], should_report_error_callback: [ @@ -95,6 +101,10 @@ defmodule Sentry.Config do This example only reports errors on final retry attempts. *Available since 12.0.0*. + + If the function crashes, the failure is logged at the `:error` level and the error is + reported, as if the function had returned `true`. See the + [*Crashing Callbacks*](#module-crashing-callbacks) section below for more information. """ ], cron: [ @@ -119,6 +129,12 @@ defmodule Sentry.Config do A `{module, function}` tuple that generates a monitor name based on the `Oban.Job` struct. The function is called with the `Oban.Job` as its arguments and must return a string. This can be used to customize monitor slugs. *Available since v10.8.0*. + + If the function crashes, the failure is logged at the `:error` level and the + check-in is still sent, under the slug the integration derives from the worker + name. Until the function is fixed, the monitor you configured it for receives no + check-ins at all. See the [*Crashing Callbacks*](#module-crashing-callbacks) + section below for more information. """ ], should_report_error_check_in_callback: [ @@ -139,6 +155,11 @@ defmodule Sentry.Config do This example only reports a failed check-in once all retries are exhausted. While retries remain the check-in is left open, so the retry that eventually succeeds closes the same check-in. *Available since v13.5.0*. + + If the function crashes, the failure is logged at the `:error` level and the failed + check-in is reported, as if the function had returned `true`. See the + [*Crashing Callbacks*](#module-crashing-callbacks) section below for more + information. """ ] ] diff --git a/lib/sentry/integrations/oban/callbacks.ex b/lib/sentry/integrations/oban/callbacks.ex new file mode 100644 index 00000000..791b979f --- /dev/null +++ b/lib/sentry/integrations/oban/callbacks.ex @@ -0,0 +1,43 @@ +defmodule Sentry.Integrations.Oban.Callbacks do + @moduledoc false + + alias Sentry.Callback + alias Sentry.LoggerUtils + + @spec should_report?(keyword(), atom(), struct()) :: boolean() + def should_report?(config, option, job) when is_list(config) and is_atom(option) do + case Keyword.get(config, option) do + callback when is_function(callback, 2) -> + worker = resolve_worker(job) + + Callback.run( + option, + fn -> callback.(worker, job) == true end, + true, + context: describe_target(worker, job) + ) + + _ -> + true + end + end + + @spec describe_target(term(), struct()) :: String.t() + def describe_target(worker, job) do + "for worker #{inspect(worker)} (job ID #{inspect(job.id)})" + end + + defp resolve_worker(job) do + case apply(Oban.Worker, :from_string, [job.worker]) do + {:ok, mod} -> + mod + + {:error, _} -> + LoggerUtils.warning( + "Could not resolve Oban worker module from string: #{inspect(job.worker)}" + ) + + nil + end + end +end diff --git a/lib/sentry/integrations/oban/cron.ex b/lib/sentry/integrations/oban/cron.ex index 4f91e541..d3cfb79e 100644 --- a/lib/sentry/integrations/oban/cron.ex +++ b/lib/sentry/integrations/oban/cron.ex @@ -5,8 +5,9 @@ defmodule Sentry.Integrations.Oban.Cron do @moduledoc since: "10.9.0" + alias Sentry.Callback alias Sentry.Integrations.CheckInIDMappings - alias Sentry.LoggerUtils + alias Sentry.Integrations.Oban.Callbacks @doc """ The Oban integration calls this callback (if present) to customize @@ -16,6 +17,13 @@ defmodule Sentry.Integrations.Oban.Cron do Options returned by this function overwrite any option inferred by the specific integration for the check in. We perform *deep merging* of nested keyword options. + + If this callback raises, throws, or exits, the failure is logged at the `:error` level with + the `:sentry` logger domain, and the check-in is still sent with the options the integration + inferred and nothing merged into them. Since those options include the monitor slug, a + check-in that this callback was meant to redirect goes to the monitor named after the worker + instead. See the [*Crashing Callbacks*](`m:Sentry#module-crashing-callbacks`) section of the + `Sentry` documentation for more information. """ @doc since: "10.9.0" @callback sentry_check_in_configuration(oban_job :: struct()) :: options_to_merge :: keyword() @@ -44,7 +52,13 @@ defmodule Sentry.Integrations.Oban.Cron do config ) when event in [:start, :stop, :exception] and mod == Oban.Job and is_binary(cron_expr) do - _ = handle_oban_job_event(event, measurements, metadata, config) + _ = + Callback.guard( + describe_failure(metadata.job), + fn -> handle_oban_job_event(event, measurements, metadata, config) end, + discard: {:internal_sdk_error, "monitor"} + ) + :ok end @@ -55,6 +69,11 @@ defmodule Sentry.Integrations.Oban.Cron do ## Helpers + defp describe_failure(job) do + "Sentry failed to report an Oban check-in for job #{inspect(job.id)} " <> + "(#{inspect(job.worker)})" + end + defp handle_oban_job_event(:start, _measurements, metadata, config) do if opts = job_to_check_in_opts(metadata.job, config) do opts @@ -96,42 +115,7 @@ defmodule Sentry.Integrations.Oban.Cron do end defp should_report_error_check_in?(job, config) do - case Keyword.get(config, :should_report_error_check_in_callback) do - callback when is_function(callback, 2) -> - call_should_report_error_check_in_callback(callback, job) - - _ -> - true - end - end - - defp call_should_report_error_check_in_callback(callback, job) do - worker = - case apply(Oban.Worker, :from_string, [job.worker]) do - {:ok, mod} -> - mod - - {:error, _} -> - LoggerUtils.warning( - "Could not resolve Oban worker module from string: #{inspect(job.worker)}" - ) - - nil - end - - try do - callback.(worker, job) == true - rescue - error -> - LoggerUtils.warning(""" - :should_report_error_check_in_callback failed for worker #{inspect(worker)} \ - (job ID #{job.id}): - - #{Exception.format(:error, error, __STACKTRACE__)}\ - """) - - true - end + Callbacks.should_report?(config, :should_report_error_check_in_callback, job) end defp job_to_check_in_opts(job, config) when is_struct(job, Oban.Job) do @@ -146,14 +130,7 @@ defmodule Sentry.Integrations.Oban.Cron do monitor_config_opts = maybe_put_timezone_option(monitor_config_opts, job) monitor_config_opts = Keyword.merge(monitor_config_opts, schedule_opts) - monitor_slug = - case config[:monitor_slug_generator] do - nil -> - slugify(job.worker) - - {mod, fun} when is_atom(mod) and is_atom(fun) -> - mod |> apply(fun, [job]) |> slugify() - end + monitor_slug = monitor_slug(job, config[:monitor_slug_generator]) id = CheckInIDMappings.lookup_or_insert_new(job.id) @@ -182,14 +159,15 @@ defmodule Sentry.Integrations.Oban.Cron do end end - defp resolve_custom_opts(opts, _job) do - opts - end - defp resolve_custom_opts(options, mod, per_integration_term) do custom_opts = if function_exported?(mod, :sentry_check_in_configuration, 1) do - mod.sentry_check_in_configuration(per_integration_term) + Callback.run( + :sentry_check_in_configuration, + fn -> mod.sentry_check_in_configuration(per_integration_term) end, + [], + context: Callbacks.describe_target(mod, per_integration_term) + ) else [] end @@ -197,6 +175,19 @@ defmodule Sentry.Integrations.Oban.Cron do deep_merge_keyword(options, custom_opts) end + defp monitor_slug(job, nil) do + slugify(job.worker) + end + + defp monitor_slug(job, {mod, fun}) when is_atom(mod) and is_atom(fun) do + Callback.run( + :monitor_slug_generator, + fn -> mod |> apply(fun, [job]) |> slugify() end, + slugify(job.worker), + context: Callbacks.describe_target(job.worker, job) + ) + end + defp deep_merge_keyword(left, right) do Keyword.merge(left, right, fn _key, left_val, right_val -> if Keyword.keyword?(left_val) and Keyword.keyword?(right_val) do diff --git a/lib/sentry/integrations/oban/error_reporter.ex b/lib/sentry/integrations/oban/error_reporter.ex index 29dd26c3..2f556b20 100644 --- a/lib/sentry/integrations/oban/error_reporter.ex +++ b/lib/sentry/integrations/oban/error_reporter.ex @@ -4,7 +4,8 @@ defmodule Sentry.Integrations.Oban.ErrorReporter do # See this blog post: # https://getoban.pro/articles/enhancing-error-reporting - alias Sentry.LoggerUtils + alias Sentry.Callback + alias Sentry.Integrations.Oban.Callbacks @spec attach(keyword()) :: :ok def attach(config \\ []) when is_list(config) do @@ -19,18 +20,31 @@ defmodule Sentry.Integrations.Oban.ErrorReporter do :ok end - @spec handle_event( - [atom(), ...], - term(), - %{required(:job) => struct(), optional(term()) => term()}, - keyword() - ) :: :ok - def handle_event( - [:oban, :job, :exception], - _measurements, - %{job: job, kind: kind, reason: reason, stacktrace: stacktrace} = _metadata, - config - ) do + @spec handle_event([atom(), ...], term(), map(), keyword()) :: :ok + def handle_event([:oban, :job, :exception], measurements, metadata, config) do + _ = + Callback.guard( + describe_failure(metadata), + fn -> capture_job_exception(measurements, metadata, config) end, + discard: {:internal_sdk_error, "error"} + ) + + :ok + end + + defp describe_failure(%{job: %{id: id, worker: worker}}) do + "Sentry failed to report an Oban job exception for job #{inspect(id)} (#{inspect(worker)})" + end + + defp describe_failure(_metadata) do + "Sentry failed to report an Oban job exception" + end + + defp capture_job_exception( + _measurements, + %{job: job, kind: kind, reason: reason, stacktrace: stacktrace} = _metadata, + config + ) do if report?(reason) and should_report?(job, config) do report(job, kind, reason, stacktrace, config) else @@ -39,42 +53,7 @@ defmodule Sentry.Integrations.Oban.ErrorReporter do end defp should_report?(job, config) do - case Keyword.get(config, :should_report_error_callback) do - callback when is_function(callback, 2) -> - call_should_report_error_callback(callback, job) - - _ -> - true - end - end - - defp call_should_report_error_callback(callback, job) do - worker = - case apply(Oban.Worker, :from_string, [job.worker]) do - {:ok, mod} -> - mod - - {:error, _} -> - LoggerUtils.warning( - "Could not resolve Oban worker module from string: #{inspect(job.worker)}" - ) - - nil - end - - try do - callback.(worker, job) == true - rescue - error -> - LoggerUtils.warning(""" - :should_report_error_callback failed for worker #{inspect(worker)} \ - (job ID #{job.id}): - - #{Exception.format(:error, error, __STACKTRACE__)}\ - """) - - true - end + Callbacks.should_report?(config, :should_report_error_callback, job) end defp report(job, kind, reason, stacktrace, config) do @@ -154,31 +133,21 @@ defmodule Sentry.Integrations.Oban.ErrorReporter do defp merge_oban_tags(base_tags, nil, _job), do: base_tags defp merge_oban_tags(base_tags, tags_config, job) do - try do - custom_tags = call_oban_tags_to_sentry_tags(tags_config, job) - - if is_map(custom_tags) do - Map.merge(base_tags, custom_tags) - else - LoggerUtils.warning( - "oban_tags_to_sentry_tags function returned a non-map value: #{inspect(custom_tags)}" - ) - - base_tags - end - rescue - error -> - LoggerUtils.warning("oban_tags_to_sentry_tags function failed: #{inspect(error)}") - - base_tags - end + Callback.run( + :oban_tags_to_sentry_tags, + fn -> + invocation = Callback.to_fun(:oban_tags_to_sentry_tags, tags_config, [job]) + merge_custom_tags(base_tags, invocation.()) + end, + base_tags, + context: Callbacks.describe_target(job.worker, job) + ) end - defp call_oban_tags_to_sentry_tags(fun, job) when is_function(fun, 1) do - fun.(job) - end - - defp call_oban_tags_to_sentry_tags({module, function}, job) do - apply(module, function, [job]) + defp merge_custom_tags(base_tags, custom_tags) do + case Callback.validate(:oban_tags_to_sentry_tags, custom_tags, &is_map/1, "a map") do + {:ok, custom_tags} -> Map.merge(base_tags, custom_tags) + :invalid -> base_tags + end end end diff --git a/test/sentry/integrations/oban/cron_test.exs b/test/sentry/integrations/oban/cron_test.exs index 43d19b31..a34d3d9c 100644 --- a/test/sentry/integrations/oban/cron_test.exs +++ b/test/sentry/integrations/oban/cron_test.exs @@ -1,3 +1,21 @@ +for {worker, failure} <- [ + {Sentry.RaisingConfigWorker, quote(do: raise("the check-in configuration is broken"))}, + {Sentry.ThrowingConfigWorker, quote(do: throw(:the_check_in_configuration_is_broken))}, + {Sentry.ExitingConfigWorker, quote(do: exit(:the_check_in_configuration_is_broken))} + ] do + defmodule worker do + use Oban.Worker + + @behaviour Sentry.Integrations.Oban.Cron + + @impl Oban.Worker + def perform(_job), do: :ok + + @impl Sentry.Integrations.Oban.Cron + def sentry_check_in_configuration(_job), do: unquote(failure) + end +end + defmodule Sentry.Integrations.Oban.CronTest do alias Sentry.Integrations.CheckInIDMappings use Sentry.Case, async: false @@ -304,6 +322,72 @@ defmodule Sentry.Integrations.Oban.CronTest do ) end + describe "when the monitor_slug_generator fails" do + for {kind, generator} <- [ + raise: :raising_name_generator, + throw: :throwing_name_generator, + exit: :exiting_name_generator + ] do + @tag attach_opts: [monitor_slug_generator: {__MODULE__, generator}] + test "still reports the check-in under the default slug when the generator #{kind}s", %{ + ref: ref + } do + log = + capture_log([metadata: [:domain]], fn -> + :telemetry.execute([:oban, :job, :start], %{}, %{ + job: cron_job(worker: "Sentry.MyWorker") + }) + + [check_in_body] = SentryTest.collect_sentry_check_ins(ref, 1) + + assert_sentry_report(check_in_body, + status: "in_progress", + monitor_slug: "sentry-my-worker" + ) + end) + + assert log =~ + ~s(:monitor_slug_generator callback failed for worker "Sentry.MyWorker" ) <> + "(job ID 942)" + + assert log =~ ~r/domain=(\w+\.)*sentry/ + end + end + end + + describe "when sentry_check_in_configuration/1 fails" do + for {kind, worker, slug} <- [ + {:raise, Sentry.RaisingConfigWorker, "sentry-raising-config-worker"}, + {:throw, Sentry.ThrowingConfigWorker, "sentry-throwing-config-worker"}, + {:exit, Sentry.ExitingConfigWorker, "sentry-exiting-config-worker"} + ] do + test "still reports the check-in with the SDK-derived options when it #{kind}s", %{ref: ref} do + log = + capture_log([metadata: [:domain]], fn -> + :telemetry.execute([:oban, :job, :start], %{}, %{ + job: cron_job(worker: inspect(unquote(worker))) + }) + + [check_in_body] = SentryTest.collect_sentry_check_ins(ref, 1) + + assert_sentry_report(check_in_body, + status: "in_progress", + monitor_slug: unquote(slug), + monitor_config: %{ + "schedule" => %{"type" => "interval", "value" => 1, "unit" => "day"} + } + ) + end) + + assert log =~ + ":sentry_check_in_configuration callback failed " <> + "for worker #{inspect(unquote(worker))} (job ID 942)" + + assert log =~ ~r/domain=(\w+\.)*sentry/ + end + end + end + describe "should_report_error_check_in_callback" do test "should not report a failed check-in when the callback returns false", %{ref: ref} do attach_with_callback(fn _worker, _job -> false end) @@ -336,20 +420,28 @@ defmodule Sentry.Integrations.Oban.CronTest do refute_sentry_check_in(ref) end - test "should report the failed check-in when the callback raises", %{ref: ref} do - log = - capture_log([metadata: [:domain]], fn -> - attach_with_callback(fn _worker, _job -> raise "callback error" end) + for {kind, failure} <- [ + raise: quote(do: raise("callback error")), + throw: quote(do: throw(:callback_error)), + exit: quote(do: exit(:callback_error)) + ] do + test "should report the failed check-in when the callback #{kind}s", %{ref: ref} do + log = + capture_log([metadata: [:domain]], fn -> + attach_with_callback(fn _worker, _job -> unquote(failure) end) - execute_exception_event() + execute_exception_event() - [check_in_body] = SentryTest.collect_sentry_check_ins(ref, 1) - assert_sentry_report(check_in_body, status: "error") - end) + [check_in_body] = SentryTest.collect_sentry_check_ins(ref, 1) + assert_sentry_report(check_in_body, status: "error") + end) - assert log =~ ":should_report_error_check_in_callback failed" - assert log =~ "callback error" - assert log =~ ~r/domain=(\w+\.)*sentry/ + assert log =~ ~r/domain=(\w+\.)*sentry \[error\]/ + + assert log =~ + ":should_report_error_check_in_callback callback failed " <> + "for worker #{inspect(MyCronWorker)} (job ID 942)" + end end test "should pass a nil worker to the callback when the worker cannot be resolved", %{ @@ -386,6 +478,61 @@ defmodule Sentry.Integrations.Oban.CronTest do end end + describe "when handling a job event fails" do + for {kind, failure} <- [ + raise: quote(do: raise("the callback is broken")), + throw: quote(do: throw(:the_callback_is_broken)), + exit: quote(do: exit(:the_callback_is_broken)) + ] do + test "keeps reporting check-ins after a callback #{kind}s", %{ref: ref} do + attach_with_callback(fn _worker, _job -> unquote(failure) end) + + capture_log(fn -> + execute_exception_event() + + :telemetry.execute([:oban, :job, :start], %{}, %{ + job: cron_job(worker: "Sentry.LaterWorker", id: 7) + }) + end) + + assert handler_attached?() + + slugs = + ref + |> SentryTest.collect_sentry_check_ins(2) + |> Enum.map(& &1["monitor_slug"]) + + assert "sentry-later-worker" in slugs + end + end + + test "records a discarded check-in when the job carries an unknown state", %{ + ref: ref, + client_report_sender: sender + } do + log = + capture_log([metadata: [:domain]], fn -> + :telemetry.execute([:oban, :job, :stop], %{duration: 0}, %{ + state: :unrecognized, + job: cron_job() + }) + end) + + assert log =~ + ~r/domain=(\w+\.)*sentry \[error\]\s+Sentry failed to report an Oban check-in for job 942/ + + assert handler_attached?() + refute_sentry_check_in(ref) + assert %{{:internal_sdk_error, "monitor"} => 1} = :sys.get_state(sender) + end + end + + defp handler_attached? do + [:oban, :job, :exception] + |> :telemetry.list_handlers() + |> Enum.any?(&(&1.id == Sentry.Integrations.Oban.Cron)) + end + defp attach_with_callback(callback) do :telemetry.detach(Sentry.Integrations.Oban.Cron) @@ -417,4 +564,10 @@ defmodule Sentry.Integrations.Oban.CronTest do end def custom_name_generator(%Oban.Job{worker: worker}), do: worker + + def raising_name_generator(_job), do: raise("the slug generator is broken") + + def throwing_name_generator(_job), do: throw(:the_slug_generator_is_broken) + + def exiting_name_generator(_job), do: exit(:the_slug_generator_is_broken) end diff --git a/test/sentry/integrations/oban/error_reporter_test.exs b/test/sentry/integrations/oban/error_reporter_test.exs index 1e30b4c8..eb681bec 100644 --- a/test/sentry/integrations/oban/error_reporter_test.exs +++ b/test/sentry/integrations/oban/error_reporter_test.exs @@ -184,19 +184,33 @@ defmodule Sentry.Integrations.Oban.ErrorReporterTest do assert_sentry_report(:event, tags: %{"custom_tag" => "custom_value"}) end - test "handles oban_tags_to_sentry_tags errors gracefully" do - log = - capture_log([metadata: [:domain]], fn -> - emit_telemetry_for_failed_job(:error, %RuntimeError{message: "oops"}, [], - oban_tags_to_sentry_tags: fn _job -> raise "tag transform error" end - ) - end) + for {kind, failure} <- [ + raise: quote(do: raise("tag transform error")), + throw: quote(do: throw(:tag_transform_error)), + exit: quote(do: exit(:tag_transform_error)) + ] do + test "falls back to the base Oban tags when oban_tags_to_sentry_tags #{kind}s" do + log = + capture_log([metadata: [:domain]], fn -> + emit_telemetry_for_failed_job(:error, %RuntimeError{message: "oops"}, [], + oban_tags_to_sentry_tags: fn _job -> unquote(failure) end + ) + end) - assert log =~ "oban_tags_to_sentry_tags function failed" - assert log =~ "tag transform error" - assert log =~ ~r/domain=(\w+\.)*sentry/ + assert log =~ ~r/domain=(\w+\.)*sentry \[error\]/ - assert_sentry_report(:event, []) + assert log =~ + ":oban_tags_to_sentry_tags callback failed " <> + "for worker #{inspect(@worker_as_string)} (job ID nil)" + + assert_sentry_report(:event, + tags: %{ + "oban_queue" => "default", + "oban_state" => "available", + "oban_worker" => @worker_as_string + } + ) + end end test "handles invalid oban_tags_to_sentry_tags return values gracefully" do @@ -217,8 +231,8 @@ defmodule Sentry.Integrations.Oban.ErrorReporterTest do end) end) - assert log =~ "oban_tags_to_sentry_tags function returned a non-map value" - assert log =~ ~r/domain=(\w+\.)*sentry/ + assert log =~ ":oban_tags_to_sentry_tags callback returned an invalid value: expected a map" + assert log =~ ~r/domain=(\w+\.)*sentry \[warning\]/ events = SentryTest.pop_sentry_reports() assert length(events) == length(test_cases) @@ -313,23 +327,30 @@ defmodule Sentry.Integrations.Oban.ErrorReporterTest do assert exception.value == "oops" end - test "should_report_error_callback handles errors gracefully and defaults to reporting" do - log = - capture_log([metadata: [:domain]], fn -> - emit_telemetry_for_failed_job(:error, %RuntimeError{message: "oops"}, [], - should_report_error_callback: fn _worker, _job -> raise "callback error" end - ) - end) + for {kind, failure} <- [ + raise: quote(do: raise("callback error")), + throw: quote(do: throw(:callback_error)), + exit: quote(do: exit(:callback_error)) + ] do + test "should_report_error_callback still reports the error when it #{kind}s" do + log = + capture_log([metadata: [:domain]], fn -> + emit_telemetry_for_failed_job(:error, %RuntimeError{message: "oops"}, [], + should_report_error_callback: fn _worker, _job -> unquote(failure) end + ) + end) - assert log =~ "should_report_error_callback failed" - assert log =~ "Sentry.Integrations.Oban.ErrorReporterTest.MyWorker" - assert log =~ "callback error" - assert log =~ ~r/domain=(\w+\.)*sentry/ + assert log =~ ~r/domain=(\w+\.)*sentry \[error\]/ - event = assert_sentry_report(:event, []) - assert [exception] = event.exception - assert exception.type == "RuntimeError" - assert exception.value == "oops" + assert log =~ + ":should_report_error_callback callback failed " <> + "for worker #{@worker_as_string} (job ID nil)" + + event = assert_sentry_report(:event, []) + assert [exception] = event.exception + assert exception.type == "RuntimeError" + assert exception.value == "oops" + end end test "should_report_error_callback receives a nil worker when the job worker doesn't resolve" do @@ -384,8 +405,91 @@ defmodule Sentry.Integrations.Oban.ErrorReporterTest do end end + describe "when handling a job event fails" do + setup do + SentryTest.setup_sentry() + end + + for {kind, failure} <- [ + raise: quote(do: raise("the callback is broken")), + throw: quote(do: throw(:the_callback_is_broken)), + exit: quote(do: exit(:the_callback_is_broken)) + ] do + test "keeps reporting job exceptions after a callback #{kind}s" do + attach_error_reporter( + should_report_error_callback: fn _worker, job -> + if job.args["id"] == "broken", do: unquote(failure), else: true + end + ) + + capture_log(fn -> + execute_exception_event(build_job(%{"id" => "broken"}), %RuntimeError{ + message: "broken job" + }) + + execute_exception_event(build_job(%{"id" => "later"}), %RuntimeError{ + message: "later job" + }) + end) + + assert handler_attached?() + assert "later job" in reported_exception_values() + end + end + + test "records a discarded error when the job event carries no exception", %{ + client_report_sender: sender + } do + attach_error_reporter() + + log = + capture_log([metadata: [:domain]], fn -> + :telemetry.execute([:oban, :job, :exception], %{}, %{job: build_job()}) + end) + + assert log =~ + ~r/domain=(\w+\.)*sentry \[error\]\s+Sentry failed to report an Oban job exception/ + + assert handler_attached?() + assert [] = SentryTest.pop_sentry_reports() + assert %{{:internal_sdk_error, "error"} => 1} = :sys.get_state(sender) + end + end + ## Helpers + defp attach_error_reporter(config \\ []) do + :ok = ErrorReporter.attach(config) + on_exit(fn -> :telemetry.detach(ErrorReporter) end) + end + + defp handler_attached? do + [:oban, :job, :exception] + |> :telemetry.list_handlers() + |> Enum.any?(&(&1.id == ErrorReporter)) + end + + defp execute_exception_event(job, reason) do + :telemetry.execute([:oban, :job, :exception], %{}, %{ + job: job, + kind: :error, + reason: reason, + stacktrace: [] + }) + end + + defp build_job(args \\ %{"id" => "123"}) do + args + |> MyWorker.new() + |> Ecto.Changeset.apply_action!(:validate) + end + + defp reported_exception_values do + for event <- SentryTest.pop_sentry_reports(), + exception <- event.exception, + do: exception.value + end + defp emit_telemetry_for_failed_job( kind, reason, diff --git a/test_integrations/phoenix_app/test/phoenix_app/oban_test.exs b/test_integrations/phoenix_app/test/phoenix_app/oban_test.exs index 7ac41c55..5044e453 100644 --- a/test_integrations/phoenix_app/test/phoenix_app/oban_test.exs +++ b/test_integrations/phoenix_app/test/phoenix_app/oban_test.exs @@ -274,7 +274,7 @@ defmodule Sentry.Integrations.Phoenix.ObanTest do Oban.drain_queue(queue: :default) end) - assert log =~ "should_report_error_callback failed" + assert log =~ ":should_report_error_callback callback failed" assert log =~ "FailingWorker" assert log =~ "callback crashed!"