I. overview
When optimizing app performance, we all hope to write a slippery UI interface. We have written a blog before. It is mainly based on the performance optimization model released by Google at that time. It mainly provides some examples of UI optimization performance:
In fact, due to different configurations and long iteration history, there may be many time-consuming operations in the UI thread in the code, so we hope to have a simple detection mechanism to help us locate the time-consuming location.
This blog mainly describes how to detect Carton in UI threads. There are two typical ways to detect it.
- Logs printed with UI thread Looper
- Using Choreographer
There are some open source projects in both ways, such as:
- https://github.com/markzhai/AndroidPerformanceMonitor [mode 1]
- https://github.com/wasabeef/Takt [mode 2]
- https://github.com/friendlyrobotnyc/TinyDancer [mode 2]
In fact, I wrote this article mainly because I found a more interesting solution. The inspiration of this method comes from an article that contributed to my micro-letter.
This project is mainly used to capture the crash of UI threads. When I finish looking at the principle of this project, it can also be used as a detection card scheme. Maybe it can do something else.
So there are three schemes to detect UI carton in this paper. The principles of these three schemes are relatively simple. Next, we will introduce them one by one.
2. Use the log printed in loop()
(1) principle
Everyone knows that there is a Looper in the Android UI thread. In its loop method, Message is constantly fetched and its bound Handler is called to execute in the UI thread.
The general code is as follows:
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
So in many cases, we just need a way to detect:
msg.target.dispatchMessage(msg);
The execution time of this line of code can detect whether some UI threads are time-consuming. You can see that before and after execution of this code, if logging is set, logs such as > > > > > Dispatching to and <<< Finished to will be printed respectively.
By calculating the time difference between two log s, we can roughly code as follows:
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
Assuming our threshold is 1000ms, when I match to <>> Dispatching, I will execute a task in 1000ms milliseconds (printing out the stack information of UI threads, which will be done in non-UI threads); normally, it must be less than 1000ms, so when I match to <<< Finished, the task will be removed.
The code is as follows:
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
We use the HandlerThread class and the Looper mechanism, but in non-UI threads, if the execution time reaches the threshold we set, mLogRunnable will be executed to print out the current stack information of the UI threads; if you finish within the threshold time, the runnable will be remove d.
(2) Testing
The usage is simple. Call in the onCreate of Application:
BlockDetectByPrinter.start();
- 1
Yes.
Then, in Activity, we click a button to sleep for 2 seconds and test:
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
When you run the click, you print the 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
It prints out information about the time-consuming code, and then locates the time-consuming place through the log.
3. Using Choreographer
The Android system sends out VSYNC signals every 16 ms, triggering the rendering of the UI. The SDK contains a related class and related callbacks. In theory, the time period of two callbacks should be 16 Ms. If it is more than 16 ms, we think that there is a Katon. We mainly use the time period between two callbacks to judge:
The general code is as follows:
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
At the first time, the detection is started. If the threshold is greater than the threshold, the related stack information is output, otherwise it is removed.
The method of use is consistent with the above.
IV. Utilizing Looper Mechanism
First look at a piece of code:
new Handler(Looper.getMainLooper())
.post(new Runnable() {
@Override
public void run() {}
}
- 1
- 2
- 3
- 4
- 5
This code inserts a Message into the MessageQueue in the UI thread and eventually takes it out of the loop() method and executes it.
Assuming that I get MessageQueue in the run method and execute the original Loper. loop () method logic myself, the subsequent UI thread's MessageQueue will be handled directly by us, so that we can do something:
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
In fact, it's very simple to copy the code in Looper.loop directly here. When this message is processed, subsequent messages will be processed here.
There are variables and methods that need reflection to invoke, but it doesn't affect viewing msg.getTarget().dispatchMessage(msg); execution time, but don't use it online.
However, compared with the above two schemes, this method has no advantages, but the idea is interesting.
The method of use is consistent with the above.
Finally, we can consider exporting the Carton log to the file and analyzing it slowly. We can develop a suitable solution based on the above principles and our own needs, or refer to the existing open source solutions.