From e83420591827d2e6559b6b036f80599e83b24999 Mon Sep 17 00:00:00 2001 From: Tianjie Date: Thu, 21 Jan 2021 21:16:44 -0800 Subject: [PATCH] Extend the metrics for resume on reboot We extend the resume on reboot metrics to help analyze the impact of new RoR features. Detailed atoms added are available in http://go/ror-metrics. This cl reports part of them in lock settings service. Bug: 179105110 Test: out/host/linux-x86/bin/statsd_testdrive 238; trigger ror & check the result; atest FrameworksServicesTests:RebootEscrowManagerTests Change-Id: I7e92c78cbd448bb49f941670d0c4489bc28d0886 --- .../locksettings/RebootEscrowManager.java | 55 ++++++++++++++----- .../RebootEscrowManagerTests.java | 43 +++++++++++---- 2 files changed, 75 insertions(+), 23 deletions(-) diff --git a/services/core/java/com/android/server/locksettings/RebootEscrowManager.java b/services/core/java/com/android/server/locksettings/RebootEscrowManager.java index 48382a946d4ba..09fade37ec23c 100644 --- a/services/core/java/com/android/server/locksettings/RebootEscrowManager.java +++ b/services/core/java/com/android/server/locksettings/RebootEscrowManager.java @@ -64,6 +64,8 @@ class RebootEscrowManager { @VisibleForTesting public static final String REBOOT_ESCROW_ARMED_KEY = "reboot_escrow_armed_count"; + static final String REBOOT_ESCROW_KEY_ARMED_TIMESTAMP = "reboot_escrow_key_stored_timestamp"; + /** * Number of boots until we consider the escrow data to be stale for the purposes of metrics. *

