Hide Forgot
Description of problem: Unregistered system, check the virt-who log, it will appear error message "IOError: [Errno 2] No such file or directory: '/etc/pki/consumer/key.pem" and exception message like "Exception caught while running <subscription_manager.entcertlib.EntCertActionInvoker object at 0x31e9490> update" Version-Release number of selected component (if applicable): subscription-manager-1.12.10-1.el6.x86_64 python-rhsm-1.12.5-1.el6.x86_64 virt-who-0.10-4.el6.noarch katello-headpin-1.4.3.26-1.el6sam_splice.noarch candlepin-0.9.6.5-1.el6sam.noarch How reproducible: Always Steps to Reproduce: 1.Register system to SAM server # subscription-manager register --username=admin --password=admin 2. Configure virt-who run at libvirtd mode # vim /etc/sysconfig/virt-who VIRTWHO_BACKGROUND=1 VIRTWHO_DEBUG=1 VIRTWHO_INTERVAL=5 3. Restart virt-who service, virt-who send host/guest associate to SAM server # service virt-who restart 4. Unregister the system # subscription-manager unregister Actual results: System has been unregistered successfully, but it will generate error message and exception as the following: 2014-08-08 15:38:11,482 [INFO] subscription-manager @managerlib.py:807 - Successfully un-registered. 2014-08-08 15:38:11,483 [DEBUG] subscription-manager @managerlib.py:853 - Removing identity cert: /etc/pki/consumer/key.pem 2014-08-08 15:38:11,483 [DEBUG] subscription-manager @managerlib.py:853 - Removing identity cert: /etc/pki/consumer/cert.pem 2014-08-08 15:38:11,483 [DEBUG] subscription-manager @identity.py:131 - Loading consumer info from identity certificates. 2014-08-08 15:38:11,483 [ERROR] subscription-manager @identity.py:143 - [Errno 2] No such file or directory: '/etc/pki/consumer/key.pem' Traceback (most recent call last): File "/usr/share/rhsm/subscription_manager/identity.py", line 135, in reload self.consumer = self._get_consumer_identity() File "/usr/share/rhsm/subscription_manager/identity.py", line 151, in _get_consumer_identity return ConsumerIdentity.read() File "/usr/share/rhsm/subscription_manager/identity.py", line 48, in read f = open(cls.keypath()) IOError: [Errno 2] No such file or directory: '/etc/pki/consumer/key.pem' 2014-08-08 15:38:11,484 [INFO] subscription-manager @identity.py:144 - Error reading consumer identity cert 2014-08-08 15:38:11,484 [DEBUG] subscription-manager @managerlib.py:864 - Removing entitlement cert: /etc/pki/entitlement/2320711087070785282-key.pem 2014-08-08 15:38:11,484 [DEBUG] subscription-manager @managerlib.py:864 - Removing entitlement cert: /etc/pki/entitlement/2320711087070785282.pem 2014-08-08 15:38:11,484 [INFO] subscription-manager @cache.py:86 - Deleting cache: /var/lib/rhsm/cache/installed_products.json 2014-08-08 15:38:11,484 [INFO] subscription-manager @cache.py:86 - Deleting cache: /var/lib/rhsm/facts/facts.json 2014-08-08 15:38:11,485 [INFO] subscription-manager @cache.py:86 - Deleting cache: /var/lib/rhsm/cache/entitlement_status.json 2014-08-08 15:38:11,485 [INFO] subscription-manager @cache.py:86 - Deleting cache: /var/lib/rhsm/cache/content_overrides.json 2014-08-08 15:38:11,485 [INFO] subscription-manager @cache.py:86 - Deleting cache: /var/lib/rhsm/cache/written_overrides.json 2014-08-08 15:38:11,485 [INFO] subscription-manager @managerlib.py:878 - Cleaned local data 2014-08-08 15:38:11,485 [DEBUG] subscription-manager @base_action_client.py:85 - running lib: <subscription_manager.entcertlib.EntCertActionInvoker object at 0x152c690> 2014-08-08 15:38:11,486 [WARNING] subscription-manager @base_action_client.py:72 - Exception caught while running <subscription_manager.entcertlib.EntCertActionInvoker object at 0x152c690> update 2014-08-08 15:38:11,486 [ERROR] subscription-manager @base_action_client.py:73 - Traceback (most recent call last): File "/usr/share/rhsm/subscription_manager/base_action_client.py", line 63, in _run_update update_report = lib.update() File "/usr/share/rhsm/subscription_manager/certlib.py", line 31, in update self.report = self.locker.run(self._do_update) File "/usr/share/rhsm/subscription_manager/certlib.py", line 17, in run return action() File "/usr/share/rhsm/subscription_manager/entcertlib.py", line 43, in _do_update return action.perform() File "/usr/share/rhsm/subscription_manager/entcertlib.py", line 119, in perform expected = self._get_expected_serials() File "/usr/share/rhsm/subscription_manager/entcertlib.py", line 251, in _get_expected_serials exp = self.get_certificate_serials_list() File "/usr/share/rhsm/subscription_manager/entcertlib.py", line 229, in get_certificate_serials_list raise Disconnected() Disconnected 2014-08-08 15:38:11,486 [DEBUG] subscription-manager @base_action_client.py:85 - running lib: <subscription_manager.content_action_client.ContentActionClient object at 0x152c710> 2014-08-08 15:38:11,487 [DEBUG] subscription-manager @base_action_client.py:85 - running lib: <subscription_manager.repolib.RepoActionInvoker object at 0x152c910> 2014-08-08 15:38:11,487 [DEBUG] subscription-manager @connection.py:414 - Loaded CA certificates from /etc/rhsm/ca/: candlepin-stage.pem, redhat-uep.pem, candlepin-local.pem Expected results: system unregistered successfully, and it won't generate any error message and exception. Additional info: It isn't exist on RHEL5.11
This is bug in subscription-manager, there is no mention about virt-who in the traceback.
BTW, this error log generated on /var/log/rhsm/rhsm.log
pr at https://github.com/candlepin/subscription-manager/pull/1005
Verified on RHEL6.6-Server-x64-20140826.0 Version: virt-who-0.10-6.el6.noarch subscription-manager-1.12.13-1.el6.x86_64 python-rhsm-1.12.5-1.el6.x86_64
Sorry, Please ignore the comment 6,it still exist on RHEL6.6-Server-x64-20140826.0. In the latest build, it will pop up the following error message and exceptions: Version: virt-who-0.10-6.el6.noarch subscription-manager-1.12.13-1.el6.x86_64 python-rhsm-1.12.5-1.el6.x86_64 2014-08-28 03:24:59,188 [WARNING] subscription-manager @connection.py:473 - Clock skew detected, please check your system time 2014-08-28 03:24:59,188 [INFO] subscription-manager @managerlib.py:807 - Successfully un-registered. 2014-08-28 03:24:59,190 [DEBUG] subscription-manager @managerlib.py:853 - Removing identity cert: /etc/pki/consumer/key.pem 2014-08-28 03:24:59,191 [DEBUG] subscription-manager @managerlib.py:853 - Removing identity cert: /etc/pki/consumer/cert.pem 2014-08-28 03:24:59,191 [DEBUG] subscription-manager @identity.py:131 - Loading consumer info from identity certificates. 2014-08-28 03:24:59,191 [DEBUG] subscription-manager @identity.py:143 - 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' 2014-08-28 03:24:59,192 [INFO] subscription-manager @cache.py:86 - Deleting cache: /var/lib/rhsm/cache/installed_products.json 2014-08-28 03:24:59,192 [INFO] subscription-manager @cache.py:86 - Deleting cache: /var/lib/rhsm/facts/facts.json 2014-08-28 03:24:59,192 [INFO] subscription-manager @cache.py:86 - Deleting cache: /var/lib/rhsm/cache/entitlement_status.json 2014-08-28 03:24:59,193 [INFO] subscription-manager @cache.py:86 - Deleting cache: /var/lib/rhsm/cache/written_overrides.json 2014-08-28 03:24:59,193 [INFO] subscription-manager @managerlib.py:878 - Cleaned local data 2014-08-28 03:24:59,194 [DEBUG] subscription-manager @base_action_client.py:85 - running lib: <subscription_manager.entcertlib.EntCertActionInvoker object at 0x1f7d390> 2014-08-28 03:24:59,194 [WARNING] subscription-manager @base_action_client.py:72 - Exception caught while running <subscription_manager.entcertlib.EntCertActionInvoker object at 0x1f7d390> update 2014-08-28 03:24:59,194 [ERROR] subscription-manager @base_action_client.py:73 - Traceback (most recent call last): File "/usr/share/rhsm/subscription_manager/base_action_client.py", line 63, in _run_update update_report = lib.update() File "/usr/share/rhsm/subscription_manager/certlib.py", line 31, in update self.report = self.locker.run(self._do_update) File "/usr/share/rhsm/subscription_manager/certlib.py", line 17, in run return action() File "/usr/share/rhsm/subscription_manager/entcertlib.py", line 43, in _do_update return action.perform() File "/usr/share/rhsm/subscription_manager/entcertlib.py", line 119, in perform expected = self._get_expected_serials() File "/usr/share/rhsm/subscription_manager/entcertlib.py", line 251, in _get_expected_serials exp = self.get_certificate_serials_list() File "/usr/share/rhsm/subscription_manager/entcertlib.py", line 229, in get_certificate_serials_list raise Disconnected() Disconnected 2014-08-28 03:24:59,195 [DEBUG] subscription-manager @base_action_client.py:85 - running lib: <subscription_manager.content_action_client.ContentActionClient object at 0x1f7d650> 2014-08-28 03:24:59,195 [DEBUG] subscription-manager @base_action_client.py:85 - running lib: <subscription_manager.repolib.RepoActionInvoker object at 0x1f7d850> 2014-08-28 03:24:59,196 [DEBUG] subscription-manager @connection.py:414 - Loaded CA certificates from /etc/rhsm/ca/: candlepin-local.pem, candlepin-stage.pem, redhat-uep.pem
on master: commit 18eeb867dc7d13958a999efb23c88258d5c0c34a Author: Adrian Likins <alikins@redhat.com> Date: Thu Aug 14 13:02:26 2014 -0400 1128061: Stop logging expected exceptions on unreg This log.exception() is information, but also unneeded. On a reload, a missing cert is a valid case, so stop cluttering the logs.
Check it on latest rhel6.6-20140903.0-Server, the same problem still exist. please see the detail log as the following: Version: virt-who-0.10-7.el6.noarch subscription-manager-1.12.14-2.el6.x86_64 python-rhsm-1.12.5-2.el6.x86_64 2014-09-04 01:44:32,681 [INFO] subscription-manager @managerlib.py:807 - Successfully un-registered. 2014-09-04 01:44:32,692 [DEBUG] subscription-manager @managerlib.py:853 - Removing identity cert: /etc/pki/consumer/key.pem 2014-09-04 01:44:32,693 [DEBUG] subscription-manager @managerlib.py:853 - Removing identity cert: /etc/pki/consumer/cert.pem 2014-09-04 01:44:32,693 [DEBUG] subscription-manager @identity.py:131 - Loading consumer info from identity certificates. 2014-09-04 01:44:32,693 [DEBUG] subscription-manager @identity.py:143 - 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' 2014-09-04 01:44:32,699 [DEBUG] subscription-manager @managerlib.py:864 - Removing entitlement cert: /etc/pki/entitlement/2726542161217885472-key.pem 2014-09-04 01:44:32,699 [DEBUG] subscription-manager @managerlib.py:864 - Removing entitlement cert: /etc/pki/entitlement/2726542161217885472.pem 2014-09-04 01:44:32,701 [INFO] subscription-manager @cache.py:86 - Deleting cache: /var/lib/rhsm/cache/installed_products.json 2014-09-04 01:44:32,701 [INFO] subscription-manager @cache.py:86 - Deleting cache: /var/lib/rhsm/facts/facts.json 2014-09-04 01:44:32,702 [INFO] subscription-manager @cache.py:86 - Deleting cache: /var/lib/rhsm/cache/entitlement_status.json 2014-09-04 01:44:32,702 [INFO] subscription-manager @cache.py:86 - Deleting cache: /var/lib/rhsm/cache/product_status.json 2014-09-04 01:44:32,702 [INFO] subscription-manager @cache.py:86 - Deleting cache: /var/lib/rhsm/cache/content_overrides.json 2014-09-04 01:44:32,715 [INFO] subscription-manager @cache.py:86 - Deleting cache: /var/lib/rhsm/cache/written_overrides.json 2014-09-04 01:44:32,716 [INFO] subscription-manager @managerlib.py:878 - Cleaned local data 2014-09-04 01:44:32,716 [DEBUG] subscription-manager @base_action_client.py:85 - running lib: <subscription_manager.entcertlib.EntCertActionInvoker object at 0x31e9750> 2014-09-04 01:44:32,716 [WARNING] subscription-manager @base_action_client.py:72 - Exception caught while running <subscription_manager.entcertlib.EntCertActionInvoker object at 0x31e9750> update 2014-09-04 01:44:32,716 [ERROR] subscription-manager @base_action_client.py:73 - Traceback (most recent call last): File "/usr/share/rhsm/subscription_manager/base_action_client.py", line 63, in _run_update update_report = lib.update() File "/usr/share/rhsm/subscription_manager/certlib.py", line 31, in update self.report = self.locker.run(self._do_update) File "/usr/share/rhsm/subscription_manager/certlib.py", line 17, in run return action() File "/usr/share/rhsm/subscription_manager/entcertlib.py", line 43, in _do_update return action.perform() File "/usr/share/rhsm/subscription_manager/entcertlib.py", line 119, in perform expected = self._get_expected_serials() File "/usr/share/rhsm/subscription_manager/entcertlib.py", line 251, in _get_expected_serials exp = self.get_certificate_serials_list() File "/usr/share/rhsm/subscription_manager/entcertlib.py", line 229, in get_certificate_serials_list raise Disconnected() Disconnected 2014-09-04 01:44:32,738 [DEBUG] subscription-manager @base_action_client.py:85 - running lib: <subscription_manager.content_action_client.ContentActionClient object at 0x31e9210> 2014-09-04 01:44:32,738 [DEBUG] subscription-manager @base_action_client.py:85 - running lib: <subscription_manager.repolib.RepoActionInvoker object at 0x31e9b90>
Yup, still there. 18eeb867dc7d13958a999efb23c88258d5c0c34a was a fix for a related and similar bug, but not this one. I got them confused. Afaict, this should only result in a logged exception, and not any functional changes. Liushihui: Are you seeing any functional problems or crashes? Is it just the logged exception?
new pr at https://github.com/candlepin/subscription-manager/pull/1019 It avoids raising the exception that is logged
commit 9b8708421f02c5cf8515bde1fa6c9895a87de377 Author: Adrian Likins <alikins@redhat.com> Date: Fri Sep 5 10:50:06 2014 -0400 1128061: Don't raise logged Disconnected on unreg BaseActionInvoker handles and logs any exceptions raise from *certlib actions. For unregister, when we run the UnregisterAction, we have already deleted id cert, ent certs, repos, so we would always raise Disconnected, and then it would get logged. In either cause, entcertlib's actions don't do much, so just return empty results instead of raising an exception that gets logged.
Hi,Adrian I haven't seen any functional problems , it's just the logged exception. Thanks. (In reply to Adrian Likins from comment #11) > Yup, still there. 18eeb867dc7d13958a999efb23c88258d5c0c34a was a fix for a > related and similar bug, but not this one. I got them confused. > > Afaict, this should only result in a logged exception, and not any > functional changes. > > Liushihui: Are you seeing any functional problems or crashes? Is it just the > logged exception?
Check it on subscription-manager-1.12.14-5.el6.x86_64. it won't show [error] message when unregister system to SAM server. Please see the log as the following: Therefore, Verify it on subscription-manager-1.12.14-5.el6.x86_64. 2014-09-11 01:26:24,917 [INFO] subscription-manager @managerlib.py:807 - Successfully un-registered. 2014-09-11 01:26:24,923 [DEBUG] subscription-manager @managerlib.py:853 - Removing identity cert: /etc/pki/consumer/key.pem 2014-09-11 01:26:24,923 [DEBUG] subscription-manager @managerlib.py:853 - Removing identity cert: /etc/pki/consumer/cert.pem 2014-09-11 01:26:24,924 [DEBUG] subscription-manager @identity.py:131 - Loading consumer info from identity certificates. 2014-09-11 01:26:24,924 [DEBUG] subscription-manager @identity.py:143 - 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' 2014-09-11 01:26:24,925 [INFO] subscription-manager @cache.py:86 - Deleting cache: /var/lib/rhsm/cache/installed_products.json 2014-09-11 01:26:24,925 [INFO] subscription-manager @cache.py:86 - Deleting cache: /var/lib/rhsm/facts/facts.json 2014-09-11 01:26:24,925 [INFO] subscription-manager @cache.py:86 - Deleting cache: /var/lib/rhsm/cache/entitlement_status.json 2014-09-11 01:26:24,926 [INFO] subscription-manager @cache.py:86 - Deleting cache: /var/lib/rhsm/cache/written_overrides.json 2014-09-11 01:26:24,926 [INFO] subscription-manager @managerlib.py:878 - Cleaned local data 2014-09-11 01:26:24,927 [DEBUG] subscription-manager @base_action_client.py:85 - running lib: <subscription_manager.entcertlib.EntCertActionInvoker object at 0x33007d0> 2014-09-11 01:26:24,928 [INFO] subscription-manager @entcertlib.py:131 - certs updated: Total updates: 0 Found (local) serial# [] Expected (UEP) serial# [] Added (new) <NONE> Deleted (rogue): <NONE> 2014-09-11 01:26:24,929 [DEBUG] subscription-manager @base_action_client.py:85 - running lib: <subscription_manager.content_action_client.ContentActionClient object at 0x3300290> 2014-09-11 01:26:24,929 [DEBUG] subscription-manager @base_action_client.py:85 - running lib: <subscription_manager.repolib.RepoActionInvoker object at 0x3300c10> 2014-09-11 01:26:24,930 [INFO] subscription-manager @repolib.py:207 - repos updated: Repo updates Total repo updates: 0 Updated <NONE> Added (new) <NONE> Deleted <NONE> 2014-09-11 01:26:24,932 [DEBUG] subscription-manager @certdirectory.py:216 - Installed product IDs: ['69'] 2014-09-11 01:26:24,932 [DEBUG] subscription-manager @cert_sorter.py:126 - Unregistered, skipping server compliance check. 2014-09-11 01:26:25,080 [INFO] rhsmd @rhsmd:194 - rhsmd started 2014-09-11 01:26:25,099 [INFO] rhsmd @rhsmd:149 - D-Bus interface com.redhat.SubscriptionManager.EntitlementStatus.update_status called with status = 0 2014-09-11 01:26:25,129 [DEBUG] rhsmd @identity.py:131 - Loading consumer info from identity certificates. 2014-09-11 01:26:25,130 [DEBUG] rhsmd @identity.py:143 - 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' 2014-09-11 01:26:25,130 [INFO] rhsmd @rhsmd:117 - D-Bus signal com.redhat.SubscriptionManager.EntitlementStatus.entitlement_status_changed emitted
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. http://rhn.redhat.com/errata/RHBA-2014-1384.html