Merge "Fix battery history corruption"

This commit is contained in:
Dmitri Plotnikov
2023-01-26 00:12:05 +00:00
committed by Android (Google) Code Review
6 changed files with 139 additions and 87 deletions

View File

@@ -115,9 +115,11 @@ public class BatteryStatsHistory {
static final int STATE_BATTERY_HEALTH_SHIFT = 26;
static final int STATE_BATTERY_PLUG_MASK = 0x00000003;
static final int STATE_BATTERY_PLUG_SHIFT = 24;
// We use the low bit of the battery state int to indicate that we have full details
// from a battery level change.
static final int BATTERY_DELTA_LEVEL_FLAG = 0x00000001;
static final int BATTERY_LEVEL_DETAILS_FLAG = 0x00000001;
// Flag in history tag index: indicates that this is the first occurrence of this tag,
// therefore the tag value is written in the parcel
static final int TAG_FIRST_OCCURRENCE_FLAG = 0x8000;
@@ -1385,8 +1387,17 @@ public class BatteryStatsHistory {
if (dataSize == 0) {
// The history is currently empty; we need it to start with a time stamp.
cur.currentTime = mClock.currentTimeMillis();
writeHistoryItem(elapsedRealtimeMs, uptimeMs, cur, HistoryItem.CMD_RESET);
HistoryItem copy = new HistoryItem();
copy.setTo(cur);
copy.currentTime = mClock.currentTimeMillis();
copy.wakelockTag = null;
copy.wakeReasonTag = null;
copy.eventCode = HistoryItem.EVENT_NONE;
copy.eventTag = null;
copy.tagsFirstOccurrence = false;
copy.energyConsumerDetails = null;
copy.cpuUsageDetails = null;
writeHistoryItem(elapsedRealtimeMs, uptimeMs, copy, HistoryItem.CMD_RESET);
}
writeHistoryItem(elapsedRealtimeMs, uptimeMs, cur, HistoryItem.CMD_UPDATE);
}
@@ -1516,10 +1527,19 @@ public class BatteryStatsHistory {
deltaTimeToken = (int) deltaTime;
}
int firstToken = deltaTimeToken | (cur.states & BatteryStatsHistory.DELTA_STATE_MASK);
final int includeStepDetails = mLastHistoryStepLevel > cur.batteryLevel
? BatteryStatsHistory.BATTERY_DELTA_LEVEL_FLAG : 0;
mLastHistoryStepLevel = cur.batteryLevel;
final int batteryLevelInt = buildBatteryLevelInt(cur) | includeStepDetails;
int batteryLevelInt = buildBatteryLevelInt(cur);
if (cur.batteryLevel < mLastHistoryStepLevel || mLastHistoryStepLevel == 0) {
cur.stepDetails = mStepDetailsCalculator.getHistoryStepDetails();
if (cur.stepDetails != null) {
batteryLevelInt |= BatteryStatsHistory.BATTERY_LEVEL_DETAILS_FLAG;
mLastHistoryStepLevel = cur.batteryLevel;
}
} else {
cur.stepDetails = null;
mLastHistoryStepLevel = cur.batteryLevel;
}
final boolean batteryLevelIntChanged = batteryLevelInt != lastBatteryLevelInt;
if (batteryLevelIntChanged) {
firstToken |= BatteryStatsHistory.DELTA_BATTERY_LEVEL_FLAG;
@@ -1652,8 +1672,7 @@ public class BatteryStatsHistory {
}
}
cur.stepDetails = mStepDetailsCalculator.getHistoryStepDetails();
if (includeStepDetails != 0) {
if (cur.stepDetails != null) {
cur.stepDetails.writeToParcel(dest);
}

View File

@@ -215,7 +215,7 @@ public class BatteryStatsHistoryIterator implements Iterator<BatteryStats.Histor
cur.eventCode = BatteryStats.HistoryItem.EVENT_NONE;
}
if ((batteryLevelInt & BatteryStatsHistory.BATTERY_DELTA_LEVEL_FLAG) != 0) {
if ((batteryLevelInt & BatteryStatsHistory.BATTERY_LEVEL_DETAILS_FLAG) != 0) {
cur.stepDetails = mReadHistoryStepDetails;
cur.stepDetails.readFromParcel(src);
} else {

View File

@@ -3926,8 +3926,6 @@ public class BatteryStatsImpl extends BatteryStats {
private boolean mHasHistoryStepDetails;
private int mLastHistoryStepLevel;
/**
* Total time (in milliseconds) spent executing in user code.
*/
@@ -3956,11 +3954,6 @@ public class BatteryStatsImpl extends BatteryStats {
@Override
public HistoryStepDetails getHistoryStepDetails() {
if (mBatteryLevel >= mLastHistoryStepLevel && mHasHistoryStepDetails) {
mLastHistoryStepLevel = mBatteryLevel;
return null;
}
// Perform a CPU update right after we do this collection, so we have started
// collecting good data for the next step.
requestImmediateCpuUpdate();
@@ -3989,7 +3982,7 @@ public class BatteryStatsImpl extends BatteryStats {
mLastStepStatIrqTimeMs = mCurStepStatIrqTimeMs;
mLastStepStatSoftIrqTimeMs = mCurStepStatSoftIrqTimeMs;
mLastStepStatIdleTimeMs = mCurStepStatIdleTimeMs;
mDetails.clear();
return null;
} else {
if (DEBUG) {
Slog.d(TAG, "Step stats last: user=" + mLastStepCpuUserTimeMs + " sys="
@@ -4058,12 +4051,8 @@ public class BatteryStatsImpl extends BatteryStats {
mLastStepStatIrqTimeMs = mCurStepStatIrqTimeMs;
mLastStepStatSoftIrqTimeMs = mCurStepStatSoftIrqTimeMs;
mLastStepStatIdleTimeMs = mCurStepStatIdleTimeMs;
return mDetails;
}
mHasHistoryStepDetails = mBatteryLevel <= mLastHistoryStepLevel;
mLastHistoryStepLevel = mBatteryLevel;
return mDetails;
}
public void addCpuStats(int totalUTimeMs, int totalSTimeMs, int statUserTimeMs,
@@ -4083,6 +4072,7 @@ public class BatteryStatsImpl extends BatteryStats {
mCurStepStatIrqTimeMs += statIrqTimeMs;
mCurStepStatSoftIrqTimeMs += statSoftIrqTimeMs;
mCurStepStatIdleTimeMs += statIdleTimeMs;
mHasHistoryStepDetails = true;
}
@Override

View File

@@ -33,21 +33,27 @@ import org.junit.runner.RunWith;
import java.io.File;
import java.util.Random;
import java.util.concurrent.Future;
@RunWith(AndroidJUnit4.class)
@SmallTest
@SuppressWarnings("GuardedBy")
public class BatteryStatsHistoryIteratorTest {
private static final int APP_UID = Process.FIRST_APPLICATION_UID + 42;
private MockClock mMockClock = new MockClock();
private MockBatteryStatsImpl mBatteryStats;
private Random mRandom = new Random();
private MockExternalStatsSync mExternalStatsSync = new MockExternalStatsSync();
@Before
public void setup() {
final File historyDir =
createTemporaryDirectory(getClass().getSimpleName());
final File historyDir = createTemporaryDirectory(getClass().getSimpleName());
mBatteryStats = new MockBatteryStatsImpl(mMockClock, historyDir);
mBatteryStats.setDummyExternalStatsSync(mExternalStatsSync);
mBatteryStats.setRecordAllHistoryLocked(true);
mBatteryStats.forceRecordAllHistory();
mBatteryStats.setNoAutoReset(true);
}
/**
@@ -65,42 +71,24 @@ public class BatteryStatsHistoryIteratorTest {
@Test
public void testIterator() {
synchronized (mBatteryStats) {
mBatteryStats.setRecordAllHistoryLocked(true);
}
mBatteryStats.forceRecordAllHistory();
mMockClock.realtime = 1000;
mMockClock.uptime = 1000;
mBatteryStats.setNoAutoReset(true);
synchronized (mBatteryStats) {
mBatteryStats.setBatteryStateLocked(BatteryManager.BATTERY_STATUS_DISCHARGING,
100, /* plugType */ 0, 90, 72, 3700, 3_600_000, 4_000_000, 0, 1_000_000,
1_000_000, 1_000_000);
}
synchronized (mBatteryStats) {
mBatteryStats.setBatteryStateLocked(BatteryManager.BATTERY_STATUS_DISCHARGING,
100, /* plugType */ 0, 80, 72, 3700, 2_400_000, 4_000_000, 0, 2_000_000,
2_000_000, 2_000_000);
}
mBatteryStats.setBatteryStateLocked(BatteryManager.BATTERY_STATUS_DISCHARGING,
100, /* plugType */ 0, 90, 72, 3700, 3_600_000, 4_000_000, 0, 1_000_000,
1_000_000, 1_000_000);
mBatteryStats.setBatteryStateLocked(BatteryManager.BATTERY_STATUS_DISCHARGING,
100, /* plugType */ 0, 80, 72, 3700, 2_400_000, 4_000_000, 0, 2_000_000,
2_000_000, 2_000_000);
mBatteryStats.noteAlarmStartLocked("foo", null, APP_UID, 3_000_000, 2_000_000);
mBatteryStats.noteAlarmFinishLocked("foo", null, APP_UID, 3_001_000, 2_001_000);
synchronized (mBatteryStats) {
mBatteryStats.noteAlarmStartLocked("foo", null, APP_UID, 3_000_000, 2_000_000);
}
synchronized (mBatteryStats) {
mBatteryStats.noteAlarmFinishLocked("foo", null, APP_UID, 3_001_000, 2_001_000);
}
final BatteryStatsHistoryIterator iterator =
mBatteryStats.iterateBatteryStatsHistory();
final BatteryStatsHistoryIterator iterator = mBatteryStats.iterateBatteryStatsHistory();
BatteryStats.HistoryItem item;
assertThat(item = iterator.next()).isNotNull();
assertHistoryItem(item,
BatteryStats.HistoryItem.CMD_RESET, BatteryStats.HistoryItem.EVENT_NONE,
null, 0, 3_600_000, 90, 1_000_000);
assertThat(item.cmd).isEqualTo(BatteryStats.HistoryItem.CMD_RESET);
assertThat(item = iterator.next()).isNotNull();
assertHistoryItem(item,
@@ -112,11 +100,6 @@ public class BatteryStatsHistoryIteratorTest {
BatteryStats.HistoryItem.CMD_UPDATE, BatteryStats.HistoryItem.EVENT_NONE,
null, 0, 2_400_000, 80, 2_000_000);
assertThat(item = iterator.next()).isNotNull();
assertHistoryItem(item,
BatteryStats.HistoryItem.CMD_UPDATE, BatteryStats.HistoryItem.EVENT_NONE,
null, 0, 2_400_000, 80, 2_000_000);
assertThat(item = iterator.next()).isNotNull();
assertHistoryItem(item,
BatteryStats.HistoryItem.CMD_UPDATE,
@@ -136,35 +119,20 @@ public class BatteryStatsHistoryIteratorTest {
// Test history that spans multiple buffers and uses more than 32k different strings.
@Test
public void tagsLongHistory() {
synchronized (mBatteryStats) {
mBatteryStats.setRecordAllHistoryLocked(true);
}
mBatteryStats.forceRecordAllHistory();
mBatteryStats.setBatteryStateLocked(BatteryManager.BATTERY_STATUS_DISCHARGING,
100, /* plugType */ 0, 90, 72, 3700, 3_600_000, 4_000_000, 0, 1_000_000,
1_000_000, 1_000_000);
mMockClock.realtime = 1000;
mMockClock.uptime = 1000;
mBatteryStats.setNoAutoReset(true);
synchronized (mBatteryStats) {
mBatteryStats.setBatteryStateLocked(BatteryManager.BATTERY_STATUS_DISCHARGING,
100, /* plugType */ 0, 90, 72, 3700, 3_600_000, 4_000_000, 0, 1_000_000,
1_000_000, 1_000_000);
}
// More than 32k strings
final int eventCount = 0x7FFF + 100;
for (int i = 0; i < eventCount; i++) {
// Names repeat in order to verify de-duping of identical history tags.
String name = "a" + (i % 10);
synchronized (mBatteryStats) {
mBatteryStats.noteAlarmStartLocked(name, null, APP_UID, 3_000_000, 2_000_000);
}
synchronized (mBatteryStats) {
mBatteryStats.noteAlarmFinishLocked(name, null, APP_UID, 3_500_000, 2_500_000);
}
mBatteryStats.noteAlarmStartLocked(name, null, APP_UID, 3_000_000, 2_000_000);
mBatteryStats.noteAlarmFinishLocked(name, null, APP_UID, 3_500_000, 2_500_000);
}
final BatteryStatsHistoryIterator iterator =
mBatteryStats.iterateBatteryStatsHistory();
final BatteryStatsHistoryIterator iterator = mBatteryStats.iterateBatteryStatsHistory();
BatteryStats.HistoryItem item;
assertThat(item = iterator.next()).isNotNull();
@@ -210,6 +178,69 @@ public class BatteryStatsHistoryIteratorTest {
assertThat(iterator.next()).isNull();
}
@Test
public void cpuSuspendHistoryEvents() {
mBatteryStats.setBatteryStateLocked(BatteryManager.BATTERY_STATUS_DISCHARGING,
100, /* plugType */ 0, 90, 72, 3700, 3_600_000, 4_000_000, 0,
1_000_000, 1_000_000, 1_000_000);
assertThat(mExternalStatsSync.mSyncScheduled).isTrue();
mBatteryStats.finishAddingCpuLocked(100, 0, 0, 0, 0, 0, 0, 0);
mExternalStatsSync.mSyncScheduled = false;
// Device was suspended for 3_000 seconds, note the difference in elapsed time and uptime
mBatteryStats.setBatteryStateLocked(BatteryManager.BATTERY_STATUS_DISCHARGING,
100, /* plugType */ 0, 80, 72, 3700, 2_400_000, 4_000_000, 0,
5_000_000, 2_000_000, 5_000_000);
assertThat(mExternalStatsSync.mSyncScheduled).isTrue();
mBatteryStats.finishAddingCpuLocked(200, 0, 0, 0, 0, 0, 0, 0);
mExternalStatsSync.mSyncScheduled = false;
// Battery level is unchanged, so we don't write battery level details in history
mBatteryStats.noteAlarmStartLocked("wakeup", null, APP_UID, 6_000_000, 3_000_000);
assertThat(mExternalStatsSync.mSyncScheduled).isFalse();
// Battery level drops, so we write the accumulated battery level details
mBatteryStats.setBatteryStateLocked(BatteryManager.BATTERY_STATUS_DISCHARGING,
100, /* plugType */ 0, 79, 72, 3700, 2_000_000, 4_000_000, 0,
7_000_000, 4_000_000, 6_000_000);
final BatteryStatsHistoryIterator iterator = mBatteryStats.iterateBatteryStatsHistory();
BatteryStats.HistoryItem item;
assertThat(item = iterator.next()).isNotNull();
assertThat(item.cmd).isEqualTo((int) BatteryStats.HistoryItem.CMD_RESET);
assertThat(item.stepDetails).isNull();
assertThat(item = iterator.next()).isNotNull();
assertThat(item.batteryLevel).isEqualTo(90);
assertThat(item.stepDetails).isNull();
assertThat(item = iterator.next()).isNotNull();
assertThat(item.batteryLevel).isEqualTo(90);
assertThat(item.states & BatteryStats.HistoryItem.STATE_CPU_RUNNING_FLAG).isEqualTo(0);
assertThat(item.stepDetails.userTime).isEqualTo(100);
assertThat(item = iterator.next()).isNotNull();
assertThat(item.batteryLevel).isEqualTo(80);
assertThat(item.states & BatteryStats.HistoryItem.STATE_CPU_RUNNING_FLAG).isNotEqualTo(0);
assertThat(item.stepDetails.userTime).isEqualTo(0);
assertThat(item = iterator.next()).isNotNull();
assertThat(item.batteryLevel).isEqualTo(80);
assertThat(item.eventCode).isEqualTo(BatteryStats.HistoryItem.EVENT_ALARM_START);
assertThat(item.stepDetails).isNull();
assertThat(item = iterator.next()).isNotNull();
assertThat(item.batteryLevel).isEqualTo(79);
assertThat(item.states & BatteryStats.HistoryItem.STATE_CPU_RUNNING_FLAG).isNotEqualTo(0);
assertThat(item.stepDetails.userTime).isEqualTo(200);
assertThat(item = iterator.next()).isNull();
}
private void assertHistoryItem(BatteryStats.HistoryItem item, int command, int eventCode,
String tag, int uid, int batteryChargeUah, int batteryLevel,
long elapsedTimeMs) {
@@ -226,4 +257,14 @@ public class BatteryStatsHistoryIteratorTest {
assertThat(item.time).isEqualTo(elapsedTimeMs);
}
private static class MockExternalStatsSync extends MockBatteryStatsImpl.DummyExternalStatsSync {
private boolean mSyncScheduled;
@Override
public Future<?> scheduleCpuSyncDueToWakelockChange(long delayMillis) {
mSyncScheduled = true;
return null;
}
}
}

View File

@@ -936,16 +936,15 @@ public class BatteryStatsNoteTest extends TestCase {
BatteryStatsHistoryIterator iterator = bi.iterateBatteryStatsHistory();
HistoryItem item;
assertThat(item = iterator.next()).isNotNull();
assertEquals(HistoryItem.CMD_RESET, item.cmd);
assertEquals(HistoryItem.EVENT_NONE, item.eventCode);
assertThat(item = iterator.next()).isNotNull();
assertEquals(HistoryItem.EVENT_ALARM_START, item.eventCode);
assertEquals("foo", item.eventTag.string);
assertEquals(UID, item.eventTag.uid);
// TODO(narayan): Figure out why this event is written to the history buffer. See
// test below where it is being interspersed between multiple START events too.
assertThat(item = iterator.next()).isNotNull();
assertEquals(HistoryItem.EVENT_NONE, item.eventCode);
assertThat(item = iterator.next()).isNotNull();
assertEquals(HistoryItem.EVENT_ALARM_FINISH, item.eventCode);
assertTrue(item.isDeltaData());
@@ -976,14 +975,15 @@ public class BatteryStatsNoteTest extends TestCase {
BatteryStatsHistoryIterator iterator = bi.iterateBatteryStatsHistory();
HistoryItem item;
assertThat(item = iterator.next()).isNotNull();
assertEquals(HistoryItem.CMD_RESET, item.cmd);
assertEquals(HistoryItem.EVENT_NONE, item.eventCode);
assertThat(item = iterator.next()).isNotNull();
assertEquals(HistoryItem.EVENT_ALARM_START, item.eventCode);
assertEquals("foo", item.eventTag.string);
assertEquals(100, item.eventTag.uid);
assertThat(item = iterator.next()).isNotNull();
assertEquals(HistoryItem.EVENT_NONE, item.eventCode);
assertThat(item = iterator.next()).isNotNull();
assertEquals(HistoryItem.EVENT_ALARM_START, item.eventCode);
assertEquals("foo", item.eventTag.string);

View File

@@ -230,11 +230,13 @@ public class BatteryUsageStatsProviderTest {
assertHistoryItem(item,
BatteryStats.HistoryItem.CMD_UPDATE, BatteryStats.HistoryItem.EVENT_NONE,
null, 0, 3_600_000, 90, 1_000_000);
assertThat(item.states & BatteryStats.HistoryItem.STATE_CPU_RUNNING_FLAG).isNotEqualTo(0);
assertThat(item = iterator.next()).isNotNull();
assertHistoryItem(item,
BatteryStats.HistoryItem.CMD_UPDATE, BatteryStats.HistoryItem.EVENT_NONE,
null, 0, 3_600_000, 90, 2_000_000);
assertThat(item.states & BatteryStats.HistoryItem.STATE_CPU_RUNNING_FLAG).isEqualTo(0);
assertThat(item = iterator.next()).isNotNull();
assertHistoryItem(item,