From edf4a580b66bbf5bed029a78a23068ef50ba16fa Mon Sep 17 00:00:00 2001 From: Stefano Date: Mon, 1 Jul 2024 16:02:47 +0200 Subject: [PATCH] Report dropped spans (#3528) * added span data category for client reports * added dropped span report when recording lostEnvelopeItem * added dropped span report on beforeSend and eventProcessor filtering (SentryClient) and backpressure and sampleRate (Hub) --- CHANGELOG.md | 4 + sentry/api/sentry.api | 4 + .../src/main/java/io/sentry/DataCategory.java | 1 + sentry/src/main/java/io/sentry/Hub.java | 12 +++ .../src/main/java/io/sentry/SentryClient.java | 39 ++++++++++ .../clientreport/ClientReportRecorder.java | 25 +++++- .../clientreport/IClientReportRecorder.java | 2 + .../NoOpClientReportRecorder.java | 6 ++ sentry/src/test/java/io/sentry/HubTest.kt | 14 +++- .../test/java/io/sentry/SentryClientTest.kt | 78 +++++++++++++++++-- .../sentry/clientreport/ClientReportTest.kt | 31 +++++++- 11 files changed, 203 insertions(+), 13 deletions(-) diff --git a/CHANGELOG.md b/CHANGELOG.md index f4a6524f4b..41e2bac3fb 100644 --- a/CHANGELOG.md +++ b/CHANGELOG.md @@ -2,6 +2,10 @@ ## Unreleased +### Features + +- Report dropped spans ([#3528](https://github.com/getsentry/sentry-java/pull/3528)) + ### Fixes - Fix duplicate session start for React Native ([#3504](https://github.com/getsentry/sentry-java/pull/3504)) diff --git a/sentry/api/sentry.api b/sentry/api/sentry.api index 01f1d2a1d8..8c25105d82 100644 --- a/sentry/api/sentry.api +++ b/sentry/api/sentry.api @@ -229,6 +229,7 @@ public final class io/sentry/DataCategory : java/lang/Enum { public static final field Profile Lio/sentry/DataCategory; public static final field Security Lio/sentry/DataCategory; public static final field Session Lio/sentry/DataCategory; + public static final field Span Lio/sentry/DataCategory; public static final field Transaction Lio/sentry/DataCategory; public static final field Unknown Lio/sentry/DataCategory; public static final field UserReport Lio/sentry/DataCategory; @@ -3142,6 +3143,7 @@ public final class io/sentry/clientreport/ClientReportRecorder : io/sentry/clien public fun recordLostEnvelope (Lio/sentry/clientreport/DiscardReason;Lio/sentry/SentryEnvelope;)V public fun recordLostEnvelopeItem (Lio/sentry/clientreport/DiscardReason;Lio/sentry/SentryEnvelopeItem;)V public fun recordLostEvent (Lio/sentry/clientreport/DiscardReason;Lio/sentry/DataCategory;)V + public fun recordLostEvent (Lio/sentry/clientreport/DiscardReason;Lio/sentry/DataCategory;J)V } public final class io/sentry/clientreport/DiscardReason : java/lang/Enum { @@ -3187,6 +3189,7 @@ public abstract interface class io/sentry/clientreport/IClientReportRecorder { public abstract fun recordLostEnvelope (Lio/sentry/clientreport/DiscardReason;Lio/sentry/SentryEnvelope;)V public abstract fun recordLostEnvelopeItem (Lio/sentry/clientreport/DiscardReason;Lio/sentry/SentryEnvelopeItem;)V public abstract fun recordLostEvent (Lio/sentry/clientreport/DiscardReason;Lio/sentry/DataCategory;)V + public abstract fun recordLostEvent (Lio/sentry/clientreport/DiscardReason;Lio/sentry/DataCategory;J)V } public abstract interface class io/sentry/clientreport/IClientReportStorage { @@ -3200,6 +3203,7 @@ public final class io/sentry/clientreport/NoOpClientReportRecorder : io/sentry/c public fun recordLostEnvelope (Lio/sentry/clientreport/DiscardReason;Lio/sentry/SentryEnvelope;)V public fun recordLostEnvelopeItem (Lio/sentry/clientreport/DiscardReason;Lio/sentry/SentryEnvelopeItem;)V public fun recordLostEvent (Lio/sentry/clientreport/DiscardReason;Lio/sentry/DataCategory;)V + public fun recordLostEvent (Lio/sentry/clientreport/DiscardReason;Lio/sentry/DataCategory;J)V } public abstract interface class io/sentry/config/PropertiesProvider { diff --git a/sentry/src/main/java/io/sentry/DataCategory.java b/sentry/src/main/java/io/sentry/DataCategory.java index c3d6520987..a4eafc2bb5 100644 --- a/sentry/src/main/java/io/sentry/DataCategory.java +++ b/sentry/src/main/java/io/sentry/DataCategory.java @@ -14,6 +14,7 @@ public enum DataCategory { Profile("profile"), MetricBucket("metric_bucket"), Transaction("transaction"), + Span("span"), Security("security"), UserReport("user_report"), Unknown("unknown"); diff --git a/sentry/src/main/java/io/sentry/Hub.java b/sentry/src/main/java/io/sentry/Hub.java index 6b6da88f09..b993b84ebc 100644 --- a/sentry/src/main/java/io/sentry/Hub.java +++ b/sentry/src/main/java/io/sentry/Hub.java @@ -686,10 +686,22 @@ public void flush(long timeoutMillis) { options .getClientReportRecorder() .recordLostEvent(DiscardReason.BACKPRESSURE, DataCategory.Transaction); + options + .getClientReportRecorder() + .recordLostEvent( + DiscardReason.BACKPRESSURE, + DataCategory.Span, + transaction.getSpans().size() + 1); } else { options .getClientReportRecorder() .recordLostEvent(DiscardReason.SAMPLE_RATE, DataCategory.Transaction); + options + .getClientReportRecorder() + .recordLostEvent( + DiscardReason.SAMPLE_RATE, + DataCategory.Span, + transaction.getSpans().size() + 1); } } else { StackItem item = null; diff --git a/sentry/src/main/java/io/sentry/SentryClient.java b/sentry/src/main/java/io/sentry/SentryClient.java index ea70371722..31d4377dbb 100644 --- a/sentry/src/main/java/io/sentry/SentryClient.java +++ b/sentry/src/main/java/io/sentry/SentryClient.java @@ -412,6 +412,7 @@ private SentryTransaction processTransaction( final @NotNull Hint hint, final @NotNull List eventProcessors) { for (final EventProcessor processor : eventProcessors) { + final int spanCountBeforeProcessor = transaction.getSpans().size(); try { transaction = processor.process(transaction, hint); } catch (Throwable e) { @@ -423,6 +424,7 @@ private SentryTransaction processTransaction( "An exception occurred while processing transaction by processor: %s", processor.getClass().getName()); } + final int spanCountAfterProcessor = transaction == null ? 0 : transaction.getSpans().size(); if (transaction == null) { options @@ -434,7 +436,25 @@ private SentryTransaction processTransaction( options .getClientReportRecorder() .recordLostEvent(DiscardReason.EVENT_PROCESSOR, DataCategory.Transaction); + // If we drop a transaction, we are also dropping all its spans (+1 for the root span) + options + .getClientReportRecorder() + .recordLostEvent( + DiscardReason.EVENT_PROCESSOR, DataCategory.Span, spanCountBeforeProcessor + 1); break; + } else if (spanCountAfterProcessor < spanCountBeforeProcessor) { + // If the callback removed some spans, we report it + final int droppedSpanCount = spanCountBeforeProcessor - spanCountAfterProcessor; + options + .getLogger() + .log( + SentryLevel.DEBUG, + "%d spans were dropped by a processor: %s", + droppedSpanCount, + processor.getClass().getName()); + options + .getClientReportRecorder() + .recordLostEvent(DiscardReason.EVENT_PROCESSOR, DataCategory.Span, droppedSpanCount); } } return transaction; @@ -666,7 +686,9 @@ public void captureSession(final @NotNull Session session, final @Nullable Hint return SentryId.EMPTY_ID; } + final int spanCountBeforeCallback = transaction.getSpans().size(); transaction = executeBeforeSendTransaction(transaction, hint); + final int spanCountAfterCallback = transaction == null ? 0 : transaction.getSpans().size(); if (transaction == null) { options @@ -675,7 +697,24 @@ public void captureSession(final @NotNull Session session, final @Nullable Hint options .getClientReportRecorder() .recordLostEvent(DiscardReason.BEFORE_SEND, DataCategory.Transaction); + // If we drop a transaction, we are also dropping all its spans (+1 for the root span) + options + .getClientReportRecorder() + .recordLostEvent( + DiscardReason.BEFORE_SEND, DataCategory.Span, spanCountBeforeCallback + 1); return SentryId.EMPTY_ID; + } else if (spanCountAfterCallback < spanCountBeforeCallback) { + // If the callback removed some spans, we report it + final int droppedSpanCount = spanCountBeforeCallback - spanCountAfterCallback; + options + .getLogger() + .log( + SentryLevel.DEBUG, + "%d spans were dropped by beforeSendTransaction.", + droppedSpanCount); + options + .getClientReportRecorder() + .recordLostEvent(DiscardReason.BEFORE_SEND, DataCategory.Span, droppedSpanCount); } try { diff --git a/sentry/src/main/java/io/sentry/clientreport/ClientReportRecorder.java b/sentry/src/main/java/io/sentry/clientreport/ClientReportRecorder.java index f51287d7d9..796a17cb3c 100644 --- a/sentry/src/main/java/io/sentry/clientreport/ClientReportRecorder.java +++ b/sentry/src/main/java/io/sentry/clientreport/ClientReportRecorder.java @@ -7,6 +7,8 @@ import io.sentry.SentryItemType; import io.sentry.SentryLevel; import io.sentry.SentryOptions; +import io.sentry.protocol.SentrySpan; +import io.sentry.protocol.SentryTransaction; import java.util.ArrayList; import java.util.Date; import java.util.List; @@ -84,8 +86,19 @@ public void recordLostEnvelopeItem( .log(SentryLevel.ERROR, "Unable to restore counts from previous client report."); } } else { - recordLostEventInternal( - reason.getReason(), categoryFromItemType(itemType).getCategory(), 1L); + final @NotNull DataCategory itemCategory = categoryFromItemType(itemType); + if (itemCategory.equals(DataCategory.Transaction)) { + final @Nullable SentryTransaction transaction = + envelopeItem.getTransaction(options.getSerializer()); + if (transaction != null) { + final @NotNull List spans = transaction.getSpans(); + // When a transaction is dropped, we also record its spans as dropped plus one, + // since Relay extracts an additional span from the transaction. + recordLostEventInternal( + reason.getReason(), DataCategory.Span.getCategory(), spans.size() + 1L); + } + } + recordLostEventInternal(reason.getReason(), itemCategory.getCategory(), 1L); } } catch (Throwable e) { options.getLogger().log(SentryLevel.ERROR, e, "Unable to record lost envelope item."); @@ -94,8 +107,14 @@ public void recordLostEnvelopeItem( @Override public void recordLostEvent(@NotNull DiscardReason reason, @NotNull DataCategory category) { + recordLostEvent(reason, category, 1); + } + + @Override + public void recordLostEvent( + @NotNull DiscardReason reason, @NotNull DataCategory category, long count) { try { - recordLostEventInternal(reason.getReason(), category.getCategory(), 1L); + recordLostEventInternal(reason.getReason(), category.getCategory(), count); } catch (Throwable e) { options.getLogger().log(SentryLevel.ERROR, e, "Unable to record lost event."); } diff --git a/sentry/src/main/java/io/sentry/clientreport/IClientReportRecorder.java b/sentry/src/main/java/io/sentry/clientreport/IClientReportRecorder.java index 72e23f5b8f..c3c2d2e9f6 100644 --- a/sentry/src/main/java/io/sentry/clientreport/IClientReportRecorder.java +++ b/sentry/src/main/java/io/sentry/clientreport/IClientReportRecorder.java @@ -16,6 +16,8 @@ void recordLostEnvelopeItem( void recordLostEvent(@NotNull DiscardReason reason, @NotNull DataCategory category); + void recordLostEvent(@NotNull DiscardReason reason, @NotNull DataCategory category, long count); + @NotNull SentryEnvelope attachReportToEnvelope(@NotNull SentryEnvelope envelope); } diff --git a/sentry/src/main/java/io/sentry/clientreport/NoOpClientReportRecorder.java b/sentry/src/main/java/io/sentry/clientreport/NoOpClientReportRecorder.java index 64aa957680..360468e19d 100644 --- a/sentry/src/main/java/io/sentry/clientreport/NoOpClientReportRecorder.java +++ b/sentry/src/main/java/io/sentry/clientreport/NoOpClientReportRecorder.java @@ -25,6 +25,12 @@ public void recordLostEvent(@NotNull DiscardReason reason, @NotNull DataCategory // do nothing } + @Override + public void recordLostEvent( + @NotNull DiscardReason reason, @NotNull DataCategory category, long count) { + // do nothing + } + @Override public @NotNull SentryEnvelope attachReportToEnvelope(@NotNull SentryEnvelope envelope) { return envelope; diff --git a/sentry/src/test/java/io/sentry/HubTest.kt b/sentry/src/test/java/io/sentry/HubTest.kt index 8fac963e70..cb66736e24 100644 --- a/sentry/src/test/java/io/sentry/HubTest.kt +++ b/sentry/src/test/java/io/sentry/HubTest.kt @@ -1450,11 +1450,16 @@ class HubTest { sut.bindClient(mockClient) val sentryTracer = SentryTracer(TransactionContext("name", "op", TracesSamplingDecision(false)), sut) + // Unsampled spans are not added to the transaction, so they are not recorded + sentryTracer.startChild("dropped span", "span 1").finish() sentryTracer.finish() assertClientReport( options.clientReportRecorder, - listOf(DiscardedEvent(DiscardReason.SAMPLE_RATE.reason, DataCategory.Transaction.category, 1)) + listOf( + DiscardedEvent(DiscardReason.SAMPLE_RATE.reason, DataCategory.Transaction.category, 1), + DiscardedEvent(DiscardReason.SAMPLE_RATE.reason, DataCategory.Span.category, 1) + ) ) } @@ -1472,11 +1477,16 @@ class HubTest { whenever(mockBackpressureMonitor.downsampleFactor).thenReturn(1) val sentryTracer = SentryTracer(TransactionContext("name", "op", TracesSamplingDecision(false)), sut) + // Unsampled spans are not added to the transaction, so they are not recorded + sentryTracer.startChild("dropped span", "span 1").finish() sentryTracer.finish() assertClientReport( options.clientReportRecorder, - listOf(DiscardedEvent(DiscardReason.BACKPRESSURE.reason, DataCategory.Transaction.category, 1)) + listOf( + DiscardedEvent(DiscardReason.BACKPRESSURE.reason, DataCategory.Transaction.category, 1), + DiscardedEvent(DiscardReason.BACKPRESSURE.reason, DataCategory.Span.category, 1) + ) ) } //endregion diff --git a/sentry/src/test/java/io/sentry/SentryClientTest.kt b/sentry/src/test/java/io/sentry/SentryClientTest.kt index de540bf90c..f70d7e0584 100644 --- a/sentry/src/test/java/io/sentry/SentryClientTest.kt +++ b/sentry/src/test/java/io/sentry/SentryClientTest.kt @@ -89,7 +89,8 @@ class SentryClientTest { init { whenever(factory.create(any(), any())).thenReturn(transport) whenever(hub.options).thenReturn(sentryOptions) - sentryTracer = SentryTracer(TransactionContext("a-transaction", "op"), hub) + sentryTracer = SentryTracer(TransactionContext("a-transaction", "op", TracesSamplingDecision(true)), hub) + sentryTracer.startChild("a-span", "span 1").finish() } var attachment = Attachment("hello".toByteArray(), "hello.txt", "text/plain", true) @@ -807,7 +808,10 @@ class SentryClientTest { assertClientReport( fixture.sentryOptions.clientReportRecorder, - listOf(DiscardedEvent(DiscardReason.EVENT_PROCESSOR.reason, DataCategory.Transaction.category, 1)) + listOf( + DiscardedEvent(DiscardReason.EVENT_PROCESSOR.reason, DataCategory.Transaction.category, 1), + DiscardedEvent(DiscardReason.EVENT_PROCESSOR.reason, DataCategory.Span.category, 2) + ) ) } @@ -893,7 +897,10 @@ class SentryClientTest { assertClientReport( fixture.sentryOptions.clientReportRecorder, - listOf(DiscardedEvent(DiscardReason.BEFORE_SEND.reason, DataCategory.Transaction.category, 1)) + listOf( + DiscardedEvent(DiscardReason.BEFORE_SEND.reason, DataCategory.Transaction.category, 1), + DiscardedEvent(DiscardReason.BEFORE_SEND.reason, DataCategory.Span.category, 2) + ) ) } @@ -909,7 +916,36 @@ class SentryClientTest { assertClientReport( fixture.sentryOptions.clientReportRecorder, - listOf(DiscardedEvent(DiscardReason.EVENT_PROCESSOR.reason, DataCategory.Transaction.category, 1)) + listOf( + DiscardedEvent(DiscardReason.EVENT_PROCESSOR.reason, DataCategory.Transaction.category, 1), + DiscardedEvent(DiscardReason.EVENT_PROCESSOR.reason, DataCategory.Span.category, 2) + ) + ) + } + + @Test + fun `span dropped by event processor is recorded`() { + fixture.sentryTracer.startChild("dropped span", "span1").finish() + fixture.sentryTracer.startChild("dropped span", "span2").finish() + val transaction = SentryTransaction(fixture.sentryTracer) + val scope = createScope() + scope.addEventProcessor(object : EventProcessor { + override fun process(transaction: SentryTransaction, hint: Hint): SentryTransaction? { + // we are removing span1 and a-span from the fixture + transaction.spans.removeIf { it.description != "span2" } + return transaction + } + }) + + fixture.getSut().captureTransaction(transaction, scope, null) + + verify(fixture.transport).send(any(), anyOrNull()) + + assertClientReport( + fixture.sentryOptions.clientReportRecorder, + listOf( + DiscardedEvent(DiscardReason.EVENT_PROCESSOR.reason, DataCategory.Span.category, 2) + ) ) } @@ -969,7 +1005,10 @@ class SentryClientTest { assertClientReport( fixture.sentryOptions.clientReportRecorder, - listOf(DiscardedEvent(DiscardReason.BEFORE_SEND.reason, DataCategory.Transaction.category, 1)) + listOf( + DiscardedEvent(DiscardReason.BEFORE_SEND.reason, DataCategory.Transaction.category, 1), + DiscardedEvent(DiscardReason.BEFORE_SEND.reason, DataCategory.Span.category, 2) + ) ) } @@ -1007,7 +1046,34 @@ class SentryClientTest { assertClientReport( fixture.sentryOptions.clientReportRecorder, - listOf(DiscardedEvent(DiscardReason.BEFORE_SEND.reason, DataCategory.Transaction.category, 1)) + listOf( + DiscardedEvent(DiscardReason.BEFORE_SEND.reason, DataCategory.Transaction.category, 1), + DiscardedEvent(DiscardReason.BEFORE_SEND.reason, DataCategory.Span.category, 2) + ) + ) + } + + @Test + fun `when beforeSendTransaction drops a span, dropped span is recorded`() { + fixture.sentryTracer.startChild("dropped span", "span1").finish() + fixture.sentryTracer.startChild("dropped span", "span2").finish() + fixture.sentryOptions.setBeforeSendTransaction { t: SentryTransaction, _: Any? -> + t.apply { + // we are removing span1 and a-span from the fixture + spans.removeIf { it.description != "span2" } + } + } + + val transaction = SentryTransaction(fixture.sentryTracer) + fixture.getSut().captureTransaction(transaction, fixture.sentryTracer.traceContext()) + + verify(fixture.transport).send(any(), anyOrNull()) + + assertClientReport( + fixture.sentryOptions.clientReportRecorder, + listOf( + DiscardedEvent(DiscardReason.BEFORE_SEND.reason, DataCategory.Span.category, 2) + ) ) } diff --git a/sentry/src/test/java/io/sentry/clientreport/ClientReportTest.kt b/sentry/src/test/java/io/sentry/clientreport/ClientReportTest.kt index 527e1b5531..c06e8da1f6 100644 --- a/sentry/src/test/java/io/sentry/clientreport/ClientReportTest.kt +++ b/sentry/src/test/java/io/sentry/clientreport/ClientReportTest.kt @@ -18,6 +18,7 @@ import io.sentry.SentryEvent import io.sentry.SentryOptions import io.sentry.SentryTracer import io.sentry.Session +import io.sentry.TracesSamplingDecision import io.sentry.TransactionContext import io.sentry.UncaughtExceptionHandlerIntegration.UncaughtExceptionHint import io.sentry.UserFeedback @@ -63,6 +64,7 @@ class ClientReportTest { val envelope = testHelper.newEnvelope( SentryEnvelopeItem.fromClientReport(opts.serializer, lostClientReport), + SentryEnvelopeItem.fromEvent(opts.serializer, SentryTransaction(transaction)), SentryEnvelopeItem.fromEvent(opts.serializer, SentryEvent()), SentryEnvelopeItem.fromSession(opts.serializer, Session("dis", User(), "env", "0.0.1")), SentryEnvelopeItem.fromUserFeedback(opts.serializer, UserFeedback(SentryId(UUID.randomUUID()))), @@ -75,10 +77,12 @@ class ClientReportTest { clientReportRecorder.recordLostEnvelope(DiscardReason.NETWORK_ERROR, envelope) val clientReportAtEnd = clientReportRecorder.resetCountsAndGenerateClientReport() - testHelper.assertTotalCount(13, clientReportAtEnd) + testHelper.assertTotalCount(15, clientReportAtEnd) testHelper.assertCountFor(DiscardReason.SAMPLE_RATE, DataCategory.Error, 3, clientReportAtEnd) testHelper.assertCountFor(DiscardReason.BEFORE_SEND, DataCategory.Error, 2, clientReportAtEnd) testHelper.assertCountFor(DiscardReason.QUEUE_OVERFLOW, DataCategory.Transaction, 1, clientReportAtEnd) + testHelper.assertCountFor(DiscardReason.NETWORK_ERROR, DataCategory.Span, 1, clientReportAtEnd) + testHelper.assertCountFor(DiscardReason.NETWORK_ERROR, DataCategory.Transaction, 1, clientReportAtEnd) testHelper.assertCountFor(DiscardReason.NETWORK_ERROR, DataCategory.Error, 1, clientReportAtEnd) testHelper.assertCountFor(DiscardReason.NETWORK_ERROR, DataCategory.UserReport, 1, clientReportAtEnd) testHelper.assertCountFor(DiscardReason.NETWORK_ERROR, DataCategory.Session, 1, clientReportAtEnd) @@ -88,6 +92,29 @@ class ClientReportTest { testHelper.assertCountFor(DiscardReason.NETWORK_ERROR, DataCategory.MetricBucket, 1, clientReportAtEnd) } + @Test + fun `lost transaction records dropped spans`() { + givenClientReportRecorder() + val hub = mock() + whenever(hub.options).thenReturn(opts) + val transaction = SentryTracer(TransactionContext("name", "op", TracesSamplingDecision(true)), hub) + transaction.startChild("lost span", "span1").finish() + transaction.startChild("lost span", "span2").finish() + transaction.startChild("lost span", "span3").finish() + transaction.startChild("lost span", "span4").finish() + + val envelope = testHelper.newEnvelope( + SentryEnvelopeItem.fromEvent(opts.serializer, SentryTransaction(transaction)) + ) + + clientReportRecorder.recordLostEnvelope(DiscardReason.NETWORK_ERROR, envelope) + + val clientReportAtEnd = clientReportRecorder.resetCountsAndGenerateClientReport() + testHelper.assertTotalCount(6, clientReportAtEnd) + testHelper.assertCountFor(DiscardReason.NETWORK_ERROR, DataCategory.Span, 5, clientReportAtEnd) + testHelper.assertCountFor(DiscardReason.NETWORK_ERROR, DataCategory.Transaction, 1, clientReportAtEnd) + } + @Test fun `lost event can be recorded`() { givenClientReportRecorder() @@ -189,7 +216,7 @@ class DropEverythingEventProcessor : EventProcessor { class ClientReportTestHelper(val options: SentryOptions) { val reasons = DiscardReason.values() - val categories = listOf(DataCategory.Error, DataCategory.Attachment, DataCategory.Session, DataCategory.Transaction, DataCategory.UserReport) + val categories = DataCategory.values() fun assertTotalCount(expectedCount: Long, clientReport: ClientReport?) { assertEquals(expectedCount, clientReport?.discardedEvents?.sumOf { it.quantity } ?: 0L)