Application Insights Profiler データを表示する

  • [アーティクル]

Web パフォーマンス テストを実行しているものとします。 Web アプリに負荷がかかった状態のパフォーマンスを把握するには、トレースが必要です。 この記事では、次のことを行います。

  • Web パフォーマンス テストを開始するか、Profiler オンデマンド セッションを開始して、Web アプリへのトラフィックを生成します。
  • ロード テストまたはプロファイラー セッションの後に Profiler トレースを表示します。
  • Profiler のパフォーマンス データと呼び出し履歴を読み取る方法について説明します。

Azure サービスへのトラフィックを生成する

Profiler がトレースをアップロードするには、サービスが要求をアクティブに処理する必要があります。

Profiler を新しく有効にした場合は、Azure Load Testing を使用して短い ロード テストを実行します。

Azure サービスに既に受信トラフィックがある場合、またはトラフィックを手動で生成するだけの場合は、ロード テストをスキップして Profiler オンデマンド セッションを開始します。

  1. Azure サービスの Application Insights の [概要] ページで、左側のメニューから [パフォーマンス] を選択します。

  2. [パフォーマンス] ペインで、Profiler 設定の上部メニューから [Profiler] を選択します。

    Screenshot of the Profiler button from the Performance pane.

  3. Profiler の [設定] ページが読み込まれたら、[今すぐプロファイル] を選択します。

    Screenshot of Profiler page features and settings.

トレースを表示する

  1. Profiler セッションの実行が完了したら、[パフォーマンス] ペインに戻ります。

  2. [ドリル イン...] で、[Profiler トレース] を選択してトレースを表示します。

    Screenshot of trace explorer page.

トレース エクスプローラーは、次の情報を表示します。

Assert 説明
プロファイル ツリー v. フレーム グラフ トレースをツリーまたはグラフ形式で表示します。
ホット パス 選択すると、最大のリーフ ノードが開きます。 ほとんどの場合、このようなノードはパフォーマンスのボトルネックの近くにあります。
フレームワークの依存関係 トレースに関連付けられているトレース対象の各フレームワークの依存関係を表示する場合に選択します。
イベントを非表示にする トレース ビューから非表示にする文字列を入力します。 [提案されたイベント] を選択して提案を確認します。
イベント イベント名または関数名。 このツリーには、コードと発生したイベント (SQL イベントや HTTP イベント) が混在して表示されます。 最上位のイベントは要求時間全体に相当します。
モジュール トレースされたイベントまたは関数が発生したモジュール。
スレッド時刻 操作の開始から終了までの期間。
タイムライン 関数またはイベントが他の関数と関連して実行されていた時間。

パフォーマンス データの解釈方法

Profiler では、アプリのパフォーマンス分析に、サンプリング メソッドとインストルメンテーションを組み合わせて使用します。 詳細なコレクションの実行中に、Profiler は次のことを行います。

  • 各マシン CPU の命令ポインターをミリ秒ごとにサンプリングします。
    • 各サンプでルは、スレッドの呼び出し履歴全体がキャプチャされ、抽象度が最も高いレベルと最も低いレベルの両方で詳細情報が取得されます。
  • アクティビティの相関関係と因果関係を追跡するイベントを収集します。
    • コンテキストの切り替え
    • タスク並列ライブラリ (TPL) イベント
    • スレッド プール イベント

タイムライン ビューに表示される呼び出し履歴は、サンプリングとインストルメンテーションの結果です。 各サンプルはスレッドの完全な呼び出し履歴をキャプチャするため、これには Microsoft .NET Framework や、参照しているその他のすべてのフレームワークのコードが含まれています。

オブジェクトの割り当て (clr!JIT_New または clr!JIT_Newarr1)

clr!JIT_New と clr!JIT_Newarr1 は、マネージド ヒープからメモリを割り当てる .NET Framework のヘルパー関数です。

  • clr!JIT_New は、オブジェクトが割り当てられるときに呼び出されます。
  • clr!JIT_Newarr1 は、オブジェクト配列が割り当てられるときに呼び出されます。

通常、これら 2 つの関数はすばやく動作します。 タイムラインで clr!JIT_New または clr!JIT_Newarr1 によって時間がかかっている場合は、そのコードが多数のオブジェクトを割り当て、大量のメモリを消費する可能性があることを示しています。

コードの読み込み (clr!ThePreStub)

clr!ThePreStub は、コードを初期実行用に準備する.NET Framework のヘルパー関数です。これには、通常、Just-In-Time (JIT) コンパイルが含まれます。 C# の各メソッドでは、1 回の処理中に clr!ThePreStub が最大 1 回呼び出されます。

