Analyzing SQL database transaction log using sys.fn_dblog( )

We all know that SQL Server transaction logs contains all the information about any changes made to a database and SQL server uses this information for recovery during any roll back.

Sometimes we feel whether we can view information inside the transaction log. Many of us may not be aware that SQL server has provided us some ways to look into the database truncation log. We can use sys.fn_dblog( ) to look into any database log file.

We should remember that sys.fn_dblog() is undocumented hence we need to use it with caution . Also remember sys.fn_dblog( ) can be used to look into only the active portion of the truncation log. So if the log backup is done the log will clear and we can’t use the function to look into the log.  The truncations in the log backups can be viewed using fn_dump_dblog(): which I have discussed in earlier article

Let’s follow the example and explore the sys.fn_dblog( ).

Let’s first Create a new database:

USE [master];

GO

SET NOCOUNT ON;

Go

CREATE DATABASE [TestFNDB];

GO

USE [TestFNDB];

GO

USE [master]

GO

ALTER DATABASE [TestFNDB] SET RECOVERY FULL WITH NO_WAIT

GO

Now Let’s create one tables:

Use [TestFNDB]

GO

CREATE TABLE [ConfigTable] (

    [ValueID] INT IDENTITY,

    [Value] CHAR (25) );

 Let’s insert some records:

INSERT INTO [ConfigTable] ([Value]) VALUES('One');

GO

Verify that the table exists and data are there

 

Now let’s update a record

Update [dbo].[ConfigTable] set Value ='Two' where ValueID=1

Now let’s see how to use fn_dblog()

SELECT

    [Current LSN],

    [Operation],

    [Context],

    [Transaction ID],

       [RowLog Contents 0],

       [RowLog Contents 1],

    [Description]

FROM

    fn_dblog (NULL, NULL),

    (SELECT

        [Transaction ID] AS [trnid]

    FROM

        fn_dblog (NULL, NULL)

    WHERE

        [Transaction Name] LIKE '%UPDATE%') [trnm]

WHERE

    [Transaction ID] = [trnm].[trnid];

My Output:

In the above output the row Operation LOP_MODIFY_ROW contains the actual data values in Column [RowLog Contents 0], [RowLog Contents 1] in varbinary

We need to convert the value in [RowLog Contents 0] (0x4F6E65) to varchar. This gives the original value.

When we convert [RowLog Contents 1] (0x54776F) to varchar. This gives the updated value.

 So using fn_dblog() we were able to explore the database transaction log and look at the value that was updated in one of the table. This was simplified view of the database transaction log since I had only one update running against one table.

You can also get details such as Transaction ID , Transaction SID , Current LSN etc. Use of some of the columns can be done during recovery which I have described in another article for fn_dump_dblog() . Please experimenting with fn_dblog() on your own and share any new things you find.

Hoping the article will be useful.

Using fn_dump_dblog for SQL DB Restore

One of the important responsibility of a DBA is to recover a database to a desirable consistent state. One of the best way to do that in SQL server is to have a good knowledge of backup and restore. Though SQL server provides us a point in time restore option, most of DBAs’ are reluctant to use point in time restore. The main reason being we are never sure till what point of time we need to restore.   We have to rely on the time the Development team provides. Most of the time no one is aware when the problem actually occurred.

To better understand the situation lets analysis the scenario.

Scenario: Some junior developer accidently dropped a table in the database. No one is aware of the timing when the table drop happen. The missing table was discovered next morning. So it will be a real challenge just to find out which log backup to restore, set aside the possibility of point in time restore.

There is actually a way to find out when the drop happens. Once we find when the table drop happened we can then decide whether we want to do a point in time restore or which log backup to restore. 

The solution is available in the undocumented function fn_dump_dblog. Though it is reliable it is still undocumented and should be used with caution.

Now let’s see how to use fn_dump_dblog:

Let’s first Create a new database:

USE [master];

GO

SET NOCOUNT ON;

Go

CREATE DATABASE [TestFNDB];

GO

USE [TestFNDB];

GO

USE [master]

GO

ALTER DATABASE [TestFNDB] SET RECOVERY FULL WITH NO_WAIT

GO

Now Let’s create some tables:

Use [TestFNDB]

GO

CREATE TABLE [ConfigTable] (

    [ValueID] INT IDENTITY,

    [Value] CHAR (25) );

CREATE TABLE [TranTable2] (

    [TranID] INT IDENTITY,

    [Value] CHAR (25) );

GO

Let’s insert some records:

INSERT INTO [ConfigTable] ([Value]) VALUES('ConfData');

GO 10

INSERT INTO [TranTable2] ([Value]) VALUES('TranData');

GO 10

  

Verify that the tables exist and data are there 

