This is a continuation of “Repl Talk” series on troubleshooting Transactional Replication. This posting walks through the LogReader as it moves transactions from the published database transaction log to the Distribution database. The walkthrough can be done on a single Microsoft SQL Server 2008 using the AdventureworksLT sample database. Parts 1 and 2 walk through setting up Transactional Replication.
http://blogs.msdn.com/chrissk/archive/2010/01/28/troubleshooting-transactional-replication-part-1.aspxhttp://blogs.msdn.com/chrissk/archive/2010/01/28/troubleshooting-transactional-replication-part-2.aspx
/***** SQL Script to Walkthrough of LogReader Activity
Chris Skorlinski
Microsoft SQL Server Escalation Services
1) Create Publication and PUSH to Subscriber
2) To better demonstrate flow of transactions,
stop LogReader Agent.
Replicated Transaction Information:
Oldest distributed LSN : (26:248:32)
Oldest non-distributed LSN : (0:0:0) <<<no pending Repl Transactions
*****/
USE [AdventureWorksLT]
GO
--Perform a Single Row Update
UPDATE [AdventureWorksLT].[SalesLT].[Product]
SET ListPrice = ListPrice * 1.1, ModifiedDate = GETDATE()
Where ProductID = 680
--Are there any "pending" transactions?
DBCC OPENTRAN
Transaction information for database 'AdventureWorksLT'.
Oldest non-distributed LSN : (26:262:1)
--What is in the Transaction Log?
--Use WHERE Description = 'Replicate' to see transactions
-- marked to pickup by the LogReader.
select [Current LSN],[Operation],[Context],[Transaction ID], [Description],
AllocUnitId, AllocUnitName, [Lock Information]
from ::fn_dblog(null,null)
--where Description = 'Replicate'
where [Transaction ID] = '0000:0000070e'
Current LSN Operation Context Transaction ID Description
----------------------- ------------------------------- ---------------- -------------- ------------
0000001a:00000106:0002 LOP_BEGIN_XACT LCX_NULL 0000:0000070e UPDATE
0000001a:00000106:0003 LOP_DELETE_ROWS LCX_MARK_AS_GHOST0000:0000070e REPLICATE
0000001a:00000106:0004 LOP_INSERT_ROWS LCX_CLUSTERED 0000:0000070e REPLICATE
0000001a:00000106:0005 LOP_COMMIT_XACT LCX_NULL 0000:0000070e REPLICATE
(4 row(s) affected)
--(I added the "LOP_BEGIN_XACT" by looking at entire transaction)
-- where [Transaction ID] = '0000:0000070e'
--How does the LogReader retrieve this transaction?
--LogReader make a connection to SQL server and executes command below.
sp_replcmds
-- xactid = Begin Transaction
-- xact_seqno = Commit Transaction
article id partial_command command xactid xact_seqno
----------- --------------- ----------------------------------------------- ---------------------- ----------------------
1 0 0x8C00000003007B00430041004C004C0020005B006400 0x0000001A000001060002 0x0000001A000001060005
--How can I see actual TSQL commands
-- the LogReader retrieves from the Transaction Log?
sp_replshowcmds
xact_seqno command
---------------------- ---------------
0x0000001A000001060005 {CALL [dbo].[sp_MSupd_SalesLTProduct] (,,,,,1574.6500. ...
--Run LogReader Agent to move transaction to Distribution Database
sp_replflush -- clear internal article cache
/****
Start LogReader from CMD line (as local administrator) to watch activity.
Note the Agent performance statistics are automatically included
during LogReader shutdown when optional -continuous
is not included as a startup parameter.
"C:\Program Files\Microsoft SQL Server\100\COM\logread.exe" -Publisher [CHRISSKACER] -PublisherDB [AdventureWorksLT] -Distributor [CHRISSKACER] -DistributorSecurityMode 1
>>>>output<<<<
2010-02-02 23:10:53.518 Microsoft SQL Server Log Reader Agent 10.0.2531.0
2010-02-02 23:10:53.518 Copyright (c) 2008 Microsoft Corporation
2010-02-02 23:10:53.519
2010-02-02 23:10:53.519 The timestamps prepended to the output lines are expressed in terms of UTC time.
2010-02-02 23:10:53.519 User-specified agent parameter values:
-Publisher CHRISSKACER
-PublisherDB AdventureWorksLT
-Distributor CHRISSKACER
-DistributorSecurityMode 1
2010-02-02 23:10:53.616 Parameter values obtained from agent profile:
-pollinginterval 5000
-historyverboselevel 1
-logintimeout 15
-querytimeout 1800
-readbatchsize 500
-readbatchsize 500000
2010-02-02 23:10:53.633 Status: 4096, code: 20024, text: 'Initializing'.
2010-02-02 23:10:53.634 The agent is running.
Use Replication Monitor to view the details of this agent session.
2010-02-02 23:10:53.649 Status: 4, code: 22021, text: 'Batch committed.
Batch consisted of 1 commands, 1 xacts. Last xact: 0x0000001a000001060002, '0x0000001a000001060005'.'.
******************** STATISTICS SINCE AGENT STARTED ***************************
02-02-2010 18:10:53
Execution time (ms): 140
Work time (ms): 15
Distribute Repl Cmds Time(ms): 15
Fetch time(ms): 15
Repldone time(ms): 0
Write time(ms): 0
Num Trans: 1 Num Trans/Sec: 66.666667
Num Cmds: 1 Num Cmds/Sec: 66.666667
*******************************************************************************
2010-02-02 23:10:53.653 Status: 1, code: 22037, text: 'A total of 1 transaction(
s) with 1 command(s) were delivered.'.
2010-02-02 23:10:53.655 A total of 1 transaction(s) with 1 command(s) were delivered.
C:\Program Files\Microsoft SQL Server\100\COM>
--Are there more pending transactions?
Oldest distributed LSN : (26:262:5) -->>>>0x0000001a000001060005
Oldest non-distributed LSN : (0:0:0) -->>>>no "pending" transactions.
/***** Key TAKEWAYS
Transactions identified by 3-part LSN (Log Sequence Number)
Normal behavior "Oldest distributed LSN" keeps incrementing
"Oldest non-distributed LSN : (0:0:0)" indicates all pending data hasbeen replicated
Log recrods with Description = "replicate" are those read by LogReader
Part 4 will show commands to explore the transactions stored in the Distribution Database. Other posts will cover topics such as Replication Latency.