Bug 1687523

Summary: when /var/log/rhsm/ is missing, subscription-manager outputs rhsm logs on terminal.
Product: Red Hat Enterprise Linux 8 Reporter: jcastran
Component: subscription-managerAssignee: Jiri Hnidek <jhnidek>
Status: CLOSED ERRATA QA Contact: Red Hat subscription-manager QE Team <rhsm-qe>
Severity: high Docs Contact:
Priority: low    
Version: 8.1CC: cdonnell, csnyder, eda, ed, jhnidek, kwalker, mbliss, redakkan, skallesh
Target Milestone: rcKeywords: Reopened, Triaged
Target Release: ---   
Hardware: All   
OS: All   
Whiteboard:
Fixed In Version: subscription-manager-1.26.5-1 Doc Type: If docs needed, set a value
Doc Text:
Story Points: ---
Clone Of: Environment:
Last Closed: 2020-04-28 16:54:49 UTC Type: Bug
Regression: --- Mount Type: ---
Documentation: --- CRM:
Verified Versions: Category: ---
oVirt Team: --- RHEL 7.3 requirements from Atomic Host:
Cloudforms Team: --- Target Upstream Version:
Embargoed:

Description jcastran 2019-03-11 16:31:01 UTC
This bug was initially created as a copy of Bug #1686920

I am copying this bug because: 
This also occurs in RHEL 8


Description of problem:
when /var/log/rhsm/ is missing, subscription-manager outputs rhsm logs on terminal.

Everytime yum is called, it calls the subscription-manager plugin and the output can be extremely excessive. This can even stop ansible which will fail when too much yum output is seen.

Version-Release number of selected component (if applicable):
subscription-manager-1.21.10-3.el7_6.x86_64

How reproducible:
Everytime

Steps to Reproduce:
1. mv /var/log/rhsm/ .
2. yum repolist

Actual results:
Loaded plugins: langpacks, product-id, search-disabled-repos, subscription-
              : manager
