mina-ftpserver-users mailing list archives

Site index · List index
Message view « Date » · « Thread »
Top « Date » · « Thread »
From m..@kanjisoft.com
Subject User disconnect causes thousands of session closes
Date Tue, 27 Feb 2018 02:25:16 GMT
Hello,

I've been struggling with an issue we've been having with the Mina FTP 
Server, 1.06 and the Apache Mina 2.13.

The problem is that when cameras sensors with embedded FTP clients 
disconnect from the FTP server, tens of thousands of session closes are 
called. Concurrently thousands of session creates are issued - this may 
be the sensors trying to log back in, but I'm not sure about that. 
Ultimately, there is a huge amount of open TCP connections in CLOSE_WAIT 
state, and the server has to be restarted.

Here is the log from the point of the disconnect:

org.apache.ftpserver.listener.nio.FtpHandlerAdapter - inputClosed. 
Session: 5
2018-02-23 14:29:36.687 [NioProcessor-29] WARN  
org.apache.ftpserver.listener.nio.FtpHandlerAdapter - inputClosed. 
Session: 4
2018-02-23 14:29:36.696 [NioProcessor-27] WARN  
org.apache.ftpserver.listener.nio.FtpHandlerAdapter - inputClosed. 
Session: 2
2018-02-23 14:29:37.185 [NioProcessor-30] WARN  
org.apache.ftpserver.impl.DefaultFtpHandler - Default FTP Handler, 
sessionClosed, Session: 5
2018-02-23 14:29:37.185 [pool-19-thread-35] INFO  
org.apache.ftpserver.listener.nio.FtpLoggingFilter - SENT: 200 Command 
TYPE okay.

2018-02-23 14:29:37.185 [NioProcessor-29] WARN  
org.apache.ftpserver.impl.DefaultFtpHandler - Default FTP Handler, 
sessionClosed, Session: 4
2018-02-23 14:29:37.185 [NioProcessor-27] WARN  
org.apache.ftpserver.impl.DefaultFtpHandler - Default FTP Handler, 
sessionClosed, Session: 2
2018-02-23 14:29:37.186 [NioProcessor-30] WARN  
org.apache.ftpserver.ftpletcontainer.impl.DefaultFtpletContainer - 
onDisconnect
2018-02-23 14:29:37.186 [NioProcessor-29] WARN  
org.apache.ftpserver.ftpletcontainer.impl.DefaultFtpletContainer - 
onDisconnect
2018-02-23 14:29:37.186 [NioProcessor-27] WARN  
org.apache.ftpserver.ftpletcontainer.impl.DefaultFtpletContainer - 
onDisconnect
2018-02-23 14:29:37.186 [NioProcessor-30] WARN  
org.apache.ftpserver.impl.DefaultFtpHandler - Default FTP Handler - 
closing session, stats not null
2018-02-23 14:29:37.186 [NioProcessor-29] WARN  
org.apache.ftpserver.impl.DefaultFtpHandler - Default FTP Handler - 
closing session, stats not null
2018-02-23 14:29:37.186 [NioProcessor-27] WARN  
org.apache.ftpserver.impl.DefaultFtpHandler - Default FTP Handler - 
closing session, stats not null
2018-02-23 14:29:37.186 [NioProcessor-30] WARN  
org.apache.ftpserver.impl.DefaultFtpStatistics - setLogout, decrementing 
currLogins before: 4, sessionId: 5
2018-02-23 14:29:37.186 [NioProcessor-30] WARN  
org.apache.ftpserver.impl.DefaultFtpStatistics - setLogout, decrementing 
currLogins after: 3, sessionId: 5
2018-02-23 14:29:37.186 [NioProcessor-30] WARN  
org.apache.ftpserver.impl.DefaultFtpStatistics - setLogout, user 
decrement, sessionId: 5, username: TOP
2018-02-23 14:29:37.186 [NioProcessor-30] WARN  
org.apache.ftpserver.impl.DefaultFtpStatistics - totalLogins before: 1, 
sessionId: 5
2018-02-23 14:29:37.187 [NioProcessor-30] WARN  
org.apache.ftpserver.impl.DefaultFtpStatistics - totalLogins after: 0, 
sessionId: 5
2018-02-23 14:29:37.187 [NioProcessor-30] WARN  
org.apache.ftpserver.impl.DefaultFtpStatistics - decrementing from 
inetAddress: /192.168.1.1, sessionId 5
2018-02-23 14:29:37.187 [NioProcessor-30] WARN  
org.apache.ftpserver.impl.DefaultFtpStatistics - inetAddr login count 
before: 1, sessionId 5
2018-02-23 14:29:37.187 [NioProcessor-30] WARN  
org.apache.ftpserver.impl.DefaultFtpStatistics - inet address login 
count after: 0, sessionId 5
2018-02-23 14:29:37.187 [NioProcessor-30] WARN  
org.apache.ftpserver.impl.DefaultFtpHandler - Default FTP Handler - 
callingSetCloseConnection