Now we simulate that some backups have happened.

BACKUP DATABASE [TestFNDB] TO DISK = N'D:\TestFNDBBackup\TestFNDB_Full.bak' WITH INIT;

GO

BACKUP LOG [TestFNDB] TO DISK = N'D:\TestFNDBBackup\TestFNDB_Log1.trn' WITH INIT;

GO

We are simulating that a Full backup have happened and after that a log backup has happened.

Suppose some more transactions have happened.

INSERT INTO [TranTable2] ([Value]) VALUES('TranData');

GO 10

Now assume by accident someone have dropped a table.

DROP TABLE [ConfigTable];

GO

No one is aware that the table was dropped. Meanwhile series of transactions and log backups have happened.

INSERT INTO [TranTable2] ([Value]) VALUES('TranData');

GO 10

BACKUP LOG [TestFNDB] TO DISK = N'D:\TestFNDBBackup\TestFNDB_Log2.trn' WITH INIT;

GO

INSERT INTO [TranTable2] ([Value]) VALUES('TranData');

GO 10

BACKUP LOG [TestFNDB] TO DISK = N'D:\TestFNDBBackup\TestFNDB_Log3.trn' WITH INIT;

GO

INSERT INTO [TranTable2] ([Value]) VALUES('TranData');

GO 10

BACKUP LOG [TestFNDB] TO DISK = N'D:\TestFNDBBackup\TestFNDB_Log4.trn' WITH INIT;

GO

  

Now suddenly someone realized that the table [ConfigTable] is not available.

Select * from [ConfigTable]

Now no one knows when the table was dropped. So it is not known which log backup needs to be restored.

Now when all the log files are available, fn_dump_dblog() can help us out .

Let see how:

We have the below log files available with us :

D:\TestFNDBBackup\TestFNDB_Log1.trn

D:\TestFNDBBackup\TestFNDB_Log2.trn

D:\TestFNDBBackup\TestFNDB_Log3.trn

D:\TestFNDBBackup\TestFNDB_Log4.trn

We now run the below query with each of the backup files and see if we can find the LSN when the table was dropped. (I am running only for D:\TestFNDBBackup\TestFNDB_Log2.trn)

SELECT

    [Current LSN],

    [Operation],

    [Context],

    [Transaction ID],

       [Transaction SID],

    [Description]

FROM

    fn_dump_dblog (

        NULL, NULL, N'DISK', 1, N'D:\TestFNDBBackup\TestFNDB_Log2.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),

    (SELECT

        [Transaction ID] AS [trnid]

    FROM

        fn_dump_dblog (

            NULL, NULL, N'DISK', 1, N'D:\TestFNDBBackup\TestFNDB_Log2.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 Name] LIKE '%DROPOBJ%') [TrnName]

WHERE [Transaction ID] = [TrnName].[trnid];

GO

My Output:

 

Note the Current LSN: 00000021:00000098:0001

Now we know till which LSN we need to restore.

So let’s recover the table to a new database:

Use Master

GO

RESTORE DATABASE [TestFNDB2]

    FROM DISK = N'D:\TestFNDBBackup\TestFNDB_Full.bak'

WITH

    MOVE N'TestFNDB' TO N'D:\DBFiles\TestFNDB.mdf',

    MOVE N'TestFNDB_log' TO N'D:\DBFiles\TestFNDB_log.ldf',

    REPLACE, NORECOVERY;

GO

 RESTORE LOG [TestFNDB2]

    FROM DISK = N'D:\TestFNDBBackup\TestFNDB_Log1.trn'

WITH

    NORECOVERY;

GO

RESTORE LOG [TestFNDB2]

FROM

    DISK = N'D:\TestFNDBBackup\TestFNDB_Log2.trn'

WITH

    STOPBEFOREMARK = 'lsn:0x00000021:00000098:0001', --- (append with lsn:0x)

    NORECOVERY;

GO

 RESTORE DATABASE [TestFNDB2] WITH RECOVERY;

GO

  

Now we check whether we have got our table back:

Use TestFNDB2

GO

Select * from [ConfigTable]

 

Now that we have recovered the table we can decide whether we want to export the table to the original database or not.

I am sure this might help you while recovering database.

But wait…. Don’t we need to find out who dropped the table in the first place, so that we can prevent such problems in future.

Well that can also be done.

Let’s see the Transaction SID we got above: 0x010500000000000515000000E07B3C4600680018184946173D6F1B00

Execute the query:

USE MASTER

GO  

SELECT SUSER_SNAME(0x010500000000000515000000E07B3C4600680018184946173D6F1B00) As LoginID

 

Hoping this article will help you in recovering your database in an efficient way and also in creating RCA for the problem.