CLOVER🍀

That was when it all began.

DomaのロガーをSLF4Jにする

これは、なにをしたくて書いたもの?

DomaのログをSLF4Jに変更できるということを知らなかったので、1度確認しておこうかなと。

Doma SLF4Jサポート

doma-slf4jというものを使うとSlf4jJdbcLoggerが使えるようになり、UtilLoggingJdbcLoggerの代わりにJdbcLoggerとして
使うことでログ出力をj.u.l.LoggerからSLF4Jに切り替えることができます。

SLF4J support — Doma documentation

Doma 2.43.0(2020年9月末付近)から使える機能なんですね。

使い方自体は上記のとおりなので、今回はこちらを簡単に試してみようと思います。

なお、Slf4jJdbcLoggerが出力するログのデフォルトのログレベルはDEBUGです。

ドキュメントに書かれていますが、ロガーの名前はorg.seasar.doma.jdbc.LogKind.[ログ種の名前]となっています。

環境

今回の環境は、こちらです。

$ java --version
openjdk 11.0.11 2021-04-20
OpenJDK Runtime Environment (build 11.0.11+9-Ubuntu-0ubuntu2.20.04)
OpenJDK 64-Bit Server VM (build 11.0.11+9-Ubuntu-0ubuntu2.20.04, mixed mode, sharing)


$ mvn --version
Apache Maven 3.8.1 (05c21c65bdfed0f71a2f2ada8b84da59348c4c5d)
Maven home: $HOME/.sdkman/candidates/maven/current
Java version: 11.0.11, vendor: Ubuntu, runtime: /usr/lib/jvm/java-11-openjdk-amd64
Default locale: ja_JP, platform encoding: UTF-8
OS name: "linux", version: "5.4.0-72-generic", arch: "amd64", family: "unix"

データベースはMySQL 8.0.24を使い、172.17.0.2でアクセスできるものとします。

準備

Maven依存関係は、このようにしました。

    <dependencies>
        <dependency>
            <groupId>org.seasar.doma</groupId>
            <artifactId>doma-core</artifactId>
            <version>2.46.1</version>
        </dependency>
        <dependency>
            <groupId>org.seasar.doma</groupId>
            <artifactId>doma-slf4j</artifactId>
            <version>2.46.1</version>
        </dependency>
        <dependency>
            <groupId>org.seasar.doma</groupId>
            <artifactId>doma-processor</artifactId>
            <version>2.46.1</version>
            <optional>true</optional>
        </dependency>
        <dependency>
            <groupId>org.slf4j</groupId>
            <artifactId>slf4j-simple</artifactId>
            <version>1.7.30</version>
        </dependency>
        <dependency>
            <groupId>mysql</groupId>
            <artifactId>mysql-connector-java</artifactId>
            <version>8.0.24</version>
        </dependency>
    </dependencies>

MySQL Connector/Jのスコープがruntimeになっていないのは、AbandonedConnectionCleanupThreadを使ったからです…。
ソースコードに出てきます

SLF4Jが利用するログ実装は、slf4j-simpleとしました。

ソースコードを作成する

では、ソースコードを作成していきます。

Configクラス。

src/main/java/org/littlewings/doma/DomaConfig.java

package org.littlewings.doma;

import javax.sql.DataSource;

import org.seasar.doma.jdbc.Config;
import org.seasar.doma.jdbc.JdbcLogger;
import org.seasar.doma.jdbc.Naming;
import org.seasar.doma.jdbc.Slf4jJdbcLogger;
import org.seasar.doma.jdbc.dialect.Dialect;
import org.seasar.doma.jdbc.dialect.MysqlDialect;
import org.seasar.doma.jdbc.tx.LocalTransactionDataSource;
import org.seasar.doma.jdbc.tx.LocalTransactionManager;
import org.seasar.doma.jdbc.tx.TransactionManager;
import org.slf4j.event.Level;

public class DomaConfig implements Config {
    static final DomaConfig CONFIG = new DomaConfig();

    Dialect dialect = new MysqlDialect();
    JdbcLogger jdbcLogger = new Slf4jJdbcLogger();
    LocalTransactionDataSource dataSource =
            new LocalTransactionDataSource(
                    "jdbc:mysql://172.17.0.2:3306/practice?characterEncoding=utf-8&characterSetResults=utf-8",
                    "kazuhira",
                    "password"
            );
    TransactionManager transactionManager = new LocalTransactionManager(dataSource, jdbcLogger);

