fix(tracing): report spans that outlive their sent parent

lib/sentry/opentelemetry/span_processor.ex

@@ -36,26 +36,39 @@ if Sentry.OpenTelemetry.VersionChecker.tracing_compatible?() do
     end
 
     defp process_span(span_record) do
-      transaction_root? =
-        cond do
-          # No parent = definitely a root
-          span_record.parent_span_id == nil ->
-            true
-
-          # Has a parent - check if it's local or remote
-          has_local_parent_span?(span_record.parent_span_id) ->
-            # Parent exists locally - this is a child span, not a transaction root
-            false
-
-          true ->
-            # Parent is remote (distributed tracing) - treat server spans as transaction roots
-            server_span?(span_record)
-        end
-
-      if transaction_root? do
-        build_and_send_transaction(span_record)
-      else
-        true
+      cond do
+        # Already reported as part of its parent's transaction (it finished
+        # while that transaction was being sent) - don't report it twice
+        SpanStorage.span_sent?(span_record.span_id) ->
+          true
+
+        # No parent = definitely a root
+        span_record.parent_span_id == nil ->
+          build_and_send_transaction(span_record)
+
+        # 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)
+
+        # Parent exists locally - this is a child span, not a transaction root
+        has_local_parent_span?(span_record.parent_span_id) ->
+          true
+
+        # Parent is remote (distributed tracing) - treat server spans as
+        # transaction roots
+        server_span?(span_record) ->
+          build_and_send_transaction(span_record)
+
+        true ->
+          LoggerUtils.debug(fn ->
+            "Discarding span #{span_record.name} (#{span_record.span_id}): its parent " <>
+              "#{span_record.parent_span_id} is neither in span storage nor recently sent, " <>
+              "so there is no transaction to attach it to"
+          end)
+
+          true
       end
     end
 
@@ -86,9 +99,26 @@ if Sentry.OpenTelemetry.VersionChecker.tracing_compatible?() do
       Map.get(attributes, to_string(MessagingAttributes.messaging_system())) == :oban
     end
 
-    defp build_and_send_transaction(span_record) do
-      child_span_records = SpanStorage.get_child_spans(span_record.span_id)
-      transaction = build_transaction(span_record, child_span_records)
+    defp build_and_send_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.
+      child_span_records =
+        span_record.span_id
+        |> 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
+      # its parent as sent to be promoted. They record that the transaction
+      # 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)
 
       result =
         case Sentry.send_transaction(transaction) do
@@ -115,7 +145,7 @@ if Sentry.OpenTelemetry.VersionChecker.tracing_compatible?() do
       result
     end
 
-    defp build_transaction(root_span_record, child_span_records) do
+    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))
 
@@ -126,7 +156,7 @@ if Sentry.OpenTelemetry.VersionChecker.tracing_compatible?() do
         start_timestamp: root_span_record.start_time,
         timestamp: root_span_record.end_time,
         contexts: %{
-          trace: build_trace_context(root_span_record)
+          trace: build_trace_context(root_span_record, opts)
         },
         spans: child_spans
       })
@@ -141,17 +171,26 @@ if Sentry.OpenTelemetry.VersionChecker.tracing_compatible?() do
 
     defp transaction_name(span_record), do: span_record.name
 
-    defp build_trace_context(span_record) do
+    defp build_trace_context(span_record, opts) do
       {op, description} = get_op_description(span_record)
 
+      data = filter_attributes(span_record.attributes)
+
+      data =
+        if Keyword.get(opts, :parent_already_sent?, false) do
+          Map.put(data, "sentry.parent_span_already_sent", true)
+        else
+          data
+        end
+
       context = %{
         trace_id: span_record.trace_id,
         span_id: span_record.span_id,
         parent_span_id: span_record.parent_span_id,
         op: op,
         description: description,
         origin: span_record.origin,
-        data: filter_attributes(span_record.attributes)
+        data: data
       }
 
       # Add links if present (for root spans, links go in trace context)

lib/sentry/opentelemetry/span_storage.ex

@@ -11,6 +11,14 @@ if Sentry.OpenTelemetry.VersionChecker.tracing_compatible?() do
 
     @span_ttl 30 * 60
 
+    # Sent markers let spans that outlive their parent detect that the
+    # parent's transaction is already closed. One is written per span of every
+    # sent transaction, so they are far more numerous than the in-progress
+    # records kept under @span_ttl and are retained for a much shorter window.
+    # A span finishing after its parent's marker expired can no longer be
+    # attached to anything and is discarded with a debug log.
+    @sent_span_ttl 5 * 60
+
     @spec start_link(keyword()) :: GenServer.on_start()
     def start_link(opts) when is_list(opts) do
       name = Keyword.get(opts, :name, __MODULE__)
@@ -53,6 +61,26 @@ if Sentry.OpenTelemetry.VersionChecker.tracing_compatible?() do
       end
     end
 
+    @spec mark_span_sent(String.t(), keyword()) :: :ok
+    def mark_span_sent(span_id, opts \\ []), do: mark_spans_sent([span_id], opts)
+
+    @spec mark_spans_sent([String.t()], keyword()) :: :ok
+    def mark_spans_sent(span_ids, 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}))
+
+      :ok
+    end
+
+    @spec span_sent?(String.t(), keyword()) :: boolean()
+    def span_sent?(span_id, opts \\ []) do
+      table_name = Keyword.get(opts, :table_name, default_table_name())
+
+      :ets.member(table_name, {:sent_span, span_id})
+    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.
@@ -166,11 +194,16 @@ if Sentry.OpenTelemetry.VersionChecker.tracing_compatible?() do
     def remove_child_spans(parent_span_id, opts) do
       table_name = Keyword.get(opts, :table_name, default_table_name())
 
+      # Finished descendants at every depth were part of the sent
+      # transaction, so their records are removed. In-progress descendants
+      # are preserved so they can be reported once they finish.
       :ets.match_object(table_name, {{:child_span, parent_span_id, :_}, :_, :_})
       |> Enum.each(fn {key, span_data, _stored_at} ->
         if span_data.end_time != nil do
           :ets.delete(table_name, key)
         end
+
+        remove_child_spans(span_data.span_id, table_name: table_name)
       end)
 
       :ok
@@ -209,6 +242,14 @@ if Sentry.OpenTelemetry.VersionChecker.tracing_compatible?() do
       ]
 
       :ets.select_delete(table_name, child_match_spec)
+
+      sent_cutoff_time = now - @sent_span_ttl
+
+      sent_match_spec = [
+        {{{:sent_span, :_}, :"$1"}, [{:<, :"$1", sent_cutoff_time}], [true]}
+      ]
+
+      :ets.select_delete(table_name, sent_match_spec)
     end
 
     defp default_table_name do