Bug 1008603

Summary: Subscription-manager should not require connectivity to list products
Product: Red Hat Enterprise Linux 6 Reporter: Ina Panova <ipanova>
Component: subscription-managerAssignee: Carter Kozak <ckozak>
Status: CLOSED ERRATA QA Contact: John Sefler <jsefler>
Severity: unspecified Docs Contact:
Priority: unspecified    
Version: 6.5CC: bkearney, ckozak, ipanova, jesusr
Target Milestone: rc   
Target Release: 6.5   
Hardware: Unspecified   
OS: Linux   
Whiteboard:
Fixed In Version: Doc Type: Bug Fix
Doc Text:
Cause: Subscription-manager requires connectivity to redhat.com to list products, meanwhile this information should be stored locally on the filesystem. Consequence: Products not displayed because connection fails. Fix: Catch and log connection error while updating installed products Result:
 Story Points: ---
Clone Of: Environment:
Last Closed: 2013-11-21 21:29:26 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:
Bug Depends On:    
Bug Blocks: 862910    
Attachments:
Description Flags
rhsm.conf_59
none
rhsm.conf_5.10
none
rhsm.log_59
none
rhsm.log_510 none

Description Ina Panova 2013-09-16 16:39:10 UTC 
Description of problem:
in rhel5.10 Subscription-manager requires connectivity to subscription.rhn.stage.redhat.com to list products,meanwhile this information should be stored locally on the filesystem.

Version-Release number of selected component (if applicable):
subscription-manager-1.8.22-1.el5

How reproducible:
always

Steps to Reproduce:
1.subscription-manager list
2.
3.

Actual results:

Network error, unable to connect to server.
Please see /var/log/rhsm/rhsm.log for more information.


Expected results:
Should not require connectivity and list products from local cache.

Additional info:
Comment 1 Carter Kozak 2013-09-16 17:15:27 UTC 
Did you delete /var/lib/rhsm/cache/installed_products.json?
Comment 2 Ina Panova 2013-09-16 21:23:17 UTC 
I have not deleted it but nevertheless I do not see any json file in the mentioned path. I've checked for the presence of this file in other versions of rhel and I do not see it as well, however I manage to perform 'subscription-manager list' command normally.
Comment 3 John Sefler 2013-09-16 21:40:44 UTC 
To help us reproduce this error, please tell us what steps you are taking to get to this error.
Are you upgrading from a former release using RHN classic channels, or using RHSM entitlements to upgrade?
Are you registered using RHSM?
Were you registered to RHSM before you hit this error?
Are you changing the rhsm.conf file during this scenario?
What is in your /etc/rhsm/rhsm.conf file ?
What is in your /var/log/rhsm/rhsm.log ?
What is the scenario by which you are getting to this error?


The subscription-manager list command works for me...

[root@jsefler-5 ~]# rpm -q subscription-manager
subscription-manager-1.8.22-1.el5
[root@jsefler-5 ~]# cat  /var/lib/rhsm/cache/installed_products.json
cat: /var/lib/rhsm/cache/installed_products.json: No such file or directory
[root@jsefler-5 ~]# subscription-manager list
+-------------------------------------------+
    Installed Product Status
+-------------------------------------------+
Product Name:   Red Hat Enterprise Linux Server
Product ID:     69
Version:        5.10
Arch:           x86_64
Status:         Unknown
Status Details: 
Starts:         
Ends:
Comment 4 Ina Panova 2013-09-17 14:23:35 UTC 
Created attachment 798838 [details]
rhsm.conf_59
Comment 5 Ina Panova 2013-09-17 14:26:27 UTC 
Created attachment 798840 [details]
rhsm.conf_5.10
Comment 6 Ina Panova 2013-09-17 14:27:11 UTC 
Created attachment 798842 [details]
rhsm.log_59
Comment 7 Ina Panova 2013-09-17 14:27:47 UTC 
Created attachment 798843 [details]
rhsm.log_510
Comment 8 Ina Panova 2013-09-17 14:29:40 UTC 
>Are you upgrading from a former release using RHN classic channels, or using RHSM entitlements to upgrade?
No

