Merge "Add new atoms to track user journeys, such as user switches." into rvc-dev

cmds/statsd/src/atoms.proto

@@ -421,6 +421,8 @@ message Atom {
         TvSettingsUIInteracted tvsettings_ui_interacted = 261 [(module) = "tv_settings"];
         LauncherStaticLayout launcher_snapshot = 262 [(module) = "sysui"];
         PackageInstallerV2Reported package_installer_v2_reported = 263 [(module) = "framework"];
+        UserLifecycleJourneyReported user_lifecycle_journey_reported = 264 [(module) = "framework"];
+        UserLifecycleEventOccurred user_lifecycle_event_occurred = 265 [(module) = "framework"];
         SdkExtensionStatus sdk_extension_status = 354;
     }
 
@@ -9357,3 +9359,82 @@ message SettingSnapshot {
     // Android user index. 0 for primary user, 10, 11 for secondary or profile user
     optional int32 user_id = 7;
 }
+
+/**
+ * An event logged to indicate that a user journey is about to be performed. This atom includes
+ * relevant information about the users involved in the journey. A UserLifecycleEventOccurred event
+ * will immediately follow this atom which will describe the event(s) and its state.
+ *
+ * Logged from:
+ *   frameworks/base/services/core/java/com/android/server/am/UserController.java
+ *   frameworks/base/services/core/java/com/android/server/pm/UserManagerService.java
+ */
+message UserLifecycleJourneyReported {
+    // An identifier to track a chain of user lifecycle events occurring (referenced in the
+    // UserLifecycleEventOccurred atom)
+    optional int64 session_id = 1;
+
+    // Indicates what type of user journey this session is related to
+    enum Journey {
+        UNKNOWN = 0; // Undefined user lifecycle journey
+        USER_SWITCH_UI = 1; // A user switch journey where a UI is shown
+        USER_SWITCH_FG = 2; // A user switch journey without a UI shown
+        USER_START = 3; // A user start journey
+        USER_CREATE = 4; // A user creation journey
+    }
+    optional Journey journey = 2;
+    // Which user the journey is originating from - could be -1 for certain phases (eg USER_CREATE)
+    // This integer is a UserIdInt (eg 0 for the system user, 10 for secondary/guest)
+    optional int32 origin_user = 3;
+    // Which user the journey is targeting
+    // This integer is a UserIdInt (eg 0 for the system user, 10 for secondary/guest)
+    optional int32 target_user = 4;
+
+    // What is the user type of the target user
+    // These should be in sync with USER_TYPE_* flags defined in UserManager.java
+    enum UserType {
+        TYPE_UNKNOWN = 0;
+        FULL_SYSTEM = 1;
+        FULL_SECONDARY = 2;
+        FULL_GUEST = 3;
+        FULL_DEMO = 4;
+        FULL_RESTRICTED = 5;
+        PROFILE_MANAGED = 6;
+        SYSTEM_HEADLESS = 7;
+    }
+    optional UserType user_type = 5;
+    // What are the flags attached to the target user
+    optional int32 user_flags = 6;
+}
+
+/**
+ * An event logged when a specific user lifecycle event is performed. These events should be
+ * correlated with a UserLifecycleJourneyReported atom via the session_id.
+ * Note: journeys can span over multiple events, hence some events may share a single session id.
+ *
+ * Logged from:
+ *   frameworks/base/services/core/java/com/android/server/am/UserController.java
+ *   frameworks/base/services/core/java/com/android/server/pm/UserManagerService.java
+ */
+message UserLifecycleEventOccurred {
+    // An id which links back to user details (reported in the UserLifecycleJourneyReported atom)
+    optional int64 session_id = 1;
+    // The target user for this event (same as target_user in the UserLifecycleJourneyReported atom)
+    // This integer is a UserIdInt (eg 0 for the system user, 10 for secondary/guest)
+    optional int32 user_id = 2;
+
+    enum Event {
+        UNKNOWN = 0; // Indicates that the associated user journey timed-out or resulted in an error
+        SWITCH_USER = 1; // Indicates that this is a user switch event
+        START_USER = 2; // Indicates that this is a user start event
+        CREATE_USER = 3; // Indicates that this is a user create event
+    }
+    optional Event event = 3;
+
+    enum State {
+        NONE = 0; // Indicates the associated event has no start/end defined
+        BEGIN = 1;
+        FINISH = 2;
+    }
+    optional State state = 4; // Represents the state of an event (beginning/ending)
+}

