Bug 752878

Summary: 'subscription-manager register' tracebacks in DELETE /api/consumers/$id
Product: Red Hat Enterprise Linux 6 Reporter: Tom McKay <tomckay>
Component: subscription-managerAssignee: Bryan Kearney <bkearney>
Status: CLOSED WONTFIX QA Contact: IDM QE LIST <seceng-idm-qe-list>
Severity: unspecified Docs Contact:
Priority: unspecified    
Version: 6.2CC: cduryee, jsefler
Target Milestone: rc   
Target Release: 6.3   
Hardware: Unspecified   
OS: Unspecified   
Whiteboard:
Fixed In Version: Doc Type: Bug Fix
Doc Text:
Story Points: ---
Clone Of: Environment:
Last Closed: 2012-03-27 17:43:20 UTC Type: ---
Regression: --- Mount Type: ---
Documentation: --- CRM:
Verified Versions: Category: ---
oVirt Team: --- RHEL 7.3 requirements from Atomic Host:
Cloudforms Team: --- Target Upstream Version:
Bug Depends On:    
Bug Blocks: 738066    

Description Tom McKay 2011-11-10 17:26:38 UTC
Description of problem:

Calling
   % subscription-manager register --force ...
from system triggers an API call to
   /katello/api/consumers/<id> DELETE

If the system does not already exist, then errors are generated:
(note that the system registration does in fact work)

Started DELETE "/katello/api/consumers/45474d8c-6362-4819-863f-1a301a3eae95" for 10.11.230.117 at Thu Nov 10 12:06:36 -0500 2011
  Processing by Api::SystemsController#destroy as JSON
  Parameters: {"id"=>"45474d8c-6362-4819-863f-1a301a3eae95"}
