Auditing changes in Merge Replication

One trick I have learned from the folks on the Replication Support Team is how to proactively audit data changes in Merge Replication.  This is useful when troubleshooting issues such as identifying where data changes are coming from, who is causing them, and what the data is before and after the change.  I have found this valuable information to have on a few occasions and thought I would share.

Keep in mind this should only be used for troubleshooting purposes and should always be tested in pre-production prior to deploying.  Make sure it works first!

Auditing data changes for a Merge article can be done by creating insert, update, and delete triggers to capture data changes and record them into an audit table.  The audit table rows consist of GETDATE(), APP_NAME(), HOST_NAME(), SUSER_NAME(), column data, action type, command, and spid for each insert, update, and delete that occurs on the article to audit.  You will have to modify the script to adjust the name of the table being audited and the relevant columns that you think should be included in the audit data.  Usually just the primary key columns are enough, but other columns can be included as well.

Audit script

/************************************************************************
This is a script to implement audit triggers of insert, update, delete on 
a base table. It is based on a generic scenario for a table with four 
columns col1, col2, col3, col4.
 
It will insert into a table called source_audit.
 
Run this script on the database you would like to audit.
 
Test first to be sure it is working as expected!
 
After the problem occurs, export the contents of the source_audit table.
************************************************************************/
 
USE DB_to_audit
GO
 
-- Drop audit table if exists
IF  EXISTS (SELECT * FROM sys.objects WHERE object_id = OBJECT_ID(N'[dbo].[source_audit]') AND type in (N'U'))
DROP TABLE [dbo].[source_audit]
 
-- Create audit table
CREATE TABLE [dbo].[source_audit]
    ([tstamp] datetime NULL, 
     [ProgramName] nvarchar(128) NULL, 
     [hostname] nvarchar(128) NULL, 
     [suser] nvarchar(128) NULL,
     [col1] int ,
     [col2] nchar(10) NULL,
     [col3] datetime NULL,
     [col4] binary NULL,
     [actiontype] char(2) NULL,
     [inputbuffer] nvarchar(255) NULL,
     [spid] int NULL)
GO
 
-------------------------------------------
-- INSERT trigger
-------------------------------------------
 
-- Delete trigger if exists
IF  EXISTS (SELECT * FROM sys.triggers WHERE object_id = OBJECT_ID(N'[dbo].[audit_source_INS]'))
DROP TRIGGER [dbo].[audit_source_INS]
GO
 
-- Create INSERT trigger
CREATE TRIGGER audit_source_INS
on Table_1
FOR INSERT
AS
DECLARE @command NVARCHAR(255)
 
if 0 = (select count(*) from inserted) return
 
CREATE TABLE #InputBuffer ([eventtype] NVARCHAR(30), [parameters] INT, [eventinfo] NVARCHAR(255))
INSERT INTO #InputBuffer exec('DBCC INPUTBUFFER(@@spid) WITH NO_INFOMSGS')
SELECT @command=eventinfo from #InputBuffer
 
INSERT INTO source_audit
SELECT getdate(), app_name(), host_name(), suser_name(), col1, col2, col3, col4, 'I', @command, @@SPID
FROM inserted
GO
 
-------------------------------------------
-- UPDATE trigger
-------------------------------------------
 
-- Delete trigger if exists
IF  EXISTS (SELECT * FROM sys.triggers WHERE object_id = OBJECT_ID(N'[dbo].[audit_source_UPD]'))
DROP TRIGGER [dbo].[audit_source_UPD]
GO
 
-- Create UPDATE trigger
CREATE TRIGGER audit_source_UPD
on Table_1
FOR UPDATE
AS
DECLARE @command NVARCHAR(255)
 
if 0 = (select count(*) from inserted) return
 
CREATE TABLE #InputBuffer ([eventtype] NVARCHAR(30), [parameters] INT, [eventinfo] NVARCHAR(255))
INSERT INTO #InputBuffer exec('DBCC INPUTBUFFER(@@spid) WITH NO_INFOMSGS')
SELECT @command=eventinfo from #InputBuffer
 
INSERT INTO source_audit
SELECT getdate(), app_name(), host_name(), suser_name(), col1, col2, col3, col4, 'UD', @command, @@SPID
FROM deleted
INSERT INTO source_audit
SELECT getdate(), app_name(), host_name(), suser_name(), col1, col2, col3, col4, 'UI', @command, @@SPID
FROM inserted
GO
 
-------------------------------------------
-- DELETE trigger
-------------------------------------------
 
-- Delete trigger if exists
IF  EXISTS (SELECT * FROM sys.triggers WHERE object_id = OBJECT_ID(N'[dbo].[audit_source_DEL]'))
DROP TRIGGER [dbo].[audit_source_DEL]
GO
 
-- Create DELETE trigger
CREATE TRIGGER audit_source_DEL
on Table_1
FOR INSERT
AS
DECLARE @command NVARCHAR(255)
 
if 0 = (select count(*) from inserted) return
 
CREATE TABLE #InputBuffer ([eventtype] NVARCHAR(30), [parameters] INT, [eventinfo] NVARCHAR(255))
INSERT INTO #InputBuffer exec('DBCC INPUTBUFFER(@@spid) WITH NO_INFOMSGS')
SELECT @command=eventinfo from #InputBuffer
 
INSERT INTO source_audit
SELECT getdate(), app_name(), host_name(), suser_name(), col1, col2, col3, col4, 'D', @command, @@SPID
FROM deleted
GO

