Fix/improve procstats association data & printing

- Fix some bugs in how we compute association data.
- Add in overall time for an association, since you can't
  tell that from the time of its individual sources.
- Fix issues in printing data filtered by package/process
  to better select the data.
- Sort the association and source data by active time, so
  the ones with the most impact are first.
- And sort associations by process so that in apps with
  multiple processes (ahem GmsCore), you can tell what is
  going on for each process separately.

Bug: 142283699
Test: manual
Change-Id: I504bd1a0614fce4f4410f3f53993af5cbd576b79

3 files changed, 464 insertions, 168 deletions

diff --git a/core/java/com/android/internal/app/procstats/AssociationState.java b/core/java/com/android/internal/app/procstats/AssociationState.java
index 2df515835026..0ed252400aa1 100644
--- a/core/java/com/android/internal/app/procstats/AssociationState.java
+++ b/core/java/com/android/internal/app/procstats/AssociationState.java
@@ -16,7 +16,6 @@
 
 package com.android.internal.app.procstats;
 
-
 import android.annotation.Nullable;
 import android.os.Parcel;
 import android.os.SystemClock;
@@ -24,23 +23,37 @@ import android.os.UserHandle;
 import android.service.procstats.PackageAssociationProcessStatsProto;
 import android.service.procstats.PackageAssociationSourceProcessStatsProto;
 import android.util.ArrayMap;
+import android.util.Pair;
 import android.util.Slog;
 import android.util.TimeUtils;
 import android.util.proto.ProtoOutputStream;
 
 import java.io.PrintWriter;
 import java.util.ArrayList;
