Log4j Logging Guide


This article explains logging and eXist-db's use of Log4j.


Logging may seem like a less important part of an application. After all, it consumes resources: programmer time, increasing class file size, CPU cycles, etc. All while doing nothing to provide end-user functionality. However, logging is an important part of any substantial body of software and is absolutely critical in enterprise software. A big issue with the use of the logging system when troubleshooting is that it changes to the log configuration require a restart. Yet, userss are often extremely reluctant to restart their production servers. Log4j is the most powerful Java-based logging library available today. It provides a many features to address such concerns.

Introducing Log4j

Log4j is based on the following core concepts:

  • Each log event is issued by a hierarchically named logger, e.g. xx.method.server.httpgw which can correspond to Java class names.

  • All log events have an associated severity level:




    Very low-level debugging “execution is here” debugging/troubleshooting messages.


    Messages of interest to those debugging or troubleshooting (with greater importance than trace messages). Probably only meaningful to developers


    General informational messages. Understandable by and/or of interest to non-developers as well.


    Warnings of potential problems


    Error conditions


    Fatal error conditions, For instance a shut down, a likely crash or something equally severe

  • Logging is controlled either via a Log4j configuration file. Exist-db's main log configuration file responsible for the exist.log is located at exist/etc/log4j2.xml. To issue log events programmatically you must acquire a logger by name and specify a log message and its severity level (and optionally a Throwable where applicable).

Based on these core concepts, Log4j provides a powerful set of functionalities:

Many “appender” choices

Each log event may be output to zero or more “appenders”. These are generalized output pipes, e.g. System.out/err, JDBC, syslog etc.

When outputing to a file various options for log rolling are available. For instance daily creation of new log files, segmenting when a given file size is reached, and externally controlled log rotation. These appenders can be run synchronously to the threads generating the log events or as separate asynchronous queues.

Flexible layout options

Each appender can specify a layout, for formatting the log message. The administrator can choose from HTML, XML, and text formats – including the flexible PatternLayout, which allows selecting the data to include (timestamps, originating thread, logger name, etc.).

Hierarchical logger configuration

Administrators can configure log event cutoff levels and appenders for entire branches of the hierarchical logger tree.

For instance, by adding a console appender targeting System.out to the root logger, all Log4j output will go to System.out. One can configure the overall cutoff level as error at the root logger level so that only error and fatal messages are output, unless otherwise specified. One could then configure the xx.method logger to have an info level cutoff and an appender to capture all output to a specified file (in addition to System.out). These xx.method settings would then affect all loggers whose names begin with xx.method. (e.g. xx.method.server.httpgw).

Log viewers

Various free and commercial products provide specialized viewing capabilities for Log4j logs. Apache provides a very useful Log4j log viewer Chainsaw.

For more information visit the Log4j website website.

Java 1.4 and higher’s java.util.logging API is very similar to Log4j’s. However Log4j is much more powerful in a number of critical areas.

In conjunction with our JMX MBeans for Log4j, one can also:

  • Dynamically examine and reconfigure the Log4j configuration for the duration of the process via a JMX console.

  • Have all processes using a Log4j configuration file periodically check its modification date and automatically re-load it upon any change.

  • Force an immediate reload from a configuration file via a JMX console.

Configuring Log4j

The $EXIST_HOME/etc/log4j2.xml configuration file controls Log4j’s behavior. Log files are written $EXIST_HOME/logs/. The configuration file is used mainly to set a given level of log output for loggers. Without such configuration only ERROR and FATAL log events will show up. Therefore you have to change the configuration to see trace, debug, info, or warn log events in the Log4j output.

To turn on a given logging level for all loggers, find the Log4j.root property and change its priority value to the desired level. For instance:

  <priority value="debug"/>
  <appender-ref ref="exist.core"/>

Change the priority level to info to see informational messages:

  <priority value="info"/>
  <appender-ref ref="exist.core"/>

This will result in a cacophony of log output, so you’ll generally want to adjust the logging level to a more specific level. For instance:

<category name="org.exist.security" additivity="false">
  <priority value="info"/>
  <appender-ref ref="exist.security"/>

This sets the org.exist.security logger’s level to info.

Note that doing this causes the default log level of all org.exist.security loggers to be set to info. For example, the level of the org.exist.security.xacml logger would also be set to info, unless of course the level for this logger is specified explicitly.

Checking the Log4j configuration file is done periodically so changes may go unnoticed for a few minutes.

To make temporary changes to the Log4j configuration without changing the configuration files, use JMX MBeans:

  1. Start jconsole

    jconsole is located in the Java SDK’s bin directory. You can either double-click on it or run it from the command line.

  2. Select the target JVM

    jconsole will list the Java processes running on your machine under the current user, which have been configured to allow local JMX connections.

  3. Navigate to the Logging node in the MBean tree:

    • Select the MBeans tab.

    • Expand the right folder.

    • In the servlet engine expand the WebAppContext folder and the folder named after your web app.

    • Select the Logging node (which should now be visible).

  4. Perform desired operations and/or modifications:

    • To change the configuration file check interval, change the ConfigurationCheckInterval attribute to the desired number of seconds. Note that this change will apply only for the duration of the JVM process unless you select the Loader node and its save operation.

    • To force an immediate reload of the configuration file, press the reconfigure button on the operations tab.

    • To examine other aspects of the configuration and make temporary changes, press the registerLoggers button on the operation tab. Expand the Logging tree node and examine/operate upon its children.

