SQL Clone
SQLServerCentral is supported by Redgate
Log in  ::  Register  ::  Not logged in

When Did That Restore Finish?

I saw this question come across Twitter under the #sqlhelp tag one day and was wondering myself. Someone suggested the default trace, I was thinking msdb.dbo.restorehistory and decided to check.

First I hit Books Online. It notes that the restore_date column means: Date and time of the restore operation. Can be NULL.

Very helpful (hopefully you read the sarcasm). This looks like a CS 101 comment, not very helpful and not detailed. Here’s a Connect item for more detail, and here’s one I submitted for clarification.

OK, time for testing. I first grabbed a copy of AdventureWorks since I assumed it would take at least a minute to restore. I restored a new database as “ADW_3”. It was around a minute and so I checked restorehistory:

USE msdb
SELECT TOP 10 * FROM restorehistory

And I got this:


This was not terribly helpful. At the time I ran this, it was 9:32, so this appears to be the start date/time of the restore.

Then I checked the default trace: ‘

SELECT * FROM ::fn_trace_getinfo(0)

FROM ::fn_trace_gettable('C:\Program Files\Microsoft SQL Server\MSSQL10.MSSQLSERVER\MSSQL\Log\log_54.trc',0)
     INNER JOIN sys.trace_events e
          ON eventclass = trace_event_id
     INNER JOIN sys.trace_categories AS cat
          ON e.category_id = cat.category_id
WHERE databasename = 'ADW_3'

The first query gets the name of the file, which is put into the second query as the file source and that returned a number of results, of which the interesting ones were:


That isn’t terribly helpful either. I was hoping there would be a second event in the default trace, but there isn’t, even 10 minutes later when I checked. (I’m ever optimistic)

Then I thought “wouldn’t recovery run in a restored database? Isn’t that in the error log?”, so I decided to check there and found this:


The “starting up datbaase ‘adw_3’ is likely just after the log file is built and corresponds to a tenth of a second after the restore starts. I suspect the files are created first as part of the restore, but not marked in the error log. Then the database is started, and is marked a “restoring” immediately after.

There is a checkdb informational message, which is the last time that the command was run not on this database, but on the source database that created the backup file (bad, Steve, bad, 8 months old!).

Last we see that just about 6sec later there is the completed restore message.

No duration, but you can calculate that based on the “starting up” message.

Filed under: Blog Tagged: Backup/Recovery, sql server, syndicated

The Voice of the DBA

Steve Jones is the editor of SQLServerCentral.com and visits a wide variety of data related topics in his daily editorial. Steve has spent years working as a DBA and general purpose Windows administrator, primarily working with SQL Server since it was ported from Sybase in 1990. You can follow Steve on Twitter at twitter.com/way0utwest


Posted by Wilfred van Dijk on 1 August 2011

By using sys.dm_exec_requests, you can predict how long a restore will take. See my website (www.wilfredvandijk.nl/20110406_whenready.html) for a T-SQL script about this (it's in dutch, but I will assume you'll understand T-SQL)

Posted by Lars Søe Mikkelsen on 1 August 2011

Using backupset and restorehistory in msdb can give an easy answer:

USE msdb

SELECT TOP 10 rh.destination_database_name, bs.backup_start_date, bs.backup_finish_date

FROM restorehistory rh

JOIN backupset bs ON rh.backup_set_id = bs.backup_set_id

Posted by Lars Søe Mikkelsen on 1 August 2011

I decided to throw in the duration as well (and order by latest):

USE msdb

SELECT TOP 10 rh.destination_database_name, bs.backup_start_date, bs.backup_finish_date, datediff(ss, bs.backup_start_date, bs.backup_finish_date) AS 'duration (in seconds)'

FROM restorehistory rh

JOIN backupset bs ON rh.backup_set_id = bs.backup_set_id

ORDER BY bs.backup_start_date DESC

Posted by lsm on 5 August 2011

If anyone stumbles upon my two last posts, please don't use the script. It's faulty. Sorry.

Posted by SQLVoila on 4 September 2013

Confused by BOL and my test results too. Enlightened by Steve. I came up with this one, which shows the COMPLETION datetime of database restore operation.

-- list database restore COMPLETION datetime

DECLARE @dt_start datetime = GETDATE() - 7 -- 7 days ago for most recent possible restore operation

DECLARE @dt_end datetime = GETDATE()

DECLARE @dbrestored TABLE (logdate datetime, processinfo varchar(25), infotext varchar(500))

INSERT INTO @dbrestored

EXEC xp_readerrorlog 0, 1, N'Restore is complete', N'The database is now available.', @dt_start, @dt_end, 'DESC'

SELECT SUBSTRING(infotext,34, (CHARINDEX ('''', infotext, 34)-34)) AS database_name

, logdate

, infotext

FROM @dbrestored

Leave a Comment

Please register or log in to leave a comment.