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 該指針時,由於分配和釋放時的指針位置不同發生瞭異常。
 
我們在代碼設計時,要盡量避免同類的使用,如果實在無法避免,應該做好註釋

發佈留言