Ask a Question

A public key corresponding to the supplied private key was not accepted by the server or the user name is incorrect.

0 votes
by (140 points)

Hi,

I am trying to use Rebex.SFTP to connect to an SFTP server using PrivateSSHKey.

        await _sftpClient.ConnectAsync("mysftpserver.com", 22);
        var privateKey = new SshPrivateKey(@"d:\ADF\privatekey.rsa");
        await _sftpClient.LoginAsync("myUserName", privateKey);

I am getting an Exception when the login is being processed:

Rebex.Net.SshException: A public key corresponding to the supplied private key was not accepted by the server or the user name is incorrect.

I have successfully connected to the SFTP server using FileZilla FTP Client, using the same RSA encrypted Private Key, and the same User login.

I have enabled debugging in the SFTP Client - here is the log:

2022-11-22 16:14:37.973 Opening log file.
2022-11-22 16:14:37.981 INFO FileLogWriter(1)[1] Info: Assembly: Rebex.Common R6.9 for .NET 6.0
2022-11-22 16:14:38.008 INFO FileLogWriter(1)[1] Info: Platform: Windows 10.0.19044 64-bit; CLR: .NET 6.0.11
2022-11-22 16:14:38.011 DEBUG FileLogWriter(1)[1] Info: Culture: da; windows-1252
2022-11-22 16:14:42.452 INFO Sftp(1)[3] Info: Connecting to andfrsftp.blob.core.windows.net:22 using Sftp.
2022-11-22 16:14:42.452 INFO Sftp(1)[3] Info: Assembly: Rebex.Sftp R6.9 for .NET 6.0 (Trial)
2022-11-22 16:14:42.453 INFO Sftp(1)[3] Info: Platform: Windows 10.0.19044 64-bit; CLR: .NET 6.0.11
2022-11-22 16:14:42.453 DEBUG Sftp(1)[3] Info: Culture: da; windows-1252
2022-11-22 16:14:42.476 DEBUG Sftp(1)[3] Proxy: Resolving 'andfrsftp.blob.core.windows.net'.
2022-11-22 16:14:42.508 DEBUG Sftp(1)[3] Proxy: Connecting to 20.150.42.228:22 (no proxy).
2022-11-22 16:14:42.547 DEBUG Sftp(1)[3] Proxy: Connection established.
2022-11-22 16:14:42.567 DEBUG Sftp(1)[3] SSH: Server is 'SSH-2.0-AzureSSH1.0.0'.
2022-11-22 16:14:42.579 INFO Sftp(1)[3] SSH: Negotiation started.
2022-11-22 16:14:42.699 DEBUG Sftp(1)[3] SSH: Negotiating key.
2022-11-22 16:14:42.735 DEBUG Sftp(1)[3] SSH: Validating 'rsa-sha2-256' signature.
2022-11-22 16:14:42.757 DEBUG Sftp(1)[3] SSH: Received 2048-bit RSA server key (minimum allowed size is 1023 bits).
2022-11-22 16:14:42.788 INFO Sftp(1)[3] SSH: Negotiation finished.
2022-11-22 16:14:42.788 INFO Sftp(1)[3] Info: Server: SSH-2.0-AzureSSH1.0.0
2022-11-22 16:14:42.789 INFO Sftp(1)[3] Info: Fingerprint (MD5): a1:4c:5f:13:43:79:8a:40:fb:cd:23:3c:99:69:95:43
2022-11-22 16:14:42.790 INFO Sftp(1)[3] Info: Fingerprint (SHA-256): IeHrQ+N6WAdLMKSMsJiML4XqMrkF1kyOiTeTjh1PFyc
2022-11-22 16:14:42.790 INFO Sftp(1)[3] Info: Cipher info: SSH 2.0, ecdh-sha2-nistp256, rsa-sha2-256, aes256-gcm@openssh.com/aes256-gcm@openssh.com
2022-11-22 16:14:42.840 DEBUG Sftp(1)[11] SSH: Server supports extension negotiation.
2022-11-22 16:14:42.936 DEBUG Sftp(1)[3] SSH: Allowed authentication methods for 'andfrsftp.ftproot.andfrkey': publickey, password.
2022-11-22 16:14:42.937 DEBUG Sftp(1)[3] SSH: Trying public key authentication for 'andfrsftp.ftproot.andfrkey' using 'rsa-sha2-256'.
2022-11-22 16:14:43.009 ERROR Sftp(1)[3] SSH: Rebex.Net.SshException: A public key corresponding to the supplied private key was not accepted by the server or the user name is incorrect.
at Rebex.Net.SshSession.oxdya(String p0, String p1, SshPrivateKey p2, SshGssApiCredentials p3, Boolean p4)

I hope you are able to help :)

Kind regards
Anders

Applies to: Rebex SFTP, Rebex Terminal Emulation
by (148k points)
Hi, would it be possible to try authenticating using OpenSSH (the version that comes with Windows 10 would be fine)? Unlike FileZilla, OpenSSH can produce a useful log at the SSH level, making it possible to determine any difference vs Rebex SFTP. For example, try connecting by running the following command (based in information from your Rebex log): sftp -vvv -i d:\ADF\privatekey.rsa andfrsftp.ftproot.andfrkey@andfrsftp.blob.core.windows.net
Then, please copy&paste the part of the log after the "Authentications that can continue: publickey,password entry and either post it here or mail it to support@rebex.net for analysis.
by (140 points)
Hi,

Ok tried the following command:
sftp -vvv -i d:\ADF\privatekey.rsa andfrsftp.ftproot.andfrkey@andfrsftp.blob.core.windows.net

Got this from the output:

debug1: Authentications that can continue: publickey,password
debug3: start over, passed a different list publickey,password
debug3: preferred publickey,keyboard-interactive,password
debug3: authmethod_lookup publickey
debug3: remaining preferred: keyboard-interactive,password
debug3: authmethod_is_enabled publickey
debug1: Next authentication method: publickey
debug1: Trying private key: d:\\ADF\\privatekey.rsa
debug3: Bad permissions. Try removing permissions for user: NT AUTHORITY\\Authenticated Users (S-1-5-11) on file d:/ADF/privatekey.rsa.
@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@
@         WARNING: UNPROTECTED PRIVATE KEY FILE!          @
@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@
Permissions for 'd:\\ADF\\privatekey.rsa' are too open.
It is required that your private key files are NOT accessible by others.
This private key will be ignored.
Load key "d:\\ADF\\privatekey.rsa": bad permissions
debug2: we did not send a packet, disable method
debug3: authmethod_lookup password
debug3: remaining preferred: ,password
debug3: authmethod_is_enabled password
debug1: Next authentication method: password
debug3: failed to open file:D:/dev/tty error:3
debug1: read_passphrase: can't open /dev/tty: No such file or directory
andfrsftp.ftproot.andfrkey@andfrsftp.blob.core.windows.net's password:
debug3: send packet: type 50
debug2: we sent a password packet, wait for reply
debug3: receive packet: type 51
debug1: Authentications that can continue: publickey,password
Permission denied, please try again.
debug3: failed to open file:D:/dev/tty error:3
debug1: read_passphrase: can't open /dev/tty: No such file or directory
andfrsftp.ftproot.andfrkey@andfrsftp.blob.core.windows.net's password:
by (140 points)
Hi,

I tried moving the privatekey.rsa file under my user account, and I am now able to connect.

