Merge "Increase BMM logging coverage for restore at install flow" into 24D1-dev am: 6afb3e754e

Original change: https://googleplex-android-review.googlesource.com/c/platform/frameworks/base/+/26748034

Change-Id: I5216ce32ba2c6b7db3e8cbe1dd8af816f958455d
Signed-off-by: Automerger Merge Worker <android-build-automerger-merge-worker@system.gserviceaccount.com>

4 files changed, 134 insertions, 22 deletions

diff --git a/services/backup/java/com/android/server/backup/UserBackupManagerService.java b/services/backup/java/com/android/server/backup/UserBackupManagerService.java
index 976504a8d880..dc1cfb92c3b8 100644
--- a/services/backup/java/com/android/server/backup/UserBackupManagerService.java
+++ b/services/backup/java/com/android/server/backup/UserBackupManagerService.java
@@ -3903,11 +3903,33 @@ public class UserBackupManagerService {
             skip = true;
         }
 
+        BackupManagerMonitorEventSender  mBMMEventSender =
+                getBMMEventSender(/*monitor=*/ null);
+        PackageInfo packageInfo = getPackageInfoForBMMLogging(packageName);
         TransportConnection transportConnection =
                 mTransportManager.getCurrentTransportClient("BMS.restoreAtInstall()");
         if (transportConnection == null) {
             if (DEBUG) Slog.w(TAG, addUserIdToLogMessage(mUserId, "No transport client"));
             skip = true;
+        } else if (Flags.enableIncreasedBmmLoggingForRestoreAtInstall()) {
+            try {
+                BackupTransportClient transportClient = transportConnection.connectOrThrow(
+                        "BMS.restoreAtInstall");
+                mBMMEventSender.setMonitor(transportClient.getBackupManagerMonitor());
+            } catch (TransportNotAvailableException | RemoteException e) {
+                mBMMEventSender.monitorEvent(
+                        BackupManagerMonitor.LOG_EVENT_ID_TRANSPORT_IS_NULL, packageInfo,
+                        BackupManagerMonitor.LOG_EVENT_CATEGORY_TRANSPORT, null);
+            }
+        }
+
+        if (Flags.enableIncreasedBmmLoggingForRestoreAtInstall()) {
+            mBMMEventSender.monitorEvent(
+                    BackupManagerMonitor.LOG_EVENT_ID_RESTORE_AT_INSTALL_INVOKED, packageInfo,
+                    BackupManagerMonitor.LOG_EVENT_CATEGORY_BACKUP_MANAGER_POLICY,
+                    mBMMEventSender.putMonitoringExtra(/*extras=*/null,
+                            BackupManagerMonitor.EXTRA_LOG_OPERATION_TYPE,
+                            BackupAnnotations.OperationType.RESTORE));
         }
 
         if (!mAutoRestore) {
@@ -3943,7 +3965,7 @@ public class UserBackupManagerService {
                         RestoreParams.createForRestoreAtInstall(
                                 transportConnection,
                                 /* observer */ null,
-                                /* monitor */ null,
+                                mBMMEventSender.getMonitor(),
                                 restoreSet,
                                 packageName,
                                 token,
@@ -3963,6 +3985,15 @@ public class UserBackupManagerService {
         if (skip) {
             // Auto-restore disabled or no way to attempt a restore
 
+            if (Flags.enableIncreasedBmmLoggingForRestoreAtInstall()) {
+                mBMMEventSender.monitorEvent(
+                        BackupManagerMonitor.LOG_EVENT_ID_SKIP_RESTORE_AT_INSTALL, packageInfo,
+                        BackupManagerMonitor.LOG_EVENT_CATEGORY_BACKUP_MANAGER_POLICY,
+                        mBMMEventSender.putMonitoringExtra(/*extras=*/null,
+                                BackupManagerMonitor.EXTRA_LOG_OPERATION_TYPE,
+                                BackupAnnotations.OperationType.RESTORE));
+            }
+
             if (transportConnection != null) {
                 mTransportManager.disposeOfTransportClient(
                         transportConnection, "BMS.restoreAtInstall()");
@@ -3976,6 +4007,23 @@ public class UserBackupManagerService {
         }
     }
 
+    private PackageInfo getPackageInfoForBMMLogging(String packageName) {
+        try {
+            return mPackageManager.getPackageInfoAsUser(packageName, 0, mUserId);
+        } catch (NameNotFoundException e) {
+            Slog.w(
+                    TAG,
+                    addUserIdToLogMessage(
+                            mUserId, "Asked to get PackageInfo for BMM logging of nonexistent pkg "
+                                    + packageName));
+
+            PackageInfo packageInfo = new PackageInfo();
+            packageInfo.packageName = packageName;
+
+            return packageInfo;
+        }
+    }
+
     /** Hand off a restore session. */
     public IRestoreSession beginRestoreSession(String packageName, String transport) {
         if (DEBUG) {
diff --git a/services/backup/java/com/android/server/backup/restore/FullRestoreEngine.java b/services/backup/java/com/android/server/backup/restore/FullRestoreEngine.java
index 2c9eb51972af..b414b252cc37 100644
--- a/services/backup/java/com/android/server/backup/restore/FullRestoreEngine.java
+++ b/services/backup/java/com/android/server/backup/restore/FullRestoreEngine.java
@@ -29,6 +29,7 @@ import android.app.ApplicationThreadConstants;
 import android.app.IBackupAgent;
 import android.app.backup.BackupAgent;
 import android.app.backup.BackupAnnotations;
+import android.app.backup.BackupManagerMonitor;
 import android.app.backup.FullBackup;
 import android.app.backup.IBackupManagerMonitor;
 import android.app.backup.IFullBackupRestoreObserver;
@@ -57,6 +58,7 @@ import com.android.server.backup.OperationStorage.OpType;
 import com.android.server.backup.UserBackupManagerService;
 import com.android.server.backup.fullbackup.FullBackupObbConnection;
 import com.android.server.backup.utils.BackupEligibilityRules;
+import com.android.server.backup.utils.BackupManagerMonitorEventSender;
 import com.android.server.backup.utils.BytesReadListener;
 import com.android.server.backup.utils.FullBackupRestoreObserverUtils;
 import com.android.server.backup.utils.RestoreUtils;
@@ -143,6 +145,8 @@ public class FullRestoreEngine extends RestoreEngine {
 
     private FileMetadata mReadOnlyParent = null;
 
+    private BackupManagerMonitorEventSender mBackupManagerMonitorEventSender;
+
     public FullRestoreEngine(
             UserBackupManagerService backupManagerService, OperationStorage operationStorage,
             BackupRestoreTask monitorTask, IFullBackupRestoreObserver observer,
@@ -155,6 +159,7 @@ public class FullRestoreEngine extends RestoreEngine {
         mMonitorTask = monitorTask;
         mObserver = observer;
         mMonitor = monitor;
+        mBackupManagerMonitorEventSender = new BackupManagerMonitorEventSender(monitor);
         mOnlyPackage = onlyPackage;
         mAllowApks = allowApks;
         mAgentTimeoutParameters = Objects.requireNonNull(
@@ -225,6 +230,9 @@ public class FullRestoreEngine extends RestoreEngine {
                     // one app's data but see a different app's on the wire
                     if (onlyPackage != null) {
                         if (!pkg.equals(onlyPackage.packageName)) {
+                            logBMMEvent(
+                                    BackupManagerMonitor.LOG_EVENT_ID_RESTORE_DATA_DOES_NOT_BELONG_TO_PACKAGE,
+                                    onlyPackage);
                             Slog.w(TAG, "Expected data for " + onlyPackage + " but saw " + pkg);
                             setResult(RestoreEngine.TRANSPORT_FAILURE);
                             setRunning(false);
@@ -412,6 +420,9 @@ public class FullRestoreEngine extends RestoreEngine {
                         }
 
                         if (mAgent == null) {
+                            logBMMEvent(
+                                    BackupManagerMonitor.LOG_EVENT_ID_UNABLE_TO_CREATE_AGENT_FOR_RESTORE,
+                                    onlyPackage);
                             Slog.e(TAG, "Unable to create agent for " + pkg);
                             okay = false;
                             tearDownPipes();
@@ -501,6 +512,9 @@ public class FullRestoreEngine extends RestoreEngine {
                         } catch (RemoteException e) {
                             // whoops, remote entity went away.  We'll eat the content
                             // ourselves, then, and not copy it over.
+                            logBMMEvent(
+                                    BackupManagerMonitor.LOG_EVENT_ID_AGENT_CRASHED_BEFORE_RESTORE_DATA_IS_SENT,
+                                    onlyPackage);
                             Slog.e(TAG, "Agent crashed during full restore");
                             agentSuccess = false;
                             okay = false;
@@ -531,6 +545,9 @@ public class FullRestoreEngine extends RestoreEngine {
                                     } catch (IOException e) {
                                         Slog.e(TAG, "Failed to write to restore pipe: "
                                                 + e.getMessage());
+                                        logBMMEvent(
+                                                BackupManagerMonitor.LOG_EVENT_ID_FAILED_TO_SEND_DATA_TO_AGENT_DURING_RESTORE,
+                                                onlyPackage);
                                         pipeOkay = false;
                                     }
                                 }
@@ -548,6 +565,8 @@ public class FullRestoreEngine extends RestoreEngine {
                         // okay, if the remote end failed at any point, deal with
                         // it by ignoring the rest of the restore on it
                         if (!agentSuccess) {
+                            logBMMEvent(BackupManagerMonitor.LOG_EVENT_ID_AGENT_FAILURE_DURING_RESTORE,
+                                    onlyPackage);
                             Slog.w(TAG, "Agent failure restoring " + pkg + "; ending restore");
                             mBackupManagerService.getBackupHandler().removeMessages(
                                     MSG_RESTORE_OPERATION_TIMEOUT);
@@ -590,6 +609,8 @@ public class FullRestoreEngine extends RestoreEngine {
             if (DEBUG) {
                 Slog.w(TAG, "io exception on restore socket read: " + e.getMessage());
             }
+            logBMMEvent(BackupManagerMonitor.LOG_EVENT_ID_FAILED_TO_READ_DATA_FROM_TRANSPORT,
+                    onlyPackage);
             setResult(RestoreEngine.TRANSPORT_FAILURE);
             info = null;
         }
@@ -631,6 +652,16 @@ public class FullRestoreEngine extends RestoreEngine {
         return false;
     }
 
+    private void logBMMEvent(int eventId, PackageInfo pkgInfo) {
+        if (Flags.enableIncreasedBmmLoggingForRestoreAtInstall()) {
+            mBackupManagerMonitorEventSender.monitorEvent(eventId, pkgInfo,
+                    BackupManagerMonitor.LOG_EVENT_CATEGORY_BACKUP_MANAGER_POLICY,
+                    mBackupManagerMonitorEventSender.putMonitoringExtra(/*extras=*/
+                            null, BackupManagerMonitor.EXTRA_LOG_OPERATION_TYPE,
+                            BackupAnnotations.OperationType.RESTORE));
+        }
+    }
+
     private static boolean isValidParent(FileMetadata parentDir, @NonNull FileMetadata childDir) {
         return parentDir != null
                 && childDir.packageName.equals(parentDir.packageName)
diff --git a/services/backup/java/com/android/server/backup/restore/PerformUnifiedRestoreTask.java b/services/backup/java/com/android/server/backup/restore/PerformUnifiedRestoreTask.java
index 8fece8257b89..e536876f6cc3 100644
--- a/services/backup/java/com/android/server/backup/restore/PerformUnifiedRestoreTask.java
+++ b/services/backup/java/com/android/server/backup/restore/PerformUnifiedRestoreTask.java
@@ -418,25 +418,6 @@ public class PerformUnifiedRestoreTask implements BackupRestoreTask {
     private void startRestore() {
         sendStartRestore(mAcceptSet.size());
 
-        // If we're starting a full-system restore, set up to begin widget ID remapping
-        if (mIsSystemRestore) {
-            AppWidgetBackupBridge.systemRestoreStarting(mUserId);
-            Bundle monitoringExtras = addRestoreOperationTypeToEvent(/* extras= */ null);
-            mBackupManagerMonitorEventSender.monitorEvent(
-                    BackupManagerMonitor.LOG_EVENT_ID_START_SYSTEM_RESTORE,
-                    null,
-                    BackupManagerMonitor.LOG_EVENT_CATEGORY_BACKUP_MANAGER_POLICY,
-                    monitoringExtras);
-        } else {
-            // We are either performing RestoreAtInstall or Bmgr.
-            Bundle monitoringExtras = addRestoreOperationTypeToEvent(/* extras= */ null);
-            mBackupManagerMonitorEventSender.monitorEvent(
-                    BackupManagerMonitor.LOG_EVENT_ID_START_RESTORE_AT_INSTALL,
-                    null,
-                    BackupManagerMonitor.LOG_EVENT_CATEGORY_BACKUP_MANAGER_POLICY,
-                    monitoringExtras);
-        }
-
         try {
             String transportDirName =
                     mTransportManager.getTransportDirName(
@@ -459,6 +440,34 @@ public class PerformUnifiedRestoreTask implements BackupRestoreTask {
                 mBackupManagerMonitorEventSender.setMonitor(transport.getBackupManagerMonitor());
             }
 
+            if (Flags.enableIncreasedBmmLoggingForRestoreAtInstall()) {
+                for (PackageInfo info : mAcceptSet) {
+                    mBackupManagerMonitorEventSender.monitorEvent(
+                            BackupManagerMonitor.LOG_EVENT_ID_PACKAGE_ACCEPTED_FOR_RESTORE, info,
+                            BackupManagerMonitor.LOG_EVENT_CATEGORY_BACKUP_MANAGER_POLICY,
+                            addRestoreOperationTypeToEvent(/* extras= */ null));
+                }
+            }
+
+            // If we're starting a full-system restore, set up to begin widget ID remapping
+            if (mIsSystemRestore) {
+                AppWidgetBackupBridge.systemRestoreStarting(mUserId);
+                Bundle monitoringExtras = addRestoreOperationTypeToEvent(/* extras= */ null);
+                mBackupManagerMonitorEventSender.monitorEvent(
+                        BackupManagerMonitor.LOG_EVENT_ID_START_SYSTEM_RESTORE,
+                        null,
+                        BackupManagerMonitor.LOG_EVENT_CATEGORY_BACKUP_MANAGER_POLICY,
+                        monitoringExtras);
+            } else {
+                // We are either performing RestoreAtInstall or Bmgr.
+                Bundle monitoringExtras = addRestoreOperationTypeToEvent(/* extras= */ null);
+                mBackupManagerMonitorEventSender.monitorEvent(
+                        BackupManagerMonitor.LOG_EVENT_ID_START_RESTORE_AT_INSTALL,
+                        null,
+                        BackupManagerMonitor.LOG_EVENT_CATEGORY_BACKUP_MANAGER_POLICY,
+                        monitoringExtras);
+            }
+
             mStatus = transport.startRestore(mToken, packages);
             if (mStatus != BackupTransport.TRANSPORT_OK) {
                 Slog.e(TAG, "Transport error " + mStatus + "; no restore possible");
@@ -638,7 +647,7 @@ public class PerformUnifiedRestoreTask implements BackupRestoreTask {
                 Bundle monitoringExtras = addRestoreOperationTypeToEvent(/* extras= */ null);
                 mBackupManagerMonitorEventSender.monitorEvent(
                         BackupManagerMonitor.LOG_EVENT_ID_PACKAGE_NOT_PRESENT,
-                        mCurrentPackage,
+                        createPackageInfoForBMMLogging(pkgName),
                         BackupManagerMonitor.LOG_EVENT_CATEGORY_BACKUP_MANAGER_POLICY,
                         monitoringExtras);
                 EventLog.writeEvent(
@@ -739,7 +748,7 @@ public class PerformUnifiedRestoreTask implements BackupRestoreTask {
             Bundle monitoringExtras = addRestoreOperationTypeToEvent(/* extras= */ null);
             mBackupManagerMonitorEventSender.monitorEvent(
                     BackupManagerMonitor.LOG_EVENT_ID_NO_NEXT_RESTORE_TARGET,
-                    mCurrentPackage,
+                    null,
                     BackupManagerMonitor.LOG_EVENT_CATEGORY_BACKUP_MANAGER_POLICY,
                     monitoringExtras);
             EventLog.writeEvent(EventLogTags.RESTORE_TRANSPORT_FAILURE);
@@ -1804,4 +1813,10 @@ public class PerformUnifiedRestoreTask implements BackupRestoreTask {
                 monitoringExtrasDenylist);
     }
 
+    private PackageInfo createPackageInfoForBMMLogging(String packageName) {
+        PackageInfo packageInfo = new PackageInfo();
+        packageInfo.packageName = packageName;
+
+        return packageInfo;
+    }
 }
diff --git a/services/backup/java/com/android/server/backup/utils/BackupManagerMonitorDumpsysUtils.java b/services/backup/java/com/android/server/backup/utils/BackupManagerMonitorDumpsysUtils.java
index 6d315ba38b31..fad59d23a6dc 100644
--- a/services/backup/java/com/android/server/backup/utils/BackupManagerMonitorDumpsysUtils.java
+++ b/services/backup/java/com/android/server/backup/utils/BackupManagerMonitorDumpsysUtils.java
@@ -371,6 +371,24 @@ public class BackupManagerMonitorDumpsysUtils {
                     "V to U restore pkg not eligible";
             case BackupManagerMonitor.LOG_EVENT_ID_V_TO_U_RESTORE_SET_LIST ->
                     "V to U restore lists";
+            case BackupManagerMonitor.LOG_EVENT_ID_RESTORE_AT_INSTALL_INVOKED ->
+                    "Invoked restore at install";
+            case BackupManagerMonitor.LOG_EVENT_ID_SKIP_RESTORE_AT_INSTALL ->
+                    "Skip restore at install";
+            case BackupManagerMonitor.LOG_EVENT_ID_PACKAGE_ACCEPTED_FOR_RESTORE ->
+                    "Pkg accepted for restore";
+            case BackupManagerMonitor.LOG_EVENT_ID_RESTORE_DATA_DOES_NOT_BELONG_TO_PACKAGE ->
+                    "Restore data does not belong to package";
+            case BackupManagerMonitor.LOG_EVENT_ID_UNABLE_TO_CREATE_AGENT_FOR_RESTORE ->
+                    "Unable to create Agent";
+            case BackupManagerMonitor.LOG_EVENT_ID_AGENT_CRASHED_BEFORE_RESTORE_DATA_IS_SENT ->
+                    "Agent crashed before restore data is streamed";
+            case BackupManagerMonitor.LOG_EVENT_ID_FAILED_TO_SEND_DATA_TO_AGENT_DURING_RESTORE ->
+                    "Failed to send data to agent";
+            case BackupManagerMonitor.LOG_EVENT_ID_AGENT_FAILURE_DURING_RESTORE ->
+                    "Agent failure during restore";
+            case BackupManagerMonitor.LOG_EVENT_ID_FAILED_TO_READ_DATA_FROM_TRANSPORT ->
+                    "Failed to read data from Transport";
             default -> "Unknown log event ID: " + code;
         };
         return id;