稳定性性能系列之三——ANR问题排查实战:日志分析与工具实战系统性讲解ANR问题排查的完整方法论,从traces.txt

排查ANR不是看运气,而是有章法的——掌握方法论,你就能像侦探一样,从蛛丝马迹中找到真相。

引言:一次凌晨的紧急排查

凌晨2点,手机突然响了——生产环境ANR率暴涨,用户疯狂投诉。

打开监控平台,ANR数量从平时的个位数飙到了上百。我立刻意识到这不是普通的Bug,而是一次系统性故障。

拿到traces.txt,第一眼看到的是:

"main" prio=5 tid=1 Blocked
  - waiting to lock <0x0a1b2c3d> (a java.lang.Object)

主线程在等锁,但持锁的线程呢?继续往下翻:

"WorkerThread-5" prio=5 tid=15 Native
  at android.os.BinderProxy.transactNative(Native Method)
  - locked <0x0a1b2c3d> (a java.lang.Object)

线程15持锁,并且正在做Binder调用。再看logcat,发现大量的"Binder transaction failed"错误。最终定位到:一个第三方SDK在后台疯狂注册ContentObserver,导致Binder资源耗尽,所有Binder调用都超时,引发大面积ANR。

那个晚上,我深刻体会到:ANR排查不是靠猜,而是靠系统的方法论和工具链。

今天这篇文章,我将把这套方法论分享给你。读完本文,你将学会:

看懂traces.txt的每一个细节
分析logcat日志的时间线和因果关系
使用adb、systrace等工具深入定位
掌握3套完整的排查流程模板
编写自动化分析脚本提升效率

准备好了吗?让我们开始这场ANR排查之旅!

一、ANR排查方法论

在动手之前,我们需要建立一套系统的排查思路。ANR排查不是"头痛医头,脚痛医脚",而是要按照方法论逐步推进。

1.1 排查的核心思路

ANR排查可以概括为**"三看四问"**:

三看:

看现场 - traces.txt(线程堆栈)
看日志 - logcat(上下文信息)
看数据 - CPU、内存、Binder等系统资源

四问:

谁 - 哪个进程/线程出了问题?
在哪 - 在执行哪一行代码?
做什么 - 在执行什么操作?
为什么 - 为什么会卡住?

1.2 排查流程总览

流程说明:

获取日志 - traces.txt + logcat + system日志
定位主线程 - 找到ANR进程的main线程
分析线程状态 - Blocked/Waiting/Native/Runnable
追踪调用链 - 从堆栈回溯到业务代码
找到根因 - 锁竞争/Binder超时/死循环/耗时操作
验证修复 - 复现问题→修复→验证

1.3 排查优先级

不是所有信息都同等重要,按优先级排序:

优先级	信息源	关键内容	为什么重要
🔴 P0	traces.txt	主线程堆栈	直接定位卡顿位置
🟠 P1	traces.txt	持锁线程堆栈	找到锁竞争源头
🟡 P2	logcat	ANR reason	了解触发类型
🟢 P3	logcat	前后日志上下文	还原事件时间线
🔵 P4	system日志	CPU/内存/Binder	系统资源状况

记住这个优先级,可以让你在海量日志中快速找到关键信息。

二、traces.txt完全解读

traces.txt是ANR排查的核心,但很多人看不懂它。让我们从头到尾拆解一遍。

2.1 traces.txt的结构

一个完整的traces.txt包含:

----- pid 12345 at 2024-12-26 10:30:15 -----
Cmd line: com.example.app
Build fingerprint: 'brand/product/device:13/...'

DALVIK THREADS (23):
"main" prio=5 tid=1 Blocked
  | group="main" sCount=1 dsCount=0 flags=1 obj=0x74e04dd8
  | sysTid=12345 nice=-10 cgrp=default sched=0/0 handle=0x7b5a9f49a8
  | state=S schedstat=( 15678923456 8765432109 1234 ) utm=1500 stm=67
  | mutexes= <none>
  at com.example.app.DataManager.getData(DataManager.java:45)
  - waiting to lock <0x0a1b2c3d> (a java.lang.Object) held by thread 15
  at com.example.app.MainActivity.onClick(MainActivity.java:100)
  ...

"WorkerThread-5" prio=5 tid=15 Native
  ...

"GC" daemon prio=5 tid=2 WaitingForGC
  ...

