From b94f31f706d47150b859bb153a99f501a8cf7440 Mon Sep 17 00:00:00 2001 From: Armin Ronacher Date: Tue, 3 Oct 2023 17:40:35 +0200 Subject: [PATCH 1/8] feat(metrics): Allow metrics emission for spans --- sentry_sdk/metrics.py | 24 ++++++++++++++---------- sentry_sdk/tracing.py | 27 +++++++++++++++++++++++++-- tests/test_metrics.py | 36 +++++++++++++++++++++++++++++++++++- 3 files changed, 74 insertions(+), 13 deletions(-) diff --git a/sentry_sdk/metrics.py b/sentry_sdk/metrics.py index debce9755f..9323612e40 100644 --- a/sentry_sdk/metrics.py +++ b/sentry_sdk/metrics.py @@ -5,12 +5,13 @@ import random import time import zlib +from datetime import datetime from functools import wraps, partial from threading import Event, Lock, Thread +import sentry_sdk from sentry_sdk._compat import text_type -from sentry_sdk.hub import Hub -from sentry_sdk.utils import now, nanosecond_time +from sentry_sdk.utils import now, nanosecond_time, to_timestamp from sentry_sdk.envelope import Envelope, Item from sentry_sdk.tracing import ( TRANSACTION_SOURCE_ROUTE, @@ -27,6 +28,7 @@ from typing import Callable from typing import Optional from typing import Tuple + from typing import Union from sentry_sdk._types import BucketKey from sentry_sdk._types import DurationUnit @@ -382,7 +384,7 @@ def add( value, # type: MetricValue unit, # type: MeasurementUnit tags, # type: Optional[MetricTags] - timestamp=None, # type: Optional[float] + timestamp=None, # type: Optional[Union[float, datetime]] ): # type: (...) -> None self._ensure_thread() @@ -392,6 +394,8 @@ def add( if timestamp is None: timestamp = time.time() + elif isinstance(timestamp, datetime): + timestamp = to_timestamp(timestamp) bucket_timestamp = int( (timestamp // self.ROLLUP_IN_SECONDS) * self.ROLLUP_IN_SECONDS @@ -477,7 +481,7 @@ def _serialize_tags( def _get_aggregator_and_update_tags(key, tags): # type: (str, Optional[MetricTags]) -> Tuple[Optional[MetricsAggregator], Optional[MetricTags]] """Returns the current metrics aggregator if there is one.""" - hub = Hub.current + hub = sentry_sdk.Hub.current client = hub.client if client is None or client.metrics_aggregator is None: return None, tags @@ -506,7 +510,7 @@ def incr( value=1.0, # type: float unit="none", # type: MeasurementUnit tags=None, # type: Optional[MetricTags] - timestamp=None, # type: Optional[float] + timestamp=None, # type: Optional[Union[float, datetime]] ): # type: (...) -> None """Increments a counter.""" @@ -520,7 +524,7 @@ def __init__( self, key, # type: str tags, # type: Optional[MetricTags] - timestamp, # type: Optional[float] + timestamp, # type: Optional[Union[float, datetime]] value, # type: Optional[float] unit, # type: DurationUnit ): @@ -572,7 +576,7 @@ def timing( value=None, # type: Optional[float] unit="second", # type: DurationUnit tags=None, # type: Optional[MetricTags] - timestamp=None, # type: Optional[float] + timestamp=None, # type: Optional[Union[float, datetime]] ): # type: (...) -> _Timing """Emits a distribution with the time it takes to run the given code block. @@ -595,7 +599,7 @@ def distribution( value, # type: float unit="none", # type: MeasurementUnit tags=None, # type: Optional[MetricTags] - timestamp=None, # type: Optional[float] + timestamp=None, # type: Optional[Union[float, datetime]] ): # type: (...) -> None """Emits a distribution.""" @@ -609,7 +613,7 @@ def set( value, # type: MetricValue unit="none", # type: MeasurementUnit tags=None, # type: Optional[MetricTags] - timestamp=None, # type: Optional[float] + timestamp=None, # type: Optional[Union[float, datetime]] ): # type: (...) -> None """Emits a set.""" @@ -623,7 +627,7 @@ def gauge( value, # type: float unit="none", # type: MetricValue tags=None, # type: Optional[MetricTags] - timestamp=None, # type: Optional[float] + timestamp=None, # type: Optional[Union[float, datetime]] ): # type: (...) -> None """Emits a gauge.""" diff --git a/sentry_sdk/tracing.py b/sentry_sdk/tracing.py index c646a40a8e..68bbfdcf08 100644 --- a/sentry_sdk/tracing.py +++ b/sentry_sdk/tracing.py @@ -101,6 +101,8 @@ class Span(object): "hub", "_context_manager_state", "_containing_transaction", + "emit_metric", + "metric_name", ) def __new__(cls, **kwargs): @@ -130,7 +132,9 @@ def __init__( status=None, # type: Optional[str] transaction=None, # type: Optional[str] # deprecated containing_transaction=None, # type: Optional[Transaction] - start_timestamp=None, # type: Optional[datetime] + start_timestamp=None, # type: Optional[Union[datetime, float]] + emit_metric=False, # type: bool + metric_name=None, # type: Optional[str] ): # type: (...) -> None self.trace_id = trace_id or uuid.uuid4().hex @@ -145,7 +149,11 @@ def __init__( self._tags = {} # type: Dict[str, str] self._data = {} # type: Dict[str, Any] self._containing_transaction = containing_transaction - self.start_timestamp = start_timestamp or datetime.utcnow() + if start_timestamp is None: + start_timestamp = datetime.utcnow() + elif isinstance(start_timestamp, float): + start_timestamp = datetime.utcfromtimestamp(start_timestamp) + self.start_timestamp = start_timestamp try: # profiling depends on this value and requires that # it is measured in nanoseconds @@ -156,6 +164,9 @@ def __init__( #: End timestamp of span self.timestamp = None # type: Optional[datetime] + self.emit_metric = emit_metric + self.metric_name = metric_name + self._span_recorder = None # type: Optional[_SpanRecorder] # TODO this should really live on the Transaction class rather than the Span @@ -471,6 +482,17 @@ def finish(self, hub=None, end_timestamp=None): except AttributeError: self.timestamp = datetime.utcnow() + # If we were asked to emit a metric, do so now. We always record + # that timing in seconds. + if self.emit_metric: + metrics.timing( + self.metric_name or ("span." + (self.op or "generic")), + timestamp=self.start_timestamp, + value=(self.timestamp - self.start_timestamp).total_seconds(), + unit="second", + tags=self._tags, + ) + maybe_create_breadcrumbs_from_span(hub, self) return None @@ -995,3 +1017,4 @@ async def my_async_function(): has_tracing_enabled, maybe_create_breadcrumbs_from_span, ) +from sentry_sdk import metrics \ No newline at end of file diff --git a/tests/test_metrics.py b/tests/test_metrics.py index 145a1e94cc..dc18e58480 100644 --- a/tests/test_metrics.py +++ b/tests/test_metrics.py @@ -2,7 +2,7 @@ import time -from sentry_sdk import Hub, metrics, push_scope +from sentry_sdk import Hub, metrics, push_scope, start_span def parse_metrics(bytes): @@ -181,6 +181,40 @@ def test_timing_basic(sentry_init, capture_envelopes): } +def test_timing_via_span(sentry_init, capture_envelopes): + sentry_init( + release="fun-release@1.0.0", + environment="not-fun-env", + _experiments={"enable_metrics": True}, + ) + ts = time.time() + envelopes = capture_envelopes() + + with start_span( + op="whatever", start_timestamp=ts, emit_metric=True + ) as span: + span.set_tag("blub", "blah") + time.sleep(0.1) + Hub.current.flush() + + (envelope,) = envelopes + + assert len(envelope.items) == 1 + assert envelope.items[0].headers["type"] == "statsd" + m = parse_metrics(envelope.items[0].payload.get_bytes()) + + assert len(m) == 1 + assert m[0][1] == "span.whatever@second" + assert m[0][2] == "d" + assert len(m[0][3]) == 1 + assert float(m[0][3][0]) >= 0.1 + assert m[0][4] == { + "blub": "blah", + "release": "fun-release@1.0.0", + "environment": "not-fun-env", + } + + def test_distribution(sentry_init, capture_envelopes): sentry_init( release="fun-release@1.0.0", From 87cc0433c1a033ecf670dcebab9f3c36ab466789 Mon Sep 17 00:00:00 2001 From: Armin Ronacher Date: Tue, 3 Oct 2023 17:45:47 +0200 Subject: [PATCH 2/8] woop woop --- sentry_sdk/tracing.py | 3 ++- 1 file changed, 2 insertions(+), 1 deletion(-) diff --git a/sentry_sdk/tracing.py b/sentry_sdk/tracing.py index 68bbfdcf08..7f497028f5 100644 --- a/sentry_sdk/tracing.py +++ b/sentry_sdk/tracing.py @@ -20,6 +20,7 @@ from typing import List from typing import Optional from typing import Tuple + from typing import Union import sentry_sdk.profiler from sentry_sdk._types import Event, MeasurementUnit, SamplingContext @@ -1017,4 +1018,4 @@ async def my_async_function(): has_tracing_enabled, maybe_create_breadcrumbs_from_span, ) -from sentry_sdk import metrics \ No newline at end of file +from sentry_sdk import metrics From fb8618bcfd34b694da49d157455d1d05038ff47f Mon Sep 17 00:00:00 2001 From: Armin Ronacher Date: Tue, 10 Oct 2023 13:29:47 +0200 Subject: [PATCH 3/8] Require explicit name for span metric --- sentry_sdk/tracing.py | 17 +++++++---------- tests/test_metrics.py | 4 ++-- 2 files changed, 9 insertions(+), 12 deletions(-) diff --git a/sentry_sdk/tracing.py b/sentry_sdk/tracing.py index 633b714d73..dda44ee3f4 100644 --- a/sentry_sdk/tracing.py +++ b/sentry_sdk/tracing.py @@ -1,7 +1,7 @@ import uuid import random -from datetime import timedelta +from datetime import datetime, timedelta import sentry_sdk from sentry_sdk.consts import INSTRUMENTER @@ -14,7 +14,6 @@ if TYPE_CHECKING: import typing - from datetime import datetime from typing import Any from typing import Dict from typing import Iterator @@ -103,8 +102,7 @@ class Span(object): "hub", "_context_manager_state", "_containing_transaction", - "emit_metric", - "metric_name", + "metric", ) def __new__(cls, **kwargs): @@ -135,8 +133,7 @@ def __init__( transaction=None, # type: Optional[str] # deprecated containing_transaction=None, # type: Optional[Transaction] start_timestamp=None, # type: Optional[Union[datetime, float]] - emit_metric=False, # type: bool - metric_name=None, # type: Optional[str] + metric=None, # type: Optional[str] ): # type: (...) -> None self.trace_id = trace_id or uuid.uuid4().hex @@ -166,8 +163,8 @@ def __init__( #: End timestamp of span self.timestamp = None # type: Optional[datetime] - self.emit_metric = emit_metric - self.metric_name = metric_name + #: The name of the metric to emit if there is one. + self.metric = metric self._span_recorder = None # type: Optional[_SpanRecorder] @@ -486,9 +483,9 @@ def finish(self, hub=None, end_timestamp=None): # If we were asked to emit a metric, do so now. We always record # that timing in seconds. - if self.emit_metric: + if self.metric is not None: metrics.timing( - self.metric_name or ("span." + (self.op or "generic")), + self.metric, timestamp=self.start_timestamp, value=(self.timestamp - self.start_timestamp).total_seconds(), unit="second", diff --git a/tests/test_metrics.py b/tests/test_metrics.py index 71f14f4aac..a82180eb74 100644 --- a/tests/test_metrics.py +++ b/tests/test_metrics.py @@ -191,7 +191,7 @@ def test_timing_via_span(sentry_init, capture_envelopes): envelopes = capture_envelopes() with start_span( - op="whatever", start_timestamp=ts, emit_metric=True + op="whatever", start_timestamp=ts, metric="my.span" ) as span: span.set_tag("blub", "blah") time.sleep(0.1) @@ -204,7 +204,7 @@ def test_timing_via_span(sentry_init, capture_envelopes): m = parse_metrics(envelope.items[0].payload.get_bytes()) assert len(m) == 1 - assert m[0][1] == "span.whatever@second" + assert m[0][1] == "my.span@second" assert m[0][2] == "d" assert len(m[0][3]) == 1 assert float(m[0][3][0]) >= 0.1 From 4a31a92ce85bb00c621abc117f1d990a1a7de442 Mon Sep 17 00:00:00 2001 From: Armin Ronacher Date: Tue, 10 Oct 2023 13:31:56 +0200 Subject: [PATCH 4/8] Blacken --- tests/test_metrics.py | 4 +--- 1 file changed, 1 insertion(+), 3 deletions(-) diff --git a/tests/test_metrics.py b/tests/test_metrics.py index a82180eb74..d4678c73a5 100644 --- a/tests/test_metrics.py +++ b/tests/test_metrics.py @@ -190,9 +190,7 @@ def test_timing_via_span(sentry_init, capture_envelopes): ts = time.time() envelopes = capture_envelopes() - with start_span( - op="whatever", start_timestamp=ts, metric="my.span" - ) as span: + with start_span(op="whatever", start_timestamp=ts, metric="my.span") as span: span.set_tag("blub", "blah") time.sleep(0.1) Hub.current.flush() From 8167297c1ab334981ed69daf1179106eb93e1cb0 Mon Sep 17 00:00:00 2001 From: Armin Ronacher Date: Mon, 23 Oct 2023 13:26:10 +0200 Subject: [PATCH 5/8] Change end_timestamp to also support floats --- sentry_sdk/tracing.py | 4 +++- 1 file changed, 3 insertions(+), 1 deletion(-) diff --git a/sentry_sdk/tracing.py b/sentry_sdk/tracing.py index dda44ee3f4..0f907ebd1e 100644 --- a/sentry_sdk/tracing.py +++ b/sentry_sdk/tracing.py @@ -448,7 +448,7 @@ def is_success(self): return self.status == "ok" def finish(self, hub=None, end_timestamp=None): - # type: (Optional[sentry_sdk.Hub], Optional[datetime]) -> Optional[str] + # type: (Optional[sentry_sdk.Hub], Optional[Union[float, datetime]]) -> Optional[str] # Note: would be type: (Optional[sentry_sdk.Hub]) -> None, but that leads # to incompatible return types for Span.finish and Transaction.finish. """Sets the end timestamp of the span. @@ -472,6 +472,8 @@ def finish(self, hub=None, end_timestamp=None): try: if end_timestamp: + if isinstance(end_timestamp, float): + end_timestamp = datetime.utcfromtimestamp(end_timestamp) self.timestamp = end_timestamp else: elapsed = nanosecond_time() - self._start_timestamp_monotonic_ns From 83b4c4f6244daf5139403bc80c15a4464c5d878b Mon Sep 17 00:00:00 2001 From: Armin Ronacher Date: Mon, 23 Oct 2023 13:38:38 +0200 Subject: [PATCH 6/8] Fix typing --- sentry_sdk/tracing.py | 4 ++-- 1 file changed, 2 insertions(+), 2 deletions(-) diff --git a/sentry_sdk/tracing.py b/sentry_sdk/tracing.py index 0f907ebd1e..88b0750dd5 100644 --- a/sentry_sdk/tracing.py +++ b/sentry_sdk/tracing.py @@ -649,7 +649,7 @@ def containing_transaction(self): return self def finish(self, hub=None, end_timestamp=None): - # type: (Optional[sentry_sdk.Hub], Optional[datetime]) -> Optional[str] + # type: (Optional[sentry_sdk.Hub], Optional[Union[float, datetime]]) -> Optional[str] """Finishes the transaction and sends it to Sentry. All finished spans in the transaction will also be sent to Sentry. @@ -957,7 +957,7 @@ def get_trace_context(self): return {} def finish(self, hub=None, end_timestamp=None): - # type: (Optional[sentry_sdk.Hub], Optional[datetime]) -> Optional[str] + # type: (Optional[sentry_sdk.Hub], Optional[Union[float, datetime]]) -> Optional[str] pass def set_measurement(self, name, value, unit=""): From 6a32b836219db6e2fa94af7c8fc107f93b86ecf7 Mon Sep 17 00:00:00 2001 From: Armin Ronacher Date: Mon, 6 Nov 2023 15:41:50 +0100 Subject: [PATCH 7/8] Remove metric attachments to span for now --- sentry_sdk/tracing.py | 17 ----------------- tests/test_metrics.py | 32 -------------------------------- 2 files changed, 49 deletions(-) diff --git a/sentry_sdk/tracing.py b/sentry_sdk/tracing.py index 88b0750dd5..3bdb46f6f6 100644 --- a/sentry_sdk/tracing.py +++ b/sentry_sdk/tracing.py @@ -102,7 +102,6 @@ class Span(object): "hub", "_context_manager_state", "_containing_transaction", - "metric", ) def __new__(cls, **kwargs): @@ -133,7 +132,6 @@ def __init__( transaction=None, # type: Optional[str] # deprecated containing_transaction=None, # type: Optional[Transaction] start_timestamp=None, # type: Optional[Union[datetime, float]] - metric=None, # type: Optional[str] ): # type: (...) -> None self.trace_id = trace_id or uuid.uuid4().hex @@ -163,9 +161,6 @@ def __init__( #: End timestamp of span self.timestamp = None # type: Optional[datetime] - #: The name of the metric to emit if there is one. - self.metric = metric - self._span_recorder = None # type: Optional[_SpanRecorder] # TODO this should really live on the Transaction class rather than the Span @@ -483,17 +478,6 @@ def finish(self, hub=None, end_timestamp=None): except AttributeError: self.timestamp = datetime_utcnow() - # If we were asked to emit a metric, do so now. We always record - # that timing in seconds. - if self.metric is not None: - metrics.timing( - self.metric, - timestamp=self.start_timestamp, - value=(self.timestamp - self.start_timestamp).total_seconds(), - unit="second", - tags=self._tags, - ) - maybe_create_breadcrumbs_from_span(hub, self) return None @@ -1018,4 +1002,3 @@ async def my_async_function(): has_tracing_enabled, maybe_create_breadcrumbs_from_span, ) -from sentry_sdk import metrics diff --git a/tests/test_metrics.py b/tests/test_metrics.py index d4678c73a5..a7bcfc3143 100644 --- a/tests/test_metrics.py +++ b/tests/test_metrics.py @@ -181,38 +181,6 @@ def test_timing_basic(sentry_init, capture_envelopes): } -def test_timing_via_span(sentry_init, capture_envelopes): - sentry_init( - release="fun-release@1.0.0", - environment="not-fun-env", - _experiments={"enable_metrics": True}, - ) - ts = time.time() - envelopes = capture_envelopes() - - with start_span(op="whatever", start_timestamp=ts, metric="my.span") as span: - span.set_tag("blub", "blah") - time.sleep(0.1) - Hub.current.flush() - - (envelope,) = envelopes - - assert len(envelope.items) == 1 - assert envelope.items[0].headers["type"] == "statsd" - m = parse_metrics(envelope.items[0].payload.get_bytes()) - - assert len(m) == 1 - assert m[0][1] == "my.span@second" - assert m[0][2] == "d" - assert len(m[0][3]) == 1 - assert float(m[0][3][0]) >= 0.1 - assert m[0][4] == { - "blub": "blah", - "release": "fun-release@1.0.0", - "environment": "not-fun-env", - } - - def test_distribution(sentry_init, capture_envelopes): sentry_init( release="fun-release@1.0.0", From c387b53cd65aad85f78547ba705e315dc41b1d33 Mon Sep 17 00:00:00 2001 From: Armin Ronacher Date: Mon, 6 Nov 2023 15:45:52 +0100 Subject: [PATCH 8/8] Make linter happy --- tests/test_metrics.py | 2 +- 1 file changed, 1 insertion(+), 1 deletion(-) diff --git a/tests/test_metrics.py b/tests/test_metrics.py index a7bcfc3143..7211881c32 100644 --- a/tests/test_metrics.py +++ b/tests/test_metrics.py @@ -2,7 +2,7 @@ import time -from sentry_sdk import Hub, metrics, push_scope, start_span +from sentry_sdk import Hub, metrics, push_scope def parse_metrics(bytes):