blob: 1f857f4b748b681ccd80c23400c3fb196037000c (
plain)
1
2
3
4
5
6
7
8
9
10
11
12
13
14
15
16
17
18
19
20
21
22
23
24
25
26
27
28
29
30
31
32
33
34
35
36
37
38
39
40
41
42
43
44
45
46
47
48
49
50
51
52
53
54
55
56
57
58
59
60
61
62
63
64
65
66
67
68
69
70
71
72
73
74
75
76
77
78
79
80
81
82
83
84
85
86
87
88
89
90
91
92
93
94
95
96
97
98
99
100
101
102
103
104
105
106
107
108
109
110
111
112
113
114
115
|
---
title: プロファイラのチュートリアル
slug: conflicting/Tools/Performance/Call_Tree
translation_of: Tools/Performance/Call_Tree
translation_of_original: Tools/Performance/Profiler_walkthrough
original_slug: Tools/Performance/Profiler_walkthrough
---
<div>{{ToolsSidebar}}</div><p>JavaScript プロファイラは JavaScript エンジンの状態を定期的にサンプリングして、その時点のコード実行のスタックを記録します。統計的に、個々の関数を実行しているときに取得したサンプル数はブラウザが実行にかけた時間に対応しますので、コード内のボトルネックを発見できます。</p>
<h2 id="Analysing_profiles" name="Analysing_profiles">プロファイルを分析する</h2>
<p>パフォーマンスツールがどのようにプロファイルを提供するかを理解するには、例を見ていくことがもっとも簡単です。以下のコードは 2 から 10,000 までの数値について素数であるかを確認して、その結果を表示します。少しおもしろくするため、素数の確認は <code><a href="/ja/docs/Web/API/WindowTimers.setTimeout">setTimeout</a></code> のコールバックとして実行します:</p>
<pre class="brush: js">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);</pre>
<p>このコードを Web ページに貼り付けて実行すると、コンソールへ以下のように出力します:</p>
<pre>"2 is prime"
"3 is prime"
"4 is not prime"
"5 is prime"
"6 is not prime"</pre>
<p>このコードのプロファイルを取得すると、以下のように表示されるでしょう:</p>
<p><img alt="" src="https://mdn.mozillademos.org/files/9511/primality-profile.png" style="display: block; margin-left: auto; margin-right: auto; width: 650px;"></p>
<p>最初の行は、<em>関数</em>列が常に <em>(ルート)</em> になります。ここでは 2 つのことを示しています: プロファイリングに 1,121.95 ミリ秒かかっており、またその間に 78 個のサンプルを取得しました。<em>(ルート)</em> の下に、サンプルの取得中にプログラムで経由した、さまざまなパスのツリーを表示します。<em>(ルート)</em> の直下に、スタックの底にあるトップレベルの関数が現れます。この例では、トップレベルの関数が 2 つあります:</p>
<ul>
<li>click イベントのリスナである <code>testPrimes()</code></li>
<li><code>timedIsPrime()</code> 内の <code>setTimeout()</code> の引数で指定した、無名のコールバック関数</li>
</ul>
<p><code>testPrimes()</code> の行を見ていきましょう:</p>
<p><img alt="" src="https://mdn.mozillademos.org/files/9515/primality-profile-testprimes.png" style="display: block; margin-left: auto; margin-right: auto; width: 650px;"></p>
<p>ここでは、78 個のサンプルのうち 29 個を <code>testPrimes()</code> 内で取得したことがわかります。<em>合計コスト</em>の列は、サンプル数をパーセント値に置き換えたものです: <code>(29/78) * 100</code> =<code> 37.17</code></p>
<p>ところが<em>時間</em>と<em>コスト</em>は、ともに 0 です。これは、そのスタックフレームのコードを実行している間に取得したサンプルがないためです。サンプルはすべて、関数内にネストしているブロックまたは <code>testPrimes()</code> が呼び出した関数の内部で取得したものです。これは次の行でわかります:</p>
<p><img alt="" src="https://mdn.mozillademos.org/files/9517/primality-profile-testprimes-2.png" style="display: block; margin-left: auto; margin-right: auto; width: 650px;"></p>
<p>この行も <em>testPrimes</em> という名称です。これは 19 行目から始まる <code>for</code> ループが作成した、<code>testPrimes()</code> の新たなスタックフレームを指しています。前のフレームの<em>コスト</em>が 0 であったことから予想されるとおり、このフレームの<em>サンプル</em>列も 29 です。</p>
<p>しかし、<em>コスト</em>と<em>時間</em>は 0 ではありません。これはいくつかのサンプルが、このフレームを実行しているときに取得されたことを表します。プロファイルではサンプルをいくつ取得したかを明示していませんが、次の <em>timedIsPrime</em> という名前の行で取得したサンプルが 24 個であることから、5 個取得したはずです。これは簡単に確認できます。<code>(5/78) * 100 = 6.41</code> であり、<em>コスト</em>の値と一致します。</p>
<p>この分岐で残る 24 個のサンプル (全体の 30.76%) は <code>timedIsPrime()</code> で取得されました。つまり、<code>setTimeout()</code> (12 行目) を呼び出している部分です。</p>
<p>コールツリーの別の分岐は、<code>setTimeout()</code> (13 行目) に渡した無名のコールバック関数から始まっています。ここではサンプルを 1 個取得しており、残り 48 個のサンプル (全体の 61.53%) はコールバックで呼び出す <code>isPrime()</code> で取得されました。</p>
<p>総括すると、もっとも多くのサンプルを <code>isPrime()</code> で取得しており (全体の 61.53%)、その次が <code>timedIsPrime()</code> (全体の 30.76%)、残りは取るに足らない量です。統計的に言えば、おそらくこれらの関数がほとんどの時間を消費していますので、プログラムを高速化したい場合の有力な最適化候補になります。</p>
<h3 id="Total_Time_and_Self_Time" name="Total_Time_and_Self_Time"><em>合計時間</em>と<em>時間</em></h3>
<p><em>合計時間</em>と<em>時間</em>の列は<em>合計コスト</em>と<em>コスト</em>から算出していますが、直接反映したものではありません。規則的にサンプルを取得しようとしていますが、そのとおりに取得できない場合もあります。適切な時期にサンプルを取得できなかった場合は、その不規則性を補正しようとします。</p>
<h3 id="Inverting_the_call_tree" name="Inverting_the_call_tree">呼び出しツリーを反転</h3>
<p>既定では、プロファイラは一般的なコールスタックと同様に、呼び出しツリーを根から葉の順に表示します。つまりそれぞれのトップレベル関数、トップレベル関数が呼び出す関数、その関数から呼び出される関数、といった順になります:</p>
<pre>testPrimes
-> timedIsPrime
(setTimeout callback)
-> isPrime</pre>
<p>これは論理的かつスタックが積み上げられる時系列に従っており、コールスタックを表現するための慣習的な方法でもあります。一方、時間がかかっている場所が呼び出しツリーの深部にあることがよくあります。前出の例でわかるとおり、全サンプルの 90% は 2 つの主要な分岐の終端で発生しています。</p>
<p>多くのサンプルを記録したスタックフレームに注目させるため、呼び出しツリーを反転させるオプションがプロファイラにあります。このオプションを選択すると、プロファイラは以下のようになります:</p>
<ul>
<li><em>コスト</em>が 0 より大きいスタックフレーム、つまり、サンプルを取得したとき実際に実行していたスタックフレームのリストを作成します。</li>
<li>リストは、スタックフレームで取得したサンプル数の順に並べ替えられます。</li>
<li>リスト内の各項目で、コールスタックをトップレベル関数に向かって逆向きに表示します。</li>
</ul>
<p>例えば testPrimes の例を、既定の表示でもう一度示します:</p>
<p><img alt="" src="https://mdn.mozillademos.org/files/9511/primality-profile.png" style="display: block; margin-left: auto; margin-right: auto; width: 650px;"></p>
<p>呼び出しツリーを反転すると以下のようになります:</p>
<p><img alt="" src="https://mdn.mozillademos.org/files/9521/primality-profile-inverted.png" style="display: block; margin-left: auto; margin-right: auto; width: 650px;"></p>
<p>反転した表示では、プログラムで時間がかかっている場所を効果的に目立たせていることがわかるでしょう。</p>
|