ANR (Application Not Responding)时而出现,抓出有效的Log是分析问题的关键。这里给出一些简单建议指导。
一点背景
ANR发生时候,多数情况下,界面没有响应,若干秒后弹出系统对话框,提示是否强制关闭应用。一般会想到主线程死锁问题,但那其实只是众多可能的原因之一。主线程也可能由于系统大量执行GC, 主线程繁忙,IO过多,等待分支线程/资源等等原因,从而会造成dispatchTimeout超时而引发ANR。而且,Service和Broadcast里的问题也会引发ANR,并且Service的ANR多数时候不弹出对话框,令问题的分析更加复杂些。
收集什么log,如何收集?- adb shell bugreport (包含dumpsys, dumpstate和logcat)
最有用的log是APP的backtrace记录:位于手机上 /data/anr/traces.txt.
可惜通常只有ROOT的手机才能取出traces.txt。这里要介绍的方法能突破这个限制(还有些特殊情况以后讨论),就是adb shell bugreport
这个利器。
具体操作:
连上数据线,不要操作对话框(因为这样会kill掉应用,backtrace log会被输出到traces.txt,再也没机会拿到)。
电脑上开个命令行,输入这样的:
adb shell bugreport > log_file_name_to_save.txt
。 这个dump的信息很多,时间可能一两分钟。
分析
bugreport的输出集合了dumpsys, dumpstate和logcat。其中:
dumpsys: 服务进程的各个信息, 比如Window Manager, System Server等等
dumpstate主要获取信息:
1,基本信息,如版本信息,内存基本信息,cpu基本信息,硬件信息等
2,系统log
3,网络信息,路由信息,网络信息
4,panic信息
5,锁的使用信息
6,进程信息
7,binder信息
8,应用程序安装信息
9,磁盘使用情况
10,所有activity,services 信息
11,properties信息 等包含所有系统services, memory,
ANR的backtrace会出现在"TRACES JUST NOW"区段:查找以"TRACES JUST NOW"开始的段落, 内容会像这样:
------ VM TRACES JUST NOW (/data/anr/traces.txt.bugreport: 2014-11-28 11:58:42) ------ ----- pid 171 at 2014-11-28 11:58:10 ----- Cmd line: /system/bin/surfaceflinger ABI: 'arm' "surfaceflinger" sysTid=171 #00 pc 00039430 /system/lib/libc.so (__epoll_pwait+20) #01 pc 00014571 /system/lib/libc.so (epoll_pwait+26) #02 pc 0001457f /system/lib/libc.so (epoll_wait+6) #03 pc 000123c3 /system/lib/libutils.so (android::Looper::pollInner(int)+98) #04 pc 000125ed /system/lib/libutils.so (android::Looper::pollOnce(int, int*, int*, void**)+92) #05 pc 00015895 /system/lib/libsurfaceflinger.so #06 pc 00017c5d /system/lib/libsurfaceflinger.so (android::SurfaceFlinger::run()+8) #07 pc 0000083d /system/bin/surfaceflinger #08 pc 000128ed /system/lib/libc.so (__libc_init+44) #09 pc 000008d8 /system/bin/surfaceflinger"Binder_1" sysTid=257 #00 pc 00039d48 /system/lib/libc.so (__ioctl+8) #01 pc 0005177d /system/lib/libc.so (ioctl+14) ... ... ... ----- pid 25927 at 2014-11-28 11:58:41 ----- Cmd line: com.alipay.mobile.stock ... ... ... Total time spent in GC: 102.620s Mean GC size throughput: 1858KB/s Mean GC object throughput: 43140.5 objects/s Total number of allocations 4623054Total bytes allocated 274MB Free memory 8MB Free memory until GC 8MB Free memory until OOME 103MB Total memory 96MB Max memory 192MB Total mutator paused time: 2.251s Total time waiting for GC to complete: 7.571ms DALVIK THREADS (59): "main" prio=5 tid=1 Waiting | group="main" sCount=1 dsCount=0 obj=0x739faec0 self=0xb4f07800 | sysTid=25927 nice=0 cgrp=apps sched=0/0 handle=0xb6f25ec8 | state=S schedstat=( 3504155493 2059950681 4737 ) utm=302 stm=48 core=0 HZ=100 | stack=0xbe5fd000-0xbe5ff000 stackSize=8MB | held mutexes= at java.lang.Object.wait!(Native method) - waiting on <0x26e2f044> (a java.lang.Object) at com.alipay.mobile.stock.ui.BaseFragmentActivity.onBackPressed(BaseFragmentActivity.java:220) - locked <0x26e2f044> (a java.lang.Object) at android.app.Activity.onKeyUp(Activity.java:2453) at android.view.KeyEvent.dispatch(KeyEvent.java:2633) at android.app.Activity.dispatchKeyEvent(Activity.java:2704) at com.android.internal.policy.impl.PhoneWindow$DecorView.dispatchKeyEvent(PhoneWindow.java:2221) at android.view.ViewRootImpl$ViewPostImeInputStage.processKeyEvent(ViewRootImpl.java:3918) at android.view.ViewRootImpl$ViewPostImeInputStage.onProcess(ViewRootImpl.java:3
每个进程的方法,编辑架构,链接库,内存,栈等信息都记录其中。
首先看主线程是否停在异常的方法中,比如上面的例子是故意制造出的ANR,backtrace显示出主线程停留在onKeyUp中的wait()。这是最容易解决的情形。
如果不是,再考虑其它情况,情况非常多,下面列举一些可能情况:
由于主线程导致的情况:
1.耗时网络访问
2.当有大量数据读写操作时再请求数据读写
3.数据库操作(比如其他大数据量应用访问数据库导致数据库负载过重时)
4.硬件操作(比如Camera)
5.调用thread_join() / Sleep() / Wait() 或者等待locker的时候
6.Service binder数量达到上限
7.在system_server中发生WatchDog ANR
8.Service忙导致超时无响应
由于非主线程导致的情况:
1.非主线程持有lock,导致主线程等待lock超时
2.非主线程终止或者崩溃导致主线程一直等待
转载于:https://blog.51cto.com/lilier/1613593