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 1886745

Summary:	Unable to sync syspurpose with server: HTTP error (401 - Unauthorized): Invalid credentials.
Product:	Red Hat Enterprise Linux 8	Reporter:	Rehana <redakkan>
Component:	subscription-manager	Assignee:	Jiri Hnidek <jhnidek>
Status:	CLOSED ERRATA	QA Contact:	Red Hat subscription-manager QE Team <rhsm-qe>
Severity:	high	Docs Contact:
Priority:	high
Version:	8.4	CC:	csnyder, jhnidek, jsefler, skallesh
Target Milestone:	rc	Keywords:	Regression, Triaged
Target Release:	8.4	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 Rehana 2020-10-09 10:14:08 UTC

Description of problem:
On the 8.4 scratch build provided, its observed that `syspurpose` commands are failing with "HTTP error (401 - Unauthorized): Invalid credentials" on a registered system

Version-Release number of selected component (if applicable):
# subscription-manager version
server type: Red Hat Subscription Management
subscription management server: 3.1.18-1
subscription management rules: 5.41
subscription-manager: 1.28.4-1.el8

How reproducible:
always

Steps to Reproduce:
1.Install latest scratch build 
2.Set syspurpose values on the unregistered system 
[root@hpe-dl380pgen8-02-vm-10 test]# syspurpose set-role foo
role set to "foo".
[root@hpe-dl380pgen8-02-vm-10 test]# syspurpose show
{
  "role": "foo",
  "usage": "QA"
}
^^ Notice the values are successfully set
 
3.Now register the system 
# subscription-manager register --username=**** --password=*****
Registering to: subscription.rhsm.stage.redhat.com:443/subscription
The system has been registered with ID: *****
The registered system name is:******

4. Try to show the syspurpose values 
[root@hpe-dl380pgen8-02-vm-10 test]# syspurpose show
HTTP error (401 - Unauthorized): Invalid credentials.
^^ Fails 

5. Set any value using subscription-manager role/usage/sla modules 

# subscription-manager usage --set="QA"
Warning: Provided value "QA" is not included in the list of valid values
 - Development/Test
 - Production
 - Disaster Recovery
usage set to "QA".
^^ Successfully set 

6. Now show / try to set value using syspurpose show 

# syspurpose set-role foo
HTTP error (401 - Unauthorized): Invalid credentials.

# syspurpose show
HTTP error (401 - Unauthorized): Invalid credentials.
^ Fails 

Actual results:
All `syspurpose` commands fails to work on a registered system 

Expected results:
All `syspurpose` commands should work 

Additional info:

Comment 1 John Sefler 2020-10-10 13:52:43 UTC

I am modifying the summary of this bug to a slightly more general statement that reflects the caught exceptions and adding another test scenario that I believe is caused by the same root issue as the test scenario in comment 0.


[root@kvm-06-guest36 ~]# subscription-manager version
server type: This system is currently not registered.
subscription management server: 3.1.18-1
subscription management rules: 5.41
subscription-manager: 1.28.4-1.el8
[root@kvm-06-guest36 ~]# 
[root@kvm-06-guest36 ~]# subscription-manager register
Registering to: subscription.rhsm.stage.redhat.com:443/subscription
Username: stage_auto_testuser
Password: 
The system has been registered with ID: 62d47fcf-0b94-49b8-8a4f-e9d96494db7e
The registered system name is: kvm-06-guest36.hv2.lab.eng.bos.redhat.com
[root@kvm-06-guest36 ~]# 
[root@kvm-06-guest36 ~]# truncate --size=0 /var/log/rhsm/rhsm.log 
[root@kvm-06-guest36 ~]# 
[root@kvm-06-guest36 ~]# subscription-manager config --logging.default_log_level=DEBUG
[root@kvm-06-guest36 ~]# 
[root@kvm-06-guest36 ~]# /usr/libexec/rhsmcertd-worker 
Updating entitlement certificates & repositories
Unable to sync syspurpose with server: HTTP error (401 - Unauthorized): Invalid credentials.

Fact updates
        status: None
        updates: []
        exceptions: 
        
Package profile updates
        status: 0
        updates: []
        exceptions: 
        
Installed Products
        status: 0
        updates: []
        exceptions: 
        
Syspurpose Sync
        status: Failed to sync system purpose
        updates: 
        exceptions: Unable to sync syspurpose with server: HTTP error (401 - Unauthorized): Invalid credentials.

        
