Jan 25 17:02:02 apache(daemon_httpd)[18205]: INFO: Successfully retrieved http header at http://localhost:80 Jan 25 17:02:07 apache(daemon_httpd)[18268]: INFO: Successfully retrieved http header at http://localhost:80 Jan 25 17:02:08 [21936] node02.example.com attrd: info: pcmk_cpg_membership: Node 1 left group attrd (peer=node01.example.com, counter=267.0) Jan 25 17:02:08 [21936] node02.example.com attrd: info: crm_update_peer_proc: pcmk_cpg_membership: Node node01.example.com[1] - corosync-cpg is now offline Jan 25 17:02:08 [21933] node02.example.com cib: info: pcmk_cpg_membership: Node 1 left group cib (peer=node01.example.com, counter=267.0) Jan 25 17:02:08 [21938] node02.example.com crmd: info: pcmk_cpg_membership: Node 1 left group crmd (peer=node01.example.com, counter=267.0) Jan 25 17:02:08 [21933] node02.example.com cib: info: crm_update_peer_proc: pcmk_cpg_membership: Node node01.example.com[1] - corosync-cpg is now offline Jan 25 17:02:08 [21938] node02.example.com crmd: info: crm_update_peer_proc: pcmk_cpg_membership: Node node01.example.com[1] - corosync-cpg is now offline Jan 25 17:02:08 [21936] node02.example.com attrd: notice: crm_update_peer_state_iter: Node node01.example.com state is now lost | nodeid=1 previous=member source=crm_update_peer_proc Jan 25 17:02:08 [21938] node02.example.com crmd: info: peer_update_callback: Client node01.example.com/peer now has status [offline] (DC=true, changed=4000000) Jan 25 17:02:08 [21938] node02.example.com crmd: info: peer_update_callback: Peer node01.example.com left us Jan 25 17:02:08 [21936] node02.example.com attrd: notice: attrd_peer_remove: Removing all node01.example.com attributes for peer loss Jan 25 17:02:08 [21938] node02.example.com crmd: info: erase_status_tag: Deleting transient_attributes status entries for node01.example.com | xpath=//node_state[@uname='node01.example.com']/transient_attributes Jan 25 17:02:08 [21933] node02.example.com cib: notice: crm_update_peer_state_iter: Node node01.example.com state is now lost | nodeid=1 previous=member source=crm_update_peer_proc Jan 25 17:02:08 [21933] node02.example.com cib: info: crm_reap_dead_member: Removing node with name node01.example.com and id 1 from membership cache Jan 25 17:02:08 [21936] node02.example.com attrd: info: crm_reap_dead_member: Removing node with name node01.example.com and id 1 from membership cache Jan 25 17:02:08 [21933] node02.example.com cib: notice: reap_crm_member: Purged 1 peer with id=1 and/or uname=node01.example.com from the membership cache Jan 25 17:02:08 [21933] node02.example.com cib: info: pcmk_cpg_membership: Node 2 still member of group cib (peer=node02.example.com, counter=267.0) Jan 25 17:02:08 [21936] node02.example.com attrd: notice: reap_crm_member: Purged 1 peer with id=1 and/or uname=node01.example.com from the membership cache Jan 25 17:02:08 [21936] node02.example.com attrd: info: pcmk_cpg_membership: Node 2 still member of group attrd (peer=node02.example.com, counter=267.0) Jan 25 17:02:08 [21934] node02.example.com stonith-ng: info: pcmk_cpg_membership: Node 1 left group stonith-ng (peer=node01.example.com, counter=267.0) Jan 25 17:02:08 [21934] node02.example.com stonith-ng: info: crm_update_peer_proc: pcmk_cpg_membership: Node node01.example.com[1] - corosync-cpg is now offline Jan 25 17:02:08 [21932] node02.example.com pacemakerd: info: pcmk_cpg_membership: Node 1 left group pacemakerd (peer=node01.example.com, counter=267.0) Jan 25 17:02:08 [21938] node02.example.com crmd: warning: match_down_event: No reason to expect node 1 to be down Jan 25 17:02:08 [21932] node02.example.com pacemakerd: info: crm_update_peer_proc: pcmk_cpg_membership: Node node01.example.com[1] - corosync-cpg is now offline Jan 25 17:02:08 [21938] node02.example.com crmd: notice: peer_update_callback: Stonith/shutdown of node01.example.com not matched Jan 25 17:02:08 [21932] node02.example.com pacemakerd: info: pcmk_cpg_membership: Node 2 still member of group pacemakerd (peer=node02.example.com, counter=267.0) Jan 25 17:02:08 [21938] node02.example.com crmd: info: crm_update_peer_join: peer_update_callback: Node node01.example.com[1] - join-269 phase confirmed -> none Jan 25 17:02:08 [21938] node02.example.com crmd: info: abort_transition_graph: Transition aborted: Node failure | source=peer_update_callback:258 complete=true Jan 25 17:02:08 [21933] node02.example.com cib: info: cib_process_request: Forwarding cib_delete operation for section //node_state[@uname='node01.example.com']/transient_attributes to all (origin=local/crmd/46288) Jan 25 17:02:08 [21932] node02.example.com pacemakerd: info: crm_cs_flush: Sent 0 CPG messages (1 remaining, last=273): Try again (6) Jan 25 17:02:08 [21933] node02.example.com cib: info: crm_cs_flush: Sent 0 CPG messages (1 remaining, last=15972): Try again (6) Jan 25 17:02:08 [21938] node02.example.com crmd: info: pcmk_cpg_membership: Node 2 still member of group crmd (peer=node02.example.com, counter=267.0) Jan 25 17:02:08 [21938] node02.example.com crmd: notice: do_state_transition: State transition S_IDLE -> S_INTEGRATION | input=I_NODE_JOIN cause=C_FSA_INTERNAL origin=check_join_state Jan 25 17:02:08 [21933] node02.example.com cib: info: cib_process_request: Forwarding cib_modify operation for section status to all (origin=local/crmd/46289) Jan 25 17:02:08 [21938] node02.example.com crmd: info: do_dc_join_offer_one: An unknown node joined - (re-)offer to any unconfirmed nodes Jan 25 17:02:08 [21938] node02.example.com crmd: info: join_make_offer: Making join offers based on membership 9184 Jan 25 17:02:08 [21938] node02.example.com crmd: info: join_make_offer: Skipping node02.example.com: already known 4 Jan 25 17:02:08 [21938] node02.example.com crmd: info: join_make_offer: Not making an offer to node01.example.com: not active (member) Jan 25 17:02:08 [21938] node02.example.com crmd: info: abort_transition_graph: Transition aborted: Peer Halt | source=do_te_invoke:150 complete=true Jan 25 17:02:08 [21934] node02.example.com stonith-ng: notice: crm_update_peer_state_iter: Node node01.example.com state is now lost | nodeid=1 previous=member source=crm_update_peer_proc Jan 25 17:02:08 [21938] node02.example.com crmd: info: do_state_transition: State transition S_INTEGRATION -> S_FINALIZE_JOIN | input=I_INTEGRATED cause=C_FSA_INTERNAL origin=check_join_state Jan 25 17:02:08 [21938] node02.example.com crmd: info: crmd_join_phase_log: join-269: node02.example.com=confirmed Jan 25 17:02:08 [21934] node02.example.com stonith-ng: info: crm_cs_flush: Sent 0 CPG messages (1 remaining, last=403): Try again (6) Jan 25 17:02:08 [21934] node02.example.com stonith-ng: info: crm_reap_dead_member: Removing node with name node01.example.com and id 1 from membership cache Jan 25 17:02:08 [21934] node02.example.com stonith-ng: notice: reap_crm_member: Purged 1 peer with id=1 and/or uname=node01.example.com from the membership cache Jan 25 17:02:08 [21934] node02.example.com stonith-ng: info: pcmk_cpg_membership: Node 2 still member of group stonith-ng (peer=node02.example.com, counter=267.0) Jan 25 17:02:08 [21938] node02.example.com crmd: info: crmd_join_phase_log: join-269: node01.example.com=none Jan 25 17:02:08 [21938] node02.example.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 Jan 25 17:02:08 [21938] node02.example.com crmd: info: abort_transition_graph: Transition aborted: Peer Cancelled | source=do_te_invoke:143 complete=true Jan 25 17:02:08 [21933] node02.example.com cib: info: cib_process_request: Forwarding cib_modify operation for section nodes to all (origin=local/crmd/46292) Jan 25 17:02:08 [21933] node02.example.com cib: info: cib_process_request: Forwarding cib_modify operation for section status to all (origin=local/crmd/46293) Jan 25 17:02:08 [21933] node02.example.com cib: info: cib_process_request: Forwarding cib_modify operation for section cib to all (origin=local/crmd/46294) Jan 25 17:02:08 [21932] node02.example.com pacemakerd: info: crm_cs_flush: Sent 0 CPG messages (1 remaining, last=273): Try again (6) Jan 25 17:02:08 [21934] node02.example.com stonith-ng: info: crm_cs_flush: Sent 0 CPG messages (1 remaining, last=403): Try again (6) Jan 25 17:02:08 [21933] node02.example.com cib: info: crm_cs_flush: Sent 0 CPG messages (5 remaining, last=15972): Try again (6) Jan 25 17:02:08 [21934] node02.example.com stonith-ng: info: crm_cs_flush: Sent 0 CPG messages (1 remaining, last=403): Try again (6) Jan 25 17:02:08 [21932] node02.example.com pacemakerd: info: crm_cs_flush: Sent 0 CPG messages (1 remaining, last=273): Try again (6) Jan 25 17:02:08 [21933] node02.example.com cib: info: crm_cs_flush: Sent 0 CPG messages (5 remaining, last=15972): Try again (6) Jan 25 17:02:09 [21934] node02.example.com stonith-ng: info: crm_cs_flush: Sent 0 CPG messages (1 remaining, last=403): Try again (6) Jan 25 17:02:09 [21932] node02.example.com pacemakerd: info: crm_cs_flush: Sent 0 CPG messages (1 remaining, last=273): Try again (6) Jan 25 17:02:09 [21933] node02.example.com cib: info: crm_cs_flush: Sent 0 CPG messages (5 remaining, last=15972): Try again (6) Jan 25 17:02:09 [21934] node02.example.com stonith-ng: info: crm_cs_flush: Sent 0 CPG messages (1 remaining, last=403): Try again (6) Jan 25 17:02:09 [21932] node02.example.com pacemakerd: info: crm_cs_flush: Sent 0 CPG messages (1 remaining, last=273): Try again (6) Jan 25 17:02:09 [21934] node02.example.com stonith-ng: info: pcmk_cpg_membership: Node 1 joined group stonith-ng (counter=268.0) Jan 25 17:02:09 [21936] node02.example.com attrd: info: pcmk_cpg_membership: Node 1 joined group attrd (counter=268.0) Jan 25 17:02:09 [21933] node02.example.com cib: info: pcmk_cpg_membership: Node 1 joined group cib (counter=268.0) Jan 25 17:02:09 [21932] node02.example.com pacemakerd: info: pcmk_cpg_membership: Node 1 joined group pacemakerd (counter=268.0) Jan 25 17:02:09 [21932] node02.example.com pacemakerd: info: pcmk_cpg_membership: Node 1 still member of group pacemakerd (peer=node01.example.com, counter=268.0) Jan 25 17:02:09 [21932] node02.example.com pacemakerd: info: crm_update_peer_proc: pcmk_cpg_membership: Node node01.example.com[1] - corosync-cpg is now online Jan 25 17:02:09 [21932] node02.example.com pacemakerd: info: pcmk_cpg_membership: Node 2 still member of group pacemakerd (peer=node02.example.com, counter=268.1) Jan 25 17:02:09 [21936] node02.example.com attrd: info: crm_get_peer: Created entry 7200fc85-2d0b-4779-8c05-0aa03b6b09ac/0x5557c06964b0 for node node01.example.com/1 (2 total) Jan 25 17:02:09 [21934] node02.example.com stonith-ng: info: crm_get_peer: Created entry fc825145-fb0a-44f5-8b53-0668de839b74/0x5592ba1efae0 for node node01.example.com/1 (2 total) Jan 25 17:02:09 [21936] node02.example.com attrd: info: crm_get_peer: Node 1 is now known as node01.example.com Jan 25 17:02:09 [21934] node02.example.com stonith-ng: info: crm_get_peer: Node 1 is now known as node01.example.com Jan 25 17:02:09 [21936] node02.example.com attrd: info: crm_get_peer: Node 1 has uuid 1 Jan 25 17:02:09 [21936] node02.example.com attrd: info: pcmk_cpg_membership: Node 1 still member of group attrd (peer=node01.example.com, counter=268.0) Jan 25 17:02:09 [21936] node02.example.com attrd: info: crm_update_peer_proc: pcmk_cpg_membership: Node node01.example.com[1] - corosync-cpg is now online Jan 25 17:02:09 [21936] node02.example.com attrd: notice: crm_update_peer_state_iter: Node node01.example.com state is now member | nodeid=1 previous=unknown source=crm_update_peer_proc Jan 25 17:02:09 [21934] node02.example.com stonith-ng: info: crm_get_peer: Node 1 has uuid 1 Jan 25 17:02:09 [21934] node02.example.com stonith-ng: info: pcmk_cpg_membership: Node 1 still member of group stonith-ng (peer=node01.example.com, counter=268.0) Jan 25 17:02:09 [21934] node02.example.com stonith-ng: info: crm_update_peer_proc: pcmk_cpg_membership: Node node01.example.com[1] - corosync-cpg is now online Jan 25 17:02:09 [21934] node02.example.com stonith-ng: notice: crm_update_peer_state_iter: Node node01.example.com state is now member | nodeid=1 previous=unknown source=crm_update_peer_proc Jan 25 17:02:09 [21934] node02.example.com stonith-ng: info: pcmk_cpg_membership: Node 2 still member of group stonith-ng (peer=node02.example.com, counter=268.1) Jan 25 17:02:09 [21936] node02.example.com attrd: info: crm_cs_flush: Sent 0 CPG messages (1 remaining, last=5929399): Try again (6) Jan 25 17:02:09 [21936] node02.example.com attrd: info: pcmk_cpg_membership: Node 2 still member of group attrd (peer=node02.example.com, counter=268.1) Jan 25 17:02:09 [21933] node02.example.com cib: info: crm_get_peer: Created entry 1651d065-cf31-481e-8e70-64683f038c71/0x5646ba971080 for node node01.example.com/1 (2 total) Jan 25 17:02:09 [21933] node02.example.com cib: info: crm_get_peer: Node 1 is now known as node01.example.com Jan 25 17:02:09 [21933] node02.example.com cib: info: crm_get_peer: Node 1 has uuid 1 Jan 25 17:02:09 [21933] node02.example.com cib: info: pcmk_cpg_membership: Node 1 still member of group cib (peer=node01.example.com, counter=268.0) Jan 25 17:02:09 [21933] node02.example.com cib: info: crm_update_peer_proc: pcmk_cpg_membership: Node node01.example.com[1] - corosync-cpg is now online Jan 25 17:02:09 [21933] node02.example.com cib: notice: crm_update_peer_state_iter: Node node01.example.com state is now member | nodeid=1 previous=unknown source=crm_update_peer_proc Jan 25 17:02:09 [21933] node02.example.com cib: info: pcmk_cpg_membership: Node 2 still member of group cib (peer=node02.example.com, counter=268.1) Jan 25 17:02:09 [21932] node02.example.com pacemakerd: info: pcmk_quorum_notification: Quorum retained | membership=9196 members=2 Jan 25 17:02:09 [21933] node02.example.com cib: info: crm_cs_flush: Sent 5 CPG messages (0 remaining, last=15977): OK (1) Jan 25 17:02:09 [21933] node02.example.com cib: info: cib_perform_op: Diff: --- 0.93.3 2 Jan 25 17:02:09 [21933] node02.example.com cib: info: cib_perform_op: Diff: +++ 0.93.4 96a2792fd8c1e6d8fff08f23e1100b4d Jan 25 17:02:09 [21933] node02.example.com cib: info: cib_perform_op: -- /cib/status/node_state[@id='1']/transient_attributes[@id='1'] Jan 25 17:02:09 [21933] node02.example.com cib: info: cib_perform_op: + /cib: @num_updates=4 Jan 25 17:02:09 [21933] node02.example.com cib: info: cib_process_request: Completed cib_delete operation for section //node_state[@uname='node01.example.com']/transient_attributes: OK (rc=0, origin=node02.example.com/crmd/46288, version=0.93.4) Jan 25 17:02:09 [21933] node02.example.com cib: info: cib_perform_op: Diff: --- 0.93.4 2 Jan 25 17:02:09 [21933] node02.example.com cib: info: cib_perform_op: Diff: +++ 0.93.5 (null) Jan 25 17:02:09 [21933] node02.example.com cib: info: cib_perform_op: + /cib: @num_updates=5 Jan 25 17:02:09 [21933] node02.example.com cib: info: cib_perform_op: + /cib/status/node_state[@id='1']: @crmd=offline, @crm-debug-origin=peer_update_callback Jan 25 17:02:09 [21933] node02.example.com cib: info: cib_process_request: Completed cib_modify operation for section status: OK (rc=0, origin=node02.example.com/crmd/46289, version=0.93.5) Jan 25 17:02:09 [21933] node02.example.com cib: info: cib_process_request: Completed cib_modify operation for section nodes: OK (rc=0, origin=node02.example.com/crmd/46292, version=0.93.5) Jan 25 17:02:09 [21933] node02.example.com cib: info: cib_perform_op: Diff: --- 0.93.5 2 Jan 25 17:02:09 [21933] node02.example.com cib: info: cib_perform_op: Diff: +++ 0.93.6 (null) Jan 25 17:02:09 [21933] node02.example.com cib: info: cib_perform_op: + /cib: @num_updates=6 Jan 25 17:02:09 [21933] node02.example.com cib: info: cib_perform_op: + /cib/status/node_state[@id='1']: @crm-debug-origin=do_state_transition, @join=down Jan 25 17:02:09 [21933] node02.example.com cib: info: cib_perform_op: + /cib/status/node_state[@id='2']: @crm-debug-origin=do_state_transition Jan 25 17:02:09 [21933] node02.example.com cib: info: cib_process_request: Completed cib_modify operation for section status: OK (rc=0, origin=node02.example.com/crmd/46293, version=0.93.6) Jan 25 17:02:09 [21933] node02.example.com cib: info: cib_process_request: Completed cib_modify operation for section cib: OK (rc=0, origin=node02.example.com/crmd/46294, version=0.93.6) Jan 25 17:02:09 [21938] node02.example.com crmd: info: abort_transition_graph: Transition aborted by deletion of transient_attributes[@id='1']: Transient attribute change | cib=0.93.4 source=abort_unless_down:357 path=/cib/status/node_state[@id='1']/transient_attributes[@id='1'] complete=true Jan 25 17:02:09 [21938] node02.example.com crmd: info: pcmk_quorum_notification: Quorum retained | membership=9196 members=2 Jan 25 17:02:09 [21938] node02.example.com crmd: info: pcmk_cpg_membership: Node 1 joined group crmd (counter=268.0) Jan 25 17:02:09 [21938] node02.example.com crmd: info: pcmk_cpg_membership: Node 1 still member of group crmd (peer=node01.example.com, counter=268.0) Jan 25 17:02:09 [21938] node02.example.com crmd: info: crm_update_peer_proc: pcmk_cpg_membership: Node node01.example.com[1] - corosync-cpg is now online Jan 25 17:02:09 [21938] node02.example.com crmd: info: peer_update_callback: Client node01.example.com/peer now has status [online] (DC=true, changed=4000000) Jan 25 17:02:09 [21938] node02.example.com crmd: info: pcmk_cpg_membership: Node 2 still member of group crmd (peer=node02.example.com, counter=268.1) Jan 25 17:02:09 [21938] node02.example.com crmd: info: do_state_transition: State transition S_POLICY_ENGINE -> S_INTEGRATION | input=I_NODE_JOIN cause=C_FSA_INTERNAL origin=peer_update_callback Jan 25 17:02:09 [21938] node02.example.com crmd: info: do_dc_join_offer_one: An unknown node joined - (re-)offer to any unconfirmed nodes Jan 25 17:02:09 [21938] node02.example.com crmd: info: join_make_offer: Making join offers based on membership 9196 Jan 25 17:02:09 [21938] node02.example.com crmd: info: join_make_offer: Skipping node02.example.com: already known 4 Jan 25 17:02:09 [21938] node02.example.com crmd: info: join_make_offer: join-269: Sending offer to node01.example.com Jan 25 17:02:09 [21938] node02.example.com crmd: info: crm_update_peer_join: join_make_offer: Node node01.example.com[1] - join-269 phase none -> welcomed Jan 25 17:02:09 [21933] node02.example.com cib: info: cib_process_request: Forwarding cib_modify operation for section nodes to all (origin=local/crmd/46299) Jan 25 17:02:09 [21933] node02.example.com cib: info: cib_process_request: Forwarding cib_modify operation for section status to all (origin=local/crmd/46300) Jan 25 17:02:09 [21933] node02.example.com cib: info: cib_process_request: Forwarding cib_modify operation for section status to all (origin=local/crmd/46301) Jan 25 17:02:09 [21933] node02.example.com cib: info: cib_process_request: Completed cib_modify operation for section nodes: OK (rc=0, origin=node02.example.com/crmd/46299, version=0.93.6) Jan 25 17:02:09 [21933] node02.example.com cib: info: cib_perform_op: Diff: --- 0.93.6 2 Jan 25 17:02:09 [21933] node02.example.com cib: info: cib_perform_op: Diff: +++ 0.93.7 (null) Jan 25 17:02:09 [21933] node02.example.com cib: info: cib_perform_op: + /cib: @num_updates=7 Jan 25 17:02:09 [21933] node02.example.com cib: info: cib_perform_op: + /cib/status/node_state[@id='1']: @crm-debug-origin=post_cache_update Jan 25 17:02:09 [21933] node02.example.com cib: info: cib_perform_op: + /cib/status/node_state[@id='2']: @crm-debug-origin=post_cache_update Jan 25 17:02:09 [21933] node02.example.com cib: info: cib_process_request: Completed cib_modify operation for section status: OK (rc=0, origin=node02.example.com/crmd/46300, version=0.93.7) Jan 25 17:02:09 [21933] node02.example.com cib: info: cib_perform_op: Diff: --- 0.93.7 2 Jan 25 17:02:09 [21933] node02.example.com cib: info: cib_perform_op: Diff: +++ 0.93.8 (null) Jan 25 17:02:09 [21933] node02.example.com cib: info: cib_perform_op: + /cib: @num_updates=8 Jan 25 17:02:09 [21933] node02.example.com cib: info: cib_perform_op: + /cib/status/node_state[@id='1']: @crmd=online, @crm-debug-origin=peer_update_callback Jan 25 17:02:09 [21933] node02.example.com cib: info: cib_process_request: Completed cib_modify operation for section status: OK (rc=0, origin=node02.example.com/crmd/46301, version=0.93.8) Jan 25 17:02:09 [21934] node02.example.com stonith-ng: info: crm_cs_flush: Sent 3 CPG messages (0 remaining, last=406): OK (1) Jan 25 17:02:09 [21932] node02.example.com pacemakerd: info: crm_cs_flush: Sent 2 CPG messages (0 remaining, last=275): OK (1) Jan 25 17:02:09 [21932] node02.example.com pacemakerd: info: mcp_cpg_deliver: Ignoring process list sent by peer for local node Jan 25 17:02:09 [21932] node02.example.com pacemakerd: info: mcp_cpg_deliver: Ignoring process list sent by peer for local node Jan 25 17:02:09 [21938] node02.example.com crmd: info: election_count_vote: Election 289 (owner: 1) pass: vote from node01.example.com (Uptime) Jan 25 17:02:09 [21938] node02.example.com crmd: info: do_state_transition: State transition S_INTEGRATION -> S_ELECTION | input=I_ELECTION cause=C_FSA_INTERNAL origin=do_election_count_vote Jan 25 17:02:09 [21938] node02.example.com crmd: info: update_dc: Unset DC. Was node02.example.com Jan 25 17:02:09 [21938] node02.example.com crmd: info: election_count_vote: Election 290 (owner: 1) pass: vote from node01.example.com (Uptime) Jan 25 17:02:09 [21938] node02.example.com crmd: info: election_complete: Election election-0 complete Jan 25 17:02:09 [21938] node02.example.com crmd: info: election_timeout_popped: Election failed: Declaring ourselves the winner Jan 25 17:02:09 [21938] node02.example.com crmd: info: do_log: Input I_ELECTION_DC received in state S_ELECTION from election_timeout_popped Jan 25 17:02:09 [21938] node02.example.com crmd: notice: do_state_transition: State transition S_ELECTION -> S_INTEGRATION | input=I_ELECTION_DC cause=C_TIMER_POPPED origin=election_timeout_popped Jan 25 17:02:09 [21936] node02.example.com attrd: info: crm_cs_flush: Sent 2 CPG messages (0 remaining, last=5929401): OK (1) Jan 25 17:02:09 [21933] node02.example.com cib: info: cib_perform_op: Diff: --- 0.93.8 2 Jan 25 17:02:09 [21933] node02.example.com cib: info: cib_perform_op: Diff: +++ 0.93.9 (null) Jan 25 17:02:09 [21933] node02.example.com cib: info: cib_perform_op: -- /cib/status/node_state[@id='2']/transient_attributes[@id='2'] Jan 25 17:02:09 [21933] node02.example.com cib: info: cib_perform_op: + /cib: @num_updates=9 Jan 25 17:02:09 [21933] node02.example.com cib: info: cib_process_request: Completed cib_delete operation for section //node_state[@uname='node02.example.com']/transient_attributes: OK (rc=0, origin=node01.example.com/crmd/3516, version=0.93.9) Jan 25 17:02:09 [21938] node02.example.com crmd: info: do_dc_takeover: Taking over DC status for this partition Jan 25 17:02:09 [21933] node02.example.com cib: info: cib_process_request: Completed cib_master operation for section 'all': OK (rc=0, origin=local/crmd/46302, version=0.93.9) Jan 25 17:02:09 [21933] node02.example.com cib: info: cib_process_request: Forwarding cib_modify operation for section cib to all (origin=local/crmd/46303) Jan 25 17:02:09 [21933] node02.example.com cib: info: cib_process_request: Forwarding cib_modify operation for section crm_config to all (origin=local/crmd/46305) Jan 25 17:02:09 [21933] node02.example.com cib: info: cib_process_request: Completed cib_modify operation for section cib: OK (rc=0, origin=node02.example.com/crmd/46303, version=0.93.9) Jan 25 17:02:09 [21933] node02.example.com cib: info: cib_process_request: Completed cib_modify operation for section crm_config: OK (rc=0, origin=node02.example.com/crmd/46305, version=0.93.9) Jan 25 17:02:09 [21933] node02.example.com cib: info: cib_process_request: Forwarding cib_modify operation for section crm_config to all (origin=local/crmd/46307) Jan 25 17:02:09 [21938] node02.example.com crmd: info: crm_update_peer_join: initialize_join: Node node02.example.com[2] - join-270 phase confirmed -> none Jan 25 17:02:09 [21938] node02.example.com crmd: info: crm_update_peer_join: initialize_join: Node node01.example.com[1] - join-270 phase welcomed -> none Jan 25 17:02:09 [21938] node02.example.com crmd: info: join_make_offer: join-270: Sending offer to node02.example.com Jan 25 17:02:09 [21938] node02.example.com crmd: info: crm_update_peer_join: join_make_offer: Node node02.example.com[2] - join-270 phase none -> welcomed Jan 25 17:02:09 [21938] node02.example.com crmd: info: join_make_offer: join-270: Sending offer to node01.example.com Jan 25 17:02:09 [21938] node02.example.com crmd: info: crm_update_peer_join: join_make_offer: Node node01.example.com[1] - join-270 phase none -> welcomed Jan 25 17:02:09 [21938] node02.example.com crmd: info: do_dc_join_offer_all: join-270: Waiting on 2 outstanding join acks Jan 25 17:02:09 [21938] node02.example.com crmd: warning: do_log: Input I_ELECTION_DC received in state S_INTEGRATION from do_election_check Jan 25 17:02:09 [21938] node02.example.com crmd: info: crm_update_peer_join: initialize_join: Node node02.example.com[2] - join-271 phase welcomed -> none Jan 25 17:02:09 [21938] node02.example.com crmd: info: crm_update_peer_join: initialize_join: Node node01.example.com[1] - join-271 phase welcomed -> none Jan 25 17:02:09 [21938] node02.example.com crmd: info: join_make_offer: join-271: Sending offer to node02.example.com Jan 25 17:02:09 [21938] node02.example.com crmd: info: crm_update_peer_join: join_make_offer: Node node02.example.com[2] - join-271 phase none -> welcomed Jan 25 17:02:09 [21938] node02.example.com crmd: info: join_make_offer: join-271: Sending offer to node01.example.com Jan 25 17:02:09 [21938] node02.example.com crmd: info: crm_update_peer_join: join_make_offer: Node node01.example.com[1] - join-271 phase none -> welcomed Jan 25 17:02:09 [21938] node02.example.com crmd: info: do_dc_join_offer_all: join-271: Waiting on 2 outstanding join acks Jan 25 17:02:09 [21938] node02.example.com crmd: info: update_dc: Set DC to node02.example.com (3.0.14) Jan 25 17:02:09 [21933] node02.example.com cib: info: cib_process_request: Completed cib_modify operation for section crm_config: OK (rc=0, origin=node02.example.com/crmd/46307, version=0.93.9) Jan 25 17:02:09 [21933] node02.example.com cib: info: cib_process_request: Forwarding cib_modify operation for section crm_config to all (origin=local/crmd/46309) Jan 25 17:02:09 [21938] node02.example.com crmd: info: crm_update_peer_join: do_dc_join_filter_offer: Node node02.example.com[2] - join-271 phase welcomed -> integrated Jan 25 17:02:09 [21933] node02.example.com cib: info: cib_process_request: Completed cib_modify operation for section crm_config: OK (rc=0, origin=node02.example.com/crmd/46309, version=0.93.9) Jan 25 17:02:09 [21938] node02.example.com crmd: info: crm_update_peer_join: do_dc_join_filter_offer: Node node01.example.com[1] - join-271 phase welcomed -> integrated Jan 25 17:02:09 [21938] node02.example.com crmd: info: do_state_transition: State transition S_INTEGRATION -> S_FINALIZE_JOIN | input=I_INTEGRATED cause=C_FSA_INTERNAL origin=check_join_state Jan 25 17:02:09 [21938] node02.example.com crmd: info: crmd_join_phase_log: join-271: node02.example.com=integrated Jan 25 17:02:09 [21938] node02.example.com crmd: info: crmd_join_phase_log: join-271: node01.example.com=integrated Jan 25 17:02:09 [21938] node02.example.com crmd: info: do_dc_join_finalize: join-271: Syncing our CIB to the rest of the cluster Jan 25 17:02:09 [21938] node02.example.com crmd: info: crm_update_peer_join: finalize_join_for: Node node02.example.com[2] - join-271 phase integrated -> finalized Jan 25 17:02:09 [21933] node02.example.com cib: info: cib_process_request: Forwarding cib_modify operation for section nodes to all (origin=local/crmd/46314) Jan 25 17:02:09 [21938] node02.example.com crmd: info: crm_update_peer_join: finalize_join_for: Node node01.example.com[1] - join-271 phase integrated -> finalized Jan 25 17:02:09 [21933] node02.example.com cib: info: cib_process_request: Forwarding cib_modify operation for section nodes to all (origin=local/crmd/46315) Jan 25 17:02:09 [21938] node02.example.com crmd: info: crm_update_peer_join: do_dc_join_ack: Node node02.example.com[2] - join-271 phase finalized -> confirmed Jan 25 17:02:09 [21938] node02.example.com crmd: info: do_dc_join_ack: join-271: Updating node state to member for node02.example.com Jan 25 17:02:09 [21938] node02.example.com crmd: info: erase_status_tag: Deleting lrm status entries for node02.example.com | xpath=//node_state[@uname='node02.example.com']/lrm Jan 25 17:02:09 [21933] node02.example.com cib: info: cib_process_replace: Digest matched on replace from node02.example.com: 28f82f49cf9d497ceb169cf85f1d7cfb Jan 25 17:02:09 [21933] node02.example.com cib: info: cib_process_replace: Replaced 0.93.9 with 0.93.9 from node02.example.com Jan 25 17:02:09 [21938] node02.example.com crmd: info: crm_update_peer_join: do_dc_join_ack: Node node01.example.com[1] - join-271 phase finalized -> confirmed Jan 25 17:02:09 [21938] node02.example.com crmd: info: do_dc_join_ack: join-271: Updating node state to member for node01.example.com Jan 25 17:02:09 [21938] node02.example.com crmd: info: erase_status_tag: Deleting lrm status entries for node01.example.com | xpath=//node_state[@uname='node01.example.com']/lrm Jan 25 17:02:09 [21933] node02.example.com cib: info: cib_process_request: Completed cib_replace operation for section 'all': OK (rc=0, origin=node02.example.com/crmd/46313, version=0.93.9) Jan 25 17:02:09 [21933] node02.example.com cib: info: cib_process_request: Completed cib_modify operation for section nodes: OK (rc=0, origin=node02.example.com/crmd/46314, version=0.93.9) Jan 25 17:02:09 [21933] node02.example.com cib: info: cib_process_request: Completed cib_modify operation for section nodes: OK (rc=0, origin=node02.example.com/crmd/46315, version=0.93.9) Jan 25 17:02:09 [21933] node02.example.com cib: info: cib_process_request: Forwarding cib_delete operation for section //node_state[@uname='node02.example.com']/lrm to all (origin=local/crmd/46316) Jan 25 17:02:09 [21933] node02.example.com cib: info: cib_process_request: Forwarding cib_modify operation for section status to all (origin=local/crmd/46317) Jan 25 17:02:09 [21933] node02.example.com cib: info: cib_process_request: Forwarding cib_delete operation for section //node_state[@uname='node01.example.com']/lrm to all (origin=local/crmd/46318) Jan 25 17:02:09 [21933] node02.example.com cib: info: cib_process_request: Forwarding cib_modify operation for section status to all (origin=local/crmd/46319) Jan 25 17:02:09 [21933] node02.example.com cib: info: cib_perform_op: Diff: --- 0.93.9 2 Jan 25 17:02:09 [21933] node02.example.com cib: info: cib_perform_op: Diff: +++ 0.93.10 (null) Jan 25 17:02:09 [21933] node02.example.com cib: info: cib_perform_op: -- /cib/status/node_state[@id='2']/lrm[@id='2'] Jan 25 17:02:09 [21933] node02.example.com cib: info: cib_perform_op: + /cib: @num_updates=10 Jan 25 17:02:09 [21933] node02.example.com cib: info: cib_process_request: Completed cib_delete operation for section //node_state[@uname='node02.example.com']/lrm: OK (rc=0, origin=node02.example.com/crmd/46316, version=0.93.10) Jan 25 17:02:09 [21933] node02.example.com cib: info: cib_perform_op: Diff: --- 0.93.10 2 Jan 25 17:02:09 [21933] node02.example.com cib: info: cib_perform_op: Diff: +++ 0.93.11 (null) Jan 25 17:02:09 [21933] node02.example.com cib: info: cib_perform_op: + /cib: @num_updates=11 Jan 25 17:02:09 [21933] node02.example.com cib: info: cib_perform_op: + /cib/status/node_state[@id='2']: @crm-debug-origin=do_lrm_query_internal Jan 25 17:02:09 [21933] node02.example.com cib: info: cib_perform_op: ++ /cib/status/node_state[@id='2']: Jan 25 17:02:09 [21933] node02.example.com cib: info: cib_perform_op: ++ Jan 25 17:02:09 [21933] node02.example.com cib: info: cib_perform_op: ++ Jan 25 17:02:09 [21933] node02.example.com cib: info: cib_perform_op: ++ Jan 25 17:02:09 [21933] node02.example.com cib: info: cib_perform_op: ++ Jan 25 17:02:09 [21933] node02.example.com cib: info: cib_perform_op: ++ Jan 25 17:02:09 [21933] node02.example.com cib: info: cib_perform_op: ++ Jan 25 17:02:09 [21933] node02.example.com cib: info: cib_perform_op: ++ Jan 25 17:02:09 [21933] node02.example.com cib: info: cib_perform_op: ++ Jan 25 17:02:09 [21933] node02.example.com cib: info: cib_perform_op: ++ Jan 25 17:02:09 [21933] node02.example.com cib: info: cib_perform_op: ++ Jan 25 17:02:09 [21933] node02.example.com cib: info: cib_perform_op: ++ Jan 25 17:02:09 [21933] node02.example.com cib: info: cib_perform_op: ++ Jan 25 17:02:09 [21933] node02.example.com cib: info: cib_perform_op: ++ Jan 25 17:02:09 [21933] node02.example.com cib: info: cib_perform_op: ++ Jan 25 17:02:09 [21933] node02.example.com cib: info: cib_process_request: Completed cib_modify operation for section status: OK (rc=0, origin=node02.example.com/crmd/46317, version=0.93.11) Jan 25 17:02:09 [21938] node02.example.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 Jan 25 17:02:09 [21938] node02.example.com crmd: info: abort_transition_graph: Transition aborted: Peer Cancelled | source=do_te_invoke:143 complete=true Jan 25 17:02:09 [21933] node02.example.com cib: info: cib_perform_op: Diff: --- 0.93.11 2 Jan 25 17:02:09 [21933] node02.example.com cib: info: cib_perform_op: Diff: +++ 0.93.12 (null) Jan 25 17:02:09 [21933] node02.example.com cib: info: cib_perform_op: -- /cib/status/node_state[@id='1']/lrm[@id='1'] Jan 25 17:02:09 [21933] node02.example.com cib: info: cib_perform_op: + /cib: @num_updates=12 Jan 25 17:02:09 [21933] node02.example.com cib: info: cib_process_request: Completed cib_delete operation for section //node_state[@uname='node01.example.com']/lrm: OK (rc=0, origin=node02.example.com/crmd/46318, version=0.93.12) Jan 25 17:02:09 [21938] node02.example.com crmd: info: abort_transition_graph: Transition aborted by deletion of lrm[@id='1']: Resource state removal | cib=0.93.12 source=abort_unless_down:357 path=/cib/status/node_state[@id='1']/lrm[@id='1'] complete=true Jan 25 17:02:09 [21933] node02.example.com cib: info: cib_perform_op: Diff: --- 0.93.12 2 Jan 25 17:02:09 [21933] node02.example.com cib: info: cib_perform_op: Diff: +++ 0.93.13 (null) Jan 25 17:02:09 [21933] node02.example.com cib: info: cib_perform_op: + /cib: @num_updates=13 Jan 25 17:02:09 [21933] node02.example.com cib: info: cib_perform_op: + /cib/status/node_state[@id='1']: @crm-debug-origin=do_lrm_query_internal, @join=member Jan 25 17:02:09 [21933] node02.example.com cib: info: cib_perform_op: ++ /cib/status/node_state[@id='1']: Jan 25 17:02:09 [21933] node02.example.com cib: info: cib_perform_op: ++ Jan 25 17:02:09 [21933] node02.example.com cib: info: cib_perform_op: ++ Jan 25 17:02:09 [21933] node02.example.com cib: info: cib_perform_op: ++ Jan 25 17:02:09 [21933] node02.example.com cib: info: cib_perform_op: ++ Jan 25 17:02:09 [21933] node02.example.com cib: info: cib_perform_op: ++ Jan 25 17:02:09 [21933] node02.example.com cib: info: cib_perform_op: ++ Jan 25 17:02:09 [21933] node02.example.com cib: info: cib_perform_op: ++ Jan 25 17:02:09 [21933] node02.example.com cib: info: cib_perform_op: ++ Jan 25 17:02:09 [21933] node02.example.com cib: info: cib_perform_op: ++ Jan 25 17:02:09 [21933] node02.example.com cib: info: cib_perform_op: ++ Jan 25 17:02:09 [21933] node02.example.com cib: info: cib_perform_op: ++ Jan 25 17:02:09 [21933] node02.example.com cib: info: cib_perform_op: ++ Jan 25 17:02:09 [21933] node02.example.com cib: info: cib_perform_op: ++ Jan 25 17:02:09 [21933] node02.example.com cib: info: cib_perform_op: ++ Jan 25 17:02:09 [21933] node02.example.com cib: info: cib_perform_op: ++ Jan 25 17:02:09 [21933] node02.example.com cib: info: cib_process_request: Completed cib_modify operation for section status: OK (rc=0, origin=node02.example.com/crmd/46319, version=0.93.13) Jan 25 17:02:09 [21938] node02.example.com crmd: info: abort_transition_graph: Transition aborted: LRM Refresh | source=process_resource_updates:278 complete=true Jan 25 17:02:09 [21933] node02.example.com cib: info: cib_process_request: Forwarding cib_modify operation for section nodes to all (origin=local/crmd/46322) Jan 25 17:02:09 [21933] node02.example.com cib: info: cib_process_request: Forwarding cib_modify operation for section status to all (origin=local/crmd/46323) Jan 25 17:02:09 [21933] node02.example.com cib: info: cib_process_request: Forwarding cib_modify operation for section cib to all (origin=local/crmd/46324) Jan 25 17:02:09 [21933] node02.example.com cib: info: cib_process_request: Completed cib_modify operation for section nodes: OK (rc=0, origin=node02.example.com/crmd/46322, version=0.93.13) Jan 25 17:02:09 [21933] node02.example.com cib: info: cib_perform_op: Diff: --- 0.93.13 2 Jan 25 17:02:09 [21933] node02.example.com cib: info: cib_perform_op: Diff: +++ 0.93.14 (null) Jan 25 17:02:09 [21933] node02.example.com cib: info: cib_perform_op: + /cib: @num_updates=14 Jan 25 17:02:09 [21933] node02.example.com cib: info: cib_perform_op: + /cib/status/node_state[@id='1']: @crm-debug-origin=do_state_transition Jan 25 17:02:09 [21933] node02.example.com cib: info: cib_perform_op: + /cib/status/node_state[@id='2']: @crm-debug-origin=do_state_transition Jan 25 17:02:09 [21933] node02.example.com cib: info: cib_process_request: Completed cib_modify operation for section status: OK (rc=0, origin=node02.example.com/crmd/46323, version=0.93.14) Jan 25 17:02:09 [21933] node02.example.com cib: info: cib_process_request: Completed cib_modify operation for section cib: OK (rc=0, origin=node02.example.com/crmd/46324, version=0.93.14) Jan 25 17:02:09 [21933] node02.example.com cib: info: cib_file_backup: Archived previous version as /var/lib/pacemaker/cib/cib-37.raw Jan 25 17:02:09 [21933] node02.example.com cib: info: cib_file_write_with_digest: Wrote version 0.93.0 of the CIB to disk (digest: 15393b38261329cd293a7032bde5b8d8) Jan 25 17:02:09 [21933] node02.example.com cib: info: cib_file_write_with_digest: Reading cluster configuration file /var/lib/pacemaker/cib/cib.THgrX2 (digest: /var/lib/pacemaker/cib/cib.nIuuTc) Jan 25 17:02:10 [21937] node02.example.com pengine: info: unpack_status: Node node01.example.com is in maintenance-mode Jan 25 17:02:10 [21937] node02.example.com pengine: info: determine_online_status: Node node01.example.com is maintenance Jan 25 17:02:10 [21937] node02.example.com pengine: info: determine_online_status: Node node02.example.com is online Jan 25 17:02:10 [21937] node02.example.com pengine: info: native_add_running: resource drbd_ourApp:0 isn't managed Jan 25 17:02:10 [21937] node02.example.com pengine: info: native_add_running: resource pingd:0 isn't managed Jan 25 17:02:10 [21937] node02.example.com pengine: info: determine_op_status: Operation monitor found resource drbd_ourApp:1 active in master mode on node02.example.com Jan 25 17:02:10 [21937] node02.example.com pengine: info: unpack_node_loop: Node 1 is already processed Jan 25 17:02:10 [21937] node02.example.com pengine: info: unpack_node_loop: Node 2 is already processed Jan 25 17:02:10 [21937] node02.example.com pengine: info: unpack_node_loop: Node 1 is already processed Jan 25 17:02:10 [21937] node02.example.com pengine: info: unpack_node_loop: Node 2 is already processed Jan 25 17:02:10 [21937] node02.example.com pengine: info: group_print: Resource Group: httpd Jan 25 17:02:10 [21937] node02.example.com pengine: info: common_print: daemon_httpd (ocf::heartbeat:apache): Started node02.example.com Jan 25 17:02:10 [21937] node02.example.com pengine: info: group_print: Resource Group: ourApp Jan 25 17:02:10 [21937] node02.example.com pengine: info: common_print: fs_ourApp (ocf::heartbeat:Filesystem): Started node02.example.com Jan 25 17:02:10 [21937] node02.example.com pengine: info: common_print: ip_ourApp (ocf::heartbeat:IPaddr2): Started node02.example.com Jan 25 17:02:10 [21937] node02.example.com pengine: info: common_print: app_ourApp (lsb:ourUser): Started node02.example.com Jan 25 17:02:10 [21937] node02.example.com pengine: info: clone_print: Master/Slave Set: ms_drbd_ourApp [drbd_ourApp] Jan 25 17:02:10 [21937] node02.example.com pengine: info: common_print: drbd_ourApp (ocf::linbit:drbd): Slave node01.example.com (unmanaged) Jan 25 17:02:10 [21937] node02.example.com pengine: info: short_print: Masters: [ node02.example.com ] Jan 25 17:02:10 [21937] node02.example.com pengine: info: clone_print: Clone Set: pingdclone [pingd] Jan 25 17:02:10 [21937] node02.example.com pengine: info: common_print: pingd (ocf::pacemaker:ping): Started node01.example.com (unmanaged) Jan 25 17:02:10 [21937] node02.example.com pengine: info: short_print: Started: [ node02.example.com ] Jan 25 17:02:10 [21937] node02.example.com pengine: info: native_color: Unmanaged resource drbd_ourApp:0 allocated to node01.example.com: active Jan 25 17:02:10 [21937] node02.example.com pengine: info: master_color: ms_drbd_ourApp: Promoted 0 instances of a possible 1 to master Jan 25 17:02:10 [21937] node02.example.com pengine: info: rsc_merge_weights: fs_ourApp: Rolling back scores from ip_ourApp Jan 25 17:02:10 [21937] node02.example.com pengine: info: native_color: Resource fs_ourApp cannot run anywhere Jan 25 17:02:10 [21937] node02.example.com pengine: info: rsc_merge_weights: ip_ourApp: Rolling back scores from app_ourApp Jan 25 17:02:10 [21937] node02.example.com pengine: info: rsc_merge_weights: ip_ourApp: Rolling back scores from daemon_httpd Jan 25 17:02:10 [21937] node02.example.com pengine: info: native_color: Resource ip_ourApp cannot run anywhere Jan 25 17:02:10 [21937] node02.example.com pengine: info: native_color: Resource app_ourApp cannot run anywhere Jan 25 17:02:10 [21937] node02.example.com pengine: info: native_color: Resource daemon_httpd cannot run anywhere Jan 25 17:02:10 [21937] node02.example.com pengine: info: native_color: Unmanaged resource pingd:0 allocated to node01.example.com: active Jan 25 17:02:10 [21937] node02.example.com pengine: info: RecurringOp: Cancelling action drbd_ourApp:1_monitor_15000 (Master vs. Slave) Jan 25 17:02:10 [21937] node02.example.com pengine: info: RecurringOp: Start recurring monitor (30s) for drbd_ourApp:1 on node02.example.com Jan 25 17:02:10 [21937] node02.example.com pengine: info: RecurringOp: Cancelling action drbd_ourApp:1_monitor_15000 (Master vs. Slave) Jan 25 17:02:10 [21937] node02.example.com pengine: info: RecurringOp: Start recurring monitor (30s) for drbd_ourApp:1 on node02.example.com Jan 25 17:02:10 [21937] node02.example.com pengine: notice: LogAction: * Stop daemon_httpd ( node02.example.com ) due to node availability Jan 25 17:02:10 [21937] node02.example.com pengine: notice: LogAction: * Stop fs_ourApp ( node02.example.com ) due to node availability Jan 25 17:02:10 [21937] node02.example.com pengine: notice: LogAction: * Stop ip_ourApp ( node02.example.com ) due to node availability Jan 25 17:02:10 [21937] node02.example.com pengine: notice: LogAction: * Stop app_ourApp ( node02.example.com ) due to node availability Jan 25 17:02:10 [21937] node02.example.com pengine: info: LogActions: Leave drbd_ourApp:0 (Slave unmanaged) Jan 25 17:02:10 [21937] node02.example.com pengine: notice: LogAction: * Demote drbd_ourApp:1 ( Master -> Slave node02.example.com ) Jan 25 17:02:10 [21937] node02.example.com pengine: info: LogActions: Leave pingd:0 (Started unmanaged) Jan 25 17:02:10 [21937] node02.example.com pengine: info: LogActions: Leave pingd:1 (Started node02.example.com) Jan 25 17:02:10 [21937] node02.example.com pengine: notice: process_pe_message: Calculated transition 37019, saving inputs in /var/lib/pacemaker/pengine/pe-input-3242.bz2 Jan 25 17:02:10 [21938] node02.example.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 Jan 25 17:02:10 [21938] node02.example.com crmd: info: do_te_invoke: Processing graph 37019 (ref=pe_calc-dc-1611612130-42213) derived from /var/lib/pacemaker/pengine/pe-input-3242.bz2 Jan 25 17:02:10 [21938] node02.example.com crmd: notice: te_rsc_command: Initiating stop operation daemon_httpd_stop_0 locally on node02.example.com | action 5 Jan 25 17:02:10 [21935] node02.example.com lrmd: info: cancel_recurring_action: Cancelling ocf operation daemon_httpd_monitor_5000 Jan 25 17:02:10 [21938] node02.example.com crmd: info: do_lrm_rsc_op: Performing key=5:37019:0:2abe0ec3-eaff-49b8-8e80-7a565bc532bd op=daemon_httpd_stop_0 Jan 25 17:02:10 [21933] node02.example.com cib: info: cib_process_request: Forwarding cib_modify operation for section status to all (origin=local/crmd/46329) Jan 25 17:02:10 [21935] node02.example.com lrmd: info: log_execute: executing - rsc:daemon_httpd action:stop call_id:1564 Jan 25 17:02:10 [21938] node02.example.com crmd: notice: te_rsc_command: Initiating cancel operation drbd_ourApp_monitor_15000 locally on node02.example.com | action 1 Jan 25 17:02:10 [21935] node02.example.com lrmd: info: cancel_recurring_action: Cancelling ocf operation drbd_ourApp_monitor_15000 Jan 25 17:02:10 [21938] node02.example.com crmd: info: process_lrm_event: Result of monitor operation for daemon_httpd on node02.example.com: Cancelled | call=1558 key=daemon_httpd_monitor_5000 confirmed=true Jan 25 17:02:10 [21938] node02.example.com crmd: info: process_lrm_event: Result of monitor operation for drbd_ourApp on node02.example.com: Cancelled | call=1547 key=drbd_ourApp_monitor_15000 confirmed=true Jan 25 17:02:10 [21938] node02.example.com crmd: notice: te_rsc_command: Initiating notify operation drbd_ourApp_pre_notify_demote_0 locally on node02.example.com | action 68 Jan 25 17:02:10 [21938] node02.example.com crmd: info: do_lrm_rsc_op: Performing key=68:37019:0:2abe0ec3-eaff-49b8-8e80-7a565bc532bd op=drbd_ourApp_notify_0 Jan 25 17:02:10 [21933] node02.example.com cib: info: cib_perform_op: Diff: --- 0.93.14 2 Jan 25 17:02:10 [21933] node02.example.com cib: info: cib_perform_op: Diff: +++ 0.93.15 (null) Jan 25 17:02:10 [21933] node02.example.com cib: info: cib_perform_op: + /cib: @num_updates=15 Jan 25 17:02:10 [21933] node02.example.com cib: info: cib_perform_op: + /cib/status/node_state[@id='2']: @crm-debug-origin=do_update_resource Jan 25 17:02:10 [21933] node02.example.com cib: info: cib_perform_op: + /cib/status/node_state[@id='2']/lrm[@id='2']/lrm_resources/lrm_resource[@id='daemon_httpd']/lrm_rsc_op[@id='daemon_httpd_last_0']: @operation_key=daemon_httpd_stop_0, @operation=stop, @crm-debug-origin=do_update_resource, @transition-key=5:37019:0:2abe0ec3-eaff-49b8-8e80-7a565bc532bd, @transition-magic=-1:193;5:37019:0:2abe0ec3-eaff-49b8-8e80-7a565bc532bd, @call-id=-1, @rc-code=193, @op-status=-1, @last-run=1611612130 Jan 25 17:02:10 [21933] node02.example.com cib: info: cib_process_request: Completed cib_modify operation for section status: OK (rc=0, origin=node02.example.com/crmd/46329, version=0.93.15) Jan 25 17:02:10 [21933] node02.example.com cib: info: cib_process_request: Forwarding cib_delete operation for section status to all (origin=local/crmd/46330) Jan 25 17:02:10 [21935] node02.example.com lrmd: info: log_execute: executing - rsc:drbd_ourApp action:notify call_id:1566 Jan 25 17:02:10 [21933] node02.example.com cib: info: cib_process_request: Forwarding cib_modify operation for section status to all (origin=local/crmd/46331) Jan 25 17:02:10 [21933] node02.example.com cib: info: cib_perform_op: Diff: --- 0.93.15 2 Jan 25 17:02:10 [21933] node02.example.com cib: info: cib_perform_op: Diff: +++ 0.93.16 (null) Jan 25 17:02:10 [21933] node02.example.com cib: info: cib_perform_op: -- /cib/status/node_state[@id='2']/lrm[@id='2']/lrm_resources/lrm_resource[@id='drbd_ourApp']/lrm_rsc_op[@id='drbd_ourApp_monitor_15000'] Jan 25 17:02:10 [21933] node02.example.com cib: info: cib_perform_op: + /cib: @num_updates=16 Jan 25 17:02:10 [21933] node02.example.com cib: info: cib_process_request: Completed cib_delete operation for section status: OK (rc=0, origin=node02.example.com/crmd/46330, version=0.93.16) Jan 25 17:02:10 [21938] node02.example.com crmd: info: te_update_diff: Cancellation of drbd_ourApp_monitor_15000 on 2 confirmed (1) Jan 25 17:02:10 [21933] node02.example.com cib: info: cib_perform_op: Diff: --- 0.93.16 2 Jan 25 17:02:10 [21933] node02.example.com cib: info: cib_perform_op: Diff: +++ 0.93.17 (null) Jan 25 17:02:10 [21933] node02.example.com cib: info: cib_perform_op: + /cib: @num_updates=17 Jan 25 17:02:10 [21933] node02.example.com cib: info: cib_perform_op: ++ /cib/status/node_state[@id='2']/lrm[@id='2']/lrm_resources/lrm_resource[@id='drbd_ourApp']: Jan 25 17:04:56 [21933] node02.example.com cib: info: cib_perform_op: ++ Jan 25 17:04:56 [21933] node02.example.com cib: info: cib_perform_op: ++ Jan 25 17:04:56 [21933] node02.example.com cib: info: cib_perform_op: ++ Jan 25 17:04:56 [21933] node02.example.com cib: info: cib_perform_op: ++ Jan 25 17:04:56 [21933] node02.example.com cib: info: cib_perform_op: ++ Jan 25 17:04:56 [21933] node02.example.com cib: info: cib_perform_op: ++ Jan 25 17:04:56 [21933] node02.example.com cib: info: cib_perform_op: ++ Jan 25 17:04:56 [21933] node02.example.com cib: info: cib_perform_op: ++ Jan 25 17:04:56 [21933] node02.example.com cib: info: cib_perform_op: ++ Jan 25 17:04:56 [21933] node02.example.com cib: info: cib_perform_op: ++ Jan 25 17:04:56 [21933] node02.example.com cib: info: cib_perform_op: ++ Jan 25 17:04:56 [21933] node02.example.com cib: info: cib_perform_op: ++ Jan 25 17:04:56 [21933] node02.example.com cib: info: cib_perform_op: ++ Jan 25 17:04:56 [21933] node02.example.com cib: info: cib_perform_op: ++ Jan 25 17:04:56 [21933] node02.example.com cib: info: cib_process_request: Completed cib_modify operation for section status: OK (rc=0, origin=node02.example.com/crmd/46393, version=0.93.36) Jan 25 17:04:56 [21938] node02.example.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 Jan 25 17:04:56 [21938] node02.example.com crmd: info: abort_transition_graph: Transition aborted: Peer Cancelled | source=do_te_invoke:143 complete=true Jan 25 17:04:56 [21933] node02.example.com cib: info: cib_perform_op: Diff: --- 0.93.36 2 Jan 25 17:04:56 [21933] node02.example.com cib: info: cib_perform_op: Diff: +++ 0.93.37 (null) Jan 25 17:04:56 [21933] node02.example.com cib: info: cib_perform_op: -- /cib/status/node_state[@id='1']/lrm[@id='1'] Jan 25 17:04:56 [21933] node02.example.com cib: info: cib_perform_op: + /cib: @num_updates=37 Jan 25 17:04:56 [21933] node02.example.com cib: info: cib_process_request: Completed cib_delete operation for section //node_state[@uname='node01.example.com']/lrm: OK (rc=0, origin=node02.example.com/crmd/46394, version=0.93.37) Jan 25 17:04:56 [21938] node02.example.com crmd: info: abort_transition_graph: Transition aborted by deletion of lrm[@id='1']: Resource state removal | cib=0.93.37 source=abort_unless_down:357 path=/cib/status/node_state[@id='1']/lrm[@id='1'] complete=true Jan 25 17:04:56 [21933] node02.example.com cib: info: cib_perform_op: Diff: --- 0.93.37 2 Jan 25 17:04:56 [21933] node02.example.com cib: info: cib_perform_op: Diff: +++ 0.93.38 (null) Jan 25 17:04:56 [21933] node02.example.com cib: info: cib_perform_op: + /cib: @num_updates=38 Jan 25 17:04:56 [21933] node02.example.com cib: info: cib_perform_op: + /cib/status/node_state[@id='1']: @crm-debug-origin=do_lrm_query_internal, @join=member Jan 25 17:04:56 [21933] node02.example.com cib: info: cib_perform_op: ++ /cib/status/node_state[@id='1']: Jan 25 17:04:56 [21933] node02.example.com cib: info: cib_perform_op: ++ Jan 25 17:04:56 [21933] node02.example.com cib: info: cib_perform_op: ++ Jan 25 17:04:56 [21933] node02.example.com cib: info: cib_perform_op: ++ Jan 25 17:04:56 [21933] node02.example.com cib: info: cib_perform_op: ++ Jan 25 17:04:56 [21933] node02.example.com cib: info: cib_perform_op: ++ Jan 25 17:04:56 [21933] node02.example.com cib: info: cib_perform_op: ++ Jan 25 17:04:56 [21933] node02.example.com cib: info: cib_perform_op: ++ Jan 25 17:04:56 [21933] node02.example.com cib: info: cib_perform_op: ++ Jan 25 17:04:56 [21933] node02.example.com cib: info: cib_perform_op: ++ Jan 25 17:04:56 [21933] node02.example.com cib: info: cib_perform_op: ++ Jan 25 17:04:56 [21933] node02.example.com cib: info: cib_perform_op: ++ Jan 25 17:04:56 [21933] node02.example.com cib: info: cib_perform_op: ++ Jan 25 17:04:56 [21933] node02.example.com cib: info: cib_perform_op: ++ Jan 25 17:04:56 [21933] node02.example.com cib: info: cib_perform_op: ++ Jan 25 17:04:56 [21933] node02.example.com cib: info: cib_perform_op: ++ Jan 25 17:04:56 [21933] node02.example.com cib: info: cib_process_request: Completed cib_modify operation for section status: OK (rc=0, origin=node02.example.com/crmd/46395, version=0.93.38) Jan 25 17:04:56 [21938] node02.example.com crmd: info: abort_transition_graph: Transition aborted: LRM Refresh | source=process_resource_updates:278 complete=true Jan 25 17:04:56 [21933] node02.example.com cib: info: cib_process_request: Forwarding cib_modify operation for section nodes to all (origin=local/crmd/46398) Jan 25 17:04:56 [21933] node02.example.com cib: info: cib_process_request: Forwarding cib_modify operation for section status to all (origin=local/crmd/46399) Jan 25 17:04:56 [21933] node02.example.com cib: info: cib_process_request: Forwarding cib_modify operation for section cib to all (origin=local/crmd/46400) Jan 25 17:04:56 [21933] node02.example.com cib: info: cib_process_request: Completed cib_modify operation for section nodes: OK (rc=0, origin=node02.example.com/crmd/46398, version=0.93.38) Jan 25 17:04:56 [21933] node02.example.com cib: info: cib_perform_op: Diff: --- 0.93.38 2 Jan 25 17:04:56 [21933] node02.example.com cib: info: cib_perform_op: Diff: +++ 0.93.39 (null) Jan 25 17:04:56 [21933] node02.example.com cib: info: cib_perform_op: + /cib: @num_updates=39 Jan 25 17:04:56 [21933] node02.example.com cib: info: cib_perform_op: + /cib/status/node_state[@id='1']: @crm-debug-origin=do_state_transition Jan 25 17:04:56 [21933] node02.example.com cib: info: cib_perform_op: + /cib/status/node_state[@id='2']: @crm-debug-origin=do_state_transition Jan 25 17:04:56 [21933] node02.example.com cib: info: cib_process_request: Completed cib_modify operation for section status: OK (rc=0, origin=node02.example.com/crmd/46399, version=0.93.39) Jan 25 17:04:56 [21933] node02.example.com cib: info: cib_process_request: Completed cib_modify operation for section cib: OK (rc=0, origin=node02.example.com/crmd/46400, version=0.93.39) Jan 25 17:04:56 [21933] node02.example.com cib: info: cib_file_backup: Archived previous version as /var/lib/pacemaker/cib/cib-38.raw Jan 25 17:04:56 [21933] node02.example.com cib: info: cib_file_write_with_digest: Wrote version 0.93.0 of the CIB to disk (digest: 1a8393ffe1a91fb7b62626f5fa419922) Jan 25 17:04:56 [21933] node02.example.com cib: info: cib_file_write_with_digest: Reading cluster configuration file /var/lib/pacemaker/cib/cib.OL7luW (digest: /var/lib/pacemaker/cib/cib.A7aUw8) Jan 25 17:04:57 [21937] node02.example.com pengine: info: unpack_status: Node node01.example.com is in maintenance-mode Jan 25 17:04:57 [21937] node02.example.com pengine: info: determine_online_status: Node node01.example.com is maintenance Jan 25 17:04:57 [21937] node02.example.com pengine: info: determine_online_status: Node node02.example.com is online Jan 25 17:04:57 [21937] node02.example.com pengine: info: native_add_running: resource drbd_ourApp:0 isn't managed Jan 25 17:04:57 [21937] node02.example.com pengine: info: native_add_running: resource pingd:0 isn't managed Jan 25 17:04:57 [21937] node02.example.com pengine: info: determine_op_status: Operation monitor found resource drbd_ourApp:1 active in master mode on node02.example.com Jan 25 17:04:57 [21937] node02.example.com pengine: info: unpack_node_loop: Node 1 is already processed Jan 25 17:04:57 [21937] node02.example.com pengine: info: unpack_node_loop: Node 2 is already processed Jan 25 17:04:57 [21937] node02.example.com pengine: info: unpack_node_loop: Node 1 is already processed Jan 25 17:04:57 [21937] node02.example.com pengine: info: unpack_node_loop: Node 2 is already processed Jan 25 17:04:57 [21937] node02.example.com pengine: info: group_print: Resource Group: httpd Jan 25 17:04:57 [21937] node02.example.com pengine: info: common_print: daemon_httpd (ocf::heartbeat:apache): Stopped Jan 25 17:04:57 [21937] node02.example.com pengine: info: group_print: Resource Group: ourApp Jan 25 17:04:57 [21937] node02.example.com pengine: info: common_print: fs_ourApp (ocf::heartbeat:Filesystem): Stopped Jan 25 17:04:57 [21937] node02.example.com pengine: info: common_print: ip_ourApp (ocf::heartbeat:IPaddr2): Stopped Jan 25 17:04:57 [21937] node02.example.com pengine: info: common_print: app_ourApp (lsb:ourUser): Stopped Jan 25 17:04:57 [21937] node02.example.com pengine: info: clone_print: Master/Slave Set: ms_drbd_ourApp [drbd_ourApp] Jan 25 17:04:57 [21937] node02.example.com pengine: info: common_print: drbd_ourApp (ocf::linbit:drbd): Slave node01.example.com (unmanaged) Jan 25 17:04:57 [21937] node02.example.com pengine: info: short_print: Slaves: [ node02.example.com ] Jan 25 17:04:57 [21937] node02.example.com pengine: info: clone_print: Clone Set: pingdclone [pingd] Jan 25 17:04:57 [21937] node02.example.com pengine: info: common_print: pingd (ocf::pacemaker:ping): Started node01.example.com (unmanaged) Jan 25 17:04:57 [21937] node02.example.com pengine: info: short_print: Started: [ node02.example.com ] Jan 25 17:04:57 [21937] node02.example.com pengine: info: native_color: Unmanaged resource drbd_ourApp:0 allocated to node01.example.com: active Jan 25 17:04:57 [21937] node02.example.com pengine: info: master_color: ms_drbd_ourApp: Promoted 0 instances of a possible 1 to master Jan 25 17:04:57 [21937] node02.example.com pengine: info: rsc_merge_weights: fs_ourApp: Rolling back scores from ip_ourApp Jan 25 17:04:57 [21937] node02.example.com pengine: info: native_color: Resource fs_ourApp cannot run anywhere Jan 25 17:04:57 [21937] node02.example.com pengine: info: rsc_merge_weights: ip_ourApp: Rolling back scores from app_ourApp Jan 25 17:04:57 [21937] node02.example.com pengine: info: rsc_merge_weights: ip_ourApp: Rolling back scores from daemon_httpd Jan 25 17:04:57 [21937] node02.example.com pengine: info: native_color: Resource ip_ourApp cannot run anywhere Jan 25 17:04:57 [21937] node02.example.com pengine: info: native_color: Resource app_ourApp cannot run anywhere Jan 25 17:04:57 [21937] node02.example.com pengine: info: native_color: Resource daemon_httpd cannot run anywhere Jan 25 17:04:57 [21937] node02.example.com pengine: info: native_color: Unmanaged resource pingd:0 allocated to node01.example.com: active Jan 25 17:04:57 [21937] node02.example.com pengine: info: LogActions: Leave daemon_httpd (Stopped) Jan 25 17:04:57 [21937] node02.example.com pengine: info: LogActions: Leave fs_ourApp (Stopped) Jan 25 17:04:57 [21937] node02.example.com pengine: info: LogActions: Leave ip_ourApp (Stopped) Jan 25 17:04:57 [21937] node02.example.com pengine: info: LogActions: Leave app_ourApp (Stopped) Jan 25 17:04:57 [21937] node02.example.com pengine: info: LogActions: Leave drbd_ourApp:0 (Slave unmanaged) Jan 25 17:04:57 [21937] node02.example.com pengine: info: LogActions: Leave drbd_ourApp:1 (Slave node02.example.com) Jan 25 17:04:57 [21937] node02.example.com pengine: info: LogActions: Leave pingd:0 (Started unmanaged) Jan 25 17:04:57 [21937] node02.example.com pengine: info: LogActions: Leave pingd:1 (Started node02.example.com) Jan 25 17:04:57 [21938] node02.example.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 Jan 25 17:04:57 [21937] node02.example.com pengine: notice: process_pe_message: Calculated transition 37020, saving inputs in /var/lib/pacemaker/pengine/pe-input-3243.bz2 Jan 25 17:04:57 [21938] node02.example.com crmd: info: do_te_invoke: Processing graph 37020 (ref=pe_calc-dc-1611612297-42243) derived from /var/lib/pacemaker/pengine/pe-input-3243.bz2 Jan 25 17:04:57 [21938] node02.example.com crmd: notice: run_graph: Transition 37020 (Complete=0, Pending=0, Fired=0, Skipped=0, Incomplete=0, Source=/var/lib/pacemaker/pengine/pe-input-3243.bz2): Complete Jan 25 17:04:57 [21938] node02.example.com crmd: info: do_log: Input I_TE_SUCCESS received in state S_TRANSITION_ENGINE from notify_crmd Jan 25 17:04:57 [21938] node02.example.com crmd: notice: do_state_transition: State transition S_TRANSITION_ENGINE -> S_IDLE | input=I_TE_SUCCESS cause=C_FSA_INTERNAL origin=notify_crmd Jan 25 17:05:01 [21933] node02.example.com cib: info: cib_process_ping: Reporting our current digest to node02.example.com: 158296c37db6bd40ed0ef2df4d4a537b for 0.93.39 (0x5646ba88bfb0 0) Jan 25 17:05:45 [21936] node02.example.com attrd: info: pcmk_cpg_membership: Node 1 left group attrd (peer=node01.example.com, counter=271.0) Jan 25 17:05:45 [21933] node02.example.com cib: info: pcmk_cpg_membership: Node 1 left group cib (peer=node01.example.com, counter=271.0) Jan 25 17:05:45 [21936] node02.example.com attrd: info: crm_update_peer_proc: pcmk_cpg_membership: Node node01.example.com[1] - corosync-cpg is now offline Jan 25 17:05:45 [21938] node02.example.com crmd: info: pcmk_cpg_membership: Node 1 left group crmd (peer=node01.example.com, counter=271.0) Jan 25 17:05:45 [21933] node02.example.com cib: info: crm_update_peer_proc: pcmk_cpg_membership: Node node01.example.com[1] - corosync-cpg is now offline Jan 25 17:05:45 [21938] node02.example.com crmd: info: crm_update_peer_proc: pcmk_cpg_membership: Node node01.example.com[1] - corosync-cpg is now offline Jan 25 17:05:45 [21934] node02.example.com stonith-ng: info: pcmk_cpg_membership: Node 1 left group stonith-ng (peer=node01.example.com, counter=271.0) Jan 25 17:05:45 [21938] node02.example.com crmd: info: peer_update_callback: Client node01.example.com/peer now has status [offline] (DC=true, changed=4000000) Jan 25 17:05:45 [21934] node02.example.com stonith-ng: info: crm_update_peer_proc: pcmk_cpg_membership: Node node01.example.com[1] - corosync-cpg is now offline Jan 25 17:05:45 [21938] node02.example.com crmd: info: peer_update_callback: Peer node01.example.com left us Jan 25 17:05:45 [21932] node02.example.com pacemakerd: info: pcmk_cpg_membership: Node 1 left group pacemakerd (peer=node01.example.com, counter=271.0) Jan 25 17:05:45 [21933] node02.example.com cib: notice: crm_update_peer_state_iter: Node node01.example.com state is now lost | nodeid=1 previous=member source=crm_update_peer_proc Jan 25 17:05:45 [21938] node02.example.com crmd: info: erase_status_tag: Deleting transient_attributes status entries for node01.example.com | xpath=//node_state[@uname='node01.example.com']/transient_attributes Jan 25 17:05:45 [21936] node02.example.com attrd: notice: crm_update_peer_state_iter: Node node01.example.com state is now lost | nodeid=1 previous=member source=crm_update_peer_proc Jan 25 17:05:45 [21932] node02.example.com pacemakerd: info: crm_update_peer_proc: pcmk_cpg_membership: Node node01.example.com[1] - corosync-cpg is now offline Jan 25 17:05:45 [21936] node02.example.com attrd: notice: attrd_peer_remove: Removing all node01.example.com attributes for peer loss Jan 25 17:05:45 [21932] node02.example.com pacemakerd: info: pcmk_cpg_membership: Node 2 still member of group pacemakerd (peer=node02.example.com, counter=271.0) Jan 25 17:05:45 [21936] node02.example.com attrd: info: crm_reap_dead_member: Removing node with name node01.example.com and id 1 from membership cache Jan 25 17:05:45 [21933] node02.example.com cib: info: crm_reap_dead_member: Removing node with name node01.example.com and id 1 from membership cache Jan 25 17:05:45 [21932] node02.example.com pacemakerd: info: crm_cs_flush: Sent 0 CPG messages (1 remaining, last=277): Try again (6) Jan 25 17:05:45 [21936] node02.example.com attrd: notice: reap_crm_member: Purged 1 peer with id=1 and/or uname=node01.example.com from the membership cache Jan 25 17:05:45 [21934] node02.example.com stonith-ng: notice: crm_update_peer_state_iter: Node node01.example.com state is now lost | nodeid=1 previous=member source=crm_update_peer_proc Jan 25 17:05:45 [21933] node02.example.com cib: notice: reap_crm_member: Purged 1 peer with id=1 and/or uname=node01.example.com from the membership cache Jan 25 17:05:45 [21936] node02.example.com attrd: info: pcmk_cpg_membership: Node 2 still member of group attrd (peer=node02.example.com, counter=271.0) Jan 25 17:05:45 [21933] node02.example.com cib: info: pcmk_cpg_membership: Node 2 still member of group cib (peer=node02.example.com, counter=271.0) Jan 25 17:05:45 [21938] node02.example.com crmd: warning: match_down_event: No reason to expect node 1 to be down Jan 25 17:05:45 [21938] node02.example.com crmd: notice: peer_update_callback: Stonith/shutdown of node01.example.com not matched Jan 25 17:05:45 [21938] node02.example.com crmd: info: crm_update_peer_join: peer_update_callback: Node node01.example.com[1] - join-273 phase confirmed -> none Jan 25 17:05:45 [21934] node02.example.com stonith-ng: info: crm_cs_flush: Sent 0 CPG messages (1 remaining, last=409): Try again (6) Jan 25 17:05:45 [21938] node02.example.com crmd: info: abort_transition_graph: Transition aborted: Node failure | source=peer_update_callback:258 complete=true Jan 25 17:05:45 [21934] node02.example.com stonith-ng: info: crm_reap_dead_member: Removing node with name node01.example.com and id 1 from membership cache Jan 25 17:05:45 [21934] node02.example.com stonith-ng: notice: reap_crm_member: Purged 1 peer with id=1 and/or uname=node01.example.com from the membership cache Jan 25 17:05:45 [21934] node02.example.com stonith-ng: info: pcmk_cpg_membership: Node 2 still member of group stonith-ng (peer=node02.example.com, counter=271.0) Jan 25 17:05:45 [21933] node02.example.com cib: info: cib_process_request: Forwarding cib_delete operation for section //node_state[@uname='node01.example.com']/transient_attributes to all (origin=local/crmd/46405) Jan 25 17:05:45 [21938] node02.example.com crmd: info: pcmk_cpg_membership: Node 2 still member of group crmd (peer=node02.example.com, counter=271.0) Jan 25 17:05:45 [21933] node02.example.com cib: info: crm_cs_flush: Sent 0 CPG messages (1 remaining, last=16057): Try again (6) Jan 25 17:05:45 [21938] node02.example.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 Jan 25 17:05:45 [21933] node02.example.com cib: info: cib_process_request: Forwarding cib_modify operation for section status to all (origin=local/crmd/46406) Jan 25 17:05:45 [21932] node02.example.com pacemakerd: info: crm_cs_flush: Sent 0 CPG messages (1 remaining, last=277): Try again (6) Jan 25 17:05:45 [21934] node02.example.com stonith-ng: info: crm_cs_flush: Sent 0 CPG messages (1 remaining, last=409): Try again (6) Jan 25 17:05:45 [21933] node02.example.com cib: info: crm_cs_flush: Sent 0 CPG messages (2 remaining, last=16057): Try again (6) Jan 25 17:05:45 [21932] node02.example.com pacemakerd: info: crm_cs_flush: Sent 0 CPG messages (1 remaining, last=277): Try again (6) Jan 25 17:05:45 [21934] node02.example.com stonith-ng: info: crm_cs_flush: Sent 0 CPG messages (1 remaining, last=409): Try again (6) Jan 25 17:05:45 [21933] node02.example.com cib: info: crm_cs_flush: Sent 0 CPG messages (2 remaining, last=16057): Try again (6) Jan 25 17:05:45 [21936] node02.example.com attrd: info: pcmk_cpg_membership: Node 1 joined group attrd (counter=272.0) Jan 25 17:05:45 [21934] node02.example.com stonith-ng: info: pcmk_cpg_membership: Node 1 joined group stonith-ng (counter=272.0) Jan 25 17:05:45 [21933] node02.example.com cib: info: pcmk_cpg_membership: Node 1 joined group cib (counter=272.0) Jan 25 17:05:45 [21932] node02.example.com pacemakerd: info: pcmk_cpg_membership: Node 1 joined group pacemakerd (counter=272.0) Jan 25 17:05:45 [21932] node02.example.com pacemakerd: info: pcmk_cpg_membership: Node 1 still member of group pacemakerd (peer=node01.example.com, counter=272.0) Jan 25 17:05:45 [21932] node02.example.com pacemakerd: info: crm_update_peer_proc: pcmk_cpg_membership: Node node01.example.com[1] - corosync-cpg is now online Jan 25 17:05:45 [21932] node02.example.com pacemakerd: info: pcmk_cpg_membership: Node 2 still member of group pacemakerd (peer=node02.example.com, counter=272.1) Jan 25 17:05:45 [21936] node02.example.com attrd: info: crm_get_peer: Created entry b6c51452-db82-47aa-820b-29eefc353857/0x5557c0696890 for node node01.example.com/1 (2 total) Jan 25 17:05:45 [21936] node02.example.com attrd: info: crm_get_peer: Node 1 is now known as node01.example.com Jan 25 17:05:45 [21936] node02.example.com attrd: info: crm_get_peer: Node 1 has uuid 1 Jan 25 17:05:45 [21936] node02.example.com attrd: info: pcmk_cpg_membership: Node 1 still member of group attrd (peer=node01.example.com, counter=272.0) Jan 25 17:05:45 [21936] node02.example.com attrd: info: crm_update_peer_proc: pcmk_cpg_membership: Node node01.example.com[1] - corosync-cpg is now online Jan 25 17:05:45 [21936] node02.example.com attrd: notice: crm_update_peer_state_iter: Node node01.example.com state is now member | nodeid=1 previous=unknown source=crm_update_peer_proc Jan 25 17:05:45 [21936] node02.example.com attrd: info: crm_cs_flush: Sent 0 CPG messages (1 remaining, last=5929416): Try again (6) Jan 25 17:05:45 [21936] node02.example.com attrd: info: pcmk_cpg_membership: Node 2 still member of group attrd (peer=node02.example.com, counter=272.1) Jan 25 17:05:45 [21934] node02.example.com stonith-ng: info: crm_get_peer: Created entry bec12d73-4a4b-43b8-95b9-a7703c63cbc5/0x5592ba20d7c0 for node node01.example.com/1 (2 total) Jan 25 17:05:45 [21934] node02.example.com stonith-ng: info: crm_get_peer: Node 1 is now known as node01.example.com Jan 25 17:05:45 [21934] node02.example.com stonith-ng: info: crm_get_peer: Node 1 has uuid 1 Jan 25 17:05:45 [21934] node02.example.com stonith-ng: info: pcmk_cpg_membership: Node 1 still member of group stonith-ng (peer=node01.example.com, counter=272.0) Jan 25 17:05:45 [21934] node02.example.com stonith-ng: info: crm_update_peer_proc: pcmk_cpg_membership: Node node01.example.com[1] - corosync-cpg is now online Jan 25 17:05:45 [21934] node02.example.com stonith-ng: notice: crm_update_peer_state_iter: Node node01.example.com state is now member | nodeid=1 previous=unknown source=crm_update_peer_proc Jan 25 17:05:45 [21934] node02.example.com stonith-ng: info: pcmk_cpg_membership: Node 2 still member of group stonith-ng (peer=node02.example.com, counter=272.1) Jan 25 17:05:45 [21933] node02.example.com cib: info: crm_get_peer: Created entry b98bd507-12cf-4d61-b23a-58037a57faa5/0x5646ba964cc0 for node node01.example.com/1 (2 total) Jan 25 17:05:45 [21933] node02.example.com cib: info: crm_get_peer: Node 1 is now known as node01.example.com Jan 25 17:05:45 [21933] node02.example.com cib: info: crm_get_peer: Node 1 has uuid 1 Jan 25 17:05:45 [21933] node02.example.com cib: info: pcmk_cpg_membership: Node 1 still member of group cib (peer=node01.example.com, counter=272.0) Jan 25 17:05:45 [21933] node02.example.com cib: info: crm_update_peer_proc: pcmk_cpg_membership: Node node01.example.com[1] - corosync-cpg is now online Jan 25 17:05:45 [21933] node02.example.com cib: notice: crm_update_peer_state_iter: Node node01.example.com state is now member | nodeid=1 previous=unknown source=crm_update_peer_proc Jan 25 17:05:45 [21933] node02.example.com cib: info: pcmk_cpg_membership: Node 2 still member of group cib (peer=node02.example.com, counter=272.1) Jan 25 17:05:45 [21932] node02.example.com pacemakerd: info: pcmk_quorum_notification: Quorum retained | membership=9236 members=2 Jan 25 17:05:45 [21932] node02.example.com pacemakerd: info: crm_cs_flush: Sent 2 CPG messages (0 remaining, last=279): OK (1) Jan 25 17:05:45 [21934] node02.example.com stonith-ng: info: crm_cs_flush: Sent 3 CPG messages (0 remaining, last=412): OK (1) Jan 25 17:05:45 [21932] node02.example.com pacemakerd: info: mcp_cpg_deliver: Ignoring process list sent by peer for local node Jan 25 17:05:45 [21932] node02.example.com pacemakerd: info: mcp_cpg_deliver: Ignoring process list sent by peer for local node Jan 25 17:05:45 [21933] node02.example.com cib: info: crm_cs_flush: Sent 2 CPG messages (0 remaining, last=16059): OK (1) Jan 25 17:05:45 [21933] node02.example.com cib: info: cib_process_request: Completed cib_delete operation for section //node_state[@uname='node01.example.com']/transient_attributes: OK (rc=0, origin=node02.example.com/crmd/46405, version=0.93.39) Jan 25 17:05:45 [21933] node02.example.com cib: info: cib_perform_op: Diff: --- 0.93.39 2 Jan 25 17:05:45 [21933] node02.example.com cib: info: cib_perform_op: Diff: +++ 0.93.40 (null) Jan 25 17:05:45 [21933] node02.example.com cib: info: cib_perform_op: + /cib: @num_updates=40 Jan 25 17:05:45 [21933] node02.example.com cib: info: cib_perform_op: + /cib/status/node_state[@id='1']: @crmd=offline, @crm-debug-origin=peer_update_callback Jan 25 17:05:45 [21933] node02.example.com cib: info: cib_process_request: Completed cib_modify operation for section status: OK (rc=0, origin=node02.example.com/crmd/46406, version=0.93.40) Jan 25 17:05:45 [21933] node02.example.com cib: info: cib_process_request: Completed cib_delete operation for section //node_state[@uname='node02.example.com']/transient_attributes: OK (rc=0, origin=node01.example.com/crmd/3524, version=0.93.40) Jan 25 17:05:46 [21938] node02.example.com crmd: info: pcmk_quorum_notification: Quorum retained | membership=9236 members=2 Jan 25 17:05:46 [21938] node02.example.com crmd: info: pcmk_cpg_membership: Node 1 joined group crmd (counter=272.0) Jan 25 17:05:46 [21938] node02.example.com crmd: info: pcmk_cpg_membership: Node 1 still member of group crmd (peer=node01.example.com, counter=272.0) Jan 25 17:05:46 [21938] node02.example.com crmd: info: crm_update_peer_proc: pcmk_cpg_membership: Node node01.example.com[1] - corosync-cpg is now online Jan 25 17:05:46 [21938] node02.example.com crmd: info: peer_update_callback: Client node01.example.com/peer now has status [online] (DC=true, changed=4000000) Jan 25 17:05:46 [21938] node02.example.com crmd: info: pcmk_cpg_membership: Node 2 still member of group crmd (peer=node02.example.com, counter=272.1) Jan 25 17:05:46 [21938] node02.example.com crmd: info: do_state_transition: State transition S_POLICY_ENGINE -> S_INTEGRATION | input=I_NODE_JOIN cause=C_FSA_INTERNAL origin=peer_update_callback Jan 25 17:05:46 [21938] node02.example.com crmd: info: do_dc_join_offer_one: An unknown node joined - (re-)offer to any unconfirmed nodes Jan 25 17:05:46 [21938] node02.example.com crmd: info: join_make_offer: Making join offers based on membership 9236 Jan 25 17:05:46 [21938] node02.example.com crmd: info: join_make_offer: Skipping node02.example.com: already known 4 Jan 25 17:05:46 [21938] node02.example.com crmd: info: join_make_offer: join-273: Sending offer to node01.example.com Jan 25 17:05:46 [21938] node02.example.com crmd: info: crm_update_peer_join: join_make_offer: Node node01.example.com[1] - join-273 phase none -> welcomed Jan 25 17:05:46 [21938] node02.example.com crmd: info: election_count_vote: Election 293 (owner: 1) pass: vote from node01.example.com (Uptime) Jan 25 17:05:46 [21938] node02.example.com crmd: info: do_state_transition: State transition S_INTEGRATION -> S_ELECTION | input=I_ELECTION cause=C_FSA_INTERNAL origin=do_election_count_vote Jan 25 17:05:46 [21938] node02.example.com crmd: info: update_dc: Unset DC. Was node02.example.com Jan 25 17:05:46 [21933] node02.example.com cib: info: cib_process_request: Forwarding cib_modify operation for section nodes to all (origin=local/crmd/46411) Jan 25 17:05:46 [21933] node02.example.com cib: info: cib_process_request: Forwarding cib_modify operation for section status to all (origin=local/crmd/46412) Jan 25 17:05:46 [21933] node02.example.com cib: info: cib_process_request: Forwarding cib_modify operation for section status to all (origin=local/crmd/46413) Jan 25 17:05:46 [21933] node02.example.com cib: info: cib_process_request: Completed cib_modify operation for section nodes: OK (rc=0, origin=node02.example.com/crmd/46411, version=0.93.40) Jan 25 17:05:46 [21933] node02.example.com cib: info: cib_perform_op: Diff: --- 0.93.40 2 Jan 25 17:05:46 [21933] node02.example.com cib: info: cib_perform_op: Diff: +++ 0.93.41 (null) Jan 25 17:05:46 [21933] node02.example.com cib: info: cib_perform_op: + /cib: @num_updates=41 Jan 25 17:05:46 [21933] node02.example.com cib: info: cib_perform_op: + /cib/status/node_state[@id='1']: @crm-debug-origin=post_cache_update Jan 25 17:05:46 [21933] node02.example.com cib: info: cib_perform_op: + /cib/status/node_state[@id='2']: @crm-debug-origin=post_cache_update Jan 25 17:05:46 [21933] node02.example.com cib: info: cib_process_request: Completed cib_modify operation for section status: OK (rc=0, origin=node02.example.com/crmd/46412, version=0.93.41) Jan 25 17:05:46 [21933] node02.example.com cib: info: cib_perform_op: Diff: --- 0.93.41 2 Jan 25 17:05:46 [21933] node02.example.com cib: info: cib_perform_op: Diff: +++ 0.93.42 (null) Jan 25 17:05:46 [21933] node02.example.com cib: info: cib_perform_op: + /cib: @num_updates=42 Jan 25 17:05:46 [21933] node02.example.com cib: info: cib_perform_op: + /cib/status/node_state[@id='1']: @crmd=online, @crm-debug-origin=peer_update_callback Jan 25 17:05:46 [21933] node02.example.com cib: info: cib_process_request: Completed cib_modify operation for section status: OK (rc=0, origin=node02.example.com/crmd/46413, version=0.93.42) Jan 25 17:05:46 [21938] node02.example.com crmd: info: election_count_vote: Election 294 (owner: 1) pass: vote from node01.example.com (Uptime) Jan 25 17:05:46 [21938] node02.example.com crmd: info: election_complete: Election election-0 complete Jan 25 17:05:46 [21938] node02.example.com crmd: info: election_timeout_popped: Election failed: Declaring ourselves the winner Jan 25 17:05:46 [21938] node02.example.com crmd: info: do_log: Input I_ELECTION_DC received in state S_ELECTION from election_timeout_popped Jan 25 17:05:46 [21938] node02.example.com crmd: notice: do_state_transition: State transition S_ELECTION -> S_INTEGRATION | input=I_ELECTION_DC cause=C_TIMER_POPPED origin=election_timeout_popped Jan 25 17:05:46 [21938] node02.example.com crmd: info: do_dc_takeover: Taking over DC status for this partition Jan 25 17:05:46 [21933] node02.example.com cib: info: cib_process_request: Completed cib_master operation for section 'all': OK (rc=0, origin=local/crmd/46414, version=0.93.42) Jan 25 17:05:46 [21933] node02.example.com cib: info: cib_process_request: Forwarding cib_modify operation for section cib to all (origin=local/crmd/46415) Jan 25 17:05:46 [21933] node02.example.com cib: info: cib_process_request: Completed cib_modify operation for section cib: OK (rc=0, origin=node02.example.com/crmd/46415, version=0.93.42) Jan 25 17:05:46 [21933] node02.example.com cib: info: cib_process_request: Forwarding cib_modify operation for section crm_config to all (origin=local/crmd/46417) Jan 25 17:05:46 [21933] node02.example.com cib: info: cib_process_request: Forwarding cib_modify operation for section crm_config to all (origin=local/crmd/46419) Jan 25 17:05:46 [21938] node02.example.com crmd: info: crm_update_peer_join: initialize_join: Node node02.example.com[2] - join-274 phase confirmed -> none Jan 25 17:05:46 [21938] node02.example.com crmd: info: crm_update_peer_join: initialize_join: Node node01.example.com[1] - join-274 phase welcomed -> none Jan 25 17:05:46 [21938] node02.example.com crmd: info: join_make_offer: join-274: Sending offer to node02.example.com Jan 25 17:05:46 [21938] node02.example.com crmd: info: crm_update_peer_join: join_make_offer: Node node02.example.com[2] - join-274 phase none -> welcomed Jan 25 17:05:46 [21938] node02.example.com crmd: info: join_make_offer: join-274: Sending offer to node01.example.com Jan 25 17:05:46 [21938] node02.example.com crmd: info: crm_update_peer_join: join_make_offer: Node node01.example.com[1] - join-274 phase none -> welcomed Jan 25 17:05:46 [21938] node02.example.com crmd: info: do_dc_join_offer_all: join-274: Waiting on 2 outstanding join acks Jan 25 17:05:46 [21938] node02.example.com crmd: warning: do_log: Input I_ELECTION_DC received in state S_INTEGRATION from do_election_check Jan 25 17:05:46 [21938] node02.example.com crmd: info: crm_update_peer_join: initialize_join: Node node02.example.com[2] - join-275 phase welcomed -> none Jan 25 17:05:46 [21938] node02.example.com crmd: info: crm_update_peer_join: initialize_join: Node node01.example.com[1] - join-275 phase welcomed -> none Jan 25 17:05:46 [21938] node02.example.com crmd: info: join_make_offer: join-275: Sending offer to node02.example.com Jan 25 17:05:46 [21938] node02.example.com crmd: info: crm_update_peer_join: join_make_offer: Node node02.example.com[2] - join-275 phase none -> welcomed Jan 25 17:05:46 [21938] node02.example.com crmd: info: join_make_offer: join-275: Sending offer to node01.example.com Jan 25 17:05:46 [21938] node02.example.com crmd: info: crm_update_peer_join: join_make_offer: Node node01.example.com[1] - join-275 phase none -> welcomed Jan 25 17:05:46 [21938] node02.example.com crmd: info: do_dc_join_offer_all: join-275: Waiting on 2 outstanding join acks Jan 25 17:05:46 [21938] node02.example.com crmd: info: update_dc: Set DC to node02.example.com (3.0.14) Jan 25 17:05:46 [21933] node02.example.com cib: info: cib_process_request: Completed cib_modify operation for section crm_config: OK (rc=0, origin=node02.example.com/crmd/46417, version=0.93.42) Jan 25 17:05:46 [21933] node02.example.com cib: info: cib_process_request: Completed cib_modify operation for section crm_config: OK (rc=0, origin=node02.example.com/crmd/46419, version=0.93.42) Jan 25 17:05:46 [21933] node02.example.com cib: info: cib_process_request: Forwarding cib_modify operation for section crm_config to all (origin=local/crmd/46421) Jan 25 17:05:46 [21938] node02.example.com crmd: info: crm_update_peer_join: do_dc_join_filter_offer: Node node02.example.com[2] - join-275 phase welcomed -> integrated Jan 25 17:05:46 [21933] node02.example.com cib: info: cib_process_request: Completed cib_modify operation for section crm_config: OK (rc=0, origin=node02.example.com/crmd/46421, version=0.93.42) Jan 25 17:05:46 [21938] node02.example.com crmd: info: crm_update_peer_join: do_dc_join_filter_offer: Node node01.example.com[1] - join-275 phase welcomed -> integrated Jan 25 17:05:46 [21938] node02.example.com crmd: info: do_state_transition: State transition S_INTEGRATION -> S_FINALIZE_JOIN | input=I_INTEGRATED cause=C_FSA_INTERNAL origin=check_join_state Jan 25 17:05:46 [21938] node02.example.com crmd: info: crmd_join_phase_log: join-275: node02.example.com=integrated Jan 25 17:05:46 [21938] node02.example.com crmd: info: crmd_join_phase_log: join-275: node01.example.com=integrated Jan 25 17:05:46 [21938] node02.example.com crmd: info: do_dc_join_finalize: join-275: Syncing our CIB to the rest of the cluster Jan 25 17:05:46 [21938] node02.example.com crmd: info: crm_update_peer_join: finalize_join_for: Node node02.example.com[2] - join-275 phase integrated -> finalized Jan 25 17:05:46 [21933] node02.example.com cib: info: cib_process_request: Forwarding cib_modify operation for section nodes to all (origin=local/crmd/46426) Jan 25 17:05:46 [21938] node02.example.com crmd: info: crm_update_peer_join: finalize_join_for: Node node01.example.com[1] - join-275 phase integrated -> finalized Jan 25 17:05:46 [21933] node02.example.com cib: info: cib_process_request: Forwarding cib_modify operation for section nodes to all (origin=local/crmd/46427) Jan 25 17:05:46 [21933] node02.example.com cib: info: cib_process_replace: Digest matched on replace from node02.example.com: 01de3a8ed0aa5fe3f4d54230d2a8b6db Jan 25 17:05:46 [21933] node02.example.com cib: info: cib_process_replace: Replaced 0.93.42 with 0.93.42 from node02.example.com Jan 25 17:05:46 [21938] node02.example.com crmd: info: crm_update_peer_join: do_dc_join_ack: Node node02.example.com[2] - join-275 phase finalized -> confirmed Jan 25 17:05:46 [21938] node02.example.com crmd: info: do_dc_join_ack: join-275: Updating node state to member for node02.example.com Jan 25 17:05:46 [21938] node02.example.com crmd: info: erase_status_tag: Deleting lrm status entries for node02.example.com | xpath=//node_state[@uname='node02.example.com']/lrm Jan 25 17:05:46 [21933] node02.example.com cib: info: cib_process_request: Completed cib_replace operation for section 'all': OK (rc=0, origin=node02.example.com/crmd/46425, version=0.93.42) Jan 25 17:05:46 [21938] node02.example.com crmd: info: crm_update_peer_join: do_dc_join_ack: Node node01.example.com[1] - join-275 phase finalized -> confirmed Jan 25 17:05:46 [21938] node02.example.com crmd: info: do_dc_join_ack: join-275: Updating node state to member for node01.example.com Jan 25 17:05:46 [21938] node02.example.com crmd: info: erase_status_tag: Deleting lrm status entries for node01.example.com | xpath=//node_state[@uname='node01.example.com']/lrm Jan 25 17:05:46 [21933] node02.example.com cib: info: cib_process_request: Completed cib_modify operation for section nodes: OK (rc=0, origin=node02.example.com/crmd/46426, version=0.93.42) Jan 25 17:05:46 [21933] node02.example.com cib: info: cib_process_request: Completed cib_modify operation for section nodes: OK (rc=0, origin=node02.example.com/crmd/46427, version=0.93.42) Jan 25 17:05:46 [21933] node02.example.com cib: info: cib_process_request: Forwarding cib_delete operation for section //node_state[@uname='node02.example.com']/lrm to all (origin=local/crmd/46428) Jan 25 17:05:46 [21933] node02.example.com cib: info: cib_process_request: Forwarding cib_modify operation for section status to all (origin=local/crmd/46429) Jan 25 17:05:46 [21933] node02.example.com cib: info: cib_process_request: Forwarding cib_delete operation for section //node_state[@uname='node01.example.com']/lrm to all (origin=local/crmd/46430) Jan 25 17:05:46 [21933] node02.example.com cib: info: cib_process_request: Forwarding cib_modify operation for section status to all (origin=local/crmd/46431) Jan 25 17:05:46 [21933] node02.example.com cib: info: cib_perform_op: Diff: --- 0.93.42 2 Jan 25 17:05:46 [21933] node02.example.com cib: info: cib_perform_op: Diff: +++ 0.93.43 (null) Jan 25 17:05:46 [21933] node02.example.com cib: info: cib_perform_op: -- /cib/status/node_state[@id='2']/lrm[@id='2'] Jan 25 17:05:46 [21933] node02.example.com cib: info: cib_perform_op: + /cib: @num_updates=43 Jan 25 17:05:46 [21933] node02.example.com cib: info: cib_process_request: Completed cib_delete operation for section //node_state[@uname='node02.example.com']/lrm: OK (rc=0, origin=node02.example.com/crmd/46428, version=0.93.43) Jan 25 17:05:46 [21933] node02.example.com cib: info: cib_perform_op: Diff: --- 0.93.43 2 Jan 25 17:05:46 [21933] node02.example.com cib: info: cib_perform_op: Diff: +++ 0.93.44 (null) Jan 25 17:05:46 [21933] node02.example.com cib: info: cib_perform_op: + /cib: @num_updates=44 Jan 25 17:05:46 [21933] node02.example.com cib: info: cib_perform_op: + /cib/status/node_state[@id='2']: @crm-debug-origin=do_lrm_query_internal Jan 25 17:05:46 [21933] node02.example.com cib: info: cib_perform_op: ++ /cib/status/node_state[@id='2']: Jan 25 17:05:46 [21933] node02.example.com cib: info: cib_perform_op: ++ Jan 25 17:05:46 [21933] node02.example.com cib: info: cib_perform_op: ++ Jan 25 17:05:46 [21933] node02.example.com cib: info: cib_perform_op: ++ Jan 25 17:05:46 [21933] node02.example.com cib: info: cib_perform_op: ++ Jan 25 17:05:46 [21933] node02.example.com cib: info: cib_perform_op: ++ Jan 25 17:05:46 [21933] node02.example.com cib: info: cib_perform_op: ++ Jan 25 17:05:46 [21933] node02.example.com cib: info: cib_perform_op: ++ Jan 25 17:05:46 [21933] node02.example.com cib: info: cib_perform_op: ++ Jan 25 17:05:46 [21933] node02.example.com cib: info: cib_perform_op: ++ Jan 25 17:05:46 [21933] node02.example.com cib: info: cib_perform_op: ++ Jan 25 17:05:46 [21933] node02.example.com cib: info: cib_perform_op: ++ Jan 25 17:05:46 [21933] node02.example.com cib: info: cib_perform_op: ++ Jan 25 17:05:46 [21933] node02.example.com cib: info: cib_perform_op: ++ Jan 25 17:05:46 [21933] node02.example.com cib: info: cib_perform_op: ++ Jan 25 17:05:46 [21933] node02.example.com cib: info: cib_process_request: Completed cib_modify operation for section status: OK (rc=0, origin=node02.example.com/crmd/46429, version=0.93.44) Jan 25 17:05:46 [21938] node02.example.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 Jan 25 17:05:46 [21938] node02.example.com crmd: info: abort_transition_graph: Transition aborted: Peer Cancelled | source=do_te_invoke:143 complete=true Jan 25 17:05:46 [21933] node02.example.com cib: info: cib_perform_op: Diff: --- 0.93.44 2 Jan 25 17:05:46 [21933] node02.example.com cib: info: cib_perform_op: Diff: +++ 0.93.45 (null) Jan 25 17:05:46 [21933] node02.example.com cib: info: cib_perform_op: -- /cib/status/node_state[@id='1']/lrm[@id='1'] Jan 25 17:05:46 [21933] node02.example.com cib: info: cib_perform_op: + /cib: @num_updates=45 Jan 25 17:05:46 [21933] node02.example.com cib: info: cib_process_request: Completed cib_delete operation for section //node_state[@uname='node01.example.com']/lrm: OK (rc=0, origin=node02.example.com/crmd/46430, version=0.93.45) Jan 25 17:05:46 [21938] node02.example.com crmd: info: abort_transition_graph: Transition aborted by deletion of lrm[@id='1']: Resource state removal | cib=0.93.45 source=abort_unless_down:357 path=/cib/status/node_state[@id='1']/lrm[@id='1'] complete=true Jan 25 17:05:46 [21933] node02.example.com cib: info: cib_perform_op: Diff: --- 0.93.45 2 Jan 25 17:05:46 [21933] node02.example.com cib: info: cib_perform_op: Diff: +++ 0.93.46 (null) Jan 25 17:05:46 [21933] node02.example.com cib: info: cib_perform_op: + /cib: @num_updates=46 Jan 25 17:05:46 [21933] node02.example.com cib: info: cib_perform_op: + /cib/status/node_state[@id='1']: @crm-debug-origin=do_lrm_query_internal Jan 25 17:05:46 [21933] node02.example.com cib: info: cib_perform_op: ++ /cib/status/node_state[@id='1']: Jan 25 17:05:46 [21933] node02.example.com cib: info: cib_perform_op: ++ Jan 25 17:05:46 [21933] node02.example.com cib: info: cib_perform_op: ++ Jan 25 17:05:46 [21933] node02.example.com cib: info: cib_perform_op: ++ Jan 25 17:05:46 [21933] node02.example.com cib: info: cib_perform_op: ++ Jan 25 17:05:46 [21933] node02.example.com cib: info: cib_perform_op: ++ Jan 25 17:05:46 [21933] node02.example.com cib: info: cib_perform_op: ++ Jan 25 17:05:46 [21933] node02.example.com cib: info: cib_perform_op: ++ Jan 25 17:05:46 [21933] node02.example.com cib: info: cib_perform_op: ++ Jan 25 17:05:46 [21933] node02.example.com cib: info: cib_perform_op: ++ Jan 25 17:05:46 [21933] node02.example.com cib: info: cib_perform_op: ++ Jan 25 17:05:46 [21933] node02.example.com cib: info: cib_perform_op: ++ Jan 25 17:05:46 [21933] node02.example.com cib: info: cib_perform_op: ++ Jan 25 17:05:46 [21933] node02.example.com cib: info: cib_perform_op: ++ Jan 25 17:05:46 [21933] node02.example.com cib: info: cib_perform_op: ++ Jan 25 17:05:46 [21933] node02.example.com cib: info: cib_perform_op: ++ Jan 25 17:05:46 [21933] node02.example.com cib: info: cib_process_request: Completed cib_modify operation for section status: OK (rc=0, origin=node02.example.com/crmd/46431, version=0.93.46) Jan 25 17:05:46 [21938] node02.example.com crmd: info: abort_transition_graph: Transition aborted: LRM Refresh | source=process_resource_updates:278 complete=true Jan 25 17:05:46 [21933] node02.example.com cib: info: cib_process_request: Forwarding cib_modify operation for section nodes to all (origin=local/crmd/46434) Jan 25 17:05:46 [21933] node02.example.com cib: info: cib_process_request: Forwarding cib_modify operation for section status to all (origin=local/crmd/46435) Jan 25 17:05:46 [21933] node02.example.com cib: info: cib_process_request: Forwarding cib_modify operation for section cib to all (origin=local/crmd/46436) Jan 25 17:05:46 [21933] node02.example.com cib: info: cib_process_request: Completed cib_modify operation for section nodes: OK (rc=0, origin=node02.example.com/crmd/46434, version=0.93.46) Jan 25 17:05:46 [21933] node02.example.com cib: info: cib_perform_op: Diff: --- 0.93.46 2 Jan 25 17:05:46 [21933] node02.example.com cib: info: cib_perform_op: Diff: +++ 0.93.47 (null) Jan 25 17:05:46 [21933] node02.example.com cib: info: cib_perform_op: + /cib: @num_updates=47 Jan 25 17:05:46 [21933] node02.example.com cib: info: cib_perform_op: + /cib/status/node_state[@id='1']: @crm-debug-origin=do_state_transition Jan 25 17:05:46 [21933] node02.example.com cib: info: cib_perform_op: + /cib/status/node_state[@id='2']: @crm-debug-origin=do_state_transition Jan 25 17:05:46 [21933] node02.example.com cib: info: cib_process_request: Completed cib_modify operation for section status: OK (rc=0, origin=node02.example.com/crmd/46435, version=0.93.47) Jan 25 17:05:46 [21933] node02.example.com cib: info: cib_process_request: Completed cib_modify operation for section cib: OK (rc=0, origin=node02.example.com/crmd/46436, version=0.93.47) Jan 25 17:05:46 [21933] node02.example.com cib: info: cib_file_backup: Archived previous version as /var/lib/pacemaker/cib/cib-39.raw Jan 25 17:05:46 [21933] node02.example.com cib: info: cib_file_write_with_digest: Wrote version 0.93.0 of the CIB to disk (digest: 6cb3f7483694406dcd087e74b49b9823) Jan 25 17:05:46 [21933] node02.example.com cib: info: cib_file_write_with_digest: Reading cluster configuration file /var/lib/pacemaker/cib/cib.BXPlGI (digest: /var/lib/pacemaker/cib/cib.2UCFI0) Jan 25 17:05:46 [21937] node02.example.com pengine: info: unpack_status: Node node01.example.com is in maintenance-mode Jan 25 17:05:46 [21937] node02.example.com pengine: info: determine_online_status: Node node01.example.com is maintenance Jan 25 17:05:46 [21937] node02.example.com pengine: info: determine_online_status: Node node02.example.com is online Jan 25 17:05:46 [21937] node02.example.com pengine: info: native_add_running: resource drbd_ourApp:0 isn't managed Jan 25 17:05:46 [21937] node02.example.com pengine: info: native_add_running: resource pingd:0 isn't managed Jan 25 17:05:46 [21937] node02.example.com pengine: info: determine_op_status: Operation monitor found resource drbd_ourApp:1 active in master mode on node02.example.com Jan 25 17:05:46 [21937] node02.example.com pengine: info: unpack_node_loop: Node 1 is already processed Jan 25 17:05:46 [21937] node02.example.com pengine: info: unpack_node_loop: Node 2 is already processed Jan 25 17:05:46 [21937] node02.example.com pengine: info: unpack_node_loop: Node 1 is already processed Jan 25 17:05:46 [21937] node02.example.com pengine: info: unpack_node_loop: Node 2 is already processed Jan 25 17:05:46 [21937] node02.example.com pengine: info: group_print: Resource Group: httpd Jan 25 17:05:46 [21937] node02.example.com pengine: info: common_print: daemon_httpd (ocf::heartbeat:apache): Stopped Jan 25 17:05:46 [21937] node02.example.com pengine: info: group_print: Resource Group: ourApp Jan 25 17:05:46 [21937] node02.example.com pengine: info: common_print: fs_ourApp (ocf::heartbeat:Filesystem): Stopped Jan 25 17:05:46 [21937] node02.example.com pengine: info: common_print: ip_ourApp (ocf::heartbeat:IPaddr2): Stopped Jan 25 17:05:46 [21937] node02.example.com pengine: info: common_print: app_ourApp (lsb:ourUser): Stopped Jan 25 17:05:46 [21937] node02.example.com pengine: info: clone_print: Master/Slave Set: ms_drbd_ourApp [drbd_ourApp] Jan 25 17:05:46 [21937] node02.example.com pengine: info: common_print: drbd_ourApp (ocf::linbit:drbd): Slave node01.example.com (unmanaged) Jan 25 17:05:46 [21937] node02.example.com pengine: info: short_print: Slaves: [ node02.example.com ] Jan 25 17:05:46 [21937] node02.example.com pengine: info: clone_print: Clone Set: pingdclone [pingd] Jan 25 17:05:46 [21937] node02.example.com pengine: info: common_print: pingd (ocf::pacemaker:ping): Started node01.example.com (unmanaged) Jan 25 17:05:46 [21937] node02.example.com pengine: info: short_print: Started: [ node02.example.com ] Jan 25 17:05:46 [21937] node02.example.com pengine: info: native_color: Unmanaged resource drbd_ourApp:0 allocated to node01.example.com: active Jan 25 17:05:46 [21937] node02.example.com pengine: info: master_color: ms_drbd_ourApp: Promoted 0 instances of a possible 1 to master Jan 25 17:05:46 [21937] node02.example.com pengine: info: rsc_merge_weights: fs_ourApp: Rolling back scores from ip_ourApp Jan 25 17:05:46 [21937] node02.example.com pengine: info: native_color: Resource fs_ourApp cannot run anywhere Jan 25 17:05:46 [21937] node02.example.com pengine: info: rsc_merge_weights: ip_ourApp: Rolling back scores from app_ourApp Jan 25 17:05:46 [21937] node02.example.com pengine: info: rsc_merge_weights: ip_ourApp: Rolling back scores from daemon_httpd Jan 25 17:05:46 [21937] node02.example.com pengine: info: native_color: Resource ip_ourApp cannot run anywhere Jan 25 17:05:46 [21937] node02.example.com pengine: info: native_color: Resource app_ourApp cannot run anywhere Jan 25 17:05:46 [21937] node02.example.com pengine: info: native_color: Resource daemon_httpd cannot run anywhere Jan 25 17:05:46 [21937] node02.example.com pengine: info: native_color: Unmanaged resource pingd:0 allocated to node01.example.com: active Jan 25 17:05:46 [21937] node02.example.com pengine: info: LogActions: Leave daemon_httpd (Stopped) Jan 25 17:05:46 [21937] node02.example.com pengine: info: LogActions: Leave fs_ourApp (Stopped) Jan 25 17:05:46 [21937] node02.example.com pengine: info: LogActions: Leave ip_ourApp (Stopped) Jan 25 17:05:46 [21937] node02.example.com pengine: info: LogActions: Leave app_ourApp (Stopped) Jan 25 17:05:46 [21937] node02.example.com pengine: info: LogActions: Leave drbd_ourApp:0 (Slave unmanaged) Jan 25 17:05:46 [21937] node02.example.com pengine: info: LogActions: Leave drbd_ourApp:1 (Slave node02.example.com) Jan 25 17:05:46 [21937] node02.example.com pengine: info: LogActions: Leave pingd:0 (Started unmanaged) Jan 25 17:05:46 [21937] node02.example.com pengine: info: LogActions: Leave pingd:1 (Started node02.example.com) Jan 25 17:05:46 [21938] node02.example.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 Jan 25 17:05:46 [21938] node02.example.com crmd: info: do_te_invoke: Processing graph 37021 (ref=pe_calc-dc-1611612346-42257) derived from /var/lib/pacemaker/pengine/pe-input-3244.bz2 Jan 25 17:05:46 [21937] node02.example.com pengine: notice: process_pe_message: Calculated transition 37021, saving inputs in /var/lib/pacemaker/pengine/pe-input-3244.bz2 Jan 25 17:05:46 [21938] node02.example.com crmd: notice: run_graph: Transition 37021 (Complete=0, Pending=0, Fired=0, Skipped=0, Incomplete=0, Source=/var/lib/pacemaker/pengine/pe-input-3244.bz2): Complete Jan 25 17:05:46 [21938] node02.example.com crmd: info: do_log: Input I_TE_SUCCESS received in state S_TRANSITION_ENGINE from notify_crmd Jan 25 17:05:46 [21938] node02.example.com crmd: notice: do_state_transition: State transition S_TRANSITION_ENGINE -> S_IDLE | input=I_TE_SUCCESS cause=C_FSA_INTERNAL origin=notify_crmd Jan 25 17:05:51 [21933] node02.example.com cib: info: cib_process_ping: Reporting our current digest to node02.example.com: b01b9fe072ac160a9f58b1e59f221900 for 0.93.47 (0x5646ba93bcc0 0) Jan 25 17:20:46 [21938] node02.example.com crmd: info: crm_timer_popped: PEngine Recheck Timer (I_PE_CALC) just popped (900000ms)