mina-ftpserver-users mailing list archives

Site index · List index
Message view « Date » · « Thread »
Top « Date » · « Thread »
From Jeroen Cranendonk <j.p.cranend...@tursiops.org>
Subject SSL logout problem ?
Date Mon, 23 Jun 2008 20:09:43 GMT
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 - anon@localhost
[ 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 - anon@localhost
[ 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 - 
flashfxp-user@flashfxp.com

[ 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

 









Mime
View raw message