THE SQL Server Blog Spot on the Web

Welcome to SQLblog.com - The SQL Server blog spot on the web Sign in | |
in Search

Tibor Karaszi

Are log records removed from ldf file for rollbacks?

Seems like a simple enough question, right? This question (but more targeted, read on) was raised in an MCT forum. While the discussion was on-going and and I tried to come up with answers, I realized that this question are really several questions. First, what is a rollback? I can see three different types of rollbacks (there might be more, of course):

  1. Regular rollback, as in ROLLBACK TRAN (or lost/terminated connection)
  2. Rollback done by restore recovery. I.e., end-time of backup included some transaciton which wasn't committed and you restore using RECOVERY, so SQL Server need to rollback this transaction (UNDO).
  3. Rollback done by crash (restart) recovery. I.e. SQL Server was shut down with some open transaction.

I'm going to try to show whether log records are removed or still present for these three types of rollback situations. I will use the fn_dblog function. This isn't documented or supported, but search the internet and you will find how to use it. The result isn't documented either, of course, so we have to guess a bit what the various values mean...

The TSQL script has some common parts (the same part executed repeatedly, once for each test):

  1. Create a database
  2. Make sure it is in full recovery
  3. Do a database backup
  4. Create a table (myTable)
  5. Insert a row into myTable. This last operation generates 5 log records for the myTable table: one for the PFS page, two for IAM pages, one format page for the heap and the last one is a LOP_INSERT_ROWS.
  6. Start a transaction
  7. Insert one more row into myTable. We now have one more log record for myTable (LOP_INSERT_ROWS). Looking at the transaction id for this last insert, we see two log records (one LOP_BEGIN_XACT and the LOP_INSERT_ROWS). Note that this transaction is now open!

Here is the above mentioned first part of the script:

