Sudden Differential Backup Failures after an Availability Group Failover

As so many stories do, this story starts with a failover - in this case an Availability Group (AG) failover.

https://cdn.meme.am/cache/instances/folder984/400x/59300984.jpg

There were several different backup and status check jobs failing on NODE01 and NODE02 because the AG01 availability group was now primary on NODE02 instead of NODE01 after a failover.

The failover occurred the previous Saturday morning at 8:30am local server time because of an application-initiated server reboot of the 01 node:

--

Log Name:      System
Source:        User32
Date:          7/22/2017 8:31:08 AM
Event ID:      1074
Task Category: None
Level:         Information
Keywords:      Classic
User:          SYSTEM
Computer:      NODE01.COMPANY1.com
Description:
The process C:\Program Files\Application12\AppAgent\01\patch\ApplicationService.exe (NODE01) has initiated the restart of computer NODE01 on behalf of user NT AUTHORITY\SYSTEM for the following reason: Legacy API shutdown
Reason Code: 0x80070000
Shutdown Type: restart
Comment: The Update Agent will now reboot this machine

--

Always fun when an application “unexpectedly” restarts a server without advance warning.

https://i.imgflip.com/w6x8g.jpg

--

Even though the Quest/Dell LiteSpeed Fast Compression maintenance plans are configured to pick up “all user databases” the availability group databases were not being backed up currently and hadn’t been since the failover:

NODE01:

NODE02:

The error messages on the SQL Error Log on the 01 node are telling:

--

Date       7/24/2017 1:09:23 AM
Log        SQL Server (Current - 7/24/2017 12:59:00 PM)
Source     Backup
Message    Error: 3041, Severity: 16, State: 1. 

-- 

Date       7/24/2017 1:09:23 AM
Log        SQL Server (Current - 7/24/2017 12:59:00 PM)
Source     Backup
Message    BACKUP failed to complete the command BACKUP DATABASE AG_DATABASE22. Check the backup application log for detailed messages. 

-- 

Date       7/24/2017 1:09:23 AM
Log        SQL Server (Current - 7/24/2017 12:59:00 PM)
Source     spid269
Message    FastCompression Alert: 62301 : SQL Server has returned a failure message to LiteSpeed™ for SQL Server® which has prevented the operation from succeeding.
The following message is not a LiteSpeed™ for SQL Server® message. Please refer to SQL Server books online or Microsoft technical support for a solution:  
BACKUP DATABASE is terminating abnormally. This BACKUP or RESTORE command is not supported on a database mirror or secondary replica. 

-- 

Date       7/24/2017 1:09:24 AM
Log        SQL Server (Current - 7/24/2017 12:59:00 PM)
Source     spid258
Message    Error: Maintenance plan 'Maint Backup User Databases'.LiteSpeed™ for SQL Server® 8.2.1.42
© 2016 Dell Inc.
           Selecting full backup: Maximum interval (7 days) has elapsed since last full
Executing SQLLitespeed.exe: Write new full backup \\adcnas21\SQL\NODE01\AG_DATABASE22\AG_DATABASE22.litespeed.f22.bkp
           Msg 62301, Level 16, State 1, Line 0: SQL Server has returned a failure message to LiteSpeed™ for SQL Server® which has prevented the operation from succeeding.
The following message is not a LiteSpeed™ for SQL Server® message. Please refer to SQL Server books online or Microsoft technical support for a solution:
           BACKUP DATABASE is terminating abnormally.
This BACKUP or RESTORE command is not supported on a database mirror or secondary replica.

--

 ** IMPORTANT **  - while this specific scenario is on a cluster running Dell/Quest LiteSpeed Fast Compression backups (a process that uses an algorithm to determine whether a differential is sufficient or a full backup is required each day), the problem does *not* directly relate to LiteSpeed - the problem is with running differential backups on availability group secondaries or database mirror partners in general.

The situation around running differentials on secondaries is described in this post from Anup Warrier (blog/@AnupWarrier):

https://sqlsailor.com/2012/05/15/backups-on-secondary-replicas-always-on-availability-groups/

--

The particular issue here is the fact that the AG’s aren’t weighted evenly, so even though it is “invalid” for the differentials, the AG still prefers NODE01 because it is more heavily weighted:

--

My recommendation to the client to fix this on LiteSpeed Fast Compression was to change the backup option on the AG from “Any Replica” to “Primary” – this would keep the backup load on the primary, which means the differential backups would work.

