VDI Error or not?
ChrisLerczak
Posts: 4
For a few weeks now, we are seeing this error in our logs.
The backup routine runs every hour 24/7 but only errors once a day usually at 9:30am. I've checked the event logs, nothing unusual happens at that time of the day, CPU%, memory, disks all nominal at this time.
I don't believe it to be a VDI error as it only happens once a day and not every day, subsequent backups complete successfully, this problem only affects diff backups.
This is on a Rackspace server , I believe they run CommVault backup at about the same time, could this be causing problems?
Any help would be appreciated.
22/02/2012 09:30:01: BACKUP DATABASE [OM**********UK] TO VIRTUAL_DEVICE = 'SQLBACKUP_C0D76161-E10D-45AC-A298-2850A55C08A1', VIRTUAL_DEVICE = 'SQLBACKUP_C0D76161-E10D-45AC-A298-2850A55C08A101', VIRTUAL_DEVICE = 'SQLBACKUP_C0D76161-E10D-45AC-A298-2850A
55C08A102' WITH BUFFERCOUNT = 18, BLOCKSIZE = 65536, MAXTRANSFERSIZE = 1048576, NAME = N'Database (OM**********UK), 22/02/2012 09:30:01', DESCRIPTION = N'Backup on 22/02/2012 09:30:01 Server: 358424-WEB3 Database: OM**********UK', FORMAT,
DIFFERENTIAL
22/02/2012 09:30:31: VDI error 1010: Failed to get the configuration from the server because the timeout interval has elapsed. Check that the SQL Server instance is running, that you have the SQL Server System Administrator server role; and that no other
processes are blocking the backup or restore process; or try increasing the value of the VDITimeout registry setting in HKEY_LOCAL_MACHINE\SOFTWARE\Red Gate\SQL Backup\BackupSettingsGlobal\[InstanceName]
22/02/2012 09:30:31:
22/02/2012 09:30:31: SPID Status Login HostName BlkBy DBName Command CPUTime DiskIO LastBatch ProgramName
SPID_1 REQUESTID
22/02/2012 09:30:31:
The backup routine runs every hour 24/7 but only errors once a day usually at 9:30am. I've checked the event logs, nothing unusual happens at that time of the day, CPU%, memory, disks all nominal at this time.
I don't believe it to be a VDI error as it only happens once a day and not every day, subsequent backups complete successfully, this problem only affects diff backups.
This is on a Rackspace server , I believe they run CommVault backup at about the same time, could this be causing problems?
Any help would be appreciated.
22/02/2012 09:30:01: BACKUP DATABASE [OM**********UK] TO VIRTUAL_DEVICE = 'SQLBACKUP_C0D76161-E10D-45AC-A298-2850A55C08A1', VIRTUAL_DEVICE = 'SQLBACKUP_C0D76161-E10D-45AC-A298-2850A55C08A101', VIRTUAL_DEVICE = 'SQLBACKUP_C0D76161-E10D-45AC-A298-2850A
55C08A102' WITH BUFFERCOUNT = 18, BLOCKSIZE = 65536, MAXTRANSFERSIZE = 1048576, NAME = N'Database (OM**********UK), 22/02/2012 09:30:01', DESCRIPTION = N'Backup on 22/02/2012 09:30:01 Server: 358424-WEB3 Database: OM**********UK', FORMAT,
DIFFERENTIAL
22/02/2012 09:30:31: VDI error 1010: Failed to get the configuration from the server because the timeout interval has elapsed. Check that the SQL Server instance is running, that you have the SQL Server System Administrator server role; and that no other
processes are blocking the backup or restore process; or try increasing the value of the VDITimeout registry setting in HKEY_LOCAL_MACHINE\SOFTWARE\Red Gate\SQL Backup\BackupSettingsGlobal\[InstanceName]
22/02/2012 09:30:31:
22/02/2012 09:30:31: SPID Status Login HostName BlkBy DBName Command CPUTime DiskIO LastBatch ProgramName
SPID_1 REQUESTID
22/02/2012 09:30:31:
Comments
Thanks.
SQL Backup Consultant Developer
Associate, Yohz Software
Beyond compression - SQL Backup goodies under the hood, updated for version 8
This is the full error log from this morning.
SQL Backup log file 6.5.1.9
-SQL "BACKUP DATABASES [OM********GermanyDE,OM********UK,OM********UK,OM********FR,OrderManagerWordLock,WarehouseHistoricStockOuts] TO DISK = 'E:\JungleDisk\BackupAllTheseFilesInHere\SQLBackups\<database>\<AUTO>.sqb' WITH ERASEFILES = 3, MAILTO_ONERROR = 'itsupport@hh2.com,it@hh2.com', DISKRETRYINTERVAL = 30, DISKRETRYCOUNT = 10, COMPRESSION = 2, THREADCOUNT = 3, VERIFY, DIFFERENTIAL "
ERRORS AND WARNINGS
28/02/2012 09:30:01: Deleting old backup file: E:\JungleDisk\BackupAllTheseFilesInHere\SQLBackups\OM********GermanyDE\DIFF_(local)_OM********GermanyDE_20120225_093001.sqb
28/02/2012 09:30:01: Backing up OM********UK (differential database) to:
28/02/2012 09:30:01: E:\JungleDisk\BackupAllTheseFilesInHere\SQLBackups\OM********UK\DIFF_(local)_OM********UK_20120228_093001.sqb
28/02/2012 09:30:01: BACKUP DATABASE [OM********UK] TO VIRTUAL_DEVICE = 'SQLBACKUP_6AECF2A1-51E3-4767-AEB3-EC6906E0F8B5', VIRTUAL_DEVICE = 'SQLBACKUP_6AECF2A1-51E3-4767-AEB3-EC6906E0F8B501', VIRTUAL_DEVICE = 'SQLBACKUP_6AECF2A1-51E3-4767-AEB3-EC6906E0F8B502' WITH BUFFERCOUNT = 18, BLOCKSIZE = 65536, MAXTRANSFERSIZE = 1048576, NAME = N'Database (OM********UK), 28/02/2012 09:30:01', DESCRIPTION = N'Backup on 28/02/2012 09:30:01 Server: 358424-WEB3 Database: OM********UK', FORMAT, DIFFERENTIAL
28/02/2012 09:30:31: VDI error 1010: Failed to get the configuration from the server because the timeout interval has elapsed. Check that the SQL Server instance is running, that you have the SQL Server System Administrator server role; and that no other processes are blocking the backup or restore process; or try increasing the value of the VDITimeout registry setting in HKEY_LOCAL_MACHINE\SOFTWARE\Red Gate\SQL Backup\BackupSettingsGlobal\[InstanceName]
28/02/2012 09:30:31:
28/02/2012 09:30:32: SPID Status Login HostName BlkBy DBName Command CPUTime DiskIO LastBatch ProgramName SPID_1 REQUESTID
28/02/2012 09:30:32:
28/02/2012 09:30:32: 1 BACKGROUND sa . . RESOURCE MONITOR 0 0 02/28 02:11:36 1 0
28/02/2012 09:30:32: 2 BACKGROUND sa . . RESOURCE MONITOR 0 0 02/28 02:11:36 2 0
28/02/2012 09:30:32: 3 BACKGROUND sa . . XE TIMER 0 0 02/28 02:11:36 3 0
28/02/2012 09:30:32: 4 BACKGROUND sa . . XE DISPATCHER 0 0 02/28 02:11:36 4 0
28/02/2012 09:30:32: 5 BACKGROUND sa . . LAZY WRITER 62 0 02/28 02:11:36 5 0
28/02/2012 09:30:32: 6 BACKGROUND sa . . LAZY WRITER 218 0 02/28 02:11:36 6 0
28/02/2012 09:30:32: 7 BACKGROUND sa . . LOG WRITER 561 0 02/28 02:11:36 7 0
28/02/2012 09:30:32: 8 BACKGROUND sa . . LOCK MONITOR 15 0 02/28 02:11:36 8 0
28/02/2012 09:30:32: 9 BACKGROUND sa . . master SIGNAL HANDLER 0 0 02/28 02:11:36 9 0
28/02/2012 09:30:32: 10 sleeping sa . . master TASK MANAGER 0 0 02/28 02:11:36 10 0
28/02/2012 09:30:32: 11 BACKGROUND sa . . master TRACE QUEUE TASK 0 0 02/28 02:11:36 11 0
28/02/2012 09:30:32: 12 BACKGROUND sa . . master BRKR TASK 0 0 02/28 02:11:36 12 0
28/02/2012 09:30:32: 13 sleeping sa . . master TASK MANAGER 0 0 02/28 02:11:36 13 0
28/02/2012 09:30:32: 14 BACKGROUND sa . . master TASK MANAGER 0 0 02/28 02:11:36 14 0
28/02/2012 09:30:32: 15 BACKGROUND sa . . tempdb CHECKPOINT 218 118 02/28 02:11:36 15 0
28/02/2012 09:30:32: 16 BACKGROUND sa . . master BRKR EVENT HNDLR 0 45 02/28 02:11:36 16 0
28/02/2012 09:30:32: 17 BACKGROUND sa . . master BRKR TASK 0 0 02/28 02:11:36 17 0
28/02/2012 09:30:32: 18 BACKGROUND sa . . master BRKR TASK 0 0 02/28 02:11:36 18 0
28/02/2012 09:30:32: 19 sleeping sa . . master TASK MANAGER 0 0 02/28 02:11:36 19 0
28/02/2012 09:30:32: 20 sleeping sa . . master TASK MANAGER 0 0 02/28 02:11:36 20 0
28/02/2012 09:30:32: 21 sleeping sa . . master TASK MANAGER 0 0 02/28 02:11:36 21 0
28/02/2012 09:30:32: 22 sleeping sa . . master TASK MANAGER 0 2 02/28 02:11:36 22 0
28/02/2012 09:30:32: 23 sleeping sa . . master TASK MANAGER 0 0 02/28 02:11:36 23 0
28/02/2012 09:30:32: 24 sleeping sa . . master TASK MANAGER 0 0 02/28 02:11:36 24 0
28/02/2012 09:30:32: 25 sleeping sa . . master TASK MANAGER 0 0 02/28 02:11:36 25 0
28/02/2012 09:30:32: 26 sleeping sa . . master TASK MANAGER 0 1 02/28 02:11:36 26 0
28/02/2012 09:30:32: 27 sleeping sa . . master TASK MANAGER 0 0 02/28 02:11:36 27 0
28/02/2012 09:30:32: 28 sleeping sa . . master TASK MANAGER 0 0 02/28 02:11:36 28 0
28/02/2012 09:30:32: 51 sleeping OMCPDE_WebUser 358424-WEB3 . OM********GermanyDE AWAITING COMMAND 0 1 02/28 09:30:15 .Net SqlClient Data Provider 51 0
28/02/2012 09:30:32: 52 sleeping OMCPDE_WebUser 358424-WEB3 . OM********GermanyDE AWAITING COMMAND 0 0 02/28 09:30:15 .Net SqlClient Data Provider 52 0
28/02/2012 09:30:32: 53 sleeping OMCPUK_WebUser 358424-WEB3 . OM********UK AWAITING COMMAND 217 0 02/28 09:30:04 .Net SqlClient Data Provider 53 0
28/02/2012 09:30:32: 55 sleeping OMUCFR_WebUser 358424-WEB3 . OM********FR AWAITING COMMAND 0 0 02/28 09:29:44 .Net SqlClient Data Provider 55 0
28/02/2012 09:30:32: 56 sleeping NT AUTHORITY\SYSTEM 358424-WEB3 . msdb AWAITING COMMAND 140 112 02/28 02:11:41 SQLAgent - Generic Refresher 56 0
28/02/2012 09:30:32: 57 sleeping OMCPUK_WebUser 358424-WEB3 . OM********UK AWAITING COMMAND 0 0 02/28 09:30:22 .Net SqlClient Data Provider 57 0
28/02/2012 09:30:32: 58 sleeping OMCPUK_WebUser 358424-WEB3 . OM********UK AWAITING COMMAND 0 0 02/28 09:26:43 .Net SqlClient Data Provider 58 0
28/02/2012 09:30:32: 59 SUSPENDED NT AUTHORITY\SYSTEM 358424-WEB3 . OM********UK BACKUP DATABASE 47 23 02/28 09:07:45 SQL Management 59 0
28/02/2012 09:30:32: 59 RUNNABLE 358424-WEB3 . OM********UK BACKUP DATABASE 1014 0 02/28 09:07:45 SQL Management 59 0
28/02/2012 09:30:32: 59 SUSPENDED 358424-WEB3 . OM********UK BACKUP DATABASE 2372 213063 02/28 09:07:45 SQL Management 59 0
28/02/2012 09:30:32: 59 SUSPENDED 358424-WEB3 . OM********UK BACKUP DATABASE 2278 0 02/28 09:07:45 SQL Management 59 0
28/02/2012 09:30:32: 60 RUNNABLE NT AUTHORITY\SYSTEM 358424-WEB3 . master EXECUTE 0 0 02/28 09:30:00 SQLAgent - TSQL JobStep (Job 0x533BB8AE51AD764097AE5D8EF4B71284 : Step 1) 60 0
28/02/2012 09:30:32: 61 sleeping OMCPUK_WebUser 358424-WEB3 . OM********UK AWAITING COMMAND 0 0 02/28 09:29:37 .Net SqlClient Data Provider 61 0
28/02/2012 09:30:32: 62 sleeping OMCPDE_WebUser 358424-WEB3 . OM********GermanyDE AWAITING COMMAND 0 0 02/28 09:30:27 .Net SqlClient Data Provider 62 0
28/02/2012 09:30:32: 63 sleeping OMPBUK_WebUser 358424-WEB3 . OM********UK AWAITING COMMAND 31 0 02/28 09:29:41 .Net SqlClient Data Provider 63 0
28/02/2012 09:30:32: 64 sleeping OMUCFR_WebUser 358424-WEB3 . OM********FR AWAITING COMMAND 0 0 02/28 09:30:07 .Net SqlClient Data Provider 64 0
28/02/2012 09:30:32: 65 RUNNABLE NT AUTHORITY\SYSTEM 358424-WEB3 . master SELECT INTO 171 8 02/28 09:30:01 SQBCoreService.exe 65 0
28/02/2012 09:30:32: 66 sleeping OMCPUK_WebUser 358424-WEB3 . OM********UK AWAITING COMMAND 609 0 02/28 09:30:22 .Net SqlClient Data Provider 66 0
28/02/2012 09:30:32: 67 sleeping OMCPDE_WebUser 358424-WEB3 . OM********GermanyDE AWAITING COMMAND 0 0 02/28 09:29:56 .Net SqlClient Data Provider 67 0
28/02/2012 09:30:32: 68 sleeping OMCPUK_WebUser 358424-WEB3 . OM********UK AWAITING COMMAND 0 0 02/28 09:30:17 .Net SqlClient Data Provider 68 0
28/02/2012 09:30:32: 69 sleeping OMCPUK_WebUser 358424-WEB3 . OM********UK AWAITING COMMAND 0 0 02/28 09:30:28 .Net SqlClient Data Provider 69 0
28/02/2012 09:30:32: 70 sleeping 358424-WEB3\Rack 358424-WEB3 . master AWAITING COMMAND 16 0 02/28 09:07:45 SQL Management 70 0
28/02/2012 09:30:32: 71 sleeping 358424-WEB3\hh-martyn 358424-WEB3 . WarehouseHistoricStockOuts AWAITING COMMAND 500 78 02/28 09:22:32 Microsoft SQL Server Management Studio 71 0
28/02/2012 09:30:32: 72 SUSPENDED NT AUTHORITY\SYSTEM 358424-WEB3 59 OM********UK BACKUP DATABASE 62 164 02/28 09:30:01 SQBCoreService.exe 72 0
28/02/2012 09:30:32: 74 sleeping OMUCFR_WebUser 358424-WEB3 . OM********FR AWAITING COMMAND 0 0 02/28 09:28:58 .Net SqlClient Data Provider 74 0
28/02/2012 09:30:32: 75 sleeping NT AUTHORITY\SYSTEM 358424-WEB3 . msdb AWAITING COMMAND 15 241 02/28 09:30:00 SQLAgent - Job invocation engine 75 0
28/02/2012 09:30:32: 77 sleeping 358424-WEB3\hh-martyn 358424-WEB3 . master AWAITING COMMAND 0 21 02/28 09:22:32 Microsoft SQL Server Management Studio - Query 77 0
28/02/2012 09:30:32: 79 sleeping 358424-WEB3\hh-martyn 358424-WEB3 . master AWAITING COMMAND 0 0 02/28 09:22:32 Microsoft SQL Server Management Studio - Query 79 0
28/02/2012 09:30:32:
28/02/2012 09:37:41: SQL error 3013: BACKUP DATABASE is terminating abnormally.
28/02/2012 09:37:41: SQL error 3201: Cannot open backup device 'SQLBACKUP_6AECF2A1-51E3-4767-AEB3-EC6906E0F8B5'. Operating system error 0x80070002(failed to retrieve text for this error. Reason: 15100).
28/02/2012 09:37:41:
28/02/2012 09:37:41: Memory profile
28/02/2012 09:37:41: Type Maximum Minimum Average Blk count Total
28/02/2012 09:37:41:
28/02/2012 09:37:41: Commit 1787822080 4096 2781519 1550 4311355392
28/02/2012 09:37:41: Reserve 8673755136 8192 34552413 264 9121837056
28/02/2012 09:37:41: Free 8776597569536 4096 38520437562 228 8782659764224
28/02/2012 09:37:41: Private 8673755136 4096 11346734 1172 13298372608
28/02/2012 09:37:41: Mapped 4059136 4096 240798 71 17096704
28/02/2012 09:37:41: Image 51638272 4096 206170 571 117723136
28/02/2012 09:37:41:
PROCESSES COMPLETED SUCCESSFULLY
28/02/2012 09:30:00: Backing up OM********GermanyDE (differential database) to:
28/02/2012 09:30:00: E:\JungleDisk\BackupAllTheseFilesInHere\SQLBackups\OM********GermanyDE\DIFF_(local)_OM********GermanyDE_20120228_093000.sqb
28/02/2012 09:30:00: BACKUP DATABASE [OM********GermanyDE] TO VIRTUAL_DEVICE = 'SQLBACKUP_AFF9262D-B37A-457D-B2B4-08DA44FEB890', VIRTUAL_DEVICE = 'SQLBACKUP_AFF9262D-B37A-457D-B2B4-08DA44FEB89001', VIRTUAL_DEVICE = 'SQLBACKUP_AFF9262D-B37A-457D-B2B4-08DA44FEB89002' WITH BUFFERCOUNT = 18, BLOCKSIZE = 65536, MAXTRANSFERSIZE = 1048576, NAME = N'Database (OM********GermanyDE), 28/02/2012 09:30:00', DESCRIPTION = N'Backup on 28/02/2012 09:30:00 Server: 358424-WEB3 Database: OM********GermanyDE', FORMAT, DIFFERENTIAL
28/02/2012 09:30:01: Backup data size : 13.313 MB
28/02/2012 09:30:01: Compressed data size: 2.832 MB
28/02/2012 09:30:01: Compression rate : 78.73%
28/02/2012 09:30:01: Processed 1296 pages for database 'OM********GermanyDE', file 'CPOrderManagerV3_Data' on file 1.
28/02/2012 09:30:01: Processed 7 pages for database 'OM********GermanyDE', file 'CPOrderManagerV3_Log' on file 1.
28/02/2012 09:30:01: BACKUP DATABASE WITH DIFFERENTIAL successfully processed 1303 pages in 0.366 seconds (27.794 MB/sec).
28/02/2012 09:30:01:
28/02/2012 09:30:01: Verifying files:
28/02/2012 09:30:01: E:\JungleDisk\BackupAllTheseFilesInHere\SQLBackups\OM********GermanyDE\DIFF_(local)_OM********GermanyDE_20120228_093000.sqb
28/02/2012 09:30:01:
28/02/2012 09:30:01: The backup set on file 1 is valid.
28/02/2012 09:37:41: Warning 300: Backup failed. Retry attempt: 1
28/02/2012 09:37:43: BACKUP DATABASE [OM********UK] TO VIRTUAL_DEVICE = 'SQLBACKUP_FF5D1903-106C-4FA8-8B0F-8911F0D9FB29', VIRTUAL_DEVICE = 'SQLBACKUP_FF5D1903-106C-4FA8-8B0F-8911F0D9FB2901', VIRTUAL_DEVICE = 'SQLBACKUP_FF5D1903-106C-4FA8-8B0F-8911F0D9FB2902' WITH BUFFERCOUNT = 18, BLOCKSIZE = 65536, MAXTRANSFERSIZE = 524288, NAME = N'Database (OM********UK), 28/02/2012 09:30:01', DESCRIPTION = N'Backup on 28/02/2012 09:30:01 Server: 358424-WEB3 Database: OM********UK', FORMAT, DIFFERENTIAL
28/02/2012 09:37:45: Backup data size : 52.313 MB
28/02/2012 09:37:45: Compressed data size: 11.199 MB
28/02/2012 09:37:45: Compression rate : 78.59%
28/02/2012 09:37:45: Processed 5928 pages for database 'OM********UK', file 'CPOrderManagerV3_Data' on file 1.
28/02/2012 09:37:45: Processed 5 pages for database 'OM********UK', file 'CPOrderManagerV3_Log' on file 1.
28/02/2012 09:37:45: BACKUP DATABASE WITH DIFFERENTIAL successfully processed 5933 pages in 1.425 seconds (32.522 MB/sec).
28/02/2012 09:37:45:
28/02/2012 09:37:45: Verifying files:
28/02/2012 09:37:45: E:\JungleDisk\BackupAllTheseFilesInHere\SQLBackups\OM********UK\DIFF_(local)_OM********UK_20120228_093001.sqb
28/02/2012 09:37:45:
28/02/2012 09:37:45: The backup set on file 1 is valid.
28/02/2012 09:37:45: Deleting old backup file: E:\JungleDisk\BackupAllTheseFilesInHere\SQLBackups\OM********UK\DIFF_(local)_OM********UK_20120225_093001.sqb
28/02/2012 09:37:45: Backing up OM********UK (differential database) to:
28/02/2012 09:37:45: E:\JungleDisk\BackupAllTheseFilesInHere\SQLBackups\OM********UK\DIFF_(local)_OM********UK_20120228_093745.sqb
28/02/2012 09:37:45: BACKUP DATABASE [OM********UK] TO VIRTUAL_DEVICE = 'SQLBACKUP_6AC5BADC-83D0-4009-8F00-089740AFB79D', VIRTUAL_DEVICE = 'SQLBACKUP_6AC5BADC-83D0-4009-8F00-089740AFB79D01', VIRTUAL_DEVICE = 'SQLBACKUP_6AC5BADC-83D0-4009-8F00-089740AFB79D02' WITH BUFFERCOUNT = 18, BLOCKSIZE = 65536, MAXTRANSFERSIZE = 1048576, NAME = N'Database (OM********UK), 28/02/2012 09:37:45', DESCRIPTION = N'Backup on 28/02/2012 09:37:45 Server: 358424-WEB3 Database: OM********UK', FORMAT, DIFFERENTIAL
28/02/2012 09:37:46: Backup data size : 16.500 MB
28/02/2012 09:37:46: Compressed data size: 4.083 MB
28/02/2012 09:37:46: Compression rate : 75.25%
28/02/2012 09:37:46: Processed 1784 pages for database 'OM********UK', file 'CPOrderManagerV3_Data' on file 1.
28/02/2012 09:37:46: Processed 8 pages for database 'OM********UK', file 'CPOrderManagerV3_Log' on file 1.
28/02/2012 09:37:46: BACKUP DATABASE WITH DIFFERENTIAL successfully processed 1792 pages in 0.489 seconds (28.616 MB/sec).
28/02/2012 09:37:46:
28/02/2012 09:37:46: Verifying files:
28/02/2012 09:37:46: E:\JungleDisk\BackupAllTheseFilesInHere\SQLBackups\OM********UK\DIFF_(local)_OM********UK_20120228_093745.sqb
28/02/2012 09:37:46:
28/02/2012 09:37:47: The backup set on file 1 is valid.
28/02/2012 09:37:47: Deleting old backup file: E:\JungleDisk\BackupAllTheseFilesInHere\SQLBackups\OM********UK\DIFF_(local)_OM********UK_20120225_093005.sqb
28/02/2012 09:37:47: Backing up OM********FR (differential database) to:
28/02/2012 09:37:47: E:\JungleDisk\BackupAllTheseFilesInHere\SQLBackups\OM********FR\DIFF_(local)_OM********FR_20120228_093747.sqb
28/02/2012 09:37:47: BACKUP DATABASE [OM********FR] TO VIRTUAL_DEVICE = 'SQLBACKUP_78C434A5-5419-457B-B4EB-EEDABAD762F6', VIRTUAL_DEVICE = 'SQLBACKUP_78C434A5-5419-457B-B4EB-EEDABAD762F601', VIRTUAL_DEVICE = 'SQLBACKUP_78C434A5-5419-457B-B4EB-EEDABAD762F602' WITH BUFFERCOUNT = 18, BLOCKSIZE = 65536, MAXTRANSFERSIZE = 1048576, NAME = N'Database (OM********FR), 28/02/2012 09:37:47', DESCRIPTION = N'Backup on 28/02/2012 09:37:47 Server: 358424-WEB3 Database: OM********FR', FORMAT, DIFFERENTIAL
28/02/2012 09:37:47: Backup data size : 4.813 MB
28/02/2012 09:37:47: Compressed data size: 699.500 KB
28/02/2012 09:37:47: Compression rate : 85.81%
28/02/2012 09:37:47: Processed 296 pages for database 'OM********FR', file 'CPOrderManagerV3_Data' on file 1.
28/02/2012 09:37:47: Processed 4 pages for database 'OM********FR', file 'CPOrderManagerV3_Log' on file 1.
28/02/2012 09:37:47: BACKUP DATABASE WITH DIFFERENTIAL successfully processed 300 pages in 0.104 seconds (22.517 MB/sec).
28/02/2012 09:37:47:
28/02/2012 09:37:47: Verifying files:
28/02/2012 09:37:47: E:\JungleDisk\BackupAllTheseFilesInHere\SQLBackups\OM********FR\DIFF_(local)_OM********FR_20120228_093747.sqb
28/02/2012 09:37:47:
28/02/2012 09:37:47: The backup set on file 1 is valid.
28/02/2012 09:37:47: Deleting old backup file: E:\JungleDisk\BackupAllTheseFilesInHere\SQLBackups\OM********FR\DIFF_(local)_OM********FR_20120225_093006.sqb
28/02/2012 09:37:47: Backing up OrderManagerWordLock (differential database) to:
28/02/2012 09:37:47: E:\JungleDisk\BackupAllTheseFilesInHere\SQLBackups\OrderManagerWordLock\DIFF_(local)_OrderManagerWordLock_20120228_093747.sqb
28/02/2012 09:37:47: BACKUP DATABASE [OrderManagerWordLock] TO VIRTUAL_DEVICE = 'SQLBACKUP_24E663B6-ABE4-423B-9086-165FB1E83B79', VIRTUAL_DEVICE = 'SQLBACKUP_24E663B6-ABE4-423B-9086-165FB1E83B7901', VIRTUAL_DEVICE = 'SQLBACKUP_24E663B6-ABE4-423B-9086-165FB1E83B7902' WITH BUFFERCOUNT = 18, BLOCKSIZE = 65536, MAXTRANSFERSIZE = 1048576, NAME = N'Database (OrderManagerWordLock), 28/02/2012 09:37:47', DESCRIPTION = N'Backup on 28/02/2012 09:37:47 Server: 358424-WEB3 Database: OrderManagerWordLock', FORMAT, DIFFERENTIAL
28/02/2012 09:37:48: Backup data size : 4.813 MB
28/02/2012 09:37:48: Compressed data size: 77.500 KB
28/02/2012 09:37:48: Compression rate : 98.43%
28/02/2012 09:37:48: Processed 56 pages for database 'OrderManagerWordLock', file 'OrderManagerWordLock' on file 1.
28/02/2012 09:37:48: Processed 2 pages for database 'OrderManagerWordLock', file 'OrderManagerWordLock_log' on file 1.
28/02/2012 09:37:48: BACKUP DATABASE WITH DIFFERENTIAL successfully processed 58 pages in 0.052 seconds (8.610 MB/sec).
28/02/2012 09:37:48:
28/02/2012 09:37:48: Verifying files:
28/02/2012 09:37:48: E:\JungleDisk\BackupAllTheseFilesInHere\SQLBackups\OrderManagerWordLock\DIFF_(local)_OrderManagerWordLock_20120228_093747.sqb
28/02/2012 09:37:48:
28/02/2012 09:37:48: The backup set on file 1 is valid.
28/02/2012 09:37:48: Deleting old backup file: E:\JungleDisk\BackupAllTheseFilesInHere\SQLBackups\OrderManagerWordLock\DIFF_(local)_OrderManagerWordLock_20120225_093007.sqb
28/02/2012 09:37:48: Backing up WarehouseHistoricStockOuts (differential database) to:
28/02/2012 09:37:48: E:\JungleDisk\BackupAllTheseFilesInHere\SQLBackups\WarehouseHistoricStockOuts\DIFF_(local)_WarehouseHistoricStockOuts_20120228_093748.sqb
28/02/2012 09:37:48: BACKUP DATABASE [WarehouseHistoricStockOuts] TO VIRTUAL_DEVICE = 'SQLBACKUP_A05CCB85-B9DF-4402-A4D1-6D25AC78DEBE', VIRTUAL_DEVICE = 'SQLBACKUP_A05CCB85-B9DF-4402-A4D1-6D25AC78DEBE01', VIRTUAL_DEVICE = 'SQLBACKUP_A05CCB85-B9DF-4402-A4D1-6D25AC78DEBE02' WITH BUFFERCOUNT = 18, BLOCKSIZE = 65536, MAXTRANSFERSIZE = 1048576, NAME = N'Database (WarehouseHistoricStockOuts), 28/02/2012 09:37:48', DESCRIPTION = N'Backup on 28/02/2012 09:37:48 Server: 358424-WEB3 Database: WarehouseHistoricStockOuts', FORMAT, DIFFERENTIAL
28/02/2012 09:37:49: Backup data size : 5.188 MB
28/02/2012 09:37:49: Compressed data size: 67.500 KB
28/02/2012 09:37:49: Compression rate : 98.73%
28/02/2012 09:37:49: Processed 32 pages for database 'WarehouseHistoricStockOuts', file 'WarehouseHistoricStockOuts' on file 1.
28/02/2012 09:37:49: Processed 1 pages for database 'WarehouseHistoricStockOuts', file 'WarehouseHistoricStockOuts_log' on file 1.
28/02/2012 09:37:49: BACKUP DATABASE WITH DIFFERENTIAL successfully processed 33 pages in 0.060 seconds (4.288 MB/sec).
28/02/2012 09:37:49:
28/02/2012 09:37:49: Verifying files:
28/02/2012 09:37:49: E:\JungleDisk\BackupAllTheseFilesInHere\SQLBackups\WarehouseHistoricStockOuts\DIFF_(local)_WarehouseHistoricStockOuts_20120228_093748.sqb
28/02/2012 09:37:49:
28/02/2012 09:37:49: The backup set on file 1 is valid.
28/02/2012 09:37:49: Deleting old backup file: E:\JungleDisk\BackupAllTheseFilesInHere\SQLBackups\WarehouseHistoricStockOuts\DIFF_(local)_WarehouseHistoricStockOuts_20120225_093008.sqb
The reason the first attempt failed was because another process (process 59) was backing up the same database during that time, probably using CommVault as you mentioned previously.
SQL Backup Consultant Developer
Associate, Yohz Software
Beyond compression - SQL Backup goodies under the hood, updated for version 8
Thanks' for that, I thought it might be Commvault as it only errors once a day.
We have now requested that Rackspace move their backup (Commvault) to an earlier time, hopefully this will resolve the problem.
If it occurs at the earlier time we will then know that there's a conflict.
Chris,
Good Evening,
If anyone interested to learn CommVault Certification Training, please feel free to ping me.
Thanks & Regards,
Anita.