How can we help you today? How can we help you today?
meastland
Peter, Thanks for the suggestions. I see the following SQLVDI errors in the Application Log which seem to correspond with the time that the restore failed: Log Name: Application Source: SQLVDI Date: 4/26/2011 7:15:19 AM Event ID: 1 Task Category: None Level: Error Keywords: Classic User: N/A Computer: SQLDEV.uhlig.com Description: SQLVDI: Loc=CVDS::Close. Desc=Open devices!. ErrorCode=(0). Process=2008. Thread=2196. Client. Instance=. VD=Global\SQLBACKUP_CD6523F1-6602-4913-B5F8-47A982752801_SQLVDIMemoryName_0. Log Name: Application Source: SQLVDI Date: 4/26/2011 7:15:19 AM Event ID: 1 Task Category: None Level: Error Keywords: Classic User: N/A Computer: SQLDEV.uhlig.com Description: SQLVDI: Loc=SignalAbort. Desc=Client initiates abort. ErrorCode=(0). Process=2008. Thread=2196. Client. Instance=. VD=Global\SQLBACKUP_CD6523F1-6602-4913-B5F8-47A982752801_SQLVDIMemoryName_0. Looking at the SQL Server error log, I also see that a process was killed by the local host around the same time. While I can't say for sure that the killed process is related to the sqlBackup error, there isn't much else going on with the server at the time of the failed restore. Date 4/26/2011 7:15:20 AM Log SQL Server (Current - 4/26/2011 12:29:00 AM) Source spid62 Message Process ID 93 was killed by hostname SQLDEV, host process ID 2208. Does this information get us any closer to a possible root cause? Thanks, -Mike / comments
Peter, Thanks for the suggestions. I see the following SQLVDI errors in the Application Log which seem to correspond with the time that the restore failed:Log Name: Application Source: ...
0 votes
Peter, The restore process failed again this morning with the same error for the same database. Unfortunately, the log file that was generated doesn't seem to contain much additional information. Here is the contents of the log file in its entirety: SQL Backup log file 6.4.0.1014 -SQL "RESTORE DATABASE [Resales4] FROM DISK = '\\uhlig.com\prod\SQLBackups\*Resales4*.sqb' LATEST_ALL WITH DISCONNECT_EXISTING, DISKRETRYCOUNT = 10, DISKRETRYINTERVAL = 30, MAILTO_ONERRORONLY = '****', PASSWORD = 'XXXXXXXXXX', RECOVERY, REPLACE " ERRORS AND WARNINGS 4/26/2011 7:01:38 AM: Restoring Resales4 (database) from: 4/26/2011 7:01:38 AM: \\uhlig.com\prod\SQLBackups\FULL_Resales4_20110426_020158_01.sqb 4/26/2011 7:01:38 AM: \\uhlig.com\prod\SQLBackups\FULL_Resales4_20110426_020158_02.sqb 4/26/2011 7:01:39 AM: ALTER DATABASE [Resales4] SET ONLINE RESTORE DATABASE [Resales4] FROM VIRTUAL_DEVICE = 'SQLBACKUP_CD6523F1-6602-4913-B5F8-47A982752801', VIRTUAL_DEVICE = 'SQLBACKUP_CD6523F1-6602-4913-B5F8-47A98275280101' WITH BUFFERCOUNT = 12, BLOCKSIZE = 65536, MAXTRANSFERSIZE = 1048576 , NORECOVERY, REPLACE 4/26/2011 7:15:17 AM: Thread 0 error: Process terminated unexpectedly. Error code: -2139684861 (The api was waiting and the timeout interval had elapsed.) 4/26/2011 7:15:17 AM: 4/26/2011 7:15:19 AM: Processed 2838336 pages for database 'Resales4', file 'Resales4_Data' on file 1. 4/26/2011 7:15:19 AM: Processed 1 pages for database 'Resales4', file 'Resales4_Log' on file 1. 4/26/2011 7:15:19 AM: RESTORE DATABASE successfully processed 2838337 pages in 817.590 seconds (28.439 MB/sec). 4/26/2011 7:15:20 AM: Mail sent successfully to: **** I'm not sure if this is relevant or not, but I did notice one other symptom of this problem when the process failed this morning. When I query msdb.dbo.backupmediafamily for the physical device name, the entry for the database where the restore failed shows the sqlBackup VIRTUAL_DEVICE name, while the entries for the databases where the restore succeeds show the actual physical path to the *.sqb files used for the restore process. So it would appear that the process is timing out before that update to the msdb backup tables can occur. Database Restore Type Physical File Name Restore Date Recovery State Utility Transaction Log \\uhlig.com\prod\SQLBackups\LOG_Utility_20110426_070538.sqb 4/26/11 7:21 Recovery Utility Transaction Log \\uhlig.com\prod\SQLBackups\LOG_Utility_20110426_065035.sqb 4/26/11 7:21 NoRecovery Utility Transaction Log \\uhlig.com\prod\SQLBackups\LOG_Utility_20110426_063534.sqb 4/26/11 7:20 NoRecovery Utility Transaction Log \\uhlig.com\prod\SQLBackups\LOG_Utility_20110426_062035.sqb 4/26/11 7:20 NoRecovery Utility Differential \\uhlig.com\prod\SQLBackups\DIFF_Utility_20110426_060905.sqb 4/26/11 7:20 NoRecovery Utility Full \\uhlig.com\prod\SQLBackups\FULL_Utility_20110426_023019.sqb 4/26/11 7:16 NoRecovery Resales4 Full SQLBACKUP_CD6523F1-6602-4913-B5F8-47A982752801 4/26/11 7:01 NoRecovery Resales4 Full SQLBACKUP_CD6523F1-6602-4913-B5F8-47A98275280101 4/26/11 7:01 NoRecovery Anyway, please let me know if you have any suggestions for next steps in the troubleshooting process. Thanks, -Mike / comments
Peter, The restore process failed again this morning with the same error for the same database. Unfortunately, the log file that was generated doesn't seem to contain much additional information. ...
0 votes
Peter, I will remove the LOG_ONERRORONLY parameter from the restore job on the destination server. If / when the job fails again, I'll update this thread. Thanks again for your time. Regards, -Mike Eastland / comments
Peter, I will remove the LOG_ONERRORONLY parameter from the restore job on the destination server. If / when the job fails again, I'll update this thread. Thanks again for your time. Regards, -Mik...
0 votes
I spoke too soon on my previous reply. After converting the differential backup into the native format, the restore DOES complete successfully. However, restoring from the same backup set while it is in the SQL Backup compressed state continues to hang indefinitely. Here is the error message that results after the process is finally killed: 4/18/2011 11:54:25 AM: Thread 0 error: Process terminated unexpectedly. Error code: -2139684861 (The api was waiting and the timeout interval had elapsed.) 4/18/2011 11:54:25 AM: 4/18/2011 11:54:25 AM: Thread 1 error: Process terminated unexpectedly. Error code: -2139684861 (The api was waiting and the timeout interval had elapsed.) 4/18/2011 11:54:25 AM: 4/18/2011 11:54:25 AM: Thread 2 error: Process terminated unexpectedly. Error code: -2139684861 (The api was waiting and the timeout interval had elapsed.) 4/18/2011 11:54:25 AM: 4/18/2011 11:54:25 AM: Thread 3 error: Process terminated unexpectedly. Error code: -2139684861 (The api was waiting and the timeout interval had elapsed.) 4/18/2011 11:54:25 AM: 4/18/2011 1:08:46 PM: SQL error 3013: SQL error 3013: RESTORE DATABASE is terminating abnormally. 4/18/2011 1:08:46 PM: SQL error 3203: SQL error 3203: Read on "SQLBACKUP_8B2CA8C7-096B-4367-B2E5-62828678140001" failed: 995(The I/O operation has been aborted because of either a thread exit or an application request.) Looking forward to some input. Thanks. / comments
I spoke too soon on my previous reply. After converting the differential backup into the native format, the restore DOES complete successfully. However, restoring from the same backup set while i...
0 votes
Some additional information... I attempted to convert the DIFFERENTIAL backup set into the native backup format, and I'm seeing the same behavior when trying to restore from the converted backup set. / comments
Some additional information... I attempted to convert the DIFFERENTIAL backup set into the native backup format, and I'm seeing the same behavior when trying to restore from the converted backup set.
0 votes