[root@kvm-06-guest36 ~]# cat /var/log/rhsm/rhsm.log 
2020-10-10 09:34:22,562 [DEBUG] subscription-manager:417678:MainThread @https.py:56 - Using standard libs to provide httplib and ssl
2020-10-10 09:34:22,689 [DEBUG] subscription-manager:417678:MainThread @dbus_interface.py:37 - self.has_main_loop=False
2020-10-10 09:34:22,691 [DEBUG] subscription-manager:417678:MainThread @dbus_interface.py:53 - Unable to connect to D-Bus service: com.redhat.SubscriptionManager
2020-10-10 09:34:22,704 [DEBUG] subscription-manager:417678:MainThread @ga_loader.py:91 - ga_loader GaImporterGtk3
2020-10-10 09:34:22,707 [DEBUG] subscription-manager:417678:MainThread @plugins.py:571 - loaded plugin modules: [<module 'ostree_content' from '/usr/share/rhsm-plugins/ostree_content.py'>]
2020-10-10 09:34:22,707 [DEBUG] subscription-manager:417678:MainThread @plugins.py:572 - loaded plugins: {'ostree_content.OstreeContentPlugin': <ostree_content.OstreeContentPlugin object at 0x7f991ebbf4e0>}
2020-10-10 09:34:22,707 [DEBUG] subscription-manager:417678:MainThread @identity.py:139 - Loading consumer info from identity certificates.
2020-10-10 09:34:31,377 [DEBUG] subscription-manager:417686:MainThread @https.py:56 - Using standard libs to provide httplib and ssl
2020-10-10 09:34:31,500 [DEBUG] subscription-manager:417686:MainThread @dbus_interface.py:37 - self.has_main_loop=False
2020-10-10 09:34:31,502 [DEBUG] subscription-manager:417686:MainThread @dbus_interface.py:53 - Unable to connect to D-Bus service: com.redhat.SubscriptionManager
2020-10-10 09:34:31,515 [DEBUG] subscription-manager:417686:MainThread @ga_loader.py:91 - ga_loader GaImporterGtk3
2020-10-10 09:34:31,518 [DEBUG] subscription-manager:417686:MainThread @plugins.py:571 - loaded plugin modules: [<module 'ostree_content' from '/usr/share/rhsm-plugins/ostree_content.py'>]
2020-10-10 09:34:31,518 [DEBUG] subscription-manager:417686:MainThread @plugins.py:572 - loaded plugins: {'ostree_content.OstreeContentPlugin': <ostree_content.OstreeContentPlugin object at 0x7fcfe95c7518>}
2020-10-10 09:34:31,518 [DEBUG] subscription-manager:417686:MainThread @identity.py:139 - Loading consumer info from identity certificates.
2020-10-10 09:34:31,524 [DEBUG] subscription-manager:417686:MainThread @managercli.py:502 - X-Correlation-ID: b4eefc9e98fb46878473b31e0c87cc81
2020-10-10 09:34:31,524 [DEBUG] subscription-manager:417686:MainThread @managercli.py:391 - Client Versions: {'subscription-manager': '1.28.4-1.el8'}
2020-10-10 09:34:31,527 [DEBUG] subscription-manager:417686:MainThread @repolib.py:175 - The rhsm.auto_enable_yum_plugins is enabled
2020-10-10 09:34:31,527 [DEBUG] subscription-manager:417686:MainThread @repolib.py:151 - dnf plugin: "/etc/dnf/plugins/subscription-manager.conf" already enabled. Nothing to do.
2020-10-10 09:34:31,527 [DEBUG] subscription-manager:417686:MainThread @repolib.py:151 - dnf plugin: "/etc/dnf/plugins/product-id.conf" already enabled. Nothing to do.
2020-10-10 09:34:31,528 [DEBUG] subscription-manager:417686:MainThread @repolib.py:151 - yum plugin: "/etc/yum/pluginconf.d/subscription-manager.conf" already enabled. Nothing to do.
2020-10-10 09:34:31,528 [DEBUG] subscription-manager:417686:MainThread @repolib.py:151 - yum plugin: "/etc/yum/pluginconf.d/product-id.conf" already enabled. Nothing to do.
2020-10-10 09:34:48,282 [DEBUG] rhsmcertd-worker:417696:MainThread @rhsmcertd_worker.py:70 - X-Correlation-ID: 62fa0d81296849ddb1bc20dab3966dc9
2020-10-10 09:34:48,282 [DEBUG] rhsmcertd-worker:417696:MainThread @rhsmcertd_worker.py:74 - check for rhsmcertd disable
2020-10-10 09:34:48,283 [DEBUG] rhsmcertd-worker:417696:MainThread @connection.py:171 - Environment variable NO_PROXY= will be used
2020-10-10 09:34:48,284 [DEBUG] rhsmcertd-worker:417696:MainThread @connection.py:267 - Connection built: host=subscription.rhsm.stage.redhat.com port=443 handler=/subscription auth=none
2020-10-10 09:34:48,284 [DEBUG] rhsmcertd-worker:417696:MainThread @connection.py:698 - Making request: GET /subscription/
2020-10-10 09:34:48,285 [DEBUG] rhsmcertd-worker:417696:MainThread @connection.py:556 - 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-10 09:34:48,662 [DEBUG] rhsmcertd-worker:417696:MainThread @connection.py:792 - Response time: 0.2996487617492676, Smoothed response time: 0.2996487617492676
2020-10-10 09:34:48,662 [DEBUG] rhsmcertd-worker:417696:MainThread @connection.py:769 - Response: status=200, requestUuid=6c79d5ab-1e82-4d00-81c1-e131af6e6c57, request="GET /subscription/"
2020-10-10 09:34:48,663 [DEBUG] rhsmcertd-worker:417696:MainThread @connection.py:969 - Server supports the following resources: {'jobs': '/jobs', 'content': '/content', 'consumertypes': '/consumertypes', 'distributor_versions': '/distributor_versions', 'content_overrides': '/consumers/{consumer_uuid}/content_overrides', 'subscriptions': '/subscriptions', 'guestids': '/consumers/{consumer_uuid}/guestids', 'crl': '/crl', 'pools': '/pools', 'serials': '/serials', 'cdn': '/cdn', 'activation_keys': '/activation_keys', 'products': '/products', 'entitlements': '/entitlements', 'rules': '/rules', 'hypervisors': '/hypervisors', 'admin': '/admin', 'owners': '/owners', 'users': '/users', 'roles': '/roles', '': '/', 'consumers': '/consumers', 'deleted_consumers': '/deleted_consumers', 'status': '/status', 'packages': '/consumers/{consumer_uuid}/packages'}
2020-10-10 09:34:48,663 [DEBUG] rhsmcertd-worker:417696:MainThread @base_action_client.py:88 - running lib: <subscription_manager.entcertlib.EntCertActionInvoker object at 0x7f49a6955a58>
2020-10-10 09:34:48,663 [DEBUG] rhsmcertd-worker:417696:MainThread @identity.py:139 - Loading consumer info from identity certificates.
2020-10-10 09:34:48,664 [DEBUG] rhsmcertd-worker:417696:MainThread @connection.py:698 - Making request: GET /subscription/consumers/62d47fcf-0b94-49b8-8a4f-e9d96494db7e/certificates/serials
2020-10-10 09:34:48,665 [DEBUG] rhsmcertd-worker:417696:MainThread @connection.py:556 - 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-10 09:34:48,986 [DEBUG] rhsmcertd-worker:417696:MainThread @connection.py:792 - Response time: 0.25473952293395996, Smoothed response time: 0.2951578378677368
2020-10-10 09:34:48,987 [DEBUG] rhsmcertd-worker:417696:MainThread @connection.py:769 - Response: status=401, requestUuid=858a5929-5134-4983-83b4-b81a7674100d, request="GET /subscription/consumers/62d47fcf-0b94-49b8-8a4f-e9d96494db7e/certificates/serials"
2020-10-10 09:34:48,987 [WARNING] rhsmcertd-worker:417696:MainThread @base_action_client.py:72 - Exception caught while running <subscription_manager.entcertlib.EntCertActionInvoker object at 0x7f49a6955a58> update
2020-10-10 09:34:48,987 [ERROR] rhsmcertd-worker:417696: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-10 09:34:48,988 [DEBUG] rhsmcertd-worker:417696:MainThread @base_action_client.py:88 - running lib: <subscription_manager.identitycertlib.IdentityCertActionInvoker object at 0x7f4991ad7cc0>
2020-10-10 09:34:48,989 [DEBUG] rhsmcertd-worker:417696:MainThread @connection.py:698 - Making request: GET /subscription/consumers/62d47fcf-0b94-49b8-8a4f-e9d96494db7e
2020-10-10 09:34:48,989 [DEBUG] rhsmcertd-worker:417696:MainThread @connection.py:556 - 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-10 09:34:49,366 [DEBUG] rhsmcertd-worker:417696:MainThread @connection.py:792 - Response time: 0.2985191345214844, Smoothed response time: 0.2954939675331116
2020-10-10 09:34:49,366 [DEBUG] rhsmcertd-worker:417696:MainThread @connection.py:769 - Response: status=401, requestUuid=ce24d5e6-3207-4319-ace2-cbf6af6725f8, request="GET /subscription/consumers/62d47fcf-0b94-49b8-8a4f-e9d96494db7e"
2020-10-10 09:34:49,367 [WARNING] rhsmcertd-worker:417696:MainThread @base_action_client.py:72 - Exception caught while running <subscription_manager.identitycertlib.IdentityCertActionInvoker object at 0x7f4991ad7cc0> update
2020-10-10 09:34:49,367 [ERROR] rhsmcertd-worker:417696: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-10 09:34:49,368 [DEBUG] rhsmcertd-worker:417696:MainThread @base_action_client.py:88 - running lib: <subscription_manager.content_action_client.ContentActionClient object at 0x7f4991ad7a58>
2020-10-10 09:34:49,368 [DEBUG] rhsmcertd-worker:417696:MainThread @base_action_client.py:88 - running lib: <subscription_manager.repolib.RepoActionInvoker object at 0x7f4991b33438>
2020-10-10 09:34:49,369 [DEBUG] rhsmcertd-worker:417696:MainThread @cache.py:881 - Trying to read SupportedResourcesCache from cache file /var/lib/rhsm/cache/supported_resources.json
2020-10-10 09:34:49,369 [DEBUG] rhsmcertd-worker:417696:MainThread @cache.py:891 - Data loaded from cache file: /var/lib/rhsm/cache/supported_resources.json
2020-10-10 09:34:49,370 [DEBUG] rhsmcertd-worker:417696:MainThread @connection.py:698 - Making request: GET /subscription/consumers/62d47fcf-0b94-49b8-8a4f-e9d96494db7e/content_overrides
2020-10-10 09:34:49,370 [DEBUG] rhsmcertd-worker:417696:MainThread @connection.py:556 - 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-10 09:34:49,747 [DEBUG] rhsmcertd-worker:417696:MainThread @connection.py:792 - Response time: 0.29952335357666016, Smoothed response time: 0.29589690613746644
2020-10-10 09:34:49,747 [DEBUG] rhsmcertd-worker:417696:MainThread @connection.py:769 - Response: status=401, requestUuid=9895bb8d-2f33-4053-a507-bca5b35a30c1, request="GET /subscription/consumers/62d47fcf-0b94-49b8-8a4f-e9d96494db7e/content_overrides"
2020-10-10 09:34:49,747 [ERROR] rhsmcertd-worker:417696:MainThread @cache.py:238 - HTTP error (401 - Unauthorized): Invalid credentials.
2020-10-10 09:34:49,748 [ERROR] rhsmcertd-worker:417696:MainThread @cache.py:241 - Server unreachable, registered, but no cache exists.
2020-10-10 09:34:49,748 [DEBUG] rhsmcertd-worker:417696:MainThread @repofile.py:364 - The directory /etc/yum.repos.d/ already exists
2020-10-10 09:34:49,748 [DEBUG] rhsmcertd-worker:417696:MainThread @repofile.py:364 - The directory /var/lib/rhsm/repo_server_val/ already exists
2020-10-10 09:34:49,748 [DEBUG] rhsmcertd-worker:417696:MainThread @__init__.py:92 - Searching for content of type: yum
2020-10-10 09:34:49,748 [DEBUG] rhsmcertd-worker:417696:MainThread @__init__.py:92 - Searching for content of type: deb
2020-10-10 09:34:49,749 [DEBUG] rhsmcertd-worker:417696:MainThread @cache.py:117 - Wrote cache: /var/lib/rhsm/cache/written_overrides.json
2020-10-10 09:34:49,749 [DEBUG] rhsmcertd-worker:417696:MainThread @repolib.py:463 - repos updated: Repo updates

