前面介绍了分析ANR的基础知识：trace信息和event log，这一章继续介绍ANR分析需要的基础：logcat（main_log）。

logcat包含很多信息，系统预设的一些log信息，还有应用自己添加的一些log信息，这些信息很多，分析ANR很多时候需要分析Logcat信息，比如Looper信息，AnrManager信息，WindowManager信息等等。这些信息会辅助我们分析发生的ANR是哪些原因导致的。

首先是AnrManager信息（下面是我过滤出来的信息，因此会带有行号）：

1
2
3
4
5
6
7
8
9
10
11
12
13
14
15
16
17
18
19
20
21
22
23
24
25
26
27
28
29
30
31
32
33
34
35
36
37
38
39
40
41
42
43
44
45
46
47
48
49
50
51
52
53
54
55
56
57
58
59
60
61
62
63
64
65
66
67
68
69
70
71
72
73
74
75
76
77
78
79
80
81
82
83
84
85
86
87
88
89
90
91
92
93
94
95
96
97
// 行号后面：时间，用户ID（UID，1000通常为系统进程），进程ID（PID），线程ID（TID），日志级别，模块，内容
行  10719: 07-02 10:13:34.102  1000  1674  1674 I AnrManager: startAnrManagerService
行  10721: 07-02 10:13:34.262  1000  1674  1674 I AnrManager: prepareStackTraceFile: 

// 这里开始记录ANR dump信息
行  15333: 07-02 10:13:56.743  1000  1674  2963 I AnrManager: startAnrDump
行  15334: 07-02 10:13:56.743  1000  1674  2963 I AnrManager: isANRFlowSkipped() AnrFlow = 0
行  15335: 07-02 10:13:56.744  1000  1674  2963 I AnrManager: enableTraceLog: false

// ANR事件发生，应用 com.android.launcher 触发 ANR，原因是 Input dispatching timed out 
// (Application does not have a focused window)（输入分发超时，应用程序没有聚焦的窗口）。
// 开始收集ANR调试信息。
行  15336: 07-02 10:13:56.750  1000  1674  2963 I AnrManager: dumpAnrDebugInfo begin: AnrDumpRecord{ Input dispatching timed out (Application does not have a focused window) ProcessRecord{6ce010b 2378:com.android.launcher/u0a63} IsCompleted:false IsCancelled:false }, onlyDumpSelf = false, isSilentANR = false
行  15337: 07-02 10:13:56.750  1000  1674  2963 I AnrManager: dumpAnrDebugInfoLocked: AnrDumpRecord{ Input dispatching timed out (Application does not have a focused window) ProcessRecord{6ce010b 2378:com.android.launcher/u0a63} IsCompleted:false IsCancelled:false }, onlyDumpSelf = false, isSilentANR = false
行  15338: 07-02 10:13:56.758  1000  1674  2964 I AnrManager: /dev/binderfs/binder_logs/timeout_log isn't exist
行  15339: 07-02 10:13:56.790  1000  1674  2963 I AnrManager: dumpStackTraces begin!

// 堆栈信息转储结束。
行  15414: 07-02 10:14:00.878  1000  1674  2963 I AnrManager: dumpStackTraces end!
行  15415: 07-02 10:14:00.882  1000  1674  2963 I AnrManager: ANR in com.android.launcher (com.android.launcher/.uioverrides.QuickstepLauncher), time=41755
行  15416: 07-02 10:14:00.882  1000  1674  2963 I AnrManager: Reason: Input dispatching timed out (Application does not have a focused window)

// 这是系统的负载信息，分别代表1分钟、5分钟和15分钟的系统平均负载。这里表示系统的负载较高，特别是
// 在过去1分钟内。
行  15417: 07-02 10:14:00.882  1000  1674  2963 I AnrManager: Load: 10.76 / 2.71 / 0.91