core/java/android/os/UserManager.java

@@ -57,6 +57,7 @@ import android.view.WindowManager.LayoutParams;
 
 import com.android.internal.R;
 import com.android.internal.os.RoSystemProperties;
+import com.android.internal.util.FrameworkStatsLog;
 
 import java.io.IOException;
 import java.lang.annotation.Retention;
@@ -1840,6 +1841,35 @@ public class UserManager {
         return USER_TYPE_FULL_DEMO.equals(userType);
     }
 
+    /**
+     * Returns the enum defined in the statsd UserLifecycleJourneyReported atom corresponding to the
+     * user type.
+     * @hide
+     */
+    public static int getUserTypeForStatsd(@NonNull String userType) {
+        switch (userType) {
+            case USER_TYPE_FULL_SYSTEM:
+                return FrameworkStatsLog.USER_LIFECYCLE_JOURNEY_REPORTED__USER_TYPE__FULL_SYSTEM;
+            case USER_TYPE_FULL_SECONDARY:
+                return FrameworkStatsLog.USER_LIFECYCLE_JOURNEY_REPORTED__USER_TYPE__FULL_SECONDARY;
+            case USER_TYPE_FULL_GUEST:
+                return FrameworkStatsLog.USER_LIFECYCLE_JOURNEY_REPORTED__USER_TYPE__FULL_GUEST;
+            case USER_TYPE_FULL_DEMO:
+                return FrameworkStatsLog.USER_LIFECYCLE_JOURNEY_REPORTED__USER_TYPE__FULL_DEMO;
+            case USER_TYPE_FULL_RESTRICTED:
+                return FrameworkStatsLog
+                        .USER_LIFECYCLE_JOURNEY_REPORTED__USER_TYPE__FULL_RESTRICTED;
+            case USER_TYPE_PROFILE_MANAGED:
+                return FrameworkStatsLog
+                        .USER_LIFECYCLE_JOURNEY_REPORTED__USER_TYPE__PROFILE_MANAGED;
+            case USER_TYPE_SYSTEM_HEADLESS:
+                return FrameworkStatsLog
+                        .USER_LIFECYCLE_JOURNEY_REPORTED__USER_TYPE__SYSTEM_HEADLESS;
+            default:
+                return FrameworkStatsLog.USER_LIFECYCLE_JOURNEY_REPORTED__USER_TYPE__TYPE_UNKNOWN;
+        }
+    }
+
     /**
      * @hide
      * @deprecated Use {@link #isRestrictedProfile()}

services/core/java/com/android/server/am/UserController.java

@@ -40,6 +40,7 @@ import static com.android.server.am.UserState.STATE_RUNNING_LOCKED;
 import static com.android.server.am.UserState.STATE_RUNNING_UNLOCKED;
 import static com.android.server.am.UserState.STATE_RUNNING_UNLOCKING;
 
+import android.annotation.IntDef;
 import android.annotation.NonNull;
 import android.annotation.Nullable;
 import android.annotation.UserIdInt;
@@ -89,6 +90,7 @@ import android.util.Pair;
 import android.util.Slog;
 import android.util.SparseArray;
 import android.util.SparseIntArray;
+import android.util.SparseLongArray;
 import android.util.proto.ProtoOutputStream;
 
 import com.android.internal.R;
@@ -112,6 +114,7 @@ import java.util.Arrays;
 import java.util.Iterator;
 import java.util.List;
 import java.util.Objects;
+import java.util.concurrent.ThreadLocalRandom;
 import java.util.concurrent.atomic.AtomicInteger;
 
 /**
@@ -162,6 +165,46 @@ class UserController implements Handler.Callback {
     // TODO(b/149604218): STOPSHIP remove  this constant and the logcat
     private static final boolean TESTS_NEED_LOGCAT = true;
 
+    // Used for statsd logging with UserLifecycleJourneyReported + UserLifecycleEventOccurred atoms
+    private static final long INVALID_SESSION_ID = 0;
+
+    // The various user journeys, defined in the UserLifecycleJourneyReported atom for statsd
+    private static final int USER_JOURNEY_UNKNOWN =
+            FrameworkStatsLog.USER_LIFECYCLE_JOURNEY_REPORTED__JOURNEY__UNKNOWN;
+    private static final int USER_JOURNEY_USER_SWITCH_FG =
+            FrameworkStatsLog.USER_LIFECYCLE_JOURNEY_REPORTED__JOURNEY__USER_SWITCH_FG;
+    private static final int USER_JOURNEY_USER_SWITCH_UI =
+            FrameworkStatsLog.USER_LIFECYCLE_JOURNEY_REPORTED__JOURNEY__USER_SWITCH_UI;
+    private static final int USER_JOURNEY_USER_START =
+            FrameworkStatsLog.USER_LIFECYCLE_JOURNEY_REPORTED__JOURNEY__USER_START;
+    private static final int USER_JOURNEY_USER_CREATE =
+            FrameworkStatsLog.USER_LIFECYCLE_JOURNEY_REPORTED__JOURNEY__USER_CREATE;
+    @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,
+    })
+    @interface UserJourney {}
+
+    // The various user lifecycle events, defined in the UserLifecycleEventOccurred atom for statsd
+    private static final int USER_LIFECYCLE_EVENT_UNKNOWN =
+            FrameworkStatsLog.USER_LIFECYCLE_EVENT_OCCURRED__EVENT__UNKNOWN;
+    private static final int USER_LIFECYCLE_EVENT_SWITCH_USER =
+            FrameworkStatsLog.USER_LIFECYCLE_EVENT_OCCURRED__EVENT__SWITCH_USER;
+    private static final int USER_LIFECYCLE_EVENT_START_USER =
+            FrameworkStatsLog.USER_LIFECYCLE_EVENT_OCCURRED__EVENT__START_USER;
+    private static final int USER_LIFECYCLE_EVENT_CREATE_USER =
+            FrameworkStatsLog.USER_LIFECYCLE_EVENT_OCCURRED__EVENT__CREATE_USER;
+    @IntDef(prefix = { "USER_LIFECYCLE_EVENT" }, value = {
+            USER_LIFECYCLE_EVENT_UNKNOWN,
+            USER_LIFECYCLE_EVENT_SWITCH_USER,
+            USER_LIFECYCLE_EVENT_START_USER,
+            USER_LIFECYCLE_EVENT_CREATE_USER,
+    })
+    @interface UserLifecycleEvent {}
+
     /**
      * Maximum number of users we allow to be running at a time, including system user.
      *
@@ -270,6 +313,13 @@ class UserController implements Handler.Callback {
     @GuardedBy("mLock")
     private final ArrayList<Integer> mLastActiveUsers = new ArrayList<>();
 
+    /**
+     * A per-user, journey to session id map, used for statsd logging for the
+     * UserLifecycleJourneyReported and UserLifecycleEventOccurred atoms.
+     */
+    @GuardedBy("mUserJourneyToSessionIdMap")
+    private final SparseArray<SparseLongArray> mUserJourneyToSessionIdMap = new SparseArray<>();
+
     UserController(ActivityManagerService service) {
         this(new Injector(service));
     }
