Access log with logback, Jetty and Tomcat

Introduction

Logback was designed as a modular framework from the start. Making logback-core reusable under different circumstances, without much recoding was one of our main goals. As such, logback-access builds on top of logback-core. It fully integrates with Servlet containers such as Jetty or Tomcat to provide HTTP-access log functionality.

Logback-access and Tomcat

To use logback-access with Tomcat, after downlading the logback distribution, place the files logback-core-VERSION.jar and logback-access-VERSION.jar under $TOMCAT_HOME/server/lib directory, where $TOMCAT_HOME is the folder where you have installed Tomcat. We have tested logback-access module with Tomcat version 5.5.20.

LogbackValve

The ch.qos.logback.access.tomcat.LogbackValve class extends Tomcat's ValveBase class. This class is used to allow external components to be integrated into Tomcat.

To configure Tomcat in order to use LogbackValve, add the following lines to the tomcat server configuration file, namely $TOMCAT_HOME/conf/server.xml:

<Valve className="ch.qos.logback.access.tomcat.LogbackValve"/>

This line is usually nested within an Engine element.

By default, LogbackValve looks for a configuration file called logback-access.xml, in the same folder where server.xml is located, that is in $TOMCAT_HOME/conf/. This configuration file contains directives for configuring logback-access components. It is used to specify appenders where the logging requests will be their format, and filters. Please refer to the section discussing this subject further below.

Logback-access and Jetty

After downlading the logback distribution, place the files logback-core-VERSION.jar and logback-access-VERSION.jar under $JETTY_HOME/lib directory, where $JETTY_HOME is the folder where you have installed Jetty. We have tested logback-access module with Jetty version 6.0 as well as 6.1.

Logback's implementation of org.mortbay.jetty.RequestLog interface

The ch.qos.logback.access.jetty.RequestLogImpl class implements jetty's RequestLog interface. Jetty delegates the manament of access logging functionality to implementations of this interface.

In logback, a logging destination is called an "appender" which can be directly attached to a ch.qos.logback.access.jetty.RequestLogImpl instance.

In order to configure Jetty to use logback-access's RequestLogImpl, please add the following lines to jetty's main configuration file, namely $JETTY_HOME/etc/jetty.xml:

<Ref id="requestLog">
  <Set name="requestLog">
    <New id="requestLogImpl"
      class="ch.qos.logback.access.jetty.RequestLogImpl">
    </New>
  </Set>
</Ref>

By default, RequestLogImpl looks for a logback configuration file called logback-access.xml, in the same folder where jetty.xml is located. This configuration file contains directives for configuring logback components. Among others, you can specify the appenders where the logging requests will be sent, and their format.

As long the path is specified, you can place the logback configuration file in any location. Here is another example of jetty configuration file, including the path to the logback-access.xml configuration file.

<Ref id="requestLog">
  <Set name="requestLog">
    <New id="requestLogImpl"
      class="ch.qos.logback.access.jetty.RequestLogImpl">
    </New>
    <Set name="fileName">path/to/myaccess.xml</Set>
  </Set>
</Ref>

Logback-access configuration

Altough similar, the logback-access.xml file is slightly different than its more common counterpart in logback-classic. Appenders and Layouts are declared the exact same way. However, in the access module there is no notion of loggers and consequently logger elements are disallowed in logback-access configuraiton files.

Example 1: basic logback-access configuration

Here is a small but fully functional logback-access.xml configuration file:

<configuration>
  <appender name="STDOUT"
    class="ch.qos.logback.core.ConsoleAppender">
    <layout
      class="ch.qos.logback.access.PatternLayout">
      <Pattern>%h %l %u %user %date "%r" %s %b</Pattern>
    </layout>
  </appender>

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

It declares a ConsoleAppender which prints its output on the console. The ConsoleAppender contains a PatternLayout object responsible to format this output. The log format is specied by the "%h %l %u %user %date "%r" %s %b" pattern which incidentally corresponds to Common Log Format (CLF). This format is recognized by log analysers such as Analog or AWStats.

The words "common" or "clf" are interpreted as shorthands for the said pattern. Thus, the following are all equivalent:

<Pattern>%h %l %u %user %date "%r" %s %b</Pattern>
<Pattern>common</Pattern>
<Pattern>clf</Pattern>

The so called "combined" format is also widely recognized. It is defined as the '%h %l %u %t "%r" %s %b "%i{Referer}" "%i{User-Agent}"' pattern. As a facilitator, you can use the "combined" as a shorthand. Thus, the following directive

<layout class="ch.qos.logback.access.PatternLayout">
  <Pattern>%h %l %u %t "%r" %s %b "%i{Referer}" "%i{User-Agent}"</Pattern>
</layout>

is equivalent to:

<layout class="ch.qos.logback.access.PatternLayout">
  <Pattern>combined</Pattern>
</layout>

Example 2: RollingFileAppender

The configuration file below configures a daily rolling RollingFileAppender. Note that due to the .zip suffix included in the value for FileNamePattern option, the log file are not only rolled daily, but they are also automatically compressed.

