Bug 1747444

Summary: Latest leapp 0.8.1 fails with an inaccurate error about internet connection
Product: Red Hat Enterprise Linux 7 Reporter: Christophe Besson <cbesson>
Component: leapp-repositoryAssignee: Leapp team <leapp-notifications>
Status: CLOSED DUPLICATE QA Contact: Alois Mahdal <amahdal>
Severity: medium Docs Contact:
Priority: medium    
Version: 7.6CC: cbesson, hannsj_uhl, mbocek
Target Milestone: rc   
Target Release: 7.8   
Hardware: All   
OS: Linux   
Whiteboard:
Fixed In Version: Doc Type: If docs needed, set a value
Doc Text:
Story Points: ---
Clone Of: Environment:
Last Closed: 2019-08-30 17:58:49 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 Christophe Besson 2019-08-30 13:08:05 UTC
Description of problem:

The customer got these messages while trying an upgrade from RHEL 7.6 to RHEL 8.0 using leapp.
~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~
2019-08-26 22:00:30.994 INFO     PID: 14537 leapp.workflow.FactsCollection.target_userspace_creator: Attempt 1 of 5 to perform unset_release failed - Retrying after 5 seconds
2019-08-26 22:00:37.91  INFO     PID: 14537 leapp.workflow.FactsCollection.target_userspace_creator: Attempt 2 of 5 to perform unset_release failed - Retrying after 5 seconds
2019-08-26 22:00:43.212 INFO     PID: 14537 leapp.workflow.FactsCollection.target_userspace_creator: Attempt 3 of 5 to perform unset_release failed - Retrying after 5 seconds
2019-08-26 22:00:49.314 INFO     PID: 14537 leapp.workflow.FactsCollection.target_userspace_creator: Attempt 4 of 5 to perform unset_release failed - Retrying after 5 seconds
2019-08-26 22:00:55.408 INFO     PID: 14537 leapp.workflow.FactsCollection.target_userspace_creator: Attempt 5 of 5 to perform unset_release failed - Retrying after 5 seconds
2019-08-26 22:01:01.487 WARNING  PID: 14537 leapp.workflow.FactsCollection.target_userspace_creator: Attempt 6 of 5 to perform unset_release failed. Maximum number of retries have been reached.
...
2019-08-26 14:22:52.539214 [ERROR] Actor: target_userspace_creator Message: A subscription-manager command failed to execute
Detail: {u'hint': u'Please ensure you have a valid RHEL subscription and your network is up.'}
~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~

Version-Release number of selected component (if applicable):
leapp-repository-0.8.1-2.el7_6

How reproducible:
Can't reproduce.

Steps to Reproduce:
1.
2.
3.

Actual results:
2019-08-26 14:22:52.539214 [ERROR] Actor: target_userspace_creator Message: A subscription-manager command failed to execute
Detail: {u'hint': u'Please ensure you have a valid RHEL subscription and your network is up.'}

Expected results:
No issue. The downgrade to the previous version (0.7) works.

Additional info:
From the leapp.db, we can see that the command "subscription-manager release --unset" returns an exit code 70.
~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~
15134 22:06:21.083344 read(4</var/lib/leapp/leapp.db>, "\r\0\0\0\1\1\1\0\1\1\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\205z\205\343v\t\0)CU\2\0\212Qprocess-result2019-08-26T10:02:11.153760Z5a4c0958-e4b7-4ea0-ae45-e12cbd6d6907\0\314{\"env\": null, \"id\": \"84de09c4-6dee-4a31-9f62-ed266ba51274\", \"parameters\": [\"systemd-nspawn\", \"--register=no\", \"--quiet\", \"-D\", \"/var/lib/leapp/scratch/mounts/source_overlay\", \"subscription-manager\", \"release\", \"--unset\"], \"result\": {\"signal\": 0, \"pid\": 11749, \"exit_code\": 70, \"stderr\": \"Failed to create directory /var/lib/leapp/scratch/mounts/source_overlay//sys/fs/selinux: Read-only file system\\nFailed to create directory /var/lib/leapp/scratch/mounts/source_overlay//sys/fs/selinux: Read-only file system\\nHost and machine ids are equal (9fe4afedfc8b4579b6d407df097233be): refusing to link journals\\nSystem certificates corrupted. Please reregister.\\n\", \"stdout\": \"\"}}"..., 16384) = 16384 <0.000025>
~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~

