微信Android客户端的卡顿监控方案
文章开始，先聊一聊卡顿与ANR的关系：产生卡顿的根本原因是UI线程不能够及时的进行渲染，导致UI的反馈不能按照用户的预期，连续、一致的呈现。产生卡顿的原因多种多样，很难一一列举，而ANR是Google人为规定的概念，产生ANR的原因最多也只有四个。
一方面，两者息息相关，事实上，长时间的UI卡顿是导致ANR最常见的原因；但另一方面，从原理上来看，两者既不充分也不必要，是两个维度的概念。
而市面上的一些卡顿监控工具，经常被拿来监控ANR（卡顿阈值设置为5秒），这其实很不严谨：首先，5秒只是发生ANR的其中一种原因（Touch事件5秒未被及时消费）的阈值，而其他原因发生ANR的阈值并不是5秒；另外，就算是主线程卡顿了5秒，如果用户没有输入任何的Touch事件，同样是不会发生ANR的，更何况还有后台ANR等情况。所以使用包括下文提到的卡顿监控方案，来监控ANR都是不准确的，真正意义上的ANR监控方案下一篇文章会详细讨论。
一、WatchDog
这种方案的本质是开启一个子线程不断轮询UI线程，这是最容易理解，最简单粗暴的方法。这种方法甚至具有一定的普适性，iOS或者其他的客户端系统，都可以用类似的思路来监控卡顿。具体的原理和实现方法很简单：不断向UI线程发送Message，每隔一段时间检查一次刚刚发送的Message是否被处理，如果没有被处理，则说明这段时间主线程被卡住了。这种方案在一些著名的APM上有使用，微信几年前也使用过这种方案。
- 优点：简单，稳定，结果论，可以监控到各种类型的卡顿
- 缺点：轮询不优雅，不环保，有不确定性，随机漏报，
这种方法的轮询的时间间隔选择很重要，又让人左右为难，轮询的时间间隔越小，对性能的负面影响就越大，而时间间隔选择的越大，漏报的可能性也就越大。前者很容易理解，UI线程要不断处理我们发送的Message，必然会影响性能和功耗。而随机漏报的问题比较有趣，可以稍微展开聊聊。
以我们微信自己之前的方案为例，时间间隔选择了4.5秒（事实上，之前是想要通过这种方案来监控ANR，当然，上面提到过，这并不严谨），简单画个图：
每隔4.5秒，向主线程发送一个消息。现在有一个5秒的卡顿（红线部分）发生在第2秒，结束在第7秒，这种情况无论是在0-4.5秒的周期内，还是4.5-9秒的周期内，都有一段时间是不卡顿的，消息都可以被处理掉，这种情况自然就无法被监控到。如果有兴趣，我们甚至可以算出一个概率：
其中x代表卡顿的时间，a代表设置的轮询间隔，可以计算出来：如果轮询间隔设置为4.5秒，发现一个5秒的卡顿的概率仅为20%。有的开源库例如ANR-WatchDog，默认轮询间隔为5秒，如果有一个8秒的卡顿（8秒已经很容易产生ANR），被发现的概率也只有8/5-1=60%。另外从这个概率公式还可以发现，对于一个固定的轮询间隔，只有卡顿时间大于两倍的轮询间隔，才能百分之百被监控到，例如想要百分之百监控到4秒以上的卡顿，轮询间隔必须要设置成2秒或者更短。
如果不断缩小轮询的间隔呢？我们所知的有些方案，是用更短的轮询时间，连续几个周期消息都没被处理才视为一次卡顿，例如：每2秒轮询一次，如果连续三次消息都没被处理，则认为发生了卡顿，这种方案我们可以再画个图：
这种情况其实是第一种情况的更一般的情况，我们同样可以算出一个概率：
其中x代表卡顿的时间，a代表设置的轮询间隔，c表示连续几次周期没处理消息才认为发生了卡顿。再举个例子：如果设置轮询间隔为2秒，连续3次没处理消息就认为发生了卡顿，那么对于7秒的卡顿，被监控到的概率为7/2-3=33.3%。
我们可以写一段测试程序，模拟上面那些情况，尝试不断在随机的时间点触发一次sleep，检查是否监控到了卡顿。结果基本上大概进行十次左右，实验得出的频率就很常接近公式算出的概率了。
二、Looper Printer
替换主线程Looper的Printer，从而监控dispatchMessage的执行时间。这方案也比较常见，微信本身（Matrix）也在线上也使用了这种方案，而且已经稳定运行了很长时间。我们之前也了解到，手Q的Android客户端也在使用这种方案。
（甚至，在Android源码中，主线程Looper也会根据执行dispatchMessage的时间来判断是否有卡顿，有则会打印一些日志）
- 优点：不会随机漏报，无需轮询，一劳永逸
- 缺点：某些类型的卡顿无法被监控到
其原理也很容易理解，以下是Looper的部分关键代码，frameworks/base/core/java/android/os/Looper.java:
for (;;) {
Message msg = queue.next(); // might block
// This must be in a local variable, in case a UI event sets the logger
final Printer logging = me.mLogging;
if (logging != null) {
logging.println(">>>>> Dispatching to " + msg.target + " " +
msg.callback + ": " + msg.what);
}
msg.target.dispatchMessage(msg);
if (logging != null) {
logging.println("<<<<< Finished to " + msg.target + " " + msg.callback);
}
}无论是通过反射替换Looper的mLogging还是通过setMessageLogging设置printer，我们只需要替换主线程Looper的printer对象，通过计算执行dispatchMessage方法之后和之前打印字符串的时间的差值，就可以拿到到dispatchMessage方法执行的时间。而大部分的主线程的操作最终都会执行到这个dispatchMessage方法中。
为什么说是大部分？因为有些情况的卡顿，这种方案从原理上就无法监控到。看到上面的queue.next()，这里给了注释：might block，直接跟你说这里是可能会卡住的，这时候再计算dispatchMessage方法的耗时显然就没有意义了。有的同学可能会想，那我改成计算相邻两次dispatchMessage执行之前打印字符串的时间差值不就好了？这样就可以把next方法的耗时也计算在内。不幸的是，主线程空闲时，也会阻塞在MessageQueue的next方法中，我们很难区分究竟是发生了卡顿还是主线程空闲。
如果排除主线程空闲的情况，究竟会是什么原因会卡在MessageQueue的next方法中呢？下图是next方法简化过后的源码，frameworks/base/core/java/android/os/MessageQueue.java:
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);
}
}
}
//......
}除了主线程空闲时就是阻塞在nativePollOnce之外，非常重要的是，应用的Touch事件也是在这里被处理的。这就意味着，View的TouchEvent中的卡顿这种方案是无法监控的。然而，对于我们来说，微信中有大量的自定义View，这些View中充满了各种各样很多的onTouch回调，卡在这里面的情况非常普遍，这种情况的卡顿监控不到是很难接受的。
另外一种常见的情况是*IdleHandler***的queueIdle()回调方法也是无法被监控的，这个方法会在主线程空闲的时候被调用。然而实际上，很多开发同学都先入为主的认为这个时候反正主线程空闲，做一些耗时操作也没所谓。其实主线程MessageQueue的queueIdle默认当然也是执行在主线程中*，所以这里的耗时操作其实是很容易引起卡顿和ANR的。例如微信之前就使用IdleHandler*在进入微信的主界面后，做一些读写文件的IO操作，就造成了一些卡顿和ANR问题。
还有一类相对少见的问题是SyncBarrier（同步屏障）的泄漏同样无法被监控到，当我们每次通过invalidate来刷新UI时，最终都会调用到ViewRootImpl中的scheduleTraversals方法，会向主线程的Looper中post一个SyncBarrier，其目的是为了在刷新UI时，主线程的同步消息都被跳过，此时渲染UI的异步消息就可以得到优先处理。但是我们注意到这个方法是线程不安全的，如果在非主线程中调用到了这里，就有可能会同时post多个SyncBarrier，但只能remove掉最后一个，从而有一个SyncBarrier就永远无法被remove，就导致了主线程Looper无法处理同步消息（Message默认就是同步消息），导致卡死，参考源码frameworks/base/core/java/android/view/ViewRootImpl.java:
void scheduleTraversals() {
if (!mTraversalScheduled) {
mTraversalScheduled = true;
mTraversalBarrier = mHandler.getLooper().getQueue().postSyncBarrier();
mChoreographer.postCallback(
Choreographer.CALLBACK_TRAVERSAL, mTraversalRunnable, null);
notifyRendererOfFramePending();
pokeDrawLockIfNeeded();
}
}
void unscheduleTraversals() {
if (mTraversalScheduled) {
mTraversalScheduled = false;
mHandler.getLooper().getQueue().removeSyncBarrier(mTraversalBarrier);
mChoreographer.removeCallbacks(
Choreographer.CALLBACK_TRAVERSAL, mTraversalRunnable, null);
}
}我们认为Looper Printer方案总体还是比较理想的，那么，既然该方案监控不到这三种卡顿的情况，我们想能不能通过其他的一些手段，专门监控这些卡顿的case呢？下面分别针对这三种情况，提出了三种对应的监控方法。
三、完善卡顿监控方案
3.1. 监控IdleHandler卡顿
首先从简单的下手，对于IdleHandler的queueIdle回调方法的监控。我们惊喜的发现MessageQueue中的mIdleHandlers是可以被反射的，这个变量保存了所有将要执行的IdleHandler，我们只需要把ArrayList类型的mIdleHandlers，通过反射，替换为MyArrayList，在我们自定义的MyArrayList中重写add方法，再将我们自定义的MyIdleHandler添加到MyArrayList中，就完成了“偷天换日”。从此之后MessageQueue每次执行queueIdle回调方法，都会执行到我们的MyIdleHandler中的的queueIdle方法，就可以在这里监控queueIdle的执行时间了。
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);
}
}
}3.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中的recvfrom和sendto方法，使用我们自己的方法进行替换。当调用到了recvfrom时，说明我们的应用接收到了Touch事件，当调用到了sendto时，说明这个Touch事件已经被成功消费掉了，当两者的时间相差过大时即说明产生了一次Touch事件的卡顿。这种方案经过验证是可行的！
3.3. 监控SyncBarrier泄漏
最后，SyncBarrier泄漏的问题，有什么好办法能监控到吗？目前我们的方案是不断轮询主线程Looper的MessageQueue的mMessage(也就是主线程当前正在处理的Message)。而SyncBarrier本身也是一种特殊的Message，其特殊在它的target是null。如果我们通过反射mMessage，发现当前的Message的target为null，并且通过这个Message的when发现其已经存在很久了，这个时候我们合理怀疑产生了SyncBarrier的泄漏（但还不能完全确定，因为如果当时因为其他原因导致主线程卡死，也可能会导致这种现象），然后再发送一个同步消息和一个异步消息，如果异步消息被处理了，但是同步消息一直无法被处理，这时候就说明产生了SyncBarrier的泄漏。如果激进一些，这个时候我们甚至可以反射调用MessageQueue的removeSyncBarrier方法，手动把这个SyncBarrier移除掉，从而从错误状态中恢复。下面代码展示了大概的原理：
MessageQueue mainQueue = Looper.getMainLooper().getQueue();
Field field = mainQueue.getClass().getDeclaredField("mMessages");
field.setAccessible(true);
Message mMessage = (Message) field.get(mainQueue); //通过反射得到当前正在等待执行的Message
if (mMessage != null) {
currentMessageToString = mMessage.toString();
long when = mMessage.getWhen() - SystemClock.uptimeMillis();
if (when < -3000 && mMessage.getTarget() == null) { //target == null则为sync barrier
int token = mMessage.arg1;
startCheckLeaking(token);
}
}
private static void startCheckLeaking(int token) {
int checkCount = 0;
barrierCount = 0;
while (checkCount < CHECK_STRICTLY_MAX_COUNT) {
checkCount++;
int latestToken = getSyncBarrierToken();
if (token != latestToken) { //token变了，不是同一个barrier，return
break;
}
if (DetectSyncBarrierOnce()) {
//发生了sync barrier泄漏
removeSyncBarrier(token); //手动remove泄漏的sync barrier
break;
}
try {
Thread.sleep(1000);
} catch (InterruptedException e) {
e.printStackTrace();
}
}
}
private static void removeSyncBarrier(int token) {
MessageQueue mainQueue = Looper.getMainLooper().getQueue();
Method method = mainQueue.getClass().getDeclaredMethod("removeSyncBarrier", int.class);
method.setAccessible(true);
method.invoke(mainQueue, token);
}
private static boolean DetectSyncBarrierOnce() {
Handler mainHandler = new Handler(Looper.getMainLooper()) {
@Override
public void handleMessage(Message msg) {
super.handleMessage(msg);
if (msg.arg1 == 0) {
barrierCount ++; //收到了异步消息，count++
} else if (msg.arg1 == 1) {
barrierCount = 0; //收到了同步消息，说明同步屏障不在, count设置为0
}
}
};
Message asyncMessage = Message.obtain();
asyncMessage.setAsynchronous(true);
asyncMessage.setTarget(mainHandler);
asyncMessage.arg1 = 0;
Message syncNormalMessage = Message.obtain();
syncNormalMessage.arg1 = 1;
mainHandler.sendMessage(asyncMessage); //发送一个异步消息
mainHandler.sendMessage(syncNormalMessage); //发送一个同步消息
if(barrierCount > 3){
return true;
}
return false;
}坏消息是，这种方案只能监控到问题的产生，也可以直接解决问题，但是无法溯源问题究竟是哪个View导致的。其实我们也尝试过，通过插桩或者Java hook的方法，监控invalidate方法是否在非主线程中进行，但是考虑到风险以及对性能影响都比较大，没有在线上使用。所幸，通过监控发现，这个问题对我们来说，发生的概率并不高。如果发现某个场景下该问题确实较为严重，可以考虑使用插桩或者Java hook在测试环境下debug该问题。
以上，针对Looper Printer监控卡顿的方案无法监控到的三类问题，分别都提出了对应的监控方案。如此以来，就得到了一套比较完整的卡顿监控方案。
如果有任何问题和建议欢迎大家评论。之后的一篇文章会仔细讨论ANR的监控方案。