Bug 1920020

pull Request:  https://github.com/candlepin/subscription-manager/pull/2477

To Test:

[vagrant@fedora32 vagrant]$ sudo subscription-manager config --logging.default_log_level=FOO
Invalid Log Level: FOO, setting to INFO.
Use: subscription-manager config --logging.default_log_level= to set the default_log_level.
Invalid Log Level: FOO, setting to INFO.
Use: subscription-manager config --logging.default_log_level= to set the default_log_level.
[vagrant@fedora32 vagrant]$ sudo subscription-manager version
Invalid Log Level: FOO, setting to INFO.
Use: subscription-manager config --logging.default_log_level= to set the default_log_level.
Invalid Log Level: FOO, setting to INFO.
Use: subscription-manager config --logging.default_log_level= to set the default_log_level.
server type: This system is currently not registered.
subscription management server: 3.2.11-1
subscription management rules: 5.41
subscription-manager: RPM_VERSION

The correct pull request is:  https://github.com/candlepin/subscription-manager/pull/2481

Pre-verifying on build to be added in development compose- subscription-manager: 1.28.15-1.el8


Re-producing issue on 
[root@kvm-08-guest13 ~]# 
[root@kvm-08-guest13 ~]# subscription-manager version
server type: This system is currently not registered.
subscription management server: 3.2.15-1
subscription management rules: 5.41
subscription-manager: 1.28.13-2.el8
[root@kvm-08-guest13 ~]# 
[root@kvm-08-guest13 ~]# subscription-manager config --logging.default_log_level=FOO   <<< no warning message and bad value set
[root@kvm-08-guest13 ~]# 
[root@kvm-08-guest13 ~]# cat /etc/rhsm/rhsm.conf | grep log
[logging]
default_log_level = FOO
[root@kvm-08-guest13 ~]# 
[root@kvm-08-guest13 ~]# subscription-manager config --list
Traceback (most recent call last):
  File "/usr/sbin/subscription-manager", line 11, in <module>
    load_entry_point('subscription-manager==1.28.13', 'console_scripts', 'subscription-manager')()
  File "/usr/lib/python3.6/site-packages/pkg_resources/__init__.py", line 476, in load_entry_point
    return get_distribution(dist).load_entry_point(group, name)
  File "/usr/lib/python3.6/site-packages/pkg_resources/__init__.py", line 2700, in load_entry_point
    return ep.load()
  File "/usr/lib/python3.6/site-packages/pkg_resources/__init__.py", line 2318, in load
    return self.resolve()
  File "/usr/lib/python3.6/site-packages/pkg_resources/__init__.py", line 2324, in resolve
    module = __import__(self.module_name, fromlist=['__name__'], level=0)
  File "/usr/lib64/python3.6/site-packages/subscription_manager/scripts/subscription_manager.py", line 62, in <module>
    logutil.init_logger()
  File "/usr/lib64/python3.6/site-packages/rhsm/logutil.py", line 169, in init_logger
    logger.setLevel(getattr(logging, default_log_level.strip()))
AttributeError: module 'logging' has no attribute 'FOO'

========================================================================================
Verifying fix on latest sub-man build: subscription-manager-1.28.15-1.el8.x86_64

[root@kvm-08-guest13 /]# 
[root@kvm-08-guest13 /]# 
[root@kvm-08-guest13 /]# subscription-manager version
server type: This system is currently not registered.
subscription management server: 3.2.15-1
subscription management rules: 5.41
subscription-manager: 1.28.15-1.el8
[root@kvm-08-guest13 /]# 
[root@kvm-08-guest13 /]# rpm -q --changelog subscription-manager | grep 1920020
- 1920020: Set default_log_level to INFO when an invalid value is passed on the
- 1920020: Set default_log_level to INFO when an invalid value is passed on the
[root@kvm-08-guest13 /]# 

