Restore process has erratic speed fluctuations

NeMNeM Posts: 25
edited February 16, 2011 9:50AM in SQL Backup Previous Versions
I don't understand why the restore durations are very erratic for the same database, same size, every night.
I know for sure that there is nothing else running on the server at those times that could cause such erratic speed fluctuations.
Could you give me an explanation for this please?

I am running SQLBackup Pro 6.4.0.56

This is the restore sql:

RESTORE DATABASE [MyDB] FROM
VIRTUAL_DEVICE = 'SQLBACKUP_8CD51C4D-7654-415E-8F07-756FEE4A483C',
VIRTUAL_DEVICE = 'SQLBACKUP_8CD51C4D-7654-415E-8F07-756FEE4A483C01',
VIRTUAL_DEVICE = 'SQLBACKUP_8CD51C4D-7654-415E-8F07-756FEE4A483C02'
WITH BUFFERCOUNT = 18, BLOCKSIZE = 65536, MAXTRANSFERSIZE = 1048576 ,RECOVERY,
MOVE 'MyDB_Data' TO 'E:\Data\MyDB_data.mdf',
MOVE 'MyDB_Log' TO 'E:\Log\MyDB_log.ldf',
REPLACE

Here is the output from the restorehistory table:
restore_start restore_end duration [duration hh:mm:ss] size speed (MB/sec)
2/15/11 2:33 2/15/11 4:31 7047 1:57:27 173128097792 17.332
2/14/11 2:36 2/14/11 4:54 8261 2:17:41 173128097792 14.745
2/12/11 2:34 2/12/11 4:41 7644 2:07:24 173128097792 15.945
2/11/11 2:49 2/11/11 4:58 7768 2:09:28 173128097792 15.666
2/10/11 2:41 2/10/11 4:57 8145 2:15:45 173128097792 14.926
2/9/11 2:40 2/9/11 4:51 7829 2:10:29 173128097792 15.526
2/8/11 4:34 2/8/11 6:27 6811 1:53:31 173128097792 17.841
· Share on Twitter

