-
-
Notifications
You must be signed in to change notification settings - Fork 474
feat(profiling): Drop profiler ids from spans no profile covers #6015
New issue
Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.
By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. Weโll occasionally send you account related emails.
Already on GitHub? Sign in to your account
base: main
Are you sure you want to change the base?
Changes from all commits
c43c325
0162f62
178d7d8
31b6ce5
File filter
Filter by extension
Conversations
Jump to
Diff view
Diff view
There are no files selected for viewing
| Original file line number | Diff line number | Diff line change | ||||||||||||
|---|---|---|---|---|---|---|---|---|---|---|---|---|---|---|
|
|
@@ -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,18 +61,28 @@ | |||||||||||||
| * <p>Currently, this class doesn't do app-start profiling {@link SentryPerformanceProvider}. It is | ||||||||||||||
| * created during {@code Sentry.init()}. | ||||||||||||||
| * | ||||||||||||||
| * <p>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. | ||||||||||||||
| * <p>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. | ||||||||||||||
| * | ||||||||||||||
| * <p>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) | ||||||||||||||
| 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<ChunkRecord> 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; | ||||||||||||||
|
Member
There was a problem hiding this comment. Choose a reason for hiding this commentThe reason will be displayed to describe this comment to others. Learn more. m: Thoughts about updating our approach to match the following policy?
We could implement it like this: @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;
}
boolean hasUnknownOverlappingChunk = false;
for (final @NotNull ChunkRecord chunk : chunkHistory) {
if (!chunk.getProfilerId().equals(profilerId) || !chunk.overlaps(startTime, endTime)) {
continue;
}
final @NotNull ProfileRecordingState state = chunk.getRecordingState();
if (state == ProfileRecordingState.RECORDED) {
return ProfileRecordingState.RECORDED;
}
if (state == ProfileRecordingState.UNKNOWN) {
hasUnknownOverlappingChunk = true;
}
}
if (hasUnknownOverlappingChunk) {
return ProfileRecordingState.UNKNOWN;
}
return ProfileRecordingState.NOT_RECORDED;
}
} That'd let us avoid returning |
||||||||||||||
| } | ||||||||||||||
| } | ||||||||||||||
|
|
||||||||||||||
| // 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; | ||||||||||||||
|
Member
There was a problem hiding this comment. Choose a reason for hiding this commentThe reason will be displayed to describe this comment to others. Learn more. m: What's the thinking behind updating the profilerId? Fwiw, I would've figured we'd keep the profilerId intact and let the ProfileRecordingState inform the outside world about the success vs failure of recording โ but perhaps I'm missing something? |
||||||||||||||
| 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<String, ProfileMeasurement> 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, | ||||||||||||||
|
|
||||||||||||||
There was a problem hiding this comment.
Choose a reason for hiding this comment
The reason will be displayed to describe this comment to others. Learn more.
l: Can we just use
chunkHistory.peekLast()instead?