am ce06c000: Merge "Debugging code for #6169553: Make Phone launch faster" into ics-mr1 (c032a73b) · Commits · e / os / android_frameworks_base

cmds/dumpstate/dumpstate.c

+18 −0

Original line number	Diff line number	Diff line
		@@ -108,6 +108,24 @@ static void dumpstate() {
		dump_file("VM TRACES AT LAST ANR", anr_traces_path);
		}

		/* slow traces for slow operations */
		if (anr_traces_path[0] != 0) {
		int tail = strlen(anr_traces_path)-1;
		while (tail > 0 && anr_traces_path[tail] != '/') {
		tail--;
		}
		int i = 0;
		while (1) {
		sprintf(anr_traces_path+tail+1, "slow%02d.txt", i);
		if (stat(anr_traces_path, &st)) {
		// No traces file at this index, done with the files.
		break;
		}
		dump_file("VM TRACES WHEN SLOW", anr_traces_path);
		i++;
		}
		}

		// dump_file("EVENT LOG TAGS", "/etc/event-log-tags");
		run_command("EVENT LOG", 20, "logcat", "-b", "events", "-v", "threadtime", "-d", "*:v", NULL);
		run_command("RADIO LOG", 20, "logcat", "-b", "radio", "-v", "threadtime", "-d", "*:v", NULL);

services/java/com/android/server/am/ActivityManagerService.java

+91 −10

