一、ANR介紹

ANR 由消息處理機制保證，Android 在系統(tǒng)層實現(xiàn)了一套精密的機制來發(fā)現(xiàn) ANR，核心原理是消息調(diào)度和超時處理。ANR 機制主體實現(xiàn)在系統(tǒng)層，所有與 ANR 相關(guān)的消息，都會經(jīng)過系統(tǒng)進程system_server調(diào)度，具體是ActivityManagerService服務(wù)，然后派發(fā)到應(yīng)用進程完成對消息的實際處理，同時，系統(tǒng)進程設(shè)計了不同的超時限制來跟蹤消息的處理。 一旦應(yīng)用程序處理消息不當，超時限制就起作用了，它收集一些系統(tǒng)狀態(tài)，譬如 CPU/IO 使用情況、進程函數(shù)調(diào)用棧 CallStack，（有些平臺比如 MTK，還會打印相應(yīng)的 Message 出來供調(diào)試分析），最后報告用戶有進程無響應(yīng)了( ANR 對話框)。

1.1、ANR類型

ANR 一般有三種類型：

1.1.1、KeyDispatchTimeout

這個主要是按鍵或觸摸事件在特定時間內(nèi)無響應(yīng)，一般 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或者繼續(xù)等待。

這個主要是 BroadcastRecevier 在規(guī)定時間無法處理完成。前臺廣播超時時間是 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&nbsp

Service 在規(guī)定時間內(nèi)無法處理完成操作，即會報出服務(wù)超時，這類 ANR 同樣沒有提示框出現(xiàn)。超時時間，前臺 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 種會顯示系統(tǒng)提示對話框，因為用戶正在做界面交互操作，如果長時間沒有任何響應(yīng)，會讓用戶懷疑設(shè)備死機了，大多數(shù)人此時會開始亂按，甚至拔出電池重啟，給用戶的體驗肯定是非常糟糕的。

三種 ANR 發(fā)生時都會在 log 中輸出錯誤信息，你會發(fā)現(xiàn)各個應(yīng)用進程和系統(tǒng)進程的函數(shù)堆棧信息都輸出到了一個 /data/anr/traces.txt 的文件中，這個文件是分析ANR原因的關(guān)鍵文件，同時在日志中還會看到當時的 CPU 使用率，這也是重要信息，在后面的章節(jié)會詳細介紹如何利用它們分析ANR問題。

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

1.2、ANR發(fā)生的原理

對于ANR 發(fā)生基本原理如下：

• 在進行相關(guān)操作調(diào)用 hander.sendMessageAtTime() 發(fā)送一個 ANR 的消息，延時時間為 ANR 發(fā)生的時間(如 activity 是當前時間 5s 之后)。
• 進行相關(guān)的操作
• 操作結(jié)束后向 remove 掉該條 message。如果相關(guān)的操作在規(guī)定時間沒有執(zhí)行完成，該條 message 將被 handler 取出并執(zhí)行，就發(fā)生了 ANR。

二、ANR 分析示例

ANR 本質(zhì)上是一個 Performance 問題，發(fā)生 ANR 的時候，如果問題可能出在 APK 自己身上，那么主要排查的方向是 apk 本身，分析看看是不是在 UI 線程做了耗時的操作？

個人認為，有一些 ANR 問題是很難分析的，比如 app 運行的時候由于當前系統(tǒng)底層的一些影響，導致當前 message 處理失敗。這類問題往往沒有規(guī)律，又難以重現(xiàn)。對于這類 ANR 問題，一般需要花費大量時間去了解系統(tǒng)的一些其他行為，而超出了 ANR 本身的范疇，這類問題就相當于一個警示信號，告訴你系統(tǒng)哪個地方出問題了。

2.1、查看 log 日志文件

搜索關(guān)鍵字 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時候發(fā)生了 ANR .其實一般還會帶上 ANR 的原因，以及 CPU 使用信息，

這里我們寫了一個 demo，比如在廣播接收器的 onReceive 方法（廣播接收器的 onReceive 方法默認在主線程執(zhí)行）里面睡眠一段時間，如果這個時候主線程沒有任何操作了，那么廣播接收器可以正常執(zhí)行完畢。不會造成 ANR 。如果我在發(fā)送廣播之后然后點擊多次返回按鍵，這個時候因為主線程睡眠了，無法響應(yīng)，就會出現(xiàn) ANR。

其對應(yīng)的完整 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 發(fā)生前 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/android.hardware.graphics.composer@2.2-service: 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/vendor.huawei.hardware.sensors@1.0-service: 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/android.hardware.graphics.allocator@2.0-service: 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/vendor.huawei.hardware.hwfactoryinterface@1.1-service: 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 發(fā)生后 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 發(fā)生所處的 activity，進程 ID，以及 ANR 原因（input 事件分發(fā)超時）；

ANRManager會打印出anr 前后的 cpu 使用情況，這個可以反映出當時系統(tǒng)的Performance狀態(tài)：

• 如果 CPU 使用量接近 100%，說明當前設(shè)備很忙，有可能是CPU饑餓導致了ANR。
• 如果 CPU 使用量很少，說明主線程被BLOCK了
• 如果 IOwait 很高，說明ANR有可能是主線程在進行 I/O 操作造成的

那么這個時候，我們就要看看 anr 發(fā)生的時候，主線程在做什么了。

2.2、Trace 文件（data/anr/traces.txt）

log 文件只是告訴你 ANR 發(fā)生時間，但是并具體詳細的信息，這時候就得查看 trace 文件（App 的進程發(fā)生 ANR 時，系統(tǒng)讓活躍的 Top 進程都進行了一下 dump，進程中的各種Thread 就都 dump 到這個 trace 文件里了，所以 trace 文件中包含了每一條線程的運行時狀態(tài)）。

