From 1a4b5a4f02e7d8ff8ff645377d97e6062d36aeaa Mon Sep 17 00:00:00 2001 From: Dianne Hackborn Date: Mon, 8 Dec 2014 17:43:31 -0800 Subject: Work on issue #18640385: Add procstats test mode You can now do "adb shell dumpsys procstats --start-testing" to enable high frequency pss sampling. Also improved the low on RAM mem reporting to separate out RAM from memtrack, in case the data we are getting from that is bad. And fixed meminfo --oom to work correctly again. Change-Id: I7af17eab110a82298bd7b0ce381f8fa5c96c1f6a --- .../android/server/am/ActivityManagerService.java | 140 +++++++++++++++------ .../java/com/android/server/am/ProcessList.java | 56 ++++++++- .../java/com/android/server/am/ProcessMemInfo.java | 1 + .../com/android/server/am/ProcessStatsService.java | 31 ++++- 4 files changed, 178 insertions(+), 50 deletions(-) (limited to 'services') diff --git a/services/core/java/com/android/server/am/ActivityManagerService.java b/services/core/java/com/android/server/am/ActivityManagerService.java index 4eadff9..0373611 100755 --- a/services/core/java/com/android/server/am/ActivityManagerService.java +++ b/services/core/java/com/android/server/am/ActivityManagerService.java @@ -1075,6 +1075,13 @@ public final class ActivityManagerService extends ActivityManagerNative */ boolean mSafeMode; + /** + * If true, we are running under a test environment so will sample PSS from processes + * much more rapidly to try to collect better data when the tests are rapidly + * running through apps. + */ + boolean mTestPssMode = false; + String mDebugApp = null; boolean mWaitForDebugger = false; boolean mDebugTransient = false; @@ -1091,6 +1098,8 @@ public final class ActivityManagerService extends ActivityManagerNative int mProfileType = 0; String mOpenGlTraceApp = null; + final long[] mTmpLong = new long[1]; + static class ProcessChangeItem { static final int CHANGE_ACTIVITIES = 1<<0; static final int CHANGE_PROCESS_STATE = 1<<1; @@ -1802,7 +1811,7 @@ public final class ActivityManagerService extends ActivityManagerNative continue; } } - nativeTotalPss += Debug.getPss(st.pid, null); + nativeTotalPss += Debug.getPss(st.pid, null, null); } } memInfo.readMemInfo(); @@ -1815,48 +1824,38 @@ public final class ActivityManagerService extends ActivityManagerNative } } - int i = 0; int num = 0; long[] tmp = new long[1]; do { ProcessRecord proc; int procState; int pid; + long lastPssTime; synchronized (ActivityManagerService.this) { - if (i >= mPendingPssProcesses.size()) { - if (DEBUG_PSS) Slog.d(TAG, "Collected PSS of " + num + " of " + i + if (mPendingPssProcesses.size() <= 0) { + if (mTestPssMode || DEBUG_PSS) Slog.d(TAG, "Collected PSS of " + num + " processes in " + (SystemClock.uptimeMillis()-start) + "ms"); mPendingPssProcesses.clear(); return; } - proc = mPendingPssProcesses.get(i); + proc = mPendingPssProcesses.remove(0); procState = proc.pssProcState; + lastPssTime = proc.lastPssTime; if (proc.thread != null && procState == proc.setProcState) { pid = proc.pid; } else { proc = null; pid = 0; } - i++; } if (proc != null) { - long pss = Debug.getPss(pid, tmp); + long pss = Debug.getPss(pid, tmp, null); synchronized (ActivityManagerService.this) { - if (proc.thread != null && proc.setProcState == procState - && proc.pid == pid) { + if (pss != 0 && proc.thread != null && proc.setProcState == procState + && proc.pid == pid && proc.lastPssTime == lastPssTime) { num++; - proc.lastPssTime = SystemClock.uptimeMillis(); - proc.baseProcessTracker.addPss(pss, tmp[0], true, proc.pkgList); - if (DEBUG_PSS) Slog.d(TAG, "PSS of " + proc.toShortString() - + ": " + pss + " lastPss=" + proc.lastPss - + " state=" + ProcessList.makeProcStateString(procState)); - if (proc.initialIdlePss == 0) { - proc.initialIdlePss = pss; - } - proc.lastPss = pss; - if (procState >= ActivityManager.PROCESS_STATE_HOME) { - proc.lastCachedPss = pss; - } + recordPssSample(proc, procState, pss, tmp[0], + SystemClock.uptimeMillis()); } } } @@ -5420,7 +5419,7 @@ public final class ActivityManagerService extends ActivityManagerNative } } long[] tmpUss = new long[1]; - pss[i] = Debug.getPss(pids[i], tmpUss); + pss[i] = Debug.getPss(pids[i], tmpUss, null); if (proc != null) { synchronized (this) { if (proc.thread != null && proc.setAdj == oomAdj) { @@ -10949,7 +10948,7 @@ public final class ActivityManagerService extends ActivityManagerNative proc.notCachedSinceIdle = true; proc.initialIdlePss = 0; proc.nextPssTime = ProcessList.computeNextPssTime(proc.curProcState, true, - isSleeping(), now); + mTestPssMode, isSleeping(), now); } } @@ -12919,7 +12918,8 @@ public final class ActivityManagerService extends ActivityManagerNative + PowerManagerInternal.wakefulnessToString(mWakefulness)); pw.println(" mSleeping=" + mSleeping + " mLockScreenShown=" + lockScreenShownToString()); - pw.println(" mShuttingDown=" + mShuttingDown + " mRunningVoice=" + mRunningVoice); + pw.println(" mShuttingDown=" + mShuttingDown + " mRunningVoice=" + mRunningVoice + + " mTestPssMode=" + mTestPssMode); } if (mDebugApp != null || mOrigDebugApp != null || mDebugTransient || mOrigWaitForDebugger) { @@ -14014,7 +14014,7 @@ public final class ActivityManagerService extends ActivityManagerNative if (dumpDetails || (!brief && !oomOnly)) { Debug.getMemoryInfo(pid, mi); } else { - mi.dalvikPss = (int)Debug.getPss(pid, tmpLong); + mi.dalvikPss = (int)Debug.getPss(pid, tmpLong, null); mi.dalvikPrivateDirty = (int)tmpLong[0]; } ActivityThread.dumpMemInfoTable(pw, mi, isCheckinRequest, dumpFullDetails, @@ -14076,7 +14076,7 @@ public final class ActivityManagerService extends ActivityManagerNative if (dumpDetails || (!brief && !oomOnly)) { Debug.getMemoryInfo(pid, mi); } else { - mi.dalvikPss = (int)Debug.getPss(pid, tmpLong); + mi.dalvikPss = (int)Debug.getPss(pid, tmpLong, null); mi.dalvikPrivateDirty = (int)tmpLong[0]; } if (dumpDetails) { @@ -14152,6 +14152,7 @@ public final class ActivityManagerService extends ActivityManagerNative // If we are showing aggregations, also look for native processes to // include so that our aggregations are more accurate. updateCpuStatsNow(); + mi = null; synchronized (mProcessCpuTracker) { final int N = mProcessCpuTracker.countStats(); for (int i=0; i 0) { + sb.append(" ("); + sb.append(memtrack); + sb.append(" kB memtrack)"); + } } private void appendMemInfo(StringBuilder sb, ProcessMemInfo mi) { - appendBasicMemEntry(sb, mi.oomAdj, mi.procState, mi.pss, mi.name); - sb.append(" ("); + appendBasicMemEntry(sb, mi.oomAdj, mi.procState, mi.pss, mi.memtrack, mi.name); + sb.append(" (pid "); sb.append(mi.pid); sb.append(") "); sb.append(mi.adjType); @@ -14386,17 +14392,19 @@ public final class ActivityManagerService extends ActivityManagerNative infoMap.put(mi.pid, mi); } updateCpuStatsNow(); + long[] memtrackTmp = new long[1]; synchronized (mProcessCpuTracker) { final int N = mProcessCpuTracker.countStats(); for (int i=0; i 0) { - long pss = Debug.getPss(st.pid, null); + long pss = Debug.getPss(st.pid, null, memtrackTmp); if (pss > 0) { if (infoMap.indexOfKey(st.pid) < 0) { ProcessMemInfo mi = new ProcessMemInfo(st.name, st.pid, ProcessList.NATIVE_ADJ, -1, "native", null); mi.pss = pss; + mi.memtrack = memtrackTmp[0]; memInfos.add(mi); } } @@ -14405,12 +14413,15 @@ public final class ActivityManagerService extends ActivityManagerNative } long totalPss = 0; + long totalMemtrack = 0; for (int i=0, N=memInfos.size(); i() { @Override public int compare(ProcessMemInfo lhs, ProcessMemInfo rhs) { @@ -14437,6 +14448,7 @@ public final class ActivityManagerService extends ActivityManagerNative boolean firstLine = true; int lastOomAdj = Integer.MIN_VALUE; long extraNativeRam = 0; + long extraNativeMemtrack = 0; long cachedPss = 0; for (int i=0, N=memInfos.size(); i= 1MB. - if (mi.pss >= 1000) { + // The short form only has native processes that are >= 512K. + if (mi.pss >= 512) { appendMemInfo(shortNativeBuilder, mi); } else { extraNativeRam += mi.pss; + extraNativeMemtrack += mi.memtrack; } } else { // Short form has all other details, but if we have collected RAM // from smaller native processes let's dump a summary of that. if (extraNativeRam > 0) { appendBasicMemEntry(shortNativeBuilder, ProcessList.NATIVE_ADJ, - -1, extraNativeRam, "(Other native)"); + -1, extraNativeRam, extraNativeMemtrack, "(Other native)"); shortNativeBuilder.append('\n'); extraNativeRam = 0; } @@ -14508,7 +14521,14 @@ public final class ActivityManagerService extends ActivityManagerNative fullJavaBuilder.append(" "); ProcessList.appendRamKb(fullJavaBuilder, totalPss); - fullJavaBuilder.append(" kB: TOTAL\n"); + fullJavaBuilder.append(" kB: TOTAL"); + if (totalMemtrack > 0) { + fullJavaBuilder.append(" ("); + fullJavaBuilder.append(totalMemtrack); + fullJavaBuilder.append(" kB memtrack)"); + } else { + } + fullJavaBuilder.append("\n"); MemInfoReader memInfo = new MemInfoReader(); memInfo.readMemInfo(); @@ -17336,6 +17356,24 @@ public final class ActivityManagerService extends ActivityManagerNative } /** + * Record new PSS sample for a process. + */ + void recordPssSample(ProcessRecord proc, int procState, long pss, long uss, long now) { + proc.lastPssTime = now; + proc.baseProcessTracker.addPss(pss, uss, true, proc.pkgList); + if (DEBUG_PSS) Slog.d(TAG, "PSS of " + proc.toShortString() + + ": " + pss + " lastPss=" + proc.lastPss + + " state=" + ProcessList.makeProcStateString(procState)); + if (proc.initialIdlePss == 0) { + proc.initialIdlePss = pss; + } + proc.lastPss = pss; + if (procState >= ActivityManager.PROCESS_STATE_HOME) { + proc.lastCachedPss = pss; + } + } + + /** * Schedule PSS collection of a process. */ void requestPssLocked(ProcessRecord proc, int procState) { @@ -17370,13 +17408,24 @@ public final class ActivityManagerService extends ActivityManagerNative if (memLowered || now > (app.lastStateTime+ProcessList.PSS_ALL_INTERVAL)) { app.pssProcState = app.setProcState; app.nextPssTime = ProcessList.computeNextPssTime(app.curProcState, true, - isSleeping(), now); + mTestPssMode, isSleeping(), now); mPendingPssProcesses.add(app); } } mBgHandler.sendEmptyMessage(COLLECT_PSS_BG_MSG); } + public void setTestPssMode(boolean enabled) { + synchronized (this) { + mTestPssMode = enabled; + if (enabled) { + // Whenever we enable the mode, we want to take a snapshot all of current + // process mem use. + requestPssAllProcsLocked(SystemClock.uptimeMillis(), true, true); + } + } + } + /** * Ask a given process to GC right now. */ @@ -17673,9 +17722,22 @@ public final class ActivityManagerService extends ActivityManagerNative } if (app.setProcState < 0 || ProcessList.procStatesDifferForMem(app.curProcState, app.setProcState)) { + if (false && mTestPssMode && app.setProcState >= 0 && app.lastStateTime <= (now-200)) { + // Experimental code to more aggressively collect pss while + // running test... the problem is that this tends to collect + // the data right when a process is transitioning between process + // states, which well tend to give noisy data. + long start = SystemClock.uptimeMillis(); + long pss = Debug.getPss(app.pid, mTmpLong, null); + recordPssSample(app, app.curProcState, pss, mTmpLong[0], now); + mPendingPssProcesses.remove(app); + Slog.i(TAG, "Recorded pss for " + app + " state " + app.setProcState + + " to " + app.curProcState + ": " + + (SystemClock.uptimeMillis()-start) + "ms"); + } app.lastStateTime = now; app.nextPssTime = ProcessList.computeNextPssTime(app.curProcState, true, - isSleeping(), now); + mTestPssMode, isSleeping(), now); if (DEBUG_PSS) Slog.d(TAG, "Process state change from " + ProcessList.makeProcStateString(app.setProcState) + " to " + ProcessList.makeProcStateString(app.curProcState) + " next pss in " @@ -17685,7 +17747,7 @@ public final class ActivityManagerService extends ActivityManagerNative && now > (app.lastStateTime+ProcessList.PSS_MIN_TIME_FROM_STATE_CHANGE))) { requestPssLocked(app, app.setProcState); app.nextPssTime = ProcessList.computeNextPssTime(app.curProcState, false, - isSleeping(), now); + mTestPssMode, isSleeping(), now); } else if (false && DEBUG_PSS) { Slog.d(TAG, "Not requesting PSS of " + app + ": next=" + (app.nextPssTime-now)); } diff --git a/services/core/java/com/android/server/am/ProcessList.java b/services/core/java/com/android/server/am/ProcessList.java index cdc5134..aa86786 100644 --- a/services/core/java/com/android/server/am/ProcessList.java +++ b/services/core/java/com/android/server/am/ProcessList.java @@ -441,6 +441,18 @@ final class ProcessList { // The amount of time until PSS when a cached process stays in the same state. private static final int PSS_SAME_CACHED_INTERVAL = 30*60*1000; + // The amount of time during testing until PSS when a process first becomes top. + private static final int PSS_TEST_FIRST_TOP_INTERVAL = 3*1000; + + // The amount of time during testing until PSS when a process first goes into the background. + private static final int PSS_TEST_FIRST_BACKGROUND_INTERVAL = 5*1000; + + // The amount of time during testing until PSS when an important process stays in same state. + private static final int PSS_TEST_SAME_IMPORTANT_INTERVAL = 10*1000; + + // The amount of time during testing until PSS when a background process stays in same state. + private static final int PSS_TEST_SAME_BACKGROUND_INTERVAL = 15*1000; + public static final int PROC_MEM_PERSISTENT = 0; public static final int PROC_MEM_TOP = 1; public static final int PROC_MEM_IMPORTANT = 2; @@ -498,16 +510,50 @@ final class ProcessList { PSS_SAME_CACHED_INTERVAL, // ActivityManager.PROCESS_STATE_CACHED_EMPTY }; + private static final long[] sTestFirstAwakePssTimes = new long[] { + PSS_TEST_FIRST_TOP_INTERVAL, // ActivityManager.PROCESS_STATE_PERSISTENT + PSS_TEST_FIRST_TOP_INTERVAL, // ActivityManager.PROCESS_STATE_PERSISTENT_UI + PSS_TEST_FIRST_TOP_INTERVAL, // ActivityManager.PROCESS_STATE_TOP + PSS_TEST_FIRST_BACKGROUND_INTERVAL, // ActivityManager.PROCESS_STATE_IMPORTANT_FOREGROUND + PSS_TEST_FIRST_BACKGROUND_INTERVAL, // ActivityManager.PROCESS_STATE_IMPORTANT_BACKGROUND + PSS_TEST_FIRST_BACKGROUND_INTERVAL, // ActivityManager.PROCESS_STATE_BACKUP + PSS_TEST_FIRST_BACKGROUND_INTERVAL, // ActivityManager.PROCESS_STATE_HEAVY_WEIGHT + PSS_TEST_FIRST_BACKGROUND_INTERVAL, // ActivityManager.PROCESS_STATE_SERVICE + PSS_TEST_FIRST_BACKGROUND_INTERVAL, // ActivityManager.PROCESS_STATE_RECEIVER + PSS_TEST_FIRST_BACKGROUND_INTERVAL, // ActivityManager.PROCESS_STATE_HOME + PSS_TEST_FIRST_BACKGROUND_INTERVAL, // ActivityManager.PROCESS_STATE_LAST_ACTIVITY + PSS_TEST_FIRST_BACKGROUND_INTERVAL, // ActivityManager.PROCESS_STATE_CACHED_ACTIVITY + PSS_TEST_FIRST_BACKGROUND_INTERVAL, // ActivityManager.PROCESS_STATE_CACHED_ACTIVITY_CLIENT + PSS_TEST_FIRST_BACKGROUND_INTERVAL, // ActivityManager.PROCESS_STATE_CACHED_EMPTY + }; + + private static final long[] sTestSameAwakePssTimes = new long[] { + PSS_TEST_SAME_BACKGROUND_INTERVAL, // ActivityManager.PROCESS_STATE_PERSISTENT + PSS_TEST_SAME_BACKGROUND_INTERVAL, // ActivityManager.PROCESS_STATE_PERSISTENT_UI + PSS_TEST_SAME_IMPORTANT_INTERVAL, // ActivityManager.PROCESS_STATE_TOP + PSS_TEST_SAME_IMPORTANT_INTERVAL, // ActivityManager.PROCESS_STATE_IMPORTANT_FOREGROUND + PSS_TEST_SAME_IMPORTANT_INTERVAL, // ActivityManager.PROCESS_STATE_IMPORTANT_BACKGROUND + PSS_TEST_SAME_IMPORTANT_INTERVAL, // ActivityManager.PROCESS_STATE_BACKUP + PSS_TEST_SAME_IMPORTANT_INTERVAL, // ActivityManager.PROCESS_STATE_HEAVY_WEIGHT + PSS_TEST_SAME_BACKGROUND_INTERVAL, // ActivityManager.PROCESS_STATE_SERVICE + PSS_TEST_SAME_BACKGROUND_INTERVAL, // ActivityManager.PROCESS_STATE_RECEIVER + PSS_TEST_SAME_BACKGROUND_INTERVAL, // ActivityManager.PROCESS_STATE_HOME + PSS_TEST_SAME_BACKGROUND_INTERVAL, // ActivityManager.PROCESS_STATE_LAST_ACTIVITY + PSS_TEST_SAME_BACKGROUND_INTERVAL, // ActivityManager.PROCESS_STATE_CACHED_ACTIVITY + PSS_TEST_SAME_BACKGROUND_INTERVAL, // ActivityManager.PROCESS_STATE_CACHED_ACTIVITY_CLIENT + PSS_TEST_SAME_BACKGROUND_INTERVAL, // ActivityManager.PROCESS_STATE_CACHED_EMPTY + }; + public static boolean procStatesDifferForMem(int procState1, int procState2) { return sProcStateToProcMem[procState1] != sProcStateToProcMem[procState2]; } - public static long computeNextPssTime(int procState, boolean first, boolean sleeping, - long now) { - final long[] table = sleeping + public static long computeNextPssTime(int procState, boolean first, boolean test, + boolean sleeping, long now) { + final long[] table = test ? (first - ? sFirstAwakePssTimes - : sSameAwakePssTimes) + ? sTestFirstAwakePssTimes + : sTestSameAwakePssTimes) : (first ? sFirstAwakePssTimes : sSameAwakePssTimes); diff --git a/services/core/java/com/android/server/am/ProcessMemInfo.java b/services/core/java/com/android/server/am/ProcessMemInfo.java index c94694e..83d29e2 100644 --- a/services/core/java/com/android/server/am/ProcessMemInfo.java +++ b/services/core/java/com/android/server/am/ProcessMemInfo.java @@ -24,6 +24,7 @@ public class ProcessMemInfo { final String adjType; final String adjReason; long pss; + long memtrack; public ProcessMemInfo(String _name, int _pid, int _oomAdj, int _procState, String _adjType, String _adjReason) { diff --git a/services/core/java/com/android/server/am/ProcessStatsService.java b/services/core/java/com/android/server/am/ProcessStatsService.java index d05910b..55aec65 100644 --- a/services/core/java/com/android/server/am/ProcessStatsService.java +++ b/services/core/java/com/android/server/am/ProcessStatsService.java @@ -583,7 +583,7 @@ public final class ProcessStatsService extends IProcessStats.Stub { pw.println(" [--checkin|-c|--csv] [--csv-screen] [--csv-proc] [--csv-mem]"); pw.println(" [--details] [--full-details] [--current] [--hours N] [--last N]"); pw.println(" [--max N] --active] [--commit] [--reset] [--clear] [--write] [-h]"); - pw.println(" []"); + pw.println(" [--start-testing] [--stop-testing] []"); pw.println(" --checkin: perform a checkin: print and delete old committed states."); pw.println(" -c: print only state in checkin format."); pw.println(" --csv: output data suitable for putting in a spreadsheet."); @@ -603,6 +603,8 @@ public final class ProcessStatsService extends IProcessStats.Stub { pw.println(" --clear: clear all stats; does both --reset and deletes old stats."); pw.println(" --write: write current in-memory stats to disk."); pw.println(" --read: replace current stats with last-written stats."); + pw.println(" --start-testing: clear all stats and starting high frequency pss sampling."); + pw.println(" --stop-testing: stop high frequency pss sampling."); pw.println(" -a: print everything."); pw.println(" -h: print this help text."); pw.println(" : optional name of package to filter output by."); @@ -636,6 +638,7 @@ public final class ProcessStatsService extends IProcessStats.Stub { boolean dumpDetails = false; boolean dumpFullDetails = false; boolean dumpAll = false; + boolean quit = false; int aggregateHours = 0; int lastIndex = 0; int maxNum = 2; @@ -761,14 +764,14 @@ public final class ProcessStatsService extends IProcessStats.Stub { mProcessStats.mFlags |= ProcessStats.FLAG_COMPLETE; writeStateLocked(true, true); pw.println("Process stats committed."); + quit = true; } - return; } else if ("--reset".equals(arg)) { synchronized (mAm) { mProcessStats.resetSafely(); pw.println("Process stats reset."); + quit = true; } - return; } else if ("--clear".equals(arg)) { synchronized (mAm) { mProcessStats.resetSafely(); @@ -779,20 +782,32 @@ public final class ProcessStatsService extends IProcessStats.Stub { } } pw.println("All process stats cleared."); + quit = true; } - return; } else if ("--write".equals(arg)) { synchronized (mAm) { writeStateSyncLocked(); pw.println("Process stats written."); + quit = true; } - return; } else if ("--read".equals(arg)) { synchronized (mAm) { readLocked(mProcessStats, mFile); pw.println("Process stats read."); + quit = true; + } + } else if ("--start-testing".equals(arg)) { + synchronized (mAm) { + mAm.setTestPssMode(true); + pw.println("Started high frequency sampling."); + quit = true; + } + } else if ("--stop-testing".equals(arg)) { + synchronized (mAm) { + mAm.setTestPssMode(false); + pw.println("Stopped high frequency sampling."); + quit = true; } - return; } else if ("-h".equals(arg)) { dumpHelp(pw); return; @@ -815,6 +830,10 @@ public final class ProcessStatsService extends IProcessStats.Stub { } } + if (quit) { + return; + } + if (isCsv) { pw.print("Processes running summed over"); if (!csvSepScreenStats) { -- cgit v1.1