ヰ刀のおもちゃ箱 music×IT×guiter×programing

【Spring Boot】【MyBatis】SQL実行時のlogging出力設定（一番お手軽なやつ）

spring frameworkでmybatisを使っていた時はlog4jやらlogbackの設定やらをゴリゴリ記述してログを出していたけど、
Spring bootでmybatisを使用する時はデフォルトでlogging機能がついているらしく、とてもお手軽にSQLのログを出力することが出来ました。
結論は、application.propertiesまたはapplication.ymlにlogging設定を追記するだけです。

目次

実験対象のAP

設定

pom.xml

<dependency>
    <groupId>org.mybatis.spring.boot</groupId>
    <artifactId>mybatis-spring-boot-starter</artifactId>
</dependency>

springBootでmybatisを使用するプラグインを使います。
ここにデフォルトでlogging機能が備わっています。
なので、「とにかくSQLログを出したい」という分には
sl4jやらlog4jやらlogbackの設定は行わなくていいです。

application.yml(logging適用前)

spring:
  datasource:
    url: jdbc:postgresql://XXX.XXX.X.X:5432/databaseName
    username: postgres
    password: postgres
    driver-class-name: org.postgresql.Driver

datasource設定しかしてません。

AP

SQLを使うメインのMapper設定です。

DemoMapperXml.java

package com.example.demo.repository;

import org.apache.ibatis.annotations.Mapper;
import org.apache.ibatis.annotations.Param;

import com.example.demo.entity.Country;

@Mapper
public interface DemoMapperXml {

    Country selectCountry(@Param("id") Integer id);

}

実際のSQLはxmlに記載してあります。

DemoMapperXmlTest.java

package com.example.demo.repository;

import static org.assertj.core.api.Assertions.assertThat;

import org.junit.jupiter.api.AfterEach;
import org.junit.jupiter.api.BeforeEach;
import org.junit.jupiter.api.Test;
import org.springframework.beans.factory.annotation.Autowired;
import org.springframework.boot.test.context.SpringBootTest;

import com.example.demo.entity.Country;

@SpringBootTest
public class DemoMapperXmlTest {

    @Autowired
    DemoMapperXml target;
    
    @Test
    void wiringCountryXmlTest() {

        // action
        Country act = target.selectCountry(87);

        // assert
        assertThat(act).isNotNull();

    }
}

テスト実行結果

21:12:16.383 [main] DEBUG org.springframework.test.context.support.TestPropertySourceUtils - Adding inlined properties to environment: {spring.jmx.enabled=false, org.springframework.boot.test.context.SpringBootTestContextBootstrapper=true, server.port=-1}

  .   ____          _            __ _ _
 /\\ / ___'_ __ _ _(_)_ __  __ _ \ \ \ \
( ( )\___ | '_ | '_| | '_ \/ _` | \ \ \ \
 \\/  ___)| |_)| | | | | || (_| |  ) ) ) )
  '  |____| .__|_| |_|_| |_\__, | / / / /
 =========|_|==============|___/=/_/_/_/
 :: Spring Boot ::        (v2.1.3.RELEASE)

2019-07-08 21:12:16.596  INFO 11512 --- [           main] c.e.demo.repository.DemoMapperXmlTest    : Starting DemoMapperXmlTest on DESKTOP-V67CH51 with PID 11512 (started by white sleipnir in F:\github\itouoti\Spring_Boot\mybatis_nestMapper)
2019-07-08 21:12:16.597  INFO 11512 --- [           main] c.e.demo.repository.DemoMapperXmlTest    : No active profile set, falling back to default profiles: default
2019-07-08 21:12:17.699  INFO 11512 --- [           main] o.s.s.concurrent.ThreadPoolTaskExecutor  : Initializing ExecutorService 'applicationTaskExecutor'
2019-07-08 21:12:17.916  INFO 11512 --- [           main] o.s.b.a.w.s.WelcomePageHandlerMapping    : Adding welcome page template: index
2019-07-08 21:12:18.279  INFO 11512 --- [           main] c.e.demo.repository.DemoMapperXmlTest    : Started DemoMapperXmlTest in 1.888 seconds (JVM running for 2.675)
2019-07-08 21:12:18.479  INFO 11512 --- [           main] com.zaxxer.hikari.HikariDataSource       : HikariPool-1 - Starting...
2019-07-08 21:12:18.604  INFO 11512 --- [           main] com.zaxxer.hikari.HikariDataSource       : HikariPool-1 - Start completed.
2019-07-08 21:12:18.689  INFO 11512 --- [       Thread-2] com.zaxxer.hikari.HikariDataSource       : HikariPool-1 - Shutdown initiated...
2019-07-08 21:12:18.690  INFO 11512 --- [       Thread-2] com.zaxxer.hikari.HikariDataSource       : HikariPool-1 - Shutdown completed.
2019-07-08 21:12:18.690  INFO 11512 --- [       Thread-2] o.s.s.concurrent.ThreadPoolTaskExecutor  : Shutting down ExecutorService 'applicationTaskExecutor'

Process finished with exit code 0

こんな感じでSQLの結果は出ません。

SQLをコンソールに出力する設定

application.yml(修正後)

spring:
  datasource:
    url: jdbc:postgresql://xxx.xxx.x.x:5432/databaseName
    username: postgres
    password: postgres
    driver-class-name: org.postgresql.Driver

logging:
  level:
    org:
      springframework: WARN
    com:
      example:
        demo:
          repository:
            DemoMapperXml: DEBUG

DemoMapperXml.javaの実行時にSQLを出力させるように設定を変更しました。
また、パッケージ単位でSQLを出力させたいときは、パッケージに対してログ出力の設定を行えばOKです。

logging:
  level:
    org:
      springframework: WARN
    com:
      example:
        demo:
          repository: DEBUG

実行結果

21:17:54.075 [main] DEBUG org.springframework.test.context.support.TestPropertySourceUtils - Adding inlined properties to environment: {spring.jmx.enabled=false, org.springframework.boot.test.context.SpringBootTestContextBootstrapper=true, server.port=-1}

  .   ____          _            __ _ _
 /\\ / ___'_ __ _ _(_)_ __  __ _ \ \ \ \
( ( )\___ | '_ | '_| | '_ \/ _` | \ \ \ \
 \\/  ___)| |_)| | | | | || (_| |  ) ) ) )
  '  |____| .__|_| |_|_| |_\__, | / / / /
 =========|_|==============|___/=/_/_/_/
 :: Spring Boot ::        (v2.1.3.RELEASE)

