RHEL Engineering is moving the tracking of its product development work on RHEL 6 through RHEL 9 to Red Hat Jira (issues.redhat.com). If you're a Red Hat customer, please continue to file support cases via the Red Hat customer portal. If you're not, please head to the "RHEL project" in Red Hat Jira and file new tickets here. Individual Bugzilla bugs in the statuses "NEW", "ASSIGNED", and "POST" are being migrated throughout September 2023. Bugs of Red Hat partners with an assigned Engineering Partner Manager (EPM) are migrated in late September as per pre-agreed dates. Bugs against components "kernel", "kernel-rt", and "kpatch" are only migrated if still in "NEW" or "ASSIGNED". If you cannot log in to RH Jira, please consult article #7032570. That failing, please send an e-mail to the RH Jira admins at rh-issues@redhat.com to troubleshoot your issue as a user management inquiry. The email creates a ServiceNow ticket with Red Hat. Individual Bugzilla bugs that are migrated will be moved to status "CLOSED", resolution "MIGRATED", and set with "MigratedToJIRA" in "Keywords". The link to the successor Jira issue will be found under "Links", have a little "two-footprint" icon next to it, and direct you to the "RHEL project" in Red Hat Jira (issue links are of type "https://issues.redhat.com/browse/RHEL-XXXX", where "X" is a digit). This same link will be available in a blue banner at the top of the page informing you that that bug has been migrated.
Bug 1171386 - Cronjob /etc/cron.daily/rhsmd fails sometimes with python traceback
Summary: Cronjob /etc/cron.daily/rhsmd fails sometimes with python traceback
Keywords:
Status: CLOSED ERRATA
Alias: None
Product: Red Hat Enterprise Linux 7
Classification: Red Hat
Component: subscription-manager
Version: 7.0
Hardware: All
OS: Linux
high
high
Target Milestone: rc
: ---
Assignee: candlepin-bugs
QA Contact: John Sefler
URL:
Whiteboard:
Depends On: 1167463
Blocks:
TreeView+ depends on / blocked
 
Reported: 2014-12-06 08:24 UTC by Jan Kurik
Modified: 2021-06-10 10:48 UTC (History)
17 users (show)

Fixed In Version:
Doc Type: Bug Fix
Doc Text:
Cause: Subscription manager was not handling error messages from the server which were not properly formatted JSON. Unexpected server-side trouble can lead to non-JSON formatted replies to subscription-manager which in turn cause subscription-manager to log tracebacks. Consequence: Erroneous network responses from the server resulted in stack traces showing up in the log or to standard out caused customers to believe that subscription-manager itself behaved incorrectly. Fix: Subscription Manager was updated to handle network errors more discretely. Network errors and non-JSON responses from the server are now filtered to keep tracebacks from cluttering syslog. Result: As unexpected responses from the entitlement server are encountered by rhsmd, the syslog and root mailbox will no longer get flooded by failing cron.daily runs of rhsmd. The unexpected responses are now caught and logged gracefully to rhsm.log.
Clone Of: 1167463
Environment:
Last Closed: 2015-01-19 10:20:52 UTC
Target Upstream Version:
Embargoed:

Attachments (Terms of Use)


Links
System ID Private Priority Status Summary Last Updated
Red Hat Product Errata RHBA-2015:0055 0 normal SHIPPED_LIVE subscription-manager bug fix update 2015-01-19 15:20:19 UTC

Description Jan Kurik 2014-12-06 08:24:41 UTC 
This bug has been copied from bug #1167463 and has been proposed
to be backported to 7.0 z-stream (EUS).
Comment 4 John Sefler 2015-01-10 01:33:23 UTC 
The following is my attempt to create/fake a reproducible scenario resulting in rhsmd tracebacks from a cron job which in turns floods root with unnecessary cron e-mails as reported in bug 1103824.

Beginning with the most recent zstream released subscription-manager package on RHEL7.0...

