Bug 1327179

Summary: Subscription Manager cannot start when entitlement server is unreachable in case a proxy connection is used
Product: Red Hat Enterprise Linux 6 Reporter: Jan Stavel <jstavel>
Component: subscription-managerAssignee: William Poteat <wpoteat>
Status: CLOSED ERRATA QA Contact: Jan Stavel <jstavel>
Severity: low Docs Contact:
Priority: low    
Version: 6.8CC: csnyder, wpoteat
Target Milestone: rcKeywords: Triaged
Target Release: 6.9   
Hardware: x86_64   
OS: Linux   
Whiteboard:
Fixed In Version: Doc Type: Bug Fix
Doc Text:
Story Points: ---
Clone Of: Environment:
Last Closed: 2017-03-21 10:55:09 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:
Attachments:
Description Flags
rhsm.log none

Description Jan Stavel 2016-04-14 12:11:48 UTC
Description of problem:

    When entitlement server is unreachable and subscription manager uses proxy connection
    I cannot start subscription manager - nothing appears on desktop.

    Subscription manager does not inform about connection problem
    anyway. It is necessary to take a look into /var/log/rhsm/rhsm.log to get to find out what happened.


Version-Release number of selected component (if applicable):

Red Hat Enterprise Linux Server release 6.8 Beta (Santiago)
----------------------------     ----------------------------
arch                             x86_64
kernel version                   2.6.32-642.el6.x86_64
----------------------------     ----------------------------
server type                      Red Hat Subscription Management
subscription management server   0.9.51.15-1
subscription management rules    5.15.1
subscription-manager             1.16.8-8.el6
python-rhsm                      1.16.6-1.el6
----------------------------     ----------------------------
Product                          69.pem
----------------------------     ----------------------------
Entitlement                      4901737346057435916.pem
----------------------------     ----------------------------

How reproducible:


Steps to Reproduce:

    Before system is registered
    and entitlement server is unreachable
    and subscription-manager uses authorized proxy connection
    When I run subscription-manager-gui
    then nothing appears
    and /var/log/rhsm/rhsm.log contains Traceback.

    #+BEGIN_SRC
        return self.conn.request_get(method)
      File "/usr/lib64/python2.6/site-packages/rhsm/connection.py", line 681, in request_get
        return self._request("GET", method)
      File "/usr/lib64/python2.6/site-packages/rhsm/connection.py", line 578, in _request
        response = conn.getresponse()
      File "/usr/lib64/python2.6/httplib.py", line 1012, in getresponse
        response.begin()
      File "/usr/lib64/python2.6/httplib.py", line 404, in begin
        version, status, reason = self._read_status()
      File "/usr/lib64/python2.6/httplib.py", line 368, in _read_status
        raise BadStatusLine(line)
    BadStatusLine
    2016-04-14 13:47:22,652 [DEBUG] subscription-manager-gui:4502 @identity.py:131 - Loading consumer info from identity certificates.
    2016-04-14 13:47:22,655 [DEBUG] subscription-manager-gui:4502 @connection.py:298 - ContectConnection
    2016-04-14 13:47:22,656 [INFO] subscription-manager-gui:4502 @connection.py:815 - Connection built: http_proxy=auto-services.usersys.redhat.com:3128 host=subscription.rhsm.stage.redhat.com port=443 handler=/subscription auth=identity_cert ca_dir=/etc/rhsm/ca/ verify=False
    2016-04-14 13:47:22,656 [DEBUG] subscription-manager-gui:4502 @cache.py:154 - Checking current system info against cache: /var/lib/rhsm/cache/installed_products.json
    2016-04-14 13:47:22,657 [DEBUG] subscription-manager-gui:4502 @cache.py:171 - No changes.
    2016-04-14 13:47:22,657 [DEBUG] subscription-manager-gui:4502 @certdirectory.py:216 - Installed product IDs: ['69']
    2016-04-14 13:47:22,657 [DEBUG] subscription-manager-gui:4502 @connection.py:509 - Loaded CA certificates from /etc/rhsm/ca/: redhat-uep.pem
    2016-04-14 13:47:22,657 [DEBUG] subscription-manager-gui:4502 @connection.py:542 - Using proxy: auto-services.usersys.redhat.com:3128
    2016-04-14 13:47:22,658 [DEBUG] subscription-manager-gui:4502 @connection.py:557 - Making request: GET https://subscription.rhsm.stage.redhat.com:443/subscription/consumers/eddb617f-bf9c-4572-8560-c529db7ea327/compliance
    2016-04-14 13:47:23,952 [ERROR] subscription-manager-gui:4502 @subscription-manager-gui:216 -
    Traceback (most recent call last):
      File "/usr/sbin/subscription-manager-gui", line 199, in <module>
        main = managergui.MainWindow(auto_launch_registration=options.register)
      File "/usr/share/rhsm/subscription_manager/gui/managergui.py", line 153, in __init__
        self.backend = backend or Backend()
      File "/usr/share/rhsm/subscription_manager/gui/managergui.py", line 100, in __init__
        self.cs = require(CERT_SORTER)
      File "/usr/share/rhsm/subscription_manager/injection.py", line 103, in require
        return FEATURES.require(feature, *args, **kwargs)
      File "/usr/share/rhsm/subscription_manager/injection.py", line 77, in require
        self.providers[feature] = provider()
      File "/usr/share/rhsm/subscription_manager/cert_sorter.py", line 325, in __init__
        super(CertSorter, self).__init__()
      File "/usr/share/rhsm/subscription_manager/cert_sorter.py", line 65, in __init__
        self.load()
      File "/usr/share/rhsm/subscription_manager/cert_sorter.py", line 111, in load
        self._parse_server_status()
      File "/usr/share/rhsm/subscription_manager/cert_sorter.py", line 130, in _parse_server_status
        status = self.get_compliance_status()
      File "/usr/share/rhsm/subscription_manager/cert_sorter.py", line 343, in get_compliance_status
        return status_cache.load_status(self.cp_provider.get_consumer_auth_cp(), self.identity.uuid)
      File "/usr/share/rhsm/subscription_manager/cache.py", line 197, in load_status
        self._sync_with_server(uep, uuid)
      File "/usr/share/rhsm/subscription_manager/cache.py", line 306, in _sync_with_server
        self.server_status = uep.getCompliance(uuid)
      File "/usr/lib64/python2.6/site-packages/rhsm/connection.py", line 1069, in getCompliance
        return self.conn.request_get(method)
      File "/usr/lib64/python2.6/site-packages/rhsm/connection.py", line 681, in request_get
        return self._request("GET", method)
      File "/usr/lib64/python2.6/site-packages/rhsm/connection.py", line 578, in _request
        response = conn.getresponse()
      File "/usr/lib64/python2.6/httplib.py", line 1012, in getresponse
        response.begin()
      File "/usr/lib64/python2.6/httplib.py", line 404, in begin
        version, status, reason = self._read_status()
      File "/usr/lib64/python2.6/httplib.py", line 368, in _read_status
        raise BadStatusLine(line)
    BadStatusLine
    #+END_SRC


