diff --git a/CHANGELOG.md b/CHANGELOG.md index 759864b5cfa..586e2964853 100644 --- a/CHANGELOG.md +++ b/CHANGELOG.md @@ -10,6 +10,7 @@ - Read integration list written by sentry gradle plugin from manifest ([#2598](https://github.com/getsentry/sentry-java/pull/2598)) - Add Logcat adapter ([#2620](https://github.com/getsentry/sentry-java/pull/2620)) - Provide CPU count/frequency data as device context ([#2622](https://github.com/getsentry/sentry-java/pull/2622)) +- Attach Trace Context when an ANR is detected (ANRv1) ([#2583](https://github.com/getsentry/sentry-java/pull/2583)) ### Fixes diff --git a/sentry-android-core/src/main/java/io/sentry/android/core/ANRWatchDog.java b/sentry-android-core/src/main/java/io/sentry/android/core/ANRWatchDog.java index 13fbebfd480..dd340ad1fd1 100644 --- a/sentry-android-core/src/main/java/io/sentry/android/core/ANRWatchDog.java +++ b/sentry-android-core/src/main/java/io/sentry/android/core/ANRWatchDog.java @@ -7,11 +7,11 @@ import android.app.ActivityManager; import android.content.Context; import android.os.Debug; +import android.os.SystemClock; import io.sentry.ILogger; import io.sentry.SentryLevel; import java.util.List; import java.util.concurrent.atomic.AtomicBoolean; -import java.util.concurrent.atomic.AtomicLong; import org.jetbrains.annotations.NotNull; import org.jetbrains.annotations.TestOnly; @@ -22,19 +22,20 @@ final class ANRWatchDog extends Thread { private final boolean reportInDebug; private final ANRListener anrListener; private final MainLooperHandler uiHandler; + private final TimeProvider timeProvider; + /** the interval in which we check if there's an ANR, in ms */ + private long pollingIntervalMs; + private final long timeoutIntervalMillis; private final @NotNull ILogger logger; - private final AtomicLong tick = new AtomicLong(0); + + private volatile long lastKnownActiveUiTimestampMs = 0; private final AtomicBoolean reported = new AtomicBoolean(false); private final @NotNull Context context; @SuppressWarnings("UnnecessaryLambda") - private final Runnable ticker = - () -> { - tick.set(0); - reported.set(false); - }; + private final Runnable ticker; ANRWatchDog( long timeoutIntervalMillis, @@ -42,40 +43,62 @@ final class ANRWatchDog extends Thread { @NotNull ANRListener listener, @NotNull ILogger logger, final @NotNull Context context) { - this(timeoutIntervalMillis, reportInDebug, listener, logger, new MainLooperHandler(), context); + this( + () -> SystemClock.uptimeMillis(), + timeoutIntervalMillis, + 500, + reportInDebug, + listener, + logger, + new MainLooperHandler(), + context); } @TestOnly ANRWatchDog( + @NotNull final TimeProvider timeProvider, long timeoutIntervalMillis, + long pollingIntervalMillis, boolean reportInDebug, @NotNull ANRListener listener, @NotNull ILogger logger, @NotNull MainLooperHandler uiHandler, final @NotNull Context context) { - super(); + + super("|ANR-WatchDog|"); + + this.timeProvider = timeProvider; + this.timeoutIntervalMillis = timeoutIntervalMillis; + this.pollingIntervalMs = pollingIntervalMillis; this.reportInDebug = reportInDebug; this.anrListener = listener; - this.timeoutIntervalMillis = timeoutIntervalMillis; this.logger = logger; this.uiHandler = uiHandler; this.context = context; + this.ticker = + () -> { + lastKnownActiveUiTimestampMs = timeProvider.getCurrentTimeMillis(); + reported.set(false); + }; + + if (timeoutIntervalMillis < (pollingIntervalMs * 2)) { + throw new IllegalArgumentException( + String.format( + "ANRWatchDog: timeoutIntervalMillis has to be at least %d ms", + pollingIntervalMs * 2)); + } } @Override public void run() { - setName("|ANR-WatchDog|"); + // right when the watchdog gets started, let's assume there's no ANR + ticker.run(); - long interval = timeoutIntervalMillis; while (!isInterrupted()) { - boolean needPost = tick.get() == 0; - tick.addAndGet(interval); - if (needPost) { - uiHandler.post(ticker); - } + uiHandler.post(ticker); try { - Thread.sleep(interval); + Thread.sleep(pollingIntervalMs); } catch (InterruptedException e) { try { Thread.currentThread().interrupt(); @@ -90,8 +113,11 @@ public void run() { return; } + final long unresponsiveDurationMs = + timeProvider.getCurrentTimeMillis() - lastKnownActiveUiTimestampMs; + // If the main thread has not handled ticker, it is blocked. ANR. - if (tick.get() != 0 && !reported.get()) { + if (unresponsiveDurationMs > timeoutIntervalMillis) { if (!reportInDebug && (Debug.isDebuggerConnected() || Debug.waitingForDebugger())) { logger.log( SentryLevel.DEBUG, @@ -100,48 +126,49 @@ public void run() { continue; } - // we only raise an ANR event if the process is in ANR state. - // if ActivityManager is not available, we'll still be able to send ANRs - final ActivityManager am = - (ActivityManager) context.getSystemService(Context.ACTIVITY_SERVICE); - - if (am != null) { - List processesInErrorState = null; - try { - // It can throw RuntimeException or OutOfMemoryError - processesInErrorState = am.getProcessesInErrorState(); - } catch (Throwable e) { - logger.log( - SentryLevel.ERROR, "Error getting ActivityManager#getProcessesInErrorState.", e); - } - // if list is null, there's no process in ANR state. - if (processesInErrorState == null) { - continue; - } - boolean isAnr = false; - for (ActivityManager.ProcessErrorStateInfo item : processesInErrorState) { - if (item.condition == NOT_RESPONDING) { - isAnr = true; - break; - } - } - if (!isAnr) { - continue; - } - } + if (isProcessNotResponding() && reported.compareAndSet(false, true)) { + final String message = + "Application Not Responding for at least " + timeoutIntervalMillis + " ms."; - logger.log(SentryLevel.INFO, "Raising ANR"); - final String message = - "Application Not Responding for at least " + timeoutIntervalMillis + " ms."; + final ApplicationNotResponding error = + new ApplicationNotResponding(message, uiHandler.getThread()); + anrListener.onAppNotResponding(error); + } + } + } + } - final ApplicationNotResponding error = - new ApplicationNotResponding(message, uiHandler.getThread()); - anrListener.onAppNotResponding(error); - interval = timeoutIntervalMillis; + private boolean isProcessNotResponding() { + // we only raise an ANR event if the process is in ANR state. + // if ActivityManager is not available, we'll still be able to send ANRs + final ActivityManager am = (ActivityManager) context.getSystemService(Context.ACTIVITY_SERVICE); - reported.set(true); + if (am != null) { + List processesInErrorState = null; + try { + // It can throw RuntimeException or OutOfMemoryError + processesInErrorState = am.getProcessesInErrorState(); + } catch (Throwable e) { + logger.log(SentryLevel.ERROR, "Error getting ActivityManager#getProcessesInErrorState.", e); + } + // if list is null, there's no process in ANR state. + if (processesInErrorState != null) { + for (ActivityManager.ProcessErrorStateInfo item : processesInErrorState) { + if (item.condition == NOT_RESPONDING) { + return true; + } + } } + // when list is empty, or there's no element NOT_RESPONDING, we can assume the app is not + // blocked + return false; } + return true; + } + + @FunctionalInterface + interface TimeProvider { + long getCurrentTimeMillis(); } public interface ANRListener { diff --git a/sentry-android-core/src/main/java/io/sentry/android/core/AnrIntegration.java b/sentry-android-core/src/main/java/io/sentry/android/core/AnrIntegration.java index b39e2a6c88b..f23fb6c7e30 100644 --- a/sentry-android-core/src/main/java/io/sentry/android/core/AnrIntegration.java +++ b/sentry-android-core/src/main/java/io/sentry/android/core/AnrIntegration.java @@ -4,10 +4,12 @@ import android.content.Context; import io.sentry.Hint; import io.sentry.IHub; +import io.sentry.ITransaction; import io.sentry.Integration; import io.sentry.SentryEvent; import io.sentry.SentryLevel; import io.sentry.SentryOptions; +import io.sentry.SpanStatus; import io.sentry.exception.ExceptionMechanismException; import io.sentry.hints.AbnormalExit; import io.sentry.protocol.Mechanism; @@ -95,9 +97,20 @@ void reportANR( final SentryEvent event = new SentryEvent(anrThrowable); event.setLevel(SentryLevel.ERROR); + // In case there's an ongoing transaction we want to finish it + // and assign the trace span context to the event + hub.configureScope( + scope -> { + @Nullable ITransaction transaction = scope.getTransaction(); + if (transaction != null) { + transaction.forceFinish(SpanStatus.ABORTED, true); + event.setTransaction(transaction.getName()); + event.getContexts().setTrace(transaction.getSpanContext()); + } + }); + final AnrHint anrHint = new AnrHint(isAppInBackground); final Hint hint = HintUtils.createWithTypeCheckHint(anrHint); - hub.captureEvent(event, hint); } diff --git a/sentry-android-core/src/test/java/io/sentry/android/core/ANRWatchDogTest.kt b/sentry-android-core/src/test/java/io/sentry/android/core/ANRWatchDogTest.kt index c4fc15a5ee1..abf54059f12 100644 --- a/sentry-android-core/src/test/java/io/sentry/android/core/ANRWatchDogTest.kt +++ b/sentry-android-core/src/test/java/io/sentry/android/core/ANRWatchDogTest.kt @@ -4,6 +4,8 @@ import android.app.ActivityManager import android.app.ActivityManager.ProcessErrorStateInfo.NOT_RESPONDING import android.app.ActivityManager.ProcessErrorStateInfo.NO_ERROR import android.content.Context +import io.sentry.android.core.ANRWatchDog.TimeProvider +import org.junit.Before import org.mockito.kotlin.any import org.mockito.kotlin.eq import org.mockito.kotlin.mock @@ -18,6 +20,15 @@ import kotlin.test.assertNull import kotlin.test.assertTrue class ANRWatchDogTest { + + private var currentTimeMs = 0L + private val timeProvider = TimeProvider { currentTimeMs } + + @Before + fun `setup`() { + currentTimeMs = 12341234 + } + @Test fun `when ANR is detected, callback is invoked with threads stacktrace`() { var anr: ApplicationNotResponding? = null @@ -30,15 +41,32 @@ class ANRWatchDogTest { val latch = CountDownLatch(1) whenever(handler.post(any())).then { latch.countDown() } whenever(handler.thread).thenReturn(thread) - val interval = 1L - val sut = ANRWatchDog(interval, true, { a -> anr = a }, mock(), handler, mock()) + val interval = 10L + + val sut = + ANRWatchDog( + timeProvider, + interval, + 1L, + true, + { a -> anr = a }, + mock(), + handler, + mock() + ) val es = Executors.newSingleThreadExecutor() try { es.submit { sut.run() } - assertTrue(latch.await(10L, TimeUnit.SECONDS)) // Wait until worker posts the job for the "UI thread" + assertTrue( + latch.await( + 10L, + TimeUnit.SECONDS + ) + ) // Wait until worker posts the job for the "UI thread" var waitCount = 0 do { + currentTimeMs += 100L Thread.sleep(100) // Let worker realize this is ANR } while (anr == null && waitCount++ < 100) @@ -62,14 +90,26 @@ class ANRWatchDogTest { (i.getArgument(0) as Runnable).run() } whenever(handler.thread).thenReturn(thread) - val interval = 1L - val sut = ANRWatchDog(interval, true, { a -> anr = a }, mock(), handler, mock()) + val interval = 10L + + val sut = + ANRWatchDog( + timeProvider, + interval, + 1L, + true, + { a -> anr = a }, + mock(), + handler, + mock() + ) val es = Executors.newSingleThreadExecutor() try { es.submit { sut.run() } var waitCount = 0 do { + currentTimeMs += 100L Thread.sleep(100) // Let worker realize his runner always runs } while (!invoked && waitCount++ < 100) @@ -93,7 +133,7 @@ class ANRWatchDogTest { val latch = CountDownLatch(1) whenever(handler.post(any())).then { latch.countDown() } whenever(handler.thread).thenReturn(thread) - val interval = 1L + val interval = 10L val context = mock() val am = mock() @@ -102,14 +142,30 @@ class ANRWatchDogTest { stateInfo.condition = NOT_RESPONDING val anrs = listOf(stateInfo) whenever(am.processesInErrorState).thenReturn(anrs) - val sut = ANRWatchDog(interval, true, { a -> anr = a }, mock(), handler, context) + + val sut = ANRWatchDog( + timeProvider, + interval, + 1L, + true, + { a -> anr = a }, + mock(), + handler, + context + ) val es = Executors.newSingleThreadExecutor() try { es.submit { sut.run() } - assertTrue(latch.await(10L, TimeUnit.SECONDS)) // Wait until worker posts the job for the "UI thread" + assertTrue( + latch.await( + 10L, + TimeUnit.SECONDS + ) + ) // Wait until worker posts the job for the "UI thread" var waitCount = 0 do { + currentTimeMs += 100L Thread.sleep(100) // Let worker realize this is ANR } while (anr == null && waitCount++ < 100) @@ -134,7 +190,7 @@ class ANRWatchDogTest { val latch = CountDownLatch(1) whenever(handler.post(any())).then { latch.countDown() } whenever(handler.thread).thenReturn(thread) - val interval = 1L + val interval = 10L val context = mock() val am = mock() @@ -143,15 +199,31 @@ class ANRWatchDogTest { stateInfo.condition = NO_ERROR val anrs = listOf(stateInfo) whenever(am.processesInErrorState).thenReturn(anrs) - val sut = ANRWatchDog(interval, true, { a -> anr = a }, mock(), handler, context) + + val sut = ANRWatchDog( + timeProvider, + interval, + 1L, + true, + { a -> anr = a }, + mock(), + handler, + context + ) val es = Executors.newSingleThreadExecutor() try { es.submit { sut.run() } - assertTrue(latch.await(10L, TimeUnit.SECONDS)) // Wait until worker posts the job for the "UI thread" + assertTrue( + latch.await( + 10L, + TimeUnit.SECONDS + ) + ) // Wait until worker posts the job for the "UI thread" var waitCount = 0 do { - Thread.sleep(100) // Let worker realize this is ANR + currentTimeMs += 100L + Thread.sleep(100L) // Let worker realize this is ANR } while (anr == null && waitCount++ < 100) assertNull(anr) // callback never ran } finally { diff --git a/sentry-android-core/src/test/java/io/sentry/android/core/AnrIntegrationTest.kt b/sentry-android-core/src/test/java/io/sentry/android/core/AnrIntegrationTest.kt index 55386b1c7a0..7a63b2edb0b 100644 --- a/sentry-android-core/src/test/java/io/sentry/android/core/AnrIntegrationTest.kt +++ b/sentry-android-core/src/test/java/io/sentry/android/core/AnrIntegrationTest.kt @@ -3,7 +3,12 @@ package io.sentry.android.core import android.content.Context import io.sentry.Hint import io.sentry.IHub +import io.sentry.ITransaction +import io.sentry.Scope +import io.sentry.ScopeCallback import io.sentry.SentryLevel +import io.sentry.SpanContext +import io.sentry.SpanStatus import io.sentry.android.core.AnrIntegration.AnrHint import io.sentry.exception.ExceptionMechanismException import io.sentry.util.HintUtils @@ -11,6 +16,7 @@ import org.mockito.kotlin.any import org.mockito.kotlin.check import org.mockito.kotlin.mock import org.mockito.kotlin.verify +import org.mockito.kotlin.whenever import kotlin.test.BeforeTest import kotlin.test.Test import kotlin.test.assertEquals @@ -127,6 +133,35 @@ class AnrIntegrationTest { ) } + @Test + fun `When ANR watch dog is triggered, and a transaction is running it should be finished`() { + val sut = fixture.getSut() + + // build up a running transaction + val spanContext = SpanContext("op.load") + val transaction = mock() + whenever(transaction.name).thenReturn("transaction") + whenever(transaction.spanContext).thenReturn(spanContext) + + val scope = mock() + whenever(scope.transaction).thenReturn(transaction) + + whenever(fixture.hub.configureScope(any())).then { + it.getArgument(0).run(scope) + } + + sut.reportANR(fixture.hub, fixture.options, getApplicationNotResponding()) + + verify(transaction).forceFinish(SpanStatus.ABORTED, true) + verify(fixture.hub).captureEvent( + check { + assertEquals("transaction", it.transaction) + assertEquals(spanContext, it.contexts.trace) + }, + any() + ) + } + private fun getApplicationNotResponding(): ApplicationNotResponding { return ApplicationNotResponding("ApplicationNotResponding", Thread.currentThread()) } diff --git a/sentry/api/sentry.api b/sentry/api/sentry.api index 8bdb12a1807..9c69d0427e1 100644 --- a/sentry/api/sentry.api +++ b/sentry/api/sentry.api @@ -578,6 +578,8 @@ public abstract interface class io/sentry/ISpan { } public abstract interface class io/sentry/ITransaction : io/sentry/ISpan { + public abstract fun finish (Lio/sentry/SpanStatus;Lio/sentry/SentryDate;Z)V + public abstract fun forceFinish (Lio/sentry/SpanStatus;Z)V public abstract fun getContexts ()Lio/sentry/protocol/Contexts; public abstract fun getEventId ()Lio/sentry/protocol/SentryId; public abstract fun getLatestActiveSpan ()Lio/sentry/Span; @@ -854,6 +856,8 @@ public final class io/sentry/NoOpTransaction : io/sentry/ITransaction { public fun finish ()V public fun finish (Lio/sentry/SpanStatus;)V public fun finish (Lio/sentry/SpanStatus;Lio/sentry/SentryDate;)V + public fun finish (Lio/sentry/SpanStatus;Lio/sentry/SentryDate;Z)V + public fun forceFinish (Lio/sentry/SpanStatus;Z)V public fun getContexts ()Lio/sentry/protocol/Contexts; public fun getData (Ljava/lang/String;)Ljava/lang/Object; public fun getDescription ()Ljava/lang/String; @@ -1782,6 +1786,8 @@ public final class io/sentry/SentryTracer : io/sentry/ITransaction { public fun finish ()V public fun finish (Lio/sentry/SpanStatus;)V public fun finish (Lio/sentry/SpanStatus;Lio/sentry/SentryDate;)V + public fun finish (Lio/sentry/SpanStatus;Lio/sentry/SentryDate;Z)V + public fun forceFinish (Lio/sentry/SpanStatus;Z)V public fun getChildren ()Ljava/util/List; public fun getContexts ()Lio/sentry/protocol/Contexts; public fun getData ()Ljava/util/Map; diff --git a/sentry/src/main/java/io/sentry/ITransaction.java b/sentry/src/main/java/io/sentry/ITransaction.java index 6e1c525fe88..90822f908da 100644 --- a/sentry/src/main/java/io/sentry/ITransaction.java +++ b/sentry/src/main/java/io/sentry/ITransaction.java @@ -79,6 +79,20 @@ public interface ITransaction extends ISpan { /** Schedules when transaction should be automatically finished. */ void scheduleFinish(); + /** + * Force finishes the transaction and it's child spans with the specified status. If the + * transaction is already finished this is a no-op. + * + * @param status The status to set the unfinished child spans / transaction to. + * @param forceKeep Ensures the transaction is kept even when it e.g. contains no child spans. + * Useful for situations were the transaction and profile provide crucial context (e.g. ANRs) + */ + @ApiStatus.Internal + void forceFinish(@NotNull final SpanStatus status, boolean forceKeep); + + @ApiStatus.Internal + void finish(@Nullable SpanStatus status, @Nullable SentryDate timestamp, boolean forceKeep); + @ApiStatus.Internal void setContext(@NotNull String key, @NotNull Object context); diff --git a/sentry/src/main/java/io/sentry/NoOpTransaction.java b/sentry/src/main/java/io/sentry/NoOpTransaction.java index eb92c66823b..bdd1a1860f5 100644 --- a/sentry/src/main/java/io/sentry/NoOpTransaction.java +++ b/sentry/src/main/java/io/sentry/NoOpTransaction.java @@ -95,6 +95,13 @@ public void setName(@NotNull String name, @NotNull TransactionNameSource transac @Override public void scheduleFinish() {} + @Override + public void forceFinish(@NotNull SpanStatus status, boolean forceKeep) {} + + @Override + public void finish( + @Nullable SpanStatus status, @Nullable SentryDate timestamp, boolean forceKeep) {} + @Override public boolean isFinished() { return true; diff --git a/sentry/src/main/java/io/sentry/SentryTracer.java b/sentry/src/main/java/io/sentry/SentryTracer.java index cf61fbdd3a9..c68ad861191 100644 --- a/sentry/src/main/java/io/sentry/SentryTracer.java +++ b/sentry/src/main/java/io/sentry/SentryTracer.java @@ -9,6 +9,7 @@ import io.sentry.util.Objects; import java.util.ArrayList; import java.util.List; +import java.util.ListIterator; import java.util.Map; import java.util.Timer; import java.util.TimerTask; @@ -127,6 +128,114 @@ public void run() { } } + @Override + public @NotNull void forceFinish(@NotNull SpanStatus status, boolean forceKeep) { + if (isFinished()) { + return; + } + + final @NotNull SentryDate finishTimestamp = hub.getOptions().getDateProvider().now(); + + // abort all child-spans first, this ensures the transaction can be finished, + // even if waitForChildren is true + // iterate in reverse order to ensure leaf spans are processed before their parents + @NotNull final ListIterator iterator = children.listIterator(children.size()); + while (iterator.hasPrevious()) { + @NotNull final Span span = iterator.previous(); + span.setSpanFinishedCallback(null); + span.finish(status, finishTimestamp); + } + finish(status, finishTimestamp, forceKeep); + } + + @Override + public void finish( + @Nullable SpanStatus status, @Nullable SentryDate finishDate, boolean forceKeep) { + // try to get the high precision timestamp from the root span + SentryDate finishTimestamp = root.getFinishDate(); + + // if a finishDate was passed in, use that instead + if (finishDate != null) { + finishTimestamp = finishDate; + } + + // if it's not set -> fallback to the current time + if (finishTimestamp == null) { + finishTimestamp = hub.getOptions().getDateProvider().now(); + } + + // auto-finish any idle spans first + for (final Span span : children) { + if (span.getOptions().isIdle()) { + span.finish((status != null) ? status : getSpanContext().status, finishTimestamp); + } + } + + this.finishStatus = FinishStatus.finishing(status); + if (!root.isFinished() + && (!transactionOptions.isWaitForChildren() || hasAllChildrenFinished())) { + List performanceCollectionData = null; + if (transactionPerformanceCollector != null) { + performanceCollectionData = transactionPerformanceCollector.stop(this); + } + + ProfilingTraceData profilingTraceData = null; + if (Boolean.TRUE.equals(isSampled()) && Boolean.TRUE.equals(isProfileSampled())) { + profilingTraceData = + hub.getOptions() + .getTransactionProfiler() + .onTransactionFinish(this, performanceCollectionData); + } + if (performanceCollectionData != null) { + performanceCollectionData.clear(); + } + + // finish unfinished children + for (final Span child : children) { + if (!child.isFinished()) { + child.setSpanFinishedCallback( + null); // reset the callback, as we're already in the finish method + child.finish(SpanStatus.DEADLINE_EXCEEDED, finishTimestamp); + } + } + root.finish(finishStatus.spanStatus, finishTimestamp); + + hub.configureScope( + scope -> { + scope.withTransaction( + transaction -> { + if (transaction == this) { + scope.clearTransaction(); + } + }); + }); + final SentryTransaction transaction = new SentryTransaction(this); + if (transactionFinishedCallback != null) { + transactionFinishedCallback.execute(this); + } + + if (timer != null) { + synchronized (timerLock) { + if (timer != null) { + timer.cancel(); + timer = null; + } + } + } + + if (!forceKeep && children.isEmpty() && transactionOptions.getIdleTimeout() != null) { + // if it's an idle transaction which has no children, we drop it to save user's quota + hub.getOptions() + .getLogger() + .log(SentryLevel.DEBUG, "Dropping idle transaction because it has no child spans"); + return; + } + + transaction.getMeasurements().putAll(measurements); + hub.captureTransaction(transaction, traceContext(), null, profilingTraceData); + } + } + private void cancelTimer() { synchronized (timerLock) { if (timerTask != null) { @@ -354,90 +463,7 @@ public void finish(@Nullable SpanStatus status) { @Override @ApiStatus.Internal public void finish(@Nullable SpanStatus status, @Nullable SentryDate finishDate) { - - // try to get the high precision timestamp from the root span - SentryDate finishTimestamp = root.getFinishDate(); - - // if a finishDate was passed in, use that instead - if (finishDate != null) { - finishTimestamp = finishDate; - } - - // if it's not set -> fallback to the current time - if (finishTimestamp == null) { - finishTimestamp = hub.getOptions().getDateProvider().now(); - } - - // auto-finish any idle spans first - for (final Span span : children) { - if (span.getOptions().isIdle()) { - span.finish((status != null) ? status : getSpanContext().status, finishTimestamp); - } - } - - this.finishStatus = FinishStatus.finishing(status); - if (!root.isFinished() - && (!transactionOptions.isWaitForChildren() || hasAllChildrenFinished())) { - List performanceCollectionData = null; - if (transactionPerformanceCollector != null) { - performanceCollectionData = transactionPerformanceCollector.stop(this); - } - - ProfilingTraceData profilingTraceData = null; - if (Boolean.TRUE.equals(isSampled()) && Boolean.TRUE.equals(isProfileSampled())) { - profilingTraceData = - hub.getOptions() - .getTransactionProfiler() - .onTransactionFinish(this, performanceCollectionData); - } - if (performanceCollectionData != null) { - performanceCollectionData.clear(); - } - - // finish unfinished children - for (final Span child : children) { - if (!child.isFinished()) { - child.setSpanFinishedCallback( - null); // reset the callback, as we're already in the finish method - child.finish(SpanStatus.DEADLINE_EXCEEDED, finishTimestamp); - } - } - root.finish(finishStatus.spanStatus, finishTimestamp); - - hub.configureScope( - scope -> { - scope.withTransaction( - transaction -> { - if (transaction == this) { - scope.clearTransaction(); - } - }); - }); - final SentryTransaction transaction = new SentryTransaction(this); - if (transactionFinishedCallback != null) { - transactionFinishedCallback.execute(this); - } - - if (timer != null) { - synchronized (timerLock) { - if (timer != null) { - timer.cancel(); - timer = null; - } - } - } - - if (children.isEmpty() && transactionOptions.getIdleTimeout() != null) { - // if it's an idle transaction which has no children, we drop it to save user's quota - hub.getOptions() - .getLogger() - .log(SentryLevel.DEBUG, "Dropping idle transaction because it has no child spans"); - return; - } - - transaction.getMeasurements().putAll(measurements); - hub.captureTransaction(transaction, traceContext(), null, profilingTraceData); - } + finish(status, finishDate, false); } @Override diff --git a/sentry/src/test/java/io/sentry/SentryTracerTest.kt b/sentry/src/test/java/io/sentry/SentryTracerTest.kt index f07249900f8..ecc6f5c9e4c 100644 --- a/sentry/src/test/java/io/sentry/SentryTracerTest.kt +++ b/sentry/src/test/java/io/sentry/SentryTracerTest.kt @@ -1096,4 +1096,102 @@ class SentryTracerTest { assertTrue(transaction.updateEndDate(endDate)) assertEquals(endDate, transaction.finishDate) } + + @Test + fun `when a finished transaction is force-finished it's a no-op`() { + // when a transaction is created + val transaction = fixture.getSut() + + // and it's finished + transaction.finish(SpanStatus.OK) + // but forceFinish is called as well + transaction.forceFinish(SpanStatus.ABORTED, false) + + // then it should keep it's original status + assertEquals(SpanStatus.OK, transaction.status) + } + + @Test + fun `when a transaction is force-finished all spans get finished as well`() { + val transaction = fixture.getSut( + waitForChildren = true, + idleTimeout = 50, + samplingDecision = TracesSamplingDecision(true) + ) + + // when two spans are created + val spanOptions = SpanOptions() + val span0 = transaction.startChild("load", null, spanOptions) as Span + val span1 = transaction.startChild("load", null, spanOptions) as Span + + // and one span is finished but not the other, and the transaction is force-finished + span0.finish(SpanStatus.OK) + val span0FinishDate = span0.finishDate + + transaction.forceFinish(SpanStatus.ABORTED, false) + + // then the first span should keep it's status + assertTrue(span0.isFinished) + assertEquals(SpanStatus.OK, span0.status) + assertEquals(span0FinishDate, span0.finishDate) + + // and the second span should have the same status as the transaction + assertTrue(span1.isFinished) + assertEquals(SpanStatus.ABORTED, span1.status) + assertEquals(transaction.finishDate, span1.finishDate) + + // and the transaction should be captured with both spans + verify(fixture.hub).captureTransaction( + check { + assertEquals(2, it.spans.size) + }, + anyOrNull(), + anyOrNull(), + anyOrNull() + ) + } + + @Test + fun `when a transaction with no childs is force-finished with force-keep it should be captured`() { + // when a transaction is created + val transaction = fixture.getSut( + waitForChildren = true, + idleTimeout = 50, + samplingDecision = TracesSamplingDecision(true) + ) + + // and force-finish with force-keep is called + transaction.forceFinish(SpanStatus.ABORTED, true) + + // then the transaction should be captured with 0 spans + verify(fixture.hub).captureTransaction( + check { + assertEquals(0, it.spans.size) + }, + anyOrNull(), + anyOrNull(), + anyOrNull() + ) + } + + @Test + fun `when a transaction with no childs is force-finished without force-keep it should be dropped`() { + // when a transaction is created + val transaction = fixture.getSut( + waitForChildren = true, + idleTimeout = 50, + samplingDecision = TracesSamplingDecision(true) + ) + + // and force-finish with force-keep is called + transaction.forceFinish(SpanStatus.ABORTED, false) + + // then the transaction should be captured with 0 spans + verify(fixture.hub, never()).captureTransaction( + anyOrNull(), + anyOrNull(), + anyOrNull(), + anyOrNull() + ) + } }