Donate to e Foundation | Murena handsets with /e/OS | Own a part of Murena! Learn more

Commit 4f93a04a authored by Mayank Garg's avatar Mayank Garg
Browse files

Added more events to user switch journey

Bug: 141388849
Bug: 146505521
Bug: 150788910
Test: statsd_testdrive 264 265
Change-Id: I9a770182706a5a9272c7b5d4fcc11f5f13020e0e
parent 3a9ceed2
Loading
Loading
Loading
Loading
+3 −0
Original line number Original line Diff line number Diff line
@@ -9587,6 +9587,9 @@ message UserLifecycleEventOccurred {
        SWITCH_USER = 1; // Indicates that this is a user switch event
        SWITCH_USER = 1; // Indicates that this is a user switch event
        START_USER = 2; // Indicates that this is a user start event
        START_USER = 2; // Indicates that this is a user start event
        CREATE_USER = 3; // Indicates that this is a user create event
        CREATE_USER = 3; // Indicates that this is a user create event
        USER_RUNNING_LOCKED = 4; // Indicates that user is running in locked state
        UNLOCKING_USER = 5; // Indicates that this is a user unlocking event
        UNLOCKED_USER = 6; // Indicates that this is a user unlocked event
    }
    }
    optional Event event = 3;
    optional Event event = 3;


+152 −52
Original line number Original line Diff line number Diff line
@@ -90,7 +90,6 @@ import android.util.Pair;
import android.util.Slog;
import android.util.Slog;
import android.util.SparseArray;
import android.util.SparseArray;
import android.util.SparseIntArray;
import android.util.SparseIntArray;
import android.util.SparseLongArray;
import android.util.proto.ProtoOutputStream;
import android.util.proto.ProtoOutputStream;


