Read SQL Server Transaction Log Backups to Find When Transactions Occurred

Problem

I have written a few tips about the SQL Server transaction log file regarding how to read the log to find unauthorized logins that have deleted or updated data. Many of the readers have asked how we can find this information after a transaction log backup has been processed. Here I will explain how to find the culprit SQL Server login that was involved using a transaction log backup.

Solution

I have already discussed How to read a SQL Server Transaction log and finding a user who has deleted or dropped SQL Server objects in my previous tips. I recommend reading my previous tips to understand how the transaction log is responsible for logging all database activities.

In this tip, we will use a different undocumented function fn_dump_dblog() to find transactions from a log backup. We can then use this information to recover deleted data from our backups. For our example, I assume the database is in full recovery mode and transaction log backups are running on a regular interval. I also strongly suggest testing any undocumented code in a lab environment prior to production.

Let’s take a scenario, someone has either accidently deleted some data or someone has intentionally removed some data and you are not aware when this occurred and who did this. When you checked the transaction log file by running fn_dblog, you find nothing and the transaction log looks flushed, so we will use fn_dump_dblog() instead to find the details.

Setup scenario and check active SQL Server transaction log

We used a database named “ReadingDBLog” for reading transaction log files in my last articles. We will use the same database. There is a table named “Location” in this database with 100 rows.

Now we are going to delete the first nine rows of this table by running the below command.

USE ReadingDBLog
Go
DELETE Location 
WHERE [Sr.No] < 10
go
select * from Location

You can see in below screenshot that first nine rows of this table have been deleted.

If you want to get info about these deleted rows from the active database log file, you can read my last tip finding a user who has deleted or dropped SQL Server objects.

But in this tip additional backups have occurred and the data is no longer in the active transaction log. So, we will need to find the information with the help of a transaction log backup, not from the active transaction log.

To simulate this clearing of the active log, we are going to run a transaction log backup to clear the active log

BACKUP LOG ReadingDBLog TO DISK ='D:\ReadingDBLog_201503022236.trn'

or we can run a full backup as shown below.

BACKUP DATABASE ReadingDBLog TO DISK ='D:\ReadingDBLog_Fullbackup.bak'

Now if we run the below script, that we looked at from my previous tip, against the active transaction log file we can see that the data has been flushed and nothing shows using this command.

use ReadingDBLog
go
SELECT 
 [Current LSN],    
 [Transaction ID],
 [Transaction Name],
     Operation,
     [Begin Time]
FROM 
    fn_dblog(NULL, NULL) 
WHERE [Operation] = 'LOP_DELETE_ROWS'

Using fn_dump_dblog to find the data in a SQL Server Transaction Log Backup

So at this point, we will have to rely on the SQL Server transaction log backups and use this undocumented function fn_dump_dblog to get the required details.

We will read the transaction log backup that we created with the help of fn_dump_dblog. This function takes a lot of parameters, but we only need to pass the backup file location along with backup file name, the rest of the parameters just take the value of DEFAULT.

When we run this code we can get a list of all rows where DELETEs occurred that are part of this transaction log backup. This will show us all DELETEs that are part of this log backup. If we want to look at other transaction log backups, we will need to change the name of the file that we are referencing.

    
SELECT [Current LSN], [Transaction ID], [Transaction Name], [Operation], [Begin Time], [PartitionID], [TRANSACTION SID]FROM fn_dump_dblog (NULL, NULL, N'DISK', 1, N'D:\ReadingDBLog_201503022236.trn',
DEFAULT, DEFAULT, DEFAULT, DEFAULT, DEFAULT, DEFAULT, DEFAULT, DEFAULT, DEFAULT, DEFAULT, DEFAULT, DEFAULT, DEFAULT, DEFAULT,
DEFAULT, DEFAULT, DEFAULT, DEFAULT, DEFAULT, DEFAULT, DEFAULT, DEFAULT, DEFAULT, DEFAULT, DEFAULT, DEFAULT, DEFAULT, DEFAULT,
DEFAULT, DEFAULT, DEFAULT, DEFAULT, DEFAULT, DEFAULT, DEFAULT, DEFAULT, DEFAULT, DEFAULT, DEFAULT, DEFAULT, DEFAULT, DEFAULT,
DEFAULT, DEFAULT, DEFAULT, DEFAULT, DEFAULT, DEFAULT, DEFAULT, DEFAULT, DEFAULT, DEFAULT, DEFAULT, DEFAULT, DEFAULT, DEFAULT,
DEFAULT, DEFAULT, DEFAULT, DEFAULT, DEFAULT, DEFAULT, DEFAULT)
WHERE Operation = 'LOP_DELETE_ROWS'
GO

log backup file output with fn_dump_dblog

The thing to note here is the TransactionID (0000:000003af) and also the PartitionID (72057594038779904) which we will use in the next steps.

Since we want to find out when the DELETE occurred and who did the DELETE, we need the values for [Begin Time] and [Transaction SID], but these are not available for this Operation (LOP_DELETE_ROWS).

We can find when this transaction was started by looking for LOP_BEGIN_XACT along with the Transaction ID (0000:000003af) that we got from above. We can also use the SUSER_NAME function to get the actual login that did the DELETE. This gives us more information, but it doesn't tell us what table was affected.

