当前位置: 首页 > news >正文

开机过程关键日志记录和介绍

前言

开机阶段描述

先用命令:

adb logcat -b events|grep boot

过滤出启动阶段的主要事件。可以看到关键log基本把开机的每一步都打印了出来

01-01 08:00:18.096 591 591 I boot_progress_start: 12229 01-01 08:00:19.291 591 591 I boot_progress_preload_start: 13425 01-01 08:00:21.902 591 591 I boot_progress_preload_end: 16035 01-01 08:00:22.196 1504 1504 I boot_progress_system_run: 16330 01-01 08:00:22.817 1504 1504 I boot_progress_pms_start: 16950 01-01 08:00:23.189 1504 1504 I boot_progress_pms_system_scan_start: 17322 01-01 08:00:25.347 1504 1504 I boot_progress_pms_data_scan_start: 19480 01-01 08:00:25.462 1504 1504 I boot_progress_pms_scan_end: 19595 01-01 08:00:25.626 1504 1504 I boot_progress_pms_ready: 19759 05-08 18:46:58.709 1504 1504 I boot_progress_ams_ready: 20802 05-08 18:47:00.093 1504 1632 I boot_progress_enable_screen: 22187 05-08 18:47:01.931 742 2191 I sf_stop_bootanim: 24024 05-08 18:47:01.934 1504 1632 I wm_boot_animation_done: 24027
阶段描述
boot_progress_start系统进入用户空间,标志着kernel启动完成
boot_progress_preload_startZygote启动
boot_progress_preload_endZygote结束
boot_progress_system_runSystemServer ready,开始启动Android系统服务
boot_progress_pms_startPMS开始扫描安装的应用
boot_progress_pms_system_scan_startPMS先行扫描/system目录下的安装包
boot_progress_pms_data_scan_startPMS扫描/data目录下的安装包
boot_progress_pms_scan_endPMS扫描结束
boot_progress_pms_readyPMS就绪
boot_progress_ams_readyAMS就绪
boot_progress_enable_screenAMS启动完成后开始激活屏幕,从此以后屏幕才能响应用户的触摸,它在WindowManagerService发出退出开机动画的时间节点之前
sf_stop_bootanimSF设置service.bootanim.exit属性值为1,标志系统要结束开机动画了
wm_boot_animation_done开机动画结束,这一步用户能直观感受到开机结束

一.各个阶段对应的代码

1. boot_progress_start

frameworks/base/core/jni/AndroidRuntime.cpp

void AndroidRuntime::start(const char* className, const Vector<String8>& options, bool zygote)
{
...
/*
* 'startSystemServer == true' means runtime is obsolete and not run from
* init.rc anymore, so we print out the boot start event here.
*/
for (size_t i = 0; i < options.size(); ++i) {
if (options[i] ==startSystemServer) {
primary_zygote = true;
/* track our progress through the boot sequence */
const intLOG_BOOT_PROGRESS_START= 3000;

//日志打印
LOG_EVENT_LONG(LOG_BOOT_PROGRESS_START, ns2ms(systemTime(SYSTEM_TIME_MONOTONIC)));
}
}
...
}

对应的

3000boot_progress_start (time|2|3)

2. boot_progress_preload_start

3. boot_progress_preload_end

/frameworks/base/core/java/com/android/internal/os/ZygoteInit.java

private static final intLOG_BOOT_PROGRESS_PRELOAD_START= 3020;
private static final intLOG_BOOT_PROGRESS_PRELOAD_END= 3030;

public static void main(String[] argv) {
...
// In some configurations, we avoid preloading resources and classes eagerly.
// In such cases, we will preload things prior to our first fork.
if (!enableLazyPreload) {
bootTimingsTraceLog.traceBegin("ZygotePreload");
EventLog.writeEvent(LOG_BOOT_PROGRESS_PRELOAD_START,SystemClock.uptimeMillis());
preload(bootTimingsTraceLog); //输出日志
EventLog.writeEvent(LOG_BOOT_PROGRESS_PRELOAD_END, SystemClock.uptimeMillis());
bootTimingsTraceLog.traceEnd(); // ZygotePreload
}
// Do an initial gc to clean up after startup
bootTimingsTraceLog.traceBegin("PostZygoteInitGC");
gcAndFinalize();
bootTimingsTraceLog.traceEnd(); // PostZygoteInitGC
bootTimingsTraceLog.traceEnd(); // ZygoteInit
Zygote.initNativeState(isPrimaryZygote);
/// M: Added for BOOTPROF
addBootEvent("Zygote:Preload End");
...
}

