Hi,<br><br>I have 3 node cluster where Pacemaker decides sometimes , happend twice today, to restart the resource(pbx_01 and pbx_02) without any obvious reasons. The log simple doesn't say why. These 2 resounces use different test LSB scripts which basically do nothing, I just have them to test my cluster conf. I read the log and I simple can't explain the behavior.<br>
When I used the ocf:heartbeat:Dummy I don't remember seeing that behavior.<br><br>All the related info are below<br><br><br><br>On DC where node resources running<br>08:30:50 cib: [3469]: info: cib_stats: Processed 50 operations (2800.00us average, 0% utilization) in the last 10min<br>
08:36:09 heartbeat: [3384]: WARN: Late heartbeat: Node node-02: interval 6470 ms<br>08:38:27 crmd: [3473]: info: crm_timer_popped: PEngine Recheck Timer (I_PE_CALC) just popped!<br>08:38:27 crmd: [3473]: info: do_state_transition: State transition S_IDLE -> S_POLICY_ENGINE [ input=I_PE_CALC cause=C_TIMER_POPPED origin=crm_timer_popped ]<br>
08:38:27 crmd: [3473]: info: do_state_transition: Progressed to state S_POLICY_ENGINE after C_TIMER_POPPED<br>08:38:27 crmd: [3473]: info: do_state_transition: All 3 cluster nodes are eligible to run resources.<br>08:38:27 crmd: [3473]: info: do_pe_invoke: Query 192: Requesting the current CIB: S_POLICY_ENGINE<br>
08:38:27 pengine: [3979]: info: unpack_config: Node scores: 'red' = -INFINITY, 'yellow' = 0, 'green' = 0<br>08:38:27 pengine: [3979]: info: determine_online_status: Node node-02 is online<br>08:38:27 crmd: [3473]: info: do_pe_invoke_callback: Invoking the PE: query=192, ref=pe_calc-dc-1285915107-259, seq=3, quorate=1<br>
08:38:27 pengine: [3979]: info: determine_online_status: Node node-03 is online<br>08:38:27 crmd: [3473]: info: do_state_transition: State transition S_POLICY_ENGINE -> S_TRANSITION_ENGINE [ input=I_PE_SUCCESS cause=C_IPC_MESSAGE origin=handle_response ]<br>
08:38:27 pengine: [3979]: info: determine_online_status: Node node-01 is online<br>08:38:27 crmd: [3473]: info: unpack_graph: Unpacked transition 21: 19 actions in 19 synapses<br>08:38:27 pengine: [3979]: info: find_clone: Internally renamed drbd_02:0 on node-01 to drbd_02:2 (ORPHAN)<br>
08:38:27 crmd: [3473]: info: do_te_invoke: Processing graph 21 (ref=pe_calc-dc-1285915107-259) derived from /var/lib/pengine/pe-input-1453.bz2<br>08:38:27 pengine: [3979]: notice: group_print:  Resource Group: pbx_service_02<br>
08:38:27 crmd: [3473]: info: te_pseudo_action: Pseudo action 27 fired and confirmed<br>08:38:27 pengine: [3979]: notice: native_print:      ip_02      (ocf::heartbeat:IPaddr2):       Started node-02<br>08:38:27 crmd: [3473]: info: te_rsc_command: Initiating action 10: stop pbx_02_stop_0 on node-02<br>
08:38:27 pengine: [3979]: notice: native_print:      fs_02      (ocf::heartbeat:Filesystem):    Started node-02<br>08:38:27 crmd: [3473]: info: te_pseudo_action: Pseudo action 67 fired and confirmed<br>08:38:27 pengine: [3979]: notice: native_print:      pbx_02     (lsb:test-02):  Started node-02<br>
08:38:27 crmd: [3473]: info: te_rsc_command: Initiating action 13: stop pbx_01_stop_0 on node-01<br>08:38:27 pengine: [3979]: notice: clone_print:  Master/Slave Set: ms-drbd_02<br>08:38:27 pengine: [3979]: notice: short_print:      Masters: [ node-02 ]<br>
08:38:27 pengine: [3979]: notice: short_print:      Slaves: [ node-03 ]<br>08:38:27 pengine: [3979]: notice: group_print:  Resource Group: pbx_service_01<br>08:38:27 pengine: [3979]: notice: native_print:      ip_01      (ocf::heartbeat:IPaddr2):       Started node-01<br>
08:38:27 pengine: [3979]: notice: native_print:      fs_01      (ocf::heartbeat:Filesystem):    Started node-01<br>08:38:27 pengine: [3979]: notice: native_print:      pbx_01     (lsb:test-01):  Started node-01<br>08:38:27 pengine: [3979]: notice: clone_print:  Master/Slave Set: ms-drbd_01<br>
08:38:27 pengine: [3979]: notice: short_print:      Masters: [ node-01 ]<br>08:38:27 pengine: [3979]: notice: short_print:      Slaves: [ node-03 ]<br>08:38:27 pengine: [3979]: notice: check_rsc_parameters: Forcing restart of pbx_02 on node-02, provider changed: heartbeat -> <null><br>
08:38:27 pengine: [3979]: notice: DeleteRsc: Removing pbx_02 from node-02<br>08:38:27 pengine: [3979]: notice: check_rsc_parameters: Forcing restart of pbx_01 on node-01, provider changed: heartbeat -> <null><br>
08:38:27 pengine: [3979]: notice: DeleteRsc: Removing pbx_01 from node-01<br>08:38:27 pengine: [3979]: info: master_color: Promoting drbd_02:0 (Master node-02)<br>08:38:27 pengine: [3979]: info: master_color: ms-drbd_02: Promoted 1 instances of a possible 1 to master<br>
08:38:27 pengine: [3979]: info: master_color: Promoting drbd_02:0 (Master node-02)<br>08:38:27 pengine: [3979]: info: master_color: ms-drbd_02: Promoted 1 instances of a possible 1 to master<br>08:38:27 pengine: [3979]: info: master_color: Promoting drbd_01:0 (Master node-01)<br>
08:38:27 pengine: [3979]: info: master_color: ms-drbd_01: Promoted 1 instances of a possible 1 to master<br>08:38:27 pengine: [3979]: info: master_color: Promoting drbd_01:0 (Master node-01)<br>08:38:27 pengine: [3979]: info: master_color: ms-drbd_01: Promoted 1 instances of a possible 1 to master<br>
08:38:27 pengine: [3979]: notice: RecurringOp:  Start recurring monitor (20s) for pbx_02 on node-02<br>08:38:27 pengine: [3979]: ERROR: create_notification_boundaries: Creating boundaries for ms-drbd_02<br>08:38:27 pengine: [3979]: ERROR: create_notification_boundaries: Creating boundaries for ms-drbd_02<br>
08:38:27 pengine: [3979]: ERROR: create_notification_boundaries: Creating boundaries for ms-drbd_02<br>08:38:27 pengine: [3979]: ERROR: create_notification_boundaries: Creating boundaries for ms-drbd_02<br>08:38:27 pengine: [3979]: notice: RecurringOp:  Start recurring monitor (20s) for pbx_01 on node-01<br>
08:38:27 pengine: [3979]: ERROR: create_notification_boundaries: Creating boundaries for ms-drbd_01<br>08:38:27 pengine: [3979]: ERROR: create_notification_boundaries: Creating boundaries for ms-drbd_01<br>08:38:27 pengine: [3979]: ERROR: create_notification_boundaries: Creating boundaries for ms-drbd_01<br>
08:38:27 pengine: [3979]: ERROR: create_notification_boundaries: Creating boundaries for ms-drbd_01<br>08:38:27 pengine: [3979]: notice: LogActions: Leave resource ip_02      (Started node-02)<br>08:38:27 pengine: [3979]: notice: LogActions: Leave resource fs_02      (Started node-02)<br>
08:38:27 pengine: [3979]: notice: LogActions: Restart resource pbx_02   (Started node-02)<br>08:38:27 pengine: [3979]: notice: LogActions: Leave resource drbd_02:0  (Master node-02)<br>08:38:27 pengine: [3979]: notice: LogActions: Leave resource drbd_02:1  (Slave node-03)<br>
08:38:27 pengine: [3979]: notice: LogActions: Leave resource ip_01      (Started node-01)<br>08:38:27 pengine: [3979]: notice: LogActions: Leave resource fs_01      (Started node-01)<br>08:38:27 pengine: [3979]: notice: LogActions: Restart resource pbx_01   (Started node-01)<br>
08:38:27 pengine: [3979]: notice: LogActions: Leave resource drbd_01:0  (Master node-01)<br>08:38:27 pengine: [3979]: notice: LogActions: Leave resource drbd_01:1  (Slave node-03)<br>08:38:27 pengine: [3979]: info: process_pe_message: Transition 21: PEngine Input stored in: /var/lib/pengine/pe-input-1453.bz2<br>
08:38:28 crmd: [3473]: info: match_graph_event: Action pbx_01_stop_0 (13) confirmed on node-01 (rc=0)<br>08:38:28 crmd: [3473]: info: te_pseudo_action: Pseudo action 68 fired and confirmed<br>08:38:28 crmd: [3473]: info: te_rsc_command: Initiating action 14: delete pbx_01_delete_0 on node-01<br>
08:38:28 crmd: [3473]: info: te_pseudo_action: Pseudo action 65 fired and confirmed<br>08:38:29 crmd: [3473]: info: match_graph_event: Action pbx_02_stop_0 (10) confirmed on node-02 (rc=0)<br>08:38:29 crmd: [3473]: info: te_pseudo_action: Pseudo action 28 fired and confirmed<br>
08:38:29 crmd: [3473]: info: te_rsc_command: Initiating action 11: delete pbx_02_delete_0 on node-02<br>08:38:29 crmd: [3473]: info: te_pseudo_action: Pseudo action 9 fired and confirmed<br>08:38:29 crmd: [3473]: info: te_pseudo_action: Pseudo action 25 fired and confirmed<br>
08:38:31 crmd: [3473]: info: process_te_message: Processing (N)ACK lrm_invoke-lrmd-1285915110-15 from node-01<br>08:38:31 crmd: [3473]: info: match_graph_event: Action pbx_01_delete_0 (14) confirmed on node-01 (rc=0)<br>08:38:31 crmd: [3473]: info: process_te_message: Processing (N)ACK lrm_invoke-lrmd-1285915111-16 from node-02<br>
08:38:31 crmd: [3473]: info: match_graph_event: Action pbx_02_delete_0 (11) confirmed on node-02 (rc=0)<br>08:38:31 crmd: [3473]: info: te_rsc_command: Initiating action 24: start pbx_02_start_0 on node-02<br>08:38:31 crmd: [3473]: info: te_rsc_command: Initiating action 64: start pbx_01_start_0 on node-01<br>
08:38:31 crmd: [3473]: info: te_crm_command: Executing crm-event (12): lrm_refresh on node-02<br>08:38:31 crmd: [3473]: info: te_crm_command: Executing crm-event (15): lrm_refresh on node-01<br>08:38:34 crmd: [3473]: info: match_graph_event: Action pbx_02_start_0 (24) confirmed on node-02 (rc=0)<br>
08:38:34 crmd: [3473]: info: te_pseudo_action: Pseudo action 26 fired and confirmed<br>08:38:34 crmd: [3473]: info: te_rsc_command: Initiating action 3: monitor pbx_02_monitor_20000 on node-02<br>08:38:34 crmd: [3473]: info: match_graph_event: Action pbx_01_start_0 (64) confirmed on node-01 (rc=0)<br>
08:38:34 crmd: [3473]: info: te_pseudo_action: Pseudo action 66 fired and confirmed<br>08:38:34 crmd: [3473]: info: te_rsc_command: Initiating action 8: monitor pbx_01_monitor_20000 on node-01<br>08:38:37 crmd: [3473]: info: match_graph_event: Action pbx_01_monitor_20000 (8) confirmed on node-01 (rc=0)<br>
08:38:37 crmd: [3473]: info: match_graph_event: Action pbx_02_monitor_20000 (3) confirmed on node-02 (rc=0)<br>08:38:37 crmd: [3473]: info: run_graph: ====================================================<br>08:38:37 crmd: [3473]: notice: run_graph: Transition 21 (Complete=19, Pending=0, Fired=0, Skipped=0, Incomplete=0, Source=/var/lib/pengine/pe-input-1453.bz2): Complete<br>
08:38:37 crmd: [3473]: info: te_graph_trigger: Transition 21 is now complete<br>08:38:37 crmd: [3473]: info: notify_crmd: Transition 21 status: done - <null><br>08:38:37 crmd: [3473]: info: do_state_transition: State transition S_TRANSITION_ENGINE -> S_IDLE [ input=I_TE_SUCCESS cause=C_FSA_INTERNAL origin=notify_crmd ]<br>
08:38:37 crmd: [3473]: info: do_state_transition: Starting PEngine Recheck Timer<br>08:40:51 cib: [3469]: info: cib_stats: Processed 30 operations (1333.00us average, 0% utilization) in the last 10min<br><br>08:50:52 cib: [3469]: info: cib_stats: Processed 22 operations (0.00us average, 0% utilization) in the last 10min<br>
08:53:38 crmd: [3473]: info: crm_timer_popped: PEngine Recheck Timer (I_PE_CALC) just popped!<br>08:53:38 crmd: [3473]: info: do_state_transition: State transition S_IDLE -> S_POLICY_ENGINE [ input=I_PE_CALC cause=C_TIMER_POPPED origin=crm_timer_popped ]<br>
08:53:38 crmd: [3473]: info: do_state_transition: Progressed to state S_POLICY_ENGINE after C_TIMER_POPPED<br>08:53:38 crmd: [3473]: info: do_state_transition: All 3 cluster nodes are eligible to run resources.<br>08:53:38 crmd: [3473]: info: do_pe_invoke: Query 193: Requesting the current CIB: S_POLICY_ENGINE<br>
08:53:38 crmd: [3473]: info: do_pe_invoke_callback: Invoking the PE: query=193, ref=pe_calc-dc-1285916018-270, seq=3, quorate=1<br>08:53:38 pengine: [3979]: info: unpack_config: Node scores: 'red' = -INFINITY, 'yellow' = 0, 'green' = 0<br>
08:53:38 pengine: [3979]: info: determine_online_status: Node node-02 is online<br>08:53:38 pengine: [3979]: info: determine_online_status: Node node-03 is online<br>08:53:38 pengine: [3979]: info: determine_online_status: Node node-01 is online<br>
08:53:38 pengine: [3979]: info: find_clone: Internally renamed drbd_02:0 on node-01 to drbd_02:2 (ORPHAN)<br>08:53:38 pengine: [3979]: notice: group_print:  Resource Group: pbx_service_02<br>08:53:38 pengine: [3979]: notice: native_print:      ip_02      (ocf::heartbeat:IPaddr2):       Started node-02<br>
08:53:38 pengine: [3979]: notice: native_print:      fs_02      (ocf::heartbeat:Filesystem):    Started node-02<br>08:53:38 pengine: [3979]: notice: native_print:      pbx_02     (lsb:test-02):  Started node-02<br>08:53:38 pengine: [3979]: notice: clone_print:  Master/Slave Set: ms-drbd_02<br>
08:53:38 pengine: [3979]: notice: short_print:      Masters: [ node-02 ]<br>08:53:38 pengine: [3979]: notice: short_print:      Slaves: [ node-03 ]<br>08:53:38 pengine: [3979]: notice: group_print:  Resource Group: pbx_service_01<br>
08:53:38 pengine: [3979]: notice: native_print:      ip_01      (ocf::heartbeat:IPaddr2):       Started node-01<br>08:53:38 pengine: [3979]: notice: native_print:      fs_01      (ocf::heartbeat:Filesystem):    Started node-01<br>
08:53:38 pengine: [3979]: notice: native_print:      pbx_01     (lsb:test-01):  Started node-01<br>08:53:38 pengine: [3979]: notice: clone_print:  Master/Slave Set: ms-drbd_01<br>08:53:38 pengine: [3979]: notice: short_print:      Masters: [ node-01 ]<br>
08:53:38 pengine: [3979]: notice: short_print:      Slaves: [ node-03 ]<br>08:53:38 pengine: [3979]: notice: check_rsc_parameters: Forcing restart of pbx_02 on node-02, provider changed: heartbeat -> <null><br>08:53:38 pengine: [3979]: notice: DeleteRsc: Removing pbx_02 from node-02<br>
08:53:38 pengine: [3979]: notice: check_rsc_parameters: Forcing restart of pbx_01 on node-01, provider changed: heartbeat -> <null><br>08:53:38 pengine: [3979]: notice: DeleteRsc: Removing pbx_01 from node-01<br>
08:53:38 pengine: [3979]: info: master_color: Promoting drbd_02:0 (Master node-02)<br>08:53:38 pengine: [3979]: info: master_color: ms-drbd_02: Promoted 1 instances of a possible 1 to master<br>08:53:38 pengine: [3979]: info: master_color: Promoting drbd_02:0 (Master node-02)<br>
08:53:38 pengine: [3979]: info: master_color: ms-drbd_02: Promoted 1 instances of a possible 1 to master<br>08:53:38 pengine: [3979]: info: master_color: Promoting drbd_01:0 (Master node-01)<br>08:53:38 pengine: [3979]: info: master_color: ms-drbd_01: Promoted 1 instances of a possible 1 to master<br>
08:53:38 pengine: [3979]: info: master_color: Promoting drbd_01:0 (Master node-01)<br>08:53:38 pengine: [3979]: info: master_color: ms-drbd_01: Promoted 1 instances of a possible 1 to master<br>08:53:38 pengine: [3979]: notice: RecurringOp:  Start recurring monitor (20s) for pbx_02 on node-02<br>
08:53:38 pengine: [3979]: ERROR: create_notification_boundaries: Creating boundaries for ms-drbd_02<br>08:53:38 pengine: [3979]: ERROR: create_notification_boundaries: Creating boundaries for ms-drbd_02<br>08:53:38 pengine: [3979]: ERROR: create_notification_boundaries: Creating boundaries for ms-drbd_02<br>
08:53:38 pengine: [3979]: ERROR: create_notification_boundaries: Creating boundaries for ms-drbd_02<br>08:53:38 pengine: [3979]: notice: RecurringOp:  Start recurring monitor (20s) for pbx_01 on node-01<br>08:53:38 pengine: [3979]: ERROR: create_notification_boundaries: Creating boundaries for ms-drbd_01<br>
08:53:38 pengine: [3979]: ERROR: create_notification_boundaries: Creating boundaries for ms-drbd_01<br>08:53:38 pengine: [3979]: ERROR: create_notification_boundaries: Creating boundaries for ms-drbd_01<br>08:53:38 pengine: [3979]: ERROR: create_notification_boundaries: Creating boundaries for ms-drbd_01<br>
08:53:38 pengine: [3979]: notice: LogActions: Leave resource ip_02      (Started node-02)<br>08:53:38 pengine: [3979]: notice: LogActions: Leave resource fs_02      (Started node-02)<br>08:53:38 pengine: [3979]: notice: LogActions: Restart resource pbx_02   (Started node-02)<br>
08:53:38 pengine: [3979]: notice: LogActions: Leave resource drbd_02:0  (Master node-02)<br>08:53:38 pengine: [3979]: notice: LogActions: Leave resource drbd_02:1  (Slave node-03)<br>08:53:38 pengine: [3979]: notice: LogActions: Leave resource ip_01      (Started node-01)<br>
08:53:38 pengine: [3979]: notice: LogActions: Leave resource fs_01      (Started node-01)<br>08:53:38 pengine: [3979]: notice: LogActions: Restart resource pbx_01   (Started node-01)<br>08:53:38 pengine: [3979]: notice: LogActions: Leave resource drbd_01:0  (Master node-01)<br>
08:53:38 pengine: [3979]: notice: LogActions: Leave resource drbd_01:1  (Slave node-03)<br>08:53:38 crmd: [3473]: info: do_state_transition: State transition S_POLICY_ENGINE -> S_TRANSITION_ENGINE [ input=I_PE_SUCCESS cause=C_IPC_MESSAGE origin=handle_response ]<br>
08:53:38 crmd: [3473]: info: unpack_graph: Unpacked transition 22: 19 actions in 19 synapses<br>08:53:38 crmd: [3473]: info: do_te_invoke: Processing graph 22 (ref=pe_calc-dc-1285916018-270) derived from /var/lib/pengine/pe-input-1454.bz2<br>
08:53:38 crmd: [3473]: info: te_pseudo_action: Pseudo action 27 fired and confirmed<br>08:53:38 crmd: [3473]: info: te_rsc_command: Initiating action 10: stop pbx_02_stop_0 on node-02<br>08:53:38 crmd: [3473]: info: te_pseudo_action: Pseudo action 67 fired and confirmed<br>
08:53:38 crmd: [3473]: info: te_rsc_command: Initiating action 13: stop pbx_01_stop_0 on node-01<br>08:53:38 pengine: [3979]: info: process_pe_message: Transition 22: PEngine Input stored in: /var/lib/pengine/pe-input-1454.bz2<br>
08:53:40 crmd: [3473]: info: match_graph_event: Action pbx_02_stop_0 (10) confirmed on node-02 (rc=0)<br>08:53:40 crmd: [3473]: info: te_pseudo_action: Pseudo action 28 fired and confirmed<br>08:53:40 crmd: [3473]: info: te_rsc_command: Initiating action 11: delete pbx_02_delete_0 on node-02<br>
08:53:40 crmd: [3473]: info: te_pseudo_action: Pseudo action 25 fired and confirmed<br>08:53:40 crmd: [3473]: info: match_graph_event: Action pbx_01_stop_0 (13) confirmed on node-01 (rc=0)<br>08:53:40 crmd: [3473]: info: te_pseudo_action: Pseudo action 68 fired and confirmed<br>
08:53:40 crmd: [3473]: info: te_rsc_command: Initiating action 14: delete pbx_01_delete_0 on node-01<br>08:53:40 crmd: [3473]: info: te_pseudo_action: Pseudo action 9 fired and confirmed<br>08:53:40 crmd: [3473]: info: te_pseudo_action: Pseudo action 65 fired and confirmed<br>
08:53:42 crmd: [3473]: info: process_te_message: Processing (N)ACK lrm_invoke-lrmd-1285916022-17 from node-02<br>08:53:42 crmd: [3473]: info: match_graph_event: Action pbx_02_delete_0 (11) confirmed on node-02 (rc=0)<br>08:53:42 crmd: [3473]: info: te_rsc_command: Initiating action 24: start pbx_02_start_0 on node-02<br>
08:53:42 crmd: [3473]: info: te_crm_command: Executing crm-event (12): lrm_refresh on node-02<br>08:53:44 crmd: [3473]: info: process_te_message: Processing (N)ACK lrm_invoke-lrmd-1285916022-16 from node-01<br>08:53:44 crmd: [3473]: info: match_graph_event: Action pbx_01_delete_0 (14) confirmed on node-01 (rc=0)<br>
08:53:44 crmd: [3473]: info: te_rsc_command: Initiating action 64: start pbx_01_start_0 on node-01<br>08:53:44 crmd: [3473]: info: te_crm_command: Executing crm-event (15): lrm_refresh on node-01<br>08:53:47 crmd: [3473]: info: match_graph_event: Action pbx_02_start_0 (24) confirmed on node-02 (rc=0)<br>
08:53:47 crmd: [3473]: info: te_pseudo_action: Pseudo action 26 fired and confirmed<br>08:53:47 crmd: [3473]: info: te_rsc_command: Initiating action 3: monitor pbx_02_monitor_20000 on node-02<br>08:53:48 crmd: [3473]: info: match_graph_event: Action pbx_01_start_0 (64) confirmed on node-01 (rc=0)<br>
08:53:48 crmd: [3473]: info: te_pseudo_action: Pseudo action 66 fired and confirmed<br>08:53:48 crmd: [3473]: info: te_rsc_command: Initiating action 8: monitor pbx_01_monitor_20000 on node-01<br>08:53:48 crmd: [3473]: info: match_graph_event: Action pbx_02_monitor_20000 (3) confirmed on node-02 (rc=0)<br>
08:53:50 crmd: [3473]: info: match_graph_event: Action pbx_01_monitor_20000 (8) confirmed on node-01 (rc=0)<br>08:53:50 crmd: [3473]: info: run_graph: ====================================================<br>08:53:50 crmd: [3473]: notice: run_graph: Transition 22 (Complete=19, Pending=0, Fired=0, Skipped=0, Incomplete=0, Source=/var/lib/pengine/pe-input-1454.bz2): Complete<br>
08:53:50 crmd: [3473]: info: te_graph_trigger: Transition 22 is now complete<br>08:53:50 crmd: [3473]: info: notify_crmd: Transition 22 status: done - <null><br>08:53:50 crmd: [3473]: info: do_state_transition: State transition S_TRANSITION_ENGINE -> S_IDLE [ input=I_TE_SUCCESS cause=C_FSA_INTERNAL origin=notify_crmd ]<br>
08:53:50 crmd: [3473]: info: do_state_transition: Starting PEngine Recheck Timer<br><br><br>On node-01 where pbx_service_01 resource group where running<br>Oct 01 08:38:28 node-01 lrmd: [3558]: info: cancel_op: operation monitor[45] on lsb::test-01::pbx_01 for client 3561, its parameters: CRM_meta_interval=[20000] CRM_meta_timeout=[20000] crm_feature_set=[3.0.1] CRM_meta_name=[monitor]  cancelled<br>
Oct 01 08:38:28 node-01 crmd: [3561]: info: do_lrm_rsc_op: Performing key=13:21:0:f80b1e20-63f0-4b00-bd04-f10c2bd10046 op=pbx_01_stop_0 )<br>Oct 01 08:38:28 node-01 lrmd: [3558]: info: rsc:pbx_01:46: stop<br>Oct 01 08:38:28 node-01 crmd: [3561]: info: process_lrm_event: LRM operation pbx_01_monitor_20000 (call=45, status=1, cib-update=0, confirmed=true) Cancelled<br>
Oct 01 08:38:28 node-01 lrmd: [19763]: WARN: For LSB init script, no additional parameters are needed.<br>Oct 01 08:38:28 node-01 lrmd: [3558]: info: RA output: (pbx_01:stop:stdout) Stopping test-01: [  OK  ]<br>Oct 01 08:38:28 node-01 crmd: [3561]: info: process_lrm_event: LRM operation pbx_01_stop_0 (call=46, rc=0, cib-update=61, confirmed=true) ok<br>
Oct 01 08:38:30 node-01 crmd: [3561]: info: do_lrm_invoke: Removing resource pbx_01 from the LRM<br>Oct 01 08:38:30 node-01 crmd: [3561]: info: do_lrm_invoke: Resource 'pbx_01' deleted for tengine on (null)<br>Oct 01 08:38:30 node-01 crmd: [3561]: info: notify_deleted: Notifying tengine on node-03 that pbx_01 was deleted<br>
Oct 01 08:38:30 node-01 crmd: [3561]: info: send_direct_ack: ACK'ing resource op pbx_01_delete_0 from 14:21:0:f80b1e20-63f0-4b00-bd04-f10c2bd10046: lrm_invoke-lrmd-1285915110-15<br>Oct 01 08:38:33 node-01 lrmd: [3558]: notice: lrmd_rsc_new(): No lrm_rprovider field in message<br>
Oct 01 08:38:33 node-01 crmd: [3561]: info: do_lrm_rsc_op: Performing key=64:21:0:f80b1e20-63f0-4b00-bd04-f10c2bd10046 op=pbx_01_start_0 )<br>Oct 01 08:38:33 node-01 lrmd: [3558]: info: rsc:pbx_01:47: start<br>Oct 01 08:38:33 node-01 lrmd: [19836]: WARN: For LSB init script, no additional parameters are needed.<br>
Oct 01 08:38:33 node-01 crmd: [3561]: WARN: msg_to_op(1326): failed to get the value of field lrm_opstatus from a ha_msg<br>Oct 01 08:38:33 node-01 crmd: [3561]: info: msg_to_op: Message follows:<br>Oct 01 08:38:33 node-01 crmd: [3561]: info: MSG: Dumping message with 16 fields<br>
Oct 01 08:38:33 node-01 crmd: [3561]: info: MSG[0] : [lrm_t=op]<br>Oct 01 08:38:33 node-01 crmd: [3561]: info: MSG[1] : [lrm_rid=pbx_01]<br>Oct 01 08:38:33 node-01 crmd: [3561]: info: MSG[2] : [lrm_op=start]<br>Oct 01 08:38:33 node-01 crmd: [3561]: info: MSG[3] : [lrm_timeout=60000]<br>
Oct 01 08:38:33 node-01 crmd: [3561]: info: MSG[4] : [lrm_interval=0]<br>Oct 01 08:38:33 node-01 crmd: [3561]: info: MSG[5] : [lrm_delay=0]<br>Oct 01 08:38:33 node-01 crmd: [3561]: info: MSG[6] : [lrm_copyparams=1]<br>Oct 01 08:38:33 node-01 crmd: [3561]: info: MSG[7] : [lrm_t_run=0]<br>
Oct 01 08:38:33 node-01 crmd: [3561]: info: MSG[8] : [lrm_t_rcchange=0]<br>Oct 01 08:38:33 node-01 crmd: [3561]: info: MSG[9] : [lrm_exec_time=0]<br>Oct 01 08:38:33 node-01 crmd: [3561]: info: MSG[10] : [lrm_queue_time=0]<br>
Oct 01 08:38:33 node-01 crmd: [3561]: info: MSG[11] : [lrm_targetrc=-1]<br>Oct 01 08:38:33 node-01 crmd: [3561]: info: MSG[12] : [lrm_app=crmd]<br>Oct 01 08:38:33 node-01 crmd: [3561]: info: MSG[13] : [lrm_userdata=64:21:0:f80b1e20-63f0-4b00-bd04-f10c2bd10046]<br>
Oct 01 08:38:33 node-01 crmd: [3561]: info: MSG[14] : [(2)lrm_param=0x9759508(88 104)]<br>Oct 01 08:38:33 node-01 crmd: [3561]: info: MSG: Dumping message with 3 fields<br>Oct 01 08:38:33 node-01 crmd: [3561]: info: MSG[0] : [CRM_meta_timeout=60000]<br>
Oct 01 08:38:33 node-01 crmd: [3561]: info: MSG[1] : [crm_feature_set=3.0.1]<br>Oct 01 08:38:33 node-01 crmd: [3561]: info: MSG[2] : [CRM_meta_name=start]<br>Oct 01 08:38:33 node-01 crmd: [3561]: info: MSG[15] : [lrm_callid=47]<br>
Oct 01 08:38:33 node-01 crmd: [3561]: info: do_lrm_invoke: Forcing a local LRM refresh<br>Oct 01 08:38:33 node-01 lrmd: [3558]: info: RA output: (pbx_01:start:stdout) Starting test-01:<br>[  OK  ]8:38:33 node-01 lrmd: [3558]: info: RA output: (pbx_01:start:stdout) [  OK  ]<br>
Oct 01 08:38:33 node-01 crmd: [3561]: info: process_lrm_event: LRM operation pbx_01_start_0 (call=47, rc=0, cib-update=63, confirmed=true) ok<br>Oct 01 08:38:36 node-01 crmd: [3561]: info: do_lrm_rsc_op: Performing key=8:21:0:f80b1e20-63f0-4b00-bd04-f10c2bd10046 op=pbx_01_monitor_20000 )<br>
Oct 01 08:38:36 node-01 crmd: [3561]: info: process_lrm_event: LRM operation pbx_01_monitor_20000 (call=48, rc=0, cib-update=64, confirmed=false) ok<br>[root@node-01 ~]# grep 08:53: /var/log/ha-log<br>Sep 29 08:53:02 node-01 lrmd: [3523]: info: rsc:drbd_01:0:112: notify<br>
Sep 29 08:53:02 node-01 crmd: [3526]: info: do_lrm_rsc_op: Performing key=135:45:0:a09c8e82-b4b8-4d01-988a-ff0cb46ea9a0 op=drbd_01:0_notify_0 )<br>Sep 29 08:53:03 node-01 lrmd: [3523]: info: RA output: (drbd_01:0:notify:stdout)<br>
Sep 29 08:53:03 node-01 crmd: [3526]: info: process_lrm_event: LRM operation drbd_01:0_notify_0 (call=112, rc=0, cib-update=147, confirmed=true) ok<br>Sep 29 08:53:05 node-01 lrmd: [3523]: info: rsc:drbd_01:0:113: notify<br>
Sep 29 08:53:05 node-01 crmd: [3526]: info: do_lrm_rsc_op: Performing key=130:45:0:a09c8e82-b4b8-4d01-988a-ff0cb46ea9a0 op=drbd_01:0_notify_0 )<br>Sep 29 08:53:05 node-01 crmd: [3526]: info: process_lrm_event: LRM operation drbd_01:0_notify_0 (call=113, rc=0, cib-update=148, confirmed=true) ok<br>
Sep 29 08:53:07 node-01 lrmd: [3523]: info: rsc:drbd_01:0:114: notify<br>Sep 29 08:53:07 node-01 crmd: [3526]: info: do_lrm_rsc_op: Performing key=131:45:0:a09c8e82-b4b8-4d01-988a-ff0cb46ea9a0 op=drbd_01:0_notify_0 )<br>Sep 29 08:53:07 node-01 lrmd: [3523]: info: RA output: (drbd_01:0:notify:stdout)<br>
Sep 29 08:53:07 node-01 crmd: [3526]: info: process_lrm_event: LRM operation drbd_01:0_notify_0 (call=114, rc=0, cib-update=149, confirmed=true) ok<br>Sep 29 08:53:09 node-01 crmd: [3526]: info: do_lrm_rsc_op: Performing key=68:45:0:a09c8e82-b4b8-4d01-988a-ff0cb46ea9a0 op=drbd_01:0_monitor_30000 )<br>
Sep 29 08:53:09 node-01 crmd: [3526]: info: process_lrm_event: LRM operation drbd_01:0_monitor_30000 (call=115, rc=0, cib-update=150, confirmed=false) ok<br>Sep 29 08:53:43 node-01 cib: [26073]: info: write_cib_contents: Archived previous version as /var/lib/heartbeat/crm/cib-18.raw<br>
Sep 29 08:53:43 node-01 cib: [26073]: info: write_cib_contents: Wrote version 0.581.0 of the CIB to disk (digest: dee87447308900b0a802faf1af419f1d)<br>Sep 29 08:53:43 node-01 cib: [26073]: info: retrieveCib: Reading cluster configuration from: /var/lib/heartbeat/crm/cib.FjyHAJ (digest: /var/lib/heartbeat/crm/cib.xzbgU3)<br>
Sep 29 08:53:52 node-01 lrmd: [3523]: info: cancel_op: operation monitor[115] on ocf::drbd::drbd_01:0 for client 3526, its parameters: CRM_meta_interval=[30000] CRM_meta_notify_stop_resource=[ ] CRM_meta_notify_active_resource=[ ] CRM_meta_notify_slave_resource=[ ] CRM_meta_notify_start_resource=[drbd_01:0 drbd_01:1 ] CRM_meta_notify_active_uname=[ ] CRM_meta_notify_promote_resource=[ ] CRM_meta_notify_stop_uname=[ ] drbd_resource=[drbd_pbx_service_1] CRM_meta_notify_master_uname=[ ] CRM_meta_master_max=[1] CRM_meta_notify_demote_uname=[ ] CRM_meta_notify_mast cancelled<br>
Sep 29 08:53:52 node-01 crmd: [3526]: info: send_direct_ack: ACK'ing resource op drbd_01:0_monitor_30000 from 1:47:0:a09c8e82-b4b8-4d01-988a-ff0cb46ea9a0: lrm_invoke-lrmd-1285743232-34<br>Sep 29 08:53:52 node-01 crmd: [3526]: info: do_lrm_rsc_op: Performing key=134:47:0:a09c8e82-b4b8-4d01-988a-ff0cb46ea9a0 op=drbd_01:0_notify_0 )<br>
Sep 29 08:53:52 node-01 lrmd: [3523]: info: rsc:drbd_01:0:116: notify<br>Sep 29 08:53:52 node-01 crmd: [3526]: info: process_lrm_event: LRM operation drbd_01:0_monitor_30000 (call=115, status=1, cib-update=0, confirmed=true) Cancelled<br>
Sep 29 08:53:52 node-01 crmd: [3526]: info: process_lrm_event: LRM operation drbd_01:0_notify_0 (call=116, rc=0, cib-update=152, confirmed=true) ok<br>Sep 29 08:53:53 node-01 cib: [26171]: info: write_cib_contents: Archived previous version as /var/lib/heartbeat/crm/cib-19.raw<br>
Sep 29 08:53:53 node-01 cib: [26171]: info: write_cib_contents: Wrote version 0.582.0 of the CIB to disk (digest: 963e0701d5049950c8625121228ae7dc)<br>Sep 29 08:53:53 node-01 cib: [26171]: info: retrieveCib: Reading cluster configuration from: /var/lib/heartbeat/crm/cib.AP6vYW (digest: /var/lib/heartbeat/crm/cib.2JZNgI)<br>
Sep 29 08:53:54 node-01 crmd: [3526]: info: do_lrm_rsc_op: Performing key=135:47:0:a09c8e82-b4b8-4d01-988a-ff0cb46ea9a0 op=drbd_01:0_notify_0 )<br>Sep 29 08:53:54 node-01 lrmd: [3523]: info: rsc:drbd_01:0:117: notify<br>Sep 29 08:53:54 node-01 lrmd: [3523]: info: RA output: (drbd_01:0:notify:stdout)<br>
Sep 29 08:53:54 node-01 crmd: [3526]: info: process_lrm_event: LRM operation drbd_01:0_notify_0 (call=117, rc=0, cib-update=153, confirmed=true) ok<br>Sep 29 08:53:56 node-01 lrmd: [3523]: info: rsc:drbd_01:0:118: notify<br>
Sep 29 08:53:56 node-01 crmd: [3526]: info: do_lrm_rsc_op: Performing key=130:47:0:a09c8e82-b4b8-4d01-988a-ff0cb46ea9a0 op=drbd_01:0_notify_0 )<br>Sep 29 08:53:56 node-01 crmd: [3526]: info: process_lrm_event: LRM operation drbd_01:0_notify_0 (call=118, rc=0, cib-update=154, confirmed=true) ok<br>
Sep 29 08:53:57 node-01 lrmd: [3523]: info: rsc:drbd_01:0:119: promote<br>Sep 29 08:53:57 node-01 crmd: [3526]: info: do_lrm_rsc_op: Performing key=68:47:0:a09c8e82-b4b8-4d01-988a-ff0cb46ea9a0 op=drbd_01:0_promote_0 )<br>
Sep 29 08:53:58 node-01 lrmd: [3523]: info: RA output: (drbd_01:0:promote:stdout)<br>Sep 29 08:53:58 node-01 crmd: [3526]: info: process_lrm_event: LRM operation drbd_01:0_promote_0 (call=119, rc=0, cib-update=155, confirmed=true) ok<br>
Oct 01 08:53:39 node-01 lrmd: [3558]: info: cancel_op: operation monitor[48] on lsb::test-01::pbx_01 for client 3561, its parameters: CRM_meta_interval=[20000] CRM_meta_timeout=[20000] crm_feature_set=[3.0.1] CRM_meta_name=[monitor]  cancelled<br>
Oct 01 08:53:39 node-01 crmd: [3561]: info: do_lrm_rsc_op: Performing key=13:22:0:f80b1e20-63f0-4b00-bd04-f10c2bd10046 op=pbx_01_stop_0 )<br>Oct 01 08:53:39 node-01 lrmd: [3558]: info: rsc:pbx_01:49: stop<br>Oct 01 08:53:39 node-01 crmd: [3561]: info: process_lrm_event: LRM operation pbx_01_monitor_20000 (call=48, status=1, cib-update=0, confirmed=true) Cancelled<br>
Oct 01 08:53:39 node-01 lrmd: [32258]: WARN: For LSB init script, no additional parameters are needed.<br>Oct 01 08:53:39 node-01 lrmd: [3558]: info: RA output: (pbx_01:stop:stdout) Stopping test-01: [  OK  ]<br>Oct 01 08:53:39 node-01 crmd: [3561]: info: process_lrm_event: LRM operation pbx_01_stop_0 (call=49, rc=0, cib-update=65, confirmed=true) ok<br>
Oct 01 08:53:42 node-01 crmd: [3561]: info: do_lrm_invoke: Removing resource pbx_01 from the LRM<br>Oct 01 08:53:42 node-01 crmd: [3561]: info: do_lrm_invoke: Resource 'pbx_01' deleted for tengine on (null)<br>Oct 01 08:53:42 node-01 crmd: [3561]: info: notify_deleted: Notifying tengine on node-03 that pbx_01 was deleted<br>
Oct 01 08:53:42 node-01 crmd: [3561]: info: send_direct_ack: ACK'ing resource op pbx_01_delete_0 from 14:22:0:f80b1e20-63f0-4b00-bd04-f10c2bd10046: lrm_invoke-lrmd-1285916022-16<br>Oct 01 08:53:46 node-01 lrmd: [3558]: notice: lrmd_rsc_new(): No lrm_rprovider field in message<br>
Oct 01 08:53:46 node-01 crmd: [3561]: info: do_lrm_rsc_op: Performing key=64:22:0:f80b1e20-63f0-4b00-bd04-f10c2bd10046 op=pbx_01_start_0 )<br>Oct 01 08:53:46 node-01 lrmd: [3558]: info: rsc:pbx_01:50: start<br>Oct 01 08:53:46 node-01 lrmd: [32322]: WARN: For LSB init script, no additional parameters are needed.<br>
[  OK  ]8:53:46 node-01 lrmd: [3558]: info: RA output: (pbx_01:start:stdout) Starting test-01: [  OK  ]<br>Oct 01 08:53:46 node-01 crmd: [3561]: info: do_lrm_invoke: Forcing a local LRM refresh<br>Oct 01 08:53:46 node-01 crmd: [3561]: info: process_lrm_event: LRM operation pbx_01_start_0 (call=50, rc=0, cib-update=67, confirmed=true) ok<br>
Oct 01 08:53:50 node-01 crmd: [3561]: info: do_lrm_rsc_op: Performing key=8:22:0:f80b1e20-63f0-4b00-bd04-f10c2bd10046 op=pbx_01_monitor_20000 )<br>Oct 01 08:53:50 node-01 crmd: [3561]: info: process_lrm_event: LRM operation pbx_01_monitor_20000 (call=51, rc=0, cib-update=68, confirmed=false) ok<br>
<br><br>On node-02 where pbx_service_02 resource group was running<br><br>Oct 01 08:38:29 node-02 lrmd: [3560]: info: cancel_op: operation monitor[51] on lsb::test-02::pbx_02 for client 3563, its parameters: CRM_meta_interval=[20000] CRM_meta_timeout=[20000] crm_feature_set=[3.0.1] CRM_meta_name=[monitor]  cancelled<br>
Oct 01 08:38:29 node-02 crmd: [3563]: info: do_lrm_rsc_op: Performing key=10:21:0:f80b1e20-63f0-4b00-bd04-f10c2bd10046 op=pbx_02_stop_0 )<br>Oct 01 08:38:29 node-02 lrmd: [3560]: info: rsc:pbx_02:52: stop<br>Oct 01 08:38:29 node-02 crmd: [3563]: info: process_lrm_event: LRM operation pbx_02_monitor_20000 (call=51, status=1, cib-update=0, confirmed=true) Cancelled<br>
Oct 01 08:38:29 node-02 lrmd: [9167]: WARN: For LSB init script, no additional parameters are needed.<br>Oct 01 08:38:29 node-02 crmd: [3563]: info: process_lrm_event: LRM operation pbx_02_stop_0 (call=52, rc=0, cib-update=69, confirmed=true) ok<br>
Oct 01 08:38:29 node-02 lrmd: [3560]: info: RA output: (pbx_02:stop:stdout) Stopping test-02: [  OK  ]<br>Oct 01 08:38:31 node-02 crmd: [3563]: info: do_lrm_invoke: Removing resource pbx_02 from the LRM<br>Oct 01 08:38:31 node-02 crmd: [3563]: info: do_lrm_invoke: Resource 'pbx_02' deleted for tengine on (null)<br>
Oct 01 08:38:31 node-02 crmd: [3563]: info: notify_deleted: Notifying tengine on node-03 that pbx_02 was deleted<br>Oct 01 08:38:31 node-02 crmd: [3563]: info: send_direct_ack: ACK'ing resource op pbx_02_delete_0 from 11:21:0:f80b1e20-63f0-4b00-bd04-f10c2bd10046: lrm_invoke-lrmd-1285915111-16<br>
Oct 01 08:38:32 node-02 lrmd: [3560]: notice: lrmd_rsc_new(): No lrm_rprovider field in message<br>Oct 01 08:38:32 node-02 lrmd: [3560]: info: rsc:pbx_02:53: start<br>Oct 01 08:38:32 node-02 crmd: [3563]: info: do_lrm_rsc_op: Performing key=24:21:0:f80b1e20-63f0-4b00-bd04-f10c2bd10046 op=pbx_02_start_0 )<br>
Oct 01 08:38:32 node-02 lrmd: [9238]: WARN: For LSB init script, no additional parameters are needed.<br>Oct 01 08:38:32 node-02 crmd: [3563]: WARN: msg_to_op(1326): failed to get the value of field lrm_opstatus from a ha_msg<br>
Oct 01 08:38:32 node-02 crmd: [3563]: info: msg_to_op: Message follows:<br>Oct 01 08:38:32 node-02 crmd: [3563]: info: MSG: Dumping message with 16 fields<br>Oct 01 08:38:32 node-02 crmd: [3563]: info: MSG[0] : [lrm_t=op]<br>
Oct 01 08:38:32 node-02 crmd: [3563]: info: MSG[1] : [lrm_rid=pbx_02]<br>Oct 01 08:38:32 node-02 crmd: [3563]: info: MSG[2] : [lrm_op=start]<br>Oct 01 08:38:32 node-02 crmd: [3563]: info: MSG[3] : [lrm_timeout=60000]<br>Oct 01 08:38:32 node-02 crmd: [3563]: info: MSG[4] : [lrm_interval=0]<br>
Oct 01 08:38:32 node-02 crmd: [3563]: info: MSG[5] : [lrm_delay=0]<br>Oct 01 08:38:32 node-02 crmd: [3563]: info: MSG[6] : [lrm_copyparams=1]<br>Oct 01 08:38:32 node-02 crmd: [3563]: info: MSG[7] : [lrm_t_run=0]<br>Oct 01 08:38:32 node-02 crmd: [3563]: info: MSG[8] : [lrm_t_rcchange=0]<br>
Oct 01 08:38:32 node-02 crmd: [3563]: info: MSG[9] : [lrm_exec_time=0]<br>Oct 01 08:38:32 node-02 crmd: [3563]: info: MSG[10] : [lrm_queue_time=0]<br>Oct 01 08:38:32 node-02 crmd: [3563]: info: MSG[11] : [lrm_targetrc=-1]<br>
Oct 01 08:38:32 node-02 crmd: [3563]: info: MSG[12] : [lrm_app=crmd]<br>Oct 01 08:38:32 node-02 crmd: [3563]: info: MSG[13] : [lrm_userdata=24:21:0:f80b1e20-63f0-4b00-bd04-f10c2bd10046]<br>Oct 01 08:38:32 node-02 crmd: [3563]: info: MSG[14] : [(2)lrm_param=0x98eacc0(88 104)]<br>
Oct 01 08:38:32 node-02 crmd: [3563]: info: MSG: Dumping message with 3 fields<br>Oct 01 08:38:32 node-02 crmd: [3563]: info: MSG[0] : [CRM_meta_timeout=60000]<br>Oct 01 08:38:32 node-02 crmd: [3563]: info: MSG[1] : [crm_feature_set=3.0.1]<br>
Oct 01 08:38:32 node-02 crmd: [3563]: info: MSG[2] : [CRM_meta_name=start]<br>Oct 01 08:38:32 node-02 crmd: [3563]: info: MSG[15] : [lrm_callid=53]<br>Oct 01 08:38:33 node-02 crmd: [3563]: info: do_lrm_invoke: Forcing a local LRM refresh<br>
[  OK  ]8:38:33 node-02 lrmd: [3560]: info: RA output: (pbx_02:start:stdout) Starting test-02: [  OK  ]<br>Oct 01 08:38:33 node-02 crmd: [3563]: info: process_lrm_event: LRM operation pbx_02_start_0 (call=53, rc=0, cib-update=71, confirmed=true) ok<br>
Oct 01 08:38:37 node-02 crmd: [3563]: info: do_lrm_rsc_op: Performing key=3:21:0:f80b1e20-63f0-4b00-bd04-f10c2bd10046 op=pbx_02_monitor_20000 )<br>Oct 01 08:38:37 node-02 crmd: [3563]: info: process_lrm_event: LRM operation pbx_02_monitor_20000 (call=54, rc=0, cib-update=72, confirmed=false) ok<br>
[root@node-02 ~]#  grep 08:53: /var/log/ha-log<br>Sep 29 08:53:43 node-02 cib: [9080]: info: write_cib_contents: Archived previous version as /var/lib/heartbeat/crm/cib-16.raw<br>Sep 29 08:53:43 node-02 cib: [9080]: info: write_cib_contents: Wrote version 0.581.0 of the CIB to disk (digest: dee87447308900b0a802faf1af419f1d)<br>
Sep 29 08:53:43 node-02 cib: [9080]: info: retrieveCib: Reading cluster configuration from: /var/lib/heartbeat/crm/cib.mh8MfP (digest: /var/lib/heartbeat/crm/cib.XlqJ9q)<br>Sep 29 08:53:52 node-02 cib: [9153]: info: write_cib_contents: Archived previous version as /var/lib/heartbeat/crm/cib-17.raw<br>
Sep 29 08:53:52 node-02 cib: [9153]: info: write_cib_contents: Wrote version 0.582.0 of the CIB to disk (digest: bf4dff2853265fdf4b5ef64eb8ba6d53)<br>Sep 29 08:53:52 node-02 cib: [9153]: info: retrieveCib: Reading cluster configuration from: /var/lib/heartbeat/crm/cib.Z0jdaH (digest: /var/lib/heartbeat/crm/cib.y7xSYI)<br>
Oct 01 08:53:39 node-02 lrmd: [3560]: info: cancel_op: operation monitor[54] on lsb::test-02::pbx_02 for client 3563, its parameters: CRM_meta_interval=[20000] CRM_meta_timeout=[20000] crm_feature_set=[3.0.1] CRM_meta_name=[monitor]  cancelled<br>
Oct 01 08:53:39 node-02 crmd: [3563]: info: do_lrm_rsc_op: Performing key=10:22:0:f80b1e20-63f0-4b00-bd04-f10c2bd10046 op=pbx_02_stop_0 )<br>Oct 01 08:53:39 node-02 lrmd: [3560]: info: rsc:pbx_02:55: stop<br>Oct 01 08:53:39 node-02 crmd: [3563]: info: process_lrm_event: LRM operation pbx_02_monitor_20000 (call=54, status=1, cib-update=0, confirmed=true) Cancelled<br>
Oct 01 08:53:39 node-02 lrmd: [18173]: WARN: For LSB init script, no additional parameters are needed.<br>Oct 01 08:53:39 node-02 lrmd: [3560]: info: RA output: (pbx_02:stop:stdout) Stopping test-02: [  OK  ]<br>Oct 01 08:53:39 node-02 crmd: [3563]: info: process_lrm_event: LRM operation pbx_02_stop_0 (call=55, rc=0, cib-update=73, confirmed=true) ok<br>
Oct 01 08:53:42 node-02 crmd: [3563]: info: do_lrm_invoke: Removing resource pbx_02 from the LRM<br>Oct 01 08:53:42 node-02 crmd: [3563]: info: do_lrm_invoke: Resource 'pbx_02' deleted for tengine on (null)<br>Oct 01 08:53:42 node-02 crmd: [3563]: info: notify_deleted: Notifying tengine on node-03 that pbx_02 was deleted<br>
Oct 01 08:53:42 node-02 crmd: [3563]: info: send_direct_ack: ACK'ing resource op pbx_02_delete_0 from 11:22:0:f80b1e20-63f0-4b00-bd04-f10c2bd10046: lrm_invoke-lrmd-1285916022-17<br>Oct 01 08:53:45 node-02 lrmd: [3560]: notice: lrmd_rsc_new(): No lrm_rprovider field in message<br>
Oct 01 08:53:45 node-02 crmd: [3563]: info: do_lrm_rsc_op: Performing key=24:22:0:f80b1e20-63f0-4b00-bd04-f10c2bd10046 op=pbx_02_start_0 )<br>Oct 01 08:53:45 node-02 lrmd: [3560]: info: rsc:pbx_02:56: start<br>Oct 01 08:53:45 node-02 lrmd: [18201]: WARN: For LSB init script, no additional parameters are needed.<br>
[  OK  ]8:53:45 node-02 lrmd: [3560]: info: RA output: (pbx_02:start:stdout) Starting test-02: [  OK  ]<br>Oct 01 08:53:45 node-02 crmd: [3563]: info: do_lrm_invoke: Forcing a local LRM refresh<br>Oct 01 08:53:45 node-02 crmd: [3563]: info: process_lrm_event: LRM operation pbx_02_start_0 (call=56, rc=0, cib-update=75, confirmed=true) ok<br>
Oct 01 08:53:48 node-02 crmd: [3563]: info: do_lrm_rsc_op: Performing key=3:22:0:f80b1e20-63f0-4b00-bd04-f10c2bd10046 op=pbx_02_monitor_20000 )<br>Oct 01 08:53:48 node-02 crmd: [3563]: info: process_lrm_event: LRM operation pbx_02_monitor_20000 (call=57, rc=0, cib-update=76, confirmed=false) ok<br>
<br><br><br>The LSB test script, it is common for both pbx resource, expect few changes like filename and etc<br>[root@node-02 ~]# cat /etc/init.d/test-02<br>#!/bin/bash<br>#<br># Init file for test-02 daemon<br>#<br># chkconfig: 2345 55 25<br>
# description: test server daemon to be used by cluster for<br># testing purposes and nothing more<br>#<br># processname: test-02<br><br># source function library<br>. /etc/rc.d/init.d/functions<br><br><br>RETVAL=0<br>prog="test-02"<br>
file="/pbx_service_02/$prog.out"<br><br>runlevel=$(set -- $(runlevel); eval "echo \$$#" )<br><br><br>start()<br>{<br>        # Create keys if necessary<br><br>        echo -n $"Starting $prog: "<br>
        touch $file && success || failure<br>        success<br>        RETVAL=$?<br>        echo<br>}<br><br>stop()<br>{<br>        echo -n $"Stopping $prog: "<br>        rm -f $file && success || failure<br>
        RETVAL=$?<br>}<br><br><br>case "$1" in<br>        start)<br>                start<br>                ;;<br>        stop)<br>                stop<br>                ;;<br>        status)<br>                if [ -f $file ] ; then<br>
                   touch $file && success || failure<br>                   RETVAL=$?<br>                else<br>                   failure<br>                   RETVAL=$?<br>                fi<br>                ;;<br>
        *)<br>                echo $"Usage: $0 {start|stop|status}"<br>                RETVAL=1<br>esac<br>exit $RETVAL<br><br>