Note: This bug is displayed in read-only format because the product is no longer active in Red Hat Bugzilla.
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 1843177

Summary: RFE - pingd resource logging is not very verbose
Product: Red Hat Enterprise Linux 8 Reporter: David Wood <dwood>
Component: pacemakerAssignee: gchin
Status: CLOSED ERRATA QA Contact: cluster-qe <cluster-qe>
Severity: low Docs Contact:
Priority: medium    
Version: 8.0CC: agk, cluster-maint, fdinitto, gvaughn, kgaillot, lmiksik, msmazova, sbradley
Target Milestone: rcKeywords: FutureFeature, Triaged
Target Release: 8.5Flags: pm-rhel: mirror+
Hardware: All   
OS: All   
Whiteboard:
Fixed In Version: pacemaker-2.1.0-1.el8 Doc Type: Enhancement
Doc Text:
Feature: The ocf:pacemaker:ping resource now supports setting the debug parameter to 2 to get highly detailed log messages. Reason: Setting debug to 1 (or true) will log ping failures and attribute changes, but not the result of each individual ping, which could be helpful when troubleshooting certain situations. Result: Setting the debug parameter to 2 will now get individual ping status sent to the logs.
 Story Points: ---
Clone Of: Environment:
Last Closed: 2021-11-09 18:44:49 UTC Type: Enhancement
Regression: --- Mount Type: ---
Documentation: --- CRM:
Verified Versions: Category: ---
oVirt Team: --- RHEL 7.3 requirements from Atomic Host:
Cloudforms Team: --- Target Upstream Version:
Embargoed:

Description David Wood 2020-06-02 18:29:17 UTC 
Description of problem:
pingd resource logging is not very verbose with debug mode on.  It would be helpful to have a setting that would log every ping attempt to assist with trouble shooting problems around the pingd resource.  

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


How reproducible:
Always

Steps to Reproduce:
1. Create and configure a pingd resource


Actual results:
Logs contain failover information if pingd resource fails only

Expected results:
Have an option to enable extra logging to be able to see successful pings, failed pings, and the return code of ping within the resource agent.  

