今回は、SQLログ出力内容をカスタマイズし、SQLの実行時間や呼出メソッドをSQLログに出力してみたので、そのサンプルプログラムを共有する。
前提条件
下記記事の実装が完了していること。
log4j2のファイルにymlを利用してみた前回は、log4j2のファイルにxmlファイルを利用していたが、今回はlog4j2のファイルにymlを利用してみたので、そのサンプルプロ...
サンプルプログラムの内容
今回のサンプルプログラムの構成は以下の通り。
なお、上記赤枠が前提条件のプログラムと変更になった箇所で「DemoSqlInvocation.java」が新規で作成したプログラムで、「build.gradle」「log4j2.yml」は変更したプログラムとなる。
また、上図には無いが、前提条件のプログラムに入っていた「mybatis-config.xml」は不要なので、今回削除している。
build.gradleの内容は以下の通りで、「Apache Common JEXL」を利用するための設定を追加している。なお、「Apache Common JEXL」は、SQLの埋め込みパラメータ値を取得するために利用している。
1 2 3 4 5 6 7 8 9 10 11 12 13 14 15 16 17 18 19 20 21 22 23 24 25 26 27 28 29 30 31 32 33 34 35 36 37 38 39 40 41 | plugins { id 'org.springframework.boot' version '2.1.7.RELEASE' id 'java' } apply plugin: 'io.spring.dependency-management' group = 'com.example' version = '0.0.1-SNAPSHOT' sourceCompatibility = '1.8' repositories { mavenCentral() } configurations { //log4j2を利用するため、Spring BootデフォルトのLogbackを利用しないよう設定 all*.exclude module : 'spring-boot-starter-logging' } dependencies { implementation 'org.springframework.boot:spring-boot-starter-thymeleaf' implementation 'org.springframework.boot:spring-boot-starter-web' testImplementation 'org.springframework.boot:spring-boot-starter-test' compileOnly 'org.projectlombok:lombok:1.18.10' annotationProcessor 'org.projectlombok:lombok:1.18.10' compile files('lib/ojdbc6.jar') implementation 'org.mybatis.spring.boot:mybatis-spring-boot-starter:2.1.1' compile group: 'org.springframework.data', name: 'spring-data-commons-core', version: '1.1.0.RELEASE' //log4j2を利用するための設定 compile group: 'org.apache.logging.log4j', name: 'log4j-api', version: '2.12.1' compile group: 'org.apache.logging.log4j', name: 'log4j-core', version: '2.12.1' //AOPを利用するための設定 implementation 'org.springframework.boot:spring-boot-starter-aop' //log4j2の設定でymlファイルを利用するための設定 compile group: 'com.fasterxml.jackson.dataformat', name: 'jackson-dataformat-yaml', version: '2.10.1' compile group: 'com.fasterxml.jackson.core', name: 'jackson-core', version: '2.10.1' compile group: 'com.fasterxml.jackson.core', name: 'jackson-databind', version: '2.10.1' //Apache Common JEXLを利用するための設定 compile group: 'org.apache.commons', name: 'commons-jexl3', version: '3.0' } |
また、application.ymlの内容は以下の通りで、log4j2でSQLログを出力するための「mybatis-config.xml」を読み込む設定を削除している。
1 2 3 4 5 6 7 8 9 10 11 12 13 | server: port: 8084 # DB接続情報 spring: datasource: url: jdbc:oracle:thin:@localhost:1521:xe username: USER01 password: USER01 driverClassName: oracle.jdbc.driver.OracleDriver # 一覧画面で1ページに表示する行数 demo: list: pageSize: 2 |
また、DemoSqlInvocation.javaの内容は以下の通りで、SQLの実行時間・呼出メソッド・SQLログを出力するようにしている。
1 2 3 4 5 6 7 8 9 10 11 12 13 14 15 16 17 18 19 20 21 22 23 24 25 26 27 28 29 30 31 32 33 34 35 36 37 38 39 40 41 42 43 44 45 46 47 48 49 50 51 52 53 54 55 56 57 58 59 60 61 62 63 64 65 66 67 68 69 70 71 72 73 74 75 76 77 78 79 80 81 82 83 84 85 86 87 88 89 90 91 92 93 94 95 96 97 98 99 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 142 143 144 145 146 | 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.apache.logging.log4j.LogManager; import org.apache.logging.log4j.Logger; 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 = LogManager.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-boot-custom-sqllog/demo
サンプルプログラムの実行結果
1) 検索し一覧を表示する場合の、画面とログ出力内容は以下の通り。
＜画面＞
＜ログ＞
2) データ更新を行う場合の、画面とログ出力内容は以下の通り。
＜画面＞
＜ログ＞
3) データ削除を行う場合の、画面とログ出力内容は以下の通り。
＜画面＞
＜ログ＞
4) データ追加を行う場合の、画面とログ出力内容は以下の通り。
＜画面＞
＜ログ＞
要点まとめ
- SQL実行時間をログ出力するようにするには、MyBatisのログ出力内容をカスタマイズすればよい。
