Spring AOP Log4j Logger example, improvement

Question

I went through some of the stuffs on net regarding spring AOP and wrote a Spring AOP logger.

Can you guys check my code and give your valuable inputs to improve it or if it is not proper, give me an another example of how can I achieve it?

My Code is as below :

@Aspect
public class SpringAOPLogger {

    @Around("execution(* com.sample.dao.*.*(..)) || execution(* com.sample.service.*.*(..))"
            + "|| execution(* com.sample.controller.*.*(..))")
    public Object logMethod(ProceedingJoinPoint joinPoint) throws Throwable {
        String className = joinPoint.getTarget().getClass().getSimpleName();
        final Logger logger = Logger.getLogger(joinPoint.getTarget().getClass());
        Object retVal = null;

        try {
            StringBuffer startMessageStringBuffer = new StringBuffer();

            startMessageStringBuffer.append("Entered in ").append(className).append(".");
            startMessageStringBuffer.append(joinPoint.getSignature().getName());
            startMessageStringBuffer.append("(");

            Object[] args = joinPoint.getArgs();
            for (Object arg : args) {
                startMessageStringBuffer.append(arg).append(", ");
            }
            if (args.length > 0) {
                startMessageStringBuffer.deleteCharAt(startMessageStringBuffer.length() - 1);
            }

            startMessageStringBuffer.append(")");

            //Method Entry Log
            logger.debug(startMessageStringBuffer.toString());

            StopWatch stopWatch = new StopWatch();
            stopWatch.start();

            retVal = joinPoint.proceed();

            stopWatch.stop();

            StringBuffer endMessageStringBuffer = new StringBuffer();
            endMessageStringBuffer.append("Exit from ").append(className).append(".");
            endMessageStringBuffer.append(joinPoint.getSignature().getName());
            endMessageStringBuffer.append("(..); Execution time: ");
            endMessageStringBuffer.append(stopWatch.getTotalTimeMillis());
            endMessageStringBuffer.append(" ms;");

            //Method Exit Log
            logger.debug(endMessageStringBuffer.toString());
        } catch (Throwable ex) {
            StringBuffer errorMessageStringBuffer = new StringBuffer();
            // Create error message
            logger.error(errorMessageStringBuffer.toString(), ex);
            throw ex;
        }
        return retVal;
    }
}

and below is the spring xml configuration for the same :

    <aop:aspectj-autoproxy>
        <aop:include name="springAopLogger" />
    </aop:aspectj-autoproxy>

    <bean id="springAopLogger" class="com.sample.utility.SpringAOPLogger" />

Answer 1

• Use StringBuilder instead of StringBuffer since the latter is synchronized and you're not sharing the instances in a multi-threading manner. So use of StringBuilder would be a bit faster.
• Narrow down the scope of retVal. Generally speaking, your variables should be as close to the use places as possible. Note that you can move the retVal declaration and the return statement to the try block entirely.
• A matter of style, but I would use final as much as possible.
• Concatenate the @Around expression into a single constant if possible and if it's not disallowed by your code convention.
• Split your single method into smaller ones. First off, you separate different responsibilities and improve the readability. Note that the message formatting methods return String (why should the call site know what's behind the scenes?). You can shorten the behind-the-scenes object names to simple builder as there are no name conflicts. These methods are declared static, and they use JoinPoint instead of ProceedingJoinPoint just because it's enough to accept an instance of the first class. And getPostMessage is better to accept long and not StopWatch -- what if you would use System.currentTimeMillis()?
• StringBuilder is a perfect example of the fluent interface concept, so you might want even use it more (and even discard its variables: see getPostMessage with a single return but multiple chained appends).
• Joining a sequence of items using a separator is a trivial problem, and you could eliminate use of deleteCharAt. Just ignore the very first "imaginary" separator and not append it. Or use Guava Joiner.appendTo(StringBuilder,Object[]) if possible (can't recall if there is a Java 8 StringBuilder-friendly collector). Note that appendTo() from the answer is really an utility-candidate method so you might want to reuse it elsewhere if it's justified.
• targetClass is introduced, because I don't know if getting the target is cheap (I believe it's extremely cheap, but this is a particular case -- but this is an interface, and what if you mock your JoinPoint to unit-test the logger and don't want the getTarget code behind to happen twice?). However, having a variable named targetClass is a good self-describing hint.
• Also, usually, a try/catch block can cover the whole method, thus className can be moved into it safely without changing the semantics (but not logger because it's used in separate blocks).
• Static imports may improve readability, so maybe just getLogger(...) instead of Logger.getLogger(...)?
• And one more thing that I'm not sure about, and it would require more investigation: StringBuilder can be replaced with string concatenation. At least for simple cases like https://gist.github.com/lyubomyr-shaydariv/ffdc40df722ca489e14364da8a8c4e30 (those two methods produce the same Java byte-code). See more at https://stackoverflow.com/questions/1532461/stringbuilder-vs-string-concatenation-in-tostring-in-java .

@Aspect
public class SpringAOPLogger {

    @Around("execution(* com.sample.dao.*.*(..)) || execution(* com.sample.service.*.*(..)) || execution(* com.sample.controller.*.*(..))")
    public Object logMethod(final ProceedingJoinPoint joinPoint)
            throws Throwable {
        final Class<?> targetClass = joinPoint.getTarget().getClass();
        final Logger logger = getLogger(targetClass);
        try {
            final String className = targetClass.getSimpleName();
            logger.debug(getPreMessage(joinPoint, className));
            final StopWatch stopWatch = new StopWatch();
            stopWatch.start();
            final Object retVal = joinPoint.proceed();
            stopWatch.stop();
            logger.debug(getPostMessage(joinPoint, className, stopWatch.getTotalTimeMillis()));
            return retVal;
        } catch ( final Throwable ex ) {
            logger.error(getErrorMessage(ex), ex);
            throw ex;
        }
    }

    private static String getPreMessage(final JoinPoint joinPoint, final String className) {
        final StringBuilder builder = new StringBuilder()
                .append("Entered in ").append(className).append(".")
                .append(joinPoint.getSignature().getName())
                .append("(");
        appendTo(builder, joinPoint);
        return builder
                .append(")")
                .toString();
    }

    private static String getPostMessage(final JoinPoint joinPoint, final String className, final long millis) {
        return new StringBuilder()
                .append("Exit from ").append(className).append(".")
                .append(joinPoint.getSignature().getName())
                .append("(..); Execution time: ")
                .append(millis)
                .append(" ms;")
                .toString();
    }

    private static String getErrorMessage(final Throwable ex) {
        return ex.getMessage();
    }

    private static void appendTo(final StringBuilder builder, final JoinPoint joinPoint) {
        final Object[] args = joinPoint.getArgs();
        for ( int i = 0; i < args.length; i++ ) {
            if ( i != 0 ) {
                builder.append(", ");
            }
            builder.append(args[i]);
        }
    }

}