linux程式崩潰調試技術

作者：宋文生             2012-2-13
 
一，起因
 
在開發android的ril過程中，遇到了rild異常崩潰的現象。該進程直接控制android RIL相關的所有操作，如果異常終止，將導致android framework的重啟。
 
二，細節
 
a)         眾所周知，linux的程式崩潰時，都會列印出崩潰前的stack trace。該stack  trace是我們尋找崩潰原因的重要線索。
 
b)        以下是android rild的崩潰細節
 
01-19 17:48:56.550 I/DEBUG ( 683): Build fingerprint: 'augusta/M70P/m70p/miracle_smt:2.2/M70P-daily/20120119:user/test-keys'
01-19 17:48:56.550 I/DEBUG ( 683): pid: 684, tid: 715 >>> /system/bin/rild <<<
01-19 17:48:56.550 I/DEBUG ( 683): signal 11 (SIGSEGV), fault addr deadbaad
01-19 17:48:56.550 I/DEBUG ( 683): r0 00000000 r1 0000000c r2 00000027 r3 00000000
01-19 17:48:56.550 I/DEBUG ( 683): r4 afd40328 r5 deadbaad r6 00001728 r7 00000000
01-19 17:48:56.550 I/DEBUG ( 683): r8 00100000 r9 ae60532d 10 10000000 fp 00000000
01-19 17:48:56.550 I/DEBUG ( 683): ip ffffffff sp 100ffcf0 lr afd154e1 pc afd11dee cpsr 00000030
01-19 17:48:56.560 W/InputManagerService( 887): Window already focused, ignoring focus gain of: com.android.internal.view.IInputMethodClient$Stub$Proxy@45ffbd88
01-19 17:48:56.580 I/DEBUG ( 683): #00 pc 00011dee /system/lib/libc.so
01-19 17:48:56.580 I/DEBUG ( 683): #01 pc 0000be1c /system/lib/libc.so
01-19 17:48:56.580 I/DEBUG ( 683):
01-19 17:48:56.580 I/DEBUG ( 683): code around pc:
01-19 17:48:56.580 I/DEBUG ( 683): afd11dcc 2d00d10d 1c2bd00b 2d00682d e026d1fb
01-19 17:48:56.580 I/DEBUG ( 683): afd11ddc 2b0068db 4e17d003 51a02001 4d164798
01-19 17:48:56.580 I/DEBUG ( 683): afd11dec 702a2227 edfef7fb f7fc2106 2380ef1c
01-19 17:48:56.580 I/DEBUG ( 683): afd11dfc aa010559 60912400 1c116054 94012006
01-19 17:48:56.580 I/DEBUG ( 683): afd11e0c eaa0f7fc 2200a905 f7fc2002 f7fbeaac
01-19 17:48:56.580 I/DEBUG ( 683):
01-19 17:48:56.580 I/DEBUG ( 683): code around lr:
01-19 17:48:56.580 I/DEBUG ( 683): afd154c0 447b4a0d 589cb083 26009001 686768a5
01-19 17:48:56.580 I/DEBUG ( 683): afd154d0 220ce008 2b005eab 1c28d003 47889901
01-19 17:48:56.590 I/DEBUG ( 683): afd154e0 35544306 d5f43f01 2c006824 b003d1ee
01-19 17:48:56.590 I/DEBUG ( 683): afd154f0 bdf01c30 0002ae62 000000d4 1c0fb5f0
01-19 17:48:56.590 I/DEBUG ( 683): afd15500 43551c3d a904b087 1c16ac01 604d9004
01-19 17:48:56.590 I/DEBUG ( 683):
01-19 17:48:56.590 I/DEBUG ( 683): stack:
01-19 17:48:56.590 I/DEBUG ( 683): 100ffcb0 00000718
01-19 17:48:56.590 I/DEBUG ( 683): 100ffcb4 afd1455b /system/lib/libc.so
01-19 17:48:56.590 I/DEBUG ( 683): 100ffcb8 afd405a0 /system/lib/libc.so
01-19 17:48:56.590 I/DEBUG ( 683): 100ffcbc afd4054c /system/lib/libc.so
01-19 17:48:56.590 I/DEBUG ( 683): 100ffcc0 00000000
01-19 17:48:56.590 I/DEBUG ( 683): 100ffcc4 afd154e1 /system/lib/libc.so
01-19 17:48:56.590 I/DEBUG ( 683): 100ffcc8 00000071
01-19 17:48:56.590 I/DEBUG ( 683): 100ffccc afd1452d /system/lib/libc.so
01-19 17:48:56.590 I/DEBUG ( 683): 100ffcd0 00000000
01-19 17:48:56.590 I/DEBUG ( 683): 100ffcd4 afd40328 /system/lib/libc.so
01-19 17:48:56.590 I/DEBUG ( 683): 100ffcd8 00000000
01-19 17:48:56.590 I/DEBUG ( 683): 100ffcdc 00001728
01-19 17:48:56.590 I/DEBUG ( 683): 100ffce0 00000000
01-19 17:48:56.590 I/DEBUG ( 683): 100ffce4 afd147cb /system/lib/libc.so
01-19 17:48:56.590 I/DEBUG ( 683): 100ffce8 df002777
01-19 17:48:56.590 I/DEBUG ( 683): 100ffcec e3a070ad
01-19 17:48:56.590 I/DEBUG ( 683): #00 100ffcf0 0000b4e8 [heap]
01-19 17:48:56.590 I/DEBUG ( 683): 100ffcf4 c0000000
01-19 17:48:56.590 I/DEBUG ( 683): 100ffcf8 afd418dc /system/lib/libc.so
01-19 17:48:56.590 I/DEBUG ( 683): 100ffcfc afd10538 /system/lib/libc.so
01-19 17:48:56.590 I/DEBUG ( 683): 100ffd00 afd40328 /system/lib/libc.so
01-19 17:48:56.590 I/DEBUG ( 683): 100ffd04 fffffbdf
01-19 17:48:56.590 I/DEBUG ( 683): 100ffd08 afd40328 /system/lib/libc.so
01-19 17:48:56.590 I/DEBUG ( 683): 100ffd0c afd41724 /system/lib/libc.so
01-19 17:48:56.590 I/DEBUG ( 683): 100ffd10 0000b000 [heap]
01-19 17:48:56.590 I/DEBUG ( 683): 100ffd14 afd0be21 /system/lib/libc.so
01-19 17:48:56.600 I/DEBUG ( 683): #01 100ffd18 afd40328 /system/lib/libc.so
01-19 17:48:56.600 I/DEBUG ( 683): 100ffd1c afd0be21 /system/lib/libc.so
01-19 17:48:56.600 I/DEBUG ( 683): 100ffd20 00000002
01-19 17:48:56.600 I/DEBUG ( 683): 100ffd24 0000b4ee [heap]
01-19 17:48:56.600 I/DEBUG ( 683): 100ffd28 0000c574 [heap]
01-19 17:48:56.600 I/DEBUG ( 683): 100ffd2c 0000b4e8 [heap]
01-19 17:48:56.600 I/DEBUG ( 683): 100ffd30 0000c574 [heap]
01-19 17:48:56.600 I/DEBUG ( 683): 100ffd34 00000006
01-19 17:48:56.600 I/DEBUG ( 683): 100ffd38 000013fc
01-19 17:48:56.600 I/DEBUG ( 683): 100ffd3c af9059ff /system/lib/libcutils.so
01-19 17:48:56.600 I/DEBUG ( 683): 100ffd40 0000b4e8 [heap]
01-19 17:48:56.600 I/DEBUG ( 683): 100ffd44 800056b5 /system/lib/libaugusta-ril.so
01-19 17:48:56.600 I/DEBUG ( 683): 100ffd48 100ffd6c
01-19 17:48:56.600 I/DEBUG ( 683): 100ffd4c 0000b438 [heap]
01-19 17:48:56.600 I/DEBUG ( 683): 100ffd50 ae6089bc /system/lib/libril.so
01-19 17:48:56.600 I/DEBUG ( 683): 100ffd54 afd0cd81 /system/lib/libc.so
01-19 17:48:56.600 I/DEBUG ( 683): 100ffd58 800056b5 /system/lib/libaugusta-ril.so
01-19 17:48:56.600 I/DEBUG ( 683): 100ffd5c ae6042a3 /system/lib/libril.so
 
 
 
 
 
 
 
 
 
 
 
 
 
