LoginSignup
22
18

More than 5 years have passed since last update.

JavaAdvent Calendar 2018Day 4
@opengl-8080inTIS株式会社

Doma2 でログ出力を制御する

Last updated at Posted at 2018-12-03

4日目担当の null です。

デフォルトだと、 INFO レベルでいっぱいログが出るので、そのへんを制御する。

環境

Java

openjdk 11.0.1 2018-10-16

Doma2

2.19.3

doma-spring-boot

1.1.1

Spring Boot

2.1.1

ソース（一部）

build.gradle
buildscript {
    ext {
        springBootVersion = '2.1.1.RELEASE'
    }
    repositories {
        mavenCentral()
    }
    dependencies {
        classpath("org.springframework.boot:spring-boot-gradle-plugin:${springBootVersion}")
    }
}

apply plugin: 'java'
apply plugin: 'org.springframework.boot'
apply plugin: 'io.spring.dependency-management'

sourceCompatibility = 11
targetCompatibility = 11

compileJava.options.encoding = "UTF-8"

repositories {
    mavenCentral()
}

dependencies {
    implementation('org.springframework.boot:spring-boot-starter-jdbc')
    implementation('org.seasar.doma.boot:doma-spring-boot-starter:1.1.1') {
        exclude group: 'org.seasar.doma', module: 'doma'
    }
    implementation('org.seasar.doma:doma:2.19.3')
    runtimeOnly('com.h2database:h2')
}

processResources.destinationDir = compileJava.destinationDir
compileJava.dependsOn processResources
TestTable.java
package sample.springboot.doma2;

import org.seasar.doma.Entity;
import org.seasar.doma.GeneratedValue;
import org.seasar.doma.GenerationType;
import org.seasar.doma.Id;
import org.seasar.doma.Table;

@Table(name = "TEST_TABLE")
@Entity
public class TestTable {
    @Id
    @GeneratedValue(strategy = GenerationType.IDENTITY)
    public Long id;
    public String name;

    @Override
    public String toString() {
        return "TestTable{" +
                "id=" + id +
                ", name='" + name + '\'' +
                '}';
    }
}
TestTableDao.java
package sample.springboot.doma2;

import org.seasar.doma.Dao;
import org.seasar.doma.Insert;
import org.seasar.doma.Select;
import org.seasar.doma.boot.ConfigAutowireable;

import java.util.List;

@Dao
@ConfigAutowireable
public interface TestTableDao {

    @Select
    List<TestTable> findAll();

    @Insert
    int insert(TestTable testTable);
}
Doma2Application.java
package sample.springboot.doma2;

import org.springframework.boot.SpringApplication;
import org.springframework.boot.autoconfigure.SpringBootApplication;
import org.springframework.context.ConfigurableApplicationContext;

@SpringBootApplication
public class Doma2Application {

    public static void main(String[] args) {
        try (ConfigurableApplicationContext context = SpringApplication.run(Doma2Application.class, args)) {
            TestTableDao dao = context.getBean(TestTableDao.class);

            System.out.println(dao.findAll());

            TestTable foo = new TestTable();
            foo.name = "foo";
            dao.insert(foo);

            TestTable bar = new TestTable();
            bar.name = "bar";
            dao.insert(bar);

            System.out.println(dao.findAll());
        }
    }
}

実行結果

2018-12-03 22:32:25.979  INFO 24784 --- [           main] o.s.doma.jdbc.UtilLoggingJdbcLogger      : [DOMA2220] ENTER  : クラス=[sample.springboot.doma2.TestTableDaoImpl], メソッド=[findAll]
2018-12-03 22:32:26.038  INFO 24784 --- [           main] o.s.doma.jdbc.UtilLoggingJdbcLogger      : [DOMA2076] SQLログ : SQLファイル=[META-INF/sample/springboot/doma2/TestTableDao/findAll.sql],
SELECT *
  FROM TEST_TABLE