[root@apollo ~]# cat /etc/redhat-release 
Red Hat Enterprise Linux Server release 7.0 (Maipo)
[root@apollo ~]# subscription-manager version
server type: Red Hat Subscription Management
subscription management server: 0.9.26.6-1
subscription-manager: 1.10.14-9.el7_0
python-rhsm: 1.10.12-2.el7

[root@apollo ~]# subscription-manager register --username=qa --serverurl=subscription.rhn.stage.redhat.com:443/subscription
Password: 
The system has been registered with ID: 2b0f31fa-5a82-4d6e-ab59-807f296bdf48 

Now let's temporarily break httplib.py by editing /usr/lib64/python2.7/httplib.py an inserting the "raise IndexError()" line of code within the request definition (this can be fixed afterwords by calling "yum reinstall python-libs")

    971     def request(self, method, url, body=None, headers={}):
    972         """Send a complete request to the server."""
    973         raise IndexError(); #testing
    974         self._send_request(method, url, body, headers)

Now let's create a cron job that runs the offending daily cron job on a per minute basis so we don't have to wait a day.  crontab -e will put you into a vi editor to enter the code you see below from crontab -l ...

[root@apollo ~]# mail
No mail for root
[root@apollo ~]# crontab -e
crontab: installing new crontab
[root@apollo ~]# crontab -l
* * * * * /etc/cron.daily/rhsmd
[root@apollo ~]# sleep 60
You have new mail in /var/spool/mail/root
[root@apollo ~]# mail
Heirloom Mail version 12.5 7/5/10.  Type ? for help.
"/var/spool/mail/root": 2 messages 2 new
>N  1 (Cron Daemon)         Fri Jan  9 18:38  61/3092  "Cron <root@apollo> /etc/cron.daily/rhsmd"
 N  2 (Cron Daemon)         Fri Jan  9 18:39  61/3091  "Cron <root@apollo> /etc/cron.daily/rhsmd"
& 1
Message  1:
From root.lab.eng.bos.redhat.com  Fri Jan  9 18:38:02 2015
Return-Path: <root.lab.eng.bos.redhat.com>
Date: Fri, 9 Jan 2015 18:38:02 -0500
From: "(Cron Daemon)" <root.lab.eng.bos.redhat.com>
To: root.lab.eng.bos.redhat.com
Subject: Cron <root@apollo> /etc/cron.daily/rhsmd
Content-Type: text/plain; charset=UTF-8
Auto-Submitted: auto-generated
Precedence: bulk
X-Cron-Env: <XDG_SESSION_ID=13>
X-Cron-Env: <XDG_RUNTIME_DIR=/run/user/0>
X-Cron-Env: <LANG=en_US.UTF-8>
X-Cron-Env: <SHELL=/bin/sh>
X-Cron-Env: <HOME=/root>
X-Cron-Env: <PATH=/usr/bin:/bin>
X-Cron-Env: <LOGNAME=root>
X-Cron-Env: <USER=root>
Status: RO

Traceback (most recent call last):
  File "/usr/libexec/rhsmd", line 264, in <module>
    main()
  File "/usr/libexec/rhsmd", line 225, in main
    status = check_status(force_signal)
  File "/usr/libexec/rhsmd", line 87, in check_status
    sorter = require(CERT_SORTER)
  File "/usr/share/rhsm/subscription_manager/injection.py", line 98, in require
    return FEATURES.require(feature, *args, **kwargs)
  File "/usr/share/rhsm/subscription_manager/injection.py", line 72, in require
    self.providers[feature] = provider()
  File "/usr/share/rhsm/subscription_manager/cert_sorter.py", line 320, 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 115, in load
    self._parse_server_status()
  File "/usr/share/rhsm/subscription_manager/cert_sorter.py", line 134, in _parse_server_status
    status = self.get_compliance_status()
  File "/usr/share/rhsm/subscription_manager/cert_sorter.py", line 328, 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 212, 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.7/site-packages/rhsm/connection.py", line 849, in getCompliance
    return self.conn.request_get(method)
  File "/usr/lib64/python2.7/site-packages/rhsm/connection.py", line 554, in request_get
    return self._request("GET", method)
  File "/usr/lib64/python2.7/site-packages/rhsm/connection.py", line 457, in _request
    conn.request(request_type, handler, body=body, headers=headers)
  File "/usr/lib64/python2.7/httplib.py", line 973, in request
    raise IndexError(); #testing
