Note: This is a beta release of Red Hat Bugzilla 5.0. The data contained within is a snapshot of the live data so any changes you make will not be reflected in the production Bugzilla. Also email is disabled so feel free to test any aspect of the site that you want. File any problems you find or give feedback here.
Bug 1510658 - when doing sub-man unregister on 20 hosts in parallel: Failed Candlepin Event: undefined method `id' for nil:NilClass
Summary: when doing sub-man unregister on 20 hosts in parallel: Failed Candlepin Event...
Keywords:
Status: CLOSED WONTFIX
Alias: None
Product: Red Hat Satellite 6
Classification: Red Hat
Component: Registration
Version: 6.3.0
Hardware: Unspecified
OS: Unspecified
unspecified
medium vote
Target Milestone: Unspecified
Assignee: satellite6-bugs
QA Contact: Katello QA List
URL:
Whiteboard:
Depends On:
Blocks:
TreeView+ depends on / blocked
 
Reported: 2017-11-07 23:00 UTC by Jan Hutař
Modified: 2019-04-01 20:27 UTC (History)
5 users (show)

Fixed In Version:
Doc Type: If docs needed, set a value
Doc Text:
Clone Of:
Environment:
Last Closed: 2019-02-07 12:03:47 UTC


Attachments (Terms of Use)

Description Jan Hutař 2017-11-07 23:00:26 UTC
Description of problem:
There is "Failed Candlepin Event: undefined method `id' for nil:NilClass" error in production.log when I run `subscription-manager unregister` on 20 hosts in parallel


Version-Release number of selected component (if applicable):
satellite-6.3.0-21.0.beta.el7sat.noarch (snap 24)


How reproducible:
always


Steps to Reproduce:
1. In parallel, run `subscription-manager unregister` registered to Satellite


