轉自：https://blog.csdn.net/fishmai/article/details/71077047

ANR簡介

• ANR，是“Application Not Responding”的縮寫，即“應用程序無響應”。在Android中，ActivityManagerService（簡稱AMS）和WindowManagerService（簡稱WMS）會監測應用程序的響應時間，如果應用程序主線程（即UI線程）在超時時間內對輸入事件沒有處理完畢，或者對特定操作沒有執行完畢，就會出現ANR。對於輸入事件沒有處理完畢產生的ANR，Android會顯示一個對話框，提示用戶當前應用程序沒有響應，用戶可以選擇繼續等待或者關閉這個應用程序（也就是殺掉這個應用程序的進程）。

為什麽會有ANR

ANR的產生需要同時滿足三個條件：

• 主線程：只有應用程序進程的主線程響應超時才會產生ANR；

• 超時時間：產生ANR的上下文不同，超時時間也會不同，但只要在這個時間上限內沒有響應就會ANR；

• 輸入事件/特定操作：輸入事件是指按鍵、觸屏等設備輸入事件，特定操作是指BroadcastReceiver和Service的生命周期中的各個函數，產生ANR的上下文不同，導致ANR的原因也會不同；

針對這三個條件，有以下三種情況會觸發ANR，詳細說明如下。

• 1、主線程對輸入事件在5秒內沒有處理完畢

Android的事件系統從2.3開始做了完全不同的實現，原先2.2中是在Java層實現的，但在2.3中整體轉移到了C++層，本書基於2.3以後的版本進行說明。我們先簡單了解一下產生這種ANR的整個流程。

當應用程序的Window處於Active狀態並且能夠接收輸入事件（例如按鍵事件、觸摸事件等）時，系統底層上報的事件就會被InputDispatcher分發給這個應用程序，應用程序的主線程通過InputChannel讀取輸入事件並交給界面視圖處理，界面視圖是一個樹狀結構，DecorView是視圖樹的根，事件從樹根開始一層一層向端點（例如一個Button）傳遞。我們通常會註冊一個監聽器來接收並處理事件，或者創建自定義的視圖控件來處理事件。

InputDispatcher運行在系統進程（進程名為system_server）的一個單獨的線程中，應用程序的主線程在處理事件的過程中，InputDispatcher會不斷的檢測處理過程是否超時，一旦超時，會通過一系列的回調通知WMS的notifyANR函數，最終會調用到AMS中mHandler對象裏的SHOW_NOT_RESPONDING_MSG這個case，此時界面上就顯示系統提示對話框了，同時使用logcat命令查看log（日誌信息）也可以看到關於ANR的信息。一下子出現了好幾個重要的名詞，要深入了解這種情況的ANR，需要熟悉Android的事件機制，本次不做解析，這裏只需要記住他們的功能：

• Window：具體指的是PhoneWindow對象，表示一個能夠顯示的窗口，它能夠接收系統分發的各種輸入事件；

• InputDispatcher：將系統上報的輸入事件分發給當前活動的窗口；

• InputChannel：InputDispatcher和應用程序分別運行在兩個不同的進程中，InputDispatcher就是通過InputChannel將事件對象傳遞給應用進程的。

註意：產生這種ANR的前提是要有輸入事件，如果用戶沒有觸發任何輸入事件，即便是主線程阻塞了，也不會產生ANR，因為InputDispatcher沒有分發事件給應用程序，當然也不會檢測處理超時和報告ANR了。

• 2、主線程在執行BroadcastReceiver的onReceive函數時10秒內沒有執行完畢
  BroadcastReceiver（簡稱BR）的onReceive函數運行在主線程中，當這個函數超過10秒鐘沒有返回就會觸發ANR。不過對這種情況的ANR系統不會顯示對話框提示，僅是輸出log而已。

• 3、主線程在執行Service的各個生命周期函數時20秒內沒有執行完畢
  Service的各個生命周期函數也運行在主線程中，當這些函數超過20秒鐘沒有返回就會觸發ANR。同樣對這種情況的ANR系統也不會顯示對話框提示，僅是輸出log。

