在Android開發中,程式Crash分三種情況:未捕獲的異常、ANR(Application Not Responding)和閃退(NDK引發錯誤)。其中未捕獲的異常根據logcat列印的堆疊資訊很容易定位錯誤。ANR錯誤也好查,Android規定,應用與使用者進行互動時,如果5秒內沒有響應使用者的操作,則會引發ANR錯誤,並彈出一個系統提示框,讓使用者選擇繼續等待或 立即關閉程式。並會在/data/anr目錄下生成一個traces.txt檔案,記錄系統產生anr異常的堆疊和執行緒資訊。如果是閃退, 這問題比較難查,通常是專案中用到了NDK引發某類致命的錯誤導致閃退。
因為NDK是使用C/C++來進行開發,熟悉C/C++的程式設計師都知道,指標和記憶體管理是最重要也是最容易出問題的地方,稍有不慎就會遇到諸如記憶體地址訪問 錯誤、使用野針對、記憶體洩露、堆疊溢位、初始化錯誤、型別轉換錯誤、數字除0等常見的問題,導致最後都是同一個結果:程式崩潰。不會像在Java層產生的 異常時彈出“xxx程式無響應,是否立即關閉”之類的提示框。當發生NDK錯誤後,logcat列印出來的那堆日誌根據看不懂,更別想從日 志當中定位錯誤的根源,讓我時常有點抓狂,火冒三丈,喝多少加多寶都不管用。當時嘗試過在各個jni函式中列印日誌來跟蹤問題,那效率實在是太低了,而且 還定位不到問題。還好老天有眼,讓我找到了NDK提供的幾款除錯工具,能夠精確的定位到產生錯誤的根源。
NDK安裝包中提供了三個除錯工 具:addr2line、objdump和ndk-stack,其中ndk-stack放在$NDK_HOME目錄下, 與ndk-build同級目錄。addr2line和objdump在ndk的交叉編譯器工具鏈目錄下,下面是我本機NDK交叉編譯器工具鏈的目錄結構:
從上圖的目錄結構中可以看出來,NDK針對不同的CPU架構實現了多套相同的工具。所以在選擇addr2line 和objdump工具的時候,要根據你目標機器的CPU架構來選擇。如果是arm架構,選擇arm-linux-androidabi- 4.6/4.8(一般選擇高版本)。x86架構,選擇x86-4.6/4.8。mipsel架構,選擇mipsel-linux-android-4.6 /4.8。如果不知道目標機器的CPU架構,把手機連上電腦,用adb shell cat /proc/cpuinfo可以檢視手機的CPU資訊。下圖是我本機的arm架構工具鏈目錄結構:
下面通過NDK自帶的例子hello-jni專案來演示一下如何精確的定位錯誤:
1 2 3 4 5 6 7 8 9 10 11 12 13 14 15 16 17 18 19 20 21 22 23 24 25 26 27 28 |
#include <string.h> #include <jni.h> // hell-jni.c #ifdef __cplusplus extern "C" { #endif void willCrash() { int i = 10; int y = i / 0; } JNIEXPORT jint JNICALL JNI_OnLoad(JavaVM* vm, void* reserved) { willCrash(); return JNI_VERSION_1_4; } jstring Java_com_example_hellojni_HelloJni_stringFromJNI( JNIEnv* env, jobject thiz ) { // 此處省略實現邏輯。。。 } #ifdef __cplusplus } #endif |
第7行定義了一個willCrash函式,函式中有一個除0的非法操作,會造成程式崩潰。第13行JNI_OnLoad函式中呼叫了willCrash,這個函式會在Java載入完.so檔案之後回撥,也就是說程式一啟動就會崩潰。下面是執行程式後列印的log:
1 2 3 4 5 6 7 8 9 10 11 12 13 14 15 16 17 18 19 20 21 22 23 24 25 26 27 28 29 30 31 32 |
01-01 17:59:38.246: D/dalvikvm(20794): Late-enabling CheckJNI 01-01 17:59:38.246: I/ActivityManager(1185): Start proc com.example.hellojni for activity com.example.hellojni/.HelloJni: pid=20794 uid=10351 gids={50351, 1028, 1015} 01-01 17:59:38.296: I/dalvikvm(20794): Enabling JNI app bug workarounds for target SDK version 3... 01-01 17:59:38.366: D/dalvikvm(20794): Trying to load lib /data/app-lib/com.example.hellojni-1/libhello-jni.so 0x422a4f58 01-01 17:59:38.366: D/dalvikvm(20794): Added shared lib /data/app-lib/com.example.hellojni-1/libhello-jni.so 0x422a4f58 01-01 17:59:38.366: A/libc(20794): Fatal signal 8 (SIGFPE) at 0x0000513a (code=-6), thread 20794 (xample.hellojni) 01-01 17:59:38.476: I/DEBUG(253): pid: 20794, tid: 20794, name: xample.hellojni >>> com.example.hellojni <<< 01-01 17:59:38.476: I/DEBUG(253): signal 8 (SIGFPE), code -6 (SI_TKILL), fault addr 0000513a 01-01 17:59:38.586: I/DEBUG(253): r0 00000000 r1 0000513a r2 00000008 r3 00000000 01-01 17:59:38.586: I/DEBUG(253): r4 00000008 r5 0000000d r6 0000513a r7 0000010c 01-01 17:59:38.586: I/DEBUG(253): r8 75226d08 r9 00000000 sl 417c5c38 fp bedbf134 01-01 17:59:38.586: I/DEBUG(253): ip 41705910 sp bedbf0f0 lr 4012e169 pc 4013d10c cpsr 000f0010 // 省略部份日誌 。。。。。。 01-01 17:59:38.596: I/DEBUG(253): backtrace: 01-01 17:59:38.596: I/DEBUG(253): #00 pc 0002210c /system/lib/libc.so (tgkill+12) 01-01 17:59:38.596: I/DEBUG(253): #01 pc 00013165 /system/lib/libc.so (pthread_kill+48) 01-01 17:59:38.596: I/DEBUG(253): #02 pc 00013379 /system/lib/libc.so (raise+10) 01-01 17:59:38.596: I/DEBUG(253): #03 pc 00000e80 /data/app-lib/com.example.hellojni-1/libhello-jni.so (__aeabi_idiv0+8) 01-01 17:59:38.596: I/DEBUG(253): #04 pc 00000cf4 /data/app-lib/com.example.hellojni-1/libhello-jni.so (willCrash+32) 01-01 17:59:38.596: I/DEBUG(253): #05 pc 00000d1c /data/app-lib/com.example.hellojni-1/libhello-jni.so (JNI_OnLoad+20) 01-01 17:59:38.596: I/DEBUG(253): #06 pc 00052eb1 /system/lib/libdvm.so (dvmLoadNativeCode(char const*, Object*, char**)+468) 01-01 17:59:38.596: I/DEBUG(253): #07 pc 0006a62d /system/lib/libdvm.so 01-01 17:59:38.596: I/DEBUG(253): // 省略部份日誌 。。。。。。 01-01 17:59:38.596: I/DEBUG(253): stack: 01-01 17:59:38.596: I/DEBUG(253): bedbf0b0 71b17034 /system/lib/libsechook.so 01-01 17:59:38.596: I/DEBUG(253): bedbf0b4 7521ce28 01-01 17:59:38.596: I/DEBUG(253): bedbf0b8 71b17030 /system/lib/libsechook.so 01-01 17:59:38.596: I/DEBUG(253): bedbf0bc 4012c3cf /system/lib/libc.so (dlfree+50) 01-01 17:59:38.596: I/DEBUG(253): bedbf0c0 40165000 /system/lib/libc.so 01-01 17:59:38.596: I/DEBUG(253): // 省略部份日誌 。。。。。。 01-01 17:59:38.736: W/ActivityManager(1185): Force finishing activity com.example.hellojni/.HelloJni |
日誌分析:
第 3行開始啟動應用,第5行嘗試載入應用資料目錄下的so,第6行在載入so檔案的時候產生了一個致命的錯誤,第7行的Fatal signal 8提示這是一個致命的錯誤,這個訊號是由linux核心發出來的,訊號8的意思是浮點數運算異常,應該是在willCrash函式中做除0操作所產生的。 下面重點看第15行backtrace的日誌,backtrace日誌可以看作是JNI呼叫的堆疊資訊,以“#兩位數字 pc”開頭的都是backtrace日誌。注意看第20行和21行,是我們自己編譯的so檔案和定義的兩個函式,在這裡引發了異常,導致程式崩潰。
1 2 |
01-01 17:59:38.596: I/DEBUG(253): #04 pc 00000cf4 /data/app-lib/com.example.hellojni-1/libhello-jni.so (willCrash+32) 01-01 17:59:38.596: I/DEBUG(253): #05 pc 00000d1c /data/app-lib/com.example.hellojni-1/libhello-jni.so (JNI_OnLoad+20) |
開始有些眉目了,但具體崩在這兩個函式的哪個位置,我們是不確定的,如果函式程式碼比較少還好查,如果比較複雜的話,查起來也費勁。這時候就需要靠NDK為 我們提供的工具來精確定位了。在這之前,我們先記錄下讓程式崩潰的彙編指令地 址,willCrash:00000cf4,JNI_OnLoad:00000d1c
方式1:使用arm-linux-androideabi-addr2line 定位出錯位置
以arm架構的CPU為例,執行如下命令:
1 |
/Users/yangxin/Documents/devToos/java/android-ndk-r9d/toolchains/arm-linux-androideabi-4.8/prebuilt/darwin-x86_64/bin/arm-linux-androideabi-addr2line -e /Users/yangxin/Documents/devToos/java/android-ndk-r9d/samples/hello-jni/obj/local/armeabi-v7a/libhello-jni.so 00000cf4 00000d1c |
-e:指定so檔案路徑
0000cf4 0000d1c:出錯的彙編指令地址
結果如下:
是不是驚喜的看到我們想要的結果了,分別在hello-jni.c的10和15行的出的錯,再回去看看hello-jni.c的原始碼,15行的Jni_OnLoad函內呼叫了willCrash函式,第10行做了除0的操作引發的crash。
方式2:使用arm-linux-androideabi-objdump 定位出錯的函式資訊
在第一種方式中,通過addr2lin已經獲取到了程式碼出錯的位置,但是不知道函式的上下文資訊,顯得有點不是那麼的“完美”,對於追求極致的我來說,這顯然是不夠的,下面我們來看一下怎麼來定位函式的資訊。
首先使用如下命令匯出so的函式表資訊:
1 |
/Users/yangxin/Documents/devToos/java/android-ndk-r9d/toolchains/arm-linux-androideabi-4.8/prebuilt/darwin-x86_64/bin/arm-linux-androideabi-objdump -S -D /Users/yangxin/Documents/devToos/java/android-ndk-r9d/samples/hello-jni/obj/local/armeabi-v7a/libhello-jni.so > Users/yangxin/Desktop/dump.log |
在生成的asm檔案中,找出我們開始定位到的那兩個出錯的彙編指令地址(在檔案中搜尋cf4或willCrash可以找到),如下圖所示:
通過這種方式,也可以查出這兩個出錯的指標地址分別位於哪個函式中。
方式3:ndk-stack
如果你覺得上面的方法太麻煩的話,ndk-stack可以幫你減輕操作步聚,直接定位到程式碼出錯的位置。
實時分析日誌:
使用adb獲取logcat的日誌,並通過管道輸出給ndk-stack分析,並指定包含符號表的so檔案位置。如果程式包含多種CPU架構,需要根據手機的CPU型別,來選擇不同的CPU架構目錄。以armv7架構為例,執行如下命令:
1 |
adb logcat | ndk-stack -sym /Users/yangxin/Documents/devToos/java/android-ndk-r9d/samples/hello-jni/obj/local/armeabi-v7a |
當程式發生crash時,會輸出如下資訊:
1 2 3 4 5 6 7 8 9 10 |
pid: 22654, tid: 22654, name: xample.hellojni >>> com.example.hellojni <<< signal 8 (SIGFPE), code -6 (SI_TKILL), fault addr 0000587e Stack frame #00 pc 0002210c /system/lib/libc.so (tgkill+12) Stack frame #01 pc 00013165 /system/lib/libc.so (pthread_kill+48) Stack frame #02 pc 00013379 /system/lib/libc.so (raise+10) Stack frame #03 pc 00000e80 /data/app-lib/com.example.hellojni-1/libhello-jni.so (__aeabi_idiv0+8): Routine __aeabi_idiv0 at /s/ndk-toolchain/src/build/../gcc/gcc-4.6/libgcc/../gcc/config/arm/lib1funcs.asm:1270 Stack frame #04 pc 00000cf4 /data/app-lib/com.example.hellojni-1/libhello-jni.so (willCrash+32): Routine willCrash at /Users/yangxin/Documents/devToos/java/android-ndk-r9d/samples/hello-jni/jni/hello-jni.c:10 Stack frame #05 pc 00000d1c /data/app-lib/com.example.hellojni-1/libhello-jni.so (JNI_OnLoad+20): Routine JNI_OnLoad at /Users/yangxin/Documents/devToos/java/android-ndk-r9d/samples/hello-jni/jni/hello-jni.c:15 Stack frame #06 pc 00052eb1 /system/lib/libdvm.so (dvmLoadNativeCode(char const*, Object*, char**)+468) Stack frame #07 pc 0006a62d /system/lib/libdvm.so |
第7行和第8行分別列印出了在原始檔中出錯的位置,和addr2line得到的結果一樣。
先獲取日誌再分析:
這種方式和上面的方法差不多,只是獲取log的來源不一樣。適用於應用或遊戲給測試部們測試的時候,測試人員發現crash,用adb logcat儲存日誌檔案,然後發給程式設計師通過ndk-stack命令分析。操作流程如下:
1 2 |
adb logcat > crash.log ndk-stack -sym /Users/yangxin/Documents/devToos/java/android-ndk-r9d/samples/hello-jni/obj/local/armeabi-v7a -dump crash.log |
得到的結果和上面的方式是一樣的。