現在の SQL Server では、軽量クエリプロファイリングが提供されており、様々なアプローチで「実行中のクエリの実際の実行プラン」を取得する方法が提供されています。
本機能は SQL Server 2014 SP2 / SQL Server 2016 から実装が行われ、Azure SQL Database / SQL Server 2019 以降では既定で有効になっています。
この機能を活用することで、冒頭に記載した「実行中のクエリの実際の実行プラン」を取得することができます。
クエリ内のパラメーターがすべてクエリに記載されているアドホックなクエリであれば、キャッシュから「実行に時間がかかったクエリで指定されたパラメーター」を確認することができる可能性が高いです。
しかし、SQL Server では実行プランの自動パラメーター化で、一部のアドホッククエリが自動的にパラメーター化されることや、アプリケーション側でパラメーター化されたクエリで実行されることが多々あります。
「実行プランが生成されたコンパイル時に指定されたパラメーター」については、キャッシュされている実行プランから追うことができますが、「時間がかかっているクエリ実行のタイミングで指定されていた実行時のパラメーター」についてはキャッシュから取得することはできません。
「実行時に指定されたパラメーターを含む実行プラン」の取得については、冒頭で紹介した軽量なクエリプロファイリングを活用することで取得することができます。
軽量クエリプロファイリング v2 を使用した情報の取得
SQL Server 2016 で SP1 で追加された軽量クエリプロファイリング v2 を使用することで、インスタンスに対しての負荷を可能な限り抑えた状態で実際の実行プランを取得することが可能ですが、v2 では、情報を取得する際には次のような対応が必要となります。
- グロバルトレースフラグ 7412 を設定
- クエリの実行中に、該当セッションの sys.dm_exec_query_statistics_xml を参照
- 実際の実行プランを取得を有効化にして、実行プランを取得したいクエリを実行
- クエリの実行中に、該当セッションの sys.dm_exec_query_statistics_xml を参照
- 「 OPTION(USE HINT(‘QUERY_PLAN_PROFILE ‘))」を指定してクエリを実行
- クエリの実行中に、該当セッションの sys.dm_exec_query_statistics_xml を参照
- 拡張イベントの「query_plan_profile」でロギング
SQL Server 2019 で実装された、v3 になると初期状態から「query_post_execution_plan_profile」という拡張イベントでロギングができるようになります。
しかし、それより前のバージョンの v2 ではロギングをするためには、自前で sys.dm_exec_query_statistics_xml を定期的に参照しロギングをするか、クエリにヒント句を追加して拡張イベントでロギングをするというような対応をする必要があります。
サーバーを操作することができる場所にデータベースの操作に明るい人がいれば対応をすることもできると思いますが、リモートでの支援となると v2 の機能を使用して特定のクエリの実際の実行プランの取得を依頼するのは難しいのではないでしょうか。
情報取得のオーバーヘッドを許容してレガシーな拡張イベントで実際の実行プランの取得を行う
SQL Server 2016 で、実際の実行プランをロギングしたい場合は、上述の内容の「3.」による取得を依頼するのが、リモートでの支援では最も容易な方法となるかと思います。
しかし、この方法で情報を取得するためには、クエリにヒント句を追加する必要があるため、該当のクエリが実行されているアプリケーション側に手を入れてヒント句の追加を行う必要があります。
ヒント句の追加は情報取得のための一時的な設定となるケースが多く、このためにアプリケーションに手を入れるのは、実施の難易度が高いケースもあるのではないでしょうか？
そのような場合は、レガシーな拡張イベントである「query_post_execution_showplan」を使用した情報取得を検討することができます。
このイベントのオーバーヘッドについては、次の情報で確認ができます。
今回ターゲットとしている SQL Server は SQL Server 2016 SP1 以降としているため、イベントを有効化することで 14.3% 程度、処理のオーバーヘッドが発生することになります。
実際の拡張イベントの説明が以下の画像となるのですが、取得時のオーバーヘッドについては説明にも記載されています。
本来は軽量なクエリプロファイリング v2 で取得する方法を検討したほうが良いのですが、SQL Server 2016 での取得については、SQL Server の基本 / 柔軟な情報取得を構築できるスキルが必要となるため、リモートで「これを実行して情報を取得してください」というような方法で対応をするためには、レガシーなイベントに頼らざるを得ないかと思います。
実際に情報を取得してみる
今回は次のようなクエリについて情報の取得を行ってみます。
-- 1 EXEC sp_executesql N'select count(*) from LINEITEM where L_ORDERKEY >= @p1', N'@p1 int', @p1 = 120000000 GO -- 2 EXEC sp_executesql N'select count(*) from LINEITEM where L_ORDERKEY >= @p1', N'@p1 int', @p1 = 1 GO
パラメーター化されたクエリのベースとなるテキストは同じなのですが、指定されたパラメーターによって大きく実行時間に差が出ます。
「1」については小量のデータ取得となり、すぐに実行が終了するのですが「2」については、大量のデータ取得となるため、実行に時間がかかります。
実運用でもも内になるのは「2」の実行パターンとなるのではないでしょうか。
単純に拡張イベントを設定してしまうと全クエリが取得対象となるため、取得するクエリについてはフィルターを行います。
(フィルターはロギングとして出力する情報の削減に使用しますが、情報取得の最初のアクションについては、全セッションで発生させないといけないため、フィルターを設定しても負荷の軽減にはつながりません)
取得のためのフィルターには、クエリハッシュを使用することができます。
拡張イベントを取得する際のクエリハッシュの指定については、次のような設定を行います。
- クエリハッシュを bigint に変換する
- 上記のハッシュであれば、「SELECT CAST(0x9571145756CBE9C2 as bigint)」で算出
- 算出したクエリハッシュを「query_hash_signed」のフィルターとして設定する
これで該当のクエリ情報のみ情報をログに出力することができるようになります。本投稿でのサンプルは次のようになります。
CREATE EVENT SESSION [Monitor_Query_Plan] ON SERVER
ADD EVENT sqlserver.query_post_execution_showplan(
ACTION(sqlserver.query_hash,sqlserver.query_hash_signed,sqlserver.query_plan_hash,sqlserver.query_plan_hash_signed,sqlserver.sql_text)
WHERE ([sqlserver].[query_hash_signed]=(-7678333524339070526.)))
ADD TARGET package0.ring_buffer(SET max_memory=(25600))
WITH (MAX_MEMORY=4096 KB,EVENT_RETENTION_MODE=ALLOW_MULTIPLE_EVENT_LOSS,MAX_DISPATCH_LATENCY=5 SECONDS,MAX_EVENT_SIZE=0 KB,MEMORY_PARTITION_MODE=NONE,TRACK_CAUSALITY=OFF,STARTUP_STATE=OFF)
GO
実際に情報を取得したものが次になりますが、特定のクエリについての情報のみ取得されています。
取得したログの中には「showplan_xml」が含まれており、この情報の中には ParameterList があり、コンパイル時のパラメーター (ParameterCompiledValue) と実行時のパラメーター (ParameterRuntimeValue) を確認することができます。
情報取得のオーバーヘッドは発生してしまいますが、この方法であれば拡張イベントのクエリを連携することで情報の取得を依頼することでリモートで情報の取得を依頼する場合も、容易の対応することができるのではないでしょうか。