From 5b163cfcee971458dd4dadd8d03ed7489e2780db Mon Sep 17 00:00:00 2001 From: JW Wang Date: Mon, 30 Mar 2020 15:53:39 +0800 Subject: [PATCH 1/2] Add logs for debugging See b/151890602#comment4. If the assumption is true, we will see logs that the rollback for testappA is exipred happens slightly after the call to #getAvailableRollbacks. Also move assertions below so the test runs to the end and we have a better picture for what happened during the test. (Cherry-picked from eab998a9afb052b5e022d0db9ab889e141213c42) Bug: 151890602 Test: m Merged-In: I85adb8c3c5598ef4ce11550b51f22d1ce3c282a6 Change-Id: I85adb8c3c5598ef4ce11550b51f22d1ce3c282a6 --- .../rollback/RollbackManagerServiceImpl.java | 9 +++------ .../android/tests/rollback/RollbackTest.java | 19 ++++++++++--------- 2 files changed, 13 insertions(+), 15 deletions(-) diff --git a/services/core/java/com/android/server/rollback/RollbackManagerServiceImpl.java b/services/core/java/com/android/server/rollback/RollbackManagerServiceImpl.java index b50c22ea09e31..e56bda2946f47 100644 --- a/services/core/java/com/android/server/rollback/RollbackManagerServiceImpl.java +++ b/services/core/java/com/android/server/rollback/RollbackManagerServiceImpl.java @@ -515,6 +515,7 @@ class RollbackManagerServiceImpl extends IRollbackManager.Stub { if (mRollbackLifetimeDurationInMillis < 0) { mRollbackLifetimeDurationInMillis = DEFAULT_ROLLBACK_LIFETIME_DURATION_MILLIS; } + Slog.d(TAG, "mRollbackLifetimeDurationInMillis=" + mRollbackLifetimeDurationInMillis); } @AnyThread @@ -656,9 +657,7 @@ class RollbackManagerServiceImpl extends IRollbackManager.Stub { if (!now.isBefore( rollbackTimestamp .plusMillis(mRollbackLifetimeDurationInMillis))) { - if (LOCAL_LOGV) { - Slog.v(TAG, "runExpiration id=" + rollback.info.getRollbackId()); - } + Slog.i(TAG, "runExpiration id=" + rollback.info.getRollbackId()); iter.remove(); rollback.delete(mAppDataRollbackHelper); } else if (oldest == null || oldest.isAfter(rollbackTimestamp)) { @@ -1170,9 +1169,7 @@ class RollbackManagerServiceImpl extends IRollbackManager.Stub { @WorkerThread @GuardedBy("rollback.getLock") private void makeRollbackAvailable(Rollback rollback) { - if (LOCAL_LOGV) { - Slog.v(TAG, "makeRollbackAvailable id=" + rollback.info.getRollbackId()); - } + Slog.i(TAG, "makeRollbackAvailable id=" + rollback.info.getRollbackId()); rollback.makeAvailable(); // TODO(zezeozue): Provide API to explicitly start observing instead diff --git a/tests/RollbackTest/RollbackTest/src/com/android/tests/rollback/RollbackTest.java b/tests/RollbackTest/RollbackTest/src/com/android/tests/rollback/RollbackTest.java index cab8b4258bc85..042ddd6c78824 100644 --- a/tests/RollbackTest/RollbackTest/src/com/android/tests/rollback/RollbackTest.java +++ b/tests/RollbackTest/RollbackTest/src/com/android/tests/rollback/RollbackTest.java @@ -487,23 +487,24 @@ public class RollbackTest { // Wait until rollback for app A has expired // This will trigger an expiration run that should expire app A but not B Thread.sleep(expirationTime / 2); - RollbackInfo rollback = + RollbackInfo rollbackA = getUniqueRollbackInfoForPackage(rm.getAvailableRollbacks(), TestApp.A); - assertThat(rollback).isNull(); + Log.i(TAG, "Checking if the rollback for TestApp.A is null"); // Rollback for app B should not be expired - rollback = getUniqueRollbackInfoForPackage( + RollbackInfo rollbackB1 = getUniqueRollbackInfoForPackage( rm.getAvailableRollbacks(), TestApp.B); - assertThat(rollback).isNotNull(); - assertThat(rollback).packagesContainsExactly( - Rollback.from(TestApp.B2).to(TestApp.B1)); // Wait until rollback for app B has expired Thread.sleep(expirationTime / 2); - rollback = getUniqueRollbackInfoForPackage( + RollbackInfo rollbackB2 = getUniqueRollbackInfoForPackage( rm.getAvailableRollbacks(), TestApp.B); - // Rollback should be expired by now - assertThat(rollback).isNull(); + + assertThat(rollbackA).isNull(); + assertThat(rollbackB1).isNotNull(); + assertThat(rollbackB1).packagesContainsExactly( + Rollback.from(TestApp.B2).to(TestApp.B1)); + assertThat(rollbackB2).isNull(); } finally { RollbackUtils.forwardTimeBy(-expirationTime); } From 9f8407b0aa145d304911fadb15c6515143e64c0d Mon Sep 17 00:00:00 2001 From: JW Wang Date: Tue, 31 Mar 2020 14:02:48 +0800 Subject: [PATCH 2/2] Run expiration when rollback lifetime is changed. DO NOT MERGE See b/151890602#comment6 for the detail. When rollback lifetime is changed, we need to re-schedule the expiration algorithm so rollbacks can expire at the correct time. Note we combine #runExpiration and #scheduleExpiration so there is only one entrance to schedule the expiration algorithm. See https://googleplex-android-review.git.corp.google.com/c/platform/frameworks/base/+/10899294/1/services/core/java/com/android/server/rollback/RollbackManagerServiceImpl.java#672 for the rationale. Bug: 151890602 Test: atest RollbackTest Change-Id: I10355143dedc0af92e0b2adfedb5f008e160cbb3 --- .../rollback/RollbackManagerServiceImpl.java | 20 ++++---- .../android/tests/rollback/RollbackTest.java | 47 +++++++++++++++++++ 2 files changed, 55 insertions(+), 12 deletions(-) diff --git a/services/core/java/com/android/server/rollback/RollbackManagerServiceImpl.java b/services/core/java/com/android/server/rollback/RollbackManagerServiceImpl.java index e56bda2946f47..5f871ad4f9e43 100644 --- a/services/core/java/com/android/server/rollback/RollbackManagerServiceImpl.java +++ b/services/core/java/com/android/server/rollback/RollbackManagerServiceImpl.java @@ -137,6 +137,7 @@ class RollbackManagerServiceImpl extends IRollbackManager.Stub { private final Installer mInstaller; private final RollbackPackageHealthObserver mPackageHealthObserver; private final AppDataRollbackHelper mAppDataRollbackHelper; + private final Runnable mRunExpiration = this::runExpiration; // The # of milli-seconds to sleep for each received ACTION_PACKAGE_ENABLE_ROLLBACK. // Used by #blockRollbackManager to test timeout in enabling rollbacks. @@ -516,6 +517,7 @@ class RollbackManagerServiceImpl extends IRollbackManager.Stub { mRollbackLifetimeDurationInMillis = DEFAULT_ROLLBACK_LIFETIME_DURATION_MILLIS; } Slog.d(TAG, "mRollbackLifetimeDurationInMillis=" + mRollbackLifetimeDurationInMillis); + runExpiration(); } @AnyThread @@ -644,6 +646,8 @@ class RollbackManagerServiceImpl extends IRollbackManager.Stub { // Schedules future expiration as appropriate. @WorkerThread private void runExpiration() { + getHandler().removeCallbacks(mRunExpiration); + Instant now = Instant.now(); Instant oldest = null; synchronized (mLock) { @@ -667,20 +671,12 @@ class RollbackManagerServiceImpl extends IRollbackManager.Stub { } if (oldest != null) { - scheduleExpiration(now.until(oldest.plusMillis(mRollbackLifetimeDurationInMillis), - ChronoUnit.MILLIS)); + long delay = now.until( + oldest.plusMillis(mRollbackLifetimeDurationInMillis), ChronoUnit.MILLIS); + getHandler().postDelayed(mRunExpiration, delay); } } - /** - * Schedules an expiration check to be run after the given duration in - * milliseconds has gone by. - */ - @AnyThread - private void scheduleExpiration(long duration) { - getHandler().postDelayed(() -> runExpiration(), duration); - } - @AnyThread private Handler getHandler() { return mHandlerThread.getThreadHandler(); @@ -1179,7 +1175,7 @@ class RollbackManagerServiceImpl extends IRollbackManager.Stub { // prepare to rollback if packages crashes too frequently. mPackageHealthObserver.startObservingHealth(rollback.getPackageNames(), mRollbackLifetimeDurationInMillis); - scheduleExpiration(mRollbackLifetimeDurationInMillis); + runExpiration(); } /* diff --git a/tests/RollbackTest/RollbackTest/src/com/android/tests/rollback/RollbackTest.java b/tests/RollbackTest/RollbackTest/src/com/android/tests/rollback/RollbackTest.java index 042ddd6c78824..48b5bed609d1d 100644 --- a/tests/RollbackTest/RollbackTest/src/com/android/tests/rollback/RollbackTest.java +++ b/tests/RollbackTest/RollbackTest/src/com/android/tests/rollback/RollbackTest.java @@ -434,6 +434,53 @@ public class RollbackTest { } } + /** + * Test that available rollbacks should expire correctly when the property + * {@link RollbackManager#PROPERTY_ROLLBACK_LIFETIME_MILLIS} is changed + */ + @Test + public void testRollbackExpiresWhenLifetimeChanges() throws Exception { + long defaultExpirationTime = TimeUnit.HOURS.toMillis(48); + RollbackManager rm = RollbackUtils.getRollbackManager(); + + try { + InstallUtils.adoptShellPermissionIdentity( + Manifest.permission.INSTALL_PACKAGES, + Manifest.permission.DELETE_PACKAGES, + Manifest.permission.TEST_MANAGE_ROLLBACKS, + Manifest.permission.WRITE_DEVICE_CONFIG); + + Uninstall.packages(TestApp.A); + assertThat(InstallUtils.getInstalledVersion(TestApp.A)).isEqualTo(-1); + Install.single(TestApp.A1).commit(); + assertThat(InstallUtils.getInstalledVersion(TestApp.A)).isEqualTo(1); + Install.single(TestApp.A2).setEnableRollback().commit(); + assertThat(InstallUtils.getInstalledVersion(TestApp.A)).isEqualTo(2); + RollbackInfo rollback = waitForAvailableRollback(TestApp.A); + assertThat(rollback).packagesContainsExactly(Rollback.from(TestApp.A2).to(TestApp.A1)); + + // Change the lifetime to 0 which should expire rollbacks immediately + DeviceConfig.setProperty(DeviceConfig.NAMESPACE_ROLLBACK_BOOT, + RollbackManager.PROPERTY_ROLLBACK_LIFETIME_MILLIS, + Long.toString(0), false /* makeDefault*/); + + // Keep polling until device config changes has happened (which might take more than + // 5 sec depending how busy system_server is) and rollbacks have expired + for (int i = 0; i < 30; ++i) { + if (hasRollbackInclude(rm.getAvailableRollbacks(), TestApp.A)) { + Thread.sleep(1000); + } + } + rollback = getUniqueRollbackInfoForPackage(rm.getAvailableRollbacks(), TestApp.A); + assertThat(rollback).isNull(); + } finally { + DeviceConfig.setProperty(DeviceConfig.NAMESPACE_ROLLBACK_BOOT, + RollbackManager.PROPERTY_ROLLBACK_LIFETIME_MILLIS, + Long.toString(defaultExpirationTime), false /* makeDefault*/); + InstallUtils.dropShellPermissionIdentity(); + } + } + /** * Test that changing time on device does not affect the duration of time that we keep * rollback available