diff options
author | 2023-09-22 14:31:27 +0000 | |
---|---|---|
committer | 2023-09-22 14:31:27 +0000 | |
commit | 933caefe553f84668690952e842ccf7e4789ffcd (patch) | |
tree | ed7ae55df07ce464740e534991f0a1e56dc07787 /services/backup/java | |
parent | 2b2a3ff22cdbff81f2b2eed27a4fa516fb583d5a (diff) | |
parent | 6f4c93a57adf142503c642734ea36e2a70867768 (diff) |
Merge changes from topic "bmm-events" into udc-qpr-dev am: 6f4c93a57a
Original change: https://googleplex-android-review.googlesource.com/c/platform/frameworks/base/+/24770152
Change-Id: I48429aeb7811ccf7f098cfdd79412f48c2750edd
Signed-off-by: Automerger Merge Worker <android-build-automerger-merge-worker@system.gserviceaccount.com>
Diffstat (limited to 'services/backup/java')
4 files changed, 400 insertions, 15 deletions
diff --git a/services/backup/java/com/android/server/backup/UserBackupManagerService.java b/services/backup/java/com/android/server/backup/UserBackupManagerService.java index 5493da6331fa..5bb0f86e1b9b 100644 --- a/services/backup/java/com/android/server/backup/UserBackupManagerService.java +++ b/services/backup/java/com/android/server/backup/UserBackupManagerService.java @@ -486,6 +486,13 @@ public class UserBackupManagerService { File baseStateDir, File dataDir, TransportManager transportManager) { + // check if we are past the retention period for BMM Events, + // if so delete expired events and do not print them to dumpsys + BackupManagerMonitorDumpsysUtils backupManagerMonitorDumpsysUtils = + new BackupManagerMonitorDumpsysUtils(); + if (backupManagerMonitorDumpsysUtils.deleteExpiredBMMEvents() && DEBUG){ + Slog.d(TAG, "BMM Events recorded for dumpsys have expired"); + } return new UserBackupManagerService( userId, context, @@ -654,6 +661,13 @@ public class UserBackupManagerService { // the pending backup set mBackupHandler.postDelayed(this::parseLeftoverJournals, INITIALIZATION_DELAY_MILLIS); + // check if we are past the retention period for BMM Events, + // if so delete expired events and do not print them to dumpsys + BackupManagerMonitorDumpsysUtils backupManagerMonitorDumpsysUtils = + new BackupManagerMonitorDumpsysUtils(); + mBackupHandler.postDelayed(backupManagerMonitorDumpsysUtils::deleteExpiredBMMEvents, + INITIALIZATION_DELAY_MILLIS); + mBackupPreferences = new UserBackupPreferences(mContext, mBaseStateDir); // Power management @@ -4177,7 +4191,19 @@ public class UserBackupManagerService { private void dumpBMMEvents(PrintWriter pw) { BackupManagerMonitorDumpsysUtils bm = new BackupManagerMonitorDumpsysUtils(); + if (bm.deleteExpiredBMMEvents()) { + pw.println("BACKUP MANAGER MONITOR EVENTS HAVE EXPIRED"); + return; + } File events = bm.getBMMEventsFile(); + if (events.length() == 0){ + // We have not recorded BMMEvents yet. + pw.println("NO BACKUP MANAGER MONITOR EVENTS"); + return; + } else if (bm.isFileLargerThanSizeLimit(events)){ + pw.println("BACKUP MANAGER MONITOR EVENTS FILE OVER SIZE LIMIT - " + + "future events will not be recorded"); + } pw.println("START OF BACKUP MANAGER MONITOR EVENTS"); try (BufferedReader reader = new BufferedReader(new FileReader(events))) { String line; 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 e04bf11dad9f..bbec79d6cd47 100644 --- a/services/backup/java/com/android/server/backup/restore/PerformUnifiedRestoreTask.java +++ b/services/backup/java/com/android/server/backup/restore/PerformUnifiedRestoreTask.java @@ -394,6 +394,20 @@ public class PerformUnifiedRestoreTask implements BackupRestoreTask { // 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 { @@ -421,6 +435,12 @@ public class PerformUnifiedRestoreTask implements BackupRestoreTask { mStatus = transport.startRestore(mToken, packages); if (mStatus != BackupTransport.TRANSPORT_OK) { Slog.e(TAG, "Transport error " + mStatus + "; no restore possible"); + Bundle monitoringExtras = addRestoreOperationTypeToEvent(/*extras*/null); + mBackupManagerMonitorEventSender.monitorEvent( + BackupManagerMonitor.LOG_EVENT_ID_TRANSPORT_ERROR_DURING_START_RESTORE, + mCurrentPackage, + BackupManagerMonitor.LOG_EVENT_CATEGORY_TRANSPORT, + monitoringExtras); mStatus = BackupTransport.TRANSPORT_ERROR; executeNextState(UnifiedRestoreState.FINAL); return; @@ -528,6 +548,12 @@ public class PerformUnifiedRestoreTask implements BackupRestoreTask { final String pkgName = (mRestoreDescription != null) ? mRestoreDescription.getPackageName() : null; if (pkgName == null) { + Bundle monitoringExtras = addRestoreOperationTypeToEvent(/*extras*/null); + mBackupManagerMonitorEventSender.monitorEvent( + BackupManagerMonitor.LOG_EVENT_ID_CANNOT_GET_NEXT_PKG_NAME, + null, + BackupManagerMonitor.LOG_EVENT_CATEGORY_TRANSPORT, + monitoringExtras); Slog.e(TAG, "Failure getting next package name"); EventLog.writeEvent(EventLogTags.RESTORE_TRANSPORT_FAILURE); nextState = UnifiedRestoreState.FINAL; @@ -550,6 +576,14 @@ public class PerformUnifiedRestoreTask implements BackupRestoreTask { Metadata metaInfo = mPmAgent.getRestoredMetadata(pkgName); if (metaInfo == null) { + PackageInfo pkgInfo = new PackageInfo(); + pkgInfo.packageName = pkgName; + Bundle monitoringExtras = addRestoreOperationTypeToEvent(/*extras*/null); + mBackupManagerMonitorEventSender.monitorEvent( + BackupManagerMonitor.LOG_EVENT_ID_PM_AGENT_HAS_NO_METADATA, + pkgInfo, + BackupManagerMonitor.LOG_EVENT_CATEGORY_BACKUP_MANAGER_POLICY, + monitoringExtras); Slog.e(TAG, "No metadata for " + pkgName); EventLog.writeEvent(EventLogTags.RESTORE_AGENT_FAILURE, pkgName, "Package metadata missing"); @@ -560,6 +594,13 @@ public class PerformUnifiedRestoreTask implements BackupRestoreTask { try { mCurrentPackage = backupManagerService.getPackageManager().getPackageInfoAsUser( pkgName, PackageManager.GET_SIGNING_CERTIFICATES, mUserId); + Bundle monitoringExtras = addRestoreOperationTypeToEvent(/*extras*/null); + mBackupManagerMonitorEventSender.monitorEvent( + BackupManagerMonitor.LOG_EVENT_ID_START_PACKAGE_RESTORE, + mCurrentPackage, + BackupManagerMonitor.LOG_EVENT_CATEGORY_BACKUP_MANAGER_POLICY, + monitoringExtras); + } catch (NameNotFoundException e) { // Whoops, we thought we could restore this package but it // turns out not to be present. Skip it. @@ -641,12 +682,24 @@ public class PerformUnifiedRestoreTask implements BackupRestoreTask { } else { // Unknown restore type; ignore this package and move on Slog.e(TAG, "Unrecognized restore type " + type); + Bundle monitoringExtras = addRestoreOperationTypeToEvent(/*extras*/null);; + mBackupManagerMonitorEventSender.monitorEvent( + BackupManagerMonitor.LOG_EVENT_ID_UNKNOWN_RESTORE_TYPE, + mCurrentPackage, + BackupManagerMonitor.LOG_EVENT_CATEGORY_BACKUP_MANAGER_POLICY, + monitoringExtras); nextState = UnifiedRestoreState.RUNNING_QUEUE; return; } } catch (Exception e) { Slog.e(TAG, "Can't get next restore target from transport; halting: " + e.getMessage()); + Bundle monitoringExtras = addRestoreOperationTypeToEvent(/*extras*/null);; + mBackupManagerMonitorEventSender.monitorEvent( + BackupManagerMonitor.LOG_EVENT_ID_NO_NEXT_RESTORE_TARGET, + mCurrentPackage, + BackupManagerMonitor.LOG_EVENT_CATEGORY_BACKUP_MANAGER_POLICY, + monitoringExtras); EventLog.writeEvent(EventLogTags.RESTORE_TRANSPORT_FAILURE); nextState = UnifiedRestoreState.FINAL; return; @@ -663,6 +716,10 @@ public class PerformUnifiedRestoreTask implements BackupRestoreTask { final String packageName = mCurrentPackage.packageName; // Validate some semantic requirements that apply in this way // only to the key/value restore API flow + mBackupManagerMonitorEventSender.monitorEvent( + BackupManagerMonitor.LOG_EVENT_ID_KV_RESTORE, mCurrentPackage, + BackupManagerMonitor.LOG_EVENT_CATEGORY_BACKUP_MANAGER_POLICY, + /*monitoringExtras*/ addRestoreOperationTypeToEvent(/*extras*/null)); if (mCurrentPackage.applicationInfo.backupAgentName == null || "".equals(mCurrentPackage.applicationInfo.backupAgentName)) { if (MORE_DEBUG) { @@ -721,6 +778,11 @@ public class PerformUnifiedRestoreTask implements BackupRestoreTask { ++mCount; } catch (Exception e) { Slog.e(TAG, "Error when attempting restore: " + e.toString()); + Bundle monitoringExtras = addRestoreOperationTypeToEvent(/*extras*/null); + mBackupManagerMonitorEventSender.monitorEvent( + BackupManagerMonitor.LOG_EVENT_ID_KV_AGENT_ERROR, mCurrentPackage, + BackupManagerMonitor.LOG_EVENT_CATEGORY_AGENT, + monitoringExtras); keyValueAgentErrorCleanup(false); executeNextState(UnifiedRestoreState.RUNNING_QUEUE); } @@ -759,6 +821,12 @@ public class PerformUnifiedRestoreTask implements BackupRestoreTask { // Transport-level failure. This failure could be specific to package currently in // restore. Slog.e(TAG, "Error getting restore data for " + packageName); + Bundle monitoringExtras = addRestoreOperationTypeToEvent(/*extras*/null); + mBackupManagerMonitorEventSender.monitorEvent( + BackupManagerMonitor.LOG_EVENT_ID_TRANSPORT_ERROR_KV_RESTORE, + mCurrentPackage, + BackupManagerMonitor.LOG_EVENT_CATEGORY_TRANSPORT, + monitoringExtras); EventLog.writeEvent(EventLogTags.RESTORE_TRANSPORT_FAILURE); stage.close(); downloadFile.delete(); @@ -815,6 +883,11 @@ public class PerformUnifiedRestoreTask implements BackupRestoreTask { new ArrayList<>(getExcludedKeysForPackage(packageName))); } catch (Exception e) { Slog.e(TAG, "Unable to call app for restore: " + packageName, e); + Bundle monitoringExtras = addRestoreOperationTypeToEvent(/*extras*/null); + mBackupManagerMonitorEventSender.monitorEvent( + BackupManagerMonitor.LOG_EVENT_ID_KV_AGENT_ERROR, mCurrentPackage, + BackupManagerMonitor.LOG_EVENT_CATEGORY_AGENT, + monitoringExtras); EventLog.writeEvent(EventLogTags.RESTORE_AGENT_FAILURE, packageName, e.toString()); // Clears any pending timeout messages as well. @@ -888,6 +961,10 @@ public class PerformUnifiedRestoreTask implements BackupRestoreTask { // // When finished, StreamFeederThread executes next state as appropriate on the // backup looper, and the overall unified restore task resumes + mBackupManagerMonitorEventSender.monitorEvent( + BackupManagerMonitor.LOG_EVENT_ID_FULL_RESTORE, mCurrentPackage, + BackupManagerMonitor.LOG_EVENT_CATEGORY_BACKUP_MANAGER_POLICY, + /*monitoringExtras*/ addRestoreOperationTypeToEvent(/*extras*/null)); try { StreamFeederThread feeder = new StreamFeederThread(); if (MORE_DEBUG) { @@ -903,6 +980,11 @@ public class PerformUnifiedRestoreTask implements BackupRestoreTask { // current target. We haven't asked the transport for data yet, though, // so we can do that simply by going back to running the restore queue. Slog.e(TAG, "Unable to construct pipes for stream restore!"); + Bundle monitoringExtras = addRestoreOperationTypeToEvent(/*extras*/null); + mBackupManagerMonitorEventSender.monitorEvent( + BackupManagerMonitor.LOG_EVENT_ID_NO_FEEDER_THREAD, mCurrentPackage, + BackupManagerMonitor.LOG_EVENT_CATEGORY_BACKUP_MANAGER_POLICY, + monitoringExtras); executeNextState(UnifiedRestoreState.RUNNING_QUEUE); } } @@ -927,6 +1009,10 @@ public class PerformUnifiedRestoreTask implements BackupRestoreTask { } catch (Exception e) { final String packageName = mCurrentPackage.packageName; Slog.e(TAG, "Unable to finalize restore of " + packageName); + Bundle monitoringExtras = addRestoreOperationTypeToEvent(/*extras*/null); + mBackupManagerMonitorEventSender.monitorEvent( + BackupManagerMonitor.LOG_EVENT_ID_AGENT_FAILURE, mCurrentPackage, + BackupManagerMonitor.LOG_EVENT_CATEGORY_AGENT, monitoringExtras); EventLog.writeEvent(EventLogTags.RESTORE_AGENT_FAILURE, packageName, e.toString()); keyValueAgentErrorCleanup(true); @@ -1020,6 +1106,12 @@ public class PerformUnifiedRestoreTask implements BackupRestoreTask { // handling will deal properly with that. Slog.e(TAG, "Error " + result + " streaming restore for " + mCurrentPackage.packageName); + Bundle monitoringExtras = addRestoreOperationTypeToEvent(/*extras*/null); + mBackupManagerMonitorEventSender.monitorEvent( + BackupManagerMonitor.LOG_EVENT_ID_TRANSPORT_ERROR_FULL_RESTORE, + mCurrentPackage, + BackupManagerMonitor.LOG_EVENT_CATEGORY_TRANSPORT, + monitoringExtras); EventLog.writeEvent(EventLogTags.RESTORE_TRANSPORT_FAILURE); status = result; } @@ -1032,6 +1124,12 @@ public class PerformUnifiedRestoreTask implements BackupRestoreTask { // but potentially recoverable; abandon this package's restore but // carry on with the next restore target. Slog.e(TAG, "Unable to route data for restore"); + Bundle monitoringExtras = addRestoreOperationTypeToEvent(/*extras*/null); + mBackupManagerMonitorEventSender.monitorEvent( + BackupManagerMonitor.LOG_EVENT_ID_FULL_AGENT_ERROR, + mCurrentPackage, + BackupManagerMonitor.LOG_EVENT_CATEGORY_AGENT, + monitoringExtras); EventLog.writeEvent(EventLogTags.RESTORE_AGENT_FAILURE, mCurrentPackage.packageName, "I/O error on pipes"); status = BackupTransport.AGENT_ERROR; @@ -1040,6 +1138,12 @@ public class PerformUnifiedRestoreTask implements BackupRestoreTask { // the sockets will wake up the engine and it will then tidy up the // remote end. Slog.e(TAG, "Transport failed during restore: " + e.getMessage()); + Bundle monitoringExtras = addRestoreOperationTypeToEvent(/*extras*/null); + mBackupManagerMonitorEventSender.monitorEvent( + BackupManagerMonitor.LOG_EVENT_ID_TRANSPORT_ERROR_FULL_RESTORE, + mCurrentPackage, + BackupManagerMonitor.LOG_EVENT_CATEGORY_TRANSPORT, + monitoringExtras); EventLog.writeEvent(EventLogTags.RESTORE_TRANSPORT_FAILURE); status = BackupTransport.TRANSPORT_ERROR; } finally { @@ -1213,6 +1317,13 @@ public class PerformUnifiedRestoreTask implements BackupRestoreTask { } Slog.i(TAG, "Restore complete."); + Bundle monitoringExtras = addRestoreOperationTypeToEvent(/*extras*/null); + mBackupManagerMonitorEventSender.monitorEvent( + BackupManagerMonitor.LOG_EVENT_ID_RESTORE_COMPLETE, + null, + BackupManagerMonitor.LOG_EVENT_CATEGORY_BACKUP_MANAGER_POLICY, + monitoringExtras); + mListener.onFinished(callerLogString); } @@ -1313,6 +1424,7 @@ public class PerformUnifiedRestoreTask implements BackupRestoreTask { @Override public void operationComplete(long unusedResult) { mOperationStorage.removeOperation(mEphemeralOpToken); + if (MORE_DEBUG) { Slog.i(TAG, "operationComplete() during restore: target=" + mCurrentPackage.packageName @@ -1341,6 +1453,11 @@ public class PerformUnifiedRestoreTask implements BackupRestoreTask { // Okay, we're done with this package. Tidy up and go on to the next // app in the queue. int size = (int) mBackupDataName.length(); + Bundle monitoringExtras = addRestoreOperationTypeToEvent(/*extras*/null); + mBackupManagerMonitorEventSender.monitorEvent( + BackupManagerMonitor.LOG_EVENT_ID_PACKAGE_RESTORE_FINISHED, mCurrentPackage, + BackupManagerMonitor.LOG_EVENT_CATEGORY_BACKUP_MANAGER_POLICY, + monitoringExtras); EventLog.writeEvent(EventLogTags.RESTORE_PACKAGE, mCurrentPackage.packageName, size); 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 0b55ca21371b..797aed9297a3 100644 --- a/services/backup/java/com/android/server/backup/utils/BackupManagerMonitorDumpsysUtils.java +++ b/services/backup/java/com/android/server/backup/utils/BackupManagerMonitorDumpsysUtils.java @@ -23,15 +23,22 @@ import android.os.Bundle; import android.os.Environment; import android.util.Slog; +import com.android.internal.annotations.VisibleForTesting; import com.android.internal.util.FastPrintWriter; +import java.io.BufferedReader; import java.io.File; +import java.io.FileInputStream; import java.io.FileOutputStream; +import java.io.FileWriter; +import java.io.IOException; +import java.io.InputStreamReader; import java.io.PrintWriter; import java.text.SimpleDateFormat; import java.util.ArrayList; import java.util.Date; import java.util.Map; +import java.util.concurrent.TimeUnit; /* @@ -46,12 +53,27 @@ public class BackupManagerMonitorDumpsysUtils { // Name of the subdirectory where the text file containing the BMM events will be stored. // Same as {@link UserBackupManagerFiles} private static final String BACKUP_PERSISTENT_DIR = "backup"; + private static final String INITIAL_SETUP_TIMESTAMP_KEY = "initialSetupTimestamp"; + // Retention period of 60 days (in millisec) for the BMM Events. + // After tha time has passed the text file containing the BMM events will be emptied + private static final long LOGS_RETENTION_PERIOD_MILLISEC = 60 * TimeUnit.DAYS.toMillis(1); + // Size limit for the text file containing the BMM events + private static final long BMM_FILE_SIZE_LIMIT_BYTES = 25 * 1024 * 1000; // 2.5 MB + + // We cache the value of IsAfterRetentionPeriod() to avoid unnecessary disk I/O + // mIsAfterRetentionPeriodCached tracks if we have cached the value of IsAfterRetentionPeriod() + private boolean mIsAfterRetentionPeriodCached = false; + // The cached value of IsAfterRetentionPeriod() + private boolean mIsAfterRetentionPeriod; + // If isFileLargerThanSizeLimit(bmmEvents) returns true we cache the value to avoid + // unnecessary disk I/O + private boolean mIsFileLargerThanSizeLimit = false; /** * Parses the BackupManagerMonitor bundle for a RESTORE event in a series of strings that * will be persisted in a text file and printed in the dumpsys. * - * If the evenntBundle passed is not a RESTORE event, return early + * If the eventBundle passed is not a RESTORE event, return early * * Key information related to the event: * - Timestamp (HAS TO ALWAYS BE THE FIRST LINE OF EACH EVENT) @@ -62,17 +84,22 @@ public class BackupManagerMonitorDumpsysUtils { * - Agent logs (if available) * * Example of formatting: - * RESTORE Event: [2023-08-18 17:16:00.735] Agent - Agent logging results - * Package name: com.android.wallpaperbackup - * Agent Logs: - * Data Type: wlp_img_system - * Item restored: 0/1 - * Agent Error - Category: no_wallpaper, Count: 1 - * Data Type: wlp_img_lock - * Item restored: 0/1 - * Agent Error - Category: no_wallpaper, Count: 1 + * [2023-09-21 14:43:33.824] - Agent logging results + * Package: com.android.wallpaperbackup + * Agent Logs: + * Data Type: wlp_img_system + * Item restored: 0/1 + * Agent Error - Category: no_wallpaper, Count: 1 + * Data Type: wlp_img_lock + * Item restored: 0/1 + * Agent Error - Category: no_wallpaper, Count: 1 */ public void parseBackupManagerMonitorRestoreEventForDumpsys(Bundle eventBundle) { + if (isAfterRetentionPeriod()) { + // We only log data for the first 60 days since setup + return; + } + if (eventBundle == null) { return; } @@ -89,8 +116,19 @@ public class BackupManagerMonitorDumpsysUtils { } File bmmEvents = getBMMEventsFile(); + if (bmmEvents.length() == 0) { + // We are parsing the first restore event. + // Time to also record the setup timestamp of the device + recordSetUpTimestamp(); + } + + if(isFileLargerThanSizeLimit(bmmEvents)){ + // Do not write more events if the file is over size limit + return; + } + try (FileOutputStream out = new FileOutputStream(bmmEvents, /*append*/ true); - PrintWriter pw = new FastPrintWriter(out);) { + PrintWriter pw = new FastPrintWriter(out);) { int eventCategory = eventBundle.getInt(BackupManagerMonitor.EXTRA_LOG_EVENT_CATEGORY); int eventId = eventBundle.getInt(BackupManagerMonitor.EXTRA_LOG_EVENT_ID); @@ -101,17 +139,16 @@ public class BackupManagerMonitorDumpsysUtils { return; } - pw.println("RESTORE Event: [" + timestamp() + "] " + - getCategory(eventCategory) + " - " + - getId(eventId)); + pw.println("[" + timestamp() + "] - " + getId(eventId)); if (eventBundle.containsKey(BackupManagerMonitor.EXTRA_LOG_EVENT_PACKAGE_NAME)) { - pw.println("\tPackage name: " + pw.println("\tPackage: " + eventBundle.getString(BackupManagerMonitor.EXTRA_LOG_EVENT_PACKAGE_NAME)); } // TODO(b/296818666): add extras to the events addAgentLogsIfAvailable(eventBundle, pw); + addExtrasIfAvailable(eventBundle, pw); } catch (java.io.IOException e) { Slog.e(TAG, "IO Exception when writing BMM events to file: " + e); } @@ -156,6 +193,37 @@ public class BackupManagerMonitorDumpsysUtils { } } + /** + * Extracts some extras (defined in BackupManagerMonitor as EXTRA_LOG_<description>) + * from the BackupManagerMonitor event. Not all extras have the same importance. For now only + * focus on extras relating to version mismatches between packages on the source and target. + * + * When an event with ID LOG_EVENT_ID_RESTORE_VERSION_HIGHER (trying to restore from higher to + * lower version of a package) parse: + * EXTRA_LOG_RESTORE_VERSION [int]: the version of the package on the source + * EXTRA_LOG_RESTORE_ANYWAY [bool]: if the package allows restore any version + * EXTRA_LOG_RESTORE_VERSION_TARGET [int]: an extra to record the package version on the target + */ + private void addExtrasIfAvailable(Bundle eventBundle, PrintWriter pw) { + if (eventBundle.getInt(BackupManagerMonitor.EXTRA_LOG_EVENT_ID) == + BackupManagerMonitor.LOG_EVENT_ID_RESTORE_VERSION_HIGHER) { + if (eventBundle.containsKey(BackupManagerMonitor.EXTRA_LOG_RESTORE_ANYWAY)) { + pw.println("\t\tPackage supports RestoreAnyVersion: " + + eventBundle.getBoolean(BackupManagerMonitor.EXTRA_LOG_RESTORE_ANYWAY)); + } + if (eventBundle.containsKey(BackupManagerMonitor.EXTRA_LOG_RESTORE_VERSION)) { + pw.println("\t\tPackage version on source: " + + eventBundle.getLong(BackupManagerMonitor.EXTRA_LOG_RESTORE_VERSION)); + } + if (eventBundle.containsKey( + BackupManagerMonitor.EXTRA_LOG_EVENT_PACKAGE_LONG_VERSION)) { + pw.println("\t\tPackage version on target: " + + eventBundle.getLong( + BackupManagerMonitor.EXTRA_LOG_EVENT_PACKAGE_LONG_VERSION)); + } + } + } + /* * Get the path of the text files which stores the BMM events */ @@ -165,6 +233,13 @@ public class BackupManagerMonitorDumpsysUtils { return fname; } + public boolean isFileLargerThanSizeLimit(File events){ + if (!mIsFileLargerThanSizeLimit) { + mIsFileLargerThanSizeLimit = events.length() > getBMMEventsFileSizeLimit(); + } + return mIsFileLargerThanSizeLimit; + } + private String timestamp() { long currentTime = System.currentTimeMillis(); Date date = new Date(currentTime); @@ -245,6 +320,32 @@ public class BackupManagerMonitorDumpsysUtils { case BackupManagerMonitor.LOG_EVENT_ID_TRANSPORT_NON_INCREMENTAL_BACKUP_REQUIRED -> "Transport non-incremental backup required"; case BackupManagerMonitor.LOG_EVENT_ID_AGENT_LOGGING_RESULTS -> "Agent logging results"; + case BackupManagerMonitor.LOG_EVENT_ID_START_SYSTEM_RESTORE -> "Start system restore"; + case BackupManagerMonitor.LOG_EVENT_ID_START_RESTORE_AT_INSTALL -> + "Start restore at install"; + case BackupManagerMonitor.LOG_EVENT_ID_TRANSPORT_ERROR_DURING_START_RESTORE -> + "Transport error during start restore"; + case BackupManagerMonitor.LOG_EVENT_ID_CANNOT_GET_NEXT_PKG_NAME -> + "Cannot get next package name"; + case BackupManagerMonitor.LOG_EVENT_ID_UNKNOWN_RESTORE_TYPE -> "Unknown restore type"; + case BackupManagerMonitor.LOG_EVENT_ID_KV_RESTORE -> "KV restore"; + case BackupManagerMonitor.LOG_EVENT_ID_FULL_RESTORE -> "Full restore"; + case BackupManagerMonitor.LOG_EVENT_ID_NO_NEXT_RESTORE_TARGET -> + "No next restore target"; + case BackupManagerMonitor.LOG_EVENT_ID_KV_AGENT_ERROR -> "KV agent error"; + case BackupManagerMonitor.LOG_EVENT_ID_PACKAGE_RESTORE_FINISHED -> + "Package restore finished"; + case BackupManagerMonitor.LOG_EVENT_ID_TRANSPORT_ERROR_KV_RESTORE -> + "Transport error KV restore"; + case BackupManagerMonitor.LOG_EVENT_ID_NO_FEEDER_THREAD -> "No feeder thread"; + case BackupManagerMonitor.LOG_EVENT_ID_FULL_AGENT_ERROR -> "Full agent error"; + case BackupManagerMonitor.LOG_EVENT_ID_TRANSPORT_ERROR_FULL_RESTORE -> + "Transport error full restore"; + case BackupManagerMonitor.LOG_EVENT_ID_RESTORE_COMPLETE -> "Restore complete"; + case BackupManagerMonitor.LOG_EVENT_ID_START_PACKAGE_RESTORE -> + "Start package restore"; + case BackupManagerMonitor.LOG_EVENT_ID_AGENT_FAILURE -> + "Agent failure"; default -> "Unknown log event ID: " + code; }; return id; @@ -257,4 +358,128 @@ public class BackupManagerMonitorDumpsysUtils { default -> false; }; } + + /** + * Store the timestamp when the device was set up (date when the first BMM event is parsed) + * in a text file. + */ + @VisibleForTesting + void recordSetUpTimestamp() { + File setupDateFile = getSetUpDateFile(); + // record setup timestamp only once + if (setupDateFile.length() == 0) { + try (FileOutputStream out = new FileOutputStream(setupDateFile, /*append*/ true); + PrintWriter pw = new FastPrintWriter(out);) { + long currentDate = System.currentTimeMillis(); + pw.println(currentDate); + } catch (IOException e) { + Slog.w(TAG, "An error occurred while recording the setup date: " + + e.getMessage()); + } + } + + } + + @VisibleForTesting + String getSetUpDate() { + File fname = getSetUpDateFile(); + try (FileInputStream inputStream = new FileInputStream(fname); + InputStreamReader reader = new InputStreamReader(inputStream); + BufferedReader bufferedReader = new BufferedReader(reader);) { + return bufferedReader.readLine(); + } catch (Exception e) { + Slog.w(TAG, "An error occurred while reading the date: " + e.getMessage()); + return "Could not retrieve setup date"; + } + } + + @VisibleForTesting + static boolean isDateAfterNMillisec(long startTimeStamp, long endTimeStamp, long millisec) { + if (startTimeStamp > endTimeStamp) { + // Something has gone wrong, timeStamp1 should always precede timeStamp2. + // Out of caution return true: we would delete the logs rather than + // risking them being kept for longer than the retention period + return true; + } + long timeDifferenceMillis = endTimeStamp - startTimeStamp; + return (timeDifferenceMillis >= millisec); + } + + /** + * Check if current date is after retention period + */ + @VisibleForTesting + boolean isAfterRetentionPeriod() { + if (mIsAfterRetentionPeriodCached) { + return mIsAfterRetentionPeriod; + } else { + File setUpDateFile = getSetUpDateFile(); + if (setUpDateFile.length() == 0) { + // We are yet to record a setup date. This means we haven't parsed the first event. + mIsAfterRetentionPeriod = false; + mIsAfterRetentionPeriodCached = true; + return false; + } + try { + long setupTimestamp = Long.parseLong(getSetUpDate()); + long currentTimestamp = System.currentTimeMillis(); + mIsAfterRetentionPeriod = isDateAfterNMillisec(setupTimestamp, currentTimestamp, + getRetentionPeriodInMillisec()); + mIsAfterRetentionPeriodCached = true; + return mIsAfterRetentionPeriod; + } catch (NumberFormatException e) { + // An error occurred when parsing the setup timestamp. + // Out of caution return true: we would delete the logs rather than + // risking them being kept for longer than the retention period + mIsAfterRetentionPeriod = true; + mIsAfterRetentionPeriodCached = true; + return true; + } + } + } + + @VisibleForTesting + File getSetUpDateFile() { + File dataDir = new File(Environment.getDataDirectory(), BACKUP_PERSISTENT_DIR); + File setupDateFile = new File(dataDir, INITIAL_SETUP_TIMESTAMP_KEY + ".txt"); + return setupDateFile; + } + + @VisibleForTesting + long getRetentionPeriodInMillisec() { + return LOGS_RETENTION_PERIOD_MILLISEC; + } + + @VisibleForTesting + long getBMMEventsFileSizeLimit(){ + return BMM_FILE_SIZE_LIMIT_BYTES; + } + + /** + * Delete the BMM Events file after the retention period has passed. + * + * @return true if the retention period has passed false otherwise. + * we want to return true even if we were unable to delete the file, as this will prevent + * expired BMM events from being printed to the dumpsys + */ + public boolean deleteExpiredBMMEvents() { + try { + if (isAfterRetentionPeriod()) { + File bmmEvents = getBMMEventsFile(); + if (bmmEvents.exists()) { + if (bmmEvents.delete()) { + Slog.i(TAG, "Deleted expired BMM Events"); + } else { + Slog.e(TAG, "Unable to delete expired BMM Events"); + } + } + return true; + } + return false; + } catch (Exception e) { + // Handle any unexpected exceptions + // To be safe we return true as we want to avoid exposing expired BMMEvents + return true; + } + } } diff --git a/services/backup/java/com/android/server/backup/utils/BackupManagerMonitorEventSender.java b/services/backup/java/com/android/server/backup/utils/BackupManagerMonitorEventSender.java index 92e3107b6977..549d08c03933 100644 --- a/services/backup/java/com/android/server/backup/utils/BackupManagerMonitorEventSender.java +++ b/services/backup/java/com/android/server/backup/utils/BackupManagerMonitorEventSender.java @@ -222,4 +222,21 @@ public class BackupManagerMonitorEventSender { extras.putBoolean(key, value); return extras; } + + /** + * Adds given key-value pair in the bundle and returns the bundle. If bundle was null it will + * be created. + * + * @param extras - bundle where to add key-value to, if null a new bundle will be created. + * @param key - key. + * @param value - value. + * @return extras if it was not null and new bundle otherwise. + */ + public static Bundle putMonitoringExtra(Bundle extras, String key, int value) { + if (extras == null) { + extras = new Bundle(); + } + extras.putInt(key, value); + return extras; + } } |