Java Logging Frameworks Part 1

Java Logging Frameworks Explained - Part 1

Java logging frameworks are almost as prolific as Java web frameworks; but while one can understand that there are lots of ways of building web applications, it is rather harder to understand why there are so many frameworks for logging in Java; after all logging is simply sending a message to log is it not?

Currently I am aware of at least 5 logging frameworks in widespread use. It appears that, after a brief period of dormancy,  logging frameworks are again experiencing a  population explosion.  The list below is not necessarily comprehensive but I am aware of the following and is roughly in chronological order:
 

FrameworkAcronymType*Description
log4jlog4jLoggingThe progenitor of all logging frameworks
java.util.loggingjulLoggingThe usurper. Jul attempted to take log4j and add it to the Java JDK as the standard implementation for logging.
Jakarta Commons LoggingjclMetaThe failed abstractor. jcl attempted to allow the underlying logging framework to be determined by the system administrator deploying the application. i.e at runtime rather than compile time. Due implementation issues which meant there ware lots of classloader problems the framework has been largely abandoned by developer and is mainly used in legacy libraries and applications
Simple Logging Façade for Javaslf4jMetaThe great abstractor. Some would call slf4j the saviour of Java logging. It is largely successful at abstracting away the underlying logging framework, allowing for it to be change at runtime with relative ease. Another aspect of slf4j is that it can be used to bridge 3rd party libraries and applications using different logging frameworks to use the preferred framework of the system administrator.
logbacklogbackLoggingThe return of the jedi - This is the successor to the great progenitor log4j. Looks promising.
jboss loggingjboss-loggingLogging/MetaThe new kid no-one likes - This is a logging framework introduced by Redhat and the JBoss project. Although the framework does add features such as internationalisation that others do not have, it seem more like an attempt by Redhat to have a logging framework that they control rather than work with existing frameworks. 

* Logging means this is a logging framework implementation. 
* Meta means this is an abstraction, meant to be used as a layer about the actual logging framework used. (I will hopefully explain the difference better in a later article.)


I am no software palaeontologist so the above characterisations and genealogy may be wrong. In addition I have not spent the time to master all of the above frameworks, especially not JBoss logging, so let me know where I am wrong.

