Another Dive into Transaction Log File Forensics

 Over the past three years since I first took a look at the insides of a Transaction Log file, I have noticed some more great products to enable forensics such as ApexSQL (which makes the job simple), Lumigent Log Explorer, and other Free tools mentioned below, as well as real world scenarios that describes every step BlackHat.com would perform in the deepest dive.

Why do you care, as a DBA, or a Developer for that matter, about what is happening in the Transaction Log? The raison d’être of a transaction log file is to write all the necessary information we need to recuperate any and all activity happening against the database, hence the interest.  Every SQL Server database must have at least one log file. Here are a few ways to take a brief look what is inside the log file itself:

SELECT * FROM  ::fn_dblog(DEFAULT, DEFAULT) AS l  -- more examples, and details, below

dbcc log(<DatabaseName>, 3)
-- 0 for minimum info, 1 for more, 2 for detailed, 3 full, 4 full+hex

Perhaps you are on auditing project, and your requirement is to be able read the active log files, as well as those that were archived.  The archived logs gave us the option, with the help of third party tools (or thanks to in part the query above), to effectively interrogate the log file as if it were one mega table. The way that Lumigent Log Explorer's documentation describes it: 'to assist you in solving or recovering from problems that may occur in a typical database system' - gets the heart of what could be a potential point-in-time restore.  Nota Bene: Please use Full recovery model if this is your requirement or if you are in doubt (thankfully it's a database model default setting) here are the many reasons why.  

And according to MVP Siddhart Mehta, another free tool is available which can read and display contents of transaction log files - Internals Viewer for SQL Server (IV). The three main components are: Allocation Map, Page Viewer, and Transaction Log Viewer. IV integrates with SSMS and works for both SQL Server 2005 and 2008. The tool is limited, so expect to pay for tools when full functionality is required.

My view is that you may end up with a mystery transaction at one point that no logic can explain, and thus your database integrity is in question - not a place where any DBA wants to be naturally. Empowering yourself to dig into the log file and resolve these types of mysteries is the main point of this post, because you will be able to find out what the values were before/after a change to the database, and who/what application has committed the change, whereas before one typically disregards anomalies for lack of forensic tools and time.  This gives us motivation to ensure that log files are archived, since we're following Erasmus' Adages proverb to 'leave no stone unturned,' with respect to resolving such mysteries.

Given that you can query the log file (you will see transactions as BEGIN_XACT , COMMIT_XACT), it is even therefore possible to raise alerts for undesirable activity, e.g. someone executing data definition language in production. Combined with Database Mail and SQL Server Agent this can be automated too, or in the case of Lumigent Log Explorer, one can configure an alert for each DDL/DML command, which is perhaps useful - to filter out problems in development.  The approach of monitoring objects during manipulation or creation will allow you to take control of an environment progressively and proactively.

Here are a few of the prominent columns you see in the
Transaction Log itself (full list here – Appendix B):

    ABORT_XACT Indicates that a transaction was aborted and rolled back.

    BEGIN_CKPT A checkpoint has begun.

    BEGIN_XACT Indicates the start of a transaction.

    BUF_WRITE Writing to Buffer.

    COMMIT_XACT Indicates that a transaction has committed.

    CREATE_INDEX Creating an index.

    DELETE_ROWS Rows were deleted from a table.

    DELETE_SPLIT A page split has occurred. Rows have moved physically.

    DELTA_SYSIND  SYSINDEXES table has been modified.

    DROP_INDEX Dropping an index.

    END_CKPT Checkpoint has finished.

    EXPUNGE_ROWS row physically expunged from a page, now free for new rows.

    FILE_HDR_MODIF  SQL Server has grown a database file.

    FORGET_XACT Shows that a 2-phase commit transaction was rolled back.

    FORMAT_PAGE  Write a header of a newly allocated database page.

    INSERT_ROWS  Insert a row into a user or system table.

    MARK_DDL Data Definition Language change - table schema was modified.

    MARK_SAVEPOINT designate that an application has issued a 'SAVE TRANSACTION' command.

    MODIFY_COLUMNS  Designates that a row was modified as the result of an Update command.

    MODIFY_HEADER  A new data page created and has initialized the header of that page.

    MODIFY_ROW  Row modification as a result of an Update command.

    PREP_XACT Transaction is in a 2-phase commit protocol.

    SET_BITS Designates that the DBMS modified space allocation bits as the result of allocating a new extent.

    SET_FREE_SPACE  Designates that a previously allocated extent has been returned to the free pool.

    SET_MASK_BITS

    SORT_BEGIN A sort begins with index creation. - SORT_END end of the sorting while creating an index.

    SORT_EXTENT Sorting extents as part of building an index.

    UNDO_DELETE_SPLIT The page split process has been dumped.

    XACT_CKPT during the Checkpoint, open transactions were detected.