Skip to content

Commit e387e89

Browse files
committed
fix(profiler): restore ns-since-chunk-start conversion for Perfetto measurements
ChunkMeasurementCollector was shipping raw clock values in elapsed_since_start_ns: System.nanoTime() for frame metrics and System.currentTimeMillis()*1e6 for cpu/memory. Cause: Conversions that the legacy AndroidProfiler performs were dropped when the collector was extracted. Fix: Restore both, refactor to make the logic more intuitive
1 parent 1a6742c commit e387e89

2 files changed

Lines changed: 47 additions & 8 deletions

File tree

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

Lines changed: 44 additions & 8 deletions
Original file line numberDiff line numberDiff line change
@@ -4,6 +4,7 @@
44
import static io.sentry.IConnectionStatusProvider.ConnectionStatus.DISCONNECTED;
55

66
import android.os.Build;
7+
import android.os.SystemClock;
78
import androidx.annotation.RequiresApi;
89
import io.sentry.CompositePerformanceCollector;
910
import io.sentry.DataCategory;
@@ -39,6 +40,7 @@
3940
import java.util.concurrent.ConcurrentLinkedDeque;
4041
import java.util.concurrent.Future;
4142
import java.util.concurrent.RejectedExecutionException;
43+
import java.util.concurrent.TimeUnit;
4244
import java.util.concurrent.atomic.AtomicBoolean;
4345
import org.jetbrains.annotations.ApiStatus;
4446
import org.jetbrains.annotations.NotNull;
@@ -423,6 +425,11 @@ static class ChunkMeasurementCollector {
423425
private final @NotNull ConcurrentLinkedDeque<ProfileMeasurementValue>
424426
screenFrameRateMeasurements = new ConcurrentLinkedDeque<>();
425427

428+
// Elapsed realtime when the measurement was started (nanosecond precision).
429+
// Used to convert wall-time clock values into ns-since-chunk-start for the measurements
430+
// payload.
431+
private long profileStartElapsedRealtimeNanos = 0;
432+
426433
ChunkMeasurementCollector(final @NotNull SentryFrameMetricsCollector frameMetricsCollector) {
427434
this.frameMetricsCollector = frameMetricsCollector;
428435
}
@@ -432,6 +439,7 @@ void start(
432439
final @NotNull String chunkId) {
433440
this.performanceCollector = performanceCollector;
434441
this.chunkId = chunkId;
442+
this.profileStartElapsedRealtimeNanos = SystemClock.elapsedRealtimeNanos();
435443

436444
// Start frame metrics collection (runs on the FrameMetrics HandlerThread)
437445
slowFrameRenderMeasurements.clear();
@@ -452,17 +460,27 @@ public void onFrameMetricCollected(
452460
final boolean isFrozen,
453461
final float refreshRate) {
454462
final long timestampNanos = new SentryNanotimeDate().nanoTimestamp();
463+
// Convert frameEndNanos (reported by FrameMetricsCollector using System.nanoTime /
464+
// SystemClock.uptimeMillis), into the SystemClock.elapsedRealtime to report elapsed
465+
// realtime nanos since chunk start
466+
final long frameEndElapsedRealtimeNanos =
467+
frameEndNanos - System.nanoTime() + SystemClock.elapsedRealtimeNanos();
468+
final long frameTimestampRelativeNanos =
469+
frameEndElapsedRealtimeNanos - profileStartElapsedRealtimeNanos;
455470
if (isFrozen) {
456471
frozenFrameRenderMeasurements.addLast(
457-
new ProfileMeasurementValue(frameEndNanos, durationNanos, timestampNanos));
472+
new ProfileMeasurementValue(
473+
frameTimestampRelativeNanos, durationNanos, timestampNanos));
458474
} else if (isSlow) {
459475
slowFrameRenderMeasurements.addLast(
460-
new ProfileMeasurementValue(frameEndNanos, durationNanos, timestampNanos));
476+
new ProfileMeasurementValue(
477+
frameTimestampRelativeNanos, durationNanos, timestampNanos));
461478
}
462479
if (refreshRate != lastRefreshRate) {
463480
lastRefreshRate = refreshRate;
464481
screenFrameRateMeasurements.addLast(
465-
new ProfileMeasurementValue(frameEndNanos, refreshRate, timestampNanos));
482+
new ProfileMeasurementValue(
483+
frameTimestampRelativeNanos, refreshRate, timestampNanos));
466484
}
467485
}
468486
});
@@ -489,7 +507,15 @@ Map<String, ProfileMeasurement> stop() {
489507
@Nullable List<PerformanceCollectionData> performanceData = null;
490508
if (performanceCollector != null && chunkId != null) {
491509
performanceData = performanceCollector.stop(chunkId);
492-
addPerformanceDataToMeasurements(performanceData, measurements);
510+
final long wallClockNowNanos =
511+
TimeUnit.MILLISECONDS.toNanos(System.currentTimeMillis());
512+
final long elapsedRealtimeNowNanos = SystemClock.elapsedRealtimeNanos();
513+
addPerformanceDataToMeasurements(
514+
performanceData,
515+
measurements,
516+
wallClockNowNanos,
517+
elapsedRealtimeNowNanos,
518+
profileStartElapsedRealtimeNanos);
493519
}
494520
performanceCollector = null;
495521
chunkId = null;
@@ -522,7 +548,10 @@ private void addFrameDataToMeasurements(
522548

523549
private static void addPerformanceDataToMeasurements(
524550
final @Nullable List<PerformanceCollectionData> performanceData,
525-
final @NotNull Map<String, ProfileMeasurement> measurements) {
551+
final @NotNull Map<String, ProfileMeasurement> measurements,
552+
final long wallClockNowNanos,
553+
final long elapsedRealtimeNowNanos,
554+
final long profileStartElapsedRealtimeNanos) {
526555
if (performanceData == null || performanceData.isEmpty()) {
527556
return;
528557
}
@@ -534,22 +563,29 @@ private static void addPerformanceDataToMeasurements(
534563
new ArrayDeque<>(performanceData.size());
535564

536565
for (final @NotNull PerformanceCollectionData data : performanceData) {
566+
// Convert sample timestamps (reported by CompositePerformanceCollector using
567+
// System.currentTimeMillis), into the SystemClock.elapsedRealtime to report
568+
// elapsed realtime nanos since chunk start
537569
final long nanoTimestamp = data.getNanoTimestamp();
570+
final long nanosSinceSample = wallClockNowNanos - nanoTimestamp;
571+
final long sampleElapsedRealtimeNanos = elapsedRealtimeNowNanos - nanosSinceSample;
572+
final long relativeStartNs =
573+
sampleElapsedRealtimeNanos - profileStartElapsedRealtimeNanos;
538574
final @Nullable Double cpuUsagePercentage = data.getCpuUsagePercentage();
539575
final @Nullable Long usedHeapMemory = data.getUsedHeapMemory();
540576
final @Nullable Long usedNativeMemory = data.getUsedNativeMemory();
541577

542578
if (cpuUsagePercentage != null) {
543579
cpuUsageMeasurements.addLast(
544-
new ProfileMeasurementValue(nanoTimestamp, cpuUsagePercentage, nanoTimestamp));
580+
new ProfileMeasurementValue(relativeStartNs, cpuUsagePercentage, nanoTimestamp));
545581
}
546582
if (usedHeapMemory != null) {
547583
memoryUsageMeasurements.addLast(
548-
new ProfileMeasurementValue(nanoTimestamp, usedHeapMemory, nanoTimestamp));
584+
new ProfileMeasurementValue(relativeStartNs, usedHeapMemory, nanoTimestamp));
549585
}
550586
if (usedNativeMemory != null) {
551587
nativeMemoryUsageMeasurements.addLast(
552-
new ProfileMeasurementValue(nanoTimestamp, usedNativeMemory, nanoTimestamp));
588+
new ProfileMeasurementValue(relativeStartNs, usedNativeMemory, nanoTimestamp));
553589
}
554590
}
555591

sentry-android-core/src/test/java/io/sentry/android/core/ChunkMeasurementCollectorTest.kt

Lines changed: 3 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -4,8 +4,11 @@ import io.sentry.CompositePerformanceCollector
44
import io.sentry.PerformanceCollectionData
55
import io.sentry.android.core.internal.util.SentryFrameMetricsCollector
66
import io.sentry.profilemeasurements.ProfileMeasurement
7+
import java.util.concurrent.TimeUnit
8+
import kotlin.math.abs
79
import kotlin.test.Test
810
import kotlin.test.assertEquals
11+
import kotlin.test.assertTrue
912
import org.mockito.kotlin.any
1013
import org.mockito.kotlin.argumentCaptor
1114
import org.mockito.kotlin.mock

0 commit comments

Comments
 (0)