Merge "Report more metrics in RecoverySystem"

services/core/java/com/android/server/recoverysystem/RecoverySystemService.java

@@ -21,11 +21,13 @@ import static android.os.UserHandle.USER_SYSTEM;
 import android.annotation.IntDef;
 import android.content.Context;
 import android.content.IntentSender;
+import android.content.SharedPreferences;
 import android.content.pm.PackageManager;
 import android.hardware.boot.V1_0.IBootControl;
 import android.net.LocalSocket;
 import android.net.LocalSocketAddress;
 import android.os.Binder;
+import android.os.Environment;
 import android.os.IRecoverySystem;
 import android.os.IRecoverySystemProgressListener;
 import android.os.PowerManager;
@@ -52,6 +54,7 @@ import libcore.io.IoUtils;
 
 import java.io.DataInputStream;
 import java.io.DataOutputStream;
+import java.io.File;
 import java.io.FileDescriptor;
 import java.io.FileWriter;
 import java.io.IOException;
@@ -87,6 +90,12 @@ public class RecoverySystemService extends IRecoverySystem.Stub implements Reboo
 
     private static final int SOCKET_CONNECTION_MAX_RETRY = 30;
 
+    static final String REQUEST_LSKF_TIMESTAMP_PREF_SUFFIX = "_request_lskf_timestamp";
+    static final String REQUEST_LSKF_COUNT_PREF_SUFFIX = "_request_lskf_count";
+
+    static final String LSKF_CAPTURED_TIMESTAMP_PREF = "lskf_captured_timestamp";
+    static final String LSKF_CAPTURED_COUNT_PREF = "lskf_captured_count";
+
     private final Injector mInjector;
     private final Context mContext;
 
@@ -127,7 +136,7 @@ public class RecoverySystemService extends IRecoverySystem.Stub implements Reboo
      */
     @IntDef({ ROR_NEED_PREPARATION,
             ROR_SKIP_PREPARATION_AND_NOTIFY,
-            ROR_SKIP_PREPARATION_NOT_NOTIFY })
+            ROR_SKIP_PREPARATION_NOT_NOTIFY})
     private @interface ResumeOnRebootActionsOnRequest {}
 
     /**
@@ -139,7 +148,7 @@ public class RecoverySystemService extends IRecoverySystem.Stub implements Reboo
     private @interface ResumeOnRebootActionsOnClear {}
 
     /**
-     * The error code for reboots initiated by resume on reboot clients.
+     * The error codes for reboots initiated by resume on reboot clients.
      */
     private static final int REBOOT_ERROR_NONE = 0;
     private static final int REBOOT_ERROR_UNKNOWN = 1;
@@ -156,11 +165,64 @@ public class RecoverySystemService extends IRecoverySystem.Stub implements Reboo
             REBOOT_ERROR_ARM_REBOOT_ESCROW_FAILURE})
     private @interface ResumeOnRebootRebootErrorCode {}
 
