Bug 1862244

Summary: dnf repoquery writes some information to stdout instead of stderr
Product: Red Hat Enterprise Linux 8 Reporter: Omair Majid <omajid>
Component: dnf-plugins-coreAssignee: David Cantrell <dcantrell>
Status: CLOSED WONTFIX QA Contact: swm-qe
Severity: medium Docs Contact: Mariya Pershina <mpershin>
Priority: medium    
Version: 8.2CC: james.antill, jhnidek, mbanas, mcurlej, mpershin, ptoscano, redakkan, tbajer
Target Milestone: rcKeywords: Reopened, Triaged
Target Release: 8.0   
Hardware: Unspecified   
OS: Unspecified   
Whiteboard:
Fixed In Version: Doc Type: Known Issue
Doc Text:
Cause: Some dnf functionality or plugins may log messages even if a logging service is not available. In these cases the log messages go to either standard output or standard error. The level of the log message indicates where it goes. Information messages go to standard output while error and debugging messages go to standard error. Consequence: When scripting dnf options, unwanted log messages on standard output or standard error can affect the functionality of the script. Workaround (if any): Suppress the log messages from standard out and standard error using the -q option to dnf. This suppresses log messages but not command results that are expected on standard output. Result: With the -q option, scripted dnf functionality will behave as expected.
Story Points: ---
Clone Of: Environment:
Last Closed: 2023-07-06 07:28:06 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 Omair Majid 2020-07-30 19:59:57 UTC
I am trying to run this command in a container:

dnf repoquery --disablerepo=* --enablerepo=*-source --arch=src --requires dotnet3.1 2>/dev/null | grep -v '^dotnet3.1'

And then use the result to install the packages explicitly.

The output I get mixes the actual command output with subscription manager messages, which are useless to me:

Updating Subscription Management repositories.
Unable to read consumer identity
Subscription Manager is operating in container mode.
clang
cmake
coreutils
git
glibc-langpack-en
hostname
krb5-devel
libcurl-devel
libicu-devel
lldb-devel
llvm
lttng-ust-devel
openssl-devel
python3
tar
zlib-devel

Shouldn't those messages be written to stderr or something? Or maybe there should be a reliable way to filter them out?

Comment 1 Jaroslav Mracek 2020-08-04 13:39:54 UTC
Thank you very much for the report. The problem is that Subscription Manager plugin logs some messages during initialization, and this is too early that it could be handled by DNF. Therefore I would like to ask maintainers of the plugin to move all login to configure phase or to std_error.

The issue could be workarounded by using `-q`. Then all logging information will be not visible at all.

Comment 5 RHEL Program Management 2022-01-30 07:27:01 UTC
After evaluating this issue, there are no plans to address it further or fix it in an upcoming release.  Therefore, it is being closed.  If plans change such that this issue will be fixed in an upcoming release, then the bug can be reopened.

Comment 6 Pino Toscano 2022-12-06 13:29:46 UTC
Reopening it after a recent discussion with Jaroslav Mracek.

The 'subscription-manager' dnf plugin uses the dnfpluginscore.logger module to log the messages that appear to the user:
https://github.com/candlepin/subscription-manager/blob/5ef557a7730650fc3eb804945fad2b781b16ed8a/src/plugins/dnf/subscription-manager.py

from dnfpluginscore import logger
...
        logger.info(_("Updating Subscription Management repositories."))

Hence, reopening and moving back to dnf, as the dnf plugin uses the correct APIs as it is supposed to.

Comment 8 Pino Toscano 2022-12-06 13:32:56 UTC
Note: this bug was reported for RHEL 8 -- I can reproduce the issue also in RHEL 9.

Comment 10 David Cantrell 2023-05-30 18:24:25 UTC
I've been working on this one today and cannot come up with a way in dnf to resolve this without breaking the dnf logging API.

The logging API in dnf uses both stdout and stderr.  Messages at the INFO level go to stdout and messages at the WARNING, CRITICAL, ERROR, or DEBUG level go to stderr.  More or less.  This is how dnf's logging API has worked for a long time.  The standard streams are in use before file logging is set up.

While logger.info() is the correct function to use here, since that reports at the INFO level it will go to stdout since file logging is not set up when those lines are executed.

A couple of options are available:

1) Break the API and change dnf's logging API to use stderr for everything.  Personally, I feel this is the more correct thing to do with a logging API since the code also uses print to put things on stdout.  However, this would break the established dnf API and there are likely things depending on this functionality.  The test suite tests to ensure the split between stdout and stderr works, so I am hesitant about this change in dnf.

2) Modify the subscription-manager plugin to strike those logger.info() messages or change them to logger.debug() or something that will go to stderr.  The problem I see there is that INFO seems appropriate for the message it is conveying.

3) Accept the behavior and use "-q" on the dnf command to silence the logging messages on stdout and stderr.

Thoughts?  I will ask the team as well.

Comment 11 David Cantrell 2023-06-01 16:59:19 UTC
Discussed among the team and the consensus was that documenting the '-q' option to suppress unwanted stderr output is the best option given where dnf 4.x is in its life.  I am clearing the devel_ack+ and adding doc text.

Comment 14 Jaroslav Mracek 2023-06-05 11:50:30 UTC
My apology for the late reaction. The option to use -q is logic and the best option but users did not adopted it fully.

We already handle the same situation for dnf logger. See https://github.com/rpm-software-management/dnf/pull/681/commits/2056f5439dc038852b4533963322252cdbbc0b76. It is called by multiple commands including repoquery.

The issue with dnf loggers was reported for example here - https://bugzilla.redhat.com/show_bug.cgi?id=1499623.

I know that the redirection is not the right approach but it is already used for dnf logger.

Comment 16 RHEL Program Management 2023-07-06 07:28:06 UTC
After evaluating this issue, there are no plans to address it further or fix it in an upcoming release.  Therefore, it is being closed.  If plans change such that this issue will be fixed in an upcoming release, then the bug can be reopened.