首次开机android.intent.action.BOOT_COMPLETED开机广播发送慢的问题

1. 背景
做过android开发的同学相信一定做个这种逻辑:app接收BOOT_COMPLETED开机广播，自启动，或者收到广播做一些事情。目前在我们的项目上遇到首次开机，BOOT_COMPLETED开机广播发送慢的问题。接下来分享记录下如何定位这类问题。

2. 分析过程

01-01 08:00:33.689247 1014 1840 I wm_create_activity:[0,42774215,7,com.android.launcher/.activity.LauncherActivity,android.intent.action.MAIN,NULL,NULL,268435712]
launcer界面的创建时间点为08:00:33

01-01 08:00:39.384523 1014 1855 I ActivityManager: Posting BOOT_COMPLETED user #0
系统发送开机广播的时间为08:00:39
中间有6秒多的间隔，需要看看开机广播发送慢的问题。

1.第一次开机，boot_completed广播之前，会先执行PreBoot 耗时6s，这是google原生行为。
行 24354: 01-01 08:00:33.293553 1014 1288 I uc_finish_user_unlocked: 0
行 24429: 01-01 08:00:33.302932 1014 1288 I PreBootBroadcaster: Pre-boot of {com.android.documentsui/com.android.documentsui.PreBootReceiver} for user 0
行 25647: 01-01 08:00:33.659771 1014 2704 I PreBootBroadcaster: Pre-boot of {com.android.managedprovisioning/com.android.managedprovisioning.ota.PreBootListener} for user 0
行 27224: 01-01 08:00:34.296557 1014 2907 I PreBootBroadcaster: Pre-boot of {com.android.providers.contacts/com.android.providers.contacts.ContactsUpgradeReceiver} for user 0
行 33427: 01-01 08:00:37.224144 1014 1856 I PreBootBroadcaster: Pre-boot of {com.android.providers.media.module/com.android.providers.media.MediaUpgradeReceiver} for user 0
行 37494: 01-01 08:00:39.384308 1014 1855 I uc_finish_user_unlocked_completed: 0

2. 后面重启，不会有preboot动作，正常。
   行 68220: 11-01 08:00:18.937687 960 1142 I uc_finish_user_unlocked: 0
   行 68294: 11-01 08:00:18.943890 960 1142 I uc_finish_user_unlocked_completed: 0
   行 115214: 11-01 08:01:17.388510 969 1098 I uc_finish_user_unlocked: 0
   行 115407: 11-01 08:01:17.482497 969 1098 I uc_finish_user_unlocked_completed: 0

    /*** Step from {@link UserState#STATE_RUNNING_UNLOCKING} to* {@link UserState#STATE_RUNNING_UNLOCKED}.*/void finishUserUnlocked(final UserState uss) {final int userId = uss.mHandle.getIdentifier();EventLog.writeEvent(EventLogTags.UC_FINISH_USER_UNLOCKED, userId);// Only keep marching forward if user is actually unlockedif (!StorageManager.isUserKeyUnlocked(userId)) return;synchronized (mLock) {// Bail if we ended up with a stale userif (mStartedUsers.get(uss.mHandle.getIdentifier()) != uss) return;// Do not proceed if unexpected stateif (!uss.setState(STATE_RUNNING_UNLOCKING, STATE_RUNNING_UNLOCKED)) {return;}}mInjector.getUserManagerInternal().setUserState(userId, uss.state);uss.mUnlockProgress.finish();// Get unaware persistent apps running and start any unaware providers// in already-running apps that are partially awareif (userId == UserHandle.USER_SYSTEM) {mInjector.startPersistentApps(PackageManager.MATCH_DIRECT_BOOT_UNAWARE);}mInjector.installEncryptionUnawareProviders(userId);// Dispatch unlocked to external appsfinal Intent unlockedIntent = new Intent(Intent.ACTION_USER_UNLOCKED);unlockedIntent.putExtra(Intent.EXTRA_USER_HANDLE, userId);unlockedIntent.addFlags(Intent.FLAG_RECEIVER_REGISTERED_ONLY | Intent.FLAG_RECEIVER_FOREGROUND);mInjector.broadcastIntent(unlockedIntent, null, null, 0, null,null, null, AppOpsManager.OP_NONE, null, false, false, MY_PID, SYSTEM_UID,Binder.getCallingUid(), Binder.getCallingPid(), userId);if (getUserInfo(userId).isManagedProfile()) {UserInfo parent = mInjector.getUserManager().getProfileParent(userId);if (parent != null) {final Intent profileUnlockedIntent = new Intent(Intent.ACTION_MANAGED_PROFILE_UNLOCKED);profileUnlockedIntent.putExtra(Intent.EXTRA_USER, UserHandle.of(userId));profileUnlockedIntent.addFlags(Intent.FLAG_RECEIVER_REGISTERED_ONLY| Intent.FLAG_RECEIVER_FOREGROUND);mInjector.broadcastIntent(profileUnlockedIntent,null, null, 0, null, null, null, AppOpsManager.OP_NONE,null, false, false, MY_PID, SYSTEM_UID, Binder.getCallingUid(),Binder.getCallingPid(), parent.id);}}// Send PRE_BOOT broadcasts if user fingerprint changed; we// purposefully block sending BOOT_COMPLETED until after all// PRE_BOOT receivers are finished to avoid ANR'ing appsfinal UserInfo info = getUserInfo(userId);if (!Objects.equals(info.lastLoggedInFingerprint, Build.FINGERPRINT)) {// Suppress double notifications for managed profiles that// were unlocked automatically as part of their parent user// being unlocked.final boolean quiet;if (info.isManagedProfile()) {quiet = !uss.tokenProvided|| !mLockPatternUtils.isSeparateProfileChallengeEnabled(userId);} else {quiet = false;}mInjector.sendPreBootBroadcast(userId, quiet,() -> finishUserUnlockedCompleted(uss));} else {finishUserUnlockedCompleted(uss);}}

关键log记录：
01-01 08:00:32.310344 1014 1265 D ActivityManager: Started unlocking user 0
01-01 08:00:32.310389 1014 1265 D ActivityManager: Unlocking user 0 progress 0
01-01 08:00:32.310526 1014 1265 D ActivityManager: Unlocking user 0 progress 5
01-01 08:00:33.245283 1014 1261 I ActivityManager: User 0 state changed from RUNNING_LOCKED to RUNNING_UNLOCKING
01-01 08:00:33.246592 1014 1261 D ActivityManager: Unlocking user 0 progress 20

unlockUserCleared
finishUserUnlocking
finishUserUnlocked
finishUserUnlockedCompleted