【性能优化】从events日志分析系统->launcher启动过程
2026/6/13 17:14:48 网站建设 项目流程

一、前言

日常分析系统启动劣化了,拿到的一手信息,一般是包含main.log、kmsg.log、events.log日志,可能不会特别理想的还能提供到复现劣化时的trace文件(systrace、atrace、perfetto工具抓取的),比如常见的情况是后台质量平台发现的劣化,这时候几乎都没有trace文件的。所以如何从这三类日志文件中初步定位劣化发生在哪个阶段,还是比较重要的一个知识点。

上述三类文件中,除了main.log我们很熟悉,其中会包含应用的日志+一些系统服务的关键日志,比如:AMS、PMS等等。events.log也是我们平时分析劣化的一个关键日志文件。

二、events.log日志中分析系统启动过程

如下是小米8SE的系统启动过程的events.log日志(做了删减仅保留了需要关注的日志):

01-1018:30:07.614I/boot_progress_start(638):596101-1018:30:10.240I/boot_progress_preload_start(638):858801-1018:30:11.833I/boot_progress_preload_end(638):1018101-1018:30:12.141I/system_server_start(1540):[1,10486,10486]01-1018:30:12.145I/boot_progress_system_run(1540):1049301-1018:30:12.765I/boot_progress_pms_start(1540):1111301-1018:30:13.306I/boot_progress_pms_system_scan_start(1540):1165301-1018:30:14.188I/boot_progress_pms_data_scan_start(1540):1253601-1018:30:15.369I/boot_progress_pms_scan_end(1540):1371601-1018:30:15.606I/boot_progress_pms_ready(1540):1395301-1018:30:19.064I/boot_progress_ams_ready(1540):17412// -------------下面开始拉取各种系统应用进程--------------------//01-1018:30:19.925I/am_proc_start(1540):[0,2098,1002,com.android.bluetooth,service,{com.android.bluetooth/com.android.bluetooth.btservice.AdapterService}]01-1018:30:19.942I/am_proc_bound(1540):[0,2098,com.android.bluetooth]01-1018:30:20.130I/am_proc_start(1540):[0,2119,1000,com.android.systemui,service,{com.android.systemui/com.android.systemui.ImageWallpaper}]01-1018:30:20.133I/am_proc_bound(1540):[0,2119,com.android.systemui]01-1018:30:20.249I/am_proc_start(1540):[0,2150,1037,WebViewLoader-armeabi-v7a,NULL,]01-1018:30:20.275I/am_proc_start(1540):[0,2172,1037,WebViewLoader-arm64-v8a,NULL,]01-1018:30:20.288I/am_proc_bound(1540):[0,2150,WebViewLoader-armeabi-v7a]01-1018:30:20.293I/am_uid_active(1540):103701-1018:30:20.308I/am_proc_bound(1540):[0,2172,WebViewLoader-arm64-v8a]01-1018:30:20.743I/am_proc_died(1540):[0,2150,WebViewLoader-armeabi-v7a,-700,0]01-1018:30:20.748I/am_proc_died(1540):[0,2172,WebViewLoader-arm64-v8a,-700,0]01-1018:30:20.796I/am_proc_start(1540):[0,2287,10102,com.android.deskclock,service,{com.android.deskclock/com.android.deskclock.JobSchedulerService}]01-1018:30:20.914I/wm_task_created(1540):[1,0]01-1018:30:20.916I/am_create_task(1540):[0,1]//----------主线流程,拉起miui系统的launcher的main activity执行生命周期过程---------//01-1018:30:20.916I/am_create_activity(1540):[0,101306167,1,com.miui.home/.launcher.Launcher,android.intent.action.MAIN,NULL,NULL,276824320]01-1018:30:21.350I/am_restart_activity(1540):[0,101306167,1,com.miui.home/.launcher.Launcher,2481]01-1018:30:21.353I/am_set_resumed_activity(1540):[0,com.miui.home/.launcher.Launcher,minimalResumeActivityLocked]01-1018:30:23.000I/am_on_create_called(2481):[0,com.miui.home.launcher.Launcher,performCreate,787]01-1018:30:23.011I/am_on_start_called(2481):[0,com.miui.home.launcher.Launcher,handleStartActivity,6]01-1018:30:23.023I/am_on_resume_called(2481):[0,com.miui.home.launcher.Launcher,RESUME_ACTIVITY,11]01-1018:30:23.030I/am_on_top_resumed_gained_called(2481):[0,com.miui.home.launcher.Launcher,topStateChangedWhenResumed]01-1018:30:23.420I/am_activity_launch_time(1540):[0,101306167,com.miui.home/.launcher.Launcher,2572]//----------开机完成的时机,也就是实际的开机耗时--------------//01-1018:30:23.617I/boot_progress_enable_screen(1540):21965

查询了下,冷开机的指标,中端系统的手机一般指标是20s以内为达标

  • 豆包提供的的不同厂商的开机时长参考如下:
  • 总结现状就是:旗舰机20s以内,中端手机25s以内
    • 旗舰手机:优秀水平是在 20 秒以内,良好水平为 20-30 秒,30-40 秒属于一般,超过 40 秒则较差。
    • 中端手机:优秀标准是在 25 秒以内,25-35 秒为良好,35-45 秒属于一般,超过 45 秒则较差。

上面是一款比较老的机型,所以耗时偏长,但是能看到开机的过程时序如下(可右键从新标签页查看清晰大图):

