一、背景

應用的使用流暢度，是衡量用戶體驗的重要標準之一。Android 由于機型配置和系統的不同，項目復雜App場景豐富，代碼多人參與迭代歷史較久，代碼可能會存在很多UI線程耗時的操作，實際測試時候也會偶爾發現某些業務場景發生卡頓的現象，用戶也經常反饋和投訴App使用遇到卡頓。因此，我們越來越關注和提升用戶體驗的流暢度問題。

二、方案

基于這樣的痛點，我們希望能使用一套有效的檢測機制，能夠覆蓋各種可能出現的卡頓場景，一旦發生卡頓，能幫助我們更方便地定位耗時卡頓發生的地方，記錄下具體的信息和堆棧，直接從代碼程度給到開發定位卡頓問題。我們設想的Android卡頓監控系統需要達到幾項基本功能：

• 如何有效地監控到App發生卡頓，同時在發生卡頓時正確記錄app的狀態，如堆棧信息，CPU占用，內存占用，IO使用情況等等；

• 統計到的卡頓信息上報到監控平臺，需要處理分析分類上報內容，并通過平臺Web直觀簡便地展示，供開發跟進處理。

三、如何從App層面監控卡頓？

我們的思路是，一般主線程過多的UI繪制、大量的IO操作或是大量的計算操作占用CPU，導致App界面卡頓。只要我們能在發生卡頓的時候，捕捉到主線程的堆棧信息和系統的資源使用信息，即可準確分析卡頓發生在什么函數，資源占用情況如何。那么問題就是如何有效檢測Android主線程的卡頓發生，目前業界兩種主流有效的app監控方式如下：

• 利用UI線程的Looper打印的日志匹配；

• 使用Choreographer.FrameCallback。

3.1、利用UI線程的Looper打印的日志匹配判斷是否卡頓

Android主線程更新UI。如果界面1秒鐘刷新少于60次，即FPS小于60，用戶就會產生卡頓感覺。簡單來說，Android使用消息機制進行UI更新，UI線程有個Looper，在其loop方法中會不斷取出message，調用其綁定的Handler在UI線程執行。如果在handler的dispatchMesaage方法里有耗時操作，就會發生卡頓。

3.1.1、Looper.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 blockif (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 loggerPrinter logging = me.mLogging;        if (logging != null) {logging.println(">>>>> Dispatching to " + msg.target + " " +msg.callback + ": " + msg.what);}msg.target.dispatchMessage(msg);        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();}
}

只要檢測第25行代碼msg.target.dispatchMessage(msg) 的執行時間，就能檢測到部分UI線程是否有耗時的操作。注意到這行執行代碼的前后，有兩個logging.println函數，如果設置了logging，會分別打印出”>>>>> Dispatching to “和”<<<<< Finished to “這樣的日志，這樣我們就可以通過兩次log的時間差值，來計算dispatchMessage的執行時間，從而設置閾值判斷是否發生了卡頓。

3.1.2、如何設置logging呢？

我們看第19行代碼me.mLogging源碼

public final class Looper {  private Printer mLogging;  public void setMessageLogging(@Nullable Printer printer) {  mLogging = printer;  }  
}  public interface Printer {  void println(String x);  
}

Looper的mLogging是私有的，并且提供了setMessageLogging(@Nullable Printer printer)方法，所以我們可以自己實現一個Printer，在通過setMessageLogging()方法傳入即可，代碼如下：

public class BlockDetectByPrinter {    public static void start() {Looper.getMainLooper().setMessageLogging(new Printer() { private static final String START = ">>>>> Dispatching"; private static final String END = "<<<<< Finished";@Overridepublic void println(String x) {if (x.startsWith(START)) {LogMonitor.getInstance().startMonitor();}  if (x.startsWith(END)) {LogMonitor.getInstance().removeMonitor();}}});}
}

設置了logging后，loop方法會回調logging.println打印出每次消息執行的時間日志：”>>>>> Dispatching to “和”<<<<< Finished to “。BlockDetectByPrinter的使用則在Application的onCreate方法中調用 BlockDetectByPrinter.start() 即可。

我們可以簡單實現一個LogMonitor來記錄卡頓時候主線程的堆棧信息。當匹配到>>>>> Dispatching時，執行startMonitor，會在1000ms（設定的卡頓閾值）后執行任務，這個任務負責在子線程（非UI線程）打印UI線程的堆棧信息。如果消息低于1000ms內執行完成，就可以匹配到<<<<< Finished日志，那么在打印堆棧任務啟動前執行removeMonitor取消了這個任務，則認為沒有卡頓的發生；如果消息超過1000ms才執行完畢，此時認為發生了卡頓，并打印UI線程的堆棧信息。

