Data channel cannot be opened in active mode
--------------------------------------------

                 Key: FTPSERVER-111
                 URL: https://issues.apache.org/jira/browse/FTPSERVER-111
             Project: FtpServer
          Issue Type: Bug
          Components: Core
         Environment: Solaris, Linux, maybe others (Windows seems to work)
            Reporter: Rico Neubauer


FTP-Server with active mode running on Solaris/Linux
Client connects to the server with active mode.
Issue list command -> ok
issue second list command -> client  hangs

Client commands:
220 Service ready for new user.
Name (localhost:username): test
331 User name okay, need password for test.
Password:
230 User logged in, proceed.
Remote system type is UNIX.
ftp> 
ftp> 
ftp> ls
200 Command PORT okay.
150 File status okay; about to open data connection.
directory1
directory2
226 Closing data connection.
11 bytes received in 0.0099 seconds (1.08 Kbytes/s)
ftp> ls
200 Command PORT okay.
150 File status okay; about to open data connection.
<Client hangs here>

Server-Log:
15:38:08,581 INFO  [UserManagerImpl] authenticate: Authentication for user 
<test> complete.
15:38:08,583 DEBUG [UserManagerImpl] setUserConfigurations: Setting up user 
permissions...
15:38:08,584 DEBUG [UserManagerImpl] setUserConfigurations: Write permission 
granted for user <test>
15:38:08,597 DEBUG [FTPServerFtplet] onLogin:PASS *****
15:38:08,627 INFO  [MinaFtpProtocolHandler] [/10.0.0.239:33204] WRITE: 230 User 
logged in, proceed.
15:38:08,628 INFO  [PASS] Login success - test
15:38:08,629 DEBUG [ExecutorFilter] Exiting since queue is empty for 
/10.0.0.239:33204
15:38:08,629 INFO  [MinaFtpProtocolHandler] [/10.0.0.239:33204] SENT: 230 User 
logged in, proceed.
15:38:08,630 DEBUG [ExecutorFilter] Launching thread for /10.0.0.239:33204
15:38:08,631 DEBUG [ExecutorFilter] Exiting since queue is empty for 
/10.0.0.239:33204
15:38:08,631 INFO  [MinaFtpProtocolHandler] [/10.0.0.239:33204] RECEIVED: SYST
15:38:08,632 DEBUG [ExecutorFilter] Launching thread for /10.0.0.239:33204
15:38:08,632 INFO  [MinaFtpProtocolHandler] [/10.0.0.239:33204] WRITE: 215 UNIX 
Type: Apache FTP Server
15:38:08,634 DEBUG [ExecutorFilter] Exiting since queue is empty for 
/10.0.0.239:33204
15:38:08,634 INFO  [MinaFtpProtocolHandler] [/10.0.0.239:33204] SENT: 215 UNIX 
Type: Apache FTP Server
15:38:08,635 DEBUG [ExecutorFilter] Launching thread for /10.0.0.239:33204
15:38:08,635 DEBUG [ExecutorFilter] Exiting since queue is empty for 
/10.0.0.239:33204
15:38:11,153 INFO  [MinaFtpProtocolHandler] [/10.0.0.239:33204] RECEIVED: PORT 
10,0,0,239,129,181
15:38:11,156 DEBUG [ExecutorFilter] Launching thread for /10.0.0.239:33204
15:38:11,157 INFO  [MinaFtpProtocolHandler] [/10.0.0.239:33204] WRITE: 510 PORT 
is disabled.
15:38:11,158 DEBUG [ExecutorFilter] Exiting since queue is empty for 
/10.0.0.239:33204
15:38:11,158 INFO  [MinaFtpProtocolHandler] [/10.0.0.239:33204] SENT: 510 PORT 
is disabled.
15:38:11,159 DEBUG [ExecutorFilter] Launching thread for /10.0.0.239:33204
15:38:11,160 DEBUG [ExecutorFilter] Exiting since queue is empty for 
/10.0.0.239:33204
15:38:11,160 INFO  [MinaFtpProtocolHandler] [/10.0.0.239:33204] RECEIVED: NLST
15:38:11,161 DEBUG [ExecutorFilter] Launching thread for /10.0.0.239:33204
15:38:11,161 INFO  [MinaFtpProtocolHandler] [/10.0.0.239:33204] WRITE: 150 File 
status okay; about to open data connection.
15:38:11,162 INFO  [MinaFtpProtocolHandler] [/10.0.0.239:33204] SENT: 150 File 
status okay; about to open data connection.
15:38:11,167 WARN  [IODataConnectionFactory] FtpDataConnection.getDataSocket()
java.lang.NullPointerException
        at java.net.Socket.<init>(Socket.java:358)
        at java.net.Socket.<init>(Socket.java:208)
        at 
