Search This Blog

Showing posts with label Cluster. Show all posts
Showing posts with label Cluster. Show all posts

Mar 19, 2012

Logging event id 1069 and 1558 every 15 minutes


    Hello,

    I'm posting a new issue that I saw in few days and was solved with a solution that it's not so simple. Actually the solution is simple but the way to do that in same cases could create a second problem :)

    Let's check the scenario and actions takens.

    Subjective
    ============

    Getting Events 1069 and 1558 logged every 15 minutes on the server USPHXE0251 which has the Cluster Group.
    In this scenario we had Exchange 2010 DAG impacting but these "errors" can appears on SQL or any Cluster activity.

    Typed "cluster res" command
    Listing status for all available resources:

    Resource             Group                Node            Status
    -------------------- -------------------- --------------- ------
    Cluster IP Address   Cluster Group        E0251      Online
    Cluster Name         Cluster Group        E0251      Online
    File Share Witness (\\e0202.xyz.com\DAG01.xyz.com) Cluster Group      E0251      Online


    Log Name:      System
    Source:        Microsoft-Windows-FailoverClustering
    Event ID:      1069
    Task Category: Resource Control Manager
    Level:         Error
    User:          SYSTEM
    Computer:      E0233.xyz.com
    Description: Cluster resource 'File Share Witness (\\e0202.xyz.com\DAG01.xyz.com)' in clustered service or application 'Cluster Group' failed.

    Log Name:      System
    Source:        Microsoft-Windows-FailoverClustering
    Event ID:      1558
    Task Category: Quorum Manager
    Level:         Warning
    User:          SYSTEM
    Computer:     E0251.xyz.com
    Description: The cluster service detected a problem with the witness resource. The witness resource will be failed over to another node within the cluster in an attempt to reestablish access to cluster configuration data.

  1. In this case my Failover Cluster is running with Exchange 2010 SP1 and we've configure the Quorum with FSM option. The File server is Hub Server.

  2. Actions Takens
    ===============

    • Looking to HUB server (Witness Disk Servers) we see the following drivers are with the same driver level for SMB:
      • contains the MRXSMB10.sys = 6.1.7601.21767 and MRXSMB20.sys = 6.1.7601.17605


    • Generated the Cluster.log using the command "cluster log  /gen"

    00002bcc.00001eb8::2012/02/28-21:47:49.278 ERR   [QUORUM] Node 4: Failing quorum resource due to witness failure
    00002bcc.00002c90::2012/02/28-21:47:49.278 INFO  [GUM] Node 4: Processing RequestLock 4:368
    00002bcc.00001eb8::2012/02/28-21:47:49.278 INFO  [RCM] HandleMonitorReply: FAILURENOTIFICATION for 'File Share Witness (\\e0202.xyz.com\DAG01.xyz.com)', gen(578) result 0.
    00002bcc.00001eb8::2012/02/28-21:47:49.278 INFO  [RCM] TransitionToState(File Share Witness (\\e0202.xyz.com\DAG01.xyz.com)) Online-->ProcessingFailure.
    00002bcc.00001eb8::2012/02/28-21:47:49.278 INFO  [RCM] rcm::RcmGroup::UpdateStateIfChanged: (Cluster Group, Online --> Failed)
    00002bcc.00001eb8::2012/02/28-21:47:49.278 ERR   [RCM] rcm::RcmResource::HandleFailure: (File Share Witness (\\e0202.xyz.com\DAG01.xyz.com))
    00002bcc.00001eb8::2012/02/28-21:47:49.278 INFO  [QUORUM] Node 4: PostRelease for 0dd9ec96-71d1-4949-806d-7d5403ff3f6d
    00002bcc.00001eb8::2012/02/28-21:47:49.278 INFO  [RCM] resource File Share Witness (\\e0202.xyz.com\DAG01.xyz.com): failure count: 2, restartAction: 2.
    00002bcc.00001eb8::2012/02/28-21:47:49.278 INFO  [RCM] Greater than restartPeriod time has elapsed since first failure, resetting failureTime and failureCount.
    00002bcc.00001eb8::2012/02/28-21:47:49.278 INFO  [RCM] Will restart resource in 500 milliseconds.
    00002bcc.00001eb8::2012/02/28-21:47:49.278 INFO  [RCM] TransitionToState(File Share Witness (\\e0202.xyz.com\DAG01.xyz.com)) ProcessingFailure-->[WaitingToTerminate to DelayRestartingResource].
    00002bcc.00001eb8::2012/02/28-21:47:49.278 INFO  [RCM] rcm::RcmGroup::UpdateStateIfChanged: (Cluster Group, Failed --> Pending)
    00002bcc.00001eb8::2012/02/28-21:47:49.278 INFO  [RCM] TransitionToState(File Share Witness (\\e0202.xyz.com\DAG01.xyz.com)) [WaitingToTerminate to DelayRestartingResource]-->[Terminating to DelayRestartingResource].
    00002284.000042a4::2012/02/28-21:47:49.278 INFO  [RES] File Share Witness <File Share Witness (\\e0202.xyz.com\DAG01.xyz.com)>: Terminating resource ...
    00002284.000042a4::2012/02/28-21:47:49.278 INFO  [RES] File Share Witness <File Share Witness (\\e0202.xyz.com\DAG01.xyz.com)>: Resource is offline.
    00002bcc.00001eb8::2012/02/28-21:47:49.278 INFO  [RCM] HandleMonitorReply: TERMINATERESOURCE for 'File Share Witness (\\e0202.xyz.com\DAG01.xyz.com)', gen(579) result 0.
    00002bcc.00001eb8::2012/02/28-21:47:49.278 INFO  [RCM] TransitionToState(File Share Witness (\\e0202.xyz.com\DAG01.xyz.com)) [Terminating to DelayRestartingResource]-->DelayRestartingResource.
    00002bcc.00001d1c::2012/02/28-21:47:49.278 INFO  [GUM] Node 4: Processing GrantLock to 4 (sent by 6 gumid: 140952)
    00002bcc.00002c90::2012/02/28-21:47:49.278 INFO  [QUORUM] Node 4: Witness Failed Gum Handler [QUORUM] Node 4
    00002bcc.00002c90::2012/02/28-21:47:49.278 INFO  [QUORUM] Node 4: witness attach failed. next restart will happen at 2012/02/28-22:02:49.278
    00002bcc.0000238c::2012/02/28-21:47:49.278 INFO  [QUORUM] Node 4: quorum is not owned by anyone
    00002bcc.00004178::2012/02/28-21:47:49.792 INFO  [RCM] Delay-restarting File Share Witness (\\e0202.xyz.com\DAG01.xyz.com) and any waiting dependents.
    00002bcc.00004178::2012/02/28-21:47:49.792 INFO  [RCM] TransitionToState(File Share Witness (\\e0202.xyz.com\DAG01.xyz.com)) DelayRestartingResource-->OnlineCallIssued.
    00002284.00002360::2012/02/28-21:47:49.792 INFO  [RES] File Share Witness <File Share Witness (\\e0202.xyz.com\DAG01.xyz.com)>: Beginning arbitration ...
    00002284.00002360::2012/02/28-21:47:49.792 INFO  [RES] File Share Witness <File Share Witness (\\e0202.xyz.com\DAG01.xyz.com)>: Opening file \\e0202.xyz.com\DAG01.xyz.com\0dd9ec96-71d1-4949-806d-7d5403ff3f6d\Witness.log.
    00002284.00002360::2012/02/28-21:47:49.808 INFO  [RES] File Share Witness <File Share Witness (\\e0202.xyz.com\DAG01.xyz.com)>: Attempting to lock file \\e0202.xyz.com\DAG01.xyz.com\0dd9ec96-71d1-4949-806d-7d5403ff3f6d\Witness.log, try 1 of 30.
    00002284.00002360::2012/02/28-21:47:49.808 INFO  [RES] File Share Witness <File Share Witness (\\e0202.xyz.com\DAG01.xyz.com)>: Succeeded in locking file \\e0202.xyz.com\DAG01.xyz.com\0dd9ec96-71d1-4949-806d-7d5403ff3f6d\Witness.log
    00002bcc.00004178::2012/02/28-21:47:49.824 INFO  [QUORUM] Node 4: PostArbitrate => 0 for 0dd9ec96-71d1-4949-806d-7d5403ff3f6d
    00002bcc.00004178::2012/02/28-21:47:49.824 INFO  [QUORUM] Node 4 CompareAndSetWitnessTag: ignoring any existing data on witness resource.
    00002bcc.00004178::2012/02/28-21:47:49.824 INFO  [QUORUM] Node 4 CompareAndSetWitnessTag: writing witness tag 164:164:509200
    00002284.00002360::2012/02/28-21:47:49.824 INFO  [RES] File Share Witness <File Share Witness (\\e0202.xyz.com\DAG01.xyz.com)>: Writing file share witness epoch data.
    00002284.00002360::2012/02/28-21:47:49.824 INFO  [RES] File Share Witness <File Share Witness (\\e0202.xyz.com\DAG01.xyz.com)>: Wrote 88 bytes to the witness file share.
    00002bcc.00004178::2012/02/28-21:47:49.824 INFO  [QUORUM] Node 4 CompareAndSetWitnessTag: releasing witness share lock
    00002284.00002360::2012/02/28-21:47:49.824 INFO  [RES] File Share Witness <File Share Witness (\\e0202.xyz.com\DAG01.xyz.com)>: Releasing locked witness share.
    00002284.00002360::2012/02/28-21:47:49.824 INFO  [RES] File Share Witness <File Share Witness (\\e0202.xyz.com\DAG01.xyz.com)>: Bringing resource online ...
    00002284.00002360::2012/02/28-21:47:49.824 INFO  [RES] File Share Witness <File Share Witness (\\e0202.xyz.com\DAG01.xyz.com)>: Resource is online.
    00002bcc.00000c60::2012/02/28-21:47:49.824 INFO  [RCM] HandleMonitorReply: ONLINERESOURCE for 'File Share Witness (\\e0202.xyz.com\DAG01.xyz.com)', gen(579) result 0.
    00002bcc.00000c60::2012/02/28-21:47:49.824 INFO  [RCM] TransitionToState(File Share Witness (\\e0202.xyz.com\DAG01.xyz.com)) OnlineCallIssued-->Online.
    00002bcc.00000c60::2012/02/28-21:47:49.824 INFO  [RCM] rcm::RcmGroup::UpdateStateIfChanged: (Cluster Group, Pending --> Online)
    00002bcc.00000c60::2012/02/28-21:47:49.824 INFO  [QUORUM] Node 4: PostOnline for 0dd9ec96-71d1-4949-806d-7d5403ff3f6d
    00002bcc.0000238c::2012/02/28-21:47:49.824 INFO  [QUORUM] Node 4: quorum is arbitrated by node 4
    00002bcc.0000238c::2012/02/28-21:47:49.824 INFO  [QUORUM] Node 4: releasing witness lock (if held) because witness is not needed for quorum in new view.
    00002284.000029f4::2012/02/28-21:47:49.886 INFO  [RES] File Share Witness <File Share Witness (\\e0202.xyz.com\DAG01.xyz.com)>: Ignoring request to release witness share because it is not currently locked.

    • Restarted the all Servers involved for tests (Cluster nodes and File Server).
    • After rebooting new "Host Current Server" is generating the event ID 1069 and 1558
    • Checked the Links below:


    • Basically in that articles Microsoft request to update some drivers like SMB, Clussvc.exe and TCPIP.
    • Changed the Cluster parameters
    cluster /prop SameSubnetDelay=2000 (The default value is 1000 milliseconds, we could set it to 2000 milliseconds.)
    cluster /prop CrossSubnetDelay=2000

    • Installed Updates
    ++++++++

    KB2550886 - A transient communication failure causes a Windows Server 2008 R2 failover cluster to stop working
    Clussvc.exe 6.1.7601.21772

    KB2661010 - IP packets are not routed through a Windows Server 2008 R2–based LAN router in a VLAN environment
    Fwpkclnt.sys 6.1.7601.17514
    Tcpip.sys 6.1.7601.17754

    Fwpkclnt.sys 6.1.7601.21889
    Tcpip.sys 6.1.7601.21889

    KB2616514 - Cluster service sends unnecessary registry key change notifications among cluster nodes in Windows Server 2008 or in Windows Server 2008 R2
    Clussvc.exe 6.1.7601.17730
    Clussvc.exe 6.1.7601.21867

    KB2612966 - Paged pool memory leak when you access some shared files in Windows 7 or in Windows Server 2008 R2
    Mrxsmb10.sys 6.1.7601.21819
    Mrxsmb20.sys 6.1.7601.21819

    ++++++++++++++++++

    • Installed the following updates and rebooted all DAGs and Hub (FSW Server).
    • Changed the Quorum model to Node and Majority and then go back to FSW.
    • AV exclusion contains the correct drive "X:\Witnesses"
    • Generated Cluster.log again. Getting the same issues on Cluster.log. Nothing changed so far.

    00001738.00002760::2012/03/12-22:23:21.225 ERR   [QUORUM] Node 3: Failing quorum resource due to witness failure
    00001738.00001b38::2012/03/12-22:23:21.225 INFO  [RCM] HandleMonitorReply: FAILURENOTIFICATION for 'File Share Witness (\\e0202.xyz.com\DAG01.xyz.com)', gen(7) result 0.
    00001738.00001b38::2012/03/12-22:23:21.225 ERR   [RCM] rcm::RcmResource::HandleFailure: (File Share Witness (\\e0202.xyz.com\DAG01.xyz.com))
    00002168.00002808::2012/03/12-22:23:21.771 INFO  [RES] File Share Witness <File Share Witness (\\e0202.xyz.com\DAG01.xyz.com)>: Ignoring request to release witness share because it is not currently locked.


    • Running a Validate this Cluster and everything is up, running and OK.
    • Checked Network Provider status inside regedit.
    • Our HUB Server is running under VM  technology and contains the following info:   on the fileshare witness server following value exist. "vmhgfs,RDPNP,LanmanWorkstation"  - but it doesn't impact anything. The values are correct.
    • File Share witness is on  a Virtual Machine. Checked on Microsoft technet that recommend configuration sould be use a File Server running on physical box .
    • Changed the FSW server to a physical server. (It doesn't worked).



    Solution
    ==============
    • Shutdown all nodes leaving just one online.
    • The last one need to be restarted to perform the FORM process.
    • After completing the reboot process turned on all others nodes.

Update: 2014/10/30 : Based on anomynous feedback the article listed below it seems to fix the problem.
http://support.microsoft.com/kb/2750820
I'm not able to make this test but it's important to keep the troubleshooting mindset to figure out the root cause.



    Forming a Cluster
    The first server that comes online in a cluster, either after installation or after the entire cluster has been shut down for some reason, forms the cluster. To succeed at forming a cluster, a server must:
    • Be running the Cluster service.
    • Be unable to locate any other nodes in the cluster (in other words, no other nodes can be running).
    • Acquire exclusive ownership of the quorum resource.


    Information
    ==================
    • According to Microsoft this logs although being generated every 15 minutes doesn’t means Cluster impact, but so far the only way to fix is using the form procedure. The Quorum (Witness Disk) is the first resource brought online when cluster service attempts to form a cluster.



Sep 1, 2011

Cannot add the 2nd Node on the Cluster

Cannot add the 2nd Node on the Cluster

This kind of case it's common an the solution could be different but here's a troubleshooting way could help many cases and perhaps can help you.
The Cluster Windows Server 2008 R2 SP1 (2 nodes) which the server (let's call) ‘XYZ02’ was evicted and now it needs to be added again but it's working.

During the Add node Wizard validate and after showing the Report message: 
Node:  xyz02.sa.com.br
Started 8/10/2011 4:48:54 PM
Completed 8/10/2011 4:55:16 PM

Adding xyz02.sa.com.br to the cluster.
Validating cluster state on node xyz02.
Getting current node membership of cluster bldv01
Adding node afgbrosabld03 to Cluster configuration data.
Validating installation of the Network FT Driver on node xyz02.
Validating installation of the Cluster Disk Driver on node xyz02.
Configuring Cluster Service on node xyz02.
Waiting for notification that Cluster service on node xyz02.sa.com.br has started.
Waiting for notification that node afgbrosabld03 is a fully functional member of the cluster.
Unable to successfully cleanup.
The server xyz02.sa.com.br' could not be added to the cluster.
An error occurred while adding node xyz02.sa.com.br' to cluster 'bldv01'.
This operation returned because the timeout period expired



Let's check the Cluster environment:

NAME: xyz02
Operating System. . . . : Windows Server 2008 Datacenter R2 SP1
Roles. . . . . . . . . . . . . : Hyper-V, Failover Cluster
Anti-virus . . . . . . . . . . : SEP 11.0.6005
Virtualized. . . . . . . . . : NO

NAME: xyz01
Operating System. . . . : Windows Server 2008 Datacenter R2 SP1
Roles. . . . . . . . . . . . . : Hyper-V, Failover Cluster
Anti-virus . . . . . . . . . . : SEP 11.0.6005
Virtualized. . . . . . . . . : NO

Cluster Name: BLDV01
After received the message above if you try again run the validation wizard to add the node again the following message will be displayed:  ‘The computer " xyz02" is joined to the Cluster’
Solution

    · First Action. Run the Validation with all option and both nodes to check the nodes are 100% OK. If you find any error/warning keep in mind to try fix it before continuous the troubleshooting.
    · Checked the Event Viewer and found:
    Log Name:      System
    Source:        Microsoft-Windows-FailoverClustering
    Date:          8/10/2011 5:02:59 PM
    Event ID:      1090
    Task Category: Startup/Shutdown
    Level:         Critical
    User:          SYSTEM
    Computer:      xyz02.sa.com.br
    Description: The Cluster service cannot be started. An attempt to read configuration data from the Windows registry failed with error '2'. Please use the Failover Cluster Management snap-in to ensure that this machine is a member of a cluster. If you intend to add this machine to an existing cluster use the Add Node Wizard. Alternatively, if this machine has been configured as a member of a cluster, it will be necessary to restore the missing configuration data that is necessary for the Cluster Service to identify that it is a member of a cluster. Perform a System State Restore of this machine in order to restore the configuration data.
    

    · To fix the Critical error logged on Event Viewer and be sure the node will execute the validation add node wizard it's needed execute the Force Evict through command line :
    
    Cluster <ClusterName> node <NodeName> /force
    
    Use the article "How to Evict a Node from a Windows Server 2008 Failover Cluster" - http://technet.microsoft.com/en-us/library/bb676524%28EXCHG.80%29.aspx
    
    
    · The following action was taken
        ○ TCP/IP Parameters set as Enabled (RSS, TCPA, Chimney)
        ○ Windows Firewall was disabled on both servers.
        ○ IPv6 was disabled for all NIC on all servers.
        ○ Removed the AV SEP from server node (xyz02).
    
    · Customer informed this case he couldn't remove the AV SEP from node XYZ01.
    
    · Checking the Cluster.log from XYZ02
 
b20:578.08/11[14:42:14.967](000000) INFO  [CS] Cluster Service started
b20:578.08/11[14:42:15.888](000000) INFO  [API] RpcServerRegister => 0
b20:578.08/11[14:42:15.903](000000) ERR   [API] DmQueryString failed to retrieve the security   descriptor status 2, default security descriptor will be used for authorizing client connections
b20:578.08/11[14:42:15.935](000000) INFO  [CS] Reporting to SCM that cluster service has started.
b20:9f0.08/11[14:42:18.228](000000) DBG   [NETFTAPI] received NsiParameterNotification  for fe80::2445:9c2a:cf4e:46fd (IpDadStatePreferred )
b20:504.08/11[14:42:20.225](000000) WARN  [NETFTAPI] Failed to query parameters for 169.254.70.253 (status 80070490)
b20:504.08/11[14:42:20.225](000000) WARN  [NETFTAPI] Failed to query parameters for 169.254.70.253 (status 80070490)
b20:504.08/11[14:42:20.225](000000) DBG   [NETFTAPI] received NsiParameterNotification  for 169.254.2.243 (IpDadStatePreferred )
b20:504.08/11[14:42:20.942](000000) INFO  [CHANNEL 10.72.0.157:~3343~] graceful close, status (of previous failure, may not indicate problem) ERROR_SUCCESS(0)
b20:504.08/11[14:42:20.974](000000) WARN  cxl::ConnectWorker::operator (): GracefulClose(1226)' because of 'channel to remote endpoint 10.72.0.157:~3343~ is closed'
b20:b50.08/11[14:43:17.931](000000) DBG   [NETFTAPI] received NsiParameterNotification  for 169.254.2.243 (IpDadStatePreferred )
b20:be0.08/11[14:43:19.225](000000) DBG   [NETFTAPI] received NsiParameterNotification  for fe80::2445:9c2a:cf4e:46fd (IpDadStatePreferred )
b20:be0.08/11[14:43:21.222](000000) DBG   [NETFTAPI] received NsiParameterNotification  for 169.254.2.243 (IpDadStatePreferred )
b20:be0.08/11[14:43:21.924](000000) INFO  [CHANNEL 10.72.0.156:~3343~] graceful close, status (of previous failure, may not indicate problem) ERROR_SUCCESS(0)
b20:be0.08/11[14:43:21.924](000000) WARN  cxl::ConnectWorker::operator (): GracefulClose(1226)' because of 'channel to remote endpoint 10.72.0.156:~3343~ is closed'
b20:b50.08/11[14:44:18.926](000000) WARN  cxl::ConnectWorker::operator (): HrError(0xd0000043)' because of '::NetftAddRoute( handle.handle, netFtRoute.get(), &netftSecurityContext )'
b20:9f0.08/11[14:44:18.958](000000) WARN  [NETFTAPI] Failed to query parameters for fe80::5efe:169.254.2.243 (status 80070490)
b20:9f0.08/11[14:44:18.958](000000) WARN  [NETFTAPI] Failed to query parameters for fe80::5efe:169.254.2.243 (status 80070490)
b20:be0.08/11[14:44:24.230](000000) DBG   [NETFTAPI] received NsiParameterNotification  for fe80::2445:9c2a:cf4e:46fd (IpDadStatePreferred )
b20:9f0.08/11[14:44:26.227](000000) DBG   [NETFTAPI] received NsiParameterNotification  for 169.254.2.243 (IpDadStatePreferred )
b20:9f0.08/11[14:45:19.939](000000) DBG   [NETFTAPI] received NsiParameterNotification  for 169.254.2.243 (IpDadStatePreferred )
b20:be0.08/11[14:45:21.234](000000) DBG   [NETFTAPI] received NsiParameterNotification  for fe80::2445:9c2a:cf4e:46fd (IpDadStatePreferred )
b20:884.08/11[14:45:22.934](000000) INFO  [CHANNEL 10.72.0.156:~3343~] graceful close, status (of previous failure, may not indicate problem) ERROR_SUCCESS(0)
b20:884.08/11[14:45:22.934](000000) WARN  cxl::ConnectWorker::operator (): GracefulClose(1226)' because of 'channel to remote endpoint 10.72.0.156:~3343~ is closed'
b20:884.08/11[14:45:23.231](000000) DBG   [NETFTAPI] received NsiParameterNotification  for 169.254.2.243 (IpDadStatePreferred )
b20:be0.08/11[14:46:20.951](000000) WARN  cxl::ConnectWorker::operator (): HrError(0xd0000043)' because of '::NetftAddRoute( handle.handle, netFtRoute.get(), &netftSecurityContext )'
b20:884.08/11[14:46:20.967](000000) WARN  [NETFTAPI] Failed to query parameters for fe80::5efe:169.254.2.243 (status 80070490)
b20:884.08/11[14:46:20.967](000000) WARN  [NETFTAPI] Failed to query parameters for fe80::5efe:169.254.2.243 (status 80070490)
b20:0e8.08/11[14:46:26.224](000000) DBG   [NETFTAPI] received NsiParameterNotification  for fe80::2445:9c2a:cf4e:46fd (IpDadStatePreferred )
b20:0e8.08/11[14:46:28.236](000000) DBG   [NETFTAPI] received NsiParameterNotification  for 169.254.2.243 (IpDadStatePreferred )
b20:be0.08/11[14:47:21.932](000000) WARN  cxl::ConnectWorker::operator (): HrError(0xd0000043)' because of '::NetftAddRoute( handle.handle, netFtRoute.get(), &netftSecurityContext )'
b20:b9c.08/11[14:47:21.963](000000) WARN  [NETFTAPI] Failed to query parameters for fe80::5efe:169.254.2.243 (status 80070490)
b20:b9c.08/11[14:47:21.963](000000) WARN  [NETFTAPI] Failed to query parameters for fe80::5efe:169.254.2.243 (status 80070490)
b20:b9c.08/11[14:47:27.236](000000) DBG   [NETFTAPI] received NsiParameterNotification  for fe80::2445:9c2a:cf4e:46fd (IpDadStatePreferred )
b20:b9c.08/11[14:47:29.233](000000) DBG   [NETFTAPI] received NsiParameterNotification  for 169.254.2.243 (IpDadStatePreferred )
b20:0e8.08/11[14:48:22.928](000000) WARN  cxl::ConnectWorker::operator (): HrError(0xd0000043)' because of '::NetftAddRoute( handle.handle, netFtRoute.get(), &netftSecurityContext )'
b20:b9c.08/11[14:48:22.960](000000) WARN  [NETFTAPI] Failed to query parameters for fe80::5efe:169.254.2.243 (status 80070490)
b20:b9c.08/11[14:48:22.960](000000) WARN  [NETFTAPI] Failed to query parameters for fe80::5efe:169.254.2.243 (status 80070490)
b20:b9c.08/11[14:48:28.232](000000) DBG   [NETFTAPI] received NsiParameterNotification  for fe80::2445:9c2a:cf4e:46fd (IpDadStatePreferred )
b20:0e8.08/11[14:48:30.229](000000) DBG   [NETFTAPI] received NsiParameterNotification  for 169.254.2.243 (IpDadStatePreferred )
b20:b9c.08/11[14:48:30.900](000000) ERR   [QUORUM] Node 2: Fail to form/join a cluster in 6:15.000
b20:b9c.08/11[14:48:30.900](000000) ERR   join/form timeout (status = 258)
b20:b9c.08/11[14:48:30.900](000000) ERR   join/form timeout (status = 258), executing OnStop
b20:b9c.08/11[14:48:30.978](000000) ERR   FatalError is Calling Exit Process.


    · Checking the Cluster.log from XYZ01

304:350.08/10[16:49:02.864](000000) ERR   [IM] Unable to find adapter
dc4:178.08/10[16:49:02.864](000000) WARN  [RES] IP Address <Cluster IP Address>: WorkerThread: NetInterface c810ac97-6966-472f-b382-968ee1f06d0b changed to state 3.
304:438.08/10[16:49:06.811](000000) WARN  [FTI][Initiator] Ignoring duplicate connection: usable route already exists
304:438.08/10[16:49:06.811](000000) INFO  [CHANNEL 10.72.0.159:~64177~] graceful close, status (of previous failure, may not indicate problem) ERROR_SUCCESS(0)
304:438.08/10[16:49:06.811](000000) WARN  mscs::ListenerWorker::operator (): GracefulClose(1226)' because of 'channel to remote endpoint 10.72.0.159:~64177~ is closed'
304:ab8.08/10[16:50:02.816](000000) INFO  [CHANNEL 10.72.0.159:~64278~] graceful close, status (of previous failure, may not indicate problem) ERROR_SUCCESS(0)
304:ab8.08/10[16:50:02.816](000000) WARN  mscs::ListenerWorker::operator (): GracefulClose(1226)' because of 'channel to remote endpoint 10.72.0.159:~64278~ is closed'
304:350.08/10[16:50:06.809](000000) ERR   [IM] Unable to find adapter
dc4:178.08/10[16:50:06.809](000000) WARN  [RES] IP Address <Cluster IP Address>: WorkerThread: NetInterface c810ac97-6966-472f-b382-968ee1f06d0b changed to state 3.
304:350.08/10[16:51:02.814](000000) ERR   [IM] Unable to find adapter
dc4:178.08/10[16:51:02.814](000000) WARN  [RES] IP Address <Cluster IP Address>: WorkerThread: NetInterface c810ac97-6966-472f-b382-968ee1f06d0b changed to state 3.
304:ae8.08/10[16:51:06.808](000000) WARN  [FTI][Initiator] Ignoring duplicate connection: usable route already exists
304:ae8.08/10[16:51:06.808](000000) INFO  [CHANNEL 10.72.0.159:~64430~] graceful close, status (of previous failure, may not indicate problem) ERROR_SUCCESS(0)
304:ae8.08/10[16:51:06.808](000000) WARN  mscs::ListenerWorker::operator (): GracefulClose(1226)' because of 'channel to remote endpoint 10.72.0.159:~64430~ is closed'
dd8:498.08/10[16:51:58.460](000000) ERR   [RHS] RhsCall::Perform_NativeEH: ERROR_NOT_READY(21)' because of 'Startup routine for ResType MSMQ returned 21.'
dd8:498.08/10[16:51:58.491](000000) ERR   [RHS] RhsCall::Perform_NativeEH: ERROR_NOT_READY(21)' because of 'Startup routine for ResType MSMQTriggers returned 21.'
304:514.08/10[16:52:02.812](000000) INFO  [CHANNEL 10.72.0.159:~64465~] graceful close, status (of previous failure, may not indicate problem) ERROR_SUCCESS(0)
304:514.08/10[16:52:02.812](000000) WARN  mscs::ListenerWorker::operator (): GracefulClose(1226)' because of 'channel to remote endpoint 10.72.0.159:~64465~ is closed'
304:350.08/10[16:52:06.806](000000) ERR   [IM] Unable to find adapter
dc4:178.08/10[16:52:06.806](000000) WARN  [RES] IP Address <Cluster IP Address>: WorkerThread: NetInterface c810ac97-6966-472f-b382-968ee1f06d0b changed to state 3.
304:02c.08/10[16:53:02.811](000000) INFO  [CHANNEL 10.72.0.159:~64587~] graceful close, status (of previous failure, may not indicate problem) ERROR_SUCCESS(0)
304:02c.08/10[16:53:02.811](000000) WARN  mscs::ListenerWorker::operator (): GracefulClose(1226)' because of 'channel to remote endpoint 10.72.0.159:~64587~ is closed'
304:02c.08/10[16:54:02.809](000000) INFO  [CHANNEL 10.72.0.159:~64662~] graceful close, status (of previous failure, may not indicate problem) ERROR_SUCCESS(0)
304:02c.08/10[16:54:02.809](000000) WARN  mscs::ListenerWorker::operator (): GracefulClose(1226)' because of 'channel to remote endpoint 10.72.0.159:~64662~ is closed'
304:b88.08/10[16:55:02.807](000000) INFO  [CHANNEL 10.72.0.159:~64762~] graceful close, status (of previous failure, may not indicate problem) ERROR_SUCCESS(0)
304:b88.08/10[16:55:02.807](000000) WARN  mscs::ListenerWorker::operator (): GracefulClose(1226)' because of 'channel to remote endpoint 10.72.0.159:~64762~ is closed'

    · Based on logs we found the XYZ01 couldn't receive any data from node XYZ02 (Remote EndPoint Error point to Server XYZ02 IP address).
    · As solution we asked to customer remove the SEP from server XYZ01 and then try again.
    · Removed the AV SEP and made a evict cleanup (described above).
    · After that we finally could add the server to Cluster successfully.

Conclusion: The main issue was related to SEP AV blocked the communication between nodes (TCP/UDP 3343).


Related Articles
===============================
Windows Server 2008 Failover Clusters: Networking (Part 1)
http://blogs.technet.com/b/askcore/archive/2010/02/12/windows-server-2008-failover-clusters-networking-part-1.aspx
"How to Evict a Node from a Windows Server 2008 Failover Cluster" - http://technet.microsoft.com/en-us/library/bb676524%28EXCHG.80%29.aspx

Nov 2, 2010

Cluster Member Win2K3 Cannot Join on the Cluster Admin

SYMPTOM:
=========
Node "XYZ01" cannot finish the Join on Windows Server 2003 Cluster Environment.
When try starts the Cluster Service on Cluadmin the message error "Could not start cluster service on XYZ01 ERROR 1067: The process terminated unexpectedly".



Environment:
=========
Two node Failover Cluster
Node OS Version --- Build 3790 Windows Enterprise Server 2003
Node Service Pack - Service Pack 2
The Quorum Drive -- Q:\MSCS\
The Quorum Reset Value is -- 4096 KB

Cluster Networks
PRIVATIVA-01 Private Only 255.255.255.0
Local Area Connection(2) All Comm 255.255.224.0

Cluster Networks Priority
PRIVATIVA-01
Local Area Connection(2)

Solution:
==========
For this issue the solution was related to Hotfixes KB968389 and KB975467.

http://support.microsoft.com/kb/975467:
" If you install update 968389 before you apply this security update, you are offered this update to address the vulnerability on your computer. If you install update 968389 after you apply this security update, you will be offered only update 968389 for installation. However, this security update does contain the update to address this security vulnerability. Upon successful installation, both "Extended Protection for Authentication (KB968389)" and this security update are listed as installed software."

To solve the issue you should use the http://support.microsoft.com/kb/968389 and choose the "LET ME FIX".

An simple example about how the hotfixes should be installed

XYZ01 ------------
10/21/2010 9:38:16 AM Information XYZ01 4377 NtServicePack CORP\xyzuser Windows Server 2003 Hotfix KB968389 was installed.
2/6/2010 Windows Server 2003 Hotfix KB975467 was installed.
8/17/2009 Update for Windows Server 2003 x64 Edition (KB968389).


KB
========================
http://support.microsoft.com/kb/975467
http://support.microsoft.com/kb/968389


Explanation about the Case/Scenario:
====================================
Although this solution looks like really simple, this scenario and complexity was too hard to find this solution.
I really recommend if you saw something similar to try the "Best Practices" for Cluster Windows 2003 at the first action.