CODEWITHSUNDEEP
javaspringlogging
Mike M. Lin
Mike M. Lin

Reputation: 10072

How do you trace the entry into and exit from all functions in Spring-based web app?

On the Spring-based web app project I'm on now, the developers have written two logging statements into every function. One logging the entry into the function, the other logging the exit. The idea is to trace the execution path -- at least a function level.

Is there a way to accomplish this without littering the entire code base with these repetitive statements?

To be clear, we want to log all functions, not just public methods of Spring beans.

Upvotes: 8

Views: 7178

Answers (2)

OlivierTerrien
OlivierTerrien

Reputation: 2601

Same idea than Nicholas. You can use Spring AOP to do that.

I like working with annotation, so that the logic is specified in the source code, not in the aspect's advice.

Define an annotation

package aop;
@Target({ElementType.METHOD})
@Retention(RetentionPolicy.RUNTIME)
public @interface Traceable {}

Define the aspect

package aop;
@Aspect
public class TraceableAspect {

    private final static AtomicLong Count = new AtomicLong(0);

    @Around("execution(* *(..)) && @annotation(aop.Traceable)")
    public Object aroundTraceableMethod(ProceedingJoinPoint pjp) throws Throwable {

        Logger logger = LoggerFactory.getLogger(pjp.getTarget().getClass());
        if (logger.isTraceEnabled()) {
            return executeWithTrace(pjp, logger, Count.incrementAndGet());
        }

        return pjp.proceed();
    }

    private Object executeWithTrace(ProceedingJoinPoint pjp, Logger logger, long id) throws Throwable {

        long start = System.currentTimeMillis();
        try {
            logger.trace(String.format("#### - #%d - Starting execution of method '%s'", id, pjp.toShortString()));
            return pjp.proceed();
        } catch (Throwable throwable) {
            logger.error(String.format("#### - #%d - Error while executing method '%s' : %s", id, pjp.toShortString(), throwable.toString()));
            throw throwable;
        } finally {
            if (logger.isTraceEnabled()) {
                logger.trace(String.format("#### - #%d - End of method '%s' (duration %s ms)", id, pjp.toShortString(), (System.currentTimeMillis() - start)));
            }
        }
    }    
}

Use the aspect in Spring Boot project

package project;
@Profile("with-trace-aop")
@Configuration
@EnableAspectJAutoProxy(proxyTargetClass = true)
public class SecToolWebApplicationTraceableAspect extends aop.TraceableAspect {

    @PostConstruct
    public void init(){
        Logger logger = LoggerFactory.getLogger(this.getClass());
        logger.warn("###-AOP-### TraceableAspect initialized for this application");
    }
}

**Trace method in a controller

package project;
@RestController
public class ModelController {

    @Traceable
    @RequestMapping(method = RequestMethod.GET, value = "/{date}")
    @ResponseBody
    public <Collection<TE> find(@PathVariable @DateTimeFormat(pattern = DateUtils.DATE_FORMAT) Date date) {
    ...
    }
}

IMPORTANT when a class is linked to an advice, all "final" methods are no more called. It is important to not use "final"

So, assuming the TRACE mode log is enabled, each call of the method "find" would be traced

Pay attention to this does not work if the

Upvotes: 0

nicholas.hauschild
nicholas.hauschild

Reputation: 42834

You can do this with Spring AOP.

Spring AOP will allow you to 'intercept' method calls and perform arbitrary code before and/or after the method call. You will also be able to examine parameters and return values of these methods.

To achieve the logging you are talking about, you would do something like this, likely using the around advice:

  1. Intercept all method calls (or preferably, only the ones you are interested in).
  2. Do your 'before method' logging.
  3. Invoke the method.
  4. Do your 'after method' logging.

All of the Spring details about how to do this can be found in the documentation provided.

Upvotes: 5

Related Questions