From e19fd90230c2aa2709ad6f9f611f07031848548d Mon Sep 17 00:00:00 2001 From: Leo Zhan Date: Wed, 2 Nov 2022 18:53:12 -0700 Subject: [PATCH 01/11] predraw and uptimeMillis --- .../firebase/perf/metrics/AppStartTrace.java | 39 ++++++++++++++++++- .../perf/util/FirstDrawDoneListener.java | 5 +-- .../firebase/perf/util/PreDrawListener.java | 38 ++++++++++++++++++ .../com/google/firebase/perf/util/Timer.java | 34 +++++++++++++--- .../google/firebase/perf/util/TimerTest.java | 18 ++++----- 5 files changed, 113 insertions(+), 21 deletions(-) create mode 100644 firebase-perf/src/main/java/com/google/firebase/perf/util/PreDrawListener.java 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 2e1bb5cd8d3..ffc03e2ee5a 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 @@ -35,6 +35,7 @@ import com.google.firebase.perf.util.Clock; import com.google.firebase.perf.util.Constants; import com.google.firebase.perf.util.FirstDrawDoneListener; +import com.google.firebase.perf.util.PreDrawListener; import com.google.firebase.perf.util.Timer; import com.google.firebase.perf.v1.ApplicationProcessState; import com.google.firebase.perf.v1.TraceMetric; @@ -96,6 +97,8 @@ public class AppStartTrace implements ActivityLifecycleCallbacks { private Timer onStartTime = null; private Timer onResumeTime = null; private Timer firstDrawDone = null; + private Timer preDraw = null; + private List preDrawSubtraces = new ArrayList<>(); private PerfSession startSession; private boolean isStartedFromBackground = false; @@ -196,7 +199,8 @@ public synchronized void unregisterActivityLifecycleCallbacks() { */ private static Timer getStartTimer() { if (Build.VERSION.SDK_INT >= Build.VERSION_CODES.N) { - return Timer.ofElapsedRealtime(Process.getStartElapsedRealtime()); + return Timer.ofElapsedRealtime( + Process.getStartElapsedRealtime(), Process.getStartUptimeMillis()); } return FirebasePerfProvider.getAppStartTime(); } @@ -215,6 +219,27 @@ private void recordFirstDrawDone() { } } + private void recordFirstDrawDonePreDraw() { + if (preDraw != null) { + return; + } + Timer start = getStartTimer(); + this.preDraw = clock.getTime(); + TraceMetric.Builder subtrace = + TraceMetric.newBuilder() + .setName("_experiment_preDraw") + .setClientStartTimeUs(start.getMicros()) + .setDurationUs(start.getDurationMicros(this.preDraw)); + preDrawSubtraces.add(subtrace.build()); + + subtrace = TraceMetric.newBuilder(); + subtrace + .setName("_experiment_preDraw_uptimeMillis") + .setClientStartTimeUs(start.getMicros()) + .setDurationUs(start.getDurationUptimeMicros(this.preDraw)); + preDrawSubtraces.add(subtrace.build()); + } + @Override public synchronized void onActivityCreated(Activity activity, Bundle savedInstanceState) { if (isStartedFromBackground || onCreateTime != null // An activity already called onCreate() @@ -252,6 +277,7 @@ public synchronized void onActivityResumed(Activity activity) { if (isExperimentTTIDEnabled) { View rootView = activity.findViewById(android.R.id.content); FirstDrawDoneListener.registerForNextDraw(rootView, this::recordFirstDrawDone); + PreDrawListener.registerForNextDraw(rootView, this::recordFirstDrawDonePreDraw); } if (onResumeTime != null) { // An activity already called onResume() @@ -286,15 +312,24 @@ private void logColdStart(Timer start, Timer end, PerfSession session) { .setName("_experiment_app_start_ttid") .setClientStartTimeUs(start.getMicros()) .setDurationUs(start.getDurationMicros(end)); + List subtraces = new ArrayList<>(); TraceMetric.Builder subtrace = TraceMetric.newBuilder() .setName("_experiment_classLoadTime") .setClientStartTimeUs(FirebasePerfProvider.getAppStartTime().getMicros()) .setDurationUs(FirebasePerfProvider.getAppStartTime().getDurationMicros(end)); + subtraces.add(subtrace.build()); - metric.addSubtraces(subtrace).addPerfSessions(this.startSession.build()); + subtrace = TraceMetric.newBuilder(); + subtrace + .setName("_experiment_uptimeMillis") + .setClientStartTimeUs(start.getMicros()) + .setDurationUs(start.getDurationUptimeMicros(end)); + subtraces.add(subtrace.build()); + subtraces.addAll(preDrawSubtraces); + metric.addAllSubtraces(subtraces).addPerfSessions(this.startSession.build()); transportManager.log(metric.build(), ApplicationProcessState.FOREGROUND_BACKGROUND); } diff --git a/firebase-perf/src/main/java/com/google/firebase/perf/util/FirstDrawDoneListener.java b/firebase-perf/src/main/java/com/google/firebase/perf/util/FirstDrawDoneListener.java index 740278ad4a4..37416398dcb 100644 --- a/firebase-perf/src/main/java/com/google/firebase/perf/util/FirstDrawDoneListener.java +++ b/firebase-perf/src/main/java/com/google/firebase/perf/util/FirstDrawDoneListener.java @@ -23,10 +23,7 @@ /** * OnDrawListener that unregisters itself and invokes callback when the next draw is done. This API - * 16+ implementation is an approximation of the initial display time. {@link - * android.view.Choreographer#postFrameCallback} is an Android API that provides a simpler and more - * accurate initial display time, but it was bugged before API 30, hence we use this backported - * implementation. + * 16+ implementation is an approximation of the initial-display-time defined by Android Vitals. */ @RequiresApi(Build.VERSION_CODES.JELLY_BEAN) public class FirstDrawDoneListener implements ViewTreeObserver.OnDrawListener { diff --git a/firebase-perf/src/main/java/com/google/firebase/perf/util/PreDrawListener.java b/firebase-perf/src/main/java/com/google/firebase/perf/util/PreDrawListener.java new file mode 100644 index 00000000000..8b3b47a3ad3 --- /dev/null +++ b/firebase-perf/src/main/java/com/google/firebase/perf/util/PreDrawListener.java @@ -0,0 +1,38 @@ +package com.google.firebase.perf.util; + +import android.os.Handler; +import android.os.Looper; +import android.view.View; +import android.view.ViewTreeObserver; +import java.util.concurrent.atomic.AtomicReference; + +public class PreDrawListener implements ViewTreeObserver.OnPreDrawListener { + private final Handler mainThreadHandler = new Handler(Looper.getMainLooper()); + private final AtomicReference viewReference; + private final Runnable callback; + + /** Registers a post-draw callback for the next draw of a view. */ + public static void registerForNextDraw(View view, Runnable drawDoneCallback) { + final PreDrawListener listener = new PreDrawListener(view, drawDoneCallback); + view.getViewTreeObserver().addOnPreDrawListener(listener); + } + + private PreDrawListener(View view, Runnable callback) { + this.viewReference = new AtomicReference<>(view); + this.callback = callback; + } + + @Override + public boolean onPreDraw() { + // Set viewReference to null so any onDraw past the first is a no-op + View view = viewReference.getAndSet(null); + if (view == null) { + return true; + } + // OnDrawListeners cannot be removed within onDraw, so we remove it with a + // GlobalLayoutListener + view.getViewTreeObserver().removeOnPreDrawListener(this); + mainThreadHandler.post(callback); + return true; + } +} diff --git a/firebase-perf/src/main/java/com/google/firebase/perf/util/Timer.java b/firebase-perf/src/main/java/com/google/firebase/perf/util/Timer.java index 5ab5539e832..029bbb12890 100644 --- a/firebase-perf/src/main/java/com/google/firebase/perf/util/Timer.java +++ b/firebase-perf/src/main/java/com/google/firebase/perf/util/Timer.java @@ -43,6 +43,11 @@ public class Timer implements Parcelable { * compute duration between 2 timestamps in the same timebase. It is NOT wall-clock time. */ private long elapsedRealtimeMicros; + /** + * Monotonic time measured in the {@link SystemClock#uptimeMillis()} timebase. Only used to + * compute duration between 2 timestamps in the same timebase. It is NOT wall-clock time. + */ + private long uptimeMicros; /** * Returns a new Timer object as if it was stamped at the given elapsedRealtime. Uses current @@ -50,10 +55,11 @@ public class Timer implements Parcelable { * * @param elapsedRealtimeMillis timestamp in the {@link SystemClock#elapsedRealtime()} timebase */ - public static Timer ofElapsedRealtime(final long elapsedRealtimeMillis) { + public static Timer ofElapsedRealtime(final long elapsedRealtimeMillis, final long uptimeMillis) { + long uptimeMicros = MILLISECONDS.toMicros(uptimeMillis); long elapsedRealtimeMicros = MILLISECONDS.toMicros(elapsedRealtimeMillis); long wallClockMicros = wallClockMicros() + (elapsedRealtimeMicros - elapsedRealtimeMicros()); - return new Timer(wallClockMicros, elapsedRealtimeMicros); + return new Timer(wallClockMicros, elapsedRealtimeMicros, uptimeMicros); } /** @@ -77,10 +83,14 @@ private static long elapsedRealtimeMicros() { return MILLISECONDS.toMicros(SystemClock.elapsedRealtime()); } + private static long uptimeMicros() { + return MILLISECONDS.toMicros(SystemClock.uptimeMillis()); + } + // TODO: make all constructors private, use public static factory methods, per Effective Java /** Construct Timer object using System clock. */ public Timer() { - this(wallClockMicros(), elapsedRealtimeMicros()); + this(wallClockMicros(), elapsedRealtimeMicros(), uptimeMicros()); } /** @@ -91,9 +101,10 @@ public Timer() { * SystemClock#elapsedRealtime()} timebase */ @VisibleForTesting - Timer(long epochMicros, long elapsedRealtimeMicros) { + Timer(long epochMicros, long elapsedRealtimeMicros, long uptimeMicros) { this.wallClockMicros = epochMicros; this.elapsedRealtimeMicros = elapsedRealtimeMicros; + this.uptimeMicros = uptimeMicros; } /** @@ -104,11 +115,11 @@ public Timer() { */ @VisibleForTesting public Timer(long testTime) { - this(testTime, testTime); + this(testTime, testTime, testTime); } private Timer(Parcel in) { - this(in.readLong(), in.readLong()); + this(in.readLong(), in.readLong(), in.readLong()); } /** resets the start time */ @@ -144,6 +155,16 @@ public long getDurationMicros(@NonNull final Timer end) { return end.elapsedRealtimeMicros - this.elapsedRealtimeMicros; } + /** + * Calculate duration in microseconds using uptime. The start time is this Timer object. + * + * @param end end Timer object + * @return duration in microseconds. + */ + public long getDurationUptimeMicros(@NonNull final Timer end) { + return end.uptimeMicros - this.uptimeMicros; + } + /** * Calculates the current wall clock off the existing wall clock time. The reason this is better * instead of just doing System.getCurrentTimeMillis is that the device time could've changed @@ -166,6 +187,7 @@ public long getCurrentTimestampMicros() { public void writeToParcel(Parcel out, int flags) { out.writeLong(wallClockMicros); out.writeLong(elapsedRealtimeMicros); + out.writeLong(uptimeMicros); } /** diff --git a/firebase-perf/src/test/java/com/google/firebase/perf/util/TimerTest.java b/firebase-perf/src/test/java/com/google/firebase/perf/util/TimerTest.java index e8031b53577..c844bce04eb 100644 --- a/firebase-perf/src/test/java/com/google/firebase/perf/util/TimerTest.java +++ b/firebase-perf/src/test/java/com/google/firebase/perf/util/TimerTest.java @@ -53,8 +53,8 @@ public void ofElapsedRealtime_createsNewTimerWithArgumentElapsedRealtime() { // Robolectric shadows SystemClock, which is paused and can only change via specific methods. long refElapsedRealtime = SystemClock.elapsedRealtime(); Timer ref = new Timer(); - Timer past = Timer.ofElapsedRealtime(refElapsedRealtime - 100); - Timer future = Timer.ofElapsedRealtime(refElapsedRealtime + 100); + Timer past = Timer.ofElapsedRealtime(refElapsedRealtime - 100, 0); + Timer future = Timer.ofElapsedRealtime(refElapsedRealtime + 100, 0); assertThat(past.getDurationMicros(ref)).isEqualTo(MILLISECONDS.toMicros(100)); assertThat(ref.getDurationMicros(future)).isEqualTo(MILLISECONDS.toMicros(100)); @@ -67,10 +67,10 @@ public void ofElapsedRealtime_extrapolatesWallTime() { ShadowSystemClock.advanceBy(Duration.ofMillis(10000000)); long nowElapsedRealtime = SystemClock.elapsedRealtime(); Timer now = new Timer(); - Timer morePast = Timer.ofElapsedRealtime(nowElapsedRealtime - 2000); - Timer past = Timer.ofElapsedRealtime(nowElapsedRealtime - 1000); - Timer future = Timer.ofElapsedRealtime(nowElapsedRealtime + 1000); - Timer moreFuture = Timer.ofElapsedRealtime(nowElapsedRealtime + 2000); + Timer morePast = Timer.ofElapsedRealtime(nowElapsedRealtime - 2000, 0); + Timer past = Timer.ofElapsedRealtime(nowElapsedRealtime - 1000, 0); + Timer future = Timer.ofElapsedRealtime(nowElapsedRealtime + 1000, 0); + Timer moreFuture = Timer.ofElapsedRealtime(nowElapsedRealtime + 2000, 0); // We cannot manipulate System.currentTimeMillis() so multiple comparisons are used to test assertThat(morePast.getMicros()).isLessThan(past.getMicros()); @@ -103,7 +103,7 @@ public void testReset() throws InterruptedException { @Test public void testGetCurrentTimestampMicros() { - Timer timer = new Timer(0, 0); + Timer timer = new Timer(0, 0, 0); long currentTimeSmallest = timer.getCurrentTimestampMicros(); assertThat(timer.getMicros()).isEqualTo(0); @@ -112,7 +112,7 @@ public void testGetCurrentTimestampMicros() { @Test public void testParcel() { - Timer timer1 = new Timer(1000, 1000000); + Timer timer1 = new Timer(1000, 1000000, 1000000); Parcel p1 = Parcel.obtain(); timer1.writeToParcel(p1, 0); @@ -132,6 +132,6 @@ public void testParcel() { /** Helper for other tests that returns elapsedRealtimeMicros from a Timer object */ public static long getElapsedRealtimeMicros(Timer timer) { - return new Timer(0, 0).getDurationMicros(timer); + return new Timer(0, 0, 0).getDurationMicros(timer); } } From 054776bdd096e8fce8b235c15ebfe33e5e2d2e45 Mon Sep 17 00:00:00 2001 From: Leo Zhan Date: Thu, 3 Nov 2022 16:47:10 -0700 Subject: [PATCH 02/11] fix send event --- .../firebase/perf/metrics/AppStartTrace.java | 75 +++++++++++-------- 1 file changed, 44 insertions(+), 31 deletions(-) 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 ffc03e2ee5a..6353b3bead4 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,6 +76,7 @@ public class AppStartTrace implements ActivityLifecycleCallbacks { private final TransportManager transportManager; private final Clock clock; private final ConfigResolver configResolver; + private final TraceMetric.Builder experimentTtid; private Context appContext; /** * The first time onCreate() of any activity is called, the activity is saved as launchActivity. @@ -166,6 +167,7 @@ static AppStartTrace getInstance(TransportManager transportManager, Clock clock) this.clock = clock; this.configResolver = configResolver; this.executorService = executorService; + this.experimentTtid = TraceMetric.newBuilder().setName("_experiment_app_start_ttid"); } /** Called from FirebasePerfProvider to register this callback. */ @@ -209,13 +211,37 @@ private void recordFirstDrawDone() { if (firstDrawDone != null) { return; } + Timer start = getStartTimer(); this.firstDrawDone = clock.getTime(); - executorService.execute( - () -> this.logColdStart(getStartTimer(), this.firstDrawDone, this.startSession)); + int subtraceCount = this.experimentTtid.getSubtracesCount(); + this.experimentTtid + .setClientStartTimeUs(start.getMicros()) + .setDurationUs(start.getDurationMicros(this.firstDrawDone)); - if (isRegisteredForLifecycleCallbacks) { - // After AppStart trace is queued to be logged, we can unregister this callback. - unregisterActivityLifecycleCallbacks(); + TraceMetric.Builder subtrace = + TraceMetric.newBuilder() + .setName("_experiment_classLoadTime") + .setClientStartTimeUs(FirebasePerfProvider.getAppStartTime().getMicros()) + .setDurationUs( + FirebasePerfProvider.getAppStartTime().getDurationMicros(this.firstDrawDone)); + this.experimentTtid.addSubtraces(subtrace.build()); + + subtrace = TraceMetric.newBuilder(); + subtrace + .setName("_experiment_uptimeMillis") + .setClientStartTimeUs(start.getMicros()) + .setDurationUs(start.getDurationUptimeMicros(this.firstDrawDone)); + this.experimentTtid.addSubtraces(subtrace.build()); + + this.experimentTtid.addPerfSessions(this.startSession.build()); + + if (subtraceCount > 0) { + executorService.execute(() -> this.logColdStart(this.experimentTtid)); + + if (isRegisteredForLifecycleCallbacks) { + // After AppStart trace is queued to be logged, we can unregister this callback. + unregisterActivityLifecycleCallbacks(); + } } } @@ -225,19 +251,29 @@ private void recordFirstDrawDonePreDraw() { } Timer start = getStartTimer(); this.preDraw = clock.getTime(); + int subtraceCount = this.experimentTtid.getSubtracesCount(); TraceMetric.Builder subtrace = TraceMetric.newBuilder() .setName("_experiment_preDraw") .setClientStartTimeUs(start.getMicros()) .setDurationUs(start.getDurationMicros(this.preDraw)); - preDrawSubtraces.add(subtrace.build()); + this.experimentTtid.addSubtraces(subtrace.build()); subtrace = TraceMetric.newBuilder(); subtrace .setName("_experiment_preDraw_uptimeMillis") .setClientStartTimeUs(start.getMicros()) .setDurationUs(start.getDurationUptimeMicros(this.preDraw)); - preDrawSubtraces.add(subtrace.build()); + this.experimentTtid.addSubtraces(subtrace.build()); + + if (subtraceCount > 0) { + executorService.execute(() -> this.logColdStart(this.experimentTtid)); + + if (isRegisteredForLifecycleCallbacks) { + // After AppStart trace is queued to be logged, we can unregister this callback. + unregisterActivityLifecycleCallbacks(); + } + } } @Override @@ -306,30 +342,7 @@ public synchronized void onActivityResumed(Activity activity) { } } - private void logColdStart(Timer start, Timer end, PerfSession session) { - TraceMetric.Builder metric = - TraceMetric.newBuilder() - .setName("_experiment_app_start_ttid") - .setClientStartTimeUs(start.getMicros()) - .setDurationUs(start.getDurationMicros(end)); - List subtraces = new ArrayList<>(); - - TraceMetric.Builder subtrace = - TraceMetric.newBuilder() - .setName("_experiment_classLoadTime") - .setClientStartTimeUs(FirebasePerfProvider.getAppStartTime().getMicros()) - .setDurationUs(FirebasePerfProvider.getAppStartTime().getDurationMicros(end)); - subtraces.add(subtrace.build()); - - subtrace = TraceMetric.newBuilder(); - subtrace - .setName("_experiment_uptimeMillis") - .setClientStartTimeUs(start.getMicros()) - .setDurationUs(start.getDurationUptimeMicros(end)); - subtraces.add(subtrace.build()); - - subtraces.addAll(preDrawSubtraces); - metric.addAllSubtraces(subtraces).addPerfSessions(this.startSession.build()); + private void logColdStart(TraceMetric.Builder metric) { transportManager.log(metric.build(), ApplicationProcessState.FOREGROUND_BACKGROUND); } From cbaf384496c31f5c0ac30e5a86cdc35a38aaf120 Mon Sep 17 00:00:00 2001 From: Leo Zhan Date: Thu, 3 Nov 2022 17:55:19 -0700 Subject: [PATCH 03/11] fix dangling variable and naming --- .../com/google/firebase/perf/metrics/AppStartTrace.java | 7 +++---- 1 file changed, 3 insertions(+), 4 deletions(-) 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 6353b3bead4..9a55eee5b5c 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 @@ -99,7 +99,6 @@ public class AppStartTrace implements ActivityLifecycleCallbacks { private Timer onResumeTime = null; private Timer firstDrawDone = null; private Timer preDraw = null; - private List preDrawSubtraces = new ArrayList<>(); private PerfSession startSession; private boolean isStartedFromBackground = false; @@ -236,7 +235,7 @@ private void recordFirstDrawDone() { this.experimentTtid.addPerfSessions(this.startSession.build()); if (subtraceCount > 0) { - executorService.execute(() -> this.logColdStart(this.experimentTtid)); + executorService.execute(() -> this.logExperimentTtid(this.experimentTtid)); if (isRegisteredForLifecycleCallbacks) { // After AppStart trace is queued to be logged, we can unregister this callback. @@ -267,7 +266,7 @@ private void recordFirstDrawDonePreDraw() { this.experimentTtid.addSubtraces(subtrace.build()); if (subtraceCount > 0) { - executorService.execute(() -> this.logColdStart(this.experimentTtid)); + executorService.execute(() -> this.logExperimentTtid(this.experimentTtid)); if (isRegisteredForLifecycleCallbacks) { // After AppStart trace is queued to be logged, we can unregister this callback. @@ -342,7 +341,7 @@ public synchronized void onActivityResumed(Activity activity) { } } - private void logColdStart(TraceMetric.Builder metric) { + private void logExperimentTtid(TraceMetric.Builder metric) { transportManager.log(metric.build(), ApplicationProcessState.FOREGROUND_BACKGROUND); } From 23e07cda96215519664c45fa83fdcf3bbf1a956f Mon Sep 17 00:00:00 2001 From: Leo Zhan Date: Thu, 3 Nov 2022 18:09:17 -0700 Subject: [PATCH 04/11] copyright --- .../google/firebase/perf/util/PreDrawListener.java | 13 +++++++++++++ 1 file changed, 13 insertions(+) diff --git a/firebase-perf/src/main/java/com/google/firebase/perf/util/PreDrawListener.java b/firebase-perf/src/main/java/com/google/firebase/perf/util/PreDrawListener.java index 8b3b47a3ad3..5ae9ce67b1b 100644 --- a/firebase-perf/src/main/java/com/google/firebase/perf/util/PreDrawListener.java +++ b/firebase-perf/src/main/java/com/google/firebase/perf/util/PreDrawListener.java @@ -1,3 +1,16 @@ +// Copyright 2022 Google LLC +// +// Licensed under the Apache License, Version 2.0 (the "License"); +// you may not use this file except in compliance with the License. +// +// You may obtain a copy of the License at +// http://www.apache.org/licenses/LICENSE-2.0 +// +// Unless required by applicable law or agreed to in writing, software +// distributed under the License is distributed on an "AS IS" BASIS, +// WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied. +// See the License for the specific language governing permissions and +// limitations under the License. package com.google.firebase.perf.util; import android.os.Handler; From 079106f1a598a2b759db134a6a5a04b93dc27743 Mon Sep 17 00:00:00 2001 From: Leo Zhan Date: Mon, 7 Nov 2022 16:12:32 -0800 Subject: [PATCH 05/11] fix test --- .../java/com/google/firebase/perf/metrics/AppStartTraceTest.java | 1 + 1 file changed, 1 insertion(+) 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 e705a145aed..519e757af09 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 @@ -305,6 +305,7 @@ public void timeToInitialDisplay_isLogged() { // Simulate draw and manually stepping time forward ShadowSystemClock.advanceBy(Duration.ofMillis(1000)); long drawTime = TimeUnit.NANOSECONDS.toMicros(SystemClock.elapsedRealtimeNanos()); + testView.getViewTreeObserver().dispatchOnPreDraw(); testView.getViewTreeObserver().dispatchOnDraw(); shadowOf(Looper.getMainLooper()).idle(); fakeExecutorService.runNext(); From 86a11675436f0c497c5a0cde04875df0a026f5ef Mon Sep 17 00:00:00 2001 From: Leo Zhan Date: Mon, 7 Nov 2022 17:48:30 -0800 Subject: [PATCH 06/11] onStop --- .../firebase/perf/metrics/AppStartTrace.java | 24 +++++++++++++++++-- 1 file changed, 22 insertions(+), 2 deletions(-) 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 9a55eee5b5c..ac3e0757f5f 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 @@ -380,10 +380,30 @@ private void logAppStartTrace() { } @Override - public void onActivityPaused(Activity activity) {} + public void onActivityPaused(Activity activity) { + if (this.firstDrawDone != null && this.preDraw != null) { + return; + } + Timer onPauseTime = clock.getTime(); + TraceMetric.Builder subtrace = TraceMetric.newBuilder() + .setName("_experiment_onPause") + .setClientStartTimeUs(onPauseTime.getMicros()) + .setDurationUs(getStartTimer().getDurationMicros(onPauseTime)); + this.experimentTtid.addSubtraces(subtrace.build()); + } @Override - public synchronized void onActivityStopped(Activity activity) {} + public void onActivityStopped(Activity activity) { + if (this.firstDrawDone != null && this.preDraw != null) { + return; + } + Timer onStopTime = clock.getTime(); + TraceMetric.Builder subtrace = TraceMetric.newBuilder() + .setName("_experiment_onStop") + .setClientStartTimeUs(onStopTime.getMicros()) + .setDurationUs(getStartTimer().getDurationMicros(onStopTime)); + this.experimentTtid.addSubtraces(subtrace.build()); + } @Override public void onActivityDestroyed(Activity activity) {} From 054be2ecc6ae66cb9f15c8615934f636e0f2463e Mon Sep 17 00:00:00 2001 From: Leo Zhan Date: Mon, 7 Nov 2022 21:55:09 -0800 Subject: [PATCH 07/11] test --- .../com/google/firebase/perf/metrics/AppStartTraceTest.java | 6 ++++++ 1 file changed, 6 insertions(+) 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 519e757af09..550accd2b92 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 @@ -298,6 +298,11 @@ public void timeToInitialDisplay_isLogged() { trace.onActivityCreated(activity1, bundle); trace.onActivityStarted(activity1); trace.onActivityResumed(activity1); + // Experiment: simulate backgrounding before draw + trace.onActivityPaused(activity1); + trace.onActivityStopped(activity1); + trace.onActivityStarted(activity1); + trace.onActivityResumed(activity1); fakeExecutorService.runAll(); verify(transportManager, times(1)) .log(isA(TraceMetric.class), isA(ApplicationProcessState.class)); @@ -318,5 +323,6 @@ public void timeToInitialDisplay_isLogged() { assertThat(ttid.getName()).isEqualTo("_experiment_app_start_ttid"); assertThat(ttid.getDurationUs()).isNotEqualTo(resumeTime - appStartTime); assertThat(ttid.getDurationUs()).isEqualTo(drawTime - appStartTime); + assertThat(ttid.getSubtracesCount()).isEqualTo(6); } } From 0511bfa7f80bcd076b4a115830a83d58f4985ab6 Mon Sep 17 00:00:00 2001 From: Leo Zhan Date: Tue, 8 Nov 2022 11:11:00 -0800 Subject: [PATCH 08/11] better readability --- .../firebase/perf/metrics/AppStartTrace.java | 16 ++++++++++------ .../perf/util/FirstDrawDoneListener.java | 2 -- .../firebase/perf/util/PreDrawListener.java | 4 ++++ 3 files changed, 14 insertions(+), 8 deletions(-) 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 ac3e0757f5f..90731953757 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 @@ -212,7 +212,6 @@ private void recordFirstDrawDone() { } Timer start = getStartTimer(); this.firstDrawDone = clock.getTime(); - int subtraceCount = this.experimentTtid.getSubtracesCount(); this.experimentTtid .setClientStartTimeUs(start.getMicros()) .setDurationUs(start.getDurationMicros(this.firstDrawDone)); @@ -234,7 +233,7 @@ private void recordFirstDrawDone() { this.experimentTtid.addPerfSessions(this.startSession.build()); - if (subtraceCount > 0) { + if (isExperimentTraceDone()) { executorService.execute(() -> this.logExperimentTtid(this.experimentTtid)); if (isRegisteredForLifecycleCallbacks) { @@ -250,7 +249,6 @@ private void recordFirstDrawDonePreDraw() { } Timer start = getStartTimer(); this.preDraw = clock.getTime(); - int subtraceCount = this.experimentTtid.getSubtracesCount(); TraceMetric.Builder subtrace = TraceMetric.newBuilder() .setName("_experiment_preDraw") @@ -265,7 +263,7 @@ private void recordFirstDrawDonePreDraw() { .setDurationUs(start.getDurationUptimeMicros(this.preDraw)); this.experimentTtid.addSubtraces(subtrace.build()); - if (subtraceCount > 0) { + if (isExperimentTraceDone()) { executorService.execute(() -> this.logExperimentTtid(this.experimentTtid)); if (isRegisteredForLifecycleCallbacks) { @@ -275,6 +273,10 @@ private void recordFirstDrawDonePreDraw() { } } + private boolean isExperimentTraceDone() { + return this.preDraw != null && this.firstDrawDone != null; + } + @Override public synchronized void onActivityCreated(Activity activity, Bundle savedInstanceState) { if (isStartedFromBackground || onCreateTime != null // An activity already called onCreate() @@ -385,7 +387,8 @@ public void onActivityPaused(Activity activity) { return; } Timer onPauseTime = clock.getTime(); - TraceMetric.Builder subtrace = TraceMetric.newBuilder() + TraceMetric.Builder subtrace = + TraceMetric.newBuilder() .setName("_experiment_onPause") .setClientStartTimeUs(onPauseTime.getMicros()) .setDurationUs(getStartTimer().getDurationMicros(onPauseTime)); @@ -398,7 +401,8 @@ public void onActivityStopped(Activity activity) { return; } Timer onStopTime = clock.getTime(); - TraceMetric.Builder subtrace = TraceMetric.newBuilder() + TraceMetric.Builder subtrace = + TraceMetric.newBuilder() .setName("_experiment_onStop") .setClientStartTimeUs(onStopTime.getMicros()) .setDurationUs(getStartTimer().getDurationMicros(onStopTime)); diff --git a/firebase-perf/src/main/java/com/google/firebase/perf/util/FirstDrawDoneListener.java b/firebase-perf/src/main/java/com/google/firebase/perf/util/FirstDrawDoneListener.java index 37416398dcb..9e8d7384107 100644 --- a/firebase-perf/src/main/java/com/google/firebase/perf/util/FirstDrawDoneListener.java +++ b/firebase-perf/src/main/java/com/google/firebase/perf/util/FirstDrawDoneListener.java @@ -18,14 +18,12 @@ import android.os.Looper; import android.view.View; import android.view.ViewTreeObserver; -import androidx.annotation.RequiresApi; import java.util.concurrent.atomic.AtomicReference; /** * OnDrawListener that unregisters itself and invokes callback when the next draw is done. This API * 16+ implementation is an approximation of the initial-display-time defined by Android Vitals. */ -@RequiresApi(Build.VERSION_CODES.JELLY_BEAN) public class FirstDrawDoneListener implements ViewTreeObserver.OnDrawListener { private final Handler mainThreadHandler = new Handler(Looper.getMainLooper()); private final AtomicReference viewReference; diff --git a/firebase-perf/src/main/java/com/google/firebase/perf/util/PreDrawListener.java b/firebase-perf/src/main/java/com/google/firebase/perf/util/PreDrawListener.java index 5ae9ce67b1b..56f57dfbdf2 100644 --- a/firebase-perf/src/main/java/com/google/firebase/perf/util/PreDrawListener.java +++ b/firebase-perf/src/main/java/com/google/firebase/perf/util/PreDrawListener.java @@ -19,6 +19,10 @@ import android.view.ViewTreeObserver; import java.util.concurrent.atomic.AtomicReference; +/** + * OnPreDraw listener that unregisters itself and post a callback to the main thread during + * OnPreDraw. This is an approximation of the initial-display time defined by Android Vitals. + */ public class PreDrawListener implements ViewTreeObserver.OnPreDrawListener { private final Handler mainThreadHandler = new Handler(Looper.getMainLooper()); private final AtomicReference viewReference; From a079b33081c5ccdf385869aa40988cfd7f5b9cc0 Mon Sep 17 00:00:00 2001 From: Leo Zhan Date: Tue, 8 Nov 2022 11:19:52 -0800 Subject: [PATCH 09/11] comments --- .../java/com/google/firebase/perf/util/PreDrawListener.java | 4 +--- 1 file changed, 1 insertion(+), 3 deletions(-) diff --git a/firebase-perf/src/main/java/com/google/firebase/perf/util/PreDrawListener.java b/firebase-perf/src/main/java/com/google/firebase/perf/util/PreDrawListener.java index 56f57dfbdf2..15c8a46a9bc 100644 --- a/firebase-perf/src/main/java/com/google/firebase/perf/util/PreDrawListener.java +++ b/firebase-perf/src/main/java/com/google/firebase/perf/util/PreDrawListener.java @@ -41,13 +41,11 @@ private PreDrawListener(View view, Runnable callback) { @Override public boolean onPreDraw() { - // Set viewReference to null so any onDraw past the first is a no-op + // Set viewReference to null so any onPreDraw past the first is a no-op View view = viewReference.getAndSet(null); if (view == null) { return true; } - // OnDrawListeners cannot be removed within onDraw, so we remove it with a - // GlobalLayoutListener view.getViewTreeObserver().removeOnPreDrawListener(this); mainThreadHandler.post(callback); return true; From 442ac7eaeb55c45320d664e8743318e2e5299694 Mon Sep 17 00:00:00 2001 From: Leo Zhan Date: Tue, 8 Nov 2022 11:40:10 -0800 Subject: [PATCH 10/11] reduce code --- .../java/com/google/firebase/perf/metrics/AppStartTrace.java | 4 ++-- 1 file changed, 2 insertions(+), 2 deletions(-) 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 90731953757..abbc80b8332 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 @@ -383,7 +383,7 @@ private void logAppStartTrace() { @Override public void onActivityPaused(Activity activity) { - if (this.firstDrawDone != null && this.preDraw != null) { + if (isExperimentTraceDone()) { return; } Timer onPauseTime = clock.getTime(); @@ -397,7 +397,7 @@ public void onActivityPaused(Activity activity) { @Override public void onActivityStopped(Activity activity) { - if (this.firstDrawDone != null && this.preDraw != null) { + if (isExperimentTraceDone()) { return; } Timer onStopTime = clock.getTime(); From 164aa8b8700123ff6e10cb8c6ca841360402f140 Mon Sep 17 00:00:00 2001 From: Leo Zhan Date: Tue, 8 Nov 2022 12:08:51 -0800 Subject: [PATCH 11/11] reset --- .../src/main/java/com/google/firebase/perf/util/Timer.java | 1 + 1 file changed, 1 insertion(+) diff --git a/firebase-perf/src/main/java/com/google/firebase/perf/util/Timer.java b/firebase-perf/src/main/java/com/google/firebase/perf/util/Timer.java index 029bbb12890..56f21955851 100644 --- a/firebase-perf/src/main/java/com/google/firebase/perf/util/Timer.java +++ b/firebase-perf/src/main/java/com/google/firebase/perf/util/Timer.java @@ -127,6 +127,7 @@ public void reset() { // TODO: consider removing this method and make Timer immutable thus fully thread-safe wallClockMicros = wallClockMicros(); elapsedRealtimeMicros = elapsedRealtimeMicros(); + uptimeMicros = uptimeMicros(); } /** Return wall-clock time in microseconds. */