Forum: JRuby SSH hanging connecting from AIX

I'm trying to connect from an AIX server to another box, but ssh hangs
after it authenticates.  Has anybody seen this, or have any ideas?
doesn't matter if its connecting to a Solaris, AIX, or linux box.


$ jruby -v
jruby 1.6.3 (ruby-1.8.7-p330) (2011-07-07 965162f) (IBM J9 VM 1.6.0)
[AIX-ppc-java]

$ jruby -S gem list

*** LOCAL GEMS ***

abstract (1.0.0)
actionmailer (3.0.7)
actionpack (3.0.7)
activemodel (3.0.7)
activesupport (3.0.7)
bouncy-castle-java (1.5.0146.1)
builder (2.1.2)
erubis (2.6.6)
i18n (0.6.0, 0.5.0)
jruby-openssl (0.7.4)
log4r (1.1.9)
mail (2.2.19)
mime-types (1.16)
net-ssh (2.1.4, 2.1.0, 2.0.8)
polyglot (0.3.1)
rack (1.2.3)
rack-mount (0.6.14)
rack-test (0.5.7)
treetop (1.4.9)
tzinfo (0.3.27)

SAMPLE CODE:

require 'rubygems'
require 'net/ssh'

Net::SSH.start('my_server_name', 'my_username', :password =>
"password", :verbose => :debug) do |ssh|
  puts  ssh.exec!("hostname")
end

And the output:


$ jruby ./ssh.rb
D, [2011-08-02T15:41:13.706000 #1447056960] DEBUG --
net.ssh.transport.session[7fe]: establishing connection to
my_server_name:22
D, [2011-08-02T15:41:13.788000 #1447056960] DEBUG --
net.ssh.transport.session[7fe]: connection established
I, [2011-08-02T15:41:13.790000 #1447056960]  INFO --
net.ssh.transport.server_version[800]: negotiating protocol version
D, [2011-08-02T15:41:13.830000 #1447056960] DEBUG --
net.ssh.transport.server_version[800]: remote is `SSH-2.0-OpenSSH_5.1'
D, [2011-08-02T15:41:13.832000 #1447056960] DEBUG --
net.ssh.transport.server_version[800]: local is
`SSH-2.0-Ruby/Net::SSH_2.1.4 java'
D, [2011-08-02T15:41:13.861000 #1447056960] DEBUG -- tcpsocket[802]:
read 784 bytes
D, [2011-08-02T15:41:13.864000 #1447056960] DEBUG -- tcpsocket[802]:
received packet nr 0 type 20 len 780
I, [2011-08-02T15:41:13.865000 #1447056960]  INFO --
net.ssh.transport.algorithms[804]: got KEXINIT from server
I, [2011-08-02T15:41:13.868000 #1447056960]  INFO --
net.ssh.transport.algorithms[804]: sending KEXINIT
D, [2011-08-02T15:41:13.872000 #1447056960] DEBUG -- tcpsocket[802]:
queueing packet nr 0 type 20 len 556
D, [2011-08-02T15:41:13.874000 #1447056960] DEBUG -- tcpsocket[802]:
sent 560 bytes
I, [2011-08-02T15:41:13.875000 #1447056960]  INFO --
net.ssh.transport.algorithms[804]: negotiating algorithms
D, [2011-08-02T15:41:13.878000 #1447056960] DEBUG --
net.ssh.transport.algorithms[804]: negotiated:
* kex: diffie-hellman-group-exchange-sha1
* host_key: ssh-rsa
* encryption_server: aes128-cbc
* encryption_client: aes128-cbc
* hmac_client: hmac-sha1
* hmac_server: hmac-sha1
* compression_client: none
* compression_server: none
* language_client:
* language_server:
D, [2011-08-02T15:41:13.879000 #1447056960] DEBUG --
net.ssh.transport.algorithms[804]: exchanging keys
D, [2011-08-02T15:41:15.126000 #1447056960] DEBUG -- tcpsocket[802]:
queueing packet nr 1 type 34 len 20
D, [2011-08-02T15:41:15.128000 #1447056960] DEBUG -- tcpsocket[802]:
sent 24 bytes
D, [2011-08-02T15:41:15.132000 #1447056960] DEBUG -- tcpsocket[802]:
read 152 bytes
D, [2011-08-02T15:41:15.136000 #1447056960] DEBUG -- tcpsocket[802]:
received packet nr 1 type 31 len 148
D, [2011-08-02T15:41:15.190000 #1447056960] DEBUG -- tcpsocket[802]:
queueing packet nr 2 type 32 len 140
D, [2011-08-02T15:41:15.191000 #1447056960] DEBUG -- tcpsocket[802]:
sent 144 bytes
D, [2011-08-02T15:41:15.196000 #1447056960] DEBUG -- tcpsocket[802]:
read 464 bytes
D, [2011-08-02T15:41:15.200000 #1447056960] DEBUG -- tcpsocket[802]:
received packet nr 2 type 33 len 444
D, [2011-08-02T15:41:15.232000 #1447056960] DEBUG -- tcpsocket[802]:
queueing packet nr 3 type 21 len 20
D, [2011-08-02T15:41:15.233000 #1447056960] DEBUG -- tcpsocket[802]:
sent 24 bytes
D, [2011-08-02T15:41:15.235000 #1447056960] DEBUG -- tcpsocket[802]:
received packet nr 3 type 21 len 12
D, [2011-08-02T15:41:15.238000 #1447056960] DEBUG --
net.ssh.authentication.session[806]: beginning authentication of
`my_user_name'
D, [2011-08-02T15:41:15.242000 #1447056960] DEBUG -- tcpsocket[802]:
queueing packet nr 4 type 5 len 28
D, [2011-08-02T15:41:15.243000 #1447056960] DEBUG -- tcpsocket[802]:
sent 52 bytes
D, [2011-08-02T15:41:15.272000 #1447056960] DEBUG -- tcpsocket[802]:
read 52 bytes
D, [2011-08-02T15:41:15.273000 #1447056960] DEBUG -- tcpsocket[802]:
received packet nr 4 type 6 len 28
D, [2011-08-02T15:41:15.275000 #1447056960] DEBUG --
net.ssh.authentication.session[806]: trying password
D, [2011-08-02T15:41:15.277000 #1447056960] DEBUG -- tcpsocket[802]:
queueing packet nr 5 type 50 len 60
D, [2011-08-02T15:41:15.277000 #1447056960] DEBUG -- tcpsocket[802]:
sent 84 bytes
D, [2011-08-02T15:41:15.430000 #1447056960] DEBUG -- tcpsocket[802]:
read 36 bytes
D, [2011-08-02T15:41:15.432000 #1447056960] DEBUG -- tcpsocket[802]:
received packet nr 5 type 52 len 12
D, [2011-08-02T15:41:15.433000 #1447056960] DEBUG --
net.ssh.authentication.methods.password[808]: password succeeded
D, [2011-08-02T15:41:15.435000 #1447056960] DEBUG -- tcpsocket[802]:
queueing packet nr 6 type 90 len 44


At which point it just sites there.

Exact same code and versions work between linux boxes.

---

Chris

Chris Evans wrote in post #1014564:
> I'm trying to connect from an AIX server to another box, but ssh hangs
> after it authenticates.  Has anybody seen this, or have any ideas?
> doesn't matter if its connecting to a Solaris, AIX, or linux box.
>

Did you find a solution to your problem?

I am seeing the same problem, except that my program ends successfully
after "hanging" for a while.
The example program you showed also finishes after hanging for around 30
sec after password authentication and again around 30 sec after sending
the "exec" request.

I should add that I am trying to SSH to localhost.

My environment is:

  AIX 5.3

  jruby 1.6.5 (ruby-1.8.7-p330) (2011-10-25 9dcd388) (IBM J9 VM 1.6.0)
  [AIX-ppc-java]

  *** LOCAL GEMS ***

  bouncy-castle-java (1.5.0146.1)
  jruby-openssl (0.7.4)
  net-scp (1.0.4)
  net-ssh (2.2.1)

Any ideas?

Claus

Claus Folke Brobak wrote in post #1029946:
>
> My environment is:
>
>   AIX 5.3
>
>   jruby 1.6.5 (ruby-1.8.7-p330) (2011-10-25 9dcd388) (IBM J9 VM 1.6.0)
>   [AIX-ppc-java]
>

By using Java 5 instead of Java 6 I can avoid the temporary hang. My
environment then is:

  jruby 1.6.5 (ruby-1.8.7-p330) (2011-10-25 9dcd388) (IBM J9 VM 1.5.0)
  [AIX-ppc-java]

Unfortunately still no idea what is causing the hang.

Claus

Sorry to dredge up an old post, but I've recently run across this 
problem and I'm hoping someone has a better solution than "use java 
1.5".  I do have a few additional details which might help.

This is not a problem unique to net/ssh.  The hang occurs because 
IO.select is returning a socket as ready to read from when it has no 
data available for reading.  The subsequent call to recv blocks waiting 
for data.

I've attached a contrived but relatively simple example of this using a 
regular TCPSocket.  As mentioned previously, this fails on aix using 
java 1.6 or 1.7, but somehow works as expected using java 1.5.  It also 
works properly on any non-aix system (even when using the ibm jvm).

The internal workings of jruby's IO.select aren't quite as easy to 
follow, so this was about as far as I was able to trace it.  I've also 
only been able to test this with jruby through 1.6.8 as the current 
releases of 1.7.0 don't appear to have aix support yet.

Is this really a bug in jruby's IO.select on aix that has gone unnoticed 
for this long?

Any suggestions for getting this working on aix with java 1.6 or above?

Thanks,

-Michael

If you can come up with a reproduction, please file a bug!

I'd like to look at fixing this for 1.7.1.

- Charlie