android 实例和分析

ANR(“Application Not Responding”)——“应用没有响应”。

当某个应用处于长期无响应状态，Android系统会弹出一个窗口上面写道，XXX is not responding给出两个按钮一个为Force close一个为Wait。

什么导致ANR发生

在Android中，应用程序是由Activity Manager和Window Manager系统服务监视的。当遇到下面任何一个情况中时，Android显示ANR：

主线程 (“事件处理线程” / “UI线程”) 在5秒内没有响应输入事件；
BroadcastReceiver 没有在10秒内完成返回；
Server没有在20秒内完成；

从代码分析ANR

ANR最终显示对话框和打印log信息方法：com.android.server.am.ActivityManagerService.appNotResponding

其调用图如下：

分析log和trace

出现ANR后需要获取的信息

trace信息（/data/anr/traces.txt）

分析方法

ANR问题，直接搜索“ANR”关键词（ANR后面加个空格，可以过滤很多无效信息），快速定位到关键事件信息；
定位到关键事件信息后，如果信息不够明确的，再去搜索虚拟机信息，关键字：“Dalvik Thread”，查看具体的进程和线程跟踪的日志，来定位到代码。但有时log中没有虚拟机的信息；
接下来就是分析traces.txt，都是虚拟机线程信息，我们可以从中找到些关键信息；
目前遇到的ANR问题绝大多是属于keyDispatchingTimedOut，其他两种很少，server超时的问题还没碰到过；
ANR出现不一定是应用本身的问题，如果机器由于某个原因就已经很慢了，然后打开某个应用，之后该应用报个ANR，这个实属正常；

实例一：

04-14 13:53:25.778 I/ActivityManager( 1415): ANR in process: com.sina.weibo (last in com.sina.weibo)04-14 13:53:25.778 I/ActivityManager( 1415): Annotation: keyDispatchingTimedOut04-14 13:53:25.778 I/ActivityManager( 1415): CPU usage:04-14 13:53:25.778 I/ActivityManager( 1415): Load: 15.43 / 13.8 / 12.0504-14 13:53:25.778 I/ActivityManager( 1415): CPU usage from 13632ms to 2264ms ago:04-14 13:53:25.778 I/ActivityManager( 1415):   init: 45% = 4% user + 41% kernel / faults: 20 minor04-14 13:53:25.778 I/ActivityManager( 1415):   com.sina.weibo: 16% = 8% user + 7% kernel / faults: 4142 minor 833 major04-14 13:53:25.778 I/ActivityManager( 1415):   mediaserver: 11% = 5% user + 5% kernel / faults: 1410 minor 12 major04-14 13:53:25.778 I/ActivityManager( 1415):   system_server: 8% = 2% user + 6% kernel / faults: 2698 minor 325 major04-14 13:53:25.778 I/ActivityManager( 1415):   kswapd0: 3% = 0% user + 3% kernel04-14 13:53:25.778 I/ActivityManager( 1415):   xin001.activity: 2% = 0% user + 1% kernel / faults: 432 minor 167 major04-14 13:53:25.778 I/ActivityManager( 1415):   mmcqd: 1% = 0% user + 1% kernel............04-14 13:53:25.778 I/ActivityManager( 1415):   dhcpcd: 0% = 0% user + 0% kernel / faults: 88 minor 12 major04-14 13:53:25.778 I/ActivityManager( 1415): TOTAL: 100% = 24% user + 74% kernel + 0% softirq04-14 13:53:25.788 I/ActivityManager( 1415): Removing old ANR trace file from /data/anr/traces.txt

搜索ANR关键字：

04-14 13:53:25.778 I/ActivityManager( 1415): ANR in process: com.sina.weibo (last in com.sina.weibo)

说明：在04-14 13:53:25.778的时候 ActivityManager（进程号为1415) 发生了如下错误：com.sina.weibo无响应。

04-14 13:53:25.778 I/ActivityManager( 1415): Annotation: keyDispatchingTimedOut