三，分析
 
       幸運的話，我們可以在這個log的前3行，知道崩潰的原因。但更多細節需要我們自己去查。
 
       堆棧記錄：
 
     
 
01-19 17:48:56.590 I/DEBUG ( 683): stack:
01-19 17:48:56.590 I/DEBUG ( 683): 100ffcb0 00000718
01-19 17:48:56.590 I/DEBUG ( 683): 100ffcb4 afd1455b /system/lib/libc.so
01-19 17:48:56.590 I/DEBUG ( 683): 100ffcb8 afd405a0 /system/lib/libc.so
01-19 17:48:56.590 I/DEBUG ( 683): 100ffcbc afd4054c /system/lib/libc.so
01-19 17:48:56.590 I/DEBUG ( 683): 100ffcc0 00000000
01-19 17:48:56.590 I/DEBUG ( 683): 100ffcc4 afd154e1 /system/lib/libc.so
01-19 17:48:56.590 I/DEBUG ( 683): 100ffcc8 00000071
01-19 17:48:56.590 I/DEBUG ( 683): 100ffccc afd1452d /system/lib/libc.so
01-19 17:48:56.590 I/DEBUG ( 683): 100ffcd0 00000000
01-19 17:48:56.590 I/DEBUG ( 683): 100ffcd4 afd40328 /system/lib/libc.so
01-19 17:48:56.590 I/DEBUG ( 683): 100ffcd8 00000000
01-19 17:48:56.590 I/DEBUG ( 683): 100ffcdc 00001728
01-19 17:48:56.590 I/DEBUG ( 683): 100ffce0 00000000
01-19 17:48:56.590 I/DEBUG ( 683): 100ffce4 afd147cb /system/lib/libc.so
01-19 17:48:56.590 I/DEBUG ( 683): 100ffce8 df002777
01-19 17:48:56.590 I/DEBUG ( 683): 100ffcec e3a070ad
01-19 17:48:56.590 I/DEBUG ( 683): #00 100ffcf0 0000b4e8 [heap]
01-19 17:48:56.590 I/DEBUG ( 683): 100ffcf4 c0000000
01-19 17:48:56.590 I/DEBUG ( 683): 100ffcf8 afd418dc /system/lib/libc.so
01-19 17:48:56.590 I/DEBUG ( 683): 100ffcfc afd10538 /system/lib/libc.so
01-19 17:48:56.590 I/DEBUG ( 683): 100ffd00 afd40328 /system/lib/libc.so
01-19 17:48:56.590 I/DEBUG ( 683): 100ffd04 fffffbdf
01-19 17:48:56.590 I/DEBUG ( 683): 100ffd08 afd40328 /system/lib/libc.so
01-19 17:48:56.590 I/DEBUG ( 683): 100ffd0c afd41724 /system/lib/libc.so
01-19 17:48:56.590 I/DEBUG ( 683): 100ffd10 0000b000 [heap]
01-19 17:48:56.590 I/DEBUG ( 683): 100ffd14 afd0be21 /system/lib/libc.so
01-19 17:48:56.600 I/DEBUG ( 683): #01 100ffd18 afd40328 /system/lib/libc.so
01-19 17:48:56.600 I/DEBUG ( 683): 100ffd1c afd0be21 /system/lib/libc.so
01-19 17:48:56.600 I/DEBUG ( 683): 100ffd20 00000002
01-19 17:48:56.600 I/DEBUG ( 683): 100ffd24 0000b4ee [heap]
01-19 17:48:56.600 I/DEBUG ( 683): 100ffd28 0000c574 [heap]
01-19 17:48:56.600 I/DEBUG ( 683): 100ffd2c 0000b4e8 [heap]
01-19 17:48:56.600 I/DEBUG ( 683): 100ffd30 0000c574 [heap]
01-19 17:48:56.600 I/DEBUG ( 683): 100ffd34 00000006
01-19 17:48:56.600 I/DEBUG ( 683): 100ffd38 000013fc
01-19 17:48:56.600 I/DEBUG ( 683): 100ffd3c af9059ff /system/lib/libcutils.so
01-19 17:48:56.600 I/DEBUG ( 683): 100ffd40 0000b4e8 [heap]
01-19 17:48:56.600 I/DEBUG ( 683): 100ffd44 800056b5 /system/lib/libaugusta-ril.so
01-19 17:48:56.600 I/DEBUG ( 683): 100ffd48 100ffd6c
01-19 17:48:56.600 I/DEBUG ( 683): 100ffd4c 0000b438 [heap]
01-19 17:48:56.600 I/DEBUG ( 683): 100ffd50 ae6089bc /system/lib/libril.so
01-19 17:48:56.600 I/DEBUG ( 683): 100ffd54 afd0cd81 /system/lib/libc.so
01-19 17:48:56.600 I/DEBUG ( 683): 100ffd58 800056b5 /system/lib/libaugusta-ril.so
01-19 17:48:56.600 I/DEBUG ( 683): 100ffd5c ae6042a3 /system/lib/libril.so
 
       寄存器：
 
