title: SQLServer · CASE分析 · 镜像状态异常排查
author: 天铭
问题
用户实例的某个DB一直处于Synchronizing无法达到SYNCHRONIZED状态,用了很多修复方法并且进行了镜像重搭,但依旧没有达到正常同步态
排查
Synchronizing态通常和redo queue或者send queue有关
主库的问题DB当前的TPS在3K左右
begin tran
DECLARE @value int
DECLARE @value2 int
select @value=CONVERT(int,cntr_value) from sys.dm_os_performance_counters
where object_name like '****:database%%'and instance_name='businesscard' and counter_name like 'Transactions/ sec%%'
waitfor delay '00:00:01'
select @value2=CONVERT(int,cntr_value) from sys.dm_os_performance_counters
where object_name like '****:database%%'and instance_name='businesscard' and counter_name like 'Transactions/ sec%%'
select @value2-@value
commit tran
主库的发送队列
begin tran
DECLARE @value int
DECLARE @value2 int
select @value=CONVERT(int,cntr_value) from sys.dm_os_performance_counters
where counter_name = 'Log Send Queue KB' and instance_name='businesscard';
waitfor delay '00:00:01'
select @value2=CONVERT(int,cntr_value) from sys.dm_os_performance_counters
where counter_name = 'Log Send Queue KB' and instance_name='businesscard';
select @value*1./1024 as first_second_MB,@value2*1./1024 as second_second_MB,(@value2-@value)*1./1024 as diff_MB
commit tran
备库的应用队列
begin tran
DECLARE @value int
DECLARE @value2 int
select @value=CONVERT(int,cntr_value) from sys.dm_os_performance_counters
where counter_name = 'Redo Queue KB' and instance_name='businesscard'
waitfor delay '00:00:01'
select @value2=CONVERT(int,cntr_value) from sys.dm_os_performance_counters
where counter_name = 'Redo Queue KB' and instance_name='businesscard';
select @value*1./1024 as first_second_MB,@value2*1./1024 as second_second_MB,(@value2-@value)*1./1024 as diff_MB
commit tran
备库的应用速度大概在 14MB
begin tran
DECLARE @value bigint
DECLARE @value2 bigint
select @value=CONVERT(bigint,cntr_value)*1./1024/1024 from sys.dm_os_performance_counters
where counter_name = 'Redo Bytes/sec' and instance_name='businesscard';
waitfor delay '00:00:01'
select @value2=CONVERT(bigint,cntr_value)*1./1024/1024 from sys.dm_os_performance_counters
where counter_name = 'Redo Bytes/sec' and instance_name='businesscard';
select (@value2-@value) as speed_MB
commit tran
假设忽略主库新产生的日志,追上主库需要的时间 32min
select 27338.278320/14/60 =32.545569428566
如果再算上主库新产生的大概在40min左右
查看其它counter值
select cntr_value,* from sys.dm_os_performance_counters
where counter_name in(
'Log Send Flow Control Time (ms)','Bytes Sent/sec','Log Bytes Sent/sec',
'Log Compressed Bytes Sent/sec','Log Harden Time (ms)','Log Send Flow Control Time (ms)',
'Log Send Queue KB','Mirrored Write Transactions/sec','Pages Sent/sec',
'Send/Receive Ack Time','Sends/sec','Transaction Delay' )
and instance_name='businesscard';
Send/Receive Ack Time:
Milliseconds that messages waited for acknowledgement from the partner, in the last second.
This counter is helpful in troubleshooting a problem that might be caused by a network bottleneck, such as unexplained failovers, a large send queue, or high transaction latency. In such cases, you can analyze the value of this counter to determine whether the network is causing the problem.
开始怀疑问题在网络上,该主机某个网络组建已经升级了,但是备机的组件未升级
等待确认的时间稳定在800ms左右,对比主备网络组件都升级的主机在100ms左右,这个值跟事务大小有关,目前发现有问题的地方可能是这里
begin tran
DECLARE @value bigint
DECLARE @value2 bigint
select @value=CONVERT(bigint,cntr_value) from sys.dm_os_performance_counters
where counter_name = 'Send/Receive Ack Time' and instance_name='_Total';
waitfor delay '00:00:01'
select @value2=CONVERT(bigint,cntr_value) from sys.dm_os_performance_counters
where counter_name = 'Send/Receive Ack Time' and instance_name='_Total';
select (@value2-@value) as 'Send/Receive Ack Time'
commit tran
另外查看errorlog,时有告警镜像的状态应该是介于suspended和SYNCHRONIZING之间,错误类似KB,2008r2 应该已经修复。
半小时后发送队列又变大了
备库的应用队列减小的也非常慢
考虑单点时间过久,只能重搭解决,但重搭后追日志还是出现此问题,怀疑可能有坏页或者其它未知情况,计划在维护时间做checkdb。
--- ---
checkdb发现没有坏页,说明数据是ok的,那么问题可能在日志了。
select log_reuse_wait,log_reuse_wait_desc,* from sys.databases where name='businesscard'
log_reuse_wait_desc 为 ACTIVE_TRANSACTION
ACTIVE_TRANSACTION:事务处于活动状态。
一个长时间运行的事务可能存在于日志备份的开头。在这种情况下,可能需要进行另一个日志备份才能释放空间。
事务被延迟(仅适用于 SQL Server 2005 Enterprise Edition 及更高版本)。“延迟的事务”是有效的活动事务,因为某些资源不可用,其回滚受阻。
dbcc opentran('businesscard')
15号的事务今天19号,导致中间的日志全是活动日志无法截断,跟用户确认kill掉后,再次查看活动日志
dbcc opentran('businesscard')
发现结果一直在变化,可以理解为活动日志一直在往前走(越来越少),再次备份后活动日志恢复到7G左右,重搭成功。
事实上这是很早以前处理的一个CASE,当时排查了很久才找到root cause但现在看来问题其实很简单,希望大家下次遇到可以很快处理好