D:\ADF>sftp -vvv -i C:\Users\ander\.ssh\privatekey.rsa andfrsftp.ftproot.andfrkey@andfrsftp.blob.core.windows.net
debug3: spawning "C:\\Windows\\System32\\OpenSSH\\ssh.exe" "-oForwardX11 no" "-oForwardAgent no" "-oPermitLocalCommand no" "-oClearAllForwardings yes" -v -v -v -i C:\\Users\\ander\\.ssh\\privatekey.rsa -l andfrsftp.ftproot.andfrkey "-oProtocol 2" -s -- andfrsftp.blob.core.windows.net sftp
OpenSSH_for_Windows_8.1p1, LibreSSL 3.0.2
debug3: Failed to open file:C:/Users/ander/.ssh/config error:2
debug3: Failed to open file:C:/ProgramData/ssh/ssh_config error:2
debug2: resolving "andfrsftp.blob.core.windows.net" port 22
debug2: ssh_connect_direct
debug1: Connecting to andfrsftp.blob.core.windows.net [20.150.42.228] port 22.
debug1: Connection established.
debug3: Failed to open file:C:/Users/ander/.ssh/privatekey.rsa.pub error:2
debug1: identity file C:\\Users\\ander\\.ssh\\privatekey.rsa type -1
debug3: Failed to open file:C:/Users/ander/.ssh/privatekey.rsa-cert error:2
debug3: Failed to open file:C:/Users/ander/.ssh/privatekey.rsa-cert.pub error:2
debug1: identity file C:\\Users\\ander\\.ssh\\privatekey.rsa-cert type -1
debug1: Local version string SSH-2.0-OpenSSH_for_Windows_8.1
debug1: Remote protocol version 2.0, remote software version AzureSSH_1.0.0
debug1: no match: AzureSSH_1.0.0
debug2: fd 3 setting O_NONBLOCK
debug1: Authenticating to andfrsftp.blob.core.windows.net:22 as 'andfrsftp.ftproot.andfrkey'
debug3: hostkeys_foreach: reading file "C:\\Users\\ander/.ssh/known_hosts"
debug3: record_hostkey: found key type ECDSA in file C:\\Users\\ander/.ssh/known_hosts:10
debug3: load_hostkeys: loaded 1 keys from andfrsftp.blob.core.windows.net
debug3: Failed to open file:C:/Users/ander/.ssh/known_hosts2 error:2
debug3: Failed to open file:C:/ProgramData/ssh/ssh_known_hosts error:2
debug3: Failed to open file:C:/ProgramData/ssh/ssh_known_hosts2 error:2
debug3: order_hostkeyalgs: prefer hostkeyalgs: ecdsa-sha2-nistp256-cert-v01@openssh.com,ecdsa-sha2-nistp384-cert-v01@openssh.com,ecdsa-sha2-nistp521-cert-v01@openssh.com,ecdsa-sha2-nistp256,ecdsa-sha2-nistp384,ecdsa-sha2-nistp521
debug3: send packet: type 20
debug1: SSH2_MSG_KEXINIT sent
debug3: receive packet: type 20
debug1: SSH2_MSG_KEXINIT received
debug2: local client KEXINIT proposal
debug2: KEX algorithms: curve25519-sha256,curve25519-sha256@libssh.org,ecdh-sha2-nistp256,ecdh-sha2-nistp384,ecdh-sha2-nistp521,diffie-hellman-group-exchange-sha256,diffie-hellman-group16-sha512,diffie-hellman-group18-sha512,diffie-hellman-group14-sha256,diffie-hellman-group14-sha1,ext-info-c
debug2: host key algorithms: ecdsa-sha2-nistp256-cert-v01@openssh.com,ecdsa-sha2-nistp384-cert-v01@openssh.com,ecdsa-sha2-nistp521-cert-v01@openssh.com,ecdsa-sha2-nistp256,ecdsa-sha2-nistp384,ecdsa-sha2-nistp521,ssh-ed25519-cert-v01@openssh.com,rsa-sha2-512-cert-v01@openssh.com,rsa-sha2-256-cert-v01@openssh.com,ssh-rsa-cert-v01@openssh.com,ssh-ed25519,rsa-sha2-512,rsa-sha2-256,ssh-rsa
debug2: ciphers ctos: chacha20-poly1305@openssh.com,aes128-ctr,aes192-ctr,aes256-ctr,aes128-gcm@openssh.com,aes256-gcm@openssh.com
debug2: ciphers stoc: chacha20-poly1305@openssh.com,aes128-ctr,aes192-ctr,aes256-ctr,aes128-gcm@openssh.com,aes256-gcm@openssh.com
debug2: MACs ctos: umac-64-etm@openssh.com,umac-128-etm@openssh.com,hmac-sha2-256-etm@openssh.com,hmac-sha2-512-etm@openssh.com,hmac-sha1-etm@openssh.com,umac-64@openssh.com,umac-128@openssh.com,hmac-sha2-256,hmac-sha2-512,hmac-sha1
debug2: MACs stoc: umac-64-etm@openssh.com,umac-128-etm@openssh.com,hmac-sha2-256-etm@openssh.com,hmac-sha2-512-etm@openssh.com,hmac-sha1-etm@openssh.com,umac-64@openssh.com,umac-128@openssh.com,hmac-sha2-256,hmac-sha2-512,hmac-sha1
debug2: compression ctos: none,zlib@openssh.com,zlib
debug2: compression stoc: none,zlib@openssh.com,zlib
debug2: languages ctos:
debug2: languages stoc:
debug2: first_kex_follows 0
debug2: reserved 0
debug2: peer server KEXINIT proposal
debug2: KEX algorithms: ecdh-sha2-nistp384,ecdh-sha2-nistp256,diffie-hellman-group14-sha256,diffie-hellman-group16-sha512,diffie-hellman-group-exchange-sha256,ext-info-s
debug2: host key algorithms: rsa-sha2-256,rsa-sha2-512,ecdsa-sha2-nistp256,ecdsa-sha2-nistp384
debug2: ciphers ctos: aes128-gcm@openssh.com,aes256-gcm@openssh.com,aes128-ctr,aes192-ctr,aes256-ctr
debug2: ciphers stoc: aes128-gcm@openssh.com,aes256-gcm@openssh.com,aes128-ctr,aes192-ctr,aes256-ctr
debug2: MACs ctos: hmac-sha2-256,hmac-sha2-512,hmac-sha2-256-etm@openssh.com,hmac-sha2-512-etm@openssh.com
debug2: MACs stoc: hmac-sha2-256,hmac-sha2-512,hmac-sha2-256-etm@openssh.com,hmac-sha2-512-etm@openssh.com
debug2: compression ctos: none
debug2: compression stoc: none
debug2: languages ctos:
debug2: languages stoc:
debug2: first_kex_follows 0
debug2: reserved 0
debug1: kex: algorithm: ecdh-sha2-nistp256
debug1: kex: host key algorithm: ecdsa-sha2-nistp256
debug1: kex: server->client cipher: aes128-ctr MAC: hmac-sha2-256-etm@openssh.com compression: none
debug1: kex: client->server cipher: aes128-ctr MAC: hmac-sha2-256-etm@openssh.com compression: none
debug3: send packet: type 30
debug1: expecting SSH2_MSG_KEX_ECDH_REPLY
debug3: receive packet: type 31
debug1: Server host key: ecdsa-sha2-nistp256 SHA256:0WNMHmCNJE1YFBpHNeADuT5h+PfJ/jJPtUDHCxCSrO0
debug3: hostkeys_foreach: reading file "C:\\Users\\ander/.ssh/known_hosts"
debug3: record_hostkey: found key type ECDSA in file C:\\Users\\ander/.ssh/known_hosts:10
debug3: load_hostkeys: loaded 1 keys from andfrsftp.blob.core.windows.net
debug3: Failed to open file:C:/Users/ander/.ssh/known_hosts2 error:2
debug3: Failed to open file:C:/ProgramData/ssh/ssh_known_hosts error:2
debug3: Failed to open file:C:/ProgramData/ssh/ssh_known_hosts2 error:2
debug3: hostkeys_foreach: reading file "C:\\Users\\ander/.ssh/known_hosts"
debug3: record_hostkey: found key type ECDSA in file C:\\Users\\ander/.ssh/known_hosts:10
debug3: load_hostkeys: loaded 1 keys from 20.150.42.228
debug3: Failed to open file:C:/Users/ander/.ssh/known_hosts2 error:2
debug3: Failed to open file:C:/ProgramData/ssh/ssh_known_hosts error:2
debug3: Failed to open file:C:/ProgramData/ssh/ssh_known_hosts2 error:2
debug1: Host 'andfrsftp.blob.core.windows.net' is known and matches the ECDSA host key.
debug1: Found key in C:\\Users\\ander/.ssh/known_hosts:10
debug3: send packet: type 21
debug2: set_newkeys: mode 1
debug1: rekey out after 4294967296 blocks
debug1: SSH2_MSG_NEWKEYS sent
debug1: expecting SSH2_MSG_NEWKEYS
debug3: receive packet: type 21
debug1: SSH2_MSG_NEWKEYS received
debug2: set_newkeys: mode 0
debug1: rekey in after 4294967296 blocks
debug3: unable to connect to pipe \\\\.\\pipe\\openssh-ssh-agent, error: 2
debug1: pubkey_prepare: ssh_get_authentication_socket: No such file or directory
debug1: Will attempt key: C:\\Users\\ander\\.ssh\\privatekey.rsa  explicit
debug2: pubkey_prepare: done
debug3: send packet: type 5
debug3: receive packet: type 7
debug1: SSH2_MSG_EXT_INFO received
debug3: receive packet: type 6
debug2: service_accept: ssh-userauth
debug1: SSH2_MSG_SERVICE_ACCEPT received
debug3: send packet: type 50
debug3: receive packet: type 51
debug1: Authentications that can continue: publickey,password
debug3: start over, passed a different list publickey,password
debug3: preferred publickey,keyboard-interactive,password
debug3: authmethod_lookup publickey
debug3: remaining preferred: keyboard-interactive,password
debug3: authmethod_is_enabled publickey
debug1: Next authentication method: publickey
debug1: Trying private key: C:\\Users\\ander\\.ssh\\privatekey.rsa
debug3: sign_and_send_pubkey: RSA SHA256:YD1wwatny+fCVA1lHW9Fwk/LqD1VHusNtPVLN1C5Hc0
debug3: sign_and_send_pubkey: signing using ssh-rsa
debug3: send packet: type 50
debug2: we sent a publickey packet, wait for reply
debug3: receive packet: type 52
debug1: Authentication succeeded (publickey).
Authenticated to andfrsftp.blob.core.windows.net ([20.150.42.228]:22).
debug2: fd 4 setting O_NONBLOCK
debug2: fd 5 setting O_NONBLOCK
debug1: channel 0: new [client-session]
debug3: ssh_session2_open: channel_new: 0
debug2: channel 0: send open
debug3: send packet: type 90
debug1: Entering interactive session.
debug1: pledge: network
debug3: receive packet: type 91
debug2: channel_input_open_confirmation: channel 0: callback start
debug2: fd 3 setting TCP_NODELAY
debug2: client_session2_setup: id 0
debug1: Sending subsystem: sftp
debug2: channel 0: request subsystem confirm 1
debug3: send packet: type 98
debug2: channel_input_open_confirmation: channel 0: callback done
debug2: channel 0: open confirm rwindow 4294967295 rmax 262143
debug3: receive packet: type 99
debug2: channel_input_status_confirm: type 99 id 0
debug2: subsystem request accepted on channel 0
debug2: Remote version: 3
Connected to andfrsftp.blob.core.windows.net.
debug3: Sent message fd 6 T:16 I:1
debug3: SSH_FXP_REALPATH . -> / size 0
sftp>
by (140 points)
So,