让我们逐行解释:

2.1.1 进程头信息

----- pid 12345 at 2024-12-26 10:30:15 -----

pid: 进程ID
时间戳: ANR发生时刻

Cmd line: com.example.app

包名: 发生ANR的应用

Build fingerprint: 'brand/product/device:13/...'

系统版本: 品牌/产品/设备/Android版本

2.1.2 线程信息头

"main" prio=5 tid=1 Blocked

"main": 线程名称
prio=5: 优先级(1-10,数字越大优先级越高)
tid=1: 线程ID(主线程永远是1)
Blocked: 线程状态(这是最关键的信息!)

2.1.3 线程详细状态

| group="main" sCount=1 dsCount=0 flags=1 obj=0x74e04dd8

group: 线程组
sCount: 挂起计数(>0表示被暂停)
dsCount: 调试器暂停计数
obj: 线程对象地址

| sysTid=12345 nice=-10 cgrp=default sched=0/0 handle=0x7b5a9f49a8

sysTid: 系统线程ID(对应Linux层的tid)
nice: 进程优先级(-20到19,越小优先级越高)
cgrp: cgroup分组
sched: 调度策略
handle: 线程句柄

| state=S schedstat=( 15678923456 8765432109 1234 ) utm=1500 stm=67

state: Linux线程状态
- R (Running): 正在运行
- S (Sleeping): 可中断睡眠
- D (Disk sleep): 不可中断睡眠(通常是IO等待)
- Z (Zombie): 僵尸进程
- T (Stopped): 停止
schedstat: 调度统计(运行时间/等待时间/时间片次数)
utm: 用户态CPU时间(单位:jiffies)
stm: 内核态CPU时间(单位:jiffies)

2.1.4 互斥锁信息

| mutexes= <none>

当前线程持有的互斥锁列表
<none> 表示没有持有锁

2.2 线程状态详解

traces.txt中最关键的就是线程状态,它直接告诉你线程在干什么:

状态	含义	典型原因	排查方向
Runnable	正在运行	死循环、大量计算	看代码逻辑
Blocked	等待获取锁	锁竞争	找持锁线程
Waiting	等待notify	wait()调用	看是否有notify
TimedWaiting	限时等待	sleep()、wait(timeout)	看超时设置
Native	执行Native代码	JNI调用、Binder调用	看Native堆栈
Suspended	被挂起	GC、调试器	看GC日志

重点记忆:

Blocked → 锁问题 → 找持锁线程
Native → Binder/JNI → 看系统日志
Runnable → 代码逻辑 → 看方法耗时

2.3 堆栈解读技巧

技巧1:从下往上读

堆栈是倒序的,最上面是当前正在执行的代码,最下面是调用起点。

at com.example.app.DataManager.getData(DataManager.java:45)  ← 当前卡在这里
  - waiting to lock <0x0a1b2c3d>                            ← 原因:在等锁
at com.example.app.MainActivity.onClick(MainActivity.java:100) ← 谁调用的
at android.view.View.performClick(View.java:7125)            ← 再往前
...
at android.app.ActivityThread.main(ActivityThread.java:7356)  ← 入口点

排查思路:

看最上面 → 卡在哪一行代码
看waiting/locked → 为什么卡住
向下追溯 → 谁调用的,业务逻辑是什么

技巧2:识别关键信息

- waiting to lock <0x0a1b2c3d> (a java.lang.Object) held by thread 15

这一行信息量巨大:

waiting to lock: 正在等待获取锁
<0x0a1b2c3d>: 锁对象的内存地址
held by thread 15: 锁被线程15持有

**下一步:**马上去找thread 15的堆栈,看它在干什么!

技巧3:识别Binder调用

at android.os.BinderProxy.transactNative(Native Method)
at android.os.BinderProxy.transact(Binder.java:1129)

看到这两行,说明正在进行Binder IPC调用。

常见Binder调用场景:

ContentProvider查询
ActivityManagerService交互
WindowManagerService交互
系统服务调用

排查方向:

看调用的是哪个系统服务
检查系统服务是否正常
看system日志有无异常

2.4 实战:读懂一个完整的线程堆栈

让我们来看一个真实的例子:

