Troubleshooting tlog backup failure in always-on environment, backups on read-only / passive node.

This was an odd failure, as it occurred 4 or 5 times, right after the full backup, than it would "resolve itself", but the next day, right after the full backup, it would happen again, repeating itself daily in this fashion.

Tracked this back to an issue with the disk, where it seems we had a 605 error during a checkdb, that also "resolved itself" and the next days checkdb was good, so no action was taken, but this is what started the chain of events.

Eventually I did find someone with a similar issue that a system spid was hung, I resolved my issue by rebooting the environment(s).  Link and text below my error messages.

Log backup for database "{db name here}" on secondary replica created backup
files successfully but could not ensure that a backup point has been
committed on the primary.  This is an informational message only.
Preserve this log backup along with the other log backups of this
database.          [SQLSTATE 01000]

Msg 35250, Sev 16, State 11, Line 39 : The connection to the primary
replica is not active.  The command cannot be processed. [SQLSTATE 42000]
Msg 3013, Sev 16, State 1, Line 39 : BACKUP LOG is terminating abnormally.
[SQLSTATE 42000]


The operating system returned error 665(The requested operation could not
be completed due to a file system limitation) to SQL Server during a write
at offset 0x00001cb940e000 in file
'{drive letter\db.ndf file}:MSSQL_DBCC12'. Additional
messages in the SQL Server error log and system event log may provide more
detail. This is a severe system-level error condition that threatens
database integrity and must be corrected immediately. Complete a full
database consistency check (DBCC CHECKDB). This error can be caused by
many factors; for more information, see SQL Server Books Online

-------------

https://blogs.msdn.microsoft.com/psssql/2012/12/05/alwayson-error-log-backup-for-database-mydb-on-secondary-replica-created-backup-files-successfully-but-could-not-ensure-that-a-backup-point-has-been-committed-on-the-primary/ 

-------

This error surprised me when it showed up in the error log so I decided to dig into it a bit more.

“Log backup for database “MyDB” on secondary replica created backup files successfully but could not ensure that a backup point has been committed on the primary.  This is an informational message only. 

Preserve this log backup along with the other log backups of this database.”

The message appears on the secondary replica, where the backup was taken, and indicates one of two possible conditions.  To understand the conditions it helps to understand the state of the backup operation.

The error occurs after the point where the backup was successfully streamed to the backup media. The first concern I had was “is my backup valid” and the answer is YES!  The backup has been written to the backup media properly.

Now the secondary sends a message to the primary to update the backup position in the database.  If this message fails the error is logged.

1. The secondary sends the completed message to the primary.  The primary records the backup position but for some reason fails to respond the secondary (I.E. lost network connection.)   In this case the next backup will pick up were the current backup completed.

2. The secondary sends the completed message to the primary.  The primary never receives the message or fails in some way before it can record the current backup position.  (I.E. network, primary shut down, etc…).  In this case the next backup will acquire the same information as the last log backup and any additional log records generated.

As you can see the message may be a bit alarming but it is harmless to your backup strategy other than the fact that you might get extra log records in a backup but that can be properly handled during restore.  NO DATA LOSS!

----------

Diane Sithoo says:

I'm seeing a third condition, trying to perform native log backups, where for some reason, although the backup has been written properly to the backup media, all further attempts to backup fail with Msg 35250, Level 16, State 11, "The connection to the primary replica is not active.  The command cannot be processed.".  This is then followed by Msg 3013, Level 16, State 1, "BACKUP LOG is terminating abnormally."

So far, even in dealing with MS support, there is no resolution to this.  What happens is that at that point, the background process is blocked.  When I use DMV view sys.dm_exec_requests, it shows as HADR BACKUP LOCK HOLDER.  The wait type on the blocked process is LCK_M_U and the wait resource is DATABASE: <id> [BULKOP_BACKUP_LOG].  On the blocking process, the wait type is HADR_BACKUP_QUEUE.  Until I either restart SQL Server Agent on the secondary, or run DBCC STACKDUMP, it continues to block.