Automated Logging with Maven

Introduction

Do you need to implement the logging-part of a medium sized project? To do this you might have to walk through the code and look at nearly every line. It's verry time consuming to find caught exceptions (empty catch block, etc.) or to include actual parameters and field values inside the log entry. If something changes you'll have to start from scratch. Your code will grow and might become a little ugly with lines like this:

LoggerFactory.getLogger(AttractionDTO.class).debug(String.format("The x coordinate of the attraction '%s' was set to %f", getName(), x));

Background

In my case this medium sized project was a JSF web application. First I tried to automate a part of the logging process using a modified ClassLoader that injects the required calls at runtime (using Javassist). This approach had serveral disadvantages like:

• complicated ClassLoader structure
• performance drop when a class gets loaded
• injected log calls are not available during the unit test execution
• difficult exception handling during the code injection (fail silently or destroy the container)

So I decided to do the required code injections during the build process. The "Java Annotation Processing API" was not usable, because it only allows to add sources. You can not edit existing ones. I also discared the usage of project Lombok because it uses internal, non standard and compiler specific techniques.

Since we used Maven to build our project, I decided to write a plugin that will invoke some "post-processor-classes" inside our project. These post-processor-classes are now able to modify the compiled class-files using Javassist.

The results

I published the results as an open source project because I thought that this could be useful in other scenarios. The maven plugin that executes these post-processor-classes can be found at

https://github.com/RandomCodeOrg/PPPlugin

and some default processor implementations at

https://github.com/RandomCodeOrg/PPDefaults

Using the plugin

Creating a new maven project

You may skip this section if you already have a maven project or if you are familiar with maven. I'm going to use Eclipse for this example but you can find a lot of tutorials explaining the process with other IDEs.

1. Create a new maven-Project

Select Maven > "Maven Project" and click "Next"

2. Confirm the following steps with "Next" until you reach the following step

Enter a "Group Id" and "Artifact Id" of your choice and complete the wizard by clicking on "Finish". Here you can find an explanation of the group- and artifact id.

The wizard will create an empty maven project containing the "pom.xml" and a main-class "App" inside a package with the name of the given group- and artifact id.

Modify your maven project

1. Run the PPPlugin with each build

Open the "pom.xml" and click on the tab with the name "pom.xml".

You will see a xml-document containing all settings concerning your project.

2. Configure the PPPlugin

In order to execute the PPPlugin you'll have to include it into your <build><plugins> section of your pom.xml by inserting the following snippet.

<code><plugin>
  <groupId>com.github.randomcodeorg.ppplugin</groupId>
  <artifactId>ppplugin</artifactId>
  <version>0.1.0</version>
  <executions>
    <execution>
    <phase>process-classes</phase>
      <goals>
        <goal>postprocess</goal>
      </goals>
    </execution>
  </executions>
</plugin></code>

(2a. Make Eclipse shut up)

If your Eclipse installation complains about:

Eclipe Maven Problem:

Plugin execution not covered by lifecycle configuration: com.github.randomcodeorg[...]

one can insert

        <pluginManagement>
            <plugins>
                <plugin>
                    <groupId>org.eclipse.m2e</groupId>
                    <artifactId>lifecycle-mapping</artifactId>
                    <version>1.0.0</version>
                    <configuration>
                        <lifecycleMappingMetadata>
                            <pluginExecutions>
                                <pluginExecution>
                                    <pluginExecutionFilter>
                                        <groupId>
                                            com.github.randomcodeorg.ppplugin
                                        </groupId>
                                        <artifactId>
                                            ppplugin
                                        </artifactId>
                                        <versionRange>
                                            [0.0.0,)
                                        </versionRange>
                                        <goals>
                                            <goal>postprocess</goal>
                                        </goals>
                                    </pluginExecutionFilter>
                                    <action>
                                        <execute></execute>
                                    </action>
                                </pluginExecution>
                            </pluginExecutions>
                        </lifecycleMappingMetadata>
                    </configuration>
                </plugin>
            </plugins>
        </pluginManagement>

