From 757c6eacc8114613e2a07a5e68628bf202ce97ab Mon Sep 17 00:00:00 2001 From: Adam Lesinski Date: Thu, 21 Apr 2016 09:55:41 -0700 Subject: [PATCH] BatteryStats: Fix up semantics of SamplingTimer SamplingTimer has been losing some data, as well as not correctly handling entries that have gone away and come back with less data (reset). This change correctly ends a SamplingTimer sample by adding the accumulated amount to the total, then reseting the running counter to accept new values. This is also triggered automatically when the incoming data is less than what is currently recorded. Bug:25695597 Change-Id: I6b540906e6be527578d1003485384a75ba211b52 --- .../android/internal/os/BatteryStatsImpl.java | 112 ++++++++++------ .../os/BatteryStatsSamplingTimerTest.java | 124 ++++++++++++++++-- 2 files changed, 189 insertions(+), 47 deletions(-) diff --git a/core/java/com/android/internal/os/BatteryStatsImpl.java b/core/java/com/android/internal/os/BatteryStatsImpl.java index 250d9b77473de..bb773d4a0e353 100644 --- a/core/java/com/android/internal/os/BatteryStatsImpl.java +++ b/core/java/com/android/internal/os/BatteryStatsImpl.java @@ -1210,6 +1210,16 @@ public class BatteryStatsImpl extends BatteryStats { } } + /** + * A counter meant to accept monotonically increasing values to its {@link #update(long, int)} + * method. The state of the timer according to its {@link TimeBase} will determine how much + * of the value is recorded. + * + * If the value being recorded resets, {@link #endSample()} can be called in order to + * account for the change. If the value passed in to {@link #update(long, int)} decreased + * between calls, the {@link #endSample()} is automatically called and the new value is + * expected to increase monotonically from that point on. + */ public static class SamplingTimer extends Timer { /** @@ -1262,16 +1272,21 @@ public class BatteryStatsImpl extends BatteryStats { } @VisibleForTesting - public SamplingTimer(Clocks clocks, TimeBase timeBase, boolean trackReportedValues) { + public SamplingTimer(Clocks clocks, TimeBase timeBase) { super(clocks, 0, timeBase); - mTrackingReportedValues = trackReportedValues; + mTrackingReportedValues = false; mTimeBaseRunning = timeBase.isRunning(); } - public void setStale() { - mTrackingReportedValues = false; - mUnpluggedReportedTotalTime = 0; - mUnpluggedReportedCount = 0; + /** + * Ends the current sample, allowing subsequent values to {@link #update(long, int)} to + * be less than the values used for a previous invocation. + */ + public void endSample() { + mTotalTime = computeRunTimeLocked(0 /* unused by us */); + mCount = computeCurrentCountLocked(); + mUnpluggedReportedTotalTime = mCurrentReportedTotalTime = 0; + mUnpluggedReportedCount = mCurrentReportedCount = 0; } public void setUpdateVersion(int version) { @@ -1282,34 +1297,46 @@ public class BatteryStatsImpl extends BatteryStats { return mUpdateVersion; } - public void updateCurrentReportedCount(int count) { - if (mTimeBaseRunning && mUnpluggedReportedCount == 0) { + /** + * Updates the current recorded values. These are meant to be monotonically increasing + * and cumulative. If you are dealing with deltas, use {@link #add(long, int)}. + * + * If the values being recorded have been reset, the monotonically increasing requirement + * will be broken. In this case, {@link #endSample()} is automatically called and + * the total value of totalTime and count are recorded, starting a new monotonically + * increasing sample. + * + * @param totalTime total time of sample in microseconds. + * @param count total number of times the event being sampled occurred. + */ + public void update(long totalTime, int count) { + if (mTimeBaseRunning && !mTrackingReportedValues) { // Updating the reported value for the first time. + mUnpluggedReportedTotalTime = totalTime; mUnpluggedReportedCount = count; - // If we are receiving an update update mTrackingReportedValues; - mTrackingReportedValues = true; } + + mTrackingReportedValues = true; + + if (totalTime < mCurrentReportedTotalTime || count < mCurrentReportedCount) { + endSample(); + } + + mCurrentReportedTotalTime = totalTime; mCurrentReportedCount = count; } - public void addCurrentReportedCount(int delta) { - updateCurrentReportedCount(mCurrentReportedCount + delta); - } - - public void updateCurrentReportedTotalTime(long totalTime) { - if (mTimeBaseRunning && mUnpluggedReportedTotalTime == 0) { - // Updating the reported value for the first time. - mUnpluggedReportedTotalTime = totalTime; - // If we are receiving an update update mTrackingReportedValues; - mTrackingReportedValues = true; - } - mCurrentReportedTotalTime = totalTime; - } - - public void addCurrentReportedTotalTime(long delta) { - updateCurrentReportedTotalTime(mCurrentReportedTotalTime + delta); + /** + * Adds deltaTime and deltaCount to the current sample. + * + * @param deltaTime additional time recorded since the last sampled event, in microseconds. + * @param deltaCount additional number of times the event being sampled occurred. + */ + public void add(long deltaTime, int deltaCount) { + update(mCurrentReportedTotalTime + deltaTime, mCurrentReportedCount + deltaCount); } + @Override public void onTimeStarted(long elapsedRealtime, long baseUptime, long baseRealtime) { super.onTimeStarted(elapsedRealtime, baseUptime, baseRealtime); if (mTrackingReportedValues) { @@ -1319,11 +1346,13 @@ public class BatteryStatsImpl extends BatteryStats { mTimeBaseRunning = true; } + @Override public void onTimeStopped(long elapsedRealtime, long baseUptime, long baseRealtime) { super.onTimeStopped(elapsedRealtime, baseUptime, baseRealtime); mTimeBaseRunning = false; } + @Override public void logState(Printer pw, String prefix) { super.logState(pw, prefix); pw.println(prefix + "mCurrentReportedCount=" + mCurrentReportedCount @@ -1332,16 +1361,19 @@ public class BatteryStatsImpl extends BatteryStats { + " mUnpluggedReportedTotalTime=" + mUnpluggedReportedTotalTime); } + @Override protected long computeRunTimeLocked(long curBatteryRealtime) { return mTotalTime + (mTimeBaseRunning && mTrackingReportedValues ? mCurrentReportedTotalTime - mUnpluggedReportedTotalTime : 0); } + @Override protected int computeCurrentCountLocked() { return mCount + (mTimeBaseRunning && mTrackingReportedValues ? mCurrentReportedCount - mUnpluggedReportedCount : 0); } + @Override public void writeToParcel(Parcel out, long elapsedRealtimeUs) { super.writeToParcel(out, elapsedRealtimeUs); out.writeInt(mCurrentReportedCount); @@ -1351,12 +1383,16 @@ public class BatteryStatsImpl extends BatteryStats { out.writeInt(mTrackingReportedValues ? 1 : 0); } + @Override public boolean reset(boolean detachIfReset) { super.reset(detachIfReset); - setStale(); + mTrackingReportedValues = false; + mUnpluggedReportedTotalTime = 0; + mUnpluggedReportedCount = 0; return true; } + @Override public void writeSummaryFromParcelLocked(Parcel out, long batteryRealtime) { super.writeSummaryFromParcelLocked(out, batteryRealtime); out.writeLong(mCurrentReportedTotalTime); @@ -1364,6 +1400,7 @@ public class BatteryStatsImpl extends BatteryStats { out.writeInt(mTrackingReportedValues ? 1 : 0); } + @Override public void readSummaryFromParcelLocked(Parcel in) { super.readSummaryFromParcelLocked(in); mUnpluggedReportedTotalTime = mCurrentReportedTotalTime = in.readLong(); @@ -2002,7 +2039,7 @@ public class BatteryStatsImpl extends BatteryStats { public SamplingTimer getWakeupReasonTimerLocked(String name) { SamplingTimer timer = mWakeupReasonStats.get(name); if (timer == null) { - timer = new SamplingTimer(mClocks, mOnBatteryTimeBase, true); + timer = new SamplingTimer(mClocks, mOnBatteryTimeBase); mWakeupReasonStats.put(name, timer); } return timer; @@ -2015,8 +2052,7 @@ public class BatteryStatsImpl extends BatteryStats { public SamplingTimer getKernelWakelockTimerLocked(String name) { SamplingTimer kwlt = mKernelWakelockStats.get(name); if (kwlt == null) { - kwlt = new SamplingTimer(mClocks, mOnBatteryScreenOffTimeBase, - true /* track reported values */); + kwlt = new SamplingTimer(mClocks, mOnBatteryScreenOffTimeBase); mKernelWakelockStats.put(name, kwlt); } return kwlt; @@ -3125,8 +3161,7 @@ public class BatteryStatsImpl extends BatteryStats { if (mLastWakeupReason != null) { long deltaUptime = uptimeMs - mLastWakeupUptimeMs; SamplingTimer timer = getWakeupReasonTimerLocked(mLastWakeupReason); - timer.addCurrentReportedCount(1); - timer.addCurrentReportedTotalTime(deltaUptime * 1000); // time is in microseconds + timer.add(deltaUptime * 1000, 1); // time in in microseconds mLastWakeupReason = null; } } @@ -8727,16 +8762,15 @@ public class BatteryStatsImpl extends BatteryStats { SamplingTimer kwlt = mKernelWakelockStats.get(name); if (kwlt == null) { - kwlt = new SamplingTimer(mClocks, mOnBatteryScreenOffTimeBase, - true /* track reported val */); + kwlt = new SamplingTimer(mClocks, mOnBatteryScreenOffTimeBase); mKernelWakelockStats.put(name, kwlt); } - kwlt.updateCurrentReportedCount(kws.mCount); - kwlt.updateCurrentReportedTotalTime(kws.mTotalTime); + kwlt.update(kws.mTotalTime, kws.mCount); kwlt.setUpdateVersion(kws.mVersion); - if (kws.mVersion != wakelockStats.kernelWakelockVersion) - seenNonZeroTime |= kws.mTotalTime > 0; + if (kws.mVersion != wakelockStats.kernelWakelockVersion) { + seenNonZeroTime |= kws.mTotalTime > 0; + } } int numWakelocksSetStale = 0; @@ -8745,7 +8779,7 @@ public class BatteryStatsImpl extends BatteryStats { for (Map.Entry ent : mKernelWakelockStats.entrySet()) { SamplingTimer st = ent.getValue(); if (st.getUpdateVersion() != wakelockStats.kernelWakelockVersion) { - st.setStale(); + st.endSample(); numWakelocksSetStale++; } } diff --git a/core/tests/coretests/src/com/android/internal/os/BatteryStatsSamplingTimerTest.java b/core/tests/coretests/src/com/android/internal/os/BatteryStatsSamplingTimerTest.java index 51d41a40d71ab..ce6879d0ef4eb 100644 --- a/core/tests/coretests/src/com/android/internal/os/BatteryStatsSamplingTimerTest.java +++ b/core/tests/coretests/src/com/android/internal/os/BatteryStatsSamplingTimerTest.java @@ -21,8 +21,119 @@ import android.support.test.filters.SmallTest; import junit.framework.TestCase; +import org.mockito.Mockito; + public class BatteryStatsSamplingTimerTest extends TestCase { + @SmallTest + public void testSettingStalePreservesData() throws Exception { + final MockClocks clocks = new MockClocks(); + final BatteryStatsImpl.SamplingTimer timer = new BatteryStatsImpl.SamplingTimer(clocks, + Mockito.mock(BatteryStatsImpl.TimeBase.class)); + + timer.onTimeStarted(100, 100, 100); + + // First update is absorbed. + timer.update(10, 1); + + timer.update(20, 2); + + assertEquals(1, timer.getCountLocked(BatteryStats.STATS_SINCE_CHARGED)); + assertEquals(10, timer.getTotalTimeLocked(200, BatteryStats.STATS_SINCE_CHARGED)); + + timer.endSample(); + + assertEquals(1, timer.getCountLocked(BatteryStats.STATS_SINCE_CHARGED)); + assertEquals(10, timer.getTotalTimeLocked(200, BatteryStats.STATS_SINCE_CHARGED)); + + timer.onTimeStopped(200, 200, 200); + + assertEquals(1, timer.getCountLocked(BatteryStats.STATS_SINCE_CHARGED)); + assertEquals(10, timer.getTotalTimeLocked(200, BatteryStats.STATS_SINCE_CHARGED)); + } + + @SmallTest + public void testEndSampleAndContinueWhenTimeOrCountDecreases() throws Exception { + final MockClocks clocks = new MockClocks(); + final BatteryStatsImpl.TimeBase timeBase = Mockito.mock(BatteryStatsImpl.TimeBase.class); + final BatteryStatsImpl.SamplingTimer timer = new BatteryStatsImpl.SamplingTimer(clocks, + timeBase); + + // First once is absorbed. + timer.update(10, 1); + + timer.add(10, 1); + + assertEquals(0, timer.getCountLocked(BatteryStats.STATS_SINCE_CHARGED)); + assertEquals(0, timer.getTotalTimeLocked(200, BatteryStats.STATS_SINCE_CHARGED)); + + // This is less than we currently have, so we will end the sample. Time isn't running, so + // nothing should happen. + timer.update(0, 0); + + assertEquals(0, timer.getCountLocked(BatteryStats.STATS_SINCE_CHARGED)); + assertEquals(0, timer.getTotalTimeLocked(200, BatteryStats.STATS_SINCE_CHARGED)); + + timer.onTimeStarted(100, 100, 100); + + // This should add. + timer.add(100, 10); + + assertEquals(100, timer.getTotalTimeLocked(200, BatteryStats.STATS_SINCE_CHARGED)); + assertEquals(10, timer.getCountLocked(BatteryStats.STATS_SINCE_CHARGED)); + + // This is less than we currently have, so we should end our sample and continue with the + // entire amount updated here. + timer.update(50, 5); + + assertEquals(150, timer.getTotalTimeLocked(200, BatteryStats.STATS_SINCE_CHARGED)); + assertEquals(15, timer.getCountLocked(BatteryStats.STATS_SINCE_CHARGED)); + + timer.onTimeStopped(200, 200, 200); + + assertEquals(150, timer.getTotalTimeLocked(200, BatteryStats.STATS_SINCE_CHARGED)); + assertEquals(15, timer.getCountLocked(BatteryStats.STATS_SINCE_CHARGED)); + } + + @SmallTest + public void testFirstUpdateIsAbsorbed() throws Exception { + final MockClocks clocks = new MockClocks(); + final BatteryStatsImpl.TimeBase timeBase = Mockito.mock(BatteryStatsImpl.TimeBase.class); + + BatteryStatsImpl.SamplingTimer timer = new BatteryStatsImpl.SamplingTimer(clocks, timeBase); + + // This should be absorbed because it is our first update and we don't know what + // was being counted before. + timer.update(10, 1); + + assertEquals(0, timer.getTotalTimeLocked(10, BatteryStats.STATS_SINCE_CHARGED)); + assertEquals(0, timer.getCountLocked(BatteryStats.STATS_SINCE_CHARGED)); + + timer = new BatteryStatsImpl.SamplingTimer(clocks, timeBase); + timer.onTimeStarted(100, 100, 100); + + // This should be absorbed. + timer.update(10, 1); + + assertEquals(0, timer.getTotalTimeLocked(100, BatteryStats.STATS_SINCE_CHARGED)); + assertEquals(0, timer.getCountLocked(BatteryStats.STATS_SINCE_CHARGED)); + + // This should NOT be aborbed, since we've already done that. + timer.add(10, 1); + + assertEquals(10, timer.getTotalTimeLocked(100, BatteryStats.STATS_SINCE_CHARGED)); + assertEquals(1, timer.getCountLocked(BatteryStats.STATS_SINCE_CHARGED)); + + timer.onTimeStopped(200, 200, 200); + timer.onTimeStarted(300, 300, 300); + + // This should NOT be absorbed. + timer.add(10, 1); + + assertEquals(20, timer.getTotalTimeLocked(300, BatteryStats.STATS_SINCE_CHARGED)); + assertEquals(2, timer.getCountLocked(BatteryStats.STATS_SINCE_CHARGED)); + } + @SmallTest public void testSampleTimerSummaryParceling() throws Exception { final MockClocks clocks = new MockClocks(); @@ -32,18 +143,15 @@ public class BatteryStatsSamplingTimerTest extends TestCase { final BatteryStatsImpl.TimeBase timeBase = new BatteryStatsImpl.TimeBase(); timeBase.init(clocks.uptimeMillis(), clocks.elapsedRealtime()); - BatteryStatsImpl.SamplingTimer timer = new BatteryStatsImpl.SamplingTimer(clocks, timeBase, - true); + BatteryStatsImpl.SamplingTimer timer = new BatteryStatsImpl.SamplingTimer(clocks, timeBase); // Start running on battery. timeBase.setRunning(true, clocks.uptimeMillis(), clocks.elapsedRealtime()); // The first update on battery consumes the values as a way of starting cleanly. - timer.addCurrentReportedTotalTime(10); - timer.addCurrentReportedCount(1); + timer.add(10, 1); - timer.addCurrentReportedTotalTime(10); - timer.addCurrentReportedCount(1); + timer.add(10, 1); clocks.realtime = 20; clocks.uptime = 20; @@ -72,14 +180,14 @@ public class BatteryStatsSamplingTimerTest extends TestCase { // Read the on battery summary from the parcel. BatteryStatsImpl.SamplingTimer unparceledTimer = new BatteryStatsImpl.SamplingTimer( - clocks, timeBase, true); + clocks, timeBase); unparceledTimer.readSummaryFromParcelLocked(onBatterySummaryParcel); assertEquals(10, unparceledTimer.getTotalTimeLocked(0, BatteryStats.STATS_SINCE_CHARGED)); assertEquals(1, unparceledTimer.getCountLocked(BatteryStats.STATS_SINCE_CHARGED)); // Read the off battery summary from the parcel. - unparceledTimer = new BatteryStatsImpl.SamplingTimer(clocks, timeBase, true); + unparceledTimer = new BatteryStatsImpl.SamplingTimer(clocks, timeBase); unparceledTimer.readSummaryFromParcelLocked(offBatterySummaryParcel); assertEquals(10, unparceledTimer.getTotalTimeLocked(0, BatteryStats.STATS_SINCE_CHARGED));