1. 程式人生 > >Tombstone/Crash的log分析和定位

Tombstone/Crash的log分析和定位

有一句話叫做常在河邊走,哪有不溼鞋。我們這些研究和開發Android的工程師正應了這句話,相必大家在除錯的時候經常會遇到這麼個東西吧

*** *** *** *** *** *** *** *** *** *** *** *** *** *** *** ***
Build fingerprint: 'XXXXXXXXX'
pid: 1658, tid: 13086  >>> system_server <<<
signal 11 (SIGSEGV), code 1 (SEGV_MAPERR), fault addr 64696f7e
 r0 00000000  r1 00000001  r2 ad12d1e8  r3 7373654d
 r4 64696f72  r5 00000406  r6 00974130  r7 40d14008
 r8 4b857b88  r9 4685adb4  10 00974130  fp 4b857ed8
 ip 00000000  sp 4b857b50  lr afd11108  pc ad115ebc  cpsr 20000030
 d0  4040000040000000  d1  0000004200000003
 d2  4e72cd924285e370  d3  00e81fe04b1b64d8
 d4  3fbc71c7009b64d8  d5  3fe999999999999a
 d6  4010000000000000  d7  4000000000000000
 d8  4000000000000000  d9  0000000000000000
 d10 0000000000000000  d11 0000000000000000
 d12 0000000000000000  d13 0000000000000000
 d14 0000000000000000  d15 0000000000000000
 scr 80000012

         #00  pc 000108d8  /system/lib/libc.so
         #01  pc 0003724c  /system/lib/libxvi020.so
         #02  pc 0000ce02  /system/lib/libxvi020.so
         #03  pc 0000d672  /system/lib/libxvi020.so
         #04  pc 00010cce  /system/lib/libxvi020.so
         #05  pc 00004432  /system/lib/libwimax_jni.so
         #06  pc 00011e74  /system/lib/libdvm.so
         #07  pc 0004354a  /system/lib/libdvm.so
         #08  pc 00017088  /system/lib/libdvm.so
         #09  pc 0001c210  /system/lib/libdvm.so
         #10  pc 0001b0f8  /system/lib/libdvm.so
         #11  pc 00059c24  /system/lib/libdvm.so
         #12  pc 00059e3c  /system/lib/libdvm.so
         #13  pc 0004e19e  /system/lib/libdvm.so
         #14  pc 00011b94  /system/lib/libc.so
         #15  pc 0001173c  /system/lib/libc.so



code around pc:
ad115e9c 4620eddc bf00bd70 0001736e 0001734e
ad115eac 4605b570 447c4c0a f7f44620 e006edc8
ad115ebc 42ab68e3 68a0d103 f7f42122 6864edd2
ad115ecc d1f52c00 44784803 edbef7f4 bf00bd70
ad115edc 00017332 00017312 2100b51f 46682210

code around lr:
afd110e8 e2166903 1a000018 e5945000 e1a02004
afd110f8 e2055a02 e1a00005 e3851001 ebffed92
afd11108 e3500000 13856002 1a000001 ea000009
afd11118 ebfffe50 e1a01004 e1a00006 ebffed92
afd11128 e1a01005 e1550000 e1a02006 e3a03000


