Bug 1419197

Summary:	subscription-manager status with bad proxy configurations should be using cache
Product:	Red Hat Enterprise Linux 6	Reporter:	John Sefler <jsefler>
Component:	subscription-manager	Assignee:	candlepin-bugs
Status:	CLOSED NOTABUG	QA Contact:	John Sefler <jsefler>
Severity:	unspecified	Docs Contact:
Priority:	unspecified
Version:	6.8	CC:	csnyder, redakkan, skallesh
Target Milestone:	rc
Target Release:	---
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:	2017-02-06 15:52:27 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 2017-02-03 21:14:15 UTC

Description of problem:
Awhile back, work was done within subscription-manager to maintain a cache for several subscription-manager functional modules including the status module.  If the connection to an rhsm.conf configured proxy failed, then a cached value would be reported.

I suspect that some of the work done or referenced in bug 1176219 and bug 1301215 may have changed this behavior for the status module.  Instead of getting a cached value, I now get a "Proxy connection failed: 407" error.


Version-Release number of selected component (if applicable):
[root@jsefler-rhel6server ~]# rpm -q subscription-manager python-rhsm
subscription-manager-1.18.9-1.el6.x86_64
python-rhsm-1.18.6-1.el6.x86_64


How reproducible:
After upgrading from rhel6.8 to rhel6.9

Steps to Reproduce:
BEGIN WITH THE RHEL68 RHSM PACKAGES INSTALLED WHERE THE OLD CACHED BEHAVIOR WAS WORKING..

[root@jsefler-rhel6server ~]# rpm -q subscription-manager python-rhsm
subscription-manager-1.16.8-8.el6.x86_64
python-rhsm-1.16.6-1.el6.x86_64

[root@jsefler-rhel6server ~]# subscription-manager config --server.proxy_hostname=auto-services.usersys.redhat.com --server.proxy_port=3128 --server.proxy_user=redhat --server.proxy_password=redhat
[root@jsefler-rhel6server ~]# 
[root@jsefler-rhel6server ~]# subscription-manager register --serverurl=subscription.rhsm.stage.redhat.com:443/subscription --username=qa
Registering to: subscription.rhsm.stage.redhat.com:443/subscription
Password: 
The system has been registered with ID: 68aeb7c0-4e98-41ad-a35c-f4a2ac36fbc2 
[root@jsefler-rhel6server ~]# 
[root@jsefler-rhel6server ~]# subscription-manager status
+-------------------------------------------+
   System Status Details
+-------------------------------------------+
Overall Status: Invalid

Red Hat Enterprise Linux Server:
- Not supported by a valid subscription.


NOW LET'S BORK THE CONFIGURED PROXY USER TO FORCE A FAILED CONNECTION...

[root@jsefler-rhel6server ~]# subscription-manager config --server.proxy_password=bad_password

NOW LET'S CALL THE STATUS MODULE WITH THE BAD PROXY PASSWORD CONFIGURED...

[root@jsefler-rhel6server ~]# subscription-manager status
+-------------------------------------------+
   System Status Details
+-------------------------------------------+
Overall Status: Invalid

Red Hat Enterprise Linux Server:
- Not supported by a valid subscription.

[root@jsefler-rhel6server ~]# 
[root@jsefler-rhel6server ~]# tail -f /var/log/rhsm/rhsm.log
Making request: GET https://subscription.rhsm.stage.redhat.com:443/subscription/consumers/68aeb7c0-4e98-41ad-a35c-f4a2ac36fbc2/compliance
2017-02-03 15:56:46,141 [ERROR] subscription-manager:23479 @cache.py:229 - Proxy connection failed: 407
2017-02-03 15:56:46,142 [WARNING] subscription-manager:23479 @cache.py:235 - Unable to reach server, using cached status.

PASS!  DESPITE THE BAD PROXY PASSWORD CONFIGURED, THE STATUS CALL WAS SUCCESSFUL WITH AN ERROR AND WARNING LOGGED TO RHSM.LOG THAT CACHED STATUS WILL BE USED.

^^ THAT IS THE EXPECTED/TESTED BEHAVIOR THAT IS NOW FAILING AFTER UPGRADING TO RHEL69 VERSION OF RHSM PACKAGES AS I WILL CONTINUE TO DEMONSTRATE

