Filezilla getting disconnected with proftpd on file transfer

[unnikpr]

Hi,

I am facing issues while transfering files. the server and client log as follows,

Server log,

2017-03-28 02:49:22,795 mod_sftp/0.9.9[23010]: + Session key exchange: diffie-hellman-group-exchange-sha256
2017-03-28 02:49:22,795 mod_sftp/0.9.9[23010]: + Session server hostkey: ssh-rsa
2017-03-28 02:49:22,795 mod_sftp/0.9.9[23010]: + Session client-to-server encryption: aes256-ctr
2017-03-28 02:49:22,795 mod_sftp/0.9.9[23010]: + Session server-to-client encryption: aes256-ctr
2017-03-28 02:49:22,796 mod_sftp/0.9.9[23010]: + Session client-to-server MAC: hmac-sha2-256
2017-03-28 02:49:22,796 mod_sftp/0.9.9[23010]: + Session server-to-client MAC: hmac-sha2-256
2017-03-28 02:49:22,796 mod_sftp/0.9.9[23010]: + Session client-to-server compression: none
2017-03-28 02:49:22,796 mod_sftp/0.9.9[23010]: + Session server-to-client compression: none
2017-03-28 02:49:43,659 mod_sftp/0.9.9[23010]: error reading from client (fd 0): Connection reset by peer
2017-03-28 02:49:43,659 mod_sftp/0.9.9[23010]: disconnecting client (Connection reset by peer)
2017-03-28 02:49:43,659 mod_sftp/0.9.9[23010]: aborting 1 unclosed file handle
2017-03-28 03:49:43,864 mod_sftp/0.9.9[23011]: sent server version 'SSH-2.0-mod_sftp/0.9.9'
2017-03-28 03:49:43,864 mod_sftp/0.9.9[23011]: received client version 'SSH-2.0-PuTTY_Local:_Mar_20_2017_16:43:56'
2017-03-28 03:49:43,865 mod_sftp/0.9.9[23011]: handling connection from SSH2 client 'PuTTY_Local:_Mar_20_2017_16:43:56'
2017-03-28 03:49:43,887 mod_sftp/0.9.9[23011]: + Session key exchange: diffie-hellman-group-exchange-sha256
2017-03-28 03:49:43,887 mod_sftp/0.9.9[23011]: + Session server hostkey: ssh-rsa
2017-03-28 03:49:43,887 mod_sftp/0.9.9[23011]: + Session client-to-server encryption: aes256-ctr
2017-03-28 03:49:43,887 mod_sftp/0.9.9[23011]: + Session server-to-client encryption: aes256-ctr
2017-03-28 03:49:43,887 mod_sftp/0.9.9[23011]: + Session client-to-server MAC: hmac-sha2-256
2017-03-28 03:49:43,887 mod_sftp/0.9.9[23011]: + Session server-to-client MAC: hmac-sha2-256
2017-03-28 03:49:43,887 mod_sftp/0.9.9[23011]: + Session client-to-server compression: none
2017-03-28 03:49:43,887 mod_sftp/0.9.9[23011]: + Session server-to-client compression: none
2017-03-28 03:49:44,359 mod_sftp/0.9.9[23011]: sending acceptable userauth methods: publickey,password
2017-03-28 02:49:44,386 mod_sftp/0.9.9[23011]: sending userauth success
2017-03-28 02:49:44,386 mod_sftp/0.9.9[23011]: user 'crisp1' authenticated via 'password' method
2017-03-28 02:49:44,386 mod_sftp/0.9.9[23011]: client sent SSH_MSG_IGNORE message (160 bytes)
2017-03-28 02:49:44,426 mod_sftp/0.9.9[23011]: unsupported 'simple@putty.projects.tartarus.org' channel requested, ignoring
2017-03-28 02:49:44,426 mod_sftp/0.9.9[23011]: 'subsystem' channel request for 'sftp' subsystem
2017-03-28 02:49:44,446 mod_sftp/0.9.9[23011]: using SFTP protocol version 3 for this session (channel ID 0)



Client log,