stack:
    4b857b10  40e43be8  
    4b857b14  00857280  
    4b857b18  00000000  
    4b857b1c  034e8968  
    4b857b20  ad118ce9  /system/lib/libnativehelper.so
    4b857b24  00000002  
    4b857b28  00000406

    .....    

    初一看到直接崩潰,我的個媽,這麼一大坨,啥玩意啊,完全搞不懂,沒有頭緒撒。這NND Android出了問題,冒出這麼大堆的地址,搞毛呢。

   其實, 我可以很負責任的告訴你,兄弟這麼多其實我也看不懂,在我眼裡除了紅色和藍色的地方,其他全是廢話。因為除了這兩個地方意外,其他的我確實看不懂,一堆線性地址,外加暫存器,跟火星文一樣。

   算了,廢話不多少,直接分析:

   1 紅色的地方,是讓我們確認問題到底發生在那個執行緒中,是主執行緒還是子執行緒,這個的判斷依據是:如果PID和TID相同,恭喜你問題出在父親這邊,看樣子問題還比較好辦。如果PID和TID不相同,那麼您悲劇了,問題出在子執行緒中。根據我的經驗,100的tombstone中,問題出現在父執行緒的概率,我還從來沒發現,尤其是什麼system_server, zygote這些,基本都是兒子的問題。唉,誰叫父親英雄,兒狗熊呢。。。

  2 確認了問題的基本點,下面就是開始看藍色的部分了。

    這個藍色不分是從#00-->#XX 表面上看是從上往下的增長,其實坑爹啊,它所顯示的程式的執行流程,恰恰是從下往上的也就是實際的執行順序是#XX-->#00。

   所以一開始我們的目的是分析第一個出現問題的動態連線庫
   #15  pc 0001173c  /system/lib/libc.so

  a 首先按圖索驥,找到你的目標,libc.so這個一般會在你編譯完的目標目錄下,也就是out/target/product/your_pro/system/lib這個目錄下。

  b 一般你如果用的是還像樣的linux系統,會有個地址解析的命令addr2line,負責解析動態連線庫的(如果你是悲劇,沒有這個命令,那好吧, google早就預料到會有象你這樣的悲劇人,他們在prebuilt/linux-x86/toolchain/arm-eabi-4.4.0/bin/arm-eabi-addr2line,給您準備了個,咋就用這個吧,功能一樣,沒啥區別)

     addr2line -e libc.so 0001173c -f 紅色是你的目標庫,綠色是你出問題的地址,看看#15這行

    結果出現:??pthread_create

                     ??:0

    恩,好了問題應該出在這個函式中,認為大功告成了?我,呸,還早呢。這個只是告訴你函式入口,至於具體執行到這個函式的哪個地方掛了,還得再看。

