You are viewing a plain text version of this content. The canonical link for it is here.
Posted to dev@mina.apache.org by Michael Benovich <mi...@hostedftp.com> on 2015/06/30 17:52:59 UTC

ftpserver warnings - cannot find an available passive port

Hi,

We have been running ftpserver 1.0.6 in a production environment for
several years. Last week we encountered an issue that we have not
encountered before.

We began to see intermittent failures when trying to enter passive mode. A
review of our logs showed multiple errors (sample trace below) with the
warning "Failed to open passive data connection... (Cannot find an
available passive port)". Our configuration includes a passive port range
of 800 ports, and based on our internal metrics and "netstat" output, we do
not believe we were using anywhere near this many ports at the time of
these errors. Restarting our java application resolved the issue.

Are there any known conditions where ftpserver could be consuming a larger
number of passive ports than expected? If so, what is the recommended
approach to detect and resolve?


Many thanks,
Mike


Detailed error trace:

Jun 25, 2015 12:07:03 PM org.apache.ftpserver.command.impl.PASV execute
WARNING: Failed to open passive data connection
org.apache.ftpserver.DataConnectionException: Cannot find an available
passive port.
        at
org.apache.ftpserver.impl.IODataConnectionFactory.initPassiveDataConnection(IODataConnectionFactory.java:170)
        at org.apache.ftpserver.command.impl.PASV.execute(PASV.java:73)
        at
org.apache.ftpserver.impl.DefaultFtpHandler.messageReceived(DefaultFtpHandler.java:210)
        at
org.apache.ftpserver.listener.nio.FtpHandlerAdapter.messageReceived(FtpHandlerAdapter.java:61)
        at
org.apache.mina.core.filterchain.DefaultIoFilterChain$TailFilter.messageReceived(DefaultIoFilterChain.java:716)
        at
org.apache.mina.core.filterchain.DefaultIoFilterChain.callNextMessageReceived(DefaultIoFilterChain.java:434)
        at
org.apache.mina.core.filterchain.DefaultIoFilterChain.access$1200(DefaultIoFilterChain.java:46)
        at
org.apache.mina.core.filterchain.DefaultIoFilterChain$EntryImpl$1.messageReceived(DefaultIoFilterChain.java:796)
        at
org.apache.ftpserver.listener.nio.FtpLoggingFilter.messageReceived(FtpLoggingFilter.java:85)
        at
org.apache.mina.core.filterchain.DefaultIoFilterChain.callNextMessageReceived(DefaultIoFilterChain.java:434)
        at
org.apache.mina.core.filterchain.DefaultIoFilterChain.access$1200(DefaultIoFilterChain.java:46)
        at
org.apache.mina.core.filterchain.DefaultIoFilterChain$EntryImpl$1.messageReceived(DefaultIoFilterChain.java:796)
        at
org.apache.mina.core.filterchain.IoFilterEvent.fire(IoFilterEvent.java:75)
        at
org.apache.mina.filter.logging.MdcInjectionFilter.filter(MdcInjectionFilter.java:136)
        at
org.apache.mina.filter.util.CommonEventFilter.messageReceived(CommonEventFilter.java:70)
        at
org.apache.mina.core.filterchain.DefaultIoFilterChain.callNextMessageReceived(DefaultIoFilterChain.java:434)
        at
org.apache.mina.core.filterchain.DefaultIoFilterChain.access$1200(DefaultIoFilterChain.java:46)
        at
org.apache.mina.core.filterchain.DefaultIoFilterChain$EntryImpl$1.messageReceived(DefaultIoFilterChain.java:796)
        at
org.apache.mina.filter.codec.ProtocolCodecFilter$ProtocolDecoderOutputImpl.flush(ProtocolCodecFilter.java:427)
        at
org.apache.mina.filter.codec.ProtocolCodecFilter.messageReceived(ProtocolCodecFilter.java:245)
        at