+    /**
+     * Manages shared preference, i.e. the storage used for metrics reporting.
+     */
+    public static class PreferencesManager {
+        private static final String METRICS_DIR = "recovery_system";
+        private static final String METRICS_PREFS_FILE = "RecoverySystemMetricsPrefs.xml";
+
+        protected final SharedPreferences mSharedPreferences;
+        private final File mMetricsPrefsFile;
+
+        PreferencesManager(Context context) {
+            File prefsDir = new File(Environment.getDataSystemCeDirectory(USER_SYSTEM),
+                    METRICS_DIR);
+            mMetricsPrefsFile = new File(prefsDir, METRICS_PREFS_FILE);
+            mSharedPreferences = context.getSharedPreferences(mMetricsPrefsFile, 0);
+        }
+
+        /** Reads the value of a given key with type long. **/
+        public long getLong(String key, long defaultValue) {
+            return mSharedPreferences.getLong(key, defaultValue);
+        }
+
+        /** Reads the value of a given key with type int. **/
+        public int getInt(String key, int defaultValue) {
+            return mSharedPreferences.getInt(key, defaultValue);
+        }
+
+        /** Stores the value of a given key with type long. **/
+        public void putLong(String key, long value) {
+            mSharedPreferences.edit().putLong(key, value).commit();
+        }
+
+        /** Stores the value of a given key with type int. **/
+        public void putInt(String key, int value) {
+            mSharedPreferences.edit().putInt(key, value).commit();
+        }
+
+        /** Increments the value of a given key with type int. **/
+        public synchronized void incrementIntKey(String key, int defaultInitialValue) {
+            int oldValue = getInt(key, defaultInitialValue);
+            putInt(key, oldValue + 1);
+        }
+
+        /** Delete the preference file and cleanup all metrics storage. **/
+        public void deletePrefsFile() {
+            if (!mMetricsPrefsFile.delete()) {
+                Slog.w(TAG, "Failed to delete metrics prefs");
+            }
+        }
+    }
+
     static class Injector {
         protected final Context mContext;
+        protected final PreferencesManager mPrefs;
 
         Injector(Context context) {
             mContext = context;
+            mPrefs = new PreferencesManager(context);
         }
 
         public Context getContext() {
@@ -236,6 +298,14 @@ public class RecoverySystemService extends IRecoverySystem.Stub implements Reboo
             return -1;
         }
 
+        public PreferencesManager getMetricsPrefs() {
+            return mPrefs;
+        }
+
+        public long getCurrentTimeMillis() {
+            return System.currentTimeMillis();
+        }
+
         public void reportRebootEscrowPreparationMetrics(int uid,
                 @ResumeOnRebootActionsOnRequest int requestResult, int requestedClientCount) {
             FrameworkStatsLog.write(FrameworkStatsLog.REBOOT_ESCROW_PREPARATION_REPORTED, uid,
@@ -414,7 +484,7 @@ public class RecoverySystemService extends IRecoverySystem.Stub implements Reboo
         if (mContext.checkCallingOrSelfPermission(android.Manifest.permission.RECOVERY)
                 != PackageManager.PERMISSION_GRANTED
                 && mContext.checkCallingOrSelfPermission(android.Manifest.permission.REBOOT)
-                        != PackageManager.PERMISSION_GRANTED) {
+                    != PackageManager.PERMISSION_GRANTED) {
             throw new SecurityException("Caller must have " + android.Manifest.permission.RECOVERY
                     + " or " + android.Manifest.permission.REBOOT + " for resume on reboot.");
         }
@@ -427,6 +497,12 @@ public class RecoverySystemService extends IRecoverySystem.Stub implements Reboo
             pendingRequestCount = mCallerPendingRequest.size();
         }
 
+        // Save the timestamp and request count for new ror request
+        PreferencesManager prefs = mInjector.getMetricsPrefs();
+        prefs.putLong(packageName + REQUEST_LSKF_TIMESTAMP_PREF_SUFFIX,
+                mInjector.getCurrentTimeMillis());
+        prefs.incrementIntKey(packageName + REQUEST_LSKF_COUNT_PREF_SUFFIX, 0);
+
         mInjector.reportRebootEscrowPreparationMetrics(uid, requestResult, pendingRequestCount);
     }
 
@@ -486,15 +562,31 @@ public class RecoverySystemService extends IRecoverySystem.Stub implements Reboo
     }
 
     private void reportMetricsOnPreparedForReboot() {
+        long currentTimestamp = mInjector.getCurrentTimeMillis();
+
         List<String> preparedClients;
         synchronized (this) {
             preparedClients = new ArrayList<>(mCallerPreparedForReboot);
         }
 
+        // Save the timestamp & lskf capture count for lskf capture
+        PreferencesManager prefs = mInjector.getMetricsPrefs();
+        prefs.putLong(LSKF_CAPTURED_TIMESTAMP_PREF, currentTimestamp);
+        prefs.incrementIntKey(LSKF_CAPTURED_COUNT_PREF, 0);
+
         for (String packageName : preparedClients) {
             int uid = mInjector.getUidFromPackageName(packageName);
+
+            int durationSeconds = -1;
+            long requestLskfTimestamp = prefs.getLong(
+                    packageName + REQUEST_LSKF_TIMESTAMP_PREF_SUFFIX, -1);
+            if (requestLskfTimestamp != -1 && currentTimestamp > requestLskfTimestamp) {
+                durationSeconds = (int) (currentTimestamp - requestLskfTimestamp) / 1000;
+            }
+            Slog.i(TAG, String.format("Reporting lskf captured, lskf capture takes %d seconds for"
+                    + " package %s", durationSeconds, packageName));
             mInjector.reportRebootEscrowLskfCapturedMetrics(uid, preparedClients.size(),
-                    -1 /* duration */);
+                    durationSeconds);
         }
     }
 