org.apache.ftpserver.IODataConnectionFactory.createDataSocket(IODataConnectionFactory.java:261)
        at 
org.apache.ftpserver.IODataConnectionFactory.openConnection(IODataConnectionFactory.java:232)
        at org.apache.ftpserver.command.NLST.execute(NLST.java:81)
        at 
org.apache.ftpserver.listener.FtpProtocolHandler.service(FtpProtocolHandler.java:195)
        at 
org.apache.ftpserver.listener.FtpProtocolHandler.onRequestReceived(FtpProtocolHandler.java:122)
        at 
org.apache.ftpserver.listener.mina.MinaFtpProtocolHandler.messageReceived(MinaFtpProtocolHandler.java:106)
        at 
org.apache.mina.common.support.AbstractIoFilterChain$TailFilter.messageReceived(AbstractIoFilterChain.java:569)
        at 
org.apache.mina.common.support.AbstractIoFilterChain.callNextMessageReceived(AbstractIoFilterChain.java:298)
        at 
org.apache.mina.common.support.AbstractIoFilterChain.access$1200(AbstractIoFilterChain.java:53)
        at 
org.apache.mina.common.support.AbstractIoFilterChain$EntryImpl$1.messageReceived(AbstractIoFilterChain.java:647)
        at 
org.apache.mina.filter.executor.ExecutorFilter.processEvent(ExecutorFilter.java:220)
        at 
org.apache.mina.filter.executor.ExecutorFilter$ProcessEventsRunnable.run(ExecutorFilter.java:266)
        at 
edu.emory.mathcs.backport.java.util.concurrent.ThreadPoolExecutor$Worker.runTask(ThreadPoolExecutor.java:650)
        at 
edu.emory.mathcs.backport.java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:675)
        at java.lang.Thread.run(Thread.java:595)
15:38:11,174 DEBUG [NLST] Exception getting the output data stream
java.lang.NullPointerException
        at java.net.Socket.<init>(Socket.java:358)
        at java.net.Socket.<init>(Socket.java:208)
        at 
org.apache.ftpserver.IODataConnectionFactory.createDataSocket(IODataConnectionFactory.java:261)
        at 
org.apache.ftpserver.IODataConnectionFactory.openConnection(IODataConnectionFactory.java:232)
        at org.apache.ftpserver.command.NLST.execute(NLST.java:81)
        at 
org.apache.ftpserver.listener.FtpProtocolHandler.service(FtpProtocolHandler.java:195)
        at 
org.apache.ftpserver.listener.FtpProtocolHandler.onRequestReceived(FtpProtocolHandler.java:122)
        at 
org.apache.ftpserver.listener.mina.MinaFtpProtocolHandler.messageReceived(MinaFtpProtocolHandler.java:106)
        at 
org.apache.mina.common.support.AbstractIoFilterChain$TailFilter.messageReceived(AbstractIoFilterChain.java:569)
        at 
org.apache.mina.common.support.AbstractIoFilterChain.callNextMessageReceived(AbstractIoFilterChain.java:298)
        at 
org.apache.mina.common.support.AbstractIoFilterChain.access$1200(AbstractIoFilterChain.java:53)
        at 
org.apache.mina.common.support.AbstractIoFilterChain$EntryImpl$1.messageReceived(AbstractIoFilterChain.java:647)
        at 
