Donate to e Foundation | Murena handsets with /e/OS | Own a part of Murena! Learn more

Commit 63a5ffd3 authored by Dmitri Plotnikov's avatar Dmitri Plotnikov
Browse files

Fix battery history parceling concurrency

Bug: 235609126
Test: atest  --rerun-until-failure 20   FrameworksCoreTests:BatteryUsageStatsProviderTest
Test: atest  --rerun-until-failure 20   FrameworksCoreTests:BatteryStatsHistoryIteratorTest
Change-Id: If20e019baa6105f7e50e9bcb8f3d6e34e7247976
parent eebee7a2
Loading
Loading
Loading
Loading
+6 −0
Original line number Diff line number Diff line
@@ -31,6 +31,7 @@ import com.android.internal.util.ParseUtils;

import java.io.File;
import java.io.FilenameFilter;
import java.io.IOException;
import java.util.ArrayList;
import java.util.Collections;
import java.util.List;
@@ -207,6 +208,11 @@ public class BatteryStatsHistory {
        final int next = mFileNumbers.get(mFileNumbers.size() - 1) + 1;
        mFileNumbers.add(next);
        setActiveFile(next);
        try {
            mActiveFile.getBaseFile().createNewFile();
        } catch (IOException e) {
            Slog.e(TAG, "Could not create history file: " + mActiveFile.getBaseFile());
        }

        // if free disk space is less than 100MB, delete oldest history file.
        if (!hasFreeDiskSpace()) {
+37 −37
Original line number Diff line number Diff line
@@ -4485,7 +4485,7 @@ public class BatteryStatsImpl extends BatteryStats {
        if (dataSize >= mConstants.MAX_HISTORY_BUFFER) {
            //open a new history file.
            final long start = SystemClock.uptimeMillis();
            writeHistoryLocked(true);
            writeHistoryLocked();
            if (DEBUG) {
                Slog.d(TAG, "addHistoryBufferLocked writeHistoryLocked takes ms:"
                        + (SystemClock.uptimeMillis() - start));
@@ -16905,22 +16905,27 @@ public class BatteryStatsImpl extends BatteryStats {
        iPw.decreaseIndent();
    }
    final ReentrantLock mWriteLock = new ReentrantLock();
    private final Runnable mWriteAsyncRunnable = () -> {
        synchronized (BatteryStatsImpl.this) {
            writeSyncLocked();
        }
    };
    @GuardedBy("this")
    public void writeAsyncLocked() {
        writeStatsLocked(false);
        writeHistoryLocked(false);
        BackgroundThread.getHandler().removeCallbacks(mWriteAsyncRunnable);
        BackgroundThread.getHandler().post(mWriteAsyncRunnable);
    }
    @GuardedBy("this")
    public void writeSyncLocked() {
        writeStatsLocked(true);
        writeHistoryLocked(true);
        BackgroundThread.getHandler().removeCallbacks(mWriteAsyncRunnable);
        writeStatsLocked();
        writeHistoryLocked();
    }
    @GuardedBy("this")
    void writeStatsLocked(boolean sync) {
    private void writeStatsLocked() {
        if (mStatsFile == null) {
            Slog.w(TAG,
                    "writeStatsLocked: no file associated with this instance");
@@ -16932,6 +16937,7 @@ public class BatteryStatsImpl extends BatteryStats {
        }
        final Parcel p = Parcel.obtain();
        try {
            final long start = SystemClock.uptimeMillis();
            writeSummaryToParcel(p, false/*history is in separate file*/);
            if (DEBUG) {
@@ -16939,13 +16945,15 @@ public class BatteryStatsImpl extends BatteryStats {
                        + (SystemClock.uptimeMillis() - start) + " bytes:" + p.dataSize());
            }
            mLastWriteTimeMs = mClock.elapsedRealtime();
        writeParcelToFileLocked(p, mStatsFile, sync);
            writeParcelToFileLocked(p, mStatsFile);
        } finally {
            p.recycle();
        }
    }
    void writeHistoryLocked(boolean sync) {
    private void writeHistoryLocked() {
        if (mBatteryStatsHistory.getActiveFile() == null) {
            Slog.w(TAG,
                    "writeHistoryLocked: no history file associated with this instance");
            Slog.w(TAG, "writeHistoryLocked: no history file associated with this instance");
            return;
        }
@@ -16954,28 +16962,21 @@ public class BatteryStatsImpl extends BatteryStats {
        }
        Parcel p = Parcel.obtain();
        try {
            final long start = SystemClock.uptimeMillis();
            writeHistoryBuffer(p, true);
            if (DEBUG) {
                Slog.d(TAG, "writeHistoryBuffer duration ms:"
                        + (SystemClock.uptimeMillis() - start) + " bytes:" + p.dataSize());
            }
        writeParcelToFileLocked(p, mBatteryStatsHistory.getActiveFile(), sync);
    }
    void writeParcelToFileLocked(Parcel p, AtomicFile file, boolean sync) {
        if (sync) {
            commitPendingDataToDisk(p, file);
        } else {
            BackgroundThread.getHandler().post(new Runnable() {
                @Override public void run() {
                    commitPendingDataToDisk(p, file);
                }
            });
            writeParcelToFileLocked(p, mBatteryStatsHistory.getActiveFile());
        } finally {
            p.recycle();
        }
    }
    private void commitPendingDataToDisk(Parcel p, AtomicFile file) {
    private final ReentrantLock mWriteLock = new ReentrantLock();
    private void writeParcelToFileLocked(Parcel p, AtomicFile file) {
        mWriteLock.lock();
        FileOutputStream fos = null;
        try {
@@ -16995,7 +16996,6 @@ public class BatteryStatsImpl extends BatteryStats {
            Slog.w(TAG, "Error writing battery statistics", e);
            file.failWrite(fos);
        } finally {
            p.recycle();
            mWriteLock.unlock();
        }
    }
+33 −17
Original line number Diff line number Diff line
@@ -35,7 +35,6 @@ import java.io.File;

@RunWith(AndroidJUnit4.class)
@SmallTest
@SuppressWarnings("GuardedBy")
public class BatteryStatsHistoryIteratorTest {
    private static final int APP_UID = Process.FIRST_APPLICATION_UID + 42;

@@ -51,22 +50,32 @@ public class BatteryStatsHistoryIteratorTest {

    @Test
    public void testIterator() {
        synchronized (mBatteryStats) {
            mBatteryStats.setRecordAllHistoryLocked(true);
        }
        mBatteryStats.forceRecordAllHistory();

        mMockClock.realtime = 1000;
        mMockClock.uptime = 1000;
        mBatteryStats.setNoAutoReset(true);

        mBatteryStats.setBatteryStateLocked(BatteryManager.BATTERY_STATUS_DISCHARGING, 100,
                /* plugType */ 0, 90, 72, 3700, 3_600_000, 4_000_000, 0, 1_000_000,
        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);
        mBatteryStats.setBatteryStateLocked(BatteryManager.BATTERY_STATUS_DISCHARGING, 100,
                /* plugType */ 0, 80, 72, 3700, 2_400_000, 4_000_000, 0, 2_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);
        }

        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.createBatteryStatsHistoryIterator();
@@ -111,25 +120,32 @@ 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();

        mMockClock.realtime = 1000;
        mMockClock.uptime = 1000;
        mBatteryStats.setNoAutoReset(true);

        mBatteryStats.setBatteryStateLocked(BatteryManager.BATTERY_STATUS_DISCHARGING, 100,
                /* plugType */ 0, 90, 72, 3700, 3_600_000, 4_000_000, 0, 1_000_000,
        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);
            }
        }

        final BatteryStatsHistoryIterator iterator =
                mBatteryStats.createBatteryStatsHistoryIterator();
+132 −68
Original line number Diff line number Diff line
@@ -50,7 +50,6 @@ import java.util.List;

@SmallTest
@RunWith(AndroidJUnit4.class)
@SuppressWarnings("GuardedBy")
public class BatteryUsageStatsProviderTest {
    private static final int APP_UID = Process.FIRST_APPLICATION_UID + 42;
    private static final long MINUTE_IN_MS = 60 * 1000;
@@ -121,28 +120,53 @@ public class BatteryUsageStatsProviderTest {
    private BatteryStatsImpl prepareBatteryStats() {
        BatteryStatsImpl batteryStats = mStatsRule.getBatteryStats();

        synchronized (batteryStats) {
            batteryStats.noteActivityResumedLocked(APP_UID,
                    10 * MINUTE_IN_MS, 10 * MINUTE_IN_MS);
        batteryStats.noteUidProcessStateLocked(APP_UID, ActivityManager.PROCESS_STATE_TOP,
        }
        synchronized (batteryStats) {
            batteryStats.noteUidProcessStateLocked(APP_UID,
                    ActivityManager.PROCESS_STATE_TOP,
                    10 * MINUTE_IN_MS, 10 * MINUTE_IN_MS);
        }
        synchronized (batteryStats) {
            batteryStats.noteActivityPausedLocked(APP_UID,
                    30 * MINUTE_IN_MS, 30 * MINUTE_IN_MS);
        batteryStats.noteUidProcessStateLocked(APP_UID, ActivityManager.PROCESS_STATE_SERVICE,
        }
        synchronized (batteryStats) {
            batteryStats.noteUidProcessStateLocked(APP_UID,
                    ActivityManager.PROCESS_STATE_SERVICE,
                    30 * MINUTE_IN_MS, 30 * MINUTE_IN_MS);
        }
        synchronized (batteryStats) {
            batteryStats.noteUidProcessStateLocked(APP_UID,
                    ActivityManager.PROCESS_STATE_FOREGROUND_SERVICE,
                    40 * MINUTE_IN_MS, 40 * MINUTE_IN_MS);
        }
        synchronized (batteryStats) {
            batteryStats.noteUidProcessStateLocked(APP_UID,
                    ActivityManager.PROCESS_STATE_BOUND_FOREGROUND_SERVICE,
                    50 * MINUTE_IN_MS, 50 * MINUTE_IN_MS);
        batteryStats.noteUidProcessStateLocked(APP_UID, ActivityManager.PROCESS_STATE_CACHED_EMPTY,
        }
        synchronized (batteryStats) {
            batteryStats.noteUidProcessStateLocked(APP_UID,
                    ActivityManager.PROCESS_STATE_CACHED_EMPTY,
                    80 * MINUTE_IN_MS, 80 * MINUTE_IN_MS);
        }

        synchronized (batteryStats) {
            batteryStats.noteFlashlightOnLocked(APP_UID, 1000, 1000);
        }
        synchronized (batteryStats) {
            batteryStats.noteFlashlightOffLocked(APP_UID, 5000, 5000);
        }

        synchronized (batteryStats) {
            batteryStats.noteAudioOnLocked(APP_UID, 10000, 10000);
        }
        synchronized (batteryStats) {
            batteryStats.noteAudioOffLocked(APP_UID, 20000, 20000);
        }

        mStatsRule.setCurrentTime(54321);
        return batteryStats;
@@ -151,17 +175,25 @@ public class BatteryUsageStatsProviderTest {
    @Test
    public void testWriteAndReadHistory() {
        MockBatteryStatsImpl batteryStats = mStatsRule.getBatteryStats();
        synchronized (batteryStats) {
            batteryStats.setRecordAllHistoryLocked(true);
        }
        batteryStats.forceRecordAllHistory();

        batteryStats.setNoAutoReset(true);

        batteryStats.setBatteryStateLocked(BatteryManager.BATTERY_STATUS_DISCHARGING, 100,
                /* plugType */ 0, 90, 72, 3700, 3_600_000, 4_000_000, 0, 1_000_000,
        synchronized (batteryStats) {
            batteryStats.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 (batteryStats) {
            batteryStats.noteAlarmStartLocked("foo", null, APP_UID, 3_000_000, 2_000_000);
        }
        synchronized (batteryStats) {
            batteryStats.noteAlarmFinishLocked("foo", null, APP_UID, 3_001_000, 2_001_000);
        }

        Context context = InstrumentationRegistry.getContext();
        BatteryUsageStatsProvider provider = new BatteryUsageStatsProvider(context, batteryStats);
@@ -217,16 +249,20 @@ public class BatteryUsageStatsProviderTest {
    @Test
    public void testWriteAndReadHistoryTags() {
        MockBatteryStatsImpl batteryStats = mStatsRule.getBatteryStats();
        synchronized (batteryStats) {
            batteryStats.setRecordAllHistoryLocked(true);
        }
        batteryStats.forceRecordAllHistory();

        batteryStats.setNoAutoReset(true);

        mStatsRule.setTime(1_000_000, 1_000_000);

        batteryStats.setBatteryStateLocked(BatteryManager.BATTERY_STATUS_DISCHARGING, 100,
                /* plugType */ 0, 90, 72, 3700, 3_600_000, 4_000_000, 0, 1_000_000,
        synchronized (batteryStats) {
            batteryStats.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);
        }

        // Add a large number of different history tags with strings of increasing length.
        // These long strings will overflow the history buffer, at which point
@@ -238,47 +274,52 @@ public class BatteryUsageStatsProviderTest {
            for (int j = 0; j <= i; j++) {
                sb.append("word ");
            }
            batteryStats.noteJobStartLocked(sb.toString(), i);
            final int uid = i;
            synchronized (batteryStats) {
                batteryStats.noteJobStartLocked(sb.toString(), uid);
            }
        }

        Context context = InstrumentationRegistry.getContext();
        BatteryUsageStatsProvider provider = new BatteryUsageStatsProvider(context, batteryStats);
        BatteryUsageStatsProvider
                provider = new BatteryUsageStatsProvider(context, batteryStats);

        final BatteryUsageStats batteryUsageStats =
                provider.getBatteryUsageStats(
                        new BatteryUsageStatsQuery.Builder().includeBatteryHistory().build());

        Parcel parcel = Parcel.obtain();
        batteryUsageStats.writeToParcel(parcel, 0);
        parcel.writeParcelable(batteryUsageStats, 0);

        assertThat(parcel.dataSize()).isAtMost(128_000);

        parcel.setDataPosition(0);
        BatteryUsageStats unparceled = BatteryUsageStats.CREATOR.createFromParcel(parcel);

        BatteryUsageStats unparceled = parcel.readParcelable(getClass().getClassLoader(),
                BatteryUsageStats.class);

        BatteryStatsHistoryIterator iterator = unparceled.iterateBatteryStatsHistory();
        BatteryStats.HistoryItem item = new BatteryStats.HistoryItem();

        assertThat(iterator.next(item)).isTrue();
        assertThat(item.cmd).isEqualTo((int) BatteryStats.HistoryItem.CMD_CURRENT_TIME);
        assertThat(item.cmd).isEqualTo((int) BatteryStats.HistoryItem.CMD_RESET);

        int lastUid = 0;
        int expectedUid = 1;
        while (iterator.next(item)) {
            if (item.eventCode == BatteryStats.HistoryItem.EVENT_NONE) {
                assertThat(iterator.next(item)).isTrue();
            }
            int uid = item.eventTag.uid;
            // We expect the history buffer to have been reset in the middle of the run because
            // there were many different history tags written, exceeding the limit of 128k.
            assertThat(uid).isGreaterThan(150);
            assertThat(uid).isEqualTo(expectedUid++);
            assertThat(item.eventCode).isEqualTo(
                    BatteryStats.HistoryItem.EVENT_JOB | BatteryStats.HistoryItem.EVENT_FLAG_START);
            assertThat(item.eventTag.string).startsWith(uid + " ");
            assertThat(item.batteryChargeUah).isEqualTo(3_600_000);
            assertThat(item.batteryLevel).isEqualTo(90);
            assertThat(item.time).isEqualTo((long) 1_000_000);

            lastUid = uid;
        }

        assertThat(lastUid).isEqualTo(199);
        assertThat(expectedUid).isEqualTo(200);
    }

    private void assertHistoryItem(BatteryStats.HistoryItem item, int command, int eventCode,
@@ -320,8 +361,9 @@ public class BatteryUsageStatsProviderTest {
        Context context = InstrumentationRegistry.getContext();
        BatteryStatsImpl batteryStats = mStatsRule.getBatteryStats();
        mStatsRule.setCurrentTime(5 * MINUTE_IN_MS);
        synchronized (batteryStats) {
            batteryStats.resetAllStatsCmdLocked();

        }
        BatteryUsageStatsStore batteryUsageStatsStore = new BatteryUsageStatsStore(context,
                batteryStats, new File(context.getCacheDir(), "BatteryUsageStatsProviderTest"),
                new TestHandler(), Integer.MAX_VALUE);
@@ -330,33 +372,55 @@ public class BatteryUsageStatsProviderTest {
        BatteryUsageStatsProvider provider = new BatteryUsageStatsProvider(context,
                batteryStats, batteryUsageStatsStore);

        synchronized (batteryStats) {
            batteryStats.noteFlashlightOnLocked(APP_UID,
                    10 * MINUTE_IN_MS, 10 * MINUTE_IN_MS);
        }
        synchronized (batteryStats) {
            batteryStats.noteFlashlightOffLocked(APP_UID,
                    20 * MINUTE_IN_MS, 20 * MINUTE_IN_MS);
        }
        mStatsRule.setCurrentTime(25 * MINUTE_IN_MS);
        synchronized (batteryStats) {
            batteryStats.resetAllStatsCmdLocked();
        }

        synchronized (batteryStats) {
            batteryStats.noteFlashlightOnLocked(APP_UID,
                    30 * MINUTE_IN_MS, 30 * MINUTE_IN_MS);
        }
        synchronized (batteryStats) {
            batteryStats.noteFlashlightOffLocked(APP_UID,
                    50 * MINUTE_IN_MS, 50 * MINUTE_IN_MS);
        }
        mStatsRule.setCurrentTime(55 * MINUTE_IN_MS);
        synchronized (batteryStats) {
            batteryStats.resetAllStatsCmdLocked();
        }

        // This section should be ignored because the timestamp is out or range
        synchronized (batteryStats) {
            batteryStats.noteFlashlightOnLocked(APP_UID,
                    60 * MINUTE_IN_MS, 60 * MINUTE_IN_MS);
        }
        synchronized (batteryStats) {
            batteryStats.noteFlashlightOffLocked(APP_UID,
                    70 * MINUTE_IN_MS, 70 * MINUTE_IN_MS);
        }
        mStatsRule.setCurrentTime(75 * MINUTE_IN_MS);
        synchronized (batteryStats) {
            batteryStats.resetAllStatsCmdLocked();
        }

        // This section should be ignored because it represents the current stats session
        synchronized (batteryStats) {
            batteryStats.noteFlashlightOnLocked(APP_UID,
                    80 * MINUTE_IN_MS, 80 * MINUTE_IN_MS);
        }
        synchronized (batteryStats) {
            batteryStats.noteFlashlightOffLocked(APP_UID,
                    90 * MINUTE_IN_MS, 90 * MINUTE_IN_MS);
        }
        mStatsRule.setCurrentTime(95 * MINUTE_IN_MS);

        // Include the first and the second snapshot, but not the third or current