"main" prio=5 tid=1 Blocked
  | group="main" sCount=1 dsCount=0 flags=1 obj=0x74e04dd8
  | sysTid=12345 nice=-10 cgrp=default sched=0/0 handle=0x7b5a9f49a8
  | state=S schedstat=( 15678923456 8765432109 1234 ) utm=1500 stm=67
  | mutexes= <none>
  at com.example.app.DataManager.getData(DataManager.java:45)
  - waiting to lock <0x0a1b2c3d> (a java.lang.Object) held by thread 15
  at com.example.app.MainActivity.onClick(MainActivity.java:100)
  at android.view.View.performClick(View.java:7125)
  at android.view.View.performClickInternal(View.java:7102)
  at android.view.View.access$3500(View.java:801)
  at android.view.View$PerformClick.run(View.java:27851)
  at android.os.Handler.handleCallback(Handler.java:883)
  at android.os.Handler.dispatchMessage(Handler.java:100)
  at android.os.Looper.loop(Looper.java:214)
  at android.app.ActivityThread.main(ActivityThread.java:7356)

分析步骤:

线程名和状态 - "main" + "Blocked" → 主线程被阻塞了
优先级和调度 - nice=-10 → 高优先级线程,系统应该优先调度
CPU时间 - utm=1500, stm=67 → 用户态1500 jiffies,内核态67 jiffies
- 1 jiffy ≈ 10ms(视系统而定)
- 用户态:15秒,内核态:0.67秒
- 说明:这个线程执行了一段时间,不是刚启动就卡住
堆栈最上层 - DataManager.getData():45 → 卡在第45行
原因 - waiting to lock <0x0a1b2c3d> held by thread 15
- 在等待一个锁
- 这个锁被线程15持有
业务逻辑 - onClick() → performClick() → Handler → Looper
- 用户点击按钮
- 事件通过Handler传递到主线程
- 调用onClick()
- 调用DataManager.getData()
- 被锁阻塞

结论:

问题: 主线程在等锁
锁持有者: thread 15
下一步: 去看thread 15的堆栈,找到持锁原因

三、logcat日志分析

traces.txt告诉你"卡在哪",logcat告诉你"为什么卡"。

3.1 ANR日志的关键标记

在logcat中搜索这些关键字:

# 1. ANR触发日志
adb logcat | grep "ANR in"

# 输出示例:
12-26 10:30:15.234  1234  1250 E ActivityManager: ANR in com.example.app (com.example.app/.MainActivity)
12-26 10:30:15.234  1234  1250 E ActivityManager: PID: 12345
12-26 10:30:15.234  1234  1250 E ActivityManager: Reason: Input dispatching timed out (Waiting to send non-key event because the touched window has not finished processing certain input events that were delivered to it over 500.0ms ago.  Wait queue length: 1.)

关键信息:

ANR in: 包名和组件名
PID: 进程ID(对应traces.txt)
Reason: ANR原因(Input/Broadcast/Service)

# 2. traces文件生成
adb logcat | grep "dumpStackTraces"

# 输出示例:
12-26 10:30:15.456  1234  1250 I ActivityManager: dumpStackTraces pids=[12345, 1234] nativePids=null

3.2 构建事件时间线

ANR不是孤立事件,需要看前因后果:

时间线分析步骤:

向前看30秒 - 找触发事件
找ANR时刻 - 确定卡顿点
向后看10秒 - 看系统响应

示例:

10:29:45.123  用户点击按钮
10:29:45.145  onClick()被调用
10:29:45.167  开始执行业务逻辑
10:29:50.000  InputDispatcher检测到超时
10:30:15.234  ActivityManager触发ANR
10:30:15.456  开始dump traces
10:30:18.789  traces.txt写入完成
10:30:20.123  弹出ANR Dialog

3.3 关键日志模式

模式1:Binder超时

12-26 10:30:10.123  12345 12360 W Binder  : Outgoing transactions from this process must be FLAG_ONEWAY
12-26 10:30:14.567  12345 12360 E Binder  : Binder call failed.
12-26 10:30:15.234  1234  1250 E ActivityManager: ANR in com.example.app

特征:

Binder相关错误在ANR前出现
通常是"Binder call failed"或"transaction failed"

可能原因:

Binder资源耗尽
目标服务进程死亡
Binder数据过大

模式2:GC导致

