You are viewing a plain text version of this content. The canonical link for it is here.
Posted to ftpserver-users@mina.apache.org by mc...@kanjisoft.com on 2018/02/27 02:25:16 UTC
User disconnect causes thousands of session closes
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.