[Pacemaker] resources are restarted without obvious reasons

Fri Oct 1 03:05:57 EDT 2010

Hi,

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.
When I used the ocf:heartbeat:Dummy I don't remember seeing that behavior.

All the related info are below

On DC where node resources running
08:30:50 cib: [3469]: info: cib_stats: Processed 50 operations (2800.00us
average, 0% utilization) in the last 10min
08:36:09 heartbeat: [3384]: WARN: Late heartbeat: Node node-02: interval
6470 ms
08:38:27 crmd: [3473]: info: crm_timer_popped: PEngine Recheck Timer
(I_PE_CALC) just popped!
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 ]
08:38:27 crmd: [3473]: info: do_state_transition: Progressed to state
S_POLICY_ENGINE after C_TIMER_POPPED
08:38:27 crmd: [3473]: info: do_state_transition: All 3 cluster nodes are
eligible to run resources.
08:38:27 crmd: [3473]: info: do_pe_invoke: Query 192: Requesting the current
CIB: S_POLICY_ENGINE
08:38:27 pengine: [3979]: info: unpack_config: Node scores: 'red' =
-INFINITY, 'yellow' = 0, 'green' = 0
08:38:27 pengine: [3979]: info: determine_online_status: Node node-02 is
online
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
08:38:27 pengine: [3979]: info: determine_online_status: Node node-03 is
online
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 ]
08:38:27 pengine: [3979]: info: determine_online_status: Node node-01 is
online
08:38:27 crmd: [3473]: info: unpack_graph: Unpacked transition 21: 19
actions in 19 synapses
08:38:27 pengine: [3979]: info: find_clone: Internally renamed drbd_02:0 on
node-01 to drbd_02:2 (ORPHAN)
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
08:38:27 pengine: [3979]: notice: group_print:  Resource Group:
pbx_service_02
08:38:27 crmd: [3473]: info: te_pseudo_action: Pseudo action 27 fired and
confirmed
08:38:27 pengine: [3979]: notice: native_print:      ip_02
(ocf::heartbeat:IPaddr2):       Started node-02
08:38:27 crmd: [3473]: info: te_rsc_command: Initiating action 10: stop
pbx_02_stop_0 on node-02
08:38:27 pengine: [3979]: notice: native_print:      fs_02
(ocf::heartbeat:Filesystem):    Started node-02
08:38:27 crmd: [3473]: info: te_pseudo_action: Pseudo action 67 fired and
confirmed
08:38:27 pengine: [3979]: notice: native_print:      pbx_02
(lsb:test-02):  Started node-02
08:38:27 crmd: [3473]: info: te_rsc_command: Initiating action 13: stop
pbx_01_stop_0 on node-01
08:38:27 pengine: [3979]: notice: clone_print:  Master/Slave Set: ms-drbd_02
08:38:27 pengine: [3979]: notice: short_print:      Masters: [ node-02 ]
08:38:27 pengine: [3979]: notice: short_print:      Slaves: [ node-03 ]
08:38:27 pengine: [3979]: notice: group_print:  Resource Group:
pbx_service_01
08:38:27 pengine: [3979]: notice: native_print:      ip_01
(ocf::heartbeat:IPaddr2):       Started node-01
08:38:27 pengine: [3979]: notice: native_print:      fs_01
(ocf::heartbeat:Filesystem):    Started node-01
08:38:27 pengine: [3979]: notice: native_print:      pbx_01
(lsb:test-01):  Started node-01
08:38:27 pengine: [3979]: notice: clone_print:  Master/Slave Set: ms-drbd_01
08:38:27 pengine: [3979]: notice: short_print:      Masters: [ node-01 ]
08:38:27 pengine: [3979]: notice: short_print:      Slaves: [ node-03 ]
08:38:27 pengine: [3979]: notice: check_rsc_parameters: Forcing restart of
pbx_02 on node-02, provider changed: heartbeat -> <null>
08:38:27 pengine: [3979]: notice: DeleteRsc: Removing pbx_02 from node-02
08:38:27 pengine: [3979]: notice: check_rsc_parameters: Forcing restart of
pbx_01 on node-01, provider changed: heartbeat -> <null>
08:38:27 pengine: [3979]: notice: DeleteRsc: Removing pbx_01 from node-01
08:38:27 pengine: [3979]: info: master_color: Promoting drbd_02:0 (Master
node-02)
08:38:27 pengine: [3979]: info: master_color: ms-drbd_02: Promoted 1
instances of a possible 1 to master
08:38:27 pengine: [3979]: info: master_color: Promoting drbd_02:0 (Master
node-02)
08:38:27 pengine: [3979]: info: master_color: ms-drbd_02: Promoted 1
instances of a possible 1 to master
08:38:27 pengine: [3979]: info: master_color: Promoting drbd_01:0 (Master
node-01)
08:38:27 pengine: [3979]: info: master_color: ms-drbd_01: Promoted 1
instances of a possible 1 to master
08:38:27 pengine: [3979]: info: master_color: Promoting drbd_01:0 (Master
node-01)
08:38:27 pengine: [3979]: info: master_color: ms-drbd_01: Promoted 1
instances of a possible 1 to master
08:38:27 pengine: [3979]: notice: RecurringOp:  Start recurring monitor
(20s) for pbx_02 on node-02
08:38:27 pengine: [3979]: ERROR: create_notification_boundaries: Creating
boundaries for ms-drbd_02
08:38:27 pengine: [3979]: ERROR: create_notification_boundaries: Creating
boundaries for ms-drbd_02
08:38:27 pengine: [3979]: ERROR: create_notification_boundaries: Creating
boundaries for ms-drbd_02
08:38:27 pengine: [3979]: ERROR: create_notification_boundaries: Creating
boundaries for ms-drbd_02
08:38:27 pengine: [3979]: notice: RecurringOp:  Start recurring monitor
(20s) for pbx_01 on node-01
08:38:27 pengine: [3979]: ERROR: create_notification_boundaries: Creating
boundaries for ms-drbd_01
08:38:27 pengine: [3979]: ERROR: create_notification_boundaries: Creating
boundaries for ms-drbd_01
08:38:27 pengine: [3979]: ERROR: create_notification_boundaries: Creating
boundaries for ms-drbd_01
08:38:27 pengine: [3979]: ERROR: create_notification_boundaries: Creating
boundaries for ms-drbd_01
08:38:27 pengine: [3979]: notice: LogActions: Leave resource ip_02
(Started node-02)
08:38:27 pengine: [3979]: notice: LogActions: Leave resource fs_02
(Started node-02)
08:38:27 pengine: [3979]: notice: LogActions: Restart resource pbx_02
(Started node-02)
08:38:27 pengine: [3979]: notice: LogActions: Leave resource drbd_02:0
(Master node-02)
08:38:27 pengine: [3979]: notice: LogActions: Leave resource drbd_02:1
(Slave node-03)
08:38:27 pengine: [3979]: notice: LogActions: Leave resource ip_01
(Started node-01)
08:38:27 pengine: [3979]: notice: LogActions: Leave resource fs_01
(Started node-01)
08:38:27 pengine: [3979]: notice: LogActions: Restart resource pbx_01
(Started node-01)
08:38:27 pengine: [3979]: notice: LogActions: Leave resource drbd_01:0
(Master node-01)
08:38:27 pengine: [3979]: notice: LogActions: Leave resource drbd_01:1
(Slave node-03)
08:38:27 pengine: [3979]: info: process_pe_message: Transition 21: PEngine
Input stored in: /var/lib/pengine/pe-input-1453.bz2
08:38:28 crmd: [3473]: info: match_graph_event: Action pbx_01_stop_0 (13)
confirmed on node-01 (rc=0)
08:38:28 crmd: [3473]: info: te_pseudo_action: Pseudo action 68 fired and
confirmed
08:38:28 crmd: [3473]: info: te_rsc_command: Initiating action 14: delete
pbx_01_delete_0 on node-01
08:38:28 crmd: [3473]: info: te_pseudo_action: Pseudo action 65 fired and
confirmed
08:38:29 crmd: [3473]: info: match_graph_event: Action pbx_02_stop_0 (10)
confirmed on node-02 (rc=0)
08:38:29 crmd: [3473]: info: te_pseudo_action: Pseudo action 28 fired and
confirmed
08:38:29 crmd: [3473]: info: te_rsc_command: Initiating action 11: delete
pbx_02_delete_0 on node-02
08:38:29 crmd: [3473]: info: te_pseudo_action: Pseudo action 9 fired and
confirmed
08:38:29 crmd: [3473]: info: te_pseudo_action: Pseudo action 25 fired and
confirmed
08:38:31 crmd: [3473]: info: process_te_message: Processing (N)ACK
lrm_invoke-lrmd-1285915110-15 from node-01
08:38:31 crmd: [3473]: info: match_graph_event: Action pbx_01_delete_0 (14)
confirmed on node-01 (rc=0)
08:38:31 crmd: [3473]: info: process_te_message: Processing (N)ACK
lrm_invoke-lrmd-1285915111-16 from node-02
08:38:31 crmd: [3473]: info: match_graph_event: Action pbx_02_delete_0 (11)
confirmed on node-02 (rc=0)
08:38:31 crmd: [3473]: info: te_rsc_command: Initiating action 24: start
pbx_02_start_0 on node-02
08:38:31 crmd: [3473]: info: te_rsc_command: Initiating action 64: start
pbx_01_start_0 on node-01
08:38:31 crmd: [3473]: info: te_crm_command: Executing crm-event (12):
lrm_refresh on node-02
08:38:31 crmd: [3473]: info: te_crm_command: Executing crm-event (15):
lrm_refresh on node-01
08:38:34 crmd: [3473]: info: match_graph_event: Action pbx_02_start_0 (24)
confirmed on node-02 (rc=0)
08:38:34 crmd: [3473]: info: te_pseudo_action: Pseudo action 26 fired and
confirmed
08:38:34 crmd: [3473]: info: te_rsc_command: Initiating action 3: monitor
pbx_02_monitor_20000 on node-02
08:38:34 crmd: [3473]: info: match_graph_event: Action pbx_01_start_0 (64)
confirmed on node-01 (rc=0)
08:38:34 crmd: [3473]: info: te_pseudo_action: Pseudo action 66 fired and
confirmed
08:38:34 crmd: [3473]: info: te_rsc_command: Initiating action 8: monitor
pbx_01_monitor_20000 on node-01
08:38:37 crmd: [3473]: info: match_graph_event: Action pbx_01_monitor_20000
(8) confirmed on node-01 (rc=0)
08:38:37 crmd: [3473]: info: match_graph_event: Action pbx_02_monitor_20000
(3) confirmed on node-02 (rc=0)
08:38:37 crmd: [3473]: info: run_graph:
====================================================
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
08:38:37 crmd: [3473]: info: te_graph_trigger: Transition 21 is now complete
08:38:37 crmd: [3473]: info: notify_crmd: Transition 21 status: done -
<null>
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 ]
08:38:37 crmd: [3473]: info: do_state_transition: Starting PEngine Recheck
Timer
08:40:51 cib: [3469]: info: cib_stats: Processed 30 operations (1333.00us
average, 0% utilization) in the last 10min

