diff --git a/CHANGELOG.md b/CHANGELOG.md index e59606e335..eaed5ce3eb 100644 --- a/CHANGELOG.md +++ b/CHANGELOG.md @@ -122,6 +122,8 @@ ### Fixes +- Fix SDK callback error handling ([#6140](https://github.com/getsentry/sentry-java/pull/6140)) + - Add `DiscardReason.CALLBACK_ERROR` and use it for telemetry dropped when a `beforeSend*` callback throws. `OnDiscardCallback` can now receive this value. - Disable URL caching when reading `META-INF/MANIFEST.MF` files during version detection so that the SDK no longer keeps jar file handles open for the life of the process ([#6124](https://github.com/getsentry/sentry-java/pull/6124) - Keep the `EventListener` wrapped by `SentryOkHttpEventListener` per `Call` ([#6003](https://github.com/getsentry/sentry-java/pull/6003)) diff --git a/sentry/api/sentry.api b/sentry/api/sentry.api index 53452c4c3b..c3dcbc730b 100644 --- a/sentry/api/sentry.api +++ b/sentry/api/sentry.api @@ -5148,6 +5148,7 @@ public final class io/sentry/clientreport/DiscardReason : java/lang/Enum { public static final field BACKPRESSURE Lio/sentry/clientreport/DiscardReason; public static final field BEFORE_SEND Lio/sentry/clientreport/DiscardReason; public static final field CACHE_OVERFLOW Lio/sentry/clientreport/DiscardReason; + public static final field CALLBACK_ERROR Lio/sentry/clientreport/DiscardReason; public static final field EVENT_PROCESSOR Lio/sentry/clientreport/DiscardReason; public static final field NETWORK_ERROR Lio/sentry/clientreport/DiscardReason; public static final field QUEUE_OVERFLOW Lio/sentry/clientreport/DiscardReason; diff --git a/sentry/src/main/java/io/sentry/SentryClient.java b/sentry/src/main/java/io/sentry/SentryClient.java index 4bba195fee..a9cc392e71 100644 --- a/sentry/src/main/java/io/sentry/SentryClient.java +++ b/sentry/src/main/java/io/sentry/SentryClient.java @@ -171,9 +171,6 @@ private boolean shouldApplyScopeData(final @NotNull CheckIn event, final @NotNul if (event == null) { options.getLogger().log(SentryLevel.DEBUG, "Event was dropped by beforeSend"); - options - .getClientReportRecorder() - .recordLostEvent(DiscardReason.BEFORE_SEND, DataCategory.Error); } } @@ -345,9 +342,6 @@ private void finalizeTransaction(final @NotNull IScope scope, final @NotNull Hin if (event == null) { options.getLogger().log(SentryLevel.DEBUG, "Event was dropped by beforeSendReplay"); - options - .getClientReportRecorder() - .recordLostEvent(DiscardReason.BEFORE_SEND, DataCategory.Replay); } } @@ -530,6 +524,24 @@ private SentryEvent processEvent( return event; } + private void recordLostLogEvent( + final @NotNull DiscardReason reason, final @NotNull SentryLogEvent event) { + options.getClientReportRecorder().recordLostEvent(reason, DataCategory.LogItem); + final long numberOfBytes = + JsonSerializationUtils.byteSizeOf(options.getSerializer(), options.getLogger(), event); + options.getClientReportRecorder().recordLostEvent(reason, DataCategory.LogByte, numberOfBytes); + } + + private void recordLostMetricsEvent( + final @NotNull DiscardReason reason, final @NotNull SentryMetricsEvent event) { + options.getClientReportRecorder().recordLostEvent(reason, DataCategory.TraceMetric); + final long numberOfBytes = + JsonSerializationUtils.byteSizeOf(options.getSerializer(), options.getLogger(), event); + options + .getClientReportRecorder() + .recordLostEvent(reason, DataCategory.TraceMetricByte, numberOfBytes); + } + @Nullable private SentryLogEvent processLogEvent( @NotNull SentryLogEvent event, final @NotNull List eventProcessors) { @@ -554,16 +566,7 @@ private SentryLogEvent processLogEvent( SentryLevel.DEBUG, "Log event was dropped by a processor: %s", processor.getClass().getName()); - options - .getClientReportRecorder() - .recordLostEvent(DiscardReason.EVENT_PROCESSOR, DataCategory.LogItem); - final long logEventNumberOfBytes = - JsonSerializationUtils.byteSizeOf( - options.getSerializer(), options.getLogger(), eventBeforeProcessor); - options - .getClientReportRecorder() - .recordLostEvent( - DiscardReason.EVENT_PROCESSOR, DataCategory.LogByte, logEventNumberOfBytes); + recordLostLogEvent(DiscardReason.EVENT_PROCESSOR, eventBeforeProcessor); break; } } @@ -596,18 +599,7 @@ private SentryMetricsEvent processMetricsEvent( SentryLevel.DEBUG, "Metrics event was dropped by a processor: %s", processor.getClass().getName()); - options - .getClientReportRecorder() - .recordLostEvent(DiscardReason.EVENT_PROCESSOR, DataCategory.TraceMetric); - final long metricsEventNumberOfBytes = - JsonSerializationUtils.byteSizeOf( - options.getSerializer(), options.getLogger(), eventBeforeProcessor); - options - .getClientReportRecorder() - .recordLostEvent( - DiscardReason.EVENT_PROCESSOR, - DataCategory.TraceMetricByte, - metricsEventNumberOfBytes); + recordLostMetricsEvent(DiscardReason.EVENT_PROCESSOR, eventBeforeProcessor); break; } } @@ -1049,35 +1041,13 @@ 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 .getLogger() .log(SentryLevel.DEBUG, "Transaction was dropped by beforeSendTransaction."); - 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 { @@ -1256,9 +1226,6 @@ public void captureSession(final @NotNull Session session, final @Nullable Hint if (event == null) { options.getLogger().log(SentryLevel.DEBUG, "Event was dropped by beforeSend"); - options - .getClientReportRecorder() - .recordLostEvent(DiscardReason.BEFORE_SEND, DataCategory.Feedback); } } @@ -1356,21 +1323,10 @@ public void captureLog(@Nullable SentryLogEvent logEvent, @Nullable IScope scope } if (logEvent != null) { - final @NotNull SentryLogEvent tmpLogEvent = logEvent; logEvent = executeBeforeSendLog(logEvent); if (logEvent == null) { options.getLogger().log(SentryLevel.DEBUG, "Log Event was dropped by beforeSendLog"); - options - .getClientReportRecorder() - .recordLostEvent(DiscardReason.BEFORE_SEND, DataCategory.LogItem); - final @NotNull long logEventNumberOfBytes = - JsonSerializationUtils.byteSizeOf( - options.getSerializer(), options.getLogger(), tmpLogEvent); - options - .getClientReportRecorder() - .recordLostEvent( - DiscardReason.BEFORE_SEND, DataCategory.LogByte, logEventNumberOfBytes); return; } @@ -1419,23 +1375,12 @@ public void captureMetric( } if (metricsEvent != null) { - final @NotNull SentryMetricsEvent tmpMetricsEvent = metricsEvent; metricsEvent = executeBeforeSendMetric(metricsEvent, hint); if (metricsEvent == null) { options .getLogger() .log(SentryLevel.DEBUG, "Metrics Event was dropped by beforeSendMetrics"); - options - .getClientReportRecorder() - .recordLostEvent(DiscardReason.BEFORE_SEND, DataCategory.TraceMetric); - final long metricsEventNumberOfBytes = - JsonSerializationUtils.byteSizeOf( - options.getSerializer(), options.getLogger(), tmpMetricsEvent); - options - .getClientReportRecorder() - .recordLostEvent( - DiscardReason.BEFORE_SEND, DataCategory.TraceMetricByte, metricsEventNumberOfBytes); return; } @@ -1673,11 +1618,17 @@ private void sortBreadcrumbsByDate( .getLogger() .log( SentryLevel.ERROR, - "The BeforeSend callback threw an exception. It will be added as breadcrumb and continue.", + "The beforeSend callback threw an exception. Dropping event.", e); - - // drop event in case of an error in beforeSend due to PII concerns - event = null; + options + .getClientReportRecorder() + .recordLostEvent(DiscardReason.CALLBACK_ERROR, DataCategory.Error); + return null; + } + if (event == null) { + options + .getClientReportRecorder() + .recordLostEvent(DiscardReason.BEFORE_SEND, DataCategory.Error); } } return event; @@ -1688,6 +1639,7 @@ private void sortBreadcrumbsByDate( final SentryOptions.BeforeSendTransactionCallback beforeSendTransaction = options.getBeforeSendTransaction(); if (beforeSendTransaction != null) { + final int spanCountBeforeCallback = transaction.getSpans().size(); try (final @NotNull ISentryLifecycleToken ignored = SentryCallbackReentrancyGuard.enter()) { transaction = beforeSendTransaction.execute(transaction, hint); } catch (Throwable e) { @@ -1695,11 +1647,40 @@ private void sortBreadcrumbsByDate( .getLogger() .log( SentryLevel.ERROR, - "The BeforeSendTransaction callback threw an exception. It will be added as breadcrumb and continue.", + "The beforeSendTransaction callback threw an exception. Dropping transaction.", e); + options + .getClientReportRecorder() + .recordLostEvent(DiscardReason.CALLBACK_ERROR, DataCategory.Transaction); + options + .getClientReportRecorder() + .recordLostEvent( + DiscardReason.CALLBACK_ERROR, DataCategory.Span, spanCountBeforeCallback + 1); + return null; + } - // drop transaction in case of an error in beforeSend due to PII concerns - transaction = null; + if (transaction == null) { + options + .getClientReportRecorder() + .recordLostEvent(DiscardReason.BEFORE_SEND, DataCategory.Transaction); + options + .getClientReportRecorder() + .recordLostEvent( + DiscardReason.BEFORE_SEND, DataCategory.Span, spanCountBeforeCallback + 1); + } else { + final int spanCountAfterCallback = transaction.getSpans().size(); + if (spanCountAfterCallback < spanCountBeforeCallback) { + 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); + } } } return transaction; @@ -1714,10 +1695,19 @@ private void sortBreadcrumbsByDate( } catch (Throwable e) { options .getLogger() - .log(SentryLevel.ERROR, "The BeforeSendFeedback callback threw an exception.", e); - - // drop feedback in case of an error in beforeSend due to PII concerns - event = null; + .log( + SentryLevel.ERROR, + "The beforeSendFeedback callback threw an exception. Dropping feedback.", + e); + options + .getClientReportRecorder() + .recordLostEvent(DiscardReason.CALLBACK_ERROR, DataCategory.Feedback); + return null; + } + if (event == null) { + options + .getClientReportRecorder() + .recordLostEvent(DiscardReason.BEFORE_SEND, DataCategory.Feedback); } } return event; @@ -1734,11 +1724,17 @@ private void sortBreadcrumbsByDate( .getLogger() .log( SentryLevel.ERROR, - "The BeforeSendReplay callback threw an exception. It will be added as breadcrumb and continue.", + "The beforeSendReplay callback threw an exception. Dropping replay event.", e); - - // drop event in case of an error in beforeSend due to PII concerns - event = null; + options + .getClientReportRecorder() + .recordLostEvent(DiscardReason.CALLBACK_ERROR, DataCategory.Replay); + return null; + } + if (event == null) { + options + .getClientReportRecorder() + .recordLostEvent(DiscardReason.BEFORE_SEND, DataCategory.Replay); } } return event; @@ -1748,6 +1744,7 @@ private void sortBreadcrumbsByDate( final SentryOptions.Logs.BeforeSendLogCallback beforeSendLog = options.getLogs().getBeforeSend(); if (beforeSendLog != null) { + final @NotNull SentryLogEvent eventBeforeCallback = event; try (final @NotNull ISentryLifecycleToken ignored = SentryCallbackReentrancyGuard.enter()) { event = beforeSendLog.execute(event); } catch (Throwable e) { @@ -1755,11 +1752,13 @@ private void sortBreadcrumbsByDate( .getLogger() .log( SentryLevel.ERROR, - "The BeforeSendLog callback threw an exception. Dropping log event.", + "The beforeSendLog callback threw an exception. Dropping log event.", e); - - // drop event in case of an error in beforeSendLog due to PII concerns - event = null; + recordLostLogEvent(DiscardReason.CALLBACK_ERROR, eventBeforeCallback); + return null; + } + if (event == null) { + recordLostLogEvent(DiscardReason.BEFORE_SEND, eventBeforeCallback); } } return event; @@ -1770,6 +1769,7 @@ private void sortBreadcrumbsByDate( final SentryOptions.Metrics.BeforeSendMetricCallback beforeSendMetric = options.getMetrics().getBeforeSend(); if (beforeSendMetric != null) { + final @NotNull SentryMetricsEvent eventBeforeCallback = event; try (final @NotNull ISentryLifecycleToken ignored = SentryCallbackReentrancyGuard.enter()) { event = beforeSendMetric.execute(event, hint); } catch (Throwable e) { @@ -1777,11 +1777,13 @@ private void sortBreadcrumbsByDate( .getLogger() .log( SentryLevel.ERROR, - "The BeforeSendMetric callback threw an exception. Dropping metrics event.", + "The beforeSendMetric callback threw an exception. Dropping metrics event.", e); - - // drop event in case of an error in beforeSendMetric due to PII concerns - event = null; + recordLostMetricsEvent(DiscardReason.CALLBACK_ERROR, eventBeforeCallback); + return null; + } + if (event == null) { + recordLostMetricsEvent(DiscardReason.BEFORE_SEND, eventBeforeCallback); } } return event; diff --git a/sentry/src/main/java/io/sentry/clientreport/DiscardReason.java b/sentry/src/main/java/io/sentry/clientreport/DiscardReason.java index 98f25386a5..4fc424dfa1 100644 --- a/sentry/src/main/java/io/sentry/clientreport/DiscardReason.java +++ b/sentry/src/main/java/io/sentry/clientreport/DiscardReason.java @@ -8,6 +8,7 @@ public enum DiscardReason { SEND_ERROR("send_error"), SAMPLE_RATE("sample_rate"), BEFORE_SEND("before_send"), + CALLBACK_ERROR("callback_error"), EVENT_PROCESSOR("event_processor"), // also for ignored exceptions BACKPRESSURE("backpressure"); diff --git a/sentry/src/test/java/io/sentry/SentryClientTest.kt b/sentry/src/test/java/io/sentry/SentryClientTest.kt index 61181ee96a..7b907df1e8 100644 --- a/sentry/src/test/java/io/sentry/SentryClientTest.kt +++ b/sentry/src/test/java/io/sentry/SentryClientTest.kt @@ -261,9 +261,10 @@ class SentryClientTest { @Test fun `when beforeSend throws an exception, event is dropped`() { val exception = Exception("test") + val onDiscardMock = mock() - exception.stackTrace.toString() fixture.sentryOptions.setBeforeSend { _, _ -> throw exception } + fixture.sentryOptions.onDiscard = onDiscardMock val sut = fixture.getSut() val actual = SentryEvent() val id = sut.captureEvent(actual) @@ -272,8 +273,9 @@ class SentryClientTest { assertClientReport( fixture.sentryOptions.clientReportRecorder, - listOf(DiscardedEvent(DiscardReason.BEFORE_SEND.reason, DataCategory.Error.category, 1)), + listOf(DiscardedEvent(DiscardReason.CALLBACK_ERROR.reason, DataCategory.Error.category, 1)), ) + verify(onDiscardMock).execute(DiscardReason.CALLBACK_ERROR, DataCategory.Error, 1) } @Test @@ -418,9 +420,10 @@ class SentryClientTest { fun `when beforeSendLog throws an exception, log is dropped`() { val scope = createScope() val exception = Exception("test") + val onDiscardMock = mock() - exception.stackTrace.toString() fixture.sentryOptions.logs.setBeforeSend { _ -> throw exception } + fixture.sentryOptions.onDiscard = onDiscardMock val sut = fixture.getSut() sut.captureLog( SentryLogEvent(SentryId(), SentryNanotimeDate(), "message", SentryLogLevel.WARN), @@ -430,10 +433,12 @@ class SentryClientTest { assertClientReport( fixture.sentryOptions.clientReportRecorder, listOf( - DiscardedEvent(DiscardReason.BEFORE_SEND.reason, DataCategory.LogItem.category, 1), - DiscardedEvent(DiscardReason.BEFORE_SEND.reason, DataCategory.LogByte.category, 109), + DiscardedEvent(DiscardReason.CALLBACK_ERROR.reason, DataCategory.LogItem.category, 1), + DiscardedEvent(DiscardReason.CALLBACK_ERROR.reason, DataCategory.LogByte.category, 109), ), ) + verify(onDiscardMock).execute(DiscardReason.CALLBACK_ERROR, DataCategory.LogItem, 1) + verify(onDiscardMock).execute(DiscardReason.CALLBACK_ERROR, DataCategory.LogByte, 109) } @Test @@ -531,9 +536,10 @@ class SentryClientTest { fun `when beforeSendMetric throws an exception, metric is dropped`() { val scope = createScope() val exception = Exception("test") + val onDiscardMock = mock() - exception.stackTrace.toString() - fixture.sentryOptions.metrics.setBeforeSend { _, hint -> throw exception } + fixture.sentryOptions.metrics.setBeforeSend { _, _ -> throw exception } + fixture.sentryOptions.onDiscard = onDiscardMock val sut = fixture.getSut() sut.captureMetric( SentryMetricsEvent(SentryId(), SentryNanotimeDate(), "name", "gauge", 123.0), @@ -544,14 +550,16 @@ class SentryClientTest { assertClientReport( fixture.sentryOptions.clientReportRecorder, listOf( - DiscardedEvent(DiscardReason.BEFORE_SEND.reason, DataCategory.TraceMetric.category, 1), + DiscardedEvent(DiscardReason.CALLBACK_ERROR.reason, DataCategory.TraceMetric.category, 1), DiscardedEvent( - DiscardReason.BEFORE_SEND.reason, + DiscardReason.CALLBACK_ERROR.reason, DataCategory.TraceMetricByte.category, 120, ), ), ) + verify(onDiscardMock).execute(DiscardReason.CALLBACK_ERROR, DataCategory.TraceMetric, 1) + verify(onDiscardMock).execute(DiscardReason.CALLBACK_ERROR, DataCategory.TraceMetricByte, 120) } @Test @@ -1552,13 +1560,14 @@ class SentryClientTest { assertClientReport( fixture.sentryOptions.clientReportRecorder, listOf( - DiscardedEvent(DiscardReason.BEFORE_SEND.reason, DataCategory.Transaction.category, 1), - DiscardedEvent(DiscardReason.BEFORE_SEND.reason, DataCategory.Span.category, 2), + DiscardedEvent(DiscardReason.CALLBACK_ERROR.reason, DataCategory.Transaction.category, 1), + DiscardedEvent(DiscardReason.CALLBACK_ERROR.reason, DataCategory.Span.category, 2), ), ) - verify(onDiscardMock, times(1)).execute(DiscardReason.BEFORE_SEND, DataCategory.Transaction, 1) - verify(onDiscardMock).execute(DiscardReason.BEFORE_SEND, DataCategory.Span, 2) + verify(onDiscardMock, times(1)) + .execute(DiscardReason.CALLBACK_ERROR, DataCategory.Transaction, 1) + verify(onDiscardMock).execute(DiscardReason.CALLBACK_ERROR, DataCategory.Span, 2) } @Test @@ -3870,10 +3879,10 @@ class SentryClientTest { assertClientReport( fixture.sentryOptions.clientReportRecorder, - listOf(DiscardedEvent(DiscardReason.BEFORE_SEND.reason, DataCategory.Replay.category, 1)), + listOf(DiscardedEvent(DiscardReason.CALLBACK_ERROR.reason, DataCategory.Replay.category, 1)), ) - verify(onDiscardMock, times(1)).execute(DiscardReason.BEFORE_SEND, DataCategory.Replay, 1) + verify(onDiscardMock, times(1)).execute(DiscardReason.CALLBACK_ERROR, DataCategory.Replay, 1) } // endregion @@ -4050,10 +4059,12 @@ class SentryClientTest { assertClientReport( fixture.sentryOptions.clientReportRecorder, - listOf(DiscardedEvent(DiscardReason.BEFORE_SEND.reason, DataCategory.Feedback.category, 1)), + listOf( + DiscardedEvent(DiscardReason.CALLBACK_ERROR.reason, DataCategory.Feedback.category, 1) + ), ) - verify(onDiscardMock, times(1)).execute(DiscardReason.BEFORE_SEND, DataCategory.Feedback, 1) + verify(onDiscardMock, times(1)).execute(DiscardReason.CALLBACK_ERROR, DataCategory.Feedback, 1) } @Test diff --git a/sentry/src/test/java/io/sentry/clientreport/ClientReportTest.kt b/sentry/src/test/java/io/sentry/clientreport/ClientReportTest.kt index b89b1894f3..165f3c6c03 100644 --- a/sentry/src/test/java/io/sentry/clientreport/ClientReportTest.kt +++ b/sentry/src/test/java/io/sentry/clientreport/ClientReportTest.kt @@ -1,5 +1,6 @@ package io.sentry.clientreport +import com.google.common.truth.Truth.assertThat import io.sentry.Attachment import io.sentry.CheckIn import io.sentry.CheckInStatus @@ -64,6 +65,11 @@ class ClientReportTest { lateinit var clientReportRecorder: ClientReportRecorder lateinit var testHelper: ClientReportTestHelper + @Test + fun `callback error has expected discard reason`() { + assertThat(DiscardReason.CALLBACK_ERROR.reason).isEqualTo("callback_error") + } + @Test fun `lost envelope can be recorded`() { givenClientReportRecorder()