Restore Log takes many hours to fail

Compresses, encrypts, secures and monitors SQL Server backups.

Moderators: JonathanWatts, Chris Auckland, eddie davis, Colin Millerchip, Brian Harris, james.billings, RBA, petey

Restore Log takes many hours to fail

Postby reinisb » Thu Feb 07, 2013 5:13 pm

Hi,

We have a daily log restore to a secondary database. For one reason or another, we have problems getting all the user connections to be automatically disconnected before the restore starts and so sometimes we get the restore failing with the error 1010 "could not get exclusive access to the database".

The weird thing is, the restore log attempts to start at 9.30pm, but it takes all the way until 4.15am before the job actually fails. It seems that redgate doesn't realize for 7 hours that it can't start the restore.

Why does it take so long for it to report a failure?

It's kind of a bummer because if it failed within 20mins of starting, I would still be awake to manually restart it!

Any thoughts? I'm actually using SQL Backup 6.5 (sorry i know this is the SQL 7 forum - couldn't see one for 6.5).

Thanks,

Reinis
reinisb
 
Posts: 13
Joined: Thu Jul 05, 2012 4:31 pm

Postby petey » Sat Feb 09, 2013 2:58 pm

Is the secondary database read-only, or read-write?
Peter Yeoh
SQL Backup Consultant Developer
Associate, Yohz Software
Beyond compression - SQL Backup goodies under the hood, updated for version 7
petey
 
Posts: 2233
Joined: Sun Apr 24, 2005 12:34 pm

Postby reinisb » Mon Feb 11, 2013 4:24 pm

Standy/Read-only because it's the log shipping target.

Reinis
reinisb
 
Posts: 13
Joined: Thu Jul 05, 2012 4:31 pm

Postby petey » Tue Feb 12, 2013 2:52 pm

Could you please post the contents of the SQL Backup log file for the restore process that failed? The default folder where the logs are stored is C:\\Documents and Settings\\All Users\\Application Data\\Red Gate\\SQL Backup\\Log\\<instance name> on Windows 2003 and older, and C:\\ProgramData\\Red Gate\\SQL Backup\\Log\\<instance name> on Windows Vista and newer.
Peter Yeoh
SQL Backup Consultant Developer
Associate, Yohz Software
Beyond compression - SQL Backup goodies under the hood, updated for version 7
petey
 
Posts: 2233
Joined: Sun Apr 24, 2005 12:34 pm

Postby reinisb » Tue Feb 12, 2013 7:31 pm

Here is the log. The names have been changed to protect the innocent. javascript:emoticon(':roll:') Failed_LS is the target database for the restore, and server2 is the Windows Server 2003 the instance is on.

I included only a partial list of the connections that were listed because I didn't want to go through changing all of them. There are a number that are shown as connected to the database we are trying to restore to but immediately before i start the restore I kill all the connections to that database. The connections listed for the restore DB are therefore created in the intervening 6 hours that the restore is failing - i checked the last batch time for all of them.

If you can figure out why it seems the restore still does not work despite the disconnect_existing, and my kill spids routine that would be a bonus. I've also tried having a trigger on the database to disallow any connections for 5 mins around the time the restore starts and that didn't work either.

Reinis

------------------------------------------------------------------------------
SQL Backup log file 6.5.1.9

-SQL \"RESTORE LOG [Failed_LS] FROM DISK = '\\\\server2\\Failed_LS_Share\\LOG_Failed_*.sqb' WITH ERASEFILES = 5, DISCONNECT_EXISTING, FILEOPTIONS = 1, STANDBY = 'I:\\Failed_LS\\UNDO_Failed_LS.dat', MOVETO = 'J:\\Failed_LS\\Completed' \"

----------------------------- ERRORS AND WARNINGS -----------------------------


2/10/2013 9:30:00 PM: Restoring Failed_LS (transaction logs) from:
2/10/2013 9:30:00 PM: \\\\server2\\Failed_LS_Share\\LOG_Failed_20130209220000.sqb

2/10/2013 9:30:04 PM: ALTER DATABASE [Failed_LS] SET ONLINE RESTORE LOG [Failed_LS] FROM VIRTUAL_DEVICE = 'SQLBACKUP_FF135A4B-697A-4263-B702-0A2FFFF8AEEA', VIRTUAL_DEVICE = 'SQLBACKUP_FF135A4B-697A-4263-B702-0A2FFFF8AEEA01', VIRTUAL_DEVICE = 'SQLBACKUP_FF135A4B-697A-4263-B702-0A2FFFF8AEEA02', VIRTUAL_DEVICE = 'SQLBACKUP_FF135A4B-697A-4263-B702-0A2FFFF8AEEA03', VIRTUAL_DEVICE = 'SQLBACKUP_FF135A4B-697A-4263-B702-0A2FFFF8AEEA04', VIRTUAL_DEVICE = 'SQLBACKUP_FF135A4B-697A-4263-B702-0A2FFFF8AEEA05', VIRTUAL_DEVICE = 'SQLBACKUP_FF135A4B-697A-4263-B702-0A2FFFF8AEEA06' WITH BUFFERCOUNT = 28, BLOCKSIZE = 65536, MAXTRANSFERSIZE = 1048576 , NORECOVERY

