diff --git a/cmds/statsd/src/atoms.proto b/cmds/statsd/src/atoms.proto index 1f090fda2ce76..b7ed6eb160135 100644 --- a/cmds/statsd/src/atoms.proto +++ b/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) +} diff --git a/core/java/android/os/UserManager.java b/core/java/android/os/UserManager.java index 0f2060a36ac93..187274a837a0a 100644 --- a/core/java/android/os/UserManager.java +++ b/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()} diff --git a/services/core/java/com/android/server/am/UserController.java b/services/core/java/com/android/server/am/UserController.java index e02c6f9d5497b..546025a2498fa 100644 --- a/services/core/java/com/android/server/am/UserController.java +++ b/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 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 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) msg.obj); + final Pair fromToUserPair = (Pair) 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 diff --git a/services/core/java/com/android/server/pm/UserManagerService.java b/services/core/java/com/android/server/pm/UserManagerService.java index 323ffcfc2a1cd..fc70af4e7bd41 100644 --- a/services/core/java/com/android/server/pm/UserManagerService.java +++ b/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,