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

Commit 9716e6a7 authored by Suprabh Shukla's avatar Suprabh Shukla
Browse files

Log kernel wakeup attribution details to stats log 

Each kernel wakeup can have multiple reasons. For each reason that
we are able to correlate with a wakeup, we log an atom to stats-log
with more details.

Currently, we only log the uids that should be blamed for this reason.
More details will be added later as needed.

Test: statsd_testdrive 588
Test: atest FrameworksServicesTests:CpuWakeupStatsTest

Bug: 195684213
Change-Id: I07df9470086927dc3f06dfd7afc5d569f2a34cb7
parent 82f3aad5

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);