    public static DomaConfig singleton() {
        return CONFIG;
    }

    @Override
    public DataSource getDataSource() {
        return dataSource;
    }

    @Override
    public Dialect getDialect() {
        return dialect;
    }

    @Override
    public JdbcLogger getJdbcLogger() {
        return jdbcLogger;
    }

    @Override
    public TransactionManager getTransactionManager() {
        return transactionManager;
    }

    @Override
    public Naming getNaming() {
        return Naming.SNAKE_LOWER_CASE;
    }
}

DataSource等いろいろ書いていますが、ポイントはSlf4jJdbcLoggerを使って

    JdbcLogger jdbcLogger = new Slf4jJdbcLogger();

getJdbcLoggerメソッドの戻り値とすることだけですね。

    @Override
    public JdbcLogger getJdbcLogger() {
        return jdbcLogger;
    }

エンティティクラス。

src/main/java/org/littlewings/doma/Book.java

package org.littlewings.doma;

import org.seasar.doma.Entity;
import org.seasar.doma.Id;

@Entity
public class Book {
    @Id
    String isbn;

    String title;

    Integer price;

    public static Book create(String isbn, String title, Integer price) {
        Book book = new Book();

        book.setIsbn(isbn);
        book.setTitle(title);
        book.setPrice(price);

        return book;
    }

    // getter/setterは省略
}

Daoインターフェース。

src/main/java/org/littlewings/doma/BookDao.java

package org.littlewings.doma;

import java.util.stream.Stream;

import org.seasar.doma.Dao;
import org.seasar.doma.Insert;
import org.seasar.doma.Script;
import org.seasar.doma.Select;
import org.seasar.doma.Sql;

@Dao
public interface BookDao {
    @Sql("drop table if exists book; create table book(isbn varchar(14), title varchar(100), price int, primary key(isbn))")
    @Script
    void createTable();

    @Insert
    int insert(Book book);

    @Sql("select * from book where isbn = /* isbn */'dummy'")
    @Select
    Book selectByIsbn(String isbn);

    @Sql("select * from book order by price desc")
    @Select
    Stream<Book> selectAllOrderByPrice();
}

メインクラス。

src/main/java/org/littlewings/doma/App.java

package org.littlewings.doma;

import com.mysql.cj.jdbc.AbandonedConnectionCleanupThread;
import org.seasar.doma.jdbc.tx.TransactionManager;

public class App {
    public static void main(String... args) {
        System.setProperty("org.slf4j.simpleLogger.defaultLogLevel", "DEBUG");

        DomaConfig config = DomaConfig.singleton();
        TransactionManager tm = config.getTransactionManager();
        BookDao dao = new BookDaoImpl(config);

        tm.required(() -> {
            dao.createTable();

            dao.insert(Book.create("978-4798161488", "MySQL徹底入門 第4版 MySQL 8.0対応", 4180));
            dao.insert(Book.create("978-4873116389", "実践ハイパフォーマンスMySQL 第3版", 5280));
            dao.insert(Book.create("978-4798147406", "詳解MySQL 5.7 止まらぬ進化に乗り遅れないためのテクニカルガイド", 3960));
        });

        tm.required(() -> {
            Book book = dao.selectByIsbn("978-4798161488");
            System.out.printf("simple: %s / %s / %d%n", book.getIsbn(), book.getTitle(), book.getPrice());

            dao.selectAllOrderByPrice().forEach(b -> System.out.printf("foreach: %s / %s / %d%n", b.getIsbn(), b.getTitle(), b.getPrice()));
        });

        AbandonedConnectionCleanupThread.checkedShutdown();
    }
}

使い方自体には特に注意点はないのですが、先述のとおりSlf4jJdbcLoggerが出力時のログレベルはDEBUGなので、
slf4j-simpleのデフォルトログレベルもDEBUGにしておきました。

        System.setProperty("org.slf4j.simpleLogger.defaultLogLevel", "DEBUG");

確認

プログラムができたので、実行します。

$ mvn compile exec:java -Dexec.mainClass=org.littlewings.doma.App

すると、こんな感じのログが得られます。

