How could I clean sessions in a Mina FTP server

Question

How could I clean sessions in a Mina FTP server

238 Views Asked by maxence smets At 26 October 2020 at 05:48

I have many logs on my server, server is trying every 10 seconds to reopen sessions which have been not active since hours, that cause exception, making logs full of noise and probably consuming cpu also. Moreover we are still on development stage, we have maybe 1 or 2 users using it for now, that could become horrible quite soon.

2020-10-26T05:38:02.145036437Z 05:38:02.144 [pool-3-thread-1] DEBUG o.a.ftpserver.impl.DefaultFtpHandler - Statistics login and connection count decreased due to session close
2020-10-26T05:38:02.145063194Z 05:38:02.144 [pool-3-thread-1] DEBUG o.a.ftpserver.impl.DefaultFtpHandler - Session closed
2020-10-26T05:38:02.145431444Z 05:38:02.145 [pool-3-thread-1] DEBUG o.a.m.core.filterchain.IoFilterEvent - Event SESSION_CLOSED has been fired for session 127
2020-10-26T05:38:02.145525229Z 05:38:02.145 [pool-3-thread-1] DEBUG o.a.m.core.filterchain.IoFilterEvent - Event SESSION_CLOSED has been fired for session 127
2020-10-26T05:38:07.284970328Z 05:38:07.284 [NioProcessor-1] DEBUG o.a.m.core.filterchain.IoFilterEvent - Firing a SESSION_CREATED event for session 128
2020-10-26T05:38:07.285069189Z 05:38:07.284 [NioProcessor-1] DEBUG o.a.m.core.filterchain.IoFilterEvent - Firing a SESSION_CREATED event for session 128
2020-10-26T05:38:07.285442711Z 05:38:07.284 [NioProcessor-1] INFO  o.a.f.listener.nio.FtpLoggingFilter - CREATED
2020-10-26T05:38:07.285491545Z 05:38:07.285 [NioProcessor-1] DEBUG o.a.m.core.filterchain.IoFilterEvent - Event SESSION_CREATED has been fired for session 128
2020-10-26T05:38:07.285498543Z 05:38:07.285 [NioProcessor-1] DEBUG o.a.m.core.filterchain.IoFilterEvent - Event SESSION_CREATED has been fired for session 128
2020-10-26T05:38:07.285504870Z 05:38:07.285 [NioProcessor-1] DEBUG o.a.m.core.filterchain.IoFilterEvent - Firing a SESSION_OPENED event for session 128
2020-10-26T05:38:07.285510595Z 05:38:07.285 [NioProcessor-1] DEBUG o.a.m.f.e.OrderedThreadPoolExecutor - Adding event SESSION_OPENED to session 128
2020-10-26T05:38:07.285516146Z Queue : [SESSION_OPENED, ]
2020-10-26T05:38:07.285521224Z 
2020-10-26T05:38:07.285526195Z 05:38:07.285 [NioProcessor-1] DEBUG o.a.m.core.filterchain.IoFilterEvent - Event SESSION_OPENED has been fired for session 128
2020-10-26T05:38:07.286082534Z 05:38:07.285 [pool-3-thread-2] DEBUG o.a.m.core.filterchain.IoFilterEvent - Firing a SESSION_OPENED event for session 128
2020-10-26T05:38:07.286112963Z 05:38:07.285 [pool-3-thread-2] DEBUG o.a.m.core.filterchain.IoFilterEvent - Firing a SESSION_OPENED event for session 128
2020-10-26T05:38:07.286220938Z 05:38:07.286 [pool-3-thread-2] INFO  o.a.f.listener.nio.FtpLoggingFilter - OPENED
2020-10-26T05:38:07.287058266Z 05:38:07.286 [pool-3-thread-2] DEBUG o.a.m.core.filterchain.IoFilterEvent - Firing a WRITE event for session 128
2020-10-26T05:38:07.287226034Z 05:38:07.287 [pool-3-thread-2] DEBUG o.a.m.core.filterchain.IoFilterEvent - Firing a WRITE event for session 128
2020-10-26T05:38:07.287457936Z 05:38:07.287 [pool-3-thread-2] DEBUG o.a.m.core.filterchain.IoFilterEvent - Event WRITE has been fired for session 128
2020-10-26T05:38:07.287475036Z 05:38:07.287 [pool-3-thread-2] DEBUG o.a.m.core.filterchain.IoFilterEvent - Firing a WRITE event for session 128
2020-10-26T05:38:07.287482220Z 05:38:07.287 [pool-3-thread-2] DEBUG o.a.m.core.filterchain.IoFilterEvent - Event WRITE has been fired for session 128
2020-10-26T05:38:07.287532062Z 05:38:07.287 [pool-3-thread-2] DEBUG o.a.m.core.filterchain.IoFilterEvent - Event WRITE has been fired for session 128
2020-10-26T05:38:07.287540285Z 05:38:07.287 [pool-3-thread-2] DEBUG o.a.m.core.filterchain.IoFilterEvent - Event SESSION_OPENED has been fired for session 128
2020-10-26T05:38:07.287546236Z 05:38:07.287 [pool-3-thread-2] DEBUG o.a.m.core.filterchain.IoFilterEvent - Event SESSION_OPENED has been fired for session 128
2020-10-26T05:38:07.288078016Z 05:38:07.287 [NioProcessor-1] DEBUG o.a.m.core.filterchain.IoFilterEvent - Firing a MESSAGE_SENT event for session 128
2020-10-26T05:38:07.288147757Z 05:38:07.287 [NioProcessor-1] DEBUG o.a.m.f.e.OrderedThreadPoolExecutor - Adding event MESSAGE_SENT to session 128
2020-10-26T05:38:07.288155468Z Queue : [MESSAGE_SENT, ]
2020-10-26T05:38:07.288160646Z 
2020-10-26T05:38:07.288165669Z 05:38:07.287 [NioProcessor-1] DEBUG o.a.m.core.filterchain.IoFilterEvent - Event MESSAGE_SENT has been fired for session 128
2020-10-26T05:38:07.288171088Z 05:38:07.287 [pool-3-thread-1] DEBUG o.a.m.core.filterchain.IoFilterEvent - Firing a MESSAGE_SENT event for session 128
2020-10-26T05:38:07.288197511Z 05:38:07.287 [pool-3-thread-1] DEBUG o.a.m.core.filterchain.IoFilterEvent - Firing a MESSAGE_SENT event for session 128
2020-10-26T05:38:07.288203626Z 05:38:07.287 [pool-3-thread-1] INFO  o.a.f.listener.nio.FtpLoggingFilter - SENT: 220 Service ready for new user.
2020-10-26T05:38:07.288209545Z 
2020-10-26T05:38:07.288214808Z 05:38:07.287 [pool-3-thread-1] DEBUG o.a.m.core.filterchain.IoFilterEvent - Event MESSAGE_SENT has been fired for session 128
2020-10-26T05:38:07.288220563Z 05:38:07.288 [pool-3-thread-1] DEBUG o.a.m.core.filterchain.IoFilterEvent - Event MESSAGE_SENT has been fired for session 128
2020-10-26T05:38:07.427407740Z 05:38:07.427 [NioProcessor-1] DEBUG o.a.m.core.filterchain.IoFilterEvent - Firing a EXCEPTION_CAUGHT event for session 128
2020-10-26T05:38:07.427475376Z 05:38:07.427 [NioProcessor-1] DEBUG o.a.m.f.e.OrderedThreadPoolExecutor - Adding event EXCEPTION_CAUGHT to session 128
2020-10-26T05:38:07.427484023Z Queue : [EXCEPTION_CAUGHT, ]
2020-10-26T05:38:07.427489058Z 
2020-10-26T05:38:07.427698283Z 05:38:07.427 [NioProcessor-1] DEBUG o.a.m.core.filterchain.IoFilterEvent - Event EXCEPTION_CAUGHT has been fired for session 128
2020-10-26T05:38:07.427782730Z 05:38:07.427 [pool-3-thread-2] DEBUG o.a.m.core.filterchain.IoFilterEvent - Firing a EXCEPTION_CAUGHT event for session 128
2020-10-26T05:38:07.427790076Z 05:38:07.427 [NioProcessor-1] DEBUG o.a.m.core.filterchain.IoFilterEvent - Firing a SESSION_CLOSED event for session 128
2020-10-26T05:38:07.427796398Z 05:38:07.427 [pool-3-thread-2] DEBUG o.a.m.core.filterchain.IoFilterEvent - Firing a EXCEPTION_CAUGHT event for session 128
2020-10-26T05:38:07.427802439Z 05:38:07.427 [NioProcessor-1] DEBUG o.a.m.f.e.OrderedThreadPoolExecutor - Adding event SESSION_CLOSED to session 128
2020-10-26T05:38:07.427808664Z Queue : [SESSION_CLOSED, ]
2020-10-26T05:38:07.427814360Z 
2020-10-26T05:38:07.427819828Z 05:38:07.427 [NioProcessor-1] DEBUG o.a.m.core.filterchain.IoFilterEvent - Event SESSION_CLOSED has been fired for session 128
2020-10-26T05:38:07.428728452Z 05:38:07.428 [pool-3-thread-2] WARN  o.a.f.listener.nio.FtpLoggingFilter - EXCEPTION :
2020-10-26T05:38:07.428764670Z java.io.IOException: Connection reset by peer
2020-10-26T05:38:07.428771912Z  at java.base/sun.nio.ch.FileDispatcherImpl.read0(Native Method)
2020-10-26T05:38:07.428777993Z  at java.base/sun.nio.ch.SocketDispatcher.read(SocketDispatcher.java:39)
2020-10-26T05:38:07.428784116Z  at java.base/sun.nio.ch.IOUtil.readIntoNativeBuffer(IOUtil.java:276)
2020-10-26T05:38:07.428789728Z  at java.base/sun.nio.ch.IOUtil.read(IOUtil.java:245)
2020-10-26T05:38:07.428794896Z  at java.base/sun.nio.ch.IOUtil.read(IOUtil.java:223)
2020-10-26T05:38:07.428800059Z  at java.base/sun.nio.ch.SocketChannelImpl.read(SocketChannelImpl.java:358)
2020-10-26T05:38:07.428805539Z  at org.apache.mina.transport.socket.nio.NioProcessor.read(NioProcessor.java:317)
2020-10-26T05:38:07.428811093Z  at org.apache.mina.transport.socket.nio.NioProcessor.read(NioProcessor.java:45)
2020-10-26T05:38:07.428841999Z  at org.apache.mina.core.polling.AbstractPollingIoProcessor.read(AbstractPollingIoProcessor.java:683)
2020-10-26T05:38:07.428847689Z  at org.apache.mina.core.polling.AbstractPollingIoProcessor.process(AbstractPollingIoProcessor.java:659)
2020-10-26T05:38:07.428853186Z  at org.apache.mina.core.polling.AbstractPollingIoProcessor.process(AbstractPollingIoProcessor.java:648)
2020-10-26T05:38:07.428858551Z  at org.apache.mina.core.polling.AbstractPollingIoProcessor.access$600(AbstractPollingIoProcessor.java:68)
2020-10-26T05:38:07.428863900Z  at org.apache.mina.core.polling.AbstractPollingIoProcessor$Processor.run(AbstractPollingIoProcessor.java:1120)
2020-10-26T05:38:07.428875186Z  at org.apache.mina.util.NamePreservingRunnable.run(NamePreservingRunnable.java:64)
2020-10-26T05:38:07.428881142Z  at java.base/java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1128)
2020-10-26T05:38:07.428886314Z  at java.base/java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:628)
2020-10-26T05:38:07.428891594Z  at java.base/java.lang.Thread.run(Thread.java:834)
2020-10-26T05:38:07.429795488Z 05:38:07.428 [pool-3-thread-2] ERROR o.a.ftpserver.impl.DefaultFtpHandler - Exception caught, closing session
2020-10-26T05:38:07.429821103Z java.io.IOException: Connection reset by peer
2020-10-26T05:38:07.429828386Z  at java.base/sun.nio.ch.FileDispatcherImpl.read0(Native Method)
2020-10-26T05:38:07.429834020Z  at java.base/sun.nio.ch.SocketDispatcher.read(SocketDispatcher.java:39)
2020-10-26T05:38:07.429839502Z  at java.base/sun.nio.ch.IOUtil.readIntoNativeBuffer(IOUtil.java:276)
2020-10-26T05:38:07.429844754Z  at java.base/sun.nio.ch.IOUtil.read(IOUtil.java:245)
2020-10-26T05:38:07.429850585Z  at java.base/sun.nio.ch.IOUtil.read(IOUtil.java:223)
2020-10-26T05:38:07.429856024Z  at java.base/sun.nio.ch.SocketChannelImpl.read(SocketChannelImpl.java:358)
2020-10-26T05:38:07.429860853Z  at org.apache.mina.transport.socket.nio.NioProcessor.read(NioProcessor.java:317)
2020-10-26T05:38:07.429866286Z  at org.apache.mina.transport.socket.nio.NioProcessor.read(NioProcessor.java:45)
2020-10-26T05:38:07.429870913Z  at org.apache.mina.core.polling.AbstractPollingIoProcessor.read(AbstractPollingIoProcessor.java:683)
2020-10-26T05:38:07.429875852Z  at org.apache.mina.core.polling.AbstractPollingIoProcessor.process(AbstractPollingIoProcessor.java:659)
2020-10-26T05:38:07.429880723Z  at org.apache.mina.core.polling.AbstractPollingIoProcessor.process(AbstractPollingIoProcessor.java:648)
2020-10-26T05:38:07.429885822Z  at org.apache.mina.core.polling.AbstractPollingIoProcessor.access$600(AbstractPollingIoProcessor.java:68)
2020-10-26T05:38:07.429891372Z  at org.apache.mina.core.polling.AbstractPollingIoProcessor$Processor.run(AbstractPollingIoProcessor.java:1120)
2020-10-26T05:38:07.429896246Z  at org.apache.mina.util.NamePreservingRunnable.run(NamePreservingRunnable.java:64)
2020-10-26T05:38:07.429917791Z  at java.base/java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1128)
2020-10-26T05:38:07.429923473Z  at java.base/java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:628)
2020-10-26T05:38:07.429928562Z  at java.base/java.lang.Thread.run(Thread.java:834)
2020-10-26T05:38:07.429933608Z 05:38:07.428 [pool-3-thread-2] DEBUG o.a.m.core.filterchain.IoFilterEvent - Event EXCEPTION_CAUGHT has been fired for session 128
2020-10-26T05:38:07.429939237Z 05:38:07.429 [pool-3-thread-2] DEBUG o.a.m.core.filterchain.IoFilterEvent - Event EXCEPTION_CAUGHT has been fired for session 128
2020-10-26T05:38:07.429944867Z 05:38:07.429 [pool-3-thread-2] DEBUG o.a.m.core.filterchain.IoFilterEvent - Firing a SESSION_CLOSED event for session 128
2020-10-26T05:38:07.429951263Z 05:38:07.429 [pool-3-thread-2] DEBUG o.a.m.core.filterchain.IoFilterEvent - Firing a SESSION_CLOSED event for session 128
2020-10-26T05:38:07.429956216Z 05:38:07.429 [pool-3-thread-2] INFO  o.a.f.listener.nio.FtpLoggingFilter - CLOSED
2020-10-26T05:38:07.429961575Z 05:38:07.429 [pool-3-thread-2] DEBUG o.a.ftpserver.impl.DefaultFtpHandler - Closing session
2020-10-26T05:38:07.429966855Z 05:38:07.429 [pool-3-thread-2] DEBUG o.a.ftpserver.impl.DefaultFtpHandler - Statistics login and connection count decreased due to session close
2020-10-26T05:38:07.429972502Z 05:38:07.429 [pool-3-thread-2] DEBUG o.a.ftpserver.impl.DefaultFtpHandler - Session closed
2020-10-26T05:38:07.430422717Z 05:38:07.429 [pool-3-thread-2] DEBUG o.a.m.core.filterchain.IoFilterEvent - Event SESSION_CLOSED has been fired for session 128
2020-10-26T05:38:07.430470189Z 05:38:07.429 [pool-3-thread-2] DEBUG o.a.m.core.filterchain.IoFilterEvent - Event SESSION_CLOSED has been fired for session 128