01-19 17:48:56.550 I/DEBUG ( 683): r0 00000000 r1 0000000c r2 00000027 r3 00000000
01-19 17:48:56.550 I/DEBUG ( 683): r4 afd40328 r5 deadbaad r6 00001728 r7 00000000
01-19 17:48:56.550 I/DEBUG ( 683): r8 00100000 r9 ae60532d 10 10000000 fp 00000000
01-19 17:48:56.550 I/DEBUG ( 683): ip ffffffff sp 100ffcf0 lr afd154e1 pc afd11dee cpsr 00000030
 
       PC在模組中的offset：
 
01-19 17:48:56.580 I/DEBUG ( 683): #00 pc 00011dee /system/lib/libc.so
01-19 17:48:56.580 I/DEBUG ( 683): #01 pc 0000be1c /system/lib/libc.so
 
       PC附近的機器碼：
 
01-19 17:48:56.580 I/DEBUG ( 683): code around pc:
01-19 17:48:56.580 I/DEBUG ( 683): afd11dcc 2d00d10d 1c2bd00b 2d00682d e026d1fb
01-19 17:48:56.580 I/DEBUG ( 683): afd11ddc 2b0068db 4e17d003 51a02001 4d164798
01-19 17:48:56.580 I/DEBUG ( 683): afd11dec 702a2227 edfef7fb f7fc2106 2380ef1c
01-19 17:48:56.580 I/DEBUG ( 683): afd11dfc aa010559 60912400 1c116054 94012006
01-19 17:48:56.580 I/DEBUG ( 683): afd11e0c eaa0f7fc 2200a905 f7fc2002 f7fbeaac
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
       LR附近的機器碼：
 
