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
This commit is contained in:
Felipe Leme
2020-01-29 12:15:29 -08:00
parent f688df3ff0
commit 48a75cbd67

View File

@@ -130,6 +130,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;
@@ -1615,9 +1619,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