Chapter 6: Filter chains

As we have seen, logback has several built-in ways for filtering log requests, including the context-wide filter, logger-level selection rule and appender filters. These provide high performance filtering for the most commonly encountered cases. These filters are largely inspired from Linux ipchains or iptables as they are called in more recent Linux kernels. Logback filters are based on ternary logic allowing them to be assembled or chained together to compose an arbitrarily complex filtering policy.

There are two main types of filters, namely Filter and TurboFilter.

Logback Classic

Filter objects all implement the Filter abstract class. The decide(Object event) method is passed a newly created LoggingEvent object.

Filter chains

This abstract class assumes that filters be organized in a linear chain. Its member field next points to the next filter in the chain, or null if there are no further filters in the chain. Figure 6.1 depicts a sample filter chain consisting of three filters.

Filters are based on ternary logic. The decide(Object event) method of each filter is called in sequence. This method returns one of the enumerations FilterReply.DENY, FilterReply.NEUTRAL or FilterReply.ACCEPT. If the returned value is FilterReply.DENY, then the log event is dropped immediately without consulting the remaining filters. If the value returned is FilterReply.NEUTRAL, then the next filter in the chain is consulted. If there are no further filters to consult, then the logging event is processed normally. If the returned value is FilterReply.ACCEPT, then the logging event is processed immediately skipping the remaining filters.

In logback-classic, Filter objects can only be added to Appender instances. By adding filters to an appender you can filter events by various criteria, such as the contents of the log message, the contents of the MDC, the time of day or any other part of the logging event.

Implementing your own Filter

Creating your own filter is not difficult. All you have to do is extend the Filter abstract class. The only method that you will have to implement is the decide() method, allowing you to contentrate only on the behaviour of your filter.

The next class is all it takes to implement one's own filter. All it does is accept logging events who's message contains the String sample. The filter will give a neutral response to any logging event who's message does not contain this String.

package chapter6;

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

public class SampleFilter extends Filter {

  @Override
  public FilterReply decide(Object eventObject) {
    LoggingEvent event = (LoggingEvent)eventObject;
    
    if (event.getMessage().contains("sample")) {
      return FilterReply.ACCEPT;
    } else {
      return FilterReply.NEUTRAL;
    }
  }
}

What is shown above might be the simplest filter. Like any filter, it can be attached to any appender using the <Filter> element, as shown below:

<configuration>
  <appender name="STDOUT"
    class="ch.qos.logback.core.ConsoleAppender">
    <Filter class="chapter6.SampleFilter" />

    <layout class="ch.qos.logback.classic.PatternLayout">
      <pattern>
        %-4relative [%thread] %-5level %logger - %msg%n
      </pattern>
    </layout>
  </appender>
	
  <root>
    <appender-ref ref="STDOUT" />
  </root>
</configuration>

Thanks to Joran, logback's powerful configuration framework, adding an option to such a filter is very easy. Just add the corresponding getter and setter methods in the class, and you can specify the option's value in an xml element, nested within the filter element.

In case you want to implement a filter that provides different behaviour depending on the result of its test (say, a filter that would accept or deny an event depending on the content of its message), you can extend the AbstractMatcherFilter class. It will provide your filter with two attribute: OnMatch and OnMismatch, that can be configured like any other option.

Logback Filters

As the moment, there are two filters that ship with logback. LevelFilter provides event filtering based on a Level value. It the event's level is equal to the configured level, the filter accepts of denies the event, depending on its configuration. It allows you to choose the behaviour of logback for a precise given level. Here is a sample configuration that uses LevelFilter.

<configuration>
  <appender name="CONSOLE"
    class="ch.qos.logback.core.ConsoleAppender">
    <filter class="ch.qos.logback.classic.filter.LevelFilter">
      <level>INFO</level>
      <onMatch>ACCEPT</onMatch>
      <onMismatch>DENY</onMismatch>
    </filter>
    <layout class="ch.qos.logback.classic.PatternLayout">
      <pattern>
        %-4relative [%thread] %-5level %logger{30} - %msg%n
      </pattern>
    </layout>
  </appender>
  <root>
    <level value="DEBUG" />
    <appender-ref ref="CONSOLE" />
  </root>
</configuration>

The second filter that ships with logback is ThresholdFilter. It is also based on level value, but acts as a threshold to deny any request whose level is not equal or greater to the configured level. A sample use of the ThresholdFilter is shown below.