+import java.util.Collections;
+import java.util.Comparator;
 import java.util.Objects;
 
 public final class AssociationState {
     private static final String TAG = "ProcessStats";
     private static final boolean DEBUG = false;
 
+    private static final boolean VALIDATE_TIMES = false;
+
     private final ProcessStats mProcessStats;
     private final ProcessStats.PackageState mPackageState;
     private final String mProcessName;
     private final String mName;
 
+    private int mTotalNesting;
+    private long mTotalStartUptime;
+    private int mTotalCount;
+    private long mTotalDuration;
+    private int mTotalActiveNesting;
+    private long mTotalActiveStartUptime;
+    private int mTotalActiveCount;
+    private long mTotalActiveDuration;
+
     public final class SourceState {
         final SourceKey mKey;
         int mProcStateSeq = -1;
@@ -55,7 +68,7 @@ public final class AssociationState {
         int mActiveProcState = ProcessStats.STATE_NOTHING;
         long mActiveStartUptime;
         long mActiveDuration;
-        DurationsTable mDurations;
+        DurationsTable mActiveDurations;
 
         SourceState(SourceKey key) {
             mKey = key;
@@ -97,9 +110,9 @@ public final class AssociationState {
         public void stop() {
             mNesting--;
             if (mNesting == 0) {
-                mDuration += SystemClock.uptimeMillis() - mStartUptime;
-                mNumActive--;
-                stopTracking(SystemClock.uptimeMillis());
+                final long now = SystemClock.uptimeMillis();
+                mDuration += now - mStartUptime;
+                stopTracking(now);
             }
         }
 
@@ -108,20 +121,25 @@ public final class AssociationState {
                 if (mActiveStartUptime == 0) {
                     mActiveStartUptime = now;
                     mActiveCount++;
+                    AssociationState.this.mTotalActiveNesting++;
+                    if (AssociationState.this.mTotalActiveNesting == 1) {
+                        AssociationState.this.mTotalActiveCount++;
+                        AssociationState.this.mTotalActiveStartUptime = now;
+                    }
                 }
                 if (mActiveProcState != mProcState) {
                     if (mActiveProcState != ProcessStats.STATE_NOTHING) {
                         // Currently active proc state changed, need to store the duration
                         // so far and switch tracking to the new proc state.
-                        final long duration = mActiveDuration + now - mActiveStartUptime;
-                        if (duration != 0) {
-                            if (mDurations == null) {
+                        final long addedDuration = mActiveDuration + now - mActiveStartUptime;
+                        mActiveStartUptime = now;
+                        if (addedDuration != 0) {
+                            if (mActiveDurations == null) {
                                 makeDurations();
                             }
-                            mDurations.addDuration(mActiveProcState, duration);
+                            mActiveDurations.addDuration(mActiveProcState, addedDuration);
                             mActiveDuration = 0;
                         }
-                        mActiveStartUptime = now;
                     }
                     mActiveProcState = mProcState;
                 }
@@ -135,21 +153,44 @@ public final class AssociationState {
                 if (!mInTrackingList) {
                     Slog.wtf(TAG, "stopActive while not tracking: " + this);
                 }
-                final long duration = mActiveDuration + now - mActiveStartUptime;
-                if (mDurations != null) {
-                    mDurations.addDuration(mActiveProcState, duration);
+                final long addedDuration = now - mActiveStartUptime;
+                mActiveStartUptime = 0;
+                if (mActiveDurations != null) {
+                    mActiveDurations.addDuration(mActiveProcState, addedDuration);
                 } else {
-                    mActiveDuration = duration;
+                    mActiveDuration += addedDuration;
+                }
+                AssociationState.this.mTotalActiveNesting--;
+                if (AssociationState.this.mTotalActiveNesting == 0) {
+                    AssociationState.this.mTotalActiveDuration += now
+                            - AssociationState.this.mTotalActiveStartUptime;
+                    AssociationState.this.mTotalActiveStartUptime = 0;
+                    if (VALIDATE_TIMES) {
+                        if (mActiveDuration > AssociationState.this.mTotalActiveDuration) {
+                            RuntimeException ex = new RuntimeException();
+                            ex.fillInStackTrace();
+                            Slog.w(TAG, "Source act duration " + mActiveDurations
+                                    + " exceeds total " + AssociationState.this.mTotalActiveDuration
+                                    + " in procstate " + mActiveProcState + " in source "
+                                    + mKey.mProcess + " to assoc "
+                                    + AssociationState.this.mName, ex);
+                        }
+
+                    }
                 }
-                mActiveStartUptime = 0;
             }
         }
 
         void makeDurations() {
-            mDurations = new DurationsTable(mProcessStats.mTableData);
+            mActiveDurations = new DurationsTable(mProcessStats.mTableData);
         }
 
         void stopTracking(long now) {
+            AssociationState.this.mTotalNesting--;
+            if (AssociationState.this.mTotalNesting == 0) {
+                AssociationState.this.mTotalDuration += now
+                        - AssociationState.this.mTotalStartUptime;
+            }
             stopActive(now);
             if (mInTrackingList) {
                 mInTrackingList = false;
@@ -181,7 +222,17 @@ public final class AssociationState {
         }
     }
 
-    private final static class SourceKey {
+    public final class SourceDumpContainer {
+        public final SourceState mState;
+        public long mTotalTime;
+        public long mActiveTime;
+
+        public SourceDumpContainer(SourceState state) {
+            mState = state;
+        }
+    }
+
+    public static final class SourceKey {
         /**
          * UID, consider this final.  Not final just to avoid a temporary object during lookup.
          */
@@ -239,12 +290,10 @@ public final class AssociationState {
      */
     private final ArrayMap<SourceKey, SourceState> mSources = new ArrayMap<>();
 
-    private final SourceKey mTmpSourceKey = new SourceKey(0, null, null);
+    private static final SourceKey sTmpSourceKey = new SourceKey(0, null, null);
 
     private ProcessState mProc;
 
-    private int mNumActive;
-
     public AssociationState(ProcessStats processStats, ProcessStats.PackageState packageState,
             String name, String processName, ProcessState proc) {
         mProcessStats = processStats;
@@ -278,11 +327,24 @@ public final class AssociationState {
         mProc = proc;
     }
 
+    public long getTotalDuration(long now) {
+        return mTotalDuration
+                + (mTotalNesting > 0 ? (now - mTotalStartUptime) : 0);
+    }
+
+    public long getActiveDuration(long now) {
+        return mTotalActiveDuration
+                + (mTotalActiveNesting > 0 ? (now - mTotalActiveStartUptime) : 0);
+    }
+
     public SourceState startSource(int uid, String processName, String packageName) {
-        mTmpSourceKey.mUid = uid;
-        mTmpSourceKey.mProcess = processName;
-        mTmpSourceKey.mPackage = packageName;
-        SourceState src = mSources.get(mTmpSourceKey);
+        SourceState src;
+        synchronized (sTmpSourceKey) {
+            sTmpSourceKey.mUid = uid;
+            sTmpSourceKey.mProcess = processName;
+            sTmpSourceKey.mPackage = packageName;
+            src = mSources.get(sTmpSourceKey);
+        }
         if (src == null) {
             SourceKey key = new SourceKey(uid, processName, packageName);
             src = new SourceState(key);
@@ -290,43 +352,88 @@ public final class AssociationState {
         }
         src.mNesting++;
         if (src.mNesting == 1) {
+            final long now = SystemClock.uptimeMillis();
             src.mCount++;
-            src.mStartUptime = SystemClock.uptimeMillis();
-            mNumActive++;
+            src.mStartUptime = now;
+            mTotalNesting++;
+            if (mTotalNesting == 1) {
+                mTotalCount++;
+                mTotalStartUptime = now;
+            }
         }
         return src;
     }
 
     public void add(AssociationState other) {
+        mTotalCount += other.mTotalCount;
+        final long origDuration = mTotalDuration;
+        mTotalDuration += other.mTotalDuration;
+        mTotalActiveCount += other.mTotalActiveCount;
+        mTotalActiveDuration += other.mTotalActiveDuration;
         for (int isrc = other.mSources.size() - 1; isrc >= 0; isrc--) {
             final SourceKey key = other.mSources.keyAt(isrc);
             final SourceState otherSrc = other.mSources.valueAt(isrc);
             SourceState mySrc = mSources.get(key);
+            boolean newSrc = false;
             if (mySrc == null) {
                 mySrc = new SourceState(key);
                 mSources.put(key, mySrc);
+                newSrc = true;
+            }
+            if (VALIDATE_TIMES) {
+                Slog.w(TAG, "Adding tot duration " + mySrc.mDuration + "+"
+                        + otherSrc.mDuration
+                        + (newSrc ? " (new)" : " (old)") + " (total "
+                        + origDuration + "+" + other.mTotalDuration + ") in source "
+                        + mySrc.mKey.mProcess + " to assoc " + mName);
+                if ((mySrc.mDuration + otherSrc.mDuration) > mTotalDuration) {
+                    RuntimeException ex = new RuntimeException();
+                    ex.fillInStackTrace();
+                    Slog.w(TAG, "Source tot duration " + mySrc.mDuration + "+"
+                            + otherSrc.mDuration
+                            + (newSrc ? " (new)" : " (old)") + " exceeds total "
+                            + origDuration + "+" + other.mTotalDuration + " in source "
+                            + mySrc.mKey.mProcess + " to assoc " + mName, ex);
+                }
+                if (mySrc.mActiveDurations == null && otherSrc.mActiveDurations == null) {
+                    Slog.w(TAG, "Adding act duration " + mySrc.mActiveDuration
+                            + "+" + otherSrc.mActiveDuration
+                            + (newSrc ? " (new)" : " (old)") + " (total "
+                            + origDuration + "+" + other.mTotalDuration + ") in source "
+                            + mySrc.mKey.mProcess + " to assoc " + mName);
+                    if ((mySrc.mActiveDuration + otherSrc.mActiveDuration) > mTotalDuration) {
+                        RuntimeException ex = new RuntimeException();
+                        ex.fillInStackTrace();
+                        Slog.w(TAG, "Source act duration " + mySrc.mActiveDuration + "+"
+                                + otherSrc.mActiveDuration
+                                + (newSrc ? " (new)" : " (old)") + " exceeds total "
+                                + origDuration + "+" + other.mTotalDuration + " in source "
+                                + mySrc.mKey.mProcess + " to assoc " + mName, ex);
+                    }
+                }
             }
             mySrc.mCount += otherSrc.mCount;
             mySrc.mDuration += otherSrc.mDuration;
             mySrc.mActiveCount += otherSrc.mActiveCount;
-            if (otherSrc.mActiveDuration != 0 || otherSrc.mDurations != null) {
+            if (otherSrc.mActiveDuration != 0 || otherSrc.mActiveDurations != null) {
                 // Only need to do anything if the other one has some duration data.
-                if (mySrc.mDurations != null) {
+                if (mySrc.mActiveDurations != null) {
                     // If the target already has multiple durations, just add in whatever
                     // we have in the other.
-                    if (otherSrc.mDurations != null) {
-                        mySrc.mDurations.addDurations(otherSrc.mDurations);
+                    if (otherSrc.mActiveDurations != null) {
+                        mySrc.mActiveDurations.addDurations(otherSrc.mActiveDurations);
                     } else {
-                        mySrc.mDurations.addDuration(otherSrc.mActiveProcState,
+                        mySrc.mActiveDurations.addDuration(otherSrc.mActiveProcState,
                                 otherSrc.mActiveDuration);
                     }
-                } else if (otherSrc.mDurations != null) {
+                } else if (otherSrc.mActiveDurations != null) {
                     // The other one has multiple durations, but we don't.  Expand to
                     // multiple durations and copy over.
                     mySrc.makeDurations();
-                    mySrc.mDurations.addDurations(otherSrc.mDurations);
+                    mySrc.mActiveDurations.addDurations(otherSrc.mActiveDurations);
                     if (mySrc.mActiveDuration != 0) {
-                        mySrc.mDurations.addDuration(mySrc.mActiveProcState, mySrc.mActiveDuration);
+                        mySrc.mActiveDurations.addDuration(mySrc.mActiveProcState,
+                                mySrc.mActiveDuration);
                         mySrc.mActiveDuration = 0;
                         mySrc.mActiveProcState = ProcessStats.STATE_NOTHING;
                     }
@@ -334,13 +441,14 @@ public final class AssociationState {
                     // Both have a single inline duration...  we can either add them together,
                     // or need to expand to multiple durations.
                     if (mySrc.mActiveProcState == otherSrc.mActiveProcState) {
-                        mySrc.mDuration += otherSrc.mDuration;
+                        mySrc.mActiveDuration += otherSrc.mActiveDuration;
                     } else {
                         // The two have durations with different proc states, need to turn
                         // in to multiple durations.
                         mySrc.makeDurations();
-                        mySrc.mDurations.addDuration(mySrc.mActiveProcState, mySrc.mActiveDuration);
-                        mySrc.mDurations.addDuration(otherSrc.mActiveProcState,
+                        mySrc.mActiveDurations.addDuration(mySrc.mActiveProcState,
+                                mySrc.mActiveDuration);
+                        mySrc.mActiveDurations.addDuration(otherSrc.mActiveProcState,
                                 otherSrc.mActiveDuration);
                         mySrc.mActiveDuration = 0;
                         mySrc.mActiveProcState = ProcessStats.STATE_NOTHING;
@@ -355,12 +463,13 @@ public final class AssociationState {
     }
 
     public boolean isInUse() {
-        return mNumActive > 0;
+        return mTotalNesting > 0;
     }
 
     public void resetSafely(long now) {
         if (!isInUse()) {
             mSources.clear();
+            mTotalCount = mTotalActiveCount = 0;
         } else {
             // We have some active sources...  clear out everything but those.
             for (int isrc = mSources.size() - 1; isrc >= 0; isrc--) {
@@ -376,15 +485,28 @@ public final class AssociationState {
                         src.mActiveCount = 0;
                     }
                     src.mActiveDuration = 0;
-                    src.mDurations = null;
+                    src.mActiveDurations = null;
                 } else {
                     mSources.removeAt(isrc);
                 }
             }
+            mTotalCount = 1;
+            mTotalStartUptime = now;
+            if (mTotalActiveNesting > 0) {
+                mTotalActiveCount = 1;
+                mTotalActiveStartUptime = now;
+            } else {
+                mTotalActiveCount = 0;
+            }
         }
+        mTotalDuration = mTotalActiveDuration = 0;
     }
 
     public void writeToParcel(ProcessStats stats, Parcel out, long nowUptime) {
+        out.writeInt(mTotalCount);
+        out.writeLong(mTotalDuration);
+        out.writeInt(mTotalActiveCount);
+        out.writeLong(mTotalActiveDuration);
         final int NSRC = mSources.size();
         out.writeInt(NSRC);
         for (int isrc = 0; isrc < NSRC; isrc++) {
@@ -396,9 +518,9 @@ public final class AssociationState {
             out.writeInt(src.mCount);
             out.writeLong(src.mDuration);
             out.writeInt(src.mActiveCount);
-            if (src.mDurations != null) {
+            if (src.mActiveDurations != null) {
                 out.writeInt(1);
-                src.mDurations.writeToParcel(out);
+                src.mActiveDurations.writeToParcel(out);
             } else {
                 out.writeInt(0);
                 out.writeInt(src.mActiveProcState);
@@ -412,6 +534,10 @@ public final class AssociationState {
      * caused it to fail.
      */
     public String readFromParcel(ProcessStats stats, Parcel in, int parcelVersion) {
+        mTotalCount = in.readInt();
+        mTotalDuration = in.readLong();
+        mTotalActiveCount = in.readInt();
+        mTotalActiveDuration = in.readLong();
         final int NSRC = in.readInt();
         if (NSRC < 0 || NSRC > 100000) {
             return "Association with bad src count: " + NSRC;
@@ -427,13 +553,29 @@ public final class AssociationState {
             src.mActiveCount = in.readInt();
             if (in.readInt() != 0) {
                 src.makeDurations();
-                if (!src.mDurations.readFromParcel(in)) {
+                if (!src.mActiveDurations.readFromParcel(in)) {
                     return "Duration table corrupt: " + key + " <- " + src;
                 }
             } else {
                 src.mActiveProcState = in.readInt();
                 src.mActiveDuration = in.readLong();
             }
+            if (VALIDATE_TIMES) {
+                if (src.mDuration > mTotalDuration) {
+                    RuntimeException ex = new RuntimeException();
+                    ex.fillInStackTrace();
+                    Slog.w(TAG, "Reading tot duration " + src.mDuration
+                            + " exceeds total " + mTotalDuration + " in source "
+                            + src.mKey.mProcess + " to assoc " + mName, ex);
+                }
+                if (src.mActiveDurations == null && src.mActiveDuration > mTotalDuration) {
+                    RuntimeException ex = new RuntimeException();
+                    ex.fillInStackTrace();
+                    Slog.w(TAG, "Reading act duration " + src.mActiveDuration
+                            + " exceeds total " + mTotalDuration + " in source "
+                            + src.mKey.mProcess + " to assoc " + mName, ex);
+                }
+            }
             mSources.put(key, src);
         }
         return null;
@@ -448,19 +590,30 @@ public final class AssociationState {
                     src.mStartUptime = nowUptime;
                 }
                 if (src.mActiveStartUptime > 0) {
-                    final long duration = src.mActiveDuration + nowUptime - src.mActiveStartUptime;
-                    if (src.mDurations != null) {
-                        src.mDurations.addDuration(src.mActiveProcState, duration);
+                    final long addedDuration = nowUptime - src.mActiveStartUptime;
+                    src.mActiveStartUptime = nowUptime;
+                    if (src.mActiveDurations != null) {
+                        src.mActiveDurations.addDuration(src.mActiveProcState, addedDuration);
                     } else {
-                        src.mActiveDuration = duration;
+                        src.mActiveDuration += addedDuration;
                     }
-                    src.mActiveStartUptime = nowUptime;
                 }
             }
+            if (mTotalNesting > 0) {
+                mTotalDuration += nowUptime - mTotalStartUptime;
+                mTotalStartUptime = nowUptime;
+            }
+            if (mTotalActiveNesting > 0) {
+                mTotalActiveDuration += nowUptime - mTotalActiveStartUptime;
+                mTotalActiveStartUptime = nowUptime;
+            }
         }
     }
 
     public boolean hasProcessOrPackage(String procName) {
+        if (mProcessName.equals(procName)) {
+            return true;
+        }
         final int NSRC = mSources.size();
         for (int isrc = 0; isrc < NSRC; isrc++) {
             final SourceKey key = mSources.keyAt(isrc);
@@ -471,22 +624,110 @@ public final class AssociationState {
         return false;
     }
 
-    public void dumpStats(PrintWriter pw, String prefix, String prefixInner, String headerPrefix,
-            long now, long totalTime, String reqPackage, boolean dumpDetails, boolean dumpAll) {
-        if (dumpAll) {
-            pw.print(prefix);
-            pw.print("mNumActive=");
-            pw.println(mNumActive);
+    static final Comparator<Pair<SourceKey, SourceDumpContainer>> ASSOCIATION_COMPARATOR =
+            (o1, o2) -> {
+        if (o1.second.mActiveTime != o2.second.mActiveTime) {
+            return o1.second.mActiveTime > o2.second.mActiveTime ? -1 : 1;
+        }
+        if (o1.second.mTotalTime != o2.second.mTotalTime) {
+            return o1.second.mTotalTime > o2.second.mTotalTime ? -1 : 1;
+        }
+        if (o1.first.mUid != o2.first.mUid) {
+            return o1.first.mUid < o2.first.mUid ? -1 : 1;
         }
+        if (o1.first.mProcess != o2.first.mProcess) {
+            int diff = o1.first.mProcess.compareTo(o2.first.mProcess);
+            if (diff != 0) {
+                return diff;
+            }
+        }
+        return 0;
+    };
+
+    public ArrayList<Pair<SourceKey, SourceDumpContainer>> createSortedAssociations(long now,
+            long totalTime) {
         final int NSRC = mSources.size();
+        ArrayList<Pair<SourceKey, SourceDumpContainer>> sources = new ArrayList<>(NSRC);
         for (int isrc = 0; isrc < NSRC; isrc++) {
-            final SourceKey key = mSources.keyAt(isrc);
             final SourceState src = mSources.valueAt(isrc);
-            if (reqPackage != null && !reqPackage.equals(key.mProcess)
-                    && !reqPackage.equals(key.mPackage)) {
-                continue;
+            final SourceDumpContainer cont = new SourceDumpContainer(src);
+            long duration = src.mDuration;
+            if (src.mNesting > 0) {
+                duration += now - src.mStartUptime;
             }
-            pw.print(prefixInner);
+            cont.mTotalTime = duration;
+            cont.mActiveTime = dumpTime(null, null, src, totalTime, now, false, false);
+            if (cont.mActiveTime < 0) {
+                cont.mActiveTime = -cont.mActiveTime;
+            }
+            sources.add(new Pair<>(mSources.keyAt(isrc), cont));
+        }
+        Collections.sort(sources, ASSOCIATION_COMPARATOR);
+        return sources;
+    }
+
+    public void dumpStats(PrintWriter pw, String prefix, String prefixInner, String headerPrefix,
+            ArrayList<Pair<SourceKey, SourceDumpContainer>> sources, long now, long totalTime,
+            String reqPackage, boolean dumpDetails, boolean dumpAll) {
+        final String prefixInnerInner = prefixInner + "     ";
+        long totalDuration = mTotalActiveDuration;
+        if (mTotalActiveNesting > 0) {
+            totalDuration += now - mTotalActiveStartUptime;
+        }
+        if (totalDuration > 0 || mTotalActiveCount != 0) {
+            pw.print(prefix);
+            pw.print("Active count ");
+            pw.print(mTotalActiveCount);
+            if (dumpAll) {
+                pw.print(": ");
+                TimeUtils.formatDuration(totalDuration, pw);
+                pw.print(" / ");
+            } else {
+                pw.print(": time ");
+            }
+            DumpUtils.printPercent(pw, (double) totalDuration / (double) totalTime);
+            pw.println();
+        }
+        if (dumpAll && mTotalActiveNesting != 0) {
+            pw.print(prefix);
+            pw.print("mTotalActiveNesting=");
+            pw.print(mTotalActiveNesting);
+            pw.print(" mTotalActiveStartUptime=");
+            TimeUtils.formatDuration(mTotalActiveStartUptime, now, pw);
+            pw.println();
+        }
+        totalDuration = mTotalDuration;
+        if (mTotalNesting > 0) {
+            totalDuration += now - mTotalStartUptime;
+        }
+        if (totalDuration > 0 || mTotalCount != 0) {
+            pw.print(prefix);
+            pw.print("Total count ");
+            pw.print(mTotalCount);
+            if (dumpAll) {
+                pw.print(": ");
+                TimeUtils.formatDuration(totalDuration, pw);
+                pw.print(" / ");
+            } else {
+                pw.print(": time ");
+            }
+            DumpUtils.printPercent(pw, (double) totalDuration / (double) totalTime);
+            pw.println();
+        }
+        if (dumpAll && mTotalNesting != 0) {
+            pw.print(prefix);
+            pw.print("mTotalNesting=");
+            pw.print(mTotalNesting);
+            pw.print(" mTotalStartUptime=");
+            TimeUtils.formatDuration(mTotalStartUptime, now, pw);
+            pw.println();
+        }
+        final int NSRC = sources.size();
+        for (int isrc = 0; isrc < NSRC; isrc++) {
+            final SourceKey key = sources.get(isrc).first;
+            final SourceDumpContainer cont = sources.get(isrc).second;
+            final SourceState src = cont.mState;
+            pw.print(prefix);
             pw.print("<- ");
             pw.print(key.mProcess);
             pw.print("/");
@@ -496,24 +737,69 @@ public final class AssociationState {
                 pw.print(key.mPackage);
                 pw.print(")");
             }
+            // If we are skipping this one, we still print the first line just to give
+            // context for the others (so it is clear the total times for the overall
+            // association come from other sources whose times are not shown).
+            if (reqPackage != null && !reqPackage.equals(key.mProcess)
+                    && !reqPackage.equals(key.mPackage)) {
+                pw.println();
+                continue;
+            }
             pw.println(":");
+            if (src.mActiveCount != 0 || src.mActiveDurations != null || src.mActiveDuration != 0
+                    || src.mActiveStartUptime != 0) {
+                pw.print(prefixInner);
+                pw.print("   Active count ");
+                pw.print(src.mActiveCount);
+                if (dumpDetails) {
+                    if (dumpAll) {
+                        if (src.mActiveDurations != null) {
+                            pw.print(" (multi-state)");
+                        } else if (src.mActiveProcState >= ProcessStats.STATE_PERSISTENT) {
+                            pw.print(" (");
+                            pw.print(DumpUtils.STATE_NAMES[src.mActiveProcState]);
+                            pw.print(")");
+                        } else {
+                            pw.print(" (*UNKNOWN STATE*)");
+                        }
+                    }
+                    if (dumpAll) {
+                        pw.print(": ");
+                        TimeUtils.formatDuration(cont.mActiveTime, pw);
+                        pw.print(" / ");
+                    } else {
+                        pw.print(": time ");
+                    }
+                    DumpUtils.printPercent(pw, (double) cont.mActiveTime / (double) totalTime);
+                    if (src.mActiveStartUptime != 0) {
+                        pw.print(" (running)");
+                    }
+                    pw.println();
+                    if (src.mActiveDurations != null) {
+                        dumpTime(pw, prefixInnerInner, src, totalTime, now, dumpDetails, dumpAll);
+                    }
+                } else {
+                    pw.print(": ");
+                    dumpActiveDurationSummary(pw, src, totalTime, now, dumpAll);
+                }
+            }
             pw.print(prefixInner);
             pw.print("   Total count ");
             pw.print(src.mCount);
-            long duration = src.mDuration;
-            if (src.mNesting > 0) {
-                duration += now - src.mStartUptime;
-            }
             if (dumpAll) {
-                pw.print(": Duration ");
-                TimeUtils.formatDuration(duration, pw);
+                pw.print(": ");
+                TimeUtils.formatDuration(cont.mTotalTime, pw);
                 pw.print(" / ");
             } else {
                 pw.print(": time ");
             }
-            DumpUtils.printPercent(pw, (double)duration/(double)totalTime);
+            DumpUtils.printPercent(pw, (double) cont.mTotalTime / (double) totalTime);
             if (src.mNesting > 0) {
                 pw.print(" (running");
+                if (dumpAll) {
+                    pw.print(" nest=");
+                    pw.print(src.mNesting);
+                }
                 if (src.mProcState != ProcessStats.STATE_NOTHING) {
                     pw.print(" / ");
                     pw.print(DumpUtils.STATE_NAMES[src.mProcState]);
@@ -523,23 +809,6 @@ public final class AssociationState {
                 pw.print(")");
             }
             pw.println();
-            if (src.mActiveCount > 0 || src.mDurations != null || src.mActiveDuration != 0
-                    || src.mActiveStartUptime != 0) {
-                pw.print(prefixInner);
-                pw.print("   Active count ");
-                pw.print(src.mActiveCount);
-                if (dumpDetails) {
-                    if (dumpAll) {
-                        pw.print(src.mDurations != null ? " (multi-field)" : " (inline)");
-                    }
-                    pw.println(":");
-                    dumpTime(pw, prefixInner, src, totalTime, now, dumpDetails, dumpAll);
-                } else {
-                    pw.print(": ");
-                    dumpActiveDurationSummary(pw, src, totalTime, now, dumpAll);
-                    pw.println();
-                }
-            }
             if (dumpAll) {
                 if (src.mInTrackingList) {
                     pw.print(prefixInner);
@@ -565,7 +834,6 @@ public final class AssociationState {
             duration = -duration;
         }
         if (dumpAll) {
-            pw.print("Duration ");
             TimeUtils.formatDuration(duration, pw);
             pw.print(" / ");
         } else {
@@ -584,10 +852,10 @@ public final class AssociationState {
         boolean isRunning = false;
         for (int iprocstate = 0; iprocstate < ProcessStats.STATE_COUNT; iprocstate++) {
             long time;
-            if (src.mDurations != null) {
-                time = src.mDurations.getValueForId((byte)iprocstate);
+            if (src.mActiveDurations != null) {
+                time = src.mActiveDurations.getValueForId((byte) iprocstate);
             } else {
-                time = src.mActiveProcState == iprocstate ? src.mDuration : 0;
+                time = src.mActiveProcState == iprocstate ? src.mActiveDuration : 0;
             }
             final String running;
             if (src.mActiveStartUptime != 0 && src.mActiveProcState == iprocstate) {
@@ -600,11 +868,9 @@ public final class AssociationState {
             if (time != 0) {
                 if (pw != null) {
                     pw.print(prefix);
-                    pw.print("  ");
                     pw.print(DumpUtils.STATE_LABELS[iprocstate]);
                     pw.print(": ");
                     if (dumpAll) {
-                        pw.print("Duration ");
                         TimeUtils.formatDuration(time, pw);
                         pw.print(" / ");
                     } else {
@@ -619,21 +885,6 @@ public final class AssociationState {
                 totalTime += time;
             }
         }
-        if (totalTime != 0 && pw != null) {
-            pw.print(prefix);
-            pw.print("  ");
-            pw.print(DumpUtils.STATE_LABEL_TOTAL);
-            pw.print(": ");
-            if (dumpAll) {
-                pw.print("Duration ");
-                TimeUtils.formatDuration(totalTime, pw);
-                pw.print(" / ");
-            } else {
-                pw.print("time ");
-            }
-            DumpUtils.printPercent(pw, (double) totalTime / (double) overallTime);
-            pw.println();
-        }
         return isRunning ? -totalTime : totalTime;
     }
 
@@ -667,11 +918,11 @@ public final class AssociationState {
             pw.print(",");
             pw.print(src.mActiveCount);
             final long timeNow = src.mActiveStartUptime != 0 ? (now-src.mActiveStartUptime) : 0;
-            if (src.mDurations != null) {
-                final int N = src.mDurations.getKeyCount();
+            if (src.mActiveDurations != null) {
+                final int N = src.mActiveDurations.getKeyCount();
                 for (int i=0; i<N; i++) {
-                    final int dkey = src.mDurations.getKeyAt(i);
-                    duration = src.mDurations.getValue(dkey);
+                    final int dkey = src.mActiveDurations.getKeyAt(i);
+                    duration = src.mActiveDurations.getValue(dkey);
                     if (dkey == src.mActiveProcState) {
                         duration += timeNow;
                     }
@@ -718,11 +969,11 @@ public final class AssociationState {
                         src.mActiveCount);
             }
             final long timeNow = src.mActiveStartUptime != 0 ? (now-src.mActiveStartUptime) : 0;
-            if (src.mDurations != null) {
-                final int N = src.mDurations.getKeyCount();
+            if (src.mActiveDurations != null) {
+                final int N = src.mActiveDurations.getKeyCount();
                 for (int i=0; i<N; i++) {
-                    final int dkey = src.mDurations.getKeyAt(i);
-                    duration = src.mDurations.getValue(dkey);
+                    final int dkey = src.mActiveDurations.getKeyAt(i);
+                    duration = src.mActiveDurations.getValue(dkey);
                     if (dkey == src.mActiveProcState) {
                         duration += timeNow;
                     }
diff --git a/core/java/com/android/internal/app/procstats/ProcessStats.java b/core/java/com/android/internal/app/procstats/ProcessStats.java
index 8e88c510ec31..875cff8d0988 100644
--- a/core/java/com/android/internal/app/procstats/ProcessStats.java
+++ b/core/java/com/android/internal/app/procstats/ProcessStats.java
@@ -31,6 +31,7 @@ import android.util.ArrayMap;
 import android.util.ArraySet;
 import android.util.DebugUtils;
 import android.util.LongSparseArray;
+import android.util.Pair;
 import android.util.Slog;
 import android.util.SparseArray;
 import android.util.TimeUtils;
@@ -48,6 +49,7 @@ import java.io.PrintWriter;
 import java.util.ArrayList;
 import java.util.Arrays;
 import java.util.Collections;
+import java.util.Comparator;
 import java.util.Objects;
 import java.util.regex.Matcher;
 import java.util.regex.Pattern;
@@ -179,7 +181,7 @@ public final class ProcessStats implements Parcelable {
             {"proc", "pkg-proc", "pkg-svc", "pkg-asc", "pkg-all", "all"};
 
     // Current version of the parcel format.
-    private static final int PARCEL_VERSION = 36;
+    private static final int PARCEL_VERSION = 38;
     // In-memory Parcel magic number, used to detect attempts to unmarshall bad data
     private static final int MAGIC = 0x50535454;
 
@@ -196,6 +198,9 @@ public final class ProcessStats implements Parcelable {
     public int mMemFactor = STATE_NOTHING;
     public long mStartTime;
 
+    // Number of individual stats that have been aggregated to create this one.
+    public int mNumAggregated = 1;
+
     public long mTimePeriodStartClock;
     public long mTimePeriodStartRealtime;
     public long mTimePeriodEndRealtime;
@@ -348,6 +353,8 @@ public final class ProcessStats implements Parcelable {
 
         mSysMemUsage.mergeStats(other.mSysMemUsage);
 
+        mNumAggregated += other.mNumAggregated;
+
         if (other.mTimePeriodStartClock < mTimePeriodStartClock) {
             mTimePeriodStartClock = other.mTimePeriodStartClock;
             mTimePeriodStartClockStr = other.mTimePeriodStartClockStr;
@@ -569,6 +576,7 @@ public final class ProcessStats implements Parcelable {
     }
 
     private void resetCommon() {
+        mNumAggregated = 1;
         mTimePeriodStartClock = System.currentTimeMillis();
         buildTimePeriodStartClockStr();
         mTimePeriodStartRealtime = mTimePeriodEndRealtime = SystemClock.elapsedRealtime();
@@ -845,6 +853,7 @@ public final class ProcessStats implements Parcelable {
             }
         }
 
+        out.writeInt(mNumAggregated);
         out.writeLong(mTimePeriodStartClock);
         out.writeLong(mTimePeriodStartRealtime);
         out.writeLong(mTimePeriodEndRealtime);
@@ -1031,6 +1040,7 @@ public final class ProcessStats implements Parcelable {
 
         mIndexToCommonString = new ArrayList<String>();
 
+        mNumAggregated = in.readInt();
         mTimePeriodStartClock = in.readLong();
         buildTimePeriodStartClockStr();
         mTimePeriodStartRealtime = in.readLong();
@@ -1457,15 +1467,79 @@ public final class ProcessStats implements Parcelable {
         }
     }
 
+    final class AssociationDumpContainer {
+        final AssociationState mState;
+        ArrayList<Pair<AssociationState.SourceKey, AssociationState.SourceDumpContainer>> mSources;
+        long mTotalTime;
+        long mActiveTime;
+
+        AssociationDumpContainer(AssociationState state) {
+            mState = state;
+        }
+    }
+
+    static final Comparator<AssociationDumpContainer> ASSOCIATION_COMPARATOR = (o1, o2) -> {
+        int diff = o1.mState.getProcessName().compareTo(o2.mState.getProcessName());
+        if (diff != 0) {
+            return diff;
+        }
+        if (o1.mActiveTime != o2.mActiveTime) {
+            return o1.mActiveTime > o2.mActiveTime ? -1 : 1;
+        }
+        if (o1.mTotalTime != o2.mTotalTime) {
+            return o1.mTotalTime > o2.mTotalTime ? -1 : 1;
+        }
+        diff = o1.mState.getName().compareTo(o2.mState.getName());
+        if (diff != 0) {
+            return diff;
+        }
+        return 0;
+    };
+
     public void dumpLocked(PrintWriter pw, String reqPackage, long now, boolean dumpSummary,
             boolean dumpDetails, boolean dumpAll, boolean activeOnly, int section) {
         long totalTime = DumpUtils.dumpSingleTime(null, null, mMemFactorDurations, mMemFactor,
                 mStartTime, now);
-        boolean sepNeeded = false;
+        pw.print("          Start time: ");
+        pw.print(DateFormat.format("yyyy-MM-dd HH:mm:ss", mTimePeriodStartClock));
+        pw.println();
+        pw.print("        Total uptime: ");
+        TimeUtils.formatDuration(
+                (mRunning ? SystemClock.uptimeMillis() : mTimePeriodEndUptime)
+                        - mTimePeriodStartUptime, pw);
+        pw.println();
+        pw.print("  Total elapsed time: ");
+        TimeUtils.formatDuration(
+                (mRunning ? SystemClock.elapsedRealtime() : mTimePeriodEndRealtime)
+                        - mTimePeriodStartRealtime, pw);
+        boolean partial = true;
+        if ((mFlags & FLAG_SHUTDOWN) != 0) {
+            pw.print(" (shutdown)");
+            partial = false;
+        }
+        if ((mFlags & FLAG_SYSPROPS) != 0) {
+            pw.print(" (sysprops)");
+            partial = false;
+        }
+        if ((mFlags & FLAG_COMPLETE) != 0) {
+            pw.print(" (complete)");
+            partial = false;
+        }
+        if (partial) {
+            pw.print(" (partial)");
+        }
+        if (mHasSwappedOutPss) {
+            pw.print(" (swapped-out-pss)");
+        }
+        pw.print(' ');
+        pw.print(mRuntime);
+        pw.println();
+        pw.print("     Aggregated over: ");
+        pw.println(mNumAggregated);
         if (mSysMemUsage.getKeyCount() > 0) {
+            pw.println();
             pw.println("System memory usage:");
             mSysMemUsage.dump(pw, "  ", ALL_SCREEN_ADJ, ALL_MEM_ADJ);
-            sepNeeded = true;
         }
         boolean printedHeader = false;
         if ((section & REPORT_PKG_STATS) != 0) {
@@ -1485,8 +1559,8 @@ public final class ProcessStats implements Parcelable {
                         final int NASCS = pkgState.mAssociations.size();
                         final boolean pkgMatch = reqPackage == null || reqPackage.equals(pkgName);
                         boolean onlyAssociations = false;
+                        boolean procMatch = false;
                         if (!pkgMatch) {
-                            boolean procMatch = false;
                             for (int iproc = 0; iproc < NPROCS; iproc++) {
                                 ProcessState proc = pkgState.mProcesses.valueAt(iproc);
                                 if (reqPackage.equals(proc.getName())) {
@@ -1511,10 +1585,9 @@ public final class ProcessStats implements Parcelable {
                         }
                         if (NPROCS > 0 || NSRVS > 0 || NASCS > 0) {
                             if (!printedHeader) {
-                                if (sepNeeded) pw.println();
+                                pw.println();
                                 pw.println("Per-Package Stats:");
                                 printedHeader = true;
-                                sepNeeded = true;
                             }
                             pw.print("  * ");
                             pw.print(pkgName);
@@ -1597,6 +1670,8 @@ public final class ProcessStats implements Parcelable {
                             }
                         }
                         if ((section & REPORT_PKG_ASC_STATS) != 0) {
+                            ArrayList<AssociationDumpContainer> associations =
+                                    new ArrayList<>(NASCS);
                             for (int iasc = 0; iasc < NASCS; iasc++) {
                                 AssociationState asc = pkgState.mAssociations.valueAt(iasc);
                                 if (!pkgMatch && !reqPackage.equals(asc.getProcessName())) {
@@ -1604,6 +1679,18 @@ public final class ProcessStats implements Parcelable {
                                         continue;
                                     }
                                 }
+                                final AssociationDumpContainer cont =
+                                        new AssociationDumpContainer(asc);
+                                cont.mSources = asc.createSortedAssociations(now, totalTime);
+                                cont.mTotalTime = asc.getTotalDuration(now);
+                                cont.mActiveTime = asc.getActiveDuration(now);
+                                associations.add(cont);
+                            }
+                            Collections.sort(associations, ASSOCIATION_COMPARATOR);
+                            final int NCONT = associations.size();
+                            for (int iasc = 0; iasc < NCONT; iasc++) {
+                                final AssociationDumpContainer cont = associations.get(iasc);
+                                final AssociationState asc = cont.mState;
                                 if (activeOnly && !asc.isInUse()) {
                                     pw.print("      (Not active association: ");
                                     pw.print(pkgState.mAssociations.keyAt(iasc));
@@ -1615,13 +1702,15 @@ public final class ProcessStats implements Parcelable {
                                 } else {
                                     pw.print("      * Asc ");
                                 }
-                                pw.print(pkgState.mAssociations.keyAt(iasc));
+                                pw.print(cont.mState.getName());
                                 pw.println(":");
                                 pw.print("        Process: ");
                                 pw.println(asc.getProcessName());
                                 asc.dumpStats(pw, "        ", "          ", "    ",
-                                        now, totalTime, onlyAssociations ? reqPackage : null,
-                                        dumpDetails, dumpAll);
+                                        cont.mSources, now, totalTime,
+                                        onlyAssociations && !pkgMatch && !procMatch
+                                                && !asc.getProcessName().equals(reqPackage)
+                                                ? reqPackage : null, dumpDetails, dumpAll);
                             }
                         }
                     }
@@ -1651,10 +1740,7 @@ public final class ProcessStats implements Parcelable {
                         continue;
                     }
                     numShownProcs++;
-                    if (sepNeeded) {
-                        pw.println();
-                    }
-                    sepNeeded = true;
+                    pw.println();
                     if (!printedHeader) {
                         pw.println("Multi-Package Common Processes:");
                         printedHeader = true;
@@ -1684,11 +1770,7 @@ public final class ProcessStats implements Parcelable {
         }
 
         if (dumpAll) {
-            if (sepNeeded) {
-                pw.println();
-            }
-            sepNeeded = true;
-
+            pw.println();
             if (mTrackingAssociations.size() > 0) {
                 pw.println();
                 pw.println("Tracking associations:");
@@ -1734,9 +1816,7 @@ public final class ProcessStats implements Parcelable {
             }
         }
 
-        if (sepNeeded) {
-            pw.println();
-        }
+        pw.println();
         if (dumpSummary) {
             pw.println("Process summary:");
             dumpSummaryLocked(pw, reqPackage, now, activeOnly);
@@ -1861,41 +1941,6 @@ public final class ProcessStats implements Parcelable {
         pw.print("x over ");
         TimeUtils.formatDuration(mExternalSlowPssTime, pw);
         pw.println();
-        pw.println();
-        pw.print("          Start time: ");
-        pw.print(DateFormat.format("yyyy-MM-dd HH:mm:ss", mTimePeriodStartClock));
-        pw.println();
-        pw.print("        Total uptime: ");
-        TimeUtils.formatDuration(
-                (mRunning ? SystemClock.uptimeMillis() : mTimePeriodEndUptime)
-                        - mTimePeriodStartUptime, pw);
-        pw.println();
-        pw.print("  Total elapsed time: ");
-        TimeUtils.formatDuration(
-                (mRunning ? SystemClock.elapsedRealtime() : mTimePeriodEndRealtime)
-                        - mTimePeriodStartRealtime, pw);
-        boolean partial = true;
-        if ((mFlags&FLAG_SHUTDOWN) != 0) {
-            pw.print(" (shutdown)");
-            partial = false;
-        }
-        if ((mFlags&FLAG_SYSPROPS) != 0) {
-            pw.print(" (sysprops)");
-            partial = false;
-        }
-        if ((mFlags&FLAG_COMPLETE) != 0) {
-            pw.print(" (complete)");
-            partial = false;
-        }
-        if (partial) {
-            pw.print(" (partial)");
-        }
-        if (mHasSwappedOutPss) {
-            pw.print(" (swapped-out-pss)");
-        }
-        pw.print(' ');
-        pw.print(mRuntime);
-        pw.println();
     }
 
     void dumpFilteredSummaryLocked(PrintWriter pw, String header, String prefix, String prcLabel,
diff --git a/services/core/java/com/android/server/am/ProcessStatsService.java b/services/core/java/com/android/server/am/ProcessStatsService.java
index 6ffd8a9180ba..5c840ada86d4 100644
--- a/services/core/java/com/android/server/am/ProcessStatsService.java
+++ b/services/core/java/com/android/server/am/ProcessStatsService.java
@@ -1101,7 +1101,7 @@ public final class ProcessStatsService extends IProcessStats.Stub {
         }
 
         boolean sepNeeded = false;
-        if (dumpAll || isCheckin) {
+        if ((dumpAll || isCheckin) && !currentOnly) {
             mWriteLock.lock();
             try {
                 ArrayList<String> files = getCommittedFiles(0, false, !isCheckin);