08:50:52 cib: [3469]: info: cib_stats: Processed 22 operations (0.00us
average, 0% utilization) in the last 10min
08:53:38 crmd: [3473]: info: crm_timer_popped: PEngine Recheck Timer
(I_PE_CALC) just popped!
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 ]
08:53:38 crmd: [3473]: info: do_state_transition: Progressed to state
S_POLICY_ENGINE after C_TIMER_POPPED
08:53:38 crmd: [3473]: info: do_state_transition: All 3 cluster nodes are
eligible to run resources.
08:53:38 crmd: [3473]: info: do_pe_invoke: Query 193: Requesting the current
CIB: S_POLICY_ENGINE
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
08:53:38 pengine: [3979]: info: unpack_config: Node scores: 'red' =
-INFINITY, 'yellow' = 0, 'green' = 0
08:53:38 pengine: [3979]: info: determine_online_status: Node node-02 is
online
08:53:38 pengine: [3979]: info: determine_online_status: Node node-03 is
online
08:53:38 pengine: [3979]: info: determine_online_status: Node node-01 is
online
08:53:38 pengine: [3979]: info: find_clone: Internally renamed drbd_02:0 on
node-01 to drbd_02:2 (ORPHAN)
08:53:38 pengine: [3979]: notice: group_print:  Resource Group:
pbx_service_02
08:53:38 pengine: [3979]: notice: native_print:      ip_02
(ocf::heartbeat:IPaddr2):       Started node-02
08:53:38 pengine: [3979]: notice: native_print:      fs_02
(ocf::heartbeat:Filesystem):    Started node-02
08:53:38 pengine: [3979]: notice: native_print:      pbx_02
(lsb:test-02):  Started node-02
08:53:38 pengine: [3979]: notice: clone_print:  Master/Slave Set: ms-drbd_02
08:53:38 pengine: [3979]: notice: short_print:      Masters: [ node-02 ]
08:53:38 pengine: [3979]: notice: short_print:      Slaves: [ node-03 ]
08:53:38 pengine: [3979]: notice: group_print:  Resource Group:
pbx_service_01
08:53:38 pengine: [3979]: notice: native_print:      ip_01
(ocf::heartbeat:IPaddr2):       Started node-01
08:53:38 pengine: [3979]: notice: native_print:      fs_01
(ocf::heartbeat:Filesystem):    Started node-01
08:53:38 pengine: [3979]: notice: native_print:      pbx_01
(lsb:test-01):  Started node-01
08:53:38 pengine: [3979]: notice: clone_print:  Master/Slave Set: ms-drbd_01
08:53:38 pengine: [3979]: notice: short_print:      Masters: [ node-01 ]
08:53:38 pengine: [3979]: notice: short_print:      Slaves: [ node-03 ]
08:53:38 pengine: [3979]: notice: check_rsc_parameters: Forcing restart of
pbx_02 on node-02, provider changed: heartbeat -> <null>
08:53:38 pengine: [3979]: notice: DeleteRsc: Removing pbx_02 from node-02
08:53:38 pengine: [3979]: notice: check_rsc_parameters: Forcing restart of
pbx_01 on node-01, provider changed: heartbeat -> <null>
08:53:38 pengine: [3979]: notice: DeleteRsc: Removing pbx_01 from node-01
08:53:38 pengine: [3979]: info: master_color: Promoting drbd_02:0 (Master
node-02)
08:53:38 pengine: [3979]: info: master_color: ms-drbd_02: Promoted 1
instances of a possible 1 to master
08:53:38 pengine: [3979]: info: master_color: Promoting drbd_02:0 (Master
node-02)
08:53:38 pengine: [3979]: info: master_color: ms-drbd_02: Promoted 1
instances of a possible 1 to master
08:53:38 pengine: [3979]: info: master_color: Promoting drbd_01:0 (Master
node-01)
08:53:38 pengine: [3979]: info: master_color: ms-drbd_01: Promoted 1
instances of a possible 1 to master
08:53:38 pengine: [3979]: info: master_color: Promoting drbd_01:0 (Master
node-01)
08:53:38 pengine: [3979]: info: master_color: ms-drbd_01: Promoted 1
instances of a possible 1 to master
08:53:38 pengine: [3979]: notice: RecurringOp:  Start recurring monitor
(20s) for pbx_02 on node-02
08:53:38 pengine: [3979]: ERROR: create_notification_boundaries: Creating
boundaries for ms-drbd_02
08:53:38 pengine: [3979]: ERROR: create_notification_boundaries: Creating
boundaries for ms-drbd_02
08:53:38 pengine: [3979]: ERROR: create_notification_boundaries: Creating
boundaries for ms-drbd_02
08:53:38 pengine: [3979]: ERROR: create_notification_boundaries: Creating
boundaries for ms-drbd_02
08:53:38 pengine: [3979]: notice: RecurringOp:  Start recurring monitor
(20s) for pbx_01 on node-01
08:53:38 pengine: [3979]: ERROR: create_notification_boundaries: Creating
boundaries for ms-drbd_01
08:53:38 pengine: [3979]: ERROR: create_notification_boundaries: Creating
boundaries for ms-drbd_01
08:53:38 pengine: [3979]: ERROR: create_notification_boundaries: Creating
boundaries for ms-drbd_01
08:53:38 pengine: [3979]: ERROR: create_notification_boundaries: Creating
boundaries for ms-drbd_01
08:53:38 pengine: [3979]: notice: LogActions: Leave resource ip_02
(Started node-02)
08:53:38 pengine: [3979]: notice: LogActions: Leave resource fs_02
(Started node-02)
08:53:38 pengine: [3979]: notice: LogActions: Restart resource pbx_02
(Started node-02)
08:53:38 pengine: [3979]: notice: LogActions: Leave resource drbd_02:0
(Master node-02)
08:53:38 pengine: [3979]: notice: LogActions: Leave resource drbd_02:1
(Slave node-03)
08:53:38 pengine: [3979]: notice: LogActions: Leave resource ip_01
(Started node-01)
08:53:38 pengine: [3979]: notice: LogActions: Leave resource fs_01
(Started node-01)
08:53:38 pengine: [3979]: notice: LogActions: Restart resource pbx_01
(Started node-01)
08:53:38 pengine: [3979]: notice: LogActions: Leave resource drbd_01:0
(Master node-01)
08:53:38 pengine: [3979]: notice: LogActions: Leave resource drbd_01:1
(Slave node-03)
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 ]
08:53:38 crmd: [3473]: info: unpack_graph: Unpacked transition 22: 19
actions in 19 synapses
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
08:53:38 crmd: [3473]: info: te_pseudo_action: Pseudo action 27 fired and
confirmed
08:53:38 crmd: [3473]: info: te_rsc_command: Initiating action 10: stop
pbx_02_stop_0 on node-02
08:53:38 crmd: [3473]: info: te_pseudo_action: Pseudo action 67 fired and
confirmed
08:53:38 crmd: [3473]: info: te_rsc_command: Initiating action 13: stop
pbx_01_stop_0 on node-01
08:53:38 pengine: [3979]: info: process_pe_message: Transition 22: PEngine
Input stored in: /var/lib/pengine/pe-input-1454.bz2
08:53:40 crmd: [3473]: info: match_graph_event: Action pbx_02_stop_0 (10)
confirmed on node-02 (rc=0)
08:53:40 crmd: [3473]: info: te_pseudo_action: Pseudo action 28 fired and
confirmed
08:53:40 crmd: [3473]: info: te_rsc_command: Initiating action 11: delete
pbx_02_delete_0 on node-02
08:53:40 crmd: [3473]: info: te_pseudo_action: Pseudo action 25 fired and
confirmed
08:53:40 crmd: [3473]: info: match_graph_event: Action pbx_01_stop_0 (13)
confirmed on node-01 (rc=0)
08:53:40 crmd: [3473]: info: te_pseudo_action: Pseudo action 68 fired and
confirmed
08:53:40 crmd: [3473]: info: te_rsc_command: Initiating action 14: delete
pbx_01_delete_0 on node-01
08:53:40 crmd: [3473]: info: te_pseudo_action: Pseudo action 9 fired and
confirmed
08:53:40 crmd: [3473]: info: te_pseudo_action: Pseudo action 65 fired and
confirmed
08:53:42 crmd: [3473]: info: process_te_message: Processing (N)ACK
lrm_invoke-lrmd-1285916022-17 from node-02
08:53:42 crmd: [3473]: info: match_graph_event: Action pbx_02_delete_0 (11)
confirmed on node-02 (rc=0)
08:53:42 crmd: [3473]: info: te_rsc_command: Initiating action 24: start
pbx_02_start_0 on node-02
08:53:42 crmd: [3473]: info: te_crm_command: Executing crm-event (12):
lrm_refresh on node-02
08:53:44 crmd: [3473]: info: process_te_message: Processing (N)ACK
lrm_invoke-lrmd-1285916022-16 from node-01
08:53:44 crmd: [3473]: info: match_graph_event: Action pbx_01_delete_0 (14)
confirmed on node-01 (rc=0)
08:53:44 crmd: [3473]: info: te_rsc_command: Initiating action 64: start
pbx_01_start_0 on node-01
08:53:44 crmd: [3473]: info: te_crm_command: Executing crm-event (15):
lrm_refresh on node-01
08:53:47 crmd: [3473]: info: match_graph_event: Action pbx_02_start_0 (24)
confirmed on node-02 (rc=0)
08:53:47 crmd: [3473]: info: te_pseudo_action: Pseudo action 26 fired and
confirmed
08:53:47 crmd: [3473]: info: te_rsc_command: Initiating action 3: monitor
pbx_02_monitor_20000 on node-02
08:53:48 crmd: [3473]: info: match_graph_event: Action pbx_01_start_0 (64)
confirmed on node-01 (rc=0)
08:53:48 crmd: [3473]: info: te_pseudo_action: Pseudo action 66 fired and
confirmed
08:53:48 crmd: [3473]: info: te_rsc_command: Initiating action 8: monitor
pbx_01_monitor_20000 on node-01
08:53:48 crmd: [3473]: info: match_graph_event: Action pbx_02_monitor_20000
(3) confirmed on node-02 (rc=0)
08:53:50 crmd: [3473]: info: match_graph_event: Action pbx_01_monitor_20000
(8) confirmed on node-01 (rc=0)
08:53:50 crmd: [3473]: info: run_graph:
====================================================
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
08:53:50 crmd: [3473]: info: te_graph_trigger: Transition 22 is now complete
08:53:50 crmd: [3473]: info: notify_crmd: Transition 22 status: done -
<null>
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 ]
08:53:50 crmd: [3473]: info: do_state_transition: Starting PEngine Recheck
Timer

