SnapManager for SQL issue: Database Verification Failed with error codes: 0xc0040813, 0x8004038f

[ivissupport]

Today i watch that an earlier backup job was failed with the following error codes:

error code: 0xc0040813
error code: 0x8004038f

Also i write the contents of SMSQL Report to this question form.

SMSQL Report
----------------------

Connecting to SQL Server [EC012QSQL] for validation...
[21:00:01.441] *** SnapManager for SQL Server Report [21:00:01.441] Backup Time Stamp: 08-25-2008_21.00.00
[21:00:01.441] Getting SQL Server Database Information, please wait...
[21:00:01.441] Getting virtual disks information...
[21:00:02.535] Querying SQL Server instances installed...
[21:00:02.535] Creating threads for enumerating databases of different SQL Server instances.
[21:00:02.535] Waiting for the threads to finish enumerating databases.
[21:00:02.550] Connecting to SQL Server instance - EC012QSQL...
[21:00:02.550] Getting SQL Server version information...
[21:00:02.566] Querying database information...
[21:00:02.644] All threads finished enumerating databases.
[21:00:02.644] Validating database configuration...
[21:00:02.644] Setting database disk configuration...
[21:00:02.644] Setting database locating on SQLRoot path...
[21:00:02.660] Querying database disk volume configuration...
[21:00:02.660] Getting SnapInfo directories configuration... [21:00:02.660] Full database backup
[21:00:02.660] Maximum databases of concurrent backup: 20
[21:00:02.660] Naming convention: Generic
[21:00:02.660] Run transaction log backup after full database backup: No
[21:00:02.660] Keep the oldest 28 full backups.
[21:00:02.660] Retain up-to-the-minute restore ability for older backups in other management groups: No
[21:00:02.660] Verify snapshot after backup(run DBCC) on EC012QDFM: Yes
[21:00:02.660] Leave database attached after DBCC: No
[21:00:02.660] Run DBCC CHECKDB with Live Database Before Backup: No
[21:00:02.660] Run DBCC CHECKDB with Live Database After Backup: No
[21:00:02.660] Backup Management Group: Standard
[21:00:02.660] Update SnapMirror after operation: No
[21:00:02.660] Run Command after operation: No
[21:00:02.660]
[21:00:02.660] Backup Database 1: EC012QSQL : Northwind
[21:00:02.660] Backup Database 2: EC012QSQL : pubs
[21:00:02.660] Backup Database 3: EC012QSQL : QBAnalytics
[21:00:02.660] Backup Database 4: EC012QSQL : QBCollection_Plus
[21:00:02.660] Backup Database 5: EC012QSQL : QBCollection_Plus_GR_Dialer
[21:00:02.660] Backup Database Group #1:
[21:00:02.660] EC012QSQL : Northwind
[21:00:02.660] EC012QSQL : pubs
[21:00:02.660] EC012QSQL : QBAnalytics
[21:00:02.660] EC012QSQL : QBCollection_Plus
[21:00:02.660] EC012QSQL : QBCollection_Plus_GR_Dialer
[21:00:02.660]
[21:00:02.660] Backup job based on volume: #1
[21:00:02.660] Sub Job: #1 of Job#1
[21:00:02.660] 1 - EC012QSQL : Northwind
[21:00:02.660] 2 - EC012QSQL : pubs
[21:00:02.660] 3 - EC012QSQL : QBAnalytics
[21:00:02.660] 4 - EC012QSQL : QBCollection_Plus
[21:00:02.660] 5 - EC012QSQL : QBCollection_Plus_GR_Dialer
[21:00:02.660] **** BACKUP JOB **** #1
[21:00:02.660] Backup Time Stamp: 08-25-2008_21.00.00
[21:00:02.660] **** Backup Group [#1] of Job#1
[21:00:02.660] Backup Database List:
[21:00:02.660] 1 - EC012QSQL : Northwind
[21:00:02.660] 2 - EC012QSQL : pubs
[21:00:02.660] 3 - EC012QSQL : QBAnalytics
[21:00:02.660] 4 - EC012QSQL : QBCollection_Plus
[21:00:02.660] 5 - EC012QSQL : QBCollection_Plus_GR_Dialer
[21:00:02.660] Maximum worker threads setting for [EC012QSQL] = 255
[21:00:02.660] Current worker threads number for [EC012QSQL] = 239
[21:00:02.660] GETTING ALL DATABASES INFO SHARING THE SAME VOLUMES... [21:00:19.504] Getting SnapInfo directory info...
[21:00:19.504] 1 - Database [Northwind] of [EC012QSQL] SnapInfo directory located at:
[21:00:19.504] I:\SMSQL_SnapInfo\VDISK__L&S
[21:00:19.504] 2 - Database [pubs] of [EC012QSQL] SnapInfo directory located at:
[21:00:19.504] I:\SMSQL_SnapInfo\VDISK__L&S
[21:00:19.504] 3 - Database [QBAnalytics] of [EC012QSQL] SnapInfo directory located at:
[21:00:19.504] I:\SMSQL_SnapInfo\VDISK__L&S
[21:00:19.504] 4 - Database [QBCollection_Plus] of [EC012QSQL] SnapInfo directory located at:
[21:00:19.504] I:\SMSQL_SnapInfo\VDISK__L&S
[21:00:19.504] 5 - Database [QBCollection_Plus_GR_Dialer] of [EC012QSQL] SnapInfo directory located at:
[21:00:19.504] I:\SMSQL_SnapInfo\VDISK__L&S
[21:00:19.504] CHECK SNAPMANAGER LICENSE ON VIRTUAL DISK.
[21:00:19.504] Querying virtual disk license: S:...
[21:00:19.504] Getting SnapInfo directory info...
[21:00:19.504] 1 - Database [Northwind] of [EC012QSQL] SnapInfo directory located at:
[21:00:19.504] I:\SMSQL_SnapInfo\VDISK__L&S
[21:00:19.504] 2 - Database [pubs] of [EC012QSQL] SnapInfo directory located at:
[21:00:19.504] I:\SMSQL_SnapInfo\VDISK__L&S
[21:00:19.504] 3 - Database [QBAnalytics] of [EC012QSQL] SnapInfo directory located at:
[21:00:19.504] I:\SMSQL_SnapInfo\VDISK__L&S
[21:00:19.504] 4 - Database [QBCollection_Plus] of [EC012QSQL] SnapInfo directory located at:
[21:00:19.504] I:\SMSQL_SnapInfo\VDISK__L&S
[21:00:19.504] 5 - Database [QBCollection_Plus_GR_Dialer] of [EC012QSQL] SnapInfo directory located at:
[21:00:19.504] I:\SMSQL_SnapInfo\VDISK__L&S
[21:00:19.504]
[21:00:19.504] RENAME MOST RECENT SNAPINFO BEFORE NEW BACKUP : EC012QSQL : Northwind - [#1] [21:00:19.504] Rename old recent snapinfo folder from and to:
[21:00:19.504] I:\SMSQL_SnapInfo\VDISK__L&S\FG__\EC012QSQL__recent
[21:00:19.504] I:\SMSQL_SnapInfo\VDISK__L&S\FG__\08-25-2008_20.00.01
[21:00:19.504] SnapManager finds an alternative snapinfo directory for database [Northwind] of [EC012QSQL] at:
[21:00:19.504] I:\SMSQL_SnapInfo\SQL__EC012QSQL\DB__Northwind
[21:00:19.504]
[21:00:19.504] RENAME MOST RECENT SNAPINFO BEFORE NEW BACKUP : EC012QSQL : pubs - [#2] [21:00:19.504] The recent backup snapinfo directory has already been renamed, it is sharing with other datatabases.
[21:00:19.504] SnapManager finds an alternative snapinfo directory for database [pubs] of [EC012QSQL] at:
[21:00:19.504] I:\SMSQL_SnapInfo\SQL__EC012QSQL\DB__pubs
[21:00:19.504]
[21:00:19.504] RENAME MOST RECENT SNAPINFO BEFORE NEW BACKUP : EC012QSQL : QBAnalytics - [#3] [21:00:19.504] The recent backup snapinfo directory has already been renamed, it is sharing with other datatabases.
[21:00:19.504] SnapManager finds an alternative snapinfo directory for database [QBAnalytics] of [EC012QSQL] at:
[21:00:19.504] I:\SMSQL_SnapInfo\SQL__EC012QSQL\DB__QBAnalytics
[21:00:19.504]
[21:00:19.504] RENAME MOST RECENT SNAPINFO BEFORE NEW BACKUP : EC012QSQL : QBCollection_Plus - [#4] [21:00:19.504] The recent backup snapinfo directory has already been renamed, it is sharing with other datatabases.
[21:00:19.504] SnapManager finds an alternative snapinfo directory for database [QBCollection_Plus] of [EC012QSQL] at:
[21:00:19.504] I:\SMSQL_SnapInfo\SQL__EC012QSQL\DB__QBCollection_Plus
[21:00:19.504]
[21:00:19.504] RENAME MOST RECENT SNAPINFO BEFORE NEW BACKUP : EC012QSQL : QBCollection_Plus_GR_Dialer - [#5] [21:00:19.504] The recent backup snapinfo directory has already been renamed, it is sharing with other datatabases.
[21:00:19.504] SnapManager finds an alternative snapinfo directory for database [QBCollection_Plus_GR_Dialer] of [EC012QSQL] at:
[21:00:19.504] I:\SMSQL_SnapInfo\SQL__EC012QSQL\DB__QBCollection_Plus_GR_Dialer
[21:00:19.520]
[21:00:19.520] RENAME OLD MOST RECENT SNAPSHOT [21:00:20.895] Rename Snapshot for virtual disk [S:] from [sqlsnap__ec012qsql__recent]
[21:00:20.895] To [sqlsnap__EC012QSQL_08-25-2008_20.00.01]
[21:00:21.848] Rename snapshot successfully completed.
[21:00:22.551] Rename Snapshot for virtual disk [L:] from [sqlsnap__ec012qsql__recent]
[21:00:22.551] To [sqlsnap__EC012QSQL_08-25-2008_20.00.01]
[21:00:23.426] Rename snapshot successfully completed.
[21:00:23.426] CREATE NEW RECENT SNAPINFO DIRECTORY : Northwind - [#1] [21:00:23.426] SnapInfo file Name:
[21:00:23.426] I:\SMSQL_SnapInfo\VDISK__L&S\FG__\EC012QSQL__recent\SnapInfo__08-25-2008_21.00.00.sml
[21:00:23.426]
[21:00:23.426] CREATE NEW RECENT SNAPINFO DIRECTORY : pubs - [#2] [21:00:23.426] SnapInfo file Name:
[21:00:23.426] I:\SMSQL_SnapInfo\VDISK__L&S\FG__\EC012QSQL__recent\SnapInfo__08-25-2008_21.00.00.sml
[21:00:23.426]
[21:00:23.426] CREATE NEW RECENT SNAPINFO DIRECTORY : QBAnalytics - [#3] [21:00:23.426] SnapInfo file Name:
[21:00:23.426] I:\SMSQL_SnapInfo\VDISK__L&S\FG__\EC012QSQL__recent\SnapInfo__08-25-2008_21.00.00.sml
[21:00:23.426]
[21:00:23.426] CREATE NEW RECENT SNAPINFO DIRECTORY : QBCollection_Plus - [#4] [21:00:23.426] SnapInfo file Name:
[21:00:23.426] I:\SMSQL_SnapInfo\VDISK__L&S\FG__\EC012QSQL__recent\SnapInfo__08-25-2008_21.00.00.sml
[21:00:23.426]
[21:00:23.426] CREATE NEW RECENT SNAPINFO DIRECTORY : QBCollection_Plus_GR_Dialer - [#5] [21:00:23.426] SnapInfo file Name:
[21:00:23.426] I:\SMSQL_SnapInfo\VDISK__L&S\FG__\EC012QSQL__recent\SnapInfo__08-25-2008_21.00.00.sml
[21:00:23.426]
[21:00:23.426] *** STARTING SQL SERVER ONLINE BACKUP PROCESS [21:00:23.426] Updating SnapInfo file for databases sharing same drive letter - [#1]
[21:00:23.426] Updating SnapInfo file for database - #1 : Northwind
[21:00:23.473] Updating SnapInfo file for database - #2 : pubs
[21:00:23.520] Updating SnapInfo file for database - #3 : QBAnalytics
[21:00:23.582] Updating SnapInfo file for database - #4 : QBCollection_Plus
[21:00:23.645] Updating SnapInfo file for database - #5 : QBCollection_Plus_GR_Dialer
[21:00:23.723]
[21:00:23.723] Starting VDI backup thread for database #1: [EC012QSQL : Northwind]...
[21:00:23.723] Starting VDI backup thread for database #2: [EC012QSQL : pubs]...
[21:00:23.723] Starting VDI backup thread for database #3: [EC012QSQL : QBAnalytics]...
[21:00:23.723] Starting VDI backup thread for database #4: [EC012QSQL : QBCollection_Plus]...
[21:00:23.723] Starting VDI backup thread for database #5: [EC012QSQL : QBCollection_Plus_GR_Dialer]...
[21:00:23.723] Sending SQL command to instance EC012QSQL for database Northwind : device NTAPDEV__EC012QSQL_Northwind...
[21:00:23.723] Receiving by server [EC012QSQL]...
[21:00:23.723] BACKUP DATABASE [Northwind] TO VIRTUAL_DEVICE='NTAPDEV__EC012QSQL_Northwind' WITH SNAPSHOT
[21:00:23.723] Waiting for SQLServer to respond...
[21:00:23.723] Sending SQL command to instance EC012QSQL for database pubs : device NTAPDEV__EC012QSQL_pubs...
[21:00:23.723] Receiving by server [EC012QSQL]...
[21:00:23.723] BACKUP DATABASE [pubs] TO VIRTUAL_DEVICE='NTAPDEV__EC012QSQL_pubs' WITH SNAPSHOT
[21:00:23.723] Waiting for SQLServer to respond...
[21:00:23.723] Sending SQL command to instance EC012QSQL for database QBAnalytics : device NTAPDEV__EC012QSQL_QBAnalytics...
[21:00:23.723] Receiving by server [EC012QSQL]...
[21:00:23.723] Sending SQL command to instance EC012QSQL for database QBCollection_Plus : device NTAPDEV__EC012QSQL_QBCollection_Plus...
[21:00:23.723] Receiving by server [EC012QSQL]...
[21:00:23.723] BACKUP DATABASE [QBAnalytics] TO VIRTUAL_DEVICE='NTAPDEV__EC012QSQL_QBAnalytics' WITH SNAPSHOT
[21:00:23.723] Sending SQL command to instance EC012QSQL for database QBCollection_Plus_GR_Dialer : device NTAPDEV__EC012QSQL_QBCollection_Plus_GR_Dialer...
[21:00:23.723] Receiving by server [EC012QSQL]...
[21:00:23.723] Waiting for SQLServer to respond...
[21:00:23.723] BACKUP DATABASE [QBCollection_Plus] TO VIRTUAL_DEVICE='NTAPDEV__EC012QSQL_QBCollection_Plus' WITH SNAPSHOT
[21:00:23.723] BACKUP DATABASE [QBCollection_Plus_GR_Dialer] TO VIRTUAL_DEVICE='NTAPDEV__EC012QSQL_QBCollection_Plus_GR_Dialer' WITH SNAPSHOT
[21:00:23.723] Waiting for SQLServer to respond...
[21:00:23.723] Waiting for SQLServer to respond...
[21:00:23.739] Performing data transfer of [EC012QSQL : QBAnalytics]...
[21:00:23.739] Performing data transfer of [EC012QSQL : pubs]...
[21:00:23.739] Performing data transfer of [EC012QSQL : QBCollection_Plus_GR_Dialer]...
[21:00:23.739] Performing data transfer of [EC012QSQL : Northwind]...
[21:00:23.739] Performing data transfer of [EC012QSQL : QBCollection_Plus]...
[21:00:24.207] SQL Server is prepared to freeze the database now [EC012QSQL : QBAnalytics]...
[21:00:24.457] SQL Server is prepared to freeze the database now [EC012QSQL : QBCollection_Plus_GR_Dialer]...
[21:00:24.661] SQL Server is prepared to freeze the database now [EC012QSQL : pubs]...
[21:00:24.942] SQL Server is prepared to freeze the database now [EC012QSQL : Northwind]...
[21:00:25.614] SQL Server is prepared to freeze the database now [EC012QSQL : QBCollection_Plus]...
[21:00:25.645] Ready to prepare to create snapshot...
[21:00:25.645]
[21:00:25.645] SNAPSHOT DATABASE [21:00:25.645] Preparing Snapshot to Virtual Disk Drive:
[21:00:25.645] Virtual Disk [S:], Virtual Disk [L:]
[21:00:25.645] Snapshot Name: sqlsnap__EC012QSQL__recent
[21:00:25.645] Begin to create snapshot...
[21:00:26.817] SnapDrive is ready to create snapshot.
[21:00:26.817] Create Snapshot Now [EC012QSQL : QBCollection_Plus_GR_Dialer]...
[21:00:26.817] Create Snapshot Now [EC012QSQL : Northwind]...
[21:00:26.817] Create Snapshot Now [EC012QSQL : QBCollection_Plus]...
[21:00:26.817] Create Snapshot Now [EC012QSQL : QBAnalytics]...
[21:00:26.817] Create Snapshot Now [EC012QSQL : pubs]...
[21:00:26.817] All VDI backup threads completed snapshot preparation and databases IO are frozen for snapshot.
[21:00:26.817] SnapManager are ready to create snapshot...
[21:00:30.176] SQLServer is aware that the snapshot is successful.
[21:00:30.176] SQLServer is aware that the snapshot is successful.
[21:00:30.176] SQLServer is aware that the snapshot is successful.
[21:00:30.176] SQLServer is aware that the snapshot is successful.
[21:00:30.176] SQLServer is aware that the snapshot is successful.
[21:00:30.176] Snapshot virtual disk S, L: for database [Northwind] successfully completed. [21:00:30.176] Snapshot virtual disk S, L: for database [pubs] successfully completed. [21:00:30.176] Snapshot virtual disk S, L: for database [QBAnalytics] successfully completed. [21:00:30.176] Snapshot virtual disk S, L: for database [QBCollection_Plus] successfully completed. [21:00:30.176] Snapshot virtual disk S, L: for database [QBCollection_Plus_GR_Dialer] successfully completed. [21:00:30.192] Msg 3014, SevLevel 0, State 1, SQLState 01000 [21:00:30.192] [Microsoft][ODBC SQL Server Driver][SQL Server]BACKUP DATABASE successfully processed 0 pages in 5.509 seconds (0.000 MB/sec).
[21:00:30.192] Msg 3014, SevLevel 0, State 1, SQLState 01000 [21:00:30.192] [Microsoft][ODBC SQL Server Driver][SQL Server]BACKUP DATABASE successfully processed 0 pages in 5.710 seconds (0.000 MB/sec).
[21:00:30.192] The SQL command executed.
[21:00:30.192] The SQL command executed.
[21:00:30.192] Msg 3014, SevLevel 0, State 1, SQLState 01000 [21:00:30.192] [Microsoft][ODBC SQL Server Driver][SQL Server]BACKUP DATABASE successfully processed 0 pages in 5.966 seconds (0.000 MB/sec).
[21:00:30.192] The SQL command executed.
[21:00:30.192] Msg 3014, SevLevel 0, State 1, SQLState 01000 [21:00:30.192] [Microsoft][ODBC SQL Server Driver][SQL Server]BACKUP DATABASE successfully processed 0 pages in 5.234 seconds (0.000 MB/sec).
[21:00:30.192] The SQL command executed.
[21:00:30.192] Msg 3014, SevLevel 0, State 1, SQLState 01000 [21:00:30.192] [Microsoft][ODBC SQL Server Driver][SQL Server]BACKUP DATABASE successfully processed 0 pages in 4.560 seconds (0.000 MB/sec).
[21:00:30.208] The SQL command executed.
[21:00:36.474]
[21:00:36.474] *** SNAPSHOT SNAPINFO DISK
[21:00:36.474]
[21:00:36.474] UPDATE MOST RECENT SNAPINFO DRIVE SNAPSHOT NAME [21:00:38.005] Rename Snapshot for virtual disk [I:] from [sqlinfo__ec012qsql__recent]
[21:00:38.005] To [sqlinfo__EC012QSQL_08-25-2008_20.00.01]
[21:00:38.911] Rename snapshot successfully completed.
[21:00:38.911] SNAPSHOT SNAPINFO DRIVE [21:00:38.911] Creating Snapshot of Virtual Disk Drive:
[21:00:38.911] Virtual Disk [I:]
[21:00:38.911] Snapshot name: sqlinfo__EC012QSQL__recent
[21:00:40.411] Snapshot SnapInfo drive(s) successfully completed.
[21:00:40.427] *** VERIFY DATABASE AFTER BACKUP
[21:00:40.427] Collecting verification information...
[21:00:40.427] Getting database backup information from SnapInfo file...
[21:00:40.427] Initializing SnapManager server on remote machine [EC012QDFM]...
[21:00:40.974] Mounting Snapshot [sqlsnap__ec012qsql__recent] for Virtual Disk S of Computer EC012QSQL
[21:01:10.194] This Snapshot is mounted as the drive [Z:].
[21:01:10.194] Mount Snapshot succeeded.
[21:01:10.194] Mounting Snapshot [sqlsnap__ec012qsql__recent] for Virtual Disk L of Computer EC012QSQL
[21:01:17.569] This Snapshot is mounted as the drive [Y:].
[21:01:17.569] Mount Snapshot succeeded.
[21:01:17.631] Using existing connection to server [EC012QDFM]...
[21:01:17.647] Attaching database [Northwind__Mount]...
[21:01:17.647] CREATE DATABASE [Northwind__Mount] ON PRIMARY (NAME = 'Northwind', FILENAME = 'Z:\Program Files\Microsoft SQL Server\MSSQL\data\northwnd.mdf') LOG ON (NAME = 'Northwind_log', FILENAME = 'Y:\Program Files\Microsoft SQL Server\MSSQL\data\northwnd.ldf') FOR ATTACH
[21:01:17.881] 1 transactions rolled back in database 'Northwind__Mount' (7).
[21:01:17.881] Database attached.
[21:01:17.881]
[21:01:17.881] DBCC CHECKDB (N'Northwind__Mount') WITH NO_INFOMSGS, PHYSICAL_ONLY
[21:01:18.022]
[21:01:18.022] DBCC CHECKDB completed successfully. [21:01:18.022] Detaching database [Northwind__Mount]...
[21:01:18.163] Database was detached successfully.
[21:01:18.163] Attaching database [pubs__Mount]...
[21:01:18.163] CREATE DATABASE [pubs__Mount] ON PRIMARY (NAME = 'pubs', FILENAME = 'Z:\Program Files\Microsoft SQL Server\MSSQL\data\pubs.mdf') LOG ON (NAME = 'pubs_log', FILENAME = 'Y:\Program Files\Microsoft SQL Server\MSSQL\data\pubs_log.ldf') FOR ATTACH
[21:01:18.397] 1 transactions rolled back in database 'pubs__Mount' (7).
[21:01:18.397] Database attached.
[21:01:18.397]
[21:01:18.397] DBCC CHECKDB (N'pubs__Mount') WITH NO_INFOMSGS, PHYSICAL_ONLY
[21:01:18.522]
[21:01:18.522] DBCC CHECKDB completed successfully. [21:01:18.522] Detaching database [pubs__Mount]...
[21:01:18.678] Database was detached successfully.
[21:01:18.678] Attaching database [QBAnalytics__Mount]...
[21:01:18.678] CREATE DATABASE [QBAnalytics__Mount] ON PRIMARY (NAME = 'QBAnalytics_Pilot_Data', FILENAME = 'Z:\Program Files\Microsoft SQL Server\MSSQL\Data\QBAnalytics_Pilot_Data.MDF') LOG ON (NAME = 'QBAnalytics_Pilot_Log', FILENAME = 'Y:\Program Files\Microsoft SQL Server\MSSQL\Data\QBAnalytics_Pilot_Log.LDF') FOR ATTACH
[21:01:37.757] 1 transactions rolled back in database 'QBAnalytics__Mount' (7).
[21:01:37.757] Database attached.
[21:01:37.757]
[21:01:37.757] DBCC CHECKDB (N'QBAnalytics__Mount') WITH NO_INFOMSGS, PHYSICAL_ONLY
[21:36:53.323]
[21:36:53.323] DBCC CHECKDB completed successfully. [21:36:53.323] Detaching database [QBAnalytics__Mount]...
[21:36:53.729] Database was detached successfully.
[21:36:53.745] Attaching database [QBCollection_Plus__Mount]...
[21:36:53.745] CREATE DATABASE [QBCollection_Plus__Mount] ON PRIMARY (NAME = 'DAD_INITIAL_DB_Data', FILENAME = 'Z:\Program Files\Microsoft SQL Server\MSSQL\Data\QBCollection_Plus.mdf') LOG ON (NAME = 'DAD_INITIAL_DB_Log', FILENAME = 'Y:\Program Files\Microsoft SQL Server\MSSQL\Data\QBCollection_Plus_log.ldf') FOR ATTACH
[21:37:17.183] 6 transactions rolled forward in database 'QBCollection_Plus__Mount' (7).
1 transactions rolled back in database 'QBCollection_Plus__Mount' (7).
[21:37:17.183] Database attached.
[21:37:17.183]
[21:37:17.183] DBCC CHECKDB (N'QBCollection_Plus__Mount') WITH NO_INFOMSGS, PHYSICAL_ONLY
[22:24:19.894] Table error: Allocation page (1:6656424) has invalid PFS_PAGE page header values. Type is 0. Check type, object ID and page ID on the page.
[22:24:19.894] WARNING: SQLServer DBCC CHECKDB failed. [22:24:19.909] SQLServer DBCC CHECKDB Failed, Error Code: 0x800422f2
[22:24:19.909] Detaching database [QBCollection_Plus__Mount]...
[22:24:20.019] Failed to detach the database.
[22:24:20.019] Attaching database [QBCollection_Plus_GR_Dialer__Mount]...
[22:24:20.019] CREATE DATABASE [QBCollection_Plus_GR_Dialer__Mount] ON PRIMARY (NAME = 'Epro_Data', FILENAME = 'Z:\Program Files\Microsoft SQL Server\MSSQL\Data\QBCollection_Plus_GR_Dialer.mdf') LOG ON (NAME = 'Epro_Log', FILENAME = 'Y:\Program Files\Microsoft SQL Server\MSSQL\Data\QBCollection_Plus_GR_Dialer_log.ldf') FOR ATTACH
[22:24:20.019] Device activation error. The physical file name 'Z:\Program Files\Microsoft SQL Server\MSSQL\Data\QBCollection_Plus_GR_Dialer.mdf' may be incorrect.
[22:24:20.019] DBCC CHECKDB (N'QBCollection_Plus_GR_Dialer__Mount') WITH NO_INFOMSGS, PHYSICAL_ONLY
[22:24:20.112] Could not locate entry in sysdatabases for database 'QBCollection_Plus_GR_Dialer__Mount'. No entry found with that name. Make sure that the name is entered correctly.
[22:24:20.112] WARNING: SQLServer DBCC CHECKDB failed. [22:24:20.128] SQLServer DBCC CHECKDB Failed, Error Code: 0x8004038f
[22:24:20.128] Detaching database [QBCollection_Plus_GR_Dialer__Mount]...
[22:24:20.237] Failed to detach the database.
[22:24:20.237] Dismounting Virtual Disk Z of SnapShot [sqlsnap__ec012qsql__recent]...
[22:24:33.519] Dismount Snapshot succeeded.
[22:24:33.519] Dismounting Virtual Disk Y of SnapShot [sqlsnap__ec012qsql__recent]...
[22:24:39.504] Dismount Snapshot succeeded.
[22:24:39.535] SQLServer DBCC CHECKDB Failed, Error Code: 0x8004038f
[22:24:39.582] Database verification information updated.
[22:24:39.598] There is an error during database verification. [22:24:39.598]
[22:24:39.598] **** FULL DATABASE BACKUP RESULT SUMMARY #1 ****
[22:24:39.598] Backup Time: 08-25-2008_21.00.00
[22:24:39.598] Backup Group [#1]:
[22:24:39.598] #1 : [EC012QSQL - Northwind] : OK
[22:24:39.598] #2 : [EC012QSQL - pubs] : OK
[22:24:39.598] #3 : [EC012QSQL - QBAnalytics] : OK
[22:24:39.598] #4 : [EC012QSQL - QBCollection_Plus] : Failed with error code 0xc0040813.
[22:24:39.598] #4 : [EC012QSQL - QBCollection_Plus] Error : Backup OK, but DBCC Failed.
[22:24:39.598] #5 : [EC012QSQL - QBCollection_Plus_GR_Dialer] : Failed with error code 0xc0040813.
[22:24:39.598] #5 : [EC012QSQL - QBCollection_Plus_GR_Dialer] Error : Backup OK, but DBCC Failed.
[22:24:39.598]
[22:24:39.598] *** SNAPMANAGER BACKUP JOB ENDED AT: [08-25-2008 22.24.39]
[22:24:39.598] SQLServer DBCC CHECKDB Failed, Error Code: 0x8004038f

I will appreciate any help

Regards

Aggelos

[BrendonHiggins]

We have our SQL verification on a 2nd SQL server just used for verification jobs, so rebooting the verification server is always our first step. I would recomend you run the SnapManager for SQL Server application and the use the 'Configuration Wizard' to confirm your setup is correct. Just accept the defaults and apply changes. Any 'faults' will be alerted as you follow the wizard.

So far this is all I have ever had to do with SQL. Don't set me off about SME!

Hope it helps and good luck.

Bren

[ivissupport]

Hi,

Thanks for reply...

As you can see from logs, this isn't a configuration error and also it happends on random hours...

[BrendonHiggins]

The log has "Failed to detach the database"& "Device activation error" messages in the logs. I was thinking you were having a problem with the flexclone being created on the SAN but snapdrive not configuringing the server in a timely fashion with the new volumes.

In the past I have found that when you click apply on the configuration wizard it will spit out error messages like QBCollection_Plus busy that does not show up anywere else.

Having a closer look at the log

[22:24:19.894] Table error: Allocation page (1:6656424) has invalid PFS_PAGE page header values. Type is 0. Check type, object ID and page ID on the page.

Would seam to be the problem to look closer at. I have found this link but it is not good news.

http://www.mydatabasesupport.com/forums/ms-sqlserver/136038-dbcc-checkdb.html

Is it always the database QBCollection_Plus? You could try and get your DBA to run DBCC CHECKDB against the live DB to confirm the source is not the problem.

[ivissupport]

You have right, but from the next full backup the errors they are not presented..

[ivissupport]

There are more errors now:

Connecting to SQL Server [EC012QSQL] for validation...
[05:00:05.426] *** SnapManager for SQL Server Report

[05:00:05.426] Backup Time Stamp: 08-27-2008_05.00.01
[05:00:05.426] Getting SQL Server Database Information, please wait...
[05:00:05.426] Getting virtual disks information...
[05:00:06.614] Querying SQL Server instances installed...
[05:00:06.614] Creating threads for enumerating databases of different SQL Server instances.
[05:00:06.614] Waiting for the threads to finish enumerating databases.
[05:00:06.629] Connecting to SQL Server instance - EC012QSQL...
[05:00:06.645] Getting SQL Server version information...
[05:00:06.723] Querying database information...
[05:00:07.004] All threads finished enumerating databases.
[05:00:07.004] Validating database configuration...
[05:00:07.004] Setting database disk configuration...
[05:00:07.004] Setting database locating on SQLRoot path...
[05:00:07.004] Querying database disk volume configuration...
[05:00:07.004] Getting SnapInfo directories configuration...

[05:00:07.004] Full database backup
[05:00:07.004] Maximum databases of concurrent backup: 20
[05:00:07.004] Naming convention: Generic
[05:00:07.004] Run transaction log backup after full database backup: No
[05:00:07.004] Keep the oldest 28 full backups.
[05:00:07.004] Retain up-to-the-minute restore ability for older backups in other management groups: No
[05:00:07.004] Verify snapshot after backup(run DBCC) on EC012QDFM: Yes
[05:00:07.004] Leave database attached after DBCC: No
[05:00:07.004] Run DBCC CHECKDB with Live Database Before Backup: No
[05:00:07.004] Run DBCC CHECKDB with Live Database After Backup: No
[05:00:07.004] Backup Management Group: Standard
[05:00:07.004] Update SnapMirror after operation: No
[05:00:07.004] Run Command after operation: No
[05:00:07.004]
[05:00:07.004] Backup Database 1: EC012QSQL : Northwind
[05:00:07.004] Backup Database 2: EC012QSQL : pubs
[05:00:07.004] Backup Database 3: EC012QSQL : QBAnalytics
[05:00:07.004] Backup Database 4: EC012QSQL : QBCollection_Plus
[05:00:07.004] Backup Database 5: EC012QSQL : QBCollection_Plus_GR_Dialer
[05:00:07.004] Backup Database Group #1:
[05:00:07.004] EC012QSQL : Northwind
[05:00:07.004] EC012QSQL : pubs
[05:00:07.004] EC012QSQL : QBAnalytics
[05:00:07.004] EC012QSQL : QBCollection_Plus
[05:00:07.004] EC012QSQL : QBCollection_Plus_GR_Dialer
[05:00:07.004]
[05:00:07.004] Backup job based on volume: #1
[05:00:07.004] Sub Job: #1 of Job#1
[05:00:07.004] 1 - EC012QSQL : Northwind
[05:00:07.004] 2 - EC012QSQL : pubs
[05:00:07.004] 3 - EC012QSQL : QBAnalytics
[05:00:07.004] 4 - EC012QSQL : QBCollection_Plus
[05:00:07.004] 5 - EC012QSQL : QBCollection_Plus_GR_Dialer
[05:00:07.004] **** BACKUP JOB **** #1
[05:00:07.004] Backup Time Stamp: 08-27-2008_05.00.01
[05:00:07.004] **** Backup Group [#1] of Job#1
[05:00:07.004] Backup Database List:
[05:00:07.004] 1 - EC012QSQL : Northwind
[05:00:07.020] 2 - EC012QSQL : pubs
[05:00:07.020] 3 - EC012QSQL : QBAnalytics
[05:00:07.020] 4 - EC012QSQL : QBCollection_Plus
[05:00:07.020] 5 - EC012QSQL : QBCollection_Plus_GR_Dialer
[05:00:07.020] Maximum worker threads setting for [EC012QSQL] = 255
[05:00:07.020] Current worker threads number for [EC012QSQL] = 250
[05:00:07.020] The number of databases selected for concurrent backup exceeds the maximum number of SQL Server worker threads that are available on the SQL Server EC012QSQL to perform this backup.
[05:00:07.020] Please increase the number of worker threads for SQL Server EC012QSQL to be greater than the sum of the worker thread required to service SQL Server client and the number of databases connected to SQL Server EC012QSQL, which are selected for concurrent backup.
[05:00:07.020] WARNING: SnapManager backup may fail.
[05:00:07.020] Please re-run Configuration Wizard, and specify 'Modify SQLServer maximum worker threads parameter' option to increase the maximum worker threads for the SQL Server EC012QSQL. Or decrease the maximum number of databases to backup concurrently.
[05:00:07.020] GETTING ALL DATABASES INFO SHARING THE SAME VOLUMES...

[05:00:23.333] Getting SnapInfo directory info...
[05:00:23.333] 1 - Database [Northwind] of [EC012QSQL] SnapInfo directory located at:
[05:00:23.333] I:\SMSQL_SnapInfo\VDISK__L&S
[05:00:23.333] 2 - Database [pubs] of [EC012QSQL] SnapInfo directory located at:
[05:00:23.333] I:\SMSQL_SnapInfo\VDISK__L&S
[05:00:23.333] 3 - Database [QBAnalytics] of [EC012QSQL] SnapInfo directory located at:
[05:00:23.333] I:\SMSQL_SnapInfo\VDISK__L&S
[05:00:23.333] 4 - Database [QBCollection_Plus] of [EC012QSQL] SnapInfo directory located at:
[05:00:23.333] I:\SMSQL_SnapInfo\VDISK__L&S
[05:00:23.333] 5 - Database [QBCollection_Plus_GR_Dialer] of [EC012QSQL] SnapInfo directory located at:
[05:00:23.333] I:\SMSQL_SnapInfo\VDISK__L&S
[05:00:23.333] CHECK SNAPMANAGER LICENSE ON VIRTUAL DISK.
[05:00:23.333] Querying virtual disk license: S:...
[05:00:23.333] Getting SnapInfo directory info...
[05:00:23.333] 1 - Database [Northwind] of [EC012QSQL] SnapInfo directory located at:
[05:00:23.333] I:\SMSQL_SnapInfo\VDISK__L&S
[05:00:23.333] 2 - Database [pubs] of [EC012QSQL] SnapInfo directory located at:
[05:00:23.333] I:\SMSQL_SnapInfo\VDISK__L&S
[05:00:23.333] 3 - Database [QBAnalytics] of [EC012QSQL] SnapInfo directory located at:
[05:00:23.333] I:\SMSQL_SnapInfo\VDISK__L&S
[05:00:23.333] 4 - Database [QBCollection_Plus] of [EC012QSQL] SnapInfo directory located at:
[05:00:23.333] I:\SMSQL_SnapInfo\VDISK__L&S
[05:00:23.333] 5 - Database [QBCollection_Plus_GR_Dialer] of [EC012QSQL] SnapInfo directory located at:
[05:00:23.333] I:\SMSQL_SnapInfo\VDISK__L&S
[05:00:23.333]
[05:00:23.333] RENAME MOST RECENT SNAPINFO BEFORE NEW BACKUP : EC012QSQL : Northwind - [#1]

[05:00:23.333] Rename old recent snapinfo folder from and to:
[05:00:23.333] I:\SMSQL_SnapInfo\VDISK__L&S\FG__\EC012QSQL__recent
[05:00:23.333] I:\SMSQL_SnapInfo\VDISK__L&S\FG__\08-27-2008_01.30.02
[05:00:23.333] SnapManager finds an alternative snapinfo directory for database [Northwind] of [EC012QSQL] at:
[05:00:23.333] I:\SMSQL_SnapInfo\SQL__EC012QSQL\DB__Northwind
[05:00:23.333]
[05:00:23.333] RENAME MOST RECENT SNAPINFO BEFORE NEW BACKUP : EC012QSQL : pubs - [#2]

[05:00:23.333] The recent backup snapinfo directory has already been renamed, it is sharing with other datatabases.
[05:00:23.333] SnapManager finds an alternative snapinfo directory for database [pubs] of [EC012QSQL] at:
[05:00:23.333] I:\SMSQL_SnapInfo\SQL__EC012QSQL\DB__pubs
[05:00:23.333]
[05:00:23.333] RENAME MOST RECENT SNAPINFO BEFORE NEW BACKUP : EC012QSQL : QBAnalytics - [#3]

[05:00:23.333] The recent backup snapinfo directory has already been renamed, it is sharing with other datatabases.
[05:00:23.333] SnapManager finds an alternative snapinfo directory for database [QBAnalytics] of [EC012QSQL] at:
[05:00:23.333] I:\SMSQL_SnapInfo\SQL__EC012QSQL\DB__QBAnalytics
[05:00:23.333]
[05:00:23.333] RENAME MOST RECENT SNAPINFO BEFORE NEW BACKUP : EC012QSQL : QBCollection_Plus - [#4]

[05:00:23.333] The recent backup snapinfo directory has already been renamed, it is sharing with other datatabases.
[05:00:23.333] SnapManager finds an alternative snapinfo directory for database [QBCollection_Plus] of [EC012QSQL] at:
[05:00:23.333] I:\SMSQL_SnapInfo\SQL__EC012QSQL\DB__QBCollection_Plus
[05:00:23.333]
[05:00:23.333] RENAME MOST RECENT SNAPINFO BEFORE NEW BACKUP : EC012QSQL : QBCollection_Plus_GR_Dialer - [#5]

[05:00:23.333] The recent backup snapinfo directory has already been renamed, it is sharing with other datatabases.
[05:00:23.333] SnapManager finds an alternative snapinfo directory for database [QBCollection_Plus_GR_Dialer] of [EC012QSQL] at:
[05:00:23.333] I:\SMSQL_SnapInfo\SQL__EC012QSQL\DB__QBCollection_Plus_GR_Dialer
[05:00:23.349]
[05:00:23.349] RENAME OLD MOST RECENT SNAPSHOT

[05:00:24.396] Rename Snapshot for virtual disk [S:] from [sqlsnap__ec012qsql__recent]
[05:00:24.396] To [sqlsnap__EC012QSQL_08-27-2008_01.30.02]
[05:00:25.817] Rename snapshot successfully completed.
[05:00:26.786] Rename Snapshot for virtual disk [L:] from [sqlsnap__ec012qsql__recent]
[05:00:26.786] To [sqlsnap__EC012QSQL_08-27-2008_01.30.02]
[05:00:28.161] Rename snapshot successfully completed.
[05:00:28.161] CREATE NEW RECENT SNAPINFO DIRECTORY : Northwind - [#1]

[05:00:28.161] SnapInfo file Name:
[05:00:28.161] I:\SMSQL_SnapInfo\VDISK__L&S\FG__\EC012QSQL__recent\SnapInfo__08-27-2008_05.00.01.sml
[05:00:28.161]
[05:00:28.161] CREATE NEW RECENT SNAPINFO DIRECTORY : pubs - [#2]

[05:00:28.161] SnapInfo file Name:
[05:00:28.161] I:\SMSQL_SnapInfo\VDISK__L&S\FG__\EC012QSQL__recent\SnapInfo__08-27-2008_05.00.01.sml
[05:00:28.161]
[05:00:28.161] CREATE NEW RECENT SNAPINFO DIRECTORY : QBAnalytics - [#3]

[05:00:28.161] SnapInfo file Name:
[05:00:28.161] I:\SMSQL_SnapInfo\VDISK__L&S\FG__\EC012QSQL__recent\SnapInfo__08-27-2008_05.00.01.sml
[05:00:28.161]
[05:00:28.161] CREATE NEW RECENT SNAPINFO DIRECTORY : QBCollection_Plus - [#4]

[05:00:28.161] SnapInfo file Name:
[05:00:28.161] I:\SMSQL_SnapInfo\VDISK__L&S\FG__\EC012QSQL__recent\SnapInfo__08-27-2008_05.00.01.sml
[05:00:28.161]
[05:00:28.161] CREATE NEW RECENT SNAPINFO DIRECTORY : QBCollection_Plus_GR_Dialer - [#5]

[05:00:28.161] SnapInfo file Name:
[05:00:28.161] I:\SMSQL_SnapInfo\VDISK__L&S\FG__\EC012QSQL__recent\SnapInfo__08-27-2008_05.00.01.sml
[05:00:28.161]
[05:00:28.161] *** STARTING SQL SERVER ONLINE BACKUP PROCESS

[05:00:28.161] Updating SnapInfo file for databases sharing same drive letter - [#1]
[05:00:28.161] Updating SnapInfo file for database - #1 : Northwind
[05:00:28.208] Updating SnapInfo file for database - #2 : pubs
[05:00:28.271] Updating SnapInfo file for database - #3 : QBAnalytics
[05:00:28.318] Updating SnapInfo file for database - #4 : QBCollection_Plus
[05:00:28.380] Updating SnapInfo file for database - #5 : QBCollection_Plus_GR_Dialer
[05:00:28.458]
[05:00:28.458] Starting VDI backup thread for database #1: [EC012QSQL : Northwind]...
[05:00:28.458] Starting VDI backup thread for database #2: [EC012QSQL : pubs]...
[05:00:28.458] Starting VDI backup thread for database #3: [EC012QSQL : QBAnalytics]...
[05:00:28.458] Starting VDI backup thread for database #4: [EC012QSQL : QBCollection_Plus]...
[05:00:28.458] Starting VDI backup thread for database #5: [EC012QSQL : QBCollection_Plus_GR_Dialer]...
[05:00:28.489] Sending SQL command to instance EC012QSQL for database QBCollection_Plus_GR_Dialer : device NTAPDEV__EC012QSQL_QBCollection_Plus_GR_Dialer...
[05:00:28.489] Sending SQL command to instance EC012QSQL for database Northwind : device NTAPDEV__EC012QSQL_Northwind...
[05:00:28.489] Receiving by server [EC012QSQL]...
[05:00:28.489] Sending SQL command to instance EC012QSQL for database QBAnalytics : device NTAPDEV__EC012QSQL_QBAnalytics...
[05:00:28.489] Receiving by server [EC012QSQL]...
[05:00:28.489] Sending SQL command to instance EC012QSQL for database pubs : device NTAPDEV__EC012QSQL_pubs...
[05:00:28.489] BACKUP DATABASE [Northwind] TO VIRTUAL_DEVICE='NTAPDEV__EC012QSQL_Northwind' WITH SNAPSHOT
[05:00:28.489] Receiving by server [EC012QSQL]...
[05:00:28.489] BACKUP DATABASE [QBAnalytics] TO VIRTUAL_DEVICE='NTAPDEV__EC012QSQL_QBAnalytics' WITH SNAPSHOT
[05:00:28.489] Receiving by server [EC012QSQL]...
[05:00:28.489] Waiting for SQLServer to respond...
[05:00:28.489] BACKUP DATABASE [QBCollection_Plus_GR_Dialer] TO VIRTUAL_DEVICE='NTAPDEV__EC012QSQL_QBCollection_Plus_GR_Dialer' WITH SNAPSHOT
[05:00:28.489] Waiting for SQLServer to respond...
[05:00:28.489] BACKUP DATABASE [pubs] TO VIRTUAL_DEVICE='NTAPDEV__EC012QSQL_pubs' WITH SNAPSHOT
[05:00:28.489] Waiting for SQLServer to respond...
[05:00:28.489] Waiting for SQLServer to respond...
[05:00:28.505] Sending SQL command to instance EC012QSQL for database QBCollection_Plus : device NTAPDEV__EC012QSQL_QBCollection_Plus...
[05:00:28.505] Receiving by server [EC012QSQL]...
[05:00:28.505] BACKUP DATABASE [QBCollection_Plus] TO VIRTUAL_DEVICE='NTAPDEV__EC012QSQL_QBCollection_Plus' WITH SNAPSHOT
[05:00:28.505] Waiting for SQLServer to respond...
[05:00:28.505] Performing data transfer of [EC012QSQL : QBAnalytics]...
[05:00:28.505] Performing data transfer of [EC012QSQL : QBCollection_Plus_GR_Dialer]...
[05:00:28.505] Performing data transfer of [EC012QSQL : QBCollection_Plus]...
[05:00:28.521] Performing data transfer of [EC012QSQL : pubs]...
[05:00:28.521] Performing data transfer of [EC012QSQL : Northwind]...
[05:00:28.958] SQL Server is prepared to freeze the database now [EC012QSQL : Northwind]...
[05:00:29.239] SQL Server is prepared to freeze the database now [EC012QSQL : pubs]...
[05:00:29.693] SQL Server is prepared to freeze the database now [EC012QSQL : QBCollection_Plus_GR_Dialer]...
[05:00:30.411] SQL Server is prepared to freeze the database now [EC012QSQL : QBCollection_Plus]...
[05:00:30.552] SQL Server is prepared to freeze the database now [EC012QSQL : QBAnalytics]...
[05:00:30.583] Ready to prepare to create snapshot...
[05:00:30.583]
[05:00:30.583] SNAPSHOT DATABASE

[05:00:30.583] Preparing Snapshot to Virtual Disk Drive:
[05:00:30.583] Virtual Disk [S:], Virtual Disk [L:]
[05:00:30.583] Snapshot Name: sqlsnap__EC012QSQL__recent
[05:00:30.583] Begin to create snapshot...
[05:00:31.786] SnapDrive is ready to create snapshot.
[05:00:31.786] Create Snapshot Now [EC012QSQL : QBCollection_Plus_GR_Dialer]...
[05:00:31.786] Create Snapshot Now [EC012QSQL : pubs]...
[05:00:31.786] Create Snapshot Now [EC012QSQL : Northwind]...
[05:00:31.786] Create Snapshot Now [EC012QSQL : QBAnalytics]...
[05:00:31.786] Create Snapshot Now [EC012QSQL : QBCollection_Plus]...
[05:00:31.786] All VDI backup threads completed snapshot preparation and databases IO are frozen for snapshot.
[05:00:31.786] SnapManager are ready to create snapshot...
[05:00:34.849] SQLServer is aware that the snapshot is successful.
[05:00:34.849] SQLServer is aware that the snapshot is successful.
[05:00:34.849] SQLServer is aware that the snapshot is successful.
[05:00:34.849] SQLServer is aware that the snapshot is successful.
[05:00:34.849] SQLServer is aware that the snapshot is successful.
[05:00:34.849] Snapshot virtual disk S, L: for database [Northwind] successfully completed.

[05:00:34.849] Snapshot virtual disk S, L: for database [pubs] successfully completed.

[05:00:34.849] Snapshot virtual disk S, L: for database [QBAnalytics] successfully completed.

[05:00:34.849] Snapshot virtual disk S, L: for database [QBCollection_Plus] successfully completed.

[05:00:34.849] Snapshot virtual disk S, L: for database [QBCollection_Plus_GR_Dialer] successfully completed.

[05:00:34.896] Msg 3014, SevLevel 0, State 1, SQLState 01000

[05:00:34.896] [Microsoft][ODBC SQL Server Driver][SQL Server]BACKUP DATABASE successfully processed 0 pages in 5.607 seconds (0.000 MB/sec).
[05:00:34.896] The SQL command executed.
[05:00:34.896] Msg 3014, SevLevel 0, State 1, SQLState 01000

[05:00:34.896] [Microsoft][ODBC SQL Server Driver][SQL Server]BACKUP DATABASE successfully processed 0 pages in 5.153 seconds (0.000 MB/sec).
[05:00:34.912] The SQL command executed.
[05:00:34.912] Msg 3014, SevLevel 0, State 1, SQLState 01000

[05:00:34.912] [Microsoft][ODBC SQL Server Driver][SQL Server]BACKUP DATABASE successfully processed 0 pages in 5.894 seconds (0.000 MB/sec).
[05:00:34.912] The SQL command executed.
[05:00:34.912] Msg 3014, SevLevel 0, State 1, SQLState 01000

[05:00:34.912] [Microsoft][ODBC SQL Server Driver][SQL Server]BACKUP DATABASE successfully processed 0 pages in 4.445 seconds (0.000 MB/sec).
[05:00:34.912] The SQL command executed.
[05:00:34.912] Msg 3014, SevLevel 0, State 1, SQLState 01000

[05:00:34.912] [Microsoft][ODBC SQL Server Driver][SQL Server]BACKUP DATABASE successfully processed 0 pages in 4.303 seconds (0.000 MB/sec).
[05:00:34.912] The SQL command executed.
[05:00:34.943]
[05:00:34.943] *** SNAPSHOT SNAPINFO DISK
[05:00:34.943]
[05:00:34.943] UPDATE MOST RECENT SNAPINFO DRIVE SNAPSHOT NAME

[05:00:36.755] Rename Snapshot for virtual disk [I:] from [sqlinfo__ec012qsql__recent]
[05:00:36.755] To [sqlinfo__EC012QSQL_08-27-2008_01.30.02]
[05:00:37.990] Rename snapshot successfully completed.
[05:00:37.990] SNAPSHOT SNAPINFO DRIVE

[05:00:37.990] Creating Snapshot of Virtual Disk Drive:
[05:00:37.990] Virtual Disk [I:]
[05:00:37.990] Snapshot name: sqlinfo__EC012QSQL__recent
[05:00:40.037] Snapshot SnapInfo drive(s) successfully completed.
[05:00:40.037] *** VERIFY DATABASE AFTER BACKUP
[05:00:40.037] Collecting verification information...
[05:00:40.037] Getting database backup information from SnapInfo file...
[05:00:40.037] Initializing SnapManager server on remote machine [EC012QDFM]...
[05:00:40.818] Mounting Snapshot [sqlsnap__ec012qsql__recent] for Virtual Disk S of Computer EC012QSQL
[05:01:10.382] This Snapshot is mounted as the drive [Z:].
[05:01:10.382] Mount Snapshot succeeded.
[05:01:10.382] Mounting Snapshot [sqlsnap__ec012qsql__recent] for Virtual Disk L of Computer EC012QSQL
[05:01:20.241] This Snapshot is mounted as the drive [Y:].
[05:01:20.241] Mount Snapshot succeeded.
[05:01:20.320] Using existing connection to server [EC012QDFM]...
[05:01:20.320] Attaching database [Northwind__Mount]...
[05:01:20.320] CREATE DATABASE [Northwind__Mount] ON PRIMARY (NAME = 'Northwind', FILENAME = 'Z:\Program Files\Microsoft SQL Server\MSSQL\data\northwnd.mdf') LOG ON (NAME = 'Northwind_log', FILENAME = 'Y:\Program Files\Microsoft SQL Server\MSSQL\data\northwnd.ldf') FOR ATTACH
[05:01:20.585] 1 transactions rolled back in database 'Northwind__Mount' (7).
[05:01:20.585] Database attached.
[05:01:20.585]
[05:01:20.585] DBCC CHECKDB (N'Northwind__Mount') WITH NO_INFOMSGS, PHYSICAL_ONLY
[05:01:20.788]
[05:01:20.788] DBCC CHECKDB completed successfully.

[05:01:20.788] Detaching database [Northwind__Mount]...
[05:01:20.929] Database was detached successfully.
[05:01:20.929] Attaching database [pubs__Mount]...
[05:01:20.929] CREATE DATABASE [pubs__Mount] ON PRIMARY (NAME = 'pubs', FILENAME = 'Z:\Program Files\Microsoft SQL Server\MSSQL\data\pubs.mdf') LOG ON (NAME = 'pubs_log', FILENAME = 'Y:\Program Files\Microsoft SQL Server\MSSQL\data\pubs_log.ldf') FOR ATTACH
[05:01:21.148] 1 transactions rolled back in database 'pubs__Mount' (7).
[05:01:21.148] Database attached.
[05:01:21.148]
[05:01:21.148] DBCC CHECKDB (N'pubs__Mount') WITH NO_INFOMSGS, PHYSICAL_ONLY
[05:01:21.273]
[05:01:21.273] DBCC CHECKDB completed successfully.

[05:01:21.273] Detaching database [pubs__Mount]...
[05:01:21.429] Database was detached successfully.
[05:01:21.429] Attaching database [QBAnalytics__Mount]...
[05:01:21.429] CREATE DATABASE [QBAnalytics__Mount] ON PRIMARY (NAME = 'QBAnalytics_Pilot_Data', FILENAME = 'Z:\Program Files\Microsoft SQL Server\MSSQL\Data\QBAnalytics_Pilot_Data.MDF') LOG ON (NAME = 'QBAnalytics_Pilot_Log', FILENAME = 'Y:\Program Files\Microsoft SQL Server\MSSQL\Data\QBAnalytics_Pilot_Log.LDF') FOR ATTACH
[05:01:50.930] 1 transactions rolled back in database 'QBAnalytics__Mount' (7).
[05:01:50.930] Database attached.
[05:01:50.930]
[05:01:50.930] DBCC CHECKDB (N'QBAnalytics__Mount') WITH NO_INFOMSGS, PHYSICAL_ONLY
[05:47:11.238]
[05:47:11.238] DBCC CHECKDB completed successfully.

[05:47:11.238] Detaching database [QBAnalytics__Mount]...
[05:47:11.660] Database was detached successfully.
[05:47:11.660] Attaching database [QBCollection_Plus__Mount]...
[05:47:11.660] CREATE DATABASE [QBCollection_Plus__Mount] ON PRIMARY (NAME = 'DAD_INITIAL_DB_Data', FILENAME = 'Z:\Program Files\Microsoft SQL Server\MSSQL\Data\QBCollection_Plus.mdf') LOG ON (NAME = 'DAD_INITIAL_DB_Log', FILENAME = 'Y:\Program Files\Microsoft SQL Server\MSSQL\Data\QBCollection_Plus_log.ldf') FOR ATTACH
[05:47:33.957] 1 transactions rolled back in database 'QBCollection_Plus__Mount' (7).
[05:47:33.957] Database attached.
[05:47:33.957]
[05:47:33.973] DBCC CHECKDB (N'QBCollection_Plus__Mount') WITH NO_INFOMSGS, PHYSICAL_ONLY
[07:32:45.981]
[07:32:45.981] DBCC CHECKDB completed successfully.

[07:32:45.981] Detaching database [QBCollection_Plus__Mount]...
[07:32:46.512] Database was detached successfully.
[07:32:46.512] Attaching database [QBCollection_Plus_GR_Dialer__Mount]...
[07:32:46.512] CREATE DATABASE [QBCollection_Plus_GR_Dialer__Mount] ON PRIMARY (NAME = 'Epro_Data', FILENAME = 'Z:\Program Files\Microsoft SQL Server\MSSQL\Data\QBCollection_Plus_GR_Dialer.mdf') LOG ON (NAME = 'Epro_Log', FILENAME = 'Y:\Program Files\Microsoft SQL Server\MSSQL\Data\QBCollection_Plus_GR_Dialer_log.ldf') FOR ATTACH
[07:32:58.122] 1 transactions rolled back in database 'QBCollection_Plus_GR_Dialer__Mount' (7).
[07:32:58.122] Database attached.
[07:32:58.122]
[07:32:58.122] DBCC CHECKDB (N'QBCollection_Plus_GR_Dialer__Mount') WITH NO_INFOMSGS, PHYSICAL_ONLY
[07:35:31.628] Operating system error 21(error not found) on device 'Y:\Program Files\Microsoft SQL Server\MSSQL\Data\QBCollection_Plus_GR_Dialer_log.ldf' during ForwardLogBlockReadAheadAsync.
[07:35:31.628] WARNING: SQLServer DBCC CHECKDB failed.

[07:35:31.644] SQLServer DBCC CHECKDB Failed, Error Code: 0x80041427
[07:35:31.644] Detaching database [QBCollection_Plus_GR_Dialer__Mount]...
[07:35:31.862] Failed to detach the database.
[07:35:31.862] Dismounting Virtual Disk Z of SnapShot [sqlsnap__ec012qsql__recent]...
[07:35:45.941] [SnapDrive Error]: The virtual disk may not be connected, because its mount point cannot be found. (SnapDrive Error Code: 0xc0040221)
[07:35:45.957] Re-trying to force dismounting Virtual disk...
[07:35:45.988] [SnapDrive Error]: The virtual disk may not be connected, because its mount point cannot be found. (SnapDrive Error Code: 0xc0040221)
[07:35:45.988] Dismounting Virtual Disk Y of SnapShot [sqlsnap__ec012qsql__recent]...
[07:36:00.020] [SnapDrive Error]: The virtual disk may not be connected, because its mount point cannot be found. (SnapDrive Error Code: 0xc0040221)
[07:36:00.035] Re-trying to force dismounting Virtual disk...
[07:36:00.051] [SnapDrive Error]: The virtual disk may not be connected, because its mount point cannot be found. (SnapDrive Error Code: 0xc0040221)
[07:36:00.113] SQLServer DBCC CHECKDB Failed, Error Code: 0x80041427
[07:36:00.192] Database verification information updated.
[07:36:00.207] There is an error during database verification.

[07:36:00.207]
[07:36:00.207] **** FULL DATABASE BACKUP RESULT SUMMARY #1 ****
[07:36:00.207] Backup Time: 08-27-2008_05.00.01
[07:36:00.207] Backup Group [#1]:
[07:36:00.207] #1 : [EC012QSQL - Northwind] : OK
[07:36:00.207] #2 : [EC012QSQL - pubs] : OK
[07:36:00.207] #3 : [EC012QSQL - QBAnalytics] : OK
[07:36:00.207] #4 : [EC012QSQL - QBCollection_Plus] : OK
[07:36:00.207] #5 : [EC012QSQL - QBCollection_Plus_GR_Dialer] : Failed with error code 0xc0040813.
[07:36:00.207] #5 : [EC012QSQL - QBCollection_Plus_GR_Dialer] Error : Backup OK, but DBCC Failed.
[07:36:00.207]
[07:36:00.223] *** SNAPMANAGER BACKUP JOB ENDED AT: [08-27-2008 07.36.00]
[07:36:00.223] SQLServer DBCC CHECKDB Failed, Error Code: 0x80041427

[sourav]

Hi Aggelos,

I would suggest that you try putting the two failing databases on a LUN and volume of their own and then see if you get the same error.

Clearly there is an issue with SDW timing out on the mounted virtual disk (Y:) so I think that if you have a iSCI connection to the storage from this host then it would be worthwhile to check for network delays too. The intermitent nature of the error points more towards this directions.

Regrads,

Sourav Chakraborty.

Technical Marketing Engineer (SMSQL , SMMOSS).

[gsraghava]

Hi,

We are running into an issue doing database backup verification on a remote server. It fails while trying to mount the snapshot.

[02:09:12.193]  [SnapDrive Error]: A timeout of 120 secs elapsed while waiting for volume arrival notification from the operating system.

(SnapDrive Error Code: 0xc00402e8)
[02:09:12.209]  Remote verification failed with FaultException<SmException>: Error code: 0xc00402e8.

[02:09:12.209]  Error Code: 0xc00402e8
A timeout of %1!d! secs elapsed while waiting for volume arrival notification from the operating system.

[sourav]

Hi,

This is an issue with the iSCSI initiator or the Host Utility Kit. If you have the HUK, can you please check the settings and reinstall it with the latest version?

Regards,

Sourav.