Merge "Log kernel wakeup attribution details to stats log" (d8b8823e) · Commits · e / os / android_frameworks_base

services/core/java/com/android/server/am/BatteryStatsService.java

+1 −1

Original line number	Diff line number	Diff line
		@@ -380,7 +380,7 @@ public final class BatteryStatsService extends IBatteryStats.Stub
		}
		mBatteryUsageStatsProvider = new BatteryUsageStatsProvider(context, mStats,
		mBatteryUsageStatsStore);
		mCpuWakeupStats = new CpuWakeupStats(context, R.xml.irq_device_map);
		mCpuWakeupStats = new CpuWakeupStats(context, R.xml.irq_device_map, mHandler);
		}

		public void publish() {

services/core/java/com/android/server/power/stats/CpuWakeupStats.java

+59 −1

Original line number	Diff line number	Diff line
		@@ -20,8 +20,10 @@ import static android.os.BatteryStatsInternal.CPU_WAKEUP_SUBSYSTEM_ALARM;
		import static android.os.BatteryStatsInternal.CPU_WAKEUP_SUBSYSTEM_UNKNOWN;

		import android.content.Context;
		import android.os.Handler;
		import android.os.UserHandle;
		import android.util.IndentingPrintWriter;
		import android.util.IntArray;
		import android.util.LongSparseArray;
		import android.util.Slog;
		import android.util.SparseArray;
		@@ -32,6 +34,7 @@ import android.util.TimeUtils;

		import com.android.internal.annotations.VisibleForTesting;
		import com.android.internal.util.ArrayUtils;
		import com.android.internal.util.FrameworkStatsLog;
		import com.android.internal.util.IntPair;

		import java.util.Arrays;
		@@ -43,12 +46,16 @@ import java.util.regex.Pattern;
		* Stores stats about CPU wakeups and tries to attribute them to subsystems and uids.
		*/
		public class CpuWakeupStats {
		private static final String TAG = "CpuWakeupStats";

		private static final String SUBSYSTEM_ALARM_STRING = "Alarm";
		@VisibleForTesting
		static final long WAKEUP_RETENTION_MS = 3 * 24 * 60 * 60_000; // 3 days.
		@VisibleForTesting
		static final long WAKEUP_REASON_HALF_WINDOW_MS = 500;
		private static final long WAKEUP_WRITE_DELAY_MS = 2 * 60 * 1000; // 2 minutes.

		private final Handler mHandler;
		private final IrqDeviceMap mIrqDeviceMap;
		private final WakingActivityHistory mRecentWakingActivity = new WakingActivityHistory();

		@@ -58,8 +65,58 @@ public class CpuWakeupStats {
		final TimeSparseArray<SparseArray<SparseBooleanArray>> mWakeupAttribution =
		new TimeSparseArray<>();

		public CpuWakeupStats(Context context, int mapRes) {
		public CpuWakeupStats(Context context, int mapRes, Handler handler) {
		mIrqDeviceMap = IrqDeviceMap.getInstance(context, mapRes);
		mHandler = handler;
		}

		private static int subsystemToStatsReason(int subsystem) {
		switch (subsystem) {
		case CPU_WAKEUP_SUBSYSTEM_ALARM:
		return FrameworkStatsLog.KERNEL_WAKEUP_ATTRIBUTED__REASON__ALARM;
		}
		return FrameworkStatsLog.KERNEL_WAKEUP_ATTRIBUTED__REASON__UNKNOWN;
		}

		private synchronized void logWakeupToStatsLog(Wakeup wakeupToLog) {
		if (ArrayUtils.isEmpty(wakeupToLog.mDevices)) {
		FrameworkStatsLog.write(FrameworkStatsLog.KERNEL_WAKEUP_ATTRIBUTED,
		FrameworkStatsLog.KERNEL_WAKEUP_ATTRIBUTED__TYPE__TYPE_UNKNOWN,
		FrameworkStatsLog.KERNEL_WAKEUP_ATTRIBUTED__REASON__UNKNOWN,
		null,
		wakeupToLog.mElapsedMillis);
		return;
		}

		final SparseArray<SparseBooleanArray> wakeupAttribution = mWakeupAttribution.get(
		wakeupToLog.mElapsedMillis);
		if (wakeupAttribution == null) {
		// This is not expected but can theoretically happen in extreme situations, e.g. if we
		// remove the wakeup before the handler gets to process this message.
		Slog.wtf(TAG, "Unexpected null attribution found for " + wakeupToLog);
		return;
		}
		for (int i = 0; i < wakeupAttribution.size(); i++) {
		final int subsystem = wakeupAttribution.keyAt(i);
		final SparseBooleanArray uidMap = wakeupAttribution.valueAt(i);
		final int[] uids;
		if (uidMap == null \|\| uidMap.size() == 0) {
		uids = new int[0];
		} else {
		final IntArray tmp = new IntArray(uidMap.size());
		for (int j = 0; j < uidMap.size(); j++) {
		if (uidMap.valueAt(j)) {
		tmp.add(uidMap.keyAt(j));
		}
		}
		uids = tmp.toArray();
		}
		FrameworkStatsLog.write(FrameworkStatsLog.KERNEL_WAKEUP_ATTRIBUTED,
		FrameworkStatsLog.KERNEL_WAKEUP_ATTRIBUTED__TYPE__TYPE_IRQ,
		subsystemToStatsReason(subsystem),
		uids,
		wakeupToLog.mElapsedMillis);
		}
		}

		/** Notes a wakeup reason as reported by SuspendControlService to battery stats. */
		@@ -83,6 +140,7 @@ public class CpuWakeupStats {
		for (int i = lastIdx; i >= 0; i--) {
		mWakeupAttribution.removeAt(i);
		}
		mHandler.postDelayed(() -> logWakeupToStatsLog(parsedWakeup), WAKEUP_WRITE_DELAY_MS);
		}

		/** Notes a waking activity that could have potentially woken up the CPU. */

services/tests/servicestests/src/com/android/server/power/stats/CpuWakeupStatsTest.java

+9 −6

Original line number	Diff line number	Diff line
		@@ -25,6 +25,7 @@ import static com.android.server.power.stats.CpuWakeupStats.WAKEUP_RETENTION_MS;
		import static com.google.common.truth.Truth.assertThat;

		import android.content.Context;
		import android.os.Handler;
		import android.util.SparseArray;
		import android.util.SparseBooleanArray;

		@@ -35,6 +36,7 @@ import com.android.frameworks.servicestests.R;

		import org.junit.Test;
		import org.junit.runner.RunWith;
		import org.mockito.Mockito;

		import java.util.HashSet;
		import java.util.Set;
		@@ -55,12 +57,13 @@ public class CpuWakeupStatsTest {
		private static final int TEST_UID_5 = 76421423;

		private static final Context sContext = InstrumentationRegistry.getTargetContext();
		private final Handler mHandler = Mockito.mock(Handler.class);
		private final ThreadLocalRandom mRandom = ThreadLocalRandom.current();

		@Test
		public void removesOldWakeups() {
		// The xml resource doesn't matter for this test.
		final CpuWakeupStats obj = new CpuWakeupStats(sContext, R.xml.irq_device_map_1);
		final CpuWakeupStats obj = new CpuWakeupStats(sContext, R.xml.irq_device_map_1, mHandler);

		final Set<Long> timestamps = new HashSet<>();
		final long firstWakeup = 453192;
		@@ -88,7 +91,7 @@ public class CpuWakeupStatsTest {

		@Test
		public void alarmIrqAttributionSolo() {
		final CpuWakeupStats obj = new CpuWakeupStats(sContext, R.xml.irq_device_map_3);
		final CpuWakeupStats obj = new CpuWakeupStats(sContext, R.xml.irq_device_map_3, mHandler);
		final long wakeupTime = 12423121;

		obj.noteWakeupTimeAndReason(wakeupTime, 1, KERNEL_REASON_ALARM_IRQ);
		@@ -113,7 +116,7 @@ public class CpuWakeupStatsTest {

		@Test
		public void alarmIrqAttributionCombined() {
		final CpuWakeupStats obj = new CpuWakeupStats(sContext, R.xml.irq_device_map_3);
		final CpuWakeupStats obj = new CpuWakeupStats(sContext, R.xml.irq_device_map_3, mHandler);
		final long wakeupTime = 92123210;

		obj.noteWakeupTimeAndReason(wakeupTime, 4,
		@@ -143,7 +146,7 @@ public class CpuWakeupStatsTest {

		@Test
		public void unknownIrqAttribution() {
		final CpuWakeupStats obj = new CpuWakeupStats(sContext, R.xml.irq_device_map_3);
		final CpuWakeupStats obj = new CpuWakeupStats(sContext, R.xml.irq_device_map_3, mHandler);
		final long wakeupTime = 92123410;

		obj.noteWakeupTimeAndReason(wakeupTime, 24, KERNEL_REASON_UNKNOWN_IRQ);
		@@ -163,7 +166,7 @@ public class CpuWakeupStatsTest {

		@Test
		public void unknownAttribution() {
		final CpuWakeupStats obj = new CpuWakeupStats(sContext, R.xml.irq_device_map_3);
		final CpuWakeupStats obj = new CpuWakeupStats(sContext, R.xml.irq_device_map_3, mHandler);
		final long wakeupTime = 72123210;

		obj.noteWakeupTimeAndReason(wakeupTime, 34, KERNEL_REASON_UNKNOWN);
		@@ -178,7 +181,7 @@ public class CpuWakeupStatsTest {

		@Test
		public void unsupportedAttribution() {
		final CpuWakeupStats obj = new CpuWakeupStats(sContext, R.xml.irq_device_map_3);
		final CpuWakeupStats obj = new CpuWakeupStats(sContext, R.xml.irq_device_map_3, mHandler);

		long wakeupTime = 970934;
		obj.noteWakeupTimeAndReason(wakeupTime, 34, KERNEL_REASON_UNSUPPORTED);