org.apache.mina.filter.executor.ExecutorFilter.processEvent(ExecutorFilter.java:220)
        at 
org.apache.mina.filter.executor.ExecutorFilter$ProcessEventsRunnable.run(ExecutorFilter.java:266)
        at 
edu.emory.mathcs.backport.java.util.concurrent.ThreadPoolExecutor$Worker.runTask(ThreadPoolExecutor.java:650)
        at 
edu.emory.mathcs.backport.java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:675)
        at java.lang.Thread.run(Thread.java:595)
15:38:11,175 INFO  [MinaFtpProtocolHandler] [/10.0.0.239:33204] WRITE: 425 
Can't open data connection.
15:38:11,176 DEBUG [ExecutorFilter] Exiting since queue is empty for 
/10.0.0.239:33204
15:38:11,176 INFO  [MinaFtpProtocolHandler] [/10.0.0.239:33204] SENT: 425 Can't 
open data connection.
15:38:11,177 DEBUG [ExecutorFilter] Launching thread for /10.0.0.239:33204
15:38:11,177 DEBUG [ExecutorFilter] Exiting since queue is empty for 
/10.0.0.239:33204
15:39:38,458 WARN  [MinaFtpProtocolHandler] [/10.0.0.239:33204] EXCEPTION:
org.apache.mina.filter.codec.ProtocolDecoderException: 
java.nio.charset.MalformedInputException: Input length = 1 (Hexdump: empty)
        at 
org.apache.mina.filter.codec.ProtocolCodecFilter.messageReceived(ProtocolCodecFilter.java:160)
        at 
org.apache.mina.common.support.AbstractIoFilterChain.callNextMessageReceived(AbstractIoFilterChain.java:298)
        at 
org.apache.mina.common.support.AbstractIoFilterChain.access$1200(AbstractIoFilterChain.java:53)
        at 
org.apache.mina.common.support.AbstractIoFilterChain$EntryImpl$1.messageReceived(AbstractIoFilterChain.java:647)
        at 
org.apache.mina.common.support.AbstractIoFilterChain$HeadFilter.messageReceived(AbstractIoFilterChain.java:498)
        at 
org.apache.mina.common.support.AbstractIoFilterChain.callNextMessageReceived(AbstractIoFilterChain.java:298)
        at 
org.apache.mina.common.support.AbstractIoFilterChain.fireMessageReceived(AbstractIoFilterChain.java:292)
        at 
org.apache.mina.transport.socket.nio.SocketIoProcessor.read(SocketIoProcessor.java:253)
        at 
org.apache.mina.transport.socket.nio.SocketIoProcessor.process(SocketIoProcessor.java:223)
        at 
org.apache.mina.transport.socket.nio.SocketIoProcessor.access$500(SocketIoProcessor.java:44)
        at 
org.apache.mina.transport.socket.nio.SocketIoProcessor$Worker.run(SocketIoProcessor.java:524)
        at 
org.apache.mina.util.NamePreservingRunnable.run(NamePreservingRunnable.java:39)
        at 
edu.emory.mathcs.backport.java.util.concurrent.ThreadPoolExecutor$Worker.runTask(ThreadPoolExecutor.java:650)
        at 
edu.emory.mathcs.backport.java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:675)
        at java.lang.Thread.run(Thread.java:595)
Caused by: java.nio.charset.MalformedInputException: Input length = 1
        at java.nio.charset.CoderResult.throwException(CoderResult.java:260)
        at org.apache.mina.common.ByteBuffer.getString(ByteBuffer.java:953)
        at 
org.apache.mina.filter.codec.textline.TextLineDecoder.decodeAuto(TextLineDecoder.java:180)
        at 
org.apache.mina.filter.codec.textline.TextLineDecoder.decode(TextLineDecoder.java:113)
        at 
org.apache.mina.filter.codec.ProtocolCodecFilter.messageReceived(ProtocolCodecFilter.java:153)
        ... 14 more

-- 
This message is automatically generated by JIRA.
-
You can reply to this email to add a comment to the issue online.

Reply via email to