Performance Logging with Spring Boot and AOP

Question

I'm trying to implement performance logging based off of this post: http://www.baeldung.com/spring-performance-logging. I'd like to log each controller endpoint and every database request. If you would like to see the full project, you can find it here. When I hit the endpoints nothing is logged. Placing a breakpoint within the interceptor class it doesn't stop either. I've already set my logging for the packages to the trace level. What am I missing? I believe it's something to with the @PointCut but after looking at the docs I believe I have it correct.

Interceptor

public class PerformanceMonitorInterceptor extends AbstractMonitoringInterceptor { @Override protected Object invokeUnderTrace(MethodInvocation methodInvocation, Log log) throws Throwable { String name = createInvocationTraceName(methodInvocation); StopWatch stopWatch = new StopWatch(); stopWatch.start(); log.trace(String.format("Method %s execution start at %s", name, LocalDateTime.now())); try { return methodInvocation.proceed(); } finally { stopWatch.stop(); log.trace(String.format("Method %s execution took %dms (%s)", name, stopWatch.getTotalTimeMillis(), DurationFormatUtils .formatDurationWords(stopWatch.getTotalTimeMillis(), true, true))); } } }

Configuration

@Configuration @EnableAspectJAutoProxy @Aspect public class ContactControllerPerfLogConfig { @Bean public PerformanceMonitorInterceptor performanceMonitorInterceptor() { return new PerformanceMonitorInterceptor(); } // Any public method on the ContactController @Pointcut("execution(public * org.example.phonebookexample.app.contact.ContactController.*(..))") public void contactControllerMonitor() { } @Bean public Advisor contactControllerMonitorAdvisor( PerformanceMonitorInterceptor performanceMonitorInterceptor) { AspectJExpressionPointcut pointcut = new AspectJExpressionPointcut(); pointcut.setExpression("org.example.phonebookexample.app.contact.ContactControllerPerfLogConfig.contactControllerMonitor()"); return new DefaultPointcutAdvisor(pointcut, performanceMonitorInterceptor); } }

Have you specified any logging properties in application.properties ? — Luay Abdulraheem
– Luay Abdulraheem, Commented Jun 19, 2017 at 1:59
Have you tried changing it to only: logging.level= trace ? — Luay Abdulraheem
– Luay Abdulraheem, Commented Jun 19, 2017 at 2:06

Sabir Khan · Accepted Answer · 2018-09-18 11:05:16Z

I never understood the importance of AbstractTraceInterceptor if you are going to customize it.

I always felt too much code for me which can be achieved by a simple @Around advice if you already have @Aspect in place.

 @Around("execution(* com..*.*(..))") public Object logStartAndEnd(ProceedingJoinPoint pjp) throws Throwable{ long startTime = System.currentTimeMillis(); String className = pjp.getTarget().getClass().getCanonicalName(); String methodName = pjp.getSignature().getName(); log.info("started method : " + className+"."+methodName); Object obj; try { obj = pjp.proceed(); log.info("finished method : " + className+"."+methodName); return obj; } catch (Throwable e) { throw e; }finally { log.info("Method "+className+"."+methodName+" execution lasted:"+((System.currentTimeMillis() - startTime )/1000f)+" seconds"); } }

I totally agree. thanks howtodoinjava.com/spring-aop/aspectj-around-annotation-example

jihor · Accepted Answer · 2017-06-19 09:54:56Z

AbstractTraceInterceptor implements MethodInterceptor and has its invoke() method implemented as follows:

public Object invoke(MethodInvocation invocation) throws Throwable { Log logger = getLoggerForInvocation(invocation); if (isInterceptorEnabled(invocation, logger)) { return invokeUnderTrace(invocation, logger); } else { return invocation.proceed(); } }

Therefore the logger for the Interceptor class needs to be set to TRACE. For the basic PerformanceMonitorInterceptor, that will be org.springframework.aop.interceptor.PerformanceMonitorInterceptor. Since you've written your own interceptor, you'll have to set logging level for your own class. Take a look at JamonPerformanceMonitorInterceptor for an example of an alternative approach, allowing to track all invocations regardless of logging level, if required.

For the sake of completeness, I'll also post an xml configuration example, because when it comes to AOP, Spring java configs are not so elegant compared to xml configs:

<bean id="performanceMonitorInterceptor" class="org.springframework.aop.interceptor.PerformanceMonitorInterceptor"/> <aop:config> <aop:pointcut id="contactControllerMonitor" expression="execution(public * org.example.phonebookexample.app.contact.ContactController.*(..))" /> <aop:advisor id="contactControllerMonitorAdvisor" pointcut-ref="contactControllerMonitor" advice-ref="performanceMonitorInterceptor"/> </aop:config>

This config can be imported into your java configuration as follows:

@ImportResource("classpath:/aop-config.xml") public class MainConfig { ... }

Yep that was it, needed to have TRACE level set for my custom interceptor. I'll have to disagree with java configs not being as elegant as the xml's though.

Collectives™ on Stack Overflow

Performance Logging with Spring Boot and AOP

2 Answers 2

1 Comment

1 Comment

Hot Network Questions

Collectives™ on Stack Overflow

2 Answers 2

1 Comment

1 Comment

Related