稳定性 框架问题 疑难问题

一例系统死机案例分析

Debuggerd存在BUG导致系统死机

发布日期 2019-02-12

1. 问题现象

  • 屏幕没有任何刷新，输入事件无任何响应，即我们平时说的死机（冻屏）；

  • watchdog没有重启system_server；

  • 问题现场可以连接adb；

2. 初步分析

死机问题分析前的准备工作：
（1）拿到问题现场，及时充电以保证问题现场不被破坏；
（2）如果没有现场可以忽略这一步，通过kill -3 后面跟上system_server pid命令产生一份最新的traces文件；
（3）通过adb将/data/anr下的文件都pull出来；
（4）通过adb将/data/tombstones下的文件都pull出来；

拿到/data/anr下的traces文件之后首先搜索定位到system_server进程中各个线程的traces处，第一步先看watchdog线程当前处于什么状态，为什么没有重启手机，通过traces可以看到watchdog线程当前在做dumpStackTraces的操作，具体调用栈如下：

"watchdog" prio=5 tid=75 Native
  | group="main" sCount=1 dsCount=0 obj=0x12f45820 self=0x7f740a2e00
  | sysTid=2358 nice=0 cgrp=default sched=0/0 handle=0x7f6d899440
  | state=S schedstat=( 399746076 1302129598 2483 ) utm=19 stm=20 core=2 HZ=100
  | stack=0x7f6d797000-0x7f6d799000 stackSize=1037KB
  | held mutexes=
  kernel: __switch_to+0x70/0x7c
  kernel: unix_stream_recvmsg+0x260/0x6c0
  kernel: sock_aio_read.part.11+0xd0/0xe8
  kernel: sock_aio_read+0x1c/0x30
  kernel: do_sync_read+0x64/0x8c
  kernel: vfs_read+0xac/0x148
  kernel: SyS_read+0x44/0x84
  kernel: el0_svc_naked+0x20/0x28
  native: #00 pc 0000000000068eb8  /system/lib64/libc.so (read+4)
  native: #01 pc 000000000000a844  /system/lib64/libcutils.so (???)
  native: #02 pc 000000000000a8f4  /system/lib64/libcutils.so (dump_backtrace_to_file_timeout+56)
  native: #03 pc 00000000000d0230  /system/lib64/libandroid_runtime.so (???)
  native: #04 pc 000000000013d23c  /data/dalvik-cache/arm64/system@framework@boot.oat (Java_android_os_Debug_dumpNativeBacktraceToFile__ILjava_lang_String_2+160)
  at android.os.Debug.dumpNativeBacktraceToFile(Native method)
  at com.android.server.am.ActivityManagerService.dumpStackTraces(ActivityManagerService.java:4917)
  at com.android.server.am.ActivityManagerService.dumpStackTraces(ActivityManagerService.java:4881)
  at com.android.server.Watchdog.run(Watchdog.java:399)
  - locked <0x0659229a> (a com.android.server.Watchdog)

从调用栈中对应的文件和行号我们可以找到对应代码，具体如下：

393                } else if (waitState == WAITED_HALF) {
394                    if (!waitedHalf) {
395                        // We've waited half the deadlock-detection interval.  Pull a stack
396                        // trace and wait another half.
397                        ArrayList<Integer> pids = new ArrayList<Integer>();
398                        pids.add(Process.myPid());
399                        ActivityManagerService.dumpStackTraces(true, pids, null, null,
400                                NATIVE_STACKS_OF_INTEREST);
401                        waitedHalf = true;
402                    }
403                    continue;
404                }

从上面的代码中我们可以看到watchdog线程是在发生waitedHalf的时候做dumpStackTraces操作，但是在dumpStackTraces的过程中发生了block，导致watchdog线程无法正常重启system_server进程。

waitedHalf是watchdog监控的线程和monitor的block时间超过了watchdog超时的一半，正常情况下是block超过了30s，此时需要进行一次dumpStackTraces操作。

解释了watchdog为什么没有重启手机的问题之后，我们继续分析为什么输入事件无法响应的问题，继续看traces文件中InputReader线程的状态，发现block在AudioSystem.isStreamActive的binder调用上，导致无法获取和处理输入事件，InputReader线程的具体调用栈如下：

