解决google原生代码死锁问题

1.背景

测试同学在下午正常测试的时候突然出现系统重启,然后开机界面一直在转圈无法进入Launcher。

2.调查过程

2.1 问题初诊断
不幸的是车机adb口不好使,首先通过串口进入在Android系统,配置usb模式,让adb好使,通过ADB进入到车机。

进入车机之后使用`uptime`指令查看系统启动时间,看是Android重启,还是QNX重启了。

一看uptime的系统启动时间,发现才10分多钟,明显是QNX重启了。那这个问题从一个问题发散成两个问题了。
  • QNX故障导致系统整体重启

  • 重启后系统无法进入Launcher

    此文章主要记录问题2:系统服务发生死锁导致无法进入Launcher。

2.2 深入调查

2.2.1 查看进程启动情况

`ps -A`查看所有进程启动情况
......
mdnsr          733     1    5628   1184 poll_sche+          0 S mdnsd
root           745     2       0      0 worker_th+          0 I [kworker/4:3]
radio          747     1   13924   3064 poll_sche+          0 S ipacm-diag
radio          751     1   22164   6476 futex_wai+          0 S ipacm
# systemserver启动
system         761   341 4523728 162136 ep_poll             0 S system_server
root           866     2       0      0 worker_th+          0 I [kworker/u13:2]
root           949     2       0      0 worker_th+          0 I [kworker/1:4]
root           950     2       0      0 worker_th+          0 I [kworker/2:3]
root           951     2       0      0 worker_th+          0 I [kworker/2:4]
root           952     2       0      0 worker_th+          0 I [kworker/2:5]
root           954     2       0      0 worker_th+          0 I [kworker/2:6]
root           955     2       0      0 worker_th+          0 I [kworker/1:5]
root           957     2       0      0 worker_th+          0 I [kworker/1:6]
root           964     2       0      0 worker_th+          0 I [kworker/1:7]
root          1006     2       0      0 worker_th+          0 I [kworker/0:3]
root          1007     2       0      0 worker_th+          0 I [kworker/1:8]
root          1008     2       0      0 worker_th+          0 I [kworker/0:4]
root          1012     2       0      0 worker_th+          0 I [kworker/0:5]
root          1015     2       0      0 worker_th+          0 I [kworker/0:6]
root          1017     2       0      0 worker_th+          0 I [kworker/0:7]
root          1020     2       0      0 worker_th+          0 I [kworker/0:8]
root          1021     2       0      0 worker_th+          0 I [kworker/0:9]
root          1022     2       0      0 worker_th+          0 I [kworker/0:10]
root          1023     2       0      0 worker_th+          0 I [kworker/0:11]
root          1025     2       0      0 worker_th+          0 I [kworker/0:12]
# 场景服务启动
system        1045   341 4361960  67808 ep_poll             0 S com.gxa.car.scene

可以看到SystemServer已经启动完毕,在startOtherService已经把管理上层场景的服务已经拉起,但是后面就没有服务起来了。因此初步判断是有系统服务卡死了!

使用`kill -3 761`将当前所有所有线程的堆栈取出来。

在`/data/anr`路径下会生成一个名为**“trace_00”**的文件。导出此文件,开始分析是哪些线程发送卡死了。

2.2.2 分析trace日志

正常看trace一半先看main线程,但是看车机现象是一直卡在开机界面,不会重启,因此可以初步判断不是主线程卡死了,如果是主线程卡死了,watchdog会直接触发重启Android。不过还是看一下main线程状态。
"main" prio=5 tid=1 Blocked
  | group="main" sCount=1 dsCount=0 flags=1 obj=0x74726b48 self=0x7b90614c00
  | sysTid=729 nice=-2 cgrp=default sched=0/0 handle=0x7c16087548
  | state=S schedstat=( 822945383 262318239 1924 ) utm=56 stm=25 core=1 HZ=100
  | stack=0x7fdac06000-0x7fdac08000 stackSize=8MB
  | held mutexes=
  at com.android.server.am.ActivityManagerService.registerReceiver(ActivityManagerService.java:20857)
  - waiting to lock <0x033008f9> (a com.android.server.am.ActivityManagerService) held by thread 86
  at android.app.ContextImpl.registerReceiverInternal(ContextImpl.java:1488)
  at android.app.ContextImpl.registerReceiver(ContextImpl.java:1449)
  at com.android.server.net.NetworkStatsService.systemReady(NetworkStatsService.java:398)
  at com.android.server.SystemServer.lambda$startOtherServices$4(SystemServer.java:1851)
  at com.android.server.-$$Lambda$SystemServer$s9erd2iGXiS7bbg_mQJUxyVboQM.run(lambda:-1)
  at com.android.server.am.ActivityManagerService.systemReady(ActivityManagerService.java:15282)
  at com.android.server.SystemServer.startOtherServices(SystemServer.java:1777)
  at com.android.server.SystemServer.run(SystemServer.java:444)
  at com.android.server.SystemServer.main(SystemServer.java:303)
  at java.lang.reflect.Method.invoke(Native method)
  at com.android.internal.os.RuntimeInit$MethodAndArgsCaller.run(RuntimeInit.java:493)
  at com.android.internal.os.ZygoteInit.main(ZygoteInit.java:838)

