NFC问题分析之死锁引起的ANR

【摘要】 对于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 communication,即近场通讯,是由非接触式射频识别(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

"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对象锁,代码如下

        @Override
        public int getState() throws RemoteException {
            synchronized (NfcService.this) {
                return mState;
            }
        }

但是这个对象锁并不能马上获得,因为thread 18正在占用,看下线程18的堆栈信息

"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/0 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()方法所持有,代码如下:

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(),这个方法希望获得0x0c8140a3,即P2pLinkManager的对象锁,但是这个对象锁也不能马上获得,正在被thread1挂起。

public boolean isLlcpActive() {
        synchronized (this) { ---> P2pLinkManager对象锁
            return mLinkState != LINK_STATE_DOWN;
        }
    }

那么我们继续看下thread1的trace信息:

"main" prio=5 tid=1 Blocked
  | group="main" sCount=1 dsCount=0 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()方法占用,代码如下:

 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(),代码如下:

@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对象。看下代码是不是这样:

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的锁释放,双方互不让步,造成死锁。

暂时想到的解决的策略就是将

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即可。

注:本人水平有限,欢迎各位大牛批评指正,谢谢~

时间: 2024-08-10 19:10:30

NFC问题分析之死锁引起的ANR的相关文章

查看死锁原因 /data/anr/traces.txt

Android ANR这个错误大家并不陌生,但是从Android 2.2开始出错的ANR信息会自动上传给Google进行系统分析改进,当然了你的应用ANR错误其实保存在一个文件中,在/data/anr/traces.txt文件中,如果你的Android设备没有Root越狱过,可以将你的软件装在模拟器上分析,模拟器可以直接使用Eclipse中的DDMS里的File Explorer来打开,如下图: 虽然traces.txt是一个文本文件,不过使用windows上的记事本打开可能无法正常处理linu

[Android Pro] 通过Android trace文件分析死锁ANR

转载自: http://blog.csdn.net/oujunli/article/details/9102101#reply 对于从事Android开发的人来说,遇到ANR(Application Not Responding)是比较常见的问题.一般情况下,如果有ANR发生,系统都会在/data/anr/目录下生成trace文件,通过分析trace文件,可以定位产生ANR的原因.产生ANR的原因有很多,比如CPU使用过高.事件没有得到及时的响应.死锁等,下面将通过一次因为死锁导致的ANR问题,

&lt;转&gt;一个最不可思议的MySQL死锁分析

1 死锁问题背景 1 1.1 一个不可思议的死锁 1 1.1.1 初步分析 3 1.2 如何阅读死锁日志 3 2 死锁原因深入剖析 4 2.1 Delete操作的加锁逻辑 4 2.2 死锁预防策略 5 2.3 剖析死锁的成因 6 3 总结 7 死锁问题背景 做MySQL代码的深入分析也有些年头了,再加上自己10年左右的数据库内核研发经验,自认为对于MySQL/InnoDB的加锁实现了如指掌,正因如此,前段时间,还专门写了一篇洋洋洒洒的文章,专门分析MySQL的加锁实现细节:<MySQL加锁处理分

一个最不可思议的MySQL死锁分析

一个最不可思议的MySQL死锁分析 死锁问题背景 做MySQL代码的深入分析也有些年头了,再加上自己10年左右的数据库内核研发经验,自认为对于MySQL/InnoDB的加锁实现了如指掌,正因如此,前段时间,还专门写了一篇洋洋洒洒的文章,专门分析MySQL的加锁实现细节:<MySQL加锁处理分析>. 但是,昨天"润洁"同学在<MySQL加锁处理分析>这篇博文下咨询的一个MySQL的死锁场景,还是彻底把我给难住了.此死锁,完全违背了本人原有的锁知识体系,让我百思不得

Java死锁范例以及如何分析死锁(转载自ImportNew)

本文由 ImportNew - 范琦琦 翻译自 journaldev.欢迎加入翻译小组.转载请见文末要求. 死锁是两个甚至多个线程被永久阻塞时的一种运行局面,这种局面的生成伴随着至少两个线程和两个或者多个资源.在这里我已写好一个简单的程序,它将会引起死锁方案然后我们就会明白如何分析它. Java死锁范例 ThreadDeadlock.java 1 2 3 4 5 6 7 8 9 10 11 12 13 14 15 16 17 18 19 20 21 22 23 24 25 26 27 28 29

android ANR traces.txt文件导出分析

来源:https://blog.csdn.net/qq_31939617/article/details/79756718 一:什么是ANR ANR:Application Not Responding,即应用无响应,ANR找原因,基本是通过traces.txt文件分析的 先说发生ANR后,如何导出traces.txt文件(我的习惯是发生一次就导出,不然可能会有很多个traces.txt) 1.连接手机,开发者模式 2.使用cmd命令模式 这样就把所有的ANR文件夹下的文件导入出了,路径就是以c

Mysql死锁如何排查:insert on duplicate死锁一次排查分析过程

前言 遇到Mysql死锁问题,我们应该怎么排查分析呢?之前线上出现一个insert on duplicate死锁问题,本文将基于这个死锁问题,分享排查分析过程,希望对大家有帮助. 死锁案发还原 表结构: CREATE TABLE `song_rank` ( `id` int(11) NOT NULL AUTO_INCREMENT, `songId` int(11) NOT NULL, `weight` int(11) NOT NULL DEFAULT '0', PRIMARY KEY (`id`

死锁问题分析,间隙锁

线上某服务时不时报出如下异常(大约一天二十多次):"Deadlock found when trying to get lock;". Oh, My God! 是死锁问题.尽管报错不多,对性能目前看来也无太大影响,但还是需要解决,保不齐哪天成为性能瓶颈.     为了更系统的分析问题,本文将从死锁检测.索引隔离级别与锁的关系.死锁成因.问题定位这五个方面来展开讨论. 图1 应用日志 1 死锁是怎么被发现的? 1.1 死锁成因&&检测方法 左图那两辆车造成死锁了吗?不是!

Android ANR 知多少

极力推荐文章:欢迎收藏 Android 干货分享 阅读五分钟,每日十点,和您一起终身学习,这里是程序员Android ANR(Application Not Responding )应用无响应的简称,是为了在 APP卡死时,用户 可以强制退出APP的选择,从而避免卡机无响应问题,这是Android系统的一种自我保护机制. 通过本篇阅读,您将学习到以下内容 什么是ANR ANR的类型 ANR 产生的原因 如何分析解决 ANR问题 ANR 问题分析解决建议 MTK 平台 ANR问题分析 1. 什么是