Unable to create directory on remote system /var/tmp/foreman-ssh-cmd REX

si_si87 · May 5, 2022, 6:22pm

Problem:
1:
Error initializing command: RuntimeError - Unable to create directory on remote system /var/tmp/foreman-ssh-cmd-59622865-f6b6-469d-b3a2-8468b1279902: exit code: 255
2:
ssh_exchange_identification: Connection closed by remote host
3:
Exit status: EXCEPTION
Trying to run remote job on host just to echo hello world.
Have just set up Foreman 3.2 with katello 4.4
Installing Foreman 3.2 server with Katello 4.4 plugin on Enterprise Linux followed this manual.
enabled at install foreman_proxy_plugin_remote_execution_ssh,foreman_plugin_remote_execution
Can do passwordless ssh -i ~foreman-proxy/.ssh/id_rsa_foreman_proxy root@...

Have tried scp -v -i ~foreman-proxy/.ssh/id_rsa_foreman_proxy file1 root@...:/var/tmp/file1
file1 appears into host /var/tmp
Expected outcome:
Job to run successfully.
Foreman version:
Foreman 3.2
Foreman and Proxy plugin versions:

Distribution and version:
CentOS Linux release 7.9.2009
Other relevant data:
DEBUG from command= scp -v -i ~foreman-proxy/.ssh/id_rsa_foreman_proxy file1 root@...:/var/tmp/file1

