A.G. Transaction Log Backup Failures?

Swedishiron

My company started running all backups on a MS SQL Server 2016 SP2 Availability Group Secondary. We occasionally have started encountering failures writing Transaction Log Backups which we execute every 5 minutes. The failed backups will produce a file that is very small (3KB) that is not restorable. However proceeding log backups are restorable. Below is the first in the string of error messages from one such failure. Is this possibly an issue with Redgate Backup's software performing backup on a Secondary?

1: The log scan number (127041:122314:306) passed to log scan in database '*******' is not valid. This error may indicate data corruption or that the log file (.ldf) does not match the data file (.mdf). If this error occurred during replication, re-create the publication. Otherwise, restore from backup if the problem results in a failure during startup.

2: BACKUP failed to complete the command BACKUP LOG ******. Check the backup application log for detailed messages.

3:SQLVDI: Loc=TriggerAbort. Desc=invoked. ErrorCode=(0). Process=2148. Thread=7192. Server. Instance=MSSQLSERVER. VD=Global\SQLBACKUP_62B7389D-D84D-423A-809B-27602CDE5EB7_SQLVDIMemoryName_0. 

4:BackupVirtualDeviceFile::RequestDurableMedia: Flush failure on backup device 'SQLBACKUP_62B7389D-D84D-423A-809B-27602CDE5EB7'. Operating system error 995(The I/O operation has been aborted because of either a thread exit or an application request.).

5:BackupVirtualDeviceFile::RequestDurableMedia: Flush failure on backup device 'SQLBACKUP_62B7389D-D84D-423A-809B-27602CDE5EB701'. Operating system error 995(The I/O operation has been aborted because of either a thread exit or an application request.).

6:SQLVDI: Loc=SignalAbort. Desc=Client initiates abort. ErrorCode=(0). Process=2252. Thread=5816. Client. Instance=. VD=Global\SQLBACKUP_62B7389D-D84D-423A-809B-27602CDE5EB7_SQLVDIMemoryName_0. 

Swedishiron

Not Yet - Thank you for pointing it out. We were already in the process of rolling CU4 out to lower environment servers and should have deployed to Production in the next couple of weeks. Relief!

Dan B

Hi Swedishiron,
 
The message appears to be a warning of database corruption. I couldn't find a definitive write up on this error but https://www.sqlservercentral.com/Forums/Topic1652661-391-1.aspx and http://www.sqldbadiaries.com/2010/08/07/how-i-conquered-a-corrupt-database/ seem to confirm this.

What I find confusing at this stage is that you say this keeps occurring. Is it the case that log 1,2,3,4work 5, doesn't and then 6,7,8 work or are you doing something after the errors to reset the behaviour and then it occurs again?

SQL Backup is set to work on AG secondaries so that shouldn't be the problem and a look through our ticketing system hasn't found any other errors against the SQL Backup product.

Swedishiron

Hi Dan B- we've run  DBCC CheckDB on both the Secondary server itself within the affected database and on a restored copy of the database and both checks came back clean -no data corruption. The last time encountered the error was 10/07/2018 a week after we first encountered it on 09/30/2018.

" Is it the case that log 1,2,3,4work 5, doesn't and then 6,7,8 work or are you doing something after the errors to reset the behaviour and then it occurs again?" - Yes that is essentially the case. We will have 1 bad log file written by Redgate SQL Backup, we manually intervene and skip it and the rest of the logs restore without issue. We did not anything to reset the behavior in between the 2 occurrences. 

Any additional suggestions to get to the bottom of this are greatly appreciated. 

Dan B

Hi SwedishIron,

That's unexpected, I think the next thing I would be interested in would be viewing the SQL Backup log files. Could you possibly send over The logs for October in a zip file to support@red-gate.com so I can review these further?

The logs can be found in C:\ProgramData\Red Gate\SQL Backup\Log\<INSTANCENAME>

Swedishiron

Hi Dan B,

I don't see the path you referenced. I do see these two paths however we are running version 9.2.1.128. Would the log be located somewhere the SQL Backup 9 path?

C:\Program Files (x86)\Red Gate\SQL Backup 8
C:\Program Files (x86)\Red Gate\SQL Backup 9

Dan B

Hi SwedishIron,

The programdata folder is a hidden folder, you can follow the instructions here to find it.

There is the alternative that you are on an older version of windows in which case the log files will be in the following directory

• %ALLUSERSPROFILE%\ Application Data\Red Gate\SQL Backup\Log\<instance> (on Windows XP and Windows 2003).

Swedishiron

I have emailed the logs in a password protected 7-ZIP archive and referenced this post in the email; is there a separate email address or means that I can communicated the password to you? Also the errors occurred on these date/times: 

10/18/2018 12:57:18AM 

10/07/2018 6:25:34 AM 

9/30/2018 11:05:36 PM

9/30/2018 11:05:36 PM

Swedishiron

I sent you a message via the site w/ the password for the archive.

Dan B

HiSwedishiron,

Apologies for the delay, I think the next stage here would be if you can forward on the SQL Server error logs for September 30, October 7, and October 18 if you still have them.

Dan B

Hi Swedishiron,

This article seems to be relevant in this case https://support.microsoft.com/en-my/help/4458880/fix-9003-error-sev-20-state-1-error-when-a-backup-operation-fails-on-a

The fix is in 'Cumulative Update 4 for SQL Server 2016 Service Pack 2'.  Has this been applied?