snippetMinor
How to estimate REDO phase time during RESTORE
Viewed 0 times
estimatephaseduringtimehowredorestore
Problem
I am restoring database now and get it hang on 100% but still going (doing redo phase). I am thinking how to estimate time of completion for this phase. But because SQL have no build-in way to do it, I suppose is it possible to count all modified by commited transactions pages from transaction log, multiple it by 8 to get exact space needed to be modified during the redo phase in data file, and estimate completion time by dividing it on your disk subsystem throughtput?
Solution
I am thinking how to estimate time of completion for this phase. But because SQL have no build-in way to do it,
If you have not enabled any trace flag you have no option but to look at DMV
I am restoring database now and get it hang on 100% but still going (doing redo phase).
Are you sure this is the redo phase, I think this is the UNDO phase and depending on how much VLF's are there in database log file the UNDO process can take time. Of course the whole process of restore can further be delayed if Instant file initialization is not there. You can check using This script whether database is having IFI . If not provide SQL Server service account perform volume maintenance tasks rights and this will require a SQL Server service restart
As already pointed by Gameiswar you can enable trace flags to get more information. You can also read Blog by Bob Dorr for more information about internal restore process.
Please note these are undocumented commands so don't enable it on prod servers.. These should be used for testing purpose only
Below is what I got when I restored a database with trace flags enabled
If you have not enabled any trace flag you have no option but to look at DMV
sys.dm_exec_requests and look for column percent_complete to gauge how much your restore operation has completed. Sample script from here SELECT r.session_id,r.command,CONVERT(NUMERIC(6,2),r.percent_complete)
AS [Percent Complete],CONVERT(VARCHAR(20),DATEADD(ms,r.estimated_completion_time,GetDate()),20) AS [ETA Completion Time],
CONVERT(NUMERIC(10,2),r.total_elapsed_time/1000.0/60.0) AS [Elapsed Min],
CONVERT(NUMERIC(10,2),r.estimated_completion_time/1000.0/60.0) AS [ETA Min],
CONVERT(NUMERIC(10,2),r.estimated_completion_time/1000.0/60.0/60.0) AS [ETA Hours],
CONVERT(VARCHAR(1000),(SELECT SUBSTRING(text,r.statement_start_offset/2,
CASE WHEN r.statement_end_offset = -1 THEN 1000 ELSE (r.statement_end_offset-r.statement_start_offset)/2 END)
FROM sys.dm_exec_sql_text(sql_handle)))
FROM sys.dm_exec_requests r WHERE command IN ('RESTORE DATABASE','BACKUP DATABASE')I am restoring database now and get it hang on 100% but still going (doing redo phase).
Are you sure this is the redo phase, I think this is the UNDO phase and depending on how much VLF's are there in database log file the UNDO process can take time. Of course the whole process of restore can further be delayed if Instant file initialization is not there. You can check using This script whether database is having IFI . If not provide SQL Server service account perform volume maintenance tasks rights and this will require a SQL Server service restart
As already pointed by Gameiswar you can enable trace flags to get more information. You can also read Blog by Bob Dorr for more information about internal restore process.
Please note these are undocumented commands so don't enable it on prod servers.. These should be used for testing purpose only
DBCC TRACEON(3004);
DBCC TRACEON(3014);
DBCC TRACEON(3604);
DBCC TRACEON(3605);
GOBelow is what I got when I restored a database with trace flags enabled
RestoreDatabase: Database logicalreads
Opening backup set
Restore: Configuration section loaded
Restore: Backup set is open
Restore: Planning begins
Halting FullText crawls on database logicalreads
Dismounting FullText catalogs
X-locking database: logicalreads
Restore: Planning complete
Restore: BeginRestore (offline) on logicalreads
Restore: PreparingContainers
Restore: Containers are ready
Restore: Restoring backup set
Restore: Transferring data to logicalreads
FileHandleCache: 0 files opened. CacheSize: 12
Restore: Data transfer complete on logicalreads
Processed 168 pages for database 'logicalreads', file 'Logicalreads' on file 1.
Processed 1 pages for database 'logicalreads', file 'Logicalreads_log' on file 1.
Restore: Backup set restored
Restore-Redo begins on database logicalreads
Rollforward complete on database logicalreads
Restore: Done with fixups
Restore: Transitioning database to ONLINE
Restore: Restarting database for ONLINE
Restore: Database is restarted
Resuming any halted fulltext crawls
Restore: Writing history records
Writing backup history records
Restore: Done with MSDB maintenance
RESTORE DATABASE successfully processed 169 pages in 0.159 seconds (8.303 MB/sec).
RestoreDatabase: FinishedCode Snippets
SELECT r.session_id,r.command,CONVERT(NUMERIC(6,2),r.percent_complete)
AS [Percent Complete],CONVERT(VARCHAR(20),DATEADD(ms,r.estimated_completion_time,GetDate()),20) AS [ETA Completion Time],
CONVERT(NUMERIC(10,2),r.total_elapsed_time/1000.0/60.0) AS [Elapsed Min],
CONVERT(NUMERIC(10,2),r.estimated_completion_time/1000.0/60.0) AS [ETA Min],
CONVERT(NUMERIC(10,2),r.estimated_completion_time/1000.0/60.0/60.0) AS [ETA Hours],
CONVERT(VARCHAR(1000),(SELECT SUBSTRING(text,r.statement_start_offset/2,
CASE WHEN r.statement_end_offset = -1 THEN 1000 ELSE (r.statement_end_offset-r.statement_start_offset)/2 END)
FROM sys.dm_exec_sql_text(sql_handle)))
FROM sys.dm_exec_requests r WHERE command IN ('RESTORE DATABASE','BACKUP DATABASE')DBCC TRACEON(3004);
DBCC TRACEON(3014);
DBCC TRACEON(3604);
DBCC TRACEON(3605);
GORestoreDatabase: Database logicalreads
Opening backup set
Restore: Configuration section loaded
Restore: Backup set is open
Restore: Planning begins
Halting FullText crawls on database logicalreads
Dismounting FullText catalogs
X-locking database: logicalreads
Restore: Planning complete
Restore: BeginRestore (offline) on logicalreads
Restore: PreparingContainers
Restore: Containers are ready
Restore: Restoring backup set
Restore: Transferring data to logicalreads
FileHandleCache: 0 files opened. CacheSize: 12
Restore: Data transfer complete on logicalreads
Processed 168 pages for database 'logicalreads', file 'Logicalreads' on file 1.
Processed 1 pages for database 'logicalreads', file 'Logicalreads_log' on file 1.
Restore: Backup set restored
Restore-Redo begins on database logicalreads
Rollforward complete on database logicalreads
Restore: Done with fixups
Restore: Transitioning database to ONLINE
Restore: Restarting database for ONLINE
Restore: Database is restarted
Resuming any halted fulltext crawls
Restore: Writing history records
Writing backup history records
Restore: Done with MSDB maintenance
RESTORE DATABASE successfully processed 169 pages in 0.159 seconds (8.303 MB/sec).
RestoreDatabase: FinishedContext
StackExchange Database Administrators Q#130534, answer score: 2
Revisions (0)
No revisions yet.