事物复制的troubleshooting 1

 

本文大量照抄了Transactional Replication Conversations

 

 

 

上图是一个事物复制的拓扑. 大致可以把这个流程分为3步

1. logReader Agent从publicationDB的日志文件中读取需要复制的日志信息
2. logReader Agent将读取的信息写入到distributor的distribution库中
3. distribution Agent将distribution库中的数据写入到subscriber

 

三个阶段都可能出现性能问题. 先使用tracertoken进行定位，找到是哪一部出现问题

 

如果是发布到分发的问题

在logreader agent的作业里添加output参数,输出具体的信息. 方法见参见’How to enable replication agents for logging to output files in SQL Server’

和 Using “Verbose history agent profile.” while troubleshooting Replication

一个示例:-Publisher [TESTDB1] -PublisherDB [pub] -Distributor [TESTDB2] -DistributorSecurityMode 1  -Continuous  -Output C:\sqldata\logreader.txt -Outputverboselevel 2

 

下面是文本输出的部分信息.

******************** STATISTICS SINCE AGENT STARTED ***************************
06-01-2011 15:28:36

Execution time (ms): 633551
Work time (ms): 633348
Distribute Repl Cmds Time(ms): 620035
Fetch time(ms): 658458
Repldone time(ms): 60429
Write time(ms): 273870
   Num Trans: 667500  Num Trans/Sec: 1053.922962
   Num Cmds: 3076294  Num Cmds/Sec: 4857.193833
*******************************************************************************

在分析这段统计信息之前先介绍一下发布到分发传输数据的大致步骤:

1 发布库数据被更新/插入/删除,产生事务日志(这其中包含需要进行复制的日志记录和不需要进行日志记录的事物)

2 LogReader agent去读取日志信息:

i.    读取LogReader profile里的配置信息,按照这些信息的配置参数去工作.(代理重启时会执行这个操作,然后将信息存储起来,直到下次代理重启才会再次执行). 例如每次读取多少记录,多长时间读取一次.详细信息查看Agent的profile信息
ii.    sp_replcmds命令读取事务日志, 这是一个sp_replcmds调用的示例: exec sp_replcmds 1000,0,-1,0x,5023,0,500000 .其中第一个参数1000为ReadBatchSize. [在发布端执行]
iii.    sp_MSadd_repl_commands去处理sp_replcmds得到的日志信息,将这些信息转化后插入distribution库[在分发端执行]
iv.    sp_repldone对日志记录进行标记(之后这些日志记录就允许被截断了,并且避免被再次读取..), 也就是那些已经在distribution端处理的记录.[在发布端执行]

 

Execution time:从logreader agent开始运行之后的总时间

Work time:除去Ideal后的Execution time, 是刨去PollingInterval的时间。另外，如果代理程序处于Idle状态（例如没有事务需要发布，都不会算作Work Time）

. 如果复制出现延迟,并且Work time和Execution Time有明显差距,则可能需要调整pollinginterval和ReadBatchSize

Distribute Repl Cmds Time:从publisher上读取出需要复制的事务的信息、写入缓存并写入到distribution库中所持续的总时间

Fetch time: 读取事物日志的时间,对应前面的ii

Repldone time: sp_repldone花费的时间,对应iv

Write time:将读取到的信息写入distribution花费的时间.对应iii

分析

 

一般来说，消耗时间的步骤就是ii和iii

第ii步是发布端执行,造成延迟的原因可能如下:

1. 执行了一些操作,这些操作产生的大量的不需要被复制的日志记录(例如rebuild index). logreader在读取时候需要进行筛选,大量的非复制性日志会延长时间.

在非高峰时间运行rebuild index, 或者将恢复模式切换成BULK_LOGGED

下面的语句返回发布库中需要复制的数据和非复制数据

Use <published database>
GO
-- Total records in the log
SELECT count(*) FROM ::fn_dblog(NULL, NULL)
GO
-- Records marked for REPLICATION
SELECT count(*) FROM ::fn_dblog(NULL, NULL) WHERE Description='REPLICATE'

2. 一个事务里的命令操作了很多行数据,产生了大量的日志

避免这种情况,将大事物拆分成小的事物分批执行.

考虑使用Publishing Stored Procedure Execution in Transactional Replication

调整MaxCmdsInTran。 缺点：如果发布库事务回滚，会导致发布服务器和分发服务器数据不一致。 参考Replication Log Reader Agent

可以使用下面的语句查看

在发布服务器执行

select [database],begin_lsn,commit_lsn,rows,cmds_in_tran from sys.dm_repl_traninfo 

或者在分发库执行

select xact_seqno, count(*) as [count] into #MSrepl_commands from dbo.MSrepl_commands

group by xact_seqno

having count(*)>100

select t.xact_seqno,t.entry_time,c.[count] from MSrepl_Transactions t inner join

#MSrepl_commands c on t.xact_seqno=c.xact_seqno

order by c.count desc,t.entry_time

3. 小而多的VLF

       过的的VLF会影响日志读取速度, 造成这种情况的原因多是日志的FILEGROWTH 过小(例如1mb)并且日志频繁的自动扩张. 解决方法:日志文件压缩,然后一次性扩张到预期的大小. 通过dbcc loginfo返回当前数据库的VLF信息. <1000是可以接受的

4. 日志磁盘存在IO压力. 如果发布数据库的压力,会影响读取速度. 解决方法:将文件存放在更高性能的磁盘上.通过performance monitor进行监控Avg. Disk Sec/Read和Avg. Disk Sec/Write,请参考Troubleshooting Performance Problems in SQL Server 2008

5. Logreader配置错误。例如ReadBatchSize设置过小或PollingInterval设置过大

6. 网络原因。 发布服务器和分发服务器之间存在网络瓶颈。检查两个服务器的Performance monitor的Network Interface output queue length.理想情况应当低于2

 

 

第iii部是分发端执行,造成延迟的原因可能如下:

 

1 不良的复制结构：同一个对象被多个发布所（n个）包含，这样在msrepl_commands和MSrepl_transationcs会产生n倍的对象，导致插入时间增长。在发布库执行以下语句，返回被多次发布的对象:

    select objid,count(*) from sysarticles group by objid having(count(*)>1) order by COUNT(*) desc 

2 阻塞：插入作业和清除作业之间形成阻塞. 解决方法：在非高峰时间运行清除作业，不过这样会导致distribution agent运行效率降低
3 IO压力：distribution的日志盘存在io压力，导致写入缓慢。参见上文
     2,3还可以通过 SQL SERVER 2005/8 Performance Dashboard Reports查看

SQLSERVER PROFILER收集logreader相关的命令

SELECT duration, starttime, endtime, textdata

FROM ::fn_trace_gettable('C:\DISTRIBUTOR_sp_trace.trc', DEFAULT)

WHERE TEXTDATA LIKE '%SP_MSadd_replcmds%' AND EVENTCLASS=10 

Or

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 sp_MSadd_replcmds%'

ORDER BY qs.total_worker_time DESC

 

如果是分发到订阅的问题…