From c43c325a7ce1eb8d2ca672b34531b7acc9213a76 Mon Sep 17 00:00:00 2001 From: Markus Hintersteiner Date: Thu, 27 Aug 2026 10:24:55 +0200 Subject: [PATCH 1/2] feat(profiling): drop profiler ids from spans no profile covers Co-Authored-By: Claude Opus 5 --- .../api/sentry-android-core.api | 3 +- .../core/AndroidContinuousProfiler.java | 13 + .../core/PerfettoContinuousProfiler.java | 120 +++++++++- .../sentry/android/core/PerfettoProfiler.java | 55 ++++- .../core/internal/profiling/ChunkRecord.java | 68 ++++++ .../core/PerfettoContinuousProfilerTest.kt | 226 +++++++++++++++++- .../android/core/PerfettoProfilerTest.kt | 122 ++++++++-- .../internal/profiling/ChunkRecordTest.kt | 81 +++++++ .../api/sentry-async-profiler.api | 1 + .../profiling/JavaContinuousProfiler.java | 13 + sentry/api/sentry.api | 10 + .../java/io/sentry/IContinuousProfiler.java | 18 ++ .../io/sentry/NoOpContinuousProfiler.java | 9 + .../src/main/java/io/sentry/SentryTracer.java | 62 +++++ .../profiling/ProfileRecordingState.java | 11 + .../test/java/io/sentry/SentryTracerTest.kt | 162 +++++++++++++ .../profiling/ProfilingServiceLoaderTest.kt | 9 + 17 files changed, 947 insertions(+), 36 deletions(-) create mode 100644 sentry-android-core/src/main/java/io/sentry/android/core/internal/profiling/ChunkRecord.java create mode 100644 sentry-android-core/src/test/java/io/sentry/android/core/internal/profiling/ChunkRecordTest.kt create mode 100644 sentry/src/main/java/io/sentry/profiling/ProfileRecordingState.java diff --git a/sentry-android-core/api/sentry-android-core.api b/sentry-android-core/api/sentry-android-core.api index 65bf072f0a0..696c26b9d2d 100644 --- a/sentry-android-core/api/sentry-android-core.api +++ b/sentry-android-core/api/sentry-android-core.api @@ -44,6 +44,7 @@ public class io/sentry/android/core/AndroidContinuousProfiler : io/sentry/IConti public fun (Lio/sentry/android/core/BuildInfoProvider;Lio/sentry/android/core/internal/util/SentryFrameMetricsCollector;Lio/sentry/ILogger;Ljava/lang/String;ILio/sentry/util/LazyEvaluator$Evaluator;)V public fun close (Z)V public fun getChunkId ()Lio/sentry/protocol/SentryId; + public fun getProfileRecordingState (Lio/sentry/protocol/SentryId;Lio/sentry/SentryDate;Lio/sentry/SentryDate;)Lio/sentry/profiling/ProfileRecordingState; public fun getProfilerId ()Lio/sentry/protocol/SentryId; public fun getRootSpanCounter ()I public fun isRunning ()Z @@ -369,6 +370,7 @@ public class io/sentry/android/core/PerfettoContinuousProfiler : io/sentry/ICont public fun (Lio/sentry/ILogger;Lio/sentry/android/core/internal/util/SentryFrameMetricsCollector;Lio/sentry/util/LazyEvaluator$Evaluator;Ljava/util/function/Supplier;)V public fun close (Z)V public fun getChunkId ()Lio/sentry/protocol/SentryId; + public fun getProfileRecordingState (Lio/sentry/protocol/SentryId;Lio/sentry/SentryDate;Lio/sentry/SentryDate;)Lio/sentry/profiling/ProfileRecordingState; public fun getProfilerId ()Lio/sentry/protocol/SentryId; public fun isRunning ()Z public fun onRateLimitChanged (Lio/sentry/transport/RateLimiter;)V @@ -380,7 +382,6 @@ public class io/sentry/android/core/PerfettoContinuousProfiler : io/sentry/ICont public class io/sentry/android/core/PerfettoProfiler { public fun (Landroid/content/Context;Lio/sentry/ILogger;Lio/sentry/ISentryExecutorService;)V public fun endAndCollect (Ljava/util/function/Consumer;)V - public fun start (J)Z } public final class io/sentry/android/core/ScreenshotEventProcessor : io/sentry/EventProcessor { diff --git a/sentry-android-core/src/main/java/io/sentry/android/core/AndroidContinuousProfiler.java b/sentry-android-core/src/main/java/io/sentry/android/core/AndroidContinuousProfiler.java index a1c0c097cb9..20fea39a28d 100644 --- a/sentry-android-core/src/main/java/io/sentry/android/core/AndroidContinuousProfiler.java +++ b/sentry-android-core/src/main/java/io/sentry/android/core/AndroidContinuousProfiler.java @@ -23,6 +23,7 @@ import io.sentry.SentryOptions; import io.sentry.TracesSampler; import io.sentry.android.core.internal.util.SentryFrameMetricsCollector; +import io.sentry.profiling.ProfileRecordingState; import io.sentry.protocol.SentryId; import io.sentry.transport.RateLimiter; import io.sentry.util.AutoClosableReentrantLock; @@ -358,6 +359,18 @@ public void close(final boolean isTerminating) { return chunkId; } + /** + * This profiler does not track the outcome of its profiling requests, so the answer is always + * unknown. + */ + @Override + public @NotNull ProfileRecordingState getProfileRecordingState( + final @NotNull SentryId profilerId, + final @NotNull SentryDate startTime, + final @NotNull SentryDate endTime) { + return ProfileRecordingState.UNKNOWN; + } + private void sendChunks(final @NotNull IScopes scopes, final @NotNull SentryOptions options) { try { options diff --git a/sentry-android-core/src/main/java/io/sentry/android/core/PerfettoContinuousProfiler.java b/sentry-android-core/src/main/java/io/sentry/android/core/PerfettoContinuousProfiler.java index 731be774339..2828628fd2b 100644 --- a/sentry-android-core/src/main/java/io/sentry/android/core/PerfettoContinuousProfiler.java +++ b/sentry-android-core/src/main/java/io/sentry/android/core/PerfettoContinuousProfiler.java @@ -23,9 +23,11 @@ import io.sentry.SentryNanotimeDate; import io.sentry.SentryOptions; import io.sentry.TracesSampler; +import io.sentry.android.core.internal.profiling.ChunkRecord; import io.sentry.android.core.internal.util.SentryFrameMetricsCollector; import io.sentry.profilemeasurements.ProfileMeasurement; import io.sentry.profilemeasurements.ProfileMeasurementValue; +import io.sentry.profiling.ProfileRecordingState; import io.sentry.protocol.SentryId; import io.sentry.transport.RateLimiter; import io.sentry.util.AutoClosableReentrantLock; @@ -59,11 +61,15 @@ *

Currently, this class doesn't do app-start profiling {@link SentryPerformanceProvider}. It is * created during {@code Sentry.init()}. * - *

Thread safety: all mutable state is guarded by a single {@link - * io.sentry.util.AutoClosableReentrantLock}. Public entry points ({@link #startProfiler}, {@link - * #stopProfiler}, {@link #close}, {@link #onRateLimitChanged}, {@link #reevaluateSampling}, and the - * getters) acquire the lock themselves and are thread-safe. Private methods {@code startInternal} - * and {@code stopInternal} require the caller to hold the lock. + *

Thread safety: the profiler state is guarded by {@link #lock}. Every public entry point + * acquires it itself and is thread-safe. Private methods that say {@code Caller must hold} a lock + * do not, and must only be reached from a frame that already holds it. + * + *

The chunk history is guarded by its own {@link #chunkHistoryLock}, so that {@link + * #getProfileRecordingState} — called for every span of a finishing transaction — never waits for a + * chunk start or a chunk stop. A frame holding {@link #lock} may take {@link #chunkHistoryLock}, + * never the other way around. Each {@link ChunkRecord} guards its own state, as the profiler writes + * the outcome of a running chunk into it. */ @ApiStatus.Internal @RequiresApi(api = Build.VERSION_CODES.VANILLA_ICE_CREAM) @@ -71,6 +77,12 @@ public class PerfettoContinuousProfiler implements IContinuousProfiler, RateLimiter.IRateLimitObserver { private static final long MAX_CHUNK_DURATION_MILLIS = 60000; + /** + * How many chunks we remember the outcome of. Spans only ask about windows they were running in, + * so a handful of chunks (a minute each) is plenty. + */ + @VisibleForTesting static final int MAX_CHUNK_HISTORY_SIZE = 10; + // Matches the thread name produced by SentryExecutorService's thread factory, used to detect // when we are already running on the executor thread. private static final String EXECUTOR_THREAD_NAME_PREFIX = "SentryExecutorServiceThreadFactory"; @@ -96,6 +108,12 @@ public class PerfettoContinuousProfiler private final AutoClosableReentrantLock lock = new AutoClosableReentrantLock(); + private final @NotNull ArrayDeque chunkHistory = + new ArrayDeque<>(MAX_CHUNK_HISTORY_SIZE); + private @Nullable ChunkRecord currentChunk = null; + + private final AutoClosableReentrantLock chunkHistoryLock = new AutoClosableReentrantLock(); + public PerfettoContinuousProfiler( final @NotNull ILogger logger, final @NotNull SentryFrameMetricsCollector frameMetricsCollector, @@ -188,6 +206,8 @@ public void close(final boolean isTerminating) { if (isTerminating) { stopInternal(false); isClosed.set(true); + // sendChunk drops everything once isClosed is set, so the chunk that just ended is lost + markLastChunkNotRecordedIfUnknown(); } } } @@ -213,6 +233,65 @@ public boolean isRunning() { } } + @Override + public @NotNull ProfileRecordingState getProfileRecordingState( + final @NotNull SentryId profilerId, + final @NotNull SentryDate startTime, + final @NotNull SentryDate endTime) { + try (final @NotNull ISentryLifecycleToken ignored = chunkHistoryLock.acquire()) { + if (chunkHistory.isEmpty()) { + return ProfileRecordingState.UNKNOWN; + } + + for (final @NotNull ChunkRecord chunk : chunkHistory) { + // A chunk that is still running, or that is still being collected, is assumed to be + // recorded in the end + if (chunk.getProfilerId().equals(profilerId) + && chunk.overlaps(startTime, endTime) + && chunk.getRecordingState() != ProfileRecordingState.NOT_RECORDED) { + return ProfileRecordingState.RECORDED; + } + } + + // Every chunk overlapping the window failed, or no chunk ran during the window at all + return ProfileRecordingState.NOT_RECORDED; + } + } + + /** + * Gives up on the newest chunk, unless its outcome is already known. Only that one can still be + * undecided, as a chunk is decided before the next one starts. + */ + private void markLastChunkNotRecordedIfUnknown() { + try (final @NotNull ISentryLifecycleToken ignored = chunkHistoryLock.acquire()) { + final @Nullable ChunkRecord lastChunk = chunkHistory.peekLast(); + if (lastChunk != null && lastChunk.getRecordingState() == ProfileRecordingState.UNKNOWN) { + lastChunk.setRecordingState(ProfileRecordingState.NOT_RECORDED); + } + } + } + + private void addChunkRecord(final @NotNull ChunkRecord chunk) { + try (final @NotNull ISentryLifecycleToken ignored = chunkHistoryLock.acquire()) { + if (chunkHistory.size() == MAX_CHUNK_HISTORY_SIZE) { + chunkHistory.removeFirst(); + } + currentChunk = chunk; + chunkHistory.addLast(chunk); + } + } + + private @Nullable ChunkRecord endChunkRecord(final @NotNull SentryDate endTimestamp) { + try (final @NotNull ISentryLifecycleToken ignored = chunkHistoryLock.acquire()) { + final @Nullable ChunkRecord chunk = currentChunk; + if (chunk != null) { + chunk.setEndTimestamp(endTimestamp); + currentChunk = null; + } + return chunk; + } + } + /** * Resolves scopes on first call. Since PerfettoContinuousProfiler is created during Sentry.init() * and never used for app-start profiling, scopes is guaranteed to be available by the time @@ -265,23 +344,27 @@ private void startInternal() { if (perfettoProfiler == null) { return; } - if (!perfettoProfiler.start(MAX_CHUNK_DURATION_MILLIS)) { + if (SentryId.EMPTY_ID.equals(profilerId)) { + profilerId = new SentryId(); + } + + final @Nullable ChunkRecord chunkRecord = + perfettoProfiler.start(startProfileChunkTimestamp, profilerId, MAX_CHUNK_DURATION_MILLIS); + if (chunkRecord == null) { + profilerId = SentryId.EMPTY_ID; + chunkId = SentryId.EMPTY_ID; logger.log( SentryLevel.ERROR, - "Failed to start Perfetto profiling. PerfettoProfiler.start() returned false."); + "Failed to start Perfetto profiling. PerfettoProfiler.start() returned no chunk."); return; } isRunning = true; - - if (profilerId.equals(SentryId.EMPTY_ID)) { - profilerId = new SentryId(); - } - if (chunkId.equals(SentryId.EMPTY_ID)) { chunkId = new SentryId(); } + addChunkRecord(chunkRecord); chunkMeasurements.start(performanceCollector, chunkId.toString()); try { @@ -328,6 +411,7 @@ private void stopInternal(final boolean restartProfiler) { final @NotNull SentryId chunkProfilerId = profilerId; final @NotNull SentryId chunkChunkId = chunkId; final @NotNull SentryDate chunkTimestamp = startProfileChunkTimestamp; + final @Nullable ChunkRecord chunkRecord = endChunkRecord(options.getDateProvider().now()); isRunning = false; perfettoProfiler = null; @@ -348,6 +432,7 @@ private void stopInternal(final boolean restartProfiler) { traceFile, chunkProfilerId, chunkChunkId, + chunkRecord, measurements, chunkTimestamp, shouldRestart, @@ -359,11 +444,22 @@ private void onChunkCollected( final @Nullable File traceFile, final @NotNull SentryId chunkProfilerId, final @NotNull SentryId chunkChunkId, + final @Nullable ChunkRecord chunkRecord, final @NotNull Map measurements, final @NotNull SentryDate chunkTimestamp, final boolean shouldRestart, final @NotNull IScopes scopes, final @NotNull SentryOptions options) { + // The trace file is the last word on whether the chunk was recorded: the OS may report success + // and still leave no usable file behind + if (chunkRecord != null) { + // Nothing is sent once the profiler is closed, so a collected chunk still covers nothing + chunkRecord.setRecordingState( + traceFile != null && !isClosed.get() + ? ProfileRecordingState.RECORDED + : ProfileRecordingState.NOT_RECORDED); + } + if (traceFile == null) { logger.log( SentryLevel.ERROR, diff --git a/sentry-android-core/src/main/java/io/sentry/android/core/PerfettoProfiler.java b/sentry-android-core/src/main/java/io/sentry/android/core/PerfettoProfiler.java index d09c7252694..d9de1355b3f 100644 --- a/sentry-android-core/src/main/java/io/sentry/android/core/PerfettoProfiler.java +++ b/sentry-android-core/src/main/java/io/sentry/android/core/PerfettoProfiler.java @@ -10,7 +10,11 @@ import androidx.annotation.RequiresApi; import io.sentry.ILogger; import io.sentry.ISentryExecutorService; +import io.sentry.SentryDate; import io.sentry.SentryLevel; +import io.sentry.android.core.internal.profiling.ChunkRecord; +import io.sentry.profiling.ProfileRecordingState; +import io.sentry.protocol.SentryId; import java.io.File; import java.util.concurrent.RejectedExecutionException; import java.util.function.Consumer; @@ -52,6 +56,8 @@ public class PerfettoProfiler { private @Nullable Consumer<@Nullable File> resultListener = null; private volatile boolean started = false; + private volatile @Nullable ChunkRecord chunkRecord = null; + @SuppressLint("WrongConstant") public PerfettoProfiler( final @NotNull Context context, @@ -72,17 +78,27 @@ public PerfettoProfiler( this.profilingManager = profilingManager; } - public boolean start(final long durationMs) { + /** + * Starts a profiling session and returns the record of the chunk it produces, or null if the + * session could not be started. A failure the OS reports later is written to that record as it + * happens, so that whoever holds it knows that no trace file is coming. + */ + @Nullable + ChunkRecord start( + final @NotNull SentryDate startTimestamp, + final @NotNull SentryId profilerId, + final long durationMs) { if (started) { logger.log(SentryLevel.WARNING, "PerfettoProfiler was already started."); - return false; + return null; } started = true; if (profilingManager == null) { logger.log(SentryLevel.WARNING, "ProfilingManager is not available."); - return false; + return null; } + this.chunkRecord = new ChunkRecord(profilerId, startTimestamp); final Bundle params = new Bundle(); params.putInt(KEY_DURATION_MS, (int) durationMs); @@ -98,10 +114,12 @@ public boolean start(final long durationMs) { this::onProfilingResult); } catch (Throwable e) { logger.log(SentryLevel.ERROR, "Failed to request Profiling.", e); - return false; + // Nobody holds the record, so a late result from the OS must not write into it + chunkRecord = null; + return null; } - return true; + return chunkRecord; } /** @@ -130,12 +148,20 @@ public void endAndCollect(final @NotNull Consumer<@Nullable File> listener) { try { executorService.schedule( () -> { + boolean hasTimedOut = false; synchronized (profilingResultLock) { if (resultListener != null) { logger.log(SentryLevel.WARNING, "Timed out waiting for Perfetto profiling result."); resultListener.accept(null); // Nobody consumes a late result anymore, so delete the trace file instead resultListener = this::deleteTraceFile; + hasTimedOut = true; + } + } + if (hasTimedOut) { + final @Nullable ChunkRecord record = chunkRecord; + if (record != null) { + record.setRecordingState(ProfileRecordingState.NOT_RECORDED); } } }, @@ -152,6 +178,15 @@ private void onProfilingResult(final @NotNull ProfilingResult result) { result.getErrorCode(), result.getResultFilePath()); + final @Nullable ChunkRecord record = chunkRecord; + if (record != null) { + final int errorCode = result.getErrorCode(); + record.setRecordingState( + errorCode == ProfilingResult.ERROR_NONE + ? ProfileRecordingState.RECORDED + : ProfileRecordingState.NOT_RECORDED); + } + synchronized (profilingResultLock) { profilingResult = result; if (resultListener != null) { @@ -177,6 +212,7 @@ private void deleteTraceFile(final @Nullable File traceFile) { private @Nullable File processResult(final @NotNull ProfilingResult result) { final int errorCode = result.getErrorCode(); + final @Nullable ChunkRecord record = chunkRecord; if (errorCode != ProfilingResult.ERROR_NONE) { switch (errorCode) { case ProfilingResult.ERROR_FAILED_RATE_LIMIT_PROCESS: @@ -203,16 +239,25 @@ private void deleteTraceFile(final @Nullable File traceFile) { final @Nullable String resultFilePath = result.getResultFilePath(); if (resultFilePath == null) { + if (record != null) { + record.setRecordingState(ProfileRecordingState.NOT_RECORDED); + } logger.log(SentryLevel.WARNING, "Perfetto profiling result file path is null."); return null; } final File traceFile = new File(resultFilePath); if (!traceFile.exists() || traceFile.length() == 0) { + if (record != null) { + record.setRecordingState(ProfileRecordingState.NOT_RECORDED); + } logger.log(SentryLevel.WARNING, "Perfetto trace file does not exist or is empty."); return null; } + if (record != null) { + record.setRecordingState(ProfileRecordingState.RECORDED); + } return traceFile; } diff --git a/sentry-android-core/src/main/java/io/sentry/android/core/internal/profiling/ChunkRecord.java b/sentry-android-core/src/main/java/io/sentry/android/core/internal/profiling/ChunkRecord.java new file mode 100644 index 00000000000..6b71ab4b92e --- /dev/null +++ b/sentry-android-core/src/main/java/io/sentry/android/core/internal/profiling/ChunkRecord.java @@ -0,0 +1,68 @@ +package io.sentry.android.core.internal.profiling; + +import io.sentry.SentryDate; +import io.sentry.profiling.ProfileRecordingState; +import io.sentry.protocol.SentryId; +import org.jetbrains.annotations.ApiStatus; +import org.jetbrains.annotations.NotNull; +import org.jetbrains.annotations.Nullable; + +/** + * A profile chunk that was started, together with the outcome of its collection, so that spans + * tagged with a profiler id can find out whether a profile covering them exists. + * + *

The profiler that produces the chunk writes the outcome from an OS binder thread or from the + * executor thread, while the thread that finishes a transaction reads it. The recording state is + * therefore guarded by the record's monitor, as two writers must not lose a reported failure + * between them. The end timestamp only ever has one writer, so it is volatile. + */ +@ApiStatus.Internal +public final class ChunkRecord { + + private final @NotNull SentryId profilerId; + private final @NotNull SentryDate startTimestamp; + private volatile @Nullable SentryDate endTimestamp = null; + private @NotNull ProfileRecordingState recordingState = ProfileRecordingState.UNKNOWN; + + public ChunkRecord(final @NotNull SentryId profilerId, final @NotNull SentryDate startTimestamp) { + this.profilerId = profilerId; + this.startTimestamp = startTimestamp; + } + + /** Marks the end of the chunk. Its outcome is only known once the trace file is collected. */ + public void setEndTimestamp(final @NotNull SentryDate endTimestamp) { + this.endTimestamp = endTimestamp; + } + + /** + * Marks the outcome of the chunk. {@link ProfileRecordingState#NOT_RECORDED} is final: once it is + * known that no trace file exists, a result the OS delivers late cannot revive the chunk. + */ + public synchronized void setRecordingState(final @NotNull ProfileRecordingState recordingState) { + if (this.recordingState == ProfileRecordingState.NOT_RECORDED) { + return; + } + this.recordingState = recordingState; + } + + public synchronized @NotNull ProfileRecordingState getRecordingState() { + return recordingState; + } + + public @NotNull SentryId getProfilerId() { + return profilerId; + } + + public @NotNull SentryDate getStartTimestamp() { + return startTimestamp; + } + + public boolean overlaps(final @NotNull SentryDate startTime, final @NotNull SentryDate endTime) { + if (endTime.isBefore(startTimestamp)) { + return false; + } + // A chunk that is still running has no end yet, and covers everything from its start on + final @Nullable SentryDate endTimestamp = this.endTimestamp; + return endTimestamp == null || !startTime.isAfter(endTimestamp); + } +} diff --git a/sentry-android-core/src/test/java/io/sentry/android/core/PerfettoContinuousProfilerTest.kt b/sentry-android-core/src/test/java/io/sentry/android/core/PerfettoContinuousProfilerTest.kt index 2f76e73108f..15fddbc52bf 100644 --- a/sentry-android-core/src/test/java/io/sentry/android/core/PerfettoContinuousProfilerTest.kt +++ b/sentry-android-core/src/test/java/io/sentry/android/core/PerfettoContinuousProfilerTest.kt @@ -10,11 +10,15 @@ import io.sentry.ProfileLifecycle import io.sentry.Sentry import io.sentry.SentryLevel import io.sentry.TracesSampler +import io.sentry.android.core.internal.profiling.ChunkRecord import io.sentry.android.core.internal.util.SentryFrameMetricsCollector +import io.sentry.profiling.ProfileRecordingState +import io.sentry.protocol.SentryId import io.sentry.test.DeferredExecutorService import kotlin.test.AfterTest import kotlin.test.BeforeTest import kotlin.test.Test +import kotlin.test.assertEquals import kotlin.test.assertFalse import kotlin.test.assertNotNull import kotlin.test.assertTrue @@ -41,6 +45,7 @@ class PerfettoContinuousProfilerTest { val mockLogger = mock() val mockTracesSampler = mock() val mockPerfettoProfiler = mock() + val startedChunks = mutableListOf() val frameMetricsCollector: SentryFrameMetricsCollector = mock() val scopes: IScopes = mock() @@ -61,7 +66,12 @@ class PerfettoContinuousProfilerTest { init { whenever(mockTracesSampler.sampleSessionProfile(any())).thenReturn(true) - whenever(mockPerfettoProfiler.start(any())).thenReturn(true) + // The profiler id is created inside PerfettoContinuousProfiler, so it is read from the call + whenever(mockPerfettoProfiler.start(any(), any(), any())).thenAnswer { invocation -> + ChunkRecord(invocation.getArgument(1), invocation.getArgument(0)).also { + startedChunks.add(it) + } + } doAnswer { invocation -> val listener = invocation.getArgument>(0) listener.accept(mockTraceFile) @@ -207,6 +217,220 @@ class PerfettoContinuousProfilerTest { ) } + // -- getProfileRecordingState -- + + @Test + fun `getProfileRecordingState is unknown when no chunk ran at all`() { + val profiler = fixture.getSut() + val now = fixture.options.dateProvider.now() + + assertEquals( + ProfileRecordingState.UNKNOWN, + profiler.getProfileRecordingState(SentryId(), now, now), + ) + } + + @Test + fun `getProfileRecordingState assumes a running chunk will be recorded`() { + val profiler = fixture.getSut() + profiler.startProfiler(ProfileLifecycle.MANUAL, fixture.mockTracesSampler) + val duringChunk = fixture.options.dateProvider.now() + + assertEquals( + ProfileRecordingState.RECORDED, + profiler.getProfileRecordingState(profiler.profilerId, duringChunk, duringChunk), + ) + } + + @Test + fun `getProfileRecordingState assumes a chunk that is still being collected was recorded`() { + doAnswer { null }.whenever(fixture.mockPerfettoProfiler).endAndCollect(any()) + val profiler = fixture.getSut() + profiler.startProfiler(ProfileLifecycle.MANUAL, fixture.mockTracesSampler) + val profilerId = profiler.profilerId + val duringChunk = fixture.options.dateProvider.now() + + profiler.stopProfiler(ProfileLifecycle.MANUAL) + fixture.executor.runAll() + + assertEquals( + ProfileRecordingState.RECORDED, + profiler.getProfileRecordingState(profilerId, duringChunk, duringChunk), + ) + } + + @Test + fun `getProfileRecordingState is recorded for a window a recorded chunk covers`() { + val profiler = fixture.getSut() + profiler.startProfiler(ProfileLifecycle.MANUAL, fixture.mockTracesSampler) + val profilerId = profiler.profilerId + val duringChunk = fixture.options.dateProvider.now() + + profiler.stopProfiler(ProfileLifecycle.MANUAL) + fixture.executor.runAll() + + assertEquals( + ProfileRecordingState.RECORDED, + profiler.getProfileRecordingState(profilerId, duringChunk, duringChunk), + ) + } + + @Test + fun `getProfileRecordingState is not recorded when the chunk produced no trace file`() { + doAnswer { invocation -> + invocation.getArgument>(0).accept(null) + null + } + .whenever(fixture.mockPerfettoProfiler) + .endAndCollect(any()) + val profiler = fixture.getSut() + profiler.startProfiler(ProfileLifecycle.MANUAL, fixture.mockTracesSampler) + val profilerId = profiler.profilerId + val duringChunk = fixture.options.dateProvider.now() + + profiler.stopProfiler(ProfileLifecycle.MANUAL) + fixture.executor.runAll() + + assertEquals( + ProfileRecordingState.NOT_RECORDED, + profiler.getProfileRecordingState(profilerId, duringChunk, duringChunk), + ) + } + + @Test + fun `getProfileRecordingState is not recorded once the OS reports a failure for the running chunk`() { + val profiler = fixture.getSut() + profiler.startProfiler(ProfileLifecycle.MANUAL, fixture.mockTracesSampler) + val duringChunk = fixture.options.dateProvider.now() + + // The profiler marks the record as soon as the OS reports the failure, e.g. on a rate limit + fixture.startedChunks.last().recordingState = ProfileRecordingState.NOT_RECORDED + + assertEquals( + ProfileRecordingState.NOT_RECORDED, + profiler.getProfileRecordingState(profiler.profilerId, duringChunk, duringChunk), + ) + } + + @Test + fun `getProfileRecordingState is not recorded for a window after the last chunk`() { + val profiler = fixture.getSut() + profiler.startProfiler(ProfileLifecycle.MANUAL, fixture.mockTracesSampler) + val profilerId = profiler.profilerId + profiler.stopProfiler(ProfileLifecycle.MANUAL) + fixture.executor.runAll() + val afterChunk = fixture.options.dateProvider.now() + + assertEquals( + ProfileRecordingState.NOT_RECORDED, + profiler.getProfileRecordingState(profilerId, afterChunk, afterChunk), + ) + } + + @Test + fun `getProfileRecordingState is not recorded for a profiler id the history does not know`() { + val profiler = fixture.getSut() + profiler.startProfiler(ProfileLifecycle.MANUAL, fixture.mockTracesSampler) + val duringChunk = fixture.options.dateProvider.now() + profiler.stopProfiler(ProfileLifecycle.MANUAL) + fixture.executor.runAll() + + assertEquals( + ProfileRecordingState.NOT_RECORDED, + profiler.getProfileRecordingState(SentryId(), duringChunk, duringChunk), + ) + } + + @Test + fun `getProfileRecordingState judges a window that starts before the profiler did`() { + // An app start transaction is back-dated to before Sentry init, and still has to be judged + val beforeProfiler = fixture.options.dateProvider.now() + val profiler = fixture.getSut() + profiler.startProfiler(ProfileLifecycle.MANUAL, fixture.mockTracesSampler) + val profilerId = profiler.profilerId + val duringChunk = fixture.options.dateProvider.now() + profiler.stopProfiler(ProfileLifecycle.MANUAL) + fixture.executor.runAll() + + assertEquals( + ProfileRecordingState.RECORDED, + profiler.getProfileRecordingState(profilerId, beforeProfiler, duringChunk), + ) + } + + @Test + fun `getProfileRecordingState answers from the chunks left after eviction`() { + val beforeProfiler = fixture.options.dateProvider.now() + val profiler = fixture.getSut() + profiler.startProfiler(ProfileLifecycle.MANUAL, fixture.mockTracesSampler) + val profilerId = profiler.profilerId + + // Each chunk timer fires a stop and a restart, until the first chunks fall out of the history + repeat(PerfettoContinuousProfiler.MAX_CHUNK_HISTORY_SIZE + 1) { fixture.executor.runAll() } + val duringLastChunk = fixture.options.dateProvider.now() + + assertEquals( + ProfileRecordingState.RECORDED, + profiler.getProfileRecordingState(profilerId, beforeProfiler, duringLastChunk), + ) + assertEquals( + ProfileRecordingState.RECORDED, + profiler.getProfileRecordingState(profilerId, duringLastChunk, duringLastChunk), + ) + } + + @Test + fun `getProfileRecordingState judges each chunk of a profiler id on its own`() { + var isFirstChunk = true + doAnswer { invocation -> + val listener = invocation.getArgument>(0) + // The first chunk produces no trace file, the ones after it do + listener.accept(if (isFirstChunk) null else fixture.mockTraceFile) + isFirstChunk = false + null + } + .whenever(fixture.mockPerfettoProfiler) + .endAndCollect(any()) + val profiler = fixture.getSut() + profiler.startProfiler(ProfileLifecycle.MANUAL, fixture.mockTracesSampler) + val profilerId = profiler.profilerId + val duringFailedChunk = fixture.options.dateProvider.now() + + // The chunk timer fires, so the failed chunk ends and the next one starts + fixture.executor.runAll() + val duringNextChunk = fixture.options.dateProvider.now() + + assertEquals( + ProfileRecordingState.NOT_RECORDED, + profiler.getProfileRecordingState(profilerId, duringFailedChunk, duringFailedChunk), + ) + assertEquals( + ProfileRecordingState.RECORDED, + profiler.getProfileRecordingState(profilerId, duringNextChunk, duringNextChunk), + ) + assertEquals( + ProfileRecordingState.RECORDED, + profiler.getProfileRecordingState(profilerId, duringFailedChunk, duringNextChunk), + "a window a recorded chunk covers in part keeps its profiler id", + ) + } + + @Test + fun `getProfileRecordingState is not recorded for chunks left pending on close`() { + doAnswer { null }.whenever(fixture.mockPerfettoProfiler).endAndCollect(any()) + val profiler = fixture.getSut() + profiler.startProfiler(ProfileLifecycle.MANUAL, fixture.mockTracesSampler) + val profilerId = profiler.profilerId + val duringChunk = fixture.options.dateProvider.now() + + profiler.close(true) + + assertEquals( + ProfileRecordingState.NOT_RECORDED, + profiler.getProfileRecordingState(profilerId, duringChunk, duringChunk), + ) + } + @Test fun `profiler multiple starts are ignored in manual mode`() { val profiler = fixture.getSut() diff --git a/sentry-android-core/src/test/java/io/sentry/android/core/PerfettoProfilerTest.kt b/sentry-android-core/src/test/java/io/sentry/android/core/PerfettoProfilerTest.kt index 0746d36dfff..f60dfb01e81 100644 --- a/sentry-android-core/src/test/java/io/sentry/android/core/PerfettoProfilerTest.kt +++ b/sentry-android-core/src/test/java/io/sentry/android/core/PerfettoProfilerTest.kt @@ -6,6 +6,10 @@ import android.os.ProfilingResult import androidx.test.core.app.ApplicationProvider import androidx.test.ext.junit.runners.AndroidJUnit4 import io.sentry.ILogger +import io.sentry.SentryNanotimeDate +import io.sentry.android.core.internal.profiling.ChunkRecord +import io.sentry.profiling.ProfileRecordingState +import io.sentry.protocol.SentryId import io.sentry.test.DeferredExecutorService import java.io.File import java.util.concurrent.CountDownLatch @@ -17,6 +21,7 @@ import kotlin.test.BeforeTest import kotlin.test.Test import kotlin.test.assertEquals import kotlin.test.assertFalse +import kotlin.test.assertNotNull import kotlin.test.assertNull import kotlin.test.assertTrue import org.junit.runner.RunWith @@ -32,6 +37,7 @@ class PerfettoProfilerTest { private lateinit var context: Context private val mockLogger = mock() + private val profilerId = SentryId() private val executor = DeferredExecutorService() private lateinit var capturedCallback: Consumer @@ -56,6 +62,9 @@ class PerfettoProfilerTest { return PerfettoProfiler(mockLogger, executor, profilingManager) } + private fun PerfettoProfiler.startSession(): ChunkRecord? = + start(SentryNanotimeDate(), profilerId, 60000) + private fun createTraceFile(): File { return File.createTempFile("test-trace", ".pftrace").apply { writeBytes(byteArrayOf(0x50, 0x65, 0x72, 0x66)) @@ -76,22 +85,22 @@ class PerfettoProfilerTest { } @Test - fun `start returns true on first call`() { + fun `start returns a chunk record on first call`() { val profiler = getSut() - assertTrue(profiler.start(60000)) + assertNotNull(profiler.startSession()) } @Test - fun `start returns false when already started`() { + fun `start returns null when already started`() { val profiler = getSut() - assertTrue(profiler.start(60000)) - assertFalse(profiler.start(60000)) + assertNotNull(profiler.startSession()) + assertNull(profiler.startSession()) } @Test - fun `start returns false when ProfilingManager is null`() { + fun `start returns null when ProfilingManager is null`() { val profiler = getSut(profilingManager = null) - assertFalse(profiler.start(60000)) + assertNull(profiler.startSession()) } @Test @@ -106,7 +115,7 @@ class PerfettoProfilerTest { fun `endAndCollect calls listener synchronously when result already available`() { val traceFile = createTraceFile() val profiler = getSut() - profiler.start(60000) + profiler.startSession() capturedCallback.accept(mockResult(filePath = traceFile.absolutePath)) @@ -120,7 +129,7 @@ class PerfettoProfilerTest { fun `endAndCollect calls listener when result arrives later`() { val traceFile = createTraceFile() val profiler = getSut() - profiler.start(60000) + profiler.startSession() val result = AtomicReference() profiler.endAndCollect { result.set(it) } @@ -135,7 +144,7 @@ class PerfettoProfilerTest { @Test fun `endAndCollect calls listener with null on error result`() { val profiler = getSut() - profiler.start(60000) + profiler.startSession() val result = AtomicReference(File("sentinel")) @@ -150,7 +159,7 @@ class PerfettoProfilerTest { @Test fun `endAndCollect calls listener with null on rate limit error`() { val profiler = getSut() - profiler.start(60000) + profiler.startSession() val result = AtomicReference(File("sentinel")) @@ -163,7 +172,7 @@ class PerfettoProfilerTest { @Test fun `timeout fires listener with null when OS never responds`() { val profiler = getSut() - profiler.start(60000) + profiler.startSession() val result = AtomicReference(File("sentinel")) profiler.endAndCollect { result.set(it) } @@ -179,7 +188,7 @@ class PerfettoProfilerTest { fun `timeout is no-op when result already arrived`() { val traceFile = createTraceFile() val profiler = getSut() - profiler.start(60000) + profiler.startSession() val callCount = AtomicInteger(0) val result = AtomicReference() @@ -202,7 +211,7 @@ class PerfettoProfilerTest { fun `listener is called exactly once when result and endAndCollect race`() { val traceFile = createTraceFile() val profiler = getSut() - profiler.start(60000) + profiler.startSession() val callCount = AtomicInteger(0) val latch = CountDownLatch(1) @@ -226,7 +235,7 @@ class PerfettoProfilerTest { fun `trace file is deleted when result arrives after the timeout`() { val traceFile = createTraceFile() val profiler = getSut() - profiler.start(60000) + profiler.startSession() val callCount = AtomicInteger(0) profiler.endAndCollect { callCount.incrementAndGet() } @@ -243,7 +252,7 @@ class PerfettoProfilerTest { @Test fun `endAndCollect calls listener with null when result file path is null`() { val profiler = getSut() - profiler.start(60000) + profiler.startSession() val result = AtomicReference(File("sentinel")) @@ -256,7 +265,7 @@ class PerfettoProfilerTest { @Test fun `endAndCollect calls listener with null when trace file does not exist`() { val profiler = getSut() - profiler.start(60000) + profiler.startSession() val result = AtomicReference(File("sentinel")) @@ -265,4 +274,83 @@ class PerfettoProfilerTest { assertNull(result.get()) } + + @Test + fun `chunk record is marked as not recorded when the result file path is null`() { + val profiler = getSut() + val chunkRecord = assertNotNull(profiler.startSession()) + + capturedCallback.accept(mockResult(filePath = null)) + profiler.endAndCollect {} + + assertEquals(ProfileRecordingState.NOT_RECORDED, chunkRecord.recordingState) + } + + @Test + fun `chunk record is marked as not recorded when the trace file does not exist`() { + val profiler = getSut() + val chunkRecord = assertNotNull(profiler.startSession()) + + capturedCallback.accept(mockResult(filePath = "/non/existent/path.pftrace")) + profiler.endAndCollect {} + + assertEquals(ProfileRecordingState.NOT_RECORDED, chunkRecord.recordingState) + } + + @Test + fun `a result arriving after the timeout does not revive the chunk record`() { + val traceFile = createTraceFile() + val profiler = getSut() + val chunkRecord = assertNotNull(profiler.startSession()) + profiler.endAndCollect {} + + // Nothing is sent for a chunk that timed out, so a late result must not mark it as recorded + executor.runAll() + capturedCallback.accept(mockResult(filePath = traceFile.absolutePath)) + + assertEquals(ProfileRecordingState.NOT_RECORDED, chunkRecord.recordingState) + } + + @Test + fun `chunk record stays unknown while no result arrived`() { + val profiler = getSut() + + val chunkRecord = assertNotNull(profiler.startSession()) + + assertEquals(ProfileRecordingState.UNKNOWN, chunkRecord.recordingState) + } + + @Test + fun `chunk record is marked as not recorded as soon as the OS reports an error`() { + val profiler = getSut() + val chunkRecord = assertNotNull(profiler.startSession()) + + capturedCallback.accept(mockResult(errorCode = ProfilingResult.ERROR_FAILED_RATE_LIMIT_PROCESS)) + + assertEquals(ProfileRecordingState.NOT_RECORDED, chunkRecord.recordingState) + } + + @Test + fun `chunk record is untouched after a successful result`() { + val traceFile = createTraceFile() + val profiler = getSut() + val chunkRecord = assertNotNull(profiler.startSession()) + + capturedCallback.accept(mockResult(filePath = traceFile.absolutePath)) + + assertEquals(ProfileRecordingState.RECORDED, chunkRecord.recordingState) + } + + @Test + fun `chunk record is marked as not recorded when the result times out`() { + val profiler = getSut() + val chunkRecord = assertNotNull(profiler.startSession()) + profiler.endAndCollect {} + + assertEquals(ProfileRecordingState.UNKNOWN, chunkRecord.recordingState) + + executor.runAll() + + assertEquals(ProfileRecordingState.NOT_RECORDED, chunkRecord.recordingState) + } } diff --git a/sentry-android-core/src/test/java/io/sentry/android/core/internal/profiling/ChunkRecordTest.kt b/sentry-android-core/src/test/java/io/sentry/android/core/internal/profiling/ChunkRecordTest.kt new file mode 100644 index 00000000000..2210eb73d4d --- /dev/null +++ b/sentry-android-core/src/test/java/io/sentry/android/core/internal/profiling/ChunkRecordTest.kt @@ -0,0 +1,81 @@ +package io.sentry.android.core.internal.profiling + +import io.sentry.SentryLongDate +import io.sentry.profiling.ProfileRecordingState +import io.sentry.protocol.SentryId +import kotlin.test.Test +import kotlin.test.assertEquals +import kotlin.test.assertFalse +import kotlin.test.assertTrue + +class ChunkRecordTest { + private val chunkStart = SentryLongDate(1000) + private val chunkEnd = SentryLongDate(2000) + + private fun getSut(withEnd: Boolean = true): ChunkRecord = + ChunkRecord(SentryId(), chunkStart).apply { if (withEnd) setEndTimestamp(chunkEnd) } + + @Test + fun `a new chunk has an unknown state`() { + assertEquals(ProfileRecordingState.UNKNOWN, getSut().recordingState) + } + + @Test + fun `not recorded is final`() { + val chunk = getSut() + + chunk.recordingState = ProfileRecordingState.NOT_RECORDED + chunk.recordingState = ProfileRecordingState.RECORDED + + assertEquals(ProfileRecordingState.NOT_RECORDED, chunk.recordingState) + } + + @Test + fun `a recorded chunk can still turn out to be not recorded`() { + val chunk = getSut() + + chunk.recordingState = ProfileRecordingState.RECORDED + chunk.recordingState = ProfileRecordingState.NOT_RECORDED + + assertEquals(ProfileRecordingState.NOT_RECORDED, chunk.recordingState) + } + + @Test + fun `a window inside the chunk overlaps`() { + assertTrue(getSut().overlaps(SentryLongDate(1200), SentryLongDate(1800))) + } + + @Test + fun `a window around the chunk overlaps`() { + assertTrue(getSut().overlaps(SentryLongDate(500), SentryLongDate(2500))) + } + + @Test + fun `a window ending exactly at the chunk start overlaps`() { + assertTrue(getSut().overlaps(SentryLongDate(500), chunkStart)) + } + + @Test + fun `a window starting exactly at the chunk end overlaps`() { + assertTrue(getSut().overlaps(chunkEnd, SentryLongDate(2500))) + } + + @Test + fun `a window before the chunk does not overlap`() { + assertFalse(getSut().overlaps(SentryLongDate(500), SentryLongDate(999))) + } + + @Test + fun `a window after the chunk does not overlap`() { + assertFalse(getSut().overlaps(SentryLongDate(2001), SentryLongDate(2500))) + } + + @Test + fun `a running chunk covers everything from its start on`() { + val chunk = getSut(withEnd = false) + + assertTrue(chunk.overlaps(SentryLongDate(1200), SentryLongDate(1200))) + assertTrue(chunk.overlaps(SentryLongDate(9000), SentryLongDate(9000))) + assertFalse(chunk.overlaps(SentryLongDate(500), SentryLongDate(999))) + } +} diff --git a/sentry-async-profiler/api/sentry-async-profiler.api b/sentry-async-profiler/api/sentry-async-profiler.api index 045465349c2..f6f709c797d 100644 --- a/sentry-async-profiler/api/sentry-async-profiler.api +++ b/sentry-async-profiler/api/sentry-async-profiler.api @@ -21,6 +21,7 @@ public final class io/sentry/asyncprofiler/profiling/JavaContinuousProfiler : io public fun (Lio/sentry/ILogger;Ljava/lang/String;ILio/sentry/ISentryExecutorService;)V public fun close (Z)V public fun getChunkId ()Lio/sentry/protocol/SentryId; + public fun getProfileRecordingState (Lio/sentry/protocol/SentryId;Lio/sentry/SentryDate;Lio/sentry/SentryDate;)Lio/sentry/profiling/ProfileRecordingState; public fun getProfilerId ()Lio/sentry/protocol/SentryId; public fun getRootSpanCounter ()I public fun isRunning ()Z diff --git a/sentry-async-profiler/src/main/java/io/sentry/asyncprofiler/profiling/JavaContinuousProfiler.java b/sentry-async-profiler/src/main/java/io/sentry/asyncprofiler/profiling/JavaContinuousProfiler.java index f5c314bf96c..09c2ed8b5d2 100644 --- a/sentry-async-profiler/src/main/java/io/sentry/asyncprofiler/profiling/JavaContinuousProfiler.java +++ b/sentry-async-profiler/src/main/java/io/sentry/asyncprofiler/profiling/JavaContinuousProfiler.java @@ -19,6 +19,7 @@ import io.sentry.SentryOptions; import io.sentry.SentryUUID; import io.sentry.TracesSampler; +import io.sentry.profiling.ProfileRecordingState; import io.sentry.protocol.SentryId; import io.sentry.transport.RateLimiter; import io.sentry.util.AutoClosableReentrantLock; @@ -382,6 +383,18 @@ public void close(final boolean isTerminating) { return SentryId.EMPTY_ID; } + /** + * This profiler does not track the outcome of its profiling requests, so the answer is always + * unknown. + */ + @Override + public @NotNull ProfileRecordingState getProfileRecordingState( + final @NotNull SentryId profilerId, + final @NotNull SentryDate startTime, + final @NotNull SentryDate endTime) { + return ProfileRecordingState.UNKNOWN; + } + @SuppressWarnings("FutureReturnValueIgnored") private void sendChunks(final @NotNull IScopes scopes, final @NotNull SentryOptions options) { try { diff --git a/sentry/api/sentry.api b/sentry/api/sentry.api index fa876b3312f..68c699497fa 100644 --- a/sentry/api/sentry.api +++ b/sentry/api/sentry.api @@ -828,6 +828,7 @@ public abstract interface class io/sentry/IConnectionStatusProvider$IConnectionS public abstract interface class io/sentry/IContinuousProfiler { public abstract fun close (Z)V public abstract fun getChunkId ()Lio/sentry/protocol/SentryId; + public abstract fun getProfileRecordingState (Lio/sentry/protocol/SentryId;Lio/sentry/SentryDate;Lio/sentry/SentryDate;)Lio/sentry/profiling/ProfileRecordingState; public abstract fun getProfilerId ()Lio/sentry/protocol/SentryId; public abstract fun isRunning ()Z public abstract fun reevaluateSampling ()V @@ -1584,6 +1585,7 @@ public final class io/sentry/NoOpContinuousProfiler : io/sentry/IContinuousProfi public fun close (Z)V public fun getChunkId ()Lio/sentry/protocol/SentryId; public static fun getInstance ()Lio/sentry/NoOpContinuousProfiler; + public fun getProfileRecordingState (Lio/sentry/protocol/SentryId;Lio/sentry/SentryDate;Lio/sentry/SentryDate;)Lio/sentry/profiling/ProfileRecordingState; public fun getProfilerId ()Lio/sentry/protocol/SentryId; public fun isRunning ()Z public fun reevaluateSampling ()V @@ -5676,6 +5678,14 @@ public abstract interface class io/sentry/profiling/JavaProfileConverterProvider public abstract fun getProfileConverter ()Lio/sentry/IProfileConverter; } +public final class io/sentry/profiling/ProfileRecordingState : java/lang/Enum { + public static final field NOT_RECORDED Lio/sentry/profiling/ProfileRecordingState; + public static final field RECORDED Lio/sentry/profiling/ProfileRecordingState; + public static final field UNKNOWN Lio/sentry/profiling/ProfileRecordingState; + public static fun valueOf (Ljava/lang/String;)Lio/sentry/profiling/ProfileRecordingState; + public static fun values ()[Lio/sentry/profiling/ProfileRecordingState; +} + public final class io/sentry/profiling/ProfilingServiceLoader { public fun ()V public static fun loadContinuousProfiler (Lio/sentry/ILogger;Ljava/lang/String;ILio/sentry/ISentryExecutorService;)Lio/sentry/IContinuousProfiler; diff --git a/sentry/src/main/java/io/sentry/IContinuousProfiler.java b/sentry/src/main/java/io/sentry/IContinuousProfiler.java index f7e59362273..19ecf81409d 100644 --- a/sentry/src/main/java/io/sentry/IContinuousProfiler.java +++ b/sentry/src/main/java/io/sentry/IContinuousProfiler.java @@ -1,5 +1,6 @@ package io.sentry; +import io.sentry.profiling.ProfileRecordingState; import io.sentry.protocol.SentryId; import org.jetbrains.annotations.ApiStatus; import org.jetbrains.annotations.NotNull; @@ -28,4 +29,21 @@ void startProfiler( @NotNull SentryId getChunkId(); + + /** + * Tells whether a profile exists for the given profiler id, covering the given time window. + * + *

The result of a profiling request can arrive long after a span was tagged with the profiler + * id, so callers are expected to ask again when they are about to send the data. + * + * @param profilerId the profiler id the caller was tagged with + * @param startTime start of the time window to check + * @param endTime end of the time window to check + * @return the state of the profile recording for that window + */ + @NotNull + ProfileRecordingState getProfileRecordingState( + final @NotNull SentryId profilerId, + final @NotNull SentryDate startTime, + final @NotNull SentryDate endTime); } diff --git a/sentry/src/main/java/io/sentry/NoOpContinuousProfiler.java b/sentry/src/main/java/io/sentry/NoOpContinuousProfiler.java index 4cda59e7c33..ffc153f0ab7 100644 --- a/sentry/src/main/java/io/sentry/NoOpContinuousProfiler.java +++ b/sentry/src/main/java/io/sentry/NoOpContinuousProfiler.java @@ -1,5 +1,6 @@ package io.sentry; +import io.sentry.profiling.ProfileRecordingState; import io.sentry.protocol.SentryId; import org.jetbrains.annotations.NotNull; @@ -41,4 +42,12 @@ public void reevaluateSampling() {} public @NotNull SentryId getChunkId() { return SentryId.EMPTY_ID; } + + @Override + public @NotNull ProfileRecordingState getProfileRecordingState( + final @NotNull SentryId profilerId, + final @NotNull SentryDate startTime, + final @NotNull SentryDate endTime) { + return ProfileRecordingState.UNKNOWN; + } } diff --git a/sentry/src/main/java/io/sentry/SentryTracer.java b/sentry/src/main/java/io/sentry/SentryTracer.java index 723538b9924..d60187cb4d5 100644 --- a/sentry/src/main/java/io/sentry/SentryTracer.java +++ b/sentry/src/main/java/io/sentry/SentryTracer.java @@ -1,5 +1,6 @@ package io.sentry; +import io.sentry.profiling.ProfileRecordingState; import io.sentry.protocol.Contexts; import io.sentry.protocol.SentryId; import io.sentry.protocol.SentryTransaction; @@ -261,6 +262,8 @@ public void finish( } }); }); + dropUnrecordedProfilerIds(finishTimestamp); + final SentryTransaction transaction = new SentryTransaction(this); if (timersEnabled) { @@ -549,6 +552,65 @@ private void setDefaultSpanData(final @NotNull ISpan span) { span.setData(SpanDataConvention.THREAD_NAME, threadChecker.getCurrentThreadName()); } + /** + * Spans are tagged with the profiler id when they start, but the profiler may only learn later + * that no profile was recorded, e.g. when the OS rate limits profiling requests. Spans that no + * profile covers drop the reference here, so they don't point to a profile that never arrives. + */ + private void dropUnrecordedProfilerIds(final @NotNull SentryDate finishTimestamp) { + final @NotNull IContinuousProfiler continuousProfiler = + scopes.getOptions().getContinuousProfiler(); + if (continuousProfiler instanceof NoOpContinuousProfiler) { + // Without a profiler no span can carry a profiler id, so the children are not worth walking + return; + } + + if (isProfileMissing(continuousProfiler, root, finishTimestamp)) { + root.setData(SpanDataConvention.PROFILER_ID, null); + contexts.remove(ProfileContext.TYPE); + scopes + .getOptions() + .getLogger() + .log( + SentryLevel.DEBUG, + "No profile was recorded for transaction, dropping its profiler id."); + } + + for (final @NotNull Span child : children) { + if (isProfileMissing(continuousProfiler, child, finishTimestamp)) { + child.setData(SpanDataConvention.PROFILER_ID, null); + } + } + } + + /** + * Whether the profiler knows that no profile covers the given span. + * + * @param finishTimestamp end of the window for a span that never finished + */ + private boolean isProfileMissing( + final @NotNull IContinuousProfiler continuousProfiler, + final @NotNull Span span, + final @NotNull SentryDate finishTimestamp) { + final @Nullable Object data = span.getData(SpanDataConvention.PROFILER_ID); + if (!(data instanceof String)) { + return false; + } + final @NotNull SentryId profilerId; + try { + profilerId = new SentryId((String) data); + } catch (IllegalArgumentException e) { + // The span data key is public API, so the value is not necessarily an id the SDK wrote + return false; + } + final @Nullable SentryDate spanFinishDate = span.getFinishDate(); + return continuousProfiler.getProfileRecordingState( + profilerId, + span.getStartDate(), + spanFinishDate != null ? spanFinishDate : finishTimestamp) + == ProfileRecordingState.NOT_RECORDED; + } + private @NotNull SentryId getProfilerId() { return !root.getSpanContext().getProfilerId().equals(SentryId.EMPTY_ID) ? root.getSpanContext().getProfilerId() diff --git a/sentry/src/main/java/io/sentry/profiling/ProfileRecordingState.java b/sentry/src/main/java/io/sentry/profiling/ProfileRecordingState.java new file mode 100644 index 00000000000..034404f2838 --- /dev/null +++ b/sentry/src/main/java/io/sentry/profiling/ProfileRecordingState.java @@ -0,0 +1,11 @@ +package io.sentry.profiling; + +import org.jetbrains.annotations.ApiStatus; + +@ApiStatus.Internal +public enum ProfileRecordingState { + RECORDED, + NOT_RECORDED, + /** The state is unknown, e.g. because an async profiling request is still awaiting an answer. */ + UNKNOWN +} diff --git a/sentry/src/test/java/io/sentry/SentryTracerTest.kt b/sentry/src/test/java/io/sentry/SentryTracerTest.kt index 20eeafffe92..7c6324db0a7 100644 --- a/sentry/src/test/java/io/sentry/SentryTracerTest.kt +++ b/sentry/src/test/java/io/sentry/SentryTracerTest.kt @@ -1,5 +1,7 @@ package io.sentry +import com.google.common.truth.Truth.assertThat +import io.sentry.profiling.ProfileRecordingState import io.sentry.protocol.SentryId import io.sentry.protocol.TransactionNameSource import io.sentry.protocol.User @@ -20,7 +22,10 @@ import kotlin.test.assertTrue import org.awaitility.kotlin.await import org.mockito.kotlin.any import org.mockito.kotlin.anyOrNull +import org.mockito.kotlin.argumentCaptor +import org.mockito.kotlin.atLeastOnce import org.mockito.kotlin.check +import org.mockito.kotlin.eq import org.mockito.kotlin.mock import org.mockito.kotlin.never import org.mockito.kotlin.spy @@ -254,6 +259,163 @@ class SentryTracerTest { ) } + @Test + fun `when no profile was recorded, profile context and profiler id are dropped`() { + val continuousProfiler = mock() + val profilerId = SentryId() + whenever(continuousProfiler.profilerId).thenReturn(profilerId) + whenever(continuousProfiler.getProfileRecordingState(any(), any(), any())) + .thenReturn(ProfileRecordingState.NOT_RECORDED) + val tracer = + fixture.getSut( + optionsConfiguration = { it.setContinuousProfiler(continuousProfiler) }, + samplingDecision = TracesSamplingDecision(true), + ) + val span = tracer.startChild("span.op") + span.finish() + + tracer.finish() + + assertThat(span.getData(SpanDataConvention.PROFILER_ID)).isNull() + assertThat(tracer.root.getData(SpanDataConvention.PROFILER_ID)).isNull() + verify(fixture.scopes) + .captureTransaction( + check { assertThat(it.contexts.profile).isNull() }, + anyOrNull(), + anyOrNull(), + anyOrNull(), + ) + } + + @Test + fun `when a profile was recorded, profile context and profiler id are kept`() { + val continuousProfiler = mock() + val profilerId = SentryId() + whenever(continuousProfiler.profilerId).thenReturn(profilerId) + whenever(continuousProfiler.getProfileRecordingState(any(), any(), any())) + .thenReturn(ProfileRecordingState.RECORDED) + val tracer = + fixture.getSut( + optionsConfiguration = { it.setContinuousProfiler(continuousProfiler) }, + samplingDecision = TracesSamplingDecision(true), + ) + val span = tracer.startChild("span.op") + span.finish() + + tracer.finish() + + assertThat(span.getData(SpanDataConvention.PROFILER_ID)).isEqualTo(profilerId.toString()) + verify(fixture.scopes) + .captureTransaction( + check { assertThat(it.contexts.profile?.profilerId).isEqualTo(profilerId) }, + anyOrNull(), + anyOrNull(), + anyOrNull(), + ) + } + + @Test + fun `when the profiling outcome is unknown, profile context and profiler id are kept`() { + val continuousProfiler = mock() + val profilerId = SentryId() + whenever(continuousProfiler.profilerId).thenReturn(profilerId) + whenever(continuousProfiler.getProfileRecordingState(any(), any(), any())) + .thenReturn(ProfileRecordingState.UNKNOWN) + val tracer = + fixture.getSut( + optionsConfiguration = { it.setContinuousProfiler(continuousProfiler) }, + samplingDecision = TracesSamplingDecision(true), + ) + val span = tracer.startChild("span.op") + span.finish() + + tracer.finish() + + assertThat(span.getData(SpanDataConvention.PROFILER_ID)).isEqualTo(profilerId.toString()) + verify(fixture.scopes) + .captureTransaction( + check { assertThat(it.contexts.profile?.profilerId).isEqualTo(profilerId) }, + anyOrNull(), + anyOrNull(), + anyOrNull(), + ) + } + + @Test + fun `only the spans no profile covers lose their profiler id`() { + val continuousProfiler = mock() + val profilerId = SentryId() + whenever(continuousProfiler.profilerId).thenReturn(profilerId) + val tracer = + fixture.getSut( + optionsConfiguration = { it.setContinuousProfiler(continuousProfiler) }, + samplingDecision = TracesSamplingDecision(true), + ) + val uncoveredSpan = tracer.startChild("uncovered.op") + val coveredSpan = tracer.startChild("covered.op") + uncoveredSpan.finish() + coveredSpan.finish() + whenever(continuousProfiler.getProfileRecordingState(any(), any(), any())).thenAnswer { + invocation -> + if (invocation.getArgument(1) === uncoveredSpan.startDate) + ProfileRecordingState.NOT_RECORDED + else ProfileRecordingState.RECORDED + } + + tracer.finish() + + assertThat(uncoveredSpan.getData(SpanDataConvention.PROFILER_ID)).isNull() + assertThat(coveredSpan.getData(SpanDataConvention.PROFILER_ID)).isEqualTo(profilerId.toString()) + verify(fixture.scopes) + .captureTransaction( + check { assertThat(it.contexts.profile?.profilerId).isEqualTo(profilerId) }, + anyOrNull(), + anyOrNull(), + anyOrNull(), + ) + } + + @Test + fun `a profiler id the SDK did not write is left alone`() { + val continuousProfiler = mock() + whenever(continuousProfiler.profilerId).thenReturn(SentryId()) + whenever(continuousProfiler.getProfileRecordingState(any(), any(), any())) + .thenReturn(ProfileRecordingState.NOT_RECORDED) + val tracer = + fixture.getSut( + optionsConfiguration = { it.setContinuousProfiler(continuousProfiler) }, + samplingDecision = TracesSamplingDecision(true), + ) + val span = tracer.startChild("span.op") + // The span data key is public API, so anyone can put anything under it + span.setData(SpanDataConvention.PROFILER_ID, "not-an-id") + + tracer.finish() + + assertThat(span.getData(SpanDataConvention.PROFILER_ID)).isEqualTo("not-an-id") + } + + @Test + fun `a span that never finished is judged until the end of the transaction`() { + val continuousProfiler = mock() + whenever(continuousProfiler.profilerId).thenReturn(SentryId()) + whenever(continuousProfiler.getProfileRecordingState(any(), any(), any())) + .thenReturn(ProfileRecordingState.UNKNOWN) + val tracer = + fixture.getSut( + optionsConfiguration = { it.setContinuousProfiler(continuousProfiler) }, + samplingDecision = TracesSamplingDecision(true), + ) + val unfinishedSpan = tracer.startChild("unfinished.op") + + tracer.finish() + + val endTimes = argumentCaptor() + verify(continuousProfiler, atLeastOnce()) + .getProfileRecordingState(any(), eq(unfinishedSpan.startDate), endTimes.capture()) + assertThat(endTimes.lastValue.isAfter(unfinishedSpan.startDate)).isTrue() + } + @Test fun `when transaction is not sampled, profile context is not set`() { val continuousProfiler = mock() diff --git a/sentry/src/test/java/io/sentry/profiling/ProfilingServiceLoaderTest.kt b/sentry/src/test/java/io/sentry/profiling/ProfilingServiceLoaderTest.kt index 0fed85995da..f3559b4e007 100644 --- a/sentry/src/test/java/io/sentry/profiling/ProfilingServiceLoaderTest.kt +++ b/sentry/src/test/java/io/sentry/profiling/ProfilingServiceLoaderTest.kt @@ -5,6 +5,7 @@ import io.sentry.ILogger import io.sentry.IProfileConverter import io.sentry.ISentryExecutorService import io.sentry.ProfileLifecycle +import io.sentry.SentryDate import io.sentry.TracesSampler import io.sentry.protocol.SentryId import io.sentry.protocol.profiling.SentryProfile @@ -78,4 +79,12 @@ class ContinuousProfilerStub() : IContinuousProfiler { override fun getChunkId(): SentryId { TODO("Not yet implemented") } + + override fun getProfileRecordingState( + profilerId: SentryId, + startTime: SentryDate, + endTime: SentryDate, + ): ProfileRecordingState { + TODO("Not yet implemented") + } } From 0162f62bc20213c4c6b6959dd77026474c330ee3 Mon Sep 17 00:00:00 2001 From: Markus Hintersteiner Date: Thu, 27 Aug 2026 10:25:47 +0200 Subject: [PATCH 2/2] changelog --- CHANGELOG.md | 1 + 1 file changed, 1 insertion(+) diff --git a/CHANGELOG.md b/CHANGELOG.md index bc5c2920ab0..16819f9eac1 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)) +- Drop the `profiler_id` from transactions and spans when no Perfetto profile covers them, e.g. when Android's `ProfilingManager` rate limits the profiling request ([#6015](https://github.com/getsentry/sentry-java/pull/6015)) ### Features