Android/Linux boot time分析優化

如果需要優化boot time，就需要一個量化的工具來分析每個階段的時間消耗。這種類型的優化特別適合使用基於timeline的圖表，有着明顯的時間順序。要求不但能給出整個流程消耗的時間，還要能對流程進行細化，獲得每個階段的時間。先從總體上查看優化程度，然后逐個查看異常的階段。

分析工具化之后，可以快速的迭代，獲得測試結果的平均值和均方差，已驗證修改的有效性和穩定性。

基於analyze_boot.py分析Android/Linux的kernel boot時間

1.修改HiKey的BoardConfig.mk文件，使能initcall_debug，增加dmesg buffer大小。

diff --git a/hikey/BoardConfig.mk b/hikey/BoardConfig.mk
index 6d17130..64e8789 100644
--- a/hikey/BoardConfig.mk
+++ b/hikey/BoardConfig.mk
@@ -4,7 +4,7 @@ TARGET_BOARD_PLATFORM := hikey
ifeq ($(TARGET_KERNEL_USE_4_1), true)
BOARD_KERNEL_CMDLINE := console=ttyAMA3,115200 androidboot.console=ttyAMA3 androidboot.hardware=hikey firmware_class.path=/system/etc/firmware efi=noru
else
-BOARD_KERNEL_CMDLINE := console=ttyFIQ0 androidboot.console=ttyFIQ0 androidboot.hardware=hikey firmware_class.path=/system/etc/firmware efi=noruntime
+BOARD_KERNEL_CMDLINE := console=ttyFIQ0 androidboot.console=ttyFIQ0 androidboot.hardware=hikey firmware_class.path=/system/etc/firmware efi=noruntime initcall_debug log_buf_len=16M
endif
 
BOARD_SYSTEMIMAGE_PARTITION_SIZE := 1610612736

2.adb shell dmesg保存內核log到dmesg.txt中。

adb shell dmesg > dmesg.txt

3.使用analyze_boot.py分析dmesg.txt，生成從kernel啟動到啟動用戶空間init之間timeline圖表。

./analyze_boot.py -dmesg dmesg.txt
          Host: lenovo-Product
     Test time: 2017-01-09_19:16:25
     Boot time: 1970-01-01_08:00:03
Kernel Version: 4.4.0-31-generic
  Kernel start: 0.000
    init start: 5977.254

4.結果分析。

整個boot情況概況如下：

查看某一個細節的啟動時間，如hisi_thermal_driver_init：

工具代碼分析

 

analyze_boot.py：https://github.com/arnoldlu/suspendresume/blob/master/analyze_boot.py

基於bootchart分析Android boot time

bootchart是一個用於分析系統啟動過程的可視化工具，包括數據收集和可視化兩部分。

在Android中，數據收集功能集成到初始化命令init中了。bootchart的官方信息在：http://www.bootchart.org/

bootchart大致流程是在待測設備（Android等）收集數據（bootchart.tgz），然后使用bootchart工具分析，並生成SVG等可視化圖表，可以使用Inkscape或者Web Browse打開SVG進行分析。

1.安裝分析工具

sudo apt-get install bootchart

2.准備Android bootchart功能

3.觸發bootchart功能

4.收集測試數據

5.生成可視化圖表

 

pybootchartgui

Using bootchart on Android：http://elinux.org/Using_Bootchart_on_Android

Ubuntu bootchart分析

Ubuntu從15.04切換到了systemd作為init啟動。

systemd-analyze作為systemd的相關命令，用於分析系統啟動性能。systemd-analyze還包含一些列子命令。

systemd-analyze time和systemd-analyze一樣用於顯示用戶空間啟動前內核啟動時間和用戶空間啟動時間。

Startup finished in 4.331s (kernel) + 42.551s (userspace) = 46.883s

systemd-analyze blame顯示以時間從長到短的啟動服務列表。

          8.977s NetworkManager-wait-online.service
          8.315s click-system-hooks.service
          7.867s apparmor.service
          7.848s expressvpn.service
          7.737s dev-sda2.device
          7.053s networking.service
          5.517s ModemManager.service
          5.415s grub-common.service
          5.025s irqbalance.service
          4.975s apport.service
          4.834s speech-dispatcher.service
          4.833s ondemand.service
          3.469s lightdm.service
          3.394s NetworkManager.service
          3.143s systemd-udevd.service
          2.624s accounts-daemon.service
          2.412s thermald.service
          2.401s systemd-logind.service
          2.365s rsyslog.service
          1.465s plymouth-start.service
          1.374s media-sda1.mount
          1.344s gpu-manager.service
          1.232s upower.service
          1.129s keyboard-setup.service
          1.125s systemd-tmpfiles-setup-dev.service
          1.118s [e-mail]
          1.056s ssh.service
           970ms console-setup.service
           918ms dev-loop0.device
           898ms polkitd.service
           893ms glances.service
           882ms lm-sensors.service

...

systemd-analyze critical-chain顯示最耗時服務單元。

The time after the unit is active or started is printed after the "@" character.
The time the unit takes to start is printed after the "+" character.

graphical.target @42.534s
└─multi-user.target @42.534s
  └─expressvpn.service @34.685s +7.848s
    └─network-online.target @34.674s
      └─NetworkManager-wait-online.service @25.696s +8.977s
        └─NetworkManager.service @22.287s +3.394s
          └─dbus.service @19.994s
            └─basic.target @19.980s
              └─sockets.target @19.980s
                └─snapd.socket @19.928s +47ms
                  └─sysinit.target @19.912s
                    └─apparmor.service @12.017s +7.867s
                      └─local-fs.target @12.007s
                        └─run-user-1000-gvfs.mount @36.764s
                          └─run-user-1000.mount @29.632s
                            └─local-fs-pre.target @7.292s
                              └─systemd-remount-fs.service @7.136s +119ms
                                └─systemd-journald.socket @2.458s
                                  └─-.slice @2.448s

systemd-analyze plot > systemd.svg

 

 

 

systemd-analyze dot

systemd-analyze dump

systemd-analyze set-log-level

systemd-analyze set-log-target

systemd-analyze verify

/etc/systemd/bootchart.conf

/etc/default/grub

systemd-analyze