How can we help you today? How can we help you today?
mgjernes
Activity overview Badges (0) Posts (0) Comments (23)

Comments

Sort by recent activity
OK, I managed to force error output from these "hung" restores - it matters in which order one kills the backup processes from SQL Activity Monitor (vs just restarting the SQL Backup service). There is no data in the _bugreport log file for these events, probably because I was just killing the process - it was not "crashing" per se. I found that if I use SQL Activity Monitor to kill the SQL process with the restore command, then the "lead" SQL process in the multi-thread restore chain (the one that shows the restore commands per virtual disk device in the details), I will get logged errors in the SQL Backup Output. I re-attempted my test server (6.4.0.1014) restore of the 30GB database using a fresh, production backup (6.4.0.56, 3 threads, level 4 compression, 256-bit, single file). I killed the restore after 6.5 hours. This time I did not remember to disable a regular log restore job before I initiated the test restore. The first stage of the log restore (different database) hung for the entire time the full restore was "working" and did not resume once I finally killed the full restore (these log restores typically complete in 30 to 50 seconds). As soon as I killed the hung log restore, the job that initiated it went on to its next DB and resumed restoring logs correctly. Below is the output from the error logs of both killed jobs. While these restores were hung up, the SQL activity monitor showed an additional SQBCoreService process per thread of the restore. The properties for these threads (details) were blank, but the CPU use column kept continuously cycling to 5 seconds for each process, while the top level processes - for the initial restore command executed in SSMS and the next level down that detailed the restore per virtual disk - had continuously increasing CPU counts. The top level process for the restore showed as Application="SQL Backup", Status="Runnable", Command="Execute", Wait Type= "MSQL_XP" The virtual disk detailed process listed as "SQBCoreService.exe", "Suspended", "Restore Database", wait type = "BACKUPTHREAD" The "cycling" processes showed as "SQBCoreService.exe", "Suspended", "Restore Database", wait type = "BACKUPIO". In the error output, each restore thread has an API timeout 1125 seconds after the start of the restore process. The log restore that was killed shows the same API timeout errors but only 650 seconds after the start entry for the restore process. The VDI timeout setting on this server is 900. Killed, Full restore log output: -SQL "RESTORE DATABASE [TestDB] FROM DISK = '\\[BackupShare]\ServerName_TestDB_20100810_021022_FULL.sqb' WITH MAILTO = '[alert email]', PASSWORD = 'XXXXXXXXXX', NORECOVERY, DISCONNECT_EXISTING, REPLACE " ERRORS AND WARNINGS 10/08/2010 07:26:03: Restoring TestDB (database) from: 10/08/2010 07:26:03: \\[BackupShare]\ServerName_TestDB_20100810_021022_FULL.sqb 10/08/2010 07:26:03: ALTER DATABASE [TestDB] SET ONLINE RESTORE DATABASE [TestDB] FROM VIRTUAL_DEVICE = 'SQLBACKUP_CBAA31FF-C010-441D-A629-B6129EE428BF', VIRTUAL_DEVICE = 'SQLBACKUP_CBAA31FF-C010-441D-A629-B6129EE428BF01', VIRTUAL_DEVICE = 'SQLBACKUP_CBAA31FF-C010-441D-A629-B6129EE428BF02' WITH BUFFERCOUNT = 18, BLOCKSIZE = 65536, MAXTRANSFERSIZE = 1048576 , NORECOVERY, REPLACE 10/08/2010 07:44:48: Thread 0 error: Process terminated unexpectedly. Error code: -2139684861 (The api was waiting and the timeout interval had elapsed.) 10/08/2010 07:44:48: 10/08/2010 07:44:48: Thread 1 error: Process terminated unexpectedly. Error code: -2139684861 (The api was waiting and the timeout interval had elapsed.) 10/08/2010 07:44:48: 10/08/2010 07:44:48: Thread 2 error: Process terminated unexpectedly. Error code: -2139684861 (The api was waiting and the timeout interval had elapsed.) 10/08/2010 07:44:48: 10/08/2010 13:56:56: SQL error 3013: SQL error 3013: RESTORE DATABASE is terminating abnormally. 10/08/2010 13:56:56: SQL error 3203: SQL error 3203: Read on "SQLBACKUP_CBAA31FF-C010-441D-A629-B6129EE428BF01" failed: 995(The I/O operation has been aborted because of either a thread exit or an application request.) Killed Log restore output: -SQL "RESTORE LOG [TestDB2] FROM DISK = '\\[BackupShare]\ServerName_TestDB2_*_LOG.sqb' WITH ERASEFILES = 14, FILEOPTIONS = 1, MAILTO_ONERRORONLY = '[Alert Email]', PASSWORD = 'XXXXXXXXXX', STANDBY = 'C:\[LocalWorkDir]\UNDO_TestDB2.dat', DISCONNECT_EXISTING, MOVETO = '\\[BackupShare]\LogShipped' " ERRORS AND WARNINGS 10/08/2010 07:30:01: Restoring TestDB2 (transaction logs) from: 10/08/2010 07:30:01: \\VirtualCenter\SQLBackup$\ServerName\ServerName_TestDB2_20100810_072500_LOG.sqb 10/08/2010 07:30:01: ALTER DATABASE [TestDB2] SET ONLINE RESTORE LOG [TestDB2] FROM VIRTUAL_DEVICE = 'SQLBACKUP_906A5990-1291-4D39-9327-5EBACB5BFF7A', VIRTUAL_DEVICE = 'SQLBACKUP_906A5990-1291-4D39-9327-5EBACB5BFF7A01', VIRTUAL_DEVICE = 'SQLBACKUP_906A5990-1291-4D39-9327-5EBACB5BFF7A02' WITH BUFFERCOUNT = 18, BLOCKSIZE = 65536, MAXTRANSFERSIZE = 1048576 , STANDBY = N'C:[LocalWorkDir]\UNDO_TestDB2.dat' 10/08/2010 07:40:51: Thread 0 error: Process terminated unexpectedly. Error code: -2139684861 (The api was waiting and the timeout interval had elapsed.) 10/08/2010 07:40:51: 10/08/2010 07:40:51: Thread 1 error: Process terminated unexpectedly. Error code: -2139684861 (The api was waiting and the timeout interval had elapsed.) 10/08/2010 07:40:51: 10/08/2010 07:40:51: Thread 2 error: Process terminated unexpectedly. Error code: -2139684861 (The api was waiting and the timeout interval had elapsed.) 10/08/2010 07:40:51: 10/08/2010 14:00:17: SQL error 3013: SQL error 3013: RESTORE LOG is terminating abnormally. / comments
  1. Community
  2. SQL Backup Previous Versions
  3. restore time VERY slow (compared to native SQL restore)
OK, I managed to force error output from these "hung" restores - it matters in which order one kills the backup processes from SQL Activity Monitor (vs just restarting the SQL Backup service). The...
0 votes
After the 30GB full restore failure above with 6.4.0.1014, I reverted this test server to 6.4.0.56 and then re-ran the same restore command. It completed successfully in 00:46:37. / comments
  1. Community
  2. SQL Backup Previous Versions
  3. restore time VERY slow (compared to native SQL restore)
After the 30GB full restore failure above with 6.4.0.1014, I reverted this test server to 6.4.0.56 and then re-ran the same restore command. It completed successfully in 00:46:37.
0 votes
It was my post in this thread dated 2010-08-07 09:20 Pacific Daylight Time. Post subject: Slow Restore "Fixed Congrats" premature / comments
  1. Community
  2. SQL Backup Previous Versions
  3. restore time VERY slow (compared to native SQL restore)
