All kinds of little bits of information have been added to the output of various DMVs, functions, and commands in SQL Server 2012.
One which I only discovered recently, and about which I’m really excited (ok, I should probably get out more :-), is the inclusion of the parent transaction ID in the output of fn_dblog. This allows us to see which transaction is the parent of nested system transactions and other sub-transactions.
You might wonder why I care? It allows us to see the hierarchy and definitive order of transactions during operations we’re performing with SQL Server, to aid in working out how operations work under the covers, rather than having to guess and assume.
For instance, when inserting the first row into a new table, the allocation system has to allocate a page from a mixed extent. Using the new field, we can see the definitive order of operations:
CREATE TABLE t1 (c1 INT);
GO
CHECKPOINT;
GO
INSERT INTO t1 VALUES (1);
GO
SELECT
[Current LSN],
[Operation],
[Context],
[Transaction ID],
[AllocUnitName],
[Transaction Name],
[Parent Transaction ID]
FROM fn_dblog (NULL, NULL);
GO
Current LSN Operation Context Transaction ID AllocUnitName Transaction Name Parent Transaction ID
———————- ———————- ————- ————– ———————– ————————– ———————
00000119:000001c2:0001 LOP_BEGIN_XACT LCX_NULL 0000:0000a216 NULL INSERT NULL
00000119:000001c2:0002 LOP_BEGIN_XACT LCX_NULL 0000:0000a217 NULL AllocHeapPageSimpleXactDML 0000:0000a216
00000119:000001c2:0003 LOP_LOCK_XACT LCX_NULL 0000:0000a217 NULL NULL NULL
00000119:000001c2:0004 LOP_SET_BITS LCX_SGAM 0000:00000000 Unknown Alloc Unit NULL NULL
00000119:000001c2:0005 LOP_BEGIN_XACT LCX_NULL 0000:0000a218 NULL AllocFirstPage 0000:0000a217
00000119:000001c2:0006 LOP_MODIFY_ROW LCX_PFS 0000:0000a218 dbo.t1 NULL NULL
00000119:000001c2:0007 LOP_BEGIN_XACT LCX_NULL 0000:0000a219 NULL AllocMixedExtent 0000:0000a217
00000119:000001c2:0008 LOP_SET_BITS LCX_GAM 0000:0000a219 Unknown Alloc Unit NULL NULL
00000119:000001c2:0009 LOP_SET_BITS LCX_SGAM 0000:0000a219 Unknown Alloc Unit NULL NULL
00000119:000001c2:000a LOP_COMMIT_XACT LCX_NULL 0000:0000a219 NULL NULL NULL
00000119:000001c2:000b LOP_MODIFY_ROW LCX_PFS 0000:0000a217 Unknown Alloc Unit NULL NULL
00000119:000001c2:000c LOP_FORMAT_PAGE LCX_IAM 0000:0000a217 dbo.t1 NULL NULL
00000119:000001c2:000d LOP_HOBT_DELTA LCX_NULL 0000:0000a217 NULL NULL NULL
00000119:000001c2:000e LOP_MODIFY_ROW LCX_IAM 0000:0000a218 dbo.t1 NULL NULL
00000119:000001c2:000f LOP_CREATE_ALLOCCHAIN LCX_NULL 0000:0000a217 NULL NULL NULL
00000119:000001c2:0010 LOP_LOCK_XACT LCX_NULL 0000:0000a217 NULL NULL NULL
00000119:000001c2:0011 LOP_COMMIT_XACT LCX_NULL 0000:0000a218 NULL NULL NULL
00000119:000001c2:0012 LOP_HOBT_DELTA LCX_NULL 0000:0000a217 NULL NULL NULL
00000119:000001c2:0013 LOP_LOCK_XACT LCX_NULL 0000:0000a217 NULL NULL NULL
00000119:000001c2:0014 LOP_ROOT_CHANGE LCX_CLUSTERED 0000:0000a217 sys.sysallocunits.clust NULL NULL
00000119:000001c2:0015 LOP_LOCK_XACT LCX_NULL 0000:0000a217 NULL NULL NULL
00000119:000001c2:0016 LOP_ROOT_CHANGE LCX_CLUSTERED 0000:0000a217 sys.sysallocunits.clust NULL NULL
00000119:000001c2:0017 LOP_FORMAT_PAGE LCX_HEAP 0000:0000a217 dbo.t1 NULL NULL
00000119:000001c2:0018 LOP_LOCK_XACT LCX_NULL 0000:0000a217 NULL NULL NULL
00000119:000001c2:0019 LOP_ROOT_CHANGE LCX_CLUSTERED 0000:0000a217 sys.sysallocunits.clust NULL NULL
00000119:000001c2:001a LOP_COMMIT_XACT LCX_NULL 0000:0000a217 NULL NULL NULL
00000119:000001c2:001b LOP_INSERT_ROWS LCX_HEAP 0000:0000a216 dbo.t1 NULL NULL
00000119:000001c2:001c LOP_SET_FREE_SPACE LCX_PFS 0000:00000000 Unknown Alloc Unit NULL NULL
00000119:000001c2:001d LOP_COMMIT_XACT LCX_NULL 0000:0000a216 NULL NULL NULL
Pretty darn cool, eh? We can see that the system started an implicit transaction for us, which it called INSERT. This then started a sub-transaction called AllocHeapPageSimpleXactDML to handle the internals of the allocating a page. This in turn started two further sub-sub-transactions to deal with the extent allocation and allocating the page.
>Note that the setting of the free space of the new page in the PFS is not done as part of a transaction (called being non-transactional), as it would be impossible to maintain transactional free space bits without causing major blocking in the system.
In future I’ll be making use of this in my spelunking exercises.
Enjoy!
9 thoughts on “Parent transaction ID in 2012 fn_dblog output”
Yeah, but this stuff is just *there* without having to do anything else :-)
It is so much easier to see the definitive order of operations with Extended Events. LOL!
Hello!
On a SQL Server 2012 CU3 performance test system there was excessive transaction logging in addition to a few other issues to research. The system was in simple recovery mode, so log backups and fn_dump_dblog wasn’t possible. I used a query with fn_dblog hoping to profile the log contents while activity was taking place. The query didn’t complete, and the SQL Server error log indicated that the transaction log had become full due to "LOG_SCAN". My fn_dblog query bridged the time from one complete masssive transaction into more logged activity and apprently prevented reuse of vlfs. Is there a way to "batch" the use of fn_dblog, perhaps by specifying lsns, in order to progress through the VLFs and records, but without causing an unnecessary dependency for VLF reuse?
Yes – the two parameters are the starting and ending LSNs to use.
It’s relatively for the SAN admins to create a separate T: drive for all our tempdb files (if more than one), and that’s typically a given for all our production servers. We typically have two or three as a default mainly because as a habit from our older servers that were SQL 2000
Hey Paul,
On my own test machine, I don’t see any log operations with context LCX_GAM or LCX_SGAM. Any idea why these might not show up? (Using SQL Server 2008 (SP3) – 10.0.5831.0 (X64))
I tried simple recovery and full recovery after a backup.
Because you already had a mixed extent with 1 or more free pages, so a new one doesn’t need to be allocated (which changes GAM and SGAM bitmaps).
Create 9 new tables with one row each and you’ll see them.
Confirmed! Thanks so much Paul.
Hi Paul,
From http://support.microsoft.com/kb/2729953 (“You may encounter a ‘result == LCK_OK’ assertion on a SQL Server mirror server”):
{
You should be aware that two scenarios do not have available fixes. The reason is that those two issues require a re-architecture of SQL Server transaction log internals. Such a change can be included only with a major release of SQL Server. In this case, the issue is fixed in Microsoft SQL Server 2012.
The master key change scenario is a rare enough event to make the scenario a corner case. However, the BCP/Bulk Insert scenario is common. Because the BCP/Bulk Insert scenario remains unfixed for SQL Server 2008 and SQL Server 2008 R2, it is the most probable known cause of “lck_ok” assertions on the current builds of these products. For more information about this scenario, see the “More Information” section.
}
I believe you will find system locks are logged in SQL Server 2012, and I assume Parent Transaction ID was part of the needed tlog “re-architecture” (mentioned above).