Sometimes we have to work on a project with only Java source files. But we can introduce some small Groovy stuff at grassroots level if we use Logback as a logging framework. Logback supports configuration by a Groovy script file. This means we can define the configuration with Groovy code instead of the default XML.
The following sample is a very small Maven project for a Java application. We use the Maven exec plugin so we can run the application directly from the command-line. We add the necessary dependencies to the pom.xml so we can write the Logback configuration in Groovy code. We must add the Groovy JAR file so Logback can execute the configuration file.
<?xml version="1.0"?>
<project xmlns="http://maven.apache.org/POM/4.0.0" xmlns:xsi="http://www.w3.org/2001/XMLSchema-instance"
xsi:schemaLocation="http://maven.apache.org/POM/4.0.0 http://maven.apache.org/xsd/maven-4.0.0.xsd">
<modelVersion>4.0.0</modelVersion>
<groupId>com.mrhaki</groupId>
<artifactId>simple-app</artifactId>
<packaging>jar</packaging>
<version>1.0-SNAPSHOT</version>
<build>
<plugins>
<plugin>
<groupId>org.codehaus.mojo</groupId>
<artifactId>exec-maven-plugin</artifactId>
<version>1.2</version>
<executions>
<execution>
<goals>
<goal>java</goal>
</goals>
</execution>
</executions>
<configuration>
<mainClass>com.mrhaki.java.Simple</mainClass>
</configuration>
</plugin>
<plugin>
<groupId>org.apache.maven.plugins</groupId>
<artifactId>maven-compiler-plugin</artifactId>
<configuration>
<source>1.6</source>
<target>1.6</target>
</configuration>
</plugin>
</plugins>
</build>
<dependencies>
<dependency>
<groupId>org.slf4j</groupId>
<artifactId>slf4j-api</artifactId>
<version>1.6.1</version>
</dependency>
<dependency>
<groupId>ch.qos.logback</groupId>
<artifactId>logback-classic</artifactId>
<version>0.9.24</version>
</dependency>
<dependency>
<groupId>org.codehaus.groovy</groupId>
<artifactId>groovy-all</artifactId>
<version>1.7.5</version>
<scope>runtime</scope>
</dependency>
</dependencies>
</project>
Our Java class is simple, just as the name suggests. We only want to demonstrate the different log levels that are used and how we can use that in our Logback configuration.
// File: src/main/java/com/mrhaki/java/Simple.java
package com.mrhaki.java;
import org.slf4j.Logger;
import org.slf4j.LoggerFactory;
public class Simple {
private static final Logger LOGGER = LoggerFactory.getLogger(Simple.class);
public Simple() {}
public String sayHelloTo(String name) {
return "Hello, " + name;
}
public static void main(String[] args) {
LOGGER.info("Starting application.");
Simple app = new Simple();
String hello = app.sayHelloTo("mrhaki");
LOGGER.debug("Saying: " + hello);
LOGGER.info("Application ends.");
}
}
Now it is time to look at the Groovy Logback configuration. Logback provides a simple DSL to configure loggers, appenders and other Logback configuration elements.
// File: src/main/resources/logback.groovy
import static ch.qos.logback.classic.Level.*
import ch.qos.logback.core.ConsoleAppender
import ch.qos.logback.classic.encoder.PatternLayoutEncoder
import ch.qos.logback.core.status.OnConsoleStatusListener
import ch.qos.logback.core.FileAppender
import com.mrhaki.java.logsupport.SmileyConverter
displayStatusOnConsole()
scan('5 minutes') // Scan for changes every 5 minutes.
setupAppenders()
setupLoggers()
def displayStatusOnConsole() {
statusListener OnConsoleStatusListener
}
def setupAppenders() {
def logfileDate = timestamp('yyyy-MM-dd') // Formatted current date.
// hostname is a binding variable injected by Logback.
def filePatternFormat = "%d{HH:mm:ss.SSS} %-5level [${hostname}] %logger - %msg%n"
appender('logfile', FileAppender) {
file = "simple.${logfileDate}.log"
encoder(PatternLayoutEncoder) {
pattern = filePatternFormat
}
}
// Add custom converter for %smiley pattern.
conversionRule 'smiley', SmileyConverter
appender('systemOut', ConsoleAppender) {
encoder(PatternLayoutEncoder) {
pattern = "%-5level %-12logger{12} %smiley - %msg%n"
}
}
}
def setupLoggers() {
logger 'com.mrhaki.java.Simple', getLogLevel(), ['logfile']
root DEBUG, ['systemOut']
}
def getLogLevel() {
(isDevelopmentEnv() ? DEBUG : INFO)
}
def isDevelopmentEnv() {
def env = System.properties['app.env'] ?: 'DEV'
env == 'DEV'
}
Logback looks for a file named logback.groovy in the classpath of the application. If the file is found it is parsed by a GroovyShell instance and Logback is configured.
We start by using the statusListener() method (line 14) so Logback logs the configuration details to the console.
To add a new appender, we use the appender() method. We use a closure to configure the appender. Loggers are configured with the logger() and root() methods. We can define the loglevel and a list of appenders that need to be used.
At line 9 we use the scan() method to define the scan interval used by Logback to check for changes in logback.groovy. If the file has changed, the new configuration is used.
At the bottom of the configuration file we define the method isDevelopmentEnv() to see if the application is running in development mode. If so we set the log level to DEBUG, otherwise it is set to INFO (see methods getLogLevel() and setupLoggers()). And because the configuration is a Groovy script this is very easy to achieve.
With the conversionRule() method at line 29 we assign the SmileyConverter class to the %smiley variable in the encoding pattern. The code for the SmileyConverter is here:
// File: src/main/java/com/mrhaki/java/logsupport/SmileyConverter.java
package com.mrhaki.java.logsupport;
import ch.qos.logback.classic.Level;
import ch.qos.logback.classic.pattern.ClassicConverter;
import ch.qos.logback.classic.spi.ILoggingEvent;
import static ch.qos.logback.classic.Level.*;
public class SmileyConverter extends ClassicConverter {
@Override
public String convert(ILoggingEvent event) {
return getSmiley(event.getLevel());
}
// Return a different smiley for different log levels.
private String getSmiley(Level level) {
String result = "";
switch (level.toInt()) {
case DEBUG_INT:
result = ";)";
break;
case INFO_INT:
result = ":)";
break;
default:
break;
}
return result;
}
}
We are ready to run the application and see our logging configuration at work:
$ mvn -q compile exec:java 11:01:52,087 |-INFO in ch.qos.logback.classic.gaffer.ConfigurationDelegate@6fa8bd74 - Added status listener of type [ch.qos.logback.core.status.OnConsoleStatusListener] 11:01:52,107 |-INFO in ch.qos.logback.classic.gaffer.ConfigurationDelegate@6fa8bd74 - Setting ReconfigureOnChangeFilter scanning period to 5 minutes 11:01:52,108 |-INFO in ch.qos.logback.classic.turbo.ReconfigureOnChangeFilter@14a97f68 - Will scan for changes in file [/Users/mrhaki/Projects/mrhaki.com/blog/posts/samples/logback/target/classes/logback.groovy] every 300 seconds. 11:01:52,109 |-INFO in ch.qos.logback.classic.gaffer.ConfigurationDelegate@6fa8bd74 - Adding ReconfigureOnChangeFilter as a turbo filter 11:01:52,170 |-INFO in ch.qos.logback.classic.gaffer.ConfigurationDelegate@6fa8bd74 - About to instantiate appender of type [ch.qos.logback.core.FileAppender] 11:01:52,171 |-INFO in ch.qos.logback.classic.gaffer.ConfigurationDelegate@6fa8bd74 - Naming appender as [logfile] 11:01:52,311 |-INFO in ch.qos.logback.core.FileAppender[logfile] - File property is set to [simple.2010-09-21.log] 11:01:52,329 |-INFO in ch.qos.logback.classic.gaffer.ConfigurationDelegate@6fa8bd74 - registering conversion word smiley with class [com.mrhaki.java.logsupport.SmileyConverter] 11:01:52,380 |-INFO in ch.qos.logback.classic.gaffer.ConfigurationDelegate@6fa8bd74 - About to instantiate appender of type [ch.qos.logback.core.ConsoleAppender] 11:01:52,382 |-INFO in ch.qos.logback.classic.gaffer.ConfigurationDelegate@6fa8bd74 - Naming appender as [systemOut] INFO c.m.j.Simple :) - Starting application. DEBUG c.m.j.Simple ;) - Saying: Hello, mrhaki INFO c.m.j.Simple :) - Application ends.
First we see the results from Logback, because we used the statusListener() method. Then at the bottom we see three output lines from our Simple java code. Now let's run the application again, but this time we use a system property to set the environment to a non-development one:
$ mvn -q -Dapp.env=TEST compile exec:java 11:04:01,588 |-INFO in ch.qos.logback.classic.gaffer.ConfigurationDelegate@563b100c - Added status listener of type [ch.qos.logback.core.status.OnConsoleStatusListener] 11:04:01,607 |-INFO in ch.qos.logback.classic.gaffer.ConfigurationDelegate@563b100c - Setting ReconfigureOnChangeFilter scanning period to 5 minutes 11:04:01,609 |-INFO in ch.qos.logback.classic.turbo.ReconfigureOnChangeFilter@364e50ee - Will scan for changes in file [/Users/mrhaki/Projects/mrhaki.com/blog/posts/samples/logback/target/classes/logback.groovy] every 300 seconds. 11:04:01,610 |-INFO in ch.qos.logback.classic.gaffer.ConfigurationDelegate@563b100c - Adding ReconfigureOnChangeFilter as a turbo filter 11:04:01,655 |-INFO in ch.qos.logback.classic.gaffer.ConfigurationDelegate@563b100c - About to instantiate appender of type [ch.qos.logback.core.FileAppender] 11:04:01,656 |-INFO in ch.qos.logback.classic.gaffer.ConfigurationDelegate@563b100c - Naming appender as [logfile] 11:04:01,811 |-INFO in ch.qos.logback.core.FileAppender[logfile] - File property is set to [simple.2010-09-21.log] 11:04:01,832 |-INFO in ch.qos.logback.classic.gaffer.ConfigurationDelegate@563b100c - registering conversion word smiley with class [com.mrhaki.java.logsupport.SmileyConverter] 11:04:01,837 |-INFO in ch.qos.logback.classic.gaffer.ConfigurationDelegate@563b100c - About to instantiate appender of type [ch.qos.logback.core.ConsoleAppender] 11:04:01,841 |-INFO in ch.qos.logback.classic.gaffer.ConfigurationDelegate@563b100c - Naming appender as [systemOut] INFO c.m.j.Simple :) - Starting application. INFO c.m.j.Simple :) - Application ends.
No if we look at the last two lines we see the DEBUG message is not shown anymore. That is because we changed the log level accordingly to the sytem property app.env..
As we can see introducing Groovy into a Java project is easy if we use Logback. We only have to add the Groovy JAR as a dependency and we are ready to go. And once that Groovy JAR dependency is in the project definition... (grin)
