Skip to content

Commit 82919fd

Browse files
runningcodeclaude
andcommitted
fix(android): Anchor the frame-metrics time projection (JAVA-579)
SpanFrameMetricsCollector places a span on the frame timeline, which is stamped by Choreographer on System.nanoTime(). Spans carrying a SentryNanotimeDate are already on that timeline, but a wall-stamped one — an app start span built from TimeSpan — has to be projected onto it, and toNanoTime read the offset between the two clocks at the moment the span finished. That offset is not a constant. A wall-clock step moves one clock, and time spent suspended moves the other, since System.nanoTime() stops in suspend and the wall clock does not. So the projection charged the span for every step and every suspend since it started, and an app start span could be placed far away from the frames it actually overlapped, taking its frames_slow/frozen/delay data with it. Take one wall reading and one tick at construction and project through that fixed anchor instead. Co-Authored-By: Claude Opus 5 (1M context) <noreply@anthropic.com>
1 parent 1b8668a commit 82919fd

2 files changed

Lines changed: 80 additions & 7 deletions

File tree

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

Lines changed: 37 additions & 7 deletions
Original file line numberDiff line numberDiff line change
@@ -1,6 +1,5 @@
11
package io.sentry.android.core;
22

3-
import io.sentry.DateUtils;
43
import io.sentry.IPerformanceContinuousCollector;
54
import io.sentry.ISentryLifecycleToken;
65
import io.sentry.ISpan;
@@ -12,6 +11,10 @@
1211
import io.sentry.SpanDataConvention;
1312
import io.sentry.android.core.internal.util.SentryFrameMetricsCollector;
1413
import io.sentry.protocol.MeasurementValue;
14+
import io.sentry.time.EpochClock;
15+
import io.sentry.time.JavaMonotonicTicker;
16+
import io.sentry.time.MonotonicTicker;
17+
import io.sentry.time.SystemEpochClock;
1518
import io.sentry.util.AutoClosableReentrantLock;
1619
import java.util.Iterator;
1720
import java.util.SortedSet;
@@ -68,12 +71,35 @@ public class SpanFrameMetricsCollector
6871
// assume 60fps until we get a value reported by the system
6972
private long lastKnownFrameDurationNanos = 16_666_666L;
7073

74+
// One wall-clock reading paired with one tick, both taken at construction, used to place
75+
// wall-stamped span dates on the frame timeline. See toNanoTime.
76+
private final long wallAnchorNanos;
77+
private final long tickAnchorNanos;
78+
7179
public SpanFrameMetricsCollector(
7280
final @NotNull SentryAndroidOptions options,
7381
final @NotNull SentryFrameMetricsCollector frameMetricsCollector) {
82+
// Deliberately not options.getMonotonicTicker(), which is elapsedRealtimeNanos on Android:
83+
// frames are stamped by Choreographer on System.nanoTime(), and the two bases drift apart by
84+
// however long the device spends suspended.
85+
this(
86+
options,
87+
frameMetricsCollector,
88+
SystemEpochClock.getInstance(),
89+
JavaMonotonicTicker.getInstance());
90+
}
91+
92+
SpanFrameMetricsCollector(
93+
final @NotNull SentryAndroidOptions options,
94+
final @NotNull SentryFrameMetricsCollector frameMetricsCollector,
95+
final @NotNull EpochClock epochClock,
96+
final @NotNull MonotonicTicker frameTicker) {
7497
this.frameMetricsCollector = frameMetricsCollector;
7598

7699
enabled = options.isEnablePerformanceV2() && options.isEnableFramesTracking();
100+
101+
this.wallAnchorNanos = epochClock.now().epochNanos();
102+
this.tickAnchorNanos = frameTicker.tickNanos();
77103
}
78104

