MDN’s new design is in Beta! A sneak peek: https://blog.mozilla.org/opendesign/mdns-new-design-beta/

プロファイラのチュートリアル

JavaScript プロファイラは JavaScript エンジンの状態を定期的にサンプリングして、その時点のコード実行のスタックを記録します。統計的に、個々の関数を実行しているときに取得したサンプル数はブラウザが実行にかけた時間に対応しますので、コード内のボトルネックを発見できます。

プロファイルを分析する

パフォーマンスツールがどのようにプロファイルを提供するかを理解するには、例を見ていくことがもっとも簡単です。以下のコードは 2 から 10,000 までの数値について素数であるかを確認して、その結果を表示します。少しおもしろくするため、素数の確認は setTimeout のコールバックとして実行します:

function isPrime(i) {
  for (var c = 2; c <= Math.sqrt(i); ++c) {
    if (i % c === 0) {
        console.log(i + " is not prime");
        return;
     }
  }
  console.log(i + " is prime");
}

function timedIsPrime(i) {
  setTimeout(function() {
    isPrime(i);
  }, 100);
}

function testPrimes() {
  var n = 10000;
  for (var i = 2; i != n; ++i) {
    timedIsPrime(i);
  }
}

var testPrimesButton = document.getElementById("test-primes");
testPrimesButton.addEventListener("click", testPrimes, false);

このコードを Web ページに貼り付けて実行すると、コンソールへ以下のように出力します:

"2 is prime"
"3 is prime"
"4 is not prime"
"5 is prime"
"6 is not prime"

このコードのプロファイルを取得すると、以下のように表示されるでしょう:

最初の行は、関数列が常に (ルート) になります。ここでは 2 つのことを示しています: プロファイリングに 1,121.95 ミリ秒かかっており、またその間に 78 個のサンプルを取得しました。(ルート) の下に、サンプルの取得中にプログラムで経由した、さまざまなパスのツリーを表示します。(ルート) の直下に、スタックの底にあるトップレベルの関数が現れます。この例では、トップレベルの関数が 2 つあります:

  • click イベントのリスナである testPrimes()
  • timedIsPrime() 内の setTimeout() の引数で指定した、無名のコールバック関数

testPrimes() の行を見ていきましょう:

ここでは、78 個のサンプルのうち 29 個を testPrimes() 内で取得したことがわかります。合計コストの列は、サンプル数をパーセント値に置き換えたものです: (29/78) * 100 = 37.17

ところが時間コストは、ともに 0 です。これは、そのスタックフレームのコードを実行している間に取得したサンプルがないためです。サンプルはすべて、関数内にネストしているブロックまたは testPrimes() が呼び出した関数の内部で取得したものです。これは次の行でわかります:

この行も testPrimes という名称です。これは 19 行目から始まる for ループが作成した、testPrimes() の新たなスタックフレームを指しています。前のフレームのコストが 0 であったことから予想されるとおり、このフレームのサンプル列も 29 です。

しかし、コスト時間は 0 ではありません。これはいくつかのサンプルが、このフレームを実行しているときに取得されたことを表します。プロファイルではサンプルをいくつ取得したかを明示していませんが、次の timedIsPrime という名前の行で取得したサンプルが 24 個であることから、5 個取得したはずです。これは簡単に確認できます。(5/78) * 100 = 6.41 であり、コストの値と一致します。

この分岐で残る 24 個のサンプル (全体の 30.76%) は timedIsPrime() で取得されました。つまり、setTimeout() (12 行目) を呼び出している部分です。

コールツリーの別の分岐は、setTimeout() (13 行目) に渡した無名のコールバック関数から始まっています。ここではサンプルを 1 個取得しており、残り 48 個のサンプル (全体の 61.53%) はコールバックで呼び出す isPrime() で取得されました。

総括すると、もっとも多くのサンプルを isPrime() で取得しており (全体の 61.53%)、その次が timedIsPrime() (全体の 30.76%)、残りは取るに足らない量です。統計的に言えば、おそらくこれらの関数がほとんどの時間を消費していますので、プログラムを高速化したい場合の有力な最適化候補になります。

合計時間時間

合計時間時間の列は合計コストコストから算出していますが、直接反映したものではありません。規則的にサンプルを取得しようとしていますが、そのとおりに取得できない場合もあります。適切な時期にサンプルを取得できなかった場合は、その不規則性を補正しようとします。

呼び出しツリーを反転

既定では、プロファイラは一般的なコールスタックと同様に、呼び出しツリーを根から葉の順に表示します。つまりそれぞれのトップレベル関数、トップレベル関数が呼び出す関数、その関数から呼び出される関数、といった順になります:

testPrimes

  -> timedIsPrime



(setTimeout callback)

  -> isPrime

これは論理的かつスタックが積み上げられる時系列に従っており、コールスタックを表現するための慣習的な方法でもあります。一方、時間がかかっている場所が呼び出しツリーの深部にあることがよくあります。前出の例でわかるとおり、全サンプルの 90% は 2 つの主要な分岐の終端で発生しています。

多くのサンプルを記録したスタックフレームに注目させるため、呼び出しツリーを反転させるオプションがプロファイラにあります。このオプションを選択すると、プロファイラは以下のようになります:

  • コストが 0 より大きいスタックフレーム、つまり、サンプルを取得したとき実際に実行していたスタックフレームのリストを作成します。
  • リストは、スタックフレームで取得したサンプル数の順に並べ替えられます。
  • リスト内の各項目で、コールスタックをトップレベル関数に向かって逆向きに表示します。

例えば testPrimes の例を、既定の表示でもう一度示します:

呼び出しツリーを反転すると以下のようになります:

反転した表示では、プログラムで時間がかかっている場所を効果的に目立たせていることがわかるでしょう。

ドキュメントのタグと貢献者

 このページの貢献者: yyss
 最終更新者: yyss,