01-19 17:48:56.580 I/DEBUG ( 683): code around lr:
01-19 17:48:56.580 I/DEBUG ( 683): afd154c0 447b4a0d 589cb083 26009001 686768a5
01-19 17:48:56.580 I/DEBUG ( 683): afd154d0 220ce008 2b005eab 1c28d003 47889901
01-19 17:48:56.590 I/DEBUG ( 683): afd154e0 35544306 d5f43f01 2c006824 b003d1ee
01-19 17:48:56.590 I/DEBUG ( 683): afd154f0 bdf01c30 0002ae62 000000d4 1c0fb5f0
01-19 17:48:56.590 I/DEBUG ( 683): afd15500 43551c3d a904b087 1c16ac01 604d9004
 
以上幾個部分，是log的組成。以下解釋每個部分的作用。
 
堆棧記錄：
 
1.       堆棧在程式中的作用
 
a)         傳遞函數參數
 
b)        記錄函數的返回地址
 
c)        暫存資料
 
2.       從堆棧記錄裡我們能看到函數之間的調用過程。
 
3.       從以上的log上，我們看到libril 調用了libaugusta-ril中的函數，接著又調用了其他模組的函數。
 
寄存器：
 
1.       寄存器是電腦運算的基礎單元，熟悉組合語言的人對寄存器都不陌生。寄存器的一部分是通用寄存器，另外一些是專用的寄存器，有自己特定的功能。關於寄存器的具體的內容這裡不具體講述。
 
