Handler(四):Handler 卡顿怎么定位?从 Slow delivery 到 Slow dispatch
真实排障时,我们很少遇到一个干净的问题叫:
Handler 原理是什么?
更多时候看到的是:
UI 不刷新;
系统服务响应慢;
回调迟迟不来;
log 里出现 Slow delivery;
log 里出现 Slow dispatch;
system_server 某条线程看起来卡住;
Binder 调用一直等不到结果。
这时最糟糕的结论是:
Handler 卡了。
因为这句话没有定位价值。
更好的拆法是:
业务是否真的调用了 post/sendMessage,目标 Handler 是否正确?
入队请求当时是否被 MessageQueue 接受?
消息在被接受后是否又被 remove 或生命周期清理?
这个 Handler 持有哪个 Looper,该 Looper 与哪条 Thread 绑定?
实际开始 dispatch 是否晚于 Message.when?
当前 dispatch 区间是否过长?
前三篇已经建立了机制:
第一篇:
调用线程只负责入队,目标 Looper 线程负责执行。
第二篇:
MessageQueue 不是普通队列,它会看 when、屏障、nativePollOnce、quit。
第三篇:
Handler 排障要先定位 Looper 所在线程,不能只说主线程或 system_server。
这一篇把这些机制变成排障路径。
核心问题只有一个:
当一个 Handler 任务没有按预期执行时,怎么判断它卡在哪一段?
本文源码以 Android 16 QPR2 的 android-16.0.0_r4 tag 为参考,正文只讨论 Handler 的稳定机制,不展开版本实现差异。
先把正常主链和中断旁路分开:
正常主链:
投递
-> 入队
-> 等待
-> 取出
-> 分发与执行
投递:
post/sendMessage 是否发生?目标 Handler 是否正确?
入队:
入队请求当时是否被 MessageQueue 接受?when 是多少?
等待:
when 是否已到?前序消息、线程调度和屏障证据分别是什么?
取出:
MessageQueue.next() 是否返回该 Message?
分发与执行:
dispatchMessage 选择 Runnable、Handler.Callback 还是 handleMessage?
实际回调是否在计算、锁、I/O、Binder 或 native/HAL 上耗时?
中断旁路:
业务根本没有投递;
入队请求被拒绝;
入队后被 remove;
owner 生命周期结束后任务被取消;
Looper / HandlerThread 退出,导致部分尚未执行的消息被丢弃。
这张图的读法很简单:
不要从“卡了”开始。
从消息生命周期开始。
每次只证明一段。
一、为什么不能说“Handler 卡了”?
因为同一个现象可能来自完全不同的阶段。
比如“UI 没刷新”,可能是:
业务代码根本没有调用 mainHandler.post。
post 调了,但返回 false。
postDelayed 的 when 还没到。
入队后被生命周期清理移除。
主线程正在执行前一个耗时消息。
主线程 runnable,但较长时间没获得 CPU。
当前 Runnable 已经开始执行,但内部等待锁。
当前 Runnable 里发起同步 Binder 调用,被对端拖住。
在 UI traversal 等有明确证据的场景中,普通同步消息被屏障延后。
目标 HandlerThread 已经 quit。
这些原因的证据完全不同。
如果你只写:
Handler 没执行。
读者不知道下一步该看什么。
如果你写:
post 返回 true,说明这次入队请求当时被目标队列接受;
Looper slow log 出现 Slow delivery;
Perfetto 显示目标线程在这段时间一直执行前一个回调;
所以这不是消息没有投递,而是前序消息占住 Looper,导致后续消息等待过久。
这就是可验证结论。
排障文章要从“现象描述”升级成“阶段 + 证据 + 结论”。
二、一条消息的排障生命周期怎么拆?
建议固定沿一条正常主链检查,再单独确认中断旁路。不要把 quit 当作每条正常消息执行后的“最后一步”。
主链第一段:投递
有没有调用 post/sendMessage?
调用方是哪条线程?
目标 Handler 是不是预期的那个?
这一段主要靠业务日志、trace 点、源码路径和返回值。
主链第二段:入队
Message.target 是否写成目标 Handler?
Message.when 是当前时间还是未来时间?
Message 是否 asynchronous?
post/sendMessage 返回值是不是 true?
这一段要结合 Handler.enqueueMessage()、MessageQueue.enqueueMessage() 和业务封装。
主链第三段:等待
when 是否还没到?
前面是否有长消息?
线程是否被系统调度延迟?
是否存在 UI traversal 等同步屏障调用链或屏障异常证据?
线程栈位于 nativePollOnce 时,入队结果、when、屏障和当前队列选择状态分别是什么?
这一段对应 Slow delivery、Perfetto 时间线、前序消息、线程调度和队列状态。同步屏障是需要证据才能成立的分支,不是普通业务 Handler 迟到时的默认猜测。
主链第四段:取出
MessageQueue.next() 是否返回该 Message?
Looper 是否进入 dispatch?
这一段通常要靠 Looper 日志、trace section 或自己加的轻量日志确认。
主链第五段:分发与执行
dispatchMessage 选择的是 Runnable、Handler.Callback,还是 handleMessage?
回调内部是否 I/O、锁等待、Binder 同步调用、native/HAL 阻塞、复杂计算?
Slow dispatch 测量的是从 dispatchStart 到 dispatchEnd 的整个区间,既包含 dispatchMessage() 的路径选择,也包含实际回调执行,不需要在总生命周期里再硬拆成两个连续阶段。这一段对应 thread dump、Perfetto slice、binder trace、锁 owner 和 native stack。
最后单独检查中断主链的旁路:
post/sendMessage 是否被队列拒绝?
removeCallbacks/removeMessages/removeCallbacksAndMessages 是否清掉了消息?
owner 生命周期结束后,任务是否被主动取消?
Looper / HandlerThread 是否已经退出?
这些分支可能在入队前拒绝任务,也可能在入队后阻止任务完成;它们不是“执行之后再退出”的正常末端。
三、怎么确认目标线程是谁?
先回到第三篇的三问:
这个 Handler 持有哪个 Looper?
这个 Looper 与哪条 Thread 绑定?
这条 Thread 在系统设计里负责什么任务?
常见确认方式:
静态定位:
看 Handler 构造时传入的 Looper,以及该 Looper 的创建处。
运行时定位:
看进程内线程列表、线程名、Looper 日志和目标线程栈。
时间线定位:
看 Perfetto 中目标线程在消息到期前后处于 running、runnable 还是 blocked。
相关命令集中放在文末附录。kill -3 会让目标进程生成线程转储并产生额外负担,stop/start 更会重启 Android Framework;只能在允许扰动的调试环境中使用,不能把它们当成无副作用的线上读操作。
如果是 App 主线程:
目标线程通常是 main。
看 ActivityThread、Choreographer、ViewRootImpl、主线程栈。
如果是 system_server:
不要只看进程名。
继续看线程名:
main
android.ui
android.display
android.anim
android.io
Binder:<pid>_x
其他服务自建 HandlerThread
如果当前栈在 Binder 线程:
它正在或曾经执行服务端 Binder 入口代码;
入口可能直接处理,也可能把后续状态处理 post 到 Handler。
因此要同时确认:
Binder 入口当前执行到哪里;
是否已经投递到目标 Handler;
Binder 线程是否还在同步等待 Handler 结果。
定位目标线程以后,再谈消息等待或执行才有意义。
四、怎么确认消息是否投递和入队?
先看调用链是否真的发生:
业务入口是否走到 post/sendMessage?
是否有条件分支提前 return?
目标 Handler 是否为 null?
目标 Handler 是否已经被替换?
然后看返回值:
boolean ok = handler.post(runnable);
ok == false 的直接机制含义是:这次入队请求失败了。对正常构造的 Handler,最常见的直接原因是目标 MessageQueue 正在退出或已经退出。
直接机制原因:
MessageQueue 当时拒绝入队,通常因为 Looper 正在退出。
接下来追问业务根因:
为什么代码仍然向一个正在退出的队列投递?
HandlerThread 的启动 / 关闭顺序是否错误?
owner 已销毁后是否仍持有旧 Handler?
是否有晚到的异步回调?
关闭队列和投递任务之间是否存在竞态?
“组件生命周期已经结束”本身不会直接让 post() 返回 false。例如向 MainLooper Handler 投递时,即使 Activity 已销毁,队列仍可能接受请求并返回 true,只是这项工作在业务上已经失效。必须把“队列为什么拒绝”与“代码为什么还在投递”分成两层结论。
源码入口:
ok == true 只表示这次入队请求在当时被 MessageQueue 接受,不代表消息还留在队列里,更不代表最终一定执行。它随后可能被 removeCallbacks()、removeMessages()、removeCallbacksAndMessages() 或生命周期清理移除,也可能遇到 Looper 退出。
所以日志不要只写:
post updateUi
更好的写法是:
post updateUi to mainHandler, result=true, caller=worker-1, uptime=123456
如果是重要系统路径,投递侧和执行侧必须使用同一标识关联。普通 traceBegin/traceEnd 只能覆盖当前线程调用 post() 的同步区间,不能自动连接目标线程稍后执行的 Runnable。
可以使用 async trace、Perfetto flow,或者同时记录 sequence + uptime 的日志建立关联。拒绝、取消和正常执行还必须保证关联区间只闭合一次;完整封装放在文末“附录 C:如何关联 Handler 投递与执行”。
五、消息没被取出,可能有哪些原因?
如果入队请求曾被接受,但任务迟迟没执行,先不要直接看回调内部。消息可能尚未被 MessageQueue.next() 取出,也可能已经被移除。
常见原因:
1. 没到 when
postDelayed、sendMessageAtTime、重试退避都会让 when 落到未来。
2. 前序消息太慢
目标 Looper 同一时间只能 dispatch 一个 Message。
3. 线程调度延迟
线程 runnable 但迟迟拿不到 CPU。
4. 入队后被移除或生命周期取消
removeCallbacks/removeMessages、组件销毁清理都可能让任务消失。
5. 有证据的同步屏障场景
UI traversal 等路径中的普通同步消息可能等待;只有看到相关调用链、
队列状态或屏障异常证据时,才继续确认屏障是否按 token 移除。
6. 队列正在退出
新的入队请求会失败,未来消息或已清理消息不会继续等待执行。
nativePollOnce 不应与这些根因并列。线程栈位于这里,通常表示 MessageQueue 当前没有选出可执行消息,正在按 timeout、wake 或已注册 fd 事件等待。如果一条已到期消息被接受入队且改变当前等待结果,正常路径会 nativeWake();因此看到 poll 栈后应继续回查入队结果、when、移除、屏障和退出状态,不能只凭这一帧栈认定线程“卡在 poll”。
这里的关键日志证据之一是 Slow delivery。
它说明:
消息计划执行时间已经到了,
但真正开始 dispatch 的时间太晚。
也就是消息从计划时间到真正开始执行之间延迟过长。这个区间通常包含队列等待,也可能包含目标线程没有及时获得 CPU 等调度延迟。
六、Slow delivery 是什么?
Android 的 Looper.loopOnce() 会在分发前后计算时间。
可以抽成这样:
Message msg = queue.next();
long dispatchStart = now();
dispatchMessage(msg);
long dispatchEnd = now();
if (dispatchStart - msg.when > slowDeliveryThreshold) {
log("Slow delivery");
}
if (dispatchEnd - dispatchStart > slowDispatchThreshold) {
log("Slow dispatch");
}
源码入口:
Slow delivery 的时间线是:
Message.when
|
| 开始执行延迟区间
v
dispatchStart
定义:
slow delivery = dispatchStart - Message.when 太长
它常见原因是:
前序消息执行过久,内部可能在计算、I/O、锁或同步 Binder 上阻塞;
队列持续积压,目标 Looper 来不及消费;
线程处于 runnable,但较长时间没有获得 CPU;
Message.when 设置得不符合预期;
在 UI traversal 等有明确证据的场景中,同步屏障延后了普通同步消息。
注意:Slow delivery 只证明实际 dispatch 开始时间晚于 Message.when 超过阈值。它不直接证明业务在哪一刻调用了 post(),也不能单独证明消息在整个区间始终留在队列中;需要与投递日志、返回值、线程调度和 Perfetto 时间线一起还原原因。它更不说明当前消息自己执行慢。
需要注意:Slow delivery / Slow dispatch 是事后证据。
Slow delivery和Slow dispatch都不是实时监控一切 Handler 问题的万能证据。
- 消息尚未开始 dispatch 时,还没有
dispatchStart,可能没有这条消息对应的Slow delivery;- 回调尚未返回时,还没有完整的
dispatchEnd,对应的Slow dispatch日志可能尚未打印;- 慢日志阈值没有启用,或者耗时没有超过阈值时,也不会出现慢日志。
因此,“没有 Slow 日志”不能单独证明没有等待或没有阻塞。消息尚未开始时,要看投递日志、队列/Looper 日志和 Perfetto;回调仍卡在锁、同步 Binder、HAL、死循环或长时间 I/O 时,要优先看 Looper dispatch start、thread dump、Perfetto 当前 slice、Binder 时间线和锁 owner。
七、Slow dispatch 是什么?
Slow dispatch 看的是消息已经开始执行之后,回调自己耗时多久。
时间线是:
dispatchStart
|
| 执行时间太长
v
dispatchEnd
定义:
slow dispatch = dispatchEnd - dispatchStart 太长
常见原因:
Runnable / handleMessage 内部做了 I/O;
等待锁;
同步 Binder 调用;
等待 Future / CountDownLatch;
复杂计算;
native/HAL 阻塞;
回调里又同步调用别的慢服务。
Slow dispatch 的排查方向是当前回调内部。
这时 thread dump 很有价值,因为目标线程正在执行这条消息。你要看它卡在哪:
Java 方法栈;
锁等待;
BinderProxy.transact;
native 方法;
文件 I/O;
数据库或配置读写;
HAL 调用;
复杂循环。
八、Slow delivery 与 Slow dispatch 怎样对照?
| 证据 | 计算区间 | 能证明什么 | 下一步看哪里 |
|---|---|---|---|
Slow delivery | dispatchStart - Message.when | 目标消息开始得晚 | 前序 dispatch、队列积压、线程调度、when;有相关调用链时再看屏障 |
Slow dispatch | dispatchEnd - dispatchStart | 当前消息执行得久 | 当前 Runnable / Callback / handleMessage 内部的栈、锁、I/O、Binder、native |
例如:
when=12:01:03.120,start=12:01:03.460,end=12:01:03.465
-> delivery 340ms,dispatch 5ms:查开始前的时间线。
when=12:01:03.120,start=12:01:03.122,end=12:01:03.320
-> delivery 2ms,dispatch 198ms:查当前回调内部。
两者也可能同时超过阈值:前序消息先让当前消息迟到,当前消息自己又执行很久。结论必须分别写出两个区间,不能合并成一句“Handler 卡顿”。
九、Binder 同步调用为什么会拖住 Handler 线程?
很多 Framework 问题里,Handler 线程慢的直接原因不是 Java 代码计算慢,而是同步 Binder 调用。
典型链路:
android.display Handler
-> 执行某个 WindowManager 回调
-> 同步 Binder 调用另一个进程或服务
-> 对端慢 / 对端等待锁 / Binder 线程池紧张
-> android.display 一直卡在 transact 返回前
-> 后续 display 消息全部 slow delivery
这类问题要同时看两边:
目标 Handler 线程:
它是不是卡在 BinderProxy.transact 或 native binder 调用?
对端进程或 system_server 其他线程:
谁在处理这个 Binder?
对端是否也在等锁、等 I/O、等另一个 Binder?
调用方:
是否同步等待返回?
是否在主线程或关键系统线程发起同步调用?
如果只看 Handler 线程,会看到它“卡在 Binder”。但真正根因可能在对端。
所以证据要写成链:
android.display slow dispatch;
thread dump 显示它在同步 Binder 调用;
binder trace 显示目标服务处理耗时;
目标服务线程栈显示等待某把锁;
因此 android.display 被同步 Binder 调用拖住,导致后续显示消息 slow delivery。
十、案例:UI 不刷新应该怎么拆?
不要直接写:
主线程卡了。
按生命周期拆:
1. 是否真的投递了刷新任务?
看业务日志、trace、post 返回值。
2. 目标 Handler 是不是 MainLooper?
看 Handler 创建处,是否显式 Looper.getMainLooper()。
3. Message.when 是否当前可执行?
是否 postDelayed,是否有重试退避。
4. 是否 slow delivery?
如果有,看前序消息和 Perfetto 时间线。
5. 主线程在等待区间处于什么状态?
是执行前序回调、runnable 未获 CPU,还是当前没有可执行消息而位于 nativePollOnce。
6. 是否存在同步屏障证据?
只有涉及 UI traversal 调用链、屏障 token 或异常队列状态时再深入确认。
7. 是否 slow dispatch?
如果有,看当前 Runnable 内部栈。
8. 主线程当前到底在哪里?
Java 栈、native 栈、Binder、锁、I/O。
可定位结论示例:
刷新 Runnable 在 10:20:31.100 由 worker-2 投递到 MainLooper,post 返回 true,说明入队请求当时被接受;
Message.when 为 10:20:31.100,没有使用 postDelayed;
logcat 出现 MainLooper Slow delivery,未出现对应 Slow dispatch;
Perfetto 显示主线程从 10:20:31.090 到 10:20:31.430 一直在执行前一个 ViewRootImpl 回调;
因此本次 UI 不刷新是前序主线程消息执行过久导致刷新消息等待过久,不是刷新 Runnable 自身执行慢,也不是消息没有投递。
十一、案例:system_server 服务响应慢该先看哪里?
不要直接写:
system_server 慢。
按线程拆:
1. 调用是同步 Binder 还是异步通知?
2. system_server 哪条 Binder 线程接到请求?
3. 服务是否把请求 post 到 Handler?
4. 目标 Handler 持有 main、android.ui、android.display、android.io,还是自建线程对应的 Looper?
5. Binder 线程是否等待 Handler 结果?
6. Handler 线程是否 slow delivery 或 slow dispatch?
7. 慢发生在 Handler 前面、Handler 队列里,还是 Handler 回调内部?
典型结论模板:
App 在 12:01:03.100 发起同步 Binder 请求;
system_server Binder:1234_5 在 12:01:03.120 收到请求,并投递到 android.display Handler;
post 返回 true,说明这次入队请求当时被目标队列接受;
Perfetto 显示 android.display 从 12:01:03.100 到 12:01:03.460 一直在执行前一个 WindowManager 回调;
Looper 日志出现 Slow delivery,而不是 Slow dispatch;
因此当前问题是 android.display 前序消息执行过久,导致后续消息在队列里等待过久;
不是消息没有投递,也不是当前回调自身执行慢。
如果是 Slow dispatch,结论要换方向:
android.display 在 12:01:03.120 开始 dispatch 目标消息;
12:01:03.520 才结束;
thread dump 显示它在目标回调内同步调用某服务;
binder trace 显示对端处理耗时 380ms;
因此问题是当前 Handler 回调内部同步 Binder 调用过慢。
十二、结论应该怎么写?
不要写:
Handler 卡了。
也不要只写:
主线程卡了。
要写成:
目标消息:
哪个消息,什么时间,由谁投递。
目标线程:
持有哪个 Looper,这个 Looper 与哪条 Thread 绑定。
投递结果:
post/sendMessage 返回值,入队请求当时是否被接受,之后是否被移除。
等待证据:
when、slow delivery、前序消息、线程调度、Perfetto 时间线;
有明确 UI traversal 或屏障异常证据时再写同步屏障。
执行证据:
slow dispatch、thread dump、Binder、锁、I/O、native 栈。
结论:
问题发生在正常主链的哪一段,还是被哪条拒绝 / 取消 / 退出旁路中断。
固定模板:
目标消息在 <时间> 由 <调用线程> 投递到 <目标 Handler / Looper 线程>;
post 返回 <true/false>;
Message.when 为 <时间>;
<证据 1> 说明入队请求当时 <被接受/被拒绝>,之后 <未见移除/被某路径移除/无法确认>;
<证据 2> 说明目标线程在 <时间段> 处于 <前序 dispatch / runnable 未获 CPU /
当前无可执行消息并位于 nativePollOnce / 当前回调内锁等待或 Binder 调用>;
Looper 日志为 <Slow delivery / Slow dispatch / 无慢日志>;
因此当前问题是 <阶段> 的 <原因>,
不是 <排除项 1>,也不是 <排除项 2>。
这个模板比“Handler 卡了”长,但它能指导下一步修复。Handler 排障始终从正常主链和中断旁路开始:
正常主链:
投递 -> 入队 -> 等待 -> 取出 -> 分发与执行
中断旁路:
未投递 / 入队被拒绝 / 入队后被移除 / 生命周期取消 / Looper 退出
其中最关键的证据边界是:
Slow delivery:
实际开始时间相对 Message.when 太晚,查前序消息、调度、when 和队列状态。
Slow dispatch:
消息自己执行太久,查回调内部、锁、I/O、Binder、native。
nativePollOnce:
当前没有被队列选出的可执行消息,是观察状态,不是独立根因。
这组四篇到这里形成完整闭环:
任务怎么走:
post -> Message -> enqueue -> next -> dispatch。
队列怎么等:
when、同步屏障、nativePollOnce、nativeWake、quit。
线程怎么分:
主线程、HandlerThread、Binder 线程、system_server 专用 Looper。
问题怎么查:
用阶段和证据替代“Handler 卡了”。
附录 A:如何临时打开 Looper 慢日志?
当前源码中的 Looper.getThresholdOverride() 支持以下系统属性:
log.looper.any.main.slow
log.looper.<uid>.any.slow
log.looper.<uid>.<thread-name>.slow
源码入口:
在允许重启 Framework 的专用测试机上,可以先记录原值,再临时设置:
adb shell getprop log.looper.any.main.slow
adb shell setprop log.looper.any.main.slow 16
adb shell getprop log.looper.1000.android.ui.slow
adb shell setprop log.looper.1000.android.ui.slow 20
adb shell stop
adb shell start
stop/start 会重启 Android Framework,导致界面、服务、连接和现场状态被打断,不适合量产设备或需要保留原始现场的故障。属性能否写入、是否需要重启 Framework 或整机,取决于 build 类型、属性权限和厂商分支;设置后必须用 getprop 验证,不要假设命令成功就已经生效。
复现结束后恢复记录的原值;原值为空时可按测试环境支持的方式清空,再执行同样的生效步骤。不要长期保留过低阈值,否则高频日志本身会扰动时序。
附录 B:工具分别能证明什么?
| 证据 | 能证明什么 | 不能单独证明什么 |
|---|---|---|
投递日志 + post 返回值 | 调用是否发生、入队请求当时是否被接受 | 消息是否仍在队列、是否最终执行 |
Looper.setMessageLogging() | 某条消息实际开始和结束 dispatch | 业务最初在何时调用 post |
Slow delivery | dispatchStart 相对 Message.when 过晚 | 迟到一定由队列积压或屏障造成 |
Slow dispatch | 当前消息的 dispatch 区间过长 | 回调内部究竟卡在锁、I/O、Binder 还是 native |
| thread dump | 采样瞬间的 Java 栈、锁等待或 native 入口 | 整个故障区间始终处于同一状态 |
| Perfetto | 线程调度、前序 slice、Binder 和显式 trace 的时间关系 | 未埋 flow/async trace/sequence 的投递与执行会自动关联 |
dumpsys | 采集时刻的系统组件状态 | 过去某一时刻的完整因果链 |
常用命令按证据选择,不要无目的全跑:
# 线程与日志
adb shell ps -A -T | grep system_server
adb logcat -v threadtime
adb logcat -d | grep -i "Slow dispatch|Slow delivery"
# Java thread dump:会向进程发送 SIGQUIT,仅在允许扰动时使用
adb shell kill -3 <pid>
# 围绕具体现象选择状态快照
adb shell dumpsys activity
adb shell dumpsys window
adb shell dumpsys input
adb shell dumpsys display
adb shell dumpsys binder_calls_stats
窗口不刷新优先围绕 window、activity 和 SurfaceFlinger 链路取证;输入迟滞看 input、window 和 Perfetto input 事件;Binder 耗时看双端线程栈、Binder 时间线和调用统计。工具只是证据来源,最终仍要落回同一条消息的生命周期。
附录 C:如何关联 Handler 投递与执行
正文只需要记住一句话:同步 traceBegin/traceEnd 受当前线程调用栈约束,只能看到 post() 这一小段;要跨越“投递线程 -> MessageQueue -> 目标 Looper 线程”,需要 async trace、flow 或显式 sequence。
下面给出一个用于 Framework / system_server 内部代码的一次性 async trace 骨架:
final class TracedPost implements Runnable {
private static final int ENQUEUED = 0;
private static final int RUNNING = 1;
private static final int FINISHED = 2;
private static final int CANCELED = 3;
private static final AtomicInteger NEXT_COOKIE = new AtomicInteger();
private final Handler mHandler;
private final Runnable mTask;
private final String mTraceName;
private final int mCookie = NEXT_COOKIE.incrementAndGet();
private final AtomicInteger mState = new AtomicInteger(ENQUEUED);
TracedPost(Handler handler, String traceName, Runnable task) {
mHandler = handler;
mTraceName = traceName;
mTask = task;
}
boolean post() {
Trace.asyncTraceBegin(
Trace.TRACE_TAG_SYSTEM_SERVER, mTraceName, mCookie);
boolean enqueued = mHandler.post(this);
if (!enqueued && mState.compareAndSet(ENQUEUED, CANCELED)) {
endTrace();
}
return enqueued;
}
boolean cancel() {
if (!mState.compareAndSet(ENQUEUED, CANCELED)) {
return false;
}
mHandler.removeCallbacks(this);
endTrace();
return true;
}
@Override
public void run() {
if (!mState.compareAndSet(ENQUEUED, RUNNING)) {
return;
}
try {
mTask.run();
} finally {
mState.set(FINISHED);
endTrace();
}
}
private void endTrace() {
Trace.asyncTraceEnd(
Trace.TRACE_TAG_SYSTEM_SERVER, mTraceName, mCookie);
}
}
这个骨架有四个关键约束:
1. begin 和 end 必须使用同一个 trace name + cookie;
2. 入队失败时立即 end,避免留下永不闭合的 async slice;
3. cancel 与 run 通过状态竞争,只有成功抢到状态的一方负责 end;
4. 这是一次性对象,不能把同一个 TracedPost 重复 post。
如果业务还会通过 removeCallbacksAndMessages() 等外部路径清消息,那些路径也必须进入同一个 cancel() 状态机;否则 async trace 无法知道消息已经被移除。普通 App 可以把 asyncTraceBegin/End + TRACE_TAG_SYSTEM_SERVER 换成公开的 Trace.beginAsyncSection/endAsyncSection,配对规则不变。
如果不方便封装 async trace,至少使用同一个 sequence 记录统一时间基准:
post: seq=1042 caller=Binder:1234_5 target=android.display uptime=123456 result=true
dispatchStart: seq=1042 thread=android.display uptime=123480
dispatchEnd: seq=1042 thread=android.display uptime=123492
这里应使用 SystemClock.uptimeMillis(),与 Message.when 保持同一时间基准。这样即使没有 async slice,也能计算 delivery 和 dispatch 区间,并判断证据缺在哪一段。