[FTPSERVER-236] DefaultFtpHandler catches WriteToCloseSessionException on failure to deliver "221 Goodbye", logs it as an error

• Type: Improvement
• Status: Closed
• Priority: Minor
• Resolution: Fixed
• Affects Version/s: 1.0.0-M3
• Fix Version/s: 1.0.0-RC1
• Component/s: Server
• Environment: Linux, probably Windows XP. FTP clients are likely EnterpriseDT's, but I don't think it's restricted to them.
• Assignee: Niklas Therning
• Reporter: Larry West
• Created: 09/Dec/08 01:55
• Updated: 11/Oct/13 18:04
• Resolved: 09/Dec/08 21:02

Description

DefaultFtpHandler.exceptionCaught() [via FtpHandlerAdapter.exceptionCaught(), via DefaultIoFilterChain.exceptionCaught() ad infinitum] logs an error when the client closes the session before the server can send the "221 Goodbye." message.
LOG.error("Exception caught, closing session", cause);
[which is also unfortunate wording in that it sounds like the session is being closed due to the exception].

In my reading of the FTP protocol, this isn't really an error; certainly not near the level of other problems.

I would like to suggest that if the only message that can't be delivered to a closing session is "221 Goodbye" that this be logged as a Warning. I'm not sure where the best place to store this state is, so I'll spare you a bogus fix, but it should be on the order of 5-10 lines of code.

However, here's a stack trace for reference:
ERROR [apache.ftpserver.DefaultFtpHandler] - Exception caught, closing session
org.apache.mina.core.write.WriteToClosedSessionException
at org.apache.mina.core.polling.AbstractPollingIoProcessor.clearWriteRequestQueue(AbstractPollingIoProcessor.java:521)
at org.apache.mina.core.polling.AbstractPollingIoProcessor.removeNow(AbstractPollingIoProcessor.java:484)
at org.apache.mina.core.polling.AbstractPollingIoProcessor.remove(AbstractPollingIoProcessor.java:455)
at org.apache.mina.core.polling.AbstractPollingIoProcessor.access$600(AbstractPollingIoProcessor.java:58)
at org.apache.mina.core.polling.AbstractPollingIoProcessor$Worker.run(AbstractPollingIoProcessor.java:862)
at org.apache.mina.util.NamePreservingRunnable.run(NamePreservingRunnable.java:51)
at java.util.concurrent.ThreadPoolExecutor$Worker.runTask(ThreadPoolExecutor.java:650)
at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:675)
at java.lang.Thread.run(Thread.java:595)

It's also inconvenient that DefaultFtpHandler.exceptionCaught is not logging the failedRequests List<> that AbstractPollingIoProcessor.clearWriteRequestQueue() so lovingly collects and passes in the WriteToClosedSessionException object.