Bug 1886628
| Summary: | rhsmcertd does not appear to catch a GoneException | ||
|---|---|---|---|
| Product: | Red Hat Enterprise Linux 8 | Reporter: | John Sefler <jsefler> |
| Component: | subscription-manager | Assignee: | Jiri Hnidek <jhnidek> |
| Status: | CLOSED ERRATA | QA Contact: | Red Hat subscription-manager QE Team <rhsm-qe> |
| Severity: | urgent | Docs Contact: | |
| Priority: | urgent | ||
| Version: | 8.4 | CC: | arpandey, cdonnell, csnyder, jhnidek, qianzhan, redakkan, skallesh |
| Target Milestone: | rc | Keywords: | Regression, Triaged |
| Target Release: | 8.0 | Flags: | pm-rhel:
mirror+
|
| Hardware: | Unspecified | ||
| OS: | Unspecified | ||
| Whiteboard: | |||
| Fixed In Version: | Doc Type: | If docs needed, set a value | |
| Doc Text: | Story Points: | --- | |
| Clone Of: | Environment: | ||
| Last Closed: | 2021-05-18 13:33:55 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
John Sefler
2020-10-09 00:34:30 UTC
To demonstrate that this is a Regression, I have downgraded to subscription-manager-1.27.16-1 (released on RHEL-8.3) and re-run the exact same scenario as presented above... [root@kvm-06-guest36 ~]# rpm -q subscription-manager subscription-manager-1.27.16-1.el8.x86_64 [root@kvm-06-guest36 ~]# [root@kvm-06-guest36 ~]# subscription-manager config --logging.default_log_level=DEBUG [root@kvm-06-guest36 ~]# subscription-manager config --rhsmcertd.splay=0 [root@kvm-06-guest36 ~]# [root@kvm-06-guest36 ~]# subscription-manager register --auto-attach --serverurl=subscription.rhsm.stage.redhat.com:443/subscription Registering to: subscription.rhsm.stage.redhat.com:443/subscription Username: stage_auto_testuser Password: The system has been registered with ID: 761077e6-e8a2-49fd-b2ee-f29f44bb5a67 The registered system name is: kvm-06-guest36.hv2.lab.eng.bos.redhat.com Installed Product Current Status: Product Name: Red Hat Enterprise Linux for x86_64 Beta Status: Subscribed [root@kvm-06-guest36 ~]# curl --stderr /dev/null --insecure --user stage_auto_testuser:REDACTED --request DELETE https://candlepin.corp.stage.redhat.com/candlepin/consumers/761077e6-e8a2-49fd-b2ee-f29f44bb5a67 [root@kvm-06-guest36 ~]# [root@kvm-06-guest36 ~]# subscription-manager identity Consumer profile "761077e6-e8a2-49fd-b2ee-f29f44bb5a67" has been deleted from the server. You can use command clean or unregister to remove local profile. [root@kvm-06-guest36 ~]# [root@kvm-06-guest36 ~]# truncate --size=0 /var/log/rhsm/rhsmcertd.log [root@kvm-06-guest36 ~]# truncate --size=0 /var/log/rhsm/rhsm.log [root@kvm-06-guest36 ~]# [root@kvm-06-guest36 ~]# date Thu Oct 8 20:16:45 EDT 2020 [root@kvm-06-guest36 ~]# [root@kvm-06-guest36 ~]# systemctl restart rhsmcertd.service [root@kvm-06-guest36 ~]# sleep 120 [root@kvm-06-guest36 ~]# [root@kvm-06-guest36 ~]# cat /var/log/rhsm/rhsmcertd.log Thu Oct 8 20:16:52 2020 [INFO] rhsmcertd is shutting down... Thu Oct 8 20:16:52 2020 [INFO] Starting rhsmcertd... Thu Oct 8 20:16:52 2020 [INFO] Auto-attach interval: 1440.0 minutes [86400 seconds] Thu Oct 8 20:16:52 2020 [INFO] Cert check interval: 240.0 minutes [14400 seconds] Thu Oct 8 20:16:52 2020 [INFO] Waiting 2.0 minutes plus 0 splay seconds [120 seconds total] before performing first auto-attach. Thu Oct 8 20:16:52 2020 [INFO] Waiting 2.0 minutes plus 0 splay seconds [120 seconds total] before performing first cert check. Thu Oct 8 20:18:53 2020 [WARN] (Cert Check) Update failed (255), retry will occur on next run. <================== VERIFIED EXPECTED RESULTS Thu Oct 8 20:18:54 2020 [WARN] (Auto-attach) Update failed (255), retry will occur on next run. <================== VERIFIED EXPECTED RESULTS [root@kvm-06-guest36 ~]# AS SHOWN ABOVE, THE rhsmcertd-worker FAILS TO UPDATE AS EXPECTED SINCE THE CONSUMER HAS BEEN DELETED ON THE SERVER MAKING IT IMPOSSIBLE TO UPDATE THE CERTS. THE rhsm.log FILE DISPLAYED BELOW CONFIRMS THAT A GoneException WAS ENCOUNTERED. [root@kvm-06-guest36 ~]# cat /var/log/rhsm/rhsm.log 2020-10-08 20:18:52,837 [DEBUG] rhsmcertd-worker:335510:MainThread @rhsmcertd_worker.py:70 - X-Correlation-ID: 51b303d78ed74f9faabb1c0b079cba76 2020-10-08 20:18:52,838 [DEBUG] rhsmcertd-worker:335510:MainThread @rhsmcertd_worker.py:74 - check for rhsmcertd disable 2020-10-08 20:18:52,839 [DEBUG] rhsmcertd-worker:335510:MainThread @connection.py:169 - Environment variable NO_PROXY= will be used 2020-10-08 20:18:52,839 [DEBUG] rhsmcertd-worker:335510:MainThread @connection.py:265 - Connection built: host=subscription.rhsm.stage.redhat.com port=443 handler=/subscription auth=identity_cert ca_dir=/etc/rhsm/ca/ insecure=False 2020-10-08 20:18:52,840 [DEBUG] rhsmcertd-worker:335510:MainThread @connection.py:685 - Making request: GET /subscription/ 2020-10-08 20:18:52,841 [DEBUG] rhsmcertd-worker:335510:MainThread @connection.py:570 - Loaded CA certificates from /etc/rhsm/ca/: rhsm-auto8-candlepin.pem, rhsm-auto8-gate-candlepin.pem, redhat-entitlement-authority.pem, redhat-uep.pem 2020-10-08 20:18:53,380 [DEBUG] rhsmcertd-worker:335510:MainThread @connection.py:779 - Response time: 0.461942195892334, Smoothed response time: 0.461942195892334 2020-10-08 20:18:53,380 [DEBUG] rhsmcertd-worker:335510:MainThread @connection.py:756 - Response: status=200, requestUuid=da47ac10-8fd7-4981-8003-f3e8db430e8a, request="GET /subscription/" 2020-10-08 20:18:53,381 [DEBUG] rhsmcertd-worker:335510:MainThread @connection.py:954 - Server supports the following resources: {'pools': '/pools', 'status': '/status', 'activation_keys': '/activation_keys', 'consumers': '/consumers', 'entitlements': '/entitlements', 'distributor_versions': '/distributor_versions', 'owners': '/owners', 'guestids': '/consumers/{consumer_uuid}/guestids', 'subscriptions': '/subscriptions', 'consumertypes': '/consumertypes', 'crl': '/crl', 'jobs': '/jobs', 'products': '/products', 'hypervisors': '/hypervisors', 'rules': '/rules', 'deleted_consumers': '/deleted_consumers', 'content': '/content', 'content_overrides': '/consumers/{consumer_uuid}/content_overrides', '': '/', 'serials': '/serials', 'admin': '/admin', 'cdn': '/cdn', 'users': '/users', 'roles': '/roles', 'packages': '/consumers/{consumer_uuid}/packages'} 2020-10-08 20:18:53,381 [DEBUG] rhsmcertd-worker:335510:MainThread @base_action_client.py:88 - running lib: <subscription_manager.entcertlib.EntCertActionInvoker object at 0x7fa7190f4160> 2020-10-08 20:18:53,381 [DEBUG] rhsmcertd-worker:335510:MainThread @identity.py:139 - Loading consumer info from identity certificates. 2020-10-08 20:18:53,384 [DEBUG] rhsmcertd-worker:335510:MainThread @connection.py:685 - Making request: GET /subscription/consumers/761077e6-e8a2-49fd-b2ee-f29f44bb5a67/certificates/serials 2020-10-08 20:18:53,384 [DEBUG] rhsmcertd-worker:335510:MainThread @connection.py:570 - Loaded CA certificates from /etc/rhsm/ca/: rhsm-auto8-candlepin.pem, rhsm-auto8-gate-candlepin.pem, redhat-entitlement-authority.pem, redhat-uep.pem 2020-10-08 20:18:53,932 [DEBUG] rhsmcertd-worker:335510:MainThread @connection.py:779 - Response time: 0.4605844020843506, Smoothed response time: 0.46180641651153564 2020-10-08 20:18:53,932 [DEBUG] rhsmcertd-worker:335510:MainThread @connection.py:756 - Response: status=410, requestUuid=cf6e8e8d-6c53-43db-b8d2-383fdb1f053a, request="GET /subscription/consumers/761077e6-e8a2-49fd-b2ee-f29f44bb5a67/certificates/serials" 2020-10-08 20:18:53,933 [CRITICAL] rhsmcertd-worker:335510:MainThread @rhsmcertd_worker.py:128 - Consumer profile "761077e6-e8a2-49fd-b2ee-f29f44bb5a67" has been deleted from the server. Its local certificates will now be archived 2020-10-08 20:18:53,934 [DEBUG] rhsmcertd-worker:335510:MainThread @managerlib.py:877 - Backing up /etc/pki/consumer to /etc/pki/consumer.old. 2020-10-08 20:18:53,934 [DEBUG] rhsmcertd-worker:335510:MainThread @managerlib.py:884 - Removing identity cert: /etc/pki/consumer/key.pem 2020-10-08 20:18:53,934 [DEBUG] rhsmcertd-worker:335510:MainThread @managerlib.py:884 - Removing identity cert: /etc/pki/consumer/cert.pem 2020-10-08 20:18:53,934 [DEBUG] rhsmcertd-worker:335510:MainThread @identity.py:139 - Loading consumer info from identity certificates. 2020-10-08 20:18:53,935 [DEBUG] rhsmcertd-worker:335510:MainThread @identity.py:154 - 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' 2020-10-08 20:18:53,935 [DEBUG] rhsmcertd-worker:335510:MainThread @managerlib.py:895 - Removing entitlement cert: /etc/pki/entitlement/4900223862453705370-key.pem 2020-10-08 20:18:53,935 [DEBUG] rhsmcertd-worker:335510:MainThread @managerlib.py:895 - Removing entitlement cert: /etc/pki/entitlement/4900223862453705370.pem 2020-10-08 20:18:53,935 [DEBUG] rhsmcertd-worker:335510:MainThread @cache.py:93 - Deleting cache: /var/lib/rhsm/cache/profile.json 2020-10-08 20:18:53,935 [DEBUG] rhsmcertd-worker:335510:MainThread @cache.py:93 - Deleting cache: /var/lib/rhsm/cache/installed_products.json 2020-10-08 20:18:53,936 [DEBUG] rhsmcertd-worker:335510:MainThread @files.py:351 - Successfully read local syspurpose contents. 2020-10-08 20:18:53,936 [DEBUG] rhsmcertd-worker:335510:MainThread @files.py:388 - Successfully read cached syspurpose contents. 2020-10-08 20:18:53,937 [DEBUG] rhsmcertd-worker:335510:MainThread @files.py:591 - Successfully updated syspurpose values at '/var/lib/rhsm/cache/syspurpose.json'. 2020-10-08 20:18:53,937 [DEBUG] rhsmcertd-worker:335510:MainThread @cache.py:93 - Deleting cache: /var/lib/rhsm/cache/entitlement_status.json 2020-10-08 20:18:53,937 [DEBUG] rhsmcertd-worker:335510:MainThread @cache.py:93 - Deleting cache: /var/lib/rhsm/cache/product_status.json 2020-10-08 20:18:53,937 [DEBUG] rhsmcertd-worker:335510:MainThread @cache.py:93 - Deleting cache: /var/lib/rhsm/cache/content_overrides.json 2020-10-08 20:18:53,937 [DEBUG] rhsmcertd-worker:335510:MainThread @repofile.py:364 - The directory /etc/yum.repos.d/ already exists 2020-10-08 20:18:53,938 [DEBUG] rhsmcertd-worker:335510:MainThread @cache.py:93 - Deleting cache: /var/lib/rhsm/cache/written_overrides.json 2020-10-08 20:18:53,938 [DEBUG] rhsmcertd-worker:335510:MainThread @managerlib.py:921 - Cleaned local data 2020-10-08 20:18:53,938 [CRITICAL] rhsmcertd-worker:335510:MainThread @rhsmcertd_worker.py:130 - Certificates archived to '/etc/pki/consumer.old'. Contact your system administrator if you need more information. 2020-10-08 20:18:53,938 [ERROR] rhsmcertd-worker:335510:MainThread @rhsmcertd_worker.py:156 - Error while updating certificates using daemon 2020-10-08 20:18:53,938 [ERROR] rhsmcertd-worker:335510:MainThread @rhsmcertd_worker.py:158 - HTTP error (410 - Gone): Unit 761077e6-e8a2-49fd-b2ee-f29f44bb5a67 has been deleted Traceback (most recent call last): File "/usr/lib64/python3.6/site-packages/subscription_manager/scripts/rhsmcertd_worker.py", line 147, in main _main(options, log) File "/usr/lib64/python3.6/site-packages/subscription_manager/scripts/rhsmcertd_worker.py", line 132, in _main raise ge File "/usr/lib64/python3.6/site-packages/subscription_manager/scripts/rhsmcertd_worker.py", line 94, in _main actionclient.update(options.autoheal) File "/usr/lib64/python3.6/site-packages/subscription_manager/base_action_client.py", line 55, in update self.update_reports = self._run_updates(autoheal) File "/usr/lib64/python3.6/site-packages/subscription_manager/base_action_client.py", line 89, in _run_updates update_report = self._run_update(lib) File "/usr/lib64/python3.6/site-packages/subscription_manager/base_action_client.py", line 63, in _run_update update_report = lib.update() File "/usr/lib64/python3.6/site-packages/subscription_manager/certlib.py", line 32, in update self.report = self.locker.run(self._do_update) File "/usr/lib64/python3.6/site-packages/subscription_manager/certlib.py", line 18, in run return action() File "/usr/lib64/python3.6/site-packages/subscription_manager/entcertlib.py", line 42, in _do_update return action.perform() File "/usr/lib64/python3.6/site-packages/subscription_manager/entcertlib.py", line 119, in perform expected = self._get_expected_serials() File "/usr/lib64/python3.6/site-packages/subscription_manager/entcertlib.py", line 292, in _get_expected_serials exp = self.get_certificate_serials_list() File "/usr/lib64/python3.6/site-packages/subscription_manager/entcertlib.py", line 272, in get_certificate_serials_list reply = self.uep.getCertificateSerials(identity.uuid) File "/usr/lib64/python3.6/site-packages/rhsm/connection.py", line 1340, in getCertificateSerials return self.conn.request_get(method) File "/usr/lib64/python3.6/site-packages/rhsm/connection.py", line 880, in request_get return self._request("GET", method, headers=headers, cert_key_pairs=cert_key_pairs) File "/usr/lib64/python3.6/site-packages/rhsm/connection.py", line 906, in _request info=info, headers=headers, cert_key_pairs=cert_key_pairs) File "/usr/lib64/python3.6/site-packages/rhsm/connection.py", line 765, in _request self.validateResponse(result, request_type, handler) File "/usr/lib64/python3.6/site-packages/rhsm/connection.py", line 809, in validateResponse parsed['deletedId']) rhsm.connection.GoneException: HTTP error (410 - Gone): Unit 761077e6-e8a2-49fd-b2ee-f29f44bb5a67 has been deleted 2020-10-08 20:18:54,277 [DEBUG] rhsmcertd-worker:335514:MainThread @rhsmcertd_worker.py:70 - X-Correlation-ID: ad1056009cf44ccdb6ffdf3f970440aa 2020-10-08 20:18:54,278 [DEBUG] rhsmcertd-worker:335514:MainThread @rhsmcertd_worker.py:74 - check for rhsmcertd disable 2020-10-08 20:18:54,278 [ERROR] rhsmcertd-worker:335514:MainThread @rhsmcertd_worker.py:81 - Either the consumer is not registered or the certificates are corrupted. Certificate update using daemon failed. [root@kvm-06-guest36 ~]# Early testing: Verifying on latest dev build : subscription-manager-1.28.5-1.el8.x86_64 [root@kvm-03-guest14 ~]# subscription-manager version server type: This system is currently not registered. subscription management server: 3.2.0-1 subscription management rules: 5.41 subscription-manager: 1.28.5-1.el8 [root@kvm-03-guest14 ~]# subscription-manager config --logging.default_log_level=DEBUG [root@kvm-03-guest14 ~]# subscription-manager config --rhsmcertd.splay=0 [root@kvm-03-guest14 ~]# [root@kvm-03-guest14 ~]# subscription-manager register --auto-attach --username stage-ethel --serverurl subscription.rhsm.stage.redhat.com Registering to: subscription.rhsm.stage.redhat.com:443/subscription Password: The system has been registered with ID: 146835d5-b232-4dde-9ace-39ed3792af87 The registered system name is: kvm-03-guest14.hv2.lab.eng.bos.redhat.com Installed Product Current Status: Product Name: Red Hat Enterprise Linux for x86_64 Beta Status: Subscribed [root@kvm-03-guest14 ~]# curl --stderr /dev/null --insecure --user stage-ethel:India@123 --request DELETE https://candlepin.corp.stage.redhat.com/candlepin/consumers/146835d5-b232-4dde-9ace-39ed3792af87 [root@kvm-03-guest14 ~]# [root@kvm-03-guest14 ~]# subscription-manager identity Consumer profile "146835d5-b232-4dde-9ace-39ed3792af87" has been deleted from the server. You can use command clean or unregister to remove local profile. [root@kvm-03-guest14 ~]# truncate --size=0 /var/log/rhsm/rhsmcertd.log [root@kvm-03-guest14 ~]# truncate --size=0 /var/log/rhsm/rhsm.log [root@kvm-03-guest14 ~]# date Tue Nov 3 04:57:11 EST 2020 [root@kvm-03-guest14 ~]# systemctl restart rhsmcertd.service [root@kvm-03-guest14 ~]# [root@kvm-03-guest14 ~]# sleep 120 [root@kvm-03-guest14 ~]# [root@kvm-03-guest14 ~]# cat /var/log/rhsm/rhsmcertd.log Tue Nov 3 04:57:25 2020 [INFO] rhsmcertd is shutting down... Tue Nov 3 04:57:25 2020 [INFO] Starting rhsmcertd... Tue Nov 3 04:57:25 2020 [INFO] Auto-attach interval: 1440.0 minutes [86400 seconds] Tue Nov 3 04:57:25 2020 [INFO] Cert check interval: 240.0 minutes [14400 seconds] Tue Nov 3 04:57:25 2020 [INFO] Waiting 2.0 minutes plus 0 splay seconds [120 seconds total] before performing first auto-attach. Tue Nov 3 04:57:25 2020 [INFO] Waiting 2.0 minutes plus 0 splay seconds [120 seconds total] before performing first cert check. Tue Nov 3 04:59:26 2020 [WARN] (Cert Check) Update failed (255), retry will occur on next run. <<<<<<<<<<< expected behavior Tue Nov 3 04:59:26 2020 [WARN] (Auto-attach) Update failed (255), retry will occur on next run. <<<<<<<<<<< expected behavior [root@kvm-03-guest14 ~]# Actual Results: rhsmcertd-worker fails to update as consumer has been deleted on server ^^^ Based on above observation moving verified field to tested Additional info: [root@kvm-03-guest14 ~]# cat /var/log/rhsm/rhsm.log 2020-11-03 04:59:25,510 [DEBUG] rhsmcertd-worker:50003:MainThread @rhsmcertd_worker.py:70 - X-Correlation-ID: d12c075b3e7a4ee397fff08e9ace8307 2020-11-03 04:59:25,510 [DEBUG] rhsmcertd-worker:50003:MainThread @rhsmcertd_worker.py:74 - check for rhsmcertd disable 2020-11-03 04:59:25,512 [DEBUG] rhsmcertd-worker:50003:MainThread @connection.py:171 - Environment variable NO_PROXY= will be used 2020-11-03 04:59:25,512 [DEBUG] rhsmcertd-worker:50003:MainThread @connection.py:267 - Connection built: host=subscription.rhsm.stage.redhat.com port=443 handler=/subscription auth=identity_cert ca_dir=/etc/rhsm/ca/ insecure=False 2020-11-03 04:59:25,512 [DEBUG] rhsmcertd-worker:50003:MainThread @connection.py:698 - Making request: GET /subscription/ 2020-11-03 04:59:25,513 [DEBUG] rhsmcertd-worker:50003:MainThread @connection.py:556 - Loaded CA certificates from /etc/rhsm/ca/: redhat-entitlement-authority.pem, redhat-uep.pem 2020-11-03 04:59:26,052 [DEBUG] rhsmcertd-worker:50003:MainThread @connection.py:792 - Response time: 0.46146273612976074, Smoothed response time: 0.46146273612976074 2020-11-03 04:59:26,052 [DEBUG] rhsmcertd-worker:50003:MainThread @connection.py:769 - Response: status=200, requestUuid=2fbf20a3-67ba-4b32-80f1-8d4456f5b1ae, request="GET /subscription/" 2020-11-03 04:59:26,053 [DEBUG] rhsmcertd-worker:50003:MainThread @connection.py:969 - Server supports the following resources: {'admin': '/admin', 'status': '/status', 'subscriptions': '/subscriptions', 'crl': '/crl', 'cdn': '/cdn', 'deleted_consumers': '/deleted_consumers', 'jobs': '/jobs', 'distributor_versions': '/distributor_versions', 'pools': '/pools', 'roles': '/roles', 'guestids': '/consumers/{consumer_uuid}/guestids', 'entitlements': '/entitlements', 'content_overrides': '/consumers/{consumer_uuid}/content_overrides', 'content': '/content', 'activation_keys': '/activation_keys', '': '/', 'products': '/products', 'consumers': '/consumers', 'users': '/users', 'consumertypes': '/consumertypes', 'owners': '/owners', 'serials': '/serials', 'rules': '/rules', 'hypervisors': '/hypervisors', 'packages': '/consumers/{consumer_uuid}/packages'} 2020-11-03 04:59:26,053 [DEBUG] rhsmcertd-worker:50003:MainThread @base_action_client.py:88 - running lib: <subscription_manager.entcertlib.EntCertActionInvoker object at 0x7f573b895630> 2020-11-03 04:59:26,054 [DEBUG] rhsmcertd-worker:50003:MainThread @identity.py:139 - Loading consumer info from identity certificates. 2020-11-03 04:59:26,056 [DEBUG] rhsmcertd-worker:50003:MainThread @connection.py:698 - Making request: GET /subscription/consumers/146835d5-b232-4dde-9ace-39ed3792af87/certificates/serials 2020-11-03 04:59:26,057 [DEBUG] rhsmcertd-worker:50003:MainThread @connection.py:556 - Loaded CA certificates from /etc/rhsm/ca/: redhat-entitlement-authority.pem, redhat-uep.pem 2020-11-03 04:59:26,605 [DEBUG] rhsmcertd-worker:50003:MainThread @connection.py:792 - Response time: 0.45885133743286133, Smoothed response time: 0.4612015962600708 2020-11-03 04:59:26,605 [DEBUG] rhsmcertd-worker:50003:MainThread @connection.py:769 - Response: status=410, requestUuid=6aeb1996-c9e7-4d2b-8b84-f5864d1f1562, request="GET /subscription/consumers/146835d5-b232-4dde-9ace-39ed3792af87/certificates/serials" 2020-11-03 04:59:26,607 [CRITICAL] rhsmcertd-worker:50003:MainThread @rhsmcertd_worker.py:128 - Consumer profile "146835d5-b232-4dde-9ace-39ed3792af87" has been deleted from the server. Its local certificates will now be archived 2020-11-03 04:59:26,607 [DEBUG] rhsmcertd-worker:50003:MainThread @managerlib.py:877 - Backing up /etc/pki/consumer to /etc/pki/consumer.old. 2020-11-03 04:59:26,608 [DEBUG] rhsmcertd-worker:50003:MainThread @managerlib.py:884 - Removing identity cert: /etc/pki/consumer/key.pem 2020-11-03 04:59:26,608 [DEBUG] rhsmcertd-worker:50003:MainThread @managerlib.py:884 - Removing identity cert: /etc/pki/consumer/cert.pem 2020-11-03 04:59:26,608 [DEBUG] rhsmcertd-worker:50003:MainThread @identity.py:139 - Loading consumer info from identity certificates. 2020-11-03 04:59:26,608 [DEBUG] rhsmcertd-worker:50003:MainThread @identity.py:154 - 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' 2020-11-03 04:59:26,608 [DEBUG] rhsmcertd-worker:50003:MainThread @managerlib.py:895 - Removing entitlement cert: /etc/pki/entitlement/504865718662545581-key.pem 2020-11-03 04:59:26,608 [DEBUG] rhsmcertd-worker:50003:MainThread @managerlib.py:895 - Removing entitlement cert: /etc/pki/entitlement/504865718662545581.pem 2020-11-03 04:59:26,608 [DEBUG] rhsmcertd-worker:50003:MainThread @cache.py:93 - Deleting cache: /var/lib/rhsm/cache/profile.json 2020-11-03 04:59:26,609 [DEBUG] rhsmcertd-worker:50003:MainThread @cache.py:93 - Deleting cache: /var/lib/rhsm/cache/installed_products.json 2020-11-03 04:59:26,609 [DEBUG] rhsmcertd-worker:50003:MainThread @cache.py:93 - Deleting cache: /var/lib/rhsm/cache/entitlement_status.json 2020-11-03 04:59:26,609 [DEBUG] rhsmcertd-worker:50003:MainThread @cache.py:93 - Deleting cache: /var/lib/rhsm/cache/product_status.json 2020-11-03 04:59:26,609 [DEBUG] rhsmcertd-worker:50003:MainThread @cache.py:93 - Deleting cache: /var/lib/rhsm/cache/content_overrides.json 2020-11-03 04:59:26,609 [DEBUG] rhsmcertd-worker:50003:MainThread @repofile.py:364 - The directory /etc/yum.repos.d/ already exists 2020-11-03 04:59:26,609 [DEBUG] rhsmcertd-worker:50003:MainThread @cache.py:93 - Deleting cache: /var/lib/rhsm/cache/written_overrides.json 2020-11-03 04:59:26,609 [DEBUG] rhsmcertd-worker:50003:MainThread @managerlib.py:921 - Cleaned local data 2020-11-03 04:59:26,609 [CRITICAL] rhsmcertd-worker:50003:MainThread @rhsmcertd_worker.py:130 - Certificates archived to '/etc/pki/consumer.old'. Contact your system administrator if you need more information. 2020-11-03 04:59:26,609 [ERROR] rhsmcertd-worker:50003:MainThread @rhsmcertd_worker.py:156 - Error while updating certificates using daemon 2020-11-03 04:59:26,609 [ERROR] rhsmcertd-worker:50003:MainThread @rhsmcertd_worker.py:158 - HTTP error (410 - Gone): Unit 146835d5-b232-4dde-9ace-39ed3792af87 has been deleted Traceback (most recent call last): File "/usr/lib64/python3.6/site-packages/subscription_manager/scripts/rhsmcertd_worker.py", line 147, in main _main(options, log) File "/usr/lib64/python3.6/site-packages/subscription_manager/scripts/rhsmcertd_worker.py", line 132, in _main raise ge File "/usr/lib64/python3.6/site-packages/subscription_manager/scripts/rhsmcertd_worker.py", line 94, in _main actionclient.update(options.autoheal) File "/usr/lib64/python3.6/site-packages/subscription_manager/base_action_client.py", line 55, in update self.update_reports = self._run_updates(autoheal) File "/usr/lib64/python3.6/site-packages/subscription_manager/base_action_client.py", line 89, in _run_updates update_report = self._run_update(lib) File "/usr/lib64/python3.6/site-packages/subscription_manager/base_action_client.py", line 63, in _run_update update_report = lib.update() File "/usr/lib64/python3.6/site-packages/subscription_manager/certlib.py", line 32, in update self.report = self.locker.run(self._do_update) File "/usr/lib64/python3.6/site-packages/subscription_manager/certlib.py", line 18, in run return action() File "/usr/lib64/python3.6/site-packages/subscription_manager/entcertlib.py", line 42, in _do_update return action.perform() File "/usr/lib64/python3.6/site-packages/subscription_manager/entcertlib.py", line 119, in perform expected = self._get_expected_serials() File "/usr/lib64/python3.6/site-packages/subscription_manager/entcertlib.py", line 292, in _get_expected_serials exp = self.get_certificate_serials_list() File "/usr/lib64/python3.6/site-packages/subscription_manager/entcertlib.py", line 272, in get_certificate_serials_list reply = self.uep.getCertificateSerials(identity.uuid) File "/usr/lib64/python3.6/site-packages/rhsm/connection.py", line 1355, in getCertificateSerials return self.conn.request_get(method) File "/usr/lib64/python3.6/site-packages/rhsm/connection.py", line 893, in request_get return self._request("GET", method, headers=headers, cert_key_pairs=cert_key_pairs) File "/usr/lib64/python3.6/site-packages/rhsm/connection.py", line 919, in _request info=info, headers=headers, cert_key_pairs=cert_key_pairs) File "/usr/lib64/python3.6/site-packages/rhsm/connection.py", line 778, in _request self.validateResponse(result, request_type, handler) File "/usr/lib64/python3.6/site-packages/rhsm/connection.py", line 822, in validateResponse parsed['deletedId']) rhsm.connection.GoneException: HTTP error (410 - Gone): Unit 146835d5-b232-4dde-9ace-39ed3792af87 has been deleted <<<<<<<<<<<<<<<<<<<<< A GoneException WAS ENCOUNTERED. 2020-11-03 04:59:26,918 [DEBUG] rhsmcertd-worker:50005:MainThread @rhsmcertd_worker.py:70 - X-Correlation-ID: 4bfddf3e7cc54a80ac195af9c4e70c5c 2020-11-03 04:59:26,918 [DEBUG] rhsmcertd-worker:50005:MainThread @rhsmcertd_worker.py:74 - check for rhsmcertd disable 2020-11-03 04:59:26,918 [ERROR] rhsmcertd-worker:50005:MainThread @rhsmcertd_worker.py:81 - Either the consumer is not registered or the certificates are corrupted. Certificate update using daemon failed. [root@kvm-03-guest14 ~]# Verification: [root@kvm-02-guest17 ~]# subscription-manager version server type: This system is currently not registered. subscription management server: 3.2.0-1 subscription management rules: 5.41 subscription-manager: 1.28.5-1.el8 [root@kvm-02-guest17 ~]# subscription-manager register --auto-attach --serverurl=subscription.rhsm.stage.redhat.com:443/subscription Registering to: subscription.rhsm.stage.redhat.com:443/subscription Username: stage_auto_testuser Password: The system has been registered with ID: 4afe6bd6-4c1d-45a7-8f23-2a3783d60859 The registered system name is: kvm-02-guest17.lab.eng.rdu2.redhat.com Installed Product Current Status: Product Name: Red Hat Enterprise Linux for x86_64 Beta Status: Subscribed [root@kvm-02-guest17 ~]# curl --stderr /dev/null --insecure --user stage_auto_testuser:redhat --request DELETE https://candlepin.corp.stage.redhat.com/candlepin/consumers/4afe6bd6-4c1d-45a7-8f23-2a3783d60859 [root@kvm-02-guest17 ~]# subscription-manager identity Consumer profile "4afe6bd6-4c1d-45a7-8f23-2a3783d60859" has been deleted from the server. You can use command clean or unregister to remove local profile. [root@kvm-02-guest17 ~]# truncate --size=0 /var/log/rhsm/rhsmcertd.log [root@kvm-02-guest17 ~]# truncate --size=0 /var/log/rhsm/rhsm.log [root@kvm-02-guest17 ~]# date Tue Nov 10 22:23:15 EST 2020 [root@kvm-02-guest17 ~]# systemctl restart rhsmcertd.service [root@kvm-02-guest17 ~]# cat /var/log/rhsm/rhsmcertd.log Tue Nov 10 22:23:28 2020 [INFO] rhsmcertd is shutting down... Tue Nov 10 22:23:28 2020 [INFO] Starting rhsmcertd... Tue Nov 10 22:23:28 2020 [INFO] Auto-attach interval: 1440.0 minutes [86400 seconds] Tue Nov 10 22:23:28 2020 [INFO] Cert check interval: 240.0 minutes [14400 seconds] Tue Nov 10 22:23:28 2020 [INFO] Waiting 2.0 minutes plus 0 splay seconds [120 seconds total] before performing first auto-attach. Tue Nov 10 22:23:28 2020 [INFO] Waiting 2.0 minutes plus 0 splay seconds [120 seconds total] before performing first cert check. Tue Nov 10 22:25:30 2020 [WARN] (Cert Check) Update failed (255), retry will occur on next run. ----------------> rhsmcertd failed to update the certs , which is expected Tue Nov 10 22:25:30 2020 [WARN] (Auto-attach) Update failed (255), retry will occur on next run. ----------------> [root@kvm-02-guest17 ~]# cat /var/log/rhsm/rhsm.log 2020-11-10 22:25:29,246 [DEBUG] rhsmcertd-worker:35451:MainThread @rhsmcertd_worker.py:70 - X-Correlation-ID: 17c10d36d6c947158496243500ca5a44 2020-11-10 22:25:29,246 [DEBUG] rhsmcertd-worker:35451:MainThread @rhsmcertd_worker.py:74 - check for rhsmcertd disable 2020-11-10 22:25:29,247 [DEBUG] rhsmcertd-worker:35451:MainThread @connection.py:171 - Environment variable NO_PROXY= will be used 2020-11-10 22:25:29,248 [DEBUG] rhsmcertd-worker:35451:MainThread @connection.py:267 - Connection built: host=subscription.rhsm.stage.redhat.com port=443 handler=/subscription auth=identity_cert ca_dir=/etc/rhsm/ca/ insecure=False 2020-11-10 22:25:29,248 [DEBUG] rhsmcertd-worker:35451:MainThread @connection.py:698 - Making request: GET /subscription/ 2020-11-10 22:25:29,249 [DEBUG] rhsmcertd-worker:35451:MainThread @connection.py:556 - Loaded CA certificates from /etc/rhsm/ca/: redhat-entitlement-authority.pem, redhat-uep.pem 2020-11-10 22:25:29,681 [DEBUG] rhsmcertd-worker:35451:MainThread @connection.py:792 - Response time: 0.37337779998779297, Smoothed response time: 0.37337779998779297 2020-11-10 22:25:29,681 [DEBUG] rhsmcertd-worker:35451:MainThread @connection.py:769 - Response: status=200, requestUuid=91351f4c-e650-45b2-8563-94995f1e6880, request="GET /subscription/" 2020-11-10 22:25:29,682 [DEBUG] rhsmcertd-worker:35451:MainThread @connection.py:969 - Server supports the following resources: {'admin': '/admin', 'pools': '/pools', 'subscriptions': '/subscriptions', 'roles': '/roles', 'users': '/users', 'content_overrides': '/consumers/{consumer_uuid}/content_overrides', 'distributor_versions': '/distributor_versions', 'serials': '/serials', 'consumers': '/consumers', 'consumertypes': '/consumertypes', 'activation_keys': '/activation_keys', 'rules': '/rules', 'cdn': '/cdn', 'deleted_consumers': '/deleted_consumers', 'jobs': '/jobs', 'content': '/content', 'status': '/status', 'entitlements': '/entitlements', 'hypervisors': '/hypervisors', 'products': '/products', 'crl': '/crl', 'owners': '/owners', '': '/', 'guestids': '/consumers/{consumer_uuid}/guestids', 'packages': '/consumers/{consumer_uuid}/packages'} 2020-11-10 22:25:29,683 [DEBUG] rhsmcertd-worker:35451:MainThread @base_action_client.py:88 - running lib: <subscription_manager.entcertlib.EntCertActionInvoker object at 0x7f3816f99630> 2020-11-10 22:25:29,683 [DEBUG] rhsmcertd-worker:35451:MainThread @identity.py:139 - Loading consumer info from identity certificates. 2020-11-10 22:25:29,685 [DEBUG] rhsmcertd-worker:35451:MainThread @connection.py:698 - Making request: GET /subscription/consumers/4afe6bd6-4c1d-45a7-8f23-2a3783d60859/certificates/serials 2020-11-10 22:25:29,686 [DEBUG] rhsmcertd-worker:35451:MainThread @connection.py:556 - Loaded CA certificates from /etc/rhsm/ca/: redhat-entitlement-authority.pem, redhat-uep.pem 2020-11-10 22:25:30,128 [DEBUG] rhsmcertd-worker:35451:MainThread @connection.py:792 - Response time: 0.37347412109375, Smoothed response time: 0.37338743209838865 2020-11-10 22:25:30,128 [DEBUG] rhsmcertd-worker:35451:MainThread @connection.py:769 - Response: status=410, requestUuid=20c528c7-353b-4661-bdc7-76e16edb187c, request="GET /subscription/consumers/4afe6bd6-4c1d-45a7-8f23-2a3783d60859/certificates/serials" 2020-11-10 22:25:30,130 [CRITICAL] rhsmcertd-worker:35451:MainThread @rhsmcertd_worker.py:128 - Consumer profile "4afe6bd6-4c1d-45a7-8f23-2a3783d60859" has been deleted from the server. Its local certificates will now be archived 2020-11-10 22:25:30,130 [DEBUG] rhsmcertd-worker:35451:MainThread @managerlib.py:877 - Backing up /etc/pki/consumer to /etc/pki/consumer.old. 2020-11-10 22:25:30,131 [DEBUG] rhsmcertd-worker:35451:MainThread @managerlib.py:884 - Removing identity cert: /etc/pki/consumer/key.pem 2020-11-10 22:25:30,131 [DEBUG] rhsmcertd-worker:35451:MainThread @managerlib.py:884 - Removing identity cert: /etc/pki/consumer/cert.pem 2020-11-10 22:25:30,131 [DEBUG] rhsmcertd-worker:35451:MainThread @identity.py:139 - Loading consumer info from identity certificates. 2020-11-10 22:25:30,131 [DEBUG] rhsmcertd-worker:35451:MainThread @identity.py:154 - 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' 2020-11-10 22:25:30,131 [DEBUG] rhsmcertd-worker:35451:MainThread @managerlib.py:895 - Removing entitlement cert: /etc/pki/entitlement/3313510275800617422-key.pem 2020-11-10 22:25:30,131 [DEBUG] rhsmcertd-worker:35451:MainThread @managerlib.py:895 - Removing entitlement cert: /etc/pki/entitlement/3313510275800617422.pem 2020-11-10 22:25:30,131 [DEBUG] rhsmcertd-worker:35451:MainThread @cache.py:93 - Deleting cache: /var/lib/rhsm/cache/profile.json 2020-11-10 22:25:30,131 [DEBUG] rhsmcertd-worker:35451:MainThread @cache.py:93 - Deleting cache: /var/lib/rhsm/cache/installed_products.json 2020-11-10 22:25:30,132 [DEBUG] rhsmcertd-worker:35451:MainThread @files.py:351 - Successfully read local syspurpose contents. 2020-11-10 22:25:30,132 [DEBUG] rhsmcertd-worker:35451:MainThread @files.py:388 - Successfully read cached syspurpose contents. 2020-11-10 22:25:30,132 [DEBUG] rhsmcertd-worker:35451:MainThread @files.py:591 - Successfully updated syspurpose values at '/var/lib/rhsm/cache/syspurpose.json'. 2020-11-10 22:25:30,132 [DEBUG] rhsmcertd-worker:35451:MainThread @cache.py:93 - Deleting cache: /var/lib/rhsm/cache/entitlement_status.json 2020-11-10 22:25:30,132 [DEBUG] rhsmcertd-worker:35451:MainThread @cache.py:93 - Deleting cache: /var/lib/rhsm/cache/product_status.json 2020-11-10 22:25:30,132 [DEBUG] rhsmcertd-worker:35451:MainThread @cache.py:93 - Deleting cache: /var/lib/rhsm/cache/content_overrides.json 2020-11-10 22:25:30,132 [DEBUG] rhsmcertd-worker:35451:MainThread @repofile.py:364 - The directory /etc/yum.repos.d/ already exists 2020-11-10 22:25:30,133 [DEBUG] rhsmcertd-worker:35451:MainThread @cache.py:93 - Deleting cache: /var/lib/rhsm/cache/written_overrides.json 2020-11-10 22:25:30,133 [DEBUG] rhsmcertd-worker:35451:MainThread @managerlib.py:921 - Cleaned local data 2020-11-10 22:25:30,133 [CRITICAL] rhsmcertd-worker:35451:MainThread @rhsmcertd_worker.py:130 - Certificates archived to '/etc/pki/consumer.old'. Contact your system administrator if you need more information. 2020-11-10 22:25:30,133 [ERROR] rhsmcertd-worker:35451:MainThread @rhsmcertd_worker.py:156 - Error while updating certificates using daemon 2020-11-10 22:25:30,133 [ERROR] rhsmcertd-worker:35451:MainThread @rhsmcertd_worker.py:158 - HTTP error (410 - Gone): Unit 4afe6bd6-4c1d-45a7-8f23-2a3783d60859 has been deleted Traceback (most recent call last): File "/usr/lib64/python3.6/site-packages/subscription_manager/scripts/rhsmcertd_worker.py", line 147, in main _main(options, log) File "/usr/lib64/python3.6/site-packages/subscription_manager/scripts/rhsmcertd_worker.py", line 132, in _main raise ge File "/usr/lib64/python3.6/site-packages/subscription_manager/scripts/rhsmcertd_worker.py", line 94, in _main actionclient.update(options.autoheal) File "/usr/lib64/python3.6/site-packages/subscription_manager/base_action_client.py", line 55, in update self.update_reports = self._run_updates(autoheal) File "/usr/lib64/python3.6/site-packages/subscription_manager/base_action_client.py", line 89, in _run_updates update_report = self._run_update(lib) File "/usr/lib64/python3.6/site-packages/subscription_manager/base_action_client.py", line 63, in _run_update update_report = lib.update() File "/usr/lib64/python3.6/site-packages/subscription_manager/certlib.py", line 32, in update self.report = self.locker.run(self._do_update) File "/usr/lib64/python3.6/site-packages/subscription_manager/certlib.py", line 18, in run return action() File "/usr/lib64/python3.6/site-packages/subscription_manager/entcertlib.py", line 42, in _do_update return action.perform() File "/usr/lib64/python3.6/site-packages/subscription_manager/entcertlib.py", line 119, in perform expected = self._get_expected_serials() File "/usr/lib64/python3.6/site-packages/subscription_manager/entcertlib.py", line 292, in _get_expected_serials exp = self.get_certificate_serials_list() File "/usr/lib64/python3.6/site-packages/subscription_manager/entcertlib.py", line 272, in get_certificate_serials_list reply = self.uep.getCertificateSerials(identity.uuid) File "/usr/lib64/python3.6/site-packages/rhsm/connection.py", line 1355, in getCertificateSerials return self.conn.request_get(method) File "/usr/lib64/python3.6/site-packages/rhsm/connection.py", line 893, in request_get return self._request("GET", method, headers=headers, cert_key_pairs=cert_key_pairs) File "/usr/lib64/python3.6/site-packages/rhsm/connection.py", line 919, in _request info=info, headers=headers, cert_key_pairs=cert_key_pairs) File "/usr/lib64/python3.6/site-packages/rhsm/connection.py", line 778, in _request self.validateResponse(result, request_type, handler) File "/usr/lib64/python3.6/site-packages/rhsm/connection.py", line 822, in validateResponse parsed['deletedId']) rhsm.connection.GoneException: HTTP error (410 - Gone): Unit 4afe6bd6-4c1d-45a7-8f23-2a3783d60859 has been deleted ----------> gone exception with proper message is expected 2020-11-10 22:25:30,491 [DEBUG] rhsmcertd-worker:35453:MainThread @rhsmcertd_worker.py:70 - X-Correlation-ID: c0638f0e06284a4a91c89e8c4dbebd89 2020-11-10 22:25:30,491 [DEBUG] rhsmcertd-worker:35453:MainThread @rhsmcertd_worker.py:74 - check for rhsmcertd disable 2020-11-10 22:25:30,491 [ERROR] rhsmcertd-worker:35453:MainThread @rhsmcertd_worker.py:81 - Either the consumer is not registered or the certificates are corrupted. Certificate update using daemon failed. 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:1575 |