Merge "Add logging of user stop and user removal events." into tm-dev

3 files changed, 78 insertions, 16 deletions

diff --git a/services/core/java/com/android/server/am/UserController.java b/services/core/java/com/android/server/am/UserController.java
index b886196755ea..c04377389e8e 100644
--- a/services/core/java/com/android/server/am/UserController.java
+++ b/services/core/java/com/android/server/am/UserController.java
@@ -173,7 +173,7 @@ class UserController implements Handler.Callback {
     // Message constant to clear {@link UserJourneySession} from {@link mUserIdToUserJourneyMap} if
     // the user journey, defined in the UserLifecycleJourneyReported atom for statsd, is not
     // complete within {@link USER_JOURNEY_TIMEOUT}.
-    private static final int CLEAR_USER_JOURNEY_SESSION_MSG = 200;
+    static final int CLEAR_USER_JOURNEY_SESSION_MSG = 200;
     // Wait time for completing the user journey. If a user journey is not complete within this
     // time, the remaining lifecycle events for the journey would not be logged in statsd.
     // Timeout set for 90 seconds.
@@ -209,12 +209,15 @@ class UserController implements Handler.Callback {
             FrameworkStatsLog.USER_LIFECYCLE_JOURNEY_REPORTED__JOURNEY__USER_START;
     private static final int USER_JOURNEY_USER_CREATE =
             FrameworkStatsLog.USER_LIFECYCLE_JOURNEY_REPORTED__JOURNEY__USER_CREATE;
+    private static final int USER_JOURNEY_USER_STOP =
+            FrameworkStatsLog.USER_LIFECYCLE_JOURNEY_REPORTED__JOURNEY__USER_STOP;
     @IntDef(prefix = { "USER_JOURNEY" }, value = {
             USER_JOURNEY_UNKNOWN,
             USER_JOURNEY_USER_SWITCH_FG,
             USER_JOURNEY_USER_SWITCH_UI,
             USER_JOURNEY_USER_START,
             USER_JOURNEY_USER_CREATE,
+            USER_JOURNEY_USER_STOP
     })
     @interface UserJourney {}
 
@@ -233,6 +236,8 @@ class UserController implements Handler.Callback {
             FrameworkStatsLog.USER_LIFECYCLE_EVENT_OCCURRED__EVENT__UNLOCKING_USER;
     private static final int USER_LIFECYCLE_EVENT_UNLOCKED_USER =
             FrameworkStatsLog.USER_LIFECYCLE_EVENT_OCCURRED__EVENT__UNLOCKED_USER;
+    private static final int USER_LIFECYCLE_EVENT_STOP_USER =
+            FrameworkStatsLog.USER_LIFECYCLE_EVENT_OCCURRED__EVENT__STOP_USER;
     @IntDef(prefix = { "USER_LIFECYCLE_EVENT" }, value = {
             USER_LIFECYCLE_EVENT_UNKNOWN,
             USER_LIFECYCLE_EVENT_SWITCH_USER,
@@ -241,6 +246,7 @@ class UserController implements Handler.Callback {
             USER_LIFECYCLE_EVENT_USER_RUNNING_LOCKED,
             USER_LIFECYCLE_EVENT_UNLOCKING_USER,
             USER_LIFECYCLE_EVENT_UNLOCKED_USER,
+            USER_LIFECYCLE_EVENT_STOP_USER
     })
     @interface UserLifecycleEvent {}
 
@@ -1008,6 +1014,10 @@ class UserController implements Handler.Callback {
             return;
         }
 
+        logUserJourneyInfo(null, getUserInfo(userId), USER_JOURNEY_USER_STOP);
+        logUserLifecycleEvent(userId, USER_LIFECYCLE_EVENT_STOP_USER,
+                USER_LIFECYCLE_EVENT_STATE_BEGIN);
+
         if (stopUserCallback != null) {
             uss.mStopCallbacks.add(stopUserCallback);
         }
@@ -1066,6 +1076,9 @@ class UserController implements Handler.Callback {
         synchronized (mLock) {
             if (uss.state != UserState.STATE_STOPPING) {
                 // Whoops, we are being started back up.  Abort, abort!
+                logUserLifecycleEvent(userId, USER_LIFECYCLE_EVENT_STOP_USER,
+                        USER_LIFECYCLE_EVENT_STATE_NONE);
+                clearSessionId(userId);
                 return;
             }
             uss.setState(UserState.STATE_SHUTDOWN);
@@ -1165,10 +1178,18 @@ class UserController implements Handler.Callback {
                 mInjector.getUserManager().removeUserEvenWhenDisallowed(userId);
             }
 
+            logUserLifecycleEvent(userId, USER_LIFECYCLE_EVENT_STOP_USER,
+                    USER_LIFECYCLE_EVENT_STATE_FINISH);
+            clearSessionId(userId);
+
             if (!lockUser) {
                 return;
             }
             dispatchUserLocking(userIdToLock, keyEvictedCallbacks);
+        } else {
+            logUserLifecycleEvent(userId, USER_LIFECYCLE_EVENT_STOP_USER,
+                    USER_LIFECYCLE_EVENT_STATE_NONE);
+            clearSessionId(userId);
         }
     }
 
@@ -2962,13 +2983,13 @@ class UserController implements Handler.Callback {
             if (userJourneySession != null) {
                 // TODO(b/157007231): Move this logic to a separate class/file.
                 if ((userJourneySession.mJourney == USER_JOURNEY_USER_SWITCH_UI
-                        && journey == USER_JOURNEY_USER_START)
-                        || (userJourneySession.mJourney == USER_JOURNEY_USER_SWITCH_FG
-                                && journey == USER_JOURNEY_USER_START)) {
+                        || userJourneySession.mJourney == USER_JOURNEY_USER_SWITCH_FG)
+                        && (journey == USER_JOURNEY_USER_START
+                                || journey == USER_JOURNEY_USER_STOP)) {
                     /*
-                     * There is already a user switch journey, and a user start journey for the same
-                     * target user received. User start journey is most likely a part of user switch
-                     * journey so no need to create a new journey for user start.
+                     * There is already a user switch journey, and a user start or stop journey for
+                     * the same target user received. New journey is most likely a part of user
+                     * switch journey so no need to create a new journey.
                      */
                     if (DEBUG_MU) {
                         Slogf.d(TAG, journey + " not logged as it is expected to be part of "
diff --git a/services/core/java/com/android/server/pm/UserManagerService.java b/services/core/java/com/android/server/pm/UserManagerService.java
index ee0fdc07f841..cb08c79a7048 100644
--- a/services/core/java/com/android/server/pm/UserManagerService.java
+++ b/services/core/java/com/android/server/pm/UserManagerService.java
@@ -4317,16 +4317,9 @@ public class UserManagerService extends IUserManager.Stub {
 
     private long logUserCreateJourneyBegin(@UserIdInt int userId, String userType,
             @UserInfoFlag int flags) {
-        final long sessionId = ThreadLocalRandom.current().nextLong(1, Long.MAX_VALUE);
-        // log the journey atom with the user metadata
-        FrameworkStatsLog.write(FrameworkStatsLog.USER_LIFECYCLE_JOURNEY_REPORTED, sessionId,
+        return logUserJourneyBegin(
                 FrameworkStatsLog.USER_LIFECYCLE_JOURNEY_REPORTED__JOURNEY__USER_CREATE,
-                /* origin_user= */ -1, userId, UserManager.getUserTypeForStatsd(userType), flags);
-        // log the event atom to indicate the event start
-        FrameworkStatsLog.write(FrameworkStatsLog.USER_LIFECYCLE_EVENT_OCCURRED, sessionId, userId,
-                FrameworkStatsLog.USER_LIFECYCLE_EVENT_OCCURRED__EVENT__CREATE_USER,
-                FrameworkStatsLog.USER_LIFECYCLE_EVENT_OCCURRED__STATE__BEGIN);
-        return sessionId;
+                userId, userType, flags);
     }
 
     private void logUserCreateJourneyFinish(long sessionId, @UserIdInt int userId, boolean finish) {
@@ -4336,6 +4329,46 @@ public class UserManagerService extends IUserManager.Stub {
                         : FrameworkStatsLog.USER_LIFECYCLE_EVENT_OCCURRED__STATE__NONE);
     }
 
+    private long logUserRemoveJourneyBegin(@UserIdInt int userId, String userType,
+            @UserInfoFlag int flags) {
+        return logUserJourneyBegin(
+                FrameworkStatsLog.USER_LIFECYCLE_JOURNEY_REPORTED__JOURNEY__USER_REMOVE,
+                userId, userType, flags);
+    }
+
+    private void logUserRemoveJourneyFinish(long sessionId, @UserIdInt int userId, boolean finish) {
+        FrameworkStatsLog.write(FrameworkStatsLog.USER_LIFECYCLE_EVENT_OCCURRED, sessionId, userId,
+                FrameworkStatsLog.USER_LIFECYCLE_EVENT_OCCURRED__EVENT__REMOVE_USER,
+                finish ? FrameworkStatsLog.USER_LIFECYCLE_EVENT_OCCURRED__STATE__FINISH
+                        : FrameworkStatsLog.USER_LIFECYCLE_EVENT_OCCURRED__STATE__NONE);
+    }
+
+    private long logUserJourneyBegin(int journey, @UserIdInt int userId, String userType,
+            @UserInfoFlag int flags) {
+        final long sessionId = ThreadLocalRandom.current().nextLong(1, Long.MAX_VALUE);
+        // log the journey atom with the user metadata
+        FrameworkStatsLog.write(FrameworkStatsLog.USER_LIFECYCLE_JOURNEY_REPORTED, sessionId,
+                journey, /* origin_user= */ -1, userId,
+                UserManager.getUserTypeForStatsd(userType), flags);
+
+        // log the event atom to indicate the event start
+        int event;
+        switch (journey) {
+            case FrameworkStatsLog.USER_LIFECYCLE_JOURNEY_REPORTED__JOURNEY__USER_CREATE:
+                event = FrameworkStatsLog.USER_LIFECYCLE_EVENT_OCCURRED__EVENT__CREATE_USER;
+                break;
+            case FrameworkStatsLog.USER_LIFECYCLE_JOURNEY_REPORTED__JOURNEY__USER_REMOVE:
+                event = FrameworkStatsLog.USER_LIFECYCLE_EVENT_OCCURRED__EVENT__REMOVE_USER;
+                break;
+            default:
+                throw new IllegalArgumentException("Journey " + journey + " not expected.");
+        }
+
+        FrameworkStatsLog.write(FrameworkStatsLog.USER_LIFECYCLE_EVENT_OCCURRED, sessionId, userId,
+                event, FrameworkStatsLog.USER_LIFECYCLE_EVENT_OCCURRED__STATE__BEGIN);
+        return sessionId;
+    }
+
     /** Register callbacks for statsd pulled atoms. */
     private void registerStatsCallbacks() {
         final StatsManager statsManager = mContext.getSystemService(StatsManager.class);
@@ -4578,6 +4611,10 @@ public class UserManagerService extends IUserManager.Stub {
                 userData.info.flags |= UserInfo.FLAG_DISABLED;
                 writeUserLP(userData);
             }
+
+            final long sessionId = logUserRemoveJourneyBegin(
+                    userId, userData.info.userType, userData.info.flags);
+
             try {
                 mAppOpsService.removeUser(userId);
             } catch (RemoteException e) {
@@ -4600,9 +4637,11 @@ public class UserManagerService extends IUserManager.Stub {
                             @Override
                             public void userStopped(int userIdParam) {
                                 finishRemoveUser(userIdParam);
+                                logUserRemoveJourneyFinish(sessionId, userIdParam, true);
                             }
                             @Override
                             public void userStopAborted(int userIdParam) {
+                                logUserRemoveJourneyFinish(sessionId, userIdParam, false);
                             }
                         });
             } catch (RemoteException e) {
diff --git a/services/tests/servicestests/src/com/android/server/am/UserControllerTest.java b/services/tests/servicestests/src/com/android/server/am/UserControllerTest.java
index e4f1a9645e5c..db1209224bd5 100644
--- a/services/tests/servicestests/src/com/android/server/am/UserControllerTest.java
+++ b/services/tests/servicestests/src/com/android/server/am/UserControllerTest.java
@@ -28,6 +28,7 @@ import static android.testing.DexmakerShareClassLoaderRule.runWithDexmakerShareC
 
 import static androidx.test.platform.app.InstrumentationRegistry.getInstrumentation;
 
+import static com.android.server.am.UserController.CLEAR_USER_JOURNEY_SESSION_MSG;
 import static com.android.server.am.UserController.COMPLETE_USER_SWITCH_MSG;
 import static com.android.server.am.UserController.CONTINUE_USER_SWITCH_MSG;
 import static com.android.server.am.UserController.REPORT_LOCKED_BOOT_COMPLETE_MSG;
@@ -410,6 +411,7 @@ public class UserControllerTest {
         expectedCodes.add(COMPLETE_USER_SWITCH_MSG);
         expectedCodes.add(REPORT_USER_SWITCH_COMPLETE_MSG);
         if (backgroundUserStopping) {
+            expectedCodes.add(CLEAR_USER_JOURNEY_SESSION_MSG);
             expectedCodes.add(0); // this is for directly posting in stopping.
         }
         Set<Integer> actualCodes = mInjector.mHandler.getMessageCodes();