On node-01 where pbx_service_01 resource group where running
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
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 )
Oct 01 08:38:28 node-01 lrmd: [3558]: info: rsc:pbx_01:46: stop
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
Oct 01 08:38:28 node-01 lrmd: [19763]: WARN: For LSB init script, no
additional parameters are needed.
Oct 01 08:38:28 node-01 lrmd: [3558]: info: RA output: (pbx_01:stop:stdout)
Stopping test-01: [  OK  ]
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
Oct 01 08:38:30 node-01 crmd: [3561]: info: do_lrm_invoke: Removing resource
pbx_01 from the LRM
Oct 01 08:38:30 node-01 crmd: [3561]: info: do_lrm_invoke: Resource 'pbx_01'
deleted for tengine on (null)
Oct 01 08:38:30 node-01 crmd: [3561]: info: notify_deleted: Notifying
tengine on node-03 that pbx_01 was deleted
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
Oct 01 08:38:33 node-01 lrmd: [3558]: notice: lrmd_rsc_new(): No
lrm_rprovider field in message
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 )
Oct 01 08:38:33 node-01 lrmd: [3558]: info: rsc:pbx_01:47: start
Oct 01 08:38:33 node-01 lrmd: [19836]: WARN: For LSB init script, no
additional parameters are needed.
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
Oct 01 08:38:33 node-01 crmd: [3561]: info: msg_to_op: Message follows:
Oct 01 08:38:33 node-01 crmd: [3561]: info: MSG: Dumping message with 16
fields
Oct 01 08:38:33 node-01 crmd: [3561]: info: MSG[0] : [lrm_t=op]
Oct 01 08:38:33 node-01 crmd: [3561]: info: MSG[1] : [lrm_rid=pbx_01]
Oct 01 08:38:33 node-01 crmd: [3561]: info: MSG[2] : [lrm_op=start]
Oct 01 08:38:33 node-01 crmd: [3561]: info: MSG[3] : [lrm_timeout=60000]
Oct 01 08:38:33 node-01 crmd: [3561]: info: MSG[4] : [lrm_interval=0]
Oct 01 08:38:33 node-01 crmd: [3561]: info: MSG[5] : [lrm_delay=0]
Oct 01 08:38:33 node-01 crmd: [3561]: info: MSG[6] : [lrm_copyparams=1]
Oct 01 08:38:33 node-01 crmd: [3561]: info: MSG[7] : [lrm_t_run=0]
Oct 01 08:38:33 node-01 crmd: [3561]: info: MSG[8] : [lrm_t_rcchange=0]
Oct 01 08:38:33 node-01 crmd: [3561]: info: MSG[9] : [lrm_exec_time=0]
Oct 01 08:38:33 node-01 crmd: [3561]: info: MSG[10] : [lrm_queue_time=0]
Oct 01 08:38:33 node-01 crmd: [3561]: info: MSG[11] : [lrm_targetrc=-1]
Oct 01 08:38:33 node-01 crmd: [3561]: info: MSG[12] : [lrm_app=crmd]
Oct 01 08:38:33 node-01 crmd: [3561]: info: MSG[13] :
[lrm_userdata=64:21:0:f80b1e20-63f0-4b00-bd04-f10c2bd10046]
Oct 01 08:38:33 node-01 crmd: [3561]: info: MSG[14] :
[(2)lrm_param=0x9759508(88 104)]
Oct 01 08:38:33 node-01 crmd: [3561]: info: MSG: Dumping message with 3
fields
Oct 01 08:38:33 node-01 crmd: [3561]: info: MSG[0] :
[CRM_meta_timeout=60000]
Oct 01 08:38:33 node-01 crmd: [3561]: info: MSG[1] : [crm_feature_set=3.0.1]
Oct 01 08:38:33 node-01 crmd: [3561]: info: MSG[2] : [CRM_meta_name=start]
Oct 01 08:38:33 node-01 crmd: [3561]: info: MSG[15] : [lrm_callid=47]
Oct 01 08:38:33 node-01 crmd: [3561]: info: do_lrm_invoke: Forcing a local
LRM refresh
Oct 01 08:38:33 node-01 lrmd: [3558]: info: RA output: (pbx_01:start:stdout)
Starting test-01:
[  OK  ]8:38:33 node-01 lrmd: [3558]: info: RA output: (pbx_01:start:stdout)
[  OK  ]
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
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 )
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
[root at node-01 ~]# grep 08:53: /var/log/ha-log
Sep 29 08:53:02 node-01 lrmd: [3523]: info: rsc:drbd_01:0:112: notify
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 )
Sep 29 08:53:03 node-01 lrmd: [3523]: info: RA output:
(drbd_01:0:notify:stdout)
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
Sep 29 08:53:05 node-01 lrmd: [3523]: info: rsc:drbd_01:0:113: notify
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 )
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
Sep 29 08:53:07 node-01 lrmd: [3523]: info: rsc:drbd_01:0:114: notify
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 )
Sep 29 08:53:07 node-01 lrmd: [3523]: info: RA output:
(drbd_01:0:notify:stdout)
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
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
)
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
Sep 29 08:53:43 node-01 cib: [26073]: info: write_cib_contents: Archived
previous version as /var/lib/heartbeat/crm/cib-18.raw
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)
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)
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
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
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 )
Sep 29 08:53:52 node-01 lrmd: [3523]: info: rsc:drbd_01:0:116: notify
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
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
Sep 29 08:53:53 node-01 cib: [26171]: info: write_cib_contents: Archived
previous version as /var/lib/heartbeat/crm/cib-19.raw
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)
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)
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 )
Sep 29 08:53:54 node-01 lrmd: [3523]: info: rsc:drbd_01:0:117: notify
Sep 29 08:53:54 node-01 lrmd: [3523]: info: RA output:
(drbd_01:0:notify:stdout)
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
Sep 29 08:53:56 node-01 lrmd: [3523]: info: rsc:drbd_01:0:118: notify
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 )
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
Sep 29 08:53:57 node-01 lrmd: [3523]: info: rsc:drbd_01:0:119: promote
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 )
Sep 29 08:53:58 node-01 lrmd: [3523]: info: RA output:
(drbd_01:0:promote:stdout)
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
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
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 )
Oct 01 08:53:39 node-01 lrmd: [3558]: info: rsc:pbx_01:49: stop
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
Oct 01 08:53:39 node-01 lrmd: [32258]: WARN: For LSB init script, no
additional parameters are needed.
Oct 01 08:53:39 node-01 lrmd: [3558]: info: RA output: (pbx_01:stop:stdout)
Stopping test-01: [  OK  ]
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
Oct 01 08:53:42 node-01 crmd: [3561]: info: do_lrm_invoke: Removing resource
pbx_01 from the LRM
Oct 01 08:53:42 node-01 crmd: [3561]: info: do_lrm_invoke: Resource 'pbx_01'
deleted for tengine on (null)
Oct 01 08:53:42 node-01 crmd: [3561]: info: notify_deleted: Notifying
tengine on node-03 that pbx_01 was deleted
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
Oct 01 08:53:46 node-01 lrmd: [3558]: notice: lrmd_rsc_new(): No
lrm_rprovider field in message
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 )
Oct 01 08:53:46 node-01 lrmd: [3558]: info: rsc:pbx_01:50: start
Oct 01 08:53:46 node-01 lrmd: [32322]: WARN: For LSB init script, no
additional parameters are needed.
[  OK  ]8:53:46 node-01 lrmd: [3558]: info: RA output: (pbx_01:start:stdout)
Starting test-01: [  OK  ]
Oct 01 08:53:46 node-01 crmd: [3561]: info: do_lrm_invoke: Forcing a local
LRM refresh
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
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 )
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

