[Pacemaker] Problems with SBD fencing

Jan Christian Kaldestad janck76 at gmail.com
Thu Aug 1 13:46:14 UTC 2013


Hi,

I am evaluating the SLES HA Extension 11 SP3 product. The cluster  consists
of 2-nodes (active/passive), using SBD stonith resource on a shared SAN
disk. Configuration according to http://www.linux-ha.org/wiki/SBD_Fencing

The SBD daemon is running on both nodes, and the stontih resource (defined
as primitive) is running on one node only.
There is also a monitor operation for the stonith resource (interval=36000,
timeout=20)
I am having some problems getting failover/fencing to work as expected in
the following scenario:
- Node 1 is running the resources that I created (except stonith)
- Node 2 is running the stonith resource
- Disconnect Node 2 from the network by bringing the interface down
- Node 2 status changes to UNCLEAN (offline), but the stonith resource does
not switch over to Node 1 and Node 2 does not reboot as I would expect.
- Checking the logs on Node 1, I notice the following:
 Aug  1 12:00:01 slesha1n1i-u pengine[8915]:  warning: pe_fence_node: Node
slesha1n2i-u will be fenced because the node is no longer part of the
cluster
 Aug  1 12:00:01 slesha1n1i-u pengine[8915]:  warning:
determine_online_status: Node slesha1n2i-u is unclean
 Aug  1 12:00:01 slesha1n1i-u pengine[8915]:  warning: custom_action:
Action stonith_sbd_stop_0 on slesha1n2i-u is unrunnable (offline)
 Aug  1 12:00:01 slesha1n1i-u pengine[8915]:  warning: stage6: Scheduling
Node slesha1n2i-u for STONITH
 Aug  1 12:00:01 slesha1n1i-u pengine[8915]:   notice: LogActions: Move
stonith_sbd   (Started slesha1n2i-u -> slesha1n1i-u)
 ...
 Aug  1 12:00:01 slesha1n1i-u crmd[8916]:   notice: te_fence_node:
Executing reboot fencing operation (24) on slesha1n2i-u (timeout=60000)
 Aug  1 12:00:01 slesha1n1i-u stonith-ng[8912]:   notice: handle_request:
Client crmd.8916.3144546f wants to fence (reboot) 'slesha1n2i-u' with
device '(any)'
 Aug  1 12:00:01 slesha1n1i-u stonith-ng[8912]:   notice:
initiate_remote_stonith_op: Initiating remote operation reboot for
slesha1n2i-u: 8c00ff7b-2986-4b2a-8b4a-760e8346349b (0)
 Aug  1 12:00:01 slesha1n1i-u stonith-ng[8912]:    error: remote_op_done:
Operation reboot of slesha1n2i-u by slesha1n1i-u for
crmd.8916 at slesha1n1i-u.8c00ff7b: No route to host
 Aug  1 12:00:01 slesha1n1i-u crmd[8916]:   notice:
tengine_stonith_callback: Stonith operation
3/24:3:0:8a0f32b2-f91c-4cdf-9cee-1ba9b6e187ab: No route to host (-113)
 Aug  1 12:00:01 slesha1n1i-u crmd[8916]:   notice:
tengine_stonith_callback: Stonith operation 3 for slesha1n2i-u failed (No
route to host): aborting transition.
 Aug  1 12:00:01 slesha1n1i-u crmd[8916]:   notice: tengine_stonith_notify:
Peer slesha1n2i-u was not terminated (st_notify_fence) by slesha1n1i-u for
slesha1n1i-u: No route to host (ref=8c00ff7b-2986-4b2a-8b4a-760e8346349b)
by client crmd.8916
 Aug  1 12:00:01 slesha1n1i-u crmd[8916]:   notice: run_graph: Transition 3
(Complete=1, Pending=0, Fired=0, Skipped=5, Incomplete=0,
Source=/var/lib/pacemaker/pengine/pe-warn-15.bz2): Stopped
 Aug  1 12:00:01 slesha1n1i-u pengine[8915]:   notice: unpack_config: On