// 这是从 /proc/pressure/memory 文件中提取的内存压力信息。avg10, avg60, avg300 
// 分别是过去10秒、60秒和300秒的内存压力统计值。这里显示内存压力为0，说明在该时间段内系统并没有
// 内存压力。
行  15418: 07-02 10:14:00.882  1000  1674  2963 I AnrManager: ----- Output from /proc/pressure/memory -----
行  15419: 07-02 10:14:00.882  1000  1674  2963 I AnrManager: some avg10=0.00 avg60=0.00 avg300=0.00 total=0
行  15420: 07-02 10:14:00.882  1000  1674  2963 I AnrManager: full avg10=0.00 avg60=0.00 avg300=0.00 total=0
行  15421: 07-02 10:14:00.882  1000  1674  2963 I AnrManager: ----- End output from /proc/pressure/memory -----
行  15422: 07-02 10:14:00.882  1000  1674  2963 I AnrManager: 
行  15423: 07-02 10:14:00.882  1000  1674  2963 I AnrManager: Android time :[2024-07-02 10:14:00.87] [45.992]

// 这是CPU使用情况报告，显示在过去6.4秒内各个进程的CPU使用率。
行  15424: 07-02 10:14:00.882  1000  1674  2963 I AnrManager: CPU usage from 6404ms to 0ms ago (2024-07-02 10:13:50.238 to 2024-07-02 10:13:56.642):

// 1674/system_server 使用了45%的CPU时间，其中28%用于用户态，17%用于内核态，另外有2881次轻微
// 页面错误（minor faults），9次重大页面错误（major faults）。
行  15425: 07-02 10:14:00.882  1000  1674  2963 I AnrManager:   45% 1674/system_server: 28% user + 17% kernel / faults: 2881 minor 9 major

// 691/surfaceflinger 和其他进程的CPU使用情况也被详细列出
行  15426: 07-02 10:14:00.882  1000  1674  2963 I AnrManager:   36% 691/surfaceflinger: 24% user + 12% kernel / faults: 1263 minor
行  15427: 07-02 10:14:00.882  1000  1674  2963 I AnrManager:   32% 1992/com.android.systemui: 20% user + 12% kernel / faults: 379 minor
行  15428: 07-02 10:14:00.882  1000  1674  2963 I AnrManager:   27% 2790/android.process.acore: 25% user + 1.7% kernel / faults: 3484 minor 31 major
行  15429: 07-02 10:14:00.882  1000  1674  2963 I AnrManager:   21% 676/android.hardware.graphics.composer@2.1-service: 10% user + 10% kernel / faults: 851 minor
行  15430: 07-02 10:14:00.882  1000  1674  2963 I AnrManager:   20% 669/android.hardware.audio.service.mediatek: 9.9% user + 10% kernel
行  15431: 07-02 10:14:00.882  1000  1674  2963 I AnrManager:   12% 688/audioserver: 7.6% user + 4.5% kernel / faults: 119 minor 1 major
行  15432: 07-02 10:14:00.882  1000  1674  2963 I AnrManager:   9% 326/logd: 2% user + 7% kernel / faults: 557 minor
行  15433: 07-02 10:14:00.882  1000  1674  2963 I AnrManager:   7.4% 2126/com.android.networkstack.process: 5.7% user + 1.7% kernel / faults: 1353 minor 7 major
行  15434: 07-02 10:14:00.882  1000  1674  2963 I AnrManager:   4.2% 893/mobile_log_d: 1.8% user + 2.3% kernel / faults: 210 minor
行  15435: 07-02 10:14:00.882  1000  1674  2963 I AnrManager:   3.2% 518/kfps: 0% user + 3.2% kernel
行  15436: 07-02 10:14:00.882  1000  1674  2963 I AnrManager:   2.9% 684/android.hardware.memtrack-service.mediatek: 0.6% user + 2.3% kernel / faults: 824 minor
行  15437: 07-02 10:14:00.882  1000  1674  2963 I AnrManager:   2.6% 2144/com.android.permissioncontroller: 1.7% user + 0.9% kernel / faults: 234 minor
行  15438: 07-02 10:14:00.882  1000  1674  2963 I AnrManager:   2.6% 2293/com.android.phone: 2% user + 0.6% kernel / faults: 1004 minor
...