2018-12-03 22:32:26.049  INFO 24784 --- [           main] o.s.doma.jdbc.UtilLoggingJdbcLogger      : [DOMA2221] EXIT   : クラス=[sample.springboot.doma2.TestTableDaoImpl], メソッド=[findAll]
[]
2018-12-03 22:32:26.049  INFO 24784 --- [           main] o.s.doma.jdbc.UtilLoggingJdbcLogger      : [DOMA2220] ENTER  : クラス=[sample.springboot.doma2.TestTableDaoImpl], メソッド=[insert]
2018-12-03 22:32:26.068  INFO 24784 --- [           main] o.s.doma.jdbc.UtilLoggingJdbcLogger      : [DOMA2076] SQLログ : SQLファイル=[null],
insert into TEST_TABLE (id, name) values (null, 'foo')
2018-12-03 22:32:26.071  INFO 24784 --- [           main] o.s.doma.jdbc.UtilLoggingJdbcLogger      : [DOMA2221] EXIT   : クラス=[sample.springboot.doma2.TestTableDaoImpl], メソッド=[insert]
2018-12-03 22:32:26.072  INFO 24784 --- [           main] o.s.doma.jdbc.UtilLoggingJdbcLogger      : [DOMA2220] ENTER  : クラス=[sample.springboot.doma2.TestTableDaoImpl], メソッド=[insert]
2018-12-03 22:32:26.072  INFO 24784 --- [           main] o.s.doma.jdbc.UtilLoggingJdbcLogger      : [DOMA2076] SQLログ : SQLファイル=[null],
insert into TEST_TABLE (id, name) values (null, 'bar')
2018-12-03 22:32:26.072  INFO 24784 --- [           main] o.s.doma.jdbc.UtilLoggingJdbcLogger      : [DOMA2221] EXIT   : クラス=[sample.springboot.doma2.TestTableDaoImpl], メソッド=[insert]
2018-12-03 22:32:26.072  INFO 24784 --- [           main] o.s.doma.jdbc.UtilLoggingJdbcLogger      : [DOMA2220] ENTER  : クラス=[sample.springboot.doma2.TestTableDaoImpl], メソッド=[findAll]
2018-12-03 22:32:26.073  INFO 24784 --- [           main] o.s.doma.jdbc.UtilLoggingJdbcLogger      : [DOMA2076] SQLログ : SQLファイル=[META-INF/sample/springboot/doma2/TestTableDao/findAll.sql],
SELECT *
  FROM TEST_TABLE
2018-12-03 22:32:26.075  INFO 24784 --- [           main] o.s.doma.jdbc.UtilLoggingJdbcLogger      : [DOMA2221] EXIT   : クラス=[sample.springboot.doma2.TestTableDaoImpl], メソッド=[findAll]
[TestTable{id=1, name='foo'}, TestTable{id=2, name='bar'}]

デフォルトだと、 Doma2 に関するログが INFO レベルで大量に出力されている。
このまま本番で動かすのはアレなので、 DEBUG レベルに出力したりいろいろ制御する。

Doma2 のログ出力の仕組み

doma2.jpg

  • Doma2 のログ出力は、 JdbcLogger インターフェースを介して行われている
  • 実装クラスとして、デフォルトで java.util.logging.Logger を使用する UtilLoggingJdbcLogger が用意されている
    • Spring Boot を利用している場合、 java.util.logging.Logger を使用していても最終的には SLF4J からログが出力されるようになっています
    • そのへんは jul-to-slf4jのしくみ - Qiita とかを参照ください
AbstractJdbcLogger.java
package org.seasar.doma.jdbc;

...

public abstract class AbstractJdbcLogger<LEVEL> implements JdbcLogger {

    /** デフォルトのログレベル */
    protected LEVEL defaultLevel;