The cost to this is that the backup I/O load would always be on the primary, but since the “normal” state for AG01 is to live on NODE01 with backups on NODE01 then requiring the backups to run on the primary node would not be different in most situations.

Note this is the state for this particular AG - in many cases part of the use of AG's is being able to offload backups to the secondary, so in many cases this is a cost to be weighed before making this change.

If you want to run backups on the secondary node then my personal best suggestion for fixing this would be outside of LiteSpeed/Fast Compression – if you want/need to stay with differentials, we could use a scripted backup solution (like Ola Hallengren's Maintenance Solution) to enable/disable the full/differential backups on the secondary node, probably by adding a check in the backup commands to ignore databases that aren’t the AG primary.  

A script to perform this Availability Group replica check appears in my previous post on determining the primary Availability Group replica:

--

SELECT AG.name AS AvailabilityGroupName,
HAGS.primary_replica AS PrimaryReplicaName, 
HARS.role_desc as LocalReplicaRoleDesc, 
DRCS.database_name AS DatabaseName, 
HDRS.synchronization_state_desc as SynchronizationStateDesc, 
HDRS.is_suspended AS IsSuspended, 
DRCS.is_database_joined AS IsJoined
FROM master.sys.availability_groups AS AG
LEFT OUTER JOIN master.sys.dm_hadr_availability_group_states as HAGS
ON AG.group_id = HAGS.group_id
INNER JOIN master.sys.availability_replicas AS AR
ON AG.group_id = AR.group_id
INNER JOIN master.sys.dm_hadr_availability_replica_states AS HARS
ON AR.replica_id = HARS.replica_id 
AND HARS.is_local = 1
INNER JOIN master.sys.dm_hadr_database_replica_cluster_states AS DRCS
ON HARS.replica_id = DRCS.replica_id
LEFT OUTER JOIN master.sys.dm_hadr_database_replica_states AS HDRS
ON DRCS.replica_id = HDRS.replica_id
AND DRCS.group_database_id = HDRS.group_database_id
ORDER BY AG.name, DRCS.database_name

--

Another option would be to go away from differentials completely and just run FULL’s and LOG’s which would allow for the current 80/50 weight model to continue.

I further advised the client that because of the differentials situation I don’t see a way to force backups to the secondary with LiteSpeed Fast Compression - since Fast Compression requires differentials as part of its process, Fast Compression backups *have* to run on the primary. (Maybe there is some setting in Fast Compression to fix this but I am not familiar with one.) 

--

Hope this helps!

It's Just Another 9002...another error like all the rest...

11:30pm on a Saturday night, and the pager went off…

Error: 5901, Severity: 16, State: 1.

One or more recovery units belonging to database 'i3_dialer' failed to generate a checkpoint. This is typically caused by lack of system resources such as disk or memory, or in some cases due to database corruption. Examine previous entries in the error log for more detailed information on this failure.

That phrase – “due to database corruption” – always makes my stomach turn just a little…

https://img.memesuper.com/9b7a67d76f5de79439a92cc9ad703dda_im-coming-elizabeth-its-the-im-coming-elizabeth-meme_500-384.jpeg

Thankfully, this turned out to *not* be corruption. <Whew!>

There was a related message:

Could not write a checkpoint record in database DB_1 because the log is out of space. Contact the database administrator to truncate the log or allocate more space to the database log files.

…and then the real problem…

Error: 9002, Severity: 17, State: 9.

The transaction log for database DB_1 is full due to 'AVAILABILITY_REPLICA'.

--

Upon cursory examination, DB_1 was suspended (not moving data) in Sales_AG, with the AG being primary on node ServerA.  The other databases in the AG were all transferring data without apparent issue.

I went to check the drive hosting the LDF log file and almost broke out laughing at midnight – it was a mount point that was 367MB.

That’s right, megabytes.

 

http://static.ddmcdn.com/gif/tallest-fishing-tales0.jpg

The DB_1 database was just over 1GB, with a 350MB LDF file.

Being an Availability Group, there wasn’t shared storage, so I went to the B node to look and see if something was sitting on the drive on that side – some extra file that was taking up space and preventing the log file from auto-growing, but I didn’t find one.

--

The regular Database Index Maintenance instigated this situation.  The largest object (table) in DB_1 is only 69MB, but the transaction LOG backup job only runs every fifteen minutes.  In a database this small it is quite possible that the index rebuild will cycle through all of the tables in the database between LOG backups, which would drive the LDF fill out towards the used space of the MDF data file, in this case 1GB.

In this specific situation, the LDF log file grew by 10% repeatedly until it hit 350MB.  At that point, there wasn’t room for another 10%/35MB so it couldn’t grow any more.

On a regular (non-availability group) database this would manifest as the 9002 errors for log full messages with a log_reuse_wait_desc of LOG_BACKUP – the most likely fix would be to take LOG backups, shrink the LDF log file if needed, and be done.  That was not the case here.

(Note that the log_reuse_wait_desc here wasn’t LOG_BACKUP, it was AVAILABILITY_REPLICA.  This shows that something was breaking the situation from the AG side before the lack of LOG_BACKUP could even be raised as a problem, but I didn’t notice that at the time.)

--

I added a second LDF log file (not a great answer but often a useful triage to get things moving) and that allowed DB_1 to function, but it did not allow the availability group data movement to resume.  To try to repair the situation, I removed DB_1 from the Sales_AG availability group.  (Note that this does not prevent applications from accessing the database, but rather it would not allow DB_1 to fail over to the B node if a failover occurred – but in the current state where data movement was suspended and non-resumable, a failover wouldn’t work anyway.)

I ran the LOG backup job manually multiple times and then tried to re-add the DB_1 database to the availability group – that action gave me a telling message that there wasn’t room on the B node to restore the LDF log file:

System.Data.SqlClient.SqlError: There is insufficient free space on disk volume 'X:\LOG' to create the database. The database requires 368050176 additional free bytes, while only 356515840 bytes are available.

http://s2.quickmeme.com/img/a7/a765c5be1bb9380025b17660b4782d2b5dc9fa3a9d50ede174a680733de1d383.jpg

 What I found surprised me even more than finding a 367MB mount point in the first place on ServerA – the mount point on ServerB was only 343 MB!

This case with the availability group made the situation especially nasty – by growing to 350MB the LDF log file was now past the size of the 343MB mount point on the B node.  This automatically suspended data movement for the DB_1 database (not the whole availability group – just the single database) while it was waiting for sufficient space to grow the LDF on the secondary node.

I have dealt with lots of clustering/mirroring/AG’s over the years, and I have never tripped over this particular issue before.  With traditional failover clustering, you have shared storage, so this isn’t an issue; with a “no shared storage” design, this is a real risk for both mirroring and AG’s, and in this case it was exaggerated by the tiny size of the mount.

I was able to shrink the LDF log file of DB_1 to 310MB, which fit inside the 343MB mount point on the B node.  At that point I was able to re-add DB_1 to Sales_AG, and after it was successfully back in the availability group the database showed in the monitor as successfully moving data from A>>B.

I removed the secondary LDF log file that I had added as it is not recommended to have multiple log files as a regular operating state. #TheMoreYouKnow

As a final step I shrunk the primary LDF log file a little further (shrinking is not great but is sometimes necessary) and then modified the FILEGROWTH for the file to grow in 10MB increments (rather than %).  I then manually capped the MAXSIZE of the file at 335MB so that if the file did fill again, it wouldn’t break the availability group in this same way.  The database would still throw 9002’s, but they would be for LOG_BACKUP, not AVAILABILITY_REPLICA.

I warned the client that they really needed to expand the mount point a little (storage is cheap, right?) to cover the needs of the index maintenance and to match the sizes.  I also noted that if the mount point were expanded, the manual cap would need to be lifted before the DB_1 LDF log file will take advantage of any extra space.

--

The cautionary tale here is about the mismatched storage – as unlikely as it may seems to have 343MB and 365MB mount points, the exact same thing could happen on a system with a 343GB and 367GB mounts with a file trying to grow past the smaller of the two sizes.

Configurations on AG partners don’t have to be exactly the same, but they should be darned close…and for storage – just make them the same, and save yourself this particular headache.

http://img01.deviantart.net/668d/i/2004/260/e/c/headache_by_cat_lovers.jpg

Hope this helps!

Where Is My Primary Replica Again?

We have many clients with multi-node Availability Groups - that is, AGs with more than two replicas.  One of the problems I have always had with Availability Group management via the GUI (admit it, you use the GUI sometimes all you non-PowerShell geeks) is the fact that most of the work needs to be done from the primary replica.  You can connect to the Availability Group manager on a secondary replica, but you can only see limited data about that particular secondary replica and can't see much about the other replicas, including *which* replica is the current primary replica!

To perform management you almost always need to connect to the primary replica, but how can I figure out which one is primary without just connecting to the instances one by one until I get lucky?

https://cdn.meme.am/instances/500x/55766239.jpg

Enter the T-SQL:

SELECT
AG.name AS AvailabilityGroupName
, HAGS.primary_replica AS PrimaryReplicaName
, HARS.role_desc as LocalReplicaRoleDesc
, DRCS.database_name AS DatabaseName
, HDRS.synchronization_state_desc as SynchronizationStateDesc
, HDRS.is_suspended AS IsSuspended
, DRCS.is_database_joined AS IsJoined
FROM master.sys.availability_groups AS AG
LEFT OUTER JOIN master.sys.dm_hadr_availability_group_states as HAGS
ON AG.group_id = HAGS.group_id
INNER JOIN master.sys.availability_replicas AS AR
ON AG.group_id = AR.group_id
INNER JOIN master.sys.dm_hadr_availability_replica_states AS HARS
ON AR.replica_id = HARS.replica_id AND HARS.is_local = 1
INNER JOIN master.sys.dm_hadr_database_replica_cluster_states AS DRCS
ON HARS.replica_id = DRCS.replica_id
LEFT OUTER JOIN master.sys.dm_hadr_database_replica_states AS HDRS
ON DRCS.replica_id = HDRS.replica_id
AND DRCS.group_database_id = HDRS.group_database_id
ORDER BY AG.name, DRCS.database_name

This query can be run on any of the replicas, and it will return information about the Availability Groups and their member databases, *including* the name of the primary replica instance!

http://vignette4.wikia.nocookie.net/randycunningham9thgradeninja/images/9/97/YES_cat.jpg/revision/latest?cb=20150330230809

Hope this helps!

Availability Groups - Where Did My Disks Go?

The TL;DR - beware of Failover Cluster Manager trying to steal your non-shared storage!

--

At a client recently two availability groups on a single Windows cluster went down simultaneously.  Apparently the server that was the primary for the AGs (Server1) had mysteriously lost its DATA and LOG drives.  By the time the client got us involved they had faked the application into coming up by pointing it directly to the single SQL Server instance that was still up (Server2) directly via the instance name rather than the availability group listeners.

I found that two of the drives on Server1 had gone offline, causing the issues – sample errors from the Windows System and Application Logs respectively:

--

Log Name:      System

Source:        Microsoft-Windows-FailoverClustering

Date:          3/31/2015 2:36:25 PM

Event ID:      1635

Task Category: Resource Control Manager

Level:         Information

Keywords:     

User:          SYSTEM

Computer:      server1.mydomain.com

Description:

Cluster resource 'Cluster Disk 2' of type 'Physical Disk' in clustered role 'Available Storage' failed.

--

     Log Name:      Application

Source:        MSSQLSERVER

Date:          3/31/2015 2:36:25 PM

Event ID:      9001

Task Category: Server

Level:         Error

Keywords:      Classic

User:          N/A

Computer:      server1.mydomain.com

Description:

The log for database 'Database1' is not available. Check the event log for related error messages. Resolve any errors and restart the database.

--

Since this is an Availability Group (AG) I was surprised that there were “Cluster Disk” resources at all – AG’s do not rely on shared disk (it is one of their many advantages) and most AG clusters don’t have any shared disk at all (occasionally a quorum drive).

This is what I saw in Failover Cluster Manager:

Cluster Disk 1 was the Quorum, but the presence of disks 2-7 did not make sense to me in a regular AG arrangement.  The two disks that were online (Disk 6 and Disk 7) were the two disks that were currently “live” on Server2, but there was still no reason for them to be in Failover Cluster Manager.

The service provider assured me that none of the drives except the Quorum are presented to more than one server from the back-end storage.

There was one reported event that happened at 2:36pm, a time that coincided with the failures – the client added a new node Server3 to the cluster (it was evicted 30 minutes later with no further impact positive or negative).

My best theory at this point was that when the engineer tried to add Server3 to the Windows cluster they mistakenly tried to add the disks as Cluster Disk resources – for a traditional SQL Server Failover Cluster Instance (FCI) this would be correct – for a SQL FCI almost all disk is shared and all nodes need to have access to all of the shared disk (although only one node can “own” it at any one time).

A cluster will “lock” disks – if cluster MySuperHugeAndAmazingCluster01 owns a particular drive then no other server or cluster can use it – the only way for a server to access it is through the cluster.  I considered that may be the cause of this issue – even though several of the drives are flagged that “clustered storage is not connected to the node” this may simply have been because the storage wasn’t presented to the current “owner” of the Cluster Disk objects Server2.

--

After an application downtime was scheduled, I signed on to the server and after deleting the AGs (first saving their settings for later re-creation) and shutting down SQL I deleted the cluster disk objects.  This, combined with a disk rescan in the Computer Management console on each server, did indeed return control of the “missing” drives to the servers.  I dropped six of the seven cluster disk objects (all of them except the Quorum object) which means I needed to rescan disks on all of the servers.  This validated that the only reason things have been working on Server2 was because the cluster thought that Server2 owned the disk objects (my guess is because the Add Node wizard to add Server3 to the cluster the other day was probably run from Server2 rather than Server1– more to follow on that).

I recreated the two AGs and as a final step I performed a failover test of each of the two availability groups from Server2 to Server1 and back again so that at the end of the process Server2 was the primary for both availability groups.  Making Server2 the primary was necessary because of the changes the client had made to the front-end applications and processes to get them to work since they redirected the applications to talk directly to Server2 rather than to the two availability group names (this works since the availability group name is really just a redirect to the server name/IP itself under the hood).  A final step for the client was to redirect the apps to once again talk to the availability group listeners.

I then added the new node (Server3) to the cluster and stepping through the Add Node wizard showed me the likely cause of the original issue (below).

 

As of the end of the call, the client was satisfied with the end state – SQL Servers online, availability groups running, and new cluster node added.

--

Here is what *I* learned today, brought to light through adding the new node and what was almost certainly the cause of the problem:

As I noticed when adding Server3 to the cluster, on the Confirmation screen of the Add Node wizard in Windows Server 2012 there is a check box to “Add all eligible storage to the cluster” – by default it is *CHECKED*.

As described here by Clustering MVP David Bermingham, this can really cause problems:

On the confirmation screen you will see the name and IP address you selected. You will also see an option which is new with Windows Server 2012 failover clustering…”Add all eligible storage to the cluster”. Personally I’m not sure why this is selected by default, as this option can really confuse things. By default, this selection will add all shared storage (if you have it configured) to the cluster, but I have also seen it add just local, non-shared disks, to the cluster as well. I suppose they want to make it easy to support symmetric storage, but generally any host based or array based replication solutions are going to have some pretty specific instructions on how to add symmetric storage to the cluster and generally this option to add all disks to the cluster is more of a hindrance than a help when it comes to asymmetric storage. For our case, since I have no shared storage configured and I don’t want the cluster adding any local disks to the cluster for me automatically I have unchecked the Add all eligible storage to the cluster option.

(emphasis mine)

Although I have seen a cluster disk object reserve/”lock” a resource so that the actual servers can’t access it other than through the cluster, but I haven’t run over this specific situation before (the check box).  The above explanation from David shows the most likely reason *why* this happened in this case – with the offending box checked by default, whoever was adding the node probably clicked right past it and when the process to actually add the node started, it grabbed all of the storage for the cluster, locking everybody out.  This would have impacted Server3 as well, but since it was a new server with no user databases (or anything else) on its D: and E: drives unless someone was looking in My Computer and saw the drives disappear, there wouldn’t be any immediately apparent problem on that server.

The reason why I believe the Add Node wizard was run from Server2 (not that it is important, just explanatory) was because the disk objects showed as being owned by Server2.  Since Server2 owned the cluster disk objects, it could still access them, which is why it was able to keep accessing its user databases on the two drives. 

--

At the end of the day, if you are working on a cluster with no shared storage, make sure to uncheck the "Add all eligible storage to the cluster" check box - and even if you do have storage, it may not be a bad practice to uncheck the box - it isn't that hard to add the disks manually afterward, and it makes your cluster creation process consistent.

--

BONUS - I am not a PowerShell-freak myself (I keep telling myself I need to become one since #YouCanDoAnythingWithPowerShell)  but if you like PS there is a flag to the relevant command there as well that is functionally equivalent to unchecking the box:

PS C:\> Add-ClusterNode -Name Server3 -NoStorage

 --

#TheMoreYouKnow