事務複製會話 (四)

四、分發代理讀者執行緒延遲

與日誌讀取器一樣，分發代理也是有兩個會話同步進行。從分發伺服器到訂閱伺服器移動行的延遲在兩種會話中都可能會發生。讀者執行緒會話負責查詢分發資料庫，從而得到要應用到訂閱方的事務列表。它首先查詢訂閱資料庫的後設資料表，找到最後一次成功複製的事務。然後，讀者執行緒執行sp_Msget_repl_commands開始從分發資料庫讀資料行並將這些行遷移至記憶體中的佇列。當行進入佇列，分發代理寫者執行緒會話開始將這些行寫到訂閱伺服器。和日誌讀取器類似，新增分發代理 –OUTPUT引數，會得到對分發代理效能的一個很好的概覽。另外，最新版本的SQL Server會在分發代理歷史表Msdistribution_history中自動記錄這些資訊。

可能的原因：大批量的事務

延遲問題通常在一系列事務嘗試向訂閱方移動大批的命令時產生。下面的查詢顯示了在分發資料庫中命令的所有行數以及索引統計資料的資訊。

--ROW COUNTS

--尋找大的行數值（>1百萬），從而說明清除過程沒有在執行

--或者有大的待完成事務

SELECT name, rowcnt, STATS_DATE (id, indid) as 'Last Update Stats'

FROM distribution.dbo.sysindexes

WHERE name IN('ucMSrepl_transactions', 'ucMSrepl_commands')

行數是預期的值，還是包含了上百萬行？行數多（>1百萬）可能說明一個大的事務正在執行或者清除作業沒有在執行。

在進行延遲的效能故障排除時，按天計算命令的數量來檢視未處理的命令可能會發現有一些有幫助的模式。下面的語句可以查詢到儲存在分發資料庫中命令的拆分資訊。

--檢查臨時表中與那些事務數目相關的時間資訊

select t.publisher_database_id, t.xact_seqno,

max(t.entry_time) as EntryTime, count(c.xact_seqno) as CommandCount

into #results

FROM MSrepl_commands c with (nolock)

LEFT JOIN msrepl_transactions t with (nolock)

on t.publisher_database_id = c.publisher_database_id

and t.xact_seqno = c.xact_seqno

GROUP BY t.publisher_database_id, t.xact_seqno

--顯示每小時以及每天的命令數

SELECT publisher_database_id

,datepart(year, EntryTime) as Year

,datepart(month, EntryTime) as Month

,datepart(day, EntryTime) as Day

,datepart(hh, EntryTime) as Hour

--,datepart(mi, EntryTime) as Minute

,sum(CommandCount) as CommandCountPerTimeUnit

FROM #results

GROUP BY publisher_database_id

,datepart(year, EntryTime)

,datepart(month, EntryTime)

,datepart(day, EntryTime)

,datepart(hh, EntryTime)

--,datepart(mi, EntryTime)

--order by publisher_database_id, sum(CommandCount) Desc

ORDER BY publisher_database_id, Month, Day, Hour

在下面的輸出示例中，由於釋出表的大量更新，一大批的事務正在被複制，導致分發代理變慢。

publisher_database_id Year Month Day Hour CommandCountPerTimeUnit

------------------------------- --------- ---------- --------- ----------- ---------------------------------------

2 2009 5 14 10 132

2 2009 5 14 11 656

2 2009 5 14 12 880

2 2009 5 14 13 4379

2 2009 5 14 14 152

2 2009 5 14 15 1478

2 2009 5 14 20 161

2 2009 5 14 21 145

2 2009 5 15 6 1700

2 2009 5 15 7 3672

2 2009 5 15 8 6266

2 2009 5 15 9 329

2 2009 5 15 10 5678715

2 2009 5 15 11 5637959

2 2009 5 15 12 5281732

2 2009 5 15 13 5020950

2 2009 5 15 14 1252

2 2009 5 16 11 732

2 2009 5 16 12 178

2 2009 5 16 13 725

2 2009 5 16 14 186

2 2009 5 16 16 72

解決方法：

分發資料庫上的分發代理讀者執行緒對大批事務有很大的IO需求。快速的磁碟以及將事務日誌和資料庫檔案分別存放在不同的磁碟上會幫助改進IO效能。如果問題持續發生，請考慮釋出儲存過程執行而不是其結果行。

（關於在事務複製中釋出儲存過程執行，請參考：http://msdn.microsoft.com/zh-cn/library/ms152754(SQL.90).aspx）

故障排除讀者執行緒：當從分發資料庫中獲取行時，讀者執行緒中的分發代理可能出現延遲。建議先檢視代理歷史日誌或在-OUTPUT結果中檢視每五分鐘產生的代理統計資訊。

**************** STATISTICS SINCE AGENT STARTED ******************

03-22-2009 09:55:19

Total Run Time (ms) : 59189906 Total Work Time : 492741

Total Num Trans : 5 Num Trans/Sec : 0.01

Total Num Cmds : 5 Num Cmds/Sec : 0.01

Total Idle Time : 58660470

Writer Thread Stats

Total Number of Retries : 0

Time Spent on Exec : 0

Time Spent on Commits (ms): 16 Commits/Sec : 0.05

