Bug 1366301

Summary: subscription-manager refresh causes: Server error attempting a PUT to /subscription/consumers/<UUID>/certificates?lazy_regen=true returned status 404
Product: Red Hat Enterprise Linux 7 Reporter: John Sefler <jsefler>
Component: subscription-managerAssignee: Chris "Ceiu" Rog <crog>
Status: CLOSED ERRATA QA Contact: John Sefler <jsefler>
Severity: high Docs Contact: Clayton Spicer <cspicer>
Priority: high    
Version: 7.3CC: brubisch, crog, hsun, jsefler, pjanda, qianzhan, redakkan, skallesh, sreber, tdarby, vrjain, xdmoon
Target Milestone: rcKeywords: Regression, Triaged
Target Release: ---   
Hardware: Unspecified   
OS: Unspecified   
Whiteboard:
Fixed In Version: Doc Type: Known Issue
Doc Text:
The "subscription-manager refresh" command fails, displaying an error Due to a bug caused by changes in the API used by the `subscription-manager` utility, executing the "subscription-manager refresh" command results in an error. There is no workaround at this point.
Story Points: ---
Clone Of: Environment:
Last Closed: 2016-11-03 20:30:34 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: 1256306, 1366991    

Description John Sefler 2016-08-11 14:41:02 UTC
Description of problem:
Subscription-manager refresh against stage (or production) candlepin server is getting a 404 response.

I suspect this is a consequence of the work done on Bug 1360909


Version-Release number of selected component (if applicable):
[root@ibm-x3650m4-01-vm-14 ~]# subscription-manager version
server type: This system is currently not registered.
subscription management server: 0.9.51.15-1
subscription management rules: 5.15.1
subscription-manager: 1.17.10-1.el7
python-rhsm: 1.17.6-1.el7


How reproducible:


Steps to Reproduce:
[root@ibm-x3650m4-01-vm-14 ~]# subscription-manager register --serverurl=subscription.rhsm.stage.redhat.com:443/subscription
Registering to: subscription.rhsm.stage.redhat.com:443/subscription
Username: qa
Password: 
The system has been registered with ID: 578a8430-36dc-498b-895a-74ffddcb8aca 
[root@ibm-x3650m4-01-vm-14 ~]# subscription-manager refresh
Remote server error. Please check the connection details, or see /var/log/rhsm/rhsm.log for more information.