2.       PC是寄存器中重要的寄存器。保持了當前運行程式的記憶體空間中正在執行的代碼的位置。此例中pc的內容為afd11dee，表示當程式執行到了afd11dee，出現了問題。
 
注意，此處顯示的值，是真實的程式記憶體空間的值，不是模組內的位移。
 
3.       LR是類似PC的一個寄存器，保持的是程式跳轉時PC的值。看過linux核心起始引導組譯工具的人，應該明白lr的作用。
 
機器碼： 個人感覺用途不是很大，可以輔助定位。
 
四，動手
 
明白了log各個部分的作用，現在要尋找導致崩潰的真正原因。
 
Linux程式在運行時，會將所有用到的模組載入到記憶體，所有的段分布到統一的虛擬記憶體空間中。從以上的堆棧的log上，我們能看到程式的調用過程，其中的地址都是記憶體空間的虛擬位址。我們只知道該位置位於哪個模組，卻不知道具體的哪個函數出了問題。但地址又確確實實對應了一個函數，只有知道了模組在記憶體中的分布情況，才能找到對應位移位置的函數。
 
1.       查看記憶體分布
 
我們的進程名字叫rild。使用命令ps –ef ，得到該進程的pid，假設為702。在/proc下，有每個進程對應的運行態資訊。使用命令cat /proc/702/maps ，得到給進程的記憶體分布。
 
00008000-0000a000 r-xp 00000000 00:0e 718        /system/bin/rild
 
0000a000-0000b000 rw-p 00002000 00:0e 718        /system/bin/rild
 
0000b000-0000e000 rw-p 00000000 00:00 0          [heap]
 
80000000-8000b000 r-xp 00000000 00:0e 311        /system/lib/libaugusta-ril.so
 
8000b000-8000c000 rw-p 0000b000 00:0e 311        /system/lib/libaugusta-ril.so
 
a7e00000-a7e04000 r-xp 00000000 00:0e 240        /system/lib/libhardware_legacy.so
 
a7e04000-a7e05000 rw-p 00004000 00:0e 240        /system/lib/libhardware_legacy.so
 
a8100000-a8127000 r-xp 00000000 00:0e 236        /system/lib/libutils.so
 
a8127000-a8128000 rw-p 00027000 00:0e 236        /system/lib/libutils.so
 
a8200000-a821f000 r-xp 00000000 00:0e 269        /system/lib/libbinder.so
 
a821f000-a8225000 rw-p 0001f000 00:0e 269        /system/lib/libbinder.so
 
ae300000-ae304000 r-xp 00000000 00:0e 297        /system/lib/libnetutils.so
 
ae304000-ae305000 rw-p 00004000 00:0e 297        /system/lib/libnetutils.so
 
ae400000-ae402000 r-xp 00000000 00:0e 233        /system/lib/libwpa_client.so
 
ae402000-ae403000 rw-p 00002000 00:0e 233        /system/lib/libwpa_client.so
 
ae600000-ae608000 r-xp 00000000 00:0e 349        /system/lib/libril.so
 
ae608000-ae609000 rw-p 00008000 00:0e 349        /system/lib/libril.so
 
af700000-af714000 r-xp 00000000 00:0e 326        /system/lib/libz.so
 
af714000-af715000 rw-p 00014000 00:0e 326        /system/lib/libz.so
 
