利用 adb 和 gdb 來 debug Firefox OS (B2G)

Debugging 絕對是每個 programmer 不得不面對的痛。有句俗話說

To err is human; to debug, divine.

當我們遇到一個 B2G 上的 bug，卻不清楚原因的時候，該怎麼辦呢？本文將介紹一些筆者日常工作中，對 B2G 的 Gecko C 部份常用的除錯方法。

adb logcat

如果你是個 C 開發者，不管是不是習慣使用先進的 debugger ，剛開始寫小程式時一定都有用過一招，俗稱「printf 大法」或「cout 大法」，說穿了就是把變數的值印到 stdout 上面，藉此找出程式運作不正常之處。但是當我們在開發機（例如 Flame）上面測試時，要如何看到印出來的 log 呢？

因為 B2G 底層的 Gonk 其實是基於 Android Open Source Project (AOSP)，所以也適用 Android Debug Bridge (adb) 這個工具。在 B2G 的 C 程式碼中，只要在你想要印出 log 的地方呼叫這個函數即可：

__android_log_print(ANDROID_LOG_INFO, "MyTag", "Variable: %d, String %s", var, str);

其中第一個參數是 priority，可視情況從以下的值取一使用 [1]：

Android log priority values, in ascending priority order.

/
typedef enum android_LogPriority {
ANDROID_LOG_UNKNOWN = 0,
ANDROID_LOG_DEFAULT, / only for SetMinPriority() /
ANDROID_LOG_VERBOSE,
ANDROID_LOG_DEBUG,
ANDROID_LOG_INFO,
ANDROID_LOG_WARN,
ANDROID_LOG_ERROR,
ANDROID_LOG_FATAL,
ANDROID_LOG_SILENT, / only for SetMinPriority(); must be last */
} android_LogPriority;

1234567891011121314

/ Android log priority values, in ascending priority order. /typedef enum android_LogPriority { ANDROID_LOG_UNKNOWN = 0, ANDROID_LOG_DEFAULT, / only for SetMinPriority() / ANDROID_LOG_VERBOSE, ANDROID_LOG_DEBUG, ANDROID_LOG_INFO, ANDROID_LOG_WARN, ANDROID_LOG_ERROR, ANDROID_LOG_FATAL, ANDROID_LOG_SILENT, / only for SetMinPriority(); must be last */} android_LogPriority;

第二個參數是 tag，可以自己設任何字串，之後用來篩選，第三個參數以後就跟 printf 的用法一樣。

通常會定義成 macro 如

#define MY_LOG(args...) __android_log_print(ANDROID_LOG_INFO, "MyTag", ##args)

或是呼叫 printf_stderr(...)，在手機上時，它的效果就相當於上面的 log，其中 priority 是 Info 而 tag 是 Gecko. [2]

接著只要將手機用 USB 線接上電腦，再呼叫 adb logcat 就可以看到 log 從 stdout 不斷的跑出來

$ adb logcat
--------- beginning of /dev/log/main
I/QCOM PowerHAL( 209): Got set_interactive hint
D/qdhwcomposer( 209): hwc_blank: Unblanking display: 0
I/qdhwcomposer( 209): handle_blank_event: dpy:0 panel power state: 1
D/qdhwcomposer( 209): hwc_blank: Done unblanking display: 0
E/Sensors ( 209): change G sensor state "0 -> 1"
I/Gecko (10252): ###################################### forms.js loaded
I/Gecko (10252): ############################### browserElementPanning.js loaded
I/Gecko (10252): ######################## BrowserElementChildPreload.js loaded

12345678910

$ adb logcat--------- beginning of /dev/log/mainI/QCOM PowerHAL( 209): Got set_interactive hintD/qdhwcomposer( 209): hwc_blank: Unblanking display: 0I/qdhwcomposer( 209): handle_blank_event: dpy:0 panel power state: 1D/qdhwcomposer( 209): hwc_blank: Done unblanking display: 0E/Sensors ( 209): change G sensor state "0 -> 1"I/Gecko (10252): ###################################### forms.js loadedI/Gecko (10252): ############################### browserElementPanning.js loadedI/Gecko (10252): ######################## BrowserElementChildPreload.js loaded

