diff --git a/CHANGELOG.md b/CHANGELOG.md index 70c9f04dee7..8c0e71517d2 100644 --- a/CHANGELOG.md +++ b/CHANGELOG.md @@ -13,6 +13,7 @@ ### Performance +- Defer `Choreographer` reflection for frame metrics collection to avoid blocking the main thread during `Sentry.init` ([#5886](https://github.com/getsentry/sentry-java/pull/5886)) - Avoid waiting up to `shutdownTimeoutMillis` when closing the SDK with a pending transaction timeout or session-end task ([#5851](https://github.com/getsentry/sentry-java/pull/5851)) - 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)) - 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)) diff --git a/sentry-android-core/src/main/java/io/sentry/android/core/internal/util/SentryFrameMetricsCollector.java b/sentry-android-core/src/main/java/io/sentry/android/core/internal/util/SentryFrameMetricsCollector.java index 4f6b486f3a1..2c0ae246558 100644 --- a/sentry-android-core/src/main/java/io/sentry/android/core/internal/util/SentryFrameMetricsCollector.java +++ b/sentry-android-core/src/main/java/io/sentry/android/core/internal/util/SentryFrameMetricsCollector.java @@ -56,8 +56,8 @@ public final class SentryFrameMetricsCollector implements Application.ActivityLi private final WindowFrameMetricsManager windowFrameMetricsManager; private @Nullable Window.OnFrameMetricsAvailableListener frameMetricsAvailableListener; - private @Nullable Choreographer choreographer; - private @Nullable Field choreographerLastFrameTimeField; + private volatile @Nullable Choreographer choreographer; + private volatile @Nullable Field choreographerLastFrameTimeField; private long lastFrameStartNanos = 0; private long lastFrameEndNanos = 0; @@ -126,7 +126,8 @@ public SentryFrameMetricsCollector( // Most considerations regarding timestamps of frames are inspired from JankStats library: // https://cs.android.com/androidx/platform/frameworks/support/+/androidx-main:metrics/metrics-performance/src/main/java/androidx/metrics/performance/JankStatsApi24Impl.kt - // The Choreographer instance must be accessed on the main thread + // The Choreographer instance should be initialized asynchronously on the main thread to avoid + // reflection during SDK init. new Handler(Looper.getMainLooper()) .post( () -> { @@ -138,15 +139,19 @@ public SentryFrameMetricsCollector( "Error retrieving Choreographer instance. Slow and frozen frames will not be reported.", e); } + + // Let's get the last frame timestamp from the choreographer private field + try { + choreographerLastFrameTimeField = + Choreographer.class.getDeclaredField("mLastFrameTimeNanos"); + choreographerLastFrameTimeField.setAccessible(true); + } catch (NoSuchFieldException e) { + logger.log( + SentryLevel.ERROR, + "Unable to get the frame timestamp from the choreographer: ", + e); + } }); - // Let's get the last frame timestamp from the choreographer private field - try { - choreographerLastFrameTimeField = Choreographer.class.getDeclaredField("mLastFrameTimeNanos"); - choreographerLastFrameTimeField.setAccessible(true); - } catch (NoSuchFieldException e) { - logger.log( - SentryLevel.ERROR, "Unable to get the frame timestamp from the choreographer: ", e); - } frameMetricsAvailableListener = (window, frameMetrics, dropCountSinceLastInvocation) -> { @@ -165,7 +170,8 @@ public SentryFrameMetricsCollector( final long delayNanos = Math.max(0, cpuDuration - expectedFrameDuration); long startTime = getFrameStartTimestamp(frameMetrics); - // If we couldn't get the timestamp through reflection, we use current time + // If we couldn't get the timestamp through FrameMetrics or reflection, we use the current + // time. if (startTime < 0) { startTime = now - cpuDuration; } @@ -217,8 +223,8 @@ public static boolean isSlow(long frameDuration, final long expectedFrameDuratio } /** - * Return the internal timestamp in the choreographer of the last frame start timestamp through - * reflection. On Android O the value is read from the frameMetrics itself. + * Return the frame start timestamp. On API 26+, this value is read directly from {@link + * FrameMetrics}; older APIs use the reflected Choreographer timestamp. */ @SuppressLint("NewApi") private long getFrameStartTimestamp(final @NotNull FrameMetrics frameMetrics) { diff --git a/sentry-android-core/src/test/java/io/sentry/android/core/internal/util/SentryFrameMetricsCollectorTest.kt b/sentry-android-core/src/test/java/io/sentry/android/core/internal/util/SentryFrameMetricsCollectorTest.kt index f90c07b70e6..334ce229066 100644 --- a/sentry-android-core/src/test/java/io/sentry/android/core/internal/util/SentryFrameMetricsCollectorTest.kt +++ b/sentry-android-core/src/test/java/io/sentry/android/core/internal/util/SentryFrameMetricsCollectorTest.kt @@ -19,7 +19,6 @@ import io.sentry.test.getCtor import io.sentry.test.getProperty import io.sentry.test.injectForField import java.lang.ref.WeakReference -import java.lang.reflect.Field import java.util.concurrent.TimeUnit import kotlin.test.BeforeTest import kotlin.test.Test @@ -302,18 +301,41 @@ class SentryFrameMetricsCollectorTest { } @Test - fun `collector accesses choreographer instance on creation on main thread`() { + fun `collector accesses choreographer instance and field asynchronously on main thread`() { val collector = fixture.getSut(context) - val field: Field? = collector.getProperty("choreographerLastFrameTimeField") + + val field: Any? = collector.getProperty("choreographerLastFrameTimeField") var choreographer: Choreographer? = collector.getProperty("choreographer") - // Choreographer instance is accessed on main thread, but the field accessor happens in whatever - // thread created the collector - assertNotNull(field) + assertNull(choreographer) + assertNull(field) + // Execute all posted tasks Shadows.shadowOf(Looper.getMainLooper()).idle() choreographer = collector.getProperty("choreographer") assertNotNull(choreographer) + assertNotNull(collector.getProperty("choreographerLastFrameTimeField")) + } + + // Frame callbacks on API 26+ read their per-frame start timestamp directly from FrameMetrics, + // which can make the Choreographer fallback look like it should be specific to APIs < 26. + // But SpanFrameMetricsCollector separately calls getLastKnownFrameStartTimeNanos() on every + // API level for pending-frame interpolation, so API 26+ still needs the Choreographer + // fallback to be initialized. + @Test + fun `collector keeps choreographer fallback available on version O+`() { + val buildInfo = + mock { whenever(it.sdkInfoVersion).thenReturn(Build.VERSION_CODES.O) } + val collector = fixture.getSut(context, buildInfo) + + Shadows.shadowOf(Looper.getMainLooper()).idle() + + val choreographer = collector.getProperty("choreographer") + assertNotNull(collector.getProperty("choreographerLastFrameTimeField")) + + choreographer.injectForField("mLastFrameTimeNanos", 100) + + assertEquals(100, collector.getLastKnownFrameStartTimeNanos()) } @Test @@ -621,10 +643,6 @@ class SentryFrameMetricsCollectorTest { // emit a fast frame (21ns cpu time — well under 16ms budget) listener.onFrameMetricsAvailable(createMockWindow(), createMockFrameMetrics(), 0) - // choreographer is at end of range so no pending delay - val choreographer = collector.getProperty("choreographer") - choreographer.injectForField("mLastFrameTimeNanos", TimeUnit.SECONDS.toNanos(1)) - val result = collector.getFramesDelay(0, TimeUnit.SECONDS.toNanos(1)) assertEquals(0.0, result.delaySeconds) assertEquals(0, result.framesContributingToDelayCount) @@ -643,22 +661,23 @@ class SentryFrameMetricsCollectorTest { // emit a slow frame (~100ms extra = ~116ms total, well over 16ms budget) listener.onFrameMetricsAvailable( createMockWindow(), - createMockFrameMetrics(extraCpuDurationNanos = TimeUnit.MILLISECONDS.toNanos(100)), + createMockFrameMetrics( + extraCpuDurationNanos = TimeUnit.MILLISECONDS.toNanos(100), + intendedVsyncTimestampNanos = TimeUnit.SECONDS.toNanos(1), + ), 0, ) // emit a frozen frame (~1000ms extra = ~1016ms total, well over 700ms) listener.onFrameMetricsAvailable( createMockWindow(), - createMockFrameMetrics(extraCpuDurationNanos = TimeUnit.MILLISECONDS.toNanos(1000)), + createMockFrameMetrics( + extraCpuDurationNanos = TimeUnit.MILLISECONDS.toNanos(1000), + intendedVsyncTimestampNanos = TimeUnit.SECONDS.toNanos(2), + ), 0, ) - // choreographer is at end of range so no pending delay - Shadows.shadowOf(Looper.getMainLooper()).idle() - val choreographer = collector.getProperty("choreographer") - choreographer.injectForField("mLastFrameTimeNanos", TimeUnit.SECONDS.toNanos(5)) - val result = collector.getFramesDelay(0, TimeUnit.SECONDS.toNanos(5)) assertTrue(result.delaySeconds > 0) assertEquals(2, result.framesContributingToDelayCount) @@ -681,11 +700,6 @@ class SentryFrameMetricsCollectorTest { 0, ) - // choreographer is at end of range - Shadows.shadowOf(Looper.getMainLooper()).idle() - val choreographer = collector.getProperty("choreographer") - choreographer.injectForField("mLastFrameTimeNanos", TimeUnit.SECONDS.toNanos(5)) - // The frame's delay interval is roughly [~16ms, ~1000ms]. // Query from 500ms so the range clips the delay interval in half. val queryStart = TimeUnit.MILLISECONDS.toNanos(500) @@ -708,7 +722,6 @@ class SentryFrameMetricsCollectorTest { Shadows.shadowOf(Looper.getMainLooper()).idle() val listener = collector.getProperty("frameMetricsAvailableListener") - val choreographer = collector.getProperty("choreographer") collector.startCollection(mock()) @@ -720,8 +733,6 @@ class SentryFrameMetricsCollectorTest { whenever(frameMetrics1.getMetric(FrameMetrics.INTENDED_VSYNC_TIMESTAMP)).thenReturn(t0) listener.onFrameMetricsAvailable(createMockWindow(), frameMetrics1, 0) - choreographer.injectForField("mLastFrameTimeNanos", t0 + TimeUnit.SECONDS.toNanos(1)) - // verify frame exists val resultBefore = collector.getFramesDelay(t0, t0 + TimeUnit.SECONDS.toNanos(1)) assertEquals(1, resultBefore.framesContributingToDelayCount) @@ -734,7 +745,6 @@ class SentryFrameMetricsCollectorTest { listener.onFrameMetricsAvailable(createMockWindow(), frameMetrics2, 0) // the first frame should have been pruned (>5min old) - choreographer.injectForField("mLastFrameTimeNanos", t1 + TimeUnit.SECONDS.toNanos(1)) val resultAfter = collector.getFramesDelay(t0, t0 + TimeUnit.SECONDS.toNanos(1)) assertEquals(0, resultAfter.framesContributingToDelayCount) } @@ -762,6 +772,7 @@ class SentryFrameMetricsCollectorTest { syncNanos: Long = 6, extraCpuDurationNanos: Long = 0, totalDurationNanos: Long = 60, + intendedVsyncTimestampNanos: Long = 50, ): FrameMetrics { val frameMetrics = mock() whenever(frameMetrics.getMetric(FrameMetrics.UNKNOWN_DELAY_DURATION)) @@ -774,7 +785,8 @@ class SentryFrameMetricsCollectorTest { whenever(frameMetrics.getMetric(FrameMetrics.DRAW_DURATION)).thenReturn(drawNanos) whenever(frameMetrics.getMetric(FrameMetrics.SYNC_DURATION)).thenReturn(syncNanos) whenever(frameMetrics.getMetric(FrameMetrics.TOTAL_DURATION)).thenReturn(totalDurationNanos) - whenever(frameMetrics.getMetric(FrameMetrics.INTENDED_VSYNC_TIMESTAMP)).thenReturn(50) + whenever(frameMetrics.getMetric(FrameMetrics.INTENDED_VSYNC_TIMESTAMP)) + .thenReturn(intendedVsyncTimestampNanos) return frameMetrics } }