USE master
IF DB_ID('x'IS NOT NULL DROP DATABASE x
GO
CREATE DATABASE x
GO
ALTER DATABASE SET RECOVERY FULL
BACKUP DATABASE 
TO DISK = 'C:\x.bak' WITH INIT

USE x
CREATE TABLE myTable(c1 INT IDENTITY)
INSERT INTO myTable DEFAULT VALUES

SELECT 
FROM fn_dblog(NULL, NULL) WHERE AllocUnitName LIKE '%myTable%'
--5 rows

BEGIN TRAN
INSERT INTO 
myTable DEFAULT VALUES

SELECT 
FROM fn_dblog(NULL, NULL) WHERE AllocUnitName LIKE '%myTable%'
--6 rows

SELECT FROM fn_dblog(NULL, NULL) 
WHERE [Transaction ID] (SELECT TOP(1[Transaction ID] 
                          
FROM fn_dblog(NULL, NULL)
                          
WHERE AllocUnitName LIKE '%myTable%'
                          
ORDER BY [Current LSN] DESC)
--2 rows

Now, on to the different cases: 

1. Regular rollback, as in ROLLBACK TRAN.
It seems reasonable to me that SQL Server will just add some "rollback transaction" log record here. So, let's try that (continuing on above first part)... We now have 7 log records for myTable, with an added LOP_DELETE_ROWS which undo the previously insert. And for our transaction ID, we have 4 rows, with added two rows being LOP_DELETE_ROWS (compensation log record) and a LOP_ABORT_XACT.

--Regular ROLLBACK
ROLLBACK TRAN

SELECT 
FROM fn_dblog(NULL, NULL) WHERE AllocUnitName LIKE '%myTable%'
--7 rows

SELECT FROM fn_dblog(NULL, NULL) 
WHERE [Transaction ID] (SELECT TOP(1[Transaction ID] 
                          
FROM fn_dblog(NULL, NULL)
                          
WHERE AllocUnitName LIKE '%myTable%'
                          
ORDER BY [Current LSN] DESC)
--4 rows

2. Restore recovery
Now, what does this really mean? Restoring a transaction log backup is a good example. SQL Server read log records from the transaction log backup file and writes them into the LDF file. This is what we call the "data copy" phase. Then SQL Server performs REDO (a.k.a. roll forward). And finally, SQL Server performs UNDO (roll back), assuming we don't do the restore using the NORECOVERY option. Restoring from a database backup isn't any differene except the log records are of course read from the database backup file.

Here it seems likely that SQL Server will wipe more or less anything from the LDF file as soon as the database is restored and brought on-line. Why? The log in this newly restored database can't serve as a starting point for a restore operation for this database. You first need a database backup. So, no use hanging onto log records either! Let's see if we can verify that:

--Restore recovery

--Do this from different connection
BACKUP LOG TO DISK = 'C:\x.bak'
--We now have open transaction in database!

--Perform RESTORE
ROLLBACK
USE 
master
RESTORE DATABASE FROM DISK = 'C:\x.bak' WITH REPLACENORECOVERY
RESTORE LOG FROM DISK = 'C:\x.bak' WITH FILE = 2RECOVERY

--Rollback was done, and database berought online. 
--What log records do we have?

SELECT FROM fn_dblog(NULL, NULL) WHERE AllocUnitName LIKE '%myTable%'
--0 rows

--Use the transaction ID from earlier SELECT
SELECT FROM fn_dblog(NULL, NULL) 
WHERE [Transaction ID] '0000:00000203'
--0 rows

So, SQL Server will remove user-defined stuff from LDF file after restore recovery was performed. Makes sense.

3. Crash recovery (a.k.a. restart or startup recovery)
I couldn't really guess here. So, lets give it a spin immediately and see:

--Crash recovery

--Do below from separate connection
SHUTDOWN WITH NOWAIT

-- startup SQL Server and examine the log records:

SELECT FROM fn_dblog(NULL, NULL) WHERE AllocUnitName LIKE '%myTable%'
--5 rows

--Use the transaction ID from earlier SELECT
SELECT FROM fn_dblog(NULL, NULL) 
WHERE [Transaction ID] '0000:00000204'
--0 rows

Hmm, so SQL Server removes the log record after the rollback was performed. Makes sense.

But this got me thinking some more. How can this be done... physically? SQL Server would just "reverse" the head of the log a bit. But what if we have later transactions for other connections, which has been committed? SQL Server can't ignore those, of course. These need to be kept in the LDF file for subsequent log backups. OTOH, I doubt that SQL Server will somehow physically delete things "in the middle" of an ldf file. Time for yet another test:

--Crash recovery, part two

--Do below from separate connection
--First something which creates more recent log records
CREATE TABLE y(c1 INTINSERT INTO y(c1VALUES(1)
SHUTDOWN WITH NOWAIT

-- startup SQL Server and examine the log records:

SELECT FROM fn_dblog(NULL, NULL) WHERE AllocUnitName LIKE '%myTable%'
--7 rows

--Use the transaction ID from earlier SELECT
SELECT FROM fn_dblog(NULL, NULL) 
WHERE [Transaction ID] (SELECT TOP(1[Transaction ID] 
                          
FROM fn_dblog(NULL, NULL)
                          
WHERE AllocUnitName LIKE '%myTable%'
                          
ORDER BY [Current LSN] DESC)
--4 rows

Now the log records for our rolled back transaction are still there! So, just as when we did a regular rollback, SQL Server inserted a LOP_DELETE_ROWS to reflect the undo of the INSERT, and then a LOP_ABORT_XACT.

Conclusion
Isn't it beautiful when it all makes sense? Here are my conclusions, whether log records are kept or removed from transaction log file (LDF) for various types of rollback scenarios:

  • Regular rollback. Log records are not removed. Compensation log records are logged, reflecting undo of the modifications, and then an LOP_ABORT_XACT is logged.
  • Restore recovery. Log records are removed.
  • Crash recovery. It depdends. If you have a transaction which is at the very head of the log, then those log records can be removed. If there are other, subsequent committed transactions, then compensation log records are logged, reflecting undo of the modifications, and then a LOP_ABORT_XACT is logged.
Published Monday, March 22, 2010 12:34 PM by TiborKaraszi
Filed under: ,

Comment Notification

If you would like to receive an email when updates are made to this post, please register here

Subscribe to this post's comments using RSS

Comments

 

Paul Randal said:

I'm afraid your conclusions are incorrect Tibor. Log records are *never* removed from the transaction log, only overwritten by subsequent resuses of the VLFs. Unfortunately, your analysis is based on the behavior of fn_dblog, which is only showing log records from the active portion of the log - this makes it seem like the log records have disappeared, when in fact they haven't.

Thanks

March 27, 2010 12:27 PM
 

TiborKaraszi said:

Thanks Paul.

You are of course correct. For the benefit of the readers, the case we are referring to here is 3, crash recovery, the first one (where fn_dblog suggested that head of log had been reversed a bit). That is *not* the case. For the fun of it, I mofified my TSQL to do a much larger transaction, stop and restart. Even fn_dblog will now show compensation records along with XACT_ABORT (possibly because we cross VLF). DBCC LOGINFO confirms that head of log *has not* been reversed.

IF @@TRANCOUNT > 0 ROLLBACK TRAN

USE master

IF DB_ID('x') IS NOT NULL DROP DATABASE x

GO

CREATE DATABASE x

GO

ALTER DATABASE x SET RECOVERY FULL

BACKUP DATABASE x TO DISK = 'C:\x.bak' WITH INIT

USE x

CREATE TABLE myTable(c1 INT IDENTITY, c2 char(100) default 'hi')

INSERT INTO myTable DEFAULT VALUES

SELECT * FROM fn_dblog(NULL, NULL) WHERE AllocUnitName LIKE '%myTable%'

--5 rows

DBCC LOGINFO -- 2 rows, first has status = 2

BEGIN TRAN

INSERT INTO myTable SELECT TOP(1000) 'hola' FROM sys.columns a, sys.columns b

INSERT INTO myTable SELECT TOP(1000) 'hola' FROM sys.columns a, sys.columns b

INSERT INTO myTable SELECT TOP(1000) 'hola' FROM sys.columns a, sys.columns b

INSERT INTO myTable SELECT TOP(1000) 'hola' FROM sys.columns a, sys.columns b

SELECT * FROM fn_dblog(NULL, NULL) WHERE AllocUnitName LIKE '%myTable%'

--4145 rows

SELECT * FROM fn_dblog(NULL, NULL)  

WHERE [Transaction ID] = (SELECT TOP(1) [Transaction ID]  

                         FROM fn_dblog(NULL, NULL)

                         WHERE AllocUnitName LIKE '%myTable%'

                         ORDER BY [Current LSN] DESC)

--4001 rows

DBCC LOGINFO --9 rows, first 5 rows has status = 2

--Crash recovery

--Do below from separate connection

SHUTDOWN WITH NOWAIT

-- startup SQL Server and examine the log records:

--Same as before the crash, with addition of UNDO records and XACT_ABORT:

SELECT * FROM fn_dblog(NULL, NULL) WHERE AllocUnitName LIKE '%myTable%'

--8145 rows

SELECT * FROM fn_dblog(NULL, NULL)  

WHERE [Transaction ID] = (SELECT TOP(1) [Transaction ID]  

                         FROM fn_dblog(NULL, NULL)

                         WHERE AllocUnitName LIKE '%myTable%'

                         ORDER BY [Current LSN] DESC)

--80002 rows

DBCC LOGINFO --9 rows, first 6 rows has status = 2

March 27, 2010 1:42 PM

Leave a Comment

(required) 
(required) 
Submit

This Blog

Syndication

Powered by Community Server (Commercial Edition), by Telligent Systems
  Privacy Statement