ANR
Application Not Responding
ANR類型
Service Timeout:比如前臺服務在20s內未執(zhí)行完成肉渴,后臺服務Timeout時間是前臺服務的10倍啃匿,200s艺玲;
BroadcastQueue Timeout:比如前臺廣播在10s內未執(zhí)行完成,后臺60s
ContentProvider Timeout:內容提供者,在publish過超時10s;
InputDispatching Timeout: 輸入事件分發(fā)超時5s险污,包括按鍵和觸摸事件。
對于input來說即便某次事件執(zhí)行時間超過Timeout時長,只要用戶后續(xù)沒有再生成輸入事件头遭,則不會觸發(fā)ANR
ANR文件獲取方式
1.低于Android10系統(tǒng)的手機
adb pull data/anr
2.大于等于Android10系統(tǒng)的手機
如果在Android10以上系統(tǒng),使用adb pull的方式拉取trace文件癣诱,會得到permission denied计维。需要使用新的命令完成
adb bugreport
導致ANR的原因
應用層導致ANR:
1.函數(shù)阻塞:如死循環(huán)、主線程IO撕予、處理大數(shù)據(jù)鲫惶。
2.鎖出錯:主線程等待子線程的鎖。
3.內存緊張:系統(tǒng)分配給一個應用的內存是有上限的实抡,長期處于內存緊張欠母,會導致頻繁內存交換欢策,進而導致應用的一些操作超時。
系統(tǒng)導致ANR:
1.CPU被搶占:一般來說赏淌,前臺在玩游戲猬腰,可能會導致你的后臺廣播被搶占。
2.系統(tǒng)服務無法及時響應:系統(tǒng)的服務都是Binder機制猜敢,服務能力也是有限的姑荷,有可能系統(tǒng)服務長時間不響應導致ANR。
3.其他應用占用大量內存缩擂。
系統(tǒng)ANR檢測機制
ANR由消息處理機制保證鼠冕,核心原理是消息調度和超時處理。
雖然系統(tǒng)觸發(fā)anr的地方有好幾種胯盯,但是檢測機制和處理機制其實是差不多的懈费,都是在操作前記錄時間,然后向消息隊列中丟向一個觸發(fā)Anr的消息(基于消息機制)博脑,再執(zhí)行完響應的操作的時候將消息移除憎乙,如果超過指定時間沒有移除,那么則會觸發(fā)anr操作叉趣。
ps
發(fā)生anr的時候是主線程已經被阻塞了泞边,anr也是基于消息機制,是一個延時消息疗杉,那為什么它還能被執(zhí)行呢阵谚?
發(fā)生anr時,被阻塞的是app進程的主線程烟具,而anr延時消息并不是在app進程中處理的梢什。它是通過AMS所在進程中的子線程消息隊列中執(zhí)行的(ams內部除了有主線程的消息隊列外,還持有了一個異步的消息隊列)朝聋,所以時間到了之后還是可以被looper取出; 然后將顯示anr彈窗的消息發(fā)送到AMS主線程的消息隊列(mUiHandler)嗡午,去展示彈窗。
service
: 當Service的生命周期開始時冀痕,bumpServiceExecutingLocked()會被調用荔睹,緊接著會調用scheduleServiceTimeoutLocked(),向消息隊列發(fā)送一個延遲消息(20s(后臺服務200s)),當Service的生命周期結束時金度,在serviceDoneExecutingLocked方法中移除這個消息应媚,如果時間到了還沒有移除,就提示anr猜极。由AMS調度,利用Handler和Looper消玄,設計了一個TIMEOUT消息交由AMS線程來處理跟伏,整個超時機制的實現(xiàn)都是在Java層丢胚。
broadcast
:Broadcast ANR,前臺的“串行廣播消息”必須在10秒內處理完畢受扳,后臺的“串行廣播消息”必須在60秒處理完畢携龟, 每派發(fā)串行廣播消息到一個接收器時,都會拋出一個定時消息BROADCAST_TIMEOUT_MSG勘高,如果定時消息響應峡蟋,則判斷是否廣播消息處理超時,超時就說明發(fā)生了ANR华望。由AMS調度蕊蝗,利用Handler和Looper,設計了一個TIMEOUT消息交由AMS線程來處理赖舟,整個超時機制的實現(xiàn)都是在Java層蓬戚。
input
: 在InputDispatcher派發(fā)輸入事件時,會尋找接收事件的窗口宾抓,如果無法正常派發(fā)子漩,則可能會導致當前需要派發(fā)的事件超時(默認是5秒)。 Native層發(fā)現(xiàn)超時了石洗,會通知Java層幢泼,Java層經過一些處理后,會反饋給Native層讲衫,是繼續(xù)等待還是丟棄當前派發(fā)的事件旭绒。 InputEvent由InputDispatcher調度,待處理的輸入事件都會進入隊列中等待焦人,設計了一個等待超時的判斷挥吵,超時機制的實現(xiàn)在Native層。
service花椭、broadcast忽匈、provider 的ANR原理都是埋定時炸彈和拆炸彈原理,
但是input的超時檢測機制稍微有點不同矿辽,需要等收到下一次input事件丹允,才會去檢測上一次input事件是否超時,input事件里埋的炸彈是普通炸彈袋倔,需要通過掃雷來排查雕蔽。
SNR(System Not Respoding)
SNR由Watchdog機制保證。Watchdog定時(30s)檢查一些重要的系統(tǒng)服務宾娜,舉報長時間阻塞的事件批狐,甚至殺掉system_server進程,讓Android系統(tǒng)重啟。
Monitor Checker(addMonitor)嚣艇,用于檢查是Monitor對象可能發(fā)生的死鎖, AMS, PKMS, WMS等核心的系統(tǒng)服務都是Monitor對象承冰。
Looper Checker(addThread),用于檢查線程的消息隊列是否長時間處于工作狀態(tài)食零。一些重要的線程的消息隊列困乒,也會加入到Looper Checker中,譬如AMS, PKMS贰谣,這些是在對應的對象初始化時加入的娜搂。
Monitor Checker預警我們不能長時間持有核心系統(tǒng)服務的對象鎖,否則會阻塞很多函數(shù)的運行; Looper Checker預警我們不能長時間的霸占消息隊列吱抚,否則其他消息將得不到處理百宇。這兩類都會導致系統(tǒng)卡住(System Not Responding)。
ANR主要流程
所有ANR频伤,最終都會調用AppErrors的appNotResponding方法
1.系統(tǒng)監(jiān)控到app發(fā)生ANR后恳谎,收集了一些相關進程pid(包括發(fā)生ANR的進程),準備讓這些進程dump堆棧憋肖,從而生成ANR Trace文件因痛。
2.系統(tǒng)開始向這些進程發(fā)送SIGQUIT信號(通過監(jiān)聽這個信號可以實現(xiàn)對anr的監(jiān)控,如matrix的實現(xiàn)
)岸更,進程收到SIGQUIT信號之后開始dump堆棧鸵膏。
AMS開始按照firstPids、nativePids怎炊、extraPids的順序dump這些進程的堆棧谭企。并且最長dump時間限制為20秒。
dump的調用過程:
→ dumpStackTraces
→ dumpJavaTracesTombstoned
→ ActivityManagerService#dumpJavaTracesTombstoned()
→ Debug#dumpJavaBacktraceToFileTimeout()
→ android_os_Debug#android_os_Debug_dumpJavaBacktraceToFileTimeout()
→ android_os_Debug#dumpTraces()
→ debuggerd_client#dump_backtrace_to_file_timeout()
→ debuggerd_client#debuggerd_trigger_dump()评肆。
1.AMS進程間接給需要dump堆棧那個進程發(fā)送了一個SIGQUIT信號
2.除Zygote進程外债查,每個進程都會創(chuàng)建一個SignalCatcher守護線程,用于捕獲SIGQUIT,然后開始dump
3.這個過程從收到SIGQUIT信號開始到使用socket寫Trace結束瓜挽。
ANR監(jiān)控
一. WatchDog
ANRWatchDog 是一個自動檢測ANR的開源庫盹廷,往主線程發(fā)送消息,并設置超時檢測久橙,如果超時還沒執(zhí)行相應消息俄占,則判定為可能發(fā)生ANR。需要進一步從系統(tǒng)服務獲取相關數(shù)據(jù)(可通過ActivityManagerService.getProcessesInErrorState()方法獲取進程的ANR信息)淆衷,進一步判定是否真的發(fā)生了ANR缸榄。
缺點
1.存在5s的誤差,假設當ANRWatchDog post消息的時候祝拯,已經卡了2s甚带,然后再過3s卡完了恢復了,那么ANRWatchDog是監(jiān)測不到的。
2.和BlockCanary一樣不支持touch事件的監(jiān)測
優(yōu)化ANRWatchDog存在5s的誤差的缺點(AnrMonitor)
欲低。每隔1s就會檢查一下辕宏,并提示可能的風險畜晰,累計5s就觸發(fā)ANR流程砾莱,這是一個實現(xiàn)思路,代碼只提供了一個demo,還需要完善凄鼻。此方案可以結合ProcessLifecycleOwner腊瑟,應用在前臺才開啟檢測,進入后臺則停止檢測块蚌。
二. SIGQUIT信號
該方案通過去監(jiān)聽SIGQUIT信號闰非,從而感知當前進程可能發(fā)生了ANR,需配合當前進程是否處于NOT_RESPONDING狀態(tài)以及主線程是否卡頓來進行甄別峭范,以免誤判财松。這種方案才是真正的監(jiān)控ANR,matrix纱控、xCrash都在使用這種方案辆毡。已經在微信等app上檢驗過,穩(wěn)定性和可靠性都能得到保證甜害。
1.監(jiān)聽SIGQUIT信號舶掖。
系統(tǒng)監(jiān)控到app發(fā)生ANR后,收集了一些相關進程pid尔店,并向這些進程發(fā)送SIGQUIT信號眨攘,進程收到SIGQUIT信號之后開始dump堆棧,通過對這個信號的監(jiān)聽嚣州,實現(xiàn)anr的監(jiān)聽鲫售,實現(xiàn)方式見matrix框架(https://github.com/Tencent/matrix/tree/master/matrix/matrix-android/matrix-trace-canary/src/main)。
2.監(jiān)聽NOT_RESPONDING標記该肴。
發(fā)生ANR的進程一定會收到SIGQUIT信號情竹;但是收到SIGQUIT信號的進程并不一定發(fā)生了ANR。為了解決這個問題沙庐,回到源碼中鲤妥,我們會發(fā)現(xiàn)執(zhí)行makeAppNotRespondingLocked方法時,會給發(fā)生ANR的進程標記一個NOT_RESPONDING的flag拱雏,這個flag可以通過ActivityManager來獲让薨病:
private static boolean checkErrorState() {
try {
Application application = sApplication == null ? Matrix.with().getApplication() : sApplication;
ActivityManager am = (ActivityManager) application.getSystemService(Context.ACTIVITY_SERVICE);
List<ActivityManager.ProcessErrorStateInfo> procs = am.getProcessesInErrorState();
if (procs == null) return false;
for (ActivityManager.ProcessErrorStateInfo proc : procs) {
if (proc.pid != android.os.Process.myPid()) continue;
if (proc.condition != ActivityManager.ProcessErrorStateInfo.NOT_RESPONDING) continue;
return true;
}
return false;
} catch (Throwable t){
MatrixLog.e(TAG,"[checkErrorState] error : %s", t.getMessage());
}
return false;
}
監(jiān)控到SIGQUIT后,我們在20秒內(20秒是ANR dump的timeout時間)不斷輪詢自己是否有NOT_RESPONDING的flag铸抑,一旦發(fā)現(xiàn)有這個flag贡耽,那么馬上就可以認定發(fā)生了一次ANR。
3.結合線程是否處于卡頓狀態(tài)判斷
發(fā)生ANR的進程并不一定會被設置為NOT_RESPONDING狀態(tài),如后臺ANR會直接被殺死蒲赂,另外有些機型修改了anr的邏輯阱冶,發(fā)生anr后直接殺死了進程,所以需要一種機制滥嘴,在收到SIGQUIT信號后木蹬,需要非常快速的偵查出自己是否已經處于ANR的狀態(tài)若皱,進行快速的dump和上報镊叁,可以通過主線程釋放處于卡頓狀態(tài)來判斷,可以通過Looper的mMessage對象走触,該對象的when變量晦譬,表示的是當前正在處理的消息入隊的時間,我們可以通過when變量減去當前時間互广,得到的就是等待時間敛腌,如果等待時間過長,就說明主線程是處于卡住的狀態(tài)惫皱。這時候收到SIGQUIT信號基本上就可以認為的確發(fā)生了一次ANR像樊。
ANR Trace.txt文件獲取
低版本可以直接拿到,但是高版本無法拿到逸吵,怎么解決這個問題凶硅?從上邊的分析我們知道,除了Zygote進程之外扫皱,每個進程都有一個SignalCatcher線程來監(jiān)聽SIGQUIT信號足绅,后邊通過socket將dump的內容寫入(write)文件中,可以直接hook這里的write韩脑,就能直接拿到系統(tǒng)dump的ANR Trace內容氢妈。
Trace.txt文件分析
"Signal Catcher" daemon prio=5 tid=4 Runnable
| group="system" sCount=0 dsCount=0 flags=0 obj=0x18c84570 self=0x7252417800
| sysTid=7772 nice=0 cgrp=default sched=0/0 handle=0x725354ad50
| state=R schedstat=( 16273959 1085938 5 ) utm=0 stm=1 core=4 HZ=100
| stack=0x7253454000-0x7253456000 stackSize=991KB
| held mutexes= "mutator lock"(shared held)
-"Signal Catcher" daemon :線程名,有daemon表示守護線程
-prio:線程優(yōu)先級
-tid:線程內部id
-線程狀態(tài):Runnable
-group:線程所屬的線程組
-sCount:線程掛起次數(shù)
-dsCount:用于調試的線程掛起次數(shù)
-obj:當前線程關聯(lián)的Java線程對象
-self:當前線程地址
-sysTid:線程真正意義上的tid
-nice:調度優(yōu)先級段多,值越小則優(yōu)先級越高
-cgrp:進程所屬的進程調度組
-sched:調度策略
-handle:函數(shù)處理地址
-state:線程狀態(tài)
-schedstat:CPU調度時間統(tǒng)計(schedstat括號中的3個數(shù)字依次是Running首量、Runable、Switch进苍,Running時間:CPU運行的時間加缘,單位ns,Runable時間:RQ隊列的等待時間觉啊,單位ns拣宏,Switch次數(shù):CPU調度切換次數(shù))
-utm/stm:用戶態(tài)/內核態(tài)的CPU時間
-core:該線程的最后運行所在核
-HZ:時鐘頻率
-stack:線程棧的地址區(qū)間
-stackSize:棧的大小
-mutex:所持有mutex類型,有獨占鎖exclusive和共享鎖shared兩類
ANR案例分析
1.主線程無卡頓杠人,處于正常狀態(tài)堆棧
"main" prio=5 tid=1 Native
| group="main" sCount=1 dsCount=0 flags=1 obj=0x74b38080 self=0x7ad9014c00
| sysTid=23081 nice=0 cgrp=default sched=0/0 handle=0x7b5fdc5548
| state=S schedstat=( 284838633 166738594 505 ) utm=21 stm=7 core=1 HZ=100
| stack=0x7fc95da000-0x7fc95dc000 stackSize=8MB
| held mutexes=
kernel: __switch_to+0xb0/0xbc
kernel: SyS_epoll_wait+0x288/0x364
kernel: SyS_epoll_pwait+0xb0/0x124
kernel: cpu_switch_to+0x38c/0x2258
native: #00 pc 000000000007cd8c /system/lib64/libc.so (__epoll_pwait+8)
native: #01 pc 0000000000014d48 /system/lib64/libutils.so (android::Looper::pollInner(int)+148)
native: #02 pc 0000000000014c18 /system/lib64/libutils.so (android::Looper::pollOnce(int, int*, int*, void**)+60)
native: #03 pc 00000000001275f4 /system/lib64/libandroid_runtime.so (android::android_os_MessageQueue_nativePollOnce(_JNIEnv*, _jobject*, long, int)+44)
at android.os.MessageQueue.nativePollOnce(Native method)
at android.os.MessageQueue.next(MessageQueue.java:330)
at android.os.Looper.loop(Looper.java:169)
at android.app.ActivityThread.main(ActivityThread.java:7073)
at java.lang.reflect.Method.invoke(Native method)
at com.android.internal.os.RuntimeInit$MethodAndArgsCaller.run(RuntimeInit.java:536)
at com.android.internal.os.ZygoteInit.main(ZygoteInit.java:876)
看起來很正常瞬矩,主線程是空閑的,因為它正處于nativePollOnce造挽,正在等待新消息。處于這個狀態(tài)学歧,那還發(fā)生了ANR,可能有2個原因:
1.dump堆棧時機太晚了各吨,ANR已經發(fā)生過了枝笨,才去dump堆棧,此時主線程已經恢復正常了绅你。
2.CPU搶占或者內存緊張等其他因素引起伺帘。
2.主線程執(zhí)行耗時操作
//模擬主線程耗時操作,View點擊的時候調用這個函數(shù)
fun makeAnr(view: View) {
var s = 0L
for (i in 0..99999999999) {
s += i
}
Log.d("xxx", "s=$s")
}
suspend all histogram: Sum: 206us 99% C.I. 0.098us-46us Avg: 7.629us Max: 46us
DALVIK THREADS (16):
"main" prio=5 tid=1 Runnable
| group="main" sCount=0 dsCount=0 flags=0 obj=0x73907540 self=0x725f010800
| sysTid=32298 nice=-10 cgrp=default sched=1073741825/2 handle=0x72e60080d0
| state=R schedstat=( 6746757297 5887495 256 ) utm=670 stm=4 core=6 HZ=100
| stack=0x7fca180000-0x7fca182000 stackSize=8192KB
| held mutexes= "mutator lock"(shared held)
at com.xfhy.watchsignaldemo.MainActivity.makeAnr(MainActivity.kt:58)
at java.lang.reflect.Method.invoke(Native method)
at androidx.appcompat.app.AppCompatViewInflater$DeclaredOnClickListener.onClick(AppCompatViewInflater.java:441)
at android.view.View.performClick(View.java:7317)
at com.google.android.material.button.MaterialButton.performClick(MaterialButton.java:1219)
at android.view.View.performClickInternal(View.java:7291)
at android.view.View.access$3600(View.java:838)
at android.view.View$PerformClick.run(View.java:28247)
at android.os.Handler.handleCallback(Handler.java:900)
at android.os.Handler.dispatchMessage(Handler.java:103)
at android.os.Looper.loop(Looper.java:219)
at android.app.ActivityThread.main(ActivityThread.java:8668)
at java.lang.reflect.Method.invoke(Native method)
at com.android.internal.os.RuntimeInit$MethodAndArgsCaller.run(RuntimeInit.java:513)
at com.android.internal.os.ZygoteInit.main(ZygoteInit.java:1109)
從日志上看昭躺,主線程處于執(zhí)行狀態(tài)忌锯,不是空閑狀態(tài),導致ANR了领炫,說明com.xfhy.watchsignaldemo.MainActivity.makeAnr這里有耗時操作偶垮。
3.主線程被鎖阻塞
fun makeAnr(view: View) {
val obj1 = Any()
val obj2 = Any()
//搞個死鎖,相互等待
thread(name = "臥槽") {
synchronized(obj1) {
SystemClock.sleep(100)
synchronized(obj2) {
}
}
}
synchronized(obj2) {
SystemClock.sleep(100)
synchronized(obj1) {
}
}
}
"main" prio=5 tid=1 Blocked
| group="main" sCount=1 dsCount=0 flags=1 obj=0x73907540 self=0x725f010800
| sysTid=19900 nice=-10 cgrp=default sched=0/0 handle=0x72e60080d0
| state=S schedstat=( 542745832 9516666 182 ) utm=48 stm=5 core=4 HZ=100
| stack=0x7fca180000-0x7fca182000 stackSize=8192KB
| held mutexes=
at com.xfhy.watchsignaldemo.MainActivity.makeAnr(MainActivity.kt:59)
- waiting to lock <0x0c6f8c52> (a java.lang.Object) held by thread 22 //注釋1
- locked <0x01abeb23> (a java.lang.Object)
at java.lang.reflect.Method.invoke(Native method)
at androidx.appcompat.app.AppCompatViewInflater$DeclaredOnClickListener.onClick(AppCompatViewInflater.java:441)
at android.view.View.performClick(View.java:7317)
at com.google.android.material.button.MaterialButton.performClick(MaterialButton.java:1219)
at android.view.View.performClickInternal(View.java:7291)
at android.view.View.access$3600(View.java:838)
at android.view.View$PerformClick.run(View.java:28247)
at android.os.Handler.handleCallback(Handler.java:900)
at android.os.Handler.dispatchMessage(Handler.java:103)
at android.os.Looper.loop(Looper.java:219)
at android.app.ActivityThread.main(ActivityThread.java:8668)
at java.lang.reflect.Method.invoke(Native method)
at com.android.internal.os.RuntimeInit$MethodAndArgsCaller.run(RuntimeInit.java:513)
at com.android.internal.os.ZygoteInit.main(ZygoteInit.java:1109)
"臥槽" prio=5 tid=22 Blocked //注釋2
| group="main" sCount=1 dsCount=0 flags=1 obj=0x12c8a118 self=0x71d625f800
| sysTid=20611 nice=0 cgrp=default sched=0/0 handle=0x71d4513d50
| state=S schedstat=( 486459 0 3 ) utm=0 stm=0 core=4 HZ=100
| stack=0x71d4411000-0x71d4413000 stackSize=1039KB
| held mutexes=
at com.xfhy.watchsignaldemo.MainActivity$makeAnr$1.invoke(MainActivity.kt:52)
- waiting to lock <0x01abeb23> (a java.lang.Object) held by thread 1
- locked <0x0c6f8c52> (a java.lang.Object)
at com.xfhy.watchsignaldemo.MainActivity$makeAnr$1.invoke(MainActivity.kt:49)
at kotlin.concurrent.ThreadsKt$thread$thread$1.run(Thread.kt:30)
......
注意看帝洪,下面幾行:
"main" prio=5 tid=1 Blocked
- waiting to lock <0x0c6f8c52> (a java.lang.Object) held by thread 22
- locked <0x01abeb23> (a java.lang.Object)
"臥槽" prio=5 tid=22 Blocked
- waiting to lock <0x01abeb23> (a java.lang.Object) held by thread 1
- locked <0x0c6f8c52> (a java.lang.Object)
主線程的tid是1似舵,線程狀態(tài)是Blocked,正在等待0x0c6f8c52這個Object葱峡,而這個Object被thread 22這個線程所持有砚哗,主線程當前持有的是0x01abeb23的鎖。而臥槽的tid是22砰奕,也是Blocked狀態(tài)蛛芥,它想請求的和已有的鎖剛好與主線程相反。這樣的話军援,ANR原因也就找到了:線程22持有了一把鎖仅淑,并且一直不釋放,主線程等待這把鎖發(fā)生超時胸哥。在線上環(huán)境涯竟,常見因鎖而ANR的場景是SharePreference寫入。
4. CPU被搶占
CPU usage from 0ms to 10625ms later (2020-03-09 14:38:31.633 to 2020-03-09 14:38:42.257):
543% 2045/com.test.demo: 54% user + 89% kernel / faults: 4608 minor 1 major //注意看這里
99% 674/android.hardware.camera.provider@2.4-service: 81% user + 18% kernel / faults: 403 minor
24% 32589/com.wang.test: 22% user + 1.4% kernel / faults: 7432 minor 1 major
......
可以看到空厌,該進程占據(jù)CPU高達543%庐船,搶占了大部分CPU資源,因為導致發(fā)生ANR嘲更,這種ANR與我們的app無關筐钟。
5.內存緊張導致ANR
如果一份ANR日志的CPU和堆棧都很正常,可以考慮是內存緊張哮内〉量茫看一下ANR日志里面的內存相關部分壮韭。還可以去日志里面搜一下onTrimMemory,如果dump ANR日志的時間附近有相關日志纹因,可能是內存比較緊張了喷屋。
10-31 22:37:19.749 20733 20733 E Runtime : onTrimMemory level:80,pid:com.xxx.xxx:Launcher0
10-31 22:37:33.458 20733 20733 E Runtime : onTrimMemory level:80,pid:com.xxx.xxx:Launcher0
10-31 22:38:00.153 20733 20733 E Runtime : onTrimMemory level:80,pid:com.xxx.xxx:Launcher0
10-31 22:38:58.731 20733 20733 E Runtime : onTrimMemory level:80,pid:com.xxx.xxx:Launcher0
10-31 22:39:02.816 20733 20733 E Runtime : onTrimMemory level:80,pid:com.xxx.xxx:Launcher0
6.系統(tǒng)服務超時導致ANR
系統(tǒng)服務超時一般會包含BinderProxy.transactNative關鍵字,來看一段日志:
"main" prio=5 tid=1 Native
| group="main" sCount=1 dsCount=0 flags=1 obj=0x727851e8 self=0x78d7060e00
| sysTid=4894 nice=0 cgrp=default sched=0/0 handle=0x795cc1e9a8
| state=S schedstat=( 8292806752 1621087524 7167 ) utm=707 stm=122 core=5 HZ=100
| stack=0x7febb64000-0x7febb66000 stackSize=8MB
| held mutexes=
kernel: __switch_to+0x90/0xc4
kernel: binder_thread_read+0xbd8/0x144c
kernel: binder_ioctl_write_read.constprop.58+0x20c/0x348
kernel: binder_ioctl+0x5d4/0x88c
kernel: do_vfs_ioctl+0xb8/0xb1c
kernel: SyS_ioctl+0x84/0x98
kernel: cpu_switch_to+0x34c/0x22c0
native: #00 pc 000000000007a2ac /system/lib64/libc.so (__ioctl+4)
native: #01 pc 00000000000276ec /system/lib64/libc.so (ioctl+132)
native: #02 pc 00000000000557d4 /system/lib64/libbinder.so (android::IPCThreadState::talkWithDriver(bool)+252)
native: #03 pc 0000000000056494 /system/lib64/libbinder.so (android::IPCThreadState::waitForResponse(android::Parcel*, int*)+60)
native: #04 pc 00000000000562d0 /system/lib64/libbinder.so (android::IPCThreadState::transact(int, unsigned int, android::Parcel const&, android::Parcel*, unsigned int)+216)
native: #05 pc 000000000004ce1c /system/lib64/libbinder.so (android::BpBinder::transact(unsigned int, android::Parcel const&, android::Parcel*, unsigned int)+72)
native: #06 pc 00000000001281c8 /system/lib64/libandroid_runtime.so (???)
native: #07 pc 0000000000947ed4 /system/framework/arm64/boot-framework.oat (Java_android_os_BinderProxy_transactNative__ILandroid_os_Parcel_2Landroid_os_Parcel_2I+196)
at android.os.BinderProxy.transactNative(Native method) ————————————————關鍵行2t恰。屯曹。? at android.os.BinderProxy.transact(Binder.java:804)
at android.net.IConnectivityManager$Stub$Proxy.getActiveNetworkInfo(IConnectivityManager.java:1204)—關鍵行惊畏!
at android.net.ConnectivityManager.getActiveNetworkInfo(ConnectivityManager.java:800)
at com.xiaomi.NetworkUtils.getNetworkInfo(NetworkUtils.java:2)
at com.xiaomi.frameworkbase.utils.NetworkUtils.getNetWorkType(NetworkUtils.java:1)
at com.xiaomi.frameworkbase.utils.NetworkUtils.isWifiConnected(NetworkUtils.java:1)
從日志堆棧中可以看到是獲取網(wǎng)絡信息發(fā)生了ANR:getActiveNetworkInfo恶耽。系統(tǒng)的服務都是Binder機制(16個線程),服務能力也是有限的颜启,有可能系統(tǒng)服務長時間不響應導致ANR偷俭。如果其他應用占用了所有Binder線程,那么當前應用只能等待缰盏∮坑可進一步搜索:blockUntilThreadAvailable關鍵字:
at android.os.Binder.blockUntilThreadAvailable(Native method)
如果有發(fā)現(xiàn)某個線程的堆棧,包含此字樣口猜,可進一步看其堆棧负溪,確定是調用了什么系統(tǒng)服務。此類ANR也是屬于系統(tǒng)環(huán)境的問題济炎,如果某類型手機上頻繁發(fā)生此問題川抡,應用層可以考慮規(guī)避策略。
還有不足
當前Trace堆棧所在業(yè)務耗時嚴重须尚。
當前Trace堆棧所在業(yè)務耗時并不嚴重崖堤,但歷史調度有一個嚴重耗時。
當前Trace堆棧所在業(yè)務耗時并不嚴重恨闪,但歷史調度有多個消息耗時倘感。
當前Trace堆棧所在業(yè)務耗時并不嚴重,但是歷史調度存在巨量重復消息(業(yè)務頻繁發(fā)送消息)咙咽。
當前Trace堆棧業(yè)務邏輯并不耗時老玛,但是其他線程存在嚴重資源搶占,如IO钧敞、Mem蜡豹、CPU。
當前Trace堆棧業(yè)務邏輯并不耗時溉苛,但是其他進程存在嚴重資源搶占镜廉,如IO、Mem愚战、CPU娇唯。
這里的6個影響因素中齐遵,除了第一個以外,其他的根據(jù)ANR Trace有可能無法進行判別塔插。這就會導致很多時候看到的ANR Trace里面主線程堆棧對應的業(yè)務其實并不耗時(因為可能是前面的消息導致的耗時梗摇,但它已經執(zhí)行完了),如何解決這個問題想许?
字節(jié)跳動內部有一個監(jiān)控工具:Raster伶授,大致原理:該工具主要是在主線程消息調度過程進行監(jiān)控。比較耗時的消息會抓取主線從堆棧流纹,這樣可以知道那個耗時的消息具體是在干什么糜烹,從而針對性優(yōu)化。同時對應用四大組件消息執(zhí)行過程進行監(jiān)控漱凝,便于對這類消息的調度及耗時情況進行跟蹤和記錄疮蹦。另外對當前正在調度的消息及消息隊列中待調度消息進行統(tǒng)計,從而在發(fā)生問題時碉哑,可以回放主線程的整體調度情況挚币。此外,該庫將系統(tǒng)服務的CheckTime機制遷移到應用側扣典,應用為線程CheckTime機制,以便于系統(tǒng)信息不足時慎玖,從線程調度及時性推測過去一段時間系統(tǒng)負載和調度情況贮尖。因此該工具用一句話來概括就是:由點到面,回放過去趁怔,現(xiàn)在和將來湿硝。