將Android啟動的logcat訊息傳送到串列埠
阿新 • • 發佈：2019-01-02
最近在Android 8.0上做啟動時間優化，對部分service優化後Android無法正常啟動了，此時shell和adb都不可用，service的除錯輸出資訊是通過logcat輸出的，串列埠無法看到。憑經驗猜測原因，除錯起來比較困難。於是想到在Android啟動中將logcat訊息傳送到kmsg，通過串列埠輸出。
將logcat訊息傳送到串列埠還是有意義的，主要有以下兩種需求：
- shell和adb不可用時，需要檢查logcat訊息 （也就是我前面提到的需求）
將kmesg和logcat訊息合併到一起，用於啟動時間優化時進行時間點檢查
這樣做有兩點侷限
- logcat其自身訊息機制的原因，得到的訊息並不是實時的(有待進一步檢驗)
- 將很多logcat訊息發往串列埠低速裝置，大量I/O會影響啟動時間
網上很多地方也提到了通過logcat的"-f"選項將輸出重定向到"/dev/kmsg"
service logcat /system/bin/logcat -f /dev/kmsg
oneshot這裡沒有為service指定class，其預設為”default”，也可以將其指定為其它名稱，這樣就能以"class_start xxx"的方式啟動。
在Android 8.0上預設情況下，由於selinux的原因，只新增上面的service後logcat是無法使用的，啟動中會出現下面的警告：
...
type=1400 audit(1420070407.770 有兩種方式設定selinux:
啟動Android的命令列中指定
"androidboot.selinux=permissive"抑制selinux操作這裡的
permissive選項表示selinux會執行許可權檢查，對於不符合規則的審查會顯示警告資訊，但會授予許可權。適合開發時使用。新增selinux規則，授予logcat操作的許可權
根據規則，在Android的sepolicy指定目錄下新建
logpersist.te檔案，包含以下規則：allow logpersist device:dir { open read }; allow logpersist kmsg_device:chr_file { open append getattr };
當然，logcat輸出的訊息可以通過"-v"選項和過濾器進行設定，例如：
"-v time"生成帶時間戳的資訊service logcat /system/bin/logcat -v time -f /dev/kmsg oneshot輸出的格式如下：
01-01 00:00:06.692 D/Zygote ( 2429): begin preload 01-01 00:00:06.699 I/Zygote ( 2429): Preloading classes... 01-01 00:00:08.136 I/Zygote ( 2429): ...preloaded 3005 classes in 1437ms. 01-01 00:00:08.342 I/Zygote ( 2429): Preloading resources... 01-01 00:00:09.591 I/Zygote ( 2429): ...preloaded 343 resources in 1249ms. 01-01 00:00:09.609 I/Zygote ( 2429): ...preloaded 41 resources in 18ms. 01-01 00:00:09.610 I/Zygote ( 2429): Preloading shared libraries... 01-01 00:00:09.630 D/Zygote ( 2429): end preload使用過濾器篩選資訊
這裡只顯示
Zygote的D級別以上資訊：service logcat /system/bin/logcat -v time -f /dev/kmsg Zygote:D *:S oneshot輸出的資訊如下：
--------- beginning of main --------- beginning of system 01-01 00:00:06.692 D/Zygote ( 2429): begin preload 01-01 00:00:06.699 I/Zygote ( 2429): Preloading classes... 01-01 00:00:08.136 I/Zygote ( 2429): ...preloaded 3005 classes in 1437ms. 01-01 00:00:08.342 I/Zygote ( 2429): Preloading resources... 01-01 00:00:09.591 I/Zygote ( 2429): ...preloaded 343 resources in 1249ms. 01-01 00:00:09.609 I/Zygote ( 2429): ...preloaded 41 resources in 18ms. 01-01 00:00:09.610 I/Zygote ( 2429): Preloading shared libraries... 01-01 00:00:09.630 D/Zygote ( 2429): end preload 01-01 00:00:09.738 I/Zygote ( 2429): System server process 2783 has been created 01-01 00:00:09.740 I/Zygote ( 2429): Accepting command socket connections 01-01 00:00:14.051 I/Zygote ( 2783): Process: zygote socket opened, supported ABIS: armeabi-v7a,armeabi