From eeb7039c236d718929acd2d13774019c0c11fde5 Mon Sep 17 00:00:00 2001 From: Felipe Leme Date: Wed, 29 Jan 2020 12:15:29 -0800 Subject: [PATCH] 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) --- .../java/com/android/server/am/UserController.java | 10 +++++++++- 1 file changed, 9 insertions(+), 1 deletion(-) diff --git a/services/core/java/com/android/server/am/UserController.java b/services/core/java/com/android/server/am/UserController.java index 598a68e90aa8f..6807caec1c1b1 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 @@ class UserController implements Handler.Callback { // 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 @@ class UserController implements Handler.Callback { 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