Description of problem: Our automation test suite has been encountering errors like the following: ssh root.redhat.com subscription-manager subscribe --pool=8a90f81a403693dc01403695d8e804a7 Stdout: Successfully attached a subscription for: Awesome OS Server Basic (multi-entitlement) Stderr: [Errno 2] No such file or directory: '/etc/pki/entitlement/6784901986324441653.pem' ExitCode: 255 ssh root.redhat.com subscription-manager subscribe --pool=8a90f81a403693dc01403695e4ae06ef Stdout: Successfully attached a subscription for: Awesome OS with unlimited virtual guests Stderr: [Errno 2] No such file or directory: '/etc/pki/entitlement/4512705153693985396.pem' ExitCode: 255 I found this traceback in the rhsm.log from last night's automation run. Hopefully it can shed some light on the cause.... I have not been able to manually re-create the failure on demand. Nevertheless the automation test suite continues to hit it... 2013-08-01 11:20:04,126 [INFO] @managercli.py:292 - Client Versions: {'python-rhsm': '1.8.15-1.git.0.1e2cca6.el5', 'subscription-manager': '1.8.14-1.git.19.e0618a9.el5'} 2013-08-01 11:20:04,127 [INFO] @connection.py:583 - Using certificate authentication: key = /etc/pki/consumer/key.pem, cert = /etc/pki/consumer/cert.pem, ca = /etc/rhsm/ca/, insecure = False 2013-08-01 11:20:04,127 [INFO] @connection.py:596 - Connection Built: host: jsefler-f14-5candlepin.usersys.redhat.com, port: 8443, handler: /candlepin 2013-08-01 11:20:04,128 [INFO] @connection.py:593 - Using no auth 2013-08-01 11:20:04,128 [INFO] @connection.py:596 - Connection Built: host: jsefler-f14-5candlepin.usersys.redhat.com, port: 8443, handler: /candlepin 2013-08-01 11:20:04,160 [DEBUG] @connection.py:434 - Response status: 200 2013-08-01 11:20:04,163 [DEBUG] @plugins.py:705 - Running handler in all_slots_test.AllSlotsTestPlugin 2013-08-01 11:20:04,163 [INFO] @all_slots_test.py:39 - Running handler for post_auto_attach_hook from slot post_auto_attach defined in all_slots_test. 2013-08-01 11:20:04,164 [DEBUG] @plugins.py:705 - Running post_auto_attach_hook in auto_attach_test.AutoAttachTestPlugin 2013-08-01 11:20:04,165 [INFO] @auto_attach_test.py:43 - Running post_auto_attach_hook: system just auto-attached 2013-08-01 11:20:04,165 [INFO] @auto_attach_test.py:44 - Running post_auto_attach_hook: auto-attached consumer is 8b4f5f57-62ae-40cc-afbc-47dc59507c43 2013-08-01 11:20:04,166 [INFO] @auto_attach_test.py:46 - Running post_auto_attach_hook: auto-attached 0 entitlements 2013-08-01 11:20:04,167 [DEBUG] @injection.py:80 - Returning instance for feature ENT_DIR 2013-08-01 11:20:04,169 [DEBUG] @connection.py:394 - Loading CA PEM certificates from: /etc/rhsm/ca/ 2013-08-01 11:20:04,169 [DEBUG] @connection.py:376 - Loading CA certificate: '/etc/rhsm/ca/jsefler-f14-5candlepin.pem' 2013-08-01 11:20:04,170 [DEBUG] @connection.py:376 - Loading CA certificate: '/etc/rhsm/ca/redhat-uep.pem' 2013-08-01 11:20:04,170 [DEBUG] @connection.py:376 - Loading CA certificate: '/etc/rhsm/ca/candlepin-stage.pem' 2013-08-01 11:20:04,171 [DEBUG] @connection.py:415 - Making request: GET /candlepin/consumers/6bfa0820-7cb4-461c-9bd7-e774940468ae/certificates/serials 2013-08-01 11:20:04,227 [DEBUG] @connection.py:394 - Loading CA PEM certificates from: /etc/rhsm/ca/ 2013-08-01 11:20:04,228 [DEBUG] @connection.py:376 - Loading CA certificate: '/etc/rhsm/ca/jsefler-f14-5candlepin.pem' 2013-08-01 11:20:04,228 [DEBUG] @connection.py:376 - Loading CA certificate: '/etc/rhsm/ca/redhat-uep.pem' 2013-08-01 11:20:04,228 [DEBUG] @connection.py:376 - Loading CA certificate: '/etc/rhsm/ca/candlepin-stage.pem' 2013-08-01 11:20:04,239 [DEBUG] @connection.py:415 - Making request: GET /candlepin/ 2013-08-01 11:20:04,264 [DEBUG] @connection.py:434 - Response status: 200 2013-08-01 11:20:04,268 [DEBUG] @connection.py:613 - Server supports the following resources: 2013-08-01 11:20:04,269 [DEBUG] @connection.py:614 - {'': '/', 'hypervisors': '/hypervisors', 'serials': '/serials', 'deleted_consumers': '/deleted_consumers', 'consumers': '/consumers', 'migrations': '/migrations', 'content': '/content', 'entitlements': '/entitlements', 'statistics/generate': '/statistics/generate', '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', 'events': '/events', 'products': '/products', 'pools': '/pools', 'crl': '/crl'} 2013-08-01 11:20:04,270 [DEBUG] @connection.py:394 - Loading CA PEM certificates from: /etc/rhsm/ca/ 2013-08-01 11:20:04,271 [DEBUG] @connection.py:376 - Loading CA certificate: '/etc/rhsm/ca/jsefler-f14-5candlepin.pem' 2013-08-01 11:20:04,272 [DEBUG] @connection.py:376 - Loading CA certificate: '/etc/rhsm/ca/redhat-uep.pem' 2013-08-01 11:20:04,273 [DEBUG] @connection.py:376 - Loading CA certificate: '/etc/rhsm/ca/candlepin-stage.pem' 2013-08-01 11:20:04,274 [DEBUG] @connection.py:415 - Making request: GET /candlepin/status 2013-08-01 11:20:04,314 [DEBUG] @connection.py:434 - Response status: 200 2013-08-01 11:20:04,314 [DEBUG] @connection.py:434 - Response status: 200 2013-08-01 11:20:04,316 [INFO] @managercli.py:303 - Server Versions: {'candlepin': '0.8.19-1', 'server-type': 'Red Hat Subscription Management'} 2013-08-01 11:20:04,317 [DEBUG] @injection.py:72 - Initializing singleton for feature CERT_SORTER 2013-08-01 11:20:04,318 [DEBUG] @injection.py:80 - Returning instance for feature CP_PROVIDER 2013-08-01 11:20:04,318 [ERROR] @certlib.py:158 - Error attempting to auto-heal: 2013-08-01 11:20:04,318 [DEBUG] @injection.py:80 - Returning instance for feature PROD_DIR 2013-08-01 11:20:04,319 [DEBUG] @injection.py:80 - Returning instance for feature ENT_DIR 2013-08-01 11:20:04,319 [DEBUG] @injection.py:80 - Returning instance for feature IDENTITY 2013-08-01 11:20:04,320 [DEBUG] @injection.py:80 - Returning instance for feature PROD_DIR 2013-08-01 11:20:04,319 [ERROR] @certlib.py:159 - [Errno 2] No such file or directory: '/etc/pki/entitlement/747295224863746693.pem' Traceback (most recent call last): File "/usr/share/rhsm/subscription_manager/certlib.py", line 135, in _do_update cert_updater.update() File "/usr/share/rhsm/subscription_manager/certlib.py", line 68, in update return self._do_update() File "/usr/share/rhsm/subscription_manager/certlib.py", line 91, in _do_update return action.perform() File "/usr/share/rhsm/subscription_manager/certlib.py", line 241, in perform self.delete(rogue_serials, report) File "/usr/share/rhsm/subscription_manager/certlib.py", line 312, in delete cert.delete() File "/usr/lib64/python2.4/site-packages/rhsm/certificate2.py", line 602, in delete Certificate.delete(self) File "/usr/lib64/python2.4/site-packages/rhsm/certificate2.py", line 472, in delete os.unlink(self.path) OSError: [Errno 2] No such file or directory: '/etc/pki/entitlement/747295224863746693.pem' 2013-08-01 11:20:04,358 [INFO] @cache.py:168 - Checking current system info against cache: /var/lib/rhsm/cache/installed_products.json 2013-08-01 11:20:04,359 [INFO] @cache.py:185 - No changes. 2013-08-01 11:20:04,359 [DEBUG] @certdirectory.py:204 - Installed product IDs: ['146', '1000000000000023', '1144', '100000000000011', '99000', '176', '27060', '69', '100000000000006', '1', '181', '37069', '37068', '37080', '37065', '37067', '37060', '37062', '100000000000060', '100000000000005', '100000000000002', '100000000000003', '100000000000000', '100000000000001', '213412341236', '213412341237', '213412341234', '213412341235', '100000000000020', '126', '90', '32060', '92', '88888', '100000000000069', '900', '917571', '801', '806', '37070']
Former bug 979492 was very similar to this bug.
Notice from the log that prior to the traceback there was an "Error attempting to auto-heal" which makes me think that there are two thread competing for management of the same entitlement file.
commit 64f3675e6390c1ce920d7bcf51e5f014d12672aa Author: ckozak <ckozak> Date: Fri Aug 2 10:15:20 2013 -0400 991214: refresh ent dir, catch exception gracefully
[root@jsefler-5 ~]# rpm -q subscription-manager subscription-manager-1.8.20-1.el5 Moving to VERIFIED: Our automation test suite is no longer encounterring this error.
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-2013-1332.html