Issue Description:

Need to find out why clustered roles running on Server W2K12R2STD did not failover from Node: “ABCDX96E”  to  Node: “ABCDX97E” when Node: “ABCDX96E”  became unresponsive on 10th May around  05:20 AM. Cluster name is “exo-clust”.

Initial Description:

Understanding how Failover Clustering Recovers from Unresponsive Resources

When a Virtual Machine is clustered, there is a cluster “Virtual Machine” resource created which controls that VM.  The “Virtual Machine” resource and its associated resource DLL communicates with the VMMS service and tells the VM when to start, when to stop, and it also does health checks to ensure the VM is ok. 

Resources all run in a component of the Failover Clustering feature called the Resource Hosting Subsystem (RHS).  These VM actions from the user map to entry point calls that RHS makes to resources, such as Online, Offline, IsAlive, and LooksAlive.  You can find the full list of resource DLL entry-point functions. 

The most interesting in most cases where resources go unresponsive and you see clustering need to recover is with the LooksAlive and IsAlive which is a health check to the resource. 

• LooksAlive is a quick light lightweight check that happens every 5 seconds by default
• IsAlive is a more verbose check that happens every 60 seconds by default. 

Health check calls to the resource continue constantly while resources are online.  If a resource returns a failure for the lightweight LooksAlive health check, RHS will then immediately do a more comprehensive health check and call IsAlive to see if the resource is really healthy.  A resource is considered failed as the result of an IsAlive failure.

Think of it like this… Every 60 seconds RHS calls IsAlive and basically is asking the resource “Are you ok?”.  And the resource then responds to RHS “Yes, I am doing fine.”  This periodic health check goes on and on…      Until, there can be a case where something happens to the resource and it doesn’t respond.  Think of it like a dropped call on your cell phone, how long are you willing to sit there going “Hello?  Hello?  Hello?”… before you give up and call the person back?  Basically resetting the connection…

Failover Clustering has this same concept.  RHS will sit there waiting for the resource to respond to an IsAlive call, and eventually it will give up and need to take recovery action.  By default RHS will wait for 5 minutes for the resource to respond to an entry point call to it.  This is configurable with the resource DeadlockTimeout common property. 

To modify the DeadlockTimeout property of an individual resource, you can use the following PowerShell cmdlet command:

(Get-ClusterResource “Resource Name”).DeadlockTimeout = 300000

Or if you want to modify the DeadlockTimeout for all resources of that type you can modify it at the resource type level with the following syntax (this example will be for all virtual machine resources):

(Get-ClusterResourceType “Virtual Machine”).DeadlockTimeout = 300000

Resources are expected to respond to an IsAlive or LooksAlive within a few hundred milliseconds, so waiting 5 minutes for a resource to respond is a really long time.  Something pretty bad happened if a resource which normally responds in milliseconds, suddenly takes longer than 5 minutes.  So it is generally recommended to stay with the default values.

If the resource doesn’t respond in 5 minutes, RHS decides that there must be something wrong with the resource and that it should take recovery action to get it back up and running.  Remember that the resource has gone silent; RHS has no idea what is wrong with it.  The only way to recover and get the resource back up and running is that the RHS process is terminated, then RHS restarts, which will then restart the resource, and everything is back up and running.  You may also see the associated entries in the System event log:

Event ID 1230

Cluster resource ‘Resource Name’ (resource type ‘Resource Type Name’, DLL ‘DLL Name’) did not respond to a request in a timely fashion. Cluster health detection will attempt to automatically recover by terminating the Resource Hosting Subsystem (RHS) process running this resource.

Event ID 1146

The cluster Resource Hosting Subsystem (RHS) stopped unexpectedly. An attempt will be made to restart it. This is usually associated with recovery of a crashed or deadlocked resource. 

The next layer of protection is that when clustering issues a request to terminate the RHS process, it will wait four times the DeadlockTimeout value (which equates to 20 minutes by default) for the RHS process to terminate.  If RHS does not terminate in 20 minutes, clustering will deem that the server has some serious health issues and will bugcheck the server to force failover and recovery.  The bugcheck code will be Stop 0x0000009E ( Parameter1 , Parameter2 , 0x0000000000000005 , Parameter4 ).  Note: that Parameter3 will always be a value of 0x5 if it is the result of an RHS process failing to terminate.

This is the way clustering is designed to work… it is monitoring the health of the system, it detects something is wrong, and recovers.  This is a good thing!

Summary of Recovery Behavior:

1. RHS calls an entry point to resource
2. RHS waits DeadlockTimeout (5 minutes) for resource to respond
3. If resource does not respond, Cluster Service terminates RHS process to recover from unresponsive resource
4. Cluster Service waits DeadlockTimeout x 4 (20 minutes) for the RHS process to terminate
5. If RHS process does not terminate, Cluster Service calls NetFT to bugcheck the node to recover from RHS termination failure
6. NetFT bugchecks the node with a STOP 0x9e

From <https://blogs.msdn.microsoft.com/clustering/2013/01/24/understanding-how-failover-clustering-recovers-from-unresponsive-resources/>

_________________________________________________________________________________________________________________ 

System Information: ABCDX97E

OS Name        Microsoft Windows Server 2012 R2 Standard

Version        6.3.9600 Build 9600

Other OS Description         Not Available

OS Manufacturer        Microsoft Corporation

System Name        ABCDX97E

System Manufacturer        Dell Inc.

System Model        PowerEdge R630

System Type        x64-based PC

