一、 开机各个阶段分析
1、Bootloader 阶段
Bootloader 阶段 该阶段分为(preloader 和Ik 阶段)
从按电源键振动到 kernel 开始启动,这部分高通平台暂无好的方法确认时间,可以从总时间推算大概时间。MTK 项目可以从bootprof 确认
2、kernel 阶段
1.Linux boot -> init first stage started!
主要耗时为电池驱动以及 TP 初始化部分
MTK 项目可从bootprof 中看到各驱动初始化时间,高通平台暂无法确认
2.init first stage started! -> boot_progress_stat
系统进入用户空间,标志着kemel 启动完成
主要是内核访问根文件系统来启动init 进程,包括 apexd、加载 sepolicy (Coldboot)、挂载各个分区
kerne_log:
若以上阶段有差异可联系测试单独给bsp提单确认
3、Android 阶段
在eventlog中搜索boot_progress |sf_stop| wm_boot_animation_done关键字分析日志,粒度较大,只能定位出大概的耗时流程,之后还需分析流程内部具体的耗时情况。开机各流程内部也有相应的日志,可以进行更加细致的分析。
每个阶段如下表所示:
阶段 | 描述 |
boot_progress_start | 系统进入用户空间,标志着kernel启动完成 |
boot_progress_preload_start | Zygote启动 |
boot_progress_preload_end | Zygote结束 |
boot_progress_system_run | SystemServer ready,开始启动Android系统服务 |
boot_progress_pms_start | PMS开始扫描安装的应用 |
boot_progress_pms_system_scan_start | PMS先行扫描/system目录下的安装包 |
boot_progress_pms_data_scan_start | PMS扫描/data目录下的安装包 |
boot_progress_pms_scan_end | PMS扫描结束 |
boot_progress_pms_ready | PMS就绪 |
boot_progress_ams_ready | AMS就绪 |
boot_progress_enable_screen | AMS启动完成后开始激活屏幕,从此以后屏幕才能响应用户的触摸,它在WindowManagerService发出退出开机动画的时间节点之前 |
sf_stop_bootanim | SF设置service.bootanim.exit属性值为1,标志系统要结束开机动画了 |
wm_boot_animation_done | 开机动画结束,这一步用户能直观感受到开机结束 |
开机流程Trace如下图所示:
1.boot_progress_start
系统进入用户空间,标志着kernel启动完成
/frameworks/base/core/jni/AndroidRuntime.cpp
void AndroidRuntime::start(const char* className, const Vector<String8>& options, bool zygote) { for (size_t i = 0; i < options.size(); ++i) { if (options[i] == startSystemServer) { primary_zygote = true; /* track our progress through the boot sequence */ const int LOG_BOOT_PROGRESS_START = 3000; LOG_EVENT_LONG(LOG_BOOT_PROGRESS_START, ns2ms(systemTime(SYSTEM_TIME_MONOTONIC))); } } }
2.boot_progress_preload_start
Zygote启动
/frameworks/base/core/java/com/android/internal/os/ZygoteInit.java
public static void main(String[] argv){ if(!enableLazyPreload){ bootTimingsTraceLog.traceBegin("ZygotePreload"); EventLog.writeEvent(BOOT_PROGRESS_PRELOAD_START, SystemClock.uptimeMillis()); preload(bootTimingsTraceLog); EventLog.writeEvent(BOOT_PROGRESS_PRELOAD_END, SystemClock.uptimeMillis()); bootTimingsTraceLog.traceEnd(); } }
trace
3.boot_progress_system_run
SystemServer ready,开始启动Android系统服务,如PMS、AMS等
/frameworks/base/services/java/com/android/server/SystemServer.java
private void run() { 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); } }
trace
4.boot_progress_pms_start
PMS开始扫描安装的应用
/frameworks/base/services/core/java/com/android/server/pm/PackageManagerService.java
public PackageManagerService(Injector injector, boolean onlyCore, boolean factoryTest) { LockGuard.installLock(mLock, LockGuard.INDEX_PACKAGES); EventLog.writeEvent(EventLogTags.BOOT_PROGRESS_PMS_START,SystemClock.uptimeMillis() ); }
一般情况下该阶段耗时差异不大 50ms 之内若耗时差异较大
1请确认 BootAnimation 进程是否跑小核心详情见<开机时间checklist>
2耗时主要差异在 read user settings
trace
5.boot_progress_pms_system_scan_start
PMS先行扫描/system目录下的安装包
/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); }
6.boot_progress_pms_data_scan_start
PMS扫描/data目录下的安装包
/frameworks/base/services/core/java/com/android/server/pm/PackageManagerService.java
public PackageManagerService(Injector injector, boolean onlyCore, boolean factoryTest) { 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) { FrameworkStatsLog.write(FrameworkStatsLog.BOOT_TIME_EVENT_DURATION_REPORTED, BOOT_TIME_EVENT_DURATION__EVENT__OTA_PACKAGE_MANAGER_SYSTEM_APP_AVG_SCAN_TIME, systemScanTime / systemPackagesCount); } if (!mOnlyCore) { EventLog.writeEvent(EventLogTags.BOOT_PROGRESS_PMS_DATA_SCAN_START, SystemClock.uptimeMillis()); scanDirTracedLI(sAppInstallDir, 0, scanFlags | SCAN_REQUIRE_KNOWN, 0, packageParser, executorService); } }
7.boot_progress_pms_scan_end
PMS扫描结束
/frameworks/base/services/core/java/com/android/server/pm/PackageManagerService.java
该阶段差异小,可忽略
public PackageManagerService(Injector injector, boolean onlyCore, boolean factoryTest) { 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"); }
8.boot_progress_pms_ready
PMS就绪
/frameworks/base/services/core/java/com/android/server/pm/PackageManagerService.java
public PackageManagerService(Injector injector, boolean onlyCore, boolean factoryTest) { t.traceBegin("write settings"); mSettings.writeLPr(); t.traceEnd(); EventLog.writeEvent(EventLogTags.BOOT_PROGRESS_PMS_READY, SystemClock.uptimeMillis()); }
startWifi R/Q差异,verifyclass比Q多
9.boot_progress_ams_ready
AMS就绪
/frameworks/base/services/core/java/com/android/server/am/ActivityManagerService.java
public void systemReady(final Runnable goingCallback, @NonNull TimingsTraceAndSlog t) { t.traceEnd(); EventLog.writeBootProgressAmsReady(SystemClock.uptimeMillis()); }
trace
10.boot_progress_enable_screen
AMS启动完成后开始激活屏幕,从此以后屏幕才能响应用户的触摸,它在WindowManagerService发出退出开机动画的时间节点之前
/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); } }
11.sf_stop_bootanim
SF设置service.bootanim.exit属性值为1,标志系统要结束开机动画了
/frameworks/native/services/surfaceflinger/SurfaceFlinger.cpp
void SurfaceFlinger::bootFinished() { property_set("service.bootanim.exit", "1"); LOG_EVENT_LONG(LOGTAG_SF_STOP_BOOTANIM, ns2ms(systemTime(SYSTEM_TIME_MONOTONIC))); }
12.wm_boot_animation_done
开机动画结束,这一步用户能直观感受到开机结束
/frameworks/base/services/core/java/com/android/server/wm/WindowManagerService.java
private void performEnableScreen() { EventLogTags.writeWmBootAnimationDone(SystemClock.uptimeMillis()); Trace.asyncTraceEnd(TRACE_TAG_WINDOW_MANAGER, "Stop bootanim"); }
可以将测试机与对比机抓取的此log数据制作成表格,制作成折线图,可以更加直观的观察到耗时异常的流程。
二、开机日志抓取
不同厂商可能暗码进入MTKLog的方式不同,打开MTKLog之后,重启手机,等开机后关闭Log
1、抓取流程:
MTKLog 拨号盘输入*#*#9646633#*#*-->EngineerMode-->log and Debugging-->DebugLoggerUI-->打开mobilelog-->重启-->停止抓取-->拉取adb pull /data/debuglogger
2、分析开机日志
Android的log系统是独立于Linux内核log系统的. Android系统把Log分为了四类,不同的类别记录不同的Log信息,默认通过logcat抓取的是main信息,开机日志主要看event.log跟kernel.log:
Log名称 | 作用 | 获取命令 |
system.log | 低级别的系统调试Log信息,包含CPU信息,大量系统服务输出的信息 | adb logcat –b system |
main.log | 主要的Log信息,大部分应用级别的Log信息都在这里 | adb logcat –b main |
event.log | 系统事件相关的Log信息,包含AMS与WMS输出的应用程序声明周期信息 | adb logcat –b event |
kernel.log | 包含kernel打出的信息,LowMemoryKiller杀进程、内存碎片化或内存不足,mmc驱动异常都可以在这里找到。 | mtk log抓取 |
3、日志地址
抓取成功后有个boot_normal文件夹,开机过程跟开机结束后Log是分开的,在boot过程可以看到里面有相应过程的Log,如下所示:
1.APLog_2023_0814_135856__4
2.boot__normal
4、查看是否第一次开机
persist.sys.device_provisioned开机向导是否完成
persist.sys.device_first_boot是否第一次开机
三、开机trace抓取
1、MTK 平台
mtk 平台抓取开机 trace 可以不改代码,只需要 user root 版本即可
抓取非首次开机信息,需要 root 权限
1. 打开 google systrace: adb shell setprop persist.traced.enable 1
2.打开 mtk systrace工具设置: adb shell setprop persist.vendor.boot_trace 1
3.联网对时,普通重启两次,再打开 开机 log(#80#-其它-重启)
4.锁屏出现后,adb shell atrace --async_stop -z -c -o /data/local/tmp/boot_trace,抓取trace
5.adb pull /data/local/tmp/boot_trace,关闭 log,导出log(/storage/ermulated/0/Android/data/com.oplus.logkit/files/Log 目录下对应时间1og)
注意:需要抓取init阶段的 trace需要修改对应项目的代码修改完代码跟高通抓取一样,需要验证代码之类的
打开抓取的开机trace如下所示:
如以上方式抓取不了,则需要在代码中修改:
2、代码修改
在 frameworks/native/cmds/atrace/atrace.rc 中,更改以下行:
write /sys/kernel/debug/tracing/tracing_on 0 write /sys/kernel/tracing/tracing_on 0
更改为:
#write /sys/kernel/debug/tracing/tracing_on 0 #write /sys/kernel/tracing/tracing_on 0
这将启用跟踪功能(默认处于停用状态)。
在 device.mk 文件中,添加以下行:
PRODUCT_PROPERTY_OVERRIDES += debug.atrace.tags.enableflags=802922 PRODUCT_PROPERTY_OVERRIDES += persist.traced.enable=0
在设备 BoardConfig.mk 文件中,添加以下行:
BOARD_KERNEL_CMDLINE := ... trace_buf_size=64M trace_event=sched_wakeup,sched_switch,sched_blocked_reason,sched_cpu_hotplug
如果是详细的 I/O 分析,还要添加块以及 ext4 和 f2fs。
在设备专属 init.rc 文件中,添加以下行:
on property:sys.boot_completed=1 // This stops tracing on boot complete write /d/tracing/tracing_on 0 write /d/tracing/events/ext4/enable 0 write /d/tracing/events/f2fs/enable 0 write /d/tracing/events/block/enable 0
在设备启动后,提取跟踪记录:
adb root && adb shell atrace --async_stop -z -c -o /data/local/tmp/boot_trace
adb pull /data/local/tmp/boot_trace
$ANDROID_BUILD_TOP/external/chromium-trace/systrace.py --from-file=boot_trace
四、 开机速度优化实践
在Android S升级Android T的过程中,同一个项目的手机,在升级Android T之后,比之前的开机时间大概要多18秒左右。
首先在手机开机之后,查看boot_progress相关日志如下
07-15 04:13:35.244 I/boot_progress_start( 1059): 4040 07-15 04:13:35.934 I/boot_progress_preload_start( 1059): 4730 07-15 04:13:37.255 I/boot_progress_preload_end( 1059): 6051 07-15 04:13:37.636 I/boot_progress_system_run( 2221): 6432 07-15 04:13:38.260 I/boot_progress_pms_start( 2221): 7056 07-15 04:13:38.473 I/boot_progress_pms_system_scan_start( 2221): 7269 07-15 04:13:38.797 I/boot_progress_pms_data_scan_start( 2221): 7593 07-15 04:13:38.803 I/boot_progress_pms_scan_end( 2221): 7599 07-15 04:13:38.894 I/boot_progress_pms_ready( 2221): 7690 07-15 04:13:58.006 I/boot_progress_ams_ready( 2221): 26802 07-15 04:13:59.164 I/boot_progress_enable_screen( 2221): 27960
发现,在boot_progress_pms_ready到boot_progress_ams_ready之间,耗时近20秒,严重超时。
确定了大体的耗时异常点之后,我们抓取boottrace再进行进一步的分析。
由于PMS和AMS服务军运行再SystemServer进程当中,所以我们重点关注SystemServer进程的运行情况。
查看trace文件发现,主要是因为在启动AudioService的时候耗时较长。startService相关的日志也表明了这一点。
可见,启动AudioService耗时15.5秒左右。通过在AudioService相关的代码里面添加log,最终定位到为AudioService驱动在Android T上的问题。转交Audio模块处理之后,开机时间正常。
谷歌官方开机优化资料
https://source.android.com/devices/tech/perf/boot-times
五、开机时间拆解澄清
1、平台信息
项目信息 | 测试机 | 对比机1 | 对比机2 |
Android版本 | 13 | 12 | 13 |
硬件平台 | mt6769 | mt6769 | mt6769 |
内存 | 4+128 | 4+128 | 4+128 |
网络制式 | LTE | WIFI | LTE |
2、测试差异
测试机 | 对比机1 | 差值 | |
开机时间 | 25.294s | 26.243s | -1s |
测试机 | 对比机2 | 差值 | |
开机时间 | 23.57s | 23.97s | -0.4s |
3、开机各阶段时间拆解
prloader->kernel启动阶段 | 测试机(ms) | 对比机1(ms) | 差值(ms) |
prloader | 1173 | 1099 | 74 |
bl2_ext | 1233 | 1041 | 192 |
lk | 1556 | 1555 | 1 |
阶段 | 测试机(ms) | 对比机1(ms) | 差值(ms) |
boot_progress_start | 7504 | 7135 | |
1601 | 1347 | 254 | |
boot_progress_preload_start | 9105 | 8482 | |
1756 | 1597 | 159 | |
boot_progress_preload_end | 10861 | 10079 | |
832 | 1904 | -1072 | |
boot_progress_system_run | 11693 | 11983 | |
1422 | 938 | 484 | |
boot_progress_pms_start | 13115 | 12921 | |
322 | 280 | 42 | |
boot_progress_pms_system_scan_start | 13437 | 13201 | |
702 | 886 | -184 | |
boot_progress_pms_data_scan_start | 14139 | 14087 | |
113 | 268 | -155 | |
boot_progress_pms_scan_end | 14252 | 14355 | |
181 | 227 | --46 | |
boot_progress_pms_ready | 1443 | 14582 | |
2484 | 2597 | -113 | |
boot_progress_ams_ready | 16917 | 17179 | |
3104 | 4268 | -1164 | |
boot_progress_enable_screen | 20021 | 21447 | |
2545 | 2214 | 331 | |
sf_stop_bootanim | 22566 | 23661 | -1095 |
对boot_progress_system_run->boot_progress_pms_start各阶段进一步拆解,各阶段耗时无异常
从拆解表查看,各阶段耗时无异常,Android13相比Android12,Preload classes较多,开机多耗时400ms左右
4、结论:
从分解结果看,测试机优于对比机,各阶段耗时正常,因为平台能力,达不到标准,予以澄清说明。
优化措施汇总:
1.解决开机时mtkcam-devicemgr:initialze一直在后台运行影响开机时间
2.优化lcd初始化时延
六、总结
1.先对开机时间进行拆解,然后根据差异大的过程进行拆解分析
2.MTK平台可以直接看 bootprof文件,查看整个开机时间以及对应做的事件
3.如果是preloader、lk、kernel阶段的耗时需要跟BSP确认
4.折解开机 log在event和 kemel里面获取对应时间
5.可以在Log里面搜索一些关键词(took duration)因为 Android是多进程有些in background即使消耗时间也可能不会影响开机时间