SQL Server では、クエリの実行プランの情報を取得することが可能です。
実行プランからは、クエリを実行した際の各処理に関してのコストや、処理対象となった行数を確認することができますが、各処理にかかった時間については確認ができなかったかと。
SQL Server 2014 以降に SQL Server 2016 の Management Studio を使用すると、ライブクエリ統計でデータの流れや進捗を確認することができますが、ライブクエリ統計のデータが流れないケースがちょいちょいあるのですよね…。
いろいろと考えてみたのですが、sys.dm_exec_query_profiles を使用するのがよいのかなと。
この DMV はライブクエリ統計の情報が取得できるように設定されたクエリに関して、実行中のクエリのプロファイル情報を取得することができるものとなります。
# 実行が完了したクエリについては情報を取得することはできません。
以下の画像は、上記の DMV の内容を表示するツール (コーディングの勉強がてらに作った Zaiba2 を実行しています) を起動した状態で、「実際の実行プラン」を取得するようにして実行したクエリを裏で流した状態です。
実際の実行プランを取得するようにして実行したクエリであれば、紹介した DMV の「elapsed_time_ms」「cpu_time_ms」というような情報を取得することができます。
これにより、実行されているクエリの実行プランの各処理に関して、どれだけ経過時間や CPU 時間が発生したのかを確認することができます。
SQL Server 2016 SP1 がリリースされた際の情報として、「トレースフラグ 7412」による、軽量プロファイルを用いた情報の取得についての情報が公開されています。
Developers Choice: Query progress ? anytime, anywhere
「実際の実行プラン」を使用したクエリについては、各クエリに対して「SET STATISTICS XML ON」や「SET STATISTICS PROFILE ON」を有効にしたクエリの実行相当となっていますので、「情報を取得できるように設定されているクエリを実行」している必要があり、クエリの実行方法を意識する必要があります。
「トレースフラグ 7412」に関しては、トレースフラグを有効にした後に実行されたクエリに関して、プロファイル情報を自動的に取得することができるようになりますので、サーバー側の動作として情報の取得を制御することができます。
軽量プロファイルと、SET 句によるクエリ情報ですが、「sys.dm_exec_query_profiles」により、取得できる情報には差があります。
「SET 句」でクエリ情報をとれるようにしたクエリについては、DMV の情報がすべて取得されているようですが、トレースフラグに関しては、一部の情報の取得に抑えられているようです。
以下はトレースフラグを有効にして DMV から情報を取得したものとなりますが、「OpenTime」「CloseTime」「elapsed_time_ms」「cpu_time_ms」というような情報については取得できていないことが確認できます。
ざっと確認したところ、
- first_active_time
- last_active_time
- open_time
- first_row_time
- last_row_time
- close_time
- elapsed_time_ms
- cpu_time_ms
あたりの項目に関しては、完全なプロファイルの情報でないと取得はされていないようですね。
クエリを実行している最中に情報を取得する必要がありますが、処理に時間がかかっている箇所の特定をするための一つの方法として、「sys.dm_exec_query_profiles」の情報を使用して、処理時間を確認するというのは使うことはできそうですね。
上記の画像は SQL Server に対して取得したものですが、SQL Database に関しても「実際の実行ブラン」を取得するようにしたものは、プロファイル情報を取得することが可能でした。