Android/frameworks_base
1
0
Fork 0
Code Issues Pull Requests Actions Packages Projects Releases Wiki Activity

Merge "Add on battery time to Binder/Looper stats"

Browse Source
This commit is contained in:
Marcin Oczeretko
2018-12-05 13:06:29 +00:00
committed by Android (Google) Code Review
parent 9f7fcda6c4 6a2e5241a8
commit 0ff4f92f65
7 changed files with 196 additions and 14 deletions
Download Patch File Download Diff File Expand all files Collapse all files

14
core/java/com/android/internal/os/BinderCallsStats.java
View File

@@ -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<UidEntry> 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();
}
}
}

96
core/java/com/android/internal/os/CachedDeviceState.java
View File

@@ -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<TimeInStateStopwatch> 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);
}
}
}
}

17
core/java/com/android/internal/os/LooperStats.java
View File

@@ -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<ExportedEntry> 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) {

17
core/tests/coretests/src/com/android/internal/os/BinderCallsStatsTest.java
View File

@@ -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<BinderCallsStats.ExportedCallStat> 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

21
core/tests/coretests/src/com/android/internal/os/LooperStatsTest.java
View File

@@ -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<LooperStats.ExportedEntry> 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<? extends Exception> 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) {

2
services/core/java/com/android/server/LooperStatsService.java
View File

@@ -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<LooperStats.ExportedEntry> entries = mStats.getEntries();
entries.sort(Comparator
.comparing((LooperStats.ExportedEntry entry) -> entry.workSourceUid)

43
services/tests/servicestests/src/com/android/server/CachedDeviceStateServiceTest.java
View File

@@ -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();
}
}