SQL Server - 拡張イベントを使ってスロークエリを取得するクエリ

SQL Serverの拡張イベントを手っ取り早く試すにはこの記事が良いかなと思います。

この記事もわかりやすくSSMSのGUI自体もわかりやすいので、簡単に拡張イベントを使えるかなと思います。簡単に使えてしまうのですが、せっかくなのでクエリをそこそこ理解したいところ。今回はGUIを使わずにクエリだけで次のことを試します。

  • 拡張イベントのセッションを作成する
  • イベントをキャプチャする
  • キャプチャしたイベントを確認する

例としてはありがちですが、いわゆるスロークエリを取得してみます。順番に見ていきましょう。

拡張イベントのセッションを作成する

イベントをキャプチャするためにまずはセッションを作成します。

-- セッションを作成
create event session test_xes
    on server
    -- sql_batch_completedイベントをキャプチャする
    add event sqlserver.sql_batch_completed(
        -- duration(バッチが完了するまでの時間)が3秒以上のイベントにフィルタする
        where duration >= 3000000
    ),
    -- rpc_completedイベントをキャプチャする
    add event sqlserver.rpc_completed(
        where duration >= 3000000
    )
    -- イベントデータはring_buffer(メモリ)に出力する
    add target package0.ring_buffer;
  • add event句でキャプチャしたい「イベント」を指定します。このクエリではsql_batch_completedイベント・rpc_completedイベントの2つをキャプチャするようにしています。
  • where句は「述語」や「述語フィルタ」と呼ばれる部分です。クエリが完了するまでに3秒以上かかったイベントだけにフィルタをしています。
  • add target句でイベントデータの出力先である「ターゲット」を指定します。このクエリではリングバッファ(メモリ)を指定しています。

またイベントや述語、ターゲットなどは「パッケージ」に含まれています。このクエリのsqlserverpackage0がパッケージ名です。パッケージは名前空間やコンテナのようなイメージでいいのかなと思います。

参考

イベントをキャプチャする

セッションを開始します。キャプチャを開始するというか、監視を開始するというか。

-- セッション(キャプチャ)を開始
alter event session test_xes
    on server
    state = start;

-- ちなみに停止するには
/*
alter event session test_xes
   on server
   state = stop;
*/

セッションが開始されたので、イベントを発生させてキャプチャしたいと思います。そのために次のプログラムを実行します。sql_batch_completedイベントとrpc_completedイベントをキャプチャできるように、3秒以上かかるクエリを2つ実行するプログラムです。

class Program {
    private static readonly string _connectionString
        = new SqlConnectionStringBuilder {
            DataSource = ".",
            IntegratedSecurity = true,
        }.ToString();

    static void Main(string[] args) {
        using (var connection = new SqlConnection(_connectionString)) {
            // 3秒以上かかってsql_batch_completedイベントを発生
            var result1 = connection.Query<int>(
                "waitfor delay '00:00:03'; select 100;").First();
            Console.WriteLine(result1); // 結果に意味はない

            // 3秒以上かかってrpc_completedイベントを発生
            var result2 = connection.Query<int>(
                "waitfor delay '00:00:03'; select @p;",
                new { p = 99 }).First();
            Console.WriteLine(result2); // 結果に意味はない
        }
    }
}

これで2つのイベントがリングバッファに出力されているはずです。

キャプチャしたイベントを確認する

キャプチャしたイベントのイベントデータを確認します。

出力されたイベントデータは、SSMSだとオブジェクトエクスプローラから[管理]-[拡張イベント]-[セッション]-[対象のセッション]の対象ターゲットを選択して[ターゲットデータを表示]すると確認できます。今回の記事ではターゲットはpackage0.ring_bufferです。

ターゲットデータを表示すると次のようなxmlを確認できます。

<!-- イベントデータ:一部要素や属性を省略 -->
<RingBufferTarget>
  <event name="sql_batch_completed" package="sqlserver" timestamp="2017-08-11T03:54:22.422Z">
    <data name="duration">
      <type name="uint64" package="package0"></type>
      <value>3002521</value>
    </data>
    <data name="batch_text">
      <type name="unicode_string" package="package0"></type>
      <value><![CDATA[waitfor delay '00:00:03'; select 100;]]></value>
    </data>
  </event>
  <event name="rpc_completed" package="sqlserver" timestamp="2017-08-11T03:54:25.445Z">
    <data name="duration">
      <type name="uint64" package="package0"></type>
      <value>3001218</value>
    </data>
    <data name="statement">
      <type name="unicode_string" package="package0"></type>
      <value><![CDATA[exec sp_executesql N'waitfor delay ''00:00:03''; select @p;',N'@p int',@p=99]]></value>
    </data>
  </event>
</RingBufferTarget>

これをクエリで確認するには、次のようなクエリを実行します。

select
    cast(xe_st.target_data as xml)  -- データ(xml)
from sys.dm_xe_sessions as xe_s
    inner join sys.dm_xe_session_targets as xe_st
        on xe_s.address = xe_st.event_session_address
where xe_s.name = N'test_xes';

sys.dm_xe_sessionsを使ってアクティブな(=開始されている)セッションを特定できます。セッションが停止中は取得できません。sys.dm_xe_session_targetsを使ってセッションのターゲットを取得でき、target_dataカラムからイベントデータを取得できます。

ここまでくればあとはxmlデータ型のnodesメソッドやvalueメソッドを使って必要な情報を抜き出すだけです。上記クエリと組み合わせて、xmlデータから必要な情報を抜き出すクエリはこんな感じです。

with xe_e(data)
as(
    select
        cast(xe_st.target_data as xml)  -- データ(xml)
    from sys.dm_xe_sessions as xe_s
        inner join sys.dm_xe_session_targets as xe_st
            on xe_s.address = xe_st.event_session_address
    where xe_s.name = N'test_xes'
)
select
    node.value('@package', 'nvarchar(10)') as package,
    node.value('@name', 'nvarchar(20)') as event,
    node.value('@timestamp', 'datetime2') as timestamp,
    node.value('(data[@name="duration"]/value)[1]', 'bigint') as duration,
    node.value('(data[@name="batch_text"]/value)[1]', 'nvarchar(max)') as batch_text,
    node.value('(data[@name="statement"]/value)[1]', 'nvarchar(max)') as statement
from xe_e
    cross apply [data].nodes('/RingBufferTarget/event') as event(node);

-- 結果
/*
package    event                timestamp                   duration             batch_text                               statement
---------- -------------------- --------------------------- -------------------- ---------------------------------------- --------------------------------------------------------------------------------
sqlserver  sql_batch_completed  2017-08-11 03:54:22.4220000 3002521              waitfor delay '00:00:03'; select 100;    NULL
sqlserver  rpc_completed        2017-08-11 03:54:25.4450000 3001218              NULL                                     exec sp_executesql N'waitfor delay ''00:00:03''; select @p;',N'@p int',@p=99
*/

必要な情報を取得することができました。ただXQueryがよく分からないので手探りです。

参考