<configuration>
  <appender name="CONSOLE"
    class="ch.qos.logback.core.ConsoleAppender">
    <filter class="ch.qos.logback.classic.filter.ThresholdFilter">
      <level>INFO</level>
    </filter>
    <layout class="ch.qos.logback.classic.PatternLayout">
      <pattern>
        %-4relative [%thread] %-5level %logger{30} - %msg%n
      </pattern>
    </layout>
  </appender>
  <root>
    <level value="DEBUG" />
    <appender-ref ref="CONSOLE" />
  </root>
</configuration>

Evaluator Filters

A special category of filters ships with logback. The EvaluatorFilter objects use an EventEvaluator to decide wether to accept or deny the request. This allows unprecedented flexibility in the way that you can affect the logging event's filtering.

Creating a customized filter that makes use of EventEvaluator objects works the same way as seen previously, except that one must extend the EvaluatorFilter class, instead of the Filter or AbstractMatcherFilter classes.

Event Evaluators

Events evaluators allow the user to enter java expressions, using components of a logging event, and to check each logging event against the compiled expression.

Let's see a sample configuration.

<configuration>

  <appender name="STDOUT"
    class="ch.qos.logback.core.ConsoleAppender">
    <filter class="ch.qos.logback.core.filter.EvaluatorFilter">
      <evaluator name="myEval">
        <expression>message.contains("billing")</expression>
      </evaluator>
      <OnMismatch>NEUTRAL</OnMismatch>
      <OnMatch>DENY</OnMatch>
    </filter>
    <layout class="ch.qos.logback.classic.PatternLayout">
      <pattern>
        %-4relative [%thread] %-5level %logger - %msg%n
      </pattern>
    </layout>
  </appender>

  <root>
    <level value="INFO" />
    <appender-ref ref="STDOUT" />
  </root>
</configuration>

The bold part in the previous configuration adds an EvaluatorFilter to a ConsoleAppender. An EventEvaluator is then given to the filter. The expression element contains a recognizable java expression. Notice that the message variable is defined implicitly. Logback provides access to the internal components of a logging event and lets the user build her expression at will.

The implicit variables available to the EventEvaluator are described below:

The behaviour of the filter is also defined by its OnMatch and OnMismatch options. The configuration specifies thanks to these elements the replies that the EvaluatorFilter must give once its expression has been evaluated. The example above returns the value FilterReply.ACCEPT when the message of the logging event contains the String important. If important is not contained in the message, then the filter lets the next filter evaluate this logging event.

Let us see an example of EvaluatorFilter. The FilterEvents class issues ten logging requests, numbered from 0 to 9.

First, let us run the FilterEvents class with a configuration that does not contain any filters. This can be done by issuing the following command:

java chapter6.FilterEvents src/main/java/chapter6/basicConfiguration.xml

All requests will be displayed, as shown below:

0    [main] INFO  chapter6.FilterEvents - logging statement 0
0    [main] INFO  chapter6.FilterEvents - logging statement 1
0    [main] INFO  chapter6.FilterEvents - logging statement 2
0    [main] DEBUG chapter6.FilterEvents - logging statement 3
0    [main] INFO  chapter6.FilterEvents - logging statement 4
0    [main] INFO  chapter6.FilterEvents - logging statement 5
0    [main] ERROR chapter6.FilterEvents - billing statement 6
0    [main] INFO  chapter6.FilterEvents - logging statement 7
0    [main] INFO  chapter6.FilterEvents - logging statement 8
0    [main] INFO  chapter6.FilterEvents - logging statement 9

Suppose that we want to get rid of the billing information. We can use an EvaluatorFilter configured as follows:

<configuration>
  ...
  <filter class="ch.qos.logback.core.filter.EvaluatorFilter">
    <evaluator name="myEval">
      <expression>message.contains("billing")</expression>
    </evaluator>
    <OnMismatch>NEUTRAL</OnMismatch>
    <OnMatch>DENY</OnMatch>
  </filter>
  ...
</configuration>

This filter will deny any logging event whose message contains the String billing. If we run the FilterEvents class again, we obtain the following output:

0    [main] INFO  chapter6.FilterEvents - logging statement 0
0    [main] INFO  chapter6.FilterEvents - logging statement 1
0    [main] INFO  chapter6.FilterEvents - logging statement 2
0    [main] DEBUG chapter6.FilterEvents - logging statement 3
0    [main] INFO  chapter6.FilterEvents - logging statement 4
0    [main] INFO  chapter6.FilterEvents - logging statement 5
0    [main] INFO  chapter6.FilterEvents - logging statement 7
0    [main] INFO  chapter6.FilterEvents - logging statement 8
0    [main] INFO  chapter6.FilterEvents - logging statement 9

TurboFilters

TurboFilter objects all extend the TurboFilter abstract class. Like the usual filters, they use ternary logic to return their evaluation of the logging event.

Overall, they work much like the previously mentionned filters. However, there are two main differences between Filter and TurboFilter objects.

TurboFilter objects are tied to the logging context. Hence, they are called not only when a given appender is used, but each and every time a logging request is issued. Their scope is wider than appender-attached filters.

More importantly, they are called before the LoggingEvent object creation. Their decision is made based on some of the logging event's components. They require no logging event instanciation, nor any other treatement to provide their filtering functionnalities. They are much more performant than the usual Filter objects.

Implementing your own TurboFilter

To create your own TurboFilter component, just extend the TurboFilter abstract class. As previously, when implementing a custumized filter object, developing a custom TurboFilter only ask that one implement the decide() method. In the next example, we create a slightly more complex filter:

package chapter6;

import org.slf4j.Marker;
import org.slf4j.MarkerFactory;

import ch.qos.logback.classic.Level;
import ch.qos.logback.classic.Logger;
import ch.qos.logback.classic.turbo.TurboFilter;
import ch.qos.logback.core.spi.FilterReply;

public class SampleTurboFilter extends TurboFilter {

  String marker;
  Marker markerToAccept;

  @Override
  public FilterReply decide(Marker marker, Logger logger, Level level,
      String format, Object[] params, Throwable t) {

    if (!isStarted()) {
      return FilterReply.NEUTRAL;
    }

    if ((markerToAccept.equals(marker))) {
      return FilterReply.ACCEPT;
    } else {
      return FilterReply.NEUTRAL;
    }
  }

  public String getMarker() {
    return marker;
  }

  public void setMarker(String markerStr) {
    this.marker = markerStr;
  }

  @Override
  public void start() {
    if (marker != null && marker.trim().length() > 0) {
      markerToAccept = MarkerFactory.getMarker(marker);
      super.start(); 
    }
  }
}

The TurboFilter above accepts events that contain a specific marker. If said marker is not found, then the filter passes the responsability to the next filter in the chain.

To allow more flexibility, the marker that will be tested can be specified in the configuration file. Hence the getter and setter methods. We also implemented the start() method, to check that the option has been specified during the configuration process.

Here is a sample configuration that makes use of the newly created TurboFilter.

<configuration>
  <turboFilter class="chapter6.SampleTurboFilter">
    <Marker>sample</Marker>
  </turboFilter>

  <appender name="STDOUT"
    class="ch.qos.logback.core.ConsoleAppender">
    <layout class="ch.qos.logback.classic.PatternLayout">
      <pattern>
        %-4relative [%thread] %-5level %logger - %msg%n
      </pattern>
    </layout>
  </appender>

  <root>
    <appender-ref ref="STDOUT" />
  </root>
</configuration>

Logback classic ships with several TurboFilter classes ready for use. The MDCFilter check the presence of a given value in the MDC. On the other hand, MarkerFilter checks for the presence of a specific marker associated with the logging request.

Here is a sample configuration, using both MDCFilter and MarkerFilter.

<configuration>

  <turboFilter class="ch.qos.logback.classic.turbo.MDCFilter">
    <MDCKey>username</MDCKey>
    <Value>sebastien</Value>
    <OnMatch>ACCEPT</OnMatch>
  </turboFilter>
	
  <turboFilter class="ch.qos.logback.classic.turbo.MarkerFilter">
    <Marker>billing</Marker>
    <OnMatch>DENY</OnMatch>
  </turboFilter>

  <appender name="console" class="ch.qos.logback.core.ConsoleAppender">
    <layout class="ch.qos.logback.classic.PatternLayout">
      <Pattern>%date [%thread] %-5level %logger - %msg%n</Pattern>
  </layout>
  </appender>

  <root>
    <level value="info"/>
    <appender-ref ref="console" />
  </root>  
</configuration>

