975164 – subscription-manager refresh with --proxy is silently failing in rhsm.log

Bug 975164 - subscription-manager refresh with --proxy is silently failing in rhsm.log

Summary: subscription-manager refresh with --proxy is silently failing in rhsm.log

Keywords:
Status:	CLOSED CURRENTRELEASE
Alias:	None
Product:	Red Hat Enterprise Linux 5
Classification:	Red Hat
Component:	subscription-manager
Sub Component:
Version:	5.10
Hardware:	Unspecified
OS:	Unspecified
Priority:	unspecified
Severity:	unspecified
Target Milestone:	rc
Target Release:	---
Assignee:	Carter Kozak
QA Contact:	IDM QE LIST
Docs Contact:
URL:
Whiteboard:
Depends On:
Blocks:	rhsm-rhel510
TreeView+	depends on / blocked

Reported:	2013-06-17 18:12 UTC by John Sefler
Modified:	2014-09-15 00:08 UTC (History)
CC List:	4 users (show)
Fixed In Version:
Doc Type:	Bug Fix
Doc Text:
Clone Of:
Environment:
Last Closed:	2013-10-01 13:48:39 UTC
Target Upstream Version:
Embargoed:
Dependent Products:

Attachments	(Terms of Use)

Description John Sefler 2013-06-17 18:12:39 UTC

Description of problem:
subscription-manager refresh is silently failing with a traceback to the rhsm.log when an invalid proxy is specified via the command line or rhsm.conf.

Version-Release number of selected component (if applicable):
[root@jsefler-5 ~]# subscription-manager version
server type: Red Hat Subscription Management
subscription management server: 0.8.13-1
subscription-manager: 1.8.10-1.git.27.c1dbb63.el5
python-rhsm: 1.8.12-1.git.0.d747a65.el5


How reproducible:


Steps to Reproduce:
After successful registration...
[root@jsefler-5 ~]# subscription-manager refresh
All local data refreshed        <==============  THAT LOOKS GOOD
[root@jsefler-5 ~]# subscription-manager refresh --proxy=foobar
All local data refreshed        <==============  THAT IS WRONG
[root@jsefler-5 ~]# 


Expected Reults:
Network error, unable to connect to server.
Please see /var/log/rhsm/rhsm.log for more information.
[root@jsefler-5 ~]# echo $?
255


[root@jsefler-5 ~]# tail -f /var/log/rhsm/rhsm.log

2013-06-17 13:58:17,352 [DEBUG]  @identity.py:131 - Loading consumer info from identity certificates.
2013-06-17 13:58:17,359 [DEBUG]  @injection.py:49 - Registering provider for feature IDENTITY: <subscription_manager.identity.Identity object at 0x2b42c27e7690>
2013-06-17 13:58:17,360 [DEBUG]  @injection.py:49 - Registering provider for feature CERT_SORTER: <class 'subscription_manager.cert_sorter.CertSorter'>
2013-06-17 13:58:17,360 [DEBUG]  @injection.py:49 - Registering provider for feature PRODUCT_DATE_RANGE_CALCULATOR: <class 'subscription_manager.validity.ValidProductDateRangeCalculator'>
2013-06-17 13:58:17,360 [DEBUG]  @injection.py:49 - Registering provider for feature ENT_DIR: <class 'subscription_manager.certdirectory.EntitlementDirectory'>
2013-06-17 13:58:17,360 [DEBUG]  @injection.py:49 - Registering provider for feature PROD_DIR: <class 'subscription_manager.certdirectory.ProductDirectory'>
2013-06-17 13:58:17,360 [DEBUG]  @injection.py:49 - Registering provider for feature STATUS_CACHE: <class 'subscription_manager.cache.StatusCache'>
2013-06-17 13:58:17,360 [DEBUG]  @injection.py:49 - Registering provider for feature PROD_STATUS_CACHE: <class 'subscription_manager.cache.ProductStatusCache'>
2013-06-17 13:58:17,415 [DEBUG]  @injection.py:64 - Returning callable provider for feature ENT_DIR: <class 'subscription_manager.certdirectory.EntitlementDirectory'>
2013-06-17 13:58:17,415 [DEBUG]  @injection.py:64 - Returning callable provider for feature PROD_DIR: <class 'subscription_manager.certdirectory.ProductDirectory'>
2013-06-17 13:58:17,422 [DEBUG]  @plugins.py:451 - Not loading "dbus_event.DbusEventPlugin" plugin as it is disabled
2013-06-17 13:58:17,422 [DEBUG]  @plugins.py:651 - <class 'dbus_event.DbusEventPlugin'> was disabled via it's config: plugin_key: dbus_event.DbusEventPlugin
config file: /etc/rhsm/pluginconf.d/dbus_event.DbusEventPlugin.conf
[main]
enabled=0

