ANR是什么
ANR全稱為Application Not Responding
,意為應(yīng)用程序無響應(yīng)窗慎,當(dāng)應(yīng)用的主線程被長時(shí)間阻塞時(shí)會觸發(fā)這個(gè)問題,在日常開發(fā)或者使用手機(jī)時(shí)敌呈,或多或少都會遇到下面這個(gè)對話框牡借,點(diǎn)擊OK
,APP將會被強(qiáng)行退出:
此時(shí)如果查看log趴乡,一般可以發(fā)現(xiàn)導(dǎo)致此問題的蛛絲馬跡:
例如上圖,可以很清晰的看到發(fā)生了ANR的原因是用戶的輸入事件未得到及時(shí)處理蝗拿,并且詳細(xì)日志存儲到了/data/data/traces.txt
文件中晾捏。
產(chǎn)生原因
只有當(dāng)應(yīng)用的主線程響應(yīng)超時(shí)才會觸發(fā)ANR,根據(jù)不同的情況哀托,超時(shí)時(shí)間也有所區(qū)別:
-
KeyDisptachTimeout
惦辛,最常見的異常類型,原因是View的按鈕或者觸摸事件在5秒內(nèi)未響應(yīng)仓手,要產(chǎn)生這種超時(shí)胖齐,最少有兩個(gè)輸入事件玻淑,首先第一個(gè)輸入事件A系統(tǒng)將其分發(fā)給用戶正在操作的APP,然后如果此時(shí)再產(chǎn)生一個(gè)輸入事件B呀伙,發(fā)現(xiàn)A在0.5秒內(nèi)未處理完补履,系統(tǒng)會設(shè)置一個(gè)5秒的定時(shí)器,5秒之后如果A事件仍未處理完成剿另,則觸發(fā)ANR -
BroadcastTimeout
干像,由于BroadcastReceiver
的onReceiver
方法運(yùn)行在主線程中,如果該方法在10秒內(nèi)未處理完驰弄,則觸發(fā)ANR -
ServiceTimeout
,比較少見速客,原因是Service
的生命周期方法在20秒內(nèi)未處理完成
典型場景
- 應(yīng)用在主線程進(jìn)行耗時(shí)操作戚篙,例如大量緩慢的I/O操作、長時(shí)間復(fù)雜的計(jì)算溺职。
- 與另一個(gè)進(jìn)程在進(jìn)行binder通信岔擂,該進(jìn)程未及時(shí)返回
- 主線程處于阻塞狀態(tài),等待其他線程釋放某個(gè)鎖
- 主線程處于死鎖狀態(tài)
如何檢測
為了將問題盡量提前暴露在開發(fā)和測試階段浪耘,可以通過一些簡單的配置和工具來進(jìn)行檢測乱灵,提前發(fā)現(xiàn)問題,從而有效的避免線上ANR的產(chǎn)生七冲。
嚴(yán)格模式-StrictMode
StrictMode
是Android SDK提供的用來檢測代碼中是否有I/O或者內(nèi)存方面違規(guī)操作的工具類痛倚,詳細(xì)API可參考官方文檔,一般需要在Application或者Lancher Activity的onCreate方法中開啟澜躺,需要注意的是蝉稳,只能在開發(fā)版本中使用,release版本不能使用嚴(yán)格模式
if (BuildConfig.DEBUG){
// 開啟所有線程策略
StrictMode.setThreadPolicy(StrictMode.ThreadPolicy.Builder().detectAll().penaltyLog().build())
// 開啟所有虛擬機(jī)策略
StrictMode.setVmPolicy(StrictMode.VmPolicy.Builder().detectAll().penaltyLog().build())
}
其中線程策略主要監(jiān)控一些發(fā)生在主線程中的I/O和耗時(shí)操作:
- detectDiskReads:檢查是否有磁盤讀操作
- detectDiskWrites:檢查是否有磁盤寫操作
- detectNetwork:檢查是否有網(wǎng)絡(luò)操作
- detectAll:開啟所有支持的檢查項(xiàng)目
虛擬機(jī)策略主要監(jiān)控內(nèi)存問題:
- detectLeakedSqlLiteObjects:檢查是否存在Sqlite對象泄漏
- detectLeakedClosableObjects:檢查是否存在未關(guān)閉的Closable對象
- detectActivityLeaks:檢查是否存在Activity泄漏
- detectAll:開啟所有支持的檢查項(xiàng)目
當(dāng)開啟了嚴(yán)格模式之后掘鄙,如果在代碼中出現(xiàn)了被監(jiān)控的違規(guī)操作之后耘戚,系統(tǒng)就會按照上面配置的提醒方式發(fā)出警告,在上面的示例中配置的是penaltyLog
操漠,表示出現(xiàn)問題輸出日志到logcat收津,同時(shí)我們也可以根據(jù)需求自己配置其他的提醒方式,例如直接crash浊伙、彈窗撞秋、回調(diào)指定方法等。
當(dāng)配置的是penaltyLog
時(shí)嚣鄙,出現(xiàn)了被監(jiān)控的違規(guī)操作后部服,會出現(xiàn)如下日志:
可以看到日志中詳細(xì)的列出了在 AnrActivity的第28行,在主線程中有一個(gè)讀磁盤的操作拗慨,耗時(shí)29ms廓八。
啟用后臺 ANR 對話框
對于BroadcastTimeout
奉芦,只有在設(shè)備的開發(fā)者選項(xiàng)中啟用了顯示所有 ANR 時(shí),Android 才會針對花費(fèi)過長時(shí)間處理廣播消息的應(yīng)用顯示 ANR 對話框剧蹂。因此声功,在開發(fā)測試的過程中最好將這個(gè)設(shè)置打開,以便于充分的暴露問題宠叼。
獲取ANR詳細(xì)日志
系統(tǒng)會在遇到 ANR 時(shí)存儲跟蹤信息先巴。在較低的操作系統(tǒng)版本中,設(shè)備上只有一個(gè) /data/anr/traces.txt
文件冒冬。在較新的操作系統(tǒng)版本中伸蚯,有多個(gè) /data/anr/anr_*
文件,可以通過adb命令或者AS的Device File Explorer功能將這個(gè)文件導(dǎo)入到PC中進(jìn)行分析简烤。:
如何定位與分析
首先通過以下代碼制造一次ANR:
btn.setOnClickListener {
synchronized(lock) {
Log.d(TAG, "ANR caused by deadlock")
}
}
var work = object : Thread() {
override fun run() {
synchronized(lock) {
Log.d(TAG, "locked by ${currentThread()}")
sleep(60 * 1000)
}
}
}
work.start()
代碼邏輯很簡單剂邮,首先在工作線程對lock進(jìn)行加鎖,然后工作線程休眠60秒横侦,此時(shí)點(diǎn)擊按鈕嘗試獲取鎖挥萌,由于鎖已經(jīng)被工作線程占用了,所以此時(shí)主線程進(jìn)入阻塞等待狀態(tài)枉侧,當(dāng)?shù)却瑫r(shí)后引瀑,就會觸發(fā)ANR。
Logcat日志信息分析
首先看ANR觸發(fā)時(shí)的logcat日志信息
ActivityManager: ANR in com.comoko.myapplication (com.comoko.myapplication/.anr.AnrActivity)
PID: 6194
Reason: 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: 5645.9ms.)
Load: 0.08 / 0.06 / 0.07
CPU usage from 140282ms to 0ms ago (2021-02-16 22:10:25.805 to 2021-02-16 22:12:46.086):
6.9% 1870/system_server: 3.4% user + 3.4% kernel / faults: 47281 minor
4.2% 1723/surfaceflinger: 1.3% user + 2.8% kernel / faults: 158 minor
2.5% 1610/android.hardware.sensors@1.0-service: 0% user + 2.4% kernel
1.7% 1595/android.hardware.audio@2.0-service: 0.1% user + 1.6% kernel
1.7% 1910/android.hardware.graphics.composer@2.1-service: 0.2% user + 1.5% kernel / faults: 23 minor
1.5% 1614/audioserver: 0.8% user + 0.6% kernel / faults: 11 minor
1.4% 5334/adbd: 0% user + 1.3% kernel / faults: 119518 minor
1.4% 2027/com.android.systemui: 0.9% user + 0.4% kernel / faults: 259 minor
0.9% 2586/com.android.launcher3: 0.6% user + 0.2% kernel / faults: 3178 minor
0.8% 5625/transport: 0.5% user + 0.2% kernel
0.4% 2176/com.android.phone: 0.2% user + 0.2% kernel / faults: 214 minor 2 major
0.3% 1539/logd: 0.2% user + 0.1% kernel / faults: 10 minor
0.2% 4932/kworker/u8:2: 0% user + 0.2% kernel
0.1% 7/rcu_preempt: 0% user + 0.1% kernel
0.1% 5734/kworker/0:2: 0% user + 0.1% kernel
0.1% 1736/statsd: 0% user + 0% kernel
0.1% 5928/kworker/u8:1: 0% user + 0.1% kernel
+0% 6105/kworker/u8:0: 0% user + 0% kernel
+0% 6129/kworker/1:2: 0% user + 0% kernel
+0% 6191/logcat: 0% user + 0% kernel
+0% 6194/com.comoko.myapplication: 0% user + 0% kernel
4.2% TOTAL: 1.8% user + 2.2% kernel + 0% iowait + 0% softirq
CPU usage from 24ms to 300ms later (2021-02-16 22:12:46.111 to 2021-02-16 22:12:46.387):
24% 1870/system_server: 0% use
可以看到榨馁,logcat日志中的信息主要包含以下內(nèi)容:
- 發(fā)生ANR的進(jìn)程名及id:com.comoko.myapplication憨栽,PID: 6194
- 發(fā)生ANR的類名及包名:com.comoko.myapplication/.anr.AnrActivity
- 發(fā)生ANR的原因:Input dispatching timed out
- 系統(tǒng)CPU占用情況:.2% TOTAL: 1.8% user + 2.2% kernel + 0% iowait + 0% softirq
traces文件信息分析
通過logcat可以大概了解到ANR發(fā)生的原因、類翼虫,以及當(dāng)時(shí)的CPU占用情況徒像,但是不足以定位到具體的代碼位置,為了進(jìn)一步的分析問題發(fā)生原因蛙讥,我們需要分析上一小節(jié)中獲取到的ANR詳細(xì)日志锯蛀,這個(gè)日志一般會比較龐大,不過我們只需關(guān)心與我們相關(guān)的即可次慢,通過第一步對logcat日志的分析旁涤,我們知道了發(fā)生ANR的粗略信息,例如進(jìn)程名稱和id等迫像,通過在ANR的詳細(xì)日志中搜索相關(guān)信息劈愚,可以很快的找到與我們有關(guān)的信息,例如下面這個(gè)日志:
----- pid 6194 at 2021-02-16 22:12:46 -----
Cmd line: com.comoko.myapplication
Build fingerprint: 'Android/sdk_phone_x86_64/generic_x86_64:9/PSR1.180720.012/4923214:userdebug/test-keys'
ABI: 'x86_64'
Build type: optimized
Zygote loaded classes=10642 post zygote classes=358
Intern table: 74152 strong; 365 weak
JNI: CheckJNI is on; globals=600 (plus 22 weak)
...
Heap: 35% free, 5MB/8MB; 56540 objects
...
DALVIK THREADS (14):
"main" prio=5 tid=1 Blocked
| group="main" sCount=1 dsCount=0 flags=1 obj=0x750fda08 self=0x7a3186014c00
| sysTid=6194 nice=-10 cgrp=default sched=0/0 handle=0x7a320b7e2548
| state=S schedstat=( 1038269434 221502550 503 ) utm=78 stm=25 core=0 HZ=100
| stack=0x7ffec331d000-0x7ffec331f000 stackSize=8MB
| held mutexes=
at com.comoko.myapplication.anr.AnrActivity$onCreate$1.onClick(AnrActivity.kt:32)
- waiting to lock <0x0aab8a86> (a java.lang.Object) held by thread 13
at android.view.View.performClick(View.java:6597)
at android.view.View.performClickInternal(View.java:6574)
at android.view.View.access$3100(View.java:778)
at android.view.View$PerformClick.run(View.java:25885)
at android.os.Handler.handleCallback(Handler.java:873)
at android.os.Handler.dispatchMessage(Handler.java:99)
at android.os.Looper.loop(Looper.java:193)
at android.app.ActivityThread.main(ActivityThread.java:6669)
at java.lang.reflect.Method.invoke(Native method)
at com.android.internal.os.RuntimeInit$MethodAndArgsCaller.run(RuntimeInit.java:493)
at com.android.internal.os.ZygoteInit.main(ZygoteInit.java:858)
...
可以看到這里面能幫助定位的相關(guān)信息有:
- 發(fā)生ANR的進(jìn)程id及時(shí)間:pid 6194 at 2021-02-16 22:12:46
- CPU架構(gòu):x86_64
- 堆內(nèi)存信息:Heap: 35% free, 5MB/8MB; 56540 objects
- 主線程基本信息:名稱("main")闻妓,優(yōu)先級( prio=5 )菌羽,線程鎖id (tid=1), 線程狀態(tài)(Blocked-阻塞)
- 主線程詳細(xì)信息
- 線程堆棧信息由缆,從中可以看到這次的ANR是由于等待鎖導(dǎo)致的注祖,這個(gè)鎖被id為13的線程持有了:
at com.comoko.myapplication.anr.AnrActivity$onCreate$1.onClick(AnrActivity.kt:32)
- waiting to lock <0x0aab8a86> (a java.lang.Object) held by thread 13
然后我們繼續(xù)通過id=13去在文件內(nèi)進(jìn)行全局搜索猾蒂,可以很容易的找到以下信息:
"Thread-2" prio=5 tid=13 Sleeping
| group="main" sCount=1 dsCount=0 flags=1 obj=0x1544f4a8 self=0x7a31861fdc00
| sysTid=6219 nice=0 cgrp=default sched=0/0 handle=0x7a316e5014f0
| state=S schedstat=( 7782128 9870407 7 ) utm=0 stm=0 core=3 HZ=100
| stack=0x7a316e3fe000-0x7a316e400000 stackSize=1041KB
| held mutexes=
at java.lang.Thread.sleep(Native method)
- sleeping on <0x08a5c912> (a java.lang.Object)
at java.lang.Thread.sleep(Thread.java:373)
- locked <0x08a5c912> (a java.lang.Object)
at java.lang.Thread.sleep(Thread.java:314)
at com.comoko.myapplication.anr.AnrActivity$onCreate$work$1.run(AnrActivity.kt:41)
- locked <0x0aab8a86> (a java.lang.Object)
可以看到id為13的線程確實(shí)持有了主線程等待的鎖0x0aab8a86
,并且狀態(tài)是Sleeping是晨,至此一次ANR的分析基本結(jié)束肚菠。
參考文檔
《Android高級進(jìn)階》