"InputReader" prio=10 tid=33 Native
  | group="main" sCount=1 dsCount=0 obj=0x1320a0a0 self=0x7f754fd600
  | sysTid=1723 nice=-8 cgrp=default sched=0/0 handle=0x7f6fd3c440
  | state=S schedstat=( 5439618537 1107252935 13071 ) utm=345 stm=198 core=0 HZ=100
  | stack=0x7f6fc40000-0x7f6fc42000 stackSize=1013KB
  | held mutexes=
  kernel: __switch_to+0x70/0x7c
  kernel: binder_thread_read+0x43c/0xef8
  kernel: binder_ioctl_write_read+0x190/0x294
  kernel: binder_ioctl+0x290/0x600
  kernel: do_vfs_ioctl+0x490/0x570
  kernel: SyS_ioctl+0x5c/0x88
  kernel: el0_svc_naked+0x20/0x28
  native: #00 pc 00000000000684e0  /system/lib64/libc.so (__ioctl+4)
  native: #01 pc 0000000000072508  /system/lib64/libc.so (ioctl+100)
  native: #02 pc 000000000002d584  /system/lib64/libbinder.so (_ZN7android14IPCThreadState14talkWithDriverEb+164)
  native: #03 pc 000000000002e050  /system/lib64/libbinder.so (_ZN7android14IPCThreadState15waitForResponseEPNS_6ParcelEPi+104)
  native: #04 pc 000000000002e2c4  /system/lib64/libbinder.so (_ZN7android14IPCThreadState8transactEijRKNS_6ParcelEPS1_j+176)
  native: #05 pc 0000000000025654  /system/lib64/libbinder.so (_ZN7android8BpBinder8transactEjRKNS_6ParcelEPS1_j+64)
  native: #06 pc 00000000000e9984  /system/lib64/libmedia.so (???)
  native: #07 pc 00000000000c2b0c  /system/lib64/libmedia.so (_ZN7android11AudioSystem14isStreamActiveE19audio_stream_type_tPbj+68)
  native: #08 pc 0000000000103a98  /system/lib64/libandroid_runtime.so (???)
  native: #09 pc 000000000027dc78  /data/dalvik-cache/arm64/system@framework@boot.oat (Java_android_media_AudioSystem_isStreamActive__II+140)
  at android.media.AudioSystem.isStreamActive(Native method)
  at com.android.server.policy.PhoneWindowManager.isAudioActive(PhoneWindowManager.java:2421)
  at com.android.server.policy.PhoneWindowManager.interceptVoluemeKeyStartCamera(PhoneWindowManager.java:2347)
  at com.android.server.policy.PhoneWindowManager.interceptKeyBeforeQueueingInternal(PhoneWindowManager.java:1066)
  at com.android.server.policy.PhoneWindowManager.interceptKeyBeforeQueueing(PhoneWindowManager.java:82)
  at com.android.server.wm.InputMonitor.interceptKeyBeforeQueueing(InputMonitor.java:357)
  at com.android.server.input.InputManagerService.interceptKeyBeforeQueueing(InputManagerService.java:1739)

顺着这个线索我们继续看AudioSystem.isStreamActive的binder调用的对端进程mediaserver的状态，为什么没有及时的处理InputReader线程发起的binder调用？

从traces文件中我们没有看到mediaserver的调用栈信息，所以需要通过问题现场的手机中来获取，如果没有问题现场则需要在下次复现时及时的dump mediaserver的调用栈信息。

获取native进程调用栈的方法可以通过debuggerd命令跟上native进程的pid，如：debuggerd -b $PID或者debuggerd $PID生成到tombstone文件中。

拿到问题现场后我们尝试通过debuggerd命令获取调用栈，但是发现无法获取，出现block的现象，这个时候怎么办？既然debuggerd无法获取那就先看看mediaserver进程当前处于什么状态，首先获取mediaserver的pid，具体命令如下：
$ ps -t | grep mediaserver
得到mediaserver的pid之后再获取mediaserver各个线程当前的状态，具体命令如下：
$ ps -t | grep $pid

打出的mediaserver各个线程的状态如下：

