Note: This bug is displayed in read-only format because the product is no longer active in Red Hat Bugzilla.
RHEL Engineering is moving the tracking of its product development work on RHEL 6 through RHEL 9 to Red Hat Jira (issues.redhat.com). If you're a Red Hat customer, please continue to file support cases via the Red Hat customer portal. If you're not, please head to the "RHEL project" in Red Hat Jira and file new tickets here. Individual Bugzilla bugs in the statuses "NEW", "ASSIGNED", and "POST" are being migrated throughout September 2023. Bugs of Red Hat partners with an assigned Engineering Partner Manager (EPM) are migrated in late September as per pre-agreed dates. Bugs against components "kernel", "kernel-rt", and "kpatch" are only migrated if still in "NEW" or "ASSIGNED". If you cannot log in to RH Jira, please consult article #7032570. That failing, please send an e-mail to the RH Jira admins at rh-issues@redhat.com to troubleshoot your issue as a user management inquiry. The email creates a ServiceNow ticket with Red Hat. Individual Bugzilla bugs that are migrated will be moved to status "CLOSED", resolution "MIGRATED", and set with "MigratedToJIRA" in "Keywords". The link to the successor Jira issue will be found under "Links", have a little "two-footprint" icon next to it, and direct you to the "RHEL project" in Red Hat Jira (issue links are of type "https://issues.redhat.com/browse/RHEL-XXXX", where "X" is a digit). This same link will be available in a blue banner at the top of the page informing you that that bug has been migrated.

Bug 1886628

Summary: rhsmcertd does not appear to catch a GoneException
Product: Red Hat Enterprise Linux 8 Reporter: John Sefler <jsefler>
Component: subscription-managerAssignee: Jiri Hnidek <jhnidek>
Status: CLOSED ERRATA QA Contact: Red Hat subscription-manager QE Team <rhsm-qe>
Severity: urgent Docs Contact:
Priority: urgent    
Version: 8.4CC: arpandey, cdonnell, csnyder, jhnidek, qianzhan, redakkan, skallesh
Target Milestone: rcKeywords: Regression, Triaged
Target Release: 8.0Flags: 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
Description of problem:
In the test scenario below, a consumer registers with auto-attach and then a server-side event is invoked to delete the consumer thereby leaving the system dirty with an identity and entitlement cert that no longer exist on the entitlement server.  Essentially we are testing the ability for the system to catch a GoneException.


Version-Release number of selected component (if applicable):
[root@kvm-06-guest36 ~]# rpm -q subscription-manager
subscription-manager-1.28.4-1.el8.x86_64

How reproducible:
Happens after upgrading to subscription-manager-1.28.4-1 from version 
subscription-manager-1.27.16-1 (released on RHEL-8.3)

