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

Commit 96b98067 authored by Jing Ji's avatar Jing Ji
Browse files

Improve the dumpsys output of the app battery tracker

Also turn on the logging in debug builds.

Bug: 203105544
Test: atest FrameworksMockingServicesTests:BackgroundRestrictionTest
Test: dumpsys activity -a
Change-Id: I08df65278e228d75dc45c995326cf9cef91de59a
parent 69bdecb3
Loading
Loading
Loading
Loading
+106 −38
Original line number Diff line number Diff line
@@ -55,6 +55,7 @@ import android.os.BatteryConsumer.Dimensions;
import android.os.BatteryStatsInternal;
import android.os.BatteryUsageStats;
import android.os.BatteryUsageStatsQuery;
import android.os.Build;
import android.os.PowerExemptionManager;
import android.os.PowerExemptionManager.ReasonCode;
import android.os.SystemClock;
@@ -62,6 +63,7 @@ import android.os.UidBatteryConsumer;
import android.os.UserHandle;
import android.provider.DeviceConfig;
import android.util.ArraySet;
import android.util.Pair;
import android.util.Slog;
import android.util.SparseArray;
import android.util.SparseBooleanArray;
@@ -80,6 +82,7 @@ import java.io.PrintWriter;
import java.lang.reflect.Constructor;
import java.util.Arrays;
import java.util.List;
import java.util.concurrent.CountDownLatch;

