From 04e9dc91d8005160fe4dcc003d61d9504dd75886 Mon Sep 17 00:00:00 2001 From: Makoto Onuki Date: Mon, 29 Jan 2018 13:09:45 -0800 Subject: [PATCH] Tron counters for battery saving stats. It adds 4 sets of the following two counters: - battery_saver_stats_seconds_XY Time spent in the current mode, in seconds. - battery_saver_stats_milliamps_XY Battery spent in the current mode, in mA. Where X = "1":battery saver ON or "0": battery saver OFF. Y = "1":device interactive or "0": device not interactive. Which are sent when either of the above states is about to change. For example, when the user turns on the screen, and turns it off in 60 seconds, and the battery level dropped 1mA during this (w/ assuming battery saver OFF), we'd send the following two values: - battery_saver_stats_seconds_01 = 60 - battery_saver_stats_milliamps_01 = 1 Bug: 72229630 Test: manual test with dumpsys power, etc Test: atest $ANDROID_BUILD_TOP/frameworks/base/services/tests/servicestests/src/com/android/server/power/batterysaver/BatterySavingStatsTest.java Change-Id: I8ab8c395ca17b64638b2b164211528ac74e49023 --- .../batterysaver/BatterySavingStats.java | 105 +++++++++++++---- .../batterysaver/BatterySavingStatsTest.java | 111 +++++++++++++++++- 2 files changed, 191 insertions(+), 25 deletions(-) diff --git a/services/core/java/com/android/server/power/batterysaver/BatterySavingStats.java b/services/core/java/com/android/server/power/batterysaver/BatterySavingStats.java index df4f8eca55955..946635043c12d 100644 --- a/services/core/java/com/android/server/power/batterysaver/BatterySavingStats.java +++ b/services/core/java/com/android/server/power/batterysaver/BatterySavingStats.java @@ -22,6 +22,7 @@ import android.util.Slog; import com.android.internal.annotations.GuardedBy; import com.android.internal.annotations.VisibleForTesting; +import com.android.internal.logging.MetricsLogger; import com.android.server.EventLogTags; import com.android.server.LocalServices; import com.android.server.power.BatterySaverPolicy; @@ -116,9 +117,16 @@ public class BatterySavingStats { } } + @VisibleForTesting + static final String COUNTER_POWER_MILLIAMPS_PREFIX = "battery_saver_stats_milliamps_"; + + @VisibleForTesting + static final String COUNTER_TIME_SECONDS_PREFIX = "battery_saver_stats_seconds_"; + private static BatterySavingStats sInstance; private BatteryManagerInternal mBatteryManagerInternal; + private final MetricsLogger mMetricsLogger; private static final int STATE_NOT_INITIALIZED = -1; private static final int STATE_CHARGING = -2; @@ -136,17 +144,21 @@ public class BatterySavingStats { @GuardedBy("mLock") final ArrayMap mStats = new ArrayMap<>(); + private final MetricsLoggerHelper mMetricsLoggerHelper = new MetricsLoggerHelper(); + /** * Don't call it directly -- use {@link #getInstance()}. Not private for testing. + * @param metricsLogger */ @VisibleForTesting - BatterySavingStats() { + BatterySavingStats(MetricsLogger metricsLogger) { mBatteryManagerInternal = LocalServices.getService(BatteryManagerInternal.class); + mMetricsLogger = metricsLogger; } public static synchronized BatterySavingStats getInstance() { if (sInstance == null) { - sInstance = new BatterySavingStats(); + sInstance = new BatterySavingStats(new MetricsLogger()); } return sInstance; } @@ -208,10 +220,12 @@ public class BatterySavingStats { return getStat(statesToIndex(batterySaverState, interactiveState, dozeState)); } + @VisibleForTesting long injectCurrentTime() { return SystemClock.elapsedRealtime(); } + @VisibleForTesting int injectBatteryLevel() { final BatteryManagerInternal bmi = getBatteryManagerInternal(); if (bmi == null) { @@ -227,15 +241,9 @@ public class BatterySavingStats { */ public void transitionState(int batterySaverState, int interactiveState, int dozeState) { synchronized (mLock) { - final int newState = statesToIndex( batterySaverState, interactiveState, dozeState); - if (mCurrentState == newState) { - return; - } - - endLastStateLocked(); - startNewStateLocked(newState); + transitionStateLocked(newState); } } @@ -244,23 +252,30 @@ public class BatterySavingStats { */ public void startCharging() { synchronized (mLock) { - if (mCurrentState < 0) { - return; - } - - endLastStateLocked(); - startNewStateLocked(STATE_CHARGING); + transitionStateLocked(STATE_CHARGING); } } - private void endLastStateLocked() { + private void transitionStateLocked(int newState) { + if (mCurrentState == newState) { + return; + } + final long now = injectCurrentTime(); + final int batteryLevel = injectBatteryLevel(); + + endLastStateLocked(now, batteryLevel); + startNewStateLocked(newState, now, batteryLevel); + mMetricsLoggerHelper.transitionState(newState, now, batteryLevel); + } + + private void endLastStateLocked(long now, int batteryLevel) { if (mCurrentState < 0) { return; } final Stat stat = getStat(mCurrentState); - stat.endBatteryLevel = injectBatteryLevel(); - stat.endTime = injectCurrentTime(); + stat.endBatteryLevel = batteryLevel; + stat.endTime = now; final long deltaTime = stat.endTime - stat.startTime; final int deltaDrain = stat.startBatteryLevel - stat.endBatteryLevel; @@ -283,9 +298,10 @@ public class BatterySavingStats { deltaDrain, stat.totalTimeMillis, stat.totalBatteryDrain); + } - private void startNewStateLocked(int newState) { + private void startNewStateLocked(int newState, long now, int batteryLevel) { if (DEBUG) { Slog.d(TAG, "New state: " + stateToString(newState)); } @@ -296,8 +312,8 @@ public class BatterySavingStats { } final Stat stat = getStat(mCurrentState); - stat.startBatteryLevel = injectBatteryLevel(); - stat.startTime = injectCurrentTime(); + stat.startBatteryLevel = batteryLevel; + stat.startTime = now; stat.endTime = 0; } @@ -349,5 +365,50 @@ public class BatterySavingStats { onStat.totalBatteryDrain / 1000, onStat.drainPerHour() / 1000.0)); } -} + @VisibleForTesting + class MetricsLoggerHelper { + private int mLastState = STATE_NOT_INITIALIZED; + private long mStartTime; + private int mStartBatteryLevel; + + private static final int STATE_CHANGE_DETECT_MASK = + (BatterySaverState.MASK << BatterySaverState.SHIFT) | + (InteractiveState.MASK << InteractiveState.SHIFT); + + public void transitionState(int newState, long now, int batteryLevel) { + final boolean stateChanging = + ((mLastState >= 0) ^ (newState >= 0)) || + (((mLastState ^ newState) & STATE_CHANGE_DETECT_MASK) != 0); + if (stateChanging) { + if (mLastState >= 0) { + final long deltaTime = now - mStartTime; + final int deltaBattery = mStartBatteryLevel - batteryLevel; + + report(mLastState, deltaTime, deltaBattery); + } + mStartTime = now; + mStartBatteryLevel = batteryLevel; + } + mLastState = newState; + } + + String getCounterSuffix(int state) { + final boolean batterySaver = + BatterySaverState.fromIndex(state) != BatterySaverState.OFF; + final boolean interactive = + InteractiveState.fromIndex(state) != InteractiveState.NON_INTERACTIVE; + if (batterySaver) { + return interactive ? "11" : "10"; + } else { + return interactive ? "01" : "00"; + } + } + + void report(int state, long deltaTimeMs, int deltaBatteryUa) { + final String suffix = getCounterSuffix(state); + mMetricsLogger.count(COUNTER_POWER_MILLIAMPS_PREFIX + suffix, deltaBatteryUa / 1000); + mMetricsLogger.count(COUNTER_TIME_SECONDS_PREFIX + suffix, (int) (deltaTimeMs / 1000)); + } + } +} diff --git a/services/tests/servicestests/src/com/android/server/power/batterysaver/BatterySavingStatsTest.java b/services/tests/servicestests/src/com/android/server/power/batterysaver/BatterySavingStatsTest.java index f788caccbdcef..c3714c85e8959 100644 --- a/services/tests/servicestests/src/com/android/server/power/batterysaver/BatterySavingStatsTest.java +++ b/services/tests/servicestests/src/com/android/server/power/batterysaver/BatterySavingStatsTest.java @@ -16,10 +16,18 @@ package com.android.server.power.batterysaver; import static org.junit.Assert.assertEquals; +import static org.mockito.ArgumentMatchers.anyInt; +import static org.mockito.ArgumentMatchers.anyString; +import static org.mockito.ArgumentMatchers.eq; +import static org.mockito.Mockito.mock; +import static org.mockito.Mockito.reset; +import static org.mockito.Mockito.times; +import static org.mockito.Mockito.verify; import android.support.test.filters.SmallTest; import android.support.test.runner.AndroidJUnit4; +import com.android.internal.logging.MetricsLogger; import com.android.server.power.batterysaver.BatterySavingStats.BatterySaverState; import com.android.server.power.batterysaver.BatterySavingStats.DozeState; import com.android.server.power.batterysaver.BatterySavingStats.InteractiveState; @@ -39,7 +47,11 @@ public class BatterySavingStatsTest { private class BatterySavingStatsTestable extends BatterySavingStats { private long mTime = 1_000_000; // Some random starting time. - private int mBatteryLevel = 100; + private int mBatteryLevel = 1_000_000_000; + + private BatterySavingStatsTestable() { + super(mMetricsLogger); + } @Override long injectCurrentTime() { @@ -60,8 +72,8 @@ public class BatterySavingStatsTest { mTime += 60_000 * minutes; } - void drainBattery(int percent) { - mBatteryLevel -= percent; + void drainBattery(int value) { + mBatteryLevel -= value; if (mBatteryLevel < 0) { mBatteryLevel = 0; } @@ -81,6 +93,8 @@ public class BatterySavingStatsTest { } } + public MetricsLogger mMetricsLogger = mock(MetricsLogger.class); + @Test public void testAll() { final BatterySavingStatsTestable target = new BatterySavingStatsTestable(); @@ -202,4 +216,95 @@ public class BatterySavingStatsTest { "BS=1,I=1,D=2:{0m,0,0.00}", target.toDebugString()); } + + private void assertMetricsLog(String counter, int value) { + verify(mMetricsLogger, times(1)).count(eq(counter), eq(value)); + } + + @Test + public void testMetricsLogger() { + final BatterySavingStatsTestable target = new BatterySavingStatsTestable(); + + target.advanceClock(1); + target.drainBattery(1000); + + target.transitionState( + BatterySaverState.OFF, + InteractiveState.INTERACTIVE, + DozeState.NOT_DOZING); + + verify(mMetricsLogger, times(0)).count(anyString(), anyInt()); + + target.advanceClock(1); + target.drainBattery(2000); + + reset(mMetricsLogger); + target.transitionState( + BatterySaverState.OFF, + InteractiveState.NON_INTERACTIVE, + DozeState.NOT_DOZING); + + assertMetricsLog(BatterySavingStats.COUNTER_POWER_MILLIAMPS_PREFIX + "01", 2); + assertMetricsLog(BatterySavingStats.COUNTER_TIME_SECONDS_PREFIX + "01", 60); + + target.advanceClock(1); + target.drainBattery(2000); + + reset(mMetricsLogger); + target.transitionState( + BatterySaverState.OFF, + InteractiveState.NON_INTERACTIVE, + DozeState.DEEP); + + target.advanceClock(1); + target.drainBattery(2000); + + verify(mMetricsLogger, times(0)).count(anyString(), anyInt()); + + target.transitionState( + BatterySaverState.OFF, + InteractiveState.NON_INTERACTIVE, + DozeState.LIGHT); + + target.advanceClock(1); + target.drainBattery(2000); + + verify(mMetricsLogger, times(0)).count(anyString(), anyInt()); + + target.transitionState( + BatterySaverState.ON, + InteractiveState.INTERACTIVE, + DozeState.NOT_DOZING); + + assertMetricsLog(BatterySavingStats.COUNTER_POWER_MILLIAMPS_PREFIX + "00", 2 * 3); + assertMetricsLog(BatterySavingStats.COUNTER_TIME_SECONDS_PREFIX + "00", 60 * 3); + + target.advanceClock(10); + target.drainBattery(10_000); + + reset(mMetricsLogger); + target.startCharging(); + + assertMetricsLog(BatterySavingStats.COUNTER_POWER_MILLIAMPS_PREFIX + "11", 10); + assertMetricsLog(BatterySavingStats.COUNTER_TIME_SECONDS_PREFIX + "11", 60 * 10); + + target.advanceClock(1); + target.drainBattery(2000); + + reset(mMetricsLogger); + target.transitionState( + BatterySaverState.ON, + InteractiveState.NON_INTERACTIVE, + DozeState.NOT_DOZING); + + verify(mMetricsLogger, times(0)).count(anyString(), anyInt()); + + target.advanceClock(1); + target.drainBattery(2000); + + target.startCharging(); + + assertMetricsLog(BatterySavingStats.COUNTER_POWER_MILLIAMPS_PREFIX + "10", 2); + assertMetricsLog(BatterySavingStats.COUNTER_TIME_SECONDS_PREFIX + "10", 60); + } }