2019-07-08 21:17:54.351  INFO 7840 --- [           main] c.e.demo.repository.DemoMapperXmlTest    : Starting DemoMapperXmlTest on DESKTOP-V67CH51 with PID 7840 (started by white sleipnir in F:\github\itouoti\Spring_Boot\mybatis_nestMapper)
2019-07-08 21:17:54.352 DEBUG 7840 --- [           main] c.e.demo.repository.DemoMapperXmlTest    : Running with Spring Boot v2.1.3.RELEASE, Spring v5.1.5.RELEASE
2019-07-08 21:17:54.352  INFO 7840 --- [           main] c.e.demo.repository.DemoMapperXmlTest    : No active profile set, falling back to default profiles: default
2019-07-08 21:17:56.082  INFO 7840 --- [           main] c.e.demo.repository.DemoMapperXmlTest    : Started DemoMapperXmlTest in 1.997 seconds (JVM running for 2.817)
2019-07-08 21:17:56.237  INFO 7840 --- [           main] com.zaxxer.hikari.HikariDataSource       : HikariPool-1 - Starting...
2019-07-08 21:17:56.371  INFO 7840 --- [           main] com.zaxxer.hikari.HikariDataSource       : HikariPool-1 - Start completed.
2019-07-08 21:17:56.377 DEBUG 7840 --- [           main] c.e.d.r.DemoMapperXml.selectCountry      : ==>  Preparing: SELECT * FROM country, city, address WHERE country.country_id = ? AND country.country_id = city.country_id AND city.city_id = address.city_id 
2019-07-08 21:17:56.387 DEBUG 7840 --- [           main] c.e.d.r.DemoMapperXml.selectCountry      : ==> Parameters: 87(Integer)
2019-07-08 21:17:56.408 DEBUG 7840 --- [           main] c.e.d.r.DemoMapperXml.selectCountry      : <==      Total: 5
2019-07-08 21:17:56.468  INFO 7840 --- [       Thread-2] com.zaxxer.hikari.HikariDataSource       : HikariPool-1 - Shutdown initiated...
2019-07-08 21:17:56.470  INFO 7840 --- [       Thread-2] com.zaxxer.hikari.HikariDataSource       : HikariPool-1 - Shutdown completed.

Process finished with exit code 0

処理実行時のSQLがコンソールに出力されました。

ソース

githubにあげてます。
https://github.com/itouoti12/mybatis_nestMapper

mybatisカテゴリの最新記事