SELECT [Current LSN], [Transaction ID], 
[Transaction Name], 
[Operation], 
[Begin Time],
SUSER_SNAME([TRANSACTION SID]) as [LoginName]
FROM fn_dump_dblog (NULL, NULL, N'DISK', 1, N'D:\ReadingDBLog_201503022236.trn',
DEFAULT, DEFAULT, DEFAULT, DEFAULT, DEFAULT, DEFAULT, DEFAULT, DEFAULT, DEFAULT, DEFAULT, DEFAULT, DEFAULT, DEFAULT, DEFAULT,
DEFAULT, DEFAULT, DEFAULT, DEFAULT, DEFAULT, DEFAULT, DEFAULT, DEFAULT, DEFAULT, DEFAULT, DEFAULT, DEFAULT, DEFAULT, DEFAULT,
DEFAULT, DEFAULT, DEFAULT, DEFAULT, DEFAULT, DEFAULT, DEFAULT, DEFAULT, DEFAULT, DEFAULT, DEFAULT, DEFAULT, DEFAULT, DEFAULT,
DEFAULT, DEFAULT, DEFAULT, DEFAULT, DEFAULT, DEFAULT, DEFAULT, DEFAULT, DEFAULT, DEFAULT, DEFAULT, DEFAULT, DEFAULT, DEFAULT,
DEFAULT, DEFAULT, DEFAULT, DEFAULT, DEFAULT, DEFAULT, DEFAULT)
WHERE [Transaction ID] = '0000:000003af'
AND Operation = 'LOP_BEGIN_XACT'
GO

We can then use the PartitionID value (72057594038779904) from fn_dump_dblog to find the actual table where the DELETEs occurred as shown below.

USE ReadingDBLogGO
SELECT so.* 
FROM sys.objects so
INNER JOIN sys.partitions sp on so.object_id = sp.object_id
WHERE partition_id = 72057594038779904

Get object name on which DELETE was executed.

Now that we have the LSN for the DELETE transaction, we can recover the deleted data by using one of my other articles Recover deleted SQL Server data and tables with the help of Transaction Log and LSNs.

Doing it all in one step

Let's say we now have the data that was DELETEd in the "Location" table, we can run the following code. This reads the transaction log backup two times. The first time through it gets a list all the Transaction IDs and a count of deleted rows for that transaction. The second time through it will get the user that did the DELETE and when the transaction occurred.

USE ReadingDBLog
GO
WITH CTE
as
       (SELECT [Transaction ID], count(*) as DeletedRows
       FROM fn_dump_dblog (NULL, NULL, N'DISK', 1, N'D:\ReadingDBLog_201503022236.trn',
       DEFAULT, DEFAULT, DEFAULT, DEFAULT, DEFAULT, DEFAULT, DEFAULT, DEFAULT, DEFAULT, DEFAULT, DEFAULT, DEFAULT, DEFAULT, DEFAULT,
       DEFAULT, DEFAULT, DEFAULT, DEFAULT, DEFAULT, DEFAULT, DEFAULT, DEFAULT, DEFAULT, DEFAULT, DEFAULT, DEFAULT, DEFAULT, DEFAULT,
       DEFAULT, DEFAULT, DEFAULT, DEFAULT, DEFAULT, DEFAULT, DEFAULT, DEFAULT, DEFAULT, DEFAULT, DEFAULT, DEFAULT, DEFAULT, DEFAULT,
       DEFAULT, DEFAULT, DEFAULT, DEFAULT, DEFAULT, DEFAULT, DEFAULT, DEFAULT, DEFAULT, DEFAULT, DEFAULT, DEFAULT, DEFAULT, DEFAULT,
       DEFAULT, DEFAULT, DEFAULT, DEFAULT, DEFAULT, DEFAULT, DEFAULT)
       WHERE Operation = ('LOP_DELETE_ROWS')
       AND [PartitionId] = (SELECT sp.partition_id
                            FROM sys.objects so
                            INNER JOIN sys.partitions sp on so.object_id = sp.object_id
                            WHERE name = 'Location')
       GROUP BY [Transaction ID]
       )
SELECT [Current LSN], a.[Transaction ID], [Transaction Name], [Operation], [Begin Time], SUSER_SNAME([TRANSACTION SID]) as LoginName, DeletedRows
FROM fn_dump_dblog (NULL, NULL, N'DISK', 1, N'D:\ReadingDBLog_201503022236.trn',
DEFAULT, DEFAULT, DEFAULT, DEFAULT, DEFAULT, DEFAULT, DEFAULT, DEFAULT, DEFAULT, DEFAULT, DEFAULT, DEFAULT, DEFAULT, DEFAULT,
DEFAULT, DEFAULT, DEFAULT, DEFAULT, DEFAULT, DEFAULT, DEFAULT, DEFAULT, DEFAULT, DEFAULT, DEFAULT, DEFAULT, DEFAULT, DEFAULT,
DEFAULT, DEFAULT, DEFAULT, DEFAULT, DEFAULT, DEFAULT, DEFAULT, DEFAULT, DEFAULT, DEFAULT, DEFAULT, DEFAULT, DEFAULT, DEFAULT,
DEFAULT, DEFAULT, DEFAULT, DEFAULT, DEFAULT, DEFAULT, DEFAULT, DEFAULT, DEFAULT, DEFAULT, DEFAULT, DEFAULT, DEFAULT, DEFAULT,
DEFAULT, DEFAULT, DEFAULT, DEFAULT, DEFAULT, DEFAULT, DEFAULT) as a
INNER JOIN cte on a.[Transaction ID] = cte.[Transaction ID]
WHERE Operation = ('LOP_BEGIN_XACT')

Next Steps

Both undocumented functions "fn_dblog" and "fn_dump_dblog" are very useful and informative. You can use these functions to get a lot of informative data in more than 100 columns. You can look into this and correlate with other data.
Explore more knowledge on SQL Server Database Administration Tips.

Resources

Community

Subscribe