プロローグ
node --help
でnodeの起動オプションを見てみると、実はひっそりと--v8-options
という初心者お断りオーラを醸し出しまくってるオプションがあります。
Node.jsの公式ドキュメントによると
Print v8 command line options.
Note: V8 options allow words to be separated by both dashes (-) or underscores (_).
For example, --stack-trace-limit is equivalent to --stack_trace_limit.
どうやらV8エンジンの起動オプションをnodeコマンドでも与えられるようです。
ついでに、「-」と「_」はどっちでもいいようです。
で、この--v8-options
を駆使すればNode.jsのパフォーマンスチューニングに役立ちそうって話です。Node.jsを使った開発から離れちゃったから使う機会あるかどうか怪しいけど。
ちなみにこの場合のV8エンジンというのはGoogle V8 JavaScriptエンジン のことであり、決してV型8気筒エンジンのことではありません。
使ってみよう…その前に
まずは前提としてNode.jsのバージョンはLTSであるv8.9.1とします。
そして使ってみるV8オプションですが、ざっと数えて400ぐらいあるオプション全てを触るのはあまりに辛いので今回は
-
--trace-opt
(--trace-deopt
) --prof
--trace-events-enabled
あたりに触れます。
--trace-opt, --trace-deopt
こいつらについて話す前に、まずNode.js(ていうかV8エンジン)の特性として 実行しながらコードを動的に最適化する というものがあります。
--trace-opt
は実行中に最適化が行われたらログが出力さるようにするオプションです。
となると「--trace-deopt
ってなんや?」となりますが、ここで 動的に最適化する というのがミソになります。
つまり
V8エンジン「おっしゃこのコード最適化したるで!」
V8エンジン「あ、さっきの最適化やとあかんわ。いっぺん戻してからやり直すけど許してや~」
という状況がNode.jsの実行中にしばしば発生します。
--trace-deopt
オプションはこの「いっぺん戻す」作業をログに出します。
で、それどんな時に起こるの?
ここに一つの適当な関数を用意します
function testFunc(a) {
return a + a;
}
例えばこの関数の引数がどちらもnumberで呼ばれた場合、V8エンジンは「お、この関数はnumberの足し算なんやな。それに合わせて最適化したろ。」となります。
しかし、その後に突然stringが放り込まれたりすると、「stringも来るんかい!最適化やり直しや!」となるわけです。
試しにまずは引数をnumberだけにして実行してみましょう。
function testFunc(a) {
return a + a;
}
// 環境によってはログを出力する前にコードを実行し終わってしまう場合があります。
// その場合ログが何も出ないので、適宜ループ回数を調節してください。
for (let i = 0; i < 1000000; i++) {
testFunc(i);
}
optimizing
みたいなログが出力されます。
それではこのコードに少し意地悪をしましょう。
function testFunc(a) {
return a + a;
}
for (let i = 0; i < 1000000; i++) {
testFunc(i);
}
for (let i = 0; i < 1000000; ++i) {
testFunc(i + "");
}
ウワアあぁぁぁああぁああぁ!
画面に収まってませんが、deoptimizing
みたいな文言が出力されてます。
ていうかコードの変更量に対してログ出力の変化が大きすぎる。明らかにただ事ではない。
この「最適化して、やっぱり戻して」みたいなのが何度も繰り返されると、最終的にV8エンジンは「これは最適化できへんわ」と匙を投げますが、ログを見た上で推測するなら結構なリソースが空費されそうです。
そもそも最適化できないケース
try-catchが使われてるなど、特定のケースではV8エンジンは最初から最適化を諦めます(あるいは単純すぎるから不要と判断します)。
詳しくはここに記載されていますが、私がまだ読めてません…
--prof
--prof
オプションはCPU使用に関するログを残します。
先ほどのコードで試してみましょう。
実行するとisolateうんたらかんたらv8.logというファイルができてますが、中身には人間やめないと読めないような地獄のログが待ってます(君の目で確かみてみろ!)。
人間が読めるように加工する機能はNode.jsに標準で備わってるので安心してください。
最初からそうしろよ
node --pref-process [さっき作ったv8.logのファイル名]
で整形してくれますが、それだと標準出力に出力されちゃうので、ちゃんと見たいなら適当なファイルに書き込むようにしましょう。
まあこれはこれで割と地獄のログなんですが、「あれれ〜、CPU使用率がおかしいぞ~?」って時に使ってみると助けになるかもしれません。
--trace-events-enabled
本命
まずは先ほどのファイルに--trace-events-enabled
オプションをつけて実行します。
node_trace.1.logとかいう怪しいファイルができてますね。
そしたらGoogle Chromeを開いてchrome://tracing
とURLを打ち込んでアクセスします1。
こんな画面になるのでLoadボタンから先ほどの怪しげなファイルを読み込みます。
すると何と…!
なんかクライアントサイドでよく使う開発ツールのパフォーマンスタブ的なサムシングが…!!
ちょっとサンプルが短すぎるせいかよくわからないが、何かに使えそうではある。2
本当に万策尽きたら
V8を讃え、
祈りを捧げましょう3
※ ただの気休めなので、良いエンジニアは真似しないように