Merge "Add elapsed time to user journey report and user lifecycle journey (from create to delete)" into udc-dev am: cdd7f04ff5 am: 76a1b10a82 am: c2433ee497

Original change: https://googleplex-android-review.googlesource.com/c/platform/frameworks/base/+/23168143

Change-Id: I968e1e3db4bdc5b605ab7936931f0f17fe8e8ca7
Signed-off-by: Automerger Merge Worker <android-build-automerger-merge-worker@system.gserviceaccount.com>

services/core/java/com/android/server/pm/UserJourneyLogger.java

@@ -99,6 +99,8 @@ public class UserJourneyLogger {
             FrameworkStatsLog.USER_LIFECYCLE_JOURNEY_REPORTED__JOURNEY__GRANT_ADMIN;
     public static final int USER_JOURNEY_REVOKE_ADMIN =
             FrameworkStatsLog.USER_LIFECYCLE_JOURNEY_REPORTED__JOURNEY__REVOKE_ADMIN;
+    public static final int USER_JOURNEY_USER_LIFECYCLE =
+            FrameworkStatsLog.USER_LIFECYCLE_JOURNEY_REPORTED__JOURNEY__USER_LIFECYCLE;
 
     @IntDef(prefix = {"USER_JOURNEY"}, value = {
             USER_JOURNEY_UNKNOWN,
@@ -109,7 +111,8 @@ public class UserJourneyLogger {
             USER_JOURNEY_USER_CREATE,
             USER_JOURNEY_USER_REMOVE,
             USER_JOURNEY_GRANT_ADMIN,
-            USER_JOURNEY_REVOKE_ADMIN
+            USER_JOURNEY_REVOKE_ADMIN,
+            USER_JOURNEY_USER_LIFECYCLE
     })
     public @interface UserJourney {
     }
@@ -272,11 +275,12 @@ public class UserJourneyLogger {
             int userType, int userFlags, @UserJourneyErrorCode int errorCode) {
         if (session == null) {
             writeUserLifecycleJourneyReported(-1, journey, originalUserId, targetUserId,
-                    userType, userFlags, ERROR_CODE_INVALID_SESSION_ID);
+                    userType, userFlags, ERROR_CODE_INVALID_SESSION_ID, -1);
         } else {
+            final long elapsedTime = System.currentTimeMillis() - session.mStartTimeInMills;
             writeUserLifecycleJourneyReported(
                     session.mSessionId, journey, originalUserId, targetUserId, userType, userFlags,
-                    errorCode);
+                    errorCode, elapsedTime);
         }
     }
 