三種ANR中只有第1種會顯示系統提示對話框，因為用戶正在做界面交互操作，如果長時間沒有任何響應，會讓用戶懷疑設備死機了，大多數人此時會開始亂按，甚至拔出電池重啟，給用戶的體驗肯定是非常糟糕的。

三種ANR發生時都會在log中輸出錯誤信息，你會發現各個應用進程和系統進程的函數堆棧信息都輸出到了一個/data/anr/traces.txt的文件中，這個文件是分析ANR原因的關鍵文件，同時在日誌中還會看到當時的CPU使用率，這也是重要信息，可以利用它們分析ANR問題。

這三種ANR不是孤立的，有可能會相互影響。例如一個應用程序進程中同時有一個正在顯示的Activity和一個正在處理消息的BroadcastReceiver，它們都運行在這個進程的主線程中。如果BR的onReceive函數沒有返回，此時用戶點擊屏幕，而onReceive超過5秒仍然沒有返回，主線程無法處理用戶輸入事件，就會引起第1種ANR。如果繼續超過10秒沒有返回，又會引起第2種ANR。

如何分析

關於發生 ANR 截取的 log 和 trace 這裏就不多說了

1、CPU 問題

• 在 Monkeylog.log 文件中定位到 "anr in" 位置，查看 cpu usage ,total 占用，如發現接近100%，暫時判斷為 cpu 問題。
• 然後在 logcat.log 文件中定位到 "not responding" 發生時間，並截取
  cpuinfo.log 中時間點前後 5s 的 log，然後計算 CPU 占中，看哪個進程用的多，在酌情分析模塊的 CPU 占中。

2、GC 問題

• 定位到 logcat.log 文件中 "not responding" 發生時間點；

• 去查看發生 ANR 時間點對應的 trace 文件，定位到應用報名，若Dalvik Thread主線程顯示“SUSPENDED”,則為內存問題；

• 截取 ANR 發生時間點前 5s 的 log，分析 "dalvikvm" 打印的 Paused GC 耗時，如果過多則定位為 GC 問題，需要查看這 5s 件發生了哪些耗時的操作。

註意：發生 GC 的進程 id 需要和當前發生 ANR 的線程 id 的要一致

如何避免

• 合理使用 UI 主線程，耗時操作放入其他線程工作；
• 合理使用 Handler 來處理其他線程請求；
• 合理使用並遵循 Android 生命周期, 避免在 onCreate() and onResume() 做過多的事情；
• 使用一些架構形成規範來避免內存等問題,例如：MVP、RxJava；
• 經常使用工具來檢查內存問題,例如:MAT、TraceView、AS 自帶等工具；
• 避免加載大圖片引起內存不足導致 ANR；
• 避免內存泄露引起的 ANR。

比如官方例子中：

 private class DownloadFilesTask extends AsyncTask<URL, Integer, Long> {
     // Do the long-running work in here
     // 耗時操作放這裏
     protected Long doInBackground(URL... urls) {
         int count = urls.length;
         long totalSize = 0;
         for (int i = 0; i < count; i++) {
             totalSize += Downloader.downloadFile(urls[i]);
             publishProgress((int) ((i / (float) count) * 100));
             // Escape early if cancel() is called
             if (isCancelled()) break;
         }
         return totalSize;
     }

     // This is called each time you call publishProgress()
     protected void onProgressUpdate(Integer... progress) {
         setProgressPercent(progress[0]);
     }

     // This is called when doInBackground() is finished
      // 耗時操作完成後 Post 到 UI 主線程
     protected void onPostExecute(Long result) {
         showNotification("Downloaded " + result + " bytes");
     }
 }

友好處理

一般情況下， 超過100至200毫秒用戶會感知程序有些緩慢。因此，可以做一些比較友好的 UI 提示頁面，比如：ProgressBar，來表明當前正在處理，使得用戶不會去一直點擊頁面，減少輸入即可能減少 ANR 出現幾率，因為按鍵5s不響應是會出現 ANR 的。

