<div dir="ltr"><div class="gmail_extra"><div><div class="gmail_signature"><div>Hello,</div><div>just for the guys who doesn't want to read all the logs, I put my question on top (and at the end) of the post :</div><div><div>Is there a timer that I can raise to try to give more time to each nodes to see each other BEFORE TOTEM fire the "A processor failed, forming new configuration", because the 2 nodes are really up and running.</div><div><br></div><div>The 2 linux servers (vif5_7 and <a href="http://host2.example.com">host2.example.com</a>) are 2 VM on the same VMWare ESX server. May be the network is 'not working' the way corosync wants ?</div></div><div><br></div></div></div>
<br><div class="gmail_quote">2015-04-26 22:08 GMT+02:00 Andrew Beekhof <span dir="ltr"><<a href="mailto:andrew@beekhof.net" target="_blank">andrew@beekhof.net</a>></span>:<br><blockquote class="gmail_quote" style="margin:0px 0px 0px 0.8ex;border-left-width:1px;border-left-color:rgb(204,204,204);border-left-style:solid;padding-left:1ex"><span class=""><br>
> On 13 Apr 2015, at 7:08 pm, Philippe Carbonnier <<a href="mailto:Philippe.Carbonnier@vif.fr">Philippe.Carbonnier@vif.fr</a>> wrote:<br>
><br>
> Hello Mr Beekhof,<br>
><br>
> thanks for your answer. The error when trying to stop the service is just the result of the unsuccesfull start of the service: the start try to create a new IP alias which fail because the other node still ran it,<br>
<br>
</span>Is this IP also a managed resource? If so, it should have been removed when the service was asked to stop (and not reported ’success’ if it could not do so).<br>
<span class=""><br></span></blockquote><div>Yes this IP is managed (<span style="font-size:12.8000001907349px">clusterIP ocf:heartbeat:IPaddr2</span>).  </div><blockquote class="gmail_quote" style="margin:0px 0px 0px 0.8ex;border-left-width:1px;border-left-color:rgb(204,204,204);border-left-style:solid;padding-left:1ex"><span class="">
> so the stop can't be successfull because the IP alias is not up on this node.<br></span></blockquote><blockquote class="gmail_quote" style="margin:0px 0px 0px 0.8ex;border-left-width:1px;border-left-color:rgb(204,204,204);border-left-style:solid;padding-left:1ex"><span class=""><br>
</span>I think we’d better see your full config and agent, something sounds very wrong.<br></blockquote><div><br></div><div style="font-size:12.8000001907349px">I don't know what you mean with full config, does crm configuration is enough ?</div><div style="font-size:12.8000001907349px"><br></div><div style="font-size:12.8000001907349px">crm configuration:</div><div style="font-size:12.8000001907349px"><div>node <a href="http://host2.exemple.com/" target="_blank">host2.exemple.com</a> \</div><div>        attributes standby="off"</div><div>node vif5_7 \</div><div>        attributes standby="off"</div><div>primitive clusterIP ocf:heartbeat:IPaddr2 \</div><div>        params ip="10.10.72.3" cidr_netmask="32" iflabel="jbossfailover" \</div><div>        op monitor interval="30s"</div><div>primitive routing-jboss lsb:routing-jboss \</div><div>        op monitor interval="30s"</div><div>group vifGroup clusterIP routing-jboss</div><div>location prefer-clusterIP clusterIP 50: vif5_7</div><div>property $id="cib-bootstrap-options" \</div><div>        dc-version="1.0.11-1554a83db0d3c3e546cfd3aaff6af1184f79ee87" \</div><div>        cluster-infrastructure="openais" \</div><div>        expected-quorum-votes="2" \</div><div>        stonith-enabled="false" \</div><div>        no-quorum-policy="ignore"</div><div>rsc_defaults $id="rsc-options" \</div><div>        resource-stickiness="20"</div></div><div><br></div><div><span style="font-size:12.8000001907349px"> lsb:routing-jboss is a simple script running iptables :</span><br></div><div><span style="font-size:12.8000001907349px">When it start : </span></div><div><span style="font-size:12.8000001907349px">iptables -t nat -A OUTPUT -d $CLUSTERIP  -j DNAT --to-destination $JBOSSFAILOVER</span><br></div><div><span style="font-size:12.8000001907349px">or when it stop :</span></div><div><span style="font-size:12.8000001907349px">iptables -t nat -D OUTPUT -d $CLUSTERIP -j DNAT --to-destination $JBOSSFAILOVER</span><br></div><div><span style="font-size:12.8000001907349px"><br></span></div><div><span style="font-size:12.8000001907349px">When the situation is clean, ie both ressources are running on vif5_7 node, all is fine during 2 hours, and sometime the 2 nodes doesn't see each other :</span></div><div><span style="font-size:12.8000001907349px">The problem I try to understand is 'just' "</span><span style="font-size:12.8000001907349px">A processor failed, forming new configuration</span><span style="font-size:12.8000001907349px">"</span></div><div><span style="font-size:12.8000001907349px"><br></span></div><div><span style="font-size:12.8000001907349px">On the vif5_7 side:</span></div><div><span style="font-size:12.8000001907349px">--------------------------</span></div><div><div style><div><div>Apr 20 03:21:29 vif5_7 lrmd: [12556]: info: rsc:clusterIP:5: monitor</div><div>Apr 20 04:18:40 corosync [pcmk  ] notice: pcmk_peer_update: Transitional membership event on ring 385864: memb=1, new=0, lost=1</div><div>Apr 20 04:18:40 corosync [pcmk  ] info: pcmk_peer_update: memb: vif5_7 38275594</div><div>Apr 20 04:18:40 corosync [pcmk  ] info: pcmk_peer_update: lost: <span style="font-size:12.8000001907349px"><a href="http://hosts2.example.com">hosts2.example.com</a></span> 122161674</div><div>Apr 20 04:18:40 corosync [pcmk  ] notice: pcmk_peer_update: Stable membership event on ring 385864: memb=1, new=0, lost=0</div><div>Apr 20 04:18:40 corosync [pcmk  ] info: pcmk_peer_update: MEMB: vif5_7 38275594</div><div>Apr 20 04:18:40 corosync [pcmk  ] info: ais_mark_unseen_peer_dead: Node <span style="font-size:12.8000001907349px"><a href="http://hosts2.example.com">hosts2.example.com</a></span> was not seen in the previous transition</div><div>Apr 20 04:18:40 corosync [pcmk  ] info: update_member: Node 122161674/<span style="font-size:12.8000001907349px"><a href="http://hosts2.example.com">hosts2.example.com</a></span> is now: lost</div><div>Apr 20 04:18:40 corosync [pcmk  ] info: send_member_notification: Sending membership update 385864 to 2 children</div><div>Apr 20 04:18:40 corosync [TOTEM ] A processor joined or left the membership and a new membership was formed.</div><div>Apr 20 04:18:40 corosync [MAIN  ] Completed service synchronization, ready to provide service.</div></div><div>Apr 20 04:18:40 vif5_7 crmd: [12559]: WARN: check_dead_member: Our DC node (<span style="font-size:12.8000001907349px"><a href="http://hosts2.example.com">hosts2.example.com</a></span>) left the cluster</div><div>...</div><div>Apr 20 04:18:40 vif5_7 crmd: [12559]: info: update_dc: Set DC to vif5_7 (3.0.1)<br></div><div><br></div></div><div style="font-size:12.8000001907349px"><br></div></div><div style="font-size:12.8000001907349px">And on the <a href="http://hosts2.example.com">hosts2.example.com</a>, at the same time I have:</div><div style="font-size:12.8000001907349px">-----------------------------------------------</div><div style="font-size:12.8000001907349px"><div style="font-size:12.8000001907349px"><div style="font-size:small">Apr 20 04:09:46 <span style="font-size:12.8000001907349px"><a href="http://hosts2.example.com">hosts2.example.com</a></span> cib: [16956]: info: cib_stats: Processed 1 operations (10000.00us average, 0% utilization) in the last 10min</div><div style="font-size:small">Apr 20 04:18:39 corosync [TOTEM ] A processor failed, forming new configuration.</div><div style="font-size:small">Apr 20 04:18:40 corosync [pcmk  ] notice: pcmk_peer_update: Transitional membership event on ring 385864: memb=1, new=0, lost=1</div><div style="font-size:small">Apr 20 04:18:40 corosync [pcmk  ] info: pcmk_peer_update: memb: <span style="font-size:12.8000001907349px"><a href="http://hosts2.example.com">hosts2.example.com</a></span> 122161674</div><div style="font-size:small">Apr 20 04:18:40 corosync [pcmk  ] info: pcmk_peer_update: lost: vif5_7 38275594</div><div style="font-size:small">Apr 20 04:18:40 corosync [pcmk  ] notice: pcmk_peer_update: Stable membership event on ring 385864: memb=1, new=0, lost=0</div><div style="font-size:small">Apr 20 04:18:40 corosync [pcmk  ] info: pcmk_peer_update: MEMB: <span style="font-size:12.8000001907349px"><a href="http://hosts2.example.com">hosts2.example.com</a></span> 122161674</div><div style="font-size:small">Apr 20 04:18:40 corosync [pcmk  ] info: ais_mark_unseen_peer_dead: Node vif5_7 was not seen in the previous transition</div><div style="font-size:small">Apr 20 04:18:40 corosync [pcmk  ] info: update_member: Node 38275594/vif5_7 is now: lost</div><div style="font-size:small">Apr 20 04:18:40 corosync [pcmk  ] info: send_member_notification: Sending membership update 385864 to 2 children</div><div><br></div></div><div style="font-size:12.8000001907349px"><br></div><div style="font-size:12.8000001907349px"><span style="font-size:12.8000001907349px">So, vif5_7 say : </span><span style="font-size:12.8000001907349px"><a href="http://host2.example.com">host2.example.com</a> has disappeared and </span><span style="font-size:12.8000001907349px"><a href="http://host2.example.com">host2.example.com</a> say : </span><span style="font-size:12.8000001907349px">vif5_7 </span><span style="font-size:12.8000001907349px">has disappeared. But why ?</span><br></div></div><div><span style="font-size:12.8000001907349px"><br></span></div><div><span style="font-size:12.8000001907349px"><br></span></div><div><span style="font-size:12.8000001907349px">And in the SAME second <a href="http://host2.example.com">host2.example.com</a> reappears from the vif5_7 point of view !</span></div><div><span style="font-size:12.8000001907349px">---------------------------------------------------------------------------------------------------------------------------</span></div><div><div style><span style="font-size:12.8000001907349px">Apr 20 04:18:40 corosync [pcmk  ] notice: pcmk_peer_update: Transitional membership event on ring 385868: memb=1, new=0, lost=0</span></div><div style><span style="font-size:12.8000001907349px">Apr 20 04:18:40 corosync [pcmk  ] info: pcmk_peer_update: memb: vif5_7 38275594</span></div><div style><span style="font-size:12.8000001907349px">Apr 20 04:18:40 corosync [pcmk  ] notice: pcmk_peer_update: Stable membership event on ring 385868: memb=2, new=1, lost=0</span></div><div style><span style="font-size:12.8000001907349px">Apr 20 04:18:40 corosync [pcmk  ] info: update_member: Node 122161674/</span><span style="font-size:12.8000001907349px"><a href="http://host2.example.com">host2.example.com</a></span><span style="font-size:12.8000001907349px"> is now: member</span></div><div style><span style="font-size:12.8000001907349px">Apr 20 04:18:40 corosync [pcmk  ] info: pcmk_peer_update: NEW:  </span><span style="font-size:12.8000001907349px"><a href="http://host2.example.com">host2.example.com</a></span><span style="font-size:12.8000001907349px"> 122161674</span></div><div style><span style="font-size:12.8000001907349px">Apr 20 04:18:40 corosync [pcmk  ] info: pcmk_peer_update: MEMB: vif5_7 38275594</span></div><div style><span style="font-size:12.8000001907349px">Apr 20 04:18:40 corosync [pcmk  ] info: pcmk_peer_update: MEMB: </span><span style="font-size:12.8000001907349px"><a href="http://host2.example.com">host2.example.com</a></span><span style="font-size:12.8000001907349px"> 122161674</span></div><div style><span style="font-size:12.8000001907349px">Apr 20 04:18:40 corosync [pcmk  ] info: send_member_notification: Sending membership update 385868 to 2 children</span></div><div style><span style="font-size:12.8000001907349px">Apr 20 04:18:40 corosync [TOTEM ] A processor joined or left the membership and a new membership was formed.</span></div><div style><span style="font-size:12.8000001907349px">Apr 20 04:18:40 vif5_7 cib: [12555]: notice: ais_dispatch: Membership 385868: quorum acquired</span></div><div style><span style="font-size:12.8000001907349px">Apr 20 04:18:40 vif5_7 cib: [12555]: info: crm_update_peer: Node </span><span style="font-size:12.8000001907349px"><a href="http://host2.example.com">host2.example.com</a></span><span style="font-size:12.8000001907349px">: id=122161674 state=member (new) addr=r(0) ip(10.10.72.7)  votes=1 born=385364 seen=385868 proc=00000000000000000000000000013312</span></div><div style><span style="font-size:12.8000001907349px">Apr 20 04:18:40 vif5_7 cib: [12555]: info: cib_process_diff: Diff 0.3023.5 -> 0.3023.6 not applied to 0.3023.1: current "num_updates" is less than required</span></div><div style><span style="font-size:12.8000001907349px">Apr 20 04:18:40 vif5_7 cib: [12555]: WARN: cib_server_process_diff: Not requesting full refresh in slave mode.</span></div><div style><span style="font-size:12.8000001907349px">Apr 20 04:18:40 vif5_7 cib: [12555]: info: cib_process_diff: Diff 0.3023.6 -> 0.3023.7 not applied to 0.3023.1: current "num_updates" is less than required</span></div><div style><span style="font-size:12.8000001907349px">Apr 20 04:18:40 vif5_7 cib: [12555]: WARN: cib_server_process_diff: Not requesting full refresh in slave mode.</span></div><div style><span style="font-size:12.8000001907349px">Apr 20 04:18:40 vif5_7 cib: [12555]: info: cib_process_diff: Diff 0.3023.7 -> 0.3023.8 not applied to 0.3023.1: current "num_updates" is less than required</span></div><div style><span style="font-size:12.8000001907349px">Apr 20 04:18:40 vif5_7 cib: [12555]: WARN: cib_server_process_diff: Not requesting full refresh in slave mode.</span></div><div style><span style="font-size:12.8000001907349px">Apr 20 04:18:40 vif5_7 cib: [12555]: info: cib_process_diff: Diff 0.3023.8 -> 0.3024.1 not applied to 0.3023.1: current "num_updates" is less than required</span></div><div style><span style="font-size:12.8000001907349px">Apr 20 04:18:40 vif5_7 cib: [12555]: WARN: cib_server_process_diff: Not requesting full refresh in slave mode.</span></div><div style><span style="font-size:12.8000001907349px">Apr 20 04:18:40 corosync [MAIN  ] Completed service synchronization, ready to provide service.</span></div><div style><span style="font-size:12.8000001907349px">Apr 20 04:18:41 vif5_7 crmd: [12559]: info: te_connect_stonith: Connected</span></div><div style><span style="font-size:12.8000001907349px">Apr 20 04:18:41 vif5_7 crmd: [12559]: notice: ais_dispatch: Membership 385868: quorum acquired</span></div><div style><span style="font-size:12.8000001907349px">Apr 20 04:18:41 vif5_7 crmd: [12559]: info: ais_status_callback: status: </span><span style="font-size:12.8000001907349px"><a href="http://host2.example.com">host2.example.com</a></span><span style="font-size:12.8000001907349px"> is now member (was lost)</span></div><div style><span style="font-size:12.8000001907349px">Apr 20 04:18:41 vif5_7 crmd: [12559]: info: crm_update_peer: Node </span><span style="font-size:12.8000001907349px"><a href="http://host2.example.com">host2.example.com</a></span><span style="font-size:12.8000001907349px">: id=122161674 state=member (new) addr=r(0) ip(10.10.72.7)  votes=1 born=385364 seen=385868 proc=00000000000000000000000000013312</span></div><div style="font-size:12.8000001907349px"><br></div></div><div><span style="font-size:12.8000001907349px"><br></span></div><div><span style="font-size:12.8000001907349px">On <a href="http://host2.example.com">host2.example.com</a>, same thing : vif5_7 reappears</span><br></div><div><div><span style="font-size:12.8000001907349px">Apr 20 04:18:40 corosync [pcmk  ] info: update_member: Node 38275594/vif5_7 is now: member</span></div><div><span style="font-size:12.8000001907349px">Apr 20 04:18:40 corosync [pcmk  ] info: pcmk_peer_update: NEW:  vif5_7 38275594</span></div><div><span style="font-size:12.8000001907349px">Apr 20 04:18:40 corosync [pcmk  ] info: pcmk_peer_update: MEMB: vif5_7 38275594</span></div><div><span style="font-size:12.8000001907349px">Apr 20 04:18:40 corosync [pcmk  ] info: pcmk_peer_update: MEMB: </span><span style="font-size:12.8000001907349px"><a href="http://host2.example.com">host2.example.com</a></span><span style="font-size:12.8000001907349px">  122161674</span></div></div><div>...</div><div><br></div><div>corosync see that the ressources are online on the 2 nodes :</div><div><div>Apr 20 04:18:41 <a href="http://host2.example.com">host2.example.com</a> pengine: [16959]: info: determine_online_status: Node <a href="http://host2.example.com">host2.example.com</a> is online<br></div><div>Apr 20 04:18:41 <a href="http://host2.example.com">host2.example.com</a> pengine: [16959]: info: determine_online_status: Node vif5_7 is online</div><div>Apr 20 04:18:41 <a href="http://host2.example.com">host2.example.com</a> pengine: [16959]: ERROR: native_add_running: Resource lsb::routing-jboss:routing-jboss appears to be active on 2 nodes.</div><div>Apr 20 04:18:41 <a href="http://host2.example.com">host2.example.com</a> pengine: [16959]: WARN: See <a href="http://clusterlabs.org/wiki/FAQ#Resource_is_Too_Active">http://clusterlabs.org/wiki/FAQ#Resource_is_Too_Active</a> for more information.</div><div>Apr 20 04:18:41 <a href="http://host2.example.com">host2.example.com</a> pengine: [16959]: ERROR: native_add_running: Resource ocf::IPaddr2:clusterIP appears to be active on 2 nodes.</div><div>Apr 20 04:18:41 <a href="http://host2.example.com">host2.example.com</a> pengine: [16959]: WARN: See <a href="http://clusterlabs.org/wiki/FAQ#Resource_is_Too_Active">http://clusterlabs.org/wiki/FAQ#Resource_is_Too_Active</a> for more information.</div><div>Apr 20 04:18:41 <a href="http://host2.example.com">host2.example.com</a> pengine: [16959]: notice: group_print:  Resource Group: vifGroup</div><div>Apr 20 04:18:41 <a href="http://host2.example.com">host2.example.com</a> pengine: [16959]: notice: native_print:      clusterIP       (ocf::heartbeat:IPaddr2) Started</div><div>Apr 20 04:18:41 <a href="http://host2.example.com">host2.example.com</a> pengine: [16959]: notice: native_print:      0 : <a href="http://host2.example.com">host2.example.com</a></div><div>Apr 20 04:18:41 <a href="http://host2.example.com">host2.example.com</a> pengine: [16959]: notice: native_print:      1 : vif5_7</div><div>Apr 20 04:18:41 <a href="http://host2.example.com">host2.example.com</a> pengine: [16959]: notice: native_print:      routing-jboss   (lsb:routing-jboss) Started</div><div>Apr 20 04:18:41 <a href="http://host2.example.com">host2.example.com</a> pengine: [16959]: notice: native_print:      0 : <a href="http://host2.example.com">host2.example.com</a></div><div>Apr 20 04:18:41 <a href="http://host2.example.com">host2.example.com</a> pengine: [16959]: notice: native_print:      1 : vif5_7</div><div>Apr 20 04:18:41 <a href="http://host2.example.com">host2.example.com</a> pengine: [16959]: WARN: native_create_actions: Attempting recovery of resource clusterIP</div><div>Apr 20 04:18:41 <a href="http://host2.example.com">host2.example.com</a> pengine: [16959]: notice: RecurringOp:  Start recurring monitor (30s) for clusterIP on vif5_7</div><div>Apr 20 04:18:41 <a href="http://host2.example.com">host2.example.com</a> pengine: [16959]: WARN: native_create_actions: Attempting recovery of resource routing-jboss</div><div>Apr 20 04:18:41 <a href="http://host2.example.com">host2.example.com</a> pengine: [16959]: notice: RecurringOp:  Start recurring monitor (30s) for routing-jboss on vif5_7</div><div>Apr 20 04:18:41 <a href="http://host2.example.com">host2.example.com</a> pengine: [16959]: notice: LogActions: Move resource clusterIP        (Started <a href="http://host2.example.com">host2.example.com</a> -> vif5_7)</div><div>Apr 20 04:18:41 <a href="http://host2.example.com">host2.example.com</a> pengine: [16959]: notice: LogActions: Move resource routing-jboss    (Started <a href="http://host2.example.com">host2.example.com</a> -> vif5_7)</div></div><div><div>Apr 20 04:18:41 <a href="http://host2.example.com">host2.example.com</a> crmd: [16960]: info: do_state_transition: State transition S_POLICY_ENGINE -> S_TRANSITION_ENGINE [ input=I_PE_SUCCESS cause=C_IPC_MESSAGE origin=handle_response ]</div><div>Apr 20 04:18:41 <a href="http://host2.example.com">host2.example.com</a> crmd: [16960]: info: unpack_graph: Unpacked transition 737: 13 actions in 13 synapses</div><div>Apr 20 04:18:41 <a href="http://host2.example.com">host2.example.com</a> crmd: [16960]: info: do_te_invoke: Processing graph 737 (ref=pe_calc-dc-1429496321-2258) derived from /var/lib/pengine/pe-error-545.bz2</div><div>Apr 20 04:18:41 <a href="http://host2.example.com">host2.example.com</a> crmd: [16960]: info: te_pseudo_action: Pseudo action 17 fired and confirmed</div><div>Apr 20 04:18:41 <a href="http://host2.example.com">host2.example.com</a> crmd: [16960]: info: te_rsc_command: Initiating action 12: stop routing-jboss_stop_0 on <a href="http://host2.example.com">host2.example.com</a> (local)</div><div>Apr 20 04:18:41 <a href="http://host2.example.com">host2.example.com</a> lrmd: [16957]: info: cancel_op: operation monitor[357] on lsb::routing-jboss::routing-jboss for client 16960, its parameters: CRM_meta_interval=[30000] CRM_meta_timeout=[20000] crm_feature_set=[3.0.1] CRM_meta_name=[monitor]  cancelled</div><div>Apr 20 04:18:41 <a href="http://host2.example.com">host2.example.com</a> attrd: [16958]: info: attrd_local_callback: Sending full refresh (origin=crmd)</div><div>Apr 20 04:18:41 <a href="http://host2.example.com">host2.example.com</a> attrd: [16958]: info: attrd_trigger_update: Sending flush op to all hosts for: fail-count-routing-jboss (<null>)</div><div>Apr 20 04:18:41 <a href="http://host2.example.com">host2.example.com</a> crmd: [16960]: info: do_lrm_rsc_op: Performing key=12:737:0:90d438c0-2db4-4d39-bdf9-f0476d6f06ff op=routing-jboss_stop_0 )</div><div>Apr 20 04:18:41 <a href="http://host2.example.com">host2.example.com</a> lrmd: [16957]: info: rsc:routing-jboss:358: stop</div><div>Apr 20 04:18:41 <a href="http://host2.example.com">host2.example.com</a> attrd: [16958]: info: attrd_trigger_update: Sending flush op to all hosts for: probe_complete (true)</div><div>Apr 20 04:18:41 <a href="http://host2.example.com">host2.example.com</a> crmd: [16960]: info: te_rsc_command: Initiating action 13: stop routing-jboss_stop_0 on vif5_7</div><div>Apr 20 04:18:41 <a href="http://host2.example.com">host2.example.com</a> crmd: [16960]: info: process_lrm_event: LRM operation routing-jboss_monitor_30000 (call=357, status=1, cib-update=0, confirmed=true) Cancelled</div><div>Apr 20 04:18:41 <a href="http://host2.example.com">host2.example.com</a> lrmd: [17123]: WARN: For LSB init script, no additional parameters are needed.</div><div>Apr 20 04:18:41 <a href="http://host2.example.com">host2.example.com</a> pengine: [16959]: ERROR: process_pe_message: Transition 737: ERRORs found during PE processing. PEngine Input stored in: /var/lib/pengine/pe-error-545.bz2</div><div>Apr 20 04:18:41 <a href="http://host2.example.com">host2.example.com</a> attrd: [16958]: info: attrd_trigger_update: Sending flush op to all hosts for: terminate (<null>)</div><div>Apr 20 04:18:41 <a href="http://host2.example.com">host2.example.com</a> attrd: [16958]: info: attrd_trigger_update: Sending flush op to all hosts for: last-failure-routing-jboss (<null>)</div><div>Apr 20 04:18:41 <a href="http://host2.example.com">host2.example.com</a> attrd: [16958]: info: attrd_trigger_update: Sending flush op to all hosts for: shutdown (<null>)</div><div>Apr 20 04:18:41 <a href="http://host2.example.com">host2.example.com</a> lrmd: [16957]: info: RA output: (routing-jboss:stop:stdout) Disabling traffic redirection from 10.10.72.3 to 10.10.72.7</div><div>Apr 20 04:18:41 <a href="http://host2.example.com">host2.example.com</a> lrmd: [16957]: info: RA output: (routing-jboss:stop:stdout) [</div><div>Apr 20 04:18:41 <a href="http://host2.example.com">host2.example.com</a> lrmd: [16957]: info: RA output: (routing-jboss:stop:stdout)   OK</div><div>Apr 20 04:18:41 <a href="http://host2.example.com">host2.example.com</a> lrmd: [16957]: info: RA output: (routing-jboss:stop:stdout) ]</div><div>Apr 20 04:18:41 <a href="http://host2.example.com">host2.example.com</a> lrmd: [16957]: info: RA output: (routing-jboss:stop:stdout) ^M</div><div>Apr 20 04:18:41 <a href="http://host2.example.com">host2.example.com</a> lrmd: [16957]: info: RA output: (routing-jboss:stop:stdout)</div><div><br></div><div>Apr 20 04:18:41 <a href="http://host2.example.com">host2.example.com</a> crmd: [16960]: info: process_lrm_event: LRM operation routing-jboss_stop_0 (call=358, rc=0, cib-update=3395, confirmed=true) ok</div><div>Apr 20 04:18:41 <a href="http://host2.example.com">host2.example.com</a> crmd: [16960]: info: match_graph_event: Action routing-jboss_stop_0 (12) confirmed on <a href="http://host2.example.com">host2.example.com</a> (rc=0)</div><div>Apr 20 04:18:41 <a href="http://host2.example.com">host2.example.com</a> crmd: [16960]: info: match_graph_event: Action routing-jboss_stop_0 (13) confirmed on vif5_7 (rc=0)</div><div>Apr 20 04:18:41 <a href="http://host2.example.com">host2.example.com</a> crmd: [16960]: info: te_rsc_command: Initiating action 9: stop clusterIP_stop_0 on <a href="http://host2.example.com">host2.example.com</a> (local)</div><div>Apr 20 04:18:41 <a href="http://host2.example.com">host2.example.com</a> lrmd: [16957]: info: cancel_op: operation monitor[355] on ocf::IPaddr2::clusterIP for client 16960, its parameters: CRM_meta_interval=[30000] ip=[10.10.72.3] cidr_netmask=[32] CRM_meta_timeout=[20000] crm_feature_set=[3.0.1] CRM_meta_name=[monitor] iflabel=[jbossfailover]  cancelled</div><div>Apr 20 04:18:41 <a href="http://host2.example.com">host2.example.com</a> crmd: [16960]: info: do_lrm_rsc_op: Performing key=9:737:0:90d438c0-2db4-4d39-bdf9-f0476d6f06ff op=clusterIP_stop_0 )</div><div>Apr 20 04:18:41 <a href="http://host2.example.com">host2.example.com</a> lrmd: [16957]: info: rsc:clusterIP:359: stop</div><div>Apr 20 04:18:41 <a href="http://host2.example.com">host2.example.com</a> crmd: [16960]: info: te_rsc_command: Initiating action 10: stop clusterIP_stop_0 on vif5_7</div><div>Apr 20 04:18:41 <a href="http://host2.example.com">host2.example.com</a> crmd: [16960]: info: process_lrm_event: LRM operation clusterIP_monitor_30000 (call=355, status=1, cib-update=0, confirmed=true) Cancelled</div><div>Apr 20 04:18:41 <a href="http://host2.example.com">host2.example.com</a> lrmd: [16957]: info: RA output: (clusterIP:stop:stderr) logger: unknown facility name: none.</div><div>Apr 20 04:18:41 <a href="http://host2.example.com">host2.example.com</a> lrmd: [16957]: info: RA output: (clusterIP:stop:stderr) logger: unknown facility name: none.<br></div><div>Apr 20 04:18:41 <a href="http://host2.example.com">host2.example.com</a> crmd: [16960]: info: process_lrm_event: LRM operation clusterIP_stop_0 (call=359, rc=0, cib-update=3396, confirmed=true) ok<br></div><div>Apr 20 04:18:41 <a href="http://host2.example.com">host2.example.com</a> crmd: [16960]: info: match_graph_event: Action clusterIP_stop_0 (9) confirmed on <a href="http://host2.example.com">host2.example.com</a> (rc=0)</div><div>Apr 20 04:18:41 <a href="http://host2.example.com">host2.example.com</a> crmd: [16960]: info: match_graph_event: Action clusterIP_stop_0 (10) confirmed on vif5_7 (rc=0)</div><div>Apr 20 04:18:41 <a href="http://host2.example.com">host2.example.com</a> crmd: [16960]: info: te_pseudo_action: Pseudo action 18 fired and confirmed</div><div>Apr 20 04:18:41 <a href="http://host2.example.com">host2.example.com</a> crmd: [16960]: info: te_pseudo_action: Pseudo action 5 fired and confirmed</div><div>Apr 20 04:18:41 <a href="http://host2.example.com">host2.example.com</a> crmd: [16960]: info: te_pseudo_action: Pseudo action 15 fired and confirmed</div><div>Apr 20 04:18:41 <a href="http://host2.example.com">host2.example.com</a> crmd: [16960]: info: te_rsc_command: Initiating action 11: start clusterIP_start_0 on vif5_7</div><div>Apr 20 04:18:41 <a href="http://host2.example.com">host2.example.com</a> crmd: [16960]: info: match_graph_event: Action clusterIP_start_0 (11) confirmed on vif5_7 (rc=0)</div><div>Apr 20 04:18:41 <a href="http://host2.example.com">host2.example.com</a> crmd: [16960]: info: te_rsc_command: Initiating action 4: monitor clusterIP_monitor_30000 on vif5_7</div><div>Apr 20 04:18:41 <a href="http://host2.example.com">host2.example.com</a> crmd: [16960]: info: te_rsc_command: Initiating action 14: start routing-jboss_start_0 on vif5_7</div><div>Apr 20 04:18:41 <a href="http://host2.example.com">host2.example.com</a> crmd: [16960]: info: match_graph_event: Action routing-jboss_start_0 (14) confirmed on vif5_7 (rc=0)</div><div>Apr 20 04:18:41 <a href="http://host2.example.com">host2.example.com</a> crmd: [16960]: info: te_pseudo_action: Pseudo action 16 fired and confirmed</div><div>Apr 20 04:18:41 <a href="http://host2.example.com">host2.example.com</a> crmd: [16960]: info: te_rsc_command: Initiating action 3: monitor routing-jboss_monitor_30000 on vif5_7</div><div>Apr 20 04:18:41 <a href="http://host2.example.com">host2.example.com</a> crmd: [16960]: info: match_graph_event: Action routing-jboss_monitor_30000 (3) confirmed on vif5_7 (rc=0)</div><div>Apr 20 04:18:41 <a href="http://host2.example.com">host2.example.com</a> crmd: [16960]: info: match_graph_event: Action clusterIP_monitor_30000 (4) confirmed on vif5_7 (rc=0)</div><div>Apr 20 04:18:41 <a href="http://host2.example.com">host2.example.com</a> crmd: [16960]: info: run_graph: ====================================================</div><div>Apr 20 04:18:41 <a href="http://host2.example.com">host2.example.com</a> crmd: [16960]: notice: run_graph: Transition 737 (Complete=13, Pending=0, Fired=0, Skipped=0, Incomplete=0, Source=/var/lib/pengine/pe-error-545.bz2): Complete</div><div>Apr 20 04:18:41 <a href="http://host2.example.com">host2.example.com</a> crmd: [16960]: info: te_graph_trigger: Transition 737 is now complete</div><div>Apr 20 04:18:41 <a href="http://host2.example.com">host2.example.com</a> crmd: [16960]: info: notify_crmd: Transition 737 status: done - <null></div><div>Apr 20 04:18:41 <a href="http://host2.example.com">host2.example.com</a> crmd: [16960]: info: do_state_transition: State transition S_TRANSITION_ENGINE -> S_IDLE [ input=I_TE_SUCCESS cause=C_FSA_INTERNAL origin=notify_crmd ]</div><div>Apr 20 04:18:41 <a href="http://host2.example.com">host2.example.com</a> crmd: [16960]: info: do_state_transition: Starting PEngine Recheck Timer</div><div>Apr 20 04:18:44 <a href="http://host2.example.com">host2.example.com</a> lrmd: [16957]: info: RA output: (clusterIP:start:stderr) ARPING 10.10.72.3 from 10.10.72.3 eth0</div><div>Sent 5 probes (5 broadcast(s))</div><div>Received 0 response(s)</div><div><br></div><div>Apr 20 04:19:46 <a href="http://host2.example.com">host2.example.com</a> cib: [16956]: info: cib_stats: Processed 80 operations (2750.00us average, 0% utilization) in the last 10min</div><div>Apr 20 04:33:41 <a href="http://host2.example.com">host2.example.com</a> crmd: [16960]: info: crm_timer_popped: PEngine Recheck Timer (I_PE_CALC) just popped!</div><div>Apr 20 04:33:41 <a href="http://host2.example.com">host2.example.com</a> crmd: [16960]: info: do_state_transition: State transition S_IDLE -> S_POLICY_ENGINE [ input=I_PE_CALC cause=C_TIMER_POPPED origin=crm_timer_popped ]</div><div>Apr 20 04:33:41 <a href="http://host2.example.com">host2.example.com</a> crmd: [16960]: info: do_state_transition: Progressed to state S_POLICY_ENGINE after C_TIMER_POPPED</div><div>Apr 20 04:33:41 <a href="http://host2.example.com">host2.example.com</a> crmd: [16960]: info: do_state_transition: All 2 cluster nodes are eligible to run resources.</div><div>Apr 20 04:33:41 <a href="http://host2.example.com">host2.example.com</a> crmd: [16960]: info: do_pe_invoke: Query 3397: Requesting the current CIB: S_POLICY_ENGINE</div><div>Apr 20 04:33:41 <a href="http://host2.example.com">host2.example.com</a> crmd: [16960]: info: do_pe_invoke_callback: Invoking the PE: query=3397, ref=pe_calc-dc-1429497221-2267, seq=385868, quorate=1</div><div>Apr 20 04:33:42 <a href="http://host2.example.com">host2.example.com</a> pengine: [16959]: notice: unpack_config: On loss of CCM Quorum: Ignore</div><div>Apr 20 04:33:42 <a href="http://host2.example.com">host2.example.com</a> pengine: [16959]: info: unpack_config: Node scores: 'red' = -INFINITY, 'yellow' = 0, 'green' = 0</div><div>Apr 20 04:33:42 <a href="http://host2.example.com">host2.example.com</a> pengine: [16959]: info: determine_online_status: Node <a href="http://host2.example.com">host2.example.com</a> is online</div><div>Apr 20 04:33:42 <a href="http://host2.example.com">host2.example.com</a> pengine: [16959]: info: determine_online_status: Node vif5_7 is online</div><div>Apr 20 04:33:42 <a href="http://host2.example.com">host2.example.com</a> pengine: [16959]: notice: group_print:  Resource Group: vifGroup</div><div>Apr 20 04:33:42 <a href="http://host2.example.com">host2.example.com</a> pengine: [16959]: notice: native_print:      clusterIP       (ocf::heartbeat:IPaddr2):       Started vif5_7</div><div>Apr 20 04:33:42 <a href="http://host2.example.com">host2.example.com</a> pengine: [16959]: notice: native_print:      routing-jboss   (lsb:routing-jboss):    Started vif5_7</div><div>Apr 20 04:33:42 <a href="http://host2.example.com">host2.example.com</a> pengine: [16959]: notice: LogActions: Leave resource clusterIP       (Started vif5_7)</div><div>Apr 20 04:33:42 <a href="http://host2.example.com">host2.example.com</a> pengine: [16959]: notice: LogActions: Leave resource routing-jboss   (Started vif5_7)</div></div><div><br></div><div>so the ressources have been returned normaly to vif5_7 node.</div><div><br></div><div>But 11hours after, same thing again : the 2 nodes dissappeared from each point of view while they are really up and running:</div><div><div>Apr 20 15:33:42 <a href="http://host2.example.com">host2.example.com</a> pengine: [16959]: info: process_pe_message: Transition 782: PEngine Input stored in: /var/lib/pengine/pe-input-88684.bz2</div><div>Apr 20 15:38:40 corosync [TOTEM ] A processor failed, forming new configuration.</div><div>Apr 20 15:38:42 corosync [pcmk  ] notice: pcmk_peer_update: Transitional membership event on ring 385872: memb=1, new=0, lost=1</div><div>Apr 20 15:38:42 corosync [pcmk  ] info: pcmk_peer_update: memb: <a href="http://host2.example.com">host2.example.com</a> 122161674</div><div>Apr 20 15:38:42 corosync [pcmk  ] info: pcmk_peer_update: lost: vif5_7 38275594</div><div>Apr 20 15:38:42 corosync [pcmk  ] notice: pcmk_peer_update: Stable membership event on ring 385872: memb=1, new=0, lost=0</div><div>Apr 20 15:38:42 corosync [pcmk  ] info: pcmk_peer_update: MEMB: <a href="http://host2.example.com">host2.example.com</a> 122161674</div><div>Apr 20 15:38:42 corosync [pcmk  ] info: ais_mark_unseen_peer_dead: Node vif5_7 was not seen in the previous transition</div></div><div><br></div><div>and so on : </div><div><div>Apr 20 04:18:39 corosync [TOTEM ] A processor failed, forming new configuration.</div><div>Apr 20 04:18:40 corosync [TOTEM ] A processor joined or left the membership and a new membership was formed.</div><div>Apr 20 04:18:40 corosync [TOTEM ] A processor joined or left the membership and a new membership was formed.</div><div>Apr 20 15:38:40 corosync [TOTEM ] A processor failed, forming new configuration.</div><div>Apr 20 15:38:42 corosync [TOTEM ] A processor joined or left the membership and a new membership was formed.</div><div>Apr 20 15:38:42 corosync [TOTEM ] A processor joined or left the membership and a new membership was formed.</div><div>Apr 20 15:57:35 corosync [TOTEM ] A processor failed, forming new configuration.</div><div>Apr 20 15:57:36 corosync [TOTEM ] A processor joined or left the membership and a new membership was formed.</div><div>Apr 20 15:57:38 corosync [TOTEM ] A processor joined or left the membership and a new membership was formed.</div><div>Apr 20 16:20:06 corosync [TOTEM ] A processor failed, forming new configuration.</div><div>Apr 20 16:20:07 corosync [TOTEM ] A processor joined or left the membership and a new membership was formed.</div><div>Apr 20 16:20:11 corosync [TOTEM ] A processor joined or left the membership and a new membership was formed.</div></div><div><br></div><div><br></div><div>So my question is : is there a timer that I can raise to try to give more time to each node to see each other BEFORE TOTEM fire the "A processor failed, forming new configuration".</div><div>Once again the 2 linux servers 'vif5_7 and <a href="http://host2.example.com">host2.example.com</a>) are 2 VM on the same VMWare ESX server. May be the network is 'not working' the way corosync wants ?<br></div><div><br></div><div>Sorry for my english. I tried to put all the logs to help you to understand the problem...</div><div>Best regards</div><div><br></div><div><div style><br></div></div><div><span style="font-size:12.8000001907349px"><br></span></div><div> </div><blockquote class="gmail_quote" style="margin:0px 0px 0px 0.8ex;border-left-width:1px;border-left-color:rgb(204,204,204);border-left-style:solid;padding-left:1ex">
<div><div class="h5"><br>
> IMHO, it's just the result while the root cause is that the 2 nodes doesn't see each other sometimes.<br>
><br>
> But I've listen to your proposition and I've change the return code of the agent when we request it to stop : now it returns 0 even if it can't remove an iptables nat rule.<br>
><br>
> Do you think that this message can help ? The 2 VM are on vmware which sometime gives strange time : " current "epoch" is greater than required"<br>
><br>
> Best regards,<br>
><br>
><br>
> 2015-04-13 5:00 GMT+02:00 Andrew Beekhof <<a href="mailto:andrew@beekhof.net">andrew@beekhof.net</a>>:<br>
><br>
> > On 10 Apr 2015, at 11:37 pm, Philippe Carbonnier <<a href="mailto:Philippe.Carbonnier@vif.fr">Philippe.Carbonnier@vif.fr</a>> wrote:<br>
> ><br>
> > Hello,<br>
> ><br>
> > The context :<br>
> >   Red Hat Enterprise Linux Server release 5.7<br>
> >   corosynclib-1.2.7-1.1.el5.x86_64<br>
> >   corosync-1.2.7-1.1.el5.x86_64<br>
> >   pacemaker-1.0.10-1.4.el5.x86_64<br>
> >   pacemaker-libs-1.0.10-1.4.el5.x86_64<br>
> >   2 nodes, both on same ESX server<br>
> ><br>
> > I've lost of processor joined of left the membership message but can't understand why, because the 2 hosts are up and running, and when the corosync try to start the cluster's ressource he can't because the are already up on the first node.<br>
> > We can see "Another DC detected" so the communication between the 2 VM is OK.<br>
> ><br>
> > I've tried to raise totem parameter, without success.<br>
><br>
> > Apr 10 13:34:55 <a href="http://host2.example.com" target="_blank">host2.example.com</a> pengine: [26529]: WARN: unpack_rsc_op: Processing failed op routing-jboss_stop_0 on <a href="http://host2.example.com">host2.example.com</a>: invalid parameter (2)<br>
><br>
> ^^^ Failed stops lead to fencing.<br>
><br>
> The agent and/or your config need fixing.<br>
><br>
><br>
> _______________________________________________<br>
> Users mailing list: <a href="mailto:Users@clusterlabs.org">Users@clusterlabs.org</a><br>
> <a href="http://clusterlabs.org/mailman/listinfo/users" target="_blank">http://clusterlabs.org/mailman/listinfo/users</a><br>
><br>
> Project Home: <a href="http://www.clusterlabs.org" target="_blank">http://www.clusterlabs.org</a><br>
> Getting started: <a href="http://www.clusterlabs.org/doc/Cluster_from_Scratch.pdf" target="_blank">http://www.clusterlabs.org/doc/Cluster_from_Scratch.pdf</a><br>
> Bugs: <a href="http://bugs.clusterlabs.org" target="_blank">http://bugs.clusterlabs.org</a><br>
><br>
><br>
><br>
</div></div>> L'informatique 100% Agro      <a href="http://www.vif.fr" target="_blank">www.vif.fr</a><br>
><br>
> Suivez l'actualité VIF sur:<br>
<div class=""><div class="h5">> _______________________________________________<br>
> Users mailing list: <a href="mailto:Users@clusterlabs.org">Users@clusterlabs.org</a><br>
> <a href="http://clusterlabs.org/mailman/listinfo/users" target="_blank">http://clusterlabs.org/mailman/listinfo/users</a><br>
><br>
> Project Home: <a href="http://www.clusterlabs.org" target="_blank">http://www.clusterlabs.org</a><br>
> Getting started: <a href="http://www.clusterlabs.org/doc/Cluster_from_Scratch.pdf" target="_blank">http://www.clusterlabs.org/doc/Cluster_from_Scratch.pdf</a><br>
> Bugs: <a href="http://bugs.clusterlabs.org" target="_blank">http://bugs.clusterlabs.org</a><br>
<br>
<br>
_______________________________________________<br>
Users mailing list: <a href="mailto:Users@clusterlabs.org">Users@clusterlabs.org</a><br>
<a href="http://clusterlabs.org/mailman/listinfo/users" target="_blank">http://clusterlabs.org/mailman/listinfo/users</a><br>
<br>
Project Home: <a href="http://www.clusterlabs.org" target="_blank">http://www.clusterlabs.org</a><br>
Getting started: <a href="http://www.clusterlabs.org/doc/Cluster_from_Scratch.pdf" target="_blank">http://www.clusterlabs.org/doc/Cluster_from_Scratch.pdf</a><br>
Bugs: <a href="http://bugs.clusterlabs.org" target="_blank">http://bugs.clusterlabs.org</a><br>
</div></div></blockquote></div><br></div></div>

