Collect background stats: scheduled jobs

Added background times and counts for an app's scheduled job usage.
Changes DualTimer to be a subclass of Timer so that background timers
can be easily accessed from the main timer (which is convenient for
jobs, whose ArrayMap of Timers is directly accessed outside of
BatteryStatsImpl).

Bug: 35669746
Test: runtest -x
frameworks/base/core/tests/coretests/src/com/android/internal/os/BatteryStatsTests.java

Change-Id: Ic1d85db34346ebda94ed39f134fc0794a5877815
(cherry picked from commit d253f537a0cc15851fb0308f3ea287e6bd93dfe6)
diff --git a/core/java/android/os/BatteryStats.java b/core/java/android/os/BatteryStats.java
index dd11f68..8349510 100644
--- a/core/java/android/os/BatteryStats.java
+++ b/core/java/android/os/BatteryStats.java
@@ -182,7 +182,7 @@
      * New in version 19:
      *   - Wakelock data (wl) gets current and max times.
      * New in version 20:
-     *   - Sensor, BluetoothScan, WifiScan get background timers and counter.
+     *   - Background timers and counters for: Sensor, BluetoothScan, WifiScan, Jobs.
      */
     static final String CHECKIN_VERSION = "20";
 
@@ -392,6 +392,16 @@
         }
 
         /**
+         * Returns the secondary Timer held by the Timer, if one exists. This secondary timer may be
+         * used, for example, for tracking background usage. Secondary timers are never pooled.
+         *
+         * Not all Timer subclasses have a secondary timer; those that don't return null.
+         */
+        public Timer getSubTimer() {
+            return null;
+        }
+
+        /**
          * Returns whether the timer is currently running.  Some types of timers
          * (e.g. BatchTimers) don't know whether the event is currently active,
          * and report false.
@@ -3393,9 +3403,13 @@
                 // Convert from microseconds to milliseconds with rounding
                 final long totalTime = (timer.getTotalTimeLocked(rawRealtime, which) + 500) / 1000;
                 final int count = timer.getCountLocked(which);
+                final Timer bgTimer = timer.getSubTimer();
+                final long bgTime = bgTimer != null ?
+                        (bgTimer.getTotalTimeLocked(rawRealtime, which) + 500) / 1000 : -1;
+                final int bgCount = bgTimer != null ? bgTimer.getCountLocked(which) : -1;
                 if (totalTime != 0) {
                     dumpLine(pw, uid, category, JOB_DATA, "\"" + jobs.keyAt(ij) + "\"",
-                            totalTime, count);
+                            totalTime, count, bgTime, bgCount);
                 }
             }
 
@@ -4616,6 +4630,10 @@
                 // Convert from microseconds to milliseconds with rounding
                 final long totalTime = (timer.getTotalTimeLocked(rawRealtime, which) + 500) / 1000;
                 final int count = timer.getCountLocked(which);
+                final Timer bgTimer = timer.getSubTimer();
+                final long bgTime = bgTimer != null ?
+                        (bgTimer.getTotalTimeLocked(rawRealtime, which) + 500) / 1000 : -1;
+                final int bgCount = bgTimer != null ? bgTimer.getCountLocked(which) : -1;
                 sb.setLength(0);
                 sb.append(prefix);
                 sb.append("    Job ");
@@ -4626,6 +4644,13 @@
                     sb.append("realtime (");
                     sb.append(count);
                     sb.append(" times)");
+                    if (bgTime > 0) {
+                        sb.append(", ");
+                        formatTimeMs(sb, bgTime);
+                        sb.append("background (");
+                        sb.append(bgCount);
+                        sb.append(" times)");
+                    }
                 } else {
                     sb.append("(not used)");
                 }
diff --git a/core/java/com/android/internal/os/BatteryStatsImpl.java b/core/java/com/android/internal/os/BatteryStatsImpl.java
index b263657..d19ffad 100644
--- a/core/java/com/android/internal/os/BatteryStatsImpl.java
+++ b/core/java/com/android/internal/os/BatteryStatsImpl.java
@@ -114,7 +114,7 @@
     private static final int MAGIC = 0xBA757475; // 'BATSTATS'
 
     // Current on-disk Parcel version
-    private static final int VERSION = 152 + (USE_OLD_HISTORY ? 1000 : 0);
+    private static final int VERSION = 153 + (USE_OLD_HISTORY ? 1000 : 0);
 
     // Maximum number of items we will record in the history.
     private static final int MAX_HISTORY_ITEMS = 2000;
@@ -2006,107 +2006,92 @@
      * State for keeping track of two DurationTimers with different TimeBases, presumably where one
      * TimeBase is effectively a subset of the other.
      */
