Android开机启动性能-初探

逼逼一下

刚接触开机启动这块不到一个月，简单记录下自己经验，因为离职了所以不知道以后还有没有机会做这块，如果有的话会接着更新。

分析手段

log

kernel log

查看启动阶段的kernel log，如果kernel有大量丢失，就注释掉printk.c中如下逻辑，log才不会被过滤。

if (!(devkmsg_log & DEVKMSG_LOG_MASK_ON)) {
	if (!___ratelimit(&user->rs, current->comm))
		return ret;
}

logcat log

logcat | grep -i Timing
getprop | grep -i boottime
logcat -b events|grep boot
logcat -s ServiceManager |grep Waiting
logcat -s SystemServer

bootchart

在system/core/init/README.md中有说明怎么启动，一般是在/data/bootchart/下面创建enabled文件，可能需要在创建start文件并写入需要采集的时间。如果没有要求创建start文件，那么结束时间可能就是在init.rc中指定了，如果需要延长，可以在init.rc中修改。启动完成后会在/data/bootchart/下面生成几个文件。
具体操作和需要的工具可以看我github: Android-Boot-performance

trace

就是systrace，功能比较强大，我是在atrace.rc中启动的，修改了service：

service boottrace /system/bin/atrace -c -b 64000 -z gfx disk sched freq am wm ss -t 10 -o /data/local/tmp/boot_trace
		oneshot

然后在init.rc中启动：start boottrace
atrace 的指令可以在终端查看，atrace -h
开机启动后可以把/data/local/tmp/boot_trace考出来，用”https://ui.perfetto.dev/#!/viewer“来查看。

我的分析过程

kernel log

使能kernel log的输出，然后查看启动的kernel log，查看有没有包含这种“took 523.011ms”的log，如果时间超过50毫秒，就说明是可以优化的。还可以查看init第二阶段启动时间、zygote32和zygote64启动时间是否正常，一般每个阶段init-firststage->setupSelinux->init-secondstage->zygote->systemserver间隔不会太长，比如4/5秒就大概率有问题了。
通过kernel log发现 init: Command ‘mount_all xxx’ took 3496ms and succeeded 指令耗时太久，最后发现是磁盘自检的问题，如果关机突然断电，开机就会做磁盘自检，所以需要在关机的时候等待各个进程退出，走原生的正常关机流程就没有问题。

bootchart

通过bootchart查看整个启动流程和耗时，查看CPU的利用情况，如果有自己的服务，可以考虑提前或者延后启动，来让CPU消耗均匀分部。我发现依赖zygote32只有webview_zygote，可以选择延后启动。还有调整SystemServer中systemui启动顺序，提前了500ms启动。WMS需要等所有画面都准备好才能结束bootanimation，通知AMS解锁用户界面。

SystemServer

SystemServer打印相关log，logcat -s SystemServer，可以看到每个服务启动时间，除了PMS到下一个服务间隔会久点，因为PMS在构造函数里做了包扫描，需要好几秒，其他服务的间隔基本都是很短的1秒以内，如果太长就是有问题了。我自己也发现了一个耗时3秒多的情况，通过打印精确log，发现是系统属性设置的问题。当时我就去看系统属性服务源码，在服务端和客户端打log，发现确实存在几秒的延时。这个问题在我用systrace查看时找到问题的根源。

systrace

通过systrace，可以看到关键进程init、zygote、system server的运行情况，找到此时关键进程uninterrupeible sleeping或者sleeping的情况，然后进行深入分析。
例如：我发现init存在多次uninterrupeible sleeping，总共消耗3秒多；发现systemserver也有3秒多的sleeping，而且此时CPU比较空闲，有可能是在读写文件，不过我觉得不是这样的。
通过log发现是系统属性设置卡的问题，系统属性服务是活在init进程的，对比init和system server进程CPU情况，发现systemserver卡住的时候init进程sleeping了，此时发现init通过subcontex进程来执行一些vendor相关的指令，也是init的子进程（subcontext）名字也是init，不过我看到该进程有几处uninterrupeible sleeping的情况，所以我就再调查该进程在做什么，于是我在action.cpp中的InvokeFunc方法里加了kernel log，打印指令耗时情况，InvokeFunc中有个case ：execute_in_subcontext_就是在子进程init中执行，这样做是为了权限的管理。
子进程init（subcontext）相关的介绍可以参考“https://source.android.com/security/selinux/vendor-init”，最后发现是驱动加载（例如“insmod /vendor/lib/modules/qca_cld3_${ro.vendor.wlan.chip}.ko”）的时候出现问题了，让驱动那边去对应了。最后解决该问题后，系统属性设置也不会卡了。整个系统启动速度提前了2秒多。

PMS

分阶段扫描，具体还没开始做，因为我们这边扫描才1秒多，不是大头。

bootanimation

bootanimation优化，开机动画在检测到退出系统属性的时候会接着把剩下的动画都做完，我统计了Android原生动画的时间，大概在收到退出后会播放5秒才能结束。源码分析：BootAnimation.cpp中playAnimation方法里循环播放，如果检测到退出了并不会马上退出，还会判断part.playUntilComplete看是否立即退出，该参数是从BootAnimation动画视频中的配置文件读取的。也就是在bootanimation.zip中的desc.txt配置文件，如下，第一行三个参数代表长宽和帧数，下面开始c代表需要等待播放完成，把所有c改成p的话就会立即退出了，p旁边的1代表不需要循环播放，0就是循环播放对应partx里面的图片。第三列的数字(例如：第二行第三列的30)代表播放完要等多少帧才到下一个part。最后partx值得是要播放的图片的路径。
所以最简单的就是把所有p改成c。这里修改后我们启动速度提前了5秒。

原生的desc.txt

832 520 30
p 1 30 part0
p 1 0 part1
p 0 0 part2
p 1 30 part3
p 1 0 part4
p 1 0 part5

我修改的desc.txt

832 520 30
c 1 30 part0
c 1 0 part1
c 0 0 part2
c 1 30 part3
c 1 0 part4
c 1 0 part5

earlycon

如果串口驱动卡了，可以考虑下是不是这个问题。
[console] earlycon配置，参考连接“https://blog.csdn.net/ooonebook/article/details/52654191”

logcat

logcat -s ServiceManager ，看有“Waiting for service”相关的log，就说明可能有问题，可以改善。

参考连接

https://source.android.google.cn/devices/tech/perf/boot-times