#7287 closed Bug report (fixed)
Uploading problems with encryption (Linux only)
| Reported by: | PressimistPrime | Owned by: | |
|---|---|---|---|
| Priority: | high | Component: | FileZilla Client |
| Keywords: | Cc: | Nico.Laus.2001@…, jiri.horky@… | |
| Component version: | Operating system type: | Linux | |
| Operating system version: | Arch Linux |
Description
This log is anonymized. Size of cloudy_violet.JPG is 833,949 bytes. Filezilla 3.4.0 client (Linux) with encryption (Require explicit FTP over TLS).The connection timeout is nonsense. The FTP server is the last one which is sending an ACK and is waiting for Filezilla to do something - checked with wireshark. Without encryption, everything is working fine under Linux - but with encryption see this log. Only max. 180,224 bytes per session possible. Firewall was not active. Filezilla 3.4.0 client under Windows Vista is working flawlessly (with no encryption and encryption, too).
Status: Resolving address of my.homepage.webpack.hosteurope.de Status: Connecting to 123.123.123.123:21... Status: Connection established, waiting for welcome message... Response: 220 ::ffff:123.123.123.123 FTP server ready Command: AUTH TLS Response: 234 AUTH TLS successful Status: Initializing TLS... Status: Verifying certificate... Command: USER account-xyz Status: TLS/SSL connection established. Response: 331 Password required for account-xyz Command: PASS ***************** Response: 230 User account-xyz logged in Command: SYST Response: 215 UNIX Type: L8 Command: FEAT Response: 550 FEAT: Operation not permitted Command: PBSZ 0 Response: 200 PBSZ 0 successful Command: PROT P Response: 200 Protection set to Private Status: Connected Status: Retrieving directory listing... Command: PWD Response: 257 "/" is the current directory Command: TYPE I Response: 200 Type set to I Command: PASV Response: 227 Entering Passive Mode (123,123,123,123,203,69). Command: LIST Response: 150 Opening ASCII mode data connection for file list Response: 226 Transfer complete Status: Directory listing successful Status: Retrieving directory listing... Command: CWD www Response: 250 CWD command successful Command: PWD Response: 257 "/www" is the current directory Command: PASV Response: 227 Entering Passive Mode (123,123,123,123,203,156). Command: LIST Response: 150 Opening ASCII mode data connection for file list Response: 226 Transfer complete Status: Directory listing successful Status: Resolving address of my.homepage.webpack.hosteurope.de Status: Connecting to 123.123.123.123:21... Status: Connection established, waiting for welcome message... Response: 220 ::ffff:123.123.123.123 FTP server ready Command: AUTH TLS Response: 234 AUTH TLS successful Status: Initializing TLS... Status: Verifying certificate... Command: USER account-xyz Status: TLS/SSL connection established. Response: 331 Password required for account-xyz Command: PASS ***************** Response: 230 User account-xyz logged in Command: PBSZ 0 Response: 200 PBSZ 0 successful Command: PROT P Response: 200 Protection set to Private Status: Connected Status: Starting upload of /home/itsme/Desktop/cloudy_violet.JPG Command: CWD /www Response: 250 CWD command successful Command: PWD Response: 257 "/www" is the current directory Command: TYPE I Response: 200 Type set to I Command: PASV Response: 227 Entering Passive Mode (123,123,123,123,202,66). Command: STOR cloudy_violet.JPG Response: 150 Opening BINARY mode data connection for cloudy_violet.JPG Error: Connection timed out Error: File transfer failed after transferring 180,224 bytes in 21 seconds Status: Resolving address of my.homepage.webpack.hosteurope.de Status: Connecting to 123.123.123.123:21... Status: Connection established, waiting for welcome message... Response: 220 ::ffff:123.123.123.123 FTP server ready Command: AUTH TLS Response: 234 AUTH TLS successful Status: Initializing TLS... Status: Verifying certificate... Command: USER account-xyz Status: TLS/SSL connection established. Response: 331 Password required for account-xyz Command: PASS ***************** Response: 230 User account-xyz logged in Command: PBSZ 0 Response: 200 PBSZ 0 successful Command: PROT P Response: 200 Protection set to Private Status: Connected Status: Starting upload of /home/itsme/Desktop/cloudy_violet.JPG Command: CWD /www Response: 250 CWD command successful Status: Retrieving directory listing... Command: TYPE I Response: 200 Type set to I Command: PASV Response: 227 Entering Passive Mode (123,123,123,123,200,14). Command: LIST Response: 150 Opening ASCII mode data connection for file list Response: 226 Transfer complete Command: PASV Response: 227 Entering Passive Mode (123,123,123,123,203,55). Command: APPE cloudy_violet.JPG Response: 150 Opening BINARY mode data connection for cloudy_violet.JPG Error: Connection timed out Error: File transfer failed after transferring 180,224 bytes in 21 seconds Status: Resolving address of my.homepage.webpack.hosteurope.de Status: Connecting to 123.123.123.123:21... Status: Connection established, waiting for welcome message... Response: 220 ::ffff:123.123.123.123 FTP server ready Command: AUTH TLS Response: 234 AUTH TLS successful Status: Initializing TLS... Status: Verifying certificate... Command: USER account-xyz Status: TLS/SSL connection established. Response: 331 Password required for account-xyz Command: PASS ***************** Response: 230 User account-xyz logged in Command: PBSZ 0 Response: 200 PBSZ 0 successful Command: PROT P Response: 200 Protection set to Private Status: Connected Status: Starting upload of /home/itsme/Desktop/cloudy_violet.JPG Command: CWD /www Response: 250 CWD command successful Status: Retrieving directory listing... Command: TYPE I Response: 200 Type set to I Command: PASV Response: 227 Entering Passive Mode (123,123,123,123,209,89). Command: LIST Response: 150 Opening ASCII mode data connection for file list Response: 226 Transfer complete Command: PASV Response: 227 Entering Passive Mode (123,123,123,123,197,213). Command: APPE cloudy_violet.JPG Response: 150 Opening BINARY mode data connection for cloudy_violet.JPG Error: Connection timed out Error: File transfer failed after transferring 180,224 bytes in 21 seconds Status: Resolving address of my.homepage.webpack.hosteurope.de Status: Connecting to 123.123.123.123:21... Status: Connection established, waiting for welcome message... Response: 220 ::ffff:123.123.123.123 FTP server ready Command: AUTH TLS Response: 234 AUTH TLS successful Status: Initializing TLS... Status: Verifying certificate... Command: USER account-xyz Status: TLS/SSL connection established. Response: 331 Password required for account-xyz Command: PASS ***************** Response: 230 User account-xyz logged in Command: PBSZ 0 Response: 200 PBSZ 0 successful Command: PROT P Response: 200 Protection set to Private Status: Connected Status: Starting upload of /home/itsme/Desktop/cloudy_violet.JPG Command: CWD /www Response: 250 CWD command successful Status: Retrieving directory listing... Command: TYPE I Response: 200 Type set to I Command: PASV Response: 227 Entering Passive Mode (123,123,123,123,210,188). Command: LIST Response: 150 Opening ASCII mode data connection for file list Response: 226 Transfer complete Command: PASV Response: 227 Entering Passive Mode (123,123,123,123,208,35). Command: APPE cloudy_violet.JPG Response: 150 Opening BINARY mode data connection for cloudy_violet.JPG Error: Connection timed out Error: File transfer failed after transferring 180,224 bytes in 21 seconds Status: Resolving address of my.homepage.webpack.hosteurope.de Status: Connecting to 123.123.123.123:21... Status: Connection established, waiting for welcome message... Response: 220 ::ffff:123.123.123.123 FTP server ready Command: AUTH TLS Response: 234 AUTH TLS successful Status: Initializing TLS... Status: Verifying certificate... Command: USER account-xyz Status: TLS/SSL connection established. Response: 331 Password required for account-xyz Command: PASS ***************** Response: 230 User account-xyz logged in Command: PBSZ 0 Response: 200 PBSZ 0 successful Command: PROT P Response: 200 Protection set to Private Status: Connected Status: Starting upload of /home/itsme/Desktop/cloudy_violet.JPG Command: CWD /www Response: 250 CWD command successful Status: Retrieving directory listing... Command: TYPE I Response: 200 Type set to I Command: PASV Response: 227 Entering Passive Mode (123,123,123,123,205,231). Command: LIST Response: 150 Opening ASCII mode data connection for file list Response: 226 Transfer complete Command: PASV Response: 227 Entering Passive Mode (123,123,123,123,210,238). Command: APPE cloudy_violet.JPG Response: 150 Opening BINARY mode data connection for cloudy_violet.JPG Response: 226 Transfer complete Status: File transfer successful, transferred 113,053 bytes in 1 second Status: Retrieving directory listing... Command: PASV Response: 227 Entering Passive Mode (123,123,123,123,198,187). Command: LIST Response: 150 Opening ASCII mode data connection for file list Response: 226 Transfer complete Status: Directory listing successful
Change History (8)
comment:1 by , 13 years ago
comment:2 by , 13 years ago
| Cc: | added |
|---|
this bug still seems present (using openSUSE 12.1, x86_64, gnutls 3.0.19, filezilla 3.5.3)
comment:3 by , 12 years ago
| Cc: | added |
|---|
Hi,
exactly the same problem here, using v3.5.3 64bit on Gentoo, gnutls 2.12.18, against vsftpd server v2.3.2-3.3.1
Regareds
Jiri Horky
comment:4 by , 12 years ago
Ok, so I have tried to debug it little bit further, all based on latest source code tarball (3.5.3). I think there are several problems. First, lets have a look at what debug logs says:
01:31:30 Status: Resolving address of xxxxxxxxxxxxxxxxxxxx 01:31:30 Status: Connecting to xxxxxxxxxxxx:21... 01:31:30 Status: Connection established, waiting for welcome message... 01:31:30 Trace: CFtpControlSocket::OnReceive() 01:31:30 Response: 220 (vsFTPd 2.3.2) 01:31:30 Trace: CFtpControlSocket::SendNextCommand() 01:31:30 Command: AUTH TLS 01:31:30 Trace: CFtpControlSocket::OnReceive() 01:31:30 Response: 234 Proceed with negotiation. 01:31:30 Status: Initializing TLS... 01:31:30 Trace: CTlsSocket::Handshake() 01:31:30 Trace: CTlsSocket::ContinueHandshake() 01:31:30 Trace: CTlsSocket::OnSend() 01:31:30 Trace: CTlsSocket::OnRead() 01:31:30 Trace: CTlsSocket::ContinueHandshake() 01:31:30 Trace: CTlsSocket::OnRead() 01:31:30 Trace: CTlsSocket::ContinueHandshake() 01:31:30 Trace: CTlsSocket::OnRead() 01:31:30 Trace: CTlsSocket::ContinueHandshake() 01:31:30 Trace: CTlsSocket::OnRead() 01:31:30 Trace: CTlsSocket::ContinueHandshake() 01:31:30 Trace: TLS Handshake successful 01:31:30 Trace: Cipher: AES-128-CBC, MAC: SHA1 01:31:30 Status: Verifying certificate... 01:31:30 Trace: CFtpControlSocket::SendNextCommand() 01:31:30 Command: USER xxxxxxxxx 01:31:30 Status: TLS/SSL connection established. 01:31:30 Trace: CTlsSocket::OnRead() 01:31:30 Trace: CFtpControlSocket::OnReceive() 01:31:30 Response: 331 Please specify the password. 01:31:30 Trace: CFtpControlSocket::SendNextCommand() 01:31:30 Command: PASS ********* 01:31:30 Trace: CTlsSocket::OnRead() 01:31:30 Trace: CFtpControlSocket::OnReceive() 01:31:30 Response: 230 Login successful. 01:31:30 Trace: CFtpControlSocket::SendNextCommand() 01:31:30 Command: SYST 01:31:30 Trace: CTlsSocket::OnRead() 01:31:30 Trace: CFtpControlSocket::OnReceive() 01:31:30 Response: 215 UNIX Type: L8 01:31:30 Trace: CFtpControlSocket::SendNextCommand() 01:31:30 Command: FEAT 01:31:30 Trace: CTlsSocket::OnRead() 01:31:30 Trace: CFtpControlSocket::OnReceive() 01:31:30 Response: 211-Features: 01:31:30 Response: AUTH SSL 01:31:30 Response: AUTH TLS 01:31:30 Response: EPRT 01:31:30 Response: EPSV 01:31:30 Trace: CTlsSocket::OnRead() 01:31:30 Trace: CFtpControlSocket::OnReceive() 01:31:30 Response: MDTM 01:31:30 Response: PASV 01:31:30 Response: PBSZ 01:31:30 Response: PROT 01:31:30 Response: REST STREAM 01:31:30 Response: SIZE 01:31:30 Response: TVFS 01:31:30 Response: UTF8 01:31:30 Response: 211 End 01:31:30 Trace: CFtpControlSocket::SendNextCommand() 01:31:30 Command: OPTS UTF8 ON 01:31:30 Trace: CTlsSocket::OnRead() 01:31:30 Trace: CFtpControlSocket::OnReceive() 01:31:30 Response: 200 Always in UTF8 mode. 01:31:30 Trace: CFtpControlSocket::SendNextCommand() 01:31:30 Command: PBSZ 0 01:31:30 Trace: CTlsSocket::OnRead() 01:31:30 Trace: CFtpControlSocket::OnReceive() 01:31:30 Response: 200 PBSZ set to 0. 01:31:30 Trace: CFtpControlSocket::SendNextCommand() 01:31:30 Command: PROT P 01:31:30 Trace: CTlsSocket::OnRead() 01:31:30 Trace: CFtpControlSocket::OnReceive() 01:31:30 Response: 200 PROT now Private. 01:31:30 Status: Connected 01:31:30 Trace: CFtpControlSocket::ResetOperation(0) 01:31:30 Trace: CControlSocket::ResetOperation(0) 01:31:30 Trace: CFileZillaEnginePrivate::ResetOperation(0) 01:31:30 Status: Retrieving directory listing... 01:31:30 Trace: CFtpControlSocket::SendNextCommand() 01:31:30 Trace: CFtpControlSocket::ChangeDirSend() 01:31:30 Command: CWD / 01:31:30 Trace: CTlsSocket::OnRead() 01:31:30 Trace: CFtpControlSocket::OnReceive() 01:31:30 Response: 250 Directory successfully changed. 01:31:30 Trace: CFtpControlSocket::SendNextCommand() 01:31:30 Trace: CFtpControlSocket::ChangeDirSend() 01:31:30 Command: PWD 01:31:30 Trace: CTlsSocket::OnRead() 01:31:30 Trace: CFtpControlSocket::OnReceive() 01:31:30 Response: 257 "/" 01:31:30 Trace: CFtpControlSocket::ResetOperation(0) 01:31:30 Trace: CControlSocket::ResetOperation(0) 01:31:30 Trace: CFtpControlSocket::ParseSubcommandResult(0) 01:31:30 Trace: CFtpControlSocket::ListSubcommandResult() 01:31:30 Trace: state = 1 01:31:30 Trace: CFtpControlSocket::SendNextCommand() 01:31:30 Trace: CFtpControlSocket::TransferSend() 01:31:30 Trace: state = 1 01:31:30 Command: TYPE I 01:31:31 Trace: CTlsSocket::OnRead() 01:31:31 Trace: CFtpControlSocket::OnReceive() 01:31:31 Response: 200 Switching to Binary mode. 01:31:31 Trace: CFtpControlSocket::TransferParseResponse() 01:31:31 Trace: code = 2 01:31:31 Trace: state = 1 01:31:31 Trace: CFtpControlSocket::SendNextCommand() 01:31:31 Trace: CFtpControlSocket::TransferSend() 01:31:31 Trace: state = 2 01:31:31 Command: PASV 01:31:31 Trace: CTlsSocket::OnRead() 01:31:31 Trace: CFtpControlSocket::OnReceive() 01:31:31 Response: 227 Entering Passive Mode (xxxxxxxxxxxx,167,7). 01:31:31 Trace: CFtpControlSocket::TransferParseResponse() 01:31:31 Trace: code = 2 01:31:31 Trace: state = 2 01:31:31 Trace: CFtpControlSocket::SendNextCommand() 01:31:31 Trace: CFtpControlSocket::TransferSend() 01:31:31 Trace: state = 4 01:31:31 Command: LIST 01:31:31 Trace: CTransferSocket::OnConnect 01:31:31 Trace: CTlsSocket::Handshake() 01:31:31 Trace: gnutls_session_get_data on primary socket failed: -51 01:31:31 Trace: CTlsSocket::ContinueHandshake() 01:31:31 Trace: CTlsSocket::OnSend() 01:31:31 Trace: CTlsSocket::OnSend() 01:31:31 Trace: CTlsSocket::OnRead() 01:31:31 Trace: CFtpControlSocket::OnReceive() 01:31:31 Response: 150 Here comes the directory listing. 01:31:31 Trace: CFtpControlSocket::TransferParseResponse() 01:31:31 Trace: code = 1 01:31:31 Trace: state = 4 01:31:31 Trace: CFtpControlSocket::SendNextCommand() 01:31:31 Trace: CFtpControlSocket::TransferSend() 01:31:31 Trace: state = 5 01:31:31 Trace: CTlsSocket::OnRead() 01:31:31 Trace: CTlsSocket::ContinueHandshake() 01:31:31 Trace: CTlsSocket::OnRead() 01:31:31 Trace: CTlsSocket::ContinueHandshake() 01:31:31 Trace: CTlsSocket::OnRead() 01:31:31 Trace: CTlsSocket::ContinueHandshake() 01:31:31 Trace: CTlsSocket::OnRead() 01:31:31 Trace: CTlsSocket::ContinueHandshake() 01:31:31 Trace: TLS Handshake successful 01:31:31 Trace: Cipher: AES-128-CBC, MAC: SHA1 01:31:31 Trace: CTransferSocket::OnConnect 01:31:31 Trace: CTlsSocket::OnRead() 01:31:31 Trace: CTransferSocket::OnReceive(), m_transferMode=0 01:31:31 Trace: CTransferSocket::TransferEnd(1) 01:31:31 Trace: CFtpControlSocket::TransferEnd() 01:31:31 Trace: CTlsSocket::OnRead() 01:31:31 Trace: CFtpControlSocket::OnReceive() 01:31:31 Response: 226 Directory send OK. 01:31:31 Trace: CFtpControlSocket::TransferParseResponse() 01:31:31 Trace: code = 2 01:31:31 Trace: state = 7 01:31:31 Trace: CFtpControlSocket::ResetOperation(0) 01:31:31 Trace: CControlSocket::ResetOperation(0) 01:31:31 Trace: CFtpControlSocket::ParseSubcommandResult(0) 01:31:31 Trace: CFtpControlSocket::ListSubcommandResult() 01:31:31 Trace: state = 3 01:31:31 Trace: CFtpControlSocket::SendNextCommand() 01:31:31 Trace: CFtpControlSocket::ListSend() 01:31:31 Trace: state = 4 01:31:31 Status: Calculating timezone offset of server... 01:31:31 Command: MDTM gparted-live-0.9.0-7.iso 01:31:31 Trace: CTlsSocket::OnRead() 01:31:31 Trace: CFtpControlSocket::OnReceive() 01:31:31 Response: 213 20120522012936 01:31:31 Trace: CFtpControlSocket::ListParseResponse() 01:31:31 Status: Timezone offsets: Server: 0 seconds. Local: 7200 seconds. Difference: 7200 seconds. 01:31:31 Trace: CFtpControlSocket::ResetOperation(0) 01:31:31 Trace: CControlSocket::ResetOperation(0) 01:31:31 Status: Directory listing successful 01:31:31 Trace: CFileZillaEnginePrivate::ResetOperation(0) 01:31:38 Status: Resolving address of store2.du1.cesnet.cz 01:31:38 Status: Connecting to xxxxxxxxxxxx:21... 01:31:38 Status: Connection established, waiting for welcome message... 01:31:38 Trace: CFtpControlSocket::OnReceive() 01:31:38 Response: 220 (vsFTPd 2.3.2) 01:31:38 Trace: CFtpControlSocket::SendNextCommand() 01:31:38 Command: AUTH TLS 01:31:38 Trace: CFtpControlSocket::OnReceive() 01:31:38 Response: 234 Proceed with negotiation. 01:31:38 Status: Initializing TLS... 01:31:38 Trace: CTlsSocket::Handshake() 01:31:38 Trace: CTlsSocket::ContinueHandshake() 01:31:38 Trace: CTlsSocket::OnSend() 01:31:38 Trace: CTlsSocket::OnRead() 01:31:38 Trace: CTlsSocket::ContinueHandshake() 01:31:38 Trace: CTlsSocket::OnRead() 01:31:38 Trace: CTlsSocket::ContinueHandshake() 01:31:38 Trace: CTlsSocket::OnRead() 01:31:38 Trace: CTlsSocket::ContinueHandshake() 01:31:38 Trace: TLS Handshake successful 01:31:38 Trace: Cipher: AES-128-CBC, MAC: SHA1 01:31:38 Status: Verifying certificate... 01:31:38 Trace: CFtpControlSocket::SendNextCommand() 01:31:38 Command: USER xxxxxxxxxxx 01:31:38 Status: TLS/SSL connection established. 01:31:38 Trace: CTlsSocket::OnRead() 01:31:38 Trace: CFtpControlSocket::OnReceive() 01:31:38 Response: 331 Please specify the password. 01:31:38 Trace: CFtpControlSocket::SendNextCommand() 01:31:38 Command: PASS ********* 01:31:38 Trace: CTlsSocket::OnRead() 01:31:38 Trace: CFtpControlSocket::OnReceive() 01:31:38 Response: 230 Login successful. 01:31:38 Trace: CFtpControlSocket::SendNextCommand() 01:31:38 Command: OPTS UTF8 ON 01:31:38 Trace: CTlsSocket::OnRead() 01:31:38 Trace: CFtpControlSocket::OnReceive() 01:31:38 Response: 200 Always in UTF8 mode. 01:31:38 Trace: CFtpControlSocket::SendNextCommand() 01:31:38 Command: PBSZ 0 01:31:38 Trace: CTlsSocket::OnRead() 01:31:38 Trace: CFtpControlSocket::OnReceive() 01:31:38 Response: 200 PBSZ set to 0. 01:31:38 Trace: CFtpControlSocket::SendNextCommand() 01:31:38 Command: PROT P 01:31:38 Trace: CTlsSocket::OnRead() 01:31:38 Trace: CFtpControlSocket::OnReceive() 01:31:38 Response: 200 PROT now Private. 01:31:38 Status: Connected 01:31:38 Trace: CFtpControlSocket::ResetOperation(0) 01:31:38 Trace: CControlSocket::ResetOperation(0) 01:31:38 Trace: CFileZillaEnginePrivate::ResetOperation(0) 01:31:38 Trace: CFtpControlSocket::FileTransfer() 01:31:38 Status: Starting upload of /home/keruom/gparted-live-0.9.0-7.iso 01:31:38 Trace: CFtpControlSocket::SendNextCommand() 01:31:38 Trace: CFtpControlSocket::ChangeDirSend() 01:31:38 Command: CWD / 01:31:38 Trace: CTlsSocket::OnRead() 01:31:38 Trace: CFtpControlSocket::OnReceive() 01:31:38 Response: 250 Directory successfully changed. 01:31:38 Trace: CFtpControlSocket::ResetOperation(0) 01:31:38 Trace: CControlSocket::ResetOperation(0) 01:31:38 Trace: CFtpControlSocket::ParseSubcommandResult(0) 01:31:38 Trace: FileTransferSubcommandResult() 01:31:39 Trace: CFtpControlSocket::SendNextCommand() 01:31:39 Trace: FileTransferSend() 01:31:39 Trace: CFtpControlSocket::SendNextCommand() 01:31:39 Trace: CFtpControlSocket::TransferSend() 01:31:39 Trace: state = 1 01:31:39 Command: TYPE I 01:31:39 Trace: CTlsSocket::OnRead() 01:31:39 Trace: CFtpControlSocket::OnReceive() 01:31:39 Response: 200 Switching to Binary mode. 01:31:39 Trace: CFtpControlSocket::TransferParseResponse() 01:31:39 Trace: code = 2 01:31:39 Trace: state = 1 01:31:39 Trace: CFtpControlSocket::SendNextCommand() 01:31:39 Trace: CFtpControlSocket::TransferSend() 01:31:39 Trace: state = 2 01:31:39 Command: PASV 01:31:39 Trace: CTlsSocket::OnRead() 01:31:39 Trace: CFtpControlSocket::OnReceive() 01:31:39 Response: 227 Entering Passive Mode (xxxxxxxxxxxxx,38,6). 01:31:39 Trace: CFtpControlSocket::TransferParseResponse() 01:31:39 Trace: code = 2 01:31:39 Trace: state = 2 01:31:39 Trace: CFtpControlSocket::SendNextCommand() 01:31:39 Trace: CFtpControlSocket::TransferSend() 01:31:39 Trace: state = 4 01:31:39 Command: STOR gparted-live-0.9.0-7.iso 01:31:39 Trace: CTransferSocket::OnConnect 01:31:39 Trace: CTlsSocket::Handshake() 01:31:39 Trace: CTlsSocket::ContinueHandshake() 01:31:39 Trace: CTlsSocket::OnSend() 01:31:39 Trace: CTlsSocket::OnSend() 01:31:39 Trace: CTlsSocket::OnRead() 01:31:39 Trace: CFtpControlSocket::OnReceive() 01:31:39 Response: 150 Ok to send data. 01:31:39 Trace: CFtpControlSocket::TransferParseResponse() 01:31:39 Trace: code = 1 01:31:39 Trace: state = 4 01:31:39 Trace: CFtpControlSocket::SendNextCommand() 01:31:39 Trace: CFtpControlSocket::TransferSend() 01:31:39 Trace: state = 5 01:31:39 Trace: CTlsSocket::OnRead() 01:31:39 Trace: CTlsSocket::ContinueHandshake() 01:31:39 Trace: CTlsSocket::OnRead() 01:31:39 Trace: CTlsSocket::ContinueHandshake() 01:31:39 Trace: CTlsSocket::OnRead() 01:31:39 Trace: CTlsSocket::ContinueHandshake() 01:31:39 Trace: TLS Handshake successful 01:31:39 Trace: Cipher: AES-128-CBC, MAC: SHA1 01:31:39 Trace: CTransferSocket::OnConnect 01:31:39 Trace: First EAGAIN in CTransferSocket::OnSend() 01:32:00 Error: Connection timed out 01:32:00 Trace: CControlSocket::DoClose(2050) 01:32:00 Trace: CFtpControlSocket::ResetOperation(2114) 01:32:00 Trace: CControlSocket::ResetOperation(2114) 01:32:00 Trace: CFtpControlSocket::ResetOperation(2114) 01:32:00 Trace: CControlSocket::ResetOperation(2114) 01:32:00 Error: File transfer failed after transferring 180224 bytes in 21 seconds
Now, the important fact is that I have disabled the "speed limit" feature, thus reatelimit.cpp is not in action. The error EAGAIN was observed in file backend.cpp:43 (function
int CSocketBackend::Write(const void *buffer, unsigned int len, int& error))
The source of the error is tlssocket.cpp:621 (function CTlsSocket::Write(const void *buffer, unsigned int len, int& error)), where one gets GNUTLS_E_AGAIN error. In return, this function set m_lastWriteFailed flag as true (which is important, see below).
I think that until now, it still behaves correctly and I didn't dig into why I got GNUTLS_E_AGAIN error every 180,224 bytes.
The problem is that nobody tries to send the data again! First, in function CTransferSocket::OnSend() in transfersocket.cpp:431, the only action upon EAGAIN error is practically to print the message about the first EAGAIN error and thats it. So this is why we get connection timeout errors.
Furthermore, if you patch the CTransferSocket::OnSend() function to not give up, it will fail in tlssocket.cpp:593, because it is checking whether the m_lastWriteFailed flag is true or not. If true, it just returns EAGAIN ending up in an infinite loop. When I deleted this (useless?) check, the transfer started to work just fine (getting GNU_TLS error regularly, but recovering from it).
I did not try to fully understand the whole error checking/recovering code so some of my thoughts may be wrong, but this should point somebody more familiar with the code to the right place.
Regards
Jiri Horky
comment:5 by , 12 years ago
Hi again,
some more information. As described above, the problem is that filezilla can not recover from GNUTLS_E_AGAIN error.
Apparently, the GNUTLS error only gets triggered in some version of gnutls library. If I try older filezilla (3.3.5.1) with gnutls < 2.12.0 (2.11.7 see note below), it behaves correctly, the same version with gnutls >= 2.12.0. fails as described in comment above.
PS: filezilla 3.5.3 with older gnutls library (2.8.6) fails even to connect because of "gnutls error -50."
Please note gnutls-2.12.0 downloaded from official homepage says about itself it is 2.11.7.
comment:6 by , 12 years ago
| Status: | new → moreinfo |
|---|
For GnuTLS error -12, please have a look at #7873.
Beside that, do you still have the mentioned problem in current version of FileZilla?
comment:7 by , 12 years ago
| Status: | moreinfo → new |
|---|
Hi,
the problem seems to be fixed in 3.6.0.2 (and I also tried 3.6.0.1 which is affected).
Jiri Horky
comment:8 by , 12 years ago
| Resolution: | → fixed |
|---|---|
| Status: | new → closed |
Note:
See TracTickets
for help on using tickets.
With v3.5.0, we also hit same issue on Pardus GNU/Linux. I also tested with v3.5.1 rc but the issue still exists. Do you have any patch/plan for this issue?