Fix counting problems in StopwatchTimer.

Changed StopwatchTimer so that its count only increases if the timer is
started when its time base is running. Previously, if the time base was
off, the timer was started, the time base was turned on, and then the
timer was stopped, the count would be increased; now, it will not
(because the time base was off when the timer started). Moreover, this
likely fixes the count==-1 bug that previously could occur, since the
count will no longer be decremented if the timer is stopped after a reset.

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

Change-Id: Iad195e431618629ce432074e0c1bd217f9818cb1

diff --git a/core/java/com/android/internal/os/BatteryStatsImpl.java b/core/java/com/android/internal/os/BatteryStatsImpl.java
index d19ffad..916241c 100644 (file)
--- a/core/java/com/android/internal/os/BatteryStatsImpl.java
+++ b/core/java/com/android/internal/os/BatteryStatsImpl.java
@@ -1798,9 +1798,10 @@ public class BatteryStatsImpl extends BatteryStats {
 
         /**
          * The total time at which the timer was acquired, to determine if it
-         * was actually held for an interesting duration.
+         * was actually held for an interesting duration. If time base was not running when timer
+         * was acquired, will be -1.
          */
-        long mAcquireTime;
+        long mAcquireTime = -1;
 
         long mTimeout;
 
@@ -1864,9 +1865,13 @@ public class BatteryStatsImpl extends BatteryStats {
                     // Add this timer to the active pool
                     mTimerPool.add(this);
                 }
-                // Increment the count
-                mCount++;
-                mAcquireTime = mTotalTime;
+                if (mTimeBase.isRunning()) {
+                    // Increment the count
+                    mCount++;
+                    mAcquireTime = mTotalTime;
+                } else {
+                    mAcquireTime = -1;
+                }
                 if (DEBUG && mType < 0) {
                     Log.v(TAG, "start #" + mType + ": mUpdateTime=" + mUpdateTime
                             + " mTotalTime=" + mTotalTime + " mCount=" + mCount
@@ -1904,7 +1909,7 @@ public class BatteryStatsImpl extends BatteryStats {
                             + " mAcquireTime=" + mAcquireTime);
                 }
 
-                if (mTotalTime == mAcquireTime) {
+                if (mAcquireTime >= 0 && mTotalTime == mAcquireTime) {
                     // If there was no change in the time, then discard this
                     // count.  A somewhat cheezy strategy, but hey.
                     mCount--;
@@ -1963,7 +1968,7 @@ public class BatteryStatsImpl extends BatteryStats {
             if (mNesting > 0) {
                 mUpdateTime = mTimeBase.getRealtime(mClocks.elapsedRealtime() * 1000);
             }
-            mAcquireTime = mTotalTime;
+            mAcquireTime = -1; // to ensure mCount isn't decreased to -1 if timer is stopped later.
             return canDetach;
         }
 

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 8283335..2b0ae21 100644 (file)
--- a/core/tests/coretests/src/com/android/internal/os/BatteryStatsBackgroundStatsTest.java
+++ b/core/tests/coretests/src/com/android/internal/os/BatteryStatsBackgroundStatsTest.java
@@ -137,7 +137,7 @@ public class BatteryStatsBackgroundStatsTest extends TestCase {
         long bgTime = bi.getUidStats().get(UID).getWifiScanBackgroundTime(curr);
         assertEquals((305 - 202) * 1000, time);
         assertEquals(1, count);
-        assertEquals(1, bgCount);
+        assertEquals(0, bgCount);
         assertEquals((305 - 202) * 1000, actualTime);
         assertEquals((305 - 254) * 1000, bgTime);
     }
@@ -184,7 +184,7 @@ public class BatteryStatsBackgroundStatsTest extends TestCase {
         long bgTime = bgTimer.getTotalDurationMsLocked(clocks.realtime) * 1000;
         assertEquals((305 - 202) * 1000, time);
         assertEquals(1, count);
-        assertEquals(1, bgCount);
+        assertEquals(0, bgCount);
         assertEquals((305 - 202) * 1000, actualTime);
         assertEquals((305 - 254) * 1000, bgTime);
     }
@@ -210,13 +210,13 @@ public class BatteryStatsBackgroundStatsTest extends TestCase {
         curr = 1000 * (clocks.realtime = clocks.uptime = 161);
         bi.noteJobFinishLocked(jobName, UID);
 
-        // Start timer
+        // Move to background
         curr = 1000 * (clocks.realtime = clocks.uptime = 202);
-        bi.noteJobStartLocked(jobName, UID);
+        bi.noteUidProcessStateLocked(UID, ActivityManager.PROCESS_STATE_IMPORTANT_BACKGROUND);
 
-        // Move to background
+        // Start timer
         curr = 1000 * (clocks.realtime = clocks.uptime = 254);
-        bi.noteUidProcessStateLocked(UID, ActivityManager.PROCESS_STATE_IMPORTANT_BACKGROUND);
+        bi.noteJobStartLocked(jobName, UID);
 
         // Off battery
         curr = 1000 * (clocks.realtime = clocks.uptime = 305);
@@ -237,7 +237,7 @@ public class BatteryStatsBackgroundStatsTest extends TestCase {
         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((161 - 151 + 305 - 254) * 1000, time);
         assertEquals(2, count);
         assertEquals(1, bgCount);
         assertEquals((305 - 254) * 1000, bgTime);

diff --git a/core/tests/coretests/src/com/android/internal/os/BatteryStatsSensorTest.java b/core/tests/coretests/src/com/android/internal/os/BatteryStatsSensorTest.java
index a41a023..47bc502 100644 (file)
--- a/core/tests/coretests/src/com/android/internal/os/BatteryStatsSensorTest.java
+++ b/core/tests/coretests/src/com/android/internal/os/BatteryStatsSensorTest.java
@@ -29,9 +29,6 @@ public class BatteryStatsSensorTest extends TestCase {
     private static final int UID = 10500;
     private static final int SENSOR_ID = -10000;
 
-    // TODO: fix the bug in StopwatchTimer to prevent this bug from manifesting here.
-    boolean revealCntBug = false;
-
     @SmallTest
     public void testSensorStartStop() throws Exception {
         final MockClocks clocks = new MockClocks();
@@ -90,11 +87,7 @@ public class BatteryStatsSensorTest extends TestCase {
                 .get(SENSOR_ID).getSensorTime();
         assertEquals(0,
                 sensorTimer.getTotalTimeLocked(curr, BatteryStats.STATS_SINCE_CHARGED));
-        if(revealCntBug) {
-            assertEquals(0, sensorTimer.getCountLocked(BatteryStats.STATS_SINCE_CHARGED));
-        } else {
-            assertEquals(1, sensorTimer.getCountLocked(BatteryStats.STATS_SINCE_CHARGED));
-        }
+        assertEquals(0, sensorTimer.getCountLocked(BatteryStats.STATS_SINCE_CHARGED));
 
         // Stop sensor (battery=off, sensor=off)
         curr = 1000 * (clocks.realtime = clocks.uptime = 550);
@@ -175,11 +168,7 @@ public class BatteryStatsSensorTest extends TestCase {
         curr = 1000 * (clocks.realtime = clocks.uptime = 657);
         BatteryStats.Timer sensorTimer = bi.getUidStats().get(UID).getSensorStats()
                 .get(SENSOR_ID).getSensorTime();
-        if(revealCntBug) {
-            assertEquals(1, sensorTimer.getCountLocked(BatteryStats.STATS_SINCE_CHARGED));
-        } else {
-            assertEquals(2, sensorTimer.getCountLocked(BatteryStats.STATS_SINCE_CHARGED));
-        }
+        assertEquals(1, sensorTimer.getCountLocked(BatteryStats.STATS_SINCE_CHARGED));
         assertEquals((305-202)*1000,
                 sensorTimer.getTotalTimeLocked(curr, BatteryStats.STATS_SINCE_CHARGED));
 
@@ -216,11 +205,7 @@ public class BatteryStatsSensorTest extends TestCase {
         assertEquals(0,
                 sensorTimer.getTotalTimeLocked(curr, BatteryStats.STATS_SINCE_CHARGED));
         // Acquired off battery, so count=0.
-        if(revealCntBug) {
-            assertEquals(0, sensorTimer.getCountLocked(BatteryStats.STATS_SINCE_CHARGED));
-        } else {
-            assertEquals(1, sensorTimer.getCountLocked(BatteryStats.STATS_SINCE_CHARGED));
-        }
+        assertEquals(0, sensorTimer.getCountLocked(BatteryStats.STATS_SINCE_CHARGED));
 
         // Unplug (battery=on, sensor=on)
         curr = 1000 * (clocks.realtime = clocks.uptime = 305);
@@ -233,11 +218,7 @@ public class BatteryStatsSensorTest extends TestCase {
         assertEquals((410-305)*1000,
                 sensorTimer.getTotalTimeLocked(curr, BatteryStats.STATS_SINCE_CHARGED));
         // Only ever acquired off battery, so count=0.
-        if(revealCntBug) {
-            assertEquals(0, sensorTimer.getCountLocked(BatteryStats.STATS_SINCE_CHARGED));
-        } else {
-            assertEquals(1, sensorTimer.getCountLocked(BatteryStats.STATS_SINCE_CHARGED));
-        }
+        assertEquals(0, sensorTimer.getCountLocked(BatteryStats.STATS_SINCE_CHARGED));
 
         // Stop sensor (battery=on, sensor=off)
         curr = 1000 * (clocks.realtime = clocks.uptime = 550);
@@ -250,11 +231,7 @@ public class BatteryStatsSensorTest extends TestCase {
         assertEquals((550-305)*1000,
                 sensorTimer.getTotalTimeLocked(curr, BatteryStats.STATS_SINCE_CHARGED));
         // Only ever acquired off battery, so count=0.
-        if(revealCntBug) {
-            assertEquals(0, sensorTimer.getCountLocked(BatteryStats.STATS_SINCE_CHARGED));
-        } else {
-            assertEquals(1, sensorTimer.getCountLocked(BatteryStats.STATS_SINCE_CHARGED));
-        }
+        assertEquals(0, sensorTimer.getCountLocked(BatteryStats.STATS_SINCE_CHARGED));
     }
 
     @SmallTest
@@ -375,11 +352,7 @@ public class BatteryStatsSensorTest extends TestCase {
         // Test: UID - count
         assertEquals(2, timer1.getCountLocked(BatteryStats.STATS_SINCE_CHARGED));
         // Test: UID - background count
-        if(revealCntBug) {
-            assertEquals(1, bgTimer1.getCountLocked(BatteryStats.STATS_SINCE_CHARGED));
-        } else {
-            assertEquals(2, bgTimer1.getCountLocked(BatteryStats.STATS_SINCE_CHARGED));
-        }
+        assertEquals(1, bgTimer1.getCountLocked(BatteryStats.STATS_SINCE_CHARGED));
 
         // Test: UID_2 - blamed time
         assertEquals(expBlamedTime2 * 1000,

diff --git a/core/tests/coretests/src/com/android/internal/os/BatteryStatsStopwatchTimerTest.java b/core/tests/coretests/src/com/android/internal/os/BatteryStatsStopwatchTimerTest.java
new file mode 100644 (file)
index 0000000..015314e
--- /dev/null
+++ b/core/tests/coretests/src/com/android/internal/os/BatteryStatsStopwatchTimerTest.java
@@ -0,0 +1,146 @@
+/*
+ * Copyright (C) 2017 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.os;
+
+import android.os.BatteryStats;
+import android.support.test.filters.SmallTest;
+
+import junit.framework.TestCase;
+
+/**
+ * Test BatteryStatsImpl.StopwatchTimer.
+ */
+public class BatteryStatsStopwatchTimerTest extends TestCase {
+
+    // Primarily testing previous bug that incremented count when timeBase was off and bug that gave
+    // negative values of count.
+    @SmallTest
+    public void testCount() throws Exception {
+        final MockClocks clocks = new MockClocks(); // holds realtime and uptime in ms
+        final BatteryStatsImpl.TimeBase timeBase = new BatteryStatsImpl.TimeBase();
+        timeBase.init(clocks.uptimeMillis(), clocks.elapsedRealtime());
+        final BatteryStatsImpl.StopwatchTimer timer = new BatteryStatsImpl.StopwatchTimer(clocks,
+                null, BatteryStats.SENSOR, null, timeBase);
+        int expectedCount = 0;
+
+        // for timeBase off tests
+        timeBase.setRunning(false, 1000 * clocks.realtime, 1000 * clocks.realtime);
+
+        // timeBase off, start, stop
+        timer.startRunningLocked(updateTime(clocks, 100)); // start
+        // Used to fail due to b/36730213 increasing count.
+        assertEquals(expectedCount, timer.getCountLocked(BatteryStats.STATS_SINCE_CHARGED));
+        timer.startRunningLocked(updateTime(clocks, 110)); // start
+        assertEquals(expectedCount, timer.getCountLocked(BatteryStats.STATS_SINCE_CHARGED));
+        timer.stopRunningLocked(updateTime(clocks, 120)); // stop
+        assertEquals(expectedCount, timer.getCountLocked(BatteryStats.STATS_SINCE_CHARGED));
+        timer.stopRunningLocked(updateTime(clocks, 130)); // stop
+        assertEquals(expectedCount, timer.getCountLocked(BatteryStats.STATS_SINCE_CHARGED));
+
+        // timeBase off, start and immediately stop
+        timer.startRunningLocked(updateTime(clocks, 200)); // start
+        timer.stopRunningLocked(updateTime(clocks, 200)); // stop
+        assertEquals(expectedCount, timer.getCountLocked(BatteryStats.STATS_SINCE_CHARGED));
+
+        // timeBase off, start, reset, stop
+        timer.startRunningLocked(updateTime(clocks, 300)); // start
+        updateTime(clocks, 310);
+        timeBase.init(clocks.uptimeMillis(), clocks.elapsedRealtime());
+        timer.reset(false);
+        expectedCount = 0; // count will be reset by reset()
+        assertEquals(expectedCount, timer.getCountLocked(BatteryStats.STATS_SINCE_CHARGED));
+        timer.stopRunningLocked(updateTime(clocks, 350)); // stop
+        // Used to fail due to b/30099724 giving -1.
+        assertEquals(expectedCount, timer.getCountLocked(BatteryStats.STATS_SINCE_CHARGED));
+
+        // timeBase off, start and immediately reset, stop
+        timer.startRunningLocked(updateTime(clocks, 400)); // start
+        timer.reset(false);
+        expectedCount = 0; // count will be reset by reset()
+        assertEquals(expectedCount, timer.getCountLocked(BatteryStats.STATS_SINCE_CHARGED));
+        timer.stopRunningLocked(updateTime(clocks, 450)); // stop
+        // Used to fail due to b/30099724 giving -1.
+        assertEquals(expectedCount, timer.getCountLocked(BatteryStats.STATS_SINCE_CHARGED));
+
+
+        // for timeBase on tests
+        updateTime(clocks, 2000);
+        timeBase.setRunning(true, 1000 * clocks.realtime, 1000 * clocks.realtime);
+        assertFalse(timer.isRunningLocked());
+
+        // timeBase on, start, stop
+        timer.startRunningLocked(updateTime(clocks, 2100)); // start
+        expectedCount++;
+        assertEquals(expectedCount, timer.getCountLocked(BatteryStats.STATS_SINCE_CHARGED));
+        timer.startRunningLocked(updateTime(clocks, 2110)); // start
+        assertEquals(expectedCount, timer.getCountLocked(BatteryStats.STATS_SINCE_CHARGED));
+        timer.stopRunningLocked(updateTime(clocks, 2120)); // stop
+        assertEquals(expectedCount, timer.getCountLocked(BatteryStats.STATS_SINCE_CHARGED));
+        timer.stopRunningLocked(updateTime(clocks, 2130)); // stop
+        assertEquals(expectedCount, timer.getCountLocked(BatteryStats.STATS_SINCE_CHARGED));
+
+        // timeBase on, start and immediately stop
+        timer.startRunningLocked(updateTime(clocks, 2200)); // start
+        timer.stopRunningLocked(updateTime(clocks, 2200)); // stop
+        assertEquals(expectedCount, timer.getCountLocked(BatteryStats.STATS_SINCE_CHARGED));
+
+        // timeBase on, start, reset, stop
+        timer.startRunningLocked(updateTime(clocks, 2300)); // start
+        updateTime(clocks, 2310);
+        timeBase.init(clocks.uptimeMillis(), clocks.elapsedRealtime());
+        timer.reset(false);
+        expectedCount = 0; // count will be reset by reset()
+        assertEquals(expectedCount, timer.getCountLocked(BatteryStats.STATS_SINCE_CHARGED));
+        timer.stopRunningLocked(updateTime(clocks, 2350)); // stop
+        assertEquals(expectedCount, timer.getCountLocked(BatteryStats.STATS_SINCE_CHARGED));
+
+        // timeBase on, start and immediately reset, stop
+        timer.startRunningLocked(updateTime(clocks, 2400)); // start
+        timer.reset(false);
+        expectedCount = 0; // count will be reset by reset()
+        assertEquals(expectedCount, timer.getCountLocked(BatteryStats.STATS_SINCE_CHARGED));
+        timer.stopRunningLocked(updateTime(clocks, 2450)); // stop
+        assertEquals(expectedCount, timer.getCountLocked(BatteryStats.STATS_SINCE_CHARGED));
+
+
+        // change timeBase tests
+        // timeBase off, start
+        updateTime(clocks, 3000);
+        timeBase.setRunning(false, 1000 * clocks.realtime, 1000 * clocks.realtime);
+        timer.startRunningLocked(updateTime(clocks, 3100)); // start
+        // Used to fail due to b/36730213 increasing count.
+        assertEquals(expectedCount, timer.getCountLocked(BatteryStats.STATS_SINCE_CHARGED));
+        // timeBase on, stop
+        updateTime(clocks, 3200);
+        timeBase.setRunning(true, 1000 * clocks.realtime, 1000 * clocks.realtime);
+        timer.stopRunningLocked(updateTime(clocks, 3300)); // stop
+        assertEquals(expectedCount, timer.getCountLocked(BatteryStats.STATS_SINCE_CHARGED));
+
+        // timeBase on, start
+        timer.startRunningLocked(updateTime(clocks, 3400)); // start
+        expectedCount++;
+        assertEquals(expectedCount, timer.getCountLocked(BatteryStats.STATS_SINCE_CHARGED));
+        // timeBase off, stop
+        updateTime(clocks, 3500);
+        timeBase.setRunning(false, 1000 * clocks.realtime, 1000 * clocks.realtime);
+        timer.stopRunningLocked(updateTime(clocks, 3600)); // stop
+        assertEquals(expectedCount, timer.getCountLocked(BatteryStats.STATS_SINCE_CHARGED));
+    }
+
+    private static long updateTime(MockClocks clocks, long time) {
+        return clocks.realtime = clocks.uptime = time;
+    }
+}

diff --git a/core/tests/coretests/src/com/android/internal/os/BatteryStatsTests.java b/core/tests/coretests/src/com/android/internal/os/BatteryStatsTests.java
index 1113268..9607a59 100644 (file)
--- a/core/tests/coretests/src/com/android/internal/os/BatteryStatsTests.java
+++ b/core/tests/coretests/src/com/android/internal/os/BatteryStatsTests.java
@@ -8,6 +8,7 @@ import org.junit.runners.Suite;
         BatteryStatsDurationTimerTest.class,
         BatteryStatsSamplingTimerTest.class,
         BatteryStatsServTest.class,
+        BatteryStatsStopwatchTimerTest.class,
         BatteryStatsTimeBaseTest.class,
         BatteryStatsTimerTest.class,
         BatteryStatsUidTest.class,