Total repo updates: 0
Updated
    <NONE>
Added (new)
    <NONE>
Deleted
    <NONE>
2020-10-10 09:34:49,753 [DEBUG] rhsmcertd-worker:417696:MainThread @plugins.py:571 - loaded plugin modules: [<module 'ostree_content' from '/usr/share/rhsm-plugins/ostree_content.py'>]
2020-10-10 09:34:49,753 [DEBUG] rhsmcertd-worker:417696:MainThread @plugins.py:572 - loaded plugins: {'ostree_content.OstreeContentPlugin': <ostree_content.OstreeContentPlugin object at 0x7f49918390b8>}
2020-10-10 09:34:49,753 [DEBUG] rhsmcertd-worker:417696:MainThread @plugins.py:778 - Running update_content_hook in ostree_content.OstreeContentPlugin
2020-10-10 09:34:49,753 [DEBUG] rhsmcertd-worker:417696:MainThread @base_action_client.py:88 - running lib: <subscription_manager.content_action_client.ContentPluginActionInvoker object at 0x7f4991846320>
2020-10-10 09:34:49,753 [DEBUG] rhsmcertd-worker:417696:MainThread @__init__.py:92 - Searching for content of type: ostree
2020-10-10 09:34:49,754 [DEBUG] rhsmcertd-worker:417696:MainThread @action_invoker.py:85 - Ostree update report: Ostree repo updates