Time to Apply Cmds (ms) : 0 Cmds/Sec : 0.00

Time Cmd Queue Empty (ms) : 528717 Empty Q Waits > 10ms: 5

Total Time Request Blk(ms): 59189187

P2P Work Time (ms) : 0 P2P Cmds Skipped : 0

Reader Thread Stats

Calls to Retrieve Cmds : 11738

Time to Retrieve Cmds (ms) : 492741 Cmds/Sec : 0.01

Time Cmd Queue Full (ms) : 0 Full Q Waits > 10ms : 0

******************************************************************

以上資訊是取自分發代理日誌的-OUTPUT輸出，可以發現在代理停止工作之前，100%的時間都花在從分發資料庫讀取行的過程。

代理日誌同時記錄了事件完成的時間。在下面的例子中，從分發代理在訂閱方查詢待複製的開始事務，到它從分發資料庫獲取一個批的事務之間，分發代理查詢花掉了4分鐘的時間。這個延遲是由讀者執行緒等待分發資料庫返回命令導致的。

--分發代理-OUTPUT輸出顯示的讀者執行緒延遲示例

--後設資料訂閱讀操作完成

2009-05-16 01:26:49.229 OLE DB Distributor 'SQL380': {call sp_MSget_subscription_guid(11)}

--4分鐘後命令複製的讀操作完成

2009-05-16 01:29:31.401 sp_MSget_repl_commands timestamp value is: 0x0x0000081a00000045000400000000

--讀者執行緒等待分發資料庫返回命令

要測試讀的執行時間，我們可以執行sp_Msget_repl_commands，從而查詢阻塞、表掃描、超時等資訊。

從-OUTPUT輸出得到長時間執行的sp_Msget_repl_commands的LSN

2009-05-16 01:29:31.401 sp_MSget_repl_commands timestamp value is: 0x0x0000081a00000045000400000000

從同一個日誌中得到Agent_ID

在分發資料庫上執行sp_Msget_repl_commands查詢

sp_MSget_repl_commands @agent_id=11, @last_xact_seqno=0x0000081a00000045000400000000

該命令需要執行多久？有沒有被阻塞？是否有大量的命令要被返回？

我們也可以利用下面的語句，從訂閱端的資料庫獲得上一次成功執行的事務。Transaction_timestamp值包含了用於儲存過程sp_Msget_repl_commands的LSN值。

USE

--獲得上一個成功執行的事務

--每個釋出有多個行說明有並行的分發流。

SELECT publisher,publication, distribution_agent,transaction_timestamp

FROM dbo.MSreplication_subscriptions

要獲得更多細節資訊，使用下面的查詢檢查執行計劃：

USE distribution

GO

DBCC FREEPROCCACHE

DBCC DROPCLEANBUFFERS

SET STATISTICS PROFILE ON

SET STATISTICS IO ON

SET STATISTICS TIME ON

sp_MSget_repl_commands @agent_id=11, @last_xact_seqno=0x0000081a00000045000400000000

SET STATISTICS PROFILE OFF

SET STATISTICS IO OFF

SET STATISTICS TIME OFF

在SQL 2005/2008中，我們還可以從DMV中得到快取的執行計劃。

--dm_exec_query_stats for sp_MSget_repl_commands

-- by top total_worker_time

SELECT TOP 25

st.text, qp.query_plan,

(qs.total_logical_reads/qs.execution_count) as avg_logical_reads,

(qs.total_logical_writes/qs.execution_count) as avg_logical_writes,

(qs.total_physical_reads/qs.execution_count) as avg_phys_reads,

qs.*

FROM sys.dm_exec_query_stats as qs

CROSS APPLY sys.dm_exec_sql_text(qs.sql_handle) as st

CROSS APPLY sys.dm_exec_query_plan(qs.plan_handle) as qp

WHERE st.text like 'CREATE PROCEDURE sys.sp_MSget_repl_commands%'

ORDER BY qs.total_worker_time DESC

Go

可能原因：表統計資訊

當讀者執行緒執行時間長幷包含很多小批事務時，可能說明覆制系統表需要更新統計資訊。如果分發資料庫的AutoUpdateStatistics被禁用了，表統計資訊就可能會過期。

-- 檢視複製表的表統計資訊，尤其是'Updated'（被更新）的日期

DBCC SHOW_STATISTICS(MSrepl_commands,ucMSrepl_commands)

DBCC SHOW_STATISTICS(MSrepl_transactions,ucMSrepl_transactions)

-- 獲得分發資料庫的設定

-- 查詢IsAutoUpdateStatistics

sp_helpdb distribution

--或(返回 1表示IsAutoUpdateStatistics為“是”)

select DATABASEPROPERTYEX('distribution','IsAutoUpdateStatistics')

解決方法：

--更新複製表的統計資訊

UPDATE STATISTICS MSrepl_transactions

WITH FULLSCAN

UPDATE STATISTICS MSrepl_commands

WITH FULLSCAN

解決方法：

使用SQL內部工具，確定分發代理讀者執行緒在分發資料庫上沒有被阻塞。

來自 “ ITPUB部落格 ” ，連結：http://blog.itpub.net/25175503/viewspace-705827/，如需轉載，請註明出處，否則將追究法律責任。

事務複製會話 (四)

相關文章