<configuration>
  <appender name="FILE"
    class="ch.qos.logback.core.rolling.RollingFileAppender">
    <File>access.log"</File>
    <rollingPolicy
      class="ch.qos.logback.core.rolling.TimeBasedRollingPolicy">
      <FileNamePattern>access.%d{yyyy-MM-dd}.log.zip</FileNamePattern>
    </rollingPolicy>

    <layout class="ch.qos.logback.access.PatternLayout">
      <Pattern">combined</Pattern">
    </layout>
  </appender>
 
  <appender-ref ref="FILE" />
</configuration>

These two examples should give you an idea of the possibilities offered by logback-access. In principle, most if not all of the features available in logback-classic are also available in logback-access.

PatternLayout

Logback-access ships with an http-specific implementation of PatternLayout. For detailled instructions on how to use the PatternLayout, please refer to the corresponding chapter of the logback manual.

JMX Components

Logback-access integrates with JMX servers to publish information about its components.

Both RequestLogImpl and LogbackValve expose data and can be updated via JMX. A special filter, covered further down this document, publishes statistical data on access logs.

Configuring Tomcat for JMX

In order to configure Tomcat for JMX, please add the following lines to the $TOMCAT_HOME/bin/catalina.sh shell script (or its MS Windows equivalent):

CATALINA_OPTS="-Dcom.sun.management.jmxremote"
CATALINA_OPTS="$CATALINA_OPTS -Dcom.sun.management.jmxremote.ssl=false"
CATALINA_OPTS="$CATALINA_OPTS -Dcom.sun.management.jmxremote.authenticate=false"

After you launch Tomcat, you can access the MBeans exposed by Tomcat throught he JConsole application, which can be started with the following command:

jconsole

If you prefer MX4J to access your components via a web-based interface, here is a short summary of the steps to follow. After downloading MX4J, place the mx4j-impl.jar file in the $TOMCAT_HOME/bin/ directory, and the mx4j-tools.jar file in the $TOMCAT_HOME/common/lib/ directory. Once that is done, add the following lines to the $TOMCAT_HOME/bin/catalina.sh shell script:

<!-- at the beginning of the file -->
CATALINA_OPTS="-Dcom.sun.management.jmxremote"
CATALINA_OPTS="$CATALINA_OPTS -Djavax.management.builder.initial=mx4j.server.MX4JMBeanServerBuilder"

<!-- in the "Add on extra jar files to CLASSPATH" section -->
CLASSPATH="$CLASSPATH":"$CATALINA_HOME"/bin/mx4j-impl.jar

Finally, declare a new Connector in the $TOMCAT_HOME/conf/server.xml file:

<Connector port="8050" 
  handler.list="mx"
  mx.enabled="true" 
  mx.httpHost="localhost" 
  mx.httpPort="8082" 
  protocol="AJP/1.3" />

Once Tomcat is started, you should be able to reach your JMX components by pointing your browser at the following URL:

http://localhost:8082/

Configuring Jetty

Configuring Jetty to publish JMX components requires a few modifications to the $JETTY_HOME/etc/jetty.xml configuration file. Here are the elements that need to be added:

<Call id="MBeanServer" class="java.lang.management.ManagementFactory" name="getPlatformMBeanServer"/>
<!-- initialize the Jetty MBean container -->
<Get id="Container" name="container">
  <Call name="addEventListener">
    <Arg>
      <New class="org.mortbay.management.MBeanContainer">
        <Arg><Ref id="MBeanServer"/></Arg>
        <Set name="managementPort">8082</Set>
        <Call name="start" />
      </New>
    </Arg>
  </Call>
</Get>

Once Jetty is started with this configuration, all available components can be reviewed at:

http://localhost:8082/

Logback-access' RequestLogImpl should be available, including its start() and stop() methods.

CountingFilter

With the help of CountingFilter class, logback-access can provide statistical data about access to the web-server.

If you wish to make use of CountingFilter, you to declare it, as any other filter:

<configuration>
  <filter class="ch.qos.logback.access.filter.CountingFilter">
    <name>countingFilter</name>
  </filter>

  <appender name="STDOUT"
    class="ch.qos.logback.core.ConsoleAppender">
    <layout class="ch.qos.logback.access.PatternLayout">
      <Pattern>%h %l %u %t \"%r\" %s %b</Pattern>
    </layout>
  </appender>

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

This component registers itself to the JMX server and publishes the statistical data such as averages by minute, by hour, by day, by week, and by month. Last month's, week's, day's, hour's and minute's counts as well as the total number of access are also exposed.

TeeFilter

For debugging purposes, it is often handy to capture the client request as well as the server response as is. The TeeFilter was desgined precisely for this purpose.

The TeeFilter is a regular servlet filter. Like other servlet filters, it needs to be declared in your web-application's web.xml file:

We have tested TeeFilter to the best of our ability. However, since it duplicates the input stream of the request and the output stream of the response, it may interfere with your application. For large input or output, it will add masurable latency. Although we have already fixed all currently known bugs, TeeFilter has broken otherwise correctly behaving applications. Thus, in case of doubt, do not hesitate to disabl TeeFilter.

Once TeeFilter is installed, the PatternLayout converters fullRequest and fullResponse will output the full contents of the request and respectively the response.

Here is a sample logback-access.xml configuration file which will output the full contents of the request and response on the console.

Few clicks accessing the logback-demo application configured as outlined above, yeilds: