Spring MVC

Spring MVCでMyBatisのSQLログ出力をしてみた

今回は、Spring MVC上のサンプルプログラムで、MyBatisのカスタムSQLログを出力する処理を追加してみたので、そのサンプルプログラムを共有する。

前提条件

下記記事の実装が完了していること。

Spring MVCでAOPを利用してみた今回は、Spring MVC上のサンプルプログラムで、AOP(Aspect Oriented Programming、アスペクト指向プロ...

サンプルプログラムの作成

作成したサンプルプログラムの構成は以下の通り。
サンプルプログラムの構成
なお、上記の赤枠は、「前提条件」のプログラムから変更したプログラムである。



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>
削除または保存していないWordドキュメントの復元方法【4DDiG Windowsデータ復元】ワード(Word)データ等のファイルを誤って削除してしまった場合は、通常はデータの復元ができませんが、4DDiGというソフトウェアを利用...

また、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();
    }

}

上記ソースコードは、下記記事と同じ実装内容になっている。

SQLログ出力内容をカスタマイズしてみた今回は、SQLログ出力内容をカスタマイズし、SQLの実行時間や呼出メソッドをSQLログに出力してみたので、そのサンプルプログラムを共有す...

その他のソースコード内容は、以下のサイトを参照のこと。
https://github.com/purin-it/java/tree/master/spring-mvc-web-mybatis-log/demo

サンプルプログラムの実行結果

1) サーバーを起動後、Webブラウザ上で「http://(サーバー名):(ポート番号)/(プロジェクト名)/」とアクセスすると、以下の画面が表示されるので、「検索」ボタンを押下
サンプルプログラムの実行_1

2) 以下の一覧画面が表示される
サンプルプログラムの実行_2

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

4) 更新したいデータの「更新」リンクを押下
サンプルプログラムの実行_4

5) 下記入力画面が表示されるので、内容を更新し「確認」ボタンを押下
サンプルプログラムの実行_5_1

サンプルプログラムの実行_5_2

6) 下記確認画面が表示されるので、「送信」ボタンを押下
サンプルプログラムの実行_6

7) 以下の完了画面が表示される
サンプルプログラムの実行_7

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

要点まとめ

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