说明：原因：keyDispatchingTimeOut – 按键分配超时

04-14 13:53:25.778 I/ActivityManager( 1415): Load: 15.43 / 13.8 / 12.05

说明：5分钟，10分钟，15分钟内的平均负载分别为：15.43 , 13.8 , 12.05

log关键字：

Annotation/Reason——发生ANR的原因

原因三种：1、keyDispatchingTimedOut 按键响应超时               例：(Reason: keyDispatchingTimedOut)2、Broadcast of ...         BroadcastReceiver执行超时  例：(Reason: Broadcast of Intent)3、Executing service...  Server执行超时             例：(Reason: Executing service net.kicksass.shootingstarbbs.streamstar/.StreamStarService)

导致ANR的原因

长时间的I/O处理，比如读写大文件；
网络访问时造成的阻塞；
BroadcastReceiver的onReceiver 方法执行超过10s;
系统同步进程死锁

避免ANR的建议

单独开工作者线程，通过独立的Thread或使用类似AsyncTask的方式来处理耗时的内容。
UI线程中不要处理过多的内容,遇到UI中需要执行复杂的操作，分段处理方式。

ANR:keyDispatchingTimedOut的检测机制

ANR的触发有三种类型，waitForNextEventTarget的调用图；

（Method com.android.server.WindowManagerService.KeyWaiter.waitForNextEventTarget）KyeWaiter.waitForNextEventTarget调用图

处理流程

1、WindowManagerService中有一个InputDispathcherThread,该线程是个while(true)循环，始终在读取输入事件队列，分类并处理这些事件；

QueuedEvent ev = mQueue.getEvent((int)((!configChanged && curTime < nextKeyTime)? (nextKeyTime-curTime): 0));消息队列：  KeyQ mQueue；private class KeyQ extends KeyInputQueue implements KeyInputQueue.FilterCallback

2、输入事件被分成四类：

       键盘输入（RawInputEvent.CLASS_KEYBOARD）；       触摸屏输入（RawInputEvent.CLASS_TOUCHSCREEN）；       轨迹球输入（RawInputEvent.CLASS_TRACKBALL）；       RawInputEvent.CLASS_CONFIGURATION_CHANGED，(注：不明)

3、然后各种事件处理的方法把事件传递给View或window：

            focus.mClient.dispatchKey(event);            target.mClient.dispatchPointer(ev, eventTime, true);            focus.mClient.dispatchTrackball(ev, eventTime, true);

分析ANR与输入事件处理流程的关联

1、当有输入事件输入并得到处理时，WindowManagerService都会记录一些状态

     输入事件的状态 由 Class com.android.server.WindowManagerService.KeyWaiter.DispatchState 实现.     显示窗口的状态 由 Class com.android.server.WindowManagerService.WindowState 实现.

