[ClusterLabs] Trying to prevent instantaneous Failover / Failback at standby reconnect
Ken Gaillot
kgaillot at redhat.com
Thu Jul 26 00:42:21 EDT 2018
On Thu, 2018-07-26 at 03:46 +0000, O'Donovan, Garret wrote:
> Thanks for the responses, Andrei and others, and for taking the time
> to
> look at this. Apologies for being slow getting back to you.
>
> We realize that having a stonith device would help avoid split-brain,
> and
> it is something we may look into in the future. In the meantime, we
> are
> looking to eliminate the failover / failback in this particular test
> case.
This scenario is what split brain is. When you pull the network, each
node thinks it's alive but the other node is dead. When you reconnect
the network, they find they were mistaken, and re-allocate the
resources.
More comments inline:
>
> We reproduced the same scenario and this time there are logs below
> from
> both nodes.
>
> Thanks again!
>
>
> Node that was running as Primary:
>
>
>
> Jul 25 07:42:46 [1638] DVTVM0802.mse.am.mot.com cib: info:
> pcmk_cpg_membership: Node 2 left group cib (peer=dvtvm0803,
> counter=4.0)
*02 sees *03 as lost
> Jul 25 07:42:46 [1638] DVTVM0802.mse.am.mot.com cib: info:
> crm_update_peer_proc: pcmk_cpg_membership: Node dvtvm0803[2] -
> corosync-cpg is now offline
> Jul 25 07:42:46 [1569] DVTVM0802.mse.am.mot.com pacemakerd: info:
> pcmk_cpg_membership: Node 2 left group pacemakerd
> (peer=dvtvm0803, counter=4.0)
> Jul 25 07:42:46 [1569] DVTVM0802.mse.am.mot.com pacemakerd: info:
> crm_update_peer_proc: pcmk_cpg_membership: Node dvtvm0803[2] -
> corosync-cpg is now offline
> Jul 25 07:42:46 [1638] DVTVM0802.mse.am.mot.com cib: notice:
> crm_update_peer_state_iter: Node dvtvm0803 state is now lost |
> nodeid=2 previous=member source=crm_update_peer_proc
> Jul 25 07:42:46 [1569] DVTVM0802.mse.am.mot.com pacemakerd: info:
> pcmk_cpg_membership: Node 1 still member of group pacemakerd
> (peer=dvtvm0802, counter=4.0)
> Jul 25 07:42:46 [1638] DVTVM0802.mse.am.mot.com cib: info:
> crm_reap_dead_member: Removing node with name dvtvm0803 and id
> 2 from membership cache
> Jul 25 07:42:46 [1569] DVTVM0802.mse.am.mot.com pacemakerd: info:
> crm_cs_flush: Sent 0 CPG messages (1 remaining, last=10): Try
> again (6)
> Jul 25 07:42:46 [1638] DVTVM0802.mse.am.mot.com cib: notice:
> reap_crm_member: Purged 1 peer with id=2 and/or
> uname=dvtvm0803 from the membership cache
> Jul 25 07:42:46 [1638] DVTVM0802.mse.am.mot.com cib: info:
> pcmk_cpg_membership: Node 1 still member of group cib
> (peer=dvtvm0802, counter=4.0)
> [1003] DVTVM0802.mse.am.mot.com corosyncnotice [QUORUM] Members[1]:
> 1
> Jul 25 07:42:46 [1569] DVTVM0802.mse.am.mot.com pacemakerd: info:
> pcmk_quorum_notification: Quorum retained | membership=52
> members=1
> [1003] DVTVM0802.mse.am.mot.com corosyncnotice [MAIN ] Completed
> service synchronization, ready to provide service.
> Jul 25 07:42:46 [1639] DVTVM0802.mse.am.mot.com stonith-ng: info:
> pcmk_cpg_membership: Node 2 left group stonith-ng
> (peer=dvtvm0803, counter=4.0)
> Jul 25 07:42:46 [1639] DVTVM0802.mse.am.mot.com stonith-ng: info:
> crm_update_peer_proc: pcmk_cpg_membership: Node dvtvm0803[2] -
> corosync-cpg is now offline
> Jul 25 07:42:46 [1569] DVTVM0802.mse.am.mot.com pacemakerd: notice:
> crm_update_peer_state_iter: Node dvtvm0803 state is now lost |
> nodeid=2 previous=member source=crm_reap_unseen_nodes
> Jul 25 07:42:46 [1645] DVTVM0802.mse.am.mot.com crmd: info:
> pcmk_quorum_notification: Quorum retained | membership=52
> members=1
> Jul 25 07:42:46 [1645] DVTVM0802.mse.am.mot.com crmd: notice:
> crm_update_peer_state_iter: Node dvtvm0803 state is now lost |
> nodeid=2 previous=member source=crm_reap_unseen_nodes
> Jul 25 07:42:46 [1639] DVTVM0802.mse.am.mot.com stonith-ng: notice:
> crm_update_peer_state_iter: Node dvtvm0803 state is now lost |
> nodeid=2 previous=member source=crm_update_peer_proc
> Jul 25 07:42:46 [1645] DVTVM0802.mse.am.mot.com crmd: info:
> peer_update_callback: Cluster node dvtvm0803 is now lost (was
> member)
> Jul 25 07:42:46 [1645] DVTVM0802.mse.am.mot.com crmd: warning:
> reap_dead_nodes: Our DC node (dvtvm0803) left the cluster
> Jul 25 07:42:46 [1639] DVTVM0802.mse.am.mot.com stonith-ng: info:
> crm_reap_dead_member: Removing node with name dvtvm0803 and id
> 2 from membership cache
> Jul 25 07:42:46 [1639] DVTVM0802.mse.am.mot.com stonith-ng: notice:
> reap_crm_member: Purged 1 peer with id=2 and/or
> uname=dvtvm0803 from the membership cache
> Jul 25 07:42:46 [1639] DVTVM0802.mse.am.mot.com stonith-ng: info:
> pcmk_cpg_membership: Node 1 still member of group stonith-ng
> (peer=dvtvm0802, counter=4.0)
> Jul 25 07:42:46 [1645] DVTVM0802.mse.am.mot.com crmd: notice:
> do_state_transition: State transition S_NOT_DC -> S_ELECTION |
> input=I_ELECTION cause=C_FSA_INTERNAL origin=reap_dead_nodes
*02 was not the DC at the time of the interruption, and it calls for a
DC election
> Jul 25 07:42:46 [1645] DVTVM0802.mse.am.mot.com crmd: info:
> update_dc: Unset DC. Was dvtvm0803
> Jul 25 07:42:46 [1645] DVTVM0802.mse.am.mot.com crmd: info:
> pcmk_cpg_membership: Node 2 left group crmd (peer=dvtvm0803,
> counter=4.0)
> Jul 25 07:42:46 [1645] DVTVM0802.mse.am.mot.com crmd: info:
> crm_update_peer_proc: pcmk_cpg_membership: Node dvtvm0803[2] -
> corosync-cpg is now offline
> Jul 25 07:42:46 [1645] DVTVM0802.mse.am.mot.com crmd: info:
> peer_update_callback: Client dvtvm0803/peer now has status
> [offline] (DC=<null>, changed=4000000)
> Jul 25 07:42:46 [1645] DVTVM0802.mse.am.mot.com crmd: info:
> pcmk_cpg_membership: Node 1 still member of group crmd
> (peer=dvtvm0802, counter=4.0)
> Jul 25 07:42:46 [1641] DVTVM0802.mse.am.mot.com attrd: info:
> pcmk_cpg_membership: Node 2 left group attrd (peer=dvtvm0803,
> counter=4.0)
> Jul 25 07:42:46 [1641] DVTVM0802.mse.am.mot.com attrd: info:
> crm_update_peer_proc: pcmk_cpg_membership: Node dvtvm0803[2] -
> corosync-cpg is now offline
> Jul 25 07:42:46 [1641] DVTVM0802.mse.am.mot.com attrd: notice:
> crm_update_peer_state_iter: Node dvtvm0803 state is now lost |
> nodeid=2 previous=member source=crm_update_peer_proc
> Jul 25 07:42:46 [1641] DVTVM0802.mse.am.mot.com attrd: notice:
> attrd_peer_remove: Removing all dvtvm0803 attributes for peer
> loss
> Jul 25 07:42:46 [1641] DVTVM0802.mse.am.mot.com attrd: notice:
> attrd_peer_change_cb: Lost attribute writer dvtvm0803
> Jul 25 07:42:46 [1641] DVTVM0802.mse.am.mot.com attrd: info:
> crm_reap_dead_member: Removing node with name dvtvm0803 and id
> 2 from membership cache
> Jul 25 07:42:46 [1645] DVTVM0802.mse.am.mot.com crmd: info:
> election_complete: Election election-0 complete
> Jul 25 07:42:46 [1641] DVTVM0802.mse.am.mot.com attrd: notice:
> reap_crm_member: Purged 1 peer with id=2 and/or
> uname=dvtvm0803 from the membership cache
> Jul 25 07:42:46 [1645] DVTVM0802.mse.am.mot.com crmd: info:
> election_timeout_popped: Election failed: Declaring ourselves
> the winner
> Jul 25 07:42:46 [1641] DVTVM0802.mse.am.mot.com attrd: info:
> pcmk_cpg_membership: Node 1 still member of group attrd
> (peer=dvtvm0802, counter=4.0)
> Jul 25 07:42:46 [1645] DVTVM0802.mse.am.mot.com crmd: info:
> do_log: Input I_ELECTION_DC received in state S_ELECTION from
> election_timeout_popped
> Jul 25 07:42:46 [1645] DVTVM0802.mse.am.mot.com crmd: notice:
> do_state_transition: State transition S_ELECTION ->
> S_INTEGRATION | input=I_ELECTION_DC cause=C_TIMER_POPPED
> origin=election_timeout_popped
> Jul 25 07:42:46 [1645] DVTVM0802.mse.am.mot.com crmd: info:
> do_te_control: Registering TE UUID: 49795742-d293-405c-a429-
> 61113ad512c0
> Jul 25 07:42:46 [1645] DVTVM0802.mse.am.mot.com crmd: info:
> set_graph_functions: Setting custom graph functions
> Jul 25 07:42:46 [1645] DVTVM0802.mse.am.mot.com crmd: info:
> do_dc_takeover: Taking over DC status for this partition
Since *02 only sees itself, it becomes DC
> Jul 25 07:42:46 [1638] DVTVM0802.mse.am.mot.com cib: info:
> cib_process_readwrite: We are now in R/W mode
> Jul 25 07:42:46 [1638] DVTVM0802.mse.am.mot.com cib: info:
> cib_process_request: Completed cib_master operation for
> section 'all': OK (rc=0, origin=local/crmd/61, version=0.20.63)
> Jul 25 07:42:46 [1638] DVTVM0802.mse.am.mot.com cib: info:
> cib_process_request: Forwarding cib_modify operation for
> section cib to all (origin=local/crmd/62)
> Jul 25 07:42:46 [1638] DVTVM0802.mse.am.mot.com cib: info:
> cib_process_request: Completed cib_modify operation for
> section cib: OK (rc=0, origin=dvtvm0802/crmd/62, version=0.20.63)
> Jul 25 07:42:46 [1638] DVTVM0802.mse.am.mot.com cib: info:
> cib_process_request: Forwarding cib_modify operation for
> section crm_config to all (origin=local/crmd/64)
> Jul 25 07:42:46 [1638] DVTVM0802.mse.am.mot.com cib: info:
> cib_process_request: Completed cib_modify operation for
> section crm_config: OK (rc=0, origin=dvtvm0802/crmd/64,
> version=0.20.63)
> Jul 25 07:42:46 [1638] DVTVM0802.mse.am.mot.com cib: info:
> cib_process_request: Forwarding cib_modify operation for
> section crm_config to all (origin=local/crmd/66)
> Jul 25 07:42:46 [1645] DVTVM0802.mse.am.mot.com crmd: info:
> crm_update_peer_join: initialize_join: Node dvtvm0802[1] -
> join-3 phase confirmed -> none
> Jul 25 07:42:46 [1645] DVTVM0802.mse.am.mot.com crmd: info:
> join_make_offer: Making join offers based on membership 52
> Jul 25 07:42:46 [1645] DVTVM0802.mse.am.mot.com crmd: info:
> join_make_offer: join-3: Sending offer to dvtvm0802
> Jul 25 07:42:46 [1645] DVTVM0802.mse.am.mot.com crmd: info:
> crm_update_peer_join: join_make_offer: Node dvtvm0802[1] -
> join-3 phase none -> welcomed
> Jul 25 07:42:46 [1645] DVTVM0802.mse.am.mot.com crmd: info:
> join_make_offer: Not making an offer to dvtvm0803: not active
> (lost)
> Jul 25 07:42:46 [1645] DVTVM0802.mse.am.mot.com crmd: info:
> do_dc_join_offer_all: join-3: Waiting on 1 outstanding join
> acks
> Jul 25 07:42:46 [1645] DVTVM0802.mse.am.mot.com crmd: warning:
> do_log: Input I_ELECTION_DC received in state S_INTEGRATION
> from do_election_check
> Jul 25 07:42:46 [1645] DVTVM0802.mse.am.mot.com crmd: info:
> crm_update_peer_join: initialize_join: Node dvtvm0802[1] -
> join-4 phase welcomed -> none
> Jul 25 07:42:46 [1645] DVTVM0802.mse.am.mot.com crmd: info:
> join_make_offer: join-4: Sending offer to dvtvm0802
> Jul 25 07:42:46 [1645] DVTVM0802.mse.am.mot.com crmd: info:
> crm_update_peer_join: join_make_offer: Node dvtvm0802[1] -
> join-4 phase none -> welcomed
> Jul 25 07:42:46 [1645] DVTVM0802.mse.am.mot.com crmd: info:
> join_make_offer: Not making an offer to dvtvm0803: not active
> (lost)
> Jul 25 07:42:46 [1645] DVTVM0802.mse.am.mot.com crmd: info:
> do_dc_join_offer_all: join-4: Waiting on 1 outstanding join
> acks
> Jul 25 07:42:46 [1645] DVTVM0802.mse.am.mot.com crmd: info:
> update_dc: Set DC to dvtvm0802 (3.0.14)
> Jul 25 07:42:46 [1638] DVTVM0802.mse.am.mot.com cib: info:
> cib_process_request: Completed cib_modify operation for
> section crm_config: OK (rc=0, origin=dvtvm0802/crmd/66,
> version=0.20.63)
> Jul 25 07:42:46 [1638] DVTVM0802.mse.am.mot.com cib: info:
> cib_process_request: Forwarding cib_modify operation for
> section crm_config to all (origin=local/crmd/68)
> Jul 25 07:42:46 [1638] DVTVM0802.mse.am.mot.com cib: info:
> cib_process_request: Completed cib_modify operation for
> section crm_config: OK (rc=0, origin=dvtvm0802/crmd/68,
> version=0.20.63)
> Jul 25 07:42:46 [1645] DVTVM0802.mse.am.mot.com crmd: info:
> crm_update_peer_join: do_dc_join_filter_offer: Node
> dvtvm0802[1] - join-4 phase welcomed -> integrated
> Jul 25 07:42:46 [1645] DVTVM0802.mse.am.mot.com crmd: info:
> do_state_transition: State transition S_INTEGRATION ->
> S_FINALIZE_JOIN | input=I_INTEGRATED cause=C_FSA_INTERNAL
> origin=check_join_state
> Jul 25 07:42:46 [1645] DVTVM0802.mse.am.mot.com crmd: info:
> crmd_join_phase_log: join-4: dvtvm0802=integrated
> Jul 25 07:42:46 [1645] DVTVM0802.mse.am.mot.com crmd: info:
> crmd_join_phase_log: join-4: dvtvm0803=none
> Jul 25 07:42:46 [1645] DVTVM0802.mse.am.mot.com crmd: info:
> do_dc_join_finalize: join-4: Syncing our CIB to the rest of
> the cluster
> Jul 25 07:42:46 [1645] DVTVM0802.mse.am.mot.com crmd: info:
> crm_update_peer_join: finalize_join_for: Node dvtvm0802[1] -
> join-4 phase integrated -> finalized
> Jul 25 07:42:46 [1638] DVTVM0802.mse.am.mot.com cib: info:
> cib_process_replace: Digest matched on replace from dvtvm0802:
> 0bc3cfc4c7b71bb6b009f97aa31175b8
> Jul 25 07:42:46 [1638] DVTVM0802.mse.am.mot.com cib: info:
> cib_process_replace: Replaced 0.20.63 with 0.20.63 from
> dvtvm0802
> Jul 25 07:42:46 [1638] DVTVM0802.mse.am.mot.com cib: info:
> cib_process_request: Completed cib_replace operation for
> section 'all': OK (rc=0, origin=dvtvm0802/crmd/72, version=0.20.63)
> Jul 25 07:42:46 [1638] DVTVM0802.mse.am.mot.com cib: info:
> cib_process_request: Forwarding cib_modify operation for
> section nodes to all (origin=local/crmd/73)
> Jul 25 07:42:46 [1645] DVTVM0802.mse.am.mot.com crmd: info:
> action_synced_wait: Managed edgemanager_meta-data_0 process
> 12189 exited with rc=4
> Jul 25 07:42:46 [1645] DVTVM0802.mse.am.mot.com crmd: error:
> lrmd_api_get_metadata: Failed to receive meta-data for
> ocf:vendor:application
This is an unrelated issue, but worth looking into: when the cluster
calls the meta-data action for this agent, it gets exit status 4
> Jul 25 07:42:46 [1645] DVTVM0802.mse.am.mot.com crmd: warning:
> build_operation_update: Failed to get metadata for application
> (ocf:vendor:application)
> Jul 25 07:42:46 [1645] DVTVM0802.mse.am.mot.com crmd: info:
> action_synced_wait: Managed edgemanager_meta-data_0 process
> 12191 exited with rc=4
> Jul 25 07:42:46 [1645] DVTVM0802.mse.am.mot.com crmd: error:
> lrmd_api_get_metadata: Failed to receive meta-data for
> ocf:vendor:application
> Jul 25 07:42:46 [1645] DVTVM0802.mse.am.mot.com crmd: warning:
> build_operation_update: Failed to get metadata for application
> (ocf:vendor:application)
> Jul 25 07:42:46 [1638] DVTVM0802.mse.am.mot.com cib: info:
> cib_process_request: Completed cib_modify operation for
> section nodes: OK (rc=0, origin=dvtvm0802/crmd/73, version=0.20.63)
> Jul 25 07:42:46 [1645] DVTVM0802.mse.am.mot.com crmd: info:
> crm_update_peer_join: do_dc_join_ack: Node dvtvm0802[1] -
> join-4 phase finalized -> confirmed
> Jul 25 07:42:46 [1645] DVTVM0802.mse.am.mot.com crmd: info:
> do_dc_join_ack: join-4: Updating node state to member for
> dvtvm0802
> Jul 25 07:42:46 [1645] DVTVM0802.mse.am.mot.com crmd: info:
> erase_status_tag: Deleting lrm status entries for dvtvm0802 |
> xpath=//node_state[@uname='dvtvm0802']/lrm
> Jul 25 07:42:46 [1638] DVTVM0802.mse.am.mot.com cib: info:
> cib_file_backup: Archived previous version as
> /var/lib/pacemaker/cib/cib-28.raw
> Jul 25 07:42:46 [1638] DVTVM0802.mse.am.mot.com cib: info:
> cib_process_request: Forwarding cib_delete operation for
> section //node_state[@uname='dvtvm0802']/lrm to all
> (origin=local/crmd/74)
> Jul 25 07:42:46 [1638] DVTVM0802.mse.am.mot.com cib: info:
> cib_perform_op: Diff: --- 0.20.63 2
> Jul 25 07:42:46 [1638] DVTVM0802.mse.am.mot.com cib: info:
> cib_perform_op: Diff: +++ 0.20.64 (null)
> Jul 25 07:42:46 [1638] DVTVM0802.mse.am.mot.com cib: info:
> cib_perform_op: --
> /cib/status/node_state[@id='1']/lrm[@id='1']
> Jul 25 07:42:46 [1638] DVTVM0802.mse.am.mot.com cib: info:
> cib_perform_op: + /cib: @num_updates=64
> Jul 25 07:42:46 [1638] DVTVM0802.mse.am.mot.com cib: info:
> cib_file_write_with_digest: Wrote version 0.20.0 of the CIB to
> disk (digest: 38d399e886fdf463121cda517374a888)
> Jul 25 07:42:46 [1638] DVTVM0802.mse.am.mot.com cib: info:
> cib_file_write_with_digest: Reading cluster configuration file
> /var/lib/pacemaker/cib/cib.mC21GJ (digest:
> /var/lib/pacemaker/cib/cib.n9gaMp)
> Jul 25 07:42:46 [1638] DVTVM0802.mse.am.mot.com cib: info:
> cib_process_request: Completed cib_delete operation for
> section //node_state[@uname='dvtvm0802']/lrm: OK (rc=0,
> origin=dvtvm0802/crmd/74, version=0.20.64)
> Jul 25 07:42:46 [1645] DVTVM0802.mse.am.mot.com crmd: info:
> action_synced_wait: Managed edgemanager_meta-data_0 process
> 12192 exited with rc=4
> Jul 25 07:42:46 [1645] DVTVM0802.mse.am.mot.com crmd: error:
> lrmd_api_get_metadata: Failed to receive meta-data for
> ocf:vendor:application
> Jul 25 07:42:46 [1645] DVTVM0802.mse.am.mot.com crmd: warning:
> build_operation_update: Failed to get metadata for application
> (ocf:vendor:application)
> Jul 25 07:42:46 [1645] DVTVM0802.mse.am.mot.com crmd: info:
> action_synced_wait: Managed edgemanager_meta-data_0 process
> 12193 exited with rc=4
> Jul 25 07:42:46 [1645] DVTVM0802.mse.am.mot.com crmd: error:
> lrmd_api_get_metadata: Failed to receive meta-data for
> ocf:vendor:application
> Jul 25 07:42:46 [1645] DVTVM0802.mse.am.mot.com crmd: warning:
> build_operation_update: Failed to get metadata for application
> (ocf:vendor:application)
> Jul 25 07:42:46 [1638] DVTVM0802.mse.am.mot.com cib: info:
> cib_process_request: Forwarding cib_modify operation for
> section status to all (origin=local/crmd/75)
> Jul 25 07:42:46 [1638] DVTVM0802.mse.am.mot.com cib: info:
> cib_perform_op: Diff: --- 0.20.64 2
> Jul 25 07:42:46 [1638] DVTVM0802.mse.am.mot.com cib: info:
> cib_perform_op: Diff: +++ 0.20.65 (null)
> Jul 25 07:42:46 [1638] DVTVM0802.mse.am.mot.com cib: info:
> cib_perform_op: + /cib: @num_updates=65
> Jul 25 07:42:46 [1638] DVTVM0802.mse.am.mot.com cib: info:
> cib_perform_op: + /cib/status/node_state[@id='1']: @crm-
> debug-origin=do_lrm_query_internal
> Jul 25 07:42:46 [1638] DVTVM0802.mse.am.mot.com cib: info:
> cib_perform_op: ++ /cib/status/node_state[@id='1']: <lrm
> id="1"/>
> Jul 25 07:42:46 [1638] DVTVM0802.mse.am.mot.com cib: info:
> cib_perform_op: ++ <lrm_re
> sources>
> Jul 25 07:42:46 [1638] DVTVM0802.mse.am.mot.com cib: info:
> cib_perform_op: ++ <lrm_
> resource id="Connected" type="ping" class="ocf" provider="pacemaker">
> Jul 25 07:42:46 [1638] DVTVM0802.mse.am.mot.com cib: info:
> cib_perform_op: ++ <lr
> m_rsc_op id="Connected_last_0" operation_key="Connected_start_0"
> operation="start" crm-debug-origin="build_active_RAs"
> crm_feature_set="3.0.14" transition-key="10:0:0:1cec18ac-2aae-4c5c-
> 8513-d6851bc10191" transition-magic="0:0;10:0:0:1cec18ac-2aae-4c5c-
> 8513-d6851bc10191" exit-reason="" on_node="dvtvm0802" call-id="15"
> rc-code="0" op-status="0" interval="0" last-run="1532518326
> Jul 25 07:42:46 [1638] DVTVM0802.mse.am.mot.com cib: info:
> cib_perform_op: ++ <lr
> m_rsc_op id="Connected_monitor_3000"
> operation_key="Connected_monitor_3000" operation="monitor" crm-debug-
> origin="build_active_RAs" crm_feature_set="3.0.14" transition-
> key="11:0:0:1cec18ac-2aae-4c5c-8513-d6851bc10191" transition-
> magic="0:0;11:0:0:1cec18ac-2aae-4c5c-8513-d6851bc10191" exit-
> reason="" on_node="dvtvm0802" call-id="16" rc-code="0" op-status="0"
> interval="3000" last
> Jul 25 07:42:46 [1638] DVTVM0802.mse.am.mot.com cib: info:
> cib_perform_op: ++ </lrm
> _resource>
> Jul 25 07:42:46 [1638] DVTVM0802.mse.am.mot.com cib: info:
> cib_perform_op: ++ <lrm_
> resource id="ClusterIP" type="IPaddr2" class="ocf"
> provider="heartbeat">
> Jul 25 07:42:46 [1638] DVTVM0802.mse.am.mot.com cib: info:
> cib_perform_op: ++ <lr
> m_rsc_op id="ClusterIP_last_0" operation_key="ClusterIP_start_0"
> operation="start" crm-debug-origin="build_active_RAs"
> crm_feature_set="3.0.14" transition-key="4:1:0:1cec18ac-2aae-4c5c-
> 8513-d6851bc10191" transition-magic="0:0;4:1:0:1cec18ac-2aae-4c5c-
> 8513-d6851bc10191" exit-reason="" on_node="dvtvm0802" call-id="17"
> rc-code="0" op-status="0" interval="0" last-run="1532518330"
> Jul 25 07:42:46 [1638] DVTVM0802.mse.am.mot.com cib: info:
> cib_perform_op: ++ <lr
> m_rsc_op id="ClusterIP_monitor_1000"
> operation_key="ClusterIP_monitor_1000" operation="monitor" crm-debug-
> origin="build_active_RAs" crm_feature_set="3.0.14" transition-
> key="5:1:0:1cec18ac-2aae-4c5c-8513-d6851bc10191" transition-
> magic="0:0;5:1:0:1cec18ac-2aae-4c5c-8513-d6851bc10191" exit-reason=""
> on_node="dvtvm0802" call-id="18" rc-code="0" op-status="0"
> interval="1000" last-r
> Jul 25 07:42:46 [1638] DVTVM0802.mse.am.mot.com cib: info:
> cib_perform_op: ++ </lrm
> _resource>
> Jul 25 07:42:46 [1638] DVTVM0802.mse.am.mot.com cib: info:
> cib_perform_op: ++ <lrm_
> resource id="application" type="application" class="ocf"
> provider="vendor">
> Jul 25 07:42:46 [1638] DVTVM0802.mse.am.mot.com cib: info:
> cib_perform_op: ++ <lr
> m_rsc_op id="edgemanager_last_0" operation_key="edgemanager_start_0"
> operation="start" crm-debug-origin="build_active_RAs"
> crm_feature_set="3.0.14" transition-key="14:1:0:1cec18ac-2aae-4c5c-
> 8513-d6851bc10191" transition-magic="0:0;14:1:0:1cec18ac-2aae-4c5c-
> 8513-d6851bc10191" exit-reason="" on_node="dvtvm0802" call-id="19"
> rc-code="0" op-status="0" interval="0" last-run="153251
> Jul 25 07:42:46 [1638] DVTVM0802.mse.am.mot.com cib: info:
> cib_perform_op: ++ <lr
> m_rsc_op id="edgemanager_monitor_1000"
> operation_key="edgemanager_monitor_1000" operation="monitor" crm-
> debug-origin="build_active_RAs" crm_feature_set="3.0.14" transition-
> key="15:1:0:1cec18ac-2aae-4c5c-8513-d6851bc10191" transition-
> magic="0:0;15:1:0:1cec18ac-2aae-4c5c-8513-d6851bc10191" exit-
> reason="" on_node="dvtvm0802" call-id="20" rc-code="0" op-status="0"
> interval="1000"
> Jul 25 07:42:46 [1638] DVTVM0802.mse.am.mot.com cib: info:
> cib_perform_op: ++ </lrm
> _resource>
> Jul 25 07:42:46 [1638] DVTVM0802.mse.am.mot.com cib: info:
> cib_perform_op: ++ </lrm_r
> esources>
> Jul 25 07:42:46 [1638] DVTVM0802.mse.am.mot.com cib: info:
> cib_perform_op: ++ </lrm>
> Jul 25 07:42:46 [1638] DVTVM0802.mse.am.mot.com cib: info:
> cib_process_request: Completed cib_modify operation for
> section status: OK (rc=0, origin=dvtvm0802/crmd/75, version=0.20.65)
> Jul 25 07:42:46 [1645] DVTVM0802.mse.am.mot.com crmd: info:
> do_state_transition: State transition S_FINALIZE_JOIN ->
> S_POLICY_ENGINE | input=I_FINALIZED cause=C_FSA_INTERNAL
> origin=check_join_state
> Jul 25 07:42:46 [1645] DVTVM0802.mse.am.mot.com crmd: info:
> abort_transition_graph: Transition aborted: Peer Cancelled |
> source=do_te_invoke:143 complete=true
> Jul 25 07:42:46 [1638] DVTVM0802.mse.am.mot.com cib: info:
> cib_process_request: Forwarding cib_modify operation for
> section nodes to all (origin=local/crmd/78)
> Jul 25 07:42:46 [1638] DVTVM0802.mse.am.mot.com cib: info:
> cib_process_request: Forwarding cib_modify operation for
> section status to all (origin=local/crmd/79)
> Jul 25 07:42:46 [1638] DVTVM0802.mse.am.mot.com cib: info:
> cib_process_request: Forwarding cib_modify operation for
> section cib to all (origin=local/crmd/80)
> Jul 25 07:42:46 [1638] DVTVM0802.mse.am.mot.com cib: info:
> cib_process_request: Completed cib_modify operation for
> section nodes: OK (rc=0, origin=dvtvm0802/crmd/78, version=0.20.65)
> Jul 25 07:42:46 [1638] DVTVM0802.mse.am.mot.com cib: info:
> cib_perform_op: Diff: --- 0.20.65 2
> Jul 25 07:42:46 [1638] DVTVM0802.mse.am.mot.com cib: info:
> cib_perform_op: Diff: +++ 0.20.66 (null)
> Jul 25 07:42:46 [1638] DVTVM0802.mse.am.mot.com cib: info:
> cib_perform_op: + /cib: @num_updates=66
> Jul 25 07:42:46 [1638] DVTVM0802.mse.am.mot.com cib: info:
> cib_perform_op: + /cib/status/node_state[@id='1']: @crm-
> debug-origin=do_state_transition
> Jul 25 07:42:46 [1638] DVTVM0802.mse.am.mot.com cib: info:
> cib_perform_op: + /cib/status/node_state[@id='2']: @in_ccm=f
> alse, @crmd=offline, @join=down
> Jul 25 07:42:46 [1638] DVTVM0802.mse.am.mot.com cib: info:
> cib_process_request: Completed cib_modify operation for
> section status: OK (rc=0, origin=dvtvm0802/crmd/79, version=0.20.66)
> Jul 25 07:42:46 [1638] DVTVM0802.mse.am.mot.com cib: info:
> cib_perform_op: Diff: --- 0.20.66 2
> Jul 25 07:42:46 [1638] DVTVM0802.mse.am.mot.com cib: info:
> cib_perform_op: Diff: +++ 0.20.67 (null)
> Jul 25 07:42:46 [1638] DVTVM0802.mse.am.mot.com cib: info:
> cib_perform_op: + /cib: @num_updates=67, @dc-uuid=1
> Jul 25 07:42:46 [1638] DVTVM0802.mse.am.mot.com cib: info:
> cib_process_request: Completed cib_modify operation for
> section cib: OK (rc=0, origin=dvtvm0802/crmd/80, version=0.20.67)
> Jul 25 07:42:46 [1643] DVTVM0802.mse.am.mot.com pengine: notice:
> unpack_config: On loss of CCM Quorum: Ignore
> Jul 25 07:42:46 [1643] DVTVM0802.mse.am.mot.com pengine: info:
> determine_online_status: Node dvtvm0802 is online
> Jul 25 07:42:46 [1643] DVTVM0802.mse.am.mot.com pengine: info:
> unpack_node_loop: Node 1 is already processed
> Jul 25 07:42:46 [1643] DVTVM0802.mse.am.mot.com pengine: info:
> unpack_node_loop: Node 1 is already processed
> Jul 25 07:42:46 [1643] DVTVM0802.mse.am.mot.com pengine: info:
> common_print: ClusterIP (ocf::heartbeat:IPaddr2):
> Started dvtvm0802
> Jul 25 07:42:46 [1643] DVTVM0802.mse.am.mot.com pengine: info:
> clone_print: Clone Set: Connected-clone [Connected]
> Jul 25 07:42:46 [1643] DVTVM0802.mse.am.mot.com pengine: info:
> short_print: Started: [ dvtvm0802 ]
> Jul 25 07:42:46 [1643] DVTVM0802.mse.am.mot.com pengine: info:
> short_print: Stopped: [ dvtvm0803 ]
> Jul 25 07:42:46 [1643] DVTVM0802.mse.am.mot.com pengine: info:
> common_print: application (ocf::vendor:application):
> Started dvtvm0802
> Jul 25 07:42:46 [1643] DVTVM0802.mse.am.mot.com pengine: info:
> native_color: Resource Connected:1 cannot run anywhere
> Jul 25 07:42:46 [1643] DVTVM0802.mse.am.mot.com pengine: info:
> LogActions: Leave ClusterIP (Started dvtvm0802)
> Jul 25 07:42:46 [1643] DVTVM0802.mse.am.mot.com pengine: info:
> LogActions: Leave Connected:0 (Started dvtvm0802)
> Jul 25 07:42:46 [1643] DVTVM0802.mse.am.mot.com pengine: info:
> LogActions: Leave Connected:1 (Stopped)
> Jul 25 07:42:46 [1643] DVTVM0802.mse.am.mot.com pengine: info:
> LogActions: Leave application (Started dvtvm0802)
> Jul 25 07:42:46 [1643] DVTVM0802.mse.am.mot.com pengine: notice:
> process_pe_message: Calculated transition 1, saving inputs in
> /var/lib/pacemaker/pengine/pe-input-5.bz2
*02 is already running ClusterIP, Connected:0 and application, and
leaves them alone
> Jul 25 07:42:46 [1645] DVTVM0802.mse.am.mot.com crmd: info:
> do_state_transition: State transition S_POLICY_ENGINE ->
> S_TRANSITION_ENGINE | input=I_PE_SUCCESS cause=C_IPC_MESSAGE
> origin=handle_response
> Jul 25 07:42:46 [1645] DVTVM0802.mse.am.mot.com crmd: info:
> do_te_invoke: Processing graph 1 (ref=pe_calc-dc-1532518966-
> 33) derived from /var/lib/pacemaker/pengine/pe-input-5.bz2
> Jul 25 07:42:46 [1645] DVTVM0802.mse.am.mot.com crmd: notice:
> run_graph: Transition 1 (Complete=0, Pending=0, Fired=0,
> Skipped=0, Incomplete=0, Source=/var/lib/pacemaker/pengine/pe-input-
> 5.bz2): Complete
> Jul 25 07:42:46 [1645] DVTVM0802.mse.am.mot.com crmd: info:
> do_log: Input I_TE_SUCCESS received in state
> S_TRANSITION_ENGINE from notify_crmd
> Jul 25 07:42:46 [1645] DVTVM0802.mse.am.mot.com crmd: notice:
> do_state_transition: State transition S_TRANSITION_ENGINE ->
> S_IDLE | input=I_TE_SUCCESS cause=C_FSA_INTERNAL origin=notify_crmd
> Jul 25 07:42:46 [1569] DVTVM0802.mse.am.mot.com pacemakerd: info:
> mcp_cpg_deliver: Ignoring process list sent by peer for local
> node
> Jul 25 07:42:49 [1641] DVTVM0802.mse.am.mot.com attrd: info:
> attrd_client_update: Starting an election to determine the
> writer
> Jul 25 07:42:49 [1641] DVTVM0802.mse.am.mot.com attrd: info:
> election_complete: Election election-attrd complete
> Jul 25 07:42:49 [1641] DVTVM0802.mse.am.mot.com attrd: info:
> write_attribute: Processed 1 private change for #attrd-
> protocol, id=<n/a>, set=(null)
> Jul 25 07:42:49 [1641] DVTVM0802.mse.am.mot.com attrd: info:
> write_attribute: Sent update 5 with 1 changes for pingd,
> id=<n/a>, set=(null)
> Jul 25 07:42:49 [1638] DVTVM0802.mse.am.mot.com cib: info:
> cib_process_request: Forwarding cib_modify operation for
> section status to all (origin=local/attrd/5)
> Jul 25 07:42:49 [1638] DVTVM0802.mse.am.mot.com cib: info:
> cib_process_request: Completed cib_modify operation for
> section status: OK (rc=0, origin=dvtvm0802/attrd/5, version=0.20.67)
> Jul 25 07:42:49 [1641] DVTVM0802.mse.am.mot.com attrd: info:
> attrd_cib_callback: Update 5 for pingd: OK (0)
> Jul 25 07:42:49 [1641] DVTVM0802.mse.am.mot.com attrd: info:
> attrd_cib_callback: Update 5 for pingd[dvtvm0802]=2000: OK (0)
> Jul 25 07:42:54 [1638] DVTVM0802.mse.am.mot.com cib: info:
> cib_process_ping: Reporting our current digest to dvtvm0802:
> d4226f5b1384916e105bdeab21320802 for 0.20.67 (0x560c396fc420 0)
> [1003] DVTVM0802.mse.am.mot.com corosyncnotice [TOTEM ] A new
> membership (10.144.102.32:56) was formed. Members joined: 2
*03 rejoins
> Jul 25 07:43:09 [1639] DVTVM0802.mse.am.mot.com stonith-ng: info:
> pcmk_cpg_membership: Node 2 joined group stonith-ng
> (counter=5.0)
> Jul 25 07:43:09 [1645] DVTVM0802.mse.am.mot.com crmd: info:
> pcmk_cpg_membership: Node 2 joined group crmd (counter=5.0)
> Jul 25 07:43:09 [1641] DVTVM0802.mse.am.mot.com attrd: info:
> pcmk_cpg_membership: Node 2 joined group attrd (counter=5.0)
> Jul 25 07:43:09 [1639] DVTVM0802.mse.am.mot.com stonith-ng: info:
> pcmk_cpg_membership: Node 1 still member of group stonith-ng
> (peer=dvtvm0802, counter=5.0)
> Jul 25 07:43:09 [1645] DVTVM0802.mse.am.mot.com crmd: info:
> pcmk_cpg_membership: Node 1 still member of group crmd
> (peer=dvtvm0802, counter=5.0)
> Jul 25 07:43:09 [1641] DVTVM0802.mse.am.mot.com attrd: info:
> pcmk_cpg_membership: Node 1 still member of group attrd
> (peer=dvtvm0802, counter=5.0)
> Jul 25 07:43:09 [1645] DVTVM0802.mse.am.mot.com crmd: info:
> pcmk_cpg_membership: Node 2 still member of group crmd
> (peer=dvtvm0803, counter=5.1)
> Jul 25 07:43:09 [1645] DVTVM0802.mse.am.mot.com crmd: info:
> crm_update_peer_proc: pcmk_cpg_membership: Node dvtvm0803[2] -
> corosync-cpg is now online
> Jul 25 07:43:09 [1645] DVTVM0802.mse.am.mot.com crmd: info:
> peer_update_callback: Client dvtvm0803/peer now has status
> [online] (DC=true, changed=4000000)
> Jul 25 07:43:09 [1569] DVTVM0802.mse.am.mot.com pacemakerd: info:
> pcmk_cpg_membership: Node 2 joined group pacemakerd
> (counter=5.0)
> Jul 25 07:43:09 [1638] DVTVM0802.mse.am.mot.com cib: info:
> pcmk_cpg_membership: Node 2 joined group cib (counter=5.0)
> Jul 25 07:43:09 [1569] DVTVM0802.mse.am.mot.com pacemakerd: info:
> pcmk_cpg_membership: Node 1 still member of group pacemakerd
> (peer=dvtvm0802, counter=5.0)
> Jul 25 07:43:09 [1645] DVTVM0802.mse.am.mot.com crmd: error:
> pcmk_cpg_membership: Node dvtvm0803[2] appears to be online
> even though we think it is dead
*02 saw *03 go away and assumed it was dead, but now it's back
> Jul 25 07:43:09 [1638] DVTVM0802.mse.am.mot.com cib: info:
> pcmk_cpg_membership: Node 1 still member of group cib
> (peer=dvtvm0802, counter=5.0)
> Jul 25 07:43:09 [1569] DVTVM0802.mse.am.mot.com pacemakerd: info:
> pcmk_cpg_membership: Node 2 still member of group pacemakerd
> (peer=dvtvm0803, counter=5.1)
> Jul 25 07:43:09 [1569] DVTVM0802.mse.am.mot.com pacemakerd: info:
> crm_update_peer_proc: pcmk_cpg_membership: Node dvtvm0803[2] -
> corosync-cpg is now online
> Jul 25 07:43:09 [1645] DVTVM0802.mse.am.mot.com crmd: notice:
> crm_update_peer_state_iter: Node dvtvm0803 state is now member
> | nodeid=2 previous=lost source=pcmk_cpg_membership
> Jul 25 07:43:09 [1645] DVTVM0802.mse.am.mot.com crmd: info:
> peer_update_callback: Cluster node dvtvm0803 is now member
> (was lost)
> Jul 25 07:43:09 [1569] DVTVM0802.mse.am.mot.com pacemakerd: error:
> pcmk_cpg_membership: Node dvtvm0803[2] appears to be online
> even though we think it is dead
> Jul 25 07:43:09 [1569] DVTVM0802.mse.am.mot.com pacemakerd: notice:
> crm_update_peer_state_iter: Node dvtvm0803 state is now member
> | nodeid=2 previous=lost source=pcmk_cpg_membership
> Jul 25 07:43:09 [1569] DVTVM0802.mse.am.mot.com pacemakerd: info:
> crm_cs_flush: Sent 0 CPG messages (1 remaining, last=11): Try
> again (6)
> [1003] DVTVM0802.mse.am.mot.com corosyncnotice [QUORUM] Members[2]:
> 1 2
> Jul 25 07:43:09 [1569] DVTVM0802.mse.am.mot.com pacemakerd: info:
> pcmk_quorum_notification: Quorum retained | membership=56
> members=2
> [1003] DVTVM0802.mse.am.mot.com corosyncnotice [MAIN ] Completed
> service synchronization, ready to provide service.
> Jul 25 07:43:09 [1641] DVTVM0802.mse.am.mot.com attrd: info:
> crm_get_peer: Created entry c0e26d80-254b-4ef5-92d6-
> feb3e4d79467/0x561724cc6f00 for node dvtvm0803/2 (2 total)
> Jul 25 07:43:09 [1641] DVTVM0802.mse.am.mot.com attrd: info:
> crm_get_peer: Node 2 is now known as dvtvm0803
> Jul 25 07:43:09 [1641] DVTVM0802.mse.am.mot.com attrd: info:
> crm_get_peer: Node 2 has uuid 2
> Jul 25 07:43:09 [1641] DVTVM0802.mse.am.mot.com attrd: info:
> pcmk_cpg_membership: Node 2 still member of group attrd
> (peer=dvtvm0803, counter=5.1)
> Jul 25 07:43:09 [1641] DVTVM0802.mse.am.mot.com attrd: info:
> crm_update_peer_proc: pcmk_cpg_membership: Node dvtvm0803[2] -
> corosync-cpg is now online
> Jul 25 07:43:09 [1641] DVTVM0802.mse.am.mot.com attrd: notice:
> crm_update_peer_state_iter: Node dvtvm0803 state is now member
> | nodeid=2 previous=unknown source=crm_update_peer_proc
> Jul 25 07:43:09 [1645] DVTVM0802.mse.am.mot.com crmd: info:
> pcmk_quorum_notification: Quorum retained | membership=56
> members=2
> Jul 25 07:43:09 [1639] DVTVM0802.mse.am.mot.com stonith-ng: info:
> crm_get_peer: Created entry 794822b3-61e5-4cda-85c6-
> 6c42c3a14471/0x55f69ac31e30 for node dvtvm0803/2 (2 total)
> Jul 25 07:43:09 [1639] DVTVM0802.mse.am.mot.com stonith-ng: info:
> crm_get_peer: Node 2 is now known as dvtvm0803
> Jul 25 07:43:09 [1639] DVTVM0802.mse.am.mot.com stonith-ng: info:
> crm_get_peer: Node 2 has uuid 2
> Jul 25 07:43:09 [1639] DVTVM0802.mse.am.mot.com stonith-ng: info:
> pcmk_cpg_membership: Node 2 still member of group stonith-ng
> (peer=dvtvm0803, counter=5.1)
> Jul 25 07:43:09 [1639] DVTVM0802.mse.am.mot.com stonith-ng: info:
> crm_update_peer_proc: pcmk_cpg_membership: Node dvtvm0803[2] -
> corosync-cpg is now online
> Jul 25 07:43:09 [1639] DVTVM0802.mse.am.mot.com stonith-ng: notice:
> crm_update_peer_state_iter: Node dvtvm0803 state is now member
> | nodeid=2 previous=unknown source=crm_update_peer_proc
> Jul 25 07:43:09 [1638] DVTVM0802.mse.am.mot.com cib: info:
> crm_get_peer: Created entry 3dc6fe56-2790-4a6f-a17b-
> 88696608ddc3/0x560c39bc9380 for node dvtvm0803/2 (2 total)
> Jul 25 07:43:09 [1638] DVTVM0802.mse.am.mot.com cib: info:
> crm_get_peer: Node 2 is now known as dvtvm0803
> Jul 25 07:43:09 [1638] DVTVM0802.mse.am.mot.com cib: info:
> crm_get_peer: Node 2 has uuid 2
> Jul 25 07:43:09 [1638] DVTVM0802.mse.am.mot.com cib: info:
> pcmk_cpg_membership: Node 2 still member of group cib
> (peer=dvtvm0803, counter=5.1)
> Jul 25 07:43:09 [1638] DVTVM0802.mse.am.mot.com cib: info:
> crm_update_peer_proc: pcmk_cpg_membership: Node dvtvm0803[2] -
> corosync-cpg is now online
> Jul 25 07:43:09 [1638] DVTVM0802.mse.am.mot.com cib: notice:
> crm_update_peer_state_iter: Node dvtvm0803 state is now member
> | nodeid=2 previous=unknown source=crm_update_peer_proc
> Jul 25 07:43:09 [1638] DVTVM0802.mse.am.mot.com cib: info:
> cib_process_request: Forwarding cib_modify operation for
> section status to all (origin=local/crmd/82)
> Jul 25 07:43:09 [1638] DVTVM0802.mse.am.mot.com cib: info:
> cib_process_request: Forwarding cib_modify operation for
> section status to all (origin=local/crmd/83)
> Jul 25 07:43:09 [1638] DVTVM0802.mse.am.mot.com cib: info:
> cib_process_request: Forwarding cib_modify operation for
> section nodes to all (origin=local/crmd/86)
> Jul 25 07:43:09 [1638] DVTVM0802.mse.am.mot.com cib: info:
> cib_process_request: Forwarding cib_modify operation for
> section status to all (origin=local/crmd/87)
> Jul 25 07:43:09 [1645] DVTVM0802.mse.am.mot.com crmd: info:
> register_fsa_error_adv: Resetting the current action list
> Jul 25 07:43:09 [1645] DVTVM0802.mse.am.mot.com crmd: warning:
> crmd_ha_msg_filter: Another DC detected: dvtvm0803 (op=noop)
Because *03 saw itself as alive and *02 as lost, it elected itself DC
during the outage as well. Now that it's back, both nodes think they're
DC
> Jul 25 07:43:09 [1645] DVTVM0802.mse.am.mot.com crmd: notice:
> do_state_transition: State transition S_IDLE -> S_ELECTION |
> input=I_ELECTION cause=C_FSA_INTERNAL origin=crmd_ha_msg_filter
> Jul 25 07:43:09 [1645] DVTVM0802.mse.am.mot.com crmd: info:
> update_dc: Unset DC. Was dvtvm0802
> Jul 25 07:43:09 [1638] DVTVM0802.mse.am.mot.com cib: info:
> cib_perform_op: Diff: --- 0.20.67 2
> Jul 25 07:43:09 [1638] DVTVM0802.mse.am.mot.com cib: info:
> cib_perform_op: Diff: +++ 0.20.68 (null)
> Jul 25 07:43:09 [1638] DVTVM0802.mse.am.mot.com cib: info:
> cib_perform_op: + /cib: @num_updates=68
> Jul 25 07:43:09 [1638] DVTVM0802.mse.am.mot.com cib: info:
> cib_perform_op: + /cib/status/node_state[@id='2']: @crmd=onl
> ine, @crm-debug-origin=peer_update_callback
> Jul 25 07:43:09 [1638] DVTVM0802.mse.am.mot.com cib: info:
> cib_process_request: Completed cib_modify operation for
> section status: OK (rc=0, origin=dvtvm0802/crmd/82, version=0.20.68)
> Jul 25 07:43:09 [1638] DVTVM0802.mse.am.mot.com cib: info:
> cib_process_request: Completed cib_modify operation for
> section status: OK (rc=0, origin=dvtvm0802/crmd/83, version=0.20.68)
> Jul 25 07:43:09 [1641] DVTVM0802.mse.am.mot.com attrd: notice:
> attrd_peer_message: Detected another attribute writer:
> dvtvm0803
> Jul 25 07:43:09 [1641] DVTVM0802.mse.am.mot.com attrd: info:
> attrd_peer_message: Processing sync-response from dvtvm0803
> Jul 25 07:43:09 [1641] DVTVM0802.mse.am.mot.com attrd: info:
> attrd_peer_update: Setting #attrd-protocol[dvtvm0803]: (null)
> -> 2 from dvtvm0803
> Jul 25 07:43:09 [1641] DVTVM0802.mse.am.mot.com attrd: info:
> attrd_peer_update: Setting pingd[dvtvm0803]: (null) -> 0 from
> dvtvm0803
> Jul 25 07:43:09 [1638] DVTVM0802.mse.am.mot.com cib: info:
> cib_process_request: Completed cib_modify operation for
> section nodes: OK (rc=0, origin=dvtvm0802/crmd/86, version=0.20.68)
> Jul 25 07:43:09 [1638] DVTVM0802.mse.am.mot.com cib: info:
> cib_perform_op: Diff: --- 0.20.68 2
> Jul 25 07:43:09 [1638] DVTVM0802.mse.am.mot.com cib: info:
> cib_perform_op: Diff: +++ 0.20.69 (null)
> Jul 25 07:43:09 [1638] DVTVM0802.mse.am.mot.com cib: info:
> cib_perform_op: + /cib: @num_updates=69
> Jul 25 07:43:09 [1638] DVTVM0802.mse.am.mot.com cib: info:
> cib_perform_op: + /cib/status/node_state[@id='1']: @crm-
> debug-origin=post_cache_update
> Jul 25 07:43:09 [1638] DVTVM0802.mse.am.mot.com cib: info:
> cib_perform_op: + /cib/status/node_state[@id='2']: @in_ccm=t
> rue, @crm-debug-origin=post_cache_update
> Jul 25 07:43:09 [1638] DVTVM0802.mse.am.mot.com cib: info:
> cib_process_request: Completed cib_modify operation for
> section status: OK (rc=0, origin=dvtvm0802/crmd/87, version=0.20.69)
> Jul 25 07:43:09 [1638] DVTVM0802.mse.am.mot.com cib: info:
> cib_perform_op: Diff: --- 0.20.69 2
> Jul 25 07:43:09 [1638] DVTVM0802.mse.am.mot.com cib: info:
> cib_perform_op: Diff: +++ 0.20.70 (null)
> Jul 25 07:43:09 [1638] DVTVM0802.mse.am.mot.com cib: info:
> cib_perform_op: + /cib: @num_updates=70
> Jul 25 07:43:09 [1638] DVTVM0802.mse.am.mot.com cib: info:
> cib_perform_op: + /cib/status/node_state[@id='1']: @crm-
> debug-origin=peer_update_callback
> Jul 25 07:43:09 [1645] DVTVM0802.mse.am.mot.com crmd: info:
> election_count_vote: Election 6 (owner: 2) lost: vote from
> dvtvm0803 (Uptime)
> Jul 25 07:43:09 [1645] DVTVM0802.mse.am.mot.com crmd: notice:
> do_state_transition: State transition S_ELECTION ->
> S_RELEASE_DC | input=I_RELEASE_DC cause=C_FSA_INTERNAL
> origin=do_election_count_vote
> Jul 25 07:43:09 [1645] DVTVM0802.mse.am.mot.com crmd: info:
> do_dc_release: DC role released
> Jul 25 07:43:09 [1638] DVTVM0802.mse.am.mot.com cib: info:
> cib_process_request: Completed cib_modify operation for
> section status: OK (rc=0, origin=dvtvm0803/crmd/129, version=0.20.70)
> Jul 25 07:43:09 [1645] DVTVM0802.mse.am.mot.com crmd: info:
> pe_ipc_destroy: Connection to the Policy Engine released
> Jul 25 07:43:09 [1638] DVTVM0802.mse.am.mot.com cib: info:
> cib_process_request: Completed cib_modify operation for
> section status: OK (rc=0, origin=dvtvm0803/crmd/130, version=0.20.70)
> Jul 25 07:43:09 [1645] DVTVM0802.mse.am.mot.com crmd: info:
> do_te_control: Transitioner is now inactive
> Jul 25 07:43:09 [1645] DVTVM0802.mse.am.mot.com crmd: info:
> do_log: Input I_RELEASE_SUCCESS received in state S_RELEASE_DC
> from do_dc_release
> Jul 25 07:43:09 [1645] DVTVM0802.mse.am.mot.com crmd: info:
> do_state_transition: State transition S_RELEASE_DC ->
> S_PENDING | input=I_RELEASE_SUCCESS cause=C_FSA_INTERNAL
> origin=do_dc_release
> Jul 25 07:43:09 [1645] DVTVM0802.mse.am.mot.com crmd: info:
> election_count_vote: Election 7 (owner: 2) lost: vote from
> dvtvm0803 (Uptime)
> Jul 25 07:43:09 [1645] DVTVM0802.mse.am.mot.com crmd: info:
> do_log: Input I_PENDING received in state S_PENDING from
> do_election_count_vote
> Jul 25 07:43:09 [1638] DVTVM0802.mse.am.mot.com cib: info:
> cib_process_request: Completed cib_modify operation for
> section nodes: OK (rc=0, origin=dvtvm0803/crmd/133, version=0.20.70)
> Jul 25 07:43:09 [1638] DVTVM0802.mse.am.mot.com cib: info:
> cib_perform_op: Diff: --- 0.20.70 2
> Jul 25 07:43:09 [1638] DVTVM0802.mse.am.mot.com cib: info:
> cib_perform_op: Diff: +++ 0.20.71 (null)
> Jul 25 07:43:09 [1638] DVTVM0802.mse.am.mot.com cib: info:
> cib_perform_op: + /cib: @num_updates=71
> Jul 25 07:43:09 [1638] DVTVM0802.mse.am.mot.com cib: info:
> cib_perform_op: + /cib/status/node_state[@id='1']: @crm-
> debug-origin=post_cache_update
> Jul 25 07:43:09 [1641] DVTVM0802.mse.am.mot.com attrd: info:
> election_count_vote: Election 4 (owner: 2) lost: vote from
> dvtvm0803 (Uptime)
> Jul 25 07:43:09 [1638] DVTVM0802.mse.am.mot.com cib: info:
> cib_process_request: Completed cib_modify operation for
> section status: OK (rc=0, origin=dvtvm0803/crmd/134, version=0.20.71)
> Jul 25 07:43:09 [1638] DVTVM0802.mse.am.mot.com cib: info:
> cib_process_readwrite: We are now in R/O mode
> Jul 25 07:43:09 [1641] DVTVM0802.mse.am.mot.com attrd: info:
> election_count_vote: Election 5 (owner: 2) lost: vote from
> dvtvm0803 (Uptime)
> Jul 25 07:43:09 [1641] DVTVM0802.mse.am.mot.com attrd: info:
> attrd_peer_message: Processing sync-response from dvtvm0803
> Jul 25 07:43:09 [1638] DVTVM0802.mse.am.mot.com cib: info:
> cib_process_request: Completed cib_modify operation for
> section cib: OK (rc=0, origin=dvtvm0803/crmd/136, version=0.20.71)
> Jul 25 07:43:09 [1638] DVTVM0802.mse.am.mot.com cib: info:
> cib_process_request: Completed cib_modify operation for
> section crm_config: OK (rc=0, origin=dvtvm0803/crmd/138,
> version=0.20.71)
> Jul 25 07:43:09 [1638] DVTVM0802.mse.am.mot.com cib: info:
> cib_process_request: Completed cib_modify operation for
> section crm_config: OK (rc=0, origin=dvtvm0803/crmd/140,
> version=0.20.71)
> Jul 25 07:43:09 [1645] DVTVM0802.mse.am.mot.com crmd: info:
> update_dc: Set DC to dvtvm0803 (3.0.14)
*03 wins the DC election after both nodes see each other again
> Jul 25 07:43:09 [1645] DVTVM0802.mse.am.mot.com crmd: info:
> election_count_vote: Election 8 (owner: 2) lost: vote from
> dvtvm0803 (Uptime)
> Jul 25 07:43:09 [1645] DVTVM0802.mse.am.mot.com crmd: info:
> update_dc: Unset DC. Was dvtvm0803
> Jul 25 07:43:09 [1645] DVTVM0802.mse.am.mot.com crmd: info:
> do_log: Input I_PENDING received in state S_PENDING from
> do_election_count_vote
> Jul 25 07:43:09 [1645] DVTVM0802.mse.am.mot.com crmd: info:
> update_dc: Set DC to dvtvm0803 (3.0.14)
> Jul 25 07:43:09 [1638] DVTVM0802.mse.am.mot.com cib: info:
> cib_process_request: Completed cib_modify operation for
> section crm_config: OK (rc=0, origin=dvtvm0803/crmd/142,
> version=0.20.71)
> Jul 25 07:43:09 [1638] DVTVM0802.mse.am.mot.com cib: info:
> cib_process_replace: Digest matched on replace from dvtvm0803:
> e5254bf4e58c636caa44908bdc7e0a94
> Jul 25 07:43:09 [1638] DVTVM0802.mse.am.mot.com cib: info:
> cib_process_replace: Replaced 0.20.71 with 0.20.83 from
> dvtvm0803
> Jul 25 07:43:09 [1638] DVTVM0802.mse.am.mot.com cib: info:
> cib_perform_op: Diff: --- 0.20.71 2
> Jul 25 07:43:09 [1638] DVTVM0802.mse.am.mot.com cib: info:
> cib_perform_op: Diff: +++ 0.20.83 (null)
> Jul 25 07:43:09 [1638] DVTVM0802.mse.am.mot.com cib: info:
> cib_perform_op: --
> /cib/status/node_state[@id='1']/transient_attributes[@id='1']
> Jul 25 07:43:09 [1638] DVTVM0802.mse.am.mot.com cib: info:
> cib_perform_op: + /cib: @num_updates=83, @dc-uuid=2
> Jul 25 07:43:09 [1638] DVTVM0802.mse.am.mot.com cib: info:
> cib_perform_op: + /cib/status/node_state[@id='2']: @join=mem
> ber
> Jul 25 07:43:09 [1638] DVTVM0802.mse.am.mot.com cib: info:
> cib_perform_op: + /cib/status/node_state[@id='2']/transient_a
> ttributes[@id='2']/instance_attributes[@id='status-
> 2']/nvpair[@id='status-2-pingd']: @value=0
> Jul 25 07:43:09 [1638] DVTVM0802.mse.am.mot.com cib: info:
> cib_perform_op: + /cib/status/node_state[@id='2']/lrm[@id='2'
> ]/lrm_resources/lrm_resource[@id='ClusterIP']/lrm_rsc_op[@id='Cluster
> IP_last_0']: @crm-debug-origin=do_update_resource, @transition-
> key=5:7:0:1cec18ac-2aae-4c5c-8513-d6851bc10191, @transition-
> magic=0:0;5:7:0:1cec18ac-2aae-4c5c-8513-d6851bc10191, @call-id=32,
> @last-run=1532518973, @last-rc-change=1532518973, @exec-time=74
> Jul 25 07:43:09 [1638] DVTVM0802.mse.am.mot.com cib: info:
> cib_perform_op: ++
> /cib/status/node_state[@id='2']/lrm[@id='2']/lrm_resources/lrm_resour
> ce[@id='ClusterIP']: <lrm_rsc_op id="ClusterIP_monitor_1000"
> operation_key="ClusterIP_monitor_1000" operation="monitor" crm-debug-
> origin="do_update_resource" crm_feature_set="3.0.14" transition-
> key="4:6:0:1cec18ac-2aae-4c5c-8513-d6851bc10191" transition-
> magic="0:0;4:6:0:1cec18ac-2aae-4c5c-8513-d6851bc10191" exit-reason=""
> on_node="dvtvm0803" call-id=
> Jul 25 07:43:09 [1638] DVTVM0802.mse.am.mot.com cib: info:
> cib_perform_op: + /cib/status/node_state[@id='2']/lrm[@id='2'
> ]/lrm_resources/lrm_resource[@id='edgemanager']/lrm_rsc_op[@id='edgem
> anager_last_0']: @crm-debug-origin=do_update_resource, @transition-
> key=12:7:0:1cec18ac-2aae-4c5c-8513-d6851bc10191, @transition-
> magic=0:0;12:7:0:1cec18ac-2aae-4c5c-8513-d6851bc10191, @call-id=30,
> @last-run=1532518973, @last-rc-change=1532518973, @exec-time=34
> Jul 25 07:43:09 [1638] DVTVM0802.mse.am.mot.com cib: info:
> cib_perform_op: ++
> /cib/status/node_state[@id='2']/lrm[@id='2']/lrm_resources/lrm_resour
> ce[@id='edgemanager']: <lrm_rsc_op id="edgemanager_monitor_1000"
> operation_key="edgemanager_monitor_1000" operation="monitor" crm-
> debug-origin="do_update_resource" crm_feature_set="3.0.14"
> transition-key="12:6:0:1cec18ac-2aae-4c5c-8513-d6851bc10191"
> transition-magic="0:0;12:6:0:1cec18ac-2aae-4c5c-8513-d6851bc10191"
> exit-reason="" on_node="dvtvm0803"
> Jul 25 07:43:09 [1638] DVTVM0802.mse.am.mot.com cib: info:
> cib_replace_notify: Replaced: 0.20.71 -> 0.20.83 from
> dvtvm0803
> Jul 25 07:43:09 [1638] DVTVM0802.mse.am.mot.com cib: info:
> cib_process_request: Completed cib_replace operation for
> section 'all': OK (rc=0, origin=dvtvm0803/crmd/146, version=0.20.83)
> Jul 25 07:43:09 [1645] DVTVM0802.mse.am.mot.com crmd: info:
> action_synced_wait: Managed edgemanager_meta-data_0 process
> 13694 exited with rc=4
> Jul 25 07:43:09 [1645] DVTVM0802.mse.am.mot.com crmd: error:
> lrmd_api_get_metadata: Failed to receive meta-data for
> ocf:vendor:application
> Jul 25 07:43:09 [1645] DVTVM0802.mse.am.mot.com crmd: warning:
> build_operation_update: Failed to get metadata for application
> (ocf:vendor:application)
> Jul 25 07:43:09 [1641] DVTVM0802.mse.am.mot.com attrd: notice:
> attrd_cib_replaced_cb: Updating all attributes after
> cib_refresh_notify event
> Jul 25 07:43:09 [1638] DVTVM0802.mse.am.mot.com cib: info:
> cib_process_request: Completed cib_modify operation for
> section nodes: OK (rc=0, origin=dvtvm0803/crmd/147, version=0.20.83)
> Jul 25 07:43:09 [1645] DVTVM0802.mse.am.mot.com crmd: info:
> action_synced_wait: Managed edgemanager_meta-data_0 process
> 13696 exited with rc=4
> Jul 25 07:43:09 [1645] DVTVM0802.mse.am.mot.com crmd: error:
> lrmd_api_get_metadata: Failed to receive meta-data for
> ocf:vendor:application
> Jul 25 07:43:09 [1645] DVTVM0802.mse.am.mot.com crmd: warning:
> build_operation_update: Failed to get metadata for application
> (ocf:vendor:application)
> Jul 25 07:43:09 [1645] DVTVM0802.mse.am.mot.com crmd: info:
> do_log: Input I_NOT_DC received in state S_PENDING from
> do_cl_join_finalize_respond
> Jul 25 07:43:09 [1645] DVTVM0802.mse.am.mot.com crmd: notice:
> do_state_transition: State transition S_PENDING -> S_NOT_DC |
> input=I_NOT_DC cause=C_HA_MESSAGE origin=do_cl_join_finalize_respond
> Jul 25 07:43:09 [1638] DVTVM0802.mse.am.mot.com cib: info:
> cib_process_request: Completed cib_modify operation for
> section nodes: OK (rc=0, origin=dvtvm0803/crmd/148, version=0.20.83)
> Jul 25 07:43:09 [1638] DVTVM0802.mse.am.mot.com cib: info:
> cib_perform_op: Diff: --- 0.20.83 2
> Jul 25 07:43:09 [1638] DVTVM0802.mse.am.mot.com cib: info:
> cib_perform_op: Diff: +++ 0.20.84 (null)
> Jul 25 07:43:09 [1638] DVTVM0802.mse.am.mot.com cib: info:
> cib_perform_op: --
> /cib/status/node_state[@id='2']/lrm[@id='2']
> Jul 25 07:43:09 [1638] DVTVM0802.mse.am.mot.com cib: info:
> cib_perform_op: + /cib: @num_updates=84
> Jul 25 07:43:09 [1638] DVTVM0802.mse.am.mot.com cib: info:
> cib_file_backup: Archived previous version as
> /var/lib/pacemaker/cib/cib-29.raw
> Jul 25 07:43:09 [1638] DVTVM0802.mse.am.mot.com cib: info:
> cib_process_request: Completed cib_delete operation for
> section //node_state[@uname='dvtvm0803']/lrm: OK (rc=0,
> origin=dvtvm0803/crmd/149, version=0.20.84)
> Jul 25 07:43:09 [1638] DVTVM0802.mse.am.mot.com cib: info:
> cib_perform_op: Diff: --- 0.20.84 2
> Jul 25 07:43:09 [1638] DVTVM0802.mse.am.mot.com cib: info:
> cib_perform_op: Diff: +++ 0.20.85 (null)
> Jul 25 07:43:09 [1638] DVTVM0802.mse.am.mot.com cib: info:
> cib_perform_op: + /cib: @num_updates=85
> Jul 25 07:43:09 [1638] DVTVM0802.mse.am.mot.com cib: info:
> cib_perform_op: + /cib/status/node_state[@id='2']: @crm-
> debug-origin=do_lrm_query_internal
> Jul 25 07:43:09 [1638] DVTVM0802.mse.am.mot.com cib: info:
> cib_perform_op: ++ /cib/status/node_state[@id='2']: <lrm
> id="2"/>
> Jul 25 07:43:09 [1638] DVTVM0802.mse.am.mot.com cib: info:
> cib_perform_op: ++ <lrm_re
> sources>
> Jul 25 07:43:09 [1638] DVTVM0802.mse.am.mot.com cib: info:
> cib_perform_op: ++ <lrm_
> resource id="Connected" type="ping" class="ocf" provider="pacemaker">
> Jul 25 07:43:09 [1638] DVTVM0802.mse.am.mot.com cib: info:
> cib_perform_op: ++ <lr
> m_rsc_op id="Connected_last_0" operation_key="Connected_start_0"
> operation="start" crm-debug-origin="build_active_RAs"
> crm_feature_set="3.0.14" transition-key="8:0:0:1cec18ac-2aae-4c5c-
> 8513-d6851bc10191" transition-magic="0:0;8:0:0:1cec18ac-2aae-4c5c-
> 8513-d6851bc10191" exit-reason="" on_node="dvtvm0803" call-id="15"
> rc-code="0" op-status="0" interval="0" last-run="1532518326"
> Jul 25 07:43:09 [1638] DVTVM0802.mse.am.mot.com cib: info:
> cib_perform_op: ++ <lr
> m_rsc_op id="Connected_monitor_3000"
> operation_key="Connected_monitor_3000" operation="monitor" crm-debug-
> origin="build_active_RAs" crm_feature_set="3.0.14" transition-
> key="9:0:0:1cec18ac-2aae-4c5c-8513-d6851bc10191" transition-
> magic="0:0;9:0:0:1cec18ac-2aae-4c5c-8513-d6851bc10191" exit-reason=""
> on_node="dvtvm0803" call-id="16" rc-code="0" op-status="0"
> interval="3000" last-r
> Jul 25 07:43:09 [1638] DVTVM0802.mse.am.mot.com cib: info:
> cib_perform_op: ++ </lrm
> _resource>
> Jul 25 07:43:09 [1638] DVTVM0802.mse.am.mot.com cib: info:
> cib_perform_op: ++ <lrm_
> resource id="ClusterIP" type="IPaddr2" class="ocf"
> provider="heartbeat">
> Jul 25 07:43:09 [1638] DVTVM0802.mse.am.mot.com cib: info:
> cib_perform_op: ++ <lr
> m_rsc_op id="ClusterIP_last_0" operation_key="ClusterIP_stop_0"
> operation="stop" crm-debug-origin="build_active_RAs"
> crm_feature_set="3.0.14" transition-key="5:7:0:1cec18ac-2aae-4c5c-
> 8513-d6851bc10191" transition-magic="0:0;5:7:0:1cec18ac-2aae-4c5c-
> 8513-d6851bc10191" exit-reason="" on_node="dvtvm0803" call-id="32"
> rc-code="0" op-status="0" interval="0" last-run="1532518973" la
> Jul 25 07:43:09 [1638] DVTVM0802.mse.am.mot.com cib: info:
> cib_perform_op: ++ </lrm
> _resource>
> Jul 25 07:43:09 [1638] DVTVM0802.mse.am.mot.com cib: info:
> cib_perform_op: ++ <lrm_
> resource id="application" type="application" class="ocf"
> provider="vendor">
> Jul 25 07:43:09 [1638] DVTVM0802.mse.am.mot.com cib: info:
> cib_perform_op: ++ <lr
> m_rsc_op id="edgemanager_last_0" operation_key="edgemanager_stop_0"
> operation="stop" crm-debug-origin="build_active_RAs"
> crm_feature_set="3.0.14" transition-key="12:7:0:1cec18ac-2aae-4c5c-
> 8513-d6851bc10191" transition-magic="0:0;12:7:0:1cec18ac-2aae-4c5c-
> 8513-d6851bc10191" exit-reason="" on_node="dvtvm0803" call-id="30"
> rc-code="0" op-status="0" interval="0" last-run="15325189
> Jul 25 07:43:09 [1638] DVTVM0802.mse.am.mot.com cib: info:
> cib_perform_op: ++ </lrm
> _resource>
> Jul 25 07:43:09 [1638] DVTVM0802.mse.am.mot.com cib: info:
> cib_perform_op: ++ </lrm_r
> esources>
> Jul 25 07:43:09 [1638] DVTVM0802.mse.am.mot.com cib: info:
> cib_perform_op: ++ </lrm>
> Jul 25 07:43:09 [1638] DVTVM0802.mse.am.mot.com cib: info:
> cib_file_write_with_digest: Wrote version 0.20.0 of the CIB to
> disk (digest: d281e07c969310cc6525c6f46ec6a307)
> Jul 25 07:43:09 [1638] DVTVM0802.mse.am.mot.com cib: info:
> cib_process_request: Completed cib_modify operation for
> section status: OK (rc=0, origin=dvtvm0803/crmd/150, version=0.20.85)
> Jul 25 07:43:09 [1638] DVTVM0802.mse.am.mot.com cib: info:
> cib_file_write_with_digest: Reading cluster configuration file
> /var/lib/pacemaker/cib/cib.rzefQ3 (digest:
> /var/lib/pacemaker/cib/cib.Pm42VJ)
> Jul 25 07:43:09 [1638] DVTVM0802.mse.am.mot.com cib: info:
> cib_perform_op: Diff: --- 0.20.85 2
> Jul 25 07:43:09 [1638] DVTVM0802.mse.am.mot.com cib: info:
> cib_perform_op: Diff: +++ 0.20.86 (null)
> Jul 25 07:43:09 [1638] DVTVM0802.mse.am.mot.com cib: info:
> cib_perform_op: --
> /cib/status/node_state[@id='1']/lrm[@id='1']
> Jul 25 07:43:09 [1638] DVTVM0802.mse.am.mot.com cib: info:
> cib_perform_op: + /cib: @num_updates=86
> Jul 25 07:43:09 [1638] DVTVM0802.mse.am.mot.com cib: info:
> cib_process_request: Completed cib_delete operation for
> section //node_state[@uname='dvtvm0802']/lrm: OK (rc=0,
> origin=dvtvm0803/crmd/151, version=0.20.86)
> Jul 25 07:43:09 [1641] DVTVM0802.mse.am.mot.com attrd: info:
> attrd_peer_update: Setting pingd[dvtvm0803]: 0 -> 1000 from
> dvtvm0803
> Jul 25 07:43:09 [1638] DVTVM0802.mse.am.mot.com cib: info:
> cib_perform_op: Diff: --- 0.20.86 2
> Jul 25 07:43:09 [1638] DVTVM0802.mse.am.mot.com cib: info:
> cib_perform_op: Diff: +++ 0.20.87 (null)
> Jul 25 07:43:09 [1638] DVTVM0802.mse.am.mot.com cib: info:
> cib_perform_op: + /cib: @num_updates=87
> Jul 25 07:43:09 [1638] DVTVM0802.mse.am.mot.com cib: info:
> cib_perform_op: + /cib/status/node_state[@id='1']: @crm-
> debug-origin=do_lrm_query_internal
> Jul 25 07:43:09 [1638] DVTVM0802.mse.am.mot.com cib: info:
> cib_perform_op: ++ /cib/status/node_state[@id='1']: <lrm
> id="1"/>
> Jul 25 07:43:09 [1638] DVTVM0802.mse.am.mot.com cib: info:
> cib_perform_op: ++ <lrm_re
> sources>
> Jul 25 07:43:09 [1638] DVTVM0802.mse.am.mot.com cib: info:
> cib_perform_op: ++ <lrm_
> resource id="Connected" type="ping" class="ocf" provider="pacemaker">
> Jul 25 07:43:09 [1638] DVTVM0802.mse.am.mot.com cib: info:
> cib_perform_op: ++ <lr
> m_rsc_op id="Connected_last_0" operation_key="Connected_start_0"
> operation="start" crm-debug-origin="build_active_RAs"
> crm_feature_set="3.0.14" transition-key="10:0:0:1cec18ac-2aae-4c5c-
> 8513-d6851bc10191" transition-magic="0:0;10:0:0:1cec18ac-2aae-4c5c-
> 8513-d6851bc10191" exit-reason="" on_node="dvtvm0802" call-id="15"
> rc-code="0" op-status="0" interval="0" last-run="1532518326
> Jul 25 07:43:09 [1638] DVTVM0802.mse.am.mot.com cib: info:
> cib_perform_op: ++ <lr
> m_rsc_op id="Connected_monitor_3000"
> operation_key="Connected_monitor_3000" operation="monitor" crm-debug-
> origin="build_active_RAs" crm_feature_set="3.0.14" transition-
> key="11:0:0:1cec18ac-2aae-4c5c-8513-d6851bc10191" transition-
> magic="0:0;11:0:0:1cec18ac-2aae-4c5c-8513-d6851bc10191" exit-
> reason="" on_node="dvtvm0802" call-id="16" rc-code="0" op-status="0"
> interval="3000" last
> Jul 25 07:43:09 [1638] DVTVM0802.mse.am.mot.com cib: info:
> cib_perform_op: ++ </lrm
> _resource>
> Jul 25 07:43:09 [1638] DVTVM0802.mse.am.mot.com cib: info:
> cib_perform_op: ++ <lrm_
> resource id="ClusterIP" type="IPaddr2" class="ocf"
> provider="heartbeat">
> Jul 25 07:43:09 [1638] DVTVM0802.mse.am.mot.com cib: info:
> cib_perform_op: ++ <lr
> m_rsc_op id="ClusterIP_last_0" operation_key="ClusterIP_start_0"
> operation="start" crm-debug-origin="build_active_RAs"
> crm_feature_set="3.0.14" transition-key="4:1:0:1cec18ac-2aae-4c5c-
> 8513-d6851bc10191" transition-magic="0:0;4:1:0:1cec18ac-2aae-4c5c-
> 8513-d6851bc10191" exit-reason="" on_node="dvtvm0802" call-id="17"
> rc-code="0" op-status="0" interval="0" last-run="1532518330"
> Jul 25 07:43:09 [1638] DVTVM0802.mse.am.mot.com cib: info:
> cib_perform_op: ++ <lr
> m_rsc_op id="ClusterIP_monitor_1000"
> operation_key="ClusterIP_monitor_1000" operation="monitor" crm-debug-
> origin="build_active_RAs" crm_feature_set="3.0.14" transition-
> key="5:1:0:1cec18ac-2aae-4c5c-8513-d6851bc10191" transition-
> magic="0:0;5:1:0:1cec18ac-2aae-4c5c-8513-d6851bc10191" exit-reason=""
> on_node="dvtvm0802" call-id="18" rc-code="0" op-status="0"
> interval="1000" last-r
> Jul 25 07:43:09 [1638] DVTVM0802.mse.am.mot.com cib: info:
> cib_perform_op: ++ </lrm
> _resource>
> Jul 25 07:43:09 [1638] DVTVM0802.mse.am.mot.com cib: info:
> cib_perform_op: ++ <lrm_
> resource id="application" type="application" class="ocf"
> provider="vendor">
> Jul 25 07:43:09 [1638] DVTVM0802.mse.am.mot.com cib: info:
> cib_perform_op: ++ <lr
> m_rsc_op id="edgemanager_last_0" operation_key="edgemanager_start_0"
> operation="start" crm-debug-origin="build_active_RAs"
> crm_feature_set="3.0.14" transition-key="14:1:0:1cec18ac-2aae-4c5c-
> 8513-d6851bc10191" transition-magic="0:0;14:1:0:1cec18ac-2aae-4c5c-
> 8513-d6851bc10191" exit-reason="" on_node="dvtvm0802" call-id="19"
> rc-code="0" op-status="0" interval="0" last-run="153251
> Jul 25 07:43:09 [1638] DVTVM0802.mse.am.mot.com cib: info:
> cib_perform_op: ++ <lr
> m_rsc_op id="edgemanager_monitor_1000"
> operation_key="edgemanager_monitor_1000" operation="monitor" crm-
> debug-origin="build_active_RAs" crm_feature_set="3.0.14" transition-
> key="15:1:0:1cec18ac-2aae-4c5c-8513-d6851bc10191" transition-
> magic="0:0;15:1:0:1cec18ac-2aae-4c5c-8513-d6851bc10191" exit-
> reason="" on_node="dvtvm0802" call-id="20" rc-code="0" op-status="0"
> interval="1000"
> Jul 25 07:43:09 [1638] DVTVM0802.mse.am.mot.com cib: info:
> cib_perform_op: ++ </lrm
> _resource>
> Jul 25 07:43:09 [1638] DVTVM0802.mse.am.mot.com cib: info:
> cib_perform_op: ++ </lrm_r
> esources>
> Jul 25 07:43:09 [1638] DVTVM0802.mse.am.mot.com cib: info:
> cib_perform_op: ++ </lrm>
> Jul 25 07:43:09 [1638] DVTVM0802.mse.am.mot.com cib: info:
> cib_process_request: Completed cib_modify operation for
> section status: OK (rc=0, origin=dvtvm0803/crmd/152, version=0.20.87)
> Jul 25 07:43:09 [1638] DVTVM0802.mse.am.mot.com cib: info:
> cib_process_request: Completed cib_modify operation for
> section nodes: OK (rc=0, origin=dvtvm0803/crmd/155, version=0.20.87)
> Jul 25 07:43:09 [1638] DVTVM0802.mse.am.mot.com cib: info:
> cib_perform_op: Diff: --- 0.20.87 2
> Jul 25 07:43:09 [1638] DVTVM0802.mse.am.mot.com cib: info:
> cib_perform_op: Diff: +++ 0.20.88 (null)
> Jul 25 07:43:09 [1638] DVTVM0802.mse.am.mot.com cib: info:
> cib_perform_op: + /cib: @num_updates=88
> Jul 25 07:43:09 [1638] DVTVM0802.mse.am.mot.com cib: info:
> cib_perform_op: + /cib/status/node_state[@id='1']: @crm-
> debug-origin=do_state_transition
> Jul 25 07:43:09 [1638] DVTVM0802.mse.am.mot.com cib: info:
> cib_perform_op: + /cib/status/node_state[@id='2']: @crm-
> debug-origin=do_state_transition
> Jul 25 07:43:09 [1638] DVTVM0802.mse.am.mot.com cib: info:
> cib_process_request: Completed cib_modify operation for
> section status: OK (rc=0, origin=dvtvm0803/crmd/156, version=0.20.88)
> Jul 25 07:43:09 [1638] DVTVM0802.mse.am.mot.com cib: info:
> cib_process_request: Completed cib_modify operation for
> section cib: OK (rc=0, origin=dvtvm0803/crmd/157, version=0.20.88)
> Jul 25 07:43:09 [1640] DVTVM0802.mse.am.mot.com lrmd: info:
> cancel_recurring_action: Cancelling ocf operation
> edgemanager_monitor_1000
> Jul 25 07:43:09 [1645] DVTVM0802.mse.am.mot.com crmd: info:
> do_lrm_rsc_op: Performing key=15:8:0:1cec18ac-2aae-4c5c-8513-
> d6851bc10191 op=edgemanager_stop_0
> Jul 25 07:43:09 [1640] DVTVM0802.mse.am.mot.com lrmd: info:
> log_execute: executing - rsc:application action:stop
> call_id:22
> Jul 25 07:43:09 [1638] DVTVM0802.mse.am.mot.com cib: info:
> cib_process_request: Forwarding cib_modify operation for
> section status to all (origin=local/crmd/92)
> Jul 25 07:43:09 [1645] DVTVM0802.mse.am.mot.com crmd: info:
> process_lrm_event: Result of monitor operation for application
> on dvtvm0802: Cancelled | call=20 key=edgemanager_monitor_1000
> confirmed=true
> Jul 25 07:43:09 [1638] DVTVM0802.mse.am.mot.com cib: info:
> cib_perform_op: Diff: --- 0.20.88 2
> Jul 25 07:43:09 [1638] DVTVM0802.mse.am.mot.com cib: info:
> cib_perform_op: Diff: +++ 0.20.89 (null)
> Jul 25 07:43:09 [1638] DVTVM0802.mse.am.mot.com cib: info:
> cib_perform_op: + /cib: @num_updates=89
> Jul 25 07:43:09 [1638] DVTVM0802.mse.am.mot.com cib: info:
> cib_perform_op: + /cib/status/node_state[@id='1']: @crm-
> debug-origin=do_update_resource
> Jul 25 07:43:09 [1638] DVTVM0802.mse.am.mot.com cib: info:
> cib_perform_op: + /cib/status/node_state[@id='1']/lrm[@id='1'
> ]/lrm_resources/lrm_resource[@id='edgemanager']/lrm_rsc_op[@id='edgem
> anager_last_0']: @operation_key=edgemanager_stop_0, @operation=stop,
> @crm-debug-origin=do_update_resource, @transition-
> key=15:8:0:1cec18ac-2aae-4c5c-8513-d6851bc10191, @transition-magic=-
> 1:193;15:8:0:1cec18ac-2aae-4c5c-8513-d6851bc10191, @call-id=-1, @rc-
> code=193, @op-status=-1, @last-run=1532518989, @last-r
> Jul 25 07:43:09 [1638] DVTVM0802.mse.am.mot.com cib: info:
> cib_process_request: Completed cib_modify operation for
> section status: OK (rc=0, origin=dvtvm0802/crmd/92, version=0.20.89)
> Jul 25 07:43:09 application(application)[13697]: INFO: Stopping
> APP - setting to Standby
> Jul 25 07:43:09 [1640] DVTVM0802.mse.am.mot.com lrmd: notice:
> operation_finished: edgemanager_stop_0:13697:stderr [
> /usr/local/vendor/bin/PrimaryMode.sh: line 27: $Filename: ambiguous
> redirect ]
> Jul 25 07:43:09 [1640] DVTVM0802.mse.am.mot.com lrmd: info:
> log_finished: finished - rsc:application action:stop
> call_id:22 pid:13697 exit-code:0 exec-time:34ms queue-time:0ms
> Jul 25 07:43:09 [1645] DVTVM0802.mse.am.mot.com crmd: notice:
> process_lrm_event: Result of stop operation for application on
> dvtvm0802: 0 (ok) | call=22 key=edgemanager_stop_0 confirmed=true
> cib-update=93
> Jul 25 07:43:09 [1638] DVTVM0802.mse.am.mot.com cib: info:
> cib_process_request: Forwarding cib_modify operation for
> section status to all (origin=local/crmd/93)
> Jul 25 07:43:09 [1638] DVTVM0802.mse.am.mot.com cib: info:
> cib_perform_op: Diff: --- 0.20.89 2
> Jul 25 07:43:09 [1638] DVTVM0802.mse.am.mot.com cib: info:
> cib_perform_op: Diff: +++ 0.20.90 (null)
> Jul 25 07:43:09 [1638] DVTVM0802.mse.am.mot.com cib: info:
> cib_perform_op: + /cib: @num_updates=90
> Jul 25 07:43:09 [1638] DVTVM0802.mse.am.mot.com cib: info:
> cib_perform_op: + /cib/status/node_state[@id='1']/lrm[@id='1'
> ]/lrm_resources/lrm_resource[@id='edgemanager']/lrm_rsc_op[@id='edgem
> anager_last_0']: @transition-magic=0:0;15:8:0:1cec18ac-2aae-4c5c-
> 8513-d6851bc10191, @call-id=22, @rc-code=0, @op-status=0, @exec-
> time=34
> Jul 25 07:43:09 [1638] DVTVM0802.mse.am.mot.com cib: info:
> cib_process_request: Completed cib_modify operation for
> section status: OK (rc=0, origin=dvtvm0802/crmd/93, version=0.20.90)
> Jul 25 07:43:09 [1640] DVTVM0802.mse.am.mot.com lrmd: info:
> cancel_recurring_action: Cancelling ocf operation
> ClusterIP_monitor_1000
> Jul 25 07:43:09 [1645] DVTVM0802.mse.am.mot.com crmd: info:
> do_lrm_rsc_op: Performing key=6:8:0:1cec18ac-2aae-4c5c-8513-
> d6851bc10191 op=ClusterIP_stop_0
> Jul 25 07:43:09 [1638] DVTVM0802.mse.am.mot.com cib: info:
> cib_process_request: Forwarding cib_modify operation for
> section status to all (origin=local/crmd/94)
> Jul 25 07:43:09 [1640] DVTVM0802.mse.am.mot.com lrmd: info:
> log_execute: executing - rsc:ClusterIP action:stop call_id:24
> Jul 25 07:43:09 [1645] DVTVM0802.mse.am.mot.com crmd: info:
> process_lrm_event: Result of monitor operation for ClusterIP
> on dvtvm0802: Cancelled | call=18 key=ClusterIP_monitor_1000
> confirmed=true
> Jul 25 07:43:09 [1638] DVTVM0802.mse.am.mot.com cib: info:
> cib_perform_op: Diff: --- 0.20.90 2
> Jul 25 07:43:09 [1638] DVTVM0802.mse.am.mot.com cib: info:
> cib_perform_op: Diff: +++ 0.20.91 (null)
> Jul 25 07:43:09 [1638] DVTVM0802.mse.am.mot.com cib: info:
> cib_perform_op: + /cib: @num_updates=91
> Jul 25 07:43:09 [1638] DVTVM0802.mse.am.mot.com cib: info:
> cib_perform_op: + /cib/status/node_state[@id='1']/lrm[@id='1'
> ]/lrm_resources/lrm_resource[@id='ClusterIP']/lrm_rsc_op[@id='Cluster
> IP_last_0']: @operation_key=ClusterIP_stop_0, @operation=stop, @crm-
> debug-origin=do_update_resource, @transition-key=6:8:0:1cec18ac-2aae-
> 4c5c-8513-d6851bc10191, @transition-magic=-1:193;6:8:0:1cec18ac-2aae-
> 4c5c-8513-d6851bc10191, @call-id=-1, @rc-code=193, @op-status=-1,
> @last-run=1532518989, @last-rc-change
> Jul 25 07:43:09 [1638] DVTVM0802.mse.am.mot.com cib: info:
> cib_process_request: Completed cib_modify operation for
> section status: OK (rc=0, origin=dvtvm0802/crmd/94, version=0.20.91)
> Jul 25 07:43:09 IPaddr2(ClusterIP)[13712]: INFO: IP status = ok,
> IP_CIP=
> Jul 25 07:43:09 [1640] DVTVM0802.mse.am.mot.com lrmd: info:
> log_finished: finished - rsc:ClusterIP action:stop call_id:24
> pid:13712 exit-code:0 exec-time:76ms queue-time:0ms
> Jul 25 07:43:09 [1645] DVTVM0802.mse.am.mot.com crmd: notice:
> process_lrm_event: Result of stop operation for ClusterIP on
> dvtvm0802: 0 (ok) | call=24 key=ClusterIP_stop_0 confirmed=true cib-
> update=95
> Jul 25 07:43:09 [1638] DVTVM0802.mse.am.mot.com cib: info:
> cib_process_request: Forwarding cib_modify operation for
> section status to all (origin=local/crmd/95)
> Jul 25 07:43:09 [1638] DVTVM0802.mse.am.mot.com cib: info:
> cib_perform_op: Diff: --- 0.20.91 2
> Jul 25 07:43:09 [1638] DVTVM0802.mse.am.mot.com cib: info:
> cib_perform_op: Diff: +++ 0.20.92 (null)
> Jul 25 07:43:09 [1638] DVTVM0802.mse.am.mot.com cib: info:
> cib_perform_op: + /cib: @num_updates=92
> Jul 25 07:43:09 [1638] DVTVM0802.mse.am.mot.com cib: info:
> cib_perform_op: + /cib/status/node_state[@id='1']/lrm[@id='1'
> ]/lrm_resources/lrm_resource[@id='ClusterIP']/lrm_rsc_op[@id='Cluster
> IP_last_0']: @transition-magic=0:0;6:8:0:1cec18ac-2aae-4c5c-8513-
> d6851bc10191, @call-id=24, @rc-code=0, @op-status=0, @exec-time=76
> Jul 25 07:43:09 [1638] DVTVM0802.mse.am.mot.com cib: info:
> cib_process_request: Completed cib_modify operation for
> section status: OK (rc=0, origin=dvtvm0802/crmd/95, version=0.20.92)
> Jul 25 07:43:09 [1569] DVTVM0802.mse.am.mot.com pacemakerd: info:
> mcp_cpg_deliver: Ignoring process list sent by peer for local
> node
> Jul 25 07:43:10 [1638] DVTVM0802.mse.am.mot.com cib: info:
> cib_perform_op: Diff: --- 0.20.92 2
> Jul 25 07:43:10 [1638] DVTVM0802.mse.am.mot.com cib: info:
> cib_perform_op: Diff: +++ 0.20.93 (null)
> Jul 25 07:43:10 [1638] DVTVM0802.mse.am.mot.com cib: info:
> cib_perform_op: + /cib: @num_updates=93
> Jul 25 07:43:10 [1638] DVTVM0802.mse.am.mot.com cib: info:
> cib_perform_op: ++
> /cib/status/node_state[@id='1']: <transient_attributes id="1"/>
> Jul 25 07:43:10 [1638] DVTVM0802.mse.am.mot.com cib: info:
> cib_perform_op: ++ <instan
> ce_attributes id="status-1">
> Jul 25 07:43:10 [1638] DVTVM0802.mse.am.mot.com cib: info:
> cib_perform_op: ++ <nvpa
> ir id="status-1-pingd" name="pingd" value="2000"/>
> Jul 25 07:43:10 [1638] DVTVM0802.mse.am.mot.com cib: info:
> cib_perform_op: ++ </insta
> nce_attributes>
> Jul 25 07:43:10 [1638] DVTVM0802.mse.am.mot.com cib: info:
> cib_perform_op: ++ </transie
> nt_attributes>
> Jul 25 07:43:10 [1638] DVTVM0802.mse.am.mot.com cib: info:
> cib_perform_op: + /cib/status/node_state[@id='2']/transient_a
> ttributes[@id='2']/instance_attributes[@id='status-
> 2']/nvpair[@id='status-2-pingd']: @value=1000
> Jul 25 07:43:10 [1638] DVTVM0802.mse.am.mot.com cib: info:
> cib_process_request: Completed cib_modify operation for
> section status: OK (rc=0, origin=dvtvm0803/attrd/9, version=0.20.93)
> Jul 25 07:43:10 [1645] DVTVM0802.mse.am.mot.com crmd: info:
> do_lrm_rsc_op: Performing key=4:9:0:1cec18ac-2aae-4c5c-8513-
> d6851bc10191 op=ClusterIP_start_0
> Jul 25 07:43:10 [1638] DVTVM0802.mse.am.mot.com cib: info:
> cib_process_request: Forwarding cib_modify operation for
> section status to all (origin=local/crmd/96)
> Jul 25 07:43:10 [1640] DVTVM0802.mse.am.mot.com lrmd: info:
> log_execute: executing - rsc:ClusterIP action:start call_id:25
> Jul 25 07:43:10 [1638] DVTVM0802.mse.am.mot.com cib: info:
> cib_perform_op: Diff: --- 0.20.93 2
> Jul 25 07:43:10 [1638] DVTVM0802.mse.am.mot.com cib: info:
> cib_perform_op: Diff: +++ 0.20.94 (null)
> Jul 25 07:43:10 [1638] DVTVM0802.mse.am.mot.com cib: info:
> cib_perform_op: + /cib: @num_updates=94
> Jul 25 07:43:10 [1638] DVTVM0802.mse.am.mot.com cib: info:
> cib_perform_op: + /cib/status/node_state[@id='1']/lrm[@id='1'
> ]/lrm_resources/lrm_resource[@id='ClusterIP']/lrm_rsc_op[@id='Cluster
> IP_last_0']: @operation_key=ClusterIP_start_0, @operation=start,
> @transition-key=4:9:0:1cec18ac-2aae-4c5c-8513-d6851bc10191,
> @transition-magic=-1:193;4:9:0:1cec18ac-2aae-4c5c-8513-d6851bc10191,
> @call-id=-1, @rc-code=193, @op-status=-1, @last-run=1532518990,
> @last-rc-change=1532518990, @exec-time=0
> Jul 25 07:43:10 [1638] DVTVM0802.mse.am.mot.com cib: info:
> cib_process_request: Completed cib_modify operation for
> section status: OK (rc=0, origin=dvtvm0802/crmd/96, version=0.20.94)
> Jul 25 07:43:10 IPaddr2(ClusterIP)[13774]: INFO: Adding inet
> address 10.144.102.230/24 with broadcast address 10.144.102.255 to
> device eth0
> Jul 25 07:43:10 IPaddr2(ClusterIP)[13774]: INFO: Bringing device
> eth0 up
> Jul 25 07:43:10 IPaddr2(ClusterIP)[13774]: INFO:
> /usr/libexec/heartbeat/send_arp -i 200 -c 5 -p /var/run/resource-
> agents/send_arp-10.144.102.230 -I eth0 -m auto 10.144.102.230
> Jul 25 07:43:14 [1641] DVTVM0802.mse.am.mot.com attrd: info:
> attrd_peer_update: Setting pingd[dvtvm0803]: 1000 -> 2000 from
> dvtvm0803
> Jul 25 07:43:14 [1640] DVTVM0802.mse.am.mot.com lrmd: info:
> log_finished: finished - rsc:ClusterIP action:start call_id:25
> pid:13774 exit-code:0 exec-time:4105ms queue-time:1ms
> Jul 25 07:43:14 [1645] DVTVM0802.mse.am.mot.com crmd: notice:
> process_lrm_event: Result of start operation for ClusterIP on
> dvtvm0802: 0 (ok) | call=25 key=ClusterIP_start_0 confirmed=true cib-
> update=97
> Jul 25 07:43:14 [1638] DVTVM0802.mse.am.mot.com cib: info:
> cib_process_request: Forwarding cib_modify operation for
> section status to all (origin=local/crmd/97)
> Jul 25 07:43:14 [1638] DVTVM0802.mse.am.mot.com cib: info:
> cib_perform_op: Diff: --- 0.20.94 2
> Jul 25 07:43:14 [1638] DVTVM0802.mse.am.mot.com cib: info:
> cib_perform_op: Diff: +++ 0.20.95 (null)
> Jul 25 07:43:14 [1638] DVTVM0802.mse.am.mot.com cib: info:
> cib_perform_op: + /cib: @num_updates=95
> Jul 25 07:43:14 [1638] DVTVM0802.mse.am.mot.com cib: info:
> cib_perform_op: + /cib/status/node_state[@id='1']/lrm[@id='1'
> ]/lrm_resources/lrm_resource[@id='ClusterIP']/lrm_rsc_op[@id='Cluster
> IP_last_0']: @transition-magic=0:0;4:9:0:1cec18ac-2aae-4c5c-8513-
> d6851bc10191, @call-id=25, @rc-code=0, @op-status=0, @exec-time=4105,
> @queue-time=1
> Jul 25 07:43:14 [1638] DVTVM0802.mse.am.mot.com cib: info:
> cib_process_request: Completed cib_modify operation for
> section status: OK (rc=0, origin=dvtvm0802/crmd/97, version=0.20.95)
> Jul 25 07:43:14 [1645] DVTVM0802.mse.am.mot.com crmd: info:
> do_lrm_rsc_op: Performing key=5:9:0:1cec18ac-2aae-4c5c-8513-
> d6851bc10191 op=ClusterIP_monitor_1000
> Jul 25 07:43:14 [1638] DVTVM0802.mse.am.mot.com cib: info:
> cib_process_request: Forwarding cib_modify operation for
> section status to all (origin=local/crmd/98)
> Jul 25 07:43:14 [1638] DVTVM0802.mse.am.mot.com cib: info:
> cib_perform_op: Diff: --- 0.20.95 2
> Jul 25 07:43:14 [1638] DVTVM0802.mse.am.mot.com cib: info:
> cib_perform_op: Diff: +++ 0.20.96 (null)
> Jul 25 07:43:14 [1638] DVTVM0802.mse.am.mot.com cib: info:
> cib_perform_op: + /cib: @num_updates=96
> Jul 25 07:43:14 [1638] DVTVM0802.mse.am.mot.com cib: info:
> cib_perform_op: + /cib/status/node_state[@id='1']/lrm[@id='1'
> ]/lrm_resources/lrm_resource[@id='ClusterIP']/lrm_rsc_op[@id='Cluster
> IP_monitor_1000']: @crm-debug-origin=do_update_resource,
> @transition-key=5:9:0:1cec18ac-2aae-4c5c-8513-d6851bc10191,
> @transition-magic=-1:193;5:9:0:1cec18ac-2aae-4c5c-8513-d6851bc10191,
> @call-id=-1, @rc-code=193, @op-status=-1, @last-rc-change=1532518994,
> @exec-time=0
> Jul 25 07:43:14 [1645] DVTVM0802.mse.am.mot.com crmd: info:
> do_lrm_rsc_op: Performing key=14:9:0:1cec18ac-2aae-4c5c-8513-
> d6851bc10191 op=edgemanager_start_0
> Jul 25 07:43:14 [1638] DVTVM0802.mse.am.mot.com cib: info:
> cib_process_request: Completed cib_modify operation for
> section status: OK (rc=0, origin=dvtvm0802/crmd/98, version=0.20.96)
> Jul 25 07:43:14 [1645] DVTVM0802.mse.am.mot.com crmd: info:
> action_synced_wait: Managed edgemanager_meta-data_0 process
> 13924 exited with rc=4
> Jul 25 07:43:14 [1645] DVTVM0802.mse.am.mot.com crmd: error:
> lrmd_api_get_metadata: Failed to receive meta-data for
> ocf:vendor:application
> Jul 25 07:43:14 [1645] DVTVM0802.mse.am.mot.com crmd: warning:
> build_operation_update: Failed to get metadata for application
> (ocf:vendor:application)
> Jul 25 07:43:14 [1638] DVTVM0802.mse.am.mot.com cib: info:
> cib_process_request: Forwarding cib_modify operation for
> section status to all (origin=local/crmd/99)
> Jul 25 07:43:14 [1640] DVTVM0802.mse.am.mot.com lrmd: info:
> log_execute: executing - rsc:application action:start
> call_id:27
> Jul 25 07:43:14 [1638] DVTVM0802.mse.am.mot.com cib: info:
> cib_perform_op: Diff: --- 0.20.96 2
> Jul 25 07:43:14 [1638] DVTVM0802.mse.am.mot.com cib: info:
> cib_perform_op: Diff: +++ 0.20.97 (null)
> Jul 25 07:43:14 [1638] DVTVM0802.mse.am.mot.com cib: info:
> cib_perform_op: + /cib: @num_updates=97
> Jul 25 07:43:14 [1638] DVTVM0802.mse.am.mot.com cib: info:
> cib_perform_op: + /cib/status/node_state[@id='1']/lrm[@id='1'
> ]/lrm_resources/lrm_resource[@id='edgemanager']/lrm_rsc_op[@id='edgem
> anager_last_0']: @operation_key=edgemanager_start_0,
> @operation=start, @transition-key=14:9:0:1cec18ac-2aae-4c5c-8513-
> d6851bc10191, @transition-magic=-1:193;14:9:0:1cec18ac-2aae-4c5c-
> 8513-d6851bc10191, @call-id=-1, @rc-code=193, @op-status=-1, @last-
> run=1532518994, @last-rc-change=1532518994, @exec-time=0
> Jul 25 07:43:14 [1638] DVTVM0802.mse.am.mot.com cib: info:
> cib_process_request: Completed cib_modify operation for
> section status: OK (rc=0, origin=dvtvm0802/crmd/99, version=0.20.97)
> Jul 25 07:43:14 application(edgemanager)[13925]: INFO: Starting
> APP - setting to Primary
> Jul 25 07:43:14 [1640] DVTVM0802.mse.am.mot.com lrmd: info:
> log_finished: finished - rsc:application action:start
> call_id:27 pid:13925 exit-code:0 exec-time:37ms queue-time:0ms
> Jul 25 07:43:14 [1645] DVTVM0802.mse.am.mot.com crmd: info:
> action_synced_wait: Managed edgemanager_meta-data_0 process
> 13955 exited with rc=4
> Jul 25 07:43:14 [1645] DVTVM0802.mse.am.mot.com crmd: error:
> lrmd_api_get_metadata: Failed to receive meta-data for
> ocf:vendor:application
> Jul 25 07:43:14 [1645] DVTVM0802.mse.am.mot.com crmd: warning:
> build_operation_update: Failed to get metadata for application
> (ocf:vendor:application)
> Jul 25 07:43:14 [1645] DVTVM0802.mse.am.mot.com crmd: notice:
> process_lrm_event: Result of start operation for application
> on dvtvm0802: 0 (ok) | call=27 key=edgemanager_start_0 confirmed=true
> cib-update=100
> Jul 25 07:43:14 [1638] DVTVM0802.mse.am.mot.com cib: info:
> cib_process_request: Forwarding cib_modify operation for
> section status to all (origin=local/crmd/100)
> Jul 25 07:43:14 [1638] DVTVM0802.mse.am.mot.com cib: info:
> cib_perform_op: Diff: --- 0.20.97 2
> Jul 25 07:43:14 [1638] DVTVM0802.mse.am.mot.com cib: info:
> cib_perform_op: Diff: +++ 0.20.98 (null)
> Jul 25 07:43:14 [1638] DVTVM0802.mse.am.mot.com cib: info:
> cib_perform_op: + /cib: @num_updates=98
> Jul 25 07:43:14 [1638] DVTVM0802.mse.am.mot.com cib: info:
> cib_perform_op: + /cib/status/node_state[@id='1']/lrm[@id='1'
> ]/lrm_resources/lrm_resource[@id='edgemanager']/lrm_rsc_op[@id='edgem
> anager_last_0']: @transition-magic=0:0;14:9:0:1cec18ac-2aae-4c5c-
> 8513-d6851bc10191, @call-id=27, @rc-code=0, @op-status=0, @exec-
> time=37
> Jul 25 07:43:14 [1638] DVTVM0802.mse.am.mot.com cib: info:
> cib_process_request: Completed cib_modify operation for
> section status: OK (rc=0, origin=dvtvm0802/crmd/100, version=0.20.98)
> Jul 25 07:43:14 [1645] DVTVM0802.mse.am.mot.com crmd: info:
> do_lrm_rsc_op: Performing key=15:9:0:1cec18ac-2aae-4c5c-8513-
> d6851bc10191 op=edgemanager_monitor_1000
> Jul 25 07:43:14 [1645] DVTVM0802.mse.am.mot.com crmd: info:
> action_synced_wait: Managed edgemanager_meta-data_0 process
> 13962 exited with rc=4
> Jul 25 07:43:14 [1645] DVTVM0802.mse.am.mot.com crmd: error:
> lrmd_api_get_metadata: Failed to receive meta-data for
> ocf:vendor:application
> Jul 25 07:43:14 [1645] DVTVM0802.mse.am.mot.com crmd: warning:
> build_operation_update: Failed to get metadata for application
> (ocf:vendor:application)
> Jul 25 07:43:14 [1638] DVTVM0802.mse.am.mot.com cib: info:
> cib_process_request: Forwarding cib_modify operation for
> section status to all (origin=local/crmd/101)
> Jul 25 07:43:14 [1638] DVTVM0802.mse.am.mot.com cib: info:
> cib_perform_op: Diff: --- 0.20.98 2
> Jul 25 07:43:14 [1638] DVTVM0802.mse.am.mot.com cib: info:
> cib_perform_op: Diff: +++ 0.20.99 (null)
> Jul 25 07:43:14 [1638] DVTVM0802.mse.am.mot.com cib: info:
> cib_perform_op: + /cib: @num_updates=99
> Jul 25 07:43:14 [1638] DVTVM0802.mse.am.mot.com cib: info:
> cib_perform_op: + /cib/status/node_state[@id='1']/lrm[@id='1'
> ]/lrm_resources/lrm_resource[@id='edgemanager']/lrm_rsc_op[@id='edgem
> anager_monitor_1000']: @crm-debug-origin=do_update_resource,
> @transition-key=15:9:0:1cec18ac-2aae-4c5c-8513-d6851bc10191,
> @transition-magic=-1:193;15:9:0:1cec18ac-2aae-4c5c-8513-d6851bc10191,
> @call-id=-1, @rc-code=193, @op-status=-1, @last-rc-change=1532518994,
> @exec-time=0, @queue-time=0
> Jul 25 07:43:14 [1638] DVTVM0802.mse.am.mot.com cib: info:
> cib_process_request: Completed cib_modify operation for
> section status: OK (rc=0, origin=dvtvm0802/crmd/101, version=0.20.99)
> Jul 25 07:43:14 [1645] DVTVM0802.mse.am.mot.com crmd: info:
> action_synced_wait: Managed edgemanager_meta-data_0 process
> 13995 exited with rc=4
> Jul 25 07:43:14 [1645] DVTVM0802.mse.am.mot.com crmd: error:
> lrmd_api_get_metadata: Failed to receive meta-data for
> ocf:vendor:application
> Jul 25 07:43:14 [1645] DVTVM0802.mse.am.mot.com crmd: warning:
> build_operation_update: Failed to get metadata for application
> (ocf:vendor:application)
> Jul 25 07:43:14 [1645] DVTVM0802.mse.am.mot.com crmd: info:
> process_lrm_event: Result of monitor operation for application
> on dvtvm0802: 0 (ok) | call=28 key=edgemanager_monitor_1000
> confirmed=false cib-update=102
> Jul 25 07:43:14 [1645] DVTVM0802.mse.am.mot.com crmd: info:
> process_lrm_event: Result of monitor operation for ClusterIP
> on dvtvm0802: 0 (ok) | call=26 key=ClusterIP_monitor_1000
> confirmed=false cib-update=103
> Jul 25 07:43:14 [1638] DVTVM0802.mse.am.mot.com cib: info:
> cib_process_request: Forwarding cib_modify operation for
> section status to all (origin=local/crmd/102)
> Jul 25 07:43:14 [1638] DVTVM0802.mse.am.mot.com cib: info:
> cib_process_request: Forwarding cib_modify operation for
> section status to all (origin=local/crmd/103)
> Jul 25 07:43:14 [1638] DVTVM0802.mse.am.mot.com cib: info:
> cib_perform_op: Diff: --- 0.20.99 2
> Jul 25 07:43:14 [1638] DVTVM0802.mse.am.mot.com cib: info:
> cib_perform_op: Diff: +++ 0.20.100 (null)
> Jul 25 07:43:14 [1638] DVTVM0802.mse.am.mot.com cib: info:
> cib_perform_op: + /cib: @num_updates=100
> Jul 25 07:43:14 [1638] DVTVM0802.mse.am.mot.com cib: info:
> cib_perform_op: + /cib/status/node_state[@id='1']/lrm[@id='1'
> ]/lrm_resources/lrm_resource[@id='edgemanager']/lrm_rsc_op[@id='edgem
> anager_monitor_1000']: @transition-magic=0:0;15:9:0:1cec18ac-2aae-
> 4c5c-8513-d6851bc10191, @call-id=28, @rc-code=0, @op-status=0, @exec-
> time=18
> Jul 25 07:43:14 [1638] DVTVM0802.mse.am.mot.com cib: info:
> cib_process_request: Completed cib_modify operation for
> section status: OK (rc=0, origin=dvtvm0802/crmd/102,
> version=0.20.100)
> Jul 25 07:43:14 [1638] DVTVM0802.mse.am.mot.com cib: info:
> cib_perform_op: Diff: --- 0.20.100 2
> Jul 25 07:43:14 [1638] DVTVM0802.mse.am.mot.com cib: info:
> cib_perform_op: Diff: +++ 0.20.101 (null)
> Jul 25 07:43:14 [1638] DVTVM0802.mse.am.mot.com cib: info:
> cib_perform_op: + /cib: @num_updates=101
> Jul 25 07:43:14 [1638] DVTVM0802.mse.am.mot.com cib: info:
> cib_perform_op: + /cib/status/node_state[@id='1']/lrm[@id='1'
> ]/lrm_resources/lrm_resource[@id='ClusterIP']/lrm_rsc_op[@id='Cluster
> IP_monitor_1000']: @transition-magic=0:0;5:9:0:1cec18ac-2aae-4c5c-
> 8513-d6851bc10191, @call-id=26, @rc-code=0, @op-status=0, @exec-
> time=71
> Jul 25 07:43:14 [1638] DVTVM0802.mse.am.mot.com cib: info:
> cib_process_request: Completed cib_modify operation for
> section status: OK (rc=0, origin=dvtvm0802/crmd/103,
> version=0.20.101)
> Jul 25 07:43:15 [1638] DVTVM0802.mse.am.mot.com cib: info:
> cib_perform_op: Diff: --- 0.20.101 2
> Jul 25 07:43:15 [1638] DVTVM0802.mse.am.mot.com cib: info:
> cib_perform_op: Diff: +++ 0.20.102 (null)
> Jul 25 07:43:15 [1638] DVTVM0802.mse.am.mot.com cib: info:
> cib_perform_op: + /cib: @num_updates=102
> Jul 25 07:43:15 [1638] DVTVM0802.mse.am.mot.com cib: info:
> cib_perform_op: + /cib/status/node_state[@id='2']/transient_a
> ttributes[@id='2']/instance_attributes[@id='status-
> 2']/nvpair[@id='status-2-pingd']: @value=2000
> Jul 25 07:43:15 [1638] DVTVM0802.mse.am.mot.com cib: info:
> cib_process_request: Completed cib_modify operation for
> section status: OK (rc=0, origin=dvtvm0803/attrd/10,
> version=0.20.102)
> Jul 25 07:43:20 [1638] DVTVM0802.mse.am.mot.com cib: info:
> cib_process_ping: Reporting our current digest to dvtvm0803:
> 6aaa74aa220cce54790a731cd758f8e3 for 0.20.102 (0x560c399ebe20 0)
>
>
>
>
>
>
> Node that was running as standby:
>
>
>
>
> Jul 25 07:42:46 [1624] DVTVM0803.mse.am.mot.com crmd: info:
> pcmk_cpg_membership: Node 1 left group crmd (peer=dvtvm0802,
> counter=3.0)
> Jul 25 07:42:46 [1624] DVTVM0803.mse.am.mot.com crmd: info:
> crm_update_peer_proc: pcmk_cpg_membership: Node dvtvm0802[1] -
> corosync-cpg is now offline
> Jul 25 07:42:46 [1624] DVTVM0803.mse.am.mot.com crmd: info:
> peer_update_callback: Client dvtvm0802/peer now has status
> [offline] (DC=true, changed=4000000)
> Jul 25 07:42:46 [1624] DVTVM0803.mse.am.mot.com crmd: info:
> peer_update_callback: Peer dvtvm0802 left us
> [994] DVTVM0803.mse.am.mot.com corosyncnotice [QUORUM] Members[1]: 2
> Jul 25 07:42:46 [1624] DVTVM0803.mse.am.mot.com crmd: info:
> erase_status_tag: Deleting transient_attributes status entries
> for dvtvm0802 |
> xpath=//node_state[@uname='dvtvm0802']/transient_attributes
> [994] DVTVM0803.mse.am.mot.com corosyncnotice [MAIN ] Completed
> service synchronization, ready to provide service.
> Jul 25 07:42:46 [1624] DVTVM0803.mse.am.mot.com crmd: warning:
> match_down_event: No reason to expect node 1 to be down
> Jul 25 07:42:46 [1624] DVTVM0803.mse.am.mot.com crmd: notice:
> peer_update_callback: Stonith/shutdown of dvtvm0802 not
> matched
> Jul 25 07:42:46 [1624] DVTVM0803.mse.am.mot.com crmd: info:
> crm_update_peer_join: peer_update_callback: Node dvtvm0802[1]
> - join-4 phase confirmed -> none
> Jul 25 07:42:46 [1624] DVTVM0803.mse.am.mot.com crmd: info:
> abort_transition_graph: Transition aborted: Node failure |
> source=peer_update_callback:258 complete=true
> Jul 25 07:42:46 [1624] DVTVM0803.mse.am.mot.com crmd: info:
> pcmk_cpg_membership: Node 2 still member of group crmd
> (peer=dvtvm0803, counter=3.0)
> Jul 25 07:42:46 [1624] DVTVM0803.mse.am.mot.com crmd: notice:
> do_state_transition: State transition S_IDLE ->
> S_POLICY_ENGINE | input=I_PE_CALC cause=C_FSA_INTERNAL
> origin=abort_transition_graph
> Jul 25 07:42:46 [1624] DVTVM0803.mse.am.mot.com crmd: info:
> pcmk_quorum_notification: Quorum retained | membership=52
> members=1
> Jul 25 07:42:46 [1624] DVTVM0803.mse.am.mot.com crmd: notice:
> crm_update_peer_state_iter: Node dvtvm0802 state is now lost |
> nodeid=1 previous=member source=crm_reap_unseen_nodes
> Jul 25 07:42:46 [1624] DVTVM0803.mse.am.mot.com crmd: info:
> peer_update_callback: Cluster node dvtvm0802 is now lost (was
> member)
> Jul 25 07:42:46 [1624] DVTVM0803.mse.am.mot.com crmd: warning:
> match_down_event: No reason to expect node 1 to be down
> Jul 25 07:42:46 [1624] DVTVM0803.mse.am.mot.com crmd: notice:
> peer_update_callback: Stonith/shutdown of dvtvm0802 not
> matched
> Jul 25 07:42:46 [1624] DVTVM0803.mse.am.mot.com crmd: info:
> abort_transition_graph: Transition aborted: Node failure |
> source=peer_update_callback:258 complete=true
> Jul 25 07:42:46 [1622] DVTVM0803.mse.am.mot.com attrd: info:
> pcmk_cpg_membership: Node 1 left group attrd (peer=dvtvm0802,
> counter=3.0)
> Jul 25 07:42:46 [1622] DVTVM0803.mse.am.mot.com attrd: info:
> crm_update_peer_proc: pcmk_cpg_membership: Node dvtvm0802[1] -
> corosync-cpg is now offline
> Jul 25 07:42:46 [1622] DVTVM0803.mse.am.mot.com attrd: notice:
> crm_update_peer_state_iter: Node dvtvm0802 state is now lost |
> nodeid=1 previous=member source=crm_update_peer_proc
> Jul 25 07:42:46 [1556] DVTVM0803.mse.am.mot.com pacemakerd: info:
> pcmk_quorum_notification: Quorum retained | membership=52
> members=1
> Jul 25 07:42:46 [1622] DVTVM0803.mse.am.mot.com attrd: notice:
> attrd_peer_remove: Removing all dvtvm0802 attributes for peer
> loss
> Jul 25 07:42:46 [1622] DVTVM0803.mse.am.mot.com attrd: info:
> crm_reap_dead_member: Removing node with name dvtvm0802 and id
> 1 from membership cache
> Jul 25 07:42:46 [1556] DVTVM0803.mse.am.mot.com pacemakerd: notice:
> crm_update_peer_state_iter: Node dvtvm0802 state is now lost |
> nodeid=1 previous=member source=crm_reap_unseen_nodes
> Jul 25 07:42:46 [1622] DVTVM0803.mse.am.mot.com attrd: notice:
> reap_crm_member: Purged 1 peer with id=1 and/or
> uname=dvtvm0802 from the membership cache
> Jul 25 07:42:46 [1556] DVTVM0803.mse.am.mot.com pacemakerd: info:
> pcmk_cpg_membership: Node 1 left group pacemakerd
> (peer=dvtvm0802, counter=3.0)
> Jul 25 07:42:46 [1622] DVTVM0803.mse.am.mot.com attrd: info:
> pcmk_cpg_membership: Node 2 still member of group attrd
> (peer=dvtvm0803, counter=3.0)
> Jul 25 07:42:46 [1556] DVTVM0803.mse.am.mot.com pacemakerd: info:
> crm_update_peer_proc: pcmk_cpg_membership: Node dvtvm0802[1] -
> corosync-cpg is now offline
> Jul 25 07:42:46 [1556] DVTVM0803.mse.am.mot.com pacemakerd: info:
> pcmk_cpg_membership: Node 2 still member of group pacemakerd
> (peer=dvtvm0803, counter=3.0)
> Jul 25 07:42:46 [1618] DVTVM0803.mse.am.mot.com cib: info:
> pcmk_cpg_membership: Node 1 left group cib (peer=dvtvm0802,
> counter=3.0)
> Jul 25 07:42:46 [1618] DVTVM0803.mse.am.mot.com cib: info:
> crm_update_peer_proc: pcmk_cpg_membership: Node dvtvm0802[1] -
> corosync-cpg is now offline
> Jul 25 07:42:46 [1618] DVTVM0803.mse.am.mot.com cib: notice:
> crm_update_peer_state_iter: Node dvtvm0802 state is now lost |
> nodeid=1 previous=member source=crm_update_peer_proc
> Jul 25 07:42:46 [1618] DVTVM0803.mse.am.mot.com cib: info:
> crm_reap_dead_member: Removing node with name dvtvm0802 and id
> 1 from membership cache
> Jul 25 07:42:46 [1618] DVTVM0803.mse.am.mot.com cib: notice:
> reap_crm_member: Purged 1 peer with id=1 and/or
> uname=dvtvm0802 from the membership cache
> Jul 25 07:42:46 [1618] DVTVM0803.mse.am.mot.com cib: info:
> pcmk_cpg_membership: Node 2 still member of group cib
> (peer=dvtvm0803, counter=3.0)
> Jul 25 07:42:46 [1556] DVTVM0803.mse.am.mot.com pacemakerd: info:
> mcp_cpg_deliver: Ignoring process list sent by peer for local
> node
> Jul 25 07:42:46 [1618] DVTVM0803.mse.am.mot.com cib: info:
> cib_process_request: Forwarding cib_delete operation for
> section //node_state[@uname='dvtvm0802']/transient_attributes to all
> (origin=local/crmd/106)
> Jul 25 07:42:46 [1618] DVTVM0803.mse.am.mot.com cib: info:
> cib_process_request: Forwarding cib_modify operation for
> section status to all (origin=local/crmd/107)
> Jul 25 07:42:46 [1619] DVTVM0803.mse.am.mot.com stonith-ng: info:
> pcmk_cpg_membership: Node 1 left group stonith-ng
> (peer=dvtvm0802, counter=3.0)
> Jul 25 07:42:46 [1619] DVTVM0803.mse.am.mot.com stonith-ng: info:
> crm_update_peer_proc: pcmk_cpg_membership: Node dvtvm0802[1] -
> corosync-cpg is now offline
> Jul 25 07:42:46 [1619] DVTVM0803.mse.am.mot.com stonith-ng: notice:
> crm_update_peer_state_iter: Node dvtvm0802 state is now lost |
> nodeid=1 previous=member source=crm_update_peer_proc
> Jul 25 07:42:46 [1618] DVTVM0803.mse.am.mot.com cib: info:
> cib_process_request: Forwarding cib_modify operation for
> section status to all (origin=local/crmd/109)
> Jul 25 07:42:46 [1619] DVTVM0803.mse.am.mot.com stonith-ng: info:
> crm_reap_dead_member: Removing node with name dvtvm0802 and id
> 1 from membership cache
> Jul 25 07:42:46 [1619] DVTVM0803.mse.am.mot.com stonith-ng: notice:
> reap_crm_member: Purged 1 peer with id=1 and/or
> uname=dvtvm0802 from the membership cache
> Jul 25 07:42:46 [1619] DVTVM0803.mse.am.mot.com stonith-ng: info:
> pcmk_cpg_membership: Node 2 still member of group stonith-ng
> (peer=dvtvm0803, counter=3.0)
> Jul 25 07:42:46 [1618] DVTVM0803.mse.am.mot.com cib: info:
> cib_perform_op: Diff: --- 0.20.63 2
> Jul 25 07:42:46 [1618] DVTVM0803.mse.am.mot.com cib: info:
> cib_perform_op: Diff: +++ 0.20.64
> 4514de4adeee3556fca57c6e9787b266
> Jul 25 07:42:46 [1618] DVTVM0803.mse.am.mot.com cib: info:
> cib_perform_op: --
> /cib/status/node_state[@id='1']/transient_attributes[@id='1']
> Jul 25 07:42:46 [1618] DVTVM0803.mse.am.mot.com cib: info:
> cib_perform_op: + /cib: @num_updates=64
> Jul 25 07:42:46 [1618] DVTVM0803.mse.am.mot.com cib: info:
> cib_process_request: Completed cib_delete operation for
> section //node_state[@uname='dvtvm0802']/transient_attributes: OK
> (rc=0, origin=dvtvm0803/crmd/106, version=0.20.64)
> Jul 25 07:42:46 [1618] DVTVM0803.mse.am.mot.com cib: info:
> cib_perform_op: Diff: --- 0.20.64 2
> Jul 25 07:42:46 [1618] DVTVM0803.mse.am.mot.com cib: info:
> cib_perform_op: Diff: +++ 0.20.65 (null)
> Jul 25 07:42:46 [1618] DVTVM0803.mse.am.mot.com cib: info:
> cib_perform_op: + /cib: @num_updates=65
> Jul 25 07:42:46 [1618] DVTVM0803.mse.am.mot.com cib: info:
> cib_perform_op: + /cib/status/node_state[@id='1']: @crmd=off
> line, @crm-debug-origin=peer_update_callback
> Jul 25 07:42:46 [1618] DVTVM0803.mse.am.mot.com cib: info:
> cib_process_request: Completed cib_modify operation for
> section status: OK (rc=0, origin=dvtvm0803/crmd/107, version=0.20.65)
> Jul 25 07:42:46 [1618] DVTVM0803.mse.am.mot.com cib: info:
> cib_process_request: Completed cib_modify operation for
> section status: OK (rc=0, origin=dvtvm0803/crmd/109, version=0.20.65)
> Jul 25 07:42:46 [1618] DVTVM0803.mse.am.mot.com cib: info:
> cib_process_request: Forwarding cib_modify operation for
> section nodes to all (origin=local/crmd/112)
> Jul 25 07:42:46 [1618] DVTVM0803.mse.am.mot.com cib: info:
> cib_process_request: Forwarding cib_modify operation for
> section status to all (origin=local/crmd/113)
> Jul 25 07:42:46 [1618] DVTVM0803.mse.am.mot.com cib: info:
> cib_process_request: Completed cib_modify operation for
> section nodes: OK (rc=0, origin=dvtvm0803/crmd/112, version=0.20.65)
> Jul 25 07:42:46 [1618] DVTVM0803.mse.am.mot.com cib: info:
> cib_perform_op: Diff: --- 0.20.65 2
> Jul 25 07:42:46 [1618] DVTVM0803.mse.am.mot.com cib: info:
> cib_perform_op: Diff: +++ 0.20.66 (null)
> Jul 25 07:42:46 [1618] DVTVM0803.mse.am.mot.com cib: info:
> cib_perform_op: + /cib: @num_updates=66
> Jul 25 07:42:46 [1618] DVTVM0803.mse.am.mot.com cib: info:
> cib_perform_op: + /cib/status/node_state[@id='1']: @in_ccm=f
> alse, @crm-debug-origin=post_cache_update
> Jul 25 07:42:46 [1618] DVTVM0803.mse.am.mot.com cib: info:
> cib_perform_op: + /cib/status/node_state[@id='2']: @crm-
> debug-origin=post_cache_update
> Jul 25 07:42:46 [1618] DVTVM0803.mse.am.mot.com cib: info:
> cib_process_request: Completed cib_modify operation for
> section status: OK (rc=0, origin=dvtvm0803/crmd/113, version=0.20.66)
> Jul 25 07:42:46 [1624] DVTVM0803.mse.am.mot.com crmd: info:
> abort_transition_graph: Transition aborted by deletion of
> transient_attributes[@id='1']: Transient attribute change |
> cib=0.20.64 source=abort_unless_down:357
> path=/cib/status/node_state[@id='1']/transient_attributes[@id='1']
> complete=true
> Jul 25 07:42:47 [1623] DVTVM0803.mse.am.mot.com pengine: notice:
> unpack_config: On loss of CCM Quorum: Ignore
> Jul 25 07:42:47 [1623] DVTVM0803.mse.am.mot.com pengine: info:
> determine_online_status: Node dvtvm0803 is online
> Jul 25 07:42:47 [1623] DVTVM0803.mse.am.mot.com pengine: info:
> unpack_node_loop: Node 2 is already processed
> Jul 25 07:42:47 [1623] DVTVM0803.mse.am.mot.com pengine: info:
> unpack_node_loop: Node 2 is already processed
> Jul 25 07:42:47 [1623] DVTVM0803.mse.am.mot.com pengine: info:
> common_print: ClusterIP (ocf::heartbeat:IPaddr2):
> Stopped
> Jul 25 07:42:47 [1623] DVTVM0803.mse.am.mot.com pengine: info:
> clone_print: Clone Set: Connected-clone [Connected]
> Jul 25 07:42:47 [1623] DVTVM0803.mse.am.mot.com pengine: info:
> short_print: Started: [ dvtvm0803 ]
> Jul 25 07:42:47 [1623] DVTVM0803.mse.am.mot.com pengine: info:
> short_print: Stopped: [ dvtvm0802 ]
> Jul 25 07:42:47 [1623] DVTVM0803.mse.am.mot.com pengine: info:
> common_print: application (ocf::vendor:application):
> Stopped
> Jul 25 07:42:47 [1623] DVTVM0803.mse.am.mot.com pengine: info:
> native_color: Resource Connected:1 cannot run anywhere
> Jul 25 07:42:47 [1623] DVTVM0803.mse.am.mot.com pengine: info:
> RecurringOp: Start recurring monitor (1s) for ClusterIP on
> dvtvm0803
> Jul 25 07:42:47 [1623] DVTVM0803.mse.am.mot.com pengine: info:
> RecurringOp: Start recurring monitor (1s) for application on
> dvtvm0803
> Jul 25 07:42:47 [1623] DVTVM0803.mse.am.mot.com pengine: notice:
> LogAction: * Start ClusterIP ( dvtvm0803 )
> Jul 25 07:42:47 [1623] DVTVM0803.mse.am.mot.com pengine: info:
> LogActions: Leave Connected:0 (Started dvtvm0803)
> Jul 25 07:42:47 [1623] DVTVM0803.mse.am.mot.com pengine: info:
> LogActions: Leave Connected:1 (Stopped)
> Jul 25 07:42:47 [1623] DVTVM0803.mse.am.mot.com pengine: notice:
> LogAction: * Start application ( dvtvm0803 )
> Jul 25 07:42:47 [1623] DVTVM0803.mse.am.mot.com pengine: notice:
> process_pe_message: Calculated transition 6, saving inputs in
> /var/lib/pacemaker/pengine/pe-input-16.bz2
Since *03 saw itself as alive and *02 as dead, it elected itself DC and
decided to start ClusterIP and application on itself. This is what a
split brain is.
> Jul 25 07:42:47 [1624] DVTVM0803.mse.am.mot.com crmd: info:
> do_state_transition: State transition S_POLICY_ENGINE ->
> S_TRANSITION_ENGINE | input=I_PE_SUCCESS cause=C_IPC_MESSAGE
> origin=handle_response
> Jul 25 07:42:47 [1624] DVTVM0803.mse.am.mot.com crmd: info:
> do_te_invoke: Processing graph 6 (ref=pe_calc-dc-1532518967-
> 53) derived from /var/lib/pacemaker/pengine/pe-input-16.bz2
> Jul 25 07:42:47 [1624] DVTVM0803.mse.am.mot.com crmd: notice:
> te_rsc_command: Initiating start operation ClusterIP_start_0
> locally on dvtvm0803 | action 3
> Jul 25 07:42:47 [1624] DVTVM0803.mse.am.mot.com crmd: info:
> do_lrm_rsc_op: Performing key=3:6:0:1cec18ac-2aae-4c5c-8513-
> d6851bc10191 op=ClusterIP_start_0
> Jul 25 07:42:47 [1618] DVTVM0803.mse.am.mot.com cib: info:
> cib_process_request: Forwarding cib_modify operation for
> section status to all (origin=local/crmd/116)
> Jul 25 07:42:47 [1618] DVTVM0803.mse.am.mot.com cib: info:
> cib_perform_op: Diff: --- 0.20.66 2
> Jul 25 07:42:47 [1618] DVTVM0803.mse.am.mot.com cib: info:
> cib_perform_op: Diff: +++ 0.20.67 (null)
> Jul 25 07:42:47 [1618] DVTVM0803.mse.am.mot.com cib: info:
> cib_perform_op: + /cib: @num_updates=67
> Jul 25 07:42:47 [1618] DVTVM0803.mse.am.mot.com cib: info:
> cib_perform_op: + /cib/status/node_state[@id='2']: @crm-
> debug-origin=do_update_resource
> Jul 25 07:42:47 [1620] DVTVM0803.mse.am.mot.com lrmd: info:
> log_execute: executing - rsc:ClusterIP action:start call_id:25
> Jul 25 07:42:47 [1618] DVTVM0803.mse.am.mot.com cib: info:
> cib_perform_op: + /cib/status/node_state[@id='2']/lrm[@id='2'
> ]/lrm_resources/lrm_resource[@id='ClusterIP']/lrm_rsc_op[@id='Cluster
> IP_last_0']: @operation_key=ClusterIP_start_0, @operation=start,
> @crm-debug-origin=do_update_resource, @transition-key=3:6:0:1cec18ac-
> 2aae-4c5c-8513-d6851bc10191, @transition-magic=-1:193;3:6:0:1cec18ac-
> 2aae-4c5c-8513-d6851bc10191, @call-id=-1, @rc-code=193, @op-status=-
> 1, @last-run=1532518967, @last-rc-chan
> Jul 25 07:42:47 [1618] DVTVM0803.mse.am.mot.com cib: info:
> cib_process_request: Completed cib_modify operation for
> section status: OK (rc=0, origin=dvtvm0803/crmd/116, version=0.20.67)
> Jul 25 07:42:47 IPaddr2(ClusterIP)[12697]: INFO: Adding inet
> address 10.144.102.230/24 with broadcast address 10.144.102.255 to
> device eth0
> Jul 25 07:42:47 IPaddr2(ClusterIP)[12697]: INFO: Bringing device
> eth0 up
> Jul 25 07:42:47 IPaddr2(ClusterIP)[12697]: INFO:
> /usr/libexec/heartbeat/send_arp -i 200 -c 5 -p /var/run/resource-
> agents/send_arp-10.144.102.230 -I eth0 -m auto 10.144.102.230
> Jul 25 07:42:49 ping(Connected)[12678]: WARNING: 10.144.102.5 is
> inactive: PING 10.144.102.5 (10.144.102.5) 56(84) bytes of data.
>
> --- 10.144.102.5 ping statistics ---
> 2 packets transmitted, 0 received, 100% packet loss, time 999ms
> Jul 25 07:42:51 [1620] DVTVM0803.mse.am.mot.com lrmd: info:
> log_finished: finished - rsc:ClusterIP action:start call_id:25
> pid:12697 exit-code:0 exec-time:4106ms queue-time:0ms
> Jul 25 07:42:51 [1624] DVTVM0803.mse.am.mot.com crmd: notice:
> process_lrm_event: Result of start operation for ClusterIP on
> dvtvm0803: 0 (ok) | call=25 key=ClusterIP_start_0 confirmed=true cib-
> update=117
> Jul 25 07:42:51 [1618] DVTVM0803.mse.am.mot.com cib: info:
> cib_process_request: Forwarding cib_modify operation for
> section status to all (origin=local/crmd/117)
> Jul 25 07:42:51 [1618] DVTVM0803.mse.am.mot.com cib: info:
> cib_perform_op: Diff: --- 0.20.67 2
> Jul 25 07:42:51 [1618] DVTVM0803.mse.am.mot.com cib: info:
> cib_perform_op: Diff: +++ 0.20.68 (null)
> Jul 25 07:42:51 [1618] DVTVM0803.mse.am.mot.com cib: info:
> cib_perform_op: + /cib: @num_updates=68
> Jul 25 07:42:51 [1618] DVTVM0803.mse.am.mot.com cib: info:
> cib_perform_op: + /cib/status/node_state[@id='2']/lrm[@id='2'
> ]/lrm_resources/lrm_resource[@id='ClusterIP']/lrm_rsc_op[@id='Cluster
> IP_last_0']: @transition-magic=0:0;3:6:0:1cec18ac-2aae-4c5c-8513-
> d6851bc10191, @call-id=25, @rc-code=0, @op-status=0, @exec-time=4106
> Jul 25 07:42:51 [1618] DVTVM0803.mse.am.mot.com cib: info:
> cib_process_request: Completed cib_modify operation for
> section status: OK (rc=0, origin=dvtvm0803/crmd/117, version=0.20.68)
> Jul 25 07:42:51 [1624] DVTVM0803.mse.am.mot.com crmd: info:
> match_graph_event: Action ClusterIP_start_0 (3) confirmed on
> dvtvm0803 (rc=0)
> Jul 25 07:42:51 [1624] DVTVM0803.mse.am.mot.com crmd: notice:
> te_rsc_command: Initiating monitor operation
> ClusterIP_monitor_1000 locally on dvtvm0803 | action 4
> Jul 25 07:42:51 [1624] DVTVM0803.mse.am.mot.com crmd: info:
> do_lrm_rsc_op: Performing key=4:6:0:1cec18ac-2aae-4c5c-8513-
> d6851bc10191 op=ClusterIP_monitor_1000
> Jul 25 07:42:51 [1618] DVTVM0803.mse.am.mot.com cib: info:
> cib_process_request: Forwarding cib_modify operation for
> section status to all (origin=local/crmd/118)
> Jul 25 07:42:51 [1624] DVTVM0803.mse.am.mot.com crmd: notice:
> te_rsc_command: Initiating start operation edgemanager_start_0
> locally on dvtvm0803 | action 11
> Jul 25 07:42:51 [1624] DVTVM0803.mse.am.mot.com crmd: info:
> do_lrm_rsc_op: Performing key=11:6:0:1cec18ac-2aae-4c5c-8513-
> d6851bc10191 op=edgemanager_start_0
> Jul 25 07:42:51 [1618] DVTVM0803.mse.am.mot.com cib: info:
> cib_perform_op: Diff: --- 0.20.68 2
> Jul 25 07:42:51 [1618] DVTVM0803.mse.am.mot.com cib: info:
> cib_perform_op: Diff: +++ 0.20.69 (null)
> Jul 25 07:42:51 [1618] DVTVM0803.mse.am.mot.com cib: info:
> cib_perform_op: + /cib: @num_updates=69
> Jul 25 07:42:51 [1618] DVTVM0803.mse.am.mot.com cib: info:
> cib_perform_op: ++
> /cib/status/node_state[@id='2']/lrm[@id='2']/lrm_resources/lrm_resour
> ce[@id='ClusterIP']: <lrm_rsc_op id="ClusterIP_monitor_1000"
> operation_key="ClusterIP_monitor_1000" operation="monitor" crm-debug-
> origin="do_update_resource" crm_feature_set="3.0.14" transition-
> key="4:6:0:1cec18ac-2aae-4c5c-8513-d6851bc10191" transition-magic="-
> 1:193;4:6:0:1cec18ac-2aae-4c5c-8513-d6851bc10191" exit-reason=""
> on_node="dvtvm0803" call-
> Jul 25 07:42:51 [1618] DVTVM0803.mse.am.mot.com cib: info:
> cib_process_request: Completed cib_modify operation for
> section status: OK (rc=0, origin=dvtvm0803/crmd/118, version=0.20.69)
> Jul 25 07:42:51 [1624] DVTVM0803.mse.am.mot.com crmd: info:
> action_synced_wait: Managed edgemanager_meta-data_0 process
> 12828 exited with rc=4
> Jul 25 07:42:51 [1624] DVTVM0803.mse.am.mot.com crmd: error:
> lrmd_api_get_metadata: Failed to receive meta-data for
> ocf:vendor:application
> Jul 25 07:42:51 [1624] DVTVM0803.mse.am.mot.com crmd: warning:
> build_operation_update: Failed to get metadata for application
> (ocf:vendor:application)
> Jul 25 07:42:51 [1618] DVTVM0803.mse.am.mot.com cib: info:
> cib_process_request: Forwarding cib_modify operation for
> section status to all (origin=local/crmd/119)
> Jul 25 07:42:51 [1620] DVTVM0803.mse.am.mot.com lrmd: info:
> log_execute: executing - rsc:application action:start
> call_id:27
> Jul 25 07:42:51 [1618] DVTVM0803.mse.am.mot.com cib: info:
> cib_perform_op: Diff: --- 0.20.69 2
> Jul 25 07:42:51 [1618] DVTVM0803.mse.am.mot.com cib: info:
> cib_perform_op: Diff: +++ 0.20.70 (null)
> Jul 25 07:42:51 [1618] DVTVM0803.mse.am.mot.com cib: info:
> cib_perform_op: + /cib: @num_updates=70
> Jul 25 07:42:51 [1618] DVTVM0803.mse.am.mot.com cib: info:
> cib_perform_op: + /cib/status/node_state[@id='2']/lrm[@id='2'
> ]/lrm_resources/lrm_resource[@id='edgemanager']/lrm_rsc_op[@id='edgem
> anager_last_0']: @operation_key=edgemanager_start_0,
> @operation=start, @crm-debug-origin=do_update_resource, @transition-
> key=11:6:0:1cec18ac-2aae-4c5c-8513-d6851bc10191, @transition-magic=-
> 1:193;11:6:0:1cec18ac-2aae-4c5c-8513-d6851bc10191, @call-id=-1, @rc-
> code=193, @op-status=-1, @last-run=1532518971, @last
> Jul 25 07:42:51 [1618] DVTVM0803.mse.am.mot.com cib: info:
> cib_process_request: Completed cib_modify operation for
> section status: OK (rc=0, origin=dvtvm0803/crmd/119, version=0.20.70)
> Jul 25 07:42:51 application(application)[12829]: INFO: Starting
> APP - setting to Primary
> Jul 25 07:42:51 [1620] DVTVM0803.mse.am.mot.com lrmd: info:
> log_finished: finished - rsc:application action:start
> call_id:27 pid:12829 exit-code:0 exec-time:33ms queue-time:0ms
> Jul 25 07:42:51 [1624] DVTVM0803.mse.am.mot.com crmd: info:
> action_synced_wait: Managed edgemanager_meta-data_0 process
> 12865 exited with rc=4
> Jul 25 07:42:51 [1624] DVTVM0803.mse.am.mot.com crmd: error:
> lrmd_api_get_metadata: Failed to receive meta-data for
> ocf:vendor:application
> Jul 25 07:42:51 [1624] DVTVM0803.mse.am.mot.com crmd: warning:
> build_operation_update: Failed to get metadata for application
> (ocf:vendor:application)
> Jul 25 07:42:51 [1624] DVTVM0803.mse.am.mot.com crmd: notice:
> process_lrm_event: Result of start operation for application
> on dvtvm0803: 0 (ok) | call=27 key=edgemanager_start_0 confirmed=true
> cib-update=120
> Jul 25 07:42:51 [1618] DVTVM0803.mse.am.mot.com cib: info:
> cib_process_request: Forwarding cib_modify operation for
> section status to all (origin=local/crmd/120)
> Jul 25 07:42:51 [1618] DVTVM0803.mse.am.mot.com cib: info:
> cib_perform_op: Diff: --- 0.20.70 2
> Jul 25 07:42:51 [1618] DVTVM0803.mse.am.mot.com cib: info:
> cib_perform_op: Diff: +++ 0.20.71 (null)
> Jul 25 07:42:51 [1618] DVTVM0803.mse.am.mot.com cib: info:
> cib_perform_op: + /cib: @num_updates=71
> Jul 25 07:42:51 [1618] DVTVM0803.mse.am.mot.com cib: info:
> cib_perform_op: + /cib/status/node_state[@id='2']/lrm[@id='2'
> ]/lrm_resources/lrm_resource[@id='edgemanager']/lrm_rsc_op[@id='edgem
> anager_last_0']: @transition-magic=0:0;11:6:0:1cec18ac-2aae-4c5c-
> 8513-d6851bc10191, @call-id=27, @rc-code=0, @op-status=0, @exec-
> time=33
> Jul 25 07:42:51 [1618] DVTVM0803.mse.am.mot.com cib: info:
> cib_process_request: Completed cib_modify operation for
> section status: OK (rc=0, origin=dvtvm0803/crmd/120, version=0.20.71)
> Jul 25 07:42:51 [1624] DVTVM0803.mse.am.mot.com crmd: info:
> match_graph_event: Action edgemanager_start_0 (11) confirmed
> on dvtvm0803 (rc=0)
> Jul 25 07:42:51 [1624] DVTVM0803.mse.am.mot.com crmd: notice:
> te_rsc_command: Initiating monitor operation
> edgemanager_monitor_1000 locally on dvtvm0803 | action 12
> Jul 25 07:42:51 [1624] DVTVM0803.mse.am.mot.com crmd: info:
> do_lrm_rsc_op: Performing key=12:6:0:1cec18ac-2aae-4c5c-8513-
> d6851bc10191 op=edgemanager_monitor_1000
> Jul 25 07:42:51 [1624] DVTVM0803.mse.am.mot.com crmd: info:
> action_synced_wait: Managed edgemanager_meta-data_0 process
> 12869 exited with rc=4
> Jul 25 07:42:51 [1624] DVTVM0803.mse.am.mot.com crmd: error:
> lrmd_api_get_metadata: Failed to receive meta-data for
> ocf:vendor:application
> Jul 25 07:42:51 [1624] DVTVM0803.mse.am.mot.com crmd: warning:
> build_operation_update: Failed to get metadata for application
> (ocf:vendor:application)
> Jul 25 07:42:51 [1618] DVTVM0803.mse.am.mot.com cib: info:
> cib_process_request: Forwarding cib_modify operation for
> section status to all (origin=local/crmd/121)
> Jul 25 07:42:51 [1618] DVTVM0803.mse.am.mot.com cib: info:
> cib_perform_op: Diff: --- 0.20.71 2
> Jul 25 07:42:51 [1618] DVTVM0803.mse.am.mot.com cib: info:
> cib_perform_op: Diff: +++ 0.20.72 (null)
> Jul 25 07:42:51 [1618] DVTVM0803.mse.am.mot.com cib: info:
> cib_perform_op: + /cib: @num_updates=72
> Jul 25 07:42:51 [1618] DVTVM0803.mse.am.mot.com cib: info:
> cib_perform_op: ++
> /cib/status/node_state[@id='2']/lrm[@id='2']/lrm_resources/lrm_resour
> ce[@id='edgemanager']: <lrm_rsc_op id="edgemanager_monitor_1000"
> operation_key="edgemanager_monitor_1000" operation="monitor" crm-
> debug-origin="do_update_resource" crm_feature_set="3.0.14"
> transition-key="12:6:0:1cec18ac-2aae-4c5c-8513-d6851bc10191"
> transition-magic="-1:193;12:6:0:1cec18ac-2aae-4c5c-8513-d6851bc10191"
> exit-reason="" on_node="dvtvm080
> Jul 25 07:42:51 [1618] DVTVM0803.mse.am.mot.com cib: info:
> cib_process_request: Completed cib_modify operation for
> section status: OK (rc=0, origin=dvtvm0803/crmd/121, version=0.20.72)
> Jul 25 07:42:51 [1624] DVTVM0803.mse.am.mot.com crmd: info:
> process_lrm_event: Result of monitor operation for ClusterIP
> on dvtvm0803: 0 (ok) | call=26 key=ClusterIP_monitor_1000
> confirmed=false cib-update=122
> Jul 25 07:42:51 [1618] DVTVM0803.mse.am.mot.com cib: info:
> cib_process_request: Forwarding cib_modify operation for
> section status to all (origin=local/crmd/122)
> Jul 25 07:42:51 [1618] DVTVM0803.mse.am.mot.com cib: info:
> cib_perform_op: Diff: --- 0.20.72 2
> Jul 25 07:42:51 [1618] DVTVM0803.mse.am.mot.com cib: info:
> cib_perform_op: Diff: +++ 0.20.73 (null)
> Jul 25 07:42:51 [1618] DVTVM0803.mse.am.mot.com cib: info:
> cib_perform_op: + /cib: @num_updates=73
> Jul 25 07:42:51 [1618] DVTVM0803.mse.am.mot.com cib: info:
> cib_perform_op: + /cib/status/node_state[@id='2']/lrm[@id='2'
> ]/lrm_resources/lrm_resource[@id='ClusterIP']/lrm_rsc_op[@id='Cluster
> IP_monitor_1000']: @transition-magic=0:0;4:6:0:1cec18ac-2aae-4c5c-
> 8513-d6851bc10191, @call-id=26, @rc-code=0, @op-status=0, @exec-
> time=56
> Jul 25 07:42:51 [1618] DVTVM0803.mse.am.mot.com cib: info:
> cib_process_request: Completed cib_modify operation for
> section status: OK (rc=0, origin=dvtvm0803/crmd/122, version=0.20.73)
> Jul 25 07:42:51 [1624] DVTVM0803.mse.am.mot.com crmd: info:
> match_graph_event: Action ClusterIP_monitor_1000 (4) confirmed
> on dvtvm0803 (rc=0)
> Jul 25 07:42:51 [1624] DVTVM0803.mse.am.mot.com crmd: info:
> action_synced_wait: Managed edgemanager_meta-data_0 process
> 12896 exited with rc=4
> Jul 25 07:42:51 [1624] DVTVM0803.mse.am.mot.com crmd: error:
> lrmd_api_get_metadata: Failed to receive meta-data for
> ocf:vendor:application
> Jul 25 07:42:51 [1624] DVTVM0803.mse.am.mot.com crmd: warning:
> build_operation_update: Failed to get metadata for application
> (ocf:vendor:application)
> Jul 25 07:42:51 [1624] DVTVM0803.mse.am.mot.com crmd: info:
> process_lrm_event: Result of monitor operation for application
> on dvtvm0803: 0 (ok) | call=28 key=edgemanager_monitor_1000
> confirmed=false cib-update=123
> Jul 25 07:42:51 [1618] DVTVM0803.mse.am.mot.com cib: info:
> cib_process_request: Forwarding cib_modify operation for
> section status to all (origin=local/crmd/123)
> Jul 25 07:42:51 [1618] DVTVM0803.mse.am.mot.com cib: info:
> cib_perform_op: Diff: --- 0.20.73 2
> Jul 25 07:42:51 [1618] DVTVM0803.mse.am.mot.com cib: info:
> cib_perform_op: Diff: +++ 0.20.74 (null)
> Jul 25 07:42:51 [1618] DVTVM0803.mse.am.mot.com cib: info:
> cib_perform_op: + /cib: @num_updates=74
> Jul 25 07:42:51 [1618] DVTVM0803.mse.am.mot.com cib: info:
> cib_perform_op: + /cib/status/node_state[@id='2']/lrm[@id='2'
> ]/lrm_resources/lrm_resource[@id='edgemanager']/lrm_rsc_op[@id='edgem
> anager_monitor_1000']: @transition-magic=0:0;12:6:0:1cec18ac-2aae-
> 4c5c-8513-d6851bc10191, @call-id=28, @rc-code=0, @op-status=0, @exec-
> time=16
> Jul 25 07:42:51 [1618] DVTVM0803.mse.am.mot.com cib: info:
> cib_process_request: Completed cib_modify operation for
> section status: OK (rc=0, origin=dvtvm0803/crmd/123, version=0.20.74)
> Jul 25 07:42:51 [1624] DVTVM0803.mse.am.mot.com crmd: info:
> match_graph_event: Action edgemanager_monitor_1000 (12)
> confirmed on dvtvm0803 (rc=0)
> Jul 25 07:42:51 [1624] DVTVM0803.mse.am.mot.com crmd: notice:
> run_graph: Transition 6 (Complete=4, Pending=0, Fired=0,
> Skipped=0, Incomplete=0, Source=/var/lib/pacemaker/pengine/pe-input-
> 16.bz2): Complete
> Jul 25 07:42:51 [1624] DVTVM0803.mse.am.mot.com crmd: info:
> do_log: Input I_TE_SUCCESS received in state
> S_TRANSITION_ENGINE from notify_crmd
> Jul 25 07:42:51 [1624] DVTVM0803.mse.am.mot.com crmd: notice:
> do_state_transition: State transition S_TRANSITION_ENGINE ->
> S_IDLE | input=I_TE_SUCCESS cause=C_FSA_INTERNAL origin=notify_crmd
> Jul 25 07:42:52 ping(Connected)[12678]: WARNING: 10.144.102.152
> is inactive: PING 10.144.102.152 (10.144.102.152) 56(84) bytes of
> data.
>
> --- 10.144.102.152 ping statistics ---
> 2 packets transmitted, 0 received, 100% packet loss, time 1000ms
> Jul 25 07:42:52 [1622] DVTVM0803.mse.am.mot.com attrd: info:
> attrd_peer_update: Setting pingd[dvtvm0803]: 2000 -> 0 from
> dvtvm0803
> Jul 25 07:42:53 [1622] DVTVM0803.mse.am.mot.com attrd: info:
> write_attribute: Sent update 8 with 1 changes for pingd,
> id=<n/a>, set=(null)
> Jul 25 07:42:53 [1618] DVTVM0803.mse.am.mot.com cib: info:
> cib_process_request: Forwarding cib_modify operation for
> section status to all (origin=local/attrd/8)
> Jul 25 07:42:53 [1618] DVTVM0803.mse.am.mot.com cib: info:
> cib_perform_op: Diff: --- 0.20.74 2
> Jul 25 07:42:53 [1618] DVTVM0803.mse.am.mot.com cib: info:
> cib_perform_op: Diff: +++ 0.20.75 (null)
> Jul 25 07:42:53 [1618] DVTVM0803.mse.am.mot.com cib: info:
> cib_perform_op: + /cib: @num_updates=75
> Jul 25 07:42:53 [1618] DVTVM0803.mse.am.mot.com cib: info:
> cib_perform_op: + /cib/status/node_state[@id='2']/transient_a
> ttributes[@id='2']/instance_attributes[@id='status-
> 2']/nvpair[@id='status-2-pingd']: @value=0
> Jul 25 07:42:53 [1618] DVTVM0803.mse.am.mot.com cib: info:
> cib_process_request: Completed cib_modify operation for
> section status: OK (rc=0, origin=dvtvm0803/attrd/8, version=0.20.75)
> Jul 25 07:42:53 [1624] DVTVM0803.mse.am.mot.com crmd: info:
> abort_transition_graph: Transition aborted by status-2-pingd
> doing modify pingd=0: Transient attribute change | cib=0.20.75
> source=abort_unless_down:343
> path=/cib/status/node_state[@id='2']/transient_attributes[@id='2']/in
> stance_attributes[@id='status-2']/nvpair[@id='status-2-pingd']
> complete=true
> Jul 25 07:42:53 [1624] DVTVM0803.mse.am.mot.com crmd: notice:
> do_state_transition: State transition S_IDLE ->
> S_POLICY_ENGINE | input=I_PE_CALC cause=C_FSA_INTERNAL
> origin=abort_transition_graph
> Jul 25 07:42:53 [1622] DVTVM0803.mse.am.mot.com attrd: info:
> attrd_cib_callback: Update 8 for pingd: OK (0)
> Jul 25 07:42:53 [1622] DVTVM0803.mse.am.mot.com attrd: info:
> attrd_cib_callback: Update 8 for pingd[dvtvm0803]=0: OK (0)
> Jul 25 07:42:53 [1623] DVTVM0803.mse.am.mot.com pengine: notice:
> unpack_config: On loss of CCM Quorum: Ignore
> Jul 25 07:42:53 [1623] DVTVM0803.mse.am.mot.com pengine: info:
> determine_online_status: Node dvtvm0803 is online
> Jul 25 07:42:53 [1623] DVTVM0803.mse.am.mot.com pengine: info:
> unpack_node_loop: Node 2 is already processed
> Jul 25 07:42:53 [1623] DVTVM0803.mse.am.mot.com pengine: info:
> unpack_node_loop: Node 2 is already processed
> Jul 25 07:42:53 [1623] DVTVM0803.mse.am.mot.com pengine: info:
> common_print: ClusterIP (ocf::heartbeat:IPaddr2):
> Started dvtvm0803
> Jul 25 07:42:53 [1623] DVTVM0803.mse.am.mot.com pengine: info:
> clone_print: Clone Set: Connected-clone [Connected]
> Jul 25 07:42:53 [1623] DVTVM0803.mse.am.mot.com pengine: info:
> short_print: Started: [ dvtvm0803 ]
> Jul 25 07:42:53 [1623] DVTVM0803.mse.am.mot.com pengine: info:
> short_print: Stopped: [ dvtvm0802 ]
> Jul 25 07:42:53 [1623] DVTVM0803.mse.am.mot.com pengine: info:
> common_print: application (ocf::vendor:application):
> Started dvtvm0803
> Jul 25 07:42:53 [1623] DVTVM0803.mse.am.mot.com pengine: info:
> rsc_merge_weights: application: Rolling back scores from
> ClusterIP
> Jul 25 07:42:53 [1623] DVTVM0803.mse.am.mot.com pengine: info:
> native_color: Resource ClusterIP cannot run anywhere
> Jul 25 07:42:53 [1623] DVTVM0803.mse.am.mot.com pengine: info:
> native_color: Resource Connected:1 cannot run anywhere
> Jul 25 07:42:53 [1623] DVTVM0803.mse.am.mot.com pengine: notice:
> LogAction: * Stop ClusterIP ( dvtvm0803 ) due
> to node availability
> Jul 25 07:42:53 [1623] DVTVM0803.mse.am.mot.com pengine: info:
> LogActions: Leave Connected:0 (Started dvtvm0803)
> Jul 25 07:42:53 [1623] DVTVM0803.mse.am.mot.com pengine: info:
> LogActions: Leave Connected:1 (Stopped)
> Jul 25 07:42:53 [1623] DVTVM0803.mse.am.mot.com pengine: notice:
> LogAction: * Stop application ( dvtvm0803 ) due
> to required ClusterIP start
> Jul 25 07:42:53 [1623] DVTVM0803.mse.am.mot.com pengine: notice:
> process_pe_message: Calculated transition 7, saving inputs in
> /var/lib/pacemaker/pengine/pe-input-17.bz2
> Jul 25 07:42:53 [1624] DVTVM0803.mse.am.mot.com crmd: info:
> do_state_transition: State transition S_POLICY_ENGINE ->
> S_TRANSITION_ENGINE | input=I_PE_SUCCESS cause=C_IPC_MESSAGE
> origin=handle_response
> Jul 25 07:42:53 [1624] DVTVM0803.mse.am.mot.com crmd: info:
> do_te_invoke: Processing graph 7 (ref=pe_calc-dc-1532518973-
> 58) derived from /var/lib/pacemaker/pengine/pe-input-17.bz2
> Jul 25 07:42:53 [1624] DVTVM0803.mse.am.mot.com crmd: notice:
> te_rsc_command: Initiating stop operation edgemanager_stop_0
> locally on dvtvm0803 | action 12
> Jul 25 07:42:53 [1620] DVTVM0803.mse.am.mot.com lrmd: info:
> cancel_recurring_action: Cancelling ocf operation
> edgemanager_monitor_1000
> Jul 25 07:42:53 [1624] DVTVM0803.mse.am.mot.com crmd: info:
> do_lrm_rsc_op: Performing key=12:7:0:1cec18ac-2aae-4c5c-8513-
> d6851bc10191 op=edgemanager_stop_0
> Jul 25 07:42:53 [1620] DVTVM0803.mse.am.mot.com lrmd: info:
> log_execute: executing - rsc:application action:stop
> call_id:30
> Jul 25 07:42:53 [1624] DVTVM0803.mse.am.mot.com crmd: info:
> process_lrm_event: Result of monitor operation for application
> on dvtvm0803: Cancelled | call=28 key=edgemanager_monitor_1000
> confirmed=true
> Jul 25 07:42:53 [1618] DVTVM0803.mse.am.mot.com cib: info:
> cib_process_request: Forwarding cib_modify operation for
> section status to all (origin=local/crmd/125)
> Jul 25 07:42:53 [1618] DVTVM0803.mse.am.mot.com cib: info:
> cib_perform_op: Diff: --- 0.20.75 2
> Jul 25 07:42:53 [1618] DVTVM0803.mse.am.mot.com cib: info:
> cib_perform_op: Diff: +++ 0.20.76 (null)
> Jul 25 07:42:53 [1618] DVTVM0803.mse.am.mot.com cib: info:
> cib_perform_op: + /cib: @num_updates=76
> Jul 25 07:42:53 [1618] DVTVM0803.mse.am.mot.com cib: info:
> cib_perform_op: + /cib/status/node_state[@id='2']/lrm[@id='2'
> ]/lrm_resources/lrm_resource[@id='edgemanager']/lrm_rsc_op[@id='edgem
> anager_last_0']: @operation_key=edgemanager_stop_0, @operation=stop,
> @transition-key=12:7:0:1cec18ac-2aae-4c5c-8513-d6851bc10191,
> @transition-magic=-1:193;12:7:0:1cec18ac-2aae-4c5c-8513-d6851bc10191,
> @call-id=-1, @rc-code=193, @op-status=-1, @last-run=1532518973,
> @last-rc-change=1532518973, @exec-time=0
> Jul 25 07:42:53 [1618] DVTVM0803.mse.am.mot.com cib: info:
> cib_process_request: Completed cib_modify operation for
> section status: OK (rc=0, origin=dvtvm0803/crmd/125, version=0.20.76)
> Jul 25 07:42:53 application(application)[12958]: INFO: Stopping
> APP - setting to Standby
> Jul 25 07:42:53 [1620] DVTVM0803.mse.am.mot.com lrmd: notice:
> operation_finished: edgemanager_stop_0:12958:stderr [
> /usr/local/vendor/bin/PrimaryMode.sh: line 27: $Filename: ambiguous
> redirect ]
> Jul 25 07:42:53 [1620] DVTVM0803.mse.am.mot.com lrmd: info:
> log_finished: finished - rsc:application action:stop
> call_id:30 pid:12958 exit-code:0 exec-time:34ms queue-time:0ms
> Jul 25 07:42:53 [1624] DVTVM0803.mse.am.mot.com crmd: notice:
> process_lrm_event: Result of stop operation for application on
> dvtvm0803: 0 (ok) | call=30 key=edgemanager_stop_0 confirmed=true
> cib-update=126
> Jul 25 07:42:53 [1618] DVTVM0803.mse.am.mot.com cib: info:
> cib_process_request: Forwarding cib_modify operation for
> section status to all (origin=local/crmd/126)
> Jul 25 07:42:53 [1618] DVTVM0803.mse.am.mot.com cib: info:
> cib_perform_op: Diff: --- 0.20.76 2
> Jul 25 07:42:53 [1618] DVTVM0803.mse.am.mot.com cib: info:
> cib_perform_op: Diff: +++ 0.20.77 (null)
> Jul 25 07:42:53 [1618] DVTVM0803.mse.am.mot.com cib: info:
> cib_perform_op: + /cib: @num_updates=77
> Jul 25 07:42:53 [1618] DVTVM0803.mse.am.mot.com cib: info:
> cib_perform_op: + /cib/status/node_state[@id='2']/lrm[@id='2'
> ]/lrm_resources/lrm_resource[@id='edgemanager']/lrm_rsc_op[@id='edgem
> anager_last_0']: @transition-magic=0:0;12:7:0:1cec18ac-2aae-4c5c-
> 8513-d6851bc10191, @call-id=30, @rc-code=0, @op-status=0, @exec-
> time=34
> Jul 25 07:42:53 [1618] DVTVM0803.mse.am.mot.com cib: info:
> cib_process_request: Completed cib_modify operation for
> section status: OK (rc=0, origin=dvtvm0803/crmd/126, version=0.20.77)
> Jul 25 07:42:53 [1624] DVTVM0803.mse.am.mot.com crmd: info:
> match_graph_event: Action edgemanager_stop_0 (12) confirmed on
> dvtvm0803 (rc=0)
> Jul 25 07:42:53 [1624] DVTVM0803.mse.am.mot.com crmd: notice:
> te_rsc_command: Initiating stop operation ClusterIP_stop_0
> locally on dvtvm0803 | action 5
> Jul 25 07:42:53 [1620] DVTVM0803.mse.am.mot.com lrmd: info:
> cancel_recurring_action: Cancelling ocf operation
> ClusterIP_monitor_1000
> Jul 25 07:42:53 [1624] DVTVM0803.mse.am.mot.com crmd: info:
> do_lrm_rsc_op: Performing key=5:7:0:1cec18ac-2aae-4c5c-8513-
> d6851bc10191 op=ClusterIP_stop_0
> Jul 25 07:42:53 [1618] DVTVM0803.mse.am.mot.com cib: info:
> cib_process_request: Forwarding cib_modify operation for
> section status to all (origin=local/crmd/127)
> Jul 25 07:42:53 [1620] DVTVM0803.mse.am.mot.com lrmd: info:
> log_execute: executing - rsc:ClusterIP action:stop call_id:32
> Jul 25 07:42:53 [1624] DVTVM0803.mse.am.mot.com crmd: info:
> process_lrm_event: Result of monitor operation for ClusterIP
> on dvtvm0803: Cancelled | call=26 key=ClusterIP_monitor_1000
> confirmed=true
> Jul 25 07:42:53 [1618] DVTVM0803.mse.am.mot.com cib: info:
> cib_perform_op: Diff: --- 0.20.77 2
> Jul 25 07:42:53 [1618] DVTVM0803.mse.am.mot.com cib: info:
> cib_perform_op: Diff: +++ 0.20.78 (null)
> Jul 25 07:42:53 [1618] DVTVM0803.mse.am.mot.com cib: info:
> cib_perform_op: + /cib: @num_updates=78
> Jul 25 07:42:53 [1618] DVTVM0803.mse.am.mot.com cib: info:
> cib_perform_op: + /cib/status/node_state[@id='2']/lrm[@id='2'
> ]/lrm_resources/lrm_resource[@id='ClusterIP']/lrm_rsc_op[@id='Cluster
> IP_last_0']: @operation_key=ClusterIP_stop_0, @operation=stop,
> @transition-key=5:7:0:1cec18ac-2aae-4c5c-8513-d6851bc10191,
> @transition-magic=-1:193;5:7:0:1cec18ac-2aae-4c5c-8513-d6851bc10191,
> @call-id=-1, @rc-code=193, @op-status=-1, @last-run=1532518973,
> @last-rc-change=1532518973, @exec-time=0
> Jul 25 07:42:53 [1618] DVTVM0803.mse.am.mot.com cib: info:
> cib_process_request: Completed cib_modify operation for
> section status: OK (rc=0, origin=dvtvm0803/crmd/127, version=0.20.78)
> Jul 25 07:42:53 IPaddr2(ClusterIP)[12970]: INFO: IP status = ok,
> IP_CIP=
> Jul 25 07:42:53 [1620] DVTVM0803.mse.am.mot.com lrmd: info:
> log_finished: finished - rsc:ClusterIP action:stop call_id:32
> pid:12970 exit-code:0 exec-time:74ms queue-time:0ms
> Jul 25 07:42:53 [1624] DVTVM0803.mse.am.mot.com crmd: notice:
> process_lrm_event: Result of stop operation for ClusterIP on
> dvtvm0803: 0 (ok) | call=32 key=ClusterIP_stop_0 confirmed=true cib-
> update=128
> Jul 25 07:42:53 [1618] DVTVM0803.mse.am.mot.com cib: info:
> cib_process_request: Forwarding cib_modify operation for
> section status to all (origin=local/crmd/128)
> Jul 25 07:42:53 [1618] DVTVM0803.mse.am.mot.com cib: info:
> cib_perform_op: Diff: --- 0.20.78 2
> Jul 25 07:42:53 [1618] DVTVM0803.mse.am.mot.com cib: info:
> cib_perform_op: Diff: +++ 0.20.79 (null)
> Jul 25 07:42:53 [1618] DVTVM0803.mse.am.mot.com cib: info:
> cib_perform_op: + /cib: @num_updates=79
> Jul 25 07:42:53 [1618] DVTVM0803.mse.am.mot.com cib: info:
> cib_perform_op: + /cib/status/node_state[@id='2']/lrm[@id='2'
> ]/lrm_resources/lrm_resource[@id='ClusterIP']/lrm_rsc_op[@id='Cluster
> IP_last_0']: @transition-magic=0:0;5:7:0:1cec18ac-2aae-4c5c-8513-
> d6851bc10191, @call-id=32, @rc-code=0, @op-status=0, @exec-time=74
> Jul 25 07:42:53 [1618] DVTVM0803.mse.am.mot.com cib: info:
> cib_process_request: Completed cib_modify operation for
> section status: OK (rc=0, origin=dvtvm0803/crmd/128, version=0.20.79)
> Jul 25 07:42:53 [1624] DVTVM0803.mse.am.mot.com crmd: info:
> match_graph_event: Action ClusterIP_stop_0 (5) confirmed on
> dvtvm0803 (rc=0)
> Jul 25 07:42:53 [1624] DVTVM0803.mse.am.mot.com crmd: notice:
> run_graph: Transition 7 (Complete=3, Pending=0, Fired=0,
> Skipped=0, Incomplete=0, Source=/var/lib/pacemaker/pengine/pe-input-
> 17.bz2): Complete
> Jul 25 07:42:53 [1624] DVTVM0803.mse.am.mot.com crmd: info:
> do_log: Input I_TE_SUCCESS received in state
> S_TRANSITION_ENGINE from notify_crmd
> Jul 25 07:42:53 [1624] DVTVM0803.mse.am.mot.com crmd: notice:
> do_state_transition: State transition S_TRANSITION_ENGINE ->
> S_IDLE | input=I_TE_SUCCESS cause=C_FSA_INTERNAL origin=notify_crmd
> Jul 25 07:42:58 ping(Connected)[13080]: WARNING: 10.144.102.5 is
> inactive: PING 10.144.102.5 (10.144.102.5) 56(84) bytes of data.
>
> --- 10.144.102.5 ping statistics ---
> 2 packets transmitted, 0 received, 100% packet loss, time 999ms
> Jul 25 07:42:58 [1618] DVTVM0803.mse.am.mot.com cib: info:
> cib_process_ping: Reporting our current digest to dvtvm0803:
> c20c09f5d9e99f10d879bc76de5ac6bb for 0.20.79 (0x55d4164ad140 0)
> Jul 25 07:43:01 ping(Connected)[13080]: WARNING: 10.144.102.152
> is inactive: PING 10.144.102.152 (10.144.102.152) 56(84) bytes of
> data.
>
> --- 10.144.102.152 ping statistics ---
> 2 packets transmitted, 0 received, 100% packet loss, time 999ms
> Jul 25 07:43:07 ping(Connected)[13164]: WARNING: 10.144.102.5 is
> inactive: PING 10.144.102.5 (10.144.102.5) 56(84) bytes of data.
>
> --- 10.144.102.5 ping statistics ---
> 2 packets transmitted, 0 received, 100% packet loss, time 999ms
> [994] DVTVM0803.mse.am.mot.com corosyncnotice [TOTEM ] A new
> membership (10.144.102.32:56) was formed. Members joined: 1
> Jul 25 07:43:09 [1619] DVTVM0803.mse.am.mot.com stonith-ng: info:
> pcmk_cpg_membership: Node 1 joined group stonith-ng
> (counter=4.0)
> Jul 25 07:43:09 [1618] DVTVM0803.mse.am.mot.com cib: info:
> pcmk_cpg_membership: Node 1 joined group cib (counter=4.0)
> Jul 25 07:43:09 [1556] DVTVM0803.mse.am.mot.com pacemakerd: info:
> pcmk_cpg_membership: Node 1 joined group pacemakerd
> (counter=4.0)
> Jul 25 07:43:09 [1556] DVTVM0803.mse.am.mot.com pacemakerd: info:
> pcmk_cpg_membership: Node 1 still member of group pacemakerd
> (peer=dvtvm0802, counter=4.0)
> Jul 25 07:43:09 [1556] DVTVM0803.mse.am.mot.com pacemakerd: info:
> crm_update_peer_proc: pcmk_cpg_membership: Node dvtvm0802[1] -
> corosync-cpg is now online
> Jul 25 07:43:09 [1556] DVTVM0803.mse.am.mot.com pacemakerd: error:
> pcmk_cpg_membership: Node dvtvm0802[1] appears to be online
> even though we think it is dead
When the nodes reconnect, *03 sees the mirror image of what *02 did
> Jul 25 07:43:09 [1556] DVTVM0803.mse.am.mot.com pacemakerd: notice:
> crm_update_peer_state_iter: Node dvtvm0802 state is now member
> | nodeid=1 previous=lost source=pcmk_cpg_membership
> Jul 25 07:43:09 [1556] DVTVM0803.mse.am.mot.com pacemakerd: info:
> pcmk_cpg_membership: Node 2 still member of group pacemakerd
> (peer=dvtvm0803, counter=4.1)
> Jul 25 07:43:09 [1556] DVTVM0803.mse.am.mot.com pacemakerd: info:
> crm_cs_flush: Sent 0 CPG messages (1 remaining, last=10): Try
> again (6)
> Jul 25 07:43:09 [1624] DVTVM0803.mse.am.mot.com crmd: info:
> pcmk_cpg_membership: Node 1 joined group crmd (counter=4.0)
> Jul 25 07:43:09 [1624] DVTVM0803.mse.am.mot.com crmd: info:
> pcmk_cpg_membership: Node 1 still member of group crmd
> (peer=dvtvm0802, counter=4.0)
> Jul 25 07:43:09 [1624] DVTVM0803.mse.am.mot.com crmd: info:
> crm_update_peer_proc: pcmk_cpg_membership: Node dvtvm0802[1] -
> corosync-cpg is now online
> Jul 25 07:43:09 [1624] DVTVM0803.mse.am.mot.com crmd: info:
> peer_update_callback: Client dvtvm0802/peer now has status
> [online] (DC=true, changed=4000000)
> Jul 25 07:43:09 [1622] DVTVM0803.mse.am.mot.com attrd: info:
> pcmk_cpg_membership: Node 1 joined group attrd (counter=4.0)
> Jul 25 07:43:09 [1624] DVTVM0803.mse.am.mot.com crmd: error:
> pcmk_cpg_membership: Node dvtvm0802[1] appears to be online
> even though we think it is dead
> Jul 25 07:43:09 [1624] DVTVM0803.mse.am.mot.com crmd: notice:
> crm_update_peer_state_iter: Node dvtvm0802 state is now member
> | nodeid=1 previous=lost source=pcmk_cpg_membership
> Jul 25 07:43:09 [1624] DVTVM0803.mse.am.mot.com crmd: info:
> peer_update_callback: Cluster node dvtvm0802 is now member
> (was lost)
> Jul 25 07:43:09 [1624] DVTVM0803.mse.am.mot.com crmd: info:
> pcmk_cpg_membership: Node 2 still member of group crmd
> (peer=dvtvm0803, counter=4.1)
> [994] DVTVM0803.mse.am.mot.com corosyncnotice [QUORUM] Members[2]: 1
> 2
> [994] DVTVM0803.mse.am.mot.com corosyncnotice [MAIN ] Completed
> service synchronization, ready to provide service.
> Jul 25 07:43:09 [1619] DVTVM0803.mse.am.mot.com stonith-ng: info:
> crm_get_peer: Created entry a3f26acd-11c5-4e8c-a839-
> fa51ac07f3c0/0x559fa4ef9300 for node dvtvm0802/1 (2 total)
> Jul 25 07:43:09 [1619] DVTVM0803.mse.am.mot.com stonith-ng: info:
> crm_get_peer: Node 1 is now known as dvtvm0802
> Jul 25 07:43:09 [1619] DVTVM0803.mse.am.mot.com stonith-ng: info:
> crm_get_peer: Node 1 has uuid 1
> Jul 25 07:43:09 [1619] DVTVM0803.mse.am.mot.com stonith-ng: info:
> pcmk_cpg_membership: Node 1 still member of group stonith-ng
> (peer=dvtvm0802, counter=4.0)
> Jul 25 07:43:09 [1619] DVTVM0803.mse.am.mot.com stonith-ng: info:
> crm_update_peer_proc: pcmk_cpg_membership: Node dvtvm0802[1] -
> corosync-cpg is now online
> Jul 25 07:43:09 [1619] DVTVM0803.mse.am.mot.com stonith-ng: notice:
> crm_update_peer_state_iter: Node dvtvm0802 state is now member
> | nodeid=1 previous=unknown source=crm_update_peer_proc
> Jul 25 07:43:09 [1619] DVTVM0803.mse.am.mot.com stonith-ng: info:
> pcmk_cpg_membership: Node 2 still member of group stonith-ng
> (peer=dvtvm0803, counter=4.1)
> Jul 25 07:43:09 [1556] DVTVM0803.mse.am.mot.com pacemakerd: info:
> pcmk_quorum_notification: Quorum retained | membership=56
> members=2
> Jul 25 07:43:09 [1624] DVTVM0803.mse.am.mot.com crmd: info:
> pcmk_quorum_notification: Quorum retained | membership=56
> members=2
> Jul 25 07:43:09 [1618] DVTVM0803.mse.am.mot.com cib: info:
> crm_get_peer: Created entry 9ac08c1f-5b08-4e91-9cf1-
> 69e9b55e7307/0x55d4165461d0 for node dvtvm0802/1 (2 total)
> Jul 25 07:43:09 [1618] DVTVM0803.mse.am.mot.com cib: info:
> crm_get_peer: Node 1 is now known as dvtvm0802
> Jul 25 07:43:09 [1622] DVTVM0803.mse.am.mot.com attrd: info:
> crm_get_peer: Created entry 9d8450fc-da7a-4f92-8fc9-
> 06a7a83f3334/0x56375c6bc590 for node dvtvm0802/1 (2 total)
> Jul 25 07:43:09 [1618] DVTVM0803.mse.am.mot.com cib: info:
> crm_get_peer: Node 1 has uuid 1
> Jul 25 07:43:09 [1622] DVTVM0803.mse.am.mot.com attrd: info:
> crm_get_peer: Node 1 is now known as dvtvm0802
> Jul 25 07:43:09 [1618] DVTVM0803.mse.am.mot.com cib: info:
> pcmk_cpg_membership: Node 1 still member of group cib
> (peer=dvtvm0802, counter=4.0)
> Jul 25 07:43:09 [1622] DVTVM0803.mse.am.mot.com attrd: info:
> crm_get_peer: Node 1 has uuid 1
> Jul 25 07:43:09 [1618] DVTVM0803.mse.am.mot.com cib: info:
> crm_update_peer_proc: pcmk_cpg_membership: Node dvtvm0802[1] -
> corosync-cpg is now online
> Jul 25 07:43:09 [1622] DVTVM0803.mse.am.mot.com attrd: info:
> pcmk_cpg_membership: Node 1 still member of group attrd
> (peer=dvtvm0802, counter=4.0)
> Jul 25 07:43:09 [1622] DVTVM0803.mse.am.mot.com attrd: info:
> crm_update_peer_proc: pcmk_cpg_membership: Node dvtvm0802[1] -
> corosync-cpg is now online
> Jul 25 07:43:09 [1622] DVTVM0803.mse.am.mot.com attrd: notice:
> crm_update_peer_state_iter: Node dvtvm0802 state is now member
> | nodeid=1 previous=unknown source=crm_update_peer_proc
> Jul 25 07:43:09 [1618] DVTVM0803.mse.am.mot.com cib: notice:
> crm_update_peer_state_iter: Node dvtvm0802 state is now member
> | nodeid=1 previous=unknown source=crm_update_peer_proc
> Jul 25 07:43:09 [1618] DVTVM0803.mse.am.mot.com cib: info:
> pcmk_cpg_membership: Node 2 still member of group cib
> (peer=dvtvm0803, counter=4.1)
> Jul 25 07:43:09 [1622] DVTVM0803.mse.am.mot.com attrd: info:
> pcmk_cpg_membership: Node 2 still member of group attrd
> (peer=dvtvm0803, counter=4.1)
> Jul 25 07:43:09 [1618] DVTVM0803.mse.am.mot.com cib: info:
> cib_process_request: Forwarding cib_modify operation for
> section status to all (origin=local/crmd/129)
> Jul 25 07:43:09 [1618] DVTVM0803.mse.am.mot.com cib: info:
> cib_process_request: Forwarding cib_modify operation for
> section status to all (origin=local/crmd/130)
> Jul 25 07:43:09 [1618] DVTVM0803.mse.am.mot.com cib: info:
> cib_process_request: Forwarding cib_modify operation for
> section nodes to all (origin=local/crmd/133)
> Jul 25 07:43:09 [1618] DVTVM0803.mse.am.mot.com cib: info:
> cib_process_request: Forwarding cib_modify operation for
> section status to all (origin=local/crmd/134)
> Jul 25 07:43:09 [1622] DVTVM0803.mse.am.mot.com attrd: notice:
> attrd_peer_message: Detected another attribute writer:
> dvtvm0802
> Jul 25 07:43:09 [1624] DVTVM0803.mse.am.mot.com crmd: info:
> register_fsa_error_adv: Resetting the current action list
> Jul 25 07:43:09 [1624] DVTVM0803.mse.am.mot.com crmd: warning:
> crmd_ha_msg_filter: Another DC detected: dvtvm0802 (op=noop)
> Jul 25 07:43:09 [1624] DVTVM0803.mse.am.mot.com crmd: notice:
> do_state_transition: State transition S_IDLE -> S_ELECTION |
> input=I_ELECTION cause=C_FSA_INTERNAL origin=crmd_ha_msg_filter
> Jul 25 07:43:09 [1624] DVTVM0803.mse.am.mot.com crmd: info:
> update_dc: Unset DC. Was dvtvm0803
> Jul 25 07:43:09 [1618] DVTVM0803.mse.am.mot.com cib: info:
> cib_perform_op: Diff: --- 0.20.79 2
> Jul 25 07:43:09 [1618] DVTVM0803.mse.am.mot.com cib: info:
> cib_perform_op: Diff: +++ 0.20.80 (null)
> Jul 25 07:43:09 [1618] DVTVM0803.mse.am.mot.com cib: info:
> cib_perform_op: + /cib: @num_updates=80
> Jul 25 07:43:09 [1618] DVTVM0803.mse.am.mot.com cib: info:
> cib_perform_op: + /cib/status/node_state[@id='2']: @crm-
> debug-origin=peer_update_callback
> Jul 25 07:43:09 [1618] DVTVM0803.mse.am.mot.com cib: info:
> cib_process_request: Completed cib_modify operation for
> section status: OK (rc=0, origin=dvtvm0802/crmd/82, version=0.20.80)
> Jul 25 07:43:09 [1618] DVTVM0803.mse.am.mot.com cib: info:
> cib_process_request: Completed cib_modify operation for
> section status: OK (rc=0, origin=dvtvm0802/crmd/83, version=0.20.80)
> Jul 25 07:43:09 [1622] DVTVM0803.mse.am.mot.com attrd: info:
> attrd_peer_message: Processing sync-response from dvtvm0802
> Jul 25 07:43:09 [1622] DVTVM0803.mse.am.mot.com attrd: info:
> attrd_peer_update: Setting #attrd-protocol[dvtvm0802]: (null)
> -> 2 from dvtvm0802
> Jul 25 07:43:09 [1622] DVTVM0803.mse.am.mot.com attrd: info:
> attrd_peer_update: Setting pingd[dvtvm0802]: (null) -> 2000
> from dvtvm0802
> Jul 25 07:43:09 [1624] DVTVM0803.mse.am.mot.com crmd: info:
> election_count_vote: Election 7 (owner: 1) pass: vote from
> dvtvm0802 (Uptime)
> Jul 25 07:43:09 [1618] DVTVM0803.mse.am.mot.com cib: info:
> cib_process_request: Completed cib_modify operation for
> section nodes: OK (rc=0, origin=dvtvm0802/crmd/86, version=0.20.80)
> Jul 25 07:43:09 [1618] DVTVM0803.mse.am.mot.com cib: info:
> cib_perform_op: Diff: --- 0.20.80 2
> Jul 25 07:43:09 [1618] DVTVM0803.mse.am.mot.com cib: info:
> cib_perform_op: Diff: +++ 0.20.81 (null)
> Jul 25 07:43:09 [1618] DVTVM0803.mse.am.mot.com cib: info:
> cib_perform_op: + /cib: @num_updates=81
> Jul 25 07:43:09 [1618] DVTVM0803.mse.am.mot.com cib: info:
> cib_perform_op: + /cib/status/node_state[@id='1']: @in_ccm=t
> rue, @crmd=online
> Jul 25 07:43:09 [1618] DVTVM0803.mse.am.mot.com cib: info:
> cib_perform_op: + /cib/status/node_state[@id='2']: @crm-
> debug-origin=post_cache_update
> Jul 25 07:43:09 [1618] DVTVM0803.mse.am.mot.com cib: info:
> cib_process_request: Completed cib_modify operation for
> section status: OK (rc=0, origin=dvtvm0802/crmd/87, version=0.20.81)
> Jul 25 07:43:09 [1622] DVTVM0803.mse.am.mot.com attrd: info:
> election_count_vote: Election 4 (owner: 1) pass: vote from
> dvtvm0802 (Uptime)
> Jul 25 07:43:09 [1618] DVTVM0803.mse.am.mot.com cib: info:
> cib_perform_op: Diff: --- 0.20.81 2
> Jul 25 07:43:09 [1618] DVTVM0803.mse.am.mot.com cib: info:
> cib_perform_op: Diff: +++ 0.20.82 (null)
> Jul 25 07:43:09 [1618] DVTVM0803.mse.am.mot.com cib: info:
> cib_perform_op: + /cib: @num_updates=82
> Jul 25 07:43:09 [1618] DVTVM0803.mse.am.mot.com cib: info:
> cib_perform_op: + /cib/status/node_state[@id='1']: @crm-
> debug-origin=peer_update_callback
> Jul 25 07:43:09 [1618] DVTVM0803.mse.am.mot.com cib: info:
> cib_process_request: Completed cib_modify operation for
> section status: OK (rc=0, origin=dvtvm0803/crmd/129, version=0.20.82)
> Jul 25 07:43:09 [1618] DVTVM0803.mse.am.mot.com cib: info:
> cib_process_request: Completed cib_modify operation for
> section status: OK (rc=0, origin=dvtvm0803/crmd/130, version=0.20.82)
> Jul 25 07:43:09 [1618] DVTVM0803.mse.am.mot.com cib: info:
> cib_process_request: Completed cib_modify operation for
> section nodes: OK (rc=0, origin=dvtvm0803/crmd/133, version=0.20.82)
> Jul 25 07:43:09 [1618] DVTVM0803.mse.am.mot.com cib: info:
> cib_perform_op: Diff: --- 0.20.82 2
> Jul 25 07:43:09 [1618] DVTVM0803.mse.am.mot.com cib: info:
> cib_perform_op: Diff: +++ 0.20.83 (null)
> Jul 25 07:43:09 [1618] DVTVM0803.mse.am.mot.com cib: info:
> cib_perform_op: + /cib: @num_updates=83
> Jul 25 07:43:09 [1618] DVTVM0803.mse.am.mot.com cib: info:
> cib_perform_op: + /cib/status/node_state[@id='1']: @crm-
> debug-origin=post_cache_update
> Jul 25 07:43:09 [1618] DVTVM0803.mse.am.mot.com cib: info:
> cib_process_request: Completed cib_modify operation for
> section status: OK (rc=0, origin=dvtvm0803/crmd/134, version=0.20.83)
> Jul 25 07:43:09 [1622] DVTVM0803.mse.am.mot.com attrd: info:
> election_complete: Election election-attrd complete
> Jul 25 07:43:09 [1622] DVTVM0803.mse.am.mot.com attrd: info:
> write_attribute: Processed 2 private changes for #attrd-
> protocol, id=<n/a>, set=(null)
> Jul 25 07:43:09 [1622] DVTVM0803.mse.am.mot.com attrd: info:
> write_attribute: Write out of 'pingd' delayed: timer is
> running
> Jul 25 07:43:09 [1624] DVTVM0803.mse.am.mot.com crmd: info:
> election_complete: Election election-0 complete
> Jul 25 07:43:09 [1624] DVTVM0803.mse.am.mot.com crmd: info:
> election_timeout_popped: Election failed: Declaring ourselves
> the winner
> Jul 25 07:43:09 [1624] DVTVM0803.mse.am.mot.com crmd: info:
> do_log: Input I_ELECTION_DC received in state S_ELECTION from
> election_timeout_popped
> Jul 25 07:43:09 [1624] DVTVM0803.mse.am.mot.com crmd: notice:
> do_state_transition: State transition S_ELECTION ->
> S_INTEGRATION | input=I_ELECTION_DC cause=C_TIMER_POPPED
> origin=election_timeout_popped
> Jul 25 07:43:09 [1624] DVTVM0803.mse.am.mot.com crmd: info:
> do_dc_takeover: Taking over DC status for this partition
*03 won the DC election after reconnect
> Jul 25 07:43:09 [1618] DVTVM0803.mse.am.mot.com cib: info:
> cib_process_request: Completed cib_master operation for
> section 'all': OK (rc=0, origin=local/crmd/135, version=0.20.83)
> Jul 25 07:43:09 [1618] DVTVM0803.mse.am.mot.com cib: info:
> cib_process_request: Forwarding cib_modify operation for
> section cib to all (origin=local/crmd/136)
> Jul 25 07:43:09 [1618] DVTVM0803.mse.am.mot.com cib: info:
> cib_process_request: Forwarding cib_modify operation for
> section crm_config to all (origin=local/crmd/138)
> Jul 25 07:43:09 [1618] DVTVM0803.mse.am.mot.com cib: info:
> cib_process_request: Completed cib_modify operation for
> section cib: OK (rc=0, origin=dvtvm0803/crmd/136, version=0.20.83)
> Jul 25 07:43:09 [1618] DVTVM0803.mse.am.mot.com cib: info:
> cib_process_request: Completed cib_modify operation for
> section crm_config: OK (rc=0, origin=dvtvm0803/crmd/138,
> version=0.20.83)
> Jul 25 07:43:09 [1618] DVTVM0803.mse.am.mot.com cib: info:
> cib_process_request: Forwarding cib_modify operation for
> section crm_config to all (origin=local/crmd/140)
> Jul 25 07:43:09 [1624] DVTVM0803.mse.am.mot.com crmd: info:
> crm_update_peer_join: initialize_join: Node dvtvm0803[2] -
> join-5 phase confirmed -> none
> Jul 25 07:43:09 [1624] DVTVM0803.mse.am.mot.com crmd: info:
> join_make_offer: Making join offers based on membership 56
> Jul 25 07:43:09 [1624] DVTVM0803.mse.am.mot.com crmd: info:
> join_make_offer: join-5: Sending offer to dvtvm0802
> Jul 25 07:43:09 [1624] DVTVM0803.mse.am.mot.com crmd: info:
> crm_update_peer_join: join_make_offer: Node dvtvm0802[1] -
> join-5 phase none -> welcomed
> Jul 25 07:43:09 [1624] DVTVM0803.mse.am.mot.com crmd: info:
> join_make_offer: join-5: Sending offer to dvtvm0803
> Jul 25 07:43:09 [1624] DVTVM0803.mse.am.mot.com crmd: info:
> crm_update_peer_join: join_make_offer: Node dvtvm0803[2] -
> join-5 phase none -> welcomed
> Jul 25 07:43:09 [1624] DVTVM0803.mse.am.mot.com crmd: info:
> do_dc_join_offer_all: join-5: Waiting on 2 outstanding join
> acks
> Jul 25 07:43:09 [1624] DVTVM0803.mse.am.mot.com crmd: warning:
> do_log: Input I_ELECTION_DC received in state S_INTEGRATION
> from do_election_check
> Jul 25 07:43:09 [1624] DVTVM0803.mse.am.mot.com crmd: info:
> crm_update_peer_join: initialize_join: Node dvtvm0802[1] -
> join-6 phase welcomed -> none
> Jul 25 07:43:09 [1624] DVTVM0803.mse.am.mot.com crmd: info:
> crm_update_peer_join: initialize_join: Node dvtvm0803[2] -
> join-6 phase welcomed -> none
> Jul 25 07:43:09 [1624] DVTVM0803.mse.am.mot.com crmd: info:
> join_make_offer: join-6: Sending offer to dvtvm0802
> Jul 25 07:43:09 [1624] DVTVM0803.mse.am.mot.com crmd: info:
> crm_update_peer_join: join_make_offer: Node dvtvm0802[1] -
> join-6 phase none -> welcomed
> Jul 25 07:43:09 [1624] DVTVM0803.mse.am.mot.com crmd: info:
> join_make_offer: join-6: Sending offer to dvtvm0803
> Jul 25 07:43:09 [1624] DVTVM0803.mse.am.mot.com crmd: info:
> crm_update_peer_join: join_make_offer: Node dvtvm0803[2] -
> join-6 phase none -> welcomed
> Jul 25 07:43:09 [1624] DVTVM0803.mse.am.mot.com crmd: info:
> do_dc_join_offer_all: join-6: Waiting on 2 outstanding join
> acks
> Jul 25 07:43:09 [1618] DVTVM0803.mse.am.mot.com cib: info:
> cib_process_request: Completed cib_modify operation for
> section crm_config: OK (rc=0, origin=dvtvm0803/crmd/140,
> version=0.20.83)
> Jul 25 07:43:09 [1618] DVTVM0803.mse.am.mot.com cib: info:
> cib_process_request: Forwarding cib_modify operation for
> section crm_config to all (origin=local/crmd/142)
> Jul 25 07:43:09 [1624] DVTVM0803.mse.am.mot.com crmd: info:
> update_dc: Set DC to dvtvm0803 (3.0.14)
> Jul 25 07:43:09 [1618] DVTVM0803.mse.am.mot.com cib: info:
> cib_process_request: Completed cib_modify operation for
> section crm_config: OK (rc=0, origin=dvtvm0803/crmd/142,
> version=0.20.83)
> Jul 25 07:43:09 [1624] DVTVM0803.mse.am.mot.com crmd: info:
> crm_update_peer_join: do_dc_join_filter_offer: Node
> dvtvm0803[2] - join-6 phase welcomed -> integrated
> Jul 25 07:43:09 [1624] DVTVM0803.mse.am.mot.com crmd: info:
> crm_update_peer_join: do_dc_join_filter_offer: Node
> dvtvm0802[1] - join-6 phase welcomed -> integrated
> Jul 25 07:43:09 [1624] DVTVM0803.mse.am.mot.com crmd: info:
> do_state_transition: State transition S_INTEGRATION ->
> S_FINALIZE_JOIN | input=I_INTEGRATED cause=C_FSA_INTERNAL
> origin=check_join_state
> Jul 25 07:43:09 [1624] DVTVM0803.mse.am.mot.com crmd: info:
> crmd_join_phase_log: join-6: dvtvm0802=integrated
> Jul 25 07:43:09 [1624] DVTVM0803.mse.am.mot.com crmd: info:
> crmd_join_phase_log: join-6: dvtvm0803=integrated
> Jul 25 07:43:09 [1624] DVTVM0803.mse.am.mot.com crmd: info:
> do_dc_join_finalize: join-6: Syncing our CIB to the rest of
> the cluster
> Jul 25 07:43:09 [1624] DVTVM0803.mse.am.mot.com crmd: info:
> crm_update_peer_join: finalize_join_for: Node dvtvm0802[1] -
> join-6 phase integrated -> finalized
> Jul 25 07:43:09 [1624] DVTVM0803.mse.am.mot.com crmd: info:
> crm_update_peer_join: finalize_join_for: Node dvtvm0803[2] -
> join-6 phase integrated -> finalized
> Jul 25 07:43:09 [1618] DVTVM0803.mse.am.mot.com cib: info:
> cib_process_replace: Digest matched on replace from dvtvm0803:
> e5254bf4e58c636caa44908bdc7e0a94
> Jul 25 07:43:09 [1618] DVTVM0803.mse.am.mot.com cib: info:
> cib_process_replace: Replaced 0.20.83 with 0.20.83 from
> dvtvm0803
> Jul 25 07:43:09 [1624] DVTVM0803.mse.am.mot.com crmd: info:
> crm_update_peer_join: do_dc_join_ack: Node dvtvm0803[2] -
> join-6 phase finalized -> confirmed
> Jul 25 07:43:09 [1624] DVTVM0803.mse.am.mot.com crmd: info:
> do_dc_join_ack: join-6: Updating node state to member for
> dvtvm0803
> Jul 25 07:43:09 [1624] DVTVM0803.mse.am.mot.com crmd: info:
> erase_status_tag: Deleting lrm status entries for dvtvm0803 |
> xpath=//node_state[@uname='dvtvm0803']/lrm
> Jul 25 07:43:09 [1618] DVTVM0803.mse.am.mot.com cib: info:
> cib_process_request: Completed cib_replace operation for
> section 'all': OK (rc=0, origin=dvtvm0803/crmd/146, version=0.20.83)
> Jul 25 07:43:09 [1618] DVTVM0803.mse.am.mot.com cib: info:
> cib_process_request: Forwarding cib_modify operation for
> section nodes to all (origin=local/crmd/147)
> Jul 25 07:43:09 [1618] DVTVM0803.mse.am.mot.com cib: info:
> cib_process_request: Forwarding cib_modify operation for
> section nodes to all (origin=local/crmd/148)
> Jul 25 07:43:09 [1618] DVTVM0803.mse.am.mot.com cib: info:
> cib_process_request: Forwarding cib_delete operation for
> section //node_state[@uname='dvtvm0803']/lrm to all
> (origin=local/crmd/149)
> Jul 25 07:43:09 [1618] DVTVM0803.mse.am.mot.com cib: info:
> cib_process_request: Forwarding cib_modify operation for
> section status to all (origin=local/crmd/150)
> Jul 25 07:43:09 [1618] DVTVM0803.mse.am.mot.com cib: info:
> cib_process_request: Completed cib_modify operation for
> section nodes: OK (rc=0, origin=dvtvm0803/crmd/147, version=0.20.83)
> Jul 25 07:43:09 [1624] DVTVM0803.mse.am.mot.com crmd: info:
> crm_update_peer_join: do_dc_join_ack: Node dvtvm0802[1] -
> join-6 phase finalized -> confirmed
> Jul 25 07:43:09 [1624] DVTVM0803.mse.am.mot.com crmd: info:
> do_dc_join_ack: join-6: Updating node state to member for
> dvtvm0802
> Jul 25 07:43:09 [1624] DVTVM0803.mse.am.mot.com crmd: info:
> erase_status_tag: Deleting lrm status entries for dvtvm0802 |
> xpath=//node_state[@uname='dvtvm0802']/lrm
> Jul 25 07:43:09 [1618] DVTVM0803.mse.am.mot.com cib: info:
> cib_process_request: Completed cib_modify operation for
> section nodes: OK (rc=0, origin=dvtvm0803/crmd/148, version=0.20.83)
> Jul 25 07:43:09 [1618] DVTVM0803.mse.am.mot.com cib: info:
> cib_perform_op: Diff: --- 0.20.83 2
> Jul 25 07:43:09 [1618] DVTVM0803.mse.am.mot.com cib: info:
> cib_perform_op: Diff: +++ 0.20.84 (null)
> Jul 25 07:43:09 [1618] DVTVM0803.mse.am.mot.com cib: info:
> cib_perform_op: --
> /cib/status/node_state[@id='2']/lrm[@id='2']
> Jul 25 07:43:09 [1618] DVTVM0803.mse.am.mot.com cib: info:
> cib_perform_op: + /cib: @num_updates=84
> Jul 25 07:43:09 [1618] DVTVM0803.mse.am.mot.com cib: info:
> cib_process_request: Completed cib_delete operation for
> section //node_state[@uname='dvtvm0803']/lrm: OK (rc=0,
> origin=dvtvm0803/crmd/149, version=0.20.84)
> Jul 25 07:43:09 [1618] DVTVM0803.mse.am.mot.com cib: info:
> cib_perform_op: Diff: --- 0.20.84 2
> Jul 25 07:43:09 [1618] DVTVM0803.mse.am.mot.com cib: info:
> cib_perform_op: Diff: +++ 0.20.85 (null)
> Jul 25 07:43:09 [1618] DVTVM0803.mse.am.mot.com cib: info:
> cib_perform_op: + /cib: @num_updates=85
> Jul 25 07:43:09 [1618] DVTVM0803.mse.am.mot.com cib: info:
> cib_perform_op: + /cib/status/node_state[@id='2']: @crm-
> debug-origin=do_lrm_query_internal
> Jul 25 07:43:09 [1618] DVTVM0803.mse.am.mot.com cib: info:
> cib_perform_op: ++ /cib/status/node_state[@id='2']: <lrm
> id="2"/>
> Jul 25 07:43:09 [1618] DVTVM0803.mse.am.mot.com cib: info:
> cib_perform_op: ++ <lrm_re
> sources>
> Jul 25 07:43:09 [1618] DVTVM0803.mse.am.mot.com cib: info:
> cib_perform_op: ++ <lrm_
> resource id="Connected" type="ping" class="ocf" provider="pacemaker">
> Jul 25 07:43:09 [1618] DVTVM0803.mse.am.mot.com cib: info:
> cib_perform_op: ++ <lr
> m_rsc_op id="Connected_last_0" operation_key="Connected_start_0"
> operation="start" crm-debug-origin="build_active_RAs"
> crm_feature_set="3.0.14" transition-key="8:0:0:1cec18ac-2aae-4c5c-
> 8513-d6851bc10191" transition-magic="0:0;8:0:0:1cec18ac-2aae-4c5c-
> 8513-d6851bc10191" exit-reason="" on_node="dvtvm0803" call-id="15"
> rc-code="0" op-status="0" interval="0" last-run="1532518326"
> Jul 25 07:43:09 [1618] DVTVM0803.mse.am.mot.com cib: info:
> cib_perform_op: ++ <lr
> m_rsc_op id="Connected_monitor_3000"
> operation_key="Connected_monitor_3000" operation="monitor" crm-debug-
> origin="build_active_RAs" crm_feature_set="3.0.14" transition-
> key="9:0:0:1cec18ac-2aae-4c5c-8513-d6851bc10191" transition-
> magic="0:0;9:0:0:1cec18ac-2aae-4c5c-8513-d6851bc10191" exit-reason=""
> on_node="dvtvm0803" call-id="16" rc-code="0" op-status="0"
> interval="3000" last-r
> Jul 25 07:43:09 [1618] DVTVM0803.mse.am.mot.com cib: info:
> cib_perform_op: ++ </lrm
> _resource>
> Jul 25 07:43:09 [1618] DVTVM0803.mse.am.mot.com cib: info:
> cib_perform_op: ++ <lrm_
> resource id="ClusterIP" type="IPaddr2" class="ocf"
> provider="heartbeat">
> Jul 25 07:43:09 [1618] DVTVM0803.mse.am.mot.com cib: info:
> cib_perform_op: ++ <lr
> m_rsc_op id="ClusterIP_last_0" operation_key="ClusterIP_stop_0"
> operation="stop" crm-debug-origin="build_active_RAs"
> crm_feature_set="3.0.14" transition-key="5:7:0:1cec18ac-2aae-4c5c-
> 8513-d6851bc10191" transition-magic="0:0;5:7:0:1cec18ac-2aae-4c5c-
> 8513-d6851bc10191" exit-reason="" on_node="dvtvm0803" call-id="32"
> rc-code="0" op-status="0" interval="0" last-run="1532518973" la
> Jul 25 07:43:09 [1618] DVTVM0803.mse.am.mot.com cib: info:
> cib_perform_op: ++ </lrm
> _resource>
> Jul 25 07:43:09 [1618] DVTVM0803.mse.am.mot.com cib: info:
> cib_perform_op: ++ <lrm_
> resource id="application" type="application" class="ocf"
> provider="vendor">
> Jul 25 07:43:09 [1618] DVTVM0803.mse.am.mot.com cib: info:
> cib_perform_op: ++ <lr
> m_rsc_op id="edgemanager_last_0" operation_key="edgemanager_stop_0"
> operation="stop" crm-debug-origin="build_active_RAs"
> crm_feature_set="3.0.14" transition-key="12:7:0:1cec18ac-2aae-4c5c-
> 8513-d6851bc10191" transition-magic="0:0;12:7:0:1cec18ac-2aae-4c5c-
> 8513-d6851bc10191" exit-reason="" on_node="dvtvm0803" call-id="30"
> rc-code="0" op-status="0" interval="0" last-run="15325189
> Jul 25 07:43:09 [1618] DVTVM0803.mse.am.mot.com cib: info:
> cib_perform_op: ++ </lrm
> _resource>
> Jul 25 07:43:09 [1618] DVTVM0803.mse.am.mot.com cib: info:
> cib_perform_op: ++ </lrm_r
> esources>
> Jul 25 07:43:09 [1618] DVTVM0803.mse.am.mot.com cib: info:
> cib_perform_op: ++ </lrm>
> Jul 25 07:43:09 [1618] DVTVM0803.mse.am.mot.com cib: info:
> cib_process_request: Completed cib_modify operation for
> section status: OK (rc=0, origin=dvtvm0803/crmd/150, version=0.20.85)
> Jul 25 07:43:09 [1618] DVTVM0803.mse.am.mot.com cib: info:
> cib_process_request: Forwarding cib_delete operation for
> section //node_state[@uname='dvtvm0802']/lrm to all
> (origin=local/crmd/151)
> Jul 25 07:43:09 [1624] DVTVM0803.mse.am.mot.com crmd: info:
> do_state_transition: State transition S_FINALIZE_JOIN ->
> S_POLICY_ENGINE | input=I_FINALIZED cause=C_FSA_INTERNAL
> origin=check_join_state
> Jul 25 07:43:09 [1618] DVTVM0803.mse.am.mot.com cib: info:
> cib_process_request: Forwarding cib_modify operation for
> section status to all (origin=local/crmd/152)
> Jul 25 07:43:09 [1624] DVTVM0803.mse.am.mot.com crmd: info:
> abort_transition_graph: Transition aborted: Peer Cancelled |
> source=do_te_invoke:143 complete=true
> Jul 25 07:43:09 [1618] DVTVM0803.mse.am.mot.com cib: info:
> cib_perform_op: Diff: --- 0.20.85 2
> Jul 25 07:43:09 [1618] DVTVM0803.mse.am.mot.com cib: info:
> cib_perform_op: Diff: +++ 0.20.86 (null)
> Jul 25 07:43:09 [1618] DVTVM0803.mse.am.mot.com cib: info:
> cib_perform_op: --
> /cib/status/node_state[@id='1']/lrm[@id='1']
> Jul 25 07:43:09 [1618] DVTVM0803.mse.am.mot.com cib: info:
> cib_perform_op: + /cib: @num_updates=86
> Jul 25 07:43:09 [1618] DVTVM0803.mse.am.mot.com cib: info:
> cib_process_request: Completed cib_delete operation for
> section //node_state[@uname='dvtvm0802']/lrm: OK (rc=0,
> origin=dvtvm0803/crmd/151, version=0.20.86)
> Jul 25 07:43:09 [1624] DVTVM0803.mse.am.mot.com crmd: info:
> abort_transition_graph: Transition aborted by deletion of
> lrm[@id='1']: Resource state removal | cib=0.20.86
> source=abort_unless_down:357
> path=/cib/status/node_state[@id='1']/lrm[@id='1'] complete=true
> Jul 25 07:43:09 [1622] DVTVM0803.mse.am.mot.com attrd: info:
> attrd_peer_update: Setting pingd[dvtvm0803]: 0 -> 1000 from
> dvtvm0803
> Jul 25 07:43:09 [1618] DVTVM0803.mse.am.mot.com cib: info:
> cib_perform_op: Diff: --- 0.20.86 2
> Jul 25 07:43:09 [1618] DVTVM0803.mse.am.mot.com cib: info:
> cib_perform_op: Diff: +++ 0.20.87 (null)
> Jul 25 07:43:09 [1618] DVTVM0803.mse.am.mot.com cib: info:
> cib_perform_op: + /cib: @num_updates=87
> Jul 25 07:43:09 [1618] DVTVM0803.mse.am.mot.com cib: info:
> cib_perform_op: + /cib/status/node_state[@id='1']: @crm-
> debug-origin=do_lrm_query_internal
> Jul 25 07:43:09 [1618] DVTVM0803.mse.am.mot.com cib: info:
> cib_perform_op: ++ /cib/status/node_state[@id='1']: <lrm
> id="1"/>
> Jul 25 07:43:09 [1618] DVTVM0803.mse.am.mot.com cib: info:
> cib_perform_op: ++ <lrm_re
> sources>
> Jul 25 07:43:09 [1618] DVTVM0803.mse.am.mot.com cib: info:
> cib_perform_op: ++ <lrm_
> resource id="Connected" type="ping" class="ocf" provider="pacemaker">
> Jul 25 07:43:09 [1618] DVTVM0803.mse.am.mot.com cib: info:
> cib_perform_op: ++ <lr
> m_rsc_op id="Connected_last_0" operation_key="Connected_start_0"
> operation="start" crm-debug-origin="build_active_RAs"
> crm_feature_set="3.0.14" transition-key="10:0:0:1cec18ac-2aae-4c5c-
> 8513-d6851bc10191" transition-magic="0:0;10:0:0:1cec18ac-2aae-4c5c-
> 8513-d6851bc10191" exit-reason="" on_node="dvtvm0802" call-id="15"
> rc-code="0" op-status="0" interval="0" last-run="1532518326
> Jul 25 07:43:09 [1618] DVTVM0803.mse.am.mot.com cib: info:
> cib_perform_op: ++ <lr
> m_rsc_op id="Connected_monitor_3000"
> operation_key="Connected_monitor_3000" operation="monitor" crm-debug-
> origin="build_active_RAs" crm_feature_set="3.0.14" transition-
> key="11:0:0:1cec18ac-2aae-4c5c-8513-d6851bc10191" transition-
> magic="0:0;11:0:0:1cec18ac-2aae-4c5c-8513-d6851bc10191" exit-
> reason="" on_node="dvtvm0802" call-id="16" rc-code="0" op-status="0"
> interval="3000" last
> Jul 25 07:43:09 [1618] DVTVM0803.mse.am.mot.com cib: info:
> cib_perform_op: ++ </lrm
> _resource>
> Jul 25 07:43:09 [1618] DVTVM0803.mse.am.mot.com cib: info:
> cib_perform_op: ++ <lrm_
> resource id="ClusterIP" type="IPaddr2" class="ocf"
> provider="heartbeat">
> Jul 25 07:43:09 [1618] DVTVM0803.mse.am.mot.com cib: info:
> cib_perform_op: ++ <lr
> m_rsc_op id="ClusterIP_last_0" operation_key="ClusterIP_start_0"
> operation="start" crm-debug-origin="build_active_RAs"
> crm_feature_set="3.0.14" transition-key="4:1:0:1cec18ac-2aae-4c5c-
> 8513-d6851bc10191" transition-magic="0:0;4:1:0:1cec18ac-2aae-4c5c-
> 8513-d6851bc10191" exit-reason="" on_node="dvtvm0802" call-id="17"
> rc-code="0" op-status="0" interval="0" last-run="1532518330"
> Jul 25 07:43:09 [1618] DVTVM0803.mse.am.mot.com cib: info:
> cib_perform_op: ++ <lr
> m_rsc_op id="ClusterIP_monitor_1000"
> operation_key="ClusterIP_monitor_1000" operation="monitor" crm-debug-
> origin="build_active_RAs" crm_feature_set="3.0.14" transition-
> key="5:1:0:1cec18ac-2aae-4c5c-8513-d6851bc10191" transition-
> magic="0:0;5:1:0:1cec18ac-2aae-4c5c-8513-d6851bc10191" exit-reason=""
> on_node="dvtvm0802" call-id="18" rc-code="0" op-status="0"
> interval="1000" last-r
> Jul 25 07:43:09 [1618] DVTVM0803.mse.am.mot.com cib: info:
> cib_perform_op: ++ </lrm
> _resource>
> Jul 25 07:43:09 [1618] DVTVM0803.mse.am.mot.com cib: info:
> cib_perform_op: ++ <lrm_
> resource id="application" type="application" class="ocf"
> provider="vendor">
> Jul 25 07:43:09 [1618] DVTVM0803.mse.am.mot.com cib: info:
> cib_perform_op: ++ <lr
> m_rsc_op id="edgemanager_last_0" operation_key="edgemanager_start_0"
> operation="start" crm-debug-origin="build_active_RAs"
> crm_feature_set="3.0.14" transition-key="14:1:0:1cec18ac-2aae-4c5c-
> 8513-d6851bc10191" transition-magic="0:0;14:1:0:1cec18ac-2aae-4c5c-
> 8513-d6851bc10191" exit-reason="" on_node="dvtvm0802" call-id="19"
> rc-code="0" op-status="0" interval="0" last-run="153251
> Jul 25 07:43:09 [1618] DVTVM0803.mse.am.mot.com cib: info:
> cib_perform_op: ++ <lr
> m_rsc_op id="edgemanager_monitor_1000"
> operation_key="edgemanager_monitor_1000" operation="monitor" crm-
> debug-origin="build_active_RAs" crm_feature_set="3.0.14" transition-
> key="15:1:0:1cec18ac-2aae-4c5c-8513-d6851bc10191" transition-
> magic="0:0;15:1:0:1cec18ac-2aae-4c5c-8513-d6851bc10191" exit-
> reason="" on_node="dvtvm0802" call-id="20" rc-code="0" op-status="0"
> interval="1000"
> Jul 25 07:43:09 [1618] DVTVM0803.mse.am.mot.com cib: info:
> cib_perform_op: ++ </lrm
> _resource>
> Jul 25 07:43:09 [1618] DVTVM0803.mse.am.mot.com cib: info:
> cib_perform_op: ++ </lrm_r
> esources>
> Jul 25 07:43:09 [1618] DVTVM0803.mse.am.mot.com cib: info:
> cib_perform_op: ++ </lrm>
> Jul 25 07:43:09 [1618] DVTVM0803.mse.am.mot.com cib: info:
> cib_process_request: Completed cib_modify operation for
> section status: OK (rc=0, origin=dvtvm0803/crmd/152, version=0.20.87)
> Jul 25 07:43:09 [1624] DVTVM0803.mse.am.mot.com crmd: info:
> abort_transition_graph: Transition aborted: LRM Refresh |
> source=process_resource_updates:278 complete=true
> Jul 25 07:43:09 [1618] DVTVM0803.mse.am.mot.com cib: info:
> cib_process_request: Forwarding cib_modify operation for
> section nodes to all (origin=local/crmd/155)
> Jul 25 07:43:09 [1618] DVTVM0803.mse.am.mot.com cib: info:
> cib_process_request: Forwarding cib_modify operation for
> section status to all (origin=local/crmd/156)
> Jul 25 07:43:09 [1618] DVTVM0803.mse.am.mot.com cib: info:
> cib_process_request: Forwarding cib_modify operation for
> section cib to all (origin=local/crmd/157)
> Jul 25 07:43:09 [1618] DVTVM0803.mse.am.mot.com cib: info:
> cib_process_request: Completed cib_modify operation for
> section nodes: OK (rc=0, origin=dvtvm0803/crmd/155, version=0.20.87)
> Jul 25 07:43:09 [1618] DVTVM0803.mse.am.mot.com cib: info:
> cib_perform_op: Diff: --- 0.20.87 2
> Jul 25 07:43:09 [1618] DVTVM0803.mse.am.mot.com cib: info:
> cib_perform_op: Diff: +++ 0.20.88 (null)
> Jul 25 07:43:09 [1618] DVTVM0803.mse.am.mot.com cib: info:
> cib_perform_op: + /cib: @num_updates=88
> Jul 25 07:43:09 [1618] DVTVM0803.mse.am.mot.com cib: info:
> cib_perform_op: + /cib/status/node_state[@id='1']: @crm-
> debug-origin=do_state_transition
> Jul 25 07:43:09 [1618] DVTVM0803.mse.am.mot.com cib: info:
> cib_perform_op: + /cib/status/node_state[@id='2']: @crm-
> debug-origin=do_state_transition
> Jul 25 07:43:09 [1618] DVTVM0803.mse.am.mot.com cib: info:
> cib_process_request: Completed cib_modify operation for
> section status: OK (rc=0, origin=dvtvm0803/crmd/156, version=0.20.88)
> Jul 25 07:43:09 [1618] DVTVM0803.mse.am.mot.com cib: info:
> cib_process_request: Completed cib_modify operation for
> section cib: OK (rc=0, origin=dvtvm0803/crmd/157, version=0.20.88)
> Jul 25 07:43:09 [1618] DVTVM0803.mse.am.mot.com cib: info:
> cib_file_backup: Archived previous version as
> /var/lib/pacemaker/cib/cib-26.raw
> Jul 25 07:43:09 [1618] DVTVM0803.mse.am.mot.com cib: info:
> cib_file_write_with_digest: Wrote version 0.20.0 of the CIB to
> disk (digest: d281e07c969310cc6525c6f46ec6a307)
> Jul 25 07:43:09 [1618] DVTVM0803.mse.am.mot.com cib: info:
> cib_file_write_with_digest: Reading cluster configuration file
> /var/lib/pacemaker/cib/cib.6H2SW1 (digest:
> /var/lib/pacemaker/cib/cib.RmM7iH)
> Jul 25 07:43:09 [1623] DVTVM0803.mse.am.mot.com pengine: notice:
> unpack_config: On loss of CCM Quorum: Ignore
> Jul 25 07:43:09 [1623] DVTVM0803.mse.am.mot.com pengine: info:
> determine_online_status: Node dvtvm0802 is online
> Jul 25 07:43:09 [1623] DVTVM0803.mse.am.mot.com pengine: info:
> determine_online_status: Node dvtvm0803 is online
> Jul 25 07:43:09 [1623] DVTVM0803.mse.am.mot.com pengine: info:
> unpack_node_loop: Node 1 is already processed
> Jul 25 07:43:09 [1623] DVTVM0803.mse.am.mot.com pengine: info:
> unpack_node_loop: Node 2 is already processed
> Jul 25 07:43:09 [1623] DVTVM0803.mse.am.mot.com pengine: info:
> unpack_node_loop: Node 1 is already processed
> Jul 25 07:43:09 [1623] DVTVM0803.mse.am.mot.com pengine: info:
> unpack_node_loop: Node 2 is already processed
> Jul 25 07:43:09 [1623] DVTVM0803.mse.am.mot.com pengine: info:
> common_print: ClusterIP (ocf::heartbeat:IPaddr2):
> Started dvtvm0802
> Jul 25 07:43:09 [1623] DVTVM0803.mse.am.mot.com pengine: info:
> clone_print: Clone Set: Connected-clone [Connected]
> Jul 25 07:43:09 [1623] DVTVM0803.mse.am.mot.com pengine: info:
> short_print: Started: [ dvtvm0802 dvtvm0803 ]
> Jul 25 07:43:09 [1623] DVTVM0803.mse.am.mot.com pengine: info:
> common_print: application (ocf::vendor:application):
> Started dvtvm0802
> Jul 25 07:43:09 [1623] DVTVM0803.mse.am.mot.com pengine: info:
> rsc_merge_weights: application: Rolling back scores from
> ClusterIP
> Jul 25 07:43:09 [1623] DVTVM0803.mse.am.mot.com pengine: info:
> native_color: Resource ClusterIP cannot run anywhere
> Jul 25 07:43:09 [1623] DVTVM0803.mse.am.mot.com pengine: notice:
> LogAction: * Stop ClusterIP ( dvtvm0802 ) due
> to node availability
> Jul 25 07:43:09 [1623] DVTVM0803.mse.am.mot.com pengine: info:
> LogActions: Leave Connected:0 (Started dvtvm0802)
> Jul 25 07:43:09 [1623] DVTVM0803.mse.am.mot.com pengine: info:
> LogActions: Leave Connected:1 (Started dvtvm0803)
> Jul 25 07:43:09 [1623] DVTVM0803.mse.am.mot.com pengine: notice:
> LogAction: * Stop application ( dvtvm0802 ) due
> to required ClusterIP start
> Jul 25 07:43:09 [1623] DVTVM0803.mse.am.mot.com pengine: notice:
> process_pe_message: Calculated transition 8, saving inputs in
> /var/lib/pacemaker/pengine/pe-input-18.bz2
As the new DC, *03 decides to stop ClusterIP and application on *02. I
didn't confirm, but most likely it's because it hasn't gotten *02's
node attribute information yet after the reconnect, and thinks *02's
ping is not successful.
With fencing, after the split, each node would have tried to shoot the
other. One of them would have succeeded, and then grabbed the resources
for itself. When the shot node rebooted and rejoined, the winning node
would have all the correct information about the state, so it would not
need to restart anything.
> Jul 25 07:43:09 [1624] DVTVM0803.mse.am.mot.com crmd: info:
> do_state_transition: State transition S_POLICY_ENGINE ->
> S_TRANSITION_ENGINE | input=I_PE_SUCCESS cause=C_IPC_MESSAGE
> origin=handle_response
> Jul 25 07:43:09 [1624] DVTVM0803.mse.am.mot.com crmd: info:
> do_te_invoke: Processing graph 8 (ref=pe_calc-dc-1532518989-
> 73) derived from /var/lib/pacemaker/pengine/pe-input-18.bz2
> Jul 25 07:43:09 [1624] DVTVM0803.mse.am.mot.com crmd: notice:
> te_rsc_command: Initiating stop operation edgemanager_stop_0
> on dvtvm0802 | action 15
> Jul 25 07:43:09 [1618] DVTVM0803.mse.am.mot.com cib: info:
> cib_perform_op: Diff: --- 0.20.88 2
> Jul 25 07:43:09 [1618] DVTVM0803.mse.am.mot.com cib: info:
> cib_perform_op: Diff: +++ 0.20.89 (null)
> Jul 25 07:43:09 [1618] DVTVM0803.mse.am.mot.com cib: info:
> cib_perform_op: + /cib: @num_updates=89
> Jul 25 07:43:09 [1618] DVTVM0803.mse.am.mot.com cib: info:
> cib_perform_op: + /cib/status/node_state[@id='1']: @crm-
> debug-origin=do_update_resource
> Jul 25 07:43:09 [1618] DVTVM0803.mse.am.mot.com cib: info:
> cib_perform_op: + /cib/status/node_state[@id='1']/lrm[@id='1'
> ]/lrm_resources/lrm_resource[@id='edgemanager']/lrm_rsc_op[@id='edgem
> anager_last_0']: @operation_key=edgemanager_stop_0, @operation=stop,
> @crm-debug-origin=do_update_resource, @transition-
> key=15:8:0:1cec18ac-2aae-4c5c-8513-d6851bc10191, @transition-magic=-
> 1:193;15:8:0:1cec18ac-2aae-4c5c-8513-d6851bc10191, @call-id=-1, @rc-
> code=193, @op-status=-1, @last-run=1532518989, @last-r
> Jul 25 07:43:09 [1618] DVTVM0803.mse.am.mot.com cib: info:
> cib_process_request: Completed cib_modify operation for
> section status: OK (rc=0, origin=dvtvm0802/crmd/92, version=0.20.89)
> Jul 25 07:43:09 [1618] DVTVM0803.mse.am.mot.com cib: info:
> cib_perform_op: Diff: --- 0.20.89 2
> Jul 25 07:43:09 [1618] DVTVM0803.mse.am.mot.com cib: info:
> cib_perform_op: Diff: +++ 0.20.90 (null)
> Jul 25 07:43:09 [1618] DVTVM0803.mse.am.mot.com cib: info:
> cib_perform_op: + /cib: @num_updates=90
> Jul 25 07:43:09 [1618] DVTVM0803.mse.am.mot.com cib: info:
> cib_perform_op: + /cib/status/node_state[@id='1']/lrm[@id='1'
> ]/lrm_resources/lrm_resource[@id='edgemanager']/lrm_rsc_op[@id='edgem
> anager_last_0']: @transition-magic=0:0;15:8:0:1cec18ac-2aae-4c5c-
> 8513-d6851bc10191, @call-id=22, @rc-code=0, @op-status=0, @exec-
> time=34
> Jul 25 07:43:09 [1618] DVTVM0803.mse.am.mot.com cib: info:
> cib_process_request: Completed cib_modify operation for
> section status: OK (rc=0, origin=dvtvm0802/crmd/93, version=0.20.90)
> Jul 25 07:43:09 [1624] DVTVM0803.mse.am.mot.com crmd: info:
> match_graph_event: Action edgemanager_stop_0 (15) confirmed on
> dvtvm0802 (rc=0)
> Jul 25 07:43:09 [1624] DVTVM0803.mse.am.mot.com crmd: notice:
> te_rsc_command: Initiating stop operation ClusterIP_stop_0 on
> dvtvm0802 | action 6
> Jul 25 07:43:09 [1618] DVTVM0803.mse.am.mot.com cib: info:
> cib_perform_op: Diff: --- 0.20.90 2
> Jul 25 07:43:09 [1618] DVTVM0803.mse.am.mot.com cib: info:
> cib_perform_op: Diff: +++ 0.20.91 (null)
> Jul 25 07:43:09 [1618] DVTVM0803.mse.am.mot.com cib: info:
> cib_perform_op: + /cib: @num_updates=91
> Jul 25 07:43:09 [1618] DVTVM0803.mse.am.mot.com cib: info:
> cib_perform_op: + /cib/status/node_state[@id='1']/lrm[@id='1'
> ]/lrm_resources/lrm_resource[@id='ClusterIP']/lrm_rsc_op[@id='Cluster
> IP_last_0']: @operation_key=ClusterIP_stop_0, @operation=stop, @crm-
> debug-origin=do_update_resource, @transition-key=6:8:0:1cec18ac-2aae-
> 4c5c-8513-d6851bc10191, @transition-magic=-1:193;6:8:0:1cec18ac-2aae-
> 4c5c-8513-d6851bc10191, @call-id=-1, @rc-code=193, @op-status=-1,
> @last-run=1532518989, @last-rc-change
> Jul 25 07:43:09 [1618] DVTVM0803.mse.am.mot.com cib: info:
> cib_process_request: Completed cib_modify operation for
> section status: OK (rc=0, origin=dvtvm0802/crmd/94, version=0.20.91)
> Jul 25 07:43:09 [1618] DVTVM0803.mse.am.mot.com cib: info:
> cib_perform_op: Diff: --- 0.20.91 2
> Jul 25 07:43:09 [1618] DVTVM0803.mse.am.mot.com cib: info:
> cib_perform_op: Diff: +++ 0.20.92 (null)
> Jul 25 07:43:09 [1618] DVTVM0803.mse.am.mot.com cib: info:
> cib_perform_op: + /cib: @num_updates=92
> Jul 25 07:43:09 [1618] DVTVM0803.mse.am.mot.com cib: info:
> cib_perform_op: + /cib/status/node_state[@id='1']/lrm[@id='1'
> ]/lrm_resources/lrm_resource[@id='ClusterIP']/lrm_rsc_op[@id='Cluster
> IP_last_0']: @transition-magic=0:0;6:8:0:1cec18ac-2aae-4c5c-8513-
> d6851bc10191, @call-id=24, @rc-code=0, @op-status=0, @exec-time=76
> Jul 25 07:43:09 [1618] DVTVM0803.mse.am.mot.com cib: info:
> cib_process_request: Completed cib_modify operation for
> section status: OK (rc=0, origin=dvtvm0802/crmd/95, version=0.20.92)
> Jul 25 07:43:09 [1624] DVTVM0803.mse.am.mot.com crmd: info:
> match_graph_event: Action ClusterIP_stop_0 (6) confirmed on
> dvtvm0802 (rc=0)
> Jul 25 07:43:09 [1624] DVTVM0803.mse.am.mot.com crmd: notice:
> run_graph: Transition 8 (Complete=3, Pending=0, Fired=0,
> Skipped=0, Incomplete=0, Source=/var/lib/pacemaker/pengine/pe-input-
> 18.bz2): Complete
> Jul 25 07:43:09 [1624] DVTVM0803.mse.am.mot.com crmd: info:
> do_log: Input I_TE_SUCCESS received in state
> S_TRANSITION_ENGINE from notify_crmd
> Jul 25 07:43:09 [1624] DVTVM0803.mse.am.mot.com crmd: notice:
> do_state_transition: State transition S_TRANSITION_ENGINE ->
> S_IDLE | input=I_TE_SUCCESS cause=C_FSA_INTERNAL origin=notify_crmd
> Jul 25 07:43:09 [1556] DVTVM0803.mse.am.mot.com pacemakerd: info:
> mcp_cpg_deliver: Ignoring process list sent by peer for local
> node
> Jul 25 07:43:10 [1622] DVTVM0803.mse.am.mot.com attrd: info:
> write_attribute: Sent update 9 with 2 changes for pingd,
> id=<n/a>, set=(null)
> Jul 25 07:43:10 [1618] DVTVM0803.mse.am.mot.com cib: info:
> cib_process_request: Forwarding cib_modify operation for
> section status to all (origin=local/attrd/9)
> Jul 25 07:43:10 [1618] DVTVM0803.mse.am.mot.com cib: info:
> cib_perform_op: Diff: --- 0.20.92 2
> Jul 25 07:43:10 [1618] DVTVM0803.mse.am.mot.com cib: info:
> cib_perform_op: Diff: +++ 0.20.93 (null)
> Jul 25 07:43:10 [1618] DVTVM0803.mse.am.mot.com cib: info:
> cib_perform_op: + /cib: @num_updates=93
> Jul 25 07:43:10 [1618] DVTVM0803.mse.am.mot.com cib: info:
> cib_perform_op: ++
> /cib/status/node_state[@id='1']: <transient_attributes id="1"/>
> Jul 25 07:43:10 [1618] DVTVM0803.mse.am.mot.com cib: info:
> cib_perform_op: ++ <instan
> ce_attributes id="status-1">
> Jul 25 07:43:10 [1618] DVTVM0803.mse.am.mot.com cib: info:
> cib_perform_op: ++ <nvpa
> ir id="status-1-pingd" name="pingd" value="2000"/>
> Jul 25 07:43:10 [1618] DVTVM0803.mse.am.mot.com cib: info:
> cib_perform_op: ++ </insta
> nce_attributes>
> Jul 25 07:43:10 [1618] DVTVM0803.mse.am.mot.com cib: info:
> cib_perform_op: ++ </transie
> nt_attributes>
> Jul 25 07:43:10 [1618] DVTVM0803.mse.am.mot.com cib: info:
> cib_perform_op: + /cib/status/node_state[@id='2']/transient_a
> ttributes[@id='2']/instance_attributes[@id='status-
> 2']/nvpair[@id='status-2-pingd']: @value=1000
> Jul 25 07:43:10 [1624] DVTVM0803.mse.am.mot.com crmd: info:
> abort_transition_graph: Transition aborted by
> transient_attributes.1 'create': Transient attribute change |
> cib=0.20.93 source=abort_unless_down:343
> path=/cib/status/node_state[@id='1'] complete=true
> Jul 25 07:43:10 [1624] DVTVM0803.mse.am.mot.com crmd: notice:
> do_state_transition: State transition S_IDLE ->
> S_POLICY_ENGINE | input=I_PE_CALC cause=C_FSA_INTERNAL
> origin=abort_transition_graph
> Jul 25 07:43:10 [1618] DVTVM0803.mse.am.mot.com cib: info:
> cib_process_request: Completed cib_modify operation for
> section status: OK (rc=0, origin=dvtvm0803/attrd/9, version=0.20.93)
> Jul 25 07:43:10 [1622] DVTVM0803.mse.am.mot.com attrd: info:
> attrd_cib_callback: Update 9 for pingd: OK (0)
> Jul 25 07:43:10 [1622] DVTVM0803.mse.am.mot.com attrd: info:
> attrd_cib_callback: Update 9 for pingd[dvtvm0802]=2000: OK (0)
> Jul 25 07:43:10 [1622] DVTVM0803.mse.am.mot.com attrd: info:
> attrd_cib_callback: Update 9 for pingd[dvtvm0803]=1000: OK (0)
> Jul 25 07:43:10 [1623] DVTVM0803.mse.am.mot.com pengine: notice:
> unpack_config: On loss of CCM Quorum: Ignore
> Jul 25 07:43:10 [1623] DVTVM0803.mse.am.mot.com pengine: info:
> determine_online_status: Node dvtvm0802 is online
> Jul 25 07:43:10 [1623] DVTVM0803.mse.am.mot.com pengine: info:
> determine_online_status: Node dvtvm0803 is online
> Jul 25 07:43:10 [1623] DVTVM0803.mse.am.mot.com pengine: info:
> unpack_node_loop: Node 1 is already processed
> Jul 25 07:43:10 [1623] DVTVM0803.mse.am.mot.com pengine: info:
> unpack_node_loop: Node 2 is already processed
> Jul 25 07:43:10 [1623] DVTVM0803.mse.am.mot.com pengine: info:
> unpack_node_loop: Node 1 is already processed
> Jul 25 07:43:10 [1623] DVTVM0803.mse.am.mot.com pengine: info:
> unpack_node_loop: Node 2 is already processed
> Jul 25 07:43:10 [1623] DVTVM0803.mse.am.mot.com pengine: info:
> common_print: ClusterIP (ocf::heartbeat:IPaddr2):
> Stopped
> Jul 25 07:43:10 [1623] DVTVM0803.mse.am.mot.com pengine: info:
> clone_print: Clone Set: Connected-clone [Connected]
> Jul 25 07:43:10 [1623] DVTVM0803.mse.am.mot.com pengine: info:
> short_print: Started: [ dvtvm0802 dvtvm0803 ]
> Jul 25 07:43:10 [1623] DVTVM0803.mse.am.mot.com pengine: info:
> common_print: application (ocf::vendor:application):
> Stopped
> Jul 25 07:43:10 [1623] DVTVM0803.mse.am.mot.com pengine: info:
> RecurringOp: Start recurring monitor (1s) for ClusterIP on
> dvtvm0802
> Jul 25 07:43:10 [1623] DVTVM0803.mse.am.mot.com pengine: info:
> RecurringOp: Start recurring monitor (1s) for application on
> dvtvm0802
> Jul 25 07:43:10 [1623] DVTVM0803.mse.am.mot.com pengine: notice:
> LogAction: * Start ClusterIP ( dvtvm0802 )
> Jul 25 07:43:10 [1623] DVTVM0803.mse.am.mot.com pengine: info:
> LogActions: Leave Connected:0 (Started dvtvm0802)
> Jul 25 07:43:10 [1623] DVTVM0803.mse.am.mot.com pengine: info:
> LogActions: Leave Connected:1 (Started dvtvm0803)
> Jul 25 07:43:10 [1623] DVTVM0803.mse.am.mot.com pengine: notice:
> LogAction: * Start application ( dvtvm0802 )
> Jul 25 07:43:10 [1623] DVTVM0803.mse.am.mot.com pengine: notice:
> process_pe_message: Calculated transition 9, saving inputs in
> /var/lib/pacemaker/pengine/pe-input-19.bz2
> Jul 25 07:43:10 [1624] DVTVM0803.mse.am.mot.com crmd: info:
> do_state_transition: State transition S_POLICY_ENGINE ->
> S_TRANSITION_ENGINE | input=I_PE_SUCCESS cause=C_IPC_MESSAGE
> origin=handle_response
> Jul 25 07:43:10 [1624] DVTVM0803.mse.am.mot.com crmd: info:
> do_te_invoke: Processing graph 9 (ref=pe_calc-dc-1532518990-
> 76) derived from /var/lib/pacemaker/pengine/pe-input-19.bz2
> Jul 25 07:43:10 [1624] DVTVM0803.mse.am.mot.com crmd: notice:
> te_rsc_command: Initiating start operation ClusterIP_start_0
> on dvtvm0802 | action 4
> Jul 25 07:43:10 [1618] DVTVM0803.mse.am.mot.com cib: info:
> cib_perform_op: Diff: --- 0.20.93 2
> Jul 25 07:43:10 [1618] DVTVM0803.mse.am.mot.com cib: info:
> cib_perform_op: Diff: +++ 0.20.94 (null)
> Jul 25 07:43:10 [1618] DVTVM0803.mse.am.mot.com cib: info:
> cib_perform_op: + /cib: @num_updates=94
> Jul 25 07:43:10 [1618] DVTVM0803.mse.am.mot.com cib: info:
> cib_perform_op: + /cib/status/node_state[@id='1']/lrm[@id='1'
> ]/lrm_resources/lrm_resource[@id='ClusterIP']/lrm_rsc_op[@id='Cluster
> IP_last_0']: @operation_key=ClusterIP_start_0, @operation=start,
> @transition-key=4:9:0:1cec18ac-2aae-4c5c-8513-d6851bc10191,
> @transition-magic=-1:193;4:9:0:1cec18ac-2aae-4c5c-8513-d6851bc10191,
> @call-id=-1, @rc-code=193, @op-status=-1, @last-run=1532518990,
> @last-rc-change=1532518990, @exec-time=0
> Jul 25 07:43:10 [1618] DVTVM0803.mse.am.mot.com cib: info:
> cib_process_request: Completed cib_modify operation for
> section status: OK (rc=0, origin=dvtvm0802/crmd/96, version=0.20.94)
> Jul 25 07:43:14 [1622] DVTVM0803.mse.am.mot.com attrd: info:
> attrd_peer_update: Setting pingd[dvtvm0803]: 1000 -> 2000 from
> dvtvm0803
> Jul 25 07:43:14 [1618] DVTVM0803.mse.am.mot.com cib: info:
> cib_perform_op: Diff: --- 0.20.94 2
> Jul 25 07:43:14 [1618] DVTVM0803.mse.am.mot.com cib: info:
> cib_perform_op: Diff: +++ 0.20.95 (null)
> Jul 25 07:43:14 [1618] DVTVM0803.mse.am.mot.com cib: info:
> cib_perform_op: + /cib: @num_updates=95
> Jul 25 07:43:14 [1618] DVTVM0803.mse.am.mot.com cib: info:
> cib_perform_op: + /cib/status/node_state[@id='1']/lrm[@id='1'
> ]/lrm_resources/lrm_resource[@id='ClusterIP']/lrm_rsc_op[@id='Cluster
> IP_last_0']: @transition-magic=0:0;4:9:0:1cec18ac-2aae-4c5c-8513-
> d6851bc10191, @call-id=25, @rc-code=0, @op-status=0, @exec-time=4105,
> @queue-time=1
> Jul 25 07:43:14 [1618] DVTVM0803.mse.am.mot.com cib: info:
> cib_process_request: Completed cib_modify operation for
> section status: OK (rc=0, origin=dvtvm0802/crmd/97, version=0.20.95)
> Jul 25 07:43:14 [1624] DVTVM0803.mse.am.mot.com crmd: info:
> match_graph_event: Action ClusterIP_start_0 (4) confirmed on
> dvtvm0802 (rc=0)
> Jul 25 07:43:14 [1624] DVTVM0803.mse.am.mot.com crmd: notice:
> te_rsc_command: Initiating monitor operation
> ClusterIP_monitor_1000 on dvtvm0802 | action 5
> Jul 25 07:43:14 [1624] DVTVM0803.mse.am.mot.com crmd: notice:
> te_rsc_command: Initiating start operation edgemanager_start_0
> on dvtvm0802 | action 14
> Jul 25 07:43:14 [1618] DVTVM0803.mse.am.mot.com cib: info:
> cib_perform_op: Diff: --- 0.20.95 2
> Jul 25 07:43:14 [1618] DVTVM0803.mse.am.mot.com cib: info:
> cib_perform_op: Diff: +++ 0.20.96 (null)
> Jul 25 07:43:14 [1618] DVTVM0803.mse.am.mot.com cib: info:
> cib_perform_op: + /cib: @num_updates=96
> Jul 25 07:43:14 [1618] DVTVM0803.mse.am.mot.com cib: info:
> cib_perform_op: + /cib/status/node_state[@id='1']/lrm[@id='1'
> ]/lrm_resources/lrm_resource[@id='ClusterIP']/lrm_rsc_op[@id='Cluster
> IP_monitor_1000']: @crm-debug-origin=do_update_resource,
> @transition-key=5:9:0:1cec18ac-2aae-4c5c-8513-d6851bc10191,
> @transition-magic=-1:193;5:9:0:1cec18ac-2aae-4c5c-8513-d6851bc10191,
> @call-id=-1, @rc-code=193, @op-status=-1, @last-rc-change=1532518994,
> @exec-time=0
> Jul 25 07:43:14 [1618] DVTVM0803.mse.am.mot.com cib: info:
> cib_process_request: Completed cib_modify operation for
> section status: OK (rc=0, origin=dvtvm0802/crmd/98, version=0.20.96)
> Jul 25 07:43:14 [1618] DVTVM0803.mse.am.mot.com cib: info:
> cib_perform_op: Diff: --- 0.20.96 2
> Jul 25 07:43:14 [1618] DVTVM0803.mse.am.mot.com cib: info:
> cib_perform_op: Diff: +++ 0.20.97 (null)
> Jul 25 07:43:14 [1618] DVTVM0803.mse.am.mot.com cib: info:
> cib_perform_op: + /cib: @num_updates=97
> Jul 25 07:43:14 [1618] DVTVM0803.mse.am.mot.com cib: info:
> cib_perform_op: + /cib/status/node_state[@id='1']/lrm[@id='1'
> ]/lrm_resources/lrm_resource[@id='edgemanager']/lrm_rsc_op[@id='edgem
> anager_last_0']: @operation_key=edgemanager_start_0,
> @operation=start, @transition-key=14:9:0:1cec18ac-2aae-4c5c-8513-
> d6851bc10191, @transition-magic=-1:193;14:9:0:1cec18ac-2aae-4c5c-
> 8513-d6851bc10191, @call-id=-1, @rc-code=193, @op-status=-1, @last-
> run=1532518994, @last-rc-change=1532518994, @exec-time=0
> Jul 25 07:43:14 [1618] DVTVM0803.mse.am.mot.com cib: info:
> cib_process_request: Completed cib_modify operation for
> section status: OK (rc=0, origin=dvtvm0802/crmd/99, version=0.20.97)
> Jul 25 07:43:14 [1618] DVTVM0803.mse.am.mot.com cib: info:
> cib_perform_op: Diff: --- 0.20.97 2
> Jul 25 07:43:14 [1618] DVTVM0803.mse.am.mot.com cib: info:
> cib_perform_op: Diff: +++ 0.20.98 (null)
> Jul 25 07:43:14 [1618] DVTVM0803.mse.am.mot.com cib: info:
> cib_perform_op: + /cib: @num_updates=98
> Jul 25 07:43:14 [1618] DVTVM0803.mse.am.mot.com cib: info:
> cib_perform_op: + /cib/status/node_state[@id='1']/lrm[@id='1'
> ]/lrm_resources/lrm_resource[@id='edgemanager']/lrm_rsc_op[@id='edgem
> anager_last_0']: @transition-magic=0:0;14:9:0:1cec18ac-2aae-4c5c-
> 8513-d6851bc10191, @call-id=27, @rc-code=0, @op-status=0, @exec-
> time=37
> Jul 25 07:43:14 [1618] DVTVM0803.mse.am.mot.com cib: info:
> cib_process_request: Completed cib_modify operation for
> section status: OK (rc=0, origin=dvtvm0802/crmd/100, version=0.20.98)
> Jul 25 07:43:14 [1624] DVTVM0803.mse.am.mot.com crmd: info:
> match_graph_event: Action edgemanager_start_0 (14) confirmed
> on dvtvm0802 (rc=0)
> Jul 25 07:43:14 [1624] DVTVM0803.mse.am.mot.com crmd: notice:
> te_rsc_command: Initiating monitor operation
> edgemanager_monitor_1000 on dvtvm0802 | action 15
> Jul 25 07:43:14 [1618] DVTVM0803.mse.am.mot.com cib: info:
> cib_perform_op: Diff: --- 0.20.98 2
> Jul 25 07:43:14 [1618] DVTVM0803.mse.am.mot.com cib: info:
> cib_perform_op: Diff: +++ 0.20.99 (null)
> Jul 25 07:43:14 [1618] DVTVM0803.mse.am.mot.com cib: info:
> cib_perform_op: + /cib: @num_updates=99
> Jul 25 07:43:14 [1618] DVTVM0803.mse.am.mot.com cib: info:
> cib_perform_op: + /cib/status/node_state[@id='1']/lrm[@id='1'
> ]/lrm_resources/lrm_resource[@id='edgemanager']/lrm_rsc_op[@id='edgem
> anager_monitor_1000']: @crm-debug-origin=do_update_resource,
> @transition-key=15:9:0:1cec18ac-2aae-4c5c-8513-d6851bc10191,
> @transition-magic=-1:193;15:9:0:1cec18ac-2aae-4c5c-8513-d6851bc10191,
> @call-id=-1, @rc-code=193, @op-status=-1, @last-rc-change=1532518994,
> @exec-time=0, @queue-time=0
> Jul 25 07:43:14 [1618] DVTVM0803.mse.am.mot.com cib: info:
> cib_process_request: Completed cib_modify operation for
> section status: OK (rc=0, origin=dvtvm0802/crmd/101, version=0.20.99)
> Jul 25 07:43:14 [1618] DVTVM0803.mse.am.mot.com cib: info:
> cib_perform_op: Diff: --- 0.20.99 2
> Jul 25 07:43:14 [1618] DVTVM0803.mse.am.mot.com cib: info:
> cib_perform_op: Diff: +++ 0.20.100 (null)
> Jul 25 07:43:14 [1618] DVTVM0803.mse.am.mot.com cib: info:
> cib_perform_op: + /cib: @num_updates=100
> Jul 25 07:43:14 [1618] DVTVM0803.mse.am.mot.com cib: info:
> cib_perform_op: + /cib/status/node_state[@id='1']/lrm[@id='1'
> ]/lrm_resources/lrm_resource[@id='edgemanager']/lrm_rsc_op[@id='edgem
> anager_monitor_1000']: @transition-magic=0:0;15:9:0:1cec18ac-2aae-
> 4c5c-8513-d6851bc10191, @call-id=28, @rc-code=0, @op-status=0, @exec-
> time=18
> Jul 25 07:43:14 [1624] DVTVM0803.mse.am.mot.com crmd: info:
> match_graph_event: Action edgemanager_monitor_1000 (15)
> confirmed on dvtvm0802 (rc=0)
> Jul 25 07:43:14 [1618] DVTVM0803.mse.am.mot.com cib: info:
> cib_process_request: Completed cib_modify operation for
> section status: OK (rc=0, origin=dvtvm0802/crmd/102,
> version=0.20.100)
> Jul 25 07:43:14 [1618] DVTVM0803.mse.am.mot.com cib: info:
> cib_perform_op: Diff: --- 0.20.100 2
> Jul 25 07:43:14 [1618] DVTVM0803.mse.am.mot.com cib: info:
> cib_perform_op: Diff: +++ 0.20.101 (null)
> Jul 25 07:43:14 [1618] DVTVM0803.mse.am.mot.com cib: info:
> cib_perform_op: + /cib: @num_updates=101
> Jul 25 07:43:14 [1618] DVTVM0803.mse.am.mot.com cib: info:
> cib_perform_op: + /cib/status/node_state[@id='1']/lrm[@id='1'
> ]/lrm_resources/lrm_resource[@id='ClusterIP']/lrm_rsc_op[@id='Cluster
> IP_monitor_1000']: @transition-magic=0:0;5:9:0:1cec18ac-2aae-4c5c-
> 8513-d6851bc10191, @call-id=26, @rc-code=0, @op-status=0, @exec-
> time=71
> Jul 25 07:43:14 [1624] DVTVM0803.mse.am.mot.com crmd: info:
> match_graph_event: Action ClusterIP_monitor_1000 (5) confirmed
> on dvtvm0802 (rc=0)
> Jul 25 07:43:14 [1624] DVTVM0803.mse.am.mot.com crmd: notice:
> run_graph: Transition 9 (Complete=4, Pending=0, Fired=0,
> Skipped=0, Incomplete=0, Source=/var/lib/pacemaker/pengine/pe-input-
> 19.bz2): Complete
> Jul 25 07:43:14 [1624] DVTVM0803.mse.am.mot.com crmd: info:
> do_log: Input I_TE_SUCCESS received in state
> S_TRANSITION_ENGINE from notify_crmd
> Jul 25 07:43:14 [1618] DVTVM0803.mse.am.mot.com cib: info:
> cib_process_request: Completed cib_modify operation for
> section status: OK (rc=0, origin=dvtvm0802/crmd/103,
> version=0.20.101)
> Jul 25 07:43:14 [1624] DVTVM0803.mse.am.mot.com crmd: notice:
> do_state_transition: State transition S_TRANSITION_ENGINE ->
> S_IDLE | input=I_TE_SUCCESS cause=C_FSA_INTERNAL origin=notify_crmd
> Jul 25 07:43:15 [1622] DVTVM0803.mse.am.mot.com attrd: info:
> write_attribute: Sent update 10 with 2 changes for pingd,
> id=<n/a>, set=(null)
> Jul 25 07:43:15 [1618] DVTVM0803.mse.am.mot.com cib: info:
> cib_process_request: Forwarding cib_modify operation for
> section status to all (origin=local/attrd/10)
> Jul 25 07:43:15 [1618] DVTVM0803.mse.am.mot.com cib: info:
> cib_perform_op: Diff: --- 0.20.101 2
> Jul 25 07:43:15 [1618] DVTVM0803.mse.am.mot.com cib: info:
> cib_perform_op: Diff: +++ 0.20.102 (null)
> Jul 25 07:43:15 [1618] DVTVM0803.mse.am.mot.com cib: info:
> cib_perform_op: + /cib: @num_updates=102
> Jul 25 07:43:15 [1618] DVTVM0803.mse.am.mot.com cib: info:
> cib_perform_op: + /cib/status/node_state[@id='2']/transient_a
> ttributes[@id='2']/instance_attributes[@id='status-
> 2']/nvpair[@id='status-2-pingd']: @value=2000
> Jul 25 07:43:15 [1624] DVTVM0803.mse.am.mot.com crmd: info:
> abort_transition_graph: Transition aborted by status-2-pingd
> doing modify pingd=2000: Transient attribute change | cib=0.20.102
> source=abort_unless_down:343
> path=/cib/status/node_state[@id='2']/transient_attributes[@id='2']/in
> stance_attributes[@id='status-2']/nvpair[@id='status-2-pingd']
> complete=true
> Jul 25 07:43:15 [1624] DVTVM0803.mse.am.mot.com crmd: notice:
> do_state_transition: State transition S_IDLE ->
> S_POLICY_ENGINE | input=I_PE_CALC cause=C_FSA_INTERNAL
> origin=abort_transition_graph
> Jul 25 07:43:15 [1618] DVTVM0803.mse.am.mot.com cib: info:
> cib_process_request: Completed cib_modify operation for
> section status: OK (rc=0, origin=dvtvm0803/attrd/10,
> version=0.20.102)
> Jul 25 07:43:15 [1622] DVTVM0803.mse.am.mot.com attrd: info:
> attrd_cib_callback: Update 10 for pingd: OK (0)
> Jul 25 07:43:15 [1622] DVTVM0803.mse.am.mot.com attrd: info:
> attrd_cib_callback: Update 10 for pingd[dvtvm0802]=2000: OK
> (0)
> Jul 25 07:43:15 [1622] DVTVM0803.mse.am.mot.com attrd: info:
> attrd_cib_callback: Update 10 for pingd[dvtvm0803]=2000: OK
> (0)
> Jul 25 07:43:15 [1623] DVTVM0803.mse.am.mot.com pengine: notice:
> unpack_config: On loss of CCM Quorum: Ignore
> Jul 25 07:43:15 [1623] DVTVM0803.mse.am.mot.com pengine: info:
> determine_online_status: Node dvtvm0802 is online
> Jul 25 07:43:15 [1623] DVTVM0803.mse.am.mot.com pengine: info:
> determine_online_status: Node dvtvm0803 is online
> Jul 25 07:43:15 [1623] DVTVM0803.mse.am.mot.com pengine: info:
> unpack_node_loop: Node 1 is already processed
> Jul 25 07:43:15 [1623] DVTVM0803.mse.am.mot.com pengine: info:
> unpack_node_loop: Node 2 is already processed
> Jul 25 07:43:15 [1623] DVTVM0803.mse.am.mot.com pengine: info:
> unpack_node_loop: Node 1 is already processed
> Jul 25 07:43:15 [1623] DVTVM0803.mse.am.mot.com pengine: info:
> unpack_node_loop: Node 2 is already processed
> Jul 25 07:43:15 [1623] DVTVM0803.mse.am.mot.com pengine: info:
> common_print: ClusterIP (ocf::heartbeat:IPaddr2):
> Started dvtvm0802
> Jul 25 07:43:15 [1623] DVTVM0803.mse.am.mot.com pengine: info:
> clone_print: Clone Set: Connected-clone [Connected]
> Jul 25 07:43:15 [1623] DVTVM0803.mse.am.mot.com pengine: info:
> short_print: Started: [ dvtvm0802 dvtvm0803 ]
> Jul 25 07:43:15 [1623] DVTVM0803.mse.am.mot.com pengine: info:
> common_print: application (ocf::vendor:application):
> Started dvtvm0802
> Jul 25 07:43:15 [1623] DVTVM0803.mse.am.mot.com pengine: info:
> LogActions: Leave ClusterIP (Started dvtvm0802)
> Jul 25 07:43:15 [1623] DVTVM0803.mse.am.mot.com pengine: info:
> LogActions: Leave Connected:0 (Started dvtvm0802)
> Jul 25 07:43:15 [1623] DVTVM0803.mse.am.mot.com pengine: info:
> LogActions: Leave Connected:1 (Started dvtvm0803)
> Jul 25 07:43:15 [1623] DVTVM0803.mse.am.mot.com pengine: info:
> LogActions: Leave application (Started dvtvm0802)
> Jul 25 07:43:15 [1623] DVTVM0803.mse.am.mot.com pengine: notice:
> process_pe_message: Calculated transition 10, saving inputs in
> /var/lib/pacemaker/pengine/pe-input-20.bz2
> Jul 25 07:43:15 [1624] DVTVM0803.mse.am.mot.com crmd: info:
> do_state_transition: State transition S_POLICY_ENGINE ->
> S_TRANSITION_ENGINE | input=I_PE_SUCCESS cause=C_IPC_MESSAGE
> origin=handle_response
> Jul 25 07:43:15 [1624] DVTVM0803.mse.am.mot.com crmd: info:
> do_te_invoke: Processing graph 10 (ref=pe_calc-dc-1532518995-
> 81) derived from /var/lib/pacemaker/pengine/pe-input-20.bz2
> Jul 25 07:43:15 [1624] DVTVM0803.mse.am.mot.com crmd: notice:
> run_graph: Transition 10 (Complete=0, Pending=0, Fired=0,
> Skipped=0, Incomplete=0, Source=/var/lib/pacemaker/pengine/pe-input-
> 20.bz2): Complete
> Jul 25 07:43:15 [1624] DVTVM0803.mse.am.mot.com crmd: info:
> do_log: Input I_TE_SUCCESS received in state
> S_TRANSITION_ENGINE from notify_crmd
> Jul 25 07:43:15 [1624] DVTVM0803.mse.am.mot.com crmd: notice:
> do_state_transition: State transition S_TRANSITION_ENGINE ->
> S_IDLE | input=I_TE_SUCCESS cause=C_FSA_INTERNAL origin=notify_crmd
> Jul 25 07:43:20 [1618] DVTVM0803.mse.am.mot.com cib: info:
> cib_process_ping: Reporting our current digest to dvtvm0803:
> 6aaa74aa220cce54790a731cd758f8e3 for 0.20.102 (0x55d416545f90 0)
>
>
>
>
>
> On 7/24/18, 2:09 PM, "Users on behalf of Andrei Borzenkov"
> <users-bounces at clusterlabs.org on behalf of arvidjaar at gmail.com>
> wrote:
>
> > 24.07.2018 20:59, O'Donovan, Garret ?????:
> > > Hello, and thank you for adding me to the list.
> > >
> > > We are using Pacemaker in a two-node hot-warm redundancy
> > > configuration.
> > > Both nodes run ocf:pacemaker:ping (cloned) to monitor a ping
> > > group of
> > > devices. The nodes share a virtual IP using
> > > ocf:heartbeat:IPAddr2. Our
> > > applications run in either Primary mode (does all the work and
> > > sends
> > > status updates to its peer), or Standby mode (receives status
> > > updates
> > > and is ready to take over if current primary fails). We have
> > > constraints set up so that IPAddr2 fails over on any failure
> > > Pacemaker
> > > detects (including ping group failure), and the applications
> > > follow it.
> > >
> > > This works great for most use cases, but we have issues in one
> > > test
> > > case where we disconnect the node in standby (by yanking the eth
> > > cable)
> > > for about 30 seconds to a minute, and then reconnect it. The
> > > problem is
> > > that Pacemaker seems to put the Primary into standby for a very
> > > short
> > > time while reconnecting the two nodes, and then making it primary
> > > again.
> > >
> > > Is there any way to prevent Pacemaker from doing this? Detailed
> > > config
> > > info and log file snippet are below.
> > >
> > > - Regards
> > > - Garret O'Donovan
> > >
> > >
> > > PLATFORM
> > > This is all running this on CentOS 7
> > > (centos-release-7-4.1708.el7.centos.x86_64) on VM's (VMware ESXi
> > > 5.5).
> > > The two nodes are hosted on physically different servers.
> > >
> > > VERSION INFO
> > > corosync-2.4.3-2.el7_5.1.x86_64.rpm
> > > pacemaker-1.1.18-11.el7_5.2.x86_64.rpm
> > > pcs-0.9.162-5.el7.centos.1.x86_64.rpm
> > > resource-agents-3.9.5-124.el7.x86_64.rpm
> > >
> > > PACEMAKER CONFIGURATION
> > > [root at DVTVM0302 ~]# pcs config show
> > > Cluster Name: vendor1
> > > Corosync Nodes:
> > > dvtvm0302 dvtvm0303
> > > Pacemaker Nodes:
> > > dvtvm0302 dvtvm0303
> > >
> > > Resources:
> > > Resource: ClusterIP (class=ocf provider=heartbeat type=IPaddr2)
> > > Attributes: cidr_netmask=24 ip=10.144.101.210 nic=eth0
> > > Operations: monitor interval=1s (ClusterIP-monitor-interval-1s)
> > > start interval=0s timeout=20s
> > > (ClusterIP-start-interval-0s)
> > > stop interval=0s timeout=20s (ClusterIP-stop-
> > > interval-0s)
> > > Resource: application (class=ocf provider=vendor
> > > type=application)
> > > Operations: migrate_from interval=0s timeout=20
> > > (application-migrate_from-interval-0s)
> > > migrate_to interval=0s timeout=20
> > > (application-migrate_to-interval-0s)
> > > monitor interval=1s (application-monitor-interval-
> > > 1s)
> > > reload interval=0s timeout=20
> > > (application-reload-interval-0s)
> > > start interval=0s timeout=20
> > > (application-start-interval-0s)
> > > stop interval=0s timeout=20 (application-stop-
> > > interval-0s)
> > > Clone: Connected-clone
> > > Meta Attrs: interleave=true
> > > Resource: Connected (class=ocf provider=pacemaker type=ping)
> > > Attributes: attempts=2 dampen=1s debug=true
> > > host_list="10.10.24.5
> > > 10.10.24.18" multiplier=1000
> > > Operations: monitor interval=3s timeout=10
> > > (Connected-monitor-interval-3s)
> > > start interval=0 timeout=3 (Connected-start-
> > > interval-0)
> > > stop interval=0s timeout=20 (Connected-stop-
> > > interval-0s)
> > >
> > > Stonith Devices:
> >
> > You are risking real split brain here.
> >
> > > Fencing Levels:
> > >
> > > Location Constraints:
> > > Resource: ClusterIP
> > > Constraint: location-ClusterIP
> > > Rule: boolean-op=or score=-INFINITY (id:location-
> > > ClusterIP-rule)
> > > Expression: pingd lt 500 (id:location-ClusterIP-rule-
> > > expr)
> > > Expression: not_defined pingd
> > > (id:location-ClusterIP-rule-expr-1)
> > > Ordering Constraints:
> > > start ClusterIP then start application (kind:Mandatory)
> > > Colocation Constraints:
> > > ClusterIP with application (score:INFINITY)
> > > Ticket Constraints:
> > >
> > > Alerts:
> > > No alerts defined
> > >
> > > Resources Defaults:
> > > migration-threshold: 1
> > > failure-timeout: 5s
> > > cluster-recheck-interval: 5s
> > > resource-stickiness: INFINITY
> > > Operations Defaults:
> > > No defaults set
> > >
> > > Cluster Properties:
> > > cluster-infrastructure: corosync
> > > cluster-name: vendor1
> > > dc-version: 1.1.18-11.el7_5.2-2b07d5c5a9
> > > have-watchdog: false
> > > no-quorum-policy: ignore
> > > stonith-enabled: false
> > >
> > > Quorum:
> > > Options:
> > >
> > > COROSYNC CONFIG FILE:
> > >
> > > [root at DVTVM0302 corosync]# cat corosync.conf
> > > totem {
> > > version: 2
> > > cluster_name: vendor1
> > > secauth: off
> > > transport: udpu
> > > }
> > >
> > > nodelist {
> > > node {
> > > ring0_addr: dvtvm0302
> > > nodeid: 1
> > > }
> > >
> > > node {
> > > ring0_addr: dvtvm0303
> > > nodeid: 2
> > > }
> > > }
> > >
> > > quorum {
> > > provider: corosync_votequorum
> > > two_node: 1
> > > }
> > >
> > > logging {
> > > to_logfile: yes
> > > logfile: /var/log/cluster/corosync.log
> > > to_syslog: yes
> > > }
> > >
> > >
> > > LOGFILE:
> > > /var/log/cluster/corosync.log
> > >
>
>
>
>
>
> >
>
> _______________________________________________
> Users mailing list: Users at clusterlabs.org
> https://lists.clusterlabs.org/mailman/listinfo/users
>
> Project Home: http://www.clusterlabs.org
> Getting started: http://www.clusterlabs.org/doc/Cluster_from_Scratch.
> pdf
> Bugs: http://bugs.clusterlabs.org
--
Ken Gaillot <kgaillot at redhat.com>
More information about the Users
mailing list