@@ -2349,6 +2399,10 @@ class UserController implements Handler.Callback {
     public boolean handleMessage(Message msg) {
         switch (msg.what) {
             case START_USER_SWITCH_FG_MSG:
+                logUserJourneyInfo(getUserInfo(getCurrentUserId()), getUserInfo(msg.arg1),
+                        USER_JOURNEY_USER_SWITCH_FG);
+                logUserLifecycleEvent(msg.arg1, USER_JOURNEY_USER_SWITCH_FG,
+                        USER_LIFECYCLE_EVENT_SWITCH_USER, true);
                 startUserInForeground(msg.arg1);
                 break;
             case REPORT_USER_SWITCH_MSG:
@@ -2370,8 +2424,14 @@ class UserController implements Handler.Callback {
                 mInjector.batteryStatsServiceNoteEvent(
                         BatteryStats.HistoryItem.EVENT_USER_RUNNING_START,
                         Integer.toString(msg.arg1), msg.arg1);
+                logUserJourneyInfo(null, getUserInfo(msg.arg1), USER_JOURNEY_USER_START);
+                logUserLifecycleEvent(msg.arg1, USER_JOURNEY_USER_START,
+                        USER_LIFECYCLE_EVENT_START_USER, true);
                 mInjector.getSystemServiceManager().startUser(TimingsTraceAndSlog.newAsyncLog(),
                         msg.arg1);
+                logUserLifecycleEvent(msg.arg1, USER_JOURNEY_USER_START,
+                        USER_LIFECYCLE_EVENT_START_USER, false);
+                clearSessionId(msg.arg1, USER_JOURNEY_USER_START);
                 break;
             case USER_UNLOCK_MSG:
                 final int userId = msg.arg1;
@@ -2400,17 +2460,94 @@ class UserController implements Handler.Callback {
                 break;
             case REPORT_USER_SWITCH_COMPLETE_MSG:
                 dispatchUserSwitchComplete(msg.arg1);
+                final int currentJourney = mUserSwitchUiEnabled ? USER_JOURNEY_USER_SWITCH_UI
+                                                                : USER_JOURNEY_USER_SWITCH_FG;
+                logUserLifecycleEvent(msg.arg1, currentJourney,
+                        USER_LIFECYCLE_EVENT_SWITCH_USER, false);
+                clearSessionId(msg.arg1, currentJourney);
                 break;
             case REPORT_LOCKED_BOOT_COMPLETE_MSG:
                 dispatchLockedBootComplete(msg.arg1);
                 break;
             case START_USER_SWITCH_UI_MSG:
-                showUserSwitchDialog((Pair<UserInfo, UserInfo>) msg.obj);
+                final Pair<UserInfo, UserInfo> fromToUserPair = (Pair<UserInfo, UserInfo>) msg.obj;
+                logUserJourneyInfo(fromToUserPair.first, fromToUserPair.second,
+                        USER_JOURNEY_USER_SWITCH_UI);
+                logUserLifecycleEvent(fromToUserPair.second.id, USER_JOURNEY_USER_SWITCH_UI,
+                        USER_LIFECYCLE_EVENT_SWITCH_USER, true);
+                showUserSwitchDialog(fromToUserPair);
                 break;
         }
         return false;
     }
 
+    /**
+     * statsd helper method for logging the start of a user journey via a UserLifecycleEventOccurred
+     * atom given the originating and targeting users for the journey.
+     *
+     * Note: these info atoms are currently logged more than once per journey since there is no
+     * state associated with the user's ongoing journey - this will be updated in a later CL.
+     */
+    private void logUserJourneyInfo(UserInfo origin, UserInfo target, @UserJourney int journey) {
+        final long newSessionId = ThreadLocalRandom.current().nextLong(1, Long.MAX_VALUE);
+        synchronized (mUserJourneyToSessionIdMap) {
+            SparseLongArray userSessions = mUserJourneyToSessionIdMap.get(target.id);
+            if (userSessions == null) {
+                userSessions = new SparseLongArray();
+                mUserJourneyToSessionIdMap.put(target.id, userSessions);
+            }
+            final long oldSessionId = userSessions.get(journey);
+            if (oldSessionId != INVALID_SESSION_ID) {
+                // potentially an incomplete or timed-out session
+                FrameworkStatsLog.write(FrameworkStatsLog.USER_LIFECYCLE_EVENT_OCCURRED,
+                        oldSessionId, target.id, USER_LIFECYCLE_EVENT_UNKNOWN,
+                        FrameworkStatsLog.USER_LIFECYCLE_EVENT_OCCURRED__STATE__NONE);
+            }
+            // update session id
+            userSessions.put(journey, newSessionId);
+        }
+
+        FrameworkStatsLog.write(FrameworkStatsLog.USER_LIFECYCLE_JOURNEY_REPORTED, newSessionId,
+                journey, origin != null ? origin.id : -1,
+                target.id, UserManager.getUserTypeForStatsd(target.userType), target.flags);
+    }
+
+    /**
+     * statsd helper method for logging the begin or finish of the given event for the
+     * UserLifecycleEventOccurred statsd atom.
+     * Note: This does not clear the user's journey session id - if this event represents the end of
+     * a particular journey, call {@link #clearSessionId} to indicate that the session is over.
+     */
+    private void logUserLifecycleEvent(@UserIdInt int userId, @UserJourney int journey,
+            @UserLifecycleEvent int event, boolean begin) {
+        final long sessionId;
+        synchronized (mUserJourneyToSessionIdMap) {
+            final SparseLongArray eventToSessionMap = mUserJourneyToSessionIdMap.get(userId);
+            if (eventToSessionMap == null || eventToSessionMap.size() == 0) {
+                return;
+            }
+            sessionId = eventToSessionMap.get(journey);
+            if (sessionId == INVALID_SESSION_ID) {
+                return;
+            }
+        }
+
+        FrameworkStatsLog.write(FrameworkStatsLog.USER_LIFECYCLE_EVENT_OCCURRED, sessionId, userId,
+                event, begin ? FrameworkStatsLog.USER_LIFECYCLE_EVENT_OCCURRED__STATE__BEGIN
+                             : FrameworkStatsLog.USER_LIFECYCLE_EVENT_OCCURRED__STATE__FINISH);
+    }
+
+    /**
+     * Clears the user's session id associated with the given UserJourney (for statsd).
+     */
+    private void clearSessionId(@UserIdInt int userId, @UserJourney int journey) {
+        synchronized (mUserJourneyToSessionIdMap) {
+            if (mUserJourneyToSessionIdMap.get(userId) != null) {
+                mUserJourneyToSessionIdMap.get(userId).delete(journey);
+            }
+        }
+    }
+
     private static class UserProgressListener extends IProgressListener.Stub {
         private volatile long mUnlockStarted;
         @Override

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

@@ -103,6 +103,7 @@ import com.android.internal.logging.MetricsLogger;
 import com.android.internal.os.BackgroundThread;
 import com.android.internal.util.DumpUtils;
 import com.android.internal.util.FastXmlSerializer;
+import com.android.internal.util.FrameworkStatsLog;
 import com.android.internal.util.Preconditions;
 import com.android.internal.util.XmlUtils;
 import com.android.internal.widget.LockPatternUtils;
@@ -137,6 +138,7 @@ import java.util.LinkedList;
 import java.util.List;
 import java.util.Objects;
 import java.util.Set;
+import java.util.concurrent.ThreadLocalRandom;
 
 /**
  * Service for {@link UserManager}.
@@ -3244,16 +3246,39 @@ public class UserManagerService extends IUserManager.Stub {
             @NonNull String userType, @UserInfoFlag int flags, @UserIdInt int parentId,
             boolean preCreate, @Nullable String[] disallowedPackages)
             throws UserManager.CheckedUserOperationException {
+        final int nextProbableUserId = getNextAvailableId();
         final TimingsTraceAndSlog t = new TimingsTraceAndSlog();
         t.traceBegin("createUser-" + flags);
+        final long sessionId = logUserCreateJourneyBegin(nextProbableUserId, userType, flags);
         try {
             return createUserInternalUncheckedNoTracing(name, userType, flags, parentId,
                     preCreate, disallowedPackages, t);
         } finally {
+            logUserCreateJourneyFinish(sessionId, nextProbableUserId);
             t.traceEnd();
         }
     }
 
+    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,
+                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;
+    }
+
+    private void logUserCreateJourneyFinish(long sessionId, @UserIdInt int userId) {
+        FrameworkStatsLog.write(FrameworkStatsLog.USER_LIFECYCLE_EVENT_OCCURRED, sessionId, userId,
+                FrameworkStatsLog.USER_LIFECYCLE_EVENT_OCCURRED__EVENT__CREATE_USER,
+                FrameworkStatsLog.USER_LIFECYCLE_EVENT_OCCURRED__STATE__FINISH);
+    }
+
     private UserInfo createUserInternalUncheckedNoTracing(@Nullable String name,
             @NonNull String userType, @UserInfoFlag int flags, @UserIdInt int parentId,
             boolean preCreate, @Nullable String[] disallowedPackages,