Actual results:
2017-11-07 16:52:48  [foreman-tasks/action] [E] Failed Candlepin Event: Katello::Resources::Candlepin::Pool: 404 Resource Not Found {"displayMessage":"Pool with id 4028fad85f965a62015f9697795c2024 could not be found.","requestUuid":"a44c831f-937c-47ea-abf5-f56725b16a66"} (GET /candlepin/pools/4028fad85f965a62015f9697795c2024)
2017-11-07 16:52:48  [foreman-tasks/action] [E] /opt/theforeman/tfm/root/usr/share/gems/gems/rest-client-1.8.0/lib/restclient/abstract_response.rb:74:in `return!'\n/opt/theforeman/tfm/root/usr/share/gems/gems/rest-client-1.8.0/lib/restclient/request.rb:495:in `process_result'\n/opt/theforeman/tfm/root/usr/share/gems/gems/rest-client-1.8.0/lib/restclient/request.rb:421:in `block in transmit'\n/opt/rh/rh-ruby23/root/usr/share/ruby/net/http.rb:853:in `start'\n/opt/theforeman/tfm/root/usr/share/gems/gems/rest-client-1.8.0/lib/restclient/request.rb:413:in `transmit'\n/opt/theforeman/tfm/root/usr/share/gems/gems/rest-client-1.8.0/lib/restclient/request.rb:176:in `execute'\n/opt/theforeman/tfm/root/usr/share/gems/gems/rest-client-1.8.0/lib/restclient/request.rb:41:in `execute'\n/opt/theforeman/tfm/root/usr/share/gems/gems/rest-client-1.8.0/lib/restclient/resource.rb:51:in `get'\n/opt/theforeman/tfm/root/usr/share/gems/gems/katello-3.4.5.25/app/lib/katello/http_resource.rb:84:in `get'\n/opt/theforeman/tfm/root/usr/share/gems/gems/katello-3.4.5.25/app/lib/katello/resources/candlepin.rb:539:in `find'\n/opt/theforeman/tfm/root/usr/share/gems/gems/katello-3.4.5.25/app/models/katello/glue/candlepin/pool.rb:27:in `candlepin_data'\n/opt/theforeman/tfm/root/usr/share/gems/gems/katello-3.4.5.25/app/models/katello/glue/candlepin/pool.rb:83:in `backend_data'\n/opt/theforeman/tfm/root/usr/share/gems/gems/katello-3.4.5.25/app/models/katello/glue/candlepin/pool.rb:99:in `import_data'\n/opt/theforeman/tfm/root/usr/share/gems/gems/katello-3.4.5.25/app/models/katello/glue/candlepin/pool.rb:39:in `import_pool'\n/opt/theforeman/tfm/root/usr/share/gems/gems/katello-3.4.5.25/app/services/katello/candlepin/message_handler.rb:71:in `import_pool'\n/opt/theforeman/tfm/root/usr/share/gems/gems/katello-3.4.5.25/app/services/katello/candlepin/message_handler.rb:84:in `import_pool_by_entity_id'\n/opt/theforeman/tfm/root/usr/share/gems/gems/katello-3.4.5.25/app/lib/actions/candlepin/import_pool_handler.rb:26:in `handle'\n/opt/theforeman/tfm/root/usr/share/gems/gems/katello-3.4.5.25/app/lib/actions/candlepin/listen_on_candlepin_events.rb:183:in `act_on_event'\n/opt/theforeman/tfm/root/usr/share/gems/gems/katello-3.4.5.25/app/lib/actions/candlepin/listen_on_candlepin_events.rb:90:in `block in run'\n/opt/theforeman/tfm/root/usr/share/gems/gems/algebrick-0.7.3/lib/algebrick/matchers/abstract.rb:74:in `block in assigns'\n/opt/theforeman/tfm/root/usr/share/gems/gems/algebrick-0.7.3/lib/algebrick/matchers/abstract.rb:73:in `tap'\n/opt/theforeman/tfm/root/usr/share/gems/gems/algebrick-0.7.3/lib/algebrick/matchers/abstract.rb:73:in `assigns'\n/opt/theforeman/tfm/root/usr/share/gems/gems/algebrick-0.7.3/lib/algebrick/matching.rb:56:in `match_value'\n/opt/theforeman/tfm/root/usr/share/gems/gems/algebrick-0.7.3/lib/algebrick/matching.rb:36:in `block in match?'\n/opt/theforeman/tfm/root/usr/share/gems/gems/algebrick-0.7.3/lib/algebrick/matching.rb:35:in `each'\n/opt/theforeman/tfm/root/usr/share/gems/gems/algebrick-0.7.3/lib/algebrick/matching.rb:35:in `match?'\n/opt/theforeman/tfm/root/usr/share/gems/gems/algebrick-0.7.3/lib/algebrick/matching.rb:23:in `match'\n/opt/theforeman/tfm/root/usr/share/gems/gems/katello-3.4.5.25/app/lib/actions/candlepin/listen_on_candlepin_events.rb:77:in `run'\n/opt/theforeman/tfm/root/usr/share/gems/gems/dynflow-0.8.30/lib/dynflow/action.rb:513:in `block (3 levels) in execute_run'\n/opt/theforeman/tfm/root/usr/share/gems/gems/dynflow-0.8.30/lib/dynflow/middleware/stack.rb:26:in `pass'\n/opt/theforeman/tfm/root/usr/share/gems/gems/dynflow-0.8.30/lib/dynflow/middleware.rb:17:in `pass'\n/opt/theforeman/tfm/root/usr/share/gems/gems/dynflow-0.8.30/lib/dynflow/action/progress.rb:30:in `with_progress_calculation'\n/opt/theforeman/tfm/root/usr/share/gems/gems/dynflow-0.8.30/lib/dynflow/action/progress.rb:16:in `run'\n/opt/theforeman/tfm/root/usr/share/gems/gems/dynflow-0.8.30/lib/dynflow/middleware/stack.rb:22:in `call'\n/opt/theforeman/tfm/root/usr/share/gems/gems/dynflow-0.8.30/lib/dynflow/middleware/stack.rb:26:in `pass'\n/opt/theforeman/tfm/root/usr/share/gems/gems/dynflow-0.8.30/lib/dynflow/middleware.rb:17:in `pass'\n/opt/theforeman/tfm/root/usr/share/gems/gems/katello-3.4.5.25/app/lib/actions/middleware/keep_locale.rb:11:in `block in run'\n/opt/theforeman/tfm/root/usr/share/gems/gems/katello-3.4.5.25/app/lib/actions/middleware/keep_locale.rb:22:in `with_locale'\n/opt/theforeman/tfm/root/usr/share/gems/gems/katello-3.4.5.25/app/lib/actions/middleware/keep_locale.rb:11:in `run'\n/opt/theforeman/tfm/root/usr/share/gems/gems/dynflow-0.8.30/lib/dynflow/middleware/stack.rb:22:in `call'\n/opt/theforeman/tfm/root/usr/share/gems/gems/dynflow-0.8.30/lib/dynflow/middleware/stack.rb:26:in `pass'\n/opt/theforeman/tfm/root/usr/share/gems/gems/dynflow-0.8.30/lib/dynflow/middleware.rb:17:in `pass'\n/opt/theforeman/tfm/root/usr/share/gems/gems/dynflow-0.8.30/lib/dynflow/middleware.rb:30:in `run'\n/opt/theforeman/tfm/root/usr/share/gems/gems/dynflow-0.8.30/lib/dynflow/middleware/stack.rb:22:in `call'\n/opt/theforeman/tfm/root/usr/share/gems/gems/dynflow-0.8.30/lib/dynflow/middleware/world.rb:30:in `execute'\n/opt/theforeman/tfm/root/usr/share/gems/gems/dynflow-0.8.30/lib/dynflow/action.rb:512:in `block (2 levels) in execute_run'\n/opt/theforeman/tfm/root/usr/share/gems/gems/dynflow-0.8.30/lib/dynflow/action.rb:511:in `catch'\n/opt/theforeman/tfm/root/usr/share/gems/gems/dynflow-0.8.30/lib/dynflow/action.rb:511:in `block in execute_run'\n/opt/theforeman/tfm/root/usr/share/gems/gems/dynflow-0.8.30/lib/dynflow/action.rb:426:in `block in with_error_handling'\n/opt/theforeman/tfm/root/usr/share/gems/gems/dynflow-0.8.30/lib/dynflow/action.rb:426:in `catch'\n/opt/theforeman/tfm/root/usr/share/gems/gems/dynflow-0.8.30/lib/dynflow/action.rb:426:in `with_error_handling'\n/opt/theforeman/tfm/root/usr/share/gems/gems/dynflow-0.8.30/lib/dynflow/action.rb:506:in `execute_run'\n/opt/theforeman/tfm/root/usr/share/gems/gems/dynflow-0.8.30/lib/dynflow/action.rb:267:in `execute'\n/opt/theforeman/tfm/root/usr/share/gems/gems/dynflow-0.8.30/lib/dynflow/execution_plan/steps/abstract_flow_step.rb:9:in `block (2 levels) in execute'\n/opt/theforeman/tfm/root/usr/share/gems/gems/dynflow-0.8.30/lib/dynflow/execution_plan/steps/abstract.rb:155:in `with_meta_calculation'\n/opt/theforeman/tfm/root/usr/share/gems/gems/dynflow-0.8.30/lib/dynflow/execution_plan/steps/abstract_flow_step.rb:8:in `block in execute'\n/opt/theforeman/tfm/root/usr/share/gems/gems/dynflow-0.8.30/lib/dynflow/execution_plan/steps/abstract_flow_step.rb:22:in `open_action'\n/opt/theforeman/tfm/root/usr/share/gems/gems/dynflow-0.8.30/lib/dynflow/execution_plan/steps/abstract_flow_step.rb:7:in `execute'\n/opt/theforeman/tfm/root/usr/share/gems/gems/dynflow-0.8.30/lib/dynflow/director.rb:55:in `execute'\n/opt/theforeman/tfm/root/usr/share/gems/gems/dynflow-0.8.30/lib/dynflow/executors/parallel/worker.rb:11:in `on_message'\n/opt/theforeman/tfm/root/usr/share/gems/gems/concurrent-ruby-edge-0.2.3/lib/concurrent/actor/context.rb:46:in `on_envelope'\n/opt/theforeman/tfm/root/usr/share/gems/gems/concurrent-ruby-edge-0.2.3/lib/concurrent/actor/behaviour/executes_context.rb:7:in `on_envelope'\n/opt/theforeman/tfm/root/usr/share/gems/gems/concurrent-ruby-edge-0.2.3/lib/concurrent/actor/behaviour/abstract.rb:25:in `pass'\n/opt/theforeman/tfm/root/usr/share/gems/gems/dynflow-0.8.30/lib/dynflow/actor.rb:26:in `on_envelope'\n/opt/theforeman/tfm/root/usr/share/gems/gems/concurrent-ruby-edge-0.2.3/lib/concurrent/actor/behaviour/abstract.rb:25:in `pass'\n/opt/theforeman/tfm/root/usr/share/gems/gems/concurrent-ruby-edge-0.2.3/lib/concurrent/actor/behaviour/awaits.rb:15:in `on_envelope'\n/opt/theforeman/tfm/root/usr/share/gems/gems/concurrent-ruby-edge-0.2.3/lib/concurrent/actor/behaviour/abstract.rb:25:in `pass'\n/opt/theforeman/tfm/root/usr/share/gems/gems/concurrent-ruby-edge-0.2.3/lib/concurrent/actor/behaviour/sets_results.rb:14:in `on_envelope'\n/opt/theforeman/tfm/root/usr/share/gems/gems/concurrent-ruby-edge-0.2.3/lib/concurrent/actor/behaviour/abstract.rb:25:in `pass'\n/opt/theforeman/tfm/root/usr/share/gems/gems/concurrent-ruby-edge-0.2.3/lib/concurrent/actor/behaviour/buffer.rb:38:in `process_envelope'\n/opt/theforeman/tfm/root/usr/share/gems/gems/concurrent-ruby-edge-0.2.3/lib/concurrent/actor/behaviour/buffer.rb:31:in `process_envelopes?'\n/opt/theforeman/tfm/root/usr/share/gems/gems/concurrent-ruby-edge-0.2.3/lib/concurrent/actor/behaviour/buffer.rb:20:in `on_envelope'\n/opt/theforeman/tfm/root/usr/share/gems/gems/concurrent-ruby-edge-0.2.3/lib/concurrent/actor/behaviour/abstract.rb:25:in `pass'\n/opt/theforeman/tfm/root/usr/share/gems/gems/concurrent-ruby-edge-0.2.3/lib/concurrent/actor/behaviour/termination.rb:55:in `on_envelope'\n/opt/theforeman/tfm/root/usr/share/gems/gems/concurrent-ruby-edge-0.2.3/lib/concurrent/actor/behaviour/abstract.rb:25:in `pass'\n/opt/theforeman/tfm/root/usr/share/gems/gems/concurrent-ruby-edge-0.2.3/lib/concurrent/actor/behaviour/removes_child.rb:10:in `on_envelope'\n/opt/theforeman/tfm/root/usr/share/gems/gems/concurrent-ruby-edge-0.2.3/lib/concurrent/actor/behaviour/abstract.rb:25:in `pass'\n/opt/theforeman/tfm/root/usr/share/gems/gems/concurrent-ruby-edge-0.2.3/lib/concurrent/actor/behaviour/sets_results.rb:14:in `on_envelope'\n/opt/theforeman/tfm/root/usr/share/gems/gems/concurrent-ruby-edge-0.2.3/lib/concurrent/actor/core.rb:161:in `process_envelope'\n/opt/theforeman/tfm/root/usr/share/gems/gems/concurrent-ruby-edge-0.2.3/lib/concurrent/actor/core.rb:95:in `block in on_envelope'\n/opt/theforeman/tfm/root/usr/share/gems/gems/concurrent-ruby-edge-0.2.3/lib/concurrent/actor/core.rb:118:in `block (2 levels) in schedule_execution'\n/opt/theforeman/tfm/root/usr/share/gems/gems/concurrent-ruby-1.0.3/lib/concurrent/synchronization/mri_lockable_object.rb:38:in `block in synchronize'\n/opt/theforeman/tfm/root/usr/share/gems/gems/concurrent-ruby-1.0.3/lib/concurrent/synchronization/mri_lockable_object.rb:38:in `synchronize'\n/opt/theforeman/tfm/root/usr/share/gems/gems/concurrent-ruby-1.0.3/lib/concurrent/synchronization/mri_lockable_object.rb:38:in `synchronize'\n/opt/theforeman/tfm/root/usr/share/gems/gems/concurrent-ruby-edge-0.2.3/lib/concurrent/actor/core.rb:115:in `block in schedule_execution'\n/opt/theforeman/tfm/root/usr/share/gems/gems/concurrent-ruby-1.0.3/lib/concurrent/executor/serialized_execution.rb:18:in `call'\n/opt/theforeman/tfm/root/usr/share/gems/gems/concurrent-ruby-1.0.3/lib/concurrent/executor/serialized_execution.rb:96:in `work'\n/opt/theforeman/tfm/root/usr/share/gems/gems/concurrent-ruby-1.0.3/lib/concurrent/executor/serialized_execution.rb:77:in `block in call_job'\n/opt/theforeman/tfm/root/usr/share/gems/gems/concurrent-ruby-1.0.3/lib/concurrent/executor/ruby_thread_pool_executor.rb:348:in `run_task'\n/opt/theforeman/tfm/root/usr/share/gems/gems/concurrent-ruby-1.0.3/lib/concurrent/executor/ruby_thread_pool_executor.rb:337:in `block (3 levels) in create_worker'\n/opt/theforeman/tfm/root/usr/share/gems/gems/concurrent-ruby-1.0.3/lib/concurrent/executor/ruby_thread_pool_executor.rb:320:in `loop'\n/opt/theforeman/tfm/root/usr/share/gems/gems/concurrent-ruby-1.0.3/lib/concurrent/executor/ruby_thread_pool_executor.rb:320:in `block (2 levels) in create_worker'\n/opt/theforeman/tfm/root/usr/share/gems/gems/concurrent-ruby-1.0.3/lib/concurrent/executor/ruby_thread_pool_executor.rb:319:in `catch'\n/opt/theforeman/tfm/root/usr/share/gems/gems/concurrent-ruby-1.0.3/lib/concurrent/executor/ruby_thread_pool_executor.rb:319:in `block in create_worker'\n/opt/theforeman/tfm/root/usr/share/gems/gems/logging-1.8.2/lib/logging/diagnostic_context.rb:323:in `block in create_with_logging_context'


