Skip to content

Commit e23fd78

Browse files
0xadam-brownOpenCode
andcommitted
fix(android): Defer frame metrics reflection during init
Moves Choreographer private field lookup out of the frame metrics collector constructor so SDK init does not synchronously perform framework reflection on the calling thread. Helps us reduce the likelihood of another common class of Sentry.init() ANRs (see [here](https://sentry.sentry.io/issues/6138715212/?project=4506812075540480&referrer=seer.agent.in-chat-link)). Behavior change from the user's perspective should usually be non-existant, and minor in the worst case. The choreographer and choreographerLastFrameTimeField properties are still initialized by a main-thread Handler post made during collector construction, before later startCollection() calls post frame-listener registration work to the same main looper. Since those main-looper tasks run in order, the Choreographer fallback should be populated before any collected frame or pending-frame interpolation normally needs it. If it's not ready yet, the failure mode is a missed/less precise first pending-frame calculation rather than a crash. Co-Authored-By: OpenCode <noreply@opencode.ai>
1 parent 926b414 commit e23fd78

3 files changed

Lines changed: 53 additions & 42 deletions

File tree

CHANGELOG.md

Lines changed: 1 addition & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -13,6 +13,7 @@
1313

1414
### Performance
1515

16+
- Defer `Choreographer` reflection for frame metrics collection until after SDK init to avoid blocking the main thread during `Sentry.init`
1617
- Use `RGB_565` instead of `ARGB_8888` for screenshot and replay capture bitmaps, halving per-frame memory usage ([#5821](https://github.com/getsentry/sentry-java/pull/5821))
1718
- Remove an unused lock from `SentryPerformanceProvider`, which was allocated on every cold start in `ContentProvider.onCreate` without ever being acquired ([#5871](https://github.com/getsentry/sentry-java/pull/5871))
1819
- Parse the app start profiling config with only the deserializer it needs instead of building a full `JsonSerializer` and `SentryOptions`, cutting 188 of 221 allocations on the main thread before `Application.onCreate` ([#5867](https://github.com/getsentry/sentry-java/pull/5867))

sentry-android-core/src/main/java/io/sentry/android/core/internal/util/SentryFrameMetricsCollector.java

Lines changed: 13 additions & 15 deletions
Original file line numberDiff line numberDiff line change
@@ -56,8 +56,8 @@ public final class SentryFrameMetricsCollector implements Application.ActivityLi
5656
private final WindowFrameMetricsManager windowFrameMetricsManager;
5757

5858
private @Nullable Window.OnFrameMetricsAvailableListener frameMetricsAvailableListener;
59-
private @Nullable Choreographer choreographer;
60-
private @Nullable Field choreographerLastFrameTimeField;
59+
private volatile @Nullable Choreographer choreographer;
60+
private volatile @Nullable Field choreographerLastFrameTimeField;
6161
private long lastFrameStartNanos = 0;
6262
private long lastFrameEndNanos = 0;
6363

@@ -126,27 +126,24 @@ public SentryFrameMetricsCollector(
126126
// Most considerations regarding timestamps of frames are inspired from JankStats library:
127127
// https://cs.android.com/androidx/platform/frameworks/support/+/androidx-main:metrics/metrics-performance/src/main/java/androidx/metrics/performance/JankStatsApi24Impl.kt
128128

129-
// The Choreographer instance must be accessed on the main thread
129+
// The Choreographer instance and private field reflection must be accessed asynchronously on
130+
// the main thread to avoid blocking SDK init. getLastKnownFrameStartTimeNanos() uses this for
131+
// pending frame interpolation on all supported API levels.
130132
new Handler(Looper.getMainLooper())
131133
.post(
132134
() -> {
133135
try {
134136
choreographer = Choreographer.getInstance();
137+
choreographerLastFrameTimeField =
138+
Choreographer.class.getDeclaredField("mLastFrameTimeNanos");
139+
choreographerLastFrameTimeField.setAccessible(true);
135140
} catch (Throwable e) {
136141
logger.log(
137142
SentryLevel.ERROR,
138-
"Error retrieving Choreographer instance. Slow and frozen frames will not be reported.",
143+
"Unable to get the frame timestamp from the choreographer: ",
139144
e);
140145
}
141146
});
142-
// Let's get the last frame timestamp from the choreographer private field
143-
try {
144-
choreographerLastFrameTimeField = Choreographer.class.getDeclaredField("mLastFrameTimeNanos");
145-
choreographerLastFrameTimeField.setAccessible(true);
146-
} catch (NoSuchFieldException e) {
147-
logger.log(
148-
SentryLevel.ERROR, "Unable to get the frame timestamp from the choreographer: ", e);
149-
}
150147

151148
frameMetricsAvailableListener =
152149
(window, frameMetrics, dropCountSinceLastInvocation) -> {
@@ -165,7 +162,8 @@ public SentryFrameMetricsCollector(
165162
final long delayNanos = Math.max(0, cpuDuration - expectedFrameDuration);
166163

167164
long startTime = getFrameStartTimestamp(frameMetrics);
168-
// If we couldn't get the timestamp through reflection, we use current time
165+
// If we couldn't get the timestamp through FrameMetrics or reflection, we use the current
166+
// time.
169167
if (startTime < 0) {
170168
startTime = now - cpuDuration;
171169
}
@@ -217,8 +215,8 @@ public static boolean isSlow(long frameDuration, final long expectedFrameDuratio
217215
}
218216

219217
/**
220-
* Return the internal timestamp in the choreographer of the last frame start timestamp through
221-
* reflection. On Android O the value is read from the frameMetrics itself.
218+
* Return the frame start timestamp. On API 26+, this value is read directly from {@link
219+
* FrameMetrics}; older APIs use the reflected Choreographer timestamp.
222220
*/
223221
@SuppressLint("NewApi")
224222
private long getFrameStartTimestamp(final @NotNull FrameMetrics frameMetrics) {

sentry-android-core/src/test/java/io/sentry/android/core/internal/util/SentryFrameMetricsCollectorTest.kt

Lines changed: 39 additions & 27 deletions
Original file line numberDiff line numberDiff line change
@@ -19,7 +19,6 @@ import io.sentry.test.getCtor
1919
import io.sentry.test.getProperty
2020
import io.sentry.test.injectForField
2121
import java.lang.ref.WeakReference
22-
import java.lang.reflect.Field
2322
import java.util.concurrent.TimeUnit
2423
import kotlin.test.BeforeTest
2524
import kotlin.test.Test
@@ -302,18 +301,41 @@ class SentryFrameMetricsCollectorTest {
302301
}
303302

304303
@Test
305-
fun `collector accesses choreographer instance on creation on main thread`() {
304+
fun `collector accesses choreographer instance and field asynchronously on main thread`() {
306305
val collector = fixture.getSut(context)
307-
val field: Field? = collector.getProperty("choreographerLastFrameTimeField")
306+
307+
val field: Any? = collector.getProperty("choreographerLastFrameTimeField")
308308
var choreographer: Choreographer? = collector.getProperty("choreographer")
309-
// Choreographer instance is accessed on main thread, but the field accessor happens in whatever
310-
// thread created the collector
311-
assertNotNull(field)
309+
312310
assertNull(choreographer)
311+
assertNull(field)
312+
313313
// Execute all posted tasks
314314
Shadows.shadowOf(Looper.getMainLooper()).idle()
315315
choreographer = collector.getProperty("choreographer")
316316
assertNotNull(choreographer)
317+
assertNotNull(collector.getProperty<Any?>("choreographerLastFrameTimeField"))
318+
}
319+
320+
// Frame callbacks on API 26+ read their per-frame start timestamp directly from FrameMetrics,
321+
// which can make the Choreographer fallback look like it should be specific to APIs < 26.
322+
// But SpanFrameMetricsCollector separately calls getLastKnownFrameStartTimeNanos() on every
323+
// API level for pending-frame interpolation, so API 26+ still needs the Choreographer
324+
// fallback to be initialized.
325+
@Test
326+
fun `collector keeps choreographer fallback available on version O+`() {
327+
val buildInfo =
328+
mock<BuildInfoProvider> { whenever(it.sdkInfoVersion).thenReturn(Build.VERSION_CODES.O) }
329+
val collector = fixture.getSut(context, buildInfo)
330+
331+
Shadows.shadowOf(Looper.getMainLooper()).idle()
332+
333+
val choreographer = collector.getProperty<Choreographer>("choreographer")
334+
assertNotNull(collector.getProperty<Any?>("choreographerLastFrameTimeField"))
335+
336+
choreographer.injectForField("mLastFrameTimeNanos", 100)
337+
338+
assertEquals(100, collector.getLastKnownFrameStartTimeNanos())
317339
}
318340

319341
@Test
@@ -621,10 +643,6 @@ class SentryFrameMetricsCollectorTest {
621643
// emit a fast frame (21ns cpu time — well under 16ms budget)
622644
listener.onFrameMetricsAvailable(createMockWindow(), createMockFrameMetrics(), 0)
623645

624-
// choreographer is at end of range so no pending delay
625-
val choreographer = collector.getProperty<Choreographer>("choreographer")
626-
choreographer.injectForField("mLastFrameTimeNanos", TimeUnit.SECONDS.toNanos(1))
627-
628646
val result = collector.getFramesDelay(0, TimeUnit.SECONDS.toNanos(1))
629647
assertEquals(0.0, result.delaySeconds)
630648
assertEquals(0, result.framesContributingToDelayCount)
@@ -643,22 +661,23 @@ class SentryFrameMetricsCollectorTest {
643661
// emit a slow frame (~100ms extra = ~116ms total, well over 16ms budget)
644662
listener.onFrameMetricsAvailable(
645663
createMockWindow(),
646-
createMockFrameMetrics(extraCpuDurationNanos = TimeUnit.MILLISECONDS.toNanos(100)),
664+
createMockFrameMetrics(
665+
extraCpuDurationNanos = TimeUnit.MILLISECONDS.toNanos(100),
666+
intendedVsyncTimestampNanos = TimeUnit.SECONDS.toNanos(1),
667+
),
647668
0,
648669
)
649670

650671
// emit a frozen frame (~1000ms extra = ~1016ms total, well over 700ms)
651672
listener.onFrameMetricsAvailable(
652673
createMockWindow(),
653-
createMockFrameMetrics(extraCpuDurationNanos = TimeUnit.MILLISECONDS.toNanos(1000)),
674+
createMockFrameMetrics(
675+
extraCpuDurationNanos = TimeUnit.MILLISECONDS.toNanos(1000),
676+
intendedVsyncTimestampNanos = TimeUnit.SECONDS.toNanos(2),
677+
),
654678
0,
655679
)
656680

657-
// choreographer is at end of range so no pending delay
658-
Shadows.shadowOf(Looper.getMainLooper()).idle()
659-
val choreographer = collector.getProperty<Choreographer>("choreographer")
660-
choreographer.injectForField("mLastFrameTimeNanos", TimeUnit.SECONDS.toNanos(5))
661-
662681
val result = collector.getFramesDelay(0, TimeUnit.SECONDS.toNanos(5))
663682
assertTrue(result.delaySeconds > 0)
664683
assertEquals(2, result.framesContributingToDelayCount)
@@ -681,11 +700,6 @@ class SentryFrameMetricsCollectorTest {
681700
0,
682701
)
683702

684-
// choreographer is at end of range
685-
Shadows.shadowOf(Looper.getMainLooper()).idle()
686-
val choreographer = collector.getProperty<Choreographer>("choreographer")
687-
choreographer.injectForField("mLastFrameTimeNanos", TimeUnit.SECONDS.toNanos(5))
688-
689703
// The frame's delay interval is roughly [~16ms, ~1000ms].
690704
// Query from 500ms so the range clips the delay interval in half.
691705
val queryStart = TimeUnit.MILLISECONDS.toNanos(500)
@@ -708,7 +722,6 @@ class SentryFrameMetricsCollectorTest {
708722
Shadows.shadowOf(Looper.getMainLooper()).idle()
709723
val listener =
710724
collector.getProperty<Window.OnFrameMetricsAvailableListener>("frameMetricsAvailableListener")
711-
val choreographer = collector.getProperty<Choreographer>("choreographer")
712725

713726
collector.startCollection(mock())
714727

@@ -720,8 +733,6 @@ class SentryFrameMetricsCollectorTest {
720733
whenever(frameMetrics1.getMetric(FrameMetrics.INTENDED_VSYNC_TIMESTAMP)).thenReturn(t0)
721734
listener.onFrameMetricsAvailable(createMockWindow(), frameMetrics1, 0)
722735

723-
choreographer.injectForField("mLastFrameTimeNanos", t0 + TimeUnit.SECONDS.toNanos(1))
724-
725736
// verify frame exists
726737
val resultBefore = collector.getFramesDelay(t0, t0 + TimeUnit.SECONDS.toNanos(1))
727738
assertEquals(1, resultBefore.framesContributingToDelayCount)
@@ -734,7 +745,6 @@ class SentryFrameMetricsCollectorTest {
734745
listener.onFrameMetricsAvailable(createMockWindow(), frameMetrics2, 0)
735746

736747
// the first frame should have been pruned (>5min old)
737-
choreographer.injectForField("mLastFrameTimeNanos", t1 + TimeUnit.SECONDS.toNanos(1))
738748
val resultAfter = collector.getFramesDelay(t0, t0 + TimeUnit.SECONDS.toNanos(1))
739749
assertEquals(0, resultAfter.framesContributingToDelayCount)
740750
}
@@ -762,6 +772,7 @@ class SentryFrameMetricsCollectorTest {
762772
syncNanos: Long = 6,
763773
extraCpuDurationNanos: Long = 0,
764774
totalDurationNanos: Long = 60,
775+
intendedVsyncTimestampNanos: Long = 50,
765776
): FrameMetrics {
766777
val frameMetrics = mock<FrameMetrics>()
767778
whenever(frameMetrics.getMetric(FrameMetrics.UNKNOWN_DELAY_DURATION))
@@ -774,7 +785,8 @@ class SentryFrameMetricsCollectorTest {
774785
whenever(frameMetrics.getMetric(FrameMetrics.DRAW_DURATION)).thenReturn(drawNanos)
775786
whenever(frameMetrics.getMetric(FrameMetrics.SYNC_DURATION)).thenReturn(syncNanos)
776787
whenever(frameMetrics.getMetric(FrameMetrics.TOTAL_DURATION)).thenReturn(totalDurationNanos)
777-
whenever(frameMetrics.getMetric(FrameMetrics.INTENDED_VSYNC_TIMESTAMP)).thenReturn(50)
788+
whenever(frameMetrics.getMetric(FrameMetrics.INTENDED_VSYNC_TIMESTAMP))
789+
.thenReturn(intendedVsyncTimestampNanos)
778790
return frameMetrics
779791
}
780792
}

0 commit comments

Comments
 (0)