It was my post in this thread dated 2010-08-07 09:20 Pacific Daylight Time. Post subject: Slow Restore "Fixed Congrats" premature
0 votes
All RedGate SQL Backup file in all my tests are production backups, all with the same settings from 6.4.0.56: single backup file, 3 threads, compression level 4, 256 bit encryption Full backup command: EXECUTE master..sqlbackup '-SQL "BACKUP DATABASES EXCLUDE [Databas list etc..] TO DISK = ''\\[network resource]\<AUTO>.sqb'' WITH ERASEFILES_ATSTART = 21, MAILTO = ''sql_alerts@archipelago.ca'', PASSWORD = ''<ENCRYPTEDPASSWORD>[pwd]=</ENCRYPTEDPASSWORD>'', DISKRETRYINTERVAL = 120, DISKRETRYCOUNT = 5, COMPRESSION = 4, INIT, KEYSIZE = 256, THREADCOUNT = 3, VERIFY"', @exitcode OUT, @sqlerrorcode OUT / comments
  1. Community
  2. SQL Backup Previous Versions
  3. restore time VERY slow (compared to native SQL restore)
All RedGate SQL Backup file in all my tests are production backups, all with the same settings from 6.4.0.56: single backup file, 3 threads, compression level 4, 256 bit encryption Full backup comm...
0 votes
All of the Red Gate SQL backup files were compressed at level 4 using 3 threads and 256 bit encryption. The temp drive used to hold the backup files for the test restores was on a different local disk set from the SQL data/log files. / comments
  1. Community
  2. SQL Backup Previous Versions
  3. restore time VERY slow (compared to native SQL restore)
All of the Red Gate SQL backup files were compressed at level 4 using 3 threads and 256 bit encryption. The temp drive used to hold the backup files for the test restores was on a different local ...
0 votes
The reported "Compressed By" amount was 97% for the full backup and 92% for the differential. Note: for me, the slower rate for the differential restore with SQL Backup is not really an issue. The faster restore over native backups is great - except in the instances with release 6.4.0.10xx where the larger restore jobs fail to complete. That is the more important issue from my perspective. 6.4.0.56 is working fine for my day to day use - I can get by without the functional LATEST_ALL option until the .10xx "patch" is really ready to go. Thanks for all your efforts! / comments
  1. Community
  2. SQL Backup Previous Versions
  3. restore time VERY slow (compared to native SQL restore)
The reported "Compressed By" amount was 97% for the full backup and 92% for the differential. Note: for me, the slower rate for the differential restore with SQL Backup is not really an issue. The...
0 votes
Well, it appears that my testing was not sufficiently thorough. Release .1014 did resolve the slow restore speed on the smaller databases I used for the testing. However, on a larger database, it hangs up just as did .1001 and .1013. The database in question is about 30GB for the data file. Release 6.4.0.56 can restore this database on my test server in about 45 minutes. In the "In Progress" view of the UI, it reaches 27.3GB restored after about 18 minutes and stays there until the restore completes. With release .1013, the progress halted at 9.1GB restored and stayed there until I killed the job after several hours. With .1014, the reported progress reaches 27.3GB in about the same time as release .56, but then it never finishes either - at least not within the limits of my tolerance [image] I saw this same behaviour with .1014 on this same DB when I tried to restore a very large log backup (after a rebuild of all indexes). The log backup size was 61GB compressed to 9GB (full DB backup was ~90GB). Note to self - enable frequent log backups during reindex next time! The log restore attempt with 6.4.0.1014 ran for over 24 hours before I canned it. I did not attempt that log restore with .56 / comments
  1. Community
  2. SQL Backup Previous Versions
  3. restore time VERY slow (compared to native SQL restore)