into the <build> element to fix this problem. Save the changes and the error should be gone.

3. Include the default post-processors

Copy the following snippet into the <dependencies> section of your pom.xml:

        <dependency>
            <groupId>com.github.randomcodeorg.ppplugin</groupId>
            <artifactId>ppdefaults</artifactId>
            <version>0.0.1</version>
        </dependency>
        <!-- The following two dependencies are required because the processor uses SLF4J's logger by default -->
        <dependency>
            <groupId>org.slf4j</groupId>
            <artifactId>slf4j-api</artifactId>
            <version>1.7.7</version>
        </dependency>
        <dependency>
            <groupId>org.slf4j</groupId>
            <artifactId>slf4j-simple</artifactId>
            <version>1.7.13</version>
        </dependency>

Enabling some default processors

The plugin only executes processors that are part of your source code. This will prevent the build process from executing third-party code. But you can simply create an inheriting class inside your project to enable the execution of such "foreign" processors.

Create the following two classes to do so:

CaughtExceptionProcessor

import com.github.randomcodeorg.ppplugin.ppdefaults.logging.InsertCaughtExceptionLogProcessor;

public class CaughtExceptionProcessor extends InsertCaughtExceptionLogProcessor {

    public CaughtExceptionProcessor(){
        
    }
    
}

MethodCallProcessor

import com.github.randomcodeorg.ppplugin.ppdefaults.logging.InsertMethodCallLogProcessor;

public class MethodCallProcessor extends InsertMethodCallLogProcessor{

    public MethodCallProcessor(){
        
    }
    
}

Now you are ready to start! The plugin will now inject log commands in every catch-block and every method that is annotated with @LogThis.

Modifications

The Annotations

@LogThis can be used to annotate methods or classes. The processor will inject a log command in every method that is annotated with this annotation. A annotation of the class will be applied to every method declared in it. Note that method-level annotations will override annotations on the class-level. The annotation contains the following attributes:

• value Defines the log level of the resulting log entry (default is 'DEBUG')
• logFields Defines if the value of the instances fields should be included in the log entry (default is 'true')
• ignoreStaticFinal Defines if fields that are static and final should be included in the log entry (default is 'true')

@Stealth can be used to exclude parameters, fields or methods from the log.

Use a different logger framework

If you want to use another logger framework you should take a look at the AbstractLoggingProcessor. You can override the methods defined in this class to do change the way a logger is created and accessed. The following example will show you how you can use the java.util.logging.Logger:

import com.github.randomcodeorg.ppplugin.ppdefaults.logging.InsertMethodCallLogProcessor;
import com.github.randomcodeorg.ppplugin.ppdefaults.logging.LogLevel;

import javassist.CtClass;

public class MyCustomMethodCallProcessor extends InsertMethodCallLogProcessor {

    public MyCustomMethodCallProcessor() {

    }

    @Override
    protected String getLoggerType() {
        return "java.util.logging.Logger";
    }

    @Override
    protected String getLoggerInitialization(CtClass cl) {
        return String.format("java.util.logging.Logger.getLogger(\"%s\");", cl.getName());
    }

    @Override
    protected String getLogMethodName(LogLevel level) {
        switch (level) {
        case VERBOSE:
            return "finest";
        case DEBUG:
            return "fine";
        case INFORMATION:
            return "info";
        case WARNING:
        case ERROR:
            return "warning";
        default:
            return "info";
        }
    }

    @Override
    protected String getLoggerFieldPrefix() {
        return "sysLogger_";
    }

}

Testing it

You can download the example from the link below. Run a maven build (Right click on the project > "Run as" > "Maven Build" > Goals: "clean install" > "Run") to execute the plugin. After this is done you can simpliy run it as a "normal" Java application (Right click on project > "Run as" > "Java Application").

Download TestProject.zip

Any questions?

If you have a question, suggestion or want to give me a feedback - Just do it!