レプリケーション遅延に関するトラブルシューティング事例を一つご紹介します。
レプリケーションの遅延では、主にパブリッシャとディストリビュータ間の遅延と、ディストリビュータとサブスクライバ間の遅延とに原因が分類されます。
今回は、遅延は事前にディストリビュータとサブスクライバ間での何かが原因であることが、レプリケーションモニタから分かっていました。
1. サブスクライバ側でのレプリ適用に時間がかかっているクエリを抽出
レプリケーションは、内部的にはサブスクライバDBに対して各テーブルのレコード単位でのinsert/update/deleteの反映という形で行われます。
このストアドはレプリケーションが作成されると自動的に一緒に作成されます。(正確にはスナップショットレプリ適用時だった気もしますが、、)
名前はすべて[sp_MSins_dboテーブル名]のような構成になっているため、それらのストアドの実行時間を調査するために以下のクエリを実行します。
set transaction isolation level read uncommitted
select top 100 DB_NAME(qt.dbid) as database_name
--query text
,qt.text as parent_query
,SUBSTRING(qt.text, qs.statement_start_offset / 2, (case when qs.statement_end_offset = - 1 then LEN(CONVERT(nvarchar(MAX), qt.text)) * 2 else qs.statement_end_offset end - qs.statement_start_offset) / 2) as statement
-- average
,total_worker_time / qs.execution_count / 1000 as average_CPU_time_ms
,total_elapsed_time / qs.execution_count / 1000 as average_duration_ms
,total_physical_reads / qs.execution_count / 1000 as average_physical_reads
-- execution count
,qs.execution_count as execution_count
-- creation / execution time
,last_execution_time
,creation_time
-- total
,total_worker_time / 1000 as total_CPU_time_ms
,total_elapsed_time / 1000 as total_duration_ms
,total_physical_reads / 1000 as total_physical_reads
,qp.query_plan
from sys.dm_exec_query_stats qs
outer apply sys.dm_exec_sql_text(qs.sql_handle) as qt -- クエリテキスト用
outer apply sys.dm_exec_query_plan(plan_handle) as qp -- プランプラン用
where qt.text like '%sp_msins%' --insert
or qt.text like '%sp_msdel%' --delete
or qt.text like '%sp_msupd%' --update
order by average_duration_ms desc
2. 原因特定→対応を実施
今回は、特定のテーブルに対するsp_MSupd***ストアドプロシージャの実行時間が他のテーブルよりも大きくなっていることが確認できました。
このテーブルにはインデックスが多数張られており、それが原因で1レコードあたりの更新時間が長くなっていると想定しました。
そのため、該当テーブルのインデックスを削除できないか調査するため、以下のクエリを実行して各インデックスの使用状況をチェックしました。
DECLARE @TableName varchar(300)
set @TableName = 'テーブル名'
SELECT
o.name AS table_name
, i.name AS index_name
, s.user_seeks -- Index Seek 数
, s.user_scans -- Index Scan 数
, s.user_updates -- UPDATE 数
, s.user_lookups -- lookup 数
, last_user_seek
, last_user_scan
, last_user_lookup
, last_user_update
FROM
sys.objects o
INNER JOIN sys.indexes i
ON o.object_id = i.object_id
INNER JOIN sys.dm_db_index_usage_stats s
ON i.index_id = s.index_id
WHERE o.type = 'U'
AND database_id = DB_ID()
AND s.object_id = OBJECT_ID(@TableName)
AND o.name = @TableName
ORDER BY
s.user_seeks+s.user_scans desc
その結果、ほぼすべてのインデックスを使っていなかったため、未使用のインデックスを全てDROPしました。
これにより1レコードあたりの更新速度が上がり、結果的にレプリ速度が5倍ほど高速化されました。
最後に
レプリに関するトラブルシューティング事例を1つご紹介しました。レプリ遅延に関する原因は様々なものがあるので今回の調査手法が汎用的に使えるわけではありませんが、原因の1つとして、「大量更新+1レコードあたりのサブスクライバ側への適用速度が少しだけ遅い=大幅な遅延につながる」というのは頭に入れておくといいかもしれません。