RHEL Engineering is moving the tracking of its product development work on RHEL 6 through RHEL 9 to Red Hat Jira (issues.redhat.com). If you're a Red Hat customer, please continue to file support cases via the Red Hat customer portal. If you're not, please head to the "RHEL project" in Red Hat Jira and file new tickets here. Individual Bugzilla bugs in the statuses "NEW", "ASSIGNED", and "POST" are being migrated throughout September 2023. Bugs of Red Hat partners with an assigned Engineering Partner Manager (EPM) are migrated in late September as per pre-agreed dates. Bugs against components "kernel", "kernel-rt", and "kpatch" are only migrated if still in "NEW" or "ASSIGNED". If you cannot log in to RH Jira, please consult article #7032570. That failing, please send an e-mail to the RH Jira admins at rh-issues@redhat.com to troubleshoot your issue as a user management inquiry. The email creates a ServiceNow ticket with Red Hat. Individual Bugzilla bugs that are migrated will be moved to status "CLOSED", resolution "MIGRATED", and set with "MigratedToJIRA" in "Keywords". The link to the successor Jira issue will be found under "Links", have a little "two-footprint" icon next to it, and direct you to the "RHEL project" in Red Hat Jira (issue links are of type "https://issues.redhat.com/browse/RHEL-XXXX", where "X" is a digit). This same link will be available in a blue banner at the top of the page informing you that that bug has been migrated.
Bug 1982453 - Pacemaker wrongly schedules probes on pending node
Summary: Pacemaker wrongly schedules probes on pending node
Keywords:
Status: CLOSED ERRATA
Alias: None
Product: Red Hat Enterprise Linux 8
Classification: Red Hat
Component: pacemaker
Version: 8.4
Hardware: All
OS: All
high
low
Target Milestone: beta
: 8.5
Assignee: Ken Gaillot
QA Contact: cluster-qe@redhat.com
URL:
Whiteboard:
Depends On:
Blocks: 1983197
TreeView+ depends on / blocked
 
Reported: 2021-07-14 21:49 UTC by Ken Gaillot
Modified: 2024-12-20 20:28 UTC (History)
5 users (show)

Fixed In Version: pacemaker-2.1.0-4.el8
Doc Type: Bug Fix
Doc Text:
Cause: If a resource is unmanaged, Pacemaker sets actions for it to optional and skips a check that makes actions on pending nodes unrunnable. Consequence: Probes could wrongly be scheduled on pending nodes, and would time out. Fix: Make actions for pending nodes unrunnable before checking whether a resource is unmanaged. Result: Probes are scheduled after the pending node joins, and complete successfully.
Clone Of:
: 1983197 (view as bug list)
Environment:
Last Closed: 2021-11-09 18:44:54 UTC
Type: Bug
Target Upstream Version: 2.1.1
Embargoed:
pm-rhel: mirror+

Attachments (Terms of Use)


Links
System ID Private Priority Status Summary Last Updated
Red Hat Knowledge Base (Solution) 6529091 0 None None None 2021-11-19 17:31:12 UTC
Red Hat Product Errata RHEA-2021:4267 0 None None None 2021-11-09 18:45:16 UTC

Description Ken Gaillot 2021-07-14 21:49:39 UTC 
Description of problem: A cluster node can't run resources until it has completed the controller join process; until that time it is considered "pending". However, when a resource is unmanaged, Pacemaker can wrongly schedule probes for it on pending nodes.

Version-Release number of selected component (if applicable): any


How reproducible: Timing sensitive


Steps to Reproduce:
1. Configure and start a cluster of at least three nodes, then stop the cluster on one of the nodes.
2. Enable maintenance mode (pcs property set maintenance-mode=true), which will unmanage all resources.
3. Start the stopped node, and add a new resource to the configuration after the node has joined the Corosync membership but before it has completed the Pacemaker controller join sequence (i.e. while it is "pending").


Actual results: If the DC schedules probes for the new resource while the joining node is still pending, the probes will time out (after the probe timeout plus the value of cluster-delay).


Expected results: The DC does not schedule probes on the new node until it has finished joining, and the probes complete successfully.