[root@ibm-x3650m4-01-vm-14 ~]# tail -f /var/log/rhsm/rhsm.log
2016-08-11 10:28:46,986 [DEBUG] subscription-manager:7190:MainThread @ga_loader.py:89 - ga_loader GaImporterGtk3
2016-08-11 10:28:46,997 [DEBUG] subscription-manager:7190:MainThread @plugins.py:569 - loaded plugin modules: [<module 'container_content' from '/usr/share/rhsm-plugins/container_content.pyc'>, <module 'ostree_content' from '/usr/share/rhsm-plugins/ostree_content.pyc'>]
2016-08-11 10:28:46,998 [DEBUG] subscription-manager:7190:MainThread @plugins.py:570 - loaded plugins: {'container_content.ContainerContentPlugin': <container_content.ContainerContentPlugin object at 0x2b43250>, 'ostree_content.OstreeContentPlugin': <ostree_content.OstreeContentPlugin object at 0x2b43810>}
2016-08-11 10:28:46,998 [DEBUG] subscription-manager:7190:MainThread @identity.py:131 - Loading consumer info from identity certificates.
2016-08-11 10:28:47,060 [INFO] subscription-manager:7190:MainThread @managercli.py:384 - Client Versions: {'python-rhsm': '1.17.6-1.el7', 'subscription-manager': '1.17.10-1.el7'}
2016-08-11 10:28:47,062 [INFO] subscription-manager:7190:MainThread @connection.py:830 - Connection built: host=subscription.rhsm.stage.redhat.com port=443 handler=/subscription auth=identity_cert ca_dir=/etc/rhsm/ca/ verify=False
2016-08-11 10:28:47,062 [INFO] subscription-manager:7190:MainThread @connection.py:830 - Connection built: host=subscription.rhsm.stage.redhat.com port=443 handler=/subscription auth=none
2016-08-11 10:28:47,062 [INFO] subscription-manager:7190:MainThread @managercli.py:359 - Consumer Identity name=ibm-x3650m4-01-vm-14.lab.eng.bos.redhat.com uuid=578a8430-36dc-498b-895a-74ffddcb8aca
2016-08-11 10:28:47,064 [DEBUG] subscription-manager:7190:MainThread @connection.py:525 - Loaded CA certificates from /etc/rhsm/ca/: redhat-uep.pem, redhat-entitlement-authority.pem
2016-08-11 10:28:47,064 [DEBUG] subscription-manager:7190:MainThread @connection.py:573 - Making request: PUT /subscription/consumers/578a8430-36dc-498b-895a-74ffddcb8aca/certificates?lazy_regen=true
2016-08-11 10:28:47,485 [DEBUG] subscription-manager:7190:MainThread @connection.py:602 - Response: status=404
2016-08-11 10:28:47,486 [ERROR] subscription-manager:7190:MainThread @managercli.py:174 - Unable to perform refresh due to the following exception: Server error attempting a PUT to /subscription/consumers/578a8430-36dc-498b-895a-74ffddcb8aca/certificates?lazy_regen=true returned status 404
2016-08-11 10:28:47,486 [ERROR] subscription-manager:7190:MainThread @managercli.py:175 - Server error attempting a PUT to /subscription/consumers/578a8430-36dc-498b-895a-74ffddcb8aca/certificates?lazy_regen=true returned status 404
Traceback (most recent call last):
  File "/usr/lib/python2.7/site-packages/subscription_manager/managercli.py", line 649, in _do_command
    self.cp.regenEntitlementCertificates(identity.uuid, True)
  File "/usr/lib64/python2.7/site-packages/rhsm/connection.py", line 1353, in regenEntitlementCertificates
    return self.conn.request_put(method)
  File "/usr/lib64/python2.7/site-packages/rhsm/connection.py", line 703, in request_put
    return self._request("PUT", method, params)
  File "/usr/lib64/python2.7/site-packages/rhsm/connection.py", line 611, in _request
    self.validateResponse(result, request_type, handler)
  File "/usr/lib64/python2.7/site-packages/rhsm/connection.py", line 667, in validateResponse
    handler=handler)
RemoteServerException: Server error attempting a PUT to /subscription/consumers/578a8430-36dc-498b-895a-74ffddcb8aca/certificates?lazy_regen=true returned status 404


Actual results:
  above

Expected results:
  no 404 response

Additional info:

Comment 5 John Sefler 2016-08-19 22:15:36 UTC
*** Bug 1367487 has been marked as a duplicate of this bug. ***

Comment 9 John Sefler 2016-08-29 18:57:53 UTC
Testing Version (against stage entitlement server where the candlepin API has not yet been opened)...

[root@jsefler-rhel7 ~]# subscription-manager version
server type: Red Hat Subscription Management
subscription management server: 0.9.51.15-1
subscription management rules: 5.15.1
subscription-manager: 1.17.11-1.el7
python-rhsm: 1.17.7-1.el7


[root@jsefler-rhel7 ~]# ls -l /etc/pki/entitlement/ /etc/pki/consumer/
/etc/pki/consumer/:
total 8
-rw-r-----. 1 root root 2057 Aug 29 14:32 cert.pem
-rw-r-----. 1 root root 1675 Aug 29 14:32 key.pem

