Android 性能优化系列 - 04 Matrix 中 Tra
一.概述
在做 UI 性能优化的时候,很重要的一点就是需要做好优化前和优化后的对比,否则怎么判断自己的优化是否有效果,效果有多大呢?对比的话,个人认为可以分为两类,一类是通过观察直观的对比,另一类是通过数据客观的对比
直观对比,我们可以通过 开发者选项
中的 过渡绘制
和 GPU 分析
查看页面中是否存在过渡绘制和 UI 渲染时的 GPU 渲染图
客观对比,我们可以通过各种测试工具分析、对比,比如网易的 Emmagee 、腾讯的 matrix 等等,很遗憾的是 Emmagee 在 Android 7.0 以上由于系统限制无法使用,所以我使用的是 matrix
做软件开发,不仅要知其然,而且要知其所以然,这样才能有更大的进步。我在做 UI 性能优化的时候,使用了 matrix 中的 TraceCanary 模块,它是功能主要是检测 UI 卡顿、启动耗时、页面切换和慢函数检测,这里主要分析一下其中的帧率是怎么计算的,其他功能的代码应该也不是很复杂,有兴趣的朋友可以自行分析
二.原理
从一开始做 Android 应用开发的时候,就经常听说不能在主线程中做耗时的操作(比如:IO 数据读取、网络请求等等),会造成 UI 卡顿等问题,因为主线程每 16.67 ms 就会渲染一帧,如果在主线程中有耗时的任务,可能在 16.67 ms 内无法渲染下一帧就会造成掉帧,而掉帧从视觉上来讲就是通常所说的卡顿了。虽然造成掉帧的原因有很多种,但是有两个变量是固定的:主线程和 16.67 ms,我们就可以通过这两个固定值入手,分析、判断主线程中是否存在卡顿
了解过 Android 性能优化的朋友可能都知道,业内主流的实现卡顿监控的思想,都是通过监控主线程中任务的耗时情况,如果任务耗时超过一定的阈值,则 dump 当前主线程的堆栈信息,就可以分析卡顿原因了,这两种思想的典型代表有 ArgusAPM、BlockCanary、BlockCanaryEx 等。思想是这样的,实现的方式可以归为两类,一类是通过主线程的 Looper 机制,另一类是通过 Choreographer 模块,下面先简单介绍下这两种方式
2.1 Looper 机制
大家都知道在主线程中有一个 MainLooper
,主线程启动以后就会调用 MainLooper#loop()
方法,主线程中执行的任务都会间接地在 ActivityThread
中的一个内部类 H
(它是一个 Handler 的子类)的 handleMessage(Message msg)
来执行,我们分析一下 Looper.loop()
方法如下
- 代码 1:
Looper.loop()
方法中会有个for(;;)
死循环不断地从MessageQueue
中读取消息并处理 - 代码 3:最终调用了
msg.target.dispatchMessage(msg)
来处理此 Message,而msg.target
其实就是 Handler,它是指在 MainLooper 对应的所有的 Handler - 代码 2 & 代码 4:在处理消息前后,都会通过
myLooper().mLogging
得到的Printer
对象,分别打印>>>>> Dispatching to
和<<<<< Finished to
-
myLooper().mLogging
是可以通过Looper.getMainLooper().setMessageLogging(Printer printer)
设置的
所以我们只需要判断 >>>>> Dispatching to
和 <<<<< Finished to
这两个 log 之间的时间是否超出阈值,就可以判定此时主线程中执行的任务是否是耗时任务
public final class Looper {
......
public static void loop() {
final Looper me = myLooper();
if (me == null) {
throw new RuntimeException("No Looper; Looper.prepare() wasn't called on this thread.");
}
final MessageQueue queue = me.mQueue;
// Make sure the identity of this thread is that of the local process,
// and keep track of what that identity token actually is.
Binder.clearCallingIdentity();
final long ident = Binder.clearCallingIdentity();
for (;;) { // 代码 1
Message msg = queue.next(); // might block
if (msg == null) {
// No message indicates that the message queue is quitting.
return;
}
// This must be in a local variable, in case a UI event sets the logger
final Printer logging = me.mLogging; // 代码 2
if (logging != null) {
logging.println(">>>>> Dispatching to " + msg.target + " " +
msg.callback + ": " + msg.what);
}
final long slowDispatchThresholdMs = me.mSlowDispatchThresholdMs;
final long traceTag = me.mTraceTag;
if (traceTag != 0 && Trace.isTagEnabled(traceTag)) {
Trace.traceBegin(traceTag, msg.target.getTraceName(msg));
}
final long start = (slowDispatchThresholdMs == 0) ? 0 : SystemClock.uptimeMillis();
final long end;
try {
msg.target.dispatchMessage(msg); // 代码 3
end = (slowDispatchThresholdMs == 0) ? 0 : SystemClock.uptimeMillis();
} finally {
if (traceTag != 0) {
Trace.traceEnd(traceTag);
}
}
if (logging != null) { // 代码 4
logging.println("<<<<< Finished to " + msg.target + " " + msg.callback);
}
......
}
}
......
}
示意代码如下
Looper.getMainLooper().setMessageLogging(new Printer() {
private static final String START = ">>>>> Dispatching";
private static final String END = "<<<<< Finished";
@Override
public void println(String x) {
if (x.startsWith(">>>>> Dispatching")) {
...... // 开始记录
}
if (x.startsWith("<<<<< Finished")) {
...... // 结束记录,判断处理时间间隔是否超过阈值
}
}
});
2.2 Choreographer 模块
Android 系统每隔 16.67 ms 都会发送一个 VSYNC 信号触发 UI 的渲染,正常情况下两个 VSYNC 信号之间是 16.67 ms ,如果超过 16.67 ms 则可以认为渲染发生了卡顿
Android SDK 中的 Choreographer
类中的 FrameCallback.doFrame(long l)
在每次发送 VSYNC 信号的时候都会被回调,所以我们只需要判断相邻的两次 FrameCallback.doFrame(long l)
间隔是否超过阈值,如果超过阈值则发生了卡顿,则可以在另外一个子线程中 dump 当前主线程的堆栈信息进行分析
示意代码如下所示,需要注意的是,在 FrameCallback.doFrame(long l)
回调方法中,我们每次都需要重新注册回调 Choreographer.getInstance().postFrameCallback(this)
Choreographer.getInstance()
.postFrameCallback(new Choreographer.FrameCallback() {
@Override
public void doFrame(long l) {
if(frameTimeNanos - mLastFrameNanos > 100) {
...
}
mLastFrameNanos = frameTimeNanos;
Choreographer.getInstance().postFrameCallback(this);
}
});
2.3 Matrix-TraceCanary 的实现方式
判断 UI 中是否存在卡顿大概可以分为以上两种实现方式
在 Matrix 的 TraceCanary 模块中,旧版本使用的是 Choreographer
的方式,但是新版本中使用的是 Looper
机制了,至于为什么会有这种差异,暂时还不清楚
不过使用 Looper
机制实现的方式存在一个缺点:在打印消息处理开始日志和消息处理结束日志的时候,都会进行字符串的拼接,频繁地进行字符串的拼接也会影响性能
三.源码解析
这里分析 Matrix 和 TraceCanary 是 0.5.2 版本
既然已经知道了它的实现原理,我们就直捣黄龙,去寻找和 Looper.getMainLooper().setMessageLogging()
相关的代码,顺藤摸瓜,这样顺着分析会更清晰一些。
Matrix 和 TraceCanary 的目录结构如下图所示
image2.png3.1 向 Looper 添加 Printer
上图中被选中的 LooperMonitor
类就是我们入手的类,其中通过调用 Looper.getMainLooper().setMessageLogging()
方法添加了一个 Printer 对象,代码如下所示
-
代码 1:
LooperMonitor
的构造方法是私有的,且有一个静态的 final 对象LooperMonitor monitor
-
代码 2 & 代码 3:
LooperMonitor
实现了MessageQueue.IdleHandler
接口及其抽象方法queueIdle()
,并且在构造方法中根据版本差异使用不同的方法将此MessageQueue.IdleHandler
实例对象添加到MessageQueue
中,queueIdle()
方法返回 true 保证消息队列中的每个消息处理完以后,都会回调queueIdle()
方法 -
代码 4:在构造方法和
queueIdle()
方法中会调用resetPrinter()
方法,其中才是真正通过Looper.getMainLooper().setMessageLogging()
设置 Printer 的地方在每次添加前,都会通过反射得到当前
Looper.getMainLooper()
设置的mLogging
对象,并判断是不是之前被 LooperMonitor 设置的,如果Looper.getMainLooper()
中的mLogging
对象是被 LooperMonitor 设置的,则不会再次设置,否则会为Looper.getMainLooper()
设置自己的 Printer 对象 -
代码 5:在
Printer.println(String x)
中,会根据传入的参数String x
的第一个字符判断是否是有效的Looper.loop()
日志,以>
开头的则是消息处理开始的日志,以>
开头的则是消息处理结束的日志,最终会调用dispatch(boolean isBegin)
方法
public class LooperMonitor implements MessageQueue.IdleHandler {
private static final HashSet<LooperDispatchListener> listeners = new HashSet<>();
private static Printer printer;
private static final LooperMonitor monitor = new LooperMonitor(); // 代码 1
private LooperMonitor() { // 代码 2
resetPrinter();
if (Build.VERSION.SDK_INT >= Build.VERSION_CODES.M) {
Looper.getMainLooper().getQueue().addIdleHandler(this);
} else {
MessageQueue queue = reflectObject(Looper.getMainLooper(), "mQueue");
queue.addIdleHandler(this);
}
}
@Override
public boolean queueIdle() { // 代码 3
resetPrinter();
return true;
}
private static void resetPrinter() { // 代码 4
final Printer originPrinter = reflectObject(Looper.getMainLooper(), "mLogging");
if (originPrinter == printer && null != printer) {
return;
}
if (null != printer) {
MatrixLog.w(TAG, "[resetPrinter] maybe looper printer was replace other!");
}
Looper.getMainLooper().setMessageLogging(printer = new Printer() { // 代码 5
boolean isHasChecked = false;
boolean isValid = false;
@Override
public void println(String x) {
if (null != originPrinter) {
originPrinter.println(x);
}
if (!isHasChecked) {
isValid = x.charAt(0) == '>' || x.charAt(0) == '<';
isHasChecked = true;
if (!isValid) {
MatrixLog.e(TAG, "[println] Printer is inValid! x:%s", x);
}
}
if (isValid) {
dispatch(x.charAt(0) == '>');
}
}
});
}
}
已经监听到了 Looper.loop() 消息处理的开始和结束,接下来看下在消息处理开始和结束时是怎么处理的,主要看 dispatch(boolean isBegin)
方法
- 在
dispatch(boolean isBegin)
中,会依次处理添加到 LooperMonitor 中的 LooperDispatchListener 监听回调 - 代码 1:
dispatch(boolean isBegin)
方法中会根据参数boolean isBegin
、listener.isValid()
以及listener.isHasDispatchStart
条件执行listener.dispatchStart()
和listener.dispatchEnd()
方法,具体的在消息处理开始和结束时做什么,都在listener.dispatchStart()
和listener.dispatchEnd()
中实现 - 代码 2:这行代码,个人理解的就是要站好最后一班岗的意思,当
listener.isValid() == false && isBegin == false && listener.isHasDispatchStart == true
时最后调用一次listener.dispatchEnd()
方法 - 代码 3:可以通过
LooperMonitor.register(LooperDispatchListener listener)
方法向 LooperMonitor 中设置LooperDispatchListener listener
,接下来我们看下在哪儿调用这个方法设置LooperDispatchListener listener
监听的,就可以看到消息处理开始和结束时都有哪些具体的逻辑了
public class LooperMonitor implements MessageQueue.IdleHandler {
private static final HashSet<LooperDispatchListener> listeners = new HashSet<>();
......
public abstract static class LooperDispatchListener {
boolean isHasDispatchStart = false;
boolean isValid() {
return false;
}
@CallSuper
void dispatchStart() {
this.isHasDispatchStart = true;
}
@CallSuper
void dispatchEnd() {
this.isHasDispatchStart = false;
}
}
......
public static void register(LooperDispatchListener listener) { // 代码 3
synchronized (listeners) {
listeners.add(listener);
}
}
private static void dispatch(boolean isBegin) {
for (LooperDispatchListener listener : listeners) {
if (listener.isValid()) { // 代码 1
if (isBegin) {
if (!listener.isHasDispatchStart) {
listener.dispatchStart();
}
} else {
if (listener.isHasDispatchStart) {
listener.dispatchEnd();
}
}
} else if (!isBegin && listener.isHasDispatchStart) { // 代码 2
listener.dispatchEnd();
}
}
}
......
}
3.2 消息处理
如下图所示,在 trace-canary 模块中有 AppMethodBeat
和 UIThreadMonitor
两个类通过 LooperMonitor.register(LooperDispatchListener listener)
方法向 LooperMonitor 中设置 LooperDispatchListener listener
,和本文相关的是 UIThreadMonitor
类,重点分析下这个类
首先分析下 UIThreadMonitor
类的初始化方法,其中主要是通过反射拿到了 Choreographer 一些属性,并且通过 LooperMonitor.register(LooperDispatchListener listener)
方法向 LooperMonitor 中设置 LooperDispatchListener listener
- 代码 1:通过反射拿到了 Choreographer 实例的
mCallbackQueues
属性,mCallbackQueues
是一个回调队列数组CallbackQueue[] mCallbackQueues
,其中包括四个回调队列,第一个是输入事件回调队列CALLBACK_INPUT = 0
,第二个是动画回调队列CALLBACK_ANIMATION = 1
,第三个是遍历绘制回调队列CALLBACK_TRAVERSAL = 2
,第四个是提交回调队列CALLBACK_COMMIT = 3
。这四个阶段在每一帧的 UI 渲染中是依次执行的,每一帧中各个阶段开始时都会回调mCallbackQueues
中对应的回调队列的回调方法。关于 Choreographer 的文章推荐这篇 Android Choreographer 源码分析 - 代码 2:通过反射拿到输入事件回调队列的
addCallbackLocked
方法 - 代码 3:通过反射拿到动画回调队列的
addCallbackLocked
方法 - 代码 4:通过反射拿到遍历绘制回调队列的
addCallbackLocked
方法 - 代码 5:通过
LooperMonitor.register(LooperDispatchListener listener)
方法向 LooperMonitor 中设置LooperDispatchListener listener
- 代码 6:在 Looper.loop() 中的消息处理开始时的回调
- 代码 7:在 Looper.loop() 中的消息处理结束时的回调
public class UIThreadMonitor implements BeatLifecycle, Runnable {
private static final String ADD_CALLBACK = "addCallbackLocked";
public static final int CALLBACK_INPUT = 0;
public static final int CALLBACK_ANIMATION = 1;
public static final int CALLBACK_TRAVERSAL = 2;
private final static UIThreadMonitor sInstance = new UIThreadMonitor();
private Object callbackQueueLock;
private Object[] callbackQueues;
private Method addTraversalQueue;
private Method addInputQueue;
private Method addAnimationQueue;
private Choreographer choreographer;
private long frameIntervalNanos = 16666666;
......
public static UIThreadMonitor getMonitor() {
return sInstance;
}
public void init(TraceConfig config) {
if (Thread.currentThread() != Looper.getMainLooper().getThread()) {
throw new AssertionError("must be init in main thread!");
}
this.isInit = true;
this.config = config;
choreographer = Choreographer.getInstance();
callbackQueueLock = reflectObject(choreographer, "mLock");
callbackQueues = reflectObject(choreographer, "mCallbackQueues"); // 代码 1
addInputQueue = reflectChoreographerMethod(callbackQueues[CALLBACK_INPUT], ADD_CALLBACK, long.class, Object.class, Object.class); // 代码 2
addAnimationQueue = reflectChoreographerMethod(callbackQueues[CALLBACK_ANIMATION], ADD_CALLBACK, long.class, Object.class, Object.class); // 代码 3
addTraversalQueue = reflectChoreographerMethod(callbackQueues[CALLBACK_TRAVERSAL], ADD_CALLBACK, long.class, Object.class, Object.class); // 代码 4
frameIntervalNanos = reflectObject(choreographer, "mFrameIntervalNanos");
LooperMonitor.register(new LooperMonitor.LooperDispatchListener() { // 代码 5
@Override
public boolean isValid() {
return isAlive;
}
@Override
public void dispatchStart() {
super.dispatchStart();
UIThreadMonitor.this.dispatchBegin(); // 代码 6
}
@Override
public void dispatchEnd() {
super.dispatchEnd();
UIThreadMonitor.this.dispatchEnd(); // 代码 7
}
});
......
}
}
在 3.1 节就讲过,在 Looper 处理消息开始和结束时,分别会回调 LooperDispatchListener 的 dispatchStart()
和 dispatchEnd()
方法,也就是如上代码所示的 代码6 和 代码7 处
dispatchStart()
方法相对简单,其中调用了 UIThreadMonitor.this.dispatchBegin()
记录两个起始时间,一个是线程起始时间,另一个是 cpu 起始时间,并且依次回调 LooperObserver#dispatchBegin()
方法,如下所示
public class UIThreadMonitor implements BeatLifecycle, Runnable {
private long[] dispatchTimeMs = new long[4];
private volatile long token = 0L;
......
private void dispatchBegin() {
token = dispatchTimeMs[0] = SystemClock.uptimeMillis();
dispatchTimeMs[2] = SystemClock.currentThreadTimeMillis();
AppMethodBeat.i(AppMethodBeat.METHOD_ID_DISPATCH);
synchronized (observers) {
for (LooperObserver observer : observers) {
if (!observer.isDispatchBegin()) {
observer.dispatchBegin(dispatchTimeMs[0], dispatchTimeMs[2], token);
}
}
}
}
......
}
dispatchEnd()
方法相对复杂一些,根据变量 isBelongFrame
判断是否调用 doFrameEnd(long token)
,然后记录线程结束时间和 cpu 结束时间,最终回调 LooperObserver#dispatchEnd()
方法
- 代码 1,在 UIThreadMonitor 中有两个长度是三的数组
queueStatus
和queueCost
分别对应着每一帧中输入事件阶段、动画阶段、遍历绘制阶段的状态和耗时,queueStatus
有三个值:DO_QUEUE_DEFAULT、DO_QUEUE_BEGIN 和 DO_QUEUE_END - 代码 2,变量
isBelongFrame
初始值是false
,是在doFrameBegin(long token)
方法中将其置位true
的,doFrameBegin(long token)
是在run()
方法中被调用的,UIThreadMonitor
实现了Runnable
接口,自然重写了run()
方法,那么UIThreadMonitor
对象是什么时候被线程执行的呢?下面再分析 - 代码 3,在消息处理结束时,会调用
dispatchEnd()
方法,其中根据变量isBelongFrame
判断是否调用doFrameEnd(long token)
- 代码 4,在
run()
方法中,首先会调用doFrameBegin(long token)
将变量isBelongFrame
设置为true
,然后通过doQueueBegin()
方法记录输入事件回调CALLBACK_INPUT
开始的状态和时间;之后又通过addFrameCallback()
方法为Choreographer
设置动画回调CALLBACK_ANIMATION
和遍历绘制回调CALLBACK_TRAVERSAL
的回调方法 - 代码 5,在动画回调
CALLBACK_ANIMATION
的回调方法run()
中,记录CALLBACK_INPUT
的结束的状态和时间,同时也记录CALLBACK_ANIMATION
的开始状态和时间 - 代码 6,在遍历绘制
CALLBACK_TRAVERSAL
的回调方法run()
中,记录CALLBACK_ANIMATION
的结束状态和时间,同时也记录CALLBACK_TRAVERSAL
的开始状态和时间 - 其实这里已经可以猜测到
UIThreadMonitor
实现Runnable
接口,也是为了将UIThreadMonitor
作为输入事件回调CALLBACK_INPUT
的回调方法,设置到Choreographer
中去的
public class UIThreadMonitor implements BeatLifecycle, Runnable {
public static final int CALLBACK_INPUT = 0;
public static final int CALLBACK_ANIMATION = 1;
public static final int CALLBACK_TRAVERSAL = 2;
private static final int CALLBACK_LAST = CALLBACK_TRAVERSAL;
private boolean isBelongFrame = false;
private int[] queueStatus = new int[CALLBACK_LAST + 1]; // 代码 1
private long[] queueCost = new long[CALLBACK_LAST + 1];
private static final int DO_QUEUE_DEDO_QUEUE_DEFAULT、FAULT = 0;
private static final int DO_QUEUE_BEGIN = 1;
private static final int DO_QUEUE_END = 2;
private void doFrameBegin(long token) { // 代码 2
this.isBelongFrame = true;
}
private void dispatchEnd() { // 代码 3
if (isBelongFrame) {
doFrameEnd(token);
}
dispatchTimeMs[3] = SystemClock.currentThreadTimeMillis();
dispatchTimeMs[1] = SystemClock.uptimeMillis();
AppMethodBeat.o(AppMethodBeat.METHOD_ID_DISPATCH);
synchronized (observers) {
for (LooperObserver observer : observers) {
if (observer.isDispatchBegin()) {
observer.dispatchEnd(dispatchTimeMs[0], dispatchTimeMs[2], dispatchTimeMs[1], dispatchTimeMs[3], token, isBelongFrame);
}
}
}
}
@Override
public void run() { // 代码 4
final long start = System.nanoTime();
try {
doFrameBegin(token); // 将 isBelongFrame 置位 true
doQueueBegin(CALLBACK_INPUT); // 通过 doQueueBegin(int type) 记录输入事件回调 CALLBACK_INPUT 开始状态和时间
addFrameCallback(CALLBACK_ANIMATION, new Runnable() { // 通过 addFrameCallback() 方法向 Choreographer 中添加动画 CALLBACK_ANIMATION 回调
// 每个回调其实都是一个 Runnable,执行时会主动调用 `run()` 方法
@Override
public void run() { // 代码 5
doQueueEnd(CALLBACK_INPUT); // 输入事件回调 CALLBACK_INPUT 结束
doQueueBegin(CALLBACK_ANIMATION); // 动画回调 CALLBACK_ANIMATION 开始
}
}, true);
addFrameCallback(CALLBACK_TRAVERSAL, new Runnable() { // 通过 addFrameCallback() 方法向 Choreographer 中添加遍历绘制 CALLBACK_TRAVERSAL 回调
@Override
public void run() { // 代码 6
doQueueEnd(CALLBACK_ANIMATION); // 动画回调 CALLBACK_ANIMATION 结束
doQueueBegin(CALLBACK_TRAVERSAL); // 遍历绘制回调 CALLBACK_TRAVERSAL 开始
}
}, true);
} finally {
if (config.isDevEnv()) {
MatrixLog.d(TAG, "[UIThreadMonitor#run] inner cost:%sns", System.nanoTime() - start);
}
}
}
private synchronized void addFrameCallback(int type, Runnable callback, boolean isAddHeader) {
if (callbackExist[type]) {
MatrixLog.w(TAG, "[addFrameCallback] this type %s callback has exist!", type);
return;
}
if (!isAlive && type == CALLBACK_INPUT) {
MatrixLog.w(TAG, "[addFrameCallback] UIThreadMonitor is not alive!");
return;
}
try {
synchronized (callbackQueueLock) {
Method method = null;
switch (type) {
case CALLBACK_INPUT:
method = addInputQueue;
break;
case CALLBACK_ANIMATION:
method = addAnimationQueue;
break;
case CALLBACK_TRAVERSAL:
method = addTraversalQueue;
break;
}
if (null != method) {
method.invoke(callbackQueues[type], !isAddHeader ? SystemClock.uptimeMillis() : -1, callback, null);
callbackExist[type] = true;
}
}
} catch (Exception e) {
MatrixLog.e(TAG, e.toString());
}
}
private void doQueueBegin(int type) {
queueStatus[type] = DO_QUEUE_BEGIN;
queueCost[type] = System.nanoTime();
}
private void doQueueEnd(int type) {
queueStatus[type] = DO_QUEUE_END;
queueCost[type] = System.nanoTime() - queueCost[type];
synchronized (callbackExist) {
callbackExist[type] = false;
}
}
......
}
接下来看下,是什么时候将输入事件回调 CALLBACK_INPUT
设置进 Choreographer 中去的
如上图所示,addFrameCallback()
方法除了添加动画回调 CALLBACK_ANIMATION
和遍历绘制回调 CALLBACK_TRAVERSAL
,有两处添加了 CALLBACK_INPUT
回调,分别是下面两处
- 代码 1,首次调用
UIThreadMonitor#onStart()
方法时会调用一次addFrameCallback(CALLBACK_INPUT, this, true)
方法,将此Runnable
作为输入事件CALLBACK_INPUT
的回调添加进 Choreographyer 中 - 代码 2,在
doFrameEnd(long token)
方法中,每一帧完成以后也会调用一次addFrameCallback(CALLBACK_INPUT, this, true)
方法,再次添加以供下一帧回调这三个回调。doFrameEnd(long token)
方法是在处理消息结束时的dispatchEnd()
方法中回调的 - 代码 3,在上面的代码分析中,最后只调用了
doQueueBegin(CALLBACK_TRAVERSAL)
,在doFrameEnd(long token)
方法中调用了doQueueEnd(CALLBACK_TRAVERSAL)
,完成了遍历绘制回调CALLBACK_TRAVERSAL
的监听 - 代码 4,新创建一个长度为 3 的数组并赋值给
queueStatus
,其实这里有一个疑问,doFrameEnd(long token)
方法在每一帧绘制的时候都会被回调,在这个方法中创建数组对象,会不会造成内存抖动 - 代码 5,遍历
LooperObserver
的 HashSet 对象,回调其doFrame(String focusedActivityName, long start, long end, long frameCostMs, long inputCostNs, long animationCostNs, long traversalCostNs)
方法,其中会将输入事件、动画、遍历绘制的耗时作为参数传入
public class UIThreadMonitor implements BeatLifecycle, Runnable {
@Override
public synchronized void onStart() {
if (!isInit) {
throw new RuntimeException("never init!");
}
if (!isAlive) {
MatrixLog.i(TAG, "[onStart] %s", Utils.getStack());
this.isAlive = true;
addFrameCallback(CALLBACK_INPUT, this, true); // 代码 1
}
}
private void doFrameEnd(long token) {
doQueueEnd(CALLBACK_TRAVERSAL); // 代码 3
for (int i : queueStatus) {
if (i != DO_QUEUE_END) {
queueCost[i] = DO_QUEUE_END_ERROR;
if (config.isDevEnv) {
throw new RuntimeException(String.format("UIThreadMonitor happens type[%s] != DO_QUEUE_END", i));
}
}
}
queueStatus = new int[CALLBACK_LAST + 1]; // 代码 4
long start = token;
long end = SystemClock.uptimeMillis();
synchronized (observers) { // 代码 5
for (LooperObserver observer : observers) {
if (observer.isDispatchBegin()) {
observer.doFrame(AppMethodBeat.getFocusedActivity(), start, end, end - start, queueCost[CALLBACK_INPUT], queueCost[CALLBACK_ANIMATION], queueCost[CALLBACK_TRAVERSAL]);
}
}
}
addFrameCallback(CALLBACK_INPUT, this, true); // 代码 2
this.isBelongFrame = false;
}
}
3.3 帧率计算
从上面代码,可以看到最后会将每一帧的时间信息通过 HashSet<LooperObserver> observers
回调出去,看一下是在哪里向 observers
添加 LooperObserver
回调的,如下图所示
这里主要看一下 FrameTracer
这个类,其中涉及到了帧率 FPS 的计算,其他的类有兴趣的朋友可以自己分析
FrameTracer 的代码如下所示,我相信仔细看看并不难懂,主要逻辑在 notifyListener(final String focusedActivityName, final long frameCostMs)
方法中,其中涉及到一个变量 frameIntervalMs = 16.67
ms
- 代码 1:会遍历
HashSet<IDoFrameListener> listeners
,并根据doFrame()
中传入的long frameCost
时间计算掉帧个数,最后将frameCostMs
和dropFrame
通过IDoFrameListener
接口中的两个方法回调出去 - 掉帧个数是通过:
final int dropFrame = (int) (frameCostMs / frameIntervalMs)
计算的,frameCostMs
是这一帧绘制的耗时,frameIntervalMs
其实就是 16.67ms
public class FrameTracer extends Tracer {
private final long frameIntervalMs;
private HashSet<IDoFrameListener> listeners = new HashSet<>();
public FrameTracer(TraceConfig config) {
this.frameIntervalMs = TimeUnit.MILLISECONDS.convert(UIThreadMonitor.getMonitor().getFrameIntervalNanos(), TimeUnit.NANOSECONDS) + 1;
......
}
public void addListener(IDoFrameListener listener) {
synchronized (listeners) {
listeners.add(listener);
}
}
public void removeListener(IDoFrameListener listener) {
synchronized (listeners) {
listeners.remove(listener);
}
}
@Override
public void onAlive() {
super.onAlive();
UIThreadMonitor.getMonitor().addObserver(this);
}
@Override
public void onDead() {
super.onDead();
UIThreadMonitor.getMonitor().removeObserver(this);
}
@Override
public void doFrame(String focusedActivityName, long start, long end, long frameCostMs, long inputCostNs, long animationCostNs, long traversalCostNs) {
notifyListener(focusedActivityName, frameCostMs);
}
private void notifyListener(final String focusedActivityName, final long frameCostMs) {
long start = System.currentTimeMillis();
try {
synchronized (listeners) {
for (final IDoFrameListener listener : listeners) {
final int dropFrame = (int) (frameCostMs / frameIntervalMs); // 代码 1
listener.doFrameSync(focusedActivityName, frameCostMs, dropFrame);
if (null != listener.getHandler()) {
listener.getHandler().post(new Runnable() {
@Override
public void run() {
listener.doFrameAsync(focusedActivityName, frameCostMs, dropFrame);
}
});
}
}
}
} finally {
long cost = System.currentTimeMillis() - start;
if (config.isDevEnv()) {
MatrixLog.v(TAG, "[notifyListener] cost:%sms", cost);
}
if (cost > frameIntervalMs) {
MatrixLog.w(TAG, "[notifyListener] warm! maybe do heavy work in doFrameSync,but you can replace with doFrameAsync! cost:%sms", cost);
}
if (config.isDebug() && !isForeground()) {
backgroundFrameCount++;
}
}
}
}
看一下在哪些地方调用 addListener(IDoFrameListener listener)
向 FrameTracer 中添加了 IDoFrameListener
,如下图所示,主要有两个地方:FrameDecorator 和 FrameTracer,这两个地方的逻辑其实差不多,主要看一下 addListener(new FPSCollector());
的
FPSCollector
是 FrameTracer
的一个内部类,实现了 IDoFrameListener
接口,主要逻辑是在 doFrameAsync()
方法中
- 代码 1:会根据当前 ActivityName 创建一个对应的 FrameCollectItem 对象,存放在 HashMap 中
- 代码 2:调用
FrameCollectItem#collect()
,计算帧率 FPS 等一些信息 - 代码 3:如果此 Activity 的绘制总时间超过 timeSliceMs(默认是 10s),则调用
FrameCollectItem#report()
上报统计数据,并从 HashMap 中移除当前 ActivityName 和对应的 FrameCollectItem 对象
private class FPSCollector extends IDoFrameListener {
private Handler frameHandler = new Handler(MatrixHandlerThread.getDefaultHandlerThread().getLooper());
private HashMap<String, FrameCollectItem> map = new HashMap<>();
@Override
public Handler getHandler() {
return frameHandler;
}
@Override
public void doFrameAsync(String focusedActivityName, long frameCost, int droppedFrames) {
super.doFrameAsync(focusedActivityName, frameCost, droppedFrames);
if (Utils.isEmpty(focusedActivityName)) {
return;
}
FrameCollectItem item = map.get(focusedActivityName); // 代码 1
if (null == item) {
item = new FrameCollectItem(focusedActivityName);
map.put(focusedActivityName, item);
}
item.collect(droppedFrames); // 代码 2
if (item.sumFrameCost >= timeSliceMs) { // report // 代码 3
map.remove(focusedActivityName);
item.report();
}
}
}
FrameCollectItem
也是 FrameTracer 的一个内部类,其中最重要的是两个方法 collect(int droppedFrames)
和 report()
方法
- 代码 1:将每一帧的耗时相加,sumFrameCost 代表总耗时
- 代码 2:sumDroppedFrames 统计总的掉帧个数
- 代码 3:sumFrame 表示总帧数
- 代码 4:根据掉帧的个数,判断此次掉帧行为属于哪个程度区间并记录其个数
- 代码 5:根据
float fps = Math.min(60.f, 1000.f * sumFrame / sumFrameCost)
计算 fps 值 - 代码 6:将统计得到的信息封装到一个 Issue 对象中,并通过
TracePlugin#onDetectIssue()
方法回调出去
private class FrameCollectItem {
String focusedActivityName;
long sumFrameCost;
int sumFrame = 0;
int sumDroppedFrames;
// record the level of frames dropped each time
int[] dropLevel = new int[DropStatus.values().length];
int[] dropSum = new int[DropStatus.values().length];
FrameCollectItem(String focusedActivityName) {
this.focusedActivityName = focusedActivityName;
}
void collect(int droppedFrames) {
long frameIntervalCost = UIThreadMonitor.getMonitor().getFrameIntervalNanos();
sumFrameCost += (droppedFrames + 1) * frameIntervalCost / Constants.TIME_MILLIS_TO_NANO; // 代码 1
sumDroppedFrames += droppedFrames; // 代码 2
sumFrame++; // 代码 3
if (droppedFrames >= frozenThreshold) { // 代码 4
dropLevel[DropStatus.DROPPED_FROZEN.index]++;
dropSum[DropStatus.DROPPED_FROZEN.index] += droppedFrames;
} else if (droppedFrames >= highThreshold) {
dropLevel[DropStatus.DROPPED_HIGH.index]++;
dropSum[DropStatus.DROPPED_HIGH.index] += droppedFrames;
} else if (droppedFrames >= middleThreshold) {
dropLevel[DropStatus.DROPPED_MIDDLE.index]++;
dropSum[DropStatus.DROPPED_MIDDLE.index] += droppedFrames;
} else if (droppedFrames >= normalThreshold) {
dropLevel[DropStatus.DROPPED_NORMAL.index]++;
dropSum[DropStatus.DROPPED_NORMAL.index] += droppedFrames;
} else {
dropLevel[DropStatus.DROPPED_BEST.index]++;
dropSum[DropStatus.DROPPED_BEST.index] += (droppedFrames < 0 ? 0 : droppedFrames);
}
}
void report() {
float fps = Math.min(60.f, 1000.f * sumFrame / sumFrameCost); // 代码 5
MatrixLog.i(TAG, "[report] FPS:%s %s", fps, toString());
try {
TracePlugin plugin = Matrix.with().getPluginByClass(TracePlugin.class); // 代码 6
JSONObject dropLevelObject = new JSONObject();
dropLevelObject.put(DropStatus.DROPPED_FROZEN.name(), dropLevel[DropStatus.DROPPED_FROZEN.index]);
dropLevelObject.put(DropStatus.DROPPED_HIGH.name(), dropLevel[DropStatus.DROPPED_HIGH.index]);
dropLevelObject.put(DropStatus.DROPPED_MIDDLE.name(), dropLevel[DropStatus.DROPPED_MIDDLE.index]);
dropLevelObject.put(DropStatus.DROPPED_NORMAL.name(), dropLevel[DropStatus.DROPPED_NORMAL.index]);
dropLevelObject.put(DropStatus.DROPPED_BEST.name(), dropLevel[DropStatus.DROPPED_BEST.index]);
JSONObject dropSumObject = new JSONObject();
dropSumObject.put(DropStatus.DROPPED_FROZEN.name(), dropSum[DropStatus.DROPPED_FROZEN.index]);
dropSumObject.put(DropStatus.DROPPED_HIGH.name(), dropSum[DropStatus.DROPPED_HIGH.index]);
dropSumObject.put(DropStatus.DROPPED_MIDDLE.name(), dropSum[DropStatus.DROPPED_MIDDLE.index]);
dropSumObject.put(DropStatus.DROPPED_NORMAL.name(), dropSum[DropStatus.DROPPED_NORMAL.index]);
dropSumObject.put(DropStatus.DROPPED_BEST.name(), dropSum[DropStatus.DROPPED_BEST.index]);
JSONObject resultObject = new JSONObject();
resultObject = DeviceUtil.getDeviceInfo(resultObject, plugin.getApplication());
resultObject.put(SharePluginInfo.ISSUE_SCENE, focusedActivityName);
resultObject.put(SharePluginInfo.ISSUE_DROP_LEVEL, dropLevelObject);
resultObject.put(SharePluginInfo.ISSUE_DROP_SUM, dropSumObject);
resultObject.put(SharePluginInfo.ISSUE_FPS, fps);
Issue issue = new Issue();
issue.setTag(SharePluginInfo.TAG_PLUGIN_FPS);
issue.setContent(resultObject);
plugin.onDetectIssue(issue);
} catch (JSONException e) {
MatrixLog.e(TAG, "json error", e);
}
}
@Override
public String toString() {
return "focusedActivityName=" + focusedActivityName
+ ", sumFrame=" + sumFrame
+ ", sumDroppedFrames=" + sumDroppedFrames
+ ", sumFrameCost=" + sumFrameCost
+ ", dropLevel=" + Arrays.toString(dropLevel);
}
}
这里主要是根据每一帧的总耗时,统计掉帧个数、FPS 等数据,最后将这些数据以一定的格式回调出去
四.总结
这篇文章主要分析了 Matrix-TraceCanary 模块中帧率 FPS、掉帧个数等数据的原理和大概流程,原理是通过 Looper.getMainLooper().setMessageLogging(Printer printer)
向其中添加 Printer 对象监听主线程中 MainLooper 每个消息的处理时间,当前处理的是不是绘制阶段产生的消息是根据 Choreographer 机制判断的,如果当前处理的是绘制阶段产生的消息,在处理消息的同时一定会回调 Choreographer 中回调队列 mCallbackQueues
中的回调方法,向回调队列 mCallbackQueues
添加回调是通过反射在 UIThreadMonitor 中实现的。
通过 Looper.getMainLooper().setMessageLogging(Printer printer)
方式实现 FPS 统计一直有一个问题,在 2.1 和 2.3 小节中也提到过,使用 Looper
机制实现的方式存在一个缺点:在打印消息处理开始日志和消息处理结束日志的时候,都会进行字符串的拼接,频繁地进行字符串的拼接也会影响性能