IndexError

& d*
& q
[root@apollo ~]# crontab -r

CONFIRMED: We have now demonstrated that tracebacks encountered while executing rhsmd cron jobs will flood root's mail box.
Comment 5 John Sefler 2015-01-10 01:34:46 UTC 
Now after installing a zstream fix for subscription-manager, let's verify the flood of rhsmd cron mail stops...

[root@apollo ~]# subscription-manager version
server type: Red Hat Subscription Management
subscription management server: 0.9.26.6-1
subscription-manager: 1.10.14-13.el7_0
python-rhsm: 1.10.12-2.el7

[root@apollo ~]# mail
No mail for root
[root@apollo ~]# crontab -e
no crontab for root - using an empty one
crontab: installing new crontab
[root@apollo ~]# crontab -l
* * * * * /etc/cron.daily/rhsmd
[root@apollo ~]# sleep 60
[root@apollo ~]# mail
No mail for root
[root@apollo ~]# 

VERIFIED: The offending tracebacks encountered by the rhsmd cron jobs no longer flood root's mail box.

[root@apollo ~]# tail -f /var/log/rhsm/rhsm.log 
2015-01-09 20:15:01,409 [INFO] rhsmd @rhsmd:225 - rhsmd started
2015-01-09 20:15:01,410 [INFO] rhsmd @rhsmd:256 - logging subscription status to syslog
2015-01-09 20:15:01,480 [DEBUG] rhsmd @identity.py:130 - Loading consumer info from identity certificates.
2015-01-09 20:15:01,482 [DEBUG] rhsmd @profile.py:97 - Loading current RPM profile.
2015-01-09 20:15:01,567 [INFO] rhsmd @connection.py:663 - Using certificate authentication: key = /etc/pki/consumer/key.pem, cert = /etc/pki/consumer/cert.pem, ca = /etc/rhsm/ca/, insecure = False
2015-01-09 20:15:01,568 [INFO] rhsmd @connection.py:674 - Connection Built: host: subscription.rhn.stage.redhat.com, port: 443, handler: /subscription
2015-01-09 20:15:01,568 [INFO] rhsmd @cache.py:169 - Checking current system info against cache: /var/lib/rhsm/cache/installed_products.json
2015-01-09 20:15:01,568 [INFO] rhsmd @cache.py:186 - No changes.
2015-01-09 20:15:01,569 [DEBUG] rhsmd @certdirectory.py:204 - Installed product IDs: ['69']
2015-01-09 20:15:01,570 [DEBUG] rhsmd @connection.py:418 - Loaded CA certificates from /etc/rhsm/ca/: candlepin-stage.pem, redhat-uep.pem
2015-01-09 20:15:01,570 [DEBUG] rhsmd @connection.py:450 - Making request: GET /subscription/consumers/2b0f31fa-5a82-4d6e-ab59-807f296bdf48/compliance
2015-01-09 20:15:01,572 [ERROR] rhsmd @rhsmd:60 - Unhandled rhsmd exception caught by the logging excepthook: Traceback (most recent call last):
  File "/usr/libexec/rhsmd", line 302, in <module>
    main()
  File "/usr/libexec/rhsmd", line 257, in main
    status = check_status(force_signal)
  File "/usr/libexec/rhsmd", line 119, in check_status
    sorter = require(CERT_SORTER)
  File "/usr/share/rhsm/subscription_manager/injection.py", line 98, in require
    return FEATURES.require(feature, *args, **kwargs)
  File "/usr/share/rhsm/subscription_manager/injection.py", line 72, in require
    self.providers[feature] = provider()
  File "/usr/share/rhsm/subscription_manager/cert_sorter.py", line 320, 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 115, in load
    self._parse_server_status()
  File "/usr/share/rhsm/subscription_manager/cert_sorter.py", line 134, in _parse_server_status
    status = self.get_compliance_status()
  File "/usr/share/rhsm/subscription_manager/cert_sorter.py", line 328, 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 212, in load_status
    self._sync_with_server(uep, uuid)
  File "/usr/share/rhsm/subscription_manager/cache.py", line 296, in _sync_with_server
    self.server_status = uep.getCompliance(uuid)
  File "/usr/lib64/python2.7/site-packages/rhsm/connection.py", line 849, in getCompliance
    return self.conn.request_get(method)
  File "/usr/lib64/python2.7/site-packages/rhsm/connection.py", line 554, in request_get
    return self._request("GET", method)
  File "/usr/lib64/python2.7/site-packages/rhsm/connection.py", line 457, in _request
    conn.request(request_type, handler, body=body, headers=headers)
  File "/usr/lib64/python2.7/httplib.py", line 973, in request
    raise IndexError(); #testing
