Remote Execution task failing

patricbalar · September 15, 2021, 11:09am

Problem:
Remote execution task failing with foreman’s host itself, I confirmed that it’s working with my system that i registered with password but not with ssh keys

I can ssh -i /var/lib/foreman-proxy/ssh/id_rsa_foreman_proxy root@foreman.pride.improwised.dev sucessfully.

Expected outcome:
Remote Execution Task successfully executed as happen with password provided system

Foreman and Proxy versions:
Foreman version Version 3.0.0-rc2 © 2009-2021 Paul Kelly and Ohad Levy

Foreman and Proxy plugin versions:

Distribution and version:
ubuntu 20.04.3 LTS kernal 5.4.0-84-generic

Other relevant data:
Installed foreman with forklift just a week ago
with these Ansible vars

---
foreman_installer_additional_packages: [ansible]
foreman_repositories_version: 3.0
foreman_installer_admin_password: xxx

# There are two options, so a user can supply their own, and a playbook can
# specify theirs. For example, foreman-proxy needs "--foreman-proxy-foreman-url"
# so we put it in internal_use_only in a role or playbook.
# The foreman_installer_options is intended for the end user to override.
foreman_installer_options: [--enable-foreman-plugin-ansible,--enable-foreman-proxy-plugin-ansible,--enable-foreman-plugin-remote-execution,--enable-foreman-proxy-plugin-remote-execution-ssh,--enable-foreman-plugin-discovery]

command ansible-playbook -i hosts playbooks/foreman.yml -e @vars.yaml -v

/etc/smart_proxy_dynflow_core/settings.yml


---

### File managed with puppet ###

## Module: 'foreman_proxy'

:settings_directory: /etc/foreman-proxy/settings.d

# SSL Setup

# if enabled, all communication would be verified via SSL

# NOTE that both certificates need to be signed by the same CA in order for this to work

# see http://theforeman.org/projects/smart-proxy/wiki/SSL for more information

:ssl_ca_file: /etc/puppetlabs/puppet/ssl/certs/ca.pem

:ssl_certificate: /etc/puppetlabs/puppet/ssl/certs/foreman.pride.improwised.dev.pem

:ssl_private_key: /etc/puppetlabs/puppet/ssl/private_keys/foreman.pride.improwised.dev.pem

# Use this option only if you need to disable certain cipher suites.

# Note: we use the OpenSSL suite name, such as "RC4-MD5".

# The complete list of cipher suite names can be found at:

# https://www.openssl.org/docs/manmaster/man1/ciphers.html#CIPHER-SUITE-NAMES

#:ssl_disabled_ciphers: [CIPHER-SUITE-1, CIPHER-SUITE-2]

# Use this option only if you need to strictly specify TLS versions to be

# disabled. SSLv3 and TLS v1.0 are always disabled and cannot be configured.

# Specify versions like: '1.1', or '1.2'

#:tls_disabled_versions: []

# the hosts which the proxy accepts connections from

# commenting the following lines would mean every verified SSL connection allowed

:trusted_hosts:

- foreman.pride.improwised.dev

# Endpoint for reverse communication

:foreman_url: https://foreman.pride.improwised.dev

# SSL settings for client authentication against Foreman. If undefined, the values

# from general SSL options are used instead. Mainly useful when Foreman uses

# different certificates for its web UI and for smart-proxy requests.

#:foreman_ssl_ca: ssl/certs/ca.pem

#:foreman_ssl_cert: ssl/certs/fqdn.pem

#:foreman_ssl_key: ssl/private_keys/fqdn.pem

# by default smart_proxy runs in the foreground. To enable running as a daemon, uncomment 'daemon' setting

:daemon: true

# Only used when 'daemon' is set to true.

# Uncomment and modify if you want to change the default pid file '/var/run/foreman-proxy/foreman-proxy.pid'

#:daemon_pid: /var/run/foreman-proxy/foreman-proxy.pid

# host and ports configuration

# Host or IP to bind ports to (e.g. *, localhost, 0.0.0.0, ::, 192.168.1.20)

:bind_host: '*'

# http is disabled by default. To enable, uncomment 'http_port' setting

# https is enabled if certificate, CA certificate, and private key are present in locations specifed by

# ssl_certificate, ssl_ca_file, and ssl_private_key correspondingly

# default values for https_port is 8443

:https_port: 8443

#:http_port: 8000

# Log configuration

# Uncomment and modify if you want to change the location of the log file or use STDOUT or SYSLOG values

:log_file: /var/log/foreman-proxy/proxy.log

# Uncomment and modify if you want to change the log level

# WARN, DEBUG, ERROR, FATAL, INFO, UNKNOWN

:log_level: DEBUG

# The maximum size of a log file before it's rolled (in MiB)

#:file_rolling_size: 100

# The maximum age of a log file before it's rolled (in seconds). Also accepts 'daily', 'weekly', or 'monthly'.

#:file_rolling_age: weekly

# Number of log files to keep

#:file_rolling_keep: 6

# Logging pattern for file-based loging

#:file_logging_pattern: '%d %.8X{request} [%.1l] %m'

# Logging pattern for syslog or journal loging

#:system_logging_pattern: '%.8X{request} [%.1l] %m'

# Log buffer size and extra buffer size (for errors). Defaults to 3000 messages in total,

# which is about 500 kB request.

:log_buffer: 2000

:log_buffer_errors: 1000

/etc/foreman-proxy/settings.d/remote_execution_ssh.yml


---

:enabled: https

:ssh_identity_key_file: /var/lib/foreman-proxy/ssh/id_rsa_foreman_proxy

:local_working_dir: /var/tmp

:remote_working_dir: /var/tmp

:kerberos_auth: false

# Whether to run remote execution jobs asynchronously

:async_ssh: false

/etc/foreman/settings.yaml


---

### File managed with puppet ###

