Take the 2-minute tour ×
Server Fault is a question and answer site for professional system and network administrators. It's 100% free, no registration required.

For very few customers, we are having problem in uploading any file greater then 64 kb. The server OS is FreeBSD running vsftpd over ssl. When we move these customers to a ftps server hosted on windows, they do not have any problem. The client system is running windows OS.

We have analyzed wireshark / tcpdump trace at client and server and our analysis is:

Once the client finishes uploading the file, it sends a FIN but the server takes time to send back the ACK/FIN by which time the client restarts the tcp handshake and begins uploading the file again. We have tried turning off tcp delayed ack, tcp checksum, changed recvBuf on the server. None of these setting make any difference.

Additional details: FreeBSD 9.0 release vsFtpd 3.0.0

vsFtpd.log

    Fri Jun 15 12:22:16 2012 [pid 1092] CONNECT: Client "xx.xxx.xx.xx"
Fri Jun 15 12:22:16 2012 [pid 1092] DEBUG: Client "xx.xxx.xx.xx", "SSL version: TLSv1/SSLv3, SSL cipher: AES128-SHA, not reused, no cert"
Fri Jun 15 12:22:16 2012 [pid 1092] FTP response: Client "xx.xxx.xx.xx", "220 (vsFTPd 3.0.0)"
Fri Jun 15 12:22:16 2012 [pid 1092] FTP command: Client "xx.xxx.xx.xx", "USER ftpuser"
Fri Jun 15 12:22:16 2012 [pid 1092] [ftpuser] FTP response: Client "xx.xxx.xx.xx", "331 Please specify the password."
Fri Jun 15 12:22:16 2012 [pid 1092] [ftpuser] FTP command: Client "xx.xxx.xx.xx", "PASS <password>"
Fri Jun 15 12:22:16 2012 [pid 1091] [ftpuser] OK LOGIN: Client "xx.xxx.xx.xx"
Fri Jun 15 12:22:16 2012 [pid 1093] [ftpuser] FTP response: Client "xx.xxx.xx.xx", "230 Login successful."
Fri Jun 15 12:22:16 2012 [pid 1093] [ftpuser] FTP command: Client "xx.xxx.xx.xx", "OPTS UTF8 ON"
Fri Jun 15 12:22:16 2012 [pid 1093] [ftpuser] FTP response: Client "xx.xxx.xx.xx", "200 Always in UTF8 mode."
Fri Jun 15 12:22:16 2012 [pid 1093] [ftpuser] FTP command: Client "xx.xxx.xx.xx", "PBSZ 0"
Fri Jun 15 12:22:16 2012 [pid 1093] [ftpuser] FTP response: Client "xx.xxx.xx.xx", "200 PBSZ set to 0."
Fri Jun 15 12:22:16 2012 [pid 1093] [ftpuser] FTP command: Client "xx.xxx.xx.xx", "PROT P"
Fri Jun 15 12:22:16 2012 [pid 1093] [ftpuser] FTP response: Client "xx.xxx.xx.xx", "200 PROT now Private."
Fri Jun 15 12:22:16 2012 [pid 1093] [ftpuser] FTP command: Client "xx.xxx.xx.xx", "CWD /usr/home/ftpuser"
Fri Jun 15 12:22:16 2012 [pid 1093] [ftpuser] FTP response: Client "xx.xxx.xx.xx", "250 Directory successfully changed."
Fri Jun 15 12:22:16 2012 [pid 1093] [ftpuser] FTP command: Client "xx.xxx.xx.xx", "TYPE I"
Fri Jun 15 12:22:16 2012 [pid 1093] [ftpuser] FTP response: Client "xx.xxx.xx.xx", "200 Switching to Binary mode."
Fri Jun 15 12:22:16 2012 [pid 1093] [ftpuser] FTP command: Client "xx.xxx.xx.xx", "PASV"
Fri Jun 15 12:22:16 2012 [pid 1093] [ftpuser] FTP response: Client "xx.xxx.xx.xx", "227 Entering Passive Mode (xx,xxx,xxx,xx,xxx,xx)."
Fri Jun 15 12:22:16 2012 [pid 1093] [ftpuser] FTP command: Client "xx.xxx.xx.xx", "STOR testfile.TIF"
Fri Jun 15 12:22:16 2012 [pid 1093] [ftpuser] FTP response: Client "xx.xxx.xx.xx", "150 Ok to send data."
Fri Jun 15 12:22:16 2012 [pid 1092] [ftpuser] DEBUG: Client "xx.xxx.xx.xx", "SSL version: TLSv1/SSLv3, SSL cipher: AES128-SHA, reused, no cert"
Fri Jun 15 12:22:17 2012 [pid 1092] [ftpuser] DEBUG: Client "xx.xxx.xx.xx", "SSL shutdown state is: SSL_RECEIVED_SHUTDOWN"
Fri Jun 15 12:22:17 2012 [pid 1092] [ftpuser] DEBUG: Client "xx.xxx.xx.xx", "SSL shutdown state is: 3"
Fri Jun 15 12:22:37 2012 [pid 1096] CONNECT: Client "xx.xxx.xx.xx"
Fri Jun 15 12:22:37 2012 [pid 1096] DEBUG: Client "xx.xxx.xx.xx", "SSL version: TLSv1/SSLv3, SSL cipher: AES128-SHA, not reused, no cert"
Fri Jun 15 12:22:37 2012 [pid 1096] FTP response: Client "xx.xxx.xx.xx", "220 (vsFTPd 3.0.0)"
Fri Jun 15 12:22:37 2012 [pid 1096] FTP command: Client "xx.xxx.xx.xx", "USER ftpuser"
Fri Jun 15 12:22:37 2012 [pid 1096] [ftpuser] FTP response: Client "xx.xxx.xx.xx", "331 Please specify the password."
Fri Jun 15 12:22:37 2012 [pid 1096] [ftpuser] FTP command: Client "xx.xxx.xx.xx", "PASS <password>"
Fri Jun 15 12:22:37 2012 [pid 1095] [ftpuser] OK LOGIN: Client "xx.xxx.xx.xx"
Fri Jun 15 12:22:37 2012 [pid 1097] [ftpuser] FTP response: Client "xx.xxx.xx.xx", "230 Login successful."
Fri Jun 15 12:22:37 2012 [pid 1097] [ftpuser] FTP command: Client "xx.xxx.xx.xx", "OPTS UTF8 ON"
Fri Jun 15 12:22:37 2012 [pid 1097] [ftpuser] FTP response: Client "xx.xxx.xx.xx", "200 Always in UTF8 mode."
Fri Jun 15 12:22:37 2012 [pid 1097] [ftpuser] FTP command: Client "xx.xxx.xx.xx", "PBSZ 0"
Fri Jun 15 12:22:37 2012 [pid 1097] [ftpuser] FTP response: Client "xx.xxx.xx.xx", "200 PBSZ set to 0."
Fri Jun 15 12:22:37 2012 [pid 1097] [ftpuser] FTP command: Client "xx.xxx.xx.xx", "PROT P"
Fri Jun 15 12:22:37 2012 [pid 1097] [ftpuser] FTP response: Client "xx.xxx.xx.xx", "200 PROT now Private."
Fri Jun 15 12:22:37 2012 [pid 1097] [ftpuser] FTP command: Client "xx.xxx.xx.xx", "CWD /usr/home/ftpuser"
Fri Jun 15 12:22:37 2012 [pid 1097] [ftpuser] FTP response: Client "xx.xxx.xx.xx", "250 Directory successfully changed."
Fri Jun 15 12:22:38 2012 [pid 1097] [ftpuser] FTP command: Client "xx.xxx.xx.xx", "TYPE I"
Fri Jun 15 12:22:38 2012 [pid 1097] [ftpuser] FTP response: Client "xx.xxx.xx.xx", "200 Switching to Binary mode."
Fri Jun 15 12:22:38 2012 [pid 1097] [ftpuser] FTP command: Client "xx.xxx.xx.xx", "PASV"
Fri Jun 15 12:22:38 2012 [pid 1097] [ftpuser] FTP response: Client "xx.xxx.xx.xx", "227 Entering Passive Mode (xx,xxx,xxx,xx,xxx,xxx)."
Fri Jun 15 12:22:38 2012 [pid 1097] [ftpuser] FTP command: Client "xx.xxx.xx.xx", "LIST"
Fri Jun 15 12:22:38 2012 [pid 1097] [ftpuser] FTP response: Client "xx.xxx.xx.xx", "150 Here comes the directory listing."
Fri Jun 15 12:22:38 2012 [pid 1096] [ftpuser] DEBUG: Client "xx.xxx.xx.xx", "SSL version: TLSv1/SSLv3, SSL cipher: AES128-SHA, reused, no cert"
Fri Jun 15 12:22:38 2012 [pid 1096] [ftpuser] DEBUG: Client "xx.xxx.xx.xx", "SSL shutdown state is: NONE"
Fri Jun 15 12:22:38 2012 [pid 1096] [ftpuser] DEBUG: Client "xx.xxx.xx.xx", "SSL shutdown state is: SSL_SENT_SHUTDOWN"
Fri Jun 15 12:22:38 2012 [pid 1096] [ftpuser] DEBUG: Client "xx.xxx.xx.xx", "SSL shutdown state is: 3"
Fri Jun 15 12:22:38 2012 [pid 1097] [ftpuser] FTP response: Client "xx.xxx.xx.xx", "226 Directory send OK."
Fri Jun 15 12:24:22 2012 [pid 1096] [ftpuser] DEBUG: Client "xx.xxx.xx.xx", "Connection terminated without SSL shutdown - buggy client?"
Fri Jun 15 12:27:04 2012 [pid 1089] [ftpuser] DEBUG: Client "xx.xxx.xx.xx", "Connection terminated without SSL shutdown - buggy client?"
Fri Jun 15 12:27:04 2012 [pid 1090] [ftpuser] FTP response: Client "xx.xxx.xx.xx", "421 Timeout."
Fri Jun 15 12:27:17 2012 [pid 1093] [ftpuser] OK UPLOAD: Client "xx.xxx.xx.xx", "/usr/home/ftpuser/testfile.TIF", 109322 bytes, 0.35Kbyte/sec
Fri Jun 15 12:27:17 2012 [pid 1093] [ftpuser] FTP response: Client "xx.xxx.xx.xx", "226 Transfer complete."
Fri Jun 15 12:27:17 2012 [pid 1092] [ftpuser] DEBUG: Client "xx.xxx.xx.xx", "Connection terminated without SSL shutdown - buggy client?"

Thank you Bharat

share|improve this question
    
FreeBSD/vsftpd versions would be helpful. Debug logs from vsftpd too. Also first thing to try is to reset all custom sysctls to their default values and if it helps do a bisect. –  SaveTheRbtz Jun 17 '12 at 3:06
    
@SaveTheRbtz: edited the question with requested additional info. –  bharat Jun 18 '12 at 13:31
    
MTU/MSS troubles? Are those troublesome customers behind some kind of PPPoE/PPTP link encapsulation? I suppose next step is to analyze tcpdumps from BOTH sides. –  SaveTheRbtz Jun 18 '12 at 22:02
    
I had forgotten about MTU - thanks for reminding about it. I will test with different MTU sizes to see if it makes a difference. Will be able to test it next week only. The client is connecting over the internet -ftps. –  bharat Jun 22 '12 at 17:04
add comment

Your Answer

 
discard

By posting your answer, you agree to the privacy policy and terms of service.

Browse other questions tagged or ask your own question.