得物App ANR監控平臺設計

得物技術發表於2021-09-25
APP

得物之前對於線上的ANR問題都是採用接入的Bugly平臺進行問題收集和平臺展示的，在體驗中發現，無論是提供的資訊對於解決問題的有效度、或者是對ANR日誌聚合，都不太符合得物實際場景的需要。因此得物在參考業界各大廠商分享的ANR監控及治理方案後，我們開始著手建設自己內部的ANR監控平臺，本文主要介紹 ANR監控 平臺部分的實現，端上相關資訊的採集實現不做闡述。

ANR 資訊的處理

在進行ANR日誌的資料處理之前，首先整理下得物目前對於ANR收集、上報的資訊內容，主要包括以下幾點資訊

  • ProcessErrorStateInfo
  • tomstone資訊
  • 主執行緒的堆疊取樣資訊
  • 主執行緒 Looper Message 歷史排程的Message資訊、當前處理的Message、未處理的Message佇列

  • App狀態資訊

    • 應用前後臺狀態
    • 應用執行時長
    • ...

以下針對上述幾個關鍵資訊的處理，進行說明。

ProcessErrorStateInfo解析

ProcessErrorStateInfo 是通過ActivityManager的getProcessesInErrorState()函式獲取的，主要包含以下資訊

  • processName
  • pid
  • uid
  • tag (如果ANR發生在 Activity、Service等系統元件上，則tag會被設定為對應的元件名)
  • shortMsg (ANR 資訊的簡短描述)
  • longMsg (ANR 的詳細資訊)

這裡主要關注的時longMsg的資訊, 通過正則匹配的方式，從 longMsg中可以解析出以下關鍵資訊

  • ANR 發生的元件
  • ANR 觸發的原因

tomstone 資訊解析

關於 Android tombstone檔案包含的資訊可以參考 debuggerd中 tombstone的相關程式碼 ，得物目前線上上採用的是iQiyi開源的xcrash進行ANR tomsbtone資訊的採集。 採集的tombstone檔案中主要包含以下資訊

  • Crash相關元資訊

    • Crash型別 (anr、java 、native)
    • 應用啟動的時間
    • Crash 的時間
    • 應用版本號
    • 系統版本
    • ABI
    • pid、tid、crash 執行緒名
  • 虛擬機器GC相關資訊

  • ANR時各執行緒的現場資訊

    • 執行緒當前呼叫棧
    • 執行緒優先順序 prio
    • 執行緒狀態
    • 持有、或者等待的鎖資訊
    • 執行緒 nice值、utm、stm等資訊
  • logcat資訊
  • open files
  • memory info
  • ....

對xcrash的 tombstone資訊的解析，也直接採用的是 xcrash中內建的程式碼實現。

Looper Message回溯資訊的解析

在LooperMessage回溯 是指對系統主執行緒Looper 對訊息記錄的歷史(也包括未處理的訊息記錄)，從Message的處理狀態上分類，包含三類Message，1. 已處理的Message 2.當前正在處理的Message 3.未處理的Message；

對於已處理的Message，採集了Message執行的耗時時間(wallTime),以及cpu分配執行的時間(cpuTime)，根據這兩個時間的可以大致判斷，主執行緒cpu的排程情況，如果兩者之間的差值較大 (cpuTime 只佔 wallTime的30%以下) ，考慮可能存在比較嚴重的執行緒排程搶佔問題。

對於未處理的Message，主要是可以用來觀測當前Message的排程延遲情況、是否存在訊息積壓過多等case。

堆疊取樣資訊(method trace)解析

得物會在App執行時，每隔一定的時間間隔(50ms)採集主執行緒當前的執行堆疊，總計會儲存10S~20S 的執行緒呼叫棧，當發生ANR時，採集的堆疊資訊會隨ANR資訊一起上報。

