Android UI性能优化 检测应用中的UI卡顿

一、概述

在做app性能优化的时候，大家都希望能够写出丝滑的UI界面，以前写过一篇博客，主要是基于Google当时发布的性能优化典范，主要提供一些UI优化性能示例：
Android UI性能优化实战 识别绘制中的性能问题

实际上，由于各种机型的配置不同、代码迭代历史悠久，代码中可能会存在很多在UI线程耗时的操作，所以我们希望有一套简单检测机制，帮助我们定位耗时发生的位置。

本篇博客主要描述如何检测应用在UI线程的卡顿，目前已经有两种比较典型方式来检测了：
利用UI线程Looper打印的日志
利用Choreographer

两种方式都有一些开源项目，例如：
https://github.com/markzhai/AndroidPerformanceMonitor [方式1]
https://github.com/wasabeef/Takt [方式2]
https://github.com/friendlyrobotnyc/TinyDancer [方式2]

其实编写本篇文章，主要是因为发现一个还比较有意思的方案，该方法的灵感来源于一篇给我微信投稿的文章：
https://github.com/android-notes/Cockroach

该项目主要用于捕获UI线程的crash，当我看完该项目原理的时候，也可以用来作为检测卡段方案，可能还可以做一些别的事情。

所以，本文出现了3种检测UI卡顿的方案，3种方案原理都比较简单，接下来将逐个介绍。

二、利用loop()中打印的日志

(1)原理

大家都知道在Android UI线程中有个Looper，在其loop方法中会不断取出Message，调用其绑定的Handler在UI线程进行执行。

大致代码如下：

public static void loop() {
final Looper me = myLooper();

final MessageQueue queue = me.mQueue;
// ...
for (;;) {
Message msg = queue.next(); // might block
// This must be in a local variable, in case a UI event sets the logger
Printer logging = me.mLogging;
if (logging != null) {
logging.println(">>>>> Dispatching to " + msg.target + " " +
msg.callback + ": " + msg.what);
}
// focus
msg.target.dispatchMessage(msg);

if (logging != null) {
logging.println("<<<<< Finished to " + msg.target + " " + msg.callback);
}

// ...
}
msg.recycleUnchecked();
}
}

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
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

所以很多时候，我们只要有办法检测：

msg.target.dispatchMessage(msg);

此行代码的执行时间，就能够检测到部分UI线程是否有耗时操作了。可以看到在执行此代码前后，如果设置了logging，会分别打印出

>>>>> Dispatching to

和

<<<<<
Finished to

这样的log。

我们可以通过计算两次log之间的时间差值，大致代码如下：

public class BlockDetectByPrinter {

public static void start() {

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(START)) {
LogMonitor.getInstance().startMonitor();
}
if (x.startsWith(END)) {
LogMonitor.getInstance().removeMonitor();
}
}
});

}
}

1
2
3
4
5
6
7
8
9
10
11
12
13
14
15
16
17
18
19
20
21
22
1
2
3
4
5
6
7
8
9
10
11
12
13
14
15
16
17
18
19
20
21
22

假设我们的阈值是1000ms，当我在匹配到

>>>>> Dispatching

时，我会在1000ms毫秒后执行一个任务（打印出UI线程的堆栈信息，会在非UI线程中进行）；正常情况下，肯定是低于1000ms执行完成的，所以当我匹配到

<<<<<
Finished

，会移除该任务。

大概代码如下：

public class LogMonitor {

private static LogMonitor sInstance = new LogMonitor();
private HandlerThread mLogThread = new HandlerThread("log");
private Handler mIoHandler;
private static final long TIME_BLOCK = 1000L;

private LogMonitor() {
mLogThread.start();
mIoHandler = new Handler(mLogThread.getLooper());
}

private static Runnable mLogRunnable = new Runnable() {
@Override
public void run() {
StringBuilder sb = new StringBuilder();
StackTraceElement[] stackTrace = Looper.getMainLooper().getThread().getStackTrace();
for (StackTraceElement s : stackTrace) {
sb.append(s.toString() + "\n");
}
Log.e("TAG", sb.toString());
}
};

public static LogMonitor getInstance() {
return sInstance;
}

public boolean isMonitor() {
return mIoHandler.hasCallbacks(mLogRunnable);
}

public void startMonitor() {
mIoHandler.postDelayed(mLogRunnable, TIME_BLOCK);
}

public void removeMonitor() {
mIoHandler.removeCallbacks(mLogRunnable);
}

}

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
41
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
41

我们利用了HandlerThread这个类，同样利用了Looper机制，只不过在非UI线程中，如果执行耗时达到我们设置的阈值，则会执行

mLogRunnable

