How to create performance listener for MyBatis statements

Question

I would like to create a sort of Quality of Service for MyBatis statements, a sort of global performance listener which will analyze all executed MyBatis statements and log those that return too many hits or take too long. If possible in such a way that the impact on the existing business logic is as small as possible.

Answer 1

You can create implementation of Interceptor interface and register it as a plugin in configuration file.

Answer 2

I only did a quick test, but a custom interceptor (a.k.a. plugin) like the following should do the job.

The message is logged only when 1) the log level is DEBUG or finer and 2) the execution time exceeds the value of the constant THRESHOLD_NANOS.

import java.text.MessageFormat;

import org.apache.ibatis.executor.Executor;
import org.apache.ibatis.logging.Log;
import org.apache.ibatis.logging.LogFactory;
import org.apache.ibatis.mapping.MappedStatement;
import org.apache.ibatis.plugin.Interceptor;
import org.apache.ibatis.plugin.Intercepts;
import org.apache.ibatis.plugin.Invocation;
import org.apache.ibatis.plugin.Signature;
import org.apache.ibatis.session.ResultHandler;
import org.apache.ibatis.session.RowBounds;

@Intercepts({
  @Signature(
      type = Executor.class,
      method = "update",
      args = { MappedStatement.class, Object.class }),
  @Signature(
      type = Executor.class,
      method = "query",
      args = { MappedStatement.class, Object.class,
        RowBounds.class, ResultHandler.class })
})
public class LogExecutionTimeInterceptor implements Interceptor {

  private static final Log log = LogFactory.getLog(LogExecutionTimeInterceptor.class);

  private static final long THRESHOLD_NANOS = 0L;

  @Override
  public Object intercept(Invocation invocation) throws Throwable {
    long before = System.nanoTime();
    Object result = invocation.proceed();
    long duration = System.nanoTime() - before;

    if (duration > THRESHOLD_NANOS && log.isDebugEnabled()) {
      MappedStatement mappedStatement = (MappedStatement) invocation.getArgs()[0];
      log.debug(MessageFormat.format(
          "Statement {0} took {1} nano seconds", mappedStatement.getId(), duration));
    }
    return result;
  }

}

To register the interceptor...

1. with XML configuration

<plugins>
  <plugin
      interceptor="xxx.yyy.LogExecutionTimeInterceptor" />
</plugins>

2. with mybatis-spring-boot-starter

@Bean
Interceptor getLogExecutionTimeInterceptor() {
  return new LogExecutionTimeInterceptor();
}