Examining the results

Once the audit table and triggers are in place we can begin collecting audit data.  The audit data can be exported from the audit table after reproducing the problem to be queried at a later place and time, or it can be queried directly.  Here is a sample audit of a Merge publisher and the audit data after an update and sync from subscriber WS2008R2_1.

SELECT tstamp, ProgramName, hostname, suser,
col1, actiontype, inputbuffer, spid
FROM dbo.source_audit


 
Using this approach, we can identify where data changes are coming from, who is causing them, and what the data is before and after the change.  This can be very useful information to have, especially when troubleshooting conflicts and determining where the conflicting changes are originating — but I will save that for a future post.  If you would like help implementing an auditing scheme in your Merge topology, feel free to drop me a line or leave a comment below.

-Brandon Williams (blog | linkedin | twitter)

Error when creating a subscription

When creating a subscription in SQL Server sometimes the following error will occur:

The remote server "%s" does not exist, or has not been designated as a valid Publisher, or you may not have permission to see available Publishers.

The error is pretty straightforward and indicates that the replication agent login used to connect to the Publisher is not a member of the publication access list (PAL).  That would be the Distribution Agent process account for Transactional Replication and the Merge Agent process account for Merge Replication.  Add the agent process account to the PAL and try to create the subscription again.

Publication Access List

The process could not read file due to OS error 3

When configuring a subscription to a publication in SQL Server, sometimes the agent process cannot read from the snapshot:

The process could not read file X:\Program Files\Microsoft SQL Server\<instance>\MSSQL\repldata\<snapshot>\<snapshot_file> due to OS error 3. (Source: MSSQL_REPL, Error number: MSSQL_REPL20016)
Get help: http://help/MSSQL_REPL20016
The system cannot find the path specified.
(Source: MSSQL_REPL, Error number: MSSQL_REPL3)
Get help: http://help/MSSQL_REPL3

This error can be puzzling at first especially when the path indeed does exist and the replication agent process accounts have sufficient privileges to access the snapshot folder.

The error occurs because when using pull subscriptions and/or a remote distributor you must specify a UNC network share such as \\<computername>\snapshot rather than a local path for the snapshot folder.  To alleviate this issue, make the snapshot folder a UNC network share and update the Distributor Properties to reflect the change.

More Information

Securing the Snapshot Folder

Replication Agent Logging

To troubleshoot replication agent failures, replication agent profiles can be configured to output verbose agent logs to a text file.  All replication agents contain the parameters -Output output_path_and_file_name and -OutputVerboseLevel [0|1|2], which when specified, output the agent log to the file output_path_and_file_name and will contain varying degrees of information depending on the verbose level passed.  In general, the information contained in the verbose agent logs consists of progress report messages, error messages, procedure calls, and various session statistics.

Depending on the verbose level and the agent, some or all of this information will be provided.  For the purpose of troubleshooting replication agent failures, a verbose level of 2 should be specified, which prints all error and progress report messages.  It might also be worth mentioning that some agents can be passed undocumented output verbose levels 3 and 4 which provide even more information.  The information provided in the verbose agent logs can be useful when trying to diagnose and identify exactly where replication is failing as well as get detailed information as to the root cause of the failure.  In addition, the verbose agent logs are likely the first piece of diagnostic data that Microsoft Support will ask for when diagnosing a replication support incident.

Reading the logs takes a little getting used to but after utilizing them to troubleshoot a few times, it becomes second nature.  I often use them when replication failures are occurring and the error given in Replication Monitor and the View Synchronization Status window isn’t sufficient enough to diagnose the issue.  An example error message with Merge Replication that occasionally crops up is: The process was successfully stopped. (Source: MSSQL_REPL, Error number: MSSQL_REPL-2147200963), which isn’t very verbose.  Knowing how to output the verbose agent logs is a smart skill to have under these circumstances in order to identify the root cause.

The parameters to output the verbose agent logs can be passed to the Run Agent job step in the Job Properties dialog, Agent Profile dialog in Replication Monitor, via RMO, or by way of invoking the agents from the command line.  After adding the parameters, the replication agent must be restarted for the profile changes to take effect.  Once restarted, the replication agent will begin outputting the verbose log to the path and file name specified.  After reproducing the failure, the log can then be examined for further information.

The verbose agent log is outputted in the form of a text document and can be opened with your favorite text editor.  The -OutputVerboseLevel specified for the agent profile will dictate the contents of the log.  Typically, if a replication agent failure occurs, it will fail and the process will stop.  That means that the failure is likely to be found at the end of the log, in the last 20 or so lines in the output file.

Be sure to remove the agent parameters after reproducing the failure and collecting the log.  Not doing so will result in the log to be appended to on subsequent synchronizations and consume disk space.  Outputting agent logs can also impact replication performance and thus isn’t recommended to do unless troubleshooting replication failures.

The Proxy Auto-configuration URL was not found

When configuring Merge Replication for Web Synchronization it's common to encounter the error The Proxy Auto-configuration URL was not found and for replication to fail on synchronization.  This error occurs when either the certificate is not installed properly, and/or Internet Explorer proxy settings are set.

To alleviate this issue, verify the certificate is installed properly at the subscriber(s) for the merge agent process account.  Then, open Internet Explorer, go to Internet Options -> Connections tab -> LAN settings, and uncheck Automatically detect settings.

You are browsing all posts categorized Troubleshoot