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

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");
         }

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;
     }
 

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--) {

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) {