Spring MVCでMyBatisのSQLログ出力をしてみた｜ITエンジニアとして経験・学習したこと

今回は、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>

<groupId>org.apache.commons</groupId>

<artifactId>commons-jexl3</artifactId>

</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>

<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>

<?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">

</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();
    }

}

100

101

102

103

104

105

106

107

108

109

110

111

112

113

114

115

116

117

118

119

120

121

122

123

124

125

126

127

128

129

130

131

132

133

134

135

136

137

138

139

140

141

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://(サーバー名):(ポート番号)/(プロジェクト名)/」とアクセスすると、以下の画面が表示されるので、「検索」ボタンを押下

2) 以下の一覧画面が表示される

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

4) 更新したいデータの「更新」リンクを押下

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

6) 下記確認画面が表示されるので、「送信」ボタンを押下

7) 以下の完了画面が表示される

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

要点まとめ

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

前提条件

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

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

要点まとめ

Spring MVCを利用してみた

Spring MVCで複数画面をもつWEBアプリケーションを作成してみた

Spring MVCでAOPを利用してみた

Spring MVCでMyBatisによるOracle連携処理を実装してみた

Spring MVCでSpring Securityを利用してみた

Spring MVCでSpring SecurityのCSRFトークンチェックを変更しエラー制御を追加してみた