c 找到了是哪個部分出了問題,下面就是開啟顯微鏡,看看誰搞的東東。

   使用objdump -S -D libc.so > deassmble_libc.txt 反彙編下你的動態連線庫檔案,並且將它寫入一個檔案中。

   開啟這個反彙編過後的重定向檔案,在查詢的時候輸入1173c這個偏移地址,你會看到在茫茫人海中

  00011684 <pthread_create>:
   11684:       e92d4ff0        push    {r4, r5, r6, r7, r8, r9, sl, fp, lr}
   11688:       e24dd01c        sub     sp, sp, #28     ; 0x1c
   1168c:       e1a06001        mov     r6, r1
   11690:       e1a08002        mov     r8, r2
   11694:       e1a09003        mov     r9, r3
   11698:       e3a04001        mov     r4, #1  ; 0x1
   1169c:       e59f521c        ldr     r5, [pc, #540]  ; 118c0 <pthread_create+0x23c>
   116a0:       e58d000c        str     r0, [sp, #12]
   116a4:       eb009a35        bl      37f80 <strncmp+0x20>
   116a8:       e59f2214        ldr     r2, [pc, #532]  ; 118c4 <pthread_create+0x240>
   116ac:       e1a03000        mov     r3, r0
   116b0:       e1a01004        mov     r1, r4
   116b4:       e593c000        ldr     ip, [r3]
   116b8:       e3a0003c        mov     r0, #60 ; 0x3c
   116bc:       e08f3005        add     r3, pc, r5
   116c0:       e7933002        ldr     r3, [r3, r2]
   116c4:       e5834000        str     r4, [r3]
   116c8:       e58dc010        str     ip, [sp, #16]
   116cc:       eb009a3b        bl      37fc0 <strncmp+0x60>
   ...

   1173c:       ebffec2b        bl      c7f0 <__pthread_clone>-->就是他了,對你成功了。

   ...

這個是ARM彙編,需要你翻譯成對應的C函式去看,這裡我就不做解釋了,照著前面的步驟,

對上面中#15-->#00 一共16行慢慢去找,直到找到#00行的問題函式,其實,最後一個#00行的是最重要的(前面不找也行,但是可以多給你提供問題資訊,和流程),因為他是第一目擊者,也是Crash前的第一現場。所以找到這個函式很重要,假設我們最後經過萬里長針發現#00的出錯的地方是pXX->member掛了(MD,我經常遇到這種問題)。

那麼你可以懷疑兩個地方:

1 您的指標是空指標,但是現實與理想總是十萬八千里,多數情況下很少出現,而且你分析程式碼後,也會對自己說怎麼可能。絕大多數情況下,從我的經驗來講,很少會有空指標這種低階錯誤,但是不排除哪個2貨出現了這麼個問題。如果是這個問題,那麼恭喜你,你很幸運。

2 還有就是懷疑越界和記憶體地址被擠佔。就拿我以前的經驗,指標不是空,但是根據彙編碼看,是訪問成員變數掛了,這個地址肯定是被佔用了。

   針對第2種比較噁心的情況,就需要你看整個log的流程了,需要你看下主要的mainlog關於出現crash前的動作,看看是哪個孫子佔用的,以最近原則為先,從下往上看,唉,說句實在話,李白的一句話可以形容整個過程:"蜀道難,難於上青天啊"。工作量大,而且要細緻。我也沒什麼辦法。。。

  還有一種情況,就是記憶體不夠,導致了您的地址被擠佔了,出現low memory, no more ...這樣的語句,以及大量出現GC_FOR_MALLOC關於GC的東西(如果是少量的,可以忽略,大量的話),呵呵表明你的某個程序在吞噬你的記憶體,存在記憶體洩漏。坑爹啊,這個問題,是最難查的,需要你花大量時間,去看記憶體的變化。一般看記憶體的情況是

cat /proc/meminfo

空閒記憶體=buffer+cache+free這三個欄位,Active欄位是已經使用的記憶體,Total不用說,是總的實體記憶體。(記住 free不高,並不代表你的記憶體空閒不高,海水不可斗量,需要看全了3個欄位的總和才是空閒記憶體)

如果你想具體跟蹤每個程序的記憶體使用情況,還是在/proc下面,對應了N多的數字檔案,那個其實是PID號,進去後cat status可以看到

VMRSS XXXKB就是你當前程序的使用記憶體量,此外還有一些其他的記憶體資料,包括頁啊等等。。。裡面還有很多有用的資料,如果你想跟蹤所有的程序的記憶體情況,推介大家可以看看linux ps命令的原始碼,看看人家是怎麼在/proc下遍歷程序,並且提取屬性值的。

寫個daemon,跟蹤一段時間,記錄下各程序記憶體的變化,然後就是通宵的分析。。。。

總之,這類問題,很難定位,也很難解決,需要花時間,精力去分析。但是如果你解了,那麼相信所有人對你會刮目相看的。包括你的老闆,量變引起質變,請記住。

我還在糾結中啊...分析ing

最後再說幾句

stack:

#12 476e5eb8  476e5ed8  
    476e5ebc  476e5ed8  
    476e5ec0  00100000  
    476e5ec4  476e5ed8  
    476e5ec8  acaa4d38  
    476e5ecc  005ec9b0  
    476e5ed0  aca4e1a3  /system/lib/libdvm.so
    476e5ed4  476e5ed8  
#13 476e5ed8  005ec9b0  
    476e5edc  005ecae8  
    476e5ee0  476e5f00  
    476e5ee4  aca4e109  /system/lib/libdvm.so
    476e5ee8  005ec9b0  
    476e5eec  afd11b98  /system/lib/libc.so
#14 476e5ef0  476e5f00  
    476e5ef4  005ecae8  
    476e5ef8  45b29b84  
    476e5efc  afd11740  /system/lib/libc.so
#15 476e5f00  476e5f00  
    476e5f04  005ecae8  
    476e5f08  00000009  
    476e5f0c  00000000  
    476e5f10  00000000  
    476e5f14  005ec9b0  
    476e5f18  00000000  
    476e5f1c  00000000  

紅色的部分是基地址+偏移地址

比如afd +11740 這個afd你可以從prelink-linux-arm.map找到每個.so的基地址(比如 libc.so                 0xAFD00000 # [~2M])11740可以從反彙編的檔案中找到對應點,但是我不知道這些有什麼用。

希望這偏小文章能幫助到大家,大家共同進步,有好的方法也歡迎您一起分享。謝謝!

下面是一個老外的摘錄早期存於google論壇的記憶體分析文章(現在沒了),我是在他基礎上,又加了一些分析和經驗之談,希望上帝保佑讓我早點定位到問題。