可以使用性能工具來優化我們的 App，如 Systrace 和 Traceview 。

關於內存泄露分析可以查看之前總結的 Android 內存泄漏工具使用分析

Basic investigate steps

1. Find "waiting to lock"

   • you can find monitor state "Binder Thread #15" prio=5 tid=75 MONITOR

   • you are lucky if find "waiting to lock"

   • example : waiting to lock <0xblahblah> (a com.foo.A) held by threadid=74

2. You can notice that "tid=74" hold a task now. So go to tid=74

3. tid=74 maybe SUSPENDED state! find main reason! trace does not always contain "waiting to lock". in this case it is hard to find main reason.

Part1:日誌獲取&註意事項
對於ANR問題，鑒於測試同事上報時抓取的日誌一般都是user版本獲取的，而對於user版本獲取的日誌除了ANR時間點，看不到其它有效信息（predump無）。

這種情況下如果提交給MTK分析的話，MTK往往會要求在userdebug或者eng版本復現問題，因為userdebug或者ENG版本可以抓到predump、message、callstack等信息。

所以一旦有ANR問題需要給MTK分析的話，首先先確認是否是eng或者userdebug版本獲取的，再一個check日誌信息是否完整。平時處理的ANR問題又不少都是跑Monkey跑出來的，其中有不少還是低概率的，所以一次就把日誌獲取完整很重要。

這裏順便說一下，如果條件允許，最好使用userdebug版本測試，因為ENG版本測試的話本身會加重CPU loading
獲取日誌還有一點需要註意，發生ANR後，不要選擇結束進程，因為這樣AMS會kill掉該進程，有些信息會打印不出來，最好是ANR發生後等兩三分鐘左右，再將mtklog提交上來（db.XX.ANR寫入到aee_exp文件夾下需要時間）

這裏順便說一下pre dump 機制
pre dump機制會分幾個時間點打印 callstack
比如anr的觸發時間是8秒無響應
則predump它會在4秒的時候預先dump一下callstack
6秒的時候再dump一下，anr發生後（8s後），本身會dump一次
則由這幾次callstack綜合分析，就會鎖定大概是什麽操作花了較長時間

所需日誌
分析ANR問題一般需要如下日誌信息：
1.aee_exp文件夾(MTK日誌目錄下，發生ANR會生成)
2.MTK目錄下的mobilelog文件夾

這裏的aee_exp文件夾一般都是需要的, 對DB進行dump解析，得到ANR發生時場景信息，比如主線程callstack，CPU，memory等，在分析問題根因時很關鍵。有些公司會有自己的抓取日誌工具，比如當發生ANR時獲取日誌存放在工具指定路徑，不過有些時候並不會抓取這個aee_exp文件，導致很多時候提交case給MTK分析時，MTK又索要這份文件，前後比較耽誤時間
Tip:有時候會出現ANR復現了，卻沒有db文件生成，因為DB文件往往比較大，產生不了db文件最大的可能就是手機存儲空間不足，所以復現時需要註意這一點

Part2:日誌分析一般步驟
Step1:
查看mobilelog文件夾下的events_log,搜索關鍵字"am_anr",這一步用於確認ANR時間點，可以搜索到類似如下信息
04-29 10:00:57.240 1267 1341 I am_anr : [0,6073,com.android.dialer,952745541,Input dispatching timed out (Waiting because no window has focus but there is a focused application that may eventually add a window when it finishes starting up.)]
這個例子中的ANR類型為Input dispatching timed out, 這種anr的原因的是在viewrootimpl分發事件時，並沒有找到focuswindow導致的。 時間點：10:00:57,進程號:6073
註意這裏的進程號比較重要，後面要去trace.txt或者db文件中去看這個process(6073)對應的backtrace