三、总结开机阶段每个关键阶段代表的含义

日志tag含义
boot_progress_start: 5961开机计时基准点(Boot 计时开始),之后所有 boot_progress_* 都是从这里开始的 uptime 时间点。
boot_progress_preload_start: 8588Zygote 开始 preload(预加载 class/resources 等)。对应源码位置(AOSP 11 典型):ZygoteInit.preload() 前后, 从 start 到 preload_start 的耗时:8588 - 5961 = 2627ms这段主要是:init → zygote 拉起、runtime 初始化、zygote 准备工作等。
boot_progress_preload_end: 10181Zygote preload 完成
boot_progress_system_run: 10493SystemServer 进入 run() 主流程(系统服务启动大幕拉开)
boot_progress_pms_start: 11113SystemServer 开始启动 PackageManagerService(PMS)初始化。
boot_progress_pms_system_scan_start: 11653PMS 开始扫描 /system 分区 包(system/priv-app/product/vendor 等)
boot_progress_pms_data_scan_start: 12536PMS 开始扫描 /data 分区(用户安装/更新、data app 等)
boot_progress_pms_scan_end: 13716PMS 扫描阶段结束(system+data 扫描完成,进入后续 reconcile/写配置等)
boot_progress_pms_ready: 13953PMS “ready”(包管理核心可用),通常意味着扫描/解析/设置完成,后续服务可依赖 PMS
boot_progress_ams_ready: 17412AMS 完成关键初始化,系统进入能调度 Activity/进程管理的 ready 点(SystemServer 在 systemReady 流程附近)
boot_progress_enable_screen: 21965WindowManagerService 满足条件并执行 enableScreenIfNeeded(允许点亮屏幕/进入可交互),ams_ready → enable_screen: AMS.systemReady() 之后到 WMS.enableScreenIfNeeded() 之间的一系列动作(启动 Home/ SystemUI、BootPhase 500/600 回调、窗口/显示策略准备、Keyguard/BootAnimation 条件等
每个耗时算的是哪个阶段?
  • preload_*:Zygote 预加载耗时
  • pms_*:PMS 初始化+扫描 /system、/data 的耗时
  • ams_ready:SystemServer 启动其它服务并跑到 AMS ready 的耗时(依赖 PMS 之后的大段)
  • enable_screen:AMS ready → 启用开屏 的耗时(Home/SystemUI/WM/BootPhase 回调/等待条件)

有了以上每个阶段tag代表的阶段含义,就能按照我们实际分析诉求进行分析了。举个例子,需要分析是否launcher劣化引起的开机慢,那么可以直接先看am_activity_launch_time这行代码:

01-10 18:30:23.420 I/am_activity_launch_time( 1540): [0,101306167,com.miui.home/.launcher.Launcher,2572]

最后一个字段代表的就是launcher启动的总耗时,然后查看正常冷开机情况下的启动launcher耗时即可知道是否存在劣化,如果确认这个耗时是有劣化的。那么就可以从以下的日志tag中分析(搜索关键字:am_、wm_、应用包名):

以Android14 aosp的源码实现为例,梳理如下:

tag日志打印的时机具体代码代码的时机
am_proc_startAMS 决定拉起进程并执行 fork 时打印(system_server)。表示“要启动某个 app 进程了”,此时进程刚 fork 出来,尚未完成 bind。ProcessList->handleProcessStartedLocked() EventLog.writeEvent(EventLogTags.AM_PROC_START…)
am_proc_boundAMS 开始向该进程下发 bindApplication
am_create_activityam_开头的是system_server进程执行的逻辑,这个tag的日志代表的ATMS/AMS 请求应用进程创建 Activity 记录并发起启动的阶段打印(system_server)。通常在 startActivity 流程已决定要启动/复用某个 Activity,进入“真正创建/启动该 Activity”的链路时出现是在执行ActivityThread#performLaunchActivity前打印的
am_restart_activityActivity 走重启/重新启动路径时打印(system_server),常见原因:该 Activity 先前被 stop、配置变更需重建、进程已在但 Activity 需要重新 launch 等
am_set_resumed_activitysystem_server 内部把某个 Activity 设为 resumed/top resumed(焦点/交互态)时打印,表示“前台栈顶已切到它”(WMS/ATMS 状态机推进)
am_on_create_called应用进程里 Activity.performCreate() 执行到(ActivityThread 侧的 instrumentation 调用链)时打点:已进入 Activity.onCreate()是在Activity#onCreate执行结束后打印的,也就是说am_create_activity->am_on_create_called过程代表业务activity实际onCreate执行的耗时
am_on_start_called应用进程里进入 Activity.onStart() 时打点
am_on_resume_called应用进程里进入 Activity.onResume() 时打点
am_on_top_resumed_gained_called应用进程里 Activity.onTopResumedActivityChanged(true) 回调发生时打点(Android 10+ 用于多窗口/焦点管理)。表示该 Activity 获得 “Top Resumed” 权限(通常就是当前可交互前台)
am_activity_launch_timesystem_server 统计并输出本次 Activity 启动耗时时打印(AMS/ATMS)。一般在系统认为“已显示/已绘制到某阶段”后汇总(口径随版本可能是 displayed/fully drawn/或 resume 到窗口可见)

需要专业的网站建设服务?

联系我们获取免费的网站建设咨询和方案报价,让我们帮助您实现业务目标

立即咨询