SQL Server のクエリの動作確認を実施していて、
- 自クエリが使用した CPU 時間等の取得
- 発生した待ち事象の取得
- 取得されたロック情報の取得
を確認したいと考えたことはないでしょうか？
拡張イベント (xEvent) と、DMV を活用することで、これらの情報を取得することができます。
SQL Server 2012 以降であればこの仕組みを使用することができるはずです。
「本番環境での利用」は一切考慮しておらず、「開発環境でクエリの動作を確認すること」を目的としていますので、実行する環境には注意してください。
本投稿のクエリは セッション単位のクエリ情報のアプローチ.sql を使用しています。
このクエリの中に、「– 情報を確認するクエリを以下に記載して実行」というブロックがありますので、この中に、実行したいクエリを入力して、バッチ全体を実行してください。
そうすると、次のような情報を取得することができます。
情報は 6 種類のセクションに分かれていて、次のような内容となっています。
- ① : 情報取得対象のクエリ実行結果
- ② : クエリで発生した CPU / 実行時間 / I/Oの情報
- ③ : クエリで使用した tempdb の情報
- ④ : クエリ内のステートメントの情報
- ⑤ : クエリで発生した待ち事象の情報
- ⑥ : クエリで取得されたロックの情報
① については、指定したクエリの実行結果ですので、これは重要ではありません。
②～⑥ が今回のクエリの仕組みで取得した情報となります。
Contents
DMV の情報の活用
② / ③ については、DMV の情報となります。
DMV については、sys.dm_exec_sessions / sys.dm_db_session_space_usage を使用しています。
DMV の中には「セッション単位の統計情報」を持っているものがあり、上記の 2 種類の DMV はそれに該当しています。
- sys.dm_exec_sessions : セッション単位の CPU / 実行時間 / I/O の使用状況の情報を格納
- sys.dm_db_session_space_usage : セッション単位の tempdb の使用状況の情報を格納
これらの情報は、セッションが存在している状態であれば、各種累計値を保持するようになっており、セッションが破棄されたタイミングでクリアされます。
そのため、外部から「特定のセッションの情報」を取得するのは難しいのですが「自セッションの情報」であれば、容易に取得することができます。
(「session_id = @@SPID」の情報を取得すればよいだけですので)
本クエリでは、次のように実行することで「クエリ実行時に発生した値」を算出しています。
- クエリ実行前の自セッションの情報を一時テーブルに格納
- クエリ実行
- クエリ実行後の自セッションの情報と一時テーブルに格納した情報の差を算出
これにより、クエリ実行時の情報の算出を行うことができます。
差分を出すための情報を一時的に tempdb に格納しているため、この部分のオーバーヘッドが発生していますが、誤差の範囲だと思います。
今回は使用していませんが、SQL Server 2016 以降であれば sys.dm_exec_session_wait_stats で、セッション単位の待ち事象の情報を取得することもできます。
実行するクエリの前後で情報を取得して差分を出すというアプローチは、汎用的に利用できるものですので、DMV の活用方法として覚えておくと便利かと。
拡張イベントの情報の活用
④～⑥ については、DMV で取得することが難しいので 拡張イベント を活用しています。
詳細については、クエリを読んでいただくとわかるのですが、次のような処理を実行しています。
- 動的な文字列生成により、拡張イベントを設定するためのクエリを生成
- 拡張イベントで出力されたファイルの情報を読み込み一時テーブルに格納
- 一時テーブルに XML インデックスを設定し、クエリの実行効率を上昇させる
- 拡張イベントの情報の XML をパースしながら必要な情報を抽出
拡張イベントの中では何種類かのイベントをキャッチするように設定をしているのですが「全てのセッションの情報」を取得してしまうと、ノイズとなる情報が多すぎてデータの分析が困難になります。
そのため、拡張イベントを作成する際には、「自セッションの情報に限定する」というようなフィルターを設定してあげる必要があります。
これを実現するために、最初に自セッションのセッション ID を含むように文字列連結で、拡張イベントを設定するためのクエリを生成して実行しています。
拡張イベントの情報は SQL Server のログディレクトリに「query_analyze_xxxx」というファイルを出力して実施しており、実行ごとにファイルを生成していますので、不要になったら削除してください。
(ring_buffer で作ってもよかったのですが、情報の解析の手間がかかるので拡張イベントのターゲットについてはファイルターゲットとしています。)
拡張イベントの情報は T-SQL のクエリ実行で解析することができるのですが、そのままの状態で解析をすると、効率が悪く、解析に時間がかかります。
拡張イベントのイベントデータは XML 形式になっていますので、XML インデックスを付与して、解析しやすい状態にしています。
あとは、XML インデックス付きの一時テーブルに対してクエリを実行して必要な情報を抜き出します。
④ の情報は、指定したステートメントの情報を解析したものとなります。
上記の例では、「SELECT * FROM REGION OPTION(RECOMPILE)」しか実行していないため、わかりずらいかもしれませんが、実行するクエリを次のように 2 つのステートメントにするとわかりやすいかと。
SELECT * FROM REGION SELECT * FROM REGION OPTION(RECOMPILE)
最初の「SET @start = (SELECT GETDATE())」は、「メッセージ」に出力している次のような処理時間の算出用ですので、この行は無視してください。
2 行目以降が実行したステートメント単位の情報となります。
複数のステートメントで構成されているクエリについては、各ステートメント単位で情報が出力されますので、クエリ全体 (バッチ全体) で、どのステートメントで時間がかかっているのか / リソースを消費しているのかという情報を確認することができます。
不足インデックスのアドバイスがあった場合は、その情報を出力するようにしていますので、インデックスのアドバイス情報を抽出することもできるようになっています。
⑤ の情報はセッションで発生した待ち事象の情報を拡張イベントで取得したものになります。
DMV で紹介した、 sys.dm_exec_session_wait_stats が使えるバージョンであれば拡張イベントで実装しなくても、DMV だけで対応できるのですが、今回、2012 以降で動作するようにしておきたかったので、拡張イベントの情報を利用しています。
「クエリで発生した待ち事象」が把握できると「クエリチューニングのポイント」が見えてきますので、クエリの実行効率の改善には有効な項目となります。
⑥ の情報は「クエリで取得されたロックの情報 (ロックの要求と解放)」となります。
通常のクエリであればどのようなロックが取得されているか判断しやすいですが、運用系のクエリですとどのようなロックが取得されたかの判断が難しいケースがあります。
例えば「統計情報の更新」を実行した際にどのようなロックが取得されているかを把握できているでしょうか？
今回のクエリの仕組みを利用すると「統計情報の更新を実行した場合に取得されたロック」についても取得できます。
実行するクエリを次のように設定してみます。
取得されたロックの情報には次のような情報が含まれています。
対象のテーブルに対して、「OBJECT:X」のロックをかけていることが確認できますね。
このほかにも統計情報のメタデータに対して、「SCH_M」のロックがかかっていることが確認できます。
このような情報が取得できると、かなり強力な情報となるケースがあります。
SELECT * FROM NATION WHERE N_NATIONKEY = '1'
このクエリを実行したときには、次のようなロックが取得されています。
かなりシンプルなロックの取得ですね。
では、クエリを次のように変更してみるとどうでしょう。
SELECT * FROM NATION WHERE N_NATIONKEY = '1' OPTION (RECOMPILE)
この結果は一部のみとなっているのですが、「クエリのコンパイル」が発生した場合は、先ほどとは異なるロックの取得状況となっていることが確認できます。
- 統計情報の更新では統計情報に対して「SCH_M」のロックが取得されている
- リコンパイルを伴うクエリ実行で使用された統計情報に対して「SCH_S」のロックが取得されている
ということがこの情報から確認できます。
ロックの互換性については データベース エンジンのロック で確認することができます。
上述の「SCH_M」と「SCH_S」については互換性がなく競合するロックですので、これらのロックが同タイミングで発生した場合にはブロッキングによる処理遅延が発生することになります。
これにより、
- 統計情報の更新中は、統計情報に対して「SCH_M」が発生しているため、コンパイルを伴うクエリが実行された場合に該当の統計情報を取得するために必要となる「SCH_S」がブロッキングされ、統計情報の更新はクエリの同時実行性を低下させる一因となりえる可能性がある
ということを判断することができます。
(「統計情報の自動更新」が発生した場合に、コンパイルが発生したクエリの同時実行性の低下を抑えるために「統計情報の自動更新の非同期更新」というようなオプションを使用することもできます)
今回は直近で必要な情報のみに絞って取得を行っていますが、拡張イベント / DMV には様々な情報がありますので、今回使用しなかった情報を組み合わせることで、いろいろな状態を取得することができます。
「自セッションの情報をフィルターして情報を取得する」というアプローチは活用できるとかなり強力なものとなりますので、今回紹介した方法以外でも、自分なりの情報取得方法というものを持っているとよいのではないでしょうか。