概述
ANR(Application Not Responding) 应用程序无响应。如果你应用程序在UI线程被阻塞太长时间,就会出现ANR,通常出现ANR,系统会弹出一个提示提示框,让用户知道,该程序正在被阻塞,是否继续等待还是关闭。
导致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发生
- 主线程尽量只做UI相关的操作,避免耗时操作,比如过度复杂的UI绘制,网络操作,文件IO操作;
- 避免主线程跟工作线程发生锁的竞争,减少系统耗时binder的调用,谨慎使用sharePreference,注意主线程执行provider query操作
总之,尽可能减少主线程的负载,让其空闲待命,以期可随时响应用户的操作
命令导出ANR日志
adb pull /data/anr/traces.txt
通常发生了ANR,ActivityManager会打印报错信息:
ANR就不作介绍了,下面只介绍如何分析ANR异常.
04-25 23:25:32.736 E/ActivityManager( 1045): ANR in cn.com.essence.stock (cn.com.essence.stock/cn.com.essence.activity.LauncherActivity)
04-25 23:25:32.736 E/ActivityManager( 1045): Reason: keyDispatchingTimedOut
04-25 23:25:32.736 E/ActivityManager( 1045): Load: 12.52 / 11.4 / 10.99
04-25 23:25:32.736 E/ActivityManager( 1045): CPU usage from 25606ms to 478ms ago:
04-25 23:25:32.736 E/ActivityManager( 1045): 9.8% 1295/com.android.systemui: 6.4% user + 3.4% kernel / faults: 690 minor 3 major
04-25 23:25:32.736 E/ActivityManager( 1045): 7.4% 1045/system_server: 5.6% user + 1.8% kernel / faults: 6899 minor 17 major
04-25 23:25:32.736 E/ActivityManager( 1045): 3.6% 257/surfaceflinger: 1.4% user + 2.2% kernel / faults: 1921 minor
04-25 23:25:32.736 E/ActivityManager( 1045): 1.7% 430/adbd: 0.3% user + 1.3% kernel
04-25 23:25:32.736 E/ActivityManager( 1045): 1% 2109/mpdecision: 0% user + 0.9% kernel / faults: 5 minor
04-25 23:25:32.736 E/ActivityManager( 1045): 0.9% 337/sdcard: 0% user + 0.9% kernel
04-25 23:25:32.736 E/ActivityManager( 1045): 0.9% 6230/logcat: 0.1% user + 0.7% kernel
04-25 23:25:32.736 E/ActivityManager( 1045): 0.7% 28528/logcat: 0.1% user + 0.6% kernel
04-25 23:25:32.736 E/ActivityManager( 1045): 0.6% 27802/kworker/u:4: 0% user + 0.6% kernel
04-25 23:25:32.736 E/ActivityManager( 1045): 0.5% 24149/kworker/u:2: 0% user + 0.5% kernel
04-25 23:25:32.736 E/ActivityManager( 1045): 0.4% 28265/logcat: 0% user + 0.4% kernel
04-25 23:25:32.736 E/ActivityManager( 1045): 0.3% 879/zygote: 0.1% user + 0.2% kernel / faults: 566 minor
04-25 23:25:32.736 E/ActivityManager( 1045): 0.2% 98/irq/581-ESD_CHE: 0% user + 0.2% kernel
04-25 23:25:32.736 E/ActivityManager( 1045): 0.2% 364/mdss_fb0: 0% user + 0.2% kernel
04-25 23:25:32.736 E/ActivityManager( 1045): 0.2% 3/ksoftirqd/0: 0% user + 0.2% kernel
04-25 23:25:32.736 E/ActivityManager( 1045): 0.2% 144/mmcqd/0: 0% user + 0.2% kernel
04-25 23:25:32.736 E/ActivityManager( 1045): 0.1% 7/kworker/u:0H: 0% user + 0.1% kernel
04-25 23:25:32.736 E/ActivityManager( 1045): 0.1% 77/kswapd0: 0% user + 0.1% kernel
04-25 23:25:32.736 E/ActivityManager( 1045): 0.1% 20197/kworker/0:3: 0% user + 0.1% kernel
04-25 23:25:32.736 E/ActivityManager( 1045): 0% 1506/android.process.safer: 0% user + 0% kernel / faults: 522 minor 5 major
04-25 23:25:32.736 E/ActivityManager( 1045): 0.1% 1877/kworker/0:0H: 0% user + 0.1% kernel
04-25 23:25:32.736 E/ActivityManager( 1045): 0.1% 25827/kworker/u:3: 0% user + 0.1% kernel
04-25 23:25:32.736 E/ActivityManager( 1045): 0% 2/kthreadd: 0% user + 0% kernel
04-25 23:25:32.736 E/ActivityManager( 1045): 0% 247/servicemanager: 0% user + 0% kernel
04-25 23:25:32.736 E/ActivityManager( 1045): 0% 254/netd: 0% user + 0% kernel / faults: 52 minor
04-25 23:25:32.736 E/ActivityManager( 1045): 0% 5554/kworker/0:2H: 0% user + 0% kernel
04-25 23:25:32.736 E/ActivityManager( 1045): 0% 260/installd: 0% user + 0% kernel
04-25 23:25:32.736 E/ActivityManager( 1045): 0% 417/location-mq: 0% user + 0% kernel
04-25 23:25:32.736 E/ActivityManager( 1045): 0% 422/xtwifi-client: 0% user + 0% kernel / faults: 108 minor
04-25 23:25:32.736 E/ActivityManager( 1045): 0% 1438/com.android.phone: 0% user + 0% kernel / faults: 44 minor 3 major
04-25 23:25:32.736 E/ActivityManager( 1045): 0% 1532/android.process.TrafficMonitor: 0% user + 0% kernel / faults: 306 minor 1 major
04-25 23:25:32.736 E/ActivityManager( 1045): 0% 9185/kworker/0:0: 0% user + 0% kernel
04-25 23:25:32.736 E/ActivityManager( 1045): 0% 14985/MC_Thread: 0% user + 0% kernel
04-25 23:25:32.736 E/ActivityManager( 1045): 0% 14987/RX_Thread: 0% user + 0% kernel
04-25 23:25:32.736 E/ActivityManager( 1045): 0% 14998/wpa_supplicant: 0% user + 0% kernel / faults: 1 minor
04-25 23:25:32.736 E/ActivityManager( 1045): 0% 26795/com.oppo.gestureguide.custom: 0% user + 0% kernel / faults: 239 minor
04-25 23:25:32.736 E/ActivityManager( 1045): +0% 30995/app_process: 0% user + 0% kernel
04-25 23:25:32.736 E/ActivityManager( 1045): +0% 31058/com.android.defcontainer: 0% user + 0% kernel
04-25 23:25:32.736 E/ActivityManager( 1045): +0% 31099/migration/1: 0% user + 0% kernel
04-25 23:25:32.736 E/ActivityManager( 1045): +0% 31100/kworker/1:0: 0% user + 0% kernel
04-25 23:25:32.736 E/ActivityManager( 1045): +0% 31101/kworker/1:0H: 0% user + 0% kernel
04-25 23:25:32.736 E/ActivityManager( 1045): +0% 31102/ksoftirqd/1: 0% user + 0% kernel
04-25 23:25:32.736 E/ActivityManager( 1045): +0% 31103/app_process: 0% user + 0% kernel
04-25 23:25:32.736 E/ActivityManager( 1045): +0% 31104/kworker/1:1: 0% user + 0% kernel
04-25 23:25:32.736 E/ActivityManager( 1045): 37% TOTAL: 23% user + 10% kernel + 4% iowait + 0.1% softirq
04-25 23:25:32.736 E/ActivityManager( 1045): CPU usage from 1553ms to 2099ms later:
04-25 23:25:32.736 E/ActivityManager( 1045): 13% 1045/system_server: 1.8% user + 11% kernel / faults: 55 minor
04-25 23:25:32.736 E/ActivityManager( 1045): 5.6% 1069/ActivityManager: 0% user + 5.6% kernel
04-25 23:25:32.736 E/ActivityManager( 1045): 1.8% 1051/Compiler: 0% user + 1.8% kernel
04-25 23:25:32.736 E/ActivityManager( 1045): 1.8% 1056/Binder_2: 0% user + 1.8% kernel
04-25 23:25:32.736 E/ActivityManager( 1045): 1.8% 1250/WifiStateMachin: 1.8% user + 0% kernel
04-25 23:25:32.736 E/ActivityManager( 1045): 1.8% 1251/WifiService: 0% user + 1.8% kernel
04-25 23:25:32.736 E/ActivityManager( 1045): 3.7% 28529/takeLog: 3.7% user + 0% kernel
04-25 23:25:32.736 E/ActivityManager( 1045): 1.8% 28439/TestManager: 1.8% user + 0% kernel
04-25 23:25:32.736 E/ActivityManager( 1045): 1.8% 30127/watcher: 1.8% user + 0% kernel
04-25 23:25:32.736 E/ActivityManager( 1045): 3.7% 430/adbd: 0% user + 3.7% kernel
04-25 23:25:32.736 E/ActivityManager( 1045): 1.8% 430/adbd: 0% user + 1.8% kernel
04-25 23:25:32.736 E/ActivityManager( 1045): 1.8% 4807/adbd: 0% user + 1.8% kernel
04-25 23:25:32.736 E/ActivityManager( 1045): 1% 247/servicemanager: 1% user + 0% kernel
04-25 23:25:32.736 E/ActivityManager( 1045): 1.8% 257/surfaceflinger: 1.8% user + 0% kernel / faults: 1 minor
04-25 23:25:32.736 E/ActivityManager( 1045): 1.8% 257/Binder_2: 0% user + 1.8% kernel
04-25 23:25:32.736 E/ActivityManager( 1045): +0% 31194/Invalidator: 0% user + 0% kernel
04-25 23:25:32.736 E/ActivityManager( 1045): 1.8% 337/sdcard: 0% user + 1.8% kernel
04-25 23:25:32.736 E/ActivityManager( 1045): 1.1% 1295/com.android.systemui: 0% user + 1.1% kernel / faults: 1 minor
04-25 23:25:32.736 E/ActivityManager( 1045): 1.1% 1295/ndroid.systemui: 0% user + 1.1% kernel
04-25 23:25:32.736 E/ActivityManager( 1045): 1.8% 6230/logcat: 1.8% user + 0% kernel
04-25 23:25:32.736 E/ActivityManager( 1045): 1.3% 27802/kworker/u:4: 0% user + 1.3% kernel
04-25 23:25:32.736 E/ActivityManager( 1045): 1.8% 28265/logcat: 1.8% user + 0% kernel
04-25 23:25:32.736 E/ActivityManager( 1045): 1.3% 28528/logcat: 1.3% user + 0% kernel
04-25 23:25:32.736 E/ActivityManager( 1045): +0% 31163/app_process: 0% user + 0% kernel
04-25 23:25:32.736 E/ActivityManager( 1045): +0% 31180/app_process: 0% user + 0% kernel
04-25 23:25:32.736 E/ActivityManager( 1045): 77% TOTAL: 54% user + 20% kernel + 2.7% iowait
04-25 23:25:32.736 V/SettingsProvider( 1045): call(global:dropbox:data_app_anr) for 0
04-25 23:25:32.736 D/ActivityManager( 1045): addErrorToDropBox processName = cn.com.essence.stock
04-25 23:25:32.736 V/SettingsProvider( 1045): call(global:send_action_app_error) for 0
04-25 23:25:32.746 I/Process ( 1045): Sending signal. PID: 29833 SIG: 6
04-25 23:25:32.746 V/SettingsProvider( 1045): call(global:logcat_for_data_app_anr) for 0
04-25 23:25:32.776 D/DropBoxManagerService( 1045): file :: /data/system/dropbox/data_app_anr@1587828332780.txt.gz
******* HERE ANR TRACES FILE START *******
---------------------------------------------------------------------------------------------------
traces_cn.com.essence.stock.txt:
---------------------------------------------------------------------------------------------------
----- pid 1045 at 2020-04-25 23:25:30 -----
Cmd line: system_server
JNI: CheckJNI is off; workarounds are off; pins=4; globals=12445 (plus 150 weak)
DALVIK THREADS:
(mutexes: tll=0 tsl=0 tscl=0 ghl=0)
"main" prio=5 tid=1 NATIVE
| group="main" sCount=1 dsCount=0 obj=0x41610710 self=0x415f8b38
| sysTid=1045 nice=0 sched=0/0 cgrp=apps handle=1074745340
| state=S schedstat=( 1346705094852 1755759884711 6754305 ) utm=92988 stm=41682 core=0
#00 pc 0001b534 /system/lib/libc.so (__ioctl+8)
#01 pc 0002bbb3 /system/lib/libc.so (ioctl+14)
#02 pc 0001b851 /system/lib/libbinder.so (android::IPCThreadState::talkWithDriver(bool)+140)
#03 pc 0001bfef /system/lib/libbinder.so (android::IPCThreadState::joinThreadPool(bool)+154)
#04 pc 000013c3 /system/lib/libsystem_server.so (system_init+378)
#05 pc 000203cc /system/lib/libdvm.so (dvmPlatformInvoke+112)
#06 pc 00050d97 /system/lib/libdvm.so (dvmCallJNIMethod(unsigned int const*, JValue*, Method const*, Thread*)+398)
#07 pc 00029860 /system/lib/libdvm.so
#08 pc 0002e218 /system/lib/libdvm.so (dvmInterpret(Thread*, Method const*, JValue*)+184)
#09 pc 000630af /system/lib/libdvm.so (dvmInvokeMethod(Object*, Method const*, ArrayObject*, ArrayObject*, ClassObject*, bool)+350)
#10 pc 0006acd3 /system/lib/libdvm.so
#11 pc 00029860 /system/lib/libdvm.so
#12 pc 0002e218 /system/lib/libdvm.so (dvmInterpret(Thread*, Method const*, JValue*)+184)
#13 pc 00062df1 /system/lib/libdvm.so (dvmCallMethodV(Thread*, Method const*, Object*, bool, JValue*, std::__va_list)+292)
#14 pc 0004c97b /system/lib/libdvm.so
#15 pc 0004f133 /system/lib/libandroid_runtime.so
#16 pc 0004fde3 /system/lib/libandroid_runtime.so (android::AndroidRuntime::start(char const*, char const*)+378)
#17 pc 0000105b /system/bin/app_process
#18 pc 0000dd37 /system/lib/libc.so (__libc_init+50)
...
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文件.
具体怎么导出ANR文件呢?
1.通过adb shell ls /data/anr/ 查看anr文件下相关信息
2.adb pull /data/anr/traces.txt d:/ 导出文件至某盘
3.查看具体anr的具体信息基本上就能具体定位代码造成的问题
如果之前没有配置 可能需要配置adb
1.输入:touch .bash_profile
2.打开:open -e .bash_profile
3.保存:source .bash_profile
其中进行第3步,打开的 .bash_profile 文件,文件的路径一定要改成你自己电脑中的具体路径。
我电脑中配置:
ANDROID_HOME=/Users/xxx/Library/Android/sdk
export PATH=$PATH:$ANDROID_HOME/tools
export PATH=$PATH:$ANDROID_HOME/platform-tools
注意: PATH 变量中的 Android/sdk/tools 路径。
执行 source .bash_profile 后,
输入 adb 命令,可见控制台输出:
Android Debug Bridge version 1.0.41
Version 30.0.0-6374843
即可.
Mac下出现-bash: 命令: command not found的解决
1.在命令行中输入:export PATH=/usr/bin:/usr/sbin:/bin:/sbin:/usr/X11R6/bin
这样可以保证命令行命令暂时可以使用。命令执行完之后先不要关闭终端。
2.输入 cd ~/
3.打开并编辑bash_profile 执行命令:open .bash_profile
4.source .bash_profile使生效
mac终端的命令都失效的解决方法
step1.
在terminal里面输入:
export PATH="/usr/bin:/bin:/usr/sbin:/sbin:/usr/local/bin:/usr/X11/bin"
然后命令暂时可以用了,
step2.
赶紧用open -e ~/.bash_profile在文本编辑器里面打开.bash_profile文件:
step3.
更改PATH环境变量设置,添加上这一行,
export PATH="/usr/bin:/bin:/usr/sbin:/sbin:/usr/local/bin:/usr/X11/bin"