[ClusterLabs] PAF not starting resource successfully after node reboot (was: How to set up fencing/stonith)
Casey & Gina
caseyandgina at icloud.com
Wed May 23 16:22:24 EDT 2018
>> 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)
More information about the Users
mailing list