Have BatteryStats track and report the running wakelocks.

The times reported are in the screen off / on battery time base.

Bug: 29546924
Change-Id: I025b2959becb256a26cf531e944786d4e9a59149
This commit is contained in:
Joe Onorato
2016-07-25 11:18:42 -07:00
parent ba8f3d03ac
commit adbee556a9
4 changed files with 451 additions and 24 deletions

View File

@@ -30,6 +30,8 @@ import android.content.pm.ApplicationInfo;
import android.telephony.SignalStrength;
import android.text.format.DateFormat;
import android.util.ArrayMap;
import android.util.Log;
import android.util.LongSparseArray;
import android.util.MutableBoolean;
import android.util.Pair;
import android.util.Printer;
@@ -47,6 +49,7 @@ import com.android.internal.os.BatteryStatsHelper;
* @hide
*/
public abstract class BatteryStats implements Parcelable {
private static final String TAG = "BatteryStats";
private static final boolean LOCAL_LOGV = false;
@@ -175,8 +178,11 @@ public abstract class BatteryStats implements Parcelable {
/**
* Current version of checkin data format.
*
* New in version 19:
* - Wakelock data (wl) gets current and max times.
*/
static final String CHECKIN_VERSION = "18";
static final String CHECKIN_VERSION = "19";
/**
* Old version, we hit 9 and ran out of room, need to remove.
@@ -351,6 +357,32 @@ public abstract class BatteryStats implements Parcelable {
*/
public abstract long getTimeSinceMarkLocked(long elapsedRealtimeUs);
/**
* Returns the max duration if it is being tracked.
* Not all Timer subclasses track the max duration and the current duration.
*/
public long getMaxDurationMsLocked(long elapsedRealtimeMs) {
return -1;
}
/**
* Returns the current time the timer has been active, if it is being tracked.
* Not all Timer subclasses track the max duration and the current duration.
*/
public long getCurrentDurationMsLocked(long elapsedRealtimeMs) {
return -1;
}
/**
* 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.
*/
public boolean isRunningLocked() {
return false;
}
/**
* Temporary for debugging.
*/
@@ -2558,6 +2590,22 @@ public abstract class BatteryStats implements Parcelable {
sb.append('(');
sb.append(count);
sb.append(" times)");
final long maxDurationMs = timer.getMaxDurationMsLocked(elapsedRealtimeUs/1000);
if (maxDurationMs >= 0) {
sb.append(" max=");
sb.append(maxDurationMs);
}
if (timer.isRunningLocked()) {
final long currentMs = timer.getCurrentDurationMsLocked(elapsedRealtimeUs/1000);
if (currentMs >= 0) {
sb.append(" (running for ");
sb.append(currentMs);
sb.append("ms)");
} else {
sb.append(" (running)");
}
}
return ", ";
}
}
@@ -2565,6 +2613,7 @@ public abstract class BatteryStats implements Parcelable {
}
/**
* Prints details about a timer, if its total time was greater than 0.
*
* @param pw a PrintWriter object to print to.
* @param sb a StringBuilder object.
@@ -2573,24 +2622,40 @@ public abstract class BatteryStats implements Parcelable {
* @param which which one of STATS_SINCE_CHARGED, STATS_SINCE_UNPLUGGED, or STATS_CURRENT.
* @param prefix a String to be prepended to each line of output.
* @param type the name of the timer.
* @return true if anything was printed.
*/
private static final boolean printTimer(PrintWriter pw, StringBuilder sb, Timer timer,
long rawRealtime, int which, String prefix, String type) {
long rawRealtimeUs, int which, String prefix, String type) {
if (timer != null) {
// Convert from microseconds to milliseconds with rounding
final long totalTime = (timer.getTotalTimeLocked(
rawRealtime, which) + 500) / 1000;
final long totalTimeMs = (timer.getTotalTimeLocked(
rawRealtimeUs, which) + 500) / 1000;
final int count = timer.getCountLocked(which);
if (totalTime != 0) {
if (totalTimeMs != 0) {
sb.setLength(0);
sb.append(prefix);
sb.append(" ");
sb.append(type);
sb.append(": ");
formatTimeMs(sb, totalTime);
formatTimeMs(sb, totalTimeMs);
sb.append("realtime (");
sb.append(count);
sb.append(" times)");
final long maxDurationMs = timer.getMaxDurationMsLocked(rawRealtimeUs/1000);
if (maxDurationMs >= 0) {
sb.append(" max=");
sb.append(maxDurationMs);
}
if (timer.isRunningLocked()) {
final long currentMs = timer.getCurrentDurationMsLocked(rawRealtimeUs/1000);
if (currentMs >= 0) {
sb.append(" (running for ");
sb.append(currentMs);
sb.append("ms)");
} else {
sb.append(" (running)");
}
}
pw.println(sb.toString());
return true;
}
@@ -2613,15 +2678,23 @@ public abstract class BatteryStats implements Parcelable {
long elapsedRealtimeUs, String name, int which, String linePrefix) {
long totalTimeMicros = 0;
int count = 0;
long max = -1;
long current = -1;
if (timer != null) {
totalTimeMicros = timer.getTotalTimeLocked(elapsedRealtimeUs, which);
count = timer.getCountLocked(which);
current = timer.getCurrentDurationMsLocked(elapsedRealtimeUs/1000);
max = timer.getMaxDurationMsLocked(elapsedRealtimeUs/1000);
}
sb.append(linePrefix);
sb.append((totalTimeMicros + 500) / 1000); // microseconds to milliseconds with rounding
sb.append(',');
sb.append(name != null ? name + "," : "");
sb.append(count);
sb.append(',');
sb.append(current);
sb.append(',');
sb.append(max);
return ",";
}

View File

@@ -108,7 +108,7 @@ public class BatteryStatsImpl extends BatteryStats {
private static final int MAGIC = 0xBA757475; // 'BATSTATS'
// Current on-disk Parcel version
private static final int VERSION = 148 + (USE_OLD_HISTORY ? 1000 : 0);
private static final int VERSION = 149 + (USE_OLD_HISTORY ? 1000 : 0);
// Maximum number of items we will record in the history.
private static final int MAX_HISTORY_ITEMS = 2000;
@@ -1566,6 +1566,186 @@ public class BatteryStatsImpl extends BatteryStats {
}
}
/**
* A StopwatchTimer that also tracks the total and max individual
* time spent active according to the given timebase. Whereas
* StopwatchTimer apportions the time amongst all in the pool,
* the total and max durations are not apportioned.
*/
public static class DurationTimer extends StopwatchTimer {
/**
* The time (in ms) that the timer was last acquired or the time base
* last (re-)started. Increasing the nesting depth does not reset this time.
*
* -1 if the timer is currently not running or the time base is not running.
*
* If written to a parcel, the start time is reset, as is mNesting in the base class
* StopwatchTimer.
*/
long mStartTimeMs = -1;
/**
* The longest time period (in ms) that the timer has been active.
*/
long mMaxDurationMs;
/**
* The total time (in ms) that that the timer has been active since reset().
*/
long mCurrentDurationMs;
public DurationTimer(Clocks clocks, Uid uid, int type, ArrayList<StopwatchTimer> timerPool,
TimeBase timeBase, Parcel in) {
super(clocks, uid, type, timerPool, timeBase, in);
mMaxDurationMs = in.readLong();
}
public DurationTimer(Clocks clocks, Uid uid, int type, ArrayList<StopwatchTimer> timerPool,
TimeBase timeBase) {
super(clocks, uid, type, timerPool, timeBase);
}
@Override
public void writeToParcel(Parcel out, long elapsedRealtimeUs) {
super.writeToParcel(out, elapsedRealtimeUs);
out.writeLong(mMaxDurationMs);
}
/**
* Write the summary to the parcel.
*
* Since the time base is probably meaningless after we come back, reading
* from this will have the effect of stopping the timer. So here all we write
* is the max duration.
*/
@Override
public void writeSummaryFromParcelLocked(Parcel out, long elapsedRealtimeUs) {
super.writeSummaryFromParcelLocked(out, elapsedRealtimeUs);
out.writeLong(mMaxDurationMs);
}
/**
* Read the summary parcel.
*
* Has the side effect of stopping the timer.
*/
@Override
public void readSummaryFromParcelLocked(Parcel in) {
super.readSummaryFromParcelLocked(in);
mMaxDurationMs = in.readLong();
mStartTimeMs = -1;
mCurrentDurationMs = 0;
}
/**
* The TimeBase time started (again).
*
* If the timer is also running, store the start time.
*/
public void onTimeStarted(long elapsedRealtimeUs, long baseUptime, long baseRealtime) {
super.onTimeStarted(elapsedRealtimeUs, baseUptime, baseRealtime);
if (mNesting > 0) {
mStartTimeMs = mTimeBase.getRealtime(mClocks.elapsedRealtime()*1000) / 1000;
}
}
/**
* The TimeBase stopped running.
*
* If the timer is running, add the duration into mCurrentDurationMs.
*/
@Override
public void onTimeStopped(long elapsedRealtimeUs, long baseUptime, long baseRealtime) {
super.onTimeStopped(elapsedRealtimeUs, baseUptime, baseRealtime);
if (mNesting > 0) {
mCurrentDurationMs += (elapsedRealtimeUs / 1000) - mStartTimeMs;
}
mStartTimeMs = -1;
}
@Override
public void logState(Printer pw, String prefix) {
super.logState(pw, prefix);
}
@Override
public void startRunningLocked(long elapsedRealtimeMs) {
super.startRunningLocked(elapsedRealtimeMs);
if (mNesting == 1 && mTimeBase.isRunning()) {
// Just started
mStartTimeMs = mTimeBase.getRealtime(mClocks.elapsedRealtime()*1000) / 1000;
}
}
/**
* Decrements the mNesting ref-count on this timer.
*
* If it actually stopped (mNesting went to 0), then possibly update
* mMaxDuration if the current duration was the longest ever.
*/
@Override
public void stopRunningLocked(long elapsedRealtimeMs) {
super.stopRunningLocked(elapsedRealtimeMs);
if (mNesting == 0) {
final long durationMs = getCurrentDurationMsLocked(elapsedRealtimeMs);
if (durationMs > mMaxDurationMs) {
mMaxDurationMs = durationMs;
}
mStartTimeMs = -1;
mCurrentDurationMs = 0;
}
}
@Override
public boolean reset(boolean detachIfReset) {
boolean result = super.reset(detachIfReset);
mMaxDurationMs = 0;
mCurrentDurationMs = 0;
if (mNesting > 0) {
mStartTimeMs = mTimeBase.getRealtime(mClocks.elapsedRealtime()*1000) / 1000;
} else {
mStartTimeMs = -1;
}
return result;
}
/**
* Returns the max duration that this timer has ever seen.
*
* Note that this time is NOT split between the timers in the timer group that
* this timer is attached to. It is the TOTAL time.
*/
@Override
public long getMaxDurationMsLocked(long elapsedRealtimeMs) {
if (mNesting > 0) {
final long durationMs = getCurrentDurationMsLocked(elapsedRealtimeMs);
if (durationMs > mMaxDurationMs) {
return durationMs;
}
}
return mMaxDurationMs;
}
/**
* Returns the time since the timer was started.
*
* Note that this time is NOT split between the timers in the timer group that
* this timer is attached to. It is the TOTAL time.
*/
@Override
public long getCurrentDurationMsLocked(long elapsedRealtimeMs) {
long durationMs = mCurrentDurationMs;
if (mNesting > 0) {
if (mTimeBase.isRunning()) {
durationMs += (mTimeBase.getRealtime(elapsedRealtimeMs*1000)/1000)
- mStartTimeMs;
}
}
return durationMs;
}
}
/**
* State for keeping track of timing information.
*/
@@ -6535,7 +6715,7 @@ public class BatteryStatsImpl extends BatteryStats {
/**
* How long (in ms) this uid has been keeping the device partially awake.
*/
StopwatchTimer mTimerPartial;
DurationTimer mTimerPartial;
/**
* How long (in ms) this uid has been keeping the device fully awake.
@@ -6564,8 +6744,8 @@ public class BatteryStatsImpl extends BatteryStats {
* @param in the Parcel to be read from.
* return a new Timer, or null.
*/
private StopwatchTimer readTimerFromParcel(int type, ArrayList<StopwatchTimer> pool,
TimeBase timeBase, Parcel in) {
private StopwatchTimer readStopwatchTimerFromParcel(int type,
ArrayList<StopwatchTimer> pool, TimeBase timeBase, Parcel in) {
if (in.readInt() == 0) {
return null;
}
@@ -6573,6 +6753,22 @@ public class BatteryStatsImpl extends BatteryStats {
return new StopwatchTimer(mBsi.mClocks, mUid, type, pool, timeBase, in);
}
/**
* Reads a possibly null Timer from a Parcel. The timer is associated with the
* proper timer pool from the given BatteryStatsImpl object.
*
* @param in the Parcel to be read from.
* return a new Timer, or null.
*/
private DurationTimer readDurationTimerFromParcel(int type,
ArrayList<StopwatchTimer> pool, TimeBase timeBase, Parcel in) {
if (in.readInt() == 0) {
return null;
}
return new DurationTimer(mBsi.mClocks, mUid, type, pool, timeBase, in);
}
boolean reset() {
boolean wlactive = false;
if (mTimerFull != null) {
@@ -6609,11 +6805,14 @@ public class BatteryStatsImpl extends BatteryStats {
}
void readFromParcelLocked(TimeBase timeBase, TimeBase screenOffTimeBase, Parcel in) {
mTimerPartial = readTimerFromParcel(WAKE_TYPE_PARTIAL,
mTimerPartial = readDurationTimerFromParcel(WAKE_TYPE_PARTIAL,
mBsi.mPartialTimers, screenOffTimeBase, in);
mTimerFull = readTimerFromParcel(WAKE_TYPE_FULL, mBsi.mFullTimers, timeBase, in);
mTimerWindow = readTimerFromParcel(WAKE_TYPE_WINDOW, mBsi.mWindowTimers, timeBase, in);
mTimerDraw = readTimerFromParcel(WAKE_TYPE_DRAW, mBsi.mDrawTimers, timeBase, in);
mTimerFull = readStopwatchTimerFromParcel(WAKE_TYPE_FULL,
mBsi.mFullTimers, timeBase, in);
mTimerWindow = readStopwatchTimerFromParcel(WAKE_TYPE_WINDOW,
mBsi.mWindowTimers, timeBase, in);
mTimerDraw = readStopwatchTimerFromParcel(WAKE_TYPE_DRAW,
mBsi.mDrawTimers, timeBase, in);
}
void writeToParcelLocked(Parcel out, long elapsedRealtimeUs) {
@@ -6635,40 +6834,43 @@ public class BatteryStatsImpl extends BatteryStats {
}
public StopwatchTimer getStopwatchTimer(int type) {
StopwatchTimer t;
switch (type) {
case WAKE_TYPE_PARTIAL:
t = mTimerPartial;
case WAKE_TYPE_PARTIAL: {
DurationTimer t = mTimerPartial;
if (t == null) {
t = new StopwatchTimer(mBsi.mClocks, mUid, WAKE_TYPE_PARTIAL,
t = new DurationTimer(mBsi.mClocks, mUid, WAKE_TYPE_PARTIAL,
mBsi.mPartialTimers, mBsi.mOnBatteryScreenOffTimeBase);
mTimerPartial = t;
}
return t;
case WAKE_TYPE_FULL:
t = mTimerFull;
}
case WAKE_TYPE_FULL: {
StopwatchTimer t = mTimerFull;
if (t == null) {
t = new StopwatchTimer(mBsi.mClocks, mUid, WAKE_TYPE_FULL,
mBsi.mFullTimers, mBsi.mOnBatteryTimeBase);
mTimerFull = t;
}
return t;
case WAKE_TYPE_WINDOW:
t = mTimerWindow;
}
case WAKE_TYPE_WINDOW: {
StopwatchTimer t = mTimerWindow;
if (t == null) {
t = new StopwatchTimer(mBsi.mClocks, mUid, WAKE_TYPE_WINDOW,
mBsi.mWindowTimers, mBsi.mOnBatteryTimeBase);
mTimerWindow = t;
}
return t;
case WAKE_TYPE_DRAW:
t = mTimerDraw;
}
case WAKE_TYPE_DRAW: {
StopwatchTimer t = mTimerDraw;
if (t == null) {
t = new StopwatchTimer(mBsi.mClocks, mUid, WAKE_TYPE_DRAW,
mBsi.mDrawTimers, mBsi.mOnBatteryTimeBase);
mTimerDraw = t;
}
return t;
}
default:
throw new IllegalArgumentException("type=" + type);
}

View File

@@ -0,0 +1,151 @@
/*
* Copyright (C) 2016 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.os.Parcel;
import android.support.test.filters.SmallTest;
import android.util.Log;
import junit.framework.TestCase;
import org.mockito.Mockito;
/**
* Test BatteryStatsImpl.DurationTimer.
*
* In these tests, unless otherwise commented, the time increments by
* 2x + 100, to make the subtraction unlikely to alias to another time.
*/
public class BatteryStatsDurationTimerTest extends TestCase {
@SmallTest
public void testStartStop() throws Exception {
final MockClocks clocks = new MockClocks();
final BatteryStatsImpl.TimeBase timeBase = new BatteryStatsImpl.TimeBase();
timeBase.init(clocks.uptimeMillis(), clocks.elapsedRealtime());
final BatteryStatsImpl.DurationTimer timer = new BatteryStatsImpl.DurationTimer(clocks,
null, BatteryStats.WAKE_TYPE_PARTIAL, null, timeBase);
// TimeBase running, timer not running: current and max are 0
timeBase.setRunning(true, /* uptimeUs */ 0, /* realtimeUs */ 100*1000);
assertFalse(timer.isRunningLocked());
assertEquals(0, timer.getCurrentDurationMsLocked(300));
assertEquals(0, timer.getMaxDurationMsLocked(301));
// Start timer: current and max advance
timer.startRunningLocked(700);
assertTrue(timer.isRunningLocked());
assertEquals(800, timer.getCurrentDurationMsLocked(1500));
assertEquals(801, timer.getMaxDurationMsLocked(1501));
// Stop timer: current resets to 0, max remains
timer.stopRunningLocked(3100);
assertFalse(timer.isRunningLocked());
assertEquals(0, timer.getCurrentDurationMsLocked(6300));
assertEquals(2400, timer.getMaxDurationMsLocked(6301));
// Start time again, but check with a short time, and make sure max doesn't
// increment.
timer.startRunningLocked(12700);
assertTrue(timer.isRunningLocked());
assertEquals(100, timer.getCurrentDurationMsLocked(12800));
assertEquals(2400, timer.getMaxDurationMsLocked(12801));
// And stop it again, but with a short time, and make sure it doesn't increment.
timer.stopRunningLocked(12900);
assertFalse(timer.isRunningLocked());
assertEquals(0, timer.getCurrentDurationMsLocked(13000));
assertEquals(2400, timer.getMaxDurationMsLocked(13001));
// Now start and check that the time doesn't increase if the two times are the same.
timer.startRunningLocked(27000);
assertTrue(timer.isRunningLocked());
assertEquals(0, timer.getCurrentDurationMsLocked(27000));
assertEquals(2400, timer.getMaxDurationMsLocked(27000));
// Stop the TimeBase. The values should be frozen.
timeBase.setRunning(false, /* uptimeUs */ 10, /* realtimeUs */ 55000*1000);
assertTrue(timer.isRunningLocked());
assertEquals(28100, timer.getCurrentDurationMsLocked(110100)); // Why 28100 and not 28000?
assertEquals(28100, timer.getMaxDurationMsLocked(110101));
// Start the TimeBase. The values should be the old value plus the delta
// between when the timer restarted and the current time
timeBase.setRunning(true, /* uptimeUs */ 10, /* realtimeUs */ 220100*1000);
assertTrue(timer.isRunningLocked());
assertEquals(28300, timer.getCurrentDurationMsLocked(220300)); // extra 100 from above??
assertEquals(28301, timer.getMaxDurationMsLocked(220301));
}
@SmallTest
public void testReset() throws Exception {
}
@SmallTest
public void testParceling() throws Exception {
final MockClocks clocks = new MockClocks();
final BatteryStatsImpl.TimeBase timeBase = new BatteryStatsImpl.TimeBase();
timeBase.init(clocks.uptimeMillis(), clocks.elapsedRealtime());
final BatteryStatsImpl.DurationTimer timer = new BatteryStatsImpl.DurationTimer(clocks,
null, BatteryStats.WAKE_TYPE_PARTIAL, null, timeBase);
// Start running on battery.
clocks.realtime = 100;
clocks.uptime = 10;
timeBase.setRunning(true, clocks.uptimeMillis()*1000, clocks.elapsedRealtime()*1000);
timer.startRunningLocked(300);
// Check that it did start running
assertEquals(400, timer.getMaxDurationMsLocked(700));
assertEquals(401, timer.getCurrentDurationMsLocked(701));
// Write summary
final Parcel summaryParcel = Parcel.obtain();
timer.writeSummaryFromParcelLocked(summaryParcel, 1500*1000);
summaryParcel.setDataPosition(0);
// Read summary
final BatteryStatsImpl.DurationTimer summary = new BatteryStatsImpl.DurationTimer(clocks,
null, BatteryStats.WAKE_TYPE_PARTIAL, null, timeBase);
summary.startRunningLocked(3100);
summary.readSummaryFromParcelLocked(summaryParcel);
// The new one shouldn't be running, and therefore 0 for current time
assertFalse(summary.isRunningLocked());
assertEquals(0, summary.getCurrentDurationMsLocked(6300));
// The new one should have the max duration that we had when we wrote it
assertEquals(1200, summary.getMaxDurationMsLocked(6301));
// Write full
final Parcel fullParcel = Parcel.obtain();
timer.writeToParcel(fullParcel, 1500*1000);
fullParcel.setDataPosition(0);
// Read full - Should be the same as the summary as far as DurationTimer is concerned.
final BatteryStatsImpl.DurationTimer full = new BatteryStatsImpl.DurationTimer(clocks,
null, BatteryStats.WAKE_TYPE_PARTIAL, null, timeBase, fullParcel);
// The new one shouldn't be running, and therefore 0 for current time
assertFalse(full.isRunningLocked());
assertEquals(0, full.getCurrentDurationMsLocked(6300));
// The new one should have the max duration that we had when we wrote it
assertEquals(1200, full.getMaxDurationMsLocked(6301));
}
}

View File

@@ -5,6 +5,7 @@ import org.junit.runners.Suite;
@RunWith(Suite.class)
@Suite.SuiteClasses({
BatteryStatsDurationTimerTest.class,
BatteryStatsSamplingTimerTest.class,
BatteryStatsServTest.class,
BatteryStatsTimeBaseTest.class,