Improve debugging for issue #7586414: AlarmManager wakelocks held

In alarm manager, print a summary of the top 10 alarms by time
being executed.  Keep track of execution time (and wake count) of
each type of alarm for each application so this can be printed in
the summary (and used to compute the top 10 alarms).  Rework how
the alarm summary stats are tracked so that we don't need to hold
on to the full Intent for each stat and can get the Intent information
at the time the alarm is sent rather than waiting for whatever Intent
comes back in the result.

Also in the battery stats: sort the kernel wake locks by time, add
a new section showing all partial wake locks across all applications
sorted by time.

Finally a new LocalLog class that is used by AlarmManager to log
important warning messages, so these can also be later found in
its dumpsys output.

Change-Id: Icc07810053e60fb623a49937e696819cb8352b06

Author: Dianne Hackborn

core/java/android/app/ActivityManagerNative.java

@@ -1701,6 +1701,21 @@ public boolean onTransact(int code, Parcel data, Parcel reply, int flags)
             return true;
         }
 
+        case GET_INTENT_FOR_INTENT_SENDER_TRANSACTION: {
+            data.enforceInterface(IActivityManager.descriptor);
+            IIntentSender r = IIntentSender.Stub.asInterface(
+                data.readStrongBinder());
+            Intent intent = getIntentForIntentSender(r);
+            reply.writeNoException();
+            if (intent != null) {
+                reply.writeInt(1);
+                intent.writeToParcel(reply, Parcelable.PARCELABLE_WRITE_RETURN_VALUE);
+            } else {
+                reply.writeInt(0);
+            }
+            return true;
+        }
+
         case UPDATE_PERSISTENT_CONFIGURATION_TRANSACTION: {
             data.enforceInterface(IActivityManager.descriptor);
             Configuration config = Configuration.CREATOR.createFromParcel(data);
@@ -3977,6 +3992,20 @@ public boolean isIntentSenderAnActivity(IIntentSender sender) throws RemoteExcep
         return res;
     }
 
+    public Intent getIntentForIntentSender(IIntentSender sender) throws RemoteException {
+        Parcel data = Parcel.obtain();
+        Parcel reply = Parcel.obtain();
+        data.writeInterfaceToken(IActivityManager.descriptor);
+        data.writeStrongBinder(sender.asBinder());
+        mRemote.transact(GET_INTENT_FOR_INTENT_SENDER_TRANSACTION, data, reply, 0);
+        reply.readException();
+        Intent res = reply.readInt() != 0
+                ? Intent.CREATOR.createFromParcel(reply) : null;
+        data.recycle();
+        reply.recycle();
+        return res;
+    }
+
     public void updatePersistentConfiguration(Configuration values) throws RemoteException
     {
         Parcel data = Parcel.obtain();

core/java/android/app/IActivityManager.java

@@ -341,6 +341,8 @@ public void setPackageAskScreenCompat(String packageName, boolean ask)
 
     public boolean isIntentSenderAnActivity(IIntentSender sender) throws RemoteException;
 
+    public Intent getIntentForIntentSender(IIntentSender sender) throws RemoteException;
+
     public void updatePersistentConfiguration(Configuration values) throws RemoteException;
 
     public long[] getProcessPss(int[] pids) throws RemoteException;
@@ -621,4 +623,5 @@ private WaitResult(Parcel source) {
     int REQUEST_BUG_REPORT_TRANSACTION = IBinder.FIRST_CALL_TRANSACTION+157;
     int INPUT_DISPATCHING_TIMED_OUT_TRANSACTION = IBinder.FIRST_CALL_TRANSACTION+158;
     int CLEAR_PENDING_BACKUP_TRANSACTION = IBinder.FIRST_CALL_TRANSACTION+159;
+    int GET_INTENT_FOR_INTENT_SENDER_TRANSACTION = IBinder.FIRST_CALL_TRANSACTION+160;
 }

core/java/android/app/PendingIntent.java

@@ -789,6 +789,20 @@ public boolean isActivity() {
         }
     }
 
