Data Backup and Recovery

SMSQL 6.0 error : Timeout expired. The timeout period elapsed prior to completion of the operation or the server is not responding.

JEANFRANCOISRIERA
8,033 Views

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

5 REPLIES 5

txskibum2000
8,033 Views

Im having this problem too..

bazmercer
8,033 Views

Hi,

What's the "remote query timout" set to? Server properties>connections. I think it defaults to ten minutes, though why it worked with smsql5.1 and not 6 is a mystery.

SHALEVSIS
8,033 Views

A few days ago 6.0.1 was released. One of the bugs this release address is the timeout you're experiencing.

Try updating your SMSQL to 6.0.1

txskibum2000
8,033 Views

Well, i rolled back from 6.0 to 5.2P1.  No more issues.  I will stay away from 6.x unless I need it for Win2012 or something else.

gharmon
8,033 Views

This issue is addressed by BURT:660615

SnapManager 6.0 for Microsoft SQL Server (SMSQL) transaction log backup fails with "Timeout expired"

http://support.netapp.com/NOW/cgi-bin/bol?Type=Detail&Display=660615

Description

Formatted    

In SnapManager 6.0 for Microsoft SQL Server, if a transaction log backup

takes more than 10 minutes, it will fail with error

[SQL SMO Error]: Backup failed for Server 'SOMEW'.

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.

Workaround

Formatted    

Add a DWORD registry "LogBackupUseSMO" in HKEY_LOCAL_MACHINE\SOFTWARE\

Network Appliance\SnapManager for SQL Server\Server and set it to 0,

then restart SnapMgrService.

Notes

Formatted    

In SMSQL 6.0, SnapManager for SQL uses a different method than in prior

releases for backing up transaction logs, and this method has a timeout

of 10 minutes.

Note the above mentioned workaround does not support copy-only log backup.

Public