解析Android ANR問題
ANR 由消息處理機制保證，Android 在系統層實現了一套精密的機制來發現 ANR，核心原理是消息調度和超時處理。ANR 機制主體實現在系統層，所有與 ANR 相關的消息，都會經過系統進程system_server調度，具體是ActivityManagerService服務，然后派發到應用進程完成對消息的實際處理，同時，系統進程設計了不同的超時限制來跟蹤消息的處理。 一旦應用程序處理消息不當，超時限制就起作用了，它收集一些系統狀態，譬如 CPU/IO 使用情況、進程函數調用棧 CallStack，（有些平臺比如 MTK，還會打印相應的 Message 出來供調試分析），最后報告用戶有進程無響應了( ANR 對話框)。
1.1、ANR類型ANR 一般有三種類型：
1.1.1、KeyDispatchTimeout這個主要是按鍵或觸摸事件在特定時間內無響應，一般 Android 平臺默認超時時間是 5s 會報 anr，不過有些平臺會修改這個時間，比如 MTK 有些平臺就是 8s 的超時時間。
這個超時時間可以在 ActivityManagerService.java 查看：
// M: ANR debug mechanism (Ori: 5*1000)static final int KEY_DISPATCHING_TIMEOUT = 8*1000;1.1.2、BroadcastTimeout
這類超時會有 ANR 提示框彈出，用戶可以選擇forceStop或者繼續等待。
這個主要是 BroadcastRecevier 在規定時間無法處理完成。前臺廣播超時時間是 10s，后臺廣播超時是 60s，這類超時沒有提示框彈出。
==> AMS.java
// How long we allow a receiver to run before giving up on it.static final int BROADCAST_FG_TIMEOUT = 10*1000;static final int BROADCAST_BG_TIMEOUT = 60*1000;1.1.3、ServiceTimeout 
Service 在規定時間內無法處理完成操作，即會報出服務超時，這類 ANR 同樣沒有提示框出現。超時時間，前臺 Service 是 20s，后臺 Service 是 200s。
==> ActivityServices.java
// How long we wait for a service to finish executing.static final int SERVICE_TIMEOUT = 20*1000;// How long we wait for a service to finish executing.static final int SERVICE_BACKGROUND_TIMEOUT = SERVICE_TIMEOUT * 10;
三種 ANR 中只有第 1 種會顯示系統提示對話框，因為用戶正在做界面交互操作，如果長時間沒有任何響應，會讓用戶懷疑設備死機了，大多數人此時會開始亂按，甚至拔出電池重啟，給用戶的體驗肯定是非常糟糕的。
三種 ANR 發生時都會在 log 中輸出錯誤信息，你會發現各個應用進程和系統進程的函數堆棧信息都輸出到了一個 /data/anr/traces.txt 的文件中，這個文件是分析ANR原因的關鍵文件，同時在日志中還會看到當時的 CPU 使用率，這也是重要信息，在后面的章節會詳細介紹如何利用它們分析ANR問題。
這三種ANR不是孤立的，有可能會相互影響。例如一個應用程序進程中同時有一個正在顯示的 Activity 和一個正在處理消息的 BroadcastReceiver，它們都運行在這個進程的主線程中。如果 BR 的 onReceive 函數沒有返回，此時用戶點擊屏幕，而 onReceive 超過 5 秒仍然沒有返回，主線程無法處理用戶輸入事件，就會引起第 1 種 ANR。如果繼續超過 10 秒沒有返回，又會引起第 2 種ANR。
1.2、ANR發生的原理對于ANR 發生基本原理如下：
在進行相關操作調用 hander.sendMessageAtTime() 發送一個 ANR 的消息，延時時間為 ANR 發生的時間(如 activity 是當前時間 5s 之后)。 進行相關的操作 操作結束后向 remove 掉該條 message。如果相關的操作在規定時間沒有執行完成，該條 message 將被 handler 取出并執行，就發生了 ANR。二、ANR 分析示例ANR 本質上是一個 Performance 問題，發生 ANR 的時候，如果問題可能出在 APK 自己身上，那么主要排查的方向是 apk 本身，分析看看是不是在 UI 線程做了耗時的操作？
個人認為，有一些 ANR 問題是很難分析的，比如 app 運行的時候由于當前系統底層的一些影響，導致當前 message 處理失敗。這類問題往往沒有規律，又難以重現。對于這類 ANR 問題，一般需要花費大量時間去了解系統的一些其他行為，而超出了 ANR 本身的范疇，這類問題就相當于一個警示信號，告訴你系統哪個地方出問題了。
2.1、查看 log 日志文件搜索關鍵字 ANR :
04-17 17:15:23.817 E/ActivityManager( 187): ANR in com.da.android
(com.da.android/com.text.my.app.ui.activities.ContentActivity)
上面這段文字的含義是 4月17日，17點15分23秒817ms時候發生了 ANR .其實一般還會帶上 ANR 的原因，以及 CPU 使用信息，
這里我們寫了一個 demo，比如在廣播接收器的 onReceive 方法（廣播接收器的 onReceive 方法默認在主線程執行）里面睡眠一段時間，如果這個時候主線程沒有任何操作了，那么廣播接收器可以正常執行完畢。不會造成 ANR 。如果我在發送廣播之后然后點擊多次返回按鍵，這個時候因為主線程睡眠了，無法響應，就會出現 ANR。
其對應的完整 log 信息如下 ：
ANR in com.brotherd.broadcastdemo (com.brotherd.broadcastdemo/.MainActivity)
PID: 6317
Reason: Input dispatching timed out (Waiting to send key event because the focused window has not finished processing all of the input events that were previously delivered to it. Outbound queue length: 0. Wait queue length: 2.)
// Load: 38.14 / 37.82 / 37.45// ANR 發生前 cpu 使用信息
CPU usage from 45678ms to 0ms ago (2020-10-27 08:39:06.256 to 2020-10-27 08:39:51.933):
15% 1265/system_server: 12% user + 3.5% kernel / faults: 6531 minor 16 major
13% 23112/com.android.systemui: 9.7% user + 3.5% kernel / faults: 6033 minor 103 major // minor major 表示頁的錯誤
4.7% 578/surfaceflinger: 2.6% user + 2% kernel / faults: 469 minor 2 major
4.4% 673/hwpged: 0% user + 4.3% kernel / faults: 29 minor
2.3% 549/[email protected]: 1.1% user + 1.1% kernel / faults: 149 minor
0.1% 2246/com.huawei.android.pushagent: 0% user + 0% kernel / faults: 2583 minor 22 major
1.5% 461/logd: 0.8% user + 0.6% kernel / faults: 52 minor
1.5% 2077/com.huawei.powergenie: 0.7% user + 0.8% kernel / faults: 843 minor 2 major
0.5% 17384/com.android.settings: 0.4% user + 0.1% kernel / faults: 5419 minor 73 major
1.3% 259/mmc-cmdqd/0: 0% user + 1.3% kernel
1% 3888/kworker/u16:0: 0% user + 1% kernel / faults: 1 minor
0.9% 18949/android.process.media: 0.5% user + 0.3% kernel / faults: 1408 minor 8 major
0.8% 148/kswapd0: 0% user + 0.8% kernel
0.5% 657/dubaid: 0.3% user + 0.2% kernel / faults: 139 minor
0.5% 2105/com.huawei.android.launcher: 0.4% user + 0.1% kernel / faults: 159 minor 1 major
0.5% 2366/com.huawei.systemmanager:service: 0.3% user + 0.1% kernel / faults: 374 minor
0.5% 922/hisi_frw/0: 0% user + 0.5% kernel
0.4% 3951/kworker/u16:8: 0% user + 0.4% kernel
0.4% 27040/com.huawei.appmarket: 0.3% user + 0.1% kernel / faults: 350 minor 2 major
0.4% 238/kworker/0:1H: 0% user + 0.4% kernel
0.4% 2028/com.huawei.hiview: 0.1% user + 0.2% kernel / faults: 88 minor
0.3% 577/lmkd: 0% user + 0.3% kernel
0.3% 677/[email protected]: 0% user + 0.3% kernel / faults: 19 minor
0.3% 3715/kworker/u16:1: 0% user + 0.3% kernel
0.3% 29718/com.huawei.hidisk: 0.2% user + 0.1% kernel / faults: 404 minor 1 major
0.1% 527/zygote64: 0% user + 0.1% kernel / faults: 541 minor
0.3% 3954/kworker/u16:10: 0% user + 0.3% kernel
0.3% 581/powerlogd: 0.2% user + 0.1% kernel / faults: 25 minor
0.3% 3952/kworker/u16:9: 0% user + 0.3% kernel
0% 23351/com.huawei.hwid: 0% user + 0% kernel / faults: 854 minor 10 major
0.1% 3945/kworker/u16:6: 0% user + 0.1% kernel
0.2% 24447/kworker/u17:0: 0% user + 0.2% kernel
0.2% 548/[email protected]: 0% user + 0.2% kernel / faults: 47 minor
0.2% 2042/com.huawei.systemserver: 0.1% user + 0.1% kernel / faults: 95 minor
0.2% 426/oeminfo_nvm_server: 0% user + 0.1% kernel / faults: 79 minor 205 major
0.2% 4187/kworker/u17:1: 0% user + 0.2% kernel
0.2% 462/servicemanager: 0% user + 0.1% kernel / faults: 20 minor
0.2% 3633/kworker/u16:2: 0% user + 0.2% kernel
0.2% 5290/com.huawei.health:DaemonService: 0.1% user + 0% kernel / faults: 77 minor
0.1% 7/rcu_preempt: 0% user + 0.1% kernel
0.1% 93/sys_heap: 0% user + 0.1% kernel
0.1% 949/hisi_hcc: 0% user + 0.1% kernel
0.1% 637/hisecd: 0% user + 0.1% kernel / faults: 66 minor
0.1% 2097/com.android.phone: 0% user + 0.1% kernel / faults: 97 minor
0.1% 3441/kworker/u16:5: 0% user + 0.1% kernel
0.1% 526/netd: 0% user + 0.1% kernel / faults: 142 minor 2 major
0.1% 2063/com.huawei.HwOPServer: 0% user + 0% kernel / faults: 168 minor
0.1% 1//init: 0% user + 0% kernel / faults: 263 minor 5 major
0% 465/[email protected]: 0% user + 0% kernel / faults: 113 minor 5 major
0.1% 3944/kworker/u16:4: 0% user + 0.1% kernel
0.1% 655/displayengineserver: 0% user + 0% kernel / faults: 21 minor
0.1% 918/oal_gpio_rx_dat: 0% user + 0.1% kernel
0.1% 3955/com.eg.android.AlipayGphone:push: 0% user + 0% kernel / faults: 132 minor
0.1% 26941/com.huawe// anr 發生后 cpu 使用情況
2020-10-27 08:39:53.753 1265-1285/? E/ActivityManager: CPU usage from 51ms to 493ms later (2020-10-27 08:39:51.984 to 2020-10-27 08:39:52.426) with 99% awake:
48% 1265/system_server: 10% user + 37% kernel
45% 1285/ActivityManager: 8% user + 37% kernel
4.9% 578/surfaceflinger: 4.9% user + 0% kernel / faults: 5 minor
2.4% 578/surfaceflinger: 2.4% user + 0% kernel
3.1% 3952/kworker/u16:9: 0% user + 3.1% kernel
3.7% 23112/com.android.systemui: 3.7% user + 0% kernel
9.7% TOTAL: 5.2% user + 4.4% kernel // 可以從 total 里面看到整個 cpu 的情況
首先看前面幾行：
ANR in com.brotherd.broadcastdemo (com.brotherd.broadcastdemo/.MainActivity)
PID: 6317
Reason: Input dispatching timed out (Waiting to send key event because the focused window has not finished processing all of the input events that were previously delivered to it. Outbound queue length: 0. Wait queue length: 2.)
這幾行表明了 ANR 發生所處的 activity，進程 ID，以及 ANR 原因（input 事件分發超時）；
ANRManager會打印出anr 前后的 cpu 使用情況，這個可以反映出當時系統的Performance狀態：
如果 CPU 使用量接近 100%，說明當前設備很忙，有可能是CPU饑餓導致了ANR。 如果 CPU 使用量很少，說明主線程被BLOCK了 如果 IOwait 很高，說明ANR有可能是主線程在進行 I/O 操作造成的那么這個時候，我們就要看看 anr 發生的時候，主線程在做什么了。
2.2、Trace 文件（data/anr/traces.txt）log 文件只是告訴你 ANR 發生時間，但是并具體詳細的信息，這時候就得查看 trace 文件（App 的進程發生 ANR 時，系統讓活躍的 Top 進程都進行了一下 dump，進程中的各種Thread 就都 dump 到這個 trace 文件里了，所以 trace 文件中包含了每一條線程的運行時狀態）。
對于當前這個例子的堆棧信息如下：
在上面的信息中，有這樣一行
at com.brotherd.broadcastdemo.MyReceiver.onReceive(MyReceiver.java:23)
這就是造成 ANR 的根本原因。在 MyReceiver 類的 onReceive 方法中調用了 Thread 的 sleep 方法導致主線程阻塞，造成 ANR。
然后我們看一些字段的信息。
'main' prio=5 tid=1 Sleeping
| group='main' sCount=1 dsCount=0 flags=1 obj=0x7682ab30 self=0x7bd3815c00
| sysTid=6317 nice=-10 cgrp=default sched=0/0 handle=0x7c59fc8548
| state=S schedstat=( 1009468742 32888019 224 ) utm=91 stm=9 core=4 HZ=100
| stack=0x7ff27e1000-0x7ff27e3000 stackSize=8MB
| held mutexes=
這些字段含義如下線程名：
線程自身信息 線程優先級：prio=5 線程ID： tid=1 線程狀態：Sleeping 線程組名稱：group='main' 線程被掛起的次數：sCount=1 線程被調試器掛起的次數：dsCount=0 線程的java的對象地址：obj= 0x7682ab30 線程本身的Native對象地址：self=0x7bd3815c00線程調度信息： Linux系統中內核線程ID: sysTid=6317與主線程的進程號相同 線程調度優先級：nice=-10 線程調度組：cgrp=default 線程調度策略和優先級：sched=0/0 線程處理函數地址：handle= 0x7c59fc8548線程的上下文信息：
線程調度狀態：state=S 線程在CPU中的執行時間、線程等待時間、線程執行的時間片長度：schedstat=(1009468742 32888019 224) 線程在用戶態中的調度時間值：utm=91 線程在內核態中的調度時間值：stm=9 最后執行這個線程的CPU核序號：core=4線程的堆棧信息：
堆棧地址和大小：stack=0x7ff27e1000-0x7ff27e3000 stackSize=8MB 線程狀態此外，線程的狀態很重要，了解這些狀態的意義對分析ANR的原因是有幫助的，總結如下：
Thread.java 中的狀態和 Thread.cpp 中的狀態是有對應關系的。可以看到前者更加概括，也比較容易理解，面向 Java 的使用者；而后者更詳細，面向虛擬機內部的環境。traces.txt 中顯示的線程狀態都是 Thread.cpp 中定義的。另外，所有的線程都是遵循 POSIX 標準的本地線程。
線程狀態示例：
主線程是 running 或者 native： 而對應的棧對應了App中的函數，則很有可能就是執行該函數時候發生了超時。 主線程被 block：非常明顯的線程被鎖，這時候可以看是被哪個線程鎖了，可以考慮優化代碼。如果是死鎖問題，就更需要及時解決了。2.3、死鎖demo我們來看一個死鎖的例子：
'PowerManagerService' prio=5 tid=24 MONITOR
| group='main' sCount=1 dsCount=0 obj=0x41dd0eb0 self=0x5241b218
| sysTid=567 nice=0 sched=0/0 cgrp=apps handle=1380038664
| state=S schedstat=( 6682116007 11324451214 33313 ) utm=450 stm=219 core=1
at com.android.server.am.ActivityManagerService.broadcastIntent(ActivityManagerService.java:~13045)
- waiting to lock <0x41a874a0> (a com.android.server.am.ActivityManagerService) held by tid=12 (android.server.ServerThread)
at android.app.ContextImpl.sendBroadcast(ContextImpl.java:1144)
at com.android.server.power.PowerManagerService$DisplayBlankerImpl.unblankAllDisplays(PowerManagerService.java:3442)
at com.android.server.power.DisplayPowerState$PhotonicModulator$1.run(DisplayPowerState.java:456)
at android.os.Handler.handleCallback(Handler.java:800)
at android.os.Handler.dispatchMessage(Handler.java:100)
at android.os.Looper.loop(Looper.java:194)
at android.os.HandlerThread.run(HandlerThread.java:60)
tid=24 線程在等待一個 <0x41a874a0> 的鎖，而這個鎖被 tid=12 的線程占用了，我們來看看 tid=12：
'android.server.ServerThread' prio=5 tid=12 MONITOR| group='main' sCount=1 dsCount=0 obj=0x41a76178 self=0x507837a8
| sysTid=545 nice=-2 sched=0/0 cgrp=apps handle=1349936616
| state=S schedstat=( 15368096286 21707846934 69485 ) utm=1226 stm=310 core=0
at com.android.server.power.PowerManagerService.isScreenOnInternal(PowerManagerService.java:~2529)
- waiting to lock <0x41a7e2e8> (a java.lang.Object) held by tid=85 (Binder_B)
at com.android.server.power.PowerManagerService.isScreenOn(PowerManagerService.java:2522)
at com.android.server.wm.WindowManagerService.sendScreenStatusToClientsLocked(WindowManagerService.java:7749)
at com.android.server.wm.WindowManagerService.setEventDispatching(WindowManagerService.java:7628)
at com.android.server.am.ActivityManagerService.updateEventDispatchingLocked(ActivityManagerService.java:8083)
at com.android.server.am.ActivityManagerService.wakingUp(ActivityManagerService.java:8077)
tid=12 線程在等待 <0x41a7e2e8> 的鎖，而這個鎖被 tid=85 的線程占用了，我們來看看 tid=85：
'Binder_B' prio=5 tid=85 MONITOR | group='main' sCount=1 dsCount=0 obj=0x42744770 self=0x58329e88
| sysTid=3700 nice=-20 sched=0/0 cgrp=apps handle=1471424616
| state=S schedstat=( 1663727513 2044643318 6806 ) utm=132 stm=34 core=1
at com.android.server.power.PowerManagerService$DisplayBlankerImpl.toString(PowerManagerService.java:~3449)
- waiting to lock <0x41a7e420> (a com.android.server.power.PowerManagerService$DisplayBlankerImpl) held by tid=24 (PowerManagerService)
值得注意的是，trace里面一般會包含時間，盡量分析跟anr時間相近的trace，避免受到其他干擾。tid=85線程在等待<0x41a7e420>的鎖釋放，而這個鎖被tid=24占用了，所以就發送了死鎖。那么這種情況下我們就需要找到發生死鎖的source code，進行分析并修改。
三、其他分析思路有時候我們 log 也分析了，traces 也分析了，還是很難分析出 ANR 的原因，那么我們可能就需要嘗試從其他方面分析了：
從main log 里面找 anr 發生時間前 8s，看看 app 的 main thread 在做什么操作？是否有異常的地方，一般 process 的 pid 會等于主線程 id。
大范圍搜尋 log，看是否 anr 發生之前，哪里有發生 crash？是否有可能引起 anr。
看情況抓取平臺的一些輔助信息，包括但不局限于：
memory info process status cpu info Binder info ftrace四、減少發生 ANR 概率 將所有耗時操作，比如訪問網絡，Socket通信，查詢大量 SQL 語句，復雜邏輯計算等都放在子線程中去，然 后通過 handler.sendMessage、runonUIThread、AsyncTask 等方式更新 UI。無論如何都要確保用戶界面作的流暢 度。如果耗時操作需要讓用戶等待，那么可以在界面上顯示度條。 使用 AsyncTask 處理耗時 IO 操作。在一些同步的操作主線程有可能被鎖，需要等待其他線程釋放相應鎖才能繼續執行，這樣會有一定的 ANR 風險，對于這種情況有時也可以用異步線程來執行相應的邏輯。另外， 要避免死鎖的發生。 使用 Thread 或者 HandlerThread 時，調用 Process.setThreadPriority(Process.THREADPRIORITYBACKGROUND) 設置優先級，否則仍然會降低程序響應，因為默認 Thread 的優先級和主線程相同。 使用 Handler 處理工作線程結果，而不是使用 Thread.wait() 或者 Thread.sleep() 來阻塞主線程。 Activity 的 onCreate 和 onResume 回調中盡量避免耗時的代碼 View 的 onOnTouchevent 和 onclick 中也要避免耗時的代碼 BroadcastReceiver 中 onReceive 代碼也要盡量減少耗時，建議使用 IntentService 處理。 各個組件的生命周期函數都不應該有太耗時的操作，即使對于后臺 Service 或者 ContentProvider 來講，應用在后臺運行時候其 onCreate() 時候不會有用戶輸入引起事件無響應 ANR，但其執行時間過長也會引起 Service 的 ANR 和 ContentProvider 的ANR。以上就是解析Android ANR問題的詳細內容，更多關于Android ANR的資料請關注好吧啦網其它相關文章！
相關文章：
網公網安備