2、在每次处理输入事件之前，WindowManagerService都会检查上一次的输入事件是否处理完成，该实现就是waitForNextEventTarget方法实现的。

      private int dispatchPointer(QueuedEvent qev, MotionEvent ev, int pid, int uid) {         Object targetObj = mKeyWaiter.waitForNextEventTarget(null, qev, ev, true, false, pid, uid);      .......

3、KeyWaiter.waitForNextEventTarget方法和注释

        /**         * Wait for the last event dispatch to complete, then find the next         * target that should receive the given event and wait for that one         * to be ready to receive it.         */        Object waitForNextEventTarget(KeyEvent nextKey, QueuedEvent qev,                MotionEvent nextMotion, boolean isPointerEvent,                boolean failIfTimeout, int callingPid, int callingUid)

4、在KeyWaiter.waitForNextEventTarget中，会根据Focuse的窗口和上一次输入事件的一些状态值去判断上一次的输入事件是否执行已经执行完成

5、值得关注的状态标识

  Variable Private com.android.server.WindowManagerService.KeyWaiter.mFinished  Variable com.android.server.WindowManagerService.KeyWaiter.waitForNextEventTarget.targetWin  Variable com.android.server.WindowManagerService.mDisplayFrozen  Variable com.android.server.WindowManagerService.mFocusedApp  Variable com.android.server.WindowManagerService.mFocusedApp  Variable com.android.server.WindowManagerService.mCurrentFocus    KeyWaiter.mFinished，当一个输入事件被处理后，但该事件没有完成时 mFinished=false，事件完成后 mFinished=true；所以ANR 产生时mFinished =false；

ANR检测机制

对与按键响应不及时（keyDispatchingTimedOut）的ANR，当触发一个造成ANR的键盘事件后，如果不再有任何输入操作，无论多长时间ANR对话框是不会弹出的，只有在下一次输入事件产生后5秒才会弹出ANR。简单说就是，输入事件ANR的检测需要下一次输入事件来触发其检测机制，并触发ANR。

实例二： traces.txt 分析：

在service中出现了阻塞，阻塞的原因是多线程死锁导致。

"BT EventLoop" prio=5 tid=39 MONITOR  | group="main" sCount=1 dsCount=0 obj=0x40760918 self=0x5a0698  | sysTid=26547 nice=0 sched=0/0 cgrp=[no-cpu-subsys] handle=5900336  at android.server.BluetoothService.addRemoteDeviceProperties(BluetoothService.java:~1404)  - waiting to lock <0x405705e0> (a android.server.BluetoothService) held by threadid=9 (android.server.ServerThread)  at android.server.BluetoothEventLoop.addDevice(BluetoothEventLoop.java:143)  at android.server.BluetoothEventLoop.onDeviceFound(BluetoothEventLoop.java:174)  at dalvik.system.NativeStart.run(Native Method)  at dalvik.system.NativeStart.run(Native Method)

"Binder Thread #8" prio=5 tid=50 MONITOR  | group="main" sCount=1 dsCount=0 obj=0x40717e60 self=0x3e6660  | sysTid=506 nice=0 sched=0/0 cgrp=[no-cpu-subsys] handle=4088552  at android.server.BluetoothService.getBondState(BluetoothService.java:~1342)  - waiting to lock <0x405705e0> (a android.server.BluetoothService) held by threadid=9 (android.server.ServerThread)  at android.bluetooth.IBluetooth$Stub.onTransact(IBluetooth.java:237)  at android.os.Binder.execTransact(Binder.java:320)  at dalvik.system.NativeStart.run(Native Method)

"android.server.ServerThread" prio=5 tid=9 NATIVE  | group="main" sCount=1 dsCount=0 obj=0x4050fab8 self=0x2b7ef0  | sysTid=309 nice=-2 sched=0/0 cgrp=[no-cpu-subsys] handle=2850856  at android.server.BluetoothEventLoop.stopEventLoopNative(Native Method)  at android.server.BluetoothEventLoop.stop(BluetoothEventLoop.java:134)  at android.server.BluetoothService.finishDisable(BluetoothService.java:353)  at android.server.BluetoothService.access$200(BluetoothService.java:77)  at android.server.BluetoothService$1.handleMessage(BluetoothService.java:504)  at android.os.Handler.dispatchMessage(Handler.java:99)  at android.os.Looper.loop(Looper.java:130)  at com.android.server.ServerThread.run(SystemServer.java:563)

以上log可以看出，有多个线程被tid=9 阻塞，而线程tid =9 是要完成什么操作呢？从stack trace可以看出是关闭蓝牙操作。 Tid 持有BluetoothService文件锁，最后是 stopEventLoopNative()本地调用。

其中两个线程tid=50和tid = 39, 都是要申请BluetoothService文件锁。其中tid =39是处理设备查找到后的来自JNI层的回调操作: onDeviceFound()。通过分析BT JNI层的代码实现，可以发现此处发生了死锁。

问题解决方法

由于以上代码实现属于原生架构设计，我们解决此问题的策略是避免死锁的发生。我们的解决策略是当蓝牙关闭时，不去对DeviceFound 消息进行处理。