diff --git a/lib/sentry/client_report.ex b/lib/sentry/client_report.ex index 4552b010..2649f37b 100644 --- a/lib/sentry/client_report.ex +++ b/lib/sentry/client_report.ex @@ -27,7 +27,8 @@ defmodule Sentry.ClientReport do :insufficient_data, :backpressure, :send_error, - :internal_sdk_error + :internal_sdk_error, + :ignored ] @typedoc """ diff --git a/lib/sentry/config.ex b/lib/sentry/config.ex index 8a98e673..bd050e24 100644 --- a/lib/sentry/config.ex +++ b/lib/sentry/config.ex @@ -340,6 +340,24 @@ defmodule Sentry.Config do This value is also used to determine if tracing is enabled: if it's not `nil`, tracing is enabled. """ ], + traces_ignore_http_status_codes: [ + type: {:custom, __MODULE__, :__validate_traces_ignore_http_status_codes__, []}, + default: [404], + type_doc: "list of `t:integer/0` or `t:Range.t/0`", + doc: """ + HTTP statuses to keep out of tracing. An incoming request answered with one of these + is not reported as a transaction, and neither is any work that outlives it. Takes + status codes and ranges, like `[404, 500..599]`. + + Defaults to `[404]`, so *404 Not Found* requests are not traced. Set it to `[]` to + trace them again. + + Outgoing requests are not affected, and the trace is still propagated to the services + this one calls. + + *Available since 14.0.0*. + """ + ], included_environments: [ type: {:or, [{:in, [:all]}, {:list, {:or, [:atom, :string]}}]}, deprecated: "Use :dsn to control whether to send events to Sentry.", @@ -1084,6 +1102,9 @@ defmodule Sentry.Config do @spec traces_sampler() :: traces_sampler_function() | nil def traces_sampler, do: get(:traces_sampler) + @spec traces_ignore_http_status_codes() :: [integer() | Range.t()] + def traces_ignore_http_status_codes, do: fetch!(:traces_ignore_http_status_codes) + @spec finch_pool_opts() :: keyword() def finch_pool_opts, do: fetch!(:finch_pool_opts) @@ -1436,6 +1457,26 @@ defmodule Sentry.Config do "expected :traces_sampler to be nil, a function with arity 1, or a {module, function} tuple, got: #{inspect(other)}"} end + def __validate_traces_ignore_http_status_codes__(codes) when is_list(codes) do + case Enum.reject(codes, &valid_trace_status_code?/1) do + [] -> {:ok, codes} + [invalid | _rest] -> invalid_trace_status_code_error(invalid) + end + end + + def __validate_traces_ignore_http_status_codes__(other) do + invalid_trace_status_code_error(other) + end + + defp valid_trace_status_code?(%Range{}), do: true + defp valid_trace_status_code?(code) when is_integer(code), do: true + defp valid_trace_status_code?(_other), do: false + + defp invalid_trace_status_code_error(value) do + {:error, + "expected :traces_ignore_http_status_codes to be a list of status codes and ranges, got: #{inspect(value)}"} + end + def __validate_json_library__(nil) do {:error, "nil is not a valid value for the :json_library option"} end diff --git a/lib/sentry/opentelemetry/span_processor.ex b/lib/sentry/opentelemetry/span_processor.ex index c162e247..888ab31e 100644 --- a/lib/sentry/opentelemetry/span_processor.ex +++ b/lib/sentry/opentelemetry/span_processor.ex @@ -10,7 +10,7 @@ if Sentry.OpenTelemetry.VersionChecker.tracing_compatible?() do alias OpenTelemetry.SemConv.Incubating.URLAttributes, as: URLAttributes require OpenTelemetry.SemConv.Incubating.MessagingAttributes, as: MessagingAttributes - alias Sentry.{ClientError, LoggerUtils} + alias Sentry.{ClientError, ClientReport, Config, LoggerUtils} alias Sentry.{Transaction, OpenTelemetry.SpanStorage, OpenTelemetry.SpanRecord} alias Sentry.Interfaces.Span @@ -83,13 +83,16 @@ if Sentry.OpenTelemetry.VersionChecker.tracing_compatible?() do # No parent = definitely a root span_record.parent_span_id == nil -> - build_and_send_transaction(span_record) + finalize_transaction(span_record) + + SpanStorage.span_excluded?(span_record.parent_span_id) -> + finalize_transaction(span_record, parent_already_sent?: true, excluded?: true) # The parent's transaction was already sent, so this span cannot be # attached to it anymore - report it as a follow-up transaction of # the same trace instead SpanStorage.span_sent?(span_record.parent_span_id) -> - build_and_send_transaction(span_record, parent_already_sent?: true) + finalize_transaction(span_record, parent_already_sent?: true) # Parent exists locally - this is a child span, not a transaction root has_local_parent_span?(span_record.parent_span_id) -> @@ -103,12 +106,12 @@ if Sentry.OpenTelemetry.VersionChecker.tracing_compatible?() do # Compared to true explicitly because the field is :undefined for # parentless spans, which is truthy. span_record.parent_span_is_remote == true -> - build_and_send_transaction(span_record) + finalize_transaction(span_record) # Parent is remote (distributed tracing) - treat server spans as # transaction roots server_span?(span_record) -> - build_and_send_transaction(span_record) + finalize_transaction(span_record) true -> LoggerUtils.debug(fn -> @@ -148,7 +151,7 @@ if Sentry.OpenTelemetry.VersionChecker.tracing_compatible?() do Map.get(attributes, to_string(MessagingAttributes.messaging_system())) == :oban end - defp build_and_send_transaction(span_record, opts \\ []) do + defp finalize_transaction(span_record, opts \\ []) do # Children still running when the root ends are excluded from the # payload: a reported span must have an end timestamp. Their records # stay in storage until they finish. @@ -157,8 +160,6 @@ if Sentry.OpenTelemetry.VersionChecker.tracing_compatible?() do |> SpanStorage.get_child_spans() |> Enum.filter(& &1.end_time) - transaction = build_transaction(span_record, child_span_records, opts) - # Every span of the transaction gets a marker - late spans may continue # the trace from any of them, not just the root. Markers must precede # the send: a span ending while the send is in flight must already see @@ -166,30 +167,15 @@ if Sentry.OpenTelemetry.VersionChecker.tracing_compatible?() do # was finalized locally - not that delivery succeeded - since once the # records are removed below, later spans can never be attached to this # transaction either way. - sent_span_ids = [span_record.span_id | Enum.map(child_span_records, & &1.span_id)] - :ok = SpanStorage.mark_spans_sent(sent_span_ids) + finalized_span_ids = [span_record.span_id | Enum.map(child_span_records, & &1.span_id)] result = - case Sentry.send_transaction(transaction) do - {:ok, _id} -> - true - - :ignored -> - true - - :excluded -> - true - - {:error, %ClientError{reason: :rate_limited} = error} -> - LoggerUtils.debug(fn -> - "Failed to send transaction to Sentry: #{inspect(error)}" - end) - - {:error, :invalid_span} - - {:error, error} -> - LoggerUtils.log(fn -> "Failed to send transaction to Sentry: #{inspect(error)}" end) - {:error, :invalid_span} + if Keyword.get(opts, :excluded?, false) or ignored_response_status?(span_record) do + :ok = SpanStorage.mark_spans_excluded(finalized_span_ids) + discard_transaction(build_transaction(span_record, child_span_records, opts)) + else + :ok = SpanStorage.mark_spans_sent(finalized_span_ids) + send_transaction(build_transaction(span_record, child_span_records, opts)) end :ok = @@ -201,6 +187,53 @@ if Sentry.OpenTelemetry.VersionChecker.tracing_compatible?() do result end + # Only incoming requests are matched. An outgoing call can become a + # transaction root of its own when it outlives the request that made it, + # and the option is not meant to drop those. + defp ignored_response_status?(%{kind: :server, attributes: attributes}) do + case Map.get(attributes, to_string(HTTPAttributes.http_response_status_code())) do + status when is_integer(status) -> + Enum.any?(Config.traces_ignore_http_status_codes(), &status_matches?(&1, status)) + + _other -> + false + end + end + + defp ignored_response_status?(_span_record), do: false + + defp status_matches?(%Range{} = range, status), do: status in range + defp status_matches?(code, status), do: code == status + + defp discard_transaction(transaction) do + ClientReport.Sender.record_discarded_events(:ignored, [transaction]) + true + end + + defp send_transaction(transaction) do + case Sentry.send_transaction(transaction) do + {:ok, _id} -> + true + + :ignored -> + true + + :excluded -> + true + + {:error, %ClientError{reason: :rate_limited} = error} -> + LoggerUtils.debug(fn -> + "Failed to send transaction to Sentry: #{inspect(error)}" + end) + + {:error, :invalid_span} + + {:error, error} -> + LoggerUtils.log(fn -> "Failed to send transaction to Sentry: #{inspect(error)}" end) + {:error, :invalid_span} + end + end + defp build_transaction(root_span_record, child_span_records, opts) do root_span = build_span(root_span_record) child_spans = Enum.map(child_span_records, &build_span(&1)) diff --git a/lib/sentry/opentelemetry/span_storage.ex b/lib/sentry/opentelemetry/span_storage.ex index 4a313b39..a36e539c 100644 --- a/lib/sentry/opentelemetry/span_storage.ex +++ b/lib/sentry/opentelemetry/span_storage.ex @@ -63,10 +63,19 @@ if Sentry.OpenTelemetry.VersionChecker.tracing_compatible?() do @spec mark_spans_sent([String.t()], keyword()) :: :ok def mark_spans_sent(span_ids, opts \\ []) do + mark_spans(span_ids, :sent, opts) + end + + @spec mark_spans_excluded([String.t()], keyword()) :: :ok + def mark_spans_excluded(span_ids, opts \\ []) do + mark_spans(span_ids, :excluded, opts) + end + + defp mark_spans(span_ids, outcome, opts) do table_name = Keyword.get(opts, :table_name, default_table_name()) stored_at = System.system_time(:second) - :ets.insert(table_name, Enum.map(span_ids, &{{:sent_span, &1}, stored_at})) + :ets.insert(table_name, Enum.map(span_ids, &{{:sent_span, &1}, stored_at, outcome})) :ok end @@ -78,6 +87,16 @@ if Sentry.OpenTelemetry.VersionChecker.tracing_compatible?() do :ets.member(table_name, {:sent_span, span_id}) end + @spec span_excluded?(String.t(), keyword()) :: boolean() + def span_excluded?(span_id, opts \\ []) do + table_name = Keyword.get(opts, :table_name, default_table_name()) + + case :ets.lookup(table_name, {:sent_span, span_id}) do + [{{:sent_span, ^span_id}, _stored_at, :excluded}] -> true + _other -> false + end + end + @doc """ Retrieves a span by its ID, regardless of whether it's a root or child span. Returns nil if the span is not found. @@ -243,7 +262,7 @@ if Sentry.OpenTelemetry.VersionChecker.tracing_compatible?() do sent_cutoff_time = now - @sent_span_ttl sent_match_spec = [ - {{{:sent_span, :_}, :"$1"}, [{:<, :"$1", sent_cutoff_time}], [true]} + {{{:sent_span, :_}, :"$1", :_}, [{:<, :"$1", sent_cutoff_time}], [true]} ] :ets.select_delete(table_name, sent_match_spec) diff --git a/test/sentry/config_test.exs b/test/sentry/config_test.exs index 3a96f9f6..969c2419 100644 --- a/test/sentry/config_test.exs +++ b/test/sentry/config_test.exs @@ -83,6 +83,16 @@ defmodule Sentry.ConfigTest do end end + test ":traces_ignore_http_status_codes rejects anything that is not a status code or a range" do + assert_raise ArgumentError, + ~r/expected :traces_ignore_http_status_codes to be a list of status codes and ranges, got: "404"/, + fn -> Config.validate!(traces_ignore_http_status_codes: [404, "404"]) end + + assert_raise ArgumentError, + ~r/expected :traces_ignore_http_status_codes to be a list of status codes and ranges, got: 404/, + fn -> Config.validate!(traces_ignore_http_status_codes: 404) end + end + test ":logs is nil by default" do assert Config.validate!([])[:logs] == nil assert Config.validate!(logs: nil)[:logs] == nil diff --git a/test/sentry/opentelemetry/span_storage_test.exs b/test/sentry/opentelemetry/span_storage_test.exs index 6bfcd108..88aaa635 100644 --- a/test/sentry/opentelemetry/span_storage_test.exs +++ b/test/sentry/opentelemetry/span_storage_test.exs @@ -360,7 +360,7 @@ defmodule Sentry.OpenTelemetry.SpanStorageTest do @tag span_storage: true test "markers expire after their TTL", %{table_name: table_name, server_name: server_name} do old_time = System.system_time(:second) - 6 * 60 - :ets.insert(table_name, {{:sent_span, "old_marker"}, old_time}) + :ets.insert(table_name, {{:sent_span, "old_marker"}, old_time, :sent}) SpanStorage.mark_spans_sent(["fresh_marker"], table_name: table_name) diff --git a/test_integrations/phoenix_app/lib/phoenix_app_web/controllers/response_status_controller.ex b/test_integrations/phoenix_app/lib/phoenix_app_web/controllers/response_status_controller.ex new file mode 100644 index 00000000..af004383 --- /dev/null +++ b/test_integrations/phoenix_app/lib/phoenix_app_web/controllers/response_status_controller.ex @@ -0,0 +1,48 @@ +defmodule PhoenixAppWeb.ResponseStatusController do + use PhoenixAppWeb, :controller + + require OpenTelemetry.Tracer, as: Tracer + + alias OpenTelemetry.SemConv.Incubating.HTTPAttributes + + def show(conn, %{"status" => status} = params) do + start_upstream_call(params["test_process"], params["upstream_status"]) + + conn + |> put_status(String.to_integer(status)) + |> json(%{status: status}) + end + + defp start_upstream_call(nil, _upstream_status), do: :ok + + defp start_upstream_call(test_process, upstream_status) do + notify = String.to_existing_atom(test_process) + ctx = :otel_ctx.get_current() + + {:ok, _pid} = + Task.start(fn -> + token = :otel_ctx.attach(ctx) + + try do + Tracer.with_span "GET /upstream", %{ + kind: :client, + attributes: %{ + HTTPAttributes.http_response_status_code() => String.to_integer(upstream_status) + } + } do + send(notify, {:upstream_call, self()}) + + receive do + :finish_upstream_call -> :ok + end + end + + send(notify, :upstream_call_finished) + after + :otel_ctx.detach(token) + end + end) + + :ok + end +end diff --git a/test_integrations/phoenix_app/lib/phoenix_app_web/router.ex b/test_integrations/phoenix_app/lib/phoenix_app_web/router.ex index 977df461..0e4ba353 100644 --- a/test_integrations/phoenix_app/lib/phoenix_app_web/router.ex +++ b/test_integrations/phoenix_app/lib/phoenix_app_web/router.ex @@ -72,6 +72,7 @@ defmodule PhoenixAppWeb.Router do post "/function-clause-error-cleared", PageController, :function_clause_error_cleared post "/generic-clause-error", PageController, :generic_clause_error post "/checkout", PageController, :checkout + get "/responses/:status", ResponseStatusController, :show get "/api/data", PageController, :api_data post "/api/oban-job", PageController, :api_oban_job put "/sentry-test-config", TestConfigController, :update diff --git a/test_integrations/phoenix_app/test/phoenix_app/ignored_status_traces_test.exs b/test_integrations/phoenix_app/test/phoenix_app/ignored_status_traces_test.exs new file mode 100644 index 00000000..9807ff35 --- /dev/null +++ b/test_integrations/phoenix_app/test/phoenix_app/ignored_status_traces_test.exs @@ -0,0 +1,133 @@ +defmodule PhoenixApp.IgnoredStatusTracesTest do + use ExUnit.Case, async: false + + import Sentry.TestHelpers + + @port 4102 + @base_url "http://localhost:#{@port}" + + setup do + start_supervised!({Bandit, plug: PhoenixAppWeb.Endpoint, scheme: :http, port: @port}) + Sentry.Test.setup_sentry(collect_envelopes: true, traces_sample_rate: 1.0) + end + + test "a request answered with an ignored status is not traced", %{ref: ref} do + put_test_config(traces_ignore_http_status_codes: [410]) + + assert request("/responses/410") == 410 + assert request("/responses/200") == 200 + + assert traced_paths(ref) == ["/responses/200"] + end + + test "a request answered with 404 is not traced by default", %{ref: ref} do + assert request("/responses/404") == 404 + assert request("/responses/200") == 200 + + assert traced_paths(ref) == ["/responses/200"] + end + + test "a request answered with 404 is traced when no status is ignored", %{ref: ref} do + put_test_config(traces_ignore_http_status_codes: []) + + assert request("/responses/404") == 404 + + assert traced_paths(ref) == ["/responses/404"] + end + + test "a request answered with a status inside an ignored range is not traced", %{ref: ref} do + put_test_config(traces_ignore_http_status_codes: [500..599]) + + assert request("/responses/503") == 503 + assert request("/responses/404") == 404 + + assert traced_paths(ref) == ["/responses/404"] + end + + test "work outliving a request answered with an ignored status is not traced", %{ref: ref} do + put_test_config(traces_ignore_http_status_codes: [410]) + test_process = register_test_process() + + assert request("/responses/410?test_process=#{test_process}&upstream_status=200") == 410 + assert reported_transactions(ref) == [] + + finish_upstream_call() + + assert reported_transactions(ref) == [] + end + + test "an outgoing call answered with an ignored status outliving its request is traced", %{ + ref: ref + } do + put_test_config(traces_ignore_http_status_codes: [410]) + test_process = register_test_process() + + assert request("/responses/200?test_process=#{test_process}&upstream_status=410") == 200 + assert traced_paths(ref) == ["/responses/200"] + + finish_upstream_call() + + assert [upstream_tx] = reported_transactions(ref) + assert upstream_tx["transaction"] == "GET /upstream" + end + + test "a request answered with an ignored status is reported as discarded telemetry", %{ + ref: ref, + client_report_sender: sender + } do + put_test_config(traces_ignore_http_status_codes: [410]) + + assert request("/responses/410") == 410 + assert reported_transactions(ref) == [] + + assert discarded_outcomes(sender, ref, "ignored") == %{"transaction" => 1, "span" => 1} + end + + defp request(path) do + {:ok, {{_version, status, _reason}, _headers, _body}} = + :httpc.request(:get, {String.to_charlist(@base_url <> path), []}, [], []) + + status + end + + defp register_test_process do + name = :"ignored_status_traces_#{System.unique_integer([:positive])}" + Process.register(self(), name) + name + end + + defp finish_upstream_call do + assert_receive {:upstream_call, upstream_pid}, 1000 + send(upstream_pid, :finish_upstream_call) + assert_receive :upstream_call_finished, 1000 + end + + defp reported_transactions(ref) do + collect_sentry_transactions(ref, 100, timeout: 1000) + end + + defp traced_paths(ref) do + Enum.map(reported_transactions(ref), & &1["contexts"]["trace"]["data"]["url.path"]) + end + + defp discarded_outcomes(sender, ref, reason) do + :ok = Sentry.ClientReport.Sender.flush(sender) + + for outcome <- await_client_report(ref)["discarded_events"], + outcome["reason"] == reason, + into: %{}, + do: {outcome["category"], outcome["quantity"]} + end + + defp await_client_report(ref) do + receive do + {:bypass_envelope, ^ref, body} -> + case decode_envelope!(body) do + [{%{"type" => "client_report"}, client_report}] -> client_report + _other -> await_client_report(ref) + end + after + 2000 -> flunk("no client report envelope received") + end + end +end