Skip to content

Commit a5555ea

Browse files
markushiclaude
andauthored
feat(profiling): Drop profiler ids from spans no profile covers (#6015)
* feat(profiling): drop profiler ids from spans no profile covers Co-Authored-By: Claude Opus 5 <noreply@anthropic.com> * changelog * feat(profiling): return unknown for profile chunks without an outcome * fix(profiling): mark a chunk collected on a terminating close as not recorded * docs(profiling): explain the chunk history size and the overlap rule * fix(profiling): remember a chunk before profiling starts * fix(profiling): keep the profiler id when no chunk covers the window --------- Co-authored-by: Claude Opus 5 <noreply@anthropic.com>
1 parent fa8c306 commit a5555ea

18 files changed

Lines changed: 1079 additions & 34 deletions

File tree

‎CHANGELOG.md‎

Lines changed: 1 addition & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -18,6 +18,7 @@
1818
- `globalHubMode` is enabled by default on Android, where tags, extras, contexts and level set inside the callback were silently dropped
1919
- Scopes that are explicitly made current, e.g. via `Sentry.setCurrentScopes` or the `SentryContext` coroutine integration, are now also honoured when `globalHubMode` is enabled
2020
- `Sentry.pushScope`, `Sentry.pushIsolationScope` and `Sentry.popScope` remain no-ops when `globalHubMode` is enabled
21+
- 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))
2122

2223
### Internal
2324

‎sentry-android-core/api/sentry-android-core.api‎

Lines changed: 2 additions & 1 deletion
Original file line numberDiff line numberDiff line change
@@ -44,6 +44,7 @@ public class io/sentry/android/core/AndroidContinuousProfiler : io/sentry/IConti
4444
public fun <init> (Lio/sentry/android/core/BuildInfoProvider;Lio/sentry/android/core/internal/util/SentryFrameMetricsCollector;Lio/sentry/ILogger;Ljava/lang/String;ILio/sentry/util/LazyEvaluator$Evaluator;)V
4545
public fun close (Z)V
4646
public fun getChunkId ()Lio/sentry/protocol/SentryId;
47+
public fun getProfileRecordingState (Lio/sentry/protocol/SentryId;Lio/sentry/SentryDate;Lio/sentry/SentryDate;)Lio/sentry/profiling/ProfileRecordingState;
4748
public fun getProfilerId ()Lio/sentry/protocol/SentryId;
4849
public fun getRootSpanCounter ()I
4950
public fun isRunning ()Z
@@ -371,6 +372,7 @@ public class io/sentry/android/core/PerfettoContinuousProfiler : io/sentry/ICont
371372
public fun <init> (Lio/sentry/ILogger;Lio/sentry/android/core/internal/util/SentryFrameMetricsCollector;Lio/sentry/util/LazyEvaluator$Evaluator;Ljava/util/function/Supplier;)V
372373
public fun close (Z)V
373374
public fun getChunkId ()Lio/sentry/protocol/SentryId;
375+
public fun getProfileRecordingState (Lio/sentry/protocol/SentryId;Lio/sentry/SentryDate;Lio/sentry/SentryDate;)Lio/sentry/profiling/ProfileRecordingState;
374376
public fun getProfilerId ()Lio/sentry/protocol/SentryId;
375377
public fun isRunning ()Z
376378
public fun onRateLimitChanged (Lio/sentry/transport/RateLimiter;)V
@@ -382,7 +384,6 @@ public class io/sentry/android/core/PerfettoContinuousProfiler : io/sentry/ICont
382384
public class io/sentry/android/core/PerfettoProfiler {
383385
public fun <init> (Landroid/content/Context;Lio/sentry/ILogger;Lio/sentry/ISentryExecutorService;)V
384386
public fun endAndCollect (Ljava/util/function/Consumer;)V
385-
public fun start (J)Z
386387
}
387388