Steps to Reproduce:
[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: f09a84ce-6620-4447-a3aa-d9d29e05aa49
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/f09a84ce-6620-4447-a3aa-d9d29e05aa49
[root@kvm-06-guest36 ~]# 
[root@kvm-06-guest36 ~]# subscription-manager identity
Consumer profile "f09a84ce-6620-4447-a3aa-d9d29e05aa49" 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 19:47:21 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 19:47:35 2020 [INFO] rhsmcertd is shutting down...
Thu Oct  8 19:47:35 2020 [INFO] Starting rhsmcertd...
Thu Oct  8 19:47:35 2020 [INFO] Auto-attach interval: 1440.0 minutes [86400 seconds]
Thu Oct  8 19:47:35 2020 [INFO] Cert check interval: 240.0 minutes [14400 seconds]
Thu Oct  8 19:47:35 2020 [INFO] Waiting 2.0 minutes plus 0 splay seconds [120 seconds total] before performing first auto-attach.
Thu Oct  8 19:47:35 2020 [INFO] Waiting 2.0 minutes plus 0 splay seconds [120 seconds total] before performing first cert check.
Thu Oct  8 19:49:39 2020 [INFO] (Cert Check) Certificates updated.    <================== HOW WAS THIS POSSIBLE?
Thu Oct  8 19:49:41 2020 [INFO] (Auto-attach) Certificates updated.   <================== HOW WAS THIS POSSIBLE?
[root@kvm-06-guest36 ~]# 


Actual results:
                         [INFO] (Cert Check) Certificates updated.
                         [INFO] (Auto-attach) Certificates updated.

Expected results:
                         [WARN] (Cert Check) Update failed (255), retry will occur on next run.
                         [WARN] (Auto-attach) Update failed (255), retry will occur on next run.


Additional info:
[root@kvm-06-guest36 ~]# cat /var/log/rhsm/rhsm.log 
2020-10-08 19:49:36,143 [DEBUG] rhsmcertd-worker:334235:MainThread @rhsmcertd_worker.py:70 - X-Correlation-ID: e011c3c8b9dc45dc85a226ebd02cb8be
2020-10-08 19:49:36,143 [DEBUG] rhsmcertd-worker:334235:MainThread @rhsmcertd_worker.py:74 - check for rhsmcertd disable
2020-10-08 19:49:36,144 [DEBUG] rhsmcertd-worker:334235:MainThread @connection.py:171 - Environment variable NO_PROXY= will be used
2020-10-08 19:49:36,145 [DEBUG] rhsmcertd-worker:334235:MainThread @connection.py:267 - Connection built: host=subscription.rhsm.stage.redhat.com port=443 handler=/subscription auth=none
2020-10-08 19:49:36,145 [DEBUG] rhsmcertd-worker:334235:MainThread @connection.py:698 - Making request: GET /subscription/
2020-10-08 19:49:36,146 [DEBUG] rhsmcertd-worker:334235:MainThread @connection.py:556 - Loaded CA certificates from /etc/rhsm/ca/: rhsm-auto8-candlepin.pem, redhat-entitlement-authority.pem, redhat-uep.pem, rhsm-auto8-gate-candlepin.pem
2020-10-08 19:49:36,469 [DEBUG] rhsmcertd-worker:334235:MainThread @connection.py:792 - Response time: 0.25649166107177734, Smoothed response time: 0.25649166107177734
2020-10-08 19:49:36,469 [DEBUG] rhsmcertd-worker:334235:MainThread @connection.py:769 - Response: status=200, requestUuid=0e854501-e981-45e7-bcbf-7c008e451bc4, request="GET /subscription/"
2020-10-08 19:49:36,470 [DEBUG] rhsmcertd-worker:334235:MainThread @connection.py:969 - Server supports the following resources: {'cdn': '/cdn', 'hypervisors': '/hypervisors', 'crl': '/crl', 'pools': '/pools', 'roles': '/roles', 'entitlements': '/entitlements', 'activation_keys': '/activation_keys', 'status': '/status', 'consumertypes': '/consumertypes', 'admin': '/admin', 'rules': '/rules', 'guestids': '/consumers/{consumer_uuid}/guestids', 'jobs': '/jobs', '': '/', 'content_overrides': '/consumers/{consumer_uuid}/content_overrides', 'products': '/products', 'distributor_versions': '/distributor_versions', 'deleted_consumers': '/deleted_consumers', 'consumers': '/consumers', 'subscriptions': '/subscriptions', 'users': '/users', 'content': '/content', 'owners': '/owners', 'serials': '/serials', 'packages': '/consumers/{consumer_uuid}/packages'}
2020-10-08 19:49:36,470 [DEBUG] rhsmcertd-worker:334235:MainThread @base_action_client.py:88 - running lib: <subscription_manager.entcertlib.EntCertActionInvoker object at 0x7f5341377160>
2020-10-08 19:49:36,470 [DEBUG] rhsmcertd-worker:334235:MainThread @identity.py:139 - Loading consumer info from identity certificates.
2020-10-08 19:49:36,473 [DEBUG] rhsmcertd-worker:334235:MainThread @connection.py:698 - Making request: GET /subscription/consumers/f09a84ce-6620-4447-a3aa-d9d29e05aa49/certificates/serials
2020-10-08 19:49:36,474 [DEBUG] rhsmcertd-worker:334235:MainThread @connection.py:556 - Loaded CA certificates from /etc/rhsm/ca/: rhsm-auto8-candlepin.pem, redhat-entitlement-authority.pem, redhat-uep.pem, rhsm-auto8-gate-candlepin.pem
2020-10-08 19:49:36,795 [DEBUG] rhsmcertd-worker:334235:MainThread @connection.py:792 - Response time: 0.2547290325164795, Smoothed response time: 0.25631539821624755
2020-10-08 19:49:36,795 [DEBUG] rhsmcertd-worker:334235:MainThread @connection.py:769 - Response: status=401, requestUuid=3185f714-8fd4-4e73-8500-383fbda6fee0, request="GET /subscription/consumers/f09a84ce-6620-4447-a3aa-d9d29e05aa49/certificates/serials"
2020-10-08 19:49:36,796 [WARNING] rhsmcertd-worker:334235:MainThread @base_action_client.py:72 - Exception caught while running <subscription_manager.entcertlib.EntCertActionInvoker object at 0x7f5341377160> update
2020-10-08 19:49:36,796 [ERROR] rhsmcertd-worker:334235:MainThread @base_action_client.py:73 - HTTP error (401 - Unauthorized): Invalid credentials.
Traceback (most recent call last):
  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 852, in validateResponse
    raise RestlibException(response['status'], error_msg, response.get('headers'))
rhsm.connection.RestlibException: HTTP error (401 - Unauthorized): Invalid credentials.
2020-10-08 19:49:36,797 [DEBUG] rhsmcertd-worker:334235:MainThread @base_action_client.py:88 - running lib: <subscription_manager.identitycertlib.IdentityCertActionInvoker object at 0x7f532c4f4ac8>
2020-10-08 19:49:36,797 [DEBUG] rhsmcertd-worker:334235:MainThread @connection.py:698 - Making request: GET /subscription/consumers/f09a84ce-6620-4447-a3aa-d9d29e05aa49
2020-10-08 19:49:36,798 [DEBUG] rhsmcertd-worker:334235:MainThread @connection.py:556 - Loaded CA certificates from /etc/rhsm/ca/: rhsm-auto8-candlepin.pem, redhat-entitlement-authority.pem, redhat-uep.pem, rhsm-auto8-gate-candlepin.pem
2020-10-08 19:49:37,175 [DEBUG] rhsmcertd-worker:334235:MainThread @connection.py:792 - Response time: 0.2981112003326416, Smoothed response time: 0.26049497842788694
2020-10-08 19:49:37,175 [DEBUG] rhsmcertd-worker:334235:MainThread @connection.py:769 - Response: status=401, requestUuid=de849de1-fd6b-4ea5-ba19-c4c9d08cefbe, request="GET /subscription/consumers/f09a84ce-6620-4447-a3aa-d9d29e05aa49"
2020-10-08 19:49:37,176 [WARNING] rhsmcertd-worker:334235:MainThread @base_action_client.py:72 - Exception caught while running <subscription_manager.identitycertlib.IdentityCertActionInvoker object at 0x7f532c4f4ac8> update
2020-10-08 19:49:37,176 [ERROR] rhsmcertd-worker:334235:MainThread @base_action_client.py:73 - HTTP error (401 - Unauthorized): Invalid credentials.
Traceback (most recent call last):
  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/identitycertlib.py", line 37, in _do_update
    return action.perform()
  File "/usr/lib64/python3.6/site-packages/subscription_manager/identitycertlib.py", line 63, in perform
    return self._update_cert(identity)
  File "/usr/lib64/python3.6/site-packages/subscription_manager/identitycertlib.py", line 73, in _update_cert
    consumer = self._get_consumer(identity)
  File "/usr/lib64/python3.6/site-packages/subscription_manager/identitycertlib.py", line 91, in _get_consumer
    consumer = self.uep.getConsumer(identity.uuid)
  File "/usr/lib64/python3.6/site-packages/rhsm/connection.py", line 1242, in getConsumer
    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 852, in validateResponse
    raise RestlibException(response['status'], error_msg, response.get('headers'))
rhsm.connection.RestlibException: HTTP error (401 - Unauthorized): Invalid credentials.
2020-10-08 19:49:37,177 [DEBUG] rhsmcertd-worker:334235:MainThread @base_action_client.py:88 - running lib: <subscription_manager.content_action_client.ContentActionClient object at 0x7f532c4f4860>
2020-10-08 19:49:37,178 [DEBUG] rhsmcertd-worker:334235:MainThread @base_action_client.py:88 - running lib: <subscription_manager.repolib.RepoActionInvoker object at 0x7f532c5552e8>
2020-10-08 19:49:37,179 [DEBUG] rhsmcertd-worker:334235:MainThread @cache.py:881 - Trying to read SupportedResourcesCache from cache file /var/lib/rhsm/cache/supported_resources.json
2020-10-08 19:49:37,179 [DEBUG] rhsmcertd-worker:334235:MainThread @cache.py:891 - Data loaded from cache file: /var/lib/rhsm/cache/supported_resources.json
2020-10-08 19:49:37,179 [DEBUG] rhsmcertd-worker:334235:MainThread @connection.py:698 - Making request: GET /subscription/consumers/f09a84ce-6620-4447-a3aa-d9d29e05aa49/content_overrides
2020-10-08 19:49:37,180 [DEBUG] rhsmcertd-worker:334235:MainThread @connection.py:556 - Loaded CA certificates from /etc/rhsm/ca/: rhsm-auto8-candlepin.pem, redhat-entitlement-authority.pem, redhat-uep.pem, rhsm-auto8-gate-candlepin.pem
2020-10-08 19:49:37,555 [DEBUG] rhsmcertd-worker:334235:MainThread @connection.py:792 - Response time: 0.2985875606536865, Smoothed response time: 0.26430423665046693
2020-10-08 19:49:37,555 [DEBUG] rhsmcertd-worker:334235:MainThread @connection.py:769 - Response: status=401, requestUuid=0d05b7a2-3e69-43d8-a7e4-27f7bcccc108, request="GET /subscription/consumers/f09a84ce-6620-4447-a3aa-d9d29e05aa49/content_overrides"
2020-10-08 19:49:37,555 [ERROR] rhsmcertd-worker:334235:MainThread @cache.py:238 - HTTP error (401 - Unauthorized): Invalid credentials.
2020-10-08 19:49:37,555 [WARNING] rhsmcertd-worker:334235:MainThread @cache.py:244 - Unable to reach server, using cached status.
2020-10-08 19:49:37,555 [DEBUG] rhsmcertd-worker:334235:MainThread @cache.py:266 - Trying to read status from /var/lib/rhsm/cache/content_overrides.json file
2020-10-08 19:49:37,556 [DEBUG] rhsmcertd-worker:334235:MainThread @repofile.py:364 - The directory /etc/yum.repos.d/ already exists
2020-10-08 19:49:37,556 [DEBUG] rhsmcertd-worker:334235:MainThread @repofile.py:364 - The directory /var/lib/rhsm/repo_server_val/ already exists
2020-10-08 19:49:37,568 [DEBUG] rhsmcertd-worker:334235:MainThread @__init__.py:92 - Searching for content of type: yum
2020-10-08 19:49:37,568 [DEBUG] rhsmcertd-worker:334235:MainThread @__init__.py:92 - Searching for content of type: deb
2020-10-08 19:49:37,659 [DEBUG] rhsmcertd-worker:334235:MainThread @cache.py:117 - Wrote cache: /var/lib/rhsm/cache/written_overrides.json
2020-10-08 19:49:37,659 [DEBUG] rhsmcertd-worker:334235:MainThread @repolib.py:463 - repos updated: Repo updates

Total repo updates: 39
Updated
    b'[id:certsys-beta-for-rhel-8-x86_64-source-rpms Red Hat Certificate System Beta for RHEL 8 x86_64 (Source RPMs)]'
    b'[id:rhel-8-for-x86_64-sap-solutions-beta-source-rpms Red Hat Enterprise Linux 8 for x86_64 - SAP Solutions Beta (Source RPMs)]'
    b'[id:codeready-builder-beta-for-rhel-8-x86_64-debug-rpms Red Hat CodeReady Linux Builder Beta for RHEL 8 x86_64 (Debug RPMs)]'
    b'[id:rhel-8-for-x86_64-baseos-beta-debug-rpms Red Hat Enterprise Linux 8 for x86_64 - BaseOS Beta (Debug RPMs)]'
    b'[id:rhel-8-for-x86_64-sap-netweaver-beta-debug-rpms Red Hat Enterprise Linux 8 for x86_64 - SAP NetWeaver Beta (Debug RPMs)]'
    b'[id:rhel-8-for-x86_64-appstream-beta-debug-rpms Red Hat Enterprise Linux 8 for x86_64 - AppStream Beta (Debug RPMs)]'
    b'[id:rhel-8-for-x86_64-resilientstorage-beta-debug-rpms Red Hat Enterprise Linux 8 for x86_64 - Resilient Storage Beta (Debug RPMs)]'
    b'[id:rhel-8-for-x86_64-rt-beta-rpms Red Hat Enterprise Linux 8 for x86_64 - Real Time Beta (RPMs)]'
    b'[id:certsys-beta-for-rhel-8-x86_64-debug-rpms Red Hat Certificate System Beta for RHEL 8 x86_64 (Debug RPMs)]'
    b'[id:rhel-8-for-x86_64-resilientstorage-beta-rpms Red Hat Enterprise Linux 8 for x86_64 - Resilient Storage Beta (RPMs)]'
    b'[id:certsys-beta-for-rhel-8-x86_64-rpms Red Hat Certificate System Beta for RHEL 8 x86_64 (RPMs)]'
    b'[id:rhel-8-for-x86_64-rt-beta-debug-rpms Red Hat Enterprise Linux 8 for x86_64 - Real Time Beta (Debug RPMs)]'
    b'[id:rhel-8-for-x86_64-supplementary-beta-debug-rpms Red Hat Enterprise Linux 8 for x86_64 - Supplementary Beta (Debug RPMs)]'
    b'[id:rhel-8-for-x86_64-appstream-beta-source-rpms Red Hat Enterprise Linux 8 for x86_64 - AppStream Beta (Source RPMs)]'
    b'[id:rhel-8-for-x86_64-appstream-beta-rpms Red Hat Enterprise Linux 8 for x86_64 - AppStream Beta (RPMs)]'
    b'[id:rhel-8-for-x86_64-sap-netweaver-beta-source-rpms Red Hat Enterprise Linux 8 for x86_64 - SAP NetWeaver Beta (Source RPMs)]'
    b'[id:fast-datapath-beta-for-rhel-8-x86_64-debug-rpms Fast Datapath Beta for RHEL 8 x86_64 (Debug RPMs)]'
    b'[id:rhel-8-for-x86_64-baseos-beta-source-rpms Red Hat Enterprise Linux 8 for x86_64 - BaseOS Beta (Source RPMs)]'
    b'[id:rhel-8-for-x86_64-sap-solutions-beta-rpms Red Hat Enterprise Linux 8 for x86_64 - SAP Solutions Beta (RPMs)]'
    b'[id:rhel-8-for-x86_64-supplementary-beta-source-rpms Red Hat Enterprise Linux 8 for x86_64 - Supplementary Beta (Source RPMs)]'
    b'[id:rhel-8-for-x86_64-sap-solutions-beta-debug-rpms Red Hat Enterprise Linux 8 for x86_64 - SAP Solutions Beta (Debug RPMs)]'
    b'[id:rhel-8-for-x86_64-baseos-beta-rpms Red Hat Enterprise Linux 8 for x86_64 - BaseOS Beta (RPMs)]'
    b'[id:rhel-8-for-x86_64-nfv-beta-source-rpms Red Hat Enterprise Linux 8 for x86_64 - Real Time for NFV Beta (Source RPMs)]'
    b'[id:rhel-8-for-x86_64-resilientstorage-beta-source-rpms Red Hat Enterprise Linux 8 for x86_64 - Resilient Storage Beta (Source RPMs)]'
    b'[id:rhel-8-for-x86_64-nfv-beta-debug-rpms Red Hat Enterprise Linux 8 for x86_64 - Real Time for NFV Beta (Debug RPMs)]'
    b'[id:rhel-8-for-x86_64-highavailability-beta-source-rpms Red Hat Enterprise Linux 8 for x86_64 - High Availability Beta (Source RPMs)]'
    b'[id:fast-datapath-beta-for-rhel-8-x86_64-rpms Fast Datapath Beta for RHEL 8 x86_64 (RPMs)]'
    b'[id:codeready-builder-beta-for-rhel-8-x86_64-source-rpms Red Hat CodeReady Linux Builder Beta for RHEL 8 x86_64 (Source RPMs)]'
    b'[id:rhel-8-for-x86_64-rt-beta-source-rpms Red Hat Enterprise Linux 8 for x86_64 - Real Time Beta (Source RPMs)]'
    b'[id:dirsrv-beta-for-rhel-8-x86_64-debug-rpms Red Hat Directory Server Beta for RHEL 8 x86_64 (Debug RPMs)]'
    b'[id:rhel-8-for-x86_64-highavailability-beta-debug-rpms Red Hat Enterprise Linux 8 for x86_64 - High Availability Beta (Debug RPMs)]'
    b'[id:rhel-8-for-x86_64-highavailability-beta-rpms Red Hat Enterprise Linux 8 for x86_64 - High Availability Beta (RPMs)]'
    b'[id:dirsrv-beta-for-rhel-8-x86_64-rpms Red Hat Directory Server Beta for RHEL 8 x86_64 (RPMs)]'
    b'[id:fast-datapath-beta-for-rhel-8-x86_64-source-rpms Fast Datapath Beta for RHEL 8 x86_64 (Source RPMs)]'
    b'[id:dirsrv-beta-for-rhel-8-x86_64-source-rpms Red Hat Directory Server Beta for RHEL 8 x86_64 (Source RPMs)]'
    b'[id:codeready-builder-beta-for-rhel-8-x86_64-rpms Red Hat CodeReady Linux Builder Beta for RHEL 8 x86_64 (RPMs)]'
    b'[id:rhel-8-for-x86_64-sap-netweaver-beta-rpms Red Hat Enterprise Linux 8 for x86_64 - SAP NetWeaver Beta (RPMs)]'
    b'[id:rhel-8-for-x86_64-nfv-beta-rpms Red Hat Enterprise Linux 8 for x86_64 - Real Time for NFV Beta (RPMs)]'
    b'[id:rhel-8-for-x86_64-supplementary-beta-rpms Red Hat Enterprise Linux 8 for x86_64 - Supplementary Beta (RPMs)]'
Added (new)
    <NONE>
Deleted
    <NONE>
2020-10-08 19:49:37,662 [DEBUG] rhsmcertd-worker:334235:MainThread @plugins.py:571 - loaded plugin modules: [<module 'ostree_content' from '/usr/share/rhsm-plugins/ostree_content.py'>]
2020-10-08 19:49:37,662 [DEBUG] rhsmcertd-worker:334235:MainThread @plugins.py:572 - loaded plugins: {'ostree_content.OstreeContentPlugin': <ostree_content.OstreeContentPlugin object at 0x7f532c13fb38>}
2020-10-08 19:49:37,662 [DEBUG] rhsmcertd-worker:334235:MainThread @plugins.py:778 - Running update_content_hook in ostree_content.OstreeContentPlugin
2020-10-08 19:49:37,662 [DEBUG] rhsmcertd-worker:334235:MainThread @base_action_client.py:88 - running lib: <subscription_manager.content_action_client.ContentPluginActionInvoker object at 0x7f532c150e10>
2020-10-08 19:49:37,662 [DEBUG] rhsmcertd-worker:334235:MainThread @__init__.py:92 - Searching for content of type: ostree
2020-10-08 19:49:37,663 [DEBUG] rhsmcertd-worker:334235:MainThread @action_invoker.py:85 - Ostree update report: Ostree repo updates

Updates:

Added:

Deleted:

2020-10-08 19:49:37,663 [DEBUG] rhsmcertd-worker:334235:MainThread @base_action_client.py:88 - running lib: <subscription_manager.factlib.FactsActionInvoker object at 0x7f532c4f48d0>
2020-10-08 19:49:37,679 [DEBUG] rhsmcertd-worker:334235:MainThread @dmiinfo.py:76 - Using dmidecode dump file: /dev/mem
2020-10-08 19:49:37,726 [DEBUG] rhsmcertd-worker:334235:MainThread @insights.py:68 - Unable to read insights machine_id file: /etc/insights-client/machine-id, error: [Errno 2] No such file or directory: '/etc/insights-client/machine-id'
2020-10-08 19:49:37,726 [DEBUG] rhsmcertd-worker:334235:MainThread @insights.py:68 - Unable to read insights machine_id file: /etc/redhat-access-insights/machine-id, error: [Errno 2] No such file or directory: '/etc/redhat-access-insights/machine-id'
2020-10-08 19:49:37,727 [DEBUG] rhsmcertd-worker:334235:MainThread @factlib.py:102 - Facts have not changed, skipping upload.
2020-10-08 19:49:37,727 [DEBUG] rhsmcertd-worker:334235:MainThread @base_action_client.py:88 - running lib: <subscription_manager.packageprofilelib.PackageProfileActionInvoker object at 0x7f532c4f4978>
2020-10-08 19:49:37,727 [DEBUG] rhsmcertd-worker:334235:MainThread @cache.py:172 - Checking current system info against cache: /var/lib/rhsm/cache/profile.json
2020-10-08 19:49:37,730 [DEBUG] rhsmcertd-worker:334235:MainThread @profile.py:312 - Loading current RPM profile.
2020-10-08 19:49:38,894 [DEBUG] rhsmcertd-worker:334235:MainThread @cache.py:189 - No changes.
2020-10-08 19:49:38,894 [DEBUG] rhsmcertd-worker:334235:MainThread @base_action_client.py:88 - running lib: <subscription_manager.installedproductslib.InstalledProductsActionInvoker object at 0x7f532c4f4a20>
2020-10-08 19:49:38,895 [DEBUG] rhsmcertd-worker:334235:MainThread @cache.py:172 - Checking current system info against cache: /var/lib/rhsm/cache/installed_products.json
2020-10-08 19:49:38,895 [DEBUG] rhsmcertd-worker:334235:MainThread @cache.py:189 - No changes.
2020-10-08 19:49:38,895 [DEBUG] rhsmcertd-worker:334235:MainThread @base_action_client.py:88 - running lib: <subscription_manager.syspurposelib.SyspurposeSyncActionInvoker object at 0x7f532c4f4b70>
2020-10-08 19:49:38,895 [DEBUG] rhsmcertd-worker:334235:MainThread @files.py:351 - Successfully read local syspurpose contents.
2020-10-08 19:49:38,895 [DEBUG] rhsmcertd-worker:334235:MainThread @files.py:388 - Successfully read cached syspurpose contents.
2020-10-08 19:49:38,895 [DEBUG] rhsmcertd-worker:334235:MainThread @files.py:297 - Attempting to sync syspurpose content...
2020-10-08 19:49:38,895 [DEBUG] rhsmcertd-worker:334235:MainThread @connection.py:698 - Making request: GET /subscription/status
2020-10-08 19:49:38,896 [DEBUG] rhsmcertd-worker:334235:MainThread @connection.py:556 - Loaded CA certificates from /etc/rhsm/ca/: rhsm-auto8-candlepin.pem, redhat-entitlement-authority.pem, redhat-uep.pem, rhsm-auto8-gate-candlepin.pem
2020-10-08 19:49:39,273 [DEBUG] rhsmcertd-worker:334235:MainThread @connection.py:792 - Response time: 0.2991902828216553, Smoothed response time: 0.26779284126758574
2020-10-08 19:49:39,273 [DEBUG] rhsmcertd-worker:334235:MainThread @connection.py:769 - Response: status=200, requestUuid=fb4035e3-fe65-4f21-b06b-7d2f11410139, request="GET /subscription/status"
2020-10-08 19:49:39,274 [DEBUG] rhsmcertd-worker:334235:MainThread @connection.py:1007 - Server has the following capabilities: ['instance_multiplier', 'derived_product', 'vcpu', 'cert_v3', 'hypervisors_heartbeat', 'remove_by_pool_id', 'syspurpose', 'insights_auto_register', 'storage_band', 'cores', 'hypervisors_async', 'org_level_content_access', 'guest_limit', 'ram', 'batch_bind', 'combined_reporting']
2020-10-08 19:49:39,274 [DEBUG] rhsmcertd-worker:334235:MainThread @connection.py:698 - Making request: GET /subscription/consumers/f09a84ce-6620-4447-a3aa-d9d29e05aa49
2020-10-08 19:49:39,275 [DEBUG] rhsmcertd-worker:334235:MainThread @connection.py:556 - Loaded CA certificates from /etc/rhsm/ca/: rhsm-auto8-candlepin.pem, redhat-entitlement-authority.pem, redhat-uep.pem, rhsm-auto8-gate-candlepin.pem
2020-10-08 19:49:39,651 [DEBUG] rhsmcertd-worker:334235:MainThread @connection.py:792 - Response time: 0.298342227935791, Smoothed response time: 0.2708477799344063
2020-10-08 19:49:39,651 [DEBUG] rhsmcertd-worker:334235:MainThread @connection.py:769 - Response: status=401, requestUuid=df260584-f930-4fc0-a5b1-bf7cedeba014, request="GET /subscription/consumers/f09a84ce-6620-4447-a3aa-d9d29e05aa49"
2020-10-08 19:49:39,652 [DEBUG] rhsmcertd-worker:334235:MainThread @syspurposelib.py:285 - Syspurpose updated: Syspurpose Sync
        status: Failed to sync system purpose
        updates: 
        exceptions: Unable to sync syspurpose with server: HTTP error (401 - Unauthorized): Invalid credentials.

        
2020-10-08 19:49:40,003 [DEBUG] rhsmcertd-worker:334281:MainThread @rhsmcertd_worker.py:70 - X-Correlation-ID: 881379e1f20f4822a3a645e82eee7df0
2020-10-08 19:49:40,004 [DEBUG] rhsmcertd-worker:334281:MainThread @rhsmcertd_worker.py:74 - check for rhsmcertd disable
2020-10-08 19:49:40,005 [DEBUG] rhsmcertd-worker:334281:MainThread @connection.py:171 - Environment variable NO_PROXY= will be used
2020-10-08 19:49:40,005 [DEBUG] rhsmcertd-worker:334281:MainThread @connection.py:267 - Connection built: host=subscription.rhsm.stage.redhat.com port=443 handler=/subscription auth=none
2020-10-08 19:49:40,005 [DEBUG] rhsmcertd-worker:334281:MainThread @connection.py:698 - Making request: GET /subscription/
2020-10-08 19:49:40,007 [DEBUG] rhsmcertd-worker:334281:MainThread @connection.py:556 - Loaded CA certificates from /etc/rhsm/ca/: rhsm-auto8-candlepin.pem, redhat-entitlement-authority.pem, redhat-uep.pem, rhsm-auto8-gate-candlepin.pem
2020-10-08 19:49:40,387 [DEBUG] rhsmcertd-worker:334281:MainThread @connection.py:792 - Response time: 0.3028268814086914, Smoothed response time: 0.3028268814086914
2020-10-08 19:49:40,387 [DEBUG] rhsmcertd-worker:334281:MainThread @connection.py:769 - Response: status=200, requestUuid=f1909563-a4f2-4f93-88bd-db506d89585a, request="GET /subscription/"
2020-10-08 19:49:40,387 [DEBUG] rhsmcertd-worker:334281:MainThread @connection.py:969 - Server supports the following resources: {'deleted_consumers': '/deleted_consumers', 'pools': '/pools', 'hypervisors': '/hypervisors', 'consumers': '/consumers', 'rules': '/rules', 'entitlements': '/entitlements', 'subscriptions': '/subscriptions', 'owners': '/owners', '': '/', 'serials': '/serials', 'status': '/status', 'jobs': '/jobs', 'cdn': '/cdn', 'distributor_versions': '/distributor_versions', 'content': '/content', 'activation_keys': '/activation_keys', 'roles': '/roles', 'crl': '/crl', 'products': '/products', 'admin': '/admin', 'content_overrides': '/consumers/{consumer_uuid}/content_overrides', 'guestids': '/consumers/{consumer_uuid}/guestids', 'users': '/users', 'consumertypes': '/consumertypes', 'packages': '/consumers/{consumer_uuid}/packages'}
2020-10-08 19:49:40,388 [DEBUG] rhsmcertd-worker:334281:MainThread @base_action_client.py:88 - running lib: <subscription_manager.installedproductslib.InstalledProductsActionInvoker object at 0x7f21622c0860>
2020-10-08 19:49:40,389 [DEBUG] rhsmcertd-worker:334281:MainThread @identity.py:139 - Loading consumer info from identity certificates.
2020-10-08 19:49:40,390 [DEBUG] rhsmcertd-worker:334281:MainThread @cache.py:172 - Checking current system info against cache: /var/lib/rhsm/cache/installed_products.json
2020-10-08 19:49:40,390 [DEBUG] rhsmcertd-worker:334281:MainThread @cache.py:189 - No changes.
2020-10-08 19:49:40,390 [DEBUG] rhsmcertd-worker:334281:MainThread @base_action_client.py:88 - running lib: <subscription_manager.syspurposelib.SyspurposeSyncActionInvoker object at 0x7f21622c0908>
2020-10-08 19:49:40,390 [DEBUG] rhsmcertd-worker:334281:MainThread @files.py:351 - Successfully read local syspurpose contents.
2020-10-08 19:49:40,390 [DEBUG] rhsmcertd-worker:334281:MainThread @files.py:388 - Successfully read cached syspurpose contents.
2020-10-08 19:49:40,390 [DEBUG] rhsmcertd-worker:334281:MainThread @files.py:297 - Attempting to sync syspurpose content...
2020-10-08 19:49:40,390 [DEBUG] rhsmcertd-worker:334281:MainThread @connection.py:698 - Making request: GET /subscription/status
2020-10-08 19:49:40,391 [DEBUG] rhsmcertd-worker:334281:MainThread @connection.py:556 - Loaded CA certificates from /etc/rhsm/ca/: rhsm-auto8-candlepin.pem, redhat-entitlement-authority.pem, redhat-uep.pem, rhsm-auto8-gate-candlepin.pem
2020-10-08 19:49:40,713 [DEBUG] rhsmcertd-worker:334281:MainThread @connection.py:792 - Response time: 0.25472474098205566, Smoothed response time: 0.29801666736602783
2020-10-08 19:49:40,713 [DEBUG] rhsmcertd-worker:334281:MainThread @connection.py:769 - Response: status=200, requestUuid=1cafa908-2768-4541-b420-9fc4e30f04b2, request="GET /subscription/status"
2020-10-08 19:49:40,714 [DEBUG] rhsmcertd-worker:334281:MainThread @connection.py:1007 - Server has the following capabilities: ['instance_multiplier', 'derived_product', 'vcpu', 'cert_v3', 'hypervisors_heartbeat', 'remove_by_pool_id', 'syspurpose', 'insights_auto_register', 'storage_band', 'cores', 'hypervisors_async', 'org_level_content_access', 'guest_limit', 'ram', 'batch_bind', 'combined_reporting']
2020-10-08 19:49:40,714 [DEBUG] rhsmcertd-worker:334281:MainThread @connection.py:698 - Making request: GET /subscription/consumers/f09a84ce-6620-4447-a3aa-d9d29e05aa49
2020-10-08 19:49:40,715 [DEBUG] rhsmcertd-worker:334281:MainThread @connection.py:556 - Loaded CA certificates from /etc/rhsm/ca/: rhsm-auto8-candlepin.pem, redhat-entitlement-authority.pem, redhat-uep.pem, rhsm-auto8-gate-candlepin.pem
2020-10-08 19:49:41,038 [DEBUG] rhsmcertd-worker:334281:MainThread @connection.py:792 - Response time: 0.25562191009521484, Smoothed response time: 0.29377719163894656
2020-10-08 19:49:41,038 [DEBUG] rhsmcertd-worker:334281:MainThread @connection.py:769 - Response: status=401, requestUuid=c9a43b30-6fd6-4958-a0d5-b00a7c61dd44, request="GET /subscription/consumers/f09a84ce-6620-4447-a3aa-d9d29e05aa49"
2020-10-08 19:49:41,039 [DEBUG] rhsmcertd-worker:334281:MainThread @syspurposelib.py:285 - Syspurpose updated: Syspurpose Sync
        status: Failed to sync system purpose
        updates: 
        exceptions: Unable to sync syspurpose with server: HTTP error (401 - Unauthorized): Invalid credentials.

        
2020-10-08 19:49:41,039 [DEBUG] rhsmcertd-worker:334281:MainThread @base_action_client.py:88 - running lib: <subscription_manager.healinglib.HealingActionInvoker object at 0x7f21622c09b0>
2020-10-08 19:49:41,043 [DEBUG] rhsmcertd-worker:334281:MainThread @plugins.py:571 - loaded plugin modules: [<module 'ostree_content' from '/usr/share/rhsm-plugins/ostree_content.py'>]
2020-10-08 19:49:41,043 [DEBUG] rhsmcertd-worker:334281:MainThread @plugins.py:572 - loaded plugins: {'ostree_content.OstreeContentPlugin': <ostree_content.OstreeContentPlugin object at 0x7f2162062160>}
2020-10-08 19:49:41,043 [DEBUG] rhsmcertd-worker:334281:MainThread @connection.py:698 - Making request: GET /subscription/consumers/f09a84ce-6620-4447-a3aa-d9d29e05aa49
2020-10-08 19:49:41,044 [DEBUG] rhsmcertd-worker:334281:MainThread @connection.py:556 - Loaded CA certificates from /etc/rhsm/ca/: rhsm-auto8-candlepin.pem, redhat-entitlement-authority.pem, redhat-uep.pem, rhsm-auto8-gate-candlepin.pem
2020-10-08 19:49:41,366 [DEBUG] rhsmcertd-worker:334281:MainThread @connection.py:792 - Response time: 0.25563669204711914, Smoothed response time: 0.28996314167976384
2020-10-08 19:49:41,366 [DEBUG] rhsmcertd-worker:334281:MainThread @connection.py:769 - Response: status=401, requestUuid=4785cf47-f6d9-4e56-ae9d-8a15936541c1, request="GET /subscription/consumers/f09a84ce-6620-4447-a3aa-d9d29e05aa49"
2020-10-08 19:49:41,367 [WARNING] rhsmcertd-worker:334281:MainThread @base_action_client.py:72 - Exception caught while running <subscription_manager.healinglib.HealingActionInvoker object at 0x7f21622c09b0> update
2020-10-08 19:49:41,367 [ERROR] rhsmcertd-worker:334281:MainThread @base_action_client.py:73 - HTTP error (401 - Unauthorized): Invalid credentials.
Traceback (most recent call last):
  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/healinglib.py", line 43, in _do_update
    return action.perform()
  File "/usr/lib64/python3.6/site-packages/subscription_manager/healinglib.py", line 77, in perform
    consumer = self.uep.getConsumer(uuid)
  File "/usr/lib64/python3.6/site-packages/rhsm/connection.py", line 1242, in getConsumer
    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 852, in validateResponse
    raise RestlibException(response['status'], error_msg, response.get('headers'))
rhsm.connection.RestlibException: HTTP error (401 - Unauthorized): Invalid credentials.
2020-10-08 19:49:41,368 [DEBUG] rhsmcertd-worker:334281:MainThread @base_action_client.py:88 - running lib: <subscription_manager.entcertlib.EntCertActionInvoker object at 0x7f2177143160>
2020-10-08 19:49:41,370 [DEBUG] rhsmcertd-worker:334281:MainThread @connection.py:698 - Making request: GET /subscription/consumers/f09a84ce-6620-4447-a3aa-d9d29e05aa49/certificates/serials
2020-10-08 19:49:41,371 [DEBUG] rhsmcertd-worker:334281:MainThread @connection.py:556 - Loaded CA certificates from /etc/rhsm/ca/: rhsm-auto8-candlepin.pem, redhat-entitlement-authority.pem, redhat-uep.pem, rhsm-auto8-gate-candlepin.pem
2020-10-08 19:49:41,747 [DEBUG] rhsmcertd-worker:334281:MainThread @connection.py:792 - Response time: 0.298372745513916, Smoothed response time: 0.2908041020631791
2020-10-08 19:49:41,747 [DEBUG] rhsmcertd-worker:334281:MainThread @connection.py:769 - Response: status=401, requestUuid=24f8d1b2-7368-45b8-bd63-95856b6af17e, request="GET /subscription/consumers/f09a84ce-6620-4447-a3aa-d9d29e05aa49/certificates/serials"
2020-10-08 19:49:41,748 [WARNING] rhsmcertd-worker:334281:MainThread @base_action_client.py:72 - Exception caught while running <subscription_manager.entcertlib.EntCertActionInvoker object at 0x7f2177143160> update
2020-10-08 19:49:41,748 [ERROR] rhsmcertd-worker:334281:MainThread @base_action_client.py:73 - HTTP error (401 - Unauthorized): Invalid credentials.
Traceback (most recent call last):
  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 852, in validateResponse
    raise RestlibException(response['status'], error_msg, response.get('headers'))
rhsm.connection.RestlibException: HTTP error (401 - Unauthorized): Invalid credentials.

Comment 1 John Sefler 2020-10-09 00:48:00 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 ~]#

Comment 4 Archana Pandey 2020-11-03 10:28:41 UTC
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 ~]#

Comment 7 Shwetha Kallesh 2020-11-11 04:41:41 UTC
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.

Comment 9 errata-xmlrpc 2021-05-18 13:33:55 UTC
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