Android性能優(yōu)化之ANR

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)行退出:

image.png

此時(shí)如果查看log趴乡,一般可以發(fā)現(xiàn)導(dǎo)致此問題的蛛絲馬跡:

image.png

例如上圖,可以很清晰的看到發(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干像,由于BroadcastReceiveronReceiver方法運(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)如下日志:

StrictMode

可以看到日志中詳細(xì)的列出了在 AnrActivity的第28行,在主線程中有一個(gè)讀磁盤的操作拗慨,耗時(shí)29ms廓八。

啟用后臺 ANR 對話框
bg_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)行分析简烤。:

ANRlog

如何定位與分析

首先通過以下代碼制造一次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é)束肚菠。

參考文檔

開發(fā)者指南-ANR

《Android高級進(jìn)階》

最后編輯于
?著作權(quán)歸作者所有,轉(zhuǎn)載或內(nèi)容合作請聯(lián)系作者
  • 序言:七十年代末,一起剝皮案震驚了整個(gè)濱河市罩缴,隨后出現(xiàn)的幾起案子蚊逢,更是在濱河造成了極大的恐慌,老刑警劉巖箫章,帶你破解...
    沈念sama閱讀 216,744評論 6 502
  • 序言:濱河連續(xù)發(fā)生了三起死亡事件烙荷,死亡現(xiàn)場離奇詭異,居然都是意外死亡檬寂,警方通過查閱死者的電腦和手機(jī)终抽,發(fā)現(xiàn)死者居然都...
    沈念sama閱讀 92,505評論 3 392
  • 文/潘曉璐 我一進(jìn)店門,熙熙樓的掌柜王于貴愁眉苦臉地迎上來焰薄,“玉大人,你說我怎么就攤上這事扒袖∪” “怎么了?”我有些...
    開封第一講書人閱讀 163,105評論 0 353
  • 文/不壞的土叔 我叫張陵季率,是天一觀的道長野瘦。 經(jīng)常有香客問我,道長飒泻,這世上最難降的妖魔是什么鞭光? 我笑而不...
    開封第一講書人閱讀 58,242評論 1 292
  • 正文 為了忘掉前任,我火速辦了婚禮泞遗,結(jié)果婚禮上惰许,老公的妹妹穿的比我還像新娘。我一直安慰自己史辙,他們只是感情好汹买,可當(dāng)我...
    茶點(diǎn)故事閱讀 67,269評論 6 389
  • 文/花漫 我一把揭開白布。 她就那樣靜靜地躺著聊倔,像睡著了一般晦毙。 火紅的嫁衣襯著肌膚如雪。 梳的紋絲不亂的頭發(fā)上耙蔑,一...
    開封第一講書人閱讀 51,215評論 1 299
  • 那天见妒,我揣著相機(jī)與錄音,去河邊找鬼甸陌。 笑死须揣,一個(gè)胖子當(dāng)著我的面吹牛盐股,可吹牛的內(nèi)容都是我干的。 我是一名探鬼主播返敬,決...
    沈念sama閱讀 40,096評論 3 418
  • 文/蒼蘭香墨 我猛地睜開眼遂庄,長吁一口氣:“原來是場噩夢啊……” “哼!你這毒婦竟也來了劲赠?” 一聲冷哼從身側(cè)響起涛目,我...
    開封第一講書人閱讀 38,939評論 0 274
  • 序言:老撾萬榮一對情侶失蹤,失蹤者是張志新(化名)和其女友劉穎凛澎,沒想到半個(gè)月后霹肝,有當(dāng)?shù)厝嗽跇淞掷锇l(fā)現(xiàn)了一具尸體,經(jīng)...
    沈念sama閱讀 45,354評論 1 311
  • 正文 獨(dú)居荒郊野嶺守林人離奇死亡塑煎,尸身上長有42處帶血的膿包…… 初始之章·張勛 以下內(nèi)容為張勛視角 年9月15日...
    茶點(diǎn)故事閱讀 37,573評論 2 333
  • 正文 我和宋清朗相戀三年沫换,在試婚紗的時(shí)候發(fā)現(xiàn)自己被綠了。 大學(xué)時(shí)的朋友給我發(fā)了我未婚夫和他白月光在一起吃飯的照片最铁。...
    茶點(diǎn)故事閱讀 39,745評論 1 348
  • 序言:一個(gè)原本活蹦亂跳的男人離奇死亡讯赏,死狀恐怖,靈堂內(nèi)的尸體忽然破棺而出冷尉,到底是詐尸還是另有隱情漱挎,我是刑警寧澤,帶...
    沈念sama閱讀 35,448評論 5 344
  • 正文 年R本政府宣布雀哨,位于F島的核電站磕谅,受9級特大地震影響,放射性物質(zhì)發(fā)生泄漏雾棺。R本人自食惡果不足惜膊夹,卻給世界環(huán)境...
    茶點(diǎn)故事閱讀 41,048評論 3 327
  • 文/蒙蒙 一、第九天 我趴在偏房一處隱蔽的房頂上張望捌浩。 院中可真熱鬧放刨,春花似錦、人聲如沸尸饺。這莊子的主人今日做“春日...
    開封第一講書人閱讀 31,683評論 0 22
  • 文/蒼蘭香墨 我抬頭看了看天上的太陽侵佃。三九已至麻昼,卻和暖如春,著一層夾襖步出監(jiān)牢的瞬間馋辈,已是汗流浹背抚芦。 一陣腳步聲響...
    開封第一講書人閱讀 32,838評論 1 269
  • 我被黑心中介騙來泰國打工, 沒想到剛下飛機(jī)就差點(diǎn)兒被人妖公主榨干…… 1. 我叫王不留,地道東北人叉抡。 一個(gè)月前我還...
    沈念sama閱讀 47,776評論 2 369
  • 正文 我出身青樓尔崔,卻偏偏與公主長得像,于是被迫代替她去往敵國和親褥民。 傳聞我的和親對象是個(gè)殘疾皇子季春,可洞房花燭夜當(dāng)晚...
    茶點(diǎn)故事閱讀 44,652評論 2 354

推薦閱讀更多精彩內(nèi)容