// 整个系统的CPU使用情况，总计36%的CPU使用率，其中19%是用户态，14%是内核态，IRQ（中断）占1.6%。
行  15506: 07-02 10:14:00.883  1000  1674  2963 I AnrManager: 36% TOTAL: 19% user + 14% kernel + 0% iowait + 1.6% irq + 0.4% softirq

// 这是在短时间内（从10:13:56.791到10:13:57.539之间）更详细的CPU使用情况。
// 1674/system_server 使用了74%的CPU，2963/AnrConsumer占用了43%的CPU（15%用户态，
// 28%内核态），以及其他子线程的使用情况。
行  15507: 07-02 10:14:00.883  1000  1674  2963 I AnrManager: CPU usage from 148ms to 897ms later (2024-07-02 10:13:56.791 to 2024-07-02 10:13:57.539):
行  15508: 07-02 10:14:00.883  1000  1674  2963 I AnrManager:   74% 1674/system_server: 33% user + 41% kernel / faults: 240 minor
行  15509: 07-02 10:14:00.883  1000  1674  2963 I AnrManager:     43% 2963/AnrConsumer: 15% user + 28% kernel
行  15510: 07-02 10:14:00.883  1000  1674  2963 I AnrManager:     5.1% 1711/binder:1674_1: 5.1% user + 0% kernel
行  15511: 07-02 10:14:00.883  1000  1674  2963 I AnrManager:     5.1% 1720/android.display: 0% user + 5.1% kernel
行  15512: 07-02 10:14:00.883  1000  1674  2963 I AnrManager:     2.5% 1718/android.ui: 2.5% user + 0% kernel
行  15513: 07-02 10:14:00.883  1000  1674  2963 I AnrManager:     2.5% 1733/batterystats-ha: 2.5% user + 0% kernel
行  15514: 07-02 10:14:00.883  1000  1674  2963 I AnrManager:     2.5% 1821/InputDispatcher: 2.5% user + 0% kernel
行  15515: 07-02 10:14:00.883  1000  1674  2963 I AnrManager:     2.5% 1822/system_server: 0% user + 2.5% kernel
行  15516: 07-02 10:14:00.883  1000  1674  2963 I AnrManager:     2.5% 1823/InputReader: 2.5% user + 0% kernel
行  15517: 07-02 10:14:00.883  1000  1674  2963 I AnrManager:     2.5% 1901/RenderThread: 2.5% user + 0% kernel
行  15518: 07-02 10:14:00.883  1000  1674  2963 I AnrManager:     2.5% 2332/binder:1674_9: 2.5% user + 0% kernel
行  15519: 07-02 10:14:00.883  1000  1674  2963 I AnrManager:   35% 691/surfaceflinger: 25% user + 10% kernel / faults: 130 minor
行  15520: 07-02 10:14:00.883  1000  1674  2963 I AnrManager:     20% 691/surfaceflinger: 17% user + 3.4% kernel
行  15521: 07-02 10:14:00.883  1000  1674  2963 I AnrManager:     5.1% 1062/surfaceflinger: 5.1% user + 0% kernel
行  15522: 07-02 10:14:00.883  1000  1674  2963 I AnrManager:     5.1% 1785/binder:691_3: 1.7% user + 3.4% kernel
行  15523: 07-02 10:14:00.883  1000  1674  2963 I AnrManager:     3.4% 1053/TimerDispatch: 1.7% user + 1.7% kernel
行  15524: 07-02 10:14:00.883  1000  1674  2963 I AnrManager:     1.7% 772/binder:691_2: 0% user + 1.7% kernel
行  15525: 07-02 10:14:00.883  1000  1674  2963 I AnrManager:     1.7% 1054/app: 0% user + 1.7% kernel
行  15526: 07-02 10:14:00.883  1000  1674  2963 I AnrManager:   47% 1992/com.android.systemui: 27% user + 19% kernel / faults: 6 minor
...