2019-01-23 07:26:48,781 [INFO] yum:23157:MainThread @connection.py:871 - Connection built: http_proxy=intsquid.imf.org:8080 host=subscription.rhn.redhat.com port=443 handler=/subscription auth=identity_cert ca_dir=/etc/rhsm/ca/ insecure=True
2019-01-23 07:26:48,802 [INFO] yum:23157:MainThread @connection.py:871 - Connection built: http_proxy=intsquid.imf.org:8080 host=subscription.rhn.redhat.com port=443 handler=/subscription auth=identity_cert ca_dir=/etc/rhsm/ca/ insecure=True
2019-01-23 07:26:49,092 [INFO] yum:23157:MainThread @connection.py:588 - Response: status=200, request="GET /subscription/"
''
repo id                           repo name                               status
rhel-7-server-rpms/7Server/x86_64 Red Hat Enterprise Linux 7 Server (RPMs 23382
repolist: 23382


Expected results:
repo id                           repo name                               status
rhel-7-server-rpms/7Server/x86_64 Red Hat Enterprise Linux 7 Server (RPMs 23382
repolist: 23382

AND /var/log/rhsm/ gets created so subscription-manager can log properly.

Additional info:
rpm -Va does show the directory as missing. reinstalling the subscription-manager package will resolve this issue. Depending on the entitlements this output can be extremely verbose and all caused by a missing directory that it should either create if needed, or log straight to /var/log/ instead of /var/log/rhsm/.

Comment 5 Chris Snyder 2019-03-22 15:17:16 UTC
To address this we have agreed on adding an extra log message to indicate that the standard log file (/var/log/rhsm/rhsm.log) could not be written to and that further log output will be to stdout/stderr.
This should help others in the future as a diagnostic step to determine the root cause of the strange log output.

I would also advise any folks seeing this issue to see the attached knowledge base solution: https://access.redhat.com/solutions/3569241

Comment 8 Jiri Hnidek 2019-09-05 08:11:58 UTC
I implemented it a little bit different than it was proposed. When /var/log/rhsm directory does not exist, then logutil module (subscription-manager, yum plugin, etc.) tries to create this directory. When it is not possible to create this directory (permission, fs us read-only, etc.), then extra error message is printed (including reason) and all other messages are printed to stderr.

Comment 12 Shwetha Kallesh 2020-02-05 08:50:22 UTC
Verification:

[root@kvm-04-guest02 ~]# subscription-manager version
server type: Red Hat Subscription Management
subscription management server: 2.9.21-1
subscription management rules: 5.37
subscription-manager: 1.26.10-1.el8


[root@kvm-04-guest02 ~]# mv /var/log/rhsm/rhsm.log /root
mv: overwrite '/root/rhsm.log'? y

[root@kvm-04-guest02 ~]# ls /var/log/rhsm/*
/var/log/rhsm/rhsmcertd.log


[root@kvm-04-guest02 ~]# yum repolist
Updating Subscription Management repositories.
repo id                                                                                                    repo name
beaker-AppStream                                                                                           beaker-AppStream
beaker-AppStream-debuginfo                                                                                 beaker-AppStream-debuginfo
beaker-BaseOS                                                                                              beaker-BaseOS
beaker-BaseOS-debuginfo                                                                                    beaker-BaseOS-debuginfo
beaker-CRB                                                                                                 beaker-CRB
beaker-CRB-debuginfo                                                                                       beaker-CRB-debuginfo
beaker-HighAvailability                                                                                    beaker-HighAvailability
beaker-HighAvailability-debuginfo                                                                          beaker-HighAvailability-debuginfo
beaker-NFV                                                                                                 beaker-NFV
beaker-NFV-debuginfo                                                                                       beaker-NFV-debuginfo
beaker-RT                                                                                                  beaker-RT
beaker-RT-debuginfo                                                                                        beaker-RT-debuginfo
beaker-ResilientStorage                                                                                    beaker-ResilientStorage
beaker-ResilientStorage-debuginfo                                                                          beaker-ResilientStorage-debuginfo
beaker-SAP                                                                                                 beaker-SAP
beaker-SAP-debuginfo                                                                                       beaker-SAP-debuginfo
beaker-SAPHANA                                                                                             beaker-SAPHANA
beaker-SAPHANA-debuginfo                                                                                   beaker-SAPHANA-debuginfo
beaker-harness                                                                                             beaker-harness
beaker-tasks                                                                                               beaker-tasks
rhel-8-for-x86_64-appstream-htb-rpms                                                                       Red Hat Enterprise Linux 8 for x86_64 - AppStream HTB (RPMs)
rhel-8-for-x86_64-baseos-htb-rpms                                                                          Red Hat Enterprise Linux 8 for x86_64 - BaseOS HTB (RPMs)

Now verify if the rhsm.log file is created:
[root@kvm-04-guest02 ~]# ls /var/log/rhsm/*
/var/log/rhsm/rhsmcertd.log  /var/log/rhsm/rhsm.log
^^ file is created
[root@kvm-04-guest02 ~]# cat /var/log/rhsm/rhsm.log 
2020-02-05 03:47:27,106 [INFO] yum:31990:MainThread @connection.py:905 - Connection built: host=subscription.rhsm.stage.redhat.com port=443 handler=/subscription auth=identity_cert ca_dir=/etc/rhsm/ca/ insecure=False
^^ output is logged as well

Comment 14 errata-xmlrpc 2020-04-28 16:54: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, 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/RHBA-2020:1849

Comment 15 Ed Avis 2020-05-12 10:55:43 UTC
The new message gets printed every time dnf is run as a non-root user:

% dnf --quiet list autoremote
2020-05-12 11:52:09,965 [ERROR] dnf:683858:MainThread @logutil.py:194 - [Errno 13] Permission denied: '/var/log/rhsm/rhsm.log' - Further logging output will be written to stderr

I think it should only appear when run as root.  A non-root user wouldn't expect to write to /var/log anyway.

Comment 16 Mason Loring Bliss 2020-08-25 13:36:10 UTC
For perspective, changes made to package repositories ought to be logged,
and as such, any inability to log should be treated as an error. In this
case, we're seeing an inability to log treated as a warning. If anything,
for clarity and auditability, we might consider going the other way, and
moving from warning the user to a hard stop.

Comment 17 Ed Avis 2020-09-08 07:17:49 UTC
I entirely agree that changes made to package repositories ought to be logged.  This bug report only concerns the case where dnf is not run as root, and so cannot change anything.  In that case it can't write to the log files either.  But if run as non-root this is all entirely expected, and should not flag a warning.

Of course continue to warn (or even hard error) when dnf is run as root and plans to make a change to the repositories, but cannot log it.