Android性能监测:Looper机制监测卡顿和丢帧(二)
Android性能监测:Looper机制监测卡顿和丢帧(二)
附录1使用Android的Choreographer监测App发生的UI卡顿丢帧问题。Choreographer本身依赖于Android主线程的Looper消息机制。
发生在Android主线程的每16ms重绘操作依赖于Main Looper中消息的发送和获取。如果App一切运行正常,无卡顿无丢帧现象发生,那么开发者的代码在主线程Looper消息队列中发送和接收消息的时间会很短,理想情况是16ms,这是也是Android系统规定的时间。但是,如果一些发生在主线程的代码写的太重,执行任务花费时间太久,就会在主线程延迟Main Looper的消息在16ms尺度范围内的读和写。
先看下Android官方实现的Looper中loop()函数代码官方实现:
/** * Run the message queue in this thread. Be sure to call * {@link #quit()} to end the loop. */ 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 (;;) { 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; 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); end = (slowDispatchThresholdMs == 0) ? 0 : SystemClock.uptimeMillis(); } finally { if (traceTag != 0) { Trace.traceEnd(traceTag); } } if (slowDispatchThresholdMs > 0) { final long time = end - start; if (time > slowDispatchThresholdMs) { Slog.w(TAG, "Dispatch took " + time + "ms on " + Thread.currentThread().getName() + ", h=" + msg.target + " cb=" + msg.callback + " msg=" + msg.what); } } if (logging != null) { logging.println("<<<<< Finished to " + msg.target + " " + msg.callback); } // Make sure that during the course of dispatching the // identity of the thread wasn't corrupted. final long newIdent = Binder.clearCallingIdentity(); if (ident != newIdent) { Log.wtf(TAG, "Thread identity changed from 0x" + Long.toHexString(ident) + " to 0x" + Long.toHexString(newIdent) + " while dispatching to " + msg.target.getClass().getName() + " " + msg.callback + " what=" + msg.what); } msg.recycleUnchecked(); } }
在loop()函数中,Android完成了Looper消息队列的分发,在分发消息开始,会打印一串log日志:
logging.println(">>>>> Dispatching to " + msg.target + " " + msg.callback + ": " + msg.what);
同时在消息处理结束后也会打印一串消息日志:
logging.println("<<<<< Finished to " + msg.target + " " + msg.callback);
正常的情况下,分发消息开始到消息结束,理想的情况下应该在16ms以内。但是分发处理的消息到上层,由开发者代码接管并处理,如果耗时太久,就很可能超出16ms,也即发生了丢帧,超时太多,由于Android系统依赖主线程Looper重绘UI的消息迟迟得不到处理,那么就导致绘图动作停滞,用户视觉上就会感受到卡顿。
利用这一特性和情景,可以使用主线程的Looper监测系统发生的卡顿和丢帧。具体是这样的:首先给App的主线程Looper注册一个自己的消息日志输出打印器,正常情况下,该日志打印器将输出全部的Android Looper上的日志,但是在这里,技巧性的过滤两个特殊日志:
>>>>> Dispatching to
表示Looper开始分发主线程上的消息。
<<<<< Finished to
表示Looper分发主线程上的消失结束。
从>>>>> Dispatching to 到 <<<<< Finished to 之间这段操作,就是留给开发者所写的代码发生在上层主线程操作的动作,通常所说的卡顿也就发生这一段。
正确情况下,从消息分发(>>>>> Dispatching to)开始,到消息处理结束(<<<<< Finished to),这段操作理想情况应在16ms以内完成,如果超过这一时间,也即意味着卡顿和丢帧。
现在设计一种技巧性的编程方案:在(>>>>> Dispatching to)开始时候,延时一定时间(THREAD_HOLD)执行一个线程,延时时间为THREAD_HOLD,该线程只完成打印当前Android堆栈的信息。THREAD_HOLD即为开发者意图捕捉到的超时时间。如果没什么意外,该线程在THREAD_HOLD后,就打印出当前Android的堆栈信息。巧就巧妙在利用这一点儿,因为延时THREAD_HOLD执行的线程和主线程Looper中的线程是并行执行的,当在>>>>> Dispatching to时刻把延时线程任务构建完抛出去等待THREAD_HOLD后执行,而当前的Looper线程中的消息分发也在执行,这两个是并发执行的不同线程。
设想如果Looper线程中的操作代码很快就执行完毕,不到16ms就到了<<<<< Finished to,那么毫无疑问当前的主线程无卡顿和丢帧发生。如果特意把THREAD_HOLD设置成大于16ms的延时时间,比如1000ms,如果线程运行顺畅不卡顿无丢帧,那么从>>>>> Dispatching to到达<<<<< Finished to后,把延时THREAD_HOLD执行的线程删除掉,那么线程就不会输出任何堆栈信息。若不行主线程发生阻塞,当从>>>>> Dispatching to到达<<<<< Finished to花费1000ms甚至更长时间后,而由于到达<<<<< Finished to的时候没来得及把堆栈打印线程删除掉,因此就输出了当前堆栈信息,此堆栈信息刚好即为发生卡顿和丢帧的代码堆栈,正好就是所需的卡顿和丢帧检测代码。
如代码:
package zhangphil.test;import android.os.Bundle;import android.os.Handler;import android.os.HandlerThread;import android.os.Looper;import android.support.annotation.Nullable;import android.support.v7.app.AppCompatActivity;import android.util.Log;import android.util.Printer;import android.view.View;public class ANRActivity extends AppCompatActivity { private final String TAG = "卡顿性能检测"; private CheckTask mCheckTask = new CheckTask(); @Override protected void onCreate(@Nullable Bundle savedInstanceState) { super.onCreate(savedInstanceState); check(); setContentView(R.layout.activity_anr); findViewById(R.id.button).setOnClickListener(new View.OnClickListener() { @Override public void onClick(View v) { uiLongTimeWork(); } }); } private void check() { Looper.getMainLooper().setMessageLogging(new Printer() { private final String START = ">>>>> Dispatching to"; private final String END = "<<<<< Finished to"; @Override public void println(String s) { if (s.startsWith(START)) { mCheckTask.start(); } else if (s.startsWith(END)) { mCheckTask.end(); } } }); } private class CheckTask { private HandlerThread mHandlerThread = new HandlerThread("卡顿检测"); private Handler mHandler; private final int THREAD_HOLD = 1000; public CheckTask() { mHandlerThread.start(); mHandler = new Handler(mHandlerThread.getLooper()); } private Runnable mRunnable = new Runnable() { @Override public void run() { log(); } }; public void start() { mHandler.postDelayed(mRunnable, THREAD_HOLD); } public void end() { mHandler.removeCallbacks(mRunnable); } } private void uiLongTimeWork() { try { Thread.sleep(1000); } catch (InterruptedException e) { e.printStackTrace(); } } /** * 输出当前异常或及错误堆栈信息。 */ private void log() { StringBuilder sb = new StringBuilder(); StackTraceElement[] stackTrace = Looper.getMainLooper().getThread().getStackTrace(); for (StackTraceElement s : stackTrace) { sb.append(s + "\n"); } Log.w(TAG, sb.toString()); }}
运行输出:
07-24 10:12:08.476 17064-17110/zhangphil.test W/卡顿性能检测: java.lang.Thread.sleep(Native Method) java.lang.Thread.sleep(Thread.java:386) java.lang.Thread.sleep(Thread.java:327) zhangphil.test.ANRActivity.uiLongTimeWork(ANRActivity.java:78) zhangphil.test.ANRActivity.access$000(ANRActivity.java:13) zhangphil.test.ANRActivity$1.onClick(ANRActivity.java:28) android.view.View.performClick(View.java:6291) android.view.View$PerformClick.run(View.java:24931) android.os.Handler.handleCallback(Handler.java:808) android.os.Handler.dispatchMessage(Handler.java:101) android.os.Looper.loop(Looper.java:166) android.app.ActivityThread.main(ActivityThread.java:7425) java.lang.reflect.Method.invoke(Native Method) com.android.internal.os.Zygote$MethodAndArgsCaller.run(Zygote.java:245) com.android.internal.os.ZygoteInit.main(ZygoteInit.java:921)
可以看到当点击按钮故意制造一个卡顿后,卡顿被检测到,并且输出和定位到了卡顿的具体代码位置。
总结起来,利用主线程的Looper检测卡顿和丢帧,从成对的消息分发(>>>>> Dispatching to),到消息处理结束(<<<<< Finished to),正常的理想时间应该在16ms以内,若当前代码耗时太多,这一段时间就会超过16ms。假设现在要检测耗时超过1秒(1000ms)的耗时操作,那就在>>>>> Dispatching to时刻,抛出一个延时执行的线程,该线程打印当前堆栈的信息,延时的时间特意设置成阈值1000。此种情况下,正常顺畅执行无卡顿无丢帧的代码从>>>>> Dispatching to到<<<<< Finished to之间不会超过设置的阈值1000ms,因此当Looper中的代码到达<<<<< Finished to就把之前抛出来延时执行的线程删除掉,也就不会输出任何堆栈信息。但是只有当耗时代码从>>>>> Dispatching to到<<<<< Finished to超过了1000ms,由于Looper中由于耗时操作很晚(超过我们设定的阈值)才到达<<<<< Finished to,没赶上删掉堆栈打印线程,于是堆栈线程得以有机会打印当前堆栈信息,这就是卡顿和丢帧的发生场景检测机制。
事实上可以灵活设置延时阈值THREAD_HOLD,从而检测到任何大于或等于该时间的耗时操作。
附录:
1,《Android性能:通过Choreographer检测UI丢帧和卡顿》链接:https://blog.csdn.net/zhangphil/article/details/81129246
更多相关文章
- Android进程与线程基本知识
- 【转】有关Android线程的学习
- 浅析Android线程模型一
- Android(安卓)线程学习
- Android面试官,面试时总喜欢挖基础坑,整理了26道面试题牢固你基础!
- Android(安卓)Framework分析 ---- 1消息处理机制 java层
- Android中的线程与进程之间的关系简单解释
- Android(安卓)Framework分析 ---- 1消息处理机制 java层
- Android的消息机制,用Android线程间通信的Message机制,Android中Ha