## Module: 'foreman'

:unattended: true

:require_ssl: true

# The following values are used for providing default settings during db migrate

:oauth_active: true

:oauth_map_users: false

:oauth_consumer_key: xxxx

:oauth_consumer_secret: xxxx

# Websockets

:websockets_encrypt: true

:websockets_ssl_key: /etc/puppetlabs/puppet/ssl/private_keys/foreman.pride.improwised.dev.pem

:websockets_ssl_cert: /etc/puppetlabs/puppet/ssl/certs/foreman.pride.improwised.dev.pem

# SSL-settings

:ssl_certificate: /etc/puppetlabs/puppet/ssl/certs/foreman.pride.improwised.dev.pem

:ssl_ca_file: /etc/puppetlabs/puppet/ssl/certs/ca.pem

:ssl_priv_key: /etc/puppetlabs/puppet/ssl/private_keys/foreman.pride.improwised.dev.pem

# HSTS setting

:hsts_enabled: true

# Log settings for the current environment can be adjusted by adding them

# here. For example, if you want to increase the log level.

:logging:

:level: debug

:production:

:type: file

:layout: multiline_request_pattern

# Individual logging types can be toggled on/off here

:loggers:

# Foreman telemetry has three destinations: prometheus, statsd and rails log.

:telemetry:

# prefix for all metrics

:prefix: 'fm_rails'

# prometheus endpoint is at /metrics

# warning: ruby client library currently does not supprt multi-process web servers

:prometheus:

:enabled: false

# works with statsd_exporter too, use the rake task to generate config

:statsd:

:enabled: false

# IP and port (do not use DNS)

:host: '127.0.0.1:8125'

# one of 'statsd', 'statsite' or 'datadog'

:protocol: 'statsd'

# Rails logs end up in logger named 'telemetry' when enabled

:logger:

:enabled: false

# logging level as in Logger::LEVEL

:level: 'DEBUG'

:dynflow:

:redis_url: redis://localhost:6379/6

:rails_cache_store:

:type: file

# Configure reverse proxy headers

:ssl_client_dn_env: HTTP_SSL_CLIENT_S_DN

:ssl_client_verify_env: HTTP_SSL_CLIENT_VERIFY

:ssl_client_cert_env: HTTP_SSL_CLIENT_CERT

failed task logs

2021-09-15T08:16:18  [D] Executor heartbeat
2021-09-15T08:16:33  [D] Executor heartbeat
2021-09-15T08:16:41  [D] accept: 10.10.0.5:34388
2021-09-15T08:16:41  [D] Rack::Handler::WEBrick is invoked.
2021-09-15T08:16:41 1ea0e922 [I] Started GET /dynflow/tasks/count state=running
2021-09-15T08:16:41 1ea0e922 [D] verifying remote client 10.10.0.5 against trusted_hosts ["foreman.pride.improwised.dev"]
2021-09-15T08:16:41 1ea0e922 [I] Finished GET /dynflow/tasks/count with 200 (1.59 ms)
2021-09-15T08:16:41  [D] close: 10.10.0.5:34388
2021-09-15T08:16:41  [D] accept: 10.10.0.5:34390
2021-09-15T08:16:41  [D] Rack::Handler::WEBrick is invoked.
2021-09-15T08:16:41 1ea0e922 [I] Started GET /version 
2021-09-15T08:16:41 1ea0e922 [I] Finished GET /version with 200 (0.83 ms)
2021-09-15T08:16:41  [D] close: 10.10.0.5:34390
2021-09-15T08:16:41  [D] accept: 10.10.0.5:34392
2021-09-15T08:16:41  [D] Rack::Handler::WEBrick is invoked.
2021-09-15T08:16:41 1ea0e922 [I] Started POST /dynflow/tasks/launch 
2021-09-15T08:16:41 1ea0e922 [D] verifying remote client 10.10.0.5 against trusted_hosts ["foreman.pride.improwised.dev"]
2021-09-15T08:16:41 1ea0e922 [D] ExecutionPlan 4db5c44d-f39c-4a04-a02a-da1e7eefd9ae      pending >>  planning
2021-09-15T08:16:41 1ea0e922 [D]          Step 4db5c44d-f39c-4a04-a02a-da1e7eefd9ae: 1   pending >>   running in phase     Plan Proxy::Dynflow::Action::Batch
2021-09-15T08:16:41 1ea0e922 [D] ExecutionPlan 72451b1d-7b60-484b-8684-dd576fa0bbed      pending >>  planning
2021-09-15T08:16:41 1ea0e922 [D]          Step 72451b1d-7b60-484b-8684-dd576fa0bbed: 1   pending >>   running in phase     Plan Proxy::RemoteExecution::Ssh::Actions::RunScript
2021-09-15T08:16:41 1ea0e922 [D]          Step 72451b1d-7b60-484b-8684-dd576fa0bbed: 4   pending >>   running in phase     Plan Proxy::Dynflow::Callback::Action
2021-09-15T08:16:41 1ea0e922 [D]          Step 72451b1d-7b60-484b-8684-dd576fa0bbed: 4   running >>   success in phase     Plan Proxy::Dynflow::Callback::Action
2021-09-15T08:16:41 1ea0e922 [D]          Step 72451b1d-7b60-484b-8684-dd576fa0bbed: 1   running >>   success in phase     Plan Proxy::RemoteExecution::Ssh::Actions::RunScript
2021-09-15T08:16:41 1ea0e922 [D] ExecutionPlan 72451b1d-7b60-484b-8684-dd576fa0bbed     planning >>   planned
2021-09-15T08:16:41  [D] ExecutionPlan 72451b1d-7b60-484b-8684-dd576fa0bbed      planned >>   running
2021-09-15T08:16:41 1ea0e922 [D]          Step 4db5c44d-f39c-4a04-a02a-da1e7eefd9ae: 1   running >>   success in phase     Plan Proxy::Dynflow::Action::Batch
2021-09-15T08:16:41 1ea0e922 [D] ExecutionPlan 4db5c44d-f39c-4a04-a02a-da1e7eefd9ae     planning >>   planned
2021-09-15T08:16:41  [D]          Step 72451b1d-7b60-484b-8684-dd576fa0bbed: 2   pending >>   running in phase      Run Proxy::RemoteExecution::Ssh::Actions::RunScript
2021-09-15T08:16:41 1ea0e922 [D]          Step 72451b1d-7b60-484b-8684-dd576fa0bbed: 2   running >> suspended in phase      Run Proxy::RemoteExecution::Ssh::Actions::RunScript
2021-09-15T08:16:41  [D] start runner 7fa7f22c-c828-4d8a-844c-3995fa6ac9e6
2021-09-15T08:16:41  [D] copying script to /var/tmp/foreman-ssh-cmd-7fa7f22c-c828-4d8a-844c-3995fa6ac9e6/script:
  | sh -c 'ls /'