On node-02 where pbx_service_02 resource group was running

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
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 )
Oct 01 08:38:29 node-02 lrmd: [3560]: info: rsc:pbx_02:52: stop
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
Oct 01 08:38:29 node-02 lrmd: [9167]: WARN: For LSB init script, no
additional parameters are needed.
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
Oct 01 08:38:29 node-02 lrmd: [3560]: info: RA output: (pbx_02:stop:stdout)
Stopping test-02: [  OK  ]
Oct 01 08:38:31 node-02 crmd: [3563]: info: do_lrm_invoke: Removing resource
pbx_02 from the LRM
Oct 01 08:38:31 node-02 crmd: [3563]: info: do_lrm_invoke: Resource 'pbx_02'
deleted for tengine on (null)
Oct 01 08:38:31 node-02 crmd: [3563]: info: notify_deleted: Notifying
tengine on node-03 that pbx_02 was deleted
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
Oct 01 08:38:32 node-02 lrmd: [3560]: notice: lrmd_rsc_new(): No
lrm_rprovider field in message
Oct 01 08:38:32 node-02 lrmd: [3560]: info: rsc:pbx_02:53: start
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 )
Oct 01 08:38:32 node-02 lrmd: [9238]: WARN: For LSB init script, no
additional parameters are needed.
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
Oct 01 08:38:32 node-02 crmd: [3563]: info: msg_to_op: Message follows:
Oct 01 08:38:32 node-02 crmd: [3563]: info: MSG: Dumping message with 16
fields
Oct 01 08:38:32 node-02 crmd: [3563]: info: MSG[0] : [lrm_t=op]
Oct 01 08:38:32 node-02 crmd: [3563]: info: MSG[1] : [lrm_rid=pbx_02]
Oct 01 08:38:32 node-02 crmd: [3563]: info: MSG[2] : [lrm_op=start]
Oct 01 08:38:32 node-02 crmd: [3563]: info: MSG[3] : [lrm_timeout=60000]
Oct 01 08:38:32 node-02 crmd: [3563]: info: MSG[4] : [lrm_interval=0]
Oct 01 08:38:32 node-02 crmd: [3563]: info: MSG[5] : [lrm_delay=0]
Oct 01 08:38:32 node-02 crmd: [3563]: info: MSG[6] : [lrm_copyparams=1]
Oct 01 08:38:32 node-02 crmd: [3563]: info: MSG[7] : [lrm_t_run=0]
Oct 01 08:38:32 node-02 crmd: [3563]: info: MSG[8] : [lrm_t_rcchange=0]
Oct 01 08:38:32 node-02 crmd: [3563]: info: MSG[9] : [lrm_exec_time=0]
Oct 01 08:38:32 node-02 crmd: [3563]: info: MSG[10] : [lrm_queue_time=0]
Oct 01 08:38:32 node-02 crmd: [3563]: info: MSG[11] : [lrm_targetrc=-1]
Oct 01 08:38:32 node-02 crmd: [3563]: info: MSG[12] : [lrm_app=crmd]
Oct 01 08:38:32 node-02 crmd: [3563]: info: MSG[13] :
[lrm_userdata=24:21:0:f80b1e20-63f0-4b00-bd04-f10c2bd10046]
Oct 01 08:38:32 node-02 crmd: [3563]: info: MSG[14] :
[(2)lrm_param=0x98eacc0(88 104)]
Oct 01 08:38:32 node-02 crmd: [3563]: info: MSG: Dumping message with 3
fields
Oct 01 08:38:32 node-02 crmd: [3563]: info: MSG[0] :
[CRM_meta_timeout=60000]
Oct 01 08:38:32 node-02 crmd: [3563]: info: MSG[1] : [crm_feature_set=3.0.1]
Oct 01 08:38:32 node-02 crmd: [3563]: info: MSG[2] : [CRM_meta_name=start]
Oct 01 08:38:32 node-02 crmd: [3563]: info: MSG[15] : [lrm_callid=53]
Oct 01 08:38:33 node-02 crmd: [3563]: info: do_lrm_invoke: Forcing a local
LRM refresh
[  OK  ]8:38:33 node-02 lrmd: [3560]: info: RA output: (pbx_02:start:stdout)
Starting test-02: [  OK  ]
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
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 )
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
[root at node-02 ~]#  grep 08:53: /var/log/ha-log
Sep 29 08:53:43 node-02 cib: [9080]: info: write_cib_contents: Archived
previous version as /var/lib/heartbeat/crm/cib-16.raw
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)
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)
Sep 29 08:53:52 node-02 cib: [9153]: info: write_cib_contents: Archived
previous version as /var/lib/heartbeat/crm/cib-17.raw
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)
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)
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
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 )
Oct 01 08:53:39 node-02 lrmd: [3560]: info: rsc:pbx_02:55: stop
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
Oct 01 08:53:39 node-02 lrmd: [18173]: WARN: For LSB init script, no
additional parameters are needed.
Oct 01 08:53:39 node-02 lrmd: [3560]: info: RA output: (pbx_02:stop:stdout)
Stopping test-02: [  OK  ]
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
Oct 01 08:53:42 node-02 crmd: [3563]: info: do_lrm_invoke: Removing resource
pbx_02 from the LRM
Oct 01 08:53:42 node-02 crmd: [3563]: info: do_lrm_invoke: Resource 'pbx_02'
deleted for tengine on (null)
Oct 01 08:53:42 node-02 crmd: [3563]: info: notify_deleted: Notifying
tengine on node-03 that pbx_02 was deleted
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
Oct 01 08:53:45 node-02 lrmd: [3560]: notice: lrmd_rsc_new(): No
lrm_rprovider field in message
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 )
Oct 01 08:53:45 node-02 lrmd: [3560]: info: rsc:pbx_02:56: start
Oct 01 08:53:45 node-02 lrmd: [18201]: WARN: For LSB init script, no
additional parameters are needed.
[  OK  ]8:53:45 node-02 lrmd: [3560]: info: RA output: (pbx_02:start:stdout)
Starting test-02: [  OK  ]
Oct 01 08:53:45 node-02 crmd: [3563]: info: do_lrm_invoke: Forcing a local
LRM refresh
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
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 )
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

