Monitor Transaction Log Rollback

I recently had a situation where an index was being updated but the process hung in the middle of the job.  Apparently this isn’t all that far fetched since it appears it has happened to other folks out there (the internet is the best… I rarely have a NEW problem)…

After stopping the query it went into a rollback.  A rollback that wouldn’t end.

How long should the query be rolling back?  How can I tell if the rollback is actually doing something, or is this thing never going to finish?

It turns out you can monitor the bytes reserved in the transaction log during a rollback.  As long as the reserved bytes are getting smaller your transaction rollback is working.

In my case, the rollback was NOT working and the reserved bytes remained flat.  The workaround, unfortunately, was to restart the SQL Server service.

Here’s the simple query to test the reserved bytes:

    select      current_timestamp as tod,
                database_transaction_log_bytes_reserved,
                database_transaction_log_bytes_used
    from  sys.dm_tran_database_transactions
    where transaction_id > 1000
    and database_id = 7 – AdventureWorks
    – and transaction_id = whatever it is…

Just to prove the point, I’ll demonstrate how it works by running a transaction in AdventureWorks.

The first thing I’ll do is setup a query to collect the bytes reserved every 1 second.  The results will be saved to a temp table with the very unique name, #t.

Save Bytes Reservered
create table #t (    tod    datetime
                    , bytes_reserved    int
                    , bytes_used        int )
    
while 1=1
begin    
    insert into #t            
    select      current_timestamp as tod,
                database_transaction_log_bytes_reserved,
                database_transaction_log_bytes_used
    from  sys.dm_tran_database_transactions
    where transaction_id > 1000
    and database_id = 7 – AdventureWorks
    – and transaction_id = whatever it is…
    
    waitfor delay '00:00:01'
end

 

Now I’ll do a little update in AdventureWorks, then rollback the transaction.

Kick off Xaction and Rollback
begin tran

    – 16s
    update Sales.SalesOrderDetail
    set ModifiedDate = CURRENT_TIMESTAMP
    
rollback    – 2 s

 

The update took about 16s to run; followed by a few second pause before I ran the rollback, which took 2 seconds.

Here’s what the result set looks like:

image

 

As the update transaction is running we see the transaction log bytes reserved increasing.  Then there is a delay before I did the rollback… Finally the last two entries shows the reserved bytes decreasing.

Although this tool may not tell you how LONG the ROLLBACK will take place, it will at least tell you that it is in fact ROLLING back and is not “hung”.

You can narrow down the query a bit by adding the transaction ID to ensure you are monitoring the transaction you need to look at.

Stay curious… Keep learning…

Leave a Reply

You must be logged in to post a comment.

Using Gravatars in the comments - get your own and be recognized!

XHTML: These are some of the tags you can use: <a href=""> <b> <blockquote> <code> <em> <i> <strike> <strong>