【问答集】主线程任务队列耗时如何分析？
可以通过Looper.loop()方法的log进行查看。
在Android中所有的事件（Activity、Fragment生命周期方法，点击事件等）最终都会被转换（封装）成Message，再交给主线程去执行。
任务队列耗时可以理解为处理每个msg的时间。
Looper.loop()方法分析：（Android api 30）
public static void loop() {
final Looper me = myLooper();
me.mInLoop = true;
final MessageQueue queue = me.mQueue;
for (;;) {
Message msg = queue.next(); // might block
if (msg == null) {
// No message indicates that the message queue is quitting.
// Q1、这个地方为什么可以return呢？第一个猜测是系统对主线程的message进行了非null验证，保证了到这里的msg不会为null，不然主线程的loop方法都退出了。第二个猜测是系统有什么方法可以把loop方法再调用一下，保证循环可用。这个需要再做研究。
return;
}
// here1：关键就在这里，开始的时候，会去打印一条日志
// This must be in a local variable, in case a UI event sets the logger
final Printer logging = me.mLogging;
if (logging != null) {
logging.println(">>>>> Dispatching to " + msg.target + " " +
msg.callback + ": " + msg.what);
}
// here2：msg分发给对应的target（也就是handler）进行处理
msg.target.dispatchMessage(msg);
// here3：关键就在这里，结束的时候，也会去打印一条日志，通过计算两条日志的时间差，就可以得到每条消息的处理时间
if (logging != null) {
logging.println("<<<<< Finished to " + msg.target + " " + msg.callback);
}
}
}
分析：
1、主要的方法就是靠注释：here1-here3
2、分析源码的时候新发现了一个问题（注释:Q1），要去思考一下。
验证1——生命周期耗时
public class MainActivity extends AppCompatActivity {
private static final String TAG = "MainActivity";
private long lastTime;
@Override
protected void onCreate(Bundle savedInstanceState) {
long startTime = System.currentTimeMillis();
Log.i(TAG, "onCreate:" + startTime);
super.onCreate(savedInstanceState);
setContentView(R.layout.activity_main);
mockSpendTimeOperate();
Looper.myLooper().setMessageLogging(new Printer() {
@Override
public void println(String x) {
Log.i(TAG, x);
if (lastTime != 0L) {
long spendTime = System.currentTimeMillis() - lastTime;
lastTime = 0L;
Log.i(TAG, "println: " + spendTime);
} else {
lastTime = System.currentTimeMillis();
}
}
});
Log.i(TAG, "onCreate:" + (System.currentTimeMillis() - startTime));
}
private void mockSpendTimeOperate() {
try {
Thread.sleep(1000L);
} catch (InterruptedException e) {
e.printStackTrace();
}
}
}
这里我预期的是：能够把onCreate等生命周期方法的执行时间给打印出来，但是结果和预期并不符合。
结果：
image-20210802204749204.png
失败了。。。
用这种方法是统计不到的 Activity 的生命周期方法。
Q2：为什么会统计不到呢？
是我我这种方法不对？还是原理就没理解好呢？
看来还是要对Activity的生命周期方法调用过程再做一个分析。
Q3：那统计耗时的方法有哪些呢？
1、手动加日志，再计算
2、字节码插入日志代码进行统计（忘了叫啥了，这个得再学一下）
3、还有啥呢？
那既然不能统计生命周期的方法，就再看看它能不能统计到我们自己发的msg耗时：
验证2：统计我们自己写的代码、发的msg
public class MainActivity extends AppCompatActivity {
private static final String TAG = "MainActivity";
private long lastTime;
@Override
protected void onCreate(Bundle savedInstanceState) {
long startTime = System.currentTimeMillis();
Log.i(TAG, "onCreate:" + startTime);
super.onCreate(savedInstanceState);
setContentView(R.layout.activity_main);
// here：就用一个点击事件来测一下
Button btnTestMsg = findViewById(R.id.btn_testMsg);
btnTestMsg.setOnClickListener(v -> mockSpendTimeOperate());
mockSpendTimeOperate();
// 首先拿到 主线程的 looper，把Printer对象设置进去。
// 这里的目的就是统计耗时
Looper.myLooper().setMessageLogging(new Printer() {
@Override
public void println(String x) {
Log.i(TAG, x);
if (lastTime != 0L) {
long spendTime = System.currentTimeMillis() - lastTime;
lastTime = 0L;
Log.i(TAG, "msg spendTime: " + spendTime);
} else {
lastTime = System.currentTimeMillis();
}
}
});
Log.i(TAG, "onCreate:" + (System.currentTimeMillis() - startTime));
}
private void mockSpendTimeOperate() {
try {
Thread.sleep(1000L);
} catch (InterruptedException e) {
e.printStackTrace();
}
}
}
这里用点击事件来测一下，能不能打印出时间来呢？
结果：
image-20210802215027114.png
这次和预期的完全符合了
然后再来看看系统给的日志：
Dispatching to Handler (android.view.ViewRootImpl
PerformClick@9ede30f: 0
image-20210802215316683.png
因此Button点击事件的msg信息为：
target：ViewRootImpl$ViewRootHandler，处理msg的handler。也是发送这条msg的Handler。
callback：android.view.View$PerformClick，msg的callback实际就是一个Runnable，就是一坨可执行的代码。
Message.java
/*package*/ Runnable callback;
callback和handlerMessage方法的关系如下：
Handler.java
public void dispatchMessage(@NonNull Message msg) {
if (msg.callback != null) {
handleCallback(msg);
} else {
if (mCallback != null) {
if (mCallback.handleMessage(msg)) {
return;
}
}
handleMessage(msg);
}
}
private static void handleCallback(Message message) {
message.callback.run();
}
msg.what：找到具体的事件，一般都是通过Switch去匹配。
因此，Button的点击就执行了callback的run方法，如下：
private final class PerformClick implements Runnable {
@Override
public void run() {
recordGestureClassification(TOUCH_GESTURE_CLASSIFIED__CLASSIFICATION__SINGLE_TAP);
performClickInternal();
}
}
private boolean performClickInternal() {
// Must notify autofill manager before performing the click actions to avoid scenarios where
// the app has a click listener that changes the state of views the autofill service might
// be interested on.
notifyAutofillManagerOnClick();
return performClick();
}
public boolean performClick() {
// We still need to call this method to handle the cases where performClick() was called
// externally, instead of through performClickInternal()
notifyAutofillManagerOnClick();
final boolean result;
final ListenerInfo li = mListenerInfo;
if (li != null && li.mOnClickListener != null) {
playSoundEffect(SoundEffectConstants.CLICK);
// here1：执行了我们的onClick事件
li.mOnClickListener.onClick(this);
result = true;
} else {
result = false;
}
sendAccessibilityEvent(AccessibilityEvent.TYPE_VIEW_CLICKED);
notifyEnterOrExitForAutoFillIfNeeded(true);
return result;
}
看注释here1处，最终执行了我们的onClick方法。
那还有一个问题？msg是在哪里发送的呢？
首先我们知道发送msg的Handler是android.view.ViewRootImpl$ViewRootHandler，但一个Handler是可以在多处使用的，我们试试这样找：
在点击事件里把调用栈打印出来：
Button btnTestMsg = findViewById(R.id.btn_testMsg);
btnTestMsg.setOnClickListener(v -> {
mockSpendTimeOperate();
Exception dumpStack = new Exception("dumpStack");
dumpStack.printStackTrace();
});
image-20210802222659171.png
image-20210802223357490.png
很可惜，毫无收获，思路不对。
那我们再回过去看看
private final class PerformClick implements Runnable {
@Override
public void run() {
recordGestureClassification(TOUCH_GESTURE_CLASSIFIED__CLASSIFICATION__SINGLE_TAP);
performClickInternal();
}
}
前面说了，最终会调用这坨代码，那看看它在哪调用的就好了（即这个callback是在哪设置给msg的）。
好在幸运的是，这个 PerformClick 是private的。
直接搜素 new PerformClick()找到唯一使用地方：
image-20210802223357490.png
是在 onTouchEvent()中的。看到这肯定就知道是走的事件分发了，一切都串联了起来。正着分析，反着分析，都是一样的。
也就是从 Activity 传到 view 的那套东西（事件方法：Activity-Window-DecorView-ViewGroup）了。
但到这里还是没有回答：msg是从哪里发出来的呢？？？
Q4：问题又来了，点击事件的msg是从哪里发出来的呢？
还没搞懂，再朝着这个方向学一下。
思考：这个就沿着找——调用 Activity#dispatchTouchEvent()方法的地方。然后再往上找。
Q5：事件又是如何传递到Activity的呢？
这个代码我还没看，又有新任务了。
然后其实看Looper.loop()方法时，还发现了个东西：
Looper.java
private static Observer sObserver;
public static void setObserver(@Nullable Observer observer) {
sObserver = observer;
}
public static void loop() {
final Looper me = myLooper();
me.mInLoop = true;
final MessageQueue queue = me.mQueue;
for (;;) {
Message msg = queue.next(); // might block
if (msg == null) {
// No message indicates that the message queue is quitting.
return;
}
// Make sure the observer won't change while processing a transaction.
final Observer observer = sObserver;
final long dispatchStart = needStartTime ? SystemClock.uptimeMillis() : 0;
final long dispatchEnd;
Object token = null;
if (observer != null) {
// here1：
token = observer.messageDispatchStarting();
}
long origWorkSource = ThreadLocalWorkSource.setUid(msg.workSourceUid);
try {
msg.target.dispatchMessage(msg);
if (observer != null) {
// here2：
observer.messageDispatched(token, msg);
}
dispatchEnd = needEndTime ? SystemClock.uptimeMillis() : 0;
} catch (Exception exception) {
if (observer != null) {
observer.dispatchingThrewException(token, msg, exception);
}
throw exception;
} finally {
ThreadLocalWorkSource.restore(origWorkSource);
if (traceTag != 0) {
Trace.traceEnd(traceTag);
}
}
}
}
我们可以设一个observe对象进去，那么在dispatch msg 的时候就会回调我们。
observe接口提供了3个方法，根据上面的代码，我们可以在注释here1处，返回一个当前时间，再在结束的时候here2处，算一下耗时，也可以计算时间，算是一个简单的运用。
public interface Observer {
/**
* Called right before a message is dispatched.
*
* <p> The token type is not specified to allow the implementation to specify its own type.
*
* @return a token used for collecting telemetry when dispatching a single message.
* The token token must be passed back exactly once to either
* {@link Observer#messageDispatched} or {@link Observer#dispatchingThrewException}
* and must not be reused again.
*
*/
Object messageDispatchStarting();
/**
* Called when a message was processed by a Handler.
*
* @param token Token obtained by previously calling
* {@link Observer#messageDispatchStarting} on the same Observer instance.
* @param msg The message that was dispatched.
*/
void messageDispatched(Object token, Message msg);
/**
* Called when an exception was thrown while processing a message.
*
* @param token Token obtained by previously calling
* {@link Observer#messageDispatchStarting} on the same Observer instance.
* @param msg The message that was dispatched and caused an exception.
* @param exception The exception that was thrown.
*/
void dispatchingThrewException(Object token, Message msg, Exception exception);
}
知识点：
Handler机制、Looper#loop()、点击事件分发
待解决问题汇总：
Q1、下面注释
here1处为什么可以return呢？第一个猜测是系统对主线程的message进行了非null验证，保证了到这里的msg不会为null，不然主线程的loop方法都退出了。第二个猜测是系统有什么方法可以把loop方法再调用一下，保证循环可用。这个需要再做研究。
public static void loop() {
final Looper me = myLooper();
me.mInLoop = true;
final MessageQueue queue = me.mQueue;
for (;;) {
Message msg = queue.next(); // might block
if (msg == null) {
// No message indicates that the message queue is quitting.
// here1
return;
}
Q2：为什么会统计不到呢？
是我我这种方法不对？还是原理就没理解好呢？
看来还是要对Activity的生命周期方法调用过程再做一个分析。
Q3：那统计耗时的方法有哪些呢？
1、手动加日志，再计算
2、字节码插入日志代码进行统计（忘了叫啥了，这个得再学一下）
3、还有啥呢？
Q4：问题又来了，点击事件的msg是从哪里发出来的呢？
还没搞懂，再朝着这个方向学一下。
思考：这个就沿着找——调用 Activity#dispatchTouchEvent()方法的地方。然后再往上找。
Q5：事件又是如何传递到Activity的呢？
这个代码我还没看，又有新任务了。
参考：
他讲的也没有很清楚，比如要如何实践也没讲，算是给了个方向。
网友评论