Bug 2143515

Summary: ERROR -- /parallel-executor-core: no manager for Dynflow::Director::Event for event: #<Actions::ProxyAction::ProxyActionStopped
Product: Red Hat Satellite Reporter: Hao Chang Yu <hyu>
Component: Remote ExecutionAssignee: Adam Ruzicka <aruzicka>
Status: CLOSED ERRATA QA Contact: Peter Ondrejka <pondrejk>
Severity: medium Docs Contact:
Priority: unspecified    
Version: 6.11.3CC: aruzicka, pcreech
Target Milestone: 6.13.0Keywords: Triaged
Target Release: Unused   
Hardware: Unspecified   
OS: Unspecified   
Whiteboard:
Fixed In Version: foreman-tasks-7.1.1 Doc Type: If docs needed, set a value
Doc Text:
Story Points: ---
Clone Of: Environment:
Last Closed: 2023-05-03 13:23:05 UTC Type: Bug
Regression: --- Mount Type: ---
Documentation: --- CRM:
Verified Versions: Category: ---
oVirt Team: --- RHEL 7.3 requirements from Atomic Host:
Cloudforms Team: --- Target Upstream Version:
Embargoed:

Description Hao Chang Yu 2022-11-17 04:20:37 UTC 
Description of problem:
Getting the following errors in the /var/log/messages when running remote execution jobs.
--------------
dynflow-sidekiq@orchestrator: E, [2022-11-15T08:49:29.338032 #XXXXX] ERROR -- /parallel-executor-core: no manager for Dynflow::Director::Event[request_id: e7012c15-8eeb-4e5c-87cf-1a34799350d7-1577, execution_plan_id: 8e3869cc-909f-4218-8e25-822d29f1c003, step_id: 3, event: #<Actions::ProxyAction::ProxyActionStopped:0xXXXXXXXXX>, result: #<Concurrent::Promises::ResolvableFuture:0xXXXXXXXXX pending>, optional: false] (Dynflow::Error)

dynflow-sidekiq@orchestrator: E, [2022-11-15T08:49:29.336864 #XXXXX] ERROR -- /parallel-executor-core: no manager for Dynflow::Director::Event[request_id: e7012c15-8eeb-4e5c-87cf-1a34799350d7-1575, execution_plan_id: 553dffde-6c86-420f-a8ed-d26a2e0e12fa, step_id: 3, event: #<Actions::ProxyAction::ProxyActionStopped:0xXXXXXXXXX>, result: #<Concurrent::Promises::ResolvableFuture:0xXXXXXXXXX pending>, optional: false] (Dynflow::Error)

dynflow-sidekiq@orchestrator: E, [2022-11-15T08:49:16.902160 #XXXXX] ERROR -- /parallel-executor-core: no manager for Dynflow::Director::Event[request_id: e7012c15-8eeb-4e5c-87cf-1a34799350d7-1566, execution_plan_id: a9af512c-32a1-4c4d-8972-e9429a361eda, step_id: 3, event: #<Actions::ProxyAction::ProxyActionStopped:0xXXXXXXXXX>, result: #<Concurrent::Promises::ResolvableFuture:0xXXXXXXXXX pending>, optional: false] (Dynflow::Error)
--------------

This issue seems to be similar to bug #1939450.

This is what I understand

"CheckOnProxyActions" task is scheduled to check the status of the REX jobs every 10 minutes in case it does not receive the callback from clients. This task checks each REX job on client side and then send an event to notify Satellite that the REX job has been completed. The above error means the REX job is finished before the event is sent.


Example 1:
REX job received the first notification from "CheckOnProxyActions" task at "2022-11-15 13:46:07 UTC" ( as it took more than 20 minutes to run. It process the event (on_proxy_action_stopped hook) and raise error because the task failed on client side.
----------------------
dynflow_steps:
8e3869cc-909f-4218-8e25-822d29f1c003,3,2,,error,2022-11-15 13:22:00,2022-11-15 13:46:07.185677,1447.185677213,0.922984392,0.5,1,Dynflow::ExecutionPlan::Steps::RunStep,{"class":"Dynflow::ExecutionPlan::Steps::Error","exception_class":"Foreman::Exception","message":"ERF42-0142 [Foreman::Exception]: The capsule task 9e1d3200-6e10-42ee-93ad-cecdfbeb812e failed.","backtrace":["/opt/theforeman/tfm/root/usr/share/gems/gems/foreman-tasks-4.1.5/app/lib/actions/proxy_action.rb:90:in `check_task_status'","/opt/theforeman/tfm/root/usr/share/gems/gems/foreman-tasks-4.1.5/app/lib/actions/proxy_action.rb:137:in `on_proxy_action_stopped'","   <=======================
----------------------

Run host job stopped at "2022-11-15 13:49:28 UTC"
----------------------
1280c827-510e-425a-ade5-70e14c6af231 | ForemanTasks::Task::DynflowTask | Actions::RemoteExecution::RunHostJob                 | 2022-11-15 12:24:26.703 | 2022-11-15 13:49:28.785 | stopped   | error     | 8e3869cc-909f-4218-8e25-822d29f1c003 | 3d342956-b7a4-4510-8a22-e8a9be7118d8 | 2022-11-15 12:24:12.914109 |              | Remote action: XXXXXXX
----------------------

Another notification send to the same REX Job at "Nov 15 08:49:29"  (UTC +00). The REX job has received the first notification about 3 minutes ago and stopped so Dynflow raise the error.
----------------------
/var/log/messages:
dynflow-sidekiq@orchestrator: E, [2022-11-15T08:49:29.338032 #XXXXX] ERROR -- /parallel-executor-core: no manager for Dynflow::Director::Event[request_id: e7012c15-8eeb-4e5c-87cf-1a34799350d7-1577, execution_plan_id: 8e3869cc-909f-4218-8e25-822d29f1c003, step_id: 3, event: #<Actions::ProxyAction::ProxyActionStopped:0xXXXXXXXXX, result: #<Concurrent::Promises::ResolvableFuture:0xXXXXXXXXX pending>, optional: false] (Dynflow::Error)
----------------------


Example 2:
The run host job was finished successfully at "2022-11-15 13:49:08"
----------------------
a9af512c-32a1-4c4d-8972-e9429a361eda,1,1,,success,2022-11-15 12:17:17.981888,2022-11-15 12:22:49.476562,331.494674682,331.494674682,1,0,Dynflow::ExecutionPlan::Steps::PlanStep,,Actions::RemoteExecution::RunHostJob,[2],
a9af512c-32a1-4c4d-8972-e9429a361eda,3,2,,success,2022-11-15 13:21:00,2022-11-15 13:46:06.52477,1506.52477077,0.373142927,1,1,Dynflow::ExecutionPlan::Steps::RunStep,,Actions::ProxyAction,,remote_execution
a9af512c-32a1-4c4d-8972-e9429a361eda,4,1,,success,2022-11-15 13:49:08.117074,2022-11-15 13:49:08.405157,0.288083601,0.288083601,1,1,Dynflow::ExecutionPlan::Steps::FinalizeStep,,Actions::RemoteExecution::RunHostJob,,remote_execution
----------------------

An event was sent at "2022-11-15T08:49:16 UTC -05:00" raise error because the task was finished.
----------------------
dynflow-sidekiq@orchestrator: E, [2022-11-15T08:49:16.902160 #XXXXXX] ERROR -- /parallel-executor-core: no manager for Dynflow::Director::Event[request_id: e7012c15-8eeb-4e5c-87cf-1a34799350d7-1566, execution_plan_id: a9af512c-32a1-4c4d-8972-e9429a361eda, step_id: 3, event: #<Actions::ProxyAction::ProxyActionStopped:0xXXXXXXXXX>, result: #<Concurrent::Promises::ResolvableFuture:0xXXXXXXXXX pending>, optional: false] (Dynflow::Error)
----------------------
Comment 3 Peter Ondrejka 2023-01-30 12:22:04 UTC 
Verified on Satellite 6.13 snap 7, using a job run with command "sleep 550" against a number of hosts, the aforementioned error is no longer logged
Comment 6 errata-xmlrpc 2023-05-03 13:23:05 UTC 
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 (Important: Satellite 6.13 Release), and where to find the updated
files, follow the link below.

If the solution does not work for you, open a new bug report.

https://access.redhat.com/errata/RHSA-2023:2097