Net::SSH "connection closed by remote host (Net::SSH::Disconnect)"
------------------------------------------------------------------
Key: JRUBY-5094
URL: http://jira.codehaus.org/browse/JRUBY-5094
Project: JRuby
Issue Type: Bug
Components: OpenSSL
Affects Versions: JRuby 1.5.2
Environment: JRuby 1.5.2, Net::SSH 2.0.23, jruby-openssl 0.7.1,
bouncy-castle-java 1.5.0145.2, Ubuntu Linux 10.04 and Mac OS X 10.6.4
Reporter: Paul Mucur
The following test script successfully connects to a Solaris Nevada snv_67
server when using Ruby Enterprise Edition 1.8.7 2010.02 with Net::SSH 2.0.15:
{code}
require 'rubygems'
require 'net/ssh'
Net::SSH.start('[SERVER]', '[USERNAME]', :verbose => :debug) do |ssh|
ssh.exec!('hostname')
end
{code}
However with JRuby 1.5.2, Net::SSH 2.0.23 and JRuby-OpenSSL 0.7.1, the
following error occurs:
{code}
$ ruby test.rb
*** Using highline effectively in JRuby requires manually installing the
ffi-ncurses gem.
*** jruby -S gem install ffi-ncurses
D, [2010-09-17T13:10:51.084000 #10990] DEBUG --
net.ssh.transport.session[800]: establishing connection to [SERVER]:22
D, [2010-09-17T13:10:51.218000 #10990] DEBUG --
net.ssh.transport.session[800]: connection established
I, [2010-09-17T13:10:51.219000 #10990] INFO --
net.ssh.transport.server_version[802]: negotiating protocol version
D, [2010-09-17T13:10:51.312000 #10990] DEBUG --
net.ssh.transport.server_version[802]: remote is `SSH-2.0-Sun_SSH_1.4'
D, [2010-09-17T13:10:51.313000 #10990] DEBUG --
net.ssh.transport.server_version[802]: local is `SSH-2.0-Ruby/Net::SSH_2.0.23
java'
D, [2010-09-17T13:10:51.532000 #10990] DEBUG -- tcpsocket[804]: read 1656
bytes
D, [2010-09-17T13:10:51.533000 #10990] DEBUG -- tcpsocket[804]: received
packet nr 0 type 20 len 1652
I, [2010-09-17T13:10:51.534000 #10990] INFO --
net.ssh.transport.algorithms[806]: got KEXINIT from server
I, [2010-09-17T13:10:51.535000 #10990] INFO --
net.ssh.transport.algorithms[806]: sending KEXINIT
D, [2010-09-17T13:10:51.536000 #10990] DEBUG -- tcpsocket[804]: queueing
packet nr 0 type 20 len 556
D, [2010-09-17T13:10:51.537000 #10990] DEBUG -- tcpsocket[804]: sent 560 bytes
I, [2010-09-17T13:10:51.537000 #10990] INFO --
net.ssh.transport.algorithms[806]: negotiating algorithms
D, [2010-09-17T13:10:51.538000 #10990] DEBUG --
net.ssh.transport.algorithms[806]: negotiated:
* kex: diffie-hellman-group-exchange-sha1
* host_key: ssh-rsa
* encryption_server: arcfour128
* encryption_client: arcfour128
* hmac_client: hmac-sha1
* hmac_server: hmac-sha1
* compression_client: none
* compression_server: none
* language_client:
* language_server:
D, [2010-09-17T13:10:51.538000 #10990] DEBUG --
net.ssh.transport.algorithms[806]: exchanging keys
D, [2010-09-17T13:10:51.604000 #10990] DEBUG -- tcpsocket[804]: queueing
packet nr 1 type 34 len 20
D, [2010-09-17T13:10:51.605000 #10990] DEBUG -- tcpsocket[804]: sent 24 bytes
D, [2010-09-17T13:10:51.729000 #10990] DEBUG -- tcpsocket[804]: read 152 bytes
D, [2010-09-17T13:10:51.731000 #10990] DEBUG -- tcpsocket[804]: received
packet nr 1 type 31 len 148
D, [2010-09-17T13:10:51.767000 #10990] DEBUG -- tcpsocket[804]: queueing
packet nr 2 type 32 len 140
D, [2010-09-17T13:10:51.767000 #10990] DEBUG -- tcpsocket[804]: sent 144 bytes
D, [2010-09-17T13:10:51.869000 #10990] DEBUG -- tcpsocket[804]: read 464 bytes
D, [2010-09-17T13:10:51.873000 #10990] DEBUG -- tcpsocket[804]: received
packet nr 2 type 33 len 444
D, [2010-09-17T13:10:51.904000 #10990] DEBUG -- tcpsocket[804]: queueing
packet nr 3 type 21 len 20
D, [2010-09-17T13:10:51.904000 #10990] DEBUG -- tcpsocket[804]: sent 24 bytes
D, [2010-09-17T13:10:51.905000 #10990] DEBUG -- tcpsocket[804]: received
packet nr 3 type 21 len 12
D, [2010-09-17T13:10:51.911000 #10990] DEBUG --
net.ssh.authentication.session[808]: beginning authentication of `[USERNAME]'
D, [2010-09-17T13:10:51.914000 #10990] DEBUG -- tcpsocket[804]: queueing
packet nr 4 type 5 len 20
D, [2010-09-17T13:10:51.914000 #10990] DEBUG -- tcpsocket[804]: sent 44 bytes
D, [2010-09-17T13:10:52.150000 #10990] DEBUG -- tcpsocket[804]: read 76 bytes
D, [2010-09-17T13:10:52.151000 #10990] DEBUG -- tcpsocket[804]: read 0 bytes
/home/paul/.rvm/gems/jruby-1.5.2/gems/net-ssh-2.0.23/lib/net/ssh/transport/packet_stream.rb:99:in
`next_packet': connection closed by remote host (Net::SSH::Disconnect)
from
/home/paul/.rvm/gems/jruby-1.5.2/gems/net-ssh-2.0.23/lib/net/ssh/transport/packet_stream.rb:89:in
`loop'
from
/home/paul/.rvm/gems/jruby-1.5.2/gems/net-ssh-2.0.23/lib/net/ssh/transport/packet_stream.rb:89:in
`next_packet'
from
/home/paul/.rvm/gems/jruby-1.5.2/gems/net-ssh-2.0.23/lib/net/ssh/transport/session.rb:169:in
`poll_message'
from
/home/paul/.rvm/gems/jruby-1.5.2/gems/net-ssh-2.0.23/lib/net/ssh/transport/session.rb:164:in
`loop'
from
/home/paul/.rvm/gems/jruby-1.5.2/gems/net-ssh-2.0.23/lib/net/ssh/transport/session.rb:164:in
`poll_message'
from
/home/paul/.rvm/gems/jruby-1.5.2/gems/net-ssh-2.0.23/lib/net/ssh/transport/session.rb:149:in
`next_message'
from
/home/paul/.rvm/gems/jruby-1.5.2/gems/net-ssh-2.0.23/lib/net/ssh/authentication/session.rb:82:in
`next_message'
from
/home/paul/.rvm/gems/jruby-1.5.2/gems/net-ssh-2.0.23/lib/net/ssh/authentication/session.rb:81:in
`loop'
from
/home/paul/.rvm/gems/jruby-1.5.2/gems/net-ssh-2.0.23/lib/net/ssh/authentication/session.rb:81:in
`next_message'
from
/home/paul/.rvm/gems/jruby-1.5.2/gems/net-ssh-2.0.23/lib/net/ssh/authentication/session.rb:110:in
`expect_message'
from
/home/paul/.rvm/gems/jruby-1.5.2/gems/net-ssh-2.0.23/lib/net/ssh/authentication/session.rb:53:in
`authenticate'
from
/home/paul/.rvm/gems/jruby-1.5.2/gems/net-ssh-2.0.23/lib/net/ssh.rb:183:in
`start'
from test.rb:4
{code}
The successful output from Ruby Enterprise Edition is as follows:
{code}
$ ruby test.rb
D, [2010-09-17T13:14:52.407929 #11236] DEBUG --
net.ssh.transport.session[470e5a0]: establishing connection to [SERVER]:22
D, [2010-09-17T13:14:52.502610 #11236] DEBUG --
net.ssh.transport.session[470e5a0]: connection established
I, [2010-09-17T13:14:52.502727 #11236] INFO --
net.ssh.transport.server_version[470d416]: negotiating protocol version
D, [2010-09-17T13:14:52.596398 #11236] DEBUG --
net.ssh.transport.server_version[470d416]: remote is `SSH-2.0-Sun_SSH_1.4'
D, [2010-09-17T13:14:52.596480 #11236] DEBUG --
net.ssh.transport.server_version[470d416]: local is
`SSH-2.0-Ruby/Net::SSH_2.0.15 i686-linux'
D, [2010-09-17T13:14:52.818520 #11236] DEBUG -- tcpsocket[470d592]: read 1448
bytes
D, [2010-09-17T13:14:52.818620 #11236] DEBUG -- tcpsocket[470d592]: read 208
bytes
D, [2010-09-17T13:14:52.818694 #11236] DEBUG -- tcpsocket[470d592]: received
packet nr 0 type 20 len 1652
I, [2010-09-17T13:14:52.818755 #11236] INFO --
net.ssh.transport.algorithms[470cfde]: got KEXINIT from server
I, [2010-09-17T13:14:52.818931 #11236] INFO --
net.ssh.transport.algorithms[470cfde]: sending KEXINIT
D, [2010-09-17T13:14:52.819071 #11236] DEBUG -- tcpsocket[470d592]: queueing
packet nr 0 type 20 len 556
D, [2010-09-17T13:14:52.819127 #11236] DEBUG -- tcpsocket[470d592]: sent 560
bytes
I, [2010-09-17T13:14:52.819156 #11236] INFO --
net.ssh.transport.algorithms[470cfde]: negotiating algorithms
D, [2010-09-17T13:14:52.819332 #11236] DEBUG --
net.ssh.transport.algorithms[470cfde]: negotiated:
* kex: diffie-hellman-group-exchange-sha1
* host_key: ssh-rsa
* encryption_server: arcfour128
* encryption_client: arcfour128
* hmac_client: hmac-sha1
* hmac_server: hmac-sha1
* compression_client: none
* compression_server: none
* language_client:
* language_server:
D, [2010-09-17T13:14:52.819368 #11236] DEBUG --
net.ssh.transport.algorithms[470cfde]: exchanging keys
D, [2010-09-17T13:14:52.819515 #11236] DEBUG -- tcpsocket[470d592]: queueing
packet nr 1 type 34 len 20
D, [2010-09-17T13:14:52.819556 #11236] DEBUG -- tcpsocket[470d592]: sent 24
bytes
D, [2010-09-17T13:14:53.011328 #11236] DEBUG -- tcpsocket[470d592]: read 152
bytes
D, [2010-09-17T13:14:53.011497 #11236] DEBUG -- tcpsocket[470d592]: received
packet nr 1 type 31 len 148
D, [2010-09-17T13:14:53.019677 #11236] DEBUG -- tcpsocket[470d592]: queueing
packet nr 2 type 32 len 140
D, [2010-09-17T13:14:53.019751 #11236] DEBUG -- tcpsocket[470d592]: sent 144
bytes
D, [2010-09-17T13:14:53.121305 #11236] DEBUG -- tcpsocket[470d592]: read 464
bytes
D, [2010-09-17T13:14:53.121470 #11236] DEBUG -- tcpsocket[470d592]: received
packet nr 2 type 33 len 444
D, [2010-09-17T13:14:53.129734 #11236] DEBUG -- tcpsocket[470d592]: queueing
packet nr 3 type 21 len 20
D, [2010-09-17T13:14:53.129808 #11236] DEBUG -- tcpsocket[470d592]: sent 24
bytes
D, [2010-09-17T13:14:53.129917 #11236] DEBUG -- tcpsocket[470d592]: received
packet nr 3 type 21 len 12
D, [2010-09-17T13:14:53.131029 #11236] DEBUG --
net.ssh.authentication.session[4456b96]: beginning authentication of
`[USERNAME]'
D, [2010-09-17T13:14:53.131160 #11236] DEBUG -- tcpsocket[470d592]: queueing
packet nr 4 type 5 len 28
D, [2010-09-17T13:14:53.131219 #11236] DEBUG -- tcpsocket[470d592]: sent 52
bytes
D, [2010-09-17T13:14:53.460164 #11236] DEBUG -- tcpsocket[470d592]: read 52
bytes
D, [2010-09-17T13:14:53.460372 #11236] DEBUG -- tcpsocket[470d592]: received
packet nr 4 type 6 len 28
D, [2010-09-17T13:14:53.460501 #11236] DEBUG --
net.ssh.authentication.session[4456b96]: trying publickey
D, [2010-09-17T13:14:53.460599 #11236] DEBUG --
net.ssh.authentication.agent[4450bf6]: connecting to ssh-agent
D, [2010-09-17T13:14:53.460727 #11236] DEBUG --
net.ssh.authentication.agent[4450bf6]: sending agent request 1 len 43
D, [2010-09-17T13:14:53.461089 #11236] DEBUG --
net.ssh.authentication.agent[4450bf6]: received agent packet 2 len 5
D, [2010-09-17T13:14:53.461144 #11236] DEBUG --
net.ssh.authentication.agent[4450bf6]: sending agent request 11 len 0
D, [2010-09-17T13:14:53.510881 #11236] DEBUG --
net.ssh.authentication.agent[4450bf6]: received agent packet 12 len 302
D, [2010-09-17T13:14:53.511135 #11236] DEBUG --
net.ssh.authentication.methods.publickey[4450c46]: trying publickey
(49:a5:65:37:3f:3f:ad:19:bf:9f:99:86:ca:47:57:44)
D, [2010-09-17T13:14:53.511283 #11236] DEBUG -- tcpsocket[470d592]: queueing
packet nr 5 type 50 len 340
D, [2010-09-17T13:14:53.511341 #11236] DEBUG -- tcpsocket[470d592]: sent 364
bytes
D, [2010-09-17T13:14:53.608929 #11236] DEBUG -- tcpsocket[470d592]: read 108
bytes
D, [2010-09-17T13:14:53.609132 #11236] DEBUG -- tcpsocket[470d592]: received
packet nr 5 type 51 len 84
D, [2010-09-17T13:14:53.609242 #11236] DEBUG --
net.ssh.authentication.session[4456b96]: allowed methods:
gssapi-keyex,gssapi-with-mic,publickey,password,keyboard-interactive
D, [2010-09-17T13:14:53.609634 #11236] DEBUG --
net.ssh.authentication.methods.publickey[4450c46]: trying publickey
(49:a5:65:37:3f:3f:ad:19:bf:9f:99:86:ca:47:57:44)
D, [2010-09-17T13:14:53.609809 #11236] DEBUG -- tcpsocket[470d592]: queueing
packet nr 6 type 50 len 340
D, [2010-09-17T13:14:53.609881 #11236] DEBUG -- tcpsocket[470d592]: sent 364
bytes
D, [2010-09-17T13:14:53.705646 #11236] DEBUG -- tcpsocket[470d592]: read 108
bytes
D, [2010-09-17T13:14:53.705851 #11236] DEBUG -- tcpsocket[470d592]: received
packet nr 6 type 51 len 84
D, [2010-09-17T13:14:53.705958 #11236] DEBUG --
net.ssh.authentication.session[4456b96]: allowed methods:
gssapi-keyex,gssapi-with-mic,publickey,password,keyboard-interactive
D, [2010-09-17T13:14:53.706071 #11236] DEBUG --
net.ssh.authentication.session[4456b96]: trying password
D, [2010-09-17T13:14:53.706130 #11236] DEBUG --
net.ssh.authentication.session[4456b96]: trying keyboard-interactive
D, [2010-09-17T13:14:53.706207 #11236] DEBUG --
net.ssh.authentication.methods.keyboard_interactive[4449e00]: trying
keyboard-interactive
D, [2010-09-17T13:14:53.706359 #11236] DEBUG -- tcpsocket[470d592]: queueing
packet nr 7 type 50 len 68
D, [2010-09-17T13:14:53.706428 #11236] DEBUG -- tcpsocket[470d592]: sent 92
bytes
D, [2010-09-17T13:14:53.800950 #11236] DEBUG -- tcpsocket[470d592]: read 68
bytes
D, [2010-09-17T13:14:53.801151 #11236] DEBUG -- tcpsocket[470d592]: received
packet nr 7 type 60 len 44
D, [2010-09-17T13:14:53.801235 #11236] DEBUG --
net.ssh.authentication.methods.keyboard_interactive[4449e00]:
keyboard-interactive info request
Password:
D, [2010-09-17T13:14:56.089726 #11236] DEBUG -- tcpsocket[470d592]: queueing
packet nr 8 type 61 len 28
D, [2010-09-17T13:14:56.089833 #11236] DEBUG -- tcpsocket[470d592]: sent 52
bytes
D, [2010-09-17T13:14:56.186883 #11236] DEBUG -- tcpsocket[470d592]: read 36
bytes
D, [2010-09-17T13:14:56.187081 #11236] DEBUG -- tcpsocket[470d592]: received
packet nr 8 type 52 len 12
D, [2010-09-17T13:14:56.187160 #11236] DEBUG --
net.ssh.authentication.methods.keyboard_interactive[4449e00]:
keyboard-interactive succeeded
D, [2010-09-17T13:14:56.187407 #11236] DEBUG -- tcpsocket[470d592]: queueing
packet nr 9 type 90 len 36
D, [2010-09-17T13:14:56.187539 #11236] DEBUG -- tcpsocket[470d592]: sent 60
bytes
D, [2010-09-17T13:14:56.280041 #11236] DEBUG -- tcpsocket[470d592]: read 52
bytes
D, [2010-09-17T13:14:56.280270 #11236] DEBUG -- tcpsocket[470d592]: received
packet nr 9 type 91 len 28
I, [2010-09-17T13:14:56.280406 #11236] INFO --
net.ssh.connection.session[444396a]: channel_open_confirmation: 0 0 0 32768
I, [2010-09-17T13:14:56.280491 #11236] INFO --
net.ssh.connection.channel[44437e4]: sending channel request "exec"
D, [2010-09-17T13:14:56.280648 #11236] DEBUG -- tcpsocket[470d592]: queueing
packet nr 10 type 98 len 36
D, [2010-09-17T13:14:56.280757 #11236] DEBUG -- tcpsocket[470d592]: sent 60
bytes
D, [2010-09-17T13:14:56.373900 #11236] DEBUG -- tcpsocket[470d592]: read 80
bytes
D, [2010-09-17T13:14:56.374119 #11236] DEBUG -- tcpsocket[470d592]: received
packet nr 10 type 93 len 20
I, [2010-09-17T13:14:56.374208 #11236] INFO --
net.ssh.connection.session[444396a]: channel_window_adjust: 0 +131072
D, [2010-09-17T13:14:56.374344 #11236] DEBUG -- tcpsocket[470d592]: received
packet nr 11 type 99 len 12
I, [2010-09-17T13:14:56.374414 #11236] INFO --
net.ssh.connection.session[444396a]: channel_success: 0
D, [2010-09-17T13:14:56.505984 #11236] DEBUG -- tcpsocket[470d592]: read 192
bytes
D, [2010-09-17T13:14:56.506214 #11236] DEBUG -- tcpsocket[470d592]: received
packet nr 12 type 94 len 36
I, [2010-09-17T13:14:56.506305 #11236] INFO --
net.ssh.connection.session[444396a]: channel_data: 0 19b
D, [2010-09-17T13:14:56.506450 #11236] DEBUG -- tcpsocket[470d592]: received
packet nr 13 type 96 len 12
I, [2010-09-17T13:14:56.506516 #11236] INFO --
net.ssh.connection.session[444396a]: channel_eof: 0
D, [2010-09-17T13:14:56.506646 #11236] DEBUG -- tcpsocket[470d592]: received
packet nr 14 type 98 len 36
I, [2010-09-17T13:14:56.506734 #11236] INFO --
net.ssh.connection.session[444396a]: channel_request: 0 exit-status false
D, [2010-09-17T13:14:56.506931 #11236] DEBUG -- tcpsocket[470d592]: received
packet nr 15 type 97 len 12
I, [2010-09-17T13:14:56.506998 #11236] INFO --
net.ssh.connection.session[444396a]: channel_close: 0
D, [2010-09-17T13:14:56.507136 #11236] DEBUG -- tcpsocket[470d592]: queueing
packet nr 11 type 97 len 20
I, [2010-09-17T13:14:56.507213 #11236] INFO --
net.ssh.connection.session[444396a]: closing remaining channels (0 open)
{code}
Installing ffi-ncurses makes no difference and the error still occurs in the
same place:
{code}
D, [2010-09-17T13:18:42.752000 #11621] DEBUG --
net.ssh.authentication.session[80c]: beginning authentication of `[USERNAME]'
D, [2010-09-17T13:18:42.754000 #11621] DEBUG -- tcpsocket[808]: queueing
packet nr 4 type 5 len 20
D, [2010-09-17T13:18:42.754000 #11621] DEBUG -- tcpsocket[808]: sent 44 bytes
D, [2010-09-17T13:18:43.045000 #11621] DEBUG -- tcpsocket[808]: read 76 bytes
D, [2010-09-17T13:18:43.046000 #11621] DEBUG -- tcpsocket[808]: read 0 bytes
{code}
The C version of this section is as follows:
{code}
D, [2010-09-17T13:19:23.230010 #11754] DEBUG --
net.ssh.authentication.session[4af6370]: beginning authentication of
`[USERNAME]'
D, [2010-09-17T13:19:23.230138 #11754] DEBUG -- tcpsocket[4da4608]: queueing
packet nr 4 type 5 len 28
D, [2010-09-17T13:19:23.230195 #11754] DEBUG -- tcpsocket[4da4608]: sent 52
bytes
D, [2010-09-17T13:19:23.567298 #11754] DEBUG -- tcpsocket[4da4608]: read 52
bytes
D, [2010-09-17T13:19:23.567554 #11754] DEBUG -- tcpsocket[4da4608]: received
packet nr 4 type 6 len 28
{code}
This problem affects me on both Ubuntu Linux 10.04 and Mac OS X 10.6.4.
Please let me know if there is anything other information I can provide to help
track this down.
--
This message is automatically generated by JIRA.
-
If you think it was sent incorrectly contact one of the administrators:
http://jira.codehaus.org/secure/Administrators.jspa
-
For more information on JIRA, see: http://www.atlassian.com/software/jira
---------------------------------------------------------------------
To unsubscribe from this list, please visit:
http://xircles.codehaus.org/manage_email
