Knowledgebase
SFTP channel open failure
Posted by Mohammad Jawwad on 07 November 2008 12:22 AM
When a client program connects to a SSH based server the client and server enter a negotiation phase where they both eventually 'settle' for a certain window size. This usually involves closing the existing channel and opening a new one in place of it. Sometimes this negotiation does not take place as expected - the server does not close the previous channel properly before opening a new one with an increased window size. An example debug log of this 'bad' negotiation is shown below :

=======================================================================

INFO [SSH CONNECTION] service started
INFO [SSH CONNECTION] opening channel: Jscape.Ssh.Connection.Channels.SessionClient+x8af637d1006f0ed2
FINE [SSH TRANSPORT] message sent: SSH_MSG_CHANNEL_OPEN, channel type: session, sender channel: 0, initial window size: 131072, max packet size: 32768
FINE [SSH TRANSPORT] message received: SSH_MSG_CHANNEL_OPEN_CONFIRMATION, recipient channel: 0, sender channel: 52, initial window size: 300000, max packet size: 30000
INFO [SSH CONNECTION] channel opened, local #0
FINE [SSH TRANSPORT] message sent: SSH_MSG_CHANNEL_EOF, recipient channel: 52
FINE [SSH TRANSPORT] message sent: SSH_MSG_CHANNEL_CLOSE, recipient channel: 52
INFO [SSH CONNECTION] opening channel: Jscape.Ssh.Connection.Channels.SessionClient+x8af637d1006f0ed2
ERROR [SSH TRANSPORT] exception: IOException: EOF reached
INFO [SSH TRANSPORT] service closed
INFO [SSH CONNECTION] service closed

=======================================================================

The debug log shows that SSH_MSG_CHANNEL_CLOSE was sent but never received. Soon afterwards the service was unexpectedly closed after a IOException. This is where the window size negotiation went bad. The above log was from WS_FTP version 7.0 for those who are wondering what server was used.
In these circumstances one cannot do much except wait for a fixed version of the server to come along. Until then the following code can prevent the negotiation and hence avoid this issue entirely :

SshParameters params = new SshParameters(hostname, username, password);
Sftp s = new Sftp(sp);
s.UseAdaptiveConnect = false;
s.Connect();
s.Disconnect();

The third line of code achieves out purpose of preventing the window size negotiation. After this code was run the following log was generated :

=======================================================================

INFO [SSH CONNECTION] service started
INFO [SSH CONNECTION] opening channel: Jscape.Ssh.Connection.Channels.SessionClient+x8af637d1006f0ed2
FINE [SSH TRANSPORT] message sent: SSH_MSG_CHANNEL_OPEN, channel type: session, sender channel: 0, initial window size: 131072, max packet size: 32768
FINE [SSH TRANSPORT] message received: SSH_MSG_CHANNEL_OPEN_CONFIRMATION, recipient channel: 0, sender channel: 53, initial window size: 300000, max packet size: 30000
INFO [SSH CONNECTION] channel opened, local #0
FINE [SSH TRANSPORT] message sent: SSH_MSG_CHANNEL_REQUEST, recipient channel: 53, request type: subsystem, want reply: True
FINE [SSH TRANSPORT] message received: SSH_MSG_CHANNEL_SUCCESS, recipient channel: 0
FINE SSH_FXP_INIT, version: 3
FINE [SSH TRANSPORT] message sent: SSH_MSG_CHANNEL_DATA, recipient channel: 53
FINE [SSH TRANSPORT] message received: SSH_MSG_CHANNEL_DATA, recipient channel: 0
FINE SSH_FXP_VERSION, version: 3, extensions:
FINE SSH_FXP_REALPATH, path: .
FINE [SSH TRANSPORT] message sent: SSH_MSG_CHANNEL_DATA, recipient channel: 53
FINE [SSH TRANSPORT] message received: SSH_MSG_CHANNEL_DATA, recipient channel: 0
FINE SSH_FXP_NAME, files:
-rwxr-x--- 1 0 0 0 Jan 01 00:00 /users/glacier

FINE [SSH TRANSPORT] message sent: SSH_MSG_CHANNEL_EOF, recipient channel: 53
FINE [SSH TRANSPORT] message received: SSH_MSG_CHANNEL_CLOSE, recipient channel: 0
FINE [SSH TRANSPORT] message sent: SSH_MSG_CHANNEL_CLOSE, recipient channel: 53
INFO [SSH CONNECTION] service closed
INFO [SSH TRANSPORT] service closed

=====================================================================

We can see that the SSH_MSG_CHANNEL_CLOSE was sent and received as required by RFC specifications. No exceptions are evident by the above log.

(138 vote(s))
This article was helpful
This article was not helpful

Comments (0)
Post a new comment
 
 
Full Name:
Email:
Comments:
CAPTCHA Verification 
 
Please enter the text you see in the image into the textbox below. This is required to prevent automated registrations and form submissions.

Help Desk Software by Kayako fusion