12-26 10:30:13.123  12345 12345 I art     : Background concurrent mark sweep GC freed 123456(8MB) AllocSpace objects, 45(1MB) LOS objects, 35% free, 47MB/72MB, paused 1.234ms total 5.678s
12-26 10:30:14.890  12345 12345 I art     : Background concurrent mark sweep GC freed ...
12-26 10:30:15.234  1234  1250 E ActivityManager: ANR in com.example.app

特征:

ANR前有多次GC日志
GC paused时间较长
频繁GC(可能内存泄漏)

模式3:IO阻塞

12-26 10:30:10.000  12345 12360 D DatabaseHelper: query() database=/data/data/com.example.app/databases/large.db
12-26 10:30:14.999  12345 12360 D DatabaseHelper: query() returned 50000 rows
12-26 10:30:15.234  1234  1250 E ActivityManager: ANR in com.example.app

特征:

IO操作耗时过长
数据库查询返回大量数据

3.4 logcat过滤技巧

按时间过滤:

# 提取ANR前后1分钟的日志
adb logcat -t '12-26 10:29:15.000' -T '12-26 10:31:15.000'

按进程过滤:

# 只看指定PID的日志
adb logcat --pid=12345

按关键字过滤:

# 组合过滤
adb logcat -s ActivityManager:I Binder:W art:I | grep -E "ANR|Binder|GC"

保存到文件:

adb logcat -d > anr_logcat.txt

四、工具实战

工欲善其事,必先利其器。这一节介绍ANR排查的实用工具。

4.1 adb命令合集

4.1.1 获取traces文件

# 方法1:直接pull
adb pull /data/anr/traces.txt ./

# 方法2:通过bugreport(推荐,信息更全)
adb bugreport bugreport.zip
# 解压后在FS/data/anr/目录下

# 方法3:手动触发ANR并获取
adb shell kill -3 <pid>
adb pull /data/anr/traces.txt ./

4.1.2 实时监控ANR

# 监控ANR触发
adb logcat -s ActivityManager:* | grep --line-buffered "ANR"

# 自动保存traces(需要root)
adb shell "while true; do
  inotifywait -e modify /data/anr/traces.txt && \
  cp /data/anr/traces.txt /sdcard/anr_$(date +%Y%m%d_%H%M%S).txt
done"

4.1.3 查看系统状态

# CPU使用情况
adb shell top -n 1 -m 10

# 内存使用
adb shell dumpsys meminfo <package_name>

# Binder状态
adb shell cat /sys/kernel/debug/binder/stats
adb shell cat /sys/kernel/debug/binder/transactions

# 进程信息
adb shell ps -A | grep <package_name>

4.2 Systrace分析

Systrace可以看到ANR发生时的系统调用情况。

4.2.1 抓取Systrace

# Android 9+使用Perfetto
adb shell perfetto \
  -c - --txt \
  -o /data/misc/perfetto-traces/trace \
<<EOF
buffers: {
  size_kb: 65536
}
data_sources: {
  config {
    name: "linux.process_stats"
  }
}
duration_ms: 30000
EOF

# 传统Systrace方法
python systrace.py --time=30 -o trace.html \
  sched freq idle am wm gfx view binder_driver hal dalvik input res

4.2.2 分析Systrace

关键点:

找到ANR时间点 - 搜索"deliverInputEvent"或应用包名
看主线程状态 - 是Sleeping还是Runnable
看锁等待 - 查找"lock contention"
看Binder调用 - 查找"binder transaction"

4.3 自动化分析脚本

我写了一个Python脚本来自动分析traces.txt:

#!/usr/bin/env python3
# anr_analyzer.py

import re
import sys
from collections import defaultdict

