Any advice about how to fix this? I've been struggling to get things working for weeks now and I think this is the final stumbling block I need to figure out.
On May 23, 2018, at 2:22 PM, Casey & Gina <caseyandg...@icloud.com> wrote: >>> So now my concern is this - our VM's are distributed across 32 hosts. One >>> condition we were hoping to handle was when one of those host machines >>> fails, due to bad memory or something else, as it is likely that not all of >>> the nodes within a cluster are residing on the same VM host (there may even >>> be some way to configure them to stay on separate hosts in ESX). In this >>> case, a reset command will fail as well, I'd assume. I had thought that >>> when the resource was fenced, it was done with an 'off' command, and that >>> the resources would be brought up on a standby node. Is there a way to >>> make this work? >> >> Configure your stonith agent to use "off" instead of "reset". > > I tried a setup with RESETPOWERON="1" for the external/vcenter stonith > plugin. It does seem to work better, but I end up with a node that can't > rejoin the cluster without being immediately rebooted, due to the PostgreSQL > resource failing. > > I have pcsd set to auto-start at boot, but not pacemaker or corosync. After > I power off the node in vSphere, the node is fenced and then powered back on. > I see it show up in `pcs status` with PCSD Status of Online after a few > seconds but shown as OFFLINE in the list of nodes on top since pacemaker and > corosync are not running. If I then do a `pcs cluster start` on the rebooted > node, it is again restarted. So I cannot get it to rejoin the cluster. > > The corosync log from another node in the cluster (pasted below) indicates > that PostgreSQL fails to start after pacemaker/corosync are restarted (on > d-gp2-dbpg0-1 in this case), but it does not seem to give any reason as to > why. When I look on the failed node, I see that the PostgreSQL log is not > being appended, so it doesn't seem it's ever actually trying to start it. > I'm not sure where else I could try looking. > > Strangely, if prior to running `pcs cluster start` on the rebooted node, I > sudo to postgres, copy the recovery.conf template to the data directory, and > use pg_ctl to start the database, it comes up just fine in standby mode. > Then if I do `pcs cluster start`, the node rejoins the cluster just fine > without any problem. > > Can you tell me why pacemaker is failing to start PostgreSQL in standby mode > based on the log data below, or how I can dig deeper into what is going on? > Is this due to some misconfiguration on my part? I thought that PAF would > try to do exactly what I do manually, but it doesn't seem this is the case... > > Actually, why is Pacemaker fencing the standby node just because the resource > fails to start there? I thought only the master should be fenced if it were > assumed to be broken. > > Thank you for any help you can provide, > -- > Casey > > > ------ > [2157] d-gp2-dbpg0-2 corosyncnotice [TOTEM ] A new membership > (10.124.164.63:392) was formed. Members joined: 1 > May 22 23:57:19 [2189] d-gp2-dbpg0-2 pacemakerd: info: > pcmk_quorum_notification: Membership 392: quorum retained (3) > May 22 23:57:19 [2197] d-gp2-dbpg0-2 crmd: info: > pcmk_quorum_notification: Membership 392: quorum retained (3) > May 22 23:57:19 [2189] d-gp2-dbpg0-2 pacemakerd: notice: > crm_update_peer_state_iter: pcmk_quorum_notification: Node d-gp2-dbpg0-1[1] > - state is now member (was lost) > May 22 23:57:19 [2197] d-gp2-dbpg0-2 crmd: notice: > crm_update_peer_state_iter: pcmk_quorum_notification: Node d-gp2-dbpg0-1[1] > - state is now member (was lost) > May 22 23:57:19 [2192] d-gp2-dbpg0-2 cib: info: > cib_process_request: Forwarding cib_modify operation for section status to > master (origin=local/crmd/268) > May 22 23:57:19 [2192] d-gp2-dbpg0-2 cib: info: cib_perform_op: > Diff: --- 0.35.51 2 > May 22 23:57:19 [2192] d-gp2-dbpg0-2 cib: info: cib_perform_op: > Diff: +++ 0.35.52 (null) > May 22 23:57:19 [2192] d-gp2-dbpg0-2 cib: info: cib_perform_op: > + /cib: @num_updates=52 > May 22 23:57:19 [2192] d-gp2-dbpg0-2 cib: info: cib_perform_op: > + /cib/status/node_state[@id='1']: @crm-debug-origin=peer_update_callback > May 22 23:57:19 [2192] d-gp2-dbpg0-2 cib: info: > cib_process_request: Completed cib_modify operation for section status: OK > (rc=0, origin=d-gp2-dbpg0-2/crmd/268, version=0.35.52) > May 22 23:57:19 [2192] d-gp2-dbpg0-2 cib: info: > cib_process_request: Forwarding cib_modify operation for section nodes to > master (origin=local/crmd/272) > May 22 23:57:19 [2192] d-gp2-dbpg0-2 cib: info: > cib_process_request: Forwarding cib_modify operation for section status to > master (origin=local/crmd/273) > May 22 23:57:19 [2192] d-gp2-dbpg0-2 cib: info: > cib_process_request: Completed cib_modify operation for section nodes: OK > (rc=0, origin=d-gp2-dbpg0-2/crmd/272, version=0.35.52) > May 22 23:57:19 [2192] d-gp2-dbpg0-2 cib: info: cib_perform_op: > Diff: --- 0.35.52 2 > May 22 23:57:19 [2192] d-gp2-dbpg0-2 cib: info: cib_perform_op: > Diff: +++ 0.35.53 (null) > May 22 23:57:19 [2192] d-gp2-dbpg0-2 cib: info: cib_perform_op: > + /cib: @num_updates=53 > May 22 23:57:19 [2192] d-gp2-dbpg0-2 cib: info: cib_perform_op: > + /cib/status/node_state[@id='1']: @in_ccm=true, > @crm-debug-origin=post_cache_update > May 22 23:57:19 [2192] d-gp2-dbpg0-2 cib: info: > cib_process_request: Completed cib_modify operation for section status: OK > (rc=0, origin=d-gp2-dbpg0-2/crmd/273, version=0.35.53) > May 22 23:57:19 [2189] d-gp2-dbpg0-2 pacemakerd: info: > pcmk_cpg_membership: Node 1 joined group pacemakerd (counter=10.0) > May 22 23:57:19 [2189] d-gp2-dbpg0-2 pacemakerd: info: > pcmk_cpg_membership: Node 1 still member of group pacemakerd > (peer=d-gp2-dbpg0-1, counter=10.0) > May 22 23:57:19 [2189] d-gp2-dbpg0-2 pacemakerd: info: > crm_update_peer_proc: pcmk_cpg_membership: Node d-gp2-dbpg0-1[1] - > corosync-cpg is now online > May 22 23:57:19 [2189] d-gp2-dbpg0-2 pacemakerd: info: > pcmk_cpg_membership: Node 2 still member of group pacemakerd > (peer=d-gp2-dbpg0-2, counter=10.1) > May 22 23:57:19 [2189] d-gp2-dbpg0-2 pacemakerd: info: > pcmk_cpg_membership: Node 3 still member of group pacemakerd > (peer=d-gp2-dbpg0-3, counter=10.2) > May 22 23:57:19 [2195] d-gp2-dbpg0-2 attrd: info: > pcmk_cpg_membership: Node 1 joined group attrd (counter=10.0) > May 22 23:57:19 [2195] d-gp2-dbpg0-2 attrd: info: crm_get_peer: > Created entry 867f0ed1-1863-40fa-8f49-a3aeba90d9e7/0x55755bf16e60 for node > d-gp2-dbpg0-1/1 (3 total) > May 22 23:57:19 [2195] d-gp2-dbpg0-2 attrd: info: crm_get_peer: > Node 1 is now known as d-gp2-dbpg0-1 > May 22 23:57:19 [2195] d-gp2-dbpg0-2 attrd: info: crm_get_peer: > Node 1 has uuid 1 > May 22 23:57:19 [2195] d-gp2-dbpg0-2 attrd: info: > pcmk_cpg_membership: Node 1 still member of group attrd (peer=d-gp2-dbpg0-1, > counter=10.0) > May 22 23:57:19 [2195] d-gp2-dbpg0-2 attrd: info: > crm_update_peer_proc: pcmk_cpg_membership: Node d-gp2-dbpg0-1[1] - > corosync-cpg is now online > May 22 23:57:19 [2195] d-gp2-dbpg0-2 attrd: notice: > crm_update_peer_state_iter: crm_update_peer_proc: Node d-gp2-dbpg0-1[1] - > state is now member (was (null)) > May 22 23:57:19 [2195] d-gp2-dbpg0-2 attrd: info: > pcmk_cpg_membership: Node 2 still member of group attrd (peer=d-gp2-dbpg0-2, > counter=10.1) > May 22 23:57:19 [2195] d-gp2-dbpg0-2 attrd: info: > pcmk_cpg_membership: Node 3 still member of group attrd (peer=d-gp2-dbpg0-3, > counter=10.2) > May 22 23:57:19 [2193] d-gp2-dbpg0-2 stonith-ng: info: > pcmk_cpg_membership: Node 1 joined group stonith-ng (counter=10.0) > May 22 23:57:19 [2193] d-gp2-dbpg0-2 stonith-ng: info: crm_get_peer: > Created entry f24c063b-0e1b-4dc6-b715-2a79a0629aa2/0x556b010e60e0 for node > d-gp2-dbpg0-1/1 (3 total) > May 22 23:57:19 [2193] d-gp2-dbpg0-2 stonith-ng: info: crm_get_peer: > Node 1 is now known as d-gp2-dbpg0-1 > May 22 23:57:19 [2193] d-gp2-dbpg0-2 stonith-ng: info: crm_get_peer: > Node 1 has uuid 1 > May 22 23:57:19 [2193] d-gp2-dbpg0-2 stonith-ng: info: > pcmk_cpg_membership: Node 1 still member of group stonith-ng > (peer=d-gp2-dbpg0-1, counter=10.0) > May 22 23:57:19 [2193] d-gp2-dbpg0-2 stonith-ng: info: > crm_update_peer_proc: pcmk_cpg_membership: Node d-gp2-dbpg0-1[1] - > corosync-cpg is now online > May 22 23:57:19 [2193] d-gp2-dbpg0-2 stonith-ng: notice: > crm_update_peer_state_iter: crm_update_peer_proc: Node d-gp2-dbpg0-1[1] - > state is now member (was (null)) > May 22 23:57:19 [2193] d-gp2-dbpg0-2 stonith-ng: info: > pcmk_cpg_membership: Node 2 still member of group stonith-ng > (peer=d-gp2-dbpg0-2, counter=10.1) > May 22 23:57:19 [2193] d-gp2-dbpg0-2 stonith-ng: info: > pcmk_cpg_membership: Node 3 still member of group stonith-ng > (peer=d-gp2-dbpg0-3, counter=10.2) > May 22 23:57:19 [2192] d-gp2-dbpg0-2 cib: info: > pcmk_cpg_membership: Node 1 joined group cib (counter=10.0) > May 22 23:57:19 [2192] d-gp2-dbpg0-2 cib: info: crm_get_peer: > Created entry add315f9-0548-4c81-8245-b9d3b4d08b4d/0x55cca2b97020 for node > d-gp2-dbpg0-1/1 (3 total) > May 22 23:57:19 [2192] d-gp2-dbpg0-2 cib: info: crm_get_peer: > Node 1 is now known as d-gp2-dbpg0-1 > May 22 23:57:19 [2192] d-gp2-dbpg0-2 cib: info: crm_get_peer: > Node 1 has uuid 1 > May 22 23:57:19 [2192] d-gp2-dbpg0-2 cib: info: > pcmk_cpg_membership: Node 1 still member of group cib (peer=d-gp2-dbpg0-1, > counter=10.0) > May 22 23:57:19 [2192] d-gp2-dbpg0-2 cib: info: > crm_update_peer_proc: pcmk_cpg_membership: Node d-gp2-dbpg0-1[1] - > corosync-cpg is now online > May 22 23:57:19 [2192] d-gp2-dbpg0-2 cib: notice: > crm_update_peer_state_iter: crm_update_peer_proc: Node d-gp2-dbpg0-1[1] - > state is now member (was (null)) > May 22 23:57:19 [2192] d-gp2-dbpg0-2 cib: info: > pcmk_cpg_membership: Node 2 still member of group cib (peer=d-gp2-dbpg0-2, > counter=10.1) > May 22 23:57:19 [2192] d-gp2-dbpg0-2 cib: info: > pcmk_cpg_membership: Node 3 still member of group cib (peer=d-gp2-dbpg0-3, > counter=10.2) > May 22 23:57:20 [2197] d-gp2-dbpg0-2 crmd: info: > pcmk_cpg_membership: Node 1 joined group crmd (counter=10.0) > May 22 23:57:20 [2197] d-gp2-dbpg0-2 crmd: info: > pcmk_cpg_membership: Node 1 still member of group crmd (peer=d-gp2-dbpg0-1, > counter=10.0) > May 22 23:57:20 [2197] d-gp2-dbpg0-2 crmd: info: > crm_update_peer_proc: pcmk_cpg_membership: Node d-gp2-dbpg0-1[1] - > corosync-cpg is now online > May 22 23:57:20 [2197] d-gp2-dbpg0-2 crmd: info: > pcmk_cpg_membership: Node 2 still member of group crmd (peer=d-gp2-dbpg0-2, > counter=10.1) > May 22 23:57:20 [2197] d-gp2-dbpg0-2 crmd: info: > pcmk_cpg_membership: Node 3 still member of group crmd (peer=d-gp2-dbpg0-3, > counter=10.2) > May 22 23:57:20 [2197] d-gp2-dbpg0-2 crmd: notice: > do_state_transition: State transition S_IDLE -> S_INTEGRATION [ > input=I_NODE_JOIN cause=C_FSA_INTERNAL origin=peer_update_callback ] > May 22 23:57:20 [2197] d-gp2-dbpg0-2 crmd: info: > abort_transition_graph: Transition aborted: Peer Halt > (source=do_te_invoke:168, 1) > May 22 23:57:20 [2192] d-gp2-dbpg0-2 cib: info: > cib_process_request: Forwarding cib_modify operation for section status to > master (origin=local/crmd/274) > May 22 23:57:20 [2192] d-gp2-dbpg0-2 cib: info: cib_perform_op: > Diff: --- 0.35.53 2 > May 22 23:57:20 [2192] d-gp2-dbpg0-2 cib: info: cib_perform_op: > Diff: +++ 0.35.54 (null) > May 22 23:57:20 [2192] d-gp2-dbpg0-2 cib: info: cib_perform_op: > + /cib: @num_updates=54 > May 22 23:57:20 [2192] d-gp2-dbpg0-2 cib: info: cib_perform_op: > + /cib/status/node_state[@id='1']: @crmd=online, > @crm-debug-origin=peer_update_callback > May 22 23:57:20 [2192] d-gp2-dbpg0-2 cib: info: > cib_process_request: Completed cib_modify operation for section status: OK > (rc=0, origin=d-gp2-dbpg0-2/crmd/274, version=0.35.54) > May 22 23:57:20 [2192] d-gp2-dbpg0-2 cib: info: > cib_process_request: Completed cib_modify operation for section nodes: OK > (rc=0, origin=d-gp2-dbpg0-1/crmd/6, version=0.35.54) > May 22 23:57:21 [2197] d-gp2-dbpg0-2 crmd: info: > abort_transition_graph: Transition aborted: Node join > (source=do_dc_join_offer_one:250, 1) > May 22 23:57:21 [2197] d-gp2-dbpg0-2 crmd: info: > crm_update_peer_expected: do_dc_join_filter_offer: Node d-gp2-dbpg0-1[1] - > expected state is now member (was down) > May 22 23:57:21 [2197] d-gp2-dbpg0-2 crmd: info: > do_state_transition: State transition S_INTEGRATION -> S_FINALIZE_JOIN [ > input=I_INTEGRATED cause=C_FSA_INTERNAL origin=check_join_state ] > May 22 23:57:21 [2197] d-gp2-dbpg0-2 crmd: info: > crmd_join_phase_log: join-2: d-gp2-dbpg0-1=integrated > May 22 23:57:21 [2197] d-gp2-dbpg0-2 crmd: info: > crmd_join_phase_log: join-2: d-gp2-dbpg0-3=confirmed > May 22 23:57:21 [2197] d-gp2-dbpg0-2 crmd: info: > crmd_join_phase_log: join-2: d-gp2-dbpg0-2=integrated > May 22 23:57:21 [2192] d-gp2-dbpg0-2 cib: info: > cib_process_replace: Digest matched on replace from d-gp2-dbpg0-2: > e2ee1983f2386143276255bdc4db56db > May 22 23:57:21 [2192] d-gp2-dbpg0-2 cib: info: > cib_process_replace: Replaced 0.35.54 with 0.35.54 from d-gp2-dbpg0-2 > May 22 23:57:21 [2192] d-gp2-dbpg0-2 cib: info: > cib_process_request: Completed cib_replace operation for section 'all': OK > (rc=0, origin=d-gp2-dbpg0-2/crmd/276, version=0.35.54) > May 22 23:57:21 [2192] d-gp2-dbpg0-2 cib: info: > cib_process_request: Forwarding cib_modify operation for section nodes to > master (origin=local/crmd/277) > May 22 23:57:21 [2192] d-gp2-dbpg0-2 cib: info: > cib_process_request: Forwarding cib_modify operation for section nodes to > master (origin=local/crmd/278) > May 22 23:57:21 [2192] d-gp2-dbpg0-2 cib: info: > cib_process_request: Completed cib_modify operation for section nodes: OK > (rc=0, origin=d-gp2-dbpg0-2/crmd/277, version=0.35.54) > May 22 23:57:21 [2192] d-gp2-dbpg0-2 cib: info: > cib_process_request: Completed cib_modify operation for section nodes: OK > (rc=0, origin=d-gp2-dbpg0-2/crmd/278, version=0.35.54) > May 22 23:57:21 [2197] d-gp2-dbpg0-2 crmd: info: > action_synced_wait: Managed IPaddr2_meta-data_0 process 11450 exited with > rc=0 > May 22 23:57:21 [2192] d-gp2-dbpg0-2 cib: info: cib_file_backup: > Archived previous version as /var/lib/pacemaker/cib/cib-44.raw > May 22 23:57:21 [2192] d-gp2-dbpg0-2 cib: info: > cib_file_write_with_digest: Wrote version 0.35.0 of the CIB to disk (digest: > 02cd04fe2eaf11aa3f455da2177a765f) > May 22 23:57:21 [2192] d-gp2-dbpg0-2 cib: info: > cib_file_write_with_digest: Reading cluster configuration file > /var/lib/pacemaker/cib/cib.JAWQvZ (digest: /var/lib/pacemaker/cib/cib.GYbAVa) > May 22 23:57:21 [2192] d-gp2-dbpg0-2 cib: info: > cib_process_request: Forwarding cib_delete operation for section > //node_state[@uname='d-gp2-dbpg0-2']/lrm to master (origin=local/crmd/279) > May 22 23:57:21 [2192] d-gp2-dbpg0-2 cib: info: cib_perform_op: > Diff: --- 0.35.54 2 > May 22 23:57:21 [2192] d-gp2-dbpg0-2 cib: info: cib_perform_op: > Diff: +++ 0.35.55 (null) > May 22 23:57:21 [2192] d-gp2-dbpg0-2 cib: info: cib_perform_op: > -- /cib/status/node_state[@id='2']/lrm[@id='2'] > May 22 23:57:21 [2192] d-gp2-dbpg0-2 cib: info: cib_perform_op: > + /cib: @num_updates=55 > May 22 23:57:21 [2192] d-gp2-dbpg0-2 cib: info: > cib_process_request: Completed cib_delete operation for section > //node_state[@uname='d-gp2-dbpg0-2']/lrm: OK (rc=0, > origin=d-gp2-dbpg0-2/crmd/279, version=0.35.55) > May 22 23:57:21 [2192] d-gp2-dbpg0-2 cib: info: > cib_process_request: Forwarding cib_modify operation for section status to > master (origin=local/crmd/280) > May 22 23:57:21 [2192] d-gp2-dbpg0-2 cib: info: cib_perform_op: > Diff: --- 0.35.55 2 > May 22 23:57:21 [2192] d-gp2-dbpg0-2 cib: info: cib_perform_op: > Diff: +++ 0.35.56 (null) > May 22 23:57:21 [2192] d-gp2-dbpg0-2 cib: info: cib_perform_op: > + /cib: @num_updates=56 > May 22 23:57:21 [2192] d-gp2-dbpg0-2 cib: info: cib_perform_op: > + /cib/status/node_state[@id='2']: @crm-debug-origin=do_lrm_query_internal > May 22 23:57:21 [2192] d-gp2-dbpg0-2 cib: info: cib_perform_op: > ++ /cib/status/node_state[@id='2']: <lrm id="2"/> > May 22 23:57:21 [2192] d-gp2-dbpg0-2 cib: info: cib_perform_op: > ++ <lrm_resources> > May 22 23:57:21 [2192] d-gp2-dbpg0-2 cib: info: cib_perform_op: > ++ <lrm_resource > id="postgresql-10-main" type="pgsqlms" class="ocf" provider="heartbeat"> > May 22 23:57:21 [2192] d-gp2-dbpg0-2 cib: info: cib_perform_op: > ++ <lrm_rsc_op > id="postgresql-10-main_last_failure_0" > operation_key="postgresql-10-main_monitor_0" operation="monitor" > crm-debug-origin="build_active_RAs" crm_feature_set="3.0.10" > transition-key="7:0:7:0df60493-9320-463d-94ca-a9515d139f9f" > transition-magic="0:0;7:0:7:0df60493-9320-463d-94ca-a9515d139f9f" > on_node="d-gp2-dbpg0-2" call-id="14" rc-code="0" op-status="0" interval="0" > last-run="1527 > May 22 23:57:21 [2192] d-gp2-dbpg0-2 cib: info: cib_perform_op: > ++ <lrm_rsc_op > id="postgresql-10-main_last_0" operation_key="postgresql-10-main_promote_0" > operation="promote" crm-debug-origin="build_active_RAs" > crm_feature_set="3.0.10" > transition-key="16:14:0:0df60493-9320-463d-94ca-a9515d139f9f" > transition-magic="0:0;16:14:0:0df60493-9320-463d-94ca-a9515d139f9f" > on_node="d-gp2-dbpg0-2" call-id="41" rc-code="0" op-status="0" interval="0" > last-run="15270322 > May 22 23:57:21 [2192] d-gp2-dbpg0-2 cib: info: cib_perform_op: > ++ <lrm_rsc_op > id="postgresql-10-main_monitor_15000" > operation_key="postgresql-10-main_monitor_15000" operation="monitor" > crm-debug-origin="build_active_RAs" crm_feature_set="3.0.10" > transition-key="17:14:8:0df60493-9320-463d-94ca-a9515d139f9f" > transition-magic="0:8;17:14:8:0df60493-9320-463d-94ca-a9515d139f9f" > on_node="d-gp2-dbpg0-2" call-id="44" rc-code="8" op-status="0" > interval="15000" las > May 22 23:57:21 [2192] d-gp2-dbpg0-2 cib: info: cib_perform_op: > ++ </lrm_resource> > May 22 23:57:21 [2192] d-gp2-dbpg0-2 cib: info: cib_perform_op: > ++ <lrm_resource > id="postgresql-master-vip" type="IPaddr2" class="ocf" provider="heartbeat"> > May 22 23:57:21 [2192] d-gp2-dbpg0-2 cib: info: cib_perform_op: > ++ <lrm_rsc_op > id="postgresql-master-vip_last_0" > operation_key="postgresql-master-vip_start_0" operation="start" > crm-debug-origin="build_active_RAs" crm_feature_set="3.0.10" > transition-key="8:14:0:0df60493-9320-463d-94ca-a9515d139f9f" > transition-magic="0:0;8:14:0:0df60493-9320-463d-94ca-a9515d139f9f" > on_node="d-gp2-dbpg0-2" call-id="43" rc-code="0" op-status="0" interval="0" > last-run="15270322 > May 22 23:57:21 [2192] d-gp2-dbpg0-2 cib: info: cib_perform_op: > ++ <lrm_rsc_op > id="postgresql-master-vip_monitor_10000" > operation_key="postgresql-master-vip_monitor_10000" operation="monitor" > crm-debug-origin="build_active_RAs" crm_feature_set="3.0.10" > transition-key="9:14:0:0df60493-9320-463d-94ca-a9515d139f9f" > transition-magic="0:0;9:14:0:0df60493-9320-463d-94ca-a9515d139f9f" > on_node="d-gp2-dbpg0-2" call-id="45" rc-code="0" op-status="0" > interval="10000" > May 22 23:57:21 [2192] d-gp2-dbpg0-2 cib: info: cib_perform_op: > ++ </lrm_resource> > May 22 23:57:21 [2192] d-gp2-dbpg0-2 cib: info: cib_perform_op: > ++ <lrm_resource id="vfencing" > type="external/vcenter" class="stonith"> > May 22 23:57:21 [2192] d-gp2-dbpg0-2 cib: info: cib_perform_op: > ++ <lrm_rsc_op id="vfencing_last_0" > operation_key="vfencing_start_0" operation="st > art" crm-debug-origin="build_active_RAs" crm_feature_set="3.0.10" > transition-key="5:14:0:0df60493-9320-463d-94ca-a9515d139f9f" > transition-magic="0:0;5:14:0:0df60493-9320-463d-94ca-a9515d139f9f" > on_node="d-gp2-dbpg0-2" call-id="34" rc-code="0" op-status="0" interval="0" > last-run="1527032266" last-rc-change="152703 > May 22 23:57:21 [2192] d-gp2-dbpg0-2 cib: info: cib_perform_op: > ++ <lrm_rsc_op > id="vfencing_monitor_60000" > operation_key="vfencing_monitor_60000"operation="monitor" > crm-debug-origin="build_active_RAs" crm_feature_set="3.0.10" > transition-key="6:14:0:0df60493-9320-463d-94ca-a9515d139f9f" > transition-magic="0:0;6:14:0:0df60493-9320-463d-94ca-a9515d139f9f" > on_node="d-gp2-dbpg0-2" call-id="36" rc-code="0" op-status="0" > interval="60000" last-rc-change="152703226 > May 22 23:57:21 [2192] d-gp2-dbpg0-2 cib: info: cib_perform_op: > ++ </lrm_resource> > May 22 23:57:21 [2192] d-gp2-dbpg0-2 cib: info: cib_perform_op: > ++ </lrm_resources> > May 22 23:57:21 [2192] d-gp2-dbpg0-2 cib: info: cib_perform_op: > ++ </lrm> > May 22 23:57:21 [2192] d-gp2-dbpg0-2 cib: info: > cib_process_request: Completed cib_modify operation for section status: OK > (rc=0, origin=d-gp2-dbpg0-2/crmd/280, version=0.35.56) > May 22 23:57:22 [2197] d-gp2-dbpg0-2 crmd: info: > do_state_transition: State transition S_FINALIZE_JOIN -> S_INTEGRATION [ > input=I_JOIN_REQUEST cause=C_HA_MESSAGE origin=route_message ] > May 22 23:57:22 [2197] d-gp2-dbpg0-2 crmd: info: > abort_transition_graph: Transition aborted: Node join > (source=do_dc_join_offer_one:250, 1) > May 22 23:57:22 [2197] d-gp2-dbpg0-2 crmd: info: do_log: FSA: > Input I_JOIN_RESULT from route_message() received in state S_INTEGRATION > May 22 23:57:22 [2192] d-gp2-dbpg0-2 cib: info: > cib_process_request: Forwarding cib_modify operation for section status to > master (origin=local/attrd/29) > May 22 23:57:22 [2197] d-gp2-dbpg0-2 crmd: info: > do_state_transition: State transition S_INTEGRATION -> S_FINALIZE_JOIN [ > input=I_INTEGRATED cause=C_FSA_INTERNAL origin=check_join_state ] > May 22 23:57:22 [2197] d-gp2-dbpg0-2 crmd: info: > crmd_join_phase_log: join-2: d-gp2-dbpg0-1=integrated > May 22 23:57:22 [2197] d-gp2-dbpg0-2 crmd: info: > crmd_join_phase_log: join-2: d-gp2-dbpg0-3=confirmed > May 22 23:57:22 [2197] d-gp2-dbpg0-2 crmd: info: > crmd_join_phase_log: join-2: d-gp2-dbpg0-2=integrated > May 22 23:57:22 [2192] d-gp2-dbpg0-2 cib: info: cib_perform_op: > Diff: --- 0.35.56 2 > May 22 23:57:22 [2192] d-gp2-dbpg0-2 cib: info: cib_perform_op: > Diff: +++ 0.35.57 (null) > May 22 23:57:22 [2192] d-gp2-dbpg0-2 cib: info: cib_perform_op: > + /cib: @num_updates=57 > May 22 23:57:22 [2192] d-gp2-dbpg0-2 cib: info: cib_perform_op: > ++ /cib/status/node_state[@id='1']: <transient_attributes id="1"/> > May 22 23:57:22 [2192] d-gp2-dbpg0-2 cib: info: cib_perform_op: > ++ <instance_attributes id="status-1"> > May 22 23:57:22 [2192] d-gp2-dbpg0-2 cib: info: cib_perform_op: > ++ <nvpair id="status-1-shutdown" > name="shutdown" value="0"/> > May 22 23:57:22 [2192] d-gp2-dbpg0-2 cib: info: cib_perform_op: > ++ </instance_attributes> > May 22 23:57:22 [2192] d-gp2-dbpg0-2 cib: info: cib_perform_op: > ++ </transient_attributes> > May 22 23:57:22 [2192] d-gp2-dbpg0-2 cib: info: > cib_process_request: Completed cib_modify operation for section status: OK > (rc=0, origin=d-gp2-dbpg0-2/attrd/29, version=0.35.57) > May 22 23:57:22 [2195] d-gp2-dbpg0-2 attrd: info: > attrd_cib_callback: Update 29 for shutdown: OK (0) > May 22 23:57:22 [2195] d-gp2-dbpg0-2 attrd: info: > attrd_cib_callback: Update 29 for shutdown[d-gp2-dbpg0-1]=0: OK (0) > May 22 23:57:22 [2195] d-gp2-dbpg0-2 attrd: info: > attrd_cib_callback: Update 29 for shutdown[d-gp2-dbpg0-2]=0: OK (0) > May 22 23:57:22 [2195] d-gp2-dbpg0-2 attrd: info: > attrd_cib_callback: Update 29 for shutdown[d-gp2-dbpg0-3]=0: OK (0) > May 22 23:57:22 [2192] d-gp2-dbpg0-2 cib: info: cib_perform_op: > Diff: --- 0.35.57 2 > May 22 23:57:22 [2192] d-gp2-dbpg0-2 cib: info: cib_perform_op: > Diff: +++ 0.35.58 (null) > May 22 23:57:22 [2192] d-gp2-dbpg0-2 cib: info: cib_perform_op: > -- /cib/status/node_state[@id='1']/transient_attributes[@id='1'] > May 22 23:57:22 [2192] d-gp2-dbpg0-2 cib: info: cib_perform_op: > + /cib: @num_updates=58 > May 22 23:57:22 [2192] d-gp2-dbpg0-2 cib: info: > cib_process_request: Completed cib_delete operation for section > //node_state[@uname='d-gp2-dbpg0-1']/transient_attributes: OK (rc=0, > origin=d-gp2-dbpg0-1/crmd/11, version=0.35.58) > May 22 23:57:22 [2192] d-gp2-dbpg0-2 cib: info: cib_perform_op: > Diff: --- 0.35.58 2 > May 22 23:57:22 [2192] d-gp2-dbpg0-2 cib: info: cib_perform_op: > Diff: +++ 0.35.59 (null) > May 22 23:57:22 [2192] d-gp2-dbpg0-2 cib: info: cib_perform_op: > + /cib: @num_updates=59 > May 22 23:57:22 [2192] d-gp2-dbpg0-2 cib: info: cib_perform_op: > ++ /cib/status/node_state[@id='1']: <transient_attributes id="1"/> > May 22 23:57:22 [2192] d-gp2-dbpg0-2 cib: info: cib_perform_op: > ++ <instance_attributes id="status-1"> > May 22 23:57:22 [2192] d-gp2-dbpg0-2 cib: info: cib_perform_op: > ++ <nvpair id="status-1-shutdown" > name="shutdown" value="0"/> > May 22 23:57:22 [2192] d-gp2-dbpg0-2 cib: info: cib_perform_op: > ++ </instance_attributes> > May 22 23:57:22 [2192] d-gp2-dbpg0-2 cib: info: cib_perform_op: > ++ </transient_attributes> > May 22 23:57:22 [2192] d-gp2-dbpg0-2 cib: info: > cib_process_request: Completed cib_modify operation for section status: OK > (rc=0, origin=d-gp2-dbpg0-1/attrd/2, version=0.35.59) > May 22 23:57:22 [2192] d-gp2-dbpg0-2 cib: info: cib_perform_op: > Diff: --- 0.35.59 2 > May 22 23:57:22 [2192] d-gp2-dbpg0-2 cib: info: cib_perform_op: > Diff: +++ 0.35.60 (null) > May 22 23:57:22 [2192] d-gp2-dbpg0-2 cib: info: cib_perform_op: > + /cib: @num_updates=60 > May 22 23:57:22 [2192] d-gp2-dbpg0-2 cib: info: > cib_process_request: Completed cib_modify operation for section status: OK > (rc=0, origin=d-gp2-dbpg0-1/attrd/3, version=0.35.60) > May 22 23:57:22 [2192] d-gp2-dbpg0-2 cib: info: > cib_process_replace: Digest matched on replace from d-gp2-dbpg0-2: > 55b20c22b84ba495b2aaa47e0c413465 > May 22 23:57:22 [2192] d-gp2-dbpg0-2 cib: info: > cib_process_replace: Replaced 0.35.60 with 0.35.60 from d-gp2-dbpg0-2 > May 22 23:57:22 [2192] d-gp2-dbpg0-2 cib: info: > cib_process_request: Completed cib_replace operation for section 'all': OK > (rc=0, origin=d-gp2-dbpg0-2/crmd/282, version=0.35.60) > May 22 23:57:22 [2192] d-gp2-dbpg0-2 cib: info: > cib_process_request: Completed cib_modify operation for section status: OK > (rc=0, origin=d-gp2-dbpg0-1/attrd/4, version=0.35.60) > May 22 23:57:22 [2192] d-gp2-dbpg0-2 cib: info: cib_perform_op: > Diff: --- 0.35.60 2 > May 22 23:57:22 [2192] d-gp2-dbpg0-2 cib: info: cib_perform_op: > Diff: +++ 0.35.61 (null) > May 22 23:57:22 [2192] d-gp2-dbpg0-2 cib: info: cib_perform_op: > + /cib: @num_updates=61 > May 22 23:57:22 [2192] d-gp2-dbpg0-2 cib: info: > cib_process_request: Completed cib_modify operation for section status: OK > (rc=0, origin=d-gp2-dbpg0-1/attrd/5, version=0.35.61) > May 22 23:57:22 [2192] d-gp2-dbpg0-2 cib: info: > cib_process_request: Forwarding cib_modify operation for section nodes to > master (origin=local/crmd/283) > May 22 23:57:22 [2192] d-gp2-dbpg0-2 cib: info: > cib_process_request: Forwarding cib_modify operation for section nodes to > master (origin=local/crmd/284) > May 22 23:57:22 [2192] d-gp2-dbpg0-2 cib: info: > cib_process_request: Completed cib_modify operation for section nodes: OK > (rc=0, origin=d-gp2-dbpg0-2/crmd/283, version=0.35.61) > May 22 23:57:22 [2192] d-gp2-dbpg0-2 cib: info: > cib_process_request: Completed cib_modify operation for section nodes: OK > (rc=0, origin=d-gp2-dbpg0-2/crmd/284, version=0.35.61) > May 22 23:57:22 [2197] d-gp2-dbpg0-2 crmd: info: > action_synced_wait: Managed IPaddr2_meta-data_0 process 11461 exited with > rc=0 > May 22 23:57:22 [2192] d-gp2-dbpg0-2 cib: info: cib_file_backup: > Archived previous version as /var/lib/pacemaker/cib/cib-45.raw > May 22 23:57:22 [2192] d-gp2-dbpg0-2 cib: info: > cib_file_write_with_digest: Wrote version 0.35.0 of the CIB to disk (digest: > 570c1d5717516723a1348d52e22d54a9) > May 22 23:57:22 [2192] d-gp2-dbpg0-2 cib: info: > cib_file_write_with_digest: Reading cluster configuration file > /var/lib/pacemaker/cib/cib.Nx9RP6 (digest: /var/lib/pacemaker/cib/cib.iQFz8k) > May 22 23:57:22 [2192] d-gp2-dbpg0-2 cib: info: > cib_process_request: Forwarding cib_delete operation for section > //node_state[@uname='d-gp2-dbpg0-1']/lrm to master (origin=local/crmd/285) > May 22 23:57:22 [2192] d-gp2-dbpg0-2 cib: info: > cib_process_request: Completed cib_delete operation for section > //node_state[@uname='d-gp2-dbpg0-1']/lrm: OK (rc=0, > origin=d-gp2-dbpg0-2/crmd/285, version=0.35.61) > May 22 23:57:22 [2192] d-gp2-dbpg0-2 cib: info: > cib_process_request: Forwarding cib_modify operation for section status to > master (origin=local/crmd/286) > May 22 23:57:22 [2192] d-gp2-dbpg0-2 cib: info: > cib_process_request: Forwarding cib_delete operation for section > //node_state[@uname='d-gp2-dbpg0-2']/lrm to master (origin=local/crmd/287) > May 22 23:57:22 [2192] d-gp2-dbpg0-2 cib: info: > cib_process_request: Forwarding cib_modify operation for section status to > master (origin=local/crmd/288) > May 22 23:57:22 [2192] d-gp2-dbpg0-2 cib: info: cib_perform_op: > Diff: --- 0.35.61 2 > May 22 23:57:22 [2192] d-gp2-dbpg0-2 cib: info: cib_perform_op: > Diff: +++ 0.35.62 (null) > May 22 23:57:22 [2192] d-gp2-dbpg0-2 cib: info: cib_perform_op: > + /cib: @num_updates=62 > May 22 23:57:22 [2192] d-gp2-dbpg0-2 cib: info: cib_perform_op: > + /cib/status/node_state[@id='1']: > @crm-debug-origin=do_lrm_query_internal, @join=member, @expected=member > May 22 23:57:22 [2192] d-gp2-dbpg0-2 cib: info: cib_perform_op: > ++ /cib/status/node_state[@id='1']: <lrm id="1"/> > May 22 23:57:22 [2192] d-gp2-dbpg0-2 cib: info: cib_perform_op: > ++ <lrm_resources/> > May 22 23:57:22 [2192] d-gp2-dbpg0-2 cib: info: cib_perform_op: > ++ </lrm> > May 22 23:57:22 [2192] d-gp2-dbpg0-2 cib: info: > cib_process_request: Completed cib_modify operation for section status: OK > (rc=0, origin=d-gp2-dbpg0-2/crmd/286, version=0.35.62) > May 22 23:57:22 [2197] d-gp2-dbpg0-2 crmd: info: > do_state_transition: State transition S_FINALIZE_JOIN -> S_POLICY_ENGINE [ > input=I_FINALIZED cause=C_FSA_INTERNAL origin=check_join_state ] > May 22 23:57:22 [2197] d-gp2-dbpg0-2 crmd: info: > abort_transition_graph: Transition aborted: Peer Cancelled > (source=do_te_invoke:161, 1) > May 22 23:57:22 [2192] d-gp2-dbpg0-2 cib: info: cib_perform_op: > Diff: --- 0.35.62 2 > May 22 23:57:22 [2192] d-gp2-dbpg0-2 cib: info: cib_perform_op: > Diff: +++ 0.35.63 (null) > May 22 23:57:22 [2192] d-gp2-dbpg0-2 cib: info: cib_perform_op: > -- /cib/status/node_state[@id='2']/lrm[@id='2'] > May 22 23:57:22 [2192] d-gp2-dbpg0-2 cib: info: cib_perform_op: > + /cib: @num_updates=63 > May 22 23:57:22 [2197] d-gp2-dbpg0-2 crmd: info: > abort_transition_graph: Transition aborted by deletion of lrm[@id='2']: > Resource state removal (cib=0.35.63, source=abort_unless_down:343, > path=/cib/status/node_state[@id='2']/lrm[@id='2'], 1) > May 22 23:57:22 [2192] d-gp2-dbpg0-2 cib: info: > cib_process_request: Completed cib_delete operation for section > //node_state[@uname='d-gp2-dbpg0-2']/lrm: OK (rc=0, > origin=d-gp2-dbpg0-2/crmd/287, version=0.35.63) > May 22 23:57:22 [2192] d-gp2-dbpg0-2 cib: info: cib_perform_op: > Diff: --- 0.35.63 2 > May 22 23:57:22 [2192] d-gp2-dbpg0-2 cib: info: cib_perform_op: > Diff: +++ 0.35.64 (null) > May 22 23:57:22 [2192] d-gp2-dbpg0-2 cib: info: cib_perform_op: > + /cib: @num_updates=64 > May 22 23:57:22 [2192] d-gp2-dbpg0-2 cib: info: cib_perform_op: > ++ /cib/status/node_state[@id='2']: <lrm id="2"/> > May 22 23:57:22 [2192] d-gp2-dbpg0-2 cib: info: cib_perform_op: > ++ <lrm_resources> > May 22 23:57:22 [2192] d-gp2-dbpg0-2 cib: info: cib_perform_op: > ++ <lrm_resource > id="postgresql-10-main" type="pgsqlms" class="ocf" provider="heartbeat"> > May 22 23:57:22 [2192] d-gp2-dbpg0-2 cib: info: cib_perform_op: > ++ <lrm_rsc_op > id="postgresql-10-main_last_failure_0" > operation_key="postgresql-10-main_monitor_0" operation="monitor" > crm-debug-origin="build_active_RAs" crm_feature_set="3.0.10" > transition-key="7:0:7:0df60493-9320-463d-94ca-a9515d139f9f" > transition-magic="0:0;7:0:7:0df60493-9320-463d-94ca-a9515d139f9f" > on_node="d-gp2-dbpg0-2" call-id="14" rc-code="0" op-status="0" interval="0" > last-run="1527 > May 22 23:57:22 [2192] d-gp2-dbpg0-2 cib: info: cib_perform_op: > ++ <lrm_rsc_op > id="postgresql-10-main_last_0" operation_key="postgresql-10-main_promote_0" > operation="promote" crm-debug-origin="build_active_RAs" > crm_feature_set="3.0.10" > transition-key="16:14:0:0df60493-9320-463d-94ca-a9515d139f9f" > transition-magic="0:0;16:14:0:0df60493-9320-463d-94ca-a9515d139f9f" > on_node="d-gp2-dbpg0-2" call-id="41" rc-code="0" op-status="0" interval="0" > last-run="15270322 > May 22 23:57:22 [2192] d-gp2-dbpg0-2 cib: info: cib_perform_op: > ++ <lrm_rsc_op > id="postgresql-10-main_monitor_15000" > operation_key="postgresql-10-main_monitor_15000" operation="monitor" > crm-debug-origin="build_active_RAs" crm_feature_set="3.0.10" > transition-key="17:14:8:0df60493-9320-463d-94ca-a9515d139f9f" > transition-magic="0:8;17:14:8:0df60493-9320-463d-94ca-a9515d139f9f" > on_node="d-gp2-dbpg0-2" call-id="44" rc-code="8" op-status="0" > interval="15000" las > May 22 23:57:22 [2192] d-gp2-dbpg0-2 cib: info: cib_perform_op: > ++ </lrm_resource> > May 22 23:57:22 [2192] d-gp2-dbpg0-2 cib: info: cib_perform_op: > ++ <lrm_resource > id="postgresql-master-vip" type="IPaddr2" class="ocf" provider="heartbeat"> > May 22 23:57:22 [2192] d-gp2-dbpg0-2 cib: info: cib_perform_op: > ++ <lrm_rsc_op > id="postgresql-master-vip_last_0" > operation_key="postgresql-master-vip_start_0" operation="start" > crm-debug-origin="build_active_RAs" crm_feature_set="3.0.10" > transition-key="8:14:0:0df60493-9320-463d-94ca-a9515d139f9f" > transition-magic="0:0;8:14:0:0df60493-9320-463d-94ca-a9515d139f9f" > on_node="d-gp2-dbpg0-2" call-id="43" rc-code="0" op-status="0" interval="0" > last-run="15270322 > May 22 23:57:22 [2192] d-gp2-dbpg0-2 cib: info: cib_perform_op: > ++ <lrm_rsc_op > id="postgresql-master-vip_monitor_10000" > operation_key="postgresql-master-vip_monitor_10000" operation="monitor" > crm-debug-origin="build_active_RAs" crm_feature_set="3.0.10" > transition-key="9:14:0:0df60493-9320-463d-94ca-a9515d139f9f" > transition-magic="0:0;9:14:0:0df60493-9320-463d-94ca-a9515d139f9f" > on_node="d-gp2-dbpg0-2" call-id="45" rc-code="0" op-status="0" > interval="10000" > May 22 23:57:22 [2192] d-gp2-dbpg0-2 cib: info: cib_perform_op: > ++ </lrm_resource> > May 22 23:57:22 [2192] d-gp2-dbpg0-2 cib: info: cib_perform_op: > ++ <lrm_resource id="vfencing" > type="external/vcenter" class="stonith"> > May 22 23:57:22 [2192] d-gp2-dbpg0-2 cib: info: cib_perform_op: > ++ <lrm_rsc_op id="vfencing_last_0" > operation_key="vfencing_start_0" operation="st > art" crm-debug-origin="build_active_RAs" crm_feature_set="3.0.10" > transition-key="5:14:0:0df60493-9320-463d-94ca-a9515d139f9f" > transition-magic="0:0;5:14:0:0df60493-9320-463d-94ca-a9515d139f9f" > on_node="d-gp2-dbpg0-2" call-id="34" rc-code="0" op-status="0" interval="0" > last-run="1527032266" last-rc-change="152703 > May 22 23:57:22 [2192] d-gp2-dbpg0-2 cib: info: cib_perform_op: > ++ <lrm_rsc_op > id="vfencing_monitor_60000" > operation_key="vfencing_monitor_60000"operation="monitor" > crm-debug-origin="build_active_RAs" crm_feature_set="3.0.10" > transition-key="6:14:0:0df60493-9320-463d-94ca-a9515d139f9f" > transition-magic="0:0;6:14:0:0df60493-9320-463d-94ca-a9515d139f9f" > on_node="d-gp2-dbpg0-2" call-id="36" rc-code="0" op-status="0" > interval="60000" last-rc-change="152703226 > May 22 23:57:22 [2192] d-gp2-dbpg0-2 cib: info: cib_perform_op: > ++ </lrm_resource> > May 22 23:57:22 [2192] d-gp2-dbpg0-2 cib: info: cib_perform_op: > ++ </lrm_resources> > May 22 23:57:22 [2192] d-gp2-dbpg0-2 cib: info: cib_perform_op: > ++ </lrm> > May 22 23:57:22 [2197] d-gp2-dbpg0-2 crmd: info: > abort_transition_graph: Transition aborted: LRM Refresh > (source=process_resource_updates:266, 1) > May 22 23:57:22 [2192] d-gp2-dbpg0-2 cib: info: > cib_process_request: Completed cib_modify operation for section status: OK > (rc=0, origin=d-gp2-dbpg0-2/crmd/288, version=0.35.64) > May 22 23:57:22 [2192] d-gp2-dbpg0-2 cib: info: > cib_process_request: Forwarding cib_modify operation for section nodes to > master (origin=local/crmd/292) > May 22 23:57:22 [2192] d-gp2-dbpg0-2 cib: info: > cib_process_request: Forwarding cib_modify operation for section status to > master (origin=local/crmd/293) > May 22 23:57:22 [2192] d-gp2-dbpg0-2 cib: info: > cib_process_request: Forwarding cib_modify operation for section status to > master (origin=local/attrd/30) > May 22 23:57:22 [2192] d-gp2-dbpg0-2 cib: info: > cib_process_request: Forwarding cib_modify operation for section status to > master (origin=local/attrd/31) > May 22 23:57:22 [2192] d-gp2-dbpg0-2 cib: info: > cib_process_request: Completed cib_modify operation for section nodes: OK > (rc=0, origin=d-gp2-dbpg0-2/crmd/292, version=0.35.64) > May 22 23:57:22 [2192] d-gp2-dbpg0-2 cib: info: cib_perform_op: > Diff: --- 0.35.64 2 > May 22 23:57:22 [2192] d-gp2-dbpg0-2 cib: info: cib_perform_op: > Diff: +++ 0.35.65 (null) > May 22 23:57:22 [2192] d-gp2-dbpg0-2 cib: info: cib_perform_op: > + /cib: @num_updates=65 > May 22 23:57:22 [2192] d-gp2-dbpg0-2 cib: info: cib_perform_op: > + /cib/status/node_state[@id='3']: @crm-debug-origin=do_state_transition > May 22 23:57:22 [2192] d-gp2-dbpg0-2 cib: info: cib_perform_op: > + /cib/status/node_state[@id='1']: @crm-debug-origin=do_state_transition > May 22 23:57:22 [2192] d-gp2-dbpg0-2 cib: info: cib_perform_op: > + /cib/status/node_state[@id='2']: @crm-debug-origin=do_state_transition > May 22 23:57:22 [2192] d-gp2-dbpg0-2 cib: info: > cib_process_request: Completed cib_modify operation for section status: OK > (rc=0, origin=d-gp2-dbpg0-2/crmd/293, version=0.35.65) > May 22 23:57:22 [2192] d-gp2-dbpg0-2 cib: info: cib_perform_op: > Diff: --- 0.35.65 2 > May 22 23:57:22 [2192] d-gp2-dbpg0-2 cib: info: cib_perform_op: > Diff: +++ 0.35.66 (null) > May 22 23:57:22 [2192] d-gp2-dbpg0-2 cib: info: cib_perform_op: > + /cib: @num_updates=66 > May 22 23:57:22 [2192] d-gp2-dbpg0-2 cib: info: > cib_process_request: Completed cib_modify operation for section status: OK > (rc=0, origin=d-gp2-dbpg0-2/attrd/30, version=0.35.66) > May 22 23:57:22 [2195] d-gp2-dbpg0-2 attrd: info: > attrd_cib_callback: Update 30 for terminate: OK (0) > May 22 23:57:22 [2195] d-gp2-dbpg0-2 attrd: info: > attrd_cib_callback: Update 30 for terminate[d-gp2-dbpg0-1]=(null): OK (0) > May 22 23:57:22 [2195] d-gp2-dbpg0-2 attrd: info: > attrd_cib_callback: Update 30 for terminate[d-gp2-dbpg0-2]=(null): OK (0) > May 22 23:57:22 [2195] d-gp2-dbpg0-2 attrd: info: > attrd_cib_callback: Update 30 for terminate[d-gp2-dbpg0-3]=(null): OK (0) > May 22 23:57:22 [2192] d-gp2-dbpg0-2 cib: info: > cib_process_request: Completed cib_modify operation for section status: OK > (rc=0, origin=d-gp2-dbpg0-2/attrd/31, version=0.35.66) > May 22 23:57:22 [2195] d-gp2-dbpg0-2 attrd: info: > attrd_cib_callback: Update 31 for shutdown: OK (0) > May 22 23:57:22 [2195] d-gp2-dbpg0-2 attrd: info: > attrd_cib_callback: Update 31 for shutdown[d-gp2-dbpg0-1]=0: OK (0) > May 22 23:57:22 [2195] d-gp2-dbpg0-2 attrd: info: > attrd_cib_callback: Update 31 for shutdown[d-gp2-dbpg0-2]=0: OK (0) > May 22 23:57:22 [2195] d-gp2-dbpg0-2 attrd: info: > attrd_cib_callback: Update 31 for shutdown[d-gp2-dbpg0-3]=0: OK (0) > May 22 23:57:22 [2192] d-gp2-dbpg0-2 cib: info: > cib_process_request: Forwarding cib_modify operation for section cib to > master (origin=local/crmd/294) > May 22 23:57:22 [2192] d-gp2-dbpg0-2 cib: info: > cib_process_request: Completed cib_modify operation for section cib: OK > (rc=0, origin=d-gp2-dbpg0-2/crmd/294, version=0.35.66) > May 22 23:57:23 [2196] d-gp2-dbpg0-2 pengine: info: > determine_online_status_fencing: Node d-gp2-dbpg0-3 is active > May 22 23:57:23 [2196] d-gp2-dbpg0-2 pengine: info: > determine_online_status: Node d-gp2-dbpg0-3 is online > May 22 23:57:23 [2196] d-gp2-dbpg0-2 pengine: info: > determine_online_status_fencing: Node d-gp2-dbpg0-1 is active > May 22 23:57:23 [2196] d-gp2-dbpg0-2 pengine: info: > determine_online_status: Node d-gp2-dbpg0-1 is online > May 22 23:57:23 [2196] d-gp2-dbpg0-2 pengine: info: > determine_online_status_fencing: Node d-gp2-dbpg0-2 is active > May 22 23:57:23 [2196] d-gp2-dbpg0-2 pengine: info: > determine_online_status: Node d-gp2-dbpg0-2 is online > May 22 23:57:23 [2196] d-gp2-dbpg0-2 pengine: info: > determine_op_status: Operation monitor found resource postgresql-10-main:1 > active on d-gp2-dbpg0-2 > May 22 23:57:23 [2196] d-gp2-dbpg0-2 pengine: info: native_print: > vfencing (stonith:external/vcenter): Started d-gp2-dbpg0-2 > May 22 23:57:23 [2196] d-gp2-dbpg0-2 pengine: info: native_print: > postgresql-master-vip (ocf::heartbeat:IPaddr2): Started > d-gp2-dbpg0-2 > May 22 23:57:23 [2196] d-gp2-dbpg0-2 pengine: info: clone_print: > Master/Slave Set: postgresql-ha [postgresql-10-main] > May 22 23:57:23 [2196] d-gp2-dbpg0-2 pengine: info: short_print: > Masters: [ d-gp2-dbpg0-2 ] > May 22 23:57:23 [2196] d-gp2-dbpg0-2 pengine: info: short_print: > Slaves: [ d-gp2-dbpg0-3 ] > May 22 23:57:23 [2196] d-gp2-dbpg0-2 pengine: info: short_print: > Stopped: [ d-gp2-dbpg0-1 ] > May 22 23:57:23 [2196] d-gp2-dbpg0-2 pengine: info: master_color: > Promoting postgresql-10-main:1 (Master d-gp2-dbpg0-2) > May 22 23:57:23 [2196] d-gp2-dbpg0-2 pengine: info: master_color: > postgresql-ha: Promoted 1 instances of a possible 1 to master > May 22 23:57:23 [2196] d-gp2-dbpg0-2 pengine: info: RecurringOp: > Start recurring monitor (16s) for postgresql-10-main:2 on d-gp2-dbpg0-1 > May 22 23:57:23 [2196] d-gp2-dbpg0-2 pengine: info: RecurringOp: > Start recurring monitor (16s) for postgresql-10-main:2 on d-gp2-dbpg0-1 > May 22 23:57:23 [2196] d-gp2-dbpg0-2 pengine: info: LogActions: Leave > vfencing (Started d-gp2-dbpg0-2) > May 22 23:57:23 [2196] d-gp2-dbpg0-2 pengine: info: LogActions: Leave > postgresql-master-vip (Started d-gp2-dbpg0-2) > May 22 23:57:23 [2196] d-gp2-dbpg0-2 pengine: info: LogActions: Leave > postgresql-10-main:0 (Slave d-gp2-dbpg0-3) > May 22 23:57:23 [2196] d-gp2-dbpg0-2 pengine: info: LogActions: Leave > postgresql-10-main:1 (Master d-gp2-dbpg0-2) > May 22 23:57:23 [2196] d-gp2-dbpg0-2 pengine: notice: LogActions: Start > postgresql-10-main:2 (d-gp2-dbpg0-1) > May 22 23:57:23 [2197] d-gp2-dbpg0-2 crmd: info: > do_state_transition: State transition S_POLICY_ENGINE -> S_TRANSITION_ENGINE > [ input=I_PE_SUCCESS cause=C_IPC_MESSAGE origin=handle_response ] > May 22 23:57:23 [2194] d-gp2-dbpg0-2 lrmd: info: log_execute: > executing - rsc:postgresql-10-main action:notify call_id:60 > May 22 23:57:23 [2196] d-gp2-dbpg0-2 pengine: notice: > process_pe_message: Calculated Transition 26: > /var/lib/pacemaker/pengine/pe-input-89.bz2 > May 22 23:57:23 [2192] d-gp2-dbpg0-2 cib: info: cib_perform_op: > Diff: --- 0.35.66 2 > May 22 23:57:23 [2192] d-gp2-dbpg0-2 cib: info: cib_perform_op: > Diff: +++ 0.35.67 (null) > May 22 23:57:23 [2192] d-gp2-dbpg0-2 cib: info: cib_perform_op: > + /cib: @num_updates=67 > May 22 23:57:23 [2192] d-gp2-dbpg0-2 cib: info: cib_perform_op: > + /cib/status/node_state[@id='1']: @crm-debug-origin=do_update_resource > May 22 23:57:23 [2192] d-gp2-dbpg0-2 cib: info: cib_perform_op: > ++ /cib/status/node_state[@id='1']/lrm[@id='1']/lrm_resources: > <lrm_resource id="vfencing" type="external/vcenter" class="stonith"/> > May 22 23:57:23 [2192] d-gp2-dbpg0-2 cib: info: cib_perform_op: > ++ > <lrm_rsc_op id="vfencing_last_0" operation_key="vfencing_monitor_0" > operation="monitor" crm-debug-origin="do_update_resource" > crm_feature_set="3.0.10" > transition-key="6:26:7:0df60493-9320-463d-94ca-a9515d139f9f" > transition-magic="0:7;6:26:7:0df60493-9320-463d-94ca-a9515d139f9f" > on_node="d-gp2-dbpg0-1" call-id="5" rc-code="7" op-status="0" interval="0" > last-run="152703 > May 22 23:57:23 [2192] d-gp2-dbpg0-2 cib: info: cib_perform_op: > ++ > </lrm_resource> > May 22 23:57:23 [2192] d-gp2-dbpg0-2 cib: info: > cib_process_request: Completed cib_modify operation for section status: OK > (rc=0, origin=d-gp2-dbpg0-1/crmd/14, version=0.35.67) > May 22 23:57:23 [2192] d-gp2-dbpg0-2 cib: info: cib_perform_op: > Diff: --- 0.35.67 2 > May 22 23:57:23 [2192] d-gp2-dbpg0-2 cib: info: cib_perform_op: > Diff: +++ 0.35.68 (null) > May 22 23:57:23 [2192] d-gp2-dbpg0-2 cib: info: cib_perform_op: > + /cib: @num_updates=68 > May 22 23:57:23 [2192] d-gp2-dbpg0-2 cib: info: cib_perform_op: > ++ /cib/status/node_state[@id='1']/lrm[@id='1']/lrm_resources: > <lrm_resource id="postgresql-master-vip" type="IPaddr2" cl > ass="ocf" provider="heartbeat"/> > May 22 23:57:23 [2192] d-gp2-dbpg0-2 cib: info: cib_perform_op: > ++ > <lrm_rsc_op id="postgresql-master-vip_last_0" > operation_key="postgresql-master-vip_monitor_0" operation="monitor" > crm-debug-origin="do_update_resource" crm_feature_set="3.0.10" > transition-key="7:26:7:0df60493-9320-463d-94ca-a9515d139f9f" > transition-magic="0:7;7:26:7:0df60493-9320-463d-94ca-a9515d139f9f" > on_node="d-gp2-dbpg0-1" call-id="9" rc-code="7" op-status="0" int > May 22 23:57:23 [2192] d-gp2-dbpg0-2 cib: info: cib_perform_op: > ++ > </lrm_resource> > May 22 23:57:23 [2192] d-gp2-dbpg0-2 cib: info: > cib_process_request: Completed cib_modify operation for section status: OK > (rc=0, origin=d-gp2-dbpg0-1/crmd/15, version=0.35.68) > May 22 23:57:23 [2194] d-gp2-dbpg0-2 lrmd: info: log_finished: > finished - rsc:postgresql-10-main action:notify call_id:60 pid:11472 > exit-code:0 exec-time:97ms queue-time:0ms > May 22 23:57:23 [2197] d-gp2-dbpg0-2 crmd: notice: process_lrm_event: > Operation postgresql-10-main_notify_0: ok (node=d-gp2-dbpg0-2, call=60, > rc=0, cib-update=0, confirmed=true) > May 22 23:57:23 [2192] d-gp2-dbpg0-2 cib: info: cib_perform_op: > Diff: --- 0.35.68 2 > May 22 23:57:23 [2192] d-gp2-dbpg0-2 cib: info: cib_perform_op: > Diff: +++ 0.35.69 (null) > May 22 23:57:23 [2192] d-gp2-dbpg0-2 cib: info: cib_perform_op: > + /cib: @num_updates=69 > May 22 23:57:23 [2192] d-gp2-dbpg0-2 cib: info: cib_perform_op: > ++ /cib/status/node_state[@id='1']/lrm[@id='1']/lrm_resources: > <lrm_resource id="postgresql-10-main" type="pgsqlms" class="ocf" > provider="heartbeat"/> > May 22 23:57:23 [2192] d-gp2-dbpg0-2 cib: info: cib_perform_op: > ++ > <lrm_rsc_op id="postgresql-10-main_last_failure_0" > operation_key="postgresql-10-main_monitor_0" operation="monitor" > crm-debug-origin="do_update_resource" crm_feature_set="3.0.10" > transition-key="8:26:7:0df60493-9320-463d-94ca-a9515d139f9f" > transition-magic="0:9;8:26:7:0df60493-9320-463d-94ca-a9515d139f9f" > exit-reason="Instance "postgresql-10-main" controldat > May 22 23:57:23 [2192] d-gp2-dbpg0-2 cib: info: cib_perform_op: > ++ > <lrm_rsc_op id="postgresql-10-main_last_0" > operation_key="postgresql-10-main_monitor_0" operation="monitor" > crm-debug-origin="do_update_resource" crm_feature_set="3.0.10" > transition-key="8:26:7:0df60493-9320-463d-94ca-a9515d139f9f" > transition-magic="0:9;8:26:7:0df60493-9320-463d-94ca-a9515d139f9f" > exit-reason="Instance "postgresql-10-main" controldata indica > May 22 23:57:23 [2192] d-gp2-dbpg0-2 cib: info: cib_perform_op: > ++ > </lrm_resource> > May 22 23:57:23 [2197] d-gp2-dbpg0-2 crmd: notice: > abort_transition_graph: Transition aborted by > postgresql-10-main_monitor_0 'create' on d-gp2-dbpg0-1: Event failed > (magic=0:9;8:26:7:0df60493-9320-463d-94ca-a9515d139f9f, cib=0.35.69, > source=match_graph_event:381, 0) > May 22 23:57:23 [2197] d-gp2-dbpg0-2 crmd: info: > abort_transition_graph: Transition aborted by > postgresql-10-main_monitor_0 'create' on d-gp2-dbpg0-1: Event failed > (magic=0:9;8:26:7:0df60493-9320-463d-94ca-a9515d139f9f, cib=0.35.69, > source=match_graph_event:381, 0) > May 22 23:57:23 [2197] d-gp2-dbpg0-2 crmd: notice: run_graph: > Transition 26 (Complete=7, Pending=0, Fired=0, Skipped=0, Incomplete=9, > Source=/var/lib/pacemaker/pengine/pe-input-89.bz2): Complete > May 22 23:57:23 [2197] d-gp2-dbpg0-2 crmd: info: > do_state_transition: State transition S_TRANSITION_ENGINE -> S_POLICY_ENGINE > [ input=I_PE_CALC cause=C_FSA_INTERNAL origin=notify_crmd ] > May 22 23:57:23 [2192] d-gp2-dbpg0-2 cib: info: > cib_process_request: Completed cib_modify operation for section status: OK > (rc=0, origin=d-gp2-dbpg0-1/crmd/16, version=0.35.69) > May 22 23:57:24 [2196] d-gp2-dbpg0-2 pengine: info: > determine_online_status_fencing: Node d-gp2-dbpg0-3 is active > May 22 23:57:24 [2196] d-gp2-dbpg0-2 pengine: info: > determine_online_status: Node d-gp2-dbpg0-3 is online > May 22 23:57:24 [2196] d-gp2-dbpg0-2 pengine: info: > determine_online_status_fencing: Node d-gp2-dbpg0-1 is active > May 22 23:57:24 [2196] d-gp2-dbpg0-2 pengine: info: > determine_online_status: Node d-gp2-dbpg0-1 is online > May 22 23:57:24 [2196] d-gp2-dbpg0-2 pengine: info: > determine_online_status_fencing: Node d-gp2-dbpg0-2 is active > May 22 23:57:24 [2196] d-gp2-dbpg0-2 pengine: info: > determine_online_status: Node d-gp2-dbpg0-2 is online > May 22 23:57:24 [2196] d-gp2-dbpg0-2 pengine: warning: > unpack_rsc_op_failure: Processing failed op monitor for > postgresql-10-main:1 on d-gp2-dbpg0-1: master (failed) (9) > May 22 23:57:24 [2196] d-gp2-dbpg0-2 pengine: warning: > unpack_rsc_op_failure: Processing failed op monitor for > postgresql-10-main:1 on d-gp2-dbpg0-1: master (failed) (9) > May 22 23:57:24 [2196] d-gp2-dbpg0-2 pengine: info: > determine_op_status: Operation monitor found resource postgresql-10-main:2 > active on d-gp2-dbpg0-2 > May 22 23:57:24 [2196] d-gp2-dbpg0-2 pengine: info: native_print: > vfencing (stonith:external/vcenter): Started d-gp2-dbpg0-2 > May 22 23:57:24 [2196] d-gp2-dbpg0-2 pengine: info: native_print: > postgresql-master-vip (ocf::heartbeat:IPaddr2): Started > d-gp2-dbpg0-2 > May 22 23:57:24 [2196] d-gp2-dbpg0-2 pengine: info: clone_print: > Master/Slave Set: postgresql-ha [postgresql-10-main] > May 22 23:57:24 [2196] d-gp2-dbpg0-2 pengine: info: native_print: > postgresql-10-main (ocf::heartbeat:pgsqlms): FAILED Master > d-gp2-dbpg0-1 > May 22 23:57:24 [2196] d-gp2-dbpg0-2 pengine: info: short_print: > Masters: [ d-gp2-dbpg0-2 ] > May 22 23:57:24 [2196] d-gp2-dbpg0-2 pengine: info: short_print: > Slaves: [ d-gp2-dbpg0-3 ] > May 22 23:57:24 [2196] d-gp2-dbpg0-2 pengine: info: master_color: > Promoting postgresql-10-main:2 (Master d-gp2-dbpg0-2) > May 22 23:57:24 [2196] d-gp2-dbpg0-2 pengine: info: master_color: > postgresql-ha: Promoted 1 instances of a possible 1 to master > May 22 23:57:24 [2196] d-gp2-dbpg0-2 pengine: info: RecurringOp: > Start recurring monitor (16s) for postgresql-10-main:1 on d-gp2-dbpg0-1 > May 22 23:57:24 [2196] d-gp2-dbpg0-2 pengine: info: RecurringOp: > Start recurring monitor (16s) for postgresql-10-main:1 on d-gp2-dbpg0-1 > May 22 23:57:24 [2196] d-gp2-dbpg0-2 pengine: info: LogActions: Leave > vfencing (Started d-gp2-dbpg0-2) > May 22 23:57:24 [2196] d-gp2-dbpg0-2 pengine: info: LogActions: Leave > postgresql-master-vip (Started d-gp2-dbpg0-2) > May 22 23:57:24 [2196] d-gp2-dbpg0-2 pengine: info: LogActions: Leave > postgresql-10-main:0 (Slave d-gp2-dbpg0-3) > May 22 23:57:24 [2196] d-gp2-dbpg0-2 pengine: notice: LogActions: > Demote postgresql-10-main:1 (Master -> Slave d-gp2-dbpg0-1) > May 22 23:57:24 [2196] d-gp2-dbpg0-2 pengine: notice: LogActions: > Recover postgresql-10-main:1 (Master d-gp2-dbpg0-1) > May 22 23:57:24 [2196] d-gp2-dbpg0-2 pengine: info: LogActions: Leave > postgresql-10-main:2 (Master d-gp2-dbpg0-2) > May 22 23:57:24 [2197] d-gp2-dbpg0-2 crmd: info: > do_state_transition: State transition S_POLICY_ENGINE -> S_TRANSITION_ENGINE > [ input=I_PE_SUCCESS cause=C_IPC_MESSAGE origin=handle_response ] > May 22 23:57:24 [2194] d-gp2-dbpg0-2 lrmd: info: log_execute: > executing - rsc:postgresql-10-main action:notify call_id:61 > May 22 23:57:24 [2196] d-gp2-dbpg0-2 pengine: notice: > process_pe_message: Calculated Transition 27: > /var/lib/pacemaker/pengine/pe-input-90.bz2 > May 22 23:57:24 [2194] d-gp2-dbpg0-2 lrmd: info: log_finished: > finished - rsc:postgresql-10-main action:notify call_id:61 pid:11484 > exit-code:0 exec-time:101ms queue-time:0ms > May 22 23:57:24 [2197] d-gp2-dbpg0-2 crmd: notice: process_lrm_event: > Operation postgresql-10-main_notify_0: ok (node=d-gp2-dbpg0-2, call=61, > rc=0, cib-update=0, confirmed=true) > May 22 23:57:24 [2192] d-gp2-dbpg0-2 cib: info: cib_perform_op: > Diff: --- 0.35.69 2 > May 22 23:57:24 [2192] d-gp2-dbpg0-2 cib: info: cib_perform_op: > Diff: +++ 0.35.70 (null) > May 22 23:57:24 [2192] d-gp2-dbpg0-2 cib: info: cib_perform_op: > + /cib: @num_updates=70 > May 22 23:57:24 [2192] d-gp2-dbpg0-2 cib: info: cib_perform_op: > + > /cib/status/node_state[@id='1']/lrm[@id='1']/lrm_resources/lrm_resource[@id='postgresql-10-main']/lrm_rsc_op[@id='postgresql-10-main_last_failure_0']: > @operation_key=postgresql-10-main_demote_0, @operation=demote, > @transition-key=13:27:0:0df60493-9320-463d-94ca-a9515d139f9f, > @transition-magic=0:1;13:27:0:0df60493-9320-463d-94ca-a9515d139f9f, > @call-id=16, @rc-code=1, @last-run=1527033444, @last-rc-change=1527033444, > @exec-time=90 > May 22 23:57:24 [2192] d-gp2-dbpg0-2 cib: info: cib_perform_op: > + > /cib/status/node_state[@id='1']/lrm[@id='1']/lrm_resources/lrm_resource[@id='postgresql-10-main']/lrm_rsc_op[@id='postgresql-10-main_last_0']: > @operation_key=postgresql-10-main_demote_0, @operation=demote, > @transition-key=13:27:0:0df60493-9320-463d-94ca-a9515d139f9f, > @transition-magic=0:1;13:27:0:0df60493-9320-463d-94c > a-a9515d139f9f, @call-id=16, @rc-code=1, @last-run=1527033444, > @last-rc-change=1527033444, @exec-time=90 > May 22 23:57:24 [2192] d-gp2-dbpg0-2 cib: info: > cib_process_request: Completed cib_modify operation for section status: OK > (rc=0, origin=d-gp2-dbpg0-1/crmd/17, version=0.35.70) > May 22 23:57:24 [2197] d-gp2-dbpg0-2 crmd: notice: > abort_transition_graph: Transition aborted by > postgresql-10-main_demote_0 'modify' on d-gp2-dbpg0-1: Event failed > (magic=0:1;13:27:0:0df60493-9320-463d-94ca-a9515d139f9f, cib=0.35.70, > source=match_graph_event:381, 0) > May 22 23:57:24 [2192] d-gp2-dbpg0-2 cib: info: > cib_process_request: Forwarding cib_modify operation for section status to > master (origin=local/attrd/32) > May 22 23:57:24 [2192] d-gp2-dbpg0-2 cib: info: cib_perform_op: > Diff: --- 0.35.70 2 > May 22 23:57:24 [2197] d-gp2-dbpg0-2 crmd: info: > abort_transition_graph: Transition aborted by > postgresql-10-main_demote_0 'modify' on d-gp2-dbpg0-1: Event failed > (magic=0:1;13:27:0:0df60493-9320-463d-94ca-a9515d139f9f, cib=0.35.70, > source=match_graph_event:381, 0) > May 22 23:57:24 [2192] d-gp2-dbpg0-2 cib: info: cib_perform_op: > Diff: +++ 0.35.71 (null) > May 22 23:57:24 [2192] d-gp2-dbpg0-2 cib: info: cib_perform_op: > + /cib: @num_updates=71 > May 22 23:57:24 [2192] d-gp2-dbpg0-2 cib: info: cib_perform_op: > ++ > /cib/status/node_state[@id='1']/transient_attributes[@id='1']/instance_attributes[@id='status-1']: > <nvpair id="status-1-fail-count-postgresql-10-main" > name="fail-count-postgresql-10-main" value="1"/> > May 22 23:57:24 [2192] d-gp2-dbpg0-2 cib: info: > cib_process_request: Completed cib_modify operation for section status: OK > (rc=0, origin=d-gp2-dbpg0-2/attrd/32, version=0.35.71) > May 22 23:57:24 [2195] d-gp2-dbpg0-2 attrd: info: > attrd_cib_callback: Update 32 for fail-count-postgresql-10-main: OK (0) > May 22 23:57:24 [2195] d-gp2-dbpg0-2 attrd: info: > attrd_cib_callback: Update 32 for > fail-count-postgresql-10-main[d-gp2-dbpg0-1]=1: OK (0) > May 22 23:57:24 [2192] d-gp2-dbpg0-2 cib: info: > cib_process_request: Forwarding cib_modify operation for section status to > master (origin=local/attrd/33) > May 22 23:57:24 [2192] d-gp2-dbpg0-2 cib: info: > cib_process_request: Forwarding cib_modify operation for section status to > master (origin=local/attrd/34) > May 22 23:57:24 [2194] d-gp2-dbpg0-2 lrmd: info: log_execute: > executing - rsc:postgresql-10-main action:notify call_id:62 > May 22 23:57:24 [2197] d-gp2-dbpg0-2 crmd: notice: > abort_transition_graph: Transition aborted by > status-1-fail-count-postgresql-10-main, fail-count-postgresql-10-main=1: > Transient attribute change (create cib=0.35.71, source=abort_unless_down:329, > path=/cib/status/node_state[@id='1']/transient_attributes[@id='1']/instance_attributes[@id='status-1'], > 0) > May 22 23:57:24 [2192] d-gp2-dbpg0-2 cib: info: cib_perform_op: > Diff: --- 0.35.71 2 > May 22 23:57:24 [2192] d-gp2-dbpg0-2 cib: info: cib_perform_op: > Diff: +++ 0.35.72 (null) > May 22 23:57:24 [2192] d-gp2-dbpg0-2 cib: info: cib_perform_op: > + /cib: @num_updates=72 > May 22 23:57:24 [2192] d-gp2-dbpg0-2 cib: info: cib_perform_op: > ++ > /cib/status/node_state[@id='1']/transient_attributes[@id='1']/instance_attributes[@id='status-1']: > <nvpair id="status-1-last-failure-postgresql-10-main" > name="last-failure-postgresql-10-main" value="1527033444"/> > May 22 23:57:24 [2192] d-gp2-dbpg0-2 cib: info: > cib_process_request: Completed cib_modify operation for section status: OK > (rc=0, origin=d-gp2-dbpg0-2/attrd/33, version=0.35.72) > May 22 23:57:24 [2197] d-gp2-dbpg0-2 crmd: info: > abort_transition_graph: Transition aborted by > status-1-last-failure-postgresql-10-main, > last-failure-postgresql-10-main=1527033444: Transient attribute change > (create cib=0.35.72, source=abort_unless_down:329, > path=/cib/status/node_state[@id='1']/transient_attributes[@id='1']/instance_attributes[@id='status-1'], > 0) > May 22 23:57:24 [2195] d-gp2-dbpg0-2 attrd: info: > attrd_cib_callback: Update 33 for last-failure-postgresql-10-main: OK (0) > May 22 23:57:24 [2195] d-gp2-dbpg0-2 attrd: info: > attrd_cib_callback: Update 33 for > last-failure-postgresql-10-main[d-gp2-dbpg0-1]=1527033444: OK (0) > May 22 23:57:24 [2192] d-gp2-dbpg0-2 cib: info: cib_perform_op: > Diff: --- 0.35.72 2 > May 22 23:57:24 [2192] d-gp2-dbpg0-2 cib: info: cib_perform_op: > Diff: +++ 0.35.73 (null) > May 22 23:57:24 [2192] d-gp2-dbpg0-2 cib: info: cib_perform_op: > + /cib: @num_updates=73 > May 22 23:57:24 [2192] d-gp2-dbpg0-2 cib: info: cib_perform_op: > + > /cib/status/node_state[@id='1']/transient_attributes[@id='1']/instance_attributes[@id='status-1']/nvpair[@id='status-1-fail-count-postgresql-10-main']: > @value=2 > May 22 23:57:24 [2197] d-gp2-dbpg0-2 crmd: info: > abort_transition_graph: Transition aborted by > status-1-fail-count-postgresql-10-main, fail-count-postgresql-10-main=2: > Transient attribute change (modify cib=0.35.73, source=abort_unless_down:329, > path=/cib/status/node_state[@id='1']/transient_attributes[@id='1']/instance_attributes[@id='status-1']/nvpair[@id='status-1-fail-count-postgresql-10-main'], > 0) > May 22 23:57:24 [2192] d-gp2-dbpg0-2 cib: info: > cib_process_request: Completed cib_modify operation for section status: OK > (rc=0, origin=d-gp2-dbpg0-2/attrd/34, version=0.35.73) > May 22 23:57:24 [2195] d-gp2-dbpg0-2 attrd: info: > attrd_cib_callback: Update 34 for fail-count-postgresql-10-main: OK (0) > May 22 23:57:24 [2195] d-gp2-dbpg0-2 attrd: info: > attrd_cib_callback: Update 34 for > fail-count-postgresql-10-main[d-gp2-dbpg0-1]=2: OK (0) > May 22 23:57:24 [2194] d-gp2-dbpg0-2 lrmd: info: log_finished: > finished - rsc:postgresql-10-main action:notify call_id:62 pid:11496 > exit-code:0 exec-time:86ms queue-time:0ms > May 22 23:57:24 [2197] d-gp2-dbpg0-2 crmd: notice: process_lrm_event: > Operation postgresql-10-main_notify_0: ok (node=d-gp2-dbpg0-2, call=62, > rc=0, cib-update=0, confirmed=true) > May 22 23:57:24 [2197] d-gp2-dbpg0-2 crmd: notice: run_graph: > Transition 27 (Complete=14, Pending=0, Fired=0, Skipped=3, Incomplete=25, > Source=/var/lib/pacemaker/pengine/pe-input-90.bz2): Stopped > May 22 23:57:24 [2197] d-gp2-dbpg0-2 crmd: info: > do_state_transition: State transition S_TRANSITION_ENGINE -> S_POLICY_ENGINE > [ input=I_PE_CALC cause=C_FSA_INTERNAL origin=notify_crmd ] > May 22 23:57:24 [2196] d-gp2-dbpg0-2 pengine: info: > determine_online_status_fencing: Node d-gp2-dbpg0-3 is active > May 22 23:57:24 [2196] d-gp2-dbpg0-2 pengine: info: > determine_online_status: Node d-gp2-dbpg0-3 is online > May 22 23:57:24 [2196] d-gp2-dbpg0-2 pengine: info: > determine_online_status_fencing: Node d-gp2-dbpg0-1 is active > May 22 23:57:24 [2196] d-gp2-dbpg0-2 pengine: info: > determine_online_status: Node d-gp2-dbpg0-1 is online > May 22 23:57:24 [2196] d-gp2-dbpg0-2 pengine: info: > determine_online_status_fencing: Node d-gp2-dbpg0-2 is active > May 22 23:57:24 [2196] d-gp2-dbpg0-2 pengine: info: > determine_online_status: Node d-gp2-dbpg0-2 is online > May 22 23:57:24 [2196] d-gp2-dbpg0-2 pengine: warning: > unpack_rsc_op_failure: Processing failed op demote for > postgresql-10-main:1 on d-gp2-dbpg0-1: unknown error (1) > May 22 23:57:24 [2196] d-gp2-dbpg0-2 pengine: warning: > unpack_rsc_op_failure: Forcing postgresql-10-main:1 to stop after a > failed demote action > May 22 23:57:24 [2196] d-gp2-dbpg0-2 pengine: warning: > unpack_rsc_op_failure: Processing failed op demote for > postgresql-10-main:1 on d-gp2-dbpg0-1: unknown error (1) > May 22 23:57:24 [2196] d-gp2-dbpg0-2 pengine: warning: > unpack_rsc_op_failure: Forcing postgresql-10-main:1 to stop after a > failed demote action > May 22 23:57:24 [2196] d-gp2-dbpg0-2 pengine: info: > determine_op_status: Operation monitor found resource postgresql-10-main:2 > active on d-gp2-dbpg0-2 > May 22 23:57:24 [2196] d-gp2-dbpg0-2 pengine: info: native_print: > vfencing (stonith:external/vcenter): Started d-gp2-dbpg0-2 > May 22 23:57:24 [2196] d-gp2-dbpg0-2 pengine: info: native_print: > postgresql-master-vip (ocf::heartbeat:IPaddr2): Started > d-gp2-dbpg0-2 > May 22 23:57:24 [2196] d-gp2-dbpg0-2 pengine: info: clone_print: > Master/Slave Set: postgresql-ha [postgresql-10-main] > May 22 23:57:24 [2196] d-gp2-dbpg0-2 pengine: info: native_print: > postgresql-10-main (ocf::heartbeat:pgsqlms): FAILED d-gp2-dbpg0-1 > May 22 23:57:24 [2196] d-gp2-dbpg0-2 pengine: info: short_print: > Masters: [ d-gp2-dbpg0-2 ] > May 22 23:57:24 [2196] d-gp2-dbpg0-2 pengine: info: short_print: > Slaves: [ d-gp2-dbpg0-3 ] > May 22 23:57:24 [2196] d-gp2-dbpg0-2 pengine: info: > get_failcount_full: postgresql-10-main:0 has failed 2 times on d-gp2-dbpg0-1 > May 22 23:57:24 [2196] d-gp2-dbpg0-2 pengine: info: > common_apply_stickiness: postgresql-ha can fail 3 more times on > d-gp2-dbpg0-1 before being forced off > May 22 23:57:24 [2196] d-gp2-dbpg0-2 pengine: info: > get_failcount_full: postgresql-10-main:1 has failed 2 times on d-gp2-dbpg0-1 > May 22 23:57:24 [2196] d-gp2-dbpg0-2 pengine: info: > common_apply_stickiness: postgresql-ha can fail 3 more times on > d-gp2-dbpg0-1 before being forced off > May 22 23:57:24 [2196] d-gp2-dbpg0-2 pengine: info: > get_failcount_full: postgresql-10-main:2 has failed 2 times on d-gp2-dbpg0-1 > May 22 23:57:24 [2196] d-gp2-dbpg0-2 pengine: info: > common_apply_stickiness: postgresql-ha can fail 3 more times on > d-gp2-dbpg0-1 before being forced off > May 22 23:57:24 [2196] d-gp2-dbpg0-2 pengine: info: native_color: > Resource postgresql-10-main:1 cannot run anywhere > May 22 23:57:24 [2196] d-gp2-dbpg0-2 pengine: info: master_color: > Promoting postgresql-10-main:2 (Master d-gp2-dbpg0-2) > May 22 23:57:24 [2196] d-gp2-dbpg0-2 pengine: info: master_color: > postgresql-ha: Promoted 1 instances of a possible 1 to master > May 22 23:57:24 [2196] d-gp2-dbpg0-2 pengine: info: LogActions: Leave > vfencing (Started d-gp2-dbpg0-2) > May 22 23:57:24 [2196] d-gp2-dbpg0-2 pengine: info: LogActions: Leave > postgresql-master-vip (Started d-gp2-dbpg0-2) > May 22 23:57:24 [2196] d-gp2-dbpg0-2 pengine: info: LogActions: Leave > postgresql-10-main:0 (Slave d-gp2-dbpg0-3) > May 22 23:57:24 [2196] d-gp2-dbpg0-2 pengine: notice: LogActions: Stop > postgresql-10-main:1 (d-gp2-dbpg0-1) > May 22 23:57:24 [2196] d-gp2-dbpg0-2 pengine: info: LogActions: Leave > postgresql-10-main:2 (Master d-gp2-dbpg0-2) > May 22 23:57:24 [2197] d-gp2-dbpg0-2 crmd: info: > do_state_transition: State transition S_POLICY_ENGINE -> S_TRANSITION_ENGINE > [ input=I_PE_SUCCESS cause=C_IPC_MESSAGE origin=handle_response ] > May 22 23:57:24 [2194] d-gp2-dbpg0-2 lrmd: info: log_execute: > executing - rsc:postgresql-10-main action:notify call_id:63 > May 22 23:57:24 [2196] d-gp2-dbpg0-2 pengine: notice: > process_pe_message: Calculated Transition 28: > /var/lib/pacemaker/pengine/pe-input-91.bz2 > May 22 23:57:24 [2194] d-gp2-dbpg0-2 lrmd: info: log_finished: > finished - rsc:postgresql-10-main action:notify call_id:63 pid:11508 > exit-code:0 exec-time:79ms queue-time:0ms > May 22 23:57:24 [2197] d-gp2-dbpg0-2 crmd: notice: process_lrm_event: > Operation postgresql-10-main_notify_0: ok (node=d-gp2-dbpg0-2, call=63, > rc=0, cib-update=0, confirmed=true) > May 22 23:57:24 [2192] d-gp2-dbpg0-2 cib: info: cib_perform_op: > Diff: --- 0.35.73 2 > May 22 23:57:24 [2192] d-gp2-dbpg0-2 cib: info: cib_perform_op: > Diff: +++ 0.35.74 (null) > May 22 23:57:24 [2192] d-gp2-dbpg0-2 cib: info: cib_perform_op: > + /cib: @num_updates=74 > May 22 23:57:24 [2192] d-gp2-dbpg0-2 cib: info: cib_perform_op: > + > /cib/status/node_state[@id='1']/lrm[@id='1']/lrm_resources/lrm_resource[@id='postgresql-10-main']/lrm_rsc_op[@id='postgresql-10-main_last_failure_0']: > @operation_key=postgresql-10-main_stop_0, @operation=stop, > @transition-key=2:28:0:0df60493-9320-463d-94ca-a9515d139f9f, > @transition-magic=0:1;2:28:0:0df60493-9320-463d-94ca-a9515d139f9f, > @exit-reason=Unexpected state for instance "postgresql-10-main" (returned 9), > @call-id=19, @ex > May 22 23:57:24 [2192] d-gp2-dbpg0-2 cib: info: cib_perform_op: > + > /cib/status/node_state[@id='1']/lrm[@id='1']/lrm_resources/lrm_resource[@id='postgresql-10-main']/lrm_rsc_op[@id='postgresql-10-main_last_0']: > @operation_key=postgresql-10-main_stop_0, @operation=stop, > @transition-key=2:28:0:0df60493-9320-463d-94ca-a9515d139f9f, > @transition-magic=0:1;2:28:0:0df60493-9320-463d-94ca-a9515d139f9f, > @exit-reason=Unexpected state for instance "postgresql-10-main" (returned 9), > @call-id=19, @exec-time= > May 22 23:57:24 [2197] d-gp2-dbpg0-2 crmd: notice: > abort_transition_graph: Transition aborted by postgresql-10-main_stop_0 > 'modify' on d-gp2-dbpg0-1: Event failed > (magic=0:1;2:28:0:0df60493-9320-463d-94ca-a9515d139f9f, cib=0.35.74, > source=match_graph_event:381, 0) > May 22 23:57:24 [2197] d-gp2-dbpg0-2 crmd: info: > abort_transition_graph: Transition aborted by postgresql-10-main_stop_0 > 'modify' on d-gp2-dbpg0-1: Event failed > (magic=0:1;2:28:0:0df60493-9320-463d-94ca-a9515d139f9f, cib=0.35.74, > source=match_graph_event:381, 0) > May 22 23:57:24 [2194] d-gp2-dbpg0-2 lrmd: info: log_execute: > executing - rsc:postgresql-10-main action:notify call_id:64 > May 22 23:57:24 [2192] d-gp2-dbpg0-2 cib: info: > cib_process_request: Completed cib_modify operation for section status: OK > (rc=0, origin=d-gp2-dbpg0-1/crmd/18, version=0.35.74) > May 22 23:57:24 [2192] d-gp2-dbpg0-2 cib: info: > cib_process_request: Forwarding cib_modify operation for section status to > master (origin=local/attrd/35) > May 22 23:57:24 [2192] d-gp2-dbpg0-2 cib: info: cib_perform_op: > Diff: --- 0.35.74 2 > May 22 23:57:24 [2192] d-gp2-dbpg0-2 cib: info: cib_perform_op: > Diff: +++ 0.35.75 (null) > May 22 23:57:24 [2192] d-gp2-dbpg0-2 cib: info: cib_perform_op: > + /cib: @num_updates=75 > May 22 23:57:24 [2192] d-gp2-dbpg0-2 cib: info: cib_perform_op: > + > /cib/status/node_state[@id='1']/transient_attributes[@id='1']/instance_attributes[@id='status-1']/nvpair[@id='status-1-fail-count-postgresql-10-main']: > @value=INFINITY > May 22 23:57:24 [2197] d-gp2-dbpg0-2 crmd: notice: > abort_transition_graph: Transition aborted by > status-1-fail-count-postgresql-10-main, > fail-count-postgresql-10-main=INFINITY: Transient attribute change (modify > cib=0.35.75, source=abort_unless_down:329, > path=/cib/status/node_state[@id='1']/transient_attributes[@id='1']/instance_attributes[@id='status-1']/nvpair[@id='status-1-fail-count-postgresql-10-main'], > 0) > May 22 23:57:24 [2192] d-gp2-dbpg0-2 cib: info: > cib_process_request: Completed cib_modify operation for section status: OK > (rc=0, origin=d-gp2-dbpg0-2/attrd/35, version=0.35.75) > May 22 23:57:24 [2195] d-gp2-dbpg0-2 attrd: info: > attrd_cib_callback: Update 35 for fail-count-postgresql-10-main: OK (0) > May 22 23:57:24 [2195] d-gp2-dbpg0-2 attrd: info: > attrd_cib_callback: Update 35 for > fail-count-postgresql-10-main[d-gp2-dbpg0-1]=INFINITY: OK (0) > May 22 23:57:24 [2194] d-gp2-dbpg0-2 lrmd: info: log_finished: > finished - rsc:postgresql-10-main action:notify call_id:64 pid:11560 > exit-code:0 exec-time:77ms queue-time:0ms > May 22 23:57:24 [2197] d-gp2-dbpg0-2 crmd: notice: process_lrm_event: > Operation postgresql-10-main_notify_0: ok (node=d-gp2-dbpg0-2, call=64, > rc=0, cib-update=0, confirmed=true) > May 22 23:57:24 [2197] d-gp2-dbpg0-2 crmd: notice: run_graph: > Transition 28 (Complete=12, Pending=0, Fired=0, Skipped=0, Incomplete=1, > Source=/var/lib/pacemaker/pengine/pe-input-91.bz2): Complete > May 22 23:57:24 [2197] d-gp2-dbpg0-2 crmd: info: > do_state_transition: State transition S_TRANSITION_ENGINE -> S_POLICY_ENGINE > [ input=I_PE_CALC cause=C_FSA_INTERNAL origin=notify_crmd ] > May 22 23:57:24 [2196] d-gp2-dbpg0-2 pengine: info: > determine_online_status_fencing: Node d-gp2-dbpg0-3 is active > May 22 23:57:24 [2196] d-gp2-dbpg0-2 pengine: info: > determine_online_status: Node d-gp2-dbpg0-3 is online > May 22 23:57:24 [2196] d-gp2-dbpg0-2 pengine: info: > determine_online_status_fencing: Node d-gp2-dbpg0-1 is active > May 22 23:57:24 [2196] d-gp2-dbpg0-2 pengine: info: > determine_online_status: Node d-gp2-dbpg0-1 is online > May 22 23:57:24 [2196] d-gp2-dbpg0-2 pengine: info: > determine_online_status_fencing: Node d-gp2-dbpg0-2 is active > May 22 23:57:24 [2196] d-gp2-dbpg0-2 pengine: info: > determine_online_status: Node d-gp2-dbpg0-2 is online > May 22 23:57:24 [2196] d-gp2-dbpg0-2 pengine: warning: > unpack_rsc_op_failure: Processing failed op stop for > postgresql-10-main:1 on d-gp2-dbpg0-1: unknown error (1) > May 22 23:57:24 [2196] d-gp2-dbpg0-2 pengine: warning: > unpack_rsc_op_failure: Processing failed op stop for > postgresql-10-main:1 on d-gp2-dbpg0-1: unknown error (1) > May 22 23:57:24 [2196] d-gp2-dbpg0-2 pengine: warning: pe_fence_node: > Node d-gp2-dbpg0-1 will be fenced because of resource failure(s) > May 22 23:57:24 [2196] d-gp2-dbpg0-2 pengine: info: > determine_op_status: Operation monitor found resource postgresql-10-main:2 > active on d-gp2-dbpg0-2 > May 22 23:57:24 [2196] d-gp2-dbpg0-2 pengine: info: native_print: > vfencing (stonith:external/vcenter): Started d-gp2-dbpg0-2 > May 22 23:57:24 [2196] d-gp2-dbpg0-2 pengine: info: native_print: > postgresql-master-vip (ocf::heartbeat:IPaddr2): Started > d-gp2-dbpg0-2 > May 22 23:57:24 [2196] d-gp2-dbpg0-2 pengine: info: clone_print: > Master/Slave Set: postgresql-ha [postgresql-10-main] > May 22 23:57:24 [2196] d-gp2-dbpg0-2 pengine: info: native_print: > postgresql-10-main (ocf::heartbeat:pgsqlms): FAILED d-gp2-dbpg0-1 > May 22 23:57:24 [2196] d-gp2-dbpg0-2 pengine: info: short_print: > Masters: [ d-gp2-dbpg0-2 ] > May 22 23:57:24 [2196] d-gp2-dbpg0-2 pengine: info: short_print: > Slaves: [ d-gp2-dbpg0-3 ] > May 22 23:57:24 [2196] d-gp2-dbpg0-2 pengine: info: > get_failcount_full: postgresql-10-main:0 has failed 2 times on d-gp2-dbpg0-1 > May 22 23:57:24 [2196] d-gp2-dbpg0-2 pengine: info: > common_apply_stickiness: postgresql-ha can fail 3 more times on > d-gp2-dbpg0-1 before being forced off > May 22 23:57:24 [2196] d-gp2-dbpg0-2 pengine: info: > get_failcount_full: postgresql-10-main:1 has failed 2 times on d-gp2-dbpg0-1 > May 22 23:57:24 [2196] d-gp2-dbpg0-2 pengine: info: > common_apply_stickiness: postgresql-ha can fail 3 more times on > d-gp2-dbpg0-1 before being forced off > May 22 23:57:24 [2196] d-gp2-dbpg0-2 pengine: info: > get_failcount_full: postgresql-10-main:2 has failed 2 times on d-gp2-dbpg0-1 > May 22 23:57:24 [2196] d-gp2-dbpg0-2 pengine: info: > common_apply_stickiness: postgresql-ha can fail 3 more times on > d-gp2-dbpg0-1 before being forced off > May 22 23:57:24 [2196] d-gp2-dbpg0-2 pengine: info: native_color: > Resource postgresql-10-main:1 cannot run anywhere > May 22 23:57:24 [2196] d-gp2-dbpg0-2 pengine: info: master_color: > Promoting postgresql-10-main:2 (Master d-gp2-dbpg0-2) > May 22 23:57:24 [2196] d-gp2-dbpg0-2 pengine: info: master_color: > postgresql-ha: Promoted 1 instances of a possible 1 to master > May 22 23:57:24 [2196] d-gp2-dbpg0-2 pengine: info: LogActions: Leave > vfencing (Started d-gp2-dbpg0-2) > May 22 23:57:24 [2196] d-gp2-dbpg0-2 pengine: info: LogActions: Leave > postgresql-master-vip (Started d-gp2-dbpg0-2) > May 22 23:57:24 [2196] d-gp2-dbpg0-2 pengine: info: LogActions: Leave > postgresql-10-main:0 (Slave d-gp2-dbpg0-3) > May 22 23:57:24 [2196] d-gp2-dbpg0-2 pengine: notice: LogActions: Stop > postgresql-10-main:1 (d-gp2-dbpg0-1) > May 22 23:57:24 [2196] d-gp2-dbpg0-2 pengine: info: LogActions: Leave > postgresql-10-main:2 (Master d-gp2-dbpg0-2) > May 22 23:57:24 [2197] d-gp2-dbpg0-2 crmd: info: > do_state_transition: State transition S_POLICY_ENGINE -> S_TRANSITION_ENGINE > [ input=I_PE_SUCCESS cause=C_IPC_MESSAGE origin=handle_response ] > May 22 23:57:24 [2194] d-gp2-dbpg0-2 lrmd: info: log_execute: > executing - rsc:postgresql-10-main action:notify call_id:63 > May 22 23:57:24 [2196] d-gp2-dbpg0-2 pengine: notice: > process_pe_message: Calculated Transition 28: > /var/lib/pacemaker/pengine/pe-input-91.bz2 > May 22 23:57:24 [2194] d-gp2-dbpg0-2 lrmd: info: log_finished: > finished - rsc:postgresql-10-main action:notify call_id:63 pid:11508 > exit-code:0 exec-time:79ms queue-time:0ms > May 22 23:57:24 [2197] d-gp2-dbpg0-2 crmd: notice: process_lrm_event: > Operation postgresql-10-main_notify_0: ok (node=d-gp2-dbpg0-2, call=63, > rc=0, cib-update=0, confirmed=true) > May 22 23:57:24 [2192] d-gp2-dbpg0-2 cib: info: cib_perform_op: > Diff: --- 0.35.73 2 > May 22 23:57:24 [2192] d-gp2-dbpg0-2 cib: info: cib_perform_op: > Diff: +++ 0.35.74 (null) > May 22 23:57:24 [2192] d-gp2-dbpg0-2 cib: info: cib_perform_op: > + /cib: @num_updates=74 > May 22 23:57:24 [2192] d-gp2-dbpg0-2 cib: info: cib_perform_op: > + > /cib/status/node_state[@id='1']/lrm[@id='1']/lrm_resources/lrm_resource[@id='postgresql-10-main']/lrm_rsc_op[@id='postgresql-10-main_last_failure_0']: > @operation_key=postgresql-10-main_stop_0, @operation=stop, > @transition-key=2:28:0:0df60493-9320-463d-94ca-a9515d139f9f, > @transition-magic=0:1;2:28:0:0df60493-9320-463d-94ca-a9515d139f9f, > @exit-reason=Unexpected state for instance "postgresql-10-main" (returned 9), > @call-id=19, @ex > May 22 23:57:24 [2192] d-gp2-dbpg0-2 cib: info: cib_perform_op: > + > /cib/status/node_state[@id='1']/lrm[@id='1']/lrm_resources/lrm_resource[@id='postgresql-10-main']/lrm_rsc_op[@id='postgresql-10-main_last_0']: > @operation_key=postgresql-10-main_stop_0, @operation=stop, > @transition-key=2:28:0:0df60493-9320-463d-94ca-a9515d139f9f, > @transition-magic=0:1;2:28:0:0df60493-9320-463d-94ca-a9515d139f9f, > @exit-reason=Unexpected state for instance "postgresql-10-main" (returned 9), > @call-id=19, @exec-time= > May 22 23:57:24 [2197] d-gp2-dbpg0-2 crmd: notice: > abort_transition_graph: Transition aborted by postgresql-10-main_stop_0 > 'modify' on d-gp2-dbpg0-1: Event failed > (magic=0:1;2:28:0:0df60493-9320-463d-94ca-a9515d139f9f, cib=0.35.74, > source=match_graph_event:381, 0) > May 22 23:57:24 [2197] d-gp2-dbpg0-2 crmd: info: > abort_transition_graph: Transition aborted by postgresql-10-main_stop_0 > 'modify' on d-gp2-dbpg0-1: Event failed > (magic=0:1;2:28:0:0df60493-9320-463d-94ca-a9515d139f9f, cib=0.35.74, > source=match_graph_event:381, 0) > May 22 23:57:24 [2194] d-gp2-dbpg0-2 lrmd: info: log_execute: > executing - rsc:postgresql-10-main action:notify call_id:64 > May 22 23:57:24 [2192] d-gp2-dbpg0-2 cib: info: > cib_process_request: Completed cib_modify operation for section status: OK > (rc=0, origin=d-gp2-dbpg0-1/crmd/18, version=0.35.74) > May 22 23:57:24 [2192] d-gp2-dbpg0-2 cib: info: > cib_process_request: Forwarding cib_modify operation for section status to > master (origin=local/attrd/35) > May 22 23:57:24 [2192] d-gp2-dbpg0-2 cib: info: cib_perform_op: > Diff: --- 0.35.74 2 > May 22 23:57:24 [2192] d-gp2-dbpg0-2 cib: info: cib_perform_op: > Diff: +++ 0.35.75 (null) > May 22 23:57:24 [2192] d-gp2-dbpg0-2 cib: info: cib_perform_op: > + /cib: @num_updates=75 > May 22 23:57:24 [2192] d-gp2-dbpg0-2 cib: info: cib_perform_op: > + > /cib/status/node_state[@id='1']/transient_attributes[@id='1']/instance_attributes[@id='status-1']/nvpair[@id='status-1-fail-count-postgresql-10-main']: > @value=INFINITY > May 22 23:57:24 [2197] d-gp2-dbpg0-2 crmd: notice: > abort_transition_graph: Transition aborted by > status-1-fail-count-postgresql-10-main, > fail-count-postgresql-10-main=INFINITY: Transient attribute change (modify > cib=0.35.75, source=abort_unless_down:329, > path=/cib/status/node_state[@id='1']/transient_attributes[@id='1']/instance_attributes[@id='status-1']/nvpair[@id='status-1-fail-count-postgresql-10-main'], > 0) > May 22 23:57:24 [2192] d-gp2-dbpg0-2 cib: info: > cib_process_request: Completed cib_modify operation for section status: OK > (rc=0, origin=d-gp2-dbpg0-2/attrd/35, version=0.35.75) > May 22 23:57:24 [2195] d-gp2-dbpg0-2 attrd: info: > attrd_cib_callback: Update 35 for fail-count-postgresql-10-main: OK (0) > May 22 23:57:24 [2195] d-gp2-dbpg0-2 attrd: info: > attrd_cib_callback: Update 35 for > fail-count-postgresql-10-main[d-gp2-dbpg0-1]=INFINITY: OK (0) > May 22 23:57:24 [2194] d-gp2-dbpg0-2 lrmd: info: log_finished: > finished - rsc:postgresql-10-main action:notify call_id:64 pid:11560 > exit-code:0 exec-time:77ms queue-time:0ms > May 22 23:57:24 [2197] d-gp2-dbpg0-2 crmd: notice: process_lrm_event: > Operation postgresql-10-main_notify_0: ok (node=d-gp2-dbpg0-2, call=64, > rc=0, cib-update=0, confirmed=true) > May 22 23:57:24 [2197] d-gp2-dbpg0-2 crmd: notice: run_graph: > Transition 28 (Complete=12, Pending=0, Fired=0, Skipped=0, Incomplete=1, > Source=/var/lib/pacemaker/pengine/pe-input-91.bz2): Complete > May 22 23:57:24 [2197] d-gp2-dbpg0-2 crmd: info: > do_state_transition: State transition S_TRANSITION_ENGINE -> S_POLICY_ENGINE > [ input=I_PE_CALC cause=C_FSA_INTERNAL origin=notify_crmd ] > May 22 23:57:24 [2196] d-gp2-dbpg0-2 pengine: info: > determine_online_status_fencing: Node d-gp2-dbpg0-3 is active > May 22 23:57:24 [2196] d-gp2-dbpg0-2 pengine: info: > determine_online_status: Node d-gp2-dbpg0-3 is online > May 22 23:57:24 [2196] d-gp2-dbpg0-2 pengine: info: > determine_online_status_fencing: Node d-gp2-dbpg0-1 is active > May 22 23:57:24 [2196] d-gp2-dbpg0-2 pengine: info: > determine_online_status: Node d-gp2-dbpg0-1 is online > May 22 23:57:24 [2196] d-gp2-dbpg0-2 pengine: info: > determine_online_status_fencing: Node d-gp2-dbpg0-2 is active > May 22 23:57:24 [2196] d-gp2-dbpg0-2 pengine: info: > determine_online_status: Node d-gp2-dbpg0-2 is online > May 22 23:57:24 [2196] d-gp2-dbpg0-2 pengine: warning: > unpack_rsc_op_failure: Processing failed op stop for > postgresql-10-main:1 on d-gp2-dbpg0-1: unknown error (1) > May 22 23:57:24 [2196] d-gp2-dbpg0-2 pengine: warning: > unpack_rsc_op_failure: Processing failed op stop for > postgresql-10-main:1 on d-gp2-dbpg0-1: unknown error (1) > May 22 23:57:24 [2196] d-gp2-dbpg0-2 pengine: warning: pe_fence_node: > Node d-gp2-dbpg0-1 will be fenced because of resource failure(s) > May 22 23:57:24 [2196] d-gp2-dbpg0-2 pengine: info: > determine_op_status: Operation monitor found resource postgresql-10-main:2 > active on d-gp2-dbpg0-2 > May 22 23:57:24 [2196] d-gp2-dbpg0-2 pengine: info: native_print: > vfencing (stonith:external/vcenter): Started d-gp2-dbpg0-2 > May 22 23:57:24 [2196] d-gp2-dbpg0-2 pengine: info: native_print: > postgresql-master-vip (ocf::heartbeat:IPaddr2): Started > d-gp2-dbpg0-2 > May 22 23:57:24 [2196] d-gp2-dbpg0-2 pengine: info: clone_print: > Master/Slave Set: postgresql-ha [postgresql-10-main] > May 22 23:57:24 [2196] d-gp2-dbpg0-2 pengine: info: native_print: > postgresql-10-main (ocf::heartbeat:pgsqlms): FAILED d-gp2-dbpg0-1 > May 22 23:57:24 [2196] d-gp2-dbpg0-2 pengine: info: short_print: > Masters: [ d-gp2-dbpg0-2 ] > May 22 23:57:24 [2196] d-gp2-dbpg0-2 pengine: info: short_print: > Slaves: [ d-gp2-dbpg0-3 ] > May 22 23:57:24 [2196] d-gp2-dbpg0-2 pengine: info: > get_failcount_full: postgresql-10-main:0 has failed INFINITY times on > d-gp2-dbpg0-1 > May 22 23:57:24 [2196] d-gp2-dbpg0-2 pengine: warning: > common_apply_stickiness: Forcing postgresql-ha away from d-gp2-dbpg0-1 > after 1000000 failures (max=5) > May 22 23:57:24 [2196] d-gp2-dbpg0-2 pengine: info: > get_failcount_full: postgresql-10-main:1 has failed INFINITY times on > d-gp2-dbpg0-1 > May 22 23:57:24 [2196] d-gp2-dbpg0-2 pengine: warning: > common_apply_stickiness: Forcing postgresql-ha away from d-gp2-dbpg0-1 > after 1000000 failures (max=5) > May 22 23:57:24 [2196] d-gp2-dbpg0-2 pengine: info: > get_failcount_full: postgresql-10-main:2 has failed INFINITY times on > d-gp2-dbpg0-1 > May 22 23:57:24 [2196] d-gp2-dbpg0-2 pengine: warning: > common_apply_stickiness: Forcing postgresql-ha away from d-gp2-dbpg0-1 > after 1000000 failures (max=5) > May 22 23:57:24 [2196] d-gp2-dbpg0-2 pengine: info: native_color: > Resource postgresql-10-main:1 cannot run anywhere > May 22 23:57:24 [2196] d-gp2-dbpg0-2 pengine: info: master_color: > Promoting postgresql-10-main:2 (Master d-gp2-dbpg0-2) > May 22 23:57:24 [2196] d-gp2-dbpg0-2 pengine: info: master_color: > postgresql-ha: Promoted 1 instances of a possible 1 to master > May 22 23:57:24 [2196] d-gp2-dbpg0-2 pengine: warning: stage6: > Scheduling Node d-gp2-dbpg0-1 for STONITH > May 22 23:57:24 [2196] d-gp2-dbpg0-2 pengine: notice: > native_stop_constraints: Stop of failed resource postgresql-10-main:1 is > implicit after d-gp2-dbpg0-1 is fenced > May 22 23:57:24 [2196] d-gp2-dbpg0-2 pengine: info: > native_stop_constraints: Creating secondary notification for > postgresql-10-main:1_stop_0 > May 22 23:57:24 [2196] d-gp2-dbpg0-2 pengine: info: LogActions: Leave > vfencing (Started d-gp2-dbpg0-2) > May 22 23:57:24 [2196] d-gp2-dbpg0-2 pengine: info: LogActions: Leave > postgresql-master-vip (Started d-gp2-dbpg0-2) > May 22 23:57:24 [2196] d-gp2-dbpg0-2 pengine: info: LogActions: Leave > postgresql-10-main:0 (Slave d-gp2-dbpg0-3) > May 22 23:57:24 [2196] d-gp2-dbpg0-2 pengine: notice: LogActions: Stop > postgresql-10-main:1 (d-gp2-dbpg0-1) > May 22 23:57:24 [2196] d-gp2-dbpg0-2 pengine: info: LogActions: Leave > postgresql-10-main:2 (Master d-gp2-dbpg0-2) > May 22 23:57:24 [2197] d-gp2-dbpg0-2 crmd: info: > do_state_transition: State transition S_POLICY_ENGINE -> S_TRANSITION_ENGINE > [ input=I_PE_SUCCESS cause=C_IPC_MESSAGE origin=handle_response ] > May 22 23:57:24 [2194] d-gp2-dbpg0-2 lrmd: info: log_execute: > executing - rsc:postgresql-10-main action:notify call_id:65 > May 22 23:57:24 [2196] d-gp2-dbpg0-2 pengine: warning: > process_pe_message: Calculated Transition 29: > /var/lib/pacemaker/pengine/pe-warn-12.bz2 > May 22 23:57:24 [2194] d-gp2-dbpg0-2 lrmd: info: log_finished: > finished - rsc:postgresql-10-main action:notify call_id:65 pid:11573 > exit-code:0 exec-time:160ms queue-time:0ms > May 22 23:57:24 [2197] d-gp2-dbpg0-2 crmd: notice: process_lrm_event: > Operation postgresql-10-main_notify_0: ok (node=d-gp2-dbpg0-2, call=65, > rc=0, cib-update=0, confirmed=true) > _______________________________________________ > Users mailing list: Users@clusterlabs.org > https://lists.clusterlabs.org/mailman/listinfo/users > > Project Home: http://www.clusterlabs.org > Getting started: http://www.clusterlabs.org/doc/Cluster_from_Scratch.pdf > Bugs: http://bugs.clusterlabs.org _______________________________________________ Users mailing list: Users@clusterlabs.org https://lists.clusterlabs.org/mailman/listinfo/users Project Home: http://www.clusterlabs.org Getting started: http://www.clusterlabs.org/doc/Cluster_from_Scratch.pdf Bugs: http://bugs.clusterlabs.org
