From 9d1eeeebc58501ab9c057fbea1460c86127d7311 Mon Sep 17 00:00:00 2001 From: Gavin Corkery Date: Mon, 27 Apr 2020 11:20:42 +0100 Subject: [PATCH] Attach logging package to staged rollback IDs To ensure consistency in pre-reboot and post-reboot metrics, associate the logging package name of a rolled back train with the staged rollback id. This uses the assumption that there is at most one logging parent (train version package) associated with the rollback. This means that there will be only one ROLLBACK_SUCCESS or ROLLBACK_FAILURE log for each event. This change changes the format of the last-staged-rollback-ids file. The file now has one line for each rollback id, rather than one line containing all ids. Test: Manual test of logging flow for a train that is configured correctly, and configured incorrectly Test: atest RollbackUnitTest Bug: 154911735 Change-Id: Ie942fdb9313137c2dc6e696840262dd457558c6d Merged-In: Ie942fdb9313137c2dc6e696840262dd457558c6d --- .../RollbackPackageHealthObserver.java | 68 +++++++++++-------- .../rollback/WatchdogRollbackLogger.java | 50 +++++--------- .../server/rollback/RollbackUnitTest.java | 21 ++++++ 3 files changed, 78 insertions(+), 61 deletions(-) diff --git a/services/core/java/com/android/server/rollback/RollbackPackageHealthObserver.java b/services/core/java/com/android/server/rollback/RollbackPackageHealthObserver.java index f6d46e24246c2..3601f1d94474d 100644 --- a/services/core/java/com/android/server/rollback/RollbackPackageHealthObserver.java +++ b/services/core/java/com/android/server/rollback/RollbackPackageHealthObserver.java @@ -36,9 +36,9 @@ import android.os.Handler; import android.os.HandlerThread; import android.os.PowerManager; import android.os.SystemProperties; -import android.text.TextUtils; import android.util.ArraySet; import android.util.Slog; +import android.util.SparseArray; import com.android.internal.annotations.GuardedBy; import com.android.internal.util.FrameworkStatsLog; @@ -56,9 +56,7 @@ import java.io.FileOutputStream; import java.io.FileReader; import java.io.IOException; import java.io.PrintWriter; -import java.util.ArrayList; import java.util.Collections; -import java.util.Iterator; import java.util.List; import java.util.Set; @@ -156,12 +154,11 @@ public final class RollbackPackageHealthObserver implements PackageHealthObserve PackageWatchdog.getInstance(mContext).scheduleCheckAndMitigateNativeCrashes(); } - List rollbackIds = popLastStagedRollbackIds(); - Iterator rollbackIterator = rollbackIds.iterator(); - while (rollbackIterator.hasNext()) { - int rollbackId = rollbackIterator.next(); - WatchdogRollbackLogger.logRollbackStatusOnBoot( - mContext, rollbackId, rollbackManager.getRecentlyCommittedRollbacks()); + SparseArray rollbackIds = popLastStagedRollbackIds(); + for (int i = 0; i < rollbackIds.size(); i++) { + WatchdogRollbackLogger.logRollbackStatusOnBoot(mContext, + rollbackIds.keyAt(i), rollbackIds.valueAt(i), + rollbackManager.getRecentlyCommittedRollbacks()); } } @@ -224,7 +221,7 @@ public final class RollbackPackageHealthObserver implements PackageHealthObserve packageInstaller.getSessionInfo(sessionId); if (sessionInfo.isStagedSessionReady() && markStagedSessionHandled(rollbackId)) { mContext.unregisterReceiver(listener); - saveStagedRollbackId(rollbackId); + saveStagedRollbackId(rollbackId, logPackage); WatchdogRollbackLogger.logEvent(logPackage, FrameworkStatsLog .WATCHDOG_ROLLBACK_OCCURRED__ROLLBACK_TYPE__ROLLBACK_BOOT_TRIGGERED, @@ -268,39 +265,54 @@ public final class RollbackPackageHealthObserver implements PackageHealthObserve } } - private void saveStagedRollbackId(int stagedRollbackId) { + private void saveStagedRollbackId(int stagedRollbackId, @Nullable VersionedPackage logPackage) { + writeStagedRollbackId(mLastStagedRollbackIdsFile, stagedRollbackId, logPackage); + } + + static void writeStagedRollbackId(File file, int stagedRollbackId, + @Nullable VersionedPackage logPackage) { try { - FileOutputStream fos = new FileOutputStream( - mLastStagedRollbackIdsFile, /*append*/true); + FileOutputStream fos = new FileOutputStream(file, true); PrintWriter pw = new PrintWriter(fos); - pw.append(",").append(String.valueOf(stagedRollbackId)); + String logPackageName = logPackage != null ? logPackage.getPackageName() : ""; + pw.append(String.valueOf(stagedRollbackId)).append(",").append(logPackageName); + pw.println(); pw.flush(); FileUtils.sync(fos); pw.close(); } catch (IOException e) { Slog.e(TAG, "Failed to save last staged rollback id", e); + file.delete(); + } + } + + private SparseArray popLastStagedRollbackIds() { + try { + return readStagedRollbackIds(mLastStagedRollbackIdsFile); + } finally { mLastStagedRollbackIdsFile.delete(); } } - private List popLastStagedRollbackIds() { - try (BufferedReader reader = - new BufferedReader(new FileReader(mLastStagedRollbackIdsFile))) { - String line = reader.readLine(); - // line is of format : ",id1,id2,id3....,idn" - String[] sessionIdsStr = line.split(","); - ArrayList result = new ArrayList<>(); - for (String sessionIdStr: sessionIdsStr) { - if (!TextUtils.isEmpty(sessionIdStr.trim())) { - result.add(Integer.parseInt(sessionIdStr)); + static SparseArray readStagedRollbackIds(File file) { + SparseArray result = new SparseArray<>(); + try { + String line; + BufferedReader reader = new BufferedReader(new FileReader(file)); + while ((line = reader.readLine()) != null) { + // Each line is of the format: "id,logging_package" + String[] values = line.trim().split(","); + String rollbackId = values[0]; + String logPackageName = ""; + if (values.length > 1) { + logPackageName = values[1]; } + result.put(Integer.parseInt(rollbackId), logPackageName); } - return result; } catch (Exception ignore) { - return Collections.emptyList(); - } finally { - mLastStagedRollbackIdsFile.delete(); + return new SparseArray<>(); } + return result; } diff --git a/services/core/java/com/android/server/rollback/WatchdogRollbackLogger.java b/services/core/java/com/android/server/rollback/WatchdogRollbackLogger.java index 659de0093ead9..e72c185a0d2d3 100644 --- a/services/core/java/com/android/server/rollback/WatchdogRollbackLogger.java +++ b/services/core/java/com/android/server/rollback/WatchdogRollbackLogger.java @@ -36,6 +36,7 @@ import android.content.pm.PackageManager; import android.content.pm.VersionedPackage; import android.content.rollback.PackageRollbackInfo; import android.content.rollback.RollbackInfo; +import android.text.TextUtils; import android.util.ArraySet; import android.util.Slog; @@ -43,7 +44,6 @@ import com.android.internal.annotations.VisibleForTesting; import com.android.internal.util.FrameworkStatsLog; import com.android.server.PackageWatchdog; -import java.util.ArrayList; import java.util.List; import java.util.Set; @@ -115,7 +115,7 @@ public final class WatchdogRollbackLogger { } - static void logRollbackStatusOnBoot(Context context, int rollbackId, + static void logRollbackStatusOnBoot(Context context, int rollbackId, String logPackageName, List recentlyCommittedRollbacks) { PackageInstaller packageInstaller = context.getPackageManager().getPackageInstaller(); @@ -132,23 +132,15 @@ public final class WatchdogRollbackLogger { return; } - // Identify the logging parent for this rollback. When all configurations are correct, - // each package in the rollback has a logging parent set in metadata. - final Set loggingPackageNames = new ArraySet<>(); - for (PackageRollbackInfo packageRollback : rollback.getPackages()) { - final String loggingParentName = getLoggingParentName(context, - packageRollback.getPackageName()); - if (loggingParentName != null) { - loggingPackageNames.add(loggingParentName); - } - } - // Use the version of the logging parent that was installed before // we rolled back for logging purposes. - final List oldLoggingPackages = new ArrayList<>(); - for (PackageRollbackInfo packageRollback : rollback.getPackages()) { - if (loggingPackageNames.contains(packageRollback.getPackageName())) { - oldLoggingPackages.add(packageRollback.getVersionRolledBackFrom()); + VersionedPackage oldLoggingPackage = null; + if (!TextUtils.isEmpty(logPackageName)) { + for (PackageRollbackInfo packageRollback : rollback.getPackages()) { + if (logPackageName.equals(packageRollback.getPackageName())) { + oldLoggingPackage = packageRollback.getVersionRolledBackFrom(); + break; + } } } @@ -159,22 +151,14 @@ public final class WatchdogRollbackLogger { return; } - // If no logging packages are found, use a null package to ensure the rollback status - // is still logged. - if (oldLoggingPackages.isEmpty()) { - oldLoggingPackages.add(null); - } - - for (VersionedPackage oldLoggingPackage : oldLoggingPackages) { - if (sessionInfo.isStagedSessionApplied()) { - logEvent(oldLoggingPackage, - WATCHDOG_ROLLBACK_OCCURRED__ROLLBACK_TYPE__ROLLBACK_SUCCESS, - WATCHDOG_ROLLBACK_OCCURRED__ROLLBACK_REASON__REASON_UNKNOWN, ""); - } else if (sessionInfo.isStagedSessionFailed()) { - logEvent(oldLoggingPackage, - WATCHDOG_ROLLBACK_OCCURRED__ROLLBACK_TYPE__ROLLBACK_FAILURE, - WATCHDOG_ROLLBACK_OCCURRED__ROLLBACK_REASON__REASON_UNKNOWN, ""); - } + if (sessionInfo.isStagedSessionApplied()) { + logEvent(oldLoggingPackage, + WATCHDOG_ROLLBACK_OCCURRED__ROLLBACK_TYPE__ROLLBACK_SUCCESS, + WATCHDOG_ROLLBACK_OCCURRED__ROLLBACK_REASON__REASON_UNKNOWN, ""); + } else if (sessionInfo.isStagedSessionFailed()) { + logEvent(oldLoggingPackage, + WATCHDOG_ROLLBACK_OCCURRED__ROLLBACK_TYPE__ROLLBACK_FAILURE, + WATCHDOG_ROLLBACK_OCCURRED__ROLLBACK_REASON__REASON_UNKNOWN, ""); } } diff --git a/services/tests/servicestests/src/com/android/server/rollback/RollbackUnitTest.java b/services/tests/servicestests/src/com/android/server/rollback/RollbackUnitTest.java index 8667801889cf9..01c89b3496872 100644 --- a/services/tests/servicestests/src/com/android/server/rollback/RollbackUnitTest.java +++ b/services/tests/servicestests/src/com/android/server/rollback/RollbackUnitTest.java @@ -30,6 +30,7 @@ import android.content.pm.PackageManagerInternal; import android.content.pm.VersionedPackage; import android.content.rollback.PackageRollbackInfo; import android.util.IntArray; +import android.util.SparseArray; import android.util.SparseIntArray; import android.util.SparseLongArray; @@ -354,6 +355,26 @@ public class RollbackUnitTest { assertThat(rollback.allPackagesEnabled()).isTrue(); } + @Test + public void readAndWriteStagedRollbackIdsFile() throws Exception { + File testFile = File.createTempFile("test", ".txt"); + RollbackPackageHealthObserver.writeStagedRollbackId(testFile, 2468, null); + RollbackPackageHealthObserver.writeStagedRollbackId(testFile, 12345, + new VersionedPackage("com.test.package", 1)); + RollbackPackageHealthObserver.writeStagedRollbackId(testFile, 13579, + new VersionedPackage("com.test.package2", 2)); + SparseArray readInfo = + RollbackPackageHealthObserver.readStagedRollbackIds(testFile); + assertThat(readInfo.size()).isEqualTo(3); + + assertThat(readInfo.keyAt(0)).isEqualTo(2468); + assertThat(readInfo.valueAt(0)).isEqualTo(""); + assertThat(readInfo.keyAt(1)).isEqualTo(12345); + assertThat(readInfo.valueAt(1)).isEqualTo("com.test.package"); + assertThat(readInfo.keyAt(2)).isEqualTo(13579); + assertThat(readInfo.valueAt(2)).isEqualTo("com.test.package2"); + } + @Test public void minExtVerConstraintNotViolated() { addPkgWithMinExtVersions("pkg0", new int[][] {{30, 4}});