Logback filter does not filter messages

Question

I have the following setup with the filter below expecting to filter certain messages. However those messages find their way to the log anyway.
Indeed the error log contains only WARN or ERROR messages as specified in the filter but the other filtering does not work.

I can't figure out what is going on?

<appender name="ROOT_ERROR_FILE" class="ch.qos.logback.core.rolling.RollingFileAppender">
    <file>${LOG_HOME}/main-error.log</file>
    <filter class="logging.LogbackCustomFilter" />
    <rollingPolicy class="ch.qos.logback.core.rolling.TimeBasedRollingPolicy">
      <!-- daily rollover -->
      <fileNamePattern>${LOG_HOME}/main-error-%d{yyyy-MM-dd}.%i.log</fileNamePattern>
      <timeBasedFileNamingAndTriggeringPolicy class="ch.qos.logback.core.rolling.SizeAndTimeBasedFNATP">
          <!-- or whenever the file size reaches 1GB -->
        <maxFileSize>1GB</maxFileSize>
      </timeBasedFileNamingAndTriggeringPolicy>
      <!-- keep 7 days' worth of history -->
      <maxHistory>7</maxHistory>
    </rollingPolicy>
    <encoder>
        <pattern>%date %-5level [%thread] - [%logger] - %msg%n</pattern>
    </encoder>
</appender>

<root level="DEBUG">
    <appender-ref ref="ROOT_FILE" />
    <appender-ref ref="ROOT_ERROR_FILE" />
</root>

Log filter class:

package logging;

import ch.qos.logback.classic.Level;
import ch.qos.logback.classic.spi.ILoggingEvent;
import ch.qos.logback.core.filter.Filter;
import ch.qos.logback.core.spi.FilterReply;

public class LogbackCustomFilter extends Filter<ILoggingEvent> {

    private static final String closedChannelException = "ClosedChannelException";

    private static final String establishedConnectionWasAborted = "An established connection was aborted";

    private static final String connectionResetByPeer = "Connection reset by peer";

    private static final String brokenPipe = "Broken pipe";

    @Override
    public FilterReply decide(ILoggingEvent event) {
        if (event.getLevel().isGreaterOrEqual(Level.WARN)) {
            if (event.getMessage().contains(closedChannelException) ||
                    event.getMessage().contains(establishedConnectionWasAborted) ||
                    event.getMessage().contains(connectionResetByPeer) ||
                    event.getMessage().contains(brokenPipe)) {
                return FilterReply.DENY;
            } else {
                return FilterReply.NEUTRAL;
            }
        } else {
            return FilterReply.DENY;
        }
    }
}

Anyway log is full of "Connection reset by peer" and "Broken pipe" messages, like so:

2018-03-05 21:05:09,933 WARN  [epollEventLoopGroup-2-6] - [io.netty.channel.DefaultChannelPipeline] - An exceptionCaught() event was fired, and it reached at the tail of the pipeline. It usually means the last handler in the pipeline did not handle the exception.
io.netty.channel.unix.Errors$NativeIoException: syscall:read(..) failed: Connection reset by peer

or this:

2018-03-01 10:33:32,239 ERROR [epollEventLoopGroup-2-10] - [handler.duplex.ExceptionHandler] - channel unhandled exception
io.netty.channel.unix.Errors$NativeIoException: writevAddresses(..) failed: Connection reset by peer
    at io.netty.channel.unix.Errors.newIOException(Errors.java:117)
    at io.netty.channel.unix.Errors.ioResult(Errors.java:138)
    at io.netty.channel.unix.FileDescriptor.writevAddresses(FileDescriptor.java:156)
    at io.netty.channel.epoll.AbstractEpollStreamChannel.writeBytesMultiple(AbstractEpollStreamChannel.java:278)
    at io.netty.channel.epoll.AbstractEpollStreamChannel.doWriteMultiple(AbstractEpollStreamChannel.java:505)
    at io.netty.channel.epoll.AbstractEpollStreamChannel.doWrite(AbstractEpollStreamChannel.java:442)
    at io.netty.channel.AbstractChannel$AbstractUnsafe.flush0(AbstractChannel.java:934)
    at io.netty.channel.epoll.AbstractEpollChannel$AbstractEpollUnsafe.epollOutReady(AbstractEpollChannel.java:555)
    at io.netty.channel.epoll.EpollEventLoop.processReady(EpollEventLoop.java:394)
    at io.netty.channel.epoll.EpollEventLoop.run(EpollEventLoop.java:304)
    at io.netty.util.concurrent.SingleThreadEventExecutor$5.run(SingleThreadEventExecutor.java:858)
    at io.netty.util.concurrent.DefaultThreadFactory$DefaultRunnableDecorator.run(DefaultThreadFactory.java:138)
    at java.lang.Thread.run(Thread.java:748)

Answer 1

In the example messages there, the event.getMessage() will return just the first logged line (e.g. "An exceptionCaught() event was fired..." or "channel unhandled exception").

To drill down to the message on the following exception, try such as event.getThrowableProxy().getMessage() .

Naturally often there will be no related exception too - you'll also need allow for event.getThrowableProxy() being null.