Hi,
Last week, I upgrade my SMSQL 5.1 to 6.0. Now I have an error in backup jobs.
There is a timeout with the transaction log backup with truncate task exactly 10 minutes after the task starts. In SMSQL 5.1 tasks could take about 25 minutes with no timeout...
I didn't find any parameters about this timeout in SMSQL.
[09:15:02.047] [FR-S-DTA-SQLP1] *** SnapManager for SQL Server Report
[09:15:02.094] [FR-S-DTA-SQLP1] Getting SQL Server Database Information, please wait...
[09:15:02.094] [FR-S-DTA-SQLP1] Creating thread for enumerating all databases from all nodes...
[09:15:02.094] [FR-S-DTA-SQLP1] Waiting for the threads to finish enum all databases...
[09:15:02.094] [FR-S-DTA-SQLP1] Get database and LUN information...
[09:15:02.094] [FR-S-DTA-SQLP1] Getting virtual disks information...
[09:15:04.937] [FR-S-DTA-SQLP1] Querying SQL Server instances installed...
[09:15:04.937] [FR-S-DTA-SQLP1] Querying installed SQL Server instances on [FR-S-DTA-SQLP1]...
[09:15:04.937] [FR-S-DTA-SQLP1] Allocating ODBC environment handle...
[09:15:04.937] [FR-S-DTA-SQLP1] Setting environment attribute...
[09:15:04.937] [FR-S-DTA-SQLP1] Setting SQLBrowseConnect option...
[09:15:04.937] [FR-S-DTA-SQLP1] SQLBrowseConnect...
[09:15:04.937] [FR-S-DTA-SQLP1] Parsing SQLBrowseConnect server string...
[09:15:04.953] [FR-S-DTA-SQLP1] Creating threads for enumerating databases of different SQL Server instances.
[09:15:04.953] [FR-S-DTA-SQLP1] Waiting for the threads to finish enumerating databases.
[09:15:06.141] [FR-S-DTA-SQLP1] [SMO] Connecting to SQL Server instance - FR-S-DTA-SQLP1...
[09:15:06.141] [FR-S-DTA-SQLP1] [SMO] Querying database information...
[09:15:06.344] [FR-S-DTA-SQLP1] All threads finished enumerating databases.
[09:15:06.344] [FR-S-DTA-SQLP1] Validating database configuration...
[09:15:06.344] [FR-S-DTA-SQLP1] Setting database disk configuration...
[09:15:06.344] [FR-S-DTA-SQLP1] Setting database locating on SQLRoot path...
[09:15:06.344] [FR-S-DTA-SQLP1] Querying database disk volume configuration...
[09:15:06.344] [FR-S-DTA-SQLP1] Getting SnapInfo directories configuration...
[09:15:06.359] [FR-S-DTA-SQLP1] Checking dataset availability, connecting to SnapDrive...
[09:15:06.453] [FR-S-DTA-SQLP1] Dataset feature is currently unavailable.
[09:15:06.453] [FR-S-DTA-SQLP1] Getting SnapManager dataset info from...
[09:15:06.453] [FR-S-DTA-SQLP1] Dataset info file has not yet created.
[09:15:06.469] [FR-S-DTA-SQLP1] Getting SnapMirror Destinations Volumes...
[09:15:10.125] [FR-S-DTA-SQLP1] Update selected destination volumes information for SQL Server FR-S-DTA-SQLP1 succeeded.
[09:15:10.125] [FR-S-DTA-SQLP1] Get all destination volumes state successfully.
[09:15:10.125] [FR-S-DTA-SQLP1] Sub-grouping databases...
[09:15:10.125] [FR-S-DTA-SQLP1] Sub-Group #0:
[09:15:10.125] [FR-S-DTA-SQLP1] Host server (FR-S-DTA-SQLP1) Federated Group ID (-1) Instance Name (FR-S-DTA-SQLP1) Database Name (AXPROD)
[09:15:10.125] [FR-S-DTA-SQLP1] Host server (FR-S-DTA-SQLP1) Federated Group ID (-1) Instance Name (FR-S-DTA-SQLP1) Database Name (ReportServer)
[09:15:10.125] [FR-S-DTA-SQLP1] Host server (FR-S-DTA-SQLP1) Federated Group ID (-1) Instance Name (FR-S-DTA-SQLP1) Database Name (ReportServerTempDB)
[09:15:10.125] [FR-S-DTA-SQLP1] Sub-Group #1:
[09:15:10.125] [FR-S-DTA-SQLP1] Federated backup(main): Backup Time Stamp: 02-11-2013_09.15.01
[09:15:10.125] [FR-S-DTA-SQLP1] Starting backup for each federated groups.....
[09:15:10.125] [FR-S-DTA-SQLP1] Retrieving database and LUN information...
[09:15:10.125] [FR-S-DTA-SQLP1] Creating thread for remote backup group(-1) sub-group server(FR-S-DTA-SQLP1) thread index(0).....
[09:15:10.125] [FR-S-DTA-SQLP1] Waiting for the threads in group -1 to finish remote backup group...
[09:15:10.141] [FR-S-DTA-SQLP1] Backup Time Stamp: 02-11-2013_09.15.10
[09:15:10.141] [FR-S-DTA-SQLP1] WARNING: Database [ReportServerTempDB] of [FR-S-DTA-SQLP1] is in simple recovery mode, and will not be included in this backup.
[09:15:10.141] [FR-S-DTA-SQLP1] Backup Database Transaction Log List:
[09:15:10.141] [FR-S-DTA-SQLP1] 1-FR-S-DTA-SQLP1 : AXPROD
[09:15:10.141] [FR-S-DTA-SQLP1] 2-FR-S-DTA-SQLP1 : ReportServer
[09:15:10.141] [FR-S-DTA-SQLP1] Transaction log backup
[09:15:10.141] [FR-S-DTA-SQLP1] Delete older log backup: No
[09:15:10.141] [FR-S-DTA-SQLP1] Verify log backup upon completion: Yes
[09:15:10.141] [FR-S-DTA-SQLP1] Create snapshot of SnapInfo drive after backup: Yes
[09:15:10.141] [FR-S-DTA-SQLP1] Delete older SnapInfo snapshots: Yes
Keep 168 SnapInfo snapshots.
[09:15:10.141] [FR-S-DTA-SQLP1] Transaction logs will be truncated after backup: Yes
[09:15:10.141] [FR-S-DTA-SQLP1] Transaction log backup will be backed up to SMSQL share for only databases belonging to Availability Group.
[09:15:10.141] [FR-S-DTA-SQLP1] Update SnapMirror after operation: Yes
[09:15:10.141] [FR-S-DTA-SQLP1] Run Command before the operation: No
[09:15:10.141] [FR-S-DTA-SQLP1] Run Command after the operation: No
[09:15:10.141] [FR-S-DTA-SQLP1]
[09:15:10.141] [FR-S-DTA-SQLP1] CHECK SNAPMANAGER LICENSE ON LUN.
[09:15:10.141] [FR-S-DTA-SQLP1] Querying LUN license: G...
[09:15:10.141] [FR-S-DTA-SQLP1] Querying LUN license: d...
[09:15:10.141] [FR-S-DTA-SQLP1] *** TRANSACTION LOG BACKUP
[09:15:10.141] [FR-S-DTA-SQLP1] TRANSACTION LOG BACKUP [#1]
[09:15:10.141] [FR-S-DTA-SQLP1] Transaction log backup location for database [AXPROD]:
[09:15:10.141] [FR-S-DTA-SQLP1] G:\SMSQL_SnapInfo\VDISK__D&E\LogBackup\LOGINST__FR-S-DTA-SQLP1\LOGDB__AXPROD\02-11-2013_09.15.10__AXPR.TRB
[09:15:10.141] [FR-S-DTA-SQLP1] Connecting to SQL server FR-S-DTA-SQLP1...
[09:15:10.141] [FR-S-DTA-SQLP1] Transaction log backup for database [AXPROD] will truncate logs...
[09:15:10.141] [FR-S-DTA-SQLP1] Starting to backup transaction log for database [AXPROD]...
[09:17:09.611] [FR-S-DTA-SQLP1] Database [FR-S-DTA-SQLP1:AXPROD] Percent: 5% completed
[09:19:17.347] [FR-S-DTA-SQLP1] Database [FR-S-DTA-SQLP1:AXPROD] Percent: 10% completed
[09:21:16.786] [FR-S-DTA-SQLP1] Database [FR-S-DTA-SQLP1:AXPROD] Percent: 15% completed
[09:22:32.678] [FR-S-DTA-SQLP1] Database [FR-S-DTA-SQLP1:AXPROD] Percent: 20% completed
[09:23:57.788] [FR-S-DTA-SQLP1] Database [FR-S-DTA-SQLP1:AXPROD] Percent: 25% completed
[09:25:10.211] [FR-S-DTA-SQLP1] [SQL SMO Error]: Backup failed for Server 'FR-S-DTA-SQLP1'.
An exception occurred while executing a Transact-SQL statement or batch.
Timeout expired. The timeout period elapsed prior to completion of the operation or the server is not responding.
[09:25:10.211] [FR-S-DTA-SQLP1] [SQL SMO Error]: Backup failed for Server 'FR-S-DTA-SQLP1'.
An exception occurred while executing a Transact-SQL statement or batch.
Timeout expired. The timeout period elapsed prior to completion of the operation or the server is not responding.
[09:25:10.211] [FR-S-DTA-SQLP1] [SQL SMO Error]: Backup failed for Server 'FR-S-DTA-SQLP1'.
An exception occurred while executing a Transact-SQL statement or batch.
Timeout expired. The timeout period elapsed prior to completion of the operation or the server is not responding.
[09:25:10.211] [FR-S-DTA-SQLP1]
[09:25:10.211] [FR-S-DTA-SQLP1] TRANSACTION LOG BACKUP [#2]
[09:25:10.211] [FR-S-DTA-SQLP1] Transaction log backup location for database [ReportServer]:
[09:25:10.211] [FR-S-DTA-SQLP1] G:\SMSQL_SnapInfo\VDISK__D&E\LogBackup\LOGINST__FR-S-DTA-SQLP1\LOGDB__ReportServer\02-11-2013_09.15.10__Repo.TRB
[09:25:10.211] [FR-S-DTA-SQLP1] Transaction log backup for database [ReportServer] will truncate logs...
[09:25:10.211] [FR-S-DTA-SQLP1] Starting to backup transaction log for database [ReportServer]...
[09:25:10.242] [FR-S-DTA-SQLP1] Database [FR-S-DTA-SQLP1:ReportServer] Percent: 100% completed
[09:25:10.414] [FR-S-DTA-SQLP1] Database [FR-S-DTA-SQLP1:ReportServer] System.Data.SqlClient.SqlError: BACKUP LOG successfully processed 0 pages in 0.059 seconds (0.000 MB/sec).
[09:25:10.414] [FR-S-DTA-SQLP1] Transaction log backup of database [ReportServer] completed.
[09:25:10.414] [FR-S-DTA-SQLP1] Verifying transaction log backup...
[09:25:10.445] [FR-S-DTA-SQLP1] Transaction log backup verification of database [ReportServer] successfully completed.
[09:25:10.445] [FR-S-DTA-SQLP1] WARNING: Transaction log backup failed!
[09:25:10.445] [FR-S-DTA-SQLP1]
[09:25:10.445] [FR-S-DTA-SQLP1] **** TRANSACTION LOG BACKUP RESULT SUMMARY ****
[09:25:10.445] [FR-S-DTA-SQLP1] Backup Group [#1]:
[09:25:10.445] [FR-S-DTA-SQLP1] #1 : [FR-S-DTA-SQLP1 - AXPROD] : Failed with error code 0x80004005.
[09:25:10.445] [FR-S-DTA-SQLP1] #1 : [FR-S-DTA-SQLP1 - AXPROD] Error : Failed to backup transaction log.
[09:25:10.445] [FR-S-DTA-SQLP1] #1 : [FR-S-DTA-SQLP1 - AXPROD] Error Details: [SQL SMO Error]: Backup failed for Server 'FR-S-DTA-SQLP1'.
An exception occurred while executing a Transact-SQL statement or batch.
Timeout expired. The timeout period elapsed prior to completion of the operation or the server is not responding.
[09:25:10.445] [FR-S-DTA-SQLP1] #2 : [FR-S-DTA-SQLP1 - ReportServer] : OK
[09:25:10.445] [FR-S-DTA-SQLP1]
[09:25:10.445] [FR-S-DTA-SQLP1] *** SNAPMANAGER LOG BACKUP JOB ENDED AT: [02-11-2013 09.25.10]
[09:25:10.445] [FR-S-DTA-SQLP1] Error Code: 0x80004005
Unspecified error
[09:25:10.445] [FR-S-DTA-SQLP1] Preparing for sending filer AutoSupport...
[09:25:10.539] [FR-S-DTA-SQLP1] A filer autosupport message is sent on failure.
[09:25:10.539] [FR-S-DTA-SQLP1]
[09:25:10.539] [FR-S-DTA-SQLP1] Federated backup(VDI): Setting abort [backup start ready] event to the driving server [FR-S-DTA-SQLP1] for host [FR-S-DTA-SQLP1]...
[09:25:10.539] [FR-S-DTA-SQLP1] Federated backup(VDI): Setting abort [prepare for snapshot] event to the driving server [FR-S-DTA-SQLP1] for host [FR-S-DTA-SQLP1]...
[09:25:10.539] [FR-S-DTA-SQLP1] Federated backup(VDI): Setting abort [ready for snapshot] event to the driving server [FR-S-DTA-SQLP1] for host [FR-S-DTA-SQLP1]...
[09:25:10.539] [FR-S-DTA-SQLP1] Federated backup(VDI): Setting abort [go create snapshot] event to the driving server [FR-S-DTA-SQLP1] for host [FR-S-DTA-SQLP1]...
[09:25:10.539] [FR-S-DTA-SQLP1] Federated backup(VDI): Setting abort [ready for marking log] event to the driving server [FR-S-DTA-SQLP1] for host [FR-S-DTA-SQLP1]...
[09:25:10.539] [FR-S-DTA-SQLP1] All threads finished remote backup groups.
[09:25:10.539] [FR-S-DTA-SQLP1]
[09:25:10.539] [FR-S-DTA-SQLP1] **** TRANSACTION LOG BACKUP RESULT SUMMARY #1 ****
[09:25:10.539] [FR-S-DTA-SQLP1] Backup Group [#1]:
[09:25:10.539] [FR-S-DTA-SQLP1] #1 : [FR-S-DTA-SQLP1 - AXPROD] : Failed with error code 0x80004005.
[09:25:10.539] [FR-S-DTA-SQLP1] #1 : [FR-S-DTA-SQLP1 - AXPROD] Error : Failed to backup transaction log.
[09:25:10.539] [FR-S-DTA-SQLP1] #1 : [FR-S-DTA-SQLP1 - AXPROD] Error Details: [SQL SMO Error]: Backup failed for Server 'FR-S-DTA-SQLP1'.
An exception occurred while executing a Transact-SQL statement or batch.
Timeout expired. The timeout period elapsed prior to completion of the operation or the server is not responding.
[09:25:10.539] [FR-S-DTA-SQLP1] #2 : [FR-S-DTA-SQLP1 - ReportServer] : OK
[09:25:10.539] [FR-S-DTA-SQLP1]
[09:25:10.539] [FR-S-DTA-SQLP1] #1 : Backup Group: Server - [FR-S-DTA-SQLP1]: Failed with error 0x80004005
[09:25:10.539] [FR-S-DTA-SQLP1] Backup Group: Failed with error 0x80004005
[09:25:10.539] [FR-S-DTA-SQLP1] Preparing for sending filer AutoSupport...
[09:25:10.539] [FR-S-DTA-SQLP1] **** BACKUP RESULT DETAILS ****
#1 : Backup Group: Server - [FR-S-DTA-SQLP1]: Failed with error 0x80004005
**** TRANSACTION LOG BACKUP RESULT SUMMARY #1 ****
Backup Group [#1]:
#1 : [FR-S-DTA-SQLP1 - AXPROD] Error : Failed to backup transaction log.
#1 : [FR-S-DTA-SQLP1 - AXPROD] Error Details: [SQL SMO Error]: Backup failed for Server 'FR-S-DTA-SQLP1'.
An exception occurred while executing a Transact-SQL statement or batch.
Timeout expired. The timeout period elapsed prior to completion of the operation or the server is not responding.
#2 : [FR-S-DTA-SQLP1 - ReportServer] : OK
[09:25:10.539] [FR-S-DTA-SQLP1] **** BACKUP RESULT SUMMARY ****
Backup Group: Failed with error 0x80004005
[09:25:10.539] [FR-S-DTA-SQLP1]
Thanks for your help,
JF Riera