media 10518 1 326848 24216 do_signal_ 00f6f5c00c T /system/bin/mediaserver
media 10602 10518 326848 24216 do_signal_ 00f6f32694 T ApmTone
media 10603 10518 326848 24216 do_signal_ 00f6f32694 T ApmAudio
media 10604 10518 326848 24216 do_signal_ 00f6f32694 T ApmOutput
media 10605 10518 326848 24216 do_signal_ 00f6f5cec0 T mediaserver
media 10606 10518 326848 24216 do_signal_ 00f6f5be44 T mediaserver
media 10607 10518 326848 24216 do_signal_ 00f6f32694 T FastMixer
media 10608 10518 326848 24216 do_signal_ 00f6f32694 T AudioOut_2
media 10609 10518 326848 24216 do_signal_ 00f6f32694 T FastMixer
media 10610 10518 326848 24216 do_signal_ 00f6f32694 T AudioOut_4
media 10611 10518 326848 24216 do_signal_ 00f6f32694 T AudioOut_6
media 10612 10518 326848 24216 do_signal_ 00f6f32694 T FastMixer
media 10613 10518 326848 24216 do_signal_ 00f6f32694 T AudioOut_8
media 10618 10518 326848 24216 do_signal_ 00f6f32694 T soundTrigger cb
media 10619 10518 326848 24216 do_signal_ 00f6f5c00c T Binder_1
media 10620 10518 326848 24216 do_signal_ 00f6f5c00c T Binder_2
media 10621 10518 326848 24216 do_signal_ 00f6f5c00c T Binder_3
media 10624 10518 326848 24216 do_signal_ 00f6f32694 T DiracSetParamet
media 10743 10518 326848 24216 do_signal_ 00f6f5bd58 T Binder_4
media 12766 10518 326848 24216 do_signal_ 00f6f5c00c T Binder_5
media 23751 10518 326848 24216 do_signal_ 00f6f5c00c T Binder_6
media 29859 10518 326848 24216 do_signal_ 00f6f5c00c T Binder_7
media 3930 10518 326848 24216 do_signal_ 00f6f5c00c T Binder_8
media 12728 10518 326848 24216 do_signal_ 00f6f32694 T gle.mp3.decoder
media 12729 10518 326848 24216 do_signal_ 00f6f32694 T OMXCallbackDisp
media 14573 10518 326848 24216 do_signal_ 00f6f32694 T NuPlayerDriver
media 14575 10518 326848 24216 do_signal_ 00f6f32694 T generic
media 14579 10518 326848 24216 do_signal_ 00f6f32694 T NuPlayerRendere
media 14580 10518 326848 24216 do_signal_ 00f6f32694 T AudioTrack
media 14581 10518 326848 24216 do_signal_ 00f6f5c0a8 T Offload Callbac
media 14582 10518 326848 24216 do_signal_ 00f6f32694 T Offload Cbk
media 14583 10518 326848 24216 do_signal_ 00f6f32694 T AudioOut_2D86
media 14586 10518 326848 24216 do_signal_ 00f6f32694 T NPDecoder
media 14597 10518 326848 24216 ptrace_sto 00f6f5c0a8 t visualizer capt
media 15030 10518 326848 24216 do_signal_ 00f6f32694 T NuPlayerDriver
media 15031 10518 326848 24216 do_signal_ 00f6f32694 T generic
media 15032 10518 326848 24216 do_signal_ 00f6f32694 T NuPlayerDriver
media 15033 10518 326848 24216 do_signal_ 00f6f32694 T generic
media 15034 10518 326848 24216 do_signal_ 00f6f32694 T NuPlayerDriver
media 15035 10518 326848 24216 do_signal_ 00f6f32694 T generic
media 15037 10518 326848 24216 do_signal_ 00f6f5bee4 T Binder_7
media 15095 10518 326848 24216 ptrace_sto 0000000000 t CAM_defrdWrk
media 15112 10518 326848 24216 do_signal_ 00f6f32694 T .vorbis.decoder
media 15113 10518 326848 24216 do_signal_ 00f6f32694 T OMXCallbackDisp

从上面的线程状态中我们可以看到除了CAM_defrdWrk和visualizer capt线程之外其他线程都处于T状态，即STOP状态，CAM_defrdWrk和visualizer capt线程处于t状态，即trace stop状态，但是为什么mediaserver的线程都处于T或t状态？