Well, it appears that my testing was not sufficiently thorough. Release .1014 did resolve the slow restore speed on the smaller databases I used for the testing. However, on a larger database, it...
0 votes
RE the slow differential restore speed shown in my earlier post: I tried the differential restores again on that same database using new full and diff backups for 6.4.0.56, 6.4.0.1014 and native. I did not get results quite as slow this time, but the RedGate differential restores were less than one third the speed of the native restore - 1.58MB/s vs 5.28MB/s, while the full backups restored at 12 to 15MB/s. Restore log output is shown below. Restore comparison - native SQL vs 6.4.0.56 vs .1014: Test database - data file 1661MB, 324MB free; log file = 2GB, 97% free. Native backup restore: Native Full restore: Processed 186736 pages for database 'TestDB', file 'TestDB_Data' on file 1. Processed 2 pages for database 'TestDB', file 'TestDB_Log' on file 1. RESTORE DATABASE successfully processed 186738 pages in 112.014 seconds (13.656 MB/sec). Native Differential restore: Processed 43432 pages for database 'TestDB', file 'TestDB_Data' on file 2. Processed 3 pages for database 'TestDB', file 'TestDB_log' on file 2. RESTORE DATABASE successfully processed 43435 pages in 67.421 seconds (5.277 MB/sec). RedGate SQL Backup 6.4.0.56 restore: SQL Backup log file 6.4.0.56 (command line) -SQL "restore database [TestDB] from disk='c:\Temp\TestDB_20100803_*_FULL.sqb' with password='XXXXXXXXXX', replace, disconnect_existing, norecovery, LOGTO = 'C:\Bin\SQLBackup_TestDB.Full.0056.log'" PROCESSES COMPLETED SUCCESSFULLY 07/08/2010 09:04:32: Restoring TestDB (database) from: 07/08/2010 09:04:32: c:\Temp\TestDB_20100803_070934_FULL.sqb 07/08/2010 09:04:36: ALTER DATABASE [TestDB] SET ONLINE RESTORE DATABASE [TestDB] FROM VIRTUAL_DEVICE = 'SQLBACKUP_87DC88F8-053B-42E6-9D89-0EAA3E4D2DB6', VIRTUAL_DEVICE = 'SQLBACKUP_87DC88F8-053B-42E6-9D89-0EAA3E4D2DB601', VIRTUAL_DEVICE = 'SQLBACKUP_87DC88F8-053B-42E6-9D89-0EAA3E4D2DB602' WITH BUFFERCOUNT = 18, BLOCKSIZE = 65536, MAXTRANSFERSIZE = 1048576 , NORECOVERY, REPLACE 07/08/2010 09:06:32: Processed 186736 pages for database 'TestDB', file 'TestDB_Data' on file 1. 07/08/2010 09:06:32: Processed 2 pages for database 'TestDB', file 'TestDB_log' on file 1. 07/08/2010 09:06:32: RESTORE DATABASE successfully processed 186738 pages in 97.580 seconds (15.676 MB/sec). 07/08/2010 09:06:32: SQL Backup process ended. SQL Backup log file 6.4.0.56 (command line) -SQL "restore database [TestDB] from disk='c:\Temp\TestDB_20100806_*_DIFF.sqb' with password='XXXXXXXXXX', recovery, LOGTO = 'C:\Bin\SQLBackup_TestDB.Diff.0056.log'" PROCESSES COMPLETED SUCCESSFULLY 07/08/2010 09:06:33: Restoring TestDB (database) from: 07/08/2010 09:06:33: c:\Temp\TestDB_20100806_032331_DIFF.sqb 07/08/2010 09:06:36: RESTORE DATABASE [TestDB] FROM VIRTUAL_DEVICE = 'SQLBACKUP_0E811483-73E1-42AA-BA61-227937D4C03F', VIRTUAL_DEVICE = 'SQLBACKUP_0E811483-73E1-42AA-BA61-227937D4C03F01', VIRTUAL_DEVICE = 'SQLBACKUP_0E811483-73E1-42AA-BA61-227937D4C03F02' WITH BUFFERCOUNT = 18, BLOCKSIZE = 65536, MAXTRANSFERSIZE = 1048576 , RECOVERY 07/08/2010 09:07:56: Processed 11664 pages for database 'TestDB', file 'TestDB_Data' on file 1. 07/08/2010 09:07:56: Processed 1 pages for database 'TestDB', file 'TestDB_log' on file 1. 07/08/2010 09:07:56: RESTORE DATABASE successfully processed 11665 pages in 60.416 seconds (1.581 MB/sec). 07/08/2010 09:07:56: SQL Backup process ended. RedGate SQL Backup 6.4.0.1014 restore: SQL Backup log file 6.4.0.1014 (command line) -SQL "restore database [TestDB] from disk='c:\Temp\TestDB_20100803_*_FULL.sqb' with password='XXXXXXXXXX', replace, disconnect_existing, norecovery, LOGTO = 'C:\Bin\SQLBackup_TestDB.Full.1014.log'" PROCESSES COMPLETED SUCCESSFULLY 07/08/2010 08:53:27: Restoring TestDB (database) from: 07/08/2010 08:53:27: c:\Temp\TestDB_20100803_070934_FULL.sqb 07/08/2010 08:53:31: ALTER DATABASE [TestDB] SET ONLINE RESTORE DATABASE [TestDB] FROM VIRTUAL_DEVICE = 'SQLBACKUP_B9612B26-B07F-43AC-A877-A043D58FB5B9', VIRTUAL_DEVICE = 'SQLBACKUP_B9612B26-B07F-43AC-A877-A043D58FB5B901', VIRTUAL_DEVICE = 'SQLBACKUP_B9612B26-B07F-43AC-A877-A043D58FB5B902' WITH BUFFERCOUNT = 18, BLOCKSIZE = 65536, MAXTRANSFERSIZE = 1048576 , NORECOVERY, REPLACE 07/08/2010 08:55:28: Processed 186736 pages for database 'TestDB', file 'TestDB_Data' on file 1. 07/08/2010 08:55:28: Processed 2 pages for database 'TestDB', file 'TestDB_log' on file 1. 07/08/2010 08:55:28: RESTORE DATABASE successfully processed 186738 pages in 98.510 seconds (15.528 MB/sec). 07/08/2010 08:55:28: SQL Backup process ended. SQL Backup log file 6.4.0.1014 (command line) -SQL "restore database [TestDB] from disk='c:\Temp\TestDB_20100806_*_DIFF.sqb' with password='XXXXXXXXXX', recovery, LOGTO = 'C:\Bin\SQLBackup_TestDB.Diff.1014.log'" PROCESSES COMPLETED SUCCESSFULLY 07/08/2010 08:58:13: Restoring TestDB (database) from: 07/08/2010 08:58:13: c:\Temp\TestDB_20100806_032331_DIFF.sqb 07/08/2010 08:58:17: RESTORE DATABASE [TestDB] FROM VIRTUAL_DEVICE = 'SQLBACKUP_8B61A026-CC88-4D56-AC8A-E3E3F2F48111', VIRTUAL_DEVICE = 'SQLBACKUP_8B61A026-CC88-4D56-AC8A-E3E3F2F4811101', VIRTUAL_DEVICE = 'SQLBACKUP_8B61A026-CC88-4D56-AC8A-E3E3F2F4811102' WITH BUFFERCOUNT = 18, BLOCKSIZE = 65536, MAXTRANSFERSIZE = 1048576 , RECOVERY 07/08/2010 08:59:36: Processed 11664 pages for database 'TestDB', file 'TestDB_Data' on file 1. 07/08/2010 08:59:36: Processed 1 pages for database 'TestDB', file 'TestDB_log' on file 1. 07/08/2010 08:59:36: RESTORE DATABASE successfully processed 11665 pages in 60.264 seconds (1.585 MB/sec). 07/08/2010 08:59:36: SQL Backup process ended. / comments
  1. Community
  2. SQL Backup Previous Versions
  3. restore time VERY slow (compared to native SQL restore)