03:47:06 Status: Connecting to secureftp.hmetrix.com...
03:47:06 Trace: CControlSocket::SendNextCommand()
03:47:06 Trace: CSftpConnectOpData::Send() in state 0
03:47:06 Trace: Going to execute C:\Program Files (x86)\FileZilla FTP Client\fzsftp.exe
03:47:06 Response: fzSftp started, protocol_version=8
03:47:06 Trace: CSftpConnectOpData::ParseResponse() in state 0
03:47:06 Trace: CControlSocket::SendNextCommand()
03:47:06 Trace: CSftpConnectOpData::Send() in state 3
03:47:06 Command: open "crisp1@secureftp.hmetrix.com" 22
03:47:06 Trace: Connecting to 209.2.40.59 port 22
03:47:06 Trace: We claim version: SSH-2.0-PuTTY_Local:_Mar_20_2017_16:43:56
03:47:06 Trace: Server version: SSH-2.0-mod_sftp/0.9.9
03:47:06 Trace: Using SSH protocol version 2
03:47:06 Trace: Doing Diffie-Hellman group exchange
03:47:06 Trace: Doing Diffie-Hellman key exchange with hash SHA-256
03:47:06 Trace: Server also has ssh-dss host key, but we don't know it
03:47:06 Trace: Host key fingerprint is:
03:47:06 Trace: ssh-rsa 2048 66:01:8f:2e:12:5a:d1:5e:4d:14:f7:30:7a:34:aa:94 lBHAVGTuuB2kSEJeSOoqHBdg5P660WpDojN5XmrRYko=
03:47:06 Command: Trust new Hostkey: Once
03:47:06 Trace: Initialised AES-256 SDCTR client->server encryption
03:47:06 Trace: Initialised HMAC-SHA-256 client->server MAC algorithm
03:47:06 Trace: Initialised AES-256 SDCTR server->client encryption
03:47:06 Trace: Initialised HMAC-SHA-256 server->client MAC algorithm
03:47:06 Command: Pass: *********
03:47:06 Trace: Sent password
03:47:06 Trace: Access granted
03:47:06 Trace: Opening session as main channel
03:47:06 Trace: Opened main channel
03:47:06 Trace: Started a shell/command
03:47:06 Status: Connected to secure.hmetrix.com
03:47:06 Trace: CSftpConnectOpData::ParseResponse() in state 3
03:47:06 Trace: CSftpControlSocket::ResetOperation(0)
03:47:06 Trace: CControlSocket::ResetOperation(0)
03:47:06 Trace: CFileZillaEnginePrivate::ResetOperation(0)
03:47:06 Status: Retrieving directory listing...
03:47:06 Trace: CControlSocket::SendNextCommand()
03:47:06 Trace: CSftpListOpData::Send() in state 0
03:47:06 Trace: CSftpChangeDirOpData::Send() in state 0
03:47:06 Trace: CSftpChangeDirOpData::Send() in state 1
03:47:06 Command: pwd
03:47:06 Response: Current directory is: "/"
03:47:06 Trace: CSftpChangeDirOpData::ParseResponse() in state 1
03:47:06 Trace: CSftpControlSocket::ResetOperation(0)
03:47:06 Trace: CControlSocket::ResetOperation(0)
03:47:06 Trace: CControlSocket::ParseSubcommandResult(0)
03:47:06 Trace: CSftpListOpData::SubcommandResult() in state 1
03:47:06 Trace: CControlSocket::SendNextCommand()
03:47:06 Trace: CSftpListOpData::Send() in state 2
03:47:06 Trace: CSftpListOpData::Send() in state 3
03:47:06 Command: ls
03:47:06 Status: Listing directory /
03:47:07 Trace: CSftpListOpData::ParseResponse() in state 3
03:47:07 Trace: CSftpControlSocket::ResetOperation(0)
03:47:07 Trace: CControlSocket::ResetOperation(0)
03:47:07 Status: Directory listing of "/" successful
03:47:07 Trace: CFileZillaEnginePrivate::ResetOperation(0)
03:47:09 Trace: CFileZillaEnginePrivate::ResetOperation(0)
03:47:39 Status: Connecting to secureftp.hmetrix.com...
03:47:39 Trace: CControlSocket::SendNextCommand()
03:47:39 Trace: CSftpConnectOpData::Send() in state 0
03:47:39 Trace: Going to execute C:\Program Files (x86)\FileZilla FTP Client\fzsftp.exe
03:47:39 Response: fzSftp started, protocol_version=8
03:47:39 Trace: CSftpConnectOpData::ParseResponse() in state 0
03:47:39 Trace: CControlSocket::SendNextCommand()
03:47:39 Trace: CSftpConnectOpData::Send() in state 3
03:47:39 Command: open "crisp1@secureftp.hmetrix.com" 22
03:47:39 Trace: Connecting to 209.2.40.59 port 22
03:47:39 Trace: We claim version: SSH-2.0-PuTTY_Local:_Mar_20_2017_16:43:56
03:47:39 Trace: Server version: SSH-2.0-mod_sftp/0.9.9
03:47:39 Trace: Using SSH protocol version 2
03:47:39 Trace: Doing Diffie-Hellman group exchange
03:47:39 Trace: Doing Diffie-Hellman key exchange with hash SHA-256
03:47:40 Trace: Server also has ssh-dss host key, but we don't know it
03:47:40 Trace: Host key fingerprint is:
03:47:40 Trace: ssh-rsa 2048 66:01:8f:2e:12:5a:d1:5e:4d:14:f7:30:7a:34:aa:94 lBHAVGTuuB2kSEJeSOoqHBdg5P660WpDojN5XmrRYko=
03:47:40 Command: Trust new Hostkey: Once
03:47:40 Trace: Initialised AES-256 SDCTR client->server encryption
03:47:40 Trace: Initialised HMAC-SHA-256 client->server MAC algorithm
03:47:40 Trace: Initialised AES-256 SDCTR server->client encryption
03:47:40 Trace: Initialised HMAC-SHA-256 server->client MAC algorithm
03:47:41 Command: Pass: *********
03:47:41 Trace: Sent password
03:47:41 Trace: Access granted
03:47:41 Trace: Opening session as main channel
03:47:41 Trace: Opened main channel
03:47:41 Trace: Started a shell/command
03:47:41 Status: Connected to secure.hmetrix.com
03:47:41 Trace: CSftpConnectOpData::ParseResponse() in state 3
03:47:41 Trace: CSftpControlSocket::ResetOperation(0)
03:47:41 Trace: CControlSocket::ResetOperation(0)
03:47:41 Trace: CFileZillaEnginePrivate::ResetOperation(0)
03:47:41 Trace: CControlSocket::SendNextCommand()
03:47:41 Trace: CSftpFileTransferOpData::Send() in state 0
03:47:41 Status: Starting upload of C:\Users\bcpi\Transfer Test\200mb.txt
03:47:41 Trace: CSftpChangeDirOpData::Send() in state 0
03:47:41 Trace: CSftpChangeDirOpData::Send() in state 2
03:47:41 Command: cd "/TohMetrix"
03:47:41 Response: New directory is: "/TohMetrix"
03:47:41 Trace: CSftpChangeDirOpData::ParseResponse() in state 2
03:47:41 Trace: CSftpControlSocket::ResetOperation(0)
03:47:41 Trace: CControlSocket::ResetOperation(0)
03:47:41 Trace: CControlSocket::ParseSubcommandResult(0)
03:47:41 Trace: CSftpFileTransferOpData::SubcommandResult() in state 1
03:47:41 Trace: CControlSocket::SendNextCommand()
03:47:41 Trace: CSftpFileTransferOpData::Send() in state 4
03:47:41 Command: put "C:\Users\bcpi\Transfer Test\200mb.txt" "200mb.txt"
03:47:41 Command: local:C:\Users\bcpi\Transfer Test\200mb.txt => remote:/TohMetrix/200mb.txt
03:49:23 Trace: Server initiated key re-exchange
03:49:23 Trace: Doing Diffie-Hellman group exchange
03:49:23 Trace: Doing Diffie-Hellman key exchange with hash SHA-256
03:49:23 Trace: Initialised AES-256 SDCTR client->server encryption
03:49:23 Trace: Initialised HMAC-SHA-256 client->server MAC algorithm
03:49:43 Error: Connection timed out after 20 seconds of inactivity
03:49:44 Trace: CControlSocket::DoClose(2050)
03:49:44 Trace: CSftpControlSocket::ResetOperation(2114)
03:49:44 Trace: CControlSocket::ResetOperation(2114)
03:49:44 Error: File transfer failed after transferring 103,874,560 bytes in 122 seconds
03:49:44 Trace: CFileZillaEnginePrivate::ResetOperation(2114)
03:49:44 Status: Disconnected from server
03:49:44 Trace: CControlSocket::DoClose(66)
03:49:44 Trace: CControlSocket::DoClose(66)
03:49:44 Trace: CControlSocket::DoClose(66)
03:49:44 Trace: CFileZillaEnginePrivate::ResetOperation(0)
03:49:44 Status: Connecting to secureftp.hmetrix.com...
03:49:44 Trace: CControlSocket::SendNextCommand()
03:49:44 Trace: CSftpConnectOpData::Send() in state 0
03:49:44 Trace: Going to execute C:\Program Files (x86)\FileZilla FTP Client\fzsftp.exe
03:49:44 Response: fzSftp started, protocol_version=8
03:49:44 Trace: CSftpConnectOpData::ParseResponse() in state 0
03:49:44 Trace: CControlSocket::SendNextCommand()
03:49:44 Trace: CSftpConnectOpData::Send() in state 3
03:49:44 Command: open "crisp1@secureftp.hmetrix.com" 22
03:49:44 Trace: Connecting to 209.2.40.59 port 22
03:49:44 Trace: We claim version: SSH-2.0-PuTTY_Local:_Mar_20_2017_16:43:56
03:49:44 Trace: Server version: SSH-2.0-mod_sftp/0.9.9
03:49:44 Trace: Using SSH protocol version 2
03:49:44 Trace: Doing Diffie-Hellman group exchange
03:49:44 Trace: Doing Diffie-Hellman key exchange with hash SHA-256
03:49:44 Trace: Server also has ssh-dss host key, but we don't know it
03:49:44 Trace: Host key fingerprint is:
03:49:44 Trace: ssh-rsa 2048 66:01:8f:2e:12:5a:d1:5e:4d:14:f7:30:7a:34:aa:94 lBHAVGTuuB2kSEJeSOoqHBdg5P660WpDojN5XmrRYko=
03:49:44 Command: Trust new Hostkey: Once
03:49:44 Trace: Initialised AES-256 SDCTR client->server encryption
03:49:44 Trace: Initialised HMAC-SHA-256 client->server MAC algorithm
03:49:44 Trace: Initialised AES-256 SDCTR server->client encryption
03:49:44 Trace: Initialised HMAC-SHA-256 server->client MAC algorithm
03:49:45 Command: Pass: *********
03:49:45 Trace: Sent password
03:49:45 Trace: Access granted
03:49:45 Trace: Opening session as main channel
03:49:45 Trace: Opened main channel
03:49:45 Trace: Started a shell/command
03:49:45 Status: Connected to secure.hmetrix.com
03:49:45 Trace: CSftpConnectOpData::ParseResponse() in state 3
03:49:45 Trace: CSftpControlSocket::ResetOperation(0)
03:49:45 Trace: CControlSocket::ResetOperation(0)
03:49:45 Trace: CFileZillaEnginePrivate::ResetOperation(0)
03:49:45 Trace: CControlSocket::SendNextCommand()
03:49:45 Trace: CSftpFileTransferOpData::Send() in state 0
03:49:45 Status: Starting upload of C:\Users\bcpi\Transfer Test\200mb.txt
03:49:45 Trace: CSftpChangeDirOpData::Send() in state 0
03:49:45 Trace: CSftpChangeDirOpData::Send() in state 2
03:49:45 Command: cd "/TohMetrix"
03:49:45 Response: New directory is: "/TohMetrix"
03:49:45 Trace: CSftpChangeDirOpData::ParseResponse() in state 2
03:49:45 Trace: CSftpControlSocket::ResetOperation(0)
03:49:45 Trace: CControlSocket::ResetOperation(0)
03:49:45 Trace: CControlSocket::ParseSubcommandResult(0)
03:49:45 Trace: CSftpFileTransferOpData::SubcommandResult() in state 1
03:49:45 Status: Retrieving directory listing of "/TohMetrix"...
03:49:45 Trace: CControlSocket::SendNextCommand()
03:49:45 Trace: CSftpListOpData::Send() in state 0
03:49:45 Trace: CSftpChangeDirOpData::Send() in state 0
03:49:45 Trace: CSftpControlSocket::ResetOperation(0)
03:49:45 Trace: CControlSocket::ResetOperation(0)
03:49:45 Trace: CControlSocket::ParseSubcommandResult(0)
03:49:45 Trace: CSftpListOpData::SubcommandResult() in state 1
03:49:45 Trace: CControlSocket::SendNextCommand()
03:49:45 Trace: CSftpListOpData::Send() in state 2
03:49:45 Trace: CSftpListOpData::Send() in state 3
03:49:45 Command: ls
03:49:45 Status: Listing directory /TohMetrix
03:49:45 Trace: CSftpListOpData::ParseResponse() in state 3
03:49:45 Trace: CSftpControlSocket::ResetOperation(0)
03:49:45 Trace: CControlSocket::ResetOperation(0)
03:49:45 Trace: CControlSocket::ParseSubcommandResult(0)
03:49:45 Trace: CSftpFileTransferOpData::SubcommandResult() in state 2
03:53:02 Trace: Server unexpectedly closed network connection
03:53:02 Error: Server unexpectedly closed network connection
03:53:02 Trace: Server unexpectedly closed network connection
03:53:02 Error: Server unexpectedly closed network connection
03:53:02 Trace: CSftpControlSocket::OnTerminate without error
03:53:02 Trace: CControlSocket::DoClose(66)
03:53:02 Trace: CSftpControlSocket::ResetOperation(66)
03:53:02 Trace: CControlSocket::ResetOperation(66)
03:53:02 Error: File transfer failed
03:53:02 Trace: CFileZillaEnginePrivate::ResetOperation(66)
03:53:02 Trace: CSftpControlSocket::OnTerminate without error
03:53:02 Trace: CControlSocket::DoClose(66)
03:53:02 Trace: CSftpControlSocket::ResetOperation(66)
03:53:02 Trace: CControlSocket::ResetOperation(66)
03:53:02 Trace: CFileZillaEnginePrivate::ResetOperation(66)
03:53:02 Status: Disconnected from server
03:53:02 Trace: CControlSocket::DoClose(66)
03:53:02 Trace: CControlSocket::DoClose(66)
03:53:02 Trace: CControlSocket::DoClose(66)
03:53:02 Trace: CFileZillaEnginePrivate::ResetOperation(0)
03:53:02 Status: Connecting to secureftp.hmetrix.com...
03:53:02 Trace: CControlSocket::SendNextCommand()
03:53:02 Trace: CSftpConnectOpData::Send() in state 0
03:53:02 Trace: Going to execute C:\Program Files (x86)\FileZilla FTP Client\fzsftp.exe
03:53:02 Response: fzSftp started, protocol_version=8
03:53:02 Trace: CSftpConnectOpData::ParseResponse() in state 0
03:53:02 Trace: CControlSocket::SendNextCommand()
03:53:02 Trace: CSftpConnectOpData::Send() in state 3
03:53:02 Command: open "crisp1@secureftp.hmetrix.com" 22
03:53:02 Trace: Connecting to 209.2.40.59 port 22
03:53:02 Trace: We claim version: SSH-2.0-PuTTY_Local:_Mar_20_2017_16:43:56
03:53:03 Trace: Failed to connect to 209.2.40.59: Network error: Connection refused
03:53:03 Trace: Network error: Connection refused
03:53:03 Error: Network error: Connection refused
03:53:03 Trace: CSftpControlSocket::OnTerminate without error
03:53:03 Trace: CControlSocket::DoClose(66)
03:53:03 Trace: CSftpControlSocket::ResetOperation(66)
03:53:03 Trace: CControlSocket::ResetOperation(66)
03:53:03 Error: Could not connect to server
03:53:03 Trace: CFileZillaEnginePrivate::ResetOperation(66)
03:53:03 Status: Disconnected from server
03:53:03 Trace: CControlSocket::DoClose(66)
03:53:03 Trace: CControlSocket::DoClose(66)
03:53:03 Trace: CControlSocket::DoClose(66)
03:53:03 Trace: CFileZillaEnginePrivate::ResetOperation(0)
03:53:03 Status: Delaying connection for 5 seconds due to previously failed connection attempt...
03:53:08 Status: Connecting to secureftp.hmetrix.com...
03:53:08 Trace: CControlSocket::SendNextCommand()
03:53:08 Trace: CSftpConnectOpData::Send() in state 0
03:53:08 Trace: Going to execute C:\Program Files (x86)\FileZilla FTP Client\fzsftp.exe
03:53:08 Response: fzSftp started, protocol_version=8
03:53:08 Trace: CSftpConnectOpData::ParseResponse() in state 0
03:53:08 Trace: CControlSocket::SendNextCommand()
03:53:08 Trace: CSftpConnectOpData::Send() in state 3
03:53:08 Command: open "123@secureftp.testxxx.com" 22
03:53:08 Trace: Connecting to 209.2.40.59 port 22
03:53:08 Trace: We claim version: SSH-2.0-PuTTY_Local:_Mar_20_2017_16:43:56
03:53:08 Trace: Server version: SSH-2.0-mod_sftp/0.9.9
03:53:08 Trace: Using SSH protocol version 2
03:53:08 Trace: Doing Diffie-Hellman group exchange
03:53:08 Trace: Doing Diffie-Hellman key exchange with hash SHA-256
03:53:09 Trace: Server also has ssh-dss host key, but we don't know it
03:53:09 Trace: Host key fingerprint is:
03:53:09 Trace: ssh-rsa 2048 66:01:8f:2e:12:5a:d1:5e:4d:14:f7:30:7a:34:aa:94 lBHAVGTuuB2kSEJeSOoqHBdg5P660WpDojN5XmrRYko=
03:53:09 Command: Trust new Hostkey: Once
03:53:09 Trace: Initialised AES-256 SDCTR client->server encryption
03:53:09 Trace: Initialised HMAC-SHA-256 client->server MAC algorithm
03:53:09 Trace: Initialised AES-256 SDCTR server->client encryption
03:53:09 Trace: Initialised HMAC-SHA-256 server->client MAC algorithm
03:53:09 Command: Pass: *********
03:53:09 Trace: Sent password
03:53:09 Trace: Access granted
03:53:09 Trace: Opening session as main channel
03:53:09 Trace: Opened main channel
03:53:09 Trace: Started a shell/command
03:53:09 Status: Connected to secure.hmetrix.com
03:53:09 Trace: CSftpConnectOpData::ParseResponse() in state 3
03:53:09 Trace: CSftpControlSocket::ResetOperation(0)
03:53:09 Trace: CControlSocket::ResetOperation(0)
03:53:09 Trace: CFileZillaEnginePrivate::ResetOperation(0)
03:53:09 Trace: CControlSocket::SendNextCommand()
03:53:09 Trace: CSftpFileTransferOpData::Send() in state 0
03:53:09 Status: Starting upload of C:\Users\bcpi\Transfer Test\200mb.txt
03:53:09 Trace: CSftpChangeDirOpData::Send() in state 0
03:53:09 Trace: CSftpChangeDirOpData::Send() in state 2
03:53:09 Command: cd "/TohMetrix"
03:53:09 Response: New directory is: "/TohMetrix"
03:53:09 Trace: CSftpChangeDirOpData::ParseResponse() in state 2
03:53:09 Trace: CSftpControlSocket::ResetOperation(0)
03:53:09 Trace: CControlSocket::ResetOperation(0)
03:53:09 Trace: CControlSocket::ParseSubcommandResult(0)
03:53:09 Trace: CSftpFileTransferOpData::SubcommandResult() in state 1
04:03:09 Trace: Server unexpectedly closed network connection
04:03:09 Error: Server unexpectedly closed network connection
04:03:09 Trace: CSftpControlSocket::OnTerminate without error
04:03:09 Trace: CControlSocket::DoClose(66)
04:03:09 Trace: CSftpControlSocket::ResetOperation(66)
04:03:09 Trace: CControlSocket::ResetOperation(66)
04:03:09 Error: File transfer failed