main线程registerReceiver()方法中等待<0x033008f9>这把锁。顺藤摸瓜,看看哪个线程持有这把锁。

"Binder:729_7" prio=5 tid=86 Blocked
  | group="main" sCount=1 dsCount=0 flags=1 obj=0x12e80020 self=0x7b87c51000
  | sysTid=1259 nice=-2 cgrp=default sched=0/0 handle=0x7b6e7df4f0
  | state=S schedstat=( 3735363 3189481 17 ) utm=0 stm=0 core=2 HZ=100
  | stack=0x7b6e6e4000-0x7b6e6e6000 stackSize=1009KB
  | held mutexes=
  at com.android.server.wm.WindowManagerService.deferSurfaceLayout(WindowManagerService.java:2894)
  - waiting to lock <0x09464241> (a com.android.server.wm.WindowHashMap) held by thread 20
  at com.android.server.am.ActivityManagerService.handleAppDiedLocked(ActivityManagerService.java:5928)
  at com.android.server.am.ActivityManagerService.appDiedLocked(ActivityManagerService.java:6107)
  at com.android.server.am.ActivityManagerService$AppDeathRecipient.binderDied(ActivityManagerService.java:1885)
  - locked <0x033008f9> (a com.android.server.am.ActivityManagerService)
  at android.os.BinderProxy.sendDeathNotice(Binder.java:1193)

名为Binder:729_7的86号线程持有main线程的<0x033008f9>锁,但是该线程执行deferSurfaceLayout方法依赖<0x09464241>锁(锁的名字WindowHashMap的实例,看源码mWindowMap这个对象)释放。继续顺藤摸瓜。

"android.display" prio=5 tid=20 Blocked
  | group="main" sCount=1 dsCount=0 flags=1 obj=0x12c40f88 self=0x7b907ddc00
  | sysTid=806 nice=-4 cgrp=default sched=0/0 handle=0x7b74e0a4f0
  | state=S schedstat=( 28085321 36714886 210 ) utm=1 stm=1 core=3 HZ=100
  | stack=0x7b74d07000-0x7b74d09000 stackSize=1041KB
  | held mutexes=
  at com.android.server.policy.PhoneWindowManager.canDismissBootAnimation(PhoneWindowManager.java:7637)
  - waiting to lock <0x0a6033e6> (a java.lang.Object) held by thread 13
  at com.android.server.wm.WindowManagerService.performEnableScreen(WindowManagerService.java:3455)
  - locked <0x09464241> (a com.android.server.wm.WindowHashMap)
  at com.android.server.wm.WindowManagerService.access$1100(WindowManagerService.java:272)
  at com.android.server.wm.WindowManagerService$H.handleMessage(WindowManagerService.java:4861)
  at android.os.Handler.dispatchMessage(Handler.java:106)
  at android.os.Looper.loop(Looper.java:193)
  at android.os.HandlerThread.run(HandlerThread.java:65)
  at com.android.server.ServiceThread.run(ServiceThread.java:44)

android.display线程持有<0x09464241>锁,需要释放该锁,依赖执行canDismissBootAnimation()方法释放<0x0a6033e6>锁(源码中该锁名字叫mLock),继续顺藤摸瓜。

