Hi!
I'm trying to setup a ftps server using the latest svn checkout (As in
today :) ).
Things work fine, except when a ftp client (FileZilla in my case)
disconnects.
Underneath is a log showing the error/warning that I get on disconnect
(using the disconnect button on filezilla, which I think is a pretty
well accepted way on closing the connection).
When using flashfxp I seem the same thing happening, even when it first
sends a QUIT (added a log for that after the filezilla one, hope the
long mail isn't a problem! :) ).
Now this warning isn't such a big issue, but it seems the 'logout' code
isn't called when this happens.
The result of this is that I run out of logins, for example with 3
'anonymous logins' (which = 3 simultaneous logins),
I will not be able to log in anymore after three -sequential- logins.
And it's not hanging connections, even if I close the client entirely,
and try to reconnect, I still get 'Response: 421 Maximum login limit
has been reached.'
I've even checked with the tcp view tool from sysinternals that there's
really no connections left.
So I think that because of the thrown exception, the code that normally
decreases the login count isn't called, my guess anyways.
Can someone please verify if this is a bug (and possibly fix it? or tell
me how to fix it ;) ).
Cheers!
Following:
- config I'm using
- filezilla log
- flashfxp log
## Properties file based configuration
##-----------------------------------------------------------------------------
## This is the listener configuration. Additional listeners can be added
if required.
## If you want to support SSL connections, please specify ssl block
##-----------------------------------------------------------------------------
config.listeners.default.class=org.apache.ftpserver.listener.nio.NioListener
config.listeners.default.serverAddress=localhost
config.listeners.default.port=21
config.listeners.default.implicit-ssl=false
config.listeners.default.ssl-configuration.class=org.apache.ftpserver.ssl.DefaultSslConfiguration
config.listeners.default.ssl-configuration.keystore-file=./res/.keystore
config.listeners.default.ssl-configuration.keystore-password=password
config.listeners.default.ssl-configuration.keystore-type=JKS
config.listeners.default.ssl-configuration.keystore-algorithm=SunX509
config.listeners.default.ssl-configuration.ssl-protocol=TLS
config.listeners.default.ssl-configuration.client-authentication=false
config.listeners.default.ssl-configuration.key-password=password
##------------------------------------------------------------------------------
## Data connection configuration
## If you want to use encrypted data connection, please use ssl block.
##------------------------------------------------------------------------------
config.listeners.default.data-connection-configuration.class=org.apache.ftpserver.DefaultDataConnectionConfiguration
config.listeners.default.data-connection-configuration.idle-time=10
config.listeners.default.data-connection-configuration.active.enable=true
config.listeners.default.data-connection-configuration.active.local-address=localhost
config.listeners.default.data-connection-configuration.active.local-port=20
config.listeners.default.data-connection-configuration.active.ip-check=false
config.listeners.default.data-connection-configuration.passive.address=localhost
config.listeners.default.data-connection-configuration.passive.ports=0
#config.listeners.default.data-connection-configuration.passive.external-address=192.1.2.3
config.listeners.default.data-connection-configuration.ssl-configuration.class=org.apache.ftpserver.ssl.DefaultSslConfiguration
config.listeners.default.data-connection-configuration.ssl-configuration.keystore-file=./res/.keystore
config.listeners.default.data-connection-configuration.ssl-configuration.keystore-password=password
config.listeners.default.data-connection-configuration.ssl-configuration.keystore-type=JKS
config.listeners.default.data-connection-configuration.ssl-configuration.keystore-algorithm=SunX509
config.listeners.default.data-connection-configuration.ssl-configuration.ssl-protocol=TLS
config.listeners.default.data-connection-configuration.ssl-configuration.client-authentication=false
config.listeners.default.data-connection-configuration.ssl-configuration.key-password=password
[ INFO] 2008-06-23 21:47:38,609 Creating user : admin
[ INFO] 2008-06-23 21:47:38,625 Creating user : anonymous
[ INFO] 2008-06-23 21:47:38,718 FTP server started
[ INFO] 2008-06-23 21:52:43,609 FTP server started
[ INFO] 2008-06-23 21:56:01,359 FTP server started
[ INFO] 2008-06-23 21:57:09,609 CREATED
[ INFO] 2008-06-23 21:57:09,609 OPENED
[ INFO] 2008-06-23 21:57:09,609 SENT: 220 Service ready for new user.
[ INFO] 2008-06-23 21:57:09,625 RECEIVED: AUTH TLS
[ INFO] 2008-06-23 21:57:09,968 SENT: 234 Command AUTH okay; starting
TLS connection.
[ INFO] 2008-06-23 21:57:19,421 RECEIVED: USER ANONYMOUS
[ INFO] 2008-06-23 21:57:19,421 SENT: 331 Guest login okay, send your
complete e-mail address as password.
[ INFO] 2008-06-23 21:57:19,421 RECEIVED: PASS *****
[ INFO] 2008-06-23 21:57:19,421 Anonymous login success - [EMAIL PROTECTED]
[ INFO] 2008-06-23 21:57:19,421 SENT: 230 User logged in, proceed.
[ INFO] 2008-06-23 21:57:19,421 RECEIVED: SYST
[ INFO] 2008-06-23 21:57:19,421 SENT: 215 UNIX Type: Apache FTP Server
[ INFO] 2008-06-23 21:57:19,437 RECEIVED: FEAT
[ INFO] 2008-06-23 21:57:19,437 SENT: 211-Extensions supported
SIZE
MDTM
REST STREAM
LANG en;zh-tw;ja;is
MLST Size;Modify;Type;Perm
AUTH SSL
AUTH TLS
MODE Z
UTF8
TVFS
MD5
MMD5
211 End
[ INFO] 2008-06-23 21:57:19,437 RECEIVED: OPTS UTF8 ON
[ INFO] 2008-06-23 21:57:19,437 SENT: 200 Command OPTS okay.
[ INFO] 2008-06-23 21:57:19,437 RECEIVED: PBSZ 0
[ INFO] 2008-06-23 21:57:19,437 SENT: 200 Command PBSZ okay.
[ INFO] 2008-06-23 21:57:19,437 RECEIVED: PROT P
[ INFO] 2008-06-23 21:57:19,437 SENT: 200 Command PROT okay.
[ INFO] 2008-06-23 21:57:19,453 RECEIVED: PWD
[ INFO] 2008-06-23 21:57:19,453 SENT: 257 "/" is current directory.
[ INFO] 2008-06-23 21:57:19,453 RECEIVED: TYPE I
[ INFO] 2008-06-23 21:57:19,453 SENT: 200 Command TYPE okay.
[ INFO] 2008-06-23 21:57:19,453 RECEIVED: PASV
[DEBUG] 2008-06-23 21:57:19,453 SSL data connection created on
localhost/127.0.0.1:3948
[ INFO] 2008-06-23 21:57:19,453 SENT: 227 Entering Passive Mode
(127,0,0,1,15,108)
[ INFO] 2008-06-23 21:57:19,453 RECEIVED: LIST
[DEBUG] 2008-06-23 21:57:19,453 Opening passive data connection
[DEBUG] 2008-06-23 21:57:19,468 Passive data connection opened
[ INFO] 2008-06-23 21:57:19,500 SENT: 150 File status okay; about to
open data connection.
[ INFO] 2008-06-23 21:57:19,500 SENT: 226 Closing data connection.
[ INFO] 2008-06-23 21:57:19,515 RECEIVED: MDTM README.TXT
[ INFO] 2008-06-23 21:57:19,515 SENT: 213 20080623214436.000
[ INFO] 2008-06-23 21:57:24,968 CREATED
[ INFO] 2008-06-23 21:57:24,968 OPENED
[ INFO] 2008-06-23 21:57:24,968 SENT: 220 Service ready for new user.
[ INFO] 2008-06-23 21:57:24,968 RECEIVED: AUTH TLS
[ INFO] 2008-06-23 21:57:25,015 SENT: 234 Command AUTH okay; starting
TLS connection.
[ INFO] 2008-06-23 21:57:25,015 RECEIVED: USER ANONYMOUS
[ INFO] 2008-06-23 21:57:25,015 SENT: 331 Guest login okay, send your
complete e-mail address as password.
[ INFO] 2008-06-23 21:57:25,015 RECEIVED: PASS *****
[ INFO] 2008-06-23 21:57:25,015 Anonymous login success - [EMAIL PROTECTED]
[ INFO] 2008-06-23 21:57:25,015 SENT: 230 User logged in, proceed.
[ INFO] 2008-06-23 21:57:25,015 RECEIVED: OPTS UTF8 ON
[ INFO] 2008-06-23 21:57:25,015 SENT: 200 Command OPTS okay.
[ INFO] 2008-06-23 21:57:25,015 RECEIVED: PBSZ 0
[ INFO] 2008-06-23 21:57:25,015 SENT: 200 Command PBSZ okay.
[ INFO] 2008-06-23 21:57:25,015 RECEIVED: PROT P
[ INFO] 2008-06-23 21:57:25,015 SENT: 200 Command PROT okay.
[ INFO] 2008-06-23 21:57:25,015 RECEIVED: CWD /
[ INFO] 2008-06-23 21:57:25,015 SENT: 250 Directory changed to /
[ INFO] 2008-06-23 21:57:25,015 RECEIVED: PWD
[ INFO] 2008-06-23 21:57:25,015 SENT: 257 "/" is current directory.
[ INFO] 2008-06-23 21:57:25,015 RECEIVED: TYPE A
[ INFO] 2008-06-23 21:57:25,031 SENT: 200 Command TYPE okay.
[ INFO] 2008-06-23 21:57:25,031 RECEIVED: PASV
[DEBUG] 2008-06-23 21:57:25,031 SSL data connection created on
localhost/127.0.0.1:3951
[ INFO] 2008-06-23 21:57:25,031 SENT: 227 Entering Passive Mode
(127,0,0,1,15,111)
[ INFO] 2008-06-23 21:57:25,031 RECEIVED: RETR README.TXT
[DEBUG] 2008-06-23 21:57:25,031 Opening passive data connection
[DEBUG] 2008-06-23 21:57:25,031 Passive data connection opened
[ INFO] 2008-06-23 21:57:25,140 File download : anonymous - /README.txt
[ INFO] 2008-06-23 21:57:25,140 SENT: 150 File status okay; about to
open data connection.
[ INFO] 2008-06-23 21:57:25,140 SENT: 226 Transfer complete.
[DEBUG] 2008-06-23 21:57:55,140 Unexpected exception from
SSLEngine.closeInbound().
javax.net.ssl.SSLException: Inbound closed before receiving peer's
close_notify: possible truncation attack?
at com.sun.net.ssl.internal.ssl.Alerts.getSSLException(Alerts.java:190)
at
com.sun.net.ssl.internal.ssl.SSLEngineImpl.fatal(SSLEngineImpl.java:1366)
at
com.sun.net.ssl.internal.ssl.SSLEngineImpl.fatal(SSLEngineImpl.java:1334)
at
com.sun.net.ssl.internal.ssl.SSLEngineImpl.closeInbound(SSLEngineImpl.java:1273)
at org.apache.mina.filter.ssl.SslHandler.destroy(SslHandler.java:155)
at
org.apache.mina.filter.ssl.SslFilter.sessionClosed(SslFilter.java:386)
at
org.apache.mina.common.DefaultIoFilterChain.callNextSessionClosed(DefaultIoFilterChain.java:369)
at
org.apache.mina.common.DefaultIoFilterChain.access$900(DefaultIoFilterChain.java:40)
at
org.apache.mina.common.DefaultIoFilterChain$EntryImpl$1.sessionClosed(DefaultIoFilterChain.java:808)
at
org.apache.mina.common.DefaultIoFilterChain$HeadFilter.sessionClosed(DefaultIoFilterChain.java:589)
at
org.apache.mina.common.DefaultIoFilterChain.callNextSessionClosed(DefaultIoFilterChain.java:369)
at
org.apache.mina.common.DefaultIoFilterChain.fireSessionClosed(DefaultIoFilterChain.java:364)
at
org.apache.mina.common.IoServiceListenerSupport.fireSessionDestroyed(IoServiceListenerSupport.java:223)
at
org.apache.mina.common.AbstractPollingIoProcessor.removeNow(AbstractPollingIoProcessor.java:342)
at
org.apache.mina.common.AbstractPollingIoProcessor.remove(AbstractPollingIoProcessor.java:312)
at
org.apache.mina.common.AbstractPollingIoProcessor.access$700(AbstractPollingIoProcessor.java:43)
at
org.apache.mina.common.AbstractPollingIoProcessor$Worker.run(AbstractPollingIoProcessor.java:708)
at
org.apache.mina.util.NamePreservingRunnable.run(NamePreservingRunnable.java:51)
at
java.util.concurrent.ThreadPoolExecutor$Worker.runTask(ThreadPoolExecutor.java:885)
at
java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:907)
at java.lang.Thread.run(Thread.java:619)
[ INFO] 2008-06-23 21:57:55,140 CLOSED
[DEBUG] 2008-06-23 21:58:03,781 Unexpected exception from
SSLEngine.closeInbound().
javax.net.ssl.SSLException: Inbound closed before receiving peer's
close_notify: possible truncation attack?
at com.sun.net.ssl.internal.ssl.Alerts.getSSLException(Alerts.java:190)
at
com.sun.net.ssl.internal.ssl.SSLEngineImpl.fatal(SSLEngineImpl.java:1366)
at
com.sun.net.ssl.internal.ssl.SSLEngineImpl.fatal(SSLEngineImpl.java:1334)
at
com.sun.net.ssl.internal.ssl.SSLEngineImpl.closeInbound(SSLEngineImpl.java:1273)
at org.apache.mina.filter.ssl.SslHandler.destroy(SslHandler.java:155)
at
org.apache.mina.filter.ssl.SslFilter.sessionClosed(SslFilter.java:386)
at
org.apache.mina.common.DefaultIoFilterChain.callNextSessionClosed(DefaultIoFilterChain.java:369)
at
org.apache.mina.common.DefaultIoFilterChain.access$900(DefaultIoFilterChain.java:40)
at
org.apache.mina.common.DefaultIoFilterChain$EntryImpl$1.sessionClosed(DefaultIoFilterChain.java:808)
at
org.apache.mina.common.DefaultIoFilterChain$HeadFilter.sessionClosed(DefaultIoFilterChain.java:589)
at
org.apache.mina.common.DefaultIoFilterChain.callNextSessionClosed(DefaultIoFilterChain.java:369)
at
org.apache.mina.common.DefaultIoFilterChain.fireSessionClosed(DefaultIoFilterChain.java:364)
at
org.apache.mina.common.IoServiceListenerSupport.fireSessionDestroyed(IoServiceListenerSupport.java:223)
at
org.apache.mina.common.AbstractPollingIoProcessor.removeNow(AbstractPollingIoProcessor.java:342)
at
org.apache.mina.common.AbstractPollingIoProcessor.remove(AbstractPollingIoProcessor.java:312)
at
org.apache.mina.common.AbstractPollingIoProcessor.access$700(AbstractPollingIoProcessor.java:43)
at
org.apache.mina.common.AbstractPollingIoProcessor$Worker.run(AbstractPollingIoProcessor.java:708)
at
org.apache.mina.util.NamePreservingRunnable.run(NamePreservingRunnable.java:51)
at
java.util.concurrent.ThreadPoolExecutor$Worker.runTask(ThreadPoolExecutor.java:885)
at
java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:907)
at java.lang.Thread.run(Thread.java:619)
[ INFO] 2008-06-23 21:58:03,781 CLOSED
[ INFO] 2008-06-23 17:37:07,862 CREATED
[ INFO] 2008-06-23 17:37:07,862 OPENED
[ INFO] 2008-06-23 17:37:07,878 SENT: 220 Service ready for new user.
[ INFO] 2008-06-23 17:37:07,878 RECEIVED: AUTH TLS
[ INFO] 2008-06-23 17:37:07,925 SENT: 234 Command AUTH okay; starting
TLS connection.
[ INFO] 2008-06-23 17:37:09,316 RECEIVED: PBSZ 0
[ INFO] 2008-06-23 17:37:09,316 SENT: 200 Command PBSZ okay.
[ INFO] 2008-06-23 17:37:09,316 RECEIVED: USER ANONYMOUS
[ INFO] 2008-06-23 17:37:09,316 SENT: 331 Guest login okay, send your
complete e-mail address as password.
[ INFO] 2008-06-23 17:37:09,316 RECEIVED: PASS *****
[ INFO] 2008-06-23 17:37:09,316 Anonymous login success -
[EMAIL PROTECTED]
[ INFO] 2008-06-23 17:37:09,316 SENT: 230 User logged in, proceed.
[ INFO] 2008-06-23 17:37:09,316 RECEIVED: SYST
[ INFO] 2008-06-23 17:37:09,316 SENT: 215 UNIX Type: Apache FTP Server
[ INFO] 2008-06-23 17:37:09,316 RECEIVED: FEAT
[ INFO] 2008-06-23 17:37:09,316 SENT: 211-Extensions supported
SIZE
MDTM
REST STREAM
LANG en;zh-tw;ja;is
MLST Size;Modify;Type;Perm
AUTH SSL
AUTH TLS
MODE Z
UTF8
TVFS
MD5
MMD5
211 End
[ INFO] 2008-06-23 17:37:09,316 RECEIVED: OPTS UTF8 ON
[ INFO] 2008-06-23 17:37:09,316 SENT: 200 Command OPTS okay.
[ INFO] 2008-06-23 17:37:09,332 RECEIVED: CWD /
[ INFO] 2008-06-23 17:37:09,332 SENT: 250 Directory changed to /
[ INFO] 2008-06-23 17:37:09,332 RECEIVED: PWD
[ INFO] 2008-06-23 17:37:09,332 SENT: 257 "/" is current directory.
[ INFO] 2008-06-23 17:37:10,895 RECEIVED: QUIT
[DEBUG] 2008-06-23 17:37:10,911 Unexpected exception from
SSLEngine.closeInbound().
javax.net.ssl.SSLException: Inbound closed before receiving peer's
close_notify: possible truncation attack?
at
com.sun.net.ssl.internal.ssl.Alerts.getSSLException(Alerts.java:190)
at
com.sun.net.ssl.internal.ssl.SSLEngineImpl.fatal(SSLEngineImpl.java:1366)
at
com.sun.net.ssl.internal.ssl.SSLEngineImpl.fatal(SSLEngineImpl.java:1334)
at
com.sun.net.ssl.internal.ssl.SSLEngineImpl.closeInbound(SSLEngineImpl.java:1273)
at org.apache.mina.filter.ssl.SslHandler.destroy(SslHandler.java:155)
at
org.apache.mina.filter.ssl.SslFilter.sessionClosed(SslFilter.java:386)
at
org.apache.mina.common.DefaultIoFilterChain.callNextSessionClosed(DefaultIoFilterChain.java:369)
at
org.apache.mina.common.DefaultIoFilterChain.access$900(DefaultIoFilterChain.java:40)
at
org.apache.mina.common.DefaultIoFilterChain$EntryImpl$1.sessionClosed(DefaultIoFilterChain.java:808)
at
org.apache.mina.common.DefaultIoFilterChain$HeadFilter.sessionClosed(DefaultIoFilterChain.java:589)
at
org.apache.mina.common.DefaultIoFilterChain.callNextSessionClosed(DefaultIoFilterChain.java:369)
at
org.apache.mina.common.DefaultIoFilterChain.fireSessionClosed(DefaultIoFilterChain.java:364)
at
org.apache.mina.common.IoServiceListenerSupport.fireSessionDestroyed(IoServiceListenerSupport.java:223)
at
org.apache.mina.common.AbstractPollingIoProcessor.removeNow(AbstractPollingIoProcessor.java:342)
at
org.apache.mina.common.AbstractPollingIoProcessor.remove(AbstractPollingIoProcessor.java:312)
at
org.apache.mina.common.AbstractPollingIoProcessor.access$700(AbstractPollingIoProcessor.java:43)
at
org.apache.mina.common.AbstractPollingIoProcessor$Worker.run(AbstractPollingIoProcessor.java:708)
at
org.apache.mina.util.NamePreservingRunnable.run(NamePreservingRunnable.java:51)
at
java.util.concurrent.ThreadPoolExecutor$Worker.runTask(ThreadPoolExecutor.java:885)
at
java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:907)
at java.lang.Thread.run(Thread.java:619)
[ INFO] 2008-06-23 17:37:10,911 SENT: 221 Goodbye.
[ INFO] 2008-06-23 17:37:10,911 CLOSED