2021-09-15T08:16:41  [D] opening session to root@foreman.pride.improwised.dev
2021-09-15T08:16:41 1ea0e922 [I] Finished POST /dynflow/tasks/launch with 200 (64.29 ms)
2021-09-15T08:16:41  [D] ExecutionPlan 4db5c44d-f39c-4a04-a02a-da1e7eefd9ae      planned >>   running
2021-09-15T08:16:41  [D] close: 10.10.0.5:34392
2021-09-15T08:16:41  [D]          Step 4db5c44d-f39c-4a04-a02a-da1e7eefd9ae: 2   pending >>   running in phase      Run Proxy::Dynflow::Action::Batch
2021-09-15T08:16:41 1ea0e922 [D]          Step 4db5c44d-f39c-4a04-a02a-da1e7eefd9ae: 2   running >> suspended in phase      Run Proxy::Dynflow::Action::Batch
2021-09-15T08:16:42  [E] error while initalizing command Net::SSH::AuthenticationFailed Authentication failed for user root@foreman.pride.improwised.dev:
 /usr/lib/ruby/vendor_ruby/net/ssh.rb:263:in `start'
/usr/lib/ruby/vendor_ruby/smart_proxy_remote_execution_ssh/runners/script_runner.rb:263:in `session'
/usr/lib/ruby/vendor_ruby/smart_proxy_remote_execution_ssh/runners/script_runner.rb:334:in `run_sync'
/usr/lib/ruby/vendor_ruby/smart_proxy_remote_execution_ssh/runners/script_runner.rb:425:in `ensure_remote_directory'
/usr/lib/ruby/vendor_ruby/smart_proxy_remote_execution_ssh/runners/script_runner.rb:401:in `upload_data'
/usr/lib/ruby/vendor_ruby/smart_proxy_remote_execution_ssh/runners/script_runner.rb:397:in `cp_script_to_remote'
/usr/lib/ruby/vendor_ruby/smart_proxy_remote_execution_ssh/runners/script_runner.rb:163:in `prepare_start'
/usr/lib/ruby/vendor_ruby/smart_proxy_remote_execution_ssh/runners/script_runner.rb:149:in `start'
/usr/lib/ruby/vendor_ruby/smart_proxy_dynflow/runner/dispatcher.rb:32:in `start_runner'
/usr/lib/ruby/vendor_ruby/dynflow/actor.rb:13:in `on_message'
/usr/lib/ruby/vendor_ruby/concurrent/actor/context.rb:46:in `on_envelope'
/usr/lib/ruby/vendor_ruby/smart_proxy_dynflow/runner/dispatcher.rb:24:in `on_envelope'
/usr/lib/ruby/vendor_ruby/concurrent/actor/behaviour/executes_context.rb:7:in `on_envelope'
/usr/lib/ruby/vendor_ruby/concurrent/actor/behaviour/abstract.rb:25:in `pass'
/usr/lib/ruby/vendor_ruby/dynflow/actor.rb:122:in `on_envelope'
/usr/lib/ruby/vendor_ruby/concurrent/actor/behaviour/abstract.rb:25:in `pass'
/usr/lib/ruby/vendor_ruby/concurrent/actor/behaviour/awaits.rb:15:in `on_envelope'
/usr/lib/ruby/vendor_ruby/concurrent/actor/behaviour/abstract.rb:25:in `pass'
/usr/lib/ruby/vendor_ruby/concurrent/actor/behaviour/sets_results.rb:14:in `on_envelope'
/usr/lib/ruby/vendor_ruby/dynflow/actor.rb:56:in `on_envelope'
/usr/lib/ruby/vendor_ruby/concurrent/actor/behaviour/abstract.rb:25:in `pass'
/usr/lib/ruby/vendor_ruby/concurrent/actor/behaviour/buffer.rb:38:in `process_envelope'
/usr/lib/ruby/vendor_ruby/concurrent/actor/behaviour/buffer.rb:31:in `process_envelopes?'
/usr/lib/ruby/vendor_ruby/concurrent/actor/behaviour/buffer.rb:20:in `on_envelope'
/usr/lib/ruby/vendor_ruby/concurrent/actor/behaviour/abstract.rb:25:in `pass'
/usr/lib/ruby/vendor_ruby/concurrent/actor/behaviour/termination.rb:55:in `on_envelope'
/usr/lib/ruby/vendor_ruby/concurrent/actor/behaviour/abstract.rb:25:in `pass'
/usr/lib/ruby/vendor_ruby/concurrent/actor/behaviour/removes_child.rb:10:in `on_envelope'
/usr/lib/ruby/vendor_ruby/concurrent/actor/behaviour/abstract.rb:25:in `pass'
/usr/lib/ruby/vendor_ruby/concurrent/actor/behaviour/sets_results.rb:14:in `on_envelope'
/usr/lib/ruby/vendor_ruby/concurrent/actor/core.rb:162:in `process_envelope'
/usr/lib/ruby/vendor_ruby/concurrent/actor/core.rb:96:in `block in on_envelope'
/usr/lib/ruby/vendor_ruby/concurrent/actor/core.rb:119:in `block (2 levels) in schedule_execution'
/usr/lib/ruby/vendor_ruby/concurrent/synchronization/mutex_lockable_object.rb:41:in `block in synchronize'
/usr/lib/ruby/vendor_ruby/concurrent/synchronization/mutex_lockable_object.rb:41:in `synchronize'
/usr/lib/ruby/vendor_ruby/concurrent/synchronization/mutex_lockable_object.rb:41:in `synchronize'
/usr/lib/ruby/vendor_ruby/concurrent/actor/core.rb:116:in `block in schedule_execution'
/usr/lib/ruby/vendor_ruby/concurrent/executor/serialized_execution.rb:18:in `call'
/usr/lib/ruby/vendor_ruby/concurrent/executor/serialized_execution.rb:96:in `work'
/usr/lib/ruby/vendor_ruby/concurrent/executor/serialized_execution.rb:77:in `block in call_job'
/usr/lib/ruby/vendor_ruby/concurrent/executor/ruby_thread_pool_executor.rb:353:in `run_task'
/usr/lib/ruby/vendor_ruby/concurrent/executor/ruby_thread_pool_executor.rb:342:in `block (3 levels) in create_worker'
/usr/lib/ruby/vendor_ruby/concurrent/executor/ruby_thread_pool_executor.rb:325:in `loop'
/usr/lib/ruby/vendor_ruby/concurrent/executor/ruby_thread_pool_executor.rb:325:in `block (2 levels) in create_worker'
/usr/lib/ruby/vendor_ruby/concurrent/executor/ruby_thread_pool_executor.rb:324:in `catch'
/usr/lib/ruby/vendor_ruby/concurrent/executor/ruby_thread_pool_executor.rb:324:in `block in create_worker'
/usr/lib/ruby/vendor_ruby/logging/diagnostic_context.rb:474:in `block in create_with_logging_context'
2021-09-15T08:16:42  [E] Error initializing command - Net::SSH::AuthenticationFailed Authentication failed for user root@foreman.pride.improwised.dev:
/usr/lib/ruby/vendor_ruby/net/ssh.rb:263:in `start'
/usr/lib/ruby/vendor_ruby/smart_proxy_remote_execution_ssh/runners/script_runner.rb:263:in `session'
/usr/lib/ruby/vendor_ruby/smart_proxy_remote_execution_ssh/runners/script_runner.rb:334:in `run_sync'
/usr/lib/ruby/vendor_ruby/smart_proxy_remote_execution_ssh/runners/script_runner.rb:425:in `ensure_remote_directory'
/usr/lib/ruby/vendor_ruby/smart_proxy_remote_execution_ssh/runners/script_runner.rb:401:in `upload_data'
/usr/lib/ruby/vendor_ruby/smart_proxy_remote_execution_ssh/runners/script_runner.rb:397:in `cp_script_to_remote'
/usr/lib/ruby/vendor_ruby/smart_proxy_remote_execution_ssh/runners/script_runner.rb:163:in `prepare_start'
/usr/lib/ruby/vendor_ruby/smart_proxy_remote_execution_ssh/runners/script_runner.rb:149:in `start'
/usr/lib/ruby/vendor_ruby/smart_proxy_dynflow/runner/dispatcher.rb:32:in `start_runner'
/usr/lib/ruby/vendor_ruby/dynflow/actor.rb:13:in `on_message'
/usr/lib/ruby/vendor_ruby/concurrent/actor/context.rb:46:in `on_envelope'
/usr/lib/ruby/vendor_ruby/smart_proxy_dynflow/runner/dispatcher.rb:24:in `on_envelope'
/usr/lib/ruby/vendor_ruby/concurrent/actor/behaviour/executes_context.rb:7:in `on_envelope'
/usr/lib/ruby/vendor_ruby/concurrent/actor/behaviour/abstract.rb:25:in `pass'
/usr/lib/ruby/vendor_ruby/dynflow/actor.rb:122:in `on_envelope'
/usr/lib/ruby/vendor_ruby/concurrent/actor/behaviour/abstract.rb:25:in `pass'
/usr/lib/ruby/vendor_ruby/concurrent/actor/behaviour/awaits.rb:15:in `on_envelope'
/usr/lib/ruby/vendor_ruby/concurrent/actor/behaviour/abstract.rb:25:in `pass'
/usr/lib/ruby/vendor_ruby/concurrent/actor/behaviour/sets_results.rb:14:in `on_envelope'
/usr/lib/ruby/vendor_ruby/dynflow/actor.rb:56:in `on_envelope'
/usr/lib/ruby/vendor_ruby/concurrent/actor/behaviour/abstract.rb:25:in `pass'
/usr/lib/ruby/vendor_ruby/concurrent/actor/behaviour/buffer.rb:38:in `process_envelope'
/usr/lib/ruby/vendor_ruby/concurrent/actor/behaviour/buffer.rb:31:in `process_envelopes?'
/usr/lib/ruby/vendor_ruby/concurrent/actor/behaviour/buffer.rb:20:in `on_envelope'
/usr/lib/ruby/vendor_ruby/concurrent/actor/behaviour/abstract.rb:25:in `pass'
/usr/lib/ruby/vendor_ruby/concurrent/actor/behaviour/termination.rb:55:in `on_envelope'
/usr/lib/ruby/vendor_ruby/concurrent/actor/behaviour/abstract.rb:25:in `pass'
/usr/lib/ruby/vendor_ruby/concurrent/actor/behaviour/removes_child.rb:10:in `on_envelope'
/usr/lib/ruby/vendor_ruby/concurrent/actor/behaviour/abstract.rb:25:in `pass'
/usr/lib/ruby/vendor_ruby/concurrent/actor/behaviour/sets_results.rb:14:in `on_envelope'
/usr/lib/ruby/vendor_ruby/concurrent/actor/core.rb:162:in `process_envelope'
/usr/lib/ruby/vendor_ruby/concurrent/actor/core.rb:96:in `block in on_envelope'
/usr/lib/ruby/vendor_ruby/concurrent/actor/core.rb:119:in `block (2 levels) in schedule_execution'
/usr/lib/ruby/vendor_ruby/concurrent/synchronization/mutex_lockable_object.rb:41:in `block in synchronize'
/usr/lib/ruby/vendor_ruby/concurrent/synchronization/mutex_lockable_object.rb:41:in `synchronize'
/usr/lib/ruby/vendor_ruby/concurrent/synchronization/mutex_lockable_object.rb:41:in `synchronize'
/usr/lib/ruby/vendor_ruby/concurrent/actor/core.rb:116:in `block in schedule_execution'
/usr/lib/ruby/vendor_ruby/concurrent/executor/serialized_execution.rb:18:in `call'
/usr/lib/ruby/vendor_ruby/concurrent/executor/serialized_execution.rb:96:in `work'
/usr/lib/ruby/vendor_ruby/concurrent/executor/serialized_execution.rb:77:in `block in call_job'
/usr/lib/ruby/vendor_ruby/concurrent/executor/ruby_thread_pool_executor.rb:353:in `run_task'
/usr/lib/ruby/vendor_ruby/concurrent/executor/ruby_thread_pool_executor.rb:342:in `block (3 levels) in create_worker'
/usr/lib/ruby/vendor_ruby/concurrent/executor/ruby_thread_pool_executor.rb:325:in `loop'
/usr/lib/ruby/vendor_ruby/concurrent/executor/ruby_thread_pool_executor.rb:325:in `block (2 levels) in create_worker'
/usr/lib/ruby/vendor_ruby/concurrent/executor/ruby_thread_pool_executor.rb:324:in `catch'
/usr/lib/ruby/vendor_ruby/concurrent/executor/ruby_thread_pool_executor.rb:324:in `block in create_worker'
/usr/lib/ruby/vendor_ruby/logging/diagnostic_context.rb:474:in `block in create_with_logging_context'
2021-09-15T08:16:42  [D] refresh runner 7fa7f22c-c828-4d8a-844c-3995fa6ac9e6
2021-09-15T08:16:42  [D] refreshing runner
2021-09-15T08:16:42  [D] finish runner 7fa7f22c-c828-4d8a-844c-3995fa6ac9e6
2021-09-15T08:16:42  [D] closing session for command [7fa7f22c-c828-4d8a-844c-3995fa6ac9e6],0 actors left 
2021-09-15T08:16:42  [D] terminate 7fa7f22c-c828-4d8a-844c-3995fa6ac9e6
2021-09-15T08:16:42  [D]          Step 72451b1d-7b60-484b-8684-dd576fa0bbed: 2 got event #<Proxy::Dynflow::Runner::Update:0x000055c2a7661768>
2021-09-15T08:16:42  [D]          Step 72451b1d-7b60-484b-8684-dd576fa0bbed: 2 suspended >>   running in phase      Run Proxy::RemoteExecution::Ssh::Actions::RunScript
2021-09-15T08:16:42 1ea0e922 [D]          Step 72451b1d-7b60-484b-8684-dd576fa0bbed: 2   running >>   success in phase      Run Proxy::RemoteExecution::Ssh::Actions::RunScript
2021-09-15T08:16:42  [D]          Step 72451b1d-7b60-484b-8684-dd576fa0bbed: 5   pending >>   running in phase      Run Proxy::Dynflow::Callback::Action
2021-09-15T08:16:42 1ea0e922 [D]          Step 72451b1d-7b60-484b-8684-dd576fa0bbed: 5   running >>   success in phase      Run Proxy::Dynflow::Callback::Action
2021-09-15T08:16:42  [D]          Step 72451b1d-7b60-484b-8684-dd576fa0bbed: 3   pending >>   running in phase Finalize Proxy::RemoteExecution::Ssh::Actions::RunScript
2021-09-15T08:16:42 1ea0e922 [E] Script execution failed
2021-09-15T08:16:42 1ea0e922 [D]          Step 72451b1d-7b60-484b-8684-dd576fa0bbed: 3   running >>     error in phase Finalize Proxy::RemoteExecution::Ssh::Actions::RunScript
2021-09-15T08:16:42  [D] ExecutionPlan 72451b1d-7b60-484b-8684-dd576fa0bbed      running >>   stopped
2021-09-15T08:16:48  [D] Executor heartbeat
2021-09-15T08:16:51  [D]          Step 4db5c44d-f39c-4a04-a02a-da1e7eefd9ae: 2 got event Dynflow::Action::WithPollingSubPlans::Poll
2021-09-15T08:16:51  [D]          Step 4db5c44d-f39c-4a04-a02a-da1e7eefd9ae: 2 suspended >>   running in phase      Run Proxy::Dynflow::Action::Batch
2021-09-15T08:16:51 1ea0e922 [E] <RuntimeError> A sub task failed
	/usr/lib/ruby/vendor_ruby/dynflow/action/with_sub_plans.rb:231:in `check_for_errors!'
	/usr/lib/ruby/vendor_ruby/dynflow/action/with_sub_plans.rb:137:in `try_to_finish'
	/usr/lib/ruby/vendor_ruby/dynflow/action/with_polling_sub_plans.rb:19:in `poll'
	/usr/lib/ruby/vendor_ruby/dynflow/action/with_polling_sub_plans.rb:11:in `run'
	/usr/lib/ruby/vendor_ruby/dynflow/action.rb:572:in `block (3 levels) in execute_run'
	/usr/lib/ruby/vendor_ruby/dynflow/middleware/stack.rb:27:in `pass'
	/usr/lib/ruby/vendor_ruby/dynflow/middleware.rb:19:in `pass'
	/usr/lib/ruby/vendor_ruby/dynflow/action/progress.rb:31:in `with_progress_calculation'
	/usr/lib/ruby/vendor_ruby/dynflow/action/progress.rb:17:in `run'
	/usr/lib/ruby/vendor_ruby/dynflow/middleware/stack.rb:23:in `call'
	/usr/lib/ruby/vendor_ruby/dynflow/middleware/stack.rb:27:in `pass'
	/usr/lib/ruby/vendor_ruby/dynflow/middleware.rb:19:in `pass'
	/usr/lib/ruby/vendor_ruby/smart_proxy_dynflow/middleware/keep_current_request_id.rb:15:in `block in run'
	/usr/lib/ruby/vendor_ruby/smart_proxy_dynflow/middleware/keep_current_request_id.rb:49:in `restore_current_request_id'
	/usr/lib/ruby/vendor_ruby/smart_proxy_dynflow/middleware/keep_current_request_id.rb:15:in `run'
	/usr/lib/ruby/vendor_ruby/dynflow/middleware/stack.rb:23:in `call'
	/usr/lib/ruby/vendor_ruby/dynflow/middleware/stack.rb:27:in `pass'
	/usr/lib/ruby/vendor_ruby/dynflow/middleware.rb:19:in `pass'
	/usr/lib/ruby/vendor_ruby/dynflow/middleware.rb:32:in `run'
	/usr/lib/ruby/vendor_ruby/dynflow/middleware/stack.rb:23:in `call'
	/usr/lib/ruby/vendor_ruby/dynflow/middleware/world.rb:31:in `execute'
	/usr/lib/ruby/vendor_ruby/dynflow/action.rb:571:in `block (2 levels) in execute_run'
	/usr/lib/ruby/vendor_ruby/dynflow/action.rb:570:in `catch'
	/usr/lib/ruby/vendor_ruby/dynflow/action.rb:570:in `block in execute_run'
	/usr/lib/ruby/vendor_ruby/dynflow/action.rb:473:in `block in with_error_handling'
	/usr/lib/ruby/vendor_ruby/dynflow/action.rb:473:in `catch'
	/usr/lib/ruby/vendor_ruby/dynflow/action.rb:473:in `with_error_handling'
	/usr/lib/ruby/vendor_ruby/dynflow/action.rb:565:in `execute_run'
	/usr/lib/ruby/vendor_ruby/dynflow/action.rb:286:in `execute'
	/usr/lib/ruby/vendor_ruby/dynflow/execution_plan/steps/abstract_flow_step.rb:18:in `block (2 levels) in execute'
	/usr/lib/ruby/vendor_ruby/dynflow/execution_plan/steps/abstract.rb:167:in `with_meta_calculation'
	/usr/lib/ruby/vendor_ruby/dynflow/execution_plan/steps/abstract_flow_step.rb:17:in `block in execute'
	/usr/lib/ruby/vendor_ruby/dynflow/execution_plan/steps/abstract_flow_step.rb:32:in `open_action'
	/usr/lib/ruby/vendor_ruby/dynflow/execution_plan/steps/abstract_flow_step.rb:16:in `execute'
	/usr/lib/ruby/vendor_ruby/dynflow/director.rb:94:in `execute'
	/usr/lib/ruby/vendor_ruby/dynflow/executors/parallel/worker.rb:15:in `block in on_message'
	/usr/lib/ruby/vendor_ruby/dynflow/executors.rb:18:in `run_user_code'
	/usr/lib/ruby/vendor_ruby/dynflow/executors/parallel/worker.rb:14:in `on_message'
	/usr/lib/ruby/vendor_ruby/concurrent/actor/context.rb:46:in `on_envelope'
	/usr/lib/ruby/vendor_ruby/concurrent/actor/behaviour/executes_context.rb:7:in `on_envelope'
	/usr/lib/ruby/vendor_ruby/concurrent/actor/behaviour/abstract.rb:25:in `pass'
	/usr/lib/ruby/vendor_ruby/dynflow/actor.rb:122:in `on_envelope'
	/usr/lib/ruby/vendor_ruby/concurrent/actor/behaviour/abstract.rb:25:in `pass'
	/usr/lib/ruby/vendor_ruby/concurrent/actor/behaviour/awaits.rb:15:in `on_envelope'
	/usr/lib/ruby/vendor_ruby/concurrent/actor/behaviour/abstract.rb:25:in `pass'
	/usr/lib/ruby/vendor_ruby/concurrent/actor/behaviour/sets_results.rb:14:in `on_envelope'
	/usr/lib/ruby/vendor_ruby/dynflow/actor.rb:56:in `on_envelope'
	/usr/lib/ruby/vendor_ruby/concurrent/actor/behaviour/abstract.rb:25:in `pass'
	/usr/lib/ruby/vendor_ruby/concurrent/actor/behaviour/buffer.rb:38:in `process_envelope'
	/usr/lib/ruby/vendor_ruby/concurrent/actor/behaviour/buffer.rb:31:in `process_envelopes?'
	/usr/lib/ruby/vendor_ruby/concurrent/actor/behaviour/buffer.rb:20:in `on_envelope'
	/usr/lib/ruby/vendor_ruby/concurrent/actor/behaviour/abstract.rb:25:in `pass'
	/usr/lib/ruby/vendor_ruby/concurrent/actor/behaviour/termination.rb:55:in `on_envelope'
	/usr/lib/ruby/vendor_ruby/concurrent/actor/behaviour/abstract.rb:25:in `pass'
	/usr/lib/ruby/vendor_ruby/concurrent/actor/behaviour/removes_child.rb:10:in `on_envelope'
	/usr/lib/ruby/vendor_ruby/concurrent/actor/behaviour/abstract.rb:25:in `pass'
	/usr/lib/ruby/vendor_ruby/concurrent/actor/behaviour/sets_results.rb:14:in `on_envelope'
	/usr/lib/ruby/vendor_ruby/concurrent/actor/core.rb:162:in `process_envelope'
	/usr/lib/ruby/vendor_ruby/concurrent/actor/core.rb:96:in `block in on_envelope'
	/usr/lib/ruby/vendor_ruby/concurrent/actor/core.rb:119:in `block (2 levels) in schedule_execution'
	/usr/lib/ruby/vendor_ruby/concurrent/synchronization/mutex_lockable_object.rb:41:in `block in synchronize'
	/usr/lib/ruby/vendor_ruby/concurrent/synchronization/mutex_lockable_object.rb:41:in `synchronize'
	/usr/lib/ruby/vendor_ruby/concurrent/synchronization/mutex_lockable_object.rb:41:in `synchronize'
	/usr/lib/ruby/vendor_ruby/concurrent/actor/core.rb:116:in `block in schedule_execution'
	/usr/lib/ruby/vendor_ruby/concurrent/executor/serialized_execution.rb:18:in `call'
	/usr/lib/ruby/vendor_ruby/concurrent/executor/serialized_execution.rb:96:in `work'
	/usr/lib/ruby/vendor_ruby/concurrent/executor/serialized_execution.rb:77:in `block in call_job'
	/usr/lib/ruby/vendor_ruby/concurrent/executor/ruby_thread_pool_executor.rb:353:in `run_task'
	/usr/lib/ruby/vendor_ruby/concurrent/executor/ruby_thread_pool_executor.rb:342:in `block (3 levels) in create_worker'
	/usr/lib/ruby/vendor_ruby/concurrent/executor/ruby_thread_pool_executor.rb:325:in `loop'
	/usr/lib/ruby/vendor_ruby/concurrent/executor/ruby_thread_pool_executor.rb:325:in `block (2 levels) in create_worker'
	/usr/lib/ruby/vendor_ruby/concurrent/executor/ruby_thread_pool_executor.rb:324:in `catch'
	/usr/lib/ruby/vendor_ruby/concurrent/executor/ruby_thread_pool_executor.rb:324:in `block in create_worker'
	/usr/lib/ruby/vendor_ruby/logging/diagnostic_context.rb:474:in `block in create_with_logging_context'