import com.android.internal.R;
import com.android.internal.R;
@@ -154,6 +153,15 @@ class UserController implements Handler.Callback {
    static final int REPORT_LOCKED_BOOT_COMPLETE_MSG = 110;
    static final int REPORT_LOCKED_BOOT_COMPLETE_MSG = 110;
    static final int START_USER_SWITCH_FG_MSG = 120;
    static final int START_USER_SWITCH_FG_MSG = 120;


    // 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;
    // 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.
    private static final int USER_JOURNEY_TIMEOUT_MS = 90_000;

    // UI thread message constants
    // UI thread message constants
    static final int START_USER_SWITCH_UI_MSG = 1000;
    static final int START_USER_SWITCH_UI_MSG = 1000;


@@ -194,14 +202,37 @@ class UserController implements Handler.Callback {
            FrameworkStatsLog.USER_LIFECYCLE_EVENT_OCCURRED__EVENT__START_USER;
            FrameworkStatsLog.USER_LIFECYCLE_EVENT_OCCURRED__EVENT__START_USER;
    private static final int USER_LIFECYCLE_EVENT_CREATE_USER =
    private static final int USER_LIFECYCLE_EVENT_CREATE_USER =
            FrameworkStatsLog.USER_LIFECYCLE_EVENT_OCCURRED__EVENT__CREATE_USER;
            FrameworkStatsLog.USER_LIFECYCLE_EVENT_OCCURRED__EVENT__CREATE_USER;
    private static final int USER_LIFECYCLE_EVENT_USER_RUNNING_LOCKED =
            FrameworkStatsLog.USER_LIFECYCLE_EVENT_OCCURRED__EVENT__USER_RUNNING_LOCKED;
    private static final int USER_LIFECYCLE_EVENT_UNLOCKING_USER =
            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;
    @IntDef(prefix = { "USER_LIFECYCLE_EVENT" }, value = {
    @IntDef(prefix = { "USER_LIFECYCLE_EVENT" }, value = {
            USER_LIFECYCLE_EVENT_UNKNOWN,
            USER_LIFECYCLE_EVENT_UNKNOWN,
            USER_LIFECYCLE_EVENT_SWITCH_USER,
            USER_LIFECYCLE_EVENT_SWITCH_USER,
            USER_LIFECYCLE_EVENT_START_USER,
            USER_LIFECYCLE_EVENT_START_USER,
            USER_LIFECYCLE_EVENT_CREATE_USER,
            USER_LIFECYCLE_EVENT_CREATE_USER,
            USER_LIFECYCLE_EVENT_USER_RUNNING_LOCKED,
            USER_LIFECYCLE_EVENT_UNLOCKING_USER,
            USER_LIFECYCLE_EVENT_UNLOCKED_USER,
    })
    })
    @interface UserLifecycleEvent {}
    @interface UserLifecycleEvent {}


    // User lifecyle event state, defined in the UserLifecycleEventOccurred atom for statsd
    private static final int USER_LIFECYCLE_EVENT_STATE_BEGIN =
            FrameworkStatsLog.USER_LIFECYCLE_EVENT_OCCURRED__STATE__BEGIN;
    private static final int USER_LIFECYCLE_EVENT_STATE_FINISH =
            FrameworkStatsLog.USER_LIFECYCLE_EVENT_OCCURRED__STATE__FINISH;
    private static final int USER_LIFECYCLE_EVENT_STATE_NONE =
            FrameworkStatsLog.USER_LIFECYCLE_EVENT_OCCURRED__STATE__NONE;
    @IntDef(prefix = { "USER_LIFECYCLE_EVENT_STATE" }, value = {
            USER_LIFECYCLE_EVENT_STATE_BEGIN,
            USER_LIFECYCLE_EVENT_STATE_FINISH,
            USER_LIFECYCLE_EVENT_STATE_NONE,
    })
    @interface UserLifecycleEventState {}

    /**
    /**
     * Maximum number of users we allow to be running at a time, including system user.
     * Maximum number of users we allow to be running at a time, including system user.
     *
     *
@@ -311,11 +342,11 @@ class UserController implements Handler.Callback {
    private final ArrayList<Integer> mLastActiveUsers = new ArrayList<>();
    private final ArrayList<Integer> mLastActiveUsers = new ArrayList<>();


    /**
    /**
     * A per-user, journey to session id map, used for statsd logging for the
     * {@link UserIdInt} to {@link UserJourneySession} mapping used for statsd logging for the
     * UserLifecycleJourneyReported and UserLifecycleEventOccurred atoms.
     * UserLifecycleJourneyReported and UserLifecycleEventOccurred atoms.
     */
     */
    @GuardedBy("mUserJourneyToSessionIdMap")
    @GuardedBy("mUserIdToUserJourneyMap")
    private final SparseArray<SparseLongArray> mUserJourneyToSessionIdMap = new SparseArray<>();
    private final SparseArray<UserJourneySession> mUserIdToUserJourneyMap = new SparseArray<>();


    UserController(ActivityManagerService service) {
    UserController(ActivityManagerService service) {
        this(new Injector(service));
        this(new Injector(service));
@@ -447,6 +478,8 @@ class UserController implements Handler.Callback {
        // but we might immediately step into RUNNING below if the user
        // but we might immediately step into RUNNING below if the user
        // storage is already unlocked.
        // storage is already unlocked.
        if (uss.setState(STATE_BOOTING, STATE_RUNNING_LOCKED)) {
        if (uss.setState(STATE_BOOTING, STATE_RUNNING_LOCKED)) {
            logUserLifecycleEvent(userId, USER_LIFECYCLE_EVENT_USER_RUNNING_LOCKED,
                    USER_LIFECYCLE_EVENT_STATE_NONE);
            mInjector.getUserManagerInternal().setUserState(userId, uss.state);
            mInjector.getUserManagerInternal().setUserState(userId, uss.state);
            // Do not report secondary users, runtime restarts or first boot/upgrade
            // Do not report secondary users, runtime restarts or first boot/upgrade
            if (userId == UserHandle.USER_SYSTEM
            if (userId == UserHandle.USER_SYSTEM
@@ -503,6 +536,8 @@ class UserController implements Handler.Callback {
    private boolean finishUserUnlocking(final UserState uss) {
    private boolean finishUserUnlocking(final UserState uss) {
        final int userId = uss.mHandle.getIdentifier();
        final int userId = uss.mHandle.getIdentifier();
        EventLog.writeEvent(EventLogTags.UC_FINISH_USER_UNLOCKING, userId);
        EventLog.writeEvent(EventLogTags.UC_FINISH_USER_UNLOCKING, userId);
        logUserLifecycleEvent(userId, USER_LIFECYCLE_EVENT_UNLOCKING_USER,
                USER_LIFECYCLE_EVENT_STATE_BEGIN);
        // Only keep marching forward if user is actually unlocked
        // Only keep marching forward if user is actually unlocked
        if (!StorageManager.isUserKeyUnlocked(userId)) return false;
        if (!StorageManager.isUserKeyUnlocked(userId)) return false;
        synchronized (mLock) {
        synchronized (mLock) {
@@ -2396,8 +2431,8 @@ class UserController implements Handler.Callback {
            case START_USER_SWITCH_FG_MSG:
            case START_USER_SWITCH_FG_MSG:
                logUserJourneyInfo(getUserInfo(getCurrentUserId()), getUserInfo(msg.arg1),
                logUserJourneyInfo(getUserInfo(getCurrentUserId()), getUserInfo(msg.arg1),
                        USER_JOURNEY_USER_SWITCH_FG);
                        USER_JOURNEY_USER_SWITCH_FG);
                logUserLifecycleEvent(msg.arg1, USER_JOURNEY_USER_SWITCH_FG,
                logUserLifecycleEvent(msg.arg1, USER_LIFECYCLE_EVENT_SWITCH_USER,
                        USER_LIFECYCLE_EVENT_SWITCH_USER, true);
                        USER_LIFECYCLE_EVENT_STATE_BEGIN);
                startUserInForeground(msg.arg1);
                startUserInForeground(msg.arg1);
                break;
                break;
            case REPORT_USER_SWITCH_MSG:
            case REPORT_USER_SWITCH_MSG:
@@ -2420,14 +2455,14 @@ class UserController implements Handler.Callback {
                        BatteryStats.HistoryItem.EVENT_USER_RUNNING_START,
                        BatteryStats.HistoryItem.EVENT_USER_RUNNING_START,
                        Integer.toString(msg.arg1), msg.arg1);
                        Integer.toString(msg.arg1), msg.arg1);
                logUserJourneyInfo(null, getUserInfo(msg.arg1), USER_JOURNEY_USER_START);
                logUserJourneyInfo(null, getUserInfo(msg.arg1), USER_JOURNEY_USER_START);
                logUserLifecycleEvent(msg.arg1, USER_JOURNEY_USER_START,
                logUserLifecycleEvent(msg.arg1, USER_LIFECYCLE_EVENT_START_USER,
                        USER_LIFECYCLE_EVENT_START_USER, true);
                        USER_LIFECYCLE_EVENT_STATE_BEGIN);


                mInjector.getSystemServiceManager().startUser(TimingsTraceAndSlog.newAsyncLog(),
                mInjector.getSystemServiceManager().startUser(TimingsTraceAndSlog.newAsyncLog(),
                        msg.arg1);
                        msg.arg1);


                logUserLifecycleEvent(msg.arg1, USER_JOURNEY_USER_START,
                logUserLifecycleEvent(msg.arg1, USER_LIFECYCLE_EVENT_START_USER,
                        USER_LIFECYCLE_EVENT_START_USER, false);
                        USER_LIFECYCLE_EVENT_STATE_FINISH);
                clearSessionId(msg.arg1, USER_JOURNEY_USER_START);
                clearSessionId(msg.arg1, USER_JOURNEY_USER_START);
                break;
                break;
            case USER_UNLOCK_MSG:
            case USER_UNLOCK_MSG:
@@ -2437,10 +2472,17 @@ class UserController implements Handler.Callback {
                FgThread.getHandler().post(() -> {
                FgThread.getHandler().post(() -> {
                    mInjector.loadUserRecents(userId);
                    mInjector.loadUserRecents(userId);
                });
                });
                logUserLifecycleEvent(msg.arg1, USER_LIFECYCLE_EVENT_UNLOCKING_USER,
                        USER_LIFECYCLE_EVENT_STATE_FINISH);
                logUserLifecycleEvent(msg.arg1, USER_LIFECYCLE_EVENT_UNLOCKED_USER,
                        USER_LIFECYCLE_EVENT_STATE_BEGIN);
                finishUserUnlocked((UserState) msg.obj);
                finishUserUnlocked((UserState) msg.obj);
                break;
                break;
            case USER_UNLOCKED_MSG:
            case USER_UNLOCKED_MSG:
                mInjector.getSystemServiceManager().onUserUnlocked(msg.arg1);
                mInjector.getSystemServiceManager().onUserUnlocked(msg.arg1);
                logUserLifecycleEvent(msg.arg1, USER_LIFECYCLE_EVENT_UNLOCKED_USER,
                        USER_LIFECYCLE_EVENT_STATE_FINISH);
                clearSessionId(msg.arg1);
                break;
                break;
            case USER_CURRENT_MSG:
            case USER_CURRENT_MSG:
                mInjector.batteryStatsServiceNoteEvent(
                mInjector.batteryStatsServiceNoteEvent(
@@ -2458,11 +2500,8 @@ class UserController implements Handler.Callback {
            case REPORT_USER_SWITCH_COMPLETE_MSG:
            case REPORT_USER_SWITCH_COMPLETE_MSG:
                dispatchUserSwitchComplete(msg.arg1);
                dispatchUserSwitchComplete(msg.arg1);


                final int currentJourney = mUserSwitchUiEnabled ? USER_JOURNEY_USER_SWITCH_UI
                logUserLifecycleEvent(msg.arg1, USER_LIFECYCLE_EVENT_SWITCH_USER,
                                                                : USER_JOURNEY_USER_SWITCH_FG;
                        USER_LIFECYCLE_EVENT_STATE_FINISH);
                logUserLifecycleEvent(msg.arg1, currentJourney,
                        USER_LIFECYCLE_EVENT_SWITCH_USER, false);
                clearSessionId(msg.arg1, currentJourney);
                break;
                break;
            case REPORT_LOCKED_BOOT_COMPLETE_MSG:
            case REPORT_LOCKED_BOOT_COMPLETE_MSG:
                dispatchLockedBootComplete(msg.arg1);
                dispatchLockedBootComplete(msg.arg1);
@@ -2471,10 +2510,13 @@ class UserController implements Handler.Callback {
                final Pair<UserInfo, UserInfo> fromToUserPair = (Pair<UserInfo, UserInfo>) msg.obj;
                final Pair<UserInfo, UserInfo> fromToUserPair = (Pair<UserInfo, UserInfo>) msg.obj;
                logUserJourneyInfo(fromToUserPair.first, fromToUserPair.second,
                logUserJourneyInfo(fromToUserPair.first, fromToUserPair.second,
                        USER_JOURNEY_USER_SWITCH_UI);
                        USER_JOURNEY_USER_SWITCH_UI);
                logUserLifecycleEvent(fromToUserPair.second.id, USER_JOURNEY_USER_SWITCH_UI,
                logUserLifecycleEvent(fromToUserPair.second.id, USER_LIFECYCLE_EVENT_SWITCH_USER,
                        USER_LIFECYCLE_EVENT_SWITCH_USER, true);
                        USER_LIFECYCLE_EVENT_STATE_BEGIN);
                showUserSwitchDialog(fromToUserPair);
                showUserSwitchDialog(fromToUserPair);
                break;
                break;
            case CLEAR_USER_JOURNEY_SESSION_MSG:
                clearSessionId(msg.arg1);
                break;
        }
        }
        return false;
        return false;
    }
    }
@@ -2482,27 +2524,61 @@ class UserController implements Handler.Callback {
    /**
    /**
     * statsd helper method for logging the start of a user journey via a UserLifecycleEventOccurred
     * statsd helper method for logging the start of a user journey via a UserLifecycleEventOccurred
     * atom given the originating and targeting users for the journey.
     * 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) {
    private void logUserJourneyInfo(UserInfo origin, UserInfo target, @UserJourney int journey) {
        final long newSessionId = ThreadLocalRandom.current().nextLong(1, Long.MAX_VALUE);
        final long newSessionId = ThreadLocalRandom.current().nextLong(1, Long.MAX_VALUE);
        synchronized (mUserJourneyToSessionIdMap) {
        synchronized (mUserIdToUserJourneyMap) {
            SparseLongArray userSessions = mUserJourneyToSessionIdMap.get(target.id);
            UserJourneySession userJourneySession = mUserIdToUserJourneyMap.get(target.id);
            if (userSessions == null) {
            if (userJourneySession != null) {
                userSessions = new SparseLongArray();
                // TODO(b/157007231): Move this logic to a separate class/file.
                mUserJourneyToSessionIdMap.put(target.id, userSessions);
                if ((userJourneySession.mJourney == USER_JOURNEY_USER_SWITCH_UI
            }
                        && journey == USER_JOURNEY_USER_START)
            final long oldSessionId = userSessions.get(journey);
                        || (userJourneySession.mJourney == USER_JOURNEY_USER_SWITCH_FG
            if (oldSessionId != INVALID_SESSION_ID) {
                                && journey == USER_JOURNEY_USER_START)) {
                // potentially an incomplete or timed-out session
                    /*
                     * 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.
                     */
                    if (DEBUG_MU) {
                        Slog.d(TAG, journey + " not logged as it is expected to be part of "
                                + userJourneySession.mJourney);
                    }
                    return;
                }
                /*
                 * Possible reasons for this condition to be true:
                 * - A user switch journey is received while another user switch journey is in
                 *   process for the same user.
                 * - A user switch journey is received while user start journey is in process for
                 *   the same user.
                 * - A user start journey is received while another user start journey is in process
                 *   for the same user.
                 * In all cases potentially an incomplete, timed-out session or multiple
                 * simultaneous requests. It is not possible to keep track of multiple sessions for
                 * the same user, so previous session is abandoned.
                 */
                FrameworkStatsLog.write(FrameworkStatsLog.USER_LIFECYCLE_EVENT_OCCURRED,
                FrameworkStatsLog.write(FrameworkStatsLog.USER_LIFECYCLE_EVENT_OCCURRED,
                        oldSessionId, target.id, USER_LIFECYCLE_EVENT_UNKNOWN,
                        userJourneySession.mSessionId, target.id, USER_LIFECYCLE_EVENT_UNKNOWN,
                        FrameworkStatsLog.USER_LIFECYCLE_EVENT_OCCURRED__STATE__NONE);
                        USER_LIFECYCLE_EVENT_STATE_NONE);
            }
            }
            // update session id

            userSessions.put(journey, newSessionId);
            if (DEBUG_MU) {
                Slog.d(TAG,
                        "Starting a new journey: " + journey + " with session id: " + newSessionId);
            }

            userJourneySession = new UserJourneySession(newSessionId, journey);
            mUserIdToUserJourneyMap.put(target.id, userJourneySession);
            /*
             * User lifecyle journey would be complete when {@code #clearSessionId} is called after
             * the last expected lifecycle event for the journey. It may be possible that the last
             * event is not called, e.g., user not unlocked after user switching. In such cases user
             * journey is cleared after {@link USER_JOURNEY_TIMEOUT}.
             */
            mHandler.removeMessages(CLEAR_USER_JOURNEY_SESSION_MSG);
            mHandler.sendMessageDelayed(mHandler.obtainMessage(CLEAR_USER_JOURNEY_SESSION_MSG,
                    target.id), USER_JOURNEY_TIMEOUT_MS);
        }
        }


        FrameworkStatsLog.write(FrameworkStatsLog.USER_LIFECYCLE_JOURNEY_REPORTED, newSessionId,
        FrameworkStatsLog.write(FrameworkStatsLog.USER_LIFECYCLE_JOURNEY_REPORTED, newSessionId,
@@ -2511,41 +2587,65 @@ class UserController implements Handler.Callback {
    }
    }


    /**
    /**
     * statsd helper method for logging the begin or finish of the given event for the
     * statsd helper method for logging the given event for the UserLifecycleEventOccurred statsd
     * UserLifecycleEventOccurred statsd atom.
     * 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,
    private void logUserLifecycleEvent(@UserIdInt int userId, @UserLifecycleEvent int event,
            @UserLifecycleEvent int event, boolean begin) {
            @UserLifecycleEventState int eventState) {
        final long sessionId;
        final long sessionId;
        synchronized (mUserJourneyToSessionIdMap) {
        synchronized (mUserIdToUserJourneyMap) {
            final SparseLongArray eventToSessionMap = mUserJourneyToSessionIdMap.get(userId);
            final UserJourneySession userJourneySession = mUserIdToUserJourneyMap.get(userId);
            if (eventToSessionMap == null || eventToSessionMap.size() == 0) {
            if (userJourneySession == null || userJourneySession.mSessionId == INVALID_SESSION_ID) {
                return;
                Slog.w(TAG, "UserLifecycleEvent " + event
            }
                        + " received without an active userJourneySession.");
            sessionId = eventToSessionMap.get(journey);
            if (sessionId == INVALID_SESSION_ID) {
                return;
                return;
            }
            }
            sessionId = userJourneySession.mSessionId;
        }
        }


        FrameworkStatsLog.write(FrameworkStatsLog.USER_LIFECYCLE_EVENT_OCCURRED, sessionId, userId,
        FrameworkStatsLog.write(FrameworkStatsLog.USER_LIFECYCLE_EVENT_OCCURRED, sessionId, userId,
                event, begin ? FrameworkStatsLog.USER_LIFECYCLE_EVENT_OCCURRED__STATE__BEGIN
                event, eventState);
                             : FrameworkStatsLog.USER_LIFECYCLE_EVENT_OCCURRED__STATE__FINISH);
    }
    }


    /**
    /**
     * Clears the user's session id associated with the given UserJourney (for statsd).
     * Clears the {@link UserJourneySession} for a given {@link UserIdInt} and {@link UserJourney}.
     */
     */
    private void clearSessionId(@UserIdInt int userId, @UserJourney int journey) {
    private void clearSessionId(@UserIdInt int userId, @UserJourney int journey) {
        synchronized (mUserJourneyToSessionIdMap) {
        synchronized (mUserIdToUserJourneyMap) {
            if (mUserJourneyToSessionIdMap.get(userId) != null) {
            final UserJourneySession userJourneySession = mUserIdToUserJourneyMap.get(userId);
                mUserJourneyToSessionIdMap.get(userId).delete(journey);
            if (userJourneySession != null && userJourneySession.mJourney == journey) {
                clearSessionId(userId);
            }
            }
        }
        }
    }
    }


    /**
     * Clears the {@link UserJourneySession} for a given {@link UserIdInt}.
     */
    private void clearSessionId(@UserIdInt int userId) {
        synchronized (mUserIdToUserJourneyMap) {
            mHandler.removeMessages(CLEAR_USER_JOURNEY_SESSION_MSG);
            mUserIdToUserJourneyMap.delete(userId);
        }
    }

    /**
     * Helper class to store user journey and session id.
     *
     * <p> User journey tracks a chain of user lifecycle events occurring during different user
     * activities such as user start, user switch, and user creation.
     */
    // TODO(b/157007231): Move this class and user journey tracking logic to a separate file.
    private static class UserJourneySession {
        final long mSessionId;
        @UserJourney final int mJourney;

        UserJourneySession(long sessionId, @UserJourney int journey) {
            mJourney = journey;
            mSessionId = sessionId;
        }
    }

    private static class UserProgressListener extends IProgressListener.Stub {
    private static class UserProgressListener extends IProgressListener.Stub {
        private volatile long mUnlockStarted;
        private volatile long mUnlockStarted;
        @Override
        @Override