System SKU        SKU=NotProvided;ModelName=PowerEdge R630

Processor        Intel(R) Xeon(R) CPU E5-2637 v3 @ 3.50GHz, 3500 Mhz, 4 Core(s), 8 Logical Processor(s)

Processor        Intel(R) Xeon(R) CPU E5-2637 v3 @ 3.50GHz, 3500 Mhz, 4 Core(s), 8 Logical Processor(s)

BIOS Version/Date        Dell Inc. 1.2.10, 09/03/2015

System Events:

• Checked the system logs but was not able to find any event around 5:30 AM. However around 6:30 we get event id 1135 which says that the cluster node is removed from FCM.

Application Events:

• Checked the application logs but was not able to find any events related to the issue.

Cluster Events:

• Checked the Cluster events and found that there are two consecutive heartbeat misses and just after which the cluster node is evicted from the failover cluster manager.

List of outdated drivers:

Cluster Logs:

• There is no Cluster logs generated at the time of issue.

_________________________________________________________________________________________________________________

System Information: ABCDX96E

OS Name        Microsoft Windows Server 2012 R2 Standard

Version        6.3.9600 Build 9600

Other OS Description         Not Available

OS Manufacturer        Microsoft Corporation

System Name        ABCDX96E

System Manufacturer        Dell Inc.

System Model        PowerEdge R630

System Type        x64-based PC

System SKU        SKU=NotProvided;ModelName=PowerEdge R630

Processor        Intel(R) Xeon(R) CPU E5-2637 v3 @ 3.50GHz, 3500 Mhz, 4 Core(s), 8 Logical Processor(s)

Processor        Intel(R) Xeon(R) CPU E5-2637 v3 @ 3.50GHz, 3500 Mhz, 4 Core(s), 8 Logical Processor(s)

BIOS Version/Date        Dell Inc. 1.2.10, 09/03/2015

System Events:

• Checked the events and found that the Machine Crashed unexpectedly on 06:30:43 on 10/05/2016.

• As per the events the machine haven’t crashed with any bug check of event id 41.
• As per this scenario the possible causes are: Hardware going bad, Hardware firmware or driver is misbehaving, Mini filter drivers (i.e. antivirus and other security software) is/are misbehaving etc…
  • For More Information please refer: https://blogs.technet.microsoft.com/yongrhee/2015/05/22/how-to-troubleshoot-an-event-id-6008-the-previous-system-shutdown-at-time-on-date-was-unexpected/

• There is No Events logged around 6:30 due to which we are not able to find the events which caused the machine crashed.

Application Events:

• Checked the application logs at the time of issue and found that there are some SQL errors around 1:02 AM and as per the Event 7 the Antivirus application was also active at the time of issue.

• Initially there was a SQL backup job running around 3:00 AM.

Cluster Events:

• Checked the Events and was not able to find any event around 5:30 AM. Events started from 6:30 when the Node Join process started.

Cluster Logs:

000011bc.00004894::2016/05/10-04:36:47.108 INFO  [RES] Network Name: Agent: Sending request Netname/RecheckConfig to NN:e45953f3-78bf-47ac-8f85-c9d89ab14907:Netbios

00000aa8.00000aac::2016/05/10-05:34:53.520 INFO  —————————–+ LOG BEGIN +—————————–

00000aa8.00000aac::2016/05/10-05:34:53.520 INFO  [CS] Starting clussvc as a service

00000aa8.00000dc0::2016/05/10-05:35:27.489 ERR   mscs::QuorumAgent::FormLeaderWorker::operator (): (5038)’ because of ‘Failed to bring quorum resource 12e4512b-aeda-4ff5-9bde-880e3ef31aca online, status 5038’

00000aa8.00000d1c::2016/05/10-05:35:27.506 DBG   [GEM] Node 1: ProcessNew message from node 2

List of outdated drivers:

_________________________________________________________________________________________________________________\ 

Conclusion:

• The logs are not seems to be conclusive as we don’t have enough logs at the time of issue. However as per the event that we found the cluster didn’t failed over the resources as the Isalive and Looksalive test didn’t failed and the Cluster node was not able to understand the unresponsiveness of the SQL resource which was running on the node.

• The following file system locations should be excluded from virus scanning on a server that is running Cluster Services:

•The path of the \mscs folder on the quorum hard disk. For example, exclude the Q:\mscs folder from virus scanning.(Applicable for Cluster 2003)

•The %Systemroot%\Cluster folder.(Applicable for Cluster 2003, 2008 & 2008 R2)

•The temp folder for the Cluster Service account. For example, exclude the \clusterserviceaccount\Local Settings\Temp folder from virus scanning.(Applicable for Cluster 2003)

1. Please follow the article to add the antivirus exclusion for SQL: https://support.microsoft.com/en-gb/kb/309422.

2.  Install following hotfixes on all cluster nodes one by one. Reboot will be required for the changes to take effect. Follow the article and make sure all these updates are installed on all the nodes:

https://support.microsoft.com/en-us/kb/2920151

3. Kindly Update the Outdated Drivers from the List that I have shared with you and some of them are not been update since 2012.

4. Communication between Server Cluster nodes is critical for smooth cluster operations. Therefore, you must configure the networks that you use for cluster communication are configured optimally and follow all hardware compatibility list requirements. For networking configuration, two or more independent networks must connect the nodes of a cluster to avoid a single point of failure. Please add a heartbeat network to the cluster so that it can work properly.

Recommended private “Heartbeat” configuration on a cluster server