APM

主线程卡顿监控

方案一、Looper Printer监控每次 dispatchMessage 的执行耗时:

DoKit & BlockCanary & Matrix

滴滴的哆啦A梦的卡顿检测其实就是blockCanary,和Matrix 的EvilMethodTracer和AnrTracer (当然后来Matrix还增加了native的Signal信号监听)使用的 方案也就是Looper设置Printer监听卡顿

都是根据handler原理,通过给Looper.loop() 中设置printer(无论是通过反射替换Looper的mLogging还是通过setMessageLogging设置printer),监控超过 设定阈值(matrix700ms) 的主线程消息(超过5s报为ANR),printer 中判断start和end,来获取主线程dispatch该message的开始和结束时间,并判定该时间超过阈值为主线程卡慢发生,并 打印当时堆栈 + 方法耗时(matrix/dokit)

1
2
3
4
5
6
7
8
9
10
11
12
13
14
15
16
17
18
19
20
21
22
23
24
25
26
27
28
29
30
Looper.loop() {  
for (;;) {
Message msg = queue.next(); // might block
if (msg == null) {
...
// 执行dispatchMessage前,执行Printer的println方法
final Printer logging = me.mLogging;
if (logging != null) {
logging.println(">>>>> Dispatching to " + msg.target + " " +
msg.callback + ": " + msg.what);
}

...

try {
msg.target.dispatchMessage(msg);
dispatchEnd = needEndTime ? SystemClock.uptimeMillis() : 0;
} finally {
...
}

...

// 执行dispatchMessage后,执行Printer的println方法
if (logging != null) {
logging.println("<<<<< Finished to " + msg.target + " " + msg.callback);
}
...
}
}

Matrix:无论是通过反射替换Looper的mLogging还是通过setMessageLogging设置printer,我们只需要替换主线程Looper的printer对象,通过计算执行dispatchMessage方法之后和之前打印字符串的时间的差值,就可以拿到到dispatchMessage方法执行的时间。而大部分的主线程的操作最终都会执行到这个dispatchMessage方法中。

printer监控方案存在问题及解决方案:

简述:一是主线程空闲时message.next()会阻塞并且Touch事件也是执行在next中的natviePollOnce里面的,二是IdleHandler空闲handler的queueIdle回调

Q:

如果排除主线程空闲的情况,究竟会是什么原因会卡在MessageQueuenext方法中呢?下图是next方法简化过后的源码,*frameworks/base/core/java/android/os/MessageQueue.java:*

1
2
3
4
5
6
7
8
9
10
11
12
13
14
15
16
17
18
19
20
21
22
23
24
25
26
27
28
29
30
31
32
33
34
35
for (;;) {
if (nextPollTimeoutMillis != 0) {
Binder.flushPendingCommands();
}

nativePollOnce(ptr, nextPollTimeoutMillis);

//......

// Run the idle handlers.
// We only ever reach this code block during the first iteration.
for (int i = 0; i < pendingIdleHandlerCount; i++) {
final IdleHandler idler = mPendingIdleHandlers[i];
mPendingIdleHandlers[i] = null; // release the reference to the handler

boolean keep = false;
try {
keep = idler.queueIdle();
} catch (Throwable t) {
Log.wtf(TAG, "IdleHandler threw exception", t);
}

if (!keep) {
synchronized (this) {
mIdleHandlers.remove(idler);
}
}
}
//......
}
/*
1. 如果本次循环拿到的Message为空,或者!这个Message是一个延时的消息而且还没到指定的触发时间,那么,就认定当前的队列为空闲状态,
2. 接着就会遍历mPendingIdleHandlers数组(这个数组里面的元素每次都会到mIdleHandlers中去拿)来调用每一个IdleHandler实例的queueIdle方法,
3. 果这个方法返回false的话,那么这个实例就会从mIdleHandlers中移除,也就是当下次队列空闲的时候,不会继续回调它的queueIdle方法了。
*/

因为有些情况的卡顿,这种方案从原理上就无法监控到。看到上面的queue.next(),这里给了注释:might block,直接跟你说这里是可能会卡住的,这时候再计算dispatchMessage方法的耗时显然就没有意义了。有的同学可能会想,那我改成计算相邻两次dispatchMessage执行之前打印字符串的时间差值不就好了?这样就可以把next方法的耗时也计算在内。

1、主线程空闲也就是queue.next()阻塞的时候,同时也是应用的Touch事件。不幸的是,主线程空闲时,也会阻塞在MessageQueuenext方法中,我们很难区分究竟是发生了卡顿还是主线程空闲,除了主线程空闲时就是阻塞在nativePollOnce之外,非常重要的是,应用的Touch事件也是在这里被处理的。这就意味着,View的TouchEvent中的卡顿这种方案是无法监控的。(微信中有大量的自定义View,这些View中充满了各种各样很多的onTouch回调,卡在这里面的情况非常普遍,这种情况的卡顿监控不到是很难接受的)

2、IdleHandler的queueIdle()回调方法。这个方法会在主线程空闲的时候被调用。然而实际上,很多开发同学都先入为主的认为这个时候反正主线程空闲,做一些耗时操作也没所谓。其实主线程MessageQueue的queueIdle默认当然也是执行在主线程中,所以这里的耗时操作其实是很容易引起卡顿和ANR的。(例如微信之前就使用IdleHandler在进入微信的主界面后,做一些读写文件的IO操作,就造成了一些卡顿和ANR问题)

3、SyncBarrier泄露。还有一类相对少见的问题是SyncBarrier(同步屏障)的泄漏同样无法被监控到

A:
A.1. 监控IdleHandler卡顿

首先从简单的下手,对于IdleHandlerqueueIdle回调方法的监控。我们惊喜的发现MessageQueue中的mIdleHandlers是可以被反射的,这个变量保存了所有将要执行的IdleHandler,我们只需要把ArrayList类型的mIdleHandlers,通过反射,替换为MyArrayList,在我们自定义的MyArrayList中重写add方法,再将我们自定义的MyIdleHandler添加到MyArrayList中,就完成了“偷天换日”。从此之后MessageQueue每次执行queueIdle回调方法,都会执行到我们的MyIdleHandler中的的queueIdle方法,就可以在这里监控queueIdle的执行时间了。

1
2
3
4
5
6
7
8
9
10
11
12
13
14
15
16
17
18
19
20
21
22
23
24
25
26
27
28
29
30
31
32
33
34
35
36
37
38
39
40
private static void detectIdleHandler() {
try {
MessageQueue mainQueue = Looper.getMainLooper().getQueue();
Field field = MessageQueue.class.getDeclaredField("mIdleHandlers");
field.setAccessible(true);
MyArrayList<MessageQueue.IdleHandler> myIdleHandlerArrayList = new MyArrayList<>();
field.set(mainQueue, myIdleHandlerArrayList);
} catch (Throwable t) {
t.printStackTrace();
}
}

static class MyArrayList<T> extends ArrayList {
Map<MessageQueue.IdleHandler, MyIdleHandler> map = new HashMap<>();

@Override
public boolean add(Object o) {
if (o instanceof MessageQueue.IdleHandler) {
MyIdleHandler myIdleHandler = new MyIdleHandler((MessageQueue.IdleHandler) o);
map.put((MessageQueue.IdleHandler) o, myIdleHandler);
return super.add(myIdleHandler);
}
return super.add(o);
}

@Override
public boolean remove(@Nullable Object o) {
if (o instanceof MyIdleHandler) {
MessageQueue.IdleHandler idleHandler = ((MyIdleHandler) o).idleHandler;
map.remove(idleHandler);
return super.remove(o);
} else {
MyIdleHandler myIdleHandler = map.remove(o);
if (myIdleHandler != null) {
return super.remove(myIdleHandler);
}
return super.remove(o);
}
}
}
A.2. 监控TouchEvent卡顿

那么TouchEvent我们有什么办法监控吗?首先想到的可能是反射View的mListenerInfo,然后进一步替换其中的mTouchListenr,但是这需要我们枚举所有需要被监控的View,全部反射替换一遍,这完全是憨憨行为。那有没有更加根本,全局性的方法呢?

熟悉input系统的同学应该知道,Touch事件最终是通过server端的InputDispatcher线程传递给Client端的UI线程的,并且使用的是一对Socket进行通讯的。我们可以通过PLT Hook,去Hook这对Socket的send和recv方法来监控Touch事件啊!我们先捋一下一次Touch事件的处理过程:

图片

我们通过PLT Hook,成功hook到libinput.so中的recvfromsendto方法,使用我们自己的方法进行替换。当调用到了recvfrom时,说明我们的应用接收到了Touch事件,当调用到了sendto时,说明这个Touch事件已经被成功消费掉了,当两者的时间相差过大时即说明产生了一次Touch事件的卡顿。这种方案经过验证是可行的!

A.3. 监控SyncBarrier泄漏

最后,SyncBarrier泄漏的问题,有什么好办法能监控到吗?目前我们的方案是不断轮询主线程LooperMessageQueuemMessage(也就是主线程当前正在处理的Message)。而SyncBarrier本身也是一种特殊的Message,其特殊在它的target是null。如果我们通过反射mMessage,发现当前的Message的target为null,并且通过这个Message的when发现其已经存在很久了,这个时候我们合理怀疑产生了SyncBarrier的泄漏(但还不能完全确定,因为如果当时因为其他原因导致主线程卡死,也可能会导致这种现象),然后再发送一个同步消息和一个异步消息,如果异步消息被处理了,但是同步消息一直无法被处理,这时候就说明产生了SyncBarrier的泄漏。如果激进一些,这个时候我们甚至可以反射调用*MessageQueue*的*removeSyncBarrier*方法,手动把这个SyncBarrier移除掉,从而从错误状态中恢复

坏消息是,这种方案只能监控到问题的产生,也可以直接解决问题,但是无法溯源问题究竟是哪个View导致的。其实我们也尝试过,通过插桩或者Java hook的方法,监控invalidate方法是否在非主线程中进行,但是考虑到风险以及对性能影响都比较大,没有在线上使用。所幸,通过监控发现,这个问题对我们来说,发生的概率并不高。如果发现某个场景下该问题确实较为严重,可以考虑使用插桩或者Java hook在测试环境下debug该问题。

方案二、依赖 Choreographer 模块,监控相邻两次 Vsync 事件通知的时间差

利用系统 Choreographer 模块,向该模块注册一个 FrameCallback 监听对象,同时通过另外一条线程循环记录主线程堆栈信息,并在每次 Vsync 事件 doFrame 通知回来时,循环注册该监听对象,间接统计两次 Vsync 事件的时间间隔,当超出阈值时,取出记录的堆栈进行分析上报。

1
2
3
4
5
6
7
8
9
10
Choreographer.getInstance().postFrameCallback(new Choreographer.FrameCallback() {
@Override
public void doFrame(long frameTimeNanos) {
if(frameTimeNanos - mLastFrameNanos > 100) {
...
}
mLastFrameNanos = frameTimeNanos;
Choreographer.getInstance().postFrameCallback(this);
}
});

卡顿发生时堆栈的收集

BlocakCanary:在执行前利用另外一条线程,通过 Thread#getStackTrace 接口,以轮询的方式获取主线程执行堆栈信息并记录起来,同时统计每次 dispatchMessage 方法执行耗时,当超出阈值时,将该次获取的堆栈进行分析上报,从而来捕捉卡顿信息,否则丢弃此次记录的堆栈信息。

Matrix:根据编译期插桩记录函数耗时,在卡顿发生时获取之前一段时间的函数进行归堆,性能更佳,

不仅在编译期时对特殊无需插桩函数排除(方法字节码中是否只包含PUT/READ FIELD等简单指令、默认或匿名构造函数)、插桩函数用ID映射

还在运行期时用long[]数组记录函数id和函数函数,极大程度的减少占用内存、另一个线程每5ms更新时间减少调用System.nanoTime的耗时

Dokit:也是插桩,但优化不细。

函数耗时统计:

DoKit:上面说的插桩

Matrix:上面说的插桩

一些细节上的区别:

Author

white crow

Posted on

2021-10-19

Updated on

2024-03-25

Licensed under