@@ -541,6 +633,7 @@ public class RecoverySystemService extends IRecoverySystem.Stub implements Reboo
             Slog.w(TAG, "Missing packageName when clearing lskf.");
             return false;
         }
+        // TODO(179105110) Clear the RoR metrics for the given packageName.
 
         @ResumeOnRebootActionsOnClear int action = updateRoRPreparationStateOnClear(packageName);
         switch (action) {
@@ -659,10 +752,23 @@ public class RecoverySystemService extends IRecoverySystem.Stub implements Reboo
             preparedClientCount = mCallerPreparedForReboot.size();
         }
 
-        // TODO(b/179105110) report the true value of duration and counts
+        long currentTimestamp = mInjector.getCurrentTimeMillis();
+        int durationSeconds = -1;
+        PreferencesManager prefs = mInjector.getMetricsPrefs();
+        long lskfCapturedTimestamp = prefs.getLong(LSKF_CAPTURED_TIMESTAMP_PREF, -1);
+        if (lskfCapturedTimestamp != -1 && currentTimestamp > lskfCapturedTimestamp) {
+            durationSeconds = (int) (currentTimestamp - lskfCapturedTimestamp) / 1000;
+        }
+
+        int requestCount = prefs.getInt(packageName + REQUEST_LSKF_COUNT_PREF_SUFFIX, -1);
+        int lskfCapturedCount = prefs.getInt(LSKF_CAPTURED_COUNT_PREF, -1);
+
+        Slog.i(TAG, String.format("Reporting reboot with lskf, package name %s, client count %d,"
+                        + " request count %d, lskf captured count %d, duration since lskf captured"
+                        + " %d seconds.", packageName, preparedClientCount, requestCount,
+                lskfCapturedCount, durationSeconds));
         mInjector.reportRebootEscrowRebootMetrics(errorCode, uid, preparedClientCount,
-                1 /* request count */, slotSwitch, serverBased,
+                requestCount, slotSwitch, serverBased, durationSeconds, lskfCapturedCount);
-                -1 /* duration */, 1 /* lskf capture count */);
     }
 
     private boolean rebootWithLskfImpl(String packageName, String reason, boolean slotSwitch) {
@@ -673,6 +779,9 @@ public class RecoverySystemService extends IRecoverySystem.Stub implements Reboo
             return false;
         }
 
+        // Clear the metrics prefs after a successful RoR reboot.
+        mInjector.getMetricsPrefs().deletePrefsFile();
+
         PowerManager pm = mInjector.getPowerManager();
         pm.reboot(reason);
         return true;

services/tests/servicestests/src/com/android/server/recoverysystem/RecoverySystemServiceTest.java

@@ -22,6 +22,7 @@ import static org.mockito.AdditionalMatchers.not;
 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.anyString;
 import static org.mockito.ArgumentMatchers.eq;
 import static org.mockito.Mockito.doNothing;