"android.ui" prio=5 tid=13 Blocked
  | group="main" sCount=1 dsCount=0 flags=1 obj=0x12c408b0 self=0x7b907d7c00
  | sysTid=799 nice=-2 cgrp=default sched=0/0 handle=0x7b756324f0
  | state=S schedstat=( 24267703 15746873 101 ) utm=2 stm=0 core=0 HZ=100
  | stack=0x7b7552f000-0x7b75531000 stackSize=1041KB
  | held mutexes=
  at com.android.server.wm.WindowManagerService$LocalService.waitForAllWindowsDrawn(WindowManagerService.java:7370)
  - waiting to lock <0x09464241> (a com.android.server.wm.WindowHashMap) held by thread 20
  at com.android.server.policy.PhoneWindowManager.finishKeyguardDrawn(PhoneWindowManager.java:6885)
  at com.android.server.policy.PhoneWindowManager.screenTurningOn(PhoneWindowManager.java:6938)
  - locked <0x0a6033e6> (a java.lang.Object)
  at com.android.server.policy.PhoneWindowManager.systemBooted(PhoneWindowManager.java:7631)
  at com.android.server.wm.WindowManagerService.enableScreenAfterBoot(WindowManagerService.java:3392)
  at com.android.server.am.ActivityManagerService.enableScreenAfterBoot(ActivityManagerService.java:7993)
  at com.android.server.am.ActivityManagerService.ensureBootCompleted(ActivityManagerService.java:8162)
  at com.android.server.am.ActivityManagerService$UiHandler.handleMessage(ActivityManagerService.java:2033)
  at android.os.Handler.dispatchMessage(Handler.java:106)
  at android.os.Looper.loop(Looper.java:193)
  at android.os.HandlerThread.run(HandlerThread.java:65)
  at com.android.server.ServiceThread.run(ServiceThread.java:44)
  at com.android.server.UiThread.run(UiThread.java:43)

android.ui线程持有<0x0a6033e6>锁,执行依赖waitForAllWindowsDrawn()依赖<0x09464241>释放!!!!

问题终于找到了

android.display线程持<0x09464241>mWindowMap对象锁,依赖<0x0a6033e6>mLock对象锁释放。

android.ui线程持有<0x0a6033e6>mLock对象锁,依赖<0x09464241>mWindowMap对象锁释放。

发生循环依赖了。导致死锁的场景发生!!!

解决思路:发生死锁一般解决办法就是翻看源码解开其中一个方法的锁即可。

2.3源码调查

从上面分析看主要是执行canDismissBootAnimation()和waitForAllWindowsDrawn()中造成循环依赖了。因此直接调查这两个方法。

/frameworks/base/services/core/java/com/android/server/policy/PhoneWindowManager.java
@Override
public boolean canDismissBootAnimation() {
    synchronized (mLock) {
        return mKeyguardDrawComplete;
    }
}
/frameworks/base/services/core/java/com/android/server/wm/WindowManagerService.java
@Override
public void waitForAllWindowsDrawn(Runnable callback, long timeout) {
    boolean allWindowsDrawn = false;
    synchronized (mWindowMap) {
        mWaitingForDrawnCallback = callback;
        getDefaultDisplayContentLocked().waitForAllWindowsDrawn();
        mWindowPlacerLocked.requestTraversal();
        mH.removeMessages(H.WAITING_FOR_DRAWN_TIMEOUT);
        if (mWaitingForDrawn.isEmpty()) {
            allWindowsDrawn = true;
        } else {
            mH.sendEmptyMessageDelayed(H.WAITING_FOR_DRAWN_TIMEOUT, timeout);
            checkDrawnWindowsLocked();
        }
    }
    if (allWindowsDrawn) {
        callback.run();
    }
}

初步一看,canDismissBootAnimation()方法的mLock锁只是为了保证返回mKeyguardDrawComplete局部变量的原子性。而waitForAllWindowsDrawn()方法的mWindowMap是为了保证那么大一段代码的原子性。

解决办法很简单,移除mKeyguardDrawComplete返回的锁即可。

2.4 解决后代码

/frameworks/base/services/core/java/com/android/server/policy/PhoneWindowManager.java
@Override
public boolean canDismissBootAnimation() {
    return mKeyguardDrawComplete;
}

3.回顾

咋一想,居然google原生代码也出现了死锁问题,还想着是不是可以取给google提交一个bug和修复方案,万一采纳了呢,那不是牛逼了。

由于当前项目用的Android P的代码,于是赶紧去看看Android Q 谷歌有没有修复该代码。
@Override
public boolean canDismissBootAnimation() {
    return mDefaultDisplayPolicy.isKeyguardDrawComplete();
}
# frameworks/base/services/core/java/com/android/server/wm/DisplayPolicy.java
public boolean isKeyguardDrawComplete() {
        return mKeyguardDrawComplete;
    }

