Ask a Question

Why does Sftp.GetFile work but Sftp.GetDownloadStream does not?

0 votes
by (120 points)

Here's the log file when using GetDownloadStream:

INFO FileLogWriter(2)[6] Info: Assembly: Rebex.Common 2017 R6.3 for .NET 2.0-3.5
INFO FileLogWriter(2)[6] Info: Platform: Windows 6.2.9200 32-bit; CLR: 2.0.50727.9035
INFO SftpKeepAlive(1)[6] Info: Connecting to oracle12c:22 using Sftp.
INFO SftpKeepAlive(1)[6] Info: Assembly: Rebex.Sftp 2017 R6.3 for .NET 2.0-3.5
INFO SftpKeepAlive(1)[6] Info: Platform: Windows 6.2.9200 32-bit; CLR: 2.0.50727.9035
INFO SftpKeepAlive(1)[6] SSH: Negotiation started.
INFO SftpKeepAlive(1)[6] SSH: Negotiation finished.
INFO SftpKeepAlive(1)[6] Info: Server: SSH-2.0-WeOnlyDo 2.4.3
INFO SftpKeepAlive(1)[6] Info: Fingerprint (MD5): 90:05:6e:67:ea:01:b4:e3:aa:89:83:ca:a9:dd:63:3c
INFO SftpKeepAlive(1)[6] Info: Fingerprint (SHA-256): x6kGY2PXDCvRhrOv30P/+1Ri6C4XDKu10YmcrmwESnA
INFO SftpKeepAlive(1)[6] Info: Cipher info: SSH 2.0, diffie-hellman-group14-sha1, ssh-dss, aes256-ctr/aes256-ctr, hmac-sha2-256/hmac-sha2-256
INFO SftpKeepAlive(1)[6] Command: SSH_FXP_INIT (4)
INFO SftpKeepAlive(1)[6] Response: SSH_FXP_VERSION (3, 0 extensions)
INFO SftpKeepAlive(1)[6] Info: Using SFTP v3 on a Windows-like platform.
INFO SftpKeepAlive(1)[6] Command: SSH_FXP_STAT (1, '/BigFile.txt')
INFO SftpKeepAlive(1)[6] Response: SSH_FXP_ATTRS (1)
INFO SftpKeepAlive(1)[6] Command: SSH_FXP_STAT (2, '/BigFile.txt')
INFO SftpKeepAlive(1)[6] Response: SSH_FXP_ATTRS (2)
INFO SftpKeepAlive(3)[6] Info: Connecting to oracle12c:22 using Sftp.
INFO SftpKeepAlive(3)[6] Info: Assembly: Rebex.Sftp 2017 R6.3 for .NET 2.0-3.5
INFO SftpKeepAlive(3)[6] Info: Platform: Windows 6.2.9200 32-bit; CLR: 2.0.50727.9035
INFO SftpKeepAlive(3)[6] SSH: Negotiation started.
INFO SftpKeepAlive(3)[6] SSH: Negotiation finished.
INFO SftpKeepAlive(3)[6] Info: Server: SSH-2.0-WeOnlyDo 2.4.3
INFO SftpKeepAlive(3)[6] Info: Fingerprint (MD5): 90:05:6e:67:ea:01:b4:e3:aa:89:83:ca:a9:dd:63:3c
INFO SftpKeepAlive(3)[6] Info: Fingerprint (SHA-256): x6kGY2PXDCvRhrOv30P/+1Ri6C4XDKu10YmcrmwESnA
INFO SftpKeepAlive(3)[6] Info: Cipher info: SSH 2.0, diffie-hellman-group14-sha1, ssh-dss, aes256-ctr/aes256-ctr, hmac-sha2-256/hmac-sha2-256
INFO SftpKeepAlive(3)[6] Command: SSH_FXP_INIT (4)
INFO SftpKeepAlive(3)[6] Response: SSH_FXP_VERSION (3, 0 extensions)
INFO SftpKeepAlive(3)[6] Info: Using SFTP v3 on a Windows-like platform.
INFO SftpKeepAlive(3)[6] Command: SSH_FXP_OPEN (1, '/BigFile.txt', 1)
INFO SftpKeepAlive(3)[6] Response: SSH_FXP_HANDLE (1, 0x776F645366747046696C6548616E646C6530)
ERROR SftpKeepAlive(3)[6] SSH: Rebex.Net.SshException: The SSH connection failed.
   at Rebex.Net.SshSession.PF(PE I, Boolean J)
   at Rebex.Net.SshChannel.DJ(PE I)
   at Rebex.Net.SshChannel.Send(Byte[] buffer, Int32 offset, Int32 count)
ERROR SftpKeepAlive(3)[6] SSH: Rebex.Net.SshException: The channel has been closed.
   at Rebex.Net.SshChannel.Send(Byte[] buffer, Int32 offset, Int32 count)
Applies to: Rebex SFTP

1 Answer

0 votes
by (148k points)