/**
 * The battery usage tracker for apps, currently we are focusing on background + FGS battery here.
@@ -90,6 +93,9 @@ final class AppBatteryTracker extends BaseAppStateTracker<AppBatteryPolicy>

    static final boolean DEBUG_BACKGROUND_BATTERY_TRACKER = false;

    static final boolean DEBUG_BACKGROUND_BATTERY_TRACKER_VERBOSE =
            DEBUG_BACKGROUND_BATTERY_TRACKER | Build.IS_DEBUGGABLE;

    // As we don't support realtime per-UID battery usage stats yet, we're polling the stats
    // in a regular time basis.
    private final long mBatteryUsageStatsPollingIntervalMs;
@@ -169,7 +175,7 @@ final class AppBatteryTracker extends BaseAppStateTracker<AppBatteryPolicy>
    private long mLastUidBatteryUsageStartTs;

    // For debug only.
    private final SparseArray<BatteryUsage> mDebugUidPercentages = new SparseArray<>();
    private final SparseArray<ImmutableBatteryUsage> mDebugUidPercentages = new SparseArray<>();

    AppBatteryTracker(Context context, AppRestrictionController controller) {
        this(context, controller, null, null);
@@ -331,10 +337,12 @@ final class AppBatteryTracker extends BaseAppStateTracker<AppBatteryPolicy>
                                bgPolicy.mBgCurrentDrainExemptedTypes);
                // It's possible the exemptedUsage could be larger than actualUsage,
                // as the former one is an approximate value.
                final BatteryUsage bgUsage = actualUsage.mutate()
                final ImmutableBatteryUsage bgUsage = actualUsage.mutate()
                        .subtract(exemptedUsage)
                        .calcPercentage(uid, bgPolicy);
                if (DEBUG_BACKGROUND_BATTERY_TRACKER) {
                        .calcPercentage(uid, bgPolicy)
                        .unmutate();
                if (DEBUG_BACKGROUND_BATTERY_TRACKER_VERBOSE
                        && !BATTERY_USAGE_NONE.equals(actualUsage)) {
                    Slog.i(TAG, String.format(
                            "UID %d: %s (%s) | %s | %s over the past %s",
                            uid,
@@ -414,7 +422,7 @@ final class AppBatteryTracker extends BaseAppStateTracker<AppBatteryPolicy>
            }
        }

        if (DEBUG_BACKGROUND_BATTERY_TRACKER) {
        if (DEBUG_BACKGROUND_BATTERY_TRACKER_VERBOSE) {
            Slog.i(TAG, "updateBatteryUsageStatsOnce");
        }

@@ -471,14 +479,17 @@ final class AppBatteryTracker extends BaseAppStateTracker<AppBatteryPolicy>
                final BatteryUsage lastUsage = mLastUidBatteryUsage.get(uid, BATTERY_USAGE_NONE);
                final BatteryUsage curUsage = buf.valueAt(i);
                final BatteryUsage before;
                final BatteryUsage totalUsage;
                if (index >= 0) {
                    before = mUidBatteryUsage.valueAt(index);
                    before.subtract(lastUsage).add(curUsage);
                    totalUsage = mUidBatteryUsage.valueAt(index);
                    before = DEBUG_BACKGROUND_BATTERY_TRACKER_VERBOSE
                            ? new BatteryUsage(totalUsage) : BATTERY_USAGE_NONE;
                    totalUsage.subtract(lastUsage).add(curUsage);
                } else {
                    before = BATTERY_USAGE_NONE;
                    before = totalUsage = BATTERY_USAGE_NONE;
                    mUidBatteryUsage.put(uid, curUsage);
                }
                if (DEBUG_BACKGROUND_BATTERY_TRACKER) {
                if (DEBUG_BACKGROUND_BATTERY_TRACKER_VERBOSE) {
                    final BatteryUsage actualDelta = new BatteryUsage(curUsage).subtract(lastUsage);
                    String msg = "Updating mUidBatteryUsage uid=" + uid + ", before=" + before
                            + ", after=" + mUidBatteryUsage.get(uid, BATTERY_USAGE_NONE)
@@ -490,7 +501,7 @@ final class AppBatteryTracker extends BaseAppStateTracker<AppBatteryPolicy>
                    if (!actualDelta.isValid()) {
                        // Something is wrong, the battery usage shouldn't be negative.
                        Slog.e(TAG, msg);
                    } else {
                    } else if (!BATTERY_USAGE_NONE.equals(actualDelta)) {
                        Slog.i(TAG, msg);
                    }
                }
@@ -513,11 +524,16 @@ final class AppBatteryTracker extends BaseAppStateTracker<AppBatteryPolicy>
                copyUidBatteryUsage(buf, mUidBatteryUsageInWindow);
            }
        }
        if (DEBUG_BACKGROUND_BATTERY_TRACKER) {
        if (DEBUG_BACKGROUND_BATTERY_TRACKER_VERBOSE) {
            synchronized (mLock) {
                for (int i = 0, size = mUidBatteryUsageInWindow.size(); i < size; i++) {
                    final ImmutableBatteryUsage usage = mUidBatteryUsageInWindow.valueAt(i);
                    if (BATTERY_USAGE_NONE.equals(usage)) {
                        // Skip the logging to avoid spamming.
                        continue;
                    }
                    Slog.i(TAG, "mUidBatteryUsageInWindow uid=" + mUidBatteryUsageInWindow.keyAt(i)
                            + " usage=" + mUidBatteryUsageInWindow.valueAt(i));
                            + " usage=" + usage);
                }
            }
        }
@@ -568,7 +584,8 @@ final class AppBatteryTracker extends BaseAppStateTracker<AppBatteryPolicy>
                    final BatteryUsage before = buf.valueAt(index);
                    before.add(bgUsage);
                }
                if (DEBUG_BACKGROUND_BATTERY_TRACKER) {
                if (DEBUG_BACKGROUND_BATTERY_TRACKER_VERBOSE
                        && !BATTERY_USAGE_NONE.equals(bgUsage)) {
                    Slog.i(TAG, "updateBatteryUsageStatsOnceInternal uid=" + rawUid
                            + ", bgUsage=" + bgUsage
                            + (rawUid == uid ? ""
@@ -625,7 +642,8 @@ final class AppBatteryTracker extends BaseAppStateTracker<AppBatteryPolicy>
    void setDebugUidPercentage(int[] uids, double[][] percentages) {
        mDebugUidPercentages.clear();
        for (int i = 0; i < uids.length; i++) {
            mDebugUidPercentages.put(uids[i], new BatteryUsage().setPercentage(percentages[i]));
            mDebugUidPercentages.put(uids[i],
                    new BatteryUsage().setPercentage(percentages[i]).unmutate());
        }
        scheduleBgBatteryUsageStatsCheck();
    }
@@ -651,7 +669,20 @@ final class AppBatteryTracker extends BaseAppStateTracker<AppBatteryPolicy>
    void dump(PrintWriter pw, String prefix) {
        pw.print(prefix);
        pw.println("APP BATTERY STATE TRACKER:");
        // Force an update.
        updateBatteryUsageStatsIfNecessary(mInjector.currentTimeMillis(), true);
        // Force a check.
        scheduleBgBatteryUsageStatsCheck();
        // Wait for its completion (as it runs in handler thread for the sake of thread safe)
        final CountDownLatch latch = new CountDownLatch(1);
        mBgHandler.getLooper().getQueue().addIdleHandler(() -> {
            latch.countDown();
            return false;
        });
        try {
            latch.await();
        } catch (InterruptedException e) {
        }
        synchronized (mLock) {
            final SparseArray<ImmutableBatteryUsage> uidConsumers = mUidBatteryUsageInWindow;
            pw.print("  " + prefix);
@@ -816,8 +847,12 @@ final class AppBatteryTracker extends BaseAppStateTracker<AppBatteryPolicy>
        }

        private BatteryUsage setToInternal(@NonNull BatteryUsage other) {
            for (int i = 0; i < other.mUsage.length; i++) {
                mUsage[i] = other.mUsage[i];
            System.arraycopy(other.mUsage, 0, mUsage, 0, other.mUsage.length);
            if (other.mPercentage != null) {
                mPercentage = new double[other.mPercentage.length];
                System.arraycopy(other.mPercentage, 0, mPercentage, 0, other.mPercentage.length);
            } else {
                mPercentage = null;
            }
            return this;
        }
@@ -1297,11 +1332,12 @@ final class AppBatteryTracker extends BaseAppStateTracker<AppBatteryPolicy>

        /**
         * List of the packages with significant background battery usage, key is the UID of
         * the package and value is an array of the timestamps when the UID is found guilty and
         * should be moved to the next level of restriction.
         * the package and value is the pair of {timestamp[], battery usage snapshot[]}
         * when the UID is found guilty and should be moved to the next level of restriction.
         */
        @GuardedBy("mLock")
        private final SparseArray<long[]> mHighBgBatteryPackages = new SparseArray<>();
        private final SparseArray<Pair<long[], ImmutableBatteryUsage[]>> mHighBgBatteryPackages =
                new SparseArray<>();

        @NonNull
        private final Object mLock;