Subsequently, it seems to go into a loop of closing sessions, causing 
the total logins to become negative:

2018-02-23 14:29:37.208 [NioProcessor-30] WARN  
org.apache.ftpserver.ftpletcontainer.impl.DefaultFtpletContainer - 
onDisconnect
2018-02-23 14:29:37.209 [NioProcessor-29] WARN  
org.apache.ftpserver.impl.DefaultFtpStatistics - 
notifyingClosedConnection,  sessionId: 4
2018-02-23 14:29:37.209 [NioProcessor-27] WARN  
org.apache.ftpserver.ftpletcontainer.impl.DefaultFtpletContainer - 
onDisconnect
2018-02-23 14:29:37.209 [NioProcessor-30] WARN  
org.apache.ftpserver.impl.DefaultFtpHandler - Default FTP Handler - 
closing session, stats not null
2018-02-23 14:29:37.209 [NioProcessor-29] WARN  
org.apache.ftpserver.impl.DefaultFtpHandler - Default FTP Handler - 
Statistics login and connection count decreased due to session close
2018-02-23 14:29:37.209 [NioProcessor-27] WARN  
org.apache.ftpserver.impl.DefaultFtpHandler - Default FTP Handler - 
closing session, stats not null
2018-02-23 14:29:37.209 [NioProcessor-30] WARN  
org.apache.ftpserver.impl.DefaultFtpStatistics - setLogout, decrementing 
currLogins before: -47, sessionId: 5
2018-02-23 14:29:37.209 [NioProcessor-29] WARN  
org.apache.ftpserver.listener.nio.FtpHandlerAdapter - inputClosed. 
Session: 4
2018-02-23 14:29:37.209 [NioProcessor-30] WARN  
org.apache.ftpserver.impl.DefaultFtpStatistics - setLogout, decrementing 
currLogins after: -48, sessionId: 5
2018-02-23 14:29:37.209 [NioProcessor-29] WARN  
org.apache.ftpserver.impl.DefaultFtpHandler - Default FTP Handler, 
sessionClosed, Session: 4
2018-02-23 14:29:37.209 [NioProcessor-30] WARN  
org.apache.ftpserver.impl.DefaultFtpStatistics - setLogout, user 
decrement, sessionId: 5, username: TOP
2018-02-23 14:29:37.209 [NioProcessor-29] WARN  
org.apache.ftpserver.ftpletcontainer.impl.DefaultFtpletContainer - 
onDisconnect
2018-02-23 14:29:37.209 [NioProcessor-30] WARN  
org.apache.ftpserver.impl.DefaultFtpStatistics - totalLogins before: 
-18, sessionId: 5
2018-02-23 14:29:37.209 [NioProcessor-29] WARN  
org.apache.ftpserver.impl.DefaultFtpHandler - Default FTP Handler - 
closing session, stats not null
2018-02-23 14:29:37.209 [NioProcessor-30] WARN  
org.apache.ftpserver.impl.DefaultFtpStatistics - totalLogins after: -19, 
sessionId: 5
2018-02-23 14:29:37.209 [NioProcessor-30] WARN  
org.apache.ftpserver.impl.DefaultFtpStatistics - decrementing from 
inetAddress: /192.168.1.1, sessionId 5
2018-02-23 14:29:37.209 [NioProcessor-30] WARN  
org.apache.ftpserver.impl.DefaultFtpStatistics - inetAddr login count 
before: -18, sessionId 5
2018-02-23 14:29:37.209 [NioProcessor-30] WARN  
org.apache.ftpserver.impl.DefaultFtpStatistics - inet address login 
count after: -19, sessionId 5
2018-02-23 14:29:37.209 [NioProcessor-30] WARN  
org.apache.ftpserver.impl.DefaultFtpHandler - Default FTP Handler - 
callingSetCloseConnection
2018-02-23 14:29:37.209 [NioProcessor-29] WARN  
org.apache.ftpserver.impl.DefaultFtpStatistics - setLogout, decrementing 
currLogins before: -48, sessionId: 4
2018-02-23 14:29:37.209 [NioProcessor-29] WARN  
org.apache.ftpserver.impl.DefaultFtpStatistics - setLogout, decrementing 
currLogins after: -49, sessionId: 4
2018-02-23 14:29:37.209 [NioProcessor-29] WARN  
org.apache.ftpserver.impl.DefaultFtpStatistics - setLogout, user 
decrement, sessionId: 4, username: RF
2018-02-23 14:29:37.209 [NioProcessor-29] WARN  
org.apache.ftpserver.impl.DefaultFtpStatistics - totalLogins before: 
-12, sessionId: 4
2018-02-23 14:29:37.209 [NioProcessor-29] WARN  
org.apache.ftpserver.impl.DefaultFtpStatistics - totalLogins after: -13, 
sessionId: 4
2018-02-23 14:29:37.209 [NioProcessor-29] WARN  
org.apache.ftpserver.impl.DefaultFtpStatistics - decrementing from 
inetAddress: /192.168.1.4, sessionId 4
2018-02-23 14:29:37.209 [NioProcessor-29] WARN  
org.apache.ftpserver.impl.DefaultFtpStatistics - inetAddr login count 
before: -12, sessionId 4
2018-02-23 14:29:37.209 [NioProcessor-29] WARN  
org.apache.ftpserver.impl.DefaultFtpStatistics - inet address login 
count after: -13, sessionId 4
2018-02-23 14:29:37.209 [NioProcessor-29] WARN  
org.apache.ftpserver.impl.DefaultFtpHandler - Default FTP Handler - 
callingSetCloseConnection
2018-02-23 14:29:37.209 [NioProcessor-27] WARN  
org.apache.ftpserver.impl.DefaultFtpStatistics - setLogout, decrementing 
currLogins before: -49, sessionId: 2
2018-02-23 14:29:37.209 [NioProcessor-27] WARN  
org.apache.ftpserver.impl.DefaultFtpStatistics - setLogout, decrementing 
currLogins after: -50, sessionId: 2
2018-02-23 14:29:37.209 [NioProcessor-27] WARN  
org.apache.ftpserver.impl.DefaultFtpStatistics - setLogout, user 
decrement, sessionId: 2, username: LB
2018-02-23 14:29:37.209 [NioProcessor-27] WARN  
org.apache.ftpserver.impl.DefaultFtpStatistics - totalLogins before: 
-18, sessionId: 2
2018-02-23 14:29:37.209 [NioProcessor-27] WARN  
org.apache.ftpserver.impl.DefaultFtpStatistics - totalLogins after: -19, 
sessionId: 2
2018-02-23 14:29:37.209 [NioProcessor-27] WARN  
org.apache.ftpserver.impl.DefaultFtpStatistics - decrementing from 
inetAddress: /192.168.1.5, sessionId 2
2018-02-23 14:29:37.209 [NioProcessor-27] WARN  
org.apache.ftpserver.impl.DefaultFtpStatistics - inetAddr login count 
before: -18, sessionId 2
2018-02-23 14:29:37.

I've attached a log from which the posted segments came.

Any idea of what could be causing this? I'm really stuck on this.

Mime
View raw message