On logging when the control is inverted

Log4j - obtaining logger

How to use log4j in our own code? The answer seems obvious - just initialize static logger instance at the beginning of every class which needs to log something:

import org.apache.log4j.Logger;

public class Foo {

  private static final Logger LOG = Logger.getLogger(Foo.class);

}

This idiom is in fact common convention. Benefits are obvious as well:

• logging could be set up similarly in many different classes
• it is initialized as early as possible when the class itself is initialized.
• duplication of loggers among different instances of the same class is avoided.
• we have some consistent naming convention (class name) regarding these different loggers of our application

What do I mean by the last point? Quick look at the source code of the Logger class reveals, that there is no "magic" involved, when JVM is calling Logger.getLogger(Foo.class) static method. It is an equivalent of Logger.getLogger(Foo.class.getName()) code snippet which means, that providing class name we are just providing logger name (category).

However the standard approach of using log4j is IMO not appropriate in every situation. Especially server side applications which consist of some interacting components or services could have logging configured better. The approach I want to recommend can be summarized by one sentence:

Class should have provided a logger instead of obtaining the logger itself

Now I will try to explain it.

Subclass - choosing right logger

Lets assume we have some class derived from Foo class:

/**
 * Public interface of abstract monitoring facility.
 */
public interface MonitoringService {

  //some methods
}

/**
 * Base class with some implementation stubs
 */
public abstract class AbstractMonitoringService implements MonitoringService {
  //common code which does logging
}

/**
 * Specialized filesystem monitoring facility.
 */
public class FilesystemMonitoringService extends AbstractMonitoringService {
  //specific code which does logging
}

/**
 * Specialized database monitoring facility.
 */
public class DatabaseMonitoringService extends AbstractMonitoringService {
  //specific code which does logging
}

The logger name should be the same for FileSystemMonitoringService even when logging is performed on the level of AbstractMonitoringService class. Analogously in case of DatabaseMonitoringService. It smoothly points us at the next problem with "traditional" log4j logging approach.

The same class, different logger

Sometimes having different loggers for different instances of the same class is extremely useful. Lets imagine that we have two instances of DatabaseMonitoringService component in our application, each one configured to monitor different database. With traditional log4j approach we will have only one logger, and only one "category" for them. How to differentiate which is logging what?

Where the solution comes from?

I use to work with Apache's avalon framework - the base code for whole bunch of early Java IoC/Dependency Injection containers. The project seems quite dead now, however I still find some aspects of avalon's design interesting. Especially unique dependency injection handling allowing lazy and background component activation and component pools, different component life cycles, component selectors, and last but not least - the way logging was supported within container and its components.

In avalon obtaining logger is just a matter of implementing enableLogging method of the LogEnabled interface. Then a container is responsible of injecting appropriate logger via this method.

The solution does not suffer from the problems described above. However as I sad the avalon project is dead and development of the excalibur project, which have been taking care of avalon's heritage for some time, is quite inactive.

I no longer believe in Dependency Injection techniques introduced in avalon. The main problem is, that developers are forced to use some special interfaces to build their components. They cannot use POJOs. I strongly believe in constructor based DI - the possibility of assigning some service provided as component dependency to some field, and declaring this field as final. It is the most logical DI solution to me.

The solution - logger passed in constructor

In order to solve all the issues with logging which are described above, I want to propose new idiom for logging (not only log4j logging).

public class Foo {

  private final Logger logger;

  public Foo(Logger logger) {
    this.logger = logger;
  }

}

In case of abstract classes the logger field should be declared as protected. In the specific implementation, a logger instance should be also injected via constructor, and then passed to underlaying abstract class.

public abstract class AbstractMonitoringService implements MonitoringService {

  protected final Logger logger;

  public AbstractMonitoringService(Logger logger) {
    this.logger = logger
  }

}

public class FilesystemMonitoringService extends AbstractMonitoringService {

  public FilesystemMonitoringService(Logger logger) {
    super(logger);
  }

}

The only problem now is how to force specific container to pass logger as a constructor dependency? I made such small container myself. I hope to publish it on open license soon (although being very small it has much more unique features). I hope it is possible to use this "logging approach" with different IoC containers like Spring or Pico Container? I hope to get some comments from people who could verify this. :)