I have seen, thats probably an issue from the client side not closing properly its session, but I want to make the backend bulletproof for that, as I won't manage all clients in the future.

Original Q&A

There are 1 best solutions below

**maxence smets** · Answer 1 · 2020-10-26T11:46:04.037000

Found the solution, actually I was regularly scanned by a bot. I just filtered the ip address in my security gateway, and it was done . I could find that ip, by overriding DefaultFtpLet's onConnect method and here just log info :

public class MyFtpPlet extends DefaultFtplet {
    public FtpletResult onConnect(FtpSession session) throws FtpException,
        IOException {
    log.info("onConnect");
    if (session != null) {
        if (session.getClientAddress() != null) {
            log.info(session.getClientAddress().toString());
        }
        if (session.getConnectionTime() != null) {
            log.info(session.getConnectionTime().toString());
        }
        if (session.getLastAccessTime() != null) {
            log.info(session.getLastAccessTime().toString());
        }
        if (session.getUser() != null) {
            log.info(session.getUser().getName());
        }
    }
    return null;
   }
[...]
}

How could I clean sessions in a Mina FTP server

There are 1 best solutions below

Related Questions in JAVA

Related Questions in APACHE-MINA

Related Questions in APACHE-FTPSERVER

Trending Questions

Popular # Hahtags

Popular Questions