Commands Dropped After Successful File Upload
---------------------------------------------
Key: FTPSERVER-339
URL: https://issues.apache.org/jira/browse/FTPSERVER-339
Project: FtpServer
Issue Type: Bug
Affects Versions: 1.0.3
Reporter: Nick Padgett
Priority: Critical
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
--
This message is automatically generated by JIRA.
-
You can reply to this email to add a comment to the issue online.
