1

Have a peculiar case where a previously working FCI, after installing a large backlog of Windows updates, is now failing often and not failing over. On occasion, and this appears to happen around backup times, the FCI will fail, fail to restart the SQL Server Service and then then, apparently, fail to attempt to start this on the other node. The “SQL Server” Resource Policies are configured to “attempt restart on current node,” but also “fail over all resources if restart is unsuccessful,” though the latter doesn’t appear to be happening.

Running Windows Server 2012 (non-R2) Standard—same SQL Server version on both nodes, all Windows updates are installed, NIC driver and firmware are current, DNS servers are fine and cluster validation passes. The relevant portion of the cluster log:

00000d2c.00001528::2018/06/27-00:42:20.212  INFO    [RES]   "Network Name <SQL Network Name (EXAMPLE-SQL)>: [cxl::Pinger-""EXAMPLE-SQL""] Host not registered."
00000d2c.00001528::2018/06/27-00:42:20.212  WARN    [RES]   "Network Name <SQL Network Name (EXAMPLE-SQL)>: [cxl::Pinger-""EXAMPLE-SQL""] Could not find any endpoints for remote target"
00000d2c.00001528::2018/06/27-00:42:20.212  INFO    [RES]   Network Name <SQL Network Name (EXAMPLE-SQL)>: Dns: PingName internal returned 258
00000d2c.00001528::2018/06/27-00:42:20.212  INFO    [RES]   Network Name <SQL Network Name (EXAMPLE-SQL)>: Setting resource specific message to Name Resolution Not Yet Available
000006ac.00001e84::2018/06/27-00:42:20.212  INFO    [GEM]   Node 1: Sending 1 messages as a batched GEM message with gid 3354
00000d2c.00001528::2018/06/27-00:42:20.212  INFO    [RES]   "Network Name <SQL Network Name (EXAMPLE-SQL)>: Dns: Slow Operation, FinishWithReply: 258"
00000d2c.00001528::2018/06/27-00:42:20.212  INFO    [RES]   Network Name <SQL Network Name (EXAMPLE-SQL)>: Dns: InternalReplyHandler: 258
00000d2c.00001528::2018/06/27-00:42:20.212  INFO    [RES]   "Network Name <SQL Network Name (EXAMPLE-SQL)>: Dns: End of Slow Operation, state: Initialized/Idle, prevWorkState: Idle"
00000d2c.0000136c::2018/06/27-00:42:22.896  INFO    [RES]   Network Name: Agent: Sending request Netname/RecheckConfig to NN:c65409d9-3cd6-4670-a26e-07912ecc888b:Netbios
00000d2c.00001528::2018/06/27-00:42:22.896  INFO    [RES]   "Network Name <SQL Network Name (EXAMPLE-SQL)>: Netbios: Slow Operation, FinishWithReply: 0"
00000d2c.00001528::2018/06/27-00:42:22.896  INFO    [RES]   Network Name:  [NN] got sync reply: 0
00000d2c.00001528::2018/06/27-00:42:22.896  INFO    [RES]   "Network Name <SQL Network Name (EXAMPLE-SQL)>: Netbios: End of Slow Operation, state: Initialized/Idle, prevWorkState: Idle"
00000d2c.0000136c::2018/06/27-00:42:24.737  INFO    [RES]   Network Name: Agent: Sending request Netname/RecheckConfig to NN:80999ce3-1900-4137-85d5-4c4bc9309ced:Netbios
00000d2c.00001528::2018/06/27-00:42:24.737  INFO    [RES]   "Network Name <Cluster Name>: Netbios: Slow Operation, FinishWithReply: 0"
00000d2c.00001528::2018/06/27-00:42:24.737  INFO    [RES]   Network Name:  [NN] got sync reply: 0
00000d2c.00001528::2018/06/27-00:42:24.737  INFO    [RES]   "Network Name <Cluster Name>: Netbios: End of Slow Operation, state: Initialized/Idle, prevWorkState: Idle"
00000d2c.00001528::2018/06/27-00:42:27.903  INFO    [RES]   Network Name: Agent: Sending request Netname/RecheckConfig to NN:c65409d9-3cd6-4670-a26e-07912ecc888b:Netbios
00000d2c.0000136c::2018/06/27-00:42:27.903  INFO    [RES]   "Network Name <SQL Network Name (EXAMPLE-SQL)>: Netbios: Slow Operation, FinishWithReply: 0"
00000d2c.0000136c::2018/06/27-00:42:27.903  INFO    [RES]   Network Name:  [NN] got sync reply: 0
00000d2c.0000136c::2018/06/27-00:42:27.903  INFO    [RES]   "Network Name <SQL Network Name (EXAMPLE-SQL)>: Netbios: End of Slow Operation, state: Initialized/Idle, prevWorkState: Idle"
00000d2c.0000136c::2018/06/27-00:42:29.744  INFO    [RES]   Network Name: Agent: Sending request Netname/RecheckConfig to NN:80999ce3-1900-4137-85d5-4c4bc9309ced:Netbios
00000d2c.00001528::2018/06/27-00:42:29.744  INFO    [RES]   "Network Name <Cluster Name>: Netbios: Slow Operation, FinishWithReply: 0"
00000d2c.00001528::2018/06/27-00:42:29.744  INFO    [RES]   Network Name:  [NN] got sync reply: 0
00000d2c.00001528::2018/06/27-00:42:29.744  INFO    [RES]   "Network Name <Cluster Name>: Netbios: End of Slow Operation, state: Initialized/Idle, prevWorkState: Idle"
00000d2c.00001528::2018/06/27-00:42:32.911  INFO    [RES]   Network Name: Agent: Sending request Netname/RecheckConfig to NN:c65409d9-3cd6-4670-a26e-07912ecc888b:Netbios
00000d2c.0000136c::2018/06/27-00:42:32.911  INFO    [RES]   "Network Name <SQL Network Name (EXAMPLE-SQL)>: Netbios: Slow Operation, FinishWithReply: 0"
00000d2c.0000136c::2018/06/27-00:42:32.911  INFO    [RES]   Network Name:  [NN] got sync reply: 0
00000d2c.0000136c::2018/06/27-00:42:32.911  INFO    [RES]   "Network Name <SQL Network Name (EXAMPLE-SQL)>: Netbios: End of Slow Operation, state: Initialized/Idle, prevWorkState: Idle"
00000d2c.00001528::2018/06/27-00:42:34.752  INFO    [RES]   Network Name: Agent: Sending request Netname/RecheckConfig to NN:80999ce3-1900-4137-85d5-4c4bc9309ced:Netbios
00000d2c.0000136c::2018/06/27-00:42:34.752  INFO    [RES]   "Network Name <Cluster Name>: Netbios: Slow Operation, FinishWithReply: 0"
00000d2c.0000136c::2018/06/27-00:42:34.752  INFO    [RES]   Network Name:  [NN] got sync reply: 0
00000d2c.0000136c::2018/06/27-00:42:34.752  INFO    [RES]   "Network Name <Cluster Name>: Netbios: End of Slow Operation, state: Initialized/Idle, prevWorkState: Idle"
00000d2c.00001528::2018/06/27-00:42:37.919  INFO    [RES]   Network Name: Agent: Sending request Netname/RecheckConfig to NN:c65409d9-3cd6-4670-a26e-07912ecc888b:Netbios
00000d2c.0000136c::2018/06/27-00:42:37.919  INFO    [RES]   "Network Name <SQL Network Name (EXAMPLE-SQL)>: Netbios: Slow Operation, FinishWithReply: 0"
00000d2c.0000136c::2018/06/27-00:42:37.919  INFO    [RES]   Network Name:  [NN] got sync reply: 0
00000d2c.0000136c::2018/06/27-00:42:37.919  INFO    [RES]   "Network Name <SQL Network Name (EXAMPLE-SQL)>: Netbios: End of Slow Operation, state: Initialized/Idle, prevWorkState: Idle"
00000d2c.00001528::2018/06/27-00:42:39.760  INFO    [RES]   Network Name: Agent: Sending request Netname/RecheckConfig to NN:80999ce3-1900-4137-85d5-4c4bc9309ced:Netbios
00000d2c.0000136c::2018/06/27-00:42:39.760  INFO    [RES]   "Network Name <Cluster Name>: Netbios: Slow Operation, FinishWithReply: 0"
00000d2c.0000136c::2018/06/27-00:42:39.760  INFO    [RES]   Network Name:  [NN] got sync reply: 0
00000d2c.0000136c::2018/06/27-00:42:39.760  INFO    [RES]   "Network Name <Cluster Name>: Netbios: End of Slow Operation, state: Initialized/Idle, prevWorkState: Idle"
00000d2c.0000136c::2018/06/27-00:42:42.927  INFO    [RES]   Network Name: Agent: Sending request Netname/RecheckConfig to NN:c65409d9-3cd6-4670-a26e-07912ecc888b:Netbios
00000d2c.00001528::2018/06/27-00:42:42.927  INFO    [RES]   "Network Name <SQL Network Name (EXAMPLE-SQL)>: Netbios: Slow Operation, FinishWithReply: 0"
00000d2c.00001528::2018/06/27-00:42:42.927  INFO    [RES]   Network Name:  [NN] got sync reply: 0
00000d2c.00001528::2018/06/27-00:42:42.927  INFO    [RES]   "Network Name <SQL Network Name (EXAMPLE-SQL)>: Netbios: End of Slow Operation, state: Initialized/Idle, prevWorkState: Idle"
00000d2c.00001528::2018/06/27-00:42:44.768  INFO    [RES]   Network Name: Agent: Sending request Netname/RecheckConfig to NN:80999ce3-1900-4137-85d5-4c4bc9309ced:Netbios
00000d2c.0000136c::2018/06/27-00:42:44.768  INFO    [RES]   "Network Name <Cluster Name>: Netbios: Slow Operation, FinishWithReply: 0"
00000d2c.0000136c::2018/06/27-00:42:44.768  INFO    [RES]   Network Name:  [NN] got sync reply: 0
00000d2c.0000136c::2018/06/27-00:42:44.768  INFO    [RES]   "Network Name <Cluster Name>: Netbios: End of Slow Operation, state: Initialized/Idle, prevWorkState: Idle"
00000d2c.00001528::2018/06/27-00:42:47.935  INFO    [RES]   Network Name: Agent: Sending request Netname/RecheckConfig to NN:c65409d9-3cd6-4670-a26e-07912ecc888b:Netbios
00000d2c.0000136c::2018/06/27-00:42:47.935  INFO    [RES]   "Network Name <SQL Network Name (EXAMPLE-SQL)>: Netbios: Slow Operation, FinishWithReply: 0"
00000d2c.0000136c::2018/06/27-00:42:47.935  INFO    [RES]   Network Name:  [NN] got sync reply: 0
00000d2c.0000136c::2018/06/27-00:42:47.935  INFO    [RES]   "Network Name <SQL Network Name (EXAMPLE-SQL)>: Netbios: End of Slow Operation, state: Initialized/Idle, prevWorkState: Idle"
00000d2c.0000136c::2018/06/27-00:42:49.775  INFO    [RES]   Network Name: Agent: Sending request Netname/RecheckConfig to NN:80999ce3-1900-4137-85d5-4c4bc9309ced:Netbios
00000d2c.00001528::2018/06/27-00:42:49.775  INFO    [RES]   "Network Name <Cluster Name>: Netbios: Slow Operation, FinishWithReply: 0"
00000d2c.00001528::2018/06/27-00:42:49.775  INFO    [RES]   Network Name:  [NN] got sync reply: 0
00000d2c.00001528::2018/06/27-00:42:49.775  INFO    [RES]   "Network Name <Cluster Name>: Netbios: End of Slow Operation, state: Initialized/Idle, prevWorkState: Idle"
00000d2c.0000136c::2018/06/27-00:42:52.942  INFO    [RES]   Network Name: Agent: Sending request Netname/RecheckConfig to NN:c65409d9-3cd6-4670-a26e-07912ecc888b:Netbios
00000d2c.00001528::2018/06/27-00:42:52.942  INFO    [RES]   "Network Name <SQL Network Name (EXAMPLE-SQL)>: Netbios: Slow Operation, FinishWithReply: 0"
00000d2c.00001528::2018/06/27-00:42:52.942  INFO    [RES]   Network Name:  [NN] got sync reply: 0
00000d2c.00001528::2018/06/27-00:42:52.942  INFO    [RES]   "Network Name <SQL Network Name (EXAMPLE-SQL)>: Netbios: End of Slow Operation, state: Initialized/Idle, prevWorkState: Idle"
00000e70.000008dc::2018/06/27-00:42:53.379  ERR [RES]   "SQL Server <SQL Server>: [sqsrvres] Failure detected, diagnostics heartbeat is lost"
00000e70.000008dc::2018/06/27-00:42:53.379  INFO    [RES]   SQL Server <SQL Server>: [sqsrvres] IsAlive returns FALSE
00000e70.000008dc::2018/06/27-00:42:53.379  WARN    [RHS]   Resource SQL Server IsAlive has indicated failure.
000006ac.00001e84::2018/06/27-00:42:53.379  INFO    [RCM]   "HandleMonitorReply: FAILURENOTIFICATION for 'SQL Server', gen(0) result 1/0."
000006ac.00001e84::2018/06/27-00:42:53.379  INFO    [RCM]   Res SQL Server: Online -> ProcessingFailure( StateUnknown )
000006ac.00001e84::2018/06/27-00:42:53.379  INFO    [RCM]   TransitionToState(SQL Server) Online-->ProcessingFailure.
000006ac.0000151c::2018/06/27-00:42:53.379  INFO    [GEM]   Node 1: Sending 1 messages as a batched GEM message with gid 3355
000006ac.00001e84::2018/06/27-00:42:53.379  INFO    [RCM]   "rcm::RcmGroup::UpdateStateIfChanged: (SQL Server (MSSQLSERVER), Online --> Pending)"
000006ac.00001e84::2018/06/27-00:42:53.379  ERR [RCM]   rcm::RcmResource::HandleFailure: (SQL Server)
00000e70.000010f4::2018/06/27-00:42:53.379  INFO    [RES]   SQL Server <SQL Server>: [sqsrvres] SQLMoreResults() returns -1 with following information
00000e70.000010f4::2018/06/27-00:42:53.379  ERR [RES]   SQL Server <SQL Server>: [sqsrvres] ODBC Error: [HYT00] [Microsoft][SQL Server Native Client 11.0]Query timeout expired (0)
00000e70.000010f4::2018/06/27-00:42:53.379  ERR [RES]   SQL Server <SQL Server>: [sqsrvres] ODBC Error: [01000] [Microsoft][SQL Server Native Client 11.0][SQL Server]  (0)
00000e70.000010f4::2018/06/27-00:42:53.379  INFO    [RES]   SQL Server <SQL Server>: [sqsrvres] No more diagnostics results
00000e70.000010f4::2018/06/27-00:42:53.379  INFO    [RES]   SQL Server <SQL Server>: [sqsrvres] Discard the pending result sets
000006ac.00000ac8::2018/06/27-00:42:53.379  INFO    [GEM]   Node 1: Sending 1 messages as a batched GEM message with gid 3356
000006ac.0000096c::2018/06/27-00:42:53.379  INFO    [RCM]   ignored non-local state Pending for group SQL Server (MSSQLSERVER)
000006ac.00001e84::2018/06/27-00:42:53.395  INFO    [RCM]   "resource SQL Server: failure count: 0, restartAction: 0 persistentState: 1."
000006ac.00001e84::2018/06/27-00:42:53.395  INFO    [RCM]   resource SQL Server will not be restarting; isLowPriority: true; numDependents: 1
000006ac.00001e84::2018/06/27-00:42:53.395  INFO    [RCM]   Res SQL Server: ProcessingFailure -> WaitingToTerminate( Failed )
000006ac.00001e84::2018/06/27-00:42:53.395  INFO    [RCM]   TransitionToState(SQL Server) ProcessingFailure-->[WaitingToTerminate to Failed].
000006ac.00001e84::2018/06/27-00:42:53.395  INFO    [RCM]   Res SQL Server Agent: Online -> WaitingToTerminate( OfflineDueToProvider )
000006ac.00001e84::2018/06/27-00:42:53.395  INFO    [RCM]   TransitionToState(SQL Server Agent) Online-->[WaitingToTerminate to OfflineDueToProvider].
000006ac.00002660::2018/06/27-00:42:53.395  INFO    [GEM]   Node 1: Sending 1 messages as a batched GEM message with gid 3357
000006ac.00001e84::2018/06/27-00:42:53.395  INFO    [RCM]   Res SQL Server Agent: [WaitingToTerminate to OfflineDueToProvider] -> Terminating( OfflineDueToProvider )
000006ac.00001e84::2018/06/27-00:42:53.395  INFO    [RCM]   TransitionToState(SQL Server Agent) [WaitingToTerminate to OfflineDueToProvider]-->[Terminating to OfflineDueToProvider].
000006ac.00001e84::2018/06/27-00:42:53.395  INFO    [RCM]   SQL Server not yet ready to terminate; dependent SQL Server Agent still terminating.
000006ac.00001e84::2018/06/27-00:42:53.395  INFO    [RCM]   Will NOT try to long delay restart SQL Server.
000006ac.00001e84::2018/06/27-00:42:53.395  INFO    [RCM]   RecursivelyCancelRestart: SQL Server Agent in state [Terminating to OfflineDueToProvider]
000006ac.00000ac8::2018/06/27-00:42:53.410  INFO    [GEM]   Node 1: Sending 1 messages as a batched GEM message with gid 3358
00000e70.000010f4::2018/06/27-00:42:53.442  ERR [RES]   SQL Server <SQL Server>: [sqsrvres] ODBC Error: [24000] [Microsoft][SQL Server Native Client 11.0]Invalid cursor state (0)
00000e70.000010f4::2018/06/27-00:42:53.442  INFO    [RES]   SQL Server <SQL Server>: [sqsrvres] Diagnostics is stopped
00000e70.0000105c::2018/06/27-00:42:53.442  INFO    [RES]   SQL Server <SQL Server>: [sqsrvres] Online worker helper is stopped
00000e70.000010f4::2018/06/27-00:42:53.442  INFO    [RES]   SQL Server <SQL Server>: [sqsrvres] Disconnect from SQL Server
00000e70.000010f4::2018/06/27-00:42:54.456  INFO    [RES]   SQL Server <SQL Server>: [sqsrvres] Connect to SQL Server ...
00000e70.000010f4::2018/06/27-00:42:54.565  INFO    [RES]   SQL Server <SQL Server>: [sqsrvres] The connection was established successfully
00000e70.000010f4::2018/06/27-00:42:54.580  INFO    [RES]   SQL Server <SQL Server>: [sqsrvres] Diagnostics is started
00000e70.000016c4::2018/06/27-00:42:54.580  INFO    [RES]   SQL Server <SQL Server>: [sqsrvres] Online worker helper is started
00000e70.000010f4::2018/06/27-00:42:54.580  INFO    [RES]   SQL Server <SQL Server>: [sqsrvres] SQL Server component 'system' health state has been changed from '' to 'clean' at 2018-06-27 00:42:54.577
00000e70.000010f4::2018/06/27-00:42:54.580  INFO    [RES]   SQL Server <SQL Server>: [sqsrvres] SQL Server component 'resource' health state has been changed from '' to 'clean' at 2018-06-27 00:42:54.577
00000e70.000010f4::2018/06/27-00:42:54.612  INFO    [RES]   SQL Server <SQL Server>: [sqsrvres] SQL Server component 'query_processing' health state has been changed from '' to 'clean' at 2018-06-27 00:42:54.577
00000e70.000010f4::2018/06/27-00:42:54.612  INFO    [RES]   SQL Server <SQL Server>: [sqsrvres] SQL Server component 'io_subsystem' health state has been changed from '' to 'clean' at 2018-06-27 00:42:54.577
00000e70.000010f4::2018/06/27-00:42:54.612  INFO    [RES]   SQL Server <SQL Server>: [sqsrvres] SQL Server component 'events' health state has been changed from '' to 'unknown' at 2018-06-27 00:42:54.577
00000d2c.0000136c::2018/06/27-00:42:54.783  INFO    [RES]   Network Name: Agent: Sending request Netname/RecheckConfig to NN:80999ce3-1900-4137-85d5-4c4bc9309ced:Netbios
00000d2c.00001528::2018/06/27-00:42:54.783  INFO    [RES]   "Network Name <Cluster Name>: Netbios: Slow Operation, FinishWithReply: 0"
00000d2c.00001528::2018/06/27-00:42:54.783  INFO    [RES]   Network Name:  [NN] got sync reply: 0
00000d2c.00001528::2018/06/27-00:42:54.783  INFO    [RES]   "Network Name <Cluster Name>: Netbios: End of Slow Operation, state: Initialized/Idle, prevWorkState: Idle"
000006ac.0000151c::2018/06/27-00:42:55.906  INFO    [RCM]   "HandleMonitorReply: TERMINATERESOURCE for 'SQL Server Agent', gen(0) result 0/0."
000006ac.0000151c::2018/06/27-00:42:55.906  INFO    [RCM]   Res SQL Server Agent: [Terminating to OfflineDueToProvider] -> OfflineDueToProvider( StateUnknown )
000006ac.0000151c::2018/06/27-00:42:55.906  INFO    [RCM]   TransitionToState(SQL Server Agent) [Terminating to OfflineDueToProvider]-->OfflineDueToProvider.
000006ac.0000151c::2018/06/27-00:42:55.906  INFO    [RCM]   Res SQL Server: [WaitingToTerminate to Failed] -> Terminating( Failed )
000006ac.00001e84::2018/06/27-00:42:55.906  INFO    [GEM]   Node 1: Sending 1 messages as a batched GEM message with gid 3359
000006ac.0000151c::2018/06/27-00:42:55.906  INFO    [RCM]   TransitionToState(SQL Server) [WaitingToTerminate to Failed]-->[Terminating to Failed].
00000e70.000008dc::2018/06/27-00:42:55.906  INFO    [RES]   SQL Server <SQL Server>: [sqsrvres] Request to terminate SQL Server
00000e70.000008dc::2018/06/27-00:42:55.906  INFO    [RES]   SQL Server <SQL Server>: [sqsrvres] Stop service MSSQLSERVER immediately
00000e70.000016c4::2018/06/27-00:42:55.906  INFO    [RES]   SQL Server <SQL Server>: [sqsrvres] Online worker was asked to terminate
00000e70.000010f4::2018/06/27-00:42:56.063  INFO    [RES]   SQL Server <SQL Server>: [sqsrvres] SQLMoreResults() returns -1 with following information
00000e70.000016c4::2018/06/27-00:42:56.063  INFO    [RES]   SQL Server <SQL Server>: [sqsrvres] Online worker helper is stopped
00000e70.000010f4::2018/06/27-00:42:56.063  ERR [RES]   SQL Server <SQL Server>: [sqsrvres] ODBC Error: [08S01] [Microsoft][SQL Server Native Client 11.0]TCP Provider: The specified network name is no longer available.
-64         
00000e70.000010f4::2018/06/27-00:42:56.063  ERR [RES]   SQL Server <SQL Server>: [sqsrvres] ODBC Error: [08S01] [Microsoft][SQL Server Native Client 11.0]Communication link failure (64)
00000e70.000010f4::2018/06/27-00:42:56.063  ERR [RES]   SQL Server <SQL Server>: [sqsrvres] ODBC Error: [01000] [Microsoft][SQL Server Native Client 11.0][SQL Server]  (0)
00000e70.000010f4::2018/06/27-00:42:56.063  INFO    [RES]   SQL Server <SQL Server>: [sqsrvres] No more diagnostics results
00000e70.000010f4::2018/06/27-00:42:56.063  INFO    [RES]   SQL Server <SQL Server>: [sqsrvres] Diagnostics is stopped
00000e70.000010f4::2018/06/27-00:42:56.063  INFO    [RES]   SQL Server <SQL Server>: [sqsrvres] Disconnect from SQL Server
00000e70.000010f4::2018/06/27-00:42:56.063  INFO    [RES]   SQL Server <SQL Server>: [sqsrvres] Extended Event logging is stopped
00000e70.000010f4::2018/06/27-00:42:56.078  INFO    [RES]   SQL Server <SQL Server>: [sqsrvres] Extended Event target state:
00000e70.000010f4::2018/06/27-00:42:56.078  INFO    [RES]   "SQL Server <SQL Server>: [sqsrvres] Extended Event session summary: dropped buffers = 0, dropped events = 0"
00000e70.000010f4::2018/06/27-00:42:56.078  INFO    [RES]   SQL Server <SQL Server>: [sqsrvres] Online worker is stopped
000006ac.00000de8::2018/06/27-00:42:57.155  INFO    [GEM]   Node 1: Sending 1 messages as a batched GEM message with gid 3360
00000d2c.0000136c::2018/06/27-00:42:57.950  INFO    [RES]   Network Name: Agent: Sending request Netname/RecheckConfig to NN:c65409d9-3cd6-4670-a26e-07912ecc888b:Netbios
00000d2c.00001528::2018/06/27-00:42:57.950  INFO    [RES]   "Network Name <SQL Network Name (EXAMPLE-SQL)>: Netbios: Slow Operation, FinishWithReply: 0"
00000d2c.00001528::2018/06/27-00:42:57.950  INFO    [RES]   Network Name:  [NN] got sync reply: 0
00000d2c.00001528::2018/06/27-00:42:57.950  INFO    [RES]   "Network Name <SQL Network Name (EXAMPLE-SQL)>: Netbios: End of Slow Operation, state: Initialized/Idle, prevWorkState: Idle"
00000d2c.0000136c::2018/06/27-00:42:59.791  INFO    [RES]   Network Name: Agent: Sending request Netname/RecheckConfig to NN:80999ce3-1900-4137-85d5-4c4bc9309ced:Netbios
00000d2c.00001528::2018/06/27-00:42:59.791  INFO    [RES]   "Network Name <Cluster Name>: Netbios: Slow Operation, FinishWithReply: 0"
00000d2c.00001528::2018/06/27-00:42:59.791  INFO    [RES]   Network Name:  [NN] got sync reply: 0
00000d2c.00001528::2018/06/27-00:42:59.791  INFO    [RES]   "Network Name <Cluster Name>: Netbios: End of Slow Operation, state: Initialized/Idle, prevWorkState: Idle"
00000e18.000021cc::2018/06/27-00:42:59.931  INFO    [RES]   Physical Disk <Cluster Disk 3>: VolumeIsNtfs: Volume \\?\GLOBALROOT\Device\Harddisk1\ClusterPartition1\ has FS type NTFS
00000e70.000008dc::2018/06/27-00:43:00.992  INFO    [RES]   SQL Server <SQL Server>: [sqsrvres] Service was stopped successfully
00000e70.000008dc::2018/06/27-00:43:00.992  INFO    [RES]   SQL Server <SQL Server>: [sqsrvres] Terminate handling is completed
00000e70.000008dc::2018/06/27-00:43:00.992  INFO    [RES]   SQL Server <SQL Server>: [sqsrvres] SQL Server resource state is changed from 'ClusterResourceOnline' to 'ClusterResourceFailed'
00000e70.000008dc::2018/06/27-00:43:00.992  WARN    [RHS]   returning ResourceExitStateTerminate.
000006ac.00001e84::2018/06/27-00:43:00.992  INFO    [RCM]   "HandleMonitorReply: TERMINATERESOURCE for 'SQL Server', gen(1) result 0/0."
000006ac.00001e84::2018/06/27-00:43:00.992  INFO    [RCM]   Res SQL Server: [Terminating to Failed] -> Failed( StateUnknown )
000006ac.00001e84::2018/06/27-00:43:00.992  INFO    [RCM]   TransitionToState(SQL Server) [Terminating to Failed]-->Failed.
000006ac.00001e84::2018/06/27-00:43:00.992  INFO    [RCM]   "rcm::RcmGroup::UpdateStateIfChanged: (SQL Server (MSSQLSERVER), Pending --> Failed)"
000006ac.00002660::2018/06/27-00:43:00.992  INFO    [RCM]   moved 0 tasks from staging set to task set.  TaskSetSize=0
000006ac.00002660::2018/06/27-00:43:00.992  INFO    [RCM]   "rcm::RcmPriorityManager::StartGroups: [RCM] done, executed 0 tasks"
000006ac.0000151c::2018/06/27-00:43:00.992  INFO    [GEM]   Node 1: Sending 1 messages as a batched GEM message with gid 3361
000006ac.0000096c::2018/06/27-00:43:00.992  INFO    [RCM]   ignored non-local state Failed for group SQL Server (MSSQLSERVER)
00000d2c.0000136c::2018/06/27-00:43:02.724  INFO    [RES]   Network Name <SQL Network Name (EXAMPLE-SQL)>: Dns: HealthCheck: EXAMPLE-SQL
00000d2c.0000136c::2018/06/27-00:43:02.724  INFO    [RES]   "Network Name <SQL Network Name (EXAMPLE-SQL)>: Dns: End of Slow Operation, state: Initialized/Reading, prevWorkState: Reading"
00000d2c.0000136c::2018/06/27-00:43:02.724  INFO    [RES]   Network Name <SQL Network Name (EXAMPLE-SQL)>: Dns: PingName internal returned 0
00000d2c.0000136c::2018/06/27-00:43:02.724  INFO    [RES]   Network Name <SQL Network Name (EXAMPLE-SQL)>: Dns: Endpoint is up
00000d2c.0000136c::2018/06/27-00:43:02.724  INFO    [RES]   Network Name <SQL Network Name (EXAMPLE-SQL)>: Setting resource specific message to
  • Do the resources have “preferred ownership” to every node? Sorry, miswrote possible. Check permissions from top down – clifton_h Jul 1 '18 at 23:10
  • Yes. All nodes are listed as Preferred Owners for the Role and Possible Owners for each Resource. For what it’s worth, manual failover works without incident. – Bink Jul 2 '18 at 16:13
  • Then what is the error? FCM certainly has some reason it cannot failover. – clifton_h Jul 2 '18 at 17:21
  • Cluster resource 'SQL Server' of type 'SQL Server' in clustered role 'SQL Server (MSSQLSERVER)' failed. See the cluster log above for more detail. – Bink Jul 2 '18 at 20:56