class ANRAnalyzer:
    def __init__(self, traces_file):
        self.traces_file = traces_file
        self.threads = {}
        self.locks = defaultdict(list)

    def parse(self):
        """解析traces文件"""
        with open(self.traces_file, 'r', encoding='utf-8', errors='ignore') as f:
            content = f.read()

        # 提取进程信息
        pid_match = re.search(r'----- pid (\d+) at (.+?) -----', content)
        if pid_match:
            self.pid = pid_match.group(1)
            self.timestamp = pid_match.group(2)
            print(f"[进程信息] PID: {self.pid}, 时间: {self.timestamp}")

        # 提取所有线程
        thread_blocks = re.split(r'\n"', content)
        for block in thread_blocks[1:]:  # 跳过第一个(进程头)
            self._parse_thread('"' + block)

    def _parse_thread(self, block):
        """解析单个线程"""
        # 提取线程名和状态
        match = re.search(r'"(.+?)" .+ tid=(\d+) (\w+)', block)
        if not match:
            return

        thread_name = match.group(1)
        tid = match.group(2)
        state = match.group(3)

        # 提取堆栈
        stack_lines = []
        for line in block.split('\n'):
            if line.strip().startswith('at '):
                stack_lines.append(line.strip())

        # 提取锁信息
        lock_match = re.search(r'waiting to lock <(0x[0-9a-f]+)>.+held by thread (\d+)', block)
        if lock_match:
            lock_addr = lock_match.group(1)
            holder_tid = lock_match.group(2)
            self.locks[lock_addr].append({
                'waiter': tid,
                'waiter_name': thread_name,
                'holder': holder_tid
            })

        # 保存线程信息
        self.threads[tid] = {
            'name': thread_name,
            'state': state,
            'stack': stack_lines
        }

    def find_main_thread(self):
        """找到主线程"""
        for tid, info in self.threads.items():
            if info['name'] == 'main':
                return tid, info
        return None, None

    def analyze_deadlock(self):
        """分析死锁"""
        print("\n[锁分析]")
        if not self.locks:
            print("  未发现锁等待")
            return

        for lock_addr, waiters in self.locks.items():
            print(f"\n  锁地址: {lock_addr}")
            for waiter in waiters:
                print(f"    等待线程: tid={waiter['waiter']} ({waiter['waiter_name']})")
                holder_tid = waiter['holder']
                if holder_tid in self.threads:
                    holder = self.threads[holder_tid]
                    print(f"    持有线程: tid={holder_tid} ({holder['name']}) - {holder['state']}")
                    if holder['stack']:
                        print(f"      堆栈: {holder['stack'][0]}")

    def analyze_main_thread(self):
        """分析主线程"""
        tid, info = self.find_main_thread()
        if not info:
            print("\n[主线程] 未找到")
            return

        print(f"\n[主线程分析]")
        print(f"  状态: {info['state']}")

        if info['stack']:
            print(f"  堆栈顶部:")
            for i, line in enumerate(info['stack'][:5]):
                print(f"    {i+1}. {line}")

        # 判断问题类型
        if info['state'] == 'Blocked':
            print("  ⚠️ 主线程被阻塞,可能是锁竞争问题")
        elif info['state'] == 'Native':
            print("  ⚠️ 主线程在执行Native代码,可能是JNI或Binder问题")
        elif info['state'] == 'Runnable':
            print("  ⚠️ 主线程在运行,可能是死循环或大量计算")

    def generate_report(self):
        """生成分析报告"""
        print("\n" + "="*60)
        print("ANR分析报告")
        print("="*60)

        self.analyze_main_thread()
        self.analyze_deadlock()

        print("\n[建议]")
        tid, info = self.find_main_thread()
        if info:
            if info['state'] == 'Blocked':
                print("  1. 检查是否有锁竞争")
                print("  2. 找到持锁线程,分析其耗时操作")
                print("  3. 考虑减少锁粒度或改用读写锁")
            elif info['state'] == 'Native':
                print("  1. 检查Binder调用是否超时")
                print("  2. 检查JNI调用是否有阻塞")
                print("  3. 查看system日志确认系统服务状态")
            elif info['state'] == 'Runnable':
                print("  1. 检查是否有死循环")
                print("  2. 检查是否有大量计算")
                print("  3. 使用Profiler分析方法耗时")

if __name__ == '__main__':
    if len(sys.argv) != 2:
        print("用法: python3 anr_analyzer.py <traces.txt文件路径>")
        sys.exit(1)

    analyzer = ANRAnalyzer(sys.argv[1])
    analyzer.parse()
    analyzer.generate_report()

使用方法:

python3 anr_analyzer.py traces.txt

输出示例:

[进程信息] PID: 12345, 时间: 2024-12-26 10:30:15

[主线程分析]
  状态: Blocked
  堆栈顶部:
    1. at com.example.app.DataManager.getData(DataManager.java:45)
    2. at com.example.app.MainActivity.onClick(MainActivity.java:100)
  ⚠️ 主线程被阻塞,可能是锁竞争问题

[锁分析]
  锁地址: 0x0a1b2c3d
    等待线程: tid=1 (main)
    持有线程: tid=15 (WorkerThread-5) - Native
      堆栈: at android.os.BinderProxy.transactNative(Native Method)

