ANR(一)

http://www.reibang.com/p/fa962a5fd939
http://gityuan.com/2016/07/02/android-anr/
https://developer.android.com/topic/performance/vitals/anr.html#java
https://developer.android.com/training/articles/perf-anr.html

控制臺日志過濾 ActivityManager
命令行導(dǎo)出手機(jī)anr日志 adb pull data/anr/ .

  • 獲取anr 日志
    獲取控制臺log 過濾 關(guān)鍵TAG ActivityManager 或者善涨、從log中搜索“ANR in”或“am_anr”恶阴,會找到ANR發(fā)生的log
    例如 過濾 ActivityManager
03-25 13:41:04.871 1614-1634/? E/ActivityManager: ANR in com.jpc.anr (com.jpc.anr/.developer.DeveloperActivity)
    PID: 17669
    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: 1.)
    Load: 0.0 / 0.0 / 0.0
    CPU usage from 0ms to 13555ms later (2019-03-25 13:40:51.258 to 2019-03-25 13:41:04.813):
      72% 17669/com.jpc.anr: 70% user + 1.9% kernel / faults: 3581 minor 191 major
      28% 1614/system_server: 16% user + 12% kernel / faults: 5253 minor 1612 major
      8.7% 123/kswapd0: 0% user + 8.7% kernel

獲取手機(jī)上的日志:androidStudio Terminal 里輸入,導(dǎo)出日志到工程目錄中會自動生成 anr 文件夾加,手機(jī)上的anr日志會被覆蓋寺渗,要及時導(dǎo)出。

