Adds a timeout for OverviewCommandHelper commands (3/3)
We had several bugs in the past months related to recents button not displaying Overview when using 3 button navigation. For some of the bug reports, we noticed the OverviewCommandHelper pending commands list got stuck and stopped processing the next commands in the list. Sometimes, the pending commands list was cleared while some command was being processed, allowing newer commands to be executed while another command is already running. This resulted in the second callback never returning and inconsistent states for OverviewCommandHelper and RecentsView.
Our logs showed OverviewCommandHelper often got stuck and didn't finish the commands correctly.
To mitigate these issues we updated the following behaviors:
- Implemented a timeout to process the commands in the queue. If the callback doesn't return in a given time, it will drop that execution and process the next one in the queue.
- Fix clearPendingCommands to clear only the pending commands from the queue, and not the running command.
Bug: 352046797
Fix: 351122926
Fix: 361768912
Flag: EXEMPT bugfix.
Test: OverviewCommandHelperTest
Change-Id: I47adf0c54dcbaef63d9b72055e000c26114e96e1
diff --git a/aconfig/launcher_overview.aconfig b/aconfig/launcher_overview.aconfig
index e11b00c..23733a4 100644
--- a/aconfig/launcher_overview.aconfig
+++ b/aconfig/launcher_overview.aconfig
@@ -39,3 +39,12 @@
bug: "353947137"
}
+flag {
+ name: "enable_overview_command_helper_timeout"
+ namespace: "launcher_overview"
+ description: "Enables OverviewCommandHelper new version with a timeout to prevent the queue to be unresponsive."
+ bug: "351122926"
+ metadata {
+ purpose: PURPOSE_BUGFIX
+ }
+}
\ No newline at end of file
diff --git a/quickstep/src/com/android/quickstep/OverviewCommandHelper.kt b/quickstep/src/com/android/quickstep/OverviewCommandHelper.kt
index 8873275..acf54e8 100644
--- a/quickstep/src/com/android/quickstep/OverviewCommandHelper.kt
+++ b/quickstep/src/com/android/quickstep/OverviewCommandHelper.kt
@@ -25,16 +25,26 @@
import android.view.View
import androidx.annotation.BinderThread
import androidx.annotation.UiThread
+import androidx.annotation.VisibleForTesting
import com.android.internal.jank.Cuj
+import com.android.launcher3.Flags.enableOverviewCommandHelperTimeout
import com.android.launcher3.PagedView
import com.android.launcher3.config.FeatureFlags
import com.android.launcher3.logger.LauncherAtom
import com.android.launcher3.logging.StatsLogManager
-import com.android.launcher3.logging.StatsLogManager.LauncherEvent.*
+import com.android.launcher3.logging.StatsLogManager.LauncherEvent.LAUNCHER_OVERVIEW_SHOW_OVERVIEW_FROM_3_BUTTON
+import com.android.launcher3.logging.StatsLogManager.LauncherEvent.LAUNCHER_OVERVIEW_SHOW_OVERVIEW_FROM_KEYBOARD_QUICK_SWITCH
+import com.android.launcher3.logging.StatsLogManager.LauncherEvent.LAUNCHER_OVERVIEW_SHOW_OVERVIEW_FROM_KEYBOARD_SHORTCUT
import com.android.launcher3.util.Executors
import com.android.launcher3.util.RunnableList
+import com.android.launcher3.util.coroutines.DispatcherProvider
+import com.android.launcher3.util.coroutines.ProductionDispatchers
import com.android.quickstep.OverviewCommandHelper.CommandInfo.CommandStatus
-import com.android.quickstep.OverviewCommandHelper.CommandType.*
+import com.android.quickstep.OverviewCommandHelper.CommandType.HIDE
+import com.android.quickstep.OverviewCommandHelper.CommandType.HOME
+import com.android.quickstep.OverviewCommandHelper.CommandType.KEYBOARD_INPUT
+import com.android.quickstep.OverviewCommandHelper.CommandType.SHOW
+import com.android.quickstep.OverviewCommandHelper.CommandType.TOGGLE
import com.android.quickstep.util.ActiveGestureLog
import com.android.quickstep.views.RecentsView
import com.android.quickstep.views.RecentsViewContainer
@@ -43,13 +53,25 @@
import com.android.systemui.shared.system.InteractionJankMonitorWrapper
import java.io.PrintWriter
import java.util.concurrent.ConcurrentLinkedDeque
+import kotlin.coroutines.resume
+import kotlinx.coroutines.CoroutineScope
+import kotlinx.coroutines.SupervisorJob
+import kotlinx.coroutines.ensureActive
+import kotlinx.coroutines.launch
+import kotlinx.coroutines.suspendCancellableCoroutine
+import kotlinx.coroutines.withTimeout
/** Helper class to handle various atomic commands for switching between Overview. */
-class OverviewCommandHelper(
+class OverviewCommandHelper
+@JvmOverloads
+constructor(
private val touchInteractionService: TouchInteractionService,
private val overviewComponentObserver: OverviewComponentObserver,
- private val taskAnimationManager: TaskAnimationManager
+ private val taskAnimationManager: TaskAnimationManager,
+ private val dispatcherProvider: DispatcherProvider = ProductionDispatchers,
) {
+ private val coroutineScope = CoroutineScope(SupervisorJob() + dispatcherProvider.default)
+
private val commandQueue = ConcurrentLinkedDeque<CommandInfo>()
/**
@@ -79,10 +101,10 @@
* dropped.
*/
@BinderThread
- fun addCommand(type: CommandType) {
+ fun addCommand(type: CommandType): CommandInfo? {
if (commandQueue.size >= MAX_QUEUE_SIZE) {
- Log.d(TAG, "commands queue is full ($commandQueue). command not added: $type")
- return
+ Log.d(TAG, "command not added: $type - queue is full ($commandQueue).")
+ return null
}
val command = CommandInfo(type)
@@ -90,8 +112,17 @@
Log.d(TAG, "command added: $command")
if (commandQueue.size == 1) {
- Executors.MAIN_EXECUTOR.execute { executeNext() }
+ Log.d(TAG, "execute: $command - queue size: ${commandQueue.size}")
+ if (enableOverviewCommandHelperTimeout()) {
+ coroutineScope.launch(dispatcherProvider.main) { processNextCommand() }
+ } else {
+ Executors.MAIN_EXECUTOR.execute { processNextCommand() }
+ }
+ } else {
+ Log.d(TAG, "not executed: $command - queue size: ${commandQueue.size}")
}
+
+ return command
}
fun canStartHomeSafely(): Boolean = commandQueue.isEmpty() || commandQueue.first().type == HOME
@@ -108,7 +139,7 @@
* completion (returns false).
*/
@UiThread
- private fun executeNext() {
+ private fun processNextCommand() {
val command: CommandInfo =
commandQueue.firstOrNull()
?: run {
@@ -119,12 +150,22 @@
command.status = CommandStatus.PROCESSING
Log.d(TAG, "executing command: $command")
- val result = executeCommand(command)
- Log.d(TAG, "command executed: $command with result: $result")
- if (result) {
- onCommandFinished(command)
+ if (enableOverviewCommandHelperTimeout()) {
+ coroutineScope.launch(dispatcherProvider.main) {
+ withTimeout(QUEUE_WAIT_DURATION_IN_MS) {
+ executeCommandSuspended(command)
+ ensureActive()
+ onCommandFinished(command)
+ }
+ }
} else {
- Log.d(TAG, "waiting for command callback: $command")
+ val result = executeCommand(command, onCallbackResult = { onCommandFinished(command) })
+ Log.d(TAG, "command executed: $command with result: $result")
+ if (result) {
+ onCommandFinished(command)
+ } else {
+ Log.d(TAG, "waiting for command callback: $command")
+ }
}
}
@@ -132,7 +173,9 @@
* Executes the task and returns true if next task can be executed. If false, then the next task
* is deferred until [.scheduleNextTask] is called
*/
- private fun executeCommand(command: CommandInfo): Boolean {
+ @VisibleForTesting
+ fun executeCommand(command: CommandInfo, onCallbackResult: () -> Unit): Boolean {
+ // This shouldn't happen if we execute 1 command per time.
if (waitForToggleCommandComplete && command.type == TOGGLE) {
Log.d(TAG, "executeCommand: $command - waiting for toggle command complete")
return true
@@ -141,15 +184,37 @@
val recentsView = visibleRecentsView
Log.d(TAG, "executeCommand: $command - visibleRecentsView: $recentsView")
return if (recentsView != null) {
- executeWhenRecentsIsVisible(command, recentsView)
+ executeWhenRecentsIsVisible(command, recentsView, onCallbackResult)
} else {
- executeWhenRecentsIsNotVisible(command)
+ executeWhenRecentsIsNotVisible(command, onCallbackResult)
}
}
+ /**
+ * Executes the task and returns true if next task can be executed. If false, then the next task
+ * is deferred until [.scheduleNextTask] is called
+ */
+ private suspend fun executeCommandSuspended(command: CommandInfo) =
+ suspendCancellableCoroutine { continuation ->
+ fun processResult(isCompleted: Boolean) {
+ Log.d(TAG, "command executed: $command with result: $isCompleted")
+ if (isCompleted) {
+ continuation.resume(Unit)
+ } else {
+ Log.d(TAG, "waiting for command callback: $command")
+ }
+ }
+
+ val result = executeCommand(command, onCallbackResult = { processResult(true) })
+ processResult(result)
+
+ continuation.invokeOnCancellation { cancelCommand(command, it) }
+ }
+
private fun executeWhenRecentsIsVisible(
command: CommandInfo,
recentsView: RecentsView<*, *>,
+ onCallbackResult: () -> Unit,
): Boolean =
when (command.type) {
SHOW -> true // already visible
@@ -161,7 +226,7 @@
keyboardTaskFocusIndex = PagedView.INVALID_PAGE
val currentPage = recentsView.nextPage
val taskView = recentsView.getTaskViewAt(currentPage)
- launchTask(recentsView, taskView, command)
+ launchTask(recentsView, taskView, command, onCallbackResult)
}
}
TOGGLE -> {
@@ -171,7 +236,7 @@
} else {
recentsView.nextTaskView ?: recentsView.runningTaskView
}
- launchTask(recentsView, taskView, command)
+ launchTask(recentsView, taskView, command, onCallbackResult)
}
HOME -> {
recentsView.startHome()
@@ -182,7 +247,8 @@
private fun launchTask(
recents: RecentsView<*, *>,
taskView: TaskView?,
- command: CommandInfo
+ command: CommandInfo,
+ onCallbackResult: () -> Unit
): Boolean {
var callbackList: RunnableList? = null
if (taskView != null) {
@@ -194,7 +260,7 @@
if (callbackList != null) {
callbackList.add {
Log.d(TAG, "launching task callback: $command")
- onCommandFinished(command)
+ onCallbackResult()
waitForToggleCommandComplete = false
}
Log.d(TAG, "launching task - waiting for callback: $command")
@@ -206,7 +272,10 @@
}
}
- private fun executeWhenRecentsIsNotVisible(command: CommandInfo): Boolean {
+ private fun executeWhenRecentsIsNotVisible(
+ command: CommandInfo,
+ onCallbackResult: () -> Unit
+ ): Boolean {
val recentsViewContainer = activityInterface.getCreatedContainer() as? RecentsViewContainer
val recentsView: RecentsView<*, *>? = recentsViewContainer?.getOverviewPanel()
val deviceProfile = recentsViewContainer?.getDeviceProfile()
@@ -263,7 +332,7 @@
Log.d(TAG, "switching to Overview state - onAnimationEnd: $command")
super.onAnimationEnd(animation)
onRecentsViewFocusUpdated(command)
- onCommandFinished(command)
+ onCallbackResult()
}
}
if (activityInterface.switchToRecentsIfVisible(animatorListener)) {
@@ -289,7 +358,7 @@
command.createTime
)
interactionHandler.setGestureEndCallback {
- onTransitionComplete(command, interactionHandler)
+ onTransitionComplete(command, interactionHandler, onCallbackResult)
}
interactionHandler.initWhenReady("OverviewCommandHelper: command.type=${command.type}")
@@ -321,11 +390,6 @@
}
}
- // TODO(b/361768912): Dead code. Remove or update after this bug is fixed.
- // if (visibleRecentsView != null) {
- // visibleRecentsView.moveRunningTaskToFront();
- // }
-
if (taskAnimationManager.isRecentsAnimationRunning) {
command.setAnimationCallbacks(
taskAnimationManager.continueRecentsAnimation(gestureState)
@@ -351,12 +415,16 @@
return false
}
- private fun onTransitionComplete(command: CommandInfo, handler: AbsSwipeUpHandler<*, *, *>) {
+ private fun onTransitionComplete(
+ command: CommandInfo,
+ handler: AbsSwipeUpHandler<*, *, *>,
+ onCommandResult: () -> Unit
+ ) {
Log.d(TAG, "switching via recents animation - onTransitionComplete: $command")
command.removeListener(handler)
Trace.endAsyncSection(TRANSITION_NAME, 0)
onRecentsViewFocusUpdated(command)
- onCommandFinished(command)
+ onCommandResult()
}
/** Called when the command finishes execution. */
@@ -373,7 +441,14 @@
Log.d(TAG, "command executed successfully! $command")
commandQueue.remove(command)
- executeNext()
+ processNextCommand()
+ }
+
+ private fun cancelCommand(command: CommandInfo, throwable: Throwable?) {
+ command.status = CommandStatus.CANCELED
+ Log.e(TAG, "command cancelled: $command - $throwable")
+ commandQueue.remove(command)
+ processNextCommand()
}
private fun updateRecentsViewFocus(command: CommandInfo) {
@@ -447,7 +522,8 @@
pw.println(" waitForToggleCommandComplete=$waitForToggleCommandComplete")
}
- private data class CommandInfo(
+ @VisibleForTesting
+ data class CommandInfo(
val type: CommandType,
var status: CommandStatus = CommandStatus.IDLE,
val createTime: Long = SystemClock.elapsedRealtime(),
@@ -468,7 +544,8 @@
enum class CommandStatus {
IDLE,
PROCESSING,
- COMPLETED
+ COMPLETED,
+ CANCELED
}
}
@@ -489,5 +566,6 @@
* should be enough. We'll toss in one more because we're kind hearted.
*/
private const val MAX_QUEUE_SIZE = 3
+ private const val QUEUE_WAIT_DURATION_IN_MS = 5000L
}
}
diff --git a/quickstep/tests/multivalentTests/src/com/android/quickstep/OverviewCommandHelperTest.kt b/quickstep/tests/multivalentTests/src/com/android/quickstep/OverviewCommandHelperTest.kt
new file mode 100644
index 0000000..0ae710f
--- /dev/null
+++ b/quickstep/tests/multivalentTests/src/com/android/quickstep/OverviewCommandHelperTest.kt
@@ -0,0 +1,179 @@
+/*
+ * Copyright (C) 2024 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.quickstep
+
+import android.platform.test.flag.junit.SetFlagsRule
+import androidx.test.filters.SmallTest
+import com.android.launcher3.Flags
+import com.android.launcher3.util.LauncherMultivalentJUnit
+import com.android.launcher3.util.TestDispatcherProvider
+import com.android.launcher3.util.rule.setFlags
+import com.android.quickstep.OverviewCommandHelper.CommandInfo
+import com.android.quickstep.OverviewCommandHelper.CommandInfo.CommandStatus
+import com.android.quickstep.OverviewCommandHelper.CommandType
+import com.google.common.truth.Truth.assertThat
+import kotlinx.coroutines.ExperimentalCoroutinesApi
+import kotlinx.coroutines.delay
+import kotlinx.coroutines.launch
+import kotlinx.coroutines.runBlocking
+import kotlinx.coroutines.test.StandardTestDispatcher
+import kotlinx.coroutines.test.TestScope
+import kotlinx.coroutines.test.advanceTimeBy
+import kotlinx.coroutines.test.runCurrent
+import kotlinx.coroutines.test.runTest
+import org.junit.Before
+import org.junit.Rule
+import org.junit.Test
+import org.junit.runner.RunWith
+import org.mockito.Mockito.doAnswer
+import org.mockito.Mockito.spy
+import org.mockito.Mockito.`when`
+import org.mockito.kotlin.any
+import org.mockito.kotlin.mock
+
+@SmallTest
+@RunWith(LauncherMultivalentJUnit::class)
+@OptIn(ExperimentalCoroutinesApi::class)
+class OverviewCommandHelperTest {
+ @get:Rule val setFlagsRule: SetFlagsRule = SetFlagsRule()
+
+ private lateinit var sut: OverviewCommandHelper
+ private val dispatcher = StandardTestDispatcher()
+ private val testScope = TestScope(dispatcher)
+
+ private var pendingCallbacksWithDelays = mutableListOf<Long>()
+
+ @Suppress("UNCHECKED_CAST")
+ @Before
+ fun setup() {
+ setFlagsRule.setFlags(true, Flags.FLAG_ENABLE_OVERVIEW_COMMAND_HELPER_TIMEOUT)
+
+ sut =
+ spy(
+ OverviewCommandHelper(
+ touchInteractionService = mock(),
+ overviewComponentObserver = mock(),
+ taskAnimationManager = mock(),
+ dispatcherProvider = TestDispatcherProvider(dispatcher)
+ )
+ )
+
+ doAnswer { invocation ->
+ val pendingCallback = invocation.arguments[1] as () -> Unit
+
+ val delayInMillis = pendingCallbacksWithDelays.removeFirstOrNull()
+ if (delayInMillis != null) {
+ runBlocking {
+ testScope.backgroundScope.launch {
+ delay(delayInMillis)
+ pendingCallback.invoke()
+ }
+ }
+ }
+ delayInMillis == null // if no callback to execute, returns success
+ }
+ .`when`(sut)
+ .executeCommand(any<CommandInfo>(), any())
+ }
+
+ private fun addCallbackDelay(delayInMillis: Long = 0) {
+ pendingCallbacksWithDelays.add(delayInMillis)
+ }
+
+ @Test
+ fun whenFirstCommandIsAdded_executeCommandImmediately() =
+ testScope.runTest {
+ // Add command to queue
+ val commandInfo: CommandInfo = sut.addCommand(CommandType.HOME)!!
+ assertThat(commandInfo.status).isEqualTo(CommandStatus.IDLE)
+ runCurrent()
+ assertThat(commandInfo.status).isEqualTo(CommandStatus.COMPLETED)
+ }
+
+ @Test
+ fun whenFirstCommandIsAdded_executeCommandImmediately_WithCallbackDelay() =
+ testScope.runTest {
+ addCallbackDelay(100)
+
+ // Add command to queue
+ val commandType = CommandType.HOME
+ val commandInfo: CommandInfo = sut.addCommand(commandType)!!
+ assertThat(commandInfo.status).isEqualTo(CommandStatus.IDLE)
+
+ runCurrent()
+ assertThat(commandInfo.status).isEqualTo(CommandStatus.PROCESSING)
+
+ advanceTimeBy(200L)
+ assertThat(commandInfo.status).isEqualTo(CommandStatus.COMPLETED)
+ }
+
+ @Test
+ fun whenFirstCommandIsPendingCallback_NextCommandWillWait() =
+ testScope.runTest {
+ // Add command to queue
+ addCallbackDelay(100)
+ val commandType1 = CommandType.HOME
+ val commandInfo1: CommandInfo = sut.addCommand(commandType1)!!
+ assertThat(commandInfo1.status).isEqualTo(CommandStatus.IDLE)
+
+ addCallbackDelay(100)
+ val commandType2 = CommandType.SHOW
+ val commandInfo2: CommandInfo = sut.addCommand(commandType2)!!
+ assertThat(commandInfo2.status).isEqualTo(CommandStatus.IDLE)
+
+ runCurrent()
+ assertThat(commandInfo1.status).isEqualTo(CommandStatus.PROCESSING)
+ assertThat(commandInfo2.status).isEqualTo(CommandStatus.IDLE)
+
+ advanceTimeBy(101L)
+ assertThat(commandInfo1.status).isEqualTo(CommandStatus.COMPLETED)
+ assertThat(commandInfo2.status).isEqualTo(CommandStatus.PROCESSING)
+
+ advanceTimeBy(101L)
+ assertThat(commandInfo2.status).isEqualTo(CommandStatus.COMPLETED)
+ }
+
+ @Test
+ fun whenCommandTakesTooLong_TriggerTimeout_AndExecuteNextCommand() =
+ testScope.runTest {
+ // Add command to queue
+ addCallbackDelay(QUEUE_TIMEOUT)
+ val commandType1 = CommandType.HOME
+ val commandInfo1: CommandInfo = sut.addCommand(commandType1)!!
+ assertThat(commandInfo1.status).isEqualTo(CommandStatus.IDLE)
+
+ addCallbackDelay(100)
+ val commandType2 = CommandType.SHOW
+ val commandInfo2: CommandInfo = sut.addCommand(commandType2)!!
+ assertThat(commandInfo2.status).isEqualTo(CommandStatus.IDLE)
+
+ runCurrent()
+ assertThat(commandInfo1.status).isEqualTo(CommandStatus.PROCESSING)
+ assertThat(commandInfo2.status).isEqualTo(CommandStatus.IDLE)
+
+ advanceTimeBy(QUEUE_TIMEOUT)
+ assertThat(commandInfo1.status).isEqualTo(CommandStatus.CANCELED)
+ assertThat(commandInfo2.status).isEqualTo(CommandStatus.PROCESSING)
+
+ advanceTimeBy(101)
+ assertThat(commandInfo2.status).isEqualTo(CommandStatus.COMPLETED)
+ }
+
+ private companion object {
+ const val QUEUE_TIMEOUT = 5001L
+ }
+}