Reduce backup manager logspew
...with particular attention to boot-time logging. In particular, the
following kinds of messages are now cut unless someone turns on the new
MORE_DEBUG flag in their local build:
08-01 11:25:32.203 155 223 V BackupManagerService: starting timeout: token=4f52ccd1 interval=30000
08-01 11:25:32.211 155 223 V BackupManagerService: opComplete: 4f52ccd1
08-01 11:25:32.211 155 223 V BackupManagerService: operation 4f52ccd1 complete: finalState=1
08-01 11:25:32.211 155 223 V PerformBackupThread: doBackup() success
and
01-01 00:00:19.710 148 162 V BackupManagerService: Adding 9 backup participants:
01-01 00:00:19.710 148 162 V BackupManagerService: PackageInfo{41af0380 android} agent=com.android.server.SystemBackupAgent uid=1000 killAfterRestore=false
01-01 00:00:19.710 148 162 V BackupManagerService: PackageInfo{41aa5068 com.android.browser} agent=com.android.browser.BrowserBackupAgent uid=10005 killAfterRestore=true
01-01 00:00:19.710 148 162 V BackupManagerService: PackageInfo{4199ce28 com.android.nfc3} agent=com.android.nfc.NfcBackupAgent uid=1025 killAfterRestore=true
01-01 00:00:19.710 148 162 V BackupManagerService: PackageInfo{41a6e170 com.android.providers.settings} agent=com.android.providers.settings.SettingsBackupAgent uid=1000 killAfterRestore=false
01-01 00:00:19.710 148 162 V BackupManagerService: PackageInfo{4198ba90 com.android.providers.userdictionary} agent=com.android.providers.userdictionary.DictionaryBackupAgent uid=10000 killAfterRestore=false
01-01 00:00:19.710 148 162 V BackupManagerService: PackageInfo{41a80190 com.android.vending} agent=com.android.vending.VendingBackupAgent uid=10042 killAfterRestore=false
01-01 00:00:19.710 148 162 V BackupManagerService: PackageInfo{41ac2980 com.google.android.calendar} agent=com.android.calendar.CalendarBackupAgent uid=10007 killAfterRestore=true
01-01 00:00:19.710 148 162 V BackupManagerService: PackageInfo{41b14fb8 com.google.android.gm} agent=com.google.android.gm.persistence.GmailBackupAgent uid=10020 killAfterRestore=true
01-01 00:00:19.710 148 162 V BackupManagerService: PackageInfo{41af89b8 com.google.android.inputmethod.latin} agent=com.android.inputmethod.latin.BackupAgent uid=10028 killAfterRestore=false
and
01-01 00:00:20.000 148 162 D BackupManagerService: Now awaiting backup for 1 participants:
01-01 00:00:20.000 148 162 D BackupManagerService: + BackupRequest{app=ApplicationInfo{41b15110 android}} agent=com.android.server.SystemBackupAgent
01-01 00:00:20.000 148 162 I BackupManagerService: New app com.android.browser never backed up; scheduling
01-01 00:00:20.015 148 162 D BackupManagerService: Now awaiting backup for 2 participants:
01-01 00:00:20.015 148 162 D BackupManagerService: + BackupRequest{app=ApplicationInfo{41b15110 android}} agent=com.android.server.SystemBackupAgent
01-01 00:00:20.015 148 162 D BackupManagerService: + BackupRequest{app=ApplicationInfo{41ae5cf8 com.android.browser}} agent=com.android.browser.BrowserBackupAgent
01-01 00:00:20.015 148 162 I BackupManagerService: New app com.android.nfc3 never backed up; scheduling
01-01 00:00:20.031 148 162 D BackupManagerService: Now awaiting backup for 3 participants:
01-01 00:00:20.031 148 162 D BackupManagerService: + BackupRequest{app=ApplicationInfo{41b15110 android}} agent=com.android.server.SystemBackupAgent
01-01 00:00:20.031 148 162 D BackupManagerService: + BackupRequest{app=ApplicationInfo{41ae5cf8 com.android.browser}} agent=com.android.browser.BrowserBackupAgent
01-01 00:00:20.031 148 162 D BackupManagerService: + BackupRequest{app=ApplicationInfo{41a47d88 com.android.nfc3}} agent=com.android.nfc.NfcBackupAgent
... [N times]
and various other overly-chatty messages that aren't useful for the midrange
debugging needs of early testing.
Bug 5104300
Change-Id: I2b2afb5ba68059cb1f4cccc07f2833e43cd6fe94
diff --git a/services/java/com/android/server/BackupManagerService.java b/services/java/com/android/server/BackupManagerService.java
index bdd8938..2e3d6dd 100644
--- a/services/java/com/android/server/BackupManagerService.java
+++ b/services/java/com/android/server/BackupManagerService.java
@@ -129,6 +129,7 @@
class BackupManagerService extends IBackupManager.Stub {
private static final String TAG = "BackupManagerService";
private static final boolean DEBUG = true;
+ private static final boolean MORE_DEBUG = false;
// Name and current contents version of the full-backup manifest file
static final String BACKUP_MANIFEST_FILENAME = "_manifest";
@@ -851,10 +852,10 @@
info = mPackageManager.getPackageInfo(pkg, 0);
mEverStoredApps.add(pkg);
temp.writeUTF(pkg);
- if (DEBUG) Slog.v(TAG, " + " + pkg);
+ if (MORE_DEBUG) Slog.v(TAG, " + " + pkg);
} catch (NameNotFoundException e) {
// nope, this package was uninstalled; don't include it
- if (DEBUG) Slog.v(TAG, " - " + pkg);
+ if (MORE_DEBUG) Slog.v(TAG, " - " + pkg);
}
}
} catch (EOFException e) {
@@ -1246,7 +1247,7 @@
private void addPackageParticipantsLockedInner(String packageName,
List<PackageInfo> targetPkgs) {
- if (DEBUG) {
+ if (MORE_DEBUG) {
Slog.v(TAG, "Adding " + targetPkgs.size() + " backup participants:");
for (PackageInfo p : targetPkgs) {
Slog.v(TAG, " " + p + " agent=" + p.applicationInfo.backupAgentName
@@ -1296,7 +1297,7 @@
private void removePackageParticipantsLockedInner(String packageName,
List<String> allPackageNames) {
- if (DEBUG) {
+ if (MORE_DEBUG) {
Slog.v(TAG, "removePackageParticipantsLockedInner (" + packageName
+ ") removing " + allPackageNames.size() + " entries");
for (String p : allPackageNames) {
@@ -1320,7 +1321,7 @@
// We can't just remove(app) because the instances are different.
for (ApplicationInfo entry: set) {
if (entry.packageName.equals(pkg)) {
- if (DEBUG) Slog.v(TAG, " removing participant " + pkg);
+ if (MORE_DEBUG) Slog.v(TAG, " removing participant " + pkg);
set.remove(entry);
removeEverBackedUp(pkg);
break;
@@ -1403,7 +1404,8 @@
// Remove our awareness of having ever backed up the given package
void removeEverBackedUp(String packageName) {
- if (DEBUG) Slog.v(TAG, "Removing backed-up knowledge of " + packageName + ", new set:");
+ if (DEBUG) Slog.v(TAG, "Removing backed-up knowledge of " + packageName);
+ if (MORE_DEBUG) Slog.v(TAG, "New set:");
synchronized (mEverStoredApps) {
// Rewrite the file and rename to overwrite. If we reboot in the middle,
@@ -1416,7 +1418,7 @@
mEverStoredApps.remove(packageName);
for (String s : mEverStoredApps) {
known.writeUTF(s);
- if (DEBUG) Slog.v(TAG, " " + s);
+ if (MORE_DEBUG) Slog.v(TAG, " " + s);
}
known.close();
known = null;
@@ -1460,7 +1462,7 @@
if (DEBUG) Slog.v(TAG, "Ancestral packages: " + mAncestralPackages.size());
for (String pkgName : mAncestralPackages) {
af.writeUTF(pkgName);
- if (DEBUG) Slog.v(TAG, " " + pkgName);
+ if (MORE_DEBUG) Slog.v(TAG, " " + pkgName);
}
}
af.close();
@@ -1523,7 +1525,7 @@
try {
PackageInfo info = mPackageManager.getPackageInfo(packageName, 0);
if ((info.applicationInfo.flags & ApplicationInfo.FLAG_ALLOW_CLEAR_USER_DATA) == 0) {
- if (DEBUG) Slog.i(TAG, "allowClearUserData=false so not wiping "
+ if (MORE_DEBUG) Slog.i(TAG, "allowClearUserData=false so not wiping "
+ packageName);
return;
}
@@ -1593,13 +1595,13 @@
}
}
mBackupHandler.removeMessages(MSG_TIMEOUT);
- if (DEBUG) Slog.v(TAG, "operation " + Integer.toHexString(token)
+ if (MORE_DEBUG) Slog.v(TAG, "operation " + Integer.toHexString(token)
+ " complete: finalState=" + finalState);
return finalState == OP_ACKNOWLEDGED;
}
void prepareOperationTimeout(int token, long interval) {
- if (DEBUG) Slog.v(TAG, "starting timeout: token=" + Integer.toHexString(token)
+ if (MORE_DEBUG) Slog.v(TAG, "starting timeout: token=" + Integer.toHexString(token)
+ " interval=" + interval);
synchronized (mCurrentOpLock) {
mCurrentOperations.put(token, OP_PENDING);
@@ -1937,7 +1939,7 @@
BackupDataOutput output = new BackupDataOutput(
mPipe.getFileDescriptor());
- if (DEBUG) Slog.d(TAG, "Writing manifest for " + mPackage.packageName);
+ if (MORE_DEBUG) Slog.d(TAG, "Writing manifest for " + mPackage.packageName);
writeAppManifest(mPackage, mManifestFile, mSendApk);
FullBackup.backupToTar(mPackage.packageName, null, null,
mFilesDir.getAbsolutePath(),
@@ -1948,7 +1950,7 @@
writeApkToBackup(mPackage, output);
}
- if (DEBUG) Slog.d(TAG, "Calling doFullBackup()");
+ if (DEBUG) Slog.d(TAG, "Calling doFullBackup() on " + mPackage.packageName);
prepareOperationTimeout(mToken, TIMEOUT_FULL_BACKUP_INTERVAL);
mAgent.doFullBackup(mPipe, mToken, mBackupManagerBinder);
} catch (IOException e) {
@@ -2285,7 +2287,7 @@
// check for .obb and save those too
final File obbDir = Environment.getExternalStorageAppObbDirectory(pkg.packageName);
if (obbDir != null) {
- if (DEBUG) Log.i(TAG, "obb dir: " + obbDir.getAbsolutePath());
+ if (MORE_DEBUG) Log.i(TAG, "obb dir: " + obbDir.getAbsolutePath());
File[] obbFiles = obbDir.listFiles();
if (obbFiles != null) {
final String obbDirName = obbDir.getAbsolutePath();
@@ -2374,10 +2376,10 @@
// The agent was running with a stub Application object, so shut it down.
if (app.uid != Process.SYSTEM_UID
&& app.uid != Process.PHONE_UID) {
- if (DEBUG) Slog.d(TAG, "Backup complete, killing host process");
+ if (MORE_DEBUG) Slog.d(TAG, "Backup complete, killing host process");
mActivityManager.killApplicationProcess(app.processName, app.uid);
} else {
- if (DEBUG) Slog.d(TAG, "Not killing after restore: " + app.processName);
+ if (MORE_DEBUG) Slog.d(TAG, "Not killing after restore: " + app.processName);
}
} catch (RemoteException e) {
Slog.d(TAG, "Lost app trying to shut down");
@@ -2600,7 +2602,7 @@
didRestore = restoreOneFile(in, buffer);
} while (didRestore);
- if (DEBUG) Slog.v(TAG, "Done consuming input tarfile, total bytes=" + mBytes);
+ if (MORE_DEBUG) Slog.v(TAG, "Done consuming input tarfile, total bytes=" + mBytes);
} catch (IOException e) {
Slog.e(TAG, "Unable to read restore input");
} finally {
@@ -2624,7 +2626,7 @@
}
sendEndRestore();
mWakelock.release();
- if (DEBUG) Slog.d(TAG, "Full restore pass complete.");
+ Slog.d(TAG, "Full restore pass complete.");
}
}
@@ -2722,7 +2724,7 @@
try {
info = readTarHeaders(instream);
if (info != null) {
- if (DEBUG) {
+ if (MORE_DEBUG) {
dumpFileMetadata(info);
}
@@ -2910,7 +2912,6 @@
boolean pipeOkay = true;
FileOutputStream pipe = new FileOutputStream(
mPipes[1].getFileDescriptor());
- if (DEBUG) Slog.d(TAG, "Piping data to agent");
while (toCopy > 0) {
int toRead = (toCopy > buffer.length)
? buffer.length : (int)toCopy;
@@ -3629,7 +3630,7 @@
// Allow unsigned apps, but not signed on one device and unsigned on the other
// !!! TODO: is this the right policy?
Signature[] deviceSigs = target.signatures;
- if (DEBUG) Slog.v(TAG, "signaturesMatch(): stored=" + storedSigs
+ if (MORE_DEBUG) Slog.v(TAG, "signaturesMatch(): stored=" + storedSigs
+ " device=" + deviceSigs);
if ((storedSigs == null || storedSigs.length == 0)
&& (deviceSigs == null || deviceSigs.length == 0)) {
@@ -4189,7 +4190,7 @@
// in the set; we want to avoid touching the disk redundantly.
writeToJournalLocked(packageName);
- if (DEBUG) {
+ if (MORE_DEBUG) {
int numKeys = mPendingBackups.size();
Slog.d(TAG, "Now awaiting backup for " + numKeys + " participants:");
for (BackupRequest b : mPendingBackups.values()) {
@@ -4387,7 +4388,7 @@
}
Binder.restoreCallingIdentity(oldId);
}
- if (DEBUG) Slog.d(TAG, "Full backup done; returning to caller");
+ if (MORE_DEBUG) Slog.d(TAG, "Full backup done; returning to caller");
}
public void fullRestore(ParcelFileDescriptor fd) {
@@ -4446,7 +4447,7 @@
}
void startConfirmationTimeout(int token, FullParams params) {
- if (DEBUG) Slog.d(TAG, "Posting conf timeout msg after "
+ if (MORE_DEBUG) Slog.d(TAG, "Posting conf timeout msg after "
+ TIMEOUT_FULL_CONFIRMATION + " millis");
Message msg = mBackupHandler.obtainMessage(MSG_FULL_CONFIRMATION_TIMEOUT,
token, 0, params);
@@ -4625,7 +4626,7 @@
public String getCurrentTransport() {
mContext.enforceCallingOrSelfPermission(android.Manifest.permission.BACKUP,
"getCurrentTransport");
- if (DEBUG) Slog.v(TAG, "... getCurrentTransport() returning " + mCurrentTransport);
+ if (MORE_DEBUG) Slog.v(TAG, "... getCurrentTransport() returning " + mCurrentTransport);
return mCurrentTransport;
}
@@ -4682,7 +4683,7 @@
if (transport != null) {
try {
final Intent intent = transport.configurationIntent();
- if (DEBUG) Slog.d(TAG, "getConfigurationIntent() returning config intent "
+ if (MORE_DEBUG) Slog.d(TAG, "getConfigurationIntent() returning config intent "
+ intent);
return intent;
} catch (RemoteException e) {
@@ -4708,7 +4709,7 @@
if (transport != null) {
try {
final String text = transport.currentDestinationString();
- if (DEBUG) Slog.d(TAG, "getDestinationString() returning " + text);
+ if (MORE_DEBUG) Slog.d(TAG, "getDestinationString() returning " + text);
return text;
} catch (RemoteException e) {
/* fall through to return null */
@@ -4853,7 +4854,7 @@
// completed the given outstanding asynchronous backup/restore operation.
public void opComplete(int token) {
synchronized (mCurrentOpLock) {
- if (DEBUG) Slog.v(TAG, "opComplete: " + Integer.toHexString(token));
+ if (MORE_DEBUG) Slog.v(TAG, "opComplete: " + Integer.toHexString(token));
mCurrentOperations.put(token, OP_ACKNOWLEDGED);
mCurrentOpLock.notifyAll();
}