From ddb2d3b96383df22a4a23f6de49e1641d597ca89 Mon Sep 17 00:00:00 2001 From: Derek Kraan Date: Fri, 18 Mar 2022 12:21:26 +0100 Subject: [PATCH] Only attempt to record an exception if there is an active span. (#37) There is an edge case, if you use `forward/4` and use Plug.ErrorHandler, then when an exception reaches the outer router, then Plug.send_resp will be called, triggering `[:phoenix, :endpoint, :stop]`, and the span will be gone by the time the outer router gets the exception. This causes this telemetry handler to crash and be detached. Sequence of events: - [:phoenix, :endpoint, :start] - [:phoenix, :router_dispatch, :exception] (inner router) - [:phoenix, :endpoint, :stop] - [:phoenix, :router_dispatch, :exception] (outer router) ** here there is no span, crashes --- .../lib/opentelemetry_phoenix.ex | 24 ++++++------ .../test/opentelemetry_phoenix_test.exs | 38 +++++++++++++++++++ 2 files changed, 51 insertions(+), 11 deletions(-) diff --git a/instrumentation/opentelemetry_phoenix/lib/opentelemetry_phoenix.ex b/instrumentation/opentelemetry_phoenix/lib/opentelemetry_phoenix.ex index 9027b55..ed8abdf 100644 --- a/instrumentation/opentelemetry_phoenix/lib/opentelemetry_phoenix.ex +++ b/instrumentation/opentelemetry_phoenix/lib/opentelemetry_phoenix.ex @@ -164,21 +164,23 @@ defmodule OpentelemetryPhoenix do %{kind: kind, reason: reason, stacktrace: stacktrace} = meta, _config ) do - ctx = OpentelemetryTelemetry.set_current_telemetry_span(@tracer_id, meta) + if OpenTelemetry.Span.is_recording(OpenTelemetry.Tracer.current_span_ctx()) do + ctx = OpentelemetryTelemetry.set_current_telemetry_span(@tracer_id, meta) - {[reason: reason], attrs} = - Reason.normalize(reason) - |> Keyword.split([:reason]) + {[reason: reason], attrs} = + Reason.normalize(reason) + |> Keyword.split([:reason]) - # try to normalize all errors to Elixir exceptions - exception = Exception.normalize(kind, reason, stacktrace) + # try to normalize all errors to Elixir exceptions + exception = Exception.normalize(kind, reason, stacktrace) - # record exception and mark the span as errored - Span.record_exception(ctx, exception, stacktrace, attrs) - Span.set_status(ctx, OpenTelemetry.status(:error, "")) + # record exception and mark the span as errored + Span.record_exception(ctx, exception, stacktrace, attrs) + Span.set_status(ctx, OpenTelemetry.status(:error, "")) - # do not close the span as endpoint stop will still be called with - # more info, including the status code, which is nil at this stage + # do not close the span as endpoint stop will still be called with + # more info, including the status code, which is nil at this stage + end end defp http_flavor({_adapter_name, meta}) do diff --git a/instrumentation/opentelemetry_phoenix/test/opentelemetry_phoenix_test.exs b/instrumentation/opentelemetry_phoenix/test/opentelemetry_phoenix_test.exs index 2742b52..526d360 100644 --- a/instrumentation/opentelemetry_phoenix/test/opentelemetry_phoenix_test.exs +++ b/instrumentation/opentelemetry_phoenix/test/opentelemetry_phoenix_test.exs @@ -167,6 +167,44 @@ defmodule OpentelemetryPhoenixTest do Map.keys(:otel_attributes.map(event_attributes)) end + test "records exceptions for nested Phoenix routers" do + OpentelemetryPhoenix.setup() + + :telemetry.execute( + [:phoenix, :endpoint, :start], + %{system_time: System.system_time()}, + Meta.endpoint_start(:exception) + ) + + :telemetry.execute( + [:phoenix, :router_dispatch, :start], + %{system_time: System.system_time()}, + Meta.router_dispatch_start(:exception) + ) + + :telemetry.execute( + [:phoenix, :router_dispatch, :exception], + %{duration: 222}, + Meta.router_dispatch_exception(:normal) + ) + + :telemetry.execute( + [:phoenix, :endpoint, :stop], + %{duration: 444}, + Meta.endpoint_stop(:exception) + ) + + :telemetry.execute( + [:phoenix, :router_dispatch, :exception], + %{duration: 222}, + Meta.router_dispatch_exception(:normal) + ) + + assert_receive {:span, _} + + assert [_ | _] = :telemetry.list_handlers([:phoenix, :router_dispatch, :exception]) + end + test "records exceptions for Phoenix web requests with plug wrappers" do OpentelemetryPhoenix.setup()