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

Commit 087d11f3 authored by Makoto Onuki's avatar Makoto Onuki
Browse files

Log slow UID observer in dumpsys

Sample output:
  mUidChangeDispatchCount=322
  Slow UID dispatches:
    com.android.server.usage.UsageStatsService$2: 0 / Max 0ms
    android.app.IUidObserver$Stub$Proxy: 0 / Max 0ms
    android.app.ActivityManager$UidObserver: 0 / Max 0ms
    com.android.server.pm.ShortcutService$3: 0 / Max 0ms
    android.app.IUidObserver$Stub$Proxy: 0 / Max 0ms
    android.app.IUidObserver$Stub$Proxy: 0 / Max 0ms
    com.android.server.net.NetworkPolicyManagerService$3: 0 / Max 0ms
    com.android.server.AlarmManagerService$UidObserver: 0 / Max 0ms
    com.android.server.job.JobSchedulerService$2: 1 / Max 826ms
    android.app.IUidObserver$Stub$Proxy: 1 / Max 44ms
    android.app.IUidObserver$Stub$Proxy: 0 / Max 0ms
    com.android.server.AppStateTracker$UidObserver: 0 / Max 0ms

Bug: 73505782
Test: Boot and observe dumpsys activity.
Change-Id: I17c971a9690a708c253a5e98e21b8c81166d3ed0
parent f9a02975
Loading
Loading
Loading
Loading
+43 −0
Original line number Diff line number Diff line
@@ -608,6 +608,9 @@ public class ActivityManagerService extends IActivityManager.Stub
    // as one line, but close enough for now.
    static final int RESERVED_BYTES_PER_LOGCAT_LINE = 100;
    /** If a UID observer takes more than this long, send a WTF. */
    private static final int SLOW_UID_OBSERVER_THRESHOLD_MS = 20;
    // Access modes for handleIncomingUser.
    static final int ALLOW_NON_FULL = 0;
    static final int ALLOW_NON_FULL_IN_PROFILE = 1;
@@ -780,6 +783,9 @@ public class ActivityManagerService extends IActivityManager.Stub
    @VisibleForTesting
    long mWaitForNetworkTimeoutMs;
    /** Total # of UID change events dispatched, shown in dumpsys. */
    int mUidChangeDispatchCount;
    /**
     * Helper class which strips out priority and proto arguments then calls the dump function with
     * the appropriate arguments. If priority arguments are omitted, function calls the legacy
@@ -1702,6 +1708,15 @@ public class ActivityManagerService extends IActivityManager.Stub
        final int which;
        final int cutpoint;
        /**
         * Total # of callback calls that took more than {@link #SLOW_UID_OBSERVER_THRESHOLD_MS}.
         * We show it in dumpsys.
         */
        int mSlowDispatchCount;
        /** Max time it took for each dispatch. */
        int mMaxDispatchTime;
        final SparseIntArray lastProcStates;
        // Please keep the enum lists in sync
@@ -4721,6 +4736,7 @@ public class ActivityManagerService extends IActivityManager.Stub
                    "*** Delivering " + N + " uid changes");
        }
        mUidChangeDispatchCount += N;
        int i = mUidObservers.beginBroadcast();
        while (i > 0) {
            i--;
@@ -4773,6 +4789,7 @@ public class ActivityManagerService extends IActivityManager.Stub
                    // interested in all proc state changes.
                    continue;
                }
                final long start = SystemClock.uptimeMillis();
                if ((change & UidRecord.CHANGE_IDLE) != 0) {
                    if ((reg.which & ActivityManager.UID_OBSERVER_IDLE) != 0) {
                        if (DEBUG_UID_OBSERVERS) Slog.i(TAG_UID_OBSERVERS,
@@ -4833,6 +4850,13 @@ public class ActivityManagerService extends IActivityManager.Stub
                        }
                    }
                }
                final int duration = (int) (SystemClock.uptimeMillis() - start);
                if (reg.mMaxDispatchTime < duration) {
                    reg.mMaxDispatchTime = duration;
                }
                if (duration >= SLOW_UID_OBSERVER_THRESHOLD_MS) {
                    reg.mSlowDispatchCount++;
                }
            }
        } catch (RemoteException e) {
        }
@@ -16793,6 +16817,25 @@ public class ActivityManagerService extends IActivityManager.Stub
                        pw.print(" mLowRamSinceLastIdle=");
                        TimeUtils.formatDuration(getLowRamTimeSinceIdle(now), pw);
                        pw.println();
                pw.println();
                pw.print("  mUidChangeDispatchCount=");
                pw.print(mUidChangeDispatchCount);
                pw.println();
                pw.println("  Slow UID dispatches:");
                final int N = mUidObservers.beginBroadcast();
                for (int i = 0; i < N; i++) {
                    UidObserverRegistration r =
                            (UidObserverRegistration) mUidObservers.getBroadcastCookie(i);
                    pw.print("    ");
                    pw.print(mUidObservers.getBroadcastItem(i).getClass().getTypeName());
                    pw.print(": ");
                    pw.print(r.mSlowDispatchCount);
                    pw.print(" / Max ");
                    pw.print(r.mMaxDispatchTime);
                    pw.println("ms");
                }
                mUidObservers.finishBroadcast();
            }
        }
        pw.println("  mForceBackgroundCheck=" + mForceBackgroundCheck);