org.apache.mina.core.filterchain.DefaultIoFilterChain.callNextMessageReceived(DefaultIoFilterChain.java:434)
        at
org.apache.mina.core.filterchain.DefaultIoFilterChain.access$1200(DefaultIoFilterChain.java:46)
        at
org.apache.mina.core.filterchain.DefaultIoFilterChain$EntryImpl$1.messageReceived(DefaultIoFilterChain.java:796)
        at
org.apache.mina.core.filterchain.IoFilterEvent.fire(IoFilterEvent.java:75)
        at org.apache.mina.core.session.IoEvent.run(IoEvent.java:63)
        at
org.apache.mina.filter.executor.OrderedThreadPoolExecutor$Worker.runTask(OrderedThreadPoolExecutor.java:780)
        at
org.apache.mina.filter.executor.OrderedThreadPoolExecutor$Worker.runTasks(OrderedThreadPoolExecutor.java:772)
        at
org.apache.mina.filter.executor.OrderedThreadPoolExecutor$Worker.run(OrderedThreadPoolExecutor.java:714)
        at java.lang.Thread.run(Thread.java:722)

Jun 25, 2015 12:07:03 PM org.apache.mina.filter.logging.LoggingFilter log
INFO: SENT: 425 Can't open passive connection.

Re: ftpserver warnings - cannot find an available passive port

Posted by Emmanuel Lécharny <el...@gmail.com>.
Le 30/06/15 17:52, Michael Benovich a écrit :
> Hi,
>
> We have been running ftpserver 1.0.6 in a production environment for
> several years. Last week we encountered an issue that we have not
> encountered before.
Hmmm.
>
> We began to see intermittent failures when trying to enter passive mode. A
> review of our logs showed multiple errors (sample trace below) with the
> warning "Failed to open passive data connection... (Cannot find an
> available passive port)". Our configuration includes a passive port range
> of 800 ports, and based on our internal metrics and "netstat" output, we do
> not believe we were using anywhere near this many ports at the time of
> these errors. Restarting our java application resolved the issue.

Have you changed the Java version you are using ? Or have you upgraded
your OS ? Or have you added some firewalls ?


Re: ftpserver warnings - cannot find an available passive port

Posted by David Latorre <dv...@gmail.com>.
Good day,

 I agree with Emmanuel suggestions on this issue. Still, if you cannot
resolve this issue, I think Niklas implemented in the Trunk version  some
changes on the way passive ports are allocated, so you might want to try
that version.



2015-06-30 17:52 GMT+02:00 Michael Benovich <mi...@hostedftp.com>:

> Hi,
>
> We have been running ftpserver 1.0.6 in a production environment for
> several years. Last week we encountered an issue that we have not
> encountered before.
>
> We began to see intermittent failures when trying to enter passive mode. A
> review of our logs showed multiple errors (sample trace below) with the
> warning "Failed to open passive data connection... (Cannot find an
> available passive port)". Our configuration includes a passive port range
> of 800 ports, and based on our internal metrics and "netstat" output, we do
> not believe we were using anywhere near this many ports at the time of
> these errors. Restarting our java application resolved the issue.
>
> Are there any known conditions where ftpserver could be consuming a larger
> number of passive ports than expected? If so, what is the recommended
> approach to detect and resolve?
>
>
> Many thanks,
> Mike
>
>
> Detailed error trace:
>
> Jun 25, 2015 12:07:03 PM org.apache.ftpserver.command.impl.PASV execute
> WARNING: Failed to open passive data connection
> org.apache.ftpserver.DataConnectionException: Cannot find an available
> passive port.
>         at
>
> org.apache.ftpserver.impl.IODataConnectionFactory.initPassiveDataConnection(IODataConnectionFactory.java:170)
>         at org.apache.ftpserver.command.impl.PASV.execute(PASV.java:73)
>         at
>
> org.apache.ftpserver.impl.DefaultFtpHandler.messageReceived(DefaultFtpHandler.java:210)
>         at
>
> org.apache.ftpserver.listener.nio.FtpHandlerAdapter.messageReceived(FtpHandlerAdapter.java:61)
>         at
>
> org.apache.mina.core.filterchain.DefaultIoFilterChain$TailFilter.messageReceived(DefaultIoFilterChain.java:716)
>         at
>
> org.apache.mina.core.filterchain.DefaultIoFilterChain.callNextMessageReceived(DefaultIoFilterChain.java:434)
>         at
>
> org.apache.mina.core.filterchain.DefaultIoFilterChain.access$1200(DefaultIoFilterChain.java:46)
>         at
>
> org.apache.mina.core.filterchain.DefaultIoFilterChain$EntryImpl$1.messageReceived(DefaultIoFilterChain.java:796)
>         at
>
> org.apache.ftpserver.listener.nio.FtpLoggingFilter.messageReceived(FtpLoggingFilter.java:85)
>         at
>
> org.apache.mina.core.filterchain.DefaultIoFilterChain.callNextMessageReceived(DefaultIoFilterChain.java:434)
>         at
>
> org.apache.mina.core.filterchain.DefaultIoFilterChain.access$1200(DefaultIoFilterChain.java:46)
>         at
>
> org.apache.mina.core.filterchain.DefaultIoFilterChain$EntryImpl$1.messageReceived(DefaultIoFilterChain.java:796)
>         at
> org.apache.mina.core.filterchain.IoFilterEvent.fire(IoFilterEvent.java:75)
>         at
>
> org.apache.mina.filter.logging.MdcInjectionFilter.filter(MdcInjectionFilter.java:136)
>         at
>
> org.apache.mina.filter.util.CommonEventFilter.messageReceived(CommonEventFilter.java:70)
>         at
>
> org.apache.mina.core.filterchain.DefaultIoFilterChain.callNextMessageReceived(DefaultIoFilterChain.java:434)
>         at
>
> org.apache.mina.core.filterchain.DefaultIoFilterChain.access$1200(DefaultIoFilterChain.java:46)
>         at
>
> org.apache.mina.core.filterchain.DefaultIoFilterChain$EntryImpl$1.messageReceived(DefaultIoFilterChain.java:796)
>         at
>
> org.apache.mina.filter.codec.ProtocolCodecFilter$ProtocolDecoderOutputImpl.flush(ProtocolCodecFilter.java:427)
>         at
>
> org.apache.mina.filter.codec.ProtocolCodecFilter.messageReceived(ProtocolCodecFilter.java:245)
>         at
>
> org.apache.mina.core.filterchain.DefaultIoFilterChain.callNextMessageReceived(DefaultIoFilterChain.java:434)
>         at
>
> org.apache.mina.core.filterchain.DefaultIoFilterChain.access$1200(DefaultIoFilterChain.java:46)
>         at
>
> org.apache.mina.core.filterchain.DefaultIoFilterChain$EntryImpl$1.messageReceived(DefaultIoFilterChain.java:796)
>         at
> org.apache.mina.core.filterchain.IoFilterEvent.fire(IoFilterEvent.java:75)
>         at org.apache.mina.core.session.IoEvent.run(IoEvent.java:63)
>         at
>
> org.apache.mina.filter.executor.OrderedThreadPoolExecutor$Worker.runTask(OrderedThreadPoolExecutor.java:780)
>         at
>
> org.apache.mina.filter.executor.OrderedThreadPoolExecutor$Worker.runTasks(OrderedThreadPoolExecutor.java:772)
>         at
>
> org.apache.mina.filter.executor.OrderedThreadPoolExecutor$Worker.run(OrderedThreadPoolExecutor.java:714)
>         at java.lang.Thread.run(Thread.java:722)
>
> Jun 25, 2015 12:07:03 PM org.apache.mina.filter.logging.LoggingFilter log
> INFO: SENT: 425 Can't open passive connection.
>