Red Hat Bugzilla – Bug 1389559
logging to /var/log/rhsm/rhsm.log ceases after upgrade from rhel6.8 to rhel6.9
Last modified: 2017-03-21 06:56:33 EDT
Description of problem: Logging to /var/log/rhsm/rhsm.log works fine with subscription-manager-1.16.8-8.el6 which was released on rhel6.8, but after yum updating to the subscription-manager-1.18 targeted for rhel6.9, the logging to /var/log/rhsm/rhsm.log ceases. Not sure why where the problem is, but I know the work done on bug 1334916 to benefit rhel7.3 is likely a factor. Version-Release number of selected component (if applicable): [root@jsefler-rhel6 ~]# rpm -q subscription-manager python-rhsm subscription-manager-1.18.3-1.el6.x86_64 python-rhsm-1.18.4-1.el6.x86_64 How reproducible: Steps to Reproduce: Begin with the release rhsm packages from rhel68... [root@jsefler-rhel6 ~]# subscription-manager versionserver type: This system is currently not registered. subscription management server: 2.0.16-1 subscription management rules: 5.20 subscription-manager: 1.16.8-8.el6 python-rhsm: 1.16.6-1.el6 [root@jsefler-rhel6 ~]# yum update subscription* python-rhsm* --enablerepo=latest*Loaded plugins: product-id, refresh-packagekit, search-disabled-repos, security, : subscription-manager This system is not registered to Red Hat Subscription Management. You can use subscription-manager to register. Setting up Update Process Resolving Dependencies --> Running transaction check ---> Package python-rhsm.x86_64 0:1.16.6-1.el6 will be updated ---> Package python-rhsm.x86_64 0:1.18.4-1.el6 will be an update ---> Package subscription-manager.x86_64 0:1.16.8-8.el6 will be updated ---> Package subscription-manager.x86_64 0:1.18.3-1.el6 will be an update --> Finished Dependency Resolution Dependencies Resolved ==================================================================================== Package Arch Version Repository Size ==================================================================================== Updating: python-rhsm x86_64 1.18.4-1.el6 latest-rhel6-server 116 k subscription-manager x86_64 1.18.3-1.el6 latest-rhel6-server 904 k Transaction Summary ==================================================================================== Upgrade 2 Package(s) Total download size: 1.0 M Is this ok [y/N]: y Downloading Packages: (1/2): python-rhsm-1.18.4-1.el6.x86_64.rpm | 116 kB 00:00 (2/2): subscription-manager-1.18.3-1.el6.x86_64.rpm | 904 kB 00:00 ------------------------------------------------------------------------------------ Total 5.6 MB/s | 1.0 MB 00:00 Running rpm_check_debug Running Transaction Test Transaction Test Succeeded Running Transaction Updating : python-rhsm-1.18.4-1.el6.x86_64 1/4 Updating : subscription-manager-1.18.3-1.el6.x86_64 2/4 warning: /etc/rhsm/rhsm.conf created as /etc/rhsm/rhsm.conf.rpmnew Cleanup : subscription-manager-1.16.8-8.el6.x86_64 3/4 Cleanup : python-rhsm-1.16.6-1.el6.x86_64 4/4 Verifying : subscription-manager-1.18.3-1.el6.x86_64 1/4 Verifying : python-rhsm-1.18.4-1.el6.x86_64 2/4 Verifying : python-rhsm-1.16.6-1.el6.x86_64 3/4 Verifying : subscription-manager-1.16.8-8.el6.x86_64 4/4 Updated: python-rhsm.x86_64 0:1.18.4-1.el6 subscription-manager.x86_64 0:1.18.3-1.el6 Complete! [root@jsefler-rhel6 ~]# subscription-manager version server type: This system is currently not registered. subscription management server: 2.0.16-1 subscription management rules: 5.20 subscription-manager: 1.18.3-1.el6 python-rhsm: 1.18.4-1.el6 Actual results: above you see three calls 1. subscription-manager version 2. yum update 3. subscription-manager version below in Additional info you see a tail -f during the 3 calls, but nothing is appended to rhsm.log after the yum update completes. Expected results: logging to /var/log/rhsm/rhsm.log should continue Additional info: [root@jsefler-rhel6 ~]# tail -f /var/log/rhsm/rhsm.log 2016-10-27 17:16:25,944 [DEBUG] subscription-manager:3141 @ga_loader.py:89 - ga_loader GaImporterGtk2 2016-10-27 17:16:25,949 [DEBUG] subscription-manager:3141 @plugins.py:569 - loaded plugin modules: [] 2016-10-27 17:16:25,949 [DEBUG] subscription-manager:3141 @plugins.py:570 - loaded plugins: {} 2016-10-27 17:16:25,949 [DEBUG] subscription-manager:3141 @identity.py:131 - Loading consumer info from identity certificates. 2016-10-27 17:16:25,949 [DEBUG] subscription-manager:3141 @identity.py:146 - Reload of consumer identity cert /etc/pki/consumer/cert.pem raised an exception with msg: [Errno 2] No such file or directory: '/etc/pki/consumer/key.pem' 2016-10-27 17:16:25,996 [INFO] subscription-manager:3141 @managercli.py:367 - Client Versions: {'python-rhsm': '1.16.6-1.el6', 'subscription-manager': '1.16.8-8.el6'} 2016-10-27 17:16:25,996 [INFO] subscription-manager:3141 @connection.py:815 - Connection built: host=jsefler-candlepin.usersys.redhat.com port=8443 handler=/candlepin auth=identity_cert ca_dir=/etc/rhsm/ca/ verify=False 2016-10-27 17:16:25,997 [INFO] subscription-manager:3141 @connection.py:815 - Connection built: host=jsefler-candlepin.usersys.redhat.com port=8443 handler=/candlepin auth=none 2016-10-27 17:16:26,014 [DEBUG] subscription-manager:3141 @connection.py:509 - Loaded CA certificates from /etc/rhsm/ca/: jsefler-candlepin.pem, redhat-uep.pem, timeout_listener.pem 2016-10-27 17:16:26,014 [DEBUG] subscription-manager:3141 @connection.py:557 - Making request: GET /candlepin/ 2016-10-27 17:16:26,166 [DEBUG] subscription-manager:3141 @connection.py:589 - Response: status=200, requestUuid=270485ed-e32c-4328-9ba0-0db73f5ee135 2016-10-27 17:16:26,168 [DEBUG] subscription-manager:3141 @connection.py:832 - Server supports the following resources: {'': '/', 'guestids': '/consumers/{consumer_uuid}/guestids', 'cdn': '/cdn', 'content_overrides': '/consumers/{consumer_uuid}/content_overrides', 'hypervisors': '/hypervisors', 'serials': '/serials', 'deleted_consumers': '/deleted_consumers', 'consumers': '/consumers', 'content': '/content', 'entitlements': '/entitlements', 'events': '/events', 'status': '/status', 'jobs': '/jobs', 'users': '/users', 'subscriptions': '/subscriptions', 'rules': '/rules', 'distributor_versions': '/distributor_versions', 'consumertypes': '/consumertypes', 'activation_keys': '/activation_keys', 'atom': '/atom', 'owners': '/owners', 'roles': '/roles', 'admin': '/admin', 'products': '/products', 'pools': '/pools', 'crl': '/crl'} 2016-10-27 17:16:26,169 [DEBUG] subscription-manager:3141 @connection.py:509 - Loaded CA certificates from /etc/rhsm/ca/: jsefler-candlepin.pem, redhat-uep.pem, timeout_listener.pem 2016-10-27 17:16:26,169 [DEBUG] subscription-manager:3141 @connection.py:557 - Making request: GET /candlepin/status 2016-10-27 17:16:26,216 [DEBUG] subscription-manager:3141 @connection.py:589 - Response: status=200, requestUuid=7bdc8cad-4f2f-43fb-82e9-07fd253a7785 2016-10-27 17:16:26,217 [INFO] subscription-manager:3141 @managercli.py:378 - Server Versions: {'rules-version': '5.20', 'candlepin': '2.0.16-1', 'server-type': 'This system is currently not registered.'} 2016-10-27 17:16:53,429 [DEBUG] yum:3143 @identity.py:131 - Loading consumer info from identity certificates. 2016-10-27 17:16:53,429 [DEBUG] yum:3143 @identity.py:146 - Reload of consumer identity cert /etc/pki/consumer/cert.pem raised an exception with msg: [Errno 2] No such file or directory: '/etc/pki/consumer/key.pem' 2016-10-27 17:16:53,467 [INFO] yum:3143 @connection.py:815 - Connection built: host=jsefler-candlepin.usersys.redhat.com port=8443 handler=/candlepin auth=identity_cert ca_dir=/etc/rhsm/ca/ verify=False 2016-10-27 17:16:53,467 [DEBUG] yum:3143 @__init__.py:85 - Searching for content of type: yum 2016-10-27 17:16:53,469 [INFO] yum:3143 @repolib.py:303 - repos updated: Repo updates Total repo updates: 0 Updated <NONE> Added (new) <NONE> Deleted <NONE>
Fix works in both 2.6 and 2.7 (RHEL6 and RHEL7). Issue was that setLevel in 2.7 handles strings specially, but 2.6 does not.
Moving to POST as the fix has been merged to upstream master.
With RHSM version : [root@hp-ml350egen8-01 ~]# subscription-manager version server type: Red Hat Subscription Management subscription management server: 0.9.51.20-1 subscription management rules: 5.15.1 subscription-manager: 1.18.3-1.el6 python-rhsm: 1.18.4-1.el6 [root@hp-ml350egen8-01 ~]# subscription-manager register Registering to: subscription.rhn.stage.redhat.com:443/subscription Username: qa@redhat.com Password: The system has been registered with ID: 5042cc50-9f67-43f7-8956-be5561d7192f [root@hp-ml350egen8-01 ~]# tail -f /var/log/rhsm/rhsm.log with version logging is fine: [root@hp-ml350egen8-01 ~]# subscription-manager version server type: Red Hat Subscription Management subscription management server: 0.9.51.20-1 subscription management rules: 5.15.1 subscription-manager: 1.18.4-1.el6 python-rhsm: 1.18.4-1.el6 [root@hp-ml350egen8-01 ~]# subscription-manager register --force The system with UUID 5042cc50-9f67-43f7-8956-be5561d7192f has been unregistered Registering to: subscription.rhn.stage.redhat.com:443/subscription Username: qa@redhat.com Password: The system has been registered with ID: 59e08d4b-09de-4b0f-b5af-e731cbcf557 [root@hp-ml350egen8-01 ~]# tail -f /var/log/rhsm/rhsm.log 2016-11-08 05:11:10,856 [INFO] subscription-manager:10918:MainThread @managercli.py:388 - Client Versions: {'python-rhsm': '1.18.4-1.el6', 'subscription-manager': '1.18.4-1.el6'} 2016-11-08 05:11:10,857 [INFO] subscription-manager:10918:MainThread @connection.py:843 - Connection built: host=subscription.rhn.stage.redhat.com port=443 handler=/subscription auth=identity_cert ca_dir=/etc/rhsm/ca/ verify=False 2016-11-08 05:11:10,858 [INFO] subscription-manager:10918:MainThread @connection.py:843 - Connection built: host=subscription.rhn.stage.redhat.com port=443 handler=/subscription auth=none 2016-11-08 05:11:12,469 [INFO] subscription-manager:10918:MainThread @managercli.py:399 - Server Versions: {'rules-version': '5.15.1', 'candlepin': '0.9.51.20-1', 'server-type': 'Red Hat Subscription Management'} 2016-11-08 05:11:27,925 [INFO] subscription-manager:10919:MainThread @managercli.py:388 - Client Versions: {'python-rhsm': '1.18.4-1.el6', 'subscription-manager': '1.18.4-1.el6'} 2016-11-08 05:11:27,926 [INFO] subscription-manager:10919:MainThread @connection.py:843 - Connection built: host=subscription.rhn.stage.redhat.com port=443 handler=/subscription auth=identity_cert ca_dir=/etc/rhsm/ca/ verify=False 2016-11-08 05:11:27,926 [INFO] subscription-manager:10919:MainThread @connection.py:843 - Connection built: host=subscription.rhn.stage.redhat.com port=443 handler=/subscription auth=none 2016-11-08 05:11:27,927 [INFO] subscription-manager:10919:MainThread @managercli.py:388 - Client Versions: {'python-rhsm': '1.18.4-1.el6', 'subscription-manager': '1.18.4-1.el6'} 2016-11-08 05:11:27,939 [INFO] subscription-manager:10919:MainThread @managercli.py:363 - Consumer Identity name=hp-ml350egen8-01.rhts.eng.bos.redhat.com uuid=5042cc50-9f67-43f7-8956-be5561d7192f 2016-11-08 05:11:27,940 [INFO] subscription-manager:10919:MainThread @managercli.py:363 - Consumer Identity name=hp-ml350egen8-01.rhts.eng.bos.redhat.com uuid=5042cc50-9f67-43f7-8956-be5561d7192f 2016-11-08 05:11:28,496 [INFO] subscription-manager:10919:MainThread @managerlib.py:793 - Successfully un-registered. 2016-11-08 05:11:28,520 [INFO] subscription-manager:10919:MainThread @managerlib.py:879 - Cleaned local data 2016-11-08 05:11:28,521 [INFO] subscription-manager:10919:MainThread @managercli.py:1098 - --force specified, unregistered old consumer: 5042cc50-9f67-43f7-8956-be5561d7192f 2016-11-08 05:11:35,723 [INFO] subscription-manager:10919:MainThread @connection.py:843 - Connection built: host=subscription.rhn.stage.redhat.com port=443 handler=/subscription auth=basic username=qa@redhat.com 2016-11-08 05:11:36,025 [INFO] subscription-manager:10919:MainThread @hwprobe.py:918 - collected virt facts: virt.is_guest=False, virt.host_type=Not Applicable, virt.uuid=Not Set 2016-11-08 05:11:45,178 [INFO] subscription-manager:10919:MainThread @managerlib.py:77 - Consumer created: {'consumer_name': 'hp-ml350egen8-01.rhts.eng.bos.redhat.com', 'uuid': '59e08d4b-09de-4b0f-b5af-e731cbcf557c'} 2016-11-08 05:11:45,179 [INFO] subscription-manager:10919:MainThread @connection.py:843 - Connection built: host=subscription.rhn.stage.redhat.com port=443 handler=/subscription auth=identity_cert ca_dir=/etc/rhsm/ca/ verify=False 2016-11-08 05:11:46,361 [INFO] subscription-manager:10919:MainThread @managercli.py:399 - Server Versions: {'rules-version': '5.15.1', 'candlepin': '0.9.51.20-1', 'server-type': 'Red Hat Subscription Management'} 2016-11-08 05:11:46,833 [INFO] rhsmcertd-worker:10964:MainThread @connection.py:843 - Connection built: host=subscription.rhn.stage.redhat.com port=443 handler=/subscription auth=identity_cert ca_dir=/etc/rhsm/ca/ verify=False 2016-11-08 05:11:46,949 [INFO] subscription-manager:10919:MainThread @cache.py:398 - Server does not support packages, skipping profile upload. 2016-11-08 05:11:47,623 [INFO] subscription-manager:10919:MainThread @cert_sorter.py:205 - Product status: valid_products= partial_products= expired_products= unentitled_producs=69 future_products= valid_until=None 2016-11-08 05:11:54,518 [INFO] rhsmcertd-worker:10964:MainThread @cert_sorter.py:205 - Product status: valid_products= partial_products= expired_products= unentitled_producs=69 future_products= valid_until=None 2016-11-08 05:11:54,523 [WARNING] rhsmcertd-worker:10964:MainThread @healinglib.py:97 - Found invalid entitlements for today: 2016-11-08 10:11:47.998455+00:00 2016-11-08 05:12:00,367 [INFO] rhsmcertd-worker:10964:MainThread @connection.py:843 - Connection built:
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://rhn.redhat.com/errata/RHSA-2017-0698.html