要求に対して clr!ThePreStub が余分な時間を要している場合、それはそのメソッドを実行する最初の要求です。 .NET Framework ランタイムは、最初のメソッドを読み込むのにかなりの時間がかかります。 以下を検討してください。

  • コードのその部分を、ユーザーがアクセスする前に実行するウォーミングアップ プロセスを使用します。
  • アセンブリでネイティブ イメージ ジェネレーター (ngen.exe) を実行します。

ロックの競合 (clr!JITutil_MonContention または clr!JITutil_MonEnterWorker)

clr!JITutil_MonContention または clr!JITutil_MonEnterWorker は、現在のスレッドが、ロックが解放されるのを待っていることを示します。 このテキストは、多くの場合、次の場合に表示されます。

  • C# LOCK ステートメントを実行する、
  • Monitor.Enter メソッドを呼び出す、または
  • MethodImplOptions.Synchronized 属性を使用してメソッドを呼び出す。

ロックの競合は通常、スレッド A がロックを取得し、スレッド A がそれを解放する前にスレッド B が同じロックを取得しようとしたときに発生します。

コードの読み込み ([COLD])

.NET Framework ランタイムで最適化されていないコードを初めて実行する場合、メソッド名には [COLD] が含まれます。

mscorlib.ni![COLD]System.Reflection.CustomAttribute.IsDefined

これは、メソッドごとに、その処理中に最大 1 回表示されます。

要求に対してコードの読み込みにかなり時間がかかっている場合、それは、そのメソッドの最適化されていない部分が初めて実行される要求です。 コードのその部分を、ユーザーがアクセスする前に実行するウォーミングアップ プロセスを使用することを検討してください。

HTTP 要求の送信

HttpClient.Send などのメソッドは、コードが HTTP 要求の完了を待機していることを示します。

データベース操作

SqlCommand.Execute などのメソッドは、データベース操作が終了するのをコードが待機していることを示します。

待機 (AWAIT_TIME)

AWAIT_TIME は、別のタスクが終了するのをコードが待機していることを示します。 この遅延は、C# の AWAIT ステートメントで発生します。 コードで C# AWAIT が実行される場合:

  • スレッドはアンワインドし、スレッド プールに制御を返します。
  • AWAIT の完了を待機しているブロックされたスレッドはありません。

ただし、論理的に見れば、AWAIT を実行したスレッドは、操作の完了を待機している間 "ブロック" されます。 AWAIT_TIME ステートメントは、タスクが終了するのを待機しているブロック時間を示します。

AWAIT_TIME が自分のコードではなくフレームワーク コード内にあるように見える場合は、Profiler に次の情報が表示される可能性があります。

  • AWAIT の実行に使用されるフレームワーク コード
  • AWAIT に関するテレメトリを記録するために使用されるコード

ページの上部にある [フレームワーク依存関係] チェック ボックスをオフにすると、自分のコードのみが表示され、AWAIT の発信元を確認しやすくなります。

ブロック時間

BLOCKED_TIME は、別のリソースが使用可能になるのをコードが待機していることを示します。 たとえば、次を待機している可能性があります。

  • 同期オブジェクト
  • 使用可能になるスレッド
  • 完了する要求

アンマネージド非同期

スレッド間で非同期呼び出しを追跡できるように、.NET Framework では、ETW イベントを出力し、スレッド間でアクティビティ ID を渡します。 アンマネージド (ネイティブ) コードと一部の古いスタイルの非同期コードには、これらのイベントとアクティビティ ID がないため、Profiler ではスレッドで実行されているスレッドと関数を追跡できません。 この項目は、呼び出し履歴で Unmanaged Async とラベルが付けられます。 PerfView を使用して詳細な分析情報を得るために ETW ファイルをダウンロードします。

CPU 時間

命令の実行中のため、CPU がビジー状態です。

ディスク時間

アプリケーションがディスク操作を実行しています。

ネットワーク時間

アプリケーションがネットワーク操作を実行しています。

[When (実行期間)] 列

[When (実行期間)] 列は、ノードについて時間の経過と共に収集されたさまざまな包括的なサンプルを視覚化したものです。 要求の全範囲が 32 個のタイム バケットに分割され、そこにノードの包括的なサンプルが蓄積されます。 各バケットはバーとして表されます。 バーの長さは、調整された値を表します。 次のノードの場合、バーはバケット中のリソースの 1 つの消費量を表します。

  • CPU_TIME または BLOCKED_TIME としてマークされたノード。
  • リソース (CPU、ディスク、スレッドなど) を消費する明確な関係を持つノード。

これらのメトリックでは、複数のリソースを消費することによって値が 100% を超える場合があります。 たとえば、特定の期間に平均して 2 つの CPU を使用する場合、CPU 使用率は 200% になります。

次のステップ

具体的には、次の方法を学習します。

Profiler の設定を構成する