TracePlugin 的功能可以说是非常丰富，其中的代码也非常有学习价值。其中的功能包括：主线程卡顿监控，主线程 IdleHandler 耗时监控，Input 事件耗时监控，ANR 监控，FPS 监控，主线程长耗时方法监控和冷热启动耗时监控。
以 TracePlugin#start() 方法作为入口函数分析：
@Override
public void start() {
super.start();
if (!isSupported()) {
MatrixLog.w(TAG, "[start] Plugin is unSupported!");
return;
}
MatrixLog.w(TAG, "start!");
Runnable runnable = new Runnable() {
@Override
public void run() {
if (sdkInt < Build.VERSION_CODES.N && willUiThreadMonitorRunning(traceConfig)) {
if (!UIThreadMonitor.getMonitor().isInit()) {
try {
// 用于监控主线程的 Message 任务和监控 Choreographer 中的任务
UIThreadMonitor.getMonitor().init(traceConfig);
} catch (java.lang.RuntimeException e) {
MatrixLog.e(TAG, "[start] RuntimeException:%s", e);
return;
}
}
}
if (traceConfig.isAppMethodBeatEnable()) {
AppMethodBeat.getInstance().onStart();
} else {
AppMethodBeat.getInstance().forceStop();
}
// 开始主线程 Message 和 Choreographer 中的任务监控
UIThreadMonitor.getMonitor().onStart();
// 卡顿监控
if (traceConfig.isAnrTraceEnable()) {
looperAnrTracer.onStartTrace();
}
// 主线程 IdleHandler 执行耗时监控
if (traceConfig.isIdleHandlerTraceEnable()) {
idleHandlerLagTracer = new IdleHandlerLagTracer(traceConfig);
idleHandlerLagTracer.onStartTrace();
}
// 处理 Input 事件超时监控
if (traceConfig.isTouchEventTraceEnable()) {
touchEventLagTracer = new TouchEventLagTracer(traceConfig);
touchEventLagTracer.onStartTrace();
}
// ANR 监控
if (traceConfig.isSignalAnrTraceEnable()) {
if (!SignalAnrTracer.hasInstance) {
signalAnrTracer = new SignalAnrTracer(traceConfig);
signalAnrTracer.onStartTrace();
}
}
// 掉帧监控
if (traceConfig.isFPSEnable()) {
frameTracer.onStartTrace();
}
// 耗时长的方法监控，在 Gradle 插件中会在需要追踪的方法中开始前调用 com.tencent.matrix.trace.core.AppMethodBeat#i()；
// 方法结束后会调用 com.tencent.matrix.trace.core.AppMethodBeat#o()；这两个方法中都会传入方法对应的 id，这个 id 是 Gradle
// 插件生成的，对应的方法 id 和方法名会生成一个映射文件，编译完成后能够找到这个文件。
// 插件的代码参考：com.tencent.matrix.trace.MethodTracer
if (traceConfig.isEvilMethodTraceEnable()) {
evilMethodTracer.onStartTrace();
}
// 冷热启动耗时监控
if (traceConfig.isStartupEnable()) {
startupTracer.onStartTrace();
}
}
};
if (Thread.currentThread() == Looper.getMainLooper().getThread()) {
runnable.run();
} else {
MatrixLog.w(TAG, "start TracePlugin in Thread[%s] but not in mainThread!", Thread.currentThread().getId());
MatrixHandlerThread.getDefaultMainHandler().post(runnable);
}
}
他的所有功能模块都是继承与 Tracer 抽象类，而每个功能的入口函数就是对应的 onAlive() 方法，这种设计也方便我们去分析他的代码。所以后面的代码分析也是以 Tracer 来分类。
LooperAnrTracer
千万别被这破玩意儿的命名给忽悠了，它只是简单的监控主线程消息的卡顿，并不能监控 ANR，真正的 ANR 监控是 SignalAnrTracer，它也是最简单的 Tracer。它的工作原理就是监控每个主线程的 Message 开始执行前和结束完成，就能够知道单个主线程 Message 的耗时，监控主线程 Message 的耗时是通过 Looper#mLogging 来完成的，每次执行前会调用 mLogging，执行后也会调用 mLogging。通过反射就可以替换成自己的 Logging，这样就知道了主线程每个消息的执行开始前和执行完成后的时间点。
直接看 LooperAnrTracer#onAlive() 方法：
@Override
public void onAlive() {
super.onAlive();
if (isAnrTraceEnable) {
// 监控主线程的 Message 执行
LooperMonitor.register(this);
// ANR 监控 Handler
this.anrHandler = new Handler(MatrixHandlerThread.getDefaultHandler().getLooper());
// 卡顿监控 Handler
this.lagHandler = new Handler(MatrixHandlerThread.getDefaultHandler().getLooper());
}
}
再来分别看看主线程消息执行前和执行完成分别做了哪些处理：
消息执行前：
@Override
public void onDispatchBegin(String log) {
// 标记方法耗时追踪点
anrTask.beginRecord = AppMethodBeat.getInstance().maskIndex("AnrTracer#dispatchBegin");
if (traceConfig.isDevEnv()) {
MatrixLog.v(TAG, "* [dispatchBegin] index:%s", anrTask.beginRecord.index);
}
// 发送 ANR 延时任务，延时 5s
anrHandler.postDelayed(anrTask, Constants.DEFAULT_ANR);
// 发送卡顿延时任务，延时 2s
lagHandler.postDelayed(lagTask, Constants.DEFAULT_NORMAL_LAG);
}
消息执行后：
@Override
public void onDispatchEnd(String log, long beginNs, long endNs) {
if (traceConfig.isDevEnv()) {
long cost = (endNs - beginNs) / Constants.TIME_MILLIS_TO_NANO;
MatrixLog.v(TAG, "[dispatchEnd] beginNs:%s endNs:%s cost:%sms", beginNs, endNs, cost);
}
// 移除方法耗时追踪点
anrTask.getBeginRecord().release();
// 移除 ANR 耗时任务
anrHandler.removeCallbacks(anrTask);
// 移除卡顿耗时任务
lagHandler.removeCallbacks(lagTask);
}
简单来说就是在 Message 开始前添加延时任务，在 Message 结束时移除延时任务，如果没有来得及移除延时任务就表示执行超时了，延时的任务也会执行。卡顿的延时是 2s，ANR 的延时是 5s（当然不能这么暴力地判断 ANR，需要监控 ANR 信号来判断，后面会讲到这部分代码）
再简单看看这两个延时任务：
class AnrHandleTask implements Runnable {
AppMethodBeat.IndexRecord beginRecord;
long token;
// ...
@Override
public void run() {
long curTime = SystemClock.uptimeMillis();
boolean isForeground = isForeground();
// process
// 获取进程状态
int[] processStat = Utils.getProcessPriority(Process.myPid());
// 获取方法耗时数据
long[] data = AppMethodBeat.getInstance().copyData(beginRecord);
beginRecord.release();
// 获取可见的 Activity
String scene = AppActiveMatrixDelegate.INSTANCE.getVisibleScene();
// memory
// 获取内存信息
long[] memoryInfo = dumpMemory();
// Thread state
// 获取主线程状态
Thread.State status = Looper.getMainLooper().getThread().getState();
// Dump 主线程栈信息
String dumpStack;
switch (traceConfig.getLooperPrinterStackStyle()) {
case TraceConfig.STACK_STYLE_WHOLE:
dumpStack = Utils.getWholeStack(Looper.getMainLooper().getThread().getStackTrace(), "|*\t\t");
break;
case TraceConfig.STACK_STYLE_RAW:
dumpStack = Utils.getMainThreadJavaStackTrace();
break;
case TraceConfig.STACK_STYLE_SIMPLE:
default:
dumpStack = Utils.getStack(Looper.getMainLooper().getThread().getStackTrace(), "|*\t\t", 12);
}
// 解析方法栈耗时信息
LinkedList<MethodItem> stack = new LinkedList<>();
if (data.length > 0) {
TraceDataUtils.structuredDataToStack(data, stack, true, curTime);
TraceDataUtils.trimStack(stack, Constants.TARGET_EVIL_METHOD_STACK, new TraceDataUtils.IStructuredDataFilter() {
@Override
public boolean isFilter(long during, int filterCount) {
return during < (long) filterCount * Constants.TIME_UPDATE_CYCLE_MS;
}
@Override
public int getFilterMaxCount() {
return Constants.FILTER_STACK_MAX_COUNT;
}
@Override
public void fallback(List<MethodItem> stack, int size) {
MatrixLog.w(TAG, "[fallback] size:%s targetSize:%s stack:%s", size, Constants.TARGET_EVIL_METHOD_STACK, stack);
Iterator<MethodItem> iterator = stack.listIterator(Math.min(size, Constants.TARGET_EVIL_METHOD_STACK));
while (iterator.hasNext()) {
iterator.next();
iterator.remove();
}
}
});
}
// 后面省略一堆上报的代码..
}
// ...
}
class LagHandleTask implements Runnable {
@Override
public void run() {
// 获取可见 Activity
String scene = AppActiveMatrixDelegate.INSTANCE.getVisibleScene();
// 前后台
boolean isForeground = isForeground();
// 后面省略一堆上报的代码..
}
}
IdleHandlerLagTracer
监控主线程 IdleHandler 超时，它的实现方式是去通过反射替换掉主线程的 MessageQueue#mIdleHandlers 成员变量，它是用来保存 IdleHandler 的集合，替换成自己的集合后就能够监听到所有的 IdleHandler 的添加和移除，所有的添加的 IdleHandler 再用自己定义的类包裹一下，这样就能够知道 IdleHandler 执行前和执行完成，这样就可以计算超时了。
@Override
public void onAlive() {
super.onAlive();
if (traceConfig.isIdleHandlerTraceEnable()) {
// 超时任务处理的 HandlerThread
idleHandlerLagHandlerThread = new HandlerThread("IdleHandlerLagThread");
// 超时任务的 Handler
idleHandlerLagRunnable = new IdleHandlerLagRunable();
// Hook 主线程的 MessageQueue#mIdleHandlers
detectIdleHandler();
}
}
看看 detectIdleHandler() 方法的实现：
private static void detectIdleHandler() {
try {
if (android.os.Build.VERSION.SDK_INT < android.os.Build.VERSION_CODES.M) {
return;
}
// 获取 mIdleHandlers 的 Fields
MessageQueue mainQueue = Looper.getMainLooper().getQueue();
Field field = MessageQueue.class.getDeclaredField("mIdleHandlers");
field.setAccessible(true);
// 替换主线程 MessageQueue#mIdleHandlers
MyArrayList<MessageQueue.IdleHandler> myIdleHandlerArrayList = new MyArrayList<>();
field.set(mainQueue, myIdleHandlerArrayList);
// 开启超时检测的后台线程
idleHandlerLagHandlerThread.start();
idleHandlerLagHandler = new Handler(idleHandlerLagHandlerThread.getLooper());
} catch (Throwable t) {
MatrixLog.e(TAG, "reflect idle handler error = " + t.getMessage());
}
}
看看 MyArrayList 的实现：
static class MyArrayList<T> extends ArrayList {
// 保存 IdleHandler，Key：原始 IdleHandler，Value：替换后的自定义 IdleHandler
Map<MessageQueue.IdleHandler, MyIdleHandler> map = new HashMap<>();
// 添加 IdleHandler
@Override
public boolean add(Object o) {
if (o instanceof MessageQueue.IdleHandler) {
// 将原来的 IdleHandler 用 MyIdleHandler 对象包裹
MyIdleHandler myIdleHandler = new MyIdleHandler((MessageQueue.IdleHandler) o);
map.put((MessageQueue.IdleHandler) o, myIdleHandler);
return super.add(myIdleHandler);
}
return super.add(o);
}
// 移除 IdleHandler
@Override
public boolean remove(@Nullable Object o) {
// 移除 IdleHandler 的时候需要找到对应的 MyIdleHandler，然后移除
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);
}
}
}
再看看 MyIdleHandler 的实现：
static class MyIdleHandler implements MessageQueue.IdleHandler {
// 原来的 IdleHandler
private final MessageQueue.IdleHandler idleHandler;
MyIdleHandler(MessageQueue.IdleHandler idleHandler) {
this.idleHandler = idleHandler;
}
@Override
public boolean queueIdle() {
// 添加延迟任务，默认延迟 2s
idleHandlerLagHandler.postDelayed(idleHandlerLagRunnable, traceConfig.idleHandlerLagThreshold);
// 执行原来的 IdleHandler 任务
boolean ret = this.idleHandler.queueIdle();
// 移除延迟任务
idleHandlerLagHandler.removeCallbacks(idleHandlerLagRunnable);
return ret;
}
}
它的工作方式和检查主线程 Message 卡顿是类似的，任务开始前添加一个延迟任务，任务结束后移除这个延迟任务，如果延迟任务执行了就表示这个 IdleHandler 执行超时了。
继续看超时任务的实现：
static class IdleHandlerLagRunable implements Runnable {
@Override
public void run() {
try {
TracePlugin plugin = Matrix.with().getPluginByClass(TracePlugin.class);
if (null == plugin) {
return;
}
// 获取主线程的栈
String stackTrace = Utils.getMainThreadJavaStackTrace();
// 前后台
boolean currentForeground = AppForegroundUtil.isInterestingToUser();
// 可见的 Activity
String scene = AppActiveMatrixDelegate.INSTANCE.getVisibleScene();
// 省略上报的代码..
} catch (Throwable t) {
MatrixLog.e(TAG, "Matrix error, error = " + t.getMessage());
}
}
}
TouchEventLagTracer
Input 事件卡顿监控，如果对 Input 事件不熟悉的同学强烈建议看看我之前写过的一篇文章：[Framework] 理解 Android 中的 Input 事件。对 Input 事件有过简单的理解后看后续的代码分析就不会困惑。
Android 在创建 Window 的时候会为它生成一对 Socket，服务端由 IMS 持有，工作在 system_server 进程，客户端由应用进程持有。当 IMS 收到 Input 事件后会去找一个正确的 Window 来处理，找到了后就会通过 Socket 服务端发送给客户端。应用进程收到后就去处理，处理完成后也通过 Socket 通知 IMS 表示处理完了，如果通知超时了 5s，那么就会出现 ANR，我们的大部分 ANR 都是 Input 类型的 ANR。
回到正题，如果监控 Input 事件的卡顿呢？Matrix 给出的方案是 Hook 客户端接收 Socket 消息和发送 Socket 消息的方法。接收消息就表示收到了 Input 事件，发送消息就表示 Input 事件处理完成了，如果这个两个时间点间隔过长就表示出现了卡顿。
@Override
public synchronized void onAlive() {
super.onAlive();
if (traceConfig.isTouchEventTraceEnable()) {
// Hook 方法，由 C++ 代码实现
nativeInitTouchEventLagDetective(traceConfig.touchEventLagThreshold);
}
}
static void nativeInitTouchEventLagDetective(JNIEnv *env, jclass, jint threshold) {
// 在添加 Window 的时候，WMS 会为每个 Window 创建一对 Socket，其中服务端由 IMS 持有，客户端通过 Binder 传给应用进程。
// 当 IMS 有 Input 事件需要传递给应用进程，就通过 Socket 传递，应用进程收到 Input 事件后就会做出相应的处理，我们最常见的就是下发至 ViewTree。
// 当应用进程处理完成后还会发送一个消息给 IMS，当这个消息超时到达 IMS 后就会触发 Input 类型的 ANR。
// 下面的代码就是 Hook 应用进程发送 Input 事件处理完成的方法和接收 Input 事件的方法，通过这两个方法就能够计算出处理 Input 事件的耗时。
xhook_grouped_register(HOOK_REQUEST_GROUPID_TOUCH_EVENT_TRACE, ".*libinput\.so$", "__sendto_chk",
(void *) my_sendto, (void **) (&original_sendto));
xhook_grouped_register(HOOK_REQUEST_GROUPID_TOUCH_EVENT_TRACE, ".*libinput\.so$", "sendto",
(void *) my_sendto, (void **) (&original_sendto));
xhook_grouped_register(HOOK_REQUEST_GROUPID_TOUCH_EVENT_TRACE, ".*libinput\.so$", "recvfrom",
(void *) my_recvfrom, (void **) (&original_recvfrom));
xhook_refresh(true);
// 开启一个线程来监听超时处理的 Input 事件
TouchEventTracer::start(threshold);
}
上面就是使用 xhook 替换原来的接收和发送 Input 事件方法，替换后的接收方法是 my_recvfrom()，发送的方法是 my_sendto()。
void TouchEventTracer::start(int threshold) {
LAG_THRESHOLD = threshold / 1000;
loopRunning = true;
thread recvThread = thread(recvQueueLooper);
recvThread.detach();
}
开启一个后台线程来处理超时的 Input 事件，处理的方法是 recvQueueLooper()。这个方法我们等下再看。先看看 my_recvfrom() 方法的实现：
/**
* 接收到 Input 事件的消息
* @param sockfd
* @param buf
* @param len
* @param flags
* @param src_addr
* @param addrlen
* @return
*/
ssize_t my_recvfrom(int sockfd, void *buf, size_t len, int flags,
struct sockaddr *src_addr, socklen_t *addrlen) {
// 每个 Window 的 Socket 的 fd 都是对应的
// 调用原来处理事件的方法
long ret = original_recvfrom(sockfd, buf, len, flags, src_addr, addrlen);
if (currentTouchFd == sockfd && inputHasSent && ret > VALIDATE_RET) {
// 接收到 Input 事件
TouchEventTracer::touchRecv(sockfd);
}
if (currentTouchFd != sockfd) {
// 结束，SocketFd 改变
TouchEventTracer::touchSendFinish(sockfd);
}
if (ret > 0) {
// 标记当前的 Socket Fd
currentTouchFd = sockfd;
} else if (ret == 0) {
// 结束
TouchEventTracer::touchSendFinish(sockfd);
}
return ret;
}
如果各种状态正确，会调用 TouchEventTracer::touchRecv() 方法，表示接收到 Input 事件。
/**
* 收到新的 Input 事件
* @param fd
*/
void TouchEventTracer::touchRecv(int fd) {
currentFd = fd;
lagFd = 0;
if (lagFd == fd) {
// 如果当前还有没有处理的卡顿事件，将时间戳设置为 0
lastRecvTouchEventTimeStamp = 0;
} else {
// 记录接收到事件的时间戳
lastRecvTouchEventTimeStamp = time(nullptr);
// notify 锁
cv.notify_one();
}
}
它主要做两件事情记录当前接收到事件时的时间戳，然后再通过锁通知后台检查线程去检查是否超时。
再看看发送消息的方法：
ssize_t my_sendto(int sockfd, const void *buf, size_t len, int flags,
const struct sockaddr *dest_addr, socklen_t addrlen) {
// 调用原来的发送方法
long ret = original_sendto(sockfd, buf, len, flags, dest_addr, addrlen);
if (ret >= 0) {
inputHasSent = true;
// 处理发送结束
TouchEventTracer::touchSendFinish(sockfd);
}
return ret;
}
/**
* 发送处理 Input 事件结束
* @param fd
*/
void TouchEventTracer::touchSendFinish(int fd) {
if (lagFd == fd) {
// 回调 Java 上报卡顿
reportLag();
}
// 重置卡顿的 FD
lagFd = 0;
// 重置接收 Input 事件的时间戳
lastRecvTouchEventTimeStamp = 0;
// 开始探测设置为 true
startDetect = true;
}
它主要做两件事情，如果有卡顿出现，直接调用 reportLag() 方法上报。还有就是重置一堆状态。
我们再来看看后台检查 Input 事件超时的代码：
void recvQueueLooper() {
unique_lock lk(queueMutex);
while (loopRunning) {
if (lastRecvTouchEventTimeStamp == 0) {
// 没有需要处理的 Input 事件，等锁。
cv.wait(lk);
} else {
long lastRecvTouchEventTimeStampNow = lastRecvTouchEventTimeStamp;
if (lastRecvTouchEventTimeStampNow <= 0) {
// 没有需要处理的 Input 事件，进入下次循环。
continue;
}
if (time(nullptr) - lastRecvTouchEventTimeStampNow >= LAG_THRESHOLD && startDetect) {
// 标记卡顿 FD
lagFd = currentFd;
// 回调 Java 层，获取 StackTrace
onTouchEventLagDumpTrace(currentFd);
cv.wait(lk);
}
}
}
}
它的工作逻辑就是当有 Input 事件来的时候就一直循环检测是否超时，如果超时了回调 Java 层去获取对应的栈信息，然后标记出现了卡顿，然后停止检测，等待下次 Input 事件的出现再去检测，当 Input 事件结束后，就会去检查是否有被标记卡顿，如果有再通知 Java 层上报异常。
所以 Java 层就做两件事情，等待收集栈信息和上报异常，对应的回调方法分别是 onTouchEventLagDumpTrace() 和 onTouchEventLag()。
/**
* Native 调用，发生了 Input 事件卡顿，收集 StackTrace
* @param fd
*/
@Keep
private static void onTouchEventLagDumpTrace(int fd) {
MatrixLog.e(TAG, "onTouchEventLagDumpTrace, fd = " + fd);
currentLagFdStackTrace = Utils.getMainThreadJavaStackTrace();
}
/**
* Native 调用，上报 Input 事件卡顿事件
* @param fd
*/
@Keep
private static void onTouchEventLag(final int fd) {
MatrixLog.e(TAG, "onTouchEventLag, fd = " + fd);
MatrixHandlerThread.getDefaultHandler().post(new Runnable() {
@Override
public void run() {
try {
if (System.currentTimeMillis() - lastLagTime < DEFAULT_TOUCH_EVENT_LAG * 2) {
return;
}
MatrixLog.i(TAG, "onTouchEventLag report");
lastLagTime = System.currentTimeMillis();
TracePlugin plugin = Matrix.with().getPluginByClass(TracePlugin.class);
if (null == plugin) {
return;
}
String stackTrace = currentLagFdStackTrace;
boolean currentForeground = AppForegroundUtil.isInterestingToUser();
String scene = AppActiveMatrixDelegate.INSTANCE.getVisibleScene();
// 省略一堆上报的代码。。
} catch (Throwable t) {
MatrixLog.e(TAG, "Matrix error, error = " + t.getMessage());
}
}
});
}
朴实无华的代码，没有太多要说的，这里再补充一下 Input 事件的卡顿默认上报的时长也是 2s。
最后
不知不觉文章也有点长了，后续的内容等后续文章再分析。