[org.littlewings.doma.App.main()] DEBUG org.seasar.doma.jdbc.LogKind.LOCAL_TRANSACTION - [DOMA2063] The local transaction "165839599" is begun.
[org.littlewings.doma.App.main()] DEBUG org.seasar.doma.jdbc.LogKind.DAO - [DOMA2220] ENTER  : CLASS=org.littlewings.doma.BookDaoImpl, METHOD=createTable
[org.littlewings.doma.App.main()] DEBUG org.seasar.doma.jdbc.LogKind.SQL.SCRIPT - [DOMA2076] SQL LOG : PATH=[org.littlewings.doma.BookDao#createTable],
drop table if exists book
[org.littlewings.doma.App.main()] DEBUG org.seasar.doma.jdbc.LogKind.SQL.SCRIPT - [DOMA2076] SQL LOG : PATH=[org.littlewings.doma.BookDao#createTable],
create table book(isbn varchar(14), title varchar(100), price int, primary key(isbn))
[org.littlewings.doma.App.main()] DEBUG org.seasar.doma.jdbc.LogKind.DAO - [DOMA2221] EXIT   : CLASS=org.littlewings.doma.BookDaoImpl, METHOD=createTable
[org.littlewings.doma.App.main()] DEBUG org.seasar.doma.jdbc.LogKind.DAO - [DOMA2220] ENTER  : CLASS=org.littlewings.doma.BookDaoImpl, METHOD=insert
[org.littlewings.doma.App.main()] DEBUG org.seasar.doma.jdbc.LogKind.SQL.INSERT - [DOMA2076] SQL LOG : PATH=[null],
insert into book (isbn, title, price) values ('978-4798161488', 'MySQL徹底入門 第4版 MySQL 8.0対応', 4180)
[org.littlewings.doma.App.main()] DEBUG org.seasar.doma.jdbc.LogKind.DAO - [DOMA2221] EXIT   : CLASS=org.littlewings.doma.BookDaoImpl, METHOD=insert
[org.littlewings.doma.App.main()] DEBUG org.seasar.doma.jdbc.LogKind.DAO - [DOMA2220] ENTER  : CLASS=org.littlewings.doma.BookDaoImpl, METHOD=insert
[org.littlewings.doma.App.main()] DEBUG org.seasar.doma.jdbc.LogKind.SQL.INSERT - [DOMA2076] SQL LOG : PATH=[null],
insert into book (isbn, title, price) values ('978-4873116389', '実践ハイパフォーマンスMySQL 第3版', 5280)
[org.littlewings.doma.App.main()] DEBUG org.seasar.doma.jdbc.LogKind.DAO - [DOMA2221] EXIT   : CLASS=org.littlewings.doma.BookDaoImpl, METHOD=insert
[org.littlewings.doma.App.main()] DEBUG org.seasar.doma.jdbc.LogKind.DAO - [DOMA2220] ENTER  : CLASS=org.littlewings.doma.BookDaoImpl, METHOD=insert
[org.littlewings.doma.App.main()] DEBUG org.seasar.doma.jdbc.LogKind.SQL.INSERT - [DOMA2076] SQL LOG : PATH=[null],
insert into book (isbn, title, price) values ('978-4798147406', '詳解MySQL 5.7 止まらぬ進化に乗り遅れないためのテクニカルガイド', 3960)
[org.littlewings.doma.App.main()] DEBUG org.seasar.doma.jdbc.LogKind.DAO - [DOMA2221] EXIT   : CLASS=org.littlewings.doma.BookDaoImpl, METHOD=insert
[org.littlewings.doma.App.main()] DEBUG org.seasar.doma.jdbc.LogKind.LOCAL_TRANSACTION - [DOMA2067] The local transaction "165839599" is committed.
[org.littlewings.doma.App.main()] DEBUG org.seasar.doma.jdbc.LogKind.LOCAL_TRANSACTION - [DOMA2064] The local transaction "165839599" is ended.
[org.littlewings.doma.App.main()] DEBUG org.seasar.doma.jdbc.LogKind.LOCAL_TRANSACTION - [DOMA2063] The local transaction "151768958" is begun.
[org.littlewings.doma.App.main()] DEBUG org.seasar.doma.jdbc.LogKind.DAO - [DOMA2220] ENTER  : CLASS=org.littlewings.doma.BookDaoImpl, METHOD=selectByIsbn
[org.littlewings.doma.App.main()] DEBUG org.seasar.doma.jdbc.LogKind.SQL.SELECT - [DOMA2076] SQL LOG : PATH=[org.littlewings.doma.BookDao#selectByIsbn],
select * from book where isbn = '978-4798161488'
[org.littlewings.doma.App.main()] DEBUG org.seasar.doma.jdbc.LogKind.DAO - [DOMA2221] EXIT   : CLASS=org.littlewings.doma.BookDaoImpl, METHOD=selectByIsbn
simple: 978-4798161488 / MySQL徹底入門 第4版 MySQL 8.0対応 / 4180
[org.littlewings.doma.App.main()] DEBUG org.seasar.doma.jdbc.LogKind.DAO - [DOMA2220] ENTER  : CLASS=org.littlewings.doma.BookDaoImpl, METHOD=selectAllOrderByPrice
[org.littlewings.doma.App.main()] DEBUG org.seasar.doma.jdbc.LogKind.SQL.SELECT - [DOMA2076] SQL LOG : PATH=[org.littlewings.doma.BookDao#selectAllOrderByPrice],
select * from book order by price desc
[org.littlewings.doma.App.main()] DEBUG org.seasar.doma.jdbc.LogKind.DAO - [DOMA2221] EXIT   : CLASS=org.littlewings.doma.BookDaoImpl, METHOD=selectAllOrderByPrice
foreach: 978-4873116389 / 実践ハイパフォーマンスMySQL 第3版 / 5280
foreach: 978-4798161488 / MySQL徹底入門 第4版 MySQL 8.0対応 / 4180
foreach: 978-4798147406 / 詳解MySQL 5.7 止まらぬ進化に乗り遅れないためのテクニカルガイド / 3960
[org.littlewings.doma.App.main()] DEBUG org.seasar.doma.jdbc.LogKind.LOCAL_TRANSACTION - [DOMA2067] The local transaction "151768958" is committed.
[org.littlewings.doma.App.main()] DEBUG org.seasar.doma.jdbc.LogKind.LOCAL_TRANSACTION - [DOMA2064] The local transaction "151768958" is ended.

OKですね。

デフォルトのログレベルの定義は?

ところでデフォルトのログレベルがDEBUGということで、どこで決まっているのかな?と思ったのですが、こちらのようです。

https://github.com/domaframework/doma/blob/2.46.1/doma-slf4j/src/main/java/org/seasar/doma/jdbc/Slf4jJdbcLogger.java#L15

ログレベルは、コンストラクタで指定できそうですね。

試しに、ログレベルをINFOにしてみましょう。こちらのslf4j-simpleの設定はコメントアウトして
※この時点で、そのままだとログが出なくなります

        // System.setProperty("org.slf4j.simpleLogger.defaultLogLevel", "DEBUG");

Configクラスで指定しているSlf4jJdbcLoggerのコンストラクタにログレベルを指定。

    JdbcLogger jdbcLogger = new Slf4jJdbcLogger(Level.INFO);

すると、ログレベルが変更できました、と。

[org.littlewings.doma.App.main()] INFO org.seasar.doma.jdbc.LogKind.LOCAL_TRANSACTION - [DOMA2063] The local transaction "2050876570" is begun.
[org.littlewings.doma.App.main()] INFO org.seasar.doma.jdbc.LogKind.DAO - [DOMA2220] ENTER  : CLASS=org.littlewings.doma.BookDaoImpl, METHOD=createTable
[org.littlewings.doma.App.main()] INFO org.seasar.doma.jdbc.LogKind.SQL.SCRIPT - [DOMA2076] SQL LOG : PATH=[org.littlewings.doma.BookDao#createTable],
drop table if exists book
[org.littlewings.doma.App.main()] INFO org.seasar.doma.jdbc.LogKind.SQL.SCRIPT - [DOMA2076] SQL LOG : PATH=[org.littlewings.doma.BookDao#createTable],
create table book(isbn varchar(14), title varchar(100), price int, primary key(isbn))
[org.littlewings.doma.App.main()] INFO org.seasar.doma.jdbc.LogKind.DAO - [DOMA2221] EXIT   : CLASS=org.littlewings.doma.BookDaoImpl, METHOD=createTable
[org.littlewings.doma.App.main()] INFO org.seasar.doma.jdbc.LogKind.DAO - [DOMA2220] ENTER  : CLASS=org.littlewings.doma.BookDaoImpl, METHOD=insert
[org.littlewings.doma.App.main()] INFO org.seasar.doma.jdbc.LogKind.SQL.INSERT - [DOMA2076] SQL LOG : PATH=[null],
insert into book (isbn, title, price) values ('978-4798161488', 'MySQL徹底入門 第4版 MySQL 8.0対応', 4180)
[org.littlewings.doma.App.main()] INFO org.seasar.doma.jdbc.LogKind.DAO - [DOMA2221] EXIT   : CLASS=org.littlewings.doma.BookDaoImpl, METHOD=insert
[org.littlewings.doma.App.main()] INFO org.seasar.doma.jdbc.LogKind.DAO - [DOMA2220] ENTER  : CLASS=org.littlewings.doma.BookDaoImpl, METHOD=insert
[org.littlewings.doma.App.main()] INFO org.seasar.doma.jdbc.LogKind.SQL.INSERT - [DOMA2076] SQL LOG : PATH=[null],
insert into book (isbn, title, price) values ('978-4873116389', '実践ハイパフォーマンスMySQL 第3版', 5280)
[org.littlewings.doma.App.main()] INFO org.seasar.doma.jdbc.LogKind.DAO - [DOMA2221] EXIT   : CLASS=org.littlewings.doma.BookDaoImpl, METHOD=insert
[org.littlewings.doma.App.main()] INFO org.seasar.doma.jdbc.LogKind.DAO - [DOMA2220] ENTER  : CLASS=org.littlewings.doma.BookDaoImpl, METHOD=insert
[org.littlewings.doma.App.main()] INFO org.seasar.doma.jdbc.LogKind.SQL.INSERT - [DOMA2076] SQL LOG : PATH=[null],
insert into book (isbn, title, price) values ('978-4798147406', '詳解MySQL 5.7 止まらぬ進化に乗り遅れないためのテクニカルガイド', 3960)
[org.littlewings.doma.App.main()] INFO org.seasar.doma.jdbc.LogKind.DAO - [DOMA2221] EXIT   : CLASS=org.littlewings.doma.BookDaoImpl, METHOD=insert
[org.littlewings.doma.App.main()] INFO org.seasar.doma.jdbc.LogKind.LOCAL_TRANSACTION - [DOMA2067] The local transaction "2050876570" is committed.
[org.littlewings.doma.App.main()] INFO org.seasar.doma.jdbc.LogKind.LOCAL_TRANSACTION - [DOMA2064] The local transaction "2050876570" is ended.
[org.littlewings.doma.App.main()] INFO org.seasar.doma.jdbc.LogKind.LOCAL_TRANSACTION - [DOMA2063] The local transaction "896707861" is begun.
[org.littlewings.doma.App.main()] INFO org.seasar.doma.jdbc.LogKind.DAO - [DOMA2220] ENTER  : CLASS=org.littlewings.doma.BookDaoImpl, METHOD=selectByIsbn
[org.littlewings.doma.App.main()] INFO org.seasar.doma.jdbc.LogKind.SQL.SELECT - [DOMA2076] SQL LOG : PATH=[org.littlewings.doma.BookDao#selectByIsbn],
select * from book where isbn = '978-4798161488'
[org.littlewings.doma.App.main()] INFO org.seasar.doma.jdbc.LogKind.DAO - [DOMA2221] EXIT   : CLASS=org.littlewings.doma.BookDaoImpl, METHOD=selectByIsbn
simple: 978-4798161488 / MySQL徹底入門 第4版 MySQL 8.0対応 / 4180
[org.littlewings.doma.App.main()] INFO org.seasar.doma.jdbc.LogKind.DAO - [DOMA2220] ENTER  : CLASS=org.littlewings.doma.BookDaoImpl, METHOD=selectAllOrderByPrice
[org.littlewings.doma.App.main()] INFO org.seasar.doma.jdbc.LogKind.SQL.SELECT - [DOMA2076] SQL LOG : PATH=[org.littlewings.doma.BookDao#selectAllOrderByPrice],
select * from book order by price desc
[org.littlewings.doma.App.main()] INFO org.seasar.doma.jdbc.LogKind.DAO - [DOMA2221] EXIT   : CLASS=org.littlewings.doma.BookDaoImpl, METHOD=selectAllOrderByPrice
foreach: 978-4873116389 / 実践ハイパフォーマンスMySQL 第3版 / 5280
foreach: 978-4798161488 / MySQL徹底入門 第4版 MySQL 8.0対応 / 4180
foreach: 978-4798147406 / 詳解MySQL 5.7 止まらぬ進化に乗り遅れないためのテクニカルガイド / 3960
[org.littlewings.doma.App.main()] INFO org.seasar.doma.jdbc.LogKind.LOCAL_TRANSACTION - [DOMA2067] The local transaction "896707861" is committed.
[org.littlewings.doma.App.main()] INFO org.seasar.doma.jdbc.LogKind.LOCAL_TRANSACTION - [DOMA2064] The local transaction "896707861" is ended.

とはいえ、ふだんはDEBUGレベルのままで良いでしょうね。