Click here to monitor SSC
SQLServerCentral is supported by Red Gate Software Ltd.
 
Log in  ::  Register  ::  Not logged in
 
 
 
        
Home       Members    Calendar    Who's On


Add to briefcase ««12

Cluster Installation Time Out Issue Expand / Collapse
Author
Message
Posted Tuesday, February 12, 2013 3:18 AM


SSC-Enthusiastic

SSC-EnthusiasticSSC-EnthusiasticSSC-EnthusiasticSSC-EnthusiasticSSC-EnthusiasticSSC-EnthusiasticSSC-EnthusiasticSSC-Enthusiastic

Group: General Forum Members
Last Login: Today @ 6:28 AM
Points: 133, Visits: 431
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
Post #1418833
Posted Tuesday, February 12, 2013 3:20 AM


SSC-Enthusiastic

SSC-EnthusiasticSSC-EnthusiasticSSC-EnthusiasticSSC-EnthusiasticSSC-EnthusiasticSSC-EnthusiasticSSC-EnthusiasticSSC-Enthusiastic

Group: General Forum Members
Last Login: Today @ 6:28 AM
Points: 133, Visits: 431
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 [EM] 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
Post #1418836
Posted Tuesday, February 12, 2013 3:38 AM


SSC-Enthusiastic

SSC-EnthusiasticSSC-EnthusiasticSSC-EnthusiasticSSC-EnthusiasticSSC-EnthusiasticSSC-EnthusiasticSSC-EnthusiasticSSC-Enthusiastic

Group: General Forum Members
Last Login: Today @ 6:28 AM
Points: 133, Visits: 431
Perry Whittle (2/11/2013)
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?


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
Post #1418843
Posted Tuesday, February 12, 2013 4:37 AM


SSCertifiable

SSCertifiableSSCertifiableSSCertifiableSSCertifiableSSCertifiableSSCertifiableSSCertifiableSSCertifiableSSCertifiable

Group: General Forum Members
Last Login: Today @ 10:43 AM
Points: 6,641, Visits: 14,226
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"
Post #1418873
Posted Tuesday, February 12, 2013 5:19 PM


SSC-Enthusiastic

SSC-EnthusiasticSSC-EnthusiasticSSC-EnthusiasticSSC-EnthusiasticSSC-EnthusiasticSSC-EnthusiasticSSC-EnthusiasticSSC-Enthusiastic

Group: General Forum Members
Last Login: Today @ 6:28 AM
Points: 133, Visits: 431
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
Post #1419244
Posted Monday, February 18, 2013 3:47 AM
SSCrazy

SSCrazySSCrazySSCrazySSCrazySSCrazySSCrazySSCrazySSCrazy

Group: General Forum Members
Last Login: Friday, November 14, 2014 8:26 AM
Points: 2,894, Visits: 3,278
If people on the Internet are not able to help within the timescale you want, then the best thing is to open a Support Case with Microsoft. SQL people know a bit about setting up clustering at an OS level, but Microsoft has experts in this area.

Original author: SQL Server FineBuild 1-click install and best practice configuration of SQL Server 2014, 2012, 2008 R2, 2008 and 2005. 18 October 2014: now over 31,000 downloads.
Disclaimer: All information provided is a personal opinion that may not match reality.
Concept: "Pizza Apartheid" - the discrimination that separates those who earn enough in one day to buy a pizza if they want one, from those who can not.
Post #1421129
Posted Monday, February 18, 2013 9:25 AM


SSCertifiable

SSCertifiableSSCertifiableSSCertifiableSSCertifiableSSCertifiableSSCertifiableSSCertifiableSSCertifiableSSCertifiable

Group: General Forum Members
Last Login: Today @ 10:43 AM
Points: 6,641, Visits: 14,226
EdVassie (2/18/2013)
the best thing is to open a Support Case with Microsoft.

or hire a consultant to troubleshoot the system for you, which would likely be a lot cheaper than calling Microsoft


-----------------------------------------------------------------------------------------------------------

"Ya can't make an omelette without breaking just a few eggs"
Post #1421265
Posted Wednesday, February 20, 2013 2:15 AM


SSC-Enthusiastic

SSC-EnthusiasticSSC-EnthusiasticSSC-EnthusiasticSSC-EnthusiasticSSC-EnthusiasticSSC-EnthusiasticSSC-EnthusiasticSSC-Enthusiastic

Group: General Forum Members
Last Login: Today @ 6:28 AM
Points: 133, Visits: 431
Perry Whittle (2/18/2013)
EdVassie (2/18/2013)
the best thing is to open a Support Case with Microsoft.

or hire a consultant to troubleshoot the system for you, which would likely be a lot cheaper than calling Microsoft


I solved it on my own. It's even cheaper! YEAH!

This error perplexed me :

[NODE] Node 2: New join with n1: stage: 'Authenticate Initial Connection'
00000f7c.000009ac::2013/02/18-12:06:33.886 ERR 000007fe:fe0f9e5d( ERROR_MOD_NOT_FOUND(126) )
00000f7c.000009ac::2013/02/18-12:06:33.886 ERR 00000000:01ebf050( ERROR_MOD_NOT_FOUND(126) )
00000f7c.000009ac::2013/02/18-12:06:33.886 ERR 00000000:003e0350( ERROR_MOD_NOT_FOUND(126) )
00000f7c.000009ac::2013/02/18-12:06:33.886 ERR 00000000:ff53c050( ERROR_MOD_NOT_FOUND(126) )
00000f7c.000009ac::2013/02/18-12:06:33.886 INFO [NODE] Node 2: New join with n1: stage: 'Authorize Initial Connection' status HrError(0x8009030c) reason: '[SV] Authorization failed'

The Problem was that the RSA-Machinekey 4f692a7dc1b824e1f679f93fadd08a3b_6adaa04c-870a-4415-a11a-3cadf31e62e0 was unaccessible, allthough the Domain-User-Account running the Cluster Service was even owner. I added rights for the local admin (just for fun) and it worked! At this point I'll give up the search for a logical explanation, just stating, that you should never trust a microsoft error message. 99% of the microsoft error messages you could overwrite with : permission problem :D!

Thank you very much for all your efforts and help!

PS: If you run into permission problems, get familiar with process monitor :P!


Greetz
Query Shepherd
Post #1421988
« Prev Topic | Next Topic »

Add to briefcase ««12

Permissions Expand / Collapse