Reduce UsageStats logspam.

When there are parsing errors while deobfuscating usage stats, it can
produce a lot of error logs. Condense and reduce the logging to a
minimal amount.

Also, keep track of the recently removed package tokens and dump them
to help debug these parsing errors.

Bug: 177610601
Test: adb shell dumpsys usagestats mappings 0
Change-Id: I860ee4b24d2ff2df88e536edca81920256257198

services/usage/java/com/android/server/usage/IntervalStats.java

@@ -54,6 +54,7 @@ import android.util.proto.ProtoInputStream;
 import com.android.internal.annotations.VisibleForTesting;
 
 import java.io.IOException;
+import java.util.Arrays;
 import java.util.List;
 
 public class IntervalStats {
@@ -459,13 +460,14 @@ public class IntervalStats {
      */
     private boolean deobfuscateUsageStats(PackagesTokenData packagesTokenData) {
         boolean dataOmitted = false;
+        final ArraySet<Integer> omittedTokens = new ArraySet<>();
         final int usageStatsSize = packageStatsObfuscated.size();
         for (int statsIndex = 0; statsIndex < usageStatsSize; statsIndex++) {
             final int packageToken = packageStatsObfuscated.keyAt(statsIndex);
             final UsageStats usageStats = packageStatsObfuscated.valueAt(statsIndex);
             usageStats.mPackageName = packagesTokenData.getPackageString(packageToken);
             if (usageStats.mPackageName == null) {
-                Slog.e(TAG, "Unable to parse usage stats package " + packageToken);
+                omittedTokens.add(packageToken);
                 dataOmitted = true;
                 continue;
             }
@@ -477,8 +479,6 @@ public class IntervalStats {
                 final int actionToken = usageStats.mChooserCountsObfuscated.keyAt(actionIndex);
                 final String action = packagesTokenData.getString(packageToken, actionToken);
                 if (action == null) {
-                    Slog.i(TAG, "Unable to parse chooser action " + actionToken
-                            + " for package " + packageToken);
                     continue;
                 }
                 final SparseIntArray categoryCounts =
@@ -489,8 +489,6 @@ public class IntervalStats {
                     final String category = packagesTokenData.getString(packageToken,
                             categoryToken);
                     if (category == null) {
-                        Slog.i(TAG, "Unable to parse chooser category " + categoryToken
-                                + " for package " + packageToken);
                         continue;
                     }
                     categoryCountsMap.put(category, categoryCounts.valueAt(categoryIndex));
@@ -499,6 +497,10 @@ public class IntervalStats {
             }
             packageStats.put(usageStats.mPackageName, usageStats);
         }
+        if (dataOmitted) {
+            Slog.d(TAG, "Unable to parse usage stats packages: "
+                    + Arrays.toString(omittedTokens.toArray()));
+        }
         return dataOmitted;
     }
 
@@ -511,12 +513,13 @@ public class IntervalStats {
      */
     private boolean deobfuscateEvents(PackagesTokenData packagesTokenData) {
         boolean dataOmitted = false;
+        final ArraySet<Integer> omittedTokens = new ArraySet<>();
         for (int i = this.events.size() - 1; i >= 0; i--) {
             final Event event = this.events.get(i);
             final int packageToken = event.mPackageToken;
             event.mPackage = packagesTokenData.getPackageString(packageToken);
             if (event.mPackage == null) {
-                Slog.e(TAG, "Unable to parse event package " + packageToken);
+                omittedTokens.add(packageToken);
                 this.events.remove(i);
                 dataOmitted = true;
                 continue;
@@ -524,26 +527,14 @@ public class IntervalStats {
 
             if (event.mClassToken != PackagesTokenData.UNASSIGNED_TOKEN) {
                 event.mClass = packagesTokenData.getString(packageToken, event.mClassToken);
-                if (event.mClass == null) {
-                    Slog.i(TAG, "Unable to parse class " + event.mClassToken
-                            + " for package " + packageToken);
-                }
             }
             if (event.mTaskRootPackageToken != PackagesTokenData.UNASSIGNED_TOKEN) {
                 event.mTaskRootPackage = packagesTokenData.getString(packageToken,
                         event.mTaskRootPackageToken);
-                if (event.mTaskRootPackage == null) {
-                    Slog.i(TAG, "Unable to parse task root package " + event.mTaskRootPackageToken
-                            + " for package " + packageToken);
-                }
             }
             if (event.mTaskRootClassToken != PackagesTokenData.UNASSIGNED_TOKEN) {
                 event.mTaskRootClass = packagesTokenData.getString(packageToken,
                         event.mTaskRootClassToken);
-                if (event.mTaskRootClass == null) {
-                    Slog.i(TAG, "Unable to parse task root class " + event.mTaskRootClassToken
-                            + " for package " + packageToken);
-                }
             }
             switch (event.mEventType) {
                 case CONFIGURATION_CHANGE:
@@ -555,7 +546,7 @@ public class IntervalStats {
                     event.mShortcutId = packagesTokenData.getString(packageToken,
                             event.mShortcutIdToken);
                     if (event.mShortcutId == null) {
-                        Slog.e(TAG, "Unable to parse shortcut " + event.mShortcutIdToken
+                        Slog.v(TAG, "Unable to parse shortcut " + event.mShortcutIdToken
                                 + " for package " + packageToken);
                         this.events.remove(i);
                         dataOmitted = true;
@@ -566,7 +557,7 @@ public class IntervalStats {
                     event.mNotificationChannelId = packagesTokenData.getString(packageToken,
                             event.mNotificationChannelIdToken);
                     if (event.mNotificationChannelId == null) {
-                        Slog.e(TAG, "Unable to parse notification channel "
+                        Slog.v(TAG, "Unable to parse notification channel "
                                 + event.mNotificationChannelIdToken + " for package "
                                 + packageToken);
                         this.events.remove(i);
@@ -577,7 +568,7 @@ public class IntervalStats {
                 case LOCUS_ID_SET:
                     event.mLocusId = packagesTokenData.getString(packageToken, event.mLocusIdToken);
                     if (event.mLocusId == null) {
-                        Slog.e(TAG, "Unable to parse locus " + event.mLocusIdToken
+                        Slog.v(TAG, "Unable to parse locus " + event.mLocusIdToken
                                 + " for package " + packageToken);
                         this.events.remove(i);
                         dataOmitted = true;
@@ -586,6 +577,10 @@ public class IntervalStats {
                     break;
             }
         }
+        if (dataOmitted) {
+            Slog.d(TAG, "Unable to parse event packages: "
+                    + Arrays.toString(omittedTokens.toArray()));
+        }
         return dataOmitted;
     }
 

services/usage/java/com/android/server/usage/PackagesTokenData.java

@@ -16,6 +16,7 @@
 package com.android.server.usage;
 
 import android.util.ArrayMap;
+import android.util.ArraySet;
 import android.util.Slog;
 import android.util.SparseArray;
 
@@ -56,6 +57,11 @@ public final class PackagesTokenData {
      * Stores a map of packages that were removed and when they were removed.
      */
     public final ArrayMap<String, Long> removedPackagesMap = new ArrayMap<>();
+    /**
+     * Stores a set of removed package tokens. This is solely for dump purposes when comparing
+     * parsing errors to recently removed packages.
+     */
+    public final ArraySet<Integer> removedPackageTokens = new ArraySet<>();
 
     public PackagesTokenData() {
     }
@@ -174,6 +180,7 @@ public final class PackagesTokenData {
         final int packageToken = packagesToTokensMap.get(packageName).get(packageName);
         packagesToTokensMap.remove(packageName);
         tokensToPackagesMap.delete(packageToken);
+        removedPackageTokens.add(packageToken);
         return packageToken;
     }
 }

services/usage/java/com/android/server/usage/UsageStatsDatabase.java

@@ -53,6 +53,7 @@ import java.io.OutputStream;
 import java.nio.file.Files;
 import java.nio.file.StandardCopyOption;
 import java.util.ArrayList;
+import java.util.Arrays;
 import java.util.HashMap;
 import java.util.List;
 
@@ -1500,6 +1501,10 @@ public class UsageStatsDatabase {
             pw.increaseIndent();
             pw.println("Counter: " + mPackagesTokenData.counter);
             pw.println("Tokens Map Size: " + mPackagesTokenData.tokensToPackagesMap.size());
+            if (!mPackagesTokenData.removedPackageTokens.isEmpty()) {
+                pw.println("Removed Package Tokens: "
+                        + Arrays.toString(mPackagesTokenData.removedPackageTokens.toArray()));
+            }
             for (int i = 0; i < mPackagesTokenData.tokensToPackagesMap.size(); i++) {
                 final int packageToken = mPackagesTokenData.tokensToPackagesMap.keyAt(i);
                 final String packageStrings = String.join(", ",