jopenssl Cipher fails after first message (Net::SSH)
----------------------------------------------------
Key: JRUBY-1692
URL: http://jira.codehaus.org/browse/JRUBY-1692
Project: JRuby
Issue Type: Bug
Components: JRuby-extras
Environment: jopenssl trunk, JRuby trunk, WinXP, Java 1.6,
bcprov-jdk15-137.jar, Net::SSH 1.1.2; server sshd is OpenSSH 4.7 (cygwin)
Reporter: Bill Dortch
Attachments: sst.rb
jopenssl support for Net::SSH is nearly working (the new BN and DH classes used
for key exchange appear to work), but I'm getting a failure that appears to be
caused by a bug in cipher code (org.jruby.ext.openssl.Cipher.java).
Here's what happens, in brief (I've attached the debug output below, and have
attached some code to repro):
- the client and server negotiate algorithms and exchange keys
- Net::SSH creates two ciphers, one for _encrypt_, one for _decrypt_
- Net::SSH uses _encrypt_ cipher to encrypt and send message "ssh-userauth"
(plus some header fields)
- Net::SSH uses _decrypt_ cipher to decrypt the response, which also has the
value "ssh-userauth" (plus headers)
So far, so good -- we've encrypted and sent a message, and received and
decrypted a valid response. Now:
- Net::SSH uses _encrypt_ cipher to encrypt and send a "ssh-connection"
message, with username, password, and other info. *We don't know if this
worked*, because:
- Net::SSH uses _decrypt_ cipher to decrypt response. This actually takes
place in a couple of steps; first, a block is read and decrypted (packet
header), and the message length is extracted. This length is then used to
determine how much more data to read. However, *the length returned is
garbage*. Typically very large or very small garbage: the RubyIO module
attempts to allocate a ByteList, and either fails with a NegativeIndex
exception, or dies with an OutOfMemory error (because the size was so large).
So it appears that the cipher doesn't work for more than one message. I've
gone through the code and can't spot the bug; Cipher#final is being called
between messages, and I've walked through the code (jopenssl and BC) and
confirmed that BufferBlockCipher#doFinal is called, which appears to call
#reset on the underlying Cipher; in the DES code at least, it appears that this
correctly copies the original IV back to the buffer.
SO... I'm not sure why this is failing. On the other hand, there seems to be a
fair amount of uncertainty in the Cipher implementation (I fixed a couple of
glaring issues), so I wouldn't be surprised if there were some sort of
misunderstanding of the BC interfaces (not so well documented) or the
MRI-OpenSSL interface we're emulating (not documented at all), or the process
in general. I'm certainly out of my depth here, though I've been doing a lot
of research (Applied Cryptography is _sorely_ out-of-date; the newer Practical
Cryptography lacks details; Wikipedia has some pretty good info and pointers,
like this one on modes:
http://csrc.nist.gov/publications/nistpubs/800-38a/sp800-38a.pdf).
I've included a listing of a debug session below. The attached script will
reproduce this, though you'll have to plug in your username and password first
(and possibly hostname if you don't have sshd on your local machine -- I've got
OpenSSH running under cygwin on my WinXP box).
Try running the script under MRI-IRB to see what the results _should_ look
like. Getting pretty darned close, considering where things stood a few weeks
ago.
{noformat}
c:\temp>jirb
irb(main):001:0> load 'sst.rb'
[DEBUG] Sun Dec 09 04:34:31 -0800 2007 -- transport.session: connecting
[DEBUG] Sun Dec 09 04:34:31 -0800 2007 -- transport.version_negotiator: remote
server is "SSH-2.0-Op
enSSH_4.7"
[DEBUG] Sun Dec 09 04:34:31 -0800 2007 -- transport.session: waiting for packet
from server...
[DEBUG] Sun Dec 09 04:34:31 -0800 2007 -- transport.incoming_packet_stream:
reading 8 bytes from soc
ket...
[DEBUG] Sun Dec 09 04:34:31 -0800 2007 -- transport.incoming_packet_stream:
packet length(780) remai
ning(776)
[DEBUG] Sun Dec 09 04:34:31 -0800 2007 -- transport.incoming_packet_stream:
received: "\024\224\315\
345Y\335f\276\223H$?
\247\355M\315\000\000\000~diffie-hellman-group-exchange-sha256,diffie-hellman-g
roup-exchange-sha1,diffie-hellman-group14-sha1,diffie-hellman-group1-sha1\000\000\000\017ssh-rsa,ssh
-dss\000\000\000\235aes128-cbc,3des-cbc,blowfish-cbc,cast128-cbc,arcfour128,arcfour256,arcfour,aes19
2-cbc,aes256-cbc,[EMAIL
PROTECTED],aes128-ctr,aes192-ctr,aes256-ctr\000\000\000\235aes128-
cbc,3des-cbc,blowfish-cbc,cast128-cbc,arcfour128,arcfour256,arcfour,aes192-cbc,aes256-cbc,rijndael-c
[EMAIL
PROTECTED],aes128-ctr,aes192-ctr,aes256-ctr\000\000\000ihmac-md5,hmac-sha1,[EMAIL
PROTECTED]
m,hmac-ripemd160,[EMAIL
PROTECTED],hmac-sha1-96,hmac-md5-96\000\000\000ihmac-md5,hmac-sha1,
[EMAIL PROTECTED],hmac-ripemd160,[EMAIL
PROTECTED],hmac-sha1-96,hmac-md5-96\000\000\000\0
25none,[EMAIL PROTECTED],[EMAIL PROTECTED]
\000\000\000"
[DEBUG] Sun Dec 09 04:34:31 -0800 2007 -- transport.session: got packet of type
20
[DEBUG] Sun Dec 09 04:34:31 -0800 2007 -- transport.session: sending message
>>"\024\336Sf\037\340\3
14\263hZ\310\005oQ\263X\\\000\000\000=diffie-hellman-group-exchange-sha1,diffie-hellman-group1-sha1\
000\000\000\017ssh-rsa,ssh-dss\000\000\000D3des-cbc,aes128-cbc,blowfish-cbc,aes256-cbc,aes192-cbc,id
ea-cbc,none\000\000\000D3des-cbc,aes128-cbc,blowfish-cbc,aes256-cbc,aes192-cbc,idea-cbc,none\000\000
\0000hmac-md5,hmac-sha1,hmac-md5-96,hmac-sha1-96,none\000\000\0000hmac-md5,hmac-sha1,hmac-md5-96,hma
c-sha1-96,none\000\000\000\tnone,zlib\000\000\000\tnone,zlib\000\000\000\000\000\000\000\000\000\000
\000\000\000"<<
[DEBUG] Sun Dec 09 04:34:31 -0800 2007 -- transport.algorithm_negotiator: kex
algorithm: diffie-hell
man-group-exchange-sha1
[DEBUG] Sun Dec 09 04:34:31 -0800 2007 -- transport.algorithm_negotiator: host
key algorithm: ssh-rs
a
[DEBUG] Sun Dec 09 04:34:31 -0800 2007 -- transport.algorithm_negotiator:
encryption algorithm (clie
nt-to-server): 3des-cbc
[DEBUG] Sun Dec 09 04:34:31 -0800 2007 -- transport.algorithm_negotiator:
encryption algorithm (serv
er-to-client): 3des-cbc
[DEBUG] Sun Dec 09 04:34:31 -0800 2007 -- transport.algorithm_negotiator: hmac
algorithm (client-to-
server): hmac-md5
[DEBUG] Sun Dec 09 04:34:31 -0800 2007 -- transport.algorithm_negotiator: hmac
algorithm (server-to-
client): hmac-md5
[DEBUG] Sun Dec 09 04:34:31 -0800 2007 -- transport.algorithm_negotiator:
compression algorithm (cli
ent-to-server): none
[DEBUG] Sun Dec 09 04:34:31 -0800 2007 -- transport.algorithm_negotiator:
compression algorithm (ser
ver-to-client): none
[DEBUG] Sun Dec 09 04:34:31 -0800 2007 -- transport.algorithm_negotiator:
language (client-to-server
):
[DEBUG] Sun Dec 09 04:34:31 -0800 2007 -- transport.algorithm_negotiator:
language (server-to-client
):
OpenSSL::Cipher::Cipher:30: initialize arg: (12)[des-ede3-cbc]
OpenSSL::Cipher::Cipher:30: key_len: [24]
OpenSSL::Cipher::Cipher:30: block_size: [8]
OpenSSL::Cipher::Cipher:32: initialize arg: (12)[des-ede3-cbc]
OpenSSL::Cipher::Cipher:32: key_len: [24]
OpenSSL::Cipher::Cipher:32: block_size: [8]
[DEBUG] Sun Dec 09 04:34:31 -0800 2007 -- transport.session: sending message
>>"\"\000\000\004\000\0
00\000\004\000\000\000 \000"<<
[DEBUG] Sun Dec 09 04:34:31 -0800 2007 -- transport.session: waiting for packet
from server...
[DEBUG] Sun Dec 09 04:34:31 -0800 2007 -- transport.incoming_packet_stream:
reading 8 bytes from soc
ket...
[DEBUG] Sun Dec 09 04:34:31 -0800 2007 -- transport.incoming_packet_stream:
packet length(148) remai
ning(144)
[DEBUG] Sun Dec 09 04:34:31 -0800 2007 -- transport.incoming_packet_stream:
received: "\037\000\000\
000\201\000\312\255\335\354\026g\374h\265\372\025\325<N\0252\335$V\032\032-G\241,\001\253\352\036\00
0s\037i!\252\304\aB1\037\337\236cK\267\023\e\356\032\362@&\025T8\232\221\004%\340D\350\214\203Y\260\
020\365\255+\200\342\234\261\245\260'\261\235\236\001\246\366:oE\345\327\355/\366\242\240\010PP\247\
320\3170|=\265\035$\2205Y\a\264B|#\251\215\361\353\212\276\362\272
\233\267\261\265\247\257\000\000\
000\001\005"
[DEBUG] Sun Dec 09 04:34:31 -0800 2007 -- transport.session: got packet of type
31
[DEBUG] Sun Dec 09 04:34:31 -0800 2007 -- transport.session: sending message
>>" \000\000\000\200L\0
27f\213\177\270\335\273\274\306\354\212\f\357\202;\216\361[I\003\242T$\252\311\360N\257W\334\261\374
\236\204N\177fY6\276%'D\367\023\344F9\305\323w\256\342|\341\236^\322\353\022o\344'3\374\206z1q)#\215
\205\234V\233\242
\306\n\t\\\v9\310]\035\316\236\364\357\330BL\"\225\021\037\370H`\236Z\334`L\257\33
0>\002L/\331'\020!\226\330e\316\236W+6\256\001j"<<
[DEBUG] Sun Dec 09 04:34:31 -0800 2007 -- transport.session: waiting for packet
from server...
[DEBUG] Sun Dec 09 04:34:31 -0800 2007 -- transport.incoming_packet_stream:
reading 8 bytes from soc
ket...
[DEBUG] Sun Dec 09 04:34:31 -0800 2007 -- transport.incoming_packet_stream:
packet length(700) remai
ning(696)
[DEBUG] Sun Dec 09 04:34:31 -0800 2007 -- transport.incoming_packet_stream:
received: "!\000\000\001
\025\000\000\000\assh-rsa\000\000\000\001#\000\000\001\001\000\267}[l\241\"\205\315\241Z\n\245\342\2
56ydv\362\367v\252\257\273+X\237\026\362\365\027\314\263\353\262u\376W'o\003\355\a\323\252e\023\236\
362\273\312'\235\030\eF\212[\226\231\220'\217\\\344\263\273v#q\210\360\271>MW\300~\276\244oh\307jNJ\
370\252\223}5&\v\241X;\244m\363]\226\351\245m\t\232\340\276
\306\026[\310\363\3373c\216\t[\253\360\3
77t;H=\223\325\246\377\240\376\200\260#\240Ao/4\023i#E4\036\345{[]\016\000\370T\245s\256\364\310U\26
5L\204p\373\337\353\235\347\313`\n\251\"rn\325\376\361\376y\226~.\027\257\023W\272\005\232:\230Y8o\2
14\376\021\260\326\376\334\360o\315\235\200k\340*\227m0WoasA\016\307\a\204\\\347kD\221\344\327\250
\
336\310f\306\361>\031\232\311\310\373\223a\216\031\201>\313\354:%\021\274\217\000\000\000\200v\376AO
\004\a\024=Z
9\324&\032\217\337\030f_\211\314?\233T\300|\232\037\332\363\360'P\026\351\3428m\226A\26
3\t\355\341\200k\0239\2507\361\r\345\213\263\2567\262;[EMAIL PROTECTED]
04\347\203\017?\322\362\vSI\301d\266\266\025''0\010T\370K\304lv\365\354I\3026'_l\3673\211\344\325TQ\
246\r\262\233\311q\337\352\223\017\311\267\300\000\000\001\017\000\000\000\assh-rsa\000\000\001\000\
264\273\211\254xSi;!{\231\332\240\313\323$H\214\251\254\022l\036\264\240\221\346\023\021.4i\203\000\
[EMAIL PROTECTED]
5?\350\273c\363\240$\364z\000&\v\020\233\240\3738\234g\242\260\277B(;\372<\372Z\230C\0056\317$\246\3
13\306\373P4\252\200\367\360\205\236\217\233\221S\t\217\332\235\271\027\345\232\326b/\313\032u\005\3
54N\0366\317\020\304\326_\r\225\303\\L\201+\216\034\305\036]\346\302|\230\201\264\217!\366X\336%A\37
3k\v;'\200\210\224\0100F\311\313(\246\355\225\340\234\021\037\006'zu2R\333&\365\v-\355\f\327\\\216\2
73;\214\237)R\305,(<j\305\237O\366\2556M\027NV\264\373\277\330{\321\343\v_O\326\261]Q\366\246N\350\2
553[\002e~\004"
[DEBUG] Sun Dec 09 04:34:31 -0800 2007 -- transport.session: got packet of type
33
[DEBUG] Sun Dec 09 04:34:31 -0800 2007 -- transport.session: sending message
>>"\025"<<
[DEBUG] Sun Dec 09 04:34:31 -0800 2007 -- transport.session: waiting for packet
from server...
[DEBUG] Sun Dec 09 04:34:31 -0800 2007 -- transport.incoming_packet_stream:
reading 8 bytes from soc
ket...
[DEBUG] Sun Dec 09 04:34:31 -0800 2007 -- transport.incoming_packet_stream:
packet length(12) remain
ing(8)
[DEBUG] Sun Dec 09 04:34:31 -0800 2007 -- transport.incoming_packet_stream:
received: "\025"
[DEBUG] Sun Dec 09 04:34:31 -0800 2007 -- transport.session: got packet of type
21
OpenSSL::Cipher::Cipher:42: initialize arg: (12)[des-ede3-cbc]
OpenSSL::Cipher::Cipher:42: encrypt: (0)[]
OpenSSL::Cipher::Cipher:42: iv_len: [8]
OpenSSL::Cipher::Cipher:42: iv =
½]8)[úP?ìuì
OpenSSL::Cipher::Cipher:42: key_len: [24]
OpenSSL::Cipher::Cipher:42: key =
](24)[¦*?p+¶é(ó ?ç?,¶J¦+c?)5G
OpenSSL::Cipher::Cipher:44: initialize arg: (12)[des-ede3-cbc]
OpenSSL::Cipher::Cipher:44: decrypt: (0)[]
OpenSSL::Cipher::Cipher:44: iv_len: [8]
OpenSSL::Cipher::Cipher:44: iv =
(8)[µ£q+rF+L]
OpenSSL::Cipher::Cipher:44: key_len: [24]
OpenSSL::Cipher::Cipher:44: key =
(24)[¦T{¦UG++Gª+ SHnº(bf?5l]ï]
[DEBUG] Sun Dec 09 04:34:32 -0800 2007 -- transport.session: sending message
>>"\005\000\000\000\fss
h-userauth"<<
OpenSSL::Cipher::Cipher:42: block_size: [8]
OpenSSL::Cipher::Cipher:42: block_size: [8]
OpenSSL::Cipher::Cipher:42: block_size: [8]
OpenSSL::Cipher::Cipher:42: update arg:
(32)[ ?
? ?ssh-userauth?Çdî=?cKvG]
OpenSSL::Cipher::Cipher:42: update result:
(32)[?+ëG+¦+¦¤6=6ä- [EMAIL PROTECTED]
OpenSSL::Cipher::Cipher:42: final: (0)[]
[DEBUG] Sun Dec 09 04:34:32 -0800 2007 -- transport.session: waiting for packet
from server...
OpenSSL::Cipher::Cipher:44: block_size: [8]
[DEBUG] Sun Dec 09 04:34:32 -0800 2007 -- transport.incoming_packet_stream:
reading 8 bytes from soc
ket...
OpenSSL::Cipher::Cipher:44: block_size: [8]
OpenSSL::Cipher::Cipher:44: update arg:
(8)[ª-P="@+A]
OpenSSL::Cipher::Cipher:44: update result:
(8)[ ?
? ]
OpenSSL::Cipher::Cipher:44: block_size: [8]
[DEBUG] Sun Dec 09 04:34:32 -0800 2007 -- transport.incoming_packet_stream:
packet length(28) remain
ing(24)
OpenSSL::Cipher::Cipher:44: update arg:
ù?¦9?TÿÆM- 8? QGi?'Äú¦ëX]
OpenSSL::Cipher::Cipher:44: update result:
(24)[ ?ssh-userauth¥{¦M?+7?+?]
OpenSSL::Cipher::Cipher:44: final: (0)[]
[DEBUG] Sun Dec 09 04:34:32 -0800 2007 -- transport.incoming_packet_stream:
received: "\006\000\000\
000\fssh-userauth"
[DEBUG] Sun Dec 09 04:34:32 -0800 2007 -- transport.session: got packet of type
6
[DEBUG] Sun Dec 09 04:34:32 -0800 2007 -- userauth.driver: trying "password"
[DEBUG] Sun Dec 09 04:34:32 -0800 2007 -- transport.session: sending message
>>"2\000\000\000\016MYU
SERNAMEXXXX\000\000\000\016ssh-connection\000\000\000\010password\000\000\000\000\010MYPASSWD"<<
OpenSSL::Cipher::Cipher:42: block_size: [8]
OpenSSL::Cipher::Cipher:42: block_size: [8]
OpenSSL::Cipher::Cipher:42: update arg:
(72)[ D?2 ?MYUSERNAMEXXXX ?ssh-connection password MYPASSWD+8?4+]
OpenSSL::Cipher::Cipher:42: update result:
(72)[A.Ü[+?-°-§iI+?+n+²-?ÿO=-@<n%¦O94£â+ÑF_Ém+T(%²o&8÷¿¦ÿ+9?+«<dæ+hSÆ#²C?k?]
OpenSSL::Cipher::Cipher:42: final: (0)[]
[DEBUG] Sun Dec 09 04:34:32 -0800 2007 -- transport.session: waiting for packet
from server...
OpenSSL::Cipher::Cipher:44: block_size: [8]
[DEBUG] Sun Dec 09 04:34:32 -0800 2007 -- transport.incoming_packet_stream:
reading 8 bytes from soc
ket...
OpenSSL::Cipher::Cipher:44: block_size: [8]
OpenSSL::Cipher::Cipher:44: update arg:
(8)[/+p?ë?ò¡]
OpenSSL::Cipher::Cipher:44: update result:
(8)[ÅùVt¦?^¶]
OpenSSL::Cipher::Cipher:44: block_size: [8]
[DEBUG] Sun Dec 09 04:34:32 -0800 2007 -- transport.incoming_packet_stream:
packet length(2409059956
) remaining(2409059952)
NativeException: java.lang.NegativeArraySizeException: null
from ByteList.java:66:in `org.jruby.util.ByteList.<init>'
from IOHandlerNio.java:266:in `org.jruby.util.IOHandlerNio.read'
from RubyIO.java:1212:in `org.jruby.RubyIO.read'
from null:-1:in `org.jruby.RubyIOInvoker$read_method_0_0.call'
from CallSite.java:144:in
`org.jruby.runtime.CallSite$InlineCachingCallSite.call'
from CallSite.java:103:in
`org.jruby.runtime.CallSite$ArgumentBoxingCallSite.call'
from ASTInterpreter.java:653:in
`org.jruby.evaluator.ASTInterpreter.callNode'
from ASTInterpreter.java:300:in
`org.jruby.evaluator.ASTInterpreter.evalInternal'
from ASTInterpreter.java:2158:in
`org.jruby.evaluator.ASTInterpreter.setupArgs'
from ASTInterpreter.java:645:in
`org.jruby.evaluator.ASTInterpreter.callNode'
from ASTInterpreter.java:300:in
`org.jruby.evaluator.ASTInterpreter.evalInternal'
from ASTInterpreter.java:627:in
`org.jruby.evaluator.ASTInterpreter.blockNode'
from ASTInterpreter.java:294:in
`org.jruby.evaluator.ASTInterpreter.evalInternal'
from ASTInterpreter.java:1765:in
`org.jruby.evaluator.ASTInterpreter.whileNode'
from ASTInterpreter.java:480:in
`org.jruby.evaluator.ASTInterpreter.evalInternal'
from ASTInterpreter.java:627:in
`org.jruby.evaluator.ASTInterpreter.blockNode'
... 267 levels...
from
C:/jruby/trunk/lib/ruby/gems/1.8/gems/net-ssh-1.1.2/lib/net/ssh/transport/session.rb:26
5:in `wait_for_message'
from
C:/jruby/trunk/lib/ruby/gems/1.8/gems/net-ssh-1.1.2/lib/net/ssh/transport/session.rb:25
8:in `loop'
from C:/jruby/trunk/lib/ruby/gems/1.8/gems/net-ssh-1.1.2/lib/n
{noformat}
--
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