@@ -144,8 +146,7 @@ class RebootEscrowManager { private RebootEscrowProviderInterface createRebootEscrowProvider() { RebootEscrowProviderInterface rebootEscrowProvider; - if (DeviceConfig.getBoolean(DeviceConfig.NAMESPACE_OTA, - "server_based_ror_enabled", false)) { + if (serverBasedResumeOnReboot()) { Slog.i(TAG, "Using server based resume on reboot"); rebootEscrowProvider = new RebootEscrowProviderServerBasedImpl(mContext, mStorage); } else { @@ -166,6 +167,11 @@ class RebootEscrowManager { handler.postDelayed(runnable, delayMillis); } + public boolean serverBasedResumeOnReboot() { + return DeviceConfig.getBoolean(DeviceConfig.NAMESPACE_OTA, + "server_based_ror_enabled", false); + } + public Context getContext() { return mContext; } @@ -204,10 +210,12 @@ class RebootEscrowManager { DEFAULT_LOAD_ESCROW_DATA_RETRY_INTERVAL_SECONDS); } - public void reportMetric(boolean success) { - // TODO(b/179105110) design error code; and report the true value for other fields. - FrameworkStatsLog.write(FrameworkStatsLog.REBOOT_ESCROW_RECOVERY_REPORTED, 0, 1, 1, - -1, 0, -1); + public void reportMetric(boolean success, int errorCode, int serviceType, int attemptCount, + int escrowDurationInSeconds, int vbmetaDigestStatus, + int durationSinceBootCompleteInSeconds) { + FrameworkStatsLog.write(FrameworkStatsLog.REBOOT_ESCROW_RECOVERY_REPORTED, success, + errorCode, serviceType, attemptCount, escrowDurationInSeconds, + vbmetaDigestStatus, durationSinceBootCompleteInSeconds); } public RebootEscrowEventLog getEventLog() { @@ -230,7 +238,7 @@ class RebootEscrowManager { mKeyStoreManager = injector.getKeyStoreManager(); } - private void onGetRebootEscrowKeyFailed(List users) { + private void onGetRebootEscrowKeyFailed(List users, int attemptCount) { Slog.w(TAG, "Had reboot escrow data for users, but no key; removing escrow storage."); for (UserInfo user : users) { mStorage.removeRebootEscrow(user.id); @@ -238,7 +246,7 @@ class RebootEscrowManager { // Clear the old key in keystore. mKeyStoreManager.clearKeyStoreEncryptionKey(); - onEscrowRestoreComplete(false); + onEscrowRestoreComplete(false, attemptCount); } void loadRebootEscrowDataIfAvailable(Handler retryHandler) { @@ -274,7 +282,7 @@ class RebootEscrowManager { } Slog.w(TAG, "Failed to load reboot escrow data after " + attemptNumber + " attempts"); - onGetRebootEscrowKeyFailed(users); + onGetRebootEscrowKeyFailed(users, attemptNumber); } void loadRebootEscrowDataWithRetry(Handler retryHandler, int attemptNumber, @@ -297,7 +305,7 @@ class RebootEscrowManager { } if (escrowKey == null) { - onGetRebootEscrowKeyFailed(users); + onGetRebootEscrowKeyFailed(users, attemptNumber + 1); return; } @@ -311,16 +319,35 @@ class RebootEscrowManager { // Clear the old key in keystore. A new key will be generated by new RoR requests. mKeyStoreManager.clearKeyStoreEncryptionKey(); - onEscrowRestoreComplete(allUsersUnlocked); + onEscrowRestoreComplete(allUsersUnlocked, attemptNumber + 1); } - private void onEscrowRestoreComplete(boolean success) { + private void reportMetricOnRestoreComplete(boolean success, int attemptCount) { + int serviceType = mInjector.serverBasedResumeOnReboot() + ? FrameworkStatsLog.REBOOT_ESCROW_RECOVERY_REPORTED__TYPE__SERVER_BASED + : FrameworkStatsLog.REBOOT_ESCROW_RECOVERY_REPORTED__TYPE__HAL; + + long armedTimestamp = mStorage.getLong(REBOOT_ESCROW_KEY_ARMED_TIMESTAMP, -1, + USER_SYSTEM); + mStorage.removeKey(REBOOT_ESCROW_KEY_ARMED_TIMESTAMP, USER_SYSTEM); + int escrowDurationInSeconds = armedTimestamp != -1 + ? (int) (System.currentTimeMillis() - armedTimestamp) / 1000 : -1; + + // TODO(b/179105110) design error code; and report the true value for other fields. + int vbmetaDigestStatus = FrameworkStatsLog + .REBOOT_ESCROW_RECOVERY_REPORTED__VBMETA_DIGEST_STATUS__MATCH_EXPECTED_SLOT; + + mInjector.reportMetric(success, 0 /* error code */, serviceType, attemptCount, + escrowDurationInSeconds, vbmetaDigestStatus, -1); + } + + private void onEscrowRestoreComplete(boolean success, int attemptCount) { int previousBootCount = mStorage.getInt(REBOOT_ESCROW_ARMED_KEY, -1, USER_SYSTEM); mStorage.removeKey(REBOOT_ESCROW_ARMED_KEY, USER_SYSTEM); int bootCountDelta = mInjector.getBootCount() - previousBootCount; if (success || (previousBootCount != -1 && bootCountDelta <= BOOT_COUNT_TOLERANCE)) { - mInjector.reportMetric(success); + reportMetricOnRestoreComplete(success, attemptCount); } } @@ -476,6 +503,8 @@ class RebootEscrowManager { boolean armedRebootEscrow = rebootEscrowProvider.storeRebootEscrowKey(escrowKey, kk); if (armedRebootEscrow) { mStorage.setInt(REBOOT_ESCROW_ARMED_KEY, mInjector.getBootCount(), USER_SYSTEM); + mStorage.setLong(REBOOT_ESCROW_KEY_ARMED_TIMESTAMP, System.currentTimeMillis(), + USER_SYSTEM); mEventLog.addEntry(RebootEscrowEvent.SET_ARMED_STATUS); } diff --git a/services/tests/servicestests/src/com/android/server/locksettings/RebootEscrowManagerTests.java b/services/tests/servicestests/src/com/android/server/locksettings/RebootEscrowManagerTests.java index b51f4df432593..91342ce925f65 100644 --- a/services/tests/servicestests/src/com/android/server/locksettings/RebootEscrowManagerTests.java +++ b/services/tests/servicestests/src/com/android/server/locksettings/RebootEscrowManagerTests.java @@ -26,6 +26,7 @@ import static org.junit.Assert.assertNotNull; import static org.junit.Assert.assertTrue; import static org.mockito.ArgumentMatchers.any; import static org.mockito.ArgumentMatchers.anyBoolean; +import static org.mockito.ArgumentMatchers.anyInt; import static org.mockito.ArgumentMatchers.anyLong; import static org.mockito.ArgumentMatchers.eq; import static org.mockito.Mockito.clearInvocations; @@ -109,7 +110,8 @@ public class RebootEscrowManagerTests { public interface MockableRebootEscrowInjected { int getBootCount(); - void reportMetric(boolean success); + void reportMetric(boolean success, int errorCode, int serviceType, int attemptCount, + int escrowDurationInSeconds, int vbmetaDigestStatus, int durationSinceBootComplete); } static class MockInjector extends RebootEscrowManager.Injector { @@ -119,6 +121,7 @@ public class RebootEscrowManagerTests { private final UserManager mUserManager; private final MockableRebootEscrowInjected mInjected; private final RebootEscrowKeyStoreManager mKeyStoreManager; + private final boolean mServerBased; MockInjector(Context context, UserManager userManager, IRebootEscrow rebootEscrow, @@ -128,6 +131,7 @@ public class RebootEscrowManagerTests { super(context, storage); mRebootEscrow = rebootEscrow; mServiceConnection = null; + mServerBased = false; RebootEscrowProviderHalImpl.Injector halInjector = new RebootEscrowProviderHalImpl.Injector() { @Override @@ -149,6 +153,7 @@ public class RebootEscrowManagerTests { super(context, storage); mServiceConnection = serviceConnection; mRebootEscrow = null; + mServerBased = true; RebootEscrowProviderServerBasedImpl.Injector injector = new RebootEscrowProviderServerBasedImpl.Injector(serviceConnection); mRebootEscrowProvider = new RebootEscrowProviderServerBasedImpl(storage, injector); @@ -167,6 +172,11 @@ public class RebootEscrowManagerTests { return mUserManager; } + @Override + public boolean serverBasedResumeOnReboot() { + return mServerBased; + } + @Override public RebootEscrowProviderInterface getRebootEscrowProvider() { return mRebootEscrowProvider; @@ -195,8 +205,11 @@ public class RebootEscrowManagerTests { } @Override - public void reportMetric(boolean success) { - mInjected.reportMetric(success); + public void reportMetric(boolean success, int errorCode, int serviceType, int attemptCount, + int escrowDurationInSeconds, int vbmetaDigestStatus, + int durationSinceBootComplete) { + mInjected.reportMetric(success, errorCode, serviceType, attemptCount, + escrowDurationInSeconds, vbmetaDigestStatus, durationSinceBootComplete); } } @@ -418,7 +431,9 @@ public class RebootEscrowManagerTests { when(mInjected.getBootCount()).thenReturn(1); ArgumentCaptor metricsSuccessCaptor = ArgumentCaptor.forClass(Boolean.class); - doNothing().when(mInjected).reportMetric(metricsSuccessCaptor.capture()); + doNothing().when(mInjected).reportMetric(metricsSuccessCaptor.capture(), + eq(0) /* error code */, eq(1) /* HAL based */, eq(1) /* attempt count */, + anyInt(), anyInt(), anyInt()); when(mRebootEscrow.retrieveKey()).thenAnswer(invocation -> keyByteCaptor.getValue()); mService.loadRebootEscrowDataIfAvailable(null); @@ -451,7 +466,9 @@ public class RebootEscrowManagerTests { // pretend reboot happens here when(mInjected.getBootCount()).thenReturn(1); ArgumentCaptor metricsSuccessCaptor = ArgumentCaptor.forClass(Boolean.class); - doNothing().when(mInjected).reportMetric(metricsSuccessCaptor.capture()); + doNothing().when(mInjected).reportMetric(metricsSuccessCaptor.capture(), + eq(0) /* error code */, eq(2) /* Server based */, eq(1) /* attempt count */, + anyInt(), anyInt(), anyInt()); when(mServiceConnection.unwrap(any(), anyLong())) .thenAnswer(invocation -> invocation.getArgument(0)); @@ -485,7 +502,8 @@ public class RebootEscrowManagerTests { // pretend reboot happens here when(mInjected.getBootCount()).thenReturn(1); ArgumentCaptor metricsSuccessCaptor = ArgumentCaptor.forClass(Boolean.class); - doNothing().when(mInjected).reportMetric(metricsSuccessCaptor.capture()); + doNothing().when(mInjected).reportMetric(metricsSuccessCaptor.capture(), + anyInt(), anyInt(), eq(2) /* attempt count */, anyInt(), anyInt(), anyInt()); when(mServiceConnection.unwrap(any(), anyLong())) .thenThrow(new IOException()) @@ -528,7 +546,8 @@ public class RebootEscrowManagerTests { mService.loadRebootEscrowDataIfAvailable(null); verify(mRebootEscrow).retrieveKey(); - verify(mInjected, never()).reportMetric(anyBoolean()); + verify(mInjected, never()).reportMetric(anyBoolean(), anyInt(), anyInt(), anyInt(), + anyInt(), anyInt(), anyInt()); } @Test @@ -554,7 +573,8 @@ public class RebootEscrowManagerTests { when(mRebootEscrow.retrieveKey()).thenReturn(new byte[32]); mService.loadRebootEscrowDataIfAvailable(null); - verify(mInjected, never()).reportMetric(anyBoolean()); + verify(mInjected, never()).reportMetric(anyBoolean(), anyInt(), anyInt(), anyInt(), + anyInt(), anyInt(), anyInt()); } @Test @@ -588,7 +608,8 @@ public class RebootEscrowManagerTests { when(mRebootEscrow.retrieveKey()).thenAnswer(invocation -> keyByteCaptor.getValue()); mService.loadRebootEscrowDataIfAvailable(null); - verify(mInjected).reportMetric(eq(true)); + verify(mInjected).reportMetric(eq(true), eq(0) /* error code */, eq(1) /* HAL based */, + eq(1) /* attempt count */, anyInt(), anyInt(), anyInt()); } @Test @@ -615,7 +636,9 @@ public class RebootEscrowManagerTests { when(mInjected.getBootCount()).thenReturn(1); ArgumentCaptor metricsSuccessCaptor = ArgumentCaptor.forClass(Boolean.class); - doNothing().when(mInjected).reportMetric(metricsSuccessCaptor.capture()); + doNothing().when(mInjected).reportMetric(metricsSuccessCaptor.capture(), + anyInt() /* error code */, eq(1) /* HAL based */, eq(1) /* attempt count */, + anyInt(), anyInt(), anyInt()); when(mRebootEscrow.retrieveKey()).thenAnswer(invocation -> new byte[32]); mService.loadRebootEscrowDataIfAvailable(null); verify(mRebootEscrow).retrieveKey();