今回は、Spring MVC上のサンプルプログラムで、MyBatisのカスタムSQLログを出力する処理を追加してみたので、そのサンプルプログラムを共有する。
前提条件
下記記事の実装が完了していること。
サンプルプログラムの作成
作成したサンプルプログラムの構成は以下の通り。

なお、上記の赤枠は、「前提条件」のプログラムから変更したプログラムである。
pom.xmlに追加した内容は以下の通りで、DemoSqlInvocation.javaで利用するcommons-jexl3を追加している。
<!-- Apache Common JEXL -->
<dependency>
<groupId>org.apache.commons</groupId>
<artifactId>commons-jexl3</artifactId>
<version>3.0</version>
</dependency>servlet-context.xmlの変更した内容は以下の通りで、sqlSessionFactory生成時にmybatis-config.xmlを読み込むようにしている。
<!-- MyBatisのMapperオブジェクトの生成 -->
<beans:bean id="sqlSessionFactory" class="org.mybatis.spring.SqlSessionFactoryBean">
<beans:property name="dataSource" ref="dataSource" />
<beans:property name="mapperLocations" value="classpath*:com/example/demo/*.xml" />
<beans:property name="configLocation" value="classpath:mybatis-config.xml" />
</beans:bean>mybatis-config.xmlは今回追加した定義ファイルで、DemoSqlInvocationクラスをmybatisのインターセプター(=横断的な処理)として追加している。
<?xml version="1.0" encoding="UTF-8" ?>
<!DOCTYPE configuration PUBLIC "-//mybatis.org//DTD Config 3.0//EN" "http://mybatis.org/dtd/mybatis-3-config.dtd">
<configuration>
<plugins>
<!-- Interceptor configuration -->
<plugin interceptor="com.example.demo.DemoSqlInvocation" />
</plugins>
</configuration> また、SQLログを出力するインターセプター(=横断的な処理)の内容は以下の通り。
package com.example.demo;
import org.apache.commons.jexl3.JexlEngine;
import org.apache.commons.jexl3.JexlBuilder;
import org.apache.commons.jexl3.JexlException;
import org.apache.ibatis.executor.Executor;
import org.apache.ibatis.mapping.BoundSql;
import org.apache.ibatis.mapping.MappedStatement;
import org.apache.ibatis.mapping.ParameterMapping;
import org.apache.ibatis.plugin.Intercepts;
import org.apache.ibatis.plugin.Signature;
import org.apache.ibatis.plugin.Interceptor;
import org.apache.ibatis.plugin.Invocation;
import org.apache.ibatis.plugin.Plugin;
import org.apache.ibatis.session.ResultHandler;
import org.apache.ibatis.session.RowBounds;
import org.slf4j.Logger;
import org.slf4j.LoggerFactory;
import org.springframework.stereotype.Component;
import java.util.List;
import java.util.Properties;
//select, update, insert, deleteの各SQLを実行するタイミングで、
//このクラスのinterceptメソッドが呼ばれるように、
//@Intercepts・@Signatureのアノテーションを下記のように設定
@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})
})
@Component
public class DemoSqlInvocation implements Interceptor {
//ログ出力のためのクラス
private Logger logger = LoggerFactory.getLogger(DemoSqlInvocation.class);
//SQLにマッピングされるパラメータ名に対応するパラメータ値を取得するために
//JexlEngineオブジェクトを利用
private JexlEngine engine = new JexlBuilder().create();
/**
* SQL実行前後に処理を追加する
*
* @param invocation メソッド呼出用オブジェクト
* @return SQL実行メソッドの戻り値
* @throws Throwable
*/
@Override
public Object intercept(Invocation invocation) throws Throwable {
//返却オブジェクトを定義
Object returnObj = null;
//SQL実行メソッドを実行し、その開始・終了時刻も取得
long start = System.currentTimeMillis();
returnObj = invocation.proceed();
long end = System.currentTimeMillis();
//SQL実行時間、実行メソッド名(フルパス)を出力
MappedStatement statement = (MappedStatement)invocation.getArgs()[0];
String[] items = statement.getId().split("\\.");
logger.info("実行時間: {} ms. 実行メソッド: {}"
, end-start, String.join(".", items));
//SQLログを出力
Object parameter = invocation.getArgs()[1];
BoundSql boundSql = statement.getBoundSql(parameter);
logger.info("Preparing: {}", shapingSql(boundSql.getSql()));
logger.info("Parameters: {}", getParameterValues(boundSql));
return returnObj;
}
@Override
public Object plugin(Object target) {
return Plugin.wrap(target, this);
}
@Override
public void setProperties(Properties properties) {
}
/**
* 引数のSQL文から、改行コード(LF)と連続する空白文字を除く
* @param beforeSql SQL文
* @return 整形後のSQL文
*/
private String shapingSql(String beforeSql){
if(DateCheckUtil.isEmpty(beforeSql)){
return beforeSql;
}
return beforeSql.replaceAll("\n", "")
.replaceAll(" {2,}", " ");
}
/**
* 引数のBoundSqlから、SQLに埋め込まれるパラメータ値を取得する
* @param boundSql BoundSqlオブジェクト
* @return SQLに埋め込まれるパラメータ値
*/
private String getParameterValues(final BoundSql boundSql) {
//返却用戻り値を格納
StringBuilder builder = new StringBuilder();
//パラメータ値を取得
Object param = boundSql.getParameterObject();
if(param == null){
//パラメータの設定が無い場合は、(No Params.)を返却
builder.append("(No Params.)");
return builder.toString();
}
//SQLにマッピングされるパラメータ名を取得
List<ParameterMapping> paramMapping = boundSql.getParameterMappings();
//SQLにマッピングされるパラメータ名に対応するパラメータ値を取得し、
//返却用戻り値に順次格納する
for (ParameterMapping mapping : paramMapping) {
String propValue = mapping.getProperty();
builder.append(propValue + "=");
try {
//SQLにマッピングされるパラメータ名に対応するパラメータ値を取得
builder.append(engine.getProperty(param, propValue));
builder.append(", ");
} catch (JexlException e) {
//パラメータ値がLong型の場合等はJexlExceptionが発生するため
//パラメータ値をそのまま指定する
builder.append(param);
builder.append(", ");
continue;
}
}
//返却用戻り値の最後のカンマを除く
if(builder.lastIndexOf(", ") > 0){
builder.deleteCharAt(builder.lastIndexOf(", "));
}
return builder.toString();
}
}
上記ソースコードは、下記記事と同じ実装内容になっている。
その他のソースコード内容は、以下のサイトを参照のこと。
https://github.com/purin-it/java/tree/master/spring-mvc-web-mybatis-log/demo
サンプルプログラムの実行結果
1) サーバーを起動後、Webブラウザ上で「http://(サーバー名):(ポート番号)/(プロジェクト名)/」とアクセスすると、以下の画面が表示されるので、「検索」ボタンを押下

3) このときのコンソールログは以下の通りで、下記赤枠のログがDemoSqlInvocation.javaによって出力されたことが確認できる。

5) 下記入力画面が表示されるので、内容を更新し「確認」ボタンを押下


8) このときのコンソールログは以下の通りで、下記赤枠のログがDemoSqlInvocation.javaによって出力されたことが確認できる

要点まとめ
- Spring MVCプロジェクトでSQLログを出力するには、servlet-context.xmlでsqlSessionFactory生成時にmybatis-config.xmlを読み込むようにし、mybatis-config.xmlに、SQLログを出力するインターセプターを追加すればよい。









