Alex Rivera | Logout

Using annotations for trace logging

Asked 2011-04-09T12:06:09.013
11

I've been working with a codebase of a company that has a policy of writing lots of trace logging. So pretty much every method has a piece of code that starts like this:

String LOG_METHOD = "nameOfMethod(String,List<Long>):void";
if(logger.isTraceEnabled()) { 
    Object[] params = new Object[] { string, list };
    logger.trace(CompanyMessages.newMethodInstanceMessage(this, LOG_METHOD, params)); 
}

and end like this (either in a finally-clause or just at the end of the method:

if(logger.isTraceEnabled()) { 
    logger.trace(CompanyMessages.leaveMethodInstanceMessage(this, LOG_METHOD)); 
}

There is actually more code to it, but this is the basic idea. This is cluttering the code and other coders are constantly messing it up with their own interpretations which don't use the specific CompanyMessages-class which is needed to format the messages to be read by the monitoring tools. So I am looking for a way to get rid of all code above and just provide all methods which need trace-logging with annotations like: @LogBefore('logLevel') & @LogAfter('logLevel').

The reason I choose this solution is to make it so other developers don't have to learn anything new but to use annotations instead of code. I'm working in a server environment in which we deploy hundreds of web applications and dozens of developers. So I have been looking for a way to implement this in a web application without a lot of extra coding or additional large libraries. This means I'm looking for a small, stable AOP implementation using annotations similar to those I proposed, easy to configure in each web application. Performance is also important. What is the simplest example to implement this with AOP?

Edit: I did find something very similar

java logging annotations trace aspects
Edit
Report

1 Answer

5

The annotations and AOP points are both valid. Use annotations to alert the AOP framework about the logging.

Another thing I would do is fix your logger.

You have:

String LOG_METHOD = "nameOfMethod(String,List<Long>):void"
if(logger.isTraceEnabled()) { 
    Object[] params = new Object[] { string, list };
    logger.trace(CompanyMessages.newMethodInstanceMessage(this, LOG_METHOD, params) ); 
}

Instead, consider something like this:

logger.trace(this, LOG_METHOD, string, list);

and you can implement it like this:

public void trace(Object obj, Object args...) {
    if (parentLogger.isTraceEnabled()) {
        logger.trace(CompanyMessages.newMethodInstanceMessage(obj, LOG_METHOD, args);
    }
}

Most of the logging utilities were written before we had varargs in Java, so we still see things like what you've written.

We also still want the guarding to prevent calling log when it's not enabled, but the primary motivation for that is because most folks in the past would do what you did, or, even worse:

logger.trace("My message: " + string + " with list " + list);

Which has has an expensive expression whether trace is enabled or not.

But by leveraging varargs, you can get both. Simply use something like MessageFormat (which you are probably doing already), you can easily get:

logger.trace("My message: {0} with list {1}", string, list);

With trace disabled, this is a cheap method call passing 3 pointers. So there is far less motivation to guard it and clutter your code.

Most of the modern loggers don't override nicely, so you typically have to encapsulate it rather than simply extend it.

It doesn't directly solve your issue, dynamically generating trace information. But it's a simple middle ground that readily, and incrementally, clean up your existing

answered 2011-04-09T16:28:56.057

Your Answer