388389
public final class io/sentry/android/core/ScreenshotEventProcessor : io/sentry/EventProcessor {

‎sentry-android-core/src/main/java/io/sentry/android/core/AndroidContinuousProfiler.java‎

Lines changed: 13 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -23,6 +23,7 @@
2323
import io.sentry.SentryOptions;
2424
import io.sentry.TracesSampler;
2525
import io.sentry.android.core.internal.util.SentryFrameMetricsCollector;
26+
import io.sentry.profiling.ProfileRecordingState;
2627
import io.sentry.protocol.SentryId;
2728
import io.sentry.transport.RateLimiter;
2829
import io.sentry.util.AutoClosableReentrantLock;
@@ -358,6 +359,18 @@ public void close(final boolean isTerminating) {
358359
return chunkId;
359360
}
360361

362+
/**
363+
* This profiler does not track the outcome of its profiling requests, so the answer is always
364+
* unknown.
365+
*/
366+
@Override
367+
public @NotNull ProfileRecordingState getProfileRecordingState(
368+
final @NotNull SentryId profilerId,
369+
final @NotNull SentryDate startTime,
370+
final @NotNull SentryDate endTime) {
371+
return ProfileRecordingState.UNKNOWN;
372+
}
373+
361374
private void sendChunks(final @NotNull IScopes scopes, final @NotNull SentryOptions options) {
362375
try {
363376
options

‎sentry-android-core/src/main/java/io/sentry/android/core/PerfettoContinuousProfiler.java‎

Lines changed: 143 additions & 14 deletions
Original file line numberDiff line numberDiff line change
@@ -23,9 +23,11 @@
2323
import io.sentry.SentryNanotimeDate;
2424
import io.sentry.SentryOptions;
2525
import io.sentry.TracesSampler;
26+
import io.sentry.android.core.internal.profiling.ChunkRecord;
2627
import io.sentry.android.core.internal.util.SentryFrameMetricsCollector;
2728
import io.sentry.profilemeasurements.ProfileMeasurement;
2829
import io.sentry.profilemeasurements.ProfileMeasurementValue;
30+
import io.sentry.profiling.ProfileRecordingState;
2931
import io.sentry.protocol.SentryId;
3032
import io.sentry.transport.RateLimiter;
3133
import io.sentry.util.AutoClosableReentrantLock;
@@ -59,18 +61,32 @@
5961
* <p>Currently, this class doesn't do app-start profiling {@link SentryPerformanceProvider}. It is
6062
* created during {@code Sentry.init()}.
6163
*
62-
* <p>Thread safety: all mutable state is guarded by a single {@link
63-
* io.sentry.util.AutoClosableReentrantLock}. Public entry points ({@link #startProfiler}, {@link
64-
* #stopProfiler}, {@link #close}, {@link #onRateLimitChanged}, {@link #reevaluateSampling}, and the
65-
* getters) acquire the lock themselves and are thread-safe. Private methods {@code startInternal}
66-
* and {@code stopInternal} require the caller to hold the lock.
64+
* <p>Thread safety: the profiler state is guarded by {@link #lock}. Every public entry point
65+
* acquires it itself and is thread-safe. Private methods that say {@code Caller must hold} a lock
66+
* do not, and must only be reached from a frame that already holds it.
67+
*
68+
* <p>The chunk history is guarded by its own {@link #chunkHistoryLock}, so that {@link
69+
* #getProfileRecordingState} — called for every span of a finishing transaction — never waits for a
70+
* chunk start or a chunk stop. A frame holding {@link #lock} may take {@link #chunkHistoryLock},
71+
* never the other way around. Each {@link ChunkRecord} guards its own state, as the profiler writes
72+
* the outcome of a running chunk into it.
6773
*/
6874
@ApiStatus.Internal
6975
@RequiresApi(api = Build.VERSION_CODES.VANILLA_ICE_CREAM)
7076
public class PerfettoContinuousProfiler
7177
implements IContinuousProfiler, RateLimiter.IRateLimitObserver {
7278
private static final long MAX_CHUNK_DURATION_MILLIS = 60000;
7379

80+
/**
81+
* How many chunks we remember the outcome of. Spans only ask about windows they were running in,
82+
* so a handful of chunks (a minute each) is plenty.
83+
*
84+
* <p>The history is therefore assumed to be long enough for every window a span can ask about. A
85+
* window whose chunks all fell out of it needs no special treatment: it reads as a window no
86+
* chunk covers, and keeps its profiler id.
87+
*/
88+
@VisibleForTesting static final int MAX_CHUNK_HISTORY_SIZE = 10;
89+
7490
// Matches the thread name produced by SentryExecutorService's thread factory, used to detect
7591
// when we are already running on the executor thread.
7692
private static final String EXECUTOR_THREAD_NAME_PREFIX = "SentryExecutorServiceThreadFactory";
@@ -96,6 +112,11 @@ public class PerfettoContinuousProfiler
96112

97113
private final AutoClosableReentrantLock lock = new AutoClosableReentrantLock();
98114

115+
private final @NotNull ArrayDeque<ChunkRecord> chunkHistory =
116+
new ArrayDeque<>(MAX_CHUNK_HISTORY_SIZE);
117+
118+
private final AutoClosableReentrantLock chunkHistoryLock = new AutoClosableReentrantLock();
119+
99120
public PerfettoContinuousProfiler(
100121
final @NotNull ILogger logger,
101122
final @NotNull SentryFrameMetricsCollector frameMetricsCollector,
@@ -186,8 +207,12 @@ public void close(final boolean isTerminating) {
186207
activeTraceCount = 0;
187208
shouldStop = true;
188209
if (isTerminating) {
189-
stopInternal(false);
210+
// Closing first, so that a result the OS already delivered cannot mark the chunk that
211+
// stopInternal ends as recorded: nothing is sent once the profiler is closed
190212
isClosed.set(true);
213+
stopInternal(false);
214+
// The chunk that just ended covers nothing, and a pending collection cannot change that
215+
markLastChunkNotRecordedIfUnknown();
191216
}
192217
}
193218
}
@@ -213,6 +238,89 @@ public boolean isRunning() {
213238
}
214239
}
215240

241+
@Override
242+
public @NotNull ProfileRecordingState getProfileRecordingState(
243+
final @NotNull SentryId profilerId,
244+
final @NotNull SentryDate startTime,
245+
final @NotNull SentryDate endTime) {
246+
try (final @NotNull ISentryLifecycleToken ignored = chunkHistoryLock.acquire()) {
247+
boolean hasFailedChunk = false;
248+
boolean hasUnknownChunk = false;
249+
250+
for (final @NotNull ChunkRecord chunk : chunkHistory) {
251+
if (!chunk.getProfilerId().equals(profilerId) || !chunk.overlaps(startTime, endTime)) {
252+
continue;
253+
}
254+
final @NotNull ProfileRecordingState state = chunk.getRecordingState();
255+
if (state == ProfileRecordingState.RECORDED) {
256+
return ProfileRecordingState.RECORDED;
257+
}
258+
if (state == ProfileRecordingState.UNKNOWN) {
259+
hasUnknownChunk = true;
260+
} else {
261+
hasFailedChunk = true;
262+
}
263+
}
264+
265+
// A chunk that is still running, or that is still being collected, may yet be recorded
266+
if (hasUnknownChunk) {
267+
return ProfileRecordingState.UNKNOWN;
268+
}
269+
270+
// Every chunk covering the window failed
271+
if (hasFailedChunk) {
272+
return ProfileRecordingState.NOT_RECORDED;
273+
}
274+
275+
// No chunk covers the window. It may have fallen out of the history, or a back-dated span may
276+
// read as outside a chunk it really ran in, so the window gets the benefit of the doubt
277+
return ProfileRecordingState.UNKNOWN;
278+
}
279+
}
280+
281+
/**
282+
* Gives up on the newest chunk, unless its outcome is already known. Only that one can still be
283+
* unknown, as a chunk gets its outcome before the next one starts.
284+
*/
285+
private void markLastChunkNotRecordedIfUnknown() {
286+
try (final @NotNull ISentryLifecycleToken ignored = chunkHistoryLock.acquire()) {
287+
final @Nullable ChunkRecord lastChunk = chunkHistory.peekLast();
288+
if (lastChunk != null && lastChunk.getRecordingState() == ProfileRecordingState.UNKNOWN) {
289+
lastChunk.setRecordingState(ProfileRecordingState.NOT_RECORDED);
290+
}
291+
}
292+
}
293+
294+
private void addChunkRecord(final @NotNull ChunkRecord chunk) {
295+
try (final @NotNull ISentryLifecycleToken ignored = chunkHistoryLock.acquire()) {
296+
if (chunkHistory.size() == MAX_CHUNK_HISTORY_SIZE) {
297+
chunkHistory.removeFirst();
298+
}
299+
chunkHistory.addLast(chunk);
300+
}
301+
}
302+
303+
private void removeChunkRecord(final @NotNull ChunkRecord chunk) {
304+
try (final @NotNull ISentryLifecycleToken ignored = chunkHistoryLock.acquire()) {
305+
chunkHistory.remove(chunk);
306+
}
307+
}
308+
309+
/**
310+
* Ends the running chunk, which is always the newest one, as a chunk only starts once the one
311+
* before it ended. Returns null if there is none, or if it already ended.
312+
*/
313+
private @Nullable ChunkRecord endChunkRecord(final @NotNull SentryDate endTimestamp) {
314+
try (final @NotNull ISentryLifecycleToken ignored = chunkHistoryLock.acquire()) {
315+
final @Nullable ChunkRecord chunk = chunkHistory.peekLast();
316+
if (chunk == null || chunk.hasEnded()) {
317+
return null;
318+
}
319+
chunk.setEndTimestamp(endTimestamp);
320+
return chunk;
321+
}
322+
}
323+
216324
/**
217325
* Resolves scopes on first call. Since PerfettoContinuousProfiler is created during Sentry.init()
218326
* and never used for app-start profiling, scopes is guaranteed to be available by the time
@@ -265,19 +373,27 @@ private void startInternal() {
265373
if (perfettoProfiler == null) {
266374
return;
267375
}
268-
if (!perfettoProfiler.start(MAX_CHUNK_DURATION_MILLIS)) {
269-
logger.log(
270-
SentryLevel.ERROR,
271-
"Failed to start Perfetto profiling. PerfettoProfiler.start() returned false.");
272-
return;
376+
if (SentryId.EMPTY_ID.equals(profilerId)) {
377+
profilerId = new SentryId();
273378
}
274379

275-
isRunning = true;
380+
// The chunk is known before profiling starts, so that a transaction finishing right after the
381+
// request cannot miss the chunk it ran in and drop its profiler id
382+
final @NotNull ChunkRecord chunkRecord =
383+
new ChunkRecord(profilerId, startProfileChunkTimestamp);
384+
addChunkRecord(chunkRecord);
276385

277-
if (profilerId.equals(SentryId.EMPTY_ID)) {
278-
profilerId = new SentryId();
386+
if (!perfettoProfiler.start(chunkRecord, MAX_CHUNK_DURATION_MILLIS)) {
387+
// No chunk ran, so the record is dropped rather than kept as a failure: it would take a slot
388+
// of the history away from the chunks that did run
389+
removeChunkRecord(chunkRecord);
390+
profilerId = SentryId.EMPTY_ID;
391+
chunkId = SentryId.EMPTY_ID;
392+
logger.log(SentryLevel.ERROR, "Failed to start Perfetto profiling.");
393+
return;
279394
}
280395

396+
isRunning = true;
281397
if (chunkId.equals(SentryId.EMPTY_ID)) {
282398
chunkId = new SentryId();
283399
}
@@ -328,6 +444,7 @@ private void stopInternal(final boolean restartProfiler) {
328444
final @NotNull SentryId chunkProfilerId = profilerId;
329445
final @NotNull SentryId chunkChunkId = chunkId;
330446
final @NotNull SentryDate chunkTimestamp = startProfileChunkTimestamp;
447+
final @Nullable ChunkRecord chunkRecord = endChunkRecord(options.getDateProvider().now());
331448

332449
isRunning = false;
333450
perfettoProfiler = null;
@@ -348,6 +465,7 @@ private void stopInternal(final boolean restartProfiler) {
348465
traceFile,
349466
chunkProfilerId,
350467
chunkChunkId,
468+
chunkRecord,
351469
measurements,
352470
chunkTimestamp,
353471
shouldRestart,
@@ -359,11 +477,22 @@ private void onChunkCollected(
359477
final @Nullable File traceFile,
360478
final @NotNull SentryId chunkProfilerId,
361479
final @NotNull SentryId chunkChunkId,
480+
final @Nullable ChunkRecord chunkRecord,
362481
final @NotNull Map<String, ProfileMeasurement> measurements,
363482
final @NotNull SentryDate chunkTimestamp,
364483
final boolean shouldRestart,
365484
final @NotNull IScopes scopes,
366485
final @NotNull SentryOptions options) {
486+
// The trace file is the last word on whether the chunk was recorded: the OS may report success
487+
// and still leave no usable file behind
488+
if (chunkRecord != null) {
489+
// Nothing is sent once the profiler is closed, so a collected chunk still covers nothing
490+
chunkRecord.setRecordingState(
491+
traceFile != null && !isClosed.get()
492+
? ProfileRecordingState.RECORDED
493+
: ProfileRecordingState.NOT_RECORDED);
494+
}
495+
367496
if (traceFile == null) {
368497
logger.log(
369498
SentryLevel.ERROR,

0 commit comments

Comments
 (0)