Setting locale: en
Setting current user thread-local variable to 45474d8c-6362-4819-863f-1a301a3eae95
Setting current user thread-local variable to nil
*** ERROR: Couldn't find system '45474d8c-6362-4819-863f-1a301a3eae95' (404) ***
REQUEST URL: /katello/api/consumers/45474d8c-6362-4819-863f-1a301a3eae95
HttpErrors::NotFound: Couldn't find system '45474d8c-6362-4819-863f-1a301a3eae95'
/home/tomckay/code/katello/src/app/controllers/api/systems_controller.rb:202:in `find_system'


Version-Release number of selected component (if applicable):


How reproducible:


Steps to Reproduce:
1. clear all katello data (scripts/clear-all.sh)
2. 'subscription-manager --force' from a system
3.
  
Actual results:
Register w/ errors in log file

Expected results:
Register w/o errors in log file


Additional info:

Comment 2 Chris Duryee 2012-03-15 14:51:24 UTC
Tom,

I tested this by resetting my candlepin db after registering and doing a --force register, and it appears to be resolved. I assume it is from the 410 work.

Marking as modified, so QE can verify.

master 0.99.10

Comment 4 John Sefler 2012-03-21 17:08:16 UTC
Testing with....
[root@kvm-guest-05 ~]# rpm -q subscription-manager
subscription-manager-0.99.10-1.el6.x86_64


The complaint in comment 0 is not that the user was unable to register.  The complaint is that there are Tracebacks encountered in the logs.  From a user's perspective on the command line, the program is working well.  From an admin log sniffer's perspective, there was Tracebacks.  This is the complaint raised this bug.

Here's another recreate...

0.  starting with an unregistered client...
[root@kvm-guest-05 ~]# subscription-manager register --username admin --password admin --force
The system has been registered with id: 02f48f0d-5ef3-4e39-943b-ee87c7d98a9f
[root@kvm-guest-05 ~]# 

1. delete the consumer on the server...
[root@kvm-guest-05 ~]# curl -k -u admin:admin --request DELETE https://tomckay.usersys.redhat.com:3000/katello/api/consumers/02f48f0d-5ef3-4e39-943b-ee87c7d98a9f
[root@kvm-guest-05 ~]# 

2. register with force and tail the rhsm.log
[root@kvm-guest-05 ~]# subscription-manager register --username admin --password admin --force
The system has been registered with id: 0f37c4f7-7a2d-4544-acde-86d28d6e1328 
[root@kvm-guest-05 ~]# 

2012-03-21 12:53:16,252 [INFO]  @connection.py:487 - Using certificate authentication: key = /etc/pki/consumer/key.pem, cert = /etc/pki/consumer/cert.pem, ca = /etc/rhsm/ca/, insecure = True
2012-03-21 12:53:16,252 [INFO]  @connection.py:498 - Connection Built: host: tomckay.usersys.redhat.com, port: 3000, handler: /katello/api
2012-03-21 12:53:16,323 [DEBUG]  @connection.py:328 - Making request: DELETE /katello/api/consumers/02f48f0d-5ef3-4e39-943b-ee87c7d98a9f
2012-03-21 12:53:17,266 [DEBUG]  @connection.py:342 - Response status: 404
2012-03-21 12:53:17,267 [ERROR]  @managercli.py:722 - Unable to un-register consumer: 02f48f0d-5ef3-4e39-943b-ee87c7d98a9f
2012-03-21 12:53:17,267 [ERROR]  @managercli.py:723 - Couldn't find system '02f48f0d-5ef3-4e39-943b-ee87c7d98a9f'
Traceback (most recent call last):
  File "/usr/share/rhsm/subscription_manager/managercli.py", line 718, in _do_command
    managerlib.unregister(self.cp, old_uuid)
  File "/usr/share/rhsm/subscription_manager/managerlib.py", line 783, in unregister
    uep.unregisterConsumer(consumer_uuid)
  File "/usr/lib/python2.6/site-packages/rhsm/connection.py", line 653, in unregisterConsumer
    return self.conn.request_delete(method)
  File "/usr/lib/python2.6/site-packages/rhsm/connection.py", line 398, in request_delete
    return self._request("DELETE", method)
  File "/usr/lib/python2.6/site-packages/rhsm/connection.py", line 347, in _request
    self.validateResponse(result)
  File "/usr/lib/python2.6/site-packages/rhsm/connection.py", line 373, in validateResponse
    raise RestlibException(response['status'], error_msg)
RestlibException: Couldn't find system '02f48f0d-5ef3-4e39-943b-ee87c7d98a9f'
2012-03-21 12:53:17,269 [INFO]  @connection.py:476 - Using basic authentication as: admin
2012-03-21 12:53:17,269 [INFO]  @connection.py:498 - Connection Built: host: tomckay.usersys.redhat.com, port: 3000, handler: /katello/api
2012-03-21 12:53:17,270 [DEBUG]  @connection.py:328 - Making request: GET /katello/api/users/admin/owners
2012-03-21 12:53:18,194 [DEBUG]  @connection.py:342 - Response status: 200
2012-03-21 12:53:18,261 [DEBUG]  @cert_sorter.py:106 - Sorting product and entitlement cert status for: 2012-03-21 16:53:18.261237+00:00
2012-03-21 12:53:18,263 [DEBUG]  @cert_sorter.py:159 - Installed product IDs: ['69']
2012-03-21 12:53:18,264 [DEBUG]  @cert_sorter.py:112 - valid entitled products: []
2012-03-21 12:53:18,264 [DEBUG]  @cert_sorter.py:113 - expired entitled products: []
2012-03-21 12:53:18,264 [DEBUG]  @cert_sorter.py:114 - partially entitled products: []
2012-03-21 12:53:18,264 [DEBUG]  @cert_sorter.py:115 - unentitled products: ['69']
2012-03-21 12:53:18,265 [DEBUG]  @cert_sorter.py:116 - future products: []
2012-03-21 12:53:18,265 [DEBUG]  @cert_sorter.py:117 - partial stacks: []
2012-03-21 12:53:18,265 [DEBUG]  @cert_sorter.py:118 - valid stacks: []
2012-03-21 12:53:18,266 [DEBUG]  @connection.py:328 - Making request: POST /katello/api/consumers?owner=ACME_Corporation
2012-03-21 12:53:21,130 [DEBUG]  @connection.py:342 - Response status: 200
2012-03-21 12:53:21,133 [INFO]  @managerlib.py:74 - Consumer created: {'consumer_name': 'kvm-guest-05.rhts.eng.bos.redhat.com', 'uuid': '0f37c4f7-7a2d-4544-acde-86d28d6e1328'}
2012-03-21 12:53:21,136 [INFO]  @connection.py:487 - Using certificate authentication: key = /etc/pki/consumer/key.pem, cert = /etc/pki/consumer/cert.pem, ca = /etc/rhsm/ca/, insecure = True
2012-03-21 12:53:21,136 [INFO]  @connection.py:498 - Connection Built: host: tomckay.usersys.redhat.com, port: 3000, handler: /katello/api
2012-03-21 12:53:21,137 [DEBUG]  @connection.py:328 - Making request: GET /katello/api/
2012-03-21 12:53:21,818 [DEBUG]  @connection.py:342 - Response status: 200
2012-03-21 12:53:21,819 [DEBUG]  @connection.py:514 - Server supports the following resources:
2012-03-21 12:53:21,819 [DEBUG]  @connection.py:515 - {'templates': '/api/templates/', 'organizations': '/api/organizations/', 'tasks': '/api/tasks/', 'users': '/api/users/', 'roles': '/api/roles/', 'changesets': '/api/changesets/', 'providers': '/api/providers/', 'repositories': '/api/repositories/', 'environments': '/api/environments/', 'entitlements': '/api/entitlements/', 'systems': '/api/systems/', 'gpg_keys': '/api/gpg_keys/', 'activation_keys': '/api/activation_keys/', 'packages': '/api/packages/', 'consumers': '/api/consumers/'}
2012-03-21 12:53:21,819 [INFO]  @cache.py:160 - Checking current system info against cache: /var/lib/rhsm/packages/packages.json
2012-03-21 12:53:21,820 [DEBUG]  @profile.py:82 - Loading RPM profile from file.
2012-03-21 12:53:21,834 [DEBUG]  @profile.py:95 - Loading current RPM profile.
2012-03-21 12:53:22,480 [INFO]  @cache.py:162 - System data has changed, updating server.
2012-03-21 12:53:22,487 [DEBUG]  @connection.py:328 - Making request: PUT /katello/api/consumers/0f37c4f7-7a2d-4544-acde-86d28d6e1328/packages
2012-03-21 12:53:25,784 [DEBUG]  @connection.py:342 - Response status: 200

^^^^
ALTHOUGH THE USER SUCCESSFULLY REGISTERED THE SYSTEM WITH FORCE, THE LOG CONTAINS A TRACEBACK.  THAT'S THE COMPLAINT.




REGARDING THE 410 WORK, THIS CASE ALSO PROCEEDS SUCCESSFULLY, BUT LOGS A TRACEBACK TOO.....

3. Now delete the system onthe server
[root@kvm-guest-05 ~]# curl -k -u admin:admin --request DELETE https://tomckay.usersys.redhat.com:3000/katello/api/consumers/0f37c4f7-7a2d-4544-acde-86d28d6e1328 
[root@kvm-guest-05 ~]# 

4. and execute identity to see the 410 response from the server with a Traceback appended to the rhsm.log...
4. AND RUN IDENTITY TO SEE THE 410 RESPONSE IN THE rhsm.log WITH A TRACEBACK
[root@kvm-guest-05 ~]# subscription-manager identity
Consumer 0f37c4f7-7a2d-4544-acde-86d28d6e1328 has been deleted
[root@kvm-guest-05 ~]# 

2012-03-21 12:59:45,662 [INFO]  @connection.py:487 - Using certificate authentication: key = /etc/pki/consumer/key.pem, cert = /etc/pki/consumer/cert.pem, ca = /etc/rhsm/ca/, insecure = True
2012-03-21 12:59:45,662 [INFO]  @connection.py:498 - Connection Built: host: tomckay.usersys.redhat.com, port: 3000, handler: /katello/api
2012-03-21 12:59:45,667 [DEBUG]  @connection.py:328 - Making request: GET /katello/api/consumers/0f37c4f7-7a2d-4544-acde-86d28d6e1328/owner
2012-03-21 12:59:46,462 [DEBUG]  @connection.py:342 - Response status: 410
2012-03-21 12:59:46,462 [ERROR]  @managercli.py:432 - Consumer 0f37c4f7-7a2d-4544-acde-86d28d6e1328 has been deleted
Traceback (most recent call last):
  File "/usr/share/rhsm/subscription_manager/managercli.py", line 411, in _do_command
    owner = self.cp.getOwner(consumerid)
  File "/usr/lib/python2.6/site-packages/rhsm/connection.py", line 639, in getOwner
    return self.conn.request_get(method)
  File "/usr/lib/python2.6/site-packages/rhsm/connection.py", line 386, in request_get
    return self._request("GET", method)
  File "/usr/lib/python2.6/site-packages/rhsm/connection.py", line 347, in _request
    self.validateResponse(result)
  File "/usr/lib/python2.6/site-packages/rhsm/connection.py", line 370, in validateResponse
    response['candlepin_version'])
GoneException: Consumer 0f37c4f7-7a2d-4544-acde-86d28d6e1328 has been deleted
2012-03-21 12:59:46,464 [ERROR]  @managercli.py:433 - Error: Unable to generate a new identity for the system: Consumer 0f37c4f7-7a2d-4544-acde-86d28d6e1328 has been deleted


^^^ A TRACEBACK IS LOGGED WITH THE 410 RESPONSE TOO.


At this point we are looking for a response of "Working as designed and Tracebacks in the rhsm.log are acceptable" or "will catch the traceback before dumping it to the log."

Moving back to NEW for a second look.