Original line number	Diff line number	Diff line
		@@ -105,6 +105,7 @@ import android.os.StrictMode;
		import android.os.SystemClock;
		import android.os.SystemProperties;
		import android.provider.Settings;
		import android.text.format.Time;
		import android.util.EventLog;
		import android.util.Pair;
		import android.util.Slog;
		@@ -186,6 +187,8 @@ public final class ActivityManagerService extends ActivityManagerNative

		private static final String SYSTEM_DEBUGGABLE = "ro.debuggable";

		static final boolean IS_USER_BUILD = "user".equals(Build.TYPE);

		// Maximum number of recent tasks that we can remember.
		static final int MAX_RECENT_TASKS = 20;

		@@ -2904,6 +2907,12 @@ public final class ActivityManagerService extends ActivityManagerNative
		return null;
		}

		dumpStackTraces(tracesPath, firstPids, processStats, lastPids);
		return tracesFile;
		}

		private static void dumpStackTraces(String tracesPath, ArrayList<Integer> firstPids,
		ProcessStats processStats, SparseArray<Boolean> lastPids) {
		// Use a FileObserver to detect when traces finish writing.
		// The order of traces is considered important to maintain for legibility.
		FileObserver observer = new FileObserver(tracesPath, FileObserver.CLOSE_WRITE) {
		@@ -2914,6 +2923,7 @@ public final class ActivityManagerService extends ActivityManagerNative
		observer.startWatching();

		// First collect all of the stacks of the most important pids.
		if (firstPids != null) {
		try {
		int num = firstPids.size();
		for (int i = 0; i < num; i++) {
		@@ -2925,6 +2935,7 @@ public final class ActivityManagerService extends ActivityManagerNative
		} catch (InterruptedException e) {
		Log.wtf(TAG, e);
		}
		}

		// Next measure CPU usage.
		if (processStats != null) {
		@@ -2959,8 +2970,6 @@ public final class ActivityManagerService extends ActivityManagerNative
		}
		}

		return tracesFile;

		} finally {
		observer.stopWatching();
		}
		@@ -2981,6 +2990,78 @@ public final class ActivityManagerService extends ActivityManagerNative
		}
		}

		final void logAppTooSlow(ProcessRecord app, long startTime, String msg) {
		if (IS_USER_BUILD) {
		return;
		}
		String tracesPath = SystemProperties.get("dalvik.vm.stack-trace-file", null);
		if (tracesPath == null \|\| tracesPath.length() == 0) {
		return;
		}

		StrictMode.ThreadPolicy oldPolicy = StrictMode.allowThreadDiskReads();
		StrictMode.allowThreadDiskWrites();
		try {
		final File tracesFile = new File(tracesPath);
		final File tracesDir = tracesFile.getParentFile();
		final File tracesTmp = new File(tracesDir, "__tmp__");
		try {
		if (!tracesDir.exists()) tracesFile.mkdirs();
		FileUtils.setPermissions(tracesDir.getPath(), 0775, -1, -1); // drwxrwxr-x

		if (tracesFile.exists()) {
		tracesTmp.delete();
		tracesFile.renameTo(tracesTmp);
		}
		StringBuilder sb = new StringBuilder();
		Time tobj = new Time();
		tobj.set(System.currentTimeMillis());
		sb.append(tobj.format("%Y-%m-%d %H:%M:%S"));
		sb.append(": ");
		TimeUtils.formatDuration(SystemClock.uptimeMillis()-startTime, sb);
		sb.append(" since ");
		sb.append(msg);
		FileOutputStream fos = new FileOutputStream(tracesFile);
		fos.write(sb.toString().getBytes());
		if (app == null) {
		fos.write("\n*** No application process!".getBytes());
		}
		fos.close();
		FileUtils.setPermissions(tracesFile.getPath(), 0666, -1, -1); // -rw-rw-rw-
		} catch (IOException e) {
		Slog.w(TAG, "Unable to prepare slow app traces file: " + tracesPath, e);
		return;
		}

		if (app != null) {
		ArrayList<Integer> firstPids = new ArrayList<Integer>();
		firstPids.add(app.pid);
		dumpStackTraces(tracesPath, firstPids, null, null);
		}

		File lastTracesFile = null;
		File curTracesFile = null;
		for (int i=9; i>=0; i--) {
		String name = String.format("slow%02d.txt", i);
		curTracesFile = new File(tracesDir, name);
		if (curTracesFile.exists()) {
		if (lastTracesFile != null) {
		curTracesFile.renameTo(lastTracesFile);
		} else {
		curTracesFile.delete();
		}
		}
		lastTracesFile = curTracesFile;
		}
		tracesFile.renameTo(curTracesFile);
		if (tracesTmp.exists()) {
		tracesTmp.renameTo(tracesFile);
		}
		} finally {
		StrictMode.setThreadPolicy(oldPolicy);
		}
		}

		final void appNotResponding(ProcessRecord app, ActivityRecord activity,
		ActivityRecord parent, final String annotation) {
		ArrayList<Integer> firstPids = new ArrayList<Integer>(5);

services/java/com/android/server/am/ActivityRecord.java

+29 −0

Original line number	Diff line number	Diff line
		@@ -82,6 +82,8 @@ final class ActivityRecord {
		long startTime; // last time this activity was started
		long lastVisibleTime; // last time this activity became visible
		long cpuTimeAtResume; // the cpu time of host process at the time of resuming activity
		long pauseTime; // last time we started pausing the activity
		long launchTickTime; // base time for launch tick messages
		Configuration configuration; // configuration activity was last running in
		CompatibilityInfo compat;// last used compatibility mode
		ActivityRecord resultTo; // who started this entry, so will get our reply
		@@ -572,6 +574,32 @@ final class ActivityRecord {
		}
		}

		void startLaunchTickingLocked() {
		if (ActivityManagerService.IS_USER_BUILD) {
		return;
		}
		if (launchTickTime == 0) {
		launchTickTime = SystemClock.uptimeMillis();
		continueLaunchTickingLocked();
		}
		}

		boolean continueLaunchTickingLocked() {
		if (launchTickTime != 0) {
		Message msg = stack.mHandler.obtainMessage(ActivityStack.LAUNCH_TICK_MSG);
		msg.obj = this;
		stack.mHandler.removeMessages(ActivityStack.LAUNCH_TICK_MSG);
		stack.mHandler.sendMessageDelayed(msg, ActivityStack.LAUNCH_TICK);
		return true;
		}
		return false;
		}

		void finishLaunchTickingLocked() {
		launchTickTime = 0;
		stack.mHandler.removeMessages(ActivityStack.LAUNCH_TICK_MSG);
		}

		// IApplicationToken

		public boolean mayFreezeScreenLocked(ProcessRecord app) {
		@@ -627,6 +655,7 @@ final class ActivityRecord {
		stack.mInitialStartTime = 0;
		}
		startTime = 0;
		finishLaunchTickingLocked();
		}
		}

services/java/com/android/server/am/ActivityStack.java

