The problem could be the client is not sending a valid PORT command where the data connection needs to be opened. The line in posted the log -
INFO - RECEIVED: PORT 0,0,0,0,192,246 It does not make sense to send 0.0.0.0 (wildcard) with the PORT command. This should be the client's IP address. Which FTP client are you using, and have you tried with any other FTP client software? On Tue, Apr 5, 2011 at 1:53 PM, frank buloup <[email protected]>wrote: > Hello, > > I've embeded FTP server in my application. It is working in localhost and > also in > our enterprise network. The problem seems to come when a connection is > initiated from > the outside of our network. You will find below a log that shows a > "java.net.ConnectException: Connection refused" exception on server when > LIST command is sent. > On the other side, client is totally frozen !!! It can also be a > "java.net.ConnectException: Operation timed out" > exception. > I've default configuration for server and client with 300s idle time and > session is closed by server > after this idle time while client is still frozen. > I've had a look at mail archive, but did not found anything ? > > Thanks a lot. > > DEBUG - File configured, will try loading > DEBUG - File found on file system > DEBUG - Intializing shared thread pool executor with max threads of 10 > INFO - FTP server started > DEBUG - Firing a SESSION_CREATED event for session 2 > DEBUG - Firing a SESSION_CREATED event for session 2 > INFO - CREATED > DEBUG - Event SESSION_CREATED has been fired for session 2 > DEBUG - Event SESSION_CREATED has been fired for session 2 > DEBUG - Firing a SESSION_OPENED event for session 2 > DEBUG - Adding event SESSION_OPENED to session 2 > Queue : [SESSION_OPENED, ] > > DEBUG - Event SESSION_OPENED has been fired for session 2 > DEBUG - Firing a SESSION_OPENED event for session 2 > DEBUG - Firing a SESSION_OPENED event for session 2 > INFO - OPENED > DEBUG - Firing a WRITE event for session 2 > DEBUG - Firing a WRITE event for session 2 > DEBUG - Event WRITE has been fired for session 2 > DEBUG - Firing a WRITE event for session 2 > DEBUG - Event WRITE has been fired for session 2 > DEBUG - Event WRITE has been fired for session 2 > DEBUG - Event SESSION_OPENED has been fired for session 2 > DEBUG - Event SESSION_OPENED has been fired for session 2 > DEBUG - Firing a MESSAGE_SENT event for session 2 > DEBUG - Adding event MESSAGE_SENT to session 2 > Queue : [MESSAGE_SENT, ] > > DEBUG - Event MESSAGE_SENT has been fired for session 2 > DEBUG - Firing a MESSAGE_SENT event for session 2 > DEBUG - Event MESSAGE_SENT has been fired for session 2 > DEBUG - Firing a MESSAGE_SENT event for session 2 > DEBUG - Adding event MESSAGE_SENT to session 2 > Queue : [MESSAGE_SENT, ] > > DEBUG - Event MESSAGE_SENT has been fired for session 2 > DEBUG - Firing a MESSAGE_SENT event for session 2 > DEBUG - Firing a MESSAGE_SENT event for session 2 > INFO - SENT: 220 Service ready for new user. > > DEBUG - Event MESSAGE_SENT has been fired for session 2 > DEBUG - Event MESSAGE_SENT has been fired for session 2 > DEBUG - Firing a MESSAGE_RECEIVED event for session 2 > DEBUG - Adding event MESSAGE_RECEIVED to session 2 > Queue : [MESSAGE_RECEIVED, ] > > DEBUG - Event MESSAGE_RECEIVED has been fired for session 2 > DEBUG - Firing a MESSAGE_RECEIVED event for session 2 > DEBUG - Processing a MESSAGE_RECEIVED for session 2 > DEBUG - Firing a MESSAGE_RECEIVED event for session 2 > INFO - RECEIVED: USER XXXX > DEBUG - Currently 0 out of 10 anonymous users logged in > DEBUG - Currently 0 out of 10 users logged in > DEBUG - Firing a WRITE event for session 2 > DEBUG - Firing a WRITE event for session 2 > DEBUG - Event WRITE has been fired for session 2 > DEBUG - Firing a WRITE event for session 2 > DEBUG - Event WRITE has been fired for session 2 > DEBUG - Event WRITE has been fired for session 2 > DEBUG - Event MESSAGE_RECEIVED has been fired for session 2 > DEBUG - Event MESSAGE_RECEIVED has been fired for session 2 > DEBUG - Firing a MESSAGE_SENT event for session 2 > DEBUG - Adding event MESSAGE_SENT to session 2 > Queue : [MESSAGE_SENT, ] > > DEBUG - Event MESSAGE_SENT has been fired for session 2 > DEBUG - Firing a MESSAGE_SENT event for session 2 > DEBUG - Adding event MESSAGE_SENT to session 2 > Queue : [MESSAGE_SENT, , MESSAGE_SENT, ] > > DEBUG - Event MESSAGE_SENT has been fired for session 2 > DEBUG - Firing a MESSAGE_SENT event for session 2 > DEBUG - Event MESSAGE_SENT has been fired for session 2 > DEBUG - Firing a MESSAGE_SENT event for session 2 > DEBUG - Firing a MESSAGE_SENT event for session 2 > INFO - SENT: 331 User name okay, need password for XXXX. > > DEBUG - Event MESSAGE_SENT has been fired for session 2 > DEBUG - Event MESSAGE_SENT has been fired for session 2 > DEBUG - Firing a MESSAGE_RECEIVED event for session 2 > DEBUG - Adding event MESSAGE_RECEIVED to session 2 > Queue : [MESSAGE_RECEIVED, ] > > DEBUG - Event MESSAGE_RECEIVED has been fired for session 2 > DEBUG - Firing a MESSAGE_RECEIVED event for session 2 > DEBUG - Processing a MESSAGE_RECEIVED for session 2 > DEBUG - Firing a MESSAGE_RECEIVED event for session 2 > INFO - RECEIVED: PASS ***** > DEBUG - Currently 0 out of 10 users logged in > DEBUG - Native filesystem view created for user "XXXX" with root > "/Users/XXXX/Desktop/XXXX/" > DEBUG - Firing a WRITE event for session 2 > DEBUG - Firing a WRITE event for session 2 > DEBUG - Event WRITE has been fired for session 2 > DEBUG - Firing a WRITE event for session 2 > DEBUG - Firing a MESSAGE_SENT event for session 2 > DEBUG - Event WRITE has been fired for session 2 > DEBUG - Adding event MESSAGE_SENT to session 2 > Queue : [MESSAGE_SENT, ] > > DEBUG - Event WRITE has been fired for session 2 > INFO - Login success - XXXX > DEBUG - Event MESSAGE_SENT has been fired for session 2 > DEBUG - Firing a MESSAGE_SENT event for session 2 > DEBUG - Adding event MESSAGE_SENT to session 2 > Queue : [MESSAGE_SENT, , MESSAGE_SENT, ] > > DEBUG - Event MESSAGE_SENT has been fired for session 2 > DEBUG - Event MESSAGE_RECEIVED has been fired for session 2 > DEBUG - Event MESSAGE_RECEIVED has been fired for session 2 > DEBUG - Firing a MESSAGE_SENT event for session 2 > DEBUG - Event MESSAGE_SENT has been fired for session 2 > DEBUG - Firing a MESSAGE_SENT event for session 2 > DEBUG - Firing a MESSAGE_SENT event for session 2 > INFO - SENT: 230 User logged in, proceed. > > DEBUG - Event MESSAGE_SENT has been fired for session 2 > DEBUG - Event MESSAGE_SENT has been fired for session 2 > DEBUG - Firing a MESSAGE_RECEIVED event for session 2 > DEBUG - Adding event MESSAGE_RECEIVED to session 2 > Queue : [MESSAGE_RECEIVED, ] > > DEBUG - Event MESSAGE_RECEIVED has been fired for session 2 > DEBUG - Firing a MESSAGE_RECEIVED event for session 2 > DEBUG - Processing a MESSAGE_RECEIVED for session 2 > DEBUG - Firing a MESSAGE_RECEIVED event for session 2 > INFO - RECEIVED: SYST > DEBUG - Firing a WRITE event for session 2 > DEBUG - Firing a WRITE event for session 2 > DEBUG - Event WRITE has been fired for session 2 > DEBUG - Firing a WRITE event for session 2 > DEBUG - Event WRITE has been fired for session 2 > DEBUG - Firing a MESSAGE_SENT event for session 2 > DEBUG - Event WRITE has been fired for session 2 > DEBUG - Adding event MESSAGE_SENT to session 2 > Queue : [MESSAGE_SENT, ] > > DEBUG - Event MESSAGE_RECEIVED has been fired for session 2 > DEBUG - Event MESSAGE_SENT has been fired for session 2 > DEBUG - Event MESSAGE_RECEIVED has been fired for session 2 > DEBUG - Firing a MESSAGE_SENT event for session 2 > DEBUG - Event MESSAGE_SENT has been fired for session 2 > DEBUG - Firing a MESSAGE_SENT event for session 2 > DEBUG - Adding event MESSAGE_SENT to session 2 > Queue : [MESSAGE_SENT, ] > > DEBUG - Event MESSAGE_SENT has been fired for session 2 > DEBUG - Firing a MESSAGE_SENT event for session 2 > DEBUG - Firing a MESSAGE_SENT event for session 2 > INFO - SENT: 215 UNIX Type: Apache FtpServer > > DEBUG - Event MESSAGE_SENT has been fired for session 2 > DEBUG - Event MESSAGE_SENT has been fired for session 2 > DEBUG - Firing a MESSAGE_RECEIVED event for session 2 > DEBUG - Adding event MESSAGE_RECEIVED to session 2 > Queue : [MESSAGE_RECEIVED, ] > > DEBUG - Event MESSAGE_RECEIVED has been fired for session 2 > DEBUG - Firing a MESSAGE_RECEIVED event for session 2 > DEBUG - Processing a MESSAGE_RECEIVED for session 2 > DEBUG - Firing a MESSAGE_RECEIVED event for session 2 > INFO - RECEIVED: PORT 0,0,0,0,192,246 > DEBUG - Firing a WRITE event for session 2 > DEBUG - Firing a WRITE event for session 2 > DEBUG - Event WRITE has been fired for session 2 > DEBUG - Firing a WRITE event for session 2 > DEBUG - Event WRITE has been fired for session 2 > DEBUG - Firing a MESSAGE_SENT event for session 2 > DEBUG - Event WRITE has been fired for session 2 > DEBUG - Adding event MESSAGE_SENT to session 2 > Queue : [MESSAGE_SENT, ] > > DEBUG - Event MESSAGE_RECEIVED has been fired for session 2 > DEBUG - Event MESSAGE_SENT has been fired for session 2 > DEBUG - Event MESSAGE_RECEIVED has been fired for session 2 > DEBUG - Firing a MESSAGE_SENT event for session 2 > DEBUG - Event MESSAGE_SENT has been fired for session 2 > DEBUG - Firing a MESSAGE_SENT event for session 2 > DEBUG - Adding event MESSAGE_SENT to session 2 > Queue : [MESSAGE_SENT, ] > > DEBUG - Event MESSAGE_SENT has been fired for session 2 > DEBUG - Firing a MESSAGE_SENT event for session 2 > DEBUG - Firing a MESSAGE_SENT event for session 2 > INFO - SENT: 200 Command PORT okay. > > DEBUG - Event MESSAGE_SENT has been fired for session 2 > DEBUG - Event MESSAGE_SENT has been fired for session 2 > DEBUG - Firing a MESSAGE_RECEIVED event for session 2 > DEBUG - Adding event MESSAGE_RECEIVED to session 2 > Queue : [MESSAGE_RECEIVED, ] > > DEBUG - Event MESSAGE_RECEIVED has been fired for session 2 > DEBUG - Firing a MESSAGE_RECEIVED event for session 2 > DEBUG - Processing a MESSAGE_RECEIVED for session 2 > DEBUG - Firing a MESSAGE_RECEIVED event for session 2 > INFO - RECEIVED: LIST > DEBUG - Firing a WRITE event for session 2 > DEBUG - Firing a WRITE event for session 2 > DEBUG - Event WRITE has been fired for session 2 > DEBUG - Firing a WRITE event for session 2 > DEBUG - Event WRITE has been fired for session 2 > DEBUG - Firing a MESSAGE_SENT event for session 2 > DEBUG - Event WRITE has been fired for session 2 > DEBUG - Adding event MESSAGE_SENT to session 2 > Queue : [MESSAGE_SENT, ] > > DEBUG - Event MESSAGE_SENT has been fired for session 2 > DEBUG - Firing a MESSAGE_SENT event for session 2 > DEBUG - Adding event MESSAGE_SENT to session 2 > Queue : [MESSAGE_SENT, , MESSAGE_SENT, ] > > DEBUG - Event MESSAGE_SENT has been fired for session 2 > DEBUG - Opening active data connection > DEBUG - Binding active data connection to /xxx.xxx.xxx.xxx:0 > WARN - FtpDataConnection.getDataSocket() > java.net.ConnectException: Connection refused > at java.net.PlainSocketImpl.socketConnect(Native Method) > at java.net.PlainSocketImpl.doConnect(PlainSocketImpl.java:333) > at java.net.PlainSocketImpl.connectToAddress(PlainSocketImpl.java:193) > at java.net.PlainSocketImpl.connect(PlainSocketImpl.java:182) > at java.net.SocksSocketImpl.connect(SocksSocketImpl.java:433) > at java.net.Socket.connect(Socket.java:529) > at java.net.Socket.connect(Socket.java:477) > at > org.apache.ftpserver.impl.IODataConnectionFactory.createDataSocket(IODataConnectionFactory.java:314) > at > org.apache.ftpserver.impl.IODataConnectionFactory.openConnection(IODataConnectionFactory.java:259) > at org.apache.ftpserver.command.impl.LIST.execute(LIST.java:114) > 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:713) > 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:793) > 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:793) > at > org.apache.mina.core.filterchain.IoFilterEvent.fire(IoFilterEvent.java:71) > 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:793) > at > org.apache.mina.filter.codec.ProtocolCodecFilter$ProtocolDecoderOutputImpl.flush(ProtocolCodecFilter.java:375) > at > org.apache.mina.filter.codec.ProtocolCodecFilter.messageReceived(ProtocolCodecFilter.java:229) > 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:793) > at > org.apache.mina.core.filterchain.IoFilterEvent.fire(IoFilterEvent.java:71) > 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:655) > DEBUG - Exception getting the output data stream > java.net.ConnectException: Connection refused > at java.net.PlainSocketImpl.socketConnect(Native Method) > at java.net.PlainSocketImpl.doConnect(PlainSocketImpl.java:333) > at java.net.PlainSocketImpl.connectToAddress(PlainSocketImpl.java:193) > at java.net.PlainSocketImpl.connect(PlainSocketImpl.java:182) > at java.net.SocksSocketImpl.connect(SocksSocketImpl.java:433) > at java.net.Socket.connect(Socket.java:529) > at java.net.Socket.connect(Socket.java:477) > at > org.apache.ftpserver.impl.IODataConnectionFactory.createDataSocket(IODataConnectionFactory.java:314) > at > org.apache.ftpserver.impl.IODataConnectionFactory.openConnection(IODataConnectionFactory.java:259) > at org.apache.ftpserver.command.impl.LIST.execute(LIST.java:114) > 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:713) > 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:793) > 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:793) > at > org.apache.mina.core.filterchain.IoFilterEvent.fire(IoFilterEvent.java:71) > 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:793) > at > org.apache.mina.filter.codec.ProtocolCodecFilter$ProtocolDecoderOutputImpl.flush(ProtocolCodecFilter.java:375) > at > org.apache.mina.filter.codec.ProtocolCodecFilter.messageReceived(ProtocolCodecFilter.java:229) > 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:793) > at > org.apache.mina.core.filterchain.IoFilterEvent.fire(IoFilterEvent.java:71) > 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:655) > DEBUG - Firing a WRITE event for session 2 > DEBUG - Firing a WRITE event for session 2 > DEBUG - Event WRITE has been fired for session 2 > DEBUG - Firing a WRITE event for session 2 > DEBUG - Firing a MESSAGE_SENT event for session 2 > DEBUG - Event WRITE has been fired for session 2 > DEBUG - Adding event MESSAGE_SENT to session 2 > Queue : [MESSAGE_SENT, , MESSAGE_SENT, , MESSAGE_SENT, ] > > DEBUG - Event WRITE has been fired for session 2 > DEBUG - Event MESSAGE_SENT has been fired for session 2 > DEBUG - Event MESSAGE_RECEIVED has been fired for session 2 > DEBUG - Event MESSAGE_RECEIVED has been fired for session 2 > DEBUG - Firing a MESSAGE_SENT event for session 2 > DEBUG - Event MESSAGE_SENT has been fired for session 2 > DEBUG - Firing a MESSAGE_SENT event for session 2 > DEBUG - Firing a MESSAGE_SENT event for session 2 > DEBUG - Adding event MESSAGE_SENT to session 2 > Queue : [MESSAGE_SENT, , MESSAGE_SENT, ] > > DEBUG - Event MESSAGE_SENT has been fired for session 2 > DEBUG - Firing a MESSAGE_SENT event for session 2 > INFO - SENT: 150 File status okay; about to open data connection. > > DEBUG - Event MESSAGE_SENT has been fired for session 2 > DEBUG - Event MESSAGE_SENT has been fired for session 2 > DEBUG - Firing a MESSAGE_SENT event for session 2 > DEBUG - Event MESSAGE_SENT has been fired for session 2 > DEBUG - Firing a MESSAGE_SENT event for session 2 > DEBUG - Firing a MESSAGE_SENT event for session 2 > INFO - SENT: 425 Can't open data connection. > > DEBUG - Event MESSAGE_SENT has been fired for session 2 > DEBUG - Event MESSAGE_SENT has been fired for session 2 > DEBUG - Firing a SESSION_IDLE event for session 2 > DEBUG - Adding event SESSION_IDLE to session 2 > Queue : [SESSION_IDLE, ] > > DEBUG - Event SESSION_IDLE has been fired for session 2 > DEBUG - Firing a SESSION_IDLE event for session 2 > DEBUG - Firing a SESSION_IDLE event for session 2 > INFO - IDLE > INFO - Session idle, closing > DEBUG - Firing a CLOSE event for session 2 > DEBUG - Firing a CLOSE event for session 2 > DEBUG - Event CLOSE has been fired for session 2 > DEBUG - Event CLOSE has been fired for session 2 > DEBUG - Event SESSION_IDLE has been fired for session 2 > DEBUG - Event SESSION_IDLE has been fired for session 2 > DEBUG - Firing a SESSION_CLOSED event for session 2 > DEBUG - Adding event SESSION_CLOSED to session 2 > Queue : [SESSION_CLOSED, ] > > DEBUG - Event SESSION_CLOSED has been fired for session 2 > DEBUG - Firing a SESSION_CLOSED event for session 2 > DEBUG - Firing a SESSION_CLOSED event for session 2 > INFO - CLOSED > DEBUG - Closing session > DEBUG - Statistics login and connection count decreased due to session > close > DEBUG - Session closed > DEBUG - Event SESSION_CLOSED has been fired for session 2 > DEBUG - Event SESSION_CLOSED has been fired for session 2 >