Using Log4j in Java

  1. Acquire a logger:

    import org.apache.logging.log4j.LogManager; import org.apache.logging.log4j.Logger; … private Logger logger = LogManager.getLogger("xx.method.server.httpgw");


    • This is a somewhat time-consuming operation and should be done in constructors of relatively long-lived objects or in static initializers.

    • Many classes can separately acquire a logger using the same logger name. They will all end up with their own reference to the same shared logger object.

  2. Use the logger:

    logger.info( "Something I really wanted to say" );


    • info() is just one of Logger’s methods for issuing Log4j log events. It implicitly assigns the event a severity level of info and does not specify a Throwable. Logger methods for issuing log events include:

      public void trace(Object message); 
          public void trace(Object message, Throwable t); 
          public void debug(Object message); 
          public void debug (Object message, Throwable t); 
          public void info(Object message); 
          public void info(Object message, Throwable t); 
          public void warn(Object message); 
          public void warn(Object message, Throwable t); 
          public void error(Object message); 
          public void error(Object message, Throwable t); 
          public void fatal(Object message); 
          public void fatal(Object message, Throwable t);
    • Note that in each case the message is an Object, not a String. If (and only if) Log4j decides to output the given log event (based on the configuration), it will render this object as a String (essentially via toString()).

You emit log events with appropriate log levels to appropriately named loggers. The Log4j configuration determines which appenders (if any) should output/record the event and how this should be done.

Converting existing logging code to Log4j

Conversion of existing logging code to Log4j can be as simple as replacing System.out.println() calls, etc, with use of the Log4j API. There are a few special considerations worth noting.

Dealing with Legacy Properties

You'll have to check the functionality of existing logging properties:

  • For instance, properties specifying output files can be removed, as customers can now siphon Log4j output to specific files via Log4j’s configuration files.

  • To preserve well-known logging properties regardless, given the following example code:

    private static final boolean VERBOSE_SERVER;
         XXProperties properties = XXProperties.getLocalProperties();
         VERBOSE_SERVER = properties.getProperty("xx.method.verboseServer", false);
       if ( VERBOSE_SERVER )
         System.out.println( "some message" );

    The static portions above can be left as is and the remainder changed to:

    import org.apache.log4j.Level;
       import org.apache.log4j.Logger;
       // place VERBOSE_SERVER declaration and static block from above here
       private static final Logger  serverLogger =
                                         Logger.getLogger( "xx.method.server" );
         if ( VERBOSE_SERVER )
           serverLogger.setLevel( Level.ALL );
       serverLogger.debug( "some message" );

    This example assumes that output from the given Log4j logger should be completely enabled when the existing property is set.

    One can also use this:

         if ( !serverLogger.isDebugEnabled() )
           serverLogger.setLevel( Level.DEBUG );

    This causes the existing property to enable output from the given Log4j logger up through the severity level, debug.

    This approach to preserving existing “enabling” properties a partal fix. The intended minimum log verbosity is ensured upon initialization but cannot be reset via the property without a restart. The ability to change the log-level on the fly or make fine grained log-level adjustments is only available through the Log4j configuration.

Conditional Computation of Data for Logging

When log messages are constructed conditionallys:

if ( VERBOSE_SERVER )  // static final boolean
     // various computations and assignment

The if block may include System.out.println()’s or the results of the block may be used in later System.out.println()’s. The code is intended to avoid computations and assignments unless their results are used.

You can now use one of Log4j’s is*Enabled() methods for this. For example:

if ( serverLogger.isDebugEnabled() )
     // various computations and assignment that will only be used
     // if serverLogger.debug() calls

The Log4j Logger class provides a set of methods for this:

public boolean isTraceEnabled();
   public boolean isDebugEnabled();
   public boolean isInfoEnabled();
   public Boolean isEnabledFor(Level);

Tips and Tricks

This section contains useful hints based on our user's experiences.


Carefully select appropriate logger names

Logger names should be meaningful and facilitate hierarchical configuration by administrators. Use a namespace prefix, either xx or com.xxx to avoid collision with logger names from 3rd-party libraries and customizations.

For instance, one might have xx.method.server for general logging related to various low-level aspects of the method server and xx.method.server.timing for logging specifically related to the method timing. Use Java class and package names where these make sense.

Document your logger if appropriate

If appropriate, document your logger in /xxx/src_web/loggers.html. For instance when the output is of interest to your customer. The logger should be documented (by name) in /xxx/src_web/loggers.html (which ends up in xxx’s codebase in an installation).