@@ -72,6 +73,7 @@ public class RecoverySystemServiceTest {
     private LockSettingsInternal mLockSettingsInternal;
     private IBootControl mIBootControl;
     private RecoverySystemServiceTestable.IMetricsReporter mMetricsReporter;
+    private RecoverySystemService.PreferencesManager mSharedPreferences;
 
     private static final String FAKE_OTA_PACKAGE_NAME = "fake.ota.package";
     private static final String FAKE_OTHER_PACKAGE_NAME = "fake.other.package";
@@ -97,10 +99,11 @@ public class RecoverySystemServiceTest {
         when(mIBootControl.getActiveBootSlot()).thenReturn(1);
 
         mMetricsReporter = mock(RecoverySystemServiceTestable.IMetricsReporter.class);
+        mSharedPreferences = mock(RecoverySystemService.PreferencesManager.class);
 
         mRecoverySystemService = new RecoverySystemServiceTestable(mContext, mSystemProperties,
                 powerManager, mUncryptUpdateFileWriter, mUncryptSocket, mLockSettingsInternal,
-                mIBootControl, mMetricsReporter);
+                mIBootControl, mMetricsReporter, mSharedPreferences);
     }
 
     @Test
@@ -237,6 +240,8 @@ public class RecoverySystemServiceTest {
                 is(true));
         verify(mMetricsReporter).reportRebootEscrowPreparationMetrics(
                 eq(1000), eq(0) /* need preparation */, eq(1) /* client count */);
+        verify(mSharedPreferences).putLong(eq(FAKE_OTA_PACKAGE_NAME
+                + RecoverySystemService.REQUEST_LSKF_TIMESTAMP_PREF_SUFFIX), eq(100_000L));
     }
 
 
@@ -245,10 +250,19 @@ public class RecoverySystemServiceTest {
         IntentSender intentSender = mock(IntentSender.class);
         assertThat(mRecoverySystemService.requestLskf(FAKE_OTA_PACKAGE_NAME, intentSender),
                 is(true));
+
+        when(mSharedPreferences.getLong(eq(FAKE_OTA_PACKAGE_NAME
+                + RecoverySystemService.REQUEST_LSKF_TIMESTAMP_PREF_SUFFIX), anyLong()))
+                .thenReturn(200_000L).thenReturn(5000L);
+        mRecoverySystemService.onPreparedForReboot(true);
+        verify(mMetricsReporter).reportRebootEscrowLskfCapturedMetrics(
+                eq(1000), eq(1) /* client count */,
+                eq(-1) /* invalid duration */);
+
         mRecoverySystemService.onPreparedForReboot(true);
         verify(intentSender).sendIntent(any(), anyInt(), any(), any(), any());
         verify(mMetricsReporter).reportRebootEscrowLskfCapturedMetrics(
-                eq(1000), eq(1) /* client count */, anyInt() /* duration */);
+                eq(1000), eq(1) /* client count */, eq(95) /* duration */);
     }
 
     @Test
@@ -352,12 +366,19 @@ public class RecoverySystemServiceTest {
     public void rebootWithLskf_Success() throws Exception {
         assertThat(mRecoverySystemService.requestLskf(FAKE_OTA_PACKAGE_NAME, null), is(true));
         mRecoverySystemService.onPreparedForReboot(true);
+
+        when(mSharedPreferences.getInt(eq(FAKE_OTA_PACKAGE_NAME
+                + RecoverySystemService.REQUEST_LSKF_COUNT_PREF_SUFFIX), anyInt())).thenReturn(2);
+        when(mSharedPreferences.getInt(eq(RecoverySystemService.LSKF_CAPTURED_COUNT_PREF),
+                anyInt())).thenReturn(3);
+        when(mSharedPreferences.getLong(eq(RecoverySystemService.LSKF_CAPTURED_TIMESTAMP_PREF),
+                anyLong())).thenReturn(40_000L);
         assertThat(mRecoverySystemService.rebootWithLskf(FAKE_OTA_PACKAGE_NAME, "ab-update", true),
                 is(true));
         verify(mIPowerManager).reboot(anyBoolean(), eq("ab-update"), anyBoolean());
         verify(mMetricsReporter).reportRebootEscrowRebootMetrics(eq(0), eq(1000),
-                eq(1) /* client count */, eq(1) /* request count */, eq(true) /* slot switch */,
+                eq(1) /* client count */, eq(2) /* request count */, eq(true) /* slot switch */,
-                anyBoolean(), anyInt(), eq(1) /* lskf capture count */);
+                anyBoolean(), eq(60) /* duration */, eq(3) /* lskf capture count */);
     }
 
 
