7

I inherited database systems like this. Currently I have publisher database in SQL Server 2005 compatibility mode on Windows Server 2008 R2 with SQL Server 2008R2 SP2 machine. Distributor is on the same machine. Subscriber is 2008R2 SP2 and database is in SQL Server 2008 compatibility mode. We are using Transactional Replication. Isolation level is Read Committed. Distributor resides on Publisher. Even though when I right click on publication and even though subscription shows as pull subscription, I think it won't matter since distributor resides on publisher itself. Please correct me if I am wrong. Storage system is IBM flex which is shared by five servers including publisher and subscriber.

Since couple of days, I see latency of few hours, it catches up in the morning and starts going up again in the afternoon. I followed https://www.mssqltips.com/sqlservertip/3598/troubleshooting-transactional-replication-latency-issues-in-sql-server/ to see exactly what was happening. I ran following query.

USE distribution 
go 
EXEC Sp_browsereplcmds 
@xact_seqno_start = '<seq#>' -- seq# is same for start and end
,@xact_seqno_end = '<seq#>'
,@publisher_database_id = <publisher database id --this is different than database_id

I see that there are supposedly massive updates being done on few tables involved in replication and Log Reader is just scanning transaction log, not able to replicate anything till transaction completes. Interestingly, I can't see any blocking on either publisher and/or subscriber. Will changing isolation level to Read Committed Snapshot Isolation (RCSI) help here? Will it help to change polling interval to 1 and readbatchsize to 1000 or 5000. What's the command to change that setting?

I changed Log Reader Agent default profile as follows. Polling Interval from 5 to 1 and ReadBatchSize to 5000. This brought latency from 13 hours to zero almost instantly. But I see that it went back to 13 hours.

Replication is in sync and I don't have a single clue for actual root cause which caused the latency and now it went away.

7

I had to finally call Microsoft support and just a simple command called DBCC LOG INFO on publisher revealed a possible root cause. I saw more than 8600 VLFs! and this was the cause of that latency. Also, our log file is preallocated to 538GB.

Replication was out of sync by almost 19 hours by the time I got follow up call from Microsoft help 4:00pm next day after I opened case with Microsoft. Steps to be taken were really simple. Backup publisher db log couple of time and try to shrink log file. Set increment factor for log file by 8GB or 12GB instead of percentage or 500MB. So, that next time log file grows, it will create 16 VLFs per 8GB or 12GB depending on your increment factor.

After I backed up log, I was able to shrink log file to 350GB and total VLFs to around 5300. Still higher. Latency didn't come down though. It went upto 22 hours. I started wondering whether number of VLFs was just one of the causes. However, around 11:30pm, latency reduced to around 7h30m and I freed up more space around that time, reducing VLFs to 2001. By 2am, replication was in sync. I hurried up and backed up log twice and shrink the log file to 10GB and grew it back to around 248GB. Total number VLFs as of now are 184 and replication is in sync since then. Whew! Log file is almost empty.

Let me know if you have any questions about this. I am glad to help. Hopefully someone else doesn't have to call Microsoft for this issue.

  • This answer doesn't surprise me. We noticed log issues with several "log use" features after enabling CDC. The fix for all the latency was resolving the VLF issue on the primary database and I've since implemented the check into our maintenance routines. – Steve Mangiameli Jun 6 '16 at 14:43
6

Will changing isolation level to Read Committed Snapshot Isolation (RCSI) help here?

This is not a straight forward change and it comes with additional tempdb penalty. I would not suggest you to just change the isolation level to RCSI without properly testing and seeing benefits in your environment. Trust me, this is a sledge hammer approach.

We recently encountered about the same problem

massive updates being done on few tables involved in replication and Log Reader is just scanning transaction log

Below is how I resolved the problem :

  • Make Articles replicate as BATCHED (This change is dynamic and does not require re-initialization):

    • This can be done by right click publication --> generate scripts --> check @status value. Any value less than 16 indicates that it is set to replicate using TSQL ==> NOT Batched !
    • Even if 1 article is not set to BATCH, non of the articles will be BATCHED when applying changes to subscriber.

    • Use below TSQL

          EXEC sp_changearticle @publication = N'<pub name>'  -- your publication Name
                              , @article = N'<article name>'  -- your article Name
                              , @property = 'status'
                              ,  @value = 'parameters'
      
  • Created a nonclusted index on the distribution database :

    USE [distribution]
    GO
    CREATE NONCLUSTERED INDEX [nc_MSrepl_commands_DBA]
    ON [dbo].[MSrepl_commands] ([publisher_database_id],[article_id],[xact_seqno])
    INCLUDE ([type],[originator_id])
    GO
    

For more advance tuning, you can refer to Enhance Transactional Replication Performance especially Distribution Agent and Log Reader Agent Parameters.

Below is the script that I am using to find T-Rep Replication status :

USE [distribution]
-- Ref: http://www.sqlservercentral.com/blogs/basits-sql-server-tips/2012/07/25/t-sql-script-to-monitor-transactional-replication-status/