常见的线程状态定义如下：
“R (running)”
“S (sleeping)”
“D (disk sleep)”
“T (stopped)”
“t (tracing stop)”
“X (dead)”
“Z (zombie)”

一般情况下在线程内执行的代码发生异常如操作无效内存地址触发SIGSEGV等，会导致进程退出并触发debuggerd来打印tombstone，这个时候发生异常的线程会处于t状态并且进程内的其他线程都会先处于T状态，然后轮流ptrace进入t状态，直到进程内各个线程的backtrace都打印完之后整个进程退出，按照这个逻辑就解释了debuggerd打不出来mediaserver调用栈的问题，因为mediaserver已经处于打印的流程中了，无法再接受和处理新的信号及打印操作，根据这个线索我们去查看pull出来的tombstone文件，发现mediaserver的CAM_defrdWrk线程确实发生了异常，是一个非常典型的操作0地址引发的SIGSEGV异常，具体信息如下：

pid: 10518, tid: 15095, name: CAM_defrdWrk >>> /system/bin/mediaserver <<<
signal 11 (SIGSEGV), code 1 (SEGV_MAPERR), fault addr 0x0
r0 e554f1ec r1 00000000 r2 00000000 r3 00000000
r4 eca56000 r5 f4b5b0e0 r6 00000003 r7 00000003
r8 e554eae8 r9 e554f1ec sl ffffffff fp 00000000
ip 00000000 sp e554ead0 lr f4bdf0a1 pc 00000000 cpsr 40090010
d0 0000000000000000 d1 0000000000000000
d2 0000000000000000 d3 0000000000000000
d4 0000000000000000 d5 0000000000000000
d6 0000000000000000 d7 0000000000000000
d8 0000000000000000 d9 0000000000000000
d10 0000000000000000 d11 0000000000000000
d12 0000000000000000 d13 0000000000000000
d14 0000000000000000 d15 0000000000000000
d16 0000000000000000 d17 0000000000000000
d18 4023ffffff8fc4c0 d19 4072dad566cf41f2
d20 4059000000000000 d21 4072dad566cf41f2
d22 be0a39ef35793c76 d23 3ff944d013a92a31
d24 00000000000000a9 d25 4000000000000000
d26 4072dad566cf41f2 d27 40082258d5842b73
d28 3ff944d013a92a31 d29 3ff0000000000000
d30 3ff455bcf61e4314 d31 4000000000000000
scr 20000012
backtrace:
#00 pc 00000000 <unknown>
#01 pc 0008409f /system/lib/hw/camera.msm8996.so (_ZN7qcamera13QCameraStream15BufAllocRoutineEPv+302)
#02 pc 0003faa3 /system/lib/libc.so (ZL15_pthread_startPv+30)
#03 pc 0001a035 /system/lib/libc.so (__start_thread+6)

到这里我们基本能解释为什么mediaserver无法及时响应system_server的binder调用问题了，但是问题还没有结束…

3. 深入分析

正常情况下一个进程发生Native异常debuggerd会在很短的时间内把tombstone打印完，然后进程退出，如果进程内有等待执行的binder调用会在进程退出时在调用端进程返回失败，同时会发送死亡通知，不会导致调用端一直block，所以到这里又引出了另外一个问题：

  • mediaserver进程为什么没有及时退出？

带着疑问我们继续分析，debuggerd打印进程的调用栈是一个线程一个线程打印的，打印到那个线程就会ptrace到那个线程上，此时线程的状态是t，同时发生异常问题的线程会一直处于t状态，直到所有线程的调用栈打印完，根据这个流程以及当前mediaserver进程中一直处于t状态的另外一个线程visualizer capt，我们可以推测出来当前block的地方是在打印visualizer capt线程调用栈的过程中，从tombstone中我们可以看到visualizer capt线程用户空间的Native调用栈如下：