@@ -1531,8 +1567,9 @@ final class AppBatteryTracker extends BaseAppStateTracker<AppBatteryPolicy>
                return RESTRICTION_LEVEL_UNKNOWN;
            }
            synchronized (mLock) {
                final long[] ts = mHighBgBatteryPackages.get(uid);
                if (ts != null) {
                final Pair<long[], ImmutableBatteryUsage[]> pair = mHighBgBatteryPackages.get(uid);
                if (pair != null) {
                    final long[] ts = pair.first;
                    final int restrictedLevel = ts[TIME_STAMP_INDEX_RESTRICTED_BUCKET] > 0
                            ? RESTRICTION_LEVEL_RESTRICTED_BUCKET
                            : RESTRICTION_LEVEL_ADAPTIVE_BUCKET;
@@ -1601,10 +1638,10 @@ final class AppBatteryTracker extends BaseAppStateTracker<AppBatteryPolicy>
            return sb.toString();
        }

        void handleUidBatteryUsage(final int uid, final BatteryUsage usage) {
        void handleUidBatteryUsage(final int uid, final ImmutableBatteryUsage usage) {
            final @ReasonCode int reason = shouldExemptUid(uid);
            if (reason != REASON_DENIED) {
                if (DEBUG_BACKGROUND_BATTERY_TRACKER) {
                if (DEBUG_BACKGROUND_BATTERY_TRACKER_VERBOSE && !BATTERY_USAGE_NONE.equals(usage)) {
                    Slog.i(TAG, "Exempting battery usage in " + UserHandle.formatUid(uid)
                            + " " + PowerExemptionManager.reasonCodeToString(reason));
                }
@@ -1612,6 +1649,7 @@ final class AppBatteryTracker extends BaseAppStateTracker<AppBatteryPolicy>
            }
            boolean notifyController = false;
            boolean excessive = false;
            int index = 0;
            final double rbPercentage = sumPercentageOfTypes(usage.getPercentage(),
                    mBgCurrentDrainRestrictedBucketTypes);
            final double brPercentage = sumPercentageOfTypes(usage.getPercentage(),
@@ -1625,33 +1663,41 @@ final class AppBatteryTracker extends BaseAppStateTracker<AppBatteryPolicy>
                final long now = SystemClock.elapsedRealtime();
                final int thresholdIndex = getCurrentDrainThresholdIndex(uid, now,
                        mBgCurrentDrainWindowMs);
                final int index = mHighBgBatteryPackages.indexOfKey(uid);
                index = mHighBgBatteryPackages.indexOfKey(uid);
                final boolean decoupleThresholds = mBgCurrentDrainDecoupleThresholds;
                final double rbThreshold = mBgCurrentDrainRestrictedBucketThreshold[thresholdIndex];
                final double brThreshold = mBgCurrentDrainBgRestrictedThreshold[thresholdIndex];
                if (index < 0) {
                    long[] ts = null;
                    ImmutableBatteryUsage[] usages = null;
                    if (rbPercentage >= rbThreshold) {
                        // New findings to us, track it and let the controller know.
                        ts = new long[TIME_STAMP_INDEX_LAST];
                        ts[TIME_STAMP_INDEX_RESTRICTED_BUCKET] = now;
                        mHighBgBatteryPackages.put(uid, ts);
                        usages = new ImmutableBatteryUsage[TIME_STAMP_INDEX_LAST];
                        usages[TIME_STAMP_INDEX_RESTRICTED_BUCKET] = usage;
                        mHighBgBatteryPackages.put(uid, Pair.create(ts, usages));
                        notifyController = excessive = true;
                    }
                    if (decoupleThresholds && brPercentage >= brThreshold) {
                        if (ts == null) {
                            ts = new long[TIME_STAMP_INDEX_LAST];
                            mHighBgBatteryPackages.put(uid, ts);
                            usages = new ImmutableBatteryUsage[TIME_STAMP_INDEX_LAST];
                            mHighBgBatteryPackages.put(uid, Pair.create(ts, usages));
                        }
                        ts[TIME_STAMP_INDEX_BG_RESTRICTED] = now;
                        usages[TIME_STAMP_INDEX_BG_RESTRICTED] = usage;
                        notifyController = excessive = true;
                    }
                } else {
                    final long[] ts = mHighBgBatteryPackages.valueAt(index);
                    final Pair<long[], ImmutableBatteryUsage[]> pair =
                            mHighBgBatteryPackages.valueAt(index);
                    final long[] ts = pair.first;
                    final long lastRestrictBucketTs = ts[TIME_STAMP_INDEX_RESTRICTED_BUCKET];
                    if (rbPercentage >= rbThreshold) {
                        if (lastRestrictBucketTs == 0) {
                            ts[TIME_STAMP_INDEX_RESTRICTED_BUCKET] = now;
                            pair.second[TIME_STAMP_INDEX_RESTRICTED_BUCKET] = usage;
                        }
                        notifyController = excessive = true;
                    } else {
@@ -1670,6 +1716,7 @@ final class AppBatteryTracker extends BaseAppStateTracker<AppBatteryPolicy>
                                && (now > lastRestrictBucketTs + mBgCurrentDrainWindowMs));
                        if (notifyController) {
                            ts[TIME_STAMP_INDEX_BG_RESTRICTED] = now;
                            pair.second[TIME_STAMP_INDEX_RESTRICTED_BUCKET] = usage;
                        }
                        excessive = true;
                    } else {
@@ -1677,13 +1724,14 @@ final class AppBatteryTracker extends BaseAppStateTracker<AppBatteryPolicy>
                        // user consent to unrestrict it; or if it's in restricted bucket level,
                        // resetting this won't lift it from that level.
                        ts[TIME_STAMP_INDEX_BG_RESTRICTED] = 0;
                        pair.second[TIME_STAMP_INDEX_RESTRICTED_BUCKET] = null;
                        // Now need to notify the controller.
                    }
                }
            }

            if (excessive) {
                if (DEBUG_BACKGROUND_BATTERY_TRACKER) {
                if (DEBUG_BACKGROUND_BATTERY_TRACKER_VERBOSE) {
                    Slog.i(TAG, "Excessive background current drain " + uid + " "
                            + usage + " (" + usage.percentageToString() + " ) over "
                            + TimeUtils.formatDuration(mBgCurrentDrainWindowMs));
@@ -1694,7 +1742,7 @@ final class AppBatteryTracker extends BaseAppStateTracker<AppBatteryPolicy>
                            REASON_SUB_FORCED_SYSTEM_FLAG_ABUSE, true);
                }
            } else {
                if (DEBUG_BACKGROUND_BATTERY_TRACKER) {
                if (DEBUG_BACKGROUND_BATTERY_TRACKER_VERBOSE && index >= 0) {
                    Slog.i(TAG, "Background current drain backs to normal " + uid + " "
                            + usage + " (" + usage.percentageToString() + " ) over "
                            + TimeUtils.formatDuration(mBgCurrentDrainWindowMs));
@@ -1764,9 +1812,10 @@ final class AppBatteryTracker extends BaseAppStateTracker<AppBatteryPolicy>
            synchronized (mLock) {
                // User has explicitly removed it from background restricted level,
                // clear the timestamp of the background-restricted
                final long[] ts = mHighBgBatteryPackages.get(uid);
                if (ts != null) {
                    ts[TIME_STAMP_INDEX_BG_RESTRICTED] = 0;
                final Pair<long[], ImmutableBatteryUsage[]> pair = mHighBgBatteryPackages.get(uid);
                if (pair != null) {
                    pair.first[TIME_STAMP_INDEX_BG_RESTRICTED] = 0;
                    pair.second[TIME_STAMP_INDEX_BG_RESTRICTED] = null;
                }
            }
        }
@@ -1841,6 +1890,10 @@ final class AppBatteryTracker extends BaseAppStateTracker<AppBatteryPolicy>
                pw.print(KEY_BG_CURRENT_DRAIN_HIGH_THRESHOLD_BY_BG_LOCATION);
                pw.print('=');
                pw.println(mBgCurrentDrainHighThresholdByBgLocation);
                pw.print(prefix);
                pw.print("Full charge capacity=");
                pw.print(mBatteryFullChargeMah);
                pw.println(" mAh");

                pw.print(prefix);
                pw.println("Excessive current drain detected:");
@@ -1851,7 +1904,10 @@ final class AppBatteryTracker extends BaseAppStateTracker<AppBatteryPolicy>
                        final long now = SystemClock.elapsedRealtime();
                        for (int i = 0; i < size; i++) {
                            final int uid = mHighBgBatteryPackages.keyAt(i);
                            final long[] ts = mHighBgBatteryPackages.valueAt(i);
                            final Pair<long[], ImmutableBatteryUsage[]> pair =
                                    mHighBgBatteryPackages.valueAt(i);
                            final long[] ts = pair.first;
                            final ImmutableBatteryUsage[] usages = pair.second;
                            final int thresholdIndex = getCurrentDrainThresholdIndex(uid, now,
                                    mBgCurrentDrainWindowMs);
                            pw.format("%s%s: (threshold=%4.2f%%/%4.2f%%) %s / %s\n",
@@ -1859,10 +1915,13 @@ final class AppBatteryTracker extends BaseAppStateTracker<AppBatteryPolicy>
                                    UserHandle.formatUid(uid),
                                    mBgCurrentDrainRestrictedBucketThreshold[thresholdIndex],
                                    mBgCurrentDrainBgRestrictedThreshold[thresholdIndex],
                                    ts[TIME_STAMP_INDEX_RESTRICTED_BUCKET] == 0 ? "0"
                                        : formatTime(ts[TIME_STAMP_INDEX_RESTRICTED_BUCKET], now),
                                    ts[TIME_STAMP_INDEX_BG_RESTRICTED] == 0 ? "0"
                                        : formatTime(ts[TIME_STAMP_INDEX_BG_RESTRICTED], now));
                                    formatHighBgBatteryRecord(
                                            ts[TIME_STAMP_INDEX_RESTRICTED_BUCKET], now,
                                            usages[TIME_STAMP_INDEX_RESTRICTED_BUCKET]),
                                    formatHighBgBatteryRecord(
                                            ts[TIME_STAMP_INDEX_BG_RESTRICTED], now,
                                            usages[TIME_STAMP_INDEX_BG_RESTRICTED])
                            );
                        }
                    } else {
                        pw.print(prefix);
@@ -1871,5 +1930,14 @@ final class AppBatteryTracker extends BaseAppStateTracker<AppBatteryPolicy>
                }
            }
        }

        private String formatHighBgBatteryRecord(long ts, long now, ImmutableBatteryUsage usage) {
            if (ts > 0 && usage != null) {
                return String.format("%s %s (%s)",
                        formatTime(ts, now), usage.toString(), usage.percentageToString());
            } else {
                return "0";
            }
        }
    }
}