Project

General

Profile

Bug #32351

Potential race condition in katello-agent dynflow actions

Added by Jonathon Turel 7 months ago. Updated 7 months ago.

Status:
Closed
Priority:
Normal
Category:
Client/Agent
Target version:
Difficulty:
Triaged:
Yes
Bugzilla link:
Fixed in Releases:
Found in Releases:

Description

Sometimes katello agent actions are resulting in the 'Host did not respond within 20 seconds.' warning. The production.log shows the error below which gives the impression that the transaction in AgentAction#plan was not comitted by the time the DispatchHistory is loaded by the agent event handler.

2021-04-19T17:08:55 [I|app|3d9fe84c] Started PUT "/api/hosts/3/errata/apply" for 192.168.121.68 at 2021-04-19 17:08:55 +0000
2021-04-19T17:08:55 [I|app|3d9fe84c] Processing by Katello::Api::V2::HostErrataController#apply as JSON
2021-04-19T17:08:55 [I|app|3d9fe84c]   Parameters: {"errata_ids"=>["RHEA-2012:0055"], "included"=>{}, "excluded"=>{}, "api_version"=>"v2", "host_id"=>"3", "host_erratum"=>{"errata_ids"=>["RHEA-2012:0055"], "included"=>{}, "excluded"=>{}}}
2021-04-19T17:08:55 [I|app|3d9fe84c] Authorized user admin(Admin User)
2021-04-19T17:08:56 [I|bac|3d9fe84c] Task {label: Actions::Katello::Host::Erratum::Install, id: 0e10aac2-52e6-427e-abae-7bbd30f2b32d, execution_plan_id: 9f83f30d-261a-41b9-a2a8-7526c9de4008} state changed: planning
2021-04-19T17:08:56 [E|app|bbf4e7b3] Error handling Katello Agent client message
2021-04-19T17:08:56 [E|app|bbf4e7b3] No valid dispatch history in client message
2021-04-19T17:08:56 [E|app|bbf4e7b3] /opt/theforeman/tfm/root/usr/share/gems/gems/katello-4.1.0.pre.master/app/lib/katello/agent/client_message_handler.rb:11:in `initialize'
 bbf4e7b3 | /opt/theforeman/tfm/root/usr/share/gems/gems/katello-4.1.0.pre.master/app/lib/katello/event_daemon/services/agent_event_receiver.rb:17:in `new'
 bbf4e7b3 | /opt/theforeman/tfm/root/usr/share/gems/gems/katello-4.1.0.pre.master/app/lib/katello/event_daemon/services/agent_event_receiver.rb:17:in `block in handle'
 bbf4e7b3 | /opt/theforeman/tfm/root/usr/share/gems/gems/katello-4.1.0.pre.master/app/lib/katello/util/support.rb:76:in `with_db_connection'
 bbf4e7b3 | /opt/theforeman/tfm/root/usr/share/gems/gems/katello-4.1.0.pre.master/app/lib/katello/event_daemon/services/agent_event_receiver.rb:16:in `handle'
 bbf4e7b3 | /opt/theforeman/tfm/root/usr/share/gems/gems/katello-4.1.0.pre.master/app/lib/katello/qpid/connection.rb:70:in `on_message'
 bbf4e7b3 | /opt/theforeman/tfm/root/usr/share/gems/gems/qpid_proton-0.33.0/lib/handler/adapter.rb:74:in `forward'
 bbf4e7b3 | /opt/theforeman/tfm/root/usr/share/gems/gems/qpid_proton-0.33.0/lib/handler/messaging_adapter.rb:27:in `delegate'
 bbf4e7b3 | /opt/theforeman/tfm/root/usr/share/gems/gems/qpid_proton-0.33.0/lib/handler/messaging_adapter.rb:108:in `on_delivery'
 bbf4e7b3 | /opt/theforeman/tfm/root/usr/share/gems/gems/qpid_proton-0.33.0/lib/core/event.rb:94:in `dispatch'
 bbf4e7b3 | /opt/theforeman/tfm/root/usr/share/gems/gems/qpid_proton-0.33.0/lib/core/connection_driver.rb:194:in `block in dispatch'
 bbf4e7b3 | /opt/theforeman/tfm/root/usr/share/gems/gems/qpid_proton-0.33.0/lib/core/connection_driver.rb:78:in `each_event'
 bbf4e7b3 | /opt/theforeman/tfm/root/usr/share/gems/gems/qpid_proton-0.33.0/lib/core/connection_driver.rb:188:in `dispatch'
 bbf4e7b3 | /opt/theforeman/tfm/root/usr/share/gems/gems/qpid_proton-0.33.0/lib/core/container.rb:270:in `dispatch'
 bbf4e7b3 | /opt/theforeman/tfm/root/usr/share/gems/gems/qpid_proton-0.33.0/lib/core/connection_driver.rb:204:in `process'
 bbf4e7b3 | /opt/theforeman/tfm/root/usr/share/gems/gems/qpid_proton-0.33.0/lib/core/container.rb:267:in `process'
 bbf4e7b3 | /opt/theforeman/tfm/root/usr/share/gems/gems/qpid_proton-0.33.0/lib/core/container.rb:419:in `block in run_one'
 bbf4e7b3 | /opt/theforeman/tfm/root/usr/share/gems/gems/qpid_proton-0.33.0/lib/core/container.rb:432:in `maybe_panic'
 bbf4e7b3 | /opt/theforeman/tfm/root/usr/share/gems/gems/qpid_proton-0.33.0/lib/core/container.rb:419:in `run_one'
 bbf4e7b3 | /opt/theforeman/tfm/root/usr/share/gems/gems/qpid_proton-0.33.0/lib/core/container.rb:197:in `run'
 bbf4e7b3 | /opt/theforeman/tfm/root/usr/share/gems/gems/katello-4.1.0.pre.master/app/lib/katello/qpid/connection.rb:141:in `with_connection'
 bbf4e7b3 | /opt/theforeman/tfm/root/usr/share/gems/gems/katello-4.1.0.pre.master/app/lib/katello/qpid/connection.rb:126:in `receive_messages'
 bbf4e7b3 | /opt/theforeman/tfm/root/usr/share/gems/gems/katello-4.1.0.pre.master/app/lib/katello/agent/connection.rb:18:in `fetch_agent_messages'
 bbf4e7b3 | /opt/theforeman/tfm/root/usr/share/gems/gems/katello-4.1.0.pre.master/app/lib/katello/event_daemon/services/agent_event_receiver.rb:38:in `block in run'
 bbf4e7b3 | /opt/theforeman/tfm/root/usr/share/gems/gems/logging-2.3.0/lib/logging/diagnostic_context.rb:474:in `block in create_with_logging_context'
2021-04-19T17:08:56 [I|bac|3d9fe84c] Task {label: Actions::Katello::Host::Erratum::Install, id: 0e10aac2-52e6-427e-abae-7bbd30f2b32d, execution_plan_id: 9f83f30d-261a-41b9-a2a8-7526c9de4008} state changed: planned 

And 20 seconds later the client times out:

    021-04-19T17:09:16 [E|bac|3d9fe84c] Host did not respond within 20 seconds. The task has been cancelled. Is katello-agent installed and goferd running on the Host? (RuntimeError)
     3d9fe84c | /opt/theforeman/tfm/root/usr/share/gems/gems/katello-4.1.0.pre.master/app/lib/actions/katello/agent_action.rb:78:in `process_timeout'
     3d9fe84c | /opt/theforeman/tfm/root/usr/share/gems/gems/katello-4.1.0.pre.master/app/lib/actions/katello/agent_action.rb:57:in `run'
     3d9fe84c | /opt/theforeman/tfm/root/usr/share/gems/gems/dynflow-1.4.7/lib/dynflow/action.rb:571:in `block (3 levels) in execute_run'
     3d9fe84c | /opt/theforeman/tfm/root/usr/share/gems/gems/dynflow-1.4.7/lib/dynflow/middleware/stack.rb:27:in `pass'
     3d9fe84c | /opt/theforeman/tfm/root/usr/share/gems/gems/dynflow-1.4.7/lib/dynflow/middleware.rb:19:in `pass'
     3d9fe84c | /opt/theforeman/tfm/root/usr/share/gems/gems/foreman-tasks-4.1.0/app/lib/actions/middleware/rails_executor_wrap.rb:14:in `block in run'
     3d9fe84c | /opt/theforeman/tfm/root/usr/share/gems/gems/activesupport-6.0.3.5/lib/active_support/execution_wrapper.rb:88:in `wrap'
     3d9fe84c | /opt/theforeman/tfm/root/usr/share/gems/gems/foreman-tasks-4.1.0/app/lib/actions/middleware/rails_executor_wrap.rb:13:in `run'
     3d9fe84c | /opt/theforeman/tfm/root/usr/share/gems/gems/dynflow-1.4.7/lib/dynflow/middleware/stack.rb:23:in `call'
     3d9fe84c | /opt/theforeman/tfm/root/usr/share/gems/gems/dynflow-1.4.7/lib/dynflow/middleware/stack.rb:27:in `pass'
     3d9fe84c | /opt/theforeman/tfm/root/usr/share/gems/gems/dynflow-1.4.7/lib/dynflow/middleware.rb:19:in `pass'
     3d9fe84c | /opt/theforeman/tfm/root/usr/share/gems/gems/dynflow-1.4.7/lib/dynflow/action/progress.rb:31:in `with_progress_calculation'
     3d9fe84c | /opt/theforeman/tfm/root/usr/share/gems/gems/dynflow-1.4.7/lib/dynflow/action/progress.rb:17:in `run'
     3d9fe84c | /opt/theforeman/tfm/root/usr/share/gems/gems/dynflow-1.4.7/lib/dynflow/middleware/stack.rb:23:in `call'
     3d9fe84c | /opt/theforeman/tfm/root/usr/share/gems/gems/dynflow-1.4.7/lib/dynflow/middleware/stack.rb:27:in `pass'
     3d9fe84c | /opt/theforeman/tfm/root/usr/share/gems/gems/dynflow-1.4.7/lib/dynflow/middleware.rb:19:in `pass'
     3d9fe84c | /opt/theforeman/tfm/root/usr/share/gems/gems/foreman-tasks-4.1.0/app/lib/actions/middleware/keep_current_request_id.rb:15:in `block in run'
     3d9fe84c | /opt/theforeman/tfm/root/usr/share/gems/gems/foreman-tasks-4.1.0/app/lib/actions/middleware/keep_current_request_id.rb:52:in `restore_current_request_id'
     3d9fe84c | /opt/theforeman/tfm/root/usr/share/gems/gems/foreman-tasks-4.1.0/app/lib/actions/middleware/keep_current_request_id.rb:15:in `run'
     3d9fe84c | /opt/theforeman/tfm/root/usr/share/gems/gems/dynflow-1.4.7/lib/dynflow/middleware/stack.rb:23:in `call'
     3d9fe84c | /opt/theforeman/tfm/root/usr/share/gems/gems/dynflow-1.4.7/lib/dynflow/middleware/stack.rb:27:in `pass'
     3d9fe84c | /opt/theforeman/tfm/root/usr/share/gems/gems/dynflow-1.4.7/lib/dynflow/middleware.rb:19:in `pass'
     3d9fe84c | /opt/theforeman/tfm/root/usr/share/gems/gems/foreman-tasks-4.1.0/app/lib/actions/middleware/keep_current_timezone.rb:15:in `block in run'
     3d9fe84c | /opt/theforeman/tfm/root/usr/share/gems/gems/foreman-tasks-4.1.0/app/lib/actions/middleware/keep_current_timezone.rb:44:in `restore_curent_timezone'
     3d9fe84c | /opt/theforeman/tfm/root/usr/share/gems/gems/foreman-tasks-4.1.0/app/lib/actions/middleware/keep_current_timezone.rb:15:in `run'
     3d9fe84c | /opt/theforeman/tfm/root/usr/share/gems/gems/dynflow-1.4.7/lib/dynflow/middleware/stack.rb:23:in `call'
     3d9fe84c | /opt/theforeman/tfm/root/usr/share/gems/gems/dynflow-1.4.7/lib/dynflow/middleware/stack.rb:27:in `pass'
     3d9fe84c | /opt/theforeman/tfm/root/usr/share/gems/gems/dynflow-1.4.7/lib/dynflow/middleware.rb:19:in `pass'
     3d9fe84c | /opt/theforeman/tfm/root/usr/share/gems/gems/foreman-tasks-4.1.0/app/lib/actions/middleware/keep_current_taxonomies.rb:15:in `block in run'
     3d9fe84c | /opt/theforeman/tfm/root/usr/share/gems/gems/foreman-tasks-4.1.0/app/lib/actions/middleware/keep_current_taxonomies.rb:45:in `restore_current_taxonomies'
     3d9fe84c | /opt/theforeman/tfm/root/usr/share/gems/gems/foreman-tasks-4.1.0/app/lib/actions/middleware/keep_current_taxonomies.rb:15:in `run'
     3d9fe84c | /opt/theforeman/tfm/root/usr/share/gems/gems/dynflow-1.4.7/lib/dynflow/middleware/stack.rb:23:in `call'
     3d9fe84c | /opt/theforeman/tfm/root/usr/share/gems/gems/dynflow-1.4.7/lib/dynflow/middleware/stack.rb:27:in `pass'
     3d9fe84c | /opt/theforeman/tfm/root/usr/share/gems/gems/dynflow-1.4.7/lib/dynflow/middleware.rb:19:in `pass'
     3d9fe84c | /opt/theforeman/tfm/root/usr/share/gems/gems/dynflow-1.4.7/lib/dynflow/middleware.rb:32:in `run'
     3d9fe84c | /opt/theforeman/tfm/root/usr/share/gems/gems/dynflow-1.4.7/lib/dynflow/middleware/stack.rb:23:in `call'
     3d9fe84c | /opt/theforeman/tfm/root/usr/share/gems/gems/dynflow-1.4.7/lib/dynflow/middleware/stack.rb:27:in `pass'
     3d9fe84c | /opt/theforeman/tfm/root/usr/share/gems/gems/dynflow-1.4.7/lib/dynflow/middleware.rb:19:in `pass'
     3d9fe84c | /opt/theforeman/tfm/root/usr/share/gems/gems/foreman-tasks-4.1.0/app/lib/actions/middleware/keep_current_user.rb:15:in `block in run'
     3d9fe84c | /opt/theforeman/tfm/root/usr/share/gems/gems/foreman-tasks-4.1.0/app/lib/actions/middleware/keep_current_user.rb:54:in `restore_curent_user'
     3d9fe84c | /opt/theforeman/tfm/root/usr/share/gems/gems/foreman-tasks-4.1.0/app/lib/actions/middleware/keep_current_user.rb:15:in `run'
     3d9fe84c | /opt/theforeman/tfm/root/usr/share/gems/gems/dynflow-1.4.7/lib/dynflow/middleware/stack.rb:23:in `call'
     3d9fe84c | /opt/theforeman/tfm/root/usr/share/gems/gems/dynflow-1.4.7/lib/dynflow/middleware/world.rb:31:in `execute'
     3d9fe84c | /opt/theforeman/tfm/root/usr/share/gems/gems/dynflow-1.4.7/lib/dynflow/action.rb:570:in `block (2 levels) in execute_run'
     3d9fe84c | /opt/theforeman/tfm/root/usr/share/gems/gems/dynflow-1.4.7/lib/dynflow/action.rb:569:in `catch'
     3d9fe84c | /opt/theforeman/tfm/root/usr/share/gems/gems/dynflow-1.4.7/lib/dynflow/action.rb:569:in `block in execute_run'
     3d9fe84c | /opt/theforeman/tfm/root/usr/share/gems/gems/dynflow-1.4.7/lib/dynflow/action.rb:472:in `block in with_error_handling'
     3d9fe84c | /opt/theforeman/tfm/root/usr/share/gems/gems/dynflow-1.4.7/lib/dynflow/action.rb:472:in `catch'
     3d9fe84c | /opt/theforeman/tfm/root/usr/share/gems/gems/dynflow-1.4.7/lib/dynflow/action.rb:472:in `with_error_handling'
     3d9fe84c | /opt/theforeman/tfm/root/usr/share/gems/gems/dynflow-1.4.7/lib/dynflow/action.rb:564:in `execute_run'
     3d9fe84c | /opt/theforeman/tfm/root/usr/share/gems/gems/dynflow-1.4.7/lib/dynflow/action.rb:285:in `execute'
     3d9fe84c | /opt/theforeman/tfm/root/usr/share/gems/gems/dynflow-1.4.7/lib/dynflow/execution_plan/steps/abstract_flow_step.rb:18:in `block (2 levels) in execute'
     3d9fe84c | /opt/theforeman/tfm/root/usr/share/gems/gems/dynflow-1.4.7/lib/dynflow/execution_plan/steps/abstract.rb:167:in `with_meta_calculation'
     3d9fe84c | /opt/theforeman/tfm/root/usr/share/gems/gems/dynflow-1.4.7/lib/dynflow/execution_plan/steps/abstract_flow_step.rb:17:in `block in execute'
     3d9fe84c | /opt/theforeman/tfm/root/usr/share/gems/gems/dynflow-1.4.7/lib/dynflow/execution_plan/steps/abstract_flow_step.rb:32:in `open_action'
     3d9fe84c | /opt/theforeman/tfm/root/usr/share/gems/gems/dynflow-1.4.7/lib/dynflow/execution_plan/steps/abstract_flow_step.rb:16:in `execute'
     3d9fe84c | /opt/theforeman/tfm/root/usr/share/gems/gems/dynflow-1.4.7/lib/dynflow/director.rb:93:in `execute'
     3d9fe84c | /opt/theforeman/tfm/root/usr/share/gems/gems/dynflow-1.4.7/lib/dynflow/executors/sidekiq/worker_jobs.rb:11:in `block (2 levels) in perform'
     3d9fe84c | /opt/theforeman/tfm/root/usr/share/gems/gems/dynflow-1.4.7/lib/dynflow/executors.rb:18:in `run_user_code'
     3d9fe84c | /opt/theforeman/tfm/root/usr/share/gems/gems/dynflow-1.4.7/lib/dynflow/executors/sidekiq/worker_jobs.rb:9:in `block in perform'
     3d9fe84c | /opt/theforeman/tfm/root/usr/share/gems/gems/dynflow-1.4.7/lib/dynflow/executors/sidekiq/worker_jobs.rb:25:in `with_telemetry'
     3d9fe84c | /opt/theforeman/tfm/root/usr/share/gems/gems/dynflow-1.4.7/lib/dynflow/executors/sidekiq/worker_jobs.rb:8:in `perform'
     3d9fe84c | /opt/theforeman/tfm/root/usr/share/gems/gems/dynflow-1.4.7/lib/dynflow/executors/sidekiq/serialization.rb:27:in `perform'
     3d9fe84c | [ sidekiq ]

Associated revisions

Revision ac1afc93 (diff)
Added by Jonathon Turel 7 months ago

Fixes #32351 - Race condition in katello-agent dynflow actions (#9304)

  • Fixes #32351 - Race condition in katello-agent dynflow actions
  • Refs #32351 - dispatcher tests

History

#1 Updated by Samir Jha 7 months ago

  • Triaged changed from No to Yes

#2 Updated by The Foreman Bot 7 months ago

  • Assignee set to Jonathon Turel
  • Status changed from New to Ready For Testing
  • Pull request https://github.com/Katello/katello/pull/9304 added

#3 Updated by The Foreman Bot 7 months ago

  • Fixed in Releases Katello 4.2.0 added

#4 Updated by Jonathon Turel 7 months ago

  • Status changed from Ready For Testing to Closed

#5 Updated by Jonathon Turel 7 months ago

  • Target version changed from Katello 4.1.0 to Katello 4.0.1

Also available in: Atom PDF