Re: Problems exchanging data with remote server

["Oliver Stöneberg" <oliverst@xxxxxxxxx>]

Hi,

I would love to help (and did already contribute to the project), but 
unfortunately everything related to the actual protocol is over my 
head.

Sorry and Greetings
Oliver

> Hi all,
> 
>  
> 
> Is there anyone on the libssh mailing list that could possibly spend some of
> his/her time on my earlier mail (see also below)?
> 
> As I am pretty stuck at the moment I'd really appreciate it!
> 
>  
> 
> Best regards,
> 
> Herwin
> 
>  
> 
> From: Herwin Kleinjan [mailto:herwin.kleinjan@xxxxxxxxxxx] 
> Sent: dinsdag 26 juli 2011 12:33
> To: libssh@xxxxxxxxxx
> Cc: development@xxxxxxxxxxx
> Subject: Problems exchanging data with remote server
> 
>  
> 
> Hi,
> 
>  
> 
> We have used libssh 0.5.0 to create an SSHv2 client that we will use to
> connect to a remote F-Secure SSHv2 server, running on a Windows NT machine.
> The connection setup and login phases are successful, but when we send data
> over this connection, the remote SSH server responds with two messages, the
> first one being an SSH_MSG_IGNORE (which is ignored of course) and the
> second one being an SSH_MSG_DISCONNECT message which causes the connection
> to be terminated. The error message we see traced by our client is: 
> 
>  
> 
> Received SSH_MSG_DISCONNECT: 33554432:Window overflow received channel data.
> 
>  
> 
> When I searched the net for any help, I came upon three sites that might
> relate to this problem. 
> 
>  
> 
> The first one is
> http://www.enterprisedt.com/products/edtftpnetpro/history.html which
> contains the edtFTPnet/PRO Product History. One of the issues of this
> product that was addressed in the past has the following description "Fixed
> "Window overflow received channel data" SSH problem where remote window size
> negotiation was not correctly handled." 
> 
> I did some debugging with gdb and indeed I saw that window sizes of client
> and server were not identical. Using the debugger, I modified the value on
> the client side so that it matched the server's value, but this did not
> resolve the problem, I was still getting the same SSH_MSG_DISCONNECT when I
> send some data.
> 
>  
> 
> The second site that I found is this one:
> http://www.biac.duke.edu/forums/topic.asp?TOPIC_ID=38, it contains a
> discussion some 8 years ago where someone mentioned the a similar problem
> when using scp on a *NIX machine to connect to F-Secure SSH server. The
> conclusion in the end of the thread was is: "This is a known incompatibility
> between OpenSSH and F-Secure SSH
> (http://bugzilla.mindrot.org/show_bug.cgi?id=248)".
> 
> Although I am not using scp, I am connecting to an F-Secure SSH server. 
> 
>  
> 
> The third site is: http://www.perlmonks.org/index.pl/jacques?node_id=642950,
> it deals with the problem someone has using net::ssh::Perl to connect to
> (again!) an F-Secure SSH server running on a Windows system. The solution in
> this case was to change the command terminator from the regular '\n' to
> '\n\r'.
> 
> As I am sending commands as well to the server that we just terminated with
> a '\n', I attached a debugger to the client and modified the command so that
> it would be terminated using '\n\r'. But unfortunately, this too did not
> make a difference.
> 
>  
> 
> I have several questions that I would appreciate some feedback on.
> 
>  
> 
> Q1. Could it be that window size negotiation is indeed a problem here and
> that it can/may not be adjusted after the connection establishment and
> authentication have been completed?
> 
> Q2. Are you aware of any issues with the implementation of SSHv2 in the
> F-Secure SSH server?
> 
> Q3. Is there any difference in the 'ssh_channel_write()' and the
> 'ssh_channel_request_exec()' functions? Currently we are using the former
> call and the data is actually just a string with the command we wish to
> execute (and len is set to the length of the string). Could we, or perhaps
> should we, be using the latter function call? 
> 
>  
> 
> At this moment, we have no idea why the remote server sends the
> SSH_MSG_DISCONNECT and unfortunately we are also unable to control it or
> enable application level logging on it.  However, when we connect to the
> remote server using an SSH client provided with the OS (RHEL 5.4), we are
> able to connect to the remote server and when we send the same command, we
> get the response we expect so all seems fine in this scenario.  Attached you
> will find two Wireshark dumps, the first one (BSCResetCBC_20110722.pcap) is
> a dump of a session using our own client during which we run into the
> problem. The second dump (BSCResetCLI_20110722.pcap)is from a session using
> the SSH client of the RHEL OS which is based on OpenSSH, this works
> flawlessly. We have also enabled packet logging in the libssh library and
> what we see when we setup the connection and then send data is this listed
> below. 
> 
>  
> 
> Could you please have a look at the wireshark dumps and the logging below
> and comment on them? Any help is really appreciated!
> 
>  
> 
> Client startup, connection setup and authentication:
> 
> [1] libssh 0.5.0 (c) 2003-2010 Aris Adamantiadis (aris@xxxxxxxxxxxx)
> Distributed under the LGPL, please refer to COPYING file for information
> about your rights, using threading threads_noop
> 
> [3] host 10.28.0.11 matches an IP address
> 
> [2] Nonblocking connection socket: 13
> 
> [2] Socket connecting, now waiting for the callbacks to work
> 
> [3] Received POLLOUT in connecting state
> 
> [1] Socket connection callback: 1 (0)
> 
> [3] Received banner: SSH-2.0-3.2.0 F-Secure SSH Windows NT Server
> 
> [1] SSH server banner: SSH-2.0-3.2.0 F-Secure SSH Windows NT Server
> 
> [1] Analyzing banner: SSH-2.0-3.2.0 F-Secure SSH Windows NT Server
> 
> [3] Enabling POLLOUT for socket
> 
> [3] Packet size decrypted: 12 (0xc)
> 
> [3] Read a 12 bytes packet
> 
> [3] 6 bytes padding, 11 bytes left in buffer
> 
> [3] After padding, 5 bytes left in buffer
> 
> [3] Final size 5
> 
> [3] Type 2
> 
> [3] Dispatching handler for packet type 2
> 
> [2] Received SSH_MSG_IGNORE packet
> 
> [3] Processing 472 bytes left in socket buffer
> 
> [3] Packet size decrypted: 468 (0x1d4)
> 
> [3] Read a 468 bytes packet
> 
> [3] 6 bytes padding, 467 bytes left in buffer
> 
> [3] After padding, 461 bytes left in buffer
> 
> [3] Final size 461
> 
> [3] Type 20
> 
> [3] Dispatching handler for packet type 20
> 
> [3] Writing on the wire a packet having 141 bytes before
> 
> [3] 141 bytes after comp + 6 padding bytes = 148 bytes packet
> 
> [3] Enabling POLLOUT for socket
> 
> [3] Writing on the wire a packet having 134 bytes before
> 
> [3] 134 bytes after comp + 5 padding bytes = 140 bytes packet
> 
> [3] Enabling POLLOUT for socket
> 
> [3] Packet size decrypted: 12 (0xc)
> 
> [3] Read a 12 bytes packet
> 
> [3] 6 bytes padding, 11 bytes left in buffer
> 
> [3] After padding, 5 bytes left in buffer
> 
> [3] Final size 5
> 
> [3] Type 2
> 
> [3] Dispatching handler for packet type 2
> 
> [2] Received SSH_MSG_IGNORE packet
> 
> [3] Processing 1024 bytes left in socket buffer
> 
> [3] Packet size decrypted: 1020 (0x3fc)
> 
> [3] Read a 1020 bytes packet
> 
> [3] 5 bytes padding, 1019 bytes left in buffer
> 
> [3] After padding, 1014 bytes left in buffer
> 
> [3] Final size 1014
> 
> [3] Type 31
> 
> [3] Dispatching handler for packet type 31
> 
> [2] Received SSH_KEXDH_REPLY
> 
> [3] Writing on the wire a packet having 1 bytes before
> 
> [3] 1 bytes after comp + 10 padding bytes = 12 bytes packet
> 
> [3] Enabling POLLOUT for socket
> 
> [2] SSH_MSG_NEWKEYS sent
> 
> [3] Packet size decrypted: 12 (0xc)
> 
> [3] Read a 12 bytes packet
> 
> [3] 6 bytes padding, 11 bytes left in buffer
> 
> [3] After padding, 5 bytes left in buffer
> 
> [3] Final size 5
> 
> [3] Type 2
> 
> [3] Dispatching handler for packet type 2
> 
> [2] Received SSH_MSG_IGNORE packet
> 
> [3] Processing 16 bytes left in socket buffer
> 
> [3] Packet size decrypted: 12 (0xc)
> 
> [3] Read a 12 bytes packet
> 
> [3] 10 bytes padding, 11 bytes left in buffer
> 
> [3] After padding, 1 bytes left in buffer
> 
> [3] Final size 1
> 
> [3] Type 21
> 
> [3] Dispatching handler for packet type 21
> 
> [2] Received SSH_MSG_NEWKEYS
> 
> [3] Set output algorithm to aes256-cbc
> 
> [3] Set input algorithm to aes256-cbc
> 
> [3] ssh_connect: Actual state : 7
> 
> [3] Writing on the wire a packet having 17 bytes before
> 
> [3] 17 bytes after comp + 10 padding bytes = 28 bytes packet
> 
> [3] Encrypting packet with seq num: 3, len: 32
> 
> [3] Enabling POLLOUT for socket
> 
> [3] Sent SSH_MSG_SERVICE_REQUEST (service ssh-userauth)
> 
> [3] Decrypting 16 bytes
> 
> [3] Packet size decrypted: 12 (0xc)
> 
> [3] Read a 12 bytes packet
> 
> [3] Decrypting 0 bytes
> 
> [3] 6 bytes padding, 11 bytes left in buffer
> 
> [3] After padding, 5 bytes left in buffer
> 
> [3] Final size 5
> 
> [3] Type 2
> 
> [3] Dispatching handler for packet type 2
> 
> [2] Received SSH_MSG_IGNORE packet
> 
> [3] Processing 52 bytes left in socket buffer
> 
> [3] Decrypting 16 bytes
> 
> [3] Packet size decrypted: 28 (0x1c)
> 
> [3] Read a 28 bytes packet
> 
> [3] Decrypting 16 bytes
> 
> [3] 10 bytes padding, 27 bytes left in buffer
> 
> [3] After padding, 17 bytes left in buffer
> 
> [3] Final size 17
> 
> [3] Type 6
> 
> [3] Dispatching handler for packet type 6
> 
> [3] Received SSH_MSG_SERVICE_ACCEPT
> 
> [3] Writing on the wire a packet having 56 bytes before
> 
> [3] 56 bytes after comp + 19 padding bytes = 76 bytes packet
> 
> [3] Encrypting packet with seq num: 4, len: 80
> 
> [3] Enabling POLLOUT for socket
> 
> [3] Decrypting 16 bytes
> 
> [3] Packet size decrypted: 1036 (0x40c)
> 
> [3] Read a 1036 bytes packet
> 
> [3] Decrypting 1024 bytes
> 
> [3] 7 bytes padding, 1035 bytes left in buffer
> 
> [3] After padding, 1028 bytes left in buffer
> 
> [3] Final size 1028
> 
> [3] Type 2
> 
> [3] Dispatching handler for packet type 2
> 
> [2] Received SSH_MSG_IGNORE packet
> 
> [3] Processing 36 bytes left in socket buffer
> 
> [3] Decrypting 16 bytes
> 
> [3] Packet size decrypted: 12 (0xc)
> 
> [3] Read a 12 bytes packet
> 
> [3] Decrypting 0 bytes
> 
> [3] 10 bytes padding, 11 bytes left in buffer
> 
> [3] After padding, 1 bytes left in buffer
> 
> [3] Final size 1
> 
> [3] Type 52
> 
> [3] Dispatching handler for packet type 52
> 
> [3] Received SSH_USERAUTH_SUCCESS
> 
> [2] Authentication successful
> 
> [2] Creating a channel 43 with 64000 window and 32000 max packet
> 
> [3] Writing on the wire a packet having 24 bytes before
> 
> [3] 24 bytes after comp + 19 padding bytes = 44 bytes packet
> 
> [3] Encrypting packet with seq num: 5, len: 48
> 
> [3] Enabling POLLOUT for socket
> 
> [3] Sent a SSH_MSG_CHANNEL_OPEN type session for channel 43
> 
> [3] Decrypting 16 bytes
> 
> [3] Packet size decrypted: 12 (0xc)
> 
> [3] Read a 12 bytes packet
> 
> [3] Decrypting 0 bytes
> 
> [3] 6 bytes padding, 11 bytes left in buffer
> 
> [3] After padding, 5 bytes left in buffer
> 
> [3] Final size 5
> 
> [3] Type 2
> 
> [3] Dispatching handler for packet type 2
> 
> [2] Received SSH_MSG_IGNORE packet
> 
> [3] Processing 52 bytes left in socket buffer
> 
> [3] Decrypting 16 bytes
> 
> [3] Packet size decrypted: 28 (0x1c)
> 
> [3] Read a 28 bytes packet
> 
> [3] Decrypting 16 bytes
> 
> [3] 10 bytes padding, 27 bytes left in buffer
> 
> [3] After padding, 17 bytes left in buffer
> 
> [3] Final size 17
> 
> [3] Type 91
> 
> [3] Dispatching handler for packet type 91
> 
> [3] Received SSH2_MSG_CHANNEL_OPEN_CONFIRMATION
> 
> [2] Received a CHANNEL_OPEN_CONFIRMATION for channel 43:0
> 
> [2] Remote window : 100000, maxpacket : 32000
> 
>  
> 
> The client sends a data packet to the server:
> 
> [3] Writing on the wire a packet having 152 bytes before
> 
> [3] 152 bytes after comp + 19 padding bytes = 172 bytes packet
> 
> [3] Encrypting packet with seq num: 6, len: 176
> 
> [3] Enabling POLLOUT for socket
> 
> [1] channel_write wrote 143 bytes
> 
>  
> 
> The client receives a data packet from the server:
> 
> [3] Decrypting 16 bytes
> 
> [3] Packet size decrypted: 12 (0xc)
> 
> [3] Read a 12 bytes packet
> 
> [3] Decrypting 0 bytes
> 
> [3] 6 bytes padding, 11 bytes left in buffer
> 
> [3] After padding, 5 bytes left in buffer
> 
> [3] Final size 5
> 
> [3] Type 2
> 
> [3] Dispatching handler for packet type 2
> 
> [2] Received SSH_MSG_IGNORE packet
> 
> [3] Processing 84 bytes left in socket buffer
> 
> [3] Decrypting 16 bytes
> 
> [3] Packet size decrypted: 60 (0x3c)
> 
> [3] Read a 60 bytes packet
> 
> [3] Decrypting 48 bytes
> 
> [3] 6 bytes padding, 59 bytes left in buffer
> 
> [3] After padding, 53 bytes left in buffer
> 
> [3] Final size 53
> 
> [3] Type 1
> 
> [3] Dispatching handler for packet type 1
> 
> [3] Received SSH_MSG_DISCONNECT 33554432:Window overflow received channel
> data.
> 
> [1] Received SSH_MSG_DISCONNECT: 33554432:Window overflow received channel
> data.
> 
>  
> 
> The client tries to send a second data packet to the server, but fails as
> the connection has been terminated:
> 
> [3] Writing on the wire a packet having 44 bytes before
> 
> [3] 44 bytes after comp + 15 padding bytes = 60 bytes packet
> 
> [3] Encrypting packet with seq num: 7, len: 64
> 
> [1] Error : Writing packet: error on socket (or connection closed):
> Operation now in progress
> 
> [1] channel_write wrote 35 bytes
> 
>  
> 
> Best regards,
> 
> Herwin
> 
>  
> 
> Herwin Kleinjan
> 
> R&D Lead Engineer 
> 
>  
> 
> o n e 2 m a n y
> 
> Leeuwenbrug 115
> 
> 7411 TH Deventer
> 
> The Netherlands
> 
>  
> 
> T: +31 (0)88 00 349 14
> 
> F: +31 (0)88 00 349 01
> 
> M: +31 (0)6  5198  3161
> E:  herwin.kleinjan@xxxxxxxxxxx
> 
>  
> 
> www.one2many.eu 
> 
>  
> 
>       
> 
>  
> 
> This e-mail and any attachment is for authorised use by the intended
> recipient(s) only. It contains proprietary material, confidential
> information and/or be subject to legal privilege. It should not be copied,
> disclosed to, retained or used by, any other party. If you are not an
> intended recipient then please promptly delete this e-mail and any
> attachment and all copies and inform the sender. Thank you.
> 
>  
> 
>