Hello,

I noticed a regression in RouterOS beta/rc up to rc1 in the way SSH server handles SSH protocol.

After some debugging I found out that the SSH server is not answering with either SSH_MSG_CHANNEL_SUCCESS or SSH_MSG_CHANNEL_FAILURE to the SSH_MSG_CHANNEL_REQUEST message, although it is sending the output as channel data.

OpenSSH outputs the data anyway, so the issue is not immediately visible with it.

OTOH ruby's net-ssh doesn't start collecting response data unless success message is received leading to empty output being read.

The ruby's code is the following:

Net::SSH.start('192.168.88.1', 'admin+ct', :password => 'xxxxx', :config => false, :auth_methods => ['password'], :verbose => Logger::DEBUG) do |ssh|
puts ssh.exec!("/interface print")
end

Relevant log of a working session (RouterOS 4.5):

I, [2010-09-24T14:14:41.792070 #23692] INFO -- net.ssh.connection.session[1074e7c]: channel_open_confirmation: 0 0 0 16384
I, [2010-09-24T14:14:41.792146 #23692] INFO -- net.ssh.connection.channel[1074c74]: sending channel request "exec"
I, [2010-09-24T14:14:41.802396 #23692] INFO -- net.ssh.connection.session[1074e7c]: channel_window_adjust: 0 +32768
I, [2010-09-24T14:14:41.802561 #23692] INFO -- net.ssh.connection.session[1074e7c]: channel_success: 0
I, [2010-09-24T14:14:41.838633 #23692] INFO -- net.ssh.connection.session[1074e7c]: channel_request: 0 exit-status false
I, [2010-09-24T14:14:41.838905 #23692] INFO -- net.ssh.connection.session[1074e7c]: channel_data: 0 731b
I, [2010-09-24T14:14:41.839079 #23692] INFO -- net.ssh.connection.session[1074e7c]: channel_eof: 0
I, [2010-09-24T14:14:41.839239 #23692] INFO -- net.ssh.connection.session[1074e7c]: channel_close: 0

Relevant log of 5.0rc1:

I, [2010-09-24T14:16:53.719107 #23700] INFO -- net.ssh.connection.session[c3b6d0]: channel_open_confirmation: 0 0 327680 32768
I, [2010-09-24T14:16:53.719187 #23700] INFO -- net.ssh.connection.channel[c3b554]: sending channel request "exec"
I, [2010-09-24T14:16:53.788932 #23700] INFO -- net.ssh.connection.session[c3b6d0]: channel_data: 0 379b
I, [2010-09-24T14:16:53.789546 #23700] INFO -- net.ssh.connection.session[c3b6d0]: channel_request: 0 exit-status false
I, [2010-09-24T14:16:53.789813 #23700] INFO -- net.ssh.connection.session[c3b6d0]: channel_close: 0
I, [2010-09-24T14:16:53.812891 #23700] INFO -- net.ssh.connection.session[c3b6d0]: closing remaining channels (0 open)

The channel_success event is missing, thus net-ssh does not know when to process the response.

I'm testing with 5.0rc3, now the reported issue isn't happening again, however (as it happened with 4.x) the channel is closed after the first command.

Isn't it possible to keep the channel open according to how OpenSSH does?