RE the slow differential restore speed shown in my earlier post: I tried the differential restores again on that same database using new full and diff backups for 6.4.0.56, 6.4.0.1014 and native. ...
0 votes
I have now tested release 6.4.0.1014 as per the download posted above. I am happy to say that the restore speed is now back up to that of 6.4.0.56 AND the LATEST_ALL disk option also works, including from a network folder with many backup files (Full, Diff and Log) per database. Testing results are posted below, both for the extended stored procedure and the command line methods. These are on the same database as per my testing with .1013 posted above, but with a differential backup and newer log files included in the mix. Cheers! Testing results: Test Restore using SQLBackup 6.4.0.1014 extended stored procedure from network source backup files: -SQL "restore database [Database] FROM DISK='\\[FileServer]\[FileShare]\[SQLServer]_[Database]*.sqb' LATEST_ALL WITH password='XXXXXXXXXX', replace, disconnect_existing" PROCESSES COMPLETED SUCCESSFULLY 04/08/2010 15:42:37: Restoring [Database] (database) from: 04/08/2010 15:42:37: \\[FileServer]\[FileShare]\[SQLServer]_[Database]_20100803_070934_FULL.sqb 04/08/2010 15:42:38: ALTER DATABASE [Database] SET ONLINE RESTORE DATABASE [Database] FROM VIRTUAL_DEVICE = 'SQLBACKUP_35C8664A-A3D8-4C43-8D06-D6D2446B1584', VIRTUAL_DEVICE = 'SQLBACKUP_35C8664A-A3D8-4C43-8D06-D6D2446B158401', VIRTUAL_DEVICE = 'SQLBACKUP_35C8664A-A3D8-4C43-8D06-D6D2446B158402' WITH BUFFERCOUNT = 18, BLOCKSIZE = 65536, MAXTRANSFERSIZE = 1048576 , NORECOVERY, REPLACE 04/08/2010 15:44:33: Processed 186736 pages for database '[Database]', file '[Database]_Data' on file 1. 04/08/2010 15:44:33: Processed 2 pages for database '[Database]', file '[Database]_log' on file 1. 04/08/2010 15:44:33: RESTORE DATABASE successfully processed 186738 pages in 98.458 seconds (15.537 MB/sec). 04/08/2010 15:44:33: Restoring [Database] (database) from: 04/08/2010 15:44:33: \\[FileServer]\[FileShare]\[SQLServer]_[Database]_20100804_022321_DIFF.sqb 04/08/2010 15:44:34: RESTORE DATABASE [Database] FROM VIRTUAL_DEVICE = 'SQLBACKUP_AD89F797-AFE1-4F75-8994-3A464CC816BE', VIRTUAL_DEVICE = 'SQLBACKUP_AD89F797-AFE1-4F75-8994-3A464CC816BE01', VIRTUAL_DEVICE = 'SQLBACKUP_AD89F797-AFE1-4F75-8994-3A464CC816BE02' WITH BUFFERCOUNT = 18, BLOCKSIZE = 65536, MAXTRANSFERSIZE = 1048576 , NORECOVERY, REPLACE 04/08/2010 15:45:50: Processed 11536 pages for database '[Database]', file '[Database]_Data' on file 1. 04/08/2010 15:45:50: Processed 1 pages for database '[Database]', file '[Database]_log' on file 1. 04/08/2010 15:45:50: RESTORE DATABASE successfully processed 11537 pages in 60.255 seconds (1.568 MB/sec). 04/08/2010 15:45:50: Restoring [Database] (transaction logs) from: 04/08/2010 15:45:50: \\[FileServer]\[FileShare]\[SQLServer]_[Database]_20100804_073856_LOG.sqb 04/08/2010 15:45:51: RESTORE LOG [Database] FROM VIRTUAL_DEVICE = 'SQLBACKUP_9B22178B-41BA-4BDE-8641-6802D9E94CF1', VIRTUAL_DEVICE = 'SQLBACKUP_9B22178B-41BA-4BDE-8641-6802D9E94CF101', VIRTUAL_DEVICE = 'SQLBACKUP_9B22178B-41BA-4BDE-8641-6802D9E94CF102' WITH BUFFERCOUNT = 18, BLOCKSIZE = 65536, MAXTRANSFERSIZE = 1048576 , NORECOVERY, REPLACE 04/08/2010 15:46:15: Processed 0 pages for database '[Database]', file '[Database]_Data' on file 1. 04/08/2010 15:46:15: Processed 13974 pages for database '[Database]', file '[Database]_log' on file 1. 04/08/2010 15:46:15: RESTORE LOG successfully processed 13974 pages in 4.989 seconds (22.944 MB/sec). 04/08/2010 15:46:15: Restoring [Database] (transaction logs) from: 04/08/2010 15:46:15: \\[FileServer]\[FileShare]\[SQLServer]_[Database]_20100804_103835_LOG.sqb 04/08/2010 15:46:15: RESTORE LOG [Database] FROM VIRTUAL_DEVICE = 'SQLBACKUP_50E44D3E-F8A5-4A73-9882-FE233EC3365F', VIRTUAL_DEVICE = 'SQLBACKUP_50E44D3E-F8A5-4A73-9882-FE233EC3365F01', VIRTUAL_DEVICE = 'SQLBACKUP_50E44D3E-F8A5-4A73-9882-FE233EC3365F02' WITH BUFFERCOUNT = 18, BLOCKSIZE = 65536, MAXTRANSFERSIZE = 1048576 , NORECOVERY, REPLACE 04/08/2010 15:47:04: Processed 0 pages for database '[Database]', file '[Database]_Data' on file 1. 04/08/2010 15:47:04: Processed 41932 pages for database '[Database]', file '[Database]_log' on file 1. 04/08/2010 15:47:04: RESTORE LOG successfully processed 41932 pages in 16.261 seconds (21.124 MB/sec). 04/08/2010 15:47:04: Restoring [Database] (transaction logs) from: 04/08/2010 15:47:04: \\[FileServer]\[FileShare]\[SQLServer]_[Database]_20100804_134115_LOG.sqb 04/08/2010 15:47:04: RESTORE LOG [Database] FROM VIRTUAL_DEVICE = 'SQLBACKUP_BBCE8E8A-834D-4E9E-9DE7-55A5D3E02000', VIRTUAL_DEVICE = 'SQLBACKUP_BBCE8E8A-834D-4E9E-9DE7-55A5D3E0200001', VIRTUAL_DEVICE = 'SQLBACKUP_BBCE8E8A-834D-4E9E-9DE7-55A5D3E0200002' WITH BUFFERCOUNT = 18, BLOCKSIZE = 65536, MAXTRANSFERSIZE = 1048576 , NORECOVERY, REPLACE 04/08/2010 15:47:55: Processed 0 pages for database '[Database]', file '[Database]_Data' on file 1. 04/08/2010 15:47:55: Processed 42036 pages for database '[Database]', file '[Database]_log' on file 1. 04/08/2010 15:47:55: RESTORE LOG successfully processed 42036 pages in 19.833 seconds (17.362 MB/sec). 04/08/2010 15:47:55: Restoring [Database] (transaction logs) from: 04/08/2010 15:47:55: \\[FileServer]\[FileShare]\[SQLServer]_[Database]_20100804_153922_LOG.sqb 04/08/2010 15:47:55: RESTORE LOG [Database] FROM VIRTUAL_DEVICE = 'SQLBACKUP_877033F0-2E6E-412C-AA9A-FD63DC92047C', VIRTUAL_DEVICE = 'SQLBACKUP_877033F0-2E6E-412C-AA9A-FD63DC92047C01', VIRTUAL_DEVICE = 'SQLBACKUP_877033F0-2E6E-412C-AA9A-FD63DC92047C02' WITH BUFFERCOUNT = 18, BLOCKSIZE = 65536, MAXTRANSFERSIZE = 1048576 , RECOVERY, REPLACE 04/08/2010 15:48:46: Processed 0 pages for database '[Database]', file '[Database]_Data' on file 1. 04/08/2010 15:48:46: Processed 28205 pages for database '[Database]', file '[Database]_log' on file 1. 04/08/2010 15:48:46: RESTORE LOG successfully processed 28205 pages in 6.942 seconds (33.282 MB/sec). 04/08/2010 15:48:46: SQL Backup process ended. TEST SCRIPT to compare performance of .1014 vs .56 via Command Line. Same database as above. SQLBackupC.6.4.0.56.exe -SQL "restore database [Database] from disk='c:\Temp\[SQLServer]_[Database]_20100803_070934_FULL.sqb' with password='XXXXXXXXXX', REPLACE, DISCONNECT_EXISTING, NORECOVERY, LOGTO = 'C:\Bin\SQLBackup_[Database]Restore.1.0056.log'" SQLBackupC.6.4.0.56.exe -SQL "restore database [Database] from disk='c:\Temp\[SQLServer]_[Database]_20100804_022321_DIFF.sqb' with password='XXXXXXXXXX', NORECOVERY, LOGTO = 'C:\Bin\SQLBackup_[Database]Restore.2.0056.log'" SQLBackupC.6.4.0.56.exe -SQL "restore LOG [Database] from disk='c:\Temp\[SQLServer]_[Database]_20100804_*_LOG.sqb' with password='XXXXXXXXXX', RECOVERY, LOGTO = 'C:\Bin\SQLBackup_[Database]Restore.3.0056.log'" SQLBackupC.6.4.0.1014.exe -SQL "restore database [Database] from disk='c:\Temp\[SQLServer]_[Database]_*.sqb' LATEST_ALL with password='XXXXXXXXXX', REPLACE, DISCONNECT_EXISTING, LOGTO = 'C:\Bin\SQLBackup_[Database]Restore.1.1014.log'" Results from test script: SQL Backup log file 6.4.0.56 (command line) -SQL "restore database [Database] from disk='c:\Temp\[SQLServer]_[Database]_20100803_070934_FULL.sqb' with password='XXXXXXXXXX', REPLACE, DISCONNECT_EXISTING, NORECOVERY, LOGTO = 'C:\Bin\SQLBackup_[Database]Restore.1.0056.log'" PROCESSES COMPLETED SUCCESSFULLY 04/08/2010 16:04:35: Restoring [Database] (database) from: 04/08/2010 16:04:35: c:\Temp\[SQLServer]_[Database]_20100803_070934_FULL.sqb 04/08/2010 16:04:39: ALTER DATABASE [Database] SET ONLINE RESTORE DATABASE [Database] FROM VIRTUAL_DEVICE = 'SQLBACKUP_2BB89EA4-F01A-4E21-BB94-EE70B056604F', VIRTUAL_DEVICE = 'SQLBACKUP_2BB89EA4-F01A-4E21-BB94-EE70B056604F01', VIRTUAL_DEVICE = 'SQLBACKUP_2BB89EA4-F01A-4E21-BB94-EE70B056604F02' WITH BUFFERCOUNT = 18, BLOCKSIZE = 65536, MAXTRANSFERSIZE = 1048576 , NORECOVERY, REPLACE 04/08/2010 16:06:36: Processed 186736 pages for database '[Database]', file '[Database]_Data' on file 1. 04/08/2010 16:06:36: Processed 2 pages for database '[Database]', file '[Database]_log' on file 1. 04/08/2010 16:06:36: RESTORE DATABASE successfully processed 186738 pages in 98.119 seconds (15.590 MB/sec). 04/08/2010 16:06:36: SQL Backup process ended. SQL Backup log file 6.4.0.56 (command line) -SQL "restore database [Database] from disk='c:\Temp\[SQLServer]_[Database]_20100804_022321_DIFF.sqb' with password='XXXXXXXXXX', NORECOVERY, LOGTO = 'C:\Bin\SQLBackup_[Database]Restore.2.0056.log'" PROCESSES COMPLETED SUCCESSFULLY 04/08/2010 16:06:37: Restoring [Database] (database) from: 04/08/2010 16:06:37: c:\Temp\[SQLServer]_[Database]_20100804_022321_DIFF.sqb 04/08/2010 16:06:40: RESTORE DATABASE [Database] FROM VIRTUAL_DEVICE = 'SQLBACKUP_CA11A2B4-8737-4F23-940B-896137A745D2', VIRTUAL_DEVICE = 'SQLBACKUP_CA11A2B4-8737-4F23-940B-896137A745D201', VIRTUAL_DEVICE = 'SQLBACKUP_CA11A2B4-8737-4F23-940B-896137A745D202' WITH BUFFERCOUNT = 18, BLOCKSIZE = 65536, MAXTRANSFERSIZE = 1048576 , NORECOVERY 04/08/2010 16:07:55: Processed 11536 pages for database '[Database]', file '[Database]_Data' on file 1. 04/08/2010 16:07:55: Processed 1 pages for database '[Database]', file '[Database]_log' on file 1. 04/08/2010 16:07:55: RESTORE DATABASE successfully processed 11537 pages in 60.554 seconds (1.560 MB/sec). 04/08/2010 16:07:55: SQL Backup process ended. SQL Backup log file 6.4.0.56 (command line) -SQL "restore LOG [Database] from disk='c:\Temp\[SQLServer]_[Database]_20100804_*_LOG.sqb' with password='XXXXXXXXXX', RECOVERY, LOGTO = 'C:\Bin\SQLBackup_[Database]Restore.3.0056.log'" PROCESSES COMPLETED SUCCESSFULLY 04/08/2010 16:08:04: Processing log group 210471245 ... 04/08/2010 16:08:04: c:\Temp\[SQLServer]_[Database]_20100804_073856_LOG.sqb 04/08/2010 16:08:04: Restoring [Database] (transaction logs) from: 04/08/2010 16:08:04: c:\Temp\[SQLServer]_[Database]_20100804_073856_LOG.sqb 04/08/2010 16:08:07: RESTORE LOG [Database] FROM VIRTUAL_DEVICE = 'SQLBACKUP_A21D4DE8-6800-4BBC-9F2A-0497674C1158', VIRTUAL_DEVICE = 'SQLBACKUP_A21D4DE8-6800-4BBC-9F2A-0497674C115801', VIRTUAL_DEVICE = 'SQLBACKUP_A21D4DE8-6800-4BBC-9F2A-0497674C115802' WITH BUFFERCOUNT = 18, BLOCKSIZE = 65536, MAXTRANSFERSIZE = 1048576 , NORECOVERY 04/08/2010 16:08:29: Processed 0 pages for database '[Database]', file '[Database]_Data' on file 1. 04/08/2010 16:08:29: Processed 13974 pages for database '[Database]', file '[Database]_log' on file 1. 04/08/2010 16:08:29: RESTORE LOG successfully processed 13974 pages in 3.178 seconds (36.019 MB/sec). 04/08/2010 16:08:29: Processing log group 165162333 ... 04/08/2010 16:08:29: c:\Temp\[SQLServer]_[Database]_20100804_103835_LOG.sqb 04/08/2010 16:08:29: Restoring [Database] (transaction logs) from: 04/08/2010 16:08:29: c:\Temp\[SQLServer]_[Database]_20100804_103835_LOG.sqb 04/08/2010 16:08:32: RESTORE LOG [Database] FROM VIRTUAL_DEVICE = 'SQLBACKUP_C3EF94BB-6314-44A6-BE54-B37A3AD09A24', VIRTUAL_DEVICE = 'SQLBACKUP_C3EF94BB-6314-44A6-BE54-B37A3AD09A2401', VIRTUAL_DEVICE = 'SQLBACKUP_C3EF94BB-6314-44A6-BE54-B37A3AD09A2402' WITH BUFFERCOUNT = 18, BLOCKSIZE = 65536, MAXTRANSFERSIZE = 1048576 , NORECOVERY 04/08/2010 16:09:14: Processed 0 pages for database '[Database]', file '[Database]_Data' on file 1. 04/08/2010 16:09:14: Processed 41932 pages for database '[Database]', file '[Database]_log' on file 1. 04/08/2010 16:09:14: RESTORE LOG successfully processed 41932 pages in 9.984 seconds (34.405 MB/sec). 04/08/2010 16:09:15: Processing log group 133458397 ... 04/08/2010 16:09:15: c:\Temp\[SQLServer]_[Database]_20100804_134115_LOG.sqb 04/08/2010 16:09:15: Restoring [Database] (transaction logs) from: 04/08/2010 16:09:15: c:\Temp\[SQLServer]_[Database]_20100804_134115_LOG.sqb 04/08/2010 16:09:18: RESTORE LOG [Database] FROM VIRTUAL_DEVICE = 'SQLBACKUP_C3456961-FB03-4E83-A77B-455C43DD2F0D', VIRTUAL_DEVICE = 'SQLBACKUP_C3456961-FB03-4E83-A77B-455C43DD2F0D01', VIRTUAL_DEVICE = 'SQLBACKUP_C3456961-FB03-4E83-A77B-455C43DD2F0D02' WITH BUFFERCOUNT = 18, BLOCKSIZE = 65536, MAXTRANSFERSIZE = 1048576 , NORECOVERY 04/08/2010 16:09:55: Processed 0 pages for database '[Database]', file '[Database]_Data' on file 1. 04/08/2010 16:09:55: Processed 42036 pages for database '[Database]', file '[Database]_log' on file 1. 04/08/2010 16:09:55: RESTORE LOG successfully processed 42036 pages in 9.835 seconds (35.013 MB/sec). 04/08/2010 16:09:55: Processing log group 206690717 ... 04/08/2010 16:09:55: c:\Temp\[SQLServer]_[Database]_20100804_153922_LOG.sqb 04/08/2010 16:09:55: Restoring [Database] (transaction logs) from: 04/08/2010 16:09:55: c:\Temp\[SQLServer]_[Database]_20100804_153922_LOG.sqb 04/08/2010 16:09:58: RESTORE LOG [Database] FROM VIRTUAL_DEVICE = 'SQLBACKUP_5B6310D2-2A0F-4271-BC25-1198A29C3BEC', VIRTUAL_DEVICE = 'SQLBACKUP_5B6310D2-2A0F-4271-BC25-1198A29C3BEC01', VIRTUAL_DEVICE = 'SQLBACKUP_5B6310D2-2A0F-4271-BC25-1198A29C3BEC02' WITH BUFFERCOUNT = 18, BLOCKSIZE = 65536, MAXTRANSFERSIZE = 1048576 , RECOVERY 04/08/2010 16:11:20: Processed 0 pages for database '[Database]', file '[Database]_Data' on file 1. 04/08/2010 16:11:20: Processed 28205 pages for database '[Database]', file '[Database]_log' on file 1. 04/08/2010 16:11:20: RESTORE LOG successfully processed 28205 pages in 6.691 seconds (34.531 MB/sec). 04/08/2010 16:11:20: SQL Backup process ended. SQL Backup log file 6.4.0.1014 (command line) -SQL "restore database [Database] from disk='c:\Temp\[SQLServer]_[Database]_*.sqb' LATEST_ALL with password='XXXXXXXXXX', REPLACE, DISCONNECT_EXISTING, LOGTO = 'C:\Bin\SQLBackup_[Database]Restore.1.1014.log'" PROCESSES COMPLETED SUCCESSFULLY 04/08/2010 16:11:51: Restoring [Database] (database) from: 04/08/2010 16:11:51: c:\Temp\[SQLServer]_[Database]_20100803_070934_FULL.sqb 04/08/2010 16:11:55: ALTER DATABASE [Database] SET ONLINE RESTORE DATABASE [Database] FROM VIRTUAL_DEVICE = 'SQLBACKUP_D51ECAD6-FBF8-4053-829A-20DABF4BF823', VIRTUAL_DEVICE = 'SQLBACKUP_D51ECAD6-FBF8-4053-829A-20DABF4BF82301', VIRTUAL_DEVICE = 'SQLBACKUP_D51ECAD6-FBF8-4053-829A-20DABF4BF82302' WITH BUFFERCOUNT = 18, BLOCKSIZE = 65536, MAXTRANSFERSIZE = 1048576 , NORECOVERY, REPLACE 04/08/2010 16:14:12: Processed 186736 pages for database '[Database]', file '[Database]_Data' on file 1. 04/08/2010 16:14:12: Processed 2 pages for database '[Database]', file '[Database]_log' on file 1. 04/08/2010 16:14:12: RESTORE DATABASE successfully processed 186738 pages in 100.350 seconds (15.244 MB/sec). 04/08/2010 16:14:12: Restoring [Database] (database) from: 04/08/2010 16:14:12: c:\Temp\[SQLServer]_[Database]_20100804_022321_DIFF.sqb 04/08/2010 16:14:15: RESTORE DATABASE [Database] FROM VIRTUAL_DEVICE = 'SQLBACKUP_A9D33290-6282-4462-ADB7-B550595F3E7A', VIRTUAL_DEVICE = 'SQLBACKUP_A9D33290-6282-4462-ADB7-B550595F3E7A01', VIRTUAL_DEVICE = 'SQLBACKUP_A9D33290-6282-4462-ADB7-B550595F3E7A02' WITH BUFFERCOUNT = 18, BLOCKSIZE = 65536, MAXTRANSFERSIZE = 1048576 , NORECOVERY, REPLACE 04/08/2010 16:15:45: Processed 11536 pages for database '[Database]', file '[Database]_Data' on file 1. 04/08/2010 16:15:45: Processed 1 pages for database '[Database]', file '[Database]_log' on file 1. 04/08/2010 16:15:45: RESTORE DATABASE successfully processed 11537 pages in 61.936 seconds (1.525 MB/sec). 04/08/2010 16:15:54: Processing log group 210471245 ... 04/08/2010 16:15:54: c:\Temp\[SQLServer]_[Database]_20100804_073856_LOG.sqb 04/08/2010 16:15:54: Restoring [Database] (transaction logs) from: 04/08/2010 16:15:54: c:\Temp\[SQLServer]_[Database]_20100804_073856_LOG.sqb 04/08/2010 16:15:57: RESTORE LOG [Database] FROM VIRTUAL_DEVICE = 'SQLBACKUP_58885327-13A2-4212-99F1-8908FFA34B40', VIRTUAL_DEVICE = 'SQLBACKUP_58885327-13A2-4212-99F1-8908FFA34B4001', VIRTUAL_DEVICE = 'SQLBACKUP_58885327-13A2-4212-99F1-8908FFA34B4002' WITH BUFFERCOUNT = 18, BLOCKSIZE = 65536, MAXTRANSFERSIZE = 1048576 , NORECOVERY, REPLACE 04/08/2010 16:16:31: Processed 0 pages for database '[Database]', file '[Database]_Data' on file 1. 04/08/2010 16:16:31: Processed 13974 pages for database '[Database]', file '[Database]_log' on file 1. 04/08/2010 16:16:31: RESTORE LOG successfully processed 13974 pages in 3.447 seconds (33.208 MB/sec). 04/08/2010 16:16:31: Processing log group 165162333 ... 04/08/2010 16:16:31: c:\Temp\[SQLServer]_[Database]_20100804_103835_LOG.sqb 04/08/2010 16:16:31: Restoring [Database] (transaction logs) from: 04/08/2010 16:16:31: c:\Temp\[SQLServer]_[Database]_20100804_103835_LOG.sqb 04/08/2010 16:16:34: RESTORE LOG [Database] FROM VIRTUAL_DEVICE = 'SQLBACKUP_40954DD7-57DD-434D-B7CB-8D038C843D6D', VIRTUAL_DEVICE = 'SQLBACKUP_40954DD7-57DD-434D-B7CB-8D038C843D6D01', VIRTUAL_DEVICE = 'SQLBACKUP_40954DD7-57DD-434D-B7CB-8D038C843D6D02' WITH BUFFERCOUNT = 18, BLOCKSIZE = 65536, MAXTRANSFERSIZE = 1048576 , NORECOVERY, REPLACE 04/08/2010 16:17:51: Processed 0 pages for database '[Database]', file '[Database]_Data' on file 1. 04/08/2010 16:17:51: Processed 41932 pages for database '[Database]', file '[Database]_log' on file 1. 04/08/2010 16:17:51: RESTORE LOG successfully processed 41932 pages in 10.607 seconds (32.384 MB/sec). 04/08/2010 16:17:51: Processing log group 133458397 ... 04/08/2010 16:17:51: c:\Temp\[SQLServer]_[Database]_20100804_134115_LOG.sqb 04/08/2010 16:17:51: Restoring [Database] (transaction logs) from: 04/08/2010 16:17:51: c:\Temp\[SQLServer]_[Database]_20100804_134115_LOG.sqb 04/08/2010 16:17:54: RESTORE LOG [Database] FROM VIRTUAL_DEVICE = 'SQLBACKUP_BC97D72C-E00F-4EB0-810C-141DED6AFE2D', VIRTUAL_DEVICE = 'SQLBACKUP_BC97D72C-E00F-4EB0-810C-141DED6AFE2D01', VIRTUAL_DEVICE = 'SQLBACKUP_BC97D72C-E00F-4EB0-810C-141DED6AFE2D02' WITH BUFFERCOUNT = 18, BLOCKSIZE = 65536, MAXTRANSFERSIZE = 1048576 , NORECOVERY, REPLACE 04/08/2010 16:19:08: Processed 0 pages for database '[Database]', file '[Database]_Data' on file 1. 04/08/2010 16:19:08: Processed 42036 pages for database '[Database]', file '[Database]_log' on file 1. 04/08/2010 16:19:08: RESTORE LOG successfully processed 42036 pages in 10.443 seconds (32.975 MB/sec). 04/08/2010 16:19:08: Processing log group 206690717 ... 04/08/2010 16:19:08: c:\Temp\[SQLServer]_[Database]_20100804_153922_LOG.sqb 04/08/2010 16:19:08: Restoring [Database] (transaction logs) from: 04/08/2010 16:19:08: c:\Temp\[SQLServer]_[Database]_20100804_153922_LOG.sqb 04/08/2010 16:19:11: RESTORE LOG [Database] FROM VIRTUAL_DEVICE = 'SQLBACKUP_25131E2A-EAF3-4B7A-BBF2-5746EE38942C', VIRTUAL_DEVICE = 'SQLBACKUP_25131E2A-EAF3-4B7A-BBF2-5746EE38942C01', VIRTUAL_DEVICE = 'SQLBACKUP_25131E2A-EAF3-4B7A-BBF2-5746EE38942C02' WITH BUFFERCOUNT = 18, BLOCKSIZE = 65536, MAXTRANSFERSIZE = 1048576 , RECOVERY, REPLACE 04/08/2010 16:20:30: Processed 0 pages for database '[Database]', file '[Database]_Data' on file 1. 04/08/2010 16:20:30: Processed 28205 pages for database '[Database]', file '[Database]_log' on file 1. 04/08/2010 16:20:30: RESTORE LOG successfully processed 28205 pages in 6.781 seconds (34.072 MB/sec). 04/08/2010 16:20:30: SQL Backup process ended. / comments
  1. Community
  2. SQL Backup Previous Versions
  3. restore time VERY slow (compared to native SQL restore)
