diff --git a/lib/sentry.ex b/lib/sentry.ex index 7824c5cf..3b5e3d76 100644 --- a/lib/sentry.ex +++ b/lib/sentry.ex @@ -155,11 +155,11 @@ defmodule Sentry do ## Crashing Callbacks - If a `:before_send`, `:after_send_event`, `:filter`, `:before_send_log`, or - `:before_send_metric` 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. + 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. The item being handled is then dropped: @@ -178,6 +178,12 @@ defmodule Sentry do return value is ignored, so a crash there changes nothing the caller sees: the send result is still the one the transport produced. + A `:traces_sampler` callback that crashes does not drop the trace outright. Sampling + falls back to the configured `:traces_sample_rate`, so the trace is kept or dropped at + the rate you configured. If `:traces_sample_rate` is not configured either, the trace is + dropped and the child spans of that trace inherit that decision instead of calling the + failing sampler again. + ## 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 5b264ef2..76b8f3d7 100644 --- a/lib/sentry/callback.ex +++ b/lib/sentry/callback.ex @@ -47,6 +47,23 @@ defmodule Sentry.Callback do end end + @spec validate(atom(), value, (value -> as_boolean(term())), String.t()) :: + {:ok, value} | :invalid + when value: var + def validate(name, value, validator, expected) + when is_atom(name) and is_function(validator, 1) and is_binary(expected) do + if validator.(value) do + {:ok, value} + else + LoggerUtils.warning( + "#{inspect(name)} callback returned an invalid value: " <> + "expected #{expected}, got: #{inspect(value)}" + ) + + :invalid + end + end + defp record_discard(nil), do: :ok defp record_discard({reason, event_or_data_category}) do diff --git a/lib/sentry/config.ex b/lib/sentry/config.ex index 88201b23..1ad5bee1 100644 --- a/lib/sentry/config.ex +++ b/lib/sentry/config.ex @@ -326,6 +326,15 @@ defmodule Sentry.Config do If both `:traces_sampler` and `:traces_sample_rate` are configured, `:traces_sampler` takes precedence. + If the callback crashes, the failure is logged at the `:error` level and sampling falls back + to `:traces_sample_rate`. When `:traces_sample_rate` is not configured either, the trace is + dropped and its child spans inherit that decision. See the + [*Crashing Callbacks*](#module-crashing-callbacks) section below for more information. + + If the callback returns successfully but the returned value is not a boolean or a float + between `0.0` and `1.0`, the invalid sample rate is logged at the `:warning` level and the + trace is dropped. + Example: ```elixir traces_sampler: fn sampling_context -> diff --git a/lib/sentry/opentelemetry/sampler.ex b/lib/sentry/opentelemetry/sampler.ex index 4cc9c24a..161c82ee 100644 --- a/lib/sentry/opentelemetry/sampler.ex +++ b/lib/sentry/opentelemetry/sampler.ex @@ -3,11 +3,10 @@ if Sentry.OpenTelemetry.VersionChecker.tracing_compatible?() do @moduledoc false alias OpenTelemetry.{Span, Tracer} + alias Sentry.Callback alias Sentry.ClientReport alias SamplingContext - alias Sentry.LoggerUtils - @behaviour :otel_sampler @sentry_sample_rate_key "sentry-sample_rate" @@ -34,9 +33,9 @@ if Sentry.OpenTelemetry.VersionChecker.tracing_compatible?() do attributes, config ) do - result = + {result, discard_reason} = if config[:drop] && span_name in config[:drop] do - {:drop, [], []} + {{:drop, [], []}, :sample_rate} else traces_sampler = Sentry.Config.traces_sampler() traces_sample_rate = Sentry.Config.traces_sample_rate() @@ -44,23 +43,23 @@ if Sentry.OpenTelemetry.VersionChecker.tracing_compatible?() do case get_trace_sampling_decision(ctx) do {:inherit, trace_sampled, tracestate} -> decision = if trace_sampled, do: :record_and_sample, else: :drop - {decision, [], tracestate} + {{decision, [], tracestate}, :sample_rate} :no_trace -> if traces_sampler do sampling_context = build_sampling_context(nil, span_name, span_kind, attributes, trace_id) - make_sampler_decision(traces_sampler, sampling_context) + make_sampler_decision(traces_sampler, sampling_context, traces_sample_rate) else - make_sampling_decision(traces_sample_rate) + {make_sampling_decision(traces_sample_rate), :sample_rate} end end end case result do {:drop, _, _} -> - record_discarded_transaction() + record_discarded_transaction(discard_reason) result _ -> @@ -147,48 +146,53 @@ if Sentry.OpenTelemetry.VersionChecker.tracing_compatible?() do sampling_context end - defp make_sampler_decision(traces_sampler, sampling_context) do - try do - result = call_traces_sampler(traces_sampler, sampling_context) - sample_rate = normalize_sampler_result(result) - - if is_float(sample_rate) and sample_rate >= 0.0 and sample_rate <= 1.0 do - make_sampling_decision(sample_rate) - else - LoggerUtils.warning( - "traces_sampler function returned an invalid sample rate: #{inspect(sample_rate)}" - ) - - make_sampling_decision(0.0) - end - rescue - error -> - LoggerUtils.warning("traces_sampler function failed: #{inspect(error)}") - - make_sampling_decision(0.0) + defp make_sampler_decision(traces_sampler, sampling_context, fallback_sample_rate) do + invocation = Callback.to_fun(:traces_sampler, traces_sampler, [sampling_context]) + + case Callback.run(:traces_sampler, invocation) do + {:ok, result} -> + sample_rate = + case Callback.validate( + :traces_sampler, + normalize_sampler_result(result), + &valid_sample_rate?/1, + "a boolean or a float between 0.0 and 1.0" + ) do + {:ok, sample_rate} -> sample_rate + :invalid -> 0.0 + end + + {make_sampling_decision(sample_rate), :sample_rate} + + :failed -> + make_fallback_decision(fallback_sample_rate) end end - defp call_traces_sampler(fun, sampling_context) when is_function(fun, 1) do - fun.(sampling_context) + defp valid_sample_rate?(sample_rate) do + is_float(sample_rate) and sample_rate >= 0.0 and sample_rate <= 1.0 + end + + defp make_fallback_decision(nil) do + {{:drop, [], [{@sentry_sampled_key, "false"}]}, :callback_error} end - defp call_traces_sampler({module, function}, sampling_context) do - apply(module, function, [sampling_context]) + defp make_fallback_decision(fallback_sample_rate) do + {make_sampling_decision(fallback_sample_rate), :sample_rate} end defp normalize_sampler_result(true), do: 1.0 defp normalize_sampler_result(false), do: 0.0 defp normalize_sampler_result(rate), do: rate - defp record_discarded_transaction() do - ClientReport.Sender.record_discarded_events(:sample_rate, "transaction") + defp record_discarded_transaction(reason) do + ClientReport.Sender.record_discarded_events(reason, "transaction") # A dropped transaction also drops its spans. The sampling decision happens # before any child spans are recorded, so only the transaction itself is # extracted as a span (0 spans + 1). # https://develop.sentry.dev/sdk/telemetry/client-reports/#span-outcomes - ClientReport.Sender.record_discarded_events(:sample_rate, "span") + ClientReport.Sender.record_discarded_events(reason, "span") end end end diff --git a/test/sentry/opentelemetry/sampler_test.exs b/test/sentry/opentelemetry/sampler_test.exs index 4bf87205..af7f1879 100644 --- a/test/sentry/opentelemetry/sampler_test.exs +++ b/test/sentry/opentelemetry/sampler_test.exs @@ -452,8 +452,8 @@ defmodule Sentry.Opentelemetry.SamplerTest do Agent.stop(sampler_call_count) end - test "handles traces_sampler errors gracefully" do - put_test_config(traces_sampler: fn _ -> raise "sampler error" end) + test "drops the trace when traces_sampler raises and no sample rate is configured" do + put_test_config(traces_sample_rate: nil, traces_sampler: fn _ -> raise "sampler error" end) test_ctx = create_test_span_context() @@ -463,9 +463,119 @@ defmodule Sentry.Opentelemetry.SamplerTest do Sampler.should_sample(test_ctx, 123, nil, "test span", nil, %{}, drop: []) end) - assert log =~ "traces_sampler function failed" + assert log =~ ~r/domain=(\w+\.)*sentry \[error\]\s+:traces_sampler callback failed/ assert log =~ "sampler error" - assert log =~ ~r/domain=(\w+\.)*sentry/ + end + + test "child spans inherit the drop when traces_sampler fails and no sample rate is configured" do + {:ok, sampler_call_count} = Agent.start_link(fn -> 0 end) + + sampler_fun = fn _sampling_context -> + Agent.update(sampler_call_count, &(&1 + 1)) + raise "sampler error" + end + + put_test_config(traces_sample_rate: nil, traces_sampler: sampler_fun) + + capture_log(fn -> + assert {:drop, [], tracestate} = + Sampler.should_sample( + create_test_span_context(), + 123, + nil, + "root span", + nil, + %{}, + drop: [] + ) + + assert {"sentry-sampled", "false"} in tracestate + + existing_span_ctx = create_span_context_with_tracestate(123, tracestate) + ctx_with_span = :otel_tracer.set_current_span(:otel_ctx.new(), existing_span_ctx) + token = :otel_ctx.attach(ctx_with_span) + + try do + assert {:drop, [], ^tracestate} = + Sampler.should_sample(ctx_with_span, 123, nil, "child span", nil, %{}, + drop: [] + ) + after + :otel_ctx.detach(token) + end + end) + + assert Agent.get(sampler_call_count, & &1) == 1 + + Agent.stop(sampler_call_count) + end + + test "counts a drop caused by a failing traces_sampler as a callback error", + %{client_report_sender: sender} do + put_test_config(traces_sample_rate: nil, traces_sampler: fn _ -> raise "sampler error" end) + + capture_log(fn -> + assert {:drop, [], _tracestate} = + Sampler.should_sample( + create_test_span_context(), + 123, + nil, + "test span", + nil, + %{}, + drop: [] + ) + end) + + assert :sys.get_state(sender) == + %{{:callback_error, "transaction"} => 1, {:callback_error, "span"} => 1} + end + + test "counts a drop produced by the fallback sample rate as a sampling drop", + %{client_report_sender: sender} do + put_test_config(traces_sample_rate: 0.0, traces_sampler: fn _ -> raise "sampler error" end) + + capture_log(fn -> + assert {:drop, [], _tracestate} = + Sampler.should_sample( + create_test_span_context(), + 123, + nil, + "test span", + nil, + %{}, + drop: [] + ) + end) + + assert :sys.get_state(sender) == + %{{:sample_rate, "transaction"} => 1, {:sample_rate, "span"} => 1} + end + + test "falls back to the configured sample rate when traces_sampler throws" do + put_test_config(traces_sample_rate: 1.0, traces_sampler: fn _ -> throw(:boom) end) + + test_ctx = create_test_span_context() + + capture_log(fn -> + assert {:record_and_sample, [], tracestate} = + Sampler.should_sample(test_ctx, 123, nil, "test span", nil, %{}, drop: []) + + assert {"sentry-sampled", "true"} in tracestate + end) + end + + test "falls back to the configured sample rate when traces_sampler exits" do + put_test_config(traces_sample_rate: 1.0, traces_sampler: fn _ -> exit(:boom) end) + + test_ctx = create_test_span_context() + + capture_log(fn -> + assert {:record_and_sample, [], tracestate} = + Sampler.should_sample(test_ctx, 123, nil, "test span", nil, %{}, drop: []) + + assert {"sentry-sampled", "true"} in tracestate + end) end test "handles invalid traces_sampler return values gracefully" do @@ -495,7 +605,7 @@ defmodule Sentry.Opentelemetry.SamplerTest do end) end) - assert log =~ "traces_sampler function returned an invalid sample rate" + assert log =~ ":traces_sampler callback returned an invalid value" assert log =~ ~r/domain=(\w+\.)*sentry/ end