导致ANR的几种情况
- KeyDispatchTimeout(5s): 按键或触摸事件在特定时间内无法处理完成
- BroadcastTimeout(前台10s,后台60s): 广播在特定时间内无法处理完成
- ServiceTimeout(前台20s,后台200s): Service在特定的时间无法处理完成 另外还有ProviderTimeout和WatchDog等导致的ANR
常见的原因
A.耗时操作，如复杂的layout，庞大的for循环，IO等。 B.被Binder 对端block C.被子线程同步锁block D.Binder被占满导致主线程无法和SystemServer通信 E.得不到系统资源（CPU/RAM/IO） 其中ABCD比较好分析，而E比较困难。
应用ANR产生的时候,ActivityManagerService的appNotResponding方法就会被调用,然后在/data/anr/traces.txt文件中写入ANR相关信息.
ANR就不作介绍了，下面只介绍如何分析ANR异常.
通常发生了ANR，ActivityManager会打印报错信息：
E/ActivityManager: ANR in com.rui.android.poc // ANR出现的进程包名 PID: 1322 // ANR进程ID Reason: Broadcast of Intent { act=android.intent.action.SCREEN_ON flg=0x50000010 }//导致ANR的原因 Load: 4.13 / 2.52 / 1.05 CPU usage from 0ms to 12843ms later://CPU在ANR发生后的使用情况 98% 1322/com.rui.android.poc: 0.5% user + 98% kernel / faults: 1044 minor 104 major 5.6% 567/system_server: 3.4% user + 2.1% kernel / faults: 1940 minor 217 major 2.3% 766/com.android.systemui: 1.2% user + 1% kernel / faults: 251 minor 165 major 1.4% 268/kworker/0:2: 0% user + 1.4% kernel 1.2% 1690/adbd: 0.1% user + 1% kernel / faults: 2 minor 3 major 1% 756/com.android.phone: 0.6% user + 0.3% kernel / faults: 347 minor 61 major 0.9% 139/surfaceflinger: 0.3% user + 0.5% kernel / faults: 1 minor 5 major 0.2% 929/com.sprd.opm: 0.2% user + 0% kernel / faults: 279 minor 115 major 0.2% 23/kworker/u4:1: 0% user + 0.2% kernel 0.2% 368/kworker/u5:1: 0% user + 0.2% kernel 0.1% 914/com.android.modemassert: 0% user + 0% kernel / faults: 182 minor 66 major 0.1% 44/ksmd: 0% user + 0.1% kernel 0% 909/com.spreadst.validator: 0% user + 0% kernel / faults: 164 minor 39 major 0% 8/rcu_preempt: 0% user + 0% kernel 0% 43/kswapd0: 0% user + 0% kernel 0% 117/mmcqd/0: 0% user + 0% kernel +0% 1770/kworker/0:3: 0% user + 0% kernel +0% 1774/debuggerd: 0% user + 0% kernel 97% TOTAL: 3.7% user + 55% kernel + 38% iowait // CUP占用情况 CPU usage from 12301ms to 12824ms later: 100% 1322/com.rui.android.poc: 0% user + 100% kernel 100% 1322/rui.android.poc: 0% user + 100% kernel 1.9% 1333/Binder_2: 0% user + 1.9% kernel 3.8% 567/system_server: 1.9% user + 1.9% kernel 3.8% 581/ActivityManager: 1.9% user + 1.9% kernel 1.3% 139/surfaceflinger: 1.3% user + 0% kernel 1.3% 249/DispSync: 0% user + 1.3% kernel 1.5% 766/com.android.systemui: 1.5% user + 0% kernel / faults: 2 minor 1.5% 766/ndroid.systemui: 0% user + 1.5% kernel 1.6% 1770/kworker/0:3: 0% user + 1.6% kernel 100% TOTAL: 0% user + 54% kernel + 45% iowait
Log分析：
log打印了ANR的基本信息,我们可以分析CPU使用率得知ANR的简单情况;如果CPU使用率很高,接近100%,可能是在进行大规模的计算更可能是陷入死循环;如果CUP使用率很低,说明主线程被阻塞了,并且当IOwait很高,可能是主线程在等待I/O操作的完成.
对于ANR只是分析Log很难知道问题所在,我们还需要通过Trace文件分析stack调用情况.
traces.txt是如何生成的
当APP(包括系统APP和用户APP)进程出现ANR、应用响应慢或WatchDog的监视没有得到回馈时,系统会dump此时的top进程,进程中Thread的运行状态就都dump到这个Trace文件中了.每次发生ANR， 这个文件都会被清空，写入新的内容. 如果想查看以前发生ANR的信息， 可以去查看DB文件.
DropBox中的log
traces.txt只保留最后一次发生ANR时的信息, android 2.2开始增加了DropBox功能, 保留历史上发生的所有ANR的log.
“/data/system/dropbox”是DB指定的文件存放位置.
日志保存的最长时间， 默认是3天.
shell@sp9820a_Rui8503:/data # cd system/dropbox/ shell@sp9820a_Rui8503:/data/system/dropbox # ls SYSTEM_BOOT@1325376052965.txt system_app_crash@1325376052598.txt system_app_crash@1325376054905.txt system_app_strictmode@1325376048453.txt.gz system_app_strictmode@1325376053442.txt.gz system_app_strictmode@1325376058904.txt.gz system_server_wtf@1325376043066.txt system_server_wtf@1325376052708.txt system_server_wtf@1325376052842.txt shell@sp9820a_Rui8503:/data/system/dropbox #
SystemServer在启动时， 会创建并添加DROPBOX_SERVICE.
//SystemServer.java private void startOtherServices() { ... ... try { Slog.i(TAG, "DropBox Service"); ServiceManager.addService(Context.DROPBOX_SERVICE, new DropBoxManagerService(context, new File("/data/system/dropbox"))); } catch (Throwable e) { reportWtf("starting DropBoxManagerService", e); } ... ... }
在traces.txt中可以看到如下信息：
//说明了发生ANR的进程id、时间和进程名称。 ----- pid 2023 at 2018-07-24 19:33:17 ----- Cmd line: com.rui.android.poc //下面三行是线程的基本信息 JNI: CheckJNI is off; workarounds are off; pins=0; globals=348 DALVIK THREADS://以下是各个线程的函数堆栈信息 (mutexes: tll=0 tsl=0 tscl=0 ghl=0) //下面一行说明了线程名称、daemon表示守护进程，线程的优先级（默认5）、线程锁id和线程状态， //线程名称是启动线程的时候手动指明的，这里的main标识是主线程，是Android自动设定的 //一个线程名称，如果是自己手动创建的线程，一般会被命名成“Thread-xx”的格式，其中xx是 //线程id，它只增不减不会被复用；注意这其中的tid不是线程的id,它是一个在Java虚拟机中用 //来实现线程锁的变量，随着线程的增减，这个变量的值是可能被复用的； "main" prio=5 tid=1 NATIVE //group是线程组名称。sCount是此线程被挂起的次数，dsCount是线程被调试器挂起的次数， //当一个进程被调试后，sCount会重置为0，调试完毕后sCount会根据是否被正常挂起增长， //但是dsCount不会被重置为0，所以dsCount也可以用来判断这个线程是否被调试过。obj表示 //这个线程的Java对象的地址，self表示这个线程Native的地址。 | group="main" sCount=1 dsCount=0 obj=0x4164dcf0 self=0x41565628 //此后是线程的调度信息，sysTid是Linux下的内核线程id，nice是线程的调度优先级， //sched分别标志了线程的调度策略和优先级，cgrp是调度属组，handle是线程的处理函数地址。 | sysTid=2023 nice=-1 sched=0/0 cgrp=apps handle=1074626900 //线程当前上下文信息，state是调度状态；schedstat从 /proc/[pid]/task/[tid]/schedstat读出， //三个值分别表示线程在cpu上执行的时间、线程的等待时间和线程执行的时间片长度，有的 //android内核版本不支持这项信息，得到的三个值都是0；utm是线程用户态下使用的时间 //值(单位是jiffies）;stm是内核态下的调度时间值；core是最后执行这个线程的cpu核的序号。 | state=S schedstat=( 0 0 0 ) utm=49 stm=21 core=0 //线程的调用栈信息(这里可查看导致ANR的代码调用流程，分析ANR最重要的信息) (native backtrace unavailable) at libcore.io.Posix.open(Native Method) at libcore.io.BlockGuardOs.open(BlockGuardOs.java:110) at libcore.io.IoBridge.open(IoBridge.java:430) at java.io.FileInputStream.<init>(FileInputStream.java:78) at com.ruiven.android.Peripheral.util.kingFiles.write(kingFiles.java:58) at com.ruiven.android.Peripheral.util.kingFiles.write(kingFiles.java:51) at com.ruiven.android.Peripheral.util.kingLog.writeToFiles(kingLog.java:71) at com.ruiven.android.Peripheral.util.kingLog.f(kingLog.java:47) at com.ruiven.android.poc.receiver.ReceiverBatteryChanged.onReceive(ReceiverBatteryChanged.java:114) at android.app.LoadedApk$ReceiverDispatcher$Args.run(LoadedApk.java:767) at android.os.Handler.handleCallback(Handler.java:769) at android.os.Handler.dispatchMessage(Handler.java:97) at android.os.Looper.loop(Looper.java:136) at com.ruiven.android.Peripheral.util.Cockroach$1.run(Cockroach.java:38) at android.os.Handler.handleCallback(Handler.java:769) at android.os.Handler.dispatchMessage(Handler.java:97) at android.os.Looper.loop(Looper.java:136) at android.app.ActivityThread.main(ActivityThread.java:5375) at java.lang.reflect.Method.invokeNative(Native Method) at java.lang.reflect.Method.invoke(Method.java:515) at com.android.internal.os.ZygoteInit$MethodAndArgsCaller.run(ZygoteInit.java:976) at com.android.internal.os.ZygoteInit.main(ZygoteInit.java:792) at dalvik.system.NativeStart.main(Native Method) //Binder线程是进程的线程池中用来处理binder请求的线程 "Binder_3" prio=5 tid=23 NATIVE | group="main" sCount=1 dsCount=0 obj=0x41b765f8 self=0x4f213f18 | sysTid=1347 nice=0 sched=0/0 cgrp=apps handle=1327603952 | state=S schedstat=( 0 0 0 ) utm=0 stm=3 core=1 #00 pc 000205d0 /system/lib/libc.so (__ioctl+8) #01 pc 0002d01f /system/lib/libc.so (ioctl+14) #02 pc 0001e519 /system/lib/libbinder.so (android::IPCThreadState::talkWithDriver(bool)+140) #03 pc 0001ec67 /system/lib/libbinder.so (android::IPCThreadState::getAndExecuteCommand()+6) #04 pc 0001ecfd /system/lib/libbinder.so (android::IPCThreadState::joinThreadPool(bool)+48) #05 pc 000236cd /system/lib/libbinder.so #06 pc 0000ea19 /system/lib/libutils.so (android::Thread::_threadLoop(void*)+216) #07 pc 0004e769 /system/lib/libandroid_runtime.so (android::AndroidRuntime::javaThreadShell(void*)+68) #08 pc 0000e54b /system/lib/libutils.so #09 pc 0000d240 /system/lib/libc.so (__thread_entry+72) #10 pc 0000d3dc /system/lib/libc.so (pthread_create+240) at dalvik.system.NativeStart.run(Native Method) //JDWP线程是支持虚拟机调试的线程，daemon表示守护进程，不需要关心 "JDWP" daemon prio=5 tid=4 VMWAIT | group="system" sCount=1 dsCount=0 obj=0x41a21868 self=0x4cc821b0 | sysTid=785 nice=0 sched=0/0 cgrp=apps handle=1257589656 | state=S schedstat=( 0 0 0 ) utm=0 stm=0 core=1 #00 pc 00021420 /system/lib/libc.so (recvmsg+8) #01 pc 000668ab /system/lib/libdvm.so #02 pc 00066adf /system/lib/libdvm.so #03 pc 000697af /system/lib/libdvm.so #04 pc 00059fdd /system/lib/libdvm.so #05 pc 0000d240 /system/lib/libc.so (__thread_entry+72) #06 pc 0000d3dc /system/lib/libc.so (pthread_create+240) at dalvik.system.NativeStart.run(Native Method) //“Signal Catcher”负责接收和处理kernel发送的各种信号，例如SIGNAL_QUIT、SIGNAL_USR1等就是被该线程 //接收到并处理的，traces.txt 文件中的内容就是由该线程负责输出的，可以看到它的状态是RUNNABLE. "Signal Catcher" daemon prio=5 tid=3 RUNNABLE | group="system" sCount=0 dsCount=0 obj=0x41a21770 self=0x4af3e5e0 | sysTid=784 nice=0 sched=0/0 cgrp=apps handle=1257677168 | state=R schedstat=( 0 0 0 ) utm=2 stm=2 core=1 at dalvik.system.NativeStart.run(Native Method) ----- end 2023 -----
如果ANR在native层,那么堆栈中就不会有相关调用的路径,这种情况只能在native层添加更多的Log,一步步来查找了
NATIVE表示当前线程的状态：
Thread状态及其对应的值 ThreadState (defined at “dalvik/vm/thread.h “) THREAD_UNDEFINED = -1, /* makes enum compatible with int32_t */ THREAD_ZOMBIE = 0, /* TERMINATED */( 线程死亡，终止运行) THREAD_RUNNING = 1, /* RUNNABLE or running now */(线程可运行或正在运行) THREAD_TIMED_WAIT = 2, /* TIMED_WAITING in Object.wait() */(执行了带有超时参数的wait、sleep或join函数) THREAD_MONITOR = 3, /* BLOCKED on a monitor */(线程阻塞，等待获取对象锁) THREAD_WAIT = 4, /* WAITING in Object.wait() */( 执行了无超时参数的wait函数) THREAD_INITIALIZING= 5, /* allocated, not yet running */(新建，正在初始化，为其分配资源) THREAD_STARTING = 6, /* started, not yet on thread list */(新建，正在启动) THREAD_NATIVE = 7, /* off in a JNI native method */(正在执行JNI本地函数) THREAD_VMWAIT = 8, /* waiting on a VM resource */(正在等待VM资源) THREAD_SUSPENDED = 9, /* suspended, usually by GC or debugger */(线程暂停，通常是由于GC或debug被暂停)
**特别说明一下MONITOR状态和SUSPEND状态，MONITOR状态一般是类的同步块或者同步方法造成的，SUSPENDED状态在debugger的时候会出现，可以用来区别是不是真的是用户正常操作跑出了ANR。
mutexes(互斥)的选项简写对应含义： tll--thread list lock tsl-- thread suspend lock tscl-- thread suspend count lock ghl--gc heap lock hwl--heap worker lock hwll--heap worker list lock
- 通过Cmd line: packagename可以找到要分析的进程
- 并不是trace文件包含的应用就一定是造成ANR的帮凶，应用出现在trace文件中，只能说明出现ANR的时候这个应用进程还活着，trace文件的顶部则是触发ANR的应用信息。因此，如果你的应用出现在了trace文件的顶部，那么很有可能是因为你的应用造成了ANR，否则是你的应用造成ANR的可能性不大，但是具体是不是还需要进一步分析