Expected results:
There should not be any error

Comment 2 Jan Hutař 2017-11-07 23:37:37 UTC
foreman-debug in attachment 1349159 [details]

Comment 3 Eric Helms 2017-12-14 14:22:00 UTC
+1 -- we see this same error on the Dogfood server:

2017-12-14 05:18:01  [foreman-tasks/action] [E] Failed Candlepin Event: undefined method `id' for nil:NilClass
2017-12-14 05:18:01  [foreman-tasks/action] [E] /opt/theforeman/tfm/root/usr/share/gems/gems/katello-3.4.5.25/app/services/katello/candlepin/message_handler.rb:62:in `remove_pool_from_host'\n/opt/theforeman/tfm/root/usr/share/gems/gems/katello-3.4.5.25/app/lib/actions/candlepin/import_pool_handler.rb:22:in

Comment 4 Nikhil Kathole 2018-02-14 11:03:24 UTC
Version tested:
Satellite 6.3 snap 35

Found this is always reproducible with registering and unregistering one host as well.

2018-02-14 05:07:28 ef5a4f4f [app] [I] Started DELETE "/rhsm/consumers/cf645fbf-4760-4266-a6e3-108567742584" for IP at
2018-02-14 05:07:28 -0500
2018-02-14 05:07:28 ef5a4f4f [app] [I] Processing by Katello::Api::Rhsm::CandlepinProxiesController#consumer_destroy as JSON
2018-02-14 05:07:28 ef5a4f4f [app] [I]   Parameters: {"id"=>"cf645fbf-4760-4266-a6e3-108567742584"}
2018-02-14 05:07:28 ef5a4f4f [app] [I] Current user: cf645fbf-4760-4266-a6e3-108567742584 (regular user)
2018-02-14 05:07:28 ef5a4f4f [app] [I] Current user: foreman_admin (administrator)
2018-02-14 05:07:29 ef5a4f4f [app] [I] Current user: cf645fbf-4760-4266-a6e3-108567742584 (regular user)
2018-02-14 05:07:29 ef5a4f4f [app] [I]   Rendered text template (0.0ms)
2018-02-14 05:07:29 ef5a4f4f [app] [I] Completed 204 No Content in 1523ms (Views: 17.4ms | ActiveRecord: 101.5ms)
2018-02-14 05:07:29 23ff2782 [app] [I] Started GET "/rhsm/status" for 10.16.69.106 at 2018-02-14 05:07:29 -0500
2018-02-14 05:07:29 23ff2782 [app] [I] Processing by Katello::Api::Rhsm::CandlepinProxiesController#server_status as JSON
2018-02-14 05:07:29 23ff2782 [app] [I] Completed 200 OK in 33ms (Views: 1.9ms | ActiveRecord: 0.0ms)
2018-02-14 05:07:31  [app] [I] Current user: foreman_admin (administrator)
2018-02-14 05:07:31  [foreman-tasks/action] [E] Failed Candlepin Event: undefined method `id' for nil:NilClass
2018-02-14 05:07:31  [foreman-tasks/action] [E] /opt/theforeman/tfm/root/usr/share/gems/gems/katello-3.4.5.58/app/services/katell
o/candlepin/message_handler.rb:62:in `remove_pool_from_host'\n/opt/theforeman/tfm/root/usr/share/gems/gems/katello-3.4.5.58/app/l
ib/actions/candlepin/import_pool_handler.rb:22:in `handle'\n/opt/theforeman/tfm/root/usr/share/gems/gems/katello-3.4.5.58/app/lib

Comment 5 David Galloway 2018-04-26 13:38:19 UTC
+1.  Seeing this on my own Satellite when registering many systems at once via ansible.

Comment 6 Jan Hutař 2018-04-30 10:19:33 UTC
(In reply to David Galloway from comment #5)
> +1.  Seeing this on my own Satellite when registering many systems at once
> via ansible.

Maybe you see it when registering because you had these hosts already registered and you are running with "--force" and maybe it tries to unregister first?

Comment 7 David Galloway 2018-05-01 13:55:48 UTC
(In reply to Jan Hutař from comment #6)
> (In reply to David Galloway from comment #5)
> > +1.  Seeing this on my own Satellite when registering many systems at once
> > via ansible.
> 
> Maybe you see it when registering because you had these hosts already
> registered and you are running with "--force" and maybe it tries to
> unregister first?

My hosts get reprovisioned before every ansible playbook run so they are unregistered.

https://github.com/ceph/ceph-cm-ansible/blob/master/roles/common/tasks/rhel-entitlements.yml#L39-L48

Comment 8 David Galloway 2018-05-01 14:12:01 UTC
I do wonder now though, since I have retries and delays set for the ansible task, if adding --force would resolve my issues.  I'm thinking maybe the machine gets partially registered and the subsequent retries are failing because of it.  I'll try that.

Comment 9 David Galloway 2018-05-03 17:53:45 UTC
Adding --force did not help.

Comment 10 Yuri Weinstein 2018-05-10 17:26:29 UTC
This issue causing a lot of failures on ceph/core/rados tests on rhel.
So adding my voice to give it high priority and fix ASAP.

Comment 11 David Galloway 2018-05-11 18:17:26 UTC
Please ignore my and Yuri's comments.  We were not hitting this bug after all.  Sorry for the noise.

Comment 12 Bryan Kearney 2018-11-30 14:59:32 UTC
The Satellite Team is attempting to provide an accurate backlog of bugzilla requests which we feel will be resolved in the next few releases. We do not believe this bugzilla will meet that criteria, and have plans to close it out in 1 month. This is not a reflection on the validity of the request, but a reflection of the many priorities for the product. If you have any concerns about this, feel free to contact Rich Jerrido or Bryan Kearney or your account team. If we do not hear from you, we will close this bug out. Thank you.

Comment 13 Bryan Kearney 2019-02-07 12:03:47 UTC
Thank you for your interest in Satellite 6. We have evaluated this request, and while we recognize that it is a valid request, we do not expect this to be implemented in the product in the foreseeable future. This is due to other priorities for the product, and not a reflection on the request itself. We are therefore closing this out as WONTFIX. If you have any concerns about this, please do not reopen. Instead, feel free to contact Red Hat Technical Support. Thank you.


Note You need to log in before you can comment on or make changes to this bug.