From 9db78024c505a841256ec524bed1fe8fdbecd4f5 Mon Sep 17 00:00:00 2001
From: Tom Cherry <tomcherry@google.com>
Date: Thu, 23 Jul 2020 09:40:51 -0700
Subject: [PATCH] Log only a summary 'Found stale backup journal' message.

With the goal of reducing log spam, print only a summary 'Found stale
backup journal' messages instead of logging within the inner loop.
Previously, over 12k messages could be printed at a time from this
function.

Before this CL:
 - a backup was scheduled for each packageName from each stale
   journal
 - one (or two, if MORE_DEBUG) message was logged for each
   packageName in each journal file.

After this CL:

 - packageNames are de-duplicated before scheduling backups or logging
   (it's not clear to me whether duplicate packageNames previously
   occurred, in practice).
 - one message is logged for the number (if > 0) of stale journals.
 - one message is logged for the number (including their names, if
   MORE_DEBUG) of packages.

Bug: 161940947
Test: fewer 'Found state backup journal' messages printed
Merged-In: Ia1343e4cea31feb1eba9da561d20736eb5df0a14
Change-Id: Ia1343e4cea31feb1eba9da561d20736eb5df0a14
---
 .../backup/UserBackupManagerService.java      | 31 +++++++++++++------
 1 file changed, 22 insertions(+), 9 deletions(-)

diff --git a/services/backup/java/com/android/server/backup/UserBackupManagerService.java b/services/backup/java/com/android/server/backup/UserBackupManagerService.java
index 2554433fb6598..c17aa4ecabbbc 100644
--- a/services/backup/java/com/android/server/backup/UserBackupManagerService.java
+++ b/services/backup/java/com/android/server/backup/UserBackupManagerService.java
@@ -156,6 +156,7 @@ import java.util.Collections;
 import java.util.Date;
 import java.util.HashMap;
 import java.util.HashSet;
+import java.util.LinkedHashSet;
 import java.util.LinkedList;
 import java.util.List;
 import java.util.Queue;
@@ -1084,19 +1085,31 @@ public class UserBackupManagerService {
 
     private void parseLeftoverJournals() {
         ArrayList<DataChangedJournal> journals = DataChangedJournal.listJournals(mJournalDir);
+        // TODO(b/162022005): Fix DataChangedJournal implementing equals() but not hashCode().
+        journals.removeAll(Collections.singletonList(mJournal));
+        if (!journals.isEmpty()) {
+            Slog.i(TAG, "Found " + journals.size() + " stale backup journal(s), scheduling.");
+        }
+        Set<String> packageNames = new LinkedHashSet<>();
         for (DataChangedJournal journal : journals) {
-            if (!journal.equals(mJournal)) {
-                try {
-                    journal.forEach(packageName -> {
-                        Slog.i(TAG, "Found stale backup journal, scheduling");
-                        if (MORE_DEBUG) Slog.i(TAG, "  " + packageName);
+            try {
+                journal.forEach(packageName -> {
+                    if (packageNames.add(packageName)) {
                         dataChangedImpl(packageName);
-                    });
-                } catch (IOException e) {
-                    Slog.e(TAG, "Can't read " + journal, e);
-                }
+                    }
+                });
+            } catch (IOException e) {
+                Slog.e(TAG, "Can't read " + journal, e);
             }
         }
+        if (!packageNames.isEmpty()) {
+            String msg = "Stale backup journals: Scheduled " + packageNames.size()
+                    + " package(s) total";
+            if (MORE_DEBUG) {
+                msg += ": " + packageNames;
+            }
+            Slog.i(TAG, msg);
+        }
     }
 
     /** Used for generating random salts or passwords. */