2021-09-15T08:16:51 1ea0e922 [D]          Step 4db5c44d-f39c-4a04-a02a-da1e7eefd9ae: 2   running >>     error in phase      Run Proxy::Dynflow::Action::Batch
2021-09-15T08:16:51  [D] ExecutionPlan 4db5c44d-f39c-4a04-a02a-da1e7eefd9ae      running >>   stopped
2021-09-15T08:17:03  [D] Executor heartbeat

aruzicka · September 15, 2021, 11:19am

Hi, could you check output of journalctl -u sshd and contents of /var/log/secure on the target host? One of those should hint you towards why the connection was actually rejected.

patricbalar · September 15, 2021, 11:20am

patricbalar · September 15, 2021, 11:34am

sshd config

PasswordAuthentication no
PermitRootLogin yes

patricbalar · September 15, 2021, 11:53am

sshd logs when task run

Sep 15 11:13:53 foreman.pride.improwised.dev sshd[5094]: Connection closed by authenticating user root 10.10.0.5 port 53888 [preauth]

aruzicka · September 15, 2021, 11:56am

Right, ubuntu. So maybe /var/log/auth.log?

Nothing really jumps to mind, it looks like you have everything configured correctly. There were some issues with newer crypto policies, but I wouldn’t expect that to happen on 20.04.