Comments

  • peteypetey Posts: 2,358 New member
    Could you please post the contents of the log for the fastest restore (2/8/11 4:34) and the slowest restore (2/14/11 2:36)?

    The default folder where the logs are stored is C:\Documents and Settings\All Users\Application Data\Red Gate\SQL Backup\Log\<instance name> on Windows 2003 and older, and C:\ProgramData\Red Gate\SQL Backup\Log\<instance name> on Windows Vista and newer.

    Thanks.
    Peter Yeoh
    SQL Backup Consultant Developer
    Associate, Yohz Software
    Beyond compression - SQL Backup goodies under the hood, updated for version 8
    · Share on Twitter
  • NeMNeM Posts: 25
    Thanks petey for your reply. Here are the logs for the slowest and fastest nights.

    Fastest night on Feb 8th:
    SQL Backup log file 6.4.0.56

    -SQL "RESTORE DATABASE [MyDB] FROM DISK = '\\BKUP\Nightly_Full\FULL_(local)_MyDB_20110208_020226.sqb' WITH RECOVERY, MOVE 'MyDB_Data' TO 'E:\Data\MyDB_data.mdf', MOVE 'MyDB_Log' TO 'E:\Log\MyDB_log.ldf', REPLACE, MAILTO_ONERROR = 'dba@email.com', THREADPRIORITY = 6 "
    PROCESSES COMPLETED SUCCESSFULLY

    2/8/2011 4:34:06 AM: Restoring MyDB (database) from:
    2/8/2011 4:34:06 AM: \\BKUP\Nightly_Full\FULL_(local)_MyDB_20110208_020226.sqb

    2/8/2011 4:34:06 AM: RESTORE DATABASE [MyDB] FROM VIRTUAL_DEVICE = 'SQLBACKUP_D0433D67-5A3F-4C91-B97D-AD3C6DE3910F', VIRTUAL_DEVICE = 'SQLBACKUP_D0433D67-5A3F-4C91-B97D-AD3C6DE3910F01', VIRTUAL_DEVICE = 'SQLBACKUP_D0433D67-5A3F-4C91-B97D-AD3C6DE3910F02' WITH BUFFERCOUNT = 18, BLOCKSIZE = 65536, MAXTRANSFERSIZE = 1048576 , RECOVERY, MOVE 'MyDB_Data' TO 'E:\Data\MyDB_data.mdf', MOVE 'MyDB_Log' TO 'E:\Log\MyDB_log.ldf', REPLACE

    2/8/2011 6:27:38 AM: Processed 14817152 pages for database 'MyDB', file 'MyDB_Data' on file 1.
    2/8/2011 6:27:38 AM: Processed 56 pages for database 'MyDB', file 'MyDB_Log' on file 1.
    2/8/2011 6:27:38 AM: RESTORE DATABASE successfully processed 14817208 pages in 6803.218 seconds (17.841 MB/sec).
    2/8/2011 6:27:38 AM: SQL Backup process ended.

    2/8/2011 6:27:38 AM: Deleted msdb entries older than 11/10/2010 6:27:38 AM
    2/8/2011 6:27:38 AM: Deleted local history entries older than 11/10/2010 6:27:38 AM

    Slowest night on Feb 14th:
    SQL Backup log file 6.4.0.56

    -SQL "RESTORE DATABASE [MyDB] FROM DISK = '\\BKUP\Nightly_Full\FULL_(local)_MyDB_20110214_020121.sqb' WITH RECOVERY, MOVE 'MyDB_Data' TO 'E:\Data\MyDB_data.mdf', MOVE 'MyDB_Log' TO 'E:\Log\MyDB_log.ldf', REPLACE, MAILTO_ONERROR = 'dba@email.com', THREADPRIORITY = 6 "
    PROCESSES COMPLETED SUCCESSFULLY

    2/14/2011 2:36:49 AM: Restoring MyDB (database) from:
    2/14/2011 2:36:49 AM: \\BKUP\Nightly_Full\FULL_(local)_MyDB_20110214_020121.sqb

    2/14/2011 2:36:49 AM: RESTORE DATABASE [MyDB] FROM VIRTUAL_DEVICE = 'SQLBACKUP_72110CCA-A1CC-48F6-9145-201A2818C995', VIRTUAL_DEVICE = 'SQLBACKUP_72110CCA-A1CC-48F6-9145-201A2818C99501', VIRTUAL_DEVICE = 'SQLBACKUP_72110CCA-A1CC-48F6-9145-201A2818C99502' WITH BUFFERCOUNT = 18, BLOCKSIZE = 65536, MAXTRANSFERSIZE = 1048576 , RECOVERY, MOVE 'MyDB_Data' TO 'E:\Data\MyDB_data.mdf', MOVE 'MyDB_Log' TO 'E:\Log\MyDB_log.ldf', REPLACE

    2/14/2011 4:54:31 AM: Processed 14865624 pages for database 'MyDB', file 'MyDB_Data' on file 1.
    2/14/2011 4:54:31 AM: Processed 1 pages for database 'MyDB', file 'MyDB_Log' on file 1.
    2/14/2011 4:54:31 AM: RESTORE DATABASE successfully processed 14865625 pages in 8258.624 seconds (14.745 MB/sec).
    2/14/2011 4:54:31 AM: SQL Backup process ended.

    2/14/2011 4:54:32 AM: Deleted msdb entries older than 11/16/2010 4:54:31 AM
    2/14/2011 4:54:32 AM: Deleted local history entries older than 11/16/2010 4:54:31 AM
    · Share on Twitter
  • peteypetey Posts: 2,358 New member
    Thanks for posting the logs.

    If it isn't the CPU load on the server, next best guess would be the network. Since you know the backup file name, would it be possible to copy the file over to the target server and record the time it takes, and then perform the restore using the local copy of the file? This would help to determine

    1. if the network throughput is affecting the restore speed
    2. if it is the load on the server itself that is affecting the restore speed

    Thanks.
    Peter Yeoh
    SQL Backup Consultant Developer
    Associate, Yohz Software
    Beyond compression - SQL Backup goodies under the hood, updated for version 8
    · Share on Twitter
  • NeMNeM Posts: 25
    Thanks for your input petey. I'll try that suggestion. I suspect it might be the network throughput between the 2 servers and not the load on the restore server itself.
    · Share on Twitter
Sign In or Register to comment.