2013-06-17 13:58:17,424 [DEBUG]  @plugins.py:541 - loaded plugin modules: [<module 'all_slots_test' from '/usr/share/rhsm-plugins/all_slots_test.pyc'>, <module 'auto_attach_test' from '/usr/share/rhsm-plugins/auto_attach_test.pyc'>, <module 'dbus_event' from '/usr/share/rhsm-plugins/dbus_event.pyc'>, <module 'facts_collection_test' from '/usr/share/rhsm-plugins/facts_collection_test.pyc'>, <module 'product_id_install_test' from '/usr/share/rhsm-plugins/product_id_install_test.pyc'>, <module 'register_consumer_test1' from '/usr/share/rhsm-plugins/register_consumer_test1.pyc'>, <module 'register_consumer_test2' from '/usr/share/rhsm-plugins/register_consumer_test2.pyc'>, <module 'subscribe_test' from '/usr/share/rhsm-plugins/subscribe_test.pyc'>]
2013-06-17 13:58:17,425 [DEBUG]  @plugins.py:542 - loaded plugins: {'register_consumer_test2.RegisterConsumerTestPlugin': <register_consumer_test2.RegisterConsumerTestPlugin object at 0xee86510>, 'subscribe_test.SubscribeTestPlugin': <subscribe_test.SubscribeTestPlugin object at 0xee86850>, 'all_slots_test.AllSlotsTestPlugin': <all_slots_test.AllSlotsTestPlugin object at 0xee7cd10>, 'product_id_install_test.ProductIdInstallTestPlugin': <product_id_install_test.ProductIdInstallTestPlugin object at 0xee82e50>, 'auto_attach_test.AutoAttachTestPlugin': <auto_attach_test.AutoAttachTestPlugin object at 0xee82310>, 'register_consumer_test1.RegisterConsumerTestPlugin': <register_consumer_test1.RegisterConsumerTestPlugin object at 0xee861d0>, 'facts_collection_test.FactsCollectionTestPlugin': <facts_collection_test.FactsCollectionTestPlugin object at 0xee82b10>}
2013-06-17 13:58:17,425 [DEBUG]  @plugins.py:514 - Calling PluginManager init
2013-06-17 13:58:17,456 [DEBUG]  @injection.py:64 - Returning callable provider for feature ENT_DIR: <class 'subscription_manager.certdirectory.EntitlementDirectory'>
2013-06-17 13:58:17,457 [DEBUG]  @injection.py:64 - Returning callable provider for feature PROD_DIR: <class 'subscription_manager.certdirectory.ProductDirectory'>
2013-06-17 13:58:17,458 [DEBUG]  @injection.py:64 - Returning callable provider for feature ENT_DIR: <class 'subscription_manager.certdirectory.EntitlementDirectory'>
2013-06-17 13:58:17,458 [DEBUG]  @injection.py:64 - Returning callable provider for feature PROD_DIR: <class 'subscription_manager.certdirectory.ProductDirectory'>
2013-06-17 13:58:17,474 [DEBUG]  @injection.py:64 - Returning callable provider for feature ENT_DIR: <class 'subscription_manager.certdirectory.EntitlementDirectory'>
2013-06-17 13:58:17,474 [DEBUG]  @injection.py:64 - Returning callable provider for feature PROD_DIR: <class 'subscription_manager.certdirectory.ProductDirectory'>
2013-06-17 13:58:17,477 [DEBUG]  @injection.py:64 - Returning callable provider for feature ENT_DIR: <class 'subscription_manager.certdirectory.EntitlementDirectory'>
2013-06-17 13:58:17,477 [DEBUG]  @injection.py:64 - Returning callable provider for feature PROD_DIR: <class 'subscription_manager.certdirectory.ProductDirectory'>
2013-06-17 13:58:17,480 [DEBUG]  @injection.py:64 - Returning callable provider for feature ENT_DIR: <class 'subscription_manager.certdirectory.EntitlementDirectory'>
2013-06-17 13:58:17,480 [DEBUG]  @injection.py:64 - Returning callable provider for feature PROD_DIR: <class 'subscription_manager.certdirectory.ProductDirectory'>
2013-06-17 13:58:17,482 [DEBUG]  @injection.py:64 - Returning callable provider for feature ENT_DIR: <class 'subscription_manager.certdirectory.EntitlementDirectory'>
2013-06-17 13:58:17,482 [DEBUG]  @injection.py:64 - Returning callable provider for feature PROD_DIR: <class 'subscription_manager.certdirectory.ProductDirectory'>
2013-06-17 13:58:17,485 [DEBUG]  @injection.py:64 - Returning callable provider for feature ENT_DIR: <class 'subscription_manager.certdirectory.EntitlementDirectory'>
2013-06-17 13:58:17,485 [DEBUG]  @injection.py:64 - Returning callable provider for feature PROD_DIR: <class 'subscription_manager.certdirectory.ProductDirectory'>
2013-06-17 13:58:17,487 [DEBUG]  @injection.py:64 - Returning callable provider for feature ENT_DIR: <class 'subscription_manager.certdirectory.EntitlementDirectory'>
2013-06-17 13:58:17,487 [DEBUG]  @injection.py:64 - Returning callable provider for feature PROD_DIR: <class 'subscription_manager.certdirectory.ProductDirectory'>
2013-06-17 13:58:17,490 [DEBUG]  @injection.py:64 - Returning callable provider for feature ENT_DIR: <class 'subscription_manager.certdirectory.EntitlementDirectory'>
2013-06-17 13:58:17,490 [DEBUG]  @injection.py:64 - Returning callable provider for feature PROD_DIR: <class 'subscription_manager.certdirectory.ProductDirectory'>
2013-06-17 13:58:17,491 [DEBUG]  @injection.py:64 - Returning callable provider for feature ENT_DIR: <class 'subscription_manager.certdirectory.EntitlementDirectory'>
2013-06-17 13:58:17,492 [DEBUG]  @injection.py:64 - Returning callable provider for feature PROD_DIR: <class 'subscription_manager.certdirectory.ProductDirectory'>
2013-06-17 13:58:17,493 [DEBUG]  @injection.py:64 - Returning callable provider for feature ENT_DIR: <class 'subscription_manager.certdirectory.EntitlementDirectory'>
2013-06-17 13:58:17,494 [DEBUG]  @injection.py:64 - Returning callable provider for feature PROD_DIR: <class 'subscription_manager.certdirectory.ProductDirectory'>
2013-06-17 13:58:17,496 [DEBUG]  @injection.py:64 - Returning callable provider for feature ENT_DIR: <class 'subscription_manager.certdirectory.EntitlementDirectory'>
2013-06-17 13:58:17,496 [DEBUG]  @injection.py:64 - Returning callable provider for feature PROD_DIR: <class 'subscription_manager.certdirectory.ProductDirectory'>
2013-06-17 13:58:17,498 [DEBUG]  @injection.py:64 - Returning callable provider for feature ENT_DIR: <class 'subscription_manager.certdirectory.EntitlementDirectory'>
2013-06-17 13:58:17,499 [DEBUG]  @injection.py:64 - Returning callable provider for feature PROD_DIR: <class 'subscription_manager.certdirectory.ProductDirectory'>
2013-06-17 13:58:17,501 [DEBUG]  @injection.py:64 - Returning callable provider for feature ENT_DIR: <class 'subscription_manager.certdirectory.EntitlementDirectory'>
2013-06-17 13:58:17,501 [DEBUG]  @injection.py:64 - Returning callable provider for feature PROD_DIR: <class 'subscription_manager.certdirectory.ProductDirectory'>
2013-06-17 13:58:17,503 [DEBUG]  @injection.py:64 - Returning callable provider for feature ENT_DIR: <class 'subscription_manager.certdirectory.EntitlementDirectory'>
2013-06-17 13:58:17,503 [DEBUG]  @injection.py:64 - Returning callable provider for feature PROD_DIR: <class 'subscription_manager.certdirectory.ProductDirectory'>
2013-06-17 13:58:17,505 [DEBUG]  @injection.py:64 - Returning callable provider for feature ENT_DIR: <class 'subscription_manager.certdirectory.EntitlementDirectory'>
2013-06-17 13:58:17,506 [DEBUG]  @injection.py:64 - Returning callable provider for feature PROD_DIR: <class 'subscription_manager.certdirectory.ProductDirectory'>
2013-06-17 13:58:17,508 [DEBUG]  @injection.py:64 - Returning callable provider for feature ENT_DIR: <class 'subscription_manager.certdirectory.EntitlementDirectory'>
2013-06-17 13:58:17,508 [DEBUG]  @injection.py:64 - Returning callable provider for feature PROD_DIR: <class 'subscription_manager.certdirectory.ProductDirectory'>
2013-06-17 13:58:17,510 [DEBUG]  @injection.py:64 - Returning callable provider for feature ENT_DIR: <class 'subscription_manager.certdirectory.EntitlementDirectory'>
2013-06-17 13:58:17,511 [DEBUG]  @injection.py:64 - Returning callable provider for feature PROD_DIR: <class 'subscription_manager.certdirectory.ProductDirectory'>
2013-06-17 13:58:17,512 [DEBUG]  @injection.py:64 - Returning callable provider for feature ENT_DIR: <class 'subscription_manager.certdirectory.EntitlementDirectory'>
2013-06-17 13:58:17,513 [DEBUG]  @injection.py:64 - Returning callable provider for feature PROD_DIR: <class 'subscription_manager.certdirectory.ProductDirectory'>
2013-06-17 13:58:17,515 [DEBUG]  @injection.py:64 - Returning callable provider for feature ENT_DIR: <class 'subscription_manager.certdirectory.EntitlementDirectory'>
2013-06-17 13:58:17,515 [DEBUG]  @injection.py:64 - Returning callable provider for feature PROD_DIR: <class 'subscription_manager.certdirectory.ProductDirectory'>
2013-06-17 13:58:17,517 [DEBUG]  @injection.py:64 - Returning callable provider for feature ENT_DIR: <class 'subscription_manager.certdirectory.EntitlementDirectory'>
2013-06-17 13:58:17,517 [DEBUG]  @injection.py:64 - Returning callable provider for feature PROD_DIR: <class 'subscription_manager.certdirectory.ProductDirectory'>
2013-06-17 13:58:17,520 [DEBUG]  @profile.py:96 - Loading current RPM profile.
2013-06-17 13:58:17,671 [INFO]  @managercli.py:309 - Client Versions: {'python-rhsm': '1.8.12-1.git.0.d747a65.el5', 'subscription-manager': '1.8.10-1.git.27.c1dbb63.el5'}
2013-06-17 13:58:17,673 [INFO]  @connection.py:583 - Using certificate authentication: key = /etc/pki/consumer/key.pem, cert = /etc/pki/consumer/cert.pem, ca = /etc/rhsm/ca/, insecure = False
2013-06-17 13:58:17,673 [INFO]  @connection.py:596 - Connection Built: host: jsefler-f14-candlepin.usersys.redhat.com, port: 8443, handler: /candlepin
2013-06-17 13:58:17,673 [INFO]  @connection.py:593 - Using no auth
2013-06-17 13:58:17,674 [INFO]  @connection.py:596 - Connection Built: host: jsefler-f14-candlepin.usersys.redhat.com, port: 8443, handler: /candlepin
2013-06-17 13:58:17,770 [DEBUG]  @connection.py:394 - Loading CA PEM certificates from: /etc/rhsm/ca/
2013-06-17 13:58:17,770 [DEBUG]  @connection.py:376 - Loading CA certificate: '/etc/rhsm/ca/candlepin-stage.pem'
2013-06-17 13:58:17,771 [DEBUG]  @connection.py:376 - Loading CA certificate: '/etc/rhsm/ca/redhat-uep.pem'
2013-06-17 13:58:17,771 [DEBUG]  @connection.py:376 - Loading CA certificate: '/etc/rhsm/ca/jsefler-f14-5candlepin.pem'
2013-06-17 13:58:17,772 [DEBUG]  @connection.py:376 - Loading CA certificate: '/etc/rhsm/ca/jsefler-f14-7candlepin.pem'
2013-06-17 13:58:17,772 [DEBUG]  @connection.py:376 - Loading CA certificate: '/etc/rhsm/ca/jsefler-f14-candlepin.pem'
2013-06-17 13:58:17,772 [DEBUG]  @connection.py:400 - Using proxy: foobar:3128
2013-06-17 13:58:17,772 [DEBUG]  @connection.py:415 - Making request: GET https://jsefler-f14-candlepin.usersys.redhat.com:8443/candlepin/
2013-06-17 13:58:17,777 [ERROR]  @utils.py:350 - Error while checking server version: (-2, 'Name or service not known')
2013-06-17 13:58:17,778 [ERROR]  @utils.py:352 - (-2, 'Name or service not known')
Traceback (most recent call last):
  File "/usr/share/rhsm/subscription_manager/utils.py", line 340, in get_server_versions
    if cp.supports_resource("status"):
  File "/usr/lib64/python2.4/site-packages/rhsm/connection.py", line 623, in supports_resource
    self._load_supported_resources()
  File "/usr/lib64/python2.4/site-packages/rhsm/connection.py", line 610, in _load_supported_resources
    resources_list = self.conn.request_get("/")
  File "/usr/lib64/python2.4/site-packages/rhsm/connection.py", line 481, in request_get
    return self._request("GET", method)
  File "/usr/lib64/python2.4/site-packages/rhsm/connection.py", line 422, in _request
    conn.request(request_type, handler, body=body, headers=headers)
  File "/usr/lib64/python2.4/httplib.py", line 810, in request
    self._send_request(method, url, body, headers)
  File "/usr/lib64/python2.4/httplib.py", line 833, in _send_request
    self.endheaders()
  File "/usr/lib64/python2.4/site-packages/rhsm/connection.py", line 174, in endheaders
    httpslib.HTTPSConnection.endheaders(self)
  File "/usr/lib64/python2.4/httplib.py", line 804, in endheaders
    self._send_output()
  File "/usr/lib64/python2.4/httplib.py", line 685, in _send_output
    self.send(msg)
  File "/usr/lib64/python2.4/httplib.py", line 652, in send
    self.connect()
  File "/usr/lib64/python2.4/site-packages/M2Crypto/httpslib.py", line 175, in connect
    HTTPConnection.connect(self)
  File "/usr/lib64/python2.4/httplib.py", line 620, in connect
    socket.SOCK_STREAM):