IndexError


VERIFIED: While the rhsmd traceback is no longer reported to root's mailbox, it is logged to /var/log/rhsm/rhsm.log as expected.
Comment 6 John Sefler 2015-01-12 23:09:06 UTC 
The following is another approach to create/fake a reproducible scenario resulting in rhsmd tracebacks from a cron job which in turns floods root with unnecessary cron e-mails as reported in bug 1103824.
Unlike the approach used above in comment 4, this time I will use netcat to force a "502 Proxy Response" from the entitlement server like the one reported in the description of bug 1103824.

Beginning with the most recent zstream released subscription-manager package on RHEL7.0...

[root@apollo ~]# cat /etc/redhat-release
Red Hat Enterprise Linux Server release 7.0 (Maipo)
[root@apollo ~]# subscription-manager version
server type: This system is currently not registered.
subscription management server: 0.9.26.6-1
subscription-manager: 1.10.14-9.el7_0
python-rhsm: 1.10.12-2.el7

[root@apollo ~]# subscription-manager register --username=qa --serverurl=subscription.rhn.stage.redhat.com:443/subscription
Password: 
The system has been registered with ID: 0d6498ad-21ee-4852-b774-dba385d331ba 

Now that the system is registered, I will use a different system, jsefler-7.usersys.redhat.com, to create a very crude server using netcat that only replys with a 502 response.  Once this is running, we'll come back to the RHEL7.0 system and change the rhsm configuration to comminicate with the crude netcat server.  Here we go, step...

1. Create a self-signed certificate for netcat to use.

[root@jsefler-7 ~]# hostname
jsefler-7.usersys.redhat.com
[root@jsefler-7 ~]# mkdir crude
[root@jsefler-7 ~]# cd crude/
[root@jsefler-7 crude]# openssl genrsa -out nc.key 2048
Generating RSA private key, 2048 bit long modulus
.............+++
..........+++
e is 65537 (0x10001)
[root@jsefler-7 crude]# openssl req -new -key nc.key -out nc.csr -subj "/C=US/O=QA/CN=localhost"
[root@jsefler-7 crude]# openssl x509 -req -days 3650 -in nc.csr -signkey nc.key -out nc.crt
Signature ok
subject=/C=US/O=QA/CN=localhost
Getting Private key
[root@jsefler-7 crude]# ls
nc.crt  nc.csr  nc.key

Now we have a self-signed certificate and a private key for that cert.  The
CSR file is extraneous at this point.

2. Create a response file named 502.response with exactly these contents...

[root@jsefler-7 crude]# cat 502.response
HTTP/1.1 502 Bad Gateway
Content-Length: 590
Connection: keep-alive

