Android性能优化系列-腾讯matrix卡顿优化之AppMethodBeat专项分析
前言
全文约4000字,深度阅读大约需要20分钟,请合理安排时间。本文主要分析AppMethodBeat这个类,AppMethodBeat是TracePlguin运行的基石,理解了此类,对后边分析其他类型的tracer至关重要。
AppMethodBeat.getInstance().copyData()做了什么,什么逻辑?
BeatLifecycle
AppMethodBeat实现了接口BeatLifecycle,BeatLifecycle定义了三个方法onStart、onStop、isAlive,可见其也是有生命周期的。
public interface BeatLifecycle {
void onStart();
void onStop();
boolean isAlive();
}
AppMethodBeat.getInstance().onStart();
AppMethodBeat.getInstance().onStop();
看到这里,很自然的想到,onStart就是AppMethodBeat最早执行的逻辑,我们以它作为入口来深入源码即可。但其实不是这样,我们看下onStart。
@Override
public void onStart() {
synchronized (statusLock) {
//status默认值是大于STATUS_STARTED的,所以这里的逻辑不会执行????
if (status < STATUS_STARTED && status >= STATUS_EXPIRED_START) {
...
} else {
MatrixLog.w(TAG, "[onStart] current status:%s", status);
}
}
}
AppMethodBeat
经过上边的简单分析,我们大概罗列一下AppMethodBeat几个关键的方法:i、o、onStart、onStop,其他方法也会分析到,如maskIndex、copyData这几个方法尤其是重中之重,会作为我们看源码的突破口。
i方法
public static void i(int methodId) {
if (status == STATUS_DEFAULT) {
synchronized (statusLock) {
if (status == STATUS_DEFAULT) {
realExecute();
status = STATUS_READY;
}
}
}
if (threadId == sMainThreadId) {
if (assertIn) {
return;
}
assertIn = true;
if (sIndex < Constants.BUFFER_SIZE) {
mergeData(methodId, sIndex, true);
} else {
sIndex = 0;
mergeData(methodId, sIndex, true);
}
++sIndex;
assertIn = false;
}
}
上边源码中有两个关键点,一是realExecute,一是mergeData。
realExecute
realExecute被status状态变量控制,只会执行一次。realExecute执行后,状态值status被切换为STATUS_READY,此时便满足了onStart方法执行的条件,前边的疑问就确认了,i方法执行后onStart才能真正执行。
private static void realExecute() {
sHandler.removeCallbacksAndMessages(null);
//第一部分
sHandler.postDelayed(sUpdateDiffTimeRunnable, Constants.TIME_UPDATE_CYCLE_MS);
//第二部分
sHandler.postDelayed(checkStartExpiredRunnable = new Runnable() {
@Override
public void run() {
synchronized (statusLock) {
if (status == STATUS_DEFAULT || status == STATUS_READY) {
status = STATUS_EXPIRED_START;
}
}
}
}, Constants.DEFAULT_RELEASE_BUFFER_DELAY);
//第三部分
ActivityThreadHacker.hackSysHandlerCallback();
//第四部分
LooperMonitor.register(looperMonitorListener);
}
realExecute方法内部可以分为四步,接下来我们一步一步来读下源码。
sUpdateDiffTimeRunnable
sUpdateDiffTimeRunnable是一个循环线程,用来每隔5ms(不包含消息队列休眠期间)更新一次sCurrentDiffTime值。sCurrentDiffTime是一个时间间隔,如10:20:15到10:20:20中间间隔了5s时间,sCurrentDiffTime代表的就是这个差值,用来记录方法执行的耗时。
但是,为什么要这么做呢?
如果仅仅是记录方法耗时,直接在方法首尾记录时间戳然后做差值即可;另外每隔5ms去更新一次时间,那么就必然存在5ms的误差。
其实matrix作为一个性能优化工具,基本原则就是尽可能的降低工具本身对性能的影响。在方法首尾执行SystemClock.uptimeMillis()当然可以,但是当它在几十万个方法首尾都去执行这个操作的时候,对性能的影响就会被明显的放大,所以matrix采用了循环线程的方式更新时间间隔,并且5ms的误差对于耗时分析来说,可忽略。
private static Runnable sUpdateDiffTimeRunnable = new Runnable() {
@Override
public void run() {
while (true) {
//可以看到这里循环更新时间还有个条件,我们看看isPauseUpdateTime是什么
while (!isPauseUpdateTime && status > STATUS_STOPPED) {
sCurrentDiffTime = SystemClock.uptimeMillis() - sDiffTime; SystemClock.sleep(Constants.TIME_UPDATE_CYCLE_MS);
}
//不满足上边条件的时候会进入挂起状态,等待唤醒,那么来唤醒的是谁,这个比较关键
synchronized (updateTimeLock) {
updateTimeLock.wait();
}
}
}
};
搜索isPauseUpdateTime找到这里。dispatchBegin和dispatchEnd是LooperMonitor提供的两个回调,分别代表主线程每个消息被执行前和执行完成后的一个时机。那么LooperMonitor具体的实现逻辑是怎样的?这个问题后边会单独分析。
private static void dispatchBegin() {
sCurrentDiffTime = SystemClock.uptimeMillis() - sDiffTime;
//更新为false,满足循环条件
isPauseUpdateTime = false;
//开始执行时唤醒循环线程继续更新时间
synchronized (updateTimeLock) {
updateTimeLock.notify();
}
}
private static void dispatchEnd() {
//更新为true,循环停止,进入挂起状态
isPauseUpdateTime = true;
}
从上边可知,sUpdateDiffTimeRunnable循环线程并非一直在运行,当主线程当前消息执行完,下一个消息尚未执行期间,sUpdateDiffTimeRunnable进入了挂起状态,减少对cpu的占用。
checkStartExpiredRunnable
从命名上可以看出,这是一个超时线程。realExecute方法只会执行一次,并且是i方法第一次调用时执行,那么也就是说,i方法调用10s后,假如status状态仍然是STATUS_DEFAULT或者STATUS_READY的情况下,就认为是超时了,将status更新为STATUS_EXPIRED_START状态。
sHandler.postDelayed(checkStartExpiredRunnable = new Runnable() {
@Override
public void run() {
synchronized (statusLock) {
MatrixLog.i(TAG, "[startExpired] timestamp:%s status:%s", System.currentTimeMillis(), status);
if (status == STATUS_DEFAULT || status == STATUS_READY) {
status = STATUS_EXPIRED_START;
}
}
}
}, Constants.DEFAULT_RELEASE_BUFFER_DELAY);
那么status状态什么时候才会被更新? 我们可以提前看一下onStart方法,当onStart被调用后,status就会被更新为STATUS_STARTED状态,而AppBeatMethod的onStart又是在TracePlugin的start方法中调用的。所以这就要求在应用启动10s内启动TracePlugin,这样一来,AppBeatMethod的功能才会正常使用,假如用户没有开启TracePlugin,那么AppBeatMethod就会自动将status切换为STATUS_EXPIRED_START。
status切换为STATUS_EXPIRED_START之后会怎样?
- LooperMonitor不会再工作
- sUpdateDiffTimeRunnable不会再更新时间
- AppBeatMethod生命周期进入非存活状态
- i、o方法不会再执行
而要打破这种状态,就要再次调用AppBeatMethod的onStart方法,使生命周期开始运行。
而从本文的分析结果可知,AppBeatMethod的生命周期是被TracePlugin控制的,只有TracePlugin才能真正意义上的启动AppBeatMethod。这样以来就稍显复杂了,AppBeatMethod的i、o等方法被外部大量调用,TracePlugin要真正做到控制AppBeatMethod,就只能为AppBeatMethod的运行附加条件了,这个条件就是TracePlugin要先运行,AppBeatMethod的内部逻辑才能执行,否则原路返回。
ActivityThreadHacker.hackSysHandlerCallback()
LooperMonitor.register(looperMonitorListener)
LooperMonitor是matrix中卡顿监控逻辑中一个很重要的类,它通过给主线程Looper设置Printer的方式来拿到主线程每一条message处理前后的回调,从而让我们可以借此来分析每条message执行的耗时情况。详细逻辑后边会单独进行专项分析,这里先有个印象。
public void setMessageLogging(@Nullable Printer printer) {
mLogging = printer;
}
调用register注册后,AppBeatMethod就可以拿到这两个关键方法的回调。
private static LooperMonitor.LooperDispatchListener looperMonitorListener = new LooperMonitor.LooperDispatchListener() {
@Override
public boolean isValid() {
return status >= STATUS_READY;
}
@Override
public void dispatchStart() {
super.dispatchStart();
AppMethodBeat.dispatchBegin();
}
@Override
public void dispatchEnd() {
super.dispatchEnd();
AppMethodBeat.dispatchEnd();
}
};
注意,接下来的内容很重要
存:mergeData
realExecute()在i方法中只会执行一次,所以i方法的关键在于后边的mergeData,接下来我们看下mergeData在做什么。
//只在主线程执行,所以插桩只对主线程方法有效
if (threadId == sMainThreadId) {
if (assertIn) {
return;
}
assertIn = true;
//容量限制,这里是最多存储100万条数据,大约占用7.6M内存
if (sIndex < Constants.BUFFER_SIZE) {
mergeData(methodId, sIndex, true);
} else {
sIndex = 0;
mergeData(methodId, sIndex, true);
}
++sIndex;
assertIn = false;
}
在主线程的message执行前后都会主动调用一次methodId为METHOD_ID_DISPATCH的i和o方法,可自行搜索,于是在mergeData中,当methodId为METHOD_ID_DISPATCH时就会主动更新当前的时间偏移量。
mergeData顾名思义,就是将数据组装起来,而这里要做的就是将methodId、in or out、方法耗时这三项信息组装成一个long, long有64位二进制位,0-42位来存储时间戳偏移量,43-62位存储方法id,最高位用来存储方法的in or out, 这样一来,一个long变量就存储了三条信息,大大降低了内存占用。
见下图(来自官方):
注:methodId是编译期生成的一个从0开始递增的值,所以你看到的methodId应该是0,1,2,3...,这些数字,而编译期会将方法id值和方法名映射生成到一个文件中,用于后期解析出方法名。
private static void mergeData(int methodId, int index, boolean isIn) {
if (methodId == AppMethodBeat.METHOD_ID_DISPATCH) {
sCurrentDiffTime = SystemClock.uptimeMillis() - sDiffTime;
}
try {
//0表示退出方法,1表示进入方法
//进入和退出的标记放在long类型的最高位
long trueId = 0L;
if (isIn) {
trueId |= 1L << 63;
}
//存储方法id
trueId |= (long) methodId << 43;
//存储时间偏移
trueId |= sCurrentDiffTime & 0x7FFFFFFFFFFL;
//存入数组
sBuffer[index] = trueId;
//清理无效数据?
checkPileup(index);
sLastIndex = index;
} catch (Throwable t) {
MatrixLog.e(TAG, t.getMessage());
}
}
上边有一个操作checkPileup,它是在做什么?
首先我们要了解一下方法信息是怎么存储的,每个方法的id、耗时信息组合成一个long之后,被放入容量大小为100万的long类型数组中,也正因为数组的极限是100万,所以当数据存储量超过100万之后,数组下标会从0重新开始计算,此时再次存入的数据就会覆盖掉老的数据,所以就要将老数据标记为无效。
private static void checkPileup(int index) {
IndexRecord indexRecord = sIndexRecordHead;
while (indexRecord != null) {
if (indexRecord.index == index || (indexRecord.index == -1 && sLastIndex == Constants.BUFFER_SIZE - 1)) {
indexRecord.isValid = false;
MatrixLog.w(TAG, "[checkPileup] %s", indexRecord.toString());
sIndexRecordHead = indexRecord = indexRecord.next;
} else {
break;
}
}
}
标记:maskIndex
而这个标记无效的操作并非针对数组,而是针对链表,突然又冒出来一个链表,我们分析了这么久,也没看到有链表,这个链表是哪来的?我们搜索sIndexRecordHead的引用位置,找到maskIndex方法,在这个方法中会首次对链表进行初始化。
public IndexRecord maskIndex(String source) {
if (sIndexRecordHead == null) {
sIndexRecordHead = new IndexRecord(sIndex - 1);
sIndexRecordHead.source = source;
return sIndexRecordHead;
} else {
IndexRecord indexRecord = new IndexRecord(sIndex - 1);
indexRecord.source = source;
IndexRecord record = sIndexRecordHead;
IndexRecord last = null;
while (record != null) {
if (indexRecord.index <= record.index) {
if (null == last) {
IndexRecord tmp = sIndexRecordHead;
sIndexRecordHead = indexRecord;
indexRecord.next = tmp;
} else {
IndexRecord tmp = last.next;
last.next = indexRecord;
indexRecord.next = tmp;
}
return indexRecord;
}
last = record;
record = record.next;
}
last.next = indexRecord;
return indexRecord;
}
}
sIndexRecordHead是一个链表的头节点,这个链接按照index值排序,小在前,大在后。我们在分析ActivityThreadHacker实现原理时,源码中有一行调用,传递一个字符串标记进来,假如此时链表为空,那么就会将这个标记source以及当前执行到的方法的index封装为一个IndexRecord对象,并将其作为头节点;假如此时头节点已经存在,则将新的IndexRecord插入到链表中,以index大小为排序的依据。
sApplicationCreateBeginMethodIndex = AppMethodBeat.getInstance().maskIndex("ApplicationCreateBeginMethodIndex");
注意看这里封装了index和source,index是什么,它是当前执行到的方法信息在sBuffer数组中的位置,也就是说,这个操作是将source标记和当前执行的方法做了映射,那么调用maskIndex其实就是标记了当前方法执行到哪了,我们就可以根据这个index拿到一段时间内的所有方法执行的信息。举个例子,假如发现某个方法很耗时,那么就可以从数组中拿出方法执行前后一段时间内所有方法执行的耗时信息。相当于回溯,非常方便。
取:copyData
copyData和maskIndex是成对出现的,因为本身标记的目的就是为了后边取出被标记处到当前时间的方法运行信息,copyData传入的IndexRecord就是maskIndex的返回值,将这个值作为起点,当前index作为终点,一起继续往下传递。
public long[] copyData(IndexRecord startRecord) {
return copyData(startRecord, new IndexRecord(sIndex - 1));
}
这里的逻辑也很清晰,从传入的起点startRecord和终点endRecord中取出两个index,从sBuffer中拷贝出两个index之间的方法信息,存入到一个新的data数组中返回。这样一来,外界就可以拿到指定区间内的方法运行信息了。
private long[] copyData(IndexRecord startRecord, IndexRecord endRecord) {
long current = System.currentTimeMillis();
long[] data = new long[0];
try {
if (startRecord.isValid && endRecord.isValid) {
int length;
int start = Math.max(0, startRecord.index);
int end = Math.max(0, endRecord.index);
if (end > start) {
//正常情况下end大于start,直接拷贝start-end之间的数据
length = end - start + 1;
data = new long[length];
System.arraycopy(sBuffer, start, data, 0, length);
} else if (end < start) {
//end小于start,说明方法数超过100万,index又从0开始,计算
//那么要拷贝的就是从start到数组末尾+0到end之间的数据
length = 1 + end + (sBuffer.length - start);
data = new long[length];
System.arraycopy(sBuffer, start, data, 0, sBuffer.length - start);
System.arraycopy(sBuffer, 0, data, sBuffer.length - start, end + 1);
}
return data;
}
return data;
} catch (Throwable t) {
MatrixLog.e(TAG, t.toString());
return data;
} finally {
MatrixLog.i(TAG, "[copyData] [%s:%s] length:%s cost:%sms", Math.max(0, startRecord.index), endRecord.index, data.length, System.currentTimeMillis() - current);
}
}
o方法
同i方法,将方法执行完成时的耗时信息存入数组。
public static void o(int methodId) {
if (status <= STATUS_STOPPED) {
return;
}
if (methodId >= METHOD_ID_MAX) {
return;
}
if (Thread.currentThread().getId() == sMainThreadId) {
if (sIndex < Constants.BUFFER_SIZE) {
mergeData(methodId, sIndex, false);
} else {
sIndex = 0;
mergeData(methodId, sIndex, false);
}
++sIndex;
}
}
onStart
移除监听,更新状态为STATUS_STARTED。
public void onStart() {
synchronized (statusLock) {
if (status < STATUS_STARTED && status >= STATUS_EXPIRED_START) {
//移除超时监听
sHandler.removeCallbacks(checkStartExpiredRunnable);
//移除超时主动释放的逻辑
MatrixHandlerThread.getDefaultHandler().removeCallbacks(realReleaseRunnable);
if (sBuffer == null) {
throw new RuntimeException(TAG + " sBuffer == null");
}
MatrixLog.i(TAG, "[onStart] preStatus:%s", status, Utils.getStack());
status = STATUS_STARTED;
} else {
MatrixLog.w(TAG, "[onStart] current status:%s", status);
}
}
}
其中realReleaseRunnable是静态代码块中执行的逻辑,延时10,若还未启动就释放。
static {
MatrixHandlerThread.getDefaultHandler().postDelayed(realReleaseRunnable, Constants.DEFAULT_RELEASE_BUFFER_DELAY);
}
所以整个AppMethodBeat中存在两个超时逻辑,一个是类加载时的10s超时,10s后status状态未更新为start就自动取消;另一个是i方法第一次执行时,10s后status状态未更新为start就将status更新为超时状态。
onStop
更新status为STATUS_STOPPED,生命周期结束。
public void onStop() {
synchronized (statusLock) {
if (status == STATUS_STARTED) {
MatrixLog.i(TAG, "[onStop] %s", Utils.getStack());
status = STATUS_STOPPED;
} else {
MatrixLog.w(TAG, "[onStop] current status:%s", status);
}
}
}
总结
至此AppMethodBeat类的内容都分析完了,可以发现其实AppMethodBeat的生命周期方法做的东西并不多,它仅仅控制AppMethodBeat的状态,而真正起作用的地方还是在插桩的两个方法i和o上,以及markIndex标记数据,和copyData取方法运行数据这几个点上。
简单一点理解,可以认为AppMethodBeat中有一个数组,这个数组存储了一定运行期内所有方法执行的耗时信息,而当我们发现耗时问题的时候,直接去AppMethodBeat取出一定范围内的方法运行信息,借此来分析卡顿耗时发生的根源,仅此而已。
总结一下,AppMethodBeat的核心功能如下:
- 在所有(符合条件的)方法中插入i和o方法记录方法信息
- 方法运行时会将方法id方法耗时信息存入内存,记录在一个long类型的数组中
- 维持一个链表,用于映射方法index和mark标记
- 根据mark标记从数组中取出区间内方法运行的信息供分析使用
后边你会发现AppMethodBeat在TracePlugin中的使用频率非常高,每一个tracer类型都会以来AppMethodBeat来获取方法耗时信息,这也是耗时分析的基础数据能力。今天分析完AppMethodBeat之后,后边的各种tracer分析起来也就简单多了。
转载自:https://juejin.cn/post/7278883051380408356