4. ANR日志体系:traces.txt、events.log、kernel log、logcat关键tag
在车载系统ANR问题定位中,日志是还原现场、锁定根因的唯一客观依据。ANR日志体系由四类核心日志构成,每一类日志提供不同维度的信息,组合使用才能完整还原ANR发生的全链路。本章将逐一解析每类日志的生成机制、关键字段、解读方法及在车载场景下的特殊注意事项。
4.1 日志体系总览
四类日志在ANR定位中承担不同角色,其关系与数据流向如下:
核心原则: traces.txt 回答“哪个线程卡住”;events.log 回答“ANR何时发生”;kernel log 回答“底层是否阻塞”;logcat 回答“上层业务与系统状态”。
4.2 traces.txt —— 线程堆栈快照
traces.txt 是ANR定位中最核心的日志文件,由系统在检测到ANR时自动dump所有Java线程的堆栈信息。文件通常位于 /data/anr/traces.txt 或 /data/anr/traces_${pid}.txt。
4.2.1 关键字段解读
| 字段 | 含义 | 定位价值 |
|---|---|---|
pid xxx at yyyy-mm-dd HH:MM:SS | 进程ID与ANR发生时间 | 确认ANR时间窗口 |
"main" prio=5 tid=1 Blocked | 主线程状态(Blocked/Waiting/Sleeping/Runnable) | 主线程是否被阻塞 |
at com.example.MyClass.myMethod(MyClass.java:100) | 当前执行代码行 | 定位卡顿代码位置 |
- waiting to lock <0x12345678> | 等待的对象锁地址 | 锁竞争分析 |
- held by thread "Binder:xxx" | 持有锁的线程 | 锁持有者追踪 |
CPU usage: xx% total, yy% user, zz% kernel | 进程CPU占用率 | 判断是否CPU饥饿 |
4.2.2 车载场景解读要点
- 主线程Blocked: 最常见根因,通常由Binder调用、ContentProvider查询、数据库操作、文件IO导致。
- 主线程在native层: 需结合kernel log分析底层阻塞原因,如HAL服务超时、驱动响应慢。
- 多进程锁链: 车载系统多进程架构下,A进程等待B进程的锁,B进程又在等待C进程,形成锁链。
- CPU usage为0%: 进程被完全挂起,可能因cgroup限制或内核调度问题。
实战技巧: 在traces.txt中搜索
"main" 定位主线程堆栈,再搜索 waiting to lock 追踪锁依赖链。若主线程状态为 Runnable 但CPU usage极低,说明线程在等待CPU时间片,需检查系统负载。
4.3 events.log —— ANR事件记录
events.log 是系统事件日志,记录所有系统级事件,包括ANR、crash、watchdog等。文件位于 /data/system/dropbox/ 或通过 logcat -b events 读取。
4.3.1 关键tag与字段
| tag | 格式示例 | 解读 |
|---|---|---|
am_anr | am_anr:[0,12345,com.example.app,1,Input dispatching timed out] | ANR类型(Input/Service/Provider/Broadcast) |
am_watchdog | am_watchdog:[12345,com.example.system,blocked in monitor] | Watchdog检测到系统服务阻塞 |
am_proc_died | am_proc_died:[12345,com.example.app] | ANR后进程被杀死 |
am_low_memory | am_low_memory:[12345] | 系统内存不足,可能触发LMK |
4.3.2 车载场景解读要点
- Input dispatching timed out: 最常见类型,表示用户触摸或按键事件未在5秒内处理完成。
- Broadcast of Intent timed out: 广播接收器执行超时(10秒),车载场景中常因广播处理中执行了耗时IO操作。
- ContentProvider not responding: Provider查询超时,多进程架构中常见于跨进程数据访问。
- Service timed out: 服务启动或执行超时(20秒),常与后台任务调度相关。
注意: events.log 中的时间戳为系统启动后的相对时间(elapsed realtime),需与logcat中的绝对时间进行换算。换算公式:
绝对时间 = 系统启动时间 + elapsed时间。
4.4 kernel log —— 底层状态追踪
kernel log 记录内核层的事件,包括进程调度、IO操作、内存管理、驱动状态等。通过 dmesg 或 logcat -b kernel 获取。在ANR定位中,kernel log用于分析底层阻塞原因。
4.4.1 关键信息与解读
| 信息类型 | 示例 | 含义 |
|---|---|---|
| D状态进程 | PID 12345 (app_process) D state | 进程处于不可中断睡眠,通常因IO或锁等待 |
| IO等待 | blocked for more than 120 seconds | IO操作超时,可能因存储性能或文件系统问题 |
| 调度延迟 | sched: RT throttling activated | 实时线程被节流,影响UI响应 |
| 内存不足 | Out of memory: kill process 12345 | LMK触发,进程被杀死 |
| 驱动超时 | i2c transfer timeout | 硬件通信超时,影响HAL服务 |
4.4.2 车载场景解读要点
- D状态进程链: 车载系统中,一个D状态的HAL服务进程可能导致上层多个应用进程阻塞。
- IO等待与存储: 车载eMMC/UFS老化后性能下降,或文件系统日志刷写延迟,会导致大量IO等待。
- RT throttling: 实时线程被节流后,UI渲染线程无法获得CPU时间片,导致ANR。
- 驱动超时: 车载外设(摄像头、传感器、CAN总线)驱动超时,会导致HAL服务卡住。
实战技巧: 在kernel log中搜索
blocked for more than 定位长时间阻塞的进程,再搜索 D state 确认进程状态。结合traces.txt中的线程堆栈,可以判断阻塞发生在哪个系统调用上。
4.5 logcat关键tag —— 上层业务与系统状态
logcat 是Android最常用的日志工具,通过 logcat -b main -b system -b events 获取。在ANR定位中,以下tag是必查项:
4.5.1 关键tag清单
| tag | buffer | 关键信息 | 定位价值 |
|---|---|---|---|
ANR in | system | ANR进程名、时间、CPU使用率 | 确认ANR发生及系统负载 |
CPU usage | system | 各进程CPU占用率、用户态/内核态占比 | 分析CPU资源竞争 |
WaitQueue | system | 等待队列长度、等待线程数 | 判断锁竞争或线程池耗尽 |
WindowManager | system | 窗口焦点变化、输入通道状态 | 分析输入事件分发延迟 |
InputDispatcher | system | 输入事件分发状态、超时信息 | 定位输入ANR根因 |
ActivityManager | system | 进程状态变化、广播超时 | 分析组件超时 |
Watchdog | system | 系统服务阻塞信息 | 定位系统级ANR |
4.5.2 ANR in 日志解读
ANR in com.example.car.app (com.example.car.app/.MainActivity)
PID: 12345
Reason: Input dispatching timed out (Waiting to send key event because the focused window has not finished processing all of the input events that were previously delivered to it.)
CPU usage: 12% total, 8% user, 4% kernel
Load: 2.5 / 1.8 / 1.2
CPU usage from 0ms to 5000ms later:
45% 12345/com.example.car.app: 30% user + 15% kernel
20% 6789/com.android.systemui: 15% user + 5% kernel
10% 1111/surfaceflinger: 5% user + 5% kernel
...
解读要点:
- Reason: 明确ANR类型,Input/Service/Provider/Broadcast。
- CPU usage total: 系统整体CPU占用率,若接近100%说明系统过载。
- Load: 系统负载,若远高于CPU核心数,说明存在大量等待任务。
- 进程CPU占用: 分析各进程CPU消耗,定位资源竞争者。
5.5.3 CPU usage 日志解读
CPU usage from 0ms to 5000ms later:
45% 12345/com.example.car.app: 30% user + 15% kernel / faults: 120 minor 5 major
20% 6789/com.android.systemui: 15% user + 5% kernel
10% 1111/surfaceflinger: 5% user + 5% kernel
8% 2222/logd: 3% user + 5% kernel
5% 3333/mediaserver: 3% user + 2% kernel
3% 4444/kworker/u16:0: 0% user + 3% kernel
...
解读要点:
- user vs kernel: kernel占比过高(>30%)说明系统调用频繁,可能涉及IO或驱动。
- faults: major: 主缺页错误(major faults)表示频繁的磁盘IO,严重影响性能。
- kworker: 内核工作线程占用高,说明底层有持续的内核任务。
5.5.4 WaitQueue 日志解读
WaitQueue: [Thread-5] waiting on <0x12345678> (a java.lang.Object)
held by: [Binder:12345_2] waiting on <0x87654321> (a java.lang.Object)
held by: [main] waiting on <0x11223344> (a java.lang.Object)
held by: [Binder:6789_1] (blocked)
解读要点:
- 等待链: 从下往上追踪锁持有链,找到最终持有锁的线程。
- blocked: 最终持有锁的线程处于Blocked状态,说明它也在等待其他资源。
- 死锁检测: 若等待链形成环,则存在死锁。
车载场景特殊关注: 在车载多屏多进程架构中,WaitQueue 经常出现跨进程锁依赖。例如,中控屏应用等待系统UI的锁,系统UI又在等待HAL服务的锁,HAL服务因驱动超时处于D状态。此时需要结合kernel log分析底层阻塞原因。
4.6 四类日志协同定位流程
在实际ANR定位中,四类日志需要按以下流程协同使用:
- 第一步: 从
logcat中搜索ANR in确认ANR发生时间、进程、类型。 - 第二步: 从
events.log中搜索am_anr获取详细ANR事件记录。 - 第三步: 从
traces.txt中定位主线程堆栈,分析阻塞原因。 - 第四步: 从
kernel log中分析底层状态,确认是否存在IO等待、D状态进程、调度延迟。 - 第五步: 从
logcat中搜索CPU usage和WaitQueue分析资源竞争情况。
效率工具: 建议使用
grep -r "ANR in" logcat.txt 快速定位ANR发生点,然后使用 sed -n '/ANR in/,/CPU usage from/p' logcat.txt 提取完整ANR上下文。