/etc/pki/entitlement/:
total 44
-rw-------. 1 root root  1675 Aug 29 14:49 5687197171835268490-key.pem
-rw-r--r--. 1 root root 38811 Aug 29 14:49 5687197171835268490.pem
[root@jsefler-rhel7 ~]# 
[root@jsefler-rhel7 ~]# 
[root@jsefler-rhel7 ~]# rm -f /etc/pki/entitlement/*
[root@jsefler-rhel7 ~]# 
[root@jsefler-rhel7 ~]# subscription-manager refresh
All local data refreshed
[root@jsefler-rhel7 ~]# 
[root@jsefler-rhel7 ~]# 
[root@jsefler-rhel7 ~]# ls -l /etc/pki/entitlement/ /etc/pki/consumer/
/etc/pki/consumer/:
total 8
-rw-r-----. 1 root root 2057 Aug 29 14:32 cert.pem
-rw-r-----. 1 root root 1675 Aug 29 14:32 key.pem

/etc/pki/entitlement/:
total 44
-rw-------. 1 root root  1675 Aug 29 14:51 5687197171835268490-key.pem
-rw-r--r--. 1 root root 38811 Aug 29 14:51 5687197171835268490.pem
[root@jsefler-rhel7 ~]# 



[root@jsefler-rhel7 ~]# tail -f /var/log/rhsm/rhsm.log
2016-08-29 14:51:18,500 [DEBUG] subscription-manager:13527:MainThread @connection.py:573 - Making request: PUT /subscription/consumers/50408baa-f58f-4015-8d8d-c26634fb7b9c/certificates?lazy_regen=true
2016-08-29 14:51:19,087 [DEBUG] subscription-manager:13527:MainThread @connection.py:602 - Response: status=404
2016-08-29 14:51:19,088 [DEBUG] subscription-manager:13527:MainThread @connection.py:1365 - Unable to refresh entitlement certificates: Service currently unsupported.
2016-08-29 14:51:19,088 [DEBUG] subscription-manager:13527:MainThread @connection.py:1366 - Server error attempting a PUT to /subscription/consumers/50408baa-f58f-4015-8d8d-c26634fb7b9c/certificates?lazy_regen=true returned status 404
2016-08-29 14:51:19,088 [DEBUG] subscription-manager:13527:MainThread @managercli.py:652 - Warning: Unable to refresh entitlement certificates; service likely unavailable



VERIFIED: The refresh command completed as desired
          The attached entitlement file was successfully re-downloaded.
          The rhsm.log was updated with a Warning "Unable to refresh entitlement certificates; service likely unavailable" for the PUT with option ?lazy_regen=true
NOTE: The log message is partially true, but this is only temporary while IT has that Candlepin API blocked.

Comment 10 Shwetha Kallesh 2016-08-30 13:39:33 UTC
Against on-premises candlepin ,refresh command successfully re-downloads entitlement certificates

[root@dhcp35-25 ~]# subscription-manager version
server type: Red Hat Subscription Management
subscription management server: 2.0.16-1
subscription management rules: 5.20
subscription-manager: 1.17.11-1.el7
python-rhsm: 1.17.7-1.el7


[root@dhcp35-25 ~]# ll /etc/pki/consumer/
total 8
-rw-r-----. 1 root root 1257 Aug 30 19:04 cert.pem
-rw-r-----. 1 root root 1679 Aug 30 19:04 key.pem
[root@dhcp35-25 ~]# ll /etc/pki/entitlement/
total 8
-rw-------. 1 root root 1679 Aug 30 19:05 7305614684193338264-key.pem
-rw-r--r--. 1 root root 2387 Aug 30 19:05 7305614684193338264.pem
[root@dhcp35-25 ~]# rm -rf /etc/pki/entitlement/*
[root@dhcp35-25 ~]# ll /etc/pki/entitlement/
total 0
[root@dhcp35-25 ~]# subscription-manager refresh
All local data refreshed
[root@dhcp35-25 ~]# ll /etc/pki/entitlement/
total 8
-rw-------. 1 root root 1679 Aug 30 19:06 7313551866513357953-key.pem
-rw-r--r--. 1 root root 2387 Aug 30 19:06 7313551866513357953.pem
[root@dhcp35-25 ~]# ll /etc/pki/consumer/
total 8
-rw-r-----. 1 root root 1257 Aug 30 19:04 cert.pem
-rw-r-----. 1 root root 1679 Aug 30 19:04 key.pem