    protected AbstractJdbcLogger(LEVEL level) {
        if (level == null) {
            throw new DomaNullPointerException("level");
        }
        this.defaultLevel = level;
    }

    @Override
    public void logDaoMethodEntering(String callerClassName,
            String callerMethodName, Object... args) {
        logDaoMethodEntering(callerClassName, callerMethodName, args,
                defaultLevel, () -> Message.DOMA2220.getMessage( // ★インスタンスフィールドのログレベルを渡してる
                        callerClassName, callerMethodName));
    }

    protected void logDaoMethodEntering(String callerClassName,
            String callerMethodName, Object args[], LEVEL level,
            Supplier<String> messageSupplier) {
        log(level, callerClassName, callerMethodName, null, messageSupplier);
    }

...
  • 例えば、 logDaoMethodEntering() は Dao のメソッドが開始されたときのログを出力する
  • このメソッドは、 protected な logDaoMethodEntering() を呼んでいて、引数のログレベル（LEVEL）に、インスタンスフィールドのデフォルトのログレベル（defaultLevel）を渡している
  • AbstractJdbcLogger には、他にも Dao が実行されるときのロギングメソッドが多数定義されているが、どれも構造は同じ
  • つまり、デフォルトは AbstractJdbcLogger の defaultLevel に設定されているログレベルでログが出力されることになる
  • そして、問題のデフォルトのログレベルが設定されている場所は UtilLoggingJdbcLogger の中
UtilLoggingJdbcLogger.java
package org.seasar.doma.jdbc;

...

public class UtilLoggingJdbcLogger extends AbstractJdbcLogger<Level> {

    /** このインスタンスで使用するロガーです。 */
    protected final Logger logger;

    ...
    public UtilLoggingJdbcLogger() {
        this(Level.INFO); // ★デフォルトコンストラクタで生成されると INFO レベルになる
    }

    ...
    public UtilLoggingJdbcLogger(Level level) {
        this(level, Logger.getLogger(UtilLoggingJdbcLogger.class.getName()));
    }

    ...
  • UtilLoggingJdbcLogger をデフォルトコンストラクタで生成した場合、ログレベルは INFO になる
  • Doma2 の設定で明示的に JdbcLogger のインスタンスを指定していない場合、 UtilLoggingJdbcLogger はデフォルトコンストラクタで生成されるので、結果としてログ出力レベルは全て INFO になる

デフォルトのログ出力レベルを変更する

doma-spring-boot を利用している場合、 Doma2 の設定は DomaConfigBuilder を利用して行えるようになっている。

Doma2Application.java
package sample.springboot.doma2;

import org.seasar.doma.boot.autoconfigure.DomaConfigBuilder;
import org.seasar.doma.jdbc.JdbcLogger;
import org.seasar.doma.jdbc.UtilLoggingJdbcLogger;
...
import org.springframework.context.annotation.Bean;

import java.util.logging.Level;

@SpringBootApplication
public class Doma2Application {

    public static void main(String[] args) {
        try (ConfigurableApplicationContext context = SpringApplication.run(Doma2Application.class, args)) {
            ...
        }
    }

    @Bean
    public JdbcLogger jdbcLogger() {
        return new UtilLoggingJdbcLogger(Level.FINE); // ★ ログレベルを FINE にして生成
    }