@@ -285,10 +289,10 @@ public class UserJourneyLogger {
      */
     @VisibleForTesting
     public void writeUserLifecycleJourneyReported(long sessionId, int journey, int originalUserId,
-            int targetUserId, int userType, int userFlags, int errorCode) {
+            int targetUserId, int userType, int userFlags, int errorCode, long elapsedTime) {
         FrameworkStatsLog.write(FrameworkStatsLog.USER_LIFECYCLE_JOURNEY_REPORTED,
                 sessionId, journey, originalUserId, targetUserId, userType, userFlags,
-                errorCode);
+                errorCode, elapsedTime);
     }
 
     /**
@@ -451,6 +455,29 @@ public class UserJourneyLogger {
         return null;
     }
 
+    /**
+     * Log user journey event and report finishing with error
+     */
+    public UserJourneySession logDelayedUserJourneyFinishWithError(@UserIdInt int originalUserId,
+            UserInfo targetUser, @UserJourney int journey, @UserJourneyErrorCode int errorCode) {
+        synchronized (mLock) {
+            final int key = getUserJourneyKey(targetUser.id, journey);
+            final UserJourneySession userJourneySession = mUserIdToUserJourneyMap.get(key);
+            if (userJourneySession != null) {
+                logUserLifecycleJourneyReported(
+                        userJourneySession,
+                        journey, originalUserId, targetUser.id,
+                        getUserTypeForStatsd(targetUser.userType),
+                        targetUser.flags,
+                        errorCode);
+                mUserIdToUserJourneyMap.remove(key);
+
+                return userJourneySession;
+            }
+        }
+        return null;
+    }
+
     /**
      * Log event and report finish when user is null. This is edge case when UserInfo
      * can not be passed because it is null, therefore all information are passed as arguments.
@@ -532,6 +559,23 @@ public class UserJourneyLogger {
         }
     }
 
+    /**
+     * This keeps the start time when finishing extensively long journey was began.
+     * For instance full user lifecycle ( from creation to deletion )when user is about to delete
+     * we need to get user creation time before it was deleted.
+     */
+    public UserJourneySession startSessionForDelayedJourney(@UserIdInt int targetId,
+            @UserJourney int journey, long startTime) {
+        final long newSessionId = ThreadLocalRandom.current().nextLong(1, Long.MAX_VALUE);
+        synchronized (mLock) {
+            final int key = getUserJourneyKey(targetId, journey);
+            final UserJourneySession userJourneySession =
+                    new UserJourneySession(newSessionId, journey, startTime);
+            mUserIdToUserJourneyMap.append(key, userJourneySession);
+            return userJourneySession;
+        }
+    }
+
     /**
      * Helper class to store user journey and session id.
      *
@@ -542,11 +586,19 @@ public class UserJourneyLogger {
         public final long mSessionId;
         @UserJourney
         public final int mJourney;
+        public long mStartTimeInMills;
 
         @VisibleForTesting
         public UserJourneySession(long sessionId, @UserJourney int journey) {
             mJourney = journey;
             mSessionId = sessionId;
+            mStartTimeInMills = System.currentTimeMillis();
+        }
+        @VisibleForTesting
+        public UserJourneySession(long sessionId, @UserJourney int journey, long startTimeInMills) {
+            mJourney = journey;
+            mSessionId = sessionId;
+            mStartTimeInMills = startTimeInMills;
         }
     }
 }

services/core/java/com/android/server/pm/UserManagerService.java

@@ -30,6 +30,7 @@ import static com.android.server.pm.UserJourneyLogger.ERROR_CODE_USER_IS_NOT_AN_
 import static com.android.server.pm.UserJourneyLogger.USER_JOURNEY_GRANT_ADMIN;
 import static com.android.server.pm.UserJourneyLogger.USER_JOURNEY_REVOKE_ADMIN;
 import static com.android.server.pm.UserJourneyLogger.USER_JOURNEY_USER_CREATE;
+import static com.android.server.pm.UserJourneyLogger.USER_JOURNEY_USER_LIFECYCLE;
 import static com.android.server.pm.UserJourneyLogger.USER_JOURNEY_USER_REMOVE;
 
 import android.Manifest;
@@ -3332,7 +3333,7 @@ public class UserManagerService extends IUserManager.Stub {
     }
 
     /**
-    * Enforces that only the system UID or root's UID or apps that have the
+     * Enforces that only the system UID or root's UID or apps that have the
      * {@link android.Manifest.permission#MANAGE_USERS MANAGE_USERS} or
      * {@link android.Manifest.permission#QUERY_USERS QUERY_USERS}
      * can make certain calls to the UserManager.
@@ -5535,6 +5536,8 @@ public class UserManagerService extends IUserManager.Stub {
             }
 
             mUserJourneyLogger.logUserJourneyBegin(userId, USER_JOURNEY_USER_REMOVE);
+            mUserJourneyLogger.startSessionForDelayedJourney(userId,
+                    USER_JOURNEY_USER_LIFECYCLE, userData.info.creationTime);
 
             try {
                 mAppOpsService.removeUser(userId);
@@ -5560,6 +5563,10 @@ public class UserManagerService extends IUserManager.Stub {
                                 mUserJourneyLogger.logUserJourneyFinishWithError(originUserId,
                                         userData.info, USER_JOURNEY_USER_REMOVE,
                                         ERROR_CODE_UNSPECIFIED);
+                                mUserJourneyLogger
+                                        .logDelayedUserJourneyFinishWithError(originUserId,
+                                                userData.info, USER_JOURNEY_USER_LIFECYCLE,
+                                                ERROR_CODE_UNSPECIFIED);
                             }
                             @Override
                             public void userStopAborted(int userIdParam) {
@@ -5567,6 +5574,10 @@ public class UserManagerService extends IUserManager.Stub {
                                 mUserJourneyLogger.logUserJourneyFinishWithError(originUserId,
                                         userData.info, USER_JOURNEY_USER_REMOVE,
                                         ERROR_CODE_ABORTED);
+                                mUserJourneyLogger
+                                        .logDelayedUserJourneyFinishWithError(originUserId,
+                                                userData.info, USER_JOURNEY_USER_LIFECYCLE,
+                                                ERROR_CODE_ABORTED);
                             }
                         });
             } catch (RemoteException e) {

services/tests/servicestests/src/com/android/server/pm/UserJourneyLoggerTest.java

@@ -27,6 +27,7 @@ import static com.android.server.pm.UserJourneyLogger.EVENT_STATE_FINISH;
 import static com.android.server.pm.UserJourneyLogger.EVENT_STATE_NONE;
 import static com.android.server.pm.UserJourneyLogger.USER_JOURNEY_GRANT_ADMIN;
 import static com.android.server.pm.UserJourneyLogger.USER_JOURNEY_USER_CREATE;
+import static com.android.server.pm.UserJourneyLogger.USER_JOURNEY_USER_LIFECYCLE;
 import static com.android.server.pm.UserJourneyLogger.USER_JOURNEY_USER_REMOVE;
 import static com.android.server.pm.UserJourneyLogger.USER_JOURNEY_USER_START;
 import static com.android.server.pm.UserJourneyLogger.USER_JOURNEY_USER_STOP;
@@ -499,6 +500,27 @@ public class UserJourneyLoggerTest {
                 0x00000402, ERROR_CODE_UNSPECIFIED, 3);
     }
 
+    @Test
+    public void testUserLifecycleJourney() {
+        final long startTime = System.currentTimeMillis();
+        final UserJourneyLogger.UserJourneySession session = mUserJourneyLogger
+                .startSessionForDelayedJourney(10, USER_JOURNEY_USER_LIFECYCLE, startTime);
+
+
+        final UserLifecycleJourneyReportedCaptor report = new UserLifecycleJourneyReportedCaptor();
+        final UserInfo targetUser = new UserInfo(10, "test target user",
+                UserInfo.FLAG_ADMIN | UserInfo.FLAG_FULL);
+        mUserJourneyLogger.logDelayedUserJourneyFinishWithError(0, targetUser,
+                USER_JOURNEY_USER_LIFECYCLE, ERROR_CODE_UNSPECIFIED);
+
+
+        report.captureAndAssert(mUserJourneyLogger, session.mSessionId,
+                USER_JOURNEY_USER_LIFECYCLE, 0, 10,
+                FrameworkStatsLog.USER_LIFECYCLE_JOURNEY_REPORTED__USER_TYPE__FULL_SECONDARY,
+                0x00000402, ERROR_CODE_UNSPECIFIED, 1);
+        assertThat(report.mElapsedTime.getValue() > 0L).isTrue();
+    }
+
     static class UserLifecycleJourneyReportedCaptor {
         ArgumentCaptor<Long> mSessionId = ArgumentCaptor.forClass(Long.class);
         ArgumentCaptor<Integer> mJourney = ArgumentCaptor.forClass(Integer.class);
@@ -507,6 +529,7 @@ public class UserJourneyLoggerTest {
         ArgumentCaptor<Integer> mUserType = ArgumentCaptor.forClass(Integer.class);
         ArgumentCaptor<Integer> mUserFlags = ArgumentCaptor.forClass(Integer.class);
         ArgumentCaptor<Integer> mErrorCode = ArgumentCaptor.forClass(Integer.class);
+        ArgumentCaptor<Long> mElapsedTime = ArgumentCaptor.forClass(Long.class);
 
         public void captureAndAssert(UserJourneyLogger mUserJourneyLogger,
                 long sessionId, int journey, int originalUserId,
@@ -518,7 +541,8 @@ public class UserJourneyLoggerTest {
                             mTargetUserId.capture(),
                             mUserType.capture(),
                             mUserFlags.capture(),
-                            mErrorCode.capture());
+                            mErrorCode.capture(),
+                            mElapsedTime.capture());
 
             assertThat(mSessionId.getValue()).isEqualTo(sessionId);
             assertThat(mJourney.getValue()).isEqualTo(journey);