Hi Andrew,<div><br></div><div>We are using Pacemaker version:1.0.10-4ubuntu3 (comes with Ubuntu Natty 11.04)</div><div><br></div><div>I captured logs with higher debug.</div><div><br></div><div><div>On node-1</div><div><br>
</div><div>Feb 3 07:02:49 vsa-0000004dc-vc-0 crmd: [1259]: info: crm_timer_popped: Election Trigger (I_DC_TIMEOUT) just popped!</div><div>Feb 3 07:02:49 vsa-0000004dc-vc-0 crmd: [1259]: debug: debug2: crm_timer_stop: Stopping Election Trigger (I_DC_TIMEOUT:5000ms), src=16</div>
<div>Feb 3 07:02:49 vsa-0000004dc-vc-0 crmd: [1259]: debug: debug2: register_fsa_input_adv: crm_timer_popped appended FSA input 9 (I_DC_TIMEOUT) (cause=C_TIMER_POPPED) without data</div><div>Feb 3 07:02:49 vsa-0000004dc-vc-0 crmd: [1259]: debug: debug2: register_fsa_input_adv: Queue len: 1</div>
<div>Feb 3 07:02:49 vsa-0000004dc-vc-0 crmd: [1259]: debug: debug3: register_fsa_input_adv: Triggering FSA: register_fsa_input_adv</div><div>Feb 3 07:02:49 vsa-0000004dc-vc-0 crmd: [1259]: debug: debug3: crm_timer_popped: Triggering FSA: crm_timer_popped</div>
<div>Feb 3 07:02:49 vsa-0000004dc-vc-0 crmd: [1259]: debug: debug2: crm_fsa_trigger: Invoked (queue len: 1)</div><div>Feb 3 07:02:49 vsa-0000004dc-vc-0 crmd: [1259]: debug: debug2: s_crmd_fsa: FSA invoked with Cause: C_FSA_INTERNAL#011State: S_PENDING</div>
<div>Feb 3 07:02:49 vsa-0000004dc-vc-0 crmd: [1259]: debug: debug2: s_crmd_fsa: Checking messages (1 remaining)</div><div>Feb 3 07:02:49 vsa-0000004dc-vc-0 crmd: [1259]: debug: debug2: get_message: Processing input 9</div>
<div>Feb 3 07:02:49 vsa-0000004dc-vc-0 heartbeat: [1018]: debug: hb_send_local_status() {</div><div>Feb 3 07:02:49 vsa-0000004dc-vc-0 cib: [1255]: debug: debug3: ha_msg_dispatch: Invoked</div><div>Feb 3 07:02:49 vsa-0000004dc-vc-0 crmd: [1259]: debug: debug2: log_fsa_input: Processing queued input 9</div>
<div>Feb 3 07:02:49 vsa-0000004dc-vc-0 heartbeat: [1018]: debug: PID 1018: Sending local status curnode = 638e58 status: active</div><div>Feb 3 07:02:49 vsa-0000004dc-vc-0 cib: [1255]: debug: debug2: cib_process_request: Processing peer message (vsa-0000004dc-vc-1) for master...</div>
<div>Feb 3 07:02:49 vsa-0000004dc-vc-0 crmd: [1259]: debug: debug3: log_fsa_input: FSA processing input from crm_timer_popped</div><div>Feb 3 07:02:49 vsa-0000004dc-vc-0 heartbeat: [1018]: debug: process_clustermsg: node [vsa-0000004dc-vc-0]</div>
<div>Feb 3 07:02:49 vsa-0000004dc-vc-0 cib: [1255]: debug: debug2: parse_peer_options: Ignoring msg for master instance</div><div>Feb 3 07:02:49 vsa-0000004dc-vc-0 crmd: [1259]: debug: s_crmd_fsa: Processing I_DC_TIMEOUT: [ state=S_PENDING cause=C_TIMER_POPPED origin=crm_timer_popped ]</div>
<div>Feb 3 07:02:49 vsa-0000004dc-vc-0 heartbeat: [1018]: debug: }/*hb_send_local_status*/;</div><div>Feb 3 07:02:49 vsa-0000004dc-vc-0 crmd: [1259]: debug: do_fsa_action: actions:trace: #011// A_WARN</div><div>Feb 3 07:02:49 vsa-0000004dc-vc-0 heartbeat: [1018]: debug: read_child_dispatch() {</div>
<div>Feb 3 07:02:49 vsa-0000004dc-vc-0 crmd: [1259]: WARN: do_log: FSA: Input I_DC_TIMEOUT from crm_timer_popped() received in state S_PENDING</div><div>Feb 3 07:02:49 vsa-0000004dc-vc-0 heartbeat: [1018]: debug: Packet authenticated</div>
<div>Feb 3 07:02:49 vsa-0000004dc-vc-0 crmd: [1259]: debug: debug2: do_state_transition: actions:trace: #011S_PENDING -> S_ELECTION [ label=I_DC_TIMEOUT cause=C_TIMER_POPPED origin=crm_timer_popped ]</div><div>Feb 3 07:02:49 vsa-0000004dc-vc-0 heartbeat: [1018]: debug: process_clustermsg: node [vsa-0000004dc-vc-1]</div>
<div>Feb 3 07:02:49 vsa-0000004dc-vc-0 crmd: [1259]: info: do_state_transition: State transition S_PENDING -> S_ELECTION [ input=I_DC_TIMEOUT cause=C_TIMER_POPPED origin=crm_timer_popped ]</div><div>Feb 3 07:02:49 vsa-0000004dc-vc-0 heartbeat: [1018]: debug: }/*read_child_dispatch*/;</div>
<div>Feb 3 07:02:49 vsa-0000004dc-vc-0 crmd: [1259]: debug: debug2: crm_timer_stop: PEngine Recheck Timer (I_PE_CALC:900000ms) already stopped</div><div>Feb 3 07:02:49 vsa-0000004dc-vc-0 heartbeat: [1018]: debug: read_child_dispatch() {</div>
<div>Feb 3 07:02:49 vsa-0000004dc-vc-0 crmd: [1259]: debug: debug2: do_state_transition: Resetting our DC to NULL on transition to S_ELECTION</div><div>Feb 3 07:02:49 vsa-0000004dc-vc-0 heartbeat: [1018]: debug: Packet authenticated</div>
<div>Feb 3 07:02:49 vsa-0000004dc-vc-0 crmd: [1259]: debug: do_fsa_action: actions:trace: #011// A_DC_TIMER_STOP</div><div>Feb 3 07:02:49 vsa-0000004dc-vc-0 heartbeat: [1018]: debug: process_clustermsg: node [vsa-0000004dc-vc-1]</div>
<div>Feb 3 07:02:49 vsa-0000004dc-vc-0 crmd: [1259]: debug: debug2: crm_timer_stop: Election Trigger (I_DC_TIMEOUT:5000ms) already stopped</div><div>Feb 3 07:02:49 vsa-0000004dc-vc-0 heartbeat: [1018]: debug: }/*read_child_dispatch*/;</div>
<div>Feb 3 07:02:49 vsa-0000004dc-vc-0 crmd: [1259]: debug: do_fsa_action: actions:trace: #011// A_INTEGRATE_TIMER_STOP</div><div>Feb 3 07:02:49 vsa-0000004dc-vc-0 heartbeat: [1018]: debug: read_child_dispatch() {</div>
<div>Feb 3 07:02:49 vsa-0000004dc-vc-0 crmd: [1259]: debug: debug2: crm_timer_stop: Integration Timer (I_INTEGRATED:180000ms) already stopped</div><div>Feb 3 07:02:49 vsa-0000004dc-vc-0 heartbeat: [1018]: debug: Packet authenticated</div>
<div>Feb 3 07:02:49 vsa-0000004dc-vc-0 crmd: [1259]: debug: do_fsa_action: actions:trace: #011// A_FINALIZE_TIMER_STOP</div><div>Feb 3 07:02:49 vsa-0000004dc-vc-0 heartbeat: [1018]: debug: process_clustermsg: node [vsa-0000004dc-vc-1]</div>
<div>Feb 3 07:02:49 vsa-0000004dc-vc-0 crmd: [1259]: debug: debug2: crm_timer_stop: Finalization Timer (I_ELECTION:1800000ms) already stopped</div><div>Feb 3 07:02:49 vsa-0000004dc-vc-0 heartbeat: [1018]: debug: }/*read_child_dispatch*/;</div>
<div>Feb 3 07:02:49 vsa-0000004dc-vc-0 crmd: [1259]: debug: do_fsa_action: actions:trace: #011// A_ELECTION_VOTE</div><div>Feb 3 07:02:49 vsa-0000004dc-vc-0 heartbeat: [1018]: debug: read_child_dispatch() {</div><div>Feb 3 07:02:49 vsa-0000004dc-vc-0 crmd: [1259]: debug: debug3: log_data_element: send_ha_message: HA[outbound] <create_request_adv origin="do_election_vote" t="crmd" version="3.0.1" subt="request" reference="vote-crmd-1328245369-3" crm_task="vote" crm_sys_to="crmd" crm_sys_from="crmd" election-owner="00001244-1244-0000-2b91-000000000000" election-id="2" /></div>
<div>Feb 3 07:02:49 vsa-0000004dc-vc-0 heartbeat: [1018]: debug: Packet authenticated</div><div>Feb 3 07:02:49 vsa-0000004dc-vc-0 crmd: [1259]: debug: do_election_vote: Started election 2</div><div>Feb 3 07:02:49 vsa-0000004dc-vc-0 heartbeat: [1018]: debug: process_clustermsg: node [vsa-0000004dc-vc-1]</div>
<div>Feb 3 07:02:49 vsa-0000004dc-vc-0 crmd: [1259]: debug: crm_timer_start: Started Election Timeout (I_ELECTION_DC:120000ms), src=17</div><div>Feb 3 07:02:49 vsa-0000004dc-vc-0 heartbeat: [1018]: debug: }/*read_child_dispatch*/;</div>
<div>Feb 3 07:02:49 vsa-0000004dc-vc-0 crmd: [1259]: debug: debug2: s_crmd_fsa: Exiting the FSA</div><div>Feb 3 07:02:49 vsa-0000004dc-vc-0 heartbeat: [1018]: debug: read_child_dispatch() {</div><div>Feb 3 07:02:49 vsa-0000004dc-vc-0 crmd: [1259]: debug: debug2: crm_fsa_trigger: Exited (queue len: 0)</div>
<div>Feb 3 07:02:49 vsa-0000004dc-vc-0 heartbeat: [1018]: debug: Packet authenticated</div><div>Feb 3 07:02:49 vsa-0000004dc-vc-0 crmd: [1259]: debug: debug3: ha_msg_dispatch: Invoked</div><div>Feb 3 07:02:49 vsa-0000004dc-vc-0 heartbeat: [1018]: debug: process_clustermsg: node [vsa-0000004dc-vc-1]</div>
<div>Feb 3 07:02:49 vsa-0000004dc-vc-0 crmd: [1259]: debug: debug2: crmd_ha_msg_callback: HA[inbound]: join_offer from vsa-0000004dc-vc-1</div><div>Feb 3 07:02:49 vsa-0000004dc-vc-0 heartbeat: [1018]: debug: }/*read_child_dispatch*/;</div>
<div>Feb 3 07:02:49 vsa-0000004dc-vc-0 crmd: [1259]: debug: debug3: relay_message: Routing message join_offer-dc-1328245368-5</div><div>Feb 3 07:02:49 vsa-0000004dc-vc-0 heartbeat: [1018]: debug: read_child_dispatch() {</div>
<div>Feb 3 07:02:49 vsa-0000004dc-vc-0 crmd: [1259]: debug: debug3: relay_message: Router result: Message result: CRMd process</div><div>Feb 3 07:02:49 vsa-0000004dc-vc-0 heartbeat: [1018]: debug: Packet authenticated</div>
<div>Feb 3 07:02:49 vsa-0000004dc-vc-0 crmd: [1259]: debug: debug3: log_data_element: relay_message: router.log <create_request_adv origin="join_make_offer" t="crmd" version="3.0.1" subt="request" reference="join_offer-dc-1328245368-5" crm_task="join_offer" crm_sys_to="crmd" crm_sys_from="dc" crm_host_to="vsa-0000004dc-vc-0" join_id="1" dest="vsa-0000004dc-vc-0" oseq="1" from_id="crmd" to_id="crmd" client_gen="4" src="vsa-0000004dc-vc-1" seq="2f" hg="4f2a227c" ts="4f2b6a79" ld="3.01 0.88 0.30 5/106 1372" ttl="3" auth="1 d2e4a8a0ea8382763ce1ecd42633b575453fee2f" /></div>
<div>Feb 3 07:02:49 vsa-0000004dc-vc-0 heartbeat: [1018]: debug: process_clustermsg: node [vsa-0000004dc-vc-1]</div><div>Feb 3 07:02:49 vsa-0000004dc-vc-0 crmd: [1259]: debug: handle_request: Raising I_JOIN_OFFER: join-1</div>
<div>Feb 3 07:02:49 vsa-0000004dc-vc-0 heartbeat: [1018]: debug: }/*read_child_dispatch*/;</div><div>Feb 3 07:02:49 vsa-0000004dc-vc-0 crmd: [1259]: debug: debug2: register_fsa_input_adv: route_message appended FSA input 10 (I_JOIN_OFFER) (cause=C_HA_MESSAGE) with data</div>
<div>Feb 3 07:02:49 vsa-0000004dc-vc-0 heartbeat: [1018]: debug: read_child_dispatch() {</div><div>Feb 3 07:02:49 vsa-0000004dc-vc-0 crmd: [1259]: debug: debug3: register_fsa_input_adv: Copying C_HA_MESSAGE data from route_message as a HA msg</div>
<div>Feb 3 07:02:49 vsa-0000004dc-vc-0 heartbeat: [1018]: debug: Packet authenticated</div><div>Feb 3 07:02:49 vsa-0000004dc-vc-0 crmd: [1259]: debug: debug2: register_fsa_input_adv: Queue len: 1</div><div>Feb 3 07:02:49 vsa-0000004dc-vc-0 heartbeat: [1018]: debug: process_clustermsg: node [vsa-0000004dc-vc-1]</div>
<div>Feb 3 07:02:49 vsa-0000004dc-vc-0 crmd: [1259]: debug: debug3: register_fsa_input_adv: Triggering FSA: register_fsa_input_adv</div><div>Feb 3 07:02:49 vsa-0000004dc-vc-0 heartbeat: [1018]: debug: }/*read_child_dispatch*/;</div>
<div>Feb 3 07:02:49 vsa-0000004dc-vc-0 crmd: [1259]: debug: debug3: crmd_ha_msg_filter: Triggering FSA: crmd_ha_msg_filter</div><div>Feb 3 07:02:49 vsa-0000004dc-vc-0 heartbeat: [1018]: debug: read_child_dispatch() {</div>
<div>Feb 3 07:02:49 vsa-0000004dc-vc-0 crmd: [1259]: debug: debug2: crmd_ha_msg_callback: HA[inbound]: vote from vsa-0000004dc-vc-0</div><div>Feb 3 07:02:49 vsa-0000004dc-vc-0 heartbeat: [1018]: debug: Packet authenticated</div>
<div>Feb 3 07:02:49 vsa-0000004dc-vc-0 crmd: [1259]: debug: debug3: relay_message: Routing message vote-crmd-1328245369-3</div><div>Feb 3 07:02:49 vsa-0000004dc-vc-0 heartbeat: [1018]: debug: process_clustermsg: node [vsa-0000004dc-vc-1]</div>
<div>Feb 3 07:02:49 vsa-0000004dc-vc-0 crmd: [1259]: debug: debug3: relay_message: Router result: Message result: CRMd process</div><div>Feb 3 07:02:49 vsa-0000004dc-vc-0 heartbeat: [1018]: debug: }/*read_child_dispatch*/;</div>
<div>Feb 3 07:02:49 vsa-0000004dc-vc-0 crmd: [1259]: debug: debug3: log_data_element: relay_message: router.log <create_request_adv origin="do_election_vote" t="crmd" version="3.0.1" subt="request" reference="vote-crmd-1328245369-3" crm_task="vote" crm_sys_to="crmd" crm_sys_from="crmd" election-owner="00001244-1244-0000-2b91-000000000000" election-id="2" oseq="1" from_id="crmd" to_id="crmd" client_gen="4" src="vsa-0000004dc-vc-0" seq="2f" hg="4f2a2274" ts="4f2b6a79" ld="2.89 0.85 0.29 7/105 1463" ttl="3" auth="1 36b49d6fb3fb61ca4d5da0e98380e36d62f42449" /></div>
<div>Feb 3 07:02:49 vsa-0000004dc-vc-0 heartbeat: [1018]: debug: APIclients_input_dispatch() {</div><div>Feb 3 07:02:49 vsa-0000004dc-vc-0 crmd: [1259]: debug: debug2: register_fsa_input_adv: handle_request appended FSA input 11 (I_NULL) (cause=C_HA_MESSAGE) with data</div>
<div>Feb 3 07:02:49 vsa-0000004dc-vc-0 heartbeat: [1018]: debug: ProcessAnAPIRequest() {</div><div>Feb 3 07:02:49 vsa-0000004dc-vc-0 crmd: [1259]: debug: debug3: register_fsa_input_adv: Adding actions 0000000200000400 to input</div>
<div>Feb 3 07:02:49 vsa-0000004dc-vc-0 heartbeat: [1018]: debug: Sending API message to cluster...</div><div>Feb 3 07:02:49 vsa-0000004dc-vc-0 crmd: [1259]: debug: debug3: register_fsa_input_adv: Copying C_HA_MESSAGE data from handle_request as a HA msg</div>
<div>Feb 3 07:02:49 vsa-0000004dc-vc-0 heartbeat: [1018]: debug: MSG: Dumping message with 14 fields</div><div>Feb 3 07:02:49 vsa-0000004dc-vc-0 crmd: [1259]: debug: debug2: register_fsa_input_adv: Queue len: 2</div><div>
Feb 3 07:02:49 vsa-0000004dc-vc-0 heartbeat: [1018]: debug: MSG[0] : [__name__=create_request_adv]</div><div>Feb 3 07:02:49 vsa-0000004dc-vc-0 crmd: [1259]: debug: debug3: register_fsa_input_adv: Triggering FSA: register_fsa_input_adv</div>
<div>Feb 3 07:02:49 vsa-0000004dc-vc-0 heartbeat: [1018]: debug: MSG[1] : [origin=do_election_vote]</div><div>Feb 3 07:02:49 vsa-0000004dc-vc-0 crmd: [1259]: debug: debug3: crmd_ha_msg_filter: Triggering FSA: crmd_ha_msg_filter</div>
<div>Feb 3 07:02:49 vsa-0000004dc-vc-0 heartbeat: [1018]: debug: MSG[2] : [t=crmd]</div><div>Feb 3 07:02:49 vsa-0000004dc-vc-0 crmd: [1259]: debug: debug2: crm_fsa_trigger: Invoked (queue len: 2)</div><div>Feb 3 07:02:49 vsa-0000004dc-vc-0 heartbeat: [1018]: debug: MSG[3] : [version=3.0.1]</div>
<div>Feb 3 07:02:49 vsa-0000004dc-vc-0 crmd: [1259]: debug: debug2: s_crmd_fsa: FSA invoked with Cause: C_FSA_INTERNAL#011State: S_ELECTION</div><div>Feb 3 07:02:49 vsa-0000004dc-vc-0 heartbeat: [1018]: debug: MSG[4] : [subt=request]</div>
<div>Feb 3 07:02:49 vsa-0000004dc-vc-0 crmd: [1259]: debug: debug2: s_crmd_fsa: Checking messages (2 remaining)</div><div>Feb 3 07:02:49 vsa-0000004dc-vc-0 heartbeat: [1018]: debug: MSG[5] : [reference=vote-crmd-1328245369-3]</div>
<div>Feb 3 07:02:49 vsa-0000004dc-vc-0 crmd: [1259]: debug: debug2: get_message: Processing input 10</div><div>Feb 3 07:02:49 vsa-0000004dc-vc-0 heartbeat: [1018]: debug: MSG[6] : [crm_task=vote]</div><div>Feb 3 07:02:49 vsa-0000004dc-vc-0 crmd: [1259]: debug: debug2: log_fsa_input: Processing queued input 10</div>
<div>Feb 3 07:02:49 vsa-0000004dc-vc-0 heartbeat: [1018]: debug: MSG[7] : [crm_sys_to=crmd]</div><div>Feb 3 07:02:49 vsa-0000004dc-vc-0 crmd: [1259]: debug: debug3: log_fsa_input: FSA processing XML message from route_message</div>
<div>Feb 3 07:02:49 vsa-0000004dc-vc-0 heartbeat: [1018]: debug: MSG[8] : [crm_sys_from=crmd]</div><div>Feb 3 07:02:49 vsa-0000004dc-vc-0 crmd: [1259]: debug: debug3: print_xml_formatted: log_fsa_input: FSA message data: NULL</div>
<div>Feb 3 07:02:49 vsa-0000004dc-vc-0 heartbeat: [1018]: debug: MSG[9] : [election-owner=00001244-1244-0000-2b91-000000000000]</div><div>Feb 3 07:02:49 vsa-0000004dc-vc-0 crmd: [1259]: debug: s_crmd_fsa: Processing I_JOIN_OFFER: [ state=S_ELECTION cause=C_HA_MESSAGE origin=route_message ]</div>
<div>Feb 3 07:02:49 vsa-0000004dc-vc-0 heartbeat: [1018]: debug: MSG[10] : [election-id=2]</div><div>Feb 3 07:02:49 vsa-0000004dc-vc-0 crmd: [1259]: debug: do_fsa_action: actions:trace: #011// A_WARN</div><div>Feb 3 07:02:49 vsa-0000004dc-vc-0 heartbeat: [1018]: debug: MSG[11] : [oseq=1]</div>
<div>Feb 3 07:02:49 vsa-0000004dc-vc-0 crmd: [1259]: WARN: do_log: FSA: Input I_JOIN_OFFER from route_message() received in state S_ELECTION</div><div>Feb 3 07:02:49 vsa-0000004dc-vc-0 heartbeat: [1018]: debug: MSG[12] : [from_id=crmd]</div>
<div>Feb 3 07:02:49 vsa-0000004dc-vc-0 crmd: [1259]: debug: debug2: s_crmd_fsa: actions:trace: #011// FSA input: State=S_ELECTION #011Cause=C_HA_MESSAGE #011Input=I_JOIN_OFFER #011Origin=route_message() #011id=10</div><div>
Feb 3 07:02:49 vsa-0000004dc-vc-0 heartbeat: [1018]: debug: MSG[13] : [to_id=crmd]</div><div>Feb 3 07:02:49 vsa-0000004dc-vc-0 crmd: [1259]: debug: do_fsa_action: actions:trace: #011// A_ELECTION_VOTE</div><div>Feb 3 07:02:49 vsa-0000004dc-vc-0 heartbeat: [1018]: debug: process_clustermsg: node [vsa-0000004dc-vc-0]</div>
<div>Feb 3 07:02:49 vsa-0000004dc-vc-0 crmd: [1259]: debug: debug3: log_data_element: send_ha_message: HA[outbound] <create_request_adv origin="do_election_vote" t="crmd" version="3.0.1" subt="request" reference="vote-crmd-1328245369-4" crm_task="vote" crm_sys_to="crmd" crm_sys_from="crmd" election-owner="00001244-1244-0000-2b91-000000000000" election-id="3" /></div>
<div>Feb 3 07:02:49 vsa-0000004dc-vc-0 heartbeat: [1018]: debug: #011return TRUE;</div><div>Feb 3 07:02:49 vsa-0000004dc-vc-0 crmd: [1259]: debug: do_election_vote: Started election 3</div><div>Feb 3 07:02:49 vsa-0000004dc-vc-0 heartbeat: [1018]: debug: }/*ProcessAnAPIRequest*/;</div>
<div>Feb 3 07:02:49 vsa-0000004dc-vc-0 crmd: [1259]: debug: crm_timer_start: Election Timeout (I_ELECTION_DC:120000ms) already running: src=17</div><div>Feb 3 07:02:49 vsa-0000004dc-vc-0 heartbeat: [1018]: debug: return 1;</div>
<div>Feb 3 07:02:49 vsa-0000004dc-vc-0 crmd: [1259]: debug: debug2: s_crmd_fsa: Checking messages (1 remaining)</div><div>Feb 3 07:02:49 vsa-0000004dc-vc-0 heartbeat: [1018]: debug: }/*APIclients_input_dispatch*/;</div>
<div>Feb 3 07:02:49 vsa-0000004dc-vc-0 crmd: [1259]: debug: debug2: get_message: Processing input 11</div><div>Feb 3 07:02:49 vsa-0000004dc-vc-0 crmd: [1259]: debug: debug2: log_fsa_input: Processing queued input 11</div>
<div>Feb 3 07:02:49 vsa-0000004dc-vc-0 crmd: [1259]: debug: debug3: log_fsa_input: FSA processing XML message from handle_request</div><div>Feb 3 07:02:49 vsa-0000004dc-vc-0 crmd: [1259]: debug: debug3: print_xml_formatted: log_fsa_input: FSA message data: NULL</div>
<div>Feb 3 07:02:49 vsa-0000004dc-vc-0 crmd: [1259]: debug: debug2: s_crmd_fsa: actions:trace: #011// FSA input: State=S_ELECTION #011Cause=C_HA_MESSAGE #011Input=I_NULL #011Origin=handle_request() #011id=11</div><div>Feb 3 07:02:49 vsa-0000004dc-vc-0 crmd: [1259]: debug: do_fsa_action: actions:trace: #011// A_ELECTION_COUNT</div>
<div>Feb 3 07:02:49 vsa-0000004dc-vc-0 crmd: [1259]: debug: do_election_count_vote: Created voted hash</div><div>Feb 3 07:02:49 vsa-0000004dc-vc-0 crmd: [1259]: debug: debug3: do_election_count_vote: Election 2 (current: 3, owner: 00001244-1244-0000-2b91-000000000000): Processed vote from vsa-0000004dc-vc-0 (Superceeded)</div>
<div>Feb 3 07:02:49 vsa-0000004dc-vc-0 crmd: [1259]: debug: do_fsa_action: actions:trace: #011// A_ELECTION_CHECK</div><div>Feb 3 07:02:49 vsa-0000004dc-vc-0 crmd: [1259]: debug: do_election_check: Still waiting on 2 non-votes (2 total)</div>
<div>Feb 3 07:02:49 vsa-0000004dc-vc-0 crmd: [1259]: debug: debug2: s_crmd_fsa: Exiting the FSA</div><div>Feb 3 07:02:49 vsa-0000004dc-vc-0 crmd: [1259]: debug: debug2: crm_fsa_trigger: Exited (queue len: 0)</div><div>
Feb 3 07:02:49 vsa-0000004dc-vc-0 heartbeat: [1018]: debug: APIclients_input_dispatch() {</div><div>Feb 3 07:02:49 vsa-0000004dc-vc-0 crmd: [1259]: debug: debug3: ha_msg_dispatch: Invoked</div><div>Feb 3 07:02:49 vsa-0000004dc-vc-0 heartbeat: [1018]: debug: ProcessAnAPIRequest() {</div>
<div>Feb 3 07:02:49 vsa-0000004dc-vc-0 crmd: [1259]: debug: debug2: crmd_ha_msg_callback: HA[inbound]: vote from vsa-0000004dc-vc-0</div><div>Feb 3 07:02:49 vsa-0000004dc-vc-0 heartbeat: [1018]: debug: Sending API message to cluster...</div>
<div>Feb 3 07:02:49 vsa-0000004dc-vc-0 crmd: [1259]: debug: debug3: relay_message: Routing message vote-crmd-1328245369-4</div><div>Feb 3 07:02:49 vsa-0000004dc-vc-0 heartbeat: [1018]: debug: MSG: Dumping message with 14 fields</div>
<div>Feb 3 07:02:49 vsa-0000004dc-vc-0 crmd: [1259]: debug: debug3: relay_message: Router result: Message result: CRMd process</div><div>Feb 3 07:02:49 vsa-0000004dc-vc-0 heartbeat: [1018]: debug: MSG[0] : [__name__=create_request_adv]</div>
<div>Feb 3 07:02:49 vsa-0000004dc-vc-0 crmd: [1259]: debug: debug3: log_data_element: relay_message: router.log <create_request_adv origin="do_election_vote" t="crmd" version="3.0.1" subt="request" reference="vote-crmd-1328245369-4" crm_task="vote" crm_sys_to="crmd" crm_sys_from="crmd" election-owner="00001244-1244-0000-2b91-000000000000" election-id="3" oseq="2" from_id="crmd" to_id="crmd" client_gen="4" src="vsa-0000004dc-vc-0" seq="30" hg="4f2a2274" ts="4f2b6a79" ld="2.89 0.85 0.29 2/105 1463" ttl="3" auth="1 51ab53d3e8bcd21bf244b526b9d9e00ff229781b" /></div>
<div>Feb 3 07:02:49 vsa-0000004dc-vc-0 heartbeat: [1018]: debug: MSG[1] : [origin=do_election_vote]</div><div>Feb 3 07:02:49 vsa-0000004dc-vc-0 crmd: [1259]: debug: debug2: register_fsa_input_adv: handle_request appended FSA input 12 (I_NULL) (cause=C_HA_MESSAGE) with data</div>
<div>Feb 3 07:02:49 vsa-0000004dc-vc-0 heartbeat: [1018]: debug: MSG[2] : [t=crmd]</div><div>Feb 3 07:02:49 vsa-0000004dc-vc-0 crmd: [1259]: debug: debug3: register_fsa_input_adv: Adding actions 0000000200000400 to input</div>
<div>Feb 3 07:02:49 vsa-0000004dc-vc-0 heartbeat: [1018]: debug: MSG[3] : [version=3.0.1]</div><div>Feb 3 07:02:49 vsa-0000004dc-vc-0 crmd: [1259]: debug: debug3: register_fsa_input_adv: Copying C_HA_MESSAGE data from handle_request as a HA msg</div>
<div>Feb 3 07:02:49 vsa-0000004dc-vc-0 heartbeat: [1018]: debug: MSG[4] : [subt=request]</div><div>Feb 3 07:02:49 vsa-0000004dc-vc-0 crmd: [1259]: debug: debug2: register_fsa_input_adv: Queue len: 1</div><div>Feb 3 07:02:49 vsa-0000004dc-vc-0 heartbeat: [1018]: debug: MSG[5] : [reference=vote-crmd-1328245369-4]</div>
<div>Feb 3 07:02:49 vsa-0000004dc-vc-0 crmd: [1259]: debug: debug3: register_fsa_input_adv: Triggering FSA: register_fsa_input_adv</div><div>Feb 3 07:02:49 vsa-0000004dc-vc-0 heartbeat: [1018]: debug: MSG[6] : [crm_task=vote]</div>
<div>Feb 3 07:02:49 vsa-0000004dc-vc-0 crmd: [1259]: debug: debug3: crmd_ha_msg_filter: Triggering FSA: crmd_ha_msg_filter</div><div>Feb 3 07:02:49 vsa-0000004dc-vc-0 heartbeat: [1018]: debug: MSG[7] : [crm_sys_to=crmd]</div>
<div>Feb 3 07:02:49 vsa-0000004dc-vc-0 crmd: [1259]: debug: debug2: crm_fsa_trigger: Invoked (queue len: 1)</div><div>Feb 3 07:02:49 vsa-0000004dc-vc-0 heartbeat: [1018]: debug: MSG[8] : [crm_sys_from=crmd]</div><div>Feb 3 07:02:49 vsa-0000004dc-vc-0 crmd: [1259]: debug: debug2: s_crmd_fsa: FSA invoked with Cause: C_FSA_INTERNAL#011State: S_ELECTION</div>
<div>Feb 3 07:02:49 vsa-0000004dc-vc-0 heartbeat: [1018]: debug: MSG[9] : [election-owner=00001244-1244-0000-2b91-000000000000]</div><div>Feb 3 07:02:49 vsa-0000004dc-vc-0 crmd: [1259]: debug: debug2: s_crmd_fsa: Checking messages (1 remaining)</div>
<div>Feb 3 07:02:49 vsa-0000004dc-vc-0 heartbeat: [1018]: debug: MSG[10] : [election-id=3]</div><div>Feb 3 07:02:49 vsa-0000004dc-vc-0 crmd: [1259]: debug: debug2: get_message: Processing input 12</div><div>Feb 3 07:02:49 vsa-0000004dc-vc-0 heartbeat: [1018]: debug: MSG[11] : [oseq=2]</div>
<div>Feb 3 07:02:49 vsa-0000004dc-vc-0 crmd: [1259]: debug: debug2: log_fsa_input: Processing queued input 12</div><div>Feb 3 07:02:49 vsa-0000004dc-vc-0 heartbeat: [1018]: debug: MSG[12] : [from_id=crmd]</div><div>Feb 3 07:02:49 vsa-0000004dc-vc-0 crmd: [1259]: debug: debug3: log_fsa_input: FSA processing XML message from handle_request</div>
<div>Feb 3 07:02:49 vsa-0000004dc-vc-0 heartbeat: [1018]: debug: MSG[13] : [to_id=crmd]</div><div>Feb 3 07:02:49 vsa-0000004dc-vc-0 crmd: [1259]: debug: debug3: print_xml_formatted: log_fsa_input: FSA message data: NULL</div>
<div>Feb 3 07:02:49 vsa-0000004dc-vc-0 heartbeat: [1018]: debug: process_clustermsg: node [vsa-0000004dc-vc-0]</div><div>Feb 3 07:02:49 vsa-0000004dc-vc-0 crmd: [1259]: debug: debug2: s_crmd_fsa: actions:trace: #011// FSA input: State=S_ELECTION #011Cause=C_HA_MESSAGE #011Input=I_NULL #011Origin=handle_request() #011id=12</div>
<div>Feb 3 07:02:49 vsa-0000004dc-vc-0 heartbeat: [1018]: debug: #011return TRUE;</div><div>Feb 3 07:02:49 vsa-0000004dc-vc-0 crmd: [1259]: debug: do_fsa_action: actions:trace: #011// A_ELECTION_COUNT</div><div>Feb 3 07:02:49 vsa-0000004dc-vc-0 heartbeat: [1018]: debug: }/*ProcessAnAPIRequest*/;</div>
<div>Feb 3 07:02:49 vsa-0000004dc-vc-0 crmd: [1259]: debug: do_election_count_vote: Election 3 (current: 3, owner: 00001244-1244-0000-2b91-000000000000): Processed vote from vsa-0000004dc-vc-0 (Recorded)</div><div>Feb 3 07:02:49 vsa-0000004dc-vc-0 heartbeat: [1018]: debug: return 1;</div>
<div>Feb 3 07:02:49 vsa-0000004dc-vc-0 crmd: [1259]: debug: do_fsa_action: actions:trace: #011// A_ELECTION_CHECK</div><div>Feb 3 07:02:49 vsa-0000004dc-vc-0 heartbeat: [1018]: debug: }/*APIclients_input_dispatch*/;</div>
<div>Feb 3 07:02:49 vsa-0000004dc-vc-0 crmd: [1259]: debug: do_election_check: Still waiting on 1 non-votes (2 total)</div><div>Feb 3 07:02:49 vsa-0000004dc-vc-0 crmd: [1259]: debug: debug2: s_crmd_fsa: Exiting the FSA</div>
<div>Feb 3 07:02:49 vsa-0000004dc-vc-0 crmd: [1259]: debug: debug2: crm_fsa_trigger: Exited (queue len: 0)</div><div>Feb 3 07:02:50 vsa-0000004dc-vc-0 heartbeat: [1018]: debug: hb_send_local_status() {</div><div>Feb 3 07:02:50 vsa-0000004dc-vc-0 cib: [1255]: debug: debug2: cib_process_request: Processing local message (vsa-0000004dc-vc-0) for master...</div>
<div>Feb 3 07:02:50 vsa-0000004dc-vc-0 crmd: [1259]: debug: debug3: ha_msg_dispatch: Invoked</div><div>Feb 3 07:02:50 vsa-0000004dc-vc-0 heartbeat: [1018]: debug: PID 1018: Sending local status curnode = 638e58 status: active</div>
<div>Feb 3 07:02:50 vsa-0000004dc-vc-0 cib: [1255]: debug: debug2: parse_local_options: Processing locally scoped cib_slave op from crmd</div><div>Feb 3 07:02:50 vsa-0000004dc-vc-0 crmd: [1259]: debug: debug2: crmd_ha_msg_callback: HA[inbound]: vote from vsa-0000004dc-vc-1</div>
<div>Feb 3 07:02:50 vsa-0000004dc-vc-0 heartbeat: [1018]: debug: process_clustermsg: node [vsa-0000004dc-vc-0]</div><div>Feb 3 07:02:50 vsa-0000004dc-vc-0 cib: [1255]: debug: debug3: cib_process_request: Finished determining processing actions</div>
<div>Feb 3 07:02:50 vsa-0000004dc-vc-0 crmd: [1259]: debug: debug3: relay_message: Routing message vote-crmd-1328245369-6</div><div>Feb 3 07:02:50 vsa-0000004dc-vc-0 heartbeat: [1018]: debug: }/*hb_send_local_status*/;</div>
<div>Feb 3 07:02:50 vsa-0000004dc-vc-0 cib: [1255]: debug: debug2: cib_process_readwrite: Processing "cib_slave" event</div><div>Feb 3 07:02:50 vsa-0000004dc-vc-0 crmd: [1259]: debug: debug3: relay_message: Router result: Message result: CRMd process</div>
<div>Feb 3 07:02:50 vsa-0000004dc-vc-0 heartbeat: [1018]: debug: read_child_dispatch() {</div><div>Feb 3 07:02:50 vsa-0000004dc-vc-0 cib: [1255]: debug: debug2: cib_process_request: Operation complete: op cib_slave for section 'all' (origin=local/crmd/6, version=1.2.0): ok (rc=0)</div>
<div>Feb 3 07:02:50 vsa-0000004dc-vc-0 crmd: [1259]: debug: debug3: log_data_element: relay_message: router.log <create_request_adv origin="do_election_vote" t="crmd" version="3.0.1" subt="request" reference="vote-crmd-1328245369-6" crm_task="vote" crm_sys_to="crmd" crm_sys_from="crmd" election-owner="00001244-1244-0001-2b91-000000000001" election-id="3" oseq="2" from_id="crmd" to_id="crmd" client_gen="4" src="vsa-0000004dc-vc-1" seq="31" hg="4f2a227c" ts="4f2b6a7a" ld="3.01 0.88 0.30 5/106 1372" ttl="3" auth="1 27a5f24827f1ca0d08946dea098d0a43404f341a" /></div>
<div>Feb 3 07:02:50 vsa-0000004dc-vc-0 heartbeat: [1018]: debug: Packet authenticated</div><div>Feb 3 07:02:50 vsa-0000004dc-vc-0 cib: [1255]: debug: debug3: cib_process_request: processing response cases</div><div>Feb 3 07:02:50 vsa-0000004dc-vc-0 crmd: [1259]: debug: debug2: register_fsa_input_adv: handle_request appended FSA input 13 (I_NULL) (cause=C_HA_MESSAGE) with data</div>
<div>Feb 3 07:02:50 vsa-0000004dc-vc-0 heartbeat: [1018]: debug: process_clustermsg: node [vsa-0000004dc-vc-1]</div><div>Feb 3 07:02:50 vsa-0000004dc-vc-0 cib: [1255]: debug: debug2: do_local_notify: Performing notification</div>
<div>Feb 3 07:02:50 vsa-0000004dc-vc-0 crmd: [1259]: debug: debug3: register_fsa_input_adv: Adding actions 0000000200000400 to input</div><div>Feb 3 07:02:50 vsa-0000004dc-vc-0 heartbeat: [1018]: debug: }/*read_child_dispatch*/;</div>
<div>Feb 3 07:02:50 vsa-0000004dc-vc-0 cib: [1255]: debug: debug3: do_local_notify: Sending callback to request originator</div><div>Feb 3 07:02:50 vsa-0000004dc-vc-0 crmd: [1259]: debug: debug3: register_fsa_input_adv: Copying C_HA_MESSAGE data from handle_request as a HA msg</div>
<div>Feb 3 07:02:50 vsa-0000004dc-vc-0 heartbeat: [1018]: debug: read_child_dispatch() {</div><div>Feb 3 07:02:50 vsa-0000004dc-vc-0 cib: [1255]: debug: debug2: do_local_notify: Sending an a-sync response to crmd</div><div>
Feb 3 07:02:50 vsa-0000004dc-vc-0 crmd: [1259]: debug: debug2: register_fsa_input_adv: Queue len: 1</div><div>Feb 3 07:02:50 vsa-0000004dc-vc-0 heartbeat: [1018]: debug: Packet authenticated</div><div>Feb 3 07:02:50 vsa-0000004dc-vc-0 cib: [1255]: debug: debug3: send_via_callback_channel: Delivering msg 0x2097a20 to client e718aaee-f618-4089-a952-11ad7da65c09</div>
<div>Feb 3 07:02:50 vsa-0000004dc-vc-0 crmd: [1259]: debug: debug3: register_fsa_input_adv: Triggering FSA: register_fsa_input_adv</div><div>Feb 3 07:02:50 vsa-0000004dc-vc-0 heartbeat: [1018]: debug: process_clustermsg: node [vsa-0000004dc-vc-1]</div>
<div>Feb 3 07:02:50 vsa-0000004dc-vc-0 cib: [1255]: debug: debug3: send_via_callback_channel: Delivering reply to client e718aaee-f618-4089-a952-11ad7da65c09 (cib_callback)</div><div>Feb 3 07:02:50 vsa-0000004dc-vc-0 crmd: [1259]: debug: debug3: crmd_ha_msg_filter: Triggering FSA: crmd_ha_msg_filter</div>
<div>Feb 3 07:02:50 vsa-0000004dc-vc-0 heartbeat: [1018]: debug: }/*read_child_dispatch*/;</div><div>Feb 3 07:02:50 vsa-0000004dc-vc-0 cib: [1255]: debug: debug2: cib_process_request: Completed slave update</div><div>Feb 3 07:02:50 vsa-0000004dc-vc-0 crmd: [1259]: debug: debug2: crmd_ha_msg_callback: HA[inbound]: join_request from vsa-0000004dc-vc-1</div>
<div>Feb 3 07:02:50 vsa-0000004dc-vc-0 heartbeat: [1018]: debug: read_child_dispatch() {</div><div>Feb 3 07:02:50 vsa-0000004dc-vc-0 cib: [1255]: debug: debug2: cib_process_request: Processing local message (vsa-0000004dc-vc-0) for master...</div>
<div>Feb 3 07:02:50 vsa-0000004dc-vc-0 crmd: [1259]: debug: debug2: crmd_ha_msg_callback: HA[inbound]: vote from vsa-0000004dc-vc-1</div><div>Feb 3 07:02:50 vsa-0000004dc-vc-0 heartbeat: [1018]: debug: Packet authenticated</div>
<div>Feb 3 07:02:50 vsa-0000004dc-vc-0 cib: [1255]: debug: debug2: parse_local_options: Processing locally scoped cib_slave op from crmd</div><div>Feb 3 07:02:50 vsa-0000004dc-vc-0 crmd: [1259]: debug: debug3: relay_message: Routing message vote-crmd-1328245370-8</div>
<div>Feb 3 07:02:50 vsa-0000004dc-vc-0 heartbeat: [1018]: debug: process_clustermsg: node [vsa-0000004dc-vc-1]</div><div>Feb 3 07:02:50 vsa-0000004dc-vc-0 cib: [1255]: debug: debug3: cib_process_request: Finished determining processing actions</div>
<div>Feb 3 07:02:50 vsa-0000004dc-vc-0 crmd: [1259]: debug: debug3: relay_message: Router result: Message result: CRMd process</div><div>Feb 3 07:02:50 vsa-0000004dc-vc-0 heartbeat: [1018]: debug: process_clustermsg: node [vsa-0000004dc-vc-0]</div>
<div>Feb 3 07:02:50 vsa-0000004dc-vc-0 cib: [1255]: debug: debug2: cib_process_readwrite: Processing "cib_slave" event</div><div>Feb 3 07:02:50 vsa-0000004dc-vc-0 crmd: [1259]: debug: debug3: log_data_element: relay_message: router.log <create_request_adv origin="do_election_vote" t="crmd" version="3.0.1" subt="request" reference="vote-crmd-1328245370-8" crm_task="vote" crm_sys_to="crmd" crm_sys_from="crmd" election-owner="00001244-1244-0001-2b91-000000000001" election-id="4" oseq="4" from_id="crmd" to_id="crmd" client_gen="4" src="vsa-0000004dc-vc-1" seq="33" hg="4f2a227c" ts="4f2b6a7a" ld="3.01 0.88 0.30 4/106 1372" ttl="3" auth="1 4cb5c076b4cd9b89a4c5daa0866b59ccb8158a58" /></div>
<div>Feb 3 07:02:50 vsa-0000004dc-vc-0 heartbeat: [1018]: debug: }/*read_child_dispatch*/;</div><div>Feb 3 07:02:50 vsa-0000004dc-vc-0 cib: [1255]: debug: debug2: cib_process_request: Operation complete: op cib_slave for section 'all' (origin=local/crmd/7, version=1.2.0): ok (rc=0)</div>
<div>Feb 3 07:02:50 vsa-0000004dc-vc-0 crmd: [1259]: debug: debug2: register_fsa_input_adv: handle_request appended FSA input 14 (I_NULL) (cause=C_HA_MESSAGE) with data</div><div>Feb 3 07:02:50 vsa-0000004dc-vc-0 heartbeat: [1018]: debug: read_child_dispatch() {</div>
<div>Feb 3 07:02:50 vsa-0000004dc-vc-0 cib: [1255]: debug: debug3: cib_process_request: processing response cases</div><div>Feb 3 07:02:50 vsa-0000004dc-vc-0 crmd: [1259]: debug: debug3: register_fsa_input_adv: Adding actions 0000000200000400 to input</div>
<div>Feb 3 07:02:50 vsa-0000004dc-vc-0 heartbeat: [1018]: debug: Packet authenticated</div><div>Feb 3 07:02:50 vsa-0000004dc-vc-0 cib: [1255]: debug: debug2: do_local_notify: Performing notification</div><div>Feb 3 07:02:50 vsa-0000004dc-vc-0 crmd: [1259]: debug: debug3: register_fsa_input_adv: Copying C_HA_MESSAGE data from handle_request as a HA msg</div>
<div>Feb 3 07:02:50 vsa-0000004dc-vc-0 heartbeat: [1018]: debug: process_clustermsg: node [vsa-0000004dc-vc-1]</div><div>Feb 3 07:02:50 vsa-0000004dc-vc-0 cib: [1255]: debug: debug3: do_local_notify: Sending callback to request originator</div>
<div>Feb 3 07:02:50 vsa-0000004dc-vc-0 crmd: [1259]: debug: debug2: register_fsa_input_adv: Queue len: 2</div><div>Feb 3 07:02:50 vsa-0000004dc-vc-0 heartbeat: [1018]: debug: }/*read_child_dispatch*/;</div><div>Feb 3 07:02:50 vsa-0000004dc-vc-0 cib: [1255]: debug: debug2: do_local_notify: Sending an a-sync response to crmd</div>
<div>Feb 3 07:02:50 vsa-0000004dc-vc-0 crmd: [1259]: debug: debug3: register_fsa_input_adv: Triggering FSA: register_fsa_input_adv</div><div>Feb 3 07:02:50 vsa-0000004dc-vc-0 heartbeat: [1018]: debug: read_child_dispatch() {</div>
<div>Feb 3 07:02:50 vsa-0000004dc-vc-0 cib: [1255]: debug: debug3: send_via_callback_channel: Delivering msg 0x2097a20 to client e718aaee-f618-4089-a952-11ad7da65c09</div><div>Feb 3 07:02:50 vsa-0000004dc-vc-0 crmd: [1259]: debug: debug3: crmd_ha_msg_filter: Triggering FSA: crmd_ha_msg_filter</div>
<div>Feb 3 07:02:50 vsa-0000004dc-vc-0 heartbeat: [1018]: debug: Packet authenticated</div><div>Feb 3 07:02:50 vsa-0000004dc-vc-0 cib: [1255]: debug: debug3: send_via_callback_channel: Delivering reply to client e718aaee-f618-4089-a952-11ad7da65c09 (cib_callback)</div>
<div>Feb 3 07:02:50 vsa-0000004dc-vc-0 crmd: [1259]: debug: debug2: crm_fsa_trigger: Invoked (queue len: 2)</div><div>Feb 3 07:02:50 vsa-0000004dc-vc-0 heartbeat: [1018]: debug: process_clustermsg: node [vsa-0000004dc-vc-1]</div>
<div>Feb 3 07:02:50 vsa-0000004dc-vc-0 cib: [1255]: debug: debug2: cib_process_request: Completed slave update</div><div>Feb 3 07:02:50 vsa-0000004dc-vc-0 crmd: [1259]: debug: debug2: s_crmd_fsa: FSA invoked with Cause: C_FSA_INTERNAL#011State: S_ELECTION</div>
<div>Feb 3 07:02:50 vsa-0000004dc-vc-0 heartbeat: [1018]: debug: }/*read_child_dispatch*/;</div><div>Feb 3 07:02:50 vsa-0000004dc-vc-0 cib: [1255]: debug: debug2: cib_process_request: Processing local message (vsa-0000004dc-vc-0) for master...</div>
<div>Feb 3 07:02:50 vsa-0000004dc-vc-0 crmd: [1259]: debug: debug2: s_crmd_fsa: Checking messages (2 remaining)</div><div>Feb 3 07:02:50 vsa-0000004dc-vc-0 heartbeat: [1018]: debug: read_child_dispatch() {</div><div>Feb 3 07:02:50 vsa-0000004dc-vc-0 cib: [1255]: debug: debug2: parse_local_options: Processing locally scoped cib_slave op from crmd</div>
<div>Feb 3 07:02:50 vsa-0000004dc-vc-0 crmd: [1259]: debug: debug2: get_message: Processing input 13</div><div>Feb 3 07:02:50 vsa-0000004dc-vc-0 heartbeat: [1018]: debug: Packet authenticated</div><div>Feb 3 07:02:50 vsa-0000004dc-vc-0 cib: [1255]: debug: debug3: cib_process_request: Finished determining processing actions</div>
<div>Feb 3 07:02:50 vsa-0000004dc-vc-0 crmd: [1259]: debug: debug2: log_fsa_input: Processing queued input 13</div><div>Feb 3 07:02:50 vsa-0000004dc-vc-0 heartbeat: [1018]: debug: process_clustermsg: node [vsa-0000004dc-vc-1]</div>
<div>Feb 3 07:02:50 vsa-0000004dc-vc-0 cib: [1255]: debug: debug2: cib_process_readwrite: Processing "cib_slave" event</div><div>Feb 3 07:02:50 vsa-0000004dc-vc-0 crmd: [1259]: debug: debug3: log_fsa_input: FSA processing XML message from handle_request</div>
<div>Feb 3 07:02:50 vsa-0000004dc-vc-0 heartbeat: [1018]: debug: }/*read_child_dispatch*/;</div><div>Feb 3 07:02:50 vsa-0000004dc-vc-0 cib: [1255]: debug: debug2: cib_process_request: Operation complete: op cib_slave for section 'all' (origin=local/crmd/8, version=1.2.0): ok (rc=0)</div>
<div>Feb 3 07:02:50 vsa-0000004dc-vc-0 crmd: [1259]: debug: debug3: print_xml_formatted: log_fsa_input: FSA message data: NULL</div><div>Feb 3 07:02:50 vsa-0000004dc-vc-0 heartbeat: [1018]: debug: read_child_dispatch() {</div>
<div>Feb 3 07:02:50 vsa-0000004dc-vc-0 cib: [1255]: debug: debug3: cib_process_request: processing response cases</div><div>Feb 3 07:02:50 vsa-0000004dc-vc-0 crmd: [1259]: debug: debug2: s_crmd_fsa: actions:trace: #011// FSA input: State=S_ELECTION #011Cause=C_HA_MESSAGE #011Input=I_NULL #011Origin=handle_request() #011id=13</div>
<div>Feb 3 07:02:50 vsa-0000004dc-vc-0 heartbeat: [1018]: debug: Packet authenticated</div><div>Feb 3 07:02:50 vsa-0000004dc-vc-0 cib: [1255]: debug: debug2: do_local_notify: Performing notification</div><div>Feb 3 07:02:50 vsa-0000004dc-vc-0 crmd: [1259]: debug: do_fsa_action: actions:trace: #011// A_ELECTION_COUNT</div>
<div>Feb 3 07:02:50 vsa-0000004dc-vc-0 heartbeat: [1018]: debug: process_clustermsg: node [vsa-0000004dc-vc-1]</div><div>Feb 3 07:02:50 vsa-0000004dc-vc-0 cib: [1255]: debug: debug3: do_local_notify: Sending callback to request originator</div>
<div>Feb 3 07:02:50 vsa-0000004dc-vc-0 crmd: [1259]: debug: debug3: compare_version: 3.0.1 == 3.0.1 (4)</div><div>Feb 3 07:02:50 vsa-0000004dc-vc-0 heartbeat: [1018]: debug: }/*read_child_dispatch*/;</div><div>Feb 3 07:02:50 vsa-0000004dc-vc-0 cib: [1255]: debug: debug2: do_local_notify: Sending an a-sync response to crmd</div>
<div>Feb 3 07:02:50 vsa-0000004dc-vc-0 crmd: [1259]: debug: debug3: compare_version: 3.0.1 == 3.0.1 (4)</div><div>Feb 3 07:02:50 vsa-0000004dc-vc-0 heartbeat: [1018]: debug: read_child_dispatch() {</div><div>Feb 3 07:02:50 vsa-0000004dc-vc-0 cib: [1255]: debug: debug3: send_via_callback_channel: Delivering msg 0x2097a20 to client e718aaee-f618-4089-a952-11ad7da65c09</div>
<div>Feb 3 07:02:50 vsa-0000004dc-vc-0 crmd: [1259]: debug: do_election_count_vote: Election 3 (owner: 00001244-1244-0001-2b91-000000000001) lost: vote from vsa-0000004dc-vc-1 (Age)</div><div>Feb 3 07:02:50 vsa-0000004dc-vc-0 heartbeat: [1018]: debug: Packet authenticated</div>
<div>Feb 3 07:02:50 vsa-0000004dc-vc-0 cib: [1255]: debug: debug3: send_via_callback_channel: Delivering reply to client e718aaee-f618-4089-a952-11ad7da65c09 (cib_callback)</div><div>Feb 3 07:02:50 vsa-0000004dc-vc-0 crmd: [1259]: debug: debug2: crm_timer_stop: Stopping Election Timeout (I_ELECTION_DC:120000ms), src=17</div>
<div>Feb 3 07:02:50 vsa-0000004dc-vc-0 heartbeat: [1018]: debug: process_clustermsg: node [vsa-0000004dc-vc-1]</div><div>Feb 3 07:02:50 vsa-0000004dc-vc-0 cib: [1255]: debug: debug2: cib_process_request: Completed slave update</div>
<div>Feb 3 07:02:50 vsa-0000004dc-vc-0 crmd: [1259]: debug: debug3: do_election_count_vote: We werent the DC anyway</div><div>Feb 3 07:02:50 vsa-0000004dc-vc-0 heartbeat: [1018]: debug: }/*read_child_dispatch*/;</div><div>
Feb 3 07:02:50 vsa-0000004dc-vc-0 cib: [1255]: debug: cib_common_callback_worker: Setting cib_diff_notify callbacks for 1259 (e718aaee-f618-4089-a952-11ad7da65c09): off</div><div>Feb 3 07:02:50 vsa-0000004dc-vc-0 crmd: [1259]: debug: debug2: register_fsa_input_adv: do_election_count_vote appended FSA input 15 (I_PENDING) (cause=C_FSA_INTERNAL) without data</div>
<div>Feb 3 07:02:50 vsa-0000004dc-vc-0 crmd: [1259]: debug: debug2: register_fsa_input_adv: Queue len: 2</div><div>Feb 3 07:02:50 vsa-0000004dc-vc-0 crmd: [1259]: debug: debug3: register_fsa_input_adv: Triggering FSA: register_fsa_input_adv</div>
<div>Feb 3 07:02:50 vsa-0000004dc-vc-0 crmd: [1259]: debug: debug3: log_data_element: send_ha_message: HA[outbound] <create_request_adv origin="do_election_count_vote" t="crmd" version="3.0.1" subt="request" reference="no-vote-crmd-1328245370-5" crm_task="no-vote" crm_sys_to="crmd" crm_sys_from="crmd" crm_host_to="vsa-0000004dc-vc-1" election-owner="00001244-1244-0001-2b91-000000000001" election-id="3" /></div>
<div>Feb 3 07:02:50 vsa-0000004dc-vc-0 crmd: [1259]: debug: debug3: cib_native_perform_op: Sending cib_slave message to CIB service</div><div>Feb 3 07:02:50 vsa-0000004dc-vc-0 crmd: [1259]: debug: debug3: cib_native_perform_op: Message sent</div>
<div>Feb 3 07:02:50 vsa-0000004dc-vc-0 crmd: [1259]: debug: debug3: cib_native_perform_op: Async call, returning</div><div>Feb 3 07:02:50 vsa-0000004dc-vc-0 heartbeat: [1018]: debug: APIclients_input_dispatch() {</div><div>
Feb 3 07:02:50 vsa-0000004dc-vc-0 crmd: [1259]: debug: do_fsa_action: actions:trace: #011// A_ELECTION_CHECK</div><div>Feb 3 07:02:50 vsa-0000004dc-vc-0 heartbeat: [1018]: debug: ProcessAnAPIRequest() {</div><div>Feb 3 07:02:50 vsa-0000004dc-vc-0 crmd: [1259]: debug: do_election_check: Still waiting on 1 non-votes (2 total)</div>
<div>Feb 3 07:02:50 vsa-0000004dc-vc-0 heartbeat: [1018]: debug: Sending API message to cluster...</div><div>Feb 3 07:02:50 vsa-0000004dc-vc-0 crmd: [1259]: debug: debug2: s_crmd_fsa: Checking messages (2 remaining)</div>
<div>Feb 3 07:02:50 vsa-0000004dc-vc-0 heartbeat: [1018]: debug: MSG: Dumping message with 16 fields</div><div>Feb 3 07:02:50 vsa-0000004dc-vc-0 crmd: [1259]: debug: debug2: get_message: Processing input 14</div><div>Feb 3 07:02:50 vsa-0000004dc-vc-0 heartbeat: [1018]: debug: MSG[0] : [__name__=create_request_adv]</div>
<div>Feb 3 07:02:50 vsa-0000004dc-vc-0 crmd: [1259]: debug: debug2: log_fsa_input: Processing queued input 14</div><div>Feb 3 07:02:50 vsa-0000004dc-vc-0 heartbeat: [1018]: debug: MSG[1] : [origin=do_election_count_vote]</div>
<div>Feb 3 07:02:50 vsa-0000004dc-vc-0 crmd: [1259]: debug: debug3: log_fsa_input: FSA processing XML message from handle_request</div><div>Feb 3 07:02:50 vsa-0000004dc-vc-0 heartbeat: [1018]: debug: MSG[2] : [t=crmd]</div>
<div>Feb 3 07:02:50 vsa-0000004dc-vc-0 crmd: [1259]: debug: debug3: print_xml_formatted: log_fsa_input: FSA message data: NULL</div><div>Feb 3 07:02:50 vsa-0000004dc-vc-0 heartbeat: [1018]: debug: MSG[3] : [version=3.0.1]</div>
<div>Feb 3 07:02:50 vsa-0000004dc-vc-0 crmd: [1259]: debug: debug2: s_crmd_fsa: actions:trace: #011// FSA input: State=S_ELECTION #011Cause=C_HA_MESSAGE #011Input=I_NULL #011Origin=handle_request() #011id=14</div><div>Feb 3 07:02:50 vsa-0000004dc-vc-0 heartbeat: [1018]: debug: MSG[4] : [subt=request]</div>
<div>Feb 3 07:02:50 vsa-0000004dc-vc-0 crmd: [1259]: debug: do_fsa_action: actions:trace: #011// A_ELECTION_COUNT</div><div>Feb 3 07:02:50 vsa-0000004dc-vc-0 heartbeat: [1018]: debug: MSG[5] : [reference=no-vote-crmd-1328245370-5]</div>
<div>Feb 3 07:02:50 vsa-0000004dc-vc-0 crmd: [1259]: debug: debug3: compare_version: 3.0.1 == 3.0.1 (4)</div><div>Feb 3 07:02:50 vsa-0000004dc-vc-0 heartbeat: [1018]: debug: MSG[6] : [crm_task=no-vote]</div><div>Feb 3 07:02:50 vsa-0000004dc-vc-0 crmd: [1259]: debug: debug3: compare_version: 3.0.1 == 3.0.1 (4)</div>
<div>Feb 3 07:02:50 vsa-0000004dc-vc-0 heartbeat: [1018]: debug: MSG[7] : [crm_sys_to=crmd]</div><div>Feb 3 07:02:50 vsa-0000004dc-vc-0 crmd: [1259]: debug: do_election_count_vote: Election 4 (owner: 00001244-1244-0001-2b91-000000000001) lost: vote from vsa-0000004dc-vc-1 (Age)</div>
<div>Feb 3 07:02:50 vsa-0000004dc-vc-0 heartbeat: [1018]: debug: MSG[8] : [crm_sys_from=crmd]</div><div>Feb 3 07:02:50 vsa-0000004dc-vc-0 crmd: [1259]: debug: debug2: crm_timer_stop: Election Timeout (I_ELECTION_DC:120000ms) already stopped</div>
<div>Feb 3 07:02:50 vsa-0000004dc-vc-0 heartbeat: [1018]: debug: MSG[9] : [crm_host_to=vsa-0000004dc-vc-1]</div><div>Feb 3 07:02:50 vsa-0000004dc-vc-0 crmd: [1259]: debug: debug3: do_election_count_vote: We werent the DC anyway</div>
<div>Feb 3 07:02:50 vsa-0000004dc-vc-0 heartbeat: [1018]: debug: MSG[10] : [election-owner=00001244-1244-0001-2b91-000000000001]</div><div>Feb 3 07:02:50 vsa-0000004dc-vc-0 crmd: [1259]: debug: debug2: register_fsa_input_adv: do_election_count_vote appended FSA input 16 (I_PENDING) (cause=C_FSA_INTERNAL) without data</div>
<div>Feb 3 07:02:50 vsa-0000004dc-vc-0 heartbeat: [1018]: debug: MSG[11] : [election-id=3]</div><div>Feb 3 07:02:50 vsa-0000004dc-vc-0 crmd: [1259]: debug: debug2: register_fsa_input_adv: Queue len: 2</div><div>Feb 3 07:02:50 vsa-0000004dc-vc-0 heartbeat: [1018]: debug: MSG[12] : [dest=vsa-0000004dc-vc-1]</div>
<div>Feb 3 07:02:50 vsa-0000004dc-vc-0 crmd: [1259]: debug: debug3: register_fsa_input_adv: Triggering FSA: register_fsa_input_adv</div><div>Feb 3 07:02:50 vsa-0000004dc-vc-0 heartbeat: [1018]: debug: MSG[13] : [oseq=2]</div>
<div>Feb 3 07:02:50 vsa-0000004dc-vc-0 crmd: [1259]: debug: debug3: log_data_element: send_ha_message: HA[outbound] <create_request_adv origin="do_election_count_vote" t="crmd" version="3.0.1" subt="request" reference="no-vote-crmd-1328245370-6" crm_task="no-vote" crm_sys_to="crmd" crm_sys_from="crmd" crm_host_to="vsa-0000004dc-vc-1" election-owner="00001244-1244-0001-2b91-000000000001" election-id="4" /></div>
<div>Feb 3 07:02:50 vsa-0000004dc-vc-0 heartbeat: [1018]: debug: MSG[14] : [from_id=crmd]</div><div>Feb 3 07:02:50 vsa-0000004dc-vc-0 crmd: [1259]: debug: debug3: cib_native_perform_op: Sending cib_slave message to CIB service</div>
<div>Feb 3 07:02:50 vsa-0000004dc-vc-0 heartbeat: [1018]: debug: MSG[15] : [to_id=crmd]</div><div>Feb 3 07:02:50 vsa-0000004dc-vc-0 crmd: [1259]: debug: debug3: cib_native_perform_op: Message sent</div><div>Feb 3 07:02:50 vsa-0000004dc-vc-0 heartbeat: [1018]: debug: process_clustermsg: node [vsa-0000004dc-vc-0]</div>
<div>Feb 3 07:02:50 vsa-0000004dc-vc-0 crmd: [1259]: debug: debug3: cib_native_perform_op: Async call, returning</div><div>Feb 3 07:02:50 vsa-0000004dc-vc-0 heartbeat: [1018]: debug: #011return TRUE;</div><div>Feb 3 07:02:50 vsa-0000004dc-vc-0 crmd: [1259]: debug: do_fsa_action: actions:trace: #011// A_ELECTION_CHECK</div>
<div>Feb 3 07:02:50 vsa-0000004dc-vc-0 heartbeat: [1018]: debug: }/*ProcessAnAPIRequest*/;</div><div>Feb 3 07:02:50 vsa-0000004dc-vc-0 crmd: [1259]: debug: do_election_check: Still waiting on 1 non-votes (2 total)</div>
<div>Feb 3 07:02:50 vsa-0000004dc-vc-0 heartbeat: [1018]: debug: return 1;</div><div>Feb 3 07:02:50 vsa-0000004dc-vc-0 crmd: [1259]: debug: debug2: s_crmd_fsa: Checking messages (2 remaining)</div><div>Feb 3 07:02:50 vsa-0000004dc-vc-0 heartbeat: [1018]: debug: }/*APIclients_input_dispatch*/;</div>
<div>Feb 3 07:02:50 vsa-0000004dc-vc-0 crmd: [1259]: debug: debug2: get_message: Processing input 15</div><div>Feb 3 07:02:50 vsa-0000004dc-vc-0 heartbeat: [1018]: debug: APIclients_input_dispatch() {</div><div>Feb 3 07:02:50 vsa-0000004dc-vc-0 crmd: [1259]: debug: debug2: log_fsa_input: Processing queued input 15</div>
<div>Feb 3 07:02:50 vsa-0000004dc-vc-0 heartbeat: [1018]: debug: ProcessAnAPIRequest() {</div><div>Feb 3 07:02:50 vsa-0000004dc-vc-0 crmd: [1259]: debug: debug3: log_fsa_input: FSA processing input from do_election_count_vote</div>
<div>Feb 3 07:02:50 vsa-0000004dc-vc-0 heartbeat: [1018]: debug: Sending API message to cluster...</div><div>Feb 3 07:02:50 vsa-0000004dc-vc-0 crmd: [1259]: debug: s_crmd_fsa: Processing I_PENDING: [ state=S_ELECTION cause=C_FSA_INTERNAL origin=do_election_count_vote ]</div>
<div>Feb 3 07:02:50 vsa-0000004dc-vc-0 heartbeat: [1018]: debug: MSG: Dumping message with 16 fields</div><div>Feb 3 07:02:50 vsa-0000004dc-vc-0 crmd: [1259]: debug: debug2: do_state_transition: actions:trace: #011S_ELECTION -> S_PENDING [ label=I_PENDING cause=C_FSA_INTERNAL origin=do_election_count_vote ]</div>
<div>Feb 3 07:02:50 vsa-0000004dc-vc-0 heartbeat: [1018]: debug: MSG[0] : [__name__=create_request_adv]</div><div>Feb 3 07:02:50 vsa-0000004dc-vc-0 crmd: [1259]: info: do_state_transition: State transition S_ELECTION -> S_PENDING [ input=I_PENDING cause=C_FSA_INTERNAL origin=do_election_count_vote ]</div>
<div>Feb 3 07:02:50 vsa-0000004dc-vc-0 heartbeat: [1018]: debug: MSG[1] : [origin=do_election_count_vote]</div><div>Feb 3 07:02:50 vsa-0000004dc-vc-0 crmd: [1259]: debug: debug2: crm_timer_stop: Election Timeout (I_ELECTION_DC:120000ms) already stopped</div>
<div>Feb 3 07:02:50 vsa-0000004dc-vc-0 heartbeat: [1018]: debug: MSG[2] : [t=crmd]</div><div>Feb 3 07:02:50 vsa-0000004dc-vc-0 crmd: [1259]: debug: debug2: crm_timer_stop: PEngine Recheck Timer (I_PE_CALC:900000ms) already stopped</div>
<div>Feb 3 07:02:50 vsa-0000004dc-vc-0 heartbeat: [1018]: debug: MSG[3] : [version=3.0.1]</div><div>Feb 3 07:02:50 vsa-0000004dc-vc-0 crmd: [1259]: debug: debug3: cib_native_perform_op: Sending cib_slave message to CIB service</div>
<div>Feb 3 07:02:50 vsa-0000004dc-vc-0 heartbeat: [1018]: debug: MSG[4] : [subt=request]</div><div>Feb 3 07:02:50 vsa-0000004dc-vc-0 crmd: [1259]: debug: debug3: cib_native_perform_op: Message sent</div><div>Feb 3 07:02:50 vsa-0000004dc-vc-0 heartbeat: [1018]: debug: MSG[5] : [reference=no-vote-crmd-1328245370-6]</div>
<div>Feb 3 07:02:50 vsa-0000004dc-vc-0 crmd: [1259]: debug: debug3: cib_native_perform_op: Async call, returning</div><div>Feb 3 07:02:50 vsa-0000004dc-vc-0 heartbeat: [1018]: debug: MSG[6] : [crm_task=no-vote]</div><div>
Feb 3 07:02:50 vsa-0000004dc-vc-0 crmd: [1259]: debug: debug2: do_state_transition: Resetting our DC to NULL on transition to S_PENDING</div><div>Feb 3 07:02:50 vsa-0000004dc-vc-0 heartbeat: [1018]: debug: MSG[7] : [crm_sys_to=crmd]</div>
<div>Feb 3 07:02:50 vsa-0000004dc-vc-0 crmd: [1259]: debug: do_fsa_action: actions:trace: #011// A_DC_TIMER_STOP</div><div>Feb 3 07:02:50 vsa-0000004dc-vc-0 heartbeat: [1018]: debug: MSG[8] : [crm_sys_from=crmd]</div><div>
Feb 3 07:02:50 vsa-0000004dc-vc-0 crmd: [1259]: debug: debug2: crm_timer_stop: Election Trigger (I_DC_TIMEOUT:5000ms) already stopped</div><div>Feb 3 07:02:50 vsa-0000004dc-vc-0 heartbeat: [1018]: debug: MSG[9] : [crm_host_to=vsa-0000004dc-vc-1]</div>
<div>Feb 3 07:02:50 vsa-0000004dc-vc-0 crmd: [1259]: debug: do_fsa_action: actions:trace: #011// A_INTEGRATE_TIMER_STOP</div><div>Feb 3 07:02:50 vsa-0000004dc-vc-0 heartbeat: [1018]: debug: MSG[10] : [election-owner=00001244-1244-0001-2b91-000000000001]</div>
<div>Feb 3 07:02:50 vsa-0000004dc-vc-0 crmd: [1259]: debug: debug2: crm_timer_stop: Integration Timer (I_INTEGRATED:180000ms) already stopped</div><div>Feb 3 07:02:50 vsa-0000004dc-vc-0 heartbeat: [1018]: debug: MSG[11] : [election-id=4]</div>
<div>Feb 3 07:02:50 vsa-0000004dc-vc-0 crmd: [1259]: debug: do_fsa_action: actions:trace: #011// A_FINALIZE_TIMER_STOP</div><div>Feb 3 07:02:50 vsa-0000004dc-vc-0 heartbeat: [1018]: debug: MSG[12] : [dest=vsa-0000004dc-vc-1]</div>
<div>Feb 3 07:02:50 vsa-0000004dc-vc-0 crmd: [1259]: debug: debug2: crm_timer_stop: Finalization Timer (I_ELECTION:1800000ms) already stopped</div><div>Feb 3 07:02:50 vsa-0000004dc-vc-0 heartbeat: [1018]: debug: MSG[13] : [oseq=3]</div>
<div>Feb 3 07:02:50 vsa-0000004dc-vc-0 crmd: [1259]: debug: do_fsa_action: actions:trace: #011// A_DC_TIMER_START</div><div>Feb 3 07:02:50 vsa-0000004dc-vc-0 heartbeat: [1018]: debug: MSG[14] : [from_id=crmd]</div><div>
Feb 3 07:02:50 vsa-0000004dc-vc-0 crmd: [1259]: debug: crm_timer_start: Started Election Trigger (I_DC_TIMEOUT:5000ms), src=18</div><div>Feb 3 07:02:50 vsa-0000004dc-vc-0 heartbeat: [1018]: debug: MSG[15] : [to_id=crmd]</div>
<div>Feb 3 07:02:50 vsa-0000004dc-vc-0 crmd: [1259]: debug: do_fsa_action: actions:trace: #011// A_DC_RELEASE</div><div>Feb 3 07:02:50 vsa-0000004dc-vc-0 heartbeat: [1018]: debug: process_clustermsg: node [vsa-0000004dc-vc-0]</div>
<div>Feb 3 07:02:50 vsa-0000004dc-vc-0 crmd: [1259]: debug: do_dc_release: Releasing the role of DC</div><div>Feb 3 07:02:50 vsa-0000004dc-vc-0 heartbeat: [1018]: debug: process_clustermsg: node [vsa-0000004dc-vc-0]</div>
<div>Feb 3 07:02:50 vsa-0000004dc-vc-0 crmd: [1259]: debug: debug2: do_dc_release: Am I still the DC? false</div><div>Feb 3 07:02:50 vsa-0000004dc-vc-0 heartbeat: [1018]: debug: #011return TRUE;</div><div>Feb 3 07:02:50 vsa-0000004dc-vc-0 crmd: [1259]: debug: do_fsa_action: actions:trace: #011// A_DC_RELEASED</div>
<div>Feb 3 07:02:50 vsa-0000004dc-vc-0 heartbeat: [1018]: debug: }/*ProcessAnAPIRequest*/;</div><div>Feb 3 07:02:50 vsa-0000004dc-vc-0 crmd: [1259]: info: do_dc_release: DC role released</div><div>Feb 3 07:02:50 vsa-0000004dc-vc-0 heartbeat: [1018]: debug: return 1;</div>
<div>Feb 3 07:02:50 vsa-0000004dc-vc-0 crmd: [1259]: debug: debug2: register_fsa_input_adv: do_dc_release appended FSA input 17 (I_RELEASE_SUCCESS) (cause=C_FSA_INTERNAL) without data</div><div>Feb 3 07:02:50 vsa-0000004dc-vc-0 heartbeat: [1018]: debug: }/*APIclients_input_dispatch*/;</div>
<div>Feb 3 07:02:50 vsa-0000004dc-vc-0 crmd: [1259]: debug: debug2: register_fsa_input_adv: Queue len: 2</div><div>Feb 3 07:02:50 vsa-0000004dc-vc-0 crmd: [1259]: debug: debug3: register_fsa_input_adv: Triggering FSA: register_fsa_input_adv</div>
<div>Feb 3 07:02:50 vsa-0000004dc-vc-0 crmd: [1259]: debug: debug2: do_dc_release: Am I still the DC? false</div><div>Feb 3 07:02:50 vsa-0000004dc-vc-0 crmd: [1259]: debug: do_fsa_action: actions:trace: #011// A_PE_STOP</div>
<div>Feb 3 07:02:50 vsa-0000004dc-vc-0 crmd: [1259]: debug: debug2: stop_subsystem: Stopping sub-system "pengine"</div><div>Feb 3 07:02:50 vsa-0000004dc-vc-0 crmd: [1259]: debug: debug2: stop_subsystem: Client pengine not running</div>
<div>Feb 3 07:02:50 vsa-0000004dc-vc-0 crmd: [1259]: debug: do_fsa_action: actions:trace: #011// A_TE_STOP</div><div>Feb 3 07:02:50 vsa-0000004dc-vc-0 crmd: [1259]: debug: cib_client_del_notify_callback: Removing callback for cib_diff_notify events</div>
<div>Feb 3 07:02:50 vsa-0000004dc-vc-0 crmd: [1259]: debug: debug3: cib_client_del_notify_callback: Callback not present</div><div>Feb 3 07:02:50 vsa-0000004dc-vc-0 crmd: [1259]: info: do_te_control: Transitioner is now inactive</div>
<div>Feb 3 07:02:50 vsa-0000004dc-vc-0 crmd: [1259]: debug: debug2: s_crmd_fsa: Checking messages (2 remaining)</div><div>Feb 3 07:02:50 vsa-0000004dc-vc-0 crmd: [1259]: debug: debug2: get_message: Processing input 16</div>
<div>Feb 3 07:02:50 vsa-0000004dc-vc-0 crmd: [1259]: debug: debug2: log_fsa_input: Processing queued input 16</div><div>Feb 3 07:02:50 vsa-0000004dc-vc-0 crmd: [1259]: debug: debug3: log_fsa_input: FSA processing input from do_election_count_vote</div>
<div>Feb 3 07:02:50 vsa-0000004dc-vc-0 crmd: [1259]: debug: s_crmd_fsa: Processing I_PENDING: [ state=S_PENDING cause=C_FSA_INTERNAL origin=do_election_count_vote ]</div><div>Feb 3 07:02:50 vsa-0000004dc-vc-0 crmd: [1259]: debug: do_fsa_action: actions:trace: #011// A_LOG</div>
<div>Feb 3 07:02:50 vsa-0000004dc-vc-0 crmd: [1259]: debug: debug2: do_log: FSA: Input I_PENDING from do_election_count_vote() received in state S_PENDING</div><div>Feb 3 07:02:50 vsa-0000004dc-vc-0 crmd: [1259]: debug: debug2: s_crmd_fsa: actions:trace: #011// FSA input: State=S_PENDING #011Cause=C_FSA_INTERNAL #011Input=I_PENDING #011Origin=do_election_count_vote() #011id=16</div>
<div>Feb 3 07:02:50 vsa-0000004dc-vc-0 crmd: [1259]: debug: do_fsa_action: actions:trace: #011// A_DC_TIMER_STOP</div><div>Feb 3 07:02:50 vsa-0000004dc-vc-0 crmd: [1259]: debug: debug2: crm_timer_stop: Stopping Election Trigger (I_DC_TIMEOUT:5000ms), src=18</div>
<div>Feb 3 07:02:50 vsa-0000004dc-vc-0 crmd: [1259]: debug: do_fsa_action: actions:trace: #011// A_DC_TIMER_START</div><div>Feb 3 07:02:50 vsa-0000004dc-vc-0 crmd: [1259]: debug: crm_timer_start: Started Election Trigger (I_DC_TIMEOUT:5000ms), src=19</div>
<div>Feb 3 07:02:50 vsa-0000004dc-vc-0 crmd: [1259]: debug: debug2: s_crmd_fsa: Checking messages (1 remaining)</div><div>Feb 3 07:02:50 vsa-0000004dc-vc-0 crmd: [1259]: debug: debug2: get_message: Processing input 17</div>
<div>Feb 3 07:02:50 vsa-0000004dc-vc-0 crmd: [1259]: debug: debug2: log_fsa_input: Processing queued input 17</div><div>Feb 3 07:02:50 vsa-0000004dc-vc-0 crmd: [1259]: debug: debug3: log_fsa_input: FSA processing input from do_dc_release</div>
<div>Feb 3 07:02:50 vsa-0000004dc-vc-0 crmd: [1259]: debug: s_crmd_fsa: Processing I_RELEASE_SUCCESS: [ state=S_PENDING cause=C_FSA_INTERNAL origin=do_dc_release ]</div><div>Feb 3 07:02:50 vsa-0000004dc-vc-0 crmd: [1259]: debug: do_fsa_action: actions:trace: #011// A_LOG</div>
<div>Feb 3 07:02:50 vsa-0000004dc-vc-0 crmd: [1259]: debug: debug2: do_log: FSA: Input I_RELEASE_SUCCESS from do_dc_release() received in state S_PENDING</div><div>Feb 3 07:02:50 vsa-0000004dc-vc-0 crmd: [1259]: debug: debug2: s_crmd_fsa: actions:trace: #011// FSA input: State=S_PENDING #011Cause=C_FSA_INTERNAL #011Input=I_RELEASE_SUCCESS #011Origin=do_dc_release() #011id=17</div>
<div>Feb 3 07:02:50 vsa-0000004dc-vc-0 crmd: [1259]: debug: debug2: s_crmd_fsa: Exiting the FSA</div><div>Feb 3 07:02:50 vsa-0000004dc-vc-0 crmd: [1259]: debug: debug2: crm_fsa_trigger: Exited (queue len: 0)</div><div>
Feb 3 07:02:50 vsa-0000004dc-vc-0 crmd: [1259]: debug: debug2: crm_fsa_trigger: Invoked (queue len: 0)</div><div>Feb 3 07:02:50 vsa-0000004dc-vc-0 crmd: [1259]: debug: debug2: s_crmd_fsa: FSA invoked with Cause: C_FSA_INTERNAL#011State: S_PENDING</div>
<div>Feb 3 07:02:50 vsa-0000004dc-vc-0 crmd: [1259]: debug: debug2: s_crmd_fsa: Exiting the FSA</div><div>Feb 3 07:02:50 vsa-0000004dc-vc-0 crmd: [1259]: debug: debug2: crm_fsa_trigger: Exited (queue len: 0)</div><div>
Feb 3 07:02:50 vsa-0000004dc-vc-0 crmd: [1259]: debug: debug2: cib_native_callback: No callback found for call 6</div><div>Feb 3 07:02:50 vsa-0000004dc-vc-0 crmd: [1259]: debug: debug2: cib_native_callback: No callback found for call 7</div>
<div>Feb 3 07:02:50 vsa-0000004dc-vc-0 crmd: [1259]: debug: debug2: cib_native_callback: No callback found for call 8</div><div>Feb 3 07:02:50 vsa-0000004dc-vc-0 crmd: [1259]: debug: debug3: cib_native_msgready: No message pending</div>
<div>Feb 3 07:02:51 vsa-0000004dc-vc-0 heartbeat: [1018]: debug: hb_send_local_status() {</div><div>Feb 3 07:02:51 vsa-0000004dc-vc-0 heartbeat: [1018]: debug: PID 1018: Sending local status curnode = 638e58 status: active</div>
<div>Feb 3 07:02:51 vsa-0000004dc-vc-0 heartbeat: [1018]: debug: process_clustermsg: node [vsa-0000004dc-vc-0]</div><div>Feb 3 07:02:51 vsa-0000004dc-vc-0 heartbeat: [1018]: debug: }/*hb_send_local_status*/;</div><div>Feb 3 07:02:51 vsa-0000004dc-vc-0 heartbeat: [1018]: debug: read_child_dispatch() {</div>
<div>Feb 3 07:02:51 vsa-0000004dc-vc-0 heartbeat: [1018]: debug: Packet authenticated</div><div>Feb 3 07:02:51 vsa-0000004dc-vc-0 heartbeat: [1018]: debug: process_clustermsg: node [vsa-0000004dc-vc-1]</div><div>Feb 3 07:02:51 vsa-0000004dc-vc-0 heartbeat: [1018]: debug: }/*read_child_dispatch*/;</div>
<div>Feb 3 07:02:51 vsa-0000004dc-vc-0 heartbeat: [1018]: debug: read_child_dispatch() {</div><div>Feb 3 07:02:51 vsa-0000004dc-vc-0 heartbeat: [1018]: debug: Packet authenticated</div><div>Feb 3 07:02:51 vsa-0000004dc-vc-0 heartbeat: [1018]: debug: process_clustermsg: node [vsa-0000004dc-vc-1]</div>
<div>Feb 3 07:02:51 vsa-0000004dc-vc-0 heartbeat: [1018]: debug: }/*read_child_dispatch*/;</div><div>Feb 3 07:02:52 vsa-0000004dc-vc-0 heartbeat: [1018]: debug: hb_send_local_status() {</div><div>Feb 3 07:02:52 vsa-0000004dc-vc-0 heartbeat: [1018]: debug: PID 1018: Sending local status curnode = 638e58 status: active</div>
<div>Feb 3 07:02:52 vsa-0000004dc-vc-0 heartbeat: [1018]: debug: process_clustermsg: node [vsa-0000004dc-vc-0]</div><div>Feb 3 07:02:52 vsa-0000004dc-vc-0 heartbeat: [1018]: debug: }/*hb_send_local_status*/;</div><div>Feb 3 07:02:52 vsa-0000004dc-vc-0 heartbeat: [1018]: debug: read_child_dispatch() {</div>
<div>Feb 3 07:02:52 vsa-0000004dc-vc-0 heartbeat: [1018]: debug: Packet authenticated</div><div>Feb 3 07:02:52 vsa-0000004dc-vc-0 heartbeat: [1018]: debug: process_clustermsg: node [vsa-0000004dc-vc-1]</div><div>Feb 3 07:02:52 vsa-0000004dc-vc-0 heartbeat: [1018]: debug: }/*read_child_dispatch*/;</div>
<div>Feb 3 07:02:52 vsa-0000004dc-vc-0 heartbeat: [1018]: debug: read_child_dispatch() {</div><div>Feb 3 07:02:52 vsa-0000004dc-vc-0 heartbeat: [1018]: debug: Packet authenticated</div><div>Feb 3 07:02:52 vsa-0000004dc-vc-0 heartbeat: [1018]: debug: process_clustermsg: node [vsa-0000004dc-vc-1]</div>
<div>Feb 3 07:02:52 vsa-0000004dc-vc-0 heartbeat: [1018]: debug: }/*read_child_dispatch*/;</div><div>Feb 3 07:02:52 vsa-0000004dc-vc-0 heartbeat: [1018]: debug: read_child_dispatch() {</div><div>Feb 3 07:02:52 vsa-0000004dc-vc-0 heartbeat: [1018]: debug: Packet authenticated</div>
<div>Feb 3 07:02:52 vsa-0000004dc-vc-0 heartbeat: [1018]: debug: process_clustermsg: node [vsa-0000004dc-vc-1]</div><div>Feb 3 07:02:52 vsa-0000004dc-vc-0 heartbeat: [1018]: debug: }/*read_child_dispatch*/;</div><div>Feb 3 07:02:52 vsa-0000004dc-vc-0 heartbeat: [1018]: debug: read_child_dispatch() {</div>
<div>Feb 3 07:02:52 vsa-0000004dc-vc-0 heartbeat: [1018]: debug: Packet authenticated</div><div>Feb 3 07:02:52 vsa-0000004dc-vc-0 heartbeat: [1018]: debug: process_clustermsg: node [vsa-0000004dc-vc-1]</div><div>Feb 3 07:02:52 vsa-0000004dc-vc-0 heartbeat: [1018]: debug: }/*read_child_dispatch*/;</div>
<div>Feb 3 07:02:52 vsa-0000004dc-vc-0 heartbeat: [1018]: debug: read_child_dispatch() {</div><div>Feb 3 07:02:52 vsa-0000004dc-vc-0 heartbeat: [1018]: debug: Packet authenticated</div><div>Feb 3 07:02:52 vsa-0000004dc-vc-0 heartbeat: [1018]: debug: process_clustermsg: node [vsa-0000004dc-vc-1]</div>
<div>Feb 3 07:02:52 vsa-0000004dc-vc-0 heartbeat: [1018]: debug: }/*read_child_dispatch*/;</div><div>Feb 3 07:02:52 vsa-0000004dc-vc-0 heartbeat: [1018]: debug: read_child_dispatch() {</div><div>Feb 3 07:02:52 vsa-0000004dc-vc-0 heartbeat: [1018]: debug: Packet authenticated</div>
<div>Feb 3 07:02:52 vsa-0000004dc-vc-0 heartbeat: [1018]: debug: process_clustermsg: node [vsa-0000004dc-vc-1]</div><div>Feb 3 07:02:52 vsa-0000004dc-vc-0 heartbeat: [1018]: debug: }/*read_child_dispatch*/;</div><div>Feb 3 07:02:53 vsa-0000004dc-vc-0 heartbeat: [1018]: debug: hb_send_local_status() {</div>
<div>Feb 3 07:02:53 vsa-0000004dc-vc-0 heartbeat: [1018]: debug: PID 1018: Sending local status curnode = 638e58 status: active</div><div>Feb 3 07:02:53 vsa-0000004dc-vc-0 heartbeat: [1018]: debug: process_clustermsg: node [vsa-0000004dc-vc-0]</div>
<div>Feb 3 07:02:53 vsa-0000004dc-vc-0 heartbeat: [1018]: debug: }/*hb_send_local_status*/;</div><div>Feb 3 07:02:53 vsa-0000004dc-vc-0 heartbeat: [1018]: debug: read_child_dispatch() {</div><div>Feb 3 07:02:53 vsa-0000004dc-vc-0 heartbeat: [1018]: debug: Packet authenticated</div>
<div>Feb 3 07:02:53 vsa-0000004dc-vc-0 heartbeat: [1018]: debug: process_clustermsg: node [vsa-0000004dc-vc-1]</div><div>Feb 3 07:02:53 vsa-0000004dc-vc-0 heartbeat: [1018]: debug: }/*read_child_dispatch*/;</div><div>Feb 3 07:02:53 vsa-0000004dc-vc-0 heartbeat: [1018]: debug: read_child_dispatch() {</div>
<div>Feb 3 07:02:53 vsa-0000004dc-vc-0 heartbeat: [1018]: debug: Packet authenticated</div><div>Feb 3 07:02:53 vsa-0000004dc-vc-0 heartbeat: [1018]: debug: process_clustermsg: node [vsa-0000004dc-vc-1]</div><div>Feb 3 07:02:53 vsa-0000004dc-vc-0 heartbeat: [1018]: debug: }/*read_child_dispatch*/;</div>
<div>Feb 3 07:02:54 vsa-0000004dc-vc-0 heartbeat: [1018]: debug: hb_send_local_status() {</div><div>Feb 3 07:02:54 vsa-0000004dc-vc-0 heartbeat: [1018]: debug: PID 1018: Sending local status curnode = 638e58 status: active</div>
<div>Feb 3 07:02:54 vsa-0000004dc-vc-0 heartbeat: [1018]: debug: process_clustermsg: node [vsa-0000004dc-vc-0]</div><div>Feb 3 07:02:54 vsa-0000004dc-vc-0 heartbeat: [1018]: debug: }/*hb_send_local_status*/;</div><div>Feb 3 07:02:54 vsa-0000004dc-vc-0 heartbeat: [1018]: debug: read_child_dispatch() {</div>
<div>Feb 3 07:02:54 vsa-0000004dc-vc-0 heartbeat: [1018]: debug: Packet authenticated</div><div>Feb 3 07:02:54 vsa-0000004dc-vc-0 heartbeat: [1018]: debug: process_clustermsg: node [vsa-0000004dc-vc-1]</div><div>Feb 3 07:02:54 vsa-0000004dc-vc-0 heartbeat: [1018]: debug: }/*read_child_dispatch*/;</div>
<div>Feb 3 07:02:54 vsa-0000004dc-vc-0 heartbeat: [1018]: debug: read_child_dispatch() {</div><div>Feb 3 07:02:54 vsa-0000004dc-vc-0 heartbeat: [1018]: debug: Packet authenticated</div><div>Feb 3 07:02:54 vsa-0000004dc-vc-0 heartbeat: [1018]: debug: process_clustermsg: node [vsa-0000004dc-vc-1]</div>
<div>Feb 3 07:02:54 vsa-0000004dc-vc-0 heartbeat: [1018]: debug: }/*read_child_dispatch*/;</div><div>Feb 3 07:02:55 vsa-0000004dc-vc-0 crmd: [1259]: info: crm_timer_popped: Election Trigger (I_DC_TIMEOUT) just popped!</div>
<div><br></div><div><br></div><div>on node-2</div><div>Feb 3 07:02:49 vsa-0000004dc-vc-1 heartbeat: [1023]: debug: hb_send_local_status() {</div><div>Feb 3 07:02:49 vsa-0000004dc-vc-1 cib: [1069]: debug: debug3: ha_msg_dispatch: Invoked</div>
<div>Feb 3 07:02:49 vsa-0000004dc-vc-1 heartbeat: [1023]: debug: PID 1023: Sending local status curnode = 638e58 status: active</div><div>Feb 3 07:02:49 vsa-0000004dc-vc-1 heartbeat: [1023]: debug: process_clustermsg: node [vsa-0000004dc-vc-1]</div>
<div>Feb 3 07:02:49 vsa-0000004dc-vc-1 heartbeat: [1023]: debug: }/*hb_send_local_status*/;</div><div>Feb 3 07:02:49 vsa-0000004dc-vc-1 heartbeat: [1023]: debug: APIclients_input_dispatch() {</div><div>Feb 3 07:02:49 vsa-0000004dc-vc-1 heartbeat: [1023]: debug: ProcessAnAPIRequest() {</div>
<div>Feb 3 07:02:49 vsa-0000004dc-vc-1 heartbeat: [1023]: debug: Sending API message to cluster...</div><div>Feb 3 07:02:49 vsa-0000004dc-vc-1 heartbeat: [1023]: debug: MSG: Dumping message with 12 fields</div><div>Feb 3 07:02:49 vsa-0000004dc-vc-1 heartbeat: [1023]: debug: MSG[0] : [__name__=copy]</div>
<div>Feb 3 07:02:49 vsa-0000004dc-vc-1 heartbeat: [1023]: debug: MSG[1] : [__name__=cib_command]</div><div>Feb 3 07:02:49 vsa-0000004dc-vc-1 heartbeat: [1023]: debug: MSG[2] : [t=cib]</div><div>Feb 3 07:02:49 vsa-0000004dc-vc-1 heartbeat: [1023]: debug: MSG[3] : [cib_clientid=fd2ec03c-a9c3-4a90-b6b7-2eb26eb24545]</div>
<div>Feb 3 07:02:49 vsa-0000004dc-vc-1 heartbeat: [1023]: debug: MSG[4] : [cib_callopt=0]</div><div>Feb 3 07:02:49 vsa-0000004dc-vc-1 heartbeat: [1023]: debug: MSG[5] : [cib_callid=5]</div><div>Feb 3 07:02:49 vsa-0000004dc-vc-1 heartbeat: [1023]: debug: MSG[6] : [cib_op=cib_slave_all]</div>
<div>Feb 3 07:02:49 vsa-0000004dc-vc-1 heartbeat: [1023]: debug: MSG[7] : [cib_async_id=aa13a017-01bf-4589-af6c-084cec13f6fa]</div><div>Feb 3 07:02:49 vsa-0000004dc-vc-1 heartbeat: [1023]: debug: MSG[8] : [cib_clientname=crmd]</div>
<div>Feb 3 07:02:49 vsa-0000004dc-vc-1 heartbeat: [1023]: debug: MSG[9] : [cib_delegated_from=vsa-0000004dc-vc-1]</div><div>Feb 3 07:02:49 vsa-0000004dc-vc-1 heartbeat: [1023]: debug: MSG[10] : [from_id=cib]</div><div>Feb 3 07:02:49 vsa-0000004dc-vc-1 heartbeat: [1023]: debug: MSG[11] : [to_id=cib]</div>
<div>Feb 3 07:02:49 vsa-0000004dc-vc-1 heartbeat: [1023]: debug: process_clustermsg: node [vsa-0000004dc-vc-1]</div><div>Feb 3 07:02:49 vsa-0000004dc-vc-1 heartbeat: [1023]: debug: #011return TRUE;</div><div>Feb 3 07:02:49 vsa-0000004dc-vc-1 heartbeat: [1023]: debug: }/*ProcessAnAPIRequest*/;</div>
<div>Feb 3 07:02:49 vsa-0000004dc-vc-1 heartbeat: [1023]: debug: return 1;</div><div>Feb 3 07:02:49 vsa-0000004dc-vc-1 heartbeat: [1023]: debug: }/*APIclients_input_dispatch*/;</div><div>Feb 3 07:02:49 vsa-0000004dc-vc-1 heartbeat: [1023]: debug: APIclients_input_dispatch() {</div>
<div>Feb 3 07:02:49 vsa-0000004dc-vc-1 heartbeat: [1023]: debug: ProcessAnAPIRequest() {</div><div>Feb 3 07:02:49 vsa-0000004dc-vc-1 heartbeat: [1023]: debug: Sending API message to cluster...</div><div>Feb 3 07:02:49 vsa-0000004dc-vc-1 heartbeat: [1023]: debug: MSG: Dumping message with 15 fields</div>
<div>Feb 3 07:02:49 vsa-0000004dc-vc-1 heartbeat: [1023]: debug: MSG[0] : [__name__=create_request_adv]</div><div>Feb 3 07:02:49 vsa-0000004dc-vc-1 heartbeat: [1023]: debug: MSG[1] : [origin=join_make_offer]</div><div>Feb 3 07:02:49 vsa-0000004dc-vc-1 heartbeat: [1023]: debug: MSG[2] : [t=crmd]</div>
<div>Feb 3 07:02:49 vsa-0000004dc-vc-1 heartbeat: [1023]: debug: MSG[3] : [version=3.0.1]</div><div>Feb 3 07:02:49 vsa-0000004dc-vc-1 heartbeat: [1023]: debug: MSG[4] : [subt=request]</div><div>Feb 3 07:02:49 vsa-0000004dc-vc-1 heartbeat: [1023]: debug: MSG[5] : [reference=join_offer-dc-1328245368-4]</div>
<div>Feb 3 07:02:49 vsa-0000004dc-vc-1 heartbeat: [1023]: debug: MSG[6] : [crm_task=join_offer]</div><div>Feb 3 07:02:49 vsa-0000004dc-vc-1 heartbeat: [1023]: debug: MSG[7] : [crm_sys_to=crmd]</div><div>Feb 3 07:02:49 vsa-0000004dc-vc-1 heartbeat: [1023]: debug: MSG[8] : [crm_sys_from=dc]</div>
<div>Feb 3 07:02:49 vsa-0000004dc-vc-1 heartbeat: [1023]: debug: MSG[9] : [crm_host_to=vsa-0000004dc-vc-1]</div><div>Feb 3 07:02:49 vsa-0000004dc-vc-1 heartbeat: [1023]: debug: MSG[10] : [join_id=1]</div><div>Feb 3 07:02:49 vsa-0000004dc-vc-1 heartbeat: [1023]: debug: MSG[11] : [dest=vsa-0000004dc-vc-1]</div>
<div>Feb 3 07:02:49 vsa-0000004dc-vc-1 heartbeat: [1023]: debug: MSG[12] : [oseq=1]</div><div>Feb 3 07:02:49 vsa-0000004dc-vc-1 heartbeat: [1023]: debug: MSG[13] : [from_id=crmd]</div><div>Feb 3 07:02:49 vsa-0000004dc-vc-1 heartbeat: [1023]: debug: MSG[14] : [to_id=crmd]</div>
<div>Feb 3 07:02:49 vsa-0000004dc-vc-1 heartbeat: [1023]: debug: process_clustermsg: node [vsa-0000004dc-vc-1]</div><div>Feb 3 07:02:49 vsa-0000004dc-vc-1 heartbeat: [1023]: debug: #011return TRUE;</div><div>Feb 3 07:02:49 vsa-0000004dc-vc-1 heartbeat: [1023]: debug: }/*ProcessAnAPIRequest*/;</div>
<div>Feb 3 07:02:49 vsa-0000004dc-vc-1 heartbeat: [1023]: debug: return 1;</div><div>Feb 3 07:02:49 vsa-0000004dc-vc-1 heartbeat: [1023]: debug: }/*APIclients_input_dispatch*/;</div><div>Feb 3 07:02:49 vsa-0000004dc-vc-1 heartbeat: [1023]: debug: APIclients_input_dispatch() {</div>
<div>Feb 3 07:02:49 vsa-0000004dc-vc-1 heartbeat: [1023]: debug: ProcessAnAPIRequest() {</div><div>Feb 3 07:02:49 vsa-0000004dc-vc-1 heartbeat: [1023]: debug: Sending API message to cluster...</div><div>Feb 3 07:02:49 vsa-0000004dc-vc-1 heartbeat: [1023]: debug: MSG: Dumping message with 15 fields</div>
<div>Feb 3 07:02:49 vsa-0000004dc-vc-1 heartbeat: [1023]: debug: MSG[0] : [__name__=create_request_adv]</div><div>Feb 3 07:02:49 vsa-0000004dc-vc-1 heartbeat: [1023]: debug: MSG[1] : [origin=join_make_offer]</div><div>Feb 3 07:02:49 vsa-0000004dc-vc-1 heartbeat: [1023]: debug: MSG[2] : [t=crmd]</div>
<div>Feb 3 07:02:49 vsa-0000004dc-vc-1 heartbeat: [1023]: debug: MSG[3] : [version=3.0.1]</div><div>Feb 3 07:02:49 vsa-0000004dc-vc-1 heartbeat: [1023]: debug: MSG[4] : [subt=request]</div><div>Feb 3 07:02:49 vsa-0000004dc-vc-1 heartbeat: [1023]: debug: MSG[5] : [reference=join_offer-dc-1328245368-5]</div>
<div>Feb 3 07:02:49 vsa-0000004dc-vc-1 heartbeat: [1023]: debug: MSG[6] : [crm_task=join_offer]</div><div>Feb 3 07:02:49 vsa-0000004dc-vc-1 heartbeat: [1023]: debug: MSG[7] : [crm_sys_to=crmd]</div><div>Feb 3 07:02:49 vsa-0000004dc-vc-1 heartbeat: [1023]: debug: MSG[8] : [crm_sys_from=dc]</div>
<div>Feb 3 07:02:49 vsa-0000004dc-vc-1 heartbeat: [1023]: debug: MSG[9] : [crm_host_to=vsa-0000004dc-vc-0]</div><div>Feb 3 07:02:49 vsa-0000004dc-vc-1 heartbeat: [1023]: debug: MSG[10] : [join_id=1]</div><div>Feb 3 07:02:49 vsa-0000004dc-vc-1 heartbeat: [1023]: debug: MSG[11] : [dest=vsa-0000004dc-vc-0]</div>
<div>Feb 3 07:02:49 vsa-0000004dc-vc-1 heartbeat: [1023]: debug: MSG[12] : [oseq=1]</div><div>Feb 3 07:02:49 vsa-0000004dc-vc-1 heartbeat: [1023]: debug: MSG[13] : [from_id=crmd]</div><div>Feb 3 07:02:49 vsa-0000004dc-vc-1 heartbeat: [1023]: debug: MSG[14] : [to_id=crmd]</div>
<div>Feb 3 07:02:49 vsa-0000004dc-vc-1 heartbeat: [1023]: debug: process_clustermsg: node [vsa-0000004dc-vc-1]</div><div>Feb 3 07:02:49 vsa-0000004dc-vc-1 heartbeat: [1023]: debug: #011return TRUE;</div><div>Feb 3 07:02:49 vsa-0000004dc-vc-1 heartbeat: [1023]: debug: }/*ProcessAnAPIRequest*/;</div>
<div>Feb 3 07:02:49 vsa-0000004dc-vc-1 heartbeat: [1023]: debug: return 1;</div><div>Feb 3 07:02:49 vsa-0000004dc-vc-1 heartbeat: [1023]: debug: }/*APIclients_input_dispatch*/;</div><div>Feb 3 07:02:49 vsa-0000004dc-vc-1 heartbeat: [1023]: debug: read_child_dispatch() {</div>
<div>Feb 3 07:02:49 vsa-0000004dc-vc-1 heartbeat: [1023]: debug: Packet authenticated</div><div>Feb 3 07:02:49 vsa-0000004dc-vc-1 heartbeat: [1023]: debug: process_clustermsg: node [vsa-0000004dc-vc-0]</div><div>Feb 3 07:02:49 vsa-0000004dc-vc-1 heartbeat: [1023]: debug: }/*read_child_dispatch*/;</div>
<div>Feb 3 07:02:49 vsa-0000004dc-vc-1 heartbeat: [1023]: debug: read_child_dispatch() {</div><div>Feb 3 07:02:49 vsa-0000004dc-vc-1 heartbeat: [1023]: debug: Packet authenticated</div><div>Feb 3 07:02:49 vsa-0000004dc-vc-1 heartbeat: [1023]: debug: process_clustermsg: node [vsa-0000004dc-vc-0]</div>
<div>Feb 3 07:02:49 vsa-0000004dc-vc-1 heartbeat: [1023]: debug: }/*read_child_dispatch*/;</div><div>Feb 3 07:02:49 vsa-0000004dc-vc-1 heartbeat: [1023]: debug: read_child_dispatch() {</div><div>Feb 3 07:02:49 vsa-0000004dc-vc-1 heartbeat: [1023]: debug: Packet authenticated</div>
<div>Feb 3 07:02:49 vsa-0000004dc-vc-1 heartbeat: [1023]: debug: process_clustermsg: node [vsa-0000004dc-vc-0]</div><div>Feb 3 07:02:49 vsa-0000004dc-vc-1 heartbeat: [1023]: debug: }/*read_child_dispatch*/;</div><div>Feb 3 07:02:49 vsa-0000004dc-vc-1 heartbeat: [1023]: debug: read_child_dispatch() {</div>
<div>Feb 3 07:02:49 vsa-0000004dc-vc-1 heartbeat: [1023]: debug: Packet authenticated</div><div>Feb 3 07:02:49 vsa-0000004dc-vc-1 heartbeat: [1023]: debug: process_clustermsg: node [vsa-0000004dc-vc-0]</div><div>Feb 3 07:02:49 vsa-0000004dc-vc-1 heartbeat: [1023]: debug: }/*read_child_dispatch*/;</div>
<div>Feb 3 07:02:49 vsa-0000004dc-vc-1 stonithd: [1071]: debug: IPC accepted a connection.</div><div>Feb 3 07:02:49 vsa-0000004dc-vc-1 cib: [1069]: debug: debug2: cib_process_request: Processing local message (vsa-0000004dc-vc-1) for master...</div>
<div>Feb 3 07:02:49 vsa-0000004dc-vc-1 crmd: [1073]: debug: stonithd_signon: creating connection</div><div>Feb 3 07:02:49 vsa-0000004dc-vc-1 stonithd: [1071]: debug: G_main_IPC_Channel_constructor(sock=7,7)</div><div>Feb 3 07:02:49 vsa-0000004dc-vc-1 cib: [1069]: debug: debug2: parse_local_options: Processing locally scoped cib_query op from crmd</div>
<div>Feb 3 07:02:49 vsa-0000004dc-vc-1 crmd: [1073]: debug: sending out the signon msg.</div><div>Feb 3 07:02:49 vsa-0000004dc-vc-1 stonithd: [1071]: debug: stonithd_client_dispatch: begin</div><div>Feb 3 07:02:49 vsa-0000004dc-vc-1 cib: [1069]: debug: debug3: cib_process_request: Finished determining processing actions</div>
<div>Feb 3 07:02:49 vsa-0000004dc-vc-1 crmd: [1073]: debug: signed on to stonithd.</div><div>Feb 3 07:02:49 vsa-0000004dc-vc-1 stonithd: [1071]: debug: begin to dealing with a api msg signon from a client PID:1073.</div>
<div>Feb 3 07:02:49 vsa-0000004dc-vc-1 cib: [1069]: debug: debug2: cib_process_query: Processing "cib_query" event for section=<null></div><div>Feb 3 07:02:49 vsa-0000004dc-vc-1 crmd: [1073]: debug: debug2: te_connect_stonith: Grabbing IPC channel</div>
<div>Feb 3 07:02:49 vsa-0000004dc-vc-1 stonithd: [1071]: debug: on_stonithd_signon: begin.</div><div>Feb 3 07:02:49 vsa-0000004dc-vc-1 cib: [1069]: debug: debug2: xpath_search: Evaluating: //cib</div><div>Feb 3 07:02:49 vsa-0000004dc-vc-1 crmd: [1073]: debug: debug2: te_connect_stonith: Attaching to mainloop</div>
<div>Feb 3 07:02:49 vsa-0000004dc-vc-1 stonithd: [1071]: debug: get_exist_client_by_chan: begin.</div><div>Feb 3 07:02:49 vsa-0000004dc-vc-1 cib: [1069]: debug: debug2: cib_process_request: Operation complete: op cib_query for section 'all' (origin=local/crmd/13, version=1.2.0): ok (rc=0)</div>
<div>Feb 3 07:02:49 vsa-0000004dc-vc-1 crmd: [1073]: debug: G_main_IPC_Channel_constructor(sock=15,15)</div><div>Feb 3 07:02:49 vsa-0000004dc-vc-1 stonithd: [1071]: debug: client tengine (pid=1073) succeeded to signon to stonithd.</div>
<div>Feb 3 07:02:49 vsa-0000004dc-vc-1 cib: [1069]: debug: debug3: cib_process_request: processing response cases</div><div>Feb 3 07:02:49 vsa-0000004dc-vc-1 crmd: [1073]: info: te_connect_stonith: Connected</div><div>Feb 3 07:02:49 vsa-0000004dc-vc-1 stonithd: [1071]: debug: stonithd_process_client_msg: end.</div>
<div>Feb 3 07:02:49 vsa-0000004dc-vc-1 cib: [1069]: debug: debug2: do_local_notify: Performing notification</div><div>Feb 3 07:02:49 vsa-0000004dc-vc-1 crmd: [1073]: debug: debug2: cib_native_callback: No callback found for call 11</div>
<div>Feb 3 07:02:49 vsa-0000004dc-vc-1 stonithd: [1071]: debug: stonithd_client_dispatch: end</div><div>Feb 3 07:02:49 vsa-0000004dc-vc-1 cib: [1069]: debug: debug3: do_local_notify: Sending callback to request originator</div>
<div>Feb 3 07:02:49 vsa-0000004dc-vc-1 crmd: [1073]: debug: debug2: cib_native_callback: Invoking global callback for call 11</div><div>Feb 3 07:02:49 vsa-0000004dc-vc-1 stonithd: [1071]: debug: IPC accepted a callback connection.</div>
<div>Feb 3 07:02:49 vsa-0000004dc-vc-1 cib: [1069]: debug: debug2: do_local_notify: Sending an a-sync response to crmd</div><div>Feb 3 07:02:49 vsa-0000004dc-vc-1 crmd: [1073]: debug: debug2: cib_native_callback: Invoking callback config_query_callback for call 12</div>
<div>Feb 3 07:02:49 vsa-0000004dc-vc-1 stonithd: [1071]: debug: G_main_IPC_Channel_constructor(sock=9,9)</div><div>Feb 3 07:02:49 vsa-0000004dc-vc-1 cib: [1069]: debug: debug3: send_via_callback_channel: Delivering msg 0x805700 to client aa13a017-01bf-4589-af6c-084cec13f6fa</div>
<div>Feb 3 07:02:49 vsa-0000004dc-vc-1 crmd: [1073]: debug: config_query_callback: Call 12 : Parsing CIB options</div><div>Feb 3 07:02:49 vsa-0000004dc-vc-1 stonithd: [1071]: debug: stonithd_client_dispatch: begin</div>
<div>Feb 3 07:02:49 vsa-0000004dc-vc-1 cib: [1069]: debug: debug3: send_via_callback_channel: Delivering reply to client aa13a017-01bf-4589-af6c-084cec13f6fa (cib_callback)</div><div>Feb 3 07:02:49 vsa-0000004dc-vc-1 crmd: [1073]: debug: debug3: unpack_attr_set: Adding attributes from cib-bootstrap-options</div>
<div>Feb 3 07:02:49 vsa-0000004dc-vc-1 stonithd: [1071]: debug: stonithd_process_client_msg: received signon request from callback channel.</div><div>Feb 3 07:02:49 vsa-0000004dc-vc-1 cib: [1069]: debug: debug2: cib_process_request: Completed slave update</div>
<div>Feb 3 07:02:49 vsa-0000004dc-vc-1 crmd: [1073]: debug: cluster_option: Using default value '15min' for cluster option 'cluster-recheck-interval'</div><div>Feb 3 07:02:49 vsa-0000004dc-vc-1 stonithd: [1071]: debug: on_stonithd_cookie: begin.</div>
<div>Feb 3 07:02:49 vsa-0000004dc-vc-1 crmd: [1073]: debug: cluster_option: Using default value '2min' for cluster option 'election-timeout'</div><div>Feb 3 07:02:49 vsa-0000004dc-vc-1 stonithd: [1071]: debug: stonithd_client_dispatch: end</div>
<div>Feb 3 07:02:49 vsa-0000004dc-vc-1 crmd: [1073]: debug: cluster_option: Using default value '20min' for cluster option 'shutdown-escalation'</div><div>Feb 3 07:02:49 vsa-0000004dc-vc-1 crmd: [1073]: debug: cluster_option: Using default value '3min' for cluster option 'crmd-integration-timeout'</div>
<div>Feb 3 07:02:49 vsa-0000004dc-vc-1 crmd: [1073]: debug: cluster_option: Using default value '30min' for cluster option 'crmd-finalization-timeout'</div><div>Feb 3 07:02:49 vsa-0000004dc-vc-1 crmd: [1073]: debug: cluster_option: Using default value '2' for cluster option 'expected-quorum-votes'</div>
<div>Feb 3 07:02:49 vsa-0000004dc-vc-1 crmd: [1073]: info: config_query_callback: Checking for expired actions every 900000ms</div><div>Feb 3 07:02:49 vsa-0000004dc-vc-1 crmd: [1073]: debug: debug3: config_query_callback: Triggering FSA: config_query_callback</div>
<div>Feb 3 07:02:49 vsa-0000004dc-vc-1 crmd: [1073]: debug: debug2: cib_native_callback: Invoking global callback for call 12</div><div>Feb 3 07:02:49 vsa-0000004dc-vc-1 crmd: [1073]: debug: debug3: cib_native_msgready: No message pending</div>
<div>Feb 3 07:02:49 vsa-0000004dc-vc-1 crmd: [1073]: debug: debug3: ha_msg_dispatch: Invoked</div><div>Feb 3 07:02:49 vsa-0000004dc-vc-1 crmd: [1073]: debug: debug2: crmd_ha_msg_callback: HA[inbound]: join_offer from vsa-0000004dc-vc-1</div>
<div>Feb 3 07:02:49 vsa-0000004dc-vc-1 crmd: [1073]: debug: debug3: relay_message: Routing message join_offer-dc-1328245368-4</div><div>Feb 3 07:02:49 vsa-0000004dc-vc-1 crmd: [1073]: debug: debug3: relay_message: Router result: Message result: CRMd process</div>
<div>Feb 3 07:02:49 vsa-0000004dc-vc-1 crmd: [1073]: debug: debug3: log_data_element: relay_message: router.log <create_request_adv origin="join_make_offer" t="crmd" version="3.0.1" subt="request" reference="join_offer-dc-1328245368-4" crm_task="join_offer" crm_sys_to="crmd" crm_sys_from="dc" crm_host_to="vsa-0000004dc-vc-1" join_id="1" dest="vsa-0000004dc-vc-1" oseq="1" from_id="crmd" to_id="crmd" client_gen="4" src="vsa-0000004dc-vc-1" seq="2e" hg="4f2a227c" ts="4f2b6a79" ld="3.01 0.88 0.30 5/106 1372" ttl="3" auth="1 6e4e4efdb36e7856aab1cd016e0fcd011ce99908" /></div>
<div>Feb 3 07:02:49 vsa-0000004dc-vc-1 crmd: [1073]: debug: handle_request: Raising I_JOIN_OFFER: join-1</div><div>Feb 3 07:02:49 vsa-0000004dc-vc-1 crmd: [1073]: debug: debug2: register_fsa_input_adv: route_message appended FSA input 10 (I_JOIN_OFFER) (cause=C_HA_MESSAGE) with data</div>
<div>Feb 3 07:02:49 vsa-0000004dc-vc-1 crmd: [1073]: debug: debug3: register_fsa_input_adv: Copying C_HA_MESSAGE data from route_message as a HA msg</div><div>Feb 3 07:02:49 vsa-0000004dc-vc-1 crmd: [1073]: debug: debug2: register_fsa_input_adv: Queue len: 1</div>
<div>Feb 3 07:02:49 vsa-0000004dc-vc-1 crmd: [1073]: debug: debug3: register_fsa_input_adv: Triggering FSA: register_fsa_input_adv</div><div>Feb 3 07:02:49 vsa-0000004dc-vc-1 crmd: [1073]: debug: debug3: crmd_ha_msg_filter: Triggering FSA: crmd_ha_msg_filter</div>
<div>Feb 3 07:02:49 vsa-0000004dc-vc-1 crmd: [1073]: debug: debug2: crmd_ha_msg_callback: HA[inbound]: vote from vsa-0000004dc-vc-0</div><div>Feb 3 07:02:49 vsa-0000004dc-vc-1 crmd: [1073]: debug: debug3: relay_message: Routing message vote-crmd-1328245369-3</div>
<div>Feb 3 07:02:49 vsa-0000004dc-vc-1 crmd: [1073]: debug: debug3: relay_message: Router result: Message result: CRMd process</div><div>Feb 3 07:02:49 vsa-0000004dc-vc-1 crmd: [1073]: debug: debug3: log_data_element: relay_message: router.log <create_request_adv origin="do_election_vote" t="crmd" version="3.0.1" subt="request" reference="vote-crmd-1328245369-3" crm_task="vote" crm_sys_to="crmd" crm_sys_from="crmd" election-owner="00001244-1244-0000-2b91-000000000000" election-id="2" oseq="1" from_id="crmd" to_id="crmd" client_gen="4" src="vsa-0000004dc-vc-0" seq="2f" hg="4f2a2274" ts="4f2b6a79" ld="2.89 0.85 0.29 7/105 1463" ttl="3" auth="1 36b49d6fb3fb61ca4d5da0e98380e36d62f42449" /></div>
<div>Feb 3 07:02:49 vsa-0000004dc-vc-1 crmd: [1073]: debug: debug2: register_fsa_input_adv: handle_request appended FSA input 11 (I_NULL) (cause=C_HA_MESSAGE) with data</div><div>Feb 3 07:02:49 vsa-0000004dc-vc-1 crmd: [1073]: debug: debug3: register_fsa_input_adv: Adding actions 0000000200000400 to input</div>
<div>Feb 3 07:02:49 vsa-0000004dc-vc-1 crmd: [1073]: debug: debug3: register_fsa_input_adv: Copying C_HA_MESSAGE data from handle_request as a HA msg</div><div>Feb 3 07:02:49 vsa-0000004dc-vc-1 crmd: [1073]: debug: debug2: register_fsa_input_adv: Queue len: 2</div>
<div>Feb 3 07:02:49 vsa-0000004dc-vc-1 crmd: [1073]: debug: debug3: register_fsa_input_adv: Triggering FSA: register_fsa_input_adv</div><div>Feb 3 07:02:49 vsa-0000004dc-vc-1 crmd: [1073]: debug: debug3: crmd_ha_msg_filter: Triggering FSA: crmd_ha_msg_filter</div>
<div>Feb 3 07:02:49 vsa-0000004dc-vc-1 crmd: [1073]: debug: debug2: crm_fsa_trigger: Invoked (queue len: 2)</div><div>Feb 3 07:02:49 vsa-0000004dc-vc-1 crmd: [1073]: debug: debug2: s_crmd_fsa: FSA invoked with Cause: C_FSA_INTERNAL#011State: S_INTEGRATION</div>
<div>Feb 3 07:02:49 vsa-0000004dc-vc-1 crmd: [1073]: debug: debug2: s_crmd_fsa: Checking messages (2 remaining)</div><div>Feb 3 07:02:49 vsa-0000004dc-vc-1 crmd: [1073]: debug: debug2: get_message: Processing input 10</div>
<div>Feb 3 07:02:49 vsa-0000004dc-vc-1 crmd: [1073]: debug: debug2: log_fsa_input: Processing queued input 10</div><div>Feb 3 07:02:49 vsa-0000004dc-vc-1 crmd: [1073]: debug: debug3: log_fsa_input: FSA processing XML message from route_message</div>
<div>Feb 3 07:02:49 vsa-0000004dc-vc-1 crmd: [1073]: debug: debug3: print_xml_formatted: log_fsa_input: FSA message data: NULL</div><div>Feb 3 07:02:49 vsa-0000004dc-vc-1 crmd: [1073]: debug: s_crmd_fsa: Processing I_JOIN_OFFER: [ state=S_INTEGRATION cause=C_HA_MESSAGE origin=route_message ]</div>
<div>Feb 3 07:02:49 vsa-0000004dc-vc-1 crmd: [1073]: debug: debug2: s_crmd_fsa: actions:trace: #011// FSA input: State=S_INTEGRATION #011Cause=C_HA_MESSAGE #011Input=I_JOIN_OFFER #011Origin=route_message() #011id=10</div>
<div>Feb 3 07:02:49 vsa-0000004dc-vc-1 crmd: [1073]: debug: do_fsa_action: actions:trace: #011// A_CL_JOIN_REQUEST</div><div>Feb 3 07:02:49 vsa-0000004dc-vc-1 crmd: [1073]: debug: debug2: do_cl_join_offer_respond: Accepting join offer: join-1</div>
<div>Feb 3 07:02:49 vsa-0000004dc-vc-1 crmd: [1073]: info: update_dc: Set DC to vsa-0000004dc-vc-1 (3.0.1)</div><div>Feb 3 07:02:49 vsa-0000004dc-vc-1 crmd: [1073]: debug: debug3: cib_native_perform_op: Sending cib_query message to CIB service</div>
<div>Feb 3 07:02:49 vsa-0000004dc-vc-1 crmd: [1073]: debug: debug3: cib_native_perform_op: Message sent</div><div>Feb 3 07:02:49 vsa-0000004dc-vc-1 crmd: [1073]: debug: debug3: cib_native_perform_op: Async call, returning</div>
<div>Feb 3 07:02:49 vsa-0000004dc-vc-1 crmd: [1073]: debug: debug2: do_cl_join_offer_respond: Registered join query callback: 13</div><div>Feb 3 07:02:49 vsa-0000004dc-vc-1 crmd: [1073]: debug: do_cl_join_offer_respond: do_cl_join_offer_respond added action A_DC_TIMER_STOP to the FSA</div>
<div>Feb 3 07:02:49 vsa-0000004dc-vc-1 crmd: [1073]: debug: do_fsa_action: actions:trace: #011// A_DC_TIMER_STOP</div><div>Feb 3 07:02:49 vsa-0000004dc-vc-1 crmd: [1073]: debug: debug2: crm_timer_stop: Election Trigger (I_DC_TIMEOUT:5000ms) already stopped</div>
<div>Feb 3 07:02:49 vsa-0000004dc-vc-1 crmd: [1073]: debug: debug2: s_crmd_fsa: Checking messages (1 remaining)</div><div>Feb 3 07:02:49 vsa-0000004dc-vc-1 crmd: [1073]: debug: debug2: get_message: Processing input 11</div>
<div>Feb 3 07:02:49 vsa-0000004dc-vc-1 crmd: [1073]: debug: debug2: log_fsa_input: Processing queued input 11</div><div>Feb 3 07:02:49 vsa-0000004dc-vc-1 crmd: [1073]: debug: debug3: log_fsa_input: FSA processing XML message from handle_request</div>
<div>Feb 3 07:02:49 vsa-0000004dc-vc-1 crmd: [1073]: debug: debug3: print_xml_formatted: log_fsa_input: FSA message data: NULL</div><div>Feb 3 07:02:49 vsa-0000004dc-vc-1 crmd: [1073]: debug: debug2: s_crmd_fsa: actions:trace: #011// FSA input: State=S_INTEGRATION #011Cause=C_HA_MESSAGE #011Input=I_NULL #011Origin=handle_request() #011id=11</div>
<div>Feb 3 07:02:49 vsa-0000004dc-vc-1 crmd: [1073]: debug: do_fsa_action: actions:trace: #011// A_ELECTION_COUNT</div><div>Feb 3 07:02:49 vsa-0000004dc-vc-1 crmd: [1073]: debug: do_election_count_vote: Created voted hash</div>
<div>Feb 3 07:02:49 vsa-0000004dc-vc-1 crmd: [1073]: debug: debug3: compare_version: 3.0.1 == 3.0.1 (4)</div><div>Feb 3 07:02:49 vsa-0000004dc-vc-1 crmd: [1073]: debug: debug3: compare_version: 3.0.1 == 3.0.1 (4)</div><div>
Feb 3 07:02:49 vsa-0000004dc-vc-1 crmd: [1073]: info: do_election_count_vote: Election 2 (owner: 00001244-1244-0000-2b91-000000000000) pass: vote from vsa-0000004dc-vc-0 (Age)</div><div>Feb 3 07:02:49 vsa-0000004dc-vc-1 crmd: [1073]: debug: debug2: register_fsa_input_adv: do_election_count_vote appended FSA input 12 (I_ELECTION) (cause=C_FSA_INTERNAL) without data</div>
<div>Feb 3 07:02:49 vsa-0000004dc-vc-1 crmd: [1073]: debug: debug2: register_fsa_input_adv: Queue len: 1</div><div>Feb 3 07:02:49 vsa-0000004dc-vc-1 crmd: [1073]: debug: debug3: register_fsa_input_adv: Triggering FSA: register_fsa_input_adv</div>
<div>Feb 3 07:02:49 vsa-0000004dc-vc-1 crmd: [1073]: debug: do_fsa_action: actions:trace: #011// A_ELECTION_CHECK</div><div>Feb 3 07:02:49 vsa-0000004dc-vc-1 crmd: [1073]: debug: do_election_check: Ignore election check: we not in an election</div>
<div>Feb 3 07:02:49 vsa-0000004dc-vc-1 crmd: [1073]: debug: debug2: s_crmd_fsa: Checking messages (1 remaining)</div><div>Feb 3 07:02:49 vsa-0000004dc-vc-1 crmd: [1073]: debug: debug2: get_message: Processing input 12</div>
<div>Feb 3 07:02:49 vsa-0000004dc-vc-1 crmd: [1073]: debug: debug2: log_fsa_input: Processing queued input 12</div><div>Feb 3 07:02:49 vsa-0000004dc-vc-1 crmd: [1073]: debug: debug3: log_fsa_input: FSA processing input from do_election_count_vote</div>
<div>Feb 3 07:02:49 vsa-0000004dc-vc-1 crmd: [1073]: debug: s_crmd_fsa: Processing I_ELECTION: [ state=S_INTEGRATION cause=C_FSA_INTERNAL origin=do_election_count_vote ]</div><div>Feb 3 07:02:49 vsa-0000004dc-vc-1 crmd: [1073]: debug: debug2: do_state_transition: actions:trace: #011S_INTEGRATION -> S_ELECTION [ label=I_ELECTION cause=C_FSA_INTERNAL origin=do_election_count_vote ]</div>
<div>Feb 3 07:02:49 vsa-0000004dc-vc-1 crmd: [1073]: info: do_state_transition: State transition S_INTEGRATION -> S_ELECTION [ input=I_ELECTION cause=C_FSA_INTERNAL origin=do_election_count_vote ]</div><div>Feb 3 07:02:49 vsa-0000004dc-vc-1 crmd: [1073]: debug: debug2: crm_timer_stop: PEngine Recheck Timer (I_PE_CALC:900000ms) already stopped</div>
<div>Feb 3 07:02:49 vsa-0000004dc-vc-1 crmd: [1073]: debug: debug2: do_state_transition: Resetting our DC to NULL on transition to S_ELECTION</div><div>Feb 3 07:02:49 vsa-0000004dc-vc-1 crmd: [1073]: info: update_dc: Unset DC vsa-0000004dc-vc-1</div>
<div>Feb 3 07:02:49 vsa-0000004dc-vc-1 crmd: [1073]: debug: do_fsa_action: actions:trace: #011// A_DC_TIMER_STOP</div><div>Feb 3 07:02:49 vsa-0000004dc-vc-1 crmd: [1073]: debug: debug2: crm_timer_stop: Election Trigger (I_DC_TIMEOUT:5000ms) already stopped</div>
<div>Feb 3 07:02:49 vsa-0000004dc-vc-1 crmd: [1073]: debug: do_fsa_action: actions:trace: #011// A_DC_TIMER_STOP</div><div>Feb 3 07:02:49 vsa-0000004dc-vc-1 crmd: [1073]: debug: debug2: crm_timer_stop: Election Trigger (I_DC_TIMEOUT:5000ms) already stopped</div>
<div>Feb 3 07:02:49 vsa-0000004dc-vc-1 crmd: [1073]: debug: do_fsa_action: actions:trace: #011// A_INTEGRATE_TIMER_STOP</div><div>Feb 3 07:02:49 vsa-0000004dc-vc-1 crmd: [1073]: debug: debug2: crm_timer_stop: Stopping Integration Timer (I_INTEGRATED:180000ms), src=19</div>
<div>Feb 3 07:02:49 vsa-0000004dc-vc-1 crmd: [1073]: debug: do_fsa_action: actions:trace: #011// A_FINALIZE_TIMER_STOP</div><div>Feb 3 07:02:49 vsa-0000004dc-vc-1 crmd: [1073]: debug: debug2: crm_timer_stop: Finalization Timer (I_ELECTION:1800000ms) already stopped</div>
<div>Feb 3 07:02:49 vsa-0000004dc-vc-1 crmd: [1073]: debug: do_fsa_action: actions:trace: #011// A_ELECTION_VOTE</div><div>Feb 3 07:02:49 vsa-0000004dc-vc-1 crmd: [1073]: debug: debug3: log_data_element: send_ha_message: HA[outbound] <create_request_adv origin="do_election_vote" t="crmd" version="3.0.1" subt="request" reference="vote-crmd-1328245369-6" crm_task="vote" crm_sys_to="crmd" crm_sys_from="crmd" election-owner="00001244-1244-0001-2b91-000000000001" election-id="3" /></div>
<div>Feb 3 07:02:49 vsa-0000004dc-vc-1 crmd: [1073]: debug: do_election_vote: Started election 3</div><div>Feb 3 07:02:49 vsa-0000004dc-vc-1 crmd: [1073]: debug: crm_timer_start: Started Election Timeout (I_ELECTION_DC:120000ms), src=24</div>
<div>Feb 3 07:02:49 vsa-0000004dc-vc-1 crmd: [1073]: debug: debug2: s_crmd_fsa: Exiting the FSA</div><div>Feb 3 07:02:49 vsa-0000004dc-vc-1 crmd: [1073]: debug: debug2: crm_fsa_trigger: Exited (queue len: 0)</div><div>
Feb 3 07:02:49 vsa-0000004dc-vc-1 crmd: [1073]: debug: debug2: crm_fsa_trigger: Invoked (queue len: 0)</div><div>Feb 3 07:02:49 vsa-0000004dc-vc-1 crmd: [1073]: debug: debug2: s_crmd_fsa: FSA invoked with Cause: C_FSA_INTERNAL#011State: S_ELECTION</div>
<div>Feb 3 07:02:49 vsa-0000004dc-vc-1 crmd: [1073]: debug: debug2: s_crmd_fsa: Exiting the FSA</div><div>Feb 3 07:02:49 vsa-0000004dc-vc-1 crmd: [1073]: debug: debug2: crm_fsa_trigger: Exited (queue len: 0)</div><div>
Feb 3 07:02:49 vsa-0000004dc-vc-1 crmd: [1073]: debug: debug2: cib_native_callback: Invoking callback join_query_callback for call 13</div><div>Feb 3 07:02:49 vsa-0000004dc-vc-1 crmd: [1073]: debug: join_query_callback: Respond to join offer join-1</div>
<div>Feb 3 07:02:49 vsa-0000004dc-vc-1 crmd: [1073]: debug: join_query_callback: Acknowledging (null) as our DC</div><div>Feb 3 07:02:49 vsa-0000004dc-vc-1 crmd: [1073]: debug: debug3: log_data_element: send_ha_message: HA[outbound] <create_request_adv origin="join_query_callback" t="crmd" version="3.0.1" subt="request" reference="join_request-crmd-1328245369-7" crm_task="join_request" crm_sys_to="dc" crm_sys_from="crmd" join_id="1" ></div>
<div>Feb 3 07:02:49 vsa-0000004dc-vc-1 crmd: [1073]: debug: debug3: log_data_element: send_ha_message: HA[outbound] <crm_xml ></div><div>Feb 3 07:02:49 vsa-0000004dc-vc-1 crmd: [1073]: debug: debug3: log_data_element: send_ha_message: HA[outbound] <generation_tuple validate-with="pacemaker-1.0" crm_feature_set="3.0.1" have-quorum="1" epoch="2" admin_epoch="1" num_updates="0" cib-last-written="Thu Feb 2 07:44:09 2012" /></div>
<div>Feb 3 07:02:49 vsa-0000004dc-vc-1 crmd: [1073]: debug: debug3: log_data_element: send_ha_message: HA[outbound] </crm_xml></div><div>Feb 3 07:02:49 vsa-0000004dc-vc-1 crmd: [1073]: debug: debug3: log_data_element: send_ha_message: HA[outbound] </create_request_adv></div>
<div>Feb 3 07:02:49 vsa-0000004dc-vc-1 crmd: [1073]: debug: debug2: cib_native_callback: Invoking global callback for call 13</div><div>Feb 3 07:02:49 vsa-0000004dc-vc-1 crmd: [1073]: debug: debug3: cib_native_msgready: No message pending</div>
<div>Feb 3 07:02:50 vsa-0000004dc-vc-1 heartbeat: [1023]: debug: hb_send_local_status() {</div><div>Feb 3 07:02:50 vsa-0000004dc-vc-1 crmd: [1073]: debug: debug3: ha_msg_dispatch: Invoked</div><div>Feb 3 07:02:50 vsa-0000004dc-vc-1 heartbeat: [1023]: debug: PID 1023: Sending local status curnode = 638e58 status: active</div>
<div>Feb 3 07:02:50 vsa-0000004dc-vc-1 crmd: [1073]: debug: debug2: crmd_ha_msg_callback: HA[inbound]: vote from vsa-0000004dc-vc-0</div><div>Feb 3 07:02:50 vsa-0000004dc-vc-1 heartbeat: [1023]: debug: process_clustermsg: node [vsa-0000004dc-vc-1]</div>
<div>Feb 3 07:02:50 vsa-0000004dc-vc-1 crmd: [1073]: debug: debug3: relay_message: Routing message vote-crmd-1328245369-4</div><div>Feb 3 07:02:50 vsa-0000004dc-vc-1 heartbeat: [1023]: debug: }/*hb_send_local_status*/;</div>
<div>Feb 3 07:02:50 vsa-0000004dc-vc-1 crmd: [1073]: debug: debug3: relay_message: Router result: Message result: CRMd process</div><div>Feb 3 07:02:50 vsa-0000004dc-vc-1 heartbeat: [1023]: debug: read_child_dispatch() {</div>
<div>Feb 3 07:02:50 vsa-0000004dc-vc-1 crmd: [1073]: debug: debug3: log_data_element: relay_message: router.log <create_request_adv origin="do_election_vote" t="crmd" version="3.0.1" subt="request" reference="vote-crmd-1328245369-4" crm_task="vote" crm_sys_to="crmd" crm_sys_from="crmd" election-owner="00001244-1244-0000-2b91-000000000000" election-id="3" oseq="2" from_id="crmd" to_id="crmd" client_gen="4" src="vsa-0000004dc-vc-0" seq="30" hg="4f2a2274" ts="4f2b6a79" ld="2.89 0.85 0.29 2/105 1463" ttl="3" auth="1 51ab53d3e8bcd21bf244b526b9d9e00ff229781b" /></div>
<div>Feb 3 07:02:50 vsa-0000004dc-vc-1 heartbeat: [1023]: debug: Packet authenticated</div><div>Feb 3 07:02:50 vsa-0000004dc-vc-1 crmd: [1073]: debug: debug2: register_fsa_input_adv: handle_request appended FSA input 13 (I_NULL) (cause=C_HA_MESSAGE) with data</div>
<div>Feb 3 07:02:50 vsa-0000004dc-vc-1 heartbeat: [1023]: debug: process_clustermsg: node [vsa-0000004dc-vc-0]</div><div>Feb 3 07:02:50 vsa-0000004dc-vc-1 crmd: [1073]: debug: debug3: register_fsa_input_adv: Adding actions 0000000200000400 to input</div>
<div>Feb 3 07:02:50 vsa-0000004dc-vc-1 heartbeat: [1023]: debug: }/*read_child_dispatch*/;</div><div>Feb 3 07:02:50 vsa-0000004dc-vc-1 crmd: [1073]: debug: debug3: register_fsa_input_adv: Copying C_HA_MESSAGE data from handle_request as a HA msg</div>
<div>Feb 3 07:02:50 vsa-0000004dc-vc-1 heartbeat: [1023]: debug: read_child_dispatch() {</div><div>Feb 3 07:02:50 vsa-0000004dc-vc-1 crmd: [1073]: debug: debug2: register_fsa_input_adv: Queue len: 1</div><div>Feb 3 07:02:50 vsa-0000004dc-vc-1 heartbeat: [1023]: debug: Packet authenticated</div>
<div>Feb 3 07:02:50 vsa-0000004dc-vc-1 crmd: [1073]: debug: debug3: register_fsa_input_adv: Triggering FSA: register_fsa_input_adv</div><div>Feb 3 07:02:50 vsa-0000004dc-vc-1 heartbeat: [1023]: debug: process_clustermsg: node [vsa-0000004dc-vc-0]</div>
<div>Feb 3 07:02:50 vsa-0000004dc-vc-1 crmd: [1073]: debug: debug3: crmd_ha_msg_filter: Triggering FSA: crmd_ha_msg_filter</div><div>Feb 3 07:02:50 vsa-0000004dc-vc-1 heartbeat: [1023]: debug: }/*read_child_dispatch*/;</div>
<div>Feb 3 07:02:50 vsa-0000004dc-vc-1 crmd: [1073]: debug: debug2: crmd_ha_msg_callback: HA[inbound]: vote from vsa-0000004dc-vc-1</div><div>Feb 3 07:02:50 vsa-0000004dc-vc-1 heartbeat: [1023]: debug: APIclients_input_dispatch() {</div>
<div>Feb 3 07:02:50 vsa-0000004dc-vc-1 crmd: [1073]: debug: debug3: relay_message: Routing message vote-crmd-1328245369-6</div><div>Feb 3 07:02:50 vsa-0000004dc-vc-1 heartbeat: [1023]: debug: ProcessAnAPIRequest() {</div>
<div>Feb 3 07:02:50 vsa-0000004dc-vc-1 crmd: [1073]: debug: debug3: relay_message: Router result: Message result: CRMd process</div><div>Feb 3 07:02:50 vsa-0000004dc-vc-1 heartbeat: [1023]: debug: Sending API message to cluster...</div>
<div>Feb 3 07:02:50 vsa-0000004dc-vc-1 crmd: [1073]: debug: debug3: log_data_element: relay_message: router.log <create_request_adv origin="do_election_vote" t="crmd" version="3.0.1" subt="request" reference="vote-crmd-1328245369-6" crm_task="vote" crm_sys_to="crmd" crm_sys_from="crmd" election-owner="00001244-1244-0001-2b91-000000000001" election-id="3" oseq="2" from_id="crmd" to_id="crmd" client_gen="4" src="vsa-0000004dc-vc-1" seq="31" hg="4f2a227c" ts="4f2b6a7a" ld="3.01 0.88 0.30 5/106 1372" ttl="3" auth="1 27a5f24827f1ca0d08946dea098d0a43404f341a" /></div>
<div>Feb 3 07:02:50 vsa-0000004dc-vc-1 heartbeat: [1023]: debug: MSG: Dumping message with 14 fields</div><div>Feb 3 07:02:50 vsa-0000004dc-vc-1 crmd: [1073]: debug: debug2: register_fsa_input_adv: handle_request appended FSA input 14 (I_NULL) (cause=C_HA_MESSAGE) with data</div>
<div>Feb 3 07:02:50 vsa-0000004dc-vc-1 heartbeat: [1023]: debug: MSG[0] : [__name__=create_request_adv]</div><div>Feb 3 07:02:50 vsa-0000004dc-vc-1 crmd: [1073]: debug: debug3: register_fsa_input_adv: Adding actions 0000000200000400 to input</div>
<div>Feb 3 07:02:50 vsa-0000004dc-vc-1 heartbeat: [1023]: debug: MSG[1] : [origin=do_election_vote]</div><div>Feb 3 07:02:50 vsa-0000004dc-vc-1 crmd: [1073]: debug: debug3: register_fsa_input_adv: Copying C_HA_MESSAGE data from handle_request as a HA msg</div>
<div>Feb 3 07:02:50 vsa-0000004dc-vc-1 heartbeat: [1023]: debug: MSG[2] : [t=crmd]</div><div>Feb 3 07:02:50 vsa-0000004dc-vc-1 crmd: [1073]: debug: debug2: register_fsa_input_adv: Queue len: 2</div><div>Feb 3 07:02:50 vsa-0000004dc-vc-1 heartbeat: [1023]: debug: MSG[3] : [version=3.0.1]</div>
<div>Feb 3 07:02:50 vsa-0000004dc-vc-1 crmd: [1073]: debug: debug3: register_fsa_input_adv: Triggering FSA: register_fsa_input_adv</div><div>Feb 3 07:02:50 vsa-0000004dc-vc-1 heartbeat: [1023]: debug: MSG[4] : [subt=request]</div>
<div>Feb 3 07:02:50 vsa-0000004dc-vc-1 crmd: [1073]: debug: debug3: crmd_ha_msg_filter: Triggering FSA: crmd_ha_msg_filter</div><div>Feb 3 07:02:50 vsa-0000004dc-vc-1 heartbeat: [1023]: debug: MSG[5] : [reference=vote-crmd-1328245369-6]</div>
<div>Feb 3 07:02:50 vsa-0000004dc-vc-1 crmd: [1073]: debug: debug2: crmd_ha_msg_callback: HA[inbound]: join_request from vsa-0000004dc-vc-1</div><div>Feb 3 07:02:50 vsa-0000004dc-vc-1 heartbeat: [1023]: debug: MSG[6] : [crm_task=vote]</div>
<div>Feb 3 07:02:50 vsa-0000004dc-vc-1 crmd: [1073]: debug: debug3: relay_message: Routing message join_request-crmd-1328245369-7</div><div>Feb 3 07:02:50 vsa-0000004dc-vc-1 heartbeat: [1023]: debug: MSG[7] : [crm_sys_to=crmd]</div>
<div>Feb 3 07:02:50 vsa-0000004dc-vc-1 crmd: [1073]: debug: debug3: relay_message: Router result: Message result: DC/CRMd process</div><div>Feb 3 07:02:50 vsa-0000004dc-vc-1 heartbeat: [1023]: debug: MSG[8] : [crm_sys_from=crmd]</div>
<div>Feb 3 07:02:50 vsa-0000004dc-vc-1 crmd: [1073]: debug: debug3: log_data_element: relay_message: router.log <create_request_adv origin="join_query_callback" t="crmd" version="3.0.1" subt="request" reference="join_request-crmd-1328245369-7" crm_task="join_request" crm_sys_to="dc" crm_sys_from="crmd" join_id="1" oseq="3" from_id="crmd" to_id="crmd" client_gen="4" src="vsa-0000004dc-vc-1" seq="32" hg="4f2a227c" ts="4f2b6a7a" ld="3.01 0.88 0.30 5/106 1372" ttl="3" auth="1 30d8bfc913c4f2ecf2fef96420e1f98e6dbf97e4" ></div>
<div>Feb 3 07:02:50 vsa-0000004dc-vc-1 heartbeat: [1023]: debug: MSG[9] : [election-owner=00001244-1244-0001-2b91-000000000001]</div><div>Feb 3 07:02:50 vsa-0000004dc-vc-1 crmd: [1073]: debug: debug3: log_data_element: relay_message: router.log <crm_xml ></div>
<div>Feb 3 07:02:50 vsa-0000004dc-vc-1 heartbeat: [1023]: debug: MSG[10] : [election-id=3]</div><div>Feb 3 07:02:50 vsa-0000004dc-vc-1 crmd: [1073]: debug: debug3: log_data_element: relay_message: router.log <generation_tuple validate-with="pacemaker-1.0" crm_feature_set="3.0.1" have-quorum="1" epoch="2" admin_epoch="1" num_updates="0" cib-last-written="Thu Feb 2 07:44:09 2012" /></div>
<div>Feb 3 07:02:50 vsa-0000004dc-vc-1 heartbeat: [1023]: debug: MSG[11] : [oseq=2]</div><div>Feb 3 07:02:50 vsa-0000004dc-vc-1 crmd: [1073]: debug: debug3: log_data_element: relay_message: router.log </crm_xml></div>
<div>Feb 3 07:02:50 vsa-0000004dc-vc-1 heartbeat: [1023]: debug: MSG[12] : [from_id=crmd]</div><div>Feb 3 07:02:50 vsa-0000004dc-vc-1 crmd: [1073]: debug: debug3: log_data_element: relay_message: router.log </create_request_adv></div>
<div>Feb 3 07:02:50 vsa-0000004dc-vc-1 heartbeat: [1023]: debug: MSG[13] : [to_id=crmd]</div><div>Feb 3 07:02:50 vsa-0000004dc-vc-1 crmd: [1073]: debug: debug2: register_fsa_input_adv: route_message appended FSA input 15 (I_JOIN_REQUEST) (cause=C_HA_MESSAGE) with data</div>
<div>Feb 3 07:02:50 vsa-0000004dc-vc-1 heartbeat: [1023]: debug: process_clustermsg: node [vsa-0000004dc-vc-1]</div><div>Feb 3 07:02:50 vsa-0000004dc-vc-1 crmd: [1073]: debug: debug3: register_fsa_input_adv: Copying C_HA_MESSAGE data from route_message as a HA msg</div>
<div>Feb 3 07:02:50 vsa-0000004dc-vc-1 heartbeat: [1023]: debug: #011return TRUE;</div><div>Feb 3 07:02:50 vsa-0000004dc-vc-1 crmd: [1073]: debug: debug2: register_fsa_input_adv: Queue len: 3</div><div>Feb 3 07:02:50 vsa-0000004dc-vc-1 heartbeat: [1023]: debug: }/*ProcessAnAPIRequest*/;</div>
<div>Feb 3 07:02:50 vsa-0000004dc-vc-1 crmd: [1073]: debug: debug3: register_fsa_input_adv: Triggering FSA: register_fsa_input_adv</div><div>Feb 3 07:02:50 vsa-0000004dc-vc-1 heartbeat: [1023]: debug: return 1;</div><div>
Feb 3 07:02:50 vsa-0000004dc-vc-1 crmd: [1073]: debug: debug3: crmd_ha_msg_filter: Triggering FSA: crmd_ha_msg_filter</div><div>Feb 3 07:02:50 vsa-0000004dc-vc-1 heartbeat: [1023]: debug: }/*APIclients_input_dispatch*/;</div>
<div>Feb 3 07:02:50 vsa-0000004dc-vc-1 crmd: [1073]: debug: debug2: crm_fsa_trigger: Invoked (queue len: 3)</div><div>Feb 3 07:02:50 vsa-0000004dc-vc-1 heartbeat: [1023]: debug: APIclients_input_dispatch() {</div><div>Feb 3 07:02:50 vsa-0000004dc-vc-1 crmd: [1073]: debug: debug2: s_crmd_fsa: FSA invoked with Cause: C_FSA_INTERNAL#011State: S_ELECTION</div>
<div>Feb 3 07:02:50 vsa-0000004dc-vc-1 heartbeat: [1023]: debug: ProcessAnAPIRequest() {</div><div>Feb 3 07:02:50 vsa-0000004dc-vc-1 crmd: [1073]: debug: debug2: s_crmd_fsa: Checking messages (3 remaining)</div><div>Feb 3 07:02:50 vsa-0000004dc-vc-1 heartbeat: [1023]: debug: Sending API message to cluster...</div>
<div>Feb 3 07:02:50 vsa-0000004dc-vc-1 crmd: [1073]: debug: debug2: get_message: Processing input 13</div><div>Feb 3 07:02:50 vsa-0000004dc-vc-1 heartbeat: [1023]: debug: MSG: Dumping message with 14 fields</div><div>Feb 3 07:02:50 vsa-0000004dc-vc-1 crmd: [1073]: debug: debug2: log_fsa_input: Processing queued input 13</div>
<div>Feb 3 07:02:50 vsa-0000004dc-vc-1 heartbeat: [1023]: debug: MSG[0] : [__name__=create_request_adv]</div><div>Feb 3 07:02:50 vsa-0000004dc-vc-1 crmd: [1073]: debug: debug3: log_fsa_input: FSA processing XML message from handle_request</div>
<div>Feb 3 07:02:50 vsa-0000004dc-vc-1 heartbeat: [1023]: debug: MSG[1] : [origin=join_query_callback]</div><div>Feb 3 07:02:50 vsa-0000004dc-vc-1 crmd: [1073]: debug: debug3: print_xml_formatted: log_fsa_input: FSA message data: NULL</div>
<div>Feb 3 07:02:50 vsa-0000004dc-vc-1 heartbeat: [1023]: debug: MSG[2] : [t=crmd]</div><div>Feb 3 07:02:50 vsa-0000004dc-vc-1 crmd: [1073]: debug: debug2: s_crmd_fsa: actions:trace: #011// FSA input: State=S_ELECTION #011Cause=C_HA_MESSAGE #011Input=I_NULL #011Origin=handle_request() #011id=13</div>
<div>Feb 3 07:02:50 vsa-0000004dc-vc-1 heartbeat: [1023]: debug: MSG[3] : [version=3.0.1]</div><div>Feb 3 07:02:50 vsa-0000004dc-vc-1 crmd: [1073]: debug: do_fsa_action: actions:trace: #011// A_ELECTION_COUNT</div><div>
Feb 3 07:02:50 vsa-0000004dc-vc-1 heartbeat: [1023]: debug: MSG[4] : [subt=request]</div><div>Feb 3 07:02:50 vsa-0000004dc-vc-1 crmd: [1073]: debug: do_election_count_vote: Created voted hash</div><div>Feb 3 07:02:50 vsa-0000004dc-vc-1 heartbeat: [1023]: debug: MSG[5] : [reference=join_request-crmd-1328245369-7]</div>
<div>Feb 3 07:02:50 vsa-0000004dc-vc-1 crmd: [1073]: debug: debug3: compare_version: 3.0.1 == 3.0.1 (4)</div><div>Feb 3 07:02:50 vsa-0000004dc-vc-1 heartbeat: [1023]: debug: MSG[6] : [crm_task=join_request]</div><div>Feb 3 07:02:50 vsa-0000004dc-vc-1 crmd: [1073]: debug: debug3: compare_version: 3.0.1 == 3.0.1 (4)</div>
<div>Feb 3 07:02:50 vsa-0000004dc-vc-1 heartbeat: [1023]: debug: MSG[7] : [crm_sys_to=dc]</div><div>Feb 3 07:02:50 vsa-0000004dc-vc-1 crmd: [1073]: info: do_election_count_vote: Election 3 (owner: 00001244-1244-0000-2b91-000000000000) pass: vote from vsa-0000004dc-vc-0 (Age)</div>
<div>Feb 3 07:02:50 vsa-0000004dc-vc-1 heartbeat: [1023]: debug: MSG[8] : [crm_sys_from=crmd]</div><div>Feb 3 07:02:50 vsa-0000004dc-vc-1 crmd: [1073]: debug: debug2: register_fsa_input_adv: do_election_count_vote appended FSA input 16 (I_ELECTION) (cause=C_FSA_INTERNAL) without data</div>
<div>Feb 3 07:02:50 vsa-0000004dc-vc-1 heartbeat: [1023]: debug: MSG[9] : [join_id=1]</div><div>Feb 3 07:02:50 vsa-0000004dc-vc-1 crmd: [1073]: debug: debug2: register_fsa_input_adv: Queue len: 3</div><div>Feb 3 07:02:50 vsa-0000004dc-vc-1 heartbeat: [1023]: debug: MSG[10] : [crm_xml=<crm_xml><generation_tuple validate-with="pacemaker-1.0" crm_feature_set="3.0.1" have-quorum="1" epoch="2" admin_epoch="1" num_updates="0" cib-last-written="Thu Feb 2 07:44:09 2012"/></crm_xml>]</div>
<div>Feb 3 07:02:50 vsa-0000004dc-vc-1 crmd: [1073]: debug: debug3: register_fsa_input_adv: Triggering FSA: register_fsa_input_adv</div><div>Feb 3 07:02:50 vsa-0000004dc-vc-1 heartbeat: [1023]: debug: MSG[11] : [oseq=3]</div>
<div>Feb 3 07:02:50 vsa-0000004dc-vc-1 crmd: [1073]: debug: do_fsa_action: actions:trace: #011// A_ELECTION_CHECK</div><div>Feb 3 07:02:50 vsa-0000004dc-vc-1 heartbeat: [1023]: debug: MSG[12] : [from_id=crmd]</div><div>
Feb 3 07:02:50 vsa-0000004dc-vc-1 crmd: [1073]: debug: do_election_check: Still waiting on 2 non-votes (2 total)</div><div>Feb 3 07:02:50 vsa-0000004dc-vc-1 heartbeat: [1023]: debug: MSG[13] : [to_id=crmd]</div><div>Feb 3 07:02:50 vsa-0000004dc-vc-1 crmd: [1073]: debug: debug2: s_crmd_fsa: Checking messages (3 remaining)</div>
<div>Feb 3 07:02:50 vsa-0000004dc-vc-1 heartbeat: [1023]: debug: process_clustermsg: node [vsa-0000004dc-vc-1]</div><div>Feb 3 07:02:50 vsa-0000004dc-vc-1 crmd: [1073]: debug: debug2: get_message: Processing input 14</div>
<div>Feb 3 07:02:50 vsa-0000004dc-vc-1 heartbeat: [1023]: debug: #011return TRUE;</div><div>Feb 3 07:02:50 vsa-0000004dc-vc-1 crmd: [1073]: debug: debug2: log_fsa_input: Processing queued input 14</div><div>Feb 3 07:02:50 vsa-0000004dc-vc-1 heartbeat: [1023]: debug: }/*ProcessAnAPIRequest*/;</div>
<div>Feb 3 07:02:50 vsa-0000004dc-vc-1 crmd: [1073]: debug: debug3: log_fsa_input: FSA processing XML message from handle_request</div><div>Feb 3 07:02:50 vsa-0000004dc-vc-1 heartbeat: [1023]: debug: return 1;</div><div>
Feb 3 07:02:50 vsa-0000004dc-vc-1 crmd: [1073]: debug: debug3: print_xml_formatted: log_fsa_input: FSA message data: NULL</div><div>Feb 3 07:02:50 vsa-0000004dc-vc-1 heartbeat: [1023]: debug: }/*APIclients_input_dispatch*/;</div>
<div>Feb 3 07:02:50 vsa-0000004dc-vc-1 crmd: [1073]: debug: debug2: s_crmd_fsa: actions:trace: #011// FSA input: State=S_ELECTION #011Cause=C_HA_MESSAGE #011Input=I_NULL #011Origin=handle_request() #011id=14</div><div>Feb 3 07:02:50 vsa-0000004dc-vc-1 heartbeat: [1023]: debug: APIclients_input_dispatch() {</div>
<div>Feb 3 07:02:50 vsa-0000004dc-vc-1 crmd: [1073]: debug: do_fsa_action: actions:trace: #011// A_ELECTION_COUNT</div><div>Feb 3 07:02:50 vsa-0000004dc-vc-1 heartbeat: [1023]: debug: ProcessAnAPIRequest() {</div><div>Feb 3 07:02:50 vsa-0000004dc-vc-1 crmd: [1073]: debug: do_election_count_vote: Created voted hash</div>
<div>Feb 3 07:02:50 vsa-0000004dc-vc-1 heartbeat: [1023]: debug: Sending API message to cluster...</div><div>Feb 3 07:02:50 vsa-0000004dc-vc-1 crmd: [1073]: debug: do_election_count_vote: Election 3 (current: 3, owner: 00001244-1244-0001-2b91-000000000001): Processed vote from vsa-0000004dc-vc-1 (Recorded)</div>
<div>Feb 3 07:02:50 vsa-0000004dc-vc-1 heartbeat: [1023]: debug: MSG: Dumping message with 14 fields</div><div>Feb 3 07:02:50 vsa-0000004dc-vc-1 crmd: [1073]: debug: do_fsa_action: actions:trace: #011// A_ELECTION_CHECK</div>
<div>Feb 3 07:02:50 vsa-0000004dc-vc-1 heartbeat: [1023]: debug: MSG[0] : [__name__=create_request_adv]</div><div>Feb 3 07:02:50 vsa-0000004dc-vc-1 crmd: [1073]: debug: do_election_check: Still waiting on 1 non-votes (2 total)</div>
<div>Feb 3 07:02:50 vsa-0000004dc-vc-1 heartbeat: [1023]: debug: MSG[1] : [origin=do_election_vote]</div><div>Feb 3 07:02:50 vsa-0000004dc-vc-1 crmd: [1073]: debug: debug2: s_crmd_fsa: Checking messages (2 remaining)</div>
<div>Feb 3 07:02:50 vsa-0000004dc-vc-1 heartbeat: [1023]: debug: MSG[2] : [t=crmd]</div><div>Feb 3 07:02:50 vsa-0000004dc-vc-1 crmd: [1073]: debug: debug2: get_message: Processing input 15</div><div>Feb 3 07:02:50 vsa-0000004dc-vc-1 heartbeat: [1023]: debug: MSG[3] : [version=3.0.1]</div>
<div>Feb 3 07:02:50 vsa-0000004dc-vc-1 crmd: [1073]: debug: debug2: log_fsa_input: Processing queued input 15</div><div>Feb 3 07:02:50 vsa-0000004dc-vc-1 heartbeat: [1023]: debug: MSG[4] : [subt=request]</div><div>Feb 3 07:02:50 vsa-0000004dc-vc-1 crmd: [1073]: debug: debug3: log_fsa_input: FSA processing XML message from route_message</div>
<div>Feb 3 07:02:50 vsa-0000004dc-vc-1 heartbeat: [1023]: debug: MSG[5] : [reference=vote-crmd-1328245370-8]</div><div>Feb 3 07:02:50 vsa-0000004dc-vc-1 crmd: [1073]: debug: debug3: log_data_element: log_fsa_input: FSA message data <generation_tuple validate-with="pacemaker-1.0" crm_feature_set="3.0.1" have-quorum="1" epoch="2" admin_epoch="1" num_updates="0" cib-last-written="Thu Feb 2 07:44:09 2012" /></div>
<div>Feb 3 07:02:50 vsa-0000004dc-vc-1 heartbeat: [1023]: debug: MSG[6] : [crm_task=vote]</div><div>Feb 3 07:02:50 vsa-0000004dc-vc-1 crmd: [1073]: debug: s_crmd_fsa: Processing I_JOIN_REQUEST: [ state=S_ELECTION cause=C_HA_MESSAGE origin=route_message ]</div>
<div>Feb 3 07:02:50 vsa-0000004dc-vc-1 heartbeat: [1023]: debug: MSG[7] : [crm_sys_to=crmd]</div><div>Feb 3 07:02:50 vsa-0000004dc-vc-1 crmd: [1073]: debug: do_fsa_action: actions:trace: #011// A_WARN</div><div>Feb 3 07:02:50 vsa-0000004dc-vc-1 heartbeat: [1023]: debug: MSG[8] : [crm_sys_from=crmd]</div>
<div>Feb 3 07:02:50 vsa-0000004dc-vc-1 crmd: [1073]: WARN: do_log: FSA: Input I_JOIN_REQUEST from route_message() received in state S_ELECTION</div><div>Feb 3 07:02:50 vsa-0000004dc-vc-1 heartbeat: [1023]: debug: MSG[9] : [election-owner=00001244-1244-0001-2b91-000000000001]</div>
<div>Feb 3 07:02:50 vsa-0000004dc-vc-1 crmd: [1073]: debug: debug2: s_crmd_fsa: actions:trace: #011// FSA input: State=S_ELECTION #011Cause=C_HA_MESSAGE #011Input=I_JOIN_REQUEST #011Origin=route_message() #011id=15</div>
<div>Feb 3 07:02:50 vsa-0000004dc-vc-1 heartbeat: [1023]: debug: MSG[10] : [election-id=4]</div><div>Feb 3 07:02:50 vsa-0000004dc-vc-1 crmd: [1073]: debug: debug2: s_crmd_fsa: Checking messages (1 remaining)</div><div>Feb 3 07:02:50 vsa-0000004dc-vc-1 heartbeat: [1023]: debug: MSG[11] : [oseq=4]</div>
<div>Feb 3 07:02:50 vsa-0000004dc-vc-1 crmd: [1073]: debug: debug2: get_message: Processing input 16</div><div>Feb 3 07:02:50 vsa-0000004dc-vc-1 heartbeat: [1023]: debug: MSG[12] : [from_id=crmd]</div><div>Feb 3 07:02:50 vsa-0000004dc-vc-1 crmd: [1073]: debug: debug2: log_fsa_input: Processing queued input 16</div>
<div>Feb 3 07:02:50 vsa-0000004dc-vc-1 heartbeat: [1023]: debug: MSG[13] : [to_id=crmd]</div><div>Feb 3 07:02:50 vsa-0000004dc-vc-1 crmd: [1073]: debug: debug3: log_fsa_input: FSA processing input from do_election_count_vote</div>
<div>Feb 3 07:02:50 vsa-0000004dc-vc-1 heartbeat: [1023]: debug: process_clustermsg: node [vsa-0000004dc-vc-1]</div><div>Feb 3 07:02:50 vsa-0000004dc-vc-1 crmd: [1073]: debug: s_crmd_fsa: Processing I_ELECTION: [ state=S_ELECTION cause=C_FSA_INTERNAL origin=do_election_count_vote ]</div>
<div>Feb 3 07:02:50 vsa-0000004dc-vc-1 heartbeat: [1023]: debug: #011return TRUE;</div><div>Feb 3 07:02:50 vsa-0000004dc-vc-1 crmd: [1073]: debug: debug2: s_crmd_fsa: actions:trace: #011// FSA input: State=S_ELECTION #011Cause=C_FSA_INTERNAL #011Input=I_ELECTION #011Origin=do_election_count_vote() #011id=16</div>
<div>Feb 3 07:02:50 vsa-0000004dc-vc-1 heartbeat: [1023]: debug: }/*ProcessAnAPIRequest*/;</div><div>Feb 3 07:02:50 vsa-0000004dc-vc-1 crmd: [1073]: debug: do_fsa_action: actions:trace: #011// A_ELECTION_VOTE</div><div>
Feb 3 07:02:50 vsa-0000004dc-vc-1 heartbeat: [1023]: debug: return 1;</div><div>Feb 3 07:02:50 vsa-0000004dc-vc-1 crmd: [1073]: debug: debug3: log_data_element: send_ha_message: HA[outbound] <create_request_adv origin="do_election_vote" t="crmd" version="3.0.1" subt="request" reference="vote-crmd-1328245370-8" crm_task="vote" crm_sys_to="crmd" crm_sys_from="crmd" election-owner="00001244-1244-0001-2b91-000000000001" election-id="4" /></div>
<div>Feb 3 07:02:50 vsa-0000004dc-vc-1 heartbeat: [1023]: debug: }/*APIclients_input_dispatch*/;</div><div>Feb 3 07:02:50 vsa-0000004dc-vc-1 crmd: [1073]: debug: do_election_vote: Started election 4</div><div>Feb 3 07:02:50 vsa-0000004dc-vc-1 crmd: [1073]: debug: crm_timer_start: Election Timeout (I_ELECTION_DC:120000ms) already running: src=24</div>
<div>Feb 3 07:02:50 vsa-0000004dc-vc-1 crmd: [1073]: debug: debug2: s_crmd_fsa: Exiting the FSA</div><div>Feb 3 07:02:50 vsa-0000004dc-vc-1 crmd: [1073]: debug: debug2: crm_fsa_trigger: Exited (queue len: 0)</div><div>
Feb 3 07:02:50 vsa-0000004dc-vc-1 crmd: [1073]: debug: debug2: crm_fsa_trigger: Invoked (queue len: 0)</div><div>Feb 3 07:02:50 vsa-0000004dc-vc-1 crmd: [1073]: debug: debug2: s_crmd_fsa: FSA invoked with Cause: C_FSA_INTERNAL#011State: S_ELECTION</div>
<div>Feb 3 07:02:50 vsa-0000004dc-vc-1 crmd: [1073]: debug: debug2: s_crmd_fsa: Exiting the FSA</div><div>Feb 3 07:02:50 vsa-0000004dc-vc-1 crmd: [1073]: debug: debug2: crm_fsa_trigger: Exited (queue len: 0)</div><div>
Feb 3 07:02:50 vsa-0000004dc-vc-1 crmd: [1073]: debug: debug3: ha_msg_dispatch: Invoked</div><div>Feb 3 07:02:50 vsa-0000004dc-vc-1 crmd: [1073]: debug: debug2: crmd_ha_msg_callback: HA[inbound]: vote from vsa-0000004dc-vc-1</div>
<div>Feb 3 07:02:50 vsa-0000004dc-vc-1 crmd: [1073]: debug: debug3: relay_message: Routing message vote-crmd-1328245370-8</div><div>Feb 3 07:02:50 vsa-0000004dc-vc-1 crmd: [1073]: debug: debug3: relay_message: Router result: Message result: CRMd process</div>
<div>Feb 3 07:02:50 vsa-0000004dc-vc-1 crmd: [1073]: debug: debug3: log_data_element: relay_message: router.log <create_request_adv origin="do_election_vote" t="crmd" version="3.0.1" subt="request" reference="vote-crmd-1328245370-8" crm_task="vote" crm_sys_to="crmd" crm_sys_from="crmd" election-owner="00001244-1244-0001-2b91-000000000001" election-id="4" oseq="4" from_id="crmd" to_id="crmd" client_gen="4" src="vsa-0000004dc-vc-1" seq="33" hg="4f2a227c" ts="4f2b6a7a" ld="3.01 0.88 0.30 4/106 1372" ttl="3" auth="1 4cb5c076b4cd9b89a4c5daa0866b59ccb8158a58" /></div>
<div>Feb 3 07:02:50 vsa-0000004dc-vc-1 crmd: [1073]: debug: debug2: register_fsa_input_adv: handle_request appended FSA input 17 (I_NULL) (cause=C_HA_MESSAGE) with data</div><div>Feb 3 07:02:50 vsa-0000004dc-vc-1 crmd: [1073]: debug: debug3: register_fsa_input_adv: Adding actions 0000000200000400 to input</div>
<div>Feb 3 07:02:50 vsa-0000004dc-vc-1 crmd: [1073]: debug: debug3: register_fsa_input_adv: Copying C_HA_MESSAGE data from handle_request as a HA msg</div><div>Feb 3 07:02:50 vsa-0000004dc-vc-1 crmd: [1073]: debug: debug2: register_fsa_input_adv: Queue len: 1</div>
<div>Feb 3 07:02:50 vsa-0000004dc-vc-1 crmd: [1073]: debug: debug3: register_fsa_input_adv: Triggering FSA: register_fsa_input_adv</div><div>Feb 3 07:02:50 vsa-0000004dc-vc-1 crmd: [1073]: debug: debug3: crmd_ha_msg_filter: Triggering FSA: crmd_ha_msg_filter</div>
<div>Feb 3 07:02:50 vsa-0000004dc-vc-1 crmd: [1073]: debug: debug2: crm_fsa_trigger: Invoked (queue len: 1)</div><div>Feb 3 07:02:50 vsa-0000004dc-vc-1 crmd: [1073]: debug: debug2: s_crmd_fsa: FSA invoked with Cause: C_FSA_INTERNAL#011State: S_ELECTION</div>
<div>Feb 3 07:02:50 vsa-0000004dc-vc-1 crmd: [1073]: debug: debug2: s_crmd_fsa: Checking messages (1 remaining)</div><div>Feb 3 07:02:50 vsa-0000004dc-vc-1 crmd: [1073]: debug: debug2: get_message: Processing input 17</div>
<div>Feb 3 07:02:50 vsa-0000004dc-vc-1 crmd: [1073]: debug: debug2: log_fsa_input: Processing queued input 17</div><div>Feb 3 07:02:50 vsa-0000004dc-vc-1 crmd: [1073]: debug: debug3: log_fsa_input: FSA processing XML message from handle_request</div>
<div>Feb 3 07:02:50 vsa-0000004dc-vc-1 crmd: [1073]: debug: debug3: print_xml_formatted: log_fsa_input: FSA message data: NULL</div><div>Feb 3 07:02:50 vsa-0000004dc-vc-1 crmd: [1073]: debug: debug2: s_crmd_fsa: actions:trace: #011// FSA input: State=S_ELECTION #011Cause=C_HA_MESSAGE #011Input=I_NULL #011Origin=handle_request() #011id=17</div>
<div>Feb 3 07:02:50 vsa-0000004dc-vc-1 crmd: [1073]: debug: do_fsa_action: actions:trace: #011// A_ELECTION_COUNT</div><div>Feb 3 07:02:50 vsa-0000004dc-vc-1 crmd: [1073]: debug: do_election_count_vote: Created voted hash</div>
<div>Feb 3 07:02:50 vsa-0000004dc-vc-1 crmd: [1073]: debug: do_election_count_vote: Election 4 (current: 4, owner: 00001244-1244-0001-2b91-000000000001): Processed vote from vsa-0000004dc-vc-1 (Recorded)</div><div>Feb 3 07:02:50 vsa-0000004dc-vc-1 crmd: [1073]: debug: do_fsa_action: actions:trace: #011// A_ELECTION_CHECK</div>
<div>Feb 3 07:02:50 vsa-0000004dc-vc-1 crmd: [1073]: debug: do_election_check: Still waiting on 1 non-votes (2 total)</div><div>Feb 3 07:02:50 vsa-0000004dc-vc-1 crmd: [1073]: debug: debug2: s_crmd_fsa: Exiting the FSA</div>
<div>Feb 3 07:02:50 vsa-0000004dc-vc-1 crmd: [1073]: debug: debug2: crm_fsa_trigger: Exited (queue len: 0)</div><div>Feb 3 07:02:50 vsa-0000004dc-vc-1 heartbeat: [1023]: debug: read_child_dispatch() {</div><div>Feb 3 07:02:50 vsa-0000004dc-vc-1 crmd: [1073]: debug: debug3: ha_msg_dispatch: Invoked</div>
<div>Feb 3 07:02:50 vsa-0000004dc-vc-1 heartbeat: [1023]: debug: Packet authenticated</div><div>Feb 3 07:02:50 vsa-0000004dc-vc-1 crmd: [1073]: debug: debug2: crmd_ha_msg_callback: HA[inbound]: no-vote from vsa-0000004dc-vc-0</div>
<div>Feb 3 07:02:50 vsa-0000004dc-vc-1 heartbeat: [1023]: debug: process_clustermsg: node [vsa-0000004dc-vc-0]</div><div>Feb 3 07:02:50 vsa-0000004dc-vc-1 crmd: [1073]: debug: debug3: relay_message: Routing message no-vote-crmd-1328245370-5</div>
<div>Feb 3 07:02:50 vsa-0000004dc-vc-1 heartbeat: [1023]: debug: }/*read_child_dispatch*/;</div><div>Feb 3 07:02:50 vsa-0000004dc-vc-1 crmd: [1073]: debug: debug3: relay_message: Router result: Message result: CRMd process</div>
<div>Feb 3 07:02:50 vsa-0000004dc-vc-1 heartbeat: [1023]: debug: read_child_dispatch() {</div><div>Feb 3 07:02:50 vsa-0000004dc-vc-1 crmd: [1073]: debug: debug3: log_data_element: relay_message: router.log <create_request_adv origin="do_election_count_vote" t="crmd" version="3.0.1" subt="request" reference="no-vote-crmd-1328245370-5" crm_task="no-vote" crm_sys_to="crmd" crm_sys_from="crmd" crm_host_to="vsa-0000004dc-vc-1" election-owner="00001244-1244-0001-2b91-000000000001" election-id="3" dest="vsa-0000004dc-vc-1" oseq="2" from_id="crmd" to_id="crmd" client_gen="4" src="vsa-0000004dc-vc-0" seq="32" hg="4f2a2274" ts="4f2b6a7a" ld="2.89 0.85 0.29 4/105 1463" ttl="3" auth="1 0ded73bd06ebe658943f0f73fae2151b9cb6b229" /></div>
<div>Feb 3 07:02:50 vsa-0000004dc-vc-1 heartbeat: [1023]: debug: Packet authenticated</div><div>Feb 3 07:02:50 vsa-0000004dc-vc-1 crmd: [1073]: debug: debug2: register_fsa_input_adv: handle_request appended FSA input 18 (I_NULL) (cause=C_HA_MESSAGE) with data</div>
<div>Feb 3 07:02:50 vsa-0000004dc-vc-1 heartbeat: [1023]: debug: process_clustermsg: node [vsa-0000004dc-vc-0]</div><div>Feb 3 07:02:50 vsa-0000004dc-vc-1 crmd: [1073]: debug: debug3: register_fsa_input_adv: Adding actions 0000000200000400 to input</div>
<div>Feb 3 07:02:50 vsa-0000004dc-vc-1 heartbeat: [1023]: debug: }/*read_child_dispatch*/;</div><div>Feb 3 07:02:50 vsa-0000004dc-vc-1 crmd: [1073]: debug: debug3: register_fsa_input_adv: Copying C_HA_MESSAGE data from handle_request as a HA msg</div>
<div>Feb 3 07:02:50 vsa-0000004dc-vc-1 heartbeat: [1023]: debug: read_child_dispatch() {</div><div>Feb 3 07:02:50 vsa-0000004dc-vc-1 crmd: [1073]: debug: debug2: register_fsa_input_adv: Queue len: 1</div><div>Feb 3 07:02:50 vsa-0000004dc-vc-1 heartbeat: [1023]: debug: Packet authenticated</div>
<div>Feb 3 07:02:50 vsa-0000004dc-vc-1 crmd: [1073]: debug: debug3: register_fsa_input_adv: Triggering FSA: register_fsa_input_adv</div><div>Feb 3 07:02:50 vsa-0000004dc-vc-1 heartbeat: [1023]: debug: process_clustermsg: node [vsa-0000004dc-vc-0]</div>
<div>Feb 3 07:02:50 vsa-0000004dc-vc-1 crmd: [1073]: debug: debug3: crmd_ha_msg_filter: Triggering FSA: crmd_ha_msg_filter</div><div>Feb 3 07:02:50 vsa-0000004dc-vc-1 heartbeat: [1023]: debug: }/*read_child_dispatch*/;</div>
<div>Feb 3 07:02:50 vsa-0000004dc-vc-1 crmd: [1073]: debug: debug2: crmd_ha_msg_callback: HA[inbound]: no-vote from vsa-0000004dc-vc-0</div><div>Feb 3 07:02:50 vsa-0000004dc-vc-1 heartbeat: [1023]: debug: read_child_dispatch() {</div>
<div>Feb 3 07:02:50 vsa-0000004dc-vc-1 crmd: [1073]: debug: debug3: relay_message: Routing message no-vote-crmd-1328245370-6</div><div>Feb 3 07:02:50 vsa-0000004dc-vc-1 heartbeat: [1023]: debug: Packet authenticated</div>
<div>Feb 3 07:02:50 vsa-0000004dc-vc-1 crmd: [1073]: debug: debug3: relay_message: Router result: Message result: CRMd process</div><div>Feb 3 07:02:50 vsa-0000004dc-vc-1 heartbeat: [1023]: debug: process_clustermsg: node [vsa-0000004dc-vc-0]</div>
<div>Feb 3 07:02:50 vsa-0000004dc-vc-1 crmd: [1073]: debug: debug3: log_data_element: relay_message: router.log <create_request_adv origin="do_election_count_vote" t="crmd" version="3.0.1" subt="request" reference="no-vote-crmd-1328245370-6" crm_task="no-vote" crm_sys_to="crmd" crm_sys_from="crmd" crm_host_to="vsa-0000004dc-vc-1" election-owner="00001244-1244-0001-2b91-000000000001" election-id="4" dest="vsa-0000004dc-vc-1" oseq="3" from_id="crmd" to_id="crmd" client_gen="4" src="vsa-0000004dc-vc-0" seq="33" hg="4f2a2274" ts="4f2b6a7a" ld="2.89 0.85 0.29 6/105 1463" ttl="3" auth="1 0c66fc873f3832778ad31f85d1a81778da4de475" /></div>
<div>Feb 3 07:02:50 vsa-0000004dc-vc-1 heartbeat: [1023]: debug: }/*read_child_dispatch*/;</div><div>Feb 3 07:02:50 vsa-0000004dc-vc-1 crmd: [1073]: debug: debug2: register_fsa_input_adv: handle_request appended FSA input 19 (I_NULL) (cause=C_HA_MESSAGE) with data</div>
<div>Feb 3 07:02:50 vsa-0000004dc-vc-1 heartbeat: [1023]: debug: read_child_dispatch() {</div><div>Feb 3 07:02:50 vsa-0000004dc-vc-1 crmd: [1073]: debug: debug3: register_fsa_input_adv: Adding actions 0000000200000400 to input</div>
<div>Feb 3 07:02:50 vsa-0000004dc-vc-1 heartbeat: [1023]: debug: Packet authenticated</div><div>Feb 3 07:02:50 vsa-0000004dc-vc-1 crmd: [1073]: debug: debug3: register_fsa_input_adv: Copying C_HA_MESSAGE data from handle_request as a HA msg</div>
<div>Feb 3 07:02:50 vsa-0000004dc-vc-1 heartbeat: [1023]: debug: process_clustermsg: node [vsa-0000004dc-vc-0]</div><div>Feb 3 07:02:50 vsa-0000004dc-vc-1 crmd: [1073]: debug: debug2: register_fsa_input_adv: Queue len: 2</div>
<div>Feb 3 07:02:50 vsa-0000004dc-vc-1 heartbeat: [1023]: debug: }/*read_child_dispatch*/;</div><div>Feb 3 07:02:50 vsa-0000004dc-vc-1 crmd: [1073]: debug: debug3: register_fsa_input_adv: Triggering FSA: register_fsa_input_adv</div>
<div>Feb 3 07:02:50 vsa-0000004dc-vc-1 heartbeat: [1023]: debug: read_child_dispatch() {</div><div>Feb 3 07:02:50 vsa-0000004dc-vc-1 crmd: [1073]: debug: debug3: crmd_ha_msg_filter: Triggering FSA: crmd_ha_msg_filter</div>
<div>Feb 3 07:02:50 vsa-0000004dc-vc-1 heartbeat: [1023]: debug: Packet authenticated</div><div>Feb 3 07:02:50 vsa-0000004dc-vc-1 crmd: [1073]: debug: debug2: crm_fsa_trigger: Invoked (queue len: 2)</div><div>Feb 3 07:02:50 vsa-0000004dc-vc-1 heartbeat: [1023]: debug: process_clustermsg: node [vsa-0000004dc-vc-0]</div>
<div>Feb 3 07:02:50 vsa-0000004dc-vc-1 crmd: [1073]: debug: debug2: s_crmd_fsa: FSA invoked with Cause: C_FSA_INTERNAL#011State: S_ELECTION</div><div>Feb 3 07:02:50 vsa-0000004dc-vc-1 heartbeat: [1023]: debug: }/*read_child_dispatch*/;</div>
<div>Feb 3 07:02:50 vsa-0000004dc-vc-1 crmd: [1073]: debug: debug2: s_crmd_fsa: Checking messages (2 remaining)</div><div>Feb 3 07:02:50 vsa-0000004dc-vc-1 heartbeat: [1023]: debug: read_child_dispatch() {</div><div>Feb 3 07:02:50 vsa-0000004dc-vc-1 crmd: [1073]: debug: debug2: get_message: Processing input 18</div>
<div>Feb 3 07:02:50 vsa-0000004dc-vc-1 heartbeat: [1023]: debug: Packet authenticated</div><div>Feb 3 07:02:50 vsa-0000004dc-vc-1 crmd: [1073]: debug: debug2: log_fsa_input: Processing queued input 18</div><div>Feb 3 07:02:50 vsa-0000004dc-vc-1 heartbeat: [1023]: debug: process_clustermsg: node [vsa-0000004dc-vc-0]</div>
<div>Feb 3 07:02:50 vsa-0000004dc-vc-1 crmd: [1073]: debug: debug3: log_fsa_input: FSA processing XML message from handle_request</div><div>Feb 3 07:02:50 vsa-0000004dc-vc-1 heartbeat: [1023]: debug: }/*read_child_dispatch*/;</div>
<div>Feb 3 07:02:50 vsa-0000004dc-vc-1 crmd: [1073]: debug: debug3: print_xml_formatted: log_fsa_input: FSA message data: NULL</div><div>Feb 3 07:02:50 vsa-0000004dc-vc-1 heartbeat: [1023]: debug: read_child_dispatch() {</div>
<div>Feb 3 07:02:50 vsa-0000004dc-vc-1 crmd: [1073]: debug: debug2: s_crmd_fsa: actions:trace: #011// FSA input: State=S_ELECTION #011Cause=C_HA_MESSAGE #011Input=I_NULL #011Origin=handle_request() #011id=18</div><div>Feb 3 07:02:50 vsa-0000004dc-vc-1 heartbeat: [1023]: debug: Packet authenticated</div>
<div>Feb 3 07:02:50 vsa-0000004dc-vc-1 crmd: [1073]: debug: do_fsa_action: actions:trace: #011// A_ELECTION_COUNT</div><div>Feb 3 07:02:50 vsa-0000004dc-vc-1 heartbeat: [1023]: debug: process_clustermsg: node [vsa-0000004dc-vc-0]</div>
<div>Feb 3 07:02:50 vsa-0000004dc-vc-1 crmd: [1073]: debug: debug3: do_election_count_vote: Election 3 (current: 4, owner: 00001244-1244-0001-2b91-000000000001): Processed no-vote from vsa-0000004dc-vc-0 (Superceeded)</div>
<div>Feb 3 07:02:50 vsa-0000004dc-vc-1 heartbeat: [1023]: debug: }/*read_child_dispatch*/;</div><div>Feb 3 07:02:50 vsa-0000004dc-vc-1 crmd: [1073]: debug: do_fsa_action: actions:trace: #011// A_ELECTION_CHECK</div><div>
Feb 3 07:02:50 vsa-0000004dc-vc-1 heartbeat: [1023]: debug: read_child_dispatch() {</div><div>Feb 3 07:02:50 vsa-0000004dc-vc-1 crmd: [1073]: debug: do_election_check: Still waiting on 1 non-votes (2 total)</div><div>Feb 3 07:02:50 vsa-0000004dc-vc-1 heartbeat: [1023]: debug: Packet authenticated</div>
<div>Feb 3 07:02:50 vsa-0000004dc-vc-1 crmd: [1073]: debug: debug2: s_crmd_fsa: Checking messages (1 remaining)</div><div>Feb 3 07:02:50 vsa-0000004dc-vc-1 heartbeat: [1023]: debug: process_clustermsg: node [vsa-0000004dc-vc-0]</div>
<div>Feb 3 07:02:50 vsa-0000004dc-vc-1 crmd: [1073]: debug: debug2: get_message: Processing input 19</div><div>Feb 3 07:02:50 vsa-0000004dc-vc-1 heartbeat: [1023]: debug: }/*read_child_dispatch*/;</div><div>Feb 3 07:02:50 vsa-0000004dc-vc-1 crmd: [1073]: debug: debug2: log_fsa_input: Processing queued input 19</div>
<div>Feb 3 07:02:50 vsa-0000004dc-vc-1 heartbeat: [1023]: debug: read_child_dispatch() {</div><div>Feb 3 07:02:50 vsa-0000004dc-vc-1 crmd: [1073]: debug: debug3: log_fsa_input: FSA processing XML message from handle_request</div>
<div>Feb 3 07:02:50 vsa-0000004dc-vc-1 heartbeat: [1023]: debug: Packet authenticated</div><div>Feb 3 07:02:50 vsa-0000004dc-vc-1 crmd: [1073]: debug: debug3: print_xml_formatted: log_fsa_input: FSA message data: NULL</div>
<div>Feb 3 07:02:50 vsa-0000004dc-vc-1 heartbeat: [1023]: debug: process_clustermsg: node [vsa-0000004dc-vc-0]</div><div>Feb 3 07:02:50 vsa-0000004dc-vc-1 crmd: [1073]: debug: debug2: s_crmd_fsa: actions:trace: #011// FSA input: State=S_ELECTION #011Cause=C_HA_MESSAGE #011Input=I_NULL #011Origin=handle_request() #011id=19</div>
<div>Feb 3 07:02:50 vsa-0000004dc-vc-1 heartbeat: [1023]: debug: }/*read_child_dispatch*/;</div><div>Feb 3 07:02:50 vsa-0000004dc-vc-1 crmd: [1073]: debug: do_fsa_action: actions:trace: #011// A_ELECTION_COUNT</div><div>
Feb 3 07:02:50 vsa-0000004dc-vc-1 crmd: [1073]: debug: do_election_count_vote: Election 4 (current: 4, owner: 00001244-1244-0001-2b91-000000000001): Processed no-vote from vsa-0000004dc-vc-0 (Recorded)</div><div>Feb 3 07:02:50 vsa-0000004dc-vc-1 crmd: [1073]: debug: do_fsa_action: actions:trace: #011// A_ELECTION_CHECK</div>
<div>Feb 3 07:02:50 vsa-0000004dc-vc-1 crmd: [1073]: debug: debug2: crm_timer_stop: Stopping Election Timeout (I_ELECTION_DC:120000ms), src=24</div><div>Feb 3 07:02:50 vsa-0000004dc-vc-1 crmd: [1073]: debug: debug2: register_fsa_input_adv: do_election_check appended FSA input 20 (I_ELECTION_DC) (cause=C_FSA_INTERNAL) without data</div>
<div>Feb 3 07:02:50 vsa-0000004dc-vc-1 crmd: [1073]: debug: debug2: register_fsa_input_adv: Queue len: 1</div><div>Feb 3 07:02:50 vsa-0000004dc-vc-1 crmd: [1073]: debug: debug3: register_fsa_input_adv: Triggering FSA: register_fsa_input_adv</div>
<div>Feb 3 07:02:50 vsa-0000004dc-vc-1 crmd: [1073]: debug: do_election_check: Destroying voted hash</div><div>Feb 3 07:02:50 vsa-0000004dc-vc-1 crmd: [1073]: debug: debug2: s_crmd_fsa: Checking messages (1 remaining)</div>
<div>Feb 3 07:02:50 vsa-0000004dc-vc-1 crmd: [1073]: debug: debug2: get_message: Processing input 20</div><div>Feb 3 07:02:50 vsa-0000004dc-vc-1 crmd: [1073]: debug: debug2: log_fsa_input: Processing queued input 20</div>
<div>Feb 3 07:02:50 vsa-0000004dc-vc-1 crmd: [1073]: debug: debug3: log_fsa_input: FSA processing input from do_election_check</div><div>Feb 3 07:02:50 vsa-0000004dc-vc-1 crmd: [1073]: debug: s_crmd_fsa: Processing I_ELECTION_DC: [ state=S_ELECTION cause=C_FSA_INTERNAL origin=do_election_check ]</div>
<div>Feb 3 07:02:50 vsa-0000004dc-vc-1 crmd: [1073]: debug: do_fsa_action: actions:trace: #011// A_LOG</div><div>Feb 3 07:02:50 vsa-0000004dc-vc-1 crmd: [1073]: debug: debug2: do_log: FSA: Input I_ELECTION_DC from do_election_check() received in state S_ELECTION</div>
<div>Feb 3 07:02:50 vsa-0000004dc-vc-1 crmd: [1073]: debug: debug2: do_state_transition: actions:trace: #011S_ELECTION -> S_INTEGRATION [ label=I_ELECTION_DC cause=C_FSA_INTERNAL origin=do_election_check ]</div><div>Feb 3 07:02:50 vsa-0000004dc-vc-1 crmd: [1073]: info: do_state_transition: State transition S_ELECTION -> S_INTEGRATION [ input=I_ELECTION_DC cause=C_FSA_INTERNAL origin=do_election_check ]</div>
<div>Feb 3 07:02:50 vsa-0000004dc-vc-1 crmd: [1073]: debug: debug2: crm_timer_stop: Election Timeout (I_ELECTION_DC:120000ms) already stopped</div><div>Feb 3 07:02:50 vsa-0000004dc-vc-1 crmd: [1073]: debug: debug2: crm_timer_stop: PEngine Recheck Timer (I_PE_CALC:900000ms) already stopped</div>
<div>Feb 3 07:02:50 vsa-0000004dc-vc-1 crmd: [1073]: debug: do_fsa_action: actions:trace: #011// A_TE_START</div><div>Feb 3 07:02:50 vsa-0000004dc-vc-1 crmd: [1073]: debug: do_te_control: The transitioner is already active</div>
<div>Feb 3 07:02:50 vsa-0000004dc-vc-1 crmd: [1073]: debug: do_fsa_action: actions:trace: #011// A_PE_START</div><div>Feb 3 07:02:50 vsa-0000004dc-vc-1 crmd: [1073]: info: start_subsystem: Starting sub-system "pengine"</div>
<div>Feb 3 07:02:50 vsa-0000004dc-vc-1 crmd: [1073]: WARN: start_subsystem: Client pengine already running as pid 1317</div><div>Feb 3 07:02:51 vsa-0000004dc-vc-1 heartbeat: [1023]: debug: hb_send_local_status() {</div>
<div>Feb 3 07:02:51 vsa-0000004dc-vc-1 heartbeat: [1023]: debug: PID 1023: Sending local status curnode = 638e58 status: active</div><div>Feb 3 07:02:51 vsa-0000004dc-vc-1 heartbeat: [1023]: debug: process_clustermsg: node [vsa-0000004dc-vc-1]</div>
<div>Feb 3 07:02:51 vsa-0000004dc-vc-1 heartbeat: [1023]: debug: }/*hb_send_local_status*/;</div><div>Feb 3 07:02:51 vsa-0000004dc-vc-1 heartbeat: [1023]: debug: read_child_dispatch() {</div><div>Feb 3 07:02:51 vsa-0000004dc-vc-1 heartbeat: [1023]: debug: Packet authenticated</div>
<div>Feb 3 07:02:51 vsa-0000004dc-vc-1 heartbeat: [1023]: debug: process_clustermsg: node [vsa-0000004dc-vc-0]</div><div>Feb 3 07:02:51 vsa-0000004dc-vc-1 heartbeat: [1023]: debug: }/*read_child_dispatch*/;</div><div>Feb 3 07:02:51 vsa-0000004dc-vc-1 heartbeat: [1023]: debug: read_child_dispatch() {</div>
<div>Feb 3 07:02:51 vsa-0000004dc-vc-1 heartbeat: [1023]: debug: Packet authenticated</div><div>Feb 3 07:02:51 vsa-0000004dc-vc-1 heartbeat: [1023]: debug: process_clustermsg: node [vsa-0000004dc-vc-0]</div><div>Feb 3 07:02:51 vsa-0000004dc-vc-1 heartbeat: [1023]: debug: }/*read_child_dispatch*/;</div>
<div>Feb 3 07:02:52 vsa-0000004dc-vc-1 heartbeat: [1023]: debug: hb_send_local_status() {</div><div>Feb 3 07:02:52 vsa-0000004dc-vc-1 heartbeat: [1023]: debug: PID 1023: Sending local status curnode = 638e58 status: active</div>
<div>Feb 3 07:02:52 vsa-0000004dc-vc-1 heartbeat: [1023]: debug: process_clustermsg: node [vsa-0000004dc-vc-1]</div><div>Feb 3 07:02:52 vsa-0000004dc-vc-1 heartbeat: [1023]: debug: process_clustermsg: node [vsa-0000004dc-vc-1]</div>
<div>Feb 3 07:02:52 vsa-0000004dc-vc-1 heartbeat: [1023]: debug: }/*hb_send_local_status*/;</div><div>Feb 3 07:02:52 vsa-0000004dc-vc-1 heartbeat: [1023]: debug: read_child_dispatch() {</div><div>Feb 3 07:02:52 vsa-0000004dc-vc-1 heartbeat: [1023]: debug: Packet authenticated</div>
<div>Feb 3 07:02:52 vsa-0000004dc-vc-1 heartbeat: [1023]: debug: process_clustermsg: node [vsa-0000004dc-vc-0]</div><div>Feb 3 07:02:52 vsa-0000004dc-vc-1 heartbeat: [1023]: debug: process_clustermsg: node [vsa-0000004dc-vc-1]</div>
<div>Feb 3 07:02:52 vsa-0000004dc-vc-1 heartbeat: [1023]: debug: }/*read_child_dispatch*/;</div><div>Feb 3 07:02:52 vsa-0000004dc-vc-1 heartbeat: [1023]: debug: read_child_dispatch() {</div><div>Feb 3 07:02:52 vsa-0000004dc-vc-1 heartbeat: [1023]: debug: Packet authenticated</div>
<div>Feb 3 07:02:52 vsa-0000004dc-vc-1 heartbeat: [1023]: debug: process_clustermsg: node [vsa-0000004dc-vc-0]</div><div>Feb 3 07:02:52 vsa-0000004dc-vc-1 heartbeat: [1023]: debug: }/*read_child_dispatch*/;</div><div>Feb 3 07:02:53 vsa-0000004dc-vc-1 heartbeat: [1023]: debug: hb_send_local_status() {</div>
<div>Feb 3 07:02:53 vsa-0000004dc-vc-1 heartbeat: [1023]: debug: PID 1023: Sending local status curnode = 638e58 status: active</div><div>Feb 3 07:02:53 vsa-0000004dc-vc-1 heartbeat: [1023]: debug: process_clustermsg: node [vsa-0000004dc-vc-1]</div>
<div>Feb 3 07:02:53 vsa-0000004dc-vc-1 heartbeat: [1023]: debug: }/*hb_send_local_status*/;</div><div>Feb 3 07:02:53 vsa-0000004dc-vc-1 heartbeat: [1023]: debug: read_child_dispatch() {</div><div>Feb 3 07:02:53 vsa-0000004dc-vc-1 heartbeat: [1023]: debug: Packet authenticated</div>
<div>Feb 3 07:02:53 vsa-0000004dc-vc-1 heartbeat: [1023]: debug: process_clustermsg: node [vsa-0000004dc-vc-0]</div><div>Feb 3 07:02:53 vsa-0000004dc-vc-1 heartbeat: [1023]: debug: }/*read_child_dispatch*/;</div><div>Feb 3 07:02:53 vsa-0000004dc-vc-1 heartbeat: [1023]: debug: read_child_dispatch() {</div>
<div>Feb 3 07:02:53 vsa-0000004dc-vc-1 heartbeat: [1023]: debug: Packet authenticated</div><div>Feb 3 07:02:53 vsa-0000004dc-vc-1 heartbeat: [1023]: debug: process_clustermsg: node [vsa-0000004dc-vc-0]</div><div>Feb 3 07:02:53 vsa-0000004dc-vc-1 heartbeat: [1023]: debug: }/*read_child_dispatch*/;</div>
<div>Feb 3 07:02:54 vsa-0000004dc-vc-1 heartbeat: [1023]: debug: hb_send_local_status() {</div><div>Feb 3 07:02:54 vsa-0000004dc-vc-1 heartbeat: [1023]: debug: PID 1023: Sending local status curnode = 638e58 status: active</div>
<div>Feb 3 07:02:54 vsa-0000004dc-vc-1 heartbeat: [1023]: debug: process_clustermsg: node [vsa-0000004dc-vc-1]</div><div>Feb 3 07:02:54 vsa-0000004dc-vc-1 heartbeat: [1023]: debug: }/*hb_send_local_status*/;</div><div>Feb 3 07:02:54 vsa-0000004dc-vc-1 heartbeat: [1023]: debug: read_child_dispatch() {</div>
<div>Feb 3 07:02:54 vsa-0000004dc-vc-1 cib: [1069]: debug: debug2: cib_process_request: Processing local message (vsa-0000004dc-vc-1) for master...</div><div>Feb 3 07:02:54 vsa-0000004dc-vc-1 crmd: [1073]: debug: init_client_ipc_comms_nodispatch: Attempting to talk on: /var/run/crm/pengine</div>
<div>Feb 3 07:02:54 vsa-0000004dc-vc-1 pengine: [1317]: debug: debug3: pe_client_connect: Invoked</div><div>Feb 3 07:02:54 vsa-0000004dc-vc-1 heartbeat: [1023]: debug: Packet authenticated</div><div>Feb 3 07:02:54 vsa-0000004dc-vc-1 cib: [1069]: debug: debug2: parse_local_options: Processing master cib_slave_all op locally from crmd</div>
<div>Feb 3 07:02:54 vsa-0000004dc-vc-1 crmd: [1073]: debug: adjusted rcvbuf size to 524288</div><div>Feb 3 07:02:54 vsa-0000004dc-vc-1 pengine: [1317]: debug: adjusted rcvbuf size to 1048576</div><div>Feb 3 07:02:54 vsa-0000004dc-vc-1 heartbeat: [1023]: debug: process_clustermsg: node [vsa-0000004dc-vc-0]</div>
<div>Feb 3 07:02:54 vsa-0000004dc-vc-1 cib: [1069]: debug: debug3: cib_process_request: Finished determining processing actions</div><div>Feb 3 07:02:54 vsa-0000004dc-vc-1 crmd: [1073]: debug: adjusted sndbuf size to 524288</div>
<div>Feb 3 07:02:54 vsa-0000004dc-vc-1 pengine: [1317]: debug: adjusted sndbuf size to 1048576</div><div>Feb 3 07:02:54 vsa-0000004dc-vc-1 heartbeat: [1023]: debug: }/*read_child_dispatch*/;</div><div>Feb 3 07:02:54 vsa-0000004dc-vc-1 cib: [1069]: debug: debug2: cib_process_readwrite: Processing "cib_slave_all" event</div>
<div>Feb 3 07:02:54 vsa-0000004dc-vc-1 crmd: [1073]: debug: debug3: init_client_ipc_comms_nodispatch: Processing of /var/run/crm/pengine complete</div><div>Feb 3 07:02:54 vsa-0000004dc-vc-1 pengine: [1317]: debug: G_main_IPC_Channel_constructor(sock=7,7)</div>
<div>Feb 3 07:02:54 vsa-0000004dc-vc-1 heartbeat: [1023]: debug: read_child_dispatch() {</div><div>Feb 3 07:02:54 vsa-0000004dc-vc-1 cib: [1069]: info: cib_process_readwrite: We are now in R/O mode</div><div>Feb 3 07:02:54 vsa-0000004dc-vc-1 crmd: [1073]: debug: G_main_IPC_Channel_constructor(sock=16,16)</div>
<div>Feb 3 07:02:54 vsa-0000004dc-vc-1 heartbeat: [1023]: debug: Packet authenticated</div><div>Feb 3 07:02:54 vsa-0000004dc-vc-1 cib: [1069]: info: cib_process_request: Operation complete: op cib_slave_all for section 'all' (origin=local/crmd/14, version=1.2.0): ok (rc=0)</div>
<div>Feb 3 07:02:54 vsa-0000004dc-vc-1 crmd: [1073]: debug: do_fsa_action: actions:trace: #011// A_DC_TIMER_STOP</div><div>Feb 3 07:02:54 vsa-0000004dc-vc-1 heartbeat: [1023]: debug: process_clustermsg: node [vsa-0000004dc-vc-0]</div>
<div>Feb 3 07:02:54 vsa-0000004dc-vc-1 cib: [1069]: debug: debug3: cib_process_request: processing response cases</div><div>Feb 3 07:02:54 vsa-0000004dc-vc-1 crmd: [1073]: debug: debug2: crm_timer_stop: Election Trigger (I_DC_TIMEOUT:5000ms) already stopped</div>
<div>Feb 3 07:02:54 vsa-0000004dc-vc-1 heartbeat: [1023]: debug: }/*read_child_dispatch*/;</div><div>Feb 3 07:02:54 vsa-0000004dc-vc-1 cib: [1069]: debug: debug2: do_local_notify: Performing notification</div><div>Feb 3 07:02:54 vsa-0000004dc-vc-1 crmd: [1073]: debug: do_fsa_action: actions:trace: #011// A_INTEGRATE_TIMER_START</div>
<div>Feb 3 07:02:54 vsa-0000004dc-vc-1 cib: [1069]: debug: debug3: do_local_notify: Sending callback to request originator</div><div>Feb 3 07:02:54 vsa-0000004dc-vc-1 crmd: [1073]: debug: crm_timer_start: Started Integration Timer (I_INTEGRATED:180000ms), src=26</div>
<div>Feb 3 07:02:54 vsa-0000004dc-vc-1 cib: [1069]: debug: debug2: do_local_notify: Sending an a-sync response to crmd</div><div>Feb 3 07:02:54 vsa-0000004dc-vc-1 crmd: [1073]: debug: do_fsa_action: actions:trace: #011// A_FINALIZE_TIMER_STOP</div>
<div>Feb 3 07:02:54 vsa-0000004dc-vc-1 cib: [1069]: debug: debug3: send_via_callback_channel: Delivering msg 0x805700 to client aa13a017-01bf-4589-af6c-084cec13f6fa</div><div>Feb 3 07:02:54 vsa-0000004dc-vc-1 crmd: [1073]: debug: debug2: crm_timer_stop: Finalization Timer (I_ELECTION:1800000ms) already stopped</div>
<div>Feb 3 07:02:54 vsa-0000004dc-vc-1 cib: [1069]: debug: debug3: send_via_callback_channel: Delivering reply to client aa13a017-01bf-4589-af6c-084cec13f6fa (cib_callback)</div><div>Feb 3 07:02:54 vsa-0000004dc-vc-1 crmd: [1073]: debug: do_fsa_action: actions:trace: #011// A_DC_TAKEOVER</div>
<div>Feb 3 07:02:54 vsa-0000004dc-vc-1 cib: [1069]: debug: debug2: cib_process_request: Completed slave update</div><div>Feb 3 07:02:54 vsa-0000004dc-vc-1 crmd: [1073]: info: do_dc_takeover: Taking over DC status for this partition</div>
<div>Feb 3 07:02:54 vsa-0000004dc-vc-1 cib: [1069]: debug: debug2: cib_process_request: Processing local message (vsa-0000004dc-vc-1) for master...</div><div>Feb 3 07:02:54 vsa-0000004dc-vc-1 crmd: [1073]: debug: debug3: cib_native_perform_op: Sending cib_slave_all message to CIB service</div>
<div>Feb 3 07:02:54 vsa-0000004dc-vc-1 cib: [1069]: debug: debug2: parse_local_options: Processing locally scoped cib_master op from crmd</div><div>Feb 3 07:02:54 vsa-0000004dc-vc-1 crmd: [1073]: debug: debug3: cib_native_perform_op: Message sent</div>
<div>Feb 3 07:02:54 vsa-0000004dc-vc-1 cib: [1069]: debug: debug3: cib_process_request: Finished determining processing actions</div><div>Feb 3 07:02:54 vsa-0000004dc-vc-1 crmd: [1073]: debug: debug3: cib_native_perform_op: Async call, returning</div>
<div>Feb 3 07:02:54 vsa-0000004dc-vc-1 cib: [1069]: debug: debug2: cib_process_readwrite: Processing "cib_master" event</div><div>Feb 3 07:02:54 vsa-0000004dc-vc-1 crmd: [1073]: debug: debug3: cib_client_set_master: Adding cib_scope_local to options</div>
<div>Feb 3 07:02:54 vsa-0000004dc-vc-1 cib: [1069]: info: cib_process_readwrite: We are now in R/W mode</div><div>Feb 3 07:02:54 vsa-0000004dc-vc-1 crmd: [1073]: debug: debug3: cib_native_perform_op: Sending cib_master message to CIB service</div>
</div><div><br></div><div>thanks</div><div>Shyam</div><div><br></div><div><br><br><div class="gmail_quote">On Fri, Feb 3, 2012 at 4:04 AM, Andrew Beekhof <span dir="ltr"><<a href="mailto:andrew@beekhof.net">andrew@beekhof.net</a>></span> wrote:<br>
<blockquote class="gmail_quote" style="margin:0 0 0 .8ex;border-left:1px #ccc solid;padding-left:1ex"><div class="im">On Fri, Feb 3, 2012 at 9:31 AM, Andrew Beekhof <<a href="mailto:andrew@beekhof.net">andrew@beekhof.net</a>> wrote:<br>
> On Thu, Feb 2, 2012 at 9:55 PM, Shyam <<a href="mailto:shyam.kaushik@gmail.com">shyam.kaushik@gmail.com</a>> wrote:<br>
>> Hi Andrew,<br>
>><br>
>> Here is more logs covering a larger period that shows multiple of this<br>
>> election cycle. Please note that in the below case I had set dc-deadtime to<br>
>> 5secs & the I_DC_TIMEOUT pops up every 5 secs. I turned this dc-deadtime to<br>
>> 10secs & the long election cycle problem disappeared. It no longer happens.<br>
>> I suspect that before a single election cycle completes, the next<br>
>> I_DC_TIMEOUT kicks-in. Could this be the reason?<br>
><br>
> Yes. The question is why the cycle is taking so long :-/<br>
<br>
</div>Could you reproduce with debug on please?<br>
It would be nice to know what the cluster is doing for the 4 seconds<br>
between these two messages:<br>
<div class="im"><br>
Jan 17 12:00:04 vsa-0000003ca-vc-0 crmd: [1120]: WARN:<br>
start_subsystem: Client pengine already running as pid 4243<br>
Jan 17 12:00:08 vsa-0000003ca-vc-0 crmd: [1120]: info: do_dc_takeover:<br>
Taking over DC status for this partition<br>
<br>
</div>What version of pacemaker is this btw?<br>
<div><div></div><div class="h5"><br>
_______________________________________________<br>
Pacemaker mailing list: <a href="mailto:Pacemaker@oss.clusterlabs.org">Pacemaker@oss.clusterlabs.org</a><br>
<a href="http://oss.clusterlabs.org/mailman/listinfo/pacemaker" target="_blank">http://oss.clusterlabs.org/mailman/listinfo/pacemaker</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>