ANR(Application Not Responding)即应用程序无响应,其本质是Android系统对应用程序主线程阻塞的监控机制。Android 在系统层实现了一套精密的机制来发现 ANR,重心是消息调度和超时处理。
ANR 由 ActivityManagerService、WindowManagerService、InputManagerService 等系统服务共同监控,由消息处理机制保证,当主线程在限定时间内未完成关键操作(如界面响应、广播处理、服务启动等),系统会判定应用失去响应能力,触发ANR。
ANR 的直接原因是主线程(UI 线程)未及时处理消息。常见阻塞操作包括:CPU 密集型计算(如复杂算法);同步 I/O 操作(如读写数据库、网络请求);死锁或线程竞争(如多线程同步不当);Binder 调用阻塞,诸如跨进程通信(如调用 ContentProvider)若服务端响应慢,会导致主线程挂起;过度布局或绘制,诸如复杂 View 树或频繁 measure/layout 操作。
1,ANR常见的分析方法以及需要的日志信息:
1.1,通过EventLog中搜索am_anr查看ANR发生的时间,进一步与anr log比对看anr log是否有效,提取有用的pid,tid,cpu,deadlock等信息。
如果 ANR 发生的输出的信息很多,当时的 CPU 和 I/O 资源比较紧张,那么日志输出的时间点可能会延迟10秒左右有时可能到20秒。
1.2,通过Android Log中搜索ANR in查看详细信息,提取诸如 发生ANR的时间、进程、原因,CPU/Memory负载,缺页次数fault(xxx minor 表示高速缓存中的缺页次数,可以理解为进程在做内存访问
xxx major 表示内存的缺页次数,可以理解为进程在做 IO 操作。)
1.3,在日志中搜索异常和系统关键日志,诸如:
系统变慢(Slow operation、Slow dispatch、Slow delivery、dvm_lock_sample),
进程变化(am_kill、am_proc_died、lowmemorykiller、ANR、应用启动关系等),
系统信息(cpu info、meminfo、binder info是否满了、iowait是否过高等)。
1.4,根据提取出来的关键信息文件,进一步理出系统当时的情况、状态,诸如:
是处于低内存频繁杀进程?重启第一次解锁系统繁忙?还是短时间内多个应用启动系统繁忙?还是应用自己的逻辑等待?
1.5,根据以上的分析,初步确认ANR是应用的问题还是系统的问题。
1.6,分析应用的问题需要理清当时用户的操作是什么,应用在用户这个操作的过程中扮演了什么角色,然后再进行进一步的分析,
分析是否存在死锁、是否是在等待 binder 返回、Trace 文件中 MainThread 和 RenderThread 是否存在异常或存在等待关系。
1.7,分析系统问题,首先查看CPU使用使用率和负载,以及SystemServer、lowmemorykiller、HeapTaskDeamon、Audio、SurfaceFlinger 这些系统相关的进程或者线程是否占用高。
ActivityManager: CPU usage from 0ms to 13135ms later (2020-09-09 02:09:54.942 to 2020-09-09 02:10:08.077):
ActivityManager: 191%(CPU 的使用率) 1948/system_server: 72%(用户态的使用率) user + 119%(内核态的使用率) kernel / faults: 78816 minor 9 major
ActivityManager: 10% 2218/android.bg: 3.6% user + 6.6% kernel
ActivityManager: 30% 5991/com.eric.launcher: 23% user + 6.4% kernel / faults: 118172 minor(高速缓存的缺页次数) 2 major(内存的缺页次数)
ActivityManager: 16% 6174/launcher-loader: 13% user + 2.8% kernel
ActivityManager: 3.9% 5991/m.eric.launcher: 3.1% user + 0.8% kernel
ActivityManager: 20% 6549/com.eric.video: 16% user + 3.7% kernel / faults: 3541 minor
ActivityManager: 10% 6889/DBCacheManager: 8.7% user + 1.2% kernel
ActivityManager: 9.4% 6942/DefaultDispatch: 7.1% user + 2.2% kernel
上面的CPU的使用率,下面看下CPU的负载。
ActivityManager: ANR in com.eric.launcher (com.eric.launcher/.Launcher)(进程名)
ActivityManager: PID: 5991(进程 pid)
ActivityManager: Reason: Input dispatching timed out (6a6083a com.eric.launcher/com.eric.launcher.Launcher (server) is not responding. Waited 5001ms for FocusEvent(hasFocus=true))(原因)
ActivityManager: Parent: com.eric.launcher/.Launcher
ActivityManager: Load: 15.29 / 5.19 / 1.87(Load 表明是 1 分钟,5 分钟,15 分钟 CPU 的负载)
ActivityManager: ----- Output from /proc/pressure/memory -----(内存压力)
ActivityManager: somavg10=1.35 avg60=0.31 avg300=0.06 total=346727
ActivityManager: full avg10=0.00 avg60=0.00 avg300=0.00 total=34803
ActivityManager: ----- End output from /proc/pressure/memory -----
Load 后面的三个数字的意思分别是1分钟、5分钟、15分钟内系统的平均负荷。当CPU完全空闲的时候,平均负荷为0;当CPU工作量饱和的时候,平均负荷为1,通过Load可以判断系统负荷是否过重。
上面的日志中,还有内存的负载信息,Memory负载是从 /proc/pressure/memory 中获取的,avg10、avg60、avg300 分别代表 10s、60s、300s 的时间周期内的阻塞时间百分比。total 是总累计时间,以毫秒为单位。
其次查看是否存在大量IO的情况,看IO负载一般看faults。
ActivityManager: 30% 5991/com.eric.launcher: 33% user + 6.4% kernel / faults: 118172 minor(高速缓存的缺页次数) 2 major(内存的缺页次数)
Minor,高速缓存的缺页次数,指的是 Minor Page Fault(次要页错误,简称 MnPF),磁盘数据被加载到内存后,内核再次读取时,会发出一个MnPF信息。 一个文件第一次被读写时会有很多的MPF,被缓存到内存后再次访问MPF就会很少,MnPF 反而变多,这是内核为减少效率低下的磁盘I/O操作采用的缓存技术的结果可以理解为进程在做内存访问。
Major,内存的缺页次数,指Major Page Fault(主要页错误,简称MPF),内核在读取数据时会先后查找CPU的高速缓存和物理内存,如果找不到会发出一个MPF信息,请求将数据加载到内存可以理解为进程在做IO操作。如果有大量的 major,那么说明当时IO操作负载比较高。
接着查看系统是否是低内存,看 dumpsys meminfo 的结果判断是否处于低内存;kernel log 是否有频繁的 lowmemorykiller;event log 是否有频繁的应用被系统低内存策略杀掉;kswapd0 。
接着查看应用是否被冻结:应用处于 D 状态,发生 ANR,如果最后的操作是 refriger,那么是应用被冻结了,正常情况下是功耗优化引起的,可以找一下前后是否有unfreeze 这样的 Log;或者在 Systrace 中的 Kernel Callstack 显示 :{kernel callsite when blocked:: "__refrigerator+0xe4/0x198"}。
查看是否存在系统异常,比如功能导致系统繁忙,没有及时响应应用 Binder 之类的,这种需要分析 Log 中 SystemServer 的日志输出,查看是否有异常的 Log 输出。
2,分析CPU异常
在日志中,如果CPU占用率偏高,也会导致进程异常。
2.1,SystemServer对于cpu占用偏高,系统整体运行会缓慢。
SystemServer 是Android系统的核心进程,负责启动和管理所有关键系统服务。
资源竞争:当SystemServer的CPU占用率过高时,它会与其他进程(包括用户应用)竞争 CPU资源。由于SystemServer的优先级较高,它可能占用大量CPU时间片,导致其他进程无法及时获得执行机会,从而引发系统整体卡顿。
Binder机制:Android 中进程间通信(IPC)主要通过 Binder 机制实现,而 SystemServer 是 Binder 服务的核心提供者。当 SystemServer 的 CPU 负载过高时,Binder 调用的响应时间会增加,导致依赖 IPC 的操作(如跨进程数据传输)变慢。
主线程阻塞:如果应用在主线程中直接调用 SystemServer 提供的服务(如通过 startActivity()),而 SystemServer 响应缓慢,主线程可能被阻塞,导致界面卡顿甚至 ANR。
进程优先级:SystemServer进程通常具有较高的优先级,在CPU调度中享有优先权。当其CPU 占用率过高时,低优先级进程(如用户应用)可能被“饿死”,无法获得足够的CPU时间。
调度延迟:高负载可能导致 CPU 调度器无法及时切换进程,进一步加剧系统卡顿。
关键路径阻塞:许多系统操作(如界面渲染、应用启动、传感器数据处理等)都依赖于SystemServer提供的服务。如果SystemServer因CPU负载过高而响应缓慢,这些操作将被阻塞,导致用户感知到的延迟。如果 SystemServer 无法及时响应应用或系统的请求(如 Activity 启动请求),可能触发 ANR(Application Not Responding),进一步加剧系统卡顿。
内存与 I/O 压力:SystemServer 的高 CPU 负载可能伴随内存泄漏或频繁的 I/O 操作(如日志写入、数据库查询),进一步消耗系统资源,形成恶性循环。
热管理与降频:长时间高 CPU 负载可能导致设备发热,触发 CPU 降频机制,进一步降低系统性能。
综上可知,SystemServer 的CPU占用率偏高会导致系统整体运行缓慢,因其承载了Android 系统的核心功能,且其高负载会引发资源竞争、服务响应延迟、主线程阻塞、调度优先级问题以及连锁资源耗尽。
2.2,kswapd0对cpu占用率偏高,系统整体运行会缓慢,从而引起各种 ANR。把问题转化为内存优化。
kswapd0 是 Linux 内核中的一个核心守护进程(Kernel Swap Daemon 0),负责内存页面的回收(Page Reclamation)和交换(Swap)操作。当系统物理内存不足时,kswapd0 会被唤醒,将不常访问的内存页面换出到磁盘(Swap 分区或文件),以释放物理内存供其他进程使用。
kswapd0 CPU 占用率偏高的原因:
物理内存不足:系统内存被大量占用(如内存泄漏、大量缓存或进程消耗),导致 kswapd0 频繁进行页面交换。
磁盘 I/O 瓶颈:页面交换涉及大量磁盘读写操作,若磁盘性能不佳(如机械硬盘或高负载 SSD),会加剧 CPU 负担。
系统负载过高:同时运行大量进程或服务,导致 kswapd0 工作量增加。
内核参数配置不当:如 vm.swappiness 参数设置过高(默认 60),会促使系统更积极使用 Swap 空间,增加 kswapd0 负载。
kswapd0 高负载导致系统整体运行缓慢的原因:
CPU 资源竞争:kswapd0 占用大量 CPU 资源,导致其他进程(包括用户应用)无法及时获得执行机会,引发系统级卡顿。
内存访问延迟增加:页面交换导致内存访问需从磁盘读取数据,延迟显著增加,影响系统响应速度。
磁盘 I/O 瓶颈:频繁的磁盘读写操作占用系统资源,进一步降低整体性能。
kswapd0 高负载引发 ANR 的原因:
主线程阻塞:
若应用在主线程中执行内存密集型操作(如大图加载、复杂计算),而系统内存不足,kswapd0 的活跃可能导致主线程被阻塞,超过 5 秒未响应即触发 ANR。
系统服务响应延迟:kswapd0 高负载可能导致系统服务(如 system_server)响应延迟,进而影响应用与系统服务的交互,增加 ANR 风险。
内存优化建议:
增加物理内存:提升系统硬件配置,减少 Swap 空间的使用需求。
优化应用内存使用:避免内存泄漏,减少不必要的内存分配和复制。使用缓存策略(如 LruCache)优化频繁访问的数据。
调整 Swap 空间配置:根据系统负载调整 Swap 空间大小(如设置为物理内存的 1-2 倍)。
避免 Swap 空间过小导致频繁交换,或过大浪费磁盘资源。
优化内核参数:调整 vm.swappiness 参数(如设置为 10-30),减少系统对 Swap 空间的依赖。修改 /etc/sysctl.conf 文件并重新加载配置:sysctl vm.swappiness=10
使用内存压缩技术:启用内核的内存压缩功能(如 zswap),减少页面交换的磁盘 I/O 开销。
监控与诊断:使用 free -m、top、vmstat 等工具监控内存和 Swap 使用情况。通过 sar 或 iostat 分析磁盘 I/O 性能,识别瓶颈。
2.3,logd对CPU占用率偏高,也会引起系统卡顿和ANR,因为各个进程输出LOG的操作被阻塞从而执行的极为缓慢。
logd(Logger Daemon)是 Android 系统中的一个核心守护进程,负责集中管理日志的读写操作,包括内核日志(如 dmesg)和应用程序日志(如 Logcat 输出的内容)。它的核心职责是通过日志缓冲区(log buffers)高效处理日志数据,支持日志的轮转(rotation)、过滤(filtering)和权限控制(permissions)。
Android 系统中,所有进程的日志输出最终会通过 logd 写入日志缓冲区。如果 logd 因高负载(如 CPU 占用率过高)无法及时处理日志请求,进程的日志写入操作会被阻塞。对于依赖日志输出的进程(尤其是主线程执行日志写入的进程),这种阻塞可能导致:
主线程卡顿:若进程在主线程中直接调用 Log.d() 等日志方法,且 logd 阻塞,主线程可能无法及时响应用户输入或系统事件,从而引发界面卡顿。
ANR(Application Not Responding):如果主线程被阻塞超过 5 秒(Android 的 ANR 阈值),系统会触发 ANR 弹窗,强制关闭应用。
间接影响系统性能:logd 阻塞不仅影响单个进程,还可能引发连锁反应:
日志缓冲区溢出:若 logd 处理速度跟不上日志生成速度,缓冲区可能被填满,后续日志会被丢弃或触发更严格的限流策略。
系统级卡顿:关键系统进程(如 system_server)的日志输出被阻塞,可能导致系统服务响应延迟,整体流畅度下降。
2.4,Vold对CPU占用率偏高,会引起系统卡顿和 ANR,把问题转给存储。
Vold(Volume Daemon)是 Android 系统中负责管理存储卷(如内部存储、SD 卡、USB 设备等)的核心守护进程。它处理存储设备的挂载、卸载、格式化、权限控制等任务,确保系统能够正确访问存储设备上的数据。
Vold 的核心职责
存储设备管理:
检测并管理连接的存储设备(如 SD 卡、U 盘)。
处理存储设备的挂载(Mount)和卸载(Unmount)操作。
管理存储设备的文件系统格式(如 FAT32、exFAT、ext4)。
权限控制:
控制用户和进程对存储设备的访问权限。
处理存储设备的加密和解密(如 Android 的加密存储功能)。
存储事件通知:
向系统和其他应用发送存储设备状态变更通知(如设备插入、拔出、挂载完成)。
Vold CPU 占用率偏高的原因:
存储设备 I/O 性能不足:
使用低速存储设备(如机械硬盘或低性能 U 盘)时,Vold 可能因等待 I/O 操作完成而占用大量 CPU 资源。
文件系统错误或碎片:
文件系统错误(如元数据损坏)或严重碎片化可能导致 Vold 在访问存储设备时效率低下。
频繁的存储操作:
大量文件读写、复制、删除或同步操作(如云存储同步、大量媒体文件扫描)可能使 Vold 负载过高。
不兼容的存储设备或文件系统:
使用 Android 系统不支持的存储设备或文件系统格式可能导致 Vold 异常。
Vold 进程本身的 Bug 或配置问题:
内核或 Vold 进程的 Bug 可能导致其陷入死循环或资源泄漏。
Vold 高负载导致系统卡顿和 ANR 的原因:
CPU 资源竞争:
Vold 占用大量 CPU 资源,导致其他进程(包括用户应用)无法及时获得执行机会,引发系统级卡顿。
存储操作延迟增加:
Vold 负责管理存储设备,若其性能不佳,可能导致存储操作(如文件读写)延迟显著增加,影响依赖存储的应用程序(如文件浏览器、媒体播放器)。
主线程阻塞:
若应用在主线程中执行存储操作(如大文件读写),而 Vold 因高负载无法及时响应,主线程可能被阻塞,超过 5 秒未响应即触发 ANR。
系统服务响应延迟:
Vold 高负载可能导致系统服务(如 system_server)响应延迟,进而影响应用与系统服务的交互,增加 ANR 风险。
存储优化建议:
使用高性能存储设备:
优先选择高速存储设备(如 UFS 3.1 闪存、NVMe SSD)以减少 I/O 延迟。
优化文件系统:
定期检查并修复文件系统错误(如使用 fsck 工具)。
避免在频繁读写的存储设备上使用日志型文件系统(如 ext4)的日志功能(可通过 tune2fs -O ^has_journal 禁用)。
减少频繁存储操作:
避免在主线程中执行大量存储操作,改用异步线程或后台服务。
优化文件读写模式(如使用内存缓存、批量写入)。
更新系统和驱动:
确保系统和存储设备驱动为最新版本,以修复已知 Bug 并提升兼容性。
监控与诊断:
使用 iostat、vmstat 等工具监控存储设备 I/O 性能。
通过 adb shell dumpsys vold 查看 Vold 的日志和状态信息。
综上可知,Vold 是 Android 存储管理的核心组件,但其高负载可能导致系统卡顿和 ANR。通过优化存储设备性能、调整文件系统配置、减少频繁存储操作以及更新系统和驱动,可有效缓解这些问题,提升系统整体性能。
2.5,应用自身对CPU占用率偏高,大概率是应用自身问题。
3,系统关键日志分析
应用冻结:xxxHansManager : freeze uid: 10245 package: com.tencent.mm reason: LcdOff
ActivityManager : Slow operation,AMS 在执行关键任务的时候,如果任务耗时超过 50 ms,则会打印对应的 Log:
ActivityManager: Slow operation: 138ms so far, now at startProcess: done updating battery stats
如果系统中频繁打印这种 Log,说明系统目前处于一个比较卡的状态,分析的时候就得考虑到系统的因素。
Binder Thread:当 system_server 等进程的线程池使用完, 无空闲线程时, 则 binder 通信都处于饥饿状态, 则饥饿状态超过一定阈值则输出信息.
E IPCThreadState: binder thread pool (31 threads) starved for 120 ms
am_kill: [0,18555,com.sina.weibo.image,945,remove task]1
remove task 指的是这个应用被杀的原因
一般啥进程时如果是通过调用 ProcessRecord.kill()方法, 必然会输出相应的 EventLog。还有一些杀进程不输出日志的情况。
Process.killProcess(int pid) //可杀任何指定进程,或者直接发 signal
adb shell kill -9 pid //可杀任何指定的进程
直接 lmk 杀掉进程,lowmemorykiller 的 log 在 kernel log 中
lowmemorykiller: Kill 'com.heytap.themestore' (15545), uid 10136, oom_adj 995 to free 105068kB
lowmemorykiller: Reclaimed 105068kB at oom_adj 606
4,ANR分析举例
Input ANR
1, 通过am_anr搜索找到ANR发生的时间点关键日志
19:44:56.815 2515 25056 I am_anr :
[0,3365,com.xxx.launcher,819478085,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. Outbound queue length: 0. Wait queue length: 9.)]
2,搜索 ANR in 找到 cpu 使用情况
19:45:07.753 251525056E ActivityManager: PID:3365
19:45:07.753 251525056E ActivityManager: Reason: Input dispatching timed out (Waiting to send key event because the focused window hasnotfinished processing all of the input events that were previously delivered to it. Outbound queue length:0. Wait queue length:9.)
19:45:07.753 251525056E ActivityManager: Parent: com.eric.launcher/.Launcher
19:45:07.753 251525056E ActivityManager: Load:0.02/0.01/0.0
19:45:07.753 251525056E ActivityManager: CPU usage from0ms to10936ms later (2020- 19:44:56.751to2020- 19:45:07.688):
19:45:07.753 251525056E ActivityManager: 97%546/logd:97% user +0.2% kernel / faults:12minor
19:45:07.753 251525056E ActivityManager: 25%956/surfaceflinger:11% user +13% kernel / faults:151minor17major
从 Load : 0.02 / 0.01 / 0.0 来看,整机的负载并不高,logd 和 SurfaceFlinger 的 cpu 使用略高。
3,分析trace.txt信息,首先看 Launcher 的主线程堆栈
"main"prio=5tid=1Native
| group="main"sCount=1dsCount=0flags=1obj=0x72a50cd0self=0x6f7ae10800
| sysTid=3365nice=-10cgrp=defaultsched=0/0handle=0x700123bed8
| state=S schedstat=(37451337214473599138010494263) utm=26967stm=10484core=0HZ=100
|stack=0x7fc0270000-0x7fc0272000stackSize=8192KB
| held mutexes=
kernel: (couldn't read /proc/self/task/3365/stack)
native: #00pc0000000000071a8c /apex/com.android.runtime/lib64/bionic/libc.so (syscall+28)
native: #01pc0000000000075710 /apex/com.android.runtime/lib64/bionic/libc.so (__futex_wait_ex(voidvolatile*,bool,int,bool, timespecconst*)+140)
native: #02pc00000000000d9744 /apex/com.android.runtime/lib64/bionic/libc.so (pthread_cond_wait+60)
native: #03pc00000000002bf5e8 /system/lib64/libhwui.so (android::uirenderer::renderthread::DrawFrameTask::postAndWait()+168)
native: #04pc00000000002bf510 /system/lib64/libhwui.so (android::uirenderer::renderthread::DrawFrameTask::drawFrame()+44)12
at android.graphics.HardwareRenderer.nSyncAndDrawFrame(Native method)
at android.graphics.HardwareRenderer.syncAndDrawFrame(HardwareRenderer.java:422)
at android.view.ThreadedRenderer.draw(ThreadedRenderer.java:671)
at android.view.ViewRootImpl.draw(ViewRootImpl.java:3983)
- locked <0x030694da> (a java.lang.Object)
at android.view.ViewRootImpl.performDraw(ViewRootImpl.java:3782)
对于上面的堆栈信息,有如下分析:
(1) 堆栈顶部的Native方法是HardwareRenderer.nSyncAndDrawFrame
(2) 主线程通过ViewRootImpl.draw()触发渲染,而渲染线程(RenderThread)通过 DrawFrameTask 执行实际绘制,在渲染完成后会通过 pthread_cond_signal 通知主线程。
(3) 堆栈中的DrawFrameTask::postAndWait()表明渲染线程(RenderThread)在提交绘制任务后,通过 pthread_cond_wait 等待 GPU 完成操作,主线程在此处阻塞,直到 RenderThread 完成渲染并发送条件变量信号 pthread_cond_signal。
(4)主线程与RenderThread的交互:
主线程提交绘制任务给RenderThread, RenderThread 执行 DrawFrameTask(GPU 渲染),此时主线程等待 RenderThread 完成渲染,RenderThread 渲染完成发送 pthread_cond_signal 通知主线程,主线程收到完成信号,继续执行。
接着查看RenderThread堆栈信息:
"RenderThread"daemon prio=7tid=25Native
| group="main"sCount=1dsCount=0flags=1obj=0x13100b00self=0x6f0c698c00
| sysTid=3616nice=-10cgrp=defaultsched=0/0handle=0x6f072e0d50
| state=S schedstat=(35808915205059629728352628704) utm=29226stm=6582core=3HZ=100
|stack=0x6f071ea000-0x6f071ec000stackSize=991KB
| held mutexes=
kernel: (couldn't read /proc/self/task/3616/stack)
native: #00pc00000000000c49f4 /apex/com.android.runtime/lib64/bionic/libc.so (__ioctl+4)
native: #01pc000000000007d518 /apex/com.android.runtime/lib64/bionic/libc.so (ioctl+132)
native: #02pc0000000000059e58 /system/lib64/libbinder.so (android::IPCThreadState::talkWithDriver(bool)+244)
native: #03pc000000000005ad94 /system/lib64/libbinder.so (android::IPCThreadState::waitForResponse(android::Parcel*,int*)+60
native: #04pc000000000005ab38 /system/lib64/libbinder.so (android::IPCThreadState::transact(int,unsignedint, android::Parcelconst&, android::Parcel*,unsignedint)+180)
native: #05pc000000000004f000 /system/lib64/libbinder.so (android::BpBinder::transact(unsignedint, android::Parcelconst&, android::Parcel*,unsignedint)+228)
native: #06pc000000000007fef8 /system/lib64/libgui.so (android::BpGraphicBufferProducer::dequeueBuffer(int*, android::sp<android::Fence>*,unsignedint,unsignedint,int,unsignedlong,unsignedlong*, android::FrameEventHistoryDelta*)+224)
native: #07pc00000000000b9880 /system/lib64/libgui.so (android::Surface::dequeueBuffer(ANativeWindowBuffer**,int*)+392)
native: #08pc0000000000380540 /system/lib64/libhwui.so (android::uirenderer::renderthread::ReliableSurface::hook_dequeueBuffer(ANativeWindow*, ANativeWindowBuffer**,int*)+104)
native: #09pc000000000000989c /vendor/lib64/egl/eglSubDriverAndroid.so (???)
native: #10pc0000000000009388 /vendor/lib64/egl/eglSubDriverAndroid.so (???)
native: #11pc000000000022cd2c /vendor/lib64/egl/libGLESv2_adreno.so (???)
native: #12pc0000000000212b8c /vendor/lib64/egl/libGLESv2_adreno.so (???)
native: #13pc0000000000020838 /system/lib64/libEGL.so (android::eglQuerySurfaceImpl(void*,void*,int,int*)+248)
native: #14pc00000000002c6794 /system/lib64/libhwui.so (android::uirenderer::renderthread::EglManager::beginFrame(void*)+224)
native: #15pc00000000002d414c /system/lib64/libhwui.so (android::uirenderer::renderthread::CanvasContext::draw()+236)
对于上面的堆栈信息,有如下分析:
(1) RenderThread 是 Android 图形渲染管线的专用线程,主要完成如下业务:
图形缓冲区管理:通过 dequeueBuffer 从 Surface 获取图形缓冲区(Graphic Buffer)。
OpenGL/Vulkan 命令执行:将主线程提交的绘制命令(如 UI 元素、纹理)转换为 GPU 指令。
帧同步:通过 eglQuerySurfaceImpl 与 GPU 驱动交互,确保帧渲染与屏幕刷新率(VSync)同步。
(2) 通过 CanvasContext::draw 和 EglManager::beginFrame 执行实际的渲染任务(如绘制 UI 元素、应用特效)。
若单帧渲染时间过长(如复杂动画、过度绘制),RenderThread 可能无法在 16.6ms(60Hz)内完成,导致帧率下降或主线程阻塞。
(3) GPU 驱动交互(libGLESv2_adreno.so)
关键信息:eglQuerySurfaceImpl 和 GPU 指令执行:RenderThread 通过 EGL 接口与 GPU 驱动交互,查询渲染表面状态或提交 OpenGL 命令。
若 GPU 驱动响应缓慢(如驱动 Bug、过热降频),或渲染任务过于复杂(如大量片元着色器计算),RenderThread 可能在此处等待 GPU 完成操作。
(4) 图形缓冲区获取(libgui.so)
关键信息:Surface::dequeueBuffer 和 BpGraphicBufferProducer::dequeueBuffer 。
RenderThread 尝试从 Surface 的生产者(如应用的主线程)获取空闲缓冲区以写入渲染结果。
若缓冲区不足或被其他进程占用(如相机预览、视频编码),RenderThread 可能阻塞,直到缓冲区可用。
(5) Binder 通信延迟(libbinder.so)
关键信息:IPCThreadState::talkWithDriver 和 waitForResponse 。
RenderThread 通过 Binder 与 SurfaceFlinger(系统合成器)通信,申请图形缓冲区或同步渲染状态。
若 SurfaceFlinger 负载过高或 Binder 通信延迟,RenderThread 可能在此处阻塞,等待缓冲区释放或合成完成。
对于上面的RenderThread的堆栈信息,与主线程阻塞的关联性有如下分析:
主线程在 HardwareRenderer.nSyncAndDrawFrame 处等待 RenderThread 完成渲染,而 RenderThread 的阻塞可能由以下原因导致:
(1) 缓冲区不足(BufferQueue 饥饿)
主线程提交渲染任务的速度 > RenderThread 消费速度,导致 BufferQueue 填满。
后果:主线程在 dequeueBuffer 处阻塞,等待 RenderThread 释放缓冲区。
(2) GPU 渲染延迟
RenderThread 因 GPU 负载过高或驱动问题无法及时完成渲染。
后果:主线程在 syncAndDrawFrame 处等待 RenderThread 的完成信号,导致卡顿。
(3) Binder 通信瓶颈
RenderThread 与 SurfaceFlinger 的 Binder 通信延迟。
后果:RenderThread 阻塞在 talkWithDriver,间接导致主线程等待渲染结果。
综上可知,RenderThread是卡在了binder通信上,调用的方法是 dequeueBuffer,在等待 dequeueBuffer 返回结果。正常情况下主线程是不等待 dequeueBuffer 的,在 nSyncAndDrawFrame 返回后就继续执行了,这里卡住是因为在等 RenderThread 的上一个 draw 任务完成,也就是说上一个 draw 任务卡在了 dequeueBuffer,导致这一帧的主线程卡住导致超时。dequeueBuffer 的对端是 SurfaceFlinger,这时候需要查看 SurfaceFlinger 是否有问题。
如果有 binder info 就可以直接看到 renderthread 在跟 SurfaceFlinger 的哪个线程进行通信,binder info 中可以看到 binder 通信的细节。通过搜dequeueBuffer看RenderThread是在与SurfaceFlinger的那个 Bidner 线程通信,比如可能是 Binder:956_4
"Binder:956_4"sysTid=1357
#00pc0000000000071a8c /apex/com.android.runtime/lib64/bionic/libc.so (syscall+28) (BuildId:340eb42dd36c6541aec54c306eb4d0ee)
#01pc0000000000075710 /apex/com.android.runtime/lib64/bionic/libc.so (__futex_wait_ex(voidvolatile*,bool,int,bool, timespecconst*)+140) (BuildId:340eb42dd36c6541aec54c306eb4d0ee)
#02pc00000000000d97e8 /apex/com.android.runtime/lib64/bionic/libc.so (pthread_cond_timedwait+120) (BuildId:340eb42dd36c6541aec54c306eb4d0ee)
#03pc0000000000072df0 /system/lib64/libc++.so (_ZNSt3__118condition_variable15__do_timed_waitERNS_11unique_lockINS_5mutexEEENS_6chrono10time_pointINS5_12system_clockENS5_8durationIxNS_5ratioILl1ELl1000000000EEEEEEE+108) (BuildId:5aad1075509f6e517eb78db32da8fbf6)
#04pc000000000006f9d8 /system/lib64/libgui.so (android::BufferQueueProducer::waitForFreeSlotThenRelock(android::BufferQueueProducer::FreeSlotCaller, std::__1::unique_lock<std::__1::mutex>&,int*)const+788) (BuildId: e017958f19275814d1f2d55ce8b10bfa)
#05pc000000000006fd8c /system/lib64/libgui.so (android::BufferQueueProducer::dequeueBuffer(int*, android::sp<android::Fence>*,unsignedint,unsignedint,int,unsignedlong,unsignedlong*, android::FrameEventHistoryDelta*)+776) (BuildId: e017958f19275814d1f2d55ce8b10bfa)
#06pc000000000007f0a8 /system/lib64/libgui.so (android::BnGraphicBufferProducer::onTransact(unsignedint, android::Parcelconst&, android::Parcel*,unsignedint)+3580) (BuildId: e017958f19275814d1f2d55ce8b10bfa)
#07pc000000000004d67c /system/lib64/libbinder.so (android::BBinder::transact(unsignedint, android::Parcelconst&, android::Parcel*,unsignedint)+136) (BuildId: bb7ca5d12323a310f26473506cf070ed)
#08pc000000000005a55c /system/lib64/libbinder.so (android::IPCThreadState::executeCommand(int)+1008) (BuildId: bb7ca5d12323a310f26473506cf070ed)
从上面的信息看出是卡在了 waitForFreeSlotThenRelock,其代码逻辑在 frameworks/native/libs/gui/BufferQueueProducer.cpp 中。
卡顿在 waitForFreeSlotThenRelock 的意思就是,没有足够的 Buffer,因为每个 Layer 对应的 Buffer 的个数是一定的(2 个或者 3 个或者 4 个,一般是 3 个或者 4 个),如果 4 个 Buffer 都在使用过程中,那么应用调用 dequeueBuffer 去申请 free 的 Buffer 是不会成功的,需要进行等待,这里就是在等待 free 的 buffer 超时,导致了应用的 ANR。
另外日志打印也有提示信息可以去捕捉。
// SurfaceFlinger 的 Log 提示可用 buffer 数量不足
19:44:42.371 956 956 E BufferQueueConsumer: [com.xxx.launcher/com.xxx.launcher.Launcher#0] acquireBuffer: max acquired buffer count reached: 2 (max 1)
19:44:42.371 956 956 E BufferLayerConsumer: [com.xxx.launcher/com.xxx.launcher.Launcher#0] updateTexImage: acquire failed: Function not implemented (-38)
// 提示是 dequeueBuffer 失败
19:45:45.127 3365 3616 W OpenGLRenderer: dequeueBuffer failed, error = -110; switching to fallback
19:45:45.138 3365 3616 I OpenGLRenderer: Davey! duration=4015ms; Flags=0, IntendedVsync=21148991192817, Vsync=21148991192817, OldestInputEvent=9223372036854775807, NewestInputEvent=0, HandleInputStart=21148991206202, AnimationStart=21148991249587, PerformTraversalsStart=21148991252765, DrawStart=21148991798858, SyncQueued=21148991974796, SyncStart=21152137782451, IssueDrawCommandsStart=21152138724534, SwapBuffers=21156150646824, FrameCompleted=21156152280366, DequeueBufferDuration=0, QueueBufferDuration=0,
// MessageQueue 的信息标识是哪个 Message block
19:45:45.142 3365 3365 E ANR_LOG : >>> msg's executing time is too long
19:45:45.142 3365 3365 E ANR_LOG : Blocked msg = { when=-4s2ms what=0 target=android.view.Choreographer$FrameHandler callback=android.view.Choreographer$FrameDisplayEventReceiver } , cost = 4002 ms
19:45:45.142 3365 3365 E ANR_LOG : >>>Current msg List is:
19:45:45.142 3365 3365 E ANR_LOG : Current msg <1> = { when=-4s5ms what=13 target=android.view.ViewRootImpl$ViewRootHandler }
19:45:45.142 3365 3365 E ANR_LOG : Current msg <2> = { when=-4s1ms what=0 target=android.view.ViewRootImpl$ViewRootHandler callback=com.android.launcher3.util.ViewOnDrawExecutor }
19:45:45.143 3365 3365 E ANR_LOG : Current msg <3> = { when=-4s1ms what=0 target=android.view.ViewRootImpl$ViewRootHandler callback=android.widget.Editor$1 }
19:45:45.143 3365 3365 E ANR_LOG : Current msg <4> = { when=-3s23ms what=0 target=android.view.ViewRootImpl$ViewRootHandler callback=android.widget.ViewFlipper$2 }
19:45:45.143 3365 3365 E ANR_LOG : Current msg <5> = { when=-1s502ms what=6 target=android.view.inputmethod.InputMethodManager$H arg1=74627 obj=android.view.inputmethod.InputMethodManager$PendingEvent@561bec9 }
19:45:45.143 3365 3365 E ANR_LOG : Current msg <6> = { when=+14s859ms what=0 target=android.os.Handler callback=xxxUIEngineProguard.i.b$b }
19:45:45.143 3365 3365 E ANR_LOG : Current msg <7> = { when=+24d20h30m18s414ms what=0 target=android.view.ViewRootImpl$ViewRootHandler callback=android.widget.ViewFlipper$2 }
19:45:45.143 3365 3365 E ANR_LOG : >>>CURRENT MSG DUMP OVER<<<
这样可以一步步定位到surface flinger问题。
(4) 一些常见的异常日志
Binder 数据量过大
07-2104:43:21.573 1000 148812756E Binder : Unreasonably large binder replybuffer: on android.content.pm.BaseParceledListSlice$1@770c74f calling1size388568(data:1,32,7274595)
07-2104:43:21.573 1000 148812756E Binder : android.util.Log$TerribleFailure: Unreasonably large binder replybuffer: on android.content.pm.BaseParceledListSlice$1@770c74f calling1size388568(data:1,32,7274595)
07-2104:43:21.607 1000 1488 2951E Binder : Unreasonably large binder replybuffer: on android.content.pm.BaseParceledListSlice$1@770c74f calling1size211848(data:1,23,7274595)
07-2104:43:21.607 1000 1488 2951E Binder : android.util.Log$TerribleFailure: Unreasonably large binder replybuffer: on android.content.pm.BaseParceledListSlice$1@770c74f calling1size211848(data:1,23,7274595)
07-2104:43:21.662 1000 1488 6258E Binder : Unreasonably large binder replybuffer: on android.content.pm.BaseParceledListSlice$1@770c74f calling1size259300(data:1,33,7274595)
Binder 通信失败
07-2106:04:35.580<6>[32837.690321] binder:1698:2362transaction failed29189/-3,size100-0line3042
07-2106:04:35.594<6>[32837.704042] binder:1765:4071transaction failed29189/-3,size76-0line3042
07-2106:04:35.899<6>[32838.009132] binder:1765:4067transaction failed29189/-3,size224-8line3042
07-2106:04:36.018<6>[32838.128903] binder:1765:2397transaction failed29189/-22,size348-0line2916