    @Bean
    public DomaConfigBuilder domaConfigBuilder() {
        DomaConfigBuilder builder = new DomaConfigBuilder();
        builder.jdbcLogger(jdbcLogger()); // ★ jdbcLogger を設定
        return builder;
    }
}
実行結果
[]
[TestTable{id=1, name='foo'}, TestTable{id=2, name='bar'}]
  • UtilLoggingJdbcLogger のコンストラクタ引数でログレベルを FINE にして生成し、 DomaConfigBuilder の jdbcLogger() にセットしている
  • これでログの出力レベルが FINE （SLF4J などにおける DEBUG レベル）になるので、ログが出力されなくなった
    • java.util.logging.Logger のログレベルと SLF4J のログレベルの対応は、 SLF4JBridgeHandler の Javadoc を参照

メソッドごとにログ出力レベルを変更する

「SQL の出力だけは INFO レベルで出したい」みたいに、特定のログだけはデフォルトのログレベルとは異なるレベルで出力したい場合は、たぶん次のようにする。

MyJdbcLogger.java
package sample.springboot.doma2;

import org.seasar.doma.jdbc.Sql;
import org.seasar.doma.jdbc.UtilLoggingJdbcLogger;

import java.util.function.Supplier;
import java.util.logging.Level;

// ★UtilLoggingJdbcLogger を継承して自作のロガーを作成
public class MyJdbcLogger extends UtilLoggingJdbcLogger {

    public MyJdbcLogger() {
        super(Level.FINE); // ★デフォルトのログレベルは FINE
    }

    // ★SQL を出力するロギングメソッドをオーバーライド
    @Override
    protected void logSql(String callerClassName, String callerMethodName, Sql<?> sql, Level level, Supplier<String> messageSupplier) {
        // ★引数の level (デフォルトログレベル) を無視して、強制的に INFO に差し替え
        super.logSql(callerClassName, callerMethodName, sql, Level.INFO, messageSupplier);
    }
}
Doma2Application.java
package sample.springboot.doma2;

...

@SpringBootApplication
public class Doma2Application {

    public static void main(String[] args) {
        try (ConfigurableApplicationContext context = SpringApplication.run(Doma2Application.class, args)) {
            ...
        }
    }

    @Bean
    public JdbcLogger jdbcLogger() {
        return new MyJdbcLogger(); // ★自作のロガーを使用
    }

    @Bean
    public DomaConfigBuilder domaConfigBuilder() {
        DomaConfigBuilder builder = new DomaConfigBuilder();
        builder.jdbcLogger(jdbcLogger());
        return builder;
    }
}
実行結果
2018-12-03 23:09:34.627  INFO 18180 --- [           main] o.s.doma.jdbc.UtilLoggingJdbcLogger      : [DOMA2076] SQLログ : SQLファイル=[META-INF/sample/springboot/doma2/TestTableDao/findAll.sql],
SELECT *
  FROM TEST_TABLE
[]
2018-12-03 23:09:34.656  INFO 18180 --- [           main] o.s.doma.jdbc.UtilLoggingJdbcLogger      : [DOMA2076] SQLログ : SQLファイル=[null],
insert into TEST_TABLE (id, name) values (null, 'foo')
2018-12-03 23:09:34.660  INFO 18180 --- [           main] o.s.doma.jdbc.UtilLoggingJdbcLogger      : [DOMA2076] SQLログ : SQLファイル=[null],
insert into TEST_TABLE (id, name) values (null, 'bar')
2018-12-03 23:09:34.661  INFO 18180 --- [           main] o.s.doma.jdbc.UtilLoggingJdbcLogger      : [DOMA2076] SQLログ : SQLファイル=[META-INF/sample/springboot/doma2/TestTableDao/findAll.sql],
SELECT *
  FROM TEST_TABLE
[TestTable{id=1, name='foo'}, TestTable{id=2, name='bar'}]
  • UtilLoggingJdbcLogger を継承して自作のロガーを作る
  • そして、ログレベルを変更したいロギングメソッド（protected の方）をオーバーライドして、ログレベルを変更したいレベルに差し替えている
  • これで、差し替えたロギングメソッドだけが、異なるログレベルで出力されるようになる

参考

以上、明日の Java アドベントカレンダー、担当は null さんです。
 誰か！書いて！！！！

明日の担当は @orekyuu さんです。

22
18
0

Register as a new user and use Qiita more conveniently

  1. You get articles that match your needs
  2. You can efficiently read back useful information
  3. You can use dark theme
What you can do with signing up
Sign upLogin
22
18