af900000-af90e000 r-xp 00000000 00:0e 264        /system/lib/libcutils.so
 
af90e000-af90f000 rw-p 0000e000 00:0e 264        /system/lib/libcutils.so
 
afa00000-afa03000 r-xp 00000000 00:0e 261        /system/lib/liblog.so
 
afa03000-afa04000 rw-p 00003000 00:0e 261        /system/lib/liblog.so
 
afb00000-afb20000 r-xp 00000000 00:0e 356        /system/lib/libm.so
 
afb20000-afb21000 rw-p 00020000 00:0e 356        /system/lib/libm.so
 
afc00000-afc01000 r-xp 00000000 00:0e 323        /system/lib/libstdc++.so
 
afc01000-afc02000 rw-p 00001000 00:0e 323        /system/lib/libstdc++.so
 
afd00000-afd40000 r-xp 00000000 00:0e 332        /system/lib/libc.so
 
afd40000-afd43000 rw-p 00040000 00:0e 332        /system/lib/libc.so
 
b0001000-b0011000 r-xp 00001000 00:0e 735        /system/bin/linker
 
b0011000-b0012000 rw-p 00011000 00:0e 735        /system/bin/linker
 
bee51000-bee53000 rw-p 00000000 00:00 0          [stack]
 
2.       具體位置
 
注意，以上的記憶體資訊，與stack trace的log是兩台機器上取得，所以會有偏差。
 
從以上的maps中可以看到每個模組在虛擬空間中分布情況。
 
有了模組的分布位置，我們就可以定位模組裡的函數。
 
從stack 的log裡，發現了800056b5 /system/lib/libaugusta-ril.so，從maps裡發現libaugusta-ril.so的起始位置為80000000， 可以很容易的知道該函數位於該模組的00056b5處。
 
到此，我們已經學會了，定位模組裡函數位置的方法了，下一步是獲得函數名。
 
五，尋找
 
當系統在編譯器時，會分成幾個步驟。最後的步驟是strip，就是把產生的模組中不必要的符號和調試資訊去掉，以減少體積和載入時間。所以，如果直接使用最終的so，我們是得不到想要的結果的，我們需要的是沒有strip過的模組。
 
在android的編譯過程中，產生的中間檔案都會放置在out目錄的obj下，在obj目錄下，對應每個模組都有自己的檔案夾。在模組檔案夾中，有LINKED目錄，裡面保持的是沒有strip過的結果。這個檔案正是我們需要的檔案。
 
六，Dump和反編譯
 
任何一個編譯工具都會提供一個dump的工具，用於瞭解產生結果的內部資訊。
 
使用dump，我們可以知道產生程式的段的資訊，符號表資訊，甚至可以反組譯碼。
 
這裡我們使用arm-eabi-objdump –dx libaugusta-ril.so > dumplog，來進行反組譯碼。
 
 
 
從dumplog檔案中搜尋56b5，我們神奇的發現，該位置對應的函數是onRequest。
 
按照上面的辦法，我們逐步分析，就可以知道出問題時的函數調用路徑，可以清晰的知道問題發生的原因。
 
七，本例的啟示
 
以上的log資訊，是一個比較特殊的操作引起的，也是大家很容易發生的錯誤。這裡在具體描述一下。
 
最終的錯誤定位在libc.so的free函數上，通過這個線索，按照函數的調用路徑重新查看了一下代碼，發現了問題的所在。
 
錯誤的代碼模型如下：
 
struct a {  char * b;};
 
 
 
void func2(struct a * s)
 
{    s.b += 1;}
 
 
 
void func1()
 
{
 
     struct a st;
 
     st.b = malloc(100);
 
     func2(&st);
 
     free(st.b);
 
}
 
 
 
st的地址作為 指標參數傳遞給func2,但是在func2中對成員b進行了修改，並且生效，最後的結果是func1在free 該指標時，由於分配和釋放時的指標位置不同發生了異常。
 
我們在代碼設計時，要盡量避免同類的使用，如果實在無法避免，應該做好注釋