每行開頭的 I, D, E 指的就是 priority 如 Info, Debug, Error。斜線後的字如 Gecko, Sensors 等是 tag，括號裡面則是 process ID。如果想要更多一點的資訊，可以加上 -v threadtime，讓它顯示出每行的 thread ID 和時間。如果要做篩選，則可以加上 -s <tag>[:<priority>]。例如若要顯示所有 tag 是 Gecko，且 prority 在 Info 以上的 log，就下這樣的指令。

＄ adb logcat -v threadtime -s Gecko:i
--------- beginning of /dev/log/main
01-27 15:23:25.858 10252 10252 I Gecko : ###################################### forms.js loaded
01-27 15:23:25.888 10252 10252 I Gecko : ############################### browserElementPanning.js loaded
01-27 15:23:25.908 10252 10252 I Gecko : ######################## BrowserElementChildPreload.js loaded

12345

＄ adb logcat -v threadtime -s Gecko:i--------- beginning of /dev/log/main01-27 15:23:25.858 10252 10252 I Gecko : ###################################### forms.js loaded01-27 15:23:25.888 10252 10252 I Gecko : ############################### browserElementPanning.js loaded01-27 15:23:25.908 10252 10252 I Gecko : ######################## BrowserElementChildPreload.js loaded

另外還有一些參數像 -d 是把累積的 log 一次 dump 出來之後就結束，-c 是把目前累積的 log 都清掉，詳細請見 adb logcat --help。

In Gecko"s JavaScript code

