8

I have simple Spring Data JPA repository.

public interface UserRepository extends JpaRepository<UserEntity, Serializable>{ … }

Is there any way to monitor execution time for methods generated by Spring (for example findOne(…))?

Oliver Drotbohm
  • 80,157
  • 18
  • 225
  • 211
luke
  • 193
  • 1
  • 1
  • 6

2 Answers2

14

The easiest way is to use a CustomizableTraceInterceptor as follows:

@Configuration
@EnableAspectJAutoProxy
public class SpringDataExecutionLoggingConfiguration {

  @Bean
  public CustomizableTraceInterceptor customizableTraceInterceptor() {

    CustomizableTraceInterceptor customizableTraceInterceptor = new CustomizableTraceInterceptor();
    customizableTraceInterceptor.setUseDynamicLogger(true);
    customizableTraceInterceptor.setExitMessage("Executed $[methodName] in $[invocationTime]");
    return customizableTraceInterceptor;
  }

  @Bean
  public Advisor advisor() {

    AspectJExpressionPointcut pointcut = new AspectJExpressionPointcut();
    pointcut.setExpression("execution(public * org.springframework.data.repository.CrudRepository+.*(..))");
    return new DefaultPointcutAdvisor(pointcut, customizableTraceInterceptor());
  }
}
Ganesh Krishnan
  • 7,155
  • 2
  • 44
  • 52
Oliver Drotbohm
  • 80,157
  • 18
  • 225
  • 211
  • Shoudn't the pointcut be: "execution(public * org.springframework.data.repository.Repository+.*(..))" ? – peceps Aug 17 '16 at 15:37
  • 4
    It does not work, I got: java.lang.IllegalArgumentException: warning no match for this type name: org.springframework.data.jpa.repository.CrudRepository [Xlint:invalidAbsoluteTypeName] – Kamil Nękanowicz Oct 24 '16 at 13:08
  • execution(public * org.springframework.data.repository.CrudRepository+.*(..)) – zhaozhi Aug 20 '20 at 09:29
11

Another working solution:

@Aspect
@Component
public class ProfilerAspect {
    Logger logger = LoggerFactory.getLogger(this.getClass());

    @Pointcut("execution(public * org.springframework.data.repository.Repository+.*(..))")
    public void monitor() {}

    @Around("monitor()")
    public Object profile(ProceedingJoinPoint pjp) {
        long start = System.currentTimeMillis();
        logger.debug("JVM memory in use = "+ (Runtime.getRuntime().totalMemory() - Runtime.getRuntime().freeMemory()));
        Object output = null;
        try {
            output = pjp.proceed();
        } catch (Throwable e) {
            logger.error(e.getMessage(), e);
        }
        long elapsedTime = System.currentTimeMillis() - start;
        logger.debug(pjp.getTarget()+"."+pjp.getSignature()+": Execution time: " + elapsedTime + " ms. ("+ elapsedTime/60000 + " minutes)");

        return output;
    }
}
luke
  • 193
  • 1
  • 1
  • 6
  • 3
    This is cool except that it is swallowing exceptions and returning null which may not be the desired behavior. – TiGz Jan 25 '18 at 11:20