system/logging/logcat/event.logtags

# ZygoteInit class preloading starts:3020boot_progress_preload_start (time|2|3) # ZygoteInit class preloading ends:3030boot_progress_preload_end (time|2|3)

4. boot_progress_system_run

frameworks/base/services/java/com/android/server/SystemServer.java

private void run() { ...// Here we go!Slog.i(TAG, "Entered the Android system server!"); final long uptimeMillis = SystemClock.elapsedRealtime(); EventLog.writeEvent(EventLogTags.BOOT_PROGRESS_SYSTEM_RUN, uptimeMillis); if (!mRuntimeRestart) { FrameworkStatsLog.write(FrameworkStatsLog.BOOT_TIME_EVENT_ELAPSED_TIME_REPORTED, FrameworkStatsLog .BOOT_TIME_EVENT_ELAPSED_TIME__EVENT__SYSTEM_SERVER_INIT_START, uptimeMillis); } ... }

5. boot_progress_pms_start

frameworks/base/services/core/java/com/android/server/pm/PackageManagerService.java

public PackageManagerService(Injector injector, boolean onlyCore, boolean factoryTest) { ... mInjector = injector; mInjector.bootstrap(this); mLock = injector.getLock(); mInstallLock = injector.getInstallLock(); LockGuard.installLock(mLock, LockGuard.INDEX_PACKAGES); EventLog.writeEvent(EventLogTags.BOOT_PROGRESS_PMS_START, SystemClock.uptimeMillis()); ... }

6. boot_progress_pms_system_scan_start

frameworks/base/services/core/java/com/android/server/pm/PackageManagerService.java

public PackageManagerService(Injector injector, boolean onlyCore, boolean factoryTest) { ... long startTime = SystemClock.uptimeMillis(); EventLog.writeEvent(EventLogTags.BOOT_PROGRESS_PMS_SYSTEM_SCAN_START, startTime); final String bootClassPath = System.getenv("BOOTCLASSPATH"); final String systemServerClassPath = System.getenv("SYSTEMSERVERCLASSPATH"); if (bootClassPath == null) { Slog.w(TAG, "No BOOTCLASSPATH found!"); } if (systemServerClassPath == null) { Slog.w(TAG, "No SYSTEMSERVERCLASSPATH found!"); } ... }

7. boot_progress_pms_data_scan_start

frameworks/base/services/core/java/com/android/server/pm/PackageManagerService.java

public PackageManagerService(Injector injector, boolean onlyCore, boolean factoryTest) { ... // Remove any shared userIDs that have no associated packages mSettings.pruneSharedUsersLPw(); final long systemScanTime = SystemClock.uptimeMillis() - startTime; final int systemPackagesCount = mPackages.size(); Slog.i(TAG, "Finished scanning system apps. Time: " + systemScanTime + " ms, packageCount: " + systemPackagesCount + " , timePerPackage: " + (systemPackagesCount == 0 ? 0 : systemScanTime / systemPackagesCount) + " , cached: " + cachedSystemApps); if (mIsUpgrade && systemPackagesCount > 0) { //CHECKSTYLE:OFF IndentationCheck FrameworkStatsLog.write(FrameworkStatsLog.BOOT_TIME_EVENT_DURATION_REPORTED, BOOT_TIME_EVENT_DURATION__EVENT__OTA_PACKAGE_MANAGER_SYSTEM_APP_AVG_SCAN_TIME, systemScanTime / systemPackagesCount); //CHECKSTYLE:ON IndentationCheck } if (!mOnlyCore) { EventLog.writeEvent(EventLogTags.BOOT_PROGRESS_PMS_DATA_SCAN_START, SystemClock.uptimeMillis()); scanDirTracedLI(sAppInstallDir, 0, scanFlags | SCAN_REQUIRE_KNOWN, 0, packageParser, executorService); } ... }

8. boot_progress_pms_scan_end

frameworks/base/services/core/java/com/android/server/pm/PackageManagerService.java

public PackageManagerService(Injector injector, boolean onlyCore, boolean factoryTest) { ... // Now that we know all the packages we are keeping, // read and update their last usage times. mPackageUsage.read(mSettings.mPackages); mCompilerStats.read(); EventLog.writeEvent(EventLogTags.BOOT_PROGRESS_PMS_SCAN_END, SystemClock.uptimeMillis()); //显示扫描时间 Slog.i(TAG, "Time to scan packages:" + ((SystemClock.uptimeMillis()-startTime)/1000f) + " seconds"); ... }

9. boot_progress_pms_ready

frameworks/base/services/core/java/com/android/server/pm/PackageManagerService.java

public PackageManagerService(Injector injector, boolean onlyCore, boolean factoryTest) { ... // can downgrade to reader t.traceBegin("write settings"); mSettings.writeLPr(); t.traceEnd(); EventLog.writeEvent(EventLogTags.BOOT_PROGRESS_PMS_READY, SystemClock.uptimeMillis()); ... }

10. boot_progress_ams_ready

frameworks/base/services/core/java/com/android/server/am/ActivityManagerService.java

public void systemReady(final Runnable goingCallback, @NonNull TimingsTraceAndSlog t) { ...**** t.traceEnd(); // KillProcesses Slog.i(TAG, "System now ready"); EventLogTags.writeBootProgressAmsReady(SystemClock.uptimeMillis()); t.traceBegin("updateTopComponentForFactoryTest"); mAtmInternal.updateTopComponentForFactoryTest(); t.traceEnd(); ... }

11. boot_progress_enable_screen

frameworks/base/services/core/java/com/android/server/wm/ActivityTaskManagerService.java

@Override public void enableScreenAfterBoot(boolean booted) {writeBootProgressEnableScreen(SystemClock.uptimeMillis()); mWindowManager.enableScreenAfterBoot(); synchronized (mGlobalLock) { updateEventDispatchingLocked(booted); } }

12. sf_stop_bootanim

frameworks/native/services/surfaceflinger/SurfaceFlinger.cpp

void SurfaceFlinger::bootFinished() { ... // stop boot animation // formerly we would just kill the process, but we now ask it to exit so it // can choose where to stop the animation. property_set("service.bootanim.exit", "1"); const intLOGTAG_SF_STOP_BOOTANIM= 60110; LOG_EVENT_LONG(LOGTAG_SF_STOP_BOOTANIM, ns2ms(systemTime(SYSTEM_TIME_MONOTONIC))); sp<IBinder> input(defaultServiceManager()->getService(String16("inputflinger"))); ... }

frameworks/native/services/surfaceflinger/EventLog/EventLogTags.logtags

60100sf_frame_dur (window|3),(dur0|1),(dur1|1),(dur2|1),(dur3|1),(dur4|1),(dur5|1),(dur6|1) 39 60110 sf_stop_bootanim (time|2|3)

13. wm_boot_animation_done

frameworks/base/services/core/java/com/android/server/wm/WindowManagerService.java

private void performEnableScreen() { ... try { IBinder surfaceFlinger = ServiceManager.getService("SurfaceFlinger"); if (surfaceFlinger != null) { ProtoLog.i(WM_ERROR, "******* TELLING SURFACE FLINGER WE ARE BOOTED!"); Parcel data = Parcel.obtain(); data.writeInterfaceToken("android.ui.ISurfaceComposer"); surfaceFlinger.transact(IBinder.FIRST_CALL_TRANSACTION, // BOOT_FINISHED data, null, 0); data.recycle(); } } catch (RemoteException ex) { ProtoLog.e(WM_ERROR, "Boot completed: SurfaceFlinger is dead!"); } EventLogTags.writeWmBootAnimationDone(SystemClock.uptimeMillis()); Trace.asyncTraceEnd(TRACE_TAG_WINDOW_MANAGER, "Stop bootanim", 0); mDisplayEnabled = true; ProtoLog.i(WM_DEBUG_SCREEN_ON,"******************** ENABLINGSCREEN!"); ... }

二. 案例:

开机动画时间长.

从日志中发现,boot_progress_ams_ready -->sf_stop_bootanim 花费的时间特别长,消耗了27秒.

从kernel 层开机开始统计.实例

3.1 log
// Linux kernel start
[0.000000] Booting Linux on physical CPU 0x100
<14>[1.765707] [01-29 01:33:34.500]init: init first stage started!
<14>[3.709000] [01-29 01:33:36.439]init: init second stage started!

//Kernel startup completed, 9462 means cost 9.462 seconds
01-29 01:33:41.223 478 478 I boot_progress_start: 9462

//zygote starts up
01-29 01:33:44.894 478 478 I boot_progress_preload_start: 13133
//zygote startup completed
01-29 01:33:49.997 478 478 I boot_progress_preload_end: 18236

//system server ready
01-29 01:33:51.088 1257 1257 I boot_progress_system_run: 19327

//PM scans the installation packages in the /system directory
01-29 01:33:52.213 1257 1257 I boot_progress_pms_start: 20452
////PM scans the installation packages in the /data directory
01-29 01:33:53.918 1257 1257 I boot_progress_pms_data_scan_start: 22157
//PM ends scanning
01-29 01:33:53.947 1257 1257 I boot_progress_pms_scan_end: 22186
//PM ready
01-29 01:33:54.172 1257 1257 I boot_progress_pms_ready: 22410

//The system has calibrated the time and there was a time jump
01-29 01:33:54.588 1257 1257 I AlarmManager: Current time only 2396034588,
advancing to build time 1721297206000
07-18 18:06:46.000 1257 1257 W AlarmManagerService: Unable to set rtc to
1721297206: No such device

3.2 log
// bootup logo AT&T amiGO Jr watch end
// The startup animation(AT&T Logo) starts playing
07-18 18:06:47.414 897 1003 D bootanimation: TrackPlayerBase::TrackPlayerBase()

//AM ready and waiting for the screen to be ready
//Even after the system animation has finished, it will continue to display until all //system servers and core system applications have started completely.
07-18 18:06:47.9081257 1257 I boot_progress_ams_ready: 24733
//surfaceflinger stops boot animation
07-18 18:07:20.408599 1396 I sf_stop_bootanim: 57236
//Boot animation ends
07-18 18:07:20.409 1257 1347 I wm_boot_animation_done: 57237

发现异常点:

开机能完成,是通过timeout的方式触发的.

07-11 05:16:09.363 1366 1485 I WindowManager: shouldWaitForSystemDecorWindowsOnBoot haveApp:true,haveKeyguard:true,wallpaperEnabled:true,haveWallpaper:false

07-11 05:16:12.663 1366 1485 I WindowManager: shouldWaitForSystemDecorWindowsOnBoot haveApp:true,haveKeyguard:true,wallpaperEnabled:true,haveWallpaper:false
07-11 17:16:39.328 1366 1485 W WindowManager:***** BOOT TIMEOUT: forcing display enabled

找到对应的代码:


3382 public void enableScreenAfterBoot() {
3383 synchronized (mGlobalLock) {
3384 ProtoLog.i(WM_DEBUG_BOOT, "enableScreenAfterBoot: mDisplayEnabled=%b "
3385 + "mForceDisplayEnabled=%b mShowingBootMessages=%b mSystemBooted=%b. "
3386 + "%s",
3387 mDisplayEnabled, mForceDisplayEnabled, mShowingBootMessages, mSystemBooted,
3388 new RuntimeException("here").fillInStackTrace());
3389 if (mSystemBooted) {
3390 return;
3391 }
3392 mSystemBooted = true;
3393 hideBootMessagesLocked();
3394// If the screen still doesn't come up after 30 seconds, give
3395// up and turn it on.
3396 mH.sendEmptyMessageDelayed(H.BOOT_TIMEOUT,30 * 1000);
3397 }

然后,再查看出现原因是什么:

怀疑SystemUI wallpaperservice 被移除,而没有禁止wallpaper的原因.

3812 // If we are turning on the screen to show the boot message, don't do it until the boot
3813 // message is actually displayed.
3814 if (!mWmService.mSystemBooted && !haveBootMsg) {
3815 return true;
3816 }
3817
3818 // If we are turning on the screen after the boot is completed normally, don't do so until
3819 // we have the application and wallpaper.
3820 if (mWmService.mSystemBooted
3821 && ((!haveApp && !haveKeyguard) || (wallpaperEnabled&& !haveWallpaper))) {
3822 return true;
3823 }

通过加日志,调试:

07-11 05:16:09.363 1366 1485 I WindowManager: shouldWaitForSystemDecorWindowsOnBoot haveApp:true,haveKeyguard:true,wallpaperEnabled:true,haveWallpaper:false

07-11 05:16:12.663 1366 1485 I WindowManager: shouldWaitForSystemDecorWindowsOnBoot haveApp:true,haveKeyguard:true,wallpaperEnabled:true,haveWallpaper:false
07-11 17:16:39.328 1366 1485 W WindowManager: ***** BOOT TIMEOUT: forcing display enabled

根本原因:

在做项目裁剪时,因为觉得wallpaper 没有用到,将wallpaper service移除,但是, 系统有需要支持wallpaper,所以只是在systemui 中移除,造成此问题.

http://www.jsqmd.com/news/1349065/

相关文章:

  • 如何3分钟批量处理1000个视频字幕:MKVToolNix批量工具完全指南
  • MySQL 基础用法(上):库表管理与数据增删改
  • 深度相机实战指南:从传感器标定到机器人视觉系统集成完全掌握
  • TencentDB Agent Memory插件开发指南:如何扩展自定义记忆处理模块?
  • Postmanerator开发指南:如何创建自定义主题
  • 终极多显示器壁纸管理指南:告别拼接错位,让桌面视觉体验飙升
  • 5个核心功能带你玩转career-ops:开源AI求职自动化工具完全指南
  • 定投10年从1W到100W基金投资复盘05-两周组合定投复盘
  • 深圳搬家公司哪家正规?2026年工商+交通双资质核查结果 - 禧燕搬家
  • Table Transformer实战指南:基于DETR的智能表格提取解决方案
  • 2026年河北优秀的缝制防护罩制造商怎么选才靠谱,认准坤腾机床 - 品牌优推
  • Changedetection.io 终极指南:免费开源的网站变更检测与实时监控工具
  • 2026琼山区营业执照办理**测评,避坑攻略与材料清单 - GrowthUME
  • 2026年PDF转图片免费工具盘点:这7款在线与电脑软件实测无水印够用
  • Adobe Illustrator脚本终极指南:10个免费工具快速提升设计效率
  • Onu UI未来路线图:即将发布的令人兴奋的新功能预览
  • 3步搞定文档处理:零基础上手DOCX、PDF、PPTX、XLSX全能工具箱
  • 如何在5分钟内掌握大麦自动抢票神器:双端智能购票终极指南
  • 2026、8 月苏州市吴江区彩钢瓦、金属屋面、钢结构,防水防腐、出新、除锈、喷漆、修缮 ** 推荐 + 避坑指南 - 万至防水
  • Torrentio终极指南:如何用开源插件打造你的私人流媒体中心
  • 2026年8月最新推荐 青岛工业机械臂厂家**名单汇总一览 - 奔跑123
  • 跨国企业即时通讯私有化部署的必然趋势
  • 终极网页时光机:如何永久保存任何网站的历史版本
  • AI 电动节日用品与电动假发智能功率 MOSFET 核心选型方案
  • 温州市苍南县GEO城市合伙人选型推荐哪家靠谱:源头厂商、区域保护与合伙人权益一次看清 - 企业新闻快传
  • 如何用Unshaky彻底解决Mac蝴蝶键盘连击问题:5步完整修复方案
  • 绍兴市嵊州市GEO城市合伙人选型推荐:哪家靠谱?本地团队如何选对源头厂商与合伙人权益 - 小随科技
  • 2026年板式初效防尘网热门厂家推荐哪家找深圳市恒丰滤业有限公司 - 品牌优推
  • 金华市金东区GEO城市合伙人选型推荐哪家靠谱:本地创业者代理加盟前,先看清这7个选型维度 - 子柔传媒
  • 3个核心技巧:彻底解决华硕笔记本性能控制的烦恼