By: Diana Moldovan | Updated: 2018-05-07 | Comments | Related: More > Service Broker
How do SQL Server Service Broker messages reach their target? Is there any record of this “journey” in the transaction logs?
In this tip I’ll explore the transaction log at both the initiator and target and answer these questions.
SQL Server Test Environment for Service Broker
I’ll use the same test environment as in my previous Service Broker tip, so please refer to this tip for more information.
- Windows 10 Enterprise version 1703 OS Build 15063.7026 (my dev physical machine)
- SQL 2014 SP2 version 12.0.5207.0
- Ports 1433 and 4023 are open
- TCP/IP protocol is enabled
- Test database: SBSource
- Windows Server 2012 R2 Standard (virtual machine)
- SQL 2014 SP2 version 12.0.5000.0
- Ports 1433 and 4022 are open
- TCP/IP protocol is enabled
- Test database: SBTarget
Following Server Broker Messages in the SQL Server Transaction Log
Basically I’ll explore the transaction log using the fn_dblog function. Before doing this, I wanted to avoid having to read too many log records not relevant for this test; therefore, the first thing I did was to issue a manual CHECKPOINT at both sides.
After issuing the CHECKPOINT I inserted a record into the SBSource.dbo.SourceTable as follows which we will see what happens in the transaction log.
USE SBSource; GO --manual CHECKPOINT CHECKPOINT; --insert data in the "source" table INSERT INTO dbo.SourceTable(ID, RegDay, RegTime, Code) VALUES(1, CAST(CURRENT_TIMESTAMP AS date), CAST(CURRENT_TIMESTAMP AS time), 'A123');
The fn_dblog output returns 130 columns, but for this test I only needed a small subset of columns:
--on the "source" side USE SBSource; GO SELECT[Operation], [Context], [Transaction ID], [AllocUnitName], [Num Elements], [Transaction Name], [Description], [RowLog Contents 0], [RowLog Contents 1], [RowLog Contents 2], [RowLog Contents 3], [RowLog Contents 4], [RowLog Contents 5], [Log Record] FROM fn_dblog(NULL, NULL); --on the "target" side USE SBTarget; GO SELECT[Operation], [Context], [Transaction ID], [AllocUnitName], [Num Elements], [Transaction Name], [Description], [RowLog Contents 0], [RowLog Contents 1], [RowLog Contents 2], [RowLog Contents 3], [RowLog Contents 4], [RowLog Contents 5], [Log Record] FROM fn_dblog(NULL, NULL);
Read SQL Server Transaction Log on Service Broker Source
From the transaction log contents, I could find out what happened to the data inserted at the source. On the source side, the result of the above SELECT looks like this screenshot and I will explain below.
The first 3 rows (Transaction ID = 0000:00000000) correspond to the checkpoint.
The next transaction (Transaction ID = 0000:000005a4), highlighted in blue, corresponds to an INSERT operation, as you can see from the transaction name and description. From the AllocUnitName values you can see the tables where the insert takes place within this transaction:
- Insert in dbo.SourceTable (operation LOP_INSERT_ROWS). If you take your time to read the values from [RowLog Contents 0] to [RowLog Contents 5] and [Log Record] you’ll notice the values inserted, in our case “A123”.
- Update the sys.sysdesend table (operation LOP_MODIFY_ROW). Sys.sysdesend tracks each conversation when messages are sent from the initiator database. The update is done for every message sent.
- Insert in sys.sysxmitqueue (operation LOP_INSERT_ROWS). This basically corresponds to the addition of the new message in the transmission queue. Sys.transmission_queue is a catalog view built upon several system tables - sys.sysxmitqueue, sys.sysdesend and sys.sysdercv.
Next there are 2 more transactions, one dispatches the message (Transaction ID = 0000:000005a5) and the other (Transaction ID = 0000:000005a6) deletes the sent message from sys.sysxmitqueue.
Read SQL Server Transaction Log on Service Broker Target
On the target side I ran the same query and the results are:
Transaction 0000:000004e0 (highlighted in blue) inserts a row into a structure called “sys.queue_messages_885578193”. This is an internal table built by SQL Server to support the Service Broker queue. The number (885578193) is the object_id of the parent of the internal table, in our case ItemQueue2014. You can find these data by querying the sys.internal_tables catalog view:
USE SBTarget; GO SELECT * FROM sys.internal_tables WHERE [name] = 'queue_messages_885578193'; --this should be ItemQueue2014. You should change “885578193” with the object id from your environment. SELECT * FROM sys.objects WHERE [object_id] = 885578193;
Next, in the same transaction, the row from sys.sysdercv corresponding to the current conversation is updated (LOP_MODIFY_ROW).
Transaction 0000:000004e1 deletes the row in ItemQueue2014 and inserts a row in dbo.TargetTable. The row is first “marked as ghost” (context LCX_MARK_AS_GHOST) and, after 000:000004e1 commits, is “expunged” (operation LOP_EXPUNGE_ROWS), i.e. completely removed. There are 2 records for each operation (mark as ghost and expunge) in the fn_dblog output for the ItemQueue2014 row because the change takes place for both the clustered and the non-clustered index. The insert in dbo.TargetTable means that the activation stored procedure for ItemQueue2014 is now run.
The Service Broker routing and networking documentation offers a nice graphical representation of this process. The message is stored first at the source’s sys.transmission_queue and then delivered to the target’s queue. If anything wrong happens with the target queue, the message will go to the target’s sys.transmission_queue.
- Check out the best Service Broker documentation
- Check out all of the SQL Server Service Broker tips on MSSQLTips.com.
Last Updated: 2018-05-07
About the author
View all my tips