Hi Andrew,<div><br></div><div>Did you get a chance to look at the below logs? Anything that needs to be setup differently in the config?</div><div><br>Thanks.</div><div><br></div><div>--Shyam<br><br><div class="gmail_quote">
On Thu, Feb 9, 2012 at 10:13 AM, Shyam <span dir="ltr">&lt;<a href="mailto:shyam.kaushik@gmail.com">shyam.kaushik@gmail.com</a>&gt;</span> wrote:<br><blockquote class="gmail_quote" style="margin:0 0 0 .8ex;border-left:1px #ccc solid;padding-left:1ex">
Hi Andrew,<div><br></div><div>I don&#39;t have below log files anymore. I captured fresh set of logs. Please find it attached. Thanks.</div><div><br></div><div>--Shyam<br><br><div class="gmail_quote">On Wed, Feb 8, 2012 at 6:29 AM, Andrew Beekhof <span dir="ltr">&lt;<a href="mailto:andrew@beekhof.net" target="_blank">andrew@beekhof.net</a>&gt;</span> wrote:<br>

<blockquote class="gmail_quote" style="margin:0 0 0 .8ex;border-left:1px #ccc solid;padding-left:1ex">On Fri, Feb 3, 2012 at 4:20 PM, Shyam &lt;<a href="mailto:shyam.kaushik@gmail.com" target="_blank">shyam.kaushik@gmail.com</a>&gt; wrote:<br>


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