+    /**
+     * @hide
+     * Return the Intent of this PendingIntent.
+     */
+    public Intent getIntent() {
+        try {
+            return ActivityManagerNative.getDefault()
+                .getIntentForIntentSender(mTarget);
+        } catch (RemoteException e) {
+            // Should never happen.
+            return null;
+        }
+    }
+
     /**
      * Comparison operator on two PendingIntent objects, such that true
      * is returned then they both represent the same operation from the

core/java/android/os/BatteryStats.java

@@ -18,6 +18,8 @@
 
 import java.io.PrintWriter;
 import java.util.ArrayList;
+import java.util.Collections;
+import java.util.Comparator;
 import java.util.Formatter;
 import java.util.List;
 import java.util.Map;
@@ -1127,8 +1129,10 @@ private static final String printWakeLock(StringBuilder sb, Timer timer,
             if (totalTimeMillis != 0) {
                 sb.append(linePrefix);
                 formatTimeMs(sb, totalTimeMillis);
-                if (name != null) sb.append(name);
-                sb.append(' ');
+                if (name != null) {
+                    sb.append(name);
+                    sb.append(' ');
+                }
                 sb.append('(');
                 sb.append(count);
                 sb.append(" times)");
@@ -1440,8 +1444,21 @@ public final void dumpCheckinLocked(PrintWriter pw, int which, int reqUid) {
         }
     }
 
+    static final class TimerEntry {
+        final String mName;
+        final int mId;
+        final BatteryStats.Timer mTimer;
+        final long mTime;
+        TimerEntry(String name, int id, BatteryStats.Timer timer, long time) {
+            mName = name;
+            mId = id;
+            mTimer = timer;
+            mTime = time;
+        }
+    }
+
     @SuppressWarnings("unused")
-    public final void dumpLocked(PrintWriter pw, String prefix, int which, int reqUid) {
+    public final void dumpLocked(PrintWriter pw, String prefix, final int which, int reqUid) {
         final long rawUptime = SystemClock.uptimeMillis() * 1000;
         final long rawRealtime = SystemClock.elapsedRealtime() * 1000;
         final long batteryUptime = getBatteryUptime(rawUptime);
@@ -1516,19 +1533,43 @@ public final void dumpLocked(PrintWriter pw, String prefix, int which, int reqUi
         long txTotal = 0;
         long fullWakeLockTimeTotalMicros = 0;
         long partialWakeLockTimeTotalMicros = 0;
-        
+
+        final Comparator<TimerEntry> timerComparator = new Comparator<TimerEntry>() {
+            @Override
+            public int compare(TimerEntry lhs, TimerEntry rhs) {
+                long lhsTime = lhs.mTime;
+                long rhsTime = rhs.mTime;
+                if (lhsTime < rhsTime) {
+                    return 1;
+                }
+                if (lhsTime > rhsTime) {
+                    return -1;
+                }
+                return 0;
+            }
+        };
+
         if (reqUid < 0) {
             Map<String, ? extends BatteryStats.Timer> kernelWakelocks = getKernelWakelockStats();
             if (kernelWakelocks.size() > 0) {
+                final ArrayList<TimerEntry> timers = new ArrayList<TimerEntry>();
                 for (Map.Entry<String, ? extends BatteryStats.Timer> ent : kernelWakelocks.entrySet()) {
-                    
+                    BatteryStats.Timer timer = ent.getValue();
+                    long totalTimeMillis = computeWakeLock(timer, batteryRealtime, which);
+                    if (totalTimeMillis > 0) {
+                        timers.add(new TimerEntry(ent.getKey(), 0, timer, totalTimeMillis));
+                    }
+                }
+                Collections.sort(timers, timerComparator);
+                for (int i=0; i<timers.size(); i++) {
+                    TimerEntry timer = timers.get(i);
                     String linePrefix = ": ";
                     sb.setLength(0);
                     sb.append(prefix);
                     sb.append("  Kernel Wake lock ");
-                    sb.append(ent.getKey());
-                    linePrefix = printWakeLock(sb, ent.getValue(), batteryRealtime, null, which, 
-                            linePrefix);
+                    sb.append(timer.mName);
+                    linePrefix = printWakeLock(sb, timer.mTimer, batteryRealtime, null,
+                            which, linePrefix);
                     if (!linePrefix.equals(": ")) {
                         sb.append(" realtime");
                         // Only print out wake locks that were held
@@ -1537,7 +1578,9 @@ public final void dumpLocked(PrintWriter pw, String prefix, int which, int reqUi
                 }
             }
         }
-    
+
+        final ArrayList<TimerEntry> timers = new ArrayList<TimerEntry>();
+
         for (int iu = 0; iu < NU; iu++) {
             Uid u = uidStats.valueAt(iu);
             rxTotal += u.getTcpBytesReceived(which);
@@ -1557,8 +1600,18 @@ public final void dumpLocked(PrintWriter pw, String prefix, int which, int reqUi
 
                     Timer partialWakeTimer = wl.getWakeTime(WAKE_TYPE_PARTIAL);
                     if (partialWakeTimer != null) {
-                        partialWakeLockTimeTotalMicros += partialWakeTimer.getTotalTimeLocked(
+                        long totalTimeMicros = partialWakeTimer.getTotalTimeLocked(
                                 batteryRealtime, which);
+                        if (totalTimeMicros > 0) {
+                            if (reqUid < 0) {
+                                // Only show the ordered list of all wake
+                                // locks if the caller is not asking for data
+                                // about a specific uid.
+                                timers.add(new TimerEntry(ent.getKey(), u.getUid(),
+                                        partialWakeTimer, totalTimeMicros));
+                            }
+                            partialWakeLockTimeTotalMicros += totalTimeMicros;
+                        }
                     }
                 }
             }
@@ -1571,7 +1624,7 @@ public final void dumpLocked(PrintWriter pw, String prefix, int which, int reqUi
         sb.append(prefix);
                 sb.append("  Total full wakelock time: "); formatTimeMs(sb,
                         (fullWakeLockTimeTotalMicros + 500) / 1000);
-                sb.append(", Total partial waklock time: "); formatTimeMs(sb,
+                sb.append(", Total partial wakelock time: "); formatTimeMs(sb,
                         (partialWakeLockTimeTotalMicros + 500) / 1000);
         pw.println(sb.toString());
 
@@ -1676,9 +1729,26 @@ public final void dumpLocked(PrintWriter pw, String prefix, int which, int reqUi
                     pw.println(getDischargeAmountScreenOnSinceCharge());
             pw.print(prefix); pw.print("    Amount discharged while screen off: ");
                     pw.println(getDischargeAmountScreenOffSinceCharge());
-            pw.println(" ");
+            pw.println();
+        }
+
+        if (timers.size() > 0) {
+            Collections.sort(timers, timerComparator);
+            pw.print(prefix); pw.println("  All partial wake locks:");
+            for (int i=0; i<timers.size(); i++) {
+                TimerEntry timer = timers.get(i);
+                sb.setLength(0);
+                sb.append("  Wake lock #");
+                sb.append(timer.mId);
+                sb.append(" ");
+                sb.append(timer.mName);
+                printWakeLock(sb, timer.mTimer, batteryRealtime, null, which, ": ");
+                sb.append(" realtime");
+                pw.println(sb.toString());
+            }
+            timers.clear();
+            pw.println();
         }
-        
 
         for (int iu=0; iu<NU; iu++) {
             final int uid = uidStats.keyAt(iu);

core/java/com/android/internal/util/LocalLog.java

@@ -0,0 +1,66 @@
+/*
+ * Copyright (C) 2012 The Android Open Source Project
+ *
+ * Licensed under the Apache License, Version 2.0 (the "License");
+ * you may not use this file except in compliance with the License.
+ * You may obtain a copy of the License at
+ *
+ *      http://www.apache.org/licenses/LICENSE-2.0
+ *
+ * Unless required by applicable law or agreed to in writing, software
+ * distributed under the License is distributed on an "AS IS" BASIS,
+ * WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied.
+ * See the License for the specific language governing permissions and
+ * limitations under the License.
+ */
+
+package com.android.internal.util;
+
+import java.io.PrintWriter;
+import java.util.ArrayList;
+
+import android.util.Slog;
+
+/**
+ * Helper class for logging serious issues, which also keeps a small
+ * snapshot of the logged events that can be printed later, such as part
+ * of a system service's dumpsys output.
+ * @hide
+ */
+public class LocalLog {
+    private final String mTag;
+    private final int mMaxLines = 20;
+    private final ArrayList<String> mLines = new ArrayList<String>(mMaxLines);
+
+    public LocalLog(String tag) {
+        mTag = tag;
+    }
+
+    public void w(String msg) {
+        synchronized (mLines) {
+            Slog.w(mTag, msg);
+            if (mLines.size() >= mMaxLines) {
+                mLines.remove(0);
+            }
+            mLines.add(msg);
+        }
+    }
+
+    public boolean dump(PrintWriter pw, String header, String prefix) {
+        synchronized (mLines) {
+            if (mLines.size() <= 0) {
+                return false;
+            }
+            if (header != null) {
+                pw.println(header);
+            }
+            for (int i=0; i<mLines.size(); i++) {
+                if (prefix != null) {
+                    pw.print(prefix);
+                }
+                pw.println(mLines.get(i));
+            }
+            return true;
+        }
+    }
+}