From 6e69c4ddceb3c5edf0283ef4f15f5750bb201dc5 Mon Sep 17 00:00:00 2001 From: Daniel Szoke Date: Wed, 3 Jul 2024 18:06:31 +0200 Subject: [PATCH] feat(tracing): Record lost spans in client reports Also, update existing transport tests so they pass against the changes introduced in this commit. Resolves #3229 --- sentry_sdk/_types.py | 1 + sentry_sdk/client.py | 28 ++++++++++++++++++- sentry_sdk/tracing.py | 4 +-- sentry_sdk/transport.py | 30 ++++++++++++++++++--- tests/conftest.py | 4 +-- tests/profiler/test_transaction_profiler.py | 6 ++--- tests/test_basics.py | 7 ++--- tests/test_monitor.py | 8 +++++- tests/test_transport.py | 23 +++++++++++++--- tests/tracing/test_sampling.py | 14 +++++++--- 10 files changed, 103 insertions(+), 22 deletions(-) diff --git a/sentry_sdk/_types.py b/sentry_sdk/_types.py index bd229977a5..14fa8d08c2 100644 --- a/sentry_sdk/_types.py +++ b/sentry_sdk/_types.py @@ -155,6 +155,7 @@ "profile_chunk", "metric_bucket", "monitor", + "span", ] SessionStatus = Literal["ok", "exited", "crashed", "abnormal"] diff --git a/sentry_sdk/client.py b/sentry_sdk/client.py index 07cd39029b..f93aa935c2 100644 --- a/sentry_sdk/client.py +++ b/sentry_sdk/client.py @@ -448,6 +448,7 @@ def _prepare_event( if scope is not None: is_transaction = event.get("type") == "transaction" + spans_before = len(event.get("spans", [])) event_ = scope.apply_to_event(event, hint, self.options) # one of the event/error processors returned None @@ -457,10 +458,22 @@ def _prepare_event( "event_processor", data_category=("transaction" if is_transaction else "error"), ) + if is_transaction: + self.transport.record_lost_event( + "event_processor", + data_category="span", + quantity=spans_before + 1, # +1 for the transaction itself + ) return None event = event_ + spans_delta = spans_before - len(event.get("spans", [])) + if is_transaction and spans_delta > 0 and self.transport is not None: + self.transport.record_lost_event( + "event_processor", data_category="span", quantity=spans_delta + ) + if ( self.options["attach_stacktrace"] and "exception" not in event @@ -541,14 +554,27 @@ def _prepare_event( and event.get("type") == "transaction" ): new_event = None + spans_before = len(event.get("spans", [])) with capture_internal_exceptions(): new_event = before_send_transaction(event, hint or {}) if new_event is None: logger.info("before send transaction dropped event") if self.transport: self.transport.record_lost_event( - "before_send", data_category="transaction" + reason="before_send", data_category="transaction" + ) + self.transport.record_lost_event( + reason="before_send", + data_category="span", + quantity=spans_before + 1, # +1 for the transaction itself ) + else: + spans_delta = spans_before - len(new_event.get("spans", [])) + if spans_delta > 0 and self.transport is not None: + self.transport.record_lost_event( + reason="before_send", data_category="span", quantity=spans_delta + ) + event = new_event # type: ignore return event diff --git a/sentry_sdk/tracing.py b/sentry_sdk/tracing.py index fe8293d645..43a13b52df 100644 --- a/sentry_sdk/tracing.py +++ b/sentry_sdk/tracing.py @@ -119,11 +119,9 @@ class TransactionKwargs(SpanKwargs, total=False): }, ) - BAGGAGE_HEADER_NAME = "baggage" SENTRY_TRACE_HEADER_NAME = "sentry-trace" - # Transaction source # see https://develop.sentry.dev/sdk/event-payloads/transaction/#transaction-annotations TRANSACTION_SOURCE_CUSTOM = "custom" @@ -858,6 +856,8 @@ def finish(self, hub=None, end_timestamp=None): client.transport.record_lost_event(reason, data_category="transaction") + # Only one span (the transaction itself) is discarded, since we did not record any spans here. + client.transport.record_lost_event(reason, data_category="span") return None if not self.name: diff --git a/sentry_sdk/transport.py b/sentry_sdk/transport.py index 293dfc0e97..63bd1d9fb3 100644 --- a/sentry_sdk/transport.py +++ b/sentry_sdk/transport.py @@ -133,10 +133,23 @@ def record_lost_event( reason, # type: str data_category=None, # type: Optional[EventDataCategory] item=None, # type: Optional[Item] + *, + quantity=1, # type: int ): # type: (...) -> None """This increments a counter for event loss by reason and - data category. + data category by the given positive-int quantity (default 1). + + If an item is provided, the data category and quantity are + extracted from the item, and the values passed for + data_category and quantity are ignored. + + When recording a lost transaction via data_category="transaction", + the calling code should also record the lost spans via this method. + When recording lost spans, `quantity` should be set to the number + of contained spans, plus one for the transaction itself. When + passing an Item containing a transaction via the `item` parameter, + this method automatically records the lost spans. """ return None @@ -224,15 +237,26 @@ def record_lost_event( reason, # type: str data_category=None, # type: Optional[EventDataCategory] item=None, # type: Optional[Item] + *, + quantity=1, # type: int ): # type: (...) -> None if not self.options["send_client_reports"]: return - quantity = 1 if item is not None: data_category = item.data_category - if data_category == "attachment": + quantity = 1 # If an item is provided, we always count it as 1 (except for attachments, handled below). + + if data_category == "transaction": + # Also record the lost spans + event = item.get_transaction_event() or {} + + # +1 for the transaction itself + span_count = len(event.get("spans") or []) + 1 + self.record_lost_event(reason, "span", quantity=span_count) + + elif data_category == "attachment": # quantity of 0 is actually 1 as we do not want to count # empty attachments as actually empty. quantity = len(item.get_bytes()) or 1 diff --git a/tests/conftest.py b/tests/conftest.py index b043a849fb..eada3bdac7 100644 --- a/tests/conftest.py +++ b/tests/conftest.py @@ -253,8 +253,8 @@ def inner(): calls = [] test_client = sentry_sdk.get_client() - def record_lost_event(reason, data_category=None, item=None): - calls.append((reason, data_category, item)) + def record_lost_event(reason, data_category=None, item=None, *, quantity=1): + calls.append((reason, data_category, item, quantity)) monkeypatch.setattr( test_client.transport, "record_lost_event", record_lost_event diff --git a/tests/profiler/test_transaction_profiler.py b/tests/profiler/test_transaction_profiler.py index b30faffc7c..ec506cfa67 100644 --- a/tests/profiler/test_transaction_profiler.py +++ b/tests/profiler/test_transaction_profiler.py @@ -162,7 +162,7 @@ def test_profiles_sample_rate( elif profile_count: assert record_lost_event_calls == [] else: - assert record_lost_event_calls == [("sample_rate", "profile", None)] + assert record_lost_event_calls == [("sample_rate", "profile", None, 1)] @pytest.mark.parametrize( @@ -231,7 +231,7 @@ def test_profiles_sampler( if profile_count: assert record_lost_event_calls == [] else: - assert record_lost_event_calls == [("sample_rate", "profile", None)] + assert record_lost_event_calls == [("sample_rate", "profile", None, 1)] def test_minimum_unique_samples_required( @@ -260,7 +260,7 @@ def test_minimum_unique_samples_required( # because we dont leave any time for the profiler to # take any samples, it should be not be sent assert len(items["profile"]) == 0 - assert record_lost_event_calls == [("insufficient_data", "profile", None)] + assert record_lost_event_calls == [("insufficient_data", "profile", None, 1)] @pytest.mark.forked diff --git a/tests/test_basics.py b/tests/test_basics.py index 391c1c418f..439215e013 100644 --- a/tests/test_basics.py +++ b/tests/test_basics.py @@ -570,7 +570,7 @@ def test_dedupe_event_processor_drop_records_client_report( assert event["level"] == "error" assert "exception" in event - assert lost_event_call == ("event_processor", "error", None) + assert lost_event_call == ("event_processor", "error", None, 1) def test_event_processor_drop_records_client_report( @@ -602,8 +602,9 @@ def foo(event, hint): # Using Counter because order of record_lost_event calls does not matter assert Counter(record_lost_event_calls) == Counter( [ - ("event_processor", "error", None), - ("event_processor", "transaction", None), + ("event_processor", "error", None, 1), + ("event_processor", "transaction", None, 1), + ("event_processor", "span", None, 1), ] ) diff --git a/tests/test_monitor.py b/tests/test_monitor.py index e15b3a7d08..03e415b5cc 100644 --- a/tests/test_monitor.py +++ b/tests/test_monitor.py @@ -1,4 +1,5 @@ import random +from collections import Counter from unittest import mock import sentry_sdk @@ -79,7 +80,12 @@ def test_transaction_uses_downsampled_rate( assert transaction.sampled is False assert transaction.sample_rate == 0.5 - assert record_lost_event_calls == [("backpressure", "transaction", None)] + assert Counter(record_lost_event_calls) == Counter( + [ + ("backpressure", "transaction", None, 1), + ("backpressure", "span", None, 1), + ] + ) def test_monitor_no_thread_on_shutdown_no_errors(sentry_init): diff --git a/tests/test_transport.py b/tests/test_transport.py index 4ed950533f..dfb8b8e25b 100644 --- a/tests/test_transport.py +++ b/tests/test_transport.py @@ -425,12 +425,17 @@ def intercepting_fetch(*args, **kwargs): discarded_events = report["discarded_events"] - assert len(discarded_events) == 2 + assert len(discarded_events) == 3 assert { "category": "transaction", "reason": "ratelimit_backoff", "quantity": 2, } in discarded_events + assert { + "category": "span", + "reason": "ratelimit_backoff", + "quantity": 2, + } in discarded_events assert { "category": "attachment", "reason": "ratelimit_backoff", @@ -454,9 +459,19 @@ def intercepting_fetch(*args, **kwargs): envelope = capturing_server.captured[1].envelope assert envelope.items[0].type == "client_report" report = parse_json(envelope.items[0].get_bytes()) - assert report["discarded_events"] == [ - {"category": "transaction", "reason": "ratelimit_backoff", "quantity": 1}, - ] + + discarded_events = report["discarded_events"] + assert len(discarded_events) == 2 + assert { + "category": "transaction", + "reason": "ratelimit_backoff", + "quantity": 1, + } in discarded_events + assert { + "category": "span", + "reason": "ratelimit_backoff", + "quantity": 1, + } in discarded_events @pytest.mark.parametrize("response_code", [200, 429]) diff --git a/tests/tracing/test_sampling.py b/tests/tracing/test_sampling.py index d9bb6ef4d8..cd43e60d8d 100644 --- a/tests/tracing/test_sampling.py +++ b/tests/tracing/test_sampling.py @@ -264,7 +264,11 @@ def test_warns_and_sets_sampled_to_false_on_invalid_traces_sampler_return_value( "traces_sample_rate,sampled_output,expected_record_lost_event_calls", [ (None, False, []), - (0.0, False, [("sample_rate", "transaction", None)]), + ( + 0.0, + False, + [("sample_rate", "transaction", None, 1), ("sample_rate", "span", None, 1)], + ), (1.0, True, []), ], ) @@ -282,7 +286,7 @@ def test_records_lost_event_only_if_traces_sample_rate_enabled( assert transaction.sampled is sampled_output transaction.finish() - # Use Counter because order of calls does not matter + # Using Counter since order does not matter assert Counter(record_lost_event_calls) == Counter(expected_record_lost_event_calls) @@ -290,7 +294,11 @@ def test_records_lost_event_only_if_traces_sample_rate_enabled( "traces_sampler,sampled_output,expected_record_lost_event_calls", [ (None, False, []), - (lambda _x: 0.0, False, [("sample_rate", "transaction", None)]), + ( + lambda _x: 0.0, + False, + [("sample_rate", "transaction", None, 1), ("sample_rate", "span", None, 1)], + ), (lambda _x: 1.0, True, []), ], )