Jan 14 10:56:34 [3918] nbgprepdb6 cib: info: crm_client_destroy: Destroying 0 events Jan 14 10:56:44 [10650] nbgprepdb6 pacemakerd: info: crm_log_init: Changed active directory to /var/lib/heartbeat/cores/root Jan 14 10:56:44 [10650] nbgprepdb6 pacemakerd: info: crm_xml_cleanup: Cleaning up memory from libxml2 Jan 14 10:57:44 [3920] nbgprepdb6 lrmd: warning: child_timeout_callback: pgsql_monitor_10000 process (PID 10640) timed out Jan 14 10:57:44 [3920] nbgprepdb6 lrmd: warning: operation_finished: pgsql_monitor_10000:10640 - timed out after 60000ms Jan 14 10:57:44 [3923] nbgprepdb6 crmd: error: process_lrm_event: LRM operation pgsql_monitor_10000 (92) Timed Out (timeout=60000ms) Jan 14 10:57:44 [3918] nbgprepdb6 cib: info: cib_process_request: Forwarding cib_modify operation for section status to master (origin=local/crmd/32) Jan 14 10:57:44 [3921] nbgprepdb6 attrd: notice: attrd_cs_dispatch: Update relayed from nbgprepwitness56 Jan 14 10:57:44 [3921] nbgprepdb6 attrd: notice: attrd_trigger_update: Sending flush op to all hosts for: fail-count-pgsql (1) Jan 14 10:57:44 [3918] nbgprepdb6 cib: info: cib_process_request: Completed cib_apply_diff operation for section status: OK (rc=0, origin=nbgprepwitness56/crmd/32, version=0.36.7) Jan 14 10:57:44 [3918] nbgprepdb6 cib: info: cib_process_request: Completed cib_query operation for section //cib/status//node_state[@id='739251316']//transient_attributes//nvpair[@name='fail-count-pgsql']: No such device o r address (rc=-6, origin=local/attrd/110, version=0.36.7) Jan 14 10:57:44 [3918] nbgprepdb6 cib: info: cib_process_request: Completed cib_query operation for section /cib: OK (rc=0, origin=local/attrd/111, version=0.36.7) Jan 14 10:57:44 [3921] nbgprepdb6 attrd: notice: attrd_perform_update: Sent update 112: fail-count-pgsql=1 Jan 14 10:57:44 [3921] nbgprepdb6 attrd: notice: attrd_cs_dispatch: Update relayed from nbgprepwitness56 Jan 14 10:57:44 [3921] nbgprepdb6 attrd: notice: attrd_trigger_update: Sending flush op to all hosts for: last-failure-pgsql (1452765464) Jan 14 10:57:44 [3918] nbgprepdb6 cib: info: cib_process_request: Forwarding cib_modify operation for section status to master (origin=local/attrd/112) Jan 14 10:57:44 [3918] nbgprepdb6 cib: info: cib_process_request: Completed cib_query operation for section //cib/status//node_state[@id='739251316']//transient_attributes//nvpair[@name='last-failure-pgsql']: No such device or address (rc=-6, origin=local/attrd/113, version=0.36.7) Jan 14 10:57:44 [3918] nbgprepdb6 cib: info: cib_process_request: Completed cib_query operation for section /cib: OK (rc=0, origin=local/attrd/114, version=0.36.7) Jan 14 10:57:44 [3921] nbgprepdb6 attrd: notice: attrd_perform_update: Sent update 115: last-failure-pgsql=1452765464 Jan 14 10:57:44 [3918] nbgprepdb6 cib: info: cib_process_request: Forwarding cib_modify operation for section status to master (origin=local/attrd/115) Jan 14 10:57:44 [3918] nbgprepdb6 cib: info: cib_process_request: Completed cib_apply_diff operation for section status: OK (rc=0, origin=nbgprepwitness56/attrd/112, version=0.36.8) Jan 14 10:57:44 [3918] nbgprepdb6 cib: info: cib_process_request: Completed cib_apply_diff operation for section status: OK (rc=0, origin=nbgprepwitness56/attrd/115, version=0.36.9) Jan 14 10:57:44 [3923] nbgprepdb6 crmd: info: do_lrm_rsc_op: Performing key=82:4104:0:48387f7e-8de3-4eed-bab6-3db414426226 op=pgsql_notify_0 Jan 14 10:57:44 [3920] nbgprepdb6 lrmd: info: log_execute: executing - rsc:pgsql action:notify call_id:145 Jan 14 10:57:44 [11338] nbgprepdb6 pacemakerd: info: crm_log_init: Changed active directory to /var/lib/heartbeat/cores/root Jan 14 10:57:44 [11338] nbgprepdb6 pacemakerd: info: crm_xml_cleanup: Cleaning up memory from libxml2 Jan 14 10:57:45 [3920] nbgprepdb6 lrmd: info: log_finished: finished - rsc:pgsql action:notify call_id:145 pid:11328 exit-code:0 exec-time:355ms queue-time:0ms Jan 14 10:57:45 [3923] nbgprepdb6 crmd: notice: process_lrm_event: LRM operation pgsql_notify_0 (call=145, rc=0, cib-update=0, confirmed=true) ok Jan 14 10:57:45 [3920] nbgprepdb6 lrmd: info: cancel_recurring_action: Cancelling operation pgsql_monitor_10000 Jan 14 10:57:45 [3923] nbgprepdb6 crmd: info: do_lrm_rsc_op: Performing key=30:4104:0:48387f7e-8de3-4eed-bab6-3db414426226 op=pgsql_demote_0 Jan 14 10:57:45 [3920] nbgprepdb6 lrmd: info: log_execute: executing - rsc:pgsql action:demote call_id:149 Jan 14 10:57:45 [3923] nbgprepdb6 crmd: info: process_lrm_event: LRM operation pgsql_monitor_10000 (call=92, status=1, cib-update=0, confirmed=true) Cancelled Jan 14 10:57:45 [11422] nbgprepdb6 pacemakerd: info: crm_log_init: Changed active directory to /var/lib/heartbeat/cores/root Jan 14 10:57:45 [11422] nbgprepdb6 pacemakerd: info: crm_xml_cleanup: Cleaning up memory from libxml2 Jan 14 10:57:45 [3918] nbgprepdb6 cib: info: crm_client_new: Connecting 0x7f30164737e0 for uid=0 gid=0 pid=11495 id=0b5f375d-11fc-4b01-8191-dafdaab8c08d Jan 14 10:57:45 [3918] nbgprepdb6 cib: info: cib_process_request: Completed cib_query operation for section nodes: OK (rc=0, origin=local/crm_attribute/2, version=0.36.9) Jan 14 10:57:45 [3921] nbgprepdb6 attrd: notice: attrd_trigger_update: Sending flush op to all hosts for: master-pgsql (-INFINITY) Jan 14 10:57:45 [3918] nbgprepdb6 cib: info: cib_process_request: Completed cib_query operation for section //cib/status//node_state[@id='739251316']//transient_attributes//nvpair[@name='master-pgsql']: OK (rc=0, origin=local/attrd/116, version=0.36.9) Jan 14 10:57:45 [3918] nbgprepdb6 cib: info: crm_client_destroy: Destroying 0 events Jan 14 10:57:45 [3921] nbgprepdb6 attrd: notice: attrd_perform_update: Sent update 117: master-pgsql=-INFINITY Jan 14 10:57:45 [3918] nbgprepdb6 cib: info: cib_process_request: Forwarding cib_modify operation for section status to master (origin=local/attrd/117) Jan 14 10:57:45 [3918] nbgprepdb6 cib: info: crm_client_new: Connecting 0x7f30164737e0 for uid=0 gid=0 pid=11496 id=6111ecce-6da3-4b41-b80f-7f3e0ebce72c Jan 14 10:57:45 [3918] nbgprepdb6 cib: info: cib_process_request: Completed cib_apply_diff operation for section status: OK (rc=0, origin=nbgprepwitness56/attrd/117, version=0.36.10) Jan 14 10:57:45 [3918] nbgprepdb6 cib: info: cib_process_request: Completed cib_query operation for section nodes: OK (rc=0, origin=local/crm_attribute/2, version=0.36.10) Jan 14 10:57:45 [3921] nbgprepdb6 attrd: notice: attrd_trigger_update: Sending flush op to all hosts for: pgsql-master-baseline () Jan 14 10:57:45 [3918] nbgprepdb6 cib: info: cib_process_request: Completed cib_query operation for section //cib/status//node_state[@id='739251316']//transient_attributes//nvpair[@name='pgsql-master-baseline']: OK (rc=0, origin=local/attrd/118, version=0.36.10) Jan 14 10:57:45 [3918] nbgprepdb6 cib: info: crm_client_destroy: Destroying 0 events Jan 14 10:57:45 [3921] nbgprepdb6 attrd: notice: attrd_perform_update: Sent delete 119: node=739251316, attr=pgsql-master-baseline, id=, set=(null), section=status Jan 14 10:57:45 [3918] nbgprepdb6 cib: info: cib_process_request: Forwarding cib_delete operation for section status to master (origin=local/attrd/119) Jan 14 10:57:45 [3918] nbgprepdb6 cib: info: cib_process_request: Completed cib_query operation for section //cib/status//node_state[@id='739251316']//transient_attributes//nvpair[@name='pgsql-master-baseline']: OK (rc=0, origin=local/attrd/120, version=0.36.10) Jan 14 10:57:45 [3921] nbgprepdb6 attrd: notice: attrd_perform_update: Sent delete 121: node=739251316, attr=pgsql-master-baseline, id=, set=(null), section=status Jan 14 10:57:45 [3918] nbgprepdb6 cib: info: cib_process_request: Forwarding cib_delete operation for section status to master (origin=local/attrd/121) Jan 14 10:57:45 [3918] nbgprepdb6 cib: info: cib_process_request: Completed cib_apply_diff operation for section status: OK (rc=0, origin=nbgprepwitness56/attrd/119, version=0.36.11) pgsql(pgsql)[11412]: 2016/01/14_10:57:45 INFO: Stopping PostgreSQL on demote. pgsql(pgsql)[11412]: 2016/01/14_10:57:54 INFO: waiting for server to shut down........... done server stopped pgsql(pgsql)[11412]: 2016/01/14_10:57:54 INFO: PostgreSQL is down Jan 14 10:57:54 [3918] nbgprepdb6 cib: info: crm_client_new: Connecting 0x7f3016348920 for uid=0 gid=0 pid=13611 id=e1998f98-d348-4478-a57e-42301d0a1b43 Jan 14 10:57:54 [3918] nbgprepdb6 cib: info: cib_process_request: Completed cib_query operation for section 'all': OK (rc=0, origin=local/crm_mon/2, version=0.36.11) Jan 14 10:57:54 [3918] nbgprepdb6 cib: info: crm_client_destroy: Destroying 0 events Jan 14 10:57:54 [3918] nbgprepdb6 cib: info: crm_client_new: Connecting 0x7f3016348920 for uid=0 gid=0 pid=13612 id=5512bdd2-3020-4b39-b091-abe4571392c1 Jan 14 10:57:54 [3918] nbgprepdb6 cib: info: cib_process_request: Completed cib_query operation for section nodes: OK (rc=0, origin=local/crm_attribute/2, version=0.36.11) Jan 14 10:57:54 [3918] nbgprepdb6 cib: info: cib_process_request: Completed cib_query operation for section //cib/status//node_state[@id='739251316']//transient_attributes//nvpair[@name='pgsql-status']: OK (rc=0, origin=local/crm_attribute/3, version=0.36.11) Jan 14 10:57:54 [3918] nbgprepdb6 cib: info: crm_client_destroy: Destroying 0 events pgsql(pgsql)[11412]: 2016/01/14_10:57:54 INFO: Changing pgsql-status on nbgprepdb6 : PRI->STOP. Jan 14 10:57:54 [3918] nbgprepdb6 cib: info: crm_client_new: Connecting 0x7f3016348920 for uid=0 gid=0 pid=13618 id=6999317e-6dc2-40cd-b9c2-8287dd764732 Jan 14 10:57:54 [3918] nbgprepdb6 cib: info: cib_process_request: Completed cib_query operation for section nodes: OK (rc=0, origin=local/crm_attribute/2, version=0.36.11) Jan 14 10:57:54 [3921] nbgprepdb6 attrd: notice: attrd_trigger_update: Sending flush op to all hosts for: pgsql-status (STOP) Jan 14 10:57:54 [3918] nbgprepdb6 cib: info: crm_client_destroy: Destroying 0 events Jan 14 10:57:54 [3918] nbgprepdb6 cib: info: cib_process_request: Completed cib_query operation for section //cib/status//node_state[@id='739251316']//transient_attributes//nvpair[@name='pgsql-status']: OK (rc=0, origin=local/attrd/122, version=0.36.11) Jan 14 10:57:54 [3921] nbgprepdb6 attrd: notice: attrd_perform_update: Sent update 123: pgsql-status=STOP Jan 14 10:57:54 [3920] nbgprepdb6 lrmd: notice: operation_finished: pgsql_demote_0:11412:stderr [ 2016/01/14_10:57:45 INFO: Stopping PostgreSQL on demote. ] Jan 14 10:57:54 [3920] nbgprepdb6 lrmd: notice: operation_finished: pgsql_demote_0:11412:stderr [ 2016/01/14_10:57:54 INFO: waiting for server to shut down........... done server stopped ] Jan 14 10:57:54 [3920] nbgprepdb6 lrmd: notice: operation_finished: pgsql_demote_0:11412:stderr [ 2016/01/14_10:57:54 INFO: PostgreSQL is down ] Jan 14 10:57:54 [3920] nbgprepdb6 lrmd: notice: operation_finished: pgsql_demote_0:11412:stderr [ 2016/01/14_10:57:54 INFO: Changing pgsql-status on nbgprepdb6 : PRI->STOP. ] Jan 14 10:57:54 [3920] nbgprepdb6 lrmd: info: log_finished: finished - rsc:pgsql action:demote call_id:149 pid:11412 exit-code:0 exec-time:9159ms queue-time:1ms Jan 14 10:57:54 [3918] nbgprepdb6 cib: info: cib_process_request: Forwarding cib_modify operation for section status to master (origin=local/attrd/123) Jan 14 10:57:54 [3923] nbgprepdb6 crmd: notice: process_lrm_event: LRM operation pgsql_demote_0 (call=149, rc=0, cib-update=33, confirmed=true) ok Jan 14 10:57:54 [3918] nbgprepdb6 cib: info: cib_process_request: Forwarding cib_modify operation for section status to master (origin=local/crmd/33) Jan 14 10:57:54 [3923] nbgprepdb6 crmd: info: do_lrm_rsc_op: Performing key=83:4104:0:48387f7e-8de3-4eed-bab6-3db414426226 op=pgsql_notify_0 Jan 14 10:57:54 [3920] nbgprepdb6 lrmd: info: log_execute: executing - rsc:pgsql action:notify call_id:153 Jan 14 10:57:54 [3918] nbgprepdb6 cib: info: cib_process_request: Completed cib_apply_diff operation for section status: OK (rc=0, origin=nbgprepwitness56/attrd/123, version=0.36.12) Jan 14 10:57:54 [3918] nbgprepdb6 cib: info: cib_process_request: Completed cib_apply_diff operation for section status: OK (rc=0, origin=nbgprepwitness56/crmd/33, version=0.36.13) Jan 14 10:57:54 [13629] nbgprepdb6 pacemakerd: info: crm_log_init: Changed active directory to /var/lib/heartbeat/cores/root Jan 14 10:57:54 [13629] nbgprepdb6 pacemakerd: info: crm_xml_cleanup: Cleaning up memory from libxml2 Jan 14 10:57:54 [3920] nbgprepdb6 lrmd: info: log_finished: finished - rsc:pgsql action:notify call_id:153 pid:13619 exit-code:0 exec-time:145ms queue-time:0ms Jan 14 10:57:54 [3923] nbgprepdb6 crmd: notice: process_lrm_event: LRM operation pgsql_notify_0 (call=153, rc=0, cib-update=0, confirmed=true) ok Jan 14 10:57:54 [3918] nbgprepdb6 cib: info: cib_process_request: Completed cib_query operation for section //cib/status//node_state[@id='739251316']//transient_attributes//nvpair[@name='pgsql-master-baseline']: No such device or address (rc=-6, origin=local/attrd/124, version=0.36.13) Jan 14 10:57:54 [3918] nbgprepdb6 cib: info: cib_process_request: Completed cib_apply_diff operation for section status: OK (rc=0, origin=nbgprepwitness56/attrd/32, version=0.36.14) Jan 14 10:57:54 [3918] nbgprepdb6 cib: info: cib_process_request: Completed cib_query operation for section //cib/status//node_state[@id='739251316']//transient_attributes//nvpair[@name='pgsql-status']: OK (rc=0, origin=local/attrd/125, version=0.36.14) Jan 14 10:57:54 [3918] nbgprepdb6 cib: info: cib_process_request: Forwarding cib_modify operation for section status to master (origin=local/attrd/126) Jan 14 10:57:54 [3918] nbgprepdb6 cib: info: cib_process_request: Completed cib_apply_diff operation for section status: OK (rc=0, origin=nbgprepwitness56/attrd/34, version=0.36.15) Jan 14 10:57:54 [3920] nbgprepdb6 lrmd: info: cancel_recurring_action: Cancelling operation vip-rep_monitor_10000 Jan 14 10:57:54 [3923] nbgprepdb6 crmd: info: do_lrm_rsc_op: Performing key=21:4105:0:48387f7e-8de3-4eed-bab6-3db414426226 op=vip-rep_stop_0 Jan 14 10:57:54 [3920] nbgprepdb6 lrmd: info: log_execute: executing - rsc:vip-rep action:stop call_id:157 Jan 14 10:57:54 [3923] nbgprepdb6 crmd: info: process_lrm_event: LRM operation vip-rep_monitor_10000 (call=105, status=1, cib-update=0, confirmed=true) Cancelled Jan 14 10:57:54 [3923] nbgprepdb6 crmd: info: do_lrm_rsc_op: Performing key=77:4105:0:48387f7e-8de3-4eed-bab6-3db414426226 op=pgsql_notify_0 Jan 14 10:57:54 [3920] nbgprepdb6 lrmd: info: log_execute: executing - rsc:pgsql action:notify call_id:160 Jan 14 10:57:54 [3918] nbgprepdb6 cib: info: cib_process_request: Completed cib_apply_diff operation for section status: OK (rc=0, origin=nbgprepwitness56/crmd/22, version=0.36.16) Jan 14 10:57:54 [13724] nbgprepdb6 pacemakerd: info: crm_log_init: Changed active directory to /var/lib/heartbeat/cores/root Jan 14 10:57:54 [13724] nbgprepdb6 pacemakerd: info: crm_xml_cleanup: Cleaning up memory from libxml2 IPaddr2(vip-rep)[13705]: 2016/01/14_10:57:55 INFO: IP status = ok, IP_CIP= Jan 14 10:57:55 [3920] nbgprepdb6 lrmd: notice: operation_finished: vip-rep_stop_0:13705:stderr [ 2016/01/14_10:57:55 INFO: IP status = ok, IP_CIP= ] Jan 14 10:57:55 [3920] nbgprepdb6 lrmd: info: log_finished: finished - rsc:vip-rep action:stop call_id:157 pid:13705 exit-code:0 exec-time:72ms queue-time:0ms Jan 14 10:57:55 [3923] nbgprepdb6 crmd: notice: process_lrm_event: LRM operation vip-rep_stop_0 (call=157, rc=0, cib-update=34, confirmed=true) ok Jan 14 10:57:55 [3918] nbgprepdb6 cib: info: cib_process_request: Forwarding cib_modify operation for section status to master (origin=local/crmd/34) Jan 14 10:57:55 [3918] nbgprepdb6 cib: info: cib_process_request: Completed cib_apply_diff operation for section status: OK (rc=0, origin=nbgprepwitness56/crmd/23, version=0.36.17) Jan 14 10:57:55 [3918] nbgprepdb6 cib: info: cib_process_request: Completed cib_apply_diff operation for section status: OK (rc=0, origin=nbgprepwitness56/crmd/34, version=0.36.18) Jan 14 10:57:55 [3920] nbgprepdb6 lrmd: info: log_finished: finished - rsc:pgsql action:notify call_id:160 pid:13707 exit-code:0 exec-time:160ms queue-time:0ms Jan 14 10:57:55 [3923] nbgprepdb6 crmd: notice: process_lrm_event: LRM operation pgsql_notify_0 (call=160, rc=0, cib-update=0, confirmed=true) ok Jan 14 10:57:55 [3920] nbgprepdb6 lrmd: info: cancel_recurring_action: Cancelling operation vip-master_monitor_10000 Jan 14 10:57:55 [3923] nbgprepdb6 crmd: info: do_lrm_rsc_op: Performing key=14:4106:0:48387f7e-8de3-4eed-bab6-3db414426226 op=vip-master_stop_0 Jan 14 10:57:55 [3920] nbgprepdb6 lrmd: info: log_execute: executing - rsc:vip-master action:stop call_id:165 Jan 14 10:57:55 [3923] nbgprepdb6 crmd: info: do_lrm_rsc_op: Performing key=72:4106:0:48387f7e-8de3-4eed-bab6-3db414426226 op=pgsql_notify_0 Jan 14 10:57:55 [3920] nbgprepdb6 lrmd: info: log_execute: executing - rsc:pgsql action:notify call_id:167 Jan 14 10:57:55 [3923] nbgprepdb6 crmd: info: process_lrm_event: LRM operation vip-master_monitor_10000 (call=98, status=1, cib-update=0, confirmed=true) Cancelled Jan 14 10:57:55 [13841] nbgprepdb6 pacemakerd: info: crm_log_init: Changed active directory to /var/lib/heartbeat/cores/root Jan 14 10:57:55 [13841] nbgprepdb6 pacemakerd: info: crm_xml_cleanup: Cleaning up memory from libxml2 IPaddr2(vip-master)[13823]: 2016/01/14_10:57:55 INFO: IP status = ok, IP_CIP= Jan 14 10:57:55 [3920] nbgprepdb6 lrmd: notice: operation_finished: vip-master_stop_0:13823:stderr [ 2016/01/14_10:57:55 INFO: IP status = ok, IP_CIP= ] Jan 14 10:57:55 [3920] nbgprepdb6 lrmd: info: log_finished: finished - rsc:vip-master action:stop call_id:165 pid:13823 exit-code:0 exec-time:75ms queue-time:0ms Jan 14 10:57:55 [3923] nbgprepdb6 crmd: notice: process_lrm_event: LRM operation vip-master_stop_0 (call=165, rc=0, cib-update=35, confirmed=true) ok Jan 14 10:57:55 [3918] nbgprepdb6 cib: info: cib_process_request: Forwarding cib_modify operation for section status to master (origin=local/crmd/35) Jan 14 10:57:55 [3918] nbgprepdb6 cib: info: cib_process_request: Completed cib_apply_diff operation for section status: OK (rc=0, origin=nbgprepwitness56/crmd/35, version=0.36.19) Jan 14 10:57:55 [3920] nbgprepdb6 lrmd: info: log_finished: finished - rsc:pgsql action:notify call_id:167 pid:13824 exit-code:0 exec-time:175ms queue-time:0ms Jan 14 10:57:55 [3923] nbgprepdb6 crmd: notice: process_lrm_event: LRM operation pgsql_notify_0 (call=167, rc=0, cib-update=0, confirmed=true) ok Jan 14 10:57:55 [3923] nbgprepdb6 crmd: info: do_lrm_rsc_op: Performing key=6:4106:0:48387f7e-8de3-4eed-bab6-3db414426226 op=pgsql_stop_0 Jan 14 10:57:55 [3920] nbgprepdb6 lrmd: info: log_execute: executing - rsc:pgsql action:stop call_id:172 Jan 14 10:57:55 [13969] nbgprepdb6 pacemakerd: info: crm_log_init: Changed active directory to /var/lib/heartbeat/cores/root Jan 14 10:57:55 [13969] nbgprepdb6 pacemakerd: info: crm_xml_cleanup: Cleaning up memory from libxml2 Jan 14 10:57:55 [3918] nbgprepdb6 cib: info: crm_client_new: Connecting 0x7f301635cde0 for uid=0 gid=0 pid=14043 id=372ede00-ed62-462f-8044-32cc22f08497 Jan 14 10:57:55 [3918] nbgprepdb6 cib: info: cib_process_request: Completed cib_query operation for section nodes: OK (rc=0, origin=local/crm_attribute/2, version=0.36.19) Jan 14 10:57:55 [3918] nbgprepdb6 cib: info: crm_client_destroy: Destroying 0 events Jan 14 10:57:55 [3918] nbgprepdb6 cib: info: crm_client_new: Connecting 0x7f301635cde0 for uid=0 gid=0 pid=14044 id=c259761d-00e9-4cbd-b694-382898471f58 Jan 14 10:57:55 [3918] nbgprepdb6 cib: info: cib_process_request: Completed cib_query operation for section nodes: OK (rc=0, origin=local/crm_attribute/2, version=0.36.19) Jan 14 10:57:55 [3918] nbgprepdb6 cib: info: crm_client_destroy: Destroying 0 events pgsql(pgsql)[13959]: 2016/01/14_10:57:55 INFO: PostgreSQL is already stopped. Jan 14 10:57:55 [3918] nbgprepdb6 cib: info: crm_client_new: Connecting 0x7f301635cde0 for uid=0 gid=0 pid=14055 id=296d3c3f-35f2-42ee-90c1-05069c7ab0a6 Jan 14 10:57:55 [3918] nbgprepdb6 cib: info: cib_process_request: Completed cib_query operation for section 'all': OK (rc=0, origin=local/crm_mon/2, version=0.36.19) Jan 14 10:57:55 [3918] nbgprepdb6 cib: info: crm_client_destroy: Destroying 0 events Jan 14 10:57:55 [3918] nbgprepdb6 cib: info: crm_client_new: Connecting 0x7f301635cde0 for uid=0 gid=0 pid=14056 id=9357f2cc-7a7e-40ca-877a-17f0b6c065e2 Jan 14 10:57:55 [3918] nbgprepdb6 cib: info: cib_process_request: Completed cib_query operation for section nodes: OK (rc=0, origin=local/crm_attribute/2, version=0.36.19) Jan 14 10:57:55 [3918] nbgprepdb6 cib: info: cib_process_request: Completed cib_query operation for section //cib/status//node_state[@id='739251316']//transient_attributes//nvpair[@name='pgsql-status']: OK (rc=0, origin=local/crm_attribute/3, version=0.36.19) Jan 14 10:57:55 [3918] nbgprepdb6 cib: info: crm_client_destroy: Destroying 0 events Jan 14 10:57:55 [3920] nbgprepdb6 lrmd: notice: operation_finished: pgsql_stop_0:13959:stderr [ 2016/01/14_10:57:55 INFO: PostgreSQL is already stopped. ] Jan 14 10:57:55 [3920] nbgprepdb6 lrmd: info: log_finished: finished - rsc:pgsql action:stop call_id:172 pid:13959 exit-code:0 exec-time:224ms queue-time:0ms Jan 14 10:57:55 [3923] nbgprepdb6 crmd: notice: process_lrm_event: LRM operation pgsql_stop_0 (call=172, rc=0, cib-update=36, confirmed=true) ok Jan 14 10:57:55 [3918] nbgprepdb6 cib: info: cib_process_request: Forwarding cib_modify operation for section status to master (origin=local/crmd/36) Jan 14 10:57:55 [3918] nbgprepdb6 cib: info: cib_process_request: Completed cib_apply_diff operation for section status: OK (rc=0, origin=nbgprepwitness56/crmd/36, version=0.36.20) Jan 14 10:57:55 [3923] nbgprepdb6 crmd: info: do_lrm_rsc_op: Performing key=27:4106:0:48387f7e-8de3-4eed-bab6-3db414426226 op=pgsql_start_0 Jan 14 10:57:55 [3920] nbgprepdb6 lrmd: info: log_execute: executing - rsc:pgsql action:start call_id:175 Jan 14 10:57:55 [14067] nbgprepdb6 pacemakerd: info: crm_log_init: Changed active directory to /var/lib/heartbeat/cores/root Jan 14 10:57:55 [14067] nbgprepdb6 pacemakerd: info: crm_xml_cleanup: Cleaning up memory from libxml2 Jan 14 10:57:56 [3918] nbgprepdb6 cib: info: crm_client_new: Connecting 0x7f3016473730 for uid=0 gid=0 pid=14143 id=94d74d0c-56b8-42cb-9f9e-f47b4fc3e3b5 Jan 14 10:57:56 [3918] nbgprepdb6 cib: info: cib_process_request: Completed cib_query operation for section 'all': OK (rc=0, origin=local/crm_mon/2, version=0.36.20) Jan 14 10:57:56 [3918] nbgprepdb6 cib: info: crm_client_destroy: Destroying 0 events Jan 14 10:57:56 [3918] nbgprepdb6 cib: info: crm_client_new: Connecting 0x7f3016473730 for uid=0 gid=0 pid=14144 id=de24d5a4-79ee-481d-9369-1ee6b858e06d Jan 14 10:57:56 [3918] nbgprepdb6 cib: info: cib_process_request: Completed cib_query operation for section nodes: OK (rc=0, origin=local/crm_attribute/2, version=0.36.20) Jan 14 10:57:56 [3918] nbgprepdb6 cib: info: cib_process_request: Completed cib_query operation for section //cib/status//node_state[@id='739251316']//transient_attributes//nvpair[@name='pgsql-status']: OK (rc=0, origin=local/crm_attribute/3, version=0.36.20) Jan 14 10:57:56 [3918] nbgprepdb6 cib: info: crm_client_destroy: Destroying 0 events Jan 14 10:57:56 [3918] nbgprepdb6 cib: info: crm_client_new: Connecting 0x7f3016473730 for uid=0 gid=0 pid=14145 id=5e010fbc-5047-4cc7-9c94-8c1dce74c922 Jan 14 10:57:56 [3918] nbgprepdb6 cib: info: cib_process_request: Completed cib_query operation for section nodes: OK (rc=0, origin=local/crm_attribute/2, version=0.36.20) Jan 14 10:57:56 [3918] nbgprepdb6 cib: info: crm_client_destroy: Destroying 0 events Jan 14 10:57:56 [3918] nbgprepdb6 cib: info: crm_client_new: Connecting 0x7f3016473730 for uid=0 gid=0 pid=14149 id=53367ba3-cdbe-4cfe-8400-85f0cd687093 Jan 14 10:57:56 [3918] nbgprepdb6 cib: info: cib_process_request: Completed cib_query operation for section nodes: OK (rc=0, origin=local/crm_attribute/2, version=0.36.20) Jan 14 10:57:56 [3918] nbgprepdb6 cib: info: crm_client_destroy: Destroying 0 events Jan 14 10:57:56 [3918] nbgprepdb6 cib: info: crm_client_new: Connecting 0x7f3016473730 for uid=0 gid=0 pid=14159 id=194de57d-3ca4-42db-9609-200156521e00 Jan 14 10:57:56 [3918] nbgprepdb6 cib: info: cib_process_request: Completed cib_query operation for section nodes: OK (rc=0, origin=local/crm_attribute/2, version=0.36.20) Jan 14 10:57:56 [3918] nbgprepdb6 cib: info: crm_client_destroy: Destroying 0 events pgsql(pgsql)[14057]: 2016/01/14_10:57:56 ERROR: My data may be inconsistent. You have to remove /var/lib/pgsql/tmp/PGSQL.lock file to force start. Jan 14 10:57:56 [3920] nbgprepdb6 lrmd: notice: operation_finished: pgsql_start_0:14057:stderr [ ocf-exit-reason:My data may be inconsistent. You have to remove /var/lib/pgsql/tmp/PGSQL.lock file to force start. ] Jan 14 10:57:56 [3920] nbgprepdb6 lrmd: info: log_finished: finished - rsc:pgsql action:start call_id:175 pid:14057 exit-code:1 exec-time:261ms queue-time:0ms Jan 14 10:57:56 [14174] nbgprepdb6 pacemakerd: info: crm_log_init: Changed active directory to /var/lib/heartbeat/cores/hacluster Jan 14 10:57:56 [14174] nbgprepdb6 pacemakerd: info: crm_xml_cleanup: Cleaning up memory from libxml2 Jan 14 10:57:56 [3923] nbgprepdb6 crmd: info: services_os_action_execute: Managed pgsql_meta-data_0 process 14164 exited with rc=0 Jan 14 10:57:56 [3923] nbgprepdb6 crmd: notice: process_lrm_event: LRM operation pgsql_start_0 (call=175, rc=1, cib-update=37, confirmed=true) unknown error Jan 14 10:57:56 [3918] nbgprepdb6 cib: info: cib_process_request: Forwarding cib_modify operation for section status to master (origin=local/crmd/37) Jan 14 10:57:56 [3921] nbgprepdb6 attrd: notice: attrd_cs_dispatch: Update relayed from nbgprepwitness56 Jan 14 10:57:56 [3921] nbgprepdb6 attrd: notice: attrd_trigger_update: Sending flush op to all hosts for: fail-count-pgsql (INFINITY) Jan 14 10:57:56 [3923] nbgprepdb6 crmd: info: do_lrm_rsc_op: Performing key=69:4106:0:48387f7e-8de3-4eed-bab6-3db414426226 op=pgsql_notify_0 Jan 14 10:57:56 [3918] nbgprepdb6 cib: info: cib_process_request: Completed cib_query operation for section //cib/status//node_state[@id='739251316']//transient_attributes//nvpair[@name='fail-count-pgsql']: OK (rc=0, origin=local/attrd/127, version=0.36.20) Jan 14 10:57:56 [3918] nbgprepdb6 cib: info: cib_process_request: Forwarding cib_modify operation for section status to master (origin=local/attrd/134) Jan 14 10:57:56 [3921] nbgprepdb6 attrd: notice: attrd_perform_update: Sent update 134: last-failure-pgsql=1452765476 Jan 14 10:57:56 [3918] nbgprepdb6 cib: info: cib_process_request: Completed cib_apply_diff operation for section status: OK (rc=0, origin=nbgprepwitness56/attrd/130, version=0.36.23) Jan 14 10:57:56 [14210] nbgprepdb6 pacemakerd: info: crm_log_init: Changed active directory to /var/lib/heartbeat/cores/root Jan 14 10:57:56 [14210] nbgprepdb6 pacemakerd: info: crm_xml_cleanup: Cleaning up memory from libxml2 Jan 14 10:57:56 [3920] nbgprepdb6 lrmd: info: log_finished: finished - rsc:pgsql action:notify call_id:178 pid:14200 exit-code:0 exec-time:158ms queue-time:0ms Jan 14 10:57:56 [3923] nbgprepdb6 crmd: notice: process_lrm_event: LRM operation pgsql_notify_0 (call=178, rc=0, cib-update=0, confirmed=true) ok Jan 14 10:57:56 [3923] nbgprepdb6 crmd: info: do_lrm_rsc_op: Performing key=68:4107:0:48387f7e-8de3-4eed-bab6-3db414426226 op=pgsql_notify_0 Jan 14 10:57:56 [3920] nbgprepdb6 lrmd: info: log_execute: executing - rsc:pgsql action:notify call_id:181 Jan 14 10:57:56 [14296] nbgprepdb6 pacemakerd: info: crm_log_init: Changed active directory to /var/lib/heartbeat/cores/root Jan 14 10:57:56 [14296] nbgprepdb6 pacemakerd: info: crm_xml_cleanup: Cleaning up memory from libxml2 Jan 14 10:57:56 [3920] nbgprepdb6 lrmd: info: log_finished: finished - rsc:pgsql action:notify call_id:181 pid:14286 exit-code:0 exec-time:156ms queue-time:1ms Jan 14 10:57:56 [3923] nbgprepdb6 crmd: notice: process_lrm_event: LRM operation pgsql_notify_0 (call=181, rc=0, cib-update=0, confirmed=true) ok Jan 14 10:57:56 [3923] nbgprepdb6 crmd: info: do_lrm_rsc_op: Performing key=5:4107:0:48387f7e-8de3-4eed-bab6-3db414426226 op=pgsql_stop_0 Jan 14 10:57:56 [3920] nbgprepdb6 lrmd: info: log_execute: executing - rsc:pgsql action:stop call_id:184 Jan 14 10:57:56 [14376] nbgprepdb6 pacemakerd: info: crm_log_init: Changed active directory to /var/lib/heartbeat/cores/root Jan 14 10:57:56 [14376] nbgprepdb6 pacemakerd: info: crm_xml_cleanup: Cleaning up memory from libxml2 Jan 14 10:57:56 [3918] nbgprepdb6 cib: info: crm_client_new: Connecting 0x7f3016473e30 for uid=0 gid=0 pid=14449 id=020024bc-0be6-417a-b095-1ff94d69372f Jan 14 10:57:56 [3918] nbgprepdb6 cib: info: cib_process_request: Completed cib_query operation for section nodes: OK (rc=0, origin=local/crm_attribute/2, version=0.36.23) Jan 14 10:57:56 [3918] nbgprepdb6 cib: info: crm_client_destroy: Destroying 0 events Jan 14 10:57:56 [3918] nbgprepdb6 cib: info: crm_client_new: Connecting 0x7f3016473e30 for uid=0 gid=0 pid=14450 id=14985434-fa71-4c61-bd51-8d2fac274a07 Jan 14 10:57:56 [3918] nbgprepdb6 cib: info: cib_process_request: Completed cib_query operation for section nodes: OK (rc=0, origin=local/crm_attribute/2, version=0.36.23) Jan 14 10:57:56 [3918] nbgprepdb6 cib: info: crm_client_destroy: Destroying 0 events pgsql(pgsql)[14366]: 2016/01/14_10:57:56 INFO: PostgreSQL is already stopped. Jan 14 10:57:56 [3918] nbgprepdb6 cib: info: crm_client_new: Connecting 0x7f3016473e30 for uid=0 gid=0 pid=14461 id=77fed886-0cb5-44df-afa5-ffa7e9bfa64d Jan 14 10:57:56 [3918] nbgprepdb6 cib: info: cib_process_request: Completed cib_query operation for section 'all': OK (rc=0, origin=local/crm_mon/2, version=0.36.23) Jan 14 10:57:56 [3918] nbgprepdb6 cib: info: crm_client_destroy: Destroying 0 events Jan 14 10:57:56 [3918] nbgprepdb6 cib: info: crm_client_new: Connecting 0x7f3016473e30 for uid=0 gid=0 pid=14462 id=dd8512a0-4237-47a5-8636-7f6c14036485 Jan 14 10:57:56 [3918] nbgprepdb6 cib: info: cib_process_request: Completed cib_query operation for section nodes: OK (rc=0, origin=local/crm_attribute/2, version=0.36.23) Jan 14 10:57:56 [3918] nbgprepdb6 cib: info: cib_process_request: Completed cib_query operation for section //cib/status//node_state[@id='739251316']//transient_attributes//nvpair[@name='pgsql-status']: OK (rc=0, origin=loc al/crm_attribute/3, version=0.36.23) Jan 14 10:57:56 [3918] nbgprepdb6 cib: info: crm_client_destroy: Destroying 0 events Jan 14 10:57:56 [3920] nbgprepdb6 lrmd: notice: operation_finished: pgsql_stop_0:14366:stderr [ 2016/01/14_10:57:56 INFO: PostgreSQL is already stopped. ] Jan 14 10:57:56 [3920] nbgprepdb6 lrmd: info: log_finished: finished - rsc:pgsql action:stop call_id:184 pid:14366 exit-code:0 exec-time:232ms queue-time:0ms Jan 14 10:57:56 [3923] nbgprepdb6 crmd: notice: process_lrm_event: LRM operation pgsql_stop_0 (call=184, rc=0, cib-update=38, confirmed=true) ok Jan 14 10:57:56 [3918] nbgprepdb6 cib: info: cib_process_request: Forwarding cib_modify operation for section status to master (origin=local/crmd/38) Jan 14 10:57:56 [3918] nbgprepdb6 cib: info: cib_process_request: Completed cib_apply_diff operation for section status: OK (rc=0, origin=nbgprepwitness56/crmd/38, version=0.36.24) Jan 14 10:57:57 [3918] nbgprepdb6 cib: info: cib_process_request: Completed cib_apply_diff operation for section nodes: OK (rc=0, origin=nbgprepwitness56/crm_attribute/4, version=0.37.1) Jan 14 10:57:57 [3918] nbgprepdb6 cib: info: write_cib_contents: Archived previous version as /var/lib/pacemaker/cib/cib-40.raw Jan 14 10:57:57 [3918] nbgprepdb6 cib: info: write_cib_contents: Wrote version 0.37.0 of the CIB to disk (digest: a2c9162c203c21d99ad1367e366d47a0) Jan 14 10:57:57 [3918] nbgprepdb6 cib: info: retrieveCib: Reading cluster configuration from: /var/lib/pacemaker/cib/cib.CwoM0i (digest: /var/lib/pacemaker/cib/cib.7lqvLW) Jan 14 10:58:02 [3918] nbgprepdb6 cib: info: cib_process_request: Completed cib_apply_diff operation for section nodes: OK (rc=0, origin=nbgprepwitness56/crm_attribute/4, version=0.38.1) Jan 14 10:58:02 [3918] nbgprepdb6 cib: info: write_cib_contents: Archived previous version as /var/lib/pacemaker/cib/cib-41.raw Jan 14 10:58:02 [3918] nbgprepdb6 cib: info: write_cib_contents: Wrote version 0.38.0 of the CIB to disk (digest: f035641a5f8a33bc8907a0f852cc607a) Jan 14 10:58:02 [3918] nbgprepdb6 cib: info: retrieveCib: Reading cluster configuration from: /var/lib/pacemaker/cib/cib.YbLKCu (digest: /var/lib/pacemaker/cib/cib.1hLESj) Jan 14 10:58:02 [3918] nbgprepdb6 cib: info: cib_process_request: Completed cib_query operation for section //cib/status//node_state[@id='739251316']//transient_attributes//nvpair[@name='master-pgsql']: OK (rc=0, origin=local/attrd/135, version=0.38.1) Jan 14 10:58:02 [3918] nbgprepdb6 cib: info: cib_process_request: Forwarding cib_modify operation for section status to master (origin=local/attrd/136) Jan 14 10:58:02 [3918] nbgprepdb6 cib: info: cib_process_request: Completed cib_apply_diff operation for section status: OK (rc=0, origin=nbgprepwitness56/attrd/40, version=0.38.2) Jan 14 10:58:02 [3918] nbgprepdb6 cib: info: cib_process_request: Completed cib_query operation for section //cib/status//node_state[@id='739251316']//transient_attributes//nvpair[@name='pgsql-status']: OK (rc=0, origin=local/attrd/137, version=0.38.2) Jan 14 10:58:02 [3918] nbgprepdb6 cib: info: cib_process_request: Forwarding cib_modify operation for section status to master (origin=local/attrd/138) Jan 14 10:58:02 [3918] nbgprepdb6 cib: info: cib_process_request: Completed cib_apply_diff operation for section status: OK (rc=0, origin=nbgprepwitness56/attrd/42, version=0.38.3) Jan 14 10:58:02 [3918] nbgprepdb6 cib: info: cib_process_request: Completed cib_apply_diff operation for section status: OK (rc=0, origin=nbgprepwitness56/crmd/24, version=0.38.4) Jan 14 10:58:02 [3918] nbgprepdb6 cib: info: cib_process_request: Completed cib_apply_diff operation for section status: OK (rc=0, origin=nbgprepwitness56/crmd/25, version=0.38.5) Jan 14 10:58:02 [3918] nbgprepdb6 cib: info: cib_process_request: Completed cib_apply_diff operation for section status: OK (rc=0, origin=nbgprepwitness56/crmd/26, version=0.38.6) Jan 14 10:58:03 [3918] nbgprepdb6 cib: info: cib_process_request: Completed cib_apply_diff operation for section status: OK (rc=0, origin=nbgprepwitness56/crmd/27, version=0.38.7) Jan 14 10:58:03 [3918] nbgprepdb6 cib: info: cib_process_request: Completed cib_apply_diff operation for section status: OK (rc=0, origin=nbgprepwitness56/crmd/28, version=0.38.8) Jan 14 10:58:03 [3918] nbgprepdb6 cib: info: cib_process_request: Completed cib_apply_diff operation for section status: OK (rc=0, origin=nbgprepwitness56/crmd/29, version=0.38.9) Jan 14 10:58:03 [3918] nbgprepdb6 cib: info: cib_process_request: Completed cib_apply_diff operation for section status: OK (rc=0, origin=nbgprepwitness56/crmd/30, version=0.38.10) Jan 14 10:58:03 [3918] nbgprepdb6 cib: info: cib_process_request: Completed cib_apply_diff operation for section status: OK (rc=0, origin=nbgprepwitness56/crmd/31, version=0.38.11) Jan 14 10:59:59 [3918] nbgprepdb6 cib: info: crm_client_new: Connecting 0x7f30163ffba0 for uid=0 gid=0 pid=14811 id=f33912d5-d6e8-44f5-8c6c-683bd3822873 Jan 14 10:59:59 [3918] nbgprepdb6 cib: info: cib_process_request: Completed cib_query operation for section 'all': OK (rc=0, origin=local/crm_mon/2, version=0.38.11) Jan 14 10:59:59 [3918] nbgprepdb6 cib: info: crm_client_destroy: Destroying 0 events Jan 14 11:02:57 [3918] nbgprepdb6 cib: info: crm_client_new: Connecting 0x7f30163ffba0 for uid=0 gid=0 pid=15181 id=0c09cfb9-f627-4c1c-a5e6-7ae9a3cd9fdc Jan 14 11:02:57 [3918] nbgprepdb6 cib: info: cib_process_request: Completed cib_query operation for section 'all': OK (rc=0, origin=local/crm_mon/2, version=0.38.11) Jan 14 11:03:00 [3918] nbgprepdb6 cib: info: crm_client_destroy: Destroying 0 events Jan 14 11:04:05 [3918] nbgprepdb6 cib: info: crm_client_new: Connecting 0x7f30163ffba0 for uid=0 gid=0 pid=15420 id=55c2aded-c7e5-4bc1-a139-92c55621ae0a Jan 14 11:04:05 [3918] nbgprepdb6 cib: info: cib_process_request: Completed cib_query operation for section 'all': OK (rc=0, origin=local/crm_mon/2, version=0.38.11) Jan 14 11:04:05 [3918] nbgprepdb6 cib: info: crm_client_destroy: Destroying 0 events Jan 14 11:08:10 [3918] nbgprepdb6 cib: info: crm_client_new: Connecting 0x7f30163ffba0 for uid=0 gid=0 pid=16269 id=4a35f8d5-e462-467f-a6ab-c8a9ae55bc9e Jan 14 11:08:10 [3918] nbgprepdb6 cib: info: cib_process_request: Completed cib_query operation for section 'all': OK (rc=0, origin=local/crm_mon/2, version=0.38.11) Jan 14 11:08:10 [3918] nbgprepdb6 cib: info: crm_client_destroy: Destroying 0 events Jan 14 11:11:10 [3918] nbgprepdb6 cib: info: crm_client_new: Connecting 0x7f30163ffba0 for uid=0 gid=0 pid=16860 id=80623f76-3b3e-4038-9186-8bf89345101b Jan 14 11:11:10 [3918] nbgprepdb6 cib: info: cib_process_request: Completed cib_query operation for section 'all': OK (rc=0, origin=local/crm_mon/2, version=0.38.11) Jan 14 11:11:41 [3918] nbgprepdb6 cib: info: crm_client_destroy: Destroying 0 events Jan 14 11:12:10 [3916] nbgprepdb6 pacemakerd: info: crm_signal_dispatch: Invoking handler for signal 15: Terminated Jan 14 11:12:10 [3916] nbgprepdb6 pacemakerd: notice: pcmk_shutdown_worker: Shuting down Pacemaker Jan 14 11:12:10 [3916] nbgprepdb6 pacemakerd: notice: stop_child: Stopping crmd: Sent -15 to process 3923 Jan 14 11:12:10 [3923] nbgprepdb6 crmd: info: crm_signal_dispatch: Invoking handler for signal 15: Terminated Jan 14 11:12:10 [3923] nbgprepdb6 crmd: notice: crm_shutdown: Requesting shutdown, upper limit is 1200000ms Jan 14 11:12:10 [3923] nbgprepdb6 crmd: info: do_shutdown_req: Sending shutdown request to nbgprepwitness56 Jan 14 11:12:10 [3921] nbgprepdb6 attrd: notice: attrd_cs_dispatch: Update relayed from nbgprepwitness56 Jan 14 11:12:10 [3921] nbgprepdb6 attrd: notice: attrd_trigger_update: Sending flush op to all hosts for: shutdown (1452766330) Jan 14 11:12:10 [3918] nbgprepdb6 cib: info: cib_process_request: Completed cib_query operation for section //cib/status//node_state[@id='739251316']//transient_attributes//nvpair[@name='shutdown']: No such device or address (rc=-6, origin=local/attrd/139, version=0.38.11)