ARTICLE DETAIL

资讯详情

深耕郑州网站建设与运营推广的一线实战洞察。

主线程 doFrame ANR 排查指南:从原理到实战

主线程 doFrame ANR 排查指南:从原理到实战 上周帮一个团队处理线上卡顿打开ANR trace 第一眼看到的又是主线程停在 Choreographer.doFrame。这个位置在性能优化里算是典型疑难杂症了从堆栈看问题似乎很明确主线程就是在绘制流程里卡住了但真正的原因往往藏在 doFrame 的前前后后有可能是布局问题有可能是动画问题也有可能是一个看似无关的业务 Handler 占住了主线程。这篇文章就围绕“应用主线程在 doFrame 的 ANR”这类问题把我平时怎么排查、怎么定位、怎么治理的完整思路过一遍。内容偏实战适合正在和线上 ANR 率、卡顿率缠斗的同学参考也适合刚接触性能优化、想理解 Choreographer 工作机制的朋友耐心看完应该会有收获。1. doFrame与ANR的关系为什么它们总是一起出现1.1 Choreographer.doFrame在UI周期里到底扮演什么角色先说一个基础但很容易被忽略的点doFrame 并不是 Android 系统 UI 线程的全部它只是被 Choreographer 调用的一次帧回调。Choreographer 会等待硬件 VSync 信号等信号来了才把当前帧里注册好的任务按顺序执行掉。这个顺序是固定的先处理 input 相关的回调再处理 animation 回调最后是 traversal 回调也就是 ViewRootImpl 的 performTraversals。可以把它类比成一个流水线VSync 就是流水线的启动铃。铃一响doFrame 开始运转把输入、动画、布局、绘制这几道工序依次推完。正常情况下这一整套流程要在 16ms 左右完成这样屏幕刷新到下一帧时恰好有新的画面可以展示。一旦 doFrame 内部任意一道工序超时比如 measure 或者 draw 消耗了 100ms那这一帧就出不来用户就会感到卡顿、掉帧。关键在于如果掉帧只是偶尔一两次系统最多是统计一下 jank并不会弹窗。但如果是持续性的、严重的主线程阻塞输入事件超过 5 秒没有被主线程处理完系统就会认定是 “Input dispatching timed out”于是弹 ANR。所以 doFrame 和 ANR 的联系本质上是一条链路doFrame 负责在每帧内完成 UI 工作doFrame 一旦长期被占用输入响应超时系统就动手了。1.2 系统是如何把慢帧一步步升级成ANR弹窗的很多人会把掉帧和 ANR 混为一谈其实它们是两个层级的故障。掉帧是性能劣化ANR 是红线事故。就拿 doFrame 相关的场景来说最典型的触发路径是用户的手指在屏幕上滑动系统派发了一个 MotionEvent 到主线程如果主线程正忙着执行 doFrame 里的 performTraversals暂时没空处理这个事件事件就会等在队列里等到 doFrame 执行完发现已经超过了 5 秒那就不好意思ANR 弹窗出现。除了输入超时还有两种情况也容易和 doFrame 扯上关系。一种是 BroadcastReceiver 超时某些广播的 onReceive 方法跑在主线程如果恰好广播是在 doFrame 链路里某个回调触发的而 onReceive 里又有耗时逻辑整个主线程被占住超过前台 10 秒的后台 60 秒也会 ANR。另一种是 Service 超时情况类似。所以看到 ANR 类型不是 “Input dispatching timed out” 时也别急着排除 doFrame 的嫌疑还得看主线程当时是不是正卡在绘制链路上。理解这一层后排查思路就能打开不要只盯着 doFrame 函数本身而要把它当作一个时间窗口窗口内任何一段主线程的高负载最终都可能表现为 doFrame 相关的 ANR。1.3 “卡在doFrame”这个结论经常会误导排查方向实际处理问题的时候我发现很多人一看到 trace 里主线程栈在 Choreographer.doFrame就以为“绘制代码写得太重了”然后一头扎进自定义 View 的 onDraw 里找问题。这个方向有时候对但经常会被打脸。原因是 doFrame 的调用方式比较特殊。它不是进程内部想调就能调的必须等 VSync。如果主线程之前已经被某个耗时任务占用了几秒钟等 VSync 来了之后doFrame 根本排不上队主线程还在执行那个耗时任务。这时抓到的 trace 停在哪里大概率不在 doFrame 里而是在那个耗时函数的堆栈上。只有当主线程其实已经空闲并且真的开始执行 doFrame 了但 doFrame 内部代码太重trace 才会停在 performTraversals、measure、draw 这些函数里面。所以看到“主线程在 doFrame”这个堆栈第一件事不是去改 doFrame 相关代码而是要先判断这是 doFrame 执行得慢还是 doFrame 压根没机会执行。前者是绘制链路问题后者通常是消息队列拥堵问题。这两种情况的修复方式完全不同判断错了后面全是白忙。2. doFrame ANR的根因分类型排查2.1 类型一主线程消息队列拥堵doFrame被硬生生饿死先说我见过最多的一类doFrame 没做任何事纯粹是被其他消息挤到后面去了。主线程的 Looper 本质上是一个死循环不断从 MessageQueue 里取消息并执行。如果某个消息执行了 2 秒那后面排队的消息全部等待包括 Choreographer 投递的帧回调。举一个实际例子有一次线上 ANR主线程 trace 停在了一个业务 Handler 的 handleMessage 上里面是一段复杂的 JSON 解析加上同步的 SharedPreferences 写入执行了将近 6 秒。那期间用户滑动列表VSync 信号一直在触发Choreographer 一次又一次尝试投递 doFrame但每次都被挡在 MessageQueue 外面。最终系统判定输入事件超时ANR 弹窗。这种场景下你去看 ANR trace主线程停在业务代码上根本不在 doFrame 函数内部。但搜索相关日志时又确实能看到掉帧统计在短时间内爆表很多同学就迷茫了。其实机制非常简单doFrame 被饿死了不是它自己不干活是没机会干活。排查时需要关注两点一是 trace 里主线程具体停在哪一个消息处理上二是看这个耗时消息是哪里 post 进来的。通常可以用自定义的主线程消息监控把每条消息的执行时间打出来找那条超过几百毫秒的消息顺藤摸瓜抓到 handler 源头。2.2 类型二performTraversals内部超时布局和绘制是重灾区第二种情况才是真正意义上的“doFrame 内部卡住”。trace 会明确停在 ViewRootImpl.performTraversals 里再往下可能是 View.measure、View.layout、View.draw 这些调用链中的任意一环。布局阶段超时的原因很直白View 树太深、节点太多、measure 写得太复杂。比如有些老项目还留着五六层嵌套的 LinearLayout一个页面大几百个 View 节点每个节点 measure 一次整个树就要跑几百上千次测量。低端机上单次 measure 就可能超过 20ms一帧里再来点自定义 View 的复杂计算50ms 就出去了。绘制阶段超时的原因更常见onDraw 里做了不该做的事。我最常遇到的是在 onDraw 里创建 Paint、创建 Path、做文字宽高测量、做字符串拼接、甚至解析 JSON。这些操作单次看着不重架不住每帧都执行滑动时一次 draw 几十毫秒指数级恶化。doFrame 里还有一段容易被忽略的时间是 draw 之后的 sync 阶段也就是 RenderThread 和 UI 线程同步渲染命令的过程。如果 view 层 android 设置了复杂的效果比如阴影、模糊、大尺寸的硬件层sync 耗时会显著上升。这属于绘制链路的另一种重负载排查时也不要漏掉。2.3 类型三高频requestLayout导致的测量风暴与无效帧这类问题表面看是 doFrame 卡了骨子里是布局请求太频繁。View 的 invalidate 和 requestLayout 是有区别的。invalidate 只在当前 View 的绘制区域打一个标记下一帧只需要重绘它requestLayout 则要求整棵 View 树重新 measure、layout、draw。一次两次无所谓但如果一个页面在短时间内被反复 requestLayout每帧都在执行完整遍历那就非常致命。最常见的触发场景是某个自定义 View 在 onDraw 里根据测量结果调整自身大小调用了 requestLayoutrequestLayout 又导致下一帧重新测量测量完又触发 onDrawonDraw 里再次 requestLayout。这个循环会让每帧的 performTraversals 都变得异常繁重轻则掉帧重则整个主线程被拖到 ANR。另一个高频场景是使用 RecyclerView 时数据更新方式不合理。比如在一个列表里频繁调用 notifyDataSetChanged而不是使用差异化更新 DiffUtil每次都会触发大量 item 重新布局在列表中间再嵌套一个自身会发 requestLayout 的组件整个 doFrame 的耗时直接起飞。这种根因的 trace 往往停在 performMeasure 或者 performLayout 上而且多次抓到的堆栈高度相似。排查时可以重点看是否在循环、回调里触发了 requestLayout以及布局层级有没有不必要的复杂结构。2.4 类型四输入事件处理与doFrame互相争抢主线程还有一种情况比较隐蔽问题不出在 doFrame 内部而是出在输入事件的预处理阶段。前面说过 Choreographer 在每一帧阶段会先处理 input 回调但如果 onTouchEvent、onInterceptTouchEvent、dispatchTouchEvent 里做了耗时操作那 input 阶段就会卡住后面的 animation 和 traversal 全部都得等。有个经典案例一个滑动的 ViewPager 页面onPageScrolled 回调里做了大量数据刷新和 Bitmap 解码每次滑动都触发一次耗时操作。从时间窗口看主线程大部分时间都在和滑动相关的事件处理纠缠Choreographer 的动画和绘制任务反复被推迟最终输入事件处理的超时直接变成 ANR。这种场景的难点在于 trace 可能看到的是 Activity.dispatchTouchEvent、View.onTouchEvent 这类堆栈而不是 doFrame但整条帧链路确实是在 doFrame 的时间片内被打断的。排查时不能只盯着绘制要把每一帧里从输入到动画再到遍历的完整时间分布都打出来才能看清是谁抢了谁的时间。2.5 四类根因的特征对照根因类型trace特征发生时机直观表现修复方向主线程消息队列拥堵主线程停在业务Handler/Looper.loop任意操作点击无响应操作延迟消息拆分、耗时任务异步化、消息去重performTraversals内部超时停在measure/layout/draw相关调用滑动、页面切换明显掉帧、卡顿布局扁平化、自定义View瘦身、绘制缓存高频requestLayout停在performMeasure/performLayout数据刷新、动画回调帧率骤降合并刷新、避免在draw里调用requestLayout输入事件与doFrame互抢停在dispatchTouchEvent/onTouchEvent触摸交互中掉帧输入延迟事件回调轻量化、耗时逻辑移出主线程这张表可以当排查的快速索引不过实际案例经常是几种根因叠加比如既有布局重又有消息队列拥堵。遇到混合型问题就需要逐个拆开验证。3. 从拿到Trace到揪出真凶的完整排查链路3.1 第一步读懂ANR trace里的主线程堆栈拿到一份 ANR trace很多人的习惯是直接搜 “main”然后把主线程的调用栈贴给同事。这个动作没问题但读栈不能只看一个函数名要按层拆。比如下面这段模拟的 trace 片段main prio5 tid1 Runnable at com.example.widget.InfoCardView.onDraw(InfoCardView.java:87) at android.view.View.draw(View.java:20100) at android.view.ViewGroup.drawChild(ViewGroup.java:4300) at android.view.ViewGroup.dispatchDraw(ViewGroup.java:4100) at android.view.View.draw(View.java:20400) at android.view.ViewRootImpl.performDraw(ViewRootImpl.java:3500) at android.view.ViewRootImpl.performTraversals(ViewRootImpl.java:3100) at android.view.ViewRootImpl.doTraversal(ViewRootImpl.java:2600) at android.view.ViewRootImpl$TraversalRunnable.run(ViewRootImpl.java:7900) at android.view.Choreographer.doFrame(Choreographer.java:700) at android.view.Choreographer$FrameDisplayEventReceiver.run(Choreographer.java:880) at android.os.Handler.handleCallback(Handler.java:890)读到这段栈不要只盯着 Choreographer.doFrame那是结果不是原因。真正的信息在栈顶也就是 com.example.widget.InfoCardView.onDraw。这个函数就是当前正在执行的耗时点重点检查它。再看调用链它是被 performDraw 调起来的说明问题确实在绘制链路内部。这时再结合前文的根因分类基本可以把方向锁定在 performTraversals 内部超时这一档。如果 trace 停在 Looper.loop 或者某个业务 Handler那就赶紧跳出 doFrame 的思路转去查消息队列拥堵。一句话读栈永远从栈顶读到栈底先确认现在到底在执行什么代码再判断责任方是谁。3.2 第二步复现并量化doFrame内各阶段的耗时静态读完栈下一步要复现问题并量化耗时分布。这里有两个很实用的工具。第一个是 Choreographer 的 FrameCallback可以用来统计相邻两帧间的真实间隔判断掉帧有没有出现、出现在什么操作之后。public class FrameMonitor { private long lastFrameTimeNanos 0L; public void start() { Choreographer.getInstance().postFrameCallback(new Choreographer.FrameCallback() { Override public void doFrame(long frameTimeNanos) { if (lastFrameTimeNanos ! 0L) { long costMs (frameTimeNanos - lastFrameTimeNanos) / 1_000_000; if (costMs 50L) { Log.w(FrameMonitor, jank, this frame cost costMs ms); } } lastFrameTimeNanos frameTimeNanos; Choreographer.getInstance().postFrameCallback(this); } }); } }注意这个监控不能常开每帧都会回调自身有一点开销但定位问题时临时开一下非常值。如果发现掉帧集中在某个业务操作之后比如点击某个按钮那后面的 trace 采集就会有的放矢。第二个是 FrameMetrics API它能直接拿到系统记录的整帧信息包括输入处理耗时、动画耗时、measure/layout 耗时、draw 耗时、同步耗时、交换缓冲耗时等。Window window getWindow(); window.addOnFrameMetricsAvailableListener((window2, frameMetrics, dropCount) - { long total frameMetrics.getMetric(FrameMetrics.TOTAL_DURATION) / 1_000_000; long measureLayout frameMetrics.getMetric(FrameMetrics.MEASURE_LAYOUT_DURATION) / 1_000_000; long draw frameMetrics.getMetric(FrameMetrics.DRAW_DURATION) / 1_000_000; long input frameMetrics.getMetric(FrameMetrics.INPUT_HANDLING_DURATION) / 1_000_000; if (total 50L) { Log.w(FrameMetrics, total total ms, input input ms, measureLayout measureLayout ms, draw draw ms); } }, new Handler(Looper.getMainLooper()));这个 API 的好处是不用侵入业务代码系统已经把每一帧拆成了几个阶段直接看哪段时间最长就能定位责任阶段。input 长是事件处理问题measureLayout 长是布局问题draw 长是绘制问题非常清晰。3.3 第三步实战复盘一个横向列表引发的doFrame ANR讲一个我实际跟过的案例帮助理解上面这套方法怎么串起来。线上反馈某版本在低端机上滑动一个横向卡片列表特别卡使用几分钟后直接 ANR。拿到 dropbox 里的 trace主线程栈停在了一个自定义 CardView 的 onDraw 方法里栈底部同样挂着 Choreographer.doFrame。按 3.1 的读法问题应该出在绘制本身。接下来复现问题时我在目标机型的 Debug 包上打开了 FrameMetrics复现滑动操作日志打出来单帧 total 稳定在 300ms 到 800ms 之间其中 draw 阶段占了 250ms 以上。再往下查 onDraw 代码发现每次 draw 都要做三件事创建 Path、做文字的 measure 计算、new 一个 Paint 对象并设置复杂 shader。这些对象的创建和计算在低端机上非常昂贵滑动时一秒钟 60 帧等于每帧都在重复做同样的事情彻底把主线程拖垮。修复方法不复杂把 Paint、Path 挪到 View 构造时初始化文字测量结果做缓存shader 复用onDraw 里只做 canvas.draw 操作。改完后在同样的机型上滑了十分钟单帧 draw 时间基本稳定在 5ms 左右不再出现卡顿和 ANR。这个案例的启发点是onDraw 里的代码量有时看着不大但每帧重复执行之后消耗会被放大到一个你想不到的量级。性能问题不能只看单次执行耗时还要看执行频率。4. 修复手段与线上防线让doFrame不再成为事故现场4.1 在Debug包落地一个无侵入的doFrame耗时监控排查类的工具再顺手也只是事后诸葛亮。真正想把 doFrame 的 ANR 压下去要在开发阶段就建立一条监控防线。我现在的习惯是在 Debug 包和内部体验包里挂一个帧耗时监控最简单的方式就是 Choreographer FrameCallback 方案设定一个阈值比如单帧耗时超过 100ms 时立刻把主线程堆栈打到日志里。代码可以参考前面那一段 FrameMonitor加一点改动在采集到慢帧的时候用 Log.getStackTraceString(Thread.currentThread()) 抓一下当前主线程栈。这样等同事反馈“开发环境也卡了”的时候调试日志里已经躺着现成的堆栈不用再让人复现一遍。有一点要提醒这种监控不要直接带到线上包更不要长期开着采集所有堆栈否则监控本身会制造掉帧。可以做成配置开关灰度期间或特定用户群里临时打开采集一段时间后关掉。4.2 从源头消灭主线程重活消息治理与布局绘制瘦身治标之外还得治本。先说消息治理。统计一下主线程消息队列里到底跑了哪些重任务有没有大型 JSON 解析、数据库查询、Bitmap 解码、加密操作这些能挪到子线程的一律异步化。挪不走的比如 View 操作要尽量合并。两个 Handler 消息如果都可以延迟一点就用一个消息合并处理减少消息队列的总排队长度。对于重复发起的延时任务比如频繁 postDelayed 的轮询要记得在页面不可见时移除避免主线程被无意义地占用。布局和绘制层面的优化可以参照几个常见原则能用一个 View 画出来的效果就不要用多层 ViewGroup 叠能用 ConstraintLayout 一层结构就不要用四层 LinearLayoutonDraw 里不要做任何对象创建、资源解码、文件读写操作。列表里的 item 优先用 RecyclerView数据刷新优先用 DiffUtil 这类增量更新避免整页重绘。这些优化不是一次能做完的建议在平时需求迭代里顺手做或者单独立项专项治理。哪块掉帧最明显就先改哪块逐步积累。4.3 用FrameMetrics和系统Trace搭起线上兜底线上环境比较复杂真机分布广、系统版本多很多卡顿只会在特定机型触发。要做线上兜底可以在几个核心 Activity 的 Window 上挂 FrameMetrics 监听把慢帧的关键指标周期上报到监控平台。平时不需要全量采集只上报 total 超过 200ms 的帧就能拿到最具参考价值的性能数据。如果有条件可以在慢帧发生时结合系统 Trace 能力把主线程当时的调度情况、CPU 占用、锁等待一起采集下来。用 perfetto 抓到的数据能看清一个问题卡顿时是 CPU 本身繁忙还是线程在等待锁或者是在低功耗模式下运行。这些信息对定位混合型问题非常关键。需要注意的是采集逻辑本身不能拖慢主线程建议采样率控制在 1% 以内上报采用异步批量。线上监控要做到“平时不动声色出事时有据可查”而不是反过来变成新的性能负担。4.4 发版前的卡顿回归与灰度监控习惯最后说点习惯层面的东西。我后来发现doFrame 类的 ANR 很容易在发版初期集中爆发因为回归测试很少会在低端机上长时间滑动列表。所以现在每次版本发布前我会安排一轮低端机的重点场景回归覆盖三个地方列表页快速滑动、列表进入二级详情页再返回、页面切换动画。这三个场景最容易触发 doFrame 相关问题。灰度期间再把 4.1 的帧耗时监控开关悄悄打开针对新用户群里出现异常的情况做实时告警。只要慢帧被及时抓到ANR 大概率能在演变成事故之前被拦下来。这套流程跑顺之后doFrame 类的 ANR 基本不会再成为线上顽疾。我自己习惯在项目的 Debug 包里长期放一个 FrameMonitor同时把线上监控阈值、采样率、白名单做成服务端可配置的参数出问题随时调整无需发版。这样一套组合下来再遇到“应用主线程在 doFrame 的 ANR”时第一步已经不是去线上日志里找堆栈而是先去监控面板确认影响范围再用 trace 和 FrameMetrics 定位耗时阶段。排查得快治理得早比事后补丁省力得多。
返回列表