Add more instrumentation to BackupManager.
This CL continues work of: ag/1835775 and ag/1870141 adding a few more
logging constans described here:
https://docs.google.com/document/d/1sUboR28LjkT1wRXOwVOV3tLo0qisiCvzxIGmzCVEjbI/edit#
Test: manual
BUG: 34873525
Change-Id: I8c81d8cfea5538e89de94919062eeff6ae09dce4
diff --git a/api/system-current.txt b/api/system-current.txt
index e0e2c35..3e7ef78 100644
--- a/api/system-current.txt
+++ b/api/system-current.txt
@@ -6942,14 +6942,22 @@
field public static final java.lang.String EXTRA_LOG_EVENT_ID = "android.app.backup.extra.LOG_EVENT_ID";
field public static final java.lang.String EXTRA_LOG_EVENT_PACKAGE_NAME = "android.app.backup.extra.LOG_EVENT_PACKAGE_NAME";
field public static final java.lang.String EXTRA_LOG_EVENT_PACKAGE_VERSION = "android.app.backup.extra.LOG_EVENT_PACKAGE_VERSION";
+ field public static final java.lang.String EXTRA_LOG_OLD_VERSION = "android.app.backup.extra.LOG_OLD_VERSION";
field public static final int LOG_EVENT_CATEGORY_AGENT = 2; // 0x2
field public static final int LOG_EVENT_CATEGORY_BACKUP_MANAGER_POLICY = 3; // 0x3
field public static final int LOG_EVENT_CATEGORY_TRANSPORT = 1; // 0x1
+ field public static final int LOG_EVENT_ID_APP_HAS_NO_AGENT = 28; // 0x1c
+ field public static final int LOG_EVENT_ID_CANT_FIND_AGENT = 30; // 0x1e
field public static final int LOG_EVENT_ID_FULL_BACKUP_TIMEOUT = 4; // 0x4
field public static final int LOG_EVENT_ID_FULL_RESTORE_TIMEOUT = 45; // 0x2d
field public static final int LOG_EVENT_ID_KEY_VALUE_BACKUP_TIMEOUT = 21; // 0x15
field public static final int LOG_EVENT_ID_KEY_VALUE_RESTORE_TIMEOUT = 31; // 0x1f
field public static final int LOG_EVENT_ID_NO_PACKAGES = 49; // 0x31
+ field public static final int LOG_EVENT_ID_NO_RESTORE_METADATA_AVAILABLE = 22; // 0x16
+ field public static final int LOG_EVENT_ID_PACKAGE_NOT_FOUND = 12; // 0xc
+ field public static final int LOG_EVENT_ID_PACKAGE_NOT_PRESENT = 26; // 0x1a
+ field public static final int LOG_EVENT_ID_PACKAGE_TRANSPORT_NOT_PRESENT = 15; // 0xf
+ field public static final int LOG_EVENT_ID_VERSION_OF_BACKUP_OLDER = 36; // 0x24
}
public abstract class BackupObserver {
diff --git a/core/java/android/app/backup/BackupManagerMonitor.java b/core/java/android/app/backup/BackupManagerMonitor.java
index 099878b..d2a623e 100644
--- a/core/java/android/app/backup/BackupManagerMonitor.java
+++ b/core/java/android/app/backup/BackupManagerMonitor.java
@@ -54,15 +54,31 @@
public static final String EXTRA_LOG_EVENT_CATEGORY =
"android.app.backup.extra.LOG_EVENT_CATEGORY";
+ /**
+ * string: when we have event of id LOG_EVENT_ID_VERSION_OF_BACKUP_OLDER we send the version
+ * of the backup.
+ */
+ public static final String EXTRA_LOG_OLD_VERSION =
+ "android.app.backup.extra.LOG_OLD_VERSION";
+
// TODO complete this list with all log messages. And document properly.
public static final int LOG_EVENT_ID_FULL_BACKUP_TIMEOUT = 4;
+ public static final int LOG_EVENT_ID_PACKAGE_NOT_FOUND = 12;
+ public static final int LOG_EVENT_ID_PACKAGE_TRANSPORT_NOT_PRESENT = 15;
public static final int LOG_EVENT_ID_KEY_VALUE_BACKUP_TIMEOUT = 21;
+ public static final int LOG_EVENT_ID_NO_RESTORE_METADATA_AVAILABLE = 22;
+ public static final int LOG_EVENT_ID_PACKAGE_NOT_PRESENT = 26;
+ public static final int LOG_EVENT_ID_APP_HAS_NO_AGENT = 28;
+ public static final int LOG_EVENT_ID_CANT_FIND_AGENT = 30;
public static final int LOG_EVENT_ID_KEY_VALUE_RESTORE_TIMEOUT = 31;
+ public static final int LOG_EVENT_ID_VERSION_OF_BACKUP_OLDER = 36;
public static final int LOG_EVENT_ID_FULL_RESTORE_TIMEOUT = 45;
public static final int LOG_EVENT_ID_NO_PACKAGES = 49;
+
+
/**
* This method will be called each time something important happens on BackupManager.
*
diff --git a/services/backup/java/com/android/server/backup/BackupManagerService.java b/services/backup/java/com/android/server/backup/BackupManagerService.java
index 9b55c7a..b459f74 100644
--- a/services/backup/java/com/android/server/backup/BackupManagerService.java
+++ b/services/backup/java/com/android/server/backup/BackupManagerService.java
@@ -16,6 +16,9 @@
package com.android.server.backup;
+import static android.app.backup.BackupManagerMonitor.LOG_EVENT_ID_VERSION_OF_BACKUP_OLDER;
+import static android.app.backup.BackupManagerMonitor.LOG_EVENT_CATEGORY_BACKUP_MANAGER_POLICY;
+import static android.app.backup.BackupManagerMonitor.EXTRA_LOG_OLD_VERSION;
import static android.content.pm.ApplicationInfo.PRIVATE_FLAG_BACKUP_IN_FOREGROUND;
import android.app.ActivityManager;
@@ -2340,7 +2343,7 @@
Slog.e(TAG, "No packages named for backup request");
sendBackupFinished(observer, BackupManager.ERROR_TRANSPORT_ABORTED);
monitor = monitorEvent(monitor, BackupManagerMonitor.LOG_EVENT_ID_NO_PACKAGES,
- null, BackupManagerMonitor.LOG_EVENT_CATEGORY_TRANSPORT);
+ null, BackupManagerMonitor.LOG_EVENT_CATEGORY_TRANSPORT, null);
throw new IllegalArgumentException("No packages are provided for backup");
}
@@ -3459,6 +3462,9 @@
// fail repeatedly (i.e. have proved themselves to be buggy).
Slog.e(TAG, "Cancel backing up " + mCurrentPackage.packageName);
EventLog.writeEvent(EventLogTags.BACKUP_AGENT_FAILURE, mCurrentPackage.packageName);
+ mMonitor = monitorEvent(mMonitor,
+ BackupManagerMonitor.LOG_EVENT_ID_KEY_VALUE_BACKUP_TIMEOUT,
+ mCurrentPackage, BackupManagerMonitor.LOG_EVENT_CATEGORY_AGENT, null);
addBackupTrace(
"cancel of " + mCurrentPackage.packageName + ", cancelAll=" + cancelAll);
errorCleanup();
@@ -4555,6 +4561,11 @@
mPackages.add(info);
} catch (NameNotFoundException e) {
Slog.i(TAG, "Requested package " + pkg + " not found; ignoring");
+ monitor = monitorEvent(monitor,
+ BackupManagerMonitor.LOG_EVENT_ID_PACKAGE_NOT_FOUND,
+ mCurrentPackage,
+ BackupManagerMonitor.LOG_EVENT_CATEGORY_BACKUP_MANAGER_POLICY,
+ null);
}
}
}
@@ -4638,6 +4649,10 @@
if (mTransport == null) {
Slog.w(TAG, "Transport not present; full data backup not performed");
backupRunStatus = BackupManager.ERROR_TRANSPORT_ABORTED;
+ mMonitor = monitorEvent(mMonitor,
+ BackupManagerMonitor.LOG_EVENT_ID_PACKAGE_TRANSPORT_NOT_PRESENT,
+ mCurrentPackage, BackupManagerMonitor.LOG_EVENT_CATEGORY_TRANSPORT,
+ null);
return;
}
@@ -5148,7 +5163,7 @@
mMonitor = monitorEvent(mMonitor,
BackupManagerMonitor.LOG_EVENT_ID_FULL_BACKUP_TIMEOUT,
- mCurrentPackage, BackupManagerMonitor.LOG_EVENT_CATEGORY_AGENT);
+ mCurrentPackage, BackupManagerMonitor.LOG_EVENT_CATEGORY_AGENT, null);
mIsCancelled = true;
// Cancel tasks spun off by this task.
BackupManagerService.this.handleCancel(mEphemeralToken, cancelAll);
@@ -5525,6 +5540,8 @@
// Dedicated observer, if any
IFullBackupRestoreObserver mObserver;
+ IBackupManagerMonitor mMonitor;
+
// Where we're delivering the file data as we go
IBackupAgent mAgent;
@@ -5606,11 +5623,12 @@
}
public FullRestoreEngine(BackupRestoreTask monitorTask, IFullBackupRestoreObserver observer,
- PackageInfo onlyPackage, boolean allowApks, boolean allowObbs,
- int ephemeralOpToken) {
+ IBackupManagerMonitor monitor, PackageInfo onlyPackage, boolean allowApks,
+ boolean allowObbs, int ephemeralOpToken) {
mEphemeralOpToken = ephemeralOpToken;
mMonitorTask = monitorTask;
mObserver = observer;
+ mMonitor = monitor;
mOnlyPackage = onlyPackage;
mAllowApks = allowApks;
mAllowObbs = allowObbs;
@@ -6326,6 +6344,16 @@
} else {
Slog.i(TAG, "Data requires newer version "
+ version + "; ignoring");
+ ArrayList<Pair<String, String>> list =
+ new ArrayList<>();
+ list.add(new Pair<String, String>(
+ EXTRA_LOG_OLD_VERSION,
+ Integer.toString(version)));
+ mMonitor = monitorEvent(mMonitor,
+ LOG_EVENT_ID_VERSION_OF_BACKUP_OLDER,
+ pkgInfo,
+ LOG_EVENT_CATEGORY_BACKUP_MANAGER_POLICY,
+ list);
policy = RestorePolicy.IGNORE;
}
}
@@ -8461,6 +8489,10 @@
RestoreDescription desc = mTransport.nextRestorePackage();
if (desc == null) {
Slog.e(TAG, "No restore metadata available; halting");
+ mMonitor = monitorEvent(mMonitor,
+ BackupManagerMonitor.LOG_EVENT_ID_NO_RESTORE_METADATA_AVAILABLE,
+ mCurrentPackage,
+ BackupManagerMonitor.LOG_EVENT_CATEGORY_BACKUP_MANAGER_POLICY, null);
mStatus = BackupTransport.TRANSPORT_ERROR;
executeNextState(UnifiedRestoreState.FINAL);
return;
@@ -8562,6 +8594,11 @@
// Whoops, we thought we could restore this package but it
// turns out not to be present. Skip it.
Slog.e(TAG, "Package not present: " + pkgName);
+ mMonitor = monitorEvent(mMonitor,
+ BackupManagerMonitor.LOG_EVENT_ID_PACKAGE_NOT_PRESENT,
+ mCurrentPackage,
+ BackupManagerMonitor.LOG_EVENT_CATEGORY_BACKUP_MANAGER_POLICY,
+ null);
EventLog.writeEvent(EventLogTags.RESTORE_AGENT_FAILURE, pkgName,
"Package missing on device");
nextState = UnifiedRestoreState.RUNNING_QUEUE;
@@ -8631,6 +8668,9 @@
Slog.i(TAG, "Data exists for package " + packageName
+ " but app has no agent; skipping");
}
+ mMonitor = monitorEvent(mMonitor,
+ BackupManagerMonitor.LOG_EVENT_ID_APP_HAS_NO_AGENT, mCurrentPackage,
+ BackupManagerMonitor.LOG_EVENT_CATEGORY_AGENT, null);
EventLog.writeEvent(EventLogTags.RESTORE_AGENT_FAILURE, packageName,
"Package has no agent");
executeNextState(UnifiedRestoreState.RUNNING_QUEUE);
@@ -8652,6 +8692,9 @@
ApplicationThreadConstants.BACKUP_MODE_INCREMENTAL);
if (mAgent == null) {
Slog.w(TAG, "Can't find backup agent for " + packageName);
+ mMonitor = monitorEvent(mMonitor,
+ BackupManagerMonitor.LOG_EVENT_ID_CANT_FIND_AGENT, mCurrentPackage,
+ BackupManagerMonitor.LOG_EVENT_CATEGORY_BACKUP_MANAGER_POLICY, null);
EventLog.writeEvent(EventLogTags.RESTORE_AGENT_FAILURE, packageName,
"Restore agent missing");
executeNextState(UnifiedRestoreState.RUNNING_QUEUE);
@@ -8857,7 +8900,7 @@
EventLog.writeEvent(EventLogTags.FULL_RESTORE_PACKAGE,
mCurrentPackage.packageName);
- mEngine = new FullRestoreEngine(this, null, mCurrentPackage, false, false, mEphemeralOpToken);
+ mEngine = new FullRestoreEngine(this, null, mMonitor, mCurrentPackage, false, false, mEphemeralOpToken);
mEngineThread = new EngineThread(mEngine, mEnginePipes[0]);
ParcelFileDescriptor eWriteEnd = mEnginePipes[1];
@@ -9001,8 +9044,10 @@
if (DEBUG) {
Slog.w(TAG, "Full-data restore target timed out; shutting down");
}
- mMonitor = monitorEvent(mMonitor, BackupManagerMonitor.LOG_EVENT_ID_FULL_RESTORE_TIMEOUT,
- mCurrentPackage, BackupManagerMonitor.LOG_EVENT_CATEGORY_AGENT);
+
+ mMonitor = monitorEvent(mMonitor,
+ BackupManagerMonitor.LOG_EVENT_ID_FULL_RESTORE_TIMEOUT,
+ mCurrentPackage, BackupManagerMonitor.LOG_EVENT_CATEGORY_AGENT, null);
mEngineThread.handleTimeout();
IoUtils.closeQuietly(mEnginePipes[1]);
@@ -9245,8 +9290,9 @@
public void handleCancel(boolean cancelAll) {
removeOperation(mEphemeralOpToken);
Slog.e(TAG, "Timeout restoring application " + mCurrentPackage.packageName);
- mMonitor = monitorEvent(mMonitor, BackupManagerMonitor.LOG_EVENT_ID_KEY_VALUE_RESTORE_TIMEOUT,
- mCurrentPackage, BackupManagerMonitor.LOG_EVENT_CATEGORY_AGENT);
+ mMonitor = monitorEvent(mMonitor,
+ BackupManagerMonitor.LOG_EVENT_ID_KEY_VALUE_RESTORE_TIMEOUT,
+ mCurrentPackage, BackupManagerMonitor.LOG_EVENT_CATEGORY_AGENT, null);
EventLog.writeEvent(EventLogTags.RESTORE_AGENT_FAILURE,
mCurrentPackage.packageName, "restore timeout");
// Handle like an agent that threw on invocation: wipe it and go on to the next
@@ -10913,7 +10959,7 @@
}
private static IBackupManagerMonitor monitorEvent(IBackupManagerMonitor monitor, int id,
- PackageInfo pkg, int category) {
+ PackageInfo pkg, int category, ArrayList<Pair<String, String>> extras) {
if (monitor != null) {
try {
Bundle bundle = new Bundle();
@@ -10925,6 +10971,11 @@
bundle.putInt(BackupManagerMonitor.EXTRA_LOG_EVENT_PACKAGE_VERSION,
pkg.versionCode);
}
+ if (extras != null) {
+ for (Pair<String,String> pair : extras) {
+ bundle.putString(pair.first, pair.second);
+ }
+ }
monitor.onEvent(bundle);
return monitor;
} catch(RemoteException e) {