>Are you registered using RHSM? 
No

>Were you registered to RHSM before you hit this error? 
No

>Are you changing the rhsm.conf file during this scenario? 
Yes

>What is in your /etc/rhsm/rhsm.conf file ?
>What is in your /var/log/rhsm/rhsm.log ?
See attachments please for logs and rhsm.conf

>What is the scenario by which you are getting to this error?
I'm installing rhel5.9/5.10. the only thing I'm doing is changing the hostname in rhsm.conf(see in attachments), then I perform these:

(This is rhel 5.9)
[root@ip-10-3-94-102 ~]# rpm -q subscription-manager
subscription-manager-1.0.24-1.el5
[root@ip-10-3-94-102 ~]# subscription-manager list
No installed products to list
[root@ip-10-3-94-102 ~]# 
[root@ip-10-3-94-102 ~]# ll /var/lib/rhsm/cache/
total 0
[root@ip-10-3-94-102 ~]# ll /etc/pki/product/
total 0


(This is 5.10)
[root@ip-10-3-94-112 ~]# rpm -q subscription-manager
subscription-manager-1.8.22-1.el5
[root@ip-10-3-94-112 ~]# subscription-manager list
Network error, unable to connect to server.
Please see /var/log/rhsm/rhsm.log for more information.
[root@ip-10-3-94-112 ~]# 
[root@ip-10-3-94-112 ~]# ll /var/lib/rhsm/cache/
total 0
[root@ip-10-3-94-112 ~]# ll /etc/pki/product/
total 0


As you can see subscription-manager in rhel5.9 is able to list products(I mean perform 'subscription-manager list') without any error(as we have in 5.10) and without external api call.
Comment 9 Carter Kozak 2013-09-17 14:33:07 UTC 
Do you have a certificate in /etc/pki/consumer?
Comment 10 Ina Panova 2013-09-17 14:59:41 UTC 
No, I do not see any certificates

[root@ip-10-3-94-112 ~]# ll /etc/pki/
total 56
drwx------ 3 root root 4096 Sep 10 15:51 CA
drwxr-xr-x 3 root root 4096 Sep 10 15:54 entitlement
drwxr-xr-x 2 root root 4096 Sep 10 15:51 nssdb
drwxr-xr-x 2 root root 4096 Sep 17 07:57 product
drwxr-xr-x 2 root root 4096 Sep 10 15:51 rpm-gpg
drwx------ 2 root root 4096 Dec  1  2011 rsyslog
drwxr-xr-x 5 root root 4096 Sep 10 15:51 tls
Comment 11 Carter Kozak 2013-09-19 18:52:11 UTC 
commit 9a1977deae8d63eeb18d56cb23808116b890584d
Author: ckozak <ckozak>
Date:   Mon Sep 16 13:10:21 2013 -0400

    1008603: Catch and log connection error while updating installed products
Comment 14 John Sefler 2013-10-08 20:55:55 UTC 
Verifying Version...
[root@jsefler-6 ~]# rpm -q subscription-manager
subscription-manager-1.9.9-1.el6.x86_64


Let's look at the comment 11 commit to determine what was fixed...
------------------- src/subscription_manager/cert_sorter.py -------------------
index 3ed82ee..66e0a05 100644
@@ -27,7 +27,6 @@ from subscription_manager.cache import InstalledProductsManager
 from subscription_manager import rhelentbranding
 from subscription_manager.identity import ConsumerIdentity
 from subscription_manager import file_monitor
-from rhsm.connection import RestlibException
 
 import gettext
 _ = gettext.gettext
@@ -338,9 +337,9 @@ class CertSorter(ComplianceManager):
         if self.is_registered():
             try:
                 self.installed_mgr.update_check(inj.require(inj.CP_PROVIDER).get_consumer_auth_cp(), inj.require(inj.IDENTITY).uuid)