IF OBJECT_ID('Tempdb.dbo.#ReplStats') IS NOT NULL  
    DROP TABLE #ReplStats 

CREATE TABLE [dbo].[#ReplStats](
    [DistributionAgentName] [nvarchar](100) NOT NULL,
    [DistributionAgentStartTime] [datetime] NOT NULL,
    [DistributionAgentRunningDurationInSeconds] [int] NOT NULL,
    [IsAgentRunning] [bit] NULL,
    [ReplicationStatus] [varchar](14) NULL,
    [LastSynchronized] [datetime] NOT NULL,
    [Comments] [nvarchar](max) NOT NULL,
    [Publisher] [sysname] NOT NULL,
    [PublicationName] [sysname] NOT NULL,
    [PublisherDB] [sysname] NOT NULL,
    [Subscriber] [nvarchar](128) NULL,
    [SubscriberDB] [sysname] NULL,
    [SubscriptionType] [varchar](64) NULL,
    [DistributionDB] [sysname] NULL,
    [Article] [sysname] NOT NULL,
    [UndelivCmdsInDistDB] [int] NULL,
    [DelivCmdsInDistDB] [int] NULL,
    [CurrentSessionDeliveryRate] [float] NOT NULL,
    [CurrentSessionDeliveryLatency] [int] NOT NULL,
    [TotalTransactionsDeliveredInCurrentSession] [int] NOT NULL,
    [TotalCommandsDeliveredInCurrentSession] [int] NOT NULL,
    [AverageCommandsDeliveredInCurrentSession] [int] NOT NULL,
    [DeliveryRate] [float] NOT NULL,
    [DeliveryLatency] [int] NOT NULL,
    [TotalCommandsDeliveredSinceSubscriptionSetup] [int] NOT NULL,
    [SequenceNumber] [varbinary](16) NULL,
    [LastDistributerSync] [datetime] NULL,
    [Retention] [int] NULL,
    [WorstLatency] [int] NULL,
    [BestLatency] [int] NULL,
    [AverageLatency] [int] NULL,
    [CurrentLatency] [int] NULL
) ON [PRIMARY]


INSERT INTO #ReplStats 
SELECT da.[name] AS [DistributionAgentName]
      ,dh.[start_time] AS [DistributionAgentStartTime]
      ,dh.[duration] AS [DistributionAgentRunningDurationInSeconds]
      ,md.[isagentrunningnow] AS [IsAgentRunning]
      ,CASE md.[status]
        WHEN 1 THEN '1 - Started'
        WHEN 2 THEN '2 - Succeeded'
        WHEN 3 THEN '3 - InProgress'
        WHEN 4 THEN '4 - Idle'
        WHEN 5 THEN '5 - Retrying'
        WHEN 6 THEN '6 - Failed'
       END AS [ReplicationStatus]
      ,dh.[time] AS [LastSynchronized]
      ,dh.[comments] AS [Comments]
      ,md.[publisher] AS [Publisher]
      ,da.[publication] AS [PublicationName]
      ,da.[publisher_db] AS [PublisherDB]
      ,CASE 
         WHEN da.[anonymous_subid] IS NOT NULL 
            THEN UPPER(da.[subscriber_name])
       ELSE UPPER (s.[name]) END AS [Subscriber]
      ,da.[subscriber_db] AS [SubscriberDB]
      ,CASE da.[subscription_type]
        WHEN '0' THEN 'Push'  
        WHEN '1' THEN 'Pull'  
        WHEN '2' THEN 'Anonymous'  
       ELSE CAST(da.[subscription_type] AS [varchar](64)) END AS [SubscriptionType]
      ,md.[distdb] AS [DistributionDB]
      ,ma.[article]    AS [Article]
      ,ds.[UndelivCmdsInDistDB] 
      ,ds.[DelivCmdsInDistDB]
      ,dh.[current_delivery_rate] AS [CurrentSessionDeliveryRate]
      ,dh.[current_delivery_latency] AS [CurrentSessionDeliveryLatency]
      ,dh.[delivered_transactions] AS [TotalTransactionsDeliveredInCurrentSession]
      ,dh.[delivered_commands] AS [TotalCommandsDeliveredInCurrentSession]
      ,dh.[average_commands] AS [AverageCommandsDeliveredInCurrentSession]
      ,dh.[delivery_rate] AS [DeliveryRate]
      ,dh.[delivery_latency] AS [DeliveryLatency]
      ,dh.[total_delivered_commands] AS [TotalCommandsDeliveredSinceSubscriptionSetup]
      ,dh.[xact_seqno] AS [SequenceNumber]
      ,md.[last_distsync] AS [LastDistributerSync]
      ,md.[retention] AS [Retention]
      ,md.[worst_latency] AS [WorstLatency]
      ,md.[best_latency] AS [BestLatency]
      ,md.[avg_latency] AS [AverageLatency]
      ,md.[cur_latency] AS [CurrentLatency]
