trace C/C++ function call 的方法

目的

• 了解特定模組或類別的使用方式。
• 找出執行時間過長的函式

方法一: 使用 gcc 參數 -finstrument-functions

參考資料:

• Code Gen Options - Using the GNU Compiler Collection (GCC)
• Jserv's blog: GCC 函式追蹤功能

優點:

• 自動含蓋所有函式。

缺點:

• 可能增加太多執行負擔, 雖然可以配合 -finstrument-functions-exclude-file-list 去除不想觀察的函式, 對於大專案來說有些不方便。

方法二: 自己寫 logger

使用 C/C++ 或 gcc 提供的語法, 自己寫 logger 沒有想像中的麻煩:

• 可用 gcc 的 __PRETTY_FUNCTION__ 或標準的 __func__ 取得函式名稱
• 用 __LINE__ 取得行數
• 用 __FILE__ 取得檔名

於是可定個巨集:

#define LOG_IT() MyFunctionLogger logger(__FILE__, __LINE__, __PRETTY_FUNCTION__)

然後用 vim 的全域取代:

:% s/^{/&\r  LOG_IT();\r\r/c

這會逐個詢問是否取代下列字串:

void foo()
{
  // blah blah

為

void foo()
{
  LOG_IT();

  // blah blah

Btw, 由此可知, 函式的左大括號放在行首比放在行尾來得方便。

MyFunctionLogger 只是個 wrapper, 目的是利用 RAII 記錄進入和離開函式, 這樣即使函式中間有任何 return, 都不會漏記離開函式:

class MyFunctionLogger
{
public:
  MyFunctionLogger(const char *file, int line, const char *func)
      : m_file(file), m_line(line), m_func(func)
  {
    MyLogger::Instance()->EnterFunctionCall(m_file, m_line, m_func);
  }

  ~MyFunctionLogger()
  {
    MyLogger::Instance()->LeaveFunctionCall(m_file, m_line, m_func);
  }

private:
  const char *m_file;
  int m_line;
  const char *m_func;
};

MyLogger 可以做的事很多, 比方說:

• 用 file 做為 tag 分類輸出。
• 在 EnterFunctionCall() 和 LeaveFunctionCall() 記錄層級, 輸出 function call 時, 視 function call 的深度做對應的縮排。
• 在 EnterFunctionCall() 和 LeaveFunctionCall() 記錄目前時間, 可在 LeaveFunctionCall() 時計算執行時間, 協助 profiling。

若 MyLogger 會被多個 thread 使用, 別忘了將 MyLogger 寫成 thread-safe, 不過以觀察或除錯的角度來說, 偷懶不作應該也OK吧。

若目標模組是純 C 的程式, 可用 gcc 的 cleanup attribute 做出 RAII 的效果, 達到和 MyFunctionLogger 一樣的效果。

vim 顯示目前函式的名稱

我平常習慣用 gj 跳到某個 symbol 位置, 但接下來上下讀程式時, 有時需要知道目前在那個函式裡, 幸好有前人提供 script 做這件事。省了自己摸索的時間。

藉這機會順便學一些 vim script 的語法:

fun! ShowFuncName()
  let lnum = line(".")  " (1)
  let col = col(".")
  echohl ModeMsg        " (2)
  echo getline(search("^[^ \t#/]\\{2}.*[^:]\s*$", 'bW'))  " (3)
  echohl None
  call search("\\%" . lnum . "l" . "\\%" . col . "c")  "(4)
endfun
map F :call ShowFuncName() <CR>  " (5)

注意 vim 是用 「"」 表示後面的字為註解

1.

• let VAR = VALUE: vim 的設值
• line("."): expression, 取回目前行數
• col("."): expression, 取回目前欄數

這裡存下目前的位置, 在 (4) 的時候可以跳回原位 (後述)。

2.

• 切換 echo 字串 highlight 的方式, 比方 echohl WarningMsg 預設會顯示紅字

3.

• :call FUNCTION(...): 呼叫函式 FUNCTION
• getline(N): 顯示檔案內第 N 行字串
• search(REGEXP, FLAG): 搜尋字串, 跳到符合的位置並傳回顯示符合的行數
• :call search(REGEXP, 'bW'): b 表示往上搜; W 表示搜到底的時候, 不用從頭 (或尾) 繼續搜。見 Searching - Vim Tips Wiki 了解更多 search 技巧
• 所以這一行的意思是往上找到開頭「兩個字不為空白字元和註解開頭」的行, 並且此行結尾不能是':'
• 由於 search() 會傳回行數, 搭配 getline() 完成目的

若希望此函式一併支援 Objective-C 的函式, 更改 REGEXP 即可, 雖說會有一些辛苦就是了。

4.

• 由於 search() 會更動游標位置, 再用 search("\\%Yl\\%Xc") 跳回原本的位置, 其中 (X, Y) 表示原本的游標位置

5.

• 我平時會用到 f, 所以改用 F 觸發這個函式。

在 x86-64 上對 system call 使用 conditional break

在了解目標模組的動態行為時, 最近覺得從模組的 public interface 設中斷點是滿不錯的作法。廣意來說, system call 則是最一般化的 public interface, 從 system call 回頭夾擊目標也滿有效的。比方像這篇用 strace 找到切入點。

若想獲得更多資訊, 可以用 gdb 在 system call 上設中斷點, 一步步從退回來找到呼叫者、傳遞的資料等更多訊息。但在尋找 write、send 這類廣為使用的 system call 時, 被呼叫的次數過於頻繁, 就有點難找了。

查了一下, 看到這篇提到從 register 設定 conditional break 的方法:

(gdb) b write if 1==$rdi  # stop only when write(1, ...)

Scott 補充了以下的資訊:

要在 syscall argument 上設條件，且要 portable 以目前的工具不容易。用 gdb 的話需能背出『x86-64 上參數依序擺在 rdi, rsi, rdx, rcx, r8d, r9d』。 x86-64 上特別好記，因 syscall 與 一般 function call 被設計成將參數擺在同位置。ARM 上還有 64bit 參數開頭一定擺在偶數暫存器如 r0-r1, r2-r3 而不擺在 r1-r2 等規則。

目前 gdb 沒有將 syscall parameter 存在如 $syscall_arg0 的 convenience variable 中，否則寫: catch syscall write if $syscall_arg0 == 1 即可。

用 "system call calling convention" 當關鍵字查到《What are the calling conventions for UNIX & Linux system calls on x86-64》, 文中有許多相關資訊, 就先備忘吧。

以使用 libsqlite 為例說明如何找到程式的進入點

一直對於如何善用 runtime 資訊找到程式進入點很有興趣, 終於有個不錯的小例子。

目標

假設要觀察的專案有用到 sqlite 儲存資料, 從使用方式知道一開始會先載入 sqlite 的內容, 現在想找到程式讀取第一筆資料的進入點。

第一步先觀察程式如何使用 sqlite, 是用 shared lib 或是直接包含在程式裡:

$ ldd PROG | grep sqlite

Case 1: 沒有結果, 表示 sqlite 的實作直接含在 PROG 裡面

找出和 sqlite 相關的 API:

$ nm PROG | grep sqlite | awk '{print $NF}' | xargs c++filt

或是查官網文件也成, 不過個人覺得 nm + c++filt 這招比較方便也比較酷。

觀察一下後, 得知開檔的 API 有: sqlite3_open, sqlite3_open16, sqlite3_open_v2, 之後用 cgdb 執行程式, 都設中斷點, 就結案了。

Case 2: 有 grep 結果, 表示在 shared lib 裡

若不想看官方文件, 也想來個動態搜集 API, 可用 ltrace:

$ ltrace -l /usr/lib/x86_64-linux-gnu/libsqlite3.so.0 PROG

其中 libsqlite3 的路徑是從 ldd PROG 得知的。

安裝需要的 debug symbol, 以做進一步觀察:

$ aptitude search sqlite | grep dbg # 找到 libsqlite3-0-dbg
$ sudo aptitude install libsqlite3-0-dbg

再來就用 cgdb 執行程式, 準備設中斷點, 結案。

相關參考資料:

• 追踪 glibc 裡的程式
• gdb 如何找到 debug symbol

查 C/C++ symbol 定義的方法

記一下目前習慣找 SYMBOL 定義的方法, 只是模糊的片段經驗, 日後再補充完整一些

用 gj

在命令列打: gj SYMBOL class 或 gj SYMBOL struct 找類別定義

找不到的話, 有可能 SYMBOL 是用 code-gen 或巨集產生的。

• 檢查一下 mkid 時有沒有漏掉 code-gen 的檔案, 再重建索引: $ mkid -m FILE_LIST ( 格式見 Language map - ID database utilities )
• 可用 $ g++ -E TARGET.cpp -IINCLUDE_DIR 展開檔案, 再回頭看 SYMBOL 是否是巨集產生的。

另外可用 gj SYMBOL void 找函式定義 (針對無傳回值的情況), 或是 gj SYMBOL 再用 ".h" 過濾只留 header 檔。

Btw, 要找 symbol 被使用的地方的話, 就直接 gj SYMBOL。

用 gdb

在 gdb 裡用 ptype VAR 會列出 VAR 的型別資訊

2013-12-08 更新

後來依自己使用習慣在 gj 加了一些功能, 像是用 gj -d1 SYMBOL 找定義或宣告, 用 gj -s LITERAL 找可能的 symbol 名稱, 詳見 gj 在 github 上的說明。

配合 c++filt 讀程式

在用 gdb 追蹤程式前, 得先找到幾個關鍵中斷點, 才能著手進行。若有機會想到不錯的關鍵字的話, 除了用 grep 之類的工具大海撈針外, 有時從 binary 裡下手, 效果也不錯, 有機會減少搜尋範圍。畢竟程式碼中難免有一些平台或參數相關的設定, 讓部份程式碼根本沒有編進 binary。從 binary 回頭找, 可免除這層顧慮。

我目前試過的作法有兩種

• string PROG | grep KEYWORD
• nm PROG | grep KEYWORD | awk '{print $NF}' | xargs c++filt

第一個作法是配合程式輸出的訊息來找程式。

第二個作法則是從 binary 取出可能有關的的 symbol, 再用 c++filt demangle symbol, 找出它的 namespace、signature 等資訊。需要注意的是, 有可能因編譯器最佳化 (如 inline), 實際上沒有呼叫到函式。經 qrtt1 提醒, 保險起見, 可在編譯時加上 -O0 確保行為符合預期。

題外話, C 的 function name 反而無法 demangle 找出 signature(應該沒理解錯吧)。不過相對於 C++ 的複雜度, 讀 C 的程式時, 也許沒那麼需要吧。

用 strace 找出 Ubuntu 如何提示未安裝的指令

在 Ubuntu 下執行指令後, 若沒有安裝指令的話, 會出現提示:

$ apt-rdepends
The program 'apt-rdepends' is currently not installed.  You can install it by typing:
sudo apt-get install apt-rdepends

但若直接用 bash 執行, 卻不會有這效果:

$ bash -c apt-rdepends
bash: apt-rdepends: command not found

以前覺得很好奇, Ubuntu 怎麼做到這件事的, 知道 strace 以後, 追這類原因簡單許多, 只要有輸入和輸出訊息, 就可夾擊出一些線索。

• 在 terminal 1 輸入 echo $$ 取得該 bash 的 PID
• 在 terminal 2 輸入 sudo strace -obash.trace -f -s512 -p PID
  • -obash.trace 表示將輸出存到 bash.trace, 訊息很多, 通常都會寫到檔案裡
  • -s512 表示輸出訊息最多到 512, 預設行寬有點短, 之後不方便找輸出的訊息
  • -f 表示一起追蹤 child process, 這點很重要, 沒加 -f 就追不到 bash 使用的其它子程序, 而關鍵就在 bash 叫起的子程序
  • -p PID 表示追踪其它 process, 照理說同一個使用者不用 root 權限應該也能看, 不知為啥不通
• 在 terminal 1 輸入 apt-rdepends, 因為 strace 有用 "-f", 速度會慢很多。等待指令完成
• 在 terminal 2 按 Ctrl+C 中斷 strace, 觀察 bash.trace

搜一下 "apt-rdepends" 會看到 bash 在嘗試各種 path 後都找不到檔案:

16520 stat("/home/fcamel/bin/apt-rdepends", 0x...) = -1 ENOENT...
16520 stat("/usr/local/sbin/apt-rdepends", 0x...) = -1 ENOENT...
16520 stat("/usr/local/bin/apt-rdepends", 0x...) = -1 ENOENT...
16520 stat("/usr/sbin/apt-rdepends", 0x...) = -1 ENOENT...
16520 stat("/usr/bin/apt-rdepends", 0x...) = -1 ENOENT...
16520 stat("/sbin/apt-rdepends", 0x...) = -1 ENOENT...
16520 stat("/bin/apt-rdepends", 0x...) = -1 ENOENT...
16520 stat("/usr/games/apt-rdepends", 0x...) = -1 ENOENT...
16520 stat("/home/fcamel/bin/apt-rdepends", 0x...) = -1 ENOENT...
16520 stat("/home/fcamel/bin/apt-rdepends", 0x...) = -1 ENOENT...

之後在別的 child process 呼叫外部程式執行 /usr/lib/command-not-found:

16877 execve("/usr/bin/python", ["/usr/bin/python", "/usr/lib/command-not-found", "--", "apt-rdepends"], [/* 38 vars */]) = 0

若想研究怎麼找出該裝的套件, 可以研究 "/usr/lib/command-not-found"。若想研究 bash 如何判斷在有 terminal 的情況下要多找安裝的指令, 可以自己編含 debug symbol 的 bash, 再用 gdb 找出相關位置, 再讀附近的原始碼。這樣一來, 至少知道需要追的時候該如何進行, 剩下就是增加經驗提昇追程式的速度了。

2012-01-23 更新

經 wens 提醒, 原來是用 bash 的 hook 做的, 見 /etc/bash.bashrc 了解設定, man bash 在 COMMAND EXECUTION 那節有說明。

gdb 初步心得

對初學者來說, 最好有個針對常用情境的簡單指南, 之後有閒再看落落長的教學。這裡列一下最近常用的功能, 之後再慢慢更新。

前置動作

• gcc/g++ 編譯時要加 -g
• 要觀察用到的函式庫, 則要裝 x-dbg 版 (如 libjpeg62 -> libjpeg62-dbg), gdb 會優先載入 debug 版函式庫。並且需要用 directory 載入原始碼, 詳情見《追踪 glibc 裡的程式》的說明。
• 若原始碼的位置和當初編 binary 時的位置不同 (常有的事), 可用 set substitute-path from to 做路徑字串取代。
• 可用 objdump --source FILE 確認是否真的有編到 -g。有的話可以在輸出裡看到程式碼。

雖說通篇我都寫 gdb, 但是 cgdb 好用許多, 推薦使用。聽 command 說 vimgdb 更好用, 不過要 patch vim 後才能用, 就 ... 先備忘吧。

執行方式

從頭執行

• bash> gdb --args PROGRAM PROGRAM-ARG1 ...
• gdb> start # 進入 main 後停下來

檢查掛點原因 (參考《產生 core dump 的方法》確保有 core dump)

• bash> gdb PROGRAM CORE
• gdb> bt 20 # 看掛掉的 call stack 最底層 20 個 function call

通常載入 PROGRAM 讀 debug symbol 較花時間, 我習慣用 gdb PROGRAM 進 gdb 後, 再用 core CORE 指令看不同的 core dump。

若希望從頭重來, 有設好中斷點就用 r, 沒有則繼續用 start, 不用離開 gdb, 可簡省載入 PROG 的時間。

設中斷點

• b LOC # 設中斷點, 或用 cgdb 直接在程式視窗按空白鍵
• i b # 列出全部中斷點
• d NUM # 移除編號 NUM 的中斷點
• save breakpoints FILE # 存下目前設的中斷點到檔案 FILE
• so FILE # 載入之前設的中斷點
• dis 1-10: 暫停使用 breakpoints 1-10。
• ena 1-10: 恢復使用 breakpoints 1-10。

關於 LOC: 見《Specify Location - Debugging with GDB》。我比較常用 filename:linenum、linenum 或 +N。因為不易對到 C++ 的函式名稱, 所以我都用行號。

我還沒有適當情境試 conditional break, 但應該很有用, 備忘。

移動

• n # 跳下行
• s # 若有函式, 跳進去; 反之則同 n
• fin # 執行到函式結尾, 返回上一層
• until LOC # 執行到 LOC 再停, 我以前都傻傻的先設中斷再按 c ...
• c # 執行到下個中斷點
• 跳過下一行程式 (ref.), 記得要設中斷點才行
  
  • b +1
  • j +1
• ret # 不執行函式剩下的程式, 直接返回上層 frame
• ps. 按 Enter 可重覆上個指令, 在移動指令時和切 stack frame (後述) 時特別好用

在 call stack 之間移動

• up # 往上移一個
• do # 往下移一個
• f N # 跳到 stack frame N

觀察值

• p EXPRESSION # 印出 EXPRESSION 的值, 可是變數、函式等
• 印出 smart pointer 的值 (ref.): 得先取出裡面的 pointer 再取出它的 member function / field
• whatis VAR # 看型別
• ptype VAR # 看型別的宣告內容, 了解有那些欄位可讀
• p P@N # 印出位置 P 開始 N 個變數的值
• p *P@N # 印出對位置 P 開始 N 個變數取值後的值
• p *argv@argc # 在 main() 函式裡執行這指令, 會印出命令列參數內容

thread

• i thr # 列出目前的 thread, 建議事先用 prctl / pthread_setname_np 設定 thread name, 比較好辨別
• thr NUM # 切換 thread

其它

• set var X = ... # 執行期間改變變數 X, 以在執行期驗證小修改是否有效, 簡省編譯時間
• handle SIGSTOP nostop noprint # 收到 SIGSTOP 時不要停且不要輸出訊息, 在 Android 環境有時 gdb 會莫明地一直收到 SIGSTOP

參考資料

• 《Debugging with GDB》: 待用一陣子後再來掃一遍, 挑出有用的東西

進階指令

• commands BREAKPOINT_ID: 定義在進入 breakpoint 後, 執行一系列指令, 比方 "p some_var; c"。
• define NEW_CMD: 類似函式, 定義由一堆指令組成的新指令。

追踪 glibc 裡的程式

這篇是一堆試誤心得的中間記錄, 使用的版本是 Ubuntu 11.04。

失敗的作法

• 在 link 時, 用 -L/usr/lib/debug/lib/x86_64-linux-gnu/ 改變 link 到的 libc.so, 但沒有效果。用 strace -e open 觀察 gcc 做的事, 發現是因為 /usr/lib/debug/lib/x86_64-linux-gnu/ 下沒有 libc.so, 而是 libc-2.13.so。之前沒學清楚 -L 和 -l 的細節, 耍笨。
• 由 man ld.so 得知可用 LD_LIBRARY_PATH 或 LD_PRELOAD 在執行期換掉 libc.so, 但是也沒有效果。用 LD_PRELOAD 換成 debug 版 libc.so 時, 跑 gdb 會 segmentation fault

成功的作法

前置作業

• $ sudo aptitude install libc6-dbg # 取得有 debug symbol 的 libc.so
• $ apt-get source libc6-dev # 取得原始碼目錄 eglibc-2.13

執行

1. $ gcc myprog.c -g -o myprog
2. $ gdb myprog
3. $ directory /path/to/eglibc-2.13/stdio-common/
4. $ start # 跑到 main 就停下來

然後 gdb 會神奇地去找含 debug symbol 的 libc, 後面就可以用 step 進入 glibc 的函式。不知這個行為寫在那裡, 或許可以從 gdb 原始碼找出來吧。

若有進入但說找不到原始碼, 表示沒有告知 gdb 正確的原始碼位置, 到 eglibc-2.13 下找一找, 再回來用 directory 設位置。

另外在用到 sqrt()、log() 時也是如此, 照一樣的編法 gcc myprog.c -g -lm -o myprog, 然後在 start 後, gdb 會去找 debug 版的 libm.so。不過要記得多執行 directory /path/to/eglibc-2.13/math 載入 math 的原始碼, gdb 才能列出原本的程式。用 ldd 觀察 myprog 也驗證原本的執行檔將 libc 和 libm 連到沒有 debug symbol 的版本。

另外試了直接和 debug 版的 libc.so 或 libm.so 編在一起 (gcc myprog.c -g /usr/lib/debug/lib/x86_64-linux-gnu/libc-2.13.so), 但是一跑就會 segmentation fault。

另外有些函式好像是用組語寫的, 看不懂它們的行為, step into sqrt 沒有效果。

結論

要觀察 glibc 的行為, 要做以下的事:

• 裝 libc6-dbg, 取得含 debug symbol 的 shared lib
• 用 apt-get source libc6-dev 取得原始碼。由於 glibc 裡有多個 shared lib, 要先 grep 找看看想觀察的程式放在那個目錄下, 跑 gdb 時再用 directory 載入該目錄, 相對路徑才會對。

2012-01-10 更新: 補充觀察 gdb 找 debug lib 的行為

一樣可以用老招 strace -e open 跑 gdb 看出背後發生的事, 以下是沒有裝 libc6-dbg 跑出的訊息:

$ strace -e open -o gdb.trace gdb myprog

然後執行 tail -f gdb.trace | grep libc 觀察行為。

以下是執行 start 以前的訊息:

open("/lib/x86_64-linux-gnu/libc.so.6", O_RDONLY) = 3
open("/lib/libcrypto.so.0.9.8", O_RDONLY) = 3
open("/usr/share/locale/en_US.UTF-8/LC_MESSAGES/libc.mo", O_RDONLY) = -1 ENOENT (No such file or directory)
open("/usr/share/locale/en_US.utf8/LC_MESSAGES/libc.mo", O_RDONLY) = -1 ENOENT (No such file or directory)
open("/usr/share/locale/en_US/LC_MESSAGES/libc.mo", O_RDONLY) = -1 ENOENT (No such file or directory)
open("/usr/share/locale/en.UTF-8/LC_MESSAGES/libc.mo", O_RDONLY) = -1 ENOENT (No such file or directory)
open("/usr/share/locale/en.utf8/LC_MESSAGES/libc.mo", O_RDONLY) = -1 ENOENT (No such file or directory)
open("/usr/share/locale/en/LC_MESSAGES/libc.mo", O_RDONLY) = -1 ENOENT (No such file or directory)
open("/usr/share/locale-langpack/en_US.UTF-8/LC_MESSAGES/libc.mo", O_RDONLY) = -1 ENOENT (No such file or directory)
open("/usr/share/locale-langpack/en_US.utf8/LC_MESSAGES/libc.mo", O_RDONLY) = -1 ENOENT (No such file or directory)
open("/usr/share/locale-langpack/en_US/LC_MESSAGES/libc.mo", O_RDONLY) = -1 ENOENT (No such file or directory)
open("/usr/share/locale-langpack/en.UTF-8/LC_MESSAGES/libc.mo", O_RDONLY) = -1 ENOENT (No such file or directory)
open("/usr/share/locale-langpack/en.utf8/LC_MESSAGES/libc.mo", O_RDONLY) = -1 ENOENT (No such file or directory)
open("/usr/share/locale-langpack/en/LC_MESSAGES/libc.mo", O_RDONLY) = -1 ENOENT (No such file or directory)

以下是執行 start 以後的訊息:

open("/lib/x86_64-linux-gnu/libc.so.6", O_RDONLY) = 6
open("/lib/x86_64-linux-gnu/libc-2.13.so", O_RDONLY) = 7
open("/lib/x86_64-linux-gnu/.debug/libc-2.13.so", O_RDONLY) = -1 ENOENT (No such file or directory)
open("/usr/lib/debug//lib/x86_64-linux-gnu/libc-2.13.so", O_RDONLY) = -1 ENOENT (No such file or directory)
open("/usr/lib/debug/lib/x86_64-linux-gnu/libc-2.13.so", O_RDONLY) = -1 ENOENT (No such file or directory)
open("/lib/x86_64-linux-gnu/libc-2.13.so-gdb.py", O_RDONLY) = -1 ENOENT (No such file or directory)
open("/usr/lib/debug/lib/x86_64-linux-gnu/libc-2.13.so-gdb.py", O_RDONLY) = -1 ENOENT (No such file or directory)
open("/usr/share/gdb/auto-load/lib/x86_64-linux-gnu/libc-2.13.so-gdb.py", O_RDONLY) = -1 ENOENT (No such file or directory)

可以看出 gdb 不論如何, 都會試著載入 debug 版的函式庫, 來執行目標程式。找不到的時候, 自然就是用沒有 debug symbol 的函式庫。

2012-01-22 更新

在《gdb 如何找到 debug symbol》有進一步說明。

2016-02-16 更新

若 Ubuntu 沒有附 X-dbg 的 package，可以自己編原始碼裝進去，詳見 自行編譯含 debug symbol 的套件 (package)

debug info 和 optimization

要知道程式有沒有編進 debug info, 可用 objdump --source BINARY | less 觀察。若有看到程式碼的內容, 表示有編進去。另外要注意的是, 程式本身和用到的函式庫編法可能不同, 可能程式有加 -g, 但函式庫沒有。造成看得到一些函式內容, 卻看不到另一些的內容。

另一個要注意的點是, 今天聽 wens 說才知道編程式時可以同時用 -O 和 -g。這樣做的好處是, 執行速度快, 接近 production 運作的情況。我自己試用的感覺是, 有些 bug 在 debug mode 可能不方便重制出來, 還有 debug mode 通常跑比較慢, 所以用 -O -g 還滿方便的。但不幸的是, 兩者合用會有一點副作用, 在 man gcc 裡有說明:

GCC allows you to use -g with -O. The shortcuts taken by optimized code may occasionally produce surprising results: some variables you declared may not exist at all; flow of control may briefly move where you did not expect it; some statements may not be executed because they compute constant results or their values were already at hand; some statements may execute in different places because they were moved out of loops.

Nevertheless it proves possible to debug optimized output. This makes it reasonable to use the optimizer for programs that might have bugs.

當程式是用 -O 和 -g 編出來的時候, 用 objdump --source 會看到程式碼怪怪的, gdb 執行順序也會怪怪的, 執行行為和程式碼有時有一點出入, 還有部份的值會印不出來, gdb 輸出 value optimized out。若要觀察的東西就是那些部份, 就得回頭用 -O0 -g 確保沒有開啟最佳化。

C/C++ 檢查和打開 debug 功能的小技巧

打開 debug flag 有助於了解模組的行為。工程師開發時應該都有幫自己除錯留後路, 所以找到他們開發的方式, 可省下自己瞎試的時間。

以前寫 Python 或 Java 時, 都有近乎標準的 logging module 可用, 所以要找到開啟 logging 機制的方式滿簡單的, 看是用那家的 logging module, 針對它的設定檔設 log file, 或在程式開始時塞段程式啟動 logging 即可。不過 C/C++ 好像沒有那麼一致。

留意程式碼會看到輸出訊息的巨集, 像是 P("What the F**k!!");, 然後在某些 debug 相關 header 檔裡會看到類似這樣的東西:

#ifdef DEBUG
#define P(x) ...
#else
#define P(x) ;
#endif

其中 "..." 的部份是該模組用來輸出除錯訊息的機制, 可能是寫到檔案, 或輸出到 stdout/stderr 等。這樣在沒有 define DEBUG 的情況下, 完全不會產生除錯訊息的程式碼, 減少執行負擔。

要確定程式真的有編進除錯訊息的話, 隨便找個程式內有的除錯訊息, 然後用 strings 檢查:

$ strings PROGRAM | grep "What the F**k!!"

看有沒有結果。有的話大概就 ok (找個少見的字串最穩), 不然就是沒編進去, 檢查看看 #define DEBUG 1 有沒有設好, 或是有沒有在 makefile 的 CFLAGS 設好 -DDEBUG。

再來, 也可以用 strace 檢查執行期間到底有沒有執行到:

$ strace -e write PROGRAM | grep "What the F**k!!"

不過 write 寫入的字串不見得會一次剛好符合一整串, 這和檔案 flush 機制有關。找子字串, 或用眼睛注意一下比較穩一些。懶得找方法打開 log 檔的話, 用 strace -e write 將就看也還可以, 不過會拖滿執行速度, 且 strace 有時會影響 process 的狀態, 常期用的話還是打開 log 檔最穩。

打開 core dump 和使用 cgdb 檢查程式掛點原因

前置動作

首先, 用 gcc/g++ 編程式時記得加 -g 以加入除錯資訊。

接著參考《產生 core dump 的方法》設成可以產生 core dump。

檢查 backtrace

$ gdb PROGRAM

然後在 gdb 內執行

core core.PROGRAM.PID.TIMESTAMP

接著就能用 bt N 看最底層 N 個 call stack 為何, 也就是所謂的命案現場啦。然後可用 up, do, l 等指令切換 call stack 和列出週圍程式。

在和 gdb 相處一段時間後, 覺得這樣在 stack 之間移動很方便, 但看週圍的程式太辛苦了, 還是會開另一個視窗用 VIM 看完整一些的程式。

看到 jserv 建議使用 cgdb, 試了發現, 人生...啊不, 是視窗變彩色的了!! 不只有彩色的程式碼, 還外加類 VI 的瀏覽方式, 相當順手。

目前有用到的功能如下:

• 按 i、ESC 在程式碼視窗和 gdb 命令列之間切換。
• 程式碼視窗裡可用 VI 的部份指令移動行數; 回到命令列後和 gdb 完全相容, 可按上下鍵選用之前的指令。
• 在程式碼視窗按空白鍵加減 break point。

官網文件有詳細的說明, 之後來掃一遍, 看有什麼好東西可用。

善用 strace、debugger 從執行期間找出問題根源

最近被迫在短時間內學會 strace、gdb 這些之前一直用不到的重兵器, 都還不熟練就是了。剛好使用 hgsubversion 時有些困擾, 雖說它和 svn 整合得很好, 無縫接好 pull / push, 但它不會顯示 mercurial 對應到的 svn 版本, 平時看其它和 svn 整合的工具 (如 issue tracking) 會很困擾, 用得都是 svn 版號。

剛剛想到可以學 Strace -- The Sysadmin's Microscope 的做法, 用 strace 找出關聯的程式, 再來看怎麼修正它。

我推測 hg 一定有記錄 svn 相關版本的方式, 不然無法和 svn server 同步資料。於是挑個會讀到 svn 資料的指令來試:

strace -o trace.log -s 512 -e read,open hg svn info

用顯示的 svn 版號 123 來翻 trace.log, 發現這兩行:

open("/path/to/project/.hg/svn/lastpulled", O_RDONLY) = 3
read(3, "123\n", 4096)                 = 5

於是找到 meta data 存在 .hg/svn/ 下。 到該目錄下找到 .hg/svn/rev_map 這個檔案, 裡面存 hg 和 svn 的版號對應表。至少這樣就有足夠的材料寫個 script 來轉換 hg、svn 的版號。

不過若能直接加到 hg 裡, 應該會更方便也較可攜。要做這點相對容易, 可以到 hgsubversion 原始碼目錄下用 ack 找相關程式。

先用 ack rev_map 找到存 meta data 的物件 revmap, 再用 ack revmap 找到 wrappers.py 是換掉 hg 指令的程式。

再來用 pdb 觀察 revmap 如何被使用。先在 wrappers.py 裡設中斷點, 然後執行 pdb /usr/local/bin/hg parents --svn 找出 meta data 如何被讀出來。於是明白可在函式 parents 的部份塞入幾行顯示 svn 版本:

--- a/hgsubversion/wrappers.py        2011-12-25 00:34:39.170606104 +0800
+++ b/hgsubversion/wrappers.py        2011-12-25 00:33:04.161800527 +0800
@@ -57,6 +57,9 @@
         raise hgutil.Abort('No parent svn revision!')
     displayer = cmdutil.show_changeset(ui, repo, opts, buffered=False)
     displayer.show(ha)
+    # patch svn revision
+    print '\033[1;32msvn revision: %d\033[0m' % hashes[ha.node()][0]
+    print
     return 0

這樣打 hg parents --svn 就會多輸出一行 svn 的版號。雖說顯示在 hg log 會更方便, 不過 wrappers.py 裡沒有 log, 之後有再找時間看看怎麼加。

附帶一提, 剛用 pdb 時還不太習慣, 忘了 python 是執行期載入程式, 不能像 gdb 那樣在執行前就指定檔名指定行數設中斷點。而是要在 script 裡直接塞

import pdb; pdb.set_trace()

2011-12-25 更新

如留言裡的討論, 上述的修正沒有實質幫助, 就當作練 debugger 吧。最後覺得另外寫個 shell script 最省事效果也最好, 寫好的東西放在這裡。