Problem:
I have upgraded from 2.5.4/4.1.4 through 3.0/4.2 to 3.1.1/4.3.0 without problems. Now I cannot run remote execution jobs anymore. They immediately end with an exception and “Job execution failed”
ssh_exchange_identification: Connection closed by remote host
This would hint towards not being to able to negotiate connection parameters with the remote host. Could you add :ssh_log_level: debug to /etc/foreman-proxy/settings.d/remote_execution.yml, restart foreman-proxy service, try running the job again and then checking the log once more?
O.K. I have set :ssh_log_level: debug in /etc/foreman-proxy/settings.d/remote_execution.yml and :log_level: DEBUG in /etc/foreman-proxy/settings.yml because otherwise it doesn’t start the ssh feature.
Output in proxy.log is at the end. I have tried to call ssh manually and it doesn’t work either when using foreman-proxy user:
[root@foreman settings.d]# sudo -u foreman-proxy ssh root@c7build.example.com -i /usr/share/foreman-proxy/.ssh/id_rsa_foreman_proxy.pub -v
OpenSSH_7.4p1, OpenSSL 1.0.2k-fips 26 Jan 2017
debug1: Reading configuration data /etc/ssh/ssh_config
debug1: /etc/ssh/ssh_config line 62: Applying options for *
debug1: Executing proxy command: exec /usr/bin/sss_ssh_knownhostsproxy -p 22 c7build.example.com
debug1: permanently_drop_suid: 493
debug1: identity file /usr/share/foreman-proxy/.ssh/id_rsa_foreman_proxy.pub type 1
debug1: key_load_public: No such file or directory
debug1: identity file /usr/share/foreman-proxy/.ssh/id_rsa_foreman_proxy.pub-cert type -1
debug1: Enabling compatibility mode for protocol 2.0
debug1: Local version string SSH-2.0-OpenSSH_7.4
ssh_exchange_identification: Connection closed by remote host
However, it does work perfectly, if I remove the sudo, i.e. run as root
Funny enough, I had to revert to my pre-update snapshot (i.e. Foreman 2.5.4) because of numerous other issues with 3.1/4.2. On Foreman 2.5.4 I see exactly the same. foreman-proxy cannot use the sss_ssh_knownhostsproxy because it has /bin/false set as shell in /etc/passwd. So that’s consistent.
However, remote execution does work with Foreman 2.5.4. So it seems to me as if with foreman 2.5.4 and foreman_remote_execution plugin 4.5.6, it calls ssh with ProxyCommand set to none or it is not using the default /etc/ssh/ssh_config at all, thus bypassing the proxy.
Here is the proxy.log output:
2022-02-02T18:39:42 [D] accept: 1234:1234:1234:19::1:52820
2022-02-02T18:39:42 [D] Rack::Handler::WEBrick is invoked.
2022-02-02T18:39:42 3d672662 [I] Started GET /dynflow/tasks/count state=running
2022-02-02T18:39:42 3d672662 [D] verifying remote client 1234:1234:1234:19::1 against trusted_hosts ["foreman.example.com"]
2022-02-02T18:39:42 3d672662 [I] Finished GET /dynflow/tasks/count with 200 (1.2 ms)
2022-02-02T18:39:42 [D] close: 1234:1234:1234:19::1:52820
2022-02-02T18:39:43 [D] accept: 1234:1234:1234:19::1:52822
2022-02-02T18:39:43 [D] Rack::Handler::WEBrick is invoked.
2022-02-02T18:39:43 3d672662 [I] Started POST /dynflow/tasks/launch
2022-02-02T18:39:43 3d672662 [D] verifying remote client 1234:1234:1234:19::1 against trusted_hosts ["foreman.example.com"]
2022-02-02T18:39:43 3d672662 [D] ExecutionPlan 8e60213b-b4d7-4f62-be9f-46ba374c54a9 pending >> planning
2022-02-02T18:39:43 3d672662 [D] Step 8e60213b-b4d7-4f62-be9f-46ba374c54a9: 1 pending >> running in phase Plan Proxy::Dynflow::Action::Batch
2022-02-02T18:39:43 3d672662 [D] ExecutionPlan ea790db9-2010-4c30-aa30-740f86f47e73 pending >> planning
2022-02-02T18:39:43 3d672662 [D] Step ea790db9-2010-4c30-aa30-740f86f47e73: 1 pending >> running in phase Plan Proxy::RemoteExecution::Ssh::Actions::RunScript
2022-02-02T18:39:43 3d672662 [D] Step ea790db9-2010-4c30-aa30-740f86f47e73: 2 pending >> running in phase Plan Proxy::RemoteExecution::Ssh::Actions::ScriptRunner
2022-02-02T18:39:43 3d672662 [D] Step ea790db9-2010-4c30-aa30-740f86f47e73: 5 pending >> running in phase Plan Proxy::Dynflow::Callback::Action
2022-02-02T18:39:43 3d672662 [D] Step ea790db9-2010-4c30-aa30-740f86f47e73: 5 running >> success in phase Plan Proxy::Dynflow::Callback::Action
2022-02-02T18:39:43 3d672662 [D] Step ea790db9-2010-4c30-aa30-740f86f47e73: 2 running >> success in phase Plan Proxy::RemoteExecution::Ssh::Actions::ScriptRunner
2022-02-02T18:39:43 3d672662 [D] Step ea790db9-2010-4c30-aa30-740f86f47e73: 1 running >> success in phase Plan Proxy::RemoteExecution::Ssh::Actions::RunScript
2022-02-02T18:39:43 3d672662 [D] ExecutionPlan ea790db9-2010-4c30-aa30-740f86f47e73 planning >> planned
2022-02-02T18:39:43 3d672662 [D] Step 8e60213b-b4d7-4f62-be9f-46ba374c54a9: 1 running >> success in phase Plan Proxy::Dynflow::Action::Batch
2022-02-02T18:39:43 3d672662 [D] ExecutionPlan 8e60213b-b4d7-4f62-be9f-46ba374c54a9 planning >> planned
2022-02-02T18:39:43 [D] ExecutionPlan ea790db9-2010-4c30-aa30-740f86f47e73 planned >> running
2022-02-02T18:39:43 [D] Step ea790db9-2010-4c30-aa30-740f86f47e73: 3 pending >> running in phase Run Proxy::RemoteExecution::Ssh::Actions::ScriptRunner
2022-02-02T18:39:43 3d672662 [D] Step ea790db9-2010-4c30-aa30-740f86f47e73: 3 running >> suspended in phase Run Proxy::RemoteExecution::Ssh::Actions::ScriptRunner
2022-02-02T18:39:43 [D] start runner e1efc663-6da4-47bb-a89c-e7ba2d4e24d5
2022-02-02T18:39:43 [D] copying script to /var/tmp/foreman-ssh-cmd-e1efc663-6da4-47bb-a89c-e7ba2d4e24d5/script:
| date
2022-02-02T18:39:43 [D] ExecutionPlan 8e60213b-b4d7-4f62-be9f-46ba374c54a9 planned >> running
2022-02-02T18:39:43 3d672662 [I] Finished POST /dynflow/tasks/launch with 200 (34.39 ms)
2022-02-02T18:39:43 [D] Step 8e60213b-b4d7-4f62-be9f-46ba374c54a9: 2 pending >> running in phase Run Proxy::Dynflow::Action::Batch
2022-02-02T18:39:43 3d672662 [D] Step 8e60213b-b4d7-4f62-be9f-46ba374c54a9: 2 running >> suspended in phase Run Proxy::Dynflow::Action::Batch
2022-02-02T18:39:43 [D] close: 1234:1234:1234:19::1:52822
2022-02-02T18:39:43 [D] debug1: Reading configuration data /etc/ssh/ssh_config
2022-02-02T18:39:43 [D] debug1: /etc/ssh/ssh_config line 62: Applying options for *
2022-02-02T18:39:43 [D] debug1: auto-mux: Trying existing master
2022-02-02T18:39:43 [D] debug1: Control socket "/var/tmp/foreman-proxy/foreman-ssh-cmd-e1efc663-6da4-47bb-a89c-e7ba2d4e24d5/socket" does not exist
2022-02-02T18:39:43 [D] debug1: Executing proxy command: exec /usr/bin/sss_ssh_knownhostsproxy -p 22 c7build.example.com
2022-02-02T18:39:43 [D] debug1: permanently_drop_suid: 493
2022-02-02T18:39:43 [D] debug1: identity file /var/lib/foreman-proxy/ssh/id_rsa_foreman_proxy type 1
2022-02-02T18:39:43 [D] debug1: key_load_public: No such file or directory
2022-02-02T18:39:43 [D] debug1: identity file /var/lib/foreman-proxy/ssh/id_rsa_foreman_proxy-cert type -1
2022-02-02T18:39:43 [D] debug1: Enabling compatibility mode for protocol 2.0
2022-02-02T18:39:43 [D] debug1: Local version string SSH-2.0-OpenSSH_7.4
2022-02-02T18:39:43 [D] ssh_exchange_identification: Connection closed by remote host
2022-02-02T18:39:43 [E] error while initializing command RuntimeError Unable to create directory on remote system /var/tmp/foreman-ssh-cmd-e1efc663-6da4-47bb-a89c-e7ba2d4e24d5: exit code: 255
debug1: Reading configuration data /etc/ssh/ssh_config
debug1: /etc/ssh/ssh_config line 62: Applying options for *
debug1: auto-mux: Trying existing master
debug1: Control socket "/var/tmp/foreman-proxy/foreman-ssh-cmd-e1efc663-6da4-47bb-a89c-e7ba2d4e24d5/socket" does not exist
debug1: Executing proxy command: exec /usr/bin/sss_ssh_knownhostsproxy -p 22 c7build.example.com
debug1: permanently_drop_suid: 493
debug1: identity file /var/lib/foreman-proxy/ssh/id_rsa_foreman_proxy type 1
debug1: key_load_public: No such file or directory
debug1: identity file /var/lib/foreman-proxy/ssh/id_rsa_foreman_proxy-cert type -1
debug1: Enabling compatibility mode for protocol 2.0
debug1: Local version string SSH-2.0-OpenSSH_7.4
ssh_exchange_identification: Connection closed by remote host
:
/opt/theforeman/tfm/root/usr/share/gems/gems/smart_proxy_remote_execution_ssh-0.5.1/lib/smart_proxy_remote_execution_ssh/runners/script_runner.rb:385:in `ensure_remote_directory'
/opt/theforeman/tfm/root/usr/share/gems/gems/smart_proxy_remote_execution_ssh-0.5.1/lib/smart_proxy_remote_execution_ssh/runners/script_runner.rb:359:in `upload_data'
/opt/theforeman/tfm/root/usr/share/gems/gems/smart_proxy_remote_execution_ssh-0.5.1/lib/smart_proxy_remote_execution_ssh/runners/script_runner.rb:355:in `cp_script_to_remote'
/opt/theforeman/tfm/root/usr/share/gems/gems/smart_proxy_remote_execution_ssh-0.5.1/lib/smart_proxy_remote_execution_ssh/runners/script_runner.rb:158:in `prepare_start'
/opt/theforeman/tfm/root/usr/share/gems/gems/smart_proxy_remote_execution_ssh-0.5.1/lib/smart_proxy_remote_execution_ssh/runners/script_runner.rb:144:in `start'
/opt/theforeman/tfm/root/usr/share/gems/gems/smart_proxy_dynflow-0.6.1/lib/smart_proxy_dynflow/runner/dispatcher.rb:32:in `start_runner'
/opt/theforeman/tfm/root/usr/share/gems/gems/dynflow-1.6.3/lib/dynflow/actor.rb:13:in `on_message'
/opt/theforeman/tfm/root/usr/share/gems/gems/concurrent-ruby-edge-0.6.0/lib/concurrent-ruby-edge/concurrent/actor/context.rb:46:in `on_envelope'
/opt/theforeman/tfm/root/usr/share/gems/gems/smart_proxy_dynflow-0.6.1/lib/smart_proxy_dynflow/runner/dispatcher.rb:24:in `on_envelope'
/opt/theforeman/tfm/root/usr/share/gems/gems/concurrent-ruby-edge-0.6.0/lib/concurrent-ruby-edge/concurrent/actor/behaviour/executes_context.rb:7:in `on_envelope'
/opt/theforeman/tfm/root/usr/share/gems/gems/concurrent-ruby-edge-0.6.0/lib/concurrent-ruby-edge/concurrent/actor/behaviour/abstract.rb:25:in `pass'
/opt/theforeman/tfm/root/usr/share/gems/gems/dynflow-1.6.3/lib/dynflow/actor.rb:122:in `on_envelope'
/opt/theforeman/tfm/root/usr/share/gems/gems/concurrent-ruby-edge-0.6.0/lib/concurrent-ruby-edge/concurrent/actor/behaviour/abstract.rb:25:in `pass'
/opt/theforeman/tfm/root/usr/share/gems/gems/concurrent-ruby-edge-0.6.0/lib/concurrent-ruby-edge/concurrent/actor/behaviour/awaits.rb:15:in `on_envelope'
/opt/theforeman/tfm/root/usr/share/gems/gems/concurrent-ruby-edge-0.6.0/lib/concurrent-ruby-edge/concurrent/actor/behaviour/abstract.rb:25:in `pass'
/opt/theforeman/tfm/root/usr/share/gems/gems/concurrent-ruby-edge-0.6.0/lib/concurrent-ruby-edge/concurrent/actor/behaviour/sets_results.rb:14:in `on_envelope'
/opt/theforeman/tfm/root/usr/share/gems/gems/dynflow-1.6.3/lib/dynflow/actor.rb:56:in `on_envelope'
/opt/theforeman/tfm/root/usr/share/gems/gems/concurrent-ruby-edge-0.6.0/lib/concurrent-ruby-edge/concurrent/actor/behaviour/abstract.rb:25:in `pass'
/opt/theforeman/tfm/root/usr/share/gems/gems/concurrent-ruby-edge-0.6.0/lib/concurrent-ruby-edge/concurrent/actor/behaviour/buffer.rb:38:in `process_envelope'
/opt/theforeman/tfm/root/usr/share/gems/gems/concurrent-ruby-edge-0.6.0/lib/concurrent-ruby-edge/concurrent/actor/behaviour/buffer.rb:31:in `process_envelopes?'
/opt/theforeman/tfm/root/usr/share/gems/gems/concurrent-ruby-edge-0.6.0/lib/concurrent-ruby-edge/concurrent/actor/behaviour/buffer.rb:20:in `on_envelope'
/opt/theforeman/tfm/root/usr/share/gems/gems/concurrent-ruby-edge-0.6.0/lib/concurrent-ruby-edge/concurrent/actor/behaviour/abstract.rb:25:in `pass'
/opt/theforeman/tfm/root/usr/share/gems/gems/concurrent-ruby-edge-0.6.0/lib/concurrent-ruby-edge/concurrent/actor/behaviour/termination.rb:55:in `on_envelope'
/opt/theforeman/tfm/root/usr/share/gems/gems/concurrent-ruby-edge-0.6.0/lib/concurrent-ruby-edge/concurrent/actor/behaviour/abstract.rb:25:in `pass'
/opt/theforeman/tfm/root/usr/share/gems/gems/concurrent-ruby-edge-0.6.0/lib/concurrent-ruby-edge/concurrent/actor/behaviour/removes_child.rb:10:in `on_envelope'
/opt/theforeman/tfm/root/usr/share/gems/gems/concurrent-ruby-edge-0.6.0/lib/concurrent-ruby-edge/concurrent/actor/behaviour/abstract.rb:25:in `pass'
/opt/theforeman/tfm/root/usr/share/gems/gems/concurrent-ruby-edge-0.6.0/lib/concurrent-ruby-edge/concurrent/actor/behaviour/sets_results.rb:14:in `on_envelope'
/opt/theforeman/tfm/root/usr/share/gems/gems/concurrent-ruby-edge-0.6.0/lib/concurrent-ruby-edge/concurrent/actor/core.rb:162:in `process_envelope'
/opt/theforeman/tfm/root/usr/share/gems/gems/concurrent-ruby-edge-0.6.0/lib/concurrent-ruby-edge/concurrent/actor/core.rb:96:in `block in on_envelope'
/opt/theforeman/tfm/root/usr/share/gems/gems/concurrent-ruby-edge-0.6.0/lib/concurrent-ruby-edge/concurrent/actor/core.rb:119:in `block (2 levels) in schedule_execution'
/opt/theforeman/tfm/root/usr/share/gems/gems/concurrent-ruby-1.1.6/lib/concurrent-ruby/concurrent/synchronization/mutex_lockable_object.rb:41:in `block in synchronize'
/opt/theforeman/tfm/root/usr/share/gems/gems/concurrent-ruby-1.1.6/lib/concurrent-ruby/concurrent/synchronization/mutex_lockable_object.rb:41:in `synchronize'
/opt/theforeman/tfm/root/usr/share/gems/gems/concurrent-ruby-1.1.6/lib/concurrent-ruby/concurrent/synchronization/mutex_lockable_object.rb:41:in `synchronize'
/opt/theforeman/tfm/root/usr/share/gems/gems/concurrent-ruby-edge-0.6.0/lib/concurrent-ruby-edge/concurrent/actor/core.rb:116:in `block in schedule_execution'
/opt/theforeman/tfm/root/usr/share/gems/gems/concurrent-ruby-1.1.6/lib/concurrent-ruby/concurrent/executor/serialized_execution.rb:18:in `call'
/opt/theforeman/tfm/root/usr/share/gems/gems/concurrent-ruby-1.1.6/lib/concurrent-ruby/concurrent/executor/serialized_execution.rb:96:in `work'
/opt/theforeman/tfm/root/usr/share/gems/gems/concurrent-ruby-1.1.6/lib/concurrent-ruby/concurrent/executor/serialized_execution.rb:77:in `block in call_job'
/opt/theforeman/tfm/root/usr/share/gems/gems/concurrent-ruby-1.1.6/lib/concurrent-ruby/concurrent/executor/ruby_thread_pool_executor.rb:353:in `run_task'
/opt/theforeman/tfm/root/usr/share/gems/gems/concurrent-ruby-1.1.6/lib/concurrent-ruby/concurrent/executor/ruby_thread_pool_executor.rb:342:in `block (3 levels) in create_worker'
/opt/theforeman/tfm/root/usr/share/gems/gems/concurrent-ruby-1.1.6/lib/concurrent-ruby/concurrent/executor/ruby_thread_pool_executor.rb:325:in `loop'
/opt/theforeman/tfm/root/usr/share/gems/gems/concurrent-ruby-1.1.6/lib/concurrent-ruby/concurrent/executor/ruby_thread_pool_executor.rb:325:in `block (2 levels) in create_worker'
/opt/theforeman/tfm/root/usr/share/gems/gems/concurrent-ruby-1.1.6/lib/concurrent-ruby/concurrent/executor/ruby_thread_pool_executor.rb:324:in `catch'
/opt/theforeman/tfm/root/usr/share/gems/gems/concurrent-ruby-1.1.6/lib/concurrent-ruby/concurrent/executor/ruby_thread_pool_executor.rb:324:in `block in create_worker'
/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'
2022-02-02T18:39:43 [E] Error initializing command - RuntimeError Unable to create directory on remote system /var/tmp/foreman-ssh-cmd-e1efc663-6da4-47bb-a89c-e7ba2d4e24d5: exit code: 255
debug1: Reading configuration data /etc/ssh/ssh_config
debug1: /etc/ssh/ssh_config line 62: Applying options for *
debug1: auto-mux: Trying existing master
debug1: Control socket "/var/tmp/foreman-proxy/foreman-ssh-cmd-e1efc663-6da4-47bb-a89c-e7ba2d4e24d5/socket" does not exist
debug1: Executing proxy command: exec /usr/bin/sss_ssh_knownhostsproxy -p 22 c7build.example.com
debug1: permanently_drop_suid: 493
debug1: identity file /var/lib/foreman-proxy/ssh/id_rsa_foreman_proxy type 1
debug1: key_load_public: No such file or directory
debug1: identity file /var/lib/foreman-proxy/ssh/id_rsa_foreman_proxy-cert type -1
debug1: Enabling compatibility mode for protocol 2.0
debug1: Local version string SSH-2.0-OpenSSH_7.4
ssh_exchange_identification: Connection closed by remote host
:
/opt/theforeman/tfm/root/usr/share/gems/gems/smart_proxy_remote_execution_ssh-0.5.1/lib/smart_proxy_remote_execution_ssh/runners/script_runner.rb:385:in `ensure_remote_directory'
/opt/theforeman/tfm/root/usr/share/gems/gems/smart_proxy_remote_execution_ssh-0.5.1/lib/smart_proxy_remote_execution_ssh/runners/script_runner.rb:359:in `upload_data'
/opt/theforeman/tfm/root/usr/share/gems/gems/smart_proxy_remote_execution_ssh-0.5.1/lib/smart_proxy_remote_execution_ssh/runners/script_runner.rb:355:in `cp_script_to_remote'
/opt/theforeman/tfm/root/usr/share/gems/gems/smart_proxy_remote_execution_ssh-0.5.1/lib/smart_proxy_remote_execution_ssh/runners/script_runner.rb:158:in `prepare_start'
/opt/theforeman/tfm/root/usr/share/gems/gems/smart_proxy_remote_execution_ssh-0.5.1/lib/smart_proxy_remote_execution_ssh/runners/script_runner.rb:144:in `start'
/opt/theforeman/tfm/root/usr/share/gems/gems/smart_proxy_dynflow-0.6.1/lib/smart_proxy_dynflow/runner/dispatcher.rb:32:in `start_runner'
/opt/theforeman/tfm/root/usr/share/gems/gems/dynflow-1.6.3/lib/dynflow/actor.rb:13:in `on_message'
/opt/theforeman/tfm/root/usr/share/gems/gems/concurrent-ruby-edge-0.6.0/lib/concurrent-ruby-edge/concurrent/actor/context.rb:46:in `on_envelope'
/opt/theforeman/tfm/root/usr/share/gems/gems/smart_proxy_dynflow-0.6.1/lib/smart_proxy_dynflow/runner/dispatcher.rb:24:in `on_envelope'
/opt/theforeman/tfm/root/usr/share/gems/gems/concurrent-ruby-edge-0.6.0/lib/concurrent-ruby-edge/concurrent/actor/behaviour/executes_context.rb:7:in `on_envelope'
/opt/theforeman/tfm/root/usr/share/gems/gems/concurrent-ruby-edge-0.6.0/lib/concurrent-ruby-edge/concurrent/actor/behaviour/abstract.rb:25:in `pass'
/opt/theforeman/tfm/root/usr/share/gems/gems/dynflow-1.6.3/lib/dynflow/actor.rb:122:in `on_envelope'
/opt/theforeman/tfm/root/usr/share/gems/gems/concurrent-ruby-edge-0.6.0/lib/concurrent-ruby-edge/concurrent/actor/behaviour/abstract.rb:25:in `pass'
/opt/theforeman/tfm/root/usr/share/gems/gems/concurrent-ruby-edge-0.6.0/lib/concurrent-ruby-edge/concurrent/actor/behaviour/awaits.rb:15:in `on_envelope'
/opt/theforeman/tfm/root/usr/share/gems/gems/concurrent-ruby-edge-0.6.0/lib/concurrent-ruby-edge/concurrent/actor/behaviour/abstract.rb:25:in `pass'
/opt/theforeman/tfm/root/usr/share/gems/gems/concurrent-ruby-edge-0.6.0/lib/concurrent-ruby-edge/concurrent/actor/behaviour/sets_results.rb:14:in `on_envelope'
/opt/theforeman/tfm/root/usr/share/gems/gems/dynflow-1.6.3/lib/dynflow/actor.rb:56:in `on_envelope'
/opt/theforeman/tfm/root/usr/share/gems/gems/concurrent-ruby-edge-0.6.0/lib/concurrent-ruby-edge/concurrent/actor/behaviour/abstract.rb:25:in `pass'
/opt/theforeman/tfm/root/usr/share/gems/gems/concurrent-ruby-edge-0.6.0/lib/concurrent-ruby-edge/concurrent/actor/behaviour/buffer.rb:38:in `process_envelope'
/opt/theforeman/tfm/root/usr/share/gems/gems/concurrent-ruby-edge-0.6.0/lib/concurrent-ruby-edge/concurrent/actor/behaviour/buffer.rb:31:in `process_envelopes?'
/opt/theforeman/tfm/root/usr/share/gems/gems/concurrent-ruby-edge-0.6.0/lib/concurrent-ruby-edge/concurrent/actor/behaviour/buffer.rb:20:in `on_envelope'
/opt/theforeman/tfm/root/usr/share/gems/gems/concurrent-ruby-edge-0.6.0/lib/concurrent-ruby-edge/concurrent/actor/behaviour/abstract.rb:25:in `pass'
/opt/theforeman/tfm/root/usr/share/gems/gems/concurrent-ruby-edge-0.6.0/lib/concurrent-ruby-edge/concurrent/actor/behaviour/termination.rb:55:in `on_envelope'
/opt/theforeman/tfm/root/usr/share/gems/gems/concurrent-ruby-edge-0.6.0/lib/concurrent-ruby-edge/concurrent/actor/behaviour/abstract.rb:25:in `pass'
/opt/theforeman/tfm/root/usr/share/gems/gems/concurrent-ruby-edge-0.6.0/lib/concurrent-ruby-edge/concurrent/actor/behaviour/removes_child.rb:10:in `on_envelope'
/opt/theforeman/tfm/root/usr/share/gems/gems/concurrent-ruby-edge-0.6.0/lib/concurrent-ruby-edge/concurrent/actor/behaviour/abstract.rb:25:in `pass'
/opt/theforeman/tfm/root/usr/share/gems/gems/concurrent-ruby-edge-0.6.0/lib/concurrent-ruby-edge/concurrent/actor/behaviour/sets_results.rb:14:in `on_envelope'
/opt/theforeman/tfm/root/usr/share/gems/gems/concurrent-ruby-edge-0.6.0/lib/concurrent-ruby-edge/concurrent/actor/core.rb:162:in `process_envelope'
/opt/theforeman/tfm/root/usr/share/gems/gems/concurrent-ruby-edge-0.6.0/lib/concurrent-ruby-edge/concurrent/actor/core.rb:96:in `block in on_envelope'
/opt/theforeman/tfm/root/usr/share/gems/gems/concurrent-ruby-edge-0.6.0/lib/concurrent-ruby-edge/concurrent/actor/core.rb:119:in `block (2 levels) in schedule_execution'
/opt/theforeman/tfm/root/usr/share/gems/gems/concurrent-ruby-1.1.6/lib/concurrent-ruby/concurrent/synchronization/mutex_lockable_object.rb:41:in `block in synchronize'
/opt/theforeman/tfm/root/usr/share/gems/gems/concurrent-ruby-1.1.6/lib/concurrent-ruby/concurrent/synchronization/mutex_lockable_object.rb:41:in `synchronize'
/opt/theforeman/tfm/root/usr/share/gems/gems/concurrent-ruby-1.1.6/lib/concurrent-ruby/concurrent/synchronization/mutex_lockable_object.rb:41:in `synchronize'
/opt/theforeman/tfm/root/usr/share/gems/gems/concurrent-ruby-edge-0.6.0/lib/concurrent-ruby-edge/concurrent/actor/core.rb:116:in `block in schedule_execution'
/opt/theforeman/tfm/root/usr/share/gems/gems/concurrent-ruby-1.1.6/lib/concurrent-ruby/concurrent/executor/serialized_execution.rb:18:in `call'
/opt/theforeman/tfm/root/usr/share/gems/gems/concurrent-ruby-1.1.6/lib/concurrent-ruby/concurrent/executor/serialized_execution.rb:96:in `work'
/opt/theforeman/tfm/root/usr/share/gems/gems/concurrent-ruby-1.1.6/lib/concurrent-ruby/concurrent/executor/serialized_execution.rb:77:in `block in call_job'
/opt/theforeman/tfm/root/usr/share/gems/gems/concurrent-ruby-1.1.6/lib/concurrent-ruby/concurrent/executor/ruby_thread_pool_executor.rb:353:in `run_task'
/opt/theforeman/tfm/root/usr/share/gems/gems/concurrent-ruby-1.1.6/lib/concurrent-ruby/concurrent/executor/ruby_thread_pool_executor.rb:342:in `block (3 levels) in create_worker'
/opt/theforeman/tfm/root/usr/share/gems/gems/concurrent-ruby-1.1.6/lib/concurrent-ruby/concurrent/executor/ruby_thread_pool_executor.rb:325:in `loop'
/opt/theforeman/tfm/root/usr/share/gems/gems/concurrent-ruby-1.1.6/lib/concurrent-ruby/concurrent/executor/ruby_thread_pool_executor.rb:325:in `block (2 levels) in create_worker'
/opt/theforeman/tfm/root/usr/share/gems/gems/concurrent-ruby-1.1.6/lib/concurrent-ruby/concurrent/executor/ruby_thread_pool_executor.rb:324:in `catch'
/opt/theforeman/tfm/root/usr/share/gems/gems/concurrent-ruby-1.1.6/lib/concurrent-ruby/concurrent/executor/ruby_thread_pool_executor.rb:324:in `block in create_worker'
/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'
2022-02-02T18:39:43 [D] refresh runner e1efc663-6da4-47bb-a89c-e7ba2d4e24d5
2022-02-02T18:39:43 [D] refreshing runner
2022-02-02T18:39:43 [D] finish runner e1efc663-6da4-47bb-a89c-e7ba2d4e24d5
2022-02-02T18:39:43 [D] closing session for command [e1efc663-6da4-47bb-a89c-e7ba2d4e24d5],0 actors left
2022-02-02T18:39:43 [D] terminate e1efc663-6da4-47bb-a89c-e7ba2d4e24d5
2022-02-02T18:39:43 [D] Step ea790db9-2010-4c30-aa30-740f86f47e73: 3 got event #<Proxy::Dynflow::Runner::Update:0x0000000002d86718>
2022-02-02T18:39:43 [D] Step ea790db9-2010-4c30-aa30-740f86f47e73: 3 suspended >> running in phase Run Proxy::RemoteExecution::Ssh::Actions::ScriptRunner
2022-02-02T18:39:43 3d672662 [D] Step ea790db9-2010-4c30-aa30-740f86f47e73: 3 running >> success in phase Run Proxy::RemoteExecution::Ssh::Actions::ScriptRunner
2022-02-02T18:39:43 [D] Step ea790db9-2010-4c30-aa30-740f86f47e73: 6 pending >> running in phase Run Proxy::Dynflow::Callback::Action
2022-02-02T18:39:43 [D] debug1: Reading configuration data /etc/ssh/ssh_config
2022-02-02T18:39:43 [D] debug1: /etc/ssh/ssh_config line 62: Applying options for *
2022-02-02T18:39:43 [D] debug1: auto-mux: Trying existing master
2022-02-02T18:39:43 [D] debug1: Control socket "/var/tmp/foreman-proxy/foreman-ssh-cmd-e1efc663-6da4-47bb-a89c-e7ba2d4e24d5/socket" does not exist
2022-02-02T18:39:43 [D] debug1: Executing proxy command: exec /usr/bin/sss_ssh_knownhostsproxy -p 22 c7build.example.com
2022-02-02T18:39:43 [D] debug1: permanently_drop_suid: 493
2022-02-02T18:39:43 [D] debug1: identity file /var/lib/foreman-proxy/ssh/id_rsa_foreman_proxy type 1
2022-02-02T18:39:43 [D] debug1: key_load_public: No such file or directory
2022-02-02T18:39:43 [D] debug1: identity file /var/lib/foreman-proxy/ssh/id_rsa_foreman_proxy-cert type -1
2022-02-02T18:39:43 [D] debug1: Enabling compatibility mode for protocol 2.0
2022-02-02T18:39:43 [D] debug1: Local version string SSH-2.0-OpenSSH_7.4
2022-02-02T18:39:43 [D] ssh_exchange_identification: Connection closed by remote host
2022-02-02T18:39:43 [E] error while dispatching request to runner e1efc663-6da4-47bb-a89c-e7ba2d4e24d5:RuntimeError Control socket file does not exist:
/opt/theforeman/tfm/root/usr/share/gems/gems/smart_proxy_remote_execution_ssh-0.5.1/lib/smart_proxy_remote_execution_ssh/runners/script_runner.rb:201:in `close_session'
/opt/theforeman/tfm/root/usr/share/gems/gems/smart_proxy_remote_execution_ssh-0.5.1/lib/smart_proxy_remote_execution_ssh/runners/script_runner.rb:213:in `close'
/opt/theforeman/tfm/root/usr/share/gems/gems/smart_proxy_dynflow-0.6.1/lib/smart_proxy_dynflow/runner/dispatcher.rb:78:in `start_termination'
/opt/theforeman/tfm/root/usr/share/gems/gems/dynflow-1.6.3/lib/dynflow/actor.rb:13:in `on_message'
/opt/theforeman/tfm/root/usr/share/gems/gems/concurrent-ruby-edge-0.6.0/lib/concurrent-ruby-edge/concurrent/actor/context.rb:46:in `on_envelope'
/opt/theforeman/tfm/root/usr/share/gems/gems/smart_proxy_dynflow-0.6.1/lib/smart_proxy_dynflow/runner/dispatcher.rb:24:in `on_envelope'
/opt/theforeman/tfm/root/usr/share/gems/gems/concurrent-ruby-edge-0.6.0/lib/concurrent-ruby-edge/concurrent/actor/behaviour/executes_context.rb:7:in `on_envelope'
/opt/theforeman/tfm/root/usr/share/gems/gems/concurrent-ruby-edge-0.6.0/lib/concurrent-ruby-edge/concurrent/actor/behaviour/abstract.rb:25:in `pass'
/opt/theforeman/tfm/root/usr/share/gems/gems/dynflow-1.6.3/lib/dynflow/actor.rb:122:in `on_envelope'
/opt/theforeman/tfm/root/usr/share/gems/gems/concurrent-ruby-edge-0.6.0/lib/concurrent-ruby-edge/concurrent/actor/behaviour/abstract.rb:25:in `pass'
/opt/theforeman/tfm/root/usr/share/gems/gems/concurrent-ruby-edge-0.6.0/lib/concurrent-ruby-edge/concurrent/actor/behaviour/awaits.rb:15:in `on_envelope'
/opt/theforeman/tfm/root/usr/share/gems/gems/concurrent-ruby-edge-0.6.0/lib/concurrent-ruby-edge/concurrent/actor/behaviour/abstract.rb:25:in `pass'
/opt/theforeman/tfm/root/usr/share/gems/gems/concurrent-ruby-edge-0.6.0/lib/concurrent-ruby-edge/concurrent/actor/behaviour/sets_results.rb:14:in `on_envelope'
/opt/theforeman/tfm/root/usr/share/gems/gems/dynflow-1.6.3/lib/dynflow/actor.rb:56:in `on_envelope'
/opt/theforeman/tfm/root/usr/share/gems/gems/concurrent-ruby-edge-0.6.0/lib/concurrent-ruby-edge/concurrent/actor/behaviour/abstract.rb:25:in `pass'
/opt/theforeman/tfm/root/usr/share/gems/gems/concurrent-ruby-edge-0.6.0/lib/concurrent-ruby-edge/concurrent/actor/behaviour/buffer.rb:38:in `process_envelope'
/opt/theforeman/tfm/root/usr/share/gems/gems/concurrent-ruby-edge-0.6.0/lib/concurrent-ruby-edge/concurrent/actor/behaviour/buffer.rb:31:in `process_envelopes?'
/opt/theforeman/tfm/root/usr/share/gems/gems/concurrent-ruby-edge-0.6.0/lib/concurrent-ruby-edge/concurrent/actor/behaviour/buffer.rb:20:in `on_envelope'
/opt/theforeman/tfm/root/usr/share/gems/gems/concurrent-ruby-edge-0.6.0/lib/concurrent-ruby-edge/concurrent/actor/behaviour/abstract.rb:25:in `pass'
/opt/theforeman/tfm/root/usr/share/gems/gems/concurrent-ruby-edge-0.6.0/lib/concurrent-ruby-edge/concurrent/actor/behaviour/termination.rb:55:in `on_envelope'
/opt/theforeman/tfm/root/usr/share/gems/gems/concurrent-ruby-edge-0.6.0/lib/concurrent-ruby-edge/concurrent/actor/behaviour/abstract.rb:25:in `pass'
/opt/theforeman/tfm/root/usr/share/gems/gems/concurrent-ruby-edge-0.6.0/lib/concurrent-ruby-edge/concurrent/actor/behaviour/removes_child.rb:10:in `on_envelope'
/opt/theforeman/tfm/root/usr/share/gems/gems/concurrent-ruby-edge-0.6.0/lib/concurrent-ruby-edge/concurrent/actor/behaviour/abstract.rb:25:in `pass'
/opt/theforeman/tfm/root/usr/share/gems/gems/concurrent-ruby-edge-0.6.0/lib/concurrent-ruby-edge/concurrent/actor/behaviour/sets_results.rb:14:in `on_envelope'
/opt/theforeman/tfm/root/usr/share/gems/gems/concurrent-ruby-edge-0.6.0/lib/concurrent-ruby-edge/concurrent/actor/core.rb:162:in `process_envelope'
/opt/theforeman/tfm/root/usr/share/gems/gems/concurrent-ruby-edge-0.6.0/lib/concurrent-ruby-edge/concurrent/actor/core.rb:96:in `block in on_envelope'
/opt/theforeman/tfm/root/usr/share/gems/gems/concurrent-ruby-edge-0.6.0/lib/concurrent-ruby-edge/concurrent/actor/core.rb:119:in `block (2 levels) in schedule_execution'
/opt/theforeman/tfm/root/usr/share/gems/gems/concurrent-ruby-1.1.6/lib/concurrent-ruby/concurrent/synchronization/mutex_lockable_object.rb:41:in `block in synchronize'
/opt/theforeman/tfm/root/usr/share/gems/gems/concurrent-ruby-1.1.6/lib/concurrent-ruby/concurrent/synchronization/mutex_lockable_object.rb:41:in `synchronize'
/opt/theforeman/tfm/root/usr/share/gems/gems/concurrent-ruby-1.1.6/lib/concurrent-ruby/concurrent/synchronization/mutex_lockable_object.rb:41:in `synchronize'
/opt/theforeman/tfm/root/usr/share/gems/gems/concurrent-ruby-edge-0.6.0/lib/concurrent-ruby-edge/concurrent/actor/core.rb:116:in `block in schedule_execution'
/opt/theforeman/tfm/root/usr/share/gems/gems/concurrent-ruby-1.1.6/lib/concurrent-ruby/concurrent/executor/serialized_execution.rb:18:in `call'
/opt/theforeman/tfm/root/usr/share/gems/gems/concurrent-ruby-1.1.6/lib/concurrent-ruby/concurrent/executor/serialized_execution.rb:96:in `work'
/opt/theforeman/tfm/root/usr/share/gems/gems/concurrent-ruby-1.1.6/lib/concurrent-ruby/concurrent/executor/serialized_execution.rb:77:in `block in call_job'
/opt/theforeman/tfm/root/usr/share/gems/gems/concurrent-ruby-1.1.6/lib/concurrent-ruby/concurrent/executor/ruby_thread_pool_executor.rb:353:in `run_task'
/opt/theforeman/tfm/root/usr/share/gems/gems/concurrent-ruby-1.1.6/lib/concurrent-ruby/concurrent/executor/ruby_thread_pool_executor.rb:342:in `block (3 levels) in create_worker'
/opt/theforeman/tfm/root/usr/share/gems/gems/concurrent-ruby-1.1.6/lib/concurrent-ruby/concurrent/executor/ruby_thread_pool_executor.rb:325:in `loop'
/opt/theforeman/tfm/root/usr/share/gems/gems/concurrent-ruby-1.1.6/lib/concurrent-ruby/concurrent/executor/ruby_thread_pool_executor.rb:325:in `block (2 levels) in create_worker'
/opt/theforeman/tfm/root/usr/share/gems/gems/concurrent-ruby-1.1.6/lib/concurrent-ruby/concurrent/executor/ruby_thread_pool_executor.rb:324:in `catch'
/opt/theforeman/tfm/root/usr/share/gems/gems/concurrent-ruby-1.1.6/lib/concurrent-ruby/concurrent/executor/ruby_thread_pool_executor.rb:324:in `block in create_worker'
/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'
2022-02-02T18:39:43 3d672662 [D] Step ea790db9-2010-4c30-aa30-740f86f47e73: 6 running >> success in phase Run Proxy::Dynflow::Callback::Action
2022-02-02T18:39:43 [D] Step ea790db9-2010-4c30-aa30-740f86f47e73: 4 pending >> running in phase Finalize Proxy::RemoteExecution::Ssh::Actions::ScriptRunner
2022-02-02T18:39:43 3d672662 [E] Script execution failed
2022-02-02T18:39:43 3d672662 [D] Step ea790db9-2010-4c30-aa30-740f86f47e73: 4 running >> error in phase Finalize Proxy::RemoteExecution::Ssh::Actions::ScriptRunner
2022-02-02T18:39:43 [D] ExecutionPlan ea790db9-2010-4c30-aa30-740f86f47e73 running >> stopped
2022-02-02T18:39:49 [D] Executor heartbeat
2022-02-02T18:39:53 [D] Step 8e60213b-b4d7-4f62-be9f-46ba374c54a9: 2 got event Dynflow::Action::WithPollingSubPlans::Poll
2022-02-02T18:39:53 [D] Step 8e60213b-b4d7-4f62-be9f-46ba374c54a9: 2 suspended >> running in phase Run Proxy::Dynflow::Action::Batch
2022-02-02T18:39:53 3d672662 [E] <RuntimeError> A sub task failed
/opt/theforeman/tfm/root/usr/share/gems/gems/dynflow-1.6.3/lib/dynflow/action/with_sub_plans.rb:231:in `check_for_errors!'
/opt/theforeman/tfm/root/usr/share/gems/gems/dynflow-1.6.3/lib/dynflow/action/with_sub_plans.rb:137:in `try_to_finish'
/opt/theforeman/tfm/root/usr/share/gems/gems/dynflow-1.6.3/lib/dynflow/action/with_polling_sub_plans.rb:19:in `poll'
/opt/theforeman/tfm/root/usr/share/gems/gems/dynflow-1.6.3/lib/dynflow/action/with_polling_sub_plans.rb:11:in `run'
/opt/theforeman/tfm/root/usr/share/gems/gems/dynflow-1.6.3/lib/dynflow/action.rb:582:in `block (3 levels) in execute_run'
/opt/theforeman/tfm/root/usr/share/gems/gems/dynflow-1.6.3/lib/dynflow/middleware/stack.rb:27:in `pass'
/opt/theforeman/tfm/root/usr/share/gems/gems/dynflow-1.6.3/lib/dynflow/middleware.rb:19:in `pass'
/opt/theforeman/tfm/root/usr/share/gems/gems/dynflow-1.6.3/lib/dynflow/action/progress.rb:31:in `with_progress_calculation'
/opt/theforeman/tfm/root/usr/share/gems/gems/dynflow-1.6.3/lib/dynflow/action/progress.rb:17:in `run'
/opt/theforeman/tfm/root/usr/share/gems/gems/dynflow-1.6.3/lib/dynflow/middleware/stack.rb:23:in `call'
/opt/theforeman/tfm/root/usr/share/gems/gems/dynflow-1.6.3/lib/dynflow/middleware/stack.rb:27:in `pass'
/opt/theforeman/tfm/root/usr/share/gems/gems/dynflow-1.6.3/lib/dynflow/middleware.rb:19:in `pass'
/opt/theforeman/tfm/root/usr/share/gems/gems/smart_proxy_dynflow-0.6.1/lib/smart_proxy_dynflow/middleware/keep_current_request_id.rb:15:in `block in run'
/opt/theforeman/tfm/root/usr/share/gems/gems/smart_proxy_dynflow-0.6.1/lib/smart_proxy_dynflow/middleware/keep_current_request_id.rb:49:in `restore_current_request_id'
/opt/theforeman/tfm/root/usr/share/gems/gems/smart_proxy_dynflow-0.6.1/lib/smart_proxy_dynflow/middleware/keep_current_request_id.rb:15:in `run'
/opt/theforeman/tfm/root/usr/share/gems/gems/dynflow-1.6.3/lib/dynflow/middleware/stack.rb:23:in `call'
/opt/theforeman/tfm/root/usr/share/gems/gems/dynflow-1.6.3/lib/dynflow/middleware/stack.rb:27:in `pass'
/opt/theforeman/tfm/root/usr/share/gems/gems/dynflow-1.6.3/lib/dynflow/middleware.rb:19:in `pass'
/opt/theforeman/tfm/root/usr/share/gems/gems/dynflow-1.6.3/lib/dynflow/middleware.rb:32:in `run'
/opt/theforeman/tfm/root/usr/share/gems/gems/dynflow-1.6.3/lib/dynflow/middleware/stack.rb:23:in `call'
/opt/theforeman/tfm/root/usr/share/gems/gems/dynflow-1.6.3/lib/dynflow/middleware/world.rb:31:in `execute'
/opt/theforeman/tfm/root/usr/share/gems/gems/dynflow-1.6.3/lib/dynflow/action.rb:581:in `block (2 levels) in execute_run'
/opt/theforeman/tfm/root/usr/share/gems/gems/dynflow-1.6.3/lib/dynflow/action.rb:580:in `catch'
/opt/theforeman/tfm/root/usr/share/gems/gems/dynflow-1.6.3/lib/dynflow/action.rb:580:in `block in execute_run'
/opt/theforeman/tfm/root/usr/share/gems/gems/dynflow-1.6.3/lib/dynflow/action.rb:483:in `block in with_error_handling'
/opt/theforeman/tfm/root/usr/share/gems/gems/dynflow-1.6.3/lib/dynflow/action.rb:483:in `catch'
/opt/theforeman/tfm/root/usr/share/gems/gems/dynflow-1.6.3/lib/dynflow/action.rb:483:in `with_error_handling'
/opt/theforeman/tfm/root/usr/share/gems/gems/dynflow-1.6.3/lib/dynflow/action.rb:575:in `execute_run'
/opt/theforeman/tfm/root/usr/share/gems/gems/dynflow-1.6.3/lib/dynflow/action.rb:296:in `execute'
/opt/theforeman/tfm/root/usr/share/gems/gems/dynflow-1.6.3/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.6.3/lib/dynflow/execution_plan/steps/abstract.rb:167:in `with_meta_calculation'
/opt/theforeman/tfm/root/usr/share/gems/gems/dynflow-1.6.3/lib/dynflow/execution_plan/steps/abstract_flow_step.rb:17:in `block in execute'
/opt/theforeman/tfm/root/usr/share/gems/gems/dynflow-1.6.3/lib/dynflow/execution_plan/steps/abstract_flow_step.rb:32:in `open_action'
/opt/theforeman/tfm/root/usr/share/gems/gems/dynflow-1.6.3/lib/dynflow/execution_plan/steps/abstract_flow_step.rb:16:in `execute'
/opt/theforeman/tfm/root/usr/share/gems/gems/dynflow-1.6.3/lib/dynflow/director.rb:94:in `execute'
/opt/theforeman/tfm/root/usr/share/gems/gems/dynflow-1.6.3/lib/dynflow/executors/parallel/worker.rb:15:in `block in on_message'
/opt/theforeman/tfm/root/usr/share/gems/gems/dynflow-1.6.3/lib/dynflow/executors.rb:18:in `run_user_code'
/opt/theforeman/tfm/root/usr/share/gems/gems/dynflow-1.6.3/lib/dynflow/executors/parallel/worker.rb:14:in `on_message'
/opt/theforeman/tfm/root/usr/share/gems/gems/concurrent-ruby-edge-0.6.0/lib/concurrent-ruby-edge/concurrent/actor/context.rb:46:in `on_envelope'
/opt/theforeman/tfm/root/usr/share/gems/gems/concurrent-ruby-edge-0.6.0/lib/concurrent-ruby-edge/concurrent/actor/behaviour/executes_context.rb:7:in `on_envelope'
/opt/theforeman/tfm/root/usr/share/gems/gems/concurrent-ruby-edge-0.6.0/lib/concurrent-ruby-edge/concurrent/actor/behaviour/abstract.rb:25:in `pass'
/opt/theforeman/tfm/root/usr/share/gems/gems/dynflow-1.6.3/lib/dynflow/actor.rb:122:in `on_envelope'
/opt/theforeman/tfm/root/usr/share/gems/gems/concurrent-ruby-edge-0.6.0/lib/concurrent-ruby-edge/concurrent/actor/behaviour/abstract.rb:25:in `pass'
/opt/theforeman/tfm/root/usr/share/gems/gems/concurrent-ruby-edge-0.6.0/lib/concurrent-ruby-edge/concurrent/actor/behaviour/awaits.rb:15:in `on_envelope'
/opt/theforeman/tfm/root/usr/share/gems/gems/concurrent-ruby-edge-0.6.0/lib/concurrent-ruby-edge/concurrent/actor/behaviour/abstract.rb:25:in `pass'
/opt/theforeman/tfm/root/usr/share/gems/gems/concurrent-ruby-edge-0.6.0/lib/concurrent-ruby-edge/concurrent/actor/behaviour/sets_results.rb:14:in `on_envelope'
/opt/theforeman/tfm/root/usr/share/gems/gems/dynflow-1.6.3/lib/dynflow/actor.rb:56:in `on_envelope'
/opt/theforeman/tfm/root/usr/share/gems/gems/concurrent-ruby-edge-0.6.0/lib/concurrent-ruby-edge/concurrent/actor/behaviour/abstract.rb:25:in `pass'
/opt/theforeman/tfm/root/usr/share/gems/gems/concurrent-ruby-edge-0.6.0/lib/concurrent-ruby-edge/concurrent/actor/behaviour/buffer.rb:38:in `process_envelope'
/opt/theforeman/tfm/root/usr/share/gems/gems/concurrent-ruby-edge-0.6.0/lib/concurrent-ruby-edge/concurrent/actor/behaviour/buffer.rb:31:in `process_envelopes?'
/opt/theforeman/tfm/root/usr/share/gems/gems/concurrent-ruby-edge-0.6.0/lib/concurrent-ruby-edge/concurrent/actor/behaviour/buffer.rb:20:in `on_envelope'
/opt/theforeman/tfm/root/usr/share/gems/gems/concurrent-ruby-edge-0.6.0/lib/concurrent-ruby-edge/concurrent/actor/behaviour/abstract.rb:25:in `pass'
/opt/theforeman/tfm/root/usr/share/gems/gems/concurrent-ruby-edge-0.6.0/lib/concurrent-ruby-edge/concurrent/actor/behaviour/termination.rb:55:in `on_envelope'
/opt/theforeman/tfm/root/usr/share/gems/gems/concurrent-ruby-edge-0.6.0/lib/concurrent-ruby-edge/concurrent/actor/behaviour/abstract.rb:25:in `pass'
/opt/theforeman/tfm/root/usr/share/gems/gems/concurrent-ruby-edge-0.6.0/lib/concurrent-ruby-edge/concurrent/actor/behaviour/removes_child.rb:10:in `on_envelope'
/opt/theforeman/tfm/root/usr/share/gems/gems/concurrent-ruby-edge-0.6.0/lib/concurrent-ruby-edge/concurrent/actor/behaviour/abstract.rb:25:in `pass'
/opt/theforeman/tfm/root/usr/share/gems/gems/concurrent-ruby-edge-0.6.0/lib/concurrent-ruby-edge/concurrent/actor/behaviour/sets_results.rb:14:in `on_envelope'
/opt/theforeman/tfm/root/usr/share/gems/gems/concurrent-ruby-edge-0.6.0/lib/concurrent-ruby-edge/concurrent/actor/core.rb:162:in `process_envelope'
/opt/theforeman/tfm/root/usr/share/gems/gems/concurrent-ruby-edge-0.6.0/lib/concurrent-ruby-edge/concurrent/actor/core.rb:96:in `block in on_envelope'
/opt/theforeman/tfm/root/usr/share/gems/gems/concurrent-ruby-edge-0.6.0/lib/concurrent-ruby-edge/concurrent/actor/core.rb:119:in `block (2 levels) in schedule_execution'
/opt/theforeman/tfm/root/usr/share/gems/gems/concurrent-ruby-1.1.6/lib/concurrent-ruby/concurrent/synchronization/mutex_lockable_object.rb:41:in `block in synchronize'
/opt/theforeman/tfm/root/usr/share/gems/gems/concurrent-ruby-1.1.6/lib/concurrent-ruby/concurrent/synchronization/mutex_lockable_object.rb:41:in `synchronize'
/opt/theforeman/tfm/root/usr/share/gems/gems/concurrent-ruby-1.1.6/lib/concurrent-ruby/concurrent/synchronization/mutex_lockable_object.rb:41:in `synchronize'
/opt/theforeman/tfm/root/usr/share/gems/gems/concurrent-ruby-edge-0.6.0/lib/concurrent-ruby-edge/concurrent/actor/core.rb:116:in `block in schedule_execution'
/opt/theforeman/tfm/root/usr/share/gems/gems/concurrent-ruby-1.1.6/lib/concurrent-ruby/concurrent/executor/serialized_execution.rb:18:in `call'
/opt/theforeman/tfm/root/usr/share/gems/gems/concurrent-ruby-1.1.6/lib/concurrent-ruby/concurrent/executor/serialized_execution.rb:96:in `work'
/opt/theforeman/tfm/root/usr/share/gems/gems/concurrent-ruby-1.1.6/lib/concurrent-ruby/concurrent/executor/serialized_execution.rb:77:in `block in call_job'
/opt/theforeman/tfm/root/usr/share/gems/gems/concurrent-ruby-1.1.6/lib/concurrent-ruby/concurrent/executor/ruby_thread_pool_executor.rb:353:in `run_task'
/opt/theforeman/tfm/root/usr/share/gems/gems/concurrent-ruby-1.1.6/lib/concurrent-ruby/concurrent/executor/ruby_thread_pool_executor.rb:342:in `block (3 levels) in create_worker'
/opt/theforeman/tfm/root/usr/share/gems/gems/concurrent-ruby-1.1.6/lib/concurrent-ruby/concurrent/executor/ruby_thread_pool_executor.rb:325:in `loop'
/opt/theforeman/tfm/root/usr/share/gems/gems/concurrent-ruby-1.1.6/lib/concurrent-ruby/concurrent/executor/ruby_thread_pool_executor.rb:325:in `block (2 levels) in create_worker'
/opt/theforeman/tfm/root/usr/share/gems/gems/concurrent-ruby-1.1.6/lib/concurrent-ruby/concurrent/executor/ruby_thread_pool_executor.rb:324:in `catch'
/opt/theforeman/tfm/root/usr/share/gems/gems/concurrent-ruby-1.1.6/lib/concurrent-ruby/concurrent/executor/ruby_thread_pool_executor.rb:324:in `block in create_worker'
/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'
2022-02-02T18:39:53 3d672662 [D] Step 8e60213b-b4d7-4f62-be9f-46ba374c54a9: 2 running >> error in phase Run Proxy::Dynflow::Action::Batch
2022-02-02T18:39:53 [D] ExecutionPlan 8e60213b-b4d7-4f62-be9f-46ba374c54a9 running >> stopped
2022-02-02T18:40:04 [D] Executor heartbeat
2022-02-02T18:40:19 [D] Executor heartbeat
2022-02-02T18:40:34 [D] Executor heartbeat
2022-02-02T18:40:49 [D] Executor heartbeat
2022-02-02T18:41:04 [D] Executor heartbeat
2022-02-02T18:41:19 [D] Executor heartbeat
2022-02-02T18:41:34 [D] Executor heartbeat
2022-02-02T18:41:49 [D] Executor heartbeat
Until you can get sudo -u foreman-proxy ssh root@c7build.example.com -i /usr/share/foreman-proxy/.ssh/id_rsa_foreman_proxy.pub -v working, there’s literally nothing we can do from our side to help you, because that’s almost exactly what we do. If ignoring ProxyCommand is fine for you, then just unset it for hosts in ~foreman-proxy/.ssh/config and you should be good to go.
O.K. But why is remote execution working with foreman 2.5.4 and foreman_remote_execution plugin 4.5.6 even though ssh is also not working unless I set ProxyCommand=none? Something must have change between plugin 4.5.6 and 5.0.1.
It is not about foreman_remote_execution itself, but more about smart_proxy_remote_execution_ssh. The version shipped with 2.5 was using an ancient version of net-ssh (pure ruby implementation of ssh), in 3.1 we threw that away and switched to using the ssh binary present on the system instead. I recall there were some issues with the previous implementation and config options like ProxyJump. It is quite possible that the previous implementation just ignored ProxyCommand on its own, while the new one honors it.
So basically, there are two solutions to this problem:
set ProxyCommand=none in /usr/share/foreman-proxy/.ssh/config for foreman-proxy
Put the ProxyCommand into a Match block in /etc/ssh/ssh_config
Match exec true
ProxyCommand /usr/bin/sss_ssh_knownhostsproxy -p %p %h
That means: if it can run /bin/true with an exit code 0 it uses the ProxyCommand. Otherwise not. So that’s a system-wide solution for all users which don’t have a shell set.
That’s a different problem. Please open a new thread and make sure you use blockquotes for proper formatting. Your logs are hard to read and possibly missing important parts if you don’t quote…