SE の雑記

SQL Server の情報をメインに Microsoft 製品の勉強内容を日々投稿

拡張イベントでスロークエリログを取得

leave a comment

プロファイラや SQL トレースでも取得はできるのですが、今後のメイン機能となると思う拡張イベントを使用してスロークエリログを取得する方法を。

拡張イベント自体は SQL Server 2008 以降で使用することができます。
SQL Server 拡張イベント

今回は SQL Server 2008 R2 と SQL Server 2012 で拡張イベントを設定する方法を。
バージョンによって設定の方法が少し異なるため両方載せてみました。

SQL Server 2008 R2

SQL Server 2008 R2 の場合は、GUI による拡張イベントの設定ができないため、クエリベースで管理する必要があります。

以下は実行に 3 秒以上かかったクエリをログに出力するための拡張イベントとなります。
# duration の指定はマイクロ秒になります。

CREATE EVENT 
SESSION [SlowQueryLog] ON SERVER
ADD EVENT sqlserver.sql_statement_completed
(ACTION(sqlserver.database_id,sqlserver.sql_text)
WHERE([duration]>=3000000))
ADD TARGET package0.asynchronous_file_target
(SET 
filename=N'C:temp2008R2SlowQueryLog.xel'
,max_file_size=(250)
,max_rollover_files=(10)
,metadatafile=N'C:temp2008R2SlowQueryLog.xem')
WITH (STARTUP_STATE=OFF)
GO

ALTER EVENT SESSION [SlowQueryLog] 
ON SERVER
STATE=START

/*
ALTER EVENT SESSION [SlowQueryLog] 
ON SERVER
STATE=STOP

DROP EVENT SESSION [SlowQueryLog]
ON SERVER
*/

 

STARTUP_STATE=OFF で設定しており、必要に応じて手動で有効にしています。

# STATUP_STATE=ON にしておくと自動で開始されます。

拡張イベントを開始すると、指定したフォルダにファイルが取得されます。

image

SQL Server 2012 であれば、GUI で取得した内容を確認できるのですが、2008 R2 の場合は sys.fn_xe_file_target_read_file  経由で確認する必要があります。

SELECT * FROM sys.fn_xe_file_target_read_file('C:temp2008R2SlowQueryLog*.xel', 'C:temp2008R2SlowQueryLog*.xem', null, null)

image

これだと少しわかりにくいので、以下のようなクエリで取得するとよいかと思います。

DECLARE @file nvarchar(max) = N'C:temp2008R2SlowQueryLog*.xel'
DECLARE @metafile nvarchar(max) = N'C:temp2008R2SlowQueryLog*.xem'

SELECT
DATEADD(hour,9 , CAST(event_data as XML).value('(/event/@timestamp)[1]', 'datetime')) AS timestamp,
CAST(event_data as XML).value('(/event/action[@name="database_id"]/value)[1]', 'sysname') AS database_id,
DB_NAME(CAST(event_data as XML).value('(/event/action[@name="database_id"]/value)[1]', 'sysname')) AS database_name,
CAST(event_data as XML).value('(/event/action[@name="sql_text"]/value)[1]', 'nvarchar(max)') AS sql_text,
CAST(event_data as XML).value('(/event/data[@name="duration"]/value)[1]', 'bigint') AS duration,
CAST(event_data as XML).value('(/event/data[@name="cpu"]/value)[1]', 'bigint') AS cpu_time, 
*
FROM 
sys.fn_xe_file_target_read_file(@file, @metafile, NULL, NULL)
ORDER BY
CAST(event_data as XML).value('(/event/data[@name="duration"]/value)[1]', 'bigint') DESC

実行すると以下のような結果を取得することができます。

image

 

なお、使用できるイベントやアクションについては以下のクエリで確認ができます。

SELECT xo.* 
FROM sys.dm_xe_objects xo
INNER JOIN sys.dm_xe_packages xp
ON xo.package_guid = xp.guid
AND xp.name = 'sqlserver'
WHERE xo.object_type = 'event'
ORDER BY xo.name asc


SELECT xo.* 
FROM sys.dm_xe_objects xo
INNER JOIN sys.dm_xe_packages xp
ON xo.package_guid = xp.guid
AND xp.name = 'sqlserver'
WHERE xo.object_type = 'action'
ORDER BY xo.name asc

 

SQL Server 2012

SQL Server 2012 であれば、SSMS から GUI ベースで設定することができます。

image

設定した内容はスクリプトボタンからスクリプトとして出力ができますので、複数のサーバーに設定したい場合にはスクリプト化するとよいかと思います。

SQL Server 2012 の拡張イベントではステートメント単位ではなく、バッチ単位で情報を取得することができます。

CREATE EVENT SESSION [SlowQueryLog] 
ON SERVER 
ADD EVENT sqlserver.sql_batch_completed
(SET collect_batch_text=(1)
    ACTION(sqlserver.database_id,sqlserver.database_name)
    WHERE ([duration]>=(3000000))) 
ADD TARGET 
package0.event_file
(SET 
filename=N'C:temp2012SlowQueryLog.xel'
,max_file_size=(250)
,max_rollover_files=(10))
WITH (STARTUP_STATE=OFF)
GO

ALTER EVENT SESSION [SlowQueryLog] 
ON SERVER
STATE=START

/*
ALTER EVENT SESSION [SlowQueryLog] 
ON SERVER
STATE=STOP

DROP EVENT SESSION [SlowQueryLog]
ON SERVER
*/

SQL Server 2012 の SSMS であれば、ファイルを開くから拡張イベントのファイルを開くことができますので、GUI から取得した内容を確認することができます。

imageimage

クエリで取得する場合は以下のようになります。

DECLARE @file nvarchar(max) = N'C:temp2012SlowQueryLog*.xel'
DECLARE @metafile nvarchar(max) = N'C:temp2012SlowQueryLog*.xem'

SELECT
DATEADD(hour,9 , CAST(event_data as XML).value('(/event/@timestamp)[1]', 'datetime')) AS timestamp,
CAST(event_data as XML).value('(/event/action[@name="database_id"]/value)[1]', 'sysname') AS database_id,
DB_NAME(CAST(event_data as XML).value('(/event/action[@name="database_id"]/value)[1]', 'sysname')) AS database_name,
CAST(event_data as XML).value('(/event/data[@name="batch_text"]/value)[1]', 'nvarchar(max)') AS batch_textt,
CAST(event_data as XML).value('(/event/data[@name="duration"]/value)[1]', 'bigint') AS duration,
CAST(event_data as XML).value('(/event/data[@name="cpu_time"]/value)[1]', 'bigint') AS cpu_time, 
*
FROM 
sys.fn_xe_file_target_read_file(@file, @metafile, NULL, NULL)
ORDER BY
CAST(event_data as XML).value('(/event/data[@name="duration"]/value)[1]', 'bigint') DESC

クエリの改善には実行時間の大きいクエリに対してアプローチをするのが一般的な手法かと思います。

スロークエリログを定期的に確認し改善をすることでクエリに対しての負荷を減らすことができるかと。

Written by masayuki.ozawa

2月 5th, 2014 at 1:03 pm

Posted in SQL Server

Tagged with

Leave a Reply

*