From f3f3f517fd48295b0605c23e06a9755d608d276a Mon Sep 17 00:00:00 2001 From: Ryan Zuklie Date: Wed, 7 Sep 2022 19:15:16 -0700 Subject: [PATCH] Export BatteryStats state bitmaps to ATrace This uses logic similar to printBitDescriptions to parse the state bitmask along with the BitDescriptions to report the information as a trace counter. Due to current tracing limitations, values are not remembered outside of or between tracing. For slow moving things (like wifi enabled/disabled), we would miss the counter in most traces if using `traceCounter` alone. The Perfetto team's current solution is to read system properties when the trace starts in order to fill in the initial value. To limit the impact of this, this aspect is only enabled in userdebug. Bug: 245749764 Test: presubmit and local perfetto tracing Change-Id: Iaae4e9796a44be3ffdaee31b956bbb3e87735ead --- .../internal/os/BatteryStatsHistory.java | 81 ++++++++++++++++++- .../power/stats/BatteryStatsHistoryTest.java | 66 ++++++++++++++- 2 files changed, 142 insertions(+), 5 deletions(-) diff --git a/core/java/com/android/internal/os/BatteryStatsHistory.java b/core/java/com/android/internal/os/BatteryStatsHistory.java index 7001c69f40427..f097bf73eb761 100644 --- a/core/java/com/android/internal/os/BatteryStatsHistory.java +++ b/core/java/com/android/internal/os/BatteryStatsHistory.java @@ -16,17 +16,23 @@ package com.android.internal.os; +import android.annotation.NonNull; import android.annotation.Nullable; import android.os.BatteryManager; +import android.os.BatteryStats; +import android.os.BatteryStats.BitDescription; import android.os.BatteryStats.HistoryItem; import android.os.BatteryStats.HistoryStepDetails; import android.os.BatteryStats.HistoryTag; import android.os.BatteryStats.MeasuredEnergyDetails; +import android.os.Build; import android.os.Parcel; import android.os.ParcelFormatException; import android.os.Process; import android.os.StatFs; import android.os.SystemClock; +import android.os.SystemProperties; +import android.os.Trace; import android.util.ArraySet; import android.util.AtomicFile; import android.util.Slog; @@ -209,6 +215,42 @@ public class BatteryStatsHistory { void clear(); } + /** + * A delegate for android.os.Trace to allow testing static calls. Due to + * limitations in Android Tracing (b/153319140), the delegate also records + * counter values in system properties which allows reading the value at the + * start of a tracing session. This overhead is limited to userdebug builds. + * On user builds, tracing still occurs but the counter value will be missing + * until the first change occurs. + */ + @VisibleForTesting + public static class TraceDelegate { + // Note: certain tests currently run as platform_app which is not allowed + // to set debug system properties. To ensure that system properties are set + // only when allowed, we check the current UID. + private final boolean mShouldSetProperty = + Build.IS_USERDEBUG && (Process.myUid() == Process.SYSTEM_UID); + + /** + * Returns true if trace counters should be recorded. + */ + public boolean tracingEnabled() { + return Trace.isTagEnabled(Trace.TRACE_TAG_POWER) || mShouldSetProperty; + } + + /** + * Records the counter value with the given name. + */ + public void traceCounter(@NonNull String name, int value) { + Trace.traceCounter(Trace.TRACE_TAG_POWER, name, value); + if (mShouldSetProperty) { + SystemProperties.set("debug.tracing." + name, Integer.toString(value)); + } + } + } + + private TraceDelegate mTracer; + /** * Constructor * @@ -219,19 +261,20 @@ public class BatteryStatsHistory { public BatteryStatsHistory(File systemDir, int maxHistoryFiles, int maxHistoryBufferSize, HistoryStepDetailsCalculator stepDetailsCalculator, Clock clock) { this(Parcel.obtain(), systemDir, maxHistoryFiles, maxHistoryBufferSize, - stepDetailsCalculator, clock); + stepDetailsCalculator, clock, new TraceDelegate()); initHistoryBuffer(); } @VisibleForTesting public BatteryStatsHistory(Parcel historyBuffer, File systemDir, int maxHistoryFiles, int maxHistoryBufferSize, - HistoryStepDetailsCalculator stepDetailsCalculator, Clock clock) { + HistoryStepDetailsCalculator stepDetailsCalculator, Clock clock, TraceDelegate tracer) { mHistoryBuffer = historyBuffer; mSystemDir = systemDir; mMaxHistoryFiles = maxHistoryFiles; mMaxHistoryBufferSize = maxHistoryBufferSize; mStepDetailsCalculator = stepDetailsCalculator; + mTracer = tracer; mClock = clock; mHistoryDir = new File(systemDir, HISTORY_DIR); @@ -272,6 +315,7 @@ public class BatteryStatsHistory { public BatteryStatsHistory(HistoryStepDetailsCalculator stepDetailsCalculator, Clock clock) { mStepDetailsCalculator = stepDetailsCalculator; + mTracer = new TraceDelegate(); mClock = clock; mHistoryBuffer = Parcel.obtain(); @@ -287,6 +331,7 @@ public class BatteryStatsHistory { private BatteryStatsHistory(Parcel historyBuffer, HistoryStepDetailsCalculator stepDetailsCalculator, Clock clock) { mHistoryBuffer = historyBuffer; + mTracer = new TraceDelegate(); mClock = clock; mSystemDir = null; mHistoryDir = null; @@ -338,7 +383,7 @@ public class BatteryStatsHistory { // Make a copy of battery history to avoid concurrent modification. Parcel historyBuffer = Parcel.obtain(); historyBuffer.appendFrom(mHistoryBuffer, 0, mHistoryBuffer.dataSize()); - return new BatteryStatsHistory(historyBuffer, mSystemDir, 0, 0, null, null); + return new BatteryStatsHistory(historyBuffer, mSystemDir, 0, 0, null, null, mTracer); } /** @@ -1119,6 +1164,30 @@ public class BatteryStatsHistory { writeHistoryItem(elapsedRealtimeMs, uptimeMs); } + /** + * Writes changes to a HistoryItem state bitmap to Atrace. + */ + private void recordTraceCounters(int oldval, int newval, BitDescription[] descriptions) { + if (!mTracer.tracingEnabled()) return; + + int diff = oldval ^ newval; + if (diff == 0) return; + + for (int i = 0; i < descriptions.length; i++) { + BitDescription bd = descriptions[i]; + if ((diff & bd.mask) == 0) continue; + + int value; + if (bd.shift < 0) { + value = (newval & bd.mask) != 0 ? 1 : 0; + } else { + value = (newval & bd.mask) >> bd.shift; + } + + mTracer.traceCounter("battery_stats." + bd.name, value); + } + } + /** * Writes the current history item to history. */ @@ -1159,6 +1228,12 @@ public class BatteryStatsHistory { + Integer.toHexString(diffStates2) + " lastDiff2=" + Integer.toHexString(lastDiffStates2)); } + + recordTraceCounters(mHistoryLastWritten.states, + cur.states & mActiveHistoryStates, BatteryStats.HISTORY_STATE_DESCRIPTIONS); + recordTraceCounters(mHistoryLastWritten.states2, + cur.states2 & mActiveHistoryStates2, BatteryStats.HISTORY_STATE2_DESCRIPTIONS); + if (mHistoryBufferLastPos >= 0 && mHistoryLastWritten.cmd == HistoryItem.CMD_UPDATE && timeDiffMs < 1000 && (diffStates & lastDiffStates) == 0 && (diffStates2 & lastDiffStates2) == 0 diff --git a/services/tests/servicestests/src/com/android/server/power/stats/BatteryStatsHistoryTest.java b/services/tests/servicestests/src/com/android/server/power/stats/BatteryStatsHistoryTest.java index 047fcd6ed108a..d5b923a81e4ab 100644 --- a/services/tests/servicestests/src/com/android/server/power/stats/BatteryStatsHistoryTest.java +++ b/services/tests/servicestests/src/com/android/server/power/stats/BatteryStatsHistoryTest.java @@ -26,6 +26,7 @@ import static org.mockito.Mockito.when; import android.content.Context; import android.os.BatteryManager; import android.os.BatteryStats; +import android.os.BatteryStats.HistoryItem; import android.os.BatteryStats.MeasuredEnergyDetails; import android.os.Parcel; import android.util.Log; @@ -40,7 +41,9 @@ import com.android.internal.os.Clock; import org.junit.Before; import org.junit.Test; import org.junit.runner.RunWith; +import org.mockito.InOrder; import org.mockito.Mock; +import org.mockito.Mockito; import org.mockito.MockitoAnnotations; import java.io.File; @@ -63,6 +66,8 @@ public class BatteryStatsHistoryTest { private final Clock mClock = new MockClock(); private BatteryStatsHistory mHistory; @Mock + private BatteryStatsHistory.TraceDelegate mTracer; + @Mock private BatteryStatsHistory.HistoryStepDetailsCalculator mStepDetailsCalculator; @Before @@ -79,12 +84,69 @@ public class BatteryStatsHistoryTest { } mHistoryDir.delete(); mHistory = new BatteryStatsHistory(mHistoryBuffer, mSystemDir, 32, 1024, - mStepDetailsCalculator, mClock); + mStepDetailsCalculator, mClock, mTracer); when(mStepDetailsCalculator.getHistoryStepDetails()) .thenReturn(new BatteryStats.HistoryStepDetails()); } + @Test + public void testAtraceBinaryState1() { + mHistory.forceRecordAllHistory(); + + InOrder inOrder = Mockito.inOrder(mTracer); + Mockito.when(mTracer.tracingEnabled()).thenReturn(true); + + mHistory.recordStateStartEvent(mClock.elapsedRealtime(), + mClock.uptimeMillis(), HistoryItem.STATE_MOBILE_RADIO_ACTIVE_FLAG); + mHistory.recordStateStopEvent(mClock.elapsedRealtime(), + mClock.uptimeMillis(), HistoryItem.STATE_MOBILE_RADIO_ACTIVE_FLAG); + mHistory.recordStateStartEvent(mClock.elapsedRealtime(), + mClock.uptimeMillis(), HistoryItem.STATE_MOBILE_RADIO_ACTIVE_FLAG); + + inOrder.verify(mTracer).traceCounter("battery_stats.mobile_radio", 1); + inOrder.verify(mTracer).traceCounter("battery_stats.mobile_radio", 0); + inOrder.verify(mTracer).traceCounter("battery_stats.mobile_radio", 1); + } + + @Test + public void testAtraceBinaryState2() { + mHistory.forceRecordAllHistory(); + + InOrder inOrder = Mockito.inOrder(mTracer); + Mockito.when(mTracer.tracingEnabled()).thenReturn(true); + + mHistory.recordState2StartEvent(mClock.elapsedRealtime(), + mClock.uptimeMillis(), HistoryItem.STATE2_WIFI_ON_FLAG); + mHistory.recordState2StopEvent(mClock.elapsedRealtime(), + mClock.uptimeMillis(), HistoryItem.STATE2_WIFI_ON_FLAG); + mHistory.recordState2StartEvent(mClock.elapsedRealtime(), + mClock.uptimeMillis(), HistoryItem.STATE2_WIFI_ON_FLAG); + + inOrder.verify(mTracer).traceCounter("battery_stats.wifi", 1); + inOrder.verify(mTracer).traceCounter("battery_stats.wifi", 0); + inOrder.verify(mTracer).traceCounter("battery_stats.wifi", 1); + } + + @Test + public void testAtraceNumericalState() { + mHistory.forceRecordAllHistory(); + + InOrder inOrder = Mockito.inOrder(mTracer); + Mockito.when(mTracer.tracingEnabled()).thenReturn(true); + + mHistory.recordDataConnectionTypeChangeEvent(mClock.elapsedRealtime(), + mClock.uptimeMillis(), 1); + mHistory.recordDataConnectionTypeChangeEvent(mClock.elapsedRealtime(), + mClock.uptimeMillis(), 2); + mHistory.recordDataConnectionTypeChangeEvent(mClock.elapsedRealtime(), + mClock.uptimeMillis(), 3); + + inOrder.verify(mTracer).traceCounter("battery_stats.data_conn", 1); + inOrder.verify(mTracer).traceCounter("battery_stats.data_conn", 2); + inOrder.verify(mTracer).traceCounter("battery_stats.data_conn", 3); + } + @Test public void testConstruct() { createActiveFile(mHistory); @@ -131,7 +193,7 @@ public class BatteryStatsHistoryTest { // create a new BatteryStatsHistory object, it will pick up existing history files. BatteryStatsHistory history2 = new BatteryStatsHistory(mHistoryBuffer, mSystemDir, 32, 1024, - null, mClock); + null, mClock, mTracer); // verify constructor can pick up all files from file system. verifyFileNumbers(history2, fileList); verifyActiveFile(history2, "33.bin");