Katello/Foreman Ansible run jobs stuck in pending state

dil · December 12, 2019, 8:56pm

**Problem:*Foreman Ansible Job stuck in pending state and fails to excute the trigger job *

**Expected outcome:Job to execute and complet on remote host succesfully

**Foreman and Proxy versions:1.24

**Foreman and Proxy plugin versions:1.24 Katello: 3.14

Distribution and version:

Other relevant data:

/var/log/foreman/dynflow_executor.output:3960:/opt/theforeman/tfm/root/usr/share/gems/gems/sequel-5.7.1/lib/sequel/adapters/postgres.rb:146:in `async_exec': PG::ConnectionBad: PQsocket() can't get socket descriptor (Sequel::DatabaseDisconnectError)
/var/log/foreman/dynflow_executor.output:3965:  from /opt/theforeman/tfm/root/usr/share/gems/gems/sequel-5.7.1/lib/sequel/adapters/postgres.rb:110:in `check_disconnect_errors'
/var/log/foreman/dynflow_executor.output:3972:  from /opt/theforeman/tfm/root/usr/share/gems/gems/sequel-5.7.1/lib/sequel/adapters/postgres.rb:478:in `check_database_errors'
/var/log/foreman/dynflow_executor.output:3979:E, [2019-12-12T11:40:51.145060 #23841] ERROR -- /parallel-executor-core/pool remote_execution/worker-9: PG::ConnectionBad: PQsocket() can't get socket descriptor: SET client_min_messages TO 'warning' (ActiveRecord::StatementInvalid)
/var/log/foreman/dynflow_executor.output:4029:E, [2019-12-12T11:40:51.146217 #23841] ERROR -- /client-dispatcher: PG::UnableToSend: server closed the connection unexpectedly
/var/log/foreman/dynflow_executor.output:4032: (Sequel::DatabaseDisconnectError)
/var/log/foreman/dynflow_executor.output:4038:/opt/theforeman/tfm/root/usr/share/gems/gems/sequel-5.7.1/lib/sequel/adapters/postgres.rb:110:in `check_disconnect_errors'
/var/log/foreman/dynflow_executor.output:4042:/opt/theforeman/tfm/root/usr/share/gems/gems/sequel-5.7.1/lib/sequel/adapters/postgres.rb:478:in `check_database_errors'
/var/log/foreman/dynflow_executor.output:4105:E, [2019-12-12T11:40:51.146628 #23841] ERROR -- /client-dispatcher: Could not find an executor for Dynflow::Dispatcher::Envelope[request_id: 53d8d9da-7604-40d4-a892-0907bbe9d8dd-10, sender_id: 53d8d9da-7604-40d4-a892-0907bbe9d8dd, receiver_id: Dynflow::Dispatcher::UnknownWorld, message: Dynflow::Dispatcher::Event[execution_plan_id: dac1c2ee-c9b8-4011-bd06-e9aae4a944cd, step_id: 2, event: Dynflow::Action::WithPollingSubPlans::Poll, time: 2019-12-12 11:40:51 -0600]] (Dynflow::Error)
/var/log/foreman/dynflow_executor.output:4145:E, [2019-12-12T11:40:53.108921 #23841] ERROR -- /parallel-executor-core: PG::ConnectionBad: could not connect to server: No such file or directory
/var/log/foreman/dynflow_executor.output:4148: (Sequel::DatabaseConnectionError)
/var/log/foreman/dynflow_executor.output:4191:E, [2019-12-12T11:41:00.199064 #23841] ERROR -- /connector-database-core: caused by Sequel::DatabaseConnectionError: PG::ConnectionBad: could not connect to server: No such file or directory
/var/log/foreman/dynflow_executor.output:4194: (Dynflow::Errors::FatalPersistenceError)
/var/log/foreman/dynflow_executor.output:4234:E, [2019-12-12T11:41:00.207578 #23841] ERROR -- /connector-database-core: Receiving envelopes failed on PG::ConnectionBad: could not connect to server: No such file or directory
/var/log/foreman/dynflow_executor.output:4238:E, [2019-12-12T11:41:10.216823 #23841] ERROR -- /connector-database-core: PG::ConnectionBad: could not connect to server: No such file or directory
/var/log/foreman/dynflow_executor.output:4241: (Sequel::DatabaseConnectionError)
/var/log/foreman/dynflow_executor.output:4271:E, [2019-12-12T11:53:00.257830 #12332] ERROR -- /parallel-executor-core: no manager for Dynflow::Director::Event[request_id: f06940d9-e984-46ef-97b5-98b1992ec6f7-5, execution_plan_id: e3ad6f58-6bf3-4626-bed5-1c569cd4e9cd, step_id: 2, event: Dynflow::Action::WithPollingSubPlans::Poll, result: #<Concurrent::Promises::ResolvableFuture:0x0000000012146da8 pending>] (Dynflow::Error)
/var/log/foreman/dynflow_executor.output:4316:/opt/theforeman/tfm/root/usr/share/gems/gems/sequel-5.7.1/lib/sequel/adapters/postgres.rb:146:in `async_exec': PG::ConnectionBad: PQsocket() can't get socket descriptor (Sequel::DatabaseDisconnectError)
/var/log/foreman/dynflow_executor.output:4321:  from /opt/theforeman/tfm/root/usr/share/gems/gems/sequel-5.7.1/lib/sequel/adapters/postgres.rb:110:in `check_disconnect_errors'
/var/log/foreman/dynflow_executor.output:4328:  from /opt/theforeman/tfm/root/usr/share/gems/gems/sequel-5.7.1/lib/sequel/adapters/postgres.rb:478:in `check_database_errors'
/var/log/foreman/dynflow_executor.output:4335:E, [2019-12-12T12:53:38.735288 #31755] ERROR -- /parallel-executor-core/pool remote_execution/worker-9: PG::ConnectionBad: PQsocket() can't get socket descriptor: SET client_min_messages TO 'warning' (ActiveRecord::StatementInvalid)
/var/log/foreman/dynflow_executor.output:4385:E, [2019-12-12T12:53:38.736658 #31755] ERROR -- /client-dispatcher: PG::UnableToSend: server closed the connection unexpectedly
/var/log/foreman/dynflow_executor.output:4388:Screenshot from 2019-12-12 14-52-36 (Sequel::DatabaseDisconnectError)
/var/log/foreman/dynflow_executor.output:4394:/opt/theforeman/tfm/root/usr/share/gems/gems/sequel-5.7.1/lib/sequel/adapters/postgres.rb:110:in `check_disconnect_errors'
/var/log/foreman/dynflow_executor.output:4398:/opt/theforeman/tfm/root/usr/share/gems/gems/sequel-5.7.1/lib/sequel/adapters/postgres.rb:478:in `check_database_errors'
/var/log/foreman/dynflow_executor.output:4461:E, [2019-12-12T12:53:38.737053 #31755] ERROR -- /client-dispatcher: Could not find an executor for Dynflow::Dispatcher::Envelope[request_id: 704cbd77-8b17-4f63-9183-d89b573354ec-86, sender_id: 704cbd77-8b17-4f63-9183-d89b573354ec, receiver_id: Dynflow::Dispatcher::UnknownWorld, message: Dynflow::Dispatcher::Event[execution_plan_id: 8765f669-0c1d-4cb9-abe6-406d00b2d879, step_id: 2, event: Dynflow::Action::WithPollingSubPlans::Poll, time: 2019-12-12 12:53:38 -0600]] (Dynflow::Error)
/var/log/foreman/dynflow_executor.output:4501:E, [2019-12-12T12:53:42.656345 #31755] ERROR -- /parallel-executor-core: PG::ConnectionBad: could not connect to server: No such file or directory
/var/log/foreman/dynflow_executor.output:4504: (Sequel::DatabaseConnectionError)
/var/log/foreman/dynflow_executor.output:4547:E, [2019-12-12T12:53:48.052907 #31755] ERROR -- /connector-database-core: caused by Sequel::DatabaseConnectionError: PG::ConnectionBad: could not connect to server: No such file or directory
/var/log/foreman/dynflow_executor.output:4550: (Dynflow::Errors::FatalPersistenceError)
/var/log/foreman/dynflow_executor.output:4590:E, [2019-12-12T12:53:48.065080 #31755] ERROR -- /connector-database-core: Receiving envelopes failed on PG::ConnectionBad: could not connect to server: No such file or directory
/var/log/foreman/dynflow_executor.output:4594:E, [2019-12-12T12:53:58.076393 #31755] ERROR -- /connector-database-core: PG::ConnectionBad: could not connect to server: No such file or directory
/var/log/foreman/dynflow_executor.output:4597: (Sequel::DatabaseConnectionError)
/var/log/foreman-proxy/smart_proxy_dynflow_core.log:13:no implicit conversion of Dynflow::Utils::IndifferentHash into String (TypeError)
/var/log/foreman-proxy/smart_proxy_dynflow_core.log:39:/opt/theforeman/tfm/root/usr/share/gems/gems/dynflow-1.4.1/lib/dynflow/action.rb:475:in `block in with_error_handling'
/var/log/foreman-proxy/smart_proxy_dynflow_core.log:41:/opt/theforeman/tfm/root/usr/share/gems/gems/dynflow-1.4.1/lib/dynflow/action.rb:475:in `with_error_handling'
/var/log/foreman-proxy/smart_proxy_dynflow_core.log:95:no implicit conversion of Dynflow::Utils::IndifferentHash into String (TypeError)
/var/log/foreman-proxy/smart_proxy_dynflow_core.log:121:/opt/theforeman/tfm/root/usr/share/gems/gems/dynflow-1.4.1/lib/dynflow/action.rb:475:in `block in with_error_handling'
/var/log/foreman-proxy/smart_proxy_dynflow_core.log:123:/opt/theforeman/tfm/root/usr/share/gems/gems/dynflow-1.4.1/lib/dynflow/action.rb:475:in `with_error_handling'
/var/log/foreman-proxy/smart_proxy_dynflow_core.log:418:no implicit conversion of Dynflow::Utils::IndifferentHash into String (TypeError)
/var/log/foreman-proxy/smart_proxy_dynflow_core.log:444:/opt/theforeman/tfm/root/usr/share/gems/gems/dynflow-1.4.1/lib/dynflow/action.rb:475:in `block in with_error_handling'
/var/log/foreman-proxy/smart_proxy_dynflow_core.log:446:/opt/theforeman/tfm/root/usr/share/gems/gems/dynflow-1.4.1/lib/dynflow/action.rb:475:in `with_error_handling'
/var/log/foreman-proxy/smart_proxy_dynflow_core.log:570:no implicit conversion of Dynflow::Utils::IndifferentHash into String (TypeError)
/var/log/foreman-proxy/smart_proxy_dynflow_core.log:596:/opt/theforeman/tfm/root/usr/share/gems/gems/dynflow-1.4.1/lib/dynflow/action.rb:475:in `block in with_error_handling'
/var/log/foreman-proxy/smart_proxy_dynflow_core.log:598:/opt/theforeman/tfm/root/usr/share/gems/gems/dynflow-1.4.1/lib/dynflow/action.rb:475:in `with_error_handling'
/var/log/foreman-proxy/smart_proxy_dynflow_core.log:744:no implicit conversion of Dynflow::Utils::IndifferentHash into String (TypeError)
/var/log/foreman-proxy/smart_proxy_dynflow_core.log:770:/opt/theforeman/tfm/root/usr/share/gems/gems/dynflow-1.4.1/lib/dynflow/action.rb:475:in `block in with_error_handling'
/var/log/foreman-proxy/smart_proxy_dynflow_core.log:772:/opt/theforeman/tfm/root/usr/share/gems/gems/dynflow-1.4.1/lib/dynflow/action.rb:475:in `with_error_handling'
/var/log/foreman-proxy/smart_proxy_dynflow_core.log:877:no implicit conversion of Dynflow::Utils::IndifferentHash into String (TypeError)
/var/log/foreman-proxy/smart_proxy_dynflow_core.log:903:/opt/theforeman/tfm/root/usr/share/gems/gems/dynflow-1.4.1/lib/dynflow/action.rb:475:in `block in with_error_handling'
/var/log/foreman-proxy/smart_proxy_dynflow_core.log:905:/opt/theforeman/tfm/root/usr/share/gems/gems/dynflow-1.4.1/lib/dynflow/action.rb:475:in `with_error_handling'
/var/log/foreman-proxy/smart_proxy_dynflow_core.log:1064:no implicit conversion of Dynflow::Utils::IndifferentHash into String (TypeError)
/var/log/foreman-proxy/smart_proxy_dynflow_core.log:1090:/opt/theforeman/tfm/root/usr/share/gems/gems/dynflow-1.4.1/lib/dynflow/action.rb:475:in `block in with_error_handling'
/var/log/foreman-proxy/smart_proxy_dynflow_core.log:1092:/opt/theforeman/tfm/root/usr/share/gems/gems/dynflow-1.4.1/lib/dynflow/action.rb:475:in `with_error_handling'
/var/log/foreman-proxy/smart_proxy_dynflow_core.log:1217:SSL_accept returned=1 errno=0 state=SSLv3 read client certificate A: sslv3 alert certificate unknown (OpenSSL::SSL::SSLError)
/var/log/foreman-proxy/smart_proxy_dynflow_core.log:1221:/opt/rh/rh-ruby25/root/usr/share/ruby/webrick/server.rb:297:in `block in start_thread'SSL_accept returned=1 errno=0 state=SSLv3 read client certificate A: sslv3 alert certificate unknown (OpenSSL::SSL::SSLError)
/var/log/foreman-proxy/smart_proxy_dynflow_core.log:1225:/opt/rh/rh-ruby25/root/usr/share/ruby/webrick/server.rb:297:in `block in start_thread'SSL_accept returned=1 errno=0 state=SSLv3 read client certificate A: sslv3 alert certificate unknown (OpenSSL::SSL::SSLError)
/var/log/foreman-proxy/smart_proxy_dynflow_core.log:1229:/opt/rh/rh-ruby25/root/usr/share/ruby/webrick/server.rb:297:in `block in start_thread'SSL_accept returned=1 errno=0 state=SSLv3 read client certificate A: sslv3 alert certificate unknown (OpenSSL::SSL::SSLError)
/var/log/foreman-proxy/smart_proxy_dynflow_core.log:1233:/opt/rh/rh-ruby25/root/usr/share/ruby/webrick/server.rb:297:in `block in start_thread'SSL_accept returned=1 errno=0 state=SSLv3 read client certificate A: sslv3 alert certificate unknown (OpenSSL::SSL::SSLError)
/var/log/foreman-proxy/smart_proxy_dynflow_core.log:1237:/opt/rh/rh-ruby25/root/usr/share/ruby/webrick/server.rb:297:in `block in start_thread'SSL_accept returned=1 errno=0 state=SSLv3 read client certificate A: sslv3 alert certificate unknown (OpenSSL::SSL::SSLError)
/var/log/foreman-proxy/smart_proxy_dynflow_core.log:1241:/opt/rh/rh-ruby25/root/usr/share/ruby/webrick/server.rb:297:in `block in start_thread'SSL_accept returned=1 errno=0 state=SSLv3 read client certificate A: sslv3 alert certificate unknown (OpenSSL::SSL::SSLError)
/var/log/foreman-proxy/smart_proxy_dynflow_core.log:1245:/opt/rh/rh-ruby25/root/usr/share/ruby/webrick/server.rb:297:in `block in start_thread'SSL_accept SYSCALL returned=5 errno=0 state=SSLv3 read client certificate A (OpenSSL::SSL::SSLError)
/var/log/foreman-proxy/smart_proxy_dynflow_core.log:1277:no implicit conversion of Dynflow::Utils::IndifferentHash into String (TypeError)
/var/log/foreman-proxy/smart_proxy_dynflow_core.log:1303:/opt/theforeman/tfm/root/usr/share/gems/gems/dynflow-1.4.1/lib/dynflow/action.rb:475:in `block in with_error_handling'
/var/log/foreman-proxy/smart_proxy_dynflow_core.log:1305:/opt/theforeman/tfm/root/usr/share/gems/gems/dynflow-1.4.1/lib/dynflow/action.rb:475:in `with_error_handling'
/var/log/foreman-proxy/smart_proxy_dynflow_core.log:1395:no implicit conversion of Dynflow::Utils::IndifferentHash into String (TypeError)
/var/log/foreman-proxy/smart_proxy_dynflow_core.log:1421:/opt/theforeman/tfm/root/usr/share/gems/gems/dynflow-1.4.1/lib/dynflow/action.rb:475:in `block in with_error_handling'
/var/log/foreman-proxy/smart_proxy_dynflow_core.log:1423:/opt/theforeman/tfm/root/usr/share/gems/gems/dynflow-1.4.1/lib/dynflow/action.rb:475:in `with_error_handling'
/var/log/foreman-proxy/smart_proxy_dynflow_core.log:1500:SSL_accept SYSCALL returned=5 errno=0 state=SSLv2/v3 read client hello A (OpenSSL::SSL::SSLError)
/var/log/foreman-proxy/smart_proxy_dynflow_core.log:1504:/opt/rh/rh-ruby25/root/usr/share/ruby/webrick/server.rb:297:in `block in start_thread'SSL_accept SYSCALL returned=5 errno=0 state=SSLv2/v3 read client hello A (OpenSSL::SSL::SSLError)

dil · December 12, 2019, 10:44pm

OS is CentOS 7 and dynflow works fine with subscriptions

Step ace63e76-4d5f-4947-a811-ff7b1bb98f66: 2 suspended >> running in phase Run ForemanTasksCore::SingleRunnerBatchAction Step ace63e76-4d5f-4947-a811-ff7b1bb98f66: 2 running >> suspended in phase Run ForemanTasksCore::SingleRunnerBatchActionExecutor heartbeat Step ace63e76-4d5f-4947-a811-ff7b1bb98f66: 2 got event Dynflow::Action::WithPollingSubPlans::Poll Step ace63e76-4d5f-4947-a811-ff7b1bb98f66: 2
suspended >> running in phase Run ForemanTasksCore::SingleRunnerBatchAction Step ace63e76-4d5f-4947-a811-ff7b1bb98f66: 2 running >> suspended in phase Run ForemanTasksCore::SingleRunnerBatchAction

kraba · December 13, 2019, 8:46am

I had the same issue and I rollbacked 1.24 from 1.23.1, recurring logics (ansibe callback) and ansible playbook were in pending state. I cleaned all the jobs, task and recreated recurring from scratch but nothing changed.

aruzicka · December 16, 2019, 9:12am

You have a lot of database connection errors in there. Without reliable connection to database, things can’t really work reliably.

Also it seems you have wrongly configured ssl certs for smart proxy dynflow core. How did you deploy this instance? Have you used the installer?

dil · December 16, 2019, 12:16pm

Upgraded using foreman-installer --scenario katello --upgrade from 1.23 to 1.24. The previous release did not have any issues and worked fine. What ssl certs should dynflow be using? The ssl certs are the katello certs that were generated and are in use by foreman/katello.

UXabre · December 16, 2019, 2:06pm

I have the same problem with vanilla foreman. Only updated from 1.23 → 1.24 and it stopped working. Other REX tasks, like running an SSH task do seem to work. So for me it seems like the issue is caused when using Ansible. When I check my logs, it seems like something is going wrong though it returns a HTTP code 200:

127.0.0.1 - - [16/Dec/2019:14:04:25 UTC] "GET /tasks/count?state=running HTTP/1.1" 200 29
127.0.0.1 - - [16/Dec/2019:14:04:26 UTC] "GET /tasks/04b7f3f5-995b-4dba-8550-9dc27996a600/status? HTTP/1.1" 200 25093
127.0.0.1 - - [16/Dec/2019:14:04:27 UTC] "GET /tasks/04b7f3f5-995b-4dba-8550-9dc27996a600/status? HTTP/1.1" 200 25093
127.0.0.1 - - [16/Dec/2019:14:04:29 UTC] "GET /tasks/04b7f3f5-995b-4dba-8550-9dc27996a600/status? HTTP/1.1" 200 25093
no implicit conversion of Dynflow::Utils::IndifferentHash into String (TypeError)
/opt/rh/rh-ruby25/root/usr/share/ruby/json/common.rb:156:in `initialize'
/opt/rh/rh-ruby25/root/usr/share/ruby/json/common.rb:156:in `new'
/opt/rh/rh-ruby25/root/usr/share/ruby/json/common.rb:156:in `parse'
/opt/theforeman/tfm/root/usr/share/gems/gems/foreman_ansible_core-3.0.1/lib/foreman_ansible_core/runner/ansible_runner.rb:123:in `block in rebuild_inventory'
/opt/theforeman/tfm/root/usr/share/gems/gems/foreman_ansible_core-3.0.1/lib/foreman_ansible_core/runner/ansible_runner.rb:123:in `map'
/opt/theforeman/tfm/root/usr/share/gems/gems/foreman_ansible_core-3.0.1/lib/foreman_ansible_core/runner/ansible_runner.rb:123:in `rebuild_inventory'
/opt/theforeman/tfm/root/usr/share/gems/gems/foreman_ansible_core-3.0.1/lib/foreman_ansible_core/runner/ansible_runner.rb:8:in `initialize'
/opt/theforeman/tfm/root/usr/share/gems/gems/foreman-tasks-core-0.3.3/lib/foreman_tasks_core/batch_runner_action.rb:11:in `new'
/opt/theforeman/tfm/root/usr/share/gems/gems/foreman-tasks-core-0.3.3/lib/foreman_tasks_core/batch_runner_action.rb:11:in `initiate_runner'
/opt/theforeman/tfm/root/usr/share/gems/gems/foreman-tasks-core-0.3.3/lib/foreman_tasks_core/runner/action.rb:40:in `init_run'
/opt/theforeman/tfm/root/usr/share/gems/gems/foreman-tasks-core-0.3.3/lib/foreman_tasks_core/runner/action.rb:10:in `run'
/opt/theforeman/tfm/root/usr/share/gems/gems/dynflow-1.4.1/lib/dynflow/action.rb:563:in `block (3 levels) in execute_run'
/opt/theforeman/tfm/root/usr/share/gems/gems/dynflow-1.4.1/lib/dynflow/middleware/stack.rb:27:in `pass'
/opt/theforeman/tfm/root/usr/share/gems/gems/dynflow-1.4.1/lib/dynflow/middleware.rb:19:in `pass'
/opt/theforeman/tfm/root/usr/share/gems/gems/dynflow-1.4.1/lib/dynflow/action/progress.rb:31:in `with_progress_calculation'
/opt/theforeman/tfm/root/usr/share/gems/gems/dynflow-1.4.1/lib/dynflow/action/progress.rb:17:in `run'
/opt/theforeman/tfm/root/usr/share/gems/gems/dynflow-1.4.1/lib/dynflow/middleware/stack.rb:23:in `call'
/opt/theforeman/tfm/root/usr/share/gems/gems/dynflow-1.4.1/lib/dynflow/middleware/stack.rb:27:in `pass'
/opt/theforeman/tfm/root/usr/share/gems/gems/dynflow-1.4.1/lib/dynflow/middleware.rb:19:in `pass'
/opt/theforeman/tfm/root/usr/share/gems/gems/dynflow-1.4.1/lib/dynflow/middleware.rb:32:in `run'
/opt/theforeman/tfm/root/usr/share/gems/gems/dynflow-1.4.1/lib/dynflow/middleware/stack.rb:23:in `call'
/opt/theforeman/tfm/root/usr/share/gems/gems/dynflow-1.4.1/lib/dynflow/middleware/world.rb:31:in `execute'
/opt/theforeman/tfm/root/usr/share/gems/gems/dynflow-1.4.1/lib/dynflow/action.rb:562:in `block (2 levels) in execute_run'
/opt/theforeman/tfm/root/usr/share/gems/gems/dynflow-1.4.1/lib/dynflow/action.rb:561:in `catch'
/opt/theforeman/tfm/root/usr/share/gems/gems/dynflow-1.4.1/lib/dynflow/action.rb:561:in `block in execute_run'
/opt/theforeman/tfm/root/usr/share/gems/gems/dynflow-1.4.1/lib/dynflow/action.rb:475:in `block in with_error_handling'
/opt/theforeman/tfm/root/usr/share/gems/gems/dynflow-1.4.1/lib/dynflow/action.rb:475:in `catch'
/opt/theforeman/tfm/root/usr/share/gems/gems/dynflow-1.4.1/lib/dynflow/action.rb:475:in `with_error_handling'
/opt/theforeman/tfm/root/usr/share/gems/gems/dynflow-1.4.1/lib/dynflow/action.rb:556:in `execute_run'
/opt/theforeman/tfm/root/usr/share/gems/gems/dynflow-1.4.1/lib/dynflow/action.rb:285:in `execute'
/opt/theforeman/tfm/root/usr/share/gems/gems/dynflow-1.4.1/lib/dynflow/execution_plan/steps/abstract_flow_step.rb:18:in `block (2 levels) in execute'
/opt/theforeman/tfm/root/usr/share/gems/gems/dynflow-1.4.1/lib/dynflow/execution_plan/steps/abstract.rb:167:in `with_meta_calculation'
/opt/theforeman/tfm/root/usr/share/gems/gems/dynflow-1.4.1/lib/dynflow/execution_plan/steps/abstract_flow_step.rb:17:in `block in execute'
/opt/theforeman/tfm/root/usr/share/gems/gems/dynflow-1.4.1/lib/dynflow/execution_plan/steps/abstract_flow_step.rb:32:in `open_action'
/opt/theforeman/tfm/root/usr/share/gems/gems/dynflow-1.4.1/lib/dynflow/execution_plan/steps/abstract_flow_step.rb:16:in `execute'
/opt/theforeman/tfm/root/usr/share/gems/gems/dynflow-1.4.1/lib/dynflow/director.rb:68:in `execute'
/opt/theforeman/tfm/root/usr/share/gems/gems/dynflow-1.4.1/lib/dynflow/executors/parallel/worker.rb:15:in `block in on_message'
/opt/theforeman/tfm/root/usr/share/gems/gems/dynflow-1.4.1/lib/dynflow/executors.rb:12:in `run_user_code'
/opt/theforeman/tfm/root/usr/share/gems/gems/dynflow-1.4.1/lib/dynflow/executors/parallel/worker.rb:14:in `on_message'
/opt/theforeman/tfm/root/usr/share/gems/gems/concurrent-ruby-edge-0.4.1/lib-edge/concurrent/actor/context.rb:46:in `on_envelope'
/opt/theforeman/tfm/root/usr/share/gems/gems/concurrent-ruby-edge-0.4.1/lib-edge/concurrent/actor/behaviour/executes_context.rb:7:in `on_envelope'
/opt/theforeman/tfm/root/usr/share/gems/gems/concurrent-ruby-edge-0.4.1/lib-edge/concurrent/actor/behaviour/abstract.rb:25:in `pass'
/opt/theforeman/tfm/root/usr/share/gems/gems/dynflow-1.4.1/lib/dynflow/actor.rb:106:in `on_envelope'
/opt/theforeman/tfm/root/usr/share/gems/gems/concurrent-ruby-edge-0.4.1/lib-edge/concurrent/actor/behaviour/abstract.rb:25:in `pass'
/opt/theforeman/tfm/root/usr/share/gems/gems/concurrent-ruby-edge-0.4.1/lib-edge/concurrent/actor/behaviour/awaits.rb:15:in `on_envelope'
/opt/theforeman/tfm/root/usr/share/gems/gems/concurrent-ruby-edge-0.4.1/lib-edge/concurrent/actor/behaviour/abstract.rb:25:in `pass'
/opt/theforeman/tfm/root/usr/share/gems/gems/concurrent-ruby-edge-0.4.1/lib-edge/concurrent/actor/behaviour/sets_results.rb:14:in `on_envelope'
/opt/theforeman/tfm/root/usr/share/gems/gems/dynflow-1.4.1/lib/dynflow/actor.rb:47:in `block in on_envelope'
/opt/theforeman/tfm/root/usr/share/gems/gems/dynflow-1.4.1/lib/dynflow/actor.rb:59:in `with_backtrace'
/opt/theforeman/tfm/root/usr/share/gems/gems/dynflow-1.4.1/lib/dynflow/actor.rb:47:in `on_envelope'
/opt/theforeman/tfm/root/usr/share/gems/gems/concurrent-ruby-edge-0.4.1/lib-edge/concurrent/actor/behaviour/abstract.rb:25:in `pass'
/opt/theforeman/tfm/root/usr/share/gems/gems/concurrent-ruby-edge-0.4.1/lib-edge/concurrent/actor/behaviour/buffer.rb:38:in `process_envelope'
/opt/theforeman/tfm/root/usr/share/gems/gems/concurrent-ruby-edge-0.4.1/lib-edge/concurrent/actor/behaviour/buffer.rb:31:in `process_envelopes?'
/opt/theforeman/tfm/root/usr/share/gems/gems/concurrent-ruby-edge-0.4.1/lib-edge/concurrent/actor/behaviour/buffer.rb:20:in `on_envelope'
/opt/theforeman/tfm/root/usr/share/gems/gems/concurrent-ruby-edge-0.4.1/lib-edge/concurrent/actor/behaviour/abstract.rb:25:in `pass'
/opt/theforeman/tfm/root/usr/share/gems/gems/concurrent-ruby-edge-0.4.1/lib-edge/concurrent/actor/behaviour/termination.rb:55:in `on_envelope'
/opt/theforeman/tfm/root/usr/share/gems/gems/concurrent-ruby-edge-0.4.1/lib-edge/concurrent/actor/behaviour/abstract.rb:25:in `pass'
/opt/theforeman/tfm/root/usr/share/gems/gems/concurrent-ruby-edge-0.4.1/lib-edge/concurrent/actor/behaviour/removes_child.rb:10:in `on_envelope'
/opt/theforeman/tfm/root/usr/share/gems/gems/concurrent-ruby-edge-0.4.1/lib-edge/concurrent/actor/behaviour/abstract.rb:25:in `pass'
/opt/theforeman/tfm/root/usr/share/gems/gems/concurrent-ruby-edge-0.4.1/lib-edge/concurrent/actor/behaviour/sets_results.rb:14:in `on_envelope'
/opt/theforeman/tfm/root/usr/share/gems/gems/concurrent-ruby-edge-0.4.1/lib-edge/concurrent/actor/core.rb:162:in `process_envelope'
/opt/theforeman/tfm/root/usr/share/gems/gems/concurrent-ruby-edge-0.4.1/lib-edge/concurrent/actor/core.rb:96:in `block in on_envelope'
/opt/theforeman/tfm/root/usr/share/gems/gems/concurrent-ruby-edge-0.4.1/lib-edge/concurrent/actor/core.rb:119:in `block (2 levels) in schedule_execution'
/opt/theforeman/tfm-ror52/root/usr/share/gems/gems/concurrent-ruby-1.1.4/lib/concurrent/synchronization/mutex_lockable_object.rb:41:in `block in synchronize'
/opt/theforeman/tfm-ror52/root/usr/share/gems/gems/concurrent-ruby-1.1.4/lib/concurrent/synchronization/mutex_lockable_object.rb:41:in `synchronize'
/opt/theforeman/tfm-ror52/root/usr/share/gems/gems/concurrent-ruby-1.1.4/lib/concurrent/synchronization/mutex_lockable_object.rb:41:in `synchronize'
/opt/theforeman/tfm/root/usr/share/gems/gems/concurrent-ruby-edge-0.4.1/lib-edge/concurrent/actor/core.rb:116:in `block in schedule_execution'
/opt/theforeman/tfm-ror52/root/usr/share/gems/gems/concurrent-ruby-1.1.4/lib/concurrent/executor/serialized_execution.rb:18:in `call'
/opt/theforeman/tfm-ror52/root/usr/share/gems/gems/concurrent-ruby-1.1.4/lib/concurrent/executor/serialized_execution.rb:96:in `work'
/opt/theforeman/tfm-ror52/root/usr/share/gems/gems/concurrent-ruby-1.1.4/lib/concurrent/executor/serialized_execution.rb:77:in `block in call_job'
/opt/theforeman/tfm-ror52/root/usr/share/gems/gems/concurrent-ruby-1.1.4/lib/concurrent/executor/ruby_thread_pool_executor.rb:348:in `run_task'
/opt/theforeman/tfm-ror52/root/usr/share/gems/gems/concurrent-ruby-1.1.4/lib/concurrent/executor/ruby_thread_pool_executor.rb:337:in `block (3 levels) in create_worker'
/opt/theforeman/tfm-ror52/root/usr/share/gems/gems/concurrent-ruby-1.1.4/lib/concurrent/executor/ruby_thread_pool_executor.rb:320:in `loop'
/opt/theforeman/tfm-ror52/root/usr/share/gems/gems/concurrent-ruby-1.1.4/lib/concurrent/executor/ruby_thread_pool_executor.rb:320:in `block (2 levels) in create_worker'
/opt/theforeman/tfm-ror52/root/usr/share/gems/gems/concurrent-ruby-1.1.4/lib/concurrent/executor/ruby_thread_pool_executor.rb:319:in `catch'
/opt/theforeman/tfm-ror52/root/usr/share/gems/gems/concurrent-ruby-1.1.4/lib/concurrent/executor/ruby_thread_pool_executor.rb:319:in `block in create_worker'127.0.0.1 - - [16/Dec/2019:14:04:31 UTC] "GET /tasks/04b7f3f5-995b-4dba-8550-9dc27996a600/status? HTTP/1.1" 200 25093

Currently I’m a a loss to figure out how to resolve this issue

Kind regards,
Arend

aruzicka · December 16, 2019, 2:33pm

Ahh, now this rings a bell! It should be fixed as part of this issue https://github.com/theforeman/foreman_ansible/pull/295 . It should be fixed in foreman_ansible_core-3.0.2, which is not in 1.24 repos yet, but I hope it should get in there soon.

dil · December 16, 2019, 2:57pm

Step",
“a1875166-77a0-43aa-8250-1a72f37eaf5e:”,
“2”,
“”,
“”,
“pending”,
“>>”,
“”,
“”,
“running”,
“in”,
“phase”,
“”,
“”,
“”,
“”,
“”,
“Run”,
“ForemanTasksCore::BatchRunnerActionno”,
“implicit”,
“conversion”,
“of”,
“Dynflow::Utils::IndifferentHash”,
“into”,
“String”,
“(TypeError)”
]
[
“/var/log/foreman-proxy/smart_proxy_dynflow_core.log:191:/opt/theforeman/tfm/root/usr/share/gems/gems/dynflow-1.4.1/lib/dynflow/action.rb:475:in”,
“block", "in", "with_error_handling'" ] [ "/var/log/foreman-proxy/smart_proxy_dynflow_core.log:193:/opt/theforeman/tfm/root/usr/share/gems/gems/dynflow-1.4.1/lib/dynflow/action.rb:475:in", "with_error_handling’”
]
[
“/var/log/foreman-proxy/smart_proxy_dynflow_core.log:242:close:”,

UXabre · December 17, 2019, 8:46am

Hi thanks! Will check it out as soon as it is released (or will check it out if it’s available as rubygem, whatever comes first :p)

UXabre · December 17, 2019, 9:12am

Hi! Just want to inform you that updating ansible-core to 3.02 (on the smart proxies that is) fixed the issue!
I used the RPM from here: https://yum.theforeman.org/plugins/nightly/el7/x86_64/ (but it’s targeted for 1.25 so at this point unofficial for 1.24)

cintrix84 · December 17, 2019, 5:51pm

Thanks @UXabre

I marked this comment as the Solution so people can find how to resolve the issue until it gets brought into a release.

dil · December 17, 2019, 10:32pm

After upgrading to ansible-core 3.0.2 I am now getting this in the logs

019-12-17 16:04:07,131 p=foreman-proxy u=10881 | [WARNING]: * Failed to parse /tmp/d20191217-8372-e184s8/inventory/hosts with
script plugin: failed to parse executable inventory script results from
/tmp/d20191217-8372-e184s8/inventory/hosts: Syntax Error while loading YAML.
found unknown escape character The error appears to be in ‘’: line 1,
column 4128, but may be elsewhere in the file depending on the exact syntax
problem.

2019-12-17 16:04:07,131 p=foreman-proxy u=10881 | [WARNING]: * Failed to parse /tmp/d20191217-8372-e184s8/inventory/hosts with
yaml plugin: YAML inventory has invalid structure, it should be a dictionary,
got: <class ‘ansible.parsing.yaml.objects.AnsibleUnicode’>

2019-12-17 16:04:07,131 p=foreman-proxy u=10881 | [WARNING]: * Failed to parse /tmp/d20191217-8372-e184s8/inventory/hosts with
ini plugin: /tmp/d20191217-8372-e184s8/inventory/hosts:2: Expected key=value
host variable assignment, got: <<-EOS

2019-12-17 16:04:07,132 p=foreman-proxy u=10881 | [WARNING]: Unable to parse /tmp/d20191217-8372-e184s8/inventory/hosts as an
inventory source

2019-12-17 16:04:07,132 p=foreman-proxy u=10881 | [WARNING]: Unable to parse /tmp/d20191217-8372-e184s8/inventory as an inventory
source

2019-12-17 16:04:07,132 p=foreman-proxy u=10881 | [WARNING]: No inventory was parsed, only implicit localhost is available

2019-12-17 16:04:07,133 p=foreman-proxy u=10881 | [WARNING]: provided hosts list is empty, only localhost is available. Note that
the implicit localhost does not match ‘all’

2019-12-17 16:04:07,439 p=foreman-proxy u=10881 | PLAY [all] *********************************************************************
2019-12-17 16:04:07,440 p=foreman-proxy u=10881 | skipping: no hosts matched
2019-12-17 16:04:07,440 p=foreman-proxy u=10881 | PLAY RECAP *********************************************************************

dil · December 17, 2019, 11:15pm

When I run the ansible play book it creates a /tmp/d20191217-8372-e184s8/inventory/hosts with this inside “{”_meta":{“hostvars”:{“blah-hostname”:{“foreman”:{“kt_env”:null,“kt_cv”:null,“foreman_host_collections”:,“lifecycle_environment”:null,“content_view”:null,“content_view_info”:{},“hostgroup”
:“Server”,“foreman_subnets”: …

dil · December 19, 2019, 3:05am

I have also notice that the ansible smart proxy did not get updated, it is still version 1.23

rpm -qa | grep ansible
tfm-rubygem-foreman_ansible-4.0.3-1.fm1_24.el7.noarch
tfm-rubygem-pulp_ansible_client-0.2.0b1.dev0.1560866833-1.el7.noarch
tfm-rubygem-hammer_cli_foreman_ansible-0.3.2-1.fm1_24.el7.noarch
rubygem-smart_proxy_ansible-3.0.1-1.fm1_23.el7.noarch
ansible-runner-1.4.4-1.el7.noarch
tfm-rubygem-foreman_ansible_core-3.0.1-1.fm1_24.el7.noarch
ansible-2.9.1-1.el7.noarch
python2-ansible-runner-1.4.4-1.el7.noarch