February 11, 2013 at 2:56 am
Hi.
I want to create a failover cluster and always get the following error while creating the windows server cluster : Security Handshake failed to obtain SecurityContext for NetFT driver. I almost tried everything I found to this topic in the internet. Could anybody help me with this issue. It's very critical, because it's a productive environment.
Sorry...the title of the topic shall be changed to : Cluster Installation Time Out Issue
Greetz
Query Shepherd
February 11, 2013 at 5:09 am
Can you supply a little more detail about the environment and exactly what steps you are at when you get the failure?
-----------------------------------------------------------------------------------------------------------
"Ya can't make an omelette without breaking just a few eggs" 😉
February 11, 2013 at 5:27 am
The cluster generation fails at the OS Level. We've got 2 servers with Windows Server 2008 R2 Enterprise 64Bit. When I want to create the cluster in failover cluster manager, it comes until the point "forming cluster". Here it hangs an comes after 2 minutes up with a timeout. The prevalidation is 100% free of errors. If I take a look at the clusterlog, I see this "Security Handshake failed to obtain SecurityContext for NetFT driver". Node 2 forcibly closes the connection so the cluster creation fails.
Tell me whatever further details you need!
Greetz
Query Shepherd
February 11, 2013 at 5:43 am
have your server admins check that each node is well connected to the domain for starters.
Are these physical or virtual machines?
-----------------------------------------------------------------------------------------------------------
"Ya can't make an omelette without breaking just a few eggs" 😉
February 11, 2013 at 5:45 am
Yes, members of the domain and physical machines.
Greetz
Query Shepherd
February 11, 2013 at 5:53 am
Check network connectivity between the nodes and the domain.
Have you checked the windows event logs and also the cluster events for further info.
-----------------------------------------------------------------------------------------------------------
"Ya can't make an omelette without breaking just a few eggs" 😉
February 11, 2013 at 7:10 am
All checked an stucked by the problem I posted since 1 week 🙁
Greetz
Query Shepherd
February 11, 2013 at 7:27 am
which problem?
-----------------------------------------------------------------------------------------------------------
"Ya can't make an omelette without breaking just a few eggs" 😉
February 11, 2013 at 7:37 am
Security Handshake failed to obtain SecurityContext for NetFT driver
Greetz
Query Shepherd
February 11, 2013 at 8:25 am
SQL Pizza (2/11/2013)
Security Handshake failed to obtain SecurityContext for NetFT driver
You need to throw a dog a bone here my friend, what you've given is not very helpful. Can you provide details of the logs (obfuscate them first)?
How many NICs does each server have?
Have you checked the binding order?
-----------------------------------------------------------------------------------------------------------
"Ya can't make an omelette without breaking just a few eggs" 😉
February 12, 2013 at 3:18 am
Add Cluster Nodes-Report
Node: xyz.mydomain.local
Started 12.02.2013 10:43:39
Completed 12.02.2013 10:49:58
Adding xyz.mydomain.local to the cluster.
Validating cluster state on node xyz.
Getting current node membership of cluster xyzCluster.
Adding node xyz to Cluster configuration data.
Validating installation of the Network FT Driver on node xyz.
Validating installation of the Cluster Disk Driver on node xyz.
Configuring Cluster Service on node xyz.
Waiting for notification that Cluster service on node xyz.mydomain.local has started.
Waiting for notification that node xyz is a fully functional member of the cluster.
Unable to successfully cleanup.
The server 'xyz.mydomain.local' could not be added to the cluster.
An error occurred while adding node 'xyz.mydomain.local' to cluster 'xyzCluster'.
This operation returned because the timeout period exp
Greetz
Query Shepherd
February 12, 2013 at 3:20 am
cluster.log of the node to be added :
0000045c.00000fd8::2013/02/12-10:25:00.688 INFO -----------------------------+ LOG BEGIN +-----------------------------
0000045c.00000fd8::2013/02/12-10:25:00.688 INFO [CS] Starting clussvc as a service
0000045c.00000fd8::2013/02/12-10:25:00.688 INFO [CS] cluster service logging level is 5
0000045c.00000d78::2013/02/12-10:25:00.703 INFO [CS] Creating cluster node <vector len='1'>
0000045c.00000d78::2013/02/12-10:25:00.703 INFO <item>ClusSvc</item>
0000045c.00000d78::2013/02/12-10:25:00.703 INFO </vector>
0000045c.00000f70::2013/02/12-10:25:00.703 INFO [StartupConfig]: Initializing.
0000045c.00000f70::2013/02/12-10:25:00.703 INFO [StartupConfig]: Local node name: xyz6.
0000045c.00000f70::2013/02/12-10:25:00.703 INFO [StartupConfig]: Initializing NetFT adapter management information.
0000045c.00000f70::2013/02/12-10:25:00.703 INFO [NETFT] Initializing NetFT driver manager
0000045c.00000f70::2013/02/12-10:25:00.703 INFO [CORE] Initializing.
0000045c.00000f70::2013/02/12-10:25:00.703 INFO [GEM] Initializing.
0000045c.00000f70::2013/02/12-10:25:00.703 INFO [MM] Initializing.
0000045c.00000f70::2013/02/12-10:25:00.703 INFO [MRR] Node 2: Initializing.
0000045c.00000f70::2013/02/12-10:25:00.703 INFO [Causal] Node 2: Initializing.
0000045c.00000f70::2013/02/12-10:25:00.703 INFO Initializing.
0000045c.00000f70::2013/02/12-10:25:00.703 INFO [GUM] Node 2: Initializing.
0000045c.00000f70::2013/02/12-10:25:00.703 INFO [DM] Node 2: Initializing.
0000045c.00000f70::2013/02/12-10:25:01.031 INFO [CLFS] Initializing CLFS logger.
0000045c.00000f70::2013/02/12-10:25:01.031 DBG [CLFS] Largest written record has size 131072 bytes
0000045c.00000f70::2013/02/12-10:25:01.031 DBG [CLFS] Deleting old marshalling area.
0000045c.00000f70::2013/02/12-10:25:01.031 DBG [CLFS] Marshaling area resized
0000045c.00000f70::2013/02/12-10:25:01.031 INFO [TM] Initializing.
0000045c.00000f70::2013/02/12-10:25:01.031 INFO [JPM] Node 2: Initializing.
0000045c.00000f70::2013/02/12-10:25:01.031 INFO [VER]: Initializing.
0000045c.00000f70::2013/02/12-10:25:01.031 INFO [CCM] Initializing.
0000045c.00000f70::2013/02/12-10:25:01.031 INFO [FTI] Initializing.
0000045c.00000f70::2013/02/12-10:25:01.031 INFO [ReM] Initializing.
0000045c.00000f70::2013/02/12-10:25:01.031 INFO [HM]: Initializing.
0000045c.00000f70::2013/02/12-10:25:01.031 INFO [NETFT] Starting NetFT eventing for FTI
0000045c.00000f70::2013/02/12-10:25:01.031 DBG [NETFTAPI] received NsiInitialNotification
0000045c.00000f70::2013/02/12-10:25:01.031 DBG [NETFTAPI] received NsiInitialNotification
0000045c.00000f70::2013/02/12-10:25:01.031 INFO [NETFT] FTI NetFT event handler ready for events.
0000045c.00000f70::2013/02/12-10:25:01.031 INFO [IM] Initializing.
0000045c.00000f70::2013/02/12-10:25:01.031 INFO [NM] Initializing.
0000045c.00000f70::2013/02/12-10:25:01.031 INFO [NSM] Initializing.
0000045c.00000f70::2013/02/12-10:25:01.031 INFO [CM] Initializing.
0000045c.00000f70::2013/02/12-10:25:01.031 INFO [RCM] Initializing.
0000045c.00000f70::2013/02/12-10:25:01.031 INFO [QUORUM] Node 2: Initializing.
0000045c.00000f70::2013/02/12-10:25:01.031 INFO [STARTUP] Node 2: startup config
0000045c.00000f70::2013/02/12-10:25:01.031 INFO <StartupConfig localNodeId='2' testMode='false' newCluster='true'
0000045c.00000f70::2013/02/12-10:25:01.031 INFO <ClusterName> xyzCluster </ClusterName>
0000045c.00000f70::2013/02/12-10:25:01.031 INFO <PaxosTag> 0:0:0 </PaxosTag>
0000045c.00000f70::2013/02/12-10:25:01.031 INFO <ConfiguredNodes> (1 2) </ConfiguredNodes>
0000045c.00000f70::2013/02/12-10:25:01.031 INFO <NodeWeights> (1 2) </NodeWeights>
0000045c.00000f70::2013/02/12-10:25:01.031 INFO <Nodes>
0000045c.00000f70::2013/02/12-10:25:01.031 INFO <Node name='xyz5' id='1'/>
0000045c.00000f70::2013/02/12-10:25:01.031 INFO <Node name='xyz6' id='2'/>
0000045c.00000f70::2013/02/12-10:25:01.031 INFO </Nodes>
0000045c.00000f70::2013/02/12-10:25:01.031 INFO <LocalHiveFile> C:\Windows\Cluster\CLUSDB </LocalHiveFile>
0000045c.00000f70::2013/02/12-10:25:01.031 INFO <LocalHiveKey> Cluster </LocalHiveKey>
0000045c.00000f70::2013/02/12-10:25:01.031 INFO <ParametersKey> System\\CurrentControlSet\\Services\ClusSvc\Parameters </ParametersKey>
0000045c.00000f70::2013/02/12-10:25:01.031 INFO <Virtual IPv6> fe80::d56b:acaf:63e7:ac5%16:~3343~ </Virtual IPv6>
0000045c.00000f70::2013/02/12-10:25:01.031 INFO <Virtual IPv4> 169.254.22.211:~3343~ </Virtual IPv4>
0000045c.00000f70::2013/02/12-10:25:01.031 INFO <NoVersionCheck> false </NoVersionCheck>
0000045c.00000f70::2013/02/12-10:25:01.031 INFO <Cookie> 41e012b4-cd84-4218-a8e2-19415ea5ac42 </Cookie>
0000045c.00000f70::2013/02/12-10:25:01.031 INFO <ClusterGuid> 831d3f40-054d-4866-9785-5cf5a9ba51dc </ClusterGuid>
0000045c.00000f70::2013/02/12-10:25:01.031 INFO <RetainNetFTConnSecurity> false </RetainNetFTConnSecurity>
0000045c.00000f70::2013/02/12-10:25:01.031 INFO </StartupConfig>
0000045c.00000d78::2013/02/12-10:25:01.031 INFO [CS] Node object creation completed.
0000045c.00000d78::2013/02/12-10:25:01.031 INFO [CS] Starting cluster node
0000045c.00000d78::2013/02/12-10:25:01.031 INFO [CS] Cluster Service started
0000045c.00000d78::2013/02/12-10:25:01.031 INFO [CS] The current time is 2013/02/12-11:25:01.031
0000045c.00000d78::2013/02/12-10:25:01.031 INFO [CS] Using virtual IPv6 Address fe80::d56b:acaf:63e7:ac5%16:~3343~
0000045c.00000d78::2013/02/12-10:25:01.031 INFO [CS] Using virtual IPv4 Address 169.254.22.211:~3343~
0000045c.00000d78::2013/02/12-10:25:01.031 INFO [CS] Max Licensed nodes is set 16
0000045c.00000d78::2013/02/12-10:25:01.031 INFO [NETFT] Disabling IP autoconfiguration on the NetFT adapter.
0000045c.00000d78::2013/02/12-10:25:01.031 INFO [NETFT] Disabling DHCP on the NetFT adapter.
0000045c.00000d78::2013/02/12-10:25:01.031 DBG [NETFT] Disabling DHCP on NetFT interface name ethernet_12.
0000045c.00000d78::2013/02/12-10:25:01.031 INFO [CS] Starting DM
0000045c.00000d78::2013/02/12-10:25:01.031 INFO [DM] Node 2: Reading quorum config
0000045c.00000d78::2013/02/12-10:25:01.031 INFO [DM] Node 2: new cluster. generating new hive
0000045c.00000d78::2013/02/12-10:25:01.031 DBG [DM] Unloading Hive, Key \Registry\Machine\Cluster, discardCurrentChanges true
0000045c.0000050c::2013/02/12-10:25:01.031 INFO [CS] Disabling connection security.
0000045c.00000d78::2013/02/12-10:25:01.031 INFO [DM] Key \Registry\Machine\Cluster does not appear to be loaded (status STATUS_OBJECT_NAME_NOT_FOUND(c0000034))
0000045c.00000d78::2013/02/12-10:25:01.031 DBG [DM] Unloading Hive, Key \Registry\Machine\Cluster, discardCurrentChanges true
0000045c.00000d78::2013/02/12-10:25:01.031 INFO [DM] Key \Registry\Machine\Cluster does not appear to be loaded (status STATUS_OBJECT_NAME_NOT_FOUND(c0000034))
0000045c.00000d78::2013/02/12-10:25:01.031 DBG [DM] Creating Hive, Key Cluster, FilePath C:\Windows\Cluster\CLUSDB
0000045c.00000938::2013/02/12-10:25:01.031 DBG [NETFTAPI] received NsiAddInstance for 169.254.22.211
0000045c.0000050c::2013/02/12-10:25:01.047 INFO [NETFT] Adding connection security permit filters for the NetFT adapter.
0000045c.0000050c::2013/02/12-10:25:01.047 INFO [NETFT] Adding FWPM filter Failover Cluster Permit Inbound Transport IPv4
0000045c.0000050c::2013/02/12-10:25:01.047 INFO [NETFT] Adding FWPM filter Failover Cluster Permit Inbound Transport IPv6
0000045c.0000050c::2013/02/12-10:25:01.047 INFO [NETFT] Adding FWPM filter Failover Cluster Permit Outbound Transport IPv4
0000045c.0000050c::2013/02/12-10:25:01.047 INFO [NETFT] Adding FWPM filter Failover Cluster Permit Outbound Transport IPv6
0000045c.0000050c::2013/02/12-10:25:01.047 INFO [NETFT] Adding FWPM filter Failover Cluster Permit ALE Accept IPv4 Universal
0000045c.0000050c::2013/02/12-10:25:01.047 INFO [NETFT] Adding FWPM filter Failover Cluster Permit ALE Accept IPv6 Universal
0000045c.0000050c::2013/02/12-10:25:01.047 INFO [NETFT] Adding FWPM filter Failover Cluster Permit ALE Accept IPv4 LIPS
0000045c.0000050c::2013/02/12-10:25:01.047 INFO [NETFT] Adding FWPM filter Failover Cluster Permit ALE Accept IPv6 LIPS
0000045c.0000050c::2013/02/12-10:25:01.047 DBG [CS] Done with connection security
0000045c.00000d78::2013/02/12-10:25:01.312 DBG [DM] Saving temp Hive
0000045c.00000d78::2013/02/12-10:25:01.343 DBG [DM] Unloading temp Hive
0000045c.00000d78::2013/02/12-10:25:01.359 DBG [DM] Deleting temp Hive
0000045c.00000d78::2013/02/12-10:25:01.359 INFO [DM] Loading Hive, Key Cluster, FilePath C:\Windows\Cluster\CLUSDB
0000045c.00000d78::2013/02/12-10:25:01.686 INFO [DM] Paxos Tag Read from Hive: 0:0:0
0000045c.00000d78::2013/02/12-10:25:01.733 DBG [DM] Beginning transaction
0000045c.00000d78::2013/02/12-10:25:01.733 INFO [QUORUM] unique node id for new node 1 is 00000000-0000-0000-0000-000000000001
0000045c.00000d78::2013/02/12-10:25:01.733 INFO [QUORUM] unique node id for new node 2 is 00000000-0000-0000-0000-000000000002
0000045c.00000d78::2013/02/12-10:25:01.733 DBG [CLFS] Deleting old marshalling area.
0000045c.00000d78::2013/02/12-10:25:01.733 DBG [CLFS] Marshaling area resized
0000045c.00000d78::2013/02/12-10:25:01.749 DBG [CLFS] Logger wrote 2830 bytes
0000045c.00000d78::2013/02/12-10:25:01.749 DBG [DM] Committed transaction 0:0:1
0000045c.00000d78::2013/02/12-10:25:01.749 INFO [DM] Populating StartupConfig data from local hive.
0000045c.00000d78::2013/02/12-10:25:01.749 INFO [DM] Node 2: startup configuration loaded:
0000045c.00000d78::2013/02/12-10:25:01.749 INFO <StartupConfig localNodeId='2' testMode='false' newCluster='true'
0000045c.00000d78::2013/02/12-10:25:01.749 INFO <ClusterName> xyzCluster </ClusterName>
0000045c.00000d78::2013/02/12-10:25:01.749 INFO <PaxosTag> 0:0:1 </PaxosTag>
0000045c.00000d78::2013/02/12-10:25:01.749 INFO <ConfiguredNodes> (1 2) </ConfiguredNodes>
0000045c.00000d78::2013/02/12-10:25:01.749 INFO <NodeWeights> (1 2) </NodeWeights>
0000045c.00000d78::2013/02/12-10:25:01.749 INFO <Nodes>
0000045c.00000d78::2013/02/12-10:25:01.749 INFO <Node name='xyz5' id='1'/>
0000045c.00000d78::2013/02/12-10:25:01.749 INFO <Node name='xyz6' id='2'/>
0000045c.00000d78::2013/02/12-10:25:01.749 INFO </Nodes>
0000045c.00000d78::2013/02/12-10:25:01.749 INFO <LocalHiveFile> C:\Windows\Cluster\CLUSDB </LocalHiveFile>
0000045c.00000d78::2013/02/12-10:25:01.749 INFO <LocalHiveKey> Cluster </LocalHiveKey>
0000045c.00000d78::2013/02/12-10:25:01.749 INFO <ParametersKey> System\\CurrentControlSet\\Services\ClusSvc\Parameters </ParametersKey>
0000045c.00000d78::2013/02/12-10:25:01.749 INFO <Virtual IPv6> fe80::d56b:acaf:63e7:ac5%16:~3343~ </Virtual IPv6>
0000045c.00000d78::2013/02/12-10:25:01.749 INFO <Virtual IPv4> 169.254.22.211:~3343~ </Virtual IPv4>
0000045c.00000d78::2013/02/12-10:25:01.749 INFO <NoVersionCheck> false </NoVersionCheck>
0000045c.00000d78::2013/02/12-10:25:01.749 INFO <Cookie> 41e012b4-cd84-4218-a8e2-19415ea5ac42 </Cookie>
0000045c.00000d78::2013/02/12-10:25:01.749 INFO <ClusterGuid> 831d3f40-054d-4866-9785-5cf5a9ba51dc </ClusterGuid>
0000045c.00000d78::2013/02/12-10:25:01.749 INFO <RetainNetFTConnSecurity> false </RetainNetFTConnSecurity>
0000045c.00000d78::2013/02/12-10:25:01.749 INFO </StartupConfig>
0000045c.00000d78::2013/02/12-10:25:01.749 INFO [CS] Starting MM
0000045c.00000d78::2013/02/12-10:25:01.749 INFO [MM] Starting.
0000045c.00000d78::2013/02/12-10:25:01.749 INFO [GEM] Node 2: Resume (newView = 002(2), previousView = 000())
0000045c.00000d78::2013/02/12-10:25:01.749 DBG [GEM] Node 2: SendNextMessage
0000045c.00000d78::2013/02/12-10:25:01.749 DBG [GEM] Node 2: No more messages in queue
0000045c.00000d78::2013/02/12-10:25:01.749 INFO [StartupConfig] Writing new StartupConfig entries to ObjectManager
0000045c.00000d78::2013/02/12-10:25:01.749 DBG [StartupConfig] Writing node xyz5 (id = 1) to ObjectManager
0000045c.00000d78::2013/02/12-10:25:01.749 INFO [QUORUM] unique node id for new node 1 is 00000000-0000-0000-0000-000000000001
0000045c.00000d78::2013/02/12-10:25:01.749 INFO [MQ-xyz5] Starting
0000045c.00000d78::2013/02/12-10:25:01.749 INFO [MQ-xyz5] Clearing 0 unsent and 0 unacknowledged messages.
0000045c.00000d78::2013/02/12-10:25:01.749 INFO <ObjectManager>
0000045c.00000d78::2013/02/12-10:25:01.749 INFO <ROOT id='.root' name='.root'>
0000045c.00000d78::2013/02/12-10:25:01.749 INFO <GEMA id='GemAgent' name='GemAgent2'/>
0000045c.00000d78::2013/02/12-10:25:01.749 INFO <MRRA id='MrrAgent2' name='MrrAgent2'/>
0000045c.00000d78::2013/02/12-10:25:01.749 INFO <CAUS id='CausalAgent' name='CausalAgent'/>
0000045c.00000d78::2013/02/12-10:25:01.749 INFO <EVTM id='EventManager' name='EventManager'/>
0000045c.00000d78::2013/02/12-10:25:01.749 INFO <GUMA id='GumAgent2' name='GumAgent2'/>
0000045c.00000d78::2013/02/12-10:25:01.749 INFO <JPMA id='JpmAgent' name='JpmAgent'/>
0000045c.00000d78::2013/02/12-10:25:01.749 INFO <IMSC id='[IM-2] ' name='[IM-2] '/>
0000045c.00000d78::2013/02/12-10:25:01.749 INFO <RPCS id='[RPC-2] ' name='[RPC-2] '/>
0000045c.00000d78::2013/02/12-10:25:01.749 INFO <RCMA id='RcmAgent' name='RcmAgent'/>
0000045c.00000d78::2013/02/12-10:25:01.749 INFO <QRMA id='QuorumAgent2' name='QuorumAgent2'/>
0000045c.00000d78::2013/02/12-10:25:01.749 INFO <DCMA id='DcmAgent' name='DcmAgent'/>
0000045c.00000d78::2013/02/12-10:25:01.749 INFO <VSSR id='Cluster VSS Writer' name='Cluster VSS Writer'/>
0000045c.00000d78::2013/02/12-10:25:01.749 INFO <CLUS id='xyzCluster' name='xyzCluster'/>
0000045c.00000d78::2013/02/12-10:25:01.749 INFO <DEAD id='.Dead' name='.Dead'>
0000045c.00000d78::2013/02/12-10:25:01.749 INFO <NODE id='1' name='xyz5'/>
0000045c.00000d78::2013/02/12-10:25:01.749 INFO </DEAD>
0000045c.00000d78::2013/02/12-10:25:01.749 INFO <LIVE id='.Live' name='.Live'/>
0000045c.00000d78::2013/02/12-10:25:01.749 INFO <JOIN id='.Joiners' name='.Joiners'/>
0000045c.00000d78::2013/02/12-10:25:01.749 INFO <MBRA id='MembershipAgent' name='MembershipAgent'/>
0000045c.00000d78::2013/02/12-10:25:01.749 INFO </ROOT>
0000045c.00000d78::2013/02/12-10:25:01.749 INFO </ObjectManager>
0000045c.00000d78::2013/02/12-10:25:01.749 INFO [MM] Node 2: got a network stream to 2. Creating new NodeObject
0000045c.00000d78::2013/02/12-10:25:01.749 INFO [QUORUM] unique node id for new node 2 is 00000000-0000-0000-0000-000000000002
0000045c.00000d78::2013/02/12-10:25:01.749 INFO [MQ-xyz6] Starting
0000045c.00000d78::2013/02/12-10:25:01.749 INFO [MQ-xyz6] Clearing 0 unsent and 0 unacknowledged messages.
0000045c.00000d78::2013/02/12-10:25:01.749 INFO [NODE] Node 2: n2 node object adding stream
0000045c.00000d78::2013/02/12-10:25:01.749 DBG [NODE] Node 2: n2 node object got a channel
0000045c.00000d78::2013/02/12-10:25:01.749 INFO [NODE] Node 2: Highest version with n2 = Major 0 Minor 0 Upgrade 0 ClusterVersion 0x00000000, lowest = Major 0 Minor 0 Upgrade 0 ClusterVersion 0x00000000
0000045c.00000d78::2013/02/12-10:25:01.749 INFO [NODE] Node 2: Done processing new stream to n2.
0000045c.00000d78::2013/02/12-10:25:01.749 INFO [CS] Starting QM
0000045c.00000d78::2013/02/12-10:25:01.749 DBG [NETFT] Halt Notification set
0000045c.00000d78::2013/02/12-10:25:01.749 INFO [CS] Starting TM
0000045c.00000d78::2013/02/12-10:25:01.749 INFO [NETFT] Starting NetFT eventing for TM
0000045c.00000d78::2013/02/12-10:25:01.749 INFO [NETFT] TM NetFT event handler ready for events.
0000045c.00000d78::2013/02/12-10:25:01.749 INFO [CS] Starting IM
0000045c.00000d78::2013/02/12-10:25:01.749 INFO [NETFT] Starting NetFT eventing for IM
0000045c.00000d78::2013/02/12-10:25:01.749 INFO [NETFT] IM NetFT event handler ready for events.
0000045c.00000d78::2013/02/12-10:25:01.749 INFO [CS] Starting NM
0000045c.00000d78::2013/02/12-10:25:01.749 INFO [CS] Starting api server
0000045c.00000d78::2013/02/12-10:25:01.749 INFO [API] Api Onlined
0000045c.000001d8::2013/02/12-10:25:01.749 INFO [PULLER xyz6] Just about to start reading from <LoopbackStream name='xyz6'/>
0000045c.00000d78::2013/02/12-10:25:01.749 INFO [API] UseProtseq ncalrpc => 0
0000045c.00000d78::2013/02/12-10:25:01.749 INFO [API] UseProtseq ncadg_ip_tcp => 0
0000045c.00000d78::2013/02/12-10:25:01.749 INFO [API] InqBindings => 0
0000045c.00000d78::2013/02/12-10:25:01.749 INFO [API] RpcEpRegister => 0
0000045c.00000d78::2013/02/12-10:25:01.749 INFO [API] RpcServerRegister => 0
0000045c.00000d78::2013/02/12-10:25:01.749 INFO [API] Initializing
0000045c.00000d78::2013/02/12-10:25:01.749 INFO [API] Adding Mgmt API SPNs to node's Computer Object
0000045c.00000d78::2013/02/12-10:25:01.764 INFO [API] Successfully added Mgmt API SPNs to node's Computer Object
0000045c.00000d78::2013/02/12-10:25:01.764 ERR [API] DmQueryString failed to retrieve the security descriptor status 2, default security descriptor will be used for authorizing client connections
0000045c.00000d78::2013/02/12-10:25:01.764 INFO [API] Successfully built the default cluster SD.
0000045c.00000d78::2013/02/12-10:25:01.764 INFO [CS] Bringing API Online
0000045c.00000d78::2013/02/12-10:25:01.764 INFO [CORE] Node 2: New View is <ViewChanged joiners=(2) downers=() newView=002(2) oldView=000() joiner=true form=true/> (Start Dispatch)
0000045c.00000d78::2013/02/12-10:25:01.764 INFO [MRR] Node 2: Process view 002(2)
0000045c.00000d78::2013/02/12-10:25:01.764 INFO [RCM] rcm::RcmAgent::ProcessView: Ignoring view change (won't attempt to move orphaned groups), since I'm not in RCM view yet.
0000045c.00000d78::2013/02/12-10:25:01.764 DBG [GEM] Node 2: message added to send queue
0000045c.00000d78::2013/02/12-10:25:01.764 DBG [GEM] Node 2: SendNextMessage
0000045c.00000d78::2013/02/12-10:25:01.764 DBG [GEM] Node 2: delivering message 2:1
0000045c.00000d78::2013/02/12-10:25:01.764 INFO [CORE] EmitReadyForState for node 2
0000045c.00000d78::2013/02/12-10:25:01.764 INFO [CORE] Issuing NeedStateViewChanged((2))
0000045c.00000d78::2013/02/12-10:25:01.764 DBG [GEM] Node 2: ProcessAck from node 2 (already acked ())
0000045c.00000d78::2013/02/12-10:25:01.764 DBG [GEM] Node 2: SendNextMessage
0000045c.00000d78::2013/02/12-10:25:01.764 DBG [GEM] Node 2: No more messages in queue
0000045c.00000d78::2013/02/12-10:25:01.764 DBG [NODE] Node 2: eating message sent to the dead node 1
0000045c.00000d78::2013/02/12-10:25:01.764 INFO [QUORUM] Node 2: I am the form/join coordinator (offline and lowest number node). Launching worker to request quorum config from other nodes
0000045c.00000d78::2013/02/12-10:25:01.764 DBG [MRR] Node 2: insert request record for RID 1
0000045c.00000d78::2013/02/12-10:25:01.764 DBG [MRR] SendRequest(<message action='qrm/request-info' GemId='0' target='QRMA' sender='-1'mrr='1'/>)
0000045c.00000d78::2013/02/12-10:25:01.764 DBG [CORE] Node 2: sending qrm/request-info to QRMA at xyz6
0000045c.00000d78::2013/02/12-10:25:01.764 INFO [CORE] Node 2: New View is <ViewChanged joiners=(2) downers=() newView=002(2) oldView=000() joiner=true form=true/> (Stop Dispatch)
0000045c.00000d78::2013/02/12-10:25:01.764 INFO [CS] Starting HM Server
0000045c.00000d78::2013/02/12-10:25:01.764 INFO [NODE] Node 2: New join with n1: stage: 'Listen for Connection'
0000045c.00000d78::2013/02/12-10:25:01.764 INFO [CS] Starting JPM (attempting connections to other cluster nodes)
0000045c.00000d78::2013/02/12-10:25:01.764 DBG [JPM] Node 2: Dead node mentioned xyz5
0000045c.00000d78::2013/02/12-10:25:01.764 DBG [JPM] Node 2: Dead node mentioned xyz6
0000045c.00000d78::2013/02/12-10:25:01.764 INFO [CS] Subscribing for VSS requests
0000045c.00000d78::2013/02/12-10:25:01.764 INFO [VSS] Initializing Cluster VSS Writer at the command of the VSS framework.
0000045c.00000a90::2013/02/12-10:25:01.764 DBG [NODE] Node 2: just about to send a message of size 109 to 2
0000045c.00000a90::2013/02/12-10:25:01.764 DBG [NODE] Node 2: message to node 2 sent
0000045c.000001d8::2013/02/12-10:25:01.764 INFO [QUORUM] Node 2: received request for quorum info. Replying with quorum state <QuorumConfig tag='0:0:1' set='(1 2)' weights='(1 2)'/>
0000045c.000001d8::2013/02/12-10:25:01.764 DBG [CORE] Node 2: sending mrr/reply to MRRA at xyz6
0000045c.00000a90::2013/02/12-10:25:01.764 DBG [NODE] Node 2: just about to send a message of size 0 to 2
0000045c.00000a90::2013/02/12-10:25:01.764 DBG [NODE] Node 2: message to node 2 sent
0000045c.00000a90::2013/02/12-10:25:01.764 DBG [NODE] Node 2: just about to send a message of size 278 to 2
0000045c.00000a90::2013/02/12-10:25:01.764 DBG [NODE] Node 2: message to node 2 sent
0000045c.000001d8::2013/02/12-10:25:01.764 DBG [MRR] Node 2: processing reply <message action='mrr/reply' GemId='0' target='MRRA' sender='2'mrr='1'/>
0000045c.000001d8::2013/02/12-10:25:01.764 DBG [MRR] Node 2: Request RID 1 is completed
0000045c.00000938::2013/02/12-10:25:01.764 INFO [QUORUM] Node 2: setting next best epoch to 0
0000045c.00000938::2013/02/12-10:25:01.764 DBG [QC] Calculating quorum: Configured nodes count = 2, Node weights count = 2, Quorum witness configured = false, Intersection count = 1
0000045c.00000938::2013/02/12-10:25:01.764 INFO [QUORUM] Node 2: Coordinator: no quorum yet. do nothing
0000045c.00000ef0::2013/02/12-10:25:01.764 DBG [JPM] Node 2: Building contact data for node xyz5.
0000045c.00000ef0::2013/02/12-10:25:01.764 INFO [JPM] Node 2: Scheduling DNS query for node name xyz5
0000045c.00000ef0::2013/02/12-10:25:01.764 DBG [JPM] Node 2: no valid contact endpoints yet for node xyz5.
0000045c.00000ef0::2013/02/12-10:25:01.780 INFO [JPM] Node 2: Found possible contact address 100.100.100.102:~0~ for node xyz5 via DNS.
0000045c.00000d78::2013/02/12-10:25:01.780 INFO [CS] Starting the Watchdog Monitor
0000045c.00000d78::2013/02/12-10:25:01.780 INFO [WM] Monitoring the kernel-mode watchdog.
0000045c.00000d78::2013/02/12-10:25:01.780 INFO [CS] Reporting to SCM that cluster service has started.
0000045c.00000c6c::2013/02/12-10:25:02.778 DBG [JPM] Node 2: contacts size for node xyz5 is 1, current index 0
0000045c.00000c6c::2013/02/12-10:25:02.778 DBG [JPM] Node 2: Trying to connect to node xyz5 (IP: 100.100.100.102:~0~)
0000045c.00000c6c::2013/02/12-10:25:02.778 DBG [HM] Trying to connect to xyz5 at 100.100.100.102:~3343~
0000045c.00000c6c::2013/02/12-10:25:02.778 INFO [CONNECT] 100.100.100.102:~3343~: Established connection to remote endpoint 100.100.100.102:~3343~.
0000045c.00000c6c::2013/02/12-10:25:02.778 INFO [NODE] Node 2: New join with n1: stage: 'Attempt Initial Connection'
0000045c.00000c6c::2013/02/12-10:25:02.778 INFO [SV] Securing route from (100.100.100.101:~50282~) to remote xyz5 (100.100.100.102:~3343~).
0000045c.00000c6c::2013/02/12-10:25:02.778 INFO [SV] Got a new outgoing stream to xyz5 at 100.100.100.102:~3343~
0000045c.00000c6c::2013/02/12-10:25:02.778 DBG [SM] Joiner: Initialized with SPN = xyz5, Package = Kerberos, RequiredCtxAttrib = 83990, HandShakeTimeout = 30000
0000045c.00000958::2013/02/12-10:25:02.778 DBG [SM] Handling auth handshake posted by thread id 3180
0000045c.00000958::2013/02/12-10:25:02.778 DBG [SM] Joiner: ISC returned status = 590610 output Blob size 1553
0000045c.00000958::2013/02/12-10:25:02.778 DBG [SM] Joiner: Received SSPI blob from the Sponsor of size 155
0000045c.00000958::2013/02/12-10:25:02.778 DBG [SM] Joiner: ISC returned status = 0 output Blob size 0
0000045c.00000c6c::2013/02/12-10:25:02.778 INFO [NODE] Node 2: New join with n1: stage: 'Authenticate Initial Connection'
0000045c.00000c6c::2013/02/12-10:25:02.809 ERR 000007fe:fdd69e5d( ERROR_MOD_NOT_FOUND(126) )
0000045c.00000c6c::2013/02/12-10:25:02.809 ERR 00000000:013deec0( ERROR_MOD_NOT_FOUND(126) )
0000045c.00000c6c::2013/02/12-10:25:02.809 ERR 00000000:0020c660( ERROR_MOD_NOT_FOUND(126) )
0000045c.00000c6c::2013/02/12-10:25:02.809 ERR 00000000:ff5fc050( ERROR_MOD_NOT_FOUND(126) )
0000045c.00000c6c::2013/02/12-10:25:02.809 INFO [NODE] Node 2: New join with n1: stage: 'Authorize Initial Connection' status HrError(0x8009030c) reason: '[SV] Authorization failed'
0000045c.00000c6c::2013/02/12-10:25:02.809 DBG [CHANNEL 100.100.100.102:~3343~] Close().
0000045c.00000c6c::2013/02/12-10:25:02.809 WARN cxl::ConnectWorker::operator (): HrError(0x8009030c)' because of '[SV] Authentication or Authorization Failed'
0000045c.00000d28::2013/02/12-10:26:03.774 DBG [JPM] Node 2: contacts size for node xyz5 is 1, current index 0
0000045c.00000d28::2013/02/12-10:26:03.774 DBG [JPM] Node 2: Trying to connect to node xyz5 (IP: 100.100.100.102:~0~)
0000045c.00000d28::2013/02/12-10:26:03.774 DBG [HM] Trying to connect to xyz5 at 100.100.100.102:~3343~
0000045c.00000d28::2013/02/12-10:26:03.774 INFO [CONNECT] 100.100.100.102:~3343~: Established connection to remote endpoint 100.100.100.102:~3343~.
0000045c.00000d28::2013/02/12-10:26:03.774 INFO [SV] Securing route from (100.100.100.101:~50292~) to remote xyz5 (100.100.100.102:~3343~).
0000045c.00000d28::2013/02/12-10:26:03.774 INFO [SV] Got a new outgoing stream to xyz5 at 100.100.100.102:~3343~
0000045c.00000d28::2013/02/12-10:26:03.774 DBG [SM] Joiner: Initialized with SPN = xyz5, Package = Kerberos, RequiredCtxAttrib = 83990, HandShakeTimeout = 30000
0000045c.00000958::2013/02/12-10:26:03.774 DBG [SM] Handling auth handshake posted by thread id 3368
0000045c.00000958::2013/02/12-10:26:03.774 DBG [SM] Joiner: ISC returned status = 590610 output Blob size 1553
0000045c.00000958::2013/02/12-10:26:03.774 DBG [SM] Joiner: Received SSPI blob from the Sponsor of size 155
0000045c.00000958::2013/02/12-10:26:03.774 DBG [SM] Joiner: ISC returned status = 0 output Blob size 0
0000045c.00000d28::2013/02/12-10:26:03.805 ERR 000007fe:fdd69e5d( ERROR_MOD_NOT_FOUND(126) )
0000045c.00000d28::2013/02/12-10:26:03.805 ERR 00000000:0192ee50( ERROR_MOD_NOT_FOUND(126) )
0000045c.00000d28::2013/02/12-10:26:03.805 ERR 00000000:001f5110( ERROR_MOD_NOT_FOUND(126) )
0000045c.00000d28::2013/02/12-10:26:03.805 ERR 00000000:ff5fc050( ERROR_MOD_NOT_FOUND(126) )
0000045c.00000d28::2013/02/12-10:26:03.805 INFO [NODE] Node 2: New join with n1: stage: 'Authorize Initial Connection' status HrError(0x8009030c) reason: '[SV] Authorization failed'
0000045c.00000d28::2013/02/12-10:26:03.805 DBG [CHANNEL 100.100.100.102:~3343~] Close().
0000045c.00000d28::2013/02/12-10:26:03.805 WARN cxl::ConnectWorker::operator (): HrError(0x8009030c)' because of '[SV] Authentication or Authorization Failed'
0000045c.00000d28::2013/02/12-10:27:04.770 DBG [JPM] Node 2: contacts size for node xyz5 is 1, current index 0
0000045c.00000d28::2013/02/12-10:27:04.770 DBG [JPM] Node 2: Trying to connect to node xyz5 (IP: 100.100.100.102:~0~)
0000045c.00000d28::2013/02/12-10:27:04.770 DBG [HM] Trying to connect to xyz5 at 100.100.100.102:~3343~
0000045c.00000d28::2013/02/12-10:27:04.770 INFO [CONNECT] 100.100.100.102:~3343~: Established connection to remote endpoint 100.100.100.102:~3343~.
0000045c.00000d28::2013/02/12-10:27:04.770 INFO [SV] Securing route from (100.100.100.101:~50298~) to remote xyz5 (100.100.100.102:~3343~).
0000045c.00000d28::2013/02/12-10:27:04.770 INFO [SV] Got a new outgoing stream to xyz5 at 100.100.100.102:~3343~
0000045c.00000d28::2013/02/12-10:27:04.770 DBG [SM] Joiner: Initialized with SPN = xyz5, Package = Kerberos, RequiredCtxAttrib = 83990, HandShakeTimeout = 30000
0000045c.00000958::2013/02/12-10:27:04.770 DBG [SM] Handling auth handshake posted by thread id 3368
0000045c.00000958::2013/02/12-10:27:04.770 DBG [SM] Joiner: ISC returned status = 590610 output Blob size 1553
0000045c.00000958::2013/02/12-10:27:04.770 DBG [SM] Joiner: Received SSPI blob from the Sponsor of size 154
0000045c.00000958::2013/02/12-10:27:04.770 DBG [SM] Joiner: ISC returned status = 0 output Blob size 0
0000045c.00000d28::2013/02/12-10:27:04.801 ERR 000007fe:fdd69e5d( ERROR_MOD_NOT_FOUND(126) )
0000045c.00000d28::2013/02/12-10:27:04.801 ERR 00000000:0192ee50( ERROR_MOD_NOT_FOUND(126) )
0000045c.00000d28::2013/02/12-10:27:04.801 ERR 00000000:001f5110( ERROR_MOD_NOT_FOUND(126) )
0000045c.00000d28::2013/02/12-10:27:04.801 ERR 00000000:ff5fc050( ERROR_MOD_NOT_FOUND(126) )
0000045c.00000d28::2013/02/12-10:27:04.801 INFO [NODE] Node 2: New join with n1: stage: 'Authorize Initial Connection' status HrError(0x8009030c) reason: '[SV] Authorization failed'
0000045c.00000d28::2013/02/12-10:27:04.801 DBG [CHANNEL 100.100.100.102:~3343~] Close().
0000045c.00000d28::2013/02/12-10:27:04.801 WARN cxl::ConnectWorker::operator (): HrError(0x8009030c)' because of '[SV] Authentication or Authorization Failed'
Greetz
Query Shepherd
February 12, 2013 at 3:38 am
Perry Whittle (2/11/2013)
SQL Pizza (2/11/2013)
Security Handshake failed to obtain SecurityContext for NetFT driverYou need to throw a dog a bone here my friend, what you've given is not very helpful. Can you provide details of the logs (obfuscate them first)?
How many NICs does each server have?
Have you checked the binding order?
Sorry for the tripple-post, but it's more open.
Each of the server has 2 NICs. The binding order is okay. Now I got rid of the error I stated before, but it seems I can't get the servers to authenticate right for the heartbeat?!?
Greetz
Query Shepherd
February 12, 2013 at 4:37 am
where did you check the bindings?
double check the TCPIP settings for each NIC and report back
-----------------------------------------------------------------------------------------------------------
"Ya can't make an omelette without breaking just a few eggs" 😉
February 12, 2013 at 5:19 pm
Changed the binding order of the networks...allthough validation did not fail about it, but nothing changed.
Got no duplicate entry as user in AD...none of the internet solutions work...can anyone help me how to dig deeper?
NOBODY ?!?
Greetz
Query Shepherd
Viewing 15 posts - 1 through 15 (of 17 total)
You must be logged in to reply to this topic. Login to reply