本文要點
- 為何需要自動化檢測方案
- 自動卡頓檢測方案原理
- 看一下Looper.loop()源碼
- 實作思路
- AndroidPerformanceMonitor實戰
- 基于AndroidPerformanceMonitor源碼簡析
- 接下來我們讨論一下方案的不足
- 自動檢測方案優化
項目GitHub
為何需要自動化檢測方案
- 前面提到過的系統工具隻适合線下針對性分析，無法帶到線上！
- 線上及測試環節需要自動化檢測方案
方案原理
-
源于Android的消息處理機制；
一個線程不管有多少Handler，隻會有一個Looper存在，
主線程中所有的代碼，都會通過Looper.loop()執行；
- loop()中有一個
mLogging
對象，
它在每個
Message
-
如果主線程發生卡頓，
一定是在
dispatchMessage
Handler機制圖
由此，我們便可以通過mLogging
對象
對
執行的時間進行監控；dispatchMessage
看一下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();
// Allow overriding a threshold with a system prop. e.g.
// adb shell 'setprop log.looper.1000.main.slow 1 && stop && start'
final int thresholdOverride =
SystemProperties.getInt("log.looper."
+ Process.myUid() + "."
+ Thread.currentThread().getName()
+ ".slow", 0);
boolean slowDeliveryDetected = false;
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 traceTag = me.mTraceTag;
long slowDispatchThresholdMs = me.mSlowDispatchThresholdMs;
long slowDeliveryThresholdMs = me.mSlowDeliveryThresholdMs;
if (thresholdOverride > 0) {
slowDispatchThresholdMs = thresholdOverride;
slowDeliveryThresholdMs = thresholdOverride;
}
final boolean logSlowDelivery = (slowDeliveryThresholdMs > 0) && (msg.when > 0);
final boolean logSlowDispatch = (slowDispatchThresholdMs > 0);
final boolean needStartTime = logSlowDelivery || logSlowDispatch;
final boolean needEndTime = logSlowDispatch;
if (traceTag != 0 && Trace.isTagEnabled(traceTag)) {
Trace.traceBegin(traceTag, msg.target.getTraceName(msg));
}
final long dispatchStart = needStartTime ? SystemClock.uptimeMillis() : 0;
final long dispatchEnd;
try {
msg.target.dispatchMessage(msg);
dispatchEnd = needEndTime ? SystemClock.uptimeMillis() : 0;
} finally {
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)) {
// Once we write a slow delivery log, suppress until the queue drains.
slowDeliveryDetected = true;
}
}
}
if (logSlowDispatch) {
showSlowLog(slowDispatchThresholdMs, dispatchStart, dispatchEnd, "dispatch", 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();
}
} 複制
-
裡邊有一個for循環，
會不斷地讀取消息隊列隊頭進行處理：
- 處理之前，會調用
logging.println()
執行之後再次調用
我們可以從列印日志的字首來判斷Message處理的
開始
和
結束
；
實作思路
- 通過
Looper.getMainLooper().setMessageLogging();
，
來設定我們自己的Logging；
這樣每次Message處理的前後，
調用的就是我們自己的Logging；
- 如果比對到
>>>>> Dispatching
，
我們就可以執行一個代碼，
即在指定的門檻值時間之後，
在子線程中開始執行一個【擷取目前子線程的堆棧資訊以及目前的一些場景資訊（如記憶體大小、變量、網絡狀态等）】的任務；
如果比對到
<<<<< Finished
，
則說明在指定的門檻值時間内，Message被執行完成，沒有發生卡頓，
那便将這個任務取消掉；
AndroidPerformanceMonitor實戰
- AndroidPerformanceMonitor原理：便是上述的實作思路和原理；
- 特性1：非侵入式的
性能監控元件
，
可以用
通知的方式
logcat
列印出關于卡頓的詳細資訊；
可以檢測所有線程中執行的任何方法，又不需要手動埋點，
設定好門檻值等配置，就“坐享其成”，等卡頓問題“願者上鈎”！！
- 特性2：友善精确，可以把問題定位到代碼的具體某一行！！！
【方案的
不足
以及
架構源碼解析
在下面實戰之後總結！！】
實戰開始---------------------------------------------------
- 庫的依賴：
implementation 'com.github.markzhai:blockcanary-android:1.5.0'
- 庫的首頁：https://github.com/markzhai/AndroidPerformanceMonitor
-
在項目中引入依賴後，
在Application進行初始化，
BlockCanary.install(this, new AppBlockCanaryContext()).start();
上下文
，
第二個參數是需要傳入一個
Block的配置類執行個體
public class TestApp extends Application {
@Override
public void onCreate() {
super.onCreate();
...
//AndroidPerformanceMonitor測試
BlockCanary.install(this, new AppBlockCanaryContext()).start();
}
} 複制
-
AppBlockCanaryContext
是我們自定義的類，
配置了
BlockCanary
的各種資訊，
代碼較多，可以看下GitHub，這裡就不貼全部代碼了~
下面兩個配置方法分别是
給出一個
uid
目前的使用者資訊
；
第二個是自定義
卡頓的門檻值時間
，過了門檻值便認為是卡頓，
這裡指定的是
500ms
/**
* Implement in your project.
*
* @return user id
*/
public String provideUid() {
return "uid";
}
/**
* Config block threshold (in millis), dispatch over this duration is regarded as a BLOCK. You may set it
* from performance of device.
*
* @return threshold in mills
*/
public int provideBlockThreshold() {
return 500;
} 複制
- 接着在
MainActivity
onCreate()
中，
讓主線程沉睡兩秒（2000ms > 設定的門檻值500ms）；
-
運作時，因為主線程停滞時間超過既定門檻值，
元件會認為其卡頓并且彈出通知！！
當然Android8.0以後比較麻煩，
因為notificationManager需要配置Channel等才能用，
或者允許
背景彈出界面
桌面上便會出現這個圖示：
進去之後就可以看到了相應的資訊了：
當然，我們可以在logcat中定位關鍵詞
blockInfo
，
看到同樣的詳細的資訊：
如上，
Block架構列印出來了【目前子線程的
堆棧資訊
以及目前的一些
場景資訊
（如記憶體大小、變量、網絡狀态等)】,
從
time-start
到
time-end
的
時間間隔
又可以知道
阻塞的時間
，如上圖展示出來的，正是我們設定的
2秒
！！！！
也可以看到
uid鍵
的值 便是我們剛剛設定的
字元串“uid”
；
同時還直接幫我們定位到
卡頓問題的出處
！！！
可見得BlockCanary已然
成功檢測到
問題的各種具體資訊了！！！卡頓
基于AndroidPerformanceMonitor源碼簡析
由于篇幅原因，筆者把以下解析内容提取出來單獨作一篇部落格哈~
目錄
1. 監控周期的 定義
2. dump子產品 / 關于.log檔案
3. 采集堆棧周期的 設定
4. 架構的 配置存儲類 以及 檔案系統操作封裝
5. 檔案寫入過程（生成.log檔案的源碼）
6. 上傳檔案
7. 設計模式、技巧
8. 架構中各個主要類的功能劃分
接下來我們讨論一下方案的不足
- 不足1：确實檢測到卡頓，但擷取到的卡頓堆棧資訊可能不準确；
-
不足2：和OOM一樣，最後的列印堆棧隻是表象，不是真正的問題；
我們還需要監控過程中的一次次log資訊來确定原因；
【假設初始方案，整個
監控周期
隻采集一次】
如上圖，
假設主線程
在
時間點T1（開始阻塞）
與
T2（阻塞結束）
之間的時間段中發生了卡頓，
而
卡頓檢測方案
是在
T2時刻
，
也就是 阻塞時間完全結束 （前提是
T2-T1大于門檻值
，确定了是卡頓問題）的時刻，
方案
才開始
擷取
卡頓堆棧的資訊
，
而
實際發生卡頓
（如發生
違例耗時處理過程
）的
時間點
，
可能是在這個時間段内，而非擷取資訊的T2點，
那有可能，
耗時操作
在
時間段内
，即在T2點之前就已經
執行完成
了，
T2點擷取到的可能不是卡頓發生的準确時刻，
也就是說
T2時刻
擷取到的資訊，不能夠完全
反映卡頓的現場
；
最後的T2點的堆棧資訊隻是表象，不能反映真正的問題；
我們需要縮小采集堆棧資訊的周期，進行
高頻采集
，詳細如下；
自動檢測方案優化
- 優化思路：擷取監控周期内的多個堆棧，而不僅是一個；
- 主要步驟：
startMonitor
開始監控（Message分發、處理前），
接着
高頻采集堆棧
！！！
阻塞結束，Message分發、處理後，前後時間差——阻塞時間超過門檻值，即發生卡頓，便調用
endMonitor
記錄 高頻采集好的堆棧資訊 到檔案中
；【具體源碼解析見上面解析部分（另一篇部落格）】
在合适的時機
上報
-
如此一來，
便能更清楚地知道在整個卡頓周期（阻塞開始到結束；Message分發、處理前到後）之内，
究竟是哪些方法在執行，哪些方法執行比較耗時；
優化
卡頓現場
- 新問題：面對 高頻卡頓堆棧資訊的上報、處理，服務端有壓力；
- 突破點：一個卡頓下多個堆棧大機率有重複；
-
解決：對一個卡頓下的堆棧進行hash排重，
找出重複的堆棧；
- 效果：極大地減少展示量，同時更高效地找到卡頓堆棧；
參考：
- 慕課網
- Android應用ANR檢測工具BlockCanary試用小記
- Android卡頓檢查-BlockCanary淺析