patricbalar · September 15, 2021, 12:11pm

same Sep 15 11:13:53 foreman.pride.improwised.dev sshd[5094]: Connection closed by authenticating user root 10.10.0.5 port 53888 [preauth] in /var/log/auth.log

it looks like you have everything configured correctly

The weird thing is it works when I try remote execution with password, for that testing registered my laptop, and it worked. see

jtruestedt · September 15, 2021, 2:20pm

Have you checked that the permissions of the ssh-key are correct? it should be only readable by the foreman-proxy user and the /var/lib/foreman-proxy/ssh folder should be the same in /usr/share/foreman-proxy/.ssh (this should be a link to /var/…)

patricbalar · September 16, 2021, 5:04am

ahh… it was own by root because root created it manually… i fixed the owner and it worked. Thank you for quick support

Question: is there any way to get automatically creating these keys when installing foreman?

before

after

jtruestedt · September 16, 2021, 5:56am

There should be an option if the remote execution keys are created during the installer run or not.
If you have a look at the /etc/foreman-installer/scenarios.d/katello-answers.yaml (or foreman-answers.yaml depending on your scenario) in the remote execution-section there should be an option.

There should be also an option which you can add to the foreman-installer-command but I have to search for it - maybe I can add it to this post later

patricbalar · September 16, 2021, 6:00am