0

Sorry for posting this as an answer, but I'm not able to "comment" yet. I see on the logs "SQL Server : [sqsrvres] IsAlive returns FALSE" If I remember correctly there's an account which perform this check, but don't remember which is. Please check in SQL Server logs if you see some login failed or anything related. It could be the account does not have permissions or the Authentication is working with some issues. Sometimes antivirus can be causing issues too. If possible paste the SQL logs during the time of the issue.

0

Since my post, newer NIC driver and firmware became available and updating to these resolved the issue, kind of. While my FCI doesn’t fail anymore because the network is stable now (it appears high NIC load would cause all sorts of issues, but the NIC updates resolved these), I don’t have a lot of confidence failover will occur properly even when I have issues again.

  • do you have a private cluster network set up? One time years ago I had a FCI cluster with HP Network Teaming and connections to different switches. I had this same problem and it was something with the port or switch configuration. Adding a cross-over cable and configuring a private cluster network solved the issue. – Alen Jul 11 '18 at 18:22
  • No. As I understand it, this is frowned upon nowadays, as this is a single point of failure. I leveraged the built in NIC Teaming and use QoS for the management network so heartbeat packets should not be dropped. – Bink Jul 12 '18 at 15:37
  • Starting with Windows 2012 or 2012 R2 the teaming was built into the OS and the HP NIC drivers took that option away. I'm not sure of the exact port or switch configuration but it was a factor in being able to failover. We had a few super-expensive core switches with a few dozen ports each and a bunch of VLAN's between them. – Alen Jul 12 '18 at 15:56

Your Answer

By clicking “Post Your Answer”, you agree to our terms of service, privacy policy and cookie policy

Not the answer you're looking for? Browse other questions tagged or ask your own question.