+31 −2

Original line number	Diff line number	Diff line
		@@ -96,6 +96,9 @@ final class ActivityStack {
		// is idle.
		static final int IDLE_TIMEOUT = 10*1000;

		// Ticks during which we check progress while waiting for an app to launch.
		static final int LAUNCH_TICK = 500;

		// How long we wait until giving up on the last activity to pause. This
		// is short because it directly impacts the responsiveness of starting the
		// next activity.
		@@ -278,6 +281,7 @@ final class ActivityStack {
		static final int PAUSE_TIMEOUT_MSG = 9;
		static final int IDLE_TIMEOUT_MSG = 10;
		static final int IDLE_NOW_MSG = 11;
		static final int LAUNCH_TICK_MSG = 12;
		static final int LAUNCH_TIMEOUT_MSG = 16;
		static final int DESTROY_TIMEOUT_MSG = 17;
		static final int RESUME_TOP_ACTIVITY_MSG = 19;
		@@ -303,6 +307,13 @@ final class ActivityStack {
		// We don't at this point know if the activity is fullscreen,
		// so we need to be conservative and assume it isn't.
		Slog.w(TAG, "Activity pause timeout for " + r);
		synchronized (mService) {
		if (r.app != null) {
		mService.logAppTooSlow(r.app, r.pauseTime,
		"pausing " + r);
		}
		}

		activityPaused(r != null ? r.appToken : null, true);
		} break;
		case IDLE_TIMEOUT_MSG: {
		@@ -319,6 +330,15 @@ final class ActivityStack {
		Slog.w(TAG, "Activity idle timeout for " + r);
		activityIdleInternal(r != null ? r.appToken : null, true, null);
		} break;
		case LAUNCH_TICK_MSG: {
		ActivityRecord r = (ActivityRecord)msg.obj;
		synchronized (mService) {
		if (r.continueLaunchTickingLocked()) {
		mService.logAppTooSlow(r.app, r.launchTickTime,
		"launching " + r);
		}
		}
		} break;
		case DESTROY_TIMEOUT_MSG: {
		ActivityRecord r = (ActivityRecord)msg.obj;
		// We don't at this point know if the activity is fullscreen,
		@@ -518,6 +538,9 @@ final class ActivityStack {
		r.startFreezingScreenLocked(app, 0);
		mService.mWindowManager.setAppVisibility(r.appToken, true);

		// schedule launch ticks to collect information about slow apps.
		r.startLaunchTickingLocked();

		// Have the window manager re-evaluate the orientation of
		// the screen based on the new activity order. Note that
		// as a result of this, it can call back into the activity
		@@ -900,6 +923,7 @@ final class ActivityStack {
		// responsiveness seen by the user.
		Message msg = mHandler.obtainMessage(PAUSE_TIMEOUT_MSG);
		msg.obj = prev;
		prev.pauseTime = SystemClock.uptimeMillis();
		mHandler.sendMessageDelayed(msg, PAUSE_TIMEOUT);
		if (DEBUG_PAUSE) Slog.v(TAG, "Waiting for pause to complete...");
		} else {
		@@ -1443,6 +1467,9 @@ final class ActivityStack {
		// This activity is now becoming visible.
		mService.mWindowManager.setAppVisibility(next.appToken, true);

		// schedule launch ticks to collect information about slow apps.
		next.startLaunchTickingLocked();

		ActivityRecord lastResumedActivity = mResumedActivity;
		ActivityState lastState = next.state;

		@@ -3218,6 +3245,7 @@ final class ActivityStack {
		ActivityRecord r = ActivityRecord.forToken(token);
		if (r != null) {
		mHandler.removeMessages(IDLE_TIMEOUT_MSG, r);
		r.finishLaunchTickingLocked();
		}

		// Get the activity record.
		@@ -3588,6 +3616,7 @@ final class ActivityStack {
		mHandler.removeMessages(PAUSE_TIMEOUT_MSG, r);
		mHandler.removeMessages(IDLE_TIMEOUT_MSG, r);
		mHandler.removeMessages(DESTROY_TIMEOUT_MSG, r);
		r.finishLaunchTickingLocked();
		}

		final void removeActivityFromHistoryLocked(ActivityRecord r) {