What do we do?

Have you ever run into a database that is in the “In Recovery” state?

If that has happened, have the bosses and/or endusers come to you asking “What do we do?” or “When will it be done?”.  They probably have – it is inevitable.

The question is, what do you do when you run into a database that is in this state?

We all know that it doesn’t help much if we are panicked about the issue – that just feeds the already growing anxiety.  If you feel anxiety – that’s OK, just don’t show that to the endusers or to the boss.  You need to portray to them that you are on top of the issue.

While trying to keep everybody calm and apprised of the situation, you would probably like some assurances for yourself that the database is progressing to a usable state.  That is what I want to share today – a little query that I wrote for this very instance.

Anxiety Tranquilizer

Code block

DECLARE @ErrorLog AS TABLE([LogDate] DATETIME, [ProcessInfo] VARCHAR(64), [TEXT] VARCHAR(MAX))
 
INSERT INTO @ErrorLog
EXEC sys.xp_readerrorlog 0, 1, 'Recovery of database'
 
SELECT  DB_NAME(dt.database_id) AS DBName,GETDATE() AS currenttime, AT.transaction_begin_time
      ,dt.transaction_id,AT.name AS TranName
  ,cx.PercentComplete,cx.MinutesRemaining
      ,d.log_reuse_wait_desc
      ,database_transaction_log_record_count, database_transaction_log_bytes_used
, database_transaction_next_undo_lsn
,CASE AT.transaction_state
WHEN 0 THEN 'Not Completely Initialized'
WHEN 1 THEN 'Initialized but Not Started'
WHEN 2 THEN 'Transaction is Active'
WHEN 3 THEN 'Read-Only tran has Ended'
WHEN 4 THEN 'Distributed Tran commit process has been initiated'
WHEN 5 THEN 'In prepared state and waiting resolution'
WHEN 6 THEN 'Transaction has been committed'
WHEN 7 THEN 'Transaction is being rolled back'
WHEN 8 THEN 'Transaction has been rolled back'
END AS TranState
      FROM sys.dm_tran_database_transactions dt
LEFT OUTER JOIN sys.dm_tran_active_transactions AT
ON dt.transaction_id = AT.transaction_id
INNER JOIN master.sys.databases d
ON d.database_id = dt.database_id
Cross Apply (SELECT TOP 1
 [LogDate]
,SUBSTRING([TEXT], CHARINDEX(') is ', [TEXT]) + 4,CHARINDEX(' complete (', [TEXT]) - CHARINDEX(') is ', [TEXT]) - 4) AS PercentComplete
,CAST(SUBSTRING([TEXT], CHARINDEX('approximately', [TEXT]) + 13,CHARINDEX(' seconds remain', [TEXT]) - CHARINDEX('approximately', [TEXT]) - 13) AS FLOAT)/60.0 AS MinutesRemaining
,DB_NAME(SUBSTRING([TEXT], CHARINDEX('(', [TEXT]) + 1,CHARINDEX(')', [TEXT]) - CHARINDEX('(', [TEXT]) - 1) ) AS DBName
,CAST(SUBSTRING([TEXT], CHARINDEX('(', [TEXT]) + 1,CHARINDEX(')', [TEXT]) - CHARINDEX('(', [TEXT]) - 1) AS INT) AS DBID
FROM @ErrorLog ORDER BY [LogDate] DESC) cx
WHERE d.state_desc <> 'online'
And cx.dbid = dt.database_id

Unfortunately, this query does not demonstrate the time remaining for the rollback nor the percent complete without needing to query the error log.  Those would be awesome additions if you know how to do it (and let me know), other than via the error log.  Thanks to a blog post by Tim Loqua for the base info on querying the error log for the percent complete.

I think the key component on this query is the LEFT OUTER JOIN to sys.dm_tran_active_transactions.  This is essential since the recovery is shown in two transactions.  One transaction is numbered and is the placeholder for the un-numbered transaction where the work is actually being done.  In the numbered transaction, you should see a transaction name of “Recovery Allocation Locks” and nothing for the unnumbered transaction.

Now, unnumbered is not entirely accurate because that transaction has an id of 0, but you will not find a correlating transaction for that in the sys.dm_tran_active_transactions DMV.

The transactions displayed here will be displayed until recovery is complete.  That also means that if you really wanted to, you could create a table to log the recovery process by inserting the results from this query into it.  Then you could revisit the table and examine at closer detail what happened during recovery.

The anxiety killer from this query is to watch two columns in the unnumbered transaction.  These columns are database_transaction_log_record_count and database_transaction_next_undo_lsn.  I rerun the query multiple times throughout the process of recovery.  I check those columns to ensure the data in them is changing.  Changing results in those fields means that you are seeing progress and can provide some comfort by seeing actual progress (even though we know in the back of our head that it is progressing).