loss of CCM Quorum: Ignore
 Aug  1 12:00:01 slesha1n1i-u pengine[8915]:  warning: pe_fence_node: Node
slesha1n2i-u will be fenced because the node is no longer part of the
cluster
 Aug  1 12:00:01 slesha1n1i-u pengine[8915]:  warning:
determine_online_status: Node slesha1n2i-u is unclean
 Aug  1 12:00:01 slesha1n1i-u pengine[8915]:  warning: custom_action:
Action stonith_sbd_stop_0 on slesha1n2i-u is unrunnable (offline)
 Aug  1 12:00:01 slesha1n1i-u pengine[8915]:  warning: stage6: Scheduling
Node slesha1n2i-u for STONITH
 Aug  1 12:00:01 slesha1n1i-u pengine[8915]:   notice: LogActions: Move
stonith_sbd   (Started slesha1n2i-u -> slesha1n1i-u)
 ...
 Aug  1 12:00:02 slesha1n1i-u crmd[8916]:   notice: too_many_st_failures:
Too many failures to fence slesha1n2i-u (11), giving up



- Then I bring Node 1 online again and start the cluster service, checking
logs:
 Aug  1 12:31:13 slesha1n1i-u corosync[8905]:  [CLM   ] CLM CONFIGURATION
CHANGE
 Aug  1 12:31:13 slesha1n1i-u corosync[8905]:  [CLM   ] New Configuration:
 Aug  1 12:31:13 slesha1n1i-u corosync[8905]:  [CLM   ]  r(0) ip(x.x.x.x)
 Aug  1 12:31:13 slesha1n1i-u corosync[8905]:  [CLM   ] Members Left:
 Aug  1 12:31:13 slesha1n1i-u corosync[8905]:  [CLM   ] Members Joined:
 Aug  1 12:31:13 slesha1n1i-u corosync[8905]:  [pcmk  ] notice:
pcmk_peer_update: Transitional membership event on ring 376: memb=1, new=0,
lost=0
 Aug  1 12:31:13 slesha1n1i-u corosync[8905]:  [pcmk  ] info:
pcmk_peer_update: memb: slesha1n1i-u 168824371
 Aug  1 12:31:13 slesha1n1i-u corosync[8905]:  [CLM   ] CLM CONFIGURATION
CHANGE
 Aug  1 12:31:13 slesha1n1i-u corosync[8905]:  [CLM   ] New Configuration:
 Aug  1 12:31:13 slesha1n1i-u corosync[8905]:  [CLM   ]  r(0) ip(x.x.x.x)
 Aug  1 12:31:13 slesha1n1i-u corosync[8905]:  [CLM   ]  r(0) ip(y.y.y.y)
 Aug  1 12:31:13 slesha1n1i-u corosync[8905]:  [CLM   ] Members Left:
 Aug  1 12:31:13 slesha1n1i-u corosync[8905]:  [CLM   ] Members Joined:
 Aug  1 12:31:13 slesha1n1i-u cib[8911]:   notice: ais_dispatch_message:
Membership 376: quorum acquired
 Aug  1 12:31:13 slesha1n1i-u corosync[8905]:  [CLM   ]  r(0) ip(y.y.y.y)
 Aug  1 12:31:13 slesha1n1i-u crmd[8916]:   notice: ais_dispatch_message:
Membership 376: quorum acquired
 Aug  1 12:31:13 slesha1n1i-u cib[8911]:   notice: crm_update_peer_state:
crm_update_ais_node: Node slesha1n2i-u[168824372] - state is now member
(was lost)
 Aug  1 12:31:13 slesha1n1i-u corosync[8905]:  [pcmk  ] notice:
pcmk_peer_update: Stable membership event on ring 376: memb=2, new=1, lost=0
 Aug  1 12:31:13 slesha1n1i-u corosync[8905]:  [pcmk  ] info:
