diff --git a/core/java/com/android/internal/os/BinderCallsStats.java b/core/java/com/android/internal/os/BinderCallsStats.java index 630c72ed96f2a..a87bbf33ca9e2 100644 --- a/core/java/com/android/internal/os/BinderCallsStats.java +++ b/core/java/com/android/internal/os/BinderCallsStats.java @@ -82,6 +82,7 @@ public class BinderCallsStats implements BinderInternal.Observer { private boolean mAddDebugEntries = false; private CachedDeviceState.Readonly mDeviceState; + private CachedDeviceState.TimeInStateStopwatch mBatteryStopwatch; /** Injector for {@link BinderCallsStats}. */ public static class Injector { @@ -95,7 +96,11 @@ public class BinderCallsStats implements BinderInternal.Observer { } public void setDeviceState(@NonNull CachedDeviceState.Readonly deviceState) { + if (mBatteryStopwatch != null) { + mBatteryStopwatch.close(); + } mDeviceState = deviceState; + mBatteryStopwatch = deviceState.createTimeOnBatteryStopwatch(); } @Override @@ -320,9 +325,11 @@ public class BinderCallsStats implements BinderInternal.Observer { } // Debug entries added to help validate the data. - if (mAddDebugEntries) { + if (mAddDebugEntries && mBatteryStopwatch != null) { resultCallStats.add(createDebugEntry("start_time_millis", mStartTime)); resultCallStats.add(createDebugEntry("end_time_millis", System.currentTimeMillis())); + resultCallStats.add( + createDebugEntry("battery_time_millis", mBatteryStopwatch.getMillis())); } return resultCallStats; @@ -362,6 +369,8 @@ public class BinderCallsStats implements BinderInternal.Observer { long totalCpuTime = 0; pw.print("Start time: "); pw.println(DateFormat.format("yyyy-MM-dd HH:mm:ss", mStartTime)); + pw.print("On battery time (ms): "); + pw.println(mBatteryStopwatch != null ? mBatteryStopwatch.getMillis() : 0); pw.println("Sampling interval period: " + mPeriodicSamplingInterval); final List entries = new ArrayList<>(); @@ -521,6 +530,9 @@ public class BinderCallsStats implements BinderInternal.Observer { mUidEntries.clear(); mExceptionCounts.clear(); mStartTime = System.currentTimeMillis(); + if (mBatteryStopwatch != null) { + mBatteryStopwatch.reset(); + } } } diff --git a/core/java/com/android/internal/os/CachedDeviceState.java b/core/java/com/android/internal/os/CachedDeviceState.java index 8c90682ec2815..334cca317c300 100644 --- a/core/java/com/android/internal/os/CachedDeviceState.java +++ b/core/java/com/android/internal/os/CachedDeviceState.java @@ -16,8 +16,14 @@ package com.android.internal.os; + +import android.os.SystemClock; + +import com.android.internal.annotations.GuardedBy; import com.android.internal.annotations.VisibleForTesting; +import java.util.ArrayList; + /** * Stores the device state (e.g. charging/on battery, screen on/off) to be shared with * the System Server telemetry services. @@ -27,6 +33,9 @@ import com.android.internal.annotations.VisibleForTesting; public class CachedDeviceState { private volatile boolean mScreenInteractive; private volatile boolean mCharging; + private final Object mStopwatchesLock = new Object(); + @GuardedBy("mStopwatchLock") + private final ArrayList mOnBatteryStopwatches = new ArrayList<>(); public CachedDeviceState() { mCharging = true; @@ -44,7 +53,23 @@ public class CachedDeviceState { } public void setCharging(boolean charging) { - mCharging = charging; + if (mCharging != charging) { + mCharging = charging; + updateStopwatches(/* shouldStart= */ !charging); + } + } + + private void updateStopwatches(boolean shouldStart) { + synchronized (mStopwatchesLock) { + final int size = mOnBatteryStopwatches.size(); + for (int i = 0; i < size; i++) { + if (shouldStart) { + mOnBatteryStopwatches.get(i).start(); + } else { + mOnBatteryStopwatches.get(i).stop(); + } + } + } } public Readonly getReadonlyClient() { @@ -62,5 +87,74 @@ public class CachedDeviceState { public boolean isScreenInteractive() { return mScreenInteractive; } + + /** Creates a {@link TimeInStateStopwatch stopwatch} that tracks the time on battery. */ + public TimeInStateStopwatch createTimeOnBatteryStopwatch() { + synchronized (mStopwatchesLock) { + final TimeInStateStopwatch stopwatch = new TimeInStateStopwatch(); + mOnBatteryStopwatches.add(stopwatch); + if (!mCharging) { + stopwatch.start(); + } + return stopwatch; + } + } + } + + /** Tracks the time the device spent in a given state. */ + public class TimeInStateStopwatch implements AutoCloseable { + private final Object mLock = new Object(); + @GuardedBy("mLock") + private long mStartTimeMillis; + @GuardedBy("mLock") + private long mTotalTimeMillis; + + /** Returns the time in state since the last call to {@link TimeInStateStopwatch#reset}. */ + public long getMillis() { + synchronized (mLock) { + return mTotalTimeMillis + elapsedTime(); + } + } + + /** Resets the time in state to 0 without stopping the timer if it's started. */ + public void reset() { + synchronized (mLock) { + mTotalTimeMillis = 0; + mStartTimeMillis = isRunning() ? SystemClock.elapsedRealtime() : 0; + } + } + + private void start() { + synchronized (mLock) { + if (!isRunning()) { + mStartTimeMillis = SystemClock.elapsedRealtime(); + } + } + } + + private void stop() { + synchronized (mLock) { + if (isRunning()) { + mTotalTimeMillis += elapsedTime(); + mStartTimeMillis = 0; + } + } + } + + private long elapsedTime() { + return isRunning() ? SystemClock.elapsedRealtime() - mStartTimeMillis : 0; + } + + @VisibleForTesting + public boolean isRunning() { + return mStartTimeMillis > 0; + } + + @Override + public void close() { + synchronized (mStopwatchesLock) { + mOnBatteryStopwatches.remove(this); + } + } } } diff --git a/core/java/com/android/internal/os/LooperStats.java b/core/java/com/android/internal/os/LooperStats.java index cf2a297bb6a53..de85c1f35a583 100644 --- a/core/java/com/android/internal/os/LooperStats.java +++ b/core/java/com/android/internal/os/LooperStats.java @@ -49,6 +49,7 @@ public class LooperStats implements Looper.Observer { private final int mEntriesSizeCap; private int mSamplingInterval; private CachedDeviceState.Readonly mDeviceState; + private CachedDeviceState.TimeInStateStopwatch mBatteryStopwatch; private long mStartTime = System.currentTimeMillis(); private boolean mAddDebugEntries = false; @@ -58,7 +59,12 @@ public class LooperStats implements Looper.Observer { } public void setDeviceState(@NonNull CachedDeviceState.Readonly deviceState) { + if (mBatteryStopwatch != null) { + mBatteryStopwatch.close(); + } + mDeviceState = deviceState; + mBatteryStopwatch = deviceState.createTimeOnBatteryStopwatch(); } public void setAddDebugEntries(boolean addDebugEntries) { @@ -148,9 +154,11 @@ public class LooperStats implements Looper.Observer { maybeAddSpecialEntry(exportedEntries, mOverflowEntry); maybeAddSpecialEntry(exportedEntries, mHashCollisionEntry); // Debug entries added to help validate the data. - if (mAddDebugEntries) { + if (mAddDebugEntries && mBatteryStopwatch != null) { exportedEntries.add(createDebugEntry("start_time_millis", mStartTime)); exportedEntries.add(createDebugEntry("end_time_millis", System.currentTimeMillis())); + exportedEntries.add( + createDebugEntry("battery_time_millis", mBatteryStopwatch.getMillis())); } return exportedEntries; } @@ -168,6 +176,10 @@ public class LooperStats implements Looper.Observer { return mStartTime; } + public long getBatteryTimeMillis() { + return mBatteryStopwatch != null ? mBatteryStopwatch.getMillis() : 0; + } + private void maybeAddSpecialEntry(List exportedEntries, Entry specialEntry) { synchronized (specialEntry) { if (specialEntry.messageCount > 0 || specialEntry.exceptionCount > 0) { @@ -188,6 +200,9 @@ public class LooperStats implements Looper.Observer { mOverflowEntry.reset(); } mStartTime = System.currentTimeMillis(); + if (mBatteryStopwatch != null) { + mBatteryStopwatch.reset(); + } } public void setSamplingInterval(int samplingInterval) { diff --git a/core/tests/coretests/src/com/android/internal/os/BinderCallsStatsTest.java b/core/tests/coretests/src/com/android/internal/os/BinderCallsStatsTest.java index cd62e530add4d..02a76f8f78af1 100644 --- a/core/tests/coretests/src/com/android/internal/os/BinderCallsStatsTest.java +++ b/core/tests/coretests/src/com/android/internal/os/BinderCallsStatsTest.java @@ -388,8 +388,7 @@ public class BinderCallsStatsTest { @Test public void testNoDataCollectedBeforeInitialDeviceStateSet() { - TestBinderCallsStats bcs = new TestBinderCallsStats(); - bcs.setDeviceState(null); + TestBinderCallsStats bcs = new TestBinderCallsStats(null); bcs.setDetailedTracking(true); Binder binder = new Binder(); CallSession callSession = bcs.callStarted(binder, 1); @@ -620,7 +619,7 @@ public class BinderCallsStatsTest { TestBinderCallsStats bcs = new TestBinderCallsStats(); bcs.setAddDebugEntries(true); ArrayList callStats = bcs.getExportedCallStats(); - assertEquals(2, callStats.size()); + assertEquals(3, callStats.size()); BinderCallsStats.ExportedCallStat debugEntry1 = callStats.get(0); assertEquals("", debugEntry1.className); assertEquals("__DEBUG_start_time_millis", debugEntry1.methodName); @@ -629,6 +628,10 @@ public class BinderCallsStatsTest { assertEquals("", debugEntry2.className); assertEquals("__DEBUG_end_time_millis", debugEntry2.methodName); assertTrue(debugEntry1.maxReplySizeBytes <= debugEntry2.maxReplySizeBytes); + BinderCallsStats.ExportedCallStat debugEntry3 = callStats.get(2); + assertEquals("", debugEntry3.className); + assertEquals("__DEBUG_battery_time_millis", debugEntry3.methodName); + assertTrue(debugEntry3.maxReplySizeBytes >= 0); } class TestBinderCallsStats extends BinderCallsStats { @@ -638,6 +641,10 @@ public class BinderCallsStatsTest { public long elapsedTime = 0; TestBinderCallsStats() { + this(mDeviceState); + } + + TestBinderCallsStats(CachedDeviceState deviceState) { // Make random generator not random. super(new Injector() { public Random getRandomGenerator() { @@ -651,8 +658,10 @@ public class BinderCallsStatsTest { } }); setSamplingInterval(1); - setDeviceState(mDeviceState.getReadonlyClient()); setAddDebugEntries(false); + if (deviceState != null) { + setDeviceState(deviceState.getReadonlyClient()); + } } @Override diff --git a/core/tests/coretests/src/com/android/internal/os/LooperStatsTest.java b/core/tests/coretests/src/com/android/internal/os/LooperStatsTest.java index 31dde5c79f27c..3d7801cbb531e 100644 --- a/core/tests/coretests/src/com/android/internal/os/LooperStatsTest.java +++ b/core/tests/coretests/src/com/android/internal/os/LooperStatsTest.java @@ -273,8 +273,7 @@ public final class LooperStatsTest { @Test public void testDataNotCollectedBeforeDeviceStateSet() { - TestableLooperStats looperStats = new TestableLooperStats(1, 100); - looperStats.setDeviceState(null); + TestableLooperStats looperStats = new TestableLooperStats(1, 100, null); Object token1 = looperStats.messageDispatchStarting(); looperStats.messageDispatched(token1, mHandlerFirst.obtainMessage(1000)); @@ -439,7 +438,7 @@ public final class LooperStatsTest { looperStats.messageDispatched(token, message); List entries = looperStats.getEntries(); - assertThat(entries).hasSize(3); + assertThat(entries).hasSize(4); LooperStats.ExportedEntry debugEntry1 = entries.get(1); assertThat(debugEntry1.handlerClassName).isEqualTo(""); assertThat(debugEntry1.messageName).isEqualTo("__DEBUG_start_time_millis"); @@ -448,6 +447,10 @@ public final class LooperStatsTest { assertThat(debugEntry2.handlerClassName).isEqualTo(""); assertThat(debugEntry2.messageName).isEqualTo("__DEBUG_end_time_millis"); assertThat(debugEntry2.maxDelayMillis).isAtLeast(looperStats.getStartTimeMillis()); + LooperStats.ExportedEntry debugEntry3 = entries.get(3); + assertThat(debugEntry3.handlerClassName).isEqualTo(""); + assertThat(debugEntry3.messageName).isEqualTo("__DEBUG_battery_time_millis"); + assertThat(debugEntry3.maxDelayMillis).isAtLeast(0L); } private static void assertThrows(Class exceptionClass, Runnable r) { @@ -468,10 +471,16 @@ public final class LooperStatsTest { private int mSamplingInterval; TestableLooperStats(int samplingInterval, int sizeCap) { + this(samplingInterval, sizeCap, mDeviceState); + } + + TestableLooperStats(int samplingInterval, int sizeCap, CachedDeviceState deviceState) { super(samplingInterval, sizeCap); - this.mSamplingInterval = samplingInterval; - this.setDeviceState(mDeviceState.getReadonlyClient()); - this.setAddDebugEntries(false); + mSamplingInterval = samplingInterval; + setAddDebugEntries(false); + if (deviceState != null) { + setDeviceState(deviceState.getReadonlyClient()); + } } void tickRealtime(long micros) { diff --git a/services/core/java/com/android/server/LooperStatsService.java b/services/core/java/com/android/server/LooperStatsService.java index c563ad224da68..fa3babad639d6 100644 --- a/services/core/java/com/android/server/LooperStatsService.java +++ b/services/core/java/com/android/server/LooperStatsService.java @@ -94,6 +94,8 @@ public class LooperStatsService extends Binder { if (!DumpUtils.checkDumpPermission(mContext, TAG, pw)) return; pw.print("Start time: "); pw.println(DateFormat.format("yyyy-MM-dd HH:mm:ss", mStats.getStartTimeMillis())); + pw.print("On battery time (ms): "); + pw.println(mStats.getBatteryTimeMillis()); final List entries = mStats.getEntries(); entries.sort(Comparator .comparing((LooperStats.ExportedEntry entry) -> entry.workSourceUid) diff --git a/services/tests/servicestests/src/com/android/server/CachedDeviceStateServiceTest.java b/services/tests/servicestests/src/com/android/server/CachedDeviceStateServiceTest.java index 81107cf2ef4fc..2a78b6f6ca241 100644 --- a/services/tests/servicestests/src/com/android/server/CachedDeviceStateServiceTest.java +++ b/services/tests/servicestests/src/com/android/server/CachedDeviceStateServiceTest.java @@ -17,9 +17,10 @@ package com.android.server; -import static org.mockito.Mockito.when; import static com.google.common.truth.Truth.assertThat; +import static org.mockito.Mockito.when; + import android.content.Context; import android.content.Intent; import android.os.BatteryManager; @@ -134,4 +135,44 @@ public class CachedDeviceStateServiceTest { mContext.sendBroadcast(intentUnplugged); assertThat(deviceState.isCharging()).isFalse(); } + + @Test + public void correctlyTracksTimeOnBattery() throws Exception { + CachedDeviceStateService service = new CachedDeviceStateService(mContext); + when(mBatteryManager.getPlugType()).thenReturn(OsProtoEnums.BATTERY_PLUGGED_NONE); + + service.onStart(); + CachedDeviceState.Readonly deviceState = + LocalServices.getService(CachedDeviceState.Readonly.class); + + CachedDeviceState.TimeInStateStopwatch stopwatch = + deviceState.createTimeOnBatteryStopwatch(); + + // State can be initialized correctly only after PHASE_SYSTEM_SERVICES_READY. + assertThat(stopwatch.isRunning()).isFalse(); + service.onBootPhase(SystemService.PHASE_SYSTEM_SERVICES_READY); + + assertThat(stopwatch.isRunning()).isTrue(); + stopwatch.reset(); + + Thread.sleep(100); + assertThat(stopwatch.isRunning()).isTrue(); + assertThat(stopwatch.getMillis()).isAtLeast(100L); + + long timeOnBatteryBeforePluggedIn = stopwatch.getMillis(); + Intent intentPluggedIn = new Intent(Intent.ACTION_BATTERY_CHANGED); + intentPluggedIn.putExtra(BatteryManager.EXTRA_PLUGGED, OsProtoEnums.BATTERY_PLUGGED_AC); + mContext.sendBroadcast(intentPluggedIn); + + assertThat(stopwatch.getMillis()).isAtLeast(timeOnBatteryBeforePluggedIn); + assertThat(stopwatch.isRunning()).isFalse(); + + long timeOnBatteryAfterPluggedIn = stopwatch.getMillis(); + Thread.sleep(20); + assertThat(stopwatch.getMillis()).isEqualTo(timeOnBatteryAfterPluggedIn); + + stopwatch.reset(); + assertThat(stopwatch.getMillis()).isEqualTo(0L); + assertThat(stopwatch.isRunning()).isFalse(); + } }