Updates:

Added:

Deleted:

2020-10-10 09:34:49,754 [DEBUG] rhsmcertd-worker:417696:MainThread @base_action_client.py:88 - running lib: <subscription_manager.factlib.FactsActionInvoker object at 0x7f4991ad7ac8>
2020-10-10 09:34:49,769 [DEBUG] rhsmcertd-worker:417696:MainThread @dmiinfo.py:76 - Using dmidecode dump file: /dev/mem
2020-10-10 09:34:49,818 [DEBUG] rhsmcertd-worker:417696: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-10 09:34:49,818 [DEBUG] rhsmcertd-worker:417696: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-10 09:34:49,819 [DEBUG] rhsmcertd-worker:417696:MainThread @factlib.py:102 - Facts have not changed, skipping upload.
2020-10-10 09:34:49,819 [DEBUG] rhsmcertd-worker:417696:MainThread @base_action_client.py:88 - running lib: <subscription_manager.packageprofilelib.PackageProfileActionInvoker object at 0x7f4991ad7b70>
2020-10-10 09:34:49,819 [DEBUG] rhsmcertd-worker:417696:MainThread @cache.py:172 - Checking current system info against cache: /var/lib/rhsm/cache/profile.json
2020-10-10 09:34:49,822 [DEBUG] rhsmcertd-worker:417696:MainThread @profile.py:312 - Loading current RPM profile.
2020-10-10 09:34:50,727 [DEBUG] rhsmcertd-worker:417696:MainThread @cache.py:189 - No changes.
2020-10-10 09:34:50,727 [DEBUG] rhsmcertd-worker:417696:MainThread @base_action_client.py:88 - running lib: <subscription_manager.installedproductslib.InstalledProductsActionInvoker object at 0x7f4991ad7c18>
2020-10-10 09:34:50,727 [DEBUG] rhsmcertd-worker:417696:MainThread @cache.py:172 - Checking current system info against cache: /var/lib/rhsm/cache/installed_products.json
2020-10-10 09:34:50,727 [DEBUG] rhsmcertd-worker:417696:MainThread @cache.py:189 - No changes.
2020-10-10 09:34:50,728 [DEBUG] rhsmcertd-worker:417696:MainThread @base_action_client.py:88 - running lib: <subscription_manager.syspurposelib.SyspurposeSyncActionInvoker object at 0x7f4991ad7d68>
2020-10-10 09:34:50,728 [DEBUG] rhsmcertd-worker:417696:MainThread @files.py:351 - Successfully read local syspurpose contents.
2020-10-10 09:34:50,728 [DEBUG] rhsmcertd-worker:417696:MainThread @files.py:388 - Successfully read cached syspurpose contents.
2020-10-10 09:34:50,728 [DEBUG] rhsmcertd-worker:417696:MainThread @files.py:297 - Attempting to sync syspurpose content...
2020-10-10 09:34:50,728 [DEBUG] rhsmcertd-worker:417696:MainThread @connection.py:698 - Making request: GET /subscription/status
2020-10-10 09:34:50,729 [DEBUG] rhsmcertd-worker:417696:MainThread @connection.py:556 - 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-10 09:34:51,105 [DEBUG] rhsmcertd-worker:417696:MainThread @connection.py:792 - Response time: 0.29871416091918945, Smoothed response time: 0.2961786316156388
2020-10-10 09:34:51,105 [DEBUG] rhsmcertd-worker:417696:MainThread @connection.py:769 - Response: status=200, requestUuid=0d452e4b-e9a0-41cc-ae29-cc22017972cb, request="GET /subscription/status"
2020-10-10 09:34:51,106 [DEBUG] rhsmcertd-worker:417696: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-10 09:34:51,106 [DEBUG] rhsmcertd-worker:417696:MainThread @connection.py:698 - Making request: GET /subscription/consumers/62d47fcf-0b94-49b8-8a4f-e9d96494db7e
2020-10-10 09:34:51,107 [DEBUG] rhsmcertd-worker:417696:MainThread @connection.py:556 - 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-10 09:34:51,431 [DEBUG] rhsmcertd-worker:417696:MainThread @connection.py:792 - Response time: 0.25744152069091797, Smoothed response time: 0.2923049205231667
2020-10-10 09:34:51,432 [DEBUG] rhsmcertd-worker:417696:MainThread @connection.py:769 - Response: status=401, requestUuid=09ab294a-a289-4ed2-a33c-f0c6478cb7e6, request="GET /subscription/consumers/62d47fcf-0b94-49b8-8a4f-e9d96494db7e"
2020-10-10 09:34:51,432 [DEBUG] rhsmcertd-worker:417696: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.

