Fix issue #15681802: Missing RESET:TIME in complete battery histories

But wait, there's more!

- Keep track of sync durations in the aggregated stats.
- Add events for users that are running and in the foreground.
- Rework the activity manager's tracking of stuff using
  battery in the background to be based on proc stats, which
  allows it to be better about determing when it should reset
  its tracking of background work.
- Also add tracking of scheduled job execution, like we are
  doing for syncs.
- And once I started hooking battery stats in to
  JobSchedulerService, I found a few things I couldn't stop myself
  from changing: (1) make it very explicit that it doesn't start
  scheduling jobs until we have reached the point in system boot
  where third party apps are allowed to run, and (2) adjust
  the various for loops to not use iterators.

Change-Id: I69d812e27bcfee9e58a614f0f6b1c7545d7530b1
This commit is contained in:
Dianne Hackborn
2014-07-11 16:03:36 -07:00
parent 213bb2fd4d
commit fdb1956ff7
11 changed files with 557 additions and 115 deletions

View File

@@ -119,6 +119,16 @@ public abstract class BatteryStats implements Parcelable {
*/
public static final int PROCESS_STATE = 12;
/**
* A constant indicating a sync timer
*/
public static final int SYNC = 13;
/**
* A constant indicating a job timer
*/
public static final int JOB = 14;
/**
* Include all of the data in the stats, including previously saved data.
*/
@@ -157,6 +167,8 @@ public abstract class BatteryStats implements Parcelable {
private static final String FOREGROUND_DATA = "fg";
private static final String STATE_TIME_DATA = "st";
private static final String WAKELOCK_DATA = "wl";
private static final String SYNC_DATA = "sy";
private static final String JOB_DATA = "jb";
private static final String KERNEL_WAKELOCK_DATA = "kwl";
private static final String WAKEUP_REASON_DATA = "wr";
private static final String NETWORK_DATA = "nt";
@@ -272,6 +284,20 @@ public abstract class BatteryStats implements Parcelable {
*/
public abstract Map<String, ? extends Wakelock> getWakelockStats();
/**
* Returns a mapping containing sync statistics.
*
* @return a Map from Strings to Timer objects.
*/
public abstract Map<String, ? extends Timer> getSyncStats();
/**
* Returns a mapping containing scheduled job statistics.
*
* @return a Map from Strings to Timer objects.
*/
public abstract Map<String, ? extends Timer> getJobStats();
/**
* The statistics associated with a particular wake lock.
*/
@@ -660,13 +686,19 @@ public abstract class BatteryStats implements Parcelable {
public static final int EVENT_FOREGROUND = 0x0002;
// Event is about an application package that is at the top of the screen.
public static final int EVENT_TOP = 0x0003;
// Event is about an application package that is at the top of the screen.
// Event is about active sync operations.
public static final int EVENT_SYNC = 0x0004;
// Events for all additional wake locks aquired/release within a wake block.
// These are not generated by default.
public static final int EVENT_WAKE_LOCK = 0x0005;
// Event is about an application executing a scheduled job.
public static final int EVENT_JOB = 0x0006;
// Events for users running.
public static final int EVENT_USER_RUNNING = 0x0007;
// Events for foreground user.
public static final int EVENT_USER_FOREGROUND = 0x0008;
// Number of event types.
public static final int EVENT_COUNT = 0x0006;
public static final int EVENT_COUNT = 0x0009;
// Mask to extract out only the type part of the event.
public static final int EVENT_TYPE_MASK = ~(EVENT_FLAG_START|EVENT_FLAG_FINISH);
@@ -680,6 +712,14 @@ public abstract class BatteryStats implements Parcelable {
public static final int EVENT_SYNC_FINISH = EVENT_SYNC | EVENT_FLAG_FINISH;
public static final int EVENT_WAKE_LOCK_START = EVENT_WAKE_LOCK | EVENT_FLAG_START;
public static final int EVENT_WAKE_LOCK_FINISH = EVENT_WAKE_LOCK | EVENT_FLAG_FINISH;
public static final int EVENT_JOB_START = EVENT_JOB | EVENT_FLAG_START;
public static final int EVENT_JOB_FINISH = EVENT_JOB | EVENT_FLAG_FINISH;
public static final int EVENT_USER_RUNNING_START = EVENT_USER_RUNNING | EVENT_FLAG_START;
public static final int EVENT_USER_RUNNING_FINISH = EVENT_USER_RUNNING | EVENT_FLAG_FINISH;
public static final int EVENT_USER_FOREGROUND_START =
EVENT_USER_FOREGROUND | EVENT_FLAG_START;
public static final int EVENT_USER_FOREGROUND_FINISH =
EVENT_USER_FOREGROUND | EVENT_FLAG_FINISH;
// For CMD_EVENT.
public int eventCode;
@@ -1269,11 +1309,11 @@ public abstract class BatteryStats implements Parcelable {
};
public static final String[] HISTORY_EVENT_NAMES = new String[] {
"null", "proc", "fg", "top", "sync", "wake_lock_in"
"null", "proc", "fg", "top", "sync", "wake_lock_in", "job", "user", "userfg"
};
public static final String[] HISTORY_EVENT_CHECKIN_NAMES = new String[] {
"Enl", "Epr", "Efg", "Etp", "Esy", "Ewl"
"Enl", "Epr", "Efg", "Etp", "Esy", "Ewl", "Ejb", "Eur", "Euf"
};
/**
@@ -2080,10 +2120,9 @@ public abstract class BatteryStats implements Parcelable {
}
}
Map<String, ? extends BatteryStats.Uid.Wakelock> wakelocks = u.getWakelockStats();
Map<String, ? extends Uid.Wakelock> wakelocks = u.getWakelockStats();
if (wakelocks.size() > 0) {
for (Map.Entry<String, ? extends BatteryStats.Uid.Wakelock> ent
: wakelocks.entrySet()) {
for (Map.Entry<String, ? extends Uid.Wakelock> ent : wakelocks.entrySet()) {
Uid.Wakelock wl = ent.getValue();
String linePrefix = "";
sb.setLength(0);
@@ -2105,6 +2144,32 @@ public abstract class BatteryStats implements Parcelable {
}
}
Map<String, ? extends Timer> syncs = u.getSyncStats();
if (syncs.size() > 0) {
for (Map.Entry<String, ? extends Timer> ent : syncs.entrySet()) {
Timer timer = ent.getValue();
// Convert from microseconds to milliseconds with rounding
long totalTime = (timer.getTotalTimeLocked(rawRealtime, which) + 500) / 1000;
int count = timer.getCountLocked(which);
if (totalTime != 0) {
dumpLine(pw, uid, category, SYNC_DATA, ent.getKey(), totalTime, count);
}
}
}
Map<String, ? extends Timer> jobs = u.getJobStats();
if (jobs.size() > 0) {
for (Map.Entry<String, ? extends Timer> ent : jobs.entrySet()) {
Timer timer = ent.getValue();
// Convert from microseconds to milliseconds with rounding
long totalTime = (timer.getTotalTimeLocked(rawRealtime, which) + 500) / 1000;
int count = timer.getCountLocked(which);
if (totalTime != 0) {
dumpLine(pw, uid, category, JOB_DATA, ent.getKey(), totalTime, count);
}
}
}
SparseArray<? extends BatteryStats.Uid.Sensor> sensors = u.getSensorStats();
int NSE = sensors.size();
for (int ise=0; ise<NSE; ise++) {
@@ -2937,8 +3002,7 @@ public abstract class BatteryStats implements Parcelable {
if (wakelocks.size() > 0) {
long totalFull = 0, totalPartial = 0, totalWindow = 0;
int count = 0;
for (Map.Entry<String, ? extends BatteryStats.Uid.Wakelock> ent
: wakelocks.entrySet()) {
for (Map.Entry<String, ? extends Uid.Wakelock> ent : wakelocks.entrySet()) {
Uid.Wakelock wl = ent.getValue();
String linePrefix = ": ";
sb.setLength(0);
@@ -2998,6 +3062,56 @@ public abstract class BatteryStats implements Parcelable {
}
}
Map<String, ? extends Timer> syncs = u.getSyncStats();
if (syncs.size() > 0) {
for (Map.Entry<String, ? extends Timer> ent : syncs.entrySet()) {
Timer timer = ent.getValue();
// Convert from microseconds to milliseconds with rounding
long totalTime = (timer.getTotalTimeLocked(rawRealtime, which) + 500) / 1000;
int count = timer.getCountLocked(which);
sb.setLength(0);
sb.append(prefix);
sb.append(" Sync ");
sb.append(ent.getKey());
sb.append(": ");
if (totalTime != 0) {
formatTimeMs(sb, totalTime);
sb.append("realtime (");
sb.append(count);
sb.append(" times)");
} else {
sb.append("(not used)");
}
pw.println(sb.toString());
uidActivity = true;
}
}
Map<String, ? extends Timer> jobs = u.getJobStats();
if (syncs.size() > 0) {
for (Map.Entry<String, ? extends Timer> ent : jobs.entrySet()) {
Timer timer = ent.getValue();
// Convert from microseconds to milliseconds with rounding
long totalTime = (timer.getTotalTimeLocked(rawRealtime, which) + 500) / 1000;
int count = timer.getCountLocked(which);
sb.setLength(0);
sb.append(prefix);
sb.append(" Job ");
sb.append(ent.getKey());
sb.append(": ");
if (totalTime != 0) {
formatTimeMs(sb, totalTime);
sb.append("realtime (");
sb.append(count);
sb.append(" times)");
} else {
sb.append("(not used)");
}
pw.println(sb.toString());
uidActivity = true;
}
}
SparseArray<? extends BatteryStats.Uid.Sensor> sensors = u.getSensorStats();
int NSE = sensors.size();
for (int ise=0; ise<NSE; ise++) {
@@ -3260,7 +3374,6 @@ public abstract class BatteryStats implements Parcelable {
int oldTemp = -1;
int oldVolt = -1;
long lastTime = -1;
long firstTime = -1;
void reset() {
oldState = oldState2 = 0;

View File

@@ -47,6 +47,10 @@ interface IBatteryStats {
void noteProcessStart(String name, int uid);
void noteProcessState(String name, int uid, int state);
void noteProcessFinish(String name, int uid);
void noteSyncStart(String name, int uid);
void noteSyncFinish(String name, int uid);
void noteJobStart(String name, int uid);
void noteJobFinish(String name, int uid);
void noteStartWakelock(int uid, int pid, String name, String historyName,
int type, boolean unimportantForLogging);

View File

@@ -91,7 +91,7 @@ public final class BatteryStatsImpl extends BatteryStats {
private static final int MAGIC = 0xBA757475; // 'BATSTATS'
// Current on-disk Parcel version
private static final int VERSION = 109 + (USE_OLD_HISTORY ? 1000 : 0);
private static final int VERSION = 112 + (USE_OLD_HISTORY ? 1000 : 0);
// Maximum number of items we will record in the history.
private static final int MAX_HISTORY_ITEMS = 2000;
@@ -2109,6 +2109,11 @@ public final class BatteryStatsImpl extends BatteryStats {
return;
}
if (dataSize == 0) {
// The history is currently empty; we need it to start with a time stamp.
cur.currentTime = System.currentTimeMillis();
addHistoryBufferLocked(elapsedRealtimeMs, uptimeMs, HistoryItem.CMD_RESET, cur);
}
addHistoryBufferLocked(elapsedRealtimeMs, uptimeMs, HistoryItem.CMD_UPDATE, cur);
}
@@ -2362,6 +2367,50 @@ public final class BatteryStatsImpl extends BatteryStats {
elapsedRealtime);
}
public void noteSyncStartLocked(String name, int uid) {
uid = mapUid(uid);
final long elapsedRealtime = SystemClock.elapsedRealtime();
final long uptime = SystemClock.uptimeMillis();
getUidStatsLocked(uid).noteStartSyncLocked(name, elapsedRealtime);
if (!mActiveEvents.updateState(HistoryItem.EVENT_SYNC_START, name, uid, 0)) {
return;
}
addHistoryEventLocked(elapsedRealtime, uptime, HistoryItem.EVENT_SYNC_START, name, uid);
}
public void noteSyncFinishLocked(String name, int uid) {
uid = mapUid(uid);
final long elapsedRealtime = SystemClock.elapsedRealtime();
final long uptime = SystemClock.uptimeMillis();
getUidStatsLocked(uid).noteStopSyncLocked(name, elapsedRealtime);
if (!mActiveEvents.updateState(HistoryItem.EVENT_SYNC_FINISH, name, uid, 0)) {
return;
}
addHistoryEventLocked(elapsedRealtime, uptime, HistoryItem.EVENT_SYNC_FINISH, name, uid);
}
public void noteJobStartLocked(String name, int uid) {
uid = mapUid(uid);
final long elapsedRealtime = SystemClock.elapsedRealtime();
final long uptime = SystemClock.uptimeMillis();
getUidStatsLocked(uid).noteStartJobLocked(name, elapsedRealtime);
if (!mActiveEvents.updateState(HistoryItem.EVENT_JOB_START, name, uid, 0)) {
return;
}
addHistoryEventLocked(elapsedRealtime, uptime, HistoryItem.EVENT_JOB_START, name, uid);
}
public void noteJobFinishLocked(String name, int uid) {
uid = mapUid(uid);
final long elapsedRealtime = SystemClock.elapsedRealtime();
final long uptime = SystemClock.uptimeMillis();
getUidStatsLocked(uid).noteStopJobLocked(name, elapsedRealtime);
if (!mActiveEvents.updateState(HistoryItem.EVENT_JOB_FINISH, name, uid, 0)) {
return;
}
addHistoryEventLocked(elapsedRealtime, uptime, HistoryItem.EVENT_JOB_FINISH, name, uid);
}
private void requestWakelockCpuUpdate() {
if (!mHandler.hasMessages(MSG_UPDATE_WAKELOCKS)) {
Message m = mHandler.obtainMessage(MSG_UPDATE_WAKELOCKS);
@@ -3832,6 +3881,16 @@ public final class BatteryStatsImpl extends BatteryStats {
*/
final ArrayMap<String, Wakelock> mWakelockStats = new ArrayMap<String, Wakelock>();
/**
* The statistics we have collected for this uid's syncs.
*/
final ArrayMap<String, StopwatchTimer> mSyncStats = new ArrayMap<String, StopwatchTimer>();
/**
* The statistics we have collected for this uid's jobs.
*/
final ArrayMap<String, StopwatchTimer> mJobStats = new ArrayMap<String, StopwatchTimer>();
/**
* The statistics we have collected for this uid's sensor activations.
*/
@@ -3871,6 +3930,16 @@ public final class BatteryStatsImpl extends BatteryStats {
return mWakelockStats;
}
@Override
public Map<String, ? extends BatteryStats.Timer> getSyncStats() {
return mSyncStats;
}
@Override
public Map<String, ? extends BatteryStats.Timer> getJobStats() {
return mJobStats;
}
@Override
public SparseArray<? extends BatteryStats.Uid.Sensor> getSensorStats() {
return mSensorStats;
@@ -4396,6 +4465,24 @@ public final class BatteryStatsImpl extends BatteryStats {
active = true;
}
}
for (int is=mSyncStats.size()-1; is>=0; is--) {
StopwatchTimer timer = mSyncStats.valueAt(is);
if (timer.reset(false)) {
mSyncStats.removeAt(is);
timer.detach();
} else {
active = true;
}
}
for (int ij=mJobStats.size()-1; ij>=0; ij--) {
StopwatchTimer timer = mJobStats.valueAt(ij);
if (timer.reset(false)) {
mJobStats.removeAt(ij);
timer.detach();
} else {
active = true;
}
}
for (int ise=mSensorStats.size()-1; ise>=0; ise--) {
Sensor s = mSensorStats.valueAt(ise);
if (s.reset()) {
@@ -4497,6 +4584,22 @@ public final class BatteryStatsImpl extends BatteryStats {
wakelock.writeToParcelLocked(out, elapsedRealtimeUs);
}
int NS = mSyncStats.size();
out.writeInt(NS);
for (int is=0; is<NS; is++) {
out.writeString(mSyncStats.keyAt(is));
StopwatchTimer timer = mSyncStats.valueAt(is);
Timer.writeTimerToParcel(out, timer, elapsedRealtimeUs);
}
int NJ = mJobStats.size();
out.writeInt(NJ);
for (int ij=0; ij<NJ; ij++) {
out.writeString(mJobStats.keyAt(ij));
StopwatchTimer timer = mJobStats.valueAt(ij);
Timer.writeTimerToParcel(out, timer, elapsedRealtimeUs);
}
int NSE = mSensorStats.size();
out.writeInt(NSE);
for (int ise=0; ise<NSE; ise++) {
@@ -4618,6 +4721,25 @@ public final class BatteryStatsImpl extends BatteryStats {
mWakelockStats.put(wakelockName, wakelock);
}
int numSyncs = in.readInt();
mSyncStats.clear();
for (int j = 0; j < numSyncs; j++) {
String syncName = in.readString();
if (in.readInt() != 0) {
mSyncStats.put(syncName,
new StopwatchTimer(Uid.this, SYNC, null, timeBase, in));
}
}
int numJobs = in.readInt();
mJobStats.clear();
for (int j = 0; j < numJobs; j++) {
String jobName = in.readString();
if (in.readInt() != 0) {
mJobStats.put(jobName, new StopwatchTimer(Uid.this, JOB, null, timeBase, in));
}
}
int numSensors = in.readInt();
mSensorStats.clear();
for (int k = 0; k < numSensors; k++) {
@@ -5670,6 +5792,38 @@ public final class BatteryStatsImpl extends BatteryStats {
return ss;
}
public StopwatchTimer getSyncTimerLocked(String name) {
StopwatchTimer t = mSyncStats.get(name);
if (t == null) {
final int N = mSyncStats.size();
if (N > MAX_WAKELOCKS_PER_UID) {
name = BATCHED_WAKELOCK_NAME;
t = mSyncStats.get(name);
}
if (t == null) {
t = new StopwatchTimer(Uid.this, SYNC, null, mOnBatteryTimeBase);
mSyncStats.put(name, t);
}
}
return t;
}
public StopwatchTimer getJobTimerLocked(String name) {
StopwatchTimer t = mJobStats.get(name);
if (t == null) {
final int N = mJobStats.size();
if (N > MAX_WAKELOCKS_PER_UID) {
name = BATCHED_WAKELOCK_NAME;
t = mJobStats.get(name);
}
if (t == null) {
t = new StopwatchTimer(Uid.this, JOB, null, mOnBatteryTimeBase);
mJobStats.put(name, t);
}
}
return t;
}
public StopwatchTimer getWakeTimerLocked(String name, int type) {
Wakelock wl = mWakelockStats.get(name);
if (wl == null) {
@@ -5737,6 +5891,34 @@ public final class BatteryStatsImpl extends BatteryStats {
return t;
}
public void noteStartSyncLocked(String name, long elapsedRealtimeMs) {
StopwatchTimer t = getSyncTimerLocked(name);
if (t != null) {
t.startRunningLocked(elapsedRealtimeMs);
}
}
public void noteStopSyncLocked(String name, long elapsedRealtimeMs) {
StopwatchTimer t = getSyncTimerLocked(name);
if (t != null) {
t.stopRunningLocked(elapsedRealtimeMs);
}
}
public void noteStartJobLocked(String name, long elapsedRealtimeMs) {
StopwatchTimer t = getJobTimerLocked(name);
if (t != null) {
t.startRunningLocked(elapsedRealtimeMs);
}
}
public void noteStopJobLocked(String name, long elapsedRealtimeMs) {
StopwatchTimer t = getJobTimerLocked(name);
if (t != null) {
t.stopRunningLocked(elapsedRealtimeMs);
}
}
public void noteStartWakeLocked(int pid, String name, int type, long elapsedRealtimeMs) {
StopwatchTimer t = getWakeTimerLocked(name, type);
if (t != null) {
@@ -7170,7 +7352,7 @@ public final class BatteryStatsImpl extends BatteryStats {
// the last run until samples in this run.
if (mHistoryBaseTime > 0) {
long oldnow = SystemClock.elapsedRealtime();
mHistoryBaseTime = (mHistoryBaseTime - oldnow) + 60*1000;
mHistoryBaseTime = mHistoryBaseTime - oldnow + 1;
if (DEBUG_HISTORY) {
StringBuilder sb = new StringBuilder(128);
sb.append("****************** ADJUSTED mHistoryBaseTime: ");
@@ -7433,6 +7615,26 @@ public final class BatteryStatsImpl extends BatteryStats {
}
}
int NS = in.readInt();
if (NS > 100) {
Slog.w(TAG, "File corrupt: too many syncs " + NS);
return;
}
for (int is = 0; is < NS; is++) {
String name = in.readString();
u.getSyncTimerLocked(name).readSummaryFromParcelLocked(in);
}
int NJ = in.readInt();
if (NJ > 100) {
Slog.w(TAG, "File corrupt: too many job timers " + NJ);
return;
}
for (int ij = 0; ij < NJ; ij++) {
String name = in.readString();
u.getJobTimerLocked(name).readSummaryFromParcelLocked(in);
}
int NP = in.readInt();
if (NP > 1000) {
Slog.w(TAG, "File corrupt: too many sensors " + NP);
@@ -7484,7 +7686,7 @@ public final class BatteryStatsImpl extends BatteryStats {
String pkgName = in.readString();
Uid.Pkg p = u.getPackageStatsLocked(pkgName);
p.mWakeups = p.mLoadedWakeups = in.readInt();
final int NS = in.readInt();
NS = in.readInt();
if (NS > 1000) {
Slog.w(TAG, "File corrupt: too many services " + NS);
return;
@@ -7717,6 +7919,20 @@ public final class BatteryStatsImpl extends BatteryStats {
}
}
int NS = u.mSyncStats.size();
out.writeInt(NS);
for (int is=0; is<NS; is++) {
out.writeString(u.mSyncStats.keyAt(is));
u.mSyncStats.valueAt(is).writeSummaryFromParcelLocked(out, NOWREAL_SYS);
}
int NJ = u.mJobStats.size();
out.writeInt(NJ);
for (int ij=0; ij<NJ; ij++) {
out.writeString(u.mJobStats.keyAt(ij));
u.mJobStats.valueAt(ij).writeSummaryFromParcelLocked(out, NOWREAL_SYS);
}
int NSE = u.mSensorStats.size();
out.writeInt(NSE);
for (int ise=0; ise<NSE; ise++) {
@@ -7760,7 +7976,7 @@ public final class BatteryStatsImpl extends BatteryStats {
out.writeString(ent.getKey());
Uid.Pkg ps = ent.getValue();
out.writeInt(ps.mWakeups);
final int NS = ps.mServiceStats.size();
NS = ps.mServiceStats.size();
out.writeInt(NS);
if (NS > 0) {
for (Map.Entry<String, BatteryStatsImpl.Uid.Pkg.Serv> sent
@@ -7786,7 +8002,7 @@ public final class BatteryStatsImpl extends BatteryStats {
void readFromParcelLocked(Parcel in) {
int magic = in.readInt();
if (magic != MAGIC) {
throw new ParcelFormatException("Bad magic number");
throw new ParcelFormatException("Bad magic number: #" + Integer.toHexString(magic));
}
readHistory(in, false);