SQL Server: 拡張イベントを使ってクエリベースでブロッキング発生状況を後追いする


背景

こちらの記事で、拡張イベントを使ってブロッキングを後追いできる仕組みの整え方をご紹介しました。

後追いの方法がGUIベース、もしくはシンプルなクエリベースでの方法だけを紹介していたため、本記事ではクエリベースでより便利に後追いする方法をご紹介します。

クエリ

githubにてクエリを公開しています。

クエリのポイントとしては、生データだと解釈が最初は難しいため、みやすく加工している点です。

適宜編集する必要のある個所だけ説明します。

SET TRANSACTION ISOLATION LEVEL READ UNCOMMITTED

DECLARE @xe_filename nvarchar(255) = N'blocked_process_and_deadlock_report*.xel' --modify here
DECLARE @begin_time datetime
DECLARE @end_time datetime
set @begin_time = '2020/08/20 07:50:00' --modify here
set @end_time = '2020/08/20 08:10:00' --modify here

ファイル名

@xe_filenameには、拡張イベントのイベントを保存しているファイル名を指定します。
ファイル名の確認は、拡張イベントの該当セッションを右クリックしてプロパティを開き、「データストレージ」ページにて確認できます。(赤枠内)
フルパスで書かれている場合はフルパスで書いた方が良かった気がします(うろ覚えですみません)
ワイルドカード「」と拡張子「.xel」も含めましょう。ファイル名+「.xel」でOKです。

時間帯

@begin_time/@end_timeをそれぞれ指定します。
拡張イベントのtimestampはutcなのですが、クエリ内で+9時間で変換しているため、普通に日本時間で絞り込みたい時間帯を指定してもらえればOKです。

取得結果例

指定した時間帯でブロッキングが発生していると、以下のようなレコードセットが取得できます。

右にスクロールしていくと以下のようなカラムを確認できます。
各ブロッキングレポート(=各レコード)で確認すべきは、ざっくりいうと「どのクエリが、どのクエリにブロックされていたか」となります。

①blocking_waitresource

ブロッキングしているプロセスが、何らかの要因で待っている場合は、ここにresourceの情報が表示されます。たとえばブロッキングツリーが形成されていて、blockingなクエリもほかのクエリにブロックされている場合なとです。

②blocking_spid

ブロッキングしてるクエリのセッションIDです。

③blocking_query

ブロッキングしているクエリです。ストアドプロシージャ名またはSQLで表示されます。

④waitresource

ブロックされているプロセスがどのリソースにロックをかけたくて待たされているかが表示されます。
具体的な後追いの方法はここでは割愛します。

⑤blocked_spid

ブロックされているクエリのセッションIDです。

⑥blocked_query

ブロックされているクエリです。ストアドプロシージャ名またはSQLで表示されます。

⑦event_data

元の拡張イベントのデータです。フルフルで詳細に確認したい場合はこちらをクリックして生データを確認できます。

ざっくりとした見方

「⑤blocked_queryが、③blocking_queryにブロックされていた」という解釈ができます。
また、該当時間帯で大量にブロッキングが発生している場合は、ブロッキングの大本「head blocker」を特定する必要したい場合があると思います。

その場合は、「該当時間帯で一番最初にブロッキングのレポートが上がったレコード」をチェックすると、そのレコードにおけるblocking_queryが「head blocker」である可能性が高いです。

まとめ

ブロッキングの情報を拡張イベントからクエリベースで後追いする方法をご紹介しました。
少なくとも、該当時間帯でブロッキングが発生していたかを後追いすることは簡単にできると思います。
また、head blockerの特定についても慣れてくれば今回の方法を使ってできるようになるかと思います。