Why is it - when I try to load the exact same privatekey.rsa file using Rebex.Ftps client, it cannot authenticate using:

                await _sftpClient.ConnectAsync("andfrsftp.blob.core.windows.net", 22);
                var privateKey = new SshPrivateKey(@"d:\ADF\privatekey.rsa");
                await _sftpClient.LoginAsync("andfrsftp.ftproot.andfrkey", privateKey);

The privateKey object here, has a fingerprint, keyalgorithmid and keysize. I tried using the key from my account directory aswell "C:\Users\ander\.ssh\privatekey.rsa", but i get the same error from Rebex:

A public key corresponding to the supplied private key was not accepted by the server or the user name is incorrect.
by (148k points)
Thanks! There actually does seem to be a difference. Rebex log:

2022-11-22 16:14:42.937 DEBUG Sftp(1)[3] SSH: Trying public key authentication for 'andfrsftp.ftproot.andfrkey' using 'rsa-sha2-256'.

OpenSSH log:
debug3: sign_and_send_pubkey: signing using ssh-rsa

Apparently, OpenSSH is using the legacy "ssh-rsa" algorithm (RSA with SHA-1 hash), while Rebex SFTP attempts the new "rsa-sha2-256" algorithm (RSA with SHA-256 hash).

Unfortunately, it's not currently possible to force "ssh-rsa", so we will update Rebex SFTP and mail you a link to try later today.
by (148k points)
Please download this hotfix build and give it a try:
https://www.rebex.net/getfile/4a456cfc6e5a42f090d365d92149f96d/RebexFileTransferPack-R6.9-Hotfix1-Trial.zip

If it still doesn't work, please post the log.
by (140 points)
Hi

Thanks. Tried the hotfix you supplied, and it works! I can now connect to the SFTP server just fine.

When will this version be available from nuget.org? :)
by (148k points)
Thanks for testing!
This hotfix seems to be quite important - we will publish a new version to nuget.org in a week or so.
by (140 points)
Hi,

That sounds good.

Though i can connect to the SFTP server and list files. I can only download files using:

await client.GetFileAsync(ftpFilePath, stream);

If I try and download s file using:

client.GetDownloadStream(filePath);

I get an exception from Rebex.Sftp client:

Rebex.Net.SshException: SSH protocol violation by the remote side.


Here is the Rebex Log for the call:

2022-11-25 10:59:02.780 INFO Sftp(1)[8] Info: Connecting to andfrsftp.blob.core.windows.net:22 using Sftp.
2022-11-25 10:59:02.780 INFO Sftp(1)[8] Info: Assembly: Rebex.Sftp R6.9 for .NET 6.0 (Trial)
2022-11-25 10:59:02.780 INFO Sftp(1)[8] Info: Platform: Windows 10.0.19044 64-bit; CLR: .NET 6.0.11
2022-11-25 10:59:02.780 DEBUG Sftp(1)[8] Info: Culture: da; windows-1252
2022-11-25 10:59:02.807 DEBUG Sftp(1)[8] Proxy: Resolving 'andfrsftp.blob.core.windows.net'.
2022-11-25 10:59:02.906 DEBUG Sftp(1)[8] Proxy: Connecting to 20.150.42.228:22 (no proxy).
2022-11-25 10:59:02.937 DEBUG Sftp(1)[8] Proxy: Connection established.
2022-11-25 10:59:02.961 DEBUG Sftp(1)[8] SSH: Server is 'SSH-2.0-AzureSSH_1.0.0'.
2022-11-25 10:59:02.971 INFO Sftp(1)[8] SSH: Negotiation started.
2022-11-25 10:59:03.064 DEBUG Sftp(1)[8] SSH: Negotiating key.
2022-11-25 10:59:03.098 DEBUG Sftp(1)[8] SSH: Validating 'rsa-sha2-256' signature.
2022-11-25 10:59:03.115 DEBUG Sftp(1)[8] SSH: Received 2048-bit RSA server key (minimum allowed size is 1023 bits).
2022-11-25 10:59:03.144 INFO Sftp(1)[8] SSH: Negotiation finished.
2022-11-25 10:59:03.144 INFO Sftp(1)[8] Info: Server: SSH-2.0-AzureSSH_1.0.0
2022-11-25 10:59:03.145 INFO Sftp(1)[8] Info: Fingerprint (MD5): a1:4c:5f:13:43:79:8a:40:fb:cd:23:3c:99:69:95:43
2022-11-25 10:59:03.145 INFO Sftp(1)[8] Info: Fingerprint (SHA-256): IeHrQ+N6WAdLMKSMsJiML4XqMrkF1kyOiTeTjh1PFyc
2022-11-25 10:59:03.145 INFO Sftp(1)[8] Info: Cipher info: SSH 2.0, ecdh-sha2-nistp256, rsa-sha2-256, aes256-gcm@openssh.com/aes256-gcm@openssh.com
2022-11-25 10:59:03.196 DEBUG Sftp(1)[11] SSH: Server supports extension negotiation.
2022-11-25 10:59:03.294 DEBUG Sftp(1)[8] SSH: Allowed authentication methods for 'andfrsftp.ftproot.andfrkey': publickey, password.
2022-11-25 10:59:03.295 DEBUG Sftp(1)[8] SSH: Trying public key authentication for 'andfrsftp.ftproot.andfrkey' using 'ssh-rsa' (SHA256:YD1wwatny+fCVA1lHW9Fwk/LqD1VHusNtPVLN1C5Hc0)
2022-11-25 10:59:03.452 DEBUG Sftp(1)[8] SSH: Authentication successful.
2022-11-25 10:59:03.456 DEBUG Sftp(1)[8] SSH: Opening channel 'session' (initial window size: 131072, max packet size: 129024).
2022-11-25 10:59:03.485 DEBUG Sftp(1)[8] SSH: Requesting subsystem 'sftp'.
2022-11-25 10:59:03.519 INFO Sftp(1)[8] Command: SSH_FXP_INIT (4)
2022-11-25 10:59:03.545 INFO Sftp(1)[8] Response: SSH_FXP_VERSION (3, 0 extensions)
2022-11-25 10:59:03.545 INFO Sftp(1)[8] Info: Using SFTP v3.
2022-11-25 10:59:03.549 INFO Sftp(1)[8] Command: SSH_FXP_REALPATH (1, '.')
2022-11-25 10:59:03.576 INFO Sftp(1)[8] Response: SSH_FXP_NAME (1, '/')
2022-11-25 10:59:03.576 INFO Sftp(1)[8] Info: Home directory is '/'.
2022-11-25 10:59:03.583 INFO Sftp(1)[8] Command: SSH_FXP_REALPATH (2, '/')
2022-11-25 10:59:03.607 INFO Sftp(1)[8] Response: SSH_FXP_NAME (2, '/')
2022-11-25 10:59:03.609 INFO Sftp(1)[8] Command: SSH_FXP_STAT (3, '/')
2022-11-25 10:59:03.639 INFO Sftp(1)[8] Response: SSH_FXP_ATTRS (3)
2022-11-25 10:59:03.643 INFO Sftp(1)[8] Batch: Calling GetItems(string = '*', TraversalMode = 'Recursive').
2022-11-25 10:59:03.673 DEBUG Sftp(1)[5] Batch: Executing multi-file operation: Listing, source = '.', target = '', TransferMethod.Copy, MoveMode.All, LinkProcessingMode.FollowLinks, ActionOnExistingFiles.ThrowException.
2022-11-25 10:59:03.674 DEBUG Sftp(1)[5] Batch: Normalizing source path ('.').
2022-11-25 10:59:03.675 DEBUG Sftp(1)[5] Batch: Checking source path ('/').
2022-11-25 10:59:03.675 DEBUG Sftp(1)[5] Batch: Multi-file operation started.
2022-11-25 10:59:03.684 DEBUG Sftp(1)[5] Batch: Retrieving items of directory ('/').
2022-11-25 10:59:03.692 INFO Sftp(1)[5] Command: SSH_FXP_OPENDIR (4, '/')
2022-11-25 10:59:03.726 INFO Sftp(1)[5] Response: SSH_FXP_HANDLE (4, 0x34656333623433362D316432332D343730332D393866302D386637376138383635313631)
2022-11-25 10:59:03.727 INFO Sftp(1)[5] Command: SSH_FXP_READDIR (5, 0x34656333623433362D316432332D343730332D393866302D386637376138383635313631)
2022-11-25 10:59:03.773 INFO Sftp(1)[5] Response: SSH_FXP_NAME (5, 18 items)
2022-11-25 10:59:03.775 DEBUG Sftp(1)[5] Info: Item: -rw-r----- $superuser $superuser           217088 Mon, 21 Nov 2022 13:38:46 GMT TestResult15.xls
2022-11-25 10:59:03.776 DEBUG Sftp(1)[5] Info: Item: -rw-r----- $superuser $superuser           217088 Mon, 21 Nov 2022 13:38:46 GMT TestResult16.xls
2022-11-25 10:59:03.776 DEBUG Sftp(1)[5] Info: Item: -rw-r----- $superuser $superuser           217088 Mon, 21 Nov 2022 13:38:46 GMT TestResult17.xls
2022-11-25 10:59:03.776 DEBUG Sftp(1)[5] Info: Item: -rw-r----- $superuser $superuser           217088 Mon, 21 Nov 2022 13:38:46 GMT TestResult18.xls
2022-11-25 10:59:03.776 DEBUG Sftp(1)[5] Info: Item: -rw-r----- $superuser $superuser           217088 Mon, 21 Nov 2022 13:38:46 GMT TestResult19.xls
2022-11-25 10:59:03.776 DEBUG Sftp(1)[5] Info: Item: -rw-r----- $superuser $superuser           217088 Mon, 21 Nov 2022 13:38:46 GMT TestResult20.xls
2022-11-25 10:59:03.776 DEBUG Sftp(1)[5] Info: Item: -rw-r----- $superuser $superuser           217088 Mon, 21 Nov 2022 13:38:46 GMT TestResult21.xls
2022-11-25 10:59:03.776 DEBUG Sftp(1)[5] Info: Item: -rw-r----- $superuser $superuser           217088 Mon, 21 Nov 2022 13:38:46 GMT TestResult22.xls
2022-11-25 10:59:03.776 DEBUG Sftp(1)[5] Info: Item: -rw-r----- $superuser $superuser           217088 Mon, 21 Nov 2022 13:38:46 GMT TestResult23.xls
2022-11-25 10:59:03.776 DEBUG Sftp(1)[5] Info: Item: -rw-r----- $superuser $superuser           217088 Mon, 21 Nov 2022 13:38:46 GMT TestResult24.xls
2022-11-25 10:59:03.776 DEBUG Sftp(1)[5] Info: Item: -rw-r----- $superuser $superuser           217088 Mon, 21 Nov 2022 13:38:46 GMT TestResult25.xls
2022-11-25 10:59:03.776 DEBUG Sftp(1)[5] Info: Item: -rw-r----- $superuser $superuser           217088 Mon, 21 Nov 2022 13:38:46 GMT TestResult26.xls
2022-11-25 10:59:03.776 DEBUG Sftp(1)[5] Info: Item: -rw-r----- $superuser $superuser           217088 Mon, 21 Nov 2022 13:38:46 GMT TestResult27.xls
2022-11-25 10:59:03.776 DEBUG Sftp(1)[5] Info: Item: -rw-r----- $superuser $superuser           217088 Mon, 21 Nov 2022 13:38:46 GMT TestResult28.xls
2022-11-25 10:59:03.776 DEBUG Sftp(1)[5] Info: Item: -rw-r----- $superuser $superuser           217088 Mon, 21 Nov 2022 13:38:46 GMT TestResult29.xls
2022-11-25 10:59:03.776 DEBUG Sftp(1)[5] Info: Item: -rw-r----- $superuser $superuser           217088 Mon, 21 Nov 2022 13:38:46 GMT TestResult30.xls
2022-11-25 10:59:03.776 DEBUG Sftp(1)[5] Info: Item: -rw-r----- $superuser $superuser         49272610 Tue, 22 Nov 2022 07:41:39 GMT large.tdms
2022-11-25 10:59:03.776 DEBUG Sftp(1)[5] Info: Item: drwxr-x--- $superuser $superuser                0 Tue, 22 Nov 2022 07:42:18 GMT some new folder
2022-11-25 10:59:03.776 INFO Sftp(1)[5] Command: SSH_FXP_READDIR (6, 0x34656333623433362D316432332D343730332D393866302D386637376138383635313631)
2022-11-25 10:59:03.801 INFO Sftp(1)[5] Response: SSH_FXP_STATUS (6, 1, '')
2022-11-25 10:59:03.802 INFO Sftp(1)[5] Command: SSH_FXP_CLOSE (7, 0x34656333623433362D316432332D343730332D393866302D386637376138383635313631)
2022-11-25 10:59:03.831 INFO Sftp(1)[5] Response: SSH_FXP_STATUS (7, 0, '')
2022-11-25 10:59:03.840 DEBUG Sftp(1)[5] Batch: Retrieving items of directory ('/some new folder').
2022-11-25 10:59:03.840 INFO Sftp(1)[5] Command: SSH_FXP_OPENDIR (8, '/some new folder')
2022-11-25 10:59:03.873 INFO Sftp(1)[5] Response: SSH_FXP_HANDLE (8, 0x39626561376532312D316631662D343665352D613037342D646265383333346137343961)
2022-11-25 10:59:03.873 INFO Sftp(1)[5] Command: SSH_FXP_READDIR (9, 0x39626561376532312D316631662D343665352D613037342D646265383333346137343961)
2022-11-25 10:59:03.911 INFO Sftp(1)[5] Response: SSH_FXP_STATUS (9, 1, '')
2022-11-25 10:59:03.911 INFO Sftp(1)[5] Command: SSH_FXP_CLOSE (10, 0x39626561376532312D316631662D343665352D613037342D646265383333346137343961)
2022-11-25 10:59:03.935 INFO Sftp(1)[5] Response: SSH_FXP_STATUS (10, 0, '')
2022-11-25 10:59:03.937 DEBUG Sftp(1)[5] Batch: Multi-file operation done.
2022-11-25 10:59:10.124 INFO Sftp(1)[1] Command: SSH_FXP_OPEN (11, '/TestResult15.xls', 1)
2022-11-25 10:59:10.154 INFO Sftp(1)[1] Response: SSH_FXP_HANDLE (11, 0x31396465323337342D656233372D343162642D386434322D623230663132346562326366)
2022-11-25 10:59:16.264 INFO Sftp(1)[1] Command: SSH_FXP_FSTAT (12, 0x31396465323337342D656233372D343162642D386434322D623230663132346562326366)
2022-11-25 10:59:16.291 INFO Sftp(1)[1] Response: SSH_FXP_ATTRS (12)
2022-11-25 10:59:16.295 DEBUG Sftp(1)[1] Command: SSH_FXP_READ (13, 0x31396465323337342D656233372D343162642D386434322D623230663132346562326366, 0, 65536)
2022-11-25 10:59:16.402 DEBUG Sftp(1)[1] Response: SSH_FXP_DATA (13, 65536 bytes)
2022-11-25 10:59:16.403 DEBUG Sftp(1)[1] Command: SSH_FXP_READ (14, 0x31396465323337342D656233372D343162642D386434322D623230663132346562326366, 65536, 65536)
2022-11-25 10:59:16.428 ERROR Sftp(1)[11] SSH: SSH protocol violation by the remote side.
2022-11-25 10:59:16.467 ERROR Sftp(1)[11] SSH: Error occured while receiving SSH packet: Rebex.Net.SshException: SSH protocol violation by the remote side.
   at Rebex.Net.SshChannel.jymuz(Byte[] p0, Int32 p1, Int32 p2)
   at Rebex.Net.SshSession.wyjrn(Byte[] p0, Int32 p1, Int32 p2)
   at Rebex.Net.SshSession.xjjoo()
   at Rebex.Net.SshSession.ifbeg()