Select appropriate levels for log events

See the table above for an outline of levels and their intended usage. informaltable

Don’t go overboard with the Log4j configuration files

Log4j provides a great deal of ease and flexibility in its configuration. Its log viewers also make it easy to merge log data from multiple Log4j logs or filter out the data of interest from a general purpose log. Given this it makes little sense to provide a complex Log4j configuration file. The customer can change the configuration to have more or less specific log outputs as dictated by their needs and desires.

Adjust log levels in Log4j configuration files where appropriate

By default only error and fatal log messages are created. This generates relatively "quiet" logs that only alert administrators to issues. There are however sometimes log messages classified as informational that should be output at this log level as well. Such as periodic information about process health summaries. Simply enable info level debig ouput in the for the logger in question.

Don’t include redundant data in log messages

Log4j includes current time, thread name, logger name, evernt level, etc information in a standard fashion so it is easily interpreted by log viewers. Inclusion of any of these pieces of information in the log message itself is therefore redundant.

make use of AttributeListWrapper where appropriate

For some particularly significant logs it is important to have even more control, including:

  • To select which attributes should be included in a given log message

  • To specify the order of these attributes

  • To specify the formatting of these attributes (e.g. comma delimited, with or without attribute names, etc)

Examples of such cases include request access and periodic statistics logging.

There is a re-usable utility for just this purpose, xx.jmx.core.AttributeListWrapper.


The operation of Log4j’s Logger class’s logging methods for issuing log events can be summed up as:

public void  log( Level level, Object message )
  if ( isEnabledFor( level ) )
    String  string = render( messasge );
    for ( Appender appender : myAppenders )
      appender.output( string );
  • render() is simply a toString() call, except when message is an instance of a class for which a specialized render has been registered.

  • trace(), debug(), info(), warn(), error(), etc, call log() with the appropriate level.

Note that Log4j's documentation claims that isEnabledFor(), and the Logger.is*Enabled() method are extremely fast. Therefore log() should take very little time as well (unless isEnabledFor() returns true).

Given this, a few additional performance tips and tricks:

Don’t reacquire a logger on each usage

The LogR.getLogger() (and underlying Logger.getLogger()) calls are relatively expensive. One should acquire these objects once per class (or once per instance of a class) and re-use them in subsequent logging calls.

Don’t assume a log’s level cannot change

One of the big advantages of Log4j is that administrators can easily change the level setting of any logger at any time. One can however easily undo this by following conventions common in existing logging code, e.g.:

static boolean  LOG_ENABLED = logger.isInfoEnabled ();
public void someMethod()
  if ( LOG_ENABLED )
    logger.info( … );

Logger’s isEnabledFor() and is*Enabled() routines are fast enough to allow calling them more frequently in order to obtain the benefits of dynamically configurable logging levels.

Don’t check whether the log level is enabled before every log call

Do not write code as:

if ( logger.isDebugEnabled() )
  logger.debug( "Some constant string" );

This results in essentially no savings when isDebugEnabled() is true. It also makes the code more verbose and harder to read. Instead do:

logger.debug( "Some constant string" );
Do avoid doing additional work for logging unless the logger is enabled

Assume the last example looked like:

if ( logger.isDebugEnabled() )
  logger.debug( "Object " + object.getDisplayIdentity() + 
                " is being deleted" );

Then the isDebugEnabled() check should be performed. In this case, two string concatenations and a potentially (somewhat) expensive method call can be saved when the logger is not debug enabled. See the “Conditional Computation of Data for Logging” section above for another example of this pattern.

On the other hand, this technique should not be used when you are all but certain the given logger will be enabled. Usually this applies only to log events being emitted with an error or fatal level. In this case saving times for the few cases in which someone has actually disabled this level of logging is not worthwhile.

Another technique to avoid unnecessary work is to leverage the fact that Logger’s take objects, not strings, as arguments. Thus one might write:

SomeClass  someObj = new SomeClass(…);
logger.info( someObj );

Here one will pay for the construction of someObj in all cases but will only pay for someObj.toString() when logging is enabled for info-level log events. Thus if very little work is done in the constructor and most is done in toString() this avoids doing work except when necessary. AttributeListWrapper (see above) is an example of this technique.

Hoist log level checks outside of very tight loops

For cases where a given log level will usually not be enabled, for instance for trace and debug log messages, one should avoid repeated checks within a tight loop. For example:

  final boolean  traceEnabled = logger.isTraceEnabled();
  for ( int ii = 0; ii < n; ++ii )
    // do some very quick stuff
    if ( traceEnabled )
      logger.trace( ... );
    // do a little more very quick stuff

Trace level logging is rarely enabled and so in this example checking for this case ahead of time can save us from repeatedly verifying this in a tight loop. This does, however, come at the cost of making it impossible to dynamically enable trace logging for this logger in the middle of this loop. Due to this, this technique should only be used for tight loops where the duration of the execution represented by the loop (and thus the time during which the logging behavior may lag the intended setting) is small.