From 1c5d72eeca156cec075d881a676b4915bc4235a8 Mon Sep 17 00:00:00 2001 From: Riddle Hsu Date: Wed, 9 Oct 2019 20:54:26 +0800 Subject: [PATCH] Report launch time on the last started activity Assume: L is "Activity launched". D is "Window drawn/displayed". T is a trampoline activity (e.g. a splash screen). M is the main activity. An application may be designed as: L(T) -> L(M) -> D(T) -> D(M) Originally we will report the launch time on D(T). Now if L(M) happens before D(T), then it is supposed to be a continuous launch sequence and report the launch time on D(M). Bug: 132736359 Test: atest ActivityMetricsLoggerTests atest ActivityMetricsLaunchObserverTests# \ testOnActivityLaunchFinishedTrampoline Change-Id: I9ffd3b94d76831572ea961a8dcbf9d760a617430 --- .../server/wm/ActivityMetricsLogger.java | 30 ++- .../ActivityMetricsLaunchObserverTests.java | 174 +++++++++--------- 2 files changed, 105 insertions(+), 99 deletions(-) diff --git a/services/core/java/com/android/server/wm/ActivityMetricsLogger.java b/services/core/java/com/android/server/wm/ActivityMetricsLogger.java index e6c6b12e18c64..6636b16615011 100644 --- a/services/core/java/com/android/server/wm/ActivityMetricsLogger.java +++ b/services/core/java/com/android/server/wm/ActivityMetricsLogger.java @@ -187,9 +187,24 @@ class ActivityMetricsLogger { private int startingWindowDelayMs = INVALID_DELAY; private int bindApplicationDelayMs = INVALID_DELAY; private int reason = APP_TRANSITION_TIMEOUT; - private boolean loggedWindowsDrawn; + private int numUndrawnActivities; private boolean loggedStartingWindowDrawn; private boolean launchTraceActive; + + /** + * Remembers the latest launched activity to represent the final transition. This also + * increments the number of activities that should be drawn, so a consecutive launching + * sequence can be coalesced as one event. + */ + void setLatestLaunchedActivity(ActivityRecord r) { + if (launchedActivity == r) { + return; + } + launchedActivity = r; + if (!r.noDisplay) { + numUndrawnActivities++; + } + } } final class WindowingModeTransitionInfoSnapshot { @@ -400,7 +415,7 @@ class ActivityMetricsLogger { // the other attributes. // Coalesce multiple (trampoline) activities from a single sequence together. - info.launchedActivity = launchedActivity; + info.setLatestLaunchedActivity(launchedActivity); return; } @@ -422,7 +437,7 @@ class ActivityMetricsLogger { // A new launch sequence [with the windowingMode] has begun. // Start tracking it. final WindowingModeTransitionInfo newInfo = new WindowingModeTransitionInfo(); - newInfo.launchedActivity = launchedActivity; + newInfo.setLatestLaunchedActivity(launchedActivity); newInfo.currentTransitionProcessRunning = processRunning; newInfo.startResult = resultCode; mWindowingModeTransitionInfo.put(windowingMode, newInfo); @@ -448,11 +463,11 @@ class ActivityMetricsLogger { if (DEBUG_METRICS) Slog.i(TAG, "notifyWindowsDrawn windowingMode=" + windowingMode); final WindowingModeTransitionInfo info = mWindowingModeTransitionInfo.get(windowingMode); - if (info == null || info.loggedWindowsDrawn) { + if (info == null || info.numUndrawnActivities == 0) { return null; } info.windowsDrawnDelayMs = calculateDelay(timestampNs); - info.loggedWindowsDrawn = true; + info.numUndrawnActivities--; final WindowingModeTransitionInfoSnapshot infoSnapshot = new WindowingModeTransitionInfoSnapshot(info); if (allWindowsDrawn() && mLoggedTransitionStarting) { @@ -594,9 +609,10 @@ class ActivityMetricsLogger { } } - private boolean allWindowsDrawn() { + @VisibleForTesting + boolean allWindowsDrawn() { for (int index = mWindowingModeTransitionInfo.size() - 1; index >= 0; index--) { - if (!mWindowingModeTransitionInfo.valueAt(index).loggedWindowsDrawn) { + if (mWindowingModeTransitionInfo.valueAt(index).numUndrawnActivities != 0) { return false; } } diff --git a/services/tests/wmtests/src/com/android/server/wm/ActivityMetricsLaunchObserverTests.java b/services/tests/wmtests/src/com/android/server/wm/ActivityMetricsLaunchObserverTests.java index 2836e69f79da2..8d22f7aaaeaa1 100644 --- a/services/tests/wmtests/src/com/android/server/wm/ActivityMetricsLaunchObserverTests.java +++ b/services/tests/wmtests/src/com/android/server/wm/ActivityMetricsLaunchObserverTests.java @@ -18,8 +18,6 @@ package com.android.server.wm; import static android.app.ActivityManager.START_SUCCESS; import static android.app.ActivityManager.START_TASK_TO_FRONT; -import static android.app.WindowConfiguration.ACTIVITY_TYPE_STANDARD; -import static android.app.WindowConfiguration.WINDOWING_MODE_FULLSCREEN; import static com.android.dx.mockito.inline.extended.ExtendedMockito.mock; import static com.android.dx.mockito.inline.extended.ExtendedMockito.verify; @@ -63,10 +61,8 @@ public class ActivityMetricsLaunchObserverTests extends ActivityTestsBase { private ActivityMetricsLaunchObserver mLaunchObserver; private ActivityMetricsLaunchObserverRegistry mLaunchObserverRegistry; - private ActivityStack mStack; - private TaskRecord mTask; - private ActivityRecord mActivityRecord; - private ActivityRecord mActivityRecordTrampoline; + private ActivityRecord mTrampolineActivity; + private ActivityRecord mTopActivity; @Before public void setUpAMLO() { @@ -80,15 +76,10 @@ public class ActivityMetricsLaunchObserverTests extends ActivityTestsBase { // Sometimes we need an ActivityRecord for ActivityMetricsLogger to do anything useful. // This seems to be the easiest way to create an ActivityRecord. - mStack = new StackBuilder(mRootActivityContainer) - .setActivityType(ACTIVITY_TYPE_STANDARD) - .setWindowingMode(WINDOWING_MODE_FULLSCREEN) - .setOnTop(true) - .setCreateActivity(true) + mTrampolineActivity = new ActivityBuilder(mService).setCreateTask(true).build(); + mTopActivity = new ActivityBuilder(mService) + .setTask(mTrampolineActivity.getTaskRecord()) .build(); - mTask = mStack.topTask(); - mActivityRecord = mTask.getTopActivity(); - mActivityRecordTrampoline = new ActivityBuilder(mService).setTask(mTask).build(); } @After @@ -123,8 +114,7 @@ public class ActivityMetricsLaunchObserverTests extends ActivityTestsBase { return verify(mock, timeout(TimeUnit.SECONDS.toMillis(5))); } - @Test - public void testOnIntentStarted() throws Exception { + private void onIntentStarted() { Intent intent = new Intent("action 1"); mActivityMetricsLogger.notifyActivityLaunching(intent); @@ -134,123 +124,123 @@ public class ActivityMetricsLaunchObserverTests extends ActivityTestsBase { } @Test - public void testOnIntentFailed() throws Exception { - testOnIntentStarted(); - - ActivityRecord activityRecord = null; + public void testOnIntentFailed() { + onIntentStarted(); // Bringing an intent that's already running 'to front' is not considered // as an ACTIVITY_LAUNCHED state transition. mActivityMetricsLogger.notifyActivityLaunched(START_TASK_TO_FRONT, - activityRecord); + null /* launchedActivity */); verifyAsync(mLaunchObserver).onIntentFailed(); verifyNoMoreInteractions(mLaunchObserver); } - @Test - public void testOnActivityLaunched() throws Exception { - testOnIntentStarted(); + private void onActivityLaunched() { + onIntentStarted(); - mActivityMetricsLogger.notifyActivityLaunched(START_SUCCESS, - mActivityRecord); + mActivityMetricsLogger.notifyActivityLaunched(START_SUCCESS, mTopActivity); - verifyAsync(mLaunchObserver).onActivityLaunched(eqProto(mActivityRecord), anyInt()); + verifyAsync(mLaunchObserver).onActivityLaunched(eqProto(mTopActivity), anyInt()); verifyNoMoreInteractions(mLaunchObserver); } @Test - public void testOnActivityLaunchFinished() throws Exception { - testOnActivityLaunched(); + public void testOnActivityLaunchFinished() { + onActivityLaunched(); - mActivityMetricsLogger.notifyTransitionStarting(new SparseIntArray(), - SystemClock.elapsedRealtimeNanos()); + mActivityMetricsLogger.notifyTransitionStarting(new SparseIntArray(), + SystemClock.elapsedRealtimeNanos()); - mActivityMetricsLogger.notifyWindowsDrawn(mActivityRecord.getWindowingMode(), - SystemClock.elapsedRealtimeNanos()); + notifyWindowsDrawn(mTopActivity); - verifyAsync(mLaunchObserver).onActivityLaunchFinished(eqProto(mActivityRecord), anyLong()); - verifyNoMoreInteractions(mLaunchObserver); - } - - @Test - public void testOnActivityLaunchCancelled() throws Exception { - testOnActivityLaunched(); - - mActivityRecord.mDrawn = true; - - // Cannot time already-visible activities. - mActivityMetricsLogger.notifyActivityLaunched(START_TASK_TO_FRONT, mActivityRecord); - - verifyAsync(mLaunchObserver).onActivityLaunchCancelled(eqProto(mActivityRecord)); - verifyNoMoreInteractions(mLaunchObserver); - } - - @Test - public void testOnReportFullyDrawn() throws Exception { - testOnActivityLaunched(); - - mActivityMetricsLogger.logAppTransitionReportedDrawn(mActivityRecord, false); - - verifyAsync(mLaunchObserver).onReportFullyDrawn(eqProto(mActivityRecord), anyLong()); + verifyAsync(mLaunchObserver).onActivityLaunchFinished(eqProto(mTopActivity), anyLong()); verifyNoMoreInteractions(mLaunchObserver); } @Test - public void testOnActivityLaunchedTrampoline() throws Exception { - testOnIntentStarted(); + public void testOnActivityLaunchCancelled() { + onActivityLaunched(); - mActivityMetricsLogger.notifyActivityLaunched(START_SUCCESS, - mActivityRecord); + mTopActivity.mDrawn = true; - verifyAsync(mLaunchObserver).onActivityLaunched(eqProto(mActivityRecord), anyInt()); + // Cannot time already-visible activities. + mActivityMetricsLogger.notifyActivityLaunched(START_TASK_TO_FRONT, mTopActivity); + + verifyAsync(mLaunchObserver).onActivityLaunchCancelled(eqProto(mTopActivity)); + verifyNoMoreInteractions(mLaunchObserver); + } + + @Test + public void testOnReportFullyDrawn() { + onActivityLaunched(); + + mActivityMetricsLogger.logAppTransitionReportedDrawn(mTopActivity, false); + + verifyAsync(mLaunchObserver).onReportFullyDrawn(eqProto(mTopActivity), anyLong()); + verifyNoMoreInteractions(mLaunchObserver); + } + + private void onActivityLaunchedTrampoline() { + onIntentStarted(); + + mActivityMetricsLogger.notifyActivityLaunched(START_SUCCESS, mTopActivity); + + verifyAsync(mLaunchObserver).onActivityLaunched(eqProto(mTopActivity), anyInt()); // A second, distinct, activity launch is coalesced into the the current app launch sequence - mActivityMetricsLogger.notifyActivityLaunched(START_SUCCESS, - mActivityRecordTrampoline); + mActivityMetricsLogger.notifyActivityLaunched(START_SUCCESS, mTrampolineActivity); verifyNoMoreInteractions(mLaunchObserver); } - @Test - public void testOnActivityLaunchFinishedTrampoline() throws Exception { - testOnActivityLaunchedTrampoline(); - - mActivityMetricsLogger.notifyTransitionStarting(new SparseIntArray(), - SystemClock.elapsedRealtimeNanos()); - - mActivityMetricsLogger.notifyWindowsDrawn(mActivityRecordTrampoline.getWindowingMode(), - SystemClock.elapsedRealtimeNanos()); - - verifyAsync(mLaunchObserver).onActivityLaunchFinished(eqProto(mActivityRecordTrampoline), - anyLong()); - verifyNoMoreInteractions(mLaunchObserver); + private void notifyWindowsDrawn(ActivityRecord r) { + mActivityMetricsLogger.notifyWindowsDrawn(r.getWindowingMode(), + SystemClock.elapsedRealtimeNanos()); } @Test - public void testOnActivityLaunchCancelledTrampoline() throws Exception { - testOnActivityLaunchedTrampoline(); + public void testOnActivityLaunchFinishedTrampoline() { + onActivityLaunchedTrampoline(); - mActivityRecordTrampoline.mDrawn = true; + mActivityMetricsLogger.notifyTransitionStarting(new SparseIntArray(), + SystemClock.elapsedRealtimeNanos()); - // Cannot time already-visible activities. - mActivityMetricsLogger.notifyActivityLaunched(START_TASK_TO_FRONT, - mActivityRecordTrampoline); + notifyWindowsDrawn(mTrampolineActivity); - verifyAsync(mLaunchObserver).onActivityLaunchCancelled(eqProto(mActivityRecordTrampoline)); - verifyNoMoreInteractions(mLaunchObserver); + assertWithMessage("Trampoline activity is drawn but the top activity is not yet") + .that(mActivityMetricsLogger.allWindowsDrawn()).isFalse(); + + notifyWindowsDrawn(mTopActivity); + + verifyAsync(mLaunchObserver).onActivityLaunchFinished(eqProto(mTrampolineActivity), + anyLong()); + verifyNoMoreInteractions(mLaunchObserver); } @Test - public void testActivityRecordProtoIsNotTooBig() throws Exception { + public void testOnActivityLaunchCancelledTrampoline() { + onActivityLaunchedTrampoline(); + + mTrampolineActivity.mDrawn = true; + + // Cannot time already-visible activities. + mActivityMetricsLogger.notifyActivityLaunched(START_TASK_TO_FRONT, mTrampolineActivity); + + verifyAsync(mLaunchObserver).onActivityLaunchCancelled(eqProto(mTrampolineActivity)); + verifyNoMoreInteractions(mLaunchObserver); + } + + @Test + public void testActivityRecordProtoIsNotTooBig() { // The ActivityRecordProto must not be too big, otherwise converting it at runtime // will become prohibitively expensive. - assertWithMessage("mActivityRecord: %s", mActivityRecord). - that(activityRecordToProto(mActivityRecord).length). - isAtMost(ActivityMetricsLogger.LAUNCH_OBSERVER_ACTIVITY_RECORD_PROTO_CHUNK_SIZE); + assertWithMessage("mTopActivity: %s", mTopActivity) + .that(activityRecordToProto(mTopActivity).length) + .isAtMost(ActivityMetricsLogger.LAUNCH_OBSERVER_ACTIVITY_RECORD_PROTO_CHUNK_SIZE); - assertWithMessage("mActivityRecordTrampoline: %s", mActivityRecordTrampoline). - that(activityRecordToProto(mActivityRecordTrampoline).length). - isAtMost(ActivityMetricsLogger.LAUNCH_OBSERVER_ACTIVITY_RECORD_PROTO_CHUNK_SIZE); + assertWithMessage("mTrampolineActivity: %s", mTrampolineActivity) + .that(activityRecordToProto(mTrampolineActivity).length) + .isAtMost(ActivityMetricsLogger.LAUNCH_OBSERVER_ACTIVITY_RECORD_PROTO_CHUNK_SIZE); } }