Comment 11 Shwetha Kallesh 2016-08-30 13:59:10 UTC
Refreshed entitlemnt is an exact match , only serial number changes when the new cert gets downloaded

[root@dhcp35-25 ~]# subscription-manager list --consumed
+-------------------------------------------+
   Consumed Subscriptions
+-------------------------------------------+
Subscription Name:   Awesome OS Instance Based one socket
Provides:            Awesome OS Instance Server Bits
SKU:                 awesomeos-onesocketib
Contract:            0
Account:             12331131231
Serial:              7313551866513357953
Pool ID:             8ac6a3fa56d5abe40156d5ad17d90537
Provides Management: No
Active:              True
Quantity Used:       1
Service Level:       Standard
Service Type:        L1-L3
Status Details:      Guest has not been reported on any host and is using a temporary unmapped guest subscription.
Subscription Type:   Instance Based (Temporary)
Starts:              08/29/2016
Ends:                08/31/2016
System Type:         Virtual

[root@dhcp35-25 ~]# rm -rf /etc/pki/entitlement/*

[root@dhcp35-25 ~]# ll /etc/pki/entitlement/
total 0

[root@dhcp35-25 ~]# subscription-manager refresh
All local data refreshed
[root@dhcp35-25 ~]# ll /etc/pki/entitlement/
total 8
-rw-------. 1 root root 1679 Aug 30 19:26 4787132322256982205-key.pem
-rw-r--r--. 1 root root 2387 Aug 30 19:26 4787132322256982205.pem
[root@dhcp35-25 ~]# subscription-manager list --consumed
+-------------------------------------------+
   Consumed Subscriptions
+-------------------------------------------+
Subscription Name:   Awesome OS Instance Based one socket
Provides:            Awesome OS Instance Server Bits
SKU:                 awesomeos-onesocketib
Contract:            0
Account:             12331131231
Serial:              4787132322256982205
Pool ID:             8ac6a3fa56d5abe40156d5ad17d90537
Provides Management: No
Active:              True
Quantity Used:       1
Service Level:       Standard
Service Type:        L1-L3
Status Details:      Guest has not been reported on any host and is using a temporary unmapped guest subscription.
Subscription Type:   Instance Based (Temporary)
Starts:              08/29/2016
Ends:                08/31/2016
System Type:         Virtual

Comment 12 Chris "Ceiu" Rog 2016-08-30 17:49:55 UTC
*** Bug 1371420 has been marked as a duplicate of this bug. ***

Comment 13 Chris Snyder 2016-08-31 17:35:48 UTC
*** Bug 1367243 has been marked as a duplicate of this bug. ***

