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