-            except RestlibException:
-                # Invalid consumer certificate
-                pass
+            except Exception, e:
+                log.debug("Failed to sync installed products with the server")
+                log.debug(e)
 
     def force_cert_check(self):
         self.identity_monitor.run_check()


It appears that the original bug was not being caught when there was no /var/lib/rhsm/cache/.  As a result, the top level try block would catch a general exception and print it as a Network error.  To test the change, let's register a system and the disconnect it from the network and forcible rmove the cache.  Then list --installed should no longer fail, but instead log a traceback to rhsm.log.



[root@jsefler-6 ~]# subscription-manager register --auto-attach
Username: stage_test_12
Password: 
The system has been registered with ID: 52f2120e-fa97-4549-8aaf-3c9740eed296 
Installed Product Current Status:
Product Name: Red Hat Enterprise Linux Server
Status:       Subscribed

[root@jsefler-6 ~]# subscription-manager list --installed
+-------------------------------------------+
    Installed Product Status
+-------------------------------------------+
Product Name:   Red Hat Enterprise Linux Server
Product ID:     69
Version:        6.5
Arch:           x86_64
Status:         Subscribed
Status Details: 
Starts:         12/31/2012
Ends:           12/31/2013

[root@jsefler-6 ~]# ip link show
1: lo: <LOOPBACK,UP,LOWER_UP> mtu 16436 qdisc noqueue state UNKNOWN 
    link/loopback 00:00:00:00:00:00 brd 00:00:00:00:00:00
2: eth0: <BROADCAST,MULTICAST,UP,LOWER_UP> mtu 1500 qdisc pfifo_fast state UP qlen 1000
    link/ether 52:54:00:16:9b:ef brd ff:ff:ff:ff:ff:ff
[root@jsefler-6 ~]# ifconfig eth0 down
[root@jsefler-6 ~]# rm -rf /var/lib/rhsm/cache/*
[root@jsefler-6 ~]# subscription-manager list --installed
+-------------------------------------------+
    Installed Product Status
+-------------------------------------------+
Product Name:   Red Hat Enterprise Linux Server
Product ID:     69
Version:        6.5
Arch:           x86_64
Status:         Unknown
Status Details: 
Starts:         
Ends:           

[root@jsefler-6 ~]#




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

