Android教你如何发现APP卡顿的实现
最近部门打算优化下APP在低端机上的卡顿情况，既然想优化，就必须获取卡顿情况，那么如何获取卡顿情况就是本文目的。
一般主线程过多的UI绘制、大量的IO操作或是大量的计算操作占用CPU，导致App界面卡顿。只要我们能在发生卡顿的时候，捕捉到主线程的堆栈信息和系统的资源使用信息，即可准确分析卡顿发生在什么函数，资源占用情况如何。那么问题就是如何有效检测Android主线程的卡顿发生？
用adb系统工具观察App的卡顿数据情况，试图重现场景来定位问题。
常用的方式是使用adbSurfaceFlinger服务和adbgfxinfo功能，在自动化操作app的过程中，使用adb获取数据来监控app的流畅情况，发现出现出现卡顿的时间段，寻找出现卡顿的场景和操作。
方式1：adbshelldumpsysSurfaceFlinger
使用‘adbshelldumpsysSurfaceFlinger'命令即可获取最近127帧的数据，通过定期执行adb命令，获取帧数来计算出帧率FPS。
方式2：adbshelldumpsysgfxinfo
使用‘adbshelldumpsysgfxinfo'命令即可获取最新128帧的绘制信息，详细包括每一帧绘制的Draw，Process，Execute三个过程的耗时，如果这三个时间总和超过16.6ms即认为是发生了卡顿。
已有的两种方案比较适合衡量回归卡顿问题的修复效果和判断某些特定场景下是否有卡顿情况，然而，这样的方式有几个明显的不足：
- 一般很难构造实际用户卡顿的环境来重现；
- 这种方式操作起来比较麻烦，需编写自动化用例，无法覆盖大量的可疑场景，测试重现耗时耗人力；
- 无法衡量静态页面的卡顿情况；
- 出现卡顿的时候app无法及时获取运行状态和信息，开发定位困难。
随着对Android源码的深入研究，也有了其他两种比较方便的方式，并且这两种方式侵入性小，占用内存低，能够更好的用在实际场景中：
- 利用UI线程的Looper打印的日志匹配；
- 使用Choreographer.FrameCallback
利用UI线程的Looper打印的日志匹配
Android主线程更新UI。如果界面1秒钟刷新少于60次，即FPS小于60，用户就会产生卡顿感觉。简单来说，Android使用消息机制进行UI更新，UI线程有个Looper，在其loop方法中会不断取出message，调用其绑定的Handler在UI线程执行。如果在handler的dispatchMesaage方法里有耗时操作，就会发生卡顿。
下面来看下Looper.loop()的源码
publicstaticvoidloop(){
finalLooperme=myLooper();
if(me==null){
thrownewRuntimeException("NoLooper;Looper.prepare()wasn'tcalledonthisthread.");
}
finalMessageQueuequeue=me.mQueue;
//Makesuretheidentityofthisthreadisthatofthelocalprocess,
//andkeeptrackofwhatthatidentitytokenactuallyis.
Binder.clearCallingIdentity();
finallongident=Binder.clearCallingIdentity();
//Allowoverridingathresholdwithasystemprop.e.g.
//adbshell'setproplog.looper.1000.main.slow1&&stop&&start'
finalintthresholdOverride=
SystemProperties.getInt("log.looper."
+Process.myUid()+"."
+Thread.currentThread().getName()
+".slow",0);
booleanslowDeliveryDetected=false;
for(;;){
Messagemsg=queue.next();//mightblock
if(msg==null){
//Nomessageindicatesthatthemessagequeueisquitting.
return;
}
//Thismustbeinalocalvariable,incaseaUIeventsetsthelogger
finalPrinterlogging=me.mLogging;
if(logging!=null){
logging.println(">>>>>Dispatchingto"+msg.target+""+
msg.callback+":"+msg.what);
}
//Makesuretheobserverwon'tchangewhileprocessingatransaction.
finalObserverobserver=sObserver;
finallongtraceTag=me.mTraceTag;
longslowDispatchThresholdMs=me.mSlowDispatchThresholdMs;
longslowDeliveryThresholdMs=me.mSlowDeliveryThresholdMs;
if(thresholdOverride>0){
slowDispatchThresholdMs=thresholdOverride;
slowDeliveryThresholdMs=thresholdOverride;
}
finalbooleanlogSlowDelivery=(slowDeliveryThresholdMs>0)&&(msg.when>0);
finalbooleanlogSlowDispatch=(slowDispatchThresholdMs>0);
finalbooleanneedStartTime=logSlowDelivery||logSlowDispatch;
finalbooleanneedEndTime=logSlowDispatch;
if(traceTag!=0&&Trace.isTagEnabled(traceTag)){
Trace.traceBegin(traceTag,msg.target.getTraceName(msg));
}
finallongdispatchStart=needStartTime?SystemClock.uptimeMillis():0;
finallongdispatchEnd;
Objecttoken=null;
if(observer!=null){
token=observer.messageDispatchStarting();
}
longorigWorkSource=ThreadLocalWorkSource.setUid(msg.workSourceUid);
try{
msg.target.dispatchMessage(msg);
if(observer!=null){
observer.messageDispatched(token,msg);
}
dispatchEnd=needEndTime?SystemClock.uptimeMillis():0;
}catch(Exceptionexception){
if(observer!=null){
observer.dispatchingThrewException(token,msg,exception);
}
throwexception;
}finally{
ThreadLocalWorkSource.restore(origWorkSource);
if(traceTag!=0){
Trace.traceEnd(traceTag);
}
}
if(logSlowDelivery){
if(slowDeliveryDetected){
if((dispatchStart-msg.when)<=10){
Slog.w(TAG,"Drained");
slowDeliveryDetected=false;
}
}else{
if(showSlowLog(slowDeliveryThresholdMs,msg.when,dispatchStart,"delivery",
msg)){
//Oncewewriteaslowdeliverylog,suppressuntilthequeuedrains.
slowDeliveryDetected=true;
}
}
}
if(logSlowDispatch){
showSlowLog(slowDispatchThresholdMs,dispatchStart,dispatchEnd,"dispatch",msg);
}
if(logging!=null){
logging.println("<<<<>>>>Dispatching";
privatestaticfinalStringEND="<<<<
设置了logging后，loop方法会回调logging.println打印出每次消息执行的时间日志：”>>>>>Dispatchingto“和”<<<<
我们可以简单实现一个LogMonitor来记录卡顿时候主线程的堆栈信息。当匹配到>>>>>Dispatching时，执行startMonitor，会在200ms（设定的卡顿阈值）后执行任务，这个任务负责在子线程（非UI线程）打印UI线程的堆栈信息。如果消息低于200ms内执行完成，就可以匹配到<<<<
LogMonitor如何实现？
publicclassLogMonitor{
privatestaticfinalStringTAG="LogMonitor";
privatestaticLogMonitorsInstance=newLogMonitor();
privateHandlerThreadmLogThread=newHandlerThread("log");
privateHandlermIoHandler;
privatestaticfinallongTIME_BLOCK=200L;
privateLogMonitor(){
mLogThread.start();
mIoHandler=newHandler(mLogThread.getLooper());
}
privatestaticRunnablemLogRunnable=newRunnable(){
@Override
publicvoidrun(){
StringBuildersb=newStringBuilder();
StackTraceElement[]stackTrace=Looper.getMainLooper().getThread().getStackTrace();
for(StackTraceElements:stackTrace){
sb.append(s.toString()+"\n");
}
Log.e(TAG,sb.toString());
}
};
publicstaticLogMonitorgetInstance(){
returnsInstance;
}
publicbooleanisMonitor(){
returnmIoHandler.hasCallbacks(mLogRunnable);
}
publicvoidstartMonitor(){
mIoHandler.postDelayed(mLogRunnable,TIME_BLOCK);
}
publicvoidremoveMonitor(){
mIoHandler.removeCallbacks(mLogRunnable);
}
}
这里我们使用HandlerThread来构造一个Handler，HandlerThread继承自Thread，实际上就一个Thread，只不过比普通的Thread多了一个Looper，对外提供自己这个Looper对象的getLooper方法，然后创建Handler时将HandlerThread中的looper对象传入。这样我们的mIoHandler对象就是与HandlerThread这个非UI线程绑定的了，它处理耗时操作将不会阻塞UI。如果UI线程阻塞超过200ms，就会在子线程中执行mLogRunnable，打印出UI线程当前的堆栈信息，如果处理消息没有超过1000ms，则会实时的remove掉这个mLogRunnable任务。
发生卡顿时打印出堆栈信息的大致内容如下，开发可以通过log定位耗时的地方。
2020-10-3014:26:13.82330359-30415/com.example.myproxypluginE/LogMonitor:java.lang.Thread.sleep(NativeMethod)
java.lang.Thread.sleep(Thread.java:443)
java.lang.Thread.sleep(Thread.java:359)
com.example.myproxyplugin.MainActivity$1.run(MainActivity.java:22)
android.os.Handler.handleCallback(Handler.java:900)
android.os.Handler.dispatchMessage(Handler.java:103)
android.os.Looper.loop(Looper.java:219)
android.app.ActivityThread.main(ActivityThread.java:8347)
java.lang.reflect.Method.invoke(NativeMethod)
com.android.internal.os.RuntimeInit$MethodAndArgsCaller.run(RuntimeInit.java:513)
com.android.internal.os.ZygoteInit.main(ZygoteInit.java:1055)
优点：用户使用app或者测试过程中都能从app层面来监控卡顿情况，一旦出现卡顿能记录app状态和信息，只要dispatchMesaage执行耗时过大都会记录下来，不再有前面两种adb方式面临的问题与不足。
缺点：需另开子线程获取堆栈信息，会消耗少量系统资源。
在实际实现中，不同手机不同Android 系统甚至是不同的ROM版本，Loop函数不一定都能打印出”>>>>>Dispatchingto“和”<<<<
优化的策略：我们知道Loop函数开始和结束必会执行println打印日志，所以优化版本将卡顿的判断改为，Loop输出第一句log时当作startMonitor，输出下一句log时当作end时刻来解决这个问题。
其实Looper中有个Observer接口可以很好的完成这个任务，只是因为被标记为hide了，所以我们不能使用，不过可以知道下。
Observer接口提供了三个方法，分别是监听任务开始，结束，发生错误的回调。
/**{@hide}*/
publicinterfaceObserver{
/**
*Calledrightbeforeamessageisdispatched.
*
*Thetokentypeisnotspecifiedtoallowtheimplementationtospecifyitsowntype.
*
*@returnatokenusedforcollectingtelemetrywhendispatchingasinglemessage.
*Thetokentokenmustbepassedbackexactlyoncetoeither
*{@linkObserver#messageDispatched}or{@linkObserver#dispatchingThrewException}
*andmustnotbereusedagain.
*
*/
ObjectmessageDispatchStarting();
/**
*CalledwhenamessagewasprocessedbyaHandler.
*
*@paramtokenTokenobtainedbypreviouslycalling
*{@linkObserver#messageDispatchStarting}onthesameObserverinstance.
*@parammsgThemessagethatwasdispatched.
*/
voidmessageDispatched(Objecttoken,Messagemsg);
/**
*Calledwhenanexceptionwasthrownwhileprocessingamessage.
*
*@paramtokenTokenobtainedbypreviouslycalling
*{@linkObserver#messageDispatchStarting}onthesameObserverinstance.
*@parammsgThemessagethatwasdispatchedandcausedanexception.
*@paramexceptionTheexceptionthatwasthrown.
*/
voiddispatchingThrewException(Objecttoken,Messagemsg,Exceptionexception);
}
利用Choreographer.FrameCallback监控卡顿
Choreographer.FrameCallback官方文档链接（https://developer.android.com/reference/android/view/Choreographer.FrameCallback.html）
我们知道，Android系统每隔16ms发出VSYNC信号，来通知界面进行重绘、渲染，每一次同步的周期为16.6ms，代表一帧的刷新频率。SDK中包含了一个相关类，以及相关回调。理论上来说两次回调的时间周期应该在16ms，如果超过了16ms我们则认为发生了卡顿，利用两次回调间的时间周期来判断是否发生卡顿（这个方案是Android4.1API16以上才支持）。
这个方案的原理主要是通过Choreographer类设置它的FrameCallback函数，当每一帧被渲染时会触发回调FrameCallback，FrameCallback回调voiddoFrame(longframeTimeNanos)函数。一次界面渲染会回调doFrame方法，如果两次doFrame之间的间隔大于16.6ms说明发生了卡顿。
publicclassFPSFrameCallbackimplementsChoreographer.FrameCallback{
privatestaticfinalStringTAG="FPS_TEST";
privatelongmLastFrameTimeNanos=0;
privatelongmFrameIntervalNanos;
publicFPSFrameCallback(longlastFrameTimeNanos){
mLastFrameTimeNanos=lastFrameTimeNanos;
//1s60帧
mFrameIntervalNanos=(long)(1000000000/60.0);
}
@Override
publicvoiddoFrame(longframeTimeNanos){
//初始化时间
if(mLastFrameTimeNanos==0){
mLastFrameTimeNanos=frameTimeNanos;
}
finallongjitterNanos=frameTimeNanos-mLastFrameTimeNanos;
if(jitterNanos>=mFrameIntervalNanos){
finallongskippedFrames=jitterNanos/mFrameIntervalNanos;
if(skippedFrames>30){
Log.i(TAG,"Skipped"+skippedFrames+"frames!"
+"Theapplicationmaybedoingtoomuchworkonitsmainthread.");
}
}
mLastFrameTimeNanos=frameTimeNanos;
//注册下一帧回调
Choreographer.getInstance().postFrameCallback(this);
}
}
本质和log没太多区别，但是这个更加通用些，不会因为机型系统原因出现不可用的问题。
示例
下面进入实战，看看代码层面是如何实现的。
MainActivity代码如下：
publicclassMainActivityextendsAppCompatActivity{
Handlerhandler=newHandler(Looper.getMainLooper());
privatefinalRunnablerunnable=newRunnable(){
@Override
publicvoidrun(){
try{
Thread.sleep(600);
handler.postDelayed(runnable,500);
}catch(InterruptedExceptione){
e.printStackTrace();
}
}
};
@Override
protectedvoidonCreate(BundlesavedInstanceState){
super.onCreate(savedInstanceState);
setContentView(R.layout.activity_main);
Choreographer.getInstance().postFrameCallback(newFPSFrameCallback(System.nanoTime()));
BlockDetectByPrinter.start();
}
@Override
protectedvoidonResume(){
super.onResume();
handler.postDelayed(runnable,500);
}
}
收集到的堆栈信息如下：
2020-10-3014:26:13.82330359-30415/com.example.myproxypluginE/LogMonitor:java.lang.Thread.sleep(NativeMethod)
java.lang.Thread.sleep(Thread.java:443)
java.lang.Thread.sleep(Thread.java:359)
com.example.myproxyplugin.MainActivity$1.run(MainActivity.java:22)
android.os.Handler.handleCallback(Handler.java:900)
android.os.Handler.dispatchMessage(Handler.java:103)
android.os.Looper.loop(Looper.java:219)
android.app.ActivityThread.main(ActivityThread.java:8347)
java.lang.reflect.Method.invoke(NativeMethod)
com.android.internal.os.RuntimeInit$MethodAndArgsCaller.run(RuntimeInit.java:513)
com.android.internal.os.ZygoteInit.main(ZygoteInit.java:1055)
对于FPSlog可以看到如下信息：
I/Choreographer:Skipped64frames! Theapplicationmaybedoingtoomuchworkonitsmainthread.
I/FPS_TEST:Skipped65frames! Theapplicationmaybedoingtoomuchworkonitsmainthread.
如果你要把上面的方法用到自己的APP中，那么还需要很多操作，具体可以阅读参考文献的内容。
参考文章
广研Android卡顿监控系统
到此这篇关于Android教你如何发现APP卡顿的实现的文章就介绍到这了,更多相关AndroidAPP卡顿内容请搜索毛票票以前的文章或继续浏览下面的相关文章希望大家以后多多支持毛票票！