Description of problem: virt-who authenticates to Satellite as a consumer. A CpConsumerUser doesn't have rights to view content views or environments, so it is unable to update the hypervisors' subscriptions Version-Release number of selected component (if applicable): 6.0.4 GA How reproducible: Always Steps to Reproduce: 1. Configure virt-who against a vmware esx server 2. Attempt to have it update subscriptions Actual results: Fails: [ERROR 2014-09-16 16:01:48 cp_proxy #9044] *** ERROR: Access denied (403) *** [ERROR 2014-09-16 16:01:48 cp_proxy #9044] REQUEST URL: /rhsm/hypervisors?owner=3&env=Library [ERROR 2014-09-16 16:01:48 cp_proxy #9044] Katello::HttpErrors::Forbidden: Access denied | /opt/rh/ruby193/root/usr/share/gems/gems/katello-1.5.0/app/controllers/katello/api/rhsm/candlepin_proxies_controller.rb:270:in `deny_access' | /opt/rh/ruby193/root/usr/share/gems/gems/katello-1.5.0/app/controllers/katello/api/rhsm/candlepin_proxies_controller.rb:376:in `get_content_view_environment' | /opt/rh/ruby193/root/usr/share/gems/gems/katello-1.5.0/app/controllers/katello/api/rhsm/candlepin_proxies_controller.rb:368:in `get_content_view_environment_by_label' | /opt/rh/ruby193/root/usr/share/gems/gems/katello-1.5.0/app/controllers/katello/api/rhsm/candlepin_proxies_controller.rb:305:in `find_hypervisor_environment_and_content_view' | /opt/rh/ruby193/root/usr/share/gems/gems/activesupport-3.2.8/lib/active_support/callbacks.rb:575:in `block (3 levels) in _run__3175478619362221649__process_action__452376957109696339__callbacks' | /opt/rh/ruby193/root/usr/share/gems/gems/activesupport-3.2.8/lib/active_support/callbacks.rb:215:in `block in _conditional_callback_around_9919' | /opt/rh/ruby193/root/usr/share/gems/gems/activesupport-3.2.8/lib/active_support/callbacks.rb:326:in `around' | /opt/rh/ruby193/root/usr/share/gems/gems/activesupport-3.2.8/lib/active_support/callbacks.rb:310:in `_callback_around_3602' | /opt/rh/ruby193/root/usr/share/gems/gems/activesupport-3.2.8/lib/active_support/callbacks.rb:214:in `_conditional_callback_around_9919' | /opt/rh/ruby193/root/usr/share/gems/gems/activesupport-3.2.8/lib/active_support/callbacks.rb:471:in `block (2 levels) in _run__3175478619362221649__process_action__452376957109696339__callbacks' | /opt/rh/ruby193/root/usr/share/gems/gems/activesupport-3.2.8/lib/active_support/callbacks.rb:215:in `block in _conditional_callback_around_9918' | /usr/share/foreman/app/models/concerns/foreman/thread_session.rb:33:in `clear_thread' | /opt/rh/ruby193/root/usr/share/gems/gems/activesupport-3.2.8/lib/active_support/callbacks.rb:214:in `_conditional_callback_around_9918' | /opt/rh/ruby193/root/usr/share/gems/gems/activesupport-3.2.8/lib/active_support/callbacks.rb:426:in `block in _run__3175478619362221649__process_action__452376957109696339__callbacks' | /opt/rh/ruby193/root/usr/share/gems/gems/activesupport-3.2.8/lib/active_support/callbacks.rb:215:in `block in _conditional_callback_around_9917' | /opt/rh/ruby193/root/usr/share/gems/gems/activesupport-3.2.8/lib/active_support/callbacks.rb:326:in `around' | /opt/rh/ruby193/root/usr/share/gems/gems/activesupport-3.2.8/lib/active_support/callbacks.rb:310:in `_callback_around_13' | /opt/rh/ruby193/root/usr/share/gems/gems/activesupport-3.2.8/lib/active_support/callbacks.rb:214:in `_conditional_callback_around_9917' | /opt/rh/ruby193/root/usr/share/gems/gems/activesupport-3.2.8/lib/active_support/callbacks.rb:414:in `_run__3175478619362221649__process_action__452376957109696339__callbacks' | /opt/rh/ruby193/root/usr/share/gems/gems/activesupport-3.2.8/lib/active_support/callbacks.rb:405:in `__run_callback' | /opt/rh/ruby193/root/usr/share/gems/gems/activesupport-3.2.8/lib/active_support/callbacks.rb:385:in `_run_process_action_callbacks' | /opt/rh/ruby193/root/usr/share/gems/gems/activesupport-3.2.8/lib/active_support/callbacks.rb:81:in `run_callbacks' | /opt/rh/ruby193/root/usr/share/gems/gems/actionpack-3.2.8/lib/abstract_controller/callbacks.rb:17:in `process_action' | /opt/rh/ruby193/root/usr/share/gems/gems/actionpack-3.2.8/lib/action_controller/metal/rescue.rb:29:in `process_action' | /opt/rh/ruby193/root/usr/share/gems/gems/actionpack-3.2.8/lib/action_controller/metal/instrumentation.rb:30:in `block in process_action' | /opt/rh/ruby193/root/usr/share/gems/gems/activesupport-3.2.8/lib/active_support/notifications.rb:123:in `block in instrument' | /opt/rh/ruby193/root/usr/share/gems/gems/activesupport-3.2.8/lib/active_support/notifications/instrumenter.rb:20:in `instrument' | /opt/rh/ruby193/root/usr/share/gems/gems/activesupport-3.2.8/lib/active_support/notifications.rb:123:in `instrument' | /opt/rh/ruby193/root/usr/share/gems/gems/actionpack-3.2.8/lib/action_controller/metal/instrumentation.rb:29:in `process_action' | /opt/rh/ruby193/root/usr/share/gems/gems/actionpack-3.2.8/lib/action_controller/metal/params_wrapper.rb:207:in `process_action' | /opt/rh/ruby193/root/usr/share/gems/gems/activerecord-3.2.8/lib/active_record/railties/controller_runtime.rb:18:in `process_action' | /opt/rh/ruby193/root/usr/share/gems/gems/katello-1.5.0/app/controllers/katello/api/api_controller.rb:61:in `process_action' | /opt/rh/ruby193/root/usr/share/gems/gems/actionpack-3.2.8/lib/abstract_controller/base.rb:121:in `process' | /opt/rh/ruby193/root/usr/share/gems/gems/actionpack-3.2.8/lib/abstract_controller/rendering.rb:45:in `process' | /opt/rh/ruby193/root/usr/share/gems/gems/actionpack-3.2.8/lib/action_controller/metal.rb:203:in `dispatch' | /opt/rh/ruby193/root/usr/share/gems/gems/actionpack-3.2.8/lib/action_controller/metal/rack_delegation.rb:14:in `dispatch' | /opt/rh/ruby193/root/usr/share/gems/gems/actionpack-3.2.8/lib/action_controller/metal.rb:246:in `block in action' | /opt/rh/ruby193/root/usr/share/gems/gems/actionpack-3.2.8/lib/action_dispatch/routing/route_set.rb:73:in `call' | /opt/rh/ruby193/root/usr/share/gems/gems/actionpack-3.2.8/lib/action_dispatch/routing/route_set.rb:73:in `dispatch' | /opt/rh/ruby193/root/usr/share/gems/gems/actionpack-3.2.8/lib/action_dispatch/routing/route_set.rb:36:in `call' | /opt/rh/ruby193/root/usr/share/gems/gems/journey-1.0.4/lib/journey/router.rb:68:in `block in call' | /opt/rh/ruby193/root/usr/share/gems/gems/journey-1.0.4/lib/journey/router.rb:56:in `each' | /opt/rh/ruby193/root/usr/share/gems/gems/journey-1.0.4/lib/journey/router.rb:56:in `call' | /opt/rh/ruby193/root/usr/share/gems/gems/actionpack-3.2.8/lib/action_dispatch/routing/route_set.rb:600:in `call' | /opt/rh/ruby193/root/usr/share/gems/gems/railties-3.2.8/lib/rails/engine.rb:479:in `call' | /opt/rh/ruby193/root/usr/share/gems/gems/railties-3.2.8/lib/rails/railtie/configurable.rb:30:in `method_missing' | /opt/rh/ruby193/root/usr/share/gems/gems/journey-1.0.4/lib/journey/router.rb:68:in `block in call' | /opt/rh/ruby193/root/usr/share/gems/gems/journey-1.0.4/lib/journey/router.rb:56:in `each' | /opt/rh/ruby193/root/usr/share/gems/gems/journey-1.0.4/lib/journey/router.rb:56:in `call' | /opt/rh/ruby193/root/usr/share/gems/gems/actionpack-3.2.8/lib/action_dispatch/routing/route_set.rb:600:in `call' | /opt/rh/ruby193/root/usr/share/gems/gems/actionpack-3.2.8/lib/action_dispatch/middleware/static.rb:62:in `call' | /opt/rh/ruby193/root/usr/share/gems/gems/apipie-rails-0.2.5/lib/apipie/static_dispatcher.rb:65:in `call' | /opt/rh/ruby193/root/usr/share/gems/gems/apipie-rails-0.2.5/lib/apipie/extractor/recorder.rb:97:in `call' | /opt/rh/ruby193/root/usr/share/gems/gems/actionpack-3.2.8/lib/action_dispatch/middleware/static.rb:62:in `call' | /opt/rh/ruby193/root/usr/share/gems/gems/actionpack-3.2.8/lib/action_dispatch/middleware/static.rb:62:in `call' | /opt/rh/ruby193/root/usr/share/gems/gems/apipie-rails-0.2.5/lib/apipie/middleware/checksum_in_headers.rb:27:in `call' | /opt/rh/ruby193/root/usr/share/gems/gems/actionpack-3.2.8/lib/action_dispatch/middleware/best_standards_support.rb:17:in `call' | /opt/rh/ruby193/root/usr/share/gems/gems/rack-1.4.1/lib/rack/etag.rb:23:in `call' | /opt/rh/ruby193/root/usr/share/gems/gems/rack-1.4.1/lib/rack/conditionalget.rb:35:in `call' | /opt/rh/ruby193/root/usr/share/gems/gems/actionpack-3.2.8/lib/action_dispatch/middleware/head.rb:14:in `call' | /opt/rh/ruby193/root/usr/share/gems/gems/actionpack-3.2.8/lib/action_dispatch/middleware/params_parser.rb:21:in `call' | /usr/share/foreman/lib/middleware/catch_json_parse_errors.rb:9:in `call' | /opt/rh/ruby193/root/usr/share/gems/gems/actionpack-3.2.8/lib/action_dispatch/middleware/flash.rb:242:in `call' | /opt/rh/ruby193/root/usr/share/gems/gems/rack-1.4.1/lib/rack/session/abstract/id.rb:205:in `context' | /opt/rh/ruby193/root/usr/share/gems/gems/rack-1.4.1/lib/rack/session/abstract/id.rb:200:in `call' | /opt/rh/ruby193/root/usr/share/gems/gems/actionpack-3.2.8/lib/action_dispatch/middleware/cookies.rb:339:in `call' | /opt/rh/ruby193/root/usr/share/gems/gems/activerecord-3.2.8/lib/active_record/query_cache.rb:64:in `call' | /opt/rh/ruby193/root/usr/share/gems/gems/activerecord-3.2.8/lib/active_record/connection_adapters/abstract/connection_pool.rb:473:in `call' | /opt/rh/ruby193/root/usr/share/gems/gems/actionpack-3.2.8/lib/action_dispatch/middleware/callbacks.rb:28:in `block in call' | /opt/rh/ruby193/root/usr/share/gems/gems/activesupport-3.2.8/lib/active_support/callbacks.rb:405:in `_run__1648421426099683854__call__862972201031679027__callbacks' | /opt/rh/ruby193/root/usr/share/gems/gems/activesupport-3.2.8/lib/active_support/callbacks.rb:405:in `__run_callback' | /opt/rh/ruby193/root/usr/share/gems/gems/activesupport-3.2.8/lib/active_support/callbacks.rb:385:in `_run_call_callbacks' | /opt/rh/ruby193/root/usr/share/gems/gems/activesupport-3.2.8/lib/active_support/callbacks.rb:81:in `run_callbacks' | /opt/rh/ruby193/root/usr/share/gems/gems/actionpack-3.2.8/lib/action_dispatch/middleware/callbacks.rb:27:in `call' | /opt/rh/ruby193/root/usr/share/gems/gems/actionpack-3.2.8/lib/action_dispatch/middleware/remote_ip.rb:31:in `call' | /opt/rh/ruby193/root/usr/share/gems/gems/actionpack-3.2.8/lib/action_dispatch/middleware/debug_exceptions.rb:16:in `call' | /opt/rh/ruby193/root/usr/share/gems/gems/actionpack-3.2.8/lib/action_dispatch/middleware/show_exceptions.rb:56:in `call' | /opt/rh/ruby193/root/usr/share/gems/gems/katello-1.5.0/lib/katello/middleware/silenced_logger.rb:30:in `call' | /opt/rh/ruby193/root/usr/share/gems/gems/actionpack-3.2.8/lib/action_dispatch/middleware/request_id.rb:22:in `call' | /opt/rh/ruby193/root/usr/share/gems/gems/rack-1.4.1/lib/rack/methodoverride.rb:21:in `call' | /opt/rh/ruby193/root/usr/share/gems/gems/rack-1.4.1/lib/rack/runtime.rb:17:in `call' | /opt/rh/ruby193/root/usr/share/gems/gems/activesupport-3.2.8/lib/active_support/cache/strategy/local_cache.rb:72:in `call' | /opt/rh/ruby193/root/usr/share/gems/gems/rack-1.4.1/lib/rack/lock.rb:15:in `call' | /opt/rh/ruby193/root/usr/share/gems/gems/actionpack-3.2.8/lib/action_dispatch/middleware/static.rb:62:in `call' | /opt/rh/ruby193/root/usr/share/gems/gems/rack-cache-1.2/lib/rack/cache/context.rb:136:in `forward' | /opt/rh/ruby193/root/usr/share/gems/gems/rack-cache-1.2/lib/rack/cache/context.rb:143:in `pass' | /opt/rh/ruby193/root/usr/share/gems/gems/rack-cache-1.2/lib/rack/cache/context.rb:155:in `invalidate' | /opt/rh/ruby193/root/usr/share/gems/gems/rack-cache-1.2/lib/rack/cache/context.rb:71:in `call!' | /opt/rh/ruby193/root/usr/share/gems/gems/rack-cache-1.2/lib/rack/cache/context.rb:51:in `call' | /opt/rh/ruby193/root/usr/share/gems/gems/railties-3.2.8/lib/rails/engine.rb:479:in `call' | /opt/rh/ruby193/root/usr/share/gems/gems/railties-3.2.8/lib/rails/application.rb:223:in `call' | /opt/rh/ruby193/root/usr/share/gems/gems/railties-3.2.8/lib/rails/railtie/configurable.rb:30:in `method_missing' | /opt/rh/ruby193/root/usr/share/gems/gems/rack-1.4.1/lib/rack/builder.rb:134:in `call' | /opt/rh/ruby193/root/usr/share/gems/gems/rack-1.4.1/lib/rack/urlmap.rb:64:in `block in call' | /opt/rh/ruby193/root/usr/share/gems/gems/rack-1.4.1/lib/rack/urlmap.rb:49:in `each' | /opt/rh/ruby193/root/usr/share/gems/gems/rack-1.4.1/lib/rack/urlmap.rb:49:in `call' | /usr/lib/ruby/gems/1.8/gems/passenger-4.0.18/lib/phusion_passenger/rack/thread_handler_extension.rb:77:in `process_request' | /usr/lib/ruby/gems/1.8/gems/passenger-4.0.18/lib/phusion_passenger/request_handler/thread_handler.rb:140:in `accept_and_process_next_request' | /usr/lib/ruby/gems/1.8/gems/passenger-4.0.18/lib/phusion_passenger/request_handler/thread_handler.rb:108:in `main_loop' | /usr/lib/ruby/gems/1.8/gems/passenger-4.0.18/lib/phusion_passenger/request_handler.rb:441:in `block (3 levels) in start_threads' | /opt/rh/ruby193/root/usr/share/gems/gems/logging-1.8.1/lib/logging/diagnostic_context.rb:323:in `call' | /opt/rh/ruby193/root/usr/share/gems/gems/logging-1.8.1/lib/logging/diagnostic_context.rb:323:in `block in create_with_logging_context' Completed 403 Forbidden in 42ms (Views: 0.5ms | ActiveRecord: 6.9ms) Processing by Katello::Api::Rhsm::CandlepinProxiesController#server_status as JSON Parameters: {"candlepin_proxy"=>{}} Completed 200 OK in 144ms (Views: 0.8ms | ActiveRecord: 0.0ms) Expected results: Update succeeds Additional info:
One more note, even if you do bypass the above permission error, the problem seems deeper: ERROR: Error in communication with subscription manager, trying to recover: Traceback (most recent call last): File "/usr/share/virt-who/virt-who.py", line 207, in _send result = self.subscriptionManager.hypervisorCheckIn(self.options.owner, self.options.env, virtualGuests, type=self.options.virtType) File "/usr/share/virt-who/subscriptionmanager.py", line 112, in hypervisorCheckIn return self.connection.hypervisorCheckIn(owner, env, mapping) File "/usr/lib64/python2.7/site-packages/rhsm/connection.py", line 755, in hypervisorCheckIn return self.conn.request_post(url, host_guest_mapping) File "/usr/lib64/python2.7/site-packages/rhsm/connection.py", line 557, in request_post return self._request("POST", method, params) 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 524, in validateResponse raise RestlibException(response['status'], error_msg) RestlibException: Runtime Error com.fasterxml.jackson.databind.JsonMappingException: Can not deserialize instance of java.util.ArrayList out of START_OBJECT token at [Source: org.candlepin.common.filter.TeeHttpServletRequest$1@16831f1e; line: 1, column: 2754] at com.fasterxml.jackson.databind.JsonMappingException.from:164
Can we get katello-debug output attached please.
Regarding the problem in comment #3: Using the virt-whom debug tool to replicate: sudo virt-whom -H dgoodhypervisor:7e0f0d93-127a-988c-f6c0-6682ef5cf16a -e Library A request is sent from the client with this body: POST /rhsm/hypervisors?owner=72&env=Library {'dgoodhypervisor': [{'guestId': '7e0f0d93-127a-988c-f6c0-6682ef5cf16a', 'attributes': {'virtWhoType': 'manual'}}]} Foreman logs: Processing by Katello::Api::Rhsm::CandlepinProxiesController#hypervisors_update as JSON Parameters: {"dgoodhypervisor"=>[{"guestId"=>"7e0f0d93-127a-988c-f6c0-6682ef5cf16a", "attributes"=>{"virtWhoType"=>"manual"}}], "owner"=>"72", "env"=>"Library", "candlepin_proxy"=>{"dgoodhyperviso r"=>[{"guestId"=>"7e0f0d93-127a-988c-f6c0-6682ef5cf16a", "attributes"=>{"virtWhoType"=>"manual"}}]}} And candlepin receives this request body: {"dgoodhypervisor":[{"guestId":"7e0f0d93-127a-988c-f6c0-6682ef5cf16a","attributes":{"virtWhoType":"manual"}}],"candlepin_proxy":{"dgoodhypervisor":[{"guestId":"7e0f0d93-127a-988c-f6c0-6682ef5cf16a", "attributes":{"virtWhoType":"manual"}}]},"organization_id":"72"} The keys "candlepin_proxy" and "organization_id" were not sent by the client, and are almost surely causing this problem as the API call expects a mapping of host IDs to a list of records for the guests, in this case it thinks these two unknown keys are host IDs that map to a list of hashes, which they do not. Something is wonky in the Katello layer proxying this call. NOTE: dgoodhypervisor is just a dummy hypervisor ID.
Bad feeling once you get this fixed, you're going to hit a third problem. The API call expects the query parameter owner to be what we call the owner "key", which I believe is Satellite's org label. Satellite code is interpreting it as a numeric DB ID, which the customer config above is bypassing by using VIRTWHO_ESX_OWNER=3. Once we fix the auth issue, and the JSON issue, we will hit Candlepin code that tries to look up the owner, and find nothing, as we have no knowledge of that ID in our database. Satellite code should interpret that owner param as a label, not a numeric db ID.
Created redmine issue http://projects.theforeman.org/issues/7521 from this bug
Upstream bug assigned to stbenjam
Committed upstream: katello|0666cd5f6e5d80a9d557fbde77611113dc85fe67
To reproduce the error: 1. Register a host to Satellite with subscription-manager 2. Setup virt-who against ESX, or use the virt-whom debug tool 3. Have virt-who or virt-whom report subscription usage to Satellite e.g. "virt-whom -H dgoodhypervisor:7e0f0d93-127a-988c-f6c0-6682ef5cf16a -e Library" You will see in /var/log/foreman/production.og an error: [ERROR 2014-09-19 09:26:35 cp_proxy] Katello::HttpErrors::NotFound: Couldn't find organization 'Default_Organization' | /home/stbenjam/katello/app/controllers/katello/api/v2/api_controller.rb:135:in `find_optional_organization' To confirm the patch works, do the above again on a patched Satellite, but this time it will succeed: Processing by Katello::Api::Rhsm::CandlepinProxiesController#hypervisors_update as JSON Parameters: {"dgoodhypervisor"=>[{"guestId"=>"7e0f0d93-127a-988c-f6c0-6682ef5cf16a", "attributes"=>{"virtWhoType"=>"manual"}}], "owner"=>"Default_Organization", "env"=>"Library"} [...] [DEBUG 2014-09-19 09:31:22 cp_rest] Processing response: 200
Verified with following testing env [1], hypervisor subscriptions can be updated in Satellite normally and listing the guests on the hypervisor works well, the /var/log/foreman/production.log also shows correct log like [2], so move this bug to VERIFIED. Thanks! [1] Testing Env RHEL-6.6-20140918.0-Server-x86_64(with virt-who-0.10-8.el6.noarch) ESX5.5 Satellite 6.0(patched with the build of the errata 18858), [2] Log info - /var/log/foreman/production.log Processing by Katello::Api::Rhsm::CandlepinProxiesController#hypervisors_update as JSON Parameters: {"aee4ff00-8c33-11e2-994a-6c3be51d959a"=>["564d15f6-ec87-12de-53b0-8097fccf069f", "423a0bfc-32b3-fcc8-5bef-e5e78a7aaee1"], "owner"=>"Default_Organization", "env"=>"Library"} Completed 200 OK in 565ms (Views: 2.5ms | ActiveRecord: 14.1ms)
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-2014-1283.html
> http://rhn.redhat.com/errata/RHBA-2014-1283.html URL correction: https://access.redhat.com/errata/RHBA-2014:1283
*** Bug 1128623 has been marked as a duplicate of this bug. ***