[ClusterLabs] Q: Starting from pcs-0.10.6-4.el8, logs of pcsd are now output to syslog

Thu Jan 7 11:49:25 EST 2021

Hi,

It took us some time to figure this out, sorry about that.

The behavior you see is not intended, it is a bug. The bug originates in 
commit 966959ac54d80c4cdeeb0fac40dc7ea60c1a0a82, more specifically in 
this line in pcs/run.py:
from pcs.app import main as cli

The pcs/app.py file is responsible for starting pcs CLI. The pcs/run.py 
file is responsible for starting pcs daemon, pcs CLI and pcs SNMP agent 
in a unified way and it serves as an entry point. Importing pcs.app 
caused logging.basicConfig(), which is called in pcs/app.py, to be 
executed when starting pcs daemon and pcs SNMP agent. This 
unintentionally configured loggers in pcs daemon and pcs SNMP agent to 
log into stderr and those logs then got propagated to system log and 
/var/log/messages.

To fix the bug, logging.basicConfig() should be removed from pcs/app.py, 
the line is actually not needed at all. The fix is available upstream in 
commit ddb0d3fed3273181356cd638d724b891ecd78263.

Regards,
Tomas

Dne 23. 12. 20 v 5:25 井上和徳 napsal(a):
> Hi!
> 
> Is it a specification that pcsd (pcs-0.10.6-4.el8) outputs logs to syslog?
> If it is a specification, which change/commit is it due to?
> 
> # rpm -q pcs
> pcs-0.10.6-4.el8.x86_64
> #
> # cat /var/log/pcsd/pcsd.log
> I, [2020-12-23T13:17:36.748 #00010]     INFO -- : Starting Daemons
> I, [2020-12-23T13:17:36.749 #00010]     INFO -- : Running:
> /usr/sbin/pcs cluster start
> I, [2020-12-23T13:17:36.749 #00010]     INFO -- : CIB USER: hacluster, groups:
> I, [2020-12-23T13:17:39.749 #00010]     INFO -- : Return Value: 0
> I, [2020-12-23T13:17:39.749 #00000]     INFO -- : 200 GET
> /remote/cluster_start (192.168.122.247) 3243.41ms
> I, [2020-12-23T13:18:47.049 #00000]     INFO -- : 200 GET
> /remote/get_configs?cluster_name=my_cluster (192.168.122.140) 4.05ms
> I, [2020-12-23T13:18:47.060 #00011]     INFO -- : Config files sync started
> I, [2020-12-23T13:18:47.061 #00011]     INFO -- : SRWT Node: rhel83-2
> Request: get_configs
> I, [2020-12-23T13:18:47.061 #00011]     INFO -- : Connecting to:
> https://192.168.122.140:2224/remote/get_configs?cluster_name=my_cluster
> I, [2020-12-23T13:18:47.061 #00011]     INFO -- : SRWT Node: rhel83-1
> Request: get_configs
> I, [2020-12-23T13:18:47.061 #00011]     INFO -- : Connecting to:
> https://192.168.122.247:2224/remote/get_configs?cluster_name=my_cluster
> I, [2020-12-23T13:18:47.061 #00011]     INFO -- : Config files sync finished
> #
> # grep pcs /var/log/messages
> Dec 23 13:17:39 rhel83-2 <daemon.info>
> pcsd[600350]:INFO:pcs.daemon:Starting Daemons
> Dec 23 13:17:39 rhel83-2 <daemon.info>
> pcsd[600350]:INFO:pcs.daemon:Running: /usr/sbin/pcs cluster start
> Dec 23 13:17:39 rhel83-2 <daemon.info>
> pcsd[600350]:INFO:pcs.daemon:CIB USER: hacluster, groups:
> Dec 23 13:17:39 rhel83-2 <daemon.info>
> pcsd[600350]:INFO:pcs.daemon:Return Value: 0
> Dec 23 13:17:39 rhel83-2 <daemon.info>
> pcsd[600350]:INFO:tornado.access:200 GET /remote/cluster_start
> (192.168.122.247) 3243.41ms
> Dec 23 13:18:47 rhel83-2 <daemon.info>
> pcsd[600350]:INFO:tornado.access:200 GET
> /remote/get_configs?cluster_name=my_cluster (192.168.122.140) 4.05ms
> Dec 23 13:18:47 rhel83-2 <daemon.info>
> pcsd[600350]:INFO:pcs.daemon:Config files sync started
> Dec 23 13:18:47 rhel83-2 <daemon.info>
> pcsd[600350]:INFO:pcs.daemon:SRWT Node: rhel83-2 Request: get_configs
> Dec 23 13:18:47 rhel83-2 <daemon.info>
> pcsd[600350]:INFO:pcs.daemon:Connecting to:
> https://192.168.122.140:2224/remote/get_configs?cluster_name=my_cluster
> Dec 23 13:18:47 rhel83-2 <daemon.info>
> pcsd[600350]:INFO:pcs.daemon:SRWT Node: rhel83-1 Request: get_configs
> Dec 23 13:18:47 rhel83-2 <daemon.info>
> pcsd[600350]:INFO:pcs.daemon:Connecting to:
> https://192.168.122.247:2224/remote/get_configs?cluster_name=my_cluster
> Dec 23 13:18:47 rhel83-2 <daemon.info>
> pcsd[600350]:INFO:pcs.daemon:Config files sync finished
> #
> 
> Up to pcs-0.10.4-6.el8, there was no output to syslog.
> 
> # rpm -q pcs
> pcs-0.10.4-6.el8.x86_64
> #
> # cat /var/log/pcsd/pcsd.log
> I, [2020-12-23T13:17:36.059 #01200]     INFO -- : Starting Daemons
> I, [2020-12-23T13:17:36.060 #01200]     INFO -- : Running:
> /usr/sbin/pcs cluster start
> I, [2020-12-23T13:17:36.060 #01200]     INFO -- : CIB USER: hacluster, groups:
> I, [2020-12-23T13:17:38.060 #01200]     INFO -- : Return Value: 0
> I, [2020-12-23T13:17:38.060 #00000]     INFO -- : 200 GET
> /remote/cluster_start (192.168.122.247) 1650.38ms
> I, [2020-12-23T13:18:46.991 #00000]     INFO -- : 200 GET
> /remote/get_configs?cluster_name=my_cluster (192.168.122.140) 5.06ms
> I, [2020-12-23T13:18:58.053 #00000]     INFO -- : 200 GET
> /remote/get_configs?cluster_name=my_cluster (192.168.122.247) 5.74ms
> I, [2020-12-23T13:18:58.064 #01201]     INFO -- : Config files sync started
> I, [2020-12-23T13:18:58.064 #01201]     INFO -- : SRWT Node: rhel83-2
> Request: get_configs
> I, [2020-12-23T13:18:58.064 #01201]     INFO -- : Connecting to:
> https://192.168.122.140:2224/remote/get_configs?cluster_name=my_cluster
> I, [2020-12-23T13:18:58.064 #01201]     INFO -- : SRWT Node: rhel83-1
> Request: get_configs
> I, [2020-12-23T13:18:58.064 #01201]     INFO -- : Connecting to:
> https://192.168.122.247:2224/remote/get_configs?cluster_name=my_cluster
> I, [2020-12-23T13:18:58.065 #01201]     INFO -- : Config files sync finished
> #
> # grep pcs /var/log/messages
> #
> 
> Regards,
> Kazunori INOUE
> 
> 
> _______________________________________________
> Manage your subscription:
> https://lists.clusterlabs.org/mailman/listinfo/users
> 
> ClusterLabs home: https://www.clusterlabs.org/
> 