diff --git a/firebase-perf/CHANGELOG.md b/firebase-perf/CHANGELOG.md index b4db8bb6bc4..4954be336b5 100644 --- a/firebase-perf/CHANGELOG.md +++ b/firebase-perf/CHANGELOG.md @@ -1,5 +1,6 @@ # Unreleased * [fixed] Fixed an ANR on app launch. [#4831] +* [fixed] Fixed app start traces on API 34+. [#5920] # 22.0.0 * [changed] **Breaking Change**: Updated minSdkVersion to API level 23 or higher. diff --git a/firebase-perf/src/main/java/com/google/firebase/perf/metrics/AppStartTrace.java b/firebase-perf/src/main/java/com/google/firebase/perf/metrics/AppStartTrace.java index 7574f989d92..1c22e74e900 100644 --- a/firebase-perf/src/main/java/com/google/firebase/perf/metrics/AppStartTrace.java +++ b/firebase-perf/src/main/java/com/google/firebase/perf/metrics/AppStartTrace.java @@ -75,6 +75,10 @@ public class AppStartTrace implements ActivityLifecycleCallbacks, LifecycleObser private static final @NonNull Timer PERF_CLASS_LOAD_TIME = new Clock().getTime(); private static final long MAX_LATENCY_BEFORE_UI_INIT = TimeUnit.MINUTES.toMicros(1); + // If the `mainThreadRunnableTime` was set within this duration, the assumption + // is that it was called immediately before `onActivityCreated` in foreground starts on API 34+. + private static final long MAX_BACKGROUND_RUNNABLE_DELAY = TimeUnit.MILLISECONDS.toMicros(100); + // Core pool size 0 allows threads to shut down if they're idle private static final int CORE_POOL_SIZE = 0; private static final int MAX_POOL_SIZE = 1; // Only need single thread @@ -111,6 +115,8 @@ public class AppStartTrace implements ActivityLifecycleCallbacks, LifecycleObser private final @Nullable Timer processStartTime; private final @Nullable Timer firebaseClassLoadTime; private Timer onCreateTime = null; + + private Timer mainThreadRunnableTime = null; private Timer onStartTime = null; private Timer onResumeTime = null; private Timer firstForegroundTime = null; @@ -319,8 +325,44 @@ private void recordOnDrawFrontOfQueue() { logExperimentTrace(this.experimentTtid); } + /** + * Sets the `isStartedFromBackground` flag to `true` if the `mainThreadRunnableTime` was set + * from the `StartFromBackgroundRunnable`. + *
+ * If it's prior to API 34, it's always set to true if `mainThreadRunnableTime` was set. + *
+ * If it's on or after API 34, and it was called less than `MAX_BACKGROUND_RUNNABLE_DELAY` + * before `onActivityCreated`, the + * assumption is that it was called immediately before the activity lifecycle callbacks in a + * foreground start. + * See https://github.com/firebase/firebase-android-sdk/issues/5920. + */ + private void resolveIsStartedFromBackground() { + // If the mainThreadRunnableTime is null, either the runnable hasn't run, or this check has + // already been made. + if (mainThreadRunnableTime == null) { + return; + } + + // If the `mainThreadRunnableTime` was set prior to API 34, it's always assumed that's it's + // a background start. + // Otherwise it's assumed to be a background start if the runnable was set more than + // `MAX_BACKGROUND_RUNNABLE_DELAY` + // before the first `onActivityCreated` call. + // TODO(b/339891952): Investigate removing the API check, and setting a more precise delay. + if ((Build.VERSION.SDK_INT < 34) + || (mainThreadRunnableTime.getDurationMicros() > MAX_BACKGROUND_RUNNABLE_DELAY)) { + isStartedFromBackground = true; + } + + // Set this to null to prevent additional checks. + mainThreadRunnableTime = null; + } + @Override public synchronized void onActivityCreated(Activity activity, Bundle savedInstanceState) { + resolveIsStartedFromBackground(); + if (isStartedFromBackground || onCreateTime != null // An activity already called onCreate() ) { return; @@ -559,9 +601,9 @@ public static boolean isScreenOn(Context appContext) { /** * We use StartFromBackgroundRunnable to detect if app is started from background or foreground. * If app is started from background, we do not generate AppStart trace. This runnable is posted - * to main UI thread from FirebasePerfEarly. If app is started from background, this runnable will - * be executed before any activity's onCreate() method. If app is started from foreground, - * activity's onCreate() method is executed before this runnable. + * to main UI thread from FirebasePerfEarly. If `onActivityCreate` has never been called, we + * record the timestamp - which allows `onActivityCreate` to determine whether it was a background + * app start or not. */ public static class StartFromBackgroundRunnable implements Runnable { private final AppStartTrace trace; @@ -572,9 +614,9 @@ public StartFromBackgroundRunnable(final AppStartTrace trace) { @Override public void run() { - // if no activity has ever been created. + // Only set the `mainThreadRunnableTime` if `onActivityCreate` has never been called. if (trace.onCreateTime == null) { - trace.isStartedFromBackground = true; + trace.mainThreadRunnableTime = new Timer(); } } } @@ -614,7 +656,7 @@ Timer getOnResumeTime() { } @VisibleForTesting - void setIsStartFromBackground() { - isStartedFromBackground = true; + void setMainThreadRunnableTime(Timer timer) { + mainThreadRunnableTime = timer; } } diff --git a/firebase-perf/src/test/java/com/google/firebase/perf/metrics/AppStartTraceTest.java b/firebase-perf/src/test/java/com/google/firebase/perf/metrics/AppStartTraceTest.java index 36ae3d10116..25ad845231a 100644 --- a/firebase-perf/src/test/java/com/google/firebase/perf/metrics/AppStartTraceTest.java +++ b/firebase-perf/src/test/java/com/google/firebase/perf/metrics/AppStartTraceTest.java @@ -18,6 +18,7 @@ import static org.mockito.ArgumentMatchers.isA; import static org.mockito.Mockito.doAnswer; import static org.mockito.Mockito.mock; +import static org.mockito.Mockito.spy; import static org.mockito.Mockito.times; import static org.mockito.Mockito.verify; import static org.mockito.Mockito.when; @@ -238,11 +239,42 @@ public void testDelayedAppStart() { } @Test - public void testStartFromBackground() { + public void testStartFromBackground_within100ms() { FakeScheduledExecutorService fakeExecutorService = new FakeScheduledExecutorService(); + Timer fakeTimer = spy(new Timer(currentTime)); AppStartTrace trace = new AppStartTrace(transportManager, clock, configResolver, fakeExecutorService); - trace.setIsStartFromBackground(); + trace.registerActivityLifecycleCallbacks(appContext); + trace.setMainThreadRunnableTime(fakeTimer); + + when(fakeTimer.getDurationMicros()).thenReturn(99L); + trace.onActivityCreated(activity1, bundle); + Assert.assertNotNull(trace.getOnCreateTime()); + ++currentTime; + trace.onActivityStarted(activity1); + Assert.assertNotNull(trace.getOnStartTime()); + ++currentTime; + trace.onActivityResumed(activity1); + Assert.assertNotNull(trace.getOnResumeTime()); + fakeExecutorService.runAll(); + // There should be a trace sent since the delay between the main thread and onActivityCreated + // is limited. + verify(transportManager, times(1)) + .log( + traceArgumentCaptor.capture(), + ArgumentMatchers.nullable(ApplicationProcessState.class)); + } + + @Test + public void testStartFromBackground_moreThan100ms() { + FakeScheduledExecutorService fakeExecutorService = new FakeScheduledExecutorService(); + Timer fakeTimer = spy(new Timer(currentTime)); + AppStartTrace trace = + new AppStartTrace(transportManager, clock, configResolver, fakeExecutorService); + trace.registerActivityLifecycleCallbacks(appContext); + trace.setMainThreadRunnableTime(fakeTimer); + + when(fakeTimer.getDurationMicros()).thenReturn(TimeUnit.MILLISECONDS.toMicros(100) + 1); trace.onActivityCreated(activity1, bundle); Assert.assertNull(trace.getOnCreateTime()); ++currentTime; @@ -252,6 +284,7 @@ public void testStartFromBackground() { trace.onActivityResumed(activity1); Assert.assertNull(trace.getOnResumeTime()); // There should be no trace sent. + fakeExecutorService.runAll(); verify(transportManager, times(0)) .log( traceArgumentCaptor.capture(),