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

Commit 9a5523a4 authored by Adam Bookatz's avatar Adam Bookatz
Browse files

More UserController tracing

Add some more trace points for user switching,
especially key points and slow processes.

Bug: 192100413
Test: N/A (but manually checked that they are interesting)
Change-Id: I7b11d16e8ef95b63b5e07ef16b7c30c1ea3f8d07
parent 2464b3f7
Loading
Loading
Loading
Loading
+24 −1
Original line number Diff line number Diff line
@@ -590,7 +590,11 @@ class UserController implements Handler.Callback {
                Slogf.w(TAG, "User key got locked unexpectedly, leaving user locked.");
                return;
            }

            final TimingsTraceAndSlog t = new TimingsTraceAndSlog();
            t.traceBegin("UM.onBeforeUnlockUser-" + userId);
            mInjector.getUserManager().onBeforeUnlockUser(userId);
            t.traceEnd();
            synchronized (mLock) {
                // Do not proceed if unexpected state
                if (!uss.setState(STATE_RUNNING_LOCKED, STATE_RUNNING_UNLOCKING)) {
@@ -1683,7 +1687,11 @@ class UserController implements Handler.Callback {
            return false;
        }

        if (!finishUserUnlocking(uss)) {
        final TimingsTraceAndSlog t = new TimingsTraceAndSlog();
        t.traceBegin("finishUserUnlocking-" + userId);
        final boolean finishUserUnlockingResult = finishUserUnlocking(uss);
        t.traceEnd();
        if (!finishUserUnlockingResult) {
            notifyFinished(userId, listener);
            return false;
        }
@@ -1849,6 +1857,9 @@ class UserController implements Handler.Callback {
    }

    void dispatchUserSwitch(final UserState uss, final int oldUserId, final int newUserId) {
        final TimingsTraceAndSlog t = new TimingsTraceAndSlog();
        t.traceBegin("dispatchUserSwitch-" + oldUserId + "-to-" + newUserId);

        EventLog.writeEvent(EventLogTags.UC_DISPATCH_USER_SWITCH, oldUserId, newUserId);

        final int observerCount = mUserSwitchObservers.beginBroadcast();
@@ -1901,6 +1912,7 @@ class UserController implements Handler.Callback {
            }
        }
        mUserSwitchObservers.finishBroadcast();
        t.traceEnd(); // end dispatchUserSwitch-
    }

    @GuardedBy("mLock")
@@ -1912,16 +1924,23 @@ class UserController implements Handler.Callback {
    }

    void continueUserSwitch(UserState uss, int oldUserId, int newUserId) {
        final TimingsTraceAndSlog t = new TimingsTraceAndSlog();
        t.traceBegin("continueUserSwitch-" + oldUserId + "-to-" + newUserId);

        EventLog.writeEvent(EventLogTags.UC_CONTINUE_USER_SWITCH, oldUserId, newUserId);

        if (isUserSwitchUiEnabled()) {
            t.traceBegin("stopFreezingScreen");
            mInjector.getWindowManager().stopFreezingScreen();
            t.traceEnd();
        }
        uss.switching = false;
        mHandler.removeMessages(REPORT_USER_SWITCH_COMPLETE_MSG);
        mHandler.sendMessage(mHandler.obtainMessage(REPORT_USER_SWITCH_COMPLETE_MSG, newUserId, 0));
        stopGuestOrEphemeralUserIfBackground(oldUserId);
        stopBackgroundUsersOnSwitchIfEnforced(oldUserId);

        t.traceEnd(); // end continueUserSwitch
    }

    private void moveUserToForeground(UserState uss, int oldUserId, int newUserId) {
@@ -2670,7 +2689,11 @@ class UserController implements Handler.Callback {
                        USER_LIFECYCLE_EVENT_STATE_FINISH);
                logUserLifecycleEvent(msg.arg1, USER_LIFECYCLE_EVENT_UNLOCKED_USER,
                        USER_LIFECYCLE_EVENT_STATE_BEGIN);

                final TimingsTraceAndSlog t = new TimingsTraceAndSlog();
                t.traceBegin("finishUserUnlocked-" + userId);
                finishUserUnlocked((UserState) msg.obj);
                t.traceEnd();
                break;
            case USER_UNLOCKED_MSG:
                mInjector.getSystemServiceManager().onUserUnlocked(msg.arg1);
+7 −0
Original line number Diff line number Diff line
@@ -4814,8 +4814,15 @@ public class UserManagerService extends IUserManager.Stub {
        final int userSerial = userInfo.serialNumber;
        // Migrate only if build fingerprints mismatch
        boolean migrateAppsData = !Build.FINGERPRINT.equals(userInfo.lastLoggedInFingerprint);

        final TimingsTraceAndSlog t = new TimingsTraceAndSlog();
        t.traceBegin("prepareUserData-" + userId);
        mUserDataPreparer.prepareUserData(userId, userSerial, StorageManager.FLAG_STORAGE_CE);
        t.traceEnd();

        t.traceBegin("reconcileAppsData-" + userId);
        mPm.reconcileAppsData(userId, StorageManager.FLAG_STORAGE_CE, migrateAppsData);
        t.traceEnd();
    }

    /**
+18 −0
Original line number Diff line number Diff line
@@ -71,6 +71,7 @@ import com.android.server.pm.UserManagerInternal;
import com.android.server.pm.parsing.pkg.AndroidPackage;
import com.android.server.pm.permission.PermissionManagerServiceInternal;
import com.android.server.policy.PermissionPolicyInternal.OnInitializedCallback;
import com.android.server.utils.TimingsTraceAndSlog;

import java.util.ArrayList;
import java.util.Collections;
@@ -365,7 +366,11 @@ public final class PermissionPolicyService extends SystemService {
            return;
        }


        final TimingsTraceAndSlog t = new TimingsTraceAndSlog();
        t.traceBegin("Permission_grant_default_permissions-" + userId);
        grantOrUpgradeDefaultRuntimePermissionsIfNeeded(userId);
        t.traceEnd();

        final OnInitializedCallback callback;

@@ -375,11 +380,15 @@ public final class PermissionPolicyService extends SystemService {
        }

        // Force synchronization as permissions might have changed
        t.traceBegin("Permission_synchronize_permissions-" + userId);
        synchronizePermissionsAndAppOpsForUser(userId);
        t.traceEnd();

        // Tell observers we are initialized for this user.
        if (callback != null) {
            t.traceBegin("Permission_onInitialized-" + userId);
            callback.onInitialized(userId);
            t.traceEnd();
        }
    }

@@ -394,6 +403,7 @@ public final class PermissionPolicyService extends SystemService {

    private void grantOrUpgradeDefaultRuntimePermissionsIfNeeded(@UserIdInt int userId) {
        if (DEBUG) Slog.i(LOG_TAG, "grantOrUpgradeDefaultPermsIfNeeded(" + userId + ")");
        final TimingsTraceAndSlog t = new TimingsTraceAndSlog();

        final PackageManagerInternal packageManagerInternal =
                LocalServices.getService(PackageManagerInternal.class);
@@ -426,9 +436,12 @@ public final class PermissionPolicyService extends SystemService {
                        }
                    });
            try {
                t.traceBegin("Permission_callback_waiting-" + userId);
                future.get();
            } catch (InterruptedException | ExecutionException e) {
                throw new IllegalStateException(e);
            } finally {
                t.traceEnd();
            }

            permissionControllerManager.updateUserSensitive();
@@ -494,14 +507,19 @@ public final class PermissionPolicyService extends SystemService {
     */
    private void synchronizePermissionsAndAppOpsForUser(@UserIdInt int userId) {
        if (DEBUG) Slog.i(LOG_TAG, "synchronizePermissionsAndAppOpsForUser(" + userId + ")");
        final TimingsTraceAndSlog t = new TimingsTraceAndSlog();

        final PackageManagerInternal packageManagerInternal = LocalServices.getService(
                PackageManagerInternal.class);
        final PermissionToOpSynchroniser synchronizer = new PermissionToOpSynchroniser(
                getUserContext(getContext(), UserHandle.of(userId)));
        t.traceBegin("Permission_synchronize_addPackages-" + userId);
        packageManagerInternal.forEachPackage(
                (pkg) -> synchronizer.addPackage(pkg.getPackageName()));
        t.traceEnd();
        t.traceBegin("Permission_syncPackages-" + userId);
        synchronizer.syncPackages();
        t.traceEnd();
    }

    private void resetAppOpPermissionsIfNotRequestedForUidAsync(int uid) {
+26 −26
Original line number Diff line number Diff line
@@ -1816,9 +1816,6 @@ public class WallpaperManagerService extends IWallpaperManager.Stub

    @Override
    public void onUnlockUser(final int userId) {
        TimingsTraceAndSlog t = new TimingsTraceAndSlog(TAG);
        t.traceBegin("on-unlock-user-" + userId);
        try {
        synchronized (mLock) {
            if (mCurrentUserId == userId) {
                if (mWaitingForUnlock) {
@@ -1836,6 +1833,9 @@ public class WallpaperManagerService extends IWallpaperManager.Stub
                if (!mUserRestorecon.get(userId)) {
                    mUserRestorecon.put(userId, true);
                    Runnable relabeler = () -> {
                        final TimingsTraceAndSlog t = new TimingsTraceAndSlog(TAG);
                        t.traceBegin("Wallpaper_selinux_restorecon-" + userId);
                        try {
                            final File wallpaperDir = getWallpaperDir(userId);
                            for (String filename : sPerUserFiles) {
                                File f = new File(wallpaperDir, filename);
@@ -1843,14 +1843,14 @@ public class WallpaperManagerService extends IWallpaperManager.Stub
                                    SELinux.restorecon(f);
                                }
                            }
                        } finally {
                            t.traceEnd();
                        }
                    };
                    BackgroundThread.getHandler().post(relabeler);
                }
            }
        }
        } finally {
            t.traceEnd();
        }
    }

    void onRemoveUser(int userId) {
@@ -1868,7 +1868,7 @@ public class WallpaperManagerService extends IWallpaperManager.Stub

    void switchUser(int userId, IRemoteCallback reply) {
        TimingsTraceAndSlog t = new TimingsTraceAndSlog(TAG);
        t.traceBegin("switch-user-" + userId);
        t.traceBegin("Wallpaper_switch-user-" + userId);
        try {
            final WallpaperData systemWallpaper;
            final WallpaperData lockWallpaper;