Ask a Question

SFTP SSH: Rebex.Net.SshException: The channel has been closed

0 votes
by (160 points)
edited

Hello, I had a strange event yesterday, were files got lost. And Im not sure if it is related to this exception:

SSH: Rebex.Net.SshException: The channel has been closed

The process reads a list of files from the SFTP server downloads and deletes them. Except for the closed channel exception the Rebex log looks fine. At least from what I read.

Does a Rebex.Net.SshException: The channel has been closed exception indicate that data was lost and the file was not downloaded properly?

regards, FDA

Applies to: Rebex SFTP, Rebex Terminal Emulation
by (58.9k points)
edited

Hello, the SftpException 'The channel has been closed.' is reported when the server closes the actual channel through which the information (e.g. files) is transferred.

Of course, if the client was right in the middle of downloading a file from the SSH/SFTP server, and you got this exception, then the file download was aborted.

Please send us the communication log to support@rebex.net or post it here, so that we could look into to help resolve the issue.

By the way what version of Rebex SFTP are you using?

2 Answers

0 votes
by (160 points)
edited

Hi, thanks for the replay I use: Rebex SFTP for .NET 3.0.4700.0

I'm aware that I delete the files at the end, but the Process did not realize that the file did not download correctly. The Exception was not thrown to the client.

The only file that was ok is File_20140205_140409.txt it somehow got through the process fine logs:

2014-02-06 13:38:31.916 Opening log file.
2014-02-06 13:38:31.948 INFO Sftp(1)[347] Info: Connecting to xxx.xxx.xxx.xxx:22 using Sftp 3.0.4700.0.
2014-02-06 13:38:32.041 DEBUG Sftp(1)[347] SSH: Server is 'SSH-2.0-1.36 sshlib: GlobalScape'.
2014-02-06 13:38:32.057 INFO Sftp(1)[347] SSH: Negotiation started.
2014-02-06 13:38:32.166 DEBUG Sftp(1)[347] SSH: Negotiating key.
2014-02-06 13:38:32.275 DEBUG Sftp(1)[347] SSH: Validating signature.
2014-02-06 13:38:32.322 INFO Sftp(1)[347] SSH: Negotiation finished.
2014-02-06 13:38:32.322 INFO Sftp(1)[347] Info: Server: SSH-2.0-1.36 sshlib: GlobalScape
2014-02-06 13:38:32.322 INFO Sftp(1)[347] Info: Fingerprint: xx:xx:xx:xx:xx:xx:xx:xx:xx:xx:xx:xx:xx:xx:xx:xx
2014-02-06 13:38:32.322 INFO Sftp(1)[347] Info: Cipher info: SSH 2.0, Diffie-Hellman-Group1-SHA1, DSS, aes256-cbc/aes256-cbc, hmac-sha1/hmac-sha1
2014-02-06 13:38:32.384 INFO Sftp(1)[347] SSH: Received banner:       
2014-02-06 13:38:32.416 DEBUG Sftp(1)[347] SSH: Allowed authentication methods: publickey, password.
2014-02-06 13:38:32.416 DEBUG Sftp(1)[347] SSH: Trying password authentication for 'xsomeUserx'.
2014-02-06 13:38:32.447 DEBUG Sftp(1)[347] SSH: Authentication successful.
2014-02-06 13:38:32.494 DEBUG Sftp(1)[347] SSH: Requesting subsystem 'sftp'.
2014-02-06 13:38:32.540 INFO Sftp(1)[347] Command: SSH_FXP_INIT (4)
2014-02-06 13:38:32.572 INFO Sftp(1)[347] Response: SSH_FXP_VERSION (3, 0 extensions)
2014-02-06 13:38:32.587 INFO Sftp(1)[347] Info: Using SFTP v3 on a Windows-like platform.
2014-02-06 13:38:32.603 INFO Sftp(1)[347] Command: SSH_FXP_REALPATH (1, '.')
2014-02-06 13:38:32.634 INFO Sftp(1)[347] Response: SSH_FXP_NAME (1, 1 item)
2014-02-06 13:38:32.634 INFO Sftp(1)[347] Info: Current directory is '/'.
2014-02-06 13:38:32.681 INFO Sftp(1)[347] Command: SSH_FXP_OPENDIR (2, '/')
2014-02-06 13:38:32.712 INFO Sftp(1)[347] Response: SSH_FXP_HANDLE (2, 0x31)
2014-02-06 13:38:32.712 INFO Sftp(1)[347] Command: SSH_FXP_READDIR (3, 0x31)
2014-02-06 13:38:32.743 INFO Sftp(1)[347] Response: SSH_FXP_NAME (3, 12 items)
2014-02-06 13:38:32.743 INFO Sftp(1)[347] Command: SSH_FXP_READDIR (4, 0x31)
2014-02-06 13:38:32.774 INFO Sftp(1)[347] Response: SSH_FXP_STATUS (4, 1, 'eof')
2014-02-06 13:38:32.774 INFO Sftp(1)[347] Command: SSH_FXP_CLOSE (5, 0x31)
2014-02-06 13:38:32.806 INFO Sftp(1)[347] Response: SSH_FXP_STATUS (5, 0, 'Ok')
2014-02-06 13:38:32.837 INFO Sftp(1)[347] Command: SSH_FXP_OPEN (6, '/File_20140123_001655.txt', 1)
2014-02-06 13:38:32.852 INFO Sftp(1)[347] Response: SSH_FXP_HANDLE (6, 0x31)
2014-02-06 13:38:32.884 INFO Sftp(1)[347] Command: SSH_FXP_OPEN (7, '/File_20140128_004736.txt', 1)
2014-02-06 13:38:32.899 INFO Sftp(1)[347] Response: SSH_FXP_HANDLE (7, 0x32)
2014-02-06 13:38:32.899 INFO Sftp(1)[347] Command: SSH_FXP_OPEN (8, '/File_20140129_140405.txt', 1)
2014-02-06 13:38:32.962 INFO Sftp(1)[347] Response: SSH_FXP_HANDLE (8, 0x33)
2014-02-06 13:38:32.962 INFO Sftp(1)[347] Command: SSH_FXP_OPEN (9, '/File_20140130_140410.txt', 1)
2014-02-06 13:38:32.993 INFO Sftp(1)[347] Response: SSH_FXP_HANDLE (9, 0x34)
2014-02-06 13:38:33.008 INFO Sftp(1)[347] Command: SSH_FXP_OPEN (10, '/File_20140131_114153.txt', 1)
2014-02-06 13:38:33.024 INFO Sftp(1)[347] Response: SSH_FXP_HANDLE (10, 0x35)
2014-02-06 13:38:33.024 INFO Sftp(1)[347] Command: SSH_FXP_OPEN (11, '/File_20140203_140404.txt', 1)
2014-02-06 13:38:33.055 INFO Sftp(1)[347] Response: SSH_FXP_HANDLE (11, 0x36)
2014-02-06 13:38:33.055 INFO Sftp(1)[347] Command: SSH_FXP_OPEN (12, '/File_20140204_140403.txt', 1)
2014-02-06 13:38:33.087 INFO Sftp(1)[347] Response: SSH_FXP_HANDLE (12, 0x37)
2014-02-06 13:38:33.087 INFO Sftp(1)[347] Command: SSH_FXP_OPEN (13, '/File_20140205_140405.txt', 1)
2014-02-06 13:38:33.118 INFO Sftp(1)[347] Response: SSH_FXP_HANDLE (13, 0x38)
2014-02-06 13:38:33.118 INFO Sftp(1)[347] Command: SSH_FXP_OPEN (14, '/OtherFile_20140128_004741.txt', 1)
2014-02-06 13:38:33.149 INFO Sftp(1)[347] Response: SSH_FXP_HANDLE (14, 0x39)
2014-02-06 13:38:33.149 INFO Sftp(1)[347] Command: SSH_FXP_OPEN (15, '/OtherFile_20140130_140415.txt', 1)
2014-02-06 13:38:33.165 INFO Sftp(1)[347] Response: SSH_FXP_HANDLE (15, 0x3130)
2014-02-06 13:38:33.180 INFO Sftp(1)[347] Command: SSH_FXP_OPEN (16, '/OtherFile_20140203_140408.txt', 1)
2014-02-06 13:38:33.196 INFO Sftp(1)[347] Response: SSH_FXP_HANDLE (16, 0x3131)
2014-02-06 13:38:33.211 INFO Sftp(1)[347] Command: SSH_FXP_OPEN (17, '/OtherFile_20140205_140409.txt', 1)
2014-02-06 13:38:33.274 INFO Sftp(1)[347] Response: SSH_FXP_STATUS (17, 2, 'File not found')
2014-02-06 13:38:33.289 ERROR Sftp(1)[347] Info: Rebex.Net.SftpException: No such file; File not found.
   at gbMKS.PEQpz.eCVvJZ(1dRwomZ , Type )
   at gbMKS.PEQpz.BGrFh(String , Qu2Ci , Boolean , ZD5WJ )
   at Rebex.Net.Sftp.sNLlLZ(String , Qu2Ci , ZD5WJ )