Executing: program /usr/bin/ssh host **.**.**.**, user root, command scp -v -t /var/tmp/file1
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 **.**.**.**
debug1: identity file /usr/share/foreman-proxy/.ssh/id_rsa_foreman_proxy type 1
debug1: permanently_drop_suid: 1753000023
debug1: key_load_public: No such file or directory
debug1: identity file /usr/share/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
debug1: Remote protocol version 2.0, remote software version OpenSSH_7.4
debug1: match: OpenSSH_7.4 pat OpenSSH* compat 0x04000000
debug1: Authenticating to 10.13.13.70:22 as 'root'
debug1: SSH2_MSG_KEXINIT sent
debug1: SSH2_MSG_KEXINIT received
debug1: kex: algorithm: curve25519-sha256
debug1: kex: host key algorithm: ecdsa-sha2-nistp256
debug1: kex: server->client cipher: chacha20-poly1305@openssh.com MAC: <implicit> compression: none
debug1: kex: client->server cipher: chacha20-poly1305@openssh.com MAC: <implicit> compression: none
debug1: kex: curve25519-sha256 need=64 dh_need=64
debug1: kex: curve25519-sha256 need=64 dh_need=64
debug1: expecting SSH2_MSG_KEX_ECDH_REPLY
debug1: Server host key: ecdsa-sha2-nistp256 SHA256:+0j2x7a0N7PfUaNI7WBlxiibMJj43jUYLMZrqGy2xoU
debug1: Host '**.**.**.**' is known and matches the ECDSA host key.
debug1: Found key in /var/lib/sss/pubconf/known_hosts:6
debug1: rekey after 134217728 blocks
debug1: SSH2_MSG_NEWKEYS sent
debug1: expecting SSH2_MSG_NEWKEYS
debug1: SSH2_MSG_NEWKEYS received
debug1: rekey after 134217728 blocks
debug1: SSH2_MSG_EXT_INFO received
debug1: kex_input_ext_info: server-sig-algs=<rsa-sha2-256,rsa-sha2-512>
debug1: SSH2_MSG_SERVICE_ACCEPT received
debug1: Authentications that can continue: publickey,gssapi-keyex,gssapi-with-mic,password,keyboard-interactive
debug1: Next authentication method: gssapi-keyex
debug1: No valid Key exchange context
debug1: Next authentication method: gssapi-with-mic
debug1: Unspecified GSS failure.  Minor code may provide more information
Server host/**.**.**.**@***.***.***** not found in Kerberos database

debug1: Authentications that can continue: publickey,gssapi-keyex,gssapi-with-mic,password,keyboard-interactive
debug1: Next authentication method: publickey
debug1: Offering RSA public key: /usr/share/foreman-proxy/.ssh/id_rsa_foreman_proxy
debug1: Server accepts key: pkalg rsa-sha2-512 blen 279
debug1: Authentication succeeded (publickey).
Authenticated to **.**.**.** (via proxy).
debug1: channel 0: new [client-session]
debug1: Requesting no-more-sessions@openssh.com
debug1: Entering interactive session.
debug1: pledge: proc
debug1: client_input_global_request: rtype hostkeys-00@openssh.com want_reply 0
debug1: Sending environment.
debug1: Sending env LANG = en_GB.UTF-8
debug1: Sending command: scp -v -t /var/tmp/file1
Sending file modes: C0664 0 file1
Sink: C0664 0 file1
file1                                                                                  100%    0     0.0KB/s   00:00
debug1: client_input_channel_req: channel 0 rtype exit-status reply 0
debug1: channel 0: free: client-session, nchannels 1
debug1: fd 0 clearing O_NONBLOCK
debug1: fd 1 clearing O_NONBLOCK
Transferred: sent 3024, received 2884 bytes, in 0.1 seconds
Bytes per second: sent 42775.9, received 40795.6
debug1: Exit status 0

/var/log/foreman-proxy/proxy.log

2022-05-05T19:13:49 8cb080dc [I] Started GET /dynflow/tasks/count state=running
2022-05-05T19:13:49 8cb080dc [I] Finished GET /dynflow/tasks/count with 200 (2.3 ms)
2022-05-05T19:13:50 8cb080dc [I] Started POST /dynflow/tasks/launch
2022-05-05T19:13:50 8cb080dc [I] Finished POST /dynflow/tasks/launch with 200 (31.14 ms)
2022-05-05T19:13:50  [E] error while initializing command RuntimeError Unable to create directory on remote system /var/tmp/foreman-ssh-cmd-7399852b-84ac-4aa5-afb3-20cb12ac14d7: exit code: 255
 ssh_exchange_identification: Connection closed by remote host
:
 /opt/theforeman/tfm/root/usr/share/gems/gems/smart_proxy_remote_execution_ssh-0.5.3/lib/smart_proxy_remote_execution_ssh/runners/script_runner.rb:387:in `ensure_remote_directory'
/opt/theforeman/tfm/root/usr/share/gems/gems/smart_proxy_remote_execution_ssh-0.5.3/lib/smart_proxy_remote_execution_ssh/runners/script_runner.rb:361:in `upload_data'
/opt/theforeman/tfm/root/usr/share/gems/gems/smart_proxy_remote_execution_ssh-0.5.3/lib/smart_proxy_remote_execution_ssh/runners/script_runner.rb:357:in `cp_script_to_remote'
/opt/theforeman/tfm/root/usr/share/gems/gems/smart_proxy_remote_execution_ssh-0.5.3/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.3/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.7.0/lib/smart_proxy_dynflow/runner/dispatcher.rb:32:in `start_runner'
/opt/theforeman/tfm/root/usr/share/gems/gems/dynflow-1.6.4/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.7.0/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.4/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.4/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-05-05T19:13:50  [E] Error initializing command - RuntimeError Unable to create directory on remote system /var/tmp/foreman-ssh-cmd-7399852b-84ac-4aa5-afb3-20cb12ac14d7: exit code: 255
 ssh_exchange_identification: Connection closed by remote host
:
/opt/theforeman/tfm/root/usr/share/gems/gems/smart_proxy_remote_execution_ssh-0.5.3/lib/smart_proxy_remote_execution_ssh/runners/script_runner.rb:387:in `ensure_remote_directory'
/opt/theforeman/tfm/root/usr/share/gems/gems/smart_proxy_remote_execution_ssh-0.5.3/lib/smart_proxy_remote_execution_ssh/runners/script_runner.rb:361:in `upload_data'
/opt/theforeman/tfm/root/usr/share/gems/gems/smart_proxy_remote_execution_ssh-0.5.3/lib/smart_proxy_remote_execution_ssh/runners/script_runner.rb:357:in `cp_script_to_remote'
/opt/theforeman/tfm/root/usr/share/gems/gems/smart_proxy_remote_execution_ssh-0.5.3/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.3/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.7.0/lib/smart_proxy_dynflow/runner/dispatcher.rb:32:in `start_runner'
/opt/theforeman/tfm/root/usr/share/gems/gems/dynflow-1.6.4/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.7.0/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.4/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.4/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-05-05T19:13:50  [E] error while dispatching request to runner 7399852b-84ac-4aa5-afb3-20cb12ac14d7:RuntimeError Control socket file does not exist:
 /opt/theforeman/tfm/root/usr/share/gems/gems/smart_proxy_remote_execution_ssh-0.5.3/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.3/lib/smart_proxy_remote_execution_ssh/runners/script_runner.rb:215:in `close'
/opt/theforeman/tfm/root/usr/share/gems/gems/smart_proxy_dynflow-0.7.0/lib/smart_proxy_dynflow/runner/dispatcher.rb:78:in `start_termination'
/opt/theforeman/tfm/root/usr/share/gems/gems/dynflow-1.6.4/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.7.0/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.4/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.4/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-05-05T19:13:50 8cb080dc [E] Script execution failed
2022-05-05T19:14:00 8cb080dc [E] <RuntimeError> A sub task failed
        /opt/theforeman/tfm/root/usr/share/gems/gems/dynflow-1.6.4/lib/dynflow/action/with_sub_plans.rb:231:in `check_for_errors!'
        /opt/theforeman/tfm/root/usr/share/gems/gems/dynflow-1.6.4/lib/dynflow/action/with_sub_plans.rb:137:in `try_to_finish'
        /opt/theforeman/tfm/root/usr/share/gems/gems/dynflow-1.6.4/lib/dynflow/action/with_polling_sub_plans.rb:19:in `poll'
        /opt/theforeman/tfm/root/usr/share/gems/gems/dynflow-1.6.4/lib/dynflow/action/with_polling_sub_plans.rb:11:in `run'
        /opt/theforeman/tfm/root/usr/share/gems/gems/dynflow-1.6.4/lib/dynflow/action.rb:582:in `block (3 levels) in execute_run'
        /opt/theforeman/tfm/root/usr/share/gems/gems/dynflow-1.6.4/lib/dynflow/middleware/stack.rb:27:in `pass'
        /opt/theforeman/tfm/root/usr/share/gems/gems/dynflow-1.6.4/lib/dynflow/middleware.rb:19:in `pass'
        /opt/theforeman/tfm/root/usr/share/gems/gems/dynflow-1.6.4/lib/dynflow/action/progress.rb:31:in `with_progress_calculation'
        /opt/theforeman/tfm/root/usr/share/gems/gems/dynflow-1.6.4/lib/dynflow/action/progress.rb:17:in `run'
        /opt/theforeman/tfm/root/usr/share/gems/gems/dynflow-1.6.4/lib/dynflow/middleware/stack.rb:23:in `call'
        /opt/theforeman/tfm/root/usr/share/gems/gems/dynflow-1.6.4/lib/dynflow/middleware/stack.rb:27:in `pass'
        /opt/theforeman/tfm/root/usr/share/gems/gems/dynflow-1.6.4/lib/dynflow/middleware.rb:19:in `pass'
        /opt/theforeman/tfm/root/usr/share/gems/gems/smart_proxy_dynflow-0.7.0/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.7.0/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.7.0/lib/smart_proxy_dynflow/middleware/keep_current_request_id.rb:15:in `run'
        /opt/theforeman/tfm/root/usr/share/gems/gems/dynflow-1.6.4/lib/dynflow/middleware/stack.rb:23:in `call'
        /opt/theforeman/tfm/root/usr/share/gems/gems/dynflow-1.6.4/lib/dynflow/middleware/stack.rb:27:in `pass'
        /opt/theforeman/tfm/root/usr/share/gems/gems/dynflow-1.6.4/lib/dynflow/middleware.rb:19:in `pass'
        /opt/theforeman/tfm/root/usr/share/gems/gems/dynflow-1.6.4/lib/dynflow/middleware.rb:32:in `run'
        /opt/theforeman/tfm/root/usr/share/gems/gems/dynflow-1.6.4/lib/dynflow/middleware/stack.rb:23:in `call'
        /opt/theforeman/tfm/root/usr/share/gems/gems/dynflow-1.6.4/lib/dynflow/middleware/world.rb:31:in `execute'
        /opt/theforeman/tfm/root/usr/share/gems/gems/dynflow-1.6.4/lib/dynflow/action.rb:581:in `block (2 levels) in execute_run'
        /opt/theforeman/tfm/root/usr/share/gems/gems/dynflow-1.6.4/lib/dynflow/action.rb:580:in `catch'
        /opt/theforeman/tfm/root/usr/share/gems/gems/dynflow-1.6.4/lib/dynflow/action.rb:580:in `block in execute_run'
        /opt/theforeman/tfm/root/usr/share/gems/gems/dynflow-1.6.4/lib/dynflow/action.rb:483:in `block in with_error_handling'
        /opt/theforeman/tfm/root/usr/share/gems/gems/dynflow-1.6.4/lib/dynflow/action.rb:483:in `catch'
        /opt/theforeman/tfm/root/usr/share/gems/gems/dynflow-1.6.4/lib/dynflow/action.rb:483:in `with_error_handling'
        /opt/theforeman/tfm/root/usr/share/gems/gems/dynflow-1.6.4/lib/dynflow/action.rb:575:in `execute_run'
        /opt/theforeman/tfm/root/usr/share/gems/gems/dynflow-1.6.4/lib/dynflow/action.rb:296:in `execute'
        /opt/theforeman/tfm/root/usr/share/gems/gems/dynflow-1.6.4/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.4/lib/dynflow/execution_plan/steps/abstract.rb:167:in `with_meta_calculation'
        /opt/theforeman/tfm/root/usr/share/gems/gems/dynflow-1.6.4/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.4/lib/dynflow/execution_plan/steps/abstract_flow_step.rb:32:in `open_action'
        /opt/theforeman/tfm/root/usr/share/gems/gems/dynflow-1.6.4/lib/dynflow/execution_plan/steps/abstract_flow_step.rb:16:in `execute'
        /opt/theforeman/tfm/root/usr/share/gems/gems/dynflow-1.6.4/lib/dynflow/director.rb:94:in `execute'
        /opt/theforeman/tfm/root/usr/share/gems/gems/dynflow-1.6.4/lib/dynflow/executors/parallel/worker.rb:15:in `block in on_message'
        /opt/theforeman/tfm/root/usr/share/gems/gems/dynflow-1.6.4/lib/dynflow/executors.rb:18:in `run_user_code'
        /opt/theforeman/tfm/root/usr/share/gems/gems/dynflow-1.6.4/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.4/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.4/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'

si_si87 · May 5, 2022, 6:23pm

/var/log/foreman/production.log

2022-05-05T19:13:45 [I|app|5641bc81] Started GET "/job_invocations/32/rerun" for **.**.**.** at 2022-05-05 19:13:45 +0100
2022-05-05T19:13:45 [I|app|5641bc81] Processing by JobInvocationsController#rerun as HTML
2022-05-05T19:13:45 [I|app|5641bc81]   Parameters: {"id"=>"32"}
2022-05-05T19:13:45 [I|app|5641bc81]   Rendering /opt/theforeman/tfm/root/usr/share/gems/gems/foreman_remote_execution-6.0.0/app/views/job_invocations/new.html.erb within layouts/application
2022-05-05T19:13:45 [I|app|5641bc81]   Rendered template_inputs/_invocation_form.html.erb (Duration: 3.9ms | Allocations: 656)
2022-05-05T19:13:45 [I|app|5641bc81]   Rendered /opt/theforeman/tfm/root/usr/share/gems/gems/foreman_remote_execution-6.0.0/app/views/job_invocations/_description_fields.html.erb (Duration: 3.8ms | Allocations: 1052)
2022-05-05T19:13:45 [I|app|5641bc81]   Rendered /opt/theforeman/tfm/root/usr/share/gems/gems/foreman-tasks-6.0.1/app/views/common/_trigger_form.html.erb (Duration: 24.8ms | Allocations: 11251)
2022-05-05T19:13:45 [I|app|5641bc81]   Rendered /opt/theforeman/tfm/root/usr/share/gems/gems/foreman_remote_execution-6.0.0/app/views/job_invocations/_preview_hosts_modal.html.erb (Duration: 1.5ms | Allocations: 368)
2022-05-05T19:13:45 [I|app|5641bc81]   Rendered /opt/theforeman/tfm/root/usr/share/gems/gems/foreman_remote_execution-6.0.0/app/views/job_invocations/_rerun_taxonomies.html.erb (Duration: 5.9ms | Allocations: 256)
2022-05-05T19:13:45 [I|app|5641bc81]   Rendered /opt/theforeman/tfm/root/usr/share/gems/gems/foreman_remote_execution-6.0.0/app/views/job_invocations/_form.html.erb (Duration: 105.2ms | Allocations: 37627)
2022-05-05T19:13:45 [I|app|5641bc81]   Rendered /opt/theforeman/tfm/root/usr/share/gems/gems/foreman_remote_execution-6.0.0/app/views/job_invocations/new.html.erb within layouts/application (Duration: 112.6ms | Allocations: 38680)
2022-05-05T19:13:45 [I|app|5641bc81]   Rendered layouts/_application_content.html.erb (Duration: 4.6ms | Allocations: 5626)
2022-05-05T19:13:45 [I|app|5641bc81]   Rendering layouts/base.html.erb
2022-05-05T19:13:45 [I|app|5641bc81]   Rendered layouts/base.html.erb (Duration: 29.8ms | Allocations: 22858)
2022-05-05T19:13:45 [I|app|5641bc81] Completed 200 OK in 292ms (Views: 153.3ms | ActiveRecord: 44.3ms | Allocations: 99900)
2022-05-05T19:13:47 [I|app|6c0d9e67] Started GET "/notification_recipients" for **.**.**.** at 2022-05-05 19:13:47 +0100
2022-05-05T19:13:47 [I|app|6c0d9e67] Processing by NotificationRecipientsController#index as JSON
2022-05-05T19:13:47 [I|app|6c0d9e67] Completed 200 OK in 8ms (Views: 0.1ms | ActiveRecord: 1.5ms | Allocations: 2163)
2022-05-05T19:13:49 [I|app|8cb080dc] Started POST "/job_invocations" for **.**.**.** at 2022-05-05 19:13:49 +0100
2022-05-05T19:13:49 [I|app|8cb080dc] Processing by JobInvocationsController#create as HTML
2022-05-05T19:13:49 [I|app|8cb080dc]   Parameters: {"utf8"=>"✓", "authenticity_token"=>"ZjSd2rg9i/ImaCfiAB0AZhSgXfGwPAwhakrPPL7n7UVzDg+kj2Qah26bmQk/d8bsujHBOL9PBRRzinN1HyJGIA==", "job_invocation"=>{"job_category"=>"Commands", "remote_execution_feature_id"=>"", "providers"=>{"SSH"=>{"job_template_id"=>"156", "job_templates"=>{"156"=>{"input_values"=>"[FILTERED]", "effective_user"=>"root", "execution_timeout_interval"=>""}}}}, "description"=>"", "description_override"=>"Run %{command}", "description_format"=>"Run %{command}", "password"=>"[FILTERED]", "key_passphrase"=>"", "effective_user_password"=>"[FILTERED]", "concurrency_level"=>"", "time_span"=>""}, "targeting"=>{"bookmark_id"=>"", "search_query"=>"name ^ (iomvlpptest01.ipa.sps.local)", "randomized_ordering"=>"false", "targeting_type"=>"static_query"}, "fakepassword"=>"[FILTERED]", "triggering"=>{"mode"=>"immediate", "start_at_raw"=>"2022-05-05 19:13", "start_before_raw"=>"", "input_type"=>"daily", "cronline"=>"", "days"=>"", "days_of_week"=>{"1"=>"0", "2"=>"0", "3"=>"0", "4"=>"0", "5"=>"0", "6"=>"0", "7"=>"0"}, "time"=>{"time(1i)"=>"2022", "time(2i)"=>"5", "time(3i)"=>"5", "time(4i)"=>"19", "time(5i)"=>"13"}, "max_iteration"=>"", "end_time_limited"=>"false", "end_time"=>{"end_time(3i)"=>"5", "end_time(2i)"=>"5", "end_time(1i)"=>"2022", "end_time(4i)"=>"19", "end_time(5i)"=>"13"}, "purpose"=>""}, "commit"=>"Submit"}
2022-05-05T19:13:49 [I|aud|8cb080dc] JobInvocation (33) create event on job_category Commands
2022-05-05T19:13:49 [I|aud|8cb080dc] JobInvocation (33) create event on description Run echo hello world
2022-05-05T19:13:49 [I|aud|8cb080dc] JobInvocation (33) create event on concurrency_level
2022-05-05T19:13:49 [I|aud|8cb080dc] JobInvocation (33) create event on time_span
2022-05-05T19:13:49 [I|aud|8cb080dc] JobInvocation (33) create event on execution_timeout_interval
2022-05-05T19:13:49 [I|aud|8cb080dc] JobInvocation (33) create event on password [redacted]
2022-05-05T19:13:49 [I|aud|8cb080dc] JobInvocation (33) create event on key_passphrase
2022-05-05T19:13:49 [I|aud|8cb080dc] JobInvocation (33) create event on remote_execution_feature_id
2022-05-05T19:13:49 [I|aud|8cb080dc] JobInvocation (33) create event on effective_user_password
2022-05-05T19:13:49 [I|bac|8cb080dc] Task {label: , execution_plan_id: 7bcbd0fc-02e5-429f-ba94-d0bc76cdbd17} state changed: pending
2022-05-05T19:13:49 [I|bac|8cb080dc] Task {label: Actions::RemoteExecution::RunHostsJob, id: f0f4941c-622a-4eab-a0c1-e84e5e5339c3, execution_plan_id: 7bcbd0fc-02e5-429f-ba94-d0bc76cdbd17} state changed: planning
2022-05-05T19:13:49 [I|bac|8cb080dc] Task {label: Actions::RemoteExecution::RunHostsJob, id: f0f4941c-622a-4eab-a0c1-e84e5e5339c3, execution_plan_id: 7bcbd0fc-02e5-429f-ba94-d0bc76cdbd17} state changed: planned
2022-05-05T19:13:49 [I|app|8cb080dc] Redirected to https://iomvlpposrepo.ipa.sps.local/job_invocations/33
2022-05-05T19:13:49 [I|app|8cb080dc] Completed 302 Found in 323ms (ActiveRecord: 56.1ms | Allocations: 60879)
2022-05-05T19:13:49 [I|bac|8cb080dc] Task {label: Actions::RemoteExecution::RunHostsJob, id: f0f4941c-622a-4eab-a0c1-e84e5e5339c3, execution_plan_id: 7bcbd0fc-02e5-429f-ba94-d0bc76cdbd17} state changed: running
2022-05-05T19:13:49 [I|app|9a10e73b] Started GET "/job_invocations/33" for **.**.**.** at 2022-05-05 19:13:49 +0100
2022-05-05T19:13:49 [I|app|9a10e73b] Processing by JobInvocationsController#show as HTML
2022-05-05T19:13:49 [I|app|9a10e73b]   Parameters: {"id"=>"33"}
2022-05-05T19:13:49 [I|bac|8cb080dc] Task {label: , execution_plan_id: 10b7a343-de70-48ad-b4fa-ed94ca98e860} state changed: pending
2022-05-05T19:13:49 [I|app|9a10e73b]   Rendering /opt/theforeman/tfm/root/usr/share/gems/gems/foreman_remote_execution-6.0.0/app/views/job_invocations/show.html.erb within layouts/application
2022-05-05T19:13:49 [I|bac|8cb080dc] Task {label: Actions::RemoteExecution::RunHostJob, id: 85161a20-e695-4586-b043-21b5f4122e95, execution_plan_id: 10b7a343-de70-48ad-b4fa-ed94ca98e860} state changed: planning
2022-05-05T19:13:49 [I|app|9a10e73b]   Rendered /opt/theforeman/tfm/root/usr/share/gems/gems/foreman_remote_execution-6.0.0/app/views/job_invocations/_card_results.html.erb (Duration: 1.9ms | Allocations: 358)
2022-05-05T19:13:49 [I|app|9a10e73b]   Rendered /opt/theforeman/tfm/root/usr/share/gems/gems/foreman_remote_execution-6.0.0/app/views/job_invocations/_card_schedule.html.erb (Duration: 3.3ms | Allocations: 1079)
2022-05-05T19:13:49 [I|app|9a10e73b]   Rendered /opt/theforeman/tfm/root/usr/share/gems/gems/foreman_remote_execution-6.0.0/app/views/job_invocations/_card_target_hosts.html.erb (Duration: 4.8ms | Allocations: 1603)
2022-05-05T19:13:49 [I|app|9a10e73b]   Rendered /opt/theforeman/tfm/root/usr/share/gems/gems/foreman_remote_execution-6.0.0/app/views/job_invocations/_card_user_input.html.erb (Duration: 4.8ms | Allocations: 1033)
2022-05-05T19:13:49 [I|app|9a10e73b]   Rendered /opt/theforeman/tfm/root/usr/share/gems/gems/foreman_remote_execution-6.0.0/app/views/job_invocations/_tab_hosts.html.erb (Duration: 2.4ms | Allocations: 269)
2022-05-05T19:13:49 [I|app|9a10e73b]   Rendered /opt/theforeman/tfm/root/usr/share/gems/gems/foreman_remote_execution-6.0.0/app/views/job_invocations/_tab_overview.html.erb (Duration: 51.8ms | Allocations: 14747)
2022-05-05T19:13:50 [I|app|9a10e73b]   Rendered /opt/theforeman/tfm/root/usr/share/gems/gems/foreman_remote_execution-6.0.0/app/views/job_invocations/_user_input.html.erb (Duration: 34.8ms | Allocations: 7813)
2022-05-05T19:13:50 [I|app|9a10e73b]   Rendered /opt/theforeman/tfm/root/usr/share/gems/gems/foreman_remote_execution-6.0.0/app/views/job_invocations/_tab_preview_templates.html.erb (Duration: 46.9ms | Allocations: 11650)
2022-05-05T19:13:50 [I|app|9a10e73b]   Rendered /opt/theforeman/tfm/root/usr/share/gems/gems/foreman_remote_execution-6.0.0/app/views/job_invocations/show.html.erb within layouts/application (Duration: 139.5ms | Allocations: 39829)
2022-05-05T19:13:50 [I|app|9a10e73b]   Rendered layouts/_application_content.html.erb (Duration: 4.9ms | Allocations: 5343)
2022-05-05T19:13:50 [I|app|9a10e73b]   Rendering layouts/base.html.erb
2022-05-05T19:13:50 [I|app|9a10e73b]   Rendered layouts/base.html.erb (Duration: 33.8ms | Allocations: 22865)
2022-05-05T19:13:50 [I|app|9a10e73b] Completed 200 OK in 210ms (Views: 170.7ms | ActiveRecord: 18.0ms | Allocations: 81840)
2022-05-05T19:13:50 [I|bac|8cb080dc] Task {label: Actions::RemoteExecution::RunHostJob, id: 85161a20-e695-4586-b043-21b5f4122e95, execution_plan_id: 10b7a343-de70-48ad-b4fa-ed94ca98e860} state changed: planned
2022-05-05T19:13:50 [I|bac|8cb080dc] Task {label: Actions::RemoteExecution::RunHostJob, id: 85161a20-e695-4586-b043-21b5f4122e95, execution_plan_id: 10b7a343-de70-48ad-b4fa-ed94ca98e860} state changed: running
2022-05-05T19:13:50 [I|app|9d6857de] Started GET "/javascripts/charts.js" for **.**.**.** at 2022-05-05 19:13:50 +0100
2022-05-05T19:13:50 [F|app|9d6857de]
 9d6857de | ActionController::RoutingError (No route matches [GET] "/javascripts/charts.js"):
 9d6857de |
 9d6857de | lib/foreman/middleware/logging_context_request.rb:11:in `call'
 9d6857de | katello (4.4.0.2) lib/katello/prevent_json_parsing.rb:12:in `call'
2022-05-05T19:13:50 [I|app|c326ffc0] Started POST "/foreman_tasks/api/tasks/callback" for **.**.**.** at 2022-05-05 19:13:50 +0100
2022-05-05T19:13:50 [I|app|c326ffc0] Processing by ForemanTasks::Api::TasksController#callback as HTML
2022-05-05T19:13:50 [I|app|c326ffc0]   Parameters: {"callback"=>{"task_id"=>"85161a20-e695-4586-b043-21b5f4122e95", "step_id"=>3}, "data"=>{"result"=>[{"output_type"=>"debug", "output"=>"Error initializing command: RuntimeError - Unable to create directory on remote system /var/tmp/foreman-ssh-cmd-7399852b-84ac-4aa5-afb3-20cb12ac14d7: exit code: 255\n ssh_exchange_identification: Connection closed by remote host\r\n", "timestamp"=>1651774430.4566014}], "runner_id"=>"7399852b-84ac-4aa5-afb3-20cb12ac14d7", "exit_status"=>"EXCEPTION"}, "task"=>{}}
2022-05-05T19:13:50 [I|app|c326ffc0] Completed 200 OK in 24ms (Views: 0.2ms | ActiveRecord: 5.7ms | Allocations: 2669)
2022-05-05T19:13:50 [I|bac|8cb080dc] Event delivered by request c326ffc0-aba2-4ceb-87d7-d1449446f61a
2022-05-05T19:13:50 [E|bac|8cb080dc] Job execution failed
2022-05-05T19:13:50 [I|bac|8cb080dc] Task {label: Actions::RemoteExecution::RunHostJob, id: 85161a20-e695-4586-b043-21b5f4122e95, execution_plan_id: 10b7a343-de70-48ad-b4fa-ed94ca98e860} state changed: stopped  result: error
2022-05-05T19:13:50 [I|app|c328056d] Started GET "/javascripts/charts.js" for **.**.**.** at 2022-05-05 19:13:50 +0100
2022-05-05T19:13:50 [F|app|c328056d]
 c328056d | ActionController::RoutingError (No route matches [GET] "/javascripts/charts.js"):
 c328056d |
 c328056d | lib/foreman/middleware/logging_context_request.rb:11:in `call'
 c328056d | katello (4.4.0.2) lib/katello/prevent_json_parsing.rb:12:in `call'
2022-05-05T19:13:50 [I|app|3456de74] Started GET "/notification_recipients" for **.**.**.** at 2022-05-05 19:13:50 +0100
2022-05-05T19:13:50 [I|app|3456de74] Processing by NotificationRecipientsController#index as JSON
2022-05-05T19:13:51 [I|app|3456de74] Completed 200 OK in 10ms (Views: 0.1ms | ActiveRecord: 1.7ms | Allocations: 2162)
2022-05-05T19:13:51 [I|app|fa82dfc2] Started GET "/job_invocations/chart?id=33" for **.**.**.** at 2022-05-05 19:13:51 +0100
2022-05-05T19:13:51 [I|app|fa82dfc2] Processing by JobInvocationsController#chart as JSON
2022-05-05T19:13:51 [I|app|fa82dfc2]   Parameters: {"id"=>"33"}
2022-05-05T19:13:51 [I|app|fa82dfc2] Completed 200 OK in 27ms (Views: 0.3ms | ActiveRecord: 3.7ms | Allocations: 7786)
2022-05-05T19:13:51 [I|app|a7eccc26] Started GET "/job_invocations/33?page=1&per_page=20" for **.**.**.** at 2022-05-05 19:13:51 +0100
2022-05-05T19:13:51 [I|app|a7eccc26] Processing by JobInvocationsController#show as JSON
2022-05-05T19:13:51 [I|app|a7eccc26]   Parameters: {"page"=>"1", "per_page"=>"20", "id"=>"33"}
2022-05-05T19:13:51 [I|app|a7eccc26]   Rendering /opt/theforeman/tfm/root/usr/share/gems/gems/foreman_remote_execution-6.0.0/app/views/job_invocations/show.json.erb
2022-05-05T19:13:51 [I|app|a7eccc26]   Rendered /opt/theforeman/tfm/root/usr/share/gems/gems/foreman_remote_execution-6.0.0/app/views/job_invocations/show.json.erb (Duration: 21.9ms | Allocations: 6247)
2022-05-05T19:13:51 [I|app|a7eccc26] Completed 200 OK in 90ms (Views: 21.9ms | ActiveRecord: 16.7ms | Allocations: 17057)
2022-05-05T19:13:52 [I|app|983b41d6] Started GET "/job_invocations/33?_=1651774430593" for **.**.**.** at 2022-05-05 19:13:52 +0100
2022-05-05T19:13:52 [I|app|7b001e3c] Started GET "/job_invocations/33?page=1&per_page=20" for **.**.**.** at 2022-05-05 19:13:52 +0100
2022-05-05T19:13:52 [I|app|983b41d6] Processing by JobInvocationsController#show as JS
2022-05-05T19:13:52 [I|app|983b41d6]   Parameters: {"_"=>"1651774430593", "id"=>"33"}
2022-05-05T19:13:52 [I|app|7b001e3c] Processing by JobInvocationsController#show as JSON
2022-05-05T19:13:52 [I|app|7b001e3c]   Parameters: {"page"=>"1", "per_page"=>"20", "id"=>"33"}
2022-05-05T19:13:52 [I|app|7b001e3c]   Rendering /opt/theforeman/tfm/root/usr/share/gems/gems/foreman_remote_execution-6.0.0/app/views/job_invocations/show.json.erb
2022-05-05T19:13:52 [I|app|983b41d6]   Rendering /opt/theforeman/tfm/root/usr/share/gems/gems/foreman_remote_execution-6.0.0/app/views/job_invocations/show.js.erb
2022-05-05T19:13:52 [I|app|7b001e3c]   Rendered /opt/theforeman/tfm/root/usr/share/gems/gems/foreman_remote_execution-6.0.0/app/views/job_invocations/show.json.erb (Duration: 9.3ms | Allocations: 6461)
2022-05-05T19:13:52 [I|app|7b001e3c] Completed 200 OK in 44ms (Views: 9.0ms | ActiveRecord: 6.3ms | Allocations: 17129)
2022-05-05T19:13:52 [I|app|983b41d6]   Rendered /opt/theforeman/tfm/root/usr/share/gems/gems/foreman_remote_execution-6.0.0/app/views/job_invocations/show.js.erb (Duration: 29.2ms | Allocations: 7870)
2022-05-05T19:13:52 [I|app|983b41d6] Completed 200 OK in 68ms (Views: 31.8ms | ActiveRecord: 9.1ms | Allocations: 19155)
2022-05-05T19:13:53 [I|app|0bbcccd7] Started GET "/job_invocations/chart?id=33" for **.**.**.** at 2022-05-05 19:13:53 +0100
2022-05-05T19:13:53 [I|app|0bbcccd7] Processing by JobInvocationsController#chart as JSON
2022-05-05T19:13:53 [I|app|0bbcccd7]   Parameters: {"id"=>"33"}
2022-05-05T19:13:53 [I|app|0bbcccd7] Completed 200 OK in 20ms (Views: 0.3ms | ActiveRecord: 3.1ms | Allocations: 7787)
2022-05-05T19:13:53 [I|app|68a8267c] Started GET "/job_invocations/33?page=1&per_page=20" for **.**.**.** at 2022-05-05 19:13:53 +0100
2022-05-05T19:13:53 [I|app|68a8267c] Processing by JobInvocationsController#show as JSON
2022-05-05T19:13:53 [I|app|68a8267c]   Parameters: {"page"=>"1", "per_page"=>"20", "id"=>"33"}
2022-05-05T19:13:53 [I|app|68a8267c]   Rendering /opt/theforeman/tfm/root/usr/share/gems/gems/foreman_remote_execution-6.0.0/app/views/job_invocations/show.json.erb
2022-05-05T19:13:53 [I|app|68a8267c]   Rendered /opt/theforeman/tfm/root/usr/share/gems/gems/foreman_remote_execution-6.0.0/app/views/job_invocations/show.json.erb (Duration: 7.8ms | Allocations: 6444)
2022-05-05T19:13:53 [I|app|68a8267c] Completed 200 OK in 35ms (Views: 7.6ms | ActiveRecord: 5.3ms | Allocations: 17107)
2022-05-05T19:13:53 [I|app|2f75b427] Started GET "/job_invocations/33?hosts_needs_refresh=&_=1651774430594" for **.**.**.** at 2022-05-05 19:13:53 +0100
2022-05-05T19:13:53 [I|app|2f75b427] Processing by JobInvocationsController#show as JS
2022-05-05T19:13:53 [I|app|2f75b427]   Parameters: {"hosts_needs_refresh"=>"", "_"=>"1651774430594", "id"=>"33"}
2022-05-05T19:13:53 [I|app|2f75b427]   Rendering /opt/theforeman/tfm/root/usr/share/gems/gems/foreman_remote_execution-6.0.0/app/views/job_invocations/show.js.erb
2022-05-05T19:13:53 [I|app|2f75b427]   Rendered /opt/theforeman/tfm/root/usr/share/gems/gems/foreman_remote_execution-6.0.0/app/views/job_invocations/show.js.erb (Duration: 25.3ms | Allocations: 12970)
2022-05-05T19:13:53 [I|app|2f75b427] Completed 200 OK in 48ms (Views: 22.0ms | ActiveRecord: 7.9ms | Allocations: 21341)
2022-05-05T19:13:54 [I|app|1bf0246a] Started GET "/job_invocations/33?page=1&per_page=20" for **.**.**.** at 2022-05-05 19:13:54 +0100
2022-05-05T19:13:54 [I|app|1bf0246a] Processing by JobInvocationsController#show as JSON
2022-05-05T19:13:54 [I|app|1bf0246a]   Parameters: {"page"=>"1", "per_page"=>"20", "id"=>"33"}
2022-05-05T19:13:54 [I|app|1bf0246a]   Rendering /opt/theforeman/tfm/root/usr/share/gems/gems/foreman_remote_execution-6.0.0/app/views/job_invocations/show.json.erb
2022-05-05T19:13:54 [I|app|1bf0246a]   Rendered /opt/theforeman/tfm/root/usr/share/gems/gems/foreman_remote_execution-6.0.0/app/views/job_invocations/show.json.erb (Duration: 8.1ms | Allocations: 6444)
2022-05-05T19:13:54 [I|app|1bf0246a] Completed 200 OK in 35ms (Views: 8.1ms | ActiveRecord: 5.1ms | Allocations: 17107)
2022-05-05T19:13:54 [I|app|4e18eb8f] Started GET "/job_invocations/chart?id=33" for **.**.**.** at 2022-05-05 19:13:54 +0100
2022-05-05T19:13:54 [I|app|4e18eb8f] Processing by JobInvocationsController#chart as JSON
2022-05-05T19:13:54 [I|app|4e18eb8f]   Parameters: {"id"=>"33"}
2022-05-05T19:13:54 [I|app|4e18eb8f] Completed 200 OK in 27ms (Views: 0.4ms | ActiveRecord: 3.5ms | Allocations: 7977)
2022-05-05T19:13:54 [I|app|a85363a6] Started GET "/job_invocations/33?hosts_needs_refresh=&_=1651774430595" for **.**.**.** at 2022-05-05 19:13:54 +0100
2022-05-05T19:13:54 [I|app|a85363a6] Processing by JobInvocationsController#show as JS
2022-05-05T19:13:54 [I|app|a85363a6]   Parameters: {"hosts_needs_refresh"=>"", "_"=>"1651774430595", "id"=>"33"}
2022-05-05T19:13:54 [I|app|a85363a6]   Rendering /opt/theforeman/tfm/root/usr/share/gems/gems/foreman_remote_execution-6.0.0/app/views/job_invocations/show.js.erb
2022-05-05T19:13:54 [I|app|a85363a6]   Rendered /opt/theforeman/tfm/root/usr/share/gems/gems/foreman_remote_execution-6.0.0/app/views/job_invocations/show.js.erb (Duration: 25.0ms | Allocations: 13730)
2022-05-05T19:13:54 [I|app|a85363a6] Completed 200 OK in 45ms (Views: 21.8ms | ActiveRecord: 6.9ms | Allocations: 22095)
2022-05-05T19:13:55 [I|app|ab76d4d8] Started GET "/job_invocations/33?page=1&per_page=20" for **.**.**.** at 2022-05-05 19:13:55 +0100
2022-05-05T19:13:55 [I|app|ab76d4d8] Processing by JobInvocationsController#show as JSON
2022-05-05T19:13:55 [I|app|ab76d4d8]   Parameters: {"page"=>"1", "per_page"=>"20", "id"=>"33"}
2022-05-05T19:13:55 [I|app|ab76d4d8]   Rendering /opt/theforeman/tfm/root/usr/share/gems/gems/foreman_remote_execution-6.0.0/app/views/job_invocations/show.json.erb
2022-05-05T19:13:55 [I|app|ab76d4d8]   Rendered /opt/theforeman/tfm/root/usr/share/gems/gems/foreman_remote_execution-6.0.0/app/views/job_invocations/show.json.erb (Duration: 7.1ms | Allocations: 6252)
2022-05-05T19:13:55 [I|app|ab76d4d8] Completed 200 OK in 42ms (Views: 7.1ms | ActiveRecord: 5.6ms | Allocations: 16915)
2022-05-05T19:13:55 [I|app|54ff7428] Started GET "/job_invocations/chart?id=33" for **.**.**.** at 2022-05-05 19:13:55 +0100
2022-05-05T19:13:55 [I|app|54ff7428] Processing by JobInvocationsController#chart as JSON
2022-05-05T19:13:55 [I|app|54ff7428]   Parameters: {"id"=>"33"}
2022-05-05T19:13:55 [I|app|54ff7428] Completed 200 OK in 18ms (Views: 0.3ms | ActiveRecord: 2.7ms | Allocations: 7785)
2022-05-05T19:13:55 [I|app|6cfbaeac] Started GET "/job_invocations/33?hosts_needs_refresh=&_=1651774430596" for **.**.**.** at 2022-05-05 19:13:55 +0100
2022-05-05T19:13:55 [I|app|6cfbaeac] Processing by JobInvocationsController#show as JS
2022-05-05T19:13:55 [I|app|6cfbaeac]   Parameters: {"hosts_needs_refresh"=>"", "_"=>"1651774430596", "id"=>"33"}
2022-05-05T19:13:55 [I|app|6cfbaeac]   Rendering /opt/theforeman/tfm/root/usr/share/gems/gems/foreman_remote_execution-6.0.0/app/views/job_invocations/show.js.erb
2022-05-05T19:13:56 [I|app|6cfbaeac]   Rendered /opt/theforeman/tfm/root/usr/share/gems/gems/foreman_remote_execution-6.0.0/app/views/job_invocations/show.js.erb (Duration: 23.4ms | Allocations: 12962)
2022-05-05T19:13:56 [I|app|6cfbaeac] Completed 200 OK in 43ms (Views: 20.5ms | ActiveRecord: 6.3ms | Allocations: 21327)
2022-05-05T19:13:56 [I|app|33ef5e28] Started GET "/job_invocations/33?page=1&per_page=20" for **.**.**.** at 2022-05-05 19:13:56 +0100
2022-05-05T19:13:56 [I|app|33ef5e28] Processing by JobInvocationsController#show as JSON
2022-05-05T19:13:56 [I|app|33ef5e28]   Parameters: {"page"=>"1", "per_page"=>"20", "id"=>"33"}
2022-05-05T19:13:56 [I|app|33ef5e28]   Rendering /opt/theforeman/tfm/root/usr/share/gems/gems/foreman_remote_execution-6.0.0/app/views/job_invocations/show.json.erb
2022-05-05T19:13:56 [I|app|33ef5e28]   Rendered /opt/theforeman/tfm/root/usr/share/gems/gems/foreman_remote_execution-6.0.0/app/views/job_invocations/show.json.erb (Duration: 7.7ms | Allocations: 6252)
2022-05-05T19:13:56 [I|app|33ef5e28] Completed 200 OK in 34ms (Views: 7.6ms | ActiveRecord: 5.1ms | Allocations: 16915)
2022-05-05T19:13:56 [I|app|c07d6147] Started GET "/job_invocations/chart?id=33" for **.**.**.** at 2022-05-05 19:13:56 +0100
2022-05-05T19:13:56 [I|app|c07d6147] Processing by JobInvocationsController#chart as JSON
2022-05-05T19:13:56 [I|app|c07d6147]   Parameters: {"id"=>"33"}
2022-05-05T19:13:56 [I|app|c07d6147] Completed 200 OK in 20ms (Views: 0.3ms | ActiveRecord: 2.9ms | Allocations: 7977)
2022-05-05T19:13:57 [I|app|558c1b5a] Started GET "/job_invocations/33?hosts_needs_refresh=&_=1651774430597" for **.**.**.** at 2022-05-05 19:13:57 +0100
2022-05-05T19:13:57 [I|app|558c1b5a] Processing by JobInvocationsController#show as JS
2022-05-05T19:13:57 [I|app|558c1b5a]   Parameters: {"hosts_needs_refresh"=>"", "_"=>"1651774430597", "id"=>"33"}
2022-05-05T19:13:57 [I|app|558c1b5a]   Rendering /opt/theforeman/tfm/root/usr/share/gems/gems/foreman_remote_execution-6.0.0/app/views/job_invocations/show.js.erb
2022-05-05T19:13:57 [I|app|558c1b5a]   Rendered /opt/theforeman/tfm/root/usr/share/gems/gems/foreman_remote_execution-6.0.0/app/views/job_invocations/show.js.erb (Duration: 26.6ms | Allocations: 13730)
2022-05-05T19:13:57 [I|app|558c1b5a] Completed 200 OK in 46ms (Views: 23.4ms | ActiveRecord: 6.7ms | Allocations: 22095)
2022-05-05T19:13:57 [I|app|e200d4fc] Started GET "/job_invocations/33?page=1&per_page=20" for **.**.**.** at 2022-05-05 19:13:57 +0100
2022-05-05T19:13:57 [I|app|e200d4fc] Processing by JobInvocationsController#show as JSON
2022-05-05T19:13:57 [I|app|e200d4fc]   Parameters: {"page"=>"1", "per_page"=>"20", "id"=>"33"}
2022-05-05T19:13:57 [I|app|e200d4fc]   Rendering /opt/theforeman/tfm/root/usr/share/gems/gems/foreman_remote_execution-6.0.0/app/views/job_invocations/show.json.erb
2022-05-05T19:13:57 [I|app|e200d4fc]   Rendered /opt/theforeman/tfm/root/usr/share/gems/gems/foreman_remote_execution-6.0.0/app/views/job_invocations/show.json.erb (Duration: 8.6ms | Allocations: 6266)
2022-05-05T19:13:57 [I|app|e200d4fc] Completed 200 OK in 37ms (Views: 8.8ms | ActiveRecord: 5.3ms | Allocations: 16930)
2022-05-05T19:13:59 [I|app|2b8f6640] Started GET "/job_invocations/33?hosts_needs_refresh=&_=1651774430598" for **.**.**.** at 2022-05-05 19:13:59 +0100
2022-05-05T19:13:59 [I|app|2b8f6640] Processing by JobInvocationsController#show as JS
2022-05-05T19:13:59 [I|app|2b8f6640]   Parameters: {"hosts_needs_refresh"=>"", "_"=>"1651774430598", "id"=>"33"}
2022-05-05T19:13:59 [I|app|2b8f6640]   Rendering /opt/theforeman/tfm/root/usr/share/gems/gems/foreman_remote_execution-6.0.0/app/views/job_invocations/show.js.erb
2022-05-05T19:13:59 [I|app|2b8f6640]   Rendered /opt/theforeman/tfm/root/usr/share/gems/gems/foreman_remote_execution-6.0.0/app/views/job_invocations/show.js.erb (Duration: 32.4ms | Allocations: 13730)
2022-05-05T19:13:59 [I|app|2b8f6640] Completed 200 OK in 58ms (Views: 29.6ms | ActiveRecord: 7.8ms | Allocations: 22095)
2022-05-05T19:13:59 [E|bac|8cb080dc] A sub task failed (RuntimeError)
 8cb080dc | /opt/theforeman/tfm/root/usr/share/gems/gems/dynflow-1.6.4/lib/dynflow/action/with_sub_plans.rb:231:in `check_for_errors!'
 8cb080dc | /opt/theforeman/tfm/root/usr/share/gems/gems/dynflow-1.6.4/lib/dynflow/action/with_sub_plans.rb:137:in `try_to_finish'
 8cb080dc | /opt/theforeman/tfm/root/usr/share/gems/gems/dynflow-1.6.4/lib/dynflow/action/with_polling_sub_plans.rb:19:in `poll'
 8cb080dc | /opt/theforeman/tfm/root/usr/share/gems/gems/dynflow-1.6.4/lib/dynflow/action/with_polling_sub_plans.rb:11:in `run'
 8cb080dc | /opt/theforeman/tfm/root/usr/share/gems/gems/foreman_remote_execution-6.0.0/app/lib/actions/remote_execution/run_hosts_job.rb:140:in `run'
 8cb080dc | /opt/theforeman/tfm/root/usr/share/gems/gems/dynflow-1.6.4/lib/dynflow/action.rb:582:in `block (3 levels) in execute_run'
 8cb080dc | /opt/theforeman/tfm/root/usr/share/gems/gems/dynflow-1.6.4/lib/dynflow/middleware/stack.rb:27:in `pass'
 8cb080dc | /opt/theforeman/tfm/root/usr/share/gems/gems/dynflow-1.6.4/lib/dynflow/middleware.rb:19:in `pass'
 8cb080dc | /opt/theforeman/tfm/root/usr/share/gems/gems/foreman-tasks-6.0.1/app/lib/actions/middleware/watch_delegated_proxy_sub_tasks.rb:17:in `run'
 8cb080dc | /opt/theforeman/tfm/root/usr/share/gems/gems/dynflow-1.6.4/lib/dynflow/middleware/stack.rb:23:in `call'
 8cb080dc | /opt/theforeman/tfm/root/usr/share/gems/gems/dynflow-1.6.4/lib/dynflow/middleware/stack.rb:27:in `pass'
 8cb080dc | /opt/theforeman/tfm/root/usr/share/gems/gems/dynflow-1.6.4/lib/dynflow/middleware.rb:19:in `pass'
 8cb080dc | /opt/theforeman/tfm/root/usr/share/gems/gems/dynflow-1.6.4/lib/dynflow/middleware.rb:32:in `run'
 8cb080dc | /opt/theforeman/tfm/root/usr/share/gems/gems/dynflow-1.6.4/lib/dynflow/middleware/stack.rb:23:in `call'
 8cb080dc | /opt/theforeman/tfm/root/usr/share/gems/gems/dynflow-1.6.4/lib/dynflow/middleware/stack.rb:27:in `pass'
 8cb080dc | /opt/theforeman/tfm/root/usr/share/gems/gems/dynflow-1.6.4/lib/dynflow/middleware.rb:19:in `pass'
 8cb080dc | /opt/theforeman/tfm/root/usr/share/gems/gems/dynflow-1.6.4/lib/dynflow/middleware.rb:32:in `run'
 8cb080dc | /opt/theforeman/tfm/root/usr/share/gems/gems/dynflow-1.6.4/lib/dynflow/middleware/stack.rb:23:in `call'
 8cb080dc | /opt/theforeman/tfm/root/usr/share/gems/gems/dynflow-1.6.4/lib/dynflow/middleware/stack.rb:27:in `pass'
 8cb080dc | /opt/theforeman/tfm/root/usr/share/gems/gems/dynflow-1.6.4/lib/dynflow/middleware.rb:19:in `pass'
 8cb080dc | /opt/theforeman/tfm/root/usr/share/gems/gems/foreman-tasks-6.0.1/app/lib/actions/middleware/rails_executor_wrap.rb:14:in `block in run'
 8cb080dc | /opt/theforeman/tfm/root/usr/share/gems/gems/activesupport-6.0.3.7/lib/active_support/execution_wrapper.rb:88:in `wrap'
 8cb080dc | /opt/theforeman/tfm/root/usr/share/gems/gems/foreman-tasks-6.0.1/app/lib/actions/middleware/rails_executor_wrap.rb:13:in `run'
 8cb080dc | /opt/theforeman/tfm/root/usr/share/gems/gems/dynflow-1.6.4/lib/dynflow/middleware/stack.rb:23:in `call'
 8cb080dc | /opt/theforeman/tfm/root/usr/share/gems/gems/dynflow-1.6.4/lib/dynflow/middleware/stack.rb:27:in `pass'
 8cb080dc | /opt/theforeman/tfm/root/usr/share/gems/gems/dynflow-1.6.4/lib/dynflow/middleware.rb:19:in `pass'
 8cb080dc | /opt/theforeman/tfm/root/usr/share/gems/gems/dynflow-1.6.4/lib/dynflow/action/progress.rb:31:in `with_progress_calculation'
 8cb080dc | /opt/theforeman/tfm/root/usr/share/gems/gems/dynflow-1.6.4/lib/dynflow/action/progress.rb:17:in `run'
 8cb080dc | /opt/theforeman/tfm/root/usr/share/gems/gems/dynflow-1.6.4/lib/dynflow/middleware/stack.rb:23:in `call'
 8cb080dc | /opt/theforeman/tfm/root/usr/share/gems/gems/dynflow-1.6.4/lib/dynflow/middleware/stack.rb:27:in `pass'
 8cb080dc | /opt/theforeman/tfm/root/usr/share/gems/gems/dynflow-1.6.4/lib/dynflow/middleware.rb:19:in `pass'
 8cb080dc | /opt/theforeman/tfm/root/usr/share/gems/gems/foreman-tasks-6.0.1/app/lib/actions/middleware/load_setting_values.rb:20:in `run'
 8cb080dc | /opt/theforeman/tfm/root/usr/share/gems/gems/dynflow-1.6.4/lib/dynflow/middleware/stack.rb:23:in `call'
 8cb080dc | /opt/theforeman/tfm/root/usr/share/gems/gems/dynflow-1.6.4/lib/dynflow/middleware/stack.rb:27:in `pass'
 8cb080dc | /opt/theforeman/tfm/root/usr/share/gems/gems/dynflow-1.6.4/lib/dynflow/middleware.rb:19:in `pass'
 8cb080dc | /opt/theforeman/tfm/root/usr/share/gems/gems/foreman-tasks-6.0.1/app/lib/actions/middleware/keep_current_request_id.rb:15:in `block in run'
 8cb080dc | /opt/theforeman/tfm/root/usr/share/gems/gems/foreman-tasks-6.0.1/app/lib/actions/middleware/keep_current_request_id.rb:52:in `restore_current_request_id'
 8cb080dc | /opt/theforeman/tfm/root/usr/share/gems/gems/foreman-tasks-6.0.1/app/lib/actions/middleware/keep_current_request_id.rb:15:in `run'
 8cb080dc | /opt/theforeman/tfm/root/usr/share/gems/gems/dynflow-1.6.4/lib/dynflow/middleware/stack.rb:23:in `call'
 8cb080dc | /opt/theforeman/tfm/root/usr/share/gems/gems/dynflow-1.6.4/lib/dynflow/middleware/stack.rb:27:in `pass'
 8cb080dc | /opt/theforeman/tfm/root/usr/share/gems/gems/dynflow-1.6.4/lib/dynflow/middleware.rb:19:in `pass'
 8cb080dc | /opt/theforeman/tfm/root/usr/share/gems/gems/foreman-tasks-6.0.1/app/lib/actions/middleware/keep_current_timezone.rb:15:in `block in run'
 8cb080dc | /opt/theforeman/tfm/root/usr/share/gems/gems/foreman-tasks-6.0.1/app/lib/actions/middleware/keep_current_timezone.rb:44:in `restore_curent_timezone'
 8cb080dc | /opt/theforeman/tfm/root/usr/share/gems/gems/foreman-tasks-6.0.1/app/lib/actions/middleware/keep_current_timezone.rb:15:in `run'
 8cb080dc | /opt/theforeman/tfm/root/usr/share/gems/gems/dynflow-1.6.4/lib/dynflow/middleware/stack.rb:23:in `call'
 8cb080dc | /opt/theforeman/tfm/root/usr/share/gems/gems/dynflow-1.6.4/lib/dynflow/middleware/stack.rb:27:in `pass'
 8cb080dc | /opt/theforeman/tfm/root/usr/share/gems/gems/dynflow-1.6.4/lib/dynflow/middleware.rb:19:in `pass'
 8cb080dc | /opt/theforeman/tfm/root/usr/share/gems/gems/foreman-tasks-6.0.1/app/lib/actions/middleware/keep_current_taxonomies.rb:15:in `block in run'
 8cb080dc | /opt/theforeman/tfm/root/usr/share/gems/gems/foreman-tasks-6.0.1/app/lib/actions/middleware/keep_current_taxonomies.rb:45:in `restore_current_taxonomies'
 8cb080dc | /opt/theforeman/tfm/root/usr/share/gems/gems/foreman-tasks-6.0.1/app/lib/actions/middleware/keep_current_taxonomies.rb:15:in `run'
 8cb080dc | /opt/theforeman/tfm/root/usr/share/gems/gems/dynflow-1.6.4/lib/dynflow/middleware/stack.rb:23:in `call'
 8cb080dc | /opt/theforeman/tfm/root/usr/share/gems/gems/dynflow-1.6.4/lib/dynflow/middleware/stack.rb:27:in `pass'
 8cb080dc | /opt/theforeman/tfm/root/usr/share/gems/gems/dynflow-1.6.4/lib/dynflow/middleware.rb:19:in `pass'
 8cb080dc | /opt/theforeman/tfm/root/usr/share/gems/gems/dynflow-1.6.4/lib/dynflow/middleware.rb:32:in `run'
 8cb080dc | /opt/theforeman/tfm/root/usr/share/gems/gems/dynflow-1.6.4/lib/dynflow/middleware/stack.rb:23:in `call'
 8cb080dc | /opt/theforeman/tfm/root/usr/share/gems/gems/dynflow-1.6.4/lib/dynflow/middleware/stack.rb:27:in `pass'
 8cb080dc | /opt/theforeman/tfm/root/usr/share/gems/gems/dynflow-1.6.4/lib/dynflow/middleware.rb:19:in `pass'
 8cb080dc | /opt/theforeman/tfm/root/usr/share/gems/gems/foreman-tasks-6.0.1/app/lib/actions/middleware/keep_current_user.rb:15:in `block in run'
 8cb080dc | /opt/theforeman/tfm/root/usr/share/gems/gems/foreman-tasks-6.0.1/app/lib/actions/middleware/keep_current_user.rb:54:in `restore_curent_user'
 8cb080dc | /opt/theforeman/tfm/root/usr/share/gems/gems/foreman-tasks-6.0.1/app/lib/actions/middleware/keep_current_user.rb:15:in `run'
 8cb080dc | /opt/theforeman/tfm/root/usr/share/gems/gems/dynflow-1.6.4/lib/dynflow/middleware/stack.rb:23:in `call'
 8cb080dc | /opt/theforeman/tfm/root/usr/share/gems/gems/dynflow-1.6.4/lib/dynflow/middleware/world.rb:31:in `execute'
 8cb080dc | /opt/theforeman/tfm/root/usr/share/gems/gems/dynflow-1.6.4/lib/dynflow/action.rb:581:in `block (2 levels) in execute_run'
 8cb080dc | /opt/theforeman/tfm/root/usr/share/gems/gems/dynflow-1.6.4/lib/dynflow/action.rb:580:in `catch'
 8cb080dc | /opt/theforeman/tfm/root/usr/share/gems/gems/dynflow-1.6.4/lib/dynflow/action.rb:580:in `block in execute_run'
 8cb080dc | /opt/theforeman/tfm/root/usr/share/gems/gems/dynflow-1.6.4/lib/dynflow/action.rb:483:in `block in with_error_handling'
 8cb080dc | /opt/theforeman/tfm/root/usr/share/gems/gems/dynflow-1.6.4/lib/dynflow/action.rb:483:in `catch'
 8cb080dc | /opt/theforeman/tfm/root/usr/share/gems/gems/dynflow-1.6.4/lib/dynflow/action.rb:483:in `with_error_handling'
 8cb080dc | /opt/theforeman/tfm/root/usr/share/gems/gems/dynflow-1.6.4/lib/dynflow/action.rb:575:in `execute_run'
 8cb080dc | /opt/theforeman/tfm/root/usr/share/gems/gems/dynflow-1.6.4/lib/dynflow/action.rb:296:in `execute'
 8cb080dc | /opt/theforeman/tfm/root/usr/share/gems/gems/dynflow-1.6.4/lib/dynflow/execution_plan/steps/abstract_flow_step.rb:18:in `block (2 levels) in execute'
 8cb080dc | /opt/theforeman/tfm/root/usr/share/gems/gems/dynflow-1.6.4/lib/dynflow/execution_plan/steps/abstract.rb:167:in `with_meta_calculation'
 8cb080dc | /opt/theforeman/tfm/root/usr/share/gems/gems/dynflow-1.6.4/lib/dynflow/execution_plan/steps/abstract_flow_step.rb:17:in `block in execute'
 8cb080dc | /opt/theforeman/tfm/root/usr/share/gems/gems/dynflow-1.6.4/lib/dynflow/execution_plan/steps/abstract_flow_step.rb:32:in `open_action'
 8cb080dc | /opt/theforeman/tfm/root/usr/share/gems/gems/dynflow-1.6.4/lib/dynflow/execution_plan/steps/abstract_flow_step.rb:16:in `execute'
 8cb080dc | /opt/theforeman/tfm/root/usr/share/gems/gems/dynflow-1.6.4/lib/dynflow/director.rb:94:in `execute'
 8cb080dc | /opt/theforeman/tfm/root/usr/share/gems/gems/dynflow-1.6.4/lib/dynflow/executors/sidekiq/worker_jobs.rb:11:in `block (2 levels) in perform'
 8cb080dc | /opt/theforeman/tfm/root/usr/share/gems/gems/dynflow-1.6.4/lib/dynflow/executors.rb:18:in `run_user_code'
 8cb080dc | /opt/theforeman/tfm/root/usr/share/gems/gems/dynflow-1.6.4/lib/dynflow/executors/sidekiq/worker_jobs.rb:9:in `block in perform'
 8cb080dc | /opt/theforeman/tfm/root/usr/share/gems/gems/dynflow-1.6.4/lib/dynflow/executors/sidekiq/worker_jobs.rb:25:in `with_telemetry'
 8cb080dc | /opt/theforeman/tfm/root/usr/share/gems/gems/dynflow-1.6.4/lib/dynflow/executors/sidekiq/worker_jobs.rb:8:in `perform'
 8cb080dc | /opt/theforeman/tfm/root/usr/share/gems/gems/dynflow-1.6.4/lib/dynflow/executors/sidekiq/serialization.rb:27:in `perform'
 8cb080dc | [ sidekiq ]
 8cb080dc | [ concurrent-ruby ]
2022-05-05T19:13:59 [I|bac|8cb080dc] Task {label: Actions::RemoteExecution::RunHostsJob, id: f0f4941c-622a-4eab-a0c1-e84e5e5339c3, execution_plan_id: 7bcbd0fc-02e5-429f-ba94-d0bc76cdbd17} state changed: stopped  result: warning
2022-05-05T19:14:01 [I|app|344a12ba] Started GET "/job_invocations/33?hosts_needs_refresh=&_=1651774430599" for **.**.**.** at 2022-05-05 19:14:01 +0100
2022-05-05T19:14:01 [I|app|344a12ba] Processing by JobInvocationsController#show as JS
2022-05-05T19:14:01 [I|app|344a12ba]   Parameters: {"hosts_needs_refresh"=>"", "_"=>"1651774430599", "id"=>"33"}
2022-05-05T19:14:01 [I|app|344a12ba]   Rendering /opt/theforeman/tfm/root/usr/share/gems/gems/foreman_remote_execution-6.0.0/app/views/job_invocations/show.js.erb
2022-05-05T19:14:01 [I|app|344a12ba]   Rendered /opt/theforeman/tfm/root/usr/share/gems/gems/foreman_remote_execution-6.0.0/app/views/job_invocations/show.js.erb (Duration: 27.4ms | Allocations: 11731)
2022-05-05T19:14:01 [I|app|344a12ba] Completed 200 OK in 53ms (Views: 23.5ms | ActiveRecord: 8.2ms | Allocations: 20354)
2022-05-05T19:14:06 [I|app|b89076fc] Started GET "/job_invocations/chart?id=33" for **.**.**.** at 2022-05-05 19:14:06 +0100
2022-05-05T19:14:06 [I|app|b89076fc] Processing by JobInvocationsController#chart as JSON
2022-05-05T19:14:06 [I|app|b89076fc]   Parameters: {"id"=>"33"}
2022-05-05T19:14:06 [I|app|b89076fc] Completed 200 OK in 29ms (Views: 0.3ms | ActiveRecord: 3.4ms | Allocations: 8257)
2022-05-05T19:14:06 [I|app|154896b0] Started GET "/job_invocations/33?page=1&per_page=20" for **.**.**.** at 2022-05-05 19:14:06 +0100
2022-05-05T19:14:06 [I|app|154896b0] Processing by JobInvocationsController#show as JSON
2022-05-05T19:14:06 [I|app|154896b0]   Parameters: {"page"=>"1", "per_page"=>"20", "id"=>"33"}
2022-05-05T19:14:06 [I|app|154896b0]   Rendering /opt/theforeman/tfm/root/usr/share/gems/gems/foreman_remote_execution-6.0.0/app/views/job_invocations/show.json.erb
2022-05-05T19:14:07 [I|app|154896b0]   Rendered /opt/theforeman/tfm/root/usr/share/gems/gems/foreman_remote_execution-6.0.0/app/views/job_invocations/show.json.erb (Duration: 8.3ms | Allocations: 6254)
2022-05-05T19:14:07 [I|app|154896b0] Completed 200 OK in 52ms (Views: 8.4ms | ActiveRecord: 6.7ms | Allocations: 17175)
2022-05-05T19:14:07 [I|app|b0793053] Started GET "/job_invocations/33?page=1&per_page=20" for **.**.**.** at 2022-05-05 19:14:07 +0100
2022-05-05T19:14:07 [I|app|b0793053] Processing by JobInvocationsController#show as JSON
2022-05-05T19:14:07 [I|app|b0793053]   Parameters: {"page"=>"1", "per_page"=>"20", "id"=>"33"}
2022-05-05T19:14:07 [I|app|b0793053]   Rendering /opt/theforeman/tfm/root/usr/share/gems/gems/foreman_remote_execution-6.0.0/app/views/job_invocations/show.json.erb
2022-05-05T19:14:07 [I|app|b0793053]   Rendered /opt/theforeman/tfm/root/usr/share/gems/gems/foreman_remote_execution-6.0.0/app/views/job_invocations/show.json.erb (Duration: 8.0ms | Allocations: 6252)
2022-05-05T19:14:07 [I|app|b0793053] Completed 200 OK in 50ms (Views: 8.1ms | ActiveRecord: 6.7ms | Allocations: 17173)
2022-05-05T19:14:08 [I|app|1419b71d] Started GET "/template_invocations/66" for **.**.**.** at 2022-05-05 19:14:08 +0100
2022-05-05T19:14:08 [I|app|1419b71d] Processing by TemplateInvocationsController#show as HTML
2022-05-05T19:14:08 [I|app|1419b71d]   Parameters: {"id"=>"66"}
2022-05-05T19:14:08 [I|app|1419b71d]   Rendering /opt/theforeman/tfm/root/usr/share/gems/gems/foreman_remote_execution-6.0.0/app/views/template_invocations/show.html.erb within layouts/application
2022-05-05T19:14:08 [I|app|1419b71d]   Rendered collection of /opt/theforeman/tfm/root/usr/share/gems/gems/foreman_remote_execution-6.0.0/app/views/template_invocations/_output_line_set.html.erb [2 times] (Duration: 10.7ms | Allocations: 6223)
2022-05-05T19:14:08 [I|app|1419b71d]   Rendered /opt/theforeman/tfm/root/usr/share/gems/gems/foreman_remote_execution-6.0.0/app/views/template_invocations/_refresh.js.erb (Duration: 1.3ms | Allocations: 199)
2022-05-05T19:14:08 [I|app|1419b71d]   Rendered /opt/theforeman/tfm/root/usr/share/gems/gems/foreman_remote_execution-6.0.0/app/views/template_invocations/show.html.erb within layouts/application (Duration: 53.4ms | Allocations: 16660)
2022-05-05T19:14:08 [I|app|1419b71d]   Rendered layouts/_application_content.html.erb (Duration: 3.5ms | Allocations: 5346)
2022-05-05T19:14:08 [I|app|1419b71d]   Rendering layouts/base.html.erb
2022-05-05T19:14:08 [I|app|1419b71d]   Rendered layouts/base.html.erb (Duration: 29.1ms | Allocations: 22866)
2022-05-05T19:14:08 [I|app|1419b71d] Completed 200 OK in 176ms (Views: 90.8ms | ActiveRecord: 9.3ms | Allocations: 63858)
2022-05-05T19:14:09 [I|app|d496c27f] Started GET "/notification_recipients" for **.**.**.** at 2022-05-05 19:14:09 +0100
2022-05-05T19:14:09 [I|app|d496c27f] Processing by NotificationRecipientsController#index as JSON
2022-05-05T19:14:09 [I|app|d496c27f] Completed 200 OK in 71ms (Views: 0.3ms | ActiveRecord: 24.4ms | Allocations: 26588)
2022-05-05T19:14:12 [I|app|b36bb327] Started GET "/javascripts/charts.js" for **.**.**.** at 2022-05-05 19:14:12 +0100
2022-05-05T19:14:12 [F|app|b36bb327]
 b36bb327 | ActionController::RoutingError (No route matches [GET] "/javascripts/charts.js"):
 b36bb327 |
 b36bb327 | lib/foreman/middleware/logging_context_request.rb:11:in `call'
 b36bb327 | katello (4.4.0.2) lib/katello/prevent_json_parsing.rb:12:in `call'
2022-05-05T19:14:13 [I|app|ded1edff] Started GET "/javascripts/charts.js" for **.**.**.** at 2022-05-05 19:14:13 +0100
2022-05-05T19:14:13 [F|app|ded1edff]
 ded1edff | ActionController::RoutingError (No route matches [GET] "/javascripts/charts.js"):
 ded1edff |
 ded1edff | lib/foreman/middleware/logging_context_request.rb:11:in `call'
 ded1edff | katello (4.4.0.2) lib/katello/prevent_json_parsing.rb:12:in `call'
2022-05-05T19:14:14 [I|app|50b61917] Started GET "/job_invocations/33?page=1&per_page=20" for **.**.**.** at 2022-05-05 19:14:14 +0100
2022-05-05T19:14:14 [I|app|50b61917] Processing by JobInvocationsController#show as JSON
2022-05-05T19:14:14 [I|app|50b61917]   Parameters: {"page"=>"1", "per_page"=>"20", "id"=>"33"}
2022-05-05T19:14:14 [I|app|50b61917]   Rendering /opt/theforeman/tfm/root/usr/share/gems/gems/foreman_remote_execution-6.0.0/app/views/job_invocations/show.json.erb
2022-05-05T19:14:14 [I|app|50b61917]   Rendered /opt/theforeman/tfm/root/usr/share/gems/gems/foreman_remote_execution-6.0.0/app/views/job_invocations/show.json.erb (Duration: 8.2ms | Allocations: 6279)
2022-05-05T19:14:14 [I|app|50b61917] Completed 200 OK in 45ms (Views: 8.3ms | ActiveRecord: 5.2ms | Allocations: 17201)
2022-05-05T19:14:15 [I|app|189daeb6] Started GET "/job_invocations/33?_=1651774453098" for **.**.**.** at 2022-05-05 19:14:15 +0100
2022-05-05T19:14:15 [I|app|189daeb6] Processing by JobInvocationsController#show as JS
2022-05-05T19:14:15 [I|app|189daeb6]   Parameters: {"_"=>"1651774453098", "id"=>"33"}
2022-05-05T19:14:15 [I|app|189daeb6]   Rendering /opt/theforeman/tfm/root/usr/share/gems/gems/foreman_remote_execution-6.0.0/app/views/job_invocations/show.js.erb
2022-05-05T19:14:15 [I|app|189daeb6]   Rendered /opt/theforeman/tfm/root/usr/share/gems/gems/foreman_remote_execution-6.0.0/app/views/job_invocations/show.js.erb (Duration: 22.3ms | Allocations: 11744)
2022-05-05T19:14:15 [I|app|189daeb6] Completed 200 OK in 44ms (Views: 19.7ms | ActiveRecord: 6.4ms | Allocations: 20366)
2022-05-05T19:15:00 [I|app|9f4de4a3] Started GET "/job_invocations/chart?id=33" for **.**.**.** at 2022-05-05 19:15:00 +0100
2022-05-05T19:15:00 [I|app|9f4de4a3] Processing by JobInvocationsController#chart as JSON
2022-05-05T19:15:00 [I|app|9f4de4a3]   Parameters: {"id"=>"33"}
2022-05-05T19:15:00 [I|app|9f4de4a3] Completed 200 OK in 23ms (Views: 0.4ms | ActiveRecord: 3.0ms | Allocations: 8065)

aruzicka · May 6, 2022, 9:39am

Hi,

ssh -i ~foreman-proxy/.ssh/id_rsa_foreman_proxy root@...

Good, that’s a solid start.

Could you bump log_level to DEBUG in /etc/foreman-proxy/settings.yml, add :ssh_log_level: debug to /etc/foreman-proxy/settings.d/remote_execution_ssh.yml, restart foreman-proxy service, try running the job again a watching its output in foreman? That should give a hint what went wrong

jpurtell · May 6, 2022, 12:25pm

Not to highjack this post, but I’m having the same exact problem with my Foreman 3.2 / Katellow 4.4 installation as well. I bumped the log level to debug and am getting this from the remote job execution

Plus here’s the log, /var/log/foreman-proxy/proxy.log

[root@foreman foreman-proxy]# cat /var/log/foreman-proxy/proxy.log
2022-05-06T08:21:25 5f68652e [I] Started GET /dynflow/tasks/count state=running
2022-05-06T08:21:25 5f68652e [I] Finished GET /dynflow/tasks/count with 200 (1.4 ms)
2022-05-06T08:21:25 5f68652e [I] Started POST /dynflow/tasks/launch
2022-05-06T08:21:25 5f68652e [I] Finished POST /dynflow/tasks/launch with 404 (0.91 ms)
2022-05-06T08:21:25 5f68652e [I] Started GET /dynflow/tasks/c7675c50-68bb-4d36-852b-5a9263cb88cb/status
2022-05-06T08:21:25 5f68652e [I] Finished GET /dynflow/tasks/c7675c50-68bb-4d36-852b-5a9263cb88cb/status with 404 (1.09 ms)
2022-05-06T08:21:30 d1b0bcb7 [I] Started GET /dynflow/tasks/c7675c50-68bb-4d36-852b-5a9263cb88cb/status
2022-05-06T08:21:30 d1b0bcb7 [I] Finished GET /dynflow/tasks/c7675c50-68bb-4d36-852b-5a9263cb88cb/status with 404 (2.02 ms)
2022-05-06T08:21:30 d1b0bcb7 [I] Started GET /dynflow/tasks/c7675c50-68bb-4d36-852b-5a9263cb88cb/status
2022-05-06T08:21:30 d1b0bcb7 [I] Finished GET /dynflow/tasks/c7675c50-68bb-4d36-852b-5a9263cb88cb/status with 404 (2.5 ms)
2022-05-06T08:21:32 65e04996 [I] Started GET /dynflow/tasks/c7675c50-68bb-4d36-852b-5a9263cb88cb/status
2022-05-06T08:21:32 65e04996 [I] Finished GET /dynflow/tasks/c7675c50-68bb-4d36-852b-5a9263cb88cb/status with 404 (2.13 ms)
2022-05-06T08:21:32 65e04996 [I] Started GET /dynflow/tasks/c7675c50-68bb-4d36-852b-5a9263cb88cb/status
2022-05-06T08:21:32 65e04996 [I] Finished GET /dynflow/tasks/c7675c50-68bb-4d36-852b-5a9263cb88cb/status with 404 (2.37 ms)
2022-05-06T08:21:34 1ee16b41 [I] Started GET /dynflow/tasks/c7675c50-68bb-4d36-852b-5a9263cb88cb/status
2022-05-06T08:21:34 1ee16b41 [I] Finished GET /dynflow/tasks/c7675c50-68bb-4d36-852b-5a9263cb88cb/status with 404 (2.52 ms)
…

jpurtell · May 6, 2022, 12:28pm

Also, I have the ssh-keys setup correctly too. . . “karma1” is my target host

-bash-4.2$ id
uid=993(foreman-proxy) gid=990(foreman-proxy) groups=990(foreman-proxy),987(puppet)
-bash-4.2$ ssh -i ~/.ssh/id_rsa_foreman_proxy root@karma1 ‘whoami’
root
-bash-4.2$

aruzicka · May 6, 2022, 12:44pm

Have you also bumped the “regular” log level in /etc/foreman-proxy/settings.yml? If not, then you should see that foreman-proxy complains about ssh log level being more verbose than the standard one.

jpurtell · May 6, 2022, 3:54pm

So, now I see a potential problem with the /etc/ssh/ssh_config. This line in the log and WebUI output. Not sure if this is a problem or not

2022-05-06T11:47:04 [D] debug1: /etc/ssh/ssh_config line 62: Applying options for *

[root@foreman foreman-proxy]# ll -rt
total 184
-rw-r–r-- 1 foreman-proxy foreman-proxy 15596 May 5 18:52 proxy.log-20220506.gz
-rw-r–r-- 1 root root 171054 May 6 08:18 proxy.log.1
-rw-r–r-- 1 foreman-proxy foreman-proxy 0 May 6 11:46 proxy.log
[root@foreman foreman-proxy]# ll -rt
total 224
-rw-r–r-- 1 foreman-proxy foreman-proxy 15596 May 5 18:52 proxy.log-20220506.gz
-rw-r–r-- 1 root root 171054 May 6 08:18 proxy.log.1
-rw-r–r-- 1 foreman-proxy foreman-proxy 40408 May 6 11:48 proxy.log
[root@foreman foreman-proxy]# cat proxy.log
2022-05-06T11:46:52 [D] Executor heartbeat
2022-05-06T11:47:03 [D] accept: 192.168.1.7:48416
2022-05-06T11:47:03 [D] Rack::Handler::WEBrick is invoked.
2022-05-06T11:47:03 c3a1e0a7 [I] Started GET /dynflow/tasks/count state=running
2022-05-06T11:47:03 c3a1e0a7 [D] verifying remote client 192.168.1.7 against trusted_hosts [“foreman.rogue.home”]
2022-05-06T11:47:03 c3a1e0a7 [I] Finished GET /dynflow/tasks/count with 200 (14.07 ms)
2022-05-06T11:47:03 [D] close: 192.168.1.7:48416
2022-05-06T11:47:04 [D] accept: 192.168.1.7:48418
2022-05-06T11:47:04 [D] Rack::Handler::WEBrick is invoked.
2022-05-06T11:47:04 c3a1e0a7 [I] Started POST /dynflow/tasks/launch
2022-05-06T11:47:04 c3a1e0a7 [D] verifying remote client 192.168.1.7 against trusted_hosts [“foreman.rogue.home”]
2022-05-06T11:47:04 c3a1e0a7 [D] ExecutionPlan 399a1566-8625-48ec-b5ea-416b0c297064 pending >> planning
2022-05-06T11:47:04 c3a1e0a7 [D] Step 399a1566-8625-48ec-b5ea-416b0c297064: 1 pending >> running in phase Plan Proxy::Dynflow::Action::Batch
2022-05-06T11:47:04 c3a1e0a7 [D] Step 399a1566-8625-48ec-b5ea-416b0c297064: 1 running >> success in phase Plan Proxy::Dynflow::Action::Batch
2022-05-06T11:47:04 c3a1e0a7 [D] ExecutionPlan 399a1566-8625-48ec-b5ea-416b0c297064 planning >> planned
2022-05-06T11:47:04 [D] ExecutionPlan 399a1566-8625-48ec-b5ea-416b0c297064 planned >> running
2022-05-06T11:47:04 c3a1e0a7 [I] Finished POST /dynflow/tasks/launch with 200 (40.84 ms)
2022-05-06T11:47:04 [D] Step 399a1566-8625-48ec-b5ea-416b0c297064: 2 pending >> running in phase Run Proxy::Dynflow::Action::Batch
2022-05-06T11:47:04 c3a1e0a7 [D] ExecutionPlan e1d94446-bd51-4ee6-b54a-9234b7ca5b31 pending >> planning
2022-05-06T11:47:04 c3a1e0a7 [D] Step e1d94446-bd51-4ee6-b54a-9234b7ca5b31: 1 pending >> running in phase Plan Proxy::RemoteExecution::Ssh::Actions::RunScript
2022-05-06T11:47:04 c3a1e0a7 [D] Step e1d94446-bd51-4ee6-b54a-9234b7ca5b31: 2 pending >> running in phase Plan Proxy::RemoteExecution::Ssh::Actions::ScriptRunner
2022-05-06T11:47:04 c3a1e0a7 [D] Step e1d94446-bd51-4ee6-b54a-9234b7ca5b31: 5 pending >> running in phase Plan Proxy::Dynflow::Callback::Action
2022-05-06T11:47:04 c3a1e0a7 [D] Step e1d94446-bd51-4ee6-b54a-9234b7ca5b31: 5 running >> success in phase Plan Proxy::Dynflow::Callback::Action
2022-05-06T11:47:04 c3a1e0a7 [D] Step e1d94446-bd51-4ee6-b54a-9234b7ca5b31: 2 running >> success in phase Plan Proxy::RemoteExecution::Ssh::Actions::ScriptRunner
2022-05-06T11:47:04 c3a1e0a7 [D] Step e1d94446-bd51-4ee6-b54a-9234b7ca5b31: 1 running >> success in phase Plan Proxy::RemoteExecution::Ssh::Actions::RunScript
2022-05-06T11:47:04 c3a1e0a7 [D] ExecutionPlan e1d94446-bd51-4ee6-b54a-9234b7ca5b31 planning >> planned
2022-05-06T11:47:04 [D] close: 192.168.1.7:48418
2022-05-06T11:47:04 c3a1e0a7 [D] Step 399a1566-8625-48ec-b5ea-416b0c297064: 2 running >> suspended in phase Run Proxy::Dynflow::Action::Batch
2022-05-06T11:47:04 [D] ExecutionPlan e1d94446-bd51-4ee6-b54a-9234b7ca5b31 planned >> running
2022-05-06T11:47:04 [D] Step e1d94446-bd51-4ee6-b54a-9234b7ca5b31: 3 pending >> running in phase Run Proxy::RemoteExecution::Ssh::Actions::ScriptRunner
2022-05-06T11:47:04 c3a1e0a7 [D] Step e1d94446-bd51-4ee6-b54a-9234b7ca5b31: 3 running >> suspended in phase Run Proxy::RemoteExecution::Ssh::Actions::ScriptRunner
2022-05-06T11:47:04 [D] start runner 8b126053-696d-4a5a-9a2b-ff0544555a0d
2022-05-06T11:47:04 [D] copying script to /var/tmp/foreman-ssh-cmd-8b126053-696d-4a5a-9a2b-ff0544555a0d/script:
| whoami
2022-05-06T11:47:04 [D] debug1: Reading configuration data /etc/ssh/ssh_config
2022-05-06T11:47:04 [D] debug1: /etc/ssh/ssh_config line 62: Applying options for *
2022-05-06T11:47:04 [D] debug1: auto-mux: Trying existing master
2022-05-06T11:47:04 [D] debug1: Control socket “/var/tmp/foreman-proxy/foreman-ssh-cmd-8b126053-696d-4a5a-9a2b-ff0544555a0d/socket” does not exist
2022-05-06T11:47:04 [D] debug1: Executing proxy command: exec /usr/bin/sss_ssh_knownhostsproxy -p 22 karma1.rogue.home
2022-05-06T11:47:04 [D] debug1: permanently_drop_suid: 993
2022-05-06T11:47:04 [D] debug1: identity file /var/lib/foreman-proxy/ssh/id_rsa_foreman_proxy type 1
2022-05-06T11:47:04 [D] debug1: key_load_public: No such file or directory
2022-05-06T11:47:04 [D] debug1: identity file /var/lib/foreman-proxy/ssh/id_rsa_foreman_proxy-cert type -1
2022-05-06T11:47:04 [D] debug1: Enabling compatibility mode for protocol 2.0
2022-05-06T11:47:04 [D] debug1: Local version string SSH-2.0-OpenSSH_7.4
2022-05-06T11:47:04 [D] ssh_exchange_identification: Connection closed by remote host
2022-05-06T11:47:04 [E] error while initializing command RuntimeError Unable to create directory on remote system /var/tmp/foreman-ssh-cmd-8b126053-696d-4a5a-9a2b-ff0544555a0d: 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-8b126053-696d-4a5a-9a2b-ff0544555a0d/socket” does not exist
debug1: Executing proxy command: exec /usr/bin/sss_ssh_knownhostsproxy -p 22 karma1.rogue.home
debug1: permanently_drop_suid: 993
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.3/lib/smart_proxy_remote_execution_ssh/runners/script_runner.rb:387:in ensure_remote_directory' /opt/theforeman/tfm/root/usr/share/gems/gems/smart_proxy_remote_execution_ssh-0.5.3/lib/smart_proxy_remote_execution_ssh/runners/script_runner.rb:361:in upload_data’
/opt/theforeman/tfm/root/usr/share/gems/gems/smart_proxy_remote_execution_ssh-0.5.3/lib/smart_proxy_remote_execution_ssh/runners/script_runner.rb:357:in cp_script_to_remote' /opt/theforeman/tfm/root/usr/share/gems/gems/smart_proxy_remote_execution_ssh-0.5.3/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.3/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.7.0/lib/smart_proxy_dynflow/runner/dispatcher.rb:32:in start_runner’
/opt/theforeman/tfm/root/usr/share/gems/gems/dynflow-1.6.4/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.7.0/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.4/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.4/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-05-06T11:47:04 [E] Error initializing command - RuntimeError Unable to create directory on remote system /var/tmp/foreman-ssh-cmd-8b126053-696d-4a5a-9a2b-ff0544555a0d: 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-8b126053-696d-4a5a-9a2b-ff0544555a0d/socket” does not exist
debug1: Executing proxy command: exec /usr/bin/sss_ssh_knownhostsproxy -p 22 karma1.rogue.home
debug1: permanently_drop_suid: 993
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.3/lib/smart_proxy_remote_execution_ssh/runners/script_runner.rb:387:in ensure_remote_directory' /opt/theforeman/tfm/root/usr/share/gems/gems/smart_proxy_remote_execution_ssh-0.5.3/lib/smart_proxy_remote_execution_ssh/runners/script_runner.rb:361:in upload_data’
/opt/theforeman/tfm/root/usr/share/gems/gems/smart_proxy_remote_execution_ssh-0.5.3/lib/smart_proxy_remote_execution_ssh/runners/script_runner.rb:357:in cp_script_to_remote' /opt/theforeman/tfm/root/usr/share/gems/gems/smart_proxy_remote_execution_ssh-0.5.3/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.3/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.7.0/lib/smart_proxy_dynflow/runner/dispatcher.rb:32:in start_runner’
/opt/theforeman/tfm/root/usr/share/gems/gems/dynflow-1.6.4/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.7.0/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.4/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.4/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-05-06T11:47:04 [D] refresh runner 8b126053-696d-4a5a-9a2b-ff0544555a0d
2022-05-06T11:47:04 [D] refreshing runner
2022-05-06T11:47:04 [D] finish runner 8b126053-696d-4a5a-9a2b-ff0544555a0d
2022-05-06T11:47:04 [D] closing session for command [8b126053-696d-4a5a-9a2b-ff0544555a0d],0 actors left
2022-05-06T11:47:04 [D] terminate 8b126053-696d-4a5a-9a2b-ff0544555a0d
2022-05-06T11:47:04 [D] Step e1d94446-bd51-4ee6-b54a-9234b7ca5b31: 3 got event #Proxy::Dynflow::Runner::Update:0x0000000003260c98
2022-05-06T11:47:04 [D] Step e1d94446-bd51-4ee6-b54a-9234b7ca5b31: 3 suspended >> running in phase Run Proxy::RemoteExecution::Ssh::Actions::ScriptRunner
2022-05-06T11:47:04 c3a1e0a7 [D] Step e1d94446-bd51-4ee6-b54a-9234b7ca5b31: 3 running >> success in phase Run Proxy::RemoteExecution::Ssh::Actions::ScriptRunner
2022-05-06T11:47:04 [D] Step e1d94446-bd51-4ee6-b54a-9234b7ca5b31: 6 pending >> running in phase Run Proxy::Dynflow::Callback::Action
2022-05-06T11:47:04 [D] debug1: Reading configuration data /etc/ssh/ssh_config
2022-05-06T11:47:04 [D] debug1: /etc/ssh/ssh_config line 62: Applying options for *
2022-05-06T11:47:04 [D] debug1: auto-mux: Trying existing master
2022-05-06T11:47:04 [D] debug1: Control socket “/var/tmp/foreman-proxy/foreman-ssh-cmd-8b126053-696d-4a5a-9a2b-ff0544555a0d/socket” does not exist
2022-05-06T11:47:04 [D] debug1: Executing proxy command: exec /usr/bin/sss_ssh_knownhostsproxy -p 22 karma1.rogue.home
2022-05-06T11:47:04 [D] debug1: permanently_drop_suid: 993
2022-05-06T11:47:04 [D] debug1: identity file /var/lib/foreman-proxy/ssh/id_rsa_foreman_proxy type 1
2022-05-06T11:47:04 [D] debug1: key_load_public: No such file or directory
2022-05-06T11:47:04 [D] debug1: identity file /var/lib/foreman-proxy/ssh/id_rsa_foreman_proxy-cert type -1
2022-05-06T11:47:04 [D] debug1: Enabling compatibility mode for protocol 2.0
2022-05-06T11:47:04 [D] debug1: Local version string SSH-2.0-OpenSSH_7.4
2022-05-06T11:47:04 [D] ssh_exchange_identification: Connection closed by remote host
2022-05-06T11:47:04 [E] error while dispatching request to runner 8b126053-696d-4a5a-9a2b-ff0544555a0d:RuntimeError Control socket file does not exist:
/opt/theforeman/tfm/root/usr/share/gems/gems/smart_proxy_remote_execution_ssh-0.5.3/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.3/lib/smart_proxy_remote_execution_ssh/runners/script_runner.rb:215:in close’
/opt/theforeman/tfm/root/usr/share/gems/gems/smart_proxy_dynflow-0.7.0/lib/smart_proxy_dynflow/runner/dispatcher.rb:78:in start_termination' /opt/theforeman/tfm/root/usr/share/gems/gems/dynflow-1.6.4/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.7.0/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.4/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.4/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-05-06T11:47:04 c3a1e0a7 [D] Step e1d94446-bd51-4ee6-b54a-9234b7ca5b31: 6 running >> success in phase Run Proxy::Dynflow::Callback::Action 2022-05-06T11:47:04 [D] Step e1d94446-bd51-4ee6-b54a-9234b7ca5b31: 4 pending >> running in phase Finalize Proxy::RemoteExecution::Ssh::Actions::ScriptRunner 2022-05-06T11:47:04 c3a1e0a7 [E] Script execution failed 2022-05-06T11:47:04 c3a1e0a7 [D] Step e1d94446-bd51-4ee6-b54a-9234b7ca5b31: 4 running >> error in phase Finalize Proxy::RemoteExecution::Ssh::Actions::ScriptRunner 2022-05-06T11:47:04 [D] ExecutionPlan e1d94446-bd51-4ee6-b54a-9234b7ca5b31 running >> stopped 2022-05-06T11:47:07 [D] Executor heartbeat 2022-05-06T11:47:14 [D] Step 399a1566-8625-48ec-b5ea-416b0c297064: 2 got event Dynflow::Action::WithPollingSubPlans::Poll 2022-05-06T11:47:14 [D] Step 399a1566-8625-48ec-b5ea-416b0c297064: 2 suspended >> running in phase Run Proxy::Dynflow::Action::Batch 2022-05-06T11:47:14 c3a1e0a7 [E] <RuntimeError> A sub task failed /opt/theforeman/tfm/root/usr/share/gems/gems/dynflow-1.6.4/lib/dynflow/action/with_sub_plans.rb:231:in check_for_errors!’
/opt/theforeman/tfm/root/usr/share/gems/gems/dynflow-1.6.4/lib/dynflow/action/with_sub_plans.rb:137:in try_to_finish' /opt/theforeman/tfm/root/usr/share/gems/gems/dynflow-1.6.4/lib/dynflow/action/with_polling_sub_plans.rb:19:in poll’
/opt/theforeman/tfm/root/usr/share/gems/gems/dynflow-1.6.4/lib/dynflow/action/with_polling_sub_plans.rb:11:in run' /opt/theforeman/tfm/root/usr/share/gems/gems/dynflow-1.6.4/lib/dynflow/action.rb:582:in block (3 levels) in execute_run’
/opt/theforeman/tfm/root/usr/share/gems/gems/dynflow-1.6.4/lib/dynflow/middleware/stack.rb:27:in pass' /opt/theforeman/tfm/root/usr/share/gems/gems/dynflow-1.6.4/lib/dynflow/middleware.rb:19:in pass’
/opt/theforeman/tfm/root/usr/share/gems/gems/dynflow-1.6.4/lib/dynflow/action/progress.rb:31:in with_progress_calculation' /opt/theforeman/tfm/root/usr/share/gems/gems/dynflow-1.6.4/lib/dynflow/action/progress.rb:17:in run’
/opt/theforeman/tfm/root/usr/share/gems/gems/dynflow-1.6.4/lib/dynflow/middleware/stack.rb:23:in call' /opt/theforeman/tfm/root/usr/share/gems/gems/dynflow-1.6.4/lib/dynflow/middleware/stack.rb:27:in pass’
/opt/theforeman/tfm/root/usr/share/gems/gems/dynflow-1.6.4/lib/dynflow/middleware.rb:19:in pass' /opt/theforeman/tfm/root/usr/share/gems/gems/smart_proxy_dynflow-0.7.0/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.7.0/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.7.0/lib/smart_proxy_dynflow/middleware/keep_current_request_id.rb:15:in run’
/opt/theforeman/tfm/root/usr/share/gems/gems/dynflow-1.6.4/lib/dynflow/middleware/stack.rb:23:in call' /opt/theforeman/tfm/root/usr/share/gems/gems/dynflow-1.6.4/lib/dynflow/middleware/stack.rb:27:in pass’
/opt/theforeman/tfm/root/usr/share/gems/gems/dynflow-1.6.4/lib/dynflow/middleware.rb:19:in pass' /opt/theforeman/tfm/root/usr/share/gems/gems/dynflow-1.6.4/lib/dynflow/middleware.rb:32:in run’
/opt/theforeman/tfm/root/usr/share/gems/gems/dynflow-1.6.4/lib/dynflow/middleware/stack.rb:23:in call' /opt/theforeman/tfm/root/usr/share/gems/gems/dynflow-1.6.4/lib/dynflow/middleware/world.rb:31:in execute’
/opt/theforeman/tfm/root/usr/share/gems/gems/dynflow-1.6.4/lib/dynflow/action.rb:581:in block (2 levels) in execute_run' /opt/theforeman/tfm/root/usr/share/gems/gems/dynflow-1.6.4/lib/dynflow/action.rb:580:in catch’
/opt/theforeman/tfm/root/usr/share/gems/gems/dynflow-1.6.4/lib/dynflow/action.rb:580:in block in execute_run' /opt/theforeman/tfm/root/usr/share/gems/gems/dynflow-1.6.4/lib/dynflow/action.rb:483:in block in with_error_handling’
/opt/theforeman/tfm/root/usr/share/gems/gems/dynflow-1.6.4/lib/dynflow/action.rb:483:in catch' /opt/theforeman/tfm/root/usr/share/gems/gems/dynflow-1.6.4/lib/dynflow/action.rb:483:in with_error_handling’
/opt/theforeman/tfm/root/usr/share/gems/gems/dynflow-1.6.4/lib/dynflow/action.rb:575:in execute_run' /opt/theforeman/tfm/root/usr/share/gems/gems/dynflow-1.6.4/lib/dynflow/action.rb:296:in execute’
/opt/theforeman/tfm/root/usr/share/gems/gems/dynflow-1.6.4/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.4/lib/dynflow/execution_plan/steps/abstract.rb:167:in with_meta_calculation’
/opt/theforeman/tfm/root/usr/share/gems/gems/dynflow-1.6.4/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.4/lib/dynflow/execution_plan/steps/abstract_flow_step.rb:32:in open_action’
/opt/theforeman/tfm/root/usr/share/gems/gems/dynflow-1.6.4/lib/dynflow/execution_plan/steps/abstract_flow_step.rb:16:in execute' /opt/theforeman/tfm/root/usr/share/gems/gems/dynflow-1.6.4/lib/dynflow/director.rb:94:in execute’
/opt/theforeman/tfm/root/usr/share/gems/gems/dynflow-1.6.4/lib/dynflow/executors/parallel/worker.rb:15:in block in on_message' /opt/theforeman/tfm/root/usr/share/gems/gems/dynflow-1.6.4/lib/dynflow/executors.rb:18:in run_user_code’
/opt/theforeman/tfm/root/usr/share/gems/gems/dynflow-1.6.4/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.4/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.4/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-05-06T11:47:14 c3a1e0a7 [D] Step 399a1566-8625-48ec-b5ea-416b0c297064: 2 running >> error in phase Run Proxy::Dynflow::Action::Batch
2022-05-06T11:47:14 [D] ExecutionPlan 399a1566-8625-48ec-b5ea-416b0c297064 running >> stopped
2022-05-06T11:47:22 [D] Executor heartbeat
2022-05-06T11:47:23 [D] Starting allocated ip addresses cleanup pass…
2022-05-06T11:47:37 [D] Executor heartbeat
2022-05-06T11:47:52 [D] Executor heartbeat
2022-05-06T11:48:07 [D] Executor heartbeat
2022-05-06T11:48:22 [D] Executor heartbeat
2022-05-06T11:48:23 [D] Starting allocated ip addresses cleanup pass…
[root@foreman foreman-proxy]#

si_si87 · May 7, 2022, 8:58am

Thanks for the response
This is the output after debug on both /etc/foreman-proxy/settings.yml and /etc/foreman-proxy/settings.d/remote_execution_ssh.yml


   1:
Error initializing command: RuntimeError - Unable to create directory on remote system /var/tmp/foreman-ssh-cmd-f0bd25d2-fc57-43a0-b4d5-b378e9dd9a0e: exit code: 255
   2:
 debug1: Reading configuration data /etc/ssh/ssh_config
   3:
debug1: /etc/ssh/ssh_config line 62: Applying options for *
   4:
debug1: auto-mux: Trying existing master
   5:
debug1: Control socket "/var/tmp/foreman-proxy/foreman-ssh-cmd-f0bd25d2-fc57-43a0-b4d5-b378e9dd9a0e/socket" does not exist
   6:
debug1: Executing proxy command: exec /usr/bin/sss_ssh_knownhostsproxy -p 22 iomvlpptest01.ipa.sps.local
   7:
debug1: identity file /var/lib/foreman-proxy/ssh/id_rsa_foreman_proxy type 1
   8:
debug1: key_load_public: No such file or directory
   9:
debug1: identity file /var/lib/foreman-proxy/ssh/id_rsa_foreman_proxy-cert type -1
  10:
debug1: permanently_drop_suid: 993
  11:
debug1: Enabling compatibility mode for protocol 2.0
  12:
debug1: Local version string SSH-2.0-OpenSSH_7.4
  13:
ssh_exchange_identification: Connection closed by remote host
  14:
Exit status: EXCEPTION

si_si87 · May 7, 2022, 10:05am

I have got it working now, I edited /etc/ssh/ssh_config and commented ProxyCommand line, It was this line,

ProxyCommand /usr/bin/sss_ssh_knownhostsproxy -p %p %h

Not sure if this should be a permenat thing. Now ssh works as my user, root user don’t work yet but it’s a start.

gvde · May 7, 2022, 11:45am

You find a better solution here

si_si87 · May 7, 2022, 12:29pm

SO uncommenting proxycommand and
Put the ProxyCommand into a Match block in /etc/ssh/ssh_config works

Match exec true
ProxyCommand /usr/bin/sss_ssh_knownhostsproxy -p %p %h

jpurtell · May 7, 2022, 2:13pm

That was it!! Such a simple little fix, that would’ve taken a millennia to find.
Thanks Foreman Support and @aruzicka!! And my apologies once again for high jacking this post @si_si87.

This community ROCKS!!