skreebydba

One of my favorite sections of the SQLskills Internals Immersion Event was logging and recovery. I've enjoyed internals since I started working as a COBOL programmer. Figuring out what SQL Server is doing under the covers makes me happy.

We covered a number of methods of interrogating the transaction log, and I have been working to put them together. In my next few blog posts, I will cover two of them and detail the challenges I faced joining the results.

I was familiar with the table-based function fn_dblog from reading SQL Server 2008 Internals. It takes two optional parameters, start and end log sequence number (lsn). Running this code:

SELECT * FROM fn_dblog(NULL,NULL)

will return the entire contents of the transaction log. Replacing the NULLs with an lsn will limit the result set. That query returns 116 columns, which is much more information than I need. Adding the following select list returned the data I was interested in:

SELECT 
SPID,                         -- The process ID for the transaction
[Begin Time],                 -- The start time for the transaction
[Current LSN],                -- The lsn of this record            
[Previous LSN],               -- Previous lsn for this record
Operation,                    -- The operation performed by the log record
Context,                      -- The resource affected by the operation
[Log Reserve],                -- The space reserved for rollback in bytes
AllocUnitName,                -- The name a the affected allocation unit
[Page ID],                    -- The page ID of the affected page
[Number of Locks],            -- The number of locks held by the transaction
[Lock Information]            -- Information about the locks held and the resources locked
FROM fn_dblog(NULL, NULL) 

To generate the result set below, I ran a CHECKPOINT on a database in SIMPLE recovery model to clear out the transaction log. I then ran the following query:

INSERT INTO loginsert
VALUES
(1
,'abcdefghij')
GO

I've split the results into two parts. The first set contains everything up to the lock information:

You can see that SPID and Begin Time are only be populated for a BEGIN TRANSACTION (LOP_BEGIN_XACT in the log). The LOP_INSERT_ROWS operation shows the table inserted to and the page affected.

Finally, the Lock Information column demonstrates SQL Server's lock escalation behavior. In the second half of the result set:

you can see SQL Server acquiring three locks. First, an intent exclusive lock is taken on a table. Second, an intent exclusive lock on a page. Finally, an exclusive lock is taken on a key. I thought this was a very cool representation of lock escalation.

My next posts will cover the following topics:

• Using sys.dm_tran_database_transactions to see what transactions are executing on the system
• More information than you thought possible about convert lsns
• Joining those results to fn_dblog to the log records associated with each active transaction