Node.jsのデバッグ方法の話

後輩に書いてくださいよ。的に言われたので、書いてみます。Node.jsは0.4くらいからやってました。

僕個人の方法なので、こんな方法もあるんだなぁという感じで見てもらいたいです。

基本はconsoleでデバッグ

普段使い

// console.logは引数を複数取れます。
var num = 1
console.log('aaaaaaaaaaaa 11', num)
num = 2
console.log('aaaaaaaaaaaa 22', num)

// こんな感じで出ます。
$ node hoge.js
aaaaaaaaaaaa 11 1
aaaaaaaaaaaa 22 2

別のソースだとaaaの部分がbbbになったりします。同じソースの近い場所でやる場合、番号振ってどれが出ているか？わかりやすくしたりします。利点は、

• 入力が簡単
• grep検索した時に一意で見つけられる
• consoleに出てくる文字列も見やすい

注意点としては、console.logは同期的に実行されるためデカイオブジェクトのパースとかのデバッグコードが残ってしまうとイベントループを止めてしまうことになります。そのため、eslintなどの静的チェッカーで警告などを出してプロダクトコードに残らないように対策しておいたほうが良いです。

json整形

jsonとかを見やすくしたい場合は、標準実装のJSON.stringifyを使います。

// 通常のstringify
$ node -e 'console.log(JSON.stringify({aaa:111, bbb:222, ccc:333}))'
{"aaa":111,"bbb":222,"ccc":333}

// 整形ありのstringify
node -e 'console.log(JSON.stringify({aaa:111, bbb:222, ccc:333}, null, "    "))'
{
    "aaa": 111,
    "bbb": 222,
    "ccc": 333
}

console.traceでスタックトレースを強制的に出す

node -e 'console.trace(111)'
Trace: 111
    at [eval]:1:9
    at ContextifyScript.Script.runInThisContext (vm.js:44:33)
    at Object.runInThisContext (vm.js:116:38)
    at Object.<anonymous> ([eval]-wrapper:6:22)
    at Module._compile (module.js:624:30)
    at evalScript (bootstrap_node.js:480:27)
    at startup (bootstrap_node.js:177:9)
    at bootstrap_node.js:626:3

コードを追うのが面倒な時とか、よくわからんときは、怪しい場所にスパッと書いてみたりします。（いつも同じ手順でデバッグしてもつまらなくなりますしね。）

console.time

console.time('hoge')
// 何かしらの処理
console.timeEnd('hoge')

時間を測ることができます。hogeの部分はラベルなので合わせないと駄目です。

consoleデバッグまとめ

TDDだと全部書いてから実行みたいにはやらないので、この程度あれば９割超えのデバッグが出来ます。

リフレクション多用コードなど、どうしてもデバッガー使いたい場合

Node.jsでデバッガを使うときは、Node.jsに標準で同梱されているものを使っています。（node-inspectorとかは使ってません）

詳しい使い方はAPIドキュメントを参考にしてほしいです。
https://nodejs.org/docs/latest/api/debugger.html

コマンド

node inspect aaa.js
// or
node debug aaa.js

最近は、V8 Inspector使うようになったからか、実行の書き方が、node inspect aaa.jsになったっぽいです。昔は、node debug aaa.js だったので、時代の変化を感じますね。（Node.js８系では、どちらでも実行できます。）

実行時の出力

node inspect aaa.js
< Debugger listening on ws://127.0.0.1:9229/3aa60b74-6389-46c4-8c0c-ebbab1c9aa24
< For help see https://nodejs.org/en/docs/inspector
< Debugger attached.
Break on start in aaa.js:1
> 1 (function (exports, require, module, __filename, __dirname) { var num = 1
  2 console.log('aaaaaaaaaaaa 11', num)
  3 num = 2
debug> c
< aaaaaaaaaaaa 11 1
< aaaaaaaaaaaa 22 2
< Waiting for the debugger to disconnect...
debug>

初回は、一番最初の行で止まるように出来ています。c で次のブレークポイントまで行けます。実行中にブレークポイントを設定することも出来ますが、割りと面倒なので、ソースコードの中に、debugger と書いてブレークポイントを貼っています。（debuggerという記述が、プロダクトコードに残っても影響は無いですが、かっこわるいので、eslintなどで警告を出して、消し忘れないようにしたいです。）

実行中にreplモードに入れば、変数の値を書き換えたり出来るので使いやすいです。また、ブラウザやIDEが無くてもデバッガを起動できるため、サーバーでデバッグしたい場合や、デーモン起動以外でデバッグしたい場合とか、テスト実行時などにはかなり良いと思います。

Mochaでデバッグ

mocha inspect aaa.js
// or
mocha debug aaa.js

終わらせるときはkillをしてから

デバッグを終了したい場合は、Ctrl + C でも終わらせられますが、なんかプロセスが残っちゃうことが初期の頃はあったので、終わらせるときはkillと打ち込んで止めてからCtrl + Cするようにしています。

まとめ

結構前からデバッグはこんな感じでやっています。Node.jsのAPIを見てみると他にもGCログの出し方とか、色々とお役立ち関数の発見があるので、ズラーッと見てみることをおすすめします。