Bug 672122

Summary: global name 'uep' is not defined causes rhsmcertd update failed (255) to occur sporadically
Product: Red Hat Enterprise Linux 6 Reporter: John Sefler <jsefler>
Component: subscription-managerAssignee: Adrian Likins <alikins>
Status: CLOSED ERRATA QA Contact: John Sefler <jsefler>
Severity: medium Docs Contact:
Priority: unspecified    
Version: 6.1CC: alikins, jharris
Target Milestone: rc   
Target Release: ---   
Hardware: Unspecified   
OS: Unspecified   
Whiteboard:
Fixed In Version: Doc Type: Bug Fix
Doc Text:
Story Points: ---
Clone Of: Environment:
Last Closed: 2011-05-19 13:39:10 UTC Type: ---
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: 639436    

Description John Sefler 2011-01-24 02:19:54 UTC
Description of problem:
I have an automated test (UnsubscribeTests.UnsubscribeAndAttemptToReuseTheRevokedEntitlementCert_Test()) that:
1. Subscribes to a pool
2. copies the entitlement to the side
3. Unsubscribes from the serial
4. restarts rhsmcertd with 1min certFrequency
5. moves the copied entitlement cert back into /etc/pki/entitlement
6. waits for a min for rhsmcertd to clean out the "revoked" entitlement cert

The problem is that the rhsmcertd sometimes fails to update certificates.
Is this something that can be made more reliable?
Here are the logs...

/var/log/rhsm/rhsmcertd.log
Sun Jan 23 20:47:23 2011: started: interval = 1 minutes
Sun Jan 23 20:47:23 2011: update failed (255), retry in 1 minutes
Sun Jan 23 20:48:23 2011: update failed (255), retry in 1 minutes
Sun Jan 23 20:49:25 2011: certificates updated
Sun Jan 23 20:50:25 2011: update failed (255), retry in 1 minutes
Sun Jan 23 20:51:26 2011: certificates updated
Sun Jan 23 20:52:26 2011: certificates updated
Sun Jan 23 20:53:27 2011: certificates updated

/var/log/rhsm/rhsm.log
2011-01-23 20:50:25,153 [INFO] __init__() @connection.py:297 - Using certificate authentication: key = /etc/pki/consumer/key.pem, cert = /etc/pki/consumer/cert.pem, ca = /etc/rhsm/ca/, insecure = False
2011-01-23 20:50:25,154 [INFO] __init__() @connection.py:300 - Connection Established: host: subscriptions.rhn.webqa.redhat.com, port: 443, handler: /subscription
2011-01-23 20:50:25,155 [INFO] perform() @repolib.py:70 - repos updated: 0
2011-01-23 20:50:25,264 [DEBUG] __init__() @certlib.py:649 - Sorting product and entitlement cert status for: 2011-01-23 20:50:25.263199
2011-01-23 20:50:25,280 [DEBUG] _populate_all_products() @certlib.py:667 - Installed product IDs: ['3', '5', '4', '7', '6']
2011-01-23 20:50:25,280 [DEBUG] __init__() @certlib.py:658 - valid entitled products: []
2011-01-23 20:50:25,281 [DEBUG] __init__() @certlib.py:659 - expired entitled products: []
2011-01-23 20:50:25,283 [ERROR] <module>() @certmgr.py:106 - Error while updating certificates using daemon
2011-01-23 20:50:25,283 [ERROR] <module>() @certmgr.py:108 - global name 'uep' is not defined
Traceback (most recent call last):
  File "/usr/share/rhsm/certmgr.py", line 104, in <module>
    main()
  File "/usr/share/rhsm/certmgr.py", line 93, in main
    updates = mgr.update()
  File "/usr/share/rhsm/certmgr.py", line 74, in update
    updates += lib.update()
  File "/usr/share/rhsm/factlib.py", line 39, in update
    return action.perform()
  File "/usr/share/rhsm/factlib.py", line 57, in perform
    updates = self.updateFacts(facts.get_facts())
  File "/usr/share/rhsm/factlib.py", line 66, in updateFacts
    self.uep.updateConsumerFacts(uep.uuid, facts)
NameError: global name 'uep' is not defined


2011-01-23 20:51:25,449 [INFO] __init__() @connection.py:297 - Using certificate authentication: key = /etc/pki/consumer/key.pem, cert = /etc/pki/consumer/cert.pem, ca = /etc/rhsm/ca/, insecure = False
2011-01-23 20:51:25,450 [INFO] __init__() @connection.py:300 - Connection Established: host: subscriptions.rhn.webqa.redhat.com, port: 443, handler: /subscription
2011-01-23 20:51:25,452 [INFO] perform() @repolib.py:70 - repos updated: 0
2011-01-23 20:51:25,544 [DEBUG] __init__() @certlib.py:649 - Sorting product and entitlement cert status for: 2011-01-23 20:51:25.544089
2011-01-23 20:51:25,559 [DEBUG] _populate_all_products() @certlib.py:667 - Installed product IDs: ['3', '5', '4', '7', '6']
2011-01-23 20:51:25,559 [DEBUG] __init__() @certlib.py:658 - valid entitled products: []
2011-01-23 20:51:25,559 [DEBUG] __init__() @certlib.py:659 - expired entitled products: []
2011-01-23 20:51:25,560 [INFO] perform() @factlib.py:58 - facts updated: 0
2011-01-23 20:51:25,563 [INFO] _request() @connection.py:146 - loading ca pem certificates from: /etc/rhsm/ca/
2011-01-23 20:51:25,564 [INFO] _load_ca_certificates() @connection.py:133 - loading ca certificate '/etc/rhsm/ca/candlepin-stage.pem'
2011-01-23 20:51:25,564 [INFO] _load_ca_certificates() @connection.py:133 - loading ca certificate '/etc/rhsm/ca/fakamai-cp1.pem'
2011-01-23 20:51:25,564 [INFO] _load_ca_certificates() @connection.py:133 - loading ca certificate '/etc/rhsm/ca/redhat-uep.pem'
2011-01-23 20:51:25,565 [INFO] _request() @connection.py:148 - work in insecure mode ?:False
2011-01-23 20:51:26,069 [INFO] _request() @connection.py:176 - status code: 200
2011-01-23 20:51:26,072 [INFO] perform() @certlib.py:137 - certs updated:
Total updates: 0
Found (local) serial# []
Expected (UEP) serial# []
Added (new)
  <NONE>
