トランザクションログを肥大化させているクエリの特定方法 [SQL Server]

トランザクションログファイル（.ldf）が意図せず肥大化するという現象が発生した場合、今後の対策を検討するため、どの処理（クエリ）が実行されたことに起因して、該当のトランザクションログファイル（.ldf）が肥大化したのかを特定したいと考える人が多いかと思います。

今回は、トランザクションログファイル（.ldf）が肥大化する要因となったクエリを特定する方法について紹介していきたいと思います。

トランザクションログファイル（.ldf）が肥大化する要因となったクエリを特定する方法として、様々な方法が存在しますが、「クエリストアを使用する方法」と、「トランザクションログが肥大化する現象が発生しているタイミングで情報を採取する方法」を紹介します。

クエリストアを使用する方法
トランザクションログが肥大化する現象が発生しているタイミングで情報を採取する方法
SQL Server トランザクションログ肥大化対策関連ブログ

クエリストアを使用する方法

クエリストアは、SQL Server 2016 以降に実装された機能で、自動的にクエリの実行統計情報を採取し、ユーザーデータベースの領域にデータを格納します。

そのため、今まで処理時間が短かったクエリが急に処理時間が長くなったなどの現象が発生した場合、クエリストアに格納された処理時間が短かった時のクエリの実行プラン、長くなった後のクエリの実行プランを比較することが可能となり、パフォーマンス低下などに伴うトラブルシューティングを簡素化することができます。

クエリストアの有効化、使用方法の詳細については、以下URLを参照

１) SQL Server Management Studio (SSMS) を起動して、該当のSQL Server インスタンスに接続します。

２) 該当ユーザーデータベース - クエリストア - 「リソースを消費するクエリの上位」を選択します。

f:id:nobtak:20200203003033p:plain

３) メトリック :「論理書き込み (KB)」､統計 :「最大」を選択します。

※ 統計 : ｢最大｣で論理書き込み (KB) の多いクエリを確認することが出来ない場合は、1回のクエリでの書き込み量は少ないが、大量に実行されていることで大量の書き込み量となっている場合もあるため、統計 :「合計」で確認すると良いかもしれません。

４) 最も「論理書き込み」が多い棒グラフ(今回の例ではクエリ id : 136) を選択し、クエリ内容を確認します。

f:id:nobtak:20200203004551p:plain

今回の例では、トランザクションログが肥大化する要因となったクエリは、「delete tab1｣というクエリであったと予測することができます。

なお、より正確にトランザクションログへの書き込み量を把握したい場合は、クエリストアで採取されたデータを直接参照可能なシステムカタログビュー query_store_runtime_stats で、クエリプランの中で使用されたデータベースログの使用量(バイト)を示す、max_log_bytes_used 列などの列を参照すると良いかと思います。

システムカタログビュー query_store_runtime_stats の詳細は、以下URLを参照

トランザクションログが肥大化する現象が発生しているタイミングで情報を採取する方法

クエリストア使用していない (使用することができない) 場合、もしくは、SQL Server 2014 以前の SQL Server を使用しているためクエリストアを使用できない場合、実際にトランザクションログが肥大化する現象が発生しているタイミングで情報を採取する必要があるため、本現象が発生する時間帯が特定できていない場合、情報の取得は少し難しいかもしれませんが、以下のようなクエリを実行することにより、トランザクションログが肥大化する要因となったクエリを特定できることが期待できます。

１)　SQL Server Management Studioを起動し、管理者権限(sysadmin)が付与されたログイン(saなど)でSQL Serverインスタンスに接続します。

２）「新しいクエリ」を選択します。

３）「クエリ」－「結果の出力」－「結果をファイルに出力」を選択します。

４）以下のクエリを実行し、情報の採取を開始します。

※ クエリ収集間隔は「WAITFOR DELAY '00:00:15'｣の部分を修正

USE master;
GO

SELECT GETDATE() as Date;
GO

SELECT @@version as Version;

SELECT
SERVERPROPERTY('ProductVersion') AS ProductVersion,
SERVERPROPERTY('ProductLevel') AS ProductLevel,
SERVERPROPERTY('Edition') AS Edition,
SERVERPROPERTY('EngineEdition') AS EngineEdition,
SERVERPROPERTY('ServerName') AS ServerName;
GO

PRINT '+++ サーバー構成オプション +++';
SELECT * FROM sys.configurations ORDER BY name;
GO

PRINT '+++ データベース情報 +++';
SELECT * FROM sys.databases;
SELECT * FROM sys.master_files;
GO

DECLARE @CursorDate datetime;

WHILE(1=1)
BEGIN
SET @CursorDate = GETDATE();

SELECT N'StartTime:',@CursorDate as Date;

-- 各トランザクションログファイルの使用量、使用率情報
PRINT '+++ DBCC SQLPERF(LOGSPACE) +++'
DBCC SQLPERF('LOGSPACE')
PRINT ''

-- 各トランザクションで使用されているログレコード数、ログの使用量(バイト) 情報
PRINT '+++ sys.dm_tran_database_transactions +++'
SELECT @CursorDate, tst.session_id, tdt.transaction_id, tdt.database_id, tdt.database_transaction_log_record_count, tdt.database_transaction_log_bytes_used, tdt.database_transaction_log_bytes_reserved, tdt.database_transaction_begin_time, tdt.database_transaction_type, tdt.database_transaction_state FROM sys.dm_tran_session_transactions tst
INNER JOIN sys.dm_tran_database_transactions tdt on tst.transaction_id = tdt.transaction_id
WHERE database_id > 4

PRINT '+++ sys.dm_exec_connections 情報 +++'
SELECT @CursorDate AS Date,* FROM sys.dm_exec_connections
WHERE session_id > 50
ORDER BY session_id;

PRINT '+++ sys.dm_exec_sessions 情報 +++'
SELECT @CursorDate AS Date,* FROM sys.dm_exec_sessions
WHERE session_id > 50
ORDER BY session_id;

PRINT '+++ sys.dm_exec_requests 情報 +++'
SELECT @CursorDate AS Date,* FROM sys.dm_exec_requests
WHERE session_id > 50
ORDER BY session_id;

-- キャッシュされているクエリ情報
PRINT '+++ キャッシュされているクエリ情報 +++'
SELECT @CursorDate as CurentDate, der.session_id, der.cpu_time, der.reads, der.writes, der.logical_reads, dst.text FROM sys.dm_exec_requests der
INNER JOIN sys.dm_exec_sessions des ON des.session_id = der.session_id
CROSS APPLY sys.dm_exec_sql_text(der.sql_handle) AS dst
WHERE der.session_id > 50

WAITFOR DELAY '00:00:15'

END

５）保存用ダイアログが開いた後、情報の出力先及びファイル名を指定します。

６）赤四角ボタン (クエリ実行の取り消し) をクリックし、情報採取を停止します。

特に、システムカタログビュー sys.dm_tran_database_transactions の出力結果がトランザクションログが肥大化する要因となったクエリを特定するうえで、有効な情報を得ることができると思います。

コマンド出力例

f:id:nobtak:20200203013307p:plain