UPGRADING RHSM PACKAGES...

[root@jsefler-rhel6server ~]# yum update --quiet --assumeyes subscription-manager* python-rhsm* --enablerepo=latest*
warning: /etc/rhsm/rhsm.conf created as /etc/rhsm/rhsm.conf.rpmnew
[root@jsefler-rhel6server ~]# 
[root@jsefler-rhel6server ~]# rpm -q subscription-manager python-rhsm
subscription-manager-1.18.9-1.el6.x86_64
python-rhsm-1.18.6-1.el6.x86_64

NOW LET'S RUN THE STATUS MODULE. (NOTICE THAT WE HAVE NOT CHANGED OUR RHSM CONFIGURATIONS NOR REGISTRATION)


[root@jsefler-rhel6server ~]# subscription-manager status
Proxy connection failed: 407

[root@jsefler-rhel6server ~]# tail -f /var/log/rhsm/rhsm.log
2017-02-03 16:09:33,524 [DEBUG] subscription-manager:23756:MainThread @connection.py:490 - Making request: GET /subscription/consumers/68aeb7c0-4e98-41ad-a35c-f4a2ac36fbc2/compliance
2017-02-03 16:09:33,590 [ERROR] subscription-manager:23756:MainThread @managercli.py:177 - exception caught in subscription-manager
2017-02-03 16:09:33,590 [ERROR] subscription-manager:23756:MainThread @managercli.py:178 - Proxy connection failed: 407
Traceback (most recent call last):
  File "/usr/sbin/subscription-manager", line 85, in <module>
    sys.exit(abs(main() or 0))
  File "/usr/sbin/subscription-manager", line 76, in main
    return managercli.ManagerCLI().main()
  File "/usr/lib/python2.6/site-packages/subscription_manager/managercli.py", line 2768, in main
    return CLI.main(self)
  File "/usr/lib/python2.6/site-packages/subscription_manager/cli.py", line 160, in main
    return cmd.main()
  File "/usr/lib/python2.6/site-packages/subscription_manager/managercli.py", line 537, in main
    return_code = self._do_command()
  File "/usr/lib/python2.6/site-packages/subscription_manager/managercli.py", line 2725, in _do_command
    self.sorter = inj.require(inj.CERT_SORTER)
  File "/usr/lib/python2.6/site-packages/subscription_manager/injection.py", line 103, in require
    return FEATURES.require(feature, *args, **kwargs)
  File "/usr/lib/python2.6/site-packages/subscription_manager/injection.py", line 77, in require
    self.providers[feature] = provider()
  File "/usr/lib/python2.6/site-packages/subscription_manager/cert_sorter.py", line 325, in __init__
    super(CertSorter, self).__init__()
  File "/usr/lib/python2.6/site-packages/subscription_manager/cert_sorter.py", line 65, in __init__
    self.load()
  File "/usr/lib/python2.6/site-packages/subscription_manager/cert_sorter.py", line 111, in load
    self._parse_server_status()
  File "/usr/lib/python2.6/site-packages/subscription_manager/cert_sorter.py", line 130, in _parse_server_status
    status = self.get_compliance_status()
  File "/usr/lib/python2.6/site-packages/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/lib/python2.6/site-packages/subscription_manager/cache.py", line 197, in load_status
    self._sync_with_server(uep, uuid)
  File "/usr/lib/python2.6/site-packages/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 1012, in getCompliance
    return self.conn.request_get(method)
  File "/usr/lib64/python2.6/site-packages/rhsm/connection.py", line 623, in request_get
    return self._request("GET", method)
  File "/usr/lib64/python2.6/site-packages/rhsm/connection.py", line 510, in _request
    raise ProxyException(e)
ProxyException: Proxy connection failed: 407




Actual results:
   Proxy connection failed: 407

Expected results:
   Expected the status call to succeed with an ERROR and WARNING logged to rhsm.log like the behavior from the prior RHEL release.

Additional info:

Comment 1 Chris Snyder 2017-02-06 15:52:27 UTC

This is expected behaviour. The old cache behaviour was incorrect for use with the status module. As subscription-manager can not reach the server the actual status cannot be known.