diff --git a/CHANGELOG.md b/CHANGELOG.md index 6accb560053..0fd81fa6d35 100644 --- a/CHANGELOG.md +++ b/CHANGELOG.md @@ -1,5 +1,11 @@ # Changelog +## Unreleased + +### Performance + +- Reduce the number of SDK threads: performance data collection now runs on the shared timer executor instead of creating a `java.util.Timer` thread per burst of transactions ([#5816](https://github.com/getsentry/sentry-java/pull/5816)) + ## 8.50.0 ### Android 17 support diff --git a/sentry/src/main/java/io/sentry/DefaultCompositePerformanceCollector.java b/sentry/src/main/java/io/sentry/DefaultCompositePerformanceCollector.java index 4736ab8fac5..7e3c80888ad 100644 --- a/sentry/src/main/java/io/sentry/DefaultCompositePerformanceCollector.java +++ b/sentry/src/main/java/io/sentry/DefaultCompositePerformanceCollector.java @@ -5,9 +5,8 @@ import java.util.ArrayList; import java.util.List; import java.util.Map; -import java.util.Timer; -import java.util.TimerTask; import java.util.concurrent.ConcurrentHashMap; +import java.util.concurrent.Future; import java.util.concurrent.TimeUnit; import java.util.concurrent.atomic.AtomicBoolean; import org.jetbrains.annotations.ApiStatus; @@ -19,7 +18,14 @@ public final class DefaultCompositePerformanceCollector implements CompositePerf private static final long TRANSACTION_COLLECTION_INTERVAL_MILLIS = 100; private static final long TRANSACTION_COLLECTION_TIMEOUT_MILLIS = 30000; private final @NotNull AutoClosableReentrantLock timerLock = new AutoClosableReentrantLock(); - private volatile @Nullable Timer timer = null; + private volatile @Nullable Future collectFuture = null; + + /** + * Incremented on close() so an in-flight collect run doesn't reschedule itself after its chain + * was cancelled. Guarded by timerLock. + */ + private long generation = 0; + private final @NotNull Map compositeDataMap = new ConcurrentHashMap<>(); private final @NotNull List snapshotCollectors; private final @NotNull List continuousCollectors; @@ -71,6 +77,7 @@ public void start(final @NotNull ITransaction transaction) { } @Override + @SuppressWarnings("FutureReturnValueIgnored") public void start(final @NotNull String id) { if (hasNoCollectors) { options @@ -88,60 +95,78 @@ public void start(final @NotNull String id) { } if (!isStarted.getAndSet(true)) { try (final @NotNull ISentryLifecycleToken ignored = timerLock.acquire()) { - if (timer == null) { - timer = new Timer(true); - } - // We schedule the timer to call setup() on collectors immediately in the background. - timer.schedule( - new TimerTask() { - @Override - public void run() { - for (IPerformanceSnapshotCollector collector : snapshotCollectors) { - collector.setup(); - } - } - }, - 0L); - // We schedule the timer to start after a delay, so we let some time pass between setup() - // and collect() calls. - // This way ICollectors that collect average stats based on time intervals, like - // AndroidCpuCollector, can have an actual time interval to evaluate. - final @NotNull List timedOutTransactions = new ArrayList<>(); - TimerTask timerTask = - new TimerTask() { - @Override - public void run() { - timedOutTransactions.clear(); - - final @NotNull PerformanceCollectionData tempData = - new PerformanceCollectionData(options.getDateProvider().now().nanoTimestamp()); - - // Enrich tempData using collectors - for (IPerformanceSnapshotCollector collector : snapshotCollectors) { - collector.collect(tempData); - } - - // Add the enriched tempData to all transactions/profiles/objects that collect data. - // Then Check if that object timed out. - for (CompositeData data : compositeDataMap.values()) { - if (data.addDataAndCheckTimeout(tempData)) { - // timed out - if (data.transaction != null) { - timedOutTransactions.add(data.transaction); + final long currentGeneration = generation; + try { + // We schedule the executor to call setup() on collectors immediately in the background. + options + .getTimerExecutorService() + .schedule( + () -> { + for (IPerformanceSnapshotCollector collector : snapshotCollectors) { + collector.setup(); } - } - } - // Stop timed out transactions outside compositeDataMap loop, as stop() modifies the - // map - for (final @NotNull ITransaction t : timedOutTransactions) { - stop(t); - } - } - }; - timer.schedule( - timerTask, - TRANSACTION_COLLECTION_INTERVAL_MILLIS, - TRANSACTION_COLLECTION_INTERVAL_MILLIS); + }, + 0L); + // We schedule the collection to start after a delay, so we let some time pass between + // setup() and collect() calls. + // This way ICollectors that collect average stats based on time intervals, like + // AndroidCpuCollector, can have an actual time interval to evaluate. + collectFuture = + options + .getTimerExecutorService() + .schedule( + () -> collectAndReschedule(currentGeneration), + TRANSACTION_COLLECTION_INTERVAL_MILLIS); + } catch (Throwable t) { + options + .getLogger() + .log(SentryLevel.WARNING, "Failed to schedule performance collection.", t); + } + } + } + } + + private void collectAndReschedule(final long scheduledGeneration) { + final @NotNull PerformanceCollectionData tempData = + new PerformanceCollectionData(options.getDateProvider().now().nanoTimestamp()); + + // Enrich tempData using collectors + for (IPerformanceSnapshotCollector collector : snapshotCollectors) { + collector.collect(tempData); + } + + // Add the enriched tempData to all transactions/profiles/objects that collect data. + // Then Check if that object timed out. + final @NotNull List timedOutTransactions = new ArrayList<>(); + for (CompositeData data : compositeDataMap.values()) { + if (data.addDataAndCheckTimeout(tempData)) { + // timed out + if (data.transaction != null) { + timedOutTransactions.add(data.transaction); + } + } + } + // Stop timed out transactions outside compositeDataMap loop, as stop() modifies the map + for (final @NotNull ITransaction t : timedOutTransactions) { + stop(t); + } + + try (final @NotNull ISentryLifecycleToken ignored = timerLock.acquire()) { + // stopping a timed out transaction above may have closed this collector; only reschedule if + // this run still belongs to the current collection chain + if (scheduledGeneration == generation) { + try { + collectFuture = + options + .getTimerExecutorService() + .schedule( + () -> collectAndReschedule(scheduledGeneration), + TRANSACTION_COLLECTION_INTERVAL_MILLIS); + } catch (Throwable t) { + options + .getLogger() + .log(SentryLevel.WARNING, "Failed to reschedule performance collection.", t); + } } } } @@ -201,9 +226,10 @@ public void close() { } if (isStarted.getAndSet(false)) { try (final @NotNull ISentryLifecycleToken ignored = timerLock.acquire()) { - if (timer != null) { - timer.cancel(); - timer = null; + generation++; + if (collectFuture != null) { + collectFuture.cancel(false); + collectFuture = null; } } } diff --git a/sentry/src/test/java/io/sentry/DefaultCompositePerformanceCollectorTest.kt b/sentry/src/test/java/io/sentry/DefaultCompositePerformanceCollectorTest.kt index bd1e584c2d7..79065bfb880 100644 --- a/sentry/src/test/java/io/sentry/DefaultCompositePerformanceCollectorTest.kt +++ b/sentry/src/test/java/io/sentry/DefaultCompositePerformanceCollectorTest.kt @@ -2,9 +2,9 @@ package io.sentry import io.sentry.test.getCtor import io.sentry.test.getProperty -import io.sentry.test.injectForField import io.sentry.util.thread.ThreadChecker -import java.util.Timer +import java.util.concurrent.CopyOnWriteArrayList +import java.util.concurrent.Future import java.util.concurrent.TimeUnit import kotlin.test.Test import kotlin.test.assertEquals @@ -34,7 +34,8 @@ class DefaultCompositePerformanceCollectorTest { val id1 = "id1" val scopes: IScopes = mock() val options = SentryOptions() - var mockTimer: Timer? = null + // a real executor so scheduled collection tasks actually run, recording schedule delays + val executorService = RecordingExecutorService(SentryExecutorService(options)) val mockCpuCollector: IPerformanceSnapshotCollector = object : IPerformanceSnapshotCollector { @@ -47,6 +48,7 @@ class DefaultCompositePerformanceCollectorTest { init { whenever(scopes.options).thenReturn(options) + options.setTimerExecutorService(executorService) } fun getSut( @@ -65,14 +67,23 @@ class DefaultCompositePerformanceCollectorTest { optionsConfiguration.configure(options) transaction1 = SentryTracer(TransactionContext("", ""), scopes) transaction2 = SentryTracer(TransactionContext("", ""), scopes) - val collector = DefaultCompositePerformanceCollector(options) - val timer: Timer = collector.getProperty("timer") ?: Timer(true) - mockTimer = spy(timer) - collector.injectForField("timer", mockTimer) - return collector + return DefaultCompositePerformanceCollector(options) } } + private class RecordingExecutorService(private val delegate: ISentryExecutorService) : + ISentryExecutorService by delegate { + val scheduledDelays = CopyOnWriteArrayList() + + override fun schedule(runnable: Runnable, delayMillis: Long): Future<*> { + scheduledDelays.add(delayMillis) + return delegate.schedule(runnable, delayMillis) + } + } + + private fun CompositePerformanceCollector.collectFuture(): Future<*>? = + getProperty?>("collectFuture") + @Test fun `when null param is provided, invalid argument is thrown`() { val ctor = className.getCtor(ctorTypes) @@ -85,7 +96,7 @@ class DefaultCompositePerformanceCollectorTest { val collector = fixture.getSut(null, null) assertTrue(fixture.options.performanceCollectors.isEmpty()) collector.start(fixture.transaction1) - verify(fixture.mockTimer, never())!!.schedule(any(), any(), any()) + assertTrue(fixture.executorService.scheduledDelays.isEmpty()) } @Test @@ -100,43 +111,43 @@ class DefaultCompositePerformanceCollectorTest { } @Test - fun `when start, timer is scheduled every 100 milliseconds`() { + fun `when start, collection is scheduled every 100 milliseconds`() { val collector = fixture.getSut() collector.start(fixture.transaction1) - verify(fixture.mockTimer)!!.schedule(any(), any(), eq(100)) + assertTrue(fixture.executorService.scheduledDelays.contains(100L)) } @Test - fun `when start with a string, timer is scheduled every 100 milliseconds`() { + fun `when start with a string, collection is scheduled every 100 milliseconds`() { val collector = fixture.getSut() collector.start(fixture.id1) - verify(fixture.mockTimer)!!.schedule(any(), any(), eq(100)) + assertTrue(fixture.executorService.scheduledDelays.contains(100L)) } @Test - fun `when stop, timer is stopped`() { + fun `when stop, collection is stopped`() { val collector = fixture.getSut() collector.start(fixture.transaction1) + assertNotNull(collector.collectFuture()) collector.stop(fixture.transaction1) - verify(fixture.mockTimer)!!.schedule(any(), any(), eq(100)) - verify(fixture.mockTimer)!!.cancel() + assertNull(collector.collectFuture()) } @Test - fun `when stop with a string, timer is stopped`() { + fun `when stop with a string, collection is stopped`() { val collector = fixture.getSut() collector.start(fixture.id1) + assertNotNull(collector.collectFuture()) collector.stop(fixture.id1) - verify(fixture.mockTimer)!!.schedule(any(), any(), eq(100)) - verify(fixture.mockTimer)!!.cancel() + assertNull(collector.collectFuture()) } @Test fun `stopping a not collected transaction return null`() { val collector = fixture.getSut() val data = collector.stop(fixture.transaction1) - verify(fixture.mockTimer, never())!!.schedule(any(), any(), eq(100)) - verify(fixture.mockTimer, never())!!.cancel() + assertTrue(fixture.executorService.scheduledDelays.isEmpty()) + assertNull(collector.collectFuture()) assertNull(data) } @@ -144,8 +155,8 @@ class DefaultCompositePerformanceCollectorTest { fun `stopping a not collected id return null`() { val collector = fixture.getSut() val data = collector.stop(fixture.id1) - verify(fixture.mockTimer, never())!!.schedule(any(), any(), eq(100)) - verify(fixture.mockTimer, never())!!.cancel() + assertTrue(fixture.executorService.scheduledDelays.isEmpty()) + assertNull(collector.collectFuture()) assertNull(data) } @@ -159,16 +170,16 @@ class DefaultCompositePerformanceCollectorTest { Thread.sleep(300) val data1 = collector.stop(fixture.transaction1) - // There is still a transaction and an id running: the timer shouldn't stop now - verify(fixture.mockTimer, never())!!.cancel() + // There is still a transaction and an id running: the collection shouldn't stop now + assertNotNull(collector.collectFuture()) val data2 = collector.stop(fixture.transaction2) - // There is still an id running: the timer shouldn't stop now - verify(fixture.mockTimer, never())!!.cancel() + // There is still an id running: the collection shouldn't stop now + assertNotNull(collector.collectFuture()) val data3 = collector.stop(fixture.id1) - // There are no more transactions or ids running: the time should stop now - verify(fixture.mockTimer)!!.cancel() + // There are no more transactions or ids running: the collection should stop now + assertNull(collector.collectFuture()) assertNotNull(data1) assertNotNull(data2) @@ -196,14 +207,14 @@ class DefaultCompositePerformanceCollectorTest { it.addPerformanceCollector(mockCollector) } collector.start(fixture.transaction1) - verify(fixture.mockTimer, never())!!.cancel() + assertNotNull(collector.collectFuture()) // Let's sleep to make the collector get values Thread.sleep(300) // When the collector gets the values, it checks the current date, set 31 seconds after the // begin. This means it should stop itself - verify(fixture.mockTimer)!!.cancel() + assertNull(collector.collectFuture()) // When the collector times out, the data collection for spans is stopped, too verify(mockCollector).onSpanFinished(eq(fixture.transaction1)) @@ -224,14 +235,14 @@ class DefaultCompositePerformanceCollectorTest { whenever(mockDateProvider.now()).thenReturn(dates[0], dates[0], dates[0], dates[1]) val collector = fixture.getSut { it.dateProvider = mockDateProvider } collector.start(fixture.transaction1) - verify(fixture.mockTimer, never())!!.cancel() + assertNotNull(collector.collectFuture()) // Let's sleep to make the collector get values Thread.sleep(300) // When the collector gets the values, it checks the current date, set 30 seconds after the // begin. This means it should continue without being cancelled - verify(fixture.mockTimer, never())!!.cancel() + assertNotNull(collector.collectFuture()) // Data is deleted after the collector times out val data1 = collector.stop(fixture.transaction1) @@ -296,14 +307,14 @@ class DefaultCompositePerformanceCollectorTest { } @Test - fun `when close, timer is stopped and data is cleared`() { + fun `when close, collection is stopped and data is cleared`() { val collector = fixture.getSut() collector.start(fixture.transaction1) collector.close() - // Timer was canceled - verify(fixture.mockTimer)!!.schedule(any(), any(), eq(100)) - verify(fixture.mockTimer)!!.cancel() + // Collection was canceled + assertTrue(fixture.executorService.scheduledDelays.contains(100L)) + assertNull(collector.collectFuture()) // Data was cleared assertNull(collector.stop(fixture.transaction1))