2014-02-06 13:38:33.336 INFO Sftp(1)[347] Info: Connecting to xxx.xxx.xxx.xxx:22 using Sftp 3.0.4700.0.
2014-02-06 13:38:33.383 DEBUG Sftp(1)[347] SSH: Server is 'SSH-2.0-1.36 sshlib: GlobalScape'.
2014-02-06 13:38:33.383 INFO Sftp(1)[347] SSH: Negotiation started.
2014-02-06 13:38:33.383 DEBUG Sftp(1)[347] SSH: Negotiating key.
2014-02-06 13:38:33.430 DEBUG Sftp(1)[347] SSH: Validating signature.
2014-02-06 13:38:33.445 INFO Sftp(1)[347] SSH: Negotiation finished.
2014-02-06 13:38:33.445 INFO Sftp(1)[347] Info: Server: SSH-2.0-1.36 sshlib: GlobalScape
2014-02-06 13:38:33.445 INFO Sftp(1)[347] Info: Fingerprint: xx:xx:xx:xx:xx:xx:xx:xx:xx:xx:xx:xx:xx:xx:xx:xx
2014-02-06 13:38:33.445 INFO Sftp(1)[347] Info: Cipher info: SSH 2.0, Diffie-Hellman-Group1-SHA1, DSS, aes256-cbc/aes256-cbc, hmac-sha1/hmac-sha1
2014-02-06 13:38:33.461 INFO Sftp(1)[347] SSH: Received banner:       
2014-02-06 13:38:33.492 DEBUG Sftp(1)[347] SSH: Allowed authentication methods: publickey, password.
2014-02-06 13:38:33.492 DEBUG Sftp(1)[347] SSH: Trying password authentication for 'xSomeUserx'.
2014-02-06 13:38:33.508 DEBUG Sftp(1)[347] SSH: Authentication successful.
2014-02-06 13:38:33.539 DEBUG Sftp(1)[347] SSH: Requesting subsystem 'sftp'.
2014-02-06 13:38:33.555 INFO Sftp(1)[347] Command: SSH_FXP_INIT (4)
2014-02-06 13:38:33.586 INFO Sftp(1)[347] Response: SSH_FXP_VERSION (3, 0 extensions)
2014-02-06 13:38:33.586 INFO Sftp(1)[347] Info: Using SFTP v3 on a Windows-like platform.
2014-02-06 13:38:33.586 INFO Sftp(1)[347] Command: SSH_FXP_REALPATH (1, '.')
2014-02-06 13:38:33.601 INFO Sftp(1)[347] Response: SSH_FXP_NAME (1, 1 item)
2014-02-06 13:38:33.601 INFO Sftp(1)[347] Info: Current directory is '/'.
2014-02-06 13:38:33.617 INFO Sftp(1)[347] Command: SSH_FXP_OPEN (2, '/OtherFile_20140205_140409.txt', 1)
2014-02-06 13:38:33.633 INFO Sftp(1)[347] Response: SSH_FXP_HANDLE (2, 0x31)
2014-02-06 13:38:34.116 ERROR Sftp(1)[328] SSH: Rebex.Net.SshException: The channel has been closed.
   at Rebex.Net.SshChannel.Send(Byte[] buffer, Int32 offset, Int32 count)
2014-02-06 13:38:34.179 ERROR Sftp(1)[328] SSH: Rebex.Net.SshException: The channel has been closed.
   at Rebex.Net.SshChannel.Send(Byte[] buffer, Int32 offset, Int32 count)
2014-02-06 13:38:34.210 ERROR Sftp(1)[328] SSH: Rebex.Net.SshException: The channel has been closed.
   at Rebex.Net.SshChannel.Send(Byte[] buffer, Int32 offset, Int32 count)
2014-02-06 13:38:34.225 ERROR Sftp(1)[328] SSH: Rebex.Net.SshException: The channel has been closed.
   at Rebex.Net.SshChannel.Send(Byte[] buffer, Int32 offset, Int32 count)
2014-02-06 13:38:34.241 ERROR Sftp(1)[328] SSH: Rebex.Net.SshException: The channel has been closed.
   at Rebex.Net.SshChannel.Send(Byte[] buffer, Int32 offset, Int32 count)
2014-02-06 13:38:34.241 ERROR Sftp(1)[328] SSH: Rebex.Net.SshException: Th
0 votes
by (58.9k points)
edited

Hi, we have looked into the log and we have found the cause of the issue you experienced:

in the log we can see that you are using multiple threads and a single instance of Rebex.Net.Sftp class. A thread connects and opens files on the SFTP server via one of our Stream based methods (GetStream, etc.) then we can see that these streams are passed to another thread which later consumes them.

However, opening the 12th file leads to an SftpException ("File not found."). A subsequent reconnect is OK, but with the reconnect the 11 streams which had been already opened become unusable. The second thread does not "know" about it and it tries to use the already opened download Streams. However, on trying to read from the Streams the component reports back the "Channel has been closed" SshException which is correct as the opened Streams can be only used as long as the session is active.

The SshExceptions ("Channel has been closed") are thrown in the other thread so that's why you might have missed it.

One thing to note. It is not always neccesary to reconnect after a SftpException occurs. If the SftpException.Status property is set to SftpExceptionStatus.ProtocolError, then a reconnect is not necessary.

If you experience an Exception after which you have to reconnect, then you would have to discard the opened streams as they will be no longer usable.

...