Skip to content

Commit 028abc6

Browse files
authored
fix: make tracing shutdown best-effort on process exit (#3343)
1 parent 4c3de2d commit 028abc6

5 files changed

Lines changed: 294 additions & 12 deletions

File tree

src/agents/tracing/processors.py

Lines changed: 78 additions & 7 deletions
Original file line numberDiff line numberDiff line change
@@ -7,8 +7,9 @@
77
import random
88
import threading
99
import time
10+
from collections.abc import Callable
1011
from functools import cached_property
11-
from typing import Any
12+
from typing import Any, cast
1213

1314
import httpx
1415

@@ -103,6 +104,9 @@ def project(self):
103104
return self._project or os.environ.get("OPENAI_PROJECT_ID")
104105

105106
def export(self, items: list[Trace | Span[Any]]) -> None:
107+
self._export_with_deadline(items, deadline=None)
108+
109+
def _export_with_deadline(self, items: list[Trace | Span[Any]], deadline: float | None) -> None:
106110
if not items:
107111
return
108112

@@ -143,9 +147,23 @@ def export(self, items: list[Trace | Span[Any]]) -> None:
143147
attempt = 0
144148
delay = self.base_delay
145149
while True:
150+
request_timeout = self._timeout_for_deadline(deadline)
151+
if deadline is not None and request_timeout is None:
152+
logger.warning(
153+
"[non-fatal] Tracing: export deadline reached, giving up on this batch."
154+
)
155+
break
156+
146157
attempt += 1
147158
try:
148-
response = self._client.post(url=self.endpoint, headers=headers, json=payload)
159+
request_kwargs: dict[str, Any] = {
160+
"url": self.endpoint,
161+
"headers": headers,
162+
"json": payload,
163+
}
164+
if request_timeout is not None:
165+
request_kwargs["timeout"] = request_timeout
166+
response = self._client.post(**request_kwargs)
149167

150168
# If the response is successful, break out of the loop
151169
if response.status_code < 300:
@@ -178,9 +196,41 @@ def export(self, items: list[Trace | Span[Any]]) -> None:
178196

179197
# Exponential backoff + jitter
180198
sleep_time = delay + random.uniform(0, 0.1 * delay) # 10% jitter
181-
time.sleep(sleep_time)
199+
if not self._sleep_before_retry(sleep_time, deadline):
200+
break
182201
delay = min(delay * 2, self.max_delay)
183202

203+
def _timeout_for_deadline(self, deadline: float | None) -> httpx.Timeout | None:
204+
if deadline is None:
205+
return None
206+
207+
remaining = deadline - time.monotonic()
208+
if remaining <= 0:
209+
return None
210+
211+
connect_timeout = min(5.0, remaining)
212+
return httpx.Timeout(remaining, connect=connect_timeout)
213+
214+
def _sleep_before_retry(self, sleep_time: float, deadline: float | None) -> bool:
215+
if deadline is None:
216+
time.sleep(sleep_time)
217+
return True
218+
219+
remaining = deadline - time.monotonic()
220+
if remaining <= 0:
221+
logger.warning("[non-fatal] Tracing: export deadline reached before retry, giving up.")
222+
return False
223+
224+
if sleep_time >= remaining:
225+
time.sleep(remaining)
226+
logger.warning(
227+
"[non-fatal] Tracing: export deadline reached during retry backoff, giving up."
228+
)
229+
return False
230+
231+
time.sleep(sleep_time)
232+
return True
233+
184234
def _should_sanitize_for_openai_tracing_api(self) -> bool:
185235
return self.endpoint.rstrip("/") == self._OPENAI_TRACING_INGEST_ENDPOINT.rstrip("/")
186236

@@ -502,6 +552,7 @@ def __init__(
502552
self._worker_thread: threading.Thread | None = None
503553
self._thread_start_lock = threading.Lock()
504554
self._export_lock = threading.Lock()
555+
self._shutdown_deadline: float | None = None
505556

506557
def _ensure_thread_started(self) -> None:
507558
# Fast path without holding the lock
@@ -547,13 +598,19 @@ def shutdown(self, timeout: float | None = None):
547598
Called when the application stops. We signal our thread to stop, then join it.
548599
"""
549600
self._shutdown_event.set()
601+
deadline = None if timeout is None else time.monotonic() + timeout
602+
self._shutdown_deadline = deadline
550603

551604
# Only join if we ever started the background thread; otherwise flush synchronously.
552605
if self._worker_thread and self._worker_thread.is_alive():
553606
self._worker_thread.join(timeout=timeout)
607+
if self._worker_thread.is_alive():
608+
logger.warning(
609+
"[non-fatal] Tracing: shutdown timeout reached; dropping queued traces."
610+
)
554611
else:
555612
# No background thread: process any remaining items synchronously.
556-
self._export_batches(force=True)
613+
self._export_batches(force=True, deadline=deadline)
557614

558615
def force_flush(self):
559616
"""
@@ -576,14 +633,20 @@ def _run(self):
576633
time.sleep(0.2)
577634

578635
# Final drain after shutdown
579-
self._export_batches(force=True)
636+
self._export_batches(force=True, deadline=self._shutdown_deadline)
580637

581-
def _export_batches(self, force: bool = False):
638+
def _export_batches(self, force: bool = False, deadline: float | None = None):
582639
"""Drains the queue and exports in batches. If force=True, export everything.
583640
Otherwise, export up to `max_batch_size` repeatedly until the queue is completely empty.
584641
"""
585642
with self._export_lock:
586643
while True:
644+
if deadline is not None and time.monotonic() >= deadline:
645+
logger.warning(
646+
"[non-fatal] Tracing: export deadline reached; dropping queued traces."
647+
)
648+
break
649+
587650
items_to_export: list[Span[Any] | Trace] = []
588651

589652
# Gather a batch of spans up to max_batch_size
@@ -604,7 +667,15 @@ def _export_batches(self, force: bool = False):
604667
# cannot kill the background worker thread and silently strand all
605668
# subsequent spans in the queue.
606669
try:
607-
self._exporter.export(items_to_export)
670+
export_with_deadline = getattr(self._exporter, "_export_with_deadline", None)
671+
if deadline is not None and callable(export_with_deadline):
672+
export_fn = cast(
673+
Callable[[list[Trace | Span[Any]], float | None], None],
674+
export_with_deadline,
675+
)
676+
export_fn(items_to_export, deadline)
677+
else:
678+
self._exporter.export(items_to_export)
608679
except Exception as exc:
609680
logger.error(
610681
"[non-fatal] Tracing: exporter raised %s; dropping batch of %d items",

src/agents/tracing/provider.py

Lines changed: 35 additions & 5 deletions
Original file line numberDiff line numberDiff line change
@@ -3,10 +3,12 @@
33
import logging
44
import os
55
import threading
6+
import time
67
import uuid
78
from abc import ABC, abstractmethod
89
from datetime import datetime, timezone
9-
from typing import Any
10+
from inspect import Parameter, signature
11+
from typing import Any, cast
1012

1113
from ..logger import logger
1214
from .config import TracingConfig
@@ -41,6 +43,24 @@ def _has_closed_stream_handler(log: logging.Logger) -> bool:
4143
return
4244

4345

46+
def _remaining_timeout(deadline: float | None) -> float | None:
47+
if deadline is None:
48+
return None
49+
return max(0.0, deadline - time.monotonic())
50+
51+
52+
def _supports_shutdown_timeout(processor: TracingProcessor) -> bool:
53+
try:
54+
parameters = signature(processor.shutdown).parameters
55+
except (TypeError, ValueError):
56+
return False
57+
58+
for parameter in parameters.values():
59+
if parameter.kind == Parameter.VAR_KEYWORD:
60+
return True
61+
return "timeout" in parameters
62+
63+
4464
def _is_noop_id(value: str | None) -> bool:
4565
return value == "no-op"
4666

@@ -119,14 +139,24 @@ def on_span_end(self, span: Span[Any]) -> None:
119139
except Exception as e:
120140
logger.error(f"Error in trace processor {processor} during on_span_end: {e}")
121141

122-
def shutdown(self) -> None:
142+
def shutdown(self, timeout: float | None = None) -> None:
123143
"""
124144
Called when the application stops.
125145
"""
146+
deadline = None if timeout is None else time.monotonic() + timeout
126147
for processor in self._processors:
127148
_safe_debug(f"Shutting down trace processor {processor}")
128149
try:
129-
processor.shutdown()
150+
processor_timeout = _remaining_timeout(deadline)
151+
if processor_timeout is not None and processor_timeout <= 0:
152+
logger.warning(
153+
"[non-fatal] Tracing: shutdown timeout reached before processor cleanup."
154+
)
155+
return
156+
if processor_timeout is not None and _supports_shutdown_timeout(processor):
157+
cast(Any, processor.shutdown)(timeout=processor_timeout)
158+
else:
159+
processor.shutdown()
130160
except Exception as e:
131161
logger.error(f"Error shutting down trace processor {processor}: {e}")
132162

@@ -405,13 +435,13 @@ def force_flush(self) -> None:
405435
except Exception as e:
406436
logger.error(f"Error flushing trace provider: {e}")
407437

408-
def shutdown(self) -> None:
438+
def shutdown(self, timeout: float | None = None) -> None:
409439
self._refresh_disabled_flag()
410440
if self._disabled:
411441
return
412442

413443
try:
414444
_safe_debug("Shutting down trace provider")
415-
self._multi_processor.shutdown()
445+
self._multi_processor.shutdown(timeout=timeout)
416446
except Exception as e:
417447
logger.error(f"Error shutting down trace provider: {e}")

src/agents/tracing/setup.py

Lines changed: 6 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -7,6 +7,7 @@
77
if TYPE_CHECKING:
88
from .provider import TraceProvider
99

10+
_DEFAULT_SHUTDOWN_TIMEOUT = 5.0
1011
GLOBAL_TRACE_PROVIDER: TraceProvider | None = None
1112
_GLOBAL_TRACE_PROVIDER_LOCK = threading.Lock()
1213
_SHUTDOWN_HANDLER_REGISTERED = False
@@ -15,6 +16,11 @@
1516
def _shutdown_global_trace_provider() -> None:
1617
provider = GLOBAL_TRACE_PROVIDER
1718
if provider is not None:
19+
from .provider import DefaultTraceProvider
20+
21+
if isinstance(provider, DefaultTraceProvider):
22+
provider.shutdown(timeout=_DEFAULT_SHUTDOWN_TIMEOUT)
23+
return
1824
provider.shutdown()
1925

2026

0 commit comments

Comments
 (0)