Okay, ill look into that too.

Thank you, @jtruestedt @aruzicka for your time.

jtruestedt · September 16, 2021, 7:40am

in the answers.yaml there should be:

foreman_proxy::plugin::remote_execution::ssh:
  enabled: true
  listen_on: https
  generate_keys: true
  install_key: false
  ssh_identity_dir: "/var/lib/foreman-proxy/ssh"
  ssh_identity_file: id_rsa_foreman_proxy
  ssh_keygen: "/usr/bin/ssh-keygen"
  local_working_dir: "/var/tmp"
  remote_working_dir: "/var/tmp"
  ssh_kerberos_auth: false
  async_ssh: false

And in the installer there are the options for it:

= Module foreman_proxy_plugin_remote_execution_ssh:
    --foreman-proxy-plugin-remote-execution-ssh-async-ssh  Whether to run remote execution jobs asynchronously. (current: false)
    --reset-foreman-proxy-plugin-remote-execution-ssh-async-ssh Reset async_ssh to the default value (false)
    --foreman-proxy-plugin-remote-execution-ssh-enabled  Enables/disables the plugin (current: true)
    --reset-foreman-proxy-plugin-remote-execution-ssh-enabled Reset enabled to the default value (true)
    --foreman-proxy-plugin-remote-execution-ssh-listen-on  Proxy feature listens on https, http, or both (current: "https")
    --reset-foreman-proxy-plugin-remote-execution-ssh-listen-on Reset listen_on to the default value ("https")
    --foreman-proxy-plugin-remote-execution-ssh-generate-keys  Automatically generate SSH keys (current: true)
    --reset-foreman-proxy-plugin-remote-execution-ssh-generate-keys Reset generate_keys to the default value (true)
    --foreman-proxy-plugin-remote-execution-ssh-install-key  Automatically install generated SSH key to root authorized keys
    --reset-foreman-proxy-plugin-remote-execution-ssh-install-key Reset install_key to the default value (false)
    --foreman-proxy-plugin-remote-execution-ssh-local-working-dir  Local working directory on the smart proxy (current: "/var/tmp")
    --reset-foreman-proxy-plugin-remote-execution-ssh-local-working-dir Reset local_working_dir to the default value ("/var/tmp")
    --foreman-proxy-plugin-remote-execution-ssh-remote-working-dir  Remote working directory on clients (current: "/var/tmp")
    --reset-foreman-proxy-plugin-remote-execution-ssh-remote-working-dir Reset remote_working_dir to the default value ("/var/tmp")
    --foreman-proxy-plugin-remote-execution-ssh-ssh-identity-dir  Directory where SSH keys are stored (current: "/var/lib/foreman-proxy/ssh")
    --reset-foreman-proxy-plugin-remote-execution-ssh-ssh-identity-dir Reset ssh_identity_dir to the default value ("/var/lib/foreman-proxy/ssh")
    --foreman-proxy-plugin-remote-execution-ssh-ssh-identity-file  Provide an alternative name for the SSH keys (current: "id_rsa_foreman_proxy")
    --reset-foreman-proxy-plugin-remote-execution-ssh-ssh-identity-file Reset ssh_identity_file to the default value ("id_rsa_foreman_proxy")
    --foreman-proxy-plugin-remote-execution-ssh-ssh-kerberos-auth  Enable kerberos authentication for SSH (current: false)
    --reset-foreman-proxy-plugin-remote-execution-ssh-ssh-kerberos-auth Reset ssh_kerberos_auth to the default value (false)
    --foreman-proxy-plugin-remote-execution-ssh-ssh-keygen  Location of the ssh-keygen binary (current: "/usr/bin/ssh-keygen")
    --reset-foreman-proxy-plugin-remote-execution-ssh-ssh-keygen Reset ssh_keygen to the default value ("/usr/bin/ssh-keygen")

