Log JPA transaction duration

Question

Is there a way to intercept JPA's start / commit / rollback transaction to trigger some behavior? More specifically, I would like to ensure that my transactions are "short-lived", and if a transaction takes over 1s from start to commit, I would like to log a warning.

I was thinking of doing some AOP on @Transactional but I'm also using transactionOperations.execute(status -> { ... }) and that wouldn't work there.

Answer 1

The easiest way is to write a TransactionExecutionListener. You can create one which logs the time, counts etc. and you can simply add it to your JpaTransactionManager. No need for additional AOP code or other callbacks and will work for anything that uses the PlatformTransactionManager.

NOTE: This class was introduced in Spring 6.1 so if you are on an older version this won't work.

public class TimingTransactionListener implements TransactionExecutionListener {

  private final Logger log = LoggerFactory.getLogger(TimingTransactionListener.class);
  private final ThreadLocal<Long> startTime = new ThreadLocal<>();
  
  @Override
  public void beforeBegin(TransactionExecution transaction) {
    startTime.set(System.currentTimeMillis());
  }

  @Override
  public void afterCommit(TransactionExecution transaction, Throwable commitFailure) {
    logTransactionCompletion(transaction, commitFailure);
  }

  @Override
  public void afterRollback(TransactionExecution transaction, Throwable rollbackFailure) {
    logTransactionCompletion(transaction, rollbackFailure);
  }
  
  private void logTransactionCompletion(TransactionExecution transaction, Throwable failure) {
    var success = failure == null;
    var time = System.currentTimeMillis() - startTime.get();
    startTime.remove();
    if (time > 1000) {
      log.warn("Transaction '{}' took '{}ms', rollback: {}.", transaction.getTransactionName(), time, success);
    } else {
      log.info("Transaction '{}' took '{}ms', rollback: {}.", transaction.getTransactionName(), time, success);
    }
  }
}

Next you can configure your JpaTransactionManager.

@Bean
public JpaTransactionManager transactionManager(EntityManagerFactory emf) {
  var transactionManager = new JpaTransactionManager(emf);
  transactionManager.addListener(new TimingTransactionListener());
  return transactionManager;
}

If you are in the ability to use Spring Boot the only thing you need to do is register the TimingTransactionListener as a bean and Spring Boot will automatically wire it to the pre-configured PlatformTransactionManager.

Ideally you wouldn't do this logging yourself but you would integrate with a library like MicroMeter and collect metrics with something like Prometheus. You can then get more insights and create alerts based on those metrics.