对于Android平台的工程师来说，ANR应该是每个人都会遇到的问题，因为导致它的原因有很多，例如在主线程进行耗时操作，调用大量cpu资源进行复杂的预算等，并且可能在大多数情况下，这类问题不会发生，只会在极端特殊的情况下暴露(例如很长时间的自动化脚本测试，monkey测试)，所以我们必须得学会如何去分析这类问题，才能让模块的性能经得住考验。
一. 什么是ANR?为什么会有ANR发生?
如果当你进行一些操作之后，发现手机屏幕上出现类似上面的dialog，那么很不幸，你中招了。。。
ANR，Application Not Responding，即应用无响应。
一般来说，当应用对用户的交互没有反应时，系统就会弹出上述的ANR dialog。这种情况一般发生在如主线程被IO操作block住了，主线程进行了大量的例如读取数据库的操作等。
从google官方文档上介绍来看，主要由以下两种情况引起:
1. 应用在5秒内对于用户的输入事件无响应
2. BroadcastReceiver在10秒内不能完成onReceive()方法的执行
Note: 上述的时间是基于Google原生的Code，国内不少厂商因为某些原因会把这些时间延长，请以具体的vendor代码为准
二. NFC为什么会有ANR问题发生
首先和没接触过NFC的朋友介绍下NFC。
NFC，Near field communicatwww.yghrcp88.cn ion，即近场通讯，是由非接触式射频识别（RFID）演变而来的短距离无线电技术，由Nokia, Sony, NXP共同研发。在国外，如日本，这种技术运用的已经十分广泛，无论从出行到购物，哪里都有Felica(日本使用的NFC标准)的身影。然而国内因为某宝过于强大和人性化，NFC技术推动任重而道远。但是随着如小米钱包等应用开始使用NFC来模拟公交卡以及银行卡方便用户的生活，个人认为，未来是美好的！！！
作为一个Local Connectivity的重要模块，NFC不仅可以进行Read/Write Tag，而且可以通过Android Beam（Android 4.0开始支持的点对点传输的feature）传输文件。handover的功能更是让NFC成为一个wifi和bt快速建立链接的桥梁，极大的方便了用户的近距离传输的需求。也正是因为这些原因，在特殊情况下的并发操作，就会导致NFC出现ANR的问题，下面以一个简单的NFC相互调用死锁导致的ANR案例进行分析。
三. 案例分析
首先推荐给各位一个查看源代码的网站，http://androidxref.com/， 如果没有VPN的话，这个网站看源码还是比较给力的，可能大多数哥们都知道，呵呵～
下面先简单介绍下导致ANR发生的操作:
在NFC关闭的情况下，(Android Beam必须是随着NFC的关闭自动关闭的，否则因为相应的component被disable,分享列表中找不到Android Beam选项)，通过Android Beam去分享一个文件，这种情况下会弹出一个提示需要开启NFC功能的Dialog,点击确定，正常情况下，会出现Android Beam的图片缩放界面如下图，但是ANR发生时整个界面没有任何反应，几秒钟后，系统就会弹出Settings ANR的dialog。
对于ANR问题的分析，我们应该首先去找问题发生时，手机自动保存在data/anr目录下的trace.txt文件，这是最能直观反应问题发生时堆栈的信息以及各种资源的使用情况。
因为NfcService是NFC上层最核心的一个文件，底层的所有处理都会一层层往上抛给NfcService,上层的API接口也只会通过NfcService去调用具体的底层实现。所有我们现在trace.txt中以NfcService作为关键字进行搜索，看到如下trace.log
[plain] view plain copy
"Binder_1" prio=5 tid=8 Blocked（prio 进程号， tid 线程号)
| group="main" sCount=1 dsCount=0 obj=0x12c8b0a0 self=0x7f8ef53400
| sysTid=2903 nice=0 cgrp=default sched=0/0 handle=0x7f93af5440
| state=S schedstat=( 81420425 126587653 792 ) utm=3 stm=5 core=0 HZ=100
| stack=0x7f939f9000-0x7f939fb000 stackSize=1013KB
| held mutexes=
at com.android.nfc.NfcService$NfcAdapterService.getState(NfcService.java:1813)
- waiting to lock <0x0196c7d2> (a com.android.nfc.NfcService) held by thread 18 --->被线程18阻塞
at android.nfc.INfcAdapter$Stub.onTransact(INfcAdapter.java:95)
at android.os.Binder.execTransact(Binder.java:477)</span>
从上面的trace log可以看到，NfcService$NfcAdapterService.getState()想获得0x0196c7d2，即NfcService对象锁，代码如下
[java] view plain copy
@Override
public int getState() throws RemoteException {
synchronized (NfcService.this) {
return mState;
}
}
但是这个对象锁并不能马上获得，因为thread 18正在占用，看下线程18的堆栈信息
[plain] view plain copy
"Binder_3" prio=5 tid=18 Blocked
| group="main" sCount=1 dsCount=0 obj=0x12e120a0 self=0x7f94114200
| sysTid=3414 nice=0 cgrp=default sched=0/0www.wx1677.com/ handle=0x7f7c9a0440
| state=S schedstat=( 67563697 66692461 439 ) utm=0 stm=6 core=0 HZ=100
| stack=0x7f7c8a4000-0x7f7c8a6000 stackSize=1013KB
| held mutexes=
at com.android.nfc.P2pLinkManager.isLlcpActive(P2pLinkManager.java:410)
- waiting to lock <0x0c8140a3> (a com.android.nfc.P2pLinkManager) held by thread 1 --->被线程1阻塞
at com.android.nfc.NfcService$NxpExtrasService._open(NfcService.java:3173)
- locked <0x0196c7d2> (a com.android.nfc.NfcService)
at com.android.nfc.NfcService$NxpExtrasService.open(NfcService.java:3149)
at com.nxp.intf.INxpExtrasService$Stub.onTransact(INxpExtrasService.java:55)
at android.os.Binder.execTransact(Binder.java:477)
上面的log可以看出，NfcService的对象锁正在被NfcService$NxpExtrasService._open()方法所持有，代码如下:
[java] view plain copy
private int _open(IBinder b) {
synchronized(NfcService.this) {
if (!isNfcEnabled()) {
return EE_ERROR_NFC_DISABLED;
}
if (mInProvisionMode) {
// Deny access to the NFCEE as long as the device is being setup
return EE_ERROR_IO;
}
if (mP2pLinkManager.isLlcpActive()) {
// Don't allow PN544-based devices to open the SE while the LLCP
// link is still up or in a debounce state. This avoids race
// conditions in the NXP stack around P2P/SMX switching.
return EE_ERROR_EXT_FIELD;
}
上面的这个方法迟迟不能执行完毕，是因为调用了mP2pLinkManager.isLlcpActive()，这个方法希望获得0x0cwww.zhenlyule.cn/ 8140a3，即P2pLinkManager的对象锁，但是这个对象锁也不能马上获得，正在被thread1挂起。
[java] view plain copy
public boolean isLlcpActive() {
synchronized (this) { ---> P2pLinkManager对象锁
return mLinkState != LINK_STATE_DOWN;
}
}
那么我们继续看下thread1的trace信息:
[plain] view plain copy
"main" prio=5 tid=1 Blocked
| group="main" sCount=1 dsCount=0www.myqunliphoto.com obj=0x762a8fb8 self=0x7f955fba00
| sysTid=2880 nice=0 cgrp=default sched=0/0 handle=0x7f98da8fe8
| state=S schedstat=( 344423025 553179190 922 ) utm=24 stm=10 core=3 HZ=100
| stack=0x7fca15d000-0x7fca15f000 stackSize=8MB
| held mutexes=
at com.android.nfc.NfcService.playSound(NfcService.java:1509)
- waiting to lock <0x0196c7d2> (a com.android.nfc.NfcService) held by thread 18
at com.android.nfc.P2pEventManager.onP2pNfcTapRequested(P2pEventManager.java:81)
at com.android.nfc.P2pLinkManager.onManualBeamInvoke(P2pLinkManager.java:455)
- locked <0x0c8140a3> (a com.android.nfc.P2pLinkManager)
at com.android.nfc.NfcService$NfcServiceHandler.handleMessage(NfcService.java:4366)
at android.os.Handler.dispatchMessage(Handler.java:102)
at android.os.Looper.loop(Looper.java:148)
at android.app.ActivityThread.main(ActivityThread.java:5541)
at java.lang.reflect.Method.invoke!(Native method)
at com.android.internal.os.ZygoteInit$MethodAndArgsCaller.run(ZygoteInit.java:935)
at com.android.internal.os.ZygoteInit.main(ZygoteInit.java:726)
0x0c8140a3这个锁正在被P2pLinkManager.onManualBeamInvoke()方法占用，代码如下:
[java] view plain copy
public void onManualBeamInvoke(BeamShareData shareData) {
synchronized (P2pLinkManager.this) {
if (mLinkState != LINK_STATE_DOWN) {
return;
}
if (mForegroundUtils.getForegroundUids().contains(mNdefCallbackUid)) {
// Try to get data from the registered NDEF callback
prepareMessageToSend(false);
} else {
mMessageToSend = null;
mUrisToSend = null;
}
if (mMessageToSend == null && mUrisToSend == null && shareData != null) {
// No data from the NDEF callback, get data from ShareData
if (shareData.uris != null) {
mUrisToSend = shareData.uris;
} else if (shareData.ndefMessage != null) {
mMessageToSend = shareData.ndefMessage;
}
mUserHandle = shareData.userHandle;
}
if (mMessageToSend != null ||
(mUrisToSend != null && mHandoverDataParser.isHandoverSupported())) {
mSendState = SEND_STATE_PENDING;
mEventListener.onP2pNfcTapRequested();
scheduleTimeoutLocked(MSG_WAIT_FOR_LINK_TIMEOUT, WAIT_FOR_LINK_TIMEOUT_MS);
}
}
}
上面的方法里会去调用mEventListener.onP2pNfcTapRequested()，代码如下:
[java] view plain copy
@Override
public void onP2pNfcTapRequested() {
mNfcService.playSound(NfcService.SOUND_START);
mNdefSent = false;
mNdefReceived = false;
mInDebounce = false;
mVibrator.vibrate(VIBRATION_PATTERN, -1);
这个方法会调用NfcService里面的mNfcService.playSound()。trace log显示playSound()会去想持有0x0196c7d2即NfcService对象。看下代码是不是这样:
[java] view plain copy
public void playSound(int sound) {
synchronized (this) { ---> NfcService对象锁
if (mSoundPool == null) {
Log.w(TAG, "Not playing sound when NFC is disabled");
return;
}
这里请注意，上面NfcService$NxpExtrasService._open()正在持有的对象也是这个。
现在基本知道什么情况下，我们回过头来再捋一捋。
NfcAdapterService.getState希望持有NfcService对象，无法获得block
NfcService对象正在被NxpExtrasService._open()持有, 这个方法无法执行完毕，被mP2pLinkManager.isLlcpActive() block
mP2pLinkManager.isLlcpActive()希望持有P2pLinkManager的对象，无法获得 block
P2pLinkManager对象正在被onManualBeamInvoke()方法持有，这个方法无法执行完毕，被mEventListener.onP2pNfcTapRequested() block
mEventListener.onP2pNfcTapRequested() 无法执行完毕，被mNfcService.playSound() block
mNfcService.playSound() 希望持有NfcService的对象，这个对象被最上面的NxpExtrasService._open()持有
所以总体来说，就是正在占用NfcService锁的NxpExtrasService._open()需要P2pLinkManager的锁释放，而正在占用P2pLinkManager这个锁的onManualBeamInvoke()方法需要NfcService的锁释放，双方互不让步，造成死锁。
暂时想到的解决的策略就是将
[java] view plain copy
public void playSound(int sound) {
synchronized (this) { <---> NfcService对象锁
if (mSoundPool == null) {
Log.w(TAG, "Not playing sound when NFC is disabled");
return;
}
这个锁的范围缩小，换成一个私有锁。
即 Object mPlaySoundLock = new Obejct()，然后将this替换成mPlaySoundLock即可。