Loading core/java/com/android/internal/os/anr/AnrLatencyTracker.java +14 −108 Original line number Diff line number Diff line Loading @@ -18,7 +18,6 @@ package com.android.internal.os.anr; import static android.os.Trace.TRACE_TAG_ACTIVITY_MANAGER; import static com.android.internal.os.TimeoutRecord.TimeoutKind; import static com.android.internal.util.FrameworkStatsLog.ANRLATENCY_REPORTED__ANR_TYPE__BROADCAST_OF_INTENT; import static com.android.internal.util.FrameworkStatsLog.ANRLATENCY_REPORTED__ANR_TYPE__CONTENT_PROVIDER_NOT_RESPONDING; Loading @@ -29,15 +28,12 @@ import static com.android.internal.util.FrameworkStatsLog.ANRLATENCY_REPORTED__A import static com.android.internal.util.FrameworkStatsLog.ANRLATENCY_REPORTED__ANR_TYPE__START_FOREGROUND_SERVICE; import static com.android.internal.util.FrameworkStatsLog.ANRLATENCY_REPORTED__ANR_TYPE__UNKNOWN_ANR_TYPE; import android.annotation.IntDef; import android.os.SystemClock; import android.os.Trace; import com.android.internal.annotations.VisibleForTesting; import com.android.internal.util.FrameworkStatsLog; import java.lang.annotation.Retention; import java.lang.annotation.RetentionPolicy; import java.util.concurrent.atomic.AtomicInteger; /** Loading @@ -48,22 +44,6 @@ import java.util.concurrent.atomic.AtomicInteger; */ public class AnrLatencyTracker implements AutoCloseable { /** Status of the early dumped pid. */ @IntDef(value = { EarlyDumpStatus.UNKNOWN, EarlyDumpStatus.SUCCEEDED, EarlyDumpStatus.FAILED_TO_CREATE_FILE, EarlyDumpStatus.TIMED_OUT }) @Retention(RetentionPolicy.SOURCE) private @interface EarlyDumpStatus { int UNKNOWN = 1; int SUCCEEDED = 2; int FAILED_TO_CREATE_FILE = 3; int TIMED_OUT = 4; } private static final AtomicInteger sNextAnrRecordPlacedOnQueueCookieGenerator = new AtomicInteger(); Loading Loading @@ -97,16 +77,7 @@ public class AnrLatencyTracker implements AutoCloseable { private int mAnrQueueSize; private int mAnrType; private final AtomicInteger mDumpedProcessesCount = new AtomicInteger(0); private volatile @EarlyDumpStatus int mEarlyDumpStatus = EarlyDumpStatus.UNKNOWN; private volatile long mTempFileDumpingStartUptime; private volatile long mTempFileDumpingDuration = 0; private long mCopyingFirstPidStartUptime; private long mCopyingFirstPidDuration = 0; private long mEarlyDumpRequestSubmissionUptime = 0; private long mEarlyDumpExecutorPidCount = 0; private int mDumpedProcessesCount = 0; private long mFirstPidsDumpingStartUptime; private long mFirstPidsDumpingDuration = 0; Loading @@ -117,7 +88,7 @@ public class AnrLatencyTracker implements AutoCloseable { private boolean mIsPushed = false; private boolean mIsSkipped = false; private boolean mCopyingFirstPidSucceeded = false; private final int mAnrRecordPlacedOnQueueCookie = sNextAnrRecordPlacedOnQueueCookieGenerator.incrementAndGet(); Loading @@ -140,15 +111,6 @@ public class AnrLatencyTracker implements AutoCloseable { Trace.traceEnd(TRACE_TAG_ACTIVITY_MANAGER); } /** * Records the number of processes we are currently early-dumping, this number includes the * current ANR's main process. */ public void earlyDumpRequestSubmittedWithSize(int currentProcessedPidCount) { mEarlyDumpRequestSubmissionUptime = getUptimeMillis(); mEarlyDumpExecutorPidCount = currentProcessedPidCount; } /** Records the placing of the AnrHelper.AnrRecord instance on the processing queue. */ public void anrRecordPlacingOnQueueWithSize(int queueSize) { mAnrRecordPlacedOnQueueUptime = getUptimeMillis(); Loading Loading @@ -248,89 +210,48 @@ public class AnrLatencyTracker implements AutoCloseable { Trace.traceEnd(TRACE_TAG_ACTIVITY_MANAGER); } /** Records the start of pid dumping to file. */ /** Records the start of pid dumping to file (subject and criticalEventSection). */ public void dumpingPidStarted(int pid) { Trace.traceBegin(TRACE_TAG_ACTIVITY_MANAGER, "dumpingPid#" + pid); } /** Records the end of pid dumping to file. */ /** Records the end of pid dumping to file (subject and criticalEventSection). */ public void dumpingPidEnded() { mDumpedProcessesCount.incrementAndGet(); mDumpedProcessesCount++; Trace.traceEnd(TRACE_TAG_ACTIVITY_MANAGER); } /** Records the start of first pids dumping to file. */ /** Records the start of pid dumping to file (subject and criticalEventSection). */ public void dumpingFirstPidsStarted() { mFirstPidsDumpingStartUptime = getUptimeMillis(); Trace.traceBegin(TRACE_TAG_ACTIVITY_MANAGER, "dumpingFirstPids"); } /** Records the end of first pids dumping to file. */ /** Records the end of pid dumping to file (subject and criticalEventSection). */ public void dumpingFirstPidsEnded() { mFirstPidsDumpingDuration = getUptimeMillis() - mFirstPidsDumpingStartUptime; Trace.traceEnd(TRACE_TAG_ACTIVITY_MANAGER); } /** Records the start of the copying of the pre-dumped first pid. */ public void copyingFirstPidStarted() { mCopyingFirstPidStartUptime = getUptimeMillis(); Trace.traceBegin(TRACE_TAG_ACTIVITY_MANAGER, "copyingFirstPid"); } /** Records the end of the copying of the pre-dumped first pid. */ public void copyingFirstPidEnded(boolean copySucceeded) { mCopyingFirstPidDuration = getUptimeMillis() - mCopyingFirstPidStartUptime; mCopyingFirstPidSucceeded = copySucceeded; Trace.traceEnd(TRACE_TAG_ACTIVITY_MANAGER); } /** Records the start of pre-dumping. */ public void dumpStackTracesTempFileStarted() { mTempFileDumpingStartUptime = getUptimeMillis(); Trace.traceBegin(TRACE_TAG_ACTIVITY_MANAGER, "dumpStackTracesTempFile"); } /** Records the end of pre-dumping. */ public void dumpStackTracesTempFileEnded() { mTempFileDumpingDuration = getUptimeMillis() - mTempFileDumpingStartUptime; if (mEarlyDumpStatus == EarlyDumpStatus.UNKNOWN) { mEarlyDumpStatus = EarlyDumpStatus.SUCCEEDED; } Trace.traceEnd(TRACE_TAG_ACTIVITY_MANAGER); } /** Records file creation failure events in dumpStackTracesTempFile. */ public void dumpStackTracesTempFileCreationFailed() { mEarlyDumpStatus = EarlyDumpStatus.FAILED_TO_CREATE_FILE; Trace.instant(TRACE_TAG_ACTIVITY_MANAGER, "dumpStackTracesTempFileCreationFailed"); } /** Records timeout events in dumpStackTracesTempFile. */ public void dumpStackTracesTempFileTimedOut() { mEarlyDumpStatus = EarlyDumpStatus.TIMED_OUT; Trace.instant(TRACE_TAG_ACTIVITY_MANAGER, "dumpStackTracesTempFileTimedOut"); } /** Records the start of native pids dumping to file. */ /** Records the start of pid dumping to file (subject and criticalEventSection). */ public void dumpingNativePidsStarted() { mNativePidsDumpingStartUptime = getUptimeMillis(); Trace.traceBegin(TRACE_TAG_ACTIVITY_MANAGER, "dumpingNativePids"); } /** Records the end of native pids dumping to file . */ /** Records the end of pid dumping to file (subject and criticalEventSection). */ public void dumpingNativePidsEnded() { mNativePidsDumpingDuration = getUptimeMillis() - mNativePidsDumpingStartUptime; Trace.traceEnd(TRACE_TAG_ACTIVITY_MANAGER); } /** Records the start of extra pids dumping to file. */ /** Records the start of pid dumping to file (subject and criticalEventSection). */ public void dumpingExtraPidsStarted() { mExtraPidsDumpingStartUptime = getUptimeMillis(); Trace.traceBegin(TRACE_TAG_ACTIVITY_MANAGER, "dumpingExtraPids"); } /** Records the end of extra pids dumping to file. */ /** Records the end of pid dumping to file (subject and criticalEventSection). */ public void dumpingExtraPidsEnded() { mExtraPidsDumpingDuration = getUptimeMillis() - mExtraPidsDumpingStartUptime; Trace.traceEnd(TRACE_TAG_ACTIVITY_MANAGER); Loading Loading @@ -416,7 +337,7 @@ public class AnrLatencyTracker implements AutoCloseable { * Returns latency data as a comma separated value string for inclusion in ANR report. */ public String dumpAsCommaSeparatedArrayWithHeader() { return "DurationsV3: " + mAnrTriggerUptime return "DurationsV2: " + mAnrTriggerUptime /* triggering_to_app_not_responding_duration = */ + "," + (mAppNotRespondingStartUptime - mAnrTriggerUptime) /* app_not_responding_duration = */ Loading Loading @@ -449,22 +370,7 @@ public class AnrLatencyTracker implements AutoCloseable { /* anr_queue_size_when_pushed = */ + "," + mAnrQueueSize /* dump_stack_traces_io_time = */ // We use copyingFirstPidUptime if we're dumping the durations list before the // first pids ie after copying the early dump stacks. + "," + ((mFirstPidsDumpingStartUptime > 0 ? mFirstPidsDumpingStartUptime : mCopyingFirstPidStartUptime) - mDumpStackTracesStartUptime) /* temp_file_dump_duration = */ + "," + mTempFileDumpingDuration /* temp_dump_request_on_queue_duration = */ + "," + (mTempFileDumpingStartUptime - mEarlyDumpRequestSubmissionUptime) /* temp_dump_pid_count_when_pushed = */ + "," + mEarlyDumpExecutorPidCount /* first_pid_copying_time = */ + "," + mCopyingFirstPidDuration /* early_dump_status = */ + "," + mEarlyDumpStatus /* copying_first_pid_succeeded = */ + "," + (mCopyingFirstPidSucceeded ? 1 : 0) + "," + (mFirstPidsDumpingStartUptime - mDumpStackTracesStartUptime) + "\n\n"; } Loading Loading @@ -543,7 +449,7 @@ public class AnrLatencyTracker implements AutoCloseable { /* anr_queue_size_when_pushed = */ mAnrQueueSize, /* anr_type = */ mAnrType, /* dumped_processes_count = */ mDumpedProcessesCount.get()); /* dumped_processes_count = */ mDumpedProcessesCount); } private void anrSkipped(String method) { Loading core/tests/coretests/src/android/internal/os/anr/AnrLatencyTrackerTests.java +2 −27 Original line number Diff line number Diff line Loading @@ -59,10 +59,7 @@ public class AnrLatencyTrackerTests { .thenReturn(175L) .thenReturn(198L) .thenReturn(203L) .thenReturn(209L) .thenReturn(211L) .thenReturn(212L) .thenReturn(220L); .thenReturn(209L); } @Test Loading @@ -71,7 +68,6 @@ public class AnrLatencyTrackerTests { mLatencyTracker.appNotRespondingStarted(); mLatencyTracker.waitingOnAnrRecordLockStarted(); mLatencyTracker.waitingOnAnrRecordLockEnded(); mLatencyTracker.earlyDumpRequestSubmittedWithSize(5); mLatencyTracker.anrRecordPlacingOnQueueWithSize(3); mLatencyTracker.appNotRespondingEnded(); Loading @@ -94,16 +90,7 @@ public class AnrLatencyTrackerTests { mLatencyTracker.waitingOnProcLockStarted(); mLatencyTracker.waitingOnProcLockEnded(); mLatencyTracker.dumpStackTracesTempFileStarted(); mLatencyTracker.dumpingPidStarted(5); mLatencyTracker.dumpStackTracesStarted(); mLatencyTracker.copyingFirstPidStarted(); mLatencyTracker.dumpingPidEnded(); mLatencyTracker.dumpStackTracesTempFileEnded(); mLatencyTracker.copyingFirstPidEnded(true); mLatencyTracker.dumpingFirstPidsStarted(); mLatencyTracker.dumpingPidStarted(1); mLatencyTracker.dumpingPidEnded(); Loading @@ -124,7 +111,7 @@ public class AnrLatencyTrackerTests { mLatencyTracker.close(); assertThat(mLatencyTracker.dumpAsCommaSeparatedArrayWithHeader()) .isEqualTo("DurationsV3: 50,5,33,11,112,4,2,4,6,5,1,10,5,10,3,9,11,129,5,8,1\n\n"); .isEqualTo("DurationsV2: 50,5,25,8,115,2,3,7,8,15,2,7,23,10,3,6\n\n"); verify(mLatencyTracker, times(1)).pushAtom(); } Loading @@ -134,7 +121,6 @@ public class AnrLatencyTrackerTests { mLatencyTracker.appNotRespondingStarted(); mLatencyTracker.waitingOnAnrRecordLockStarted(); mLatencyTracker.waitingOnAnrRecordLockEnded(); mLatencyTracker.earlyDumpRequestSubmittedWithSize(5); mLatencyTracker.anrRecordPlacingOnQueueWithSize(3); mLatencyTracker.appNotRespondingEnded(); Loading @@ -157,18 +143,7 @@ public class AnrLatencyTrackerTests { mLatencyTracker.waitingOnProcLockStarted(); mLatencyTracker.waitingOnProcLockEnded(); mLatencyTracker.dumpStackTracesTempFileStarted(); mLatencyTracker.dumpingPidStarted(5); mLatencyTracker.dumpStackTracesStarted(); mLatencyTracker.copyingFirstPidStarted(); mLatencyTracker.dumpingPidEnded(); mLatencyTracker.dumpStackTracesTempFileEnded(); mLatencyTracker.copyingFirstPidEnded(true); mLatencyTracker.dumpingFirstPidsStarted(); mLatencyTracker.dumpingPidStarted(1); mLatencyTracker.dumpingPidEnded(); Loading services/core/java/com/android/server/am/AnrHelper.java +12 −49 Original line number Diff line number Diff line Loading @@ -22,7 +22,6 @@ import static com.android.server.am.ActivityManagerDebugConfig.TAG_WITH_CLASS_NA import android.content.pm.ApplicationInfo; import android.os.SystemClock; import android.os.Trace; import android.util.ArraySet; import android.util.Slog; import com.android.internal.annotations.GuardedBy; Loading @@ -30,12 +29,8 @@ import com.android.internal.annotations.VisibleForTesting; import com.android.internal.os.TimeoutRecord; import com.android.server.wm.WindowProcessController; import java.io.File; import java.util.ArrayList; import java.util.Collections; import java.util.Set; import java.util.concurrent.ExecutorService; import java.util.concurrent.Future; import java.util.concurrent.LinkedBlockingQueue; import java.util.concurrent.ThreadFactory; import java.util.concurrent.ThreadPoolExecutor; Loading Loading @@ -64,19 +59,13 @@ class AnrHelper { /** * The keep alive time for the threads in the helper threadpool executor */ private static final int DEFAULT_THREAD_KEEP_ALIVE_SECOND = 10; private static final int AUX_THREAD_KEEP_ALIVE_SECOND = 10; private static final ThreadFactory sDefaultThreadFactory = r -> new Thread(r, "AnrAuxiliaryTaskExecutor"); private static final ThreadFactory sMainProcessDumpThreadFactory = r -> new Thread(r, "AnrMainProcessDumpThread"); @GuardedBy("mAnrRecords") private final ArrayList<AnrRecord> mAnrRecords = new ArrayList<>(); private final Set<Integer> mTempDumpedPids = Collections.synchronizedSet(new ArraySet<Integer>()); private final AtomicBoolean mRunning = new AtomicBoolean(false); private final ActivityManagerService mService; Loading @@ -91,23 +80,17 @@ class AnrHelper { private int mProcessingPid = -1; private final ExecutorService mAuxiliaryTaskExecutor; private final ExecutorService mEarlyDumpExecutor; AnrHelper(final ActivityManagerService service) { this(service, new ThreadPoolExecutor(/* corePoolSize= */ 0, /* maximumPoolSize= */ 1, /* keepAliveTime= */ DEFAULT_THREAD_KEEP_ALIVE_SECOND, TimeUnit.SECONDS, new LinkedBlockingQueue<>(), sDefaultThreadFactory), new ThreadPoolExecutor(/* corePoolSize= */ 0, /* maximumPoolSize= */ 2, /* keepAliveTime= */ DEFAULT_THREAD_KEEP_ALIVE_SECOND, TimeUnit.SECONDS, new LinkedBlockingQueue<>(), sMainProcessDumpThreadFactory)); /* keepAliveTime= */ AUX_THREAD_KEEP_ALIVE_SECOND, TimeUnit.SECONDS, new LinkedBlockingQueue<>(), sDefaultThreadFactory)); } @VisibleForTesting AnrHelper(ActivityManagerService service, ExecutorService auxExecutor, ExecutorService earlyDumpExecutor) { AnrHelper(ActivityManagerService service, ExecutorService auxExecutor) { mService = service; mAuxiliaryTaskExecutor = auxExecutor; mEarlyDumpExecutor = earlyDumpExecutor; } void appNotResponding(ProcessRecord anrProcess, TimeoutRecord timeoutRecord) { Loading Loading @@ -138,12 +121,6 @@ class AnrHelper { + timeoutRecord.mReason); return; } if (!mTempDumpedPids.add(incomingPid)) { Slog.i(TAG, "Skip ANR being predumped, pid=" + incomingPid + " " + timeoutRecord.mReason); return; } for (int i = mAnrRecords.size() - 1; i >= 0; i--) { if (mAnrRecords.get(i).mPid == incomingPid) { Slog.i(TAG, Loading @@ -152,24 +129,10 @@ class AnrHelper { return; } } // We dump the main process as soon as we can on a different thread, // this is done as the main process's dump can go stale in a few hundred // milliseconds and the average full ANR dump takes a few seconds. timeoutRecord.mLatencyTracker.earlyDumpRequestSubmittedWithSize( mTempDumpedPids.size()); Future<File> firstPidDumpPromise = mEarlyDumpExecutor.submit(() -> { // the class AnrLatencyTracker is not generally thread safe but the values // recorded/touched by the Temporary dump thread(s) are all volatile/atomic. File tracesFile = StackTracesDumpHelper.dumpStackTracesTempFile(incomingPid, timeoutRecord.mLatencyTracker); mTempDumpedPids.remove(incomingPid); return tracesFile; }); timeoutRecord.mLatencyTracker.anrRecordPlacingOnQueueWithSize(mAnrRecords.size()); mAnrRecords.add(new AnrRecord(anrProcess, activityShortComponentName, aInfo, parentShortComponentName, parentProcess, aboveSystem, timeoutRecord, isContinuousAnr, firstPidDumpPromise)); parentShortComponentName, parentProcess, aboveSystem, mAuxiliaryTaskExecutor, timeoutRecord, isContinuousAnr)); } startAnrConsumerIfNeeded(); } finally { Loading Loading @@ -256,7 +219,7 @@ class AnrHelper { } } private class AnrRecord { private static class AnrRecord { final ProcessRecord mApp; final int mPid; final String mActivityShortComponentName; Loading @@ -265,14 +228,14 @@ class AnrHelper { final ApplicationInfo mAppInfo; final WindowProcessController mParentProcess; final boolean mAboveSystem; final ExecutorService mAuxiliaryTaskExecutor; final long mTimestamp = SystemClock.uptimeMillis(); final boolean mIsContinuousAnr; final Future<File> mFirstPidFilePromise; AnrRecord(ProcessRecord anrProcess, String activityShortComponentName, ApplicationInfo aInfo, String parentShortComponentName, WindowProcessController parentProcess, boolean aboveSystem, TimeoutRecord timeoutRecord, boolean isContinuousAnr, Future<File> firstPidFilePromise) { ExecutorService auxiliaryTaskExecutor, TimeoutRecord timeoutRecord, boolean isContinuousAnr) { mApp = anrProcess; mPid = anrProcess.mPid; mActivityShortComponentName = activityShortComponentName; Loading @@ -281,8 +244,8 @@ class AnrHelper { mAppInfo = aInfo; mParentProcess = parentProcess; mAboveSystem = aboveSystem; mAuxiliaryTaskExecutor = auxiliaryTaskExecutor; mIsContinuousAnr = isContinuousAnr; mFirstPidFilePromise = firstPidFilePromise; } void appNotResponding(boolean onlyDumpSelf) { Loading @@ -291,7 +254,7 @@ class AnrHelper { mApp.mErrorState.appNotResponding(mActivityShortComponentName, mAppInfo, mParentShortComponentName, mParentProcess, mAboveSystem, mTimeoutRecord, mAuxiliaryTaskExecutor, onlyDumpSelf, mIsContinuousAnr, mFirstPidFilePromise); mIsContinuousAnr); } finally { mTimeoutRecord.mLatencyTracker.anrProcessingEnded(); } Loading services/core/java/com/android/server/am/ProcessErrorStateRecord.java +3 −5 Original line number Diff line number Diff line Loading @@ -287,7 +287,7 @@ class ProcessErrorStateRecord { String parentShortComponentName, WindowProcessController parentProcess, boolean aboveSystem, TimeoutRecord timeoutRecord, ExecutorService auxiliaryTaskExecutor, boolean onlyDumpSelf, boolean isContinuousAnr, Future<File> firstPidFilePromise) { boolean isContinuousAnr) { String annotation = timeoutRecord.mReason; AnrLatencyTracker latencyTracker = timeoutRecord.mLatencyTracker; Future<?> updateCpuStatsNowFirstCall = null; Loading Loading @@ -334,6 +334,7 @@ class ProcessErrorStateRecord { Counter.logIncrement("stability_anr.value_skipped_anrs"); return; } // In case we come through here for the same app before completing // this one, mark as anring now so we will bail out. latencyTracker.waitingOnProcLockStarted(); Loading Loading @@ -367,9 +368,6 @@ class ProcessErrorStateRecord { firstPids.add(pid); // Don't dump other PIDs if it's a background ANR or is requested to only dump self. // Note that the primary pid is added here just in case, as it should normally be // dumped on the early dump thread, and would only be dumped on the Anr consumer thread // as a fallback. isSilentAnr = isSilentAnr(); if (!isSilentAnr && !onlyDumpSelf) { int parentPid = pid; Loading Loading @@ -500,7 +498,7 @@ class ProcessErrorStateRecord { File tracesFile = StackTracesDumpHelper.dumpStackTraces(firstPids, isSilentAnr ? null : processCpuTracker, isSilentAnr ? null : lastPids, nativePidsFuture, tracesFileException, firstPidEndOffset, annotation, criticalEventLog, auxiliaryTaskExecutor, firstPidFilePromise, latencyTracker); criticalEventLog, auxiliaryTaskExecutor, latencyTracker); if (isMonitorCpuUsage()) { // Wait for the first call to finish Loading services/core/java/com/android/server/am/StackTracesDumpHelper.java +29 −161 File changed.Preview size limit exceeded, changes collapsed. Show changes Loading
core/java/com/android/internal/os/anr/AnrLatencyTracker.java +14 −108 Original line number Diff line number Diff line Loading @@ -18,7 +18,6 @@ package com.android.internal.os.anr; import static android.os.Trace.TRACE_TAG_ACTIVITY_MANAGER; import static com.android.internal.os.TimeoutRecord.TimeoutKind; import static com.android.internal.util.FrameworkStatsLog.ANRLATENCY_REPORTED__ANR_TYPE__BROADCAST_OF_INTENT; import static com.android.internal.util.FrameworkStatsLog.ANRLATENCY_REPORTED__ANR_TYPE__CONTENT_PROVIDER_NOT_RESPONDING; Loading @@ -29,15 +28,12 @@ import static com.android.internal.util.FrameworkStatsLog.ANRLATENCY_REPORTED__A import static com.android.internal.util.FrameworkStatsLog.ANRLATENCY_REPORTED__ANR_TYPE__START_FOREGROUND_SERVICE; import static com.android.internal.util.FrameworkStatsLog.ANRLATENCY_REPORTED__ANR_TYPE__UNKNOWN_ANR_TYPE; import android.annotation.IntDef; import android.os.SystemClock; import android.os.Trace; import com.android.internal.annotations.VisibleForTesting; import com.android.internal.util.FrameworkStatsLog; import java.lang.annotation.Retention; import java.lang.annotation.RetentionPolicy; import java.util.concurrent.atomic.AtomicInteger; /** Loading @@ -48,22 +44,6 @@ import java.util.concurrent.atomic.AtomicInteger; */ public class AnrLatencyTracker implements AutoCloseable { /** Status of the early dumped pid. */ @IntDef(value = { EarlyDumpStatus.UNKNOWN, EarlyDumpStatus.SUCCEEDED, EarlyDumpStatus.FAILED_TO_CREATE_FILE, EarlyDumpStatus.TIMED_OUT }) @Retention(RetentionPolicy.SOURCE) private @interface EarlyDumpStatus { int UNKNOWN = 1; int SUCCEEDED = 2; int FAILED_TO_CREATE_FILE = 3; int TIMED_OUT = 4; } private static final AtomicInteger sNextAnrRecordPlacedOnQueueCookieGenerator = new AtomicInteger(); Loading Loading @@ -97,16 +77,7 @@ public class AnrLatencyTracker implements AutoCloseable { private int mAnrQueueSize; private int mAnrType; private final AtomicInteger mDumpedProcessesCount = new AtomicInteger(0); private volatile @EarlyDumpStatus int mEarlyDumpStatus = EarlyDumpStatus.UNKNOWN; private volatile long mTempFileDumpingStartUptime; private volatile long mTempFileDumpingDuration = 0; private long mCopyingFirstPidStartUptime; private long mCopyingFirstPidDuration = 0; private long mEarlyDumpRequestSubmissionUptime = 0; private long mEarlyDumpExecutorPidCount = 0; private int mDumpedProcessesCount = 0; private long mFirstPidsDumpingStartUptime; private long mFirstPidsDumpingDuration = 0; Loading @@ -117,7 +88,7 @@ public class AnrLatencyTracker implements AutoCloseable { private boolean mIsPushed = false; private boolean mIsSkipped = false; private boolean mCopyingFirstPidSucceeded = false; private final int mAnrRecordPlacedOnQueueCookie = sNextAnrRecordPlacedOnQueueCookieGenerator.incrementAndGet(); Loading @@ -140,15 +111,6 @@ public class AnrLatencyTracker implements AutoCloseable { Trace.traceEnd(TRACE_TAG_ACTIVITY_MANAGER); } /** * Records the number of processes we are currently early-dumping, this number includes the * current ANR's main process. */ public void earlyDumpRequestSubmittedWithSize(int currentProcessedPidCount) { mEarlyDumpRequestSubmissionUptime = getUptimeMillis(); mEarlyDumpExecutorPidCount = currentProcessedPidCount; } /** Records the placing of the AnrHelper.AnrRecord instance on the processing queue. */ public void anrRecordPlacingOnQueueWithSize(int queueSize) { mAnrRecordPlacedOnQueueUptime = getUptimeMillis(); Loading Loading @@ -248,89 +210,48 @@ public class AnrLatencyTracker implements AutoCloseable { Trace.traceEnd(TRACE_TAG_ACTIVITY_MANAGER); } /** Records the start of pid dumping to file. */ /** Records the start of pid dumping to file (subject and criticalEventSection). */ public void dumpingPidStarted(int pid) { Trace.traceBegin(TRACE_TAG_ACTIVITY_MANAGER, "dumpingPid#" + pid); } /** Records the end of pid dumping to file. */ /** Records the end of pid dumping to file (subject and criticalEventSection). */ public void dumpingPidEnded() { mDumpedProcessesCount.incrementAndGet(); mDumpedProcessesCount++; Trace.traceEnd(TRACE_TAG_ACTIVITY_MANAGER); } /** Records the start of first pids dumping to file. */ /** Records the start of pid dumping to file (subject and criticalEventSection). */ public void dumpingFirstPidsStarted() { mFirstPidsDumpingStartUptime = getUptimeMillis(); Trace.traceBegin(TRACE_TAG_ACTIVITY_MANAGER, "dumpingFirstPids"); } /** Records the end of first pids dumping to file. */ /** Records the end of pid dumping to file (subject and criticalEventSection). */ public void dumpingFirstPidsEnded() { mFirstPidsDumpingDuration = getUptimeMillis() - mFirstPidsDumpingStartUptime; Trace.traceEnd(TRACE_TAG_ACTIVITY_MANAGER); } /** Records the start of the copying of the pre-dumped first pid. */ public void copyingFirstPidStarted() { mCopyingFirstPidStartUptime = getUptimeMillis(); Trace.traceBegin(TRACE_TAG_ACTIVITY_MANAGER, "copyingFirstPid"); } /** Records the end of the copying of the pre-dumped first pid. */ public void copyingFirstPidEnded(boolean copySucceeded) { mCopyingFirstPidDuration = getUptimeMillis() - mCopyingFirstPidStartUptime; mCopyingFirstPidSucceeded = copySucceeded; Trace.traceEnd(TRACE_TAG_ACTIVITY_MANAGER); } /** Records the start of pre-dumping. */ public void dumpStackTracesTempFileStarted() { mTempFileDumpingStartUptime = getUptimeMillis(); Trace.traceBegin(TRACE_TAG_ACTIVITY_MANAGER, "dumpStackTracesTempFile"); } /** Records the end of pre-dumping. */ public void dumpStackTracesTempFileEnded() { mTempFileDumpingDuration = getUptimeMillis() - mTempFileDumpingStartUptime; if (mEarlyDumpStatus == EarlyDumpStatus.UNKNOWN) { mEarlyDumpStatus = EarlyDumpStatus.SUCCEEDED; } Trace.traceEnd(TRACE_TAG_ACTIVITY_MANAGER); } /** Records file creation failure events in dumpStackTracesTempFile. */ public void dumpStackTracesTempFileCreationFailed() { mEarlyDumpStatus = EarlyDumpStatus.FAILED_TO_CREATE_FILE; Trace.instant(TRACE_TAG_ACTIVITY_MANAGER, "dumpStackTracesTempFileCreationFailed"); } /** Records timeout events in dumpStackTracesTempFile. */ public void dumpStackTracesTempFileTimedOut() { mEarlyDumpStatus = EarlyDumpStatus.TIMED_OUT; Trace.instant(TRACE_TAG_ACTIVITY_MANAGER, "dumpStackTracesTempFileTimedOut"); } /** Records the start of native pids dumping to file. */ /** Records the start of pid dumping to file (subject and criticalEventSection). */ public void dumpingNativePidsStarted() { mNativePidsDumpingStartUptime = getUptimeMillis(); Trace.traceBegin(TRACE_TAG_ACTIVITY_MANAGER, "dumpingNativePids"); } /** Records the end of native pids dumping to file . */ /** Records the end of pid dumping to file (subject and criticalEventSection). */ public void dumpingNativePidsEnded() { mNativePidsDumpingDuration = getUptimeMillis() - mNativePidsDumpingStartUptime; Trace.traceEnd(TRACE_TAG_ACTIVITY_MANAGER); } /** Records the start of extra pids dumping to file. */ /** Records the start of pid dumping to file (subject and criticalEventSection). */ public void dumpingExtraPidsStarted() { mExtraPidsDumpingStartUptime = getUptimeMillis(); Trace.traceBegin(TRACE_TAG_ACTIVITY_MANAGER, "dumpingExtraPids"); } /** Records the end of extra pids dumping to file. */ /** Records the end of pid dumping to file (subject and criticalEventSection). */ public void dumpingExtraPidsEnded() { mExtraPidsDumpingDuration = getUptimeMillis() - mExtraPidsDumpingStartUptime; Trace.traceEnd(TRACE_TAG_ACTIVITY_MANAGER); Loading Loading @@ -416,7 +337,7 @@ public class AnrLatencyTracker implements AutoCloseable { * Returns latency data as a comma separated value string for inclusion in ANR report. */ public String dumpAsCommaSeparatedArrayWithHeader() { return "DurationsV3: " + mAnrTriggerUptime return "DurationsV2: " + mAnrTriggerUptime /* triggering_to_app_not_responding_duration = */ + "," + (mAppNotRespondingStartUptime - mAnrTriggerUptime) /* app_not_responding_duration = */ Loading Loading @@ -449,22 +370,7 @@ public class AnrLatencyTracker implements AutoCloseable { /* anr_queue_size_when_pushed = */ + "," + mAnrQueueSize /* dump_stack_traces_io_time = */ // We use copyingFirstPidUptime if we're dumping the durations list before the // first pids ie after copying the early dump stacks. + "," + ((mFirstPidsDumpingStartUptime > 0 ? mFirstPidsDumpingStartUptime : mCopyingFirstPidStartUptime) - mDumpStackTracesStartUptime) /* temp_file_dump_duration = */ + "," + mTempFileDumpingDuration /* temp_dump_request_on_queue_duration = */ + "," + (mTempFileDumpingStartUptime - mEarlyDumpRequestSubmissionUptime) /* temp_dump_pid_count_when_pushed = */ + "," + mEarlyDumpExecutorPidCount /* first_pid_copying_time = */ + "," + mCopyingFirstPidDuration /* early_dump_status = */ + "," + mEarlyDumpStatus /* copying_first_pid_succeeded = */ + "," + (mCopyingFirstPidSucceeded ? 1 : 0) + "," + (mFirstPidsDumpingStartUptime - mDumpStackTracesStartUptime) + "\n\n"; } Loading Loading @@ -543,7 +449,7 @@ public class AnrLatencyTracker implements AutoCloseable { /* anr_queue_size_when_pushed = */ mAnrQueueSize, /* anr_type = */ mAnrType, /* dumped_processes_count = */ mDumpedProcessesCount.get()); /* dumped_processes_count = */ mDumpedProcessesCount); } private void anrSkipped(String method) { Loading
core/tests/coretests/src/android/internal/os/anr/AnrLatencyTrackerTests.java +2 −27 Original line number Diff line number Diff line Loading @@ -59,10 +59,7 @@ public class AnrLatencyTrackerTests { .thenReturn(175L) .thenReturn(198L) .thenReturn(203L) .thenReturn(209L) .thenReturn(211L) .thenReturn(212L) .thenReturn(220L); .thenReturn(209L); } @Test Loading @@ -71,7 +68,6 @@ public class AnrLatencyTrackerTests { mLatencyTracker.appNotRespondingStarted(); mLatencyTracker.waitingOnAnrRecordLockStarted(); mLatencyTracker.waitingOnAnrRecordLockEnded(); mLatencyTracker.earlyDumpRequestSubmittedWithSize(5); mLatencyTracker.anrRecordPlacingOnQueueWithSize(3); mLatencyTracker.appNotRespondingEnded(); Loading @@ -94,16 +90,7 @@ public class AnrLatencyTrackerTests { mLatencyTracker.waitingOnProcLockStarted(); mLatencyTracker.waitingOnProcLockEnded(); mLatencyTracker.dumpStackTracesTempFileStarted(); mLatencyTracker.dumpingPidStarted(5); mLatencyTracker.dumpStackTracesStarted(); mLatencyTracker.copyingFirstPidStarted(); mLatencyTracker.dumpingPidEnded(); mLatencyTracker.dumpStackTracesTempFileEnded(); mLatencyTracker.copyingFirstPidEnded(true); mLatencyTracker.dumpingFirstPidsStarted(); mLatencyTracker.dumpingPidStarted(1); mLatencyTracker.dumpingPidEnded(); Loading @@ -124,7 +111,7 @@ public class AnrLatencyTrackerTests { mLatencyTracker.close(); assertThat(mLatencyTracker.dumpAsCommaSeparatedArrayWithHeader()) .isEqualTo("DurationsV3: 50,5,33,11,112,4,2,4,6,5,1,10,5,10,3,9,11,129,5,8,1\n\n"); .isEqualTo("DurationsV2: 50,5,25,8,115,2,3,7,8,15,2,7,23,10,3,6\n\n"); verify(mLatencyTracker, times(1)).pushAtom(); } Loading @@ -134,7 +121,6 @@ public class AnrLatencyTrackerTests { mLatencyTracker.appNotRespondingStarted(); mLatencyTracker.waitingOnAnrRecordLockStarted(); mLatencyTracker.waitingOnAnrRecordLockEnded(); mLatencyTracker.earlyDumpRequestSubmittedWithSize(5); mLatencyTracker.anrRecordPlacingOnQueueWithSize(3); mLatencyTracker.appNotRespondingEnded(); Loading @@ -157,18 +143,7 @@ public class AnrLatencyTrackerTests { mLatencyTracker.waitingOnProcLockStarted(); mLatencyTracker.waitingOnProcLockEnded(); mLatencyTracker.dumpStackTracesTempFileStarted(); mLatencyTracker.dumpingPidStarted(5); mLatencyTracker.dumpStackTracesStarted(); mLatencyTracker.copyingFirstPidStarted(); mLatencyTracker.dumpingPidEnded(); mLatencyTracker.dumpStackTracesTempFileEnded(); mLatencyTracker.copyingFirstPidEnded(true); mLatencyTracker.dumpingFirstPidsStarted(); mLatencyTracker.dumpingPidStarted(1); mLatencyTracker.dumpingPidEnded(); Loading
services/core/java/com/android/server/am/AnrHelper.java +12 −49 Original line number Diff line number Diff line Loading @@ -22,7 +22,6 @@ import static com.android.server.am.ActivityManagerDebugConfig.TAG_WITH_CLASS_NA import android.content.pm.ApplicationInfo; import android.os.SystemClock; import android.os.Trace; import android.util.ArraySet; import android.util.Slog; import com.android.internal.annotations.GuardedBy; Loading @@ -30,12 +29,8 @@ import com.android.internal.annotations.VisibleForTesting; import com.android.internal.os.TimeoutRecord; import com.android.server.wm.WindowProcessController; import java.io.File; import java.util.ArrayList; import java.util.Collections; import java.util.Set; import java.util.concurrent.ExecutorService; import java.util.concurrent.Future; import java.util.concurrent.LinkedBlockingQueue; import java.util.concurrent.ThreadFactory; import java.util.concurrent.ThreadPoolExecutor; Loading Loading @@ -64,19 +59,13 @@ class AnrHelper { /** * The keep alive time for the threads in the helper threadpool executor */ private static final int DEFAULT_THREAD_KEEP_ALIVE_SECOND = 10; private static final int AUX_THREAD_KEEP_ALIVE_SECOND = 10; private static final ThreadFactory sDefaultThreadFactory = r -> new Thread(r, "AnrAuxiliaryTaskExecutor"); private static final ThreadFactory sMainProcessDumpThreadFactory = r -> new Thread(r, "AnrMainProcessDumpThread"); @GuardedBy("mAnrRecords") private final ArrayList<AnrRecord> mAnrRecords = new ArrayList<>(); private final Set<Integer> mTempDumpedPids = Collections.synchronizedSet(new ArraySet<Integer>()); private final AtomicBoolean mRunning = new AtomicBoolean(false); private final ActivityManagerService mService; Loading @@ -91,23 +80,17 @@ class AnrHelper { private int mProcessingPid = -1; private final ExecutorService mAuxiliaryTaskExecutor; private final ExecutorService mEarlyDumpExecutor; AnrHelper(final ActivityManagerService service) { this(service, new ThreadPoolExecutor(/* corePoolSize= */ 0, /* maximumPoolSize= */ 1, /* keepAliveTime= */ DEFAULT_THREAD_KEEP_ALIVE_SECOND, TimeUnit.SECONDS, new LinkedBlockingQueue<>(), sDefaultThreadFactory), new ThreadPoolExecutor(/* corePoolSize= */ 0, /* maximumPoolSize= */ 2, /* keepAliveTime= */ DEFAULT_THREAD_KEEP_ALIVE_SECOND, TimeUnit.SECONDS, new LinkedBlockingQueue<>(), sMainProcessDumpThreadFactory)); /* keepAliveTime= */ AUX_THREAD_KEEP_ALIVE_SECOND, TimeUnit.SECONDS, new LinkedBlockingQueue<>(), sDefaultThreadFactory)); } @VisibleForTesting AnrHelper(ActivityManagerService service, ExecutorService auxExecutor, ExecutorService earlyDumpExecutor) { AnrHelper(ActivityManagerService service, ExecutorService auxExecutor) { mService = service; mAuxiliaryTaskExecutor = auxExecutor; mEarlyDumpExecutor = earlyDumpExecutor; } void appNotResponding(ProcessRecord anrProcess, TimeoutRecord timeoutRecord) { Loading Loading @@ -138,12 +121,6 @@ class AnrHelper { + timeoutRecord.mReason); return; } if (!mTempDumpedPids.add(incomingPid)) { Slog.i(TAG, "Skip ANR being predumped, pid=" + incomingPid + " " + timeoutRecord.mReason); return; } for (int i = mAnrRecords.size() - 1; i >= 0; i--) { if (mAnrRecords.get(i).mPid == incomingPid) { Slog.i(TAG, Loading @@ -152,24 +129,10 @@ class AnrHelper { return; } } // We dump the main process as soon as we can on a different thread, // this is done as the main process's dump can go stale in a few hundred // milliseconds and the average full ANR dump takes a few seconds. timeoutRecord.mLatencyTracker.earlyDumpRequestSubmittedWithSize( mTempDumpedPids.size()); Future<File> firstPidDumpPromise = mEarlyDumpExecutor.submit(() -> { // the class AnrLatencyTracker is not generally thread safe but the values // recorded/touched by the Temporary dump thread(s) are all volatile/atomic. File tracesFile = StackTracesDumpHelper.dumpStackTracesTempFile(incomingPid, timeoutRecord.mLatencyTracker); mTempDumpedPids.remove(incomingPid); return tracesFile; }); timeoutRecord.mLatencyTracker.anrRecordPlacingOnQueueWithSize(mAnrRecords.size()); mAnrRecords.add(new AnrRecord(anrProcess, activityShortComponentName, aInfo, parentShortComponentName, parentProcess, aboveSystem, timeoutRecord, isContinuousAnr, firstPidDumpPromise)); parentShortComponentName, parentProcess, aboveSystem, mAuxiliaryTaskExecutor, timeoutRecord, isContinuousAnr)); } startAnrConsumerIfNeeded(); } finally { Loading Loading @@ -256,7 +219,7 @@ class AnrHelper { } } private class AnrRecord { private static class AnrRecord { final ProcessRecord mApp; final int mPid; final String mActivityShortComponentName; Loading @@ -265,14 +228,14 @@ class AnrHelper { final ApplicationInfo mAppInfo; final WindowProcessController mParentProcess; final boolean mAboveSystem; final ExecutorService mAuxiliaryTaskExecutor; final long mTimestamp = SystemClock.uptimeMillis(); final boolean mIsContinuousAnr; final Future<File> mFirstPidFilePromise; AnrRecord(ProcessRecord anrProcess, String activityShortComponentName, ApplicationInfo aInfo, String parentShortComponentName, WindowProcessController parentProcess, boolean aboveSystem, TimeoutRecord timeoutRecord, boolean isContinuousAnr, Future<File> firstPidFilePromise) { ExecutorService auxiliaryTaskExecutor, TimeoutRecord timeoutRecord, boolean isContinuousAnr) { mApp = anrProcess; mPid = anrProcess.mPid; mActivityShortComponentName = activityShortComponentName; Loading @@ -281,8 +244,8 @@ class AnrHelper { mAppInfo = aInfo; mParentProcess = parentProcess; mAboveSystem = aboveSystem; mAuxiliaryTaskExecutor = auxiliaryTaskExecutor; mIsContinuousAnr = isContinuousAnr; mFirstPidFilePromise = firstPidFilePromise; } void appNotResponding(boolean onlyDumpSelf) { Loading @@ -291,7 +254,7 @@ class AnrHelper { mApp.mErrorState.appNotResponding(mActivityShortComponentName, mAppInfo, mParentShortComponentName, mParentProcess, mAboveSystem, mTimeoutRecord, mAuxiliaryTaskExecutor, onlyDumpSelf, mIsContinuousAnr, mFirstPidFilePromise); mIsContinuousAnr); } finally { mTimeoutRecord.mLatencyTracker.anrProcessingEnded(); } Loading
services/core/java/com/android/server/am/ProcessErrorStateRecord.java +3 −5 Original line number Diff line number Diff line Loading @@ -287,7 +287,7 @@ class ProcessErrorStateRecord { String parentShortComponentName, WindowProcessController parentProcess, boolean aboveSystem, TimeoutRecord timeoutRecord, ExecutorService auxiliaryTaskExecutor, boolean onlyDumpSelf, boolean isContinuousAnr, Future<File> firstPidFilePromise) { boolean isContinuousAnr) { String annotation = timeoutRecord.mReason; AnrLatencyTracker latencyTracker = timeoutRecord.mLatencyTracker; Future<?> updateCpuStatsNowFirstCall = null; Loading Loading @@ -334,6 +334,7 @@ class ProcessErrorStateRecord { Counter.logIncrement("stability_anr.value_skipped_anrs"); return; } // In case we come through here for the same app before completing // this one, mark as anring now so we will bail out. latencyTracker.waitingOnProcLockStarted(); Loading Loading @@ -367,9 +368,6 @@ class ProcessErrorStateRecord { firstPids.add(pid); // Don't dump other PIDs if it's a background ANR or is requested to only dump self. // Note that the primary pid is added here just in case, as it should normally be // dumped on the early dump thread, and would only be dumped on the Anr consumer thread // as a fallback. isSilentAnr = isSilentAnr(); if (!isSilentAnr && !onlyDumpSelf) { int parentPid = pid; Loading Loading @@ -500,7 +498,7 @@ class ProcessErrorStateRecord { File tracesFile = StackTracesDumpHelper.dumpStackTraces(firstPids, isSilentAnr ? null : processCpuTracker, isSilentAnr ? null : lastPids, nativePidsFuture, tracesFileException, firstPidEndOffset, annotation, criticalEventLog, auxiliaryTaskExecutor, firstPidFilePromise, latencyTracker); criticalEventLog, auxiliaryTaskExecutor, latencyTracker); if (isMonitorCpuUsage()) { // Wait for the first call to finish Loading
services/core/java/com/android/server/am/StackTracesDumpHelper.java +29 −161 File changed.Preview size limit exceeded, changes collapsed. Show changes