From e9ef7ad43ca6ff667fd01c505457741f03a90f50 Mon Sep 17 00:00:00 2001 From: Tony Wickham Date: Mon, 19 May 2025 23:47:17 +0000 Subject: [PATCH] Migrate some logs to OverviewCommandHelperProtoLogProxy This will allow us to see the logs in Winscope, including frame by frame to make debugging easier. Also added a log for Launcher#onNewIntent to help with Home button. Test: EXEMPT log only update Bug: 417248321 Bug: 384423890 Flag: NONE log only update Change-Id: Ib24aeb78e44ff29542eb25411c51f77dba299a2e --- .../uioverrides/QuickstepLauncher.java | 8 + .../quickstep/OverviewCommandHelper.kt | 56 +++--- .../OverviewCommandHelperProtoLogProxy.java | 182 ++++++++++++++++++ .../util/ActiveGestureProtoLogProxy.java | 6 - .../util/QuickstepProtoLogGroup.java | 5 +- src/com/android/launcher3/Launcher.java | 6 + 6 files changed, 229 insertions(+), 34 deletions(-) create mode 100644 quickstep/src_protolog/com/android/launcher3/util/OverviewCommandHelperProtoLogProxy.java diff --git a/quickstep/src/com/android/launcher3/uioverrides/QuickstepLauncher.java b/quickstep/src/com/android/launcher3/uioverrides/QuickstepLauncher.java index 86113841c3..9149eac53d 100644 --- a/quickstep/src/com/android/launcher3/uioverrides/QuickstepLauncher.java +++ b/quickstep/src/com/android/launcher3/uioverrides/QuickstepLauncher.java @@ -165,6 +165,7 @@ import com.android.launcher3.util.DisplayController; import com.android.launcher3.util.IntSet; import com.android.launcher3.util.NavigationMode; import com.android.launcher3.util.ObjectWrapper; +import com.android.launcher3.util.OverviewCommandHelperProtoLogProxy; import com.android.launcher3.util.PendingRequestArgs; import com.android.launcher3.util.PendingSplitSelectInfo; import com.android.launcher3.util.RunnableList; @@ -897,6 +898,13 @@ public class QuickstepLauncher extends Launcher implements RecentsViewContainer, } } + @Override + protected void logOnNewIntent(boolean alreadyOnHome, boolean shouldMoveToDefaultScreen, + String action, boolean internalStateHandled) { + OverviewCommandHelperProtoLogProxy.logOnNewIntent(alreadyOnHome, shouldMoveToDefaultScreen, + action, internalStateHandled); + } + public QuickstepTransitionManager getAppTransitionManager() { return mAppTransitionManager; } diff --git a/quickstep/src/com/android/quickstep/OverviewCommandHelper.kt b/quickstep/src/com/android/quickstep/OverviewCommandHelper.kt index f146c65156..d62d0c85a8 100644 --- a/quickstep/src/com/android/quickstep/OverviewCommandHelper.kt +++ b/quickstep/src/com/android/quickstep/OverviewCommandHelper.kt @@ -41,6 +41,7 @@ import com.android.launcher3.logging.StatsLogManager.LauncherEvent.LAUNCHER_OVER import com.android.launcher3.logging.StatsLogManager.LauncherEvent.LAUNCHER_OVERVIEW_SHOW_OVERVIEW_FROM_KEYBOARD_SHORTCUT import com.android.launcher3.taskbar.TaskbarManager import com.android.launcher3.taskbar.TaskbarUIController +import com.android.launcher3.util.OverviewCommandHelperProtoLogProxy import com.android.launcher3.util.OverviewReleaseFlags.enableGridOnlyOverview import com.android.launcher3.util.RunnableList import com.android.launcher3.util.coroutines.DispatcherProvider @@ -118,7 +119,7 @@ constructor( isLastOfBatch: Boolean = true, ): CommandInfo? { if (commandQueue.size >= MAX_QUEUE_SIZE) { - Log.d(TAG, "command not added: $type - queue is full ($commandQueue).") + OverviewCommandHelperProtoLogProxy.logCommandQueueFull(type, commandQueue) return null } @@ -130,13 +131,13 @@ constructor( isLastOfBatch = isLastOfBatch, ) commandQueue.add(command) - Log.d(TAG, "command added: $command") + OverviewCommandHelperProtoLogProxy.logCommandAdded(command) if (commandQueue.size == 1) { - Log.d(TAG, "execute: $command - queue size: ${commandQueue.size}") + OverviewCommandHelperProtoLogProxy.logCommandExecuted(command, commandQueue.size) coroutineScope.launch(dispatcherProvider.main) { processNextCommand() } } else { - Log.d(TAG, "not executed: $command - queue size: ${commandQueue.size}") + OverviewCommandHelperProtoLogProxy.logCommandNotExecuted(command, commandQueue.size) } return command @@ -172,7 +173,7 @@ constructor( /** Clear pending or completed commands from the queue */ fun clearPendingCommands() { - Log.d(TAG, "clearing pending commands: $commandQueue") + OverviewCommandHelperProtoLogProxy.logClearPendingCommands(commandQueue) commandQueue.removeAll { it.status != CommandStatus.PROCESSING } } @@ -186,12 +187,12 @@ constructor( traceSection("OverviewCommandHelper.processNextCommand") { val command: CommandInfo? = commandQueue.firstOrNull() if (command == null) { - Log.d(TAG, "no pending commands to be executed.") + OverviewCommandHelperProtoLogProxy.logNoPendingCommands() return@traceSection } command.status = CommandStatus.PROCESSING - Log.d(TAG, "executing command: $command") + OverviewCommandHelperProtoLogProxy.logExecutingCommand(command) coroutineScope.launch(dispatcherProvider.main) { traceSection("OverviewCommandHelper.executeCommandWithTimeout") { @@ -211,7 +212,7 @@ constructor( @VisibleForTesting fun executeCommand(command: CommandInfo, onCallbackResult: () -> Unit): Boolean { val recentsView = getVisibleRecentsView(command.displayId) - Log.d(TAG, "executeCommand: $command - visibleRecentsView: $recentsView") + OverviewCommandHelperProtoLogProxy.logExecutingCommand(command, recentsView) return if (recentsView != null) { executeWhenRecentsIsVisible(command, recentsView, onCallbackResult) } else { @@ -226,11 +227,14 @@ constructor( private suspend fun executeCommandSuspended(command: CommandInfo) = suspendCancellableCoroutine { continuation -> fun processResult(isCompleted: Boolean) { - Log.d(TAG, "command executed: $command with result: $isCompleted") + OverviewCommandHelperProtoLogProxy.logExecutedCommandWithResult( + command, + isCompleted, + ) if (isCompleted) { continuation.resume(Unit) } else { - Log.d(TAG, "waiting for command callback: $command") + OverviewCommandHelperProtoLogProxy.logWaitingForCommandCallback(command) } } @@ -326,10 +330,10 @@ constructor( if (callbackList != null) { callbackList.add { - Log.d(TAG, "launching task callback: $command") + OverviewCommandHelperProtoLogProxy.logLaunchingTaskCallback(command) onCallbackResult() } - Log.d(TAG, "launching task - waiting for callback: $command") + OverviewCommandHelperProtoLogProxy.logLaunchingTaskWaitingForCallback(command) return false } else { recents.startHome() @@ -390,7 +394,6 @@ constructor( } HOME -> { - ActiveGestureProtoLogProxy.logExecuteHomeCommand() taskAnimationManager.maybeStartHomeAction { // Although IActivityTaskManager$Stub$Proxy.startActivity is a slow binder call, // we should still call it on main thread because launcher is waiting for @@ -423,21 +426,21 @@ constructor( val animatorListener: Animator.AnimatorListener = object : AnimatorListenerAdapter() { override fun onAnimationStart(animation: Animator) { - Log.d(TAG, "switching to Overview state - onAnimationStart: $command") + OverviewCommandHelperProtoLogProxy.logSwitchingToOverviewStateStart(command) super.onAnimationStart(animation) updateRecentsViewFocus(command) logShowOverviewFrom(command) } override fun onAnimationEnd(animation: Animator) { - Log.d(TAG, "switching to Overview state - onAnimationEnd: $command") + OverviewCommandHelperProtoLogProxy.logSwitchingToOverviewStateEnd(command) super.onAnimationEnd(animation) onRecentsViewFocusUpdated(command) onCallbackResult() } } if (containerInterface.switchToRecentsIfVisible(animatorListener)) { - Log.d(TAG, "switching to Overview state - waiting: $command") + OverviewCommandHelperProtoLogProxy.logSwitchingToOverviewStateWaiting(command) // If successfully switched, wait until animation finishes return false } @@ -480,7 +483,7 @@ constructor( targets: RecentsAnimationTargets, transitionInfo: TransitionInfo?, ) { - Log.d(TAG, "recents animation started: $command") + OverviewCommandHelperProtoLogProxy.logRecentsAnimStarted(command) if (recentsViewContainer is RecentsWindowManager) { recentsViewContainer.rootView?.let { view -> InteractionJankMonitorWrapper.begin(view, Cuj.CUJ_LAUNCHER_QUICK_SWITCH) @@ -490,7 +493,7 @@ constructor( updateRecentsViewFocus(command) logShowOverviewFrom(command) containerInterface.runOnInitBackgroundStateUI { - Log.d(TAG, "recents animation started - onInitBackgroundStateUI: $command") + OverviewCommandHelperProtoLogProxy.logOnInitBackgroundStateUI(command) interactionHandler.onGestureEnded( 0f, PointF(), @@ -503,7 +506,7 @@ constructor( override fun onRecentsAnimationCanceled( thumbnailDatas: HashMap ) { - Log.d(TAG, "recents animation canceled: $command") + OverviewCommandHelperProtoLogProxy.logRecentsAnimCanceled(command) interactionHandler.onGestureCancelled() command.removeListener(this) @@ -533,7 +536,7 @@ constructor( command.addListener(recentAnimListener) } Trace.beginAsyncSection(TRANSITION_NAME, 0) - Log.d(TAG, "switching via recents animation - onGestureStarted: $command") + OverviewCommandHelperProtoLogProxy.logSwitchingViaRecentsAnim(command) return false } @@ -548,7 +551,7 @@ constructor( handler: AbsSwipeUpHandler<*, *, *>, onCommandResult: () -> Unit, ) { - Log.d(TAG, "switching via recents animation - onTransitionComplete: $command") + OverviewCommandHelperProtoLogProxy.logSwitchingViaRecentsAnimComplete(command) command.removeListener(handler) Trace.endAsyncSection(TRANSITION_NAME, 0) onRecentsViewFocusUpdated(command) @@ -559,22 +562,21 @@ constructor( private fun onCommandFinished(command: CommandInfo) { command.status = CommandStatus.COMPLETED if (commandQueue.firstOrNull() !== command) { - Log.d( - TAG, - "next task not scheduled. First pending command type " + - "is ${commandQueue.firstOrNull()} - command type is: $command", + OverviewCommandHelperProtoLogProxy.logCommandFinishedButNotScheduled( + commandQueue.firstOrNull(), + command, ) return } - Log.d(TAG, "command executed successfully! $command") + OverviewCommandHelperProtoLogProxy.logCommandFinishedSuccessfully(command) commandQueue.remove(command) processNextCommand() } private fun cancelCommand(command: CommandInfo, throwable: Throwable?) { command.status = CommandStatus.CANCELED - Log.e(TAG, "command cancelled: $command - $throwable") + OverviewCommandHelperProtoLogProxy.logCommandCanceled(command, throwable) commandQueue.remove(command) processNextCommand() } diff --git a/quickstep/src_protolog/com/android/launcher3/util/OverviewCommandHelperProtoLogProxy.java b/quickstep/src_protolog/com/android/launcher3/util/OverviewCommandHelperProtoLogProxy.java new file mode 100644 index 0000000000..a3941b3e3c --- /dev/null +++ b/quickstep/src_protolog/com/android/launcher3/util/OverviewCommandHelperProtoLogProxy.java @@ -0,0 +1,182 @@ +/* + * Copyright (C) 2025 The Android Open Source Project + * + * 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.android.launcher3.util; + +import static com.android.quickstep.util.QuickstepProtoLogGroup.OVERVIEW_COMMAND_HELPER; +import static com.android.quickstep.util.QuickstepProtoLogGroup.isProtoLogInitialized; + +import androidx.annotation.NonNull; +import androidx.annotation.Nullable; + +import com.android.internal.protolog.ProtoLog; + +/** + * Proxy class used for OverviewCommandHelper ProtoLog support. (e.g. for 3 button nav) + */ +public class OverviewCommandHelperProtoLogProxy { + + public static void logCommandQueueFull(@NonNull Object type, @NonNull Object commandQueue) { + if (!isProtoLogInitialized()) return; + ProtoLog.d(OVERVIEW_COMMAND_HELPER, + "command not added: %s - queue is full (%s).", + type, + commandQueue); + } + + public static void logCommandAdded(@NonNull Object command) { + if (!isProtoLogInitialized()) return; + ProtoLog.d(OVERVIEW_COMMAND_HELPER, "command added: %s", command); + } + + public static void logCommandExecuted(@NonNull Object command, int queueSize) { + if (!isProtoLogInitialized()) return; + ProtoLog.d(OVERVIEW_COMMAND_HELPER, + "execute: %s - queue size: %d", + command, + queueSize); + } + + public static void logCommandNotExecuted(@NonNull Object command, int queueSize) { + if (!isProtoLogInitialized()) return; + ProtoLog.d(OVERVIEW_COMMAND_HELPER, + "command not executed: %s - queue size: %d", + command, + queueSize); + } + + public static void logClearPendingCommands(@NonNull Object commandQueue) { + if (!isProtoLogInitialized()) return; + ProtoLog.d(OVERVIEW_COMMAND_HELPER, + "clearing pending commands: %s", commandQueue); + } + + public static void logNoPendingCommands() { + if (!isProtoLogInitialized()) return; + ProtoLog.d(OVERVIEW_COMMAND_HELPER, "no pending commands to be executed."); + } + + public static void logExecutingCommand(@NonNull Object command) { + if (!isProtoLogInitialized()) return; + ProtoLog.d(OVERVIEW_COMMAND_HELPER, "executing command: %s", command); + } + + public static void logExecutingCommand(@NonNull Object command, @Nullable Object recentsView) { + if (!isProtoLogInitialized()) return; + ProtoLog.d(OVERVIEW_COMMAND_HELPER, + "executing command: %s - visibleRecentsView: %s", + command, + recentsView); + } + + public static void logExecutedCommandWithResult(@NonNull Object command, boolean isCompleted) { + if (!isProtoLogInitialized()) return; + ProtoLog.d(OVERVIEW_COMMAND_HELPER, "command executed: %s with result: %b", + command, + isCompleted); + } + + public static void logWaitingForCommandCallback(@NonNull Object command) { + if (!isProtoLogInitialized()) return; + ProtoLog.d(OVERVIEW_COMMAND_HELPER, "waiting for command callback: %s", command); + } + + public static void logLaunchingTaskCallback(@NonNull Object command) { + if (!isProtoLogInitialized()) return; + ProtoLog.d(OVERVIEW_COMMAND_HELPER, "launching task callback: %s", command); + } + + public static void logLaunchingTaskWaitingForCallback(@NonNull Object command) { + if (!isProtoLogInitialized()) return; + ProtoLog.d(OVERVIEW_COMMAND_HELPER, "launching task - waiting for callback: %s", command); + } + + public static void logSwitchingToOverviewStateStart(@NonNull Object command) { + if (!isProtoLogInitialized()) return; + ProtoLog.d(OVERVIEW_COMMAND_HELPER, "switching to Overview state - onAnimationStart: %s", + command); + } + + public static void logSwitchingToOverviewStateEnd(@NonNull Object command) { + if (!isProtoLogInitialized()) return; + ProtoLog.d(OVERVIEW_COMMAND_HELPER, "switching to Overview state - onAnimationEnd: %s", + command); + } + + public static void logSwitchingToOverviewStateWaiting(@NonNull Object command) { + if (!isProtoLogInitialized()) return; + ProtoLog.d(OVERVIEW_COMMAND_HELPER, "switching to Overview state - waiting: %s", command); + } + + public static void logRecentsAnimStarted(@NonNull Object command) { + if (!isProtoLogInitialized()) return; + ProtoLog.d(OVERVIEW_COMMAND_HELPER, "recents animation started: %s", command); + } + + public static void logOnInitBackgroundStateUI(@NonNull Object command) { + if (!isProtoLogInitialized()) return; + ProtoLog.d(OVERVIEW_COMMAND_HELPER, + "recents animation started - onInitBackgroundStateUI: %s", command); + } + + public static void logRecentsAnimCanceled(@NonNull Object command) { + if (!isProtoLogInitialized()) return; + ProtoLog.d(OVERVIEW_COMMAND_HELPER, "recents animation canceled: %s", command); + } + + public static void logSwitchingViaRecentsAnim(@NonNull Object command) { + if (!isProtoLogInitialized()) return; + ProtoLog.d(OVERVIEW_COMMAND_HELPER, + "switching via recents animation - onGestureStarted: %s", command); + } + + public static void logSwitchingViaRecentsAnimComplete(@NonNull Object command) { + if (!isProtoLogInitialized()) return; + ProtoLog.d(OVERVIEW_COMMAND_HELPER, + "switching via recents animation - onTransitionComplete: %s", command); + } + + public static void logCommandFinishedButNotScheduled(@Nullable Object nextCommandInQueue, + @NonNull Object command) { + if (!isProtoLogInitialized()) return; + ProtoLog.d(OVERVIEW_COMMAND_HELPER, + "next task not scheduled. First pending command type is %s - command type is: %s", + nextCommandInQueue, + command); + } + + public static void logCommandFinishedSuccessfully(@NonNull Object command) { + if (!isProtoLogInitialized()) return; + ProtoLog.d(OVERVIEW_COMMAND_HELPER, "command executed successfully: %s", command); + } + + public static void logCommandCanceled(@NonNull Object command, @Nullable Throwable throwable) { + if (!isProtoLogInitialized()) return; + ProtoLog.e(OVERVIEW_COMMAND_HELPER, "command canceled: %s - %s", command, throwable); + } + + public static void logOnNewIntent(boolean alreadyOnHome, boolean shouldMoveToDefaultScreen, + String intentAction, boolean internalStateHandled) { + if (!isProtoLogInitialized()) return; + ProtoLog.d(OVERVIEW_COMMAND_HELPER, + "Launcher.onNewIntent: alreadyOnHome: %b, shouldMoveToDefaultScreen: %b, " + + "intentAction: %s, internalStateHandled: %b", + alreadyOnHome, + shouldMoveToDefaultScreen, + intentAction, + internalStateHandled); + } +} diff --git a/quickstep/src_protolog/com/android/quickstep/util/ActiveGestureProtoLogProxy.java b/quickstep/src_protolog/com/android/quickstep/util/ActiveGestureProtoLogProxy.java index cf1eb87df1..982abc844d 100644 --- a/quickstep/src_protolog/com/android/quickstep/util/ActiveGestureProtoLogProxy.java +++ b/quickstep/src_protolog/com/android/quickstep/util/ActiveGestureProtoLogProxy.java @@ -203,12 +203,6 @@ public class ActiveGestureProtoLogProxy { ProtoLog.d(ACTIVE_GESTURE_LOG, "Null mRecentTasks"); } - public static void logExecuteHomeCommand() { - ActiveGestureLog.INSTANCE.addLog("OverviewCommandHelper.executeCommand(HOME)"); - if (!isProtoLogInitialized()) return; - ProtoLog.d(ACTIVE_GESTURE_LOG, "OverviewCommandHelper.executeCommand(HOME)"); - } - public static void logFinishRecentsAnimationCallback() { ActiveGestureLog.INSTANCE.addLog("finishRecentsAnimation-callback"); if (!isProtoLogInitialized()) return; diff --git a/quickstep/src_protolog/com/android/quickstep/util/QuickstepProtoLogGroup.java b/quickstep/src_protolog/com/android/quickstep/util/QuickstepProtoLogGroup.java index 2327cfcf1d..7696a70a07 100644 --- a/quickstep/src_protolog/com/android/quickstep/util/QuickstepProtoLogGroup.java +++ b/quickstep/src_protolog/com/android/quickstep/util/QuickstepProtoLogGroup.java @@ -30,7 +30,9 @@ public enum QuickstepProtoLogGroup implements IProtoLogGroup { ACTIVE_GESTURE_LOG(true, true, Constants.DEBUG_ACTIVE_GESTURE, "ActiveGestureLog"), RECENTS_WINDOW(true, true, Constants.DEBUG_RECENTS_WINDOW, "RecentsWindow"), - LAUNCHER_STATE_MANAGER(true, true, Constants.DEBUG_STATE_MANAGER, "LauncherStateManager"); + LAUNCHER_STATE_MANAGER(true, true, Constants.DEBUG_STATE_MANAGER, "LauncherStateManager"), + OVERVIEW_COMMAND_HELPER(true, true, Constants.DEBUG_OVERVIEW_COMMAND_HELPER, + "OverviewCommandHelper"); private final boolean mEnabled; private volatile boolean mLogToProto; @@ -125,6 +127,7 @@ public enum QuickstepProtoLogGroup implements IProtoLogGroup { private static final boolean DEBUG_ACTIVE_GESTURE = false; private static final boolean DEBUG_RECENTS_WINDOW = false; private static final boolean DEBUG_STATE_MANAGER = true; // b/279059025, b/325463989 + private static final boolean DEBUG_OVERVIEW_COMMAND_HELPER = true; private static final int LOG_START_ID = (int) (UUID.nameUUIDFromBytes(QuickstepProtoLogGroup.class.getName().getBytes()) diff --git a/src/com/android/launcher3/Launcher.java b/src/com/android/launcher3/Launcher.java index 3b982debe9..0ece53d587 100644 --- a/src/com/android/launcher3/Launcher.java +++ b/src/com/android/launcher3/Launcher.java @@ -1518,6 +1518,9 @@ public class Launcher extends StatefulActivity boolean isActionMain = Intent.ACTION_MAIN.equals(intent.getAction()); boolean internalStateHandled = ACTIVITY_TRACKER.handleNewIntent(this); + logOnNewIntent(alreadyOnHome, shouldMoveToDefaultScreen, intent.getAction(), + internalStateHandled); + if (isActionMain) { if (!internalStateHandled) { // In all these cases, only animate if we're already on home @@ -1555,6 +1558,9 @@ public class Launcher extends StatefulActivity TraceHelper.INSTANCE.endSection(); } + protected void logOnNewIntent(boolean alreadyOnHome, boolean shouldMoveToDefaultScreen, + String action, boolean internalStateHandled) { } + /** Handle animating away split placeholder view when user taps on home button */ protected void handleSplitAnimationGoingToHome(EventEnum splitDismissReason) { // Overridden