[botg]

Unfortunately the logs don't match. Please synchronize your clocks and provide matching logs.

[elichtas]

I'm hitting the same sporadic issue against the Legacy Maverick SFTP server. I have a snippet of my logs listed below, and full logs from FileZilla and Maverick attached. I'm not able to reproduce this issue with other SFTP clients, including CoreFTP, JSch, and psftp (which i believe Filezilla's SFTP capabilities is based on/uses).

The Maverick server has been updated to initiate the re-exchange every 100MB to force it to go through re-exchanges more frequently, and as far as I can tell, the Maverick server is sending all the required messages during the re-keying, but Filezilla is missing something and ultimately timing out. I appreciate any help in pinpointing and resolving this issue.

-----------------------------------------------------
FileZilla Trace Logs:
-----------------------------------------------------
07:50:48 Trace: Server initiated key re-exchange
07:50:48 Trace: Doing Diffie-Hellman group exchange
07:50:49 Trace: Doing Diffie-Hellman key exchange with hash SHA-256
07:50:51 Trace: Initialised AES-256 CBC client->server encryption
07:50:51 Trace: Initialised HMAC-SHA1 client->server MAC algorithm
07:50:51 Trace: Initialised AES-256 CBC server->client encryption
07:50:51 Trace: Initialised HMAC-SHA1 server->client MAC algorithm
07:50:51 Trace: Server initiated key re-exchange
07:50:51 Trace: Doing Diffie-Hellman group exchange
07:50:52 Trace: Doing Diffie-Hellman key exchange with hash SHA-256
07:50:53 Trace: Initialised AES-256 CBC client->server encryption
07:50:53 Trace: Initialised HMAC-SHA1 client->server MAC algorithm
07:50:53 Trace: Initialised AES-256 CBC server->client encryption
07:50:53 Trace: Initialised HMAC-SHA1 server->client MAC algorithm
07:50:53 Trace: Server initiated key re-exchange
07:50:53 Trace: Doing Diffie-Hellman group exchange
07:50:54 Trace: Doing Diffie-Hellman key exchange with hash SHA-256
07:50:56 Trace: Initialised AES-256 CBC client->server encryption
07:50:56 Trace: Initialised HMAC-SHA1 client->server MAC algorithm
07:51:16 Error: Connection timed out after 20 seconds of inactivity
07:51:16 Trace: CControlSocket::DoClose(2050)
07:51:16 Trace: CSftpControlSocket::ResetOperation(2114)
07:51:16 Trace: CControlSocket::ResetOperation(2114)
07:51:16 Error: File transfer failed after transferring 47,218,688 bytes in 50 seconds
07:51:16 Trace: CFileZillaEnginePrivate::ResetOperation(2114)
07:51:16 Status: Disconnected from server
07:51:16 Trace: CControlSocket::DoClose(66)
07:51:16 Trace: CControlSocket::DoClose(66)
07:51:16 Trace: CControlSocket::DoClose(66)
07:51:16 Trace: CFileZillaEnginePrivate::ResetOperation(0)
07:51:16 Status: Connecting to localhost:10022...
07:51:16 Trace: CControlSocket::SendNextCommand()
07:51:16 Trace: CSftpConnectOpData::Send() in state 0
07:51:16 Trace: Going to execute C:\Program Files\FileZilla FTP Client\fzsftp.exe
07:51:16 Response: fzSftp started, protocol_version=8
07:51:16 Trace: CSftpConnectOpData::ParseResponse() in state 0
07:51:16 Trace: CControlSocket::SendNextCommand()
07:51:16 Trace: CSftpConnectOpData::Send() in state 3
07:51:16 Command: open "User@localhost" 10022
07:51:16 Trace: Connecting to ::1 port 10022

-----------------------------------------------------
Maverick Debug Logs:
-----------------------------------------------------
017-05-10 07:50:53,809 [SFTP] Processing SSH_MSG_IGNORE
[DEBUG] 2017-05-10 07:50:53,809 [SFTP] Processing SSH_MSG_IGNORE
[DEBUG] 2017-05-10 07:50:53,809 [SFTP] Processing SSH_MSG_IGNORE
[DEBUG] 2017-05-10 07:50:53,809 [SFTP] Processing SSH_MSG_IGNORE
[DEBUG] 2017-05-10 07:50:53,810 [SFTP] Processing SSH_MSG_IGNORE
[DEBUG] 2017-05-10 07:50:53,810 [SFTP] Processing SSH_MSG_IGNORE
[DEBUG] 2017-05-10 07:50:53,810 [SFTP] Sent SSH_MSG_KEX_INIT
[DEBUG] 2017-05-10 07:50:53,810 [SFTP] Processing SSH_MSG_IGNORE
[DEBUG] 2017-05-10 07:50:53,810 [SFTP] Processing SSH_MSG_IGNORE
[DEBUG] 2017-05-10 07:50:53,810 [SFTP] Processing SSH_MSG_IGNORE
[DEBUG] 2017-05-10 07:50:53,811 [SFTP] Processing SSH_MSG_IGNORE
[DEBUG] 2017-05-10 07:50:53,811 [SFTP] Processing SSH_MSG_IGNORE
[DEBUG] 2017-05-10 07:50:53,811 [SFTP] Processing SSH_MSG_KEX_INIT
[DEBUG] 2017-05-10 07:50:53,812 [SFTP] Processing SSH_MSG_IGNORE
[DEBUG] 2017-05-10 07:50:53,812 [SFTP] Processing SSH_MSG_KEY_DH_GEX_REQUEST
[DEBUG] 2017-05-10 07:50:54,881 [SFTP] Sent SSH_MSG_KEY_DH_GEX_GROUP
[DEBUG] 2017-05-10 07:50:54,999 [SFTP] Processing SSH_MSG_IGNORE
[DEBUG] 2017-05-10 07:50:54,999 [SFTP] Processing SSH_MSG_KEY_DH_GEX_INIT
[DEBUG] 2017-05-10 07:50:56,077 [SFTP] Sent SSH_MSG_KEY_DH_GEX_REPLY
[DEBUG] 2017-05-10 07:50:56,077 [SFTP] Sent SSH_MSG_NEWKEYS
[DEBUG] 2017-05-10 07:50:56,077 [SFTP] generateNewKeys Server>Client before synchronized kexlock on thread: SSHD-TRANSFER-2
[DEBUG] 2017-05-10 07:50:56,193 [SFTP] Processing SSH_MSG_IGNORE
[DEBUG] 2017-05-10 07:50:56,193 [SFTP] Processing SSH_MSG_NEWKEYS
[DEBUG] 2017-05-10 07:50:56,193 [SFTP] generateNewKeys Client>Server before synchronized kexlock on thread: SSHD-TRANSFER-2
[DEBUG] 2017-05-10 07:51:15,246 [SFTP] Sent SSH_MSG_IGNORE
[DEBUG] 2017-05-10 07:51:16,701 [SFTP] Performing internal disconnect
[DEBUG] 2017-05-10 07:51:16,701 [SFTP] Stopping the active service
[DEBUG] 2017-05-10 07:51:16,706 [SFTP] Logging off user
[DEBUG] 2017-05-10 07:51:16,706 [SFTP] Submitting transport cleanup to executor service
[DEBUG] 2017-05-10 07:51:16,710 [SFTP] Selection key is being cancelled
[DEBUG] 2017-05-10 07:51:16,710 [SFTP] Cancelled key
[DEBUG] 2017-05-10 07:51:16,725 [SFTP] Cleaning up transport protocol
[DEBUG] 2017-05-10 07:51:16,725 [SFTP] There is now 1 active connection
[DEBUG] 2017-05-10 07:51:16,739 [SFTP] Thread id 1 has a current load of 1 channels
[DEBUG] 2017-05-10 07:51:16,739 [SFTP] An idle thread has been selected id=2
[DEBUG] 2017-05-10 07:51:16,739 [SFTP] Adding registration request to queue on thread: SSHD-ACCEPT-1
[DEBUG] 2017-05-10 07:51:16,739 [SFTP] Registering channel with interested ops 5
[DEBUG] 2017-05-10 07:51:16,739 [SFTP] Channel is open
[DEBUG] 2017-05-10 07:51:16,739 [SFTP] Channel is registered
[DEBUG] 2017-05-10 07:51:16,740 [SFTP] Access Manager has authorized access to 0:0:0:0:0:0:0:1
[DEBUG] 2017-05-10 07:51:16,740 [SFTP] There are now 2 active connections
[DEBUG] 2017-05-10 07:51:16,741 [SFTP] Registration complete
[DEBUG] 2017-05-10 07:51:16,741 [SFTP] Remote client identification string is SSH-2.0-PuTTY_Local:_Apr_30_2017_13:18:36

filezilla-reinit-kex.txt

(16.72 KiB) Downloaded 279 times

maverick-reinit-kex.txt

(546.95 KiB) Downloaded 248 times

[botg]

Which version of psftp did you try?

[elichtas]

Thanks for the reply Tim.

I'm was using PuTTY_Release_0.63 and have attached the PSFTP logs here as well. I notice that you recently updated FileZilla to be based on Putty 0.69 in 3.25.2, but i'm reproducing the issue in both Filezilla 3.25.1 and 3.25.2.

psftp-reinit-kex.txt

(18.07 KiB) Downloaded 286 times

[botg]

Could you please try psftp from PuTTY 0.69?

[elichtas]

There we go. Issue is reproduced with psftp 0.69 which i'm guessing is the root of why Filezilla is experiencing the failure. To solidify this, WinSCP (also using putty in the backend) experiences the same symptoms. I will send a message to the Putty team. Their mailing list seems to be private, so PM me if you would like to be included in this correspondence.

If i receiving any substantial feedback from them, i will make sure to post it here on this thread.

thanks again!

[botg]

Thanks for forwarding this to the PuTTY developers.

Yes, please include me in the CC: tim.kosse@filezilla-project.org

[lumaforge]

We're not too far out from when this post was created and either A) this is still a problem or B) a regressive bug has returned.

Does anyone on this thread already have an open communication with the PuTTY team on this or should I open a new ticket?

Thank you!

(Edit: Having same issues connecting to a ProFTPd server with WinSCP and FileZilla where CyberDuck and all terminal based sftp connections work just fine.)