Hide Forgot
Created attachment 1276501 [details] rhsm.log
Moving to RHEL/subscription-manager as this is seemingly related to that component and not Satellite, but I will do some testing and confirmation.
Confirmed that this is non-specific to Satellite, the same occurs against SAM (I know, not that different.. per say), but as well against the Customer portal / Prod candlepin. This is simply due to rhsm_icon.json not existing prior to us trying to do something with it. It gets created immediately after, and therefore you do not see the error again. Its contents appear to always be '1'. Can we handle this issue differently to steer people away from the "false" error?
*** Bug 1467837 has been marked as a duplicate of this bug. ***
Reproducing the failure on RHEL74 with the following build: ====================================================== # subscription-manager version server type: Red Hat Subscription Management subscription management server: 3.4.5.25-Unknown subscription management rules: 5.26 subscription-manager: 1.19.21-1.el7 python-rhsm: 1.19.9-1.el7 Register system against satellite 6 server and watch the rhsm.log Make sure rhsm_icon.json doesnt exist # ll /var/lib/rhsm/cache/rhsm_icon.json ls: cannot access /var/lib/rhsm/cache/rhsm_icon.json: No such file or directory [root@dhcp35-157 ~]# # subscription-manager register --username=username --password=password --org=Default_Organization --environment=Dev/rhel7_cv Registering to: qeblade36.rhq.lab.eng.bos.redhat.com:443/rhsm The system has been registered with ID: 3c292a80-35f9-4273-a920-281907dc0305 rhsm.log =========== 2017-11-13 16:01:07,061 [INFO] subscription-manager:11626:MainThread @connection.py:552 - Response: status=200, request="GET /rhsm/consumers/3c292a80-35f9-4273-a920-281907dc0305/compliance" 2017-11-13 16:01:07,063 [INFO] subscription-manager:11626:MainThread @cert_sorter.py:204 - Product status: valid_products= partial_products= expired_products= unentitled_producs=69 future_products= valid_until=None 2017-11-13 16:01:07,152 [INFO] rhsmd:11465:MainThread @connection.py:822 - Connection built: host=subscription.rhsm.stage.redhat.com port=443 handler=/subscription auth=identity_cert ca_dir=/etc/rhsm/ca/ insecure=False 2017-11-13 16:01:08,611 [INFO] rhsmd:11465:MainThread @connection.py:552 - Response: status=401, requestUuid=d8497379-e999-449e-908c-5628f74e8c52, request="GET /subscription/consumers/3c292a80-35f9-4273-a920-281907dc0305/compliance" 2017-11-13 16:01:08,612 [ERROR] rhsmd:11465:MainThread @cache.py:221 - Invalid credentials. Traceback (most recent call last): File "/usr/lib/python2.7/site-packages/subscription_manager/cache.py", line 209, in load_status self._sync_with_server(uep, uuid) File "/usr/lib/python2.7/site-packages/subscription_manager/cache.py", line 318, in _sync_with_server self.server_status = uep.getCompliance(uuid) File "/usr/lib64/python2.7/site-packages/rhsm/connection.py", line 1076, in getCompliance return self.conn.request_get(method) File "/usr/lib64/python2.7/site-packages/rhsm/connection.py", line 646, in request_get return self._request("GET", method, headers=headers) File "/usr/lib64/python2.7/site-packages/rhsm/connection.py", line 672, in _request info=info, headers=headers) File "/usr/lib64/python2.7/site-packages/rhsm/connection.py", line 561, in _request self.validateResponse(result, request_type, handler) File "/usr/lib64/python2.7/site-packages/rhsm/connection.py", line 610, in validateResponse raise RestlibException(response['status'], error_msg, response.get('headers')) RestlibException: Invalid credentials. 2017-11-13 16:01:08,615 [ERROR] rhsmd:11465:MainThread @cache.py:128 - Unable to read cache: /var/lib/rhsm/cache/rhsm_icon.json 2017-11-13 16:01:08,615 [ERROR] rhsmd:11465:MainThread @cache.py:129 - [Errno 2] No such file or directory: '/var/lib/rhsm/cache/rhsm_icon.json' Traceback (most recent call last): File "/usr/lib/python2.7/site-packages/subscription_manager/cache.py", line 123, in _read_cache f = open(self.CACHE_FILE) IOError: [Errno 2] No such file or directory: '/var/lib/rhsm/cache/rhsm_icon.json' Verification steps on rhel75: ============================= Install the Satellite6 server's certificate on the system With new fix ,the following DEBUG message should appear in log file: "Cache file: /var/lib/rhsm/cache/rhsm_icon.json does not exist yet " to view this Debug message set the log level to "Debug" ex: default_log_level = DEBUG Make sure rhsm_icon.json doesn't exist # ll /var/lib/rhsm/cache/rhsm_icon.json ls: cannot access /var/lib/rhsm/cache/rhsm_icon.json: No such file or directory [root@dhcp35-157 ~]# 2017-11-13 16:14:57,622 [DEBUG] rhsmd:32253:MainThread @cert_sorter.py:207 - partial stacks: [] 2017-11-13 16:14:57,622 [DEBUG] rhsmd:32253:MainThread @cache.py:168 - Checking current system info against cache: /var/lib/rhsm/cache/installed_products.json 2017-11-13 16:14:57,627 [DEBUG] rhsmd:32253:MainThread @cache.py:185 - No changes. 2017-11-13 16:14:57,627 [DEBUG] rhsmd:32253:MainThread @identity.py:137 - Loading consumer info from identity certificates. 2017-11-13 16:14:57,628 [DEBUG] rhsmd:32253:MainThread @rhsmd:238 - Cache file: /var/lib/rhsm/cache/rhsm_icon.json does not exist yet 2017-11-13 16:14:57,629 [DEBUG] rhsmd:32253:MainThread @cache.py:114 - Wrote cache: /var/lib/rhsm/cache/rhsm_icon.json ^^ observed that a DEBUG message is now displayed in rhsm.log stating " rhsm_icon.json doesnt exist" and a new file was written. Based on the above observations , marking the bug as verified!!
Moving the bug to "New" based on the following observation : 1) Deploy a fresh RHEL75 machine , OR make sure that "/var/lib/rhsm/cache/rhsm_icon.json" file does not exist 2) WITHOUT registering the sysstem , execute `service rhsmcertd restart" observed following error message on the rhsm.log 2017-11-16 12:39:01,884 [ERROR] rhsmd:13540:MainThread @cache.py:130 - Unable to read cache: /var/lib/rhsm/cache/rhsm_icon.json 2017-11-16 12:39:01,884 [ERROR] rhsmd:13540:MainThread @cache.py:131 - [Errno 2] No such file or directory: '/var/lib/rhsm/cache/rhsm_icon.json' Traceback (most recent call last): File "/usr/lib64/python2.7/site-packages/subscription_manager/cache.py", line 125, in _read_cache f = open(self.CACHE_FILE) IOError: [Errno 2] No such file or directory: '/var/lib/rhsm/cache/rhsm_icon.json' 2017-11-16 12:39:01,900 [DEBUG] rhsmd:13540:MainThread @rhsmd:196 - D-Bus signal com.redhat.SubscriptionManager.EntitlementStatus.entitlement_status_changed emitted 2017-11-16 12:39:01,902 [DEBUG] rhsmd:13540:MainThread @cache.py:114 - Wrote cache: /var/lib/rhsm/cache/rhsm_icon.json ^C Similar to the fix made to this bug , (and as verified in comment 8 ) , request you to have the same Debug messages displayed in the rhsm.log instead of the traceback error. Based on the discussion with Jiri , moving this bug to "New"
Verifying on : ============= subscription-manager-plugin-container-1.20.10-1.el7.x86_64 subscription-manager-rhsm-1.20.10-1.el7.x86_64 subscription-manager-plugin-ostree-1.20.10-1.el7.x86_64 subscription-manager-initial-setup-addon-1.20.10-1.el7.x86_64 subscription-manager-migration-data-2.0.37-1.el7.noarch subscription-manager-debuginfo-1.20.10-1.el7.x86_64 subscription-manager-rhsm-certificates-1.20.10-1.el7.x86_64 Make sure the file "/var/lib/rhsm/cache/rhsm_icon.json" file does not exist and Restart rhsmcertd service ( make sure rhsmd service is running) 2018-02-08 05:56:23,532 [DEBUG] rhsmd:31662:MainThread @connection.py:543 - Making request: GET /rhsm/consumers/5ddb16cb-5ff5-4c9c-8a4d-016a9719af79/compliance 2018-02-08 05:56:23,632 [INFO] rhsmd:31662:MainThread @connection.py:586 - Response: status=200, request="GET /rhsm/consumers/5ddb16cb-5ff5-4c9c-8a4d-016a9719af79/compliance" 2018-02-08 05:56:23,634 [DEBUG] rhsmd:31662:WriteCacheEntitlementStatusCacheThread @cache.py:114 - Wrote cache: /var/lib/rhsm/cache/entitlement_status.json 2018-02-08 05:56:23,634 [DEBUG] rhsmd:31662:MainThread @cache.py:302 - Started thread to write cache: /var/lib/rhsm/cache/entitlement_status.json 2018-02-08 05:56:23,635 [INFO] rhsmd:31662:MainThread @cert_sorter.py:205 - Product status: valid_products= partial_products= expired_products= unentitled_producs=69 and 230 future_products= valid_until=None 2018-02-08 05:56:23,635 [DEBUG] rhsmd:31662:MainThread @cert_sorter.py:207 - partial stacks: [] 2018-02-08 05:56:23,635 [DEBUG] rhsmd:31662:MainThread @cache.py:169 - Checking current system info against cache: /var/lib/rhsm/cache/installed_products.json 2018-02-08 05:56:23,637 [DEBUG] rhsmd:31662:MainThread @cache.py:186 - No changes. 2018-02-08 05:56:23,637 [DEBUG] rhsmd:31662:MainThread @identity.py:137 - Loading consumer info from identity certificates. 2018-02-08 05:56:23,638 [DEBUG] rhsmd:31662:MainThread @cache.py:146 - Cache file /var/lib/rhsm/cache/rhsm_icon.json does not exist 2018-02-08 05:56:23,638 [DEBUG] rhsmd:31662:MainThread @cache.py:114 - Wrote cache: /var/lib/rhsm/cache/rhsm_icon.json Observed that rhsm_icon.json file was created and no IO errors were observed. Based on the observation , moving the bug as Verified..
*** Bug 1559238 has been marked as a duplicate of this bug. ***
Since the problem described in this bug report should be resolved in a recent advisory, it has been closed with a resolution of ERRATA. For information on the advisory, and where to find the updated files, follow the link below. If the solution does not work for you, open a new bug report. https://access.redhat.com/errata/RHBA-2018:0681