Logo Questions Linux Laravel Mysql Ubuntu Git Menu
 

How to log Spring Data JPA repository method execution time?

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(…))?

like image 773
luke Avatar asked Sep 22 '14 15:09

luke


People also ask

How are spring data repositories implemented at runtime?

In the repository interfaces, we can add the methods like findByCustomerNameAndPhone() (assuming customerName and phone are fields in the domain object). Then, Spring provides the implementation by implementing the above repository interface methods at runtime (during the application run).

How does findById work in JPA?

Its findById method retrieves an entity by its id. The return value is Optional<T> . Optional<T> is a container object which may or may not contain a non-null value. If a value is present, isPresent returns true and get returns the value.

How JPA save method works?

save(…) -Method. It will persist or merge the given entity using the underlying JPA EntityManager . If the entity has not been persisted yet Spring Data JPA will save the entity via a call to the entityManager.

What is @query used for spring data?

Spring Data JPA @Query The @Query annotation declares finder queries directly on repository methods. While similar @NamedQuery is used on domain classes, Spring Data JPA @Query annotation is used on Repository interface. This frees the domain classes from persistence specific information, which is a good thing.


2 Answers

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());
  }
}
like image 177
Oliver Drotbohm Avatar answered Oct 19 '22 15:10

Oliver Drotbohm


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;
    }
}
like image 43
luke Avatar answered Oct 19 '22 15:10

luke