I have now tested release 6.4.0.1014 as per the download posted above. I am happy to say that the restore speed is now back up to that of 6.4.0.56 AND the LATEST_ALL disk option also works, includ...
0 votes
I have encountered a similar issue with 6.4.0.1013 - which I am using to fix the LATEST_ALL skipped log file bug with 6.4.0.56. The 1013 release seems to slow down more as a restore job goes on. I did several restores today. The first was not too bad, but the second was much slower and I had to cancel the 3rd after 4 hours for a 9GB database. I ran the restore on that same 9GB database using the .56 command line version and it completed in 11 minutes. Both were from a network backup file. I noticed the same performance problem when testing with 6.4.0.1001, but I do not have any saved data to back that up. Below are some tests done using .1013 vs .56 on the same database, same server, same backup files, this time from a local file location. The SQL server was not doing anything else at the time. The test server here is rather old and slow, but still... I did notice that .56 seems to maintain a higher, average CPU utilization than the slower restores with .1013. Test data: - Database size: 3.5GB - All backups created on production server using SQLBackup 6.4.0.56 - compression level 4, 256-bit encryption, 3 backup threads - backups copied locally to the test server for these restore attempts, separate physical disk from SQL disks. SQL Backup log file 6.4.0.1013 -SQL "restore database [DBName] from disk='c:\Temp\[SeverName]_[DBName]_20100803_*.sqb' LATEST_ALL with password='XXXXXXXXXX', REPLACE, DISCONNECT_EXISTING, RECOVERY, LOGTO = 'C:\Bin\SQLBackup_[DBName]FullRestore.SQL1.1013.log', mailto='mikeg@archipelago.ca' " PROCESSES COMPLETED SUCCESSFULLY 03/08/2010 18:41:41: Restoring [DBName] (database) from: 03/08/2010 18:41:41: c:\Temp\[SeverName]_[DBName]_20100803_070934_FULL.sqb 03/08/2010 18:41:42: ALTER DATABASE [DBName] SET ONLINE RESTORE DATABASE [DBName] FROM VIRTUAL_DEVICE = 'SQLBACKUP_EFDF9783-3F78-4D75-901B-DBE17941BCBF', VIRTUAL_DEVICE = 'SQLBACKUP_EFDF9783-3F78-4D75-901B-DBE17941BCBF01', VIRTUAL_DEVICE = 'SQLBACKUP_EFDF9783-3F78-4D75-901B-DBE17941BCBF02' WITH BUFFERCOUNT = 18, BLOCKSIZE = 65536, MAXTRANSFERSIZE = 1048576 , NORECOVERY, REPLACE 03/08/2010 18:44:58: Processed 186736 pages for database '[DBName]', file '[DBName]_Data' on file 1. 03/08/2010 18:44:58: Processed 2 pages for database '[DBName]', file '[DBName]_log' on file 1. 03/08/2010 18:44:58: RESTORE DATABASE successfully processed 186738 pages in 173.308 seconds (8.826 MB/sec). 03/08/2010 18:44:58: Restoring [DBName] (transaction logs) from: 03/08/2010 18:44:58: c:\Temp\[SeverName]_[DBName]_20100803_074115_LOG.sqb 03/08/2010 18:44:58: RESTORE LOG [DBName] FROM VIRTUAL_DEVICE = 'SQLBACKUP_138BE1AD-A187-4F6E-AEDF-788229F19C91', VIRTUAL_DEVICE = 'SQLBACKUP_138BE1AD-A187-4F6E-AEDF-788229F19C9101', VIRTUAL_DEVICE = 'SQLBACKUP_138BE1AD-A187-4F6E-AEDF-788229F19C9102' WITH BUFFERCOUNT = 18, BLOCKSIZE = 65536, MAXTRANSFERSIZE = 1048576 , NORECOVERY, REPLACE 03/08/2010 18:47:18: Processed 0 pages for database '[DBName]', file '[DBName]_Data' on file 1. 03/08/2010 18:47:18: Processed 13836 pages for database '[DBName]', file '[DBName]_log' on file 1. 03/08/2010 18:47:18: RESTORE LOG successfully processed 13836 pages in 81.170 seconds (1.396 MB/sec). 03/08/2010 18:47:18: Restoring [DBName] (transaction logs) from: 03/08/2010 18:47:18: c:\Temp\[SeverName]_[DBName]_20100803_103826_LOG.sqb 03/08/2010 18:47:18: RESTORE LOG [DBName] FROM VIRTUAL_DEVICE = 'SQLBACKUP_C2F3D067-D704-4C06-A488-FE5C482DE7E7', VIRTUAL_DEVICE = 'SQLBACKUP_C2F3D067-D704-4C06-A488-FE5C482DE7E701', VIRTUAL_DEVICE = 'SQLBACKUP_C2F3D067-D704-4C06-A488-FE5C482DE7E702' WITH BUFFERCOUNT = 18, BLOCKSIZE = 65536, MAXTRANSFERSIZE = 1048576 , NORECOVERY, REPLACE 03/08/2010 19:10:40: Processed 0 pages for database '[DBName]', file '[DBName]_Data' on file 1. 03/08/2010 19:10:40: Processed 41491 pages for database '[DBName]', file '[DBName]_log' on file 1. 03/08/2010 19:10:40: RESTORE LOG successfully processed 41491 pages in 1329.247 seconds (0.255 MB/sec). 03/08/2010 19:10:40: Restoring [DBName] (transaction logs) from: 03/08/2010 19:10:40: c:\Temp\[SeverName]_[DBName]_20100803_133835_LOG.sqb 03/08/2010 19:10:41: RESTORE LOG [DBName] FROM VIRTUAL_DEVICE = 'SQLBACKUP_D588B70C-8F50-483C-A786-236D9B2E520F', VIRTUAL_DEVICE = 'SQLBACKUP_D588B70C-8F50-483C-A786-236D9B2E520F01', VIRTUAL_DEVICE = 'SQLBACKUP_D588B70C-8F50-483C-A786-236D9B2E520F02' WITH BUFFERCOUNT = 18, BLOCKSIZE = 65536, MAXTRANSFERSIZE = 1048576 , RECOVERY, REPLACE 03/08/2010 19:34:32: Processed 0 pages for database '[DBName]', file '[DBName]_Data' on file 1. 03/08/2010 19:34:32: Processed 41654 pages for database '[DBName]', file '[DBName]_log' on file 1. 03/08/2010 19:34:32: RESTORE LOG successfully processed 41654 pages in 1339.540 seconds (0.254 MB/sec). 03/08/2010 19:34:32: SQL Backup process ended. SQL Backup log file 6.4.0.56 -SQL "restore database [DBName] from disk='c:\Temp\[SeverName]_[DBName]_20100803_*FULL.sqb' with password='XXXXXXXXXX', REPLACE, DISCONNECT_EXISTING, NORECOVERY, LOGTO = 'C:\Bin\SQLBackup_[DBName]FullRestore.SQLData1.0056.log', mailto='mikeg@archipelago.ca' " PROCESSES COMPLETED SUCCESSFULLY 03/08/2010 19:50:55: Restoring [DBName] (database) from: 03/08/2010 19:50:55: c:\Temp\[SeverName]_[DBName]_20100803_070934_FULL.sqb 03/08/2010 19:50:56: ALTER DATABASE [DBName] SET ONLINE RESTORE DATABASE [DBName] FROM VIRTUAL_DEVICE = 'SQLBACKUP_C67B88AD-63D6-47C4-B98A-87E93ABF92E7', VIRTUAL_DEVICE = 'SQLBACKUP_C67B88AD-63D6-47C4-B98A-87E93ABF92E701', VIRTUAL_DEVICE = 'SQLBACKUP_C67B88AD-63D6-47C4-B98A-87E93ABF92E702' WITH BUFFERCOUNT = 18, BLOCKSIZE = 65536, MAXTRANSFERSIZE = 1048576 , NORECOVERY, REPLACE 03/08/2010 19:52:50: Processed 186736 pages for database '[DBName]', file '[DBName]_Data' on file 1. 03/08/2010 19:52:50: Processed 2 pages for database '[DBName]', file '[DBName]_log' on file 1. 03/08/2010 19:52:50: RESTORE DATABASE successfully processed 186738 pages in 97.681 seconds (15.660 MB/sec). 03/08/2010 19:52:50: SQL Backup process ended. SQL Backup log file 6.4.0.56 -SQL "restore log [DBName] from disk='c:\Temp\[SeverName]_[DBName]_20100803_*Log.sqb' with password='XXXXXXXXXX', REPLACE, DISCONNECT_EXISTING, RECOVERY, LOGTO = 'C:\Bin\SQLBackup_[DBName]FullRestore.SQLLog1.0056.log', mailto='mikeg@archipelago.ca' " PROCESSES COMPLETED SUCCESSFULLY 03/08/2010 19:52:51: Restoring [DBName] (transaction logs) from: 03/08/2010 19:52:51: c:\Temp\[SeverName]_[DBName]_20100803_074115_LOG.sqb 03/08/2010 19:52:51: RESTORE LOG [DBName] FROM VIRTUAL_DEVICE = 'SQLBACKUP_4B539039-F257-422E-ADD0-29EC9A0545B8', VIRTUAL_DEVICE = 'SQLBACKUP_4B539039-F257-422E-ADD0-29EC9A0545B801', VIRTUAL_DEVICE = 'SQLBACKUP_4B539039-F257-422E-ADD0-29EC9A0545B802' WITH BUFFERCOUNT = 18, BLOCKSIZE = 65536, MAXTRANSFERSIZE = 1048576 , NORECOVERY, REPLACE 03/08/2010 19:53:11: Processed 0 pages for database '[DBName]', file '[DBName]_Data' on file 1. 03/08/2010 19:53:11: Processed 13836 pages for database '[DBName]', file '[DBName]_log' on file 1. 03/08/2010 19:53:11: RESTORE LOG successfully processed 13836 pages in 3.361 seconds (33.723 MB/sec). 03/08/2010 19:53:11: Restoring [DBName] (transaction logs) from: 03/08/2010 19:53:11: c:\Temp\[SeverName]_[DBName]_20100803_103826_LOG.sqb 03/08/2010 19:53:11: RESTORE LOG [DBName] FROM VIRTUAL_DEVICE = 'SQLBACKUP_68BCDA9E-32BE-40E0-8593-B71A9ADE2D04', VIRTUAL_DEVICE = 'SQLBACKUP_68BCDA9E-32BE-40E0-8593-B71A9ADE2D0401', VIRTUAL_DEVICE = 'SQLBACKUP_68BCDA9E-32BE-40E0-8593-B71A9ADE2D0402' WITH BUFFERCOUNT = 18, BLOCKSIZE = 65536, MAXTRANSFERSIZE = 1048576 , NORECOVERY, REPLACE 03/08/2010 19:53:53: Processed 0 pages for database '[DBName]', file '[DBName]_Data' on file 1. 03/08/2010 19:53:53: Processed 41491 pages for database '[DBName]', file '[DBName]_log' on file 1. 03/08/2010 19:53:53: RESTORE LOG successfully processed 41491 pages in 10.221 seconds (33.254 MB/sec). 03/08/2010 19:53:53: Restoring [DBName] (transaction logs) from: 03/08/2010 19:53:53: c:\Temp\[SeverName]_[DBName]_20100803_133835_LOG.sqb 03/08/2010 19:53:54: RESTORE LOG [DBName] FROM VIRTUAL_DEVICE = 'SQLBACKUP_BEFCB8D8-7358-4A88-AF49-91D7555EAABD', VIRTUAL_DEVICE = 'SQLBACKUP_BEFCB8D8-7358-4A88-AF49-91D7555EAABD01', VIRTUAL_DEVICE = 'SQLBACKUP_BEFCB8D8-7358-4A88-AF49-91D7555EAABD02' WITH BUFFERCOUNT = 18, BLOCKSIZE = 65536, MAXTRANSFERSIZE = 1048576 , RECOVERY, REPLACE 03/08/2010 19:54:56: Processed 0 pages for database '[DBName]', file '[DBName]_Data' on file 1. 03/08/2010 19:54:56: Processed 41654 pages for database '[DBName]', file '[DBName]_log' on file 1. 03/08/2010 19:54:56: RESTORE LOG successfully processed 41654 pages in 10.534 seconds (32.392 MB/sec). 03/08/2010 19:54:56: SQL Backup process ended. / comments
  1. Community
  2. SQL Backup Previous Versions
  3. restore time VERY slow (compared to native SQL restore)
I have encountered a similar issue with 6.4.0.1013 - which I am using to fix the LATEST_ALL skipped log file bug with 6.4.0.56. The 1013 release seems to slow down more as a restore job goes on. I...
0 votes
Total activity
26
Last activity
Member since
Following
0 users
Followed by
0 users
Votes
0
Subscriptions
3