2013-10-08 16:40:32,899 [DEBUG]  @plugins.py:519 - loaded plugin modules: []
2013-10-08 16:40:32,899 [DEBUG]  @plugins.py:520 - loaded plugins: {}
2013-10-08 16:40:32,943 [DEBUG]  @identity.py:130 - Loading consumer info from identity certificates.
2013-10-08 16:40:32,954 [DEBUG]  @profile.py:96 - Loading current RPM profile.
2013-10-08 16:40:33,188 [INFO]  @managercli.py:295 - Client Versions: {'python-rhsm': '1.9.6-1.el6', 'subscription-manager': '1.9.9-1.el6'}
2013-10-08 16:40:33,189 [INFO]  @connection.py:646 - Using certificate authentication: key = /etc/pki/consumer/key.pem, cert = /etc/pki/consumer/cert.pem, ca = /etc/rhsm/ca/, insecure = False
2013-10-08 16:40:33,189 [INFO]  @connection.py:657 - Connection Built: host: subscription.rhn.stage.redhat.com, port: 443, handler: /subscription
2013-10-08 16:40:33,190 [INFO]  @connection.py:653 - Using no auth
2013-10-08 16:40:33,190 [INFO]  @connection.py:657 - Connection Built: host: subscription.rhn.stage.redhat.com, port: 443, handler: /subscription
2013-10-08 16:40:33,254 [DEBUG]  @connection.py:420 - Loading CA PEM certificates from: /etc/rhsm/ca/
2013-10-08 16:40:33,255 [DEBUG]  @connection.py:402 - Loading CA certificate: '/etc/rhsm/ca/jsefler-f14-candlepin.pem'
2013-10-08 16:40:33,255 [DEBUG]  @connection.py:402 - Loading CA certificate: '/etc/rhsm/ca/candlepin-stage.pem'
2013-10-08 16:40:33,256 [DEBUG]  @connection.py:402 - Loading CA certificate: '/etc/rhsm/ca/redhat-uep.pem'
2013-10-08 16:40:33,257 [DEBUG]  @connection.py:441 - Making request: GET /subscription/
2013-10-08 16:40:33,258 [ERROR]  @utils.py:361 - Error while checking server version: [Errno -2] Name or service not known
2013-10-08 16:40:33,258 [ERROR]  @utils.py:363 - [Errno -2] Name or service not known
Traceback (most recent call last):
  File "/usr/share/rhsm/subscription_manager/utils.py", line 341, in get_server_versions
    if cp.supports_resource("status"):
  File "/usr/lib64/python2.6/site-packages/rhsm/connection.py", line 683, in supports_resource
    self._load_supported_resources()
  File "/usr/lib64/python2.6/site-packages/rhsm/connection.py", line 670, in _load_supported_resources
    resources_list = self.conn.request_get("/")
  File "/usr/lib64/python2.6/site-packages/rhsm/connection.py", line 541, in request_get
    return self._request("GET", method)
  File "/usr/lib64/python2.6/site-packages/rhsm/connection.py", line 448, in _request
    conn.request(request_type, handler, body=body, headers=headers)
  File "/usr/lib64/python2.6/httplib.py", line 914, in request
    self._send_request(method, url, body, headers)
  File "/usr/lib64/python2.6/httplib.py", line 951, in _send_request
    self.endheaders()
  File "/usr/lib64/python2.6/httplib.py", line 908, in endheaders
    self._send_output()
  File "/usr/lib64/python2.6/httplib.py", line 780, in _send_output
    self.send(msg)
  File "/usr/lib64/python2.6/httplib.py", line 739, in send
    self.connect()
  File "/usr/lib64/python2.6/site-packages/M2Crypto/httpslib.py", line 51, in connect
    socket.getaddrinfo(self.host, self.port, 0, socket.SOCK_STREAM):
gaierror: [Errno -2] Name or service not known
2013-10-08 16:40:33,260 [INFO]  @managercli.py:306 - Server Versions: {'candlepin': 'Unknown', 'server-type': 'Red Hat Subscription Management'}
2013-10-08 16:40:33,261 [INFO]  @cache.py:168 - Checking current system info against cache: /var/lib/rhsm/cache/installed_products.json
2013-10-08 16:40:33,262 [INFO]  @cache.py:398 - Cache does not exist
2013-10-08 16:40:33,263 [INFO]  @cache.py:170 - System data has changed, updating server.
2013-10-08 16:40:33,263 [DEBUG]  @connection.py:420 - Loading CA PEM certificates from: /etc/rhsm/ca/
2013-10-08 16:40:33,264 [DEBUG]  @connection.py:402 - Loading CA certificate: '/etc/rhsm/ca/jsefler-f14-candlepin.pem'
2013-10-08 16:40:33,264 [DEBUG]  @connection.py:402 - Loading CA certificate: '/etc/rhsm/ca/candlepin-stage.pem'
2013-10-08 16:40:33,264 [DEBUG]  @connection.py:402 - Loading CA certificate: '/etc/rhsm/ca/redhat-uep.pem'
2013-10-08 16:40:33,265 [DEBUG]  @connection.py:441 - Making request: PUT /subscription/consumers/52f2120e-fa97-4549-8aaf-3c9740eed296
2013-10-08 16:40:33,266 [ERROR]  @cache.py:180 - Error updating system data on the server
2013-10-08 16:40:33,266 [ERROR]  @cache.py:181 - [Errno -2] Name or service not known
Traceback (most recent call last):
  File "/usr/share/rhsm/subscription_manager/cache.py", line 172, in update_check
    self._sync_with_server(uep, consumer_uuid)
  File "/usr/share/rhsm/subscription_manager/cache.py", line 421, in _sync_with_server
    installed_products=self.format_for_server())
  File "/usr/lib64/python2.6/site-packages/rhsm/connection.py", line 777, in updateConsumer
    ret = self.conn.request_put(method, params)
  File "/usr/lib64/python2.6/site-packages/rhsm/connection.py", line 550, in request_put
    return self._request("PUT", method, params)
  File "/usr/lib64/python2.6/site-packages/rhsm/connection.py", line 448, in _request
    conn.request(request_type, handler, body=body, headers=headers)
  File "/usr/lib64/python2.6/httplib.py", line 914, in request
    self._send_request(method, url, body, headers)
  File "/usr/lib64/python2.6/httplib.py", line 951, in _send_request
    self.endheaders()
  File "/usr/lib64/python2.6/httplib.py", line 908, in endheaders
    self._send_output()
  File "/usr/lib64/python2.6/httplib.py", line 780, in _send_output
    self.send(msg)
  File "/usr/lib64/python2.6/httplib.py", line 739, in send
    self.connect()
  File "/usr/lib64/python2.6/site-packages/M2Crypto/httpslib.py", line 51, in connect
    socket.getaddrinfo(self.host, self.port, 0, socket.SOCK_STREAM):
