SQL Server Always On延迟观测和预警
一、介绍
延迟是AlwaysON的最大敌人之一。对AlwaysON而言，其首要目标就尽量减少（无法避免）主副本、辅助副本的数据延迟，实现主副本、辅助副本的“数据同步”。只有主副本、辅助副本的同步延迟越小越高，只读访问的实性性才会越高，数据库的RTO（Estimating Failover Time ）和RPO（Estimating Potential Data Loss）也才会越小。
但延迟可能存在于AlwaysON同步的各个环节中，因此，在分析现延迟情况时，应该首先理解AlwaysON的同步过程，然后切分到每个过程中进行监控和分析。
二、AlwaysON同步的6大步骤
在我的上篇文章《AlwaysON的同步原理及同步模式》中，曾介绍过AlwaysON的同步过程。归结起来，主要包括如下六个步骤：
① log flush(primary)
② log capture(primary)
③ send(primary and secondary)
④ log receive and cache(secondary)
⑤ log hardened(secondary)
⑥ redo(secondary)
前两个步骤发生在主副本，最后三个步骤发生在辅助副本，中间的第三个步骤发生主副本和辅助副本之间。
另外，如果是同步提交模式，还需要增加一个步骤：辅助副本在步骤5之后，会发送一个（日志硬化）确认信息给主副本，然后才能进入redo阶段。
三、监控AlwaysOn的同步过程
Log Flush(Primary)
Log Flush就是将log buffer中的日志刷入到磁盘中。在SQL Server中，log buffer的大小固定为60KB，当发生事务提交时、checkpoint、或者buffer可用空间不足时，日志就会被flush磁盘中。
AlwaysON只有待主副本的日志刷入磁盘后才能继续后面的步骤（为了保护主副本的数据一致性）。因此，log flush的越快，AlwaysON后续步骤进入的就越早，延迟就越小，反之亦然。
那么，在这个阶段中，如何监控log flush的速度和性能呢？通常，我们使用如下两个性能计数器：
- Avg. Disk sec/Write
这是一个磁盘的性能计数器，这个指标反映的是flush期间磁盘的写操作的平均响应时间，如果10ms以内，说明磁盘性能非常好，如果在10ms到20ms，说明性能较好，如果在20ms到50ms说明性能较差，如果在50ms以上，说明性能很差。
这个指标直接反映了每秒flush的日志大小，因在不同的时段、不同的业务中日志产生的大小可能不同，因此不能提供一个标准值用来衡量flush性能的好坏，不过，当这个值很大时，说明数据库操作（增、删、改）比较频繁，需要引起注意，结合后续步骤中的其他指标一起分析。
log capture(primary)
log capture发生在log flush之后，是AlwaysON中最重要的阶段（个人认为）。在这个阶段中，主副本上会为每个辅助副本维护一个发送队列，队列的内容就是从日志缓冲或者磁盘中capture的日志，而队列的大小则反映了主副本和辅助副本数据不同步的差量。
显然，在这个阶段最可能影响AlwaysON同步性能的两个关键因素就是：capture日志的来源（是磁盘还是内存）和队列的大小。
在上述两个因素中，我需要着重解释下capture日志的来源：是磁盘还是内存？我们自导，从内存中读取数据效率要远远高于从磁盘中读取，所以在AlwaysON中，SQL Server会尽可能多将日志缓冲到内存中。但缓冲的大小是有限的，如果日志量太大、缓冲的大小不足，则不得不读取磁盘。
下面我们来熟悉下如何监控日志的来源和发送队列的大小：
监控日志的来源：
日志到底是读取自内存还是磁盘，通过如下性能计数器可窥见一斑：
- SQL Server:Databases:Log Pool Requests/sec和SQL Server:Memory Manager:Log Pool Memory (KB)
解释：前者表示每秒中从内存中请求日志块的数量；后者表示log pool memory的大小；
说明：对于这两个值，我们希望越高越好，则说明越多的日志可以从内存中读取到。
- SQL Server:Databases:Log Pool Disk Reads/sec和SQL Server:Databases:Log Pool Cache Misses/sec
解释：两个性能计数器其实都表示内存中找不到要读取的日志，必须从磁盘中读取；
说明：如果两个值越高，说明内存性能不足，SQL Server没法缓冲更多的日志。
监控日志发送队列：
在主副本上执行如下语句即可：
SELECT ag.name AS ag_name, ar.replica_server_name AS ag_replica_server, dr_state.database_id as database_id, dr_state.log_send_queue_size, is_ag_replica_local = CASE WHEN ar_state.is_local = 1 THEN N'LOCAL' ELSE 'REMOTE' END , ag_replica_role = CASE WHEN ar_state.role_desc IS NULL THEN N'DISCONNECTED' ELSE ar_state.role_desc END FROM (( sys.availability_groups AS ag JOIN sys.availability_replicas AS ar ON ag.group_id = ar.group_id ) JOIN sys.dm_hadr_availability_replica_states AS ar_state ON ar.replica_id = ar_state.replica_id) JOIN sys.dm_hadr_database_replica_states dr_state on ag.group_id = dr_state.group_id and dr_state.replica_id = ar_state.replica_id;
log_send_queue_size表示主数据库中尚未发送到辅助数据库的日志记录量 (KB)，也就是上文说的发送队列，如果某个辅助副本的发送队列持续增加，说明此副本与主副本同步的数据差量就越大。
在上例中，server1是主副本，server2是辅助副本。主副本的log_send_queue_size始终为null，server2的log_send_queue_size为154067KB。显然，此时server2明显落后于主副本。
send(primary and secondary)
send阶段是 AlwaysON同步过程中最简单的一个步骤（个人认为）。在这个阶段中，我们主要关注网络性能就好了，因为主副本必须借助网络才能把发送队列的日志传输到到对应的辅助副本。如果网络不好，AlwaysON就会产生延迟，更有甚者，如果是在同步提交模式下，还会导致主副本的事务迟迟不能提交。
对网络的监控主要通过如下两个性能计数器即可：
- Network Interface:bytes sent/sec
解释：网卡每秒发送的字节数；
说明：对于这个指标我们不能孤立来看，需结合发送队列的大小，当发送队列很大，但此性能指标持续比较低时，有可能是网络有问题（当然，如果是同步模式，需要考虑辅助副本log harden的速度才能决定是否一定跟网络有关）。
- Network Interface:output Queue Length
解释：网卡的发送队列大小；
说明：一般来说，网卡的队列大于2时，说明网络存在拥堵，可能出现了网络问题。
Log Receive and cache(sencondary)
log receive and cache发生在辅助副本上，表示辅助副本接受来自主副本发送的日志块、并缓冲起来的过程。
这个阶段其实跟网络速度和内存大小有关，两者在上文中均有介绍，这里不做过多阐述，只跟大家介绍下这个阶段中AlwaysON专有性能计数器。
解释：每秒接受的日志大小（单位为KB）；
说明：接受的速度越快，说明网络性能和内存性能均越好。
Log Hardened(sencondary)
介绍log hardened时不得不谈一谈第一个步骤的log flush，两者其实是一个东西，只是表述不一样。因为它们无论是工作原理还是对事务提交的影响都非常类似，因此对log hardened的监控，直接参考步骤一就好了。
redo(secondary)
redo的对象是辅助副本中已经固化的日志（该日志可能是内存中副本，也可能来自磁盘上），是AlwaysON中“实现”数据同步的步骤，其他步骤都是为此做铺垫，即便是上个步骤的日志固化，它也只能保证主副本和辅助副本的数据一致，而真正的数据同步必须等待辅助副本的redo完成。
在这个阶段中，有两个因素决定了数据延迟的大小：redo的日志大小和redo的速度。下面我们从这两个角度来了解下redo阶段的性能监控：
监控redo日志大小
SELECT ag.name AS ag_name, ar.replica_server_name AS ag_replica_server, dr_state.database_id as database_id, dr_state.redo_queue_size, is_ag_replica_local = CASE WHEN ar_state.is_local = 1 THEN N'LOCAL' ELSE 'REMOTE' END , ag_replica_role = CASE WHEN ar_state.role_desc IS NULL THEN N'DISCONNECTED' ELSE ar_state.role_desc END FROM (( sys.availability_groups AS ag JOIN sys.availability_replicas AS ar ON ag.group_id = ar.group_id ) JOIN sys.dm_hadr_availability_replica_states AS ar_state ON ar.replica_id = ar_state.replica_id) JOIN sys.dm_hadr_database_replica_states dr_state on ag.group_id = dr_state.group_id and dr_state.replica_id = ar_state.replica_id;
监控redo的速度
redo的速度通过如下性能计数器即可：
解释：辅助副本每秒完成redo的字节数；
说明：在分析此指标时，必须结合redo的日志大小，将两者的结果相除可得到一个大致的同步延迟时间。
四、跟踪延迟
通过扩展事件跟踪，我们可以知道日志块移动的每个步骤，并且可以确切地知道事务延迟来自何处。
通常，延迟来自三个部分：
- 主库日志固化的持续时间：它等于Log_flush_start（步骤2）和Log_flush_complete（步骤3）的时间之和。
- 从库日志固化的持续时间：它等于Log_flush_start（步骤10）和Log_flush_complete（步骤11）的时间之和。
- 网络传送的持续时间 ：primary：hadr_log_block_send_complete-> secondary：hadr_transport_receive_log_block_message（步骤6-7）和（secondary：hadr_lsn_send_complete-> primary：hadr_receive_harden_lsn_message（步骤12-13）的时间之和
创建扩展事件：
/* Note: this trace could generate very large amount of data very quickly,
depends on the actual transaction rate. On a busy server it can grow several GB per minute,
so do not run the script too long to avoid the impact to the production server. */ CREATE EVENT SESSION [AlwaysOn_Data_Movement_Tracing] ON SERVER
ADD EVENT sqlserver.file_write_completed,
ADD EVENT sqlserver.file_write_enqueued,
ADD EVENT sqlserver.hadr_apply_log_block,
ADD EVENT sqlserver.hadr_apply_vlfheader,
ADD EVENT sqlserver.hadr_capture_compressed_log_cache,
ADD EVENT sqlserver.hadr_capture_filestream_wait,
ADD EVENT sqlserver.hadr_capture_log_block,
ADD EVENT sqlserver.hadr_capture_vlfheader,
ADD EVENT sqlserver.hadr_db_commit_mgr_harden,
ADD EVENT sqlserver.hadr_db_commit_mgr_harden_still_waiting,
ADD EVENT sqlserver.hadr_db_commit_mgr_update_harden,
ADD EVENT sqlserver.hadr_filestream_processed_block,
ADD EVENT sqlserver.hadr_log_block_compression,
ADD EVENT sqlserver.hadr_log_block_decompression,
ADD EVENT sqlserver.hadr_log_block_group_commit ,
ADD EVENT sqlserver.hadr_log_block_send_complete,
ADD EVENT sqlserver.hadr_lsn_send_complete,
ADD EVENT sqlserver.hadr_receive_harden_lsn_message,
ADD EVENT sqlserver.hadr_send_harden_lsn_message,
ADD EVENT sqlserver.hadr_transport_flow_control_action,
ADD EVENT sqlserver.hadr_transport_receive_log_block_message,
ADD EVENT sqlserver.log_block_pushed_to_logpool,
ADD EVENT sqlserver.log_flush_complete ,
ADD EVENT sqlserver.log_flush_start,
ADD EVENT sqlserver.recovery_unit_harden_log_timestamps
ADD TARGET package0.event_file(SET filename=N'c:\mslog\AlwaysOn_Data_Movement_Tracing.xel',max_file_size=(500),max_rollover_files=(4))
WITH (MAX_MEMORY=4096 KB,
EVENT_RETENTION_MODE=ALLOW_SINGLE_EVENT_LOSS,
MAX_DISPATCH_LATENCY=30 SECONDS,
MAX_EVENT_SIZE=0 KB,
MEMORY_PARTITION_MODE=NONE,
TRACK_CAUSALITY=OFF,
STARTUP_STATE=ON
) GO
五、预警
IF EXISTS(SELECT 1 FROM sys.objects o WHERE o.[object_id]=OBJECT_ID('[dbo].[Proc_DBA_AlwaysonWarning]') AND o.[type] IN(N'P',N'PC')) DROP PROC [dbo].[Proc_DBA_AlwaysonWarning] GO -- ============================================= -- Description: alwayson预警 -- Remark : 所有参数均为产生预警的参数 -- ============================================= CREATE PROCEDURE dbo.Proc_DBA_AlwaysonWarning @syncMode BIT=NULL, --"同步模式" 是否为同步提交，是1否0，如为NULL则不处理。默认为 NULL (不处理是否异步) @syncStateIsFinished BIT=0, --"同步状态" 是否为 "SYNCHRONIZED"，是1否0，如为NULL则不处理。默认为 0 (如同步状态为未完成则预警) @syncHealth BIT=0, --"同步健康状态" 是否为健康, 是1否0，如为NULL则不处理。默认为 0 否 (如健康状态为不健康则预警) @redoDelaySeconds INT=600, --"Redo延迟(秒)" > 多少则预警。默认为 600 (s) @logDelaySeconds INT=600, --"Log传送延迟(秒)" > 多少则预警。默认为 600 (s) @redoWaitQueueKB BIGINT=10240, --"Redo等待队列(KB)" > 多少则预警。默认为 10240 (10MB) @logWaitQueueKB BIGINT=524288 --"Log传送等待队列(KB)" > 多少则预警。默认为 524288 (512MB) AS BEGIN SET NOCOUNT ON; ;WITH t AS ( SELECT ar.replica_server_name AS [副本名称] , ar.availability_mode_desc as [同步模式], DB_NAME(dbr.database_id) AS [数据库名称] , dbr.database_state_desc AS [数据库状态], dbr.synchronization_state_desc AS [同步状态], dbr.synchronization_health_desc AS [同步健康状态], ISNULL(CASE dbr.redo_rate WHEN 0 THEN -1 ELSE CAST(dbr.redo_queue_size AS FLOAT) / dbr.redo_rate END, -1) AS [Redo延迟(秒)] , ISNULL(CASE dbr.log_send_rate WHEN 0 THEN -1 ELSE CAST(dbr.log_send_queue_size AS FLOAT) / dbr.log_send_rate END, -1) AS [Log传送延迟(秒)] , dbr.redo_queue_size AS [Redo等待队列(KB)] , dbr.redo_rate AS [Redo速率(KB/S)] , dbr.log_send_queue_size AS [Log传送等待队列(KB)] , dbr.log_send_rate AS [Log传送速率(KB/S)] FROM [master].sys.availability_replicas AS AR INNER JOIN [master].sys.dm_hadr_database_replica_states AS dbr ON ar.replica_id = dbr.replica_id WHERE dbr.redo_queue_size IS NOT NULL ) /* @syncMode BIT=NULL, --"同步模式" 是否为同步提交，是1否0，如为NULL则不处理。默认为 NULL (不处理是否异步) @syncStateIsFinished BIT=0, --"同步状态" 是否为 "SYNCHRONIZED"，是1否0，如为NULL则不处理。默认为 0 (如同步状态为未完成则预警) @syncHealth BIT=0, --"同步健康状态" 是否为健康, 是1否0，如为NULL则不处理。默认为 0 否 (如健康状态为不健康则预警) @redoDelaySeconds INT=60, --"Redo延迟(秒)" > 多少则预警。默认为 60 (s) @logDelaySeconds INT=600, --"Log传送延迟(秒)" > 多少则预警。默认为 600 (s) @redoWaitQueueKB BIGINT=10240, --"Redo等待队列(KB)" > 多少则预警。默认为 10240 (10MB) @logWaitQueueKB BIGINT=524288, --"Log传送等待队列(KB)" > 多少则预警。默认为 524288 (512MB) */ SELECT CASE WHEN ( (@syncMode=0 AND [同步模式]!='SYNCHRONOUS_COMMIT') or ( @syncMode=1 AND [同步模式]='SYNCHRONOUS_COMMIT' ) ) OR ( (@syncStateIsFinished=0 AND [同步状态]!='SYNCHRONIZED') or ( @syncStateIsFinished=1 AND [同步状态]='SYNCHRONIZED' ) ) OR ( (@syncHealth=0 AND [同步健康状态]!='HEALTHY') or ( @syncHealth=1 AND [同步健康状态]='HEALTHY' ) ) OR ( [Redo延迟(秒)] > @redoDelaySeconds ) OR ( [Log传送延迟(秒)] > @logDelaySeconds ) OR ( [Redo等待队列(KB)] > @redoWaitQueueKB ) OR ( [Log传送等待队列(KB)] > @logWaitQueueKB ) THEN 1 ELSE 0 END AS Warning, [副本名称], [同步模式], [数据库名称], [数据库状态], [同步状态], [同步健康状态], [Redo延迟(秒)], [Log传送延迟(秒)], [Redo等待队列(KB)], [Redo速率(KB/S)], [Log传送等待队列(KB)], [Log传送速率(KB/S)] FROM t END GO EXEC sys.sp_addextendedproperty @name=N'Version', @value=N'2.0' , @level0type=N'SCHEMA',@level0name=N'dbo', @level1type=N'PROCEDURE',@level1name=N'Proc_DBA_AlwaysonWarning'