-    public static class DualTimer {
-        // mMainTimer typically tracks the total time. May be pooled (but since it's a durationTimer,
-        // it also has the unpooled getTotalDurationMsLocked() for STATS_SINCE_CHARGED).
-        private final DurationTimer mMainTimer;
+    public static class DualTimer extends DurationTimer {
+        // This class both is a DurationTimer and also holds a second DurationTimer.
+        // The main timer (this) typically tracks the total time. It may be pooled (but since it's a
+        // durationTimer, it also has the unpooled getTotalDurationMsLocked() for
+        // STATS_SINCE_CHARGED).
         // mSubTimer typically tracks only part of the total time, such as background time, as
         // determined by a subTimeBase. It is NOT pooled.
         private final DurationTimer mSubTimer;
 
         /**
-         * Creates a DualTimer to hold a mMainTimer and a mSubTimer.
-         * The mMainTimer is based on the given timeBase and timerPool.
+         * Creates a DualTimer to hold a main timer (this) and a mSubTimer.
+         * The main timer (this) is based on the given timeBase and timerPool.
          * The mSubTimer is based on the given subTimeBase. The mSubTimer is not pooled, even if
-         * the mMainTimer is.
+         * the main timer is.
          */
         public DualTimer(Clocks clocks, Uid uid, int type, ArrayList<StopwatchTimer> timerPool,
                 TimeBase timeBase, TimeBase subTimeBase, Parcel in) {
-            mMainTimer = new DurationTimer(clocks, uid, type, timerPool, timeBase, in);
+            super(clocks, uid, type, timerPool, timeBase, in);
             mSubTimer = new DurationTimer(clocks, uid, type, null, subTimeBase, in);
         }
 
         /**
-         * Creates a DualTimer to hold a mMainTimer and a mSubTimer.
-         * The mMainTimer is based on the given timeBase and timerPool.
+         * Creates a DualTimer to hold a main timer (this) and a mSubTimer.
+         * The main timer (this) is based on the given timeBase and timerPool.
          * The mSubTimer is based on the given subTimeBase. The mSubTimer is not pooled, even if
-         * the mMainTimer is.
+         * the main timer is.
          */
         public DualTimer(Clocks clocks, Uid uid, int type, ArrayList<StopwatchTimer> timerPool,
                 TimeBase timeBase, TimeBase subTimeBase) {
-            mMainTimer = new DurationTimer(clocks, uid, type, timerPool, timeBase);
+            super(clocks, uid, type, timerPool, timeBase);
             mSubTimer = new DurationTimer(clocks, uid, type, null, subTimeBase);
         }
 
-        /** Get the main timer. */
-        public DurationTimer getMainTimer() {
-            return mMainTimer;
-        }
-
         /** Get the secondary timer. */
+        @Override
         public DurationTimer getSubTimer() {
             return mSubTimer;
         }
 
+        @Override
         public void startRunningLocked(long elapsedRealtimeMs) {
-            mMainTimer.startRunningLocked(elapsedRealtimeMs);
+            super.startRunningLocked(elapsedRealtimeMs);
             mSubTimer.startRunningLocked(elapsedRealtimeMs);
         }
 
+        @Override
         public void stopRunningLocked(long elapsedRealtimeMs) {
-            mMainTimer.stopRunningLocked(elapsedRealtimeMs);
+            super.stopRunningLocked(elapsedRealtimeMs);
             mSubTimer.stopRunningLocked(elapsedRealtimeMs);
         }
 
+        @Override
         public void stopAllRunningLocked(long elapsedRealtimeMs) {
-            mMainTimer.stopAllRunningLocked(elapsedRealtimeMs);
+            super.stopAllRunningLocked(elapsedRealtimeMs);
             mSubTimer.stopAllRunningLocked(elapsedRealtimeMs);
         }
 
-        public void setMark(long elapsedRealtimeMs) {
-            mMainTimer.setMark(elapsedRealtimeMs);
-            mSubTimer.setMark(elapsedRealtimeMs);
-        }
-
+        @Override
         public boolean reset(boolean detachIfReset) {
             boolean active = false;
-            active |= !mMainTimer.reset(detachIfReset);
+            active |= !super.reset(detachIfReset);
             active |= !mSubTimer.reset(detachIfReset);
             return !active;
         }
 
+        @Override
         public void detach() {
-            mMainTimer.detach();
+            super.detach();
             mSubTimer.detach();
         }
 
-        /**
-         * Writes a possibly null DualTimer to a Parcel.
-         *
-         * @param out the Parcel to which to write.
-         * @param t a DualTimer, or null.
-         */
-        public static void writeDualTimerToParcel(Parcel out, DualTimer t, long elapsedRealtimeUs) {
-            if (t != null) {
-                out.writeInt(1);
-                t.writeToParcel(out, elapsedRealtimeUs);
-            } else {
-                out.writeInt(0);
-            }
-        }
-
+        @Override
         public void writeToParcel(Parcel out, long elapsedRealtimeUs) {
-            mMainTimer.writeToParcel(out, elapsedRealtimeUs);
+            super.writeToParcel(out, elapsedRealtimeUs);
             mSubTimer.writeToParcel(out, elapsedRealtimeUs);
         }
 
+        @Override
         public void writeSummaryFromParcelLocked(Parcel out, long elapsedRealtimeUs) {
-            mMainTimer.writeSummaryFromParcelLocked(out, elapsedRealtimeUs);
+            super.writeSummaryFromParcelLocked(out, elapsedRealtimeUs);
             mSubTimer.writeSummaryFromParcelLocked(out, elapsedRealtimeUs);
         }
 
+        @Override
         public void readSummaryFromParcelLocked(Parcel in) {
-            mMainTimer.readSummaryFromParcelLocked(in);
+            super.readSummaryFromParcelLocked(in);
             mSubTimer.readSummaryFromParcelLocked(in);
         }
     }
@@ -5488,7 +5473,7 @@
         /**
          * The statistics we have collected for this uid's jobs.
          */
-        final OverflowArrayMap<StopwatchTimer> mJobStats;
+        final OverflowArrayMap<DualTimer> mJobStats;
 
         /**
          * The statistics we have collected for this uid's sensor activations.
@@ -5533,10 +5518,10 @@
                             mBsi.mOnBatteryTimeBase);
                 }
             };
-            mJobStats = mBsi.new OverflowArrayMap<StopwatchTimer>(uid) {
-                @Override public StopwatchTimer instantiateObject() {
-                    return new StopwatchTimer(mBsi.mClocks, Uid.this, JOB, null,
-                            mBsi.mOnBatteryTimeBase);
+            mJobStats = mBsi.new OverflowArrayMap<DualTimer>(uid) {
+                @Override public DualTimer instantiateObject() {
+                    return new DualTimer(mBsi.mClocks, Uid.this, JOB, null,
+                            mBsi.mOnBatteryTimeBase, mOnBatteryBackgroundTimeBase);
                 }
             };
 
@@ -5918,7 +5903,7 @@
             if (mWifiScanTimer == null) {
                 return 0;
             }
-            return mWifiScanTimer.getMainTimer().getTotalTimeLocked(elapsedRealtimeUs, which);
+            return mWifiScanTimer.getTotalTimeLocked(elapsedRealtimeUs, which);
         }
 
         @Override
@@ -5926,12 +5911,12 @@
             if (mWifiScanTimer == null) {
                 return 0;
             }
-            return mWifiScanTimer.getMainTimer().getCountLocked(which);
+            return mWifiScanTimer.getCountLocked(which);
         }
 
         @Override
         public int getWifiScanBackgroundCount(int which) {
-            if (mWifiScanTimer == null) {
+            if (mWifiScanTimer == null || mWifiScanTimer.getSubTimer() == null) {
                 return 0;
             }
             return mWifiScanTimer.getSubTimer().getCountLocked(which);
@@ -5943,12 +5928,12 @@
                 return 0;
             }
             final long elapsedRealtimeMs = (elapsedRealtimeUs + 500) / 1000;
-            return mWifiScanTimer.getMainTimer().getTotalDurationMsLocked(elapsedRealtimeMs) * 1000;
+            return mWifiScanTimer.getTotalDurationMsLocked(elapsedRealtimeMs) * 1000;
         }
 
         @Override
         public long getWifiScanBackgroundTime(final long elapsedRealtimeUs) {
-            if (mWifiScanTimer == null) {
+            if (mWifiScanTimer == null || mWifiScanTimer.getSubTimer() == null) {
                 return 0;
             }
             final long elapsedRealtimeMs = (elapsedRealtimeUs + 500) / 1000;
@@ -6008,10 +5993,7 @@
 
         @Override
         public Timer getBluetoothScanTimer() {
-            if (mBluetoothScanTimer == null) {
-                return null;
-            }
-            return mBluetoothScanTimer.getMainTimer();
+            return mBluetoothScanTimer;
         }
 
         @Override
@@ -6361,9 +6343,9 @@
                 }
             }
             mSyncStats.cleanup();
-            final ArrayMap<String, StopwatchTimer> jobStats = mJobStats.getMap();
+            final ArrayMap<String, DualTimer> jobStats = mJobStats.getMap();
             for (int ij=jobStats.size()-1; ij>=0; ij--) {
-                StopwatchTimer timer = jobStats.valueAt(ij);
+                DualTimer timer = jobStats.valueAt(ij);
                 if (timer.reset(false)) {
                     jobStats.removeAt(ij);
                     timer.detach();
@@ -6531,12 +6513,12 @@
                 Timer.writeTimerToParcel(out, timer, elapsedRealtimeUs);
             }
 
-            final ArrayMap<String, StopwatchTimer> jobStats = mJobStats.getMap();
+            final ArrayMap<String, DualTimer> jobStats = mJobStats.getMap();
             int NJ = jobStats.size();
             out.writeInt(NJ);
             for (int ij=0; ij<NJ; ij++) {
                 out.writeString(jobStats.keyAt(ij));
-                StopwatchTimer timer = jobStats.valueAt(ij);
+                DualTimer timer = jobStats.valueAt(ij);
                 Timer.writeTimerToParcel(out, timer, elapsedRealtimeUs);
             }
 
@@ -6756,8 +6738,8 @@
             for (int j = 0; j < numJobs; j++) {
                 String jobName = in.readString();
                 if (in.readInt() != 0) {
-                    mJobStats.add(jobName, new StopwatchTimer(mBsi.mClocks, Uid.this, JOB, null,
-                                timeBase, in));
+                    mJobStats.add(jobName, new DualTimer(mBsi.mClocks, Uid.this, JOB, null,
+                            mBsi.mOnBatteryTimeBase, mOnBatteryBackgroundTimeBase, in));
                 }
             }
 
@@ -7196,15 +7178,12 @@
             }
 
             void writeToParcelLocked(Parcel out, long elapsedRealtimeUs) {
-                DualTimer.writeDualTimerToParcel(out, mTimer, elapsedRealtimeUs);
+                Timer.writeTimerToParcel(out, mTimer, elapsedRealtimeUs);
             }
 
             @Override
             public Timer getSensorTime() {
-                if (mTimer == null) {
-                    return null;
-                }
-                return mTimer.getMainTimer();
+                return mTimer;
             }
 
             @Override
@@ -8023,7 +8002,7 @@
         }
 
         public void readJobSummaryFromParcelLocked(String name, Parcel in) {
-            StopwatchTimer timer = mJobStats.instantiateObject();
+            DualTimer timer = mJobStats.instantiateObject();
             timer.readSummaryFromParcelLocked(in);
             mJobStats.add(name, timer);
         }
@@ -8084,14 +8063,14 @@
         }
 
         public void noteStartJobLocked(String name, long elapsedRealtimeMs) {
-            StopwatchTimer t = mJobStats.startObject(name);
+            DualTimer t = mJobStats.startObject(name);
             if (t != null) {
                 t.startRunningLocked(elapsedRealtimeMs);
             }
         }
 
         public void noteStopJobLocked(String name, long elapsedRealtimeMs) {
-            StopwatchTimer t = mJobStats.stopObject(name);
+            DualTimer t = mJobStats.stopObject(name);
             if (t != null) {
                 t.stopRunningLocked(elapsedRealtimeMs);
             }
@@ -9149,7 +9128,7 @@
                 final Uid uid = mUidStats.valueAt(i);
 
                 // Sum the total scan power for all apps.
-                totalScanTimeMs += uid.mWifiScanTimer.getMainTimer().getTimeSinceMarkLocked(
+                totalScanTimeMs += uid.mWifiScanTimer.getTimeSinceMarkLocked(
                         elapsedRealtimeMs * 1000) / 1000;
 
                 // Sum the total time holding wifi lock for all apps.
@@ -9170,7 +9149,7 @@
             for (int i = 0; i < uidStatsSize; i++) {
                 final Uid uid = mUidStats.valueAt(i);
 
-                long scanTimeSinceMarkMs = uid.mWifiScanTimer.getMainTimer().getTimeSinceMarkLocked(
+                long scanTimeSinceMarkMs = uid.mWifiScanTimer.getTimeSinceMarkLocked(
                         elapsedRealtimeMs * 1000) / 1000;
                 if (scanTimeSinceMarkMs > 0) {
                     // Set the new mark so that next time we get new data since this point.
@@ -9444,7 +9423,7 @@
                 continue;
             }
 
-            totalScanTimeMs += u.mBluetoothScanTimer.getMainTimer().getTimeSinceMarkLocked(
+            totalScanTimeMs += u.mBluetoothScanTimer.getTimeSinceMarkLocked(
                     elapsedRealtimeMs * 1000) / 1000;
         }
 
@@ -9465,7 +9444,7 @@
                 continue;
             }
 
-            long scanTimeSinceMarkMs = u.mBluetoothScanTimer.getMainTimer().getTimeSinceMarkLocked(
+            long scanTimeSinceMarkMs = u.mBluetoothScanTimer.getTimeSinceMarkLocked(
                     elapsedRealtimeMs * 1000) / 1000;
             if (scanTimeSinceMarkMs > 0) {
                 // Set the new mark so that next time we get new data since this point.
@@ -11526,7 +11505,7 @@
                 syncStats.valueAt(is).writeSummaryFromParcelLocked(out, NOWREAL_SYS);
             }
 
-            final ArrayMap<String, StopwatchTimer> jobStats = u.mJobStats.getMap();
+            final ArrayMap<String, DualTimer> jobStats = u.mJobStats.getMap();
             int NJ = jobStats.size();
             out.writeInt(NJ);
             for (int ij=0; ij<NJ; ij++) {
diff --git a/core/tests/coretests/src/com/android/internal/os/BatteryStatsBackgroundStatsTest.java b/core/tests/coretests/src/com/android/internal/os/BatteryStatsBackgroundStatsTest.java
index 6b52b98..8283335 100644
--- a/core/tests/coretests/src/com/android/internal/os/BatteryStatsBackgroundStatsTest.java
+++ b/core/tests/coretests/src/com/android/internal/os/BatteryStatsBackgroundStatsTest.java
@@ -21,6 +21,7 @@
 import android.os.BatteryStats;
 import android.os.WorkSource;
 import android.support.test.filters.SmallTest;
+import android.util.ArrayMap;
 
 import junit.framework.TestCase;
 
@@ -187,4 +188,65 @@
         assertEquals((305 - 202) * 1000, actualTime);
         assertEquals((305 - 254) * 1000, bgTime);
     }
+
+    @SmallTest
+    public void testJob() throws Exception {
+        final MockClocks clocks = new MockClocks();
+        MockBatteryStatsImpl bi = new MockBatteryStatsImpl(clocks);
+        final String jobName = "job_name";
+        long curr = 0; // realtime in us
+
+        // On battery
+        curr = 1000 * (clocks.realtime = clocks.uptime = 100);
+        bi.updateTimeBasesLocked(true, false, curr, curr); // on battery
+        // App in foreground
+        bi.noteUidProcessStateLocked(UID, ActivityManager.PROCESS_STATE_IMPORTANT_FOREGROUND);
+
+        // Start timer
+        curr = 1000 * (clocks.realtime = clocks.uptime = 151);
+        bi.noteJobStartLocked(jobName, UID);
+
+        // Stop timer
+        curr = 1000 * (clocks.realtime = clocks.uptime = 161);
+        bi.noteJobFinishLocked(jobName, UID);
+
+        // Start timer
+        curr = 1000 * (clocks.realtime = clocks.uptime = 202);
+        bi.noteJobStartLocked(jobName, UID);
+
+        // Move to background
+        curr = 1000 * (clocks.realtime = clocks.uptime = 254);
+        bi.noteUidProcessStateLocked(UID, ActivityManager.PROCESS_STATE_IMPORTANT_BACKGROUND);
+
+        // Off battery
+        curr = 1000 * (clocks.realtime = clocks.uptime = 305);
+        bi.updateTimeBasesLocked(false, false, curr, curr); // off battery
+
+        // Stop timer
+        curr = 1000 * (clocks.realtime = clocks.uptime = 409);
+        bi.noteJobFinishLocked(jobName, UID);
+
+        // Test
+        curr = 1000 * (clocks.realtime = clocks.uptime = 657);
+        final ArrayMap<String, ? extends BatteryStats.Timer> jobs =
+                bi.getUidStats().get(UID).getJobStats();
+        assertEquals(1, jobs.size());
+        BatteryStats.Timer timer = jobs.valueAt(0);
+        BatteryStats.Timer bgTimer = timer.getSubTimer();
+        long time = timer.getTotalTimeLocked(curr, STATS_SINCE_CHARGED);
+        int count = timer.getCountLocked(STATS_SINCE_CHARGED);
+        int bgCount = bgTimer.getCountLocked(STATS_SINCE_CHARGED);
+        long bgTime = bgTimer.getTotalTimeLocked(curr, STATS_SINCE_CHARGED);
+        assertEquals((161 - 151 + 305 - 202) * 1000, time);
+        assertEquals(2, count);
+        assertEquals(1, bgCount);
+        assertEquals((305 - 254) * 1000, bgTime);
+
+        // Test that a second job is separate.
+        curr = 1000 * (clocks.realtime = clocks.uptime = 3000);
+        final String jobName2 = "second_job";
+        bi.noteJobStartLocked(jobName2, UID);
+        assertEquals(2, bi.getUidStats().get(UID).getJobStats().size());
+        bi.noteJobFinishLocked(jobName2, UID);
+    }
 }