Easy Groovy Logger Injection and Log Guarding

Groovy 1.8 was recently released with a long list of new features. I focus on one of these new features, logger injection via new AST Transformations, in this post.

Groovy 1.8 provides AST Transformations for annotation-based logged injection for four of the most popular Java logging frameworks: the standard java.util.logging, Log4j, Apache Commons Logging, and Simple Logging Facade for Java (SLF4J). The annotation is different for each of these logging frameworks, but the effect is the same: each injects the respective logger into the annotated class accessible by a "log" variable name handle. Each AST does more than simply inject the logger; each also automatically wraps all calls to logging methods with checks for the logging level being set sufficiently to log at that level.

The @Log annotation is used to inject a java.util.logging logger. Its Groovydoc states the following regarding use of @Log to inject the Log4j logger:

The method name will be used to determine what to call on the logger.

 log.name(exp)
 
is mapped to
 if (log.isLoggable(Level.NAME) {
    log.name(exp)
 }
Here name is a place holder for info, fine, finer, finest, config, warning, severe.

As the Groovydoc documentation for @Log indicates, using code like log.info(expression) is mapped to a conditional logging guard call before actually invoking that named method (info in this case) on the logger.

Just as the @Log annotation injects a java.util.logging logger, there are different annotations that do the same thing for the other three previously mentioned logging frameworks. A Log4j logger is injected with the @Log4j annotation, an Apache Commons Logging logger is injected with the @Commons annotation, and an SLF4J logger is injected with the @Slf4j annotation.

These logger annotations are easily demonstrated in the following Groovy code snippets. I first list four simple Groovy classes, one for each of the four logging frameworks for which Groovy 1.8 provides logger transformations.

JavaUtilLoggerClass.groovy - Demonstrates @Log for java.util.logging

import groovy.util.logging.Log

@Log
class JavaUtilLoggerClass
{
   public JavaUtilLoggerClass()
   {
      println "\njava.util.logging (${log.name}: ${log.class}):"
      log.info "${this.printAndReturnValue(1)}"
      log.finer "${this.printAndReturnValue(2)}"
   }

   public String printAndReturnValue(int newValue)
   {
      println "JDK: Print method invoked for ${newValue}"
      return "JDK: ${newValue}"
   }
}

Log4jLoggerClass.groovy - Demonstrates @Log4j for Log4j

import groovy.util.logging.Log4j

import org.apache.log4j.Level

@Log4j
class Log4jLoggerClass
{
   Log4jLoggerClass()
   {
      // It is necessary to set logging level here because default is FATAL and
      // we are not using a Log4j external configuration file in this example
      log.setLevel(Level.INFO)
      println "\nLog4j Logging (${log.name}: ${log.class}):"
      log.info "${this.printAndReturnValue(1)}"
      log.debug "${this.printAndReturnValue(2)}"
   }

   public String printAndReturnValue(int newValue)
   {
      println "Log4j: Print method invoked for ${newValue}"
      return "Log4j: ${newValue}"
   }
}

ApacheCommonsLoggerClass.groovy - Demonstrates @Commons for Commons Logging

import groovy.util.logging.Commons

@Commons
class ApacheCommonsLoggerClass
{
   public ApacheCommonsLoggerClass()
   {
      println "\nApache Commons Logging (${log.name}: ${log.class}):"
      log.info "${this.printAndReturnValue(1)}"
      log.debug "${this.printAndReturnValue(2)}"
   }

   public String printAndReturnValue(int newValue)
   {
      println "Commons: Print method invoked for ${newValue}"
      return "Commons: ${newValue}"
   }
}

Slf4jLoggerClass.groovy - Demonstrates @Slf4j for SLF4J Logging

import groovy.util.logging.Slf4j

@Slf4j
class Slf4jLoggerClass
{
   public Slf4jLoggerClass()
   {
      println "\nSLF4J Logging (${log.name}: ${log.class}):"
      log.info "${this.printAndReturnValue(1)}"
      log.debug "${this.printAndReturnValue(2)}"
   }

   public String printAndReturnValue(int newValue)
   {
      println "SLF4J: Print method invoked for ${newValue}"
      return "SLF4J: ${newValue}"
   }
}

The above four Groovy classes are very similar, but each one takes advantage of a different Groovy 1.8 logger injection. The next Groovy code listing shows a script that makes use of these classes and demonstrates the workings of the respective injected loggers.

demoGroovyLogTransformation.groovy

#!/usr/bin/env groovy
// demoGroovyLogTransformation.groovy

//
// Grab SLF4J, Log4j, and Apache Commons Logging dependencies using @Grab
//

// No need to "grab" java.util.logging: it's part of the JDK!

/*
 * Specifying 'slf4j-simple' rather than 'slf4j-api' to avoid the error
 * "Failed to load class "org.slf4j.impl.StaticLoggerBinder" that is caused by
 * specifying no or more than one of the actual logging binding libraries to
 * be used (see http://www.slf4j.org/codes.html#StaticLoggerBinder). One should
 * be selected from 'slf4j-nop', 'slf4j-simple', 'slf4j-log4j12.jar',
 * 'slf4j-jdk14', or 'logback-classic'. An example of specifying the SLF4J
 * dependency via @Grab is available at
 * http://mvnrepository.com/artifact/org.slf4j/slf4j-api/1.6.1.
 */
@Grab(group='org.slf4j', module='slf4j-simple', version='1.6.1')

/*
 * An example of specifying the Log4j dependency via @Grab is at
 * http://mvnrepository.com/artifact/log4j/log4j/1.2.16.
 */
@Grab(group='log4j', module='log4j', version='1.2.16')

/*
 * An example of specifying the Apache Commons Logging dependency via @Grab is at
 * http://mvnrepository.com/artifact/commons-logging/commons-logging-api/1.1.
 */
@Grab(group='commons-logging', module='commons-logging-api', version='1.1')


//
// Run the tests...
//

def javaUtilLogger = new JavaUtilLoggerClass()
def log4jLogger = new Log4jLoggerClass()
def slf4jLogger = new Slf4jLoggerClass()
def commonsLogger = new ApacheCommonsLoggerClass()

Most of the above script is comments. The script takes advantage of Groovy's built-in Grape/@Grab support to find its dependencies on the various logging frameworks. There is no need to explicitly "grab" available-by-default java.util.logging, but @Grab is used to specify dependencies on the other three logging frameworks. Groovy 1.8 introduces more concise syntax for @Grab, but I used the pre-1.8 syntax in this example. As the comments in the script indicate, I used Maven repository settings for declaring these dependencies on Log4j, Apache Commons Logging, and SLF4J (Simple Binding).

The output from running the above script that instantiates the four Groovy classes is shown next.

java.util.logging (JavaUtilLoggerClass: class java.util.logging.Logger):
JDK: Print method invoked for 1
May 2, 2011 9:42:23 PM org.codehaus.groovy.runtime.callsite.PojoMetaMethodSite$PojoCachedMethodSiteNoUnwrap invoke
INFO: JDK: 1

Log4j Logging (Log4jLoggerClass: class org.apache.log4j.Logger):
Log4j: Print method invoked for 1
INFO - Log4j: 1

SLF4J Logging (Slf4jLoggerClass: class org.slf4j.impl.SimpleLogger):
SLF4J: Print method invoked for 1
19 [main] INFO Slf4jLoggerClass - SLF4J: 1

Apache Commons Logging (ApacheCommonsLoggerClass: class org.apache.commons.logging.impl.Jdk14Logger):
Commons: Print method invoked for 1
May 2, 2011 9:42:23 PM org.apache.commons.logging.Log$info call
INFO: Commons: 1

The output above proves that the injected loggers do indeed prevent the classes from even being instantiated when the level of logging does not meet the log level of the application.


Conclusion

This post's simple example demonstrates that the Groovy 1.8 logger AST Transformations can inject loggers from the four major Java logging frameworks and map logging calls to code that checks the log level before trying to log only if appropriate. This greatly reduces the amount of code necessary to set up and use logging for any of these four popular logging frameworks.