PS: There are even more than I thought. Check out this list. (http://java-source.net/open-source/logging)

Java Logging Complexity

The logging landscape can seem inordinately convoluted to a person coming to logging for the first time. There are, however, a host of issues that make application logging complex:

  • Filtering of log messages to extract messages that meet system admin defined criteria,
  • Writing of a single log message to multiple destination,
  • Formatting log messages for different log back-ends such as text files, databases, email etc.
  • Ensuring logging has minimal impact on performance,
  • Integrating 3r party libraries with their own logging requirements,
  • Allowing for the runtime selection of logging frameworks,
  • Allowing for runtime configuration of the selected logging framework,
  • Allowing for the reconfiguration of logging without restarting applications,
  • Distributed applications  have special needs such as logging to a centralised log server, tracing user sessions or transactions across application layers and physical servers,
  • Web servers make use of multiple threads, with user sessions being distributed across available threads over the duration of a session,

Initially, I was hoping to write a succinct overview of Java logging for people who just want to get the basics, so as to be able to get on with the real problem of coding your applications. This seemed all the more necessary since I have never found an article  on the Internet I could simple point people to, to read to get up to speed.  Sadly, soon after starting this endeavour I realised just why this was the case. The number of frameworks and the evolution of logging makes this impossible. It is easy for someone to get lost in the nitty-gritty of framework differences, differences between framework versions and meta frameworks to abstract logging frameworks, without a concise conceptual model being explained before hand.

So I have decided to break this article up into several parts. I am not sure how far I will get with further articles on Java logging, it will all depend on time and motivation on my part. This first article will attempt to develop a conceptual model for application logging.

Application Logging System - Conceptual Model

The conceptual model for Java logging presented is not necessarily complete and will not reflect any concrete logging framework completely. Rather it is an abstraction of the concepts that are common to nearly all the available logging frameworks. Once you have a model it will be easier to understand what a particular implementation is doing. For the beginner to understand an application logging system its best to get a grip of the following concepts.
 

ConceptDescription
log managerthe log manager is the access point into the logging system. It is a static, globally accessible object. It can be used to create or retrieve loggers, handler, filters etc
log message/log entrythe message your application wishes to have processed by the logging system,
severity/levelthe severity of the error that is being logged. Severity/levels are also used as thresholds for loggers and appenders for accepting messages.
loggera "postbox" for log messages, the logger will process your applications message,
appenders/handlersThe target, or destination, for where the log message is persisted/saved after acceptance & formatting, like a file, database, operating system
filtersa criteria used by loggers and appenders to determine if the message sent should be processed  or not,
formatters/renderers/layoutshow you application message should be transformed for "display" before being sent to the appender/handler

Log Message/Log Entry

A log message or entry is fairly easy to wrap your mind around. It is the message you want to log. At the most simple level it will be a text message but may be more complex with place holders and parameters needing to be replaced by the framework. Still not that difficult to get to grips with, so lets move on.

Severity/Level

This is the classification of the message being logged. Severities are organised in a hierarchy from critical messages at the top, to informational messages at the bottom. i.e  messages lower down the hierarchy include or are a super set of the severity/levels above. So warn includes fatal, error and warn messages.
 

Venn diagramme of
severity levels

The exact number and names of the severity levels differ from framework to framework. The above diagram is based on the log4j levels describe below:
 

Level/SeverityDescription
FATALThe FATAL level designates very severe error events that will presumably lead the application to abort.
ERRORThe ERROR level designates error events that might still allow the application to continue running.
WARNThe WARN level designates potentially harmful situations.
INFOThe INFO level designates informational messages that highlight the progress of the application at coarse-grained level
DEBUGThe DEBUG Level designates fine-grained informational events that are most useful to debug an application.

Severity/levels are also used by loggers and appenders to filter messages that they wish to process. I.E Loggers and appenders/handlers can stipulate they are only interested in messages of a certain level and below.

Logger

A Logger can be thought of as a message queue or postbox for log messages to be sent to for processing. A logger is identify by a string name which applications use to select their target logger for a message.  A logger is assigned a name when it is created A logger can be configured and created via an API or configuration file. A logger is also configured as to how it processes messages that have been sent to it. This is the reason the queue is called a logger and not a log. A log is a final destination such as a file, email or database etc to which the message can be persisted. A logger, on the other hand, simply accepts the log message for processing.

One of the important properties of a Logger is that it has a parent logger. Each logger has a single parent and is part of a tree structure of loggers. The topmost logger or root logger is called, unsurprisingly, the root logger. The root logger always exists so it is also the default logger if not other loggers are created.  

When a logger is created it parent is automatically determined from the logger name. The logger name reflects the hierarchy of the logger with a "." being used to show the relationship between a parent and the child. i.e "myapp.service.paymentprocessing" has the parents "myapp.service" which in turn has the parent "myapp".

myapp
myapp.service
myapp.service.paymentprocessing

Although the name of a logger can be any string, it is convention to use the classname of your object as the logger name. This makes it easier later to find the name of the logger you would like to configure, additionally it is allows for a great deal of flexibility when configuring your logging after your application has been developed.

When a logger such as za.co.jumpingbean.training.studentservice is created, usually by a call to a method of the form

 Logger mylogger = Logger.getLogger("za.co.jumpingbean.training.studentservice"); or
 Logger mylogger = Logger.getLogger(za.co.jumpingbean.training.studentservice.class),

the intermediate loggers are not automatically created. i.e the parent logger for mylogger will be the root logger and not "za.co.jumpingbean.training", unless that logger is also created, either programmatically, at compile time, or in configuration files at run time.

Another important thing to note about Loggers and their hierarchy is that messages bubble up the hierarchy. So once it has been processed by the target logger the message is sent to the parent for processing. This behaviour can be modified at runtime or compile time so that once it is processed by the target logger it is not processed further up the stack. This also means that if a lower level logger discards a message it will not be handled by ancestor loggers. Messages can be discarded by loggers because the message is above its severity or level setting or because its filters have determined it does not meet the required criteria for logging. It should be noted that parent loggers may discard a message and thereby stop its walk up the logger hierarchy.

(Log4j will ignore parent loggers severity threshold for propagated log messages, but java.util.logging will stop processing if the level/severity threshold of a parent logger is not met. JUL however ignores any filters on parent loggers for propagated messages. Does this make your head hurt? It sure makes mine hurt. These are the nuances that make Java logging a pain in the butt.)

Logger also inherit settings from their parent if not set explicitly. Log4j loggers inherit their parent severity levels and appenders. In java.util.logging loggers inherit their severity level from their parents and since messages propagated up the hierarchy are handled by the parent loggers, the in effect inherit their parent loggers as well.

Appenders or handlers

The appender or handler takes messages it  received from a logger and writes it to its back-end.  Different appenders/handlers write log messages to:

  • the console,
  • a file,
  • operating system logging system e.g. syslog,
  • database,
  • email,
  • etc

Each type of appender can be configured, for example file appenders allow for the location an name of the log file to be set, while email appenders allow for the receiving email address to be set. Appenders are assigned to loggers. Appenders can be assigned to multiple loggers.

Filters

Filters allows for more fine grain control over what messages are accepted. Filters are attached to handlers in most logging frameworks but some also allow for appenders to be attached to a logger. Filters need to be implemented in code but can be assigned at runtime via configuration files.

Formatters or renderers

A formatter formats a given log message before writing it to the appender. Mostly this consists of taking the binary object and converting it to a string representation or inserting information such as time stamps, class names, thread id etc. These much like formatter/renderers/layouts this conceptual entity is easy to understand.
 

Interaction between the components of the conceptual model

These various components interact to build the desired logging system. The interaction between the components can be done in code or via configuration files. The diagram below attempts to show the interaction between the components. The sequence diagram below shows how the components interact to write to the appenders.


click image to enlarge
Sequence diagram showing interaction with model
components

The above sequence diagram is fairly easy to follow. The complexity really comes when understanding how log message propagation works. The diagram below attempts to explain this. I am no graphic artists and it took all of my limited skill to get this done so it will have to do. I hope it makes things clearer.

Logger hierarchy diagram
What the above shows is three log messages of different severities arriving at the  "za.co.jumpingbean.training.studentservice" logger. There are three loggers in the hierarchy. The "za.co.jumpingbean.training.studentservice" logger 'skips' one parent, that has not been created by code or in configuration files, namely "za.co.jumpingbean.training" and has the parent "za.co.jumpingbean". This logger, "za.co.jumpingebean", has been explictly created in code or a configuration file. This is to illustrate that intermediate loggers do not need to exist but if they are created later they will be inserted at the appropriate position in the tree hierarchy by the log manager.

Each logger has a severity threshold set. Note that if a logger does not have an  severity threshold set, it will inherit its parent threshold. Two of the loggers have handlers or appenders assigned namely "File Appender A" and "Console Appender". There is a third appender "File Appender B" which has been created by not assigned to any logger. This may be due to a coding error where the set appender method was not called, or that the appender was not assigned a logger in the configuration file. Once of the appenders, "Console Appender" has a severity threshold assigned to it.

The messages attempt to propagate up the hierarchy. The info message dies at the first parent due to the severity level of the logger not being met. Although it is accepted by the first logger it is not logged anywhere beacuse the first logger has no appenders set. This is true for java.util.logging as the loggers severity threshold is applied to propogated messages.  (Note in log4j this would still be logged to the appender "File Appender A" and "Console Appender" of its ancestors, since Log4j does not check propagated log messages against severity thresholds of the logger. This is illustrated in the graphic below.) The error and fatal log messages make it to the 1st parent and the 2nd parent logger. However the error log message fails the severity level set on the "Console Appender" so is not logged to the console. (In Log4j the message would be logged to the "Console Appender" as well since appenders do not have severity levels in Log4J. See below) The flow above more closely resembles that of java.util.logging.

It should be noted that log messages can enter the logger hierarchy at any level. I.E Log messages can be sent directly to the root logger or any intermediate logger.

Addendum to Log Message propogation (Log4J example).

The graphic below attempts to show the way log messages are propogated in Log4j. It shows how appenders are inherited by Log4j loggers from their ancestors and messages are logged to all parent appenders as they propogate. It also shows how log messages can enter the logger hierachy at any level.
Logger hierarchy diagram

 

Captain's Log - The End!

So now you know that when the captain of the Enterprise starts his log entry he/she has to employ all his/her Starfleet Academy training to do so without messing up.mmm

Well that's it for now. I think I confused myself writing this article! So let me know if there are any corrections. Its quiet hard to abstract the general out of the particular for the various logging frameworks. What one should try and remember are the conceptual entities and their relationships as well as the fact there is a propagation flow up the hierarchy of loggers. This, and what is inherited by loggers, will usually be the source of most of your headaches once the basics are under the belt.

Comments

Thank you - your article clarified quite a few things for me. I'm a logging newbie trying to figure out which frameworks to go with. From everything I have read so far, sl4j with logback seems the best way to go.