So you could activate it with foreman-installer --foreman-proxy-plugin-remote-execution-ssh-generate-keys

techietubby · September 20, 2021, 10:42am

You can try re-running the task and entering a (root) username and password to see if the task runs apart from the KEX. The other problem I found was that client hostnames were not known to DNS and this broke the negotiation. My test was to add the FQDN and alias names of the client and server to both /etc/hosts files.

# ssh-keygen -t rsa -N '' -f /etc/foreman-proxy/id_rsa
# chgrp foreman-proxy /etc/foreman-proxy/id_rsa
# chmod 640 /etc/foreman-proxy/id_rsa
# systemctl restart foreman-proxy
# systemctl status -l foreman-proxy
# echo -e "Host *\n\tStrictHostKeyChecking no\n\tUserKnownHostsFile /dev/null" > /usr/share/foreman-proxy/.ssh/config
# chown foreman-proxy:foreman-proxy /usr/share/foreman-proxy/.ssh/config
# chmod 600 /usr/share/foreman-proxy/.ssh/config
# su - foreman-proxy -s /bin/bash

Now try ssh’ing to root@client.example.com to see if it works.

Another possibility:

# sudo -u foreman-proxy ssh-keygen -f ~foreman-proxy/.ssh/id_rsa_foreman_proxy -N ''