通過在後臺對採集的堆疊進行處理，可以預先分析出其中較為耗時的函式，在這裡簡單描述下對函式取樣資料的分析處理方式

  1. 首先將採集的堆疊遍歷解析，並按照函式的呼叫關係轉成NodeTree的形式，遍歷過程中，記錄每個函式的耗時
  2. 從根節點開始，層級遍歷 MethodNodeTree，找出所有耗時大於一定閾值的函式
  3. 過濾掉一些白名單函式，比如 com.android.internal.os.ZygoteInit.main 、android.app.ActivityThread.main

部分程式碼

public class MethodNode {
     private List<MethodNode> children = new ArrayList<>();

    //method cost time
    private int cost;
    
    private String fullMethodName;

    private JavaStackFrameSnapshot javaStackFrameSnapshot;
    
}

ANR 日誌的聚合

在APM平臺中，對於issue 型別的事件，一個很重要的處理環節 就是對資料的聚合過程。 對於端上上報的 ANR 日誌同樣也需要進行聚合處理，這樣可以更好的對ANR問題進行分類，評估不同問題線上上發生ANR的嚴重程度，根據嚴重程度進行集中治理。

聚合策略

在生產環境中，裝置發生ANR的原因多種多樣，簡單歸類的話可以分為以下幾種情況

  • 主執行緒慢函式執行導致

    • 比如主執行緒執行繁重的程式碼，比如對大資料量的排序
    • 主執行緒上執行 IO操作
  • Looper 訊息排程異常
  • 鎖等待、死鎖
  • 系統負載較高、當前程式的CPU排程受到影響
  • 系統binder 服務異常
  • ....其他異常情況

針對可能因為慢函式導致的ANR問題，通過上節的 “堆疊資訊解析”環節已經解析出所有耗時大於一定閾值的應用內函式，在符合一定條件的情況下(主執行緒cpu排程正常) 可以按照 耗時函式進行聚合。

對於其他的case，我們先簡單的按照 發生ANR的元件+ANR觸發的原因 兩個關鍵資訊進行聚合，先按照這種比較粗的粒度進行聚合，再進行分析，如果發現一定的規律後，可以在平臺支援一些 特定規則的自定義聚合能力進行資料聚合。

平臺體驗

這個章節分享的是，得物針對ANR問題在平臺功能上的體驗設計，重點主要是說明如何展現現有的這些資料資訊，幫助開發者更好的發現及定位問題。

對於每一個上報的ANR日誌來說，除了一些通用的埋點資訊外（如userId、sessionId、deviceOs等），重點是對於ANR該問題相關的上下文資訊的展示。

問題列表

首先ANR日誌在經過聚合流程後，被分成一個個ANR ISSUE，每個ISSUE都有單獨的處理狀態及趨勢 ，以便進行問題治理及問題趨勢的跟進

在應用整體上，也提供了相應維度的趨勢圖可以觀測目前線上ANR的情況。

問題詳情

在問題列表頁，可以大概概念當前ANR 有多少個問題，每個問題的趨勢及處理狀態，當點選每個問題時，會跳轉到該“聚合問題”的詳情頁，在聚合演算法實現較為完備的情況下（在實際場景中，以ANR目前原因的多樣性，較難達到），每個問題詳情都是一個特定原因導致的ANR、或者是發生在某一個特定的應用元件上的ANR。

在問題詳情頁，同樣可以展示該特定問題的發生趨勢，以及對問題處理狀態等，但更為重要的是 這個問題，平臺提供了哪些關鍵元素資訊來幫助開發者定位ANR問題。

日誌詳情

在每個ANR ISSUE詳情頁中，每個ISSUE 都是一堆ANR上報的日誌集合，即ISSUE 跟 Log，是一個一對多的關係，在問題詳情頁，可以檢視該問題下面上報的所有異常日誌，點選每個異常日誌時，可以檢視該日誌的詳細資訊。在日誌詳情部分，ANR平臺將上個小節 解析的所以資訊，包括主執行緒 Message回溯資訊、method trace資訊，各程式CPU使用率等，以更友好的視覺化方式進行展示。