// 这行日志记录了系统整体的CPU使用情况：
//	•	总使用率为32%。
//	•	其中 15% 是用户态（user mode），即应用程序或用户空间的进程使用的CPU时间。
//	•	14% 是内核态（kernel mode），即操作系统内核或设备驱动程序占用的CPU时间。
//	•	1.7% 是硬件中断（irq），表示系统响应外部硬件设备的中断请求所占用的CPU时间。
//	•	0.5% 是软中断（softirq），这通常与处理一些高优先级任务如网络包等相关。
行  15559: 07-02 10:14:00.883  1000  1674  2963 I AnrManager: 32% TOTAL: 15% user + 14% kernel + 1.7% irq + 0.5% softirq
行  15560: 07-02 10:14:00.883  1000  1674  2963 I AnrManager: dumpAnrDebugInfo end: AnrDumpRecord{ Input dispatching timed out (Application does not have a focused window) ProcessRecord{6ce010b 2378:com.android.launcher/u0a63} IsCompleted:true IsCancelled:false }, onlyDumpSelf = false , isSilentANR = false
行  15561: 07-02 10:14:00.884  1000  1674  2963 I AnrManager: addErrorToDropBox app = ProcessRecord{6ce010b 2378:com.android.launcher/u0a63} processName = com.android.launcher activityShortComponentName = com.android.launcher/.uioverrides.QuickstepLauncher parentShortComponentName = com.android.launcher/.uioverrides.QuickstepLauncher parentProcess = ProcessRecord{6ce010b 2378:com.android.launcher/u0a63} annotation = Input dispatching timed out (Application does not have a focused window) mTracesFile = /data/anr/anr_2024-07-02-10-13-57-639
行  15562: 07-02 10:14:00.886  1000  1674  2963 I AnrManager:  controller = null

这里记录了ANR发生前的总的cpu使用以及各个进程的一些状态，通过这些分析有时候可以确定ANR的部分原因。

关于这部分资料其实网上很多，这里不用太详细介绍。

另外logcat还有很多信息，由于我接触的有限，因此也没办法全部列出来，只能把我经常遇到的记录下来。

比如上面提到的一些：

WindowManager & InputManager：

1
2
3
4
5
6
03-12 15:36:42.713  853  895 I WindowManager: **Input event dispatching timed out** sending to application AppWindowToken{f24f3cf token=Token{70fcbf5 ActivityRecord{1a714df u0 com.android.browser/.**BrowserActivity** t30}}}. Reason: Waiting because **no window has focus** but there is a focused application that may eventually add a window when it finishes starting up.

// 刷新window布局
11-08 01:29:45.895444  995 2093 I WindowManager: **Relayout Window**{599852d u0 com.mediatek.camera/com.android.camera.CameraLauncher}: oldVis=4 newVis=0 focusMayChange = true

11-08 01:29:46.034805  995 2087 W InputManager: Input event injection from pid 13134 timed out.

VRI：我们通常来判断是否绘制完成

1
2
11-24 03:37:02.511 28056 28056 D VRI[QuickstepLauncher]: reportDrawFinished
11-24 03:37:02.512  1569  4644 W WindowManager: finishDrawingWindow: Window{b58e8a5 u0 com.android.launcher/com.android.launcher.uioverrides.QuickstepLauncher} mDrawState=HAS_DRAWN

Looper信息：表明处理消息慢，但是应用慢还是系统慢还需要更多信息判断。

1
08-04 11:29:00.170  8261  8456 W Looper  : Slow dispatch took 5117ms TGuardServiceHandler h=com.android.server.am.TGuardService$ServiceHandler c=null m=1

还有一些信息比如timeout关键字的信息，low memory信息，onTrimMemory信息等，都是我们发现问题的关键信息。

这些与前面写的ANR分析流程中的部分流程是对应的，因此要知道这些关键字，不然按照流程分析就没法进行下去了。

基础的信息就介绍这些，后面开始分析一些真实案例，看看还有哪些关键字。