inspection of a connection

#+begin_example
[root@localhost ~]# ping subscription.rhsm.stage.redhat.com
PING subscription-rhsm-redhat-com.edge.stage.ext.phx2.redhat.com (10.5.164.73) 56(84) bytes of data.
64 bytes from subscription-rhsm-redhat-com.edge.stage.ext.phx2.redhat.com (10.5.164.73): icmp_seq=1 ttl=249 time=204 ms
64 bytes from subscription-rhsm-redhat-com.edge.stage.ext.phx2.redhat.com (10.5.164.73): icmp_seq=2 ttl=249 time=226 ms
^C
--- subscription-rhsm-redhat-com.edge.stage.ext.phx2.redhat.com ping statistics ---
3 packets transmitted, 2 received, 33% packet loss, time 2109ms
rtt min/avg/max/mdev = 204.083/215.156/226.230/11.083 ms
[root@localhost ~]# curl -k https://subscription.rhsm.stage.redhat.com:443/subscription/consumers/eddb617f-bf9c-4572-8560-c529db7ea327/compliance
curl: (56) NSS: client certificate not found (nickname not specified)
[root@localhost ~]# curl -k https://subscription.rhsm.stage.redhat.com:443/subscription/consumers/eddb617f-bf9c-4572-8560-c529db7ea327/compliance
curl: (56) NSS: client certificate not found (nickname not specified)
#+end_example

Actual results:

Just traceback in /var/log/rhsm/rhsm.log appears when connection problem throught proxy connection.

Expected results:


Additional info:

Comment 2 Jan Stavel 2016-04-14 13:24:36 UTC
I have tried to switch proxy connection off.

Subscription-manager started and text "Entitlement server is unreachable" appeared in its main page.

Comment 3 Jan Stavel 2016-04-14 13:28:02 UTC
Created attachment 1147258 [details]
rhsm.log

Comment 5 Jan Stavel 2016-04-14 13:52:11 UTC
I would like to emphasize that main point of this issue is that subscription-manager does not tell me anything about this problem (when using proxy) and that it is even unable to start.

Comment 7 Chris Snyder 2016-07-18 15:11:36 UTC
Commit for fix in master:

6df3f6458c61d6e334a40001a10868477490497c

Comment 9 Chris Snyder 2016-10-17 22:21:15 UTC
Moving to MODIFIED as this will be included in the first build on the RHEL 6.9 errata.

Comment 11 Jan Stavel 2016-11-09 15:10:24 UTC
Verified. No problem occurs when such situation happens. And that is the main point of this story.

Thanks!

Comment 12 Jan Stavel 2016-11-25 15:18:54 UTC
I have automated this use case.

Comment 14 errata-xmlrpc 2017-03-21 10:55:09 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, 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://rhn.redhat.com/errata/RHSA-2017-0698.html