diff --git a/CHANGELOG.md b/CHANGELOG.md index d4b03cd492..d65166145b 100644 --- a/CHANGELOG.md +++ b/CHANGELOG.md @@ -10,6 +10,8 @@ Breaking changes: - Set ip_address to {{auto}} by default, even if sendDefaultPII is disabled ([#2860](https://github.com/getsentry/sentry-java/pull/2860)) - Instead use the "Prevent Storing of IP Addresses" option in the "Security & Privacy" project settings on sentry.io - Reduce timeout of AsyncHttpTransport to avoid ANR ([#2879](https://github.com/getsentry/sentry-java/pull/2879)) +- Add deadline timeout for automatic transactions ([#2865](https://github.com/getsentry/sentry-java/pull/2865)) + - This affects all automatically generated transactions on Android (UI, clicks), the default timeout is 30s ### Fixes diff --git a/sentry-android-core/src/main/java/io/sentry/android/core/ActivityLifecycleIntegration.java b/sentry-android-core/src/main/java/io/sentry/android/core/ActivityLifecycleIntegration.java index 070fed2e0f..4cf44e7f49 100644 --- a/sentry-android-core/src/main/java/io/sentry/android/core/ActivityLifecycleIntegration.java +++ b/sentry-android-core/src/main/java/io/sentry/android/core/ActivityLifecycleIntegration.java @@ -192,6 +192,9 @@ private void startTracing(final @NotNull Activity activity) { final Boolean coldStart = AppStartState.getInstance().isColdStart(); final TransactionOptions transactionOptions = new TransactionOptions(); + transactionOptions.setDeadlineTimeout( + TransactionOptions.DEFAULT_DEADLINE_TIMEOUT_AUTO_TRANSACTION); + if (options.isEnableActivityLifecycleTracingAutoFinish()) { transactionOptions.setIdleTimeout(options.getIdleTimeout()); transactionOptions.setTrimEnd(true); diff --git a/sentry-android-core/src/main/java/io/sentry/android/core/internal/gestures/SentryGestureListener.java b/sentry-android-core/src/main/java/io/sentry/android/core/internal/gestures/SentryGestureListener.java index e502aea71d..2493f5b5f0 100644 --- a/sentry-android-core/src/main/java/io/sentry/android/core/internal/gestures/SentryGestureListener.java +++ b/sentry-android-core/src/main/java/io/sentry/android/core/internal/gestures/SentryGestureListener.java @@ -237,6 +237,8 @@ private void startTracing(final @NotNull UiElement target, final @NotNull String final TransactionOptions transactionOptions = new TransactionOptions(); transactionOptions.setWaitForChildren(true); + transactionOptions.setDeadlineTimeout( + TransactionOptions.DEFAULT_DEADLINE_TIMEOUT_AUTO_TRANSACTION); transactionOptions.setIdleTimeout(options.getIdleTimeout()); transactionOptions.setTrimEnd(true); diff --git a/sentry-android-core/src/test/java/io/sentry/android/core/ActivityLifecycleIntegrationTest.kt b/sentry-android-core/src/test/java/io/sentry/android/core/ActivityLifecycleIntegrationTest.kt index 1004575976..45f9780730 100644 --- a/sentry-android-core/src/test/java/io/sentry/android/core/ActivityLifecycleIntegrationTest.kt +++ b/sentry-android-core/src/test/java/io/sentry/android/core/ActivityLifecycleIntegrationTest.kt @@ -43,7 +43,6 @@ import org.mockito.kotlin.clearInvocations import org.mockito.kotlin.eq import org.mockito.kotlin.mock import org.mockito.kotlin.never -import org.mockito.kotlin.times import org.mockito.kotlin.verify import org.mockito.kotlin.whenever import org.robolectric.Shadows.shadowOf @@ -354,7 +353,7 @@ class ActivityLifecycleIntegrationTest { } @Test - fun `Transaction op is ui_load`() { + fun `Transaction op is ui_load and idle+deadline timeouts are set`() { val sut = fixture.getSut() fixture.options.tracesSampleRate = 1.0 sut.register(fixture.hub, fixture.options) @@ -365,11 +364,14 @@ class ActivityLifecycleIntegrationTest { sut.onActivityCreated(activity, fixture.bundle) verify(fixture.hub).startTransaction( - check { + check { assertEquals("ui.load", it.operation) assertEquals(TransactionNameSource.COMPONENT, it.transactionNameSource) }, - any() + check { transactionOptions -> + assertEquals(fixture.options.idleTimeout, transactionOptions.idleTimeout) + assertEquals(TransactionOptions.DEFAULT_DEADLINE_TIMEOUT_AUTO_TRANSACTION, transactionOptions.deadlineTimeout) + } ) } diff --git a/sentry-android-core/src/test/java/io/sentry/android/core/internal/gestures/SentryGestureListenerTracingTest.kt b/sentry-android-core/src/test/java/io/sentry/android/core/internal/gestures/SentryGestureListenerTracingTest.kt index b9a7eee52c..f39f70c552 100644 --- a/sentry-android-core/src/test/java/io/sentry/android/core/internal/gestures/SentryGestureListenerTracingTest.kt +++ b/sentry-android-core/src/test/java/io/sentry/android/core/internal/gestures/SentryGestureListenerTracingTest.kt @@ -206,6 +206,24 @@ class SentryGestureListenerTracingTest { ) } + @Test + fun `captures transaction and both idle+deadline timeouts are set`() { + val sut = fixture.getSut() + + sut.onSingleTapUp(fixture.event) + + verify(fixture.hub).startTransaction( + any(), + check { transactionOptions -> + assertEquals(fixture.options.idleTimeout, transactionOptions.idleTimeout) + assertEquals( + TransactionOptions.DEFAULT_DEADLINE_TIMEOUT_AUTO_TRANSACTION, + transactionOptions.deadlineTimeout + ) + } + ) + } + @Test fun `captures transaction with interaction event type as op`() { val sut = fixture.getSut() diff --git a/sentry-android-navigation/src/main/java/io/sentry/android/navigation/SentryNavigationListener.kt b/sentry-android-navigation/src/main/java/io/sentry/android/navigation/SentryNavigationListener.kt index dae348bef5..8ca52e3c41 100644 --- a/sentry-android-navigation/src/main/java/io/sentry/android/navigation/SentryNavigationListener.kt +++ b/sentry-android-navigation/src/main/java/io/sentry/android/navigation/SentryNavigationListener.kt @@ -132,15 +132,16 @@ class SentryNavigationListener @JvmOverloads constructor( // we add '/' to the name to match dart and web pattern name = "/" + name.substringBefore('/') // strip out arguments from the tx name - val transactonOptions = TransactionOptions().also { + val transactionOptions = TransactionOptions().also { it.isWaitForChildren = true it.idleTimeout = hub.options.idleTimeout + it.deadlineTimeout = TransactionOptions.DEFAULT_DEADLINE_TIMEOUT_AUTO_TRANSACTION it.isTrimEnd = true } val transaction = hub.startTransaction( TransactionContext(name, TransactionNameSource.ROUTE, NAVIGATION_OP), - transactonOptions + transactionOptions ) transaction.spanContext.origin = traceOriginAppendix?.let { diff --git a/sentry-android-navigation/src/test/java/io/sentry/android/navigation/SentryNavigationListenerTest.kt b/sentry-android-navigation/src/test/java/io/sentry/android/navigation/SentryNavigationListenerTest.kt index 0d7441c549..e1c899d136 100644 --- a/sentry-android-navigation/src/test/java/io/sentry/android/navigation/SentryNavigationListenerTest.kt +++ b/sentry-android-navigation/src/test/java/io/sentry/android/navigation/SentryNavigationListenerTest.kt @@ -94,7 +94,12 @@ class SentryNavigationListenerTest { whenever(context.resources).thenReturn(resources) whenever(navController.context).thenReturn(context) whenever(destination.route).thenReturn(toRoute) - return SentryNavigationListener(hub, enableBreadcrumbs, enableTracing, traceOriginAppendix) + return SentryNavigationListener( + hub, + enableBreadcrumbs, + enableTracing, + traceOriginAppendix + ) } } @@ -355,7 +360,8 @@ class SentryNavigationListenerTest { fun `starts new trace if performance is disabled`() { val sut = fixture.getSut(enableTracing = false) - val argumentCaptor: ArgumentCaptor = ArgumentCaptor.forClass(ScopeCallback::class.java) + val argumentCaptor: ArgumentCaptor = + ArgumentCaptor.forClass(ScopeCallback::class.java) val scope = Scope(fixture.options) val propagationContextAtStart = scope.propagationContext whenever(fixture.hub.configureScope(argumentCaptor.capture())).thenAnswer { @@ -385,4 +391,18 @@ class SentryNavigationListenerTest { assertEquals("auto.navigation.jetpack_compose", fixture.transaction.spanContext.origin) } + + @Test + fun `Navigation listener transactions set automatic deadline timeout`() { + val sut = fixture.getSut() + + sut.onDestinationChanged(fixture.navController, fixture.destination, null) + + verify(fixture.hub).startTransaction( + any(), + check { options -> + assertEquals(TransactionOptions.DEFAULT_DEADLINE_TIMEOUT_AUTO_TRANSACTION, options.deadlineTimeout) + } + ) + } } diff --git a/sentry/api/sentry.api b/sentry/api/sentry.api index 2b83f5fb0d..c1e55e642e 100644 --- a/sentry/api/sentry.api +++ b/sentry/api/sentry.api @@ -2352,8 +2352,10 @@ public abstract interface class io/sentry/TransactionFinishedCallback { } public final class io/sentry/TransactionOptions : io/sentry/SpanOptions { + public static final field DEFAULT_DEADLINE_TIMEOUT_AUTO_TRANSACTION J public fun ()V public fun getCustomSamplingContext ()Lio/sentry/CustomSamplingContext; + public fun getDeadlineTimeout ()Ljava/lang/Long; public fun getIdleTimeout ()Ljava/lang/Long; public fun getStartTimestamp ()Lio/sentry/SentryDate; public fun getTransactionFinishedCallback ()Lio/sentry/TransactionFinishedCallback; @@ -2361,6 +2363,7 @@ public final class io/sentry/TransactionOptions : io/sentry/SpanOptions { public fun isWaitForChildren ()Z public fun setBindToScope (Z)V public fun setCustomSamplingContext (Lio/sentry/CustomSamplingContext;)V + public fun setDeadlineTimeout (Ljava/lang/Long;)V public fun setIdleTimeout (Ljava/lang/Long;)V public fun setStartTimestamp (Lio/sentry/SentryDate;)V public fun setTransactionFinishedCallback (Lio/sentry/TransactionFinishedCallback;)V diff --git a/sentry/src/main/java/io/sentry/SentryTracer.java b/sentry/src/main/java/io/sentry/SentryTracer.java index e3cc1498e5..f3ffb8db45 100644 --- a/sentry/src/main/java/io/sentry/SentryTracer.java +++ b/sentry/src/main/java/io/sentry/SentryTracer.java @@ -37,10 +37,14 @@ public final class SentryTracer implements ITransaction { */ private @NotNull FinishStatus finishStatus = FinishStatus.NOT_FINISHED; - private volatile @Nullable TimerTask timerTask; + private volatile @Nullable TimerTask idleTimeoutTask; + private volatile @Nullable TimerTask deadlineTimeoutTask; + private volatile @Nullable Timer timer = null; private final @NotNull Object timerLock = new Object(); - private final @NotNull AtomicBoolean isFinishTimerRunning = new AtomicBoolean(false); + + private final @NotNull AtomicBoolean isIdleFinishTimerRunning = new AtomicBoolean(false); + private final @NotNull AtomicBoolean isDeadlineTimerRunning = new AtomicBoolean(false); private final @NotNull Baggage baggage; private @NotNull TransactionNameSource transactionNameSource; @@ -92,8 +96,11 @@ public SentryTracer( transactionPerformanceCollector.start(this); } - if (transactionOptions.getIdleTimeout() != null) { + if (transactionOptions.getIdleTimeout() != null + || transactionOptions.getDeadlineTimeout() != null) { timer = new Timer(true); + + scheduleDeadlineTimeout(); scheduleFinish(); } } @@ -101,34 +108,47 @@ public SentryTracer( @Override public void scheduleFinish() { synchronized (timerLock) { - cancelTimer(); if (timer != null) { - isFinishTimerRunning.set(true); - timerTask = - new TimerTask() { - @Override - public void run() { - finishFromTimer(); - } - }; - - try { - timer.schedule(timerTask, transactionOptions.getIdleTimeout()); - } catch (Throwable e) { - hub.getOptions() - .getLogger() - .log(SentryLevel.WARNING, "Failed to schedule finish timer", e); - // if we failed to schedule the finish timer for some reason, we finish it here right away - finishFromTimer(); + final @Nullable Long idleTimeout = transactionOptions.getIdleTimeout(); + + if (idleTimeout != null) { + cancelIdleTimer(); + isIdleFinishTimerRunning.set(true); + idleTimeoutTask = + new TimerTask() { + @Override + public void run() { + onIdleTimeoutReached(); + } + }; + + try { + timer.schedule(idleTimeoutTask, idleTimeout); + } catch (Throwable e) { + hub.getOptions() + .getLogger() + .log(SentryLevel.WARNING, "Failed to schedule finish timer", e); + // if we failed to schedule the finish timer for some reason, we finish it here right + // away + onIdleTimeoutReached(); + } } } } } - private void finishFromTimer() { - final SpanStatus status = getStatus(); + private void onIdleTimeoutReached() { + final @Nullable SpanStatus status = getStatus(); finish((status != null) ? status : SpanStatus.OK); - isFinishTimerRunning.set(false); + isIdleFinishTimerRunning.set(false); + } + + private void onDeadlineTimeoutReached() { + final @Nullable SpanStatus status = getStatus(); + forceFinish( + (status != null) ? status : SpanStatus.DEADLINE_EXCEEDED, + transactionOptions.getIdleTimeout() != null); + isDeadlineTimerRunning.set(false); } @Override @@ -222,6 +242,8 @@ public void finish( if (timer != null) { synchronized (timerLock) { if (timer != null) { + cancelIdleTimer(); + cancelDeadlineTimer(); timer.cancel(); timer = null; } @@ -244,12 +266,51 @@ public void finish( } } - private void cancelTimer() { + private void cancelIdleTimer() { synchronized (timerLock) { - if (timerTask != null) { - timerTask.cancel(); - isFinishTimerRunning.set(false); - timerTask = null; + if (idleTimeoutTask != null) { + idleTimeoutTask.cancel(); + isIdleFinishTimerRunning.set(false); + idleTimeoutTask = null; + } + } + } + + private void scheduleDeadlineTimeout() { + final @Nullable Long deadlineTimeOut = transactionOptions.getDeadlineTimeout(); + if (deadlineTimeOut != null) { + synchronized (timerLock) { + if (timer != null) { + cancelDeadlineTimer(); + isDeadlineTimerRunning.set(true); + deadlineTimeoutTask = + new TimerTask() { + @Override + public void run() { + onDeadlineTimeoutReached(); + } + }; + try { + timer.schedule(deadlineTimeoutTask, deadlineTimeOut); + } catch (Throwable e) { + hub.getOptions() + .getLogger() + .log(SentryLevel.WARNING, "Failed to schedule finish timer", e); + // if we failed to schedule the finish timer for some reason, we finish it here right + // away + onDeadlineTimeoutReached(); + } + } + } + } + } + + private void cancelDeadlineTimer() { + synchronized (timerLock) { + if (deadlineTimeoutTask != null) { + deadlineTimeoutTask.cancel(); + isDeadlineTimerRunning.set(false); + deadlineTimeoutTask = null; } } } @@ -360,7 +421,7 @@ private ISpan createChild( Objects.requireNonNull(parentSpanId, "parentSpanId is required"); Objects.requireNonNull(operation, "operation is required"); - cancelTimer(); + cancelIdleTimer(); final Span span = new Span( root.getTraceId(), @@ -720,8 +781,14 @@ Span getRoot() { @TestOnly @Nullable - TimerTask getTimerTask() { - return timerTask; + TimerTask getIdleTimeoutTask() { + return idleTimeoutTask; + } + + @TestOnly + @Nullable + TimerTask getDeadlineTimeoutTask() { + return deadlineTimeoutTask; } @TestOnly @@ -733,7 +800,13 @@ Timer getTimer() { @TestOnly @NotNull AtomicBoolean isFinishTimerRunning() { - return isFinishTimerRunning; + return isIdleFinishTimerRunning; + } + + @TestOnly + @NotNull + AtomicBoolean isDeadlineTimerRunning() { + return isDeadlineTimerRunning; } @TestOnly diff --git a/sentry/src/main/java/io/sentry/TransactionOptions.java b/sentry/src/main/java/io/sentry/TransactionOptions.java index 3362d97940..0ae4b94ace 100644 --- a/sentry/src/main/java/io/sentry/TransactionOptions.java +++ b/sentry/src/main/java/io/sentry/TransactionOptions.java @@ -1,10 +1,13 @@ package io.sentry; +import org.jetbrains.annotations.ApiStatus; import org.jetbrains.annotations.Nullable; /** Sentry Transaction options */ public final class TransactionOptions extends SpanOptions { + @ApiStatus.Internal public static final long DEFAULT_DEADLINE_TIMEOUT_AUTO_TRANSACTION = 300000; + /** * Arbitrary data used in {@link SamplingContext} to determine if transaction is going to be * sampled. @@ -34,6 +37,16 @@ public final class TransactionOptions extends SpanOptions { */ private @Nullable Long idleTimeout = null; + /** + * The deadline time, measured in ms, to wait until the transaction will be force-finished with + * deadline-exceeded status./ + * + *

When set to {@code null} the transaction won't be forcefully finished. + * + *

The default is 30 seconds. + */ + private @Nullable Long deadlineTimeout = null; + /** * When `waitForChildren` is set to `true` and this callback is set, it's called before the * transaction is captured. @@ -121,6 +134,28 @@ public void setWaitForChildren(boolean waitForChildren) { return idleTimeout; } + /** + * Sets the deadlineTimeout. If set, an transaction and it's child spans will be force-finished + * with status {@link SpanStatus#DEADLINE_EXCEEDED} in case the transaction isn't finished in + * time. + * + * @param deadlineTimeoutMs - the deadlineTimeout, in ms - or null if no deadline should be set + */ + @ApiStatus.Internal + public void setDeadlineTimeout(@Nullable Long deadlineTimeoutMs) { + this.deadlineTimeout = deadlineTimeoutMs; + } + + /** + * Gets the deadlineTimeout + * + * @return deadlineTimeout - the deadlineTimeout, in ms - or null if no deadline is set + */ + @ApiStatus.Internal + public @Nullable Long getDeadlineTimeout() { + return deadlineTimeout; + } + /** * Sets the idleTimeout * diff --git a/sentry/src/test/java/io/sentry/SentryTracerTest.kt b/sentry/src/test/java/io/sentry/SentryTracerTest.kt index ee698af6c0..d150148c08 100644 --- a/sentry/src/test/java/io/sentry/SentryTracerTest.kt +++ b/sentry/src/test/java/io/sentry/SentryTracerTest.kt @@ -43,6 +43,7 @@ class SentryTracerTest { startTimestamp: SentryDate? = null, waitForChildren: Boolean = false, idleTimeout: Long? = null, + deadlineTimeout: Long? = null, trimEnd: Boolean = false, transactionFinishedCallback: TransactionFinishedCallback? = null, samplingDecision: TracesSamplingDecision? = null, @@ -54,6 +55,7 @@ class SentryTracerTest { transactionOptions.startTimestamp = startTimestamp transactionOptions.isWaitForChildren = waitForChildren transactionOptions.idleTimeout = idleTimeout + transactionOptions.deadlineTimeout = deadlineTimeout transactionOptions.isTrimEnd = trimEnd transactionOptions.transactionFinishedCallback = transactionFinishedCallback return SentryTracer(TransactionContext("name", "op", samplingDecision), hub, transactionOptions, performanceCollector) @@ -751,17 +753,73 @@ class SentryTracerTest { } @Test - fun `when initialized without idleTimeout, does not schedule finish timer`() { + fun `when initialized without deadlineTimeout, does not schedule finish timer`() { val transaction = fixture.getSut() + assertNull(transaction.deadlineTimeoutTask) + } + + @Test + fun `when initialized with deadlineTimeout, schedules finish timer`() { + val transaction = fixture.getSut(deadlineTimeout = 50) + + assertTrue(transaction.isDeadlineTimerRunning.get()) + assertNotNull(transaction.deadlineTimeoutTask) + } + + @Test + fun `when deadline is reached transaction is finished`() { + // when a transaction with a deadline timeout is created + // and the tx and child keep on running + val transaction = fixture.getSut(deadlineTimeout = 20) + val span = transaction.startChild("op") + + // and the deadline is exceed + await.untilFalse(transaction.isDeadlineTimerRunning) + + // then both tx + span should be force finished + assertEquals(transaction.isFinished, true) + assertEquals(SpanStatus.DEADLINE_EXCEEDED, transaction.status) + assertEquals(SpanStatus.DEADLINE_EXCEEDED, span.status) + } + + @Test + fun `when transaction is finished before deadline is reached, deadline should not be running anymore`() { + val transaction = fixture.getSut(deadlineTimeout = 1000) + val span = transaction.startChild("op") + + span.finish(SpanStatus.OK) + transaction.finish(SpanStatus.OK) + + assertEquals(transaction.isDeadlineTimerRunning.get(), false) + assertNull(transaction.deadlineTimeoutTask) + assertEquals(transaction.isFinished, true) + assertEquals(SpanStatus.OK, transaction.status) + assertEquals(SpanStatus.OK, span.status) + } + + @Test + fun `when initialized with idleTimeout it has no influence on deadline timeout`() { + val transaction = fixture.getSut(idleTimeout = 3000, deadlineTimeout = 20) + val deadlineTimeoutTask = transaction.deadlineTimeoutTask + + val span = transaction.startChild("op") + // when the span finishes, it re-schedules the idle task + span.finish() + + // but the deadline timeout task should not be re-scheduled + assertEquals(deadlineTimeoutTask, transaction.deadlineTimeoutTask) + } - assertNull(transaction.timerTask) + @Test + fun `when initialized without idleTimeout, does not schedule finish timer`() { + val transaction = fixture.getSut() + assertNull(transaction.idleTimeoutTask) } @Test fun `when initialized with idleTimeout, schedules finish timer`() { val transaction = fixture.getSut(idleTimeout = 50) - - assertNotNull(transaction.timerTask) + assertNotNull(transaction.idleTimeoutTask) } @Test @@ -801,20 +859,20 @@ class SentryTracerTest { transaction.startChild("op") - assertNull(transaction.timerTask) + assertNull(transaction.idleTimeoutTask) } @Test fun `when a child is finished and the transaction is idle, resets the timer`() { val transaction = fixture.getSut(waitForChildren = true, idleTimeout = 3000) - val initialTime = transaction.timerTask!!.scheduledExecutionTime() + val initialTime = transaction.idleTimeoutTask!!.scheduledExecutionTime() val span = transaction.startChild("op") Thread.sleep(1) span.finish() - val timerAfterFinishingChild = transaction.timerTask!!.scheduledExecutionTime() + val timerAfterFinishingChild = transaction.idleTimeoutTask!!.scheduledExecutionTime() assertTrue { timerAfterFinishingChild > initialTime } } @@ -828,7 +886,7 @@ class SentryTracerTest { Thread.sleep(1) span.finish() - assertNull(transaction.timerTask) + assertNull(transaction.idleTimeoutTask) } @Test @@ -1220,7 +1278,7 @@ class SentryTracerTest { @Test fun `when timer is cancelled, schedule finish does not crash`() { - val tracer = fixture.getSut(idleTimeout = 50) + val tracer = fixture.getSut(idleTimeout = 50, deadlineTimeout = 100) tracer.timer!!.cancel() tracer.scheduleFinish() }