The log seems incomplete. The data/time info (which would be quite useful in this case) is missing. Then there are two separate SFTP sessions - the first one ends suddenly with no apparent reason after it (seemingly successfully) determined the attributes of the file. The other session (again seemingly successfully) opened the same file for reading, but no data has actually been read. And eventually, the connection appears to have been closed from the server-side, although it's impossible to tell how whether this happened imediatelly or later (due to the lack of date/time info).

Would it be possible to post an updated log - with date/time info and created at LogLevel.Debug instead of LogLevel.Info? That would hopefully shed some light onto this issue.

by (120 points)
Here is the updated log:

2019-03-22 08:53:35.308 Opening log file.
2019-03-22 08:53:35.311 INFO FileLogWriter(2)[6] Info: Assembly: Rebex.Common 2017 R6.3 for .NET 2.0-3.5
2019-03-22 08:53:35.312 INFO FileLogWriter(2)[6] Info: Platform: Windows 6.2.9200 32-bit; CLR: 2.0.50727.9035
2019-03-22 08:53:35.312 DEBUG FileLogWriter(2)[6] Info: Culture: en; Windows-1252
2019-03-22 08:53:35.326 INFO SftpKeepAlive(1)[6] Info: Connecting to oracle12c:22 using Sftp.
2019-03-22 08:53:35.328 INFO SftpKeepAlive(1)[6] Info: Assembly: Rebex.Sftp 2017 R6.3 for .NET 2.0-3.5
2019-03-22 08:53:35.329 INFO SftpKeepAlive(1)[6] Info: Platform: Windows 6.2.9200 32-bit; CLR: 2.0.50727.9035
2019-03-22 08:53:35.330 DEBUG SftpKeepAlive(1)[6] Info: Culture: en; Windows-1252
2019-03-22 08:53:35.360 DEBUG ProxySocket(1)[6] Proxy: Resolving 'oracle12c'.
2019-03-22 08:53:35.413 DEBUG ProxySocket(1)[6] Proxy: Connecting to none proxy at 10.10.10.60:22.
2019-03-22 08:53:35.434 DEBUG SftpKeepAlive(1)[6] SSH: Server is 'SSH-2.0-WeOnlyDo 2.4.3'.
2019-03-22 08:53:35.450 INFO SftpKeepAlive(1)[6] SSH: Negotiation started.
2019-03-22 08:53:35.543 DEBUG SftpKeepAlive(1)[6] SSH: Negotiating key.
2019-03-22 08:53:35.581 DEBUG SftpKeepAlive(1)[6] SSH: Using 2048-bit Diffie-Hellman prime (minimum allowed size is 1024 bits).
2019-03-22 08:53:35.814 DEBUG SftpKeepAlive(1)[6] SSH: Validating signature.
2019-03-22 08:53:35.879 INFO SftpKeepAlive(1)[6] SSH: Negotiation finished.
2019-03-22 08:53:35.880 INFO SftpKeepAlive(1)[6] Info: Server: SSH-2.0-WeOnlyDo 2.4.3
2019-03-22 08:53:35.882 INFO SftpKeepAlive(1)[6] Info: Fingerprint (MD5): 90:05:6e:67:ea:01:b4:e3:aa:89:83:ca:a9:dd:63:3c
2019-03-22 08:53:35.887 INFO SftpKeepAlive(1)[6] Info: Fingerprint (SHA-256): x6kGY2PXDCvRhrOv30P/+1Ri6C4XDKu10YmcrmwESnA
2019-03-22 08:53:35.889 INFO SftpKeepAlive(1)[6] Info: Cipher info: SSH 2.0, diffie-hellman-group14-sha1, ssh-dss, aes256-ctr/aes256-ctr, hmac-sha2-256/hmac-sha2-256
2019-03-22 08:53:35.907 DEBUG SftpKeepAlive(1)[6] SSH: Allowed authentication methods for 'user1': password, gssapi-with-mic, publickey.
2019-03-22 08:53:35.909 DEBUG SftpKeepAlive(1)[6] SSH: Trying password authentication for 'user1'.
2019-03-22 08:53:35.913 DEBUG SftpKeepAlive(1)[6] SSH: Authentication successful.
2019-03-22 08:53:35.923 DEBUG SftpKeepAlive(1)[6] SSH: Requesting subsystem 'sftp'.
2019-03-22 08:53:35.933 INFO SftpKeepAlive(1)[6] Command: SSH_FXP_INIT (4)
2019-03-22 08:53:35.975 INFO SftpKeepAlive(1)[6] Response: SSH_FXP_VERSION (3, 0 extensions)
2019-03-22 08:53:35.977 INFO SftpKeepAlive(1)[6] Info: Using SFTP v3 on a Windows-like platform.
2019-03-22 08:53:35.983 INFO SftpKeepAlive(1)[6] Command: SSH_FXP_STAT (1, '/BigFile.txt')
2019-03-22 08:53:35.987 INFO SftpKeepAlive(1)[6] Response: SSH_FXP_ATTRS (1)
2019-03-22 08:53:35.990 INFO SftpKeepAlive(1)[6] Command: SSH_FXP_STAT (2, '/BigFile.txt')
2019-03-22 08:53:35.991 INFO SftpKeepAlive(1)[6] Response: SSH_FXP_ATTRS (2)
2019-03-22 08:53:35.999 INFO SftpKeepAlive(3)[6] Info: Connecting to oracle12c:22 using Sftp.
2019-03-22 08:53:36.001 INFO SftpKeepAlive(3)[6] Info: Assembly: Rebex.Sftp 2017 R6.3 for .NET 2.0-3.5
2019-03-22 08:53:36.002 INFO SftpKeepAlive(3)[6] Info: Platform: Windows 6.2.9200 32-bit; CLR: 2.0.50727.9035
2019-03-22 08:53:36.003 DEBUG SftpKeepAlive(3)[6] Info: Culture: en; Windows-1252
2019-03-22 08:53:36.004 DEBUG ProxySocket(2)[6] Proxy: Resolving 'oracle12c'.
2019-03-22 08:53:36.007 DEBUG ProxySocket(2)[6] Proxy: Connecting to none proxy at 10.10.10.60:22.
2019-03-22 08:53:36.012 DEBUG SftpKeepAlive(3)[6] SSH: Server is 'SSH-2.0-WeOnlyDo 2.4.3'.
2019-03-22 08:53:36.014 INFO SftpKeepAlive(3)[6] SSH: Negotiation started.
2019-03-22 08:53:36.015 DEBUG SftpKeepAlive(3)[6] SSH: Negotiating key.
2019-03-22 08:53:36.047 DEBUG SftpKeepAlive(3)[6] SSH: Using 2048-bit Diffie-Hellman prime (minimum allowed size is 1024 bits).
2019-03-22 08:53:36.284 DEBUG SftpKeepAlive(3)[6] SSH: Validating signature.
2019-03-22 08:53:36.287 INFO SftpKeepAlive(3)[6] SSH: Negotiation finished.
2019-03-22 08:53:36.288 INFO SftpKeepAlive(3)[6] Info: Server: SSH-2.0-WeOnlyDo 2.4.3
2019-03-22 08:53:36.289 INFO SftpKeepAlive(3)[6] Info: Fingerprint (MD5): 90:05:6e:67:ea:01:b4:e3:aa:89:83:ca:a9:dd:63:3c
2019-03-22 08:53:36.290 INFO SftpKeepAlive(3)[6] Info: Fingerprint (SHA-256): x6kGY2PXDCvRhrOv30P/+1Ri6C4XDKu10YmcrmwESnA
2019-03-22 08:53:36.291 INFO SftpKeepAlive(3)[6] Info: Cipher info: SSH 2.0, diffie-hellman-group14-sha1, ssh-dss, aes256-ctr/aes256-ctr, hmac-sha2-256/hmac-sha2-256
2019-03-22 08:53:36.293 DEBUG SftpKeepAlive(3)[6] SSH: Allowed authentication methods for 'user1': password, gssapi-with-mic, publickey.
2019-03-22 08:53:36.294 DEBUG SftpKeepAlive(3)[6] SSH: Trying password authentication for 'user1'.
2019-03-22 08:53:36.297 DEBUG SftpKeepAlive(3)[6] SSH: Authentication successful.
2019-03-22 08:53:36.300 DEBUG SftpKeepAlive(3)[6] SSH: Requesting subsystem 'sftp'.
2019-03-22 08:53:36.304 INFO SftpKeepAlive(3)[6] Command: SSH_FXP_INIT (4)
2019-03-22 08:53:36.345 INFO SftpKeepAlive(3)[6] Response: SSH_FXP_VERSION (3, 0 extensions)
2019-03-22 08:53:36.348 INFO SftpKeepAlive(3)[6] Info: Using SFTP v3 on a Windows-like platform.
2019-03-22 08:53:36.355 INFO SftpKeepAlive(3)[6] Command: SSH_FXP_OPEN (1, '/BigFile.txt', 1)
2019-03-22 08:53:36.357 INFO SftpKeepAlive(3)[6] Response: SSH_FXP_HANDLE (1, 0x776F645366747046696C6548616E646C6530)
2019-03-22 08:53:36.370 ERROR SftpKeepAlive(3)[6] SSH: Rebex.Net.SshException: The SSH connection failed.
   at Rebex.Net.SshSession.PF(PE I, Boolean J)
   at Rebex.Net.SshChannel.DJ(PE I)
   at Rebex.Net.SshChannel.Send(Byte[] buffer, Int32 offset, Int32 count)
2019-03-22 08:53:36.373 ERROR SftpKeepAlive(3)[6] SSH: Rebex.Net.SshException: The channel has been closed.
   at Rebex.Net.SshChannel.Send(Byte[] buffer, Int32 offset, Int32 count)
by (148k points)
Thanks for the updated log! Unfortunately, the log still does not explain the reason for the failure - it almost looks like the underlying SSH session is getting disposed for some reason.

To determine what is going on, we'll have to prepare a build that logs additional information. In the meantime, please contact us at support@rebex.net and provide your order number and/or email address associated with your Rebex license.
...