October 13, 2015 at 4:19 am
We are running SQL Server 2014 Web Edition (64-bit). On three occasions now we have had two of our live secondary log shipping databases become unusable through the log shipping process. We ship logs to these databases every five minutes, and generally the process works fine.
However, on three occasions in as many months we have suddenly received alerts warning us that the transaction log restores could not be performed on the secondary databases. The SQL Server Error Log revealed the following:
Date,Source,Severity,Message
10/13/2015 04:01:16,spid52,Unknown,Setting database option SINGLE_USER to ON for database 'ObfuscatedName'.
10/13/2015 04:01:17,spid52,Unknown,Starting up database 'ObfuscatedName'.
10/13/2015 04:01:17,spid52,Unknown,Recovery is writing a checkpoint in database 'ObfuscatedName' (8). This is an informational message only. No user action is required.
10/13/2015 04:01:17,spid52,Unknown,CHECKDB for database 'ObfuscatedName' finished without errors on 2015-10-13 03:01:41.260 (local time). This is an informational message only; no user action is required.
10/13/2015 04:01:17,spid52,Unknown,Starting up database 'ObfuscatedName'.
10/13/2015 04:01:17,spid52,Unknown,CHECKDB for database 'ObfuscatedName' finished without errors on 2015-10-13 03:01:41.260 (local time). This is an informational message only; no user action is required.
10/13/2015 04:01:17,Backup,Unknown,"Log was restored. Database: ObfuscatedName, creation date(time): 2015/04/02(10:54:18), first LSN: 29435:800:1, last LSN: 29435:816:1, number of dump devices: 1, device information: (FILE=1, TYPE=DISK: {'\\ServerName\Log Shipping\ObfuscatedName\ObfuscatedName_20151013035845.trn'}). This is an informational message. No user action is required."
10/13/2015 04:01:17,spid52,Unknown,Setting database option MULTI_USER to ON for database 'ObfuscatedName'.
10/13/2015 04:06:16,spid52,Unknown,Setting database option SINGLE_USER to ON for database 'ObfuscatedName'.
10/13/2015 04:06:17,spid52,Unknown,Starting up database 'ObfuscatedName'.
10/13/2015 04:06:17,spid52,Unknown,Recovery is writing a checkpoint in database 'ObfuscatedName' (8). This is an informational message only. No user action is required.
10/13/2015 04:06:17,spid52,Unknown,CHECKDB for database 'ObfuscatedName' finished without errors on 2015-10-13 03:01:41.260 (local time). This is an informational message only; no user action is required.
10/13/2015 04:06:17,spid52,Unknown,Starting up database 'ObfuscatedName'.
10/13/2015 04:06:17,spid52,Unknown,CHECKDB for database 'ObfuscatedName' finished without errors on 2015-10-13 03:01:41.260 (local time). This is an informational message only; no user action is required.
10/13/2015 04:06:17,Backup,Unknown,"Log was restored. Database: ObfuscatedName, creation date(time): 2015/04/02(10:54:18), first LSN: 29435:816:1, last LSN: 29435:832:1, number of dump devices: 1, device information: (FILE=1, TYPE=DISK: {'\\ServerName\Log Shipping\ObfuscatedName\ObfuscatedName_20151013040345.trn'}). This is an informational message. No user action is required."
10/13/2015 04:06:17,spid52,Unknown,Setting database option MULTI_USER to ON for database 'ObfuscatedName'.
10/13/2015 04:11:16,spid52,Unknown,Setting database option SINGLE_USER to ON for database 'ObfuscatedName'.
10/13/2015 04:11:16,spid52,Unknown,Starting up database 'ObfuscatedName'.
10/13/2015 04:11:18,spid52,Unknown,"An error occurred while processing the log for database 'ObfuscatedName'. If possible, restore from backup. If a backup is not available, it might be necessary to rebuild the log."
10/13/2015 04:11:18,spid52,Unknown,"An error occurred during recovery, preventing the database 'ObfuscatedName' (8:0) from restarting. Diagnose the recovery errors and fix them, or restore from a known good backup. If errors are not corrected or expected, contact Technical Support."
The extract above shows two previously successful restores to the secondary database. Suddenly, at 04:11:16, the database can no longer be started up or restored to. This is despite CHECKDB giving a clean bill of health only five minutes earlier. The result is that the last three lines are then repeated ad infinitum.
The only way we have managed to get around this issue so far is to replace the secondary database with a recent backup of the primary. Once this is in place, any outstanding transaction logs are successfully applied when the log shipping restore job next runs. However, this seems rather drastic.
Can anyone please confirm what is going on here, and if anything can be done to prevent this from happening? It is rather concerning that our warm-standby databases continue to become corrupted without any apparent explanation from SQL Server.
October 13, 2015 at 4:45 am
Update:
We attempted to go down the repair route for the secondary database, to try and glean more information. However this did not meet with success.
-- The following failed, and resulted in the database being marked as "Suspect".
ALTER DATABASE ObfuscatedName SET SINGLE_USER WITH ROLLBACK IMMEDIATE;
GO
RESTORE DATABASE ObfuscatedName WITH RECOVERY;
GO
-- Reset the status of the suspect database
EXEC sp_resetstatus ObfuscatedName;
-- The following was run to put the database into a state of "Emergency"
ALTER DATABASE ObfuscatedName SET EMERGENCY;
-- The following resulted in the following error message:
DBCC CHECKDB (ObfuscatedName);
/*
Msg 945, Level 14, State 2, Line 18
Database 'ObfuscatedName' cannot be opened due to inaccessible files or insufficient memory or disk space. See the SQL Server errorlog for details.
*/
There is no additional information in the SQL Server Error Log. We have plenty of hard disk space available, and the data/log files are both present and accessible as far as we can tell. There appears to be very little we can do to this database.
Any suggestions?
October 13, 2015 at 5:46 am
-- The following resulted in the following error message:
DBCC CHECKDB (ObfuscatedName);
/*
Msg 945, Level 14, State 2, Line 18
Database 'ObfuscatedName' cannot be opened due to inaccessible files or insufficient memory or disk space. See the SQL Server errorlog for details.
*/
What are your performance counters looking like for memory?
Disk space?
Permissions to the folders containing the database files?
October 13, 2015 at 6:12 am
What are your performance counters looking like for memory?
Disk space?
Permissions to the folders containing the database files?
CPU averages around 1%
108GB free on the data drive, 83GB free on the logs drive
Permissions unaltered. A restore has reinstated log shipping, so the problem lay with the corrupted database files.
October 13, 2015 at 6:21 am
Is opening a support call with MS an option? If so, I'd recommend that approach.
Also check the IO subsystem for any errors in any drivers, caches, etc. Make sure firmware and drivers are updated, that write cache is battery-backed and that the batteries work.
Gail Shaw
Microsoft Certified Master: SQL Server, MVP, M.Sc (Comp Sci)
SQL In The Wild: Discussions on DB performance with occasional diversions into recoverability
October 13, 2015 at 7:23 am
The underlying hypervisor virtual infrastructure all appears to be ok and up-to-date. It is regularly patched and updated.
We may well need to open a support request with MS. In the meantime, please let us know if you have any further thoughts or suggestions.
October 13, 2015 at 4:02 pm
I strongly believe there is a intermittent access problem with shared location where logs are placed
\\ServerName\Log Shipping\ObfuscatedName\ObfuscatedName_20151013040345.trn....
@JayMunnangi
October 14, 2015 at 2:43 am
JakDBA (10/13/2015)
I strongly believe there is a intermittent access problem with shared location where logs are placed\\ServerName\Log Shipping\ObfuscatedName\ObfuscatedName_20151013040345.trn....
This share is located locally on the secondary server, so I feel this is unlikely. It also seems unlikely that an intermittent access problem to these transaction log files would result in the corruption of the database, and more likely that we would receive SQL Server Agent job errors relating to network issues (which we have seen on other networks, which resulted in the copy jobs failing).
October 14, 2015 at 9:10 am
I did not see any ware in the error log Corruption....
"An error occurred during recovery, preventing the database 'ObfuscatedName' (8:0) from restarting. Diagnose the recovery errors and fix them, or restore from a known good backup. If errors are not corrected or expected, contact Technical Support."
and also query the data from MSDB
--List of Log Shipping jobs
SELECT * from dbo.sysjobs WHERE category_id = 6
SELECT * FROM [msdb].[dbo].[sysjobhistory]
where [message] like '%Operating system error%'
order by [run_date] , [run_time]
SELECT * FROM [msdb].[dbo].[log_shipping_monitor_error_detail]
where [message] like '%Operating system error%'
SELECT * FROM [msdb].[dbo].[restorehistory]
@JayMunnangi
October 14, 2015 at 9:21 am
JakDBA (10/14/2015)
I did not see any ware in the error log Corruption...."An error occurred during recovery, preventing the database 'ObfuscatedName' (8:0) from restarting. Diagnose the recovery errors and fix them, or restore from a known good backup. If errors are not corrected or expected, contact Technical Support."
That message is the indication of corruption. Some form of damage to the log has prevented the database from recovering.
If the log backup destination disappeared, the log backup would just fail, not damage the transaction log itself.
Gail Shaw
Microsoft Certified Master: SQL Server, MVP, M.Sc (Comp Sci)
SQL In The Wild: Discussions on DB performance with occasional diversions into recoverability
October 28, 2015 at 12:00 am
Justin Manning SA (10/13/2015)
-- The following resulted in the following error message:
DBCC CHECKDB (ObfuscatedName);
/*
Msg 945, Level 14, State 2, Line 18
Database 'ObfuscatedName' cannot be opened due to inaccessible files or insufficient memory or disk space. See the SQL Server errorlog for details.
*/
Add more hard drive space either by removing of unnecessary files from hard drive or add new hard drive with larger size if possible or check if the database is set to Autogrow on
October 28, 2015 at 3:34 am
As previously mentioned:
108GB free on the data drive, 83GB free on the logs drive
Viewing 12 posts - 1 through 11 (of 11 total)
You must be logged in to reply to this topic. Login to reply