3.1.3、LogMonitor如何實現？

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() {        @Overridepublic 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);}
}

這里我們使用HandlerThread來構造一個Handler，HandlerThread繼承自Thread，實際上就一個Thread，只不過比普通的Thread多了一個Looper，對外提供自己這個Looper對象的getLooper方法，然后創建Handler時將HandlerThread中的looper對象傳入。這樣我們的mIoHandler對象就是與HandlerThread這個非UI線程綁定的了，它處理耗時操作將不會阻塞UI。如果UI線程阻塞超過1000ms，就會在子線程中執行mLogRunnable，打印出UI線程當前的堆棧信息，如果處理消息沒有超過1000ms，則會實時的remove掉這個mLogRunnable任務。

發生卡頓時打印出堆棧信息的大致內容如下，開發可以通過log定位耗時的地方。

優點：用戶使用app或者測試過程中都能從app層面來監控卡頓情況，一旦出現卡頓能記錄app狀態和信息， 只要dispatchMesaage執行耗時過大都會記錄下來，不再有前面兩種adb方式面臨的問題與不足。

缺點：需另開子線程獲取堆棧信息，會消耗少量系統資源。

在實際實現中，不同手機不同Android系統甚至是不同的ROM版本，Loop函數不一定都能打印出”>>>>> Dispatching to “和”<<<<< Finished to “這樣的日志，導致該方式無法進行。

優化的策略：我們知道Loop函數開始和結束必會執行println打印日志，所以優化版本將卡頓的判斷改為，Loop輸出第一句log時當作startMonitor，輸出下一句log時當作end時刻來解決這個問題。

3.2、利用Choreographer.FrameCallback監控卡頓

Choreographer.FrameCallback官方文檔鏈接（https://developer.android.com/reference/android/view/Choreographer.FrameCallback.html）

我們知道， Android系統每隔16ms發出VSYNC信號，來通知界面進行重繪、渲染，每一次同步的周期為16.6ms，代表一幀的刷新頻率。SDK中包含了一個相關類，以及相關回調。理論上來說兩次回調的時間周期應該在16ms，如果超過了16ms我們則認為發生了卡頓，利用兩次回調間的時間周期來判斷是否發生卡頓（這個方案是Android 4.1 API 16以上才支持）。

這個方案的原理主要是通過Choreographer類設置它的FrameCallback函數，當每一幀被渲染時會觸發回調FrameCallback， FrameCallback回調void doFrame (long frameTimeNanos)函數。一次界面渲染會回調doFrame方法，如果兩次doFrame之間的間隔大于16.6ms說明發生了卡頓。

public class BlockDetectByChoreographer {public static void start() {Choreographer.getInstance().postFrameCallback(new Choreographer.FrameCallback() { long lastFrameTimeNanos = 0; long currentFrameTimeNanos = 0;@Overridepublic void doFrame(long frameTimeNanos) { if(lastFrameTimeNanos == 0){lastFrameTimeNanos == frameTimeNanos;}currentFrameTimeNanos = frameTimeNanos;long diffMs = TimeUnit.MILLISECONDS.convert(currentFrameTimeNanos-lastFrameTimeNanos, TimeUnit.NANOSECONDS);if (diffMs > 16.6f) {            long droppedCount = (int)diffMs / 16.6;}if (LogMonitor.getInstance().isMonitor()) {LogMonitor.getInstance().removeMonitor();                    } LogMonitor.getInstance().startMonitor();Choreographer.getInstance().postFrameCallback(this);}});}
}

在每一幀被渲染時，記下了渲染的時間用來計算掉幀數，數據可以繪制出流暢度曲線；同時，獲取isMonitor（）函數判斷上一幀LogMonitor已經啟動打印堆棧的任務，如果已啟動，則移除LogMonitor，此時如果上一幀渲染的時間到現在已經超過了閾值，則已經執行了任務打印堆棧出來了；如果沒有超過閾值則及時移除了任務。如果isMonitor返回false，沒有LogMonitor回調任務，則開始新的一幀的監控任務。

優點：不僅可用來從app層面來監控卡頓，同時可以實時計算幀率和掉幀數，實時監測App頁面的幀率數據，一旦發現幀率過低，可自動保存現場堆棧信息。

缺點：需另開子線程獲取堆棧信息，會消耗少量系統資源。

3.3、總結下上述兩種方案的對比情況：

	Looper.loop	Choreographer.FrameCallback
監控是否卡頓	√	√
支持靜態頁面卡頓檢測	√	√
支持計算幀率	X	√
支持獲取App運行信息	√	√

