Android APP native 崩潰分析之時間的祕密

時間  2019-11-07
標籤 android app native 崩潰 分析 時間 祕密 欄目 Android 简体版
原文   原文鏈接

原文地址：caikelun.io/post/2019-0…android

對於程序的崩潰問題，不管是面對 Linux 的 coredump 仍是 Android 的 tombstone，咱們最終都須要進行俗稱爲 「驗屍」 的過程。有時候，咱們會遇到一些堪稱完美的 「犯罪現場」。git

現象

現象 1

Signal: 7 (SIGBUS), Code: 2 (BUS_ADRERR), fault addr 0xcd596372

r0  0000006e  r1  00000000  r2  00000000  r3  00000000
r4  f35bb740  r5  f35bb748  r6  cd3ff8a8  r7  00000064
r8  f7451e34  r9  f35bb708  r10 cd301000  r11 cd5a3ac5
ip  00000000  sp  cd3ff890  lr  00000000  pc  cd596372

#00 pc 0009a372 /data/data/com.package.name/files/download/libCube.so
#01 pc 000a4f69 /data/data/com.package.name/files/download/libCube.so
#02 pc 000a513f /data/data/com.package.name/files/download/libCube.so
#03 pc 000a7ab9 /data/data/com.package.name/files/download/libCube.so
#04 pc 000a7abf /data/data/com.package.name/files/download/libCube.so
#05 pc 000a7add /data/data/com.package.name/files/download/libCube.so
#06 pc 0004078b /system/lib/libc.so (_ZL15__pthread_startPv+30)
#07 pc 0001a031 /system/lib/libc.so (__start_thread+6)

#00 cd3ff890 cd3ff8dc
     cd3ff894  5d419f43
     cd3ff898  cd3ff8a0
     cd3ff89c  f35bb744  [anon:libc_malloc]
     cd3ff8a0  5d419f43
     cd3ff8a4  000a5952
     cd3ff8a8  5d419f43
     cd3ff8ac  2e62c950  /dev/ashmem/dalvik-main space (deleted)
     cd3ff8b0  00000064
     cd3ff8b4  f35bb700  [anon:libc_malloc]
     cd3ff8b8  f35bb750  [anon:libc_malloc]
     cd3ff8bc  00000064
     cd3ff8c0  cd3ff8dc
     cd3ff8c4  cd5a0f6d  /data/data/com.package.name/files/download/libCube.so
#01 cd3ff8c8 cd5a3ac5 /data/data/com.package.name/files/download/libCube.so
     cd3ff8cc  00000000
     cd3ff8d0  00000001
     cd3ff8d4  262237a1  /dev/ashmem/dalvik-main space (deleted)
     cd3ff8d8  00000000
......

