From df235a4d677ae46d9b17b17ad37291ec353ddd41 Mon Sep 17 00:00:00 2001 From: Riddle Hsu Date: Wed, 9 Dec 2020 19:11:39 +0800 Subject: [PATCH] Use LatencyTracker to log the time of recents animation The ACTION_TOGGLE_RECENTS on launcher side may be not close enough to the user feeling because it cannot know the actual window drawn time on system. And it may be mixed with 3 button navigation mode which doesn't start recents animation. So here creates a new latency type to log the case of recents animation explicitly. Bug: 169221287 Test: Use gesture navigation mode and swipe up from an app. The log will show "LatencyTracker: action=8 latency=xx". Change-Id: I660f472113684590b4eba40c0534da9dcf7773ce --- .../android/internal/util/LatencyTracker.java | 12 +++++++++++- .../server/wm/ActivityMetricsLogger.java | 4 ++++ .../server/wm/RecentsAnimationController.java | 18 +++++++++++++++++- .../server/wm/WindowManagerService.java | 14 ++++++++------ 4 files changed, 40 insertions(+), 8 deletions(-) diff --git a/core/java/com/android/internal/util/LatencyTracker.java b/core/java/com/android/internal/util/LatencyTracker.java index 8012540ed3149..254c2997fa65c 100644 --- a/core/java/com/android/internal/util/LatencyTracker.java +++ b/core/java/com/android/internal/util/LatencyTracker.java @@ -86,6 +86,11 @@ public class LatencyTracker { */ public static final int ACTION_FACE_WAKE_AND_UNLOCK = 7; + /** + * Time between the swipe-up gesture and window drawn of recents activity. + */ + public static final int ACTION_START_RECENTS_ANIMATION = 8; + private static final String[] NAMES = new String[]{ "expand panel", "toggle recents", @@ -94,7 +99,9 @@ public class LatencyTracker { "check credential unlocked", "turn on screen", "rotate the screen", - "face wake-and-unlock"}; + "face wake-and-unlock", + "start recents-animation", + }; private static final int[] STATSD_ACTION = new int[]{ FrameworkStatsLog.UIACTION_LATENCY_REPORTED__ACTION__ACTION_EXPAND_PANEL, @@ -105,6 +112,7 @@ public class LatencyTracker { FrameworkStatsLog.UIACTION_LATENCY_REPORTED__ACTION__ACTION_TURN_ON_SCREEN, FrameworkStatsLog.UIACTION_LATENCY_REPORTED__ACTION__ACTION_ROTATE_SCREEN, FrameworkStatsLog.UIACTION_LATENCY_REPORTED__ACTION__ACTION_FACE_WAKE_AND_UNLOCK, + FrameworkStatsLog.UIACTION_LATENCY_REPORTED__ACTION__ACTION_START_RECENTS_ANIMATION, }; private static LatencyTracker sLatencyTracker; @@ -170,6 +178,8 @@ public class LatencyTracker { return "ACTION_ROTATE_SCREEN"; case 8: return "ACTION_FACE_WAKE_AND_UNLOCK"; + case 9: + return "ACTION_START_RECENTS_ANIMATION"; default: throw new IllegalArgumentException("Invalid action"); } diff --git a/services/core/java/com/android/server/wm/ActivityMetricsLogger.java b/services/core/java/com/android/server/wm/ActivityMetricsLogger.java index 6a50b793de0f9..b0847879f4566 100644 --- a/services/core/java/com/android/server/wm/ActivityMetricsLogger.java +++ b/services/core/java/com/android/server/wm/ActivityMetricsLogger.java @@ -631,6 +631,10 @@ class ActivityMetricsLogger { if (info.mLoggedTransitionStarting && info.allDrawn()) { done(false /* abort */, info, "notifyWindowsDrawn - all windows drawn", timestampNs); } + if (r.mWmService.isRecentsAnimationTarget(r)) { + r.mWmService.getRecentsAnimationController().logRecentsAnimationStartTime( + info.mSourceEventDelayMs + info.mWindowsDrawnDelayMs); + } return infoSnapshot; } diff --git a/services/core/java/com/android/server/wm/RecentsAnimationController.java b/services/core/java/com/android/server/wm/RecentsAnimationController.java index 16c722653960c..3e42b8cfca2b0 100644 --- a/services/core/java/com/android/server/wm/RecentsAnimationController.java +++ b/services/core/java/com/android/server/wm/RecentsAnimationController.java @@ -57,7 +57,9 @@ import android.view.WindowInsets.Type; import com.android.internal.annotations.VisibleForTesting; import com.android.internal.inputmethod.SoftInputShowHideReason; +import com.android.internal.os.BackgroundThread; import com.android.internal.protolog.common.ProtoLog; +import com.android.internal.util.LatencyTracker; import com.android.internal.util.function.pooled.PooledConsumer; import com.android.internal.util.function.pooled.PooledFunction; import com.android.internal.util.function.pooled.PooledLambda; @@ -84,6 +86,11 @@ import java.util.stream.Collectors; public class RecentsAnimationController implements DeathRecipient { private static final String TAG = RecentsAnimationController.class.getSimpleName(); private static final long FAILSAFE_DELAY = 1000; + /** + * If the recents animation is canceled before the delay since the window drawn, do not log the + * action because the duration is too small that may be just a mistouch, + */ + private static final long LATENCY_TRACKER_LOG_DELAY_MS = 300; public static final int REORDER_KEEP_IN_PLACE = 0; public static final int REORDER_MOVE_TO_TOP = 1; @@ -123,7 +130,7 @@ public class RecentsAnimationController implements DeathRecipient { private boolean mPendingStart = true; // Set when the animation has been canceled - private boolean mCanceled; + private volatile boolean mCanceled; // Whether or not the input consumer is enabled. The input consumer must be both registered and // enabled for it to start intercepting touch events. @@ -592,6 +599,15 @@ public class RecentsAnimationController implements DeathRecipient { return adapter.createRemoteAnimationTarget(); } + void logRecentsAnimationStartTime(int durationMs) { + BackgroundThread.getHandler().postDelayed(() -> { + if (!mCanceled) { + mService.mLatencyTracker.logAction(LatencyTracker.ACTION_START_RECENTS_ANIMATION, + durationMs); + } + }, LATENCY_TRACKER_LOG_DELAY_MS); + } + private boolean removeTaskInternal(int taskId) { boolean result = false; for (int i = mPendingAnimations.size() - 1; i >= 0; i--) { diff --git a/services/core/java/com/android/server/wm/WindowManagerService.java b/services/core/java/com/android/server/wm/WindowManagerService.java index 8fd342c25bc32..b2ff923472125 100644 --- a/services/core/java/com/android/server/wm/WindowManagerService.java +++ b/services/core/java/com/android/server/wm/WindowManagerService.java @@ -1036,7 +1036,7 @@ public class WindowManagerService extends IWindowManager.Stub private WindowContentFrameStats mTempWindowRenderStats; - private final LatencyTracker mLatencyTracker; + final LatencyTracker mLatencyTracker; /** * Whether the UI is currently running in touch mode (not showing @@ -1120,18 +1120,16 @@ public class WindowManagerService extends IWindowManager.Stub // While running a recents animation, this will get called early because we show the // recents animation target activity immediately when the animation starts. Defer the // mLaunchTaskBehind updates until recents animation finishes. - final boolean isRecentsAnimationTarget = getRecentsAnimationController() != null - && getRecentsAnimationController().isTargetApp(atoken); - if (atoken.mLaunchTaskBehind && !isRecentsAnimationTarget) { + if (atoken.mLaunchTaskBehind && !isRecentsAnimationTarget(atoken)) { mAtmService.mTaskSupervisor.scheduleLaunchTaskBehindComplete(atoken.token); atoken.mLaunchTaskBehind = false; } else { atoken.updateReportedVisibilityLocked(); // We should also defer sending the finished callback until the recents animation // successfully finishes. - if (atoken.mEnteringAnimation && !isRecentsAnimationTarget) { + if (atoken.mEnteringAnimation && !isRecentsAnimationTarget(atoken)) { atoken.mEnteringAnimation = false; - if (atoken != null && atoken.attachedToProcess()) { + if (atoken.attachedToProcess()) { try { atoken.app.getThread().scheduleEnterAnimationComplete(atoken.appToken); } catch (RemoteException e) { @@ -2968,6 +2966,10 @@ public class WindowManagerService extends IWindowManager.Stub } } + boolean isRecentsAnimationTarget(ActivityRecord r) { + return mRecentsAnimationController != null && mRecentsAnimationController.isTargetApp(r); + } + void setWindowOpaqueLocked(IBinder token, boolean isOpaque) { final ActivityRecord wtoken = mRoot.getActivityRecord(token); if (wtoken != null) {