1.开机启动日志抓取1.1.bootChartadb shell “touch /data/bootchart/enabled”adb rebootadb pull data/bootcharttar -czf bootchart.tgz header proc_ps.log proc_stat.log proc_diskstats.logjava -jar bootchart.jar bootchart.tgz抓完之后要删掉enable文件不然每次开机都会抓rm -rf /data/bootchart/enabledsearch_replace工具1.2.开机traceadb push boottrace.pbtxt /data/misc/perfetto-configs/boottrace.pbtxt#启用开机追踪adb shell setprop persist.debug.perfetto.boottrace 1#重启设备adb rebootadb pull /data/misc/perfetto-traces/boottrace.perfetto-trace1.3. 普通日志awk ‘match($0, /took to complete: ([0-9])ms/, a) a[1] 300 {print}’ logcat.02 // 查询启动慢的日志adb shell setprop persist.logd.size 8388608 修改log内存大小adb logcat -b all log.txtadb shell getprop persist.logd.size2.分析延迟的日志2.1 KMSG日志init: Wait for日志01-01 00:00:07.172 0 0 W kmsg : 14[ 4.176199][ T841] init: Wait for property ‘vendor.all.modules.ready1’ took 1635ms这里就可以看到vendor.all.modules.ready启动的时候延迟了 1635ms可以重点分析解决。核心日志区分zygote启动前后的日志日志01-01 08:00:25.867 0 0 W kmsg : 14[ 23.658255][ T1] init: processing action (zygote-start) from (/system/etc/init/hw/init.rc:1125)zygote开始启动的时间可以重点分析前面是否有比较慢的程序这里是5秒日志01-01 00:00:59.180 0 0 W kmsg : 14[ 5.236604][ T1] init: processing action (zygote-start) from (/system/etc/init/hw/init.rc:1125)2.2 LOG日志2.2.1.看一下zygote启动后哪些是可以运行的整体关键日志01-01 00:05:19.365840 2005 2005 I boot_progress_start: 551101-01 00:05:21.551305 2005 2005 I boot_progress_preload_start: 769701-01 00:05:22.412232 2005 2005 I boot_progress_preload_end: 855801-01 00:05:22.620375 2775 2775 I boot_progress_system_run: 876601-01 00:05:22.868056 2775 2775 I boot_progress_pms_start: 901401-01 00:05:23.087153 2775 2775 I boot_progress_pms_system_scan_start: 923301-01 00:05:23.853946 2775 2775 I boot_progress_pms_data_scan_start: 999901-01 00:05:23.864085 2775 2775 I boot_progress_pms_scan_end: 1001001-01 00:05:25.866407 2775 2775 I boot_progress_pms_ready: 1201209-21 19:32:57.848022 2775 2775 I boot_progress_ams_ready: 1661909-21 19:32:58.748371 2775 2800 I boot_progress_enable_screen: 1752009-21 19:32:59.724545 2261 2379 I sf_stop_bootanim: 1873409-21 19:32:59.724775 2796 2824 I wm_boot_animation_done: 1873409-21 19:32:59.605635 2796 2831 I am_proc_start: [10,4741,1010130,com.android.car.carlauncher,service,{com.android.car.carlauncher/com.android.car.carlauncher.recents.CarQuickStepService}]IVI整体启动时间是13秒。这是优化后的如果遇到比较慢的可以直接找SystemService的日志这里可以看到电池服务延迟了5秒例如延迟日志电池延迟在等待IHealth hal 01-01 08:00:25.990925 3091 3091 W ServiceManagerCppClient: Waited one second for android.hardware.health.IHealth/default (is service started? Number of threads started in the threadpool: 32. Are binder threads started and available?) 01-01 08:00:26.991420 3091 3091 W ServiceManagerCppClient: Waited one second for android.hardware.health.IHealth/default (is service started? Number of threads started in the threadpool: 32. Are binder threads started and available?) 01-01 08:00:27.991875 3091 3091 W ServiceManagerCppClient: Waited one second for android.hardware.health.IHealth/default (is service started? Number of threads started in the threadpool: 32. Are binder threads started and available?) 01-01 08:00:28.992476 3091 3091 W ServiceManagerCppClient: Waited one second for android.hardware.health.IHealth/default (is service started? Number of threads started in the threadpool: 32. Are binder threads started and available?) 01-01 08:00:29.997573 3091 3091 W ServiceManagerCppClient: Waited one second for android.hardware.health.IHealth/default (is service started? Number of threads started in the threadpool: 32. Are binder threads started and available?) 01-01 08:00:30.347840 3091 3215 I battery_status: [1,1,0,0,] 01-01 08:00:30.353079 3091 3091 I HealthServiceWrapperAidl: health: HealthServiceWrapper listening to AIDL HAL 01-01 08:00:30.353384 3091 3091 I BatteryService: health: Waited 0ms and received the update. 01-01 08:00:30.354052 3091 3091 W SystemServiceManager: Service com.android.server.BatteryService took 5365 ms in onStart 01-01 08:00:30.354372 3091 3091 V SystemServerTiming: StartBatteryService took to complete: 5366ms 01-01 08:00:30.354408 3091 3091 D SystemServerTiming: StartUsageService audio服务启动慢的日志 07-27 03:14:26.230 2464 2464 V SystemServerTiming: StartAudioService took to complete: 25645ms3、开机时间计算方式命令logcat -b all | grep -iE “boot_progress|bootanim”不包含BootLoader的时间为18734ms09-21 19:32:59.724545 2261 2379 I sf_stop_bootanim: 18734找到BootLoader的日志[11308] Shutting Down UEFI Boot Services: 11308 ms Start EBS [11308]最后加上硬件上电的时间其他4 .trace文件内容cat /data/misc/perfetto-configs/boottrace.pbtxt EOF buffers { size\_kb: 65536 fill\_policy: DISCARD } buffers { size\_kb: 4096 fill\_policy: DISCARD } data\_sources { config { name: linux.ftrace ftrace\_config { ftrace\_events: sched/sched\_process\_exit ftrace\_events: sched/sched\_process\_free ftrace\_events: task/task\_newtask ftrace\_events: task/task\_rename ftrace\_events: sched/sched\_switch ftrace\_events: power/suspend\_resume ftrace\_events: sched/sched\_blocked\_reason ftrace\_events: sched/sched\_wakeup ftrace\_events: sched/sched\_wakeup\_new ftrace\_events: sched/sched\_waking ftrace\_events: sched/sched\_process\_exit ftrace\_events: sched/sched\_process\_free ftrace\_events: task/task\_newtask ftrace\_events: task/task\_rename ftrace\_events: power/cpu\_frequency ftrace\_events: power/cpu\_idle ftrace\_events: power/suspend\_resume ftrace\_events: ftrace/print atrace\_categories: adb atrace\_categories: aidl atrace\_categories: am atrace\_categories: audio atrace\_categories: binder\_driver atrace\_categories: binder\_lock atrace\_categories: bionic atrace\_categories: database atrace\_categories: gfx atrace\_categories: hal atrace\_categories: input atrace\_categories: pm atrace\_categories: power atrace\_categories: res atrace\_categories: ss atrace\_categories: view atrace\_categories: wm disable\_generic\_events: true } } } data\_sources { config { name: linux.process\_stats process\_stats\_config { } } } data\_sources { config { name: linux.sys\_stats sys\_stats\_config { stat\_period\_ms: 500 stat\_counters: STAT\_CPU\_TIMES stat\_counters: STAT\_FORK\_COUNT cpufreq\_period\_ms: 500 } } } duration\_ms: 30000 EOF
