3

Used this script to restore a full backup (about 30GB of data and 100GB log) on a SQL Server 2012 box:

RESTORE DATABASE [dbname] FROM DISK = N'S:\import\dbname_201505131100.bak' WITH FILE = 1, MOVE N'dbname' TO N'F:\SQL\INST1\DATA\dbname.mdf', MOVE N'dbname_log' TO N'G:\SQL\INST1\LOG\dbname_log.ldf', NOUNLOAD, STATS = 1

98 percent processed. 99 percent processed. 100 percent processed. ... and nothing else for another 20 mins until "RESTORE DATABASE successfully processed...".

All this time, the query window showed "Executing query...", there was no more I/O on the data files drive (F:), but a lot of writing on the log file drive (G:). sys.dm_exec_requests showed percent_complete 100 and status suspended.

Looks like there's no insight into the status of the log file restore. As the log restore takes more that 2 thirds of the total restore time in this scenario, any way to check the progress ?

  • 2
    You can enable 3004 trace flag to see what it's doing. Also you can read about the restore recovery here. How big is the log? – DenisT May 13 '15 at 14:34
  • 100.60 GB. I'll enable that and try it again, thank you. – Razvan Zoitanu May 13 '15 at 14:45
  • DenisT, please feel free to change your comment to an answer and I'll accept it, as it really helped me understand what's going on. According to the SQL Server log: "Restore: Waiting for log zero" followed by "Zeroing completed" after half hour. Instant file initialization doesn't apply to the log file: sqlskills.com/blogs/paul/… – Razvan Zoitanu May 13 '15 at 16:14
  • 1
    I just blogged about getting a little more diagnostics about the restore process yesterday: blogs.sqlsentry.com/aaronbertrand/… - probably won't help you for a restore you're already waiting on, but could be useful to set up those flags before you start it next time. – Aaron Bertrand May 13 '15 at 19:08
3

You can run the following code to see how much longer a backup or a restore will take. It also tells you how long a DBCC checkdb will take and a few other commands as well.

SELECT session_id, command, s.text, start_time, percent_complete, 
CAST(((DATEDIFF(s,start_time,GetDate()))/3600) as varchar) + ' hour(s), '
    + CAST((DATEDIFF(s,start_time,GetDate())%3600)/60 as varchar) + 'min, '
    + CAST((DATEDIFF(s,start_time,GetDate())%60) as varchar) + ' sec' as running_time,
CAST((estimated_completion_time/3600000) as varchar) + ' hour(s), '
    + CAST((estimated_completion_time %3600000)/60000 as varchar) + 'min, '
    + CAST((estimated_completion_time %60000)/1000 as varchar) + ' sec' as est_time_to_go,
dateadd(second,estimated_completion_time/1000, getdate()) as est_completion_time 
FROM sys.dm_exec_requests r
CROSS APPLY sys.dm_exec_sql_text(r.sql_handle) s
  • Thank you Chris, but this doesn't answer the question. I wouldn't rely on these estimates to schedule maintenance windows. In my scenario, the 15 minutes estimate didn't match the real duration, 19 minutes. And then there's the log restore time that's not taken into consideration (script shows percent_complete 100 and est_time_to_go 0, but the restore isn't done, and that adds another half hour or more to the total time). – Razvan Zoitanu May 13 '15 at 15:54

Your Answer

By clicking “Post Your Answer”, you agree to our terms of service, privacy policy and cookie policy

Not the answer you're looking for? Browse other questions tagged or ask your own question.