ANR
Application Not Responding
ANR类型
Service Timeout:比如前台服务在20s内未执行完成,后台服务Timeout时间是前台服务的10倍,200s;
BroadcastQueue Timeout:比如前台广播在10s内未执行完成,后台60s
ContentProvider Timeout:内容提供者,在publish过超时10s;
InputDispatching Timeout: 输入事件分发超时5s,包括按键和触摸事件。
对于input来说即便某次事件执行时间超过Timeout时长,只要用户后续没有再生成输入事件,则不会触发ANR
ANR文件获取方式
1.低于Android10系统的手机
adb pull data/anr
2.大于等于Android10系统的手机
如果在Android10以上系统,使用adb pull的方式拉取trace文件,会得到permission denied。需要使用新的命令完成
adb bugreport
导致ANR的原因
应用层导致ANR:
1.函数阻塞:如死循环、主线程IO、处理大数据。
2.锁出错:主线程等待子线程的锁。
3.内存紧张:系统分配给一个应用的内存是有上限的,长期处于内存紧张,会导致频繁内存交换,进而导致应用的一些操作超时。
系统导致ANR:
1.CPU被抢占:一般来说,前台在玩游戏,可能会导致你的后台广播被抢占。
2.系统服务无法及时响应:系统的服务都是Binder机制,服务能力也是有限的,有可能系统服务长时间不响应导致ANR。
3.其他应用占用大量内存。
系统ANR检测机制
ANR由消息处理机制保证,核心原理是消息调度和超时处理。
虽然系统触发anr的地方有好几种,但是检测机制和处理机制其实是差不多的,都是在操作前记录时间,然后向消息队列中丢向一个触发Anr的消息(基于消息机制),再执行完响应的操作的时候将消息移除,如果超过指定时间没有移除,那么则会触发anr操作。
ps
发生anr的时候是主线程已经被阻塞了,anr也是基于消息机制,是一个延时消息,那为什么它还能被执行呢?
发生anr时,被阻塞的是app进程的主线程,而anr延时消息并不是在app进程中处理的。它是通过AMS所在进程中的子线程消息队列中执行的(ams内部除了有主线程的消息队列外,还持有了一个异步的消息队列),所以时间到了之后还是可以被looper取出; 然后将显示anr弹窗的消息发送到AMS主线程的消息队列(mUiHandler),去展示弹窗。
service
: 当Service的生命周期开始时,bumpServiceExecutingLocked()会被调用,紧接着会调用scheduleServiceTimeoutLocked(),向消息队列发送一个延迟消息(20s(后台服务200s)),当Service的生命周期结束时,在serviceDoneExecutingLocked方法中移除这个消息,如果时间到了还没有移除,就提示anr。由AMS调度,利用Handler和Looper,设计了一个TIMEOUT消息交由AMS线程来处理,整个超时机制的实现都是在Java层。
broadcast
:Broadcast ANR,前台的“串行广播消息”必须在10秒内处理完毕,后台的“串行广播消息”必须在60秒处理完毕, 每派发串行广播消息到一个接收器时,都会抛出一个定时消息BROADCAST_TIMEOUT_MSG,如果定时消息响应,则判断是否广播消息处理超时,超时就说明发生了ANR。由AMS调度,利用Handler和Looper,设计了一个TIMEOUT消息交由AMS线程来处理,整个超时机制的实现都是在Java层。
input
: 在InputDispatcher派发输入事件时,会寻找接收事件的窗口,如果无法正常派发,则可能会导致当前需要派发的事件超时(默认是5秒)。 Native层发现超时了,会通知Java层,Java层经过一些处理后,会反馈给Native层,是继续等待还是丢弃当前派发的事件。 InputEvent由InputDispatcher调度,待处理的输入事件都会进入队列中等待,设计了一个等待超时的判断,超时机制的实现在Native层。
service、broadcast、provider 的ANR原理都是埋定时炸弹和拆炸弹原理,
但是input的超时检测机制稍微有点不同,需要等收到下一次input事件,才会去检测上一次input事件是否超时,input事件里埋的炸弹是普通炸弹,需要通过扫雷来排查。
SNR(System Not Respoding)
SNR由Watchdog机制保证。Watchdog定时(30s)检查一些重要的系统服务,举报长时间阻塞的事件,甚至杀掉system_server进程,让Android系统重启。
Monitor Checker(addMonitor),用于检查是Monitor对象可能发生的死锁, AMS, PKMS, WMS等核心的系统服务都是Monitor对象。
Looper Checker(addThread),用于检查线程的消息队列是否长时间处于工作状态。一些重要的线程的消息队列,也会加入到Looper Checker中,譬如AMS, PKMS,这些是在对应的对象初始化时加入的。
Monitor Checker预警我们不能长时间持有核心系统服务的对象锁,否则会阻塞很多函数的运行; Looper Checker预警我们不能长时间的霸占消息队列,否则其他消息将得不到处理。这两类都会导致系统卡住(System Not Responding)。
ANR主要流程
所有ANR,最终都会调用AppErrors的appNotResponding方法
1.系统监控到app发生ANR后,收集了一些相关进程pid(包括发生ANR的进程),准备让这些进程dump堆栈,从而生成ANR Trace文件。
2.系统开始向这些进程发送SIGQUIT信号(通过监听这个信号可以实现对anr的监控,如matrix的实现
),进程收到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堆栈那个进程发送了一个SIGQUIT信号
2.除Zygote进程外,每个进程都会创建一个SignalCatcher守护线程,用于捕获SIGQUIT,然后开始dump
3.这个过程从收到SIGQUIT信号开始到使用socket写Trace结束。
ANR监控
一. WatchDog
ANRWatchDog 是一个自动检测ANR的开源库,往主线程发送消息,并设置超时检测,如果超时还没执行相应消息,则判定为可能发生ANR。需要进一步从系统服务获取相关数据(可通过ActivityManagerService.getProcessesInErrorState()方法获取进程的ANR信息),进一步判定是否真的发生了ANR。
缺点
1.存在5s的误差,假设当ANRWatchDog post消息的时候,已经卡了2s,然后再过3s卡完了恢复了,那么ANRWatchDog是监测不到的。
2.和BlockCanary一样不支持touch事件的监测
优化ANRWatchDog存在5s的误差的缺点(AnrMonitor)
。每隔1s就会检查一下,并提示可能的风险,累计5s就触发ANR流程,这是一个实现思路,代码只提供了一个demo,还需要完善。此方案可以结合ProcessLifecycleOwner,应用在前台才开启检测,进入后台则停止检测。
二. SIGQUIT信号
该方案通过去监听SIGQUIT信号,从而感知当前进程可能发生了ANR,需配合当前进程是否处于NOT_RESPONDING状态以及主线程是否卡顿来进行甄别,以免误判。这种方案才是真正的监控ANR,matrix、xCrash都在使用这种方案。已经在微信等app上检验过,稳定性和可靠性都能得到保证。
1.监听SIGQUIT信号。
系统监控到app发生ANR后,收集了一些相关进程pid,并向这些进程发送SIGQUIT信号,进程收到SIGQUIT信号之后开始dump堆栈,通过对这个信号的监听,实现anr的监听,实现方式见matrix框架(https://github.com/Tencent/matrix/tree/master/matrix/matrix-android/matrix-trace-canary/src/main)。
2.监听NOT_RESPONDING标记。
发生ANR的进程一定会收到SIGQUIT信号;但是收到SIGQUIT信号的进程并不一定发生了ANR。为了解决这个问题,回到源码中,我们会发现执行makeAppNotRespondingLocked方法时,会给发生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;
}
监控到SIGQUIT后,我们在20秒内(20秒是ANR dump的timeout时间)不断轮询自己是否有NOT_RESPONDING的flag,一旦发现有这个flag,那么马上就可以认定发生了一次ANR。
3.结合线程是否处于卡顿状态判断
发生ANR的进程并不一定会被设置为NOT_RESPONDING状态,如后台ANR会直接被杀死,另外有些机型修改了anr的逻辑,发生anr后直接杀死了进程,所以需要一种机制,在收到SIGQUIT信号后,需要非常快速的侦查出自己是否已经处于ANR的状态,进行快速的dump和上报,可以通过主线程释放处于卡顿状态来判断,可以通过Looper的mMessage对象,该对象的when变量,表示的是当前正在处理的消息入队的时间,我们可以通过when变量减去当前时间,得到的就是等待时间,如果等待时间过长,就说明主线程是处于卡住的状态。这时候收到SIGQUIT信号基本上就可以认为的确发生了一次ANR。
ANR Trace.txt文件获取
低版本可以直接拿到,但是高版本无法拿到,怎么解决这个问题?从上边的分析我们知道,除了Zygote进程之外,每个进程都有一个SignalCatcher线程来监听SIGQUIT信号,后边通过socket将dump的内容写入(write)文件中,可以直接hook这里的write,就能直接拿到系统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:线程优先级
-tid:线程内部id
-线程状态:Runnable
-group:线程所属的线程组
-sCount:线程挂起次数
-dsCount:用于调试的线程挂起次数
-obj:当前线程关联的Java线程对象
-self:当前线程地址
-sysTid:线程真正意义上的tid
-nice:调度优先级,值越小则优先级越高
-cgrp:进程所属的进程调度组
-sched:调度策略
-handle:函数处理地址
-state:线程状态
-schedstat:CPU调度时间统计(schedstat括号中的3个数字依次是Running、Runable、Switch,Running时间:CPU运行的时间,单位ns,Runable时间:RQ队列的等待时间,单位ns,Switch次数:CPU调度切换次数)
-utm/stm:用户态/内核态的CPU时间
-core:该线程的最后运行所在核
-HZ:时钟频率
-stack:线程栈的地址区间
-stackSize:栈的大小
-mutex:所持有mutex类型,有独占锁exclusive和共享锁shared两类
ANR案例分析
1.主线程无卡顿,处于正常状态堆栈
"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,正在等待新消息。处于这个状态,那还发生了ANR,可能有2个原因:
1.dump堆栈时机太晚了,ANR已经发生过了,才去dump堆栈,此时主线程已经恢复正常了。
2.CPU抢占或者内存紧张等其他因素引起。
2.主线程执行耗时操作
//模拟主线程耗时操作,View点击的时候调用这个函数
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)
从日志上看,主线程处于执行状态,不是空闲状态,导致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,线程状态是Blocked,正在等待0x0c6f8c52这个Object,而这个Object被thread 22这个线程所持有,主线程当前持有的是0x01abeb23的锁。而卧槽的tid是22,也是Blocked状态,它想请求的和已有的锁刚好与主线程相反。这样的话,ANR原因也就找到了:线程22持有了一把锁,并且一直不释放,主线程等待这把锁发生超时。在线上环境,常见因锁而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
......
可以看到,该进程占据CPU高达543%,抢占了大部分CPU资源,因为导致发生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.系统服务超时导致ANR
系统服务超时一般会包含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) ————————————————关键行!!!
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)
从日志堆栈中可以看到是获取网络信息发生了ANR:getActiveNetworkInfo。系统的服务都是Binder机制(16个线程),服务能力也是有限的,有可能系统服务长时间不响应导致ANR。如果其他应用占用了所有Binder线程,那么当前应用只能等待。可进一步搜索:blockUntilThreadAvailable关键字:
at android.os.Binder.blockUntilThreadAvailable(Native method)
如果有发现某个线程的堆栈,包含此字样,可进一步看其堆栈,确定是调用了什么系统服务。此类ANR也是属于系统环境的问题,如果某类型手机上频繁发生此问题,应用层可以考虑规避策略。
还有不足
当前Trace堆栈所在业务耗时严重。
当前Trace堆栈所在业务耗时并不严重,但历史调度有一个严重耗时。
当前Trace堆栈所在业务耗时并不严重,但历史调度有多个消息耗时。
当前Trace堆栈所在业务耗时并不严重,但是历史调度存在巨量重复消息(业务频繁发送消息)。
当前Trace堆栈业务逻辑并不耗时,但是其他线程存在严重资源抢占,如IO、Mem、CPU。
当前Trace堆栈业务逻辑并不耗时,但是其他进程存在严重资源抢占,如IO、Mem、CPU。
这里的6个影响因素中,除了第一个以外,其他的根据ANR Trace有可能无法进行判别。这就会导致很多时候看到的ANR Trace里面主线程堆栈对应的业务其实并不耗时(因为可能是前面的消息导致的耗时,但它已经执行完了),如何解决这个问题?
字节跳动内部有一个监控工具:Raster,大致原理:该工具主要是在主线程消息调度过程进行监控。比较耗时的消息会抓取主线从堆栈,这样可以知道那个耗时的消息具体是在干什么,从而针对性优化。同时对应用四大组件消息执行过程进行监控,便于对这类消息的调度及耗时情况进行跟踪和记录。另外对当前正在调度的消息及消息队列中待调度消息进行统计,从而在发生问题时,可以回放主线程的整体调度情况。此外,该库将系统服务的CheckTime机制迁移到应用侧,应用为线程CheckTime机制,以便于系统信息不足时,从线程调度及时性推测过去一段时间系统负载和调度情况。因此该工具用一句话来概括就是:由点到面,回放过去,现在和将来。