Comment 2 Rehana 2020-11-02 10:09:30 UTC

This bug was reported during one of our early testing cycle using the scratch builds. Reproducing this bug again is not possible as those scratch builds are no longer available.

Early Verification for Scenario 1 ( from description) 
=================================================

 # subscription-manager version
server type: This system is currently not registered.
subscription management server: 3.2.0-1
subscription management rules: 5.41

 # rpm -qa subscription-manager --changelog | grep 1886745
- 1886745: Fix __init__ of CPProvider; ENT-3147 (jhnidek)

 # syspurpose set-role foo
role set to "foo".
 # syspurpose show
{
  "role": "foo"
}
 # vi /etc/rhsm/rhsm.conf 
 # subscription-manager register --username=***** --password=******
Registering to: subscription.rhsm.stage.redhat.com:443/subscription
The system has been registered with ID: ***********
The registered system name is: **************
 # syspurpose show
{
  "role": "foo"
}
 # subscription-manager usage --set="QA"
Warning: Provided value "QA" is not included in the list of valid values
 - Development/Test
 - Production
 - Disaster Recovery
usage set to "QA".
 # syspurpose set-role foo
role set to "foo".
 # syspurpose show
{
  "role": "foo",
  "usage": "QA"
}

Result : The system purpose values can now be successfully set/retrieved via both syspurpose and subscription-manager modules 