FROM [distribution]..[MSdistribution_status] ds 
INNER JOIN [distribution]..[MSdistribution_agents] da
    ON da.[id] = ds.[agent_id]                          
INNER JOIN [distribution]..[MSArticles] ma 
    ON ma.publisher_id = da.publisher_id 
        AND ma.[article_id] = ds.[article_id]
INNER JOIN [distribution]..[MSreplication_monitordata] md
    ON [md].[job_id] = da.[job_id]
INNER JOIN [distribution]..[MSdistribution_history] dh
    ON [dh].[agent_id] = md.[agent_id] 
        AND md.[agent_type] = 3
INNER JOIN [master].[sys].[servers]  s
    ON s.[server_id] = da.[subscriber_id] 
--Created WHEN your publication has the immediate_sync property set to true. This property dictates 
--whether snapshot is available all the time for new subscriptions to be initialized. 
--This affects the cleanup behavior of transactional replication. If this property is set to true, 
--the transactions will be retained for max retention period instead of it getting cleaned up
--as soon as all the subscriptions got the change. 
WHERE da.[subscriber_db] <> 'virtual' 
    AND da.[anonymous_subid] IS NULL
    AND dh.[start_time] = (SELECT TOP 1 start_time
                            FROM [distribution]..[MSdistribution_history] a
                            JOIN [distribution]..[MSdistribution_agents] b
                            ON a.[agent_id] = b.[id] AND b.[subscriber_db] <> 'virtual'
                            WHERE [runstatus] <> 1
                            ORDER BY [start_time] DESC)
    AND dh.[runstatus] <> 1

SELECT 'Transactional Replication Summary' AS [Comments];
SELECT [DistributionAgentName]
      ,[DistributionAgentStartTime]
      ,[DistributionAgentRunningDurationInSeconds]
      ,[IsAgentRunning]
      ,[ReplicationStatus]
      ,[LastSynchronized]
      ,[Comments]
      ,[Publisher]
      ,[PublicationName]
      ,[PublisherDB]
      ,[Subscriber]
      ,[SubscriberDB]
      ,[SubscriptionType]
      ,[DistributionDB]
      ,SUM([UndelivCmdsInDistDB]) AS [UndelivCmdsInDistDB]
      ,SUM([DelivCmdsInDistDB]) AS [DelivCmdsInDistDB]
      ,[CurrentSessionDeliveryRate]
      ,[CurrentSessionDeliveryLatency]
      ,[TotalTransactionsDeliveredInCurrentSession]
      ,[TotalCommandsDeliveredInCurrentSession]
      ,[AverageCommandsDeliveredInCurrentSession]
      ,[DeliveryRate]
      ,[DeliveryLatency]
      ,[TotalCommandsDeliveredSinceSubscriptionSetup]
      ,[SequenceNumber]
      ,[LastDistributerSync]
      ,[Retention]
      ,[WorstLatency]
      ,[BestLatency]
      ,[AverageLatency]
      ,[CurrentLatency]
FROM #ReplStats
GROUP BY [DistributionAgentName]
        ,[DistributionAgentStartTime]
        ,[DistributionAgentRunningDurationInSeconds]
        ,[IsAgentRunning]
        ,[ReplicationStatus]
        ,[LastSynchronized]
        ,[Comments]
        ,[Publisher]
        ,[PublicationName]
        ,[PublisherDB]
        ,[Subscriber]
        ,[SubscriberDB]
        ,[SubscriptionType]
        ,[DistributionDB]
        ,[CurrentSessionDeliveryRate]
        ,[CurrentSessionDeliveryLatency]
        ,[TotalTransactionsDeliveredInCurrentSession]
        ,[TotalCommandsDeliveredInCurrentSession]
        ,[AverageCommandsDeliveredInCurrentSession]
        ,[DeliveryRate]
        ,[DeliveryLatency]
        ,[TotalCommandsDeliveredSinceSubscriptionSetup]
        ,[SequenceNumber]
        ,[LastDistributerSync]
        ,[Retention]
        ,[WorstLatency]
        ,[BestLatency]
        ,[AverageLatency]
        ,[CurrentLatency]

SELECT 'Transactional Replication Summary Details' AS [Comments];
SELECT [Publisher]
      ,[PublicationName]
      ,[PublisherDB]
      ,[Article]
      ,[Subscriber]
      ,[SubscriberDB]
      ,[SubscriptionType]
      ,[DistributionDB]
      ,SUM([UndelivCmdsInDistDB]) AS [UndelivCmdsInDistDB]
      ,SUM([DelivCmdsInDistDB]) AS [DelivCmdsInDistDB]
FROM #ReplStats
GROUP BY [Publisher]
        ,[PublicationName]
        ,[PublisherDB]
        ,[Article]
        ,[Subscriber]
        ,[SubscriberDB]
        ,[SubscriptionType]
        ,[DistributionDB]

Your Answer

By clicking “Post Your Answer”, you agree to our terms of service, privacy policy and cookie policy

Not the answer you're looking for? Browse other questions tagged or ask your own question.