ANR日誌 基礎資訊的展示

  • ANR 觸發的元件
  • ANR觸發的原因
  • ANR 發生時的應用的前後臺狀態
  • 應用執行時長
  • ....

ANR後一段時間各程式CPU的使用率資訊

這裡主要是展示端上收集上來的 各程式的cpu使用率資訊，使用率上分為使用者態和核心態。

在這裡主要檢視兩個方面的資訊，當前程式的cpu使用率有無異常，以及在使用者態和 核心態的分佈情況。另外一個方面是檢視其它程式的cpu使用率，考慮是否可能出現由於其它程式cpu使用率過高，而影響當前程式的情況。

ANR 時各執行緒現場資訊展示

執行緒現場資訊，主要是檢視 主執行緒是否有可能發生死鎖、以及其它執行緒的執行情況，是否有可能出現其它工作現場過多，導致當前執行緒排程受影響的情況等。

Looper訊息回溯資訊的展示

Looper訊息的回溯是可以從主執行緒處理Message的視角看訊息的分發、處理情況。ANR發生的原因除了耗時函式外，也可能是由於主執行緒CPU的排程受到了瓶頸、或者是向Looper傳送了過多訊息導致等諸多原因。

logcat 資訊

從logcat資訊中，可以輔助驗證、獲取ANR發生前後的一些資訊，有時候從logcat中的異常日誌中也能定位出問題。

函式執行火焰圖（Flame Chart）的展示

火焰圖可以以全域性的視角來看應用函式執行的情況，更直觀的分析出可能導致出現anr的函式。

使用ANR監控平臺排查問題的思路

簡單來說，通過現有的平臺，可以從以下幾個方面來分析ANR問題

  1. 從ANR的前後臺狀態、應用執行時長、程式cpu使用率、Message Trace 中Message 的cpuTime、wallTime的差值 大概對當前應用的cpu排程能力有一個評估。
  2. 從火焰圖中 分析是否有明顯耗時的業務程式碼
  3. 從 MessageTrace中看是否有明顯異常的訊息處理（單個訊息處理過長、Message數過多 等情況）

  4. 從CPU使用率上

    • 看 應用程式user和kernel的使用佔比有無異常，如果kernel使用較高，則分析是否發生了大量的系統呼叫, 如果user層的使用率較高，則說明在業務側有較多繁重的任務執行。
    • 檢視 kswapd0 cpu使用率是否較高，如果cpu使用率比較高，則說明系統記憶體資源不足，此時系統正在進行頻繁的記憶體交換 (記憶體空間和磁碟空間的交換)，佔用系統的cpu及io資源,因此會影響整機效能。
    • 檢視 systemServer的cpu使用率,是否是由於系統服務的cpu使用率過高，導致當前程式無法分配到足夠的時間片

  5. 從logcat排查問題

    • 從logcat中觀察 gc相關的資訊，是否有可能是由於記憶體嚴重不足，執行blocking gc導致的ANR，這裡也可以結合線上的記憶體採集資訊，將ANR發生前後的記憶體使用資訊一同上報
    • 檢視 kernerl 相關的日誌，是否 有lomemorykiller iowait等系統相關資源不足的情況

部分問題治理分享

本節是分享在ANR平臺上線後，利用ANR平臺定位到的一些ANR問題。

呼叫Kotlin Function 物件的 toString 函式呼叫導致ANR

在排查ANR日誌時，發現有多個ANR 日誌中，Kotlin 的KfunctionImpl.toString都比較耗時，火焰圖case如下

於是線上下對Kotlin的該函式進行了測試，在demo中參照火焰圖中的業務程式碼進行了場景還原

結果發現，一個簡單的toString呼叫，在demo中耗時達到了 118ms。經過一系列的變數測試發現，在引入kotlin後，並且 引入了 kotlin-reflection庫的情況下， 呼叫 Kotlin Function物件的toString函式時 耗時非常嚴重。因此在業務程式碼中要注意，不要對kotlin的 函式物件 直接或者間接的觸發toString操作。

主執行緒執行View.getDrawingCache進行bitmap轉換

從佇列中，發現大量的訊息已被阻塞，並且在前序的Mesage處理記錄中，發現有耗時900ms的訊息處理。

轉到對應的 method trace中發現，卡頓主要是由於在主執行緒對Webview獲取drawingCache導致的。

線上下進行測試時，可能在正常情況下該函式的耗時並沒有這麼耗時，因此暫不能確定該問題是如何引起的，但是從程式碼實現的角度，也不應該在主執行緒執行類似的耗時操作，因此可以將該操作移入非同步執行緒執行。

SP 等待任務造成的 ANR 問題

在ANR平臺上線後，發現目前收集的用例中 有大量資料是由於 系 統元件在 onPause、onStop等相關流程需要等待所有非同步的 SP寫入操作完成造成的

得物目前的業務都已使用 MMKV 替換SP，主要使用SP的場景都是接入的一些三方SDK，而這些sdk一般不需要對這部分資料在元件跳轉間 對“非同步任務資料寫入完成”的強保證，因此得物對這部分系統的機制進行了HOOK，在這部分HOOK功能上線後，ANR率有了明顯下降。

後續優化迭代方向

從目前ANR平臺上線後 問題的治理情況上來看，大部分容易解決的問題都是從 火焰圖上分析出明顯耗時的業務程式碼從而解析的，在實際的線上場景中，目前還是發現有一些特定的case以現有上報的日誌資訊無法明確給出發生ANR的根本原因。後面會根據每種case，加強其他方面的監控能力，來協助定位問題。

端側

其他上下文資訊收集的增強

比如線上上發現，某些ANR問題 耗時函式卡在一個簡單的 File.exist函式呼叫上，針對此類問題，後續可能需要結合native層 對file io操作的一些監控、hook來協助定位問題。

端上 Method Trace 效能優化

目前得物APP在端上進行Method Trace的方案是 在子執行緒定時通過主執行緒的Thread物件 呼叫getStackTrace進行採集，雖然該函式的執行是在非同步執行緒，但是在虛擬機器底層在非當前執行緒獲取某個執行緒的堆疊時，會先suspend對應的執行緒，獲取完成後再resume。 因此如果對主執行緒抓起堆疊的頻率較為頻繁的話，勢必會影響主執行緒正常函式的執行。

我們的MethodTrace的要求是應該儘量保證其只產生極小的執行時開銷，避免為了監控反而影響應用效能，雖然目前的這套取樣方案，控制的最小取樣間隔為50s，對效能影響不大。在facebook 的profilo開源庫中有一套 非同步非阻塞獲取執行緒堆疊的方案，不過其目前只開源了適配了 Android 9及以下的版本。位元組跳動的西瓜視訊 分享了另外一種 Java Method Trace ，不過該方案最終也是需要suspend thread, 對效能也是有一定影響，不過在實現上也是一個可以參考的方向。

平臺測

MessageTrace 體驗優化

目前Looper Message Trace 功能和 Method Trace(函式執行火焰圖)功能是兩個比較獨立的功能，當我們在Message Trace 功能 中發現某個訊息比較耗時，正常情況下是希望能夠直接看到該訊息具體做了什麼操作，因此在平臺測可以做的一個優化是， 當點選Message時，根據這個Message的處理的開始結束時間，自動擷取對應時間的函式堆疊片段，進行資訊展示。

Anr 時間的區分

端上收集上來的 Message資訊及 函式取樣資訊，其實是包含了anr之後的，因為從anr觸發到應用程式捕獲再到收集資訊 存在一定的時間差，因此從問題分析的角度上，這個時間點需要做一個明顯的區分。

參考資料

  1. https://www.ssw.uni-linz.ac.a...
  2. https://mp.weixin.qq.com/s?__...
  3. https://mp.weixin.qq.com/s?__...
  4. https://mp.weixin.qq.com/s?__...
  5. https://androidperformance.co...

文/Knight-ZXW

關注得物技術，做最潮技術人！

相關文章