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 eab998a9af)

Bug: 151890602
Test: m
Merged-In: I85adb8c3c5598ef4ce11550b51f22d1ce3c282a6
Change-Id: I85adb8c3c5598ef4ce11550b51f22d1ce3c282a6
This commit is contained in:
JW Wang
2020-03-30 15:53:39 +08:00
parent d7437c58c0
commit 5b163cfcee
2 changed files with 13 additions and 15 deletions

View File

@@ -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

View File

@@ -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);
}