gaierror: (-2, 'Name or service not known')
2013-06-17 13:58:17,785 [INFO]  @managercli.py:320 - Server Versions: {'candlepin': 'Unknown', 'server-type': 'Red Hat Subscription Management'}
2013-06-17 13:58:17,793 [DEBUG]  @connection.py:394 - Loading CA PEM certificates from: /etc/rhsm/ca/
2013-06-17 13:58:17,793 [DEBUG]  @connection.py:376 - Loading CA certificate: '/etc/rhsm/ca/candlepin-stage.pem'
2013-06-17 13:58:17,793 [DEBUG]  @connection.py:376 - Loading CA certificate: '/etc/rhsm/ca/redhat-uep.pem'
2013-06-17 13:58:17,794 [DEBUG]  @connection.py:376 - Loading CA certificate: '/etc/rhsm/ca/jsefler-f14-5candlepin.pem'
2013-06-17 13:58:17,794 [DEBUG]  @connection.py:376 - Loading CA certificate: '/etc/rhsm/ca/jsefler-f14-7candlepin.pem'
2013-06-17 13:58:17,795 [DEBUG]  @connection.py:376 - Loading CA certificate: '/etc/rhsm/ca/jsefler-f14-candlepin.pem'
2013-06-17 13:58:17,795 [DEBUG]  @connection.py:400 - Using proxy: foobar:3128
2013-06-17 13:58:17,795 [DEBUG]  @connection.py:415 - Making request: GET https://jsefler-f14-candlepin.usersys.redhat.com:8443/candlepin/consumers/40bf216a-43b0-4088-98c5-1a8daa40ff20/certificates/serials
2013-06-17 13:58:17,797 [ERROR]  @certlib.py:241 - (-2, 'Name or service not known')
Traceback (most recent call last):
  File "/usr/share/rhsm/subscription_manager/certlib.py", line 239, in perform
    expected = self._get_expected_serials(report)
  File "/usr/share/rhsm/subscription_manager/certlib.py", line 318, in _get_expected_serials
    exp = self.get_certificate_serials_list()
  File "/usr/share/rhsm/subscription_manager/certlib.py", line 311, in get_certificate_serials_list
    reply = self.uep.getCertificateSerials(self._get_consumer_id())
  File "/usr/lib64/python2.4/site-packages/rhsm/connection.py", line 811, in getCertificateSerials
    return self.conn.request_get(method)
  File "/usr/lib64/python2.4/site-packages/rhsm/connection.py", line 481, in request_get
    return self._request("GET", method)
  File "/usr/lib64/python2.4/site-packages/rhsm/connection.py", line 422, in _request
    conn.request(request_type, handler, body=body, headers=headers)
  File "/usr/lib64/python2.4/httplib.py", line 810, in request
    self._send_request(method, url, body, headers)
  File "/usr/lib64/python2.4/httplib.py", line 833, in _send_request
    self.endheaders()
  File "/usr/lib64/python2.4/site-packages/rhsm/connection.py", line 174, in endheaders
    httpslib.HTTPSConnection.endheaders(self)
  File "/usr/lib64/python2.4/httplib.py", line 804, in endheaders
    self._send_output()
  File "/usr/lib64/python2.4/httplib.py", line 685, in _send_output
    self.send(msg)
  File "/usr/lib64/python2.4/httplib.py", line 652, in send
    self.connect()
  File "/usr/lib64/python2.4/site-packages/M2Crypto/httpslib.py", line 175, in connect
    HTTPConnection.connect(self)
  File "/usr/lib64/python2.4/httplib.py", line 620, in connect
    socket.SOCK_STREAM):