Early Verification for Scenario 2 ( from comment 1)
===================================================

# subscription-manager version
server type: Red Hat Subscription Management
subscription management server: 3.2.0-1
subscription management rules: 5.41
subscription-manager: 1.28.5-1.el8

# subscription-manager register --username=********* --password=******
Registering to: subscription.rhsm.stage.redhat.com:443/subscription
The system has been registered with ID: **************
The registered system name is: *************

 # truncate --size=0 /var/log/rhsm/rhsm.log
 # subscription-manager config --logging.default_log_level=DEBUG
 # /usr/libexec/rhsmcertd-worker
Updating entitlement certificates & repositories
Total updates: 0
Found (local) serial# []
Expected (UEP) serial# []
Added (new)
  <NONE>
Deleted (rogue):
  <NONE>
Report
        status: 1
        updates: []
        exceptions: 
        
Fact updates
        status: None
        updates: []
        exceptions: 
        
Package profile updates
        status: 0
        updates: []
        exceptions: 
        
Installed Products
        status: 0
        updates: []
        exceptions: 
        
Syspurpose Sync
        status: Successfully synced system purpose
        updates: 
        exceptions: 
        
rhsm.log 
========
2020-11-02 11:03:26,996 [DEBUG] rhsmcertd-worker:17234:MainThread @files.py:297 - Attempting to sync syspurpose content...
2020-11-02 11:03:26,997 [DEBUG] rhsmcertd-worker:17234:MainThread @connection.py:698 - Making request: GET /subscription/consumers/664eaf4b-6e88-460a-be84-b5553d5973ac
2020-11-02 11:03:26,997 [DEBUG] rhsmcertd-worker:17234:MainThread @connection.py:556 - Loaded CA certificates from /etc/rhsm/ca/: redhat-entitlement-authority.pem, redhat-uep.pem
2020-11-02 11:03:28,301 [DEBUG] rhsmcertd-worker:17234:MainThread @connection.py:792 - Response time: 0.9265861511230469, Smoothed response time: 0.9323901981663704
2020-11-02 11:03:28,302 [DEBUG] rhsmcertd-worker:17234:MainThread @connection.py:769 - Response: status=200, requestUuid=d355be23-0c93-43b5-a32a-80a984e4eff7, request="GET /subscription/consumers/**********"
2020-11-02 11:03:28,303 [DEBUG] rhsmcertd-worker:17234:MainThread @files.py:380 - Successfully read remote syspurpose from server.
2020-11-02 11:03:28,303 [DEBUG] rhsmcertd-worker:17234:MainThread @files.py:661 - Attempting a three-way merge...
2020-11-02 11:03:28,305 [DEBUG] rhsmcertd-worker:17234:MainThread @files.py:591 - Successfully updated syspurpose values at '/etc/rhsm/syspurpose/syspurpose.json'.
2020-11-02 11:03:28,306 [DEBUG] rhsmcertd-worker:17234:MainThread @files.py:591 - Successfully updated syspurpose values at '/var/lib/rhsm/cache/syspurpose.json'.
2020-11-02 11:03:28,306 [DEBUG] rhsmcertd-worker:17234:MainThread @files.py:324 - Successfully synced system purpose.
2020-11-02 11:03:28,307 [DEBUG] rhsmcertd-worker:17234:MainThread @syspurposelib.py:285 - Syspurpose updated: Syspurpose Sync
        status: Successfully synced system purpose
        updates: 
        exceptions: 

Result: System purpose value were successfully synced and there we were no error reported. 

Conclusion: 
============
Based on the above observations, this bug has now passed the early verification . Hence setting "Verified" field to "Tested"

Comment 5 Shwetha Kallesh 2020-11-05 06:07:54 UTC

Verification:

[root@hpe-dl380pgen8-02-vm-15 ~]# subscription-manager version
server type: Red Hat Subscription Management
subscription management server: 3.2.0-1
subscription management rules: 5.41
subscription-manager: 1.28.5-1.el8


Case 1:

[root@hpe-dl380pgen8-02-vm-15 ~]# rpm -qa subscription-manager --changelog | grep 1886745
- 1886745: Fix __init__ of CPProvider; ENT-3147 (jhnidek)


[root@hpe-dl380pgen8-02-vm-15 ~]# syspurpose show
{}


[root@hpe-dl380pgen8-02-vm-15 ~]# syspurpose set-role foorole
role set to "foorole".


[root@hpe-dl380pgen8-02-vm-15 ~]# syspurpose show
{
  "role": "foorole"
}