[建议]
  1. 检查是否有锁竞争
  2. 找到持锁线程,分析其耗时操作
  3. 考虑减少锁粒度或改用读写锁

五、完整排查案例

理论讲完了,让我们通过3个真实案例,手把手演示完整的排查流程。

5.1 案例1:主线程等锁导致ANR

场景: 用户点击按钮后ANR

步骤1:看traces.txt

"main" prio=5 tid=1 Blocked
  at com.example.app.CacheManager.get(CacheManager.java:56)
  - waiting to lock <0x0abc1234> (a java.util.HashMap) held by thread 12
  at com.example.app.DataLoader.loadData(DataLoader.java:89)
  at com.example.app.MainActivity$1.onClick(MainActivity.java:45)

分析:

主线程Blocked
等待HashMap的锁
锁被thread 12持有

步骤2:找thread 12

"AsyncTask #1" prio=5 tid=12 Runnable
  at java.util.HashMap.put(HashMap.java:1234)
  - locked <0x0abc1234> (a java.util.HashMap)
  at com.example.app.CacheManager.put(CacheManager.java:78)
  at com.example.app.DataSyncTask.doInBackground(DataSyncTask.java:123)

分析:

AsyncTask持有HashMap锁
正在执行put操作

步骤3:看代码

// ❌ 问题代码
public class CacheManager {
    private HashMap<String, Object> mCache = new HashMap<>();

    public synchronized Object get(String key) {  // 主线程调用
        return mCache.get(key);
    }

    public synchronized void put(String key, Object value) {  // 后台线程调用
        // 如果后台线程执行时间长,主线程就会一直等
        mCache.put(key, value);
        saveToDatabase(value);  // 耗时操作!
    }
}

根因: 后台线程持锁做耗时IO操作,主线程等不到锁

解决方案:

// ✅ 修复后
public class CacheManager {
    private final ConcurrentHashMap<String, Object> mCache = new ConcurrentHashMap<>();

    public Object get(String key) {
        return mCache.get(key);  // 无锁读
    }

    public void put(String key, Object value) {
        mCache.put(key, value);  // 先更新缓存

        // 耗时操作异步执行
        executor.execute(() -> {
            saveToDatabase(value);
        });
    }
}

排查用时: 5分钟

5.2 案例2:Binder资源耗尽

场景: 应用在后台,突然收到大量ANR

步骤1:看logcat

12-26 10:30:10.123  12345 12360 E Binder  : Binder call failed.
12-26 10:30:10.456  12345 12370 E Binder  : Binder call failed.
12-26 10:30:11.789  12345 12380 E Binder  : Binder call failed.
...
12-26 10:30:15.234  1234  1250 E ActivityManager: ANR in com.example.app

分析: Binder调用大量失败

步骤2:检查Binder状态

adb shell cat /sys/kernel/debug/binder/stats

# 输出
binder stats:
  BC_TRANSACTION: 5000
  BC_REPLY: 4500
  BC_FREE_BUFFER: 4500
  ...
  active transactions: 500  ← 异常!正常应该接近0
  ready threads: 0          ← 异常!没有可用线程

分析: Binder事务堆积,线程池耗尽

步骤3:看traces.txt找根因

"Binder:12345_1" prio=5 tid=20 Native
  at android.os.BinderProxy.transactNative(Native Method)
  at android.content.IContentProvider$Stub$Proxy.registerContentObserver(...)

"Binder:12345_2" prio=5 tid=21 Native
  at android.os.BinderProxy.transactNative(Native Method)
  at android.content.IContentProvider$Stub$Proxy.registerContentObserver(...)

... (重复多次)

分析: 大量线程在注册ContentObserver

步骤4:定位业务代码

// ❌ 问题代码
public class SettingsMonitor {
    public void startMonitoring() {
        // 每个设置项都注册一个Observer
        for (String key : ALL_SETTINGS_KEYS) {  // 有500个key!
            getContentResolver().registerContentObserver(
                Settings.System.getUriFor(key),
                true,
                new ContentObserver(mHandler) {
                    @Override
                    public void onChange(boolean selfChange) {
                        handleChange(key);
                    }
                }
            );
        }
    }
}

根因: 一次性注册500个ContentObserver,耗尽Binder资源

解决方案:

// ✅ 修复后
public class SettingsMonitor {
    public void startMonitoring() {
        // 只监听Settings.System整体变化
        getContentResolver().registerContentObserver(
            Settings.System.CONTENT_URI,  // 监听整个Settings.System
            true,  // notifyForDescendants=true
            new ContentObserver(mHandler) {
                @Override
                public void onChange(boolean selfChange, Uri uri) {
                    String key = uri.getLastPathSegment();
                    if (mInterestedKeys.contains(key)) {
                        handleChange(key);
                    }
                }
            }
        );
    }
}

排查用时: 15分钟

5.3 案例3:主线程死循环

场景: 应用打开后立即ANR

步骤1:看traces.txt

"main" prio=5 tid=1 Runnable
  | state=R schedstat=( 5000000000 0 1 ) utm=5000 stm=0
  at com.example.app.StringUtils.validate(StringUtils.java:123)
  at com.example.app.InputValidator.check(InputValidator.java:45)
  at com.example.app.MainActivity.onCreate(MainActivity.java:67)

分析:

主线程Runnable (正在运行)
utm=5000 (用户态CPU时间5秒,很高!)
卡在StringUtils.validate()

步骤2:看CPU使用

adb shell top -n 1 -m 10

PID   USER     CPU%  ...
12345 u0_a123  98%   ...  com.example.app  ← 占用98% CPU!

步骤3:看代码

// ❌ 问题代码
public class StringUtils {
    public static boolean validate(String input) {
        // 正则表达式灾难性回溯!
        String regex = "(a+)+b";
        return input.matches(regex);

        // 当input = "aaaaaaaaaaaaaaaaaaaaaa"(没有b)时
        // 正则引擎会尝试所有可能的匹配组合
        // 时间复杂度O(2^n),输入22个a就卡5秒
    }
}

根因: 正则表达式灾难性回溯导致死循环

解决方案:

// ✅ 修复后
public class StringUtils {
    public static boolean validate(String input) {
        // 方法1:优化正则
        String regex = "a+b";  // 去掉嵌套量词

        // 方法2:限制输入长度
        if (input.length() > 100) {
            return false;
        }

        // 方法3:使用Pattern.matcher()并设置超时
        Pattern pattern = Pattern.compile(regex);
        Matcher matcher = pattern.matcher(input);

        try {
            // 设置匹配超时(需要Java 8+)
            return matcher.matches();
        } catch (Exception e) {
            return false;
        }
    }
}

排查用时: 10分钟

六、排查工作流总结

经过前面的学习,让我们总结一套标准化的排查流程:

6.1 标准排查清单

6.2 常见ANR类型速查表

线程状态	常见原因	排查重点	解决方向
Blocked	锁竞争	找持锁线程,看在干什么	减少锁粒度/改用无锁结构
Native (Binder)	Binder超时	看system日志,检查服务	检查Binder资源/服务状态
Native (JNI)	JNI阻塞	看Native堆栈	优化JNI调用/异步化
Runnable	死循环/大量计算	看CPU占用,Profiler分析	优化算法/异步执行
Waiting	wait()无notify	看等待条件	检查notify逻辑
TimedWaiting	sleep()过长	看sleep时间	减少sleep时间

6.3 排查陷阱与技巧

陷阱1:只看主线程

❌ 只关注main线程堆栈
✅ 完整分析所有线程,找出关联

陷阱2:忽略时间线

❌ 孤立看ANR那一刻
✅ 结合logcat看前因后果

陷阱3:过度解读traces

❌ traces显示在A方法,就认为是A的问题
✅ A可能只是受害者,真正原因在其他线程

技巧1:对比多次traces

连续抓取多次traces,看线程状态变化
如果状态不变,说明真的卡住了
如果状态在变,可能只是偶发性卡顿

技巧2:使用二分法

如果堆栈很长,用二分法定位
在堆栈中间加日志,看能否执行到
逐步缩小范围

技巧3:复现优先

能稳定复现的ANR,排查效率10倍
花时间找复现路径,值得!

七、总结

7.1 核心要点回顾

本文我们系统学习了ANR排查的完整方法论:

1. 方法论框架

"三看四问"思维模型
优先级排序:traces.txt > logcat > 系统日志
标准化排查流程

2. traces.txt解读

线程状态是最关键的信息
Blocked → 找持锁线程
Native → 看Binder调用
Runnable → 查CPU和代码逻辑

