Skip to content
Merged
4 changes: 4 additions & 0 deletions CHANGELOG.md
Original file line number Diff line number Diff line change
Expand Up @@ -2,6 +2,10 @@

## Unreleased

### Fixes

- Avoid ExecutorService for DefaultCompositePerformanceCollector timeout ([#4841](https://github.com/getsentry/sentry-java/pull/4841))

### Dependencies

- Bump Native SDK from v0.11.2 to v0.11.3 ([#4810](https://github.com/getsentry/sentry-java/pull/4810))
Expand Down
Original file line number Diff line number Diff line change
Expand Up @@ -8,7 +8,7 @@
import java.util.Timer;
import java.util.TimerTask;
import java.util.concurrent.ConcurrentHashMap;
import java.util.concurrent.RejectedExecutionException;
import java.util.concurrent.TimeUnit;
import java.util.concurrent.atomic.AtomicBoolean;
import org.jetbrains.annotations.ApiStatus;
import org.jetbrains.annotations.NotNull;
Expand All @@ -20,8 +20,7 @@ public final class DefaultCompositePerformanceCollector implements CompositePerf
private static final long TRANSACTION_COLLECTION_TIMEOUT_MILLIS = 30000;
private final @NotNull AutoClosableReentrantLock timerLock = new AutoClosableReentrantLock();
private volatile @Nullable Timer timer = null;
private final @NotNull Map<String, List<PerformanceCollectionData>> performanceDataMap =
new ConcurrentHashMap<>();
private final @NotNull Map<String, CompositeData> compositeDataMap = new ConcurrentHashMap<>();
private final @NotNull List<IPerformanceSnapshotCollector> snapshotCollectors;
private final @NotNull List<IPerformanceContinuousCollector> continuousCollectors;
private final boolean hasNoCollectors;
Expand Down Expand Up @@ -65,23 +64,11 @@ public void start(final @NotNull ITransaction transaction) {
collector.onSpanStarted(transaction);
}

if (!performanceDataMap.containsKey(transaction.getEventId().toString())) {
performanceDataMap.put(transaction.getEventId().toString(), new ArrayList<>());
// We schedule deletion of collected performance data after a timeout
try {
options
.getExecutorService()
.schedule(() -> stop(transaction), TRANSACTION_COLLECTION_TIMEOUT_MILLIS);
} catch (RejectedExecutionException e) {
options
.getLogger()
.log(
SentryLevel.ERROR,
"Failed to call the executor. Performance collector will not be automatically finished. Did you call Sentry.close()?",
e);
}
final @NotNull String id = transaction.getEventId().toString();
if (!compositeDataMap.containsKey(id)) {
compositeDataMap.put(id, new CompositeData(id, true));
}
start(transaction.getEventId().toString());
start(id);
}

@Override
Expand All @@ -95,8 +82,10 @@ public void start(final @NotNull String id) {
return;
}

if (!performanceDataMap.containsKey(id)) {
performanceDataMap.put(id, new ArrayList<>());
if (!compositeDataMap.containsKey(id)) {
// Transactions are added in start(ITransaction). If we are here, it means we don't come from
// a transaction
compositeDataMap.put(id, new CompositeData(id, false));
}
if (!isStarted.getAndSet(true)) {
try (final @NotNull ISentryLifecycleToken ignored = timerLock.acquire()) {
Expand Down Expand Up @@ -131,14 +120,17 @@ public void run() {
}
lastCollectionTimestamp = now;
final @NotNull PerformanceCollectionData tempData =
new PerformanceCollectionData(new SentryNanotimeDate().nanoTimestamp());
new PerformanceCollectionData(options.getDateProvider().now().nanoTimestamp());

for (IPerformanceSnapshotCollector collector : snapshotCollectors) {
collector.collect(tempData);
}

for (List<PerformanceCollectionData> data : performanceDataMap.values()) {
data.add(tempData);
for (CompositeData data : compositeDataMap.values()) {
if (data.addDataAndCheckTimeout(tempData)) {
// timed out
stop(data.id);
}
}
}
};
Expand Down Expand Up @@ -183,13 +175,14 @@ public void onSpanFinished(@NotNull ISpan span) {

@Override
public @Nullable List<PerformanceCollectionData> stop(final @NotNull String id) {
final @Nullable List<PerformanceCollectionData> data = performanceDataMap.remove(id);
final @Nullable CompositeData data = compositeDataMap.remove(id);
options.getLogger().log(SentryLevel.DEBUG, "stop collecting performance info for " + id);

// close if they are no more running requests
if (performanceDataMap.isEmpty()) {
// close if there are no more running requests
if (compositeDataMap.isEmpty()) {
close();
}
return data;
return data != null ? data.dataList : null;
}

@Override
Expand All @@ -198,7 +191,7 @@ public void close() {
.getLogger()
.log(SentryLevel.DEBUG, "stop collecting all performance info for transactions");

performanceDataMap.clear();
compositeDataMap.clear();
for (final @NotNull IPerformanceContinuousCollector collector : continuousCollectors) {
collector.clear();
}
Expand All @@ -211,4 +204,32 @@ public void close() {
}
}
}

private class CompositeData {
private final @NotNull List<PerformanceCollectionData> dataList;
private final @NotNull String id;
private final boolean isTransaction;
private final long startTimestamp;

private CompositeData(final @NotNull String id, final boolean isTransaction) {
this.dataList = new ArrayList<>();
this.id = id;
this.isTransaction = isTransaction;
this.startTimestamp = options.getDateProvider().now().nanoTimestamp();
}

/**
* Adds the data to the internal list of PerformanceCollectionData. Then it checks if data
* collection timed out (for transactions only).
*
* @return true if data collection timed out (for transactions only).
*/
boolean addDataAndCheckTimeout(final @NotNull PerformanceCollectionData data) {
dataList.add(data);
return isTransaction
&& options.getDateProvider().now().nanoTimestamp()
> startTimestamp
+ TimeUnit.MILLISECONDS.toNanos(TRANSACTION_COLLECTION_TIMEOUT_MILLIS);
}
}
}
Original file line number Diff line number Diff line change
@@ -1,12 +1,12 @@
package io.sentry

import io.sentry.test.DeferredExecutorService
import io.sentry.test.getCtor
import io.sentry.test.getProperty
import io.sentry.test.injectForField
import io.sentry.util.thread.ThreadChecker
import java.util.Date
import java.util.Timer
import java.util.concurrent.RejectedExecutionException
import java.util.concurrent.TimeUnit
import kotlin.test.Test
import kotlin.test.assertEquals
import kotlin.test.assertFailsWith
Expand Down Expand Up @@ -36,7 +36,6 @@ class DefaultCompositePerformanceCollectorTest {
val scopes: IScopes = mock()
val options = SentryOptions()
var mockTimer: Timer? = null
val deferredExecutorService = DeferredExecutorService()

val mockCpuCollector: IPerformanceSnapshotCollector =
object : IPerformanceSnapshotCollector {
Expand All @@ -54,16 +53,17 @@ class DefaultCompositePerformanceCollectorTest {
fun getSut(
memoryCollector: IPerformanceSnapshotCollector? = JavaMemoryCollector(),
cpuCollector: IPerformanceSnapshotCollector? = mockCpuCollector,
executorService: ISentryExecutorService = deferredExecutorService,
optionsConfiguration: Sentry.OptionsConfiguration<SentryOptions> =
Sentry.OptionsConfiguration {},
): CompositePerformanceCollector {
options.dsn = "https://[email protected]/proj"
options.executorService = executorService
if (cpuCollector != null) {
options.addPerformanceCollector(cpuCollector)
}
if (memoryCollector != null) {
options.addPerformanceCollector(memoryCollector)
}
optionsConfiguration.configure(options)
transaction1 = SentryTracer(TransactionContext("", ""), scopes)
transaction2 = SentryTracer(TransactionContext("", ""), scopes)
val collector = DefaultCompositePerformanceCollector(options)
Expand Down Expand Up @@ -184,21 +184,66 @@ class DefaultCompositePerformanceCollectorTest {

@Test
fun `collector times out after 30 seconds`() {
val collector = fixture.getSut()
val mockDateProvider = mock<SentryDateProvider>()
val dates =
listOf(
SentryNanotimeDate(
Date().apply { time = TimeUnit.SECONDS.toMillis(100) },
TimeUnit.SECONDS.toNanos(100),
),
SentryNanotimeDate(
Date().apply { time = TimeUnit.SECONDS.toMillis(131) },
TimeUnit.SECONDS.toNanos(131),
),
)
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()

// Let's sleep to make the collector get values
Thread.sleep(300)
verify(fixture.mockTimer, never())!!.cancel()

// Let the timeout job stop the collector
fixture.deferredExecutorService.runAll()
// 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()

// Data is deleted after the collector times out
val data1 = collector.stop(fixture.transaction1)
assertNull(data1)
}

@Test
fun `collector collects for 30 seconds`() {
val mockDateProvider = mock<SentryDateProvider>()
val dates =
listOf(
SentryNanotimeDate(
Date().apply { time = TimeUnit.SECONDS.toMillis(100) },
TimeUnit.SECONDS.toNanos(100),
),
SentryNanotimeDate(
Date().apply { time = TimeUnit.SECONDS.toMillis(130) },
TimeUnit.SECONDS.toNanos(130),
),
)
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()

// 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()

// Data is deleted after the collector times out
val data1 = collector.stop(fixture.transaction1)
assertNotNull(data1)
}

@Test
fun `collector has no IPerformanceCollector by default`() {
val collector = fixture.getSut(null, null)
Expand Down Expand Up @@ -270,25 +315,6 @@ class DefaultCompositePerformanceCollectorTest {
assertNull(collector.stop(fixture.transaction1))
}

@Test
fun `start does not throw on executor shut down`() {
val executorService = mock<ISentryExecutorService>()
whenever(executorService.schedule(any(), any())).thenThrow(RejectedExecutionException())
val logger = mock<ILogger>()
fixture.options.setLogger(logger)
fixture.options.isDebug = true
val sut = fixture.getSut(executorService = executorService)
sut.start(fixture.transaction1)
verify(logger)
.log(
eq(SentryLevel.ERROR),
eq(
"Failed to call the executor. Performance collector will not be automatically finished. Did you call Sentry.close()?"
),
any(),
)
}

@Test
fun `Continuous collectors are notified properly`() {
val collector = mock<IPerformanceContinuousCollector>()
Expand Down
Loading