Step2:
查看mobilelog文件夾下的main_log,搜索關鍵字"Application is not responding",發生ANR的時間點如下：
04-29 10:00:57.113 1267 1488 I InputDispatcher: Application is not responding: AppWindowToken{953236e token=Token{1b1a770 ActivityRecord{c3285b3 u0 com.android.dialer/.DialtactsActivity t2002}}}. It has been 8005.2ms since event, 8003.3ms since wait started. Reason: Waiting because no window has focus but there is a focused application that may eventually add a window when it finishes starting up.
這裏可以看出卡在com.android.dialer這個應用的DialtactsActivity這支文件
這個anr的直接原因是com.android.dialer/.DialtactsActivity已經成為 focused application 但是其window暫時未成為focuswindow，因此輸入事件暫時不能分發，
inputdispatcher線程中的輸入事件在8s內未得到處理完成的回復則會出現此類anr。

接著搜索關鍵字"ANR in",時間上應該是接著上面這一段，下面可以看到如下類似信息(如下片段僅僅舉例，和上面的event日誌不是一套)

可以看到ANR發生在com.android.dialer進程
ANR的類型，比如這個例子中是Input dispatching timed out
發生ANR時的CPU使用情況，CPU是否吃緊，列出的進程中是否有非常消耗CPU資源的，重點看下75% TOTAL: 30% user + 42% kernel + 1.3% iowait + 0.1% softirq這行，這個例子中發生ANR的Dialer進程CPU消耗為零，也就是壓根沒有拿到CPU資源，而總的CPU資源使用雖然蠻高的，卻也沒有達到百分百，很可能是依賴的某個進程掛住了，原因下面會繼續分析
另外，很多時候需要註意iowait的占有率，如果占比比較高，則排查的方向要傾向與讀取文件操作有關的信息，可以看trace日誌中有沒有一些讀取文件或者操作SD卡的動作
還有註意觀察一下在出現“Application is not responding”信息往上看，註意主線程是不是有耗時的動作，可以搜索關鍵字"ActivityThread"且搜索到的片段含有ANR的進程名

如果發現ANR時CPU loading並不高，再去檢查memory的情況，以排查是否存在競爭memory的情況。aee_exp文件下的db文件解析後會有一個SYS_MEMORY_INFO文件，這個文件會列出問題發生時的MemTotal,MemFree,MemAvailable等信息

Step3:
trace.txt，這份trace務必要與moile日誌匹配，可以看這份trace日誌的最開頭，比如這個例子trace最開頭信息如下;
----- pid 6073 at 04-29 10:00:57 -----
Cmd line: com.android.dialer
這裏可以看到pid 6073，和events_log搜索關鍵字"am_anr"得到的片段中的進程信息匹配

查看主線程的CallStack, 註意這裏的sysTid號需要同events_log中含有“am_anr”片段中的6073一致，類似如下信息

Step2中可以看到發生ANR的線程CPU使用為零，沒有得到執行
再結合這一段的callstack，可以知道是由於com.android.dialer.dialpad.DialpadFragment的onStart方法沒有得到執行
再往上看
at android.media.ToneGenerator.native_setup(Native method)
at android.media.ToneGenerator.<init>(ToneGenerator.java:756)
初步猜測是dialer進行撥號的時候，去播放撥號音，ToneGenerator被卡住了。 而卡住的原因是什麽，這個時候再去看main.log看看能不能得到一些線索
在ANR時間點即關鍵字"ANR in"向上查看，發現有一段信息如下：
04-29 09:56:31.178 1267 2146 I ActivityManager: Process android.process.media (pid 1228) has died
至此ToneGenerator被卡住的原因清晰了，至於android.process.media這個進程為什麽died.則不在本文討論範圍內

Part3:常見ANR案例分析

案例一：等待binder調用返回
比較常見的情況是在Binder通信時，對端沒有回復導致，比如下面這個trace例子

這裏說明對端沒有回復，這就需要看當前這個線程6132在和誰通信，當前線程號在這段trace前面部分或者搜索"sysTid"
這個時候需要看SYS_BINDER_INFO這個文件了，aee_exp文件下的db文件(dbg結尾)通過MTK工具GAT解析後會有很多文件，其中就有SYS_BINDER_INFO這個文件
查找到有如下信息：
4897163: call from 6132:6132 to 1278:0 node 898 handle 6 size 96:0
4897164: reply from 1278:2035 to 6132:6132 node 0 handle -1 size 180:0