Comment 14 qianzhan 2016-09-01 02:38:59 UTC
(In reply to Shwetha Kallesh from comment #10)
> Against on-premises candlepin ,refresh command successfully re-downloads
> entitlement certificates
> 
> [root@dhcp35-25 ~]# subscription-manager version
> server type: Red Hat Subscription Management
> subscription management server: 2.0.16-1
> subscription management rules: 5.20
> subscription-manager: 1.17.11-1.el7
> python-rhsm: 1.17.7-1.el7
> 
> 
> [root@dhcp35-25 ~]# ll /etc/pki/consumer/
> total 8
> -rw-r-----. 1 root root 1257 Aug 30 19:04 cert.pem
> -rw-r-----. 1 root root 1679 Aug 30 19:04 key.pem
> [root@dhcp35-25 ~]# ll /etc/pki/entitlement/
> total 8
> -rw-------. 1 root root 1679 Aug 30 19:05 7305614684193338264-key.pem
> -rw-r--r--. 1 root root 2387 Aug 30 19:05 7305614684193338264.pem
> [root@dhcp35-25 ~]# rm -rf /etc/pki/entitlement/*
> [root@dhcp35-25 ~]# ll /etc/pki/entitlement/
> total 0
> [root@dhcp35-25 ~]# subscription-manager refresh
> All local data refreshed
> [root@dhcp35-25 ~]# ll /etc/pki/entitlement/
> total 8
> -rw-------. 1 root root 1679 Aug 30 19:06 7313551866513357953-key.pem
> -rw-r--r--. 1 root root 2387 Aug 30 19:06 7313551866513357953.pem
> [root@dhcp35-25 ~]# ll /etc/pki/consumer/
> total 8
> -rw-r-----. 1 root root 1257 Aug 30 19:04 cert.pem
> -rw-r-----. 1 root root 1679 Aug 30 19:04 key.pem


Still failed agaist SAM-1.4.1-RHEL-6-20141113.0, so I reopen bug 1367243.

Comment 15 Rehana 2016-09-21 09:37:24 UTC
Retesting the bug against stage candlepin server , as the API end point is now open (Retest request received from Tramaine Darby.) 

# subscription-manager version
server type: Red Hat Subscription Management
subscription management server: 0.9.51.15-1
subscription management rules: 5.15.1
subscription-manager: 1.17.15-1.el7
python-rhsm: 1.17.9-1.el7


# subscription-manager register --auto-attach
Registering to: subscription.rhsm.stage.redhat.com:443/subscription
Username: qa
Password: 
The system has been registered with ID: 5b314817-77fb-4d2a-a8d4-541a8a3cf852 

Installed Product Current Status:
Product Name: Red Hat Enterprise Linux Server
Status:       Subscribed

# ls -l /etc/pki/entitlement/ /etc/pki/consumer/
/etc/pki/consumer/:
total 8
-rw-r-----. 1 root root 2041 Sep 21 05:12 cert.pem
-rw-r-----. 1 root root 1675 Sep 21 05:12 key.pem

/etc/pki/entitlement/:
total 24
-rw-------. 1 root root  1675 Sep 21 05:12 8929858690542245449-key.pem
-rw-r--r--. 1 root root 16439 Sep 21 05:12 8929858690542245449.pem

# rm -rf /etc/pki/entitlement/


# subscription-manager refresh
All local data refreshed

# ls -l /etc/pki/entitlement/ /etc/pki/consumer/
/etc/pki/consumer/:
total 8
-rw-r-----. 1 root root 2041 Sep 21 05:12 cert.pem
-rw-r-----. 1 root root 1675 Sep 21 05:12 key.pem

/etc/pki/entitlement/:
total 24
-rw-------. 1 root root  1675 Sep 21 05:13 2718907493359068982-key.pem
-rw-r--r--. 1 root root 16451 Sep 21 05:13 2718907493359068982.pem

rhsm.log 
=====

2016-09-21 05:13:13,701 [INFO] subscription-manager:11481:MainThread @managercli.py:384 - Client Versions: {'python-rhsm': '1.17.9-1.el7', 'subscription-manager': '1.17.15-1.el7'}
2016-09-21 05:13:13,701 [INFO] subscription-manager:11481:MainThread @connection.py:830 - Connection built: host=subscription.rhsm.stage.redhat.com port=443 handler=/subscription auth=identity_cert ca_dir=/etc/rhsm/ca/ verify=False
2016-09-21 05:13:13,702 [INFO] subscription-manager:11481:MainThread @connection.py:830 - Connection built: host=subscription.rhsm.stage.redhat.com port=443 handler=/subscription auth=none
2016-09-21 05:13:13,702 [INFO] subscription-manager:11481:MainThread @managercli.py:359 - Consumer Identity name=localhost.localdomain uuid=5b314817-77fb-4d2a-a8d4-541a8a3cf852
2016-09-21 05:13:13,702 [DEBUG] subscription-manager:11481:MainThread @connection.py:525 - Loaded CA certificates from /etc/rhsm/ca/: redhat-uep.pem
2016-09-21 05:13:13,702 [DEBUG] subscription-manager:11481:MainThread @connection.py:573 - Making request: PUT /subscription/consumers/5b314817-77fb-4d2a-a8d4-541a8a3cf852/certificates?lazy_regen=true
2016-09-21 05:13:14,172 [DEBUG] subscription-manager:11481:MainThread @connection.py:602 - Response: status=204, requestUuid=8188fa9e-508e-4ba1-bcd0-d57c75467d0f
2016-09-21 05:13:14,173 [DEBUG] subscription-manager:11481:MainThread @connection.py:525 - Loaded CA certificates from /etc/rhsm/ca/: redhat-uep.pem
2016-09-21 05:13:14,173 [DEBUG] subscription-manager:11481:MainThread @connection.py:573 - Making request: GET /subscription/consumers/5b314817-77fb-4d2a-a8d4-541a8a3cf852/certificates/serials
2016-09-21 05:13:15,083 [DEBUG] subscription-manager:11481:MainThread @connection.py:602 - Response: status=200, requestUuid=c71b37cd-4b25-4102-a685-719bf18b4bec
2016-09-21 05:13:15,084 [DEBUG] subscription-manager:11481:MainThread @connection.py:525 - Loaded CA certificates from /etc/rhsm/ca/: redhat-uep.pem
2016-09-21 05:13:15,084 [DEBUG] subscription-manager:11481:MainThread @connection.py:573 - Making request: GET /subscription/consumers/5b314817-77fb-4d2a-a8d4-541a8a3cf852/certificates?serials=2718907493359068982
2016-09-21 05:13:15,598 [DEBUG] subscription-manager:11481:MainThread @connection.py:602 - Response: status=200, requestUuid=3cdf1a05-9c54-45d1-928c-1b21084a08ce
2016-09-21 05:13:15,599 [DEBUG] subscription-manager:11481:MainThread @entcertlib.py:351 - Ent cert bundle pre_install
2016-09-21 05:13:15,605 [DEBUG] subscription-manager:11481:MainThread @entcertlib.py:373 - ent cert bundle post_install
2016-09-21 05:13:15,605 [DEBUG] subscription-manager:11481:MainThread @entcertlib.py:305 - cert bundles post_install: <rhsm.certificate2.EntitlementCertificate object at 0x2668f50>
2016-09-21 05:13:15,605 [INFO] subscription-manager:11481:MainThread @entcertlib.py:131 - certs updated:
Total updates: 1
Found (local) serial# []
Expected (UEP) serial# [2718907493359068982]


The refresh command completed successfully and the attached entitlement filewas successfully re-downloaded.

Below is the part of the rhsm.log demonstrating the "PUT with option ?lazy_regen=true" is completed 

2016-09-21 05:13:13,702 [DEBUG] subscription-manager:11481:MainThread @connection.py:573 - Making request: PUT /subscription/consumers/5b314817-77fb-4d2a-a8d4-541a8a3cf852/certificates?lazy_regen=true
2016-09-21 05:13:14,172 [DEBUG] subscription-manager:11481:MainThread @connection.py:602 - Response: status=204, requestUuid=8188fa9e-508e-4ba1-bcd0-d57c75467d0f
2016-09-21 05:13:14,173 [DEBUG] subscription-manager:11481:MainThread

Comment 16 Tramaine Darby 2016-09-29 13:41:24 UTC
This change has been migrated to production.

Comment 18 errata-xmlrpc 2016-11-03 20:30:34 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/RHSA-2016-2592.html