gaierror: [Errno -2] Name or service not known
2013-10-08 16:40:33,267 [DEBUG]  @cert_sorter.py:340 - Failed to sync installed products with the server
2013-10-08 16:40:33,267 [DEBUG]  @cert_sorter.py:341 - Error updating system data on the server, see /var/log/rhsm/rhsm.log for more details.
2013-10-08 16:40:33,267 [DEBUG]  @certdirectory.py:204 - Installed product IDs: ['69']
2013-10-08 16:40:33,268 [DEBUG]  @connection.py:420 - Loading CA PEM certificates from: /etc/rhsm/ca/
2013-10-08 16:40:33,268 [DEBUG]  @connection.py:402 - Loading CA certificate: '/etc/rhsm/ca/jsefler-f14-candlepin.pem'
2013-10-08 16:40:33,269 [DEBUG]  @connection.py:402 - Loading CA certificate: '/etc/rhsm/ca/candlepin-stage.pem'
2013-10-08 16:40:33,269 [DEBUG]  @connection.py:402 - Loading CA certificate: '/etc/rhsm/ca/redhat-uep.pem'
2013-10-08 16:40:33,270 [DEBUG]  @connection.py:441 - Making request: GET /subscription/consumers/52f2120e-fa97-4549-8aaf-3c9740eed296/compliance
2013-10-08 16:40:33,270 [ERROR]  @cache.py:232 - [Errno -2] Name or service not known
Traceback (most recent call last):
  File "/usr/share/rhsm/subscription_manager/cache.py", line 216, in load_status
    self._sync_with_server(uep, uuid)
  File "/usr/share/rhsm/subscription_manager/cache.py", line 201, in _sync_with_server
    self.server_status = uep.getCompliance(uuid)
  File "/usr/lib64/python2.6/site-packages/rhsm/connection.py", line 817, in getCompliance
    return self.conn.request_get(method)
  File "/usr/lib64/python2.6/site-packages/rhsm/connection.py", line 541, in request_get
    return self._request("GET", method)
  File "/usr/lib64/python2.6/site-packages/rhsm/connection.py", line 448, in _request
    conn.request(request_type, handler, body=body, headers=headers)
  File "/usr/lib64/python2.6/httplib.py", line 914, in request
    self._send_request(method, url, body, headers)
  File "/usr/lib64/python2.6/httplib.py", line 951, in _send_request
    self.endheaders()
  File "/usr/lib64/python2.6/httplib.py", line 908, in endheaders
    self._send_output()
  File "/usr/lib64/python2.6/httplib.py", line 780, in _send_output
    self.send(msg)
  File "/usr/lib64/python2.6/httplib.py", line 739, in send
    self.connect()
  File "/usr/lib64/python2.6/site-packages/M2Crypto/httpslib.py", line 51, in connect
    socket.getaddrinfo(self.host, self.port, 0, socket.SOCK_STREAM):