[root@hpe-dl380pgen8-02-vm-15 ~]# subscription-manager register --serverurl subscription.rhsm.stage.redhat.com
Registering to: subscription.rhsm.stage.redhat.com:443/subscription
Username: stage_auto_testuser
Password: 
The system has been registered with ID: 2cc67cfe-6d5b-4312-8b17-59cfb0643b9c
The registered system name is: hpe-dl380pgen8-02-vm-15.hpe2.lab.eng.bos.redhat.com


[root@hpe-dl380pgen8-02-vm-15 ~]# syspurpose show
{
  "role": "foorole"
}
^^ no "HTTP error (401 - Unauthorized): Invalid credentials." error message, syspurpose show displays expected result

[root@hpe-dl380pgen8-02-vm-15 ~]# subscription-manager usage --set=foousage
Warning: Provided value "foousage" is not included in the list of valid values
 - Production
usage set to "foousage".


[root@hpe-dl380pgen8-02-vm-15 ~]# syspurpose set-role foo
Warning: Provided value "foo" is not included in the list of valid values for attribute role:
 - Red Hat Enterprise Linux Workstation
 - SP Server
 - Red Hat Enterprise Linux Server
 - Red Hat Enterprise Linux Compute Node
role set to "foo".
^^ no "HTTP error (401 - Unauthorized): Invalid credentials." error message, syspurpose set-role works fine
[root@hpe-dl380pgen8-02-vm-15 ~]# syspurpose show
{
  "role": "foo",
  "usage": "foousage"
}
^^ no "HTTP error (401 - Unauthorized): Invalid credentials." error message, syspurpose show displays expected result

Comment 6 Shwetha Kallesh 2020-11-05 06:10:48 UTC

Verification:

case 2:

[root@hpe-dl380pgen8-02-vm-15 ~]# /usr/libexec/rhsmcertd-worker 
Updating entitlement certificates & repositories
Total updates: 0
Found (local) serial# []
Expected (UEP) serial# []
Added (new)
  <NONE>
Deleted (rogue):
  <NONE>
Report
        status: 1
        updates: []
        exceptions: 
        
Fact updates
        status: None
        updates: []
        exceptions: 
        
Package profile updates
        status: 0
        updates: []
        exceptions: 
        
Installed Products
        status: 0
        updates: []
        exceptions: 
        
Syspurpose Sync
        status: Successfully synced system purpose
        updates: 
        exceptions:
^^System purpose value were successfully synced and there was no error reported. 
        
[root@hpe-dl380pgen8-02-vm-15 ~]# tail -50 /var/log/rhsm/rhsm.log 
2020-11-05 01:08:39,094 [DEBUG] rhsmcertd-worker:50137:MainThread @connection.py:792 - Response time: 0.4631526470184326, Smoothed response time: 0.4303240231513978
2020-11-05 01:08:39,094 [DEBUG] rhsmcertd-worker:50137:MainThread @connection.py:769 - Response: status=200, requestUuid=605fce3e-b819-4cca-9f6e-7af0062d7d8e, request="GET /subscription/consumers/2cc67cfe-6d5b-4312-8b17-59cfb0643b9c/content_overrides"
2020-11-05 01:08:39,096 [DEBUG] rhsmcertd-worker:50137:MainThread @cache.py:309 - Started thread to write cache: /var/lib/rhsm/cache/content_overrides.json
2020-11-05 01:08:39,096 [DEBUG] rhsmcertd-worker:50137:MainThread @repofile.py:364 - The directory /etc/yum.repos.d/ already exists
2020-11-05 01:08:39,096 [DEBUG] rhsmcertd-worker:50137:MainThread @repofile.py:364 - The directory /var/lib/rhsm/repo_server_val/ already exists
2020-11-05 01:08:39,097 [DEBUG] rhsmcertd-worker:50137:WriteCacheOverrideStatusCacheThread @cache.py:117 - Wrote cache: /var/lib/rhsm/cache/content_overrides.json
2020-11-05 01:08:39,097 [DEBUG] rhsmcertd-worker:50137:MainThread @__init__.py:92 - Searching for content of type: yum
2020-11-05 01:08:39,098 [DEBUG] rhsmcertd-worker:50137:MainThread @__init__.py:92 - Searching for content of type: deb
2020-11-05 01:08:39,098 [DEBUG] rhsmcertd-worker:50137:MainThread @cache.py:117 - Wrote cache: /var/lib/rhsm/cache/written_overrides.json
2020-11-05 01:08:39,098 [DEBUG] rhsmcertd-worker:50137:MainThread @repolib.py:463 - repos updated: Repo updates

Total repo updates: 0
Updated
    <NONE>
Added (new)
    <NONE>
Deleted
    <NONE>