2022-11-25 10:59:16.473 ERROR Sftp(1)[1] SSH: Rebex.Net.SshException: SSH protocol violation by the remote side.
 ---> Rebex.Net.SshException: SSH protocol violation by the remote side.
   at Rebex.Net.SshChannel.jymuz(Byte[] p0, Int32 p1, Int32 p2)
   at Rebex.Net.SshSession.wyjrn(Byte[] p0, Int32 p1, Int32 p2)
   at Rebex.Net.SshSession.xjjoo()
   at Rebex.Net.SshSession.ifbeg()
   --- End of inner exception stack trace ---
   at Rebex.Net.SshSession.umxnl()
   at Rebex.Net.SshSession.wkprm[T,S](onjvl`2 p0, Int32 p1, yzjut p2, S p3, T p4, T p5)
   at Rebex.Net.SshSession.bbbes[T,S](onjvl`2 p0, S p1)
   at Rebex.Net.SshChannel.pvwgd[T,S](onjvl`2 p0, S p1)
   at Rebex.Net.SshChannel.uazfl(Byte[] p0, Int32 p1, Int32 p2)
   at Rebex.Net.SshChannel.Receive(Byte[] buffer, Int32 offset, Int32 count)

Can you help me with this?
by (148k points)
GetFile/GetFileAsync uses block size of 28672 bytes by default because some SSH servers reject packets longer than 32KB (the minimum value all SSH servers must support). However, it looks like you are reading in blocks of 65536 bytes from the Stream returned by GetDownloadStream. Does it work if you lower this to 28672?
by (140 points)
edited by
Hi,

Actually when i use the Method GetFileAsync, it fails after having transffered some parts of the file - around 450kb of a 209 mb file.

....
2022-11-25 13:37:05.676 DEBUG Sftp(1)[3] Batch: Multi-file operation done.
2022-11-25 13:37:07.785 INFO Sftp(1)[5] Command: SSH_FXP_OPEN (9, '/some new folder/Demo of scaling Azure Functions-20221116_150826-Meeting Recording.mp4', 1)
2022-11-25 13:37:07.819 INFO Sftp(1)[5] Response: SSH_FXP_HANDLE (9, 0x30346539353863322D326465392D343930352D383531312D356130336239613336343330)
2022-11-25 13:37:07.822 DEBUG Sftp(1)[5] Command: SSH_FXP_READ (10, 0x30346539353863322D326465392D343930352D383531312D356130336239613336343330, 0, 28672)
2022-11-25 13:37:07.822 DEBUG Sftp(1)[5] Command: SSH_FXP_READ (11, 0x30346539353863322D326465392D343930352D383531312D356130336239613336343330, 28672, 28672)
2022-11-25 13:37:07.822 DEBUG Sftp(1)[5] Command: SSH_FXP_READ (12, 0x30346539353863322D326465392D343930352D383531312D356130336239613336343330, 57344, 28672)
2022-11-25 13:37:07.823 DEBUG Sftp(1)[5] Command: SSH_FXP_READ (13, 0x30346539353863322D326465392D343930352D383531312D356130336239613336343330, 86016, 28672)
2022-11-25 13:37:07.823 DEBUG Sftp(1)[5] Command: SSH_FXP_READ (14, 0x30346539353863322D326465392D343930352D383531312D356130336239613336343330, 114688, 28672)
2022-11-25 13:37:07.823 DEBUG Sftp(1)[5] Command: SSH_FXP_READ (15, 0x30346539353863322D326465392D343930352D383531312D356130336239613336343330, 143360, 28672)
2022-11-25 13:37:07.823 DEBUG Sftp(1)[5] Command: SSH_FXP_READ (16, 0x30346539353863322D326465392D343930352D383531312D356130336239613336343330, 172032, 28672)
2022-11-25 13:37:07.823 DEBUG Sftp(1)[5] Command: SSH_FXP_READ (17, 0x30346539353863322D326465392D343930352D383531312D356130336239613336343330, 200704, 28672)
2022-11-25 13:37:07.823 DEBUG Sftp(1)[5] Command: SSH_FXP_READ (18, 0x30346539353863322D326465392D343930352D383531312D356130336239613336343330, 229376, 28672)
2022-11-25 13:37:07.823 DEBUG Sftp(1)[5] Command: SSH_FXP_READ (19, 0x30346539353863322D326465392D343930352D383531312D356130336239613336343330, 258048, 28672)
2022-11-25 13:37:07.823 DEBUG Sftp(1)[5] Command: SSH_FXP_READ (20, 0x30346539353863322D326465392D343930352D383531312D356130336239613336343330, 286720, 28672)
2022-11-25 13:37:07.823 DEBUG Sftp(1)[5] Command: SSH_FXP_READ (21, 0x30346539353863322D326465392D343930352D383531312D356130336239613336343330, 315392, 28672)
2022-11-25 13:37:07.823 DEBUG Sftp(1)[5] Command: SSH_FXP_READ (22, 0x30346539353863322D326465392D343930352D383531312D356130336239613336343330, 344064, 28672)
2022-11-25 13:37:07.823 DEBUG Sftp(1)[5] Command: SSH_FXP_READ (23, 0x30346539353863322D326465392D343930352D383531312D356130336239613336343330, 372736, 28672)
2022-11-25 13:37:07.823 DEBUG Sftp(1)[5] Command: SSH_FXP_READ (24, 0x30346539353863322D326465392D343930352D383531312D356130336239613336343330, 401408, 28672)
2022-11-25 13:37:07.823 DEBUG Sftp(1)[5] Command: SSH_FXP_READ (25, 0x30346539353863322D326465392D343930352D383531312D356130336239613336343330, 430080, 28672)
2022-11-25 13:37:07.933 DEBUG Sftp(1)[5] Response: SSH_FXP_DATA (10, 28672 bytes)
2022-11-25 13:37:07.933 DEBUG Sftp(1)[5] Command: SSH_FXP_READ (26, 0x30346539353863322D326465392D343930352D383531312D356130336239613336343330, 458752, 28672)
2022-11-25 13:37:07.956 DEBUG Sftp(1)[5] Response: SSH_FXP_DATA (11, 28672 bytes)
2022-11-25 13:37:07.956 DEBUG Sftp(1)[5] Command: SSH_FXP_READ (27, 0x30346539353863322D326465392D343930352D383531312D356130336239613336343330, 487424, 28672)
2022-11-25 13:37:07.956 DEBUG Sftp(1)[5] Response: SSH_FXP_DATA (12, 28672 bytes)
2022-11-25 13:37:07.956 DEBUG Sftp(1)[5] Command: SSH_FXP_READ (28, 0x30346539353863322D326465392D343930352D383531312D356130336239613336343330, 516096, 28672)
2022-11-25 13:37:07.981 DEBUG Sftp(1)[5] SSH: Adjusted local receive window size: 15746 -> 131072.
2022-11-25 13:37:07.981 DEBUG Sftp(1)[5] Response: SSH_FXP_DATA (13, 28672 bytes)
2022-11-25 13:37:07.981 DEBUG Sftp(1)[5] Command: SSH_FXP_READ (29, 0x30346539353863322D326465392D343930352D383531312D356130336239613336343330, 544768, 28672)
2022-11-25 13:37:07.981 DEBUG Sftp(1)[5] Response: SSH_FXP_DATA (14, 28672 bytes)
2022-11-25 13:37:07.981 DEBUG Sftp(1)[5] Command: SSH_FXP_READ (30, 0x30346539353863322D326465392D343930352D383531312D356130336239613336343330, 573440, 28672)
2022-11-25 13:37:07.981 DEBUG Sftp(1)[5] Response: SSH_FXP_DATA (15, 28672 bytes)
2022-11-25 13:37:07.981 DEBUG Sftp(1)[5] Command: SSH_FXP_READ (31, 0x30346539353863322D326465392D343930352D383531312D356130336239613336343330, 602112, 28672)
2022-11-25 13:37:07.984 DEBUG Sftp(1)[5] Response: SSH_FXP_DATA (16, 28672 bytes)
2022-11-25 13:37:07.984 DEBUG Sftp(1)[5] Command: SSH_FXP_READ (32, 0x30346539353863322D326465392D343930352D383531312D356130336239613336343330, 630784, 28672)
2022-11-25 13:37:08.010 DEBUG Sftp(1)[5] SSH: Adjusted local receive window size: 16332 -> 131072.
2022-11-25 13:37:08.010 DEBUG Sftp(1)[5] Response: SSH_FXP_DATA (17, 28672 bytes)
2022-11-25 13:37:08.010 DEBUG Sftp(1)[5] Command: SSH_FXP_READ (33, 0x30346539353863322D326465392D343930352D383531312D356130336239613336343330, 659456, 28672)
2022-11-25 13:37:08.010 DEBUG Sftp(1)[5] Response: SSH_FXP_DATA (18, 28672 bytes)
2022-11-25 13:37:08.010 DEBUG Sftp(1)[5] Command: SSH_FXP_READ (34, 0x30346539353863322D326465392D343930352D383531312D356130336239613336343330, 688128, 28672)
2022-11-25 13:37:08.010 DEBUG Sftp(1)[5] Response: SSH_FXP_DATA (19, 28672 bytes)
2022-11-25 13:37:08.010 DEBUG Sftp(1)[5] Command: SSH_FXP_READ (35, 0x30346539353863322D326465392D343930352D383531312D356130336239613336343330, 716800, 28672)
2022-11-25 13:37:08.010 DEBUG Sftp(1)[5] SSH: Adjusted local receive window size: 16332 -> 106457.
2022-11-25 13:37:08.010 DEBUG Sftp(1)[5] Response: SSH_FXP_DATA (20, 28672 bytes)
2022-11-25 13:37:08.010 DEBUG Sftp(1)[5] Command: SSH_FXP_READ (36, 0x30346539353863322D326465392D343930352D383531312D356130336239613336343330, 745472, 28672)
2022-11-25 13:37:08.010 DEBUG Sftp(1)[5] Response: SSH_FXP_DATA (21, 28672 bytes)
2022-11-25 13:37:08.010 DEBUG Sftp(1)[5] Command: SSH_FXP_READ (37, 0x30346539353863322D326465392D343930352D383531312D356130336239613336343330, 774144, 28672)
2022-11-25 13:37:08.059 DEBUG Sftp(1)[5] Response: SSH_FXP_DATA (22, 28672 bytes)
2022-11-25 13:37:08.059 DEBUG Sftp(1)[5] Command: SSH_FXP_READ (38, 0x30346539353863322D326465392D343930352D383531312D356130336239613336343330, 802816, 28672)
2022-11-25 13:37:08.060 DEBUG Sftp(1)[5] Response: SSH_FXP_DATA (23, 28672 bytes)
2022-11-25 13:37:08.060 DEBUG Sftp(1)[5] Command: SSH_FXP_READ (39, 0x30346539353863322D326465392D343930352D383531312D356130336239613336343330, 831488, 28672)
2022-11-25 13:37:08.061 ERROR Sftp(1)[11] SSH: SSH protocol violation by the remote side.
2022-11-25 13:37:08.063 DEBUG Sftp(1)[5] SSH: Adjusted local receive window size: 20402 -> 131072.
2022-11-25 13:37:08.063 DEBUG Sftp(1)[5] Response: SSH_FXP_DATA (24, 28672 bytes)
2022-11-25 13:37:08.063 DEBUG Sftp(1)[5] Command: SSH_FXP_READ (40, 0x30346539353863322D326465392D343930352D383531312D356130336239613336343330, 860160, 28672)
2022-11-25 13:37:08.098 ERROR Sftp(1)[11] SSH: Error occured while receiving SSH packet: Rebex.Net.SshException: SSH protocol violation by the remote side.
   at Rebex.Net.SshChannel.jymuz(Byte[] p0, Int32 p1, Int32 p2)
   at Rebex.Net.SshSession.wyjrn(Byte[] p0, Int32 p1, Int32 p2)
   at Rebex.Net.SshSession.xjjoo()
   at Rebex.Net.SshSession.ifbeg()
2022-11-25 13:37:08.103 ERROR Sftp(1)[5] SSH: Rebex.Net.SshException: SSH protocol violation by the remote side.
 ---> Rebex.Net.SshException: SSH protocol violation by the remote side.
   at Rebex.Net.SshChannel.jymuz(Byte[] p0, Int32 p1, Int32 p2)
   at Rebex.Net.SshSession.wyjrn(Byte[] p0, Int32 p1, Int32 p2)
   at Rebex.Net.SshSession.xjjoo()
   at Rebex.Net.SshSession.ifbeg()
   --- End of inner exception stack trace ---
   at Rebex.Net.SshSession.umxnl()
   at Rebex.Net.SshSession.wkprm[T,S](onjvl`2 p0, Int32 p1, yzjut p2, S p3, T p4, T p5)
   at Rebex.Net.SshSession.bbbes[T,S](onjvl`2 p0, S p1)
   at Rebex.Net.SshChannel.pvwgd[T,S](onjvl`2 p0, S p1)
   at Rebex.Net.SshChannel.uazfl(Byte[] p0, Int32 p1, Int32 p2)
   at Rebex.Net.SshChannel.Receive(Byte[] buffer, Int32 offset, Int32 count)