gaierror: (-2, 'Name or service not known')
2013-06-17 13:58:17,798 [ERROR]  @certlib.py:242 - Cannot detach subscriptions while disconnected
2013-06-17 13:58:17,799 [INFO]  @managercli.py:605 - Refreshed local data

Comment 2 Carter Kozak 2013-06-17 21:21:41 UTC

commit 7f8fa13145e6475bca4600b2cc30576bbf1a0d82
Author: ckozak <ckozak>
Date:   Mon Jun 17 16:55:10 2013 -0400

    975164: 975186: fix certlib exception handling

Comment 4 Shwetha Kallesh 2013-07-15 07:16:20 UTC

[root@localhost ~]# subscription-manager version
server type: Red Hat Subscription Management
subscription management server: 0.8.16-1
subscription-manager: 1.8.13-1.el5
python-rhsm: 1.8.13-1.git.0.85d7af5.el5


[root@localhost ~]# subscription-manager refresh
All local data refreshed

[root@localhost ~]# subscription-manager refresh --proxy=foobar
Network error, unable to connect to server.
Please see /var/log/rhsm/rhsm.log for more information.

[root@localhost ~]# tail -f /var/log/rhsm/rhsm.log
Traceback (most recent call last):
  File "/usr/share/rhsm/subscription_manager/managercli.py", line 574, in _do_command
    self.certlib.update()
  File "/usr/share/rhsm/subscription_manager/certlib.py", line 68, in update
    return self._do_update()
  File "/usr/share/rhsm/subscription_manager/certlib.py", line 91, in _do_update
    return action.perform()
  File "/usr/share/rhsm/subscription_manager/certlib.py", line 238, in perform
    raise Disconnected()
Disconnected

[root@localhost ~]# echo $?
130

Note You need to log in before you can comment on or make changes to this bug.