记录这次 Debug 的原因主要是在 debug 过程中用到了之前写的另一篇贴文 所描述的一些做法,并且整个过程也比较曲折,其中的一些现象及其背后的原因也比较罕见。
先给个简单的 Takeaway:如果发生了段错误但 Logcat 中没有打印堆栈,可以考虑一下“人为捕获了 SIGSEGV 信号,但挂接的处理函数出错崩溃”这种情况。
问题现象
当时是在协助开发某 Android 底层框架 A 的新版本。在某次合入新代码后进行测试,发现其上层 App 在运行时会发生“必现但时间及场景不定”的崩溃。比较奇怪的是,Logcat 中完全没有打印 App 崩溃时的错误类型或堆栈信息。
原因定位
后面在 Logcat 中找到的一些边缘信息指出,崩溃的原因是发生了段错误:
102-25 15:43:54.620 15725 15725 I Zygote : Process 31289 exited due to signal 11 (Segmentation fault)
由于 Logcat 中没有有用的信息,只好去找找还有没有别的日志。通过寻找,在内核日志中找到了下列信息,通过 PID 可以确定其与 App 崩溃有关:
1[159064.016937] [pid:31605,cpu5,Thread-27]potentially unexpected fatal signal 11.
2[159064.016937] [pid:31605,cpu5,Thread-27]CPU: 5 PID: 31605 Comm: Thread-27 VIP: 00 Tainted: G W 4.14.116 #1
3[159064.016937] [pid:31605,cpu5,Thread-27]TGID: 31289 Comm: ██████████████
4[159064.016937] [pid:31605,cpu5,Thread-27]Hardware name: █████████
5[159064.016937] [pid:31605,cpu5,Thread-27]task: ffffffea6ff86780 task.stack: ffffffeb99e8c000
6[159064.016967] [pid:31605,cpu5,Thread-27]PC is at 0x7eccc80d40
7[159064.016967] [pid:31605,cpu5,Thread-27]LR is at 0x7e2cb3c40c
8[159064.016967] [pid:31605,cpu5,Thread-27]pc : [<0000007eccc80d40>] lr : [<0000007e2cb3c40c>] pstate: 20001000
9[159064.016967] [pid:31605,cpu5,Thread-27]sp : 0000007e32f65940
10[159064.016967] [pid:31605,cpu5,Thread-27]x29: 0000007e32f6ebb0 x28: 0000000000000004
11[159064.016967] [pid:31605,cpu5,Thread-27]x27: 0000005b47c31000 x26: 000000000000000b
12[159064.016967] [pid:31605,cpu5,Thread-27]x25: 0000007dd45fc020 x24: 0000000000000040
13[159064.016998] [pid:31605,cpu5,Thread-27]x23: 0000005b47c313e0 x22: 0000007e32f65940
14[159064.016998] [pid:31605,cpu5,Thread-27]x21: 0000007dd45fc020 x20: 0000007e32f6d980
15[159064.016998] [pid:31605,cpu5,Thread-27]x19: 0000007e32f6ebc8 x18: 0000007db1570000
16[159064.016998] [pid:31605,cpu5,Thread-27]x17: 0000007eccc80c40 x16: 0000007e2cbb0788
17[159064.016998] [pid:31605,cpu5,Thread-27]x15: 000000000000000a x14: 000000000000000a
18[159064.016998] [pid:31605,cpu5,Thread-27]x13: 0000000000000000 x12: 0000000080001604
19[159064.017028] [pid:31605,cpu5,Thread-27]x11: 0000000000000000 x10: 0000000000000001
20[159064.017028] [pid:31605,cpu5,Thread-27]x9 : 37d1b204abb9d79e x8 : 37d1b204abb9d79e
21[159064.017028] [pid:31605,cpu5,Thread-27]x7 : 00000000000000e0 x6 : 0000000000000008
22[159064.017028] [pid:31605,cpu5,Thread-27]x5 : 0000000000000004 x4 : 0000007e32f6d980
23[159064.017028] [pid:31605,cpu5,Thread-27]x3 : 0000007e32f67000 x2 : 0000000000006900
24[159064.017028] [pid:31605,cpu5,Thread-27]x1 : 0000000000000000 x0 : 0000007e32f65980
25[159064.017059] [pid:31605,cpu5,Thread-27]
26[159064.017822] [pid:31289,cpu0,██████████████][█████████████████████████] fail to find the task comm=██████████████ pid=31289
我们发现从中可以获取到 PC 和 LR 的值,而若是将其配合上进程空间的信息,我们就可以进一步确定错误发生的位置。获取进程空间的具体方法为:先运行 App,在其崩溃前使用 pmap <PID>
获取1。
1......
20000007e2cad4000 184K r---- /system/lib64/libA.so
30000007e2cb02000 648K r-x-- /system/lib64/libA.so
40000007e2cba4000 36K rw--- /system/lib64/libA.so
50000007e2cbad000 16K r---- /system/lib64/libA.so
6......
70000007eccc15000 252K r---- /apex/com.android.runtime/lib64/bionic/libc.so
80000007eccc54000 236K r-x-- /apex/com.android.runtime/lib64/bionic/libc.so
90000007eccc8f000 4K rwx-- /apex/com.android.runtime/lib64/bionic/libc.so
100000007eccc90000 304K r-x-- /apex/com.android.runtime/lib64/bionic/libc.so
110000007ecccdc000 4K rwx-- /apex/com.android.runtime/lib64/bionic/libc.so
120000007ecccdd000 52K r-x-- /apex/com.android.runtime/lib64/bionic/libc.so
130000007ecccea000 8K rw--- /apex/com.android.runtime/lib64/bionic/libc.so
140000007ecccec000 24K r---- /apex/com.android.runtime/lib64/bionic/libc.so
15......
可见 PC 指向 libc.so,而 LR 所在的 libA.so 为本项目的代码,因此重点关注 LR。用 LR 的值,配合进程空间信息、带符号表版本的 libA.so(即 libA_symbol.so)和 addr2line,我们可以定位出错源代码的位置。根据 addr2line 的文档:
Given an address in an executable or an offset in a section of a relocatable object, it uses the debugging information to figure out which file name and line number are associated with it.
对可重定位文件,使用 addr2line 时需要加 -j <section>
,且地址应转换为对该 section
的偏移;对可执行文件,则不需要加 -j
部分,地址也直接使用就好,无需计算偏移。因此我们通过如下命令:
1# 0x7e2cb3c40c - 0x7e2cb02000 = 0x3a40c
2# ^~~~~~~~~~~~ (start addr of .text section of libA.so)
3addr2line -j .text -e ./libA_symbol.so 0x3a40c
定位到源代码里的这行:
1void CaptureBacktraceUsingLibUnwind(BacktraceState *state)
2{
3 // ...
4#if defined(__aarch64__)
5 unw_set_reg(&unWindCursor, UNW_AARCH64_X0, signalContext->regs[0]);
6 // ...
7 unw_set_reg(&unWindCursor, UNW_AARCH64_X15, signalContext->regs[15]);
8 unw_set_reg(&unWindCursor, UNW_REG_IP, signalContext->pc); // <------- HERE
9 unw_set_reg(&unWindCursor, UNW_REG_SP, signalContext->sp);
10 //...
11}
我们发现,该函数属于框架 A 中调试部分的代码,在 SIGSEGV 信号处理函数中使用:
1void SigActionHandler(int sig, siginfo_t *info, void *uContext)
2{
3 // ...
4 CaptureBacktraceUsingLibUnwind(&backtraceState);
5 // ...
6}
7
8static void InstallSignalHandle()
9{
10 // ...
11 struct sigaction siga;
12 siga.sa_sigaction = SigActionHandler;
13 // ...
14 sigaction(SIGSEGV, &siga, nullptr);
15 // ...
16}
目前基本可以确定,当前的段错误的确是发生在这里。可问题是,这几行代码不是我们引入的,而且整个这部分的代码与新版本的开发也没有一点关系。综合上述所有发现,我们推测整个过程是这样的:App 运行时中发生了段错误,信号被交给框架中自定义的处理函数处理,而在这个处理的过程中,处理函数本身又出了问题。这就基本解释了“Logcat 中没有日志”(SIGSEGV 被捕获)和“定位到的源代码在远离业务逻辑的调试模块中”(处理函数发生二次错误)这两个现象。
处理办法
本人对 libunwind 是完全陌生的,况且这部分跟业务逻辑无关,因此也不想深入其中。根据我们的推测,之所以 Logcat 没有错误日志是因为 SIGSEGV 被捕获,那我们不捕获这个信息,把该信号的处理交还给 Android 不就好了吗2?随后,我们在代码中临时取消了对这个信号的处理,果然在重新编译运行后 Logcat 中出现了实际(属于业务逻辑代码的)错误的堆栈信息。据此信息我们很快定位为修复了代码中的一个空指针 bug。