<!DOCTYPE HTML PUBLIC -//IETF//DTD HTML 2.0//EN>
<html><head>
<title>502 Proxy Error</title>
</head><body><h1>Proxy Error</h1>
<p>The proxy server received an invalid
response from an upstream server.<br />
The proxy server could not handle the request <em><a href=/subscription/consumers/9decaece-a2eb-42e6-8d2c-0fd541a38499/compliance>GET&nbsp;/subscription/consumers/9decaece-a2eb-42e6-8d2c-0fd541a38499/compliance</a></em>.<p>
Reason: <strong>Error reading from remote server</strong></p></p>
<hr>
<address>Apache Server at subscription.rhn.redhat.com Port 443</address>
</body></html>
[root@jsefler-7 crude]# 

3. Start netcat configured to respond to any request with the desired reply.

The -l argument takes the port number to listen on (8445 in this case).  The -k
option keeps netcat listening forever (ctrl-C to stop).  The ssl options allow
netcat to respond to requests over SSL.  The -e option is a command that netcat
will execute on every request.  In this case, it will cat the file 502.response file and send it back to subscription-manager.

[root@jsefler-7 crude]# nc -l 8445 -k --ssl-cert nc.crt --ssl-key nc.key -e '/bin/cat 502.response'


4. To verify that netcat is working, open a second terminal shell since the one above is running in the foreground and run...

