I have a two-node cluster with a problem. If I start Corosync/Pacemaker on one
node, and then delay startup on the 2nd node (which is otherwise up and
running), the 2nd node will be rebooted very soon after STONITH is enabled on
the first node. This reboot seems to be gratuitous and could under some
circumstances be problematic. While, at present, I "manually" start
Corosync/Pacemaker by invoking a script from an ssh session, in a production
environment, this script would be started by a systemd service. It's not hard
to imagine that if both nodes were started at approximately the same time (each
node runs on a separate motherboard in the same chassis), this behavior could
cause one of the nodes to be rebooted while it's in the process of booting up.
The two nodes' host names are mgraid-16201289RN00023-0 and
mgraid-16201289RN00023-1. Both hosts are running, but Pacemaker has been
started on neither. If Pacemaker is started on mgraid-16201289RN00023-0,
within a few seconds after STONITH is enabled, the following messages will
appear in the system log file, and soon thereafter STONITH will be invoked to
reboot the other node, on which Pacemaker has not yet been started. (NB: The
fence agent is a process named mgpstonith which uses the ipmi interface to
reboot the other node. For debugging, it prints the data it receives from
stdin. )
2019-07-08T13:11:14.907668-07:00 mgraid-16201289RN00023-0 HA_STARTSTOP:
Configure mgraid-stonith # This message indicates that STONITH is about to
be configured and enabled
...
2019-07-08T13:11:15.018131-07:00 mgraid-16201289RN00023-0 MGPSTONITH[16299]:
info:... action=metadata#012
2019-07-08T13:11:15.050817-07:00 mgraid-16201289RN00023-0 MGPSTONITH[16301]:
info:... action=metadata#012
...
2019-07-08T13:11:21.085092-07:00 mgraid-16201289RN00023-0 pengine[16216]:
warning: Scheduling Node mgraid-16201289RN00023-1 for STONITH
2019-07-08T13:11:21.085615-07:00 mgraid-16201289RN00023-0 pengine[16216]:
notice: * Fence (reboot) mgraid-16201289RN00023-1 'node is unclean'
2019-07-08T13:11:21.085663-07:00 mgraid-16201289RN00023-0 pengine[16216]:
notice: * Promote SS16201289RN00023:0 ( Stopped -> Master
mgraid-16201289RN00023-0 )
2019-07-08T13:11:21.085704-07:00 mgraid-16201289RN00023-0 pengine[16216]:
notice: * Start mgraid-stonith:0 (
mgraid-16201289RN00023-0 )
2019-07-08T13:11:21.091673-07:00 mgraid-16201289RN00023-0 pengine[16216]:
warning: Calculated transition 0 (with warnings), saving inputs in
/var/lib/pacemaker/pengine/pe-warn-3.bz2
2019-07-08T13:11:21.093155-07:00 mgraid-16201289RN00023-0 crmd[16218]:
notice: Initiating monitor operation SS16201289RN00023:0_monitor_0 locally on
mgraid-16201289RN00023-0
2019-07-08T13:11:21.124403-07:00 mgraid-16201289RN00023-0 crmd[16218]:
notice: Initiating monitor operation mgraid-stonith:0_monitor_0 locally on
mgraid-16201289RN00023-0
...
2019-07-08T13:11:21.132994-07:00 mgraid-16201289RN00023-0 MGPSTONITH[16361]:
info:... action=metadata#012
...
2019-07-08T13:11:22.128139-07:00 mgraid-16201289RN00023-0 crmd[16218]:
notice: Requesting fencing (reboot) of node mgraid-16201289RN00023-1
2019-07-08T13:11:22.129150-07:00 mgraid-16201289RN00023-0 crmd[16218]:
notice: Result of probe operation for SS16201289RN00023 on
mgraid-16201289RN00023-0: 7 (not running)
2019-07-08T13:11:22.129191-07:00 mgraid-16201289RN00023-0 crmd[16218]:
notice: mgraid-16201289RN00023-0-SS16201289RN00023_monitor_0:6 [ \n\n ]
2019-07-08T13:11:22.133846-07:00 mgraid-16201289RN00023-0 stonith-ng[16213]:
notice: Client crmd.16218.a7e3cbae wants to fence (reboot)
'mgraid-16201289RN00023-1' with device '(any)'
2019-07-08T13:11:22.133997-07:00 mgraid-16201289RN00023-0 stonith-ng[16213]:
notice: Requesting peer fencing (reboot) of mgraid-16201289RN00023-1
2019-07-08T13:11:22.136287-07:00 mgraid-16201289RN00023-0 crmd[16218]:
notice: Result of probe operation for mgraid-stonith on
mgraid-16201289RN00023-0: 7 (not running)
2019-07-08T13:11:22.141393-07:00 mgraid-16201289RN00023-0 MGPSTONITH[16444]:
info:... action=status#012 # Status requests always return 0.
2019-07-08T13:11:22.141418-07:00 mgraid-16201289RN00023-0 MGPSTONITH[16444]:
info:... nodename=mgraid-16201289RN00023-1#012
2019-07-08T13:11:22.141432-07:00 mgraid-16201289RN00023-0 MGPSTONITH[16444]:
info:... port=mgraid-16201289RN00023-1#012
2019-07-08T13:11:22.141444-07:00 mgraid-16201289RN00023-0 MGPSTONITH[16444]:
info:Ignoring: port
...
2019-07-08T13:11:22.148973-07:00 mgraid-16201289RN00023-0 MGPSTONITH[16445]:
info:... action=status#012
2019-07-08T13:11:22.148997-07:00 mgraid-16201289RN00023-0 MGPSTONITH[16445]:
info:... nodename=mgraid-16201289RN00023-1#012
2019-07-08T13:11:22.149009-07:00 mgraid-16201289RN00023-0 MGPSTONITH[16445]:
info:... port=mgraid-16201289RN00023-1#012
2019-07-08T13:11:22.149019-07:00 mgraid-16201289RN00023-0 MGPSTONITH[16445]:
info:Ignoring: port
...
2019-07-08T13:11:22.155226-07:00 mgraid-16201289RN00023-0 MGPSTONITH[16446]:
info:... action=reboot#012
2019-07-08T13:11:22.155250-07:00 mgraid-16201289RN00023-0 MGPSTONITH[16446]:
info:... nodename=mgraid-16201289RN00023-1#012
2019-07-08T13:11:22.155263-07:00 mgraid-16201289RN00023-0 MGPSTONITH[16446]:
info:... port=mgraid-16201289RN00023-1#012
2019-07-08T13:11:22.155273-07:00 mgraid-16201289RN00023-0 MGPSTONITH[16446]:
info:Ignoring: port
________________________________
Following is a relevant excerpt of the corosync.log file -
Jul 08 13:11:21 [16216] mgraid-16201289RN00023-0 pengine: debug:
unpack_config: STONITH timeout: 60000
Jul 08 13:11:21 [16216] mgraid-16201289RN00023-0 pengine: debug:
unpack_config: STONITH of failed nodes is enabled
Jul 08 13:11:21 [16216] mgraid-16201289RN00023-0 pengine: debug:
unpack_config: Concurrent fencing is disabled
Jul 08 13:11:21 [16216] mgraid-16201289RN00023-0 pengine: debug:
unpack_config: Stop all active resources: false
Jul 08 13:11:21 [16216] mgraid-16201289RN00023-0 pengine: debug:
unpack_config: Cluster is symmetric - resources can run anywhere by default
Jul 08 13:11:21 [16216] mgraid-16201289RN00023-0 pengine: debug:
unpack_config: Default stickiness: 0
Jul 08 13:11:21 [16216] mgraid-16201289RN00023-0 pengine: debug:
unpack_config: On loss of CCM Quorum: Stop ALL resources
Jul 08 13:11:21 [16216] mgraid-16201289RN00023-0 pengine: debug:
unpack_config: Node scores: 'red' = -INFINITY, 'yellow' = 0, 'green' = 0
Jul 08 13:11:21 [16216] mgraid-16201289RN00023-0 pengine: info:
determine_online_status_fencing: Node mgraid-16201289RN00023-0 is active
Jul 08 13:11:21 [16216] mgraid-16201289RN00023-0 pengine: info:
determine_online_status: Node mgraid-16201289RN00023-0 is online
Jul 08 13:11:21 [16216] mgraid-16201289RN00023-0 pengine: info:
unpack_node_loop: Node 1 is already processed
Jul 08 13:11:21 [16216] mgraid-16201289RN00023-0 pengine: info:
unpack_node_loop: Node 1 is already processed
Jul 08 13:11:21 [16216] mgraid-16201289RN00023-0 pengine: info:
clone_print: Master/Slave Set: ms-SS16201289RN00023 [SS16201289RN00023]
Jul 08 13:11:21 [16216] mgraid-16201289RN00023-0 pengine: info:
short_print: Stopped: [ mgraid-16201289RN00023-0
mgraid-16201289RN00023-1 ]
Jul 08 13:11:21 [16216] mgraid-16201289RN00023-0 pengine: info:
clone_print: Clone Set: mgraid-stonith-clone [mgraid-stonith]
Jul 08 13:11:21 [16216] mgraid-16201289RN00023-0 pengine: info:
short_print: Stopped: [ mgraid-16201289RN00023-0
mgraid-16201289RN00023-1 ]
Jul 08 13:11:21 [16216] mgraid-16201289RN00023-0 pengine: debug:
native_rsc_location: Constraint (ms-SS16201289RN00023-master-w1-rule) is
not active (role : Master vs. Unknown)
Jul 08 13:11:21 [16216] mgraid-16201289RN00023-0 pengine: debug:
native_rsc_location: Constraint (ms-SS16201289RN00023-master-w1-rule) is
not active (role : Master vs. Unknown)
Jul 08 13:11:21 [16216] mgraid-16201289RN00023-0 pengine: debug:
native_rsc_location: Constraint (ms-SS16201289RN00023-master-w1-rule) is
not active (role : Master vs. Unknown)
Jul 08 13:11:21 [16216] mgraid-16201289RN00023-0 pengine: debug:
distribute_children: Allocating up to 2 ms-SS16201289RN00023 instances to
a possible 1 nodes (at most 1 per host, 2 optimal)
Jul 08 13:11:21 [16216] mgraid-16201289RN00023-0 pengine: debug:
native_assign_node: Assigning mgraid-16201289RN00023-0 to
SS16201289RN00023:0
Jul 08 13:11:21 [16216] mgraid-16201289RN00023-0 pengine: debug:
native_assign_node: All nodes for resource SS16201289RN00023:1 are
unavailable, unclean or shutting down (mgraid-16201289RN00023-1: 0, -1000000)
Jul 08 13:11:21 [16216] mgraid-16201289RN00023-0 pengine: debug:
native_assign_node: Could not allocate a node for SS16201289RN00023:1
Jul 08 13:11:21 [16216] mgraid-16201289RN00023-0 pengine: info:
native_color: Resource SS16201289RN00023:1 cannot run anywhere
Jul 08 13:11:21 [16216] mgraid-16201289RN00023-0 pengine: debug:
distribute_children: Allocated 1 ms-SS16201289RN00023 instances of a
possible 2
Jul 08 13:11:21 [16216] mgraid-16201289RN00023-0 pengine: debug:
master_color: SS16201289RN00023:0 master score: 99
Jul 08 13:11:21 [16216] mgraid-16201289RN00023-0 pengine: info:
master_color: Promoting SS16201289RN00023:0 (Stopped mgraid-16201289RN00023-0)
Jul 08 13:11:21 [16216] mgraid-16201289RN00023-0 pengine: debug:
master_color: SS16201289RN00023:1 master score: 0
Jul 08 13:11:21 [16216] mgraid-16201289RN00023-0 pengine: info:
master_color: ms-SS16201289RN00023: Promoted 1 instances of a possible 1 to
master
Jul 08 13:11:21 [16216] mgraid-16201289RN00023-0 pengine: debug:
distribute_children: Allocating up to 2 mgraid-stonith-clone instances to
a possible 1 nodes (at most 1 per host, 2 optimal)
Jul 08 13:11:21 [16216] mgraid-16201289RN00023-0 pengine: debug:
native_assign_node: Assigning mgraid-16201289RN00023-0 to mgraid-stonith:0
Jul 08 13:11:21 [16216] mgraid-16201289RN00023-0 pengine: debug:
native_assign_node: All nodes for resource mgraid-stonith:1 are unavailable,
unclean or shutting down (mgraid-16201289RN00023-1: 0, -1000000)
Jul 08 13:11:21 [16216] mgraid-16201289RN00023-0 pengine: debug:
native_assign_node: Could not allocate a node for mgraid-stonith:1
Jul 08 13:11:21 [16216] mgraid-16201289RN00023-0 pengine: info:
native_color: Resource mgraid-stonith:1 cannot run anywhere
Jul 08 13:11:21 [16216] mgraid-16201289RN00023-0 pengine: debug:
distribute_children: Allocated 1 mgraid-stonith-clone instances of a
possible 2
Jul 08 13:11:21 [16216] mgraid-16201289RN00023-0 pengine: debug:
native_create_probe: Probing SS16201289RN00023:0 on
mgraid-16201289RN00023-0 (Stopped) 1 (nil)
Jul 08 13:11:21 [16216] mgraid-16201289RN00023-0 pengine: debug:
native_create_probe: Probing mgraid-stonith:0 on mgraid-16201289RN00023-0
(Stopped) 1 (nil)
Jul 08 13:11:21 [16216] mgraid-16201289RN00023-0 pengine: debug:
master_create_actions: Creating actions for ms-SS16201289RN00023
Jul 08 13:11:21 [16216] mgraid-16201289RN00023-0 pengine: info:
RecurringOp: Start recurring monitor (3s) for SS16201289RN00023:0 on
mgraid-16201289RN00023-0
Jul 08 13:11:21 [16216] mgraid-16201289RN00023-0 pengine: info:
RecurringOp: Start recurring monitor (3s) for SS16201289RN00023:0 on
mgraid-16201289RN00023-0
Jul 08 13:11:21 [16216] mgraid-16201289RN00023-0 pengine: warning: stage6:
Scheduling Node mgraid-16201289RN00023-1 for STONITH
Jul 08 13:11:21 [16216] mgraid-16201289RN00023-0 pengine: debug:
native_start_constraints: Ordering mgraid-stonith:0_start_0 after
mgraid-16201289RN00023-1 recovery
Jul 08 13:11:21 [16216] mgraid-16201289RN00023-0 pengine: notice:
LogNodeActions: * Fence (reboot) mgraid-16201289RN00023-1 'node is unclean'
Jul 08 13:11:21 [16216] mgraid-16201289RN00023-0 pengine: notice:
LogAction: * Promote SS16201289RN00023:0 ( Stopped -> Master
mgraid-16201289RN00023-0 )
Jul 08 13:11:21 [16216] mgraid-16201289RN00023-0 pengine: info:
LogActions: Leave SS16201289RN00023:1 (Stopped)
Jul 08 13:11:21 [16216] mgraid-16201289RN00023-0 pengine: notice:
LogAction: * Start mgraid-stonith:0 (
mgraid-16201289RN00023-0 )
Jul 08 13:11:21 [16216] mgraid-16201289RN00023-0 pengine: info:
LogActions: Leave mgraid-stonith:1 (Stopped)
Jul 08 13:11:21 [16216] mgraid-16201289RN00023-0 pengine: debug:
action2xml: Using anonymous clone name SS16201289RN00023 for
SS16201289RN00023:0 (aka. (null))
Jul 08 13:11:21 [16216] mgraid-16201289RN00023-0 pengine: debug:
action2xml: Using anonymous clone name SS16201289RN00023 for
SS16201289RN00023:0 (aka. (null))
Jul 08 13:11:21 [16216] mgraid-16201289RN00023-0 pengine: debug:
action2xml: Using anonymous clone name SS16201289RN00023 for
SS16201289RN00023:0 (aka. (null))
Jul 08 13:11:21 [16216] mgraid-16201289RN00023-0 pengine: debug:
action2xml: Using anonymous clone name SS16201289RN00023 for
SS16201289RN00023:0 (aka. (null))
Jul 08 13:11:21 [16216] mgraid-16201289RN00023-0 pengine: debug:
action2xml: Using anonymous clone name SS16201289RN00023 for
SS16201289RN00023:0 (aka. (null))
Jul 08 13:11:21 [16216] mgraid-16201289RN00023-0 pengine: debug:
action2xml: Using anonymous clone name SS16201289RN00023 for
SS16201289RN00023:0 (aka. (null))
Jul 08 13:11:21 [16216] mgraid-16201289RN00023-0 pengine: debug:
action2xml: Using anonymous clone name SS16201289RN00023 for
SS16201289RN00023:0 (aka. (null))
Jul 08 13:11:21 [16216] mgraid-16201289RN00023-0 pengine: debug:
action2xml: Using anonymous clone name mgraid-stonith for mgraid-stonith:0
(aka. (null))
Jul 08 13:11:21 [16216] mgraid-16201289RN00023-0 pengine: debug:
action2xml: Using anonymous clone name mgraid-stonith for mgraid-stonith:0
(aka. (null))
Jul 08 13:11:21 [16216] mgraid-16201289RN00023-0 pengine: warning:
process_pe_message: Calculated transition 0 (with warnings), saving
inputs in /var/lib/pacemaker/pengine/pe-warn-3.bz2
________________________________
Here is the status of the first node, once Pacemaker is started -
[root@mgraid-16201289RN00023-0 bin]# pcs status
Cluster name:
Stack: corosync
Current DC: mgraid-16201289RN00023-0 (version 1.1.19-8.el7-c3c624ea3d) -
partition with quorum
Last updated: Mon Jul 8 17:51:22 2019
Last change: Mon Jul 8 16:11:23 2019 by root via cibadmin on
mgraid-16201289RN00023-0
2 nodes configured
4 resources configured
Online: [ mgraid-16201289RN00023-0 ]
OFFLINE: [ mgraid-16201289RN00023-1 ]
Full list of resources:
Master/Slave Set: ms-SS16201289RN00023 [SS16201289RN00023]
SS16201289RN00023 (ocf::omneon:ss): Starting
mgraid-16201289RN00023-0
Stopped: [ mgraid-16201289RN00023-1 ]
Clone Set: mgraid-stonith-clone [mgraid-stonith]
Started: [ mgraid-16201289RN00023-0 ]
Stopped: [ mgraid-16201289RN00023-1 ]
Daemon Status:
corosync: active/disabled
pacemaker: active/disabled
pcsd: inactive/disabled
________________________________
Here's the configuration, from the first node -
[root@mgraid-16201289RN00023-0 bin]# pcs status
Cluster name:
Stack: corosync
Current DC: mgraid-16201289RN00023-0 (version 1.1.19-8.el7-c3c624ea3d) -
partition with quorum
Last updated: Mon Jul 8 17:51:22 2019
Last change: Mon Jul 8 16:11:23 2019 by root via cibadmin on
mgraid-16201289RN00023-0
2 nodes configured
4 resources configured
Online: [ mgraid-16201289RN00023-0 ]
OFFLINE: [ mgraid-16201289RN00023-1 ]
Full list of resources:
Master/Slave Set: ms-SS16201289RN00023 [SS16201289RN00023]
SS16201289RN00023 (ocf::omneon:ss): Starting
mgraid-16201289RN00023-0
Stopped: [ mgraid-16201289RN00023-1 ]
Clone Set: mgraid-stonith-clone [mgraid-stonith]
Started: [ mgraid-16201289RN00023-0 ]
Stopped: [ mgraid-16201289RN00023-1 ]
Daemon Status:
corosync: active/disabled
pacemaker: active/disabled
pcsd: inactive/disabled
[root@mgraid-16201289RN00023-0 bin]# pcs config
Cluster Name:
Corosync Nodes:
mgraid-16201289RN00023-0 mgraid-16201289RN00023-1
Pacemaker Nodes:
mgraid-16201289RN00023-0 mgraid-16201289RN00023-1
Resources:
Master: ms-SS16201289RN00023
Meta Attrs: clone-max=2 notify=true globally-unique=false target-role=Started
Resource: SS16201289RN00023 (class=ocf provider=omneon type=ss)
Attributes: ss_resource=SS16201289RN00023
ssconf=/var/omneon/config/config.16201289RN00023
Operations: monitor interval=3s role=Master timeout=7s
(SS16201289RN00023-monitor-3s)
monitor interval=10s role=Slave timeout=7
(SS16201289RN00023-monitor-10s)
stop interval=0 timeout=20 (SS16201289RN00023-stop-0)
start interval=0 timeout=300 (SS16201289RN00023-start-0)
Clone: mgraid-stonith-clone
Resource: mgraid-stonith (class=stonith type=mgpstonith)
Operations: monitor interval=0 timeout=20s
(mgraid-stonith-monitor-interval-0)
Stonith Devices:
Fencing Levels:
Location Constraints:
Resource: ms-SS16201289RN00023
Constraint: ms-SS16201289RN00023-master-w1
Rule: role=master score=100 (id:ms-SS16201289RN00023-master-w1-rule)
Expression: #uname eq mgraid-16201289rn00023-0
(id:ms-SS16201289RN00023-master-w1-rule-expression)
Ordering Constraints:
Colocation Constraints:
Ticket Constraints:
Alerts:
No alerts defined
Resources Defaults:
failure-timeout: 1min
Operations Defaults:
No defaults set
Cluster Properties:
cluster-infrastructure: corosync
cluster-recheck-interval: 1min
dc-deadtime: 5s
dc-version: 1.1.19-8.el7-c3c624ea3d
have-watchdog: false
last-lrm-refresh: 1562513532
stonith-enabled: true
Quorum:
Options:
wait_for_all: 0
________________________________
Interestingly, as you'll note below, the "two_node" option is also set to 1,
but is not reported as such above.
Finally, here's /etc/corosync/corosync.conf -
totem {
version: 2
crypto_cipher: none
crypto_hash: none
interface {
ringnumber: 0
bindnetaddr: 169.254.1.1
mcastaddr: 239.255.1.1
mcastport: 5405
ttl: 1
}
}
logging {
fileline: off
to_stderr: no
to_logfile: yes
logfile: /var/log/cluster/corosync.log
to_syslog: yes
debug: on
timestamp: on
logger_subsys {
subsys: QUORUM
debug: on
}
}
nodelist {
node {
ring0_addr: mgraid-16201289RN00023-0
nodeid: 1
}
node {
ring0_addr: mgraid-16201289RN00023-1
nodeid: 2
}
}
quorum {
provider: corosync_votequorum
two_node: 1
wait_for_all: 0
}
I'd appreciate any insight you can offer into this behavior, and any
suggestions you may have.
Regards,
Michael
[cid:[email protected]]
Michael Powell
Sr. Staff Engineer
15220 NW Greenbrier Pkwy
Suite 290
Beaverton, OR 97006
T 503-372-7327 M 503-789-3019 H 503-625-5332
_______________________________________________
Manage your subscription:
https://lists.clusterlabs.org/mailman/listinfo/users
ClusterLabs home: https://www.clusterlabs.org/