update_member: Node 168824372/slesha1n2i-u is now: member
 Aug  1 12:31:13 slesha1n1i-u corosync[8905]:  [pcmk  ] info:
pcmk_peer_update: NEW:  slesha1n2i-u 168824372
 Aug  1 12:31:13 slesha1n1i-u crmd[8916]:   notice: crm_update_peer_state:
crm_update_ais_node: Node slesha1n2i-u[168824372] - state is now member
(was lost)
 Aug  1 12:31:13 slesha1n1i-u corosync[8905]:  [pcmk  ] info:
pcmk_peer_update: MEMB: slesha1n1i-u 168824371
 Aug  1 12:31:13 slesha1n1i-u crmd[8916]:   notice: peer_update_callback:
Node return implies stonith of slesha1n2i-u (action 24) completed
 Aug  1 12:31:13 slesha1n1i-u corosync[8905]:  [pcmk  ] info:
pcmk_peer_update: MEMB: slesha1n2i-u 168824372
 Aug  1 12:31:13 slesha1n1i-u corosync[8905]:  [pcmk  ] info:
send_member_notification: Sending membership update 376 to 2 children
 Aug  1 12:31:13 slesha1n1i-u corosync[8905]:  [TOTEM ] A processor joined
or left the membership and a new membership was formed.
 Aug  1 12:31:13 slesha1n1i-u corosync[8905]:  [pcmk  ] info:
update_member: 0x69f2f0 Node 168824372 (slesha1n2i-u) born on: 376
 Aug  1 12:31:13 slesha1n1i-u corosync[8905]:  [pcmk  ] info:
send_member_notification: Sending membership update 376 to 2 children
 Aug  1 12:31:13 slesha1n1i-u crmd[8916]:   notice: crm_update_quorum:
Updating quorum status to true (call=119)
 Aug  1 12:31:13 slesha1n1i-u corosync[8905]:  [CPG   ] chosen downlist:
sender r(0) ip(x.x.x.x) ; members(old:1 left:0)
 Aug  1 12:31:13 slesha1n1i-u corosync[8905]:  [MAIN  ] Completed service
synchronization, ready to provide service.
 Aug  1 12:31:13 slesha1n1i-u crmd[8916]:   notice: too_many_st_failures:
Too many failures to fence slesha1n2i-u (13), giving up
 Aug  1 12:31:13 slesha1n1i-u crmd[8916]:   notice: too_many_st_failures:
Too many failures to fence slesha1n2i-u (13), giving up
 Aug  1 12:31:14 slesha1n1i-u mgmtd: [8917]: info: CIB query: cib
 Aug  1 12:31:14 slesha1n1i-u corosync[8905]:  [pcmk  ] info:
update_member: Node slesha1n2i-u now has process list:
00000000000000000000000000151302 (1381122)
 Aug  1 12:31:14 slesha1n1i-u corosync[8905]:  [pcmk  ] info:
send_member_notification: Sending membership update 376 to 2 children
 Aug  1 12:31:14 slesha1n1i-u corosync[8905]:  [pcmk  ] info:
update_member: Node slesha1n2i-u now has process list:
00000000000000000000000000141302 (1315586)
 Aug  1 12:31:14 slesha1n1i-u corosync[8905]:  [pcmk  ] info:
send_member_notification: Sending membership update 376 to 2 children
 Aug  1 12:31:14 slesha1n1i-u corosync[8905]:  [pcmk  ] info:
update_member: Node slesha1n2i-u now has process list:
00000000000000000000000000101302 (1053442)
 Aug  1 12:31:14 slesha1n1i-u corosync[8905]:  [pcmk  ] info:
send_member_notification: Sending membership update 376 to 2 children
 Aug  1 12:31:15 slesha1n1i-u crmd[8916]:   notice: do_state_transition:
State transition S_IDLE -> S_INTEGRATION [ input=I_NODE_JOIN
cause=C_HA_MESSAGE origin=route_message ]
 Aug  1 12:31:15 slesha1n1i-u crmd[8916]:   notice: too_many_st_failures:
Too many failures to fence slesha1n2i-u (13), giving up
 Aug  1 12:31:15 slesha1n1i-u crmd[8916]:   notice: too_many_st_failures:
Too many failures to fence slesha1n2i-u (13), giving up
- Cluster status changes to Online for both nodes, but the stonith resource
won't start on any of the nodes.
- Trying to start the resource manually, but no success.
- Trying to restart the corosync process on Node 1 (rcopenais restart), but
it hangs forever. Checking logs:
 Aug  1 12:42:08 slesha1n1i-u corosync[8905]:  [SERV  ] Unloading all
Corosync service engines.
 Aug  1 12:42:08 slesha1n1i-u corosync[8905]:  [pcmk  ] notice:
pcmk_shutdown: Shuting down Pacemaker
 Aug  1 12:42:08 slesha1n1i-u corosync[8905]:  [pcmk  ] notice: stop_child:
Sent -15 to mgmtd: [8917]
 Aug  1 12:42:08 slesha1n1i-u mgmtd: [8917]: info: mgmtd is shutting down
 Aug  1 12:42:08 slesha1n1i-u mgmtd: [8917]: info: final_crm: client_id=1
cib_name=live
 Aug  1 12:42:08 slesha1n1i-u mgmtd: [8917]: info: final_crm: client_id=2
cib_name=live
 Aug  1 12:42:08 slesha1n1i-u mgmtd: [8917]: debug: [mgmtd] stopped
 Aug  1 12:42:08 slesha1n1i-u corosync[8905]:  [pcmk  ] notice:
pcmk_shutdown: mgmtd confirmed stopped
 Aug  1 12:42:08 slesha1n1i-u corosync[8905]:  [pcmk  ] notice: stop_child:
Sent -15 to crmd: [8916]
 Aug  1 12:42:08 slesha1n1i-u crmd[8916]:   notice: crm_shutdown:
Requesting shutdown, upper limit is 1200000ms
 Aug  1 12:42:08 slesha1n1i-u attrd[8914]:   notice: attrd_trigger_update:
Sending flush op to all hosts for: shutdown (1375353728)
 Aug  1 12:42:08 slesha1n1i-u attrd[8914]:   notice: attrd_perform_update:
Sent update 22: shutdown=1375353728
 Aug  1 12:42:08 slesha1n1i-u crmd[8916]:   notice: too_many_st_failures:
Too many failures to fence slesha1n2i-u (13), giving up
 Aug  1 12:42:08 slesha1n1i-u crmd[8916]:  warning: do_log: FSA: Input
I_TE_SUCCESS from abort_transition_graph() received in state S_POLICY_ENGINE
 Aug  1 12:42:38 slesha1n1i-u corosync[8905]:  [pcmk  ] notice:
pcmk_shutdown: Still waiting for crmd (pid=8916, seq=6) to terminate...
 Aug  1 12:43:08 slesha1n1i-u corosync[8905]:  [pcmk  ] notice:
pcmk_shutdown: Still waiting for crmd (pid=8916, seq=6) to terminate...
...

- Finally I kill the corosync process on Node 1 (killall -9 corosync), then
corsoync restarts.
- Checking status. All resources are up and running on Node 1, and the
stonith resource is running on Node 2 again.



I have tested the same scenario several times. Sometimes the fencing
mechaism works as expected, but other times the stonith resource is not
transferred to Node 1 - as described here. So I need some assistance to
overcome this problem....



--
Best regards
Jan
-------------- next part --------------
An HTML attachment was scrubbed...
URL: <https://lists.clusterlabs.org/pipermail/pacemaker/attachments/20130801/62f03fa1/attachment-0003.html>


More information about the Pacemaker mailing list