實際項目使用中，我們一開始兩種監控方式都用上，上報的兩種方式收集到的卡頓信息我們分開處理，發現卡頓的監控效果基本相當。同一個卡頓發生時，兩種監控方式都能記錄下來。 由于Choreographer.FrameCallback的監控方式不僅用來監控卡頓，也方便用來計算實時幀率，因此我們現在只使用Choreographer.FrameCallback來監控app卡頓情況。

四、如何保證捕獲卡頓堆棧的準確性？

細心的同學可以發現，我們通過上述兩種方案（Looper.loop和Choreographer.FrameCallback）可以判斷是當前主線程是否發生了卡頓，進而在計算發現卡頓后的時刻dump下了主線程的堆棧信息。實際上，通過一個子線程，監控主線程的活動情況，計算發現超過閾值后dump下主線程的堆棧，那么生成的堆棧文件只是捕捉了一個時刻的現場快照。打個不太恰當的比方，相當于閉路電視監控只拍下了兇案發生后的慘狀，而并沒有錄下這個案件發生的過程，那么作為警察的你只看到了結局，依然很難判斷案情和兇手。在實際的運用中，我們也發現這種方式下獲取到的堆棧情況，查看相關的代碼和函數，經常已經不是發生卡頓的代碼了。

如圖所示，主線程在T1~T2時間段內發生卡頓，上述方案中獲取卡頓堆棧的時機已經是T2時刻。實際卡頓可能是這段時間內某個函數的耗時過大導致卡頓，而不一定是T2時刻的問題，如此捕獲的卡頓信息就無法如實反應卡頓的現場。

我們看看在這之前微信iOS主線程卡頓監控系統是如何實現的捕獲堆棧。微信iOS的方案是起檢測線程每1秒檢查一次，如果檢測到主線程卡頓，就將所有線程的函數調用堆棧dump到內存中。本質上，微信iOS方案的計時起點是固定的，檢查次數也是固定的。如果任務1執行花費了較長的時間導致卡頓，但由于監控線程是隔1秒掃一次的，可能到了任務N才發現并dump下來堆棧，并不能抓到關鍵任務1的堆棧。這樣的情況的確是存在的，只不過現上監控量大走人海戰術，通過概率分布抓到卡頓點，但依然不是最佳的捕獲方案。

因此，擺在我們面前的是如何更加精準地獲取卡頓堆棧。為了卡頓堆棧的準確度，我們想要能獲取一段時間內的堆棧，而不是一個點的堆棧，如下圖：

我們采用高頻采集的方案來獲取一段卡頓時間內的多個堆棧，而不再是只有一個點的堆棧。這樣的方案的優點是保證了監控的完備性，整個卡頓過程的堆棧都得以采樣、收集和落地。

具體做法是在子線程監控的過程中，每一輪log輸出或是每一幀開始啟動monitor時，我們便已經開啟了高頻采樣收集主線程堆棧的工作了。當下一輪log或者下一幀結束monitor時，我們判斷是否發生卡頓（計算耗時是否超過閾值），來決定是否將內存中的這段堆棧集合落地到文件存儲。也就是說，每一次卡頓的發生，我們記錄了整個卡頓過程的多個高頻采樣堆棧。由此精確地記錄下整個兇案發生的詳細過程，供上報后分析處理（后文會闡述如何從一次卡頓中多個堆棧信息中提取出關鍵堆棧）。

五、海量卡頓堆棧后該如何處理？

卡頓堆棧上報到平臺后，需要對上報的文件進行分析，提取和聚類過程，最終展示到卡頓平臺。前面我們提到，每一次卡頓發生時，會高頻采樣到多個堆棧信息描述著這一個卡頓。做個最小的估算，每天上報收集2000個用戶卡頓文件，每個卡頓文件dump下了用戶遇到的10個卡頓，每個卡頓高頻收集到30個堆棧，這就已經產生20001030=60W個堆棧。按照這個量級發展，一個月可產生上千萬的堆棧信息，每個堆棧還是幾十行的函數調用關系。這么大量的信息對存儲，分析，頁面展示等均帶來相當大的壓力。很快就能撐爆存儲層，平臺無法展示這么大量的數據，開發更是沒辦法處理這些多的堆棧問題。因而，海量卡頓堆棧成為我們另外一個面對的難題。

在一個卡頓過程中，一般卡頓發生在某個函數的調用上，在這多個堆棧列表中，我們把每個堆棧都做一次hash處理后進行排重分析，有很大的幾率會是dump到同一個堆棧hash，如下圖：