2/11/2013 4:19:40 AM: 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]
2/11/2013 4:19:40 AM: Also check that the database is not currently in use.
2/11/2013 4:19:40 AM:
2/11/2013 4:19:40 AM: SPID Status Login HostName BlkBy DBName Command CPUTime DiskIO LastBatch ProgramName SPID_1 REQUESTID
2/11/2013 4:19:40 AM: ----- ------------------------------ -------------------------------------------------------- ---------- ----- ---------------- ---------------- ------- -------- -------------- ------------------------------------------------------------------------- ------ ---------
2/11/2013 4:19:40 AM: 1 BACKGROUND sa . . RESOURCE MONITOR 1257406 26548 01/25 14:46:54 1 0
2/11/2013 4:19:40 AM: 2 SUSPENDED sa . . LOG WRITER 2825296 0 01/25 14:46:54 2 0
2/11/2013 4:19:40 AM: 3 BACKGROUND sa . . master SIGNAL HANDLER 0 0 01/25 14:46:54 3 0
2/11/2013 4:19:40 AM: 4 BACKGROUND sa . . LOCK MONITOR 31 0 01/25 14:46:54 4 0
2/11/2013 4:19:40 AM: 5 BACKGROUND sa . . LAZY WRITER 1626859 0 01/25 14:46:54 5 0
2/11/2013 4:19:40 AM: 6 sleeping sa . . master TASK MANAGER 0 0 01/25 14:46:54 6 0
2/11/2013 4:19:40 AM: 7 BACKGROUND sa . . master TRACE QUEUE TASK 11765 0 01/25 14:46:54 7 0
2/11/2013 4:19:40 AM: 8 sleeping sa . . UNKNOWN TOKEN 0 0 01/25 14:46:54 8 0
2/11/2013 4:19:40 AM: 9 BACKGROUND sa . . master BRKR TASK 0 0 01/25 14:46:54 9 0
2/11/2013 4:19:40 AM: 10 BACKGROUND sa . . master CHECKPOINT 2473062 97776 01/25 14:46:54 10 0
2/11/2013 4:19:40 AM: 11 BACKGROUND sa . . master TASK MANAGER 125 38 01/25 14:46:54 11 0
2/11/2013 4:19:40 AM: 12 BACKGROUND sa . . master BRKR EVENT HNDLR 15 39 01/25 14:46:54 12 0
2/11/2013 4:19:40 AM: 13 BACKGROUND sa . . master BRKR TASK 0 0 01/25 14:46:54 13 0
2/11/2013 4:19:40 AM: 14 sleeping sa . . master TASK MANAGER 0 3 01/25 14:46:54 14 0
2/11/2013 4:19:40 AM: 15 sleeping sa . . master TASK MANAGER 0 0 01/25 14:46:54 15 0
2/11/2013 4:19:40 AM: 16 sleeping sa . . master TASK MANAGER 0 114 01/25 14:46:54 16 0
2/11/2013 4:19:40 AM: 17 sleeping sa . . master TASK MANAGER 0 0 01/25 14:46:54 17 0
2/11/2013 4:19:40 AM: 18 sleeping sa . . master TASK MANAGER 0 0 01/25 14:46:54 18 0
2/11/2013 4:19:40 AM: 19 sleeping sa . . master TASK MANAGER 0 29 01/25 14:46:54 19 0

.....................................................

2/11/2013 4:19:40 AM:
2/11/2013 4:19:40 AM: SQL error 3013: RESTORE LOG is terminating abnormally.
2/11/2013 4:19:40 AM: SQL error 3101: Exclusive access could not be obtained because the database is in use.
reinisb
 
Posts: 13
Joined: Thu Jul 05, 2012 4:31 pm

Postby petey » Wed Feb 13, 2013 4:02 am

By default, SQL Backup would only wait 30 seconds for SQL Server to start the restore, before it aborts the process. In this case, it waited almost 7 hours. What is the VDITimeout value in the HKEY_LOCAL_MACHINE\\SOFTWARE\\Red Gate\\SQL Backup\\BackupSettingsGlobal\\[InstanceName] registry node?
Peter Yeoh
SQL Backup Consultant Developer
Associate, Yohz Software
Beyond compression - SQL Backup goodies under the hood, updated for version 7
petey
 
Posts: 2233
Joined: Sun Apr 24, 2005 12:34 pm

Postby reinisb » Wed Feb 13, 2013 6:02 am

The value is 24576 which would be 6.8 hours (I assume that is in seconds) so it seems to make sense. I have no idea why that would be set to such a high value. I switched it to 30 so we'll see what happens with that.

Thanks,

Reinis
reinisb
 
Posts: 13
Joined: Thu Jul 05, 2012 4:31 pm


Return to SQL Backup 7

Who is online

Users browsing this forum: No registered users and 1 guest