2022-11-25 13:37:08.103 DEBUG Sftp(1)[5] Info: Waiting for 15 outstanding read requests to arrive.
2022-11-25 13:37:08.105 ERROR Sftp(1)[5] Info: Rebex.Net.SftpException: The server has closed the connection.
   at xuxsl.psvpz.evdio(Int32 p0)
   at xuxsl.psvpz.jxdek(aaskk& p0)
   at xuxsl.psvpz.ytmxj(UInt32 p0, Boolean p1)
   at xuxsl.psvpz.oluec(UInt32 p0, tyohx p1)
   at Rebex.Net.Sftp.xptro(tyohx p0, String p1, vcaer p2, Int64 p3, Int64 p4, usvmw p5)
by (140 points)
I implemented a method to read the 209 mb file, from the sftp server, by using GetDownloadStream

And only reading chunks of size 28672 bytes.

This works, and gets the job done - however extremely slowly. It took 5 minutes and 25 seconds to download 209 Mb. So an average speed of 0.5 Mb/s

FileZilla does this in about 30 seconds at 8Mb/s

I guess FileZilla must be downloading in multiple threads or something like that.

Are Rebex.SFTP downloading in multiple threads when using the GetFileAsync?
by (148k points)
Sftp.GetFile method would be faster - like FileZilla, it sends multiple SFTP read requests in advance, so when the SFTP server is done processing one request, it can immediately start processing the next. This eliminates the latency (which is the reason for slowness in GetDownloadStram).

