From b8f20ead8ace2bfa02c20b99a75dce4efdb0b59b Mon Sep 17 00:00:00 2001 From: Joseph Rodiz Date: Wed, 20 May 2026 01:21:16 -0600 Subject: [PATCH 1/2] firebase-perf: widen background-start timing window to 1000ms (#8103) The API-34 fix in 22.0.2 (PR #7281) used a 50 ms MAX_BACKGROUND_RUNNABLE_DELAY to tell cold foreground starts from genuine background starts. That threshold was calibrated against a near-empty test app on API 35, where the gap between StartFromBackgroundRunnable firing and the first onActivityCreated was ~10 ms. On API 34+ physical devices, the gap is dominated by Android's main-thread vs Binder scheduling, not by app work: - 316 ms on a minimal ContentProvider repro (issue #5920, PhilGlass). - 204 ms on a large production app (issue #8103, manavchandrakar29011994). 50 ms is well below both, so _app_start is unconditionally suppressed for typical real-world apps on the very devices the fix was meant to support. Bump MAX_BACKGROUND_RUNNABLE_DELAY to 1000 ms. The mechanism (timing window) and the warm-start guard introduced in PR #7281 (mainThreadRunnableTime is only set when onCreateTime == null) are unchanged. Genuine warm starts where the process was forked for background work seconds-to-minutes before any activity launch are still suppressed, since their gap far exceeds 1000 ms and MAX_LATENCY_BEFORE_UI_INIT (60 s) remains the upper backstop. Tests: - Rename the existing 50 ms tests to _within1000ms / _moreThan1000ms. - Add testStartFromBackground_largeAppGap_isForegroundStart: ~300 ms gap on API 34 now logs the trace (regression-locks #8103). - Add testStartFromBackground_warmStart_stillSuppressed: 10 s gap is still suppressed. --- firebase-perf/CHANGELOG.md | 4 ++ .../firebase/perf/metrics/AppStartTrace.java | 15 ++++- .../perf/metrics/AppStartTraceTest.java | 65 +++++++++++++++++-- 3 files changed, 78 insertions(+), 6 deletions(-) diff --git a/firebase-perf/CHANGELOG.md b/firebase-perf/CHANGELOG.md index fd06467ade2..5ff802164c1 100644 --- a/firebase-perf/CHANGELOG.md +++ b/firebase-perf/CHANGELOG.md @@ -1,5 +1,9 @@ # Unreleased +- [fixed] Fixed `_app_start` traces being suppressed on API 34+ devices for typical + real-world apps by widening the foreground/background-start timing window to account + for Android's main-thread vs Binder scheduling on physical devices. [#8103] + # 22.0.5 - [changed] Bumped internal dependencies. 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 813c8988383..9d1891e9a5e 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 @@ -76,8 +76,19 @@ public class AppStartTrace implements ActivityLifecycleCallbacks, LifecycleObser // If the `mainThreadRunnableTime` was set within this duration, the assumption // is that it was called immediately before `onActivityCreated` in foreground starts on API 34+. - // See b/339891952. - private static final long MAX_BACKGROUND_RUNNABLE_DELAY = TimeUnit.MILLISECONDS.toMicros(50); + // + // On API 34+, Android may drain posted main-thread runnables before processing the + // Activity-launch Binder transaction even during a genuine cold foreground start. The + // resulting gap between `StartFromBackgroundRunnable` firing and the first + // `onActivityCreated` is dominated by system scheduling, not by app work, and has been + // measured at ~316ms on a minimal repro app and ~204ms on a large production app on + // physical Pixel devices. The threshold must therefore comfortably exceed these + // real-world gaps; 1000ms provides ~5x headroom over the worst measured cold-start gap + // while still being two orders of magnitude below `MAX_LATENCY_BEFORE_UI_INIT` so that + // genuine warm starts (where the process was forked for background work seconds-to- + // minutes before any activity launch) remain correctly suppressed. + // See b/339891952 and https://github.com/firebase/firebase-android-sdk/issues/8103. + private static final long MAX_BACKGROUND_RUNNABLE_DELAY = TimeUnit.MILLISECONDS.toMicros(1000); // Core pool size 0 allows threads to shut down if they're idle private static final int CORE_POOL_SIZE = 0; 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 daa80ad29a2..715b1a11d0f 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 @@ -239,7 +239,7 @@ public void testDelayedAppStart() { } @Test - public void testStartFromBackground_within50ms() { + public void testStartFromBackground_within1000ms() { FakeScheduledExecutorService fakeExecutorService = new FakeScheduledExecutorService(); Timer fakeTimer = spy(new Timer(currentTime)); AppStartTrace trace = @@ -248,7 +248,7 @@ public void testStartFromBackground_within50ms() { trace.setMainThreadRunnableTime(fakeTimer); // See AppStartTrace.MAX_BACKGROUND_RUNNABLE_DELAY. - when(fakeTimer.getDurationMicros()).thenReturn(TimeUnit.MILLISECONDS.toMicros(50) - 1); + when(fakeTimer.getDurationMicros()).thenReturn(TimeUnit.MILLISECONDS.toMicros(1000) - 1); trace.onActivityCreated(activity1, bundle); Assert.assertNotNull(trace.getOnCreateTime()); ++currentTime; @@ -267,7 +267,7 @@ public void testStartFromBackground_within50ms() { } @Test - public void testStartFromBackground_moreThan50ms() { + public void testStartFromBackground_moreThan1000ms() { FakeScheduledExecutorService fakeExecutorService = new FakeScheduledExecutorService(); Timer fakeTimer = spy(new Timer(currentTime)); AppStartTrace trace = @@ -276,7 +276,7 @@ public void testStartFromBackground_moreThan50ms() { trace.setMainThreadRunnableTime(fakeTimer); // See AppStartTrace.MAX_BACKGROUND_RUNNABLE_DELAY. - when(fakeTimer.getDurationMicros()).thenReturn(TimeUnit.MILLISECONDS.toMicros(50) + 1); + when(fakeTimer.getDurationMicros()).thenReturn(TimeUnit.MILLISECONDS.toMicros(1000) + 1); trace.onActivityCreated(activity1, bundle); Assert.assertNull(trace.getOnCreateTime()); ++currentTime; @@ -293,6 +293,63 @@ public void testStartFromBackground_moreThan50ms() { ArgumentMatchers.nullable(ApplicationProcessState.class)); } + // Regression test for https://github.com/firebase/firebase-android-sdk/issues/8103. + // On API 34+ physical devices, the gap between StartFromBackgroundRunnable firing and the + // first onActivityCreated has been measured at ~204-316ms on real apps; the previous 50ms + // threshold misclassified these as background starts and suppressed _app_start traces. + @Test + public void testStartFromBackground_largeAppGap_isForegroundStart() { + FakeScheduledExecutorService fakeExecutorService = new FakeScheduledExecutorService(); + Timer fakeTimer = spy(new Timer(currentTime)); + AppStartTrace trace = + new AppStartTrace(transportManager, clock, configResolver, fakeExecutorService); + trace.registerActivityLifecycleCallbacks(appContext); + trace.setMainThreadRunnableTime(fakeTimer); + + // Simulates the API 34+ scheduling gap observed in real-world apps. + when(fakeTimer.getDurationMicros()).thenReturn(TimeUnit.MILLISECONDS.toMicros(300)); + 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(); + verify(transportManager, times(1)) + .log( + traceArgumentCaptor.capture(), + ArgumentMatchers.nullable(ApplicationProcessState.class)); + } + + // Genuine warm starts (process alive for background work, activity launched seconds later) + // must still be classified as background and suppressed. + @Test + public void testStartFromBackground_warmStart_stillSuppressed() { + 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.SECONDS.toMicros(10)); + trace.onActivityCreated(activity1, bundle); + Assert.assertNull(trace.getOnCreateTime()); + ++currentTime; + trace.onActivityStarted(activity1); + Assert.assertNull(trace.getOnStartTime()); + ++currentTime; + trace.onActivityResumed(activity1); + Assert.assertNull(trace.getOnResumeTime()); + fakeExecutorService.runAll(); + verify(transportManager, times(0)) + .log( + traceArgumentCaptor.capture(), + ArgumentMatchers.nullable(ApplicationProcessState.class)); + } + @Test @Config(sdk = 26) public void timeToInitialDisplay_isLogged() { From c872d8e4261dbeee5f928ee2e463d149c5a40683 Mon Sep 17 00:00:00 2001 From: Joseph Rodiz Date: Wed, 20 May 2026 11:23:42 -0600 Subject: [PATCH 2/2] firebase-perf: TODO pointing at causal-signal alternatives for app-start detection The timing-window heuristic in resolveIsStartedFromBackground() infers "was this process forked to launch an Activity?" from the ordering of a posted runnable vs the first onActivityCreated callback. That ordering already shifted once on API 34+ (caused the original bug fixed in PR #7281, and the threshold-too-tight follow-up in #8103) and could shift again on future OS versions. Add a TODO documenting two cleaner alternatives so the next maintainer doesn't have to re-derive them: - API 35+: ApplicationStartInfo / getHistoricalProcessStartReasons gives the OS's authoritative start reason (LAUNCHER, SERVICE, CONTENT_PROVIDER, ...). Removes the heuristic entirely on supported devices. - API 34: RunningAppProcessInfo.importanceReasonCode + .importance captured early in FirebasePerfEarly (before our own ContentProvider work mutates the cause), combined with the timing window as a fallback. Comment-only change; no behavior or test surface affected. --- .../firebase/perf/metrics/AppStartTrace.java | 20 ++++++++++++++++++- 1 file changed, 19 insertions(+), 1 deletion(-) 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 9d1891e9a5e..652cbd71a55 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 @@ -347,7 +347,25 @@ private void recordOnDrawFrontOfQueue() { * before `onActivityCreated`, the * assumption is that it was called immediately before the activity lifecycle callbacks in a * foreground start. - * See b/339891952. + * See b/339891952 and https://github.com/firebase/firebase-android-sdk/issues/8103. + * + *

TODO(b/339891952): Replace this timing-window heuristic with a causal signal. + * The current approach infers "was the process forked to launch an Activity?" from the + * ordering of a posted runnable vs the first onActivityCreated callback, which is + * inherently fragile (its calibration depends on Android scheduling behavior that has + * already shifted once on API 34+ and could shift again). Better candidates: + *

+ * Adopting either of these would also let the API-34-vs-pre-34 branch below collapse. */ private void resolveIsStartedFromBackground() { // If the mainThreadRunnableTime is null, either the runnable hasn't run, or this check has