You can see this configuration in action by issuing the following command:

java chapter6.FilterEvents src/main/java/chapter6/turboFilters.xml

As we've seen previously, the FilterEvents class creates 10 logging requests, each with its number from 0 to 9. All of the requests are of level INFO, just like the configured overall level, except for two requests. The 3rd request, is a DEBUG level corresponding to the key username. This obviously satisfies the first TurboFilter declared in the previous configuration file. The 6th request, a ERROR level request, which is issued along with the billing marker, matches the second TurboFilter.

Here is the output of the previous command:

2006-12-04 15:17:22,859 [main] INFO  chapter6.FilterEvents - logging statement 0
2006-12-04 15:17:22,875 [main] INFO  chapter6.FilterEvents - logging statement 1
2006-12-04 15:17:22,875 [main] INFO  chapter6.FilterEvents - logging statement 2
2006-12-04 15:17:22,875 [main] DEBUG chapter6.FilterEvents - logging statement 3
2006-12-04 15:17:22,875 [main] INFO  chapter6.FilterEvents - logging statement 4
2006-12-04 15:17:22,875 [main] INFO  chapter6.FilterEvents - logging statement 5
2006-12-04 15:17:22,875 [main] INFO  chapter6.FilterEvents - logging statement 7
2006-12-04 15:17:22,875 [main] INFO  chapter6.FilterEvents - logging statement 8
2006-12-04 15:17:22,875 [main] INFO  chapter6.FilterEvents - logging statement 9

One can see that the 3rd request, who should not be displayed if we only followed the overall INFO level, appears anyway, because it matched the first TurboFilter requirements and was accepted.

On the other hand, the 6th request, that is a ERROR level request should have been displayed. But it satisfied the second TurboFilter whose OnMatch option is set to DENY. Thus, the 6th request was not displayed.

Logback Access

Logback access benefits from most of the possibilities available to the classic module. Filter objects are available and work in the same way as their classic counterpart. They handle access' implementation of logging events: AccessEvent. Thus, a customized filter for logback access is follows strictly the same rules than one for the classic module, except for the event implemenation recieved as a parameter. On the other hand, TurboFilter objects are not available to the access module.

Filters

EvaluatorFilter objects, with their expressions, are available to the access module. However, the variables that one can use to build an expression are different. Only the AccessEvent object can be used, by inserting the event variable in the expression. Although less wide than its classic counterpart, the access evaluation filter is just as powerfull. All the request and response components are reachable from the event variable.

Here is a sample configuration that will ensure that any 404 error will be displayed:

<configuration>

  <appender name="STDOUT"
    class="ch.qos.logback.core.ConsoleAppender">
    <filter class="ch.qos.logback.core.filter.EvaluatorFilter">
      <evaluator name="myEval">
        <expression>event.getStatusCode() == 404</expression>
      </evaluator>
      <OnMismatch>NEUTRAL</OnMismatch>
      <OnMatch>ACCEPT</OnMatch>
    </filter>
    <layout class="ch.qos.logback.access.PatternLayout">
      <pattern>
        %h %l %u %t %r %s %b
      </pattern>
    </layout>
  </appender>

  <appender-ref ref="STDOUT" />
</configuration>

We might imagine a slightly more complex use of filters to ensure the display of 404 errors, but to prevent polluting the output with endless accesses to CSS files. Here is what such a configuration would look like:

<configuration>

  <appender name="STDOUT"
    class="ch.qos.logback.core.ConsoleAppender">
    <filter class="ch.qos.logback.core.filter.EvaluatorFilter">
      <evaluator name="Eval404">
        <expression>event.getStatusCode() == 404</expression>
      </evaluator>
      <OnMismatch>NEUTRAL</OnMismatch>
      <OnMatch>ACCEPT</OnMatch>
    </filter>
    <filter class="ch.qos.logback.core.filter.EvaluatorFilter">
      <evaluator name="EvalCSS">
        <expression>event.getRequestURI().contains("css")</expression>
      </evaluator>
      <OnMismatch>NEUTRAL</OnMismatch>
      <OnMatch>DENY</OnMatch>
    </filter>
    <layout class="ch.qos.logback.access.PatternLayout">
      <pattern>
        %h %l %u %t %r %s %b
      </pattern>
    </layout>
  </appender>

  <appender-ref ref="STDOUT" />
</configuration>