找出 node.js 中 block main loop 的程式

環境

• Mac 用 node.js 0.10.36
• Ubuntu (VM) 用 node.js 0.10.38

問題描述

node.js 的 single thread event loop 架構容易處理 I/O bound, 也避開 multi-thread 的各式問題, 但弱點是 main loop 被卡住了, 整個程式就不會動了。幸好找出錯誤原因的方法滿多的, 若確定是 CPU bound 而不是自己呼叫到 sync API, 也有很多成熟的解法。

在開發環境偵錯

node.js 有很多種 profiling 的方法, 試過幾種作法, 我偏好這兩個作法:

• node-inspector
• look

兩者都會產生一個 web server 讓你可以連到指定的 port 用網頁作的 UI 看資料。也都不用傳資料到別人機器上。配合 stress test 可以找出潛在的 CPU bound。look 的介面比較簡單, 啟動速度較快。

在上線環境除錯

但若 CPU bound 只有在上線後才會遇到, 就不容易找了。試了一些方法, 覺得用內建的 command line debugger 最管用。

node.js 已內建 debugger, 不需特殊設定就可以用 debugger attach 上線執行的程式。執行方法如下:

$ kill -USR1 PID  # PID 為 node.js pid
$ node debug -p PID

然後執行 pause 暫停程式，接著執行 bt (backtrace) 才會有效。這樣就有線索找出 main loop 卡住的時候在作什麼了。

下面是一個完整的小例子:

$ cat b.js
function fib(n) {
  if (n <= 1) {
    return 1;
  }
  return fib(n - 1) + fib(n - 2);
}

setTimeout(function() {
  console.log(fib(100));
}, 10000);
$ node b.js
Hit SIGUSR1 - starting debugger agent.
debugger listening on port 5858

在另一個 shell 用 debugger:

$ ps auxw | grep node
fcamel          44656   3.2  0.2  3075620  18524 s013  S+    9:23PM
$ kill -USR1 44656
$ node debug -p 44656
connecting... ok
debug> bt
Can't request backtrace now
debug> pause
break in b.js:6
  4   }
  5   return fib(n - 1) + fib(n - 2);
  6 }
  7
  8 setTimeout(function() {
debug> bt
#0 b.js:6:1
#1 b.js:5:10
#2 b.js:5:23
#3 b.js:5:23
#4 b.js:5:23
#5 b.js:5:10
#6 b.js:5:10
#7 b.js:5:23
#8 b.js:5:10
#9 b.js:5:10
debug> repl
Press Ctrl + C to leave debug repl
> n
6

不過 CPU 太忙的時候 kill -USR1 好像會失效 (node.js 沒有顯示收到 SIGUSR1 進入 debug mode), 然後 debugger attach 會失敗。或是 debugger attach 成功, 有時 pause 也會失敗, 像這樣卡住沒反應:

debug> pause
break in [unnamed]:1
  1

有閒再深入了解原因。