gaierror: [Errno -2] Name or service not known
2013-10-08 16:40:33,271 [ERROR]  @cache.py:234 - Server unreachable, registered, but no cache exists.
2013-10-08 16:40:33,272 [DEBUG]  @connection.py:420 - Loading CA PEM certificates from: /etc/rhsm/ca/
2013-10-08 16:40:33,272 [DEBUG]  @connection.py:402 - Loading CA certificate: '/etc/rhsm/ca/jsefler-f14-candlepin.pem'
2013-10-08 16:40:33,272 [DEBUG]  @connection.py:402 - Loading CA certificate: '/etc/rhsm/ca/candlepin-stage.pem'
2013-10-08 16:40:33,273 [DEBUG]  @connection.py:402 - Loading CA certificate: '/etc/rhsm/ca/redhat-uep.pem'
2013-10-08 16:40:33,274 [DEBUG]  @connection.py:441 - Making request: GET /subscription/consumers/52f2120e-fa97-4549-8aaf-3c9740eed296
2013-10-08 16:40:33,274 [ERROR]  @cache.py:232 - [Errno -2] Name or service not known
Traceback (most recent call last):
  File "/usr/share/rhsm/subscription_manager/cache.py", line 216, in load_status
    self._sync_with_server(uep, uuid)
  File "/usr/share/rhsm/subscription_manager/cache.py", line 298, in _sync_with_server
    consumer_data = uep.getConsumer(uuid)
  File "/usr/lib64/python2.6/site-packages/rhsm/connection.py", line 797, in getConsumer
    return self.conn.request_get(method)
  File "/usr/lib64/python2.6/site-packages/rhsm/connection.py", line 541, in request_get
    return self._request("GET", method)
  File "/usr/lib64/python2.6/site-packages/rhsm/connection.py", line 448, in _request
    conn.request(request_type, handler, body=body, headers=headers)
  File "/usr/lib64/python2.6/httplib.py", line 914, in request
    self._send_request(method, url, body, headers)
  File "/usr/lib64/python2.6/httplib.py", line 951, in _send_request
    self.endheaders()
  File "/usr/lib64/python2.6/httplib.py", line 908, in endheaders
    self._send_output()
  File "/usr/lib64/python2.6/httplib.py", line 780, in _send_output
    self.send(msg)
  File "/usr/lib64/python2.6/httplib.py", line 739, in send
    self.connect()
  File "/usr/lib64/python2.6/site-packages/M2Crypto/httpslib.py", line 51, in connect
    socket.getaddrinfo(self.host, self.port, 0, socket.SOCK_STREAM):
gaierror: [Errno -2] Name or service not known
2013-10-08 16:40:33,275 [ERROR]  @cache.py:234 - Server unreachable, registered, but no cache exists.



VERIFIED: After disconnecting the system from the network and deleting the cache, subscription-manager list --installed successfully rendered (notice that the installed product status was "Unknown").  The rhsm.log now shows that "Failed to sync installed products with the server", and "Server unreachable, registered, but no cache exists."


[root@jsefler-6 ~]# ifconfig eth0 up
[root@jsefler-6 ~]# subscription-manager list --installed
+-------------------------------------------+
    Installed Product Status
+-------------------------------------------+
Product Name:   Red Hat Enterprise Linux Server
Product ID:     69
Version:        6.5
Arch:           x86_64
Status:         Subscribed
Status Details: 
Starts:         12/31/2012
Ends:           12/31/2013


VERIFIED: After reconnecting the network, subscription-manager list --installed successfully renders (notice that the installed product status was restored to "Subscribed").
Comment 15 errata-xmlrpc 2013-11-21 21:29:26 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.

http://rhn.redhat.com/errata/RHBA-2013-1659.html