fix(tracing): avoid raising index errors on partial flushes (#15409)

## Description

Fixes an `IndexError` in `SpanAggregator.on_span_finish()` when partial
flush is enabled. The error occurred when `num_finished >=
partial_flush_min_spans` but `remove_finished()` returned an empty list
due to counter inconsistency.

Fix:
- Add defensive check before accessing `finished[0]`
- Prevents partial flushing min spans from being set to a value less
than zero


## Risks

Low. Minimal change maintains O(1) performance for counting finished
spans. Partial flush behavior unchanged when spans are available.

---------

Co-authored-by: Brett Langdon <[email protected]>

Author: mabdinur

ddtrace/_trace/processor/__init__.py

@@ -378,7 +378,11 @@ def on_span_finish(self, span: Span) -> None:
             elif self.partial_flush_enabled and num_finished >= self.partial_flush_min_spans:
                 should_partial_flush = True
                 finished = trace.remove_finished()
-                finished[0].set_metric("_dd.py.partial_flush", num_finished)
+                if finished:
+                    finished[0].set_metric("_dd.py.partial_flush", num_finished)
+                else:
+                    # num_finished was out of sync with the actual finished spans, skip partial flush
+                    return
             else:
                 return
 
@@ -446,17 +450,16 @@ def shutdown(self, timeout: Optional[float]) -> None:
         self._queue_span_count_metrics("spans_finished", "integration_name", 1)
         # Log a warning if the tracer is shutdown before spans are finished
         if log.isEnabledFor(logging.WARNING):
-            unfinished_spans = [
+            unsent_spans = [
                 f"trace_id={s.trace_id} parent_id={s.parent_id} span_id={s.span_id} name={s.name} resource={s.resource} started={s.start} sampling_priority={s.context.sampling_priority}"  # noqa: E501
                 for t in self._traces.values()
                 for s in t.spans
-                if not s.finished
             ]
-            if unfinished_spans:
+            if unsent_spans:
                 log.warning(
-                    "Shutting down tracer with %d unfinished spans. Unfinished spans will not be sent to Datadog: %s",
-                    len(unfinished_spans),
-                    ", ".join(unfinished_spans),
+                    "Shutting down tracer with %d spans. These spans will not be sent to Datadog: %s",
+                    len(unsent_spans),
+                    ", ".join(unsent_spans),
                 )
 
         try:

ddtrace/internal/settings/_config.py

@@ -446,7 +446,12 @@ def __init__(self):
                 self._trace_rate_limit,
             )
         self._partial_flush_enabled = _get_config("DD_TRACE_PARTIAL_FLUSH_ENABLED", True, asbool)
-        self._partial_flush_min_spans = _get_config("DD_TRACE_PARTIAL_FLUSH_MIN_SPANS", 300, int)
+        partial_flush_min_spans = _get_config("DD_TRACE_PARTIAL_FLUSH_MIN_SPANS", 300, int)
+        if partial_flush_min_spans < 1:
+            log.warning("DD_TRACE_PARTIAL_FLUSH_MIN_SPANS must be >= 1, defaulting to 1")
+            self._partial_flush_min_spans = 1
+        else:
+            self._partial_flush_min_spans = partial_flush_min_spans
 
         self._http = HttpConfig(header_tags=self._trace_http_header_tags)
         self._remote_config_enabled = _get_config("DD_REMOTE_CONFIGURATION_ENABLED", True, asbool)

releasenotes/notes/fix-partial-flush-indexerror-empty-list.yaml

@@ -0,0 +1,6 @@
+---
+fixes:
+  - |
+    tracing: Fixed a potential ``IndexError`` in partial flush when the finished span counter was out of sync with actual finished spans.
+  - |
+    tracing: ``DD_TRACE_PARTIAL_FLUSH_MIN_SPANS`` values less than 1 now default to 1 with a warning.

tests/integration/test_integration_snapshots.py

@@ -352,3 +352,22 @@ def test_encode_span_with_large_unicode_string_attributes(encoding):
     with override_global_config(dict(_trace_api=encoding)):
         with tracer.trace(name="á" * 25000, resource="â" * 25001) as span:
             span.set_tag(key="å" * 25001, value="ä" * 2000)
+
+
+@pytest.mark.snapshot
+@pytest.mark.subprocess(env={"DD_TRACE_PARTIAL_FLUSH_ENABLED": "true", "DD_TRACE_PARTIAL_FLUSH_MIN_SPANS": "1"})
+def test_aggregator_partial_flush_finished_counter_out_of_sync():
+    """Regression test for IndexError when num_finished counter is out of sync with finished spans."""
+    from ddtrace import tracer
+
+    span1 = tracer.start_span("span1")
+    span2 = tracer.start_span("span2", child_of=span1)
+    # Manually set duration_ns before calling finish() to trigger the race condition
+    # where trace.num_finished == 1 but len(trace.spans) == 0 after span1.finish().
+    # In this scenario, span1.finish() does NOT trigger encoding, both span1 and span2
+    # are encoded during span2.finish(). This occurs because _Trace.remove_finished()
+    # removes all spans that have a duration (end state). This test ensures that calling
+    # span1.finish() in this state does not cause unexpected behavior or crash trace encoding.
+    span1.duration_ns = 1
+    span2.finish()
+    span1.finish()

tests/snapshots/tests.integration.test_integration_snapshots.test_aggregator_partial_flush_finished_counter_out_of_sync.json

@@ -0,0 +1,37 @@
+[[
+  {
+    "name": "span1",
+    "service": "ddtrace_subprocess_dir",
+    "resource": "span1",
+    "trace_id": 0,
+    "span_id": 1,
+    "parent_id": 0,
+    "type": "",
+    "error": 0,
+    "meta": {
+      "_dd.p.dm": "-0",
+      "_dd.p.tid": "692a0cfd00000000",
+      "language": "python",
+      "runtime-id": "48593bb50c174935bfdd35e973b6247b"
+    },
+    "metrics": {
+      "_dd.py.partial_flush": 1.0,
+      "_dd.tracer_kr": 1.0,
+      "_sampling_priority_v1": 1.0,
+      "process_id": 74422.0
+    },
+    "duration": 1,
+    "start": 1764363517274022000
+  },
+     {
+       "name": "span2",
+       "service": "ddtrace_subprocess_dir",
+       "resource": "span2",
+       "trace_id": 0,
+       "span_id": 2,
+       "parent_id": 1,
+       "type": "",
+       "error": 0,
+       "duration": 46000,
+       "start": 1764363517274097000
+     }]]

tests/tracer/test_processors.py

@@ -282,6 +282,17 @@ def test_aggregator_multi_span():
     assert writer.pop() == [parent, child]
 
 
+@pytest.mark.subprocess(
+    parametrize={"DD_TRACE_PARTIAL_FLUSH_MIN_SPANS": ["0", "-1", "-20"]},
+    err=b"DD_TRACE_PARTIAL_FLUSH_MIN_SPANS must be >= 1, defaulting to 1\n",
+)
+def test_config_partial_flush_min_spans_validation():
+    """Test that DD_TRACE_PARTIAL_FLUSH_MIN_SPANS < 1 defaults to 1 with warning."""
+    from ddtrace import config
+
+    assert config._partial_flush_min_spans == 1
+
+
 def test_aggregator_partial_flush_0_spans():
     writer = DummyWriter()
     aggr = SpanAggregator(partial_flush_enabled=True, partial_flush_min_spans=0)

tests/tracer/test_tracer.py

@@ -1042,8 +1042,8 @@ def test_enable():
 
 
 @pytest.mark.subprocess(
-    err=b"Shutting down tracer with 2 unfinished spans. "
-    b"Unfinished spans will not be sent to Datadog: "
+    err=b"Shutting down tracer with 2 spans. "
+    b"These spans will not be sent to Datadog: "
     b"trace_id=123 parent_id=0 span_id=456 name=unfinished_span1 "
     b"resource=my_resource1 started=46121775360.0 sampling_priority=2, "
     b"trace_id=123 parent_id=456 span_id=666 name=unfinished_span2 "