Deleted (rogue):
  <NONE>
Expired (not deleted):
  <NONE>
Expired (deleted):
  <NONE>

Version-Release number of selected component (if applicable):
[root@jsefler-betaqa-1 ~]# rpm -qa | grep subscription-manager
subscription-manager-firstboot-0.93.14-1.el6.x86_64
subscription-manager-0.93.14-1.el6.x86_64
subscription-manager-gnome-0.93.14-1.el6.x86_64


How reproducible:
Occasional


  
Actual results:
Sun Jan 23 20:50:25 2011: update failed (255), retry in 1 minutes

Expected results:
Sun Jan 23 20:51:26 2011: certificates updated

Comment 2 John Sefler 2011-01-24 02:31:49 UTC
This is happening against the QA environment candlepin server
[root@jsefler-betaqa-1 ~]# grep hostname /etc/rhsm/rhsm.conf 
# Server hostname:
hostname=subscriptions.rhn.webqa.redhat.com
proxy_hostname=

[root@jsefler-betaqa-1 ~]# curl -k -u foo:bar --request GET https://subscriptions.rhn.webqa.redhat.com:443/subscription/status
{"version":"0.1.30","result":true,"release":"1%{?dist}"}

Comment 3 Adrian Likins 2011-01-24 21:25:49 UTC
commit ff4553398bd78be039b1704ae00210cc38fe1025
Author: Adrian Likins <alikins>
Date:   Mon Jan 24 12:22:07 2011 -0500

    672122: facts updating wasn't using consumer_uuid
    
    Pull in consumer_uuid from certlib and send it along.

Comment 5 John Sefler 2011-01-26 16:55:57 UTC
VERIFYING VERSION...

[root@jsefler-onprem01 ~]# rpm -q subscription-manager
subscription-manager-0.93.15-1.git.2.483e1d2.el6.x86_64
[root@jsefler-onprem01 ~]# rpm -q subscription-manager --changelog | grep 672122
- 672122: facts updating wasn't using consumer_uuid (alikins)

[root@jsefler-onprem01 ~]# grep hostname /etc/rhsm/rhsm.conf
# Server hostname:
hostname=subscriptions.rhn.webqa.redhat.com
proxy_hostname=


register and subscribe to a pool

[root@jsefler-onprem01 ~]# service rhsmcertd restart
Stopping rhsmcertd                                         [  OK  ]
Starting rhsmcertd 1                                       [  OK  ]
[root@jsefler-onprem01 ~]# tail -f /var/log/rhsm/rhsmcertd.log
Wed Jan 26 11:31:13 2011: started: interval = 1 minutes
Wed Jan 26 11:31:14 2011: certificates updated
Wed Jan 26 11:32:15 2011: certificates updated
Wed Jan 26 11:33:15 2011: certificates updated
Wed Jan 26 11:34:16 2011: certificates updated
Wed Jan 26 11:35:17 2011: certificates updated
Wed Jan 26 11:36:18 2011: certificates updated
Wed Jan 26 11:37:18 2011: certificates updated
Wed Jan 26 11:38:19 2011: certificates updated
Wed Jan 26 11:39:20 2011: certificates updated
Wed Jan 26 11:40:21 2011: certificates updated
Wed Jan 26 11:41:22 2011: certificates updated
Wed Jan 26 11:42:22 2011: certificates updated
Wed Jan 26 11:43:23 2011: certificates updated
Wed Jan 26 11:44:24 2011: certificates updated
Wed Jan 26 11:45:25 2011: certificates updated
Wed Jan 26 11:46:26 2011: certificates updated
Wed Jan 26 11:47:27 2011: certificates updated
Wed Jan 26 11:48:28 2011: certificates updated
Wed Jan 26 11:49:29 2011: certificates updated
Wed Jan 26 11:50:29 2011: certificates updated
Wed Jan 26 11:51:30 2011: certificates updated
Wed Jan 26 11:52:31 2011: certificates updated


With your fix, the certificates update appears to be stable now.
Moving to VERIFIED

Comment 6 errata-xmlrpc 2011-05-19 13:39:10 UTC
An advisory has been issued which should help the problem
described in this bug report. This report is therefore being
closed with a resolution of ERRATA. For more information
on therefore solution and/or where to find the updated files,
please follow the link below. You may reopen this bug report
if the solution does not work for you.

http://rhn.redhat.com/errata/RHEA-2011-0611.html