[root@jsefler-7 crude]# curl -k -v https://localhost:8445/
* About to connect() to localhost port 8445 (#0)
*   Trying ::1...
* Connected to localhost (::1) port 8445 (#0)
* Initializing NSS with certpath: sql:/etc/pki/nssdb
* skipping SSL peer certificate verification
* SSL connection using TLS_RSA_WITH_AES_128_CBC_SHA
* Server certificate:
* 	subject: CN=localhost,O=QA,C=US
* 	start date: Jan 12 21:44:31 2015 GMT
* 	expire date: Jan 09 21:44:31 2025 GMT
* 	common name: localhost
* 	issuer: CN=localhost,O=QA,C=US
> GET / HTTP/1.1
> User-Agent: curl/7.29.0
> Host: localhost:8445
> Accept: */*
> 
< HTTP/1.1 502 Bad Gateway
< Content-Length: 590
< Connection: keep-alive
< 
<!DOCTYPE HTML PUBLIC -//IETF//DTD HTML 2.0//EN>
<html><head>
<title>502 Proxy Error</title>
</head><body><h1>Proxy Error</h1>
<p>The proxy server received an invalid
response from an upstream server.<br />
The proxy server could not handle the request <em><a href=/subscription/consumers/9decaece-a2eb-42e6-8d2c-0fd541a38499/compliance>GET&nbsp;/subscription/consumers/9decaece-a2eb-42e6-8d2c-0fd541a38499/compliance</a></em>.<p>
Reason: <strong>Error reading from remote server</strong></p></p>
<hr>
<address>Apache Server at subscription.rhn.redhat.com Port 443</address>
</body></html>
* Connection #0 to host localhost left intact
[root@jsefler-7 crude]# 

Its working!  Now let's get back to our RHEL7.0 system.
First we will reconfigure rhsm to comminicate to the crude server...

[root@apollo ~]# subscription-manager config --server.hostname=jsefler-7.usersys.redhat.com --server.port=8444 --server.insecure=1

Now let's create a cron job that runs the offending daily cron job on a per minute basis so we don't have to wait a day.  crontab -e will put you into a vi editor to enter the code you see below from crontab -l ...


[root@apollo ~]# crontab -r
[root@apollo ~]# echo "d*" | mail > /dev/null
[root@apollo ~]# mail
No mail for root
[root@apollo ~]# crontab -e
no crontab for root - using an empty one
crontab: installing new crontab
[root@apollo ~]# crontab -l
* * * * * /etc/cron.daily/rhsmd
[root@apollo ~]# sleep 60
You have new mail in /var/spool/mail/root
[root@apollo ~]# mail
Heirloom Mail version 12.5 7/5/10.  Type ? for help.
"/var/spool/mail/root": 1 message 1 new
>N  1 (Cron Daemon)         Mon Jan 12 17:08  60/3257  "Cron <root@apollo> /etc/cron.daily/rhsmd"
& 1
Message  1:
From root.lab.eng.bos.redhat.com  Mon Jan 12 17:08:02 2015
Return-Path: <root.lab.eng.bos.redhat.com>
Date: Mon, 12 Jan 2015 17:08:02 -0500
From: "(Cron Daemon)" <root.lab.eng.bos.redhat.com>
To: root.lab.eng.bos.redhat.com
Subject: Cron <root@apollo> /etc/cron.daily/rhsmd
Content-Type: text/plain; charset=UTF-8
Auto-Submitted: auto-generated
Precedence: bulk
X-Cron-Env: <XDG_SESSION_ID=4288>
X-Cron-Env: <XDG_RUNTIME_DIR=/run/user/0>
X-Cron-Env: <LANG=en_US.UTF-8>
X-Cron-Env: <SHELL=/bin/sh>
X-Cron-Env: <HOME=/root>
X-Cron-Env: <PATH=/usr/bin:/bin>
X-Cron-Env: <LOGNAME=root>
X-Cron-Env: <USER=root>
Status: R

Traceback (most recent call last):
  File "/usr/libexec/rhsmd", line 264, in <module>
    main()
  File "/usr/libexec/rhsmd", line 225, in main
    status = check_status(force_signal)
  File "/usr/libexec/rhsmd", line 87, in check_status
    sorter = require(CERT_SORTER)
  File "/usr/share/rhsm/subscription_manager/injection.py", line 98, in require
    return FEATURES.require(feature, *args, **kwargs)
  File "/usr/share/rhsm/subscription_manager/injection.py", line 72, in require
    self.providers[feature] = provider()
  File "/usr/share/rhsm/subscription_manager/cert_sorter.py", line 320, 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 115, in load
    self._parse_server_status()
  File "/usr/share/rhsm/subscription_manager/cert_sorter.py", line 134, in _parse_server_status
    status = self.get_compliance_status()
  File "/usr/share/rhsm/subscription_manager/cert_sorter.py", line 328, 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 212, 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.7/site-packages/rhsm/connection.py", line 849, in getCompliance
    return self.conn.request_get(method)
  File "/usr/lib64/python2.7/site-packages/rhsm/connection.py", line 554, in request_get
    return self._request("GET", method)
  File "/usr/lib64/python2.7/site-packages/rhsm/connection.py", line 482, in _request
    self.validateResponse(result, request_type, handler)
  File "/usr/lib64/python2.7/site-packages/rhsm/connection.py", line 530, in validateResponse
    handler=handler)
rhsm.connection.RemoteServerException: Server error attempting a GET to /subscription/consumers/0d6498ad-21ee-4852-b774-dba385d331ba/compliance re
turned status 502

& d*
& q
New mail has arrived.
[root@apollo ~]# crontab -r
[root@apollo ~]# echo "d*" | mail > /dev/null
[root@apollo ~]# 


CONFIRMED: We have now demonstrated that when the entitlement server responds with a 502 Proxy Error, tracebacks encountered while executing rhsmd cron jobs will flood root's mail box.
Comment 7 John Sefler 2015-01-12 23:11:39 UTC 
Now after installing a zstream fix for subscription-manager (and keeping subscription-manager configured to communicate with the crude netcat server detailed in comment 6 above), let's verify the flood of rhsmd cron mail stops...

[root@apollo ~]# subscription-manager version
server type: Red Hat Subscription Management
subscription management server: Unknown
subscription-manager: 1.10.14-13.el7_0
python-rhsm: 1.10.12-2.el7

[root@apollo ~]# mail
No mail for root
[root@apollo ~]# crontab -e
no crontab for root - using an empty one
crontab: installing new crontab
[root@apollo ~]# crontab -l
* * * * * /etc/cron.daily/rhsmd
[root@apollo ~]# sleep 60
[root@apollo ~]# mail
No mail for root
[root@apollo ~]# 

VERIFIED: The offending tracebacks encountered by the rhsmd cron jobs caused by 502 Proxy responses no longer flood root's mail box.

[root@apollo ~]# tail -f /var/log/rhsm/rhsm.log
2015-01-12 17:56:01,403 [INFO] rhsmd @rhsmd:225 - rhsmd started
2015-01-12 17:56:01,404 [INFO] rhsmd @rhsmd:256 - logging subscription status to syslog
2015-01-12 17:56:01,475 [DEBUG] rhsmd @identity.py:130 - Loading consumer info from identity certificates.
2015-01-12 17:56:01,476 [DEBUG] rhsmd @profile.py:97 - Loading current RPM profile.
2015-01-12 17:56:01,562 [INFO] rhsmd @connection.py:663 - Using certificate authentication: key = /etc/pki/consumer/key.pem, cert = /etc/pki/consumer/cert.pem, ca = /etc/rhsm/ca/, insecure = True
2015-01-12 17:56:01,562 [INFO] rhsmd @connection.py:674 - Connection Built: host: jsefler-7.usersys.redhat.com, port: 8444, handler: /subscription
2015-01-12 17:56:01,563 [INFO] rhsmd @cache.py:169 - Checking current system info against cache: /var/lib/rhsm/cache/installed_products.json
2015-01-12 17:56:01,563 [INFO] rhsmd @cache.py:186 - No changes.
2015-01-12 17:56:01,563 [DEBUG] rhsmd @certdirectory.py:204 - Installed product IDs: ['69']
2015-01-12 17:56:01,564 [DEBUG] rhsmd @connection.py:450 - Making request: GET /subscription/consumers/0d6498ad-21ee-4852-b774-dba385d331ba/compliance
2015-01-12 17:56:01,705 [DEBUG] rhsmd @connection.py:473 - Response: status=502
2015-01-12 17:56:01,706 [ERROR] rhsmd @connection.py:502 - Response: 502
2015-01-12 17:56:01,706 [ERROR] rhsmd @connection.py:503 - JSON parsing error: No JSON object could be decoded
2015-01-12 17:56:01,706 [ERROR] rhsmd @cache.py:235 - Server error attempting a GET to /subscription/consumers/0d6498ad-21ee-4852-b774-dba385d331ba/compliance returned status 502
2015-01-12 17:56:01,706 [WARNING] rhsmd @cache.py:241 - Unable to reach server, using cached status.
2015-01-12 17:56:01,707 [DEBUG] rhsmd @cert_sorter.py:199 - valid entitled products: []
2015-01-12 17:56:01,707 [DEBUG] rhsmd @cert_sorter.py:200 - expired entitled products: []
2015-01-12 17:56:01,707 [DEBUG] rhsmd @cert_sorter.py:201 - partially entitled products: []
2015-01-12 17:56:01,707 [DEBUG] rhsmd @cert_sorter.py:202 - unentitled products: [u'69']
2015-01-12 17:56:01,707 [DEBUG] rhsmd @cert_sorter.py:203 - future products: []
2015-01-12 17:56:01,708 [DEBUG] rhsmd @cert_sorter.py:204 - partial stacks: []
2015-01-12 17:56:01,708 [DEBUG] rhsmd @cert_sorter.py:205 - entitlements valid until: None
2015-01-12 17:56:01,709 [INFO] rhsmd @rhsmd:218 - rhsmd: This system is missing one or more subscriptions. Please run subscription-manager for more information.


In fact, rhsm.log shows that the 502 response was caught as a failure to decode an expected JSON response and correctly goes on to used a cached value for status.


VERIFIED: subscription-manager: 1.10.14-13.el7_0 is a good fix for this bug.
Comment 9 errata-xmlrpc 2015-01-19 10:20:52 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/RHBA-2015-0055.html
Note You need to log in before you can comment on or make changes to this bug.