79105
@Override
@@ -312,18 +338,22 @@ private static int addPendingFrameDelay(
312338
* @param date the input date
313339
* @return a non-unix timestamp in nano precision, similar to {@link System#nanoTime()}.
314340
*/
315-
private static long toNanoTime(final @NotNull SentryDate date) {
341+
private long toNanoTime(final @NotNull SentryDate date) {
316342
// SentryNanotimeDate nanotime is based on System.nanotime(), like EMPTY_NANO_TIME,
317343
// thus diff will simply return the System.nanotime() value of date
318344
if (date instanceof SentryNanotimeDate) {
319345
return date.diff(EMPTY_NANO_TIME);
320346
}
321347

322-
// e.g. SentryLongDate is unix time based - upscaled to nanos,
323-
// we need to project it back to System.nanotime() format
324-
long nowUnixInNanos = DateUtils.millisToNanos(System.currentTimeMillis());
325-
long shiftInNanos = nowUnixInNanos - date.nanoTimestamp();
326-
return System.nanoTime() - shiftInNanos;
348+
// e.g. SentryLongDate is unix time based - upscaled to nanos, so it has to be projected onto
349+
// the frame timeline. That projection needs the offset between the two clocks, and the offset
350+
// is only a constant while nothing disturbs either of them: a wall-clock step moves one, and
351+
// time spent suspended moves the other, since System.nanoTime() stops in suspend and the wall
352+
// clock does not. Reading the offset here, whenever a span happens to finish, would therefore
353+
// charge the span for every step and every suspend since it started - an app start span can
354+
// be projected hours away from the frames it actually overlapped. Hold the offset from
355+
// construction instead, so a span lands where it did when the SDK started.
356+
return tickAnchorNanos + (date.nanoTimestamp() - wallAnchorNanos);
327357
}
328358

329359
private static class Frame implements Comparable<Frame> {

‎sentry-android-core/src/test/java/io/sentry/android/core/SpanFrameMetricsCollectorTest.kt‎

Lines changed: 43 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -4,10 +4,15 @@ import io.sentry.ISpan
44
import io.sentry.ITransaction
55
import io.sentry.NoOpSpan
66
import io.sentry.NoOpTransaction
7+
import io.sentry.SentryLongDate
78
import io.sentry.SentryNanotimeDate
89
import io.sentry.SpanContext
10+
import io.sentry.SpanDataConvention
911
import io.sentry.android.core.internal.util.SentryFrameMetricsCollector
1012
import io.sentry.protocol.MeasurementValue
13+
import io.sentry.time.EpochClock
14+
import io.sentry.time.TestMonotonicTicker
15+
import io.sentry.time.Timestamp
1116
import java.util.UUID
1217
import java.util.concurrent.TimeUnit
1318
import kotlin.test.Test
@@ -84,6 +89,44 @@ class SpanFrameMetricsCollectorTest {
8489

8590
private val fixture = Fixture()
8691

92+
@Test
93+
fun `a wall-clock span is placed on the frame timeline using the anchor taken at construction`() {
94+
// app start spans are SentryLongDates, stamped on the wall clock rather than on nanoTime
95+
val anchorEpochNanos = TimeUnit.SECONDS.toNanos(1_600_000_000)
96+
val frameTicker = TestMonotonicTicker()
97+
98+
whenever(fixture.frameMetricsCollector.startCollection(any()))
99+
.thenReturn(UUID.randomUUID().toString())
100+
whenever(fixture.frameMetricsCollector.getLastKnownFrameStartTimeNanos()).thenReturn(-1)
101+
fixture.options.frameMetricsCollector = fixture.frameMetricsCollector
102+
fixture.options.isEnableFramesTracking = true
103+
fixture.options.isEnablePerformanceV2 = true
104+
105+
val sut =
106+
SpanFrameMetricsCollector(
107+
fixture.options,
108+
fixture.frameMetricsCollector,
109+
EpochClock { Timestamp.ofEpochNanos(anchorEpochNanos) },
110+
frameTicker,
111+
)
112+
113+
val span = mock<ISpan>()
114+
whenever(span.spanContext).thenReturn(SpanContext("op.fake"))
115+
whenever(span.startDate).thenReturn(SentryLongDate(anchorEpochNanos + 1_000))
116+
whenever(span.finishDate).thenReturn(SentryLongDate(anchorEpochNanos + 100_000_000))
117+
118+
sut.onSpanStarted(span)
119+
// one slow frame, on the frame timeline, fully inside the span
120+
sut.onFrameMetricCollected(2_000, 50_000_000, 49_998_000, 30_000_000, true, false, 60.0f)
121+
122+
// the device spends an hour suspended before the span finishes, so the offset between the
123+
// wall clock and the frame timeline is no longer what it was when the span started
124+
frameTicker.advance(1, TimeUnit.HOURS)
125+
sut.onSpanFinished(span)
126+
127+
verify(span).setData(SpanDataConvention.FRAMES_SLOW, 1)
128+
}
129+
87130
@Test
88131
fun `When AndroidSlowFrozenFrameCollector is initialized, it doesn't register any listener`() {
89132
fixture.getSut()

0 commit comments

Comments
 (0)