，打印出UI线程当前的堆栈信息；如果你阈值时间之内完成，则会remove掉该runnable。

（2）测试

用法很简单，在Application的onCreate中调用：

BlockDetectByPrinter.start();

1
1

即可。

然后我们在Activity里面，点击一个按钮，让睡眠2s，测试下：

findViewById(R.id.id_btn02)
.setOnClickListener(new View.OnClickListener() {
@Override
public void onClick(View v) {
try {
Thread.sleep(2000);
} catch (InterruptedException e) {
}
}
});

1
2
3
4
5
6
7
8
9
10
1
2
3
4
5
6
7
8
9
10

运行点击时，会打印出log：

02-21 00:26:26.408 2999-3014/com.zhy.testlp E/TAG:
java.lang.VMThread.sleep(Native Method)
java.lang.Thread.sleep(Thread.java:1013)
java.lang.Thread.sleep(Thread.java:995)
com.zhy.testlp.MainActivity$2.onClick(MainActivity.java:70)
android.view.View.performClick(View.java:4438)
android.view.View$PerformClick.run(View.java:18422)
android.os.Handler.handleCallback(Handler.java:733)
android.os.Handler.dispatchMessage(Handler.java:95)

1
2
3
4
5
6
7
8
9
1
2
3
4
5
6
7
8
9

会打印出耗时相关代码的信息，然后可以通过该log定位到耗时的地方。

三、 利用Choreographer

Android系统每隔16ms发出VSYNC信号，触发对UI进行渲染。SDK中包含了一个相关类，以及相关回调。理论上来说两次回调的时间周期应该在16ms，如果超过了16ms我们则认为发生了卡顿，我们主要就是利用两次回调间的时间周期来判断：

大致代码如下：

public class BlockDetectByChoreographer {
public static void start() {
Choreographer.getInstance()
.postFrameCallback(new Choreographer.FrameCallback() {
@Override
public void doFrame(long l) {
if (LogMonitor.getInstance().isMonitor()) {
LogMonitor.getInstance().removeMonitor();
}
LogMonitor.getInstance().startMonitor();
Choreographer.getInstance().postFrameCallback(this);
}
});
}
}

1
2
3
4
5
6
7
8
9
10
11
12
13
14
15
1
2
3
4
5
6
7
8
9
10
11
12
13
14
15

第一次的时候开始检测，如果大于阈值则输出相关堆栈信息，否则则移除。

使用方式和上述一致。

四、 利用Looper机制

先看一段代码：

new Handler(Looper.getMainLooper())
.post(new Runnable() {
@Override
public void run() {}
}

1
2
3
4
5
1
2
3
4
5

该代码在UI线程中的MessageQueue中插入一个Message，最终会在loop()方法中取出并执行。

假设，我在run方法中，拿到MessageQueue，自己执行原本的

Looper.loop()

方法逻辑，那么后续的UI线程的Message就会将直接让我们处理，这样我们就可以做一些事情：

public class BlockDetectByLooper {
private static final String FIELD_mQueue = "mQueue";
private static final String METHOD_next = "next";

public static void start() {
new Handler(Looper.getMainLooper()).post(new Runnable() {
@Override
public void run() {
try {
Looper mainLooper = Looper.getMainLooper();
final Looper me = mainLooper;
final MessageQueue queue;
Field fieldQueue = me.getClass().getDeclaredField(FIELD_mQueue);
fieldQueue.setAccessible(true);
queue = (MessageQueue) fieldQueue.get(me);
Method methodNext = queue.getClass().getDeclaredMethod(METHOD_next);
methodNext.setAccessible(true);
Binder.clearCallingIdentity();
for (; ; ) {
Message msg = (Message) methodNext.invoke(queue);
if (msg == null) {
return;
}
LogMonitor.getInstance().startMonitor();
msg.getTarget().dispatchMessage(msg);
msg.recycle();
LogMonitor.getInstance().removeMonitor();
}
} catch (Exception e) {
e.printStackTrace();
}

}
});
}
}

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
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

其实很简单，将Looper.loop里面本身的代码直接copy来了这里。当这个消息被处理后，后续的消息都将会在这里进行处理。

中间有变量和方法需要反射来调用，不过不影响查看

msg.getTarget().dispatchMessage(msg);

执行时间，但是就不要在线上使用这种方式了。

不过该方式和以上两个方案对比，并无优势，不过这个思路挺有意思的。

使用方式和上述一致。

最后，可以考虑将卡顿日志输出到文件，慢慢分析；可以结合上述原理以及自己需求开发做一个合适的方案，也可以参考已有开源方案。

参考

https://github.com/markzhai/AndroidPerformanceMonitor
https://github.com/wasabeef/Takt
https://github.com/friendlyrobotnyc/TinyDancer