A tour of the transaction log: Part 1 INSERT operations

The transaction log is a very important part of SQL Server. Every data modification operation is logged in the transaction log before being ‘hardened’ to the database file.

There are plenty of scenarios where you might take a look at the transaction log like point-in-time transaction log backup restores (to stop at a certain LSN) or finding out who deleted that row or table.

In this series of articles we’ll delve deeper into the transaction log and its use in DML/DDL operations like INSERT, UPDATE, DELETE and DROP. We’ll also restore a transaction log backup at a certain LSN.

This article is the introduction into the commands you can use to explore the transaction log, which are undocumented by Microsoft. We will be tracing an INSERT command through the transaction log right down to the page level!

Setting up the test

The first thing we will be doing is creating a simple test database:

CREATE DATABASE [TlogTest] ON  PRIMARY
(
NAME = N'TlogTest', FILENAME = N'E:\Data\TlogTest.mdf' , SIZE = 3072KB , FILEGROWTH = 1024KB
)
LOG ON
(
NAME = N'TlogTest_log', FILENAME = N'E:\Log\TlogTest_log.ldf' , SIZE = 1024KB , FILEGROWTH = 10%
)
GO

Next step…a table!

USE [TlogTest]

CREATE TABLE [Table01]
(
[n1] INT IDENTITY,
[n2] CHAR DEFAULT 'a'
);

Now let’s insert some data into the table:

INSERT INTO Table01 DEFAULT VALUES;
GO 1000

Reading the transaction log

Now that we created a test database and table and filled it with some data, let’s see how it looks if we take a peek at the transaction log. For this we will be using the fn_dblog function.

USE [TlogTest]

SELECT *
FROM fn_dblog(DEFAULT, DEFAULT)

As you can see from the results we get a whole lot of information back from the transaction log! There are a lot of very interesting columns in the data that is returned, we can see at what time the transaction was processed, the lock information for that transaction, and much more. Keep in mind though that the entire fn_dblog function is undocumented, so looking for Microsoft articles that explain the way it works will get you nowhere.

Following INSERT events

A nice way to see how the transaction log works is following an INSERT action. To make it a bit easier to trace we will be inserting a new value into our test table, it’s a ‘b’ instead of an ‘a’ to make finding it later on easier:

USE [TlogTest]

INSERT INTO Table01
(n2)
VALUES
('b')
GO

Now we will use the fn_dblog function again and look for INSERT operations, order by LSN should give us the latest transaction which is our INSERT:

USE [TlogTest]

SELECT
[Current LSN],
[Operation],
[Transaction Name],
[Transaction SID],
[Page ID],
[Slot ID]
FROM fn_dblog(DEFAULT, DEFAULT)
WHERE [Operation] = 'LOP_INSERT_ROWS'
OR [Description] LIKE '%INSERT%'
ORDER BY [Current LSN] DESC

This query gave me the following result, keep in mind that you might get other ID’s back then I did!

tlog_1_01

The LOB_BEGIN_XACT operation is the actual INSERT query, LOP_INSERT_ROWS is the operation that places the data into the data pages.

We’ll follow the trail of the data page first! To find out in what data page the data was inserted we can use the Page ID column, only problem is that it’s a hex number. We are only interested in the last 8 numbers, in this case 0000009e. If we convert this value to decimal we get 158, which is the page id we are looking for.

Use DBCC PAGE (and a traceflag) we can take a look inside the data page and see if our data is there:

DBCC TRACEON (3604);
GO

USE [TlogTest]

DBCC PAGE (TLogTest, 1, 158, 3);
GO

Now the Slot ID comes in handy, this is the slot in the data page where our data is stored, in my results the Slot ID was 351.

This is the result I got from the DBCC PAGE and scrolling down to Slot 351:

tlog_1_04

As you can see the data from the INSERT is there!

Tracing who did the INSERT

In some cases it might also be useful to find out who performed this INSERT. If we look at our fn_dblog query results again we can focus on the LOB_BEGIN_XACT operation.

tlog_1_02

We used the LOP_INSERT_ROWS operation for tracing the data pages, we can use the LOB_BEGIN_XACT to find out who performed the transaction by using the Transaction SID.

Simply copy the Transaction SID and perform the following query:

SELECT SUSER_SNAME(Transaction SID);

In this example I get the following result:

tlog_1_03

As you can see the Windows user Administrator performed the INSERT query, which happens to be true 😉

Write a Reply or Comment

Your email address will not be published.