妙用跟踪令牌定位事务复制的延迟问题
我们知道，事务复制是将数据从发布服务器传到分发服务器然后复制到订阅服务器的过程 - 数据流几乎是实时地进行这些步骤。当有问题产生而造成流程中断，就会出现数据复制延迟。我们经常碰到的难题和关键是定位到哪一步是整个延迟的原因。从SQL2005开始支持的跟踪令牌功能，可以帮助我们轻松确定延迟问题是出现在1）从发布服务器到分发服务器，还是2）从分发服务器到订阅服务器。
跟踪令牌
跟踪令牌是一种特殊的时间戳事务，可以从复制监视器或运行T-SQL语句插入，它会被写到发布数据库的事务日志中并被日志读取代理获取。之后被分发代理读取并写到订阅服务器。每一步的时间戳都被记录到分发数据库的跟踪表中并显示在复制监视器或通过T-SQL语句获得。见下图：
在SQL Server Management Studio中，右击Replication（复制），然后选择Launch Replication Monitor（启动复制监视器）。
在复制监视器中，选择事务复制发布，然后打开Tracer Tokens页面。点击Insert Tracer插入新令牌。在插入跟踪令牌之后，复制监视器显示“Pending…”。
当日志读取代理获取令牌后，它会在分发数据库的Mstracer_token系统表中记录时间 – 通过计算插入令牌和日志读取代理获得令牌的时间差，来获得Publisher到Distributor的时间；然后分发代理获取令牌和并在分发数据库的Mstracer_history系统表中记录写入订阅方的时间 - 通过计算日志读取代理获得令牌和分发代理获取令牌并写入订阅方的时间差，来获得Distributor到Subscriber的时间。
跟踪令牌示例
在这个示例中，延迟大约持续了6秒，其中订阅方的写入只有1-2秒，但跟踪令牌却用了5秒将它们从发布服务器复制到分发服务器。因而，此示例中的事务延迟的关键显然应从日志读取代理开始而非分发代理。
再来看另一个例子，令牌复制到分发服务器用了3秒，但是到订阅服务器#1用了1秒，到订阅服务器#2用了4秒。尽管日志读取代理不像想象中那么快，但改进到订阅服务器#2的延迟将可以减少至少一半的整体延迟。
查看跟踪令牌的T-SQL命令
接着，我们再来看看如何使用T-SQL命令来使用和查看跟踪令牌。sp_posttracertoken可以用来发起一个跟踪令牌 - 该指令可以在SQL Server Management Studio中执行，或者创建一个SQL代理作业并以一个固定的时间间隔发布跟踪令牌。
--Tracer Token in the publication database 在发布数据库中执行：
USE [AdventureWorks]
Go
DECLARE @publication AS sysname
DECLARE @tokenID AS int
SET @publication = N'Portal'
-- Insert a new tracer token in the publication database.
EXEC sys.sp_posttracertoken
@publication = @publication,
@tracer_token_id = @tokenID OUTPUT
然后，通过查看下面的两张系统表来确认每一步的复制延迟如何：
--Token Tracking Tables
USE Distribution
Go
--publisher_commit
SELECT Top 20 * FROM MStracer_tokens Order by tracer_id desc
--subscriber_commit
SELECT Top 20 * FROM MStracer_history Order by parent_tracer_id desc
案例分析
1. “发布服务器到分发服务器”（日志读取代理）仍旧显示“Pending”
跟踪令牌系统表中的“Null”或者复制监视器中的“Pending”状态，说明日志读取代理没有在运行，或者事务日志中存在太多日志读取代理尚未复制的事务，而日志读取代理无法及时读取跟踪令牌。因此，我们首先要确认日志读取代理正在运行并且日志读取代理历史记录中没有错误。
打开复制监视器并选择代理页面，很明显，我们可以看到日志读取代理没在运行。”Last Action”的信息显示日志读取代理没有执行错误，只是被停止了。
右击日志读取代理（Log Reader Agent），选择View Details（查看细节）。代理运行的统计数据和遇到的错误将被显示在Details中。注意，Stop Agent（停止代理）是灰的，Start Agent（开启代理）是可选的 – 这也能再次确认日志读取代理正处于停止的状态。从这个菜单上，还可以查看代理Profile（Agent Profile）以及自定义日志读取代理的命令行属性。
我们也可以通过查看MSlogreader_history表得到日志读取代理最新历史更新记录进行交叉确认。如果你有多个发布，可以使用WHERE语句来指定agent_id。
--Check Log Reader Agents Table for correct Agent_id
SELECT id, publisher_db
FROM distribution.dbo.MSlogreader_agents
id publisher_db
----------- ---------------------------------------------
1 AdventureWorksLT
--Check Agent History Table for last updates
SELECT top 10 agent_id, start_time,comments
FROM distribution.dbo.MSlogreader_history
ORDER BY time desc
agent_id start_time comments
----------- ----------------------- ---------------------------------------------
1 2010-03-07 12:46:21.503 The process was successfully stopped.
1 2010-03-07 12:46:21.503 No replicated transactions are available.
日志读取代理延迟
就象前面提到的一样，如果看到NULL，这说明日志读取代理尚未读到已发布数据库事务日志中的跟踪令牌。如果我们已经确认日志读取代理确实正在运行，并且没有遇到错误，但是跟踪令牌没有被获得，这就说明日志读取代理出现了延迟，我们需要进一步查看并排除故障。
--publisher_commit
SELECT Top 20 * FROM MStracer_tokens Order by tracer_id desc
tracer_id publication_id publisher_commit distributor_commit
----------- -------------- ----------------------- -----------------------
-2147483431 1 2010-03-10 20:08:00.400 NULL
2. 订阅方离线
如下图所示，即使没有跟踪令牌，也可以看到，分发代理或者是被停止，或者是订阅服务器长时间离线。下一步是：1）确认分发代理在运行；2）检查复制监视器中代理历史记录是否有任何错误；3）确认订阅方运行良好，可以被连接。
订阅方延迟
跟踪令牌表可以帮助查看订阅方延迟。下面的语句显示了跟踪令牌的端到端时间戳。为了看得更清楚，可以将脚本及其输出粘贴到SQL Server Management Studio中。
1. 日志读取代理延迟输出示例以及到某订阅方的分发代理延迟输出示例
--End to End time
SELECT publication_id, agent_id,
t.publisher_commit, t.distributor_commit, h.subscriber_commit
FROM MStracer_tokens t
JOIN MStracer_history h
ON t.tracer_id = h.parent_tracer_id
ORDER BY t.publisher_commit DESC
--Historical Breakdown (in seconds)
SELECT publication_id 'PubID', agent_id 'AgentID',convert(smalldatetime,t.publisher_commit) 'PubCommit',
convert(smalldatetime,t.distributor_commit) 'DistCommit',
convert(smalldatetime,h.subscriber_commit) 'SubCommit',
Datediff(s,t.publisher_commit,t.distributor_commit) as 'Dist(sec)',
Datediff(s,t.distributor_commit,h.subscriber_commit) as 'Sub(sec)'
FROM MStracer_tokens t
JOIN MStracer_history h
ON t.tracer_id = h.parent_tracer_id
ORDER BY t.publisher_commit DESC
/*
--Slow LogReader 日志读取代理延迟输出示例
PubID AgentID PubCommit DistCommit SubCommit Dist(sec) Sub(sec)
----------- ----------- ----------------------- ----------------------- ----------------------- ----------- -----------
1 3 2010-02-25 20:38:00 2010-02-25 20:53:00 2010-02-25 20:54:00 902 5
1 4 2010-02-25 20:38:00 2010-02-25 20:53:00 2010-02-25 20:54:00 902 7
1 3 2010-02-25 20:46:00 2010-02-25 20:53:00 2010-02-25 20:54:00 427 5
1 4 2010-02-25 20:46:00 2010-02-25 20:53:00 2010-02-25 20:54:00 427 7
1 3 2010-02-25 20:46:00 2010-02-25 20:53:00 2010-02-25 20:54:00 425 5
1 4 2010-02-25 20:46:00 2010-02-25 20:53:00 2010-02-25 20:54:00 425 7
--Slow Distributor on 1 subscriber 到某订阅方的分发代理延迟输出示例
PubID AgentID PubCommit DistCommit SubCommit Dist(sec) Sub(sec)
----------- ----------- ----------------------- ----------------------- ----------------------- ----------- -----------
1 3 2010-03-04 17:10:00 2010-03-04 17:10:00 2010-03-04 17:11:00 1 42
1 4 2010-03-04 17:10:00 2010-03-04 17:10:00 2010-03-04 17:11:00 1 4
1 3 2010-03-04 17:28:00 2010-03-04 17:28:00 2010-03-04 17:29:00 6 36
1 4 2010-03-04 17:28:00 2010-03-04 17:28:00 2010-03-04 17:28:00 6 3
1 3 2010-03-04 17:30:00 2010-03-04 17:30:00 2010-03-04 17:31:00 5 33
1 4 2010-03-04 17:30:00 2010-03-04 17:30:00 2010-03-04 17:30:00 5 2
*/
2. 根据不同的分发代理输出示例
--By Agent_id
SELECT publication_id 'PubID', agent_id 'AgentID',convert(smalldatetime,t.publisher_commit) 'PubCommit',
convert(smalldatetime,t.distributor_commit) 'DistCommit',
convert(smalldatetime,h.subscriber_commit) 'SubCommit',
Datediff(s,t.publisher_commit,t.distributor_commit) as 'Dist(sec)',
Datediff(s,t.distributor_commit,h.subscriber_commit) as 'Sub(sec)'
FROM MStracer_tokens t
JOIN MStracer_history h
ON t.tracer_id = h.parent_tracer_id
ORDER BY agent_id,t.publisher_commit DESC
/*
PubID AgentID PubCommit DistCommit SubCommit Dist(sec) Sub(sec)
----------- ----------- ----------------------- ----------------------- ----------------------- ----------- -----------
1 3 2010-03-03 09:38:00 2010-03-03 09:38:00 2010-03-03 09:38:00 2 3
1 3 2010-03-03 09:39:00 2010-03-03 09:39:00 2010-03-03 09:39:00 5 3
1 3 2010-03-04 16:43:00 2010-03-04 16:43:00 2010-03-04 16:43:00 3 1
1 3 2010-03-04 17:10:00 2010-03-04 17:10:00 2010-03-04 17:11:00 1 42
1 3 2010-03-04 17:28:00 2010-03-04 17:28:00 2010-03-04 17:29:00 6 36
1 3 2010-03-04 17:30:00 2010-03-04 17:30:00 2010-03-04 17:31:00 5 33
1 3 2010-03-04 17:32:00 2010-03-04 17:32:00 2010-03-04 17:33:00 2 36
*/
3. 输出最大分发代理延迟示例
---Find worst performing subscribers.
SELECT
convert(varchar(10),agent_id) as 'agent id',
max(Datediff(s,distributor_commit,subscriber_commit)) as 'MAXTime To Sub (sec)',
avg(Datediff(s,distributor_commit,subscriber_commit)) as 'AVG Time To Sub (sec)'
FROM MStracer_tokens t
JOIN MStracer_history h
ON t.tracer_id = h.parent_tracer_id
group by agent_id
order by 2 desc
/*
agent id MAXTime To Sub (sec) AVG Time To Sub (sec)
---------- -------------------- ---------------------
3 57391 21372
4 286 9
*/
--再由得到的AgentID=3来获得更多复制的相关信息
SELECT id, name, publisher_db, publication
FROM distribution.dbo.MSdistribution_agents
/*
id name publisher_db publication
----- --------------------------------------------- --------------------- ------------
3 CHRISSKACER-AdventureWorksLT-TranProducts-CH AdventureWorksLT TranProducts
4 CHRISSKACER-AdventureWorksLT-TranProducts-CH AdventureWorksLT TranProducts
*/
隔离与解决
通过以上所述步骤和方法定位了延迟的来源，可以让我们集中到真正的问题上。跟踪令牌就是帮助我们可以很快将事务复制延迟问题隔离到日志读取代理延迟，还是分发代理延迟的手段。对它的灵活应用可以让我们事半功倍。关于更多日志读取代理和分发服务代理故障排除的步骤，请继续关注我们后续更多关于复制的博文。