adb pull data/anr/ .
  • 什么情況下會出現(xiàn)ANR問題:
    ANR(Application Not responding)定欧。Android中,主線程(UI線程)如果在規(guī)定時內(nèi)沒有處理完相應(yīng)工作聚请,就會出現(xiàn)ANR荠雕。
    具體來說稳其,ANR會在以下幾種情況中出現(xiàn):
  1. 輸入事件(按鍵和觸摸事件)5s內(nèi)沒被處理: Input event dispatching timed out
  2. BroadcastReceiver的事件(onRecieve方法)在規(guī)定時間內(nèi)沒處理完(前臺廣播為10s,后臺廣播為60s):Timeout of broadcast BroadcastRecord
  3. service 前臺20s后臺200s未完成啟動 Timeout executing service
  4. ContentProvider的publish在10s內(nèi)沒進(jìn)行完:timeout publishing content providers
    在android文檔([https://developer.android.com/training/articles/perf-anr.html]中炸卑,只寫了第一種和第二種情況既鞠,而根據(jù)源碼和實(shí)際的實(shí)驗(yàn),我們能發(fā)現(xiàn)service的啟動和provider的publish同樣會造成anr問題盖文。
    這里需要注意的是嘱蛋,在后三種情況,以BroadcastReviever為例五续,在onRecieve()方法執(zhí)行10秒內(nèi)沒發(fā)生第一種ANR(也就是在這個過程中沒有輸入事件或輸入事件還沒到5s)才會發(fā)生Receiver timeout洒敏,否則將先發(fā)生事件無相應(yīng)ANR,所以onRecieve()是有可能執(zhí)行不到10s就發(fā)生ANR的疙驾,所以不要在onRecieve()方法里面干活凶伙,service的onCreate()和ContentProvider的onCreate()也一樣,他們都是主線程的它碎,不要在這些方法里干活
  • 如何分析ANR問題:
    從前文可以明確函荣,ANR問題是由于主線程的任務(wù)在規(guī)定時間內(nèi)沒處理完任務(wù),而造成這種情況的原因大致會有一下幾點(diǎn):

主線程在做一些耗時的工作
主線程被其他線程鎖
cpu被其他進(jìn)程占用扳肛,該進(jìn)程沒被分配到足夠的cpu資源傻挂。

判斷一個ANR屬于哪種情況便是分析ANR問題的關(guān)鍵。那么拿到一個anr的日志挖息,應(yīng)該如何分析呢金拒?
在發(fā)生ANR的時候,系統(tǒng)會收集ANR相關(guān)的信息提供給開發(fā)者:首先在Log中有ANR相關(guān)的信息旋讹,其次會收集ANR時的CPU使用情況殖蚕,還會收集trace信息,也就是當(dāng)時各個線程的執(zhí)行情況沉迹。trace文件保存到了/data/anr/traces.txt中睦疫,此外,ANR前后該進(jìn)程打印出的log也有一定價值鞭呕。一般來說可以按一下思路來分析:

從log中找到ANR反生的信息:可以從log中搜索“ANR in”或“am_anr”蛤育,會找到ANR發(fā)生的log,該行會包含了ANR的時間葫松、進(jìn)程瓦糕、是何種ANR等信息,如果是BroadcastReceiver的ANR可以懷疑BroadCastReceiver.onRecieve()的問題腋么,如果的Service或Provider就懷疑是否其onCreate()的問題咕娄。
在該條log之后會有CPU usage的信息,表明了CPU在ANR前后的用量(log會表明截取ANR的時間)珊擂,從各種CPU Usage信息中大概可以分析如下幾點(diǎn):
(1). 如果某些進(jìn)程的CPU占用百分比較高圣勒,幾乎占用了所有CPU資源费变,而發(fā)生ANR的進(jìn)程CPU占用為0%或非常低,則認(rèn)為CPU資源被占用圣贸,進(jìn)程沒有被分配足夠的資源挚歧,從而發(fā)生了ANR。這種情況多數(shù)可以認(rèn)為是系統(tǒng)狀態(tài)的問題吁峻,并不是由本應(yīng)用造成的滑负。
(2). 如果發(fā)生ANR的進(jìn)程CPU占用較高,如到了80%或90%以上用含,則可以懷疑應(yīng)用內(nèi)一些代碼不合理消耗掉了CPU資源矮慕,如出現(xiàn)了死循環(huán)或者后臺有許多線程執(zhí)行任務(wù)等等原因,這就要結(jié)合trace和ANR前后的log進(jìn)一步分析了耕餐。
(3). 如果CPU總用量不高凡傅,該進(jìn)程和其他進(jìn)程的占用過高,這有一定概率是由于某些主線程的操作就是耗時過長肠缔,或者是由于主進(jìn)程被鎖造成的夏跷。
除了上述的情況(1)以外,分析CPU usage之后明未,確定問題需要我們進(jìn)一步分析trace文件槽华。trace文件記錄了發(fā)生ANR前后該進(jìn)程的各個線程的stack。對我們分析ANR問題最有價值的就是其中主線程的stack趟妥,一般主線程的trace可能有如下幾種情況:
(1). 主線程是running或者native而對應(yīng)的棧對應(yīng)了我們應(yīng)用中的函數(shù)猫态,則很有可能就是執(zhí)行該函數(shù)時候發(fā)生了超時。
(2). 主線程被block:非常明顯的線程被鎖披摄,這時候可以看是被哪個線程鎖了亲雪,可以考慮優(yōu)化代碼。如果是死鎖問題疚膊,就更需要及時解決了义辕。
(3). 由于抓trace的時刻很有可能耗時操作已經(jīng)執(zhí)行完了(ANR -> 耗時操作執(zhí)行完畢 ->系統(tǒng)抓trace),這時候的trace就沒有什么用了寓盗,主線程的stack就是這樣的:

"main" prio=5 tid=1 Native
  | group="main" sCount=1 dsCount=0 obj=0x757855c8 self=0xb4d76500
  | sysTid=3276 nice=0 cgrp=default sched=0/0 handle=0xb6ff5b34
  | state=S schedstat=( 50540218363 186568972172 209049 ) utm=3290 stm=1764 core=3 HZ=100
  | stack=0xbe307000-0xbe309000 stackSize=8MB
  | held mutexes=
  kernel: (couldn't read /proc/self/task/3276/stack)
  native: #00 pc 0004099c  /system/lib/libc.so (__epoll_pwait+20)
  native: #01 pc 00019f63  /system/lib/libc.so (epoll_pwait+26)
  native: #02 pc 00019f71  /system/lib/libc.so (epoll_wait+6)
  native: #03 pc 00012ce7  /system/lib/libutils.so (_ZN7android6Looper9pollInnerEi+102)
  native: #04 pc 00012f63  /system/lib/libutils.so (_ZN7android6Looper8pollOnceEiPiS1_PPv+130)
  native: #05 pc 00086abd  /system/lib/libandroid_runtime.so (_ZN7android18NativeMessageQueue8pollOnceEP7_JNIEnvP8_jobjecti+22)
  native: #06 pc 0000055d  /data/dalvik-cache/arm/system@framework@boot.oat (Java_android_os_MessageQueue_nativePollOnce__JI+96)
  at android.os.MessageQueue.nativePollOnce(Native method)
  at android.os.MessageQueue.next(MessageQueue.java:323)
  at android.os.Looper.loop(Looper.java:138)
  at android.app.ActivityThread.main(ActivityThread.java:5528)
  at java.lang.reflect.Method.invoke!(Native method)
  at com.android.internal.os.ZygoteInit$MethodAndArgsCaller.run(ZygoteInit.java:740)
  at com.android.internal.os.ZygoteInit.main(ZygoteInit.java:630)

當(dāng)然這種情況很有可能是由于該進(jìn)程的其他線程消耗掉了CPU資源灌砖,這就需要分析其他線程的trace以及ANR前后該進(jìn)程自己輸出的log了。

  • 如何降低ANR的概率:

有一些操作是很危險的傀蚌,非常容易發(fā)生ANR基显,在寫代碼時候一定要避免:

  1. 主線程讀取數(shù)據(jù):在Android中主線程去讀取數(shù)據(jù)是非常不好的,Android是不允許主線程從網(wǎng)絡(luò)讀數(shù)據(jù)的善炫,但系統(tǒng)允許主線程從數(shù)據(jù)庫或者其他地方獲取數(shù)據(jù)撩幽,但這種操作ANR風(fēng)險很大,也會造成掉幀等箩艺,影響用戶體驗(yàn)摸航。
    (1). 避免在主線程query provider制跟,首先這會比較耗時,另外這個操作provider那一方的進(jìn)程如果掛掉了或者正在啟動酱虎,我們應(yīng)用的query就會很長時間不會返回,我們應(yīng)該在其他線程中執(zhí)行數(shù)據(jù)庫query擂涛、provider的query等獲取數(shù)據(jù)的操作读串。
    (2). sharePreference的調(diào)用:針對sharePreference的優(yōu)化點(diǎn)有很多,文章http://weishu.me/2016/10/13/sharedpreference-advices/ 詳細(xì)介紹了幾點(diǎn)sharepreference使用時候的注意事項(xiàng)撒妈。首先sharePreference的commit()方法是同步的恢暖,apply()方法一般是異步執(zhí)行的。所以在主線程不要用其commit()狰右,用apply()替換杰捂。其次sharePreference的寫是全量寫而非增量寫,所以盡量都修改完同一apply棋蚌,避免改一點(diǎn)apply一次(apply()方法在Activity stop的時候主線程會等待寫入完成嫁佳,提交多次就很容易卡)。并且存儲文本也不宜過大谷暮,這樣會很慢蒿往。另外,如果寫入的是json或者xml湿弦,由于需要加和刪轉(zhuǎn)義符號瓤漏,速度會比較慢。
  2. 不要在broadcastReciever的onRecieve()方法中干活颊埃,這一點(diǎn)很容易被忽略蔬充,尤其應(yīng)用在后臺的時候。為避免這種情況班利,一種解決方案是直接開的異步線程執(zhí)行饥漫,但此時應(yīng)用可能在后臺,系統(tǒng)優(yōu)先級較低肥败,進(jìn)程很容易被系統(tǒng)殺死趾浅,所以可以選擇開個IntentService去執(zhí)行相應(yīng)操作,即使是后臺Service也會提高進(jìn)程優(yōu)先級馒稍,降低被殺可能性皿哨。
  3. 各個組件的生命周期函數(shù)都不應(yīng)該有太耗時的操作,即使對于后臺Service或者ContentProvider來講纽谒,應(yīng)用在后臺運(yùn)行時候其onCreate()時候不會有用戶輸入引起事件無響應(yīng)ANR证膨,但其執(zhí)行時間過長也會引起Service的ANR和ContentProvider的ANR。
  4. 盡量避免主線程的被鎖的情況鼓黔,在一些同步的操作主線程有可能被鎖央勒,需要等待其他線程釋放相應(yīng)鎖才能繼續(xù)執(zhí)行不见,這樣會有一定的ANR風(fēng)險,對于這種情況有時也可以用異步線程來執(zhí)行相應(yīng)的邏輯崔步。另外稳吮, 我們要避免死鎖的發(fā)生(主線程被死鎖基本就等于要發(fā)生ANR了)
ANR超時時間在ActivityManagerService.Java文件中進(jìn)行了定義    
// 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;  
// How long we wait until we timeout on key dispatching.  
static final int KEY_DISPATCHING_TIMEOUT = 5*1000;  
// How long we wait until we timeout on key dispatching during instrumentation.  
static final int INSTRUMENTATION_KEY_DISPATCHING_TIMEOUT = 60*1000;  
service ANR超時的定義在ActiveServices.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 日志分析
    從LOG可以看出ANR的類型,CPU的使用情況井濒,如果CPU使用量接近100%灶似,說明當(dāng)前設(shè)備很忙,有可能是CPU饑餓導(dǎo)致了ANR
    如果CPU使用量很少瑞你,說明主線程被BLOCK了
    如果IOwait很高酪惭,說明ANR有可能是主線程在進(jìn)行I/O操作造成的
    主線程等待子線程釋放鎖 的控制臺 anr日志 log_develop_3_1.txt
03-25 17:30:19.379 1614-1634/? E/ActivityManager: ANR in com.jpc.anr (com.jpc.anr/.developer.DeveloperActivity)
    PID: 25121
    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: 28285.5ms.)
    Load: 0.0 / 0.11 / 0.1
    CPU usage from 164ms to -12075ms ago (2019-03-25 17:30:07.083 to 2019-03-25 17:30:19.322):
      100% 25121/com.jpc.anr: 99% user + 0.4% kernel / faults: 1429 minor 111 major
      57% 1614/system_server: 32% user + 25% kernel / faults: 30845 minor 19010 major
      ...

主線程等待子線程釋放鎖 手機(jī)端日志 traces_develop_anr_3_1.txt

----- pid 25121 at 2019-03-25 17:30:07 -----
Cmd line: com.jpc.anr
...

suspend all histogram:  Sum: 2.395s 99% C.I. 0.006ms-19.618ms Avg: 1.257ms Max: 63.326ms
DALVIK THREADS (23):
"AsyncTask #1" prio=5 tid=23 Runnable
  | group="main" sCount=0 dsCount=0 flags=0 obj=0x15e80028 self=0x7224df7800
  | sysTid=28220 nice=10 cgrp=default sched=0/0 handle=0x7222b824f0
  | state=R schedstat=( 32246677889 21909686 174 ) utm=3224 stm=0 core=4 HZ=100
  | stack=0x7222a80000-0x7222a82000 stackSize=1037KB
  | held mutexes= "mutator lock"(shared held)
  at com.jpc.anr.developer.BubbleSort.sortData(BubbleSort.java:26)


"Signal Catcher" daemon prio=5 tid=3 Runnable
  | group="system" sCount=0 dsCount=0 flags=0 obj=0x15e80e38 self=0x72416c4400
  | sysTid=25127 nice=0 cgrp=default sched=0/0 handle=0x72368fe4f0


"main" prio=5 tid=1 Blocked
  | group="main" sCount=1 dsCount=0 flags=1 obj=0x731f8120 self=0x72416c3a00
  | sysTid=25121 nice=-10 cgrp=default sched=0/0 handle=0x72468ee9c8
  | state=S schedstat=( 1306069289 83794736 729 ) utm=102 stm=28 core=6 HZ=100
  | stack=0x7fce8a2000-0x7fce8a4000 stackSize=8MB
  | held mutexes=
  at com.jpc.anr.developer.DeveloperActivity$1.onClick(DeveloperActivity.java:92)
  - waiting to lock <0x0f2ca04d> (a java.lang.Object) held by thread 23
  at android.view.View.performClick(View.java:6891)

從控制臺日志里知道anr的包名和pid = A,在手機(jī)的日志里搜索 “"main" prio=5” 同時pid = A的線程者甲,這個是發(fā)生ANR 應(yīng)用的主線程春感,【"main" prio=5 tid=1 Blocked】看線程狀態(tài) 推測一些信息;一般手機(jī)日志的和第一個線程相關(guān)的記錄和發(fā)生anr有關(guān)【"AsyncTask #1" prio=5 tid=23 Runnable】虏缸。

線程狀態(tài)
線程狀態(tài).png

相關(guān)anr日志分析帖子
https://blog.csdn.net/fanxudonggreat/article/details/81840791
http://www.reibang.com/p/545e5e7bbf94
https://blog.csdn.net/tinderliang/article/details/77717872
https://blog.csdn.net/tjy1985/article/details/6777983

其他
http://www.reibang.com/p/388166988cef

?著作權(quán)歸作者所有,轉(zhuǎn)載或內(nèi)容合作請聯(lián)系作者
  • 序言:七十年代末鲫懒,一起剝皮案震驚了整個濱河市,隨后出現(xiàn)的幾起案子寇钉,更是在濱河造成了極大的恐慌刀疙,老刑警劉巖,帶你破解...
    沈念sama閱讀 219,270評論 6 508
  • 序言:濱河連續(xù)發(fā)生了三起死亡事件扫倡,死亡現(xiàn)場離奇詭異谦秧,居然都是意外死亡,警方通過查閱死者的電腦和手機(jī)撵溃,發(fā)現(xiàn)死者居然都...
    沈念sama閱讀 93,489評論 3 395
  • 文/潘曉璐 我一進(jìn)店門疚鲤,熙熙樓的掌柜王于貴愁眉苦臉地迎上來,“玉大人缘挑,你說我怎么就攤上這事集歇。” “怎么了语淘?”我有些...
    開封第一講書人閱讀 165,630評論 0 356
  • 文/不壞的土叔 我叫張陵诲宇,是天一觀的道長。 經(jīng)常有香客問我惶翻,道長姑蓝,這世上最難降的妖魔是什么? 我笑而不...
    開封第一講書人閱讀 58,906評論 1 295
  • 正文 為了忘掉前任吕粗,我火速辦了婚禮纺荧,結(jié)果婚禮上,老公的妹妹穿的比我還像新娘。我一直安慰自己宙暇,他們只是感情好输枯,可當(dāng)我...
    茶點(diǎn)故事閱讀 67,928評論 6 392
  • 文/花漫 我一把揭開白布。 她就那樣靜靜地躺著占贫,像睡著了一般桃熄。 火紅的嫁衣襯著肌膚如雪。 梳的紋絲不亂的頭發(fā)上靶剑,一...
    開封第一講書人閱讀 51,718評論 1 305
  • 那天蜻拨,我揣著相機(jī)與錄音,去河邊找鬼桩引。 笑死,一個胖子當(dāng)著我的面吹牛收夸,可吹牛的內(nèi)容都是我干的坑匠。 我是一名探鬼主播,決...
    沈念sama閱讀 40,442評論 3 420
  • 文/蒼蘭香墨 我猛地睜開眼卧惜,長吁一口氣:“原來是場噩夢啊……” “哼厘灼!你這毒婦竟也來了?” 一聲冷哼從身側(cè)響起咽瓷,我...
    開封第一講書人閱讀 39,345評論 0 276
  • 序言:老撾萬榮一對情侶失蹤设凹,失蹤者是張志新(化名)和其女友劉穎,沒想到半個月后茅姜,有當(dāng)?shù)厝嗽跇淞掷锇l(fā)現(xiàn)了一具尸體闪朱,經(jīng)...
    沈念sama閱讀 45,802評論 1 317
  • 正文 獨(dú)居荒郊野嶺守林人離奇死亡,尸身上長有42處帶血的膿包…… 初始之章·張勛 以下內(nèi)容為張勛視角 年9月15日...
    茶點(diǎn)故事閱讀 37,984評論 3 337
  • 正文 我和宋清朗相戀三年钻洒,在試婚紗的時候發(fā)現(xiàn)自己被綠了奋姿。 大學(xué)時的朋友給我發(fā)了我未婚夫和他白月光在一起吃飯的照片。...
    茶點(diǎn)故事閱讀 40,117評論 1 351
  • 序言:一個原本活蹦亂跳的男人離奇死亡素标,死狀恐怖称诗,靈堂內(nèi)的尸體忽然破棺而出,到底是詐尸還是另有隱情头遭,我是刑警寧澤寓免,帶...
    沈念sama閱讀 35,810評論 5 346
  • 正文 年R本政府宣布,位于F島的核電站计维,受9級特大地震影響袜香,放射性物質(zhì)發(fā)生泄漏。R本人自食惡果不足惜享潜,卻給世界環(huán)境...
    茶點(diǎn)故事閱讀 41,462評論 3 331
  • 文/蒙蒙 一困鸥、第九天 我趴在偏房一處隱蔽的房頂上張望。 院中可真熱鬧,春花似錦疾就、人聲如沸澜术。這莊子的主人今日做“春日...
    開封第一講書人閱讀 32,011評論 0 22
  • 文/蒼蘭香墨 我抬頭看了看天上的太陽鸟废。三九已至,卻和暖如春姑荷,著一層夾襖步出監(jiān)牢的瞬間盒延,已是汗流浹背。 一陣腳步聲響...
    開封第一講書人閱讀 33,139評論 1 272
  • 我被黑心中介騙來泰國打工鼠冕, 沒想到剛下飛機(jī)就差點(diǎn)兒被人妖公主榨干…… 1. 我叫王不留添寺,地道東北人。 一個月前我還...
    沈念sama閱讀 48,377評論 3 373
  • 正文 我出身青樓懈费,卻偏偏與公主長得像计露,于是被迫代替她去往敵國和親。 傳聞我的和親對象是個殘疾皇子憎乙,可洞房花燭夜當(dāng)晚...
    茶點(diǎn)故事閱讀 45,060評論 2 355

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