哎哎哎,还是太年轻,too young,too simple了。看来Android P的漏洞,Android Q已经修复了,修复的方法和我开始调查的时候修复的方法一样,还是挺开心的。因此顺利提交代码到项目中了。

©著作权归作者所有,转载或内容合作请联系作者
  • 序言:七十年代末,一起剥皮案震惊了整个滨河市,随后出现的几起案子,更是在滨河造成了极大的恐慌,老刑警刘岩,带你破解...
    沈念sama阅读 214,776评论 6 496
  • 序言:滨河连续发生了三起死亡事件,死亡现场离奇诡异,居然都是意外死亡,警方通过查阅死者的电脑和手机,发现死者居然都...
    沈念sama阅读 91,527评论 3 389
  • 文/潘晓璐 我一进店门,熙熙楼的掌柜王于贵愁眉苦脸地迎上来,“玉大人,你说我怎么就摊上这事。” “怎么了?”我有些...
    开封第一讲书人阅读 160,361评论 0 350
  • 文/不坏的土叔 我叫张陵,是天一观的道长。 经常有香客问我,道长,这世上最难降的妖魔是什么? 我笑而不...
    开封第一讲书人阅读 57,430评论 1 288
  • 正文 为了忘掉前任,我火速办了婚礼,结果婚礼上,老公的妹妹穿的比我还像新娘。我一直安慰自己,他们只是感情好,可当我...
    茶点故事阅读 66,511评论 6 386
  • 文/花漫 我一把揭开白布。 她就那样静静地躺着,像睡着了一般。 火红的嫁衣衬着肌肤如雪。 梳的纹丝不乱的头发上,一...
    开封第一讲书人阅读 50,544评论 1 293
  • 那天,我揣着相机与录音,去河边找鬼。 笑死,一个胖子当着我的面吹牛,可吹牛的内容都是我干的。 我是一名探鬼主播,决...
    沈念sama阅读 39,561评论 3 414
  • 文/苍兰香墨 我猛地睁开眼,长吁一口气:“原来是场噩梦啊……” “哼!你这毒妇竟也来了?” 一声冷哼从身侧响起,我...
    开封第一讲书人阅读 38,315评论 0 270
  • 序言:老挝万荣一对情侣失踪,失踪者是张志新(化名)和其女友刘颖,没想到半个月后,有当地人在树林里发现了一具尸体,经...
    沈念sama阅读 44,763评论 1 307
  • 正文 独居荒郊野岭守林人离奇死亡,尸身上长有42处带血的脓包…… 初始之章·张勋 以下内容为张勋视角 年9月15日...
    茶点故事阅读 37,070评论 2 330
  • 正文 我和宋清朗相恋三年,在试婚纱的时候发现自己被绿了。 大学时的朋友给我发了我未婚夫和他白月光在一起吃饭的照片。...
    茶点故事阅读 39,235评论 1 343
  • 序言:一个原本活蹦乱跳的男人离奇死亡,死状恐怖,灵堂内的尸体忽然破棺而出,到底是诈尸还是另有隐情,我是刑警宁泽,带...
    沈念sama阅读 34,911评论 5 338
  • 正文 年R本政府宣布,位于F岛的核电站,受9级特大地震影响,放射性物质发生泄漏。R本人自食恶果不足惜,却给世界环境...
    茶点故事阅读 40,554评论 3 322
  • 文/蒙蒙 一、第九天 我趴在偏房一处隐蔽的房顶上张望。 院中可真热闹,春花似锦、人声如沸。这庄子的主人今日做“春日...
    开封第一讲书人阅读 31,173评论 0 21
  • 文/苍兰香墨 我抬头看了看天上的太阳。三九已至,却和暖如春,着一层夹袄步出监牢的瞬间,已是汗流浃背。 一阵脚步声响...
    开封第一讲书人阅读 32,424评论 1 268
  • 我被黑心中介骗来泰国打工, 没想到刚下飞机就差点儿被人妖公主榨干…… 1. 我叫王不留,地道东北人。 一个月前我还...
    沈念sama阅读 47,106评论 2 365
  • 正文 我出身青楼,却偏偏与公主长得像,于是被迫代替她去往敌国和亲。 传闻我的和亲对象是个残疾皇子,可洞房花烛夜当晚...
    茶点故事阅读 44,103评论 2 352

推荐阅读更多精彩内容