Critical Description
After my ftp client successfully uploads a file, it sends a QUIT request. This QUIT request doesn't always appear to be logged by the FtpServer which results in the connection idling and the FtpServer subsequently closes the connection. We experience this issue often when uploading large files (2+GB) or multiple medium size files (~1 GB). When the QUIT is received before the FtpServer issues a 226 transfer complete message, the server sends a 226 transfer complete message , the a 221 goodbye message before closing the connection. When the QUIT is received after the FtpServer issues a 226 transfer complete message, sometimes the QUIT is processed on the existing thread and sometimes it is processed on a new thread. In either case, the server sends a 221 goodbye message and closed the connection. This leads me to believe that a QUIT message could be sent to the server in the time between when the first thread is being closed and the second thread is being opened. Below are logs from my FtpServer that illustrate all of these scenarios.
This issue occurs very frequently and is resulting in the user believing their uploads failed.
QUIT received before 226 transfer complete sent:
2009-11-04 14:32:31,936 [pool-4-thread-8] INFO org.apache.ftpserver.command.impl.STOR - File uploaded /1024/2009/11/02/7558_7W5oJqfN_event.wmv
2009-11-04 14:32:31,937 [pool-4-thread-8] INFO org.apache.ftpserver.listener.nio.FtpLoggingFilter - SENT: 150 File status okay; about to open data connection.
2009-11-04 14:32:32,104 [pool-4-thread-8] INFO org.apache.ftpserver.listener.nio.FtpLoggingFilter - RECEIVED: QUIT
2009-11-04 14:32:32,104 [pool-4-thread-8] INFO org.apache.ftpserver.listener.nio.FtpLoggingFilter - SENT: 226 Transfer complete.
2009-11-04 14:32:32,105 [pool-4-thread-8] INFO org.apache.ftpserver.listener.nio.FtpLoggingFilter - SENT: 221 Goodbye.
2009-11-04 14:32:32,105 [pool-4-thread-8] INFO org.apache.ftpserver.listener.nio.FtpLoggingFilter - CLOSED
QUIT received after 226 transfer complete sent on the same thread:
2009-11-03 19:25:23,958 [pool-4-thread-697] INFO org.apache.ftpserver.command.impl.STOR - File uploaded /1017/2009/10/09/7235_xVJpQ8tT_event.wmv
2009-11-03 19:25:23,958 [pool-4-thread-697] INFO org.apache.ftpserver.listener.nio.FtpLoggingFilter - SENT: 150 File status okay; about to open data connection.
2009-11-03 19:25:23,968 [pool-4-thread-697] INFO org.apache.ftpserver.listener.nio.FtpLoggingFilter - SENT: 226 Transfer complete.
2009-11-03 19:25:23,991 [pool-4-thread-697] INFO org.apache.ftpserver.listener.nio.FtpLoggingFilter - RECEIVED: QUIT
2009-11-03 19:25:23,992 [pool-4-thread-697] INFO org.apache.ftpserver.listener.nio.FtpLoggingFilter - SENT: 221 Goodbye.
2009-11-03 19:25:23,992 [pool-4-thread-697] INFO org.apache.ftpserver.listener.nio.FtpLoggingFilter - CLOSED
QUIT received after the 226 transfer complete sent on a new thread:
2009-11-03 04:43:16,551 [pool-4-thread-662] INFO org.apache.ftpserver.command.impl.STOR - File uploaded /1030/2009/11/02/7580_GxDwum7M_event.wmv
2009-11-03 04:43:16,552 [pool-4-thread-662] INFO org.apache.ftpserver.listener.nio.FtpLoggingFilter - SENT: 150 File status okay; about to open data connection.
2009-11-03 04:43:16,552 [pool-4-thread-662] INFO org.apache.ftpserver.listener.nio.FtpLoggingFilter - SENT: 226 Transfer complete.
2009-11-03 04:43:16,595 [pool-4-thread-667] INFO org.apache.ftpserver.listener.nio.FtpLoggingFilter - RECEIVED: QUIT
2009-11-03 04:43:16,598 [pool-4-thread-667] INFO org.apache.ftpserver.listener.nio.FtpLoggingFilter - SENT: 221 Goodbye.
2009-11-03 04:43:16,598 [pool-4-thread-667] INFO org.apache.ftpserver.listener.nio.FtpLoggingFilter - CLOSED
QUIT NOT received because the FtpServer is between threads:
2009-11-04 02:05:18,328 [pool-4-thread-16] INFO org.apache.ftpserver.command.impl.STOR - File uploaded /1051/2008/11/15/7400_NHftLRzu_event.mp4
2009-11-04 02:05:18,329 [pool-4-thread-16] INFO org.apache.ftpserver.listener.nio.FtpLoggingFilter - SENT: 150 File status okay; about to open data connection.
2009-11-04 02:05:18,397 [pool-4-thread-16] INFO org.apache.ftpserver.listener.nio.FtpLoggingFilter - SENT: 226 Transfer complete.
2009-11-04 02:08:18,394 [pool-4-thread-106] INFO org.apache.ftpserver.listener.nio.FtpLoggingFilter - IDLE
2009-11-04 02:08:18,394 [pool-4-thread-106] INFO org.apache.ftpserver.impl.DefaultFtpHandler - Session idle, closing
2009-11-04 02:08:18,395 [pool-4-thread-106] INFO org.apache.ftpserver.listener.nio.FtpLoggingFilter - CLOSED