Fix issue #3022508: Crash during media scan

Don't kill processes for excessive wake lock use, even if they
are in the background, as long as they have running services.

Also fix some problems with this, such as not noting the kill
in battery stats.

And add killing of processes for cpu usage as well, along with
some optimizations to computing CPU usage.

And fix BatteryWaster to be better behaving for testing these
cases.

Add new "monitor" command to am to watch as the activity manager
does stuff (so we can catch things at the point of ANR).

Finally some miscellaneous debug output for the stuff here, as
well as in progress debugging of an ANR.

Change-Id: Ib32f55ca50fb7486b4be4eb5e695f8f60c882cd1
diff --git a/services/java/com/android/server/am/ActivityManagerService.java b/services/java/com/android/server/am/ActivityManagerService.java
index 3edf196..ff650ec 100644
--- a/services/java/com/android/server/am/ActivityManagerService.java
+++ b/services/java/com/android/server/am/ActivityManagerService.java
@@ -121,6 +121,8 @@
 import java.lang.IllegalStateException;
 import java.lang.ref.WeakReference;
 import java.util.ArrayList;
+import java.util.Collections;
+import java.util.Comparator;
 import java.util.HashMap;
 import java.util.HashSet;
 import java.util.Iterator;
@@ -144,6 +146,7 @@
     static final boolean DEBUG_BROADCAST = localLOGV || false;
     static final boolean DEBUG_BROADCAST_LIGHT = DEBUG_BROADCAST || false;
     static final boolean DEBUG_SERVICE = localLOGV || false;
+    static final boolean DEBUG_SERVICE_EXECUTING = localLOGV || false;
     static final boolean DEBUG_VISBILITY = localLOGV || false;
     static final boolean DEBUG_PROCESSES = localLOGV || false;
     static final boolean DEBUG_PROVIDER = localLOGV || false;
@@ -152,6 +155,8 @@
     static final boolean DEBUG_RESULTS = localLOGV || false;
     static final boolean DEBUG_BACKUP = localLOGV || false;
     static final boolean DEBUG_CONFIGURATION = localLOGV || false;
+    static final boolean DEBUG_POWER = localLOGV || false;
+    static final boolean DEBUG_POWER_QUICK = DEBUG_POWER || false;
     static final boolean VALIDATE_TOKENS = false;
     static final boolean SHOW_ACTIVITY_START_TIME = true;
     
@@ -197,8 +202,16 @@
     // The minimum amount of time between successive GC requests for a process.
     static final int GC_MIN_INTERVAL = 60*1000;
 
-    // The rate at which we check for apps using excessive wake locks -- 15 mins.
-    static final int WAKE_LOCK_CHECK_DELAY = 15*60*1000;
+    // The rate at which we check for apps using excessive power -- 15 mins.
+    static final int POWER_CHECK_DELAY = (DEBUG_POWER_QUICK ? 2 : 15) * 60*1000;
+
+    // The minimum sample duration we will allow before deciding we have
+    // enough data on wake locks to start killing things.
+    static final int WAKE_LOCK_MIN_CHECK_DURATION = (DEBUG_POWER_QUICK ? 1 : 5) * 60*1000;
+
+    // The minimum sample duration we will allow before deciding we have
+    // enough data on CPU usage to start killing things.
+    static final int CPU_MIN_CHECK_DURATION = (DEBUG_POWER_QUICK ? 1 : 5) * 60*1000;
 
     // How long we allow a receiver to run before giving up on it.
     static final int BROADCAST_TIMEOUT = 10*1000;
@@ -779,9 +792,14 @@
     boolean mDidAppSwitch;
     
     /**
-     * Last time (in realtime) at which we checked for wake lock usage.
+     * Last time (in realtime) at which we checked for power usage.
      */
