对一款Android应用来说,用户体验是至高无上的原则。如果应用上手的体验特别差,点点这点点那就出现各种问题,用户就会执行最简单的一个操作——卸载你的应用。用户体验是一个非常大的概念,其中最直接粗暴的表现有两个:崩溃和ANR。这两个问题是开发人员最不想看到的两个现象。对于崩溃来说,一般原因比较明显,Android会在logcat中以红色的字体打印出具体导致崩溃的代码。对于线上应用, 也有各种性能监控工具可以帮我们分析。但是ANR的原因就比较难以定位。
ANR(Application Not Responding),即应用程序无响应,相信很多安卓用户都碰到过那个然并卵的对话框:
出现这个对话框,会让用户觉得很沮丧,轻则关闭,重则卸载。用户就是这么一点一点流失的啊。
产生ANR的原因
那么怎么避免出现ANR呢?首先要知道ANR产生的原因。
Android系统中产生ANR的原因大致分为三类:
- Service ANR,前台进程中的Service生命周期超过20秒,后台进程中的Service生命周期超过200秒时;
- Broadcast ANR,前台的串行广播消息中onReceive()方法执行超过10秒,后台的串行广播消息中onReceive()方法执行超过60秒时;
- Input ANR,输入时间在5秒内无法响应时;
Android系统采用不同的监测机制来监测ANR,Service和Broadcast都是由AMS调度,利用Handler和Looper,设计了一个TIMEOUT消息交由AMS线程来处理,整个超时机制的实现都是在Java层; InputEvent由InputDispatcher调度,待处理的输入事件都会进入队列中等待,设计了一个等待超时的判断,超时机制的实现在Native层。在这篇文章中做了很详细的介绍。
具体到代码层面,是什么操作导致了以上情况的产生呢?最重要的原因就是在主线程里执行了太多的阻塞耗时操作。那么要避免ANR也就需要坚持一个原则:不要在主线程里做繁重的耗时操作。悲伤的是,我们的主工程里大量的数据库操作都执行在主线程里,这是接下来(不是本文)需要深入探讨的一个问题。
哪些操作时在主线程执行的?
要做到不在主线程里执行耗时操作,首先要知道哪些地方执行的代码是在主线程执行的。
- Activity和Fragment里的所有生命周期回调都是执行在主线程;
- Service默认是执行在主线程的;
- BroadcastReceiver的onReceive()方法是执行在主线程的;
- 没有使用子线程looper的handler的handleMessage()方法和post(runnable)是执行在主线程的;
- View的post(Runnbale)是执行在主线程的;
因此,在这些地方执行操作时,要格外小心,最保险的方法就是开启一个子线程,把耗时操作都扔到子线程里做,具体创建一个异步操作,方法五花八门,这里不展开讲了。
怎么分析ANR?
即使写代码的时候特别小心,也无法保证你的应用不发生ANR,因为不同的设备配置和性能上的差异,使得在A机器上4秒钟执行完的操作,在B机器上可能会花费超过4秒的时间,甚至是由于手机上的其他进程占用cpu导致cpu无法响应当前应用,种种原因都会导致ANR的出现。所以我们必须分析其产生的原因,才能及时发现问题,解决问题。
当ANR发生时,我们通常采用Logcat和traces.txt文件的相关信息去定位问题。主要包含以下几个方面:
- 基本信息,进程名、进程号、包名、系统build号、ANR类型等;
- cpu使用信息,活跃进程的cpu平均占用率、IO情况等;
- 堆栈信息;
可以通过adb命令将traces.txt文件拉到本地:
$adb pull data/anr/traces.txt .
以下是病历夹某一次ANR的日志:
----- pid 6603 at 2016-10-14 09:57:24 -----
Cmd line: com.apricotforest.dossier
JNI: CheckJNI is off; workarounds are off; pins=0; globals=412 (plus 20 weak)
DALVIK THREADS:
(mutexes: tll=0 tsl=0 tscl=0 ghl=0)
"main" prio=5 tid=1 TIMED_WAIT
| group="main" sCount=1 dsCount=0 obj=0x41744e58 self=0x41664910
| sysTid=6603 nice=-6 sched=0/0 cgrp=apps handle=1074172244
| state=S schedstat=( 28338231507 276030844958 49092 ) utm=2490 stm=343 core=3
at java.lang.VMThread.sleep(Native Method)
at java.lang.Thread.sleep(Thread.java:1013)
at java.lang.Thread.sleep(Thread.java:995)
at com.apricotforest.dossier.persistentconnection.PersistentConnectionService$3.onClose(PersistentConnectionService.java:162)
at com.xingshulin.persistentconnection.WebSocketManager$1.onClose(WebSocketManager.java:31)
at de.tavendo.autobahn.WebSocketConnection.failConnection(WebSocketConnection.java:198)
at de.tavendo.autobahn.WebSocketConnection.access$7(WebSocketConnection.java:156)
at de.tavendo.autobahn.WebSocketConnection$1.handleMessage(WebSocketConnection.java:390)
at android.os.Handler.dispatchMessage(Handler.java:102)
at android.os.Looper.loop(Looper.java:136)
at android.app.ActivityThread.main(ActivityThread.java:5047)
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:793)
at com.android.internal.os.ZygoteInit.main(ZygoteInit.java:609)
at dalvik.system.NativeStart.main(Native Method)
...
从文中可以看到以上描述的一些信息,很明显问题发生在长连接服务的onClose()方法中,该方法中执行的操作耗时导致发生了Service的ANR。
上面这个例子比较简单,日志里已经很明白的告诉你出错的位置了,还有一些ANR问题发生的原因比较隐蔽,需要认真的分析,比如:
Process:com.apricotforest.dossier
...
CPU usage from 3330ms to 814ms ago:
6% 178/system_server: 3.5% user + 1.4% kernel / faults: 86 minor 20 major
4.6% 2976/com.apricotforest.dossier: 0.7% user + 3.7% kernel /faults: 52 minor 19 major
0.9% 252/com.android.systemui: 0.9% user + 0% kernel
...
100%TOTAL: 5.9% user + 4.1% kernel + 89% iowait
最后一句说明CPU占用100%,已经满负荷,其中大部分被iowait即I/O操作占用。这时候需要仔细的分析logcat和trace.txt,同时结合google,才有可能定位到问题原因。
p.p1 {margin: 0.0px 0.0px 0.0px 60.0px; font: 16.0px 'Heiti SC Light'; color: #586e75}p.p2 {margin: 0.0px 0.0px 0.0px 60.0px; font: 16.0px Courier; color: #586e75; min-height: 19.0px}p.p3 {margin: 0.0px 0.0px 0.0px 60.0px; font: 16.0px Courier; color: #859900}p.p4 {margin: 0.0px 0.0px 0.0px 60.0px; font: 16.0px Courier; color: #859900; min-height: 19.0px}span.s1 {font: 16.0px Courier}
内存原因也可能导致ANR,例如用一张大图片作为activity的背景,trace信息可能是这样的:
Cmdline: android.process.acore
DALVIK THREADS:
"main"prio=5 tid=3 VMWAIT
|group="main" sCount=1 dsCount=0 s=N obj=0x40026240self=0xbda8
| sysTid=1815 nice=0 sched=0/0 cgrp=unknownhandle=-1344001376
atdalvik.system.VMRuntime.trackExternalAllocation(NativeMethod)
atandroid.graphics.Bitmap.nativeCreate(Native Method)
atandroid.graphics.Bitmap.createBitmap(Bitmap.java:468)
atandroid.view.View.buildDrawingCache(View.java:6324)
atandroid.view.View.getDrawingCache(View.java:6178)
...
MEMINFO in pid 1360 [android.process.acore] **
native dalvik other total
size: 17036 23111 N/A 40147
allocated: 16484 20675 N/A 37159
free: 296 2436 N/A 2732
free的内存已经所剩无几。当然,这时候发生OOM的几率也变的很大了。
病历夹的现状:ANR比较频繁,需要重点解决。