......
memory near pc:
    cd596350 43591889 60714b11 dd054299 33019b01  ..YC.Kq`.B.....3
    cd596360 4b0f9306 607118c9 1c299803 f0251c32  ...K..q`..).2.%.
    cd596370 286ef8d5 7b23d003 d0f52b00 2601e002  ..n(..#{.+.....&
    cd596380 e0004276 78232600 d1002b00 1c287323  vB...&#x.+..#s(.
    cd596390 fd84f024 b0091c30 46c0bdf0 3b9ac9ff  $...0......F...;
    cd5963a0 c4653600 1c0cb510 f8c0f025 d1022800  .6e.....%....(..
    cd5963b0 20016020 f024e004 6800fcd1 20006020   `. ..$....h `. 
    cd5963c0 b570bd10 26006803 3b0cb09a 1c0c681b  ..p..h.&...;.h..
    cd5963d0 d10342b3 600a2202 e0161c18 6800600e  .B...".`.....`.h cd5963e0 f0244669 2800fef3 f024d005 6800fcb7 iF$....(..$....h cd5963f0 1c306020 9b04e009 021222f0 2380401a `0......"...@.#
    cd596400 429a021b 6020d101 b01a2001 b538bd70  ...B.. `. ..p.8.
    cd596410 1c0d6800 3b0c1c03 2c00681c 2302d102  .h.....;.h.,...#
    cd596420 e00d600b feeaf024 d0051e04 602b2300  .`..$........#+`
    cd596430 fef4f024 e0042001 fc90f024 60286800  $.... ..$....h(`
    cd596440 bd381c20 6803b570 1c0d1c06 681c3b0c   .8.p..h.....;.h
......

......
cd4fc000-cd5e9000 r-x       0  ed000 /data/data/com.package.name/files/download/libCube.so
cd5e9000-cd5ee000 r--   ec000   5000 /data/data/com.package.name/files/download/libCube.so
cd5ee000-cd5ef000 rw-   f1000   1000 /data/data/com.package.name/files/download/libCube.so
......

複製代碼
.text:0009A368      LDR     R0, [SP,#0x38+var_2C]
.text:0009A36A      MOVS    R1, R5
.text:0009A36C      MOVS    R2, R6
.text:0009A36E      BL      j_pthread_cond_timedwait
.text:0009A372      CMP     R0, #0x6E ;在這個位置發生了 SIGBUS
.text:0009A374      BEQ     loc_9A37E
複製代碼

崩潰位置在 libCube.so 的 offset 0009a372 處，根據 arm32 fastcall 調用約定，這裏在 pthread_cond_timedwait() 函數返回後，檢查 r0 中的返回值是否爲 6e （十進制：110），查 pthread_cond_timedwait() manpage 和 Linux errno list 得知：pthread_cond_timedwait() 返回 110（ETIMEDOUT） 表示超時。github

這是一個正常的調用，沒有問題。那爲何會 SIGBUS 呢？難道是偶發的 NAND Flash 硬件故障？或者是驅動的 bug ？bash

從 xCrash 捕獲的崩潰信息中能夠看到， 當前 pc 位置（0009a372）的二進制指令碼是 286e，恰好對應 CMP R0, #0x6E，這裏的指令碼數據是經過 ptrace() 獲取的，xCrash 能獲取到可是 CPU 執行這條指令時卻獲取不到？app

現象 2

Signal: 11 (SIGSEGV), Code: 1 (SEGV_MAPERR), fault addr 0x11d868

r0  bf206648  r1  00000000  r2  00000000  r3  00000000
r4  bf206640  r5  bf206648  r6  ffffffff  r7  000001b9
r8  d44bf980  r9  bf206608  r10 b1654000  r11 b21bd89d
ip  b240ed4c  sp  b1752890  lr  b21a66b9  pc  0011d868

#00 pc 0011d868 <unknown>
#01 pc 005586b5 /data/data/com.package.name/files/download/libHCDNClientNet.so (_ZN3psl5Event4WaitEi+160)
#02 pc 0056fe55 /data/data/com.package.name/files/download/libHCDNClientNet.so (_ZN8BaseHcdn6Thread9ThreadRunEv+122)
#03 pc 0057002b /data/data/com.package.name/files/download/libHCDNClientNet.so (_ZN8BaseHcdn10CThreadObj14ThreadWorkFuncEv+6)
#04 pc 0056f891 /data/data/com.package.name/files/download/libHCDNClientNet.so (_ZN3psl13CThreadObject14ThreadBaseFuncEv+26)
#05 pc 0056f897 /data/data/com.package.name/files/download/libHCDNClientNet.so (_ZN3psl13CThreadObject3RunEv+2)
#06 pc 0056f8b5 /data/data/com.package.name/files/download/libHCDNClientNet.so (_ZN3psl10ThreadBaseINS_13CThreadObjectEE10ThreadProcEPv+24)
#07 pc 00040aab /system/lib/libc.so (_ZL15__pthread_startPv+30)
#08 pc 0001a011 /system/lib/libc.so (__start_thread+6)

#00 b1752890 b17528dc
     ........  ........
#01 b1752890 b17528dc
     b1752894  5d419f83
     b1752898  b17528a0
     b175289c  bf206644  [anon:libc_malloc]
     b17528a0  5d419f83
     b17528a4  000cf94e
     b17528a8  5d419f84
     b17528ac  115c2ef0
     b17528b0  000001b9
     b17528b4  bf206600  [anon:libc_malloc]
     b17528b8  bf206650  [anon:libc_malloc]
     b17528bc  000001b9
     b17528c0  b17528dc
     b17528c4  b21bde59  /data/data/com.package.name/files/download/libHCDNClientNet.so (_ZN8BaseHcdn6Thread9ThreadRunEv+126)
#02 b17528c8 b21bd89d /data/data/com.package.name/files/download/libHCDNClientNet.so (_ZN3psl10ThreadBaseINS_13CThreadObjectEE10ThreadProcEPv)
     b17528cc  00000000
     b17528d0  00000001
     b17528d4  0730c6a9
     b17528d8  00000000
     b17528dc  bf20663c  [anon:libc_malloc]
     b17528e0  00000000
     b17528e4  bf206600  [anon:libc_malloc]
     b17528e8  b1752970
     b17528ec  b1752930
......

......
f73d0000-f7444000 r-x        0   74000 /system/lib/libc.so
f7444000-f7448000 r--    73000    4000 /system/lib/libc.so
f7448000-f744b000 rw-    77000    3000 /system/lib/libc.so
......
b1c4e000-b23ef000 r-x        0  7a1000 /data/data/com.package.name/files/download/libHCDNClientNet.so
b23ef000-b23f0000 ---        0    1000
b23f0000-b240f000 r--   7a1000   1f000 /data/data/com.package.name/files/download/libHCDNClientNet.so
b240f000-b241a000 rw-   7c0000    b000 /data/data/com.package.name/files/download/libHCDNClientNet.so
......
複製代碼

這是一個段錯誤，pc 的值是 0011d868，這個地址顯然是異常的，咱們俗稱 pc 「跑飛了」。backtrace 第二行中，libHCDNClientNet.so 的 offset 005586b5 對應的指令以下：函數

.text:005586B2      MOVS    R0, R5
.text:005586B4      BL      j_pthread_mutex_unlock ;這裏
.text:005586B8      MOVS    R0, R6
複製代碼

這是對 libc.so 中 pthread_mutex_unlock() 函數的調用，這裏不該該有問題。難道是 linker 的 bug？pthread_mutex_unlock() 的絕對地址應該由 linker 寫入 libHCDNClientNet.so 的 GOT 中。post

此類怪異的崩潰現象還有一些，這裏不繼續羅列了。ui

問題到底出在哪裏？google

分析

問題特徵

通過總結，發現上述的問題有如下幾個特徵：spa

  • 從 tombstone 看不出問題的根本緣由。
  • 崩潰點自己都不在業務邏輯可控的範圍內。
  • 大多數發生在會致使線程 block 的調用的後一條指令處。
  • 都發生在動態下載的 so 庫中。（注意 so 庫都在 files 目錄中）
  • 設備機型和操做系統版本分佈無明顯特徵。
  • 99% 以上發生在非 root 的設備上。（如今 root 手機的用戶愈來愈少了）

崩潰捕獲的機制

不管是安卓系統的 debuggerd，仍是 xCrash，或者 Breakpad，在捕獲 native 崩潰時，都會經歷如下幾個階段：

  • 崩潰進程的 signal handler 被喚起執行。
  • clone() 子進程。
  • 在子進程中 ptrace() attach 到崩潰進程的各個線程。
  • 讀取崩潰進程中各個線程的寄存器、內存、ELF 等信息。
  • 將信息直接寫入 dump 文件；或者進一步分析提取 backtrace 等信息寫入 dump 文件。

在子進程 attach 到全部崩潰進程的線程以前，崩潰進程仍然還在執行。若是考慮安卓 app 的多進程狀況，那麼在整個崩潰捕獲期間，app 的其餘進程也均可能在執行中。

崩潰捕獲的機制也是由代碼實現的，它們須要被一步一步的執行。咱們能夠想象：當案件（崩潰）發生時，警察（崩潰捕獲機制）趕到案發現場是須要必定的時間的，這段時間就是 「視覺的盲區」。

對於咱們前面描述的崩潰問題，在進程崩潰以後，但在 xCrash 開始執行並記錄崩潰信息以前，必定還發生了一些咱們所不知道的事情，案發現場的某些細節被篡改了！

可疑之處

回想上述的 「現象1」，指令碼 286e 爲何 xCrash 能獲取到，可是 CPU 執行時卻獲取不到而發生了 SIGBUS？

也許緣由很簡單：CPU 的執行流水線從內存加載這條指令時，so 庫文件的這個 offset 位置確實不可讀，因而發生了 SIGBUS；以後 xCrash 開始捕獲崩潰信息，當 xCrash 用 ptrace() 從同一個內存位置讀取數據時，so 庫文件的這個 offset 位置又從新變的可讀了。

最大的可能性是：so 庫文件在已經被 linker 加載並開始執行的狀況下，又再次被覆寫了。也許是 so 庫在動態下載、解壓、校驗的某些環節存在 bug，致使內部狀態發生了異常。

尋找間接的證據

通過仔細的分析，咱們確實發現了一些間接的證據：

so 文件的最後修改時間

咱們發了大量的 「崩潰 so 庫文件的最後修改時間」 晚於 「崩潰時間點」 的狀況。相似下面的狀況：

process start time  : 2019-08-01 01:54:51.519 +0800
process crash time  : 2019-08-01 01:54:53.743 +0800
so last modify time : 2019-08-01 01:54:53.938 +0800
複製代碼

so 文件的大小和 MD5 hash

因爲動態下載的 so 庫咱們是能夠從服務端可靠的獲取的，咱們比對了 xCrash 記錄的崩潰 so 庫的文件大小和 MD5 hash。發現有一部分確實是不對的，這部分狀況應該就屬於：「直到 xCrash 開始記錄崩潰信息的時候，so 庫被錯誤覆蓋的過程尚未徹底結束」。

open files

經過分析 open files 列表，咱們看到在有些狀況下，崩潰進程仍然持有有效的 FD 可用於訪問動態下載的 so 庫所屬的 zip 包：

Open files:
......
fd 57: /data/data/com.package.name/files/download/fullso.zip
......
複製代碼

有些 FD 還指向 zip 包的 crc 文件：

Open files:
......
fd 58: /data/data/com.package.name/files/download/fullso.zip.crc
......
複製代碼

結論

結論已經比較明顯了：so 庫在動態下載、解壓、校驗的某些環節存在 bug，致使 so 庫文件在已經被 linker 加載並開始執行的狀況下，又再次被覆寫了。

後續：咱們的 so 庫動態下發流程作了改進，增長了更多防護性的設計。咱們從 APM 線上崩潰數據的統計中看到，相似前述 「現象1」 和 「現象2」 的崩潰幾乎都沒有了，APP 的總體 native 崩潰率也進一步的下降了。

相關文章
相關標籤/搜索
每日一句
    每一个你不满意的现在，都有一个你没有努力的曾经。
本站公眾號
   歡迎關注本站公眾號,獲取更多信息
聯繫我們 最近搜索 最新文章 沪ICP备13005482号-10 MyBatis教程 SQL 教程 MySQL教程 Java 教程 Thymeleaf 教程 Hibernate教程 Spring教程 Redis教程