The LSB test script, it is common for both pbx resource, expect few changes
like filename and etc
[root at node-02 ~]# cat /etc/init.d/test-02
#!/bin/bash
#
# Init file for test-02 daemon
#
# chkconfig: 2345 55 25
# description: test server daemon to be used by cluster for
# testing purposes and nothing more
#
# processname: test-02

# source function library
. /etc/rc.d/init.d/functions

RETVAL=0
prog="test-02"
file="/pbx_service_02/$prog.out"

runlevel=$(set -- $(runlevel); eval "echo \$$#" )

start()
{
        # Create keys if necessary

        echo -n $"Starting $prog: "
        touch $file && success || failure
        success
        RETVAL=$?
        echo
}

stop()
{
        echo -n $"Stopping $prog: "
        rm -f $file && success || failure
        RETVAL=$?
}

case "$1" in
        start)
                start
                ;;
        stop)
                stop
                ;;
        status)
                if [ -f $file ] ; then
                   touch $file && success || failure
                   RETVAL=$?
                else
                   failure
                   RETVAL=$?
                fi
                ;;
        *)
                echo $"Usage: $0 {start|stop|status}"
                RETVAL=1
esac
exit $RETVAL
-------------- next part --------------
An HTML attachment was scrubbed...
URL: <http://lists.clusterlabs.org/pipermail/pacemaker/attachments/20101001/c1eea245/attachment.html>