Bug #32351: Potential race condition in katello-agent dynflow actions - Katello - Foreman

Actions

Copy link

Bug #32351

closed

Potential race condition in katello-agent dynflow actions

Added by Jonathon Turel about 3 years ago. Updated almost 3 years ago.

Status:

Closed

Priority:

Normal

Assignee:

Jonathon Turel

Category:

Client/Agent

Target version:

Katello 4.0.1

Difficulty:

Triaged:

Yes

Bugzilla link:

Pull request:

https://github.com/Katello/katello/pull/9304

Fixed in Releases:

Katello 4.2.0

Found in Releases:

Red Hat JIRA:

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 ]

Actions

Copy link

Also available in: Atom PDF

Project

General

Profile

Plugins » Katello

Custom queries

Bug #32351

Potential race condition in katello-agent dynflow actions

Updated by Samir Jha about 3 years ago

Updated by The Foreman Bot about 3 years ago

Updated by The Foreman Bot almost 3 years ago

Updated by Jonathon Turel almost 3 years ago

Updated by Jonathon Turel almost 3 years ago