.NET Aspireなどの分散アプリが遅いのにCPU使用率が低い場合、最初に確認すべきなのは「CPU性能が足りないか」ではありません。遅い処理を実行しているプロセスを正しく測れているか、そしてCPUを使わずに待機している時間がないかを確認します。
AppHostだけをVisual Studio Performance Profilerで測定しても、別プロセスとして動くWeb UIやバックエンドの処理まで自動的に測れたことにはなりません。まず遅い操作を所有するプロセスを特定し、そのプロセスの問題区間をCPU Usageで採取します。CPUのホットスポットが見つからなければ、Stopwatchなどを使ってI/O、別サービス、ロック、タイマーの待機時間を直接測るのが基本です。([Microsoft for Developers][1])
結論：プロセス、CPU、待ち時間の順に測る
.NET分散アプリの性能調査では、次の3段階に分けると原因を絞り込みやすくなります。
| 確認したいこと | 測るもの | 分かること |
|---|---|---|
| どのプロセスが遅い処理を担当しているか | プロセス別のCPU Usage、処理ログ | 測定対象が正しいか |
| 対象プロセスが計算処理で詰まっているか | CPUタイムライン、Call Tree、Functions | CPU負荷の高いメソッドがあるか |
| CPUを使わずに待っているか | 処理全体と待機箇所の経過時間 | I/O、別サービス、ロック、タイマー待機があるか |
重要なのは、CPU Usageだけで原因を最後まで特定しようとしないことです。CPU Usageが低いという結果は、「遅延が存在しない」という意味ではなく、選択したプロセスと時間範囲ではCPU計算が支配的ではなかったことを示します。([Microsoft for Developers][1])
AppHostを測るだけではWeb UIやバックエンドを測ったことにならない
.NET AspireのAppHostは、Web UI、バックエンド、データベース、外部連携用サービスなどをまとめて起動・管理します。しかし、それぞれのアプリケーションは通常、別プロセスとして動作します。
そのため、Sample.AppHostをプロファイリング対象にしても、Sample.WebやSample.Apiで実行されているコードのCPU負荷が自動的にAppHostのCall Treeへ表示されるわけではありません。Microsoftの公式事例でも、AppHostはオーケストレーターとして残し、実際にストリーミング処理を行っていたWeb UIを個別の測定対象にしています。([Microsoft for Developers][1])
典型的な分散アプリでは、1回のユーザー操作が次のように複数プロセスを通過します。
| 処理段階 | 主な候補プロセス | 確認する内容 |
|---|---|---|
| ボタン操作、入力内容の送信 | Web UI | イベント処理、シリアライズ、画面状態更新 |
| APIリクエストの処理 | バックエンド | 業務ロジック、データ変換、外部サービス呼び出し |
| AI応答やデータの生成 | エージェント、外部API | 応答開始までの時間、ストリーミング間隔 |
| データの保存・取得 | データサービス | クエリ、ネットワーク、接続待機 |
| ストリーミング結果の描画 | Web UI | 更新ループ、描画頻度、明示的な待機 |
「画面の表示が遅い」という症状だけでは、Web UIが遅いとは限りません。Web UIはバックエンドの応答を待っているだけかもしれず、反対にバックエンドは速く応答していても、Web UI側の更新処理が遅延を追加している可能性があります。
最初は複数プロセス、次に対象プロセスへ絞る
対応するVisual Studioでは、CPU Usageで複数プロセスのデータを収集し、タイムライン上でプロセス別に確認できます。Visual Studio 2022 version 17.13以降では、.NET Aspireのようなマルチプロセスアプリを分析するための複数プロセス収集が用意されています。([Microsoft Learn][2])
実務では、次の順番が効率的です。
- 複数プロセス収集で、どのプロセスが動いているかを大まかに確認する
- 遅い操作に関係するプロセスを絞る
- そのプロセスだけを対象に、短く焦点を絞った測定を行う
- CPUで説明できなければ、コード内の待機時間を直接測る
初回からAppHostだけを長時間採取するより、原因候補を絞り込んだうえで短い測定を繰り返す方が、Call Treeを読みやすくできます。
Visual Studio Performance ProfilerでCPU Usageを採取する手順
測定前に再現条件を決める
プロファイリングを始める前に、遅延を再現する操作を1つに絞ります。
たとえば、次のように具体化します。
- チャット画面でメッセージを送信してから、最後の応答が表示されるまで
- 検索ボタンを押してから、一覧の描画が完了するまで
- APIリクエストを送ってから、最初のストリーミング更新を受信するまで
- 最初の更新を受け取ってから、最終更新を描画するまで
「アプリ全体が遅い」という単位ではなく、開始と終了を決められる操作区間にします。
Release構成に切り替える
Visual Studioでソリューション構成をReleaseに切り替えます。
CPU UsageはDebug構成でも利用できますが、Microsoftのドキュメントでは、実際のアプリ性能を確認しやすい構成としてReleaseビルドが案内されています。Debug構成では最適化の違いやデバッガーの影響が加わるため、性能判断ではReleaseを基準にするのが適切です。([Microsoft Learn][2])
遅い処理を所有するプロジェクトを対象にする
たとえばWeb UIのストリーミング更新を調査する場合は、Web UIプロジェクトを測定対象にします。
バックエンドなどの依存サービスはAppHostで動かしたまま、測定対象のWeb UIだけをVisual Studioから個別に起動する方法があります。この場合、Aspire側で同じWeb UIが二重起動しないようにし、サービスディスカバリの接続先を実際に動作しているバックエンドへ向けます。
Aspireが割り当てるポートは再起動後に変わる場合があります。公式事例に掲載された固定ポートをそのままコピーせず、Aspireダッシュボードなどで現在のエンドポイントを確認してください。([Microsoft for Developers][1])
CPU Usageの収集を開始する
Visual Studioでは次の手順で採取します。
- 測定対象のプロジェクトと起動プロファイルを確認する
- ソリューション構成を
Releaseにする DebugからPerformance Profilerを開く- または
Alt+F2を押す - 対象プロセスまたはプロジェクトが正しいことを確認する
CPU Usageを選択する- 可能であれば、収集を一時停止した状態で開始する
- アプリの初期化が終わってから収集を再開する
- 問題の操作を実行する
- 操作が完了した時点で収集を停止する
CPU Usageには、起動時から収集せず、必要なタイミングで記録を開始するオプションがあります。これを利用すると、JITコンパイル、DIコンテナーの構築、初期画面の読み込みなど、今回の調査と関係しない処理を除外しやすくなります。([Microsoft for Developers][1])
CPUレポートはタイムラインから読む
収集が終わったら、最初にCPUタイムラインを確認します。
アプリ起動から終了までをまとめて分析するのではなく、ユーザーが操作を開始してから結果が完了するまでの範囲だけを選択します。選択範囲を絞ると、その時間帯に対応したCall TreeやFunctionsの値を確認できます。([Microsoft for Developers][1])
Call TreeでTotal CPUとSelf CPUを区別する
Call Treeでは、特に次の2列を確認します。
| 指標 | 意味 | 読み方 |
|---|---|---|
| Total CPU | そのメソッドと、配下で呼び出したメソッドを含むCPU時間 | 処理経路全体の負荷を追う |
| Self CPU | そのメソッド自身で消費したCPU時間 | メソッド本体が重いかを判断する |
たとえば、あるメソッドのTotal CPUが高く、Self CPUが低い場合、重い処理はそのメソッド自身ではなく、内部から呼び出している別のメソッドにある可能性があります。
反対にSelf CPUが高ければ、そのメソッド内のループ、変換処理、計算処理などがCPUを多く消費している可能性があります。([Microsoft for Developers][1])
Call Treeの実務的な確認手順
Call Treeでは次の順に確認します。
Just My Codeを有効にして、アプリケーションコードへ絞るExpand Hot PathでCPU負荷の高い呼び出し経路を展開する- 問題の操作に関係するメソッド名を検索する
- Total CPUとSelf CPUを比較する
- Functionsビューでも、Total CPUまたはSelf CPU順に並べ替える
CPU負荷の高い経路が見つかれば、その経路をさらに下へたどります。一方、問題のメソッドがCall Treeに存在していてもCPU値が小さい場合、処理時間の大半はCPU計算以外に使われている可能性があります。
非同期メソッドが見つからない場合
C#の非同期メソッドは、コンパイラーによってステートマシンへ変換されます。そのため、Call Tree上では想定した場所にメソッド名が表示されず、[External Code]配下などに現れる場合があります。
メソッド名による検索を使い、それでも見つからなければ、一時的に外部コードも表示して呼び出し経路を確認します。([Microsoft Learn][2])
CPU使用率が低くても処理が速いとは限らない
CPU Usageが低い場合、次のような時間はCPUのホットスポットとして目立たないことがあります。
| 待機の種類 | 具体例 | 次に測るもの |
|---|---|---|
| I/O待機 | HTTP、データベース、ファイル、外部API | 呼び出し前後の経過時間 |
| 別サービス待機 | Web UIがバックエンドの応答を待つ | 相手側プロセスのプロファイル |
| タイマー待機 | Task.Delay、定期更新 | 待機回数と累積待機時間 |
| 同期待機 | ロック、Semaphore、キュー待ち | 待機開始から取得までの時間 |
| ストリーム待機 | 次の更新データが届くまでのawait | 更新間隔、更新数、全体時間 |
Visual StudioのCPU Usageは、プロセッサーが実際にコードを実行していた時間を中心に示します。I/O、タイマー、ロック、別サービスの応答を待っている間は、利用者には遅く感じられても、CPUのホットパスには現れない場合があります。([Microsoft for Developers][1])
したがって、CPU値が低かった場合の次の質問は、「どのメソッドを高速化するか」ではなく、どこで経過時間を消費しているかです。
ストリーミング処理ではTask.Delayの累積を確認する
ストリーミング経路で特に注意したいのが、更新ループ内のTask.Delayです。
たとえば、更新を受信するたびに次の処理を実行しているとします。
await Task.Delay(50, cancellationToken);1回だけなら50ミリ秒ですが、200回の更新で実行されれば、公称値だけで次の待機が追加されます。
200回 × 50ミリ秒 = 10,000ミリ秒つまり、約10秒です。
この待機はCPUをほとんど消費しないため、CPU Usageのホットスポットだけを見ても原因として浮かびにくくなります。さらに、Task.Delay(50)は正確に50ミリ秒後の再開を保証するものではありません。スレッドのスケジューリングや他の処理により、実測値が50ミリ秒を上回る可能性があります。([Microsoft for Developers][1])
また、ストリーミングの「更新回数」とAIモデルの「トークン数」は同じとは限りません。ログには、トークン数ではなく、アプリが実際に処理した更新回数として記録する方が正確です。([Microsoft for Developers][1])
Stopwatchで全体時間と待機時間を分けて測る
CPUプロファイルで遅延を説明できない場合は、疑わしい待機箇所の前後をStopwatchで測ります。
次は、ストリーム全体の経過時間、更新回数、明示的な待機の累積時間を記録する例です。
using System.Diagnostics;
var totalWatch = Stopwatch.StartNew();
var accumulatedWait = TimeSpan.Zero;
var updateCount = 0;
await foreach (var update in client.ReadUpdatesAsync(cancellationToken))
{
updateCount++;
var waitStarted = Stopwatch.GetTimestamp();
await Task.Delay(50, cancellationToken);
accumulatedWait += Stopwatch.GetElapsedTime(waitStarted);
ApplyUpdate(update);
}
logger.LogInformation(
"ElapsedMs={ElapsedMs}, Updates={Updates}, ExplicitWaitMs={WaitMs}",
totalWatch.Elapsed.TotalMilliseconds,
updateCount,
accumulatedWait.TotalMilliseconds);このログから、次の3つを分けて判断できます。
- 処理全体に何ミリ秒かかったか
- ストリーミング更新が何回来たか
- 明示的な待機に合計何ミリ秒使ったか
全体時間だけでは、ネットワーク、外部サービス、モデル生成、描画、アプリ内の待機が混ざってしまいます。待機箇所を直接囲んだ累積値があれば、少なくとも、そのコードが追加した遅延を独立して確認できます。Microsoftの公式事例でも、CPUプロファイルだけでは説明できなかった待機を、更新ループ内のタイマー計測で切り分けています。([Microsoft for Developers][1])
I/O呼び出しも同じ考え方で測る
バックエンド呼び出しを待っている場合は、その前後を測ります。
var started = Stopwatch.GetTimestamp();
var response = await backendClient.GetResultAsync(
request,
cancellationToken);
var backendWait = Stopwatch.GetElapsedTime(started);
logger.LogInformation(
"BackendWaitMs={WaitMs}",
backendWait.TotalMilliseconds);この時間が長ければ、Web UI内部のCPU最適化よりも、バックエンド側のプロファイリングや、その先の外部サービス調査を優先します。
ただし、この測定値には通信時間と相手側の処理時間が含まれます。バックエンド内部のどの処理が遅いかまでは分からないため、次はバックエンドプロセスを測定対象にします。
CPU Usageの結果から次の調査へ進む判断基準
結果は次のように判断できます。
| 測定結果 | 考えられる状態 | 次の対応 |
|---|---|---|
| 特定メソッドのSelf CPUが高い | メソッド本体の計算が重い | ループ、変換、アルゴリズムを調査 |
| Total CPUが高くSelf CPUが低い | 呼び出し先が重い | Call Treeを下へ展開 |
| CPU全体が高いが自分のコードが少ない | ランタイムや外部ライブラリの可能性 | 外部コードを含めて確認 |
| CPUが低くホットパスがない | 非同期待機の可能性 | I/O、タイマー、ロック、別サービスを測る |
| 対象メソッドが表示されない | プロセスまたは区間が違う可能性 | 測定対象と選択範囲を再確認 |
| AppHostしか表示されない | 子アプリを測れていない可能性 | Web UIやバックエンドを個別に測る |
CPUが低いという結果だけで、原因をTask.Delayと断定することはできません。プロファイルが示すのは、「選択した区間ではCPU計算が支配的ではなかった」という範囲までです。
その後、実際のコード経路を確認し、明示的な待機や外部呼び出しを個別に測定して、初めて原因を裏付けられます。([Microsoft for Developers][1])
待機を削除するときは目的を確認する
ストリーミング更新ごとのTask.Delayには、画面の更新頻度を抑える目的があった可能性があります。
しかし、受信する更新ごとに固定時間待つ設計では、更新数が増えるほど遅延も直線的に増えます。
画面描画を抑制したい場合は、次の2つを分けて考えます。
- ストリームのデータはすぐに受信する
- UI描画だけを一定間隔にまとめる
たとえば、更新データを止めずに受け取り、画面の再描画だけを最大50ミリ秒に1回へまとめる設計が候補になります。ただし、50ミリ秒という値自体が最適とは限りません。更新頻度、描画コスト、操作感を基に、自分の環境で再測定する必要があります。
Microsoftの公式事例でも、描画をまとめる方式は改善候補として示されていますが、その方式自体の前後比較は未実施と明記されています。候補コードを導入しただけで改善したと判断せず、同じ条件で改めて測定してください。([Microsoft for Developers][1])
改修前後の比較で気を付けること
エンドツーエンド時間だけで判断しない
外部APIや生成AIモデルを含む分散アプリでは、同じ入力でも応答内容、更新回数、ネットワーク時間が変わることがあります。
そのため、改修前が80秒、改修後が70秒だったとしても、その10秒すべてがコード変更による改善とは限りません。
比較では次の値を分けます。
- ユーザー操作全体の経過時間
- 最初の応答までの時間
- ストリーム完了までの時間
- 更新回数
- 明示的な待機の累積時間
- 対象プロセスのCPU時間
全体時間は利用者体験を確認するために必要ですが、原因を切り分ける証拠としては、対象箇所を直接測った値の方が強くなります。公式事例でも、ライブモデルによる応答内容や更新回数の変動があるため、全体時間の差を管理されたベンチマークとして扱っていません。([Microsoft for Developers][1])
複数回測定する
最低でも同じ条件で複数回実行し、特定の1回だけを採用しないようにします。
特に次の条件は揃えます。
- 同じReleaseビルド
- 同じ入力データ
- 同じ起動方法
- 同じ接続先
- 同じ測定区間
- 同じログ項目
- ウォームアップの有無
- 初回だけ発生する処理を含めるかどうか
平均値だけでなく、中央値や更新回数も確認すると、外れ値に引っ張られにくくなります。
Visual Studioでの性能調査でよくある失敗
AppHostだけを測って調査を終える
AppHostのCPUが低くても、Web UIやバックエンドが別プロセスで動いていれば、その結果だけでは判断できません。
修正方法： 遅い操作を実行しているプロジェクトを特定し、そのプロセスを個別に測ります。
起動処理を含めたままCall Treeを見る
起動時のDI構築やJITなどが上位に表示され、ユーザー操作の処理が埋もれます。
修正方法： 収集を一時停止して開始し、アプリの準備が整ってから記録を再開します。収集後も問題区間だけをタイムラインで選択します。
CPU使用率が低いので問題なしと判断する
CPUを使わない待機でも、ユーザーは長時間待たされます。
修正方法： I/O、タイマー、ロック、別サービスの前後をStopwatchで測ります。
Total CPUが高いメソッドを直接書き換える
Total CPUには呼び出し先のCPU時間も含まれます。メソッド本体が原因とは限りません。
修正方法： Self CPUと比較し、Call Treeを下へたどります。
公式事例のポートや測定結果を転用する
Aspireのポート、CPU使用率、処理時間、更新回数は実行環境によって変わります。
修正方法： Aspireダッシュボードと自分の測定ログを基準にします。
1回の前後比較だけで改善率を出す
外部APIやAIモデルを含む処理では、実行ごとの変動があります。
修正方法： 複数回測定し、全体時間と直接測定した待機時間を分けて評価します。
調査時に使えるチェックリスト
- 遅い操作の開始地点と終了地点を決めた
- 操作が通過するプロセスを整理した
- AppHostだけでなく、Web UIやバックエンドも候補にした
- Release構成で測定した
- Visual Studioの測定対象を確認した
- アプリ初期化後に収集を開始した
- 問題の操作区間だけを選択した
- Total CPUとSelf CPUを区別した
- CPUホットパスがない場合は待機を疑った
Task.Delayなどの明示的な待機を検索した- 全体時間、更新回数、累積待機時間を分けて記録した
- 公式事例のポートや結果を自分の環境へ転用していない
- 改修後も同じ条件で再測定した
まず測定対象を直し、CPUで説明できなければ待ち時間を測る
.NET分散アプリが遅いのにCPU使用率が低い場合、最初にコードを最適化するのではなく、測定の順番を見直します。
まず、遅い処理を所有するプロセスを特定します。次に、そのプロセスをRelease構成でVisual Studio Performance ProfilerのCPU Usageへかけ、問題の操作区間だけを分析します。
Call TreeではTotal CPUとSelf CPUを区別し、CPUホットパスがなければ、I/O、別サービス、ロック、タイマーなどの待機へ調査対象を移します。ストリーミング経路にTask.Delayがある場合は、更新回数と累積待機時間を直接測ってください。
次に行うべき作業は、AppHostを漫然と再測定することではありません。遅い操作の経路を書き出し、Web UIまたはバックエンドのどちらがその処理を所有しているかを決め、対象プロセスの短いCPUプロファイルを採取することです。
[1]: https://devblogs.microsoft.com/visualstudio/today-i-will-find-hidden-latency-across-a-distributed-net-application/ “Today I will… find hidden latency across a distributed .NET application – Visual Studio Blog”
[2]: https://learn.microsoft.com/visualstudio/profiling/cpu-usage “CPU profiling in the Performance Profiler – Visual Studio (Windows) | Microsoft Learn”
コメント