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

Question

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.

This may be of some help - http://stackoverflow.com/questions/2071050/is-using-spring-aop-for-logging-a-good-idea — adarshr, Aug 25 '11 at 16:45
it's usually a lot more useful to pick important methods that represent decision points and log the method+params on entry and the method+return value on exit. The downside is that this requires a small amount of actual thinking. — Kevin, Aug 25 '11 at 16:48

score 5 · Accepted Answer · answered Aug 25 '11 at 17:19

5

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:

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

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

answered Aug 25 '11 at 17:19

nicholas.hauschild

42,483
9
127
120

1

Does this mean that any object I'd want to log would have to be a Spring bean? – Mike M. Lin Aug 25 '11 at 18:42
Sort of. I think you can do any bean if you also use `AspectJ`, which Spring supports. In the Spring AOP documentation, take a look at `section 7.8` and its children sections. – nicholas.hauschild Aug 25 '11 at 18:51
@MikeM.Lin Could you please share an example or reference tutorial? – Pratik Ambani Aug 06 '17 at 07:04

score 0 · Answer 2 · answered Nov 07 '16 at 13:05

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

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

2 Answers2