-    long mLastWakeLockCheckTime;
+    long mLastPowerCheckRealtime;
+
+    /**
+     * Last time (in uptime) at which we checked for power usage.
+     */
+    long mLastPowerCheckUptime;
 
     /**
      * Set while we are wanting to sleep, to prevent any
@@ -1194,12 +1212,10 @@
             } break;
             case CHECK_EXCESSIVE_WAKE_LOCKS_MSG: {
                 synchronized (ActivityManagerService.this) {
-                    checkExcessiveWakeLocksLocked(true);
+                    checkExcessivePowerUsageLocked(true);
                     removeMessages(CHECK_EXCESSIVE_WAKE_LOCKS_MSG);
-                    if (mSleeping) {
-                        Message nmsg = obtainMessage(CHECK_EXCESSIVE_WAKE_LOCKS_MSG);
-                        sendMessageDelayed(nmsg, WAKE_LOCK_CHECK_DELAY);
-                    }
+                    Message nmsg = obtainMessage(CHECK_EXCESSIVE_WAKE_LOCKS_MSG);
+                    sendMessageDelayed(nmsg, POWER_CHECK_DELAY);
                 }
             } break;
             }
@@ -1394,7 +1410,8 @@
                 systemDir, "batterystats.bin").toString());
         mBatteryStatsService.getActiveStatistics().readLocked();
         mBatteryStatsService.getActiveStatistics().writeAsyncLocked();
-        mOnBattery = mBatteryStatsService.getActiveStatistics().getIsOnBattery();
+        mOnBattery = DEBUG_POWER ? true
+                : mBatteryStatsService.getActiveStatistics().getIsOnBattery();
         mBatteryStatsService.getActiveStatistics().setCallback(this);
         
         mUsageStatsService = new UsageStatsService(new File(
@@ -1514,10 +1531,12 @@
                             int perc = bstats.startAddingCpuLocked();
                             int totalUTime = 0;
                             int totalSTime = 0;
-                            final int N = mProcessStats.countWorkingStats();
+                            final int N = mProcessStats.countStats();
                             for (int i=0; i<N; i++) {
-                                ProcessStats.Stats st
-                                        = mProcessStats.getWorkingStats(i);
+                                ProcessStats.Stats st = mProcessStats.getStats(i);
+                                if (!st.working) {
+                                    continue;
+                                }
                                 ProcessRecord pr = mPidsSelfLocked.get(st.pid);
                                 int otherUTime = (st.rel_utime*perc)/100;
                                 int otherSTime = (st.rel_stime*perc)/100;
@@ -1528,6 +1547,7 @@
                                     ps.addCpuTimeLocked(st.rel_utime-otherUTime,
                                             st.rel_stime-otherSTime);
                                     ps.addSpeedStepTimes(cpuSpeedTimes);
+                                    pr.curCpuTime += (st.rel_utime+st.rel_stime) * 10;
                                 } else {
                                     BatteryStatsImpl.Uid.Proc ps =
                                             bstats.getProcessStatsLocked(st.name, st.pid);
@@ -1564,7 +1584,7 @@
         updateCpuStatsNow();
         synchronized (this) {
             synchronized(mPidsSelfLocked) {
-                mOnBattery = onBattery;
+                mOnBattery = DEBUG_POWER ? true : onBattery;
             }
         }
     }
@@ -2790,6 +2810,16 @@
         ArrayList<Integer> firstPids = new ArrayList<Integer>(5);
         SparseArray<Boolean> lastPids = new SparseArray<Boolean>(20);
 
+        if (mController != null) {
+            try {
+                // 0 == continue, -1 = kill process immediately
+                int res = mController.appEarlyNotResponding(app.processName, app.pid, annotation);
+                if (res < 0 && app.pid != MY_PID) Process.killProcess(app.pid);
+            } catch (RemoteException e) {
+                mController = null;
+            }
+        }
+
         long anrTime = SystemClock.uptimeMillis();
         if (MONITOR_CPU_USAGE) {
             updateCpuStatsNow();
@@ -2840,10 +2870,6 @@
             }
         }
 
-        final ProcessStats processStats = new ProcessStats(true);
-
-        File tracesFile = dumpStackTraces(true, firstPids, processStats, lastPids);
-
         // Log the ANR to the main log.
         StringBuilder info = mStringBuilder;
         info.setLength(0);
@@ -2859,6 +2885,10 @@
             info.append("Parent: ").append(parent.shortComponentName).append("\n");
         }
 
+        final ProcessStats processStats = new ProcessStats(true);
+
+        File tracesFile = dumpStackTraces(true, firstPids, processStats, lastPids);
+
         String cpuInfo = null;
         if (MONITOR_CPU_USAGE) {
             updateCpuStatsNow();
@@ -3735,7 +3765,7 @@
             if (mFactoryTest != SystemServer.FACTORY_TEST_LOW_LEVEL) {
                 // Start looking for apps that are abusing wake locks.
                 Message nmsg = mHandler.obtainMessage(CHECK_EXCESSIVE_WAKE_LOCKS_MSG);
-                mHandler.sendMessageDelayed(nmsg, WAKE_LOCK_CHECK_DELAY);
+                mHandler.sendMessageDelayed(nmsg, POWER_CHECK_DELAY);
                 // Tell anyone interested that we are done booting!
                 SystemProperties.set("sys.boot_completed", "1");
                 broadcastIntentLocked(null, null,
@@ -5648,10 +5678,10 @@
             }
 
             // Initialize the wake times of all processes.
-            checkExcessiveWakeLocksLocked(false);
+            checkExcessivePowerUsageLocked(false);
             mHandler.removeMessages(CHECK_EXCESSIVE_WAKE_LOCKS_MSG);
             Message nmsg = mHandler.obtainMessage(CHECK_EXCESSIVE_WAKE_LOCKS_MSG);
-            mHandler.sendMessageDelayed(nmsg, WAKE_LOCK_CHECK_DELAY);
+            mHandler.sendMessageDelayed(nmsg, POWER_CHECK_DELAY);
         }
     }
 
@@ -5701,7 +5731,6 @@
             mWindowManager.setEventDispatching(true);
             mSleeping = false;
             mMainStack.resumeTopActivityLocked(null);
-            mHandler.removeMessages(CHECK_EXCESSIVE_WAKE_LOCKS_MSG);
         }
     }
 
@@ -6998,12 +7027,13 @@
                 pw.println("Activity manager dump options:");
                 pw.println("  [-a] [-h] [cmd] ...");
                 pw.println("  cmd may be one of:");
-                pw.println("    activities: activity stack state");
-                pw.println("    broadcasts: broadcast state");
-                pw.println("    intents: pending intent state");
-                pw.println("    processes: process state");
-                pw.println("    providers: content provider state");
-                pw.println("    services: service state");
+                pw.println("    a[ctivities]: activity stack state");
+                pw.println("    b[roadcasts]: broadcast state");
+                pw.println("    i[ntents]: pending intent state");
+                pw.println("    p[rocesses]: process state");
+                pw.println("    o[om]: out of memory management");
+                pw.println("    prov[iders]: content provider state");
+                pw.println("    s[ervices]: service state");
                 pw.println("    service [name]: service client-side state");
                 return;
             } else {
@@ -7035,6 +7065,11 @@
                     dumpProcessesLocked(fd, pw, args, opti, true);
                 }
                 return;
+            } else if ("oom".equals(cmd) || "o".equals(cmd)) {
+                synchronized (this) {
+                    dumpOomLocked(fd, pw, args, opti, true);
+                }
+                return;
             } else if ("providers".equals(cmd) || "prov".equals(cmd)) {
                 synchronized (this) {
                     dumpProvidersLocked(fd, pw, args, opti, true);
@@ -7150,7 +7185,7 @@
         
         return true;
     }
-        
+
     boolean dumpProcessesLocked(FileDescriptor fd, PrintWriter pw, String[] args,
             int opti, boolean dumpAll) {
         boolean needSep = false;
@@ -7180,8 +7215,8 @@
             if (needSep) pw.println(" ");
             needSep = true;
             pw.println("  Running processes (most recent first):");
-            dumpProcessList(pw, this, mLruProcesses, "    ",
-                    "Proc", "PERS", true);
+            dumpProcessOomList(pw, this, mLruProcesses, "    ",
+                    "Proc", "PERS", false);
             needSep = true;
         }
 
@@ -7212,7 +7247,7 @@
             needSep = true;
             pw.println("  Persisent processes that are starting:");
             dumpProcessList(pw, this, mPersistentStartingProcesses, "    ",
-                    "Starting Norm", "Restarting PERS", false);
+                    "Starting Norm", "Restarting PERS");
         }
 
         if (mStartingProcesses.size() > 0) {
@@ -7220,7 +7255,7 @@
             needSep = true;
             pw.println("  Processes that are starting:");
             dumpProcessList(pw, this, mStartingProcesses, "    ",
-                    "Starting Norm", "Starting PERS", false);
+                    "Starting Norm", "Starting PERS");
         }
 
         if (mRemovedProcesses.size() > 0) {
@@ -7228,7 +7263,7 @@
             needSep = true;
             pw.println("  Processes that are being removed:");
             dumpProcessList(pw, this, mRemovedProcesses, "    ",
-                    "Removed Norm", "Removed PERS", false);
+                    "Removed Norm", "Removed PERS");
         }
         
         if (mProcessesOnHold.size() > 0) {
@@ -7236,26 +7271,10 @@
             needSep = true;
             pw.println("  Processes that are on old until the system is ready:");
             dumpProcessList(pw, this, mProcessesOnHold, "    ",
-                    "OnHold Norm", "OnHold PERS", false);
+                    "OnHold Norm", "OnHold PERS");
         }
 
-        if (mProcessesToGc.size() > 0) {
-            if (needSep) pw.println(" ");
-            needSep = true;
-            pw.println("  Processes that are waiting to GC:");
-            long now = SystemClock.uptimeMillis();
-            for (int i=0; i<mProcessesToGc.size(); i++) {
-                ProcessRecord proc = mProcessesToGc.get(i);
-                pw.print("    Process "); pw.println(proc);
-                pw.print("      lowMem="); pw.print(proc.reportLowMemory);
-                        pw.print(", last gced=");
-                        pw.print(now-proc.lastRequestedGc);
-                        pw.print(" ms ago, last lowMem=");
-                        pw.print(now-proc.lastLowMemory);
-                        pw.println(" ms ago");
-                
-            }
-        }
+        needSep = dumpProcessesToGc(fd, pw, args, opti, needSep, dumpAll);
         
         if (mProcessCrashTimes.getMap().size() > 0) {
             if (needSep) pw.println(" ");
@@ -7319,6 +7338,12 @@
             pw.println("  mBooting=" + mBooting
                     + " mBooted=" + mBooted
                     + " mFactoryTest=" + mFactoryTest);
+            pw.print("  mLastPowerCheckRealtime=");
+                    TimeUtils.formatDuration(mLastPowerCheckRealtime, pw);
+                    pw.println("");
+            pw.print("  mLastPowerCheckUptime=");
+                    TimeUtils.formatDuration(mLastPowerCheckUptime, pw);
+                    pw.println("");
             pw.println("  mGoingToSleep=" + mMainStack.mGoingToSleep);
             pw.println("  mLaunchingActivity=" + mMainStack.mLaunchingActivity);
             pw.println("  mAdjSeq=" + mAdjSeq + " mLruSeq=" + mLruSeq);
@@ -7327,6 +7352,75 @@
         return true;
     }
 
+    boolean dumpProcessesToGc(FileDescriptor fd, PrintWriter pw, String[] args,
+            int opti, boolean needSep, boolean dumpAll) {
+        if (mProcessesToGc.size() > 0) {
+            if (needSep) pw.println(" ");
+            needSep = true;
+            pw.println("  Processes that are waiting to GC:");
+            long now = SystemClock.uptimeMillis();
+            for (int i=0; i<mProcessesToGc.size(); i++) {
+                ProcessRecord proc = mProcessesToGc.get(i);
+                pw.print("    Process "); pw.println(proc);
+                pw.print("      lowMem="); pw.print(proc.reportLowMemory);
+                        pw.print(", last gced=");
+                        pw.print(now-proc.lastRequestedGc);
+                        pw.print(" ms ago, last lowMem=");
+                        pw.print(now-proc.lastLowMemory);
+                        pw.println(" ms ago");
+
+            }
+        }
+        return needSep;
+    }
+
+    boolean dumpOomLocked(FileDescriptor fd, PrintWriter pw, String[] args,
+            int opti, boolean dumpAll) {
+        boolean needSep = false;
+
+        if (mLruProcesses.size() > 0) {
+            ArrayList<ProcessRecord> procs = new ArrayList<ProcessRecord>(mLruProcesses);
+
+            Comparator<ProcessRecord> comparator = new Comparator<ProcessRecord>() {
+                @Override
+                public int compare(ProcessRecord object1, ProcessRecord object2) {
+                    if (object1.setAdj != object2.setAdj) {
+                        return object1.setAdj > object2.setAdj ? -1 : 1;
+                    }
+                    if (object1.setSchedGroup != object2.setSchedGroup) {
+                        return object1.setSchedGroup > object2.setSchedGroup ? -1 : 1;
+                    }
+                    if (object1.keeping != object2.keeping) {
+                        return object1.keeping ? -1 : 1;
+                    }
+                    if (object1.pid != object2.pid) {
+                        return object1.pid > object2.pid ? -1 : 1;
+                    }
+                    return 0;
+                }
+            };
+
+            Collections.sort(procs, comparator);
+
+            if (needSep) pw.println(" ");
+            needSep = true;
+            pw.println("  Process OOM control:");
+            dumpProcessOomList(pw, this, procs, "    ",
+                    "Proc", "PERS", true);
+            needSep = true;
+        }
+
+        needSep = dumpProcessesToGc(fd, pw, args, opti, needSep, dumpAll);
+
+        pw.println(" ");
+        pw.println("  mHomeProcess: " + mHomeProcess);
+        if (mHeavyWeightProcess != null) {
+            pw.println("  mHeavyWeightProcess: " + mHeavyWeightProcess);
+        }
+
+        return true;
+    }
+
     /**
      * There are three ways to call this:
      *  - no service specified: dump all the services
@@ -7694,84 +7788,14 @@
     
     private static final int dumpProcessList(PrintWriter pw,
             ActivityManagerService service, List list,
-            String prefix, String normalLabel, String persistentLabel,
-            boolean inclOomAdj) {
+            String prefix, String normalLabel, String persistentLabel) {
         int numPers = 0;
         final int N = list.size()-1;
         for (int i=N; i>=0; i--) {
             ProcessRecord r = (ProcessRecord)list.get(i);
-            if (false) {
-                pw.println(prefix + (r.persistent ? persistentLabel : normalLabel)
-                      + " #" + i + ":");
-                r.dump(pw, prefix + "  ");
-            } else if (inclOomAdj) {
-                String oomAdj;
-                if (r.setAdj >= EMPTY_APP_ADJ) {
-                    oomAdj = buildOomTag("empty", null, r.setAdj, EMPTY_APP_ADJ);
-                } else if (r.setAdj >= HIDDEN_APP_MIN_ADJ) {
-                    oomAdj = buildOomTag("bak", "  ", r.setAdj, HIDDEN_APP_MIN_ADJ);
-                } else if (r.setAdj >= HOME_APP_ADJ) {
-                    oomAdj = buildOomTag("home ", null, r.setAdj, HOME_APP_ADJ);
-                } else if (r.setAdj >= SECONDARY_SERVER_ADJ) {
-                    oomAdj = buildOomTag("svc", "  ", r.setAdj, SECONDARY_SERVER_ADJ);
-                } else if (r.setAdj >= BACKUP_APP_ADJ) {
-                    oomAdj = buildOomTag("bckup", null, r.setAdj, BACKUP_APP_ADJ);
-                } else if (r.setAdj >= HEAVY_WEIGHT_APP_ADJ) {
-                    oomAdj = buildOomTag("hvy  ", null, r.setAdj, HEAVY_WEIGHT_APP_ADJ);
-                } else if (r.setAdj >= PERCEPTIBLE_APP_ADJ) {
-                    oomAdj = buildOomTag("prcp ", null, r.setAdj, PERCEPTIBLE_APP_ADJ);
-                } else if (r.setAdj >= VISIBLE_APP_ADJ) {
-                    oomAdj = buildOomTag("vis  ", null, r.setAdj, VISIBLE_APP_ADJ);
-                } else if (r.setAdj >= FOREGROUND_APP_ADJ) {
-                    oomAdj = buildOomTag("fore ", null, r.setAdj, FOREGROUND_APP_ADJ);
-                } else if (r.setAdj >= CORE_SERVER_ADJ) {
-                    oomAdj = buildOomTag("core ", null, r.setAdj, CORE_SERVER_ADJ);
-                } else if (r.setAdj >= SYSTEM_ADJ) {
-                    oomAdj = buildOomTag("sys  ", null, r.setAdj, SYSTEM_ADJ);
-                } else {
-                    oomAdj = Integer.toString(r.setAdj);
-                }
-                String schedGroup;
-                switch (r.setSchedGroup) {
-                    case Process.THREAD_GROUP_BG_NONINTERACTIVE:
-                        schedGroup = "B";
-                        break;
-                    case Process.THREAD_GROUP_DEFAULT:
-                        schedGroup = "F";
-                        break;
-                    default:
-                        schedGroup = Integer.toString(r.setSchedGroup);
-                        break;
-                }
-                pw.println(String.format("%s%s #%2d: adj=%s/%s %s (%s)",
-                        prefix, (r.persistent ? persistentLabel : normalLabel),
-                        N-i, oomAdj, schedGroup, r.toShortString(), r.adjType));
-                if (r.adjSource != null || r.adjTarget != null) {
-                    pw.print(prefix);
-                    pw.print("          ");
-                    if (r.adjTarget instanceof ComponentName) {
-                        pw.print(((ComponentName)r.adjTarget).flattenToShortString());
-                    } else if (r.adjTarget != null) {
-                        pw.print(r.adjTarget.toString());
-                    } else {
-                        pw.print("{null}");
-                    }
-                    pw.print("<=");
-                    if (r.adjSource instanceof ProcessRecord) {
-                        pw.print("Proc{");
-                        pw.print(((ProcessRecord)r.adjSource).toShortString());
-                        pw.println("}");
-                    } else if (r.adjSource != null) {
-                        pw.println(r.adjSource.toString());
-                    } else {
-                        pw.println("{null}");
-                    }
-                }
-            } else {
-                pw.println(String.format("%s%s #%2d: %s",
-                        prefix, (r.persistent ? persistentLabel : normalLabel),
-                        i, r.toString()));
-            }
+            pw.println(String.format("%s%s #%2d: %s",
+                    prefix, (r.persistent ? persistentLabel : normalLabel),
+                    i, r.toString()));
             if (r.persistent) {
                 numPers++;
             }
@@ -7779,6 +7803,132 @@
         return numPers;
     }
 
+    private static final void dumpProcessOomList(PrintWriter pw,
+            ActivityManagerService service, List<ProcessRecord> list,
+            String prefix, String normalLabel, String persistentLabel,
+            boolean inclDetails) {
+
+        final long curRealtime = SystemClock.elapsedRealtime();
+        final long realtimeSince = curRealtime - service.mLastPowerCheckRealtime;
+        final long curUptime = SystemClock.uptimeMillis();
+        final long uptimeSince = curUptime - service.mLastPowerCheckUptime;
+
+        final int N = list.size()-1;
+        for (int i=N; i>=0; i--) {
+            ProcessRecord r = list.get(i);
+            String oomAdj;
+            if (r.setAdj >= EMPTY_APP_ADJ) {
+                oomAdj = buildOomTag("empty", null, r.setAdj, EMPTY_APP_ADJ);
+            } else if (r.setAdj >= HIDDEN_APP_MIN_ADJ) {
+                oomAdj = buildOomTag("bak", "  ", r.setAdj, HIDDEN_APP_MIN_ADJ);
+            } else if (r.setAdj >= HOME_APP_ADJ) {
+                oomAdj = buildOomTag("home ", null, r.setAdj, HOME_APP_ADJ);
+            } else if (r.setAdj >= SECONDARY_SERVER_ADJ) {
+                oomAdj = buildOomTag("svc", "  ", r.setAdj, SECONDARY_SERVER_ADJ);
+            } else if (r.setAdj >= BACKUP_APP_ADJ) {
+                oomAdj = buildOomTag("bckup", null, r.setAdj, BACKUP_APP_ADJ);
+            } else if (r.setAdj >= HEAVY_WEIGHT_APP_ADJ) {
+                oomAdj = buildOomTag("hvy  ", null, r.setAdj, HEAVY_WEIGHT_APP_ADJ);
+            } else if (r.setAdj >= PERCEPTIBLE_APP_ADJ) {
+                oomAdj = buildOomTag("prcp ", null, r.setAdj, PERCEPTIBLE_APP_ADJ);
+            } else if (r.setAdj >= VISIBLE_APP_ADJ) {
+                oomAdj = buildOomTag("vis  ", null, r.setAdj, VISIBLE_APP_ADJ);
+            } else if (r.setAdj >= FOREGROUND_APP_ADJ) {
+                oomAdj = buildOomTag("fore ", null, r.setAdj, FOREGROUND_APP_ADJ);
+            } else if (r.setAdj >= CORE_SERVER_ADJ) {
+                oomAdj = buildOomTag("core ", null, r.setAdj, CORE_SERVER_ADJ);
+            } else if (r.setAdj >= SYSTEM_ADJ) {
+                oomAdj = buildOomTag("sys  ", null, r.setAdj, SYSTEM_ADJ);
+            } else {
+                oomAdj = Integer.toString(r.setAdj);
+            }
+            String schedGroup;
+            switch (r.setSchedGroup) {
+                case Process.THREAD_GROUP_BG_NONINTERACTIVE:
+                    schedGroup = "B";
+                    break;
+                case Process.THREAD_GROUP_DEFAULT:
+                    schedGroup = "F";
+                    break;
+                default:
+                    schedGroup = Integer.toString(r.setSchedGroup);
+                    break;
+            }
+            pw.println(String.format("%s%s #%2d: adj=%s/%s %s (%s)",
+                    prefix, (r.persistent ? persistentLabel : normalLabel),
+                    N-i, oomAdj, schedGroup, r.toShortString(), r.adjType));
+            if (r.adjSource != null || r.adjTarget != null) {
+                pw.print(prefix);
+                pw.print("          ");
+                if (r.adjTarget instanceof ComponentName) {
+                    pw.print(((ComponentName)r.adjTarget).flattenToShortString());
+                } else if (r.adjTarget != null) {
+                    pw.print(r.adjTarget.toString());
+                } else {
+                    pw.print("{null}");
+                }
+                pw.print("<=");
+                if (r.adjSource instanceof ProcessRecord) {
+                    pw.print("Proc{");
+                    pw.print(((ProcessRecord)r.adjSource).toShortString());
+                    pw.println("}");
+                } else if (r.adjSource != null) {
+                    pw.println(r.adjSource.toString());
+                } else {
+                    pw.println("{null}");
+                }
+            }
+            if (inclDetails) {
+                pw.print(prefix);
+                pw.print("    ");
+                pw.print("oom: max="); pw.print(r.maxAdj);
+                pw.print(" hidden="); pw.print(r.hiddenAdj);
+                pw.print(" curRaw="); pw.print(r.curRawAdj);
+                pw.print(" setRaw="); pw.print(r.setRawAdj);
+                pw.print(" cur="); pw.print(r.curAdj);
+                pw.print(" set="); pw.println(r.setAdj);
+                pw.print(prefix);
+                pw.print("    ");
+                pw.print("keeping="); pw.print(r.keeping);
+                pw.print(" hidden="); pw.print(r.hidden);
+                pw.print(" empty="); pw.println(r.empty);
+
+                if (!r.keeping) {
+                    if (r.lastWakeTime != 0) {
+                        long wtime;
+                        BatteryStatsImpl stats = service.mBatteryStatsService.getActiveStatistics();
+                        synchronized (stats) {
+                            wtime = stats.getProcessWakeTime(r.info.uid,
+                                    r.pid, curRealtime);
+                        }
+                        long timeUsed = wtime - r.lastWakeTime;
+                        pw.print(prefix);
+                        pw.print("    ");
+                        pw.print("keep awake over ");
+                        TimeUtils.formatDuration(realtimeSince, pw);
+                        pw.print(" used ");
+                        TimeUtils.formatDuration(timeUsed, pw);
+                        pw.print(" (");
+                        pw.print((timeUsed*100)/realtimeSince);
+                        pw.println("%)");
+                    }
+                    if (r.lastCpuTime != 0) {
+                        long timeUsed = r.curCpuTime - r.lastCpuTime;
+                        pw.print(prefix);
+                        pw.print("    ");
+                        pw.print("run cpu over ");
+                        TimeUtils.formatDuration(uptimeSince, pw);
+                        pw.print(" used ");
+                        TimeUtils.formatDuration(timeUsed, pw);
+                        pw.print(" (");
+                        pw.print((timeUsed*100)/uptimeSince);
+                        pw.println("%)");
+                    }
+                }
+            }
+        }
+    }
+
     static final void dumpApplicationMemoryUsage(FileDescriptor fd,
             PrintWriter pw, List list, String prefix, String[] args) {
         final boolean isCheckinRequest = scanArgs(args, "--checkin");
@@ -8405,7 +8555,11 @@
         return null;
     }
 
-    private final void bumpServiceExecutingLocked(ServiceRecord r) {
+    private final void bumpServiceExecutingLocked(ServiceRecord r, String why) {
+        if (DEBUG_SERVICE) Log.v(TAG, ">>> EXECUTING "
+                + why + " of " + r + " in app " + r.app);
+        else if (DEBUG_SERVICE_EXECUTING) Log.v(TAG, ">>> EXECUTING "
+                + why + " of " + r.shortName);
         long now = SystemClock.uptimeMillis();
         if (r.executeNesting == 0 && r.app != null) {
             if (r.app.executingServices.size() == 0) {
@@ -8443,8 +8597,7 @@
                     grantUriPermissionUncheckedFromIntentLocked(si.targetPermissionUid,
                             r.packageName, si.intent, si.getUriPermissionsLocked());
                 }
-                if (DEBUG_SERVICE) Slog.v(TAG, ">>> EXECUTING start of " + r);
-                bumpServiceExecutingLocked(r);
+                bumpServiceExecutingLocked(r, "start");
                 if (!oomAdjusted) {
                     oomAdjusted = true;
                     updateOomAdjLocked(r.app);
@@ -8477,9 +8630,7 @@
         }
         if ((!i.requested || rebind) && i.apps.size() > 0) {
             try {
-                if (DEBUG_SERVICE) Slog.v(TAG, ">>> EXECUTING bind of " + r
-                        + " in " + i + ": shouldUnbind=" + i.hasBound);
-                bumpServiceExecutingLocked(r);
+                bumpServiceExecutingLocked(r, "bind");
                 r.app.thread.scheduleBindService(r, i.intent.getIntent(), rebind);
                 if (!rebind) {
                     i.requested = true;
@@ -8514,8 +8665,7 @@
         r.restartTime = r.lastActivity = SystemClock.uptimeMillis();
 
         app.services.add(r);
-        if (DEBUG_SERVICE) Slog.v(TAG, ">>> EXECUTING create of " + r + " " + r.intent);
-        bumpServiceExecutingLocked(r);
+        bumpServiceExecutingLocked(r, "create");
         updateLruProcessLocked(app, true, true);
 
         boolean created = false;
@@ -8767,9 +8917,7 @@
                         + ": hasBound=" + ibr.hasBound);
                 if (r.app != null && r.app.thread != null && ibr.hasBound) {
                     try {
-                        if (DEBUG_SERVICE) Slog.v(TAG, ">>> EXECUTING bring down unbind of " + r
-                                + " for " + ibr);
-                        bumpServiceExecutingLocked(r);
+                        bumpServiceExecutingLocked(r, "bring down unbind");
                         updateOomAdjLocked(r.app);
                         ibr.hasBound = false;
                         r.app.thread.scheduleUnbindService(r,
@@ -8820,12 +8968,7 @@
             r.app.services.remove(r);
             if (r.app.thread != null) {
                 try {
-                    if (DEBUG_SERVICE) {
-                        RuntimeException here = new RuntimeException();
-                        here.fillInStackTrace();
-                        Slog.v(TAG, ">>> EXECUTING stop of " + r, here);
-                    }
-                    bumpServiceExecutingLocked(r);
+                    bumpServiceExecutingLocked(r, "stop");
                     mStoppingServices.add(r);
                     updateOomAdjLocked(r.app);
                     r.app.thread.scheduleStopService(r);
@@ -9281,9 +9424,7 @@
         if (s.app != null && s.app.thread != null && b.intent.apps.size() == 0
                 && b.intent.hasBound) {
             try {
-                if (DEBUG_SERVICE) Slog.v(TAG, ">>> EXECUTING unbind of " + s
-                        + " from " + b);
-                bumpServiceExecutingLocked(s);
+                bumpServiceExecutingLocked(s, "unbind");
                 updateOomAdjLocked(s.app);
                 b.intent.hasBound = false;
                 // Assume the client doesn't want to know about a rebind;
@@ -9504,14 +9645,20 @@
         if (DEBUG_SERVICE) Slog.v(TAG, "<<< DONE EXECUTING " + r
                 + ": nesting=" + r.executeNesting
                 + ", inStopping=" + inStopping + ", app=" + r.app);
+        else if (DEBUG_SERVICE_EXECUTING) Slog.v(TAG, "<<< DONE EXECUTING " + r.shortName);
         r.executeNesting--;
         if (r.executeNesting <= 0 && r.app != null) {
+            if (DEBUG_SERVICE) Slog.v(TAG,
+                    "Nesting at 0 of " + r.shortName);
             r.app.executingServices.remove(r);
             if (r.app.executingServices.size() == 0) {
+                if (DEBUG_SERVICE || DEBUG_SERVICE_EXECUTING) Slog.v(TAG,
+                        "No more executingServices of " + r.shortName);
                 mHandler.removeMessages(SERVICE_TIMEOUT_MSG, r.app);
             }
             if (inStopping) {
-                if (DEBUG_SERVICE) Slog.v(TAG, "doneExecuting remove stopping " + r);
+                if (DEBUG_SERVICE) Slog.v(TAG,
+                        "doneExecuting remove stopping " + r);
                 mStoppingServices.remove(r);
             }
             updateOomAdjLocked(r.app);
@@ -11187,6 +11334,7 @@
             app.adjType = "fixed";
             app.adjSeq = mAdjSeq;
             app.curRawAdj = app.maxAdj;
+            app.keeping = true;
             app.curSchedGroup = Process.THREAD_GROUP_DEFAULT;
             return (app.curAdj=app.maxAdj);
        }
@@ -11194,6 +11342,7 @@
         app.adjTypeCode = ActivityManager.RunningAppProcessInfo.REASON_UNKNOWN;
         app.adjSource = null;
         app.adjTarget = null;
+        app.keeping = false;
         app.empty = false;
         app.hidden = false;
 
@@ -11323,6 +11472,9 @@
                     if (adj > SECONDARY_SERVER_ADJ) {
                         app.adjType = "started-bg-services";
                     }
+                    // Don't kill this process because it is doing work; it
+                    // has said it is doing work.
+                    app.keeping = true;
                 }
                 if (s.connections.size() > 0 && (adj > FOREGROUND_APP_ADJ
                         || schedGroup == Process.THREAD_GROUP_BG_NONINTERACTIVE)) {
@@ -11356,6 +11508,9 @@
                                     if (!client.hidden) {
                                         app.hidden = false;
                                     }
+                                    if (client.keeping) {
+                                        app.keeping = true;
+                                    }
                                     app.adjType = "service";
                                     app.adjTypeCode = ActivityManager.RunningAppProcessInfo
                                             .REASON_SERVICE_IN_USE;
@@ -11389,7 +11544,7 @@
                 }
             }
             
-            // Finally, f this process has active services running in it, we
+            // Finally, if this process has active services running in it, we
             // would like to avoid killing it unless it would prevent the current
             // application from running.  By default we put the process in
             // with the rest of the background processes; as we scan through
@@ -11431,6 +11586,9 @@
                             if (!client.hidden) {
                                 app.hidden = false;
                             }
+                            if (client.keeping) {
+                                app.keeping = true;
+                            }
                             app.adjType = "provider";
                             app.adjTypeCode = ActivityManager.RunningAppProcessInfo
                                     .REASON_PROVIDER_IN_USE;
@@ -11450,6 +11608,7 @@
                         adj = FOREGROUND_APP_ADJ;
                         schedGroup = Process.THREAD_GROUP_DEFAULT;
                         app.hidden = false;
+                        app.keeping = true;
                         app.adjType = "provider";
                         app.adjTarget = cpr.name;
                     }
@@ -11467,6 +11626,9 @@
                 schedGroup = Process.THREAD_GROUP_DEFAULT;
             }
         }
+        if (adj < HIDDEN_APP_MIN_ADJ) {
+            app.keeping = true;
+        }
 
         app.curAdj = adj;
         app.curSchedGroup = schedGroup;
@@ -11604,57 +11766,99 @@
         }
     }
 
-    final void checkExcessiveWakeLocksLocked(boolean doKills) {
+    final void checkExcessivePowerUsageLocked(boolean doKills) {
+        updateCpuStatsNow();
+
         BatteryStatsImpl stats = mBatteryStatsService.getActiveStatistics();
-        if (mLastWakeLockCheckTime == 0) {
-            doKills = false;
+        boolean doWakeKills = doKills;
+        boolean doCpuKills = doKills;
+        if (mLastPowerCheckRealtime == 0) {
+            doWakeKills = false;
+        }
+        if (mLastPowerCheckUptime == 0) {
+            doCpuKills = false;
         }
         if (stats.isScreenOn()) {
-            doKills = false;
+            doWakeKills = false;
         }
         final long curRealtime = SystemClock.elapsedRealtime();
-        final long timeSince = curRealtime - mLastWakeLockCheckTime;
-        mLastWakeLockCheckTime = curRealtime;
-        if (timeSince < (WAKE_LOCK_CHECK_DELAY/3)) {
-            doKills = false;
+        final long realtimeSince = curRealtime - mLastPowerCheckRealtime;
+        final long curUptime = SystemClock.uptimeMillis();
+        final long uptimeSince = curUptime - mLastPowerCheckUptime;
+        mLastPowerCheckRealtime = curRealtime;
+        mLastPowerCheckUptime = curUptime;
+        if (realtimeSince < WAKE_LOCK_MIN_CHECK_DURATION) {
+            doWakeKills = false;
+        }
+        if (uptimeSince < CPU_MIN_CHECK_DURATION) {
+            doCpuKills = false;
         }
         int i = mLruProcesses.size();
         while (i > 0) {
             i--;
             ProcessRecord app = mLruProcesses.get(i);
-            if (app.curAdj >= HIDDEN_APP_MIN_ADJ) {
+            if (!app.keeping) {
                 long wtime;
                 synchronized (stats) {
                     wtime = stats.getProcessWakeTime(app.info.uid,
                             app.pid, curRealtime);
                 }
-                long timeUsed = wtime - app.lastWakeTime;
-                if (false) {
+                long wtimeUsed = wtime - app.lastWakeTime;
+                long cputimeUsed = app.curCpuTime - app.lastCpuTime;
+                if (DEBUG_POWER) {
                     StringBuilder sb = new StringBuilder(128);
                     sb.append("Wake for ");
                     app.toShortString(sb);
                     sb.append(": over ");
-                    TimeUtils.formatDuration(timeSince, sb);
+                    TimeUtils.formatDuration(realtimeSince, sb);
                     sb.append(" used ");
-                    TimeUtils.formatDuration(timeUsed, sb);
+                    TimeUtils.formatDuration(wtimeUsed, sb);
                     sb.append(" (");
-                    sb.append((timeUsed*100)/timeSince);
+                    sb.append((wtimeUsed*100)/realtimeSince);
+                    sb.append("%)");
+                    Slog.i(TAG, sb.toString());
+                    sb.setLength(0);
+                    sb.append("CPU for ");
+                    app.toShortString(sb);
+                    sb.append(": over ");
+                    TimeUtils.formatDuration(uptimeSince, sb);
+                    sb.append(" used ");
+                    TimeUtils.formatDuration(cputimeUsed, sb);
+                    sb.append(" (");
+                    sb.append((cputimeUsed*100)/uptimeSince);
                     sb.append("%)");
                     Slog.i(TAG, sb.toString());
                 }
                 // If a process has held a wake lock for more
                 // than 50% of the time during this period,
                 // that sounds pad.  Kill!
-                if (doKills && timeSince > 0
-                        && ((timeUsed*100)/timeSince) >= 50) {
-                    Slog.i(TAG, "Excessive wake lock in " + app.processName
-                            + " (pid " + app.pid + "): held " + timeUsed
-                            + " during " + timeSince);
+                if (doWakeKills && realtimeSince > 0
+                        && ((wtimeUsed*100)/realtimeSince) >= 50) {
+                    synchronized (stats) {
+                        stats.reportExcessiveWakeLocked(app.info.uid, app.processName,
+                                realtimeSince, wtimeUsed);
+                    }
+                    Slog.w(TAG, "Excessive wake lock in " + app.processName
+                            + " (pid " + app.pid + "): held " + wtimeUsed
+                            + " during " + realtimeSince);
                     EventLog.writeEvent(EventLogTags.AM_KILL, app.pid,
                             app.processName, app.setAdj, "excessive wake lock");
                     Process.killProcessQuiet(app.pid);
+                } else if (doCpuKills && uptimeSince > 0
+                        && ((cputimeUsed*100)/uptimeSince) >= 50) {
+                    synchronized (stats) {
+                        stats.reportExcessiveCpuLocked(app.info.uid, app.processName,
+                                uptimeSince, cputimeUsed);
+                    }
+                    Slog.w(TAG, "Excessive CPU in " + app.processName
+                            + " (pid " + app.pid + "): used " + cputimeUsed
+                            + " during " + uptimeSince);
+                    EventLog.writeEvent(EventLogTags.AM_KILL, app.pid,
+                            app.processName, app.setAdj, "excessive cpu");
+                    Process.killProcessQuiet(app.pid);
                 } else {
                     app.lastWakeTime = wtime;
+                    app.lastCpuTime = app.curCpuTime;
                 }
             }
         }
@@ -11668,6 +11872,8 @@
             return true;
         }
 
+        final boolean wasKeeping = app.keeping;
+
         int adj = computeOomAdjLocked(app, hiddenAdj, TOP_APP, false);
 
         if ((app.pid != 0 && app.pid != MY_PID) || Process.supportsProcesses()) {
@@ -11682,13 +11888,20 @@
                     // Likewise do a gc when an app is moving in to the
                     // background (such as a service stopping).
                     scheduleAppGcLocked(app);
-                    // And note its current wake lock time.
+                }
+
+                if (wasKeeping && !app.keeping) {
+                    // This app is no longer something we want to keep.  Note
+                    // its current wake lock time to later know to kill it if
+                    // it is not behaving well.
                     BatteryStatsImpl stats = mBatteryStatsService.getActiveStatistics();
                     synchronized (stats) {
                         app.lastWakeTime = stats.getProcessWakeTime(app.info.uid,
                                 app.pid, SystemClock.elapsedRealtime());
                     }
+                    app.lastCpuTime = app.curCpuTime;
                 }
+
                 app.setRawAdj = app.curRawAdj;
             }
             if (adj != app.setAdj) {