對于當前這個例子的堆棧信息如下：

在上面的信息中，有這樣一行

at com.brotherd.broadcastdemo.MyReceiver.onReceive(MyReceiver.java:23)

這就是造成 ANR 的根本原因。在 MyReceiver 類的 onReceive 方法中調(diào)用了 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=

這些字段含義如下線程名：

• 線程自身信息
• 線程優(yōu)先級：prio=5
• 線程ID： tid=1
• 線程狀態(tài)：Sleeping
• 線程組名稱：group="main"
• 線程被掛起的次數(shù)：sCount=1
• 線程被調(diào)試器掛起的次數(shù)：dsCount=0
• 線程的java的對象地址：obj= 0x7682ab30
• 線程本身的Native對象地址：self=0x7bd3815c00線程調(diào)度信息：
• Linux系統(tǒng)中內(nèi)核線程ID: sysTid=6317與主線程的進程號相同
• 線程調(diào)度優(yōu)先級：nice=-10
• 線程調(diào)度組：cgrp=default
• 線程調(diào)度策略和優(yōu)先級：sched=0/0
• 線程處理函數(shù)地址：handle= 0x7c59fc8548

線程的上下文信息：

• 線程調(diào)度狀態(tài)：state=S
• 線程在CPU中的執(zhí)行時間、線程等待時間、線程執(zhí)行的時間片長度：schedstat=(1009468742 32888019 224)
• 線程在用戶態(tài)中的調(diào)度時間值：utm=91
• 線程在內(nèi)核態(tài)中的調(diào)度時間值：stm=9
• 最后執(zhí)行這個線程的CPU核序號：core=4

線程的堆棧信息：

• 堆棧地址和大?。簊tack=0x7ff27e1000-0x7ff27e3000 stackSize=8MB 線程狀態(tài)

此外，線程的狀態(tài)很重要，了解這些狀態(tài)的意義對分析ANR的原因是有幫助的，總結(jié)如下：

Thread.java 中的狀態(tài)和 Thread.cpp 中的狀態(tài)是有對應(yīng)關(guān)系的?？梢钥吹角罢吒痈爬?，也比較容易理解，面向 Java 的使用者；而后者更詳細，面向虛擬機內(nèi)部的環(huán)境。traces.txt 中顯示的線程狀態(tài)都是 Thread.cpp 中定義的。另外，所有的線程都是遵循 POSIX 標準的本地線程。

線程狀態(tài)示例：

• 主線程是 running 或者 native： 而對應(yīng)的棧對應(yīng)了App中的函數(shù)，則很有可能就是執(zhí)行該函數(shù)時候發(fā)生了超時。
• 主線程被 block：非常明顯的線程被鎖，這時候可以看是被哪個線程鎖了，可以考慮優(yōu)化代碼。如果是死鎖問題，就更需要及時解決了。

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占用了，所以就發(fā)送了死鎖。那么這種情況下我們就需要找到發(fā)生死鎖的source code，進行分析并修改。

三、其他分析思路

有時候我們 log 也分析了，traces 也分析了，還是很難分析出 ANR 的原因，那么我們可能就需要嘗試從其他方面分析了：

從main log 里面找 anr 發(fā)生時間前 8s，看看 app 的 main thread 在做什么操作？是否有異常的地方，一般 process 的 pid 會等于主線程 id。

大范圍搜尋 log，看是否 anr 發(fā)生之前，哪里有發(fā)生 crash？是否有可能引起 anr。

看情況抓取平臺的一些輔助信息，包括但不局限于：

• memory info
• process status
• cpu info
• Binder info
• ftrace

四、減少發(fā)生 ANR 概率

• 將所有耗時操作，比如訪問網(wǎng)絡(luò)，Socket通信，查詢大量 SQL 語句，復雜邏輯計算等都放在子線程中去，然 后通過 handler.sendMessage、runonUIThread、AsyncTask 等方式更新 UI。無論如何都要確保用戶界面作的流暢 度。如果耗時操作需要讓用戶等待，那么可以在界面上顯示度條。
• 使用 AsyncTask 處理耗時 IO 操作。在一些同步的操作主線程有可能被鎖，需要等待其他線程釋放相應(yīng)鎖才能繼續(xù)執(zhí)行，這樣會有一定的 ANR 風險，對于這種情況有時也可以用異步線程來執(zhí)行相應(yīng)的邏輯。另外， 要避免死鎖的發(fā)生。
• 使用 Thread 或者 HandlerThread 時，調(diào)用 Process.setThreadPriority(Process.THREADPRIORITYBACKGROUND) 設(shè)置優(yōu)先級，否則仍然會降低程序響應(yīng)，因為默認 Thread 的優(yōu)先級和主線程相同。
• 使用 Handler 處理工作線程結(jié)果，而不是使用 Thread.wait() 或者 Thread.sleep() 來阻塞主線程。
• Activity 的 onCreate 和 onResume 回調(diào)中盡量避免耗時的代碼
• View 的 onOnTouchevent 和 onclick 中也要避免耗時的代碼
• BroadcastReceiver 中 onReceive 代碼也要盡量減少耗時，建議使用 IntentService 處理。
• 各個組件的生命周期函數(shù)都不應(yīng)該有太耗時的操作，即使對于后臺 Service 或者 ContentProvider 來講，應(yīng)用在后臺運行時候其 onCreate() 時候不會有用戶輸入引起事件無響應(yīng) ANR，但其執(zhí)行時間過長也會引起 Service 的 ANR 和 ContentProvider 的ANR。

以上就是解析Android ANR問題的詳細內(nèi)容，更多關(guān)于Android ANR的資料請關(guān)注腳本之家其它相關(guān)文章！

最新評論