Hi Andrew, all,<div><br></div><div>We are using Pacemaker 1.0.10-4 on Ubuntu Natty (11.4) for a 2 node (VM) cluster. I have attached the pkg versions + crm configuration.</div><div><br></div><div>Periodically we run into a very strange issue where pacemaker takes a very very long duration in the election process. I have attached syslog of both nodes corresponding to one specific case.</div>
<div><br></div><div>As can be seen, one of the node constantly goes into this loop</div><div><div>Jan 17 12:04:50 vsa-0000003ca-vc-1 crmd: [1104]: info: crm_timer_popped: Election Trigger (I_DC_TIMEOUT) just popped!</div>
<div>Jan 17 12:04:50 vsa-0000003ca-vc-1 crmd: [1104]: WARN: do_log: FSA: Input I_DC_TIMEOUT from crm_timer_popped() received in state S_PENDING</div><div>Jan 17 12:04:50 vsa-0000003ca-vc-1 crmd: [1104]: info: do_state_transition: State transition S_PENDING -> S_ELECTION [ input=I_DC_TIMEOUT cause=C_TIMER_POPPED origin=crm_timer_popped ]</div>
<div>Jan 17 12:04:50 vsa-0000003ca-vc-1 crmd: [1104]: WARN: do_log: FSA: Input I_JOIN_OFFER from route_message() received in state S_ELECTION</div><div>Jan 17 12:04:50 vsa-0000003ca-vc-1 crmd: [1104]: info: do_state_transition: State transition S_ELECTION -> S_PENDING [ input=I_PENDING cause=C_FSA_INTERNAL origin=do_election_count_vote ]</div>
<div>Jan 17 12:04:50 vsa-0000003ca-vc-1 crmd: [1104]: info: do_dc_release: DC role released</div><div>Jan 17 12:04:50 vsa-0000003ca-vc-1 crmd: [1104]: info: do_te_control: Transitioner is now inactive</div></div><div><br>
</div><div>while other goes into this loop</div><div><div>Jan 17 12:04:49 vsa-0000003ca-vc-0 crmd: [1120]: info: do_dc_takeover: Taking over DC status for this partition</div><div>Jan 17 12:04:49 vsa-0000003ca-vc-0 cib: [1116]: info: cib_process_readwrite: We are now in R/O mode</div>
<div>Jan 17 12:04:49 vsa-0000003ca-vc-0 cib: [1116]: info: cib_process_request: Operation complete: op cib_slave_all for section 'all' (origin=local/crmd/521, version=1.8.26): ok (rc=0)</div><div>Jan 17 12:04:49 vsa-0000003ca-vc-0 cib: [1116]: info: cib_process_readwrite: We are now in R/W mode</div>
<div>Jan 17 12:04:49 vsa-0000003ca-vc-0 cib: [1116]: info: cib_process_request: Operation complete: op cib_master for section 'all' (origin=local/crmd/522, version=1.8.26): ok (rc=0)</div><div>Jan 17 12:04:49 vsa-0000003ca-vc-0 cib: [1116]: info: cib_process_request: Operation complete: op cib_modify for section cib (origin=local/crmd/523, version=1.8.26): ok (rc=0)</div>
<div>Jan 17 12:04:49 vsa-0000003ca-vc-0 cib: [1116]: info: cib_process_request: Operation complete: op cib_modify for section crm_config (origin=local/crmd/525, version=1.8.26): ok (rc=0)</div><div>Jan 17 12:04:49 vsa-0000003ca-vc-0 crmd: [1120]: info: do_dc_join_offer_all: join-51: Waiting on 2 outstanding join acks</div>
<div>Jan 17 12:04:49 vsa-0000003ca-vc-0 cib: [1116]: info: cib_process_request: Operation complete: op cib_modify for section crm_config (origin=local/crmd/527, version=1.8.26): ok (rc=0)</div><div>Jan 17 12:04:49 vsa-0000003ca-vc-0 crmd: [1120]: info: config_query_callback: Checking for expired actions every 900000ms</div>
<div>Jan 17 12:04:50 vsa-0000003ca-vc-0 crmd: [1120]: info: update_dc: Set DC to vsa-0000003ca-vc-0 (3.0.1)</div><div>Jan 17 12:04:50 vsa-0000003ca-vc-0 crmd: [1120]: info: do_election_count_vote: Election 98 (owner: 00000970-0970-0001-2b91-000000000001) pass: vote from vsa-0000003ca-vc-1 (Age)</div>
<div>Jan 17 12:04:50 vsa-0000003ca-vc-0 crmd: [1120]: info: do_election_count_vote: Election 99 (owner: 00000970-0970-0001-2b91-000000000001) pass: vote from vsa-0000003ca-vc-1 (Age)</div><div>Jan 17 12:04:50 vsa-0000003ca-vc-0 crmd: [1120]: info: do_state_transition: State transition S_INTEGRATION -> S_ELECTION [ input=I_ELECTION cause=C_FSA_INTERNAL origin=do_election_count_vote ]</div>
<div>Jan 17 12:04:50 vsa-0000003ca-vc-0 crmd: [1120]: info: update_dc: Unset DC vsa-0000003ca-vc-0</div><div>Jan 17 12:04:51 vsa-0000003ca-vc-0 crmd: [1120]: info: do_state_transition: State transition S_ELECTION -> S_INTEGRATION [ input=I_ELECTION_DC cause=C_FSA_INTERNAL origin=do_election_check ]</div>
<div>Jan 17 12:04:51 vsa-0000003ca-vc-0 crmd: [1120]: info: start_subsystem: Starting sub-system "pengine"</div><div>Jan 17 12:04:51 vsa-0000003ca-vc-0 crmd: [1120]: WARN: start_subsystem: Client pengine already running as pid 4243</div>
</div><div><br></div><div>This process in this case has repeated for 7 minutes. dc-deadtime is set to 5s & that shrinks this cycle. With higher dc-deadtime this problem happens for a much more longer time.</div><div><br>
</div><div>The specific scenario was I had done "crm node standby" on one node & rebooted the other one. Also I observe in logs that the node that was offline still kept attempting stonith, when the stonith resource itself was stopped (as part of the crm node standby).</div>
<div><br></div><div>Is this is a known issue in the version of Pacemaker I am using? Any suggestions/pointers/workarounds on how to resolve this is greatly appreciated.</div><div><br>Thanks.</div><div><br></div><div>--Shyam</div>
<div><div><br></div></div>