@@ -400,13 +421,19 @@ public class RecoverySystemServiceTest {
         assertThat(mRecoverySystemService.requestLskf(FAKE_OTHER_PACKAGE_NAME, null), is(true));
         mRecoverySystemService.onPreparedForReboot(true);
 
-        // Client B's clear won't affect client A's preparation.
+        when(mSharedPreferences.getInt(eq(FAKE_OTA_PACKAGE_NAME
+                + RecoverySystemService.REQUEST_LSKF_COUNT_PREF_SUFFIX), anyInt())).thenReturn(2);
+        when(mSharedPreferences.getInt(eq(RecoverySystemService.LSKF_CAPTURED_COUNT_PREF),
+                anyInt())).thenReturn(1);
+        when(mSharedPreferences.getLong(eq(RecoverySystemService.LSKF_CAPTURED_TIMESTAMP_PREF),
+                anyLong())).thenReturn(60_000L);
+
         assertThat(mRecoverySystemService.rebootWithLskf(FAKE_OTA_PACKAGE_NAME, "ab-update", true),
                 is(true));
         verify(mIPowerManager).reboot(anyBoolean(), eq("ab-update"), anyBoolean());
         verify(mMetricsReporter).reportRebootEscrowRebootMetrics(eq(0), eq(1000),
-                eq(2) /* client count */, eq(1) /* request count */, eq(true) /* slot switch */,
+                eq(2) /* client count */, eq(2) /* request count */, eq(true) /* slot switch */,
-                anyBoolean(), anyInt(), eq(1) /* lskf capture count */);
+                anyBoolean(), eq(40), eq(1) /* lskf capture count */);
     }
 
     @Test
@@ -415,22 +442,30 @@ public class RecoverySystemServiceTest {
         mRecoverySystemService.onPreparedForReboot(true);
         assertThat(mRecoverySystemService.requestLskf(FAKE_OTHER_PACKAGE_NAME, null), is(true));
 
+        when(mSharedPreferences.getInt(eq(FAKE_OTHER_PACKAGE_NAME
+                + RecoverySystemService.REQUEST_LSKF_COUNT_PREF_SUFFIX), anyInt())).thenReturn(2);
+        when(mSharedPreferences.getInt(eq(RecoverySystemService.LSKF_CAPTURED_COUNT_PREF),
+                anyInt())).thenReturn(1);
+        when(mSharedPreferences.getLong(eq(RecoverySystemService.LSKF_CAPTURED_TIMESTAMP_PREF),
+                anyLong())).thenReturn(60_000L);
+
         assertThat(mRecoverySystemService.clearLskf(FAKE_OTA_PACKAGE_NAME), is(true));
         assertThat(mRecoverySystemService.rebootWithLskf(FAKE_OTA_PACKAGE_NAME, null, true),
                 is(false));
         verifyNoMoreInteractions(mIPowerManager);
         verify(mMetricsReporter).reportRebootEscrowRebootMetrics(not(eq(0)), eq(1000),
-                eq(1) /* client count */, eq(1) /* request count */, eq(true) /* slot switch */,
+                eq(1) /* client count */, anyInt() /* request count */, eq(true) /* slot switch */,
-                anyBoolean(), anyInt(), eq(1) /* lskf capture count */);
+                anyBoolean(), eq(40), eq(1)/* lskf capture count */);
 
         assertThat(mRecoverySystemService.requestLskf(FAKE_OTHER_PACKAGE_NAME, null), is(true));
         assertThat(
                 mRecoverySystemService.rebootWithLskf(FAKE_OTHER_PACKAGE_NAME, "ab-update", true),
                 is(true));
         verify(mIPowerManager).reboot(anyBoolean(), eq("ab-update"), anyBoolean());
