From 876a8aa66058fdea125bb76194eea3cc1ce5dc05 Mon Sep 17 00:00:00 2001 From: "Gabriele N. Tornetta" Date: Fri, 4 Oct 2024 11:43:52 +0100 Subject: [PATCH 1/9] chore(di): trigger probes We implement trigger probes. These allows triggering the capture of debug information along a trace, ensuring all the relevant probes are also triggered. --- ddtrace/_trace/context.py | 15 ++- ddtrace/contrib/trace_utils.py | 3 + ddtrace/debugging/_debugger.py | 11 +- ddtrace/debugging/_live.py | 22 ++++ ddtrace/debugging/_origin/span.py | 117 ++++++++++-------- ddtrace/debugging/_probe/model.py | 24 +++- ddtrace/debugging/_probe/remoteconfig.py | 34 +++-- ddtrace/debugging/_products/live_debugger.py | 31 +++++ ddtrace/debugging/_session.py | 65 ++++++++++ ddtrace/debugging/_signal/model.py | 8 +- ddtrace/debugging/_signal/snapshot.py | 1 + ddtrace/debugging/_uploader.py | 1 + ddtrace/settings/live_debugging.py | 16 +++ docs/configuration.rst | 6 + pyproject.toml | 1 + tests/debugging/live/__init__.py | 0 tests/debugging/live/test_live_debugger.py | 69 +++++++++++ tests/debugging/mocking.py | 10 ++ tests/debugging/origin/test_span.py | 53 +++++++- .../test_debugger_span_decoration.py | 6 +- tests/debugging/utils.py | 19 +++ tests/submod/traced_stuff.py | 22 ++++ 22 files changed, 467 insertions(+), 67 deletions(-) create mode 100644 ddtrace/debugging/_live.py create mode 100644 ddtrace/debugging/_products/live_debugger.py create mode 100644 ddtrace/debugging/_session.py create mode 100644 ddtrace/settings/live_debugging.py create mode 100644 tests/debugging/live/__init__.py create mode 100644 tests/debugging/live/test_live_debugger.py diff --git a/ddtrace/_trace/context.py b/ddtrace/_trace/context.py index 07bc3960b56..065da866006 100644 --- a/ddtrace/_trace/context.py +++ b/ddtrace/_trace/context.py @@ -48,7 +48,17 @@ class Context(object): boundaries. """ - __slots__ = ["trace_id", "span_id", "_lock", "_meta", "_metrics", "_span_links", "_baggage", "_is_remote"] + __slots__ = [ + "trace_id", + "span_id", + "_lock", + "_meta", + "_metrics", + "_span_links", + "_baggage", + "_is_remote", + "__weakref__", + ] def __init__( self, @@ -279,4 +289,7 @@ def __repr__(self) -> str: self._is_remote, ) + def __hash__(self) -> int: + return hash((self.trace_id, self.span_id)) + __str__ = __repr__ diff --git a/ddtrace/contrib/trace_utils.py b/ddtrace/contrib/trace_utils.py index f0ff816ed43..48f96a084d4 100644 --- a/ddtrace/contrib/trace_utils.py +++ b/ddtrace/contrib/trace_utils.py @@ -28,6 +28,7 @@ from ddtrace.internal.compat import ensure_text from ddtrace.internal.compat import ip_is_global from ddtrace.internal.compat import parse +from ddtrace.internal.core.event_hub import dispatch from ddtrace.internal.logger import get_logger from ddtrace.internal.utils.cache import cached from ddtrace.internal.utils.http import normalize_header_name @@ -578,6 +579,8 @@ def activate_distributed_headers(tracer, int_config=None, request_headers=None, # have a context with the same trace id active tracer.context_provider.activate(context) + dispatch("distributed_context.activated", (context,)) + def _flatten( obj, # type: Any diff --git a/ddtrace/debugging/_debugger.py b/ddtrace/debugging/_debugger.py index 4c2369d6f42..7ccddf1b392 100644 --- a/ddtrace/debugging/_debugger.py +++ b/ddtrace/debugging/_debugger.py @@ -36,14 +36,17 @@ from ddtrace.debugging._probe.model import MetricFunctionProbe from ddtrace.debugging._probe.model import MetricLineProbe from ddtrace.debugging._probe.model import Probe +from ddtrace.debugging._probe.model import ProbeEvaluateTimingForMethod from ddtrace.debugging._probe.model import SpanDecorationFunctionProbe from ddtrace.debugging._probe.model import SpanDecorationLineProbe from ddtrace.debugging._probe.model import SpanFunctionProbe +from ddtrace.debugging._probe.model import TriggerFunctionProbe from ddtrace.debugging._probe.registry import ProbeRegistry from ddtrace.debugging._probe.remoteconfig import ProbePollerEvent from ddtrace.debugging._probe.remoteconfig import ProbePollerEventType from ddtrace.debugging._probe.remoteconfig import ProbeRCAdapter from ddtrace.debugging._probe.status import ProbeStatusLogger +from ddtrace.debugging._session import Session from ddtrace.debugging._signal.collector import SignalCollector from ddtrace.debugging._signal.metric_sample import MetricSample from ddtrace.debugging._signal.model import Signal @@ -220,6 +223,10 @@ def _open_signals(self) -> None: frame=frame, thread=thread, ) + elif isinstance(probe, TriggerFunctionProbe) and probe.evaluate_at is ProbeEvaluateTimingForMethod.ENTER: + Session(probe.session_id, probe.level).link_to_trace(trace_context) + # This probe does not emit any signals + continue else: log.error("Unsupported probe type: %s", type(probe)) continue @@ -400,7 +407,9 @@ def _dd_debugger_hook(self, probe: Probe) -> None: meter=self._probe_meter, ) elif isinstance(probe, LogLineProbe): - if probe.take_snapshot: + session_id = probe.tags.get("sessionId") + session = Session.lookup(session_id) if session_id is not None else None + if session is None and probe.take_snapshot: # TODO: Global limit evaluated before probe conditions if self._global_rate_limiter.limit() is RateLimitExceeded: return diff --git a/ddtrace/debugging/_live.py b/ddtrace/debugging/_live.py new file mode 100644 index 00000000000..6022b7c3348 --- /dev/null +++ b/ddtrace/debugging/_live.py @@ -0,0 +1,22 @@ +import typing as t + +from ddtrace.debugging._session import Session +from ddtrace.internal import core + + +def handle_distributed_context(context: t.Any) -> None: + debug_tag = context._meta.get("_dd.p.debug") + if debug_tag is None: + return + + for session in debug_tag.split(","): + ident, _, level = session.partition(":") + Session(ident=ident, level=int(level or 0)).link_to_trace(context) + + +def enable() -> None: + core.on("distributed_context.activated", handle_distributed_context, "live_debugger") + + +def disable() -> None: + core.reset_listeners("distributed_context.activated", handle_distributed_context) diff --git a/ddtrace/debugging/_origin/span.py b/ddtrace/debugging/_origin/span.py index 9f0433cbca0..abaa35f2292 100644 --- a/ddtrace/debugging/_origin/span.py +++ b/ddtrace/debugging/_origin/span.py @@ -1,28 +1,26 @@ from dataclasses import dataclass +from functools import partial from itertools import count from pathlib import Path import sys - -# from threading import current_thread +from threading import current_thread from types import FrameType from types import FunctionType import typing as t import uuid import ddtrace - -# from ddtrace import config from ddtrace._trace.processor import SpanProcessor - -# from ddtrace.debugging._debugger import Debugger from ddtrace.debugging._probe.model import DEFAULT_CAPTURE_LIMITS from ddtrace.debugging._probe.model import LiteralTemplateSegment from ddtrace.debugging._probe.model import LogFunctionProbe from ddtrace.debugging._probe.model import LogLineProbe from ddtrace.debugging._probe.model import ProbeEvalTiming - -# from ddtrace.debugging._signal.snapshot import Snapshot -from ddtrace.debugging._signal.model import Signal +from ddtrace.debugging._session import Session +from ddtrace.debugging._signal.collector import SignalCollector +from ddtrace.debugging._signal.snapshot import Snapshot +from ddtrace.debugging._uploader import LogsIntakeUploaderV1 +from ddtrace.debugging._uploader import UploaderProduct from ddtrace.ext import EXIT_SPAN_TYPES from ddtrace.internal import compat from ddtrace.internal import core @@ -40,13 +38,13 @@ def frame_stack(frame: FrameType) -> t.Iterator[FrameType]: _frame = _frame.f_back -def wrap_entrypoint(f: t.Callable) -> None: +def wrap_entrypoint(collector: SignalCollector, f: t.Callable) -> None: if not _isinstance(f, FunctionType): return _f = t.cast(FunctionType, f) if not EntrySpanWrappingContext.is_wrapped(_f): - EntrySpanWrappingContext(_f).wrap() + EntrySpanWrappingContext(collector, _f).wrap() @dataclass @@ -120,9 +118,11 @@ class EntrySpanLocation: class EntrySpanWrappingContext(WrappingContext): - def __init__(self, f): + def __init__(self, collector: SignalCollector, f: FunctionType) -> None: super().__init__(f) + self.collector = collector + filename = str(Path(f.__code__.co_filename).resolve()) name = f.__qualname__ module = f.__module__ @@ -152,36 +152,37 @@ def __enter__(self): s.set_tag_str("_dd.code_origin.frames.0.type", location.module) s.set_tag_str("_dd.code_origin.frames.0.method", location.name) - # TODO[gab]: This will be enabled as part of the live debugger/distributed debugging - # if ld_config.enabled: - # # Create a snapshot - # snapshot = Snapshot( - # probe=location.probe, - # frame=self.__frame__, - # thread=current_thread(), - # trace_context=root, - # ) + # Check if we have any level 2 debugging sessions running for the + # current trace + if any(s.level >= 2 for s in Session.from_trace()): + # Create a snapshot + snapshot = Snapshot( + probe=location.probe, + frame=self.__frame__, + thread=current_thread(), + trace_context=root, + ) - # # Capture on entry - # context = Debugger.get_collector().attach(snapshot) + # Capture on entry + snapshot.do_enter() - # # Correlate the snapshot with the span - # root.set_tag_str("_dd.code_origin.frames.0.snapshot_id", snapshot.uuid) - # span.set_tag_str("_dd.code_origin.frames.0.snapshot_id", snapshot.uuid) + # Correlate the snapshot with the span + root.set_tag_str("_dd.code_origin.frames.0.snapshot_id", snapshot.uuid) + span.set_tag_str("_dd.code_origin.frames.0.snapshot_id", snapshot.uuid) - # self.set("context", context) - # self.set("start_time", compat.monotonic_ns()) + self.set("snapshot", snapshot) + self.set("start_time", compat.monotonic_ns()) return self def _close_signal(self, retval=None, exc_info=(None, None, None)): try: - signal: Signal = t.cast(Signal, self.get("signal")) + snapshot: Snapshot = t.cast(Snapshot, self.get("snapshot")) except KeyError: # No snapshot was created return - signal.do_exit(retval, exc_info, compat.monotonic_ns() - self.get("start_time")) + snapshot.do_exit(retval, exc_info, compat.monotonic_ns() - self.get("start_time")) def __return__(self, retval): self._close_signal(retval=retval) @@ -194,7 +195,10 @@ def __exit__(self, exc_type, exc_value, traceback): @dataclass class SpanCodeOriginProcessor(SpanProcessor): + __uploader__ = LogsIntakeUploaderV1 + _instance: t.Optional["SpanCodeOriginProcessor"] = None + _handler: t.Optional[t.Callable] = None def on_span_start(self, span: Span) -> None: if span.span_type not in EXIT_SPAN_TYPES: @@ -219,24 +223,25 @@ def on_span_start(self, span: Span) -> None: # DEV: Without a function object we cannot infer the function # and any potential class name. - # TODO[gab]: This will be enabled as part of the live debugger/distributed debugging - # if ld_config.enabled: - # # Create a snapshot - # snapshot = Snapshot( - # probe=ExitSpanProbe.from_frame(frame), - # frame=frame, - # thread=current_thread(), - # trace_context=span, - # ) + # Check if we have any level 2 debugging sessions running for + # the current trace + if any(s.level >= 2 for s in Session.from_trace()): + # Create a snapshot + snapshot = Snapshot( + probe=ExitSpanProbe.from_frame(frame), + frame=frame, + thread=current_thread(), + trace_context=span, + ) - # # Capture on entry - # snapshot.line() + # Capture on entry + snapshot.do_line() - # # Collect - # Debugger.get_collector().push(snapshot) + # Collect + self.__uploader__.get_collector().push(snapshot) - # # Correlate the snapshot with the span - # span.set_tag_str(f"_dd.code_origin.frames.{n}.snapshot_id", snapshot.uuid) + # Correlate the snapshot with the span + span.set_tag_str(f"_dd.code_origin.frames.{n}.snapshot_id", snapshot.uuid) def on_span_finish(self, span: Span) -> None: pass @@ -246,17 +251,31 @@ def enable(cls): if cls._instance is not None: return - core.on("service_entrypoint.patch", wrap_entrypoint) - instance = cls._instance = cls() + + # Register code origin for span with the snapshot uploader + cls.__uploader__.register(UploaderProduct.CODE_ORIGIN_SPAN) + + # Register the processor for exit spans instance.register() + # Register the entrypoint wrapping for entry spans + cls._handler = handler = partial(wrap_entrypoint, cls.__uploader__.get_collector()) + core.on("service_entrypoint.patch", handler) + @classmethod def disable(cls): if cls._instance is None: return + # Unregister the entrypoint wrapping for entry spans + core.reset_listeners("service_entrypoint.patch", cls._handler) + cls._handler = None + + # Unregister the processor for exit spans cls._instance.unregister() - cls._instance = None - core.reset_listeners("service_entrypoint.patch", wrap_entrypoint) + # Unregister code origin for span with the snapshot uploader + cls.__uploader__.unregister(UploaderProduct.CODE_ORIGIN_SPAN) + + cls._instance = None diff --git a/ddtrace/debugging/_probe/model.py b/ddtrace/debugging/_probe/model.py index 6f989d627f4..5a8c4a3309b 100644 --- a/ddtrace/debugging/_probe/model.py +++ b/ddtrace/debugging/_probe/model.py @@ -14,6 +14,7 @@ from typing import Union from ddtrace.debugging._expressions import DDExpression +from ddtrace.debugging._session import SessionId from ddtrace.internal.compat import maybe_stringify from ddtrace.internal.logger import get_logger from ddtrace.internal.module import _resolve @@ -296,8 +297,26 @@ class SpanDecorationFunctionProbe(Probe, FunctionLocationMixin, TimingMixin, Spa pass -LineProbe = Union[LogLineProbe, MetricLineProbe, SpanDecorationLineProbe] -FunctionProbe = Union[LogFunctionProbe, MetricFunctionProbe, SpanFunctionProbe, SpanDecorationFunctionProbe] +@dataclass +class SessionMixin: + session_id: SessionId + level: int + + +@dataclass +class TriggerLineProbe(Probe, LineLocationMixin, SessionMixin): + pass + + +@dataclass +class TriggerFunctionProbe(Probe, FunctionLocationMixin, SessionMixin): + pass + + +LineProbe = Union[LogLineProbe, MetricLineProbe, SpanDecorationLineProbe, TriggerLineProbe] +FunctionProbe = Union[ + LogFunctionProbe, MetricFunctionProbe, SpanFunctionProbe, SpanDecorationFunctionProbe, TriggerFunctionProbe +] class ProbeType(str, Enum): @@ -305,3 +324,4 @@ class ProbeType(str, Enum): METRIC_PROBE = "METRIC_PROBE" SPAN_PROBE = "SPAN_PROBE" SPAN_DECORATION_PROBE = "SPAN_DECORATION_PROBE" + TRIGGER_PROBE = "TRIGGER_PROBE" diff --git a/ddtrace/debugging/_probe/remoteconfig.py b/ddtrace/debugging/_probe/remoteconfig.py index b305e0fb5da..5831f3ba284 100644 --- a/ddtrace/debugging/_probe/remoteconfig.py +++ b/ddtrace/debugging/_probe/remoteconfig.py @@ -34,6 +34,8 @@ from ddtrace.debugging._probe.model import StringTemplate from ddtrace.debugging._probe.model import TemplateSegment from ddtrace.debugging._probe.model import TimingMixin +from ddtrace.debugging._probe.model import TriggerFunctionProbe +from ddtrace.debugging._probe.model import TriggerLineProbe from ddtrace.debugging._probe.status import ProbeStatusLogger from ddtrace.debugging._redaction import DDRedactedExpression from ddtrace.internal.logger import get_logger @@ -202,10 +204,31 @@ def update_args(cls, args, attribs): ) +class TriggerProbeFactory(ProbeFactory): + __line_class__ = TriggerLineProbe + __function_class__ = TriggerFunctionProbe + + @classmethod + def update_args(cls, args, attribs): + args.update( + session_id=attribs["sessionId"], + level=attribs["level"], + ) + + class InvalidProbeConfiguration(ValueError): pass +PROBE_FACTORY = { + ProbeType.LOG_PROBE: LogProbeFactory, + ProbeType.METRIC_PROBE: MetricProbeFactory, + ProbeType.SPAN_PROBE: SpanProbeFactory, + ProbeType.SPAN_DECORATION_PROBE: SpanDecorationProbeFactory, + ProbeType.TRIGGER_PROBE: TriggerProbeFactory, +} + + def build_probe(attribs: Dict[str, Any]) -> Probe: """ Create a new Probe instance. @@ -222,14 +245,9 @@ def build_probe(attribs: Dict[str, Any]) -> Probe: tags=dict(_.split(":", 1) for _ in attribs.get("tags", [])), ) - if _type == ProbeType.LOG_PROBE: - return LogProbeFactory.build(args, attribs) - if _type == ProbeType.METRIC_PROBE: - return MetricProbeFactory.build(args, attribs) - if _type == ProbeType.SPAN_PROBE: - return SpanProbeFactory.build(args, attribs) - if _type == ProbeType.SPAN_DECORATION_PROBE: - return SpanDecorationProbeFactory.build(args, attribs) + factory = PROBE_FACTORY.get(_type) + if factory is not None: + return factory.build(args, attribs) raise InvalidProbeConfiguration("Unsupported probe type: %s" % _type) diff --git a/ddtrace/debugging/_products/live_debugger.py b/ddtrace/debugging/_products/live_debugger.py new file mode 100644 index 00000000000..1417d22d320 --- /dev/null +++ b/ddtrace/debugging/_products/live_debugger.py @@ -0,0 +1,31 @@ +from ddtrace.settings.live_debugging import config + + +# TODO[gab]: Uncomment when the product is ready +# requires = ["tracer"] + + +def post_preload(): + pass + + +def start() -> None: + if config.enabled: + from ddtrace.debugging._live import enable + + enable() + + +def restart(join: bool = False) -> None: + pass + + +def stop(join: bool = False): + if config.enabled: + from ddtrace.debugging._live import disable + + disable() + + +def at_exit(join: bool = False): + stop(join=join) diff --git a/ddtrace/debugging/_session.py b/ddtrace/debugging/_session.py new file mode 100644 index 00000000000..83849eb2af0 --- /dev/null +++ b/ddtrace/debugging/_session.py @@ -0,0 +1,65 @@ +from dataclasses import dataclass +import typing as t +from weakref import WeakKeyDictionary as wkdict + +from ddtrace import tracer + + +SessionId = str + + +@dataclass +class Session: + ident: SessionId + level: int + + def link_to_trace(self, trace_context: t.Optional[t.Any] = None): + SessionManager.link_session_to_trace(self, trace_context) + + @classmethod + def from_trace(cls) -> t.Iterable["Session"]: + return SessionManager.get_sessions_for_trace() + + @classmethod + def lookup(cls, ident: SessionId) -> t.Optional["Session"]: + return SessionManager.lookup_session(ident) + + +class SessionManager: + _sessions_trace_map: t.MutableMapping[ + t.Any, t.Dict[SessionId, Session] + ] = wkdict() # Trace context to Sessions mapping + + @classmethod + def link_session_to_trace(cls, session, trace_context: t.Optional[t.Any] = None) -> None: + if trace_context is None: + # Get the current root + trace_context = tracer.current_root_span() + + if trace_context is None: + # We don't have a context to link to + return + + # If the root has a parent context, use that + try: + trace_context = trace_context.context or trace_context + except AttributeError: + pass + + cls._sessions_trace_map.setdefault(trace_context, {})[session.ident] = session + + @classmethod + def get_sessions_for_trace(cls) -> t.Iterable[Session]: + root = tracer.current_root_span() + if root is None: + return [] + + return cls._sessions_trace_map.get(root.context or root, {}).values() + + @classmethod + def lookup_session(cls, ident: SessionId) -> t.Optional[Session]: + root = tracer.current_root_span() + if root is None: + return None + + return cls._sessions_trace_map.get(root.context or root, {}).get(ident) # type: ignore[call-overload] diff --git a/ddtrace/debugging/_signal/model.py b/ddtrace/debugging/_signal/model.py index a03b157adde..6a2111d7801 100644 --- a/ddtrace/debugging/_signal/model.py +++ b/ddtrace/debugging/_signal/model.py @@ -27,6 +27,7 @@ from ddtrace.debugging._probe.model import RateLimitMixin from ddtrace.debugging._probe.model import TimingMixin from ddtrace.debugging._safety import get_args +from ddtrace.debugging._session import Session from ddtrace.internal.compat import ExcInfoType from ddtrace.internal.rate_limiter import RateLimitExceeded @@ -119,12 +120,17 @@ def _rate_limit_exceeded(self) -> bool: # We don't have a rate limiter, so no rate was exceeded. return False - exceeded = probe.limiter.limit() is RateLimitExceeded + exceeded = self.session is None and probe.limiter.limit() is RateLimitExceeded if exceeded: self.state = SignalState.SKIP_RATE return exceeded + @property + def session(self): + session_id = self.probe.tags.get("sessionId") + return Session.lookup(session_id) if session_id is not None else None + @property def args(self): return dict(get_args(self.frame)) diff --git a/ddtrace/debugging/_signal/snapshot.py b/ddtrace/debugging/_signal/snapshot.py index 54b23830be5..8e58e7370c4 100644 --- a/ddtrace/debugging/_signal/snapshot.py +++ b/ddtrace/debugging/_signal/snapshot.py @@ -24,6 +24,7 @@ from ddtrace.debugging._safety import get_args from ddtrace.debugging._safety import get_globals from ddtrace.debugging._safety import get_locals +from ddtrace.debugging._session import Session from ddtrace.debugging._signal import utils from ddtrace.debugging._signal.model import EvaluationError from ddtrace.debugging._signal.model import LogSignal diff --git a/ddtrace/debugging/_uploader.py b/ddtrace/debugging/_uploader.py index f2a3dae8d68..7f6226f7192 100644 --- a/ddtrace/debugging/_uploader.py +++ b/ddtrace/debugging/_uploader.py @@ -26,6 +26,7 @@ class UploaderProduct(str, Enum): DEBUGGER = "dynamic_instrumentation" EXCEPTION_REPLAY = "exception_replay" + CODE_ORIGIN_SPAN = "code_origin.span" class LogsIntakeUploaderV1(ForksafeAwakeablePeriodicService): diff --git a/ddtrace/settings/live_debugging.py b/ddtrace/settings/live_debugging.py new file mode 100644 index 00000000000..b9183ae0a77 --- /dev/null +++ b/ddtrace/settings/live_debugging.py @@ -0,0 +1,16 @@ +from envier import En + + +class LiveDebuggerConfig(En): + __prefix__ = "dd.live_debugging" + + enabled = En.v( + bool, + "enabled", + default=False, + help_type="Boolean", + help="Enable the live debugger.", + ) + + +config = LiveDebuggerConfig() diff --git a/docs/configuration.rst b/docs/configuration.rst index 45673747b72..cb70798f3cd 100644 --- a/docs/configuration.rst +++ b/docs/configuration.rst @@ -681,3 +681,9 @@ Exception Replay ---------------- .. ddtrace-envier-configuration:: ddtrace.settings.exception_replay:ExceptionReplayConfig + + +Live Debugging +-------------- + +.. ddtrace-envier-configuration:: ddtrace.settings.live_debugging:LiveDebuggerConfig diff --git a/pyproject.toml b/pyproject.toml index 9c8ff26d223..c0821dc4fcf 100644 --- a/pyproject.toml +++ b/pyproject.toml @@ -60,6 +60,7 @@ ddtrace = "ddtrace.contrib.pytest.plugin" "code-origin-for-spans" = "ddtrace.debugging._products.code_origin.span" "dynamic-instrumentation" = "ddtrace.debugging._products.dynamic_instrumentation" "exception-replay" = "ddtrace.debugging._products.exception_replay" +"live-debugger" = "ddtrace.debugging._products.live_debugger" "remote-configuration" = "ddtrace.internal.remoteconfig.product" "symbol-database" = "ddtrace.internal.symbol_db.product" diff --git a/tests/debugging/live/__init__.py b/tests/debugging/live/__init__.py new file mode 100644 index 00000000000..e69de29bb2d diff --git a/tests/debugging/live/test_live_debugger.py b/tests/debugging/live/test_live_debugger.py new file mode 100644 index 00000000000..c96a519e3ae --- /dev/null +++ b/tests/debugging/live/test_live_debugger.py @@ -0,0 +1,69 @@ +from collections import Counter +import typing as t + +import ddtrace +from ddtrace.debugging._origin.span import SpanCodeOriginProcessor +from ddtrace.debugging._probe.model import ProbeEvaluateTimingForMethod +from ddtrace.internal import core +from tests.debugging.mocking import MockLogsIntakeUploaderV1 +from tests.debugging.mocking import debugger +from tests.debugging.utils import create_snapshot_function_probe +from tests.debugging.utils import create_trigger_function_probe +from tests.utils import TracerTestCase + + +class MockSpanCodeOriginProcessor(SpanCodeOriginProcessor): + __uploader__ = MockLogsIntakeUploaderV1 + + @classmethod + def get_uploader(cls) -> MockLogsIntakeUploaderV1: + return t.cast(MockLogsIntakeUploaderV1, cls.__uploader__._instance) + + +class SpanProbeTestCase(TracerTestCase): + def setUp(self): + super(SpanProbeTestCase, self).setUp() + self.backup_tracer = ddtrace.tracer + ddtrace.tracer = self.tracer + + MockSpanCodeOriginProcessor.enable() + + def tearDown(self): + ddtrace.tracer = self.backup_tracer + super(SpanProbeTestCase, self).tearDown() + + MockSpanCodeOriginProcessor.disable() + core.reset_listeners(event_id="service_entrypoint.patch") + + def test_live_debugger(self): + from tests.submod.traced_stuff import entrypoint + from tests.submod.traced_stuff import traced_entrypoint + + with debugger() as d: + d.add_probes( + create_trigger_function_probe( + probe_id="trigger-probe", + module="tests.submod.traced_stuff", + func_qname="entrypoint", + evaluate_at=ProbeEvaluateTimingForMethod.ENTER, + session_id="test-session-id", + level=2, + ), + create_snapshot_function_probe( + probe_id="snapshot-probe", + module="tests.submod.traced_stuff", + func_qname="middle", + evaluate_at=ProbeEvaluateTimingForMethod.EXIT, + tags={"sessionId": "test-session-id"}, + rate=0.0, + ), + ) + + core.dispatch("service_entrypoint.patch", (entrypoint,)) + + for _ in range(10): + traced_entrypoint(self.tracer) + + # Check that the function probe has been triggered always, regardless of + # the rate limit. + assert Counter(s.probe.probe_id for s in d.snapshots)["snapshot-probe"] == 10 diff --git a/tests/debugging/mocking.py b/tests/debugging/mocking.py index dee76125ba3..82a9301eaaf 100644 --- a/tests/debugging/mocking.py +++ b/tests/debugging/mocking.py @@ -5,6 +5,7 @@ from time import sleep from typing import Any from typing import Generator +from typing import List from envier import En @@ -15,6 +16,7 @@ from ddtrace.debugging._probe.remoteconfig import ProbePollerEvent from ddtrace.debugging._probe.remoteconfig import _filter_by_env_and_version from ddtrace.debugging._signal.collector import SignalCollector +from ddtrace.debugging._signal.snapshot import Snapshot from ddtrace.debugging._uploader import LogsIntakeUploaderV1 from ddtrace.internal.compat import monotonic from tests.debugging.probe.test_status import DummyProbeStatusLogger @@ -115,6 +117,10 @@ def collector(self): def payloads(self): return [_ for data in self.queue for _ in json.loads(data)] + @property + def snapshots(self) -> List[Snapshot]: + return self.collector.queue + class TestDebugger(Debugger): __logger__ = MockProbeStatusLogger @@ -145,6 +151,10 @@ def uploader(self): def collector(self): return self.__uploader__.get_collector() + @property + def snapshots(self) -> List[Snapshot]: + return self.uploader.snapshots + @property def probe_status_logger(self): return self._probe_registry.logger diff --git a/tests/debugging/origin/test_span.py b/tests/debugging/origin/test_span.py index b443f784d2a..67570f97710 100644 --- a/tests/debugging/origin/test_span.py +++ b/tests/debugging/origin/test_span.py @@ -1,25 +1,36 @@ from pathlib import Path +import typing as t import ddtrace from ddtrace.debugging._origin.span import SpanCodeOriginProcessor +from ddtrace.debugging._session import Session from ddtrace.ext import SpanTypes from ddtrace.internal import core +from tests.debugging.mocking import MockLogsIntakeUploaderV1 from tests.utils import TracerTestCase +class MockSpanCodeOriginProcessor(SpanCodeOriginProcessor): + __uploader__ = MockLogsIntakeUploaderV1 + + @classmethod + def get_uploader(cls) -> MockLogsIntakeUploaderV1: + return t.cast(MockLogsIntakeUploaderV1, cls.__uploader__._instance) + + class SpanProbeTestCase(TracerTestCase): def setUp(self): super(SpanProbeTestCase, self).setUp() self.backup_tracer = ddtrace.tracer ddtrace.tracer = self.tracer - SpanCodeOriginProcessor.enable() + MockSpanCodeOriginProcessor.enable() def tearDown(self): ddtrace.tracer = self.backup_tracer super(SpanProbeTestCase, self).tearDown() - SpanCodeOriginProcessor.disable() + MockSpanCodeOriginProcessor.disable() core.reset_listeners(event_id="service_entrypoint.patch") def test_span_origin(self): @@ -54,3 +65,41 @@ def entry_call(): assert _exit.get_tag("_dd.code_origin.type") == "exit" assert _exit.get_tag("_dd.code_origin.frames.2.file") == str(Path(__file__).resolve()) assert _exit.get_tag("_dd.code_origin.frames.2.line") == str(self.test_span_origin.__code__.co_firstlineno) + + def test_span_origin_session(self): + def entry_call(): + pass + + core.dispatch("service_entrypoint.patch", (entry_call,)) + + with self.tracer.trace("entry"): + # Emulate a trigger probe + Session(ident="test", level=2).link_to_trace() + entry_call() + with self.tracer.trace("middle"): + with self.tracer.trace("exit", span_type=SpanTypes.HTTP): + pass + + self.assert_span_count(3) + entry, middle, _exit = self.get_spans() + payloads = MockSpanCodeOriginProcessor.get_uploader().wait_for_payloads() + snapshot_ids = {p["debugger"]["snapshot"]["id"] for p in payloads} + + assert len(payloads) == len(snapshot_ids) + + entry_snapshot_id = entry.get_tag("_dd.code_origin.frames.0.snapshot_id") + assert entry.get_tag("_dd.code_origin.type") == "entry" + assert entry_snapshot_id in snapshot_ids + + # Check that we don't have span location tags on the middle span + assert middle.get_tag("_dd.code_origin.frames.0.snapshot_id") is None + + # Check that we have all the snapshots for the exit span + assert _exit.get_tag("_dd.code_origin.type") == "exit" + snapshot_ids_from_span_tags = {_exit.get_tag(f"_dd.code_origin.frames.{_}.snapshot_id") for _ in range(8)} + snapshot_ids_from_span_tags.discard(None) + assert snapshot_ids_from_span_tags < snapshot_ids + + # Check that we have complete data + snapshot_ids_from_span_tags.add(entry_snapshot_id) + assert snapshot_ids_from_span_tags == snapshot_ids diff --git a/tests/debugging/test_debugger_span_decoration.py b/tests/debugging/test_debugger_span_decoration.py index fd6e8d2aca7..54a28e916d1 100644 --- a/tests/debugging/test_debugger_span_decoration.py +++ b/tests/debugging/test_debugger_span_decoration.py @@ -122,7 +122,7 @@ def test_debugger_span_decoration_probe_in_inner_function_active_span(self): create_span_decoration_line_probe( probe_id="span-decoration", source_file="tests/submod/traced_stuff.py", - line=3, + line=6, target_span=SpanDecorationTargetSpan.ACTIVE, decorations=[ SpanDecoration( @@ -175,7 +175,7 @@ def test_debugger_span_decoration_probe_in_traced_function_active_span(self): create_span_decoration_line_probe( probe_id="span-decoration", source_file="tests/submod/traced_stuff.py", - line=7, + line=10, target_span=SpanDecorationTargetSpan.ACTIVE, decorations=[ SpanDecoration( @@ -201,7 +201,7 @@ def test_debugger_span_decoration_probe_in_traced_function_root_span(self): create_span_decoration_line_probe( probe_id="span-decoration", source_file="tests/submod/traced_stuff.py", - line=8, + line=11, target_span=SpanDecorationTargetSpan.ROOT, decorations=[ SpanDecoration( diff --git a/tests/debugging/utils.py b/tests/debugging/utils.py index d4828be3cfd..fadd470a784 100644 --- a/tests/debugging/utils.py +++ b/tests/debugging/utils.py @@ -1,3 +1,5 @@ +import uuid + from ddtrace.debugging._expressions import DDExpression from ddtrace.debugging._expressions import dd_compile from ddtrace.debugging._probe.model import DEFAULT_CAPTURE_LIMITS @@ -16,6 +18,7 @@ from ddtrace.debugging._probe.model import SpanDecorationTargetSpan from ddtrace.debugging._probe.model import SpanFunctionProbe from ddtrace.debugging._probe.model import StringTemplate +from ddtrace.debugging._probe.model import TriggerFunctionProbe from ddtrace.debugging._redaction import DDRedactedExpression @@ -114,6 +117,15 @@ def _wrapper(*args, **kwargs): return _wrapper +def trigger_probe_defaults(f): + def _wrapper(*args, **kwargs): + kwargs.setdefault("session_id", str(uuid.uuid4)) + kwargs.setdefault("level", 0) + return f(*args, **kwargs) + + return _wrapper + + @create_probe_defaults @probe_conditional_defaults @snapshot_probe_defaults @@ -177,3 +189,10 @@ def create_span_decoration_line_probe(**kwargs): @span_decoration_probe_defaults def create_span_decoration_function_probe(**kwargs): return SpanDecorationFunctionProbe(**kwargs) + + +@create_probe_defaults +@function_location_defaults +@trigger_probe_defaults +def create_trigger_function_probe(**kwargs): + return TriggerFunctionProbe(**kwargs) diff --git a/tests/submod/traced_stuff.py b/tests/submod/traced_stuff.py index a414e86b4e3..caa28dac5b4 100644 --- a/tests/submod/traced_stuff.py +++ b/tests/submod/traced_stuff.py @@ -1,4 +1,7 @@ # -*- encoding: utf-8 -*- +from ddtrace.ext import SpanTypes + + def inner(): return 42 @@ -6,3 +9,22 @@ def inner(): def traceme(): cake = "🍰" # noqa return 42 + inner() + + +def exit_call(tracer): + with tracer.trace("exit", span_type=SpanTypes.HTTP): + return 42 + + +def middle(tracer): + with tracer.trace("middle"): + return exit_call(tracer) + + +def entrypoint(tracer): + return middle(tracer) + + +def traced_entrypoint(tracer): + with tracer.trace("entry"): + return entrypoint(tracer) From 325b1a4de0ec99a66f8d4eef12e19f57b2b3e45b Mon Sep 17 00:00:00 2001 From: "Gabriele N. Tornetta" Date: Tue, 22 Oct 2024 15:24:12 +0100 Subject: [PATCH 2/9] make conditional --- ddtrace/debugging/_debugger.py | 13 +++-- ddtrace/debugging/_probe/model.py | 4 +- ddtrace/debugging/_session.py | 29 ++++------ ddtrace/debugging/_signal/trigger.py | 80 ++++++++++++++++++++++++++++ tests/debugging/origin/test_span.py | 4 +- tests/debugging/utils.py | 1 + 6 files changed, 103 insertions(+), 28 deletions(-) create mode 100644 ddtrace/debugging/_signal/trigger.py diff --git a/ddtrace/debugging/_debugger.py b/ddtrace/debugging/_debugger.py index 7ccddf1b392..5d73f61ccdd 100644 --- a/ddtrace/debugging/_debugger.py +++ b/ddtrace/debugging/_debugger.py @@ -36,7 +36,6 @@ from ddtrace.debugging._probe.model import MetricFunctionProbe from ddtrace.debugging._probe.model import MetricLineProbe from ddtrace.debugging._probe.model import Probe -from ddtrace.debugging._probe.model import ProbeEvaluateTimingForMethod from ddtrace.debugging._probe.model import SpanDecorationFunctionProbe from ddtrace.debugging._probe.model import SpanDecorationLineProbe from ddtrace.debugging._probe.model import SpanFunctionProbe @@ -54,6 +53,7 @@ from ddtrace.debugging._signal.snapshot import Snapshot from ddtrace.debugging._signal.tracing import DynamicSpan from ddtrace.debugging._signal.tracing import SpanDecoration +from ddtrace.debugging._signal.trigger import Trigger from ddtrace.debugging._uploader import LogsIntakeUploaderV1 from ddtrace.debugging._uploader import UploaderProduct from ddtrace.internal import compat @@ -223,10 +223,13 @@ def _open_signals(self) -> None: frame=frame, thread=thread, ) - elif isinstance(probe, TriggerFunctionProbe) and probe.evaluate_at is ProbeEvaluateTimingForMethod.ENTER: - Session(probe.session_id, probe.level).link_to_trace(trace_context) - # This probe does not emit any signals - continue + elif isinstance(probe, TriggerFunctionProbe): + signal = Trigger( + probe=probe, + frame=frame, + thread=thread, + trace_context=trace_context, + ) else: log.error("Unsupported probe type: %s", type(probe)) continue diff --git a/ddtrace/debugging/_probe/model.py b/ddtrace/debugging/_probe/model.py index 5a8c4a3309b..cd7864f3bc3 100644 --- a/ddtrace/debugging/_probe/model.py +++ b/ddtrace/debugging/_probe/model.py @@ -304,12 +304,12 @@ class SessionMixin: @dataclass -class TriggerLineProbe(Probe, LineLocationMixin, SessionMixin): +class TriggerLineProbe(Probe, LineLocationMixin, SessionMixin, ProbeConditionMixin): pass @dataclass -class TriggerFunctionProbe(Probe, FunctionLocationMixin, SessionMixin): +class TriggerFunctionProbe(Probe, FunctionLocationMixin, SessionMixin, ProbeConditionMixin): pass diff --git a/ddtrace/debugging/_session.py b/ddtrace/debugging/_session.py index 83849eb2af0..936756b1265 100644 --- a/ddtrace/debugging/_session.py +++ b/ddtrace/debugging/_session.py @@ -32,34 +32,25 @@ class SessionManager: @classmethod def link_session_to_trace(cls, session, trace_context: t.Optional[t.Any] = None) -> None: - if trace_context is None: - # Get the current root - trace_context = tracer.current_root_span() - - if trace_context is None: - # We don't have a context to link to + context = trace_context or tracer.current_trace_context() + if context is None: + # Nothing to link to return - # If the root has a parent context, use that - try: - trace_context = trace_context.context or trace_context - except AttributeError: - pass - - cls._sessions_trace_map.setdefault(trace_context, {})[session.ident] = session + cls._sessions_trace_map.setdefault(context, {})[session.ident] = session @classmethod def get_sessions_for_trace(cls) -> t.Iterable[Session]: - root = tracer.current_root_span() - if root is None: + context = tracer.current_trace_context() + if context is None: return [] - return cls._sessions_trace_map.get(root.context or root, {}).values() + return cls._sessions_trace_map.get(context, {}).values() @classmethod def lookup_session(cls, ident: SessionId) -> t.Optional[Session]: - root = tracer.current_root_span() - if root is None: + context = tracer.current_trace_context() + if context is None: return None - return cls._sessions_trace_map.get(root.context or root, {}).get(ident) # type: ignore[call-overload] + return cls._sessions_trace_map.get(context, {}).get(ident) diff --git a/ddtrace/debugging/_signal/trigger.py b/ddtrace/debugging/_signal/trigger.py new file mode 100644 index 00000000000..5b84b410d9d --- /dev/null +++ b/ddtrace/debugging/_signal/trigger.py @@ -0,0 +1,80 @@ +from collections import ChainMap +from dataclasses import dataclass +import typing as t + +from ddtrace.debugging._probe.model import ProbeEvaluateTimingForMethod +from ddtrace.debugging._probe.model import SessionMixin +from ddtrace.debugging._probe.model import TriggerFunctionProbe +from ddtrace.debugging._probe.model import TriggerLineProbe +from ddtrace.debugging._session import Session +from ddtrace.debugging._signal.model import LogSignal +from ddtrace.debugging._signal.model import SignalState +from ddtrace.internal.compat import ExcInfoType +from ddtrace.internal.logger import get_logger + + +log = get_logger(__name__) + + +@dataclass +class Trigger(LogSignal): + """Trigger a session creation.""" + + def _link_session(self) -> None: + probe = t.cast(SessionMixin, self.probe) + Session(probe.session_id, probe.level).link_to_trace(self.trace_context) + + def enter(self) -> None: + probe = self.probe + if not isinstance(probe, TriggerFunctionProbe): + log.debug("Trigger probe entered with non-trigger probe: %s", self.probe) + return + + if probe.evaluate_at not in (ProbeEvaluateTimingForMethod.ENTER, ProbeEvaluateTimingForMethod.DEFAULT): + return + + if not self._eval_condition(ChainMap(self.args, self.frame.f_globals)): + return + + self._link_session() + + self.state = SignalState.DONE + + def exit(self, retval: t.Any, exc_info: ExcInfoType, duration: float) -> None: + probe = self.probe + + if not isinstance(probe, TriggerFunctionProbe): + log.debug("Trigger probe exited with non-trigger probe: %s", self.probe) + return + + if probe.evaluate_at is not ProbeEvaluateTimingForMethod.EXIT: + return + + if not self._eval_condition(self.get_full_scope(retval, exc_info, duration)): + return + + self._link_session() + + self.state = SignalState.DONE + + def line(self): + probe = self.probe + if not isinstance(probe, TriggerLineProbe): + log.debug("Span decoration on line with non-span decoration probe: %s", self.probe) + return + + frame = self.frame + + if not self._eval_condition(ChainMap(frame.f_locals, frame.f_globals)): + return + + self._link_session() + + self.state = SignalState.DONE + + @property + def message(self): + return f"Condition evaluation errors for probe {self.probe.probe_id}" if self.errors else None + + def has_message(self) -> bool: + return bool(self.errors) diff --git a/tests/debugging/origin/test_span.py b/tests/debugging/origin/test_span.py index 67570f97710..226bb8c7f79 100644 --- a/tests/debugging/origin/test_span.py +++ b/tests/debugging/origin/test_span.py @@ -63,8 +63,8 @@ def entry_call(): # Check for the expected tags on the exit span assert _exit.get_tag("_dd.code_origin.type") == "exit" - assert _exit.get_tag("_dd.code_origin.frames.2.file") == str(Path(__file__).resolve()) - assert _exit.get_tag("_dd.code_origin.frames.2.line") == str(self.test_span_origin.__code__.co_firstlineno) + assert _exit.get_tag("_dd.code_origin.frames.0.file") == str(Path(__file__).resolve()) + assert _exit.get_tag("_dd.code_origin.frames.0.line") == str(self.test_span_origin.__code__.co_firstlineno) def test_span_origin_session(self): def entry_call(): diff --git a/tests/debugging/utils.py b/tests/debugging/utils.py index fadd470a784..cef5f5fabe2 100644 --- a/tests/debugging/utils.py +++ b/tests/debugging/utils.py @@ -192,6 +192,7 @@ def create_span_decoration_function_probe(**kwargs): @create_probe_defaults +@probe_conditional_defaults @function_location_defaults @trigger_probe_defaults def create_trigger_function_probe(**kwargs): From 533cd90125eedaeb46c27e73c01457bcedd48764 Mon Sep 17 00:00:00 2001 From: "Gabriele N. Tornetta" Date: Mon, 28 Oct 2024 12:41:27 +0000 Subject: [PATCH 3/9] adapt to refactor --- ddtrace/debugging/_origin/span.py | 2 + ddtrace/debugging/_session.py | 12 +++++ ddtrace/debugging/_signal/snapshot.py | 1 - ddtrace/debugging/_signal/trigger.py | 57 ++++------------------ tests/debugging/live/test_live_debugger.py | 5 +- tests/debugging/utils.py | 1 - 6 files changed, 25 insertions(+), 53 deletions(-) diff --git a/ddtrace/debugging/_origin/span.py b/ddtrace/debugging/_origin/span.py index abaa35f2292..4f9908cd004 100644 --- a/ddtrace/debugging/_origin/span.py +++ b/ddtrace/debugging/_origin/span.py @@ -184,6 +184,8 @@ def _close_signal(self, retval=None, exc_info=(None, None, None)): snapshot.do_exit(retval, exc_info, compat.monotonic_ns() - self.get("start_time")) + self.collector.push(snapshot) + def __return__(self, retval): self._close_signal(retval=retval) return super().__return__(retval) diff --git a/ddtrace/debugging/_session.py b/ddtrace/debugging/_session.py index 936756b1265..7db73d5f7c5 100644 --- a/ddtrace/debugging/_session.py +++ b/ddtrace/debugging/_session.py @@ -16,6 +16,9 @@ class Session: def link_to_trace(self, trace_context: t.Optional[t.Any] = None): SessionManager.link_session_to_trace(self, trace_context) + def unlink_from_trace(self, trace_context: t.Optional[t.Any] = None): + SessionManager.unlink_session_to_trace(self, trace_context) + @classmethod def from_trace(cls) -> t.Iterable["Session"]: return SessionManager.get_sessions_for_trace() @@ -39,6 +42,15 @@ def link_session_to_trace(cls, session, trace_context: t.Optional[t.Any] = None) cls._sessions_trace_map.setdefault(context, {})[session.ident] = session + @classmethod + def unlink_session_to_trace(cls, session, trace_context: t.Optional[t.Any] = None) -> None: + context = trace_context or tracer.current_trace_context() + if context is None: + # Nothing to unlink from + return + + cls._sessions_trace_map.get(context, {}).pop(session.ident, None) + @classmethod def get_sessions_for_trace(cls) -> t.Iterable[Session]: context = tracer.current_trace_context() diff --git a/ddtrace/debugging/_signal/snapshot.py b/ddtrace/debugging/_signal/snapshot.py index 8e58e7370c4..54b23830be5 100644 --- a/ddtrace/debugging/_signal/snapshot.py +++ b/ddtrace/debugging/_signal/snapshot.py @@ -24,7 +24,6 @@ from ddtrace.debugging._safety import get_args from ddtrace.debugging._safety import get_globals from ddtrace.debugging._safety import get_locals -from ddtrace.debugging._session import Session from ddtrace.debugging._signal import utils from ddtrace.debugging._signal.model import EvaluationError from ddtrace.debugging._signal.model import LogSignal diff --git a/ddtrace/debugging/_signal/trigger.py b/ddtrace/debugging/_signal/trigger.py index 5b84b410d9d..20fa04e15e8 100644 --- a/ddtrace/debugging/_signal/trigger.py +++ b/ddtrace/debugging/_signal/trigger.py @@ -1,14 +1,10 @@ -from collections import ChainMap from dataclasses import dataclass import typing as t -from ddtrace.debugging._probe.model import ProbeEvaluateTimingForMethod +from ddtrace.debugging._probe.model import ProbeEvalTiming from ddtrace.debugging._probe.model import SessionMixin -from ddtrace.debugging._probe.model import TriggerFunctionProbe -from ddtrace.debugging._probe.model import TriggerLineProbe from ddtrace.debugging._session import Session from ddtrace.debugging._signal.model import LogSignal -from ddtrace.debugging._signal.model import SignalState from ddtrace.internal.compat import ExcInfoType from ddtrace.internal.logger import get_logger @@ -20,58 +16,23 @@ class Trigger(LogSignal): """Trigger a session creation.""" + __default_timing__ = ProbeEvalTiming.ENTRY + def _link_session(self) -> None: probe = t.cast(SessionMixin, self.probe) Session(probe.session_id, probe.level).link_to_trace(self.trace_context) - def enter(self) -> None: - probe = self.probe - if not isinstance(probe, TriggerFunctionProbe): - log.debug("Trigger probe entered with non-trigger probe: %s", self.probe) - return - - if probe.evaluate_at not in (ProbeEvaluateTimingForMethod.ENTER, ProbeEvaluateTimingForMethod.DEFAULT): - return - - if not self._eval_condition(ChainMap(self.args, self.frame.f_globals)): - return - + def enter(self, scope: t.Mapping[str, t.Any]) -> None: self._link_session() - self.state = SignalState.DONE - - def exit(self, retval: t.Any, exc_info: ExcInfoType, duration: float) -> None: - probe = self.probe - - if not isinstance(probe, TriggerFunctionProbe): - log.debug("Trigger probe exited with non-trigger probe: %s", self.probe) - return - - if probe.evaluate_at is not ProbeEvaluateTimingForMethod.EXIT: - return - - if not self._eval_condition(self.get_full_scope(retval, exc_info, duration)): - return + def exit(self, retval: t.Any, exc_info: ExcInfoType, duration: float, scope: t.Mapping[str, t.Any]) -> None: + session = self.session + if session is not None: + session.unlink_from_trace(self.trace_context) + def line(self, scope: t.Mapping[str, t.Any]): self._link_session() - self.state = SignalState.DONE - - def line(self): - probe = self.probe - if not isinstance(probe, TriggerLineProbe): - log.debug("Span decoration on line with non-span decoration probe: %s", self.probe) - return - - frame = self.frame - - if not self._eval_condition(ChainMap(frame.f_locals, frame.f_globals)): - return - - self._link_session() - - self.state = SignalState.DONE - @property def message(self): return f"Condition evaluation errors for probe {self.probe.probe_id}" if self.errors else None diff --git a/tests/debugging/live/test_live_debugger.py b/tests/debugging/live/test_live_debugger.py index c96a519e3ae..cb7872486e2 100644 --- a/tests/debugging/live/test_live_debugger.py +++ b/tests/debugging/live/test_live_debugger.py @@ -3,7 +3,7 @@ import ddtrace from ddtrace.debugging._origin.span import SpanCodeOriginProcessor -from ddtrace.debugging._probe.model import ProbeEvaluateTimingForMethod +from ddtrace.debugging._probe.model import ProbeEvalTiming from ddtrace.internal import core from tests.debugging.mocking import MockLogsIntakeUploaderV1 from tests.debugging.mocking import debugger @@ -45,7 +45,6 @@ def test_live_debugger(self): probe_id="trigger-probe", module="tests.submod.traced_stuff", func_qname="entrypoint", - evaluate_at=ProbeEvaluateTimingForMethod.ENTER, session_id="test-session-id", level=2, ), @@ -53,7 +52,7 @@ def test_live_debugger(self): probe_id="snapshot-probe", module="tests.submod.traced_stuff", func_qname="middle", - evaluate_at=ProbeEvaluateTimingForMethod.EXIT, + evaluate_at=ProbeEvalTiming.EXIT, tags={"sessionId": "test-session-id"}, rate=0.0, ), diff --git a/tests/debugging/utils.py b/tests/debugging/utils.py index cef5f5fabe2..85cf1437da4 100644 --- a/tests/debugging/utils.py +++ b/tests/debugging/utils.py @@ -193,7 +193,6 @@ def create_span_decoration_function_probe(**kwargs): @create_probe_defaults @probe_conditional_defaults -@function_location_defaults @trigger_probe_defaults def create_trigger_function_probe(**kwargs): return TriggerFunctionProbe(**kwargs) From a6af837363c7b33e4c62bcf03f7e3c255766e114 Mon Sep 17 00:00:00 2001 From: "Gabriele N. Tornetta" Date: Tue, 29 Oct 2024 16:15:15 +0000 Subject: [PATCH 4/9] add rate limiter and propagation --- ddtrace/debugging/_exception/replay.py | 4 +++ ddtrace/debugging/_live.py | 16 ++------- ddtrace/debugging/_probe/model.py | 1 + ddtrace/debugging/_probe/remoteconfig.py | 2 ++ ddtrace/debugging/_session.py | 45 +++++++++++++++++++++--- ddtrace/debugging/_signal/trigger.py | 9 ++++- tests/debugging/test_session.py | 11 ++++++ 7 files changed, 68 insertions(+), 20 deletions(-) create mode 100644 tests/debugging/test_session.py diff --git a/ddtrace/debugging/_exception/replay.py b/ddtrace/debugging/_exception/replay.py index 15d03c678af..89a676f7f72 100644 --- a/ddtrace/debugging/_exception/replay.py +++ b/ddtrace/debugging/_exception/replay.py @@ -11,6 +11,7 @@ from ddtrace._trace.span import Span from ddtrace.debugging._probe.model import LiteralTemplateSegment from ddtrace.debugging._probe.model import LogLineProbe +from ddtrace.debugging._session import Session from ddtrace.debugging._signal.snapshot import DEFAULT_CAPTURE_LIMITS from ddtrace.debugging._signal.snapshot import Snapshot from ddtrace.debugging._uploader import LogsIntakeUploaderV1 @@ -135,6 +136,9 @@ def can_capture(span: Span) -> bool: return True if info_captured is None: + if Session.from_trace(): + # If we are in a debug session we always capture + return True result = GLOBAL_RATE_LIMITER.limit() is not RateLimitExceeded root.set_tag_str(CAPTURE_TRACE_TAG, str(result).lower()) return result diff --git a/ddtrace/debugging/_live.py b/ddtrace/debugging/_live.py index 6022b7c3348..31a3d315bc4 100644 --- a/ddtrace/debugging/_live.py +++ b/ddtrace/debugging/_live.py @@ -1,22 +1,10 @@ -import typing as t - from ddtrace.debugging._session import Session from ddtrace.internal import core -def handle_distributed_context(context: t.Any) -> None: - debug_tag = context._meta.get("_dd.p.debug") - if debug_tag is None: - return - - for session in debug_tag.split(","): - ident, _, level = session.partition(":") - Session(ident=ident, level=int(level or 0)).link_to_trace(context) - - def enable() -> None: - core.on("distributed_context.activated", handle_distributed_context, "live_debugger") + core.on("distributed_context.activated", Session.activate_distributed, "live_debugger") def disable() -> None: - core.reset_listeners("distributed_context.activated", handle_distributed_context) + core.reset_listeners("distributed_context.activated", Session.activate_distributed) diff --git a/ddtrace/debugging/_probe/model.py b/ddtrace/debugging/_probe/model.py index cd7864f3bc3..842bd42af8a 100644 --- a/ddtrace/debugging/_probe/model.py +++ b/ddtrace/debugging/_probe/model.py @@ -27,6 +27,7 @@ DEFAULT_PROBE_RATE = 5000.0 DEFAULT_SNAPSHOT_PROBE_RATE = 1.0 +DEFAULT_TRIGGER_PROBE_RATE = 1.0 DEFAULT_PROBE_CONDITION_ERROR_RATE = 1.0 / 60 / 5 diff --git a/ddtrace/debugging/_probe/remoteconfig.py b/ddtrace/debugging/_probe/remoteconfig.py index 5831f3ba284..f71660364fb 100644 --- a/ddtrace/debugging/_probe/remoteconfig.py +++ b/ddtrace/debugging/_probe/remoteconfig.py @@ -14,6 +14,7 @@ from ddtrace.debugging._probe.model import DEFAULT_PROBE_CONDITION_ERROR_RATE from ddtrace.debugging._probe.model import DEFAULT_PROBE_RATE from ddtrace.debugging._probe.model import DEFAULT_SNAPSHOT_PROBE_RATE +from ddtrace.debugging._probe.model import DEFAULT_TRIGGER_PROBE_RATE from ddtrace.debugging._probe.model import CaptureLimits from ddtrace.debugging._probe.model import ExpressionTemplateSegment from ddtrace.debugging._probe.model import FunctionProbe @@ -211,6 +212,7 @@ class TriggerProbeFactory(ProbeFactory): @classmethod def update_args(cls, args, attribs): args.update( + rate=attribs.get("sampling", {}).get("cooldownInSeconds", DEFAULT_TRIGGER_PROBE_RATE), session_id=attribs["sessionId"], level=attribs["level"], ) diff --git a/ddtrace/debugging/_session.py b/ddtrace/debugging/_session.py index 7db73d5f7c5..91ff77afd78 100644 --- a/ddtrace/debugging/_session.py +++ b/ddtrace/debugging/_session.py @@ -8,19 +8,54 @@ SessionId = str +def _sessions_from_debug_tag(debug_tag: str) -> t.Generator["Session", None, None]: + for session in debug_tag.split(","): + ident, _, level = session.partition(":") + yield Session(ident=ident, level=int(level or 0)) + + +def _sessions_to_debug_tag(sessions: t.Iterable["Session"]) -> str: + # TODO: Validate tag length + return ",".join(f"{session.ident}:{session.level}" for session in sessions) + + @dataclass class Session: ident: SessionId level: int + @classmethod + def activate_distributed(cls, context: t.Any) -> None: + debug_tag = context._meta.get("_dd.p.debug") + if debug_tag is None: + return + + for session in _sessions_from_debug_tag(debug_tag): + session.link_to_trace(context) + + def propagate(self, context: t.Any) -> None: + sessions = list(_sessions_from_debug_tag(context)) + for session in sessions: + if self.ident == session.ident: + # The session is already in the tags so we don't need to add it + if self.level > session.level: + # We only need to update the level if it's higher + session.level = self.level + break + else: + # The session is not in the tags so we need to add it + sessions.append(self) + + context._meta["_dd.p.debug"] = _sessions_to_debug_tag(sessions) + def link_to_trace(self, trace_context: t.Optional[t.Any] = None): SessionManager.link_session_to_trace(self, trace_context) def unlink_from_trace(self, trace_context: t.Optional[t.Any] = None): - SessionManager.unlink_session_to_trace(self, trace_context) + SessionManager.unlink_session_from_trace(self, trace_context) @classmethod - def from_trace(cls) -> t.Iterable["Session"]: + def from_trace(cls) -> t.List["Session"]: return SessionManager.get_sessions_for_trace() @classmethod @@ -43,7 +78,7 @@ def link_session_to_trace(cls, session, trace_context: t.Optional[t.Any] = None) cls._sessions_trace_map.setdefault(context, {})[session.ident] = session @classmethod - def unlink_session_to_trace(cls, session, trace_context: t.Optional[t.Any] = None) -> None: + def unlink_session_from_trace(cls, session, trace_context: t.Optional[t.Any] = None) -> None: context = trace_context or tracer.current_trace_context() if context is None: # Nothing to unlink from @@ -52,12 +87,12 @@ def unlink_session_to_trace(cls, session, trace_context: t.Optional[t.Any] = Non cls._sessions_trace_map.get(context, {}).pop(session.ident, None) @classmethod - def get_sessions_for_trace(cls) -> t.Iterable[Session]: + def get_sessions_for_trace(cls) -> t.List[Session]: context = tracer.current_trace_context() if context is None: return [] - return cls._sessions_trace_map.get(context, {}).values() + return list(cls._sessions_trace_map.get(context, {}).values()) @classmethod def lookup_session(cls, ident: SessionId) -> t.Optional[Session]: diff --git a/ddtrace/debugging/_signal/trigger.py b/ddtrace/debugging/_signal/trigger.py index 20fa04e15e8..fb6ae240a5d 100644 --- a/ddtrace/debugging/_signal/trigger.py +++ b/ddtrace/debugging/_signal/trigger.py @@ -20,7 +20,14 @@ class Trigger(LogSignal): def _link_session(self) -> None: probe = t.cast(SessionMixin, self.probe) - Session(probe.session_id, probe.level).link_to_trace(self.trace_context) + session = Session(probe.session_id, probe.level) + + # Link the session to the running trace + session.link_to_trace(self.trace_context) + + # Ensure that the new session information is included in the debug + # propagation tag for distributed debugging + session.propagate(self.trace_context) def enter(self, scope: t.Mapping[str, t.Any]) -> None: self._link_session() diff --git a/tests/debugging/test_session.py b/tests/debugging/test_session.py new file mode 100644 index 00000000000..732c7793084 --- /dev/null +++ b/tests/debugging/test_session.py @@ -0,0 +1,11 @@ +from ddtrace.debugging._session import _sessions_from_debug_tag +from ddtrace.debugging._session import _sessions_to_debug_tag + + +def test_tag_identity(): + """ + Test that the combination of _sessions_from_debug_tag and + _sessions_to_debug_tag is the identity function. + """ + debug_tag = "session1:1,session2:2" + assert _sessions_to_debug_tag(_sessions_from_debug_tag(debug_tag)) == debug_tag From 0b265baa403aa1224002aefa94ec4d11eef68fe7 Mon Sep 17 00:00:00 2001 From: "Gabriele N. Tornetta" Date: Thu, 7 Nov 2024 10:30:29 +0000 Subject: [PATCH 5/9] make code origin for span opt-out --- ddtrace/settings/code_origin.py | 2 +- 1 file changed, 1 insertion(+), 1 deletion(-) diff --git a/ddtrace/settings/code_origin.py b/ddtrace/settings/code_origin.py index 919e01bd02b..ab27e3e5e20 100644 --- a/ddtrace/settings/code_origin.py +++ b/ddtrace/settings/code_origin.py @@ -20,7 +20,7 @@ class SpanCodeOriginConfig(En): enabled = En.v( bool, "enabled", - default=False, + default=True, help_type="Boolean", help="Enable code origin for spans", ) From 9edcbc1805ff3f219612cafb65e8b7a0c00a36aa Mon Sep 17 00:00:00 2001 From: "Gabriele N. Tornetta" Date: Fri, 13 Dec 2024 16:34:39 +0000 Subject: [PATCH 6/9] session to trace linking fix and wrapper ordering --- ddtrace/_trace/context.py | 3 +-- ddtrace/debugging/_debugger.py | 1 - ddtrace/debugging/_origin/span.py | 2 ++ ddtrace/debugging/_probe/model.py | 4 ++-- ddtrace/debugging/_probe/remoteconfig.py | 4 +++- ddtrace/debugging/_session.py | 7 ++++--- ddtrace/debugging/_signal/__init__.py | 1 + ddtrace/debugging/_signal/trigger.py | 18 +++++++++++++++++- 8 files changed, 30 insertions(+), 10 deletions(-) diff --git a/ddtrace/_trace/context.py b/ddtrace/_trace/context.py index 065da866006..4f444aafd9d 100644 --- a/ddtrace/_trace/context.py +++ b/ddtrace/_trace/context.py @@ -269,7 +269,6 @@ def __eq__(self, other: Any) -> bool: with self._lock: return ( self.trace_id == other.trace_id - and self.span_id == other.span_id and self._meta == other._meta and self._metrics == other._metrics and self._span_links == other._span_links @@ -290,6 +289,6 @@ def __repr__(self) -> str: ) def __hash__(self) -> int: - return hash((self.trace_id, self.span_id)) + return hash(self.trace_id) __str__ = __repr__ diff --git a/ddtrace/debugging/_debugger.py b/ddtrace/debugging/_debugger.py index 4d525a0137a..65b9ecfec5e 100644 --- a/ddtrace/debugging/_debugger.py +++ b/ddtrace/debugging/_debugger.py @@ -37,7 +37,6 @@ from ddtrace.debugging._probe.remoteconfig import ProbePollerEventType from ddtrace.debugging._probe.remoteconfig import ProbeRCAdapter from ddtrace.debugging._probe.status import ProbeStatusLogger -from ddtrace.debugging._session import Session from ddtrace.debugging._signal.collector import SignalCollector from ddtrace.debugging._signal.model import Signal from ddtrace.debugging._signal.model import SignalState diff --git a/ddtrace/debugging/_origin/span.py b/ddtrace/debugging/_origin/span.py index 54924ac4b93..4ded9bd7a80 100644 --- a/ddtrace/debugging/_origin/span.py +++ b/ddtrace/debugging/_origin/span.py @@ -118,6 +118,8 @@ class EntrySpanLocation: class EntrySpanWrappingContext(WrappingContext): + __priority__ = 199 + def __init__(self, collector: SignalCollector, f: FunctionType) -> None: super().__init__(f) diff --git a/ddtrace/debugging/_probe/model.py b/ddtrace/debugging/_probe/model.py index b6db7613c4f..893961d7044 100644 --- a/ddtrace/debugging/_probe/model.py +++ b/ddtrace/debugging/_probe/model.py @@ -310,12 +310,12 @@ class SessionMixin: @dataclass -class TriggerLineProbe(Probe, LineLocationMixin, SessionMixin, ProbeConditionMixin): +class TriggerLineProbe(Probe, LineLocationMixin, SessionMixin, ProbeConditionMixin, RateLimitMixin): pass @dataclass -class TriggerFunctionProbe(Probe, FunctionLocationMixin, SessionMixin, ProbeConditionMixin): +class TriggerFunctionProbe(Probe, FunctionLocationMixin, SessionMixin, ProbeConditionMixin, RateLimitMixin): pass diff --git a/ddtrace/debugging/_probe/remoteconfig.py b/ddtrace/debugging/_probe/remoteconfig.py index f71660364fb..4db0a7fac78 100644 --- a/ddtrace/debugging/_probe/remoteconfig.py +++ b/ddtrace/debugging/_probe/remoteconfig.py @@ -214,7 +214,9 @@ def update_args(cls, args, attribs): args.update( rate=attribs.get("sampling", {}).get("cooldownInSeconds", DEFAULT_TRIGGER_PROBE_RATE), session_id=attribs["sessionId"], - level=attribs["level"], + level=int(attribs["level"]), + condition=DDRedactedExpression.compile(attribs["when"]) if "when" in attribs else None, + condition_error_rate=DEFAULT_PROBE_CONDITION_ERROR_RATE, ) diff --git a/ddtrace/debugging/_session.py b/ddtrace/debugging/_session.py index 91ff77afd78..74a636217f7 100644 --- a/ddtrace/debugging/_session.py +++ b/ddtrace/debugging/_session.py @@ -9,14 +9,14 @@ def _sessions_from_debug_tag(debug_tag: str) -> t.Generator["Session", None, None]: - for session in debug_tag.split(","): + for session in debug_tag.split("."): ident, _, level = session.partition(":") yield Session(ident=ident, level=int(level or 0)) def _sessions_to_debug_tag(sessions: t.Iterable["Session"]) -> str: # TODO: Validate tag length - return ",".join(f"{session.ident}:{session.level}" for session in sessions) + return ".".join(f"{session.ident}:{session.level}" for session in sessions) @dataclass @@ -34,7 +34,8 @@ def activate_distributed(cls, context: t.Any) -> None: session.link_to_trace(context) def propagate(self, context: t.Any) -> None: - sessions = list(_sessions_from_debug_tag(context)) + debug_tag = context._meta.get("_dd.p.debug") + sessions = list(_sessions_from_debug_tag(debug_tag)) if debug_tag is not None else [] for session in sessions: if self.ident == session.ident: # The session is already in the tags so we don't need to add it diff --git a/ddtrace/debugging/_signal/__init__.py b/ddtrace/debugging/_signal/__init__.py index 6dea9afe965..494a46a9a91 100644 --- a/ddtrace/debugging/_signal/__init__.py +++ b/ddtrace/debugging/_signal/__init__.py @@ -3,3 +3,4 @@ from ddtrace.debugging._signal.snapshot import Snapshot # noqa from ddtrace.debugging._signal.tracing import DynamicSpan # noqa from ddtrace.debugging._signal.tracing import SpanDecoration # noqa +from ddtrace.debugging._signal.trigger import Trigger # noqa diff --git a/ddtrace/debugging/_signal/trigger.py b/ddtrace/debugging/_signal/trigger.py index fb6ae240a5d..f88baf4c9bb 100644 --- a/ddtrace/debugging/_signal/trigger.py +++ b/ddtrace/debugging/_signal/trigger.py @@ -3,8 +3,11 @@ from ddtrace.debugging._probe.model import ProbeEvalTiming from ddtrace.debugging._probe.model import SessionMixin +from ddtrace.debugging._probe.model import TriggerFunctionProbe +from ddtrace.debugging._probe.model import TriggerLineProbe from ddtrace.debugging._session import Session -from ddtrace.debugging._signal.model import LogSignal +from ddtrace.debugging._signal.log import LogSignal +from ddtrace.debugging._signal.model import probe_to_signal from ddtrace.internal.compat import ExcInfoType from ddtrace.internal.logger import get_logger @@ -29,6 +32,9 @@ def _link_session(self) -> None: # propagation tag for distributed debugging session.propagate(self.trace_context) + # DEV: Unfortunately we don't have an API for this :( + self.trace_context._meta[f"_dd.ld.probe_id.{self.probe.probe_id}"] = "true" # type: ignore[union-attr] + def enter(self, scope: t.Mapping[str, t.Any]) -> None: self._link_session() @@ -46,3 +52,13 @@ def message(self): def has_message(self) -> bool: return bool(self.errors) + + +@probe_to_signal.register +def _(probe: TriggerFunctionProbe, frame, thread, trace_context, meter): + return Trigger(probe=probe, frame=frame, thread=thread, trace_context=trace_context) + + +@probe_to_signal.register +def _(probe: TriggerLineProbe, frame, thread, trace_context, meter): + return Trigger(probe=probe, frame=frame, thread=thread, trace_context=trace_context) From 8401d1cfb8766ad04abac8e2ee70d35824b7665c Mon Sep 17 00:00:00 2001 From: "Gabriele N. Tornetta" Date: Fri, 3 Jan 2025 11:00:32 +0000 Subject: [PATCH 7/9] include changes from review --- ddtrace/debugging/_origin/span.py | 23 +++++++++++------------ ddtrace/debugging/_probe/model.py | 2 +- ddtrace/debugging/_session.py | 9 +++++++-- ddtrace/debugging/_signal/model.py | 20 ++++++++++++++++++++ ddtrace/debugging/_signal/trigger.py | 6 +++--- ddtrace/settings/code_origin.py | 2 +- tests/debugging/conftest.py | 5 ++--- tests/debugging/signal/test_collector.py | 15 ++++++++++++++- tests/debugging/test_session.py | 14 +++++++++++--- tests/debugging/utils.py | 1 + 10 files changed, 71 insertions(+), 26 deletions(-) diff --git a/ddtrace/debugging/_origin/span.py b/ddtrace/debugging/_origin/span.py index 4ded9bd7a80..011c85743f5 100644 --- a/ddtrace/debugging/_origin/span.py +++ b/ddtrace/debugging/_origin/span.py @@ -154,12 +154,20 @@ def __enter__(self): s.set_tag_str("_dd.code_origin.frames.0.type", location.module) s.set_tag_str("_dd.code_origin.frames.0.method", location.name) + return self + + def _close_signal(self, retval=None, exc_info=(None, None, None)): + root = ddtrace.tracer.current_root_span() + span = ddtrace.tracer.current_span() + if root is None or span is None: + return + # Check if we have any level 2 debugging sessions running for the # current trace if any(s.level >= 2 for s in Session.from_trace()): # Create a snapshot snapshot = Snapshot( - probe=location.probe, + probe=self.location.probe, frame=self.__frame__, thread=current_thread(), trace_context=root, @@ -175,18 +183,9 @@ def __enter__(self): self.set("snapshot", snapshot) self.set("start_time", compat.monotonic_ns()) - return self - - def _close_signal(self, retval=None, exc_info=(None, None, None)): - try: - snapshot: Snapshot = t.cast(Snapshot, self.get("snapshot")) - except KeyError: - # No snapshot was created - return - - snapshot.do_exit(retval, exc_info, compat.monotonic_ns() - self.get("start_time")) + snapshot.do_exit(retval, exc_info, compat.monotonic_ns() - self.get("start_time")) - self.collector.push(snapshot) + self.collector.push(snapshot) def __return__(self, retval): self._close_signal(retval=retval) diff --git a/ddtrace/debugging/_probe/model.py b/ddtrace/debugging/_probe/model.py index 893961d7044..1b904288104 100644 --- a/ddtrace/debugging/_probe/model.py +++ b/ddtrace/debugging/_probe/model.py @@ -27,7 +27,7 @@ DEFAULT_PROBE_RATE = 5000.0 DEFAULT_SNAPSHOT_PROBE_RATE = 1.0 -DEFAULT_TRIGGER_PROBE_RATE = 1.0 +DEFAULT_TRIGGER_PROBE_RATE = 1.0 / 60.0 # 1 per minute DEFAULT_PROBE_CONDITION_ERROR_RATE = 1.0 / 60 / 5 diff --git a/ddtrace/debugging/_session.py b/ddtrace/debugging/_session.py index 74a636217f7..d9f25157d2c 100644 --- a/ddtrace/debugging/_session.py +++ b/ddtrace/debugging/_session.py @@ -7,16 +7,21 @@ SessionId = str +DEFAULT_SESSION_LEVEL = 1 + def _sessions_from_debug_tag(debug_tag: str) -> t.Generator["Session", None, None]: for session in debug_tag.split("."): ident, _, level = session.partition(":") - yield Session(ident=ident, level=int(level or 0)) + yield Session(ident=ident, level=int(level or DEFAULT_SESSION_LEVEL)) def _sessions_to_debug_tag(sessions: t.Iterable["Session"]) -> str: # TODO: Validate tag length - return ".".join(f"{session.ident}:{session.level}" for session in sessions) + return ".".join( + (f"{session.ident}:{session.level}" if session.level != DEFAULT_SESSION_LEVEL else session.ident) + for session in sessions + ) @dataclass diff --git a/ddtrace/debugging/_signal/model.py b/ddtrace/debugging/_signal/model.py index 9fa381426ff..9354c56f0ff 100644 --- a/ddtrace/debugging/_signal/model.py +++ b/ddtrace/debugging/_signal/model.py @@ -128,6 +128,17 @@ def _rate_limit_exceeded(self) -> bool: return exceeded + def _session_check(self) -> bool: + # Check that we emit signals from probes with a session ID only if the + # session is active. If the probe has no session ID, or the session ID + # is active, we can proceed with the signal emission. + session_id = self.probe.tags.get("sessionId") + if session_id is not None: + session = Session.lookup(session_id) + if session is None or session.level == 0: + return False + return True + @property def session(self): session_id = self.probe.tags.get("sessionId") @@ -150,6 +161,9 @@ def line(self, scope: Mapping[str, Any]) -> None: pass def do_enter(self) -> None: + if not self._session_check(): + return + if self._timing is not ProbeEvalTiming.ENTRY: return @@ -163,6 +177,9 @@ def do_enter(self) -> None: self.enter(scope) def do_exit(self, retval: Any, exc_info: ExcInfoType, duration: int) -> None: + if not self._session_check(): + return + if self.state is not SignalState.NONE: # The signal has already been handled and move to a final state return @@ -192,6 +209,9 @@ def do_exit(self, retval: Any, exc_info: ExcInfoType, duration: int) -> None: self.state = SignalState.DONE def do_line(self, global_limiter: Optional[RateLimiter] = None) -> None: + if not self._session_check(): + return + frame = self.frame scope = ChainMap(frame.f_locals, frame.f_globals) diff --git a/ddtrace/debugging/_signal/trigger.py b/ddtrace/debugging/_signal/trigger.py index f88baf4c9bb..6f1eec74e30 100644 --- a/ddtrace/debugging/_signal/trigger.py +++ b/ddtrace/debugging/_signal/trigger.py @@ -39,9 +39,9 @@ def enter(self, scope: t.Mapping[str, t.Any]) -> None: self._link_session() def exit(self, retval: t.Any, exc_info: ExcInfoType, duration: float, scope: t.Mapping[str, t.Any]) -> None: - session = self.session - if session is not None: - session.unlink_from_trace(self.trace_context) + # DEV: We do not unlink on exit explicitly here. We let the weak + # reference to the context object do the job. + pass def line(self, scope: t.Mapping[str, t.Any]): self._link_session() diff --git a/ddtrace/settings/code_origin.py b/ddtrace/settings/code_origin.py index ab27e3e5e20..919e01bd02b 100644 --- a/ddtrace/settings/code_origin.py +++ b/ddtrace/settings/code_origin.py @@ -20,7 +20,7 @@ class SpanCodeOriginConfig(En): enabled = En.v( bool, "enabled", - default=True, + default=False, help_type="Boolean", help="Enable code origin for spans", ) diff --git a/tests/debugging/conftest.py b/tests/debugging/conftest.py index 71664983ea4..24fde8ebe86 100644 --- a/tests/debugging/conftest.py +++ b/tests/debugging/conftest.py @@ -5,9 +5,8 @@ @pytest.fixture def stuff(): - was_loaded = False - if "tests.submod.stuff" in sys.modules: - was_loaded = True + was_loaded = "tests.submod.stuff" in sys.modules + if was_loaded: del sys.modules["tests.submod.stuff"] __import__("tests.submod.stuff") diff --git a/tests/debugging/signal/test_collector.py b/tests/debugging/signal/test_collector.py index 49e4f1aef2c..9bb4e72de8b 100644 --- a/tests/debugging/signal/test_collector.py +++ b/tests/debugging/signal/test_collector.py @@ -5,10 +5,12 @@ import mock +from ddtrace.debugging._probe.model import ProbeEvalTiming from ddtrace.debugging._signal.collector import SignalCollector from ddtrace.debugging._signal.log import LogSignal from ddtrace.debugging._signal.model import SignalState from ddtrace.debugging._signal.snapshot import Snapshot +from tests.debugging.utils import create_log_function_probe from tests.debugging.utils import create_snapshot_line_probe @@ -45,7 +47,18 @@ def has_message(self): c = 0 for i in range(10): - mocked_signal = MockLogSignal(mock.Mock(), sys._getframe(), threading.current_thread()) + mocked_signal = MockLogSignal( + create_log_function_probe( + probe_id="test", + template=None, + segments=[], + module="foo", + func_qname="bar", + evaluate_at=ProbeEvalTiming.ENTRY, + ), + sys._getframe(), + threading.current_thread(), + ) mocked_signal.do_enter() assert mocked_signal.enter_call_count == 1 diff --git a/tests/debugging/test_session.py b/tests/debugging/test_session.py index 732c7793084..af2988ec49f 100644 --- a/tests/debugging/test_session.py +++ b/tests/debugging/test_session.py @@ -1,11 +1,19 @@ +import pytest + from ddtrace.debugging._session import _sessions_from_debug_tag from ddtrace.debugging._session import _sessions_to_debug_tag -def test_tag_identity(): +@pytest.mark.parametrize( + "a,b", + [ + ("session1:1.session2:2", "session1.session2:2"), + ("session1:0.session2:2", "session1:0.session2:2"), + ], +) +def test_tag_identity(a, b): """ Test that the combination of _sessions_from_debug_tag and _sessions_to_debug_tag is the identity function. """ - debug_tag = "session1:1,session2:2" - assert _sessions_to_debug_tag(_sessions_from_debug_tag(debug_tag)) == debug_tag + assert _sessions_to_debug_tag(_sessions_from_debug_tag(a)) == b diff --git a/tests/debugging/utils.py b/tests/debugging/utils.py index 85cf1437da4..4d25f908bb3 100644 --- a/tests/debugging/utils.py +++ b/tests/debugging/utils.py @@ -121,6 +121,7 @@ def trigger_probe_defaults(f): def _wrapper(*args, **kwargs): kwargs.setdefault("session_id", str(uuid.uuid4)) kwargs.setdefault("level", 0) + kwargs.setdefault("rate", DEFAULT_PROBE_RATE) return f(*args, **kwargs) return _wrapper From f108c5ad087a203c2ed7fb553cbcb8bd5c046280 Mon Sep 17 00:00:00 2001 From: "Gabriele N. Tornetta" Date: Mon, 6 Jan 2025 15:06:10 +0000 Subject: [PATCH 8/9] avoid extraction for baggage --- ddtrace/propagation/http.py | 18 +++++++++--------- 1 file changed, 9 insertions(+), 9 deletions(-) diff --git a/ddtrace/propagation/http.py b/ddtrace/propagation/http.py index efe96c9dd0d..4261433f573 100644 --- a/ddtrace/propagation/http.py +++ b/ddtrace/propagation/http.py @@ -976,15 +976,15 @@ class HTTPPropagator(object): def _extract_configured_contexts_avail(normalized_headers): contexts = [] styles_w_ctx = [] - for prop_style in config._propagation_style_extract: - propagator = _PROP_STYLES[prop_style] - context = propagator._extract(normalized_headers) - # baggage is handled separately - if prop_style == _PROPAGATION_STYLE_BAGGAGE: - continue - if context: - contexts.append(context) - styles_w_ctx.append(prop_style) + if config._propagation_style_extract is not None: + for prop_style in config._propagation_style_extract: + if prop_style == _PROPAGATION_STYLE_BAGGAGE: + continue + propagator = _PROP_STYLES[prop_style] + context = propagator._extract(normalized_headers) + if context: + contexts.append(context) + styles_w_ctx.append(prop_style) return contexts, styles_w_ctx @staticmethod From 2d85475326f050e3ac0b991b31fd6eb7e2b6077b Mon Sep 17 00:00:00 2001 From: "Gabriele N. Tornetta" Date: Thu, 9 Jan 2025 10:35:32 +0000 Subject: [PATCH 9/9] fix start time --- ddtrace/debugging/_origin/span.py | 5 ++--- tests/debugging/test_session.py | 16 ++++++++++++++++ 2 files changed, 18 insertions(+), 3 deletions(-) diff --git a/ddtrace/debugging/_origin/span.py b/ddtrace/debugging/_origin/span.py index 9f3c2174a4c..abd63dbb97d 100644 --- a/ddtrace/debugging/_origin/span.py +++ b/ddtrace/debugging/_origin/span.py @@ -154,6 +154,8 @@ def __enter__(self): s.set_tag_str("_dd.code_origin.frames.0.type", location.module) s.set_tag_str("_dd.code_origin.frames.0.method", location.name) + self.set("start_time", monotonic_ns()) + return self def _close_signal(self, retval=None, exc_info=(None, None, None)): @@ -180,9 +182,6 @@ def _close_signal(self, retval=None, exc_info=(None, None, None)): root.set_tag_str("_dd.code_origin.frames.0.snapshot_id", snapshot.uuid) span.set_tag_str("_dd.code_origin.frames.0.snapshot_id", snapshot.uuid) - self.set("snapshot", snapshot) - self.set("start_time", monotonic_ns()) - snapshot.do_exit(retval, exc_info, monotonic_ns() - self.get("start_time")) self.collector.push(snapshot) diff --git a/tests/debugging/test_session.py b/tests/debugging/test_session.py index af2988ec49f..ef71b062d70 100644 --- a/tests/debugging/test_session.py +++ b/tests/debugging/test_session.py @@ -1,14 +1,30 @@ import pytest +from ddtrace.debugging._session import DEFAULT_SESSION_LEVEL +from ddtrace.debugging._session import Session from ddtrace.debugging._session import _sessions_from_debug_tag from ddtrace.debugging._session import _sessions_to_debug_tag +@pytest.mark.parametrize( + "tag,sessions", + [ + ("session1", [Session("session1", DEFAULT_SESSION_LEVEL)]), + ("session1:2", [Session("session1", 2)]), + ("session1:1.session2:2", [Session("session1", 1), Session("session2", 2)]), + ("session1.session2", [Session("session1", DEFAULT_SESSION_LEVEL), Session("session2", DEFAULT_SESSION_LEVEL)]), + ], +) +def test_session_parse(tag, sessions): + assert list(_sessions_from_debug_tag(tag)) == sessions + + @pytest.mark.parametrize( "a,b", [ ("session1:1.session2:2", "session1.session2:2"), ("session1:0.session2:2", "session1:0.session2:2"), + ("session1.session2", "session1.session2"), ], ) def test_tag_identity(a, b):