Remote command: Error initializing command: IOError - closed stream

[Edgars_M]

Hi

I am trying to setup remote jobs from Katello to clients unfortunately all
SSH remote commands fails with:

1: Error initializing command: IOError - closed stream
2: Exit status: EXCEPTION

The only thing I see on client's side is:

Connection closed by 10.30.xxx.xxx [preauth]

If I try to do simple ssh with OpenSSH client it works just fine.

Here is the log:

Action:

ForemanRemoteExecutionCore::Actions::RunScript

Input:

{"ssh_user"=>"redacted-username",
"effective_user"=>"root",
"effective_user_method"=>"sudo",
"ssh_port"=>22,
"hostname"=>"some_hostname",
"script"=>"uptime",
"execution_timeout_interval"=>nil,
"task_id"=>"9f4b7f1e-92e0-4b50-afad-1356f4821595",
"locale"=>"en"}

Output:

{"result"=>
[{"output_type"=>"debug",
"output"=>"Error initializing command: IOError - closed stream",
"timestamp"=>1504872104.755812}],
"runner_id"=>"289b1675-3a4f-4a85-af90-68d84c9f4e9b",
"exit_status"=>"EXCEPTION"}

Exception:

StandardError: Script execution failed

Backtrace:

/opt/theforeman/tfm/root/usr/share/gems/gems/algebrick-0.7.3/lib/algebrick/matchers/abstract.rb:74:in block in assigns' /opt/theforeman/tfm/root/usr/share/gems/gems/algebrick-0.7.3/lib/algebrick/matchers/abstract.rb:73:intap'
/opt/theforeman/tfm/root/usr/share/gems/gems/algebrick-0.7.3/lib/algebrick/matchers/abstract.rb:73:in assigns' /opt/theforeman/tfm/root/usr/share/gems/gems/algebrick-0.7.3/lib/algebrick/matching.rb:56:inmatch_value'
/opt/theforeman/tfm/root/usr/share/gems/gems/algebrick-0.7.3/lib/algebrick/matching.rb:36:in block in match?' /opt/theforeman/tfm/root/usr/share/gems/gems/algebrick-0.7.3/lib/algebrick/matching.rb:35:ineach'
/opt/theforeman/tfm/root/usr/share/gems/gems/algebrick-0.7.3/lib/algebrick/matching.rb:35:in match?' /opt/theforeman/tfm/root/usr/share/gems/gems/algebrick-0.7.3/lib/algebrick/matching.rb:23:inmatch'
/opt/theforeman/tfm/root/usr/share/gems/gems/dynflow-0.8.24/lib/dynflow/execution_plan/steps/error.rb:12:in new' /opt/theforeman/tfm/root/usr/share/gems/gems/dynflow-0.8.24/lib/dynflow/action.rb:454:inset_error'
/opt/theforeman/tfm/root/usr/share/gems/gems/dynflow-0.8.24/lib/dynflow/action.rb:417:in error!' /opt/theforeman/tfm/root/usr/share/gems/gems/foreman-tasks-core-0.1.4/lib/foreman_tasks_core/runner/action.rb:25:infinalize'
/opt/theforeman/tfm/root/usr/share/gems/gems/dynflow-0.8.24/lib/dynflow/action.rb:534:in block (2 levels) in execute_finalize' /opt/theforeman/tfm/root/usr/share/gems/gems/dynflow-0.8.24/lib/dynflow/middleware/stack.rb:26:incall'
/opt/theforeman/tfm/root/usr/share/gems/gems/dynflow-0.8.24/lib/dynflow/middleware/stack.rb:26:in pass' /opt/theforeman/tfm/root/usr/share/gems/gems/dynflow-0.8.24/lib/dynflow/middleware.rb:17:inpass'
/opt/theforeman/tfm/root/usr/share/gems/gems/dynflow-0.8.24/lib/dynflow/action/progress.rb:30:in with_progress_calculation' /opt/theforeman/tfm/root/usr/share/gems/gems/dynflow-0.8.24/lib/dynflow/action/progress.rb:22:infinalize'
/opt/theforeman/tfm/root/usr/share/gems/gems/dynflow-0.8.24/lib/dynflow/middleware/stack.rb:22:in call' /opt/theforeman/tfm/root/usr/share/gems/gems/dynflow-0.8.24/lib/dynflow/middleware/stack.rb:26:inpass'
/opt/theforeman/tfm/root/usr/share/gems/gems/dynflow-0.8.24/lib/dynflow/middleware.rb:17:in pass' /opt/theforeman/tfm/root/usr/share/gems/gems/katello-3.4.5/app/lib/actions/middleware/keep_locale.rb:15:inblock in finalize'
/opt/theforeman/tfm/root/usr/share/gems/gems/katello-3.4.5/app/lib/actions/middleware/keep_locale.rb:22:in with_locale' /opt/theforeman/tfm/root/usr/share/gems/gems/katello-3.4.5/app/lib/actions/middleware/keep_locale.rb:15:infinalize'
/opt/theforeman/tfm/root/usr/share/gems/gems/dynflow-0.8.24/lib/dynflow/middleware/stack.rb:22:in call' /opt/theforeman/tfm/root/usr/share/gems/gems/dynflow-0.8.24/lib/dynflow/middleware/stack.rb:26:inpass'
/opt/theforeman/tfm/root/usr/share/gems/gems/dynflow-0.8.24/lib/dynflow/middleware.rb:17:in pass' /opt/theforeman/tfm/root/usr/share/gems/gems/dynflow-0.8.24/lib/dynflow/middleware.rb:38:infinalize'
/opt/theforeman/tfm/root/usr/share/gems/gems/dynflow-0.8.24/lib/dynflow/middleware/stack.rb:22:in call' /opt/theforeman/tfm/root/usr/share/gems/gems/dynflow-0.8.24/lib/dynflow/middleware/world.rb:30:inexecute'
/opt/theforeman/tfm/root/usr/share/gems/gems/dynflow-0.8.24/lib/dynflow/action.rb:533:in block in execute_finalize' /opt/theforeman/tfm/root/usr/share/gems/gems/dynflow-0.8.24/lib/dynflow/action.rb:425:incall'
/opt/theforeman/tfm/root/usr/share/gems/gems/dynflow-0.8.24/lib/dynflow/action.rb:425:in block in with_error_handling' /opt/theforeman/tfm/root/usr/share/gems/gems/dynflow-0.8.24/lib/dynflow/action.rb:425:incatch'
/opt/theforeman/tfm/root/usr/share/gems/gems/dynflow-0.8.24/lib/dynflow/action.rb:425:in with_error_handling' /opt/theforeman/tfm/root/usr/share/gems/gems/dynflow-0.8.24/lib/dynflow/action.rb:532:inexecute_finalize'
/opt/theforeman/tfm/root/usr/share/gems/gems/dynflow-0.8.24/lib/dynflow/action.rb:266:in execute' /opt/theforeman/tfm/root/usr/share/gems/gems/dynflow-0.8.24/lib/dynflow/execution_plan/steps/abstract_flow_step.rb:9:inblock (2 levels) in execute'
/opt/theforeman/tfm/root/usr/share/gems/gems/dynflow-0.8.24/lib/dynflow/execution_plan/steps/abstract.rb:155:in call' /opt/theforeman/tfm/root/usr/share/gems/gems/dynflow-0.8.24/lib/dynflow/execution_plan/steps/abstract.rb:155:inwith_meta_calculation'
/opt/theforeman/tfm/root/usr/share/gems/gems/dynflow-0.8.24/lib/dynflow/execution_plan/steps/abstract_flow_step.rb:8:in block in execute' /opt/theforeman/tfm/root/usr/share/gems/gems/dynflow-0.8.24/lib/dynflow/execution_plan/steps/abstract_flow_step.rb:22:inopen_action'
/opt/theforeman/tfm/root/usr/share/gems/gems/dynflow-0.8.24/lib/dynflow/execution_plan/steps/abstract_flow_step.rb:7:in execute' /opt/theforeman/tfm/root/usr/share/gems/gems/dynflow-0.8.24/lib/dynflow/director/sequential_manager.rb:68:inrun_step'
/opt/theforeman/tfm/root/usr/share/gems/gems/dynflow-0.8.24/lib/dynflow/director/sequential_manager.rb:53:in dispatch' /opt/theforeman/tfm/root/usr/share/gems/gems/dynflow-0.8.24/lib/dynflow/director/sequential_manager.rb:60:inblock in run_in_sequence'
/opt/theforeman/tfm/root/usr/share/gems/gems/dynflow-0.8.24/lib/dynflow/director/sequential_manager.rb:60:in each' /opt/theforeman/tfm/root/usr/share/gems/gems/dynflow-0.8.24/lib/dynflow/director/sequential_manager.rb:60:inall?'
/opt/theforeman/tfm/root/usr/share/gems/gems/dynflow-0.8.24/lib/dynflow/director/sequential_manager.rb:60:in run_in_sequence' /opt/theforeman/tfm/root/usr/share/gems/gems/dynflow-0.8.24/lib/dynflow/director/sequential_manager.rb:49:indispatch'
/opt/theforeman/tfm/root/usr/share/gems/gems/dynflow-0.8.24/lib/dynflow/director/sequential_manager.rb:27:in block in finalize' /opt/theforeman/tfm/root/usr/share/gems/gems/dynflow-0.8.24/lib/dynflow/middleware/stack.rb:26:incall'
/opt/theforeman/tfm/root/usr/share/gems/gems/dynflow-0.8.24/lib/dynflow/middleware/stack.rb:26:in pass' /opt/theforeman/tfm/root/usr/share/gems/gems/dynflow-0.8.24/lib/dynflow/middleware.rb:17:inpass'
/opt/theforeman/tfm/root/usr/share/gems/gems/dynflow-0.8.24/lib/dynflow/middleware.rb:46:in finalize_phase' /opt/theforeman/tfm/root/usr/share/gems/gems/dynflow-0.8.24/lib/dynflow/middleware/stack.rb:22:incall'
/opt/theforeman/tfm/root/usr/share/gems/gems/dynflow-0.8.24/lib/dynflow/middleware/stack.rb:26:in pass' /opt/theforeman/tfm/root/usr/share/gems/gems/dynflow-0.8.24/lib/dynflow/middleware.rb:17:inpass'
/opt/theforeman/tfm/root/usr/share/gems/gems/dynflow-0.8.24/lib/dynflow/middleware.rb:46:in finalize_phase' /opt/theforeman/tfm/root/usr/share/gems/gems/dynflow-0.8.24/lib/dynflow/middleware/stack.rb:22:incall'
/opt/theforeman/tfm/root/usr/share/gems/gems/dynflow-0.8.24/lib/dynflow/middleware/stack.rb:26:in pass' /opt/theforeman/tfm/root/usr/share/gems/gems/dynflow-0.8.24/lib/dynflow/middleware.rb:17:inpass'
/opt/theforeman/tfm/root/usr/share/gems/gems/dynflow-0.8.24/lib/dynflow/middleware/common/transaction.rb:16:in block in rollback_on_error' /opt/rh/sclo-ror42/root/usr/share/gems/gems/activerecord-4.2.5.1/lib/active_record/connection_adapters/abstract/database_statements.rb:213:inblock in transaction'
/opt/rh/sclo-ror42/root/usr/share/gems/gems/activerecord-4.2.5.1/lib/active_record/connection_adapters/abstract/transaction.rb:184:in within_new_transaction' /opt/rh/sclo-ror42/root/usr/share/gems/gems/activerecord-4.2.5.1/lib/active_record/connection_adapters/abstract/database_statements.rb:213:intransaction'
/opt/rh/sclo-ror42/root/usr/share/gems/gems/activerecord-4.2.5.1/lib/active_record/transactions.rb:220:in transaction' /opt/theforeman/tfm/root/usr/share/gems/gems/dynflow-0.8.24/lib/dynflow/transaction_adapters/active_record.rb:5:intransaction'
/opt/theforeman/tfm/root/usr/share/gems/gems/dynflow-0.8.24/lib/dynflow/middleware/common/transaction.rb:15:in rollback_on_error' /opt/theforeman/tfm/root/usr/share/gems/gems/dynflow-0.8.24/lib/dynflow/middleware/common/transaction.rb:9:infinalize_phase'
/opt/theforeman/tfm/root/usr/share/gems/gems/dynflow-0.8.24/lib/dynflow/middleware/stack.rb:22:in call' /opt/theforeman/tfm/root/usr/share/gems/gems/dynflow-0.8.24/lib/dynflow/middleware/world.rb:30:inexecute'
/opt/theforeman/tfm/root/usr/share/gems/gems/dynflow-0.8.24/lib/dynflow/director/sequential_manager.rb:26:in finalize' /opt/theforeman/tfm/root/usr/share/gems/gems/dynflow-0.8.24/lib/dynflow/director.rb:66:inexecute'
/opt/theforeman/tfm/root/usr/share/gems/gems/dynflow-0.8.24/lib/dynflow/executors/parallel/worker.rb:11:in on_message' /opt/theforeman/tfm/root/usr/share/gems/gems/concurrent-ruby-edge-0.2.3/lib/concurrent/actor/context.rb:46:inon_envelope'
/opt/theforeman/tfm/root/usr/share/gems/gems/concurrent-ruby-edge-0.2.3/lib/concurrent/actor/behaviour/executes_context.rb:7:in on_envelope' /opt/theforeman/tfm/root/usr/share/gems/gems/concurrent-ruby-edge-0.2.3/lib/concurrent/actor/behaviour/abstract.rb:25:inpass'
/opt/theforeman/tfm/root/usr/share/gems/gems/dynflow-0.8.24/lib/dynflow/actor.rb:26:in on_envelope' /opt/theforeman/tfm/root/usr/share/gems/gems/concurrent-ruby-edge-0.2.3/lib/concurrent/actor/behaviour/abstract.rb:25:inpass'
/opt/theforeman/tfm/root/usr/share/gems/gems/concurrent-ruby-edge-0.2.3/lib/concurrent/actor/behaviour/awaits.rb:15:in on_envelope' /opt/theforeman/tfm/root/usr/share/gems/gems/concurrent-ruby-edge-0.2.3/lib/concurrent/actor/behaviour/abstract.rb:25:inpass'
/opt/theforeman/tfm/root/usr/share/gems/gems/concurrent-ruby-edge-0.2.3/lib/concurrent/actor/behaviour/sets_results.rb:14:in on_envelope' /opt/theforeman/tfm/root/usr/share/gems/gems/concurrent-ruby-edge-0.2.3/lib/concurrent/actor/behaviour/abstract.rb:25:inpass'
/opt/theforeman/tfm/root/usr/share/gems/gems/concurrent-ruby-edge-0.2.3/lib/concurrent/actor/behaviour/buffer.rb:38:in process_envelope' /opt/theforeman/tfm/root/usr/share/gems/gems/concurrent-ruby-edge-0.2.3/lib/concurrent/actor/behaviour/buffer.rb:31:inprocess_envelopes?'
/opt/theforeman/tfm/root/usr/share/gems/gems/concurrent-ruby-edge-0.2.3/lib/concurrent/actor/behaviour/buffer.rb:20:in on_envelope' /opt/theforeman/tfm/root/usr/share/gems/gems/concurrent-ruby-edge-0.2.3/lib/concurrent/actor/behaviour/abstract.rb:25:inpass'
/opt/theforeman/tfm/root/usr/share/gems/gems/concurrent-ruby-edge-0.2.3/lib/concurrent/actor/behaviour/termination.rb:55:in on_envelope' /opt/theforeman/tfm/root/usr/share/gems/gems/concurrent-ruby-edge-0.2.3/lib/concurrent/actor/behaviour/abstract.rb:25:inpass'
/opt/theforeman/tfm/root/usr/share/gems/gems/concurrent-ruby-edge-0.2.3/lib/concurrent/actor/behaviour/removes_child.rb:10:in on_envelope' /opt/theforeman/tfm/root/usr/share/gems/gems/concurrent-ruby-edge-0.2.3/lib/concurrent/actor/behaviour/abstract.rb:25:inpass'
/opt/theforeman/tfm/root/usr/share/gems/gems/concurrent-ruby-edge-0.2.3/lib/concurrent/actor/behaviour/sets_results.rb:14:in on_envelope' /opt/theforeman/tfm/root/usr/share/gems/gems/concurrent-ruby-edge-0.2.3/lib/concurrent/actor/core.rb:161:inprocess_envelope'
/opt/theforeman/tfm/root/usr/share/gems/gems/concurrent-ruby-edge-0.2.3/lib/concurrent/actor/core.rb:95:in block in on_envelope' /opt/theforeman/tfm/root/usr/share/gems/gems/concurrent-ruby-edge-0.2.3/lib/concurrent/actor/core.rb:118:inblock (2 levels) in schedule_execution'
/opt/theforeman/tfm/root/usr/share/gems/gems/concurrent-ruby-1.0.3/lib/concurrent/synchronization/mri_lockable_object.rb:38:in block in synchronize' /opt/theforeman/tfm/root/usr/share/gems/gems/concurrent-ruby-1.0.3/lib/concurrent/synchronization/mri_lockable_object.rb:38:insynchronize'
/opt/theforeman/tfm/root/usr/share/gems/gems/concurrent-ruby-1.0.3/lib/concurrent/synchronization/mri_lockable_object.rb:38:in synchronize' /opt/theforeman/tfm/root/usr/share/gems/gems/concurrent-ruby-edge-0.2.3/lib/concurrent/actor/core.rb:115:inblock in schedule_execution'
/opt/theforeman/tfm/root/usr/share/gems/gems/concurrent-ruby-1.0.3/lib/concurrent/executor/serialized_execution.rb:18:in call' /opt/theforeman/tfm/root/usr/share/gems/gems/concurrent-ruby-1.0.3/lib/concurrent/executor/serialized_execution.rb:18:incall'
/opt/theforeman/tfm/root/usr/share/gems/gems/concurrent-ruby-1.0.3/lib/concurrent/executor/serialized_execution.rb:96:in work' /opt/theforeman/tfm/root/usr/share/gems/gems/concurrent-ruby-1.0.3/lib/concurrent/executor/serialized_execution.rb:77:inblock in call_job'
/opt/theforeman/tfm/root/usr/share/gems/gems/concurrent-ruby-1.0.3/lib/concurrent/executor/ruby_thread_pool_executor.rb:348:in call' /opt/theforeman/tfm/root/usr/share/gems/gems/concurrent-ruby-1.0.3/lib/concurrent/executor/ruby_thread_pool_executor.rb:348:inrun_task'
/opt/theforeman/tfm/root/usr/share/gems/gems/concurrent-ruby-1.0.3/lib/concurrent/executor/ruby_thread_pool_executor.rb:337:in block (3 levels) in create_worker' /opt/theforeman/tfm/root/usr/share/gems/gems/concurrent-ruby-1.0.3/lib/concurrent/executor/ruby_thread_pool_executor.rb:320:inloop'
/opt/theforeman/tfm/root/usr/share/gems/gems/concurrent-ruby-1.0.3/lib/concurrent/executor/ruby_thread_pool_executor.rb:320:in block (2 levels) in create_worker' /opt/theforeman/tfm/root/usr/share/gems/gems/concurrent-ruby-1.0.3/lib/concurrent/executor/ruby_thread_pool_executor.rb:319:incatch'
/opt/theforeman/tfm/root/usr/share/gems/gems/concurrent-ruby-1.0.3/lib/concurrent/executor/ruby_thread_pool_executor.rb:319:in block in create_worker' /opt/theforeman/tfm/root/usr/share/gems/gems/logging-1.8.2/lib/logging/diagnostic_context.rb:323:incall'
/opt/theforeman/tfm/root/usr/share/gems/gems/logging-1.8.2/lib/logging/diagnostic_context.rb:323:in `block in create_with_logging_context'

[Edgars_M]

Hi

I did some testing and here is what I found. I took this script from the
Internet, modified it and ran:

require 'rubygems'
require 'net/ssh'

Net::SSH.start('client.fqdn', 'admin', :keys =>
['/usr/share/foreman-proxy/.ssh/id_rsa_foreman_proxy'], :verbose => :debug,
:forward_agent => true ) do |ssh|
output = ssh.exec!("hostname -f")
puts output
end

And this was the output:
<…>
D, [2017-09-11T12:01:20.674105 #11798] DEBUG –
net.ssh.authentication.session[905b78]: allowed methods: publickey
D, [2017-09-11T12:01:20.674154 #11798] DEBUG –
net.ssh.authentication.methods.none[8f1dd0]: none failed
D, [2017-09-11T12:01:20.674193 #11798] DEBUG –
net.ssh.authentication.session[905b78]: trying publickey
D, [2017-09-11T12:01:20.674265 #11798] DEBUG –
net.ssh.authentication.agent[804314]: connecting to ssh-agent
E, [2017-09-11T12:01:20.674305 #11798] ERROR –
net.ssh.authentication.agent[804314]: could not connect to ssh-agent: Agent
not configured
E, [2017-09-11T12:01:20.674331 #11798] ERROR –
net.ssh.authentication.session[905b78]: all authorization methods failed
(tried none, publickey)
/opt/theforeman/tfm/root/usr/share/gems/gems/net-ssh-4.0.1/lib/net/ssh/transport/session.rb:128:in
close': closed stream (IOError) from /opt/theforeman/tfm/root/usr/share/gems/gems/net-ssh-4.0.1/lib/net/ssh/transport/session.rb:128:inclose'
from
/opt/theforeman/tfm/root/usr/share/gems/gems/net-ssh-4.0.1/lib/net/ssh.rb:253:in
rescue in start' from /opt/theforeman/tfm/root/usr/share/gems/gems/net-ssh-4.0.1/lib/net/ssh.rb:205:instart'

So it seems that Ruby SSH client is trying to connect to ssh-agent. So here
is what I did next on Katello server:

[admin@katello-server.fqdn ~]$ sudo -u foreman-proxy ssh-agent bash
bash-4.2$ ssh-add /usr/share/foreman-proxy/.ssh/id_rsa_foreman_proxy
Identity added: /usr/share/foreman-proxy/.ssh/id_rsa_foreman_proxy
(/usr/share/foreman-proxy/.ssh/id_rsa_foreman_proxy)

and then ran script again and everything worked!
bash-4.2$ ruby193-ruby /opt/sshtest.rb
D, [2017-09-11T12:05:07.462362 #12073] DEBUG –
net.ssh.transport.session[d4b6c4]: establishing connection to client.fqdn:22
D, [2017-09-11T12:05:07.463975 #12073] DEBUG –
net.ssh.transport.session[d4b6c4]: connection established
I, [2017-09-11T12:05:07.464038 #12073] INFO –
net.ssh.transport.server_version[d4ab5c]: negotiating protocol version
D, [2017-09-11T12:05:07.464059 #12073] DEBUG –
net.ssh.transport.server_version[d4ab5c]: local is
SSH-2.0-Ruby/Net::SSH_4.0.1 x86_64-linux' D, [2017-09-11T12:05:07.472592 #12073] DEBUG -- net.ssh.transport.server_version[d4ab5c]: remote isSSH-2.0-OpenSSH_6.6.1'
I, [2017-09-11T12:05:07.473015 #12073] INFO –
net.ssh.transport.algorithms[d3fb08]: sending KEXINIT
D, [2017-09-11T12:05:07.473164 #12073] DEBUG – socket[d4b2dc]: queueing
packet nr 0 type 20 len 1156
D, [2017-09-11T12:05:07.473218 #12073] DEBUG – socket[d4b2dc]: sent 1160
bytes
D, [2017-09-11T12:05:07.473473 #12073] DEBUG – socket[d4b2dc]: read 336
bytes
D, [2017-09-11T12:05:07.473528 #12073] DEBUG – socket[d4b2dc]: received
packet nr 0 type 20 len 332
I, [2017-09-11T12:05:07.473559 #12073] INFO –
net.ssh.transport.algorithms[d3fb08]: got KEXINIT from server
I, [2017-09-11T12:05:07.473620 #12073] INFO –
net.ssh.transport.algorithms[d3fb08]: negotiating algorithms
D, [2017-09-11T12:05:07.473705 #12073] DEBUG –
net.ssh.transport.algorithms[d3fb08]: negotiated:

• kex: diffie-hellman-group14-sha1
• host_key: ecdsa-sha2-nistp256
• encryption_server: aes128-ctr
• encryption_client: aes128-ctr
• hmac_client: hmac-sha2-256
• hmac_server: hmac-sha2-256
• compression_client: none
• compression_server: none
• language_client:
• language_server:
  D, [2017-09-11T12:05:07.473730 #12073] DEBUG –
  net.ssh.transport.algorithms[d3fb08]: exchanging keys
  D, [2017-09-11T12:05:07.480944 #12073] DEBUG – socket[d4b2dc]: queueing
  packet nr 1 type 30 len 268
  D, [2017-09-11T12:05:07.480998 #12073] DEBUG – socket[d4b2dc]: sent 272
  bytes
  D, [2017-09-11T12:05:07.482845 #12073] DEBUG – socket[d4b2dc]: read 504
  bytes
  D, [2017-09-11T12:05:07.482917 #12073] DEBUG – socket[d4b2dc]: received
  packet nr 1 type 31 len 484
  D, [2017-09-11T12:05:07.484437 #12073] DEBUG – socket[d4b2dc]: queueing
  packet nr 2 type 21 len 20
  D, [2017-09-11T12:05:07.484491 #12073] DEBUG – socket[d4b2dc]: sent 24
  bytes
  D, [2017-09-11T12:05:07.484547 #12073] DEBUG – socket[d4b2dc]: received
  packet nr 2 type 21 len 12
  D, [2017-09-11T12:05:07.484810 #12073] DEBUG –
  net.ssh.authentication.session[96bb30]: beginning authentication of `admin'
  D, [2017-09-11T12:05:07.485013 #12073] DEBUG – socket[d4b2dc]: queueing
  packet nr 3 type 5 len 28
  D, [2017-09-11T12:05:07.485072 #12073] DEBUG – socket[d4b2dc]: sent 64
  bytes
  D, [2017-09-11T12:05:07.524301 #12073] DEBUG – socket[d4b2dc]: read 64
  bytes
  D, [2017-09-11T12:05:07.524450 #12073] DEBUG – socket[d4b2dc]: received
  packet nr 3 type 6 len 28
  D, [2017-09-11T12:05:07.524556 #12073] DEBUG –
  net.ssh.authentication.session[96bb30]: trying none
  D, [2017-09-11T12:05:07.525420 #12073] DEBUG – socket[d4b2dc]: queueing
  packet nr 4 type 50 len 44
  D, [2017-09-11T12:05:07.525490 #12073] DEBUG – socket[d4b2dc]: sent 80
  bytes
  D, [2017-09-11T12:05:07.528362 #12073] DEBUG – socket[d4b2dc]: read 320
  bytes
  D, [2017-09-11T12:05:07.528552 #12073] DEBUG – socket[d4b2dc]: received
  packet nr 4 type 53 len 220
  I, [2017-09-11T12:05:07.528612 #12073] INFO –
  net.ssh.authentication.session[96bb30]:
  WARNING: Unauthorized access to this system is forbidden and will be
  prosecuted by law. By accessing this system, you agree that your
  actions may be monitored if unauthorized usage is suspected.

D, [2017-09-11T12:05:07.528700 #12073] DEBUG – socket[d4b2dc]: received
packet nr 5 type 51 len 28
D, [2017-09-11T12:05:07.529156 #12073] DEBUG –
net.ssh.authentication.session[96bb30]: allowed methods: publickey
D, [2017-09-11T12:05:07.529226 #12073] DEBUG –
net.ssh.authentication.methods.none[963278]: none failed
D, [2017-09-11T12:05:07.529274 #12073] DEBUG –
net.ssh.authentication.session[96bb30]: trying publickey
D, [2017-09-11T12:05:07.529476 #12073] DEBUG –
net.ssh.authentication.agent[97cc28]: connecting to ssh-agent
D, [2017-09-11T12:05:07.529566 #12073] DEBUG –
net.ssh.authentication.agent[97cc28]: sending agent request 1 len 44
D, [2017-09-11T12:05:07.529661 #12073] DEBUG –
net.ssh.authentication.agent[97cc28]: received agent packet 2 len 5
D, [2017-09-11T12:05:07.529726 #12073] DEBUG –
net.ssh.authentication.agent[97cc28]: sending agent request 11 len 0
D, [2017-09-11T12:05:07.529819 #12073] DEBUG –
net.ssh.authentication.agent[97cc28]: received agent packet 12 len 342
D, [2017-09-11T12:05:07.530101 #12073] DEBUG –
net.ssh.authentication.methods.publickey[97d3f8]: trying publickey
(8a:99:a1:12:8a:87:c5:8e:58:45:a9:d8:f9:0a:61:16)
D, [2017-09-11T12:05:07.530746 #12073] DEBUG – socket[d4b2dc]: queueing
packet nr 5 type 50 len 348
D, [2017-09-11T12:05:07.530813 #12073] DEBUG – socket[d4b2dc]: sent 384
bytes
D, [2017-09-11T12:05:07.531222 #12073] DEBUG – socket[d4b2dc]: read 336
bytes
D, [2017-09-11T12:05:07.531458 #12073] DEBUG – socket[d4b2dc]: received
packet nr 6 type 60 len 300
D, [2017-09-11T12:05:07.531979 #12073] DEBUG –
net.ssh.authentication.agent[97cc28]: sending agent request 13 len 653
D, [2017-09-11T12:05:07.533364 #12073] DEBUG –
net.ssh.authentication.agent[97cc28]: received agent packet 14 len 276
D, [2017-09-11T12:05:07.533804 #12073] DEBUG – socket[d4b2dc]: queueing
packet nr 6 type 50 len 620
D, [2017-09-11T12:05:07.533860 #12073] DEBUG – socket[d4b2dc]: sent 656
bytes
D, [2017-09-11T12:05:07.534713 #12073] DEBUG – socket[d4b2dc]: read 48
bytes
D, [2017-09-11T12:05:07.534799 #12073] DEBUG – socket[d4b2dc]: received
packet nr 7 type 52 len 12
D, [2017-09-11T12:05:07.534842 #12073] DEBUG –
net.ssh.authentication.methods.publickey[97d3f8]: publickey succeeded
(8a:99:a1:12:8a:87:c5:8e:58:45:a9:d8:f9:0a:61:16)
D, [2017-09-11T12:05:07.535158 #12073] DEBUG – socket[d4b2dc]: queueing
packet nr 7 type 90 len 44
D, [2017-09-11T12:05:07.535265 #12073] DEBUG – socket[d4b2dc]: sent 80
bytes
D, [2017-09-11T12:05:07.540589 #12073] DEBUG – socket[d4b2dc]: read 64
bytes
D, [2017-09-11T12:05:07.540678 #12073] DEBUG – socket[d4b2dc]: received
packet nr 8 type 91 len 28
I, [2017-09-11T12:05:07.540744 #12073] INFO –
net.ssh.connection.session[a6ba30]: channel_open_confirmation: 0 0 0 32768
I, [2017-09-11T12:05:07.540809 #12073] INFO –
net.ssh.connection.channel[a6ac48]: sending channel request
"auth-agent-req@openssh.com"
D, [2017-09-11T12:05:07.540906 #12073] DEBUG – socket[d4b2dc]: queueing
packet nr 8 type 98 len 44
I, [2017-09-11T12:05:07.541142 #12073] INFO –
net.ssh.connection.channel[a6ac48]: sending channel request "env"
D, [2017-09-11T12:05:07.541229 #12073] DEBUG – socket[d4b2dc]: queueing
packet nr 9 type 98 len 44
I, [2017-09-11T12:05:07.541764 #12073] INFO –
net.ssh.connection.channel[a6ac48]: sending channel request "exec"
D, [2017-09-11T12:05:07.541852 #12073] DEBUG – socket[d4b2dc]: queueing
packet nr 10 type 98 len 44
D, [2017-09-11T12:05:07.541937 #12073] DEBUG – socket[d4b2dc]: sent 240
bytes
D, [2017-09-11T12:05:07.543087 #12073] DEBUG – socket[d4b2dc]: read 160
bytes
D, [2017-09-11T12:05:07.543342 #12073] DEBUG – socket[d4b2dc]: received
packet nr 9 type 99 len 12
I, [2017-09-11T12:05:07.543385 #12073] INFO –
net.ssh.connection.session[a6ba30]: channel_success: 0
D, [2017-09-11T12:05:07.543427 #12073] DEBUG –
net.ssh.service.forward[d196d8]: authentication agent forwarding is active
D, [2017-09-11T12:05:07.543490 #12073] DEBUG – socket[d4b2dc]: received
packet nr 10 type 93 len 28
I, [2017-09-11T12:05:07.543524 #12073] INFO –
net.ssh.connection.session[a6ba30]: channel_window_adjust: 0 +2097152
D, [2017-09-11T12:05:07.543581 #12073] DEBUG – socket[d4b2dc]: received
packet nr 11 type 99 len 12
I, [2017-09-11T12:05:07.543611 #12073] INFO –
net.ssh.connection.session[a6ba30]: channel_success: 0
D, [2017-09-11T12:05:07.579167 #12073] DEBUG – socket[d4b2dc]: read 256
bytes
D, [2017-09-11T12:05:07.579327 #12073] DEBUG – socket[d4b2dc]: received
packet nr 12 type 94 len 44
I, [2017-09-11T12:05:07.579378 #12073] INFO –
net.ssh.connection.session[a6ba30]: channel_data: 0 28b
D, [2017-09-11T12:05:07.579666 #12073] DEBUG – socket[d4b2dc]: received
packet nr 13 type 98 len 44
I, [2017-09-11T12:05:07.579716 #12073] INFO –
net.ssh.connection.session[a6ba30]: channel_request: 0 exit-status false
D, [2017-09-11T12:05:07.579795 #12073] DEBUG – socket[d4b2dc]: received
packet nr 14 type 96 len 12
I, [2017-09-11T12:05:07.579830 #12073] INFO –
net.ssh.connection.session[a6ba30]: channel_eof: 0
D, [2017-09-11T12:05:07.579897 #12073] DEBUG – socket[d4b2dc]: received
packet nr 15 type 97 len 12
I, [2017-09-11T12:05:07.579933 #12073] INFO –
net.ssh.connection.session[a6ba30]: channel_close: 0
D, [2017-09-11T12:05:07.580043 #12073] DEBUG – socket[d4b2dc]: queueing
packet nr 11 type 97 len 28
I, [2017-09-11T12:05:07.580073 #12073] INFO –
net.ssh.connection.session[a6ba30]: client.fqdn delete channel 0 which
closed locally and remotely
client.fqdn
I, [2017-09-11T12:05:07.580128 #12073] INFO –
net.ssh.connection.session[a6ba30]: closing remaining channels (0 open)
bash-4.2$

Is this expected behaviour?

Edgars

···

On Friday, September 8, 2017 at 3:13:35 PM UTC+3, Edgars M. wrote: > > Hi > > I am trying to setup remote jobs from Katello to clients unfortunately all > SSH remote commands fails with: > > 1: Error initializing command: IOError - closed stream > 2: Exit status: EXCEPTION > > The only thing I see on client's side is: > > Connection closed by 10.30.xxx.xxx [preauth] > > If I try to do simple ssh with OpenSSH client it works just fine. > > Here is the log: > > Action: > > ForemanRemoteExecutionCore::Actions::RunScript > > Input: > > {"ssh_user"=>"redacted-username", > "effective_user"=>"root", > "effective_user_method"=>"sudo", > "ssh_port"=>22, > "hostname"=>"some_hostname", > "script"=>"uptime", > "execution_timeout_interval"=>nil, > "task_id"=>"9f4b7f1e-92e0-4b50-afad-1356f4821595", > "locale"=>"en"} > > Output: > > {"result"=> > [{"output_type"=>"debug", > "output"=>"Error initializing command: IOError - closed stream", > "timestamp"=>1504872104.755812}], > "runner_id"=>"289b1675-3a4f-4a85-af90-68d84c9f4e9b", > "exit_status"=>"EXCEPTION"} > > Exception: > > StandardError: Script execution failed > > Backtrace: > > /opt/theforeman/tfm/root/usr/share/gems/gems/algebrick-0.7.3/lib/algebrick/matchers/abstract.rb:74:in `block in assigns' > /opt/theforeman/tfm/root/usr/share/gems/gems/algebrick-0.7.3/lib/algebrick/matchers/abstract.rb:73:in `tap' > /opt/theforeman/tfm/root/usr/share/gems/gems/algebrick-0.7.3/lib/algebrick/matchers/abstract.rb:73:in `assigns' > /opt/theforeman/tfm/root/usr/share/gems/gems/algebrick-0.7.3/lib/algebrick/matching.rb:56:in `match_value' > /opt/theforeman/tfm/root/usr/share/gems/gems/algebrick-0.7.3/lib/algebrick/matching.rb:36:in `block in match?' > /opt/theforeman/tfm/root/usr/share/gems/gems/algebrick-0.7.3/lib/algebrick/matching.rb:35:in `each' > /opt/theforeman/tfm/root/usr/share/gems/gems/algebrick-0.7.3/lib/algebrick/matching.rb:35:in `match?' > /opt/theforeman/tfm/root/usr/share/gems/gems/algebrick-0.7.3/lib/algebrick/matching.rb:23:in `match' > /opt/theforeman/tfm/root/usr/share/gems/gems/dynflow-0.8.24/lib/dynflow/execution_plan/steps/error.rb:12:in `new' > /opt/theforeman/tfm/root/usr/share/gems/gems/dynflow-0.8.24/lib/dynflow/action.rb:454:in `set_error' > /opt/theforeman/tfm/root/usr/share/gems/gems/dynflow-0.8.24/lib/dynflow/action.rb:417:in `error!' > /opt/theforeman/tfm/root/usr/share/gems/gems/foreman-tasks-core-0.1.4/lib/foreman_tasks_core/runner/action.rb:25:in `finalize' > /opt/theforeman/tfm/root/usr/share/gems/gems/dynflow-0.8.24/lib/dynflow/action.rb:534:in `block (2 levels) in execute_finalize' > /opt/theforeman/tfm/root/usr/share/gems/gems/dynflow-0.8.24/lib/dynflow/middleware/stack.rb:26:in `call' > /opt/theforeman/tfm/root/usr/share/gems/gems/dynflow-0.8.24/lib/dynflow/middleware/stack.rb:26:in `pass' > /opt/theforeman/tfm/root/usr/share/gems/gems/dynflow-0.8.24/lib/dynflow/middleware.rb:17:in `pass' > /opt/theforeman/tfm/root/usr/share/gems/gems/dynflow-0.8.24/lib/dynflow/action/progress.rb:30:in `with_progress_calculation' > /opt/theforeman/tfm/root/usr/share/gems/gems/dynflow-0.8.24/lib/dynflow/action/progress.rb:22:in `finalize' > /opt/theforeman/tfm/root/usr/share/gems/gems/dynflow-0.8.24/lib/dynflow/middleware/stack.rb:22:in `call' > /opt/theforeman/tfm/root/usr/share/gems/gems/dynflow-0.8.24/lib/dynflow/middleware/stack.rb:26:in `pass' > /opt/theforeman/tfm/root/usr/share/gems/gems/dynflow-0.8.24/lib/dynflow/middleware.rb:17:in `pass' > /opt/theforeman/tfm/root/usr/share/gems/gems/katello-3.4.5/app/lib/actions/middleware/keep_locale.rb:15:in `block in finalize' > /opt/theforeman/tfm/root/usr/share/gems/gems/katello-3.4.5/app/lib/actions/middleware/keep_locale.rb:22:in `with_locale' > /opt/theforeman/tfm/root/usr/share/gems/gems/katello-3.4.5/app/lib/actions/middleware/keep_locale.rb:15:in `finalize' > /opt/theforeman/tfm/root/usr/share/gems/gems/dynflow-0.8.24/lib/dynflow/middleware/stack.rb:22:in `call' > /opt/theforeman/tfm/root/usr/share/gems/gems/dynflow-0.8.24/lib/dynflow/middleware/stack.rb:26:in `pass' > /opt/theforeman/tfm/root/usr/share/gems/gems/dynflow-0.8.24/lib/dynflow/middleware.rb:17:in `pass' > /opt/theforeman/tfm/root/usr/share/gems/gems/dynflow-0.8.24/lib/dynflow/middleware.rb:38:in `finalize' > /opt/theforeman/tfm/root/usr/share/gems/gems/dynflow-0.8.24/lib/dynflow/middleware/stack.rb:22:in `call' > /opt/theforeman/tfm/root/usr/share/gems/gems/dynflow-0.8.24/lib/dynflow/middleware/world.rb:30:in `execute' > /opt/theforeman/tfm/root/usr/share/gems/gems/dynflow-0.8.24/lib/dynflow/action.rb:533:in `block in execute_finalize' > /opt/theforeman/tfm/root/usr/share/gems/gems/dynflow-0.8.24/lib/dynflow/action.rb:425:in `call' > /opt/theforeman/tfm/root/usr/share/gems/gems/dynflow-0.8.24/lib/dynflow/action.rb:425:in `block in with_error_handling' > /opt/theforeman/tfm/root/usr/share/gems/gems/dynflow-0.8.24/lib/dynflow/action.rb:425:in `catch' > /opt/theforeman/tfm/root/usr/share/gems/gems/dynflow-0.8.24/lib/dynflow/action.rb:425:in `with_error_handling' > /opt/theforeman/tfm/root/usr/share/gems/gems/dynflow-0.8.24/lib/dynflow/action.rb:532:in `execute_finalize' > /opt/theforeman/tfm/root/usr/share/gems/gems/dynflow-0.8.24/lib/dynflow/action.rb:266:in `execute' > /opt/theforeman/tfm/root/usr/share/gems/gems/dynflow-0.8.24/lib/dynflow/execution_plan/steps/abstract_flow_step.rb:9:in `block (2 levels) in execute' > /opt/theforeman/tfm/root/usr/share/gems/gems/dynflow-0.8.24/lib/dynflow/execution_plan/steps/abstract.rb:155:in `call' > /opt/theforeman/tfm/root/usr/share/gems/gems/dynflow-0.8.24/lib/dynflow/execution_plan/steps/abstract.rb:155:in `with_meta_calculation' > /opt/theforeman/tfm/root/usr/share/gems/gems/dynflow-0.8.24/lib/dynflow/execution_plan/steps/abstract_flow_step.rb:8:in `block in execute' > /opt/theforeman/tfm/root/usr/share/gems/gems/dynflow-0.8.24/lib/dynflow/execution_plan/steps/abstract_flow_step.rb:22:in `open_action' > /opt/theforeman/tfm/root/usr/share/gems/gems/dynflow-0.8.24/lib/dynflow/execution_plan/steps/abstract_flow_step.rb:7:in `execute' > /opt/theforeman/tfm/root/usr/share/gems/gems/dynflow-0.8.24/lib/dynflow/director/sequential_manager.rb:68:in `run_step' > /opt/theforeman/tfm/root/usr/share/gems/gems/dynflow-0.8.24/lib/dynflow/director/sequential_manager.rb:53:in `dispatch' > /opt/theforeman/tfm/root/usr/share/gems/gems/dynflow-0.8.24/lib/dynflow/director/sequential_manager.rb:60:in `block in run_in_sequence' > /opt/theforeman/tfm/root/usr/share/gems/gems/dynflow-0.8.24/lib/dynflow/director/sequential_manager.rb:60:in `each' > /opt/theforeman/tfm/root/usr/share/gems/gems/dynflow-0.8.24/lib/dynflow/director/sequential_manager.rb:60:in `all?' > /opt/theforeman/tfm/root/usr/share/gems/gems/dynflow-0.8.24/lib/dynflow/director/sequential_manager.rb:60:in `run_in_sequence' > /opt/theforeman/tfm/root/usr/share/gems/gems/dynflow-0.8.24/lib/dynflow/director/sequential_manager.rb:49:in `dispatch' > /opt/theforeman/tfm/root/usr/share/gems/gems/dynflow-0.8.24/lib/dynflow/director/sequential_manager.rb:27:in `block in finalize' > /opt/theforeman/tfm/root/usr/share/gems/gems/dynflow-0.8.24/lib/dynflow/middleware/stack.rb:26:in `call' > /opt/theforeman/tfm/root/usr/share/gems/gems/dynflow-0.8.24/lib/dynflow/middleware/stack.rb:26:in `pass' > /opt/theforeman/tfm/root/usr/share/gems/gems/dynflow-0.8.24/lib/dynflow/middleware.rb:17:in `pass' > /opt/theforeman/tfm/root/usr/share/gems/gems/dynflow-0.8.24/lib/dynflow/middleware.rb:46:in `finalize_phase' > /opt/theforeman/tfm/root/usr/share/gems/gems/dynflow-0.8.24/lib/dynflow/middleware/stack.rb:22:in `call' > /opt/theforeman/tfm/root/usr/share/gems/gems/dynflow-0.8.24/lib/dynflow/middleware/stack.rb:26:in `pass' > /opt/theforeman/tfm/root/usr/share/gems/gems/dynflow-0.8.24/lib/dynflow/middleware.rb:17:in `pass' > /opt/theforeman/tfm/root/usr/share/gems/gems/dynflow-0.8.24/lib/dynflow/middleware.rb:46:in `finalize_phase' > /opt/theforeman/tfm/root/usr/share/gems/gems/dynflow-0.8.24/lib/dynflow/middleware/stack.rb:22:in `call' > /opt/theforeman/tfm/root/usr/share/gems/gems/dynflow-0.8.24/lib/dynflow/middleware/stack.rb:26:in `pass' > /opt/theforeman/tfm/root/usr/share/gems/gems/dynflow-0.8.24/lib/dynflow

[aruzicka]

Hi,
did you try connecting using the ssh client as the foreman-proxy user using
its ssh key? That would be sudo -u foreman-proxy ssh -i
~foreman-proxy/.ssh/id_rsa_foreman_proxy "${username}:${remote_host}".

From what you provided it seems the connection was closed by the remote
host before the authentication could be carried out, but it is just a
guess. Please let us know if you come across anything that would help shed
some light on this.

– Adam

···

On Fri, Sep 8, 2017 at 2:13 PM, Edgars M. wrote:

Hi

I am trying to setup remote jobs from Katello to clients unfortunately all
SSH remote commands fails with:

1: Error initializing command: IOError - closed stream
2: Exit status: EXCEPTION

The only thing I see on client’s side is:

Connection closed by 10.30.xxx.xxx [preauth]

If I try to do simple ssh with OpenSSH client it works just fine.

Here is the log:

Action:

ForemanRemoteExecutionCore::Actions::RunScript

Input:

{“ssh_user”=>“redacted-username”,
“effective_user”=>“root”,
“effective_user_method”=>“sudo”,
“ssh_port”=>22,
“hostname”=>“some_hostname”,
“script”=>“uptime”,
“execution_timeout_interval”=>nil,
“task_id”=>“9f4b7f1e-92e0-4b50-afad-1356f4821595”,
“locale”=>“en”}

Output:

{“result”=>
[{“output_type”=>“debug”,
“output”=>“Error initializing command: IOError - closed stream”,
“timestamp”=>1504872104.755812}],
“runner_id”=>“289b1675-3a4f-4a85-af90-68d84c9f4e9b”,
“exit_status”=>“EXCEPTION”}

Exception:

StandardError: Script execution failed

Backtrace:

/opt/theforeman/tfm/root/usr/share/gems/gems/algebrick-0.7.3/lib/algebrick/matchers/abstract.rb:74:in block in assigns' /opt/theforeman/tfm/root/usr/share/gems/gems/algebrick-0.7.3/lib/algebrick/matchers/abstract.rb:73:intap’
/opt/theforeman/tfm/root/usr/share/gems/gems/algebrick-0.7.3/lib/algebrick/matchers/abstract.rb:73:in assigns' /opt/theforeman/tfm/root/usr/share/gems/gems/algebrick-0.7.3/lib/algebrick/matching.rb:56:inmatch_value’
/opt/theforeman/tfm/root/usr/share/gems/gems/algebrick-0.7.3/lib/algebrick/matching.rb:36:in block in match?' /opt/theforeman/tfm/root/usr/share/gems/gems/algebrick-0.7.3/lib/algebrick/matching.rb:35:ineach’
/opt/theforeman/tfm/root/usr/share/gems/gems/algebrick-0.7.3/lib/algebrick/matching.rb:35:in match?' /opt/theforeman/tfm/root/usr/share/gems/gems/algebrick-0.7.3/lib/algebrick/matching.rb:23:inmatch’
/opt/theforeman/tfm/root/usr/share/gems/gems/dynflow-0.8.24/lib/dynflow/execution_plan/steps/error.rb:12:in new' /opt/theforeman/tfm/root/usr/share/gems/gems/dynflow-0.8.24/lib/dynflow/action.rb:454:inset_error’
/opt/theforeman/tfm/root/usr/share/gems/gems/dynflow-0.8.24/lib/dynflow/action.rb:417:in error!' /opt/theforeman/tfm/root/usr/share/gems/gems/foreman-tasks-core-0.1.4/lib/foreman_tasks_core/runner/action.rb:25:infinalize’
/opt/theforeman/tfm/root/usr/share/gems/gems/dynflow-0.8.24/lib/dynflow/action.rb:534:in block (2 levels) in execute_finalize' /opt/theforeman/tfm/root/usr/share/gems/gems/dynflow-0.8.24/lib/dynflow/middleware/stack.rb:26:incall’
/opt/theforeman/tfm/root/usr/share/gems/gems/dynflow-0.8.24/lib/dynflow/middleware/stack.rb:26:in pass' /opt/theforeman/tfm/root/usr/share/gems/gems/dynflow-0.8.24/lib/dynflow/middleware.rb:17:inpass’
/opt/theforeman/tfm/root/usr/share/gems/gems/dynflow-0.8.24/lib/dynflow/action/progress.rb:30:in with_progress_calculation' /opt/theforeman/tfm/root/usr/share/gems/gems/dynflow-0.8.24/lib/dynflow/action/progress.rb:22:infinalize’
/opt/theforeman/tfm/root/usr/share/gems/gems/dynflow-0.8.24/lib/dynflow/middleware/stack.rb:22:in call' /opt/theforeman/tfm/root/usr/share/gems/gems/dynflow-0.8.24/lib/dynflow/middleware/stack.rb:26:inpass’
/opt/theforeman/tfm/root/usr/share/gems/gems/dynflow-0.8.24/lib/dynflow/middleware.rb:17:in pass' /opt/theforeman/tfm/root/usr/share/gems/gems/katello-3.4.5/app/lib/actions/middleware/keep_locale.rb:15:inblock in finalize’
/opt/theforeman/tfm/root/usr/share/gems/gems/katello-3.4.5/app/lib/actions/middleware/keep_locale.rb:22:in with_locale' /opt/theforeman/tfm/root/usr/share/gems/gems/katello-3.4.5/app/lib/actions/middleware/keep_locale.rb:15:infinalize’
/opt/theforeman/tfm/root/usr/share/gems/gems/dynflow-0.8.24/lib/dynflow/middleware/stack.rb:22:in call' /opt/theforeman/tfm/root/usr/share/gems/gems/dynflow-0.8.24/lib/dynflow/middleware/stack.rb:26:inpass’
/opt/theforeman/tfm/root/usr/share/gems/gems/dynflow-0.8.24/lib/dynflow/middleware.rb:17:in pass' /opt/theforeman/tfm/root/usr/share/gems/gems/dynflow-0.8.24/lib/dynflow/middleware.rb:38:infinalize’
/opt/theforeman/tfm/root/usr/share/gems/gems/dynflow-0.8.24/lib/dynflow/middleware/stack.rb:22:in call' /opt/theforeman/tfm/root/usr/share/gems/gems/dynflow-0.8.24/lib/dynflow/middleware/world.rb:30:inexecute’
/opt/theforeman/tfm/root/usr/share/gems/gems/dynflow-0.8.24/lib/dynflow/action.rb:533:in block in execute_finalize' /opt/theforeman/tfm/root/usr/share/gems/gems/dynflow-0.8.24/lib/dynflow/action.rb:425:incall’
/opt/theforeman/tfm/root/usr/share/gems/gems/dynflow-0.8.24/lib/dynflow/action.rb:425:in block in with_error_handling' /opt/theforeman/tfm/root/usr/share/gems/gems/dynflow-0.8.24/lib/dynflow/action.rb:425:incatch’
/opt/theforeman/tfm/root/usr/share/gems/gems/dynflow-0.8.24/lib/dynflow/action.rb:425:in with_error_handling' /opt/theforeman/tfm/root/usr/share/gems/gems/dynflow-0.8.24/lib/dynflow/action.rb:532:inexecute_finalize’
/opt/theforeman/tfm/root/usr/share/gems/gems/dynflow-0.8.24/lib/dynflow/action.rb:266:in execute' /opt/theforeman/tfm/root/usr/share/gems/gems/dynflow-0.8.24/lib/dynflow/execution_plan/steps/abstract_flow_step.rb:9:inblock (2 levels) in execute’
/opt/theforeman/tfm/root/usr/share/gems/gems/dynflow-0.8.24/lib/dynflow/execution_plan/steps/abstract.rb:155:in call' /opt/theforeman/tfm/root/usr/share/gems/gems/dynflow-0.8.24/lib/dynflow/execution_plan/steps/abstract.rb:155:inwith_meta_calculation’
/opt/theforeman/tfm/root/usr/share/gems/gems/dynflow-0.8.24/lib/dynflow/execution_plan/steps/abstract_flow_step.rb:8:in block in execute' /opt/theforeman/tfm/root/usr/share/gems/gems/dynflow-0.8.24/lib/dynflow/execution_plan/steps/abstract_flow_step.rb:22:inopen_action’
/opt/theforeman/tfm/root/usr/share/gems/gems/dynflow-0.8.24/lib/dynflow/execution_plan/steps/abstract_flow_step.rb:7:in execute' /opt/theforeman/tfm/root/usr/share/gems/gems/dynflow-0.8.24/lib/dynflow/director/sequential_manager.rb:68:inrun_step’
/opt/theforeman/tfm/root/usr/share/gems/gems/dynflow-0.8.24/lib/dynflow/director/sequential_manager.rb:53:in dispatch' /opt/theforeman/tfm/root/usr/share/gems/gems/dynflow-0.8.24/lib/dynflow/director/sequential_manager.rb:60:inblock in run_in_sequence’
/opt/theforeman/tfm/root/usr/share/gems/gems/dynflow-0.8.24/lib/dynflow/director/sequential_manager.rb:60:in each' /opt/theforeman/tfm/root/usr/share/gems/gems/dynflow-0.8.24/lib/dynflow/director/sequential_manager.rb:60:inall?’
/opt/theforeman/tfm/root/usr/share/gems/gems/dynflow-0.8.24/lib/dynflow/director/sequential_manager.rb:60:in run_in_sequence' /opt/theforeman/tfm/root/usr/share/gems/gems/dynflow-0.8.24/lib/dynflow/director/sequential_manager.rb:49:indispatch’
/opt/theforeman/tfm/root/usr/share/gems/gems/dynflow-0.8.24/lib/dynflow/director/sequential_manager.rb:27:in block in finalize' /opt/theforeman/tfm/root/usr/share/gems/gems/dynflow-0.8.24/lib/dynflow/middleware/stack.rb:26:incall’
/opt/theforeman/tfm/root/usr/share/gems/gems/dynflow-0.8.24/lib/dynflow/middleware/stack.rb:26:in pass' /opt/theforeman/tfm/root/usr/share/gems/gems/dynflow-0.8.24/lib/dynflow/middleware.rb:17:inpass’
/opt/theforeman/tfm/root/usr/share/gems/gems/dynflow-0.8.24/lib/dynflow/middleware.rb:46:in finalize_phase' /opt/theforeman/tfm/root/usr/share/gems/gems/dynflow-0.8.24/lib/dynflow/middleware/stack.rb:22:incall’
/opt/theforeman/tfm/root/usr/share/gems/gems/dynflow-0.8.24/lib/dynflow/middleware/stack.rb:26:in pass' /opt/theforeman/tfm/root/usr/share/gems/gems/dynflow-0.8.24/lib/dynflow/middleware.rb:17:inpass’
/opt/theforeman/tfm/root/usr/share/gems/gems/dynflow-0.8.24/lib/dynflow/middleware.rb:46:in finalize_phase' /opt/theforeman/tfm/root/usr/share/gems/gems/dynflow-0.8.24/lib/dynflow/middleware/stack.rb:22:incall’
/opt/theforeman/tfm/root/usr/share/gems/gems/dynflow-0.8.24/lib/dynflow/middleware/stack.rb:26:in pass' /opt/theforeman/tfm/root/usr/share/gems/gems/dynflow-0.8.24/lib/dynflow/middleware.rb:17:inpass’
/opt/theforeman/tfm/root/usr/share/gems/gems/dynflow-0.8.24/lib/dynflow/middleware/common/transaction.rb:16:in block in rollback_on_error' /opt/rh/sclo-ror42/root/usr/share/gems/gems/activerecord-4.2.5.1/lib/active_record/connection_adapters/abstract/database_statements.rb:213:inblock in transaction’
/opt/rh/sclo-ror42/root/usr/share/gems/gems/activerecord-4.2.5.1/lib/active_record/connection_adapters/abstract/transaction.rb:184:in within_new_transaction' /opt/rh/sclo-ror42/root/usr/share/gems/gems/activerecord-4.2.5.1/lib/active_record/connection_adapters/abstract/database_statements.rb:213:intransaction’
/opt/rh/sclo-ror42/root/usr/share/gems/gems/activerecord-4.2.5.1/lib/active_record/transactions.rb:220:in transaction' /opt/theforeman/tfm/root/usr/share/gems/gems/dynflow-0.8.24/lib/dynflow/transaction_adapters/active_record.rb:5:intransaction’
/opt/theforeman/tfm/root/usr/share/gems/gems/dynflow-0.8.24/lib/dynflow/middleware/common/transaction.rb:15:in rollback_on_error' /opt/theforeman/tfm/root/usr/share/gems/gems/dynflow-0.8.24/lib/dynflow/middleware/common/transaction.rb:9:infinalize_phase’
/opt/theforeman/tfm/root/usr/share/gems/gems/dynflow-0.8.24/lib/dynflow/middleware/stack.rb:22:in call' /opt/theforeman/tfm/root/usr/share/gems/gems/dynflow-0.8.24/lib/dynflow/middleware/world.rb:30:inexecute’
/opt/theforeman/tfm/root/usr/share/gems/gems/dynflow-0.8.24/lib/dynflow/director/sequential_manager.rb:26:in finalize' /opt/theforeman/tfm/root/usr/share/gems/gems/dynflow-0.8.24/lib/dynflow/director.rb:66:inexecute’
/opt/theforeman/tfm/root/usr/share/gems/gems/dynflow-0.8.24/lib/dynflow/executors/parallel/worker.rb:11:in on_message' /opt/theforeman/tfm/root/usr/share/gems/gems/concurrent-ruby-edge-0.2.3/lib/concurrent/actor/context.rb:46:inon_envelope’
/opt/theforeman/tfm/root/usr/share/gems/gems/concurrent-ruby-edge-0.2.3/lib/concurrent/actor/behaviour/executes_context.rb:7:in on_envelope' /opt/theforeman/tfm/root/usr/share/gems/gems/concurrent-ruby-edge-0.2.3/lib/concurrent/actor/behaviour/abstract.rb:25:inpass’
/opt/theforeman/tfm/root/usr/share/gems/gems/dynflow-0.8.24/lib/dynflow/actor.rb:26:in on_envelope' /opt/theforeman/tfm/root/usr/share/gems/gems/concurrent-ruby-edge-0.2.3/lib/concurrent/actor/behaviour/abstract.rb:25:inpass’
/opt/theforeman/tfm/root/usr/share/gems/gems/concurrent-ruby-edge-0.2.3/lib/concurrent/actor/behaviour/awaits.rb:15:in on_envelope' /opt/theforeman/tfm/root/usr/share/gems/gems/concurrent-ruby-edge-0.2.3/lib/concurrent/actor/behaviour/abstract.rb:25:inpass’
/opt/theforeman/tfm/root/usr/share/gems/gems/concurrent-ruby-edge-0.2.3/lib/concurrent/actor/behaviour/sets_results.rb:14:in on_envelope' /opt/theforeman/tfm/root/usr/share/gems/gems/concurrent-ruby-edge-0.2.3/lib/concurrent/actor/behaviour/abstract.rb:25:inpass’
/opt/theforeman/tfm/root/usr/share/gems/gems/concurrent-ruby-edge-0.2.3/lib/concurrent/actor/behaviour/buffer.rb:38:in process_envelope' /opt/theforeman/tfm/root/usr/share/gems/gems/concurrent-ruby-edge-0.2.3/lib/concurrent/actor/behaviour/buffer.rb:31:inprocess_envelopes?’
/opt/theforeman/tfm/root/usr/share/gems/gems/concurrent-ruby-edge-0.2.3/lib/concurrent/actor/behaviour/buffer.rb:20:in on_envelope' /opt/theforeman/tfm/root/usr/share/gems/gems/concurrent-ruby-edge-0.2.3/lib/concurrent/actor/behaviour/abstract.rb:25:inpass’
/opt/theforeman/tfm/root/usr/share/gems/gems/concurrent-ruby-edge-0.2.3/lib/concurrent/actor/behaviour/termination.rb:55:in on_envelope' /opt/theforeman/tfm/root/usr/share/gems/gems/concurrent-ruby-edge-0.2.3/lib/concurrent/actor/behaviour/abstract.rb:25:inpass’
/opt/theforeman/tfm/root/usr/share/gems/gems/concurrent-ruby-edge-0.2.3/lib/concurrent/actor/behaviour/removes_child.rb:10:in on_envelope' /opt/theforeman/tfm/root/usr/share/gems/gems/concurrent-ruby-edge-0.2.3/lib/concurrent/actor/behaviour/abstract.rb:25:inpass’
/opt/theforeman/tfm/root/usr/share/gems/gems/concurrent-ruby-edge-0.2.3/lib/concurrent/actor/behaviour/sets_results.rb:14:in on_envelope' /opt/theforeman/tfm/root/usr/share/gems/gems/concurrent-ruby-edge-0.2.3/lib/concurrent/actor/core.rb:161:inprocess_envelope’
/opt/theforeman/tfm/root/usr/share/gems/gems/concurrent-ruby-edge-0.2.3/lib/concurrent/actor/core.rb:95:in block in on_envelope' /opt/theforeman/tfm/root/usr/share/gems/gems/concurrent-ruby-edge-0.2.3/lib/concurrent/actor/core.rb:118:inblock (2 levels) in schedule_execution’
/opt/theforeman/tfm/root/usr/share/gems/gems/concurrent-ruby-1.0.3/lib/concurrent/synchronization/mri_lockable_object.rb:38:in block in synchronize' /opt/theforeman/tfm/root/usr/share/gems/gems/concurrent-ruby-1.0.3/lib/concurrent/synchronization/mri_lockable_object.rb:38:insynchronize’
/opt/theforeman/tfm/root/usr/share/gems/gems/concurrent-ruby-1.0.3/lib/concurrent/synchronization/mri_lockable_object.rb:38:in synchronize' /opt/theforeman/tfm/root/usr/share/gems/gems/concurrent-ruby-edge-0.2.3/lib/concurrent/actor/core.rb:115:inblock in schedule_execution’
/opt/theforeman/tfm/root/usr/share/gems/gems/concurrent-ruby-1.0.3/lib/concurrent/executor/serialized_execution.rb:18:in call' /opt/theforeman/tfm/root/usr/share/gems/gems/concurrent-ruby-1.0.3/lib/concurrent/executor/serialized_execution.rb:18:incall’
/opt/theforeman/tfm/root/usr/share/gems/gems/concurrent-ruby-1.0.3/lib/concurrent/executor/serialized_execution.rb:96:in work' /opt/theforeman/tfm/root/usr/share/gems/gems/concurrent-ruby-1.0.3/lib/concurrent/executor/serialized_execution.rb:77:inblock in call_job’
/opt/theforeman/tfm/root/usr/share/gems/gems/concurrent-ruby-1.0.3/lib/concurrent/executor/ruby_thread_pool_executor.rb:348:in call' /opt/theforeman/tfm/root/usr/share/gems/gems/concurrent-ruby-1.0.3/lib/concurrent/executor/ruby_thread_pool_executor.rb:348:inrun_task’
/opt/theforeman/tfm/root/usr/share/gems/gems/concurrent-ruby-1.0.3/lib/concurrent/executor/ruby_thread_pool_executor.rb:337:in block (3 levels) in create_worker' /opt/theforeman/tfm/root/usr/share/gems/gems/concurrent-ruby-1.0.3/lib/concurrent/executor/ruby_thread_pool_executor.rb:320:inloop’
/opt/theforeman/tfm/root/usr/share/gems/gems/concurrent-ruby-1.0.3/lib/concurrent/executor/ruby_thread_pool_executor.rb:320:in block (2 levels) in create_worker' /opt/theforeman/tfm/root/usr/share/gems/gems/concurrent-ruby-1.0.3/lib/concurrent/executor/ruby_thread_pool_executor.rb:319:incatch’
/opt/theforeman/tfm/root/usr/share/gems/gems/concurrent-ruby-1.0.3/lib/concurrent/executor/ruby_thread_pool_executor.rb:319:in block in create_worker' /opt/theforeman/tfm/root/usr/share/gems/gems/logging-1.8.2/lib/logging/diagnostic_context.rb:323:incall’
/opt/theforeman/tfm/root/usr/share/gems/gems/logging-1.8.2/lib/logging/diagnostic_context.rb:323:in `block in create_with_logging_context’

–
You received this message because you are subscribed to the Google Groups
"Foreman users" group.
To unsubscribe from this group and stop receiving emails from it, send an
email to foreman-users+unsubscribe@googlegroups.com.
To post to this group, send email to foreman-users@googlegroups.com.
Visit this group at https://groups.google.com/group/foreman-users.
For more options, visit https://groups.google.com/d/optout.

[Edgars_M]

Hi Adam

Yes, when I am using OpenSSH client from Katello server to remote client,
everything works just fine:

[admin@katello-server.fqdn ~]$ sudo -u foreman-proxy ssh -i
~foreman-proxy/.ssh/id_rsa_foreman_proxy "admin@client.fqdn"

WARNING: Unauthorized access to this system is forbidden and will be
prosecuted by law. By accessing this system, you agree that your
actions may be monitored if unauthorized usage is suspected.

Last login: Mon Sep 11 10:07:34 2017 from 10.30.177.36
[admin@client.fqdn ~]$ exit
logout
Connection to client.fqdn closed.

···

On Monday, September 11, 2017 at 9:55:57 AM UTC+3, Adam Ruzicka wrote: > > Hi, > did you try connecting using the ssh client as the foreman-proxy user > using its ssh key? That would be sudo -u foreman-proxy ssh -i > ~foreman-proxy/.ssh/id_rsa_foreman_proxy "${username}:${remote_host}". > > From what you provided it seems the connection was closed by the remote > host before the authentication could be carried out, but it is just a > guess. Please let us know if you come across anything that would help shed > some light on this. > > -- Adam > > On Fri, Sep 8, 2017 at 2:13 PM, Edgars M. > wrote: > >> Hi >> >> I am trying to setup remote jobs from Katello to clients unfortunately >> all SSH remote commands fails with: >> >> 1: Error initializing command: IOError - closed stream >> 2: Exit status: EXCEPTION >> >> The only thing I see on client's side is: >> >> Connection closed by 10.30.xxx.xxx [preauth] >> >> If I try to do simple ssh with OpenSSH client it works just fine. >> >> Here is the log: >> >> Action: >> >> ForemanRemoteExecutionCore::Actions::RunScript >> >> Input: >> >> {"ssh_user"=>"redacted-username", >> "effective_user"=>"root", >> "effective_user_method"=>"sudo", >> "ssh_port"=>22, >> "hostname"=>"some_hostname", >> "script"=>"uptime", >> "execution_timeout_interval"=>nil, >> "task_id"=>"9f4b7f1e-92e0-4b50-afad-1356f4821595", >> "locale"=>"en"} >> >> Output: >> >> {"result"=> >> [{"output_type"=>"debug", >> "output"=>"Error initializing command: IOError - closed stream", >> "timestamp"=>1504872104.755812}], >> "runner_id"=>"289b1675-3a4f-4a85-af90-68d84c9f4e9b", >> "exit_status"=>"EXCEPTION"} >> >> Exception: >> >> StandardError: Script execution failed >> >> Backtrace: >> >> /opt/theforeman/tfm/root/usr/share/gems/gems/algebrick-0.7.3/lib/algebrick/matchers/abstract.rb:74:in `block in assigns' >> /opt/theforeman/tfm/root/usr/share/gems/gems/algebrick-0.7.3/lib/algebrick/matchers/abstract.rb:73:in `tap' >> /opt/theforeman/tfm/root/usr/share/gems/gems/algebrick-0.7.3/lib/algebrick/matchers/abstract.rb:73:in `assigns' >> /opt/theforeman/tfm/root/usr/share/gems/gems/algebrick-0.7.3/lib/algebrick/matching.rb:56:in `match_value' >> /opt/theforeman/tfm/root/usr/share/gems/gems/algebrick-0.7.3/lib/algebrick/matching.rb:36:in `block in match?' >> /opt/theforeman/tfm/root/usr/share/gems/gems/algebrick-0.7.3/lib/algebrick/matching.rb:35:in `each' >> /opt/theforeman/tfm/root/usr/share/gems/gems/algebrick-0.7.3/lib/algebrick/matching.rb:35:in `match?' >> /opt/theforeman/tfm/root/usr/share/gems/gems/algebrick-0.7.3/lib/algebrick/matching.rb:23:in `match' >> /opt/theforeman/tfm/root/usr/share/gems/gems/dynflow-0.8.24/lib/dynflow/execution_plan/steps/error.rb:12:in `new' >> /opt/theforeman/tfm/root/usr/share/gems/gems/dynflow-0.8.24/lib/dynflow/action.rb:454:in `set_error' >> /opt/theforeman/tfm/root/usr/share/gems/gems/dynflow-0.8.24/lib/dynflow/action.rb:417:in `error!' >> /opt/theforeman/tfm/root/usr/share/gems/gems/foreman-tasks-core-0.1.4/lib/foreman_tasks_core/runner/action.rb:25:in `finalize' >> /opt/theforeman/tfm/root/usr/share/gems/gems/dynflow-0.8.24/lib/dynflow/action.rb:534:in `block (2 levels) in execute_finalize' >> /opt/theforeman/tfm/root/usr/share/gems/gems/dynflow-0.8.24/lib/dynflow/middleware/stack.rb:26:in `call' >> /opt/theforeman/tfm/root/usr/share/gems/gems/dynflow-0.8.24/lib/dynflow/middleware/stack.rb:26:in `pass' >> /opt/theforeman/tfm/root/usr/share/gems/gems/dynflow-0.8.24/lib/dynflow/middleware.rb:17:in `pass' >> /opt/theforeman/tfm/root/usr/share/gems/gems/dynflow-0.8.24/lib/dynflow/action/progress.rb:30:in `with_progress_calculation' >> /opt/theforeman/tfm/root/usr/share/gems/gems/dynflow-0.8.24/lib/dynflow/action/progress.rb:22:in `finalize' >> /opt/theforeman/tfm/root/usr/share/gems/gems/dynflow-0.8.24/lib/dynflow/middleware/stack.rb:22:in `call' >> /opt/theforeman/tfm/root/usr/share/gems/gems/dynflow-0.8.24/lib/dynflow/middleware/stack.rb:26:in `pass' >> /opt/theforeman/tfm/root/usr/share/gems/gems/dynflow-0.8.24/lib/dynflow/middleware.rb:17:in `pass' >> /opt/theforeman/tfm/root/usr/share/gems/gems/katello-3.4.5/app/lib/actions/middleware/keep_locale.rb:15:in `block in finalize' >> /opt/theforeman/tfm/root/usr/share/gems/gems/katello-3.4.5/app/lib/actions/middleware/keep_locale.rb:22:in `with_locale' >> /opt/theforeman/tfm/root/usr/share/gems/gems/katello-3.4.5/app/lib/actions/middleware/keep_locale.rb:15:in `finalize' >> /opt/theforeman/tfm/root/usr/share/gems/gems/dynflow-0.8.24/lib/dynflow/middleware/stack.rb:22:in `call' >> /opt/theforeman/tfm/root/usr/share/gems/gems/dynflow-0.8.24/lib/dynflow/middleware/stack.rb:26:in `pass' >> /opt/theforeman/tfm/root/usr/share/gems/gems/dynflow-0.8.24/lib/dynflow/middleware.rb:17:in `pass' >> /opt/theforeman/tfm/root/usr/share/gems/gems/dynflow-0.8.24/lib/dynflow/middleware.rb:38:in `finalize' >> /opt/theforeman/tfm/root/usr/share/gems/gems/dynflow-0.8.24/lib/dynflow/middleware/stack.rb:22:in `call' >> /opt/theforeman/tfm/root/usr/share/gems/gems/dynflow-0.8.24/lib/dynflow/middleware/world.rb:30:in `execute' >> /opt/theforeman/tfm/root/usr/share/gems/gems/dynflow-0.8.24/lib/dynflow/action.rb:533:in `block in execute_finalize' >> /opt/theforeman/tfm/root/usr/share/gems/gems/dynflow-0.8.24/lib/dynflow/action.rb:425:in `call' >> /opt/theforeman/tfm/root/usr/share/gems/gems/dynflow-0.8.24/lib/dynflow/action.rb:425:in `block in with_error_handling' >> /opt/theforeman/tfm/root/usr/share/gems/gems/dynflow-0.8.24/lib/dynflow/action.rb:425:in `catch' >> /opt/theforeman/tfm/root/usr/share/gems/gems/dynflow-0.8.24/lib/dynflow/action.rb:425:in `with_error_handling' >> /opt/theforeman/tfm/root/usr/share/gems/gems/dynflow-0.8.24/lib/dynflow/action.rb:532:in `execute_finalize' >> /opt/theforeman/tfm/root/usr/share/gems/gems/dynflow-0.8.24/lib/dynflow/action.rb:266:in `execute' >> /opt/theforeman/tfm/root/usr/share/gems/gems/dynflow-0.8.24/lib/dynflow/execution_plan/steps/abstract_flow_step.rb:9:in `block (2 levels) in execute' >> /opt/theforeman/tfm/root/usr/share/gems/gems/dynflow-0.8.24/lib/dynflow/execution_plan/steps/abstract.rb:155:in `call' >> /opt/theforeman/tfm/root/usr/share/gems/gems/dynflow-0.8.24/lib/dynflow/execution_plan/steps/abstract.rb:155:in `with_meta_calculation' >> /opt/theforeman/tfm/root/usr/share/gems/gems/dynflow-0.8.24/lib/dynflow/execution_plan/steps/abstract_flow_step.rb:8:in `block in execute' >> /opt/theforeman/tfm/root/usr/share/gems/gems/dynflow-0.8.24/lib/dynflow/execution_plan/steps/abstract_flow_step.rb:22:in `open_action' >> /opt/theforeman/tfm/root/usr/share/gems/gems/dynflow-0.8.24/lib/dynflow/execution_plan/steps/abstract_flow_step.rb:7:in `execute' >> /opt/theforeman/tfm/root/usr/share/gems/gems/dynflow-0.8.24/lib/dynflow/director/sequential_manager.rb:68:in `run_step' >> /opt/theforeman/tfm/root/usr/share/gems/gems/dynflow-0.8.24/lib/dynflow/director/sequential_manager.rb:53:in `dispatch' >> /opt/theforeman/tfm/root/usr/share/gems/gems/dynflow-0.8.24/lib/dynflow/director/sequential_manager.rb:60:in `block in run_in_sequence' >> /opt/theforeman/tfm/root/usr/share/gems/gems/dynflow-0.8.24/lib/dynflow/director/sequential_manager.rb:60:in `each' >> /opt/theforeman/tfm/root/usr/share/gems/gems/dynflow-0.8.24/lib/dynflow/director/sequential_manager.rb:60:in `all?' >> /opt/theforeman/tfm/root/usr/share/gems/gems/dynflow-0.8.24/lib/dynflow/director/sequential_manager.rb:60:in `run_in_sequence' >> /opt/theforeman/tfm/root/usr/share/gems/gems/dynflow-0.8.24/lib/dynflow/director/sequential_manager.rb:49:in `dispatch' >> /opt/theforeman/tfm/root/usr/share/gems/gems/dynflow-0.8.24/lib/dynflow/director/sequential_manager.rb:27:in `block in finalize' >> /opt/theforeman/tfm/root/usr/share/gems/gems/dynflow-0.8.24/lib/dynflow/middleware/stack.rb:26:in `call' >> /opt/theforeman/tfm/root/usr/share/gems/gems/dynflow-0.8.24/lib/dynflow/middleware/stack.rb:26:in `pass' >> /opt/theforeman/tfm/root/usr/share/gems/gems/dynflow-0.8.24/lib/dynflow/middleware.rb:17:in `pass' >> /opt/theforeman/tfm/root/usr/share/gems/gems/dynflow-0.8.24/lib/dynflow/middleware.rb:46:in `finalize_phase' >> /opt/theforeman/tfm/root/usr/share/gems/gems/dynflow-0.8.24/lib/dynflow/middleware/stack.rb:22:in `call' >> /opt/theforeman/tfm/root/usr/share/gems/gems/dynflow-0.8.24/lib/dynflow/middleware/stack.rb:26:in `pass' >> /opt/theforeman/tfm/root/usr/share/gems/gems/dynflow-0.8.24/lib/dynflow/middleware.rb:17:in `pass' >> /opt/theforeman/tfm/root/usr/share/gems/gems/dynflow-0.8.24/lib/dynflow/middleware.rb:46:in `finalize_phase' >> /opt/theforeman/tfm/root/usr/share/gems/gems/dynflow-0.8.24/lib/dynflow/middleware/stack.rb:22:in `call' >> /opt/theforeman/tfm/root/usr/share/gems/gems/dynflow-0.8.24/lib/dynflow/middleware/stack.rb:26:in `pass' >> /opt/theforeman/tfm/root/usr/share/gems/gems/dynflow-0.8.24/lib/dynflow/middleware.rb:17:in `pass' >> /opt/theforeman/tfm/root/usr/share/gems/gems/dynflow-0.8.24/lib/dynflow/middleware/common/transaction.rb:16:in `block in rollback_on_error' >> /opt/rh/sclo-ror42/root/usr/share/gems/gems/activerecord-4.2.5.1/lib/active_record/connection_adapters/abstract/database_statements.rb:213:in `block in transaction' >> /opt/rh/sclo-ror42/root/usr/share/gems/gems/activerecord-4.2.5.1/lib/active_record/connection_adapters/abstract/transaction.rb:184:in `within_new_transaction' >> /opt/rh/sclo-ror42/root/usr/share/gems/gems/activerecord-4.2.5.1/lib/active_record/connection_adapters/abstract/database_statements.rb:213:in `transaction' >> /opt/rh/sclo-ror42/root/usr/share/gems/gems/activerecord-4.2.5.1/lib/active_record/transactions.rb:220:in `transaction' >> /opt/theforeman/tfm/root/usr/share/gems/gems/dynflow-0.8.24/lib/dynflow/transaction_adapters/active_record.rb:5:in `transaction' >> /opt/theforeman/tfm/root/usr/share/gems/gems/dynflow-0.8.24/lib/dynflow/middleware/common/transaction.rb:15:in `rollback_on_error' >> /opt/theforeman/tfm/root/usr/share/gems/gems/dynflow-0.8.24/lib/dynflow/middleware/common/transaction.rb:9:in `finalize_phase' >> /opt/theforeman/tfm/root/usr/share/gems/gems/dynflow-0.8.24/lib/dynflow/middleware/stack.rb:22:in `call' >> /opt/theforeman/tfm/root/usr/share/gems/gems/dynflow-0.8.24/lib/dynflow/middleware/world.rb:30:in `execute' >> /opt/theforeman/tfm/root/usr/share/gems/gems/dynflow-0.8.24/lib/dynflow/director/sequential_manager.rb:26:in `finalize' >> /opt/theforeman/tfm/root/usr/share/gems/gems/dynflow-0.8.24/lib/dynflow/director.rb:66:in `execute' >> /opt/theforeman/tfm/root/usr/share/gems/gems/dynflow-0.8.24/lib/dynflow/executors/parallel/worker.rb:11:in `on_message' >> /opt/theforeman/tfm/root/usr/share/gems/gems/concurrent-ruby-edge-0.2.3/lib/concurrent/actor/context.rb:46:in `on_envelope' >> /opt/theforeman/tfm/root/usr/share/gems/gems/concurrent-ruby-edge-0.2.3/lib/concurrent/actor/behaviour/executes_context.rb:7:in `on_envelope' >> /opt/theforeman/tfm/root/usr/share/gems/gems/concurrent-ruby-edge-0.2.3/lib/concurrent/actor/behaviour/abstract.rb:25:in `pass' >> /opt/theforeman/tfm/root/usr/share/gems/gems/dynflow-0.8.24/lib/dynflow/actor.rb:26:in `on_envelope' >> /opt/theforeman/tfm/root/usr/share/gems/gems/concurrent-ruby-edge-0.2.3/lib/concurrent/actor/behaviour/abstract.rb:25:in `pass' >> /opt/theforeman/tfm/root/usr/share/gems/gems/concurrent-ruby-edge-0.2.3/lib/concurrent/actor/behaviour/awaits.rb:15:in `on_envelope' >> /opt/theforeman/tfm/root/usr/share/gems/gems/concurrent-ruby-edge-0.2.3/lib/concurrent/actor/behaviour/abstract.rb:25:in `pass' >> /opt/theforeman/tfm/root/usr/share/gems/gems/concurrent-ruby-edge-0.2.3/lib/concurrent/actor/behaviour/sets_results.rb:14:in `on_envelope' >> /opt/theforeman/tfm/root/usr/share/gems/gems/concurrent-ruby-edge-0.2.3/lib/concurrent/actor/behaviour/abstract.rb:25:in `pass' >> /opt/theforeman/tfm/root/usr/share/gems/gems/concurrent-ruby-edge-0.2.3/lib/concurrent/actor/behaviour/buffer.rb:38:in `process_envelope' >> /opt/theforeman/tfm/root/usr/share/gems/gems/concurrent-ruby-edge-0.2.3/lib/concurrent/actor/behaviour/buffer.rb:31:in `process_envelopes?' >> /opt/theforeman/tfm/root/usr/share/gems/gems/concurrent-ruby-edge-0.2.3/lib/concurrent/actor/behaviour/buffer.rb:20:in `on_envelope' >> /opt/theforeman/tfm/root/usr/share/gems/gems/concurrent-ruby-edge-0.2.3/lib/concurrent/actor/behaviour/abstract.rb:25:in `pass' >> /opt/theforeman/tfm/root/usr/share/gems/gems/concurrent-ruby-edge-0.2.3/lib/concurrent/actor/behaviour/termination.rb:55:in `on_envelope' >> /opt/theforeman/tfm/root/usr/share/gems/gems/concurrent-ruby-edge-0.2.3/lib/concurrent/actor/behaviour/abstract.rb:25:in `pass' >> /opt/theforeman/tfm/root/usr/share/gems/gems/concurrent-ruby-edge-0.2.3/lib/concurrent/actor/behaviour/removes_child.rb:10:in `on_envelope' >> /opt/theforeman/tfm/root/usr/share/gems/gems/concurrent-ruby-edge-0.2.3/lib/concurrent/actor/behaviour/abstract.rb:25:in `pass' >> /opt/theforeman/tfm/root/usr/share/gems/gems/concurrent-ruby-edge-0.2.3/lib/concurrent/actor/behaviour/sets_results.rb:14:in `on_envelope' >> /opt/theforeman/tfm/root/usr/share/gems/gems/concurrent-ruby-edge-0.2.3/lib/concurrent/actor/core.rb:161:in `process_envelope' >> /opt/theforeman/tfm/root/usr/share/gems/gems/concurrent-ruby-edge-0.2.3/lib/concurrent/actor/core.rb:95:in `block in on_envelope' >> /opt/theforeman/tfm/root/usr/share/gems/gems/concurrent-ruby-edge-0.2.3/lib/concurrent/actor/core.rb:118:in `block (2 levels) in schedule_execution' >> /opt/theforeman/tfm/root/usr/share/gems/gems/concurrent-ruby-1.0.3/lib/concurrent/synchronization/mri_lockable_object.rb:38:in `block in synchronize' >> /opt/theforeman/tfm/root/usr/share/gems/gems/concurrent-ruby-1.0.3/lib/concurrent/synchronization/mri_lockable_object.rb:38:in `synchronize' >> /opt/theforeman/tfm/root/usr/share/gems/gems/concurrent-ruby-1.0.3/lib/concurrent/synchronization/mri_lockable_object.rb:38:in `synchronize' >> /opt/theforeman/tfm/root/usr/share/gems/gems/concurrent-ruby-edge-0.2.3/lib/concurrent/actor/core.rb:115:in `block in schedule_execution' >> /opt/theforeman/tfm/root/usr/share/gems/gems/concurrent-ruby-1.0.3/lib/concurrent/executor/serialized_execution.rb:18:in `call' >> /opt/theforeman/tfm/root/usr/share/gems/gems/concurrent-ruby-1.0.3/lib/concurrent/executor/serialized_execution.rb:18:in `call' >> /opt/theforeman/tfm/root/usr/share/gems/gems/concurrent-ruby-1.0.3/lib/concurrent/executor/serialized_execution.rb:96:in `work' >> /opt/theforeman/tfm/root/usr/share/gems/gems/concurrent-ruby-1.0.3/lib/concurrent/executor/serialized_execution.rb:77:in `block in call_job' >> /opt/theforeman/tfm/root/usr/share/gems/gems/concurrent-ruby-1.0.3/lib/concurrent/executor/ruby_thread_pool_executor.rb:348:in `call' >> /opt/theforeman/tfm/root/usr/share/gems/gems/concurrent-ruby-1.0.3/lib/concurrent/executor/ruby_thread_pool_executor.rb:348:in `run_task' >> /opt/theforeman/tfm/root/usr/share/gems/gems/concurrent-ruby-1.0.3/lib/concurrent/executor/ruby_thread_pool_executor.rb:337:in `block (3 levels) in create_worker' >> /opt/theforeman/tfm/root/usr/share/gems/gems/concurrent-ruby-1.0.3/lib/concurrent/executor/ruby_thread_pool_executor.rb:320:in `loop' >> /opt/theforeman/tfm/root/usr/share/gems/gems/concurrent-ruby-1.0.3/lib/concurrent/executor/ruby_thread_pool_executor.rb:320:in `block (2 levels) in create_worker' >> /opt/theforeman/tfm/root/usr/share/gems/gems/concurrent-ruby-1.0.3/lib/concurrent/executor/ruby_thread_pool_executor.rb:319:in `catch' >> /opt/theforeman/tfm/root/usr/share/gems/gems/concurrent-ruby-1.0.3/lib/concurrent/executor/ruby_thread_pool_executor.rb:319:in `block in create_worker' >> /opt/theforeman/tfm/root/usr/share/gems/gems/logging-1.8.2/lib/logging/diagnostic_context.rb:323:in `call' >> /opt/theforeman/tfm/root/usr/share/gems/gems/logging-1.8.2/lib/logging/diagnostic_context.rb:323:in `block in create_with_logging_context' >> >> >> >> -- >> You received this message because you are subscribed to the Google Groups >> "Foreman users" group. >> To unsubscribe from this group and stop receiving emails from it, send an >> email to foreman-user...@googlegroups.com . >> To post to this group, send email to forema...@googlegroups.com >> . >> Visit this group at https://groups.google.com/group/foreman-users. >> For more options, visit https://groups.google.com/d/optout. >> > >

[aruzicka]

This is definitely not expected behavior. It should try to connect to the
agent and either use it or continue without it. Could you please file an
issue in our redmine[1]? Thanks

[1] - Overview - Foreman Remote Execution - Foreman

– Adam

···

On Mon, Sep 11, 2017 at 11:12 AM, Edgars M. wrote:

Hi

I did some testing and here is what I found. I took this script from the
Internet, modified it and ran:

require 'rubygems’
require ‘net/ssh’

Net::SSH.start(‘client.fqdn’, ‘admin’, :keys =>
[’/usr/share/foreman-proxy/.ssh/id_rsa_foreman_proxy’], :verbose =>
:debug, :forward_agent => true ) do |ssh|
output = ssh.exec!(“hostname -f”)
puts output
end

And this was the output:
<…>
D, [2017-09-11T12:01:20.674105 #11798] DEBUG – net.ssh.authentication.session[905b78]:
allowed methods: publickey
D, [2017-09-11T12:01:20.674154 #11798] DEBUG – net.ssh.authentication.methods.none[8f1dd0]:
none failed
D, [2017-09-11T12:01:20.674193 #11798] DEBUG – net.ssh.authentication.session[905b78]:
trying publickey
D, [2017-09-11T12:01:20.674265 #11798] DEBUG –
net.ssh.authentication.agent[804314]: connecting to ssh-agent
E, [2017-09-11T12:01:20.674305 #11798] ERROR –
net.ssh.authentication.agent[804314]: could not connect to ssh-agent:
Agent not configured
E, [2017-09-11T12:01:20.674331 #11798] ERROR – net.ssh.authentication.session[905b78]:
all authorization methods failed (tried none, publickey)
/opt/theforeman/tfm/root/usr/share/gems/gems/net-ssh-4.0.1/
lib/net/ssh/transport/session.rb:128:in close': closed stream (IOError) from /opt/theforeman/tfm/root/usr/share/gems/gems/net-ssh-4.0.1/ lib/net/ssh/transport/session.rb:128:inclose’
from /opt/theforeman/tfm/root/usr/share/gems/gems/net-ssh-4.0.1/lib/net/ssh.rb:253:in
rescue in start' from /opt/theforeman/tfm/root/usr/share/gems/gems/net-ssh-4.0.1/lib/net/ssh.rb:205:instart’

So it seems that Ruby SSH client is trying to connect to ssh-agent. So
here is what I did next on Katello server:

[admin@katello-server.fqdn ~]$ sudo -u foreman-proxy ssh-agent bash
bash-4.2$ ssh-add /usr/share/foreman-proxy/.ssh/id_rsa_foreman_proxy
Identity added: /usr/share/foreman-proxy/.ssh/id_rsa_foreman_proxy
(/usr/share/foreman-proxy/.ssh/id_rsa_foreman_proxy)

and then ran script again and everything worked!
bash-4.2$ ruby193-ruby /opt/sshtest.rb
D, [2017-09-11T12:05:07.462362 #12073] DEBUG – net.ssh.transport.session[d4b6c4]:
establishing connection to client.fqdn:22
D, [2017-09-11T12:05:07.463975 #12073] DEBUG – net.ssh.transport.session[d4b6c4]:
connection established
I, [2017-09-11T12:05:07.464038 #12073] INFO – net.ssh.transport.server_version[d4ab5c]:
negotiating protocol version
D, [2017-09-11T12:05:07.464059 #12073] DEBUG – net.ssh.transport.server_version[d4ab5c]:
local is SSH-2.0-Ruby/Net::SSH_4.0.1 x86_64-linux' D, [2017-09-11T12:05:07.472592 #12073] DEBUG -- net.ssh.transport.server_version[d4ab5c]: remote isSSH-2.0-OpenSSH_6.6.1’
I, [2017-09-11T12:05:07.473015 #12073] INFO –
net.ssh.transport.algorithms[d3fb08]: sending KEXINIT
D, [2017-09-11T12:05:07.473164 #12073] DEBUG – socket[d4b2dc]: queueing
packet nr 0 type 20 len 1156
D, [2017-09-11T12:05:07.473218 #12073] DEBUG – socket[d4b2dc]: sent 1160
bytes
D, [2017-09-11T12:05:07.473473 #12073] DEBUG – socket[d4b2dc]: read 336
bytes
D, [2017-09-11T12:05:07.473528 #12073] DEBUG – socket[d4b2dc]: received
packet nr 0 type 20 len 332
I, [2017-09-11T12:05:07.473559 #12073] INFO –
net.ssh.transport.algorithms[d3fb08]: got KEXINIT from server
I, [2017-09-11T12:05:07.473620 #12073] INFO –
net.ssh.transport.algorithms[d3fb08]: negotiating algorithms
D, [2017-09-11T12:05:07.473705 #12073] DEBUG –
net.ssh.transport.algorithms[d3fb08]: negotiated:

• kex: diffie-hellman-group14-sha1
• host_key: ecdsa-sha2-nistp256
• encryption_server: aes128-ctr
• encryption_client: aes128-ctr
• hmac_client: hmac-sha2-256
• hmac_server: hmac-sha2-256
• compression_client: none
• compression_server: none
• language_client:
• language_server:
  D, [2017-09-11T12:05:07.473730 #12073] DEBUG –
  net.ssh.transport.algorithms[d3fb08]: exchanging keys
  D, [2017-09-11T12:05:07.480944 #12073] DEBUG – socket[d4b2dc]: queueing
  packet nr 1 type 30 len 268
  D, [2017-09-11T12:05:07.480998 #12073] DEBUG – socket[d4b2dc]: sent 272
  bytes
  D, [2017-09-11T12:05:07.482845 #12073] DEBUG – socket[d4b2dc]: read 504
  bytes
  D, [2017-09-11T12:05:07.482917 #12073] DEBUG – socket[d4b2dc]: received
  packet nr 1 type 31 len 484
  D, [2017-09-11T12:05:07.484437 #12073] DEBUG – socket[d4b2dc]: queueing
  packet nr 2 type 21 len 20
  D, [2017-09-11T12:05:07.484491 #12073] DEBUG – socket[d4b2dc]: sent 24
  bytes
  D, [2017-09-11T12:05:07.484547 #12073] DEBUG – socket[d4b2dc]: received
  packet nr 2 type 21 len 12
  D, [2017-09-11T12:05:07.484810 #12073] DEBUG – net.ssh.authentication.session[96bb30]:
  beginning authentication of `admin’
  D, [2017-09-11T12:05:07.485013 #12073] DEBUG – socket[d4b2dc]: queueing
  packet nr 3 type 5 len 28
  D, [2017-09-11T12:05:07.485072 #12073] DEBUG – socket[d4b2dc]: sent 64
  bytes
  D, [2017-09-11T12:05:07.524301 #12073] DEBUG – socket[d4b2dc]: read 64
  bytes
  D, [2017-09-11T12:05:07.524450 #12073] DEBUG – socket[d4b2dc]: received
  packet nr 3 type 6 len 28
  D, [2017-09-11T12:05:07.524556 #12073] DEBUG – net.ssh.authentication.session[96bb30]:
  trying none
  D, [2017-09-11T12:05:07.525420 #12073] DEBUG – socket[d4b2dc]: queueing
  packet nr 4 type 50 len 44
  D, [2017-09-11T12:05:07.525490 #12073] DEBUG – socket[d4b2dc]: sent 80
  bytes
  D, [2017-09-11T12:05:07.528362 #12073] DEBUG – socket[d4b2dc]: read 320
  bytes
  D, [2017-09-11T12:05:07.528552 #12073] DEBUG – socket[d4b2dc]: received
  packet nr 4 type 53 len 220
  I, [2017-09-11T12:05:07.528612 #12073] INFO – net.ssh.authentication.
  session[96bb30]:
  WARNING: Unauthorized access to this system is forbidden and will be
  prosecuted by law. By accessing this system, you agree that your
  actions may be monitored if unauthorized usage is suspected.

D, [2017-09-11T12:05:07.528700 #12073] DEBUG – socket[d4b2dc]: received
packet nr 5 type 51 len 28
D, [2017-09-11T12:05:07.529156 #12073] DEBUG – net.ssh.authentication.session[96bb30]:
allowed methods: publickey
D, [2017-09-11T12:05:07.529226 #12073] DEBUG – net.ssh.authentication.methods.none[963278]:
none failed
D, [2017-09-11T12:05:07.529274 #12073] DEBUG – net.ssh.authentication.session[96bb30]:
trying publickey
D, [2017-09-11T12:05:07.529476 #12073] DEBUG –
net.ssh.authentication.agent[97cc28]: connecting to ssh-agent
D, [2017-09-11T12:05:07.529566 #12073] DEBUG –
net.ssh.authentication.agent[97cc28]: sending agent request 1 len 44
D, [2017-09-11T12:05:07.529661 #12073] DEBUG –
net.ssh.authentication.agent[97cc28]: received agent packet 2 len 5
D, [2017-09-11T12:05:07.529726 #12073] DEBUG –
net.ssh.authentication.agent[97cc28]: sending agent request 11 len 0
D, [2017-09-11T12:05:07.529819 #12073] DEBUG –
net.ssh.authentication.agent[97cc28]: received agent packet 12 len 342
D, [2017-09-11T12:05:07.530101 #12073] DEBUG – net.ssh.authentication.methods.publickey[97d3f8]:
trying publickey (8a:99:a1:12:8a:87:c5:8e:58:45:a9:d8:f9:0a:61:16)
D, [2017-09-11T12:05:07.530746 #12073] DEBUG – socket[d4b2dc]: queueing
packet nr 5 type 50 len 348
D, [2017-09-11T12:05:07.530813 #12073] DEBUG – socket[d4b2dc]: sent 384
bytes
D, [2017-09-11T12:05:07.531222 #12073] DEBUG – socket[d4b2dc]: read 336
bytes
D, [2017-09-11T12:05:07.531458 #12073] DEBUG – socket[d4b2dc]: received
packet nr 6 type 60 len 300
D, [2017-09-11T12:05:07.531979 #12073] DEBUG –
net.ssh.authentication.agent[97cc28]: sending agent request 13 len 653
D, [2017-09-11T12:05:07.533364 #12073] DEBUG –
net.ssh.authentication.agent[97cc28]: received agent packet 14 len 276
D, [2017-09-11T12:05:07.533804 #12073] DEBUG – socket[d4b2dc]: queueing
packet nr 6 type 50 len 620
D, [2017-09-11T12:05:07.533860 #12073] DEBUG – socket[d4b2dc]: sent 656
bytes
D, [2017-09-11T12:05:07.534713 #12073] DEBUG – socket[d4b2dc]: read 48
bytes
D, [2017-09-11T12:05:07.534799 #12073] DEBUG – socket[d4b2dc]: received
packet nr 7 type 52 len 12
D, [2017-09-11T12:05:07.534842 #12073] DEBUG – net.ssh.authentication.methods.publickey[97d3f8]:
publickey succeeded (8a:99:a1:12:8a:87:c5:8e:58:45:a9:d8:f9:0a:61:16)
D, [2017-09-11T12:05:07.535158 #12073] DEBUG – socket[d4b2dc]: queueing
packet nr 7 type 90 len 44
D, [2017-09-11T12:05:07.535265 #12073] DEBUG – socket[d4b2dc]: sent 80
bytes
D, [2017-09-11T12:05:07.540589 #12073] DEBUG – socket[d4b2dc]: read 64
bytes
D, [2017-09-11T12:05:07.540678 #12073] DEBUG – socket[d4b2dc]: received
packet nr 8 type 91 len 28
I, [2017-09-11T12:05:07.540744 #12073] INFO – net.ssh.connection.session[a6ba30]:
channel_open_confirmation: 0 0 0 32768
I, [2017-09-11T12:05:07.540809 #12073] INFO – net.ssh.connection.channel[a6ac48]:
sending channel request "auth-agent-req@openssh.com"
D, [2017-09-11T12:05:07.540906 #12073] DEBUG – socket[d4b2dc]: queueing
packet nr 8 type 98 len 44
I, [2017-09-11T12:05:07.541142 #12073] INFO – net.ssh.connection.channel[a6ac48]:
sending channel request "env"
D, [2017-09-11T12:05:07.541229 #12073] DEBUG – socket[d4b2dc]: queueing
packet nr 9 type 98 len 44
I, [2017-09-11T12:05:07.541764 #12073] INFO – net.ssh.connection.channel[a6ac48]:
sending channel request "exec"
D, [2017-09-11T12:05:07.541852 #12073] DEBUG – socket[d4b2dc]: queueing
packet nr 10 type 98 len 44
D, [2017-09-11T12:05:07.541937 #12073] DEBUG – socket[d4b2dc]: sent 240
bytes
D, [2017-09-11T12:05:07.543087 #12073] DEBUG – socket[d4b2dc]: read 160
bytes
D, [2017-09-11T12:05:07.543342 #12073] DEBUG – socket[d4b2dc]: received
packet nr 9 type 99 len 12
I, [2017-09-11T12:05:07.543385 #12073] INFO – net.ssh.connection.session[a6ba30]:
channel_success: 0
D, [2017-09-11T12:05:07.543427 #12073] DEBUG – net.ssh.service.forward[d196d8]:
authentication agent forwarding is active
D, [2017-09-11T12:05:07.543490 #12073] DEBUG – socket[d4b2dc]: received
packet nr 10 type 93 len 28
I, [2017-09-11T12:05:07.543524 #12073] INFO – net.ssh.connection.session[a6ba30]:
channel_window_adjust: 0 +2097152
D, [2017-09-11T12:05:07.543581 #12073] DEBUG – socket[d4b2dc]: received
packet nr 11 type 99 len 12
I, [2017-09-11T12:05:07.543611 #12073] INFO – net.ssh.connection.session[a6ba30]:
channel_success: 0
D, [2017-09-11T12:05:07.579167 #12073] DEBUG – socket[d4b2dc]: read 256
bytes
D, [2017-09-11T12:05:07.579327 #12073] DEBUG – socket[d4b2dc]: received
packet nr 12 type 94 len 44
I, [2017-09-11T12:05:07.579378 #12073] INFO – net.ssh.connection.session[a6ba30]:
channel_data: 0 28b
D, [2017-09-11T12:05:07.579666 #12073] DEBUG – socket[d4b2dc]: received
packet nr 13 type 98 len 44
I, [2017-09-11T12:05:07.579716 #12073] INFO – net.ssh.connection.session[a6ba30]:
channel_request: 0 exit-status false
D, [2017-09-11T12:05:07.579795 #12073] DEBUG – socket[d4b2dc]: received
packet nr 14 type 96 len 12
I, [2017-09-11T12:05:07.579830 #12073] INFO – net.ssh.connection.session[a6ba30]:
channel_eof: 0
D, [2017-09-11T12:05:07.579897 #12073] DEBUG – socket[d4b2dc]: received
packet nr 15 type 97 len 12
I, [2017-09-11T12:05:07.579933 #12073] INFO – net.ssh.connection.session[a6ba30]:
channel_close: 0
D, [2017-09-11T12:05:07.580043 #12073] DEBUG – socket[d4b2dc]: queueing
packet nr 11 type 97 len 28
I, [2017-09-11T12:05:07.580073 #12073] INFO – net.ssh.connection.session[a6ba30]:
client.fqdn delete channel 0 which closed locally and remotely
client.fqdn
I, [2017-09-11T12:05:07.580128 #12073] INFO – net.ssh.connection.session[a6ba30]:
closing remaining channels (0 open)
bash-4.2$

Is this expected behaviour?

Edgars

On Friday, September 8, 2017 at 3:13:35 PM UTC+3, Edgars M. wrote:

Hi

I am trying to setup remote jobs from Katello to clients unfortunately
all SSH remote commands fails with:

1: Error initializing command: IOError - closed stream
2: Exit status: EXCEPTION

The only thing I see on client’s side is:

Connection closed by 10.30.xxx.xxx [preauth]

If I try to do simple ssh with OpenSSH client it works just fine.

Here is the log:

Action:

ForemanRemoteExecutionCore::Actions::RunScript

Input:

{“ssh_user”=>“redacted-username”,
“effective_user”=>“root”,
“effective_user_method”=>“sudo”,
“ssh_port”=>22,
“hostname”=>“some_hostname”,
“script”=>“uptime”,
“execution_timeout_interval”=>nil,
“task_id”=>“9f4b7f1e-92e0-4b50-afad-1356f4821595”,
“locale”=>“en”}

Output:

{“result”=>
[{“output_type”=>“debug”,
“output”=>“Error initializing command: IOError - closed stream”,
“timestamp”=>1504872104.755812}],
“runner_id”=>“289b1675-3a4f-4a85-af90-68d84c9f4e9b”,
“exit_status”=>“EXCEPTION”}

Exception:

StandardError: Script execution failed

Backtrace:

/opt/theforeman/tfm/root/usr/share/gems/gems/algebrick-0.7.3/lib/algebrick/matchers/abstract.rb:74:in block in assigns' /opt/theforeman/tfm/root/usr/share/gems/gems/algebrick-0.7.3/lib/algebrick/matchers/abstract.rb:73:intap’
/opt/theforeman/tfm/root/usr/share/gems/gems/algebrick-0.7.3/lib/algebrick/matchers/abstract.rb:73:in assigns' /opt/theforeman/tfm/root/usr/share/gems/gems/algebrick-0.7.3/lib/algebrick/matching.rb:56:inmatch_value’
/opt/theforeman/tfm/root/usr/share/gems/gems/algebrick-0.7.3/lib/algebrick/matching.rb:36:in block in match?' /opt/theforeman/tfm/root/usr/share/gems/gems/algebrick-0.7.3/lib/algebrick/matching.rb:35:ineach’
/opt/theforeman/tfm/root/usr/share/gems/gems/algebrick-0.7.3/lib/algebrick/matching.rb:35:in match?' /opt/theforeman/tfm/root/usr/share/gems/gems/algebrick-0.7.3/lib/algebrick/matching.rb:23:inmatch’
/opt/theforeman/tfm/root/usr/share/gems/gems/dynflow-0.8.24/lib/dynflow/execution_plan/steps/error.rb:12:in new' /opt/theforeman/tfm/root/usr/share/gems/gems/dynflow-0.8.24/lib/dynflow/action.rb:454:inset_error’
/opt/theforeman/tfm/root/usr/share/gems/gems/dynflow-0.8.24/lib/dynflow/action.rb:417:in error!' /opt/theforeman/tfm/root/usr/share/gems/gems/foreman-tasks-core-0.1.4/lib/foreman_tasks_core/runner/action.rb:25:infinalize’
/opt/theforeman/tfm/root/usr/share/gems/gems/dynflow-0.8.24/lib/dynflow/action.rb:534:in block (2 levels) in execute_finalize' /opt/theforeman/tfm/root/usr/share/gems/gems/dynflow-0.8.24/lib/dynflow/middleware/stack.rb:26:incall’
/opt/theforeman/tfm/root/usr/share/gems/gems/dynflow-0.8.24/lib/dynflow/middleware/stack.rb:26:in pass' /opt/theforeman/tfm/root/usr/share/gems/gems/dynflow-0.8.24/lib/dynflow/middleware.rb:17:inpass’
/opt/theforeman/tfm/root/usr/share/gems/gems/dynflow-0.8.24/lib/dynflow/action/progress.rb:30:in with_progress_calculation' /opt/theforeman/tfm/root/usr/share/gems/gems/dynflow-0.8.24/lib/dynflow/action/progress.rb:22:infinalize’
/opt/theforeman/tfm/root/usr/share/gems/gems/dynflow-0.8.24/lib/dynflow/middleware/stack.rb:22:in call' /opt/theforeman/tfm/root/usr/share/gems/gems/dynflow-0.8.24/lib/dynflow/middleware/stack.rb:26:inpass’
/opt/theforeman/tfm/root/usr/share/gems/gems/dynflow-0.8.24/lib/dynflow/middleware.rb:17:in pass' /opt/theforeman/tfm/root/usr/share/gems/gems/katello-3.4.5/app/lib/actions/middleware/keep_locale.rb:15:inblock in finalize’
/opt/theforeman/tfm/root/usr/share/gems/gems/katello-3.4.5/app/lib/actions/middleware/keep_locale.rb:22:in with_locale' /opt/theforeman/tfm/root/usr/share/gems/gems/katello-3.4.5/app/lib/actions/middleware/keep_locale.rb:15:infinalize’
/opt/theforeman/tfm/root/usr/share/gems/gems/dynflow-0.8.24/lib/dynflow/middleware/stack.rb:22:in call' /opt/theforeman/tfm/root/usr/share/gems/gems/dynflow-0.8.24/lib/dynflow/middleware/stack.rb:26:inpass’
/opt/theforeman/tfm/root/usr/share/gems/gems/dynflow-0.8.24/lib/dynflow/middlew