Finding a transaction in the log for a particular user

In the last IEHADR class we just had in Chicago, I was doing a demo of looking in the transaction log to find the point at which a table was dropped so a restore could be performed (as described in this blog post). One of the students asked how to find a transaction for a particular user, so I demo’d that and thought it would make a good little post.

This can be done using fn_dblog, or if the relevant log isn’t available on the system any more, using fn_dump_dblog, albeit more slowly.

The two pieces of information needed are the user and the rough time that the transaction occurred.

The user can’t be used to search in the log directly, but every LOP_BEGIN_XACT log record contains the SID of who ran the transaction. The SID can be obtained from the username using the SUSER_SID function (remember that it’s more complicated if someone’s used EXECUTE AS, as that can mask who they really are – details in this post).

For instance, on my laptop:

SELECT SUSER_SID ('APPLECROSS\PAUL') AS [SID];
GO
SID
-----------------------------------------------------------------
0x0105000000000005150000008E888D4129BB677CAA278B76E8030000

Then you can use that SID as a filter for fn_dblog (or fn_dump_dblog), like so:

SELECT
	[Current LSN],
	[Operation],
	[Transaction ID],
	[Begin Time],
	LEFT ([Description], 40) AS [Description]
FROM
	fn_dblog (NULL, NULL)
WHERE
	[Transaction SID] = SUSER_SID ('APPLECROSS\PAUL');
GO
Current LSN             Operation                       Transaction ID Begin Time               Description
----------------------- ------------------------------- -------------- ------------------------ ----------------------------------------
00000021:0000049d:0001  LOP_BEGIN_XACT                  0000:000006c8  2015/06/03 11:18:13:790  Backup:CommitDifferentialBase;0x01050000
00000021:000004a5:0001  LOP_BEGIN_XACT                  0000:000006c9  2015/06/03 11:18:13:810  Backup:CommitLogArchivePoint;0x010500000
00000021:000004a5:0002  LOP_BEGIN_XACT                  0000:000006ca  2015/06/03 11:18:13:810  Backup:CommitLogArchivePoint;0x010500000
00000021:000004a7:0003  LOP_BEGIN_XACT                  0000:000006cb  2015/06/03 11:18:13:820  INSERT;0x0105000000000005150000008e888d4
00000021:000004a7:0004  LOP_BEGIN_XACT                  0000:000006cc  2015/06/03 11:18:13:820  AllocHeapPageSimpleXactDML;0x01050000000
00000021:000004a7:0007  LOP_BEGIN_XACT                  0000:000006cd  2015/06/03 11:18:13:820  AllocFirstPage;0x01050000000000051500000
00000021:000004ad:0002  LOP_BEGIN_XACT                  0000:000006ce  2015/06/03 11:18:13:820  INSERT;0x0105000000000005150000008e888d4
00000021:000004ae:0001  LOP_BEGIN_XACT                  0000:000006cf  2015/06/03 11:18:16:112  INSERT;0x0105000000000005150000008e888d4
00000021:000004af:0001  LOP_BEGIN_XACT                  0000:000006d0  2015/06/03 11:19:17:306  INSERT;0x0105000000000005150000008e888d4
00000021:000004b0:0001  LOP_BEGIN_XACT                  0000:000006d1  2015/06/03 11:22:35:451  DELETE;0x0105000000000005150000008e888d4
00000021:000004b1:0001  LOP_BEGIN_XACT                  0000:000006d2  2015/06/03 11:27:42:998  INSERT;0x0105000000000005150000008e888d4
00000021:000004b2:0001  LOP_BEGIN_XACT                  0000:000006d3  2015/06/03 11:29:56:044  DELETE;0x0105000000000005150000008e888d4

.
.
.

Obviously the transactions above are a contrived example. You can imagine the case of lots of transactions spread out over a few hours (or even over a day, being investigated through log backups with fn_dump_dblog) and to narrow it down to the transaction you want you could look through the list manually for the rough time or specify a time range on the SELECT using predicates on the Begin Time column in the fn_dblog output.

For example:

SELECT
	[Current LSN],
	[Operation],
	[Transaction ID],
	[Begin Time],
	LEFT ([Description], 40) AS [Description]
FROM
	fn_dblog (NULL, NULL)
WHERE
	[Transaction SID] = SUSER_SID ('APPLECROSS\PAUL')
AND ([Begin Time] > '2015/06/03 11:18:15' AND [Begin Time] < '2015/06/03 11:18:25');
GO
Current LSN             Operation                       Transaction ID Begin Time               Description
----------------------- ------------------------------- -------------- ------------------------ ----------------------------------------
00000021:000004ae:0001  LOP_BEGIN_XACT                  0000:000006cf  2015/06/03 11:18:16:112  INSERT;0x0105000000000005150000008e888d4
00000021:000004af:0001  LOP_BEGIN_XACT                  0000:000006d0  2015/06/03 11:19:17:306  INSERT;0x0105000000000005150000008e888d4
00000021:000004b0:0001  LOP_BEGIN_XACT                  0000:000006d1  2015/06/03 11:22:35:451  DELETE;0x0105000000000005150000008e888d4

And if you knew what the operation was, you could narrow it down by the Description too.

Then it’s a simple case of taking the Current LSN of the LOP_BEGIN_XACT log record of the transaction you’re interested in, and restoring a copy of the database using the STOPBEFOREMARK trick (that I showed in my previous post on using this stuff) to restore to a point just before that transaction.

Enjoy!

14 thoughts on “Finding a transaction in the log for a particular user

  1. Hi Paul,

    Thanks for the Nice article.
    I can get user as described in article but how can I get full statement user has executed?

    Thanks,
    Rahul.

  2. The log file is full. I have tried to shrink the log file by changing the recovery model to simple. The log file shrunk to initial size. I have left the recovery model as simple. The log file grew again filling up the whole drive. Now I am not able to reduce the log file size. What should I do to reduce the size of the log?

  3. Hi Paul! Very good article!

    Can I get the SQL server user instead of the windows user on the result? The windows user for me is always the user that runs the sql server daemon.

  4. hey Paul,
    How can we see the command which updated sql log? Like sql log analyzer or apex sql both shows the command.
    I want to copy the commands from log any apply to my mysql instance.
    or can I find only the specific row that is been affected, this row may be in table with index or without index

  5. Can We maintain log in table for DML operation (log details required Statement and user info).
    Can we implement that without using SQL Profile and Audit (inbuilt in SQL server)?
    If yes Please inform me.

Leave a Reply

Your email address will not be published. Required fields are marked *

Other articles

Imagine feeling confident enough to handle whatever your database throws at you.

With training and consulting from SQLskills, you’ll be able to solve big problems, elevate your team’s capacity, and take control of your data career.