在 Gecko 的 JavaScript code 中，可以使用 dump(“…")。印出來的 log 也會在 adb logcat 中，它的 tag 是 GeckoDump。

打開 NSPR 的 log

Gecko 本身也會有一些用 NSPR (Netscape Portable Runtime) 的 API 產生的 log，通常會透過 macro 定義如

PRLogModuleInfo* gMediaDecoderLog;
#define DECODER_LOG(x, ...) \
PR_LOG(gMediaDecoderLog, PR_LOG_DEBUG, ("Decoder=%p " x, this, ##__VA_ARGS__))

123

PRLogModuleInfo* gMediaDecoderLog;#define DECODER_LOG(x, ...) \ PR_LOG(gMediaDecoderLog, PR_LOG_DEBUG, ("Decoder=%p " x, this, ##__VA_ARGS__))

然後在需要時呼叫 DECODER_LOG(...)。

要怎麼看到這些 log 呢？首先你的 B2G オンラインスロット必須是 debug build。編譯前在你的 B2G 根目錄下的 .userconfig 要加入一行：

export B2G_DEBUG=1

編譯好並用 adb shell 直接對手機下指令

＄ adb shell
root@flame:/ # export NSPR_LOG_MODULES=MediaDecoder:5
root@flame:/ # export NSPR_LOG_FILE=/data/local/tmp/myLogFile
root@flame:/ # stop b2g
root@flame:/ # /system/bin/b2g.sh

12345

＄ adb shellroot@flame:/ # export NSPR_LOG_MODULES=MediaDecoder:5root@flame:/ # export NSPR_LOG_FILE=/data/local/tmp/myLogFileroot@flame:/ # stop b2groot@flame:/ # /system/bin/b2g.sh

其中 NSPR_LOG_MODULES 這個環境變數是你要 log 的 module 名字。以上面的例子來說，gMediaDecoderLog 一定會在某處被定義，例如：

gMediaDecoderLog = PR_NewLogModule("MediaDecoder");

所以我們要找的 module 名字就是 MediaDecoder，冒號後面的 5 跟之前一樣是指定 priority。NSPR_LOG_FILE 這個環境變數則是 log 產生的位置。最後還要把 b2g process 先關掉再重開。接著就可以做你要做的測試，做完要把 log 取出時，下這個指令

$ adb pull /data/local/tmp/myLogFile <path>

就可以拿到 log 囉！

gdb

有的時候印 log 可能還不足以解決問題，也許你想對程式設中斷點做進一步的檢查，或是看看程式到底是在哪裡 crash 的，gdb 就可以派上用場了。以下介紹如何將 gdb attach 到手機程式中。

首先，你要先知道你想要設中斷點的地方是跑在哪個 process 裡。可以用這個指令看到手機裡有哪些 process，

$ adb shell b2g-ps
APPLICATION    SEC USER     PID   PPID VSIZE RSS     WCHAN    PC         NAME
b2g              0 root      209   1     255324 100848 ffffffff b6e49894 S /system/b2g/b2g
(Nuwa)           0 root      462   209   65624 22600 ffffffff b6e49894 S /system/b2g/b2g
Homescreen       2 u0_a936   936   462   89636 30392 ffffffff b6e49894 S /system/b2g/b2g
Built-in Keyboa 2 u0_a1085 1085 209   82828 33940 ffffffff b6f38894 S /system/b2g/plugin-container
Find My Device   2 u0_a1192 1192 462   72824 23636 ffffffff b6e49894 S /system/b2g/b2g
Smart Collectio 2 u0_a1480 1480 462   74360 26124 ffffffff b6e49894 S /system/b2g/b2g
Usage            2 u0_a1582 1582 462   75024 26120 ffffffff b6e49894 S /system/b2g/b2g
Browser          2 u0_a11075 11075 462   93568 31248 ffffffff b6e49894 S /system/b2g/b2g
(Preallocated a 2 u0_a14373 14373 462   71820 17532 ffffffff b6e49894 S /system/b2g/b2g

1234567891011

$ adb shell b2g-psAPPLICATION SEC USER PID PPID VSIZE RSS WCHAN PC NAMEb2g 0 root 209 1 255324 100848 ffffffff b6e49894 S /system/b2g/b2g(Nuwa) 0 root 462 209 65624 22600 ffffffff b6e49894 S /system/b2g/b2gHomescreen 2 u0_a936 936 462 89636 30392 ffffffff b6e49894 S /system/b2g/b2gBuilt-in Keyboa 2 u0_a1085 1085 209 82828 33940 ffffffff b6f38894 S /system/b2g/plugin-containerFind My Device 2 u0_a1192 1192 462 72824 23636 ffffffff b6e49894 S /system/b2g/b2gSmart Collectio 2 u0_a1480 1480 462 74360 26124 ffffffff b6e49894 S /system/b2g/b2gUsage 2 u0_a1582 1582 462 75024 26120 ffffffff b6e49894 S /system/b2g/b2gBrowser 2 u0_a11075 11075 462 93568 31248 ffffffff b6e49894 S /system/b2g/b2g(Preallocated a 2 u0_a14373 14373 462 71820 17532 ffffffff b6e49894 S /system/b2g/b2g

假設想要中斷的程式是執行在 Browser app 裡面，它的 process ID 是 11075，那就在 B2G 的根目錄裡面執行

./run-gdb.sh attach 11075

或是如果你覺得

要注意的是，即使某段程式碼看起來是運行在某個 app 之中，但有可能它為了用到某些 privilege，其實是運行在 b2g process 之中的。例如 Web app 如何操作硬體功能（Firefox OS 的內部溝通－藍牙篇）一文中提到的，藍牙的 code 可能有一部份在 content process，有一部份在 chrome process。以上述的 case 為例，如果要 debug 的程式碼是在 b2g process 之中，你要 attach 的 ID 就變成 209。

然後就可以設中斷點啦！假設要設一個中斷點在 MediaDecoder::Pause()，先看一下 MediaDecoder.h，原來 MediaDecoder 這個 class 是被包在 mozilla 這個 namespace 裡，所以要做的事就是

(gdb) b mozilla::MediaDecoder::Pause()

或是也可以設在某個檔案的某一行，像

(gdb) b MediaDecoder.cpp:174

然後再下指令 c(ontinue) 繼續執行就可以囉！其餘關於 gdb 的一些用法請參照要出問題，C4炸藥 gdb 都能搞定。

如果你覺得純命令列方式的 gdb 用起來不順手，可以參考看看CGDB – 更好用的 GDB。或是也可以使用圖形化介面的 DDD，只要改用 ./run-ddd.sh 即可。

[1] http://androidxref.com/5.0.0_r2/xref/system/core/include/android/log.h

[2] https://dxr.mozilla.org/mozilla-central/source/xpcom/glue/nsCRTGlue.cpp#398