The SQL Dude!

Have you ever wondered why a database takes a long time to recover during start-up or when you performed a restore operation? Recovery is a regular part of Database start-up as SQL server has to go through various phases like Analysis, Redo and Undo to bring the database online in a consistent state. But, sometimes you might notice that recovery is taking an awfully long time, which is preventing the DB from coming online and is inaccessible to your users. From SSMS you will notice the DB is showing up as “In Recovery” or “Recovering”. If anyone tries to use the database, you will get this error.

Msg 922, Level 14, State 1, Line 1
Database ‘MyDB1’ is being recovered. Waiting until recovery is finished.

Once a DB is in recovery, there is pretty much nothing you can do to make it go faster. Read the troubleshooting section below if your database is already in the recovery phase.

The SQL Errorlogs will tell you the following information:-

1. The current phase of the DB Recovery process.
2. The % completed in the current phase.
3. Approximate time remaining before it completes this phase.
4. Starting with SQL Server 2008 R2 SP2 and SQL Server 2012 RTM, you will also see the following message if the DB recovery is slow due to large number of Virtual Log Files (VLF’s) present in the transaction log of the database.

Database MyDB1 has more than 1000 virtual log files which is excessive. Too many virtual log files can cause long startup and backup times. Consider shrinking the log and using a different growth increment to reduce the number of virtual log files.

When does a database go into a recovery phase?

1. During SQL Server start/restart and when the database initializes
2. When you restore a database from a backup.
3. When you attach a database.
4. When you have the AUTO_CLOSE property turned ON and the database was shutdown because no users were connected. The next time a connection to this database comes in it will enter the recovery phase (usually this should be very fast, since it would have been cleanly shutdown and recovery shouldn’t have any work to do).

There are many known issues with slow database recovery. If you are facing a slow database start-up or recovery issue, first check the following table to ensure your SQL Server build is equal to or greater than the builds mentioned below (depending on the version of your SQL Server instance).

Known Issues Section

SQL Server 2005

SQL Server 2008

SQL Server 2008 R2

Sample information in the error log about DB recovery

Pre-Recovery
The last message you will see for that database (while in recovery) in the log:
2012-06-26 10:29:20.48 spid58 Starting up database ‘MyDB1’.

Once the pre-recovery has completed, you will see the following message. In this example, it took almost 9 minutes before the following message appeared.
2012-06-26 10:38:23.25 spid58s Analysis of database ‘MyDB1’ (7) is 37% complete (approximately 0 seconds remain). This is an informational message only. No user action is required.

Phase 1: Analysis
2012-06-26 10:58:15.84 spid58s Analysis of database ‘MyDB1’ (7) is 0% complete (approximately 26933 seconds remain). This is an informational message only. No user action is required.
2010-06-26 17:58:10.70 spid58s Analysis of database ‘MyDB1’ (7) is 100% complete (approximately 0 seconds remain). This is an informational message only. No user action is required.

Phase 2: Redo
2012-06-26 17:59:40.16 spid58s Recovery of database ‘MyDB1’ (7) is 1% complete (approximately 1508718 seconds remain). Phase 2 of 3. This is an informational message only. No user action is required.
2012-06-26 18:00:40.17 spid58s Recovery of database ‘MyDB1’ (7) is 1% complete (approximately 1508698 seconds remain). Phase 2 of 3. This is an informational message only. No user action is required. 

Phase 3: Undo
2012-06-26 21:33:41.12 spid58s Recovery of database ‘MyDB1’ (7) is 7% complete

Starting with SQL Server 2008, the error log also prints summary info about time spent in each phase of the recovery.
2012-06-27 12:21:48.29 spid7s Recovery completed for database MYDB1 (database ID 7) in 1 second(s) (analysis 460 ms, redo 0 ms, undo 591 ms.) This is an informational message only. No user action is required.

Troubleshooting Information

I’m not going to re-invent the wheel since this topic has been covered already by folks in the SQL community. You can refer to the following blog posts that explain how to troubleshoot  this issue using DMV’s as well as steps to reduce the VLF’s by shrinking the TLOG file.

1. http://www.sqlskills.com/BLOGS/KIMBERLY/post/Transaction-Log-VLFs-too-many-or-too-few.aspx
2. http://blogs.msdn.com/b/psssql/archive/2010/12/29/tracking-database-recovery-progress-using-information-from-dmv.aspx
3. http://blogs.msdn.com/grahamk/archive/2008/05/09/1413-error-when-starting-database-mirroring-how-many-virtual-log-files-is-too-many.aspx
4. http://blogs.msdn.com/psssql/archive/2009/05/21/how-a-log-file-structure-can-affect-database-recovery-time.aspx
5. http://blogs.msdn.com/psssql/archive/2008/09/12/sql-server-2000-2005-2008-recovery-rollback-taking-longer-than-expected.aspx

Well, that’s all folks! Staying tuned as always for more SQL’lly stuff.

– TheSQLDude