# cat > passwd.txt << EOF
MyPassword
EOF

# ssh-copy-id -i /usr/share/foreman-proxy/.ssh/id_rsa_foreman_proxy.pub root@test.example.com
# sshpass -f password.txt ssh-copy-id -i /usr/share/foreman-proxy/.ssh/id_rsa_foreman_proxy.pub root@test.example.com
# hammer host info --name test.example.com

patricbalar · October 18, 2021, 11:08am

Yes without key with password it works

SarathHewage · January 17, 2023, 8:42am

I have a similar issue, but not the same. If anyone can help me appreciate a lot.
I have ansible role which is called by Foreman Template
This ansible role has tasks run on target host and also some tasks which should run on other related hosts. tasks should run on other hosts are directed by ‘delegated_to:’ facility.
When run through Foreman Template, the tasks that needs to be run on target host run correctly on the target host. The tasks should run other related hosts run on control host, which is the smart proxy server. It swich to the delegated_to host but ‘ESTABLISH LOCAL CONNECTION FOR USER: foreman-proxy’

Wonder, why this is happening?

gvde · January 17, 2023, 8:55am

New issue, new topic please…

SarathHewage · January 17, 2023, 9:26am

//New issue, new topic please…//

Already new topic is created and waiting for someone to reply.
Ansible roles dosn’t work on delegated host - Support - TheForeman

Mean time I noticed this topic and thought to mention about my issue.