前回、クエリ パフォーマンスが著しく低下した場合の一時的な対処方法について紹介しました。
今回は、SQL Server / Azure SQL Database の CPU使用率が長期間 100% を推移するという現象が発生した場合、SQL Server プロセスのどの処理で CPU時間が消費されているかを特定する方法について、自分の整理も兼ねて、まとめてみようと思います。
[対象]
SQL Server すべてのバージョン、エディション
Azure SQL Database
Azure SQL Managed Instance
SQL Server プロセスのどの処理で CPU時間が消費されているかを特定する方法
サーバー全体の CPU 使用率が 100% を長期間推移するという現象が発生し、CPU時間を消費しているプロセスが SQL Server プロセスである場合、SQL Server 標準で用意されている「システム動的管理ビュー」を使用することで、SQL Server プロセス内部のどの処理で CPU時間が消費されているかを特定することが可能になります。
以下に詳細な特定方法について記載してみようと思います。
1) SQL Server Management Studio (SSMS) を起動し、該当のインスタンスに対して、管理者権限が付与されたログインで接続します。
2) 「新しいクエリ」を選択します。
3) CPU時間を消費しているスレッドを確認する以下のクエリを実行します。
| select top 50 thr.*, wor.*, tas.*, req.* from sys.dm_os_threads thr inner join sys.dm_os_workers wor on thr.thread_address = wor.thread_address left outer join sys.dm_os_tasks tas on wor.task_address = tas.task_address left outer join sys.dm_exec_requests req on tas.session_id = req.session_id order by thr.usermode_time desc, thr.kernel_time desc |
※ 本クエリでは、SQL Server プロセス内のスレッドの中で、ユーザーモード時間 (アプリケーション (今回の場合は SQL Server プロセス) で使用された CPU時間)、カーネル時間 (OSのコア コンポーネントで使用された CPU時間) の上位 50 スレッドの情報を出力しています。
[クエリの実行例]
※ 本クエリの実行例では、スレッド : 0x0000016BB7B302E0 で、ユーザーモード時間(usermode_time)、カーネル時間 (kernel_time) が多く消費されていることが確認できます。本クエリでは、以下のシステム動的管理ビューを参照しており、セッション情報 (session_id)、コマンド情報 (command)、SQLハンドル情報 (sql_handle)、実行プランハンドル情報 (plan_handle) などの情報を確認し、問題となっているクエリの状態などを確認します。
4) CPU時間を消費しているスレッドで実行されているクエリ情報 (クエリの実行プラン)を確認する以下のクエリを実行します。
| select top 50 thr.thread_address, thr.kernel_time, thr.usermode_time, wor.worker_address, tas.task_address, tas.task_state, tas.session_id, req.start_time, req.command, req.sql_handle, req.plan_handle, req.database_id, req.cpu_time, req.reads, req.writes, req.logical_reads, sqlpl.query_plan from sys.dm_os_threads thr inner join sys.dm_os_workers wor on thr.thread_address = wor.thread_address left outer join sys.dm_os_tasks tas on wor.task_address = tas.task_address left outer join sys.dm_exec_requests req on tas.session_id = req.session_id cross apply sys.dm_exec_query_plan(req.plan_handle) sqlpl order by thr.usermode_time desc, thr.kernel_time desc |
※ 本クエリでは、SQL Server プロセス内のスレッドの中で、ユーザーモード時間 (アプリケーション (今回の場合は SQL Server プロセス) で使用された CPU時間)、カーネル時間 (OSのコア コンポーネントで使用された CPU時間) の上位 50 スレッドの情報および該当スレッドで実行されているクエリ情報 (クエリの実行プラン) を出力します。
[クエリの実行例]
※ クエリ情報 (query_plan) をクリックすることで、CPU時間を消費しているクエリ情報およびクエリの実行プラン情報を確認することができます。
※ 実行プラン情報の上にカーソルを移動し、右クリック -「実行プランに名前を付けて保存」を選択することで、該当クエリ情報をファイルに保存することができます。
5) 3)、4) で出力した情報をもとに、CPU時間を消費している処理の特定、および、原因調査を実施します。
BCP ユーティリティで情報を出力する方法
SQL Server プロセス内部のどの処理で CPU時間が消費されているかを特定するために実行したクエリ内容をファイルに出力する方法として、BCP ユーティリティを使用する方法があります。
[コマンド実行例]
1) CPU時間を消費しているスレッド情報を出力する場合
コマンド プロンプトから BCP コマンドを実行します。
| BCP "select top 50 thr.*, wor.*, tas.*, req.* from sys.dm_os_threads thr inner join sys.dm_os_workers wor on thr.thread_address = wor.thread_address left outer join sys.dm_os_tasks tas on wor.task_address = tas.task_address left outer join sys.dm_exec_requests req on tas.session_id = req.session_id order by thr.usermode_time desc, thr.kernel_time desc" QUERYOUT <出力先ファイル名> -S <インスタンス名> -T -w |
出力先ファイル名 : クエリ情報の出力先を指定
インスタンス名 : 該当インスタンスを指定
※ SQL Server 認証で該当のインスタンスに接続する場合は、「-U」、「-P」オプションを「-T」オプション (Windows 認証) の代わりに指定。
※ BCP ユーティリティの詳細なオプションについては、上記の公開情報を参照。
[例] インスタンス名：「SERVER01\INSTANCE01」、出力先ファイル名 :「c:\temp\queryout1.txt」の場合
| BCP "select top 50 thr.*, wor.*, tas.*, req.* from sys.dm_os_threads thr inner join sys.dm_os_workers wor on thr.thread_address = wor.thread_address left outer join sys.dm_os_tasks tas on wor.task_address = tas.task_address left outer join sys.dm_exec_requests req on tas.session_id = req.session_id order by thr.usermode_time desc, thr.kernel_time desc" QUERYOUT "c:\temp\queryout1.txt" -S SERVER01\INSTANCE01 -T -w |
2) CPU時間を消費しているスレッドで実行されているクエリ情報を出力する場合
コマンド プロンプトから BCP コマンドを実行します。
| BCP "select top 50 thr.thread_address, thr.kernel_time, thr.usermode_time, wor.worker_address, tas.task_address, tas.task_state, tas.session_id, req.start_time, req.command, req.sql_handle, req.plan_handle, req.database_id, req.cpu_time, req.reads, req.writes, req.logical_reads, sqlpl.query_plan from sys.dm_os_threads thr inner join sys.dm_os_workers wor on thr.thread_address = wor.thread_address left outer join sys.dm_os_tasks tas on wor.task_address = tas.task_address left outer join sys.dm_exec_requests req on tas.session_id = req.session_id cross apply sys.dm_exec_query_plan(req.plan_handle) sqlpl order by thr.usermode_time desc, thr.kernel_time desc" QUERYOUT <出力先ファイル名> -S <インスタンス名> -T -w |
[例] インスタンス名：「SERVER01\INSTANCE01」、出力先ファイル名 :「c:\temp\queryout2.txt」の場合
| BCP "select top 50 thr.thread_address, thr.kernel_time, thr.usermode_time, wor.worker_address, tas.task_address, tas.task_state, tas.session_id, req.start_time, req.command, req.sql_handle, req.plan_handle, req.database_id, req.cpu_time, req.reads, req.writes, req.logical_reads, sqlpl.query_plan from sys.dm_os_threads thr inner join sys.dm_os_workers wor on thr.thread_address = wor.thread_address left outer join sys.dm_os_tasks tas on wor.task_address = tas.task_address left outer join sys.dm_exec_requests req on tas.session_id = req.session_id cross apply sys.dm_exec_query_plan(req.plan_handle) sqlpl order by thr.usermode_time desc, thr.kernel_time desc" QUERYOUT "c:\temp\queryout2.txt" -S SERVER01\INSTANCE01 -T -w |
まとめ
今回は、SQL Server / Azure SQL Database の CPU使用率が 100% を推移するという現象が発生した場合、CPU時間がSQL Server プロセスのどの処理で消費されているかを特定する方法についてまとめてみました。
特定のクエリのみで CPU時間を多く消費している場合、クエリ ストア からでも CPU時間を多く消費しているクエリを特定することが可能になると思いますが、今回 紹介したクエリから情報を取得することで、より詳細に SQL Server プロセスで CPU時間が消費されている状況を把握することが可能になります。
なお、今回 紹介した手順は、実際に現象が発生している状況時に情報を採取する必要がありますが、現象が発生したらすぐに情報採取ができるように事前に準備する、もしくは、定期的にコマンドを実行し情報採取することを検討してもらうと良いかと思います。