2020-11-05 01:08:39,099 [DEBUG] rhsmcertd-worker:50137:MainThread @plugins.py:571 - loaded plugin modules: []
2020-11-05 01:08:39,099 [DEBUG] rhsmcertd-worker:50137:MainThread @plugins.py:572 - loaded plugins: {}
2020-11-05 01:08:39,100 [DEBUG] rhsmcertd-worker:50137:MainThread @base_action_client.py:88 - running lib: <subscription_manager.factlib.FactsActionInvoker object at 0x7f12e6bab588>
2020-11-05 01:08:39,115 [DEBUG] rhsmcertd-worker:50137:MainThread @dmiinfo.py:76 - Using dmidecode dump file: /dev/mem
2020-11-05 01:08:39,167 [DEBUG] rhsmcertd-worker:50137: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-11-05 01:08:39,167 [DEBUG] rhsmcertd-worker:50137: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-11-05 01:08:39,168 [DEBUG] rhsmcertd-worker:50137:MainThread @factlib.py:102 - Facts have not changed, skipping upload.
2020-11-05 01:08:39,168 [DEBUG] rhsmcertd-worker:50137:MainThread @base_action_client.py:88 - running lib: <subscription_manager.packageprofilelib.PackageProfileActionInvoker object at 0x7f12e6bab630>
2020-11-05 01:08:39,169 [DEBUG] rhsmcertd-worker:50137:MainThread @cache.py:172 - Checking current system info against cache: /var/lib/rhsm/cache/profile.json
2020-11-05 01:08:39,171 [DEBUG] rhsmcertd-worker:50137:MainThread @profile.py:312 - Loading current RPM profile.
2020-11-05 01:08:40,047 [DEBUG] rhsmcertd-worker:50137:MainThread @cache.py:189 - No changes.
2020-11-05 01:08:40,047 [DEBUG] rhsmcertd-worker:50137:MainThread @base_action_client.py:88 - running lib: <subscription_manager.installedproductslib.InstalledProductsActionInvoker object at 0x7f12e6bab6d8>
2020-11-05 01:08:40,048 [DEBUG] rhsmcertd-worker:50137:MainThread @cache.py:172 - Checking current system info against cache: /var/lib/rhsm/cache/installed_products.json
2020-11-05 01:08:40,048 [DEBUG] rhsmcertd-worker:50137:MainThread @cache.py:189 - No changes.
2020-11-05 01:08:40,048 [DEBUG] rhsmcertd-worker:50137:MainThread @base_action_client.py:88 - running lib: <subscription_manager.syspurposelib.SyspurposeSyncActionInvoker object at 0x7f12e6bab828>
2020-11-05 01:08:40,049 [DEBUG] rhsmcertd-worker:50137:MainThread @files.py:351 - Successfully read local syspurpose contents.
2020-11-05 01:08:40,049 [DEBUG] rhsmcertd-worker:50137:MainThread @files.py:388 - Successfully read cached syspurpose contents.
2020-11-05 01:08:40,049 [DEBUG] rhsmcertd-worker:50137:MainThread @files.py:297 - Attempting to sync syspurpose content...
2020-11-05 01:08:40,049 [DEBUG] rhsmcertd-worker:50137:MainThread @connection.py:698 - Making request: GET /subscription/consumers/2cc67cfe-6d5b-4312-8b17-59cfb0643b9c
2020-11-05 01:08:40,050 [DEBUG] rhsmcertd-worker:50137:MainThread @connection.py:556 - Loaded CA certificates from /etc/rhsm/ca/: redhat-entitlement-authority.pem, redhat-uep.pem
2020-11-05 01:08:40,676 [DEBUG] rhsmcertd-worker:50137:MainThread @connection.py:792 - Response time: 0.40766072273254395, Smoothed response time: 0.4280576931095124
2020-11-05 01:08:40,676 [DEBUG] rhsmcertd-worker:50137:MainThread @connection.py:769 - Response: status=200, requestUuid=8ca682a8-5662-4362-ad93-20cd08ee9538, request="GET /subscription/consumers/2cc67cfe-6d5b-4312-8b17-59cfb0643b9c"
2020-11-05 01:08:40,677 [DEBUG] rhsmcertd-worker:50137:MainThread @files.py:380 - Successfully read remote syspurpose from server.
2020-11-05 01:08:40,677 [DEBUG] rhsmcertd-worker:50137:MainThread @files.py:661 - Attempting a three-way merge...
2020-11-05 01:08:40,678 [DEBUG] rhsmcertd-worker:50137:MainThread @files.py:591 - Successfully updated syspurpose values at '/etc/rhsm/syspurpose/syspurpose.json'.
2020-11-05 01:08:40,678 [DEBUG] rhsmcertd-worker:50137:MainThread @files.py:591 - Successfully updated syspurpose values at '/var/lib/rhsm/cache/syspurpose.json'.
2020-11-05 01:08:40,678 [DEBUG] rhsmcertd-worker:50137:MainThread @files.py:324 - Successfully synced system purpose.
2020-11-05 01:08:40,678 [DEBUG] rhsmcertd-worker:50137:MainThread @syspurposelib.py:285 - Syspurpose updated: Syspurpose Sync
        status: Successfully synced system purpose
        updates: 
        exceptions: 
^^System purpose value were successfully synced and there was no error reported.

Comment 8 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