Merge "Include ANR duration & start time in the ANR report file" into main (5d6e140f) · Commits · e / os / android_frameworks_base

services/core/java/com/android/server/am/ProcessErrorStateRecord.java

+1 −1

Original line number	Diff line number	Diff line
		@@ -538,7 +538,7 @@ class ProcessErrorStateRecord {
		isSilentAnr ? null : processCpuTracker, isSilentAnr ? null : lastPids,
		nativePidsFuture, tracesFileException, firstPidEndOffset, annotation,
		criticalEventLog, memoryHeaders, auxiliaryTaskExecutor, firstPidFilePromise,
		latencyTracker);
		latencyTracker, timeoutRecord);

		if (isMonitorCpuUsage()) {
		// Wait for the first call to finish

services/core/java/com/android/server/am/StackTracesDumpHelper.java

+110 −22

Original line number	Diff line number	Diff line
		@@ -33,7 +33,9 @@ import android.util.SparseBooleanArray;

		import com.android.internal.annotations.GuardedBy;
		import com.android.internal.os.ProcessCpuTracker;
		import com.android.internal.os.TimeoutRecord;
		import com.android.internal.os.anr.AnrLatencyTracker;
		import com.android.server.utils.AnrTimer;

		import java.io.File;
		import java.io.FileOutputStream;
		@@ -84,25 +86,39 @@ public class StackTracesDumpHelper {
		/**
		* If a stack trace dump file is configured, dump process stack traces.
		* @param firstPids of dalvik VM processes to dump stack traces for first
		* @param processCpuTracker
		* @param lastPids of dalvik VM processes to dump stack traces for last
		* @param nativePidsFuture optional future for a list of native pids to dump stack crawls
		* @param logExceptionCreatingFile optional writer to which we log errors creating the file
		* @param auxiliaryTaskExecutor executor to execute auxiliary tasks on
		* @param latencyTracker the latency tracker instance of the current ANR.
		*/
		public static File dumpStackTraces(ArrayList<Integer> firstPids,
		ProcessCpuTracker processCpuTracker, SparseBooleanArray lastPids,
		Future<ArrayList<Integer>> nativePidsFuture, StringWriter logExceptionCreatingFile,
		@NonNull Executor auxiliaryTaskExecutor, AnrLatencyTracker latencyTracker) {
		public static File dumpStackTraces(
		ArrayList<Integer> firstPids,
		ProcessCpuTracker processCpuTracker,
		SparseBooleanArray lastPids,
		Future<ArrayList<Integer>> nativePidsFuture,
		StringWriter logExceptionCreatingFile,
		@NonNull Executor auxiliaryTaskExecutor,
		AnrLatencyTracker latencyTracker) {
		return dumpStackTraces(firstPids, processCpuTracker, lastPids, nativePidsFuture,
		logExceptionCreatingFile, null, null, null, null, auxiliaryTaskExecutor, null,
		latencyTracker);
		latencyTracker, null);
		}

		/**
		* If a stack trace dump file is configured, dump process stack traces.
		*
		* @param firstPids of dalvik VM processes to dump stack traces for first
		* @param processCpuTracker of dalvik VM processes
		* @param lastPids of dalvik VM processes to dump stack traces for last
		* @param nativePidsFuture optional future for a list of native pids to dump stack crawls
		* @param logExceptionCreatingFile optional writer to which we log errors creating the file
		* @param subject the subject of the dumped traces
		* @param criticalEventSection the critical event log, passed as a string
		* @param extraHeaders Optional, Extra headers added by the dumping method
		* @param auxiliaryTaskExecutor executor to execute auxiliary tasks on
		* @param latencyTracker the latency tracker instance of the current ANR.
		*/
		public static File dumpStackTraces(ArrayList<Integer> firstPids,
		ProcessCpuTracker processCpuTracker, SparseBooleanArray lastPids,
		@@ -110,21 +126,75 @@ public class StackTracesDumpHelper {
		String subject, String criticalEventSection,
		LinkedHashMap<String, String> extraHeaders, @NonNull Executor auxiliaryTaskExecutor,
		AnrLatencyTracker latencyTracker) {
		return dumpStackTraces(
		firstPids,
		processCpuTracker,
		lastPids,
		nativePidsFuture,
		logExceptionCreatingFile,
		/* firstPidEndOffset= */ null,
		subject,
		criticalEventSection,
		extraHeaders,
		auxiliaryTaskExecutor,
		/* firstPidFilePromise= */ null,
		latencyTracker,
		/* timeoutRecord= */ null);
		}


		/**
		* If a stack trace dump file is configured, dump process stack traces.
		*
		* @param firstPids of dalvik VM processes to dump stack traces for first
		* @param processCpuTracker of dalvik VM processes
		* @param lastPids of dalvik VM processes to dump stack traces for last
		* @param nativePidsFuture optional future for a list of native pids to dump stack crawls
		* @param logExceptionCreatingFile optional writer to which we log errors creating the file
		* @param subject the subject of the dumped traces
		* @param criticalEventSection the critical event log, passed as a string
		* @param extraHeaders Optional, Extra headers added by the dumping method
		* @param auxiliaryTaskExecutor executor to execute auxiliary tasks on
		* @param firstPidEndOffset Optional, when it's set, it receives the start/end offset of the
		* very first pid to be dumped.
		* @param latencyTracker the latency tracker instance of the current ANR.
		*/
		public static File dumpStackTraces(
		ArrayList<Integer> firstPids,
		ProcessCpuTracker processCpuTracker,
		SparseBooleanArray lastPids,
		Future<ArrayList<Integer>> nativePidsFuture,
		StringWriter logExceptionCreatingFile,
		AtomicLong firstPidEndOffset,
		String subject,
		String criticalEventSection,
		LinkedHashMap<String, String> extraHeaders,
		@NonNull Executor auxiliaryTaskExecutor,
		Future<File> firstPidFilePromise,
		AnrLatencyTracker latencyTracker) {
		return dumpStackTraces(firstPids, processCpuTracker, lastPids, nativePidsFuture,
		logExceptionCreatingFile, null, subject, criticalEventSection,
		extraHeaders, auxiliaryTaskExecutor, null, latencyTracker);
		logExceptionCreatingFile, firstPidEndOffset, subject, criticalEventSection,
		extraHeaders, auxiliaryTaskExecutor, firstPidFilePromise, latencyTracker,
		null);
		}

		/**
		* @param firstPidEndOffset Optional, when it's set, it receives the start/end offset
		* of the very first pid to be dumped.
		* @param timeoutRecord the timeout record of the current ANR.
		*/
		/* package */ static File dumpStackTraces(ArrayList<Integer> firstPids,
		ProcessCpuTracker processCpuTracker, SparseBooleanArray lastPids,
		Future<ArrayList<Integer>> nativePidsFuture, StringWriter logExceptionCreatingFile,
		AtomicLong firstPidEndOffset, String subject, String criticalEventSection,
		LinkedHashMap<String, String> extraHeaders, @NonNull Executor auxiliaryTaskExecutor,
		Future<File> firstPidFilePromise, AnrLatencyTracker latencyTracker) {
		public static File dumpStackTraces(
		ArrayList<Integer> firstPids,
		ProcessCpuTracker processCpuTracker,
		SparseBooleanArray lastPids,
		Future<ArrayList<Integer>> nativePidsFuture,
		StringWriter logExceptionCreatingFile,
		AtomicLong firstPidEndOffset,
		String subject,
		String criticalEventSection,
		LinkedHashMap<String, String> extraHeaders,
		@NonNull Executor auxiliaryTaskExecutor,
		Future<File> firstPidFilePromise,
		AnrLatencyTracker latencyTracker,
		TimeoutRecord timeoutRecord) {
		try {

		if (latencyTracker != null) {
		@@ -163,13 +233,31 @@ public class StackTracesDumpHelper {
		}
		return null;
		}
		boolean extraHeadersExist = extraHeaders != null && !extraHeaders.isEmpty();

		if (subject != null \|\| criticalEventSection != null \|\| extraHeadersExist) {
		appendtoANRFile(tracesFile.getAbsolutePath(),
		(subject != null ? "Subject: " + subject + "\n" : "")
		+ (extraHeadersExist ? stringifyHeaders(extraHeaders) + "\n\n" : "")
		+ (criticalEventSection != null ? criticalEventSection : ""));
		StringBuilder headers = new StringBuilder();
		if (subject != null) {
		headers.append("Subject: ").append(subject).append("\n");
		}
		if (timeoutRecord != null) {
		AnrTimer.ExpiredTimer expiredTimer = AnrTimer.expiredTimer(timeoutRecord);
		if (expiredTimer != null && expiredTimer.mDurationMs > 0) {
		headers.append("Timeout: ")
		.append(expiredTimer.mDurationMs)
		.append("\n");
		}
		if (expiredTimer != null && expiredTimer.mStartMs > 0) {
		headers.append("TimeoutStart: ")
		.append(expiredTimer.mStartMs)
		.append("\n");
		}
		}
		if (extraHeaders != null && !extraHeaders.isEmpty()) {
		headers.append(stringifyHeaders(extraHeaders)).append("\n\n");
		}
		if (criticalEventSection != null) {
		headers.append(criticalEventSection);
		}
		if (!headers.isEmpty()) {
		appendtoANRFile(tracesFile.getAbsolutePath(), headers.toString());
		}

		long firstPidEndPos = dumpStackTraces(

services/core/java/com/android/server/utils/AnrTimer.java

+12 −3

Original line number	Diff line number	Diff line
		@@ -304,8 +304,17 @@ public class AnrTimer<V> implements AutoCloseable {
		// The timer ID.
		final int mTimerId;

		ExpiredTimer(int id) {
		// The start uptime of the timer in millis.
		public final long mStartMs;

		// The total duration uptime of the timer in millis.
		// Includes any extensions.
		public final long mDurationMs;

		ExpiredTimer(int id, long startMs, long durationMs) {
		mTimerId = id;
		mStartMs = startMs;
		mDurationMs = durationMs;
		}
		}

		@@ -876,7 +885,7 @@ public class AnrTimer<V> implements AutoCloseable {
		* message is delivered to the upper layers and false if it could not be delivered.
		*/
		@Keep
		private boolean expire(int timerId, int pid, int uid, long elapsedMs) {
		private boolean expire(int timerId, int pid, int uid, long startMs, long elapsedMs) {
		trace("expired", timerId, pid, uid, mLabel, elapsedMs);
		final V arg;
		synchronized (mLock) {
		@@ -887,7 +896,7 @@ public class AnrTimer<V> implements AutoCloseable {
		mTotalErrors++;
		return false;
		}
		mExpiredTimers.put(timerId, new ExpiredTimer(timerId));
		mExpiredTimers.put(timerId, new ExpiredTimer(timerId, startMs, elapsedMs));
		mTotalExpired++;
		}
		final Message msg = Message.obtain(mHandler, mWhat, arg);

services/core/java/com/android/server/wm/AnrController.java

+18 −8

Original line number	Diff line number	Diff line
		@@ -70,7 +70,7 @@ class AnrController {
		try {
		timeoutRecord.mLatencyTracker.notifyAppUnresponsiveStarted();
		timeoutRecord.mLatencyTracker.preDumpIfLockTooSlowStarted();
		preDumpIfLockTooSlow();
		preDumpIfLockTooSlow(timeoutRecord);
		timeoutRecord.mLatencyTracker.preDumpIfLockTooSlowEnded();
		final ActivityRecord activity;
		timeoutRecord.mLatencyTracker.waitingOnGlobalLockStarted();
		@@ -167,7 +167,7 @@ class AnrController {
		private boolean notifyWindowUnresponsive(@NonNull IBinder inputToken,
		TimeoutRecord timeoutRecord) {
		timeoutRecord.mLatencyTracker.preDumpIfLockTooSlowStarted();
		preDumpIfLockTooSlow();
		preDumpIfLockTooSlow(timeoutRecord);
		timeoutRecord.mLatencyTracker.preDumpIfLockTooSlowEnded();
		final int pid;
		final boolean aboveSystem;
		@@ -279,7 +279,7 @@ class AnrController {
		* <p>
		* Do not hold the {@link WindowManagerGlobalLock} while calling this method.
		*/
		private void preDumpIfLockTooSlow() {
		private void preDumpIfLockTooSlow(TimeoutRecord timeoutRecord) {
		if (!Build.IS_DEBUGGABLE) {
		return;
		}
		@@ -341,11 +341,21 @@ class AnrController {

		String criticalEvents =
		CriticalEventLog.getInstance().logLinesForSystemServerTraceFile();
		final File tracesFile = StackTracesDumpHelper.dumpStackTraces(firstPids,
		null /* processCpuTracker /, null / lastPids */,
		final File tracesFile =
		StackTracesDumpHelper.dumpStackTraces(
		firstPids,
		null /* processCpuTracker */,
		null /* lastPids */,
		CompletableFuture.completedFuture(nativePids),
		null /* logExceptionCreatingFile */, "Pre-dump", criticalEvents,
		null /* extraHeaders /, Runnable::run, null/ AnrLatencyTracker */);
		null /* logExceptionCreatingFile */,
		null /* firstPidEndOffset */,
		"Pre-dump",
		criticalEvents,
		null /* extraHeaders */,
		Runnable::run /* auxiliaryTaskExecutor */,
		null /* firstPidFilePromise */,
		null /* latencyTracker */,
		timeoutRecord);
		if (tracesFile != null) {
		tracesFile.renameTo(
		new File(tracesFile.getParent(), tracesFile.getName() + "_pre"));

services/core/jni/com_android_server_utils_AnrTimer.cpp

+11 −8

Original line number	Diff line number	Diff line
		@@ -683,8 +683,8 @@ class AnrTimerService {
		// A notifier is called with a timer ID, the timer's tag, and the client's cookie. The pid
		// and uid that were originally assigned to the timer are passed as well. The elapsed time
		// is the time since the timer was scheduled.
		using notifier_t = bool ()(timer_id_t, int pid, int uid, nsecs_t elapsed, void cookie,
		jweak object, bool expired, uint32_t token);
		using notifier_t = bool (*)(timer_id_t, int pid, int uid, nsecs_t started, nsecs_t elapsed,
		void* cookie, jweak object, bool expired, uint32_t token);

		enum Status {
		Invalid,
		@@ -1415,6 +1415,7 @@ void AnrTimerService::expire(timer_id_t timerId) {
		// Save the timer attributes for the notification
		int pid = 0;
		int uid = 0;
		nsecs_t started = 0;
		nsecs_t elapsed = 0;
		SplitPoint meta;
		bool expired = false;
		@@ -1435,6 +1436,7 @@ void AnrTimerService::expire(timer_id_t timerId) {
		}
		pid = t.pid;
		uid = t.uid;
		started = t.started;
		elapsed = now() - t.started;
		}

		@@ -1446,8 +1448,8 @@ void AnrTimerService::expire(timer_id_t timerId) {

		// Deliver the notification outside of the lock.
		if (meta.action == SplitAction::Expire \|\| meta.action == SplitAction::EarlyNotify) {
		if (!notifier_(timerId, pid, uid, elapsed, notifierCookie_, notifierObject_, expired,
		meta.token)) {
		if (!notifier_(timerId, pid, uid, started, elapsed, notifierCookie_, notifierObject_,
		expired, meta.token)) {
		// Notification failed, which means the listener will never call accept() or
		// discard(). Do not reinsert the timer.
		discard(timerId);
		@@ -1530,8 +1532,8 @@ struct AnrArgs {
		static AnrArgs gAnrArgs;

		// The cookie is the address of the AnrArgs object to which the notification should be sent.
		static bool anrNotify(AnrTimerService::timer_id_t timerId, int pid, int uid, nsecs_t elapsed,
		void* cookie, jweak jtimer, bool expired, uint32_t token) {
		static bool anrNotify(AnrTimerService::timer_id_t timerId, int pid, int uid, nsecs_t started,
		nsecs_t elapsed, void* cookie, jweak jtimer, bool expired, uint32_t token) {
		AutoMutex _l(gAnrLock);
		AnrArgs* target = reinterpret_cast<AnrArgs* >(cookie);
		JNIEnv *env;
		@@ -1543,7 +1545,8 @@ static bool anrNotify(AnrTimerService::timer_id_t timerId, int pid, int uid, nse
		jobject timer = env->NewGlobalRef(jtimer);
		if (timer != nullptr) {
		if (expired) {
		r = env->CallBooleanMethod(timer, target->func, timerId, pid, uid, ns2ms(elapsed));
		r = env->CallBooleanMethod(timer, target->func, timerId, pid, uid, ns2ms(started),
		ns2ms(elapsed));
		} else {
		env->CallVoidMethod(timer, target->funcEarly, timerId, pid, uid, ns2ms(elapsed), token);
		r = true;
		@@ -1694,7 +1697,7 @@ int register_android_server_utils_AnrTimer(JNIEnv* env)

		jclass service = FindClassOrDie(env, className);
		gAnrArgs.clazz = MakeGlobalRefOrDie(env, service);
		gAnrArgs.func = env->GetMethodID(gAnrArgs.clazz, "expire", "(IIIJ)Z");
		gAnrArgs.func = env->GetMethodID(gAnrArgs.clazz, "expire", "(IIIJJ)Z");
		gAnrArgs.funcEarly = env->GetMethodID(gAnrArgs.clazz, "notifyEarly", "(IIIJI)V");

		env->GetJavaVM(&gAnrArgs.vm);