Android內核開發：學會分析系統的啟動log

本文是《Android內核開發》系列的第八篇文章，本文主要關注如何分析Android系統的啟動log，學會通過搜索重要的TAG標簽，找到Android啟動過程中的重要節點。

要學會分析系統的啟動log信息，首先得了解Android系統的啟動過程，建議先閱讀《Android內核開發：圖解Android系統的啟動過程》這篇文章，它詳細介紹了Android系統的啟動過程。其次，你需要知道如何抓取系統啟動log信息，建議閱讀《Android內核開發：如何統計系統啟動時間》這篇文章，它詳細地介紹了如何抓取系統的啟動log信息。

本文在這2篇文章的基礎上，進一步介紹如何深入地分析系統啟動log信息，找出Android啟動啟動過程中每一個部分所消耗的具體時間節點。

首先，我們給出一張比較全面的Android系統啟動圖（來自Embeded Android）：

根據上述Android的啟動框圖，我們可以順序地列出Android系統啟動中涉及的幾個關鍵步驟：

（1） Linux內核的啟動

（2） Init程序啟動，并啟動各個本地服務（如 healthd, debuggerd等）

（3） Zygote進程啟動

（4） Zygote進程初始化工作（preload class/resource）

（5） SystemServer進程啟動，并啟動各個Java服務（如 ActivityManager， PackageManager等 ）

（7） 啟動結束的標志點

如果我們能夠從啟動log信息中找出上述這些關鍵步驟的時間節點，也就可以很清晰地得到Android系統啟動過程中各個模塊消耗的時間了，在做系統啟動優化時，也就知道該去優化哪些耗時的模塊了，同樣，在分析系統啟動bug的時候，也就知道到底哪里出了問題了。

下面，我們以高通的APQ8064開發板(Android 4.4.2)的啟動log信息為例來分析（這些log文件上傳到我的Github上了：https://github.com/Jhuster/AOSP/tree/master/logs/APQ8064），其實各個Android系統都有類似的log輸出，我們只需重點掌握關鍵節點的TAG和分析方法。

1.  配置系統的log輸出

（1） 在內核log信息中打印出時間信息

在Linux kernel源碼樹中執行 make menuconfig，勾選下面的選項：

"Kernel hacking" -> "Show timing information on printks"

（2） 將init進程的詳細log輸出到dmesg文件中

修改/system/core/rootdir/init.rc，把loglevel從3改為7

2.  抓取系統啟動的log信息

前面的文章已經介紹過，Android系統啟動的log分為Linux內核的log和Android Logger系統的log，

抓取的方法如下：

$ adb shell dmesg > dmesg.txt

$ adb logcat -d -v time -b "main"   >  main.txt

$ adb logcat -d -v time -b "system" >  system.txt

$ adb logcat -d -v time -b "events" >  events.txt

3.  分析log信息

（1） Linux內核的啟動

Linux內核啟動的log都位于dmesg.txt文件中，從log文件開始直到出現下面這條消息則標志著Linux內核已經完成了啟動：

"Freeing init memory"

因此，我們從dmesg.txt文件中即可得到APQ8064開發板的Linux內核啟動只用了6.613s，如圖所示：

（2） Init程序啟動，并啟動各個本地服務（如 healthd, debuggerd等）

Init程序的log信息也位于dmesg.txt文件中，我們可以通過檢索“init”找到該程序的打印消息。

通過檢索“init starting”，我們可以找到init進程啟動了哪些本地服務，如：

（3） Zygote進程啟動

zygote進程是在init進程中啟動的，因此，我們從上面init進程的輸出log中，檢索"zygote"就可以找到zygote進程何時啟動的，如圖所示：

（4） Zygote進程初始化工作（preload class/resource）

Zygote進程所輸出的log信息被放到/dev/log/main文件中了，因此，我們需要檢索main.txt得到Zygote的log信息。

由于后續所有的Android應用程序都是從Zygote進程fork出來的，Android系統為了提高應用程序的啟動速度，會在Zygote進程初始化過程中加載一些常用的java class和資源文件到進程的內存中，從而共享常用的class和resourse資源。這個過程我們可以通過檢索"preload"標簽得到這個過程所消耗的時間，如圖所示：

（5） SystemServer進程啟動，并啟動各個Java服務（如 ActivityManager， PackageManager等 ）

Zygote完成了初始化工作后就啟動SystemServer進程了，SystemServer進程的log信息被放到了/dev/log/system文件中了，因此，我們需要檢索system.txt文件得到SystemServer的log信息，如圖所示：

（7） 啟動結束的標志點

《Android內核開發：如何統計系統啟動時間》這篇文章已經詳細地介紹了如何找到啟動結束的時間，這里選取其中一種方法再復述一遍，就是檢索dmesg文件的 "boot_completed" 標志，如圖所示，我們知道了整個系統一共耗時29.913s完成啟動：

4. 小結

關于深度解析Android系統的啟動log信息就介紹到這里了，有任何疑問或者建議歡迎留言或者來信lujun.hust@gmail.com交流，或者關注我的新浪微博 @盧_俊 獲取最新的文章和資訊。