4897175: call from 6132:6132 to 1278:0 node 898 handle 6 size 96:0
4897176: reply from 1278:2034 to 6132:6132 node 0 handle -1 size 180:0

4897188: call from 6132:6132 to 1278:0 node 898 handle 6 size 96:0
4897189: reply from 1278:10225 to 6132:6132 node 0 handle -1 size 180:0

或者可以搜索關鍵字"outgoing transaction"，搜索到的片段中需含有"6132",這樣可以順著找到對端的進程號是1278
這個時候再去查看pid為1278即server端的trace dump信息，同時結合main.log，看看當時pid為1278的進程在做什麽
這種就需要具體問題具體分析了，之前遇到過一個問題是對端的process在ANR之前一直在做網絡通信，最終鑒定是網絡異常導致

案例二：主線程等待鎖
比如下面這個主線程的CallStack例子，可以看到如下信息：

這個例子中gallery的main thread在執行UploaderChimeraService的onDestroy方法時，需要lock 0x23f65d8b，但這個lock有被upload_periodic GCM Task 拿住，這個thread當前是在做連接網絡的動作。所以如果僅僅從這段信息來看，很有可能是測試時手機連接的網絡，無法連接gms的相關server有關

案例三：卡在IO上
這種情況一般是和文件操作相關，判斷是否是這種情況，可以看mainlog中搜索關鍵字"ANR in",查看當時的CPU具體使用情況，比如下面這種
ANRManager: 100% TOTAL: 2% user + 2.1% kernel + 95% iowait + 0.1% softirq
很明顯，IO占比很高，這個時候就需要查看trace日誌看當時的callstack，著重看有沒有file相關的動作，這個場景沒有示例

案例四：主線程作耗時的動作
比如網絡訪問，訪問數據庫之類的，都很容易造成主線程堵塞，所以這種問題的解決，一般需要另起thread做耗時的操作
這裏以訪問數據庫來說，這類型引起的ANR，一般來講看當時的CPU使用情況會發現user占比較高，看trace中主線程當時的信息會發現會有一些比如query像ContentProvider這種數據庫的動作。
這種情況下，還可以去看eventlog或者mainlog，在ANR發生前後打印出來的信息，比如訪問數據庫這種，在eventlog中搜索"am_anr",然後看前後片段，會發現發生ANR的這個進程有很多數據庫相關的信息，說明在發生ANR前後主線程一直在忙於訪問數據庫，這類型的問題常見於圖庫，聯系人，彩短信應用。

案例五：binder線程被占滿
系統對每個process最多分配15個binder線程，這個是谷歌的設計（/frameworks/native/libs/binder/ProcessState.cpp)
如果另一個process發送太多重復binder請求，那麽就會導致接收端binder線程被占滿，從而處理不了其它的binder請求
這本身就是系統的一個限制，如果應用未按照系統的要求來實現對應邏輯，那麽就會造成問題。
而系統端是不會（也不建議）通過修改系統行為來兼容應用邏輯，否則更容易造成其它根據系統需求正常編寫的應用反而出現不可預料的問題。
判斷Binder是否用完，可以在trace中搜索關鍵字"binder_f"，如果搜索到則表示已經用完，然後就要找log其他地方看是誰一直在消耗binder或者是有死鎖發生，對於binder用完的前期思路大致如此。

