diff --git a/CHANGELOG.md b/CHANGELOG.md index 0723a5ae0e..a10dd9b1c4 100644 --- a/CHANGELOG.md +++ b/CHANGELOG.md @@ -8,6 +8,7 @@ - Prevent duplicated breadcrumbs on tombstone-merged native crash events ([#5888](https://github.com/getsentry/sentry-java/pull/5888)) - Prevent a class of Session Replay deadlocks by confining lifecycle state changes to Android's main thread ([#5965](https://github.com/getsentry/sentry-java/pull/5965)) - Symbolicate tombstone native frames for libraries loaded directly from APKs ([#5992](https://github.com/getsentry/sentry-java/pull/5992)) +- Prevent a deadlock between the app start extension and the Android performance event processor ([#6007](https://github.com/getsentry/sentry-java/pull/6007)) ### Features diff --git a/sentry-android-core/src/main/java/io/sentry/android/core/AppStartExtension.java b/sentry-android-core/src/main/java/io/sentry/android/core/AppStartExtension.java index 3583474cfa..793ebc5443 100644 --- a/sentry-android-core/src/main/java/io/sentry/android/core/AppStartExtension.java +++ b/sentry-android-core/src/main/java/io/sentry/android/core/AppStartExtension.java @@ -34,6 +34,10 @@ public interface ExtendAppStartListener { private final @NotNull AppStartMetrics metrics; private final @NotNull AutoClosableReentrantLock lock = new AutoClosableReentrantLock(); + // Serializes the two finish paths against each other. Deliberately separate from `lock`: + // finishing re-enters the SDK and that re-entrant path takes `lock`, so the finish cannot run + // under `lock` (see finishTransaction). When both are held the order is finishLock, then `lock`. + private final @NotNull AutoClosableReentrantLock finishLock = new AutoClosableReentrantLock(); private @Nullable ExtendAppStartListener extendAppStartListener; // We hold onto both the span and its transaction because they mean different things and finish @@ -108,8 +112,12 @@ public void setData(final @NotNull String key, final @Nullable Object value) { @Override public void finishExtendedAppStart() { - try (final @NotNull ISentryLifecycleToken ignored = lock.acquire()) { - final @Nullable ISpan span = extendedSpan; + try (final @NotNull ISentryLifecycleToken ignoredFinish = finishLock.acquire()) { + final @Nullable ISpan span; + try (final @NotNull ISentryLifecycleToken ignored = lock.acquire()) { + span = extendedSpan; + } + // Finishing runs outside `lock`, see the note on finishTransaction. if (span != null && !span.isFinished()) { span.finish(SpanStatus.OK); } @@ -145,10 +153,19 @@ public boolean isExtended() { } public void finishTransaction(final @NotNull SentryDate endTimestamp) { - try (final @NotNull ISentryLifecycleToken ignored = lock.acquire()) { - final @Nullable ITransaction transaction = extendedTransaction; + // Finishing has to run outside `lock`: it captures the transaction synchronously, which runs + // PerformanceAndroidEventProcessor, which calls back into isExtended()/getExtendedEndTime() + // while holding its own lock. Holding `lock` across the call would let the two be taken in + // opposite orders and deadlock. finishLock still serializes this against + // finishExtendedAppStart, so the end-time clamp below and the finish stay atomic. + try (final @NotNull ISentryLifecycleToken ignoredFinish = finishLock.acquire()) { + final @Nullable ITransaction transaction; + final @Nullable ISpan span; + try (final @NotNull ISentryLifecycleToken ignored = lock.acquire()) { + transaction = extendedTransaction; + span = extendedSpan; + } if (transaction != null && !transaction.isFinished()) { - final @Nullable ISpan span = extendedSpan; final @Nullable SentryDate spanEnd = span == null ? null : span.getFinishDate(); final @NotNull SentryDate end = spanEnd != null && spanEnd.isAfter(endTimestamp) ? spanEnd : endTimestamp; diff --git a/sentry-android-core/src/test/java/io/sentry/android/core/AppStartExtensionTest.kt b/sentry-android-core/src/test/java/io/sentry/android/core/AppStartExtensionTest.kt index 7fbbca4a3a..38f7f29e7d 100644 --- a/sentry-android-core/src/test/java/io/sentry/android/core/AppStartExtensionTest.kt +++ b/sentry-android-core/src/test/java/io/sentry/android/core/AppStartExtensionTest.kt @@ -8,6 +8,9 @@ import io.sentry.SentryLongDate import io.sentry.SentryNanotimeDate import io.sentry.SpanStatus import io.sentry.android.core.performance.AppStartMetrics +import java.util.concurrent.CountDownLatch +import java.util.concurrent.TimeUnit +import java.util.concurrent.atomic.AtomicBoolean import java.util.concurrent.atomic.AtomicInteger import kotlin.test.Test import kotlin.test.assertEquals @@ -17,6 +20,7 @@ import kotlin.test.assertSame import kotlin.test.assertTrue import org.junit.runner.RunWith import org.mockito.kotlin.any +import org.mockito.kotlin.doAnswer import org.mockito.kotlin.mock import org.mockito.kotlin.never import org.mockito.kotlin.verify @@ -34,6 +38,26 @@ class AppStartExtensionTest { return AppStartExtension(metrics) } + private class ReentrantCall(val run: () -> Unit, val succeeded: AtomicBoolean) + + /** + * Runs [call] on another thread and records whether it completed while the caller is still inside + * the stubbed method. Used to prove a lock is not held across that call. + */ + private fun reentrantCallDuring(call: () -> Unit): ReentrantCall { + val succeeded = AtomicBoolean(false) + val done = CountDownLatch(1) + val run = { + Thread { + call() + done.countDown() + } + .start() + succeeded.set(done.await(2, TimeUnit.SECONDS)) + } + return ReentrantCall(run, succeeded) + } + /** Simulates the integration's listener: hands a transaction + span back to the extension. */ private fun AppStartExtension.registerHandOver( txn: ITransaction = mock(), @@ -123,6 +147,68 @@ class AppStartExtensionTest { verify(span, never()).finish(any()) } + @Test + fun `finishExtendedAppStart releases the lock before finishing the span`() { + val ext = extension(windowOpen = true) + val span = mock() + ext.registerHandOver(span = span) + ext.extendAppStart() + + // Finishing the real span captures the transaction synchronously, which runs + // PerformanceAndroidEventProcessor, which calls back into the extension while holding its own + // lock. Holding this lock across the finish lets the two be taken in opposite orders and + // deadlock, so require another thread to get through the extension lock during the finish. + val reentered = reentrantCallDuring { ext.isExtended } + doAnswer { reentered.run() }.whenever(span).finish(any()) + + ext.finishExtendedAppStart() + + assertTrue(reentered.succeeded.get(), "extension lock was held while finishing the span") + } + + @Test + fun `finishTransaction releases the lock before finishing the transaction`() { + val ext = extension(windowOpen = true) + val txn = mock() + ext.registerHandOver(txn = txn) + ext.extendAppStart() + + val reentered = reentrantCallDuring { ext.isExtended } + doAnswer { reentered.run() }.whenever(txn).finish(any(), any()) + + ext.finishTransaction(SentryNanotimeDate()) + + assertTrue(reentered.succeeded.get(), "extension lock was held while finishing the transaction") + } + + @Test + fun `finishTransaction and finishExtendedAppStart do not interleave`() { + val ext = extension(windowOpen = true) + val txn = mock() + val span = mock() + ext.registerHandOver(txn = txn, span = span) + ext.extendAppStart() + + // The end-time clamp in finishTransaction reads the span's finish date and then finishes the + // transaction. If finishExtendedAppStart can finish the span in between, the transaction is + // captured with an end earlier than its own child span. + val spanFinished = AtomicBoolean(false) + val interleaved = AtomicBoolean(false) + doAnswer { spanFinished.set(true) }.whenever(span).finish(any()) + doAnswer { + val other = Thread { ext.finishExtendedAppStart() } + other.start() + other.join(1_000) + interleaved.set(spanFinished.get()) + } + .whenever(txn) + .finish(any(), any()) + + ext.finishTransaction(SentryNanotimeDate()) + + assertFalse(interleaved.get(), "the extended span was finished mid-finishTransaction") + } + @Test fun `isActive reflects the transaction state`() { val ext = extension(windowOpen = true)