pid: 10518, tid: 14597, name: visualizer capt  >>> /system/bin/mediaserver <<<
    r0 ede01058  r1 00000001  r2 ede01040  r3 00000000
    r4 00000000  r5 00000001  r6 00000000  r7 00000150
    r8 00000000  r9 f67e9f14  sl f161207c  fp f64efc60
    ip ede01038  sp ede01028  lr f6f37131  pc f6f5c0a8  cpsr 400f0010
    d0  0000000000000000  d1  0000000000000000
    d2  0000000000000000  d3  0000000000000000
    d4  0000000000000000  d5  0000000000000000
    d6  0000000000000000  d7  0000000000000000
    d8  0000000000000000  d9  0000000000000000
    d10 0000000000000000  d11 0000000000000000
    d12 0000000000000000  d13 0000000000000000
    d14 0000000000000000  d15 0000000000000000
    d16 0000000000000000  d17 0000000000000000
    d18 0000000200000001  d19 0000000000000000
    d20 3fc54df05f8014f2  d21 3fd16459255125be
    d22 be106435816bc5ca  d23 3fb3d8f80e0fe72b
    d24 000000000000003c  d25 4000000000000000
    d26 3ffba6e9b6abb690  d27 3fa6f7e64fa1fce7
    d28 bfa6f7e657d417a8  d29 3ff0000000000000
    d30 3ff54852efeea0bd  d31 4000000000000000
    scr 60000012

backtrace:
    #00 pc 000410a8  /system/lib/libc.so (__ppoll+16)
    #01 pc 0001c12d  /system/lib/libc.so (poll+32)
    #02 pc 00002e5d  /system/lib/libtinyalsa.so (pcm_wait+24)
    #03 pc 00002fa5  /system/lib/libtinyalsa.so (pcm_mmap_transfer+228)
    #04 pc 00001809  /system/lib/soundfx/libqcomvisualizer.so
    #05 pc 0003faa3  /system/lib/libc.so (_ZL15__pthread_startPv+30)
    #06 pc 0001a035  /system/lib/libc.so (__start_thread+6)

visualizer capt线程kernel空间的调用栈如下：

root@scorpio:/ # cat /proc/14597/stack
[<0000000000000000>] __switch_to+0x70/0x7c
[<0000000000000000>] ptrace_stop+0x18c/0x260
[<0000000000000000>] get_signal+0x21c/0x578
[<0000000000000000>] do_signal+0x98/0x4b8
[<0000000000000000>] do_notify_resume+0x14/0x5c
[<0000000000000000>] work_pending+0x18/0x20
[<0000000000000000>] 0xffffffffffffffff

从tombstone文件和kernel调用栈中我们看到visualizer capt线程的stack并没有打印完而是打印到中途就没有接下来的信息了，并且一直处于ptrace_stop的t状态，这是一个疑点和线索，我们先记下来，通过稍后的分析我们就能解释为什么没有打印完全。

我们知道进程发生异常打印tombstone时，控制线程状态切换和打印的是debuggerd进程，既然visualizer capt线程的打印block了，那我们也看一下debuggerd当前的状态，因为debuggerd当前无法打印Native的调用栈了，所以我们通过另外一种方式来查看它的kernel stack：
$ cat /proc/522/stack
得到debuggerd kernel空间的调用栈如下：

[<0000000000000000>] __switch_to+0x70/0x7c
[<0000000000000000>] snd_pcm_open+0x138/0x1c8
[<0000000000000000>] snd_pcm_capture_open+0x40/0x68
[<0000000000000000>] snd_open+0x130/0x14c
[<0000000000000000>] chrdev_open+0x134/0x168
[<0000000000000000>] do_dentry_open+0x260/0x2dc
[<0000000000000000>] vfs_open+0x3c/0x48
[<0000000000000000>] do_last.isra.39+0x7a8/0x9d0
[<0000000000000000>] path_openat+0x204/0x560
[<0000000000000000>] do_filp_open+0x2c/0x80
[<0000000000000000>] do_sys_open+0x160/0x1fc
[<0000000000000000>] compat_SyS_openat+0x8/0x14
[<0000000000000000>] el0_svc_naked+0x20/0x28
[<0000000000000000>] 0xffffffffffffffff

从调用栈中可以看到一些线索，debuggerd和visualizer capt线程都在做pcm相关的操作，debuggerd是在打开snd pcm设备，但是debuggerd为什么会打开snd pcm设备？又为什么会在snd_pcm_open时block？借助addr2line工具和vmlinux镜像我们可以定位到snd_pcm_open+0x138/0x1c8对应的源代码如下：

