Android Native/Tombstone Crash Log 詳細分析
Android 雖然已經有好幾年了,但是NDK的開放速度卻非常緩慢,所以目前網路上針對對Android Native Crash的分析說明還比較少,尤其是非常詳細的分析方式更難以查詢。因此大部分程式設計師在遇到難以進行addr2line的crash log時,會一籌莫展。事實上這份log中的其他部分同樣提供了非常豐富的資訊可供解讀,所以在這裡總結一下對在這方面的一些經驗,在這裡以Android samples中的hello-jni為參照做了一定的修改產生的crash來進行分析說明。在深入理解錯誤日誌的分析之後,許多難以複製或者幾乎不能重現的bug也能夠得到有效的解決。以下所有內容為夜鶯原創。
內容主要分為一下幾個部分:
- 1.Library Symbols (共享庫的符號)
- 2.Analyze Tools (可用到的分析工具)
- 3.CrashLog – Header
- 4.CrashLog – Backtrace(For most crashes)
- 5.CrashLog – Registers
- 6.CrashLog – Memory
- 7.CrashLog – Stack
- 8.Library Base Address (共享庫在記憶體中基地址)
1.Library Symbols (共享庫的符號)
ndk提供了一些工具可以供程式設計師直接獲取到出錯的檔案,函式以及行數。 但是這部分工具都需要沒有去符號的共享庫(通常是放在out/target/product/xxx/symbols
2.Analyze Tools
即常用的輔助工具
01 addr2line ($(ANDROID_NDK)\toolchains\arm-linux-androideabi-4.7\prebuilt\windows\b
3.Crash Log - Header
資訊頭,包含當前系統版本有關的資訊,如果是做平臺級的開發,這將有助於定位當前的系統的開發版本。
1 Time: 2014-11-28 17:40:522 Build description: xxxx3 Build: xxxx4 Hardware: xxxx5 Revision: 06 Bootloader: unknown7 Radio: unknown8 Kernel: Linux version 3.4.5 xxxx
這部分較為容易閱讀。所以不再贅述。
4.CrashLog – Backtrace(For most crashes)
即最常用的看backtrace部分,backtrace的地址可用addr2line或者ndk-stack查詢對應的symbol,非常直觀,大多數的crash都能夠通過這種方式解決。
01 backtrace:02 #00 pc 00026fbc /system/lib/libc.so03 #01 pc 000004cf /data/app-lib/com.example.hellojni-1/libhello-jni.so (Java_com_example_hellojni_HelloJni_stringFromJNI+18)04 #02 pc 0001e610 /system/lib/libdvm.so (dvmPlatformInvoke+112)05 #03 pc 0004e015 /system/lib/libdvm.so (dvmCallJNIMethod(unsigned int const*, JValue*, Method const*, Thread*)+500)06 #04 pc 00050421 /system/lib/libdvm.so (dvmResolveNativeMethod(unsigned int const*, JValue*, Method const*, Thread*)+200)07 #05 pc 000279e0 /system/lib/libdvm.so08 #06 pc 0002b934 /system/lib/libdvm.so (dvmInterpret(Thread*, Method const*, JValue*)+180)09 #07 pc 0006175f /system/lib/libdvm.so (dvmInvokeMethod(Object*, Method const*, ArrayObject*, ArrayObject*, ClassObject*, bool)+374)10 #08 pc 00069785 /system/lib/libdvm.so11 #09 pc 000279e0 /system/lib/libdvm.so12 #10 pc 0002b934 /system/lib/libdvm.so (dvmInterpret(Thread*, Method const*, JValue*)+180)13 #11 pc 00061439 /system/lib/libdvm.so (dvmCallMethodV(Thread*, Method const*, Object*, bool, JValue*, std::__va_list)+272)14 #12 pc 0004a2ed /system/lib/libdvm.so15 #13 pc 0004d501 /system/lib/libandroid_runtime.so16 #14 pc 0004e259 /system/lib/libandroid_runtime.so (android::AndroidRuntime::start(char const*, char const*)+536)17 #15 pc 00000db7 /system/bin/app_process18 #16 pc 00020ea0 /system/lib/libc.so (__libc_init+64)19 #17 pc 00000ae8 /system/bin/app_process
從上面這份backtrace可以看到包含一個pc地址和後面的symbol。部分錯誤可以通過只看這裡的symbol發現問題所在。而如果想要更準確的定位,則需要藉助ndk工具。
1 $addr2line -aCfe out/target/production/xxx/symbols/system/lib/libhello-jni.so 4cf2 0x4cf3 java_com_example_hellojni_HelloJni_stringFromJNI4 /ANDROID_PRODUCT/hello-jni/jni/hello-jni.c:48
然後再來看看hello-jni.c
01 17 #include18 #include19 20 26 void func_a(char *p);27 void func_b(char *p);28 void func_a(char *p)29 {30 const char* A = "AAAAAAAAA"; // len = 931 char* a = "dead";32 memcpy(p, A, strlen(A));33 memcpy(p, a, strlen(a));34 p[strlen(a)] = 0;35 func_b(p);36 }37 void func_b(char *p)38 {39 char* b = 0xddeeaadd;40 memcpy(b, p, strlen(p));41 }42 43 jstring44 Java_com_example_hellojni_HelloJni_stringFromJNI( JNIEnv* env,45 jobject thiz )46 {47 char buf[10];48 func_a(buf);49 return (*env)->NewStringUTF(env, "Hello from JNI !");50 }
可以看到現在只能看到出錯在func_a(). 這裡面有個比較特別的地方是為什麼backtrace 中只有func_a而沒有出現func_b. 這是編譯器的處理部分,不過多贅述。所以現在只能從backtrace中確認#1是在func_a,然後#0是在libc中的某個函式死掉。其實symbols/system/lib中也包含有libc.so,可以通過addr2line確認是那個函式。而這裡呼叫到libc的只有memcpy, 所以可以基本確定出錯在memcpy,但是有三個memcpy,又怎麼確定是哪一個呢?(當然,可以通過直接檢查程式碼發現是在func_b裡面)
5.CrashLog – Registers
暫存器資訊,可以通過這部分資訊基本確定系統為什麼會錯。
01 pid: 4000, tid: 4000, name: xample.hellojni
02 signal 11 (SIGSEGV), code 1 (SEGV_MAPERR), fault addr ddeeaadd03 r0 ddeeaadd r1 beab238c r2 00000004 r3 beab239004 r4 4012b260 r5 40e1b760 r6 00000004 r7 4bdd2ca005 r8 beab23a8 r9 4bdd2c98 sl 40e1d050 fp beab23bc06 ip 80000000 sp beab2380 lr 518254d3 pc 400dffbc cpsr 8000001007 d0 4141414141414164 d1 6e6a6f6c6c65686508 d2 3133393766666661 d3 726f6c6f632f3c6409 d4 3e2d2d206f646f54 d5 6f633c202020200a10 d6 656d616e20726f6c d7 3f8000003f80000011 d8 0000000000000000 d9 000000000000000012 d10 0000000000000000 d11 000000000000000013 d12 0000000000000000 d13 000000000000000014 d14 0000000000000000 d15 000000000000000015 d16 000000000000019e d17 000000000000019e16 d18 0000000000000000 d19 000000e60000000017 d20 e600000000000000 d21 000000000000000018 d22 0000000000000000 d23 090a0b0c0d0e0f1019 d24 0000004d0000003d d25 000000e60000000020 d26 000000e7000000b7 d27 000000000000000021 d28 0000004d0000003d d29 000000000000000022 d30 0000000100000001 d31 000000010000000123 scr 60000090
這部分資訊展示了出錯時的執行狀態, 當前中斷原因是收到SIGSEGV(通常crash也都是因為收到這個訊號,也有少數是因為SIGFPE,即除0操作)。錯誤碼是SEGV_MAPERR,常見的段錯誤。然後出錯地址為ddeeaadd。即第39行的地址0xddeeadd。所以已經可以基本確定和指標b有關。
而程式碼裡面接下來便是memcpy的操作。所以很明顯就是在這裡的memcpy有問題。
再看r0是ddeeaadd,r1是beab238c,r2是4,其實這三個暫存器剛好代表memcpy的操作引數。目的地址為ddeeaadd,源地址加偏移為beab238c,長度是4。這裡有提到beab238c為源地址加偏移,原因的話會在後面解釋。
通常我們需要關注的暫存器主要就是r0到pc,下面的32個暫存器的話通常是資料存取時常用,有時也會有重要資訊,但一般情況下不會太關注。如果是對這部分不太瞭解的話,也不用擔心,多看一看就自然明白了,筆者在嘗試卻解讀之前也完全沒有接觸過這方面的內容。
6.CrashLog – Memory
日誌當中也提供了出錯時暫存器地址裡面的臨近記憶體資訊,資訊量同樣很豐富。之前有提到r1是與源地址有關,所以先看看r1(0xbeab238c)附近的記憶體情況
1 memory near r1:2 beab236c 4f659a18 51825532 518254a5 df0027ad 3 beab237c 00000000 ddeeaadd 518254d3 64616564 4 beab238c 41414100 41714641 a8616987 40e1d040 5 beab239c 4c11cb40 40e1d040 40a2f614 4bdd2c94 6 beab23ac 00000000 41714608 00000001 417093c4 7 beab23bc 40a5f019 4bdd2c94 518215a3 518254bd
beab238c在第四行,但是注意在第三行末尾有一串類似ASCII的字元,64616564,這即是dead,而從這裡開始,一段記憶體為64616564 41414100 41714641即"64,65,61,64, 00,41,41,41, 41"647141。其實不難發現這就是dead'\0'AAAA,其後位於棧上的值沒有初始化,會比較隨機。
所以func_b中p的起始地址應該是從64616564 的位置開始的,至於為什麼r1是beab238c,解讀一下彙編程式碼即可很容易發現。
在Android中使用的binoc實現中,查詢原始檔為memcpy.s(可通過addr2line 找到檔案路徑和行數)。看到出錯點在memcpy.s +248。
這部分原始碼如下:
這兩段的大致意思為從r1地址讀取4個位元組放到d0~d3,r1地址增加,然後將d0~d3中的資料存入到r0的地址去,同時r0也增加。
現在可以回過去檢視d0~d3暫存器的最後一個位元組,分別是64,65,61,64。為“dead“。因此當前的r1是增加後後的地址。而此時企圖對r0處無效的地址0xddeeaadd寫入資料,所以出錯。並顯示錯誤地址為0xddeeaadd.
objdump,到這裡,再提一提objdump的部分。
可以對共享庫(.so)使用或者對目標檔案(.o)使用,如果共享庫比較大,那還是對被編譯檔案的目標檔案使用比較好。通常來說Android的編譯會預設儲存目標檔案,存放在out/target/product/xxxx/obj目錄下面,於是現在找到libhello-jni.o通過objdump來檢視它的資訊。
jstringJava_com_example_hellojni_HelloJni_stringFromJNI( JNIEnv* env, jobject thiz ){ a: 447c add r4, pc c: 6824 ldr r4, [r4, #0] e: 6821 ldr r1, [r4, #0] 10: 9103 str r1, [sp, #12] char buf[10]; func_a(buf); 12: f7ff fffe bl 0 <</span>Java_com_example_hellojni_HelloJni_stringFromJNI> return (*env)->NewStringUTF(env, "Hello from JNI !"); 16: 6828 ldr r0, [r5, #0] 18: 4907 ldr r1, [pc, #28] ; (38 <</span>Java_com_example_hellojni_HelloJni_stringFromJNI+0x38>) 1a: f8d0 229c ldr.w r2, [r0, #668] ; 0x29c 1e: 4628 mov r0, r5 20: 4479 add r1, pc 22: 4790 blx r2}
不要太在意諸如'Java_com_example_hellojni_HelloJni_stringFromJNI','{','}'之類的符號,它只是提供給我們大致的位置資訊,並不是完全等同於C語言中的程式碼段。
之前有通過backtrace #1看到(Java_com_example_hellojni_HelloJni_stringFromJNI+18)這樣的資訊,將+18轉換成16進製為0x12.那麼對應dump 出來的檔案位置就是上面的12.指令為bl 0.這是一個常見的跳轉指令。從原始碼裡面也可以看到開始呼叫func_a().
再看看func_b的程式碼:
void func_b(char *p){ 0: b510 push {r4, lr} 2: 4604 mov r4, r0 4: f7ff fffe bl 0 <</span>strlen> 8: 4621 mov r1, r4 a: 4602 mov r2, r0 c: 4802 ldr r0, [pc, #8] ; (18 <</span>func_b+0x18>)} e: e8bd 4010 ldmia.w sp!, {r4, lr} 12: f7ff bffe b.w 0 <</span>memcpy> 16: bf00 nop 18: ddeeaadd .word 0xddeeaadd
先將r0(p指標的值)放入r4,呼叫strlen,返回值預設放入r0(值為4),再將r4取出放入r1,然後從pc+8的位置拿地址放入r0(可以看到func_b+0x18為0xddeeaadd),再跳轉到memcpy。所以r0為ddeeaadd,r1為p指標的值,r4為長度。由此進行了memcpy的呼叫,然後出錯。
通過objdump通常可以更進一步的確定錯誤產生的情況,對追蹤程式碼邏輯有極大的幫助,所以在很多情況下解決問題可以只通過閱讀程式碼,並不需要不停地加debug列印並嘗試去複製它。
7.CrashLog – Stack
當backtrace資訊量極少時(沒有給全函式呼叫棧),這是重點。
Stack一欄提供的是執行緒呼叫棧的資訊。可以從右邊的一些symbol大致猜測出錯的位置。但由於stack上的內容可能殘留未初始化或者未清空的資訊,又或者儲存有其他的資料,所以有時會造成一定的困惑。因此stack上的symbol雖然大部分是本次呼叫棧的symbol,但不一定全都是。
stack: beab2340 4012ac68 beab2344 50572968 beab2348 4f659a50 beab234c 0000002f beab2350 00000038 beab2354 50572960 beab2358 beab2390 [stack] beab235c 4012ac68 beab2360 00000071 beab2364 400cb528 /system/lib/libc.so beab2368 00000208 beab236c 4f659a18 beab2370 51825532 /data/app-lib/com.example.hellojni-1/libhello-jni.so beab2374 518254a5 /data/app-lib/com.example.hellojni-1/libhello-jni.so (func_a+56) beab2378 df0027ad beab237c 00000000 #00 beab2380 ddeeaadd beab2384 518254d3 /data/app-lib/com.example.hellojni-1/libhello-jni.so (Java_com_example_hellojni_HelloJni_stringFromJNI+22) #01 beab2388 64616564
棧是由下往上(frame#02->#01->#00)。 現在可以大致看到從#01到#00,從Java_com_example_hellojni_HelloJni_stringFromJNI進入func_a。但是這裡是不能夠通過左邊的地址直接addr2line得到目標symbol。它是屬於在記憶體當中的相對地址。接下來就會提到如何去通過相對地址計算可用的addr2line地址。
8.Library Base Address (共享庫在記憶體中基地址)
通過地址計算得出可用的addr2line地址。
addr2line需要一份未去symbol的共享庫。當代碼沒有改變時,每次生成的.so的符號位置應該是相同的。所以如果想要得到有效的符號,必須要使用程式執行時對應的未去符號的.so。
jni在執行時可以看到在java中有load_library的動作,這個動作大致可以看做將一個庫檔案載入到記憶體當中。因此這個庫在記憶體當中就存在一個載入的基地址,但是根據記憶體的情況和相應的演算法,基地址每次都可能會不一樣。addr2line需要的地址是相對於共享庫的一個絕對地址。因此現在只要能夠得到共享庫在記憶體中的基地址就能夠有辦法通過stack上的地址計算出可用的addr2line地址。
在上面的stack和backtrace資訊當中有(Java_com_example_hellojni_HelloJni_stringFromJNI+22)和(Java_com_example_hellojni_HelloJni_stringFromJNI+18)這兩個symbol的相對地址和絕對地址。
所以基地址的計算應該為對應的地址相減:0x518254d3 - 0x000004cf - 0x4 = 0x51825000.
為了驗證基地址有效性,可以嘗試計算0x518254a5(func_a+56)的符號:0x518254a5 - 0x51825000 = 0x4a5。
然後使用addr2line查詢0x4a5得到hello-jni.c:34。
除此之外還有另一種方法計算可用的地址,同樣需要stack裡提供的個別的symbol資訊: 例0x518254a5(func_a+56),然後之前有提到objdump可以直接將.so作為輸入,這時會出來整個lib的彙編資訊。然後可以從中找到"0xxxxxxxx <func_a>:"這樣的資訊,前面的0xxxxxx就代表函式的在lib中的地址,在這裡是"0x46c <func_a>:" ,然後加上0x38(56) 就等於0x4a4,這個和之前有一定的差別,原因是stack上儲存的會是函式返回地址,但指向的指令是相同的。
提出基地址的問題是為了進一步說明stack中的地址和backtrace中地址的不同,以及共享庫被載入到記憶體當中指令的存在形式,但是通過比較也可以發現,在所載入的庫非常大的時候(例如100M+)前一種方式得到可以用的地址會相對於後一種方式簡單許多。
大多數情況下應該是不需要使用計算基地址的方式。但是也有個別的日誌資訊給出的backtrace不完整,導致難以解析出具體的問題所在。這個時候就需要使用基地址計算的方式得出可用的addr2line地址。
到最後看來,一般只要有一份類似於錯誤日誌的資訊檔案,通常可以解決絕大部分的問題。那麼如果是執行時,可以通過gdb(如果開啟corefile的選項更好),或者kill -9(同樣需要開啟編譯選項才行)。還有就是Android系統通常內自帶有debuggerd命令可以使用。詳情可以從上網查閱。
最後附上本次測試的原始碼:http://vdisk.weibo.com/s/yVmhF5M5tTuIi
2014.12.01