Upload timeout when using Explicit TLS

[darxmurf]

Hi,

Got some issues when using Explicit TLS connexion to UPLOAD files.
Connexion is ok, I can browse and Download without problems but can't Upload. The file is created on the remote side, then upload starts and the speed falls down to 0 after 1 second. Then the transfer timeout and try again.

No problems when connecting with other FTP clients.

Tested on client Client : Filezilla Client 3.5.3
Linux Debian Wheezy

Tested on Server : Pureftpd 1.0.22, Pureftpd 1.0.28, proftpd 1.3.4a
Server OS : Debian

Here is the log when connecting on a pureftpd machine

Status: Resolving address of xxx.xxx.xxx
Status: Connecting to xxx.xxx.xxx.xxx:21...
Status: Connection established, waiting for welcome message...
Trace: CFtpControlSocket::OnReceive()
Response: 220-FTP server ready.
Response: 220 This is a private system - No anonymous login
Trace: CFtpControlSocket::SendNextCommand()
Command: AUTH TLS
Trace: CFtpControlSocket::OnReceive()
Response: 234 AUTH TLS OK.
Status: Initializing TLS...
Trace: CTlsSocket::Handshake()
Trace: CTlsSocket::ContinueHandshake()
Trace: CTlsSocket::OnSend()
Trace: CTlsSocket::OnRead()
Trace: CTlsSocket::ContinueHandshake()
Trace: CTlsSocket::OnRead()
Trace: CTlsSocket::ContinueHandshake()
Trace: TLS Handshake successful
Trace: Cipher: AES-128-CBC, MAC: SHA1
Status: Verifying certificate...
Trace: CFtpControlSocket::SendNextCommand()
Command: USER xxxxxxxx
Status: TLS/SSL connection established.
Trace: CTlsSocket::OnRead()
Trace: CFtpControlSocket::OnReceive()
Response: 331 User bk34466 OK. Password required
Trace: CFtpControlSocket::SendNextCommand()
Command: PASS
Trace: CTlsSocket::OnRead()
Trace: CFtpControlSocket::OnReceive()
Response: 230-User xxxxxxxx has group access to: ftpgroup
Response: 230-OK. Current restricted directory is /
Response: 230 10103133 Kbytes used (24%) - authorized: 41943040 Kb
Trace: CFtpControlSocket::SendNextCommand()
Command: PBSZ 0
Trace: CTlsSocket::OnRead()
Trace: CFtpControlSocket::OnReceive()
Response: 200 PBSZ=0
Trace: CFtpControlSocket::SendNextCommand()
Command: PROT P
Trace: CTlsSocket::OnRead()
Trace: CFtpControlSocket::OnReceive()
Response: 200 Data protection level set to "private"
Status: Connected
Trace: CFtpControlSocket::ResetOperation(0)
Trace: CControlSocket::ResetOperation(0)
Trace: CFileZillaEnginePrivate::ResetOperation(0)
Trace: CFtpControlSocket::FileTransfer()
Status: Starting upload of /home/thib/Desktop/test/test.test
Trace: CFtpControlSocket::SendNextCommand()
Trace: CFtpControlSocket::ChangeDirSend()
Command: CWD /
Trace: CTlsSocket::OnRead()
Trace: CFtpControlSocket::OnReceive()
Response: 250 OK. Current directory is /
Trace: CFtpControlSocket::ResetOperation(0)
Trace: CControlSocket::ResetOperation(0)
Trace: CFtpControlSocket::ParseSubcommandResult(0)
Trace: FileTransferSubcommandResult()
Trace: CFtpControlSocket::SendNextCommand()
Trace: FileTransferSend()
Trace: CFtpControlSocket::SendNextCommand()
Trace: CFtpControlSocket::TransferSend()
Trace: state = 1
Command: TYPE I
Trace: CTlsSocket::OnRead()
Trace: CFtpControlSocket::OnReceive()
Response: 200 TYPE is now 8-bit binary
Trace: CFtpControlSocket::TransferParseResponse()
Trace: code = 2
Trace: state = 1
Trace: CFtpControlSocket::SendNextCommand()
Trace: CFtpControlSocket::TransferSend()
Trace: state = 2
Command: PASV
Trace: CTlsSocket::OnRead()
Trace: CFtpControlSocket::OnReceive()
Response: 227 Entering Passive Mode (xxx,xxx,xxx,xxx,248,52)
Trace: CFtpControlSocket::TransferParseResponse()
Trace: code = 2
Trace: state = 2
Trace: CFtpControlSocket::SendNextCommand()
Trace: CFtpControlSocket::TransferSend()
Trace: state = 4
Command: STOR test.test
Trace: CTransferSocket::OnConnect
Trace: CTlsSocket::Handshake()
Trace: CTlsSocket::ContinueHandshake()
Trace: CTlsSocket::OnSend()
Trace: CTlsSocket::OnSend()
Trace: CTlsSocket::OnRead()
Trace: CTlsSocket::ContinueHandshake()
Trace: CTlsSocket::OnRead()
Trace: CTlsSocket::ContinueHandshake()
Trace: TLS Handshake successful
Trace: Cipher: AES-128-CBC, MAC: SHA1
Trace: CTlsSocket::OnRead()
Trace: CTransferSocket::OnConnect
Trace: First EAGAIN in CTransferSocket::OnSend()
Trace: CFtpControlSocket::OnReceive()
Response: 150 Accepted data connection
Trace: CFtpControlSocket::TransferParseResponse()
Trace: code = 1
Trace: state = 4
Trace: CFtpControlSocket::SendNextCommand()
Trace: CFtpControlSocket::TransferSend()
Trace: state = 5
Error: Connection timed out
Trace: CControlSocket::DoClose(2050)
Trace: CFtpControlSocket::ResetOperation(2114)
Trace: CControlSocket::ResetOperation(2114)
Trace: CFtpControlSocket::ResetOperation(2114)
Trace: CControlSocket::ResetOperation(2114)
Error: File transfer failed after transferring 737,280 bytes in 21 seconds
Trace: CFileZillaEnginePrivate::ResetOperation(2114)
Trace: CControlSocket::DoClose(64)
Trace: CControlSocket::DoClose(64)
Status: Resolving address of xxxxxxx
Status: Connecting to xxx.xxx.xxx.xxx:21...
Status: Connection established, waiting for welcome message...
Trace: CFtpControlSocket::OnReceive()
Response: 220-FTP server ready.
Response: 220 This is a private system - No anonymous login
Trace: CFtpControlSocket::SendNextCommand()
Command: AUTH TLS
Trace: CFtpControlSocket::OnReceive()
Response: 234 AUTH TLS OK.
Status: Initializing TLS...
Trace: CTlsSocket::Handshake()
Trace: CTlsSocket::ContinueHandshake()
Trace: CTlsSocket::OnSend()
Trace: CTlsSocket::OnRead()
Trace: CTlsSocket::ContinueHandshake()
Trace: CTlsSocket::OnRead()
Trace: CTlsSocket::ContinueHandshake()
Trace: TLS Handshake successful
Trace: Cipher: AES-128-CBC, MAC: SHA1
Status: Verifying certificate...
Trace: CFtpControlSocket::SendNextCommand()
Command: USER bk34466
Status: TLS/SSL connection established.
Trace: CTlsSocket::OnRead()
Trace: CFtpControlSocket::OnReceive()
Response: 331 User bk34466 OK. Password required
Trace: CFtpControlSocket::SendNextCommand()
Command: PASS
Trace: CTlsSocket::OnRead()
Trace: CFtpControlSocket::OnReceive()
Response: 230-User xxxxx has group access to: ftpgroup
Response: 230-OK. Current restricted directory is /
Response: 230 10103853 Kbytes used (24%) - authorized: 41943040 Kb
Trace: CFtpControlSocket::SendNextCommand()
Command: PBSZ 0
Trace: CTlsSocket::OnRead()
Trace: CFtpControlSocket::OnReceive()
Response: 200 PBSZ=0
Trace: CFtpControlSocket::SendNextCommand()
Command: PROT P
Trace: CTlsSocket::OnRead()
Trace: CFtpControlSocket::OnReceive()
Response: 200 Data protection level set to "private"
Status: Connected
Trace: CFtpControlSocket::ResetOperation(0)
Trace: CControlSocket::ResetOperation(0)
Trace: CFileZillaEnginePrivate::ResetOperation(0)
Trace: CFtpControlSocket::FileTransfer()
Status: Starting upload of /home/thib/Desktop/test/test.test
Trace: CFtpControlSocket::SendNextCommand()
Trace: CFtpControlSocket::ChangeDirSend()
Command: CWD /
Trace: CTlsSocket::OnRead()
Trace: CFtpControlSocket::OnReceive()
Response: 250 OK. Current directory is /
Trace: CFtpControlSocket::ResetOperation(0)
Trace: CControlSocket::ResetOperation(0)
Trace: CFtpControlSocket::ParseSubcommandResult(0)
Trace: FileTransferSubcommandResult()
Status: Retrieving directory listing...
Trace: ftpcontrolsocket.cpp(1296): List called from other command caller=0x7f0d30005470
Trace: CFtpControlSocket::ParseSubcommandResult(0)
Trace: CFtpControlSocket::ListSubcommandResult()
Trace: state = 1
Trace: CFtpControlSocket::SendNextCommand()
Trace: CFtpControlSocket::TransferSend()
Trace: state = 1
Command: TYPE I
Trace: CTlsSocket::OnRead()
Trace: CFtpControlSocket::OnReceive()
Response: 200 TYPE is now 8-bit binary
Trace: CFtpControlSocket::TransferParseResponse()
Trace: code = 2
Trace: state = 1
Trace: CFtpControlSocket::SendNextCommand()
Trace: CFtpControlSocket::TransferSend()
Trace: state = 2
Command: PASV
Trace: CTlsSocket::OnRead()
Trace: CFtpControlSocket::OnReceive()
Response: 227 Entering Passive Mode (xxx,xxx,xxx,xxx,49,114)
Trace: CFtpControlSocket::TransferParseResponse()
Trace: code = 2
Trace: state = 2
Trace: CFtpControlSocket::SendNextCommand()
Trace: CFtpControlSocket::TransferSend()
Trace: state = 4
Command: MLSD
Trace: CTransferSocket::OnConnect
Trace: CTlsSocket::Handshake()
Trace: CTlsSocket::ContinueHandshake()
Trace: CTlsSocket::OnSend()
Trace: CTlsSocket::OnSend()
Trace: CTlsSocket::OnRead()
Trace: CTlsSocket::ContinueHandshake()
Trace: CTlsSocket::OnRead()
Trace: CTlsSocket::ContinueHandshake()
Trace: TLS Handshake successful
Trace: Cipher: AES-128-CBC, MAC: SHA1
Trace: CTlsSocket::OnRead()
Trace: CTransferSocket::OnConnect
Trace: CTransferSocket::OnReceive(), m_transferMode=0
Trace: CTransferSocket::TransferEnd(1)
Trace: CFtpControlSocket::OnReceive()
Response: 150 Accepted data connection
Trace: CFtpControlSocket::TransferParseResponse()
Trace: code = 1
Trace: state = 4
Trace: CFtpControlSocket::SendNextCommand()
Trace: CFtpControlSocket::TransferSend()
Trace: state = 5
Response: 226-ASCII
Response: 226-Options: -a -l
Response: 226 12 matches total
Trace: CFtpControlSocket::TransferParseResponse()
Trace: code = 2
Trace: state = 5
Trace: CFtpControlSocket::SendNextCommand()
Trace: CFtpControlSocket::TransferSend()
Trace: state = 8
Trace: CFtpControlSocket::TransferEnd()
Trace: CFtpControlSocket::ResetOperation(0)
Trace: CControlSocket::ResetOperation(0)
Trace: CFtpControlSocket::ParseSubcommandResult(0)
Trace: CFtpControlSocket::ListSubcommandResult()
Trace: state = 3
Trace: CFtpControlSocket::ResetOperation(0)
Trace: CControlSocket::ResetOperation(0)
Trace: CFtpControlSocket::ParseSubcommandResult(0)
Trace: FileTransferSubcommandResult()
Trace: CFtpControlSocket::SendNextCommand()
Trace: FileTransferSend()
Trace: CFtpControlSocket::SendNextCommand()
Trace: CFtpControlSocket::TransferSend()
Trace: state = 2
Command: PASV
Trace: CTlsSocket::OnRead()
Trace: CFtpControlSocket::OnReceive()
Response: 227 Entering Passive Mode (xxx,xxx,xxx,xxx,49,5)
Trace: CFtpControlSocket::TransferParseResponse()
Trace: code = 2
Trace: state = 2
Trace: CFtpControlSocket::SendNextCommand()
Trace: CFtpControlSocket::TransferSend()
Trace: state = 3
Command: REST 737280
Trace: CTlsSocket::OnRead()
Trace: CFtpControlSocket::OnReceive()
Response: 350 Restarting at 737280
Trace: CFtpControlSocket::TransferParseResponse()
Trace: code = 3
Trace: state = 3
Trace: CFtpControlSocket::SendNextCommand()
Trace: CFtpControlSocket::TransferSend()
Trace: state = 4
Command: STOR test.test
Trace: CTransferSocket::OnConnect
Trace: CTlsSocket::Handshake()
Trace: CTlsSocket::ContinueHandshake()
Trace: CTlsSocket::OnSend()
Trace: CTlsSocket::OnSend()
Trace: CTlsSocket::OnRead()
Trace: CTlsSocket::ContinueHandshake()
Trace: CTlsSocket::OnRead()
Trace: CTlsSocket::ContinueHandshake()
Trace: TLS Handshake successful
Trace: Cipher: AES-128-CBC, MAC: SHA1
Trace: CTlsSocket::OnRead()
Trace: CTransferSocket::OnConnect
Trace: First EAGAIN in CTransferSocket::OnSend()
Trace: CFtpControlSocket::OnReceive()
Response: 150 Accepted data connection
Trace: CFtpControlSocket::TransferParseResponse()
Trace: code = 1
Trace: state = 4
Trace: CFtpControlSocket::SendNextCommand()
Trace: CFtpControlSocket::TransferSend()
Trace: state = 5