/* kernel/sound/core/pcm_native.c */
2351static int snd_pcm_open(struct file *file, struct snd_pcm *pcm, int stream)
2352{
        ...
2367    init_waitqueue_entry(&wait, current);
2368    add_wait_queue(&pcm->open_wait, &wait);
2369    mutex_lock(&pcm->open_mutex);
2370    while (1) {
2371        err = snd_pcm_open_file(file, pcm, stream);
2372        if (err >= 0)
2373            break;
2374        if (err == -EAGAIN) {
2375            if (file->f_flags & O_NONBLOCK) {
2376                err = -EBUSY;
2377                break;
2378            }
2379        } else
2380            break;
2381        set_current_state(TASK_INTERRUPTIBLE);
2382        mutex_unlock(&pcm->open_mutex);
2383        schedule();
        ...
2393    }

当前代码执行到了2383行，从代码逻辑来看是snd_pcm_open_file返回了err == -EAGAIN，并且不满足break的条件，从而走到了2383行主动将自己调度出去，同时往wait_queue中设置了一个wait entry，等待被wakeup后重新调度并运行当前线程。

进一步分析snd_pcm_open_file的逻辑发现snd_pcm设备是单线程独占的，一旦第一个线程打开之后substream的ref_count就会增加，当第二个线程要打开的时候就会判断ref_count的值，如果大于0就会返回-EAGAIN，debuggerd就是因为要打开的snd_pcm设备被其他线程先打开了所以主动调度出去，并等待另外一个线程release snd_pcm设备的时候去减少substream的ref_count值，同时wakeup debuggerd，snd_pcm设备release的代码如下：

/* kernel/sound/core/pcm_native.c */
2408static int snd_pcm_release(struct inode *inode, struct file *file)
2409{
      ...
2420	snd_pcm_release_substream(substream);
2421	kfree(pcm_file);
2422	mutex_unlock(&pcm->open_mutex);
2423	wake_up(&pcm->open_wait);
      ...
2427}

但是从当前的问题现象来看debuggerd并没有等到第一个打开的线程去release snd_pcm这个设备，接下来我们继续查找mediaserver中是那个线程打开了这个snd_pcm设备又没有及时释放。

通过查看backtrace发现只有visualizer capt线程在做pcm_mmap_transfer和pcm_wait的操作，执行pcm_mmap_transfer的前提是先打开并mmap snd_pcm设备，所以可以确定是visualizer capt线程打开了snd_pcm设备且没有释放，导致debuggerd在打开时block，通过如下命令可以知道snd_pcm设备文件是否mmap到了maps表中：

$ cat /proc/10518/maps | grep snd

根据输出可以看到snd_pcm设备文件确实mmap到了maps表中：

efc66000-efc7e000 rw-s 00000000 00:0d 3565 /dev/snd/pcmC0D8c

通过进一步的代码和逻辑分析，发现visualizer capt线程没有及时释放的原因是还在做pcm_mmap_transfer操作的过程中没有做完，正常情况下pcm_mmap_transfer操作是有做完的时候，但是在mediaserver进程的CAM_defrdWrk线程发生异常时会先STOP所有线程，并逐个打印线程的调用栈，这个时候pcm_mmap_transfer的操作就被暂停了，从而无法及时完成pcm_mmap_transfer操作并release snd_pcm设备，而debuggerd在打印visualizer capt线程的过程中需要推导stack上内存地址对应的函数和偏移，此时恰好有个内存地址是mmap snd_pcm设备文件得来的，所以在推导这个地址时会打开对应的snd_pcm设备文件，从而引发debuggerd的block，至此问题的死锁环已经成立。

4. 问题总结

总结一下问题的死锁流程：

  • 线程独占的设备节点文件/dev/snd/pcmC0D8c被mediaserver进程的visualizer capt线程打开并mmap到了用户空间的maps表中；
  • mediaserver的CAM_defrdWrk线程访问0地址发生空指针Crash；
  • debuggerd发现mediaserver Crash，然后开始处理Crash流程，打印tombstone；
  • 打印tombstone的过程中会先将进程中所有线程设置为T状态，然后ptrace到出问题的线程，使其进入t状态，然后开始从Crash的线程开始逐个线程打印调用栈；
  • 打印visualizer capt线程的过程中会推导stack上的内存地址，其中有一些地址正好在mmap /dev/snd/pcmC0D8c设备节点的范围内，所以推导的过程中debuggerd会去打开/dev/snd/pcmC0D8c设备节点文件；
  • 此时visualizer capt线程已经打开了/dev/snd/pcmC0D8c设备节点文件，正在做pcm_mmap_transfer操作，所以此时debuggerd无法打开/dev/snd/pcmC0D8c设备节点文件而处于等待状态；
  • visualizer capt线程的pcm_mmap_transfer操作被debuggerd发起的打印调用栈的操作而暂停处于t状态，从而无法释放/dev/snd/pcmC0D8c设备节点文件；
  • debuggerd和visualizer capt线程之间产生死锁环，debuggerd需要的条件在visualizer capt线程手上，visualizer capt线程需要继续执行的条件在debuggerd手机，谁都无法打断谁获取对方的条件，最终导致watchdog线程和activitymanager线程在dumpStackTraces时被block，同时导致InputReader线程在发起对mediaserver的binder调用时被block，最终用户看到的结果就是输入无效，冻屏，并且不会自动重启；

5. 解决方案

通过初步分析、深入分析和问题总结，我们清楚的知道了问题的原因，接下来我们再分析一下如何解决这个问题：

  • snd_pcm设备的驱动的单线程独占模式我们不能调整；
  • visualizer capt线程的mmap逻辑也是正常的，不能调整；
  • debuggerd打印调用栈时的推导过程存在一定的优化空间，因为推导的目的是为了将stack上对应的内存地址推导出so文件中的函数地址和偏移，已知snd_pcm和其他设备文件中不会有函数地址和偏移，所以对于stack上内存地址在mmap的设备文件范围中的，可以跳过推导过程，从而避免这个问题；
  • watchdog线程的dumpStackTraces操作可以添加超时机制，从而避免因为debuggerd的原因而导致system_server永远无法被watchdog重启；

debuggerd跳过设备文件地址推导的patch如下：

/* system/core/libbacktrace/Backtrace.cpp */
std::string Backtrace::GetFunctionName(uintptr_t pc, uintptr_t* offset, const backtrace_map_t* map) {
  backtrace_map_t map_value;
  ...
  // If no map is found, or this map is backed by a device, then return nothing.
  if (map->start == 0 || (map->flags & PROT_DEVICE_MAP)) {
    return "";
  }
  ...
}

为watchdog线程的dumpStackTraces操作增加超时机制的patch如下：

/* frameworks/base/services/core/java/com/android/server/am/ActivityManagerService.java */
private static void dumpStackTraces(String tracesPath, ArrayList<Integer> firstPids,
        ProcessCpuTracker processCpuTracker, SparseArray<Boolean> lastPids, String[] nativeProcs) {
      ...
        // Next collect the stacks of the native pids
        if (nativeProcs != null) {
            int[] pids = Process.getPidsForCommands(nativeProcs);
            if (pids != null) {
                for (int pid : pids) {
                    Debug.dumpNativeBacktraceToFileTimeout(pid, tracesPath, 10);
            }
        }

/* frameworks/base/core/java/android/os/Debug.java */
/**
 * Append the stack traces of a given native process to a specified file.
 * @param pid pid to dump.
 * @param file path of file to append dump to.
 * @param timeoutSecs time to wait in seconds, or 0 to wait forever.
 * @hide
 */
public static native void dumpNativeBacktraceToFileTimeout(int pid, String file, int timeoutSecs);

6. 实战心得

  • 对于可能耗时的操作比如I/O，网络操作等，尽量增加超时机制，以提升程序的健壮性和容错能力，在最坏的情况下也能做到状态可控；
  • 对于一些实时性要求比较高以及执行热点代码的线程，例如InputReader线程，尽量不添加耗时操作和处理逻辑，特别是同步的binder调用更尽量减少使用，以减少对外部进程的依赖，同时提升InputReader线程处理输入时间的及时性；
CATALOG
    热门标签
    工具命令 Android Android10 framework 稳定性 组件学习 进程间通信 Binder 疑难问题 android 框架问题 系统启动 系统组件 Input系统 系统原理 系统服务 系统调试 Handler PKMS
    资源网站