V8 をつかって JIT コンパイラによる最適化の挙動を確認してみる
つねみ@tocomi業務で JavaScript を書いていたときに、色々理由があって「JIT コンパイラで最適化されにくい」コードを書きたいという場面に出くわした。
そもそも JIT コンパイラについてあまり知らないので、手元で動かしながら挙動を確認してみようと思った🤖
つねみ@tocomijsvu
jsvu というツールを使うと、様々な JavaScript エンジンを手元で手軽に実行できるらしい！
今回は Chrome 等で使われている V8 を使ってみる。
リポジトリの README を参考にセットアップしていく。
インストールが無事完了すると v8 コマンドで REPL が起動するように🎉
つねみ@tocomiスクリプトの実行
console.log('Hello World');
> v8 script.js
Hello World
簡単なスクリプトファイルを作って v8 コマンドに渡すと実行できた！
--trace-opt, --trace-deopt オプションを使うと、最適化と最適化解除のログを出力してくれるらしい。
つねみ@tocomi最適化を走らせる
function testFunction(x) {
return x * 2;
}
const LOOP_COUNT = 100;
for (let i = 0; i < LOOP_COUNT; i++) {
testFunction(10);
}
こんな感じで同じ関数をループで何度も呼び出してみる。
(実行コマンド: v8 --trace-opt --trace-deopt script.js)
ループ回数が 100 回だと何もログが出なかったので最適化は行われていないみたい。
ループ回数を増やしていくと、500 を超えたタイミングでログが出力されるようになった。最適化が行われるようになったのでしょう。
[marking 0x1300001995c5 <JSFunction testFunction (sfi = 0x13000019951d)> for optimization to MAGLEV, ConcurrencyMode::kConcurrent, reason: hot and stable]
[compiling method 0x1300001995c5 <JSFunction testFunction (sfi = 0x13000019951d)> (target MAGLEV), mode: ConcurrencyMode::kConcurrent]
メモ
- mariking で関数を最適化対象としてマークしている
- compiling method で実際に最適化を開始している
- MAGLEV というコンパイラが使われている
GPT による解説
[marking ... for optimization]:
testFunctionという名前のJavaScript関数が、最適化対象としてマークされたことを示しています。
この関数は現在「ホット（頻繁に実行される）」であり、かつ「安定している（型や実行パターンが変わらない）」と判断されたため、より効率的な実行のために最適化される予定です。
最適化のターゲットとして指定されているのは「MAGLEV」というコンパイラです（MAGLEVはV8エンジンで導入された中間層の最適化コンパイラで、従来のIgnitionやTurbofanの間を埋める役割を果たします）。
ConcurrencyMode::kConcurrentは、この最適化処理が並列的に（バックグラウンドで）行われることを意味します。
[compiling method ... (target MAGLEV)]:
実際にtestFunctionの最適化コンパイルが開始されたことを示しています。
このコンパイルでは、MAGLEVコンパイラを使用して関数を高速化するためのバイトコードやネイティブコードが生成されます。
ConcurrencyMode::kConcurrentが再び指定されているので、この処理もバックグラウンドで非同期的に実行されます。
補足
- MAGLEV: V8エンジンにおける新しいJIT（Just-In-Time）コンパイラで、軽量かつ迅速な最適化を目的としています。従来のTurbofanよりもコンパイルが高速で、特定のケースでパフォーマンスを向上させることが期待されています。
- ホット関数: 実行頻度が高い関数。JavaScriptエンジンはこのような関数を検出し、より効率的に実行するために最適化します。
つねみ@tocomiもっとループ回数を増やしてみる
ループを 10,000 回まで増やすと更にログが増えた。
[marking 0x15ab001995c5 <JSFunction testFunction (sfi = 0x15ab0019951d)> for optimization to MAGLEV, ConcurrencyMode::kConcurrent, reason: hot and stable]
[compiling method 0x15ab001995c5 <JSFunction testFunction (sfi = 0x15ab0019951d)> (target MAGLEV), mode: ConcurrencyMode::kConcurrent]
[marking 0x15ab0019956d <JSFunction (sfi = 0x15ab001994b5)> for optimization to MAGLEV, ConcurrencyMode::kConcurrent, reason: hot and stable]
[compiling method 0x15ab0019956d <JSFunction (sfi = 0x15ab001994b5)> (target MAGLEV) OSR, mode: ConcurrencyMode::kConcurrent]
[completed compiling 0x15ab001995c5 <JSFunction testFunction (sfi = 0x15ab0019951d)> (target MAGLEV) - took 0.000, 0.250, 0.000 ms]
[marking 0x15ab001995c5 <JSFunction testFunction (sfi = 0x15ab0019951d)> for optimization to TURBOFAN_JS, ConcurrencyMode::kConcurrent, reason: hot and stable]
[compiling method 0x15ab001995c5 <JSFunction testFunction (sfi = 0x15ab0019951d)> (target TURBOFAN_JS), mode: ConcurrencyMode::kConcurrent]
[completed compiling 0x15ab0019956d <JSFunction (sfi = 0x15ab001994b5)> (target MAGLEV) OSR - took 0.000, 0.208, 0.000 ms]
[compiling method 0x15ab0019956d <JSFunction (sfi = 0x15ab001994b5)> (target TURBOFAN_JS) OSR, mode: ConcurrencyMode::kConcurrent]
メモ
- TURBOFAN という新しいコンパイラが出てきた
- MAGREV から切り替わってるから、より高性能だったりするのかな？
- testFunction が最適化されるのはわかるが、他の関数も最適されてるのはなぜ？そもそもどこを指しているんだろうか
- OSR(On-Stack Replacement) という概念
- 一つ前の実行だと completed compiling というログはなかったから、最適化が完了する前にスクリプトの実行自体が完了したんだろうな
GPT による解説
この出力は、V8エンジンがJavaScriptコードを最適化する際の動作ログです。関数が実行される中で、頻繁に呼び出される（“hot”）と判断された関数を、V8の最適化コンパイラ（MAGLEVやTURBOFAN）で効率化している様子が記録されています。以下に各行の解説を示します。
1. testFunction の最適化対象へのマーク
[marking 0x15ab001995c5 <JSFunction testFunction (sfi = 0x15ab0019951d)> for optimization to MAGLEV, ConcurrencyMode::kConcurrent, reason: hot and stable]
- testFunction が頻繁に呼び出され、かつエラーなどなく安定しているため、最適化の対象として選ばれました。
- 最適化には、軽量で高速なコンパイラ「MAGLEV」を使用。
- ConcurrencyMode::kConcurrent は、この最適化が並列処理としてバックグラウンドで実行されることを示しています。
2. MAGLEVでの最適化開始
[compiling method 0x15ab001995c5 <JSFunction testFunction (sfi = 0x15ab0019951d)> (target MAGLEV), mode: ConcurrencyMode::kConcurrent]
- testFunction の最適化が、MAGLEVコンパイラによって開始されました。
- 並列処理（他の作業と同時進行）で行われています。
3. 別の関数の最適化対象マーク
[marking 0x15ab0019956d <JSFunction (sfi = 0x15ab001994b5)> for optimization to MAGLEV, ConcurrencyMode::kConcurrent, reason: hot and stable]
- もう1つの関数が、頻繁に呼び出され安定しているため、最適化の対象に選ばれました。
- この関数も、MAGLEVコンパイラで最適化されます。
4. 別の関数でOSR（On-Stack Replacement）による最適化
[compiling method 0x15ab0019956d <JSFunction (sfi = 0x15ab001994b5)> (target MAGLEV) OSR, mode: ConcurrencyMode::kConcurrent]
- この関数は、「OSR（On-Stack Replacement）」という方式で最適化されます。
- OSR とは:
- 実行中の関数が特定のタイミングで最適化されたコードに置き換えられる技術。
- ループなど、長時間実行される処理の最適化に特に有効。
5. MAGLEVでの最適化完了
[completed compiling 0x15ab001995c5 <JSFunction testFunction (sfi = 0x15ab0019951d)> (target MAGLEV) - took 0.000, 0.250, 0.000 ms]
- testFunction の最適化が完了しました。
- 最適化にかかった時間が記録されています:
- 0.250 ms: MAGLEVによる最適化処理時間。
6. TURBOFANによる更なる最適化のマーク
[marking 0x15ab001995c5 <JSFunction testFunction (sfi = 0x15ab0019951d)> for optimization to TURBOFAN_JS, ConcurrencyMode::kConcurrent, reason: hot and stable]
- MAGLEV による最適化後も、さらに高度な TURBOFAN コンパイラで最適化を進めることが決定。
- TURBOFAN は、MAGLEVよりも重い処理を行いますが、より高性能な最適化を実現します。
7. TURBOFANでの最適化開始
[compiling method 0x15ab001995c5 <JSFunction testFunction (sfi = 0x15ab0019951d)> (target TURBOFAN_JS), mode: ConcurrencyMode::kConcurrent]
- TURBOFAN コンパイラで testFunction の最適化が開始されました。
- 並列処理で実行されています。
8. MAGLEVで別の関数の最適化完了
[completed compiling 0x15ab0019956d <JSFunction (sfi = 0x15ab001994b5)> (target MAGLEV) OSR - took 0.000, 0.208, 0.000 ms]
- OSR（On-Stack Replacement）で最適化されていた別の関数のMAGLEV最適化が完了。
- 処理時間は0.208 msでした。
9. TURBOFANで別の関数の最適化開始
[compiling method 0x15ab0019956d <JSFunction (sfi = 0x15ab001994b5)> (target TURBOFAN_JS) OSR, mode: ConcurrencyMode::kConcurrent]
- OSRによるMAGLEV最適化が終わった後、この関数をさらに TURBOFAN コンパイラで最適化するプロセスが開始されました。
- これも並列処理で行われています。
要約
- V8エンジンは、関数が頻繁に呼び出されていることを検知すると、軽量な MAGLEV コンパイラで最適化を開始します。
- MAGLEVでの最適化が完了すると、さらに高度な TURBOFAN コンパイラでの最適化に進みます。
- 実行中の関数でも、OSR（On-Stack Replacement）を利用して動的に最適化が適用されます。
- それぞれの処理には並列性が確保されており、効率よく最適化が進められています。
このログは、V8エンジンがパフォーマンス向上のために段階的な最適化を行っている様子を示しています。
つねみ@tocomiもっともっとループ回数を増やしてみる
1,000,000回ループ
[marking 0x2e5f001995c5 <JSFunction testFunction (sfi = 0x2e5f0019951d)> for optimization to MAGLEV, ConcurrencyMode::kConcurrent, reason: hot and stable]
[compiling method 0x2e5f001995c5 <JSFunction testFunction (sfi = 0x2e5f0019951d)> (target MAGLEV), mode: ConcurrencyMode::kConcurrent]
[marking 0x2e5f0019956d <JSFunction (sfi = 0x2e5f001994b5)> for optimization to MAGLEV, ConcurrencyMode::kConcurrent, reason: hot and stable]
[compiling method 0x2e5f0019956d <JSFunction (sfi = 0x2e5f001994b5)> (target MAGLEV) OSR, mode: ConcurrencyMode::kConcurrent]
[completed compiling 0x2e5f001995c5 <JSFunction testFunction (sfi = 0x2e5f0019951d)> (target MAGLEV) - took 0.000, 0.208, 0.000 ms]
[completed compiling 0x2e5f0019956d <JSFunction (sfi = 0x2e5f001994b5)> (target MAGLEV) OSR - took 0.000, 0.208, 0.000 ms]
[compiling method 0x2e5f0019956d <JSFunction (sfi = 0x2e5f001994b5)> (target TURBOFAN_JS) OSR, mode: ConcurrencyMode::kConcurrent]
[completed compiling 0x2e5f0019956d <JSFunction (sfi = 0x2e5f001994b5)> (target TURBOFAN_JS) OSR - took 0.000, 0.834, 0.000 ms]
[completed optimizing 0x2e5f0019956d <JSFunction (sfi = 0x2e5f001994b5)> (target TURBOFAN_JS) OSR]
[bailout (kind: deopt-eager, reason: prepare for on stack replacement (OSR)): begin. deoptimizing 0x2e5f0019956d <JSFunction (sfi = 0x2e5f001994b5)>, 0x22b5000803c5 <Code MAGLEV>, opt id 1, bytecode offset 25, deopt exit 5, FP to SP delta 96, caller SP 0x00016bd061a8, pc 0x00016d980570]
メモ
- bailout というのが起こった。これは最適化の解除で、OSR の準備のために一時的に発生した模様。
GPT による解説
このログは、V8エンジンが関数を最適化する際のプロセスと、それに伴う「最適化解除（deopt）」が発生する様子を記録したものです。それぞれの段階を分かりやすく解説します。
1. testFunction を MAGLEV で最適化対象にマーク
[marking 0x2e5f001995c5 <JSFunction testFunction (sfi = 0x2e5f0019951d)> for optimization to MAGLEV, ConcurrencyMode::kConcurrent, reason: hot and stable]
- testFunction が頻繁に呼び出されていて（hot）、かつ安定している（stable）ため、軽量で高速な MAGLEV コンパイラで最適化することが決定されました。
- 並列処理（ConcurrencyMode::kConcurrent）として実行されます。
2. MAGLEV での最適化開始
[compiling method 0x2e5f001995c5 <JSFunction testFunction (sfi = 0x2e5f0019951d)> (target MAGLEV), mode: ConcurrencyMode::kConcurrent]
- testFunction の最適化が、MAGLEV を使って開始されました。
3. 別の関数も MAGLEV の最適化対象にマーク
[marking 0x2e5f0019956d <JSFunction (sfi = 0x2e5f001994b5)> for optimization to MAGLEV, ConcurrencyMode::kConcurrent, reason: hot and stable]
- 別の関数が頻繁に呼び出されており、MAGLEV で最適化することが決定されました。
4. OSR（On-Stack Replacement）による MAGLEV 最適化
[compiling method 0x2e5f0019956d <JSFunction (sfi = 0x2e5f001994b5)> (target MAGLEV) OSR, mode: ConcurrencyMode::kConcurrent]
- 別の関数は、OSR（On-Stack Replacement）を利用して最適化されています。
- OSR:
- 実行中の関数（特に長時間実行されるループなど）が、最適化されたコードに切り替わる仕組み。
5. MAGLEV 最適化の完了
[completed compiling 0x2e5f001995c5 <JSFunction testFunction (sfi = 0x2e5f0019951d)> (target MAGLEV) - took 0.000, 0.208, 0.000 ms]
- testFunction の MAGLEV 最適化が 0.208 ms で完了しました。
[completed compiling 0x2e5f0019956d <JSFunction (sfi = 0x2e5f001994b5)> (target MAGLEV) OSR - took 0.000, 0.208, 0.000 ms]
- 別の関数の MAGLEV 最適化も 0.208 ms で完了しました。
6. TURBOFAN を使った OSR 最適化
[compiling method 0x2e5f0019956d <JSFunction (sfi = 0x2e5f001994b5)> (target TURBOFAN_JS) OSR, mode: ConcurrencyMode::kConcurrent]
- MAGLEV の次に、より高度な TURBOFAN コンパイラを使って OSR 最適化が開始されました。
- TURBOFAN は重い処理を行いますが、より高性能な最適化が可能です。
[completed compiling 0x2e5f0019956d <JSFunction (sfi = 0x2e5f001994b5)> (target TURBOFAN_JS) OSR - took 0.000, 0.834, 0.000 ms]
- TURBOFAN による最適化が 0.834 ms で完了しました。
7. TURBOFAN 最適化完了の記録
[completed optimizing 0x2e5f0019956d <JSFunction (sfi = 0x2e5f001994b5)> (target TURBOFAN_JS) OSR]
- 最適化の最終段階として、TURBOFAN コンパイラを使った OSR 最適化が完全に終了しました。
8. デオプティマイズ（最適化解除）の発生
[bailout (kind: deopt-eager, reason: prepare for on stack replacement (OSR)): begin. deoptimizing 0x2e5f0019956d <JSFunction (sfi = 0x2e5f001994b5)>, 0x22b5000803c5 <Code MAGLEV>, opt id 1, bytecode offset 25, deopt exit 5, FP to SP delta 96, caller SP 0x00016bd061a8, pc 0x00016d980570]
- 最適化が解除され、関数が元の非最適化コードに戻されました。
- 理由:
- OSR（On-Stack Replacement）の準備のために、一時的に最適化を解除しました（reason: prepare for on stack replacement）。
- 詳細:
- bytecode offset 25: 問題が発生したコードの位置。
- FP to SP delta 96: フレームポインタ（FP）とスタックポインタ（SP）のメモリ位置の差異。
- caller SP: 呼び出し元のスタックポインタ。
要約
- testFunction と別の関数が MAGLEV コンパイラで最適化されました。
- MAGLEV の次に、TURBOFAN コンパイラでさらに最適化が行われました。
- 最適化中に、OSR の準備のために一部のコードがデオプティマイズされました。
このログは、V8 が関数を効率化するために複数段階の最適化を実行し、必要に応じて元のコードに戻すプロセスを記録しています。デオプティマイズは必ずしもエラーではなく、動的な最適化の一環です。
つねみ@tocomi最適化を邪魔したい
1,000,000回ループの状態で、最適化を起こさせないようなコードを書けないか試してみる。
function testFunction(x) {
return x * 2;
}
const LOOP_COUNT = 1000000;
for (let i = 0; i < LOOP_COUNT; i++) {
testFunction(Math.random());
}
testFunction の引数を Math.random() に変えてみたが、ログの出方は変わらず🤔
つねみ@tocomi最適化を無効にすると？
ループ 100,000,000 回で速度を比較してみるよ
function testFunction(x) {
return x * 2;
}
const LOOP_COUNT = 100000000;
const start = performance.now();
for (let i = 0; i < LOOP_COUNT; i++) {
testFunction(10);
}
const end = performance.now();
console.log(`🏁 Execution time: ${end - start} ms`);
最適化あり
v8 --trace-opt --trace-deopt script.js
54.625ms
[marking 0x00a400199659 <JSFunction testFunction (sfi = 0xa4001995a1)> for optimization to MAGLEV, ConcurrencyMode::kConcurrent, reason: hot and stable]
[compiling method 0x00a400199659 <JSFunction testFunction (sfi = 0xa4001995a1)> (target MAGLEV), mode: ConcurrencyMode::kConcurrent]
[marking 0x00a4001995f9 <JSFunction (sfi = 0xa400199529)> for optimization to MAGLEV, ConcurrencyMode::kConcurrent, reason: hot and stable]
[compiling method 0x00a4001995f9 <JSFunction (sfi = 0xa400199529)> (target MAGLEV) OSR, mode: ConcurrencyMode::kConcurrent]
[completed compiling 0x00a400199659 <JSFunction testFunction (sfi = 0xa4001995a1)> (target MAGLEV) - took 0.000, 0.167, 0.000 ms]
[marking 0x00a400199659 <JSFunction testFunction (sfi = 0xa4001995a1)> for optimization to TURBOFAN_JS, ConcurrencyMode::kConcurrent, reason: hot and stable]
[compiling method 0x00a400199659 <JSFunction testFunction (sfi = 0xa4001995a1)> (target TURBOFAN_JS), mode: ConcurrencyMode::kConcurrent]
[completed compiling 0x00a4001995f9 <JSFunction (sfi = 0xa400199529)> (target MAGLEV) OSR - took 0.000, 0.167, 0.000 ms]
[compiling method 0x00a4001995f9 <JSFunction (sfi = 0xa400199529)> (target TURBOFAN_JS) OSR, mode: ConcurrencyMode::kConcurrent]
[completed compiling 0x00a400199659 <JSFunction testFunction (sfi = 0xa4001995a1)> (target TURBOFAN_JS) - took 0.000, 0.541, 0.000 ms]
[completed optimizing 0x00a400199659 <JSFunction testFunction (sfi = 0xa4001995a1)> (target TURBOFAN_JS)]
[completed compiling 0x00a4001995f9 <JSFunction (sfi = 0xa400199529)> (target TURBOFAN_JS) OSR - took 0.041, 0.625, 0.000 ms]
[completed optimizing 0x00a4001995f9 <JSFunction (sfi = 0xa400199529)> (target TURBOFAN_JS) OSR]
[bailout (kind: deopt-eager, reason: prepare for on stack replacement (OSR)): begin. deoptimizing 0x00a4001995f9 <JSFunction (sfi = 0xa400199529)>, 0x26ea000c03d1 <Code MAGLEV>, opt id 2, bytecode offset 38, deopt exit 6, FP to SP delta 96, caller SP 0x00016fc661a8, pc 0x000150040774]
[bailout (kind: deopt-eager, reason: Insufficient type feedback for generic named access): begin. deoptimizing 0x00a4001995f9 <JSFunction (sfi = 0xa400199529)>, 0x26ea000405a9 <Code TURBOFAN_JS>, opt id 3, bytecode offset 67, deopt exit 7, FP to SP delta 128, caller SP 0x00016fc661a8, pc 0x000150040ae0]
🏁 Execution time: 54.625 ms
最適化なし
v8 --trace-opt --trace-deopt --no-opt --no-maglev script.js
--no-opt オプションだけでいけると思ったけど、これだと TURBOFAN のみが無効になり MAGLEV が動いていたので、 --no-maglev オプションも付けた。
1135.417ms
めっちゃ速度変わった！
ログも何も出なくなったので、最適化がされない結果速度が変化したことが確認できた！
🏁 Execution time: 1135.417 ms