BatteryStats: Add debug logging to find source of b/22716723

Bug:22716723
Change-Id: I97b940b702666b393555622d034e1c694b1e346a

Author: Adam Lesinski

core/java/com/android/internal/os/BatteryStatsImpl.java

@@ -7915,6 +7915,8 @@ public void updateKernelWakelocksLocked() {
             return;
         }
 
+        // Record whether we've seen a non-zero time (for debugging b/22716723).
+        boolean seenNonZeroTime = false;
         for (Map.Entry<String, KernelWakelockStats.Entry> ent : wakelockStats.entrySet()) {
             String name = ent.getKey();
             KernelWakelockStats.Entry kws = ent.getValue();
@@ -7928,17 +7930,31 @@ public void updateKernelWakelocksLocked() {
             kwlt.updateCurrentReportedCount(kws.mCount);
             kwlt.updateCurrentReportedTotalTime(kws.mTotalTime);
             kwlt.setUpdateVersion(kws.mVersion);
+
+            if (kws.mVersion != wakelockStats.kernelWakelockVersion)
+            seenNonZeroTime |= kws.mTotalTime > 0;
         }
 
+        int numWakelocksSetStale = 0;
         if (wakelockStats.size() != mKernelWakelockStats.size()) {
             // Set timers to stale if they didn't appear in /proc/wakelocks this time.
             for (Map.Entry<String, SamplingTimer> ent : mKernelWakelockStats.entrySet()) {
                 SamplingTimer st = ent.getValue();
                 if (st.getUpdateVersion() != wakelockStats.kernelWakelockVersion) {
                     st.setStale();
+                    numWakelocksSetStale++;
                 }
             }
         }
+
+        if (!seenNonZeroTime) {
+            Slog.wtf(TAG, "All kernel wakelocks had time of zero");
+        }
+
+        if (numWakelocksSetStale == mKernelWakelockStats.size()) {
+            Slog.wtf(TAG, "All kernel wakelocks were set stale. new version=" +
+                    wakelockStats.kernelWakelockVersion);
+        }
     }
 
     // We use an anonymous class to access these variables,

core/java/com/android/internal/os/KernelWakelockReader.java

@@ -75,13 +75,16 @@ public final KernelWakelockStats readKernelWakelockStats(KernelWakelockStats sta
                     is = new FileInputStream(sWakeupSourceFile);
                     wakeup_sources = true;
                 } catch (java.io.FileNotFoundException e2) {
+                    Slog.wtf(TAG, "neither " + sWakelockFile + " nor " +
+                            sWakeupSourceFile + " exists");
                     return null;
                 }
             }
 
             len = is.read(buffer);
             is.close();
         } catch (java.io.IOException e) {
+            Slog.wtf(TAG, "failed to read kernel wakelocks", e);
             return null;
         }
 
@@ -171,6 +174,13 @@ private KernelWakelockStats parseProcWakelocks(byte[] wlBuffer, int len, boolean
                             numUpdatedWlNames++;
                         }
                     }
+                } else if (!parsed) {
+                    try {
+                        Slog.wtf(TAG, "Failed to parse proc line: " +
+                                new String(wlBuffer, startIndex, endIndex - startIndex));
+                    } catch (Exception e) {
+                        Slog.wtf(TAG, "Failed to parse proc line!");
+                    }
                 }
                 startIndex = endIndex;
             }