The transaction log of a SQL Server database is often misunderstood. In short, the transaction log records every change made to the database. Yes, that’s right – every change. As such, depending on the changes being made to the database, the recovery model and certain other factors that can prevent log truncation, transaction logs can grow – sometimes out of control.
A SQL Server transaction log that has runaway growth can have several negative side-effects including:
- Consuming all of the free space on the disk
- Overloading the I/O subsystem
- Causing Transaction Log Shipping to fall out of sync
So, how can one determine the cause of the rapid growth of the transaction log? Well, fortunately, there is a function named sys.fn_dblog. This function is officially undocumented, however it is very straightforward to use. It takes 2 input parameters, the first being the starting LSN (Log Sequence Number) and the second being the ending LSN. If NULL provided to either of these parameters, the parameter is effectively ignored. What sys.fn_dblog returns is a table with 129 columns (SQL Server 2012). While there is enough information to write a book about all of these columns, we are going to focus our attention on only 3 columns:
- Log Record Length
The combination of the above columns will give us the information we need to identify the cause of transaction log growth.
The code above simply:
- Creates the database
- Sets the recovery model to simple
- Sets the transaction log size to 10 MB
- Creates a table named TestTable
Now that we have an environment to work in, let’s clear out the transaction log. Since the recovery model is simple (formerly known as “TRUNCATE LOG ON CHECKPOINT”) issuing a simple CHECKPOINT command will clear the entries out of the transaction log.
Next, let’s insert a few rows of data to work with.
Now that we’ve just performed an insert, there should be records written to the transaction log. We can check with the following query:
On my system, when I execute the above query, I get the following:
You can see right at the top of the list the the LOP_INSERT_ROWS operation on the clustered index of dbo.TestTable accounts for 21.524% of my total transaction log consumption.
Let’s try an update next:
Since I omitted the WHERE clause, we updated all 5 rows in the table. Checking with sys.fn_dblog again, we get the following result:
Again, at the top, we can see the LOP_MODIFY_ROW operation which represents the UPDATE operation we just performed.
TRUNCATE vs. DELETE
How about TRUNCATE vs. DELETE? Let’s check out TRUNCATE first:
We have cleared the table, inserted a fresh set of rows, cleared the transaction log using a CHECKPOINT and then issued the TRUNCATE TABLE command. Here is our result:
The sum of the “TotalTranLogBytes” comes out to 2,402. As you can see, some system tables are updated to take note of the now missing data, but only 196 “TotalTranLogBytes” were used for the actual clustered index of dbo.TestTable.
Let’s check DELETE next.
We’ve just performed the same set of steps, only replacing the last TRUNCATE with a DELETE. Checking the transaction log we see the following:
The total “TotalTranLogBytes” here totals up to 1,224! How can that be? DELETE operations are always supposed to consume more transaction log space.
Let’s check it again:
Whoa! We didn’t execute any further commands but our “TotalTranLogBytes” just jumped to 1,612. How can that be? Well, the reason for this is how SQL Server handles DELETE operations. When a record is deleted, it is simply marked for deletion and becomes a “ghost record”. A separate process comes along (think Garbage Collection) and actually deletes the records at a later time.
So, the TRUNCATE statement still took (though very little) more transaction log space than the delete. Let’s check this again with larger data sets.
I’ve modify my query slightly to insert 5,000 rows instead of just 5. When we check the transaction log again, this is what we find:
A total of 4,438 bytes have been consumed truncating this table of 5,000 records.
Let’s try the same thing with DELETE:
This is what we get:
The DELETE operation took a total of 968,604 bytes – more than 218 times the space taken by the TRUNCATE operation. This of course also translates into disk I/O as well as time.
I would like to point out that sys.fn_dblog is an undocumented function and as such is subject to change without notice from Microsoft. Additionally, this function can be resource intensive so if you use this code in production, please do so with care.
Until next time.