From 5c7327ff2f9d926e3dd707527b01de96633385e1 Mon Sep 17 00:00:00 2001 From: Mohamad Mahmoud Date: Wed, 31 May 2023 12:00:04 +0000 Subject: [PATCH] Move dumpAnrStateAsync calls after inputDispatchingTimedOut and update the durations array Reorder the calls to dumpAnrStateAsync, placing them after the execution of ActivityManagerService.InputDispatchingTimedOut. This adjustment prevents a potential race condition that could cause a significant delay in inputDispatchingTimedOut (and consequently, the generation of the first core dump in the ANR). By making this change, we ensure that the global window lock is held first by inputDispatchingTimedOut (in the call to WindowProcessController.getInputDispatchingTimeoutMillis) Test: Tested manually Bug: 272292150 Change-Id: If48a9e5e3af38cabe618750b7989318af3fd75c4 --- .../internal/os/anr/AnrLatencyTracker.java | 35 ++++++++++++++++++- .../com/android/server/wm/AnrController.java | 26 +++++++------- 2 files changed, 47 insertions(+), 14 deletions(-) diff --git a/core/java/com/android/internal/os/anr/AnrLatencyTracker.java b/core/java/com/android/internal/os/anr/AnrLatencyTracker.java index 3ba4ea55b5d3e..80d753c7ed099 100644 --- a/core/java/com/android/internal/os/anr/AnrLatencyTracker.java +++ b/core/java/com/android/internal/os/anr/AnrLatencyTracker.java @@ -120,6 +120,10 @@ public class AnrLatencyTracker implements AutoCloseable { private long mPreDumpIfLockTooSlowStartUptime; private long mPreDumpIfLockTooSlowDuration = 0; + private long mNotifyAppUnresponsiveStartUptime; + private long mNotifyAppUnresponsiveDuration = 0; + private long mNotifyWindowUnresponsiveStartUptime; + private long mNotifyWindowUnresponsiveDuration = 0; private final int mAnrRecordPlacedOnQueueCookie = sNextAnrRecordPlacedOnQueueCookieGenerator.incrementAndGet(); @@ -425,11 +429,36 @@ public class AnrLatencyTracker implements AutoCloseable { anrSkipped("dumpStackTraces"); } + /** Records the start of AnrController#notifyAppUnresponsive. */ + public void notifyAppUnresponsiveStarted() { + mNotifyAppUnresponsiveStartUptime = getUptimeMillis(); + Trace.traceBegin(Trace.TRACE_TAG_ACTIVITY_MANAGER, "notifyAppUnresponsive()"); + } + + /** Records the end of AnrController#notifyAppUnresponsive. */ + public void notifyAppUnresponsiveEnded() { + mNotifyAppUnresponsiveDuration = getUptimeMillis() - mNotifyAppUnresponsiveStartUptime; + Trace.traceEnd(TRACE_TAG_ACTIVITY_MANAGER); + } + + /** Records the start of AnrController#notifyWindowUnresponsive. */ + public void notifyWindowUnresponsiveStarted() { + mNotifyWindowUnresponsiveStartUptime = getUptimeMillis(); + Trace.traceBegin(Trace.TRACE_TAG_ACTIVITY_MANAGER, "notifyWindowUnresponsive()"); + } + + /** Records the end of AnrController#notifyWindowUnresponsive. */ + public void notifyWindowUnresponsiveEnded() { + mNotifyWindowUnresponsiveDuration = getUptimeMillis() + - mNotifyWindowUnresponsiveStartUptime; + Trace.traceEnd(TRACE_TAG_ACTIVITY_MANAGER); + } + /** * Returns latency data as a comma separated value string for inclusion in ANR report. */ public String dumpAsCommaSeparatedArrayWithHeader() { - return "DurationsV4: " + mAnrTriggerUptime + return "DurationsV5: " + mAnrTriggerUptime /* triggering_to_app_not_responding_duration = */ + "," + (mAppNotRespondingStartUptime - mAnrTriggerUptime) /* app_not_responding_duration = */ @@ -480,6 +509,10 @@ public class AnrLatencyTracker implements AutoCloseable { + "," + (mCopyingFirstPidSucceeded ? 1 : 0) /* preDumpIfLockTooSlow_duration = */ + "," + mPreDumpIfLockTooSlowDuration + /* notifyAppUnresponsive_duration = */ + + "," + mNotifyAppUnresponsiveDuration + /* notifyWindowUnresponsive_duration = */ + + "," + mNotifyWindowUnresponsiveDuration + "\n\n"; } diff --git a/services/core/java/com/android/server/wm/AnrController.java b/services/core/java/com/android/server/wm/AnrController.java index 2df601fd1d3b6..b9f6e177e6377 100644 --- a/services/core/java/com/android/server/wm/AnrController.java +++ b/services/core/java/com/android/server/wm/AnrController.java @@ -68,7 +68,7 @@ class AnrController { void notifyAppUnresponsive(InputApplicationHandle applicationHandle, TimeoutRecord timeoutRecord) { try { - Trace.traceBegin(Trace.TRACE_TAG_ACTIVITY_MANAGER, "notifyAppUnresponsive()"); + timeoutRecord.mLatencyTracker.notifyAppUnresponsiveStarted(); timeoutRecord.mLatencyTracker.preDumpIfLockTooSlowStarted(); preDumpIfLockTooSlow(); timeoutRecord.mLatencyTracker.preDumpIfLockTooSlowEnded(); @@ -111,7 +111,6 @@ class AnrController { if (!blamePendingFocusRequest) { Slog.i(TAG_WM, "ANR in " + activity.getName() + ". Reason: " + timeoutRecord.mReason); - dumpAnrStateAsync(activity, null /* windowState */, timeoutRecord.mReason); mUnresponsiveAppByDisplay.put(activity.getDisplayId(), activity); } } @@ -123,8 +122,13 @@ class AnrController { } else { activity.inputDispatchingTimedOut(timeoutRecord, INVALID_PID); } + + if (!blamePendingFocusRequest) { + dumpAnrStateAsync(activity, null /* windowState */, timeoutRecord.mReason); + } + } finally { - Trace.traceEnd(Trace.TRACE_TAG_ACTIVITY_MANAGER); + timeoutRecord.mLatencyTracker.notifyAppUnresponsiveEnded(); } } @@ -139,7 +143,7 @@ class AnrController { void notifyWindowUnresponsive(@NonNull IBinder token, @NonNull OptionalInt pid, @NonNull TimeoutRecord timeoutRecord) { try { - Trace.traceBegin(Trace.TRACE_TAG_ACTIVITY_MANAGER, "notifyWindowUnresponsive()"); + timeoutRecord.mLatencyTracker.notifyWindowUnresponsiveStarted(); if (notifyWindowUnresponsive(token, timeoutRecord)) { return; } @@ -150,7 +154,7 @@ class AnrController { } notifyWindowUnresponsive(pid.getAsInt(), timeoutRecord); } finally { - Trace.traceEnd(Trace.TRACE_TAG_ACTIVITY_MANAGER); + timeoutRecord.mLatencyTracker.notifyWindowUnresponsiveEnded(); } } @@ -168,6 +172,7 @@ class AnrController { final int pid; final boolean aboveSystem; final ActivityRecord activity; + final WindowState windowState; timeoutRecord.mLatencyTracker.waitingOnGlobalLockStarted(); synchronized (mService.mGlobalLock) { timeoutRecord.mLatencyTracker.waitingOnGlobalLockEnded(); @@ -175,7 +180,7 @@ class AnrController { if (target == null) { return false; } - WindowState windowState = target.getWindowState(); + windowState = target.getWindowState(); pid = target.getPid(); // Blame the activity if the input token belongs to the window. If the target is // embedded, then we will blame the pid instead. @@ -183,13 +188,13 @@ class AnrController { ? windowState.mActivityRecord : null; Slog.i(TAG_WM, "ANR in " + target + ". Reason:" + timeoutRecord.mReason); aboveSystem = isWindowAboveSystem(windowState); - dumpAnrStateAsync(activity, windowState, timeoutRecord.mReason); } if (activity != null) { activity.inputDispatchingTimedOut(timeoutRecord, pid); } else { mService.mAmInternal.inputDispatchingTimedOut(pid, aboveSystem, timeoutRecord); } + dumpAnrStateAsync(activity, windowState, timeoutRecord.mReason); return true; } @@ -199,15 +204,10 @@ class AnrController { private void notifyWindowUnresponsive(int pid, TimeoutRecord timeoutRecord) { Slog.i(TAG_WM, "ANR in input window owned by pid=" + pid + ". Reason: " + timeoutRecord.mReason); - timeoutRecord.mLatencyTracker.waitingOnGlobalLockStarted(); - synchronized (mService.mGlobalLock) { - timeoutRecord.mLatencyTracker.waitingOnGlobalLockEnded(); - dumpAnrStateAsync(null /* activity */, null /* windowState */, timeoutRecord.mReason); - } - // We cannot determine the z-order of the window, so place the anr dialog as high // as possible. mService.mAmInternal.inputDispatchingTimedOut(pid, true /*aboveSystem*/, timeoutRecord); + dumpAnrStateAsync(null /* activity */, null /* windowState */, timeoutRecord.mReason); } /**