After a look in the subscription-manager code, it seems to come from there:
~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~
/usr/lib64/python2.7/site-packages/subscription_manager/managercli.py:
 499         try:
 500 
 501             return_code = self._do_command()
 502 
 503             # Only persist the config changes if there was no exception
 504             if config_changed and self.persist_server_options():
 505                 conf.persist()
 506 
 507             if return_code is not None:
 508                 return return_code
 509         except (CertificateException, ssl.SSLError) as e:
 510             log.error(e)
 511             system_exit(os.EX_SOFTWARE, _('System certificates corrupted. Please reregister.'))
~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~


The strace shows information on what was logged into rhsm.log:
~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~
16749 22:09:30.323544 write(4</var/log/rhsm/rhsm.log>, "2019-08-26 22:09:30,323 [INFO] subscription-manager:1:MainThread @managercli.py:346 - Client Versions: {'subscription-manager': '1.21.10-3.el7_6'}\n", 147) = 147 <0.000010>
16749 22:09:30.324245 write(4</var/log/rhsm/rhsm.log>, "2019-08-26 22:09:30,324 [INFO] subscription-manager:1:MainThread @connection.py:871 - Connection built: http_proxy=205.235.99.79:3128 host=subscription.rhsm.redhat.com port=443 handler=/subscription auth=identity_cert ca_dir=/etc/rhsm/ca/ insecure=False\n", 254) = 254 <0.000014>
16749 22:09:30.324741 write(4</var/log/rhsm/rhsm.log>, "2019-08-26 22:09:30,324 [INFO] subscription-manager:1:MainThread @connection.py:871 - Connection built: http_proxy=205.235.99.79:3128 host=subscription.rhsm.redhat.com port=443 handler=/subscription auth=none\n", 209) = 209 <0.000014>
16749 22:09:30.325935 write(4</var/log/rhsm/rhsm.log>, "2019-08-26 22:09:30,325 [INFO] subscription-manager:1:MainThread @managercli.py:322 - Consumer Identity name=sgccav011 uuid=702c6051-cdd3-4df8-8509-7e40f1140e3d\n", 161) = 161 <0.000014>
16749 22:09:31.191314 write(4</var/log/rhsm/rhsm.log>, "2019-08-26 22:09:31,191 [INFO] subscription-manager:1:MainThread @connection.py:588 - Response: status=204, requestUuid=d65730dd-7bdf-4e11-a08d-e2336d2cd007, request=\"PUT /subscription/consumers/702c6051-cdd3-4df8-8509-7e40f1140e3d\"\n", 233) = 233 <0.000015>
16749 22:09:31.196361 write(4</var/log/rhsm/rhsm.log>, "2019-08-26 22:09:31,196 [ERROR] subscription-manager:1:MainThread @managercli.py:510 - Error loading certificate: [Errno 2] No such file or directory: '/etc/pki/product-default/69.pem'\n", 185) = 185 <0.000014>
~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~

=> The error being: Error loading certificate: [Errno 2] No such file or directory: '/etc/pki/product-default/69.pem

=> The customer has this file on its RHEL 7.6 rootfs, but not in the "el8target" used for the upgrade.

=> I noticed that the behavior was different with the previous leapp release (0.7.x), so I asked for the customer to downgrade, and then it works for him.
~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~
# yum remove 'leapp*'
# yum install leapp-0.7.0-2.el7_6 leapp-repository-0.7.0-5.el7_6
~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~

Unfortunately, I didn't succeed to reproduce the issue. If I removed this file from my test VM, it is upgraded anyway, without failure.
If I copy the file during the leapp process, before the release --unset, it doesn't work too, I got the following error message:
~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~
No releases match '8.0'.  Consult 'release --list' for a full listing.
~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~

Comment 2 Christophe Besson 2019-08-30 13:10:52 UTC
Additional note:

The following error message can be safely ignored, this is not the root cause.

Failed to create directory /var/lib/leapp/scratch/mounts/source_overlay//sys/fs/selinux: Read-only file system\\nFailed to create directory /var/lib/leapp/scratch/mounts/source_overlay//sys/fs/selinux: Read-only file system

Comment 3 Michal Bocek 2019-08-30 17:58:49 UTC

*** This bug has been marked as a duplicate of bug 1746956 ***