Additional info:
pingd can be configured to have a longing timeout and more pings sent before ping will fail.  These "extra" pings seem to be part of the ping command itself but it would be helpful to know how many of these pings were successful and how many did not receive a reply.
Comment 3 Grimm 2020-09-25 21:07:25 UTC 
What is the current status of this bugzilla?
Comment 4 Ken Gaillot 2020-09-25 21:46:46 UTC 
This will likely make the 8.4 release. (I hadn't noticed before that this was filed against RHEL 7, which is not getting new features at this stage of its lifecycle.)
Comment 6 Ken Gaillot 2020-10-20 20:56:21 UTC 
Due to limited QA capacity, this needs to be moved back to 8.5
Comment 10 Ken Gaillot 2021-04-28 18:26:18 UTC 
The original reporter no longer has an account, so I'm making some assumptions about the request.

Regardless of the value of the "debug" parameter, the ocf:pacemaker:ping agent will currently log an error message if the ping command exits with an error such as an invalid IP address (as opposed to not getting a reply). This log will have the ping command's exit status and output.

If "debug" is set to "true", and the ping command does not get a reply, the agent will currently log a warning with the ping command's output. The exit status is always 1 in this case, so it is not logged.

I assume the request here is to be able to log the ping command output even if a ping is received. This could particularly be useful if some of the individual pings got a reply and some didn't. I'm thinking we can do this if "debug" is set to "verbose", and that's what this BZ will track.
Comment 13 gchin 2021-05-13 14:09:35 UTC 
This PR adds more verbose logging: https://github.com/ClusterLabs/pacemaker/pull/2372
Comment 19 Markéta Smazová 2021-08-12 12:27:59 UTC 
>   [root@virt-520 16:25:03 ~]# rpm -q pacemaker
>   pacemaker-2.1.0-3.el8.x86_64

Setup a cluster and setup a `ocf:pacemaker:ping` resource. Use an invalid IP address in `host_list`, leave `debug`
option to default setting 0 (or "false").

>   [root@virt-520 16:25:07 ~]# pcs resource create ping1 ocf:pacemaker:ping host_list="10.37.166."

Resource is started, but since the IP address is invalid, it can't connect to any nodes:

>   [root@virt-520 16:25:18 ~]# crm_mon -rfA1
>   Cluster Summary:
>     * Stack: corosync
>     * Current DC: virt-520 (version 2.1.0-3.el8-7c3f660707) - partition with quorum
>     * Last updated: Wed Aug 11 16:25:33 2021
>     * Last change:  Wed Aug 11 16:25:17 2021 by root via cibadmin on virt-520
>     * 2 nodes configured
>     * 3 resource instances configured

>   Node List:
>     * Online: [ virt-520 virt-521 ]

>   Full List of Resources:
>     * fence-virt-520	(stonith:fence_xvm):	 Started virt-520
>     * fence-virt-521	(stonith:fence_xvm):	 Started virt-521
>     * ping1	(ocf::pacemaker:ping):	 Started virt-520

>   Node Attributes:
>     * Node: virt-520:
>       * pingd                           	: 0         	: Connectivity is lost

>   Migration Summary:


The `ocf:pacemaker:ping` agent logs an error message with the ping command's exit status and output:

    /var/log/pacemaker/pacemaker.log excerpts:

>   Aug 11 16:25:18  ping(ping1)[1312442]:    ERROR: Unexpected result for 'ping -n -q -W 18 -c 3  10.37.166.' 2: ping: 10.37.166.: Name or service not known
>   Aug 11 16:25:28  ping(ping1)[1312476]:    ERROR: Unexpected result for 'ping -n -q -W 18 -c 3  10.37.166.' 2: ping: 10.37.166.: Name or service not known
>   Aug 11 16:25:38  ping(ping1)[1312508]:    ERROR: Unexpected result for 'ping -n -q -W 18 -c 3  10.37.166.' 2: ping: 10.37.166.: Name or service not known

    /var/log/messages excerpts:

>   Aug 11 16:25:18 virt-520 ping(ping1)[1312442]: ERROR: Unexpected result for 'ping -n -q -W 18 -c 3  10.37.166.' 2: ping: 10.37.166.: Name or service not known
>   Aug 11 16:25:28 virt-520 ping(ping1)[1312476]: ERROR: Unexpected result for 'ping -n -q -W 18 -c 3  10.37.166.' 2: ping: 10.37.166.: Name or service not known
>   Aug 11 16:25:38 virt-520 ping(ping1)[1312508]: ERROR: Unexpected result for 'ping -n -q -W 18 -c 3  10.37.166.' 2: ping: 10.37.166.: Name or service not known

Agent records (in the CIB) the current number of nodes the host can connect to:

>   Aug 11 16:25:23 virt-521 pacemaker-attrd     [1142470] (attrd_cib_callback) 	info: * pingd[virt-520]=0


Set `debug` to 1 (or "true") and update `host_list` with a valid IP address of a node, that is currently offline:

>   [root@virt-520 16:25:33 ~]# pcs resource update ping1 debug=1 host_list=10.37.166.190

>   [root@virt-520 16:29:59 ~]# crm_mon -rfA1
>   Cluster Summary:
>     * Stack: corosync
>     * Current DC: virt-520 (version 2.1.0-3.el8-7c3f660707) - partition with quorum
>     * Last updated: Wed Aug 11 16:30:02 2021
>     * Last change:  Wed Aug 11 16:29:41 2021 by root via cibadmin on virt-520
>     * 2 nodes configured
>     * 3 resource instances configured

>   Node List:
>     * Online: [ virt-520 virt-521 ]

>   Full List of Resources:
>     * fence-virt-520	(stonith:fence_xvm):	 Started virt-520
>     * fence-virt-521	(stonith:fence_xvm):	 Started virt-521
>     * ping1	(ocf::pacemaker:ping):	 Started virt-520

>   Node Attributes:
>     * Node: virt-520:
>       * pingd                           	: 0         	: Connectivity is lost

>   Migration Summary:

If `debug` is set to 1, and the ping command does not get a reply, the agent will log a warning with the ping 
command's output. The exit status is always 1 in this case, so it is not logged.

    /var/log/pacemaker/pacemaker.log excerpts:

>   Aug 11 16:29:48  ping(ping1)[1313630]:    WARNING: 10.37.166.190 is inactive: PING 10.37.166.190 (10.37.166.190) 56(84) bytes of data.

>   --- 10.37.166.190 ping statistics ---
>   3 packets transmitted, 0 received, +3 errors, 100% packet loss, time 2066ms
>   pipe 3
>   Aug 11 16:30:01  ping(ping1)[1313662]:    WARNING: 10.37.166.190 is inactive: PING 10.37.166.190 (10.37.166.190) 56(84) bytes of data.

>   --- 10.37.166.190 ping statistics ---
>   3 packets transmitted, 0 received, +3 errors, 100% packet loss, time 2038ms
>   pipe 3
>   Aug 11 16:30:14  ping(ping1)[1313696]:    WARNING: 10.37.166.190 is inactive: PING 10.37.166.190 (10.37.166.190) 56(84) bytes of data.

>   --- 10.37.166.190 ping statistics ---
>   3 packets transmitted, 0 received, +3 errors, 100% packet loss, time 2042ms
>   pipe 3

>   Aug 11 16:29:50 virt-521 pacemaker-attrd     [1142470] (attrd_cib_callback) 	info: * pingd[virt-520]=0
>   Aug 11 16:30:56 virt-521 pacemaker-attrd     [1142470] (attrd_cib_callback) 	info: * pingd[virt-520]=0

    /var/log/messages excerpts:

>   Aug 11 16:29:48 virt-520 ping(ping1)[1313630]: WARNING: 10.37.166.190 is inactive: PING 10.37.166.190 (10.37.166.190) 56(84) bytes of data.#012#012--- 10.37.166.190 ping statistics ---#0123 packets transmitted, 0 received, +3 errors, 100% packet loss, time 2066ms#012pipe 3
>   Aug 11 16:29:48 virt-520 pacemaker-controld[1310410]: notice: Result of monitor operation for ping1 on virt-520: ok
>   Aug 11 16:30:01 virt-520 ping(ping1)[1313662]: WARNING: 10.37.166.190 is inactive: PING 10.37.166.190 (10.37.166.190) 56(84) bytes of data.#012#012--- 10.37.166.190 ping statistics ---#0123 packets transmitted, 0 received, +3 errors, 100% packet loss, time 2038ms#012pipe 3
>   Aug 11 16:30:14 virt-520 ping(ping1)[1313696]: WARNING: 10.37.166.190 is inactive: PING 10.37.166.190 (10.37.166.190) 56(84) bytes of data.#012#012--- 10.37.166.190 ping statistics ---#0123 packets transmitted, 0 received, +3 errors, 100% packet loss, time 2042ms#012pipe 3


Set `debug` to 2 (or "verbose") and update `host_list` with a valid IP address of the second node in cluster virt-521:

>   [root@virt-520 16:30:13 ~]# pcs resource update ping1 debug=2 host_list=10.37.165.169
>   [root@virt-520 16:32:24 ~]# crm_mon -rfA1
>   Cluster Summary:
>     * Stack: corosync
>     * Current DC: virt-520 (version 2.1.0-3.el8-7c3f660707) - partition with quorum
>     * Last updated: Wed Aug 11 16:32:44 2021
>     * Last change:  Wed Aug 11 16:32:23 2021 by root via cibadmin on virt-520
>     * 2 nodes configured
>     * 3 resource instances configured

>   Node List:
>     * Online: [ virt-520 virt-521 ]

>   Full List of Resources:
>     * fence-virt-520	(stonith:fence_xvm):	 Started virt-520
>     * fence-virt-521	(stonith:fence_xvm):	 Started virt-521
>     * ping1	(ocf::pacemaker:ping):	 Started virt-520

>   Node Attributes:
>     * Node: virt-520:
>       * pingd                           	: 1         

>   Migration Summary:

>   [root@virt-520 16:32:44 ~]# pcs resource config ping1
>    Resource: ping1 (class=ocf provider=pacemaker type=ping)
>     Attributes: debug=2 host_list=10.37.165.169
>     Operations: monitor interval=10s timeout=60s (ping1-monitor-interval-10s)
>                 start interval=0s timeout=60s (ping1-start-interval-0s)
>                 stop interval=0s timeout=20s (ping1-stop-interval-0s)


Setting the `debug` parameter to 2 will now get individual ping status sent to the logs:

    /var/log/pacemaker/pacemaker.log excerpts:

>   Aug 11 16:32:29  ping(ping1)[1314270]:    INFO: PING 10.37.165.169 (10.37.165.169) 56(84) bytes of data.

>   --- 10.37.165.169 ping statistics ---
>   3 packets transmitted, 3 received, 0% packet loss, time 2052ms
>   rtt min/avg/max/mdev = 0.226/0.360/0.569/0.150 ms
>   Aug 11 16:32:41  ping(ping1)[1314303]:    INFO: PING 10.37.165.169 (10.37.165.169) 56(84) bytes of data.

>   --- 10.37.165.169 ping statistics ---
>   3 packets transmitted, 3 received, 0% packet loss, time 2044ms
>   rtt min/avg/max/mdev = 0.192/0.230/0.303/0.054 ms
>   Aug 11 16:32:53  ping(ping1)[1314338]:    INFO: PING 10.37.165.169 (10.37.165.169) 56(84) bytes of data.

>   --- 10.37.165.169 ping statistics ---
>   3 packets transmitted, 3 received, 0% packet loss, time 2045ms
>   rtt min/avg/max/mdev = 0.207/0.247/0.328/0.059 ms


>   Aug 11 16:32:32 virt-521 pacemaker-attrd     [1142470] (attrd_cib_callback) 	info: * pingd[virt-520]=1


    /var/log/messages excerpts:

>   Aug 11 16:32:29 virt-520 ping(ping1)[1314270]: INFO: PING 10.37.165.169 (10.37.165.169) 56(84) bytes of data.#012#012--- 10.37.165.169 ping statistics ---#0123 packets transmitted, 3 received, 0% packet loss, time 2052ms#012rtt min/avg/max/mdev = 0.226/0.360/0.569/0.150 ms
>   Aug 11 16:32:29 virt-520 pacemaker-controld[1310410]: notice: Result of monitor operation for ping1 on virt-520: ok
>   Aug 11 16:32:41 virt-520 ping(ping1)[1314303]: INFO: PING 10.37.165.169 (10.37.165.169) 56(84) bytes of data.#012#012--- 10.37.165.169 ping statistics ---#0123 packets transmitted, 3 received, 0% packet loss, time 2044ms#012rtt min/avg/max/mdev = 0.192/0.230/0.303/0.054 ms
>   Aug 11 16:32:53 virt-520 ping(ping1)[1314338]: INFO: PING 10.37.165.169 (10.37.165.169) 56(84) bytes of data.#012#012--- 10.37.165.169 ping statistics ---#0123 packets transmitted, 3 received, 0% packet loss, time 2045ms#012rtt min/avg/max/mdev = 0.207/0.247/0.328/0.059 ms



marking verified in pacemaker-2.1.0-3.el8
Comment 21 errata-xmlrpc 2021-11-09 18:44:49 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