Additional info: It might be possible to prolong the "pending" time by nice'ing pacmaker-controld on the joining node, or briefly SIGSTOP'ing it.
Comment 1 Reid Wahl 2021-07-16 01:33:19 UTC 
A few small clarification questions:


> when a resource is unmanaged, Pacemaker can wrongly schedule probes for it on pending nodes.

Is the issue (probes scheduled before the controller join is complete) reproducible only when a resource is unmanaged or the cluster is in maintenance mode? I want to confirm that the scope is limited to these situations, since probes do run when a node joins a cluster (without maintenance mode or unmanaged resources).

-----

> Configure and start a cluster of at least three nodes
> ...
> add a new resource to the configuration

I presume this is for easier/more reliable reproduction. As a record, the initial report occurred when the second node of a two-node cluster joined, with no new resources.

-----

(from email)
> I don't think there are any serious consequences, but if I'm
> overlooking something, let me know and I can raise it.

All I can think of is: If the node is still in pending state when a stop operation is scheduled in response to the failed probe, then the stop operation will also be lost and time out, causing fencing.

But if so, then that's a corner case within a corner case, the node is clearly having problems, and fencing might not be a bad thing.
Comment 2 Ken Gaillot 2021-07-16 15:14:20 UTC 
(In reply to Reid Wahl from comment #1)
> A few small clarification questions:
> 
> 
> > when a resource is unmanaged, Pacemaker can wrongly schedule probes for it on pending nodes.
> 
> Is the issue (probes scheduled before the controller join is complete)
> reproducible only when a resource is unmanaged or the cluster is in
> maintenance mode? I want to confirm that the scope is limited to these
> situations, since probes do run when a node joins a cluster (without
> maintenance mode or unmanaged resources).

Correct, it can only occur when the resource is unmanaged (whether directly or indirectly via maintenance mode).


> -----
> 
> > Configure and start a cluster of at least three nodes
> > ...
> > add a new resource to the configuration
> 
> I presume this is for easier/more reliable reproduction. As a record, the
> initial report occurred when the second node of a two-node cluster joined,
> with no new resources.
> 
> -----

That's what I was thinking, since it's timing-sensitive, but I'm not sure it will actually help vs. adding the resource beforehand. If we can prolong the joining period, the issue should occur regardless of whether the resource is new or pre-existing.


> (from email)
> > I don't think there are any serious consequences, but if I'm
> > overlooking something, let me know and I can raise it.
> 
> All I can think of is: If the node is still in pending state when a stop
> operation is scheduled in response to the failed probe, then the stop
> operation will also be lost and time out, causing fencing.
> 
> But if so, then that's a corner case within a corner case, the node is
> clearly having problems, and fencing might not be a bad thing.

Right, the probe timeout takes so long, that it would really unusual for a node to be pending that long. Of course, someone could tune the probe timeout and cluster-delay way down, but that would be highly unusual.
Comment 3 Ken Gaillot 2021-07-16 19:32:24 UTC 
Fixed upstream as of master branch commit b0347f7
Comment 10 Markéta Smazová 2021-09-02 16:52:57 UTC 
before fix:
-----------

I was unable to reproduce the issue on RHEL 8.4, but I was successful with RHEL 7.9:

>   [root@virt-123 ~]# rpm -q pacemaker
>   pacemaker-1.1.23-1.el7.x86_64


Setup 3 node cluster:

>   [root@virt-123 ~]# pcs status
>   Cluster name: STSRHTS26371
>   Stack: corosync
>   Current DC: virt-125 (version 1.1.23-1.el7-9acf116022) - partition with quorum
>   Last updated: Thu Sep  2 11:10:18 2021
>   Last change: Thu Sep  2 11:09:54 2021 by root via cibadmin on virt-123

>   3 nodes configured
>   3 resource instances configured

>   Online: [ virt-123 virt-124 virt-125 ]

>   Full list of resources:

>    fence-virt-123	(stonith:fence_xvm):	Started virt-123
>    fence-virt-124	(stonith:fence_xvm):	Started virt-124
>    fence-virt-125	(stonith:fence_xvm):	Started virt-125

>   Daemon Status:
>     corosync: active/disabled
>     pacemaker: active/disabled
>     pcsd: active/enabled


Enable maintenance mode:

>   [root@virt-123 ~]# pcs property set maintenance-mode=true


Stop the cluster on node "virt-124":

>   [root@virt-123 ~]# pcs cluster stop virt-124
>   virt-124: Stopping Cluster (pacemaker)...
>   virt-124: Stopping Cluster (corosync)...

>   [root@virt-123 ~]# pcs status
>   Cluster name: STSRHTS26371
>   Stack: corosync
>   Current DC: virt-125 (version 1.1.23-1.el7-9acf116022) - partition with quorum
>   Last updated: Thu Sep  2 11:11:04 2021
>   Last change: Thu Sep  2 11:10:32 2021 by root via cibadmin on virt-123

>   3 nodes configured
>   3 resource instances configured

>                 *** Resource management is DISABLED ***
>     The cluster will not attempt to start, stop or recover services

>   Online: [ virt-123 virt-125 ]
>   OFFLINE: [ virt-124 ]

>   Full list of resources:

>    fence-virt-123	(stonith:fence_xvm):	Started virt-123 (unmanaged)
>    fence-virt-124	(stonith:fence_xvm):	Started virt-124 (unmanaged)
>    fence-virt-125	(stonith:fence_xvm):	Started virt-125 (unmanaged)

>   Daemon Status:
>     corosync: active/disabled
>     pacemaker: active/disabled
>     pcsd: active/enabled


Start cluster on the node "virt-124" again and add a new resource "dummy1" while the node "virt-124" is joining the cluster:

>   [root@virt-123 ~]# pcs cluster start virt-124 &>/dev/null & sleep 2.3; pcs resource create dummy1 ocf:pacemaker:Dummy
>   [1] 13231
>   [1]+  Done                    pcs cluster start virt-124 &>/dev/null


Since maintenance mode is still enabled, new resource "dummy1" remains stopped:

>   [root@virt-123 ~]# crm_mon -1rf
>   Stack: corosync
>   Current DC: virt-125 (version 1.1.23-1.el7-9acf116022) - partition with quorum
>   Last updated: Thu Sep  2 11:11:32 2021
>   Last change: Thu Sep  2 11:11:26 2021 by root via cibadmin on virt-123

>   3 nodes configured
>   4 resource instances configured

>                 *** Resource management is DISABLED ***
>     The cluster will not attempt to start, stop or recover services

>   Node virt-124: pending
>   Online: [ virt-123 virt-125 ]

>   Full list of resources:

>    fence-virt-123	(stonith:fence_xvm):	Started virt-123 (unmanaged)
>    fence-virt-124	(stonith:fence_xvm):	Started virt-124 (unmanaged)
>    fence-virt-125	(stonith:fence_xvm):	Started virt-125 (unmanaged)
>    dummy1	(ocf::pacemaker:Dummy):	Stopped (unmanaged)

>   Migration Summary:
>   * Node virt-123:
>   * Node virt-124:
>   * Node virt-125:


After few minutes "dummy1" fails and "fence-virt-124" is stopped:

>   [root@virt-123 ~]# crm_mon -1rf
>   Stack: corosync
>   Current DC: virt-125 (version 1.1.23-1.el7-9acf116022) - partition with quorum
>   Last updated: Thu Sep  2 11:12:47 2021
>   Last change: Thu Sep  2 11:11:26 2021 by root via cibadmin on virt-123

>   3 nodes configured
>   4 resource instances configured

>                 *** Resource management is DISABLED ***
>     The cluster will not attempt to start, stop or recover services

>   Online: [ virt-123 virt-124 virt-125 ]

>   Full list of resources:

>    fence-virt-123	(stonith:fence_xvm):	Started virt-123 (unmanaged)
>    fence-virt-124	(stonith:fence_xvm):	Stopped (unmanaged)
>    fence-virt-125	(stonith:fence_xvm):	Started virt-125 (unmanaged)
>    dummy1	(ocf::pacemaker:Dummy):	FAILED virt-124 (unmanaged)

>   Migration Summary:
>   * Node virt-123:
>   * Node virt-124:
>   * Node virt-125:

>   Failed Resource Actions:
>   * dummy1_monitor_0 on virt-124 'unknown error' (1): call=-1, status=Timed Out, exitreason='',
>       last-rc-change='Thu Sep  2 11:12:46 2021', queued=0ms, exec=0ms


Both corosync.log and messages logged "Processing failed probe" warning:

Log excerpts:

>   [root@virt-125 ~]# tail -f /var/log/cluster/corosync.log | grep probe
>   Sep 02 11:11:26 [4014] virt-125.cluster-qe.lab.eng.brq.redhat.com       crmd:   notice: process_lrm_event:	Result of probe operation for dummy1 on virt-125: 7 (not running) | call=54 key=dummy1_monitor_0 confirmed=true cib-update=167
>   Sep 02 11:12:47 [4013] virt-125.cluster-qe.lab.eng.brq.redhat.com    pengine:  warning: unpack_rsc_op_failure:	Processing failed probe of dummy1 on virt-124: unknown error | rc=1
>   Sep 02 11:12:47 [4013] virt-125.cluster-qe.lab.eng.brq.redhat.com    pengine:  warning: unpack_rsc_op_failure:	Processing failed probe of dummy1 on virt-124: unknown error | rc=1
>   Sep 02 11:15:51 [4013] virt-125.cluster-qe.lab.eng.brq.redhat.com    pengine:  warning: unpack_rsc_op_failure:	Processing failed probe of dummy1 on virt-124: unknown error | rc=1
>   Sep 02 11:15:51 [4013] virt-125.cluster-qe.lab.eng.brq.redhat.com    pengine:  warning: unpack_rsc_op_failure:	Processing failed probe of dummy1 on virt-124: unknown error | rc=1


>   [root@virt-125 ~]# tail -f /var/log/messages | grep probe
>   Sep  2 11:11:26 virt-125 crmd[4014]:  notice: Result of probe operation for dummy1 on virt-125: 7 (not running)
>   Sep  2 11:12:47 virt-125 pengine[4013]: warning: Processing failed probe of dummy1 on virt-124: unknown error
>   Sep  2 11:12:47 virt-125 pengine[4013]: warning: Processing failed probe of dummy1 on virt-124: unknown error
>   Sep  2 11:15:51 virt-125 pengine[4013]: warning: Processing failed probe of dummy1 on virt-124: unknown error
>   Sep  2 11:15:51 virt-125 pengine[4013]: warning: Processing failed probe of dummy1 on virt-124: unknown error



after fix:
----------

>   [root@virt-520 ~]# rpm -q pacemaker
>   pacemaker-2.1.0-6.el8.x86_64

Setup 3 node cluster:

>   [root@virt-520 ~]# pcs status
>   Cluster name: STSRHTS27666
>   Cluster Summary:
>     * Stack: corosync
>     * Current DC: virt-522 (version 2.1.0-6.el8-7c3f660707) - partition with quorum
>     * Last updated: Thu Sep  2 16:06:36 2021
>     * Last change:  Thu Sep  2 15:55:38 2021 by root via cibadmin on virt-520
>     * 3 nodes configured
>     * 3 resource instances configured

>   Node List:
>     * Online: [ virt-520 virt-522 virt-538 ]

>   Full List of Resources:
>     * fence-virt-520	(stonith:fence_xvm):	 Started virt-520
>     * fence-virt-522	(stonith:fence_xvm):	 Started virt-522
>     * fence-virt-538	(stonith:fence_xvm):	 Started virt-538

>   Daemon Status:
>     corosync: active/disabled
>     pacemaker: active/disabled
>     pcsd: active/enabled


Enable maintenance mode:

>   [root@virt-520 ~]# pcs property set maintenance-mode=true


Stop the cluster on node "virt-538":

>   [root@virt-520 16:07:13 ~]# pcs cluster stop virt-538
>   virt-538: Stopping Cluster (pacemaker)...
>   virt-538: Stopping Cluster (corosync)...

>   [root@virt-520 16:07:54 ~]# pcs status
>   Cluster name: STSRHTS27666
>   Cluster Summary:
>     * Stack: corosync
>     * Current DC: virt-522 (version 2.1.0-6.el8-7c3f660707) - partition with quorum
>     * Last updated: Thu Sep  2 16:07:59 2021
>     * Last change:  Thu Sep  2 16:06:51 2021 by root via cibadmin on virt-520
>     * 3 nodes configured
>     * 3 resource instances configured

>                 *** Resource management is DISABLED ***
>     The cluster will not attempt to start, stop or recover services

>   Node List:
>     * Online: [ virt-520 virt-522 ]
>     * OFFLINE: [ virt-538 ]

>   Full List of Resources:
>     * fence-virt-520	(stonith:fence_xvm):	 Started virt-520 (unmanaged)
>     * fence-virt-522	(stonith:fence_xvm):	 Started virt-522 (unmanaged)
>     * fence-virt-538	(stonith:fence_xvm):	 Started virt-538 (unmanaged)

>   Daemon Status:
>     corosync: active/disabled
>     pacemaker: active/disabled
>     pcsd: active/enabled


Start cluster on the node "virt-538" again and add a new resource "dummy1" while the node "virt-538" is joining the cluster:

>   [root@virt-520 16:07:59 ~]# pcs cluster start virt-538 &>/dev/null & sleep 2.3; pcs resource create dummy1 ocf:pacemaker:Dummy
>   [1] 887919
>   [1]+  Done                    pcs cluster start virt-538 &> /dev/null


Maintenance mode is still enabled, new resource "dummy1" remains stopped, but doesn't fail:

>   [root@virt-520 16:08:29 ~]# pcs status
>   Cluster name: STSRHTS27666
>   Cluster Summary:
>     * Stack: corosync
>     * Current DC: virt-522 (version 2.1.0-6.el8-7c3f660707) - partition with quorum
>     * Last updated: Thu Sep  2 16:08:32 2021
>     * Last change:  Thu Sep  2 16:08:29 2021 by root via cibadmin on virt-520
>     * 3 nodes configured
>     * 4 resource instances configured

>                 *** Resource management is DISABLED ***
>     The cluster will not attempt to start, stop or recover services

>   Node List:
>     * Online: [ virt-520 virt-522 virt-538 ]

>   Full List of Resources:
>     * fence-virt-520	(stonith:fence_xvm):	 Started virt-520 (unmanaged)
>     * fence-virt-522	(stonith:fence_xvm):	 Started virt-522 (unmanaged)
>     * fence-virt-538	(stonith:fence_xvm):	 Stopped (unmanaged)
>     * dummy1	(ocf::pacemaker:Dummy):	 Stopped (unmanaged)

>   Daemon Status:
>     corosync: active/disabled
>     pacemaker: active/disabled
>     pcsd: active/enabled


Pacemaker.log and messages logged probe request and notice "Result of probe operation for dummy1 on virt-522: not running" 
and did not log any "failed probe" warning:

Log excerpts:

>   [root@virt-522 ~]# tail -f /var/log/pacemaker/pacemaker.log | grep probe
>   Sep 02 16:08:29 virt-522 pacemaker-controld  [887634] (do_lrm_rsc_op) 	notice: Requesting local execution of probe operation for dummy1 on virt-522 | transition_key=2:6:7:86e56de2-ff7a-45eb-b666-00effc552e44 op_key=dummy1_monitor_0
>   Sep 02 16:08:29 virt-522 pacemaker-controld  [887634] (process_lrm_event) 	notice: Result of probe operation for dummy1 on virt-522: not running | rc=7 call=24 key=dummy1_monitor_0 confirmed=true cib-update=105

>   [root@virt-522 ~]# tail -f /var/log/messages | grep probe
>   Sep  2 16:08:29 virt-522 pacemaker-controld[887634]: notice: Requesting local execution of probe operation for dummy1 on virt-522
>   Sep  2 16:08:29 virt-522 pacemaker-controld[887634]: notice: Result of probe operation for dummy1 on virt-522: not running


Since there was no success in reproducing the issue in RHEL 8.4., marking verified as SanityOnly in pacemaker-2.1.0-6.el8
Comment 12 errata-xmlrpc 2021-11-09 18:44:54 UTC 
Since the problem described in this bug report should be
resolved in a recent advisory, it has been closed with a
resolution of ERRATA.

For information on the advisory (pacemaker bug fix and enhancement update), and where to find the updated
files, follow the link below.

If the solution does not work for you, open a new bug report.

https://access.redhat.com/errata/RHEA-2021:4267
Note You need to log in before you can comment on or make changes to this bug.