I found the real issue here. I was misguided by Filezilla's dual connection
behavior where it always spawns a new connection for a data transfer and
leaved the original listing connection open. It's the listing connection
that times out, but the transfer connection is active and my assumption of
the root cause was wrong.

 

My real problem is the issue reported in various other cases like:

http://mail-archives.apache.org/mod_mbox/mina-dev/201102.mbox/%3C987378340.1
0467.1297432017841.javamail.tom...@hel.zones.apache.org%3E

http://old.nabble.com/-jira--Created:-%28FTPSERVER-295%29-Connection-reset-b
y-peer,-help-td23269194.html

 

I can reproduce this in filezilla, by setting a slow upload speed 1kbps,
causing the upload to go on for more than an hour. Filezilla transfers the
whole file and then fails with 

 

Error:                             Connection timed out

Error:                             File transfer failed after transferring
2,392,064 bytes in 2551 seconds

 

 

FTP Logs:

 

INFO 2011-12-10 15:48:54,134 pool-3-thread-54 D- U- S-
org.apache.ftpserver.command.impl.STOR - File uploaded
/Private/sshetty/9.doc

INFO 2011-12-10 15:48:54,138 pool-3-thread-54 D- U- S-
org.apache.ftpserver.listener.nio.FtpLoggingFilter - SENT: 150 File status
okay; about to open data connection.^M

 

INFO 2011-12-10 15:48:54,138 pool-3-thread-54 D- U- S-
org.apache.ftpserver.listener.nio.FtpLoggingFilter - SENT: 226 Transfer
complete.^M

 

WARN 2011-12-10 15:48:54,138 pool-3-thread-54 D- U- S-
org.apache.ftpserver.listener.nio.FtpLoggingFilter - EXCEPTION :

java.io.IOException: Connection reset by peer

    at sun.nio.ch.FileDispatcher.read0(Native Method)

    at sun.nio.ch.SocketDispatcher.read(SocketDispatcher.java:21)

    at sun.nio.ch.IOUtil.readIntoNativeBuffer(IOUtil.java:233)

    at sun.nio.ch.IOUtil.read(IOUtil.java:206)

    at sun.nio.ch.SocketChannelImpl.read(SocketChannelImpl.java:236)

    at
org.apache.mina.transport.socket.nio.NioProcessor.read(NioProcessor.java:214
)

    at
org.apache.mina.transport.socket.nio.NioProcessor.read(NioProcessor.java:42)

    at
org.apache.mina.core.polling.AbstractPollingIoProcessor.read(AbstractPolling
IoProcessor.java:673)

    at
org.apache.mina.core.polling.AbstractPollingIoProcessor.process(AbstractPoll
ingIoProcessor.java:646)

    at
org.apache.mina.core.polling.AbstractPollingIoProcessor.process(AbstractPoll
ingIoProcessor.java:635)

    at
org.apache.mina.core.polling.AbstractPollingIoProcessor.access$400(AbstractP
ollingIoProcessor.java:67)

    at
org.apache.mina.core.polling.AbstractPollingIoProcessor$Processor.run(Abstra
ctPollingIoProcessor.java:1079)

    at
org.apache.mina.util.NamePreservingRunnable.run(NamePreservingRunnable.java:
64)

    at
java.util.concurrent.ThreadPoolExecutor$Worker.runTask(ThreadPoolExecutor.ja
va:886)

    at
java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:9
08)

    at java.lang.Thread.run(Thread.java:619)

ERROR 2011-12-10 15:48:54,139 pool-3-thread-54 D- U- S-
org.apache.ftpserver.impl.DefaultFtpHandler - Exception caught, closing
session

java.io.IOException: Connection reset by peer

    at sun.nio.ch.FileDispatcher.read0(Native Method)

    at sun.nio.ch.SocketDispatcher.read(SocketDispatcher.java:21)

    at sun.nio.ch.IOUtil.readIntoNativeBuffer(IOUtil.java:233)

    at sun.nio.ch.IOUtil.read(IOUtil.java:206)

    at sun.nio.ch.SocketChannelImpl.read(SocketChannelImpl.java:236)

    at
org.apache.mina.transport.socket.nio.NioProcessor.read(NioProcessor.java:214
)

    at
org.apache.mina.transport.socket.nio.NioProcessor.read(NioProcessor.java:42)

    at
org.apache.mina.core.polling.AbstractPollingIoProcessor.read(AbstractPolling
IoProcessor.java:673)

    at
org.apache.mina.core.polling.AbstractPollingIoProcessor.process(AbstractPoll
ingIoProcessor.java:646)

    at
org.apache.mina.core.polling.AbstractPollingIoProcessor.process(AbstractPoll
ingIoProcessor.java:635)

    at
org.apache.mina.core.polling.AbstractPollingIoProcessor.access$400(AbstractP
ollingIoProcessor.java:67)

    at
org.apache.mina.core.polling.AbstractPollingIoProcessor$Processor.run(Abstra
ctPollingIoProcessor.java:1079)

    at
org.apache.mina.util.NamePreservingRunnable.run(NamePreservingRunnable.java:
64)

    at
java.util.concurrent.ThreadPoolExecutor$Worker.runTask(ThreadPoolExecutor.ja
va:886)

    at
java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:9
08)

    at java.lang.Thread.run(Thread.java:619)

INFO 2011-12-10 15:48:54,139 pool-3-thread-54 D- U- S-
org.apache.ftpserver.listener.nio.FtpLoggingFilter - CLOSED

 

 

 

 

 

From: Sachin Shetty [mailto:sshe...@egnyte.com] 
Sent: Monday, December 05, 2011 4:04 PM
To: 'Sachin Shetty'; 'ftpserver-users@mina.apache.org'
Subject: RE: Control connection closing on idle timeout even when data
transfer is going on

 

anybody?

 

this seems like a valid bug..

 

From: Sachin Shetty [mailto:sshe...@egnyte.com] 
Sent: Sunday, December 04, 2011 1:56 PM
To: 'ftpserver-users@mina.apache.org'
Subject: Control connection closing on idle timeout even when data transfer
is going on

 

We have configured our ftp servers to set idle timeout to 15 minutes. When
we are transferring huge files where it takes more than 15 minutes, the
control connection is closed by the server, while the data connection
continues as usual.

 

I am not sure how the idle time out kicks in here, because even though there
is no activity on the control connection, the data connection is active. 

 

Anybody faced same problem?

 

Thanks

Sachin

Reply via email to