On the other hand, the methods in the Stream from Sftp.GetDownloadStream method directly correspond to SFTP protocol commands - a Write call results in SSH_FXP_WRITE request, and there is no way to issue multiple requests in advance using this API. (The benefit of this approach is that you get fine-grained control with GetDownloadStream, and that seeking is supported as well, although this is not actually supported by Azure SFTP unless I'm mistaken).

We have been considering adding a "read-in-advance" mode to GetDownloadStream/GetUploadStream, but we have been busy with other features and this keeps getting postponed. However, it is possible to achieve this with a bit of custom code using GetFile with a custom pass-through (pipe-like) Stream - my answer at https://forum.rebex.net/2892/performance-issue-with-direct-stream-access-getuploadstream?show=2893#a2893 shows how to achieve a faster equivalent of GetUploadStream. The same approach could be used for a faster GetDownloadStream equivalent as well.
by (140 points)
Hi,

Thanks for your reply. Instead of using GetDownloadStream, im trying to get performance by using GetFileAsync. However, when I use the Method GetFileAsync, it fails after having transffered some parts of the file - around 450kb - 4Mb (Random) of a 209 mb file.

....
2022-11-25 13:37:05.676 DEBUG Sftp(1)[3] Batch: Multi-file operation done.
2022-11-25 13:37:07.785 INFO Sftp(1)[5] Command: SSH_FXP_OPEN (9, '/some new folder/Demo of scaling Azure Functions-20221116_150826-Meeting Recording.mp4', 1)
2022-11-25 13:37:07.819 INFO Sftp(1)[5] Response: SSH_FXP_HANDLE (9, 0x30346539353863322D326465392D343930352D383531312D356130336239613336343330)
2022-11-25 13:37:07.822 DEBUG Sftp(1)[5] Command: SSH_FXP_READ (10, 0x30346539353863322D326465392D343930352D383531312D356130336239613336343330, 0, 28672)
2022-11-25 13:37:07.822 DEBUG Sftp(1)[5] Command: SSH_FXP_READ (11, 0x30346539353863322D326465392D343930352D383531312D356130336239613336343330, 28672, 28672)
2022-11-25 13:37:07.822 DEBUG Sftp(1)[5] Command: SSH_FXP_READ (12, 0x30346539353863322D326465392D343930352D383531312D356130336239613336343330, 57344, 28672)
2022-11-25 13:37:07.823 DEBUG Sftp(1)[5] Command: SSH_FXP_READ (13, 0x30346539353863322D326465392D343930352D383531312D356130336239613336343330, 86016, 28672)
2022-11-25 13:37:07.823 DEBUG Sftp(1)[5] Command: SSH_FXP_READ (14, 0x30346539353863322D326465392D343930352D383531312D356130336239613336343330, 114688, 28672)
2022-11-25 13:37:07.823 DEBUG Sftp(1)[5] Command: SSH_FXP_READ (15, 0x30346539353863322D326465392D343930352D383531312D356130336239613336343330, 143360, 28672)
2022-11-25 13:37:07.823 DEBUG Sftp(1)[5] Command: SSH_FXP_READ (16, 0x30346539353863322D326465392D343930352D383531312D356130336239613336343330, 172032, 28672)
2022-11-25 13:37:07.823 DEBUG Sftp(1)[5] Command: SSH_FXP_READ (17, 0x30346539353863322D326465392D343930352D383531312D356130336239613336343330, 200704, 28672)
2022-11-25 13:37:07.823 DEBUG Sftp(1)[5] Command: SSH_FXP_READ (18, 0x30346539353863322D326465392D343930352D383531312D356130336239613336343330, 229376, 28672)
2022-11-25 13:37:07.823 DEBUG Sftp(1)[5] Command: SSH_FXP_READ (19, 0x30346539353863322D326465392D343930352D383531312D356130336239613336343330, 258048, 28672)
2022-11-25 13:37:07.823 DEBUG Sftp(1)[5] Command: SSH_FXP_READ (20, 0x30346539353863322D326465392D343930352D383531312D356130336239613336343330, 286720, 28672)
2022-11-25 13:37:07.823 DEBUG Sftp(1)[5] Command: SSH_FXP_READ (21, 0x30346539353863322D326465392D343930352D383531312D356130336239613336343330, 315392, 28672)
2022-11-25 13:37:07.823 DEBUG Sftp(1)[5] Command: SSH_FXP_READ (22, 0x30346539353863322D326465392D343930352D383531312D356130336239613336343330, 344064, 28672)
2022-11-25 13:37:07.823 DEBUG Sftp(1)[5] Command: SSH_FXP_READ (23, 0x30346539353863322D326465392D343930352D383531312D356130336239613336343330, 372736, 28672)
2022-11-25 13:37:07.823 DEBUG Sftp(1)[5] Command: SSH_FXP_READ (24, 0x30346539353863322D326465392D343930352D383531312D356130336239613336343330, 401408, 28672)
2022-11-25 13:37:07.823 DEBUG Sftp(1)[5] Command: SSH_FXP_READ (25, 0x30346539353863322D326465392D343930352D383531312D356130336239613336343330, 430080, 28672)
2022-11-25 13:37:07.933 DEBUG Sftp(1)[5] Response: SSH_FXP_DATA (10, 28672 bytes)
2022-11-25 13:37:07.933 DEBUG Sftp(1)[5] Command: SSH_FXP_READ (26, 0x30346539353863322D326465392D343930352D383531312D356130336239613336343330, 458752, 28672)
2022-11-25 13:37:07.956 DEBUG Sftp(1)[5] Response: SSH_FXP_DATA (11, 28672 bytes)
2022-11-25 13:37:07.956 DEBUG Sftp(1)[5] Command: SSH_FXP_READ (27, 0x30346539353863322D326465392D343930352D383531312D356130336239613336343330, 487424, 28672)
2022-11-25 13:37:07.956 DEBUG Sftp(1)[5] Response: SSH_FXP_DATA (12, 28672 bytes)
2022-11-25 13:37:07.956 DEBUG Sftp(1)[5] Command: SSH_FXP_READ (28, 0x30346539353863322D326465392D343930352D383531312D356130336239613336343330, 516096, 28672)
2022-11-25 13:37:07.981 DEBUG Sftp(1)[5] SSH: Adjusted local receive window size: 15746 -> 131072.
2022-11-25 13:37:07.981 DEBUG Sftp(1)[5] Response: SSH_FXP_DATA (13, 28672 bytes)
2022-11-25 13:37:07.981 DEBUG Sftp(1)[5] Command: SSH_FXP_READ (29, 0x30346539353863322D326465392D343930352D383531312D356130336239613336343330, 544768, 28672)
2022-11-25 13:37:07.981 DEBUG Sftp(1)[5] Response: SSH_FXP_DATA (14, 28672 bytes)
2022-11-25 13:37:07.981 DEBUG Sftp(1)[5] Command: SSH_FXP_READ (30, 0x30346539353863322D326465392D343930352D383531312D356130336239613336343330, 573440, 28672)
2022-11-25 13:37:07.981 DEBUG Sftp(1)[5] Response: SSH_FXP_DATA (15, 28672 bytes)
2022-11-25 13:37:07.981 DEBUG Sftp(1)[5] Command: SSH_FXP_READ (31, 0x30346539353863322D326465392D343930352D383531312D356130336239613336343330, 602112, 28672)
2022-11-25 13:37:07.984 DEBUG Sftp(1)[5] Response: SSH_FXP_DATA (16, 28672 bytes)
2022-11-25 13:37:07.984 DEBUG Sftp(1)[5] Command: SSH_FXP_READ (32, 0x30346539353863322D326465392D343930352D383531312D356130336239613336343330, 630784, 28672)
2022-11-25 13:37:08.010 DEBUG Sftp(1)[5] SSH: Adjusted local receive window size: 16332 -> 131072.
2022-11-25 13:37:08.010 DEBUG Sftp(1)[5] Response: SSH_FXP_DATA (17, 28672 bytes)
2022-11-25 13:37:08.010 DEBUG Sftp(1)[5] Command: SSH_FXP_READ (33, 0x30346539353863322D326465392D343930352D383531312D356130336239613336343330, 659456, 28672)
2022-11-25 13:37:08.010 DEBUG Sftp(1)[5] Response: SSH_FXP_DATA (18, 28672 bytes)
2022-11-25 13:37:08.010 DEBUG Sftp(1)[5] Command: SSH_FXP_READ (34, 0x30346539353863322D326465392D343930352D383531312D356130336239613336343330, 688128, 28672)
2022-11-25 13:37:08.010 DEBUG Sftp(1)[5] Response: SSH_FXP_DATA (19, 28672 bytes)
2022-11-25 13:37:08.010 DEBUG Sftp(1)[5] Command: SSH_FXP_READ (35, 0x30346539353863322D326465392D343930352D383531312D356130336239613336343330, 716800, 28672)
2022-11-25 13:37:08.010 DEBUG Sftp(1)[5] SSH: Adjusted local receive window size: 16332 -> 106457.
2022-11-25 13:37:08.010 DEBUG Sftp(1)[5] Response: SSH_FXP_DATA (20, 28672 bytes)
2022-11-25 13:37:08.010 DEBUG Sftp(1)[5] Command: SSH_FXP_READ (36, 0x30346539353863322D326465392D343930352D383531312D356130336239613336343330, 745472, 28672)
2022-11-25 13:37:08.010 DEBUG Sftp(1)[5] Response: SSH_FXP_DATA (21, 28672 bytes)
2022-11-25 13:37:08.010 DEBUG Sftp(1)[5] Command: SSH_FXP_READ (37, 0x30346539353863322D326465392D343930352D383531312D356130336239613336343330, 774144, 28672)
2022-11-25 13:37:08.059 DEBUG Sftp(1)[5] Response: SSH_FXP_DATA (22, 28672 bytes)
2022-11-25 13:37:08.059 DEBUG Sftp(1)[5] Command: SSH_FXP_READ (38, 0x30346539353863322D326465392D343930352D383531312D356130336239613336343330, 802816, 28672)
2022-11-25 13:37:08.060 DEBUG Sftp(1)[5] Response: SSH_FXP_DATA (23, 28672 bytes)
2022-11-25 13:37:08.060 DEBUG Sftp(1)[5] Command: SSH_FXP_READ (39, 0x30346539353863322D326465392D343930352D383531312D356130336239613336343330, 831488, 28672)
2022-11-25 13:37:08.061 ERROR Sftp(1)[11] SSH: SSH protocol violation by the remote side.
2022-11-25 13:37:08.063 DEBUG Sftp(1)[5] SSH: Adjusted local receive window size: 20402 -> 131072.
2022-11-25 13:37:08.063 DEBUG Sftp(1)[5] Response: SSH_FXP_DATA (24, 28672 bytes)
2022-11-25 13:37:08.063 DEBUG Sftp(1)[5] Command: SSH_FXP_READ (40, 0x30346539353863322D326465392D343930352D383531312D356130336239613336343330, 860160, 28672)
2022-11-25 13:37:08.098 ERROR Sftp(1)[11] SSH: Error occured while receiving SSH packet: Rebex.Net.SshException: SSH protocol violation by the remote side.
   at Rebex.Net.SshChannel.jymuz(Byte[] p0, Int32 p1, Int32 p2)
   at Rebex.Net.SshSession.wyjrn(Byte[] p0, Int32 p1, Int32 p2)
   at Rebex.Net.SshSession.xjjoo()
   at Rebex.Net.SshSession.ifbeg()
2022-11-25 13:37:08.103 ERROR Sftp(1)[5] SSH: Rebex.Net.SshException: SSH protocol violation by the remote side.
 ---> Rebex.Net.SshException: SSH protocol violation by the remote side.
   at Rebex.Net.SshChannel.jymuz(Byte[] p0, Int32 p1, Int32 p2)
   at Rebex.Net.SshSession.wyjrn(Byte[] p0, Int32 p1, Int32 p2)
   at Rebex.Net.SshSession.xjjoo()
   at Rebex.Net.SshSession.ifbeg()
   --- End of inner exception stack trace ---
   at Rebex.Net.SshSession.umxnl()
   at Rebex.Net.SshSession.wkprm[T,S](onjvl`2 p0, Int32 p1, yzjut p2, S p3, T p4, T p5)
   at Rebex.Net.SshSession.bbbes[T,S](onjvl`2 p0, S p1)
   at Rebex.Net.SshChannel.pvwgd[T,S](onjvl`2 p0, S p1)
   at Rebex.Net.SshChannel.uazfl(Byte[] p0, Int32 p1, Int32 p2)
   at Rebex.Net.SshChannel.Receive(Byte[] buffer, Int32 offset, Int32 count)
2022-11-25 13:37:08.103 DEBUG Sftp(1)[5] Info: Waiting for 15 outstanding read requests to arrive.
2022-11-25 13:37:08.105 ERROR Sftp(1)[5] Info: Rebex.Net.SftpException: The server has closed the connection.
   at xuxsl.psvpz.evdio(Int32 p0)
   at xuxsl.psvpz.jxdek(aaskk& p0)
   at xuxsl.psvpz.ytmxj(UInt32 p0, Boolean p1)
   at xuxsl.psvpz.oluec(UInt32 p0, tyohx p1)
   at Rebex.Net.Sftp.xptro(tyohx p0, String p1, vcaer p2, Int64 p3, Int64 p4, usvmw p5)
by (148k points)
Thanks for reporting this - it actually sheds more light onto the previous "SSH protocol violation by the remote side" occurrence. Apparently, the authors of Azure SSH invented additional requirements of their own along the lines of "SFTP client must ensure that its receive window size is large enough for receiving the server response at the time of sending the request". We will add a workaround for this to the next release. In the meantime, setting "_sftpClient.Settings.UseLargeBuffers = true" should resolve the issue (again, this will make Rebex SFTP behave a bit more like FileZilla).
by (140 points)
Hi

Thanks. Using the "_sftpClient.Settings.UseLargeBuffers = true" did the trick. I can now download at full speed.
by (140 points)
Which version will the hotfix be released in?
by (148k points)
It will be released in version R6.10.

1 Answer

0 votes
by (140 points)
edited by

Apologies to continue on this thread but I have an issue that seems very closely related here.

It was reported above that this would be resolved in 6.10. We are currently using 6.9 (6.0.8348.0) so I was testing using the Trial Rebex SFTP R6.10 for .NET 4.6-4.8 6.0.8372.0(I am not a developer)and am still having the same issue.

The Debug results in the following IPADDRESS and USERNAME replaced.

Welcome to Rebex SFTP!
14:45:37.172 Info Info: Connecting to IPADDRESS:22 using Sftp.
14:45:37.175 Info Info: Assembly: Rebex.Sftp R6.10 for .NET 4.6-4.8 (Trial)
14:45:37.175 Info Info: Platform: Windows 6.2.9200 32-bit; CLR: 4.0.30319.42000
14:45:37.176 Debug Info: Culture: en; Windows-1252
14:45:37.188 Debug Proxy: Connecting to IPADDRESS:22 (no proxy).
14:45:37.207 Debug Proxy: Connection established.
14:45:37.221 Debug SSH: Server is 'SSH-2.0-srtSSHServer_19.00'.
14:45:37.227 Info SSH: Negotiation started.
14:45:37.335 Debug SSH: Group exchange.
14:45:37.463 Debug SSH: Negotiating key.
14:45:37.478 Debug SSH: Received 2048-bit Diffie-Hellman prime (minimum allowed size is 1024 bits).
14:45:37.513 Debug SSH: Validating 'rsa-sha2-256' signature.
14:45:37.532 Debug SSH: Received 1024-bit RSA server key (minimum allowed size is 1023 bits).
14:45:57.280 Info SSH: Negotiation finished.
14:45:57.280 Info Info: Server: SSH-2.0-srtSSHServer_19.00
14:45:57.280 Info Info: Fingerprint (MD5): 8c:03:71:19:9f:e2:0f:e5:26:9c:06:df:ec:b7:45:99
14:45:57.280 Info Info: Fingerprint (SHA-256): Cv78auli0BEDW9ic2+l8NO1bC8MYVs8xtAApwzu9ZDI
14:45:57.281 Info Info: Cipher info: SSH 2.0, diffie-hellman-group-exchange-sha256, rsa-sha2-256, aes256-ctr/aes256-ctr, hmac-sha2-256/hmac-sha2-256
14:45:57.346 Debug SSH: Allowed authentication methods for 'USERNAME': publickey, password.
14:45:57.347 Debug SSH: Trying public key authentication for 'USERNAME' using 'rsa-sha2-256' (SHA256:bObKuB+t7YtKrYpi/0aQPiDEDvc7X+szWmCbGN5ibx4)
14:45:57.482 Error SSH: Rebex.Net.SshException: A public key corresponding to the supplied private key was not accepted by the server or the user name is incorrect.
   at Rebex.Net.SshSession.azxlb(String p0, String p1, SshPrivateKey p2, SshGssApiCredentials p3, Boolean p4)


14:32:09    Status: Connecting to IPADDRESS...
14:32:09    Trace:  Going to execute C:\Program Files\FileZilla FTP Client\fzsftp.exe
14:32:09    Response:   fzSftp started, protocol_version=11
14:32:09    Trace:  CSftpConnectOpData::ParseResponse() in state 0
14:32:09    Trace:  CControlSocket::SendNextCommand()
14:32:09    Trace:  CSftpConnectOpData::Send() in state 2
14:32:09    Command:    keyfile "C:\Clients\Private_Key.ppk"
14:32:09    Trace:  CSftpConnectOpData::ParseResponse() in state 2
14:32:09    Trace:  CControlSocket::SendNextCommand()
14:32:09    Trace:  CSftpConnectOpData::Send() in state 3
14:32:09    Command:    open "USERNAME@IPADDRESS" 22
14:32:09    Trace:  Looking up host "IPADDRESS" for SSH connection
14:32:09    Trace:  Connecting to IPADDRESS port 22
14:32:09    Trace:  We claim version: SSH-2.0-FileZilla_3.60.1
14:32:09    Trace:  Connected to IPADDRESS
14:32:09    Trace:  Remote version: SSH-2.0-srtSSHServer_19.00
14:32:09    Trace:  Using SSH protocol version 2
14:32:09    Trace:  Doing Diffie-Hellman group exchange
14:32:09    Trace:  Doing Diffie-Hellman key exchange using 2070-bit modulus and hash SHA-256 (unaccelerated) with a server-supplied group
14:32:09    Trace:  Server also has rsa-sha2-256/ssh-rsa host keys, but we don't know any of them
14:32:09    Trace:  Host key fingerprint is:
14:32:09    Trace:  ssh-rsa 1024 SHA256:Cv78auli0BEDW9ic2+l8NO1bC8MYVs8xtAApwzu9ZDI
14:32:09    Trace:  CSftpControlSocket::SetAsyncRequestReply
14:32:09    Command:    Trust new Hostkey: Once
14:32:09    Trace:  Initialised AES-256 SDCTR (AES-NI accelerated) outbound encryption
14:32:09    Trace:  Initialised HMAC-SHA-256 (unaccelerated) outbound MAC algorithm
14:32:09    Trace:  Initialised AES-256 SDCTR (AES-NI accelerated) inbound encryption
14:32:09    Trace:  Initialised HMAC-SHA-256 (unaccelerated) inbound MAC algorithm
14:32:09    Trace:  Successfully loaded 1 key pair from file
14:32:09    Status: Using username "USERNAME". 
14:32:09    Trace:  Offered public key from "C:\Clients\Private_Key.ppk"
14:32:10    Trace:  Offer of public key accepted, trying to authenticate using it.
14:32:10    Trace:  Sent public key signature
14:32:10    Trace:  Access granted
14:32:10    Trace:  Opening main session channel
14:32:10    Trace:  Opened main channel
14:32:10    Trace:  Started a shell/command
14:32:10    Status: Connected to IPADDRESS

Filezilla seems to connect successfully. Any extra thoughts here please?

Many thanks

Rich

by (148k points)
If this is indeed a similar issue, the following code should help. Please give it a try.

    SshPrivateKey key = ...;

    var sftp = new Sftp();
    sftp.LogWriter = ...;
    sftp.Settings.EnsureKeyAcceptable = true;
    Rebex.Security.Cryptography.CryptoHelper.SetOption(sftp.Settings.SshParameters, "ClientKeyAlgorithms", new string[] { "ssh-rsa" });
    sftp.Connect("IPADDRESS", 22);
    sftp.Login("USERNAME", key);
by (140 points)
Thanks for the super quick response Lukas!   I would need to get this to my dev team to implement.  I was trying to ensure that the hotfix that was made available in November listed above, had been applied to 6.1, and expected this to have just worked in Rebex SFTP and then I would get the team to implement the new version of the .DLL's

"Apparently, OpenSSH is using the legacy "ssh-rsa" algorithm (RSA with SHA-1 hash), while Rebex SFTP attempts the new "rsa-sha2-256" algorithm (RSA with SHA-256 hash).

Unfortunately, it's not currently possible to force "ssh-rsa", so we will update Rebex SFTP and mail you a link to try later today."

Is it just that the Hotfix applied now gives the option to force ssh-rsa as you show in your snippet above that wasn't available before so there would be no way of testing this from the Rebext SFTP client for someone with no coding... I am happy to tinker with config files :-) ?  

Maybe a (very) simple question, apologies, but if we use the above and it resolves the issue for this client forcing ssh-rsa and we roll it out, I'm guessing that it will only use this as a last resort as it is a weaker connection option than trying 256 first?

Regards

Rich
by (148k points)
The hotfix announced in November has been available since R6.10, but it only applies to Azure Storage SFTP server. Your server seems to be "srtSSHServer 19.00", and the hotfix won't be applied to it. Instead, CryptoHelper.SetOption has to be used to enforceusage of "ssh-rsa". And the additional EnsureKeyAcceptable makes the authentication exchange more like FileZilla client.
by (140 points)
Thank you Lukas, I'll advise our dev team.
by (140 points)
Hi Lukas, I have just tested the changes you suggested and this seems to have resolved the issue in our testing environment.  Thanks again for the quick response here.

Can I just confirm exactly what this does?  Does it force a connection at ssh-rsa even if the later ssh-rsa2 may be available at the host, or does this just change the sequence of connectivity offered so the legacy one comes first?

Hopefully, it is just a sequence change as I am a little bit twitchy to release this to the entire customer base if this is only affecting one customer if it has to connect using this method.

As I mentioned, I am not a dev, I'm on the Tech Services team, so this may seem like a simple question to all out there, apologies!  Rich
by (148k points)
Hi AptWat, you are right to be a little bit twitchy about releasing this to the entire customer base, although it's not as bad as it sounds:

The "ClientKeyAlgorithms" option does not actually affect SSH negotiation, and has no effect on encryption or server host key validation (which would still use "rsa-sha2-256", as you can see i the log). What it does affect is client public key authentication - it forces Rebex SFTP to use "ssh-rsa" (RSA with SHA-1) instead of "rsa-sha2-256" (RSA with SHA-256) during client public key authentication even when the server claims or appears to support "rsa-sha2-256".

The effect of the option can be clearly seen in the log. Without the option, there is:
  Trying public key authentication for 'USERNAME' using 'rsa-sha2-256' (...)
And with the option, this becomes:
  Trying public key authentication for 'USERNAME' using 'ssh-rsa' (...)

But still, forcing RSA with SHA-1 for everyone is not a good idea - it's less secure, and even if you didn't care about that, some SFTP servers might actually reject this and require RSA with SHA-2.

Obviously, the proper solution to this issue is to have the servers fixed - both Azure SFTP server and srtSSHServer do support RSA/SHA-2 for server key authentication, and the fact that they refuse it for client key authentication seems to be a bug or an omission. If your clients suffer from this issue, please ask them to report the bug to the server vendor so they can fix it.

In the meantime, you have two options - either make the behavior configurable (such as adding "force legacy RSA/SHA-1 client authentication" to the UI or configuration file), or only enable the option when the application detects "srtSSHServer", like this for example:

            SshPrivateKey key = ...

            var sftp = new Sftp();
            sftp.LogWriter = new ConsoleLogWriter(LogLevel.Debug);
            sftp.Settings.EnsureKeyAcceptable = true;
            sftp.Connect("IPADDRESS", 22);

            // detect 'srtSSHServer' and force 'ssh-rsa' for client authentication
            if (sftp.Session.ServerIdentification.Contains("srtSSHServer_19.", StringComparison.Ordinal))
            {
                Rebex.Security.Cryptography.CryptoHelper.SetOption(sftp.Session.Parameters, "ClientKeyAlgorithms", new string[] { "ssh-rsa" });
            }

            sftp.Login("USERNAME", key);
by (140 points)
Hi Lukas,, once again, I appreciate your time and continued patience here. Your explanation is perfectly clear and the option to check for sshserver is a great suggestion I'll take back to the team, regards Rich
...