<br>
<table border="0" cellspacing="0" cellpadding="0" style="color:rgb(34,34,34);font-size:13px;background-color:rgb(255,255,255);font-family:Times;width:300px;display:block"><tbody><tr><td colspan="3" style="font-family:arial,sans-serif;margin:0px"><a href="http://www.vif.fr/" style="color:rgb(17,85,204);float:left" target="_blank"><img src="https://ci3.googleusercontent.com/proxy/jNw3kk6adk01Es5Sohxe1dLczyeO-oDK-x1ilyy9UZKzBvvYS6tLJdWQccesL76IUbn7nqjdykptLsCu6Q=s0-d-e1-ft#http://exper-ia.com/images/logo_vif.png" alt="logoVif"></a></td></tr><tr><td width="148" style="font-family:'Trebuchet MS',Arial,Helvetica,sans-serif;margin:0px;vertical-align:top;line-height:16px;font-size:11px;font-weight:bold"><span style="color:rgb(77,77,77)"><font><font><font><font>L'informatique 100% Agro</font></font></font></font></span></td><td width="81" align="right" style="font-family:'Trebuchet MS',Arial,Helvetica,sans-serif;margin:0px;color:rgb(77,77,77);font-size:11px;line-height:16px;font-weight:bold;vertical-align:top"><a href="http://www.vif.fr/" style="color:rgb(77,77,77);text-decoration:none" target="_blank"><font><font><font><font>www.vif.fr</font></font></font></font></a> <br></td><td width="71" rowspan="2" style="font-family:arial,sans-serif;margin:0px"><a href="http://www.youtube.com/user/Agrovif" style="color:rgb(17,85,204);float:right" target="_blank"><img src="https://ci3.googleusercontent.com/proxy/McHI_KgbDIV1VTZNHms4RfYjSyf9dZilloQOXJFt2R_8k5gZP5ezMt8pL7m7dkrNDrVIYdSrY9JJO8CWk8AArr_x2xs=s0-d-e1-ft#http://exper-ia.com/images/ico_YouTubeMail.png" alt="VifYouTube"></a><a href="https://twitter.com/VIF_agro" style="color:rgb(17,85,204);float:right;margin-right:4px" target="_blank"><img src="https://ci5.googleusercontent.com/proxy/TQSsKHGL--n7vnMbP-E37n9cQ0gF0xKtEyEKLVaDA1XyHPqseT8z2Ocw6PnUxjTfHHg7o8H3fzrNxcs7ZmDoKGzURx4=s0-d-e1-ft#http://exper-ia.com/images/ico_twitterMail.png" alt="VifTwitter"></a></td></tr><tr><td colspan="2" align="right" style="font-family:'Trebuchet MS',Arial,Helvetica,sans-serif;margin:0px;color:rgb(239,124,0);font-size:9px;line-height:16px;width:220px;vertical-align:top"><em><font><font><font><font>Suivez l'actualité VIF sur:</font></font></font></font></em></td></tr></tbody></table><a href="http://www.agrovif.com/" target="_blank"><img src="http://www.vif.fr/wp-content/uploads/2014/02/signature-mail-agrovif-2015.jpg"></a>