Page 1 of 1

Download fails after complete data transfer

Posted: 2020-05-29 18:08
by jgao
Hello,

We are experience a strange issue. One of our client using FileZilla (v3.48.1) fails the download right after complete data transfer due to control session timeout. We enabled the "keep-alive" but still once reach the end of download it fails.

The FTP connection is Explicit TLS in passive mode. Client's FileZilla is on Windows. The server is vsftpd on CentOS behind a firewall. Because the FTP server serves many clients and this is the only client have such issue so we want to figure out what cause the timeout. I am kind of think that this is caused by client's side (firewall or their FileZilla) but I need to prove it.

Here is the debug log:

2020-05-28 23:07:05 32192 2 Status: Connected
2020-05-28 23:07:05 32192 2 Trace: CFtpControlSocket::ResetOperation(0)
2020-05-28 23:07:05 32192 2 Trace: CControlSocket::ResetOperation(0)
2020-05-28 23:07:05 32192 2 Trace: CFileZillaEnginePrivate::ResetOperation(0)
2020-05-28 23:07:05 32192 2 Trace: Measured latency of 53 ms
2020-05-28 23:07:05 32192 2 Trace: CFtpControlSocket::FileTransfer()
2020-05-28 23:07:05 32192 2 Status: Starting download of /delivery/FailedFiles/testfile_1000MB
2020-05-28 23:07:05 32192 2 Trace: CFtpControlSocket::SendNextCommand()
2020-05-28 23:07:05 32192 2 Trace: CFtpControlSocket::ChangeDirSend()
2020-05-28 23:07:05 32192 2 Command: CWD /delivery/FailedFiles
2020-05-28 23:07:05 32192 1 Trace: CTransferSocket::OnReceive(), m_transferMode=2
2020-05-28 23:07:05 32192 1 Trace: CTransferSocket::OnReceive(), m_transferMode=2
2020-05-28 23:07:05 32192 2 Trace: CFtpControlSocket::OnReceive()
2020-05-28 23:07:05 32192 2 Response: 250 Directory successfully changed.
2020-05-28 23:07:05 32192 2 Trace: CFtpControlSocket::ResetOperation(0)
2020-05-28 23:07:05 32192 2 Trace: CControlSocket::ResetOperation(0)
2020-05-28 23:07:05 32192 2 Trace: CFtpControlSocket::ParseSubcommandResult(0)
2020-05-28 23:07:05 32192 2 Trace: FileTransferSubcommandResult()
2020-05-28 23:07:05 32192 1 Trace: CTransferSocket::OnReceive(), m_transferMode=2
2020-05-28 23:07:05 32192 1 Trace: CTransferSocket::OnReceive(), m_transferMode=2

2020-05-28 23:07:08 32192 2 Command: RETR testfile_1000MB
2020-05-28 23:07:08 32192 2 Trace: CTransferSocket::OnConnect
2020-05-28 23:07:08 32192 2 Trace: CTransferSocket::OnReceive(), m_transferMode=2
2020-05-28 23:07:08 32192 2 Trace: CFtpControlSocket::OnReceive()
2020-05-28 23:07:08 32192 2 Response: 150 Opening BINARY mode data connection for testfile_1000MB (1073741824 bytes).
2020-05-28 23:07:08 32192 2 Trace: CFtpControlSocket::TransferParseResponse()
2020-05-28 23:07:08 32192 2 Trace: code = 1
2020-05-28 23:07:08 32192 2 Trace: state = 4
2020-05-28 23:07:08 32192 2 Trace: CFtpControlSocket::SendNextCommand()
2020-05-28 23:07:08 32192 2 Trace: CFtpControlSocket::TransferSend()
2020-05-28 23:07:08 32192 2 Trace: state = 5
2020-05-28 23:07:08 32192 2 Trace: CTransferSocket::OnReceive(), m_transferMode=2
2020-05-28 23:07:08 32192 2 Trace: CTransferSocket::OnReceive(), m_transferMode=2

2020-05-28 23:17:30 32192 1 Trace: CTransferSocket::OnReceive(), m_transferMode=2
2020-05-28 23:17:30 32192 1 Trace: CTransferSocket::OnReceive(), m_transferMode=2
2020-05-28 23:17:30 32192 2 Error: Connection timed out
2020-05-28 23:17:30 32192 2 Trace: CControlSocket::DoClose(2050)
2020-05-28 23:17:30 32192 2 Trace: CFtpControlSocket::ResetOperation(2114)
2020-05-28 23:17:30 32192 2 Trace: CControlSocket::ResetOperation(2114)
2020-05-28 23:17:30 32192 2 Trace: CFtpControlSocket::ResetOperation(2114)
2020-05-28 23:17:30 32192 2 Trace: CControlSocket::ResetOperation(2114)
2020-05-28 23:17:30 32192 2 Error: File transfer failed after transferring 1,073,741,824 bytes in 622 seconds
2020-05-28 23:17:30 32192 2 Trace: CFileZillaEnginePrivate::ResetOperation(2114)
2020-05-28 23:17:30 32192 2 Trace: CControlSocket::DoClose(64)