3. logcat分析

构建事件时间线
识别日志模式(Binder/GC/IO)
关联前因后果

4. 工具使用

adb命令获取日志和系统状态
Systrace/Perfetto可视化分析
自动化脚本提升效率

5. 实战经验

通过3个案例掌握实际操作
避免常见陷阱
复现优先原则

7.2 进阶学习路径

掌握了本文内容后,你可以继续深入学习:

Native Crash分析 - 如果traces.txt显示Native方法,需要掌握Native Crash的排查
Perfetto深度使用 - 学习Perfetto的高级功能,分析系统调用和性能瓶颈
监控系统搭建 - 构建完整的ANR监控和告警体系
性能优化 - ANR排查只是第一步,还需要系统性能优化

7.3 常见问题FAQ

Q1: traces.txt找不到怎么办?

A: traces.txt可能在这些位置:

/data/anr/traces.txt (主要位置)
/data/system/dropbox/ (以data_app_anr@xxx.txt.gz格式)
通过adb bugreport获取

如果确实没有:

检查ANR是否真的触发了(看logcat)
检查权限(需要root或debuggable应用)
使用kill -3 <pid>手动触发dump

Q2: 如何复现ANR?

A: 复现技巧:

压力测试 - 使用monkey或UIAutomator快速点击
人为制造 - 在主线程sleep(10000)
环境模拟 - 使用慢速手机/低内存设备
日志分析 - 通过logcat找到触发操作

Q3: 线上ANR率多少算正常?

A: 行业标准:

优秀: < 0.1% (千分之一)
良好: 0.1% - 0.5%
需要优化: 0.5% - 1%
严重: > 1%

Q4: 第三方SDK导致ANR怎么办?

A: 处理策略:

隔离 - 将SDK调用放在独立进程
异步化 - SDK初始化放到后台线程
超时保护 - 给SDK调用加timeout
降级 - 准备SDK失败时的降级方案
反馈 - 联系SDK提供商修复

7.4 下一篇预告

在下一篇文章《异常日志机制与进程冻结》中,我们将学习:

Android的异常日志体系(logcat/EventLog/DropBox)
tombstone日志的生成和分析
进程冻结(Freeze)机制
如何通过日志追踪问题根源

这些知识将帮助你构建完整的稳定性监控体系。

如果这篇文章对你有帮助,欢迎分享给更多人!有问题也欢迎留言讨论。

记住:排查ANR不是靠运气,而是靠方法论。掌握了方法,你就是那个能在凌晨2点救火的英雄! 🔥

作者简介: 多年Android系统开发经验,专注于系统稳定性与性能优化领域。欢迎关注本系列,一起深入Android系统的精彩世界!

稳定性性能系列之三——ANR问题排查实战:日志分析与工具实战

引言:一次凌晨的紧急排查

一、ANR排查方法论

1.1 排查的核心思路

1.2 排查流程总览

1.3 排查优先级

二、traces.txt完全解读

2.1 traces.txt的结构

2.1.1 进程头信息

2.1.2 线程信息头

2.1.3 线程详细状态

2.1.4 互斥锁信息

2.2 线程状态详解

2.3 堆栈解读技巧

技巧1:从下往上读

技巧2:识别关键信息

技巧3:识别Binder调用

2.4 实战:读懂一个完整的线程堆栈

三、logcat日志分析

3.1 ANR日志的关键标记

3.2 构建事件时间线

3.3 关键日志模式

模式1:Binder超时

模式2:GC导致

模式3:IO阻塞

3.4 logcat过滤技巧

四、工具实战

4.1 adb命令合集

4.1.1 获取traces文件

4.1.2 实时监控ANR

4.1.3 查看系统状态

4.2 Systrace分析

4.2.1 抓取Systrace

4.2.2 分析Systrace

4.3 自动化分析脚本

五、完整排查案例

5.1 案例1:主线程等锁导致ANR

5.2 案例2:Binder资源耗尽

5.3 案例3:主线程死循环

六、排查工作流总结

6.1 标准排查清单

6.2 常见ANR类型速查表

6.3 排查陷阱与技巧

七、总结

7.1 核心要点回顾

7.2 进阶学习路径

7.3 常见问题FAQ

7.4 下一篇预告

相关文章

🎉 感谢关注,让我们一起深入Android系统的精彩世界!

找到我: 个人主页