Set a shorter timeout for logging a warn on slow IUserSwitchObservers.
On automotive, it helps identify slow services. For example:
W ActivityManager: User switch delayed: observer #1
WallpaperManagerService sent result after 1608 ms
Without this change, the WallpaperManagerService wouldn't be logged
because the "give up" timeout is 3000ms.
Bug: 145558164
Bug: 144801993
Test: manual verification (see logcat above)
Change-Id: I68e3b7220bbac25075e4fd4dad83c3a26b88940c
Merged-In: I68e3b7220bbac25075e4fd4dad83c3a26b88940c
(cherry picked from commit 48a75cbd675117471f7547c84e00833c32b4a677)
diff --git a/services/core/java/com/android/server/am/UserController.java b/services/core/java/com/android/server/am/UserController.java
index 598a68e..6807cae 100644
--- a/services/core/java/com/android/server/am/UserController.java
+++ b/services/core/java/com/android/server/am/UserController.java
@@ -129,6 +129,10 @@
// giving up on them and unfreezing the screen.
static final int USER_SWITCH_TIMEOUT_MS = 3 * 1000;
+ // Amount of time we wait for observers to handle a user switch before we log a warning.
+ // Must be smaller than USER_SWITCH_TIMEOUT_MS.
+ private static final int USER_SWITCH_WARNING_TIMEOUT_MS = 500;
+
// ActivityManager thread message constants
static final int REPORT_USER_SWITCH_MSG = 10;
static final int CONTINUE_USER_SWITCH_MSG = 20;
@@ -1486,9 +1490,13 @@
synchronized (mLock) {
long delay = SystemClock.elapsedRealtime() - dispatchStartedTime;
if (delay > USER_SWITCH_TIMEOUT_MS) {
- Slog.e(TAG, "User switch timeout: observer " + name
+ Slog.e(TAG, "User switch timeout: observer " + name
+ " sent result after " + delay + " ms");
+ } else if (delay > USER_SWITCH_WARNING_TIMEOUT_MS) {
+ Slog.w(TAG, "User switch slowed down by observer " + name
+ + ": result sent after " + delay + " ms");
}
+
curWaitingUserSwitchCallbacks.remove(name);
// Continue switching if all callbacks have been notified and
// user switching session is still valid