UI フリーズの原因を見つける
このチュートリアルでは、主要なプロファイリング手順を詳しく見ていき、dotTrace ビューアーのユーザーインターフェースを紹介します。 また、サンプルアプリケーションのプロファイルを取得し、その UI がフリーズする理由を特定してみます。これは非常に一般的なプロファイリングタスクです。
サンプルアプリケーション
サンプルアプリケーションは、テキストファイルの行を逆にするために使用されます（例: ABC => CBA）。 ファイルの選択 ボタンを使用して、ユーザーは処理する 1 つ以上のテキストファイルを選択します。 プロセスファイル ボタンは、ファイル内の行を逆にする別の BackgroundWorker スレッドを実行します。 ウィンドウの左隅に進行状況が表示されます。 処理が終了すると、ラベルは すべてのファイルが正常に処理されました を報告します。
ソースコードは github(英語) で入手できます。
このアプリケーションには重大な欠点があります。 ファイル処理を開始した後、処理が終了するまで UI ラグが発生します。
タイムラインプロファイリングを使って、これらのフリーズが起こる理由を調べましょう*
プロファイラの実行とスナップショットの取得
Visual Studio で MassFileProcessing.sln ソリューションを開きます。
を選択してプロファイラを実行します。
プロファイリングタイプ で、 タイムライン を選択します。
実行 をクリックします。 dotTrace はアプリケーションを実行し、プロファイリングプロセスを管理する専用のコントローラーウィンドウを表示します。
さて、アプリでパフォーマンスの問題を再現してみましょう。
ファイルの選択 をクリックし、 Text Files フォルダーにあるアプリケーション付属のテキストファイル 5 つを選択してください。
ファイル処理を開始するには、 プロセスファイル をクリックします。 ご覧のように、アプリケーションは非常に悪いです。 実際には、ファイル処理が完了して すべてのファイルが正常に処理されました が表示されるまで、ファイル処理の進行状況を見ることさえできません。
コントローラーウィンドウで スナップショットを取得して待機する をクリックして、タイムラインプロファイリングスナップショットを収集します。 スナップショットは Visual Studio の別の パフォーマンスプロファイラ ツールウィンドウで開きます。
アプリケーションを閉じます。 これにより、コントローラーウィンドウも閉じます。
タイムラインプロファイリングスナップショットの分析
スレッド をクリックして、 スレッド ツールウィンドウを開きます。 デフォルトでは、アンマネージドスレッドを除くすべてのアプリケーションスレッドが表示されます。表示されているフィルター値は、現在表示されているすべてのスレッドに対して計算されることに注意してください。 さらに分析を進めるため、何も作業していないスレッドには関心がありません。 では、まずそれらを除外しましょう。
ツールウィンドウのスレッドのリストを参照してください。 Main アプリケーションスレッド、実行時にオブジェクトをファイナライズするために使用する ファイナライザーオブジェクトのファイナライズ処理用スレッド スレッド（アプリケーションでは機能しません）、および ガベージコレクション スレッド（バックグラウンド GC の実行に使用）が含まれています。 バックグラウンドスレッドは CLR スレッドプールによって作成されるため、アプリケーションのファイルを処理する
BackgroundWorkerスレッドは スレッドプール （ID 13456）と識別されます。 もう 1 つの スレッドプール （ID 7416）も動作しません。 これは、おそらく補助 CLR スレッドプールです。 私たちの分析と無関係な ファイナライザーオブジェクトのファイナライズ処理用スレッド と スレッドプール （ID 7416）スレッドを隠してみましょう。スレッド ツールウィンドウで、 ファイナライザーオブジェクトのファイナライズ処理用スレッド と スレッドプール （ID 7416）スレッドを選択します。
右クリックして、 選択したスレッドを非表示にする を選択してください。
スレッド ウィンドウを参照してください。 スナップショットデータには、次のフィルターが現在適用されています： 「非表示以外のすべてのスレッドのライフタイム区間を選択」。
他のフィルターのデータもどのように変化したか確認してください。 例えば、 スレッドの状態 の状態時間は現在、非表示以外のすべてのスレッドについて計算されています。 ホットスポット と 呼び出しツリー も変化し、フィルターされたスレッドの呼び出しのみが表示されます。
現在の スレッド ダイアグラムのスケールでは、 13456 スレッドプール （
BackgroundWorkerスレッド）を詳細に見ることができません。 ダイアグラム全体に収まるように拡大しましょう。 これを行うには、 マウス ホイール を スレッド ダイアグラム上で使います。 これにより、可視時間範囲でのフィルター 1489 ミリ秒 が自動的に追加されます。 このフィルターが他のフィルターにどのような影響を与えるかに注目してください。すべての値が表示範囲の時間に合わせて再計算されます。 スナップショットデータには、現在次のフィルターが適用されています： 「可視時間範囲内で非表示以外のすべてのスレッドのすべての時間区間を選択」。
スレッド ダイアグラムを参照してください。 スレッドの状態が時間の経過とともにどのように変化したかがわかります。 例:
BackgroundWorkerスレッド 13456 スレッドプール は、約 16 秒後 (プロセスファイル ボタンをクリックした後) に開始されました。 ほとんどの時間、スレッドは 実行中 (濃い青の間隔) でした。 さらに、スレッドが 待機 状態 (薄い青の間隔) だった間隔もあります。
スレッド ツールウィンドウ * のプロセス概要ダイアグラムを参照してください。 CPU の利用に加えて、パフォーマンス分析に非常に役立つ 2 つのイベントダイアグラムを示しています。 UI フリーズ バーは、 13456 スレッドプール が作成された直後にフリーズが開始されたことを示します。
ガベージコレクションのブロック GC もこの時間間隔で集中的に実行されました。 ブロッキング GC はすべての管理対象スレッドを中断させるため、UI がフリーズする可能性があります。
これらの出来事を詳しく見なければならない。
まず、表示されている時間範囲フィルターが不要になったため削除しましょう。 これを行うには、 スレッド ツールウィンドウの上部にあるフィルターをクリックします *. ダイアグラムが再びズームアウトされます。
では、UI フリーズイベントをさらに詳しく調査しましょう。 このようなフリーズの主な原因は何でしょうか？ 主な原因は次のとおりです：
長いまたは頻繁なブロッキング GC;
他のスレッド（たとえば、ロックの競合による）による UI スレッドのブロック。
および / または過剰な計算作業を UI スレッド上で行うことができます。
これらの原因を一つずつ除外していき、最終的に本当の原因だけを残します。
UI フリーズ イベントを選択し、 スレッド ツールウィンドウのプロセス概要セクション内の該当バーをクリックしてください。 これで UI フリーズイベントによるフィルターが適用されます。 この操作により、フリーズの時間帯だけでなく、 Main スレッドによるフィルターも適用されることに注意してください。 この処理は自動的に行われます。なぜなら、メインスレッドのみがアプリケーション内の UI 操作を処理しているからです。 したがって、現在のフィルター結果は 「UI フリーズイベントが発生したメインスレッド上のすべての時間区間を選択」となります。
このフリーズの真の原因を特定するために、他のフィルター値を調べてみましょう。 解析すべき最初の潜在的な原因は、過剰なブロッキング GC です。
ブロッキング GC をクリックしてブロッキング GC フィルターを開き、値を確認します。
現在適用されているフィルターを考慮すると、メインスレッドがフリーズ中に GC によってブロックされた時間（ブロッキング GC 値）と（ブロッキング GC を除外する 値）は示されませんでした。
ブロッキング GC 時間は非常に長く（420 ミリ秒、または選択した間隔の 10.2%）、パフォーマンスに多少の影響を与える可能性があります。 それにもかかわらず、4 秒の凍結の原因となることはほとんどありません。 容疑者リストから過度のガベージコレクションを除外することがあります。
ブロッキング GC を除外する 値をクリックします。 結果のフィルターは 、「UI フリーズイベントが発生し、ブロッキング GC が実行されていないメインスレッド上のすべての時間間隔を選択する」になります。
「他のスレッドによるブロック」と「メインスレッドの過剰な処理」という潜在的な原因を調べてみましょう。
スレッドの状態 の値を開いて参照してください。 このフィルターは、特定の状態でスレッドが費やした合計時間を示します。 現在適用されているフィルターを考慮すると、フリーズ中の Main スレッドの状態を示します。
フリーズ時間（92.9% 、または 3426 ミリ秒 ）のほとんどは、スレッドが 実行中 のようにいくつかの作業を行っていたようです。 待機 状態の 225 ミリ秒 値が小さすぎるため、自動的に「他のスレッドによるブロッキング」が潜在的な原因から除外されます。 フリーズの原因は、メインスレッド上の計算作業のみになります。
今必要とするのは、フリーズ中に Main スレッド上で実行されたメソッドを見つけることだけです。 これには ホットスポット と 呼び出しツリー フィルターを使用できます。
スレッドの状態 フィルターで 実行中 を選択します。 これにより、結果のフィルターは 「UI フリーズが発生したときにメインスレッドが実行されていて、ブロッキング GC が実行されなかったすべての時間間隔を選択する」になります。 フィルターのリストは次のようになります：
これで、 ホットスポット および 呼び出しツリー のフィルターには、これらの時間帯に実行されたメソッドのみが含まれます。
パフォーマンスプロファイラ ウィンドウで ホットスポット をクリックし、該当するフィルターを開いてください。 ユーザーメソッドが実行時間順に並べられたシンプルなリストが表示されます。 ユーザーメソッドの実行時間は、そのメソッド自身の時間と、そのメソッドが呼び出すすべてのシステムメソッド（スタック内の次のユーザーメソッドまで）の自身の時間の合計として計算されます。
ご覧のとおり、実行時間が意味のあるメソッドは 2 つだけです：
App.MainとMainWindow.ProcessInProgress。呼び出しツリー を参照してください。
ご覧の通り、
App.Mainはほとんどの時間を Windows メッセージの処理に関連するいくつかのシステムメソッドで費やしています。これは、グラフィカルユーザーインターフェースを提供するアプリケーションの典型的な動作です。 これは、アプリケーションがメッセージループでユーザー入力を待っていることを示しています。 スナップショットを分析する際、これらのメソッドは無視しても問題ありません。 フリーズの原因となるメソッドを特定するには、スタック内の次のユーザーメソッドであるMainWindow.ProcessInProgressに着目する必要があります。 このメソッド内の何らかの計算作業により遅延が発生していると想定しているので、ソースコードを確認しましょう。呼び出しツリー で、
ProcessInProgressメソッドを右クリックし、コンテキストメニューから コードに移動する を選択してください。
ソースコードを参照してください。
private void ProcessInProgress(object sender, ProgressChangedEventArgs e) { var upd = (ProgressUpdater) e.UserState; lblProgress.Content = $"File {upd.CurrentFileNmb} of {upd.TotalFiles}: {e.ProgressPercentage}%"; }このメソッドは、メインウィンドウの進捗ラベルでファイル処理の進行状況を更新するだけのイベントハンドラーのようです。 これらの計算は複雑に見えませんが、なぜフリーズが発生したのでしょうか？ 実際には、このイベントハンドラーが頻繁に呼び出されすぎて、メインウィンドウがラベル更新に対応できていなかったようです。 この点をコードで確認してみましょう。
さらにコードの調査 * は、このイベントハンドラーが背景ワーカーの
ProgressChangedイベントに登録されていることを示しています。 このイベントは、ワーカーがReportProgressメソッドを呼び出すときに発生します。 これは、背景ワーカーのProcessFilesメソッドから呼び出されます。... for (int j = 0; j < _lines.Length; j++) { var line = _lines[j]; var stringReverser = new StringReverser(line); _lines[j] = stringReverser.Reverse(); if (j % 5 == 0) { var p = ((float)(j + 1) / _lines.Length) * 100; Worker.ReportProgress((int) p, _updater); } } ...パフォーマンス問題の原因はここです：
ReportProgressがテキストファイルの 5 行ごとに呼び出されています。 行が非常に速く処理されるため、ReportProgressがシステムにとって頻繁に呼び出されすぎています。 この頻度を、例えば 1000 行ごとに呼び出し 1 回といった具合に下げましょう。 コード内のif条件を改善してください。... if (j % 1000 == 0) { float _p = ((float)(j + 1) / _lines.Length) * 100; Worker.ReportProgress((int) _p, _updater); } ...ソリューションを再ビルドし、 プロファイラーの実行とスナップショット取得 に記載されている手順で、もう一度プロファイリングを実行してください。
もう遅延はありません！ タイムラインでも、ファイル処理中に UI フリーズは検出されません。
結論
ここでは主なチュートリアルを紹介します:
「古典的」パフォーマンスプロファイリングとは異なり、タイムラインプロファイリング中に、dotTrace は一時コールスタックとスレッド状態データを収集します。
タイムラインプロファイリングの結果を分析するには、Visual Studio の パフォーマンスプロファイラ ツールウィンドウまたはスタンドアロンの dotTrace Viewer アプリケーションを使用できます。
パフォーマンスプロファイラ および dotTrace Viewer は、アプリケーションのイベントタイムラインを視覚化し、収集された一時的なデータを細分化できるフィルターとダイアグラムのセットです。
各フィルターはデュアル目的です: データを表示し、特定の条件を設定することができます。
フィルターは一緒に連鎖することができます。