-        verify(mMetricsReporter).reportRebootEscrowRebootMetrics(eq(0), eq(2000),
+
-                eq(1) /* client count */, eq(1) /* request count */, eq(true) /* slot switch */,
+        verify(mMetricsReporter).reportRebootEscrowRebootMetrics((eq(0)), eq(2000),
-                anyBoolean(), anyInt(), eq(1) /* lskf capture count */);
+                eq(1) /* client count */, eq(2) /* request count */, eq(true) /* slot switch */,
+                anyBoolean(), eq(40), eq(1) /* lskf capture count */);
     }
 
     @Test

services/tests/servicestests/src/com/android/server/recoverysystem/RecoverySystemServiceTestable.java

@@ -33,11 +33,13 @@ public class RecoverySystemServiceTestable extends RecoverySystemService {
         private final LockSettingsInternal mLockSettingsInternal;
         private final IBootControl mIBootControl;
         private final IMetricsReporter mIMetricsReporter;
+        private final RecoverySystemService.PreferencesManager mSharedPreferences;
 
         MockInjector(Context context, FakeSystemProperties systemProperties,
                 PowerManager powerManager, FileWriter uncryptPackageFileWriter,
                 UncryptSocket uncryptSocket, LockSettingsInternal lockSettingsInternal,
-                IBootControl bootControl, IMetricsReporter metricsReporter) {
+                IBootControl bootControl, IMetricsReporter metricsReporter,
+                RecoverySystemService.PreferencesManager preferences) {
             super(context);
             mSystemProperties = systemProperties;
             mPowerManager = powerManager;
@@ -46,6 +48,7 @@ public class RecoverySystemServiceTestable extends RecoverySystemService {
             mLockSettingsInternal = lockSettingsInternal;
             mIBootControl = bootControl;
             mIMetricsReporter = metricsReporter;
+            mSharedPreferences = preferences;
         }
 
         @Override
@@ -114,12 +117,14 @@ public class RecoverySystemServiceTestable extends RecoverySystemService {
                     requestedClientCount);
         }
 
+        @Override
         public void reportRebootEscrowLskfCapturedMetrics(int uid, int requestedClientCount,
                 int requestedToLskfCapturedDurationInSeconds) {
             mIMetricsReporter.reportRebootEscrowLskfCapturedMetrics(uid, requestedClientCount,
                     requestedToLskfCapturedDurationInSeconds);
         }
 
+        @Override
         public void reportRebootEscrowRebootMetrics(int errorCode, int uid, int preparedClientCount,
                 int requestCount, boolean slotSwitch, boolean serverBased,
                 int lskfCapturedToRebootDurationInSeconds, int lskfCapturedCounts) {
@@ -127,14 +132,25 @@ public class RecoverySystemServiceTestable extends RecoverySystemService {
                     requestCount, slotSwitch, serverBased, lskfCapturedToRebootDurationInSeconds,
                     lskfCapturedCounts);
         }
+
+        @Override
+        public long getCurrentTimeMillis() {
+            return 100_000;
+        }
+
+        @Override
+        public RecoverySystemService.PreferencesManager getMetricsPrefs() {
+            return mSharedPreferences;
+        }
     }
 
     RecoverySystemServiceTestable(Context context, FakeSystemProperties systemProperties,
             PowerManager powerManager, FileWriter uncryptPackageFileWriter,
             UncryptSocket uncryptSocket, LockSettingsInternal lockSettingsInternal,
-            IBootControl bootControl, IMetricsReporter metricsReporter) {
+            IBootControl bootControl, IMetricsReporter metricsReporter,
+            RecoverySystemService.PreferencesManager preferences) {
         super(new MockInjector(context, systemProperties, powerManager, uncryptPackageFileWriter,
-                uncryptSocket, lockSettingsInternal, bootControl, metricsReporter));
+                uncryptSocket, lockSettingsInternal, bootControl, metricsReporter, preferences));
     }
 
     public static class FakeSystemProperties {
@@ -176,5 +192,4 @@ public class RecoverySystemServiceTestable extends RecoverySystemService {
                 int requestCount, boolean slotSwitch, boolean serverBased,
                 int lskfCapturedToRebootDurationInSeconds, int lskfCapturedCounts);
     }
-
 }