[root@kvm-08-guest13 /]# 
[root@kvm-08-guest13 /]# subscription-manager config --logging.default_log_level=FOO   <<<<< expected warning not displayed
[root@kvm-08-guest13 /]# 
[root@kvm-08-guest13 /]# subscription-manager config --list
Invalid Log Level: FOO, setting to INFO.         <<<< warning getting displayed in subsequent subscription-manager commands
Use:  subscription-manager config --logging.default_log_level=<Log Level> to set the default_log_level.
[server]
   hostname = [subscription.rhsm.redhat.com]
   insecure = [0]
   no_proxy = []
   port = [443]
   prefix = [/subscription]
   proxy_hostname = []
   proxy_password = []
   proxy_port = []
   proxy_scheme = [http]
   proxy_user = []
   server_timeout = [180]
   ssl_verify_depth = [3]

[rhsm]
   auto_enable_yum_plugins = [1]
   baseurl = [https://cdn.redhat.com]
   ca_cert_dir = [/etc/rhsm/ca/]
   consumercertdir = [/etc/pki/consumer]
   entitlementcertdir = [/etc/pki/entitlement]
   full_refresh_on_yum = [0]
   inotify = [1]
   manage_repos = [1]
   package_profile_on_trans = [0]
   pluginconfdir = [/etc/rhsm/pluginconf.d]
   plugindir = [/usr/share/rhsm-plugins]
   productcertdir = [/etc/pki/product]
   repo_ca_cert = /etc/rhsm/ca/redhat-uep.pem
   repomd_gpg_url = []
   report_package_profile = [1]

[rhsmcertd]
   auto_registration = [0]
   auto_registration_interval = [60]
   autoattachinterval = [1440]
   certcheckinterval = [240]
   disable = [0]
   splay = [1]

[logging]
   default_log_level = FOO    <<<< Bad value set

[] - Default value in use


[root@kvm-08-guest13 /]#


Actual results:
User was allowed to set a bad value for logging.default_log_level and no warning message being displayed

Expected results:
User should not be allowed to set bad values for default_log_level and a message should be displayed for setting  value to INFO

PR for the main branch:  https://github.com/candlepin/subscription-manager/pull/2640

Per @csnyder (paraphrasing) We will allow the value to be set to "*" (basically whatever value the user defines).  If the value is not in the list of valid values, then an error message is written to std.error() and the system will progress further on that run of a CLI command with the default_log_level = INFO.

INFO is usually the default from my understanding.

The description in comment 7 is accurate.

Cheers,
Chris

Pre-verification....

[root@rhsm-auto85-client2 ~]# rpm -q subscription-manager
subscription-manager-1.28.17-1.git.31.e9a56b5.el8.x86_64
[root@rhsm-auto85-client2 ~]# rpm -q subscription-manager --changelog | grep 1920020
- 1920020: show error message when setting invalid default_log_level as well as
- 1920020: Set default_log_level to INFO when an invalid value is passed on the
[root@rhsm-auto85-client2 ~]# 
[root@rhsm-auto85-client2 ~]# subscription-manager config --logging.default_log_level=foo
Invalid Log Level: foo, setting to INFO for this run.
Please use:  subscription-manager config --logging.default_log_level=<Log Level> to set the default_log_level to a valid value.
Valid Values: CRITICAL, ERROR, WARNING, INFO, DEBUG, NOSET
[root@rhsm-auto85-client2 ~]# 
[root@rhsm-auto85-client2 ~]# subscription-manager version
Invalid Log Level: foo, setting to INFO for this run.
Please use:  subscription-manager config --logging.default_log_level=<Log Level> to set the default_log_level to a valid value.
Valid Values: CRITICAL, ERROR, WARNING, INFO, DEBUG, NOSET
server type: Red Hat Subscription Management
subscription management server: 3.2.12-1
subscription management rules: 5.41
subscription-manager: 1.28.17-1.git.31.e9a56b5.el8
[root@rhsm-auto85-client2 ~]# 
[root@rhsm-auto85-client2 ~]# grep default_log_level /etc/rhsm/rhsm.conf
default_log_level = foo
[root@rhsm-auto85-client2 ~]# 
[root@rhsm-auto85-client2 ~]# subscription-manager config --logging.default_log_level=DEBUG
Invalid Log Level: foo, setting to INFO for this run.
Please use:  subscription-manager config --logging.default_log_level=<Log Level> to set the default_log_level to a valid value.
Valid Values: CRITICAL, ERROR, WARNING, INFO, DEBUG, NOSET
[root@rhsm-auto85-client2 ~]# 
[root@rhsm-auto85-client2 ~]# subscription-manager version
server type: Red Hat Subscription Management
subscription management server: 3.2.12-1
subscription management rules: 5.41
subscription-manager: 1.28.17-1.git.31.e9a56b5.el8
[root@rhsm-auto85-client2 ~]# 
[root@rhsm-auto85-client2 ~]# grep default_log_level /etc/rhsm/rhsm.conf
default_log_level = DEBUG
[root@rhsm-auto85-client2 ~]# 

Verified:Tested setting a bad default_log_level no longer throws an AttributeError and temporarily runs with INFO until the user re-configured a valid log level.

Verifying on :
============

# subscription-manager version
server type: This system is currently not registered.
subscription management server: 3.2.19-1
subscription management rules: 5.41
subscription-manager: 1.28.19-1.el8

# rpm -q subscription-manager --changelog | grep 1920020
- 1920020: show error message when setting invalid default_log_level as well as
- 1920020: Set default_log_level to INFO when an invalid value is passed on the

Set a bad value : 

# subscription-manager config --logging.default_log_level=foo
Invalid Log Level: foo, setting to INFO for this run.
Please use:  subscription-manager config --logging.default_log_level=<Log Level> to set the default_log_level to a valid value.
Valid Values: CRITICAL, ERROR, WARNING, INFO, DEBUG, NOSET

# subscription-manager config --list | grep log_level
Invalid Log Level: foo, setting to INFO for this run.
Please use:  subscription-manager config --logging.default_log_level=<Log Level> to set the default_log_level to a valid value.
Valid Values: CRITICAL, ERROR, WARNING, INFO, DEBUG, NOSET
   default_log_level = foo

Value set to "foo" also notice the warning message appears every time a subscription-manager command is executed . 

Now try to register the system and notice the in rhsm.log 

# subscription-manager register
Invalid Log Level: foo, setting to INFO for this run.
Please use:  subscription-manager config --logging.default_log_level=<Log Level> to set the default_log_level to a valid value.
Valid Values: CRITICAL, ERROR, WARNING, INFO, DEBUG, NOSET
Registering to: subscription.rhsm.stage.redhat.com:443/subscription
Username: *****
Password: 
The system has been registered with ID: 6116a352-dd89-4298-8c39-8256a9004571
The registered system name is: kvm-06-guest13.hv2.lab.eng.bos.redhat.com
# grep default_log_level /etc/rhsm/rhsm.conf
default_log_level =foo

rhsm.log 
========
2021-07-16 07:44:12,278 [INFO] subscription-manager:17738:MainThread @managerlib.py:72 - Consumer created: kvm-06-guest13.hv2.lab.eng.bos.redhat.com (6116a352-dd89-4298-8c39-8256a9004571)
2021-07-16 07:44:14,297 [INFO] subscription-manager:17738:MainThread @entcertlib.py:131 - certs updated:
Total updates: 0
Found (local) serial# []
Expected (UEP) serial# []
Added (new)
  <NONE>
Deleted (rogue):
  <NONE>

NOW set a correct value 

# subscription-manager config --logging.default_log_level=DEBUG

# grep default_log_level /etc/rhsm/rhsm.conf
default_log_level = DEBUG

^^ Value has been successfully set to "Debug" . Based on the above observation moving the bug to "Verified".

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 (subscription-manager 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/RHBA-2021:4390