案例六：JE或者NE導致ANR
比如如下這個例子com.xrom.intl.appcenter發生ANR,不過看log裏有很多/system/bin/mediaserver的NE，且在ANR發生前也有一次。
一般NE dump trace等行為可能會導致ANR，所以建議把NE解掉後再看是否會發生ANR。
08-02 02:17:34.697 1133 1203 I am_anr : [0,28880,com.xrom.intl.appcenter,952680005,Input dispatching timed out (Waiting to send non-key event because the touched window has not finished processing certain input events that were delivered to it over 500.0ms ago. Wait queue length: 2. Wait queue head age: 8507.7ms.)]
08-02 02:17:34.697 1133 1203 I ANRManager: startAsyncDump: AnrDumpRecord{ Input dispatching timed out (Waiting to send non-key event because the touched window has not finished processing certain input events that were delivered to it over 500.0ms ago. Wait queue length: 2. Wait queue head age: 8507.7ms.) ProcessRecord{b678adb 28880:com.xrom.intl.appcenter/u0a32} IsCompleted:false IsCancelled:false }
而NE沒有抓取到coredump，無法分析。

main線程看起來是卡在hwui。
"main" prio=5 tid=1 Native
native: #02 pc 0001d0b9 /system/lib/libhwui.so (_ZN7android10uirenderer12renderthread11RenderProxy11postAndWaitEPNS1_22MethodInvokeRenderTaskE+108)
看起來是卡在renderthread
檢查renderThread是在做binder通信:
"RenderThread" prio=5 tid=16 Native
| group="main" sCount=1 dsCount=0 obj=0x32dd90a0 self=0xee82a000
| sysTid=29618 nice=-4 cgrp=default sched=0/0 handle=0xe6bff930
native: #02 pc 0001a86f /system/lib/libbinder.so (_ZN7android14IPCThreadState14talkWithDriverEb+174)
進入SYS_BINDER_INFO(aee_exp下的db文件解析出來會包含此文件)檢查它和誰在通信：
outgoing transaction 29169360: ffffffc02b41b680 from 28880:29618 to 363:15204 code 8 flags 10 pri -4 r1 node 34 size 80:8 data ffffff8004f800c8
那363又是誰：
system 363 1 27328 1204 0 20 0 0 0 fg binder_thr 7fad229b34 S 64 /system/bin/guiext-server
363又和誰在通信呢？
pending transaction 29168166: ffffffc0081f2100 from 363:363 to 28213:0 code 1 flags 10 pri -10 r1 node 15518486 size 13660:0 data ffffff8008b80408
28213：
----- pid 28213 at 2016-08-02 00:46:33 -----
Cmd line: /system/bin/mediaserver
所以是因為28213沒有響應導致環環相扣最終引起com.xrom.intl.appcenter發生ANR。
28213沒有響應正是因為/system/bin/mediaserver發生NE。

案例七：只存在於Monkey測試下
有些問題是只有在Monkey環境下才能跑出來，平時的user版本用戶使用是不會出現的，這種問題的話就沒有改動的意義。
比如下面這個例子：
ActivityManager: Not finishing activity because controller resumed
03-18 07:25:50.901 810 870 I am_anr : [0,25443,android.process.media,1086897733,Input dispatching timed out (Waiting because no window has focus but there is a focused application that may eventually add a window when it finishes starting up.)]
發生這個ANR的原因是Contoller將resume的操作給攔截了, 導致Focus不過去, 從而導致ANR，User版本不會有Contoller, 所以不會出現這個 ANR. 所以這個 ANR 可以忽略.

小結：
總的說來，拿到一份eng的完整日誌，一般步驟如下：
1.find ANR time,PID,ANR type
2.check CPU usage and Memory
3.check trace.txt,mapping process ID and time stamp
4.find more information about main thread through main log and event log

這裏的第四步需要根據問題來看，可以看看ANR時間點之前的日誌信息找出懷疑點，這個時候需要結合trace來看，可以進一步確認懷疑點。舉個例子，比如說如果ANR發生時間點之前有JE或者NE發生，則看下這些異常是否會阻礙某些事件的處理導致處理延時，如果不好判斷是否會有影響，則可以先嘗試去解決這些異常再去看ANR是否發生。

這裏需要註意的是在分析ANR發生點之前的信息，時間點不能過早，ANR發生點之前太早的話也沒有分析的意義，最好看發生ANR前0~4s的trace，這裏的分析有時候很關鍵，往往會成為定位問題的關鍵。

android anr分析