SpringBootのDBへのログ出力

はじめに

SpringBootアプリケーションの開発時、テストやデバッグ目的でデータベースにログを出力したいと思うことがよくあり、方法を調査しました。

build.gradleの修正

Logbackのドキュメント によると、DBAppender は、バージョン 1.2.11.1 以降は削除されてしまったため、下記の行をbuild.gradleのdependencies配下に追加する必要があります。

build.gradle

implementation 'ch.qos.logback.db:logback-classic-db:1.2.11.1'

dependencies全体は例えば下記のような感じになります。

build.gradle

dependencies {
    implementation 'org.springframework.boot:spring-boot-starter-thymeleaf'
    implementation 'org.springframework.boot:spring-boot-starter-web'
    implementation 'org.springframework.boot:spring-boot-starter-jdbc'
    implementation 'io.github.wimdeblauwe:htmx-spring-boot-thymeleaf:4.0.1'
    implementation 'ch.qos.logback.db:logback-classic-db:1.2.11.1'
    runtimeOnly 'com.h2database:h2'
    compileOnly 'org.projectlombok:lombok'
    developmentOnly 'org.springframework.boot:spring-boot-devtools'
    annotationProcessor 'org.projectlombok:lombok'
    testImplementation 'org.springframework.boot:spring-boot-starter-test'
    testRuntimeOnly 'org.junit.platform:junit-platform-launcher'
}

application.propertiesの修正

DBにログを書き込むため、DB周りの設定をapplication.propertiesに記述します。
この例ではh2を使用しています

resources/application.properties

spring.application.name=demo

# H2 datasource for logging
spring.datasource.driver-class-name=org.h2.Driver
spring.datasource.url=jdbc:h2:file:./build/h2db/logs;MODE=PostgreSQL;DB_CLOSE_DELAY=-1;AUTO_SERVER=TRUE
spring.datasource.username=sa
spring.datasource.password=

# Initialize schema.sql even for non-embedded detection
spring.sql.init.mode=always
spring.sql.init.encoding=UTF-8

# H2 web console (for manual checks)
spring.h2.console.enabled=true
spring.h2.console.path=/h2-console

logback-spring.xmlの修正

application.propertiesに設定した内容を使用して、DBAppenderを使用するように設定します

resources/logback-spring.xml

<?xml version="1.0" encoding="UTF-8"?>
<configuration debug="true">
    <!-- Read datasource properties from Spring Environment -->
    <springProperty scope="context" name="dsUrl" source="spring.datasource.url"/>
    <springProperty scope="context" name="dsUser" source="spring.datasource.username"/>
    <springProperty scope="context" name="dsPass" source="spring.datasource.password"/>
    <springProperty scope="context" name="dsDriver" source="spring.datasource.driver-class-name"/>

    <!-- Console appender stays for local visibility -->
    <appender name="CONSOLE" class="ch.qos.logback.core.ConsoleAppender">
        <encoder>
            <pattern>%d{yyyy-MM-dd HH:mm:ss.SSS} %-5level [%thread] %logger{36} - %msg%n</pattern>
        </encoder>
    </appender>

    <!-- DB appender that writes to logging_event* tables -->
    <appender name="DB" class="ch.qos.logback.classic.db.DBAppender">
        <connectionSource class="ch.qos.logback.core.db.DriverManagerConnectionSource">
            <driverClass>${dsDriver}</driverClass>
            <url>${dsUrl}</url>
            <user>${dsUser}</user>
            <password>${dsPass}</password>
        </connectionSource>
    </appender>

    <root level="INFO">
        <appender-ref ref="CONSOLE"/>
        <appender-ref ref="DB"/>
    </root>
</configuration>

Springアプリケーションの作成

下記の通り作成して実際にログが出力されるかを確認します

com.example.demo.DemoApplication.java

package com.example.demo;

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

@SpringBootApplication
public class DemoApplication {

    public static void main(String[] args) {
        SpringApplication.run(DemoApplication.class, args);
    }

}

com.examle.demo.SampleController.java

package com.example.demo;

import org.slf4j.Logger;
import org.slf4j.LoggerFactory;
import org.springframework.web.bind.annotation.GetMapping;
import org.springframework.web.bind.annotation.RequestMapping;
import org.springframework.web.bind.annotation.RestController;

@RestController
@RequestMapping("/api")
public class SampleController {

    private static final Logger log = LoggerFactory.getLogger(SampleController.class);

    // シンプルなサンプルエンドポイント
    // 例: GET http://localhost:8080/api/hello -> "Hello, World!"
    @GetMapping("/hello")
    public String hello() {
        log.info("/api/hello endpoint called");
        return "Hello, World!";
    }
}

SpringBootアプリを起動すると下記のようにログが出力されます

独自のDBAppenderを作成する

DBAppenderのデフォルトのテーブル構造は下記になっており、日付がBIGINTになっています。

フィールド名	タイプ	説明
timestamp	bigint型	ログイベントが作成された時点で有効なタイムスタンプです。
formatted_message	text	メッセージフォーマット処理（org.slf4j.impl.MessageFormatter を使用）後にログイベントに追加されるメッセージです。メッセージにオブジェクトが渡されている場合にこのフィールドに値が設定されます。
logger_name	varchar型	ログ記録要求を発行する際に使用されるロガーの名称です。
level_string	varchar	ログイベントのレベルです。
reference_flag	smallint	logback が例外または MDC プロパティ値を持つログイベントを識別するために使用します。 この値は ch.qos.logback.classic.db.DBHelper によって計算されます。 MDC または Context プロパティを含む場合は 1、例外を含む場合は 2、両方を含む場合は 3 となります。
caller_filename	varchar	ログ記録要求が発行されたファイルの名前です。
caller_class	varchar	ログ記録要求が発行されたクラス名です。
caller_method	varchar	ログ記録要求が発行されたメソッド名です。
caller_line	char	ログ記録要求が発行された行番号です。
event_id	int型	ログイベントのデータベース ID です。

日付型にするため、独自のDBAppenderを作成します。また、ログ出力のプレースホルダに設定した値もログに出力するようにします。

TimestampDBAppender.java

package com.example.demo;

import ch.qos.logback.classic.db.DBAppender;
import ch.qos.logback.classic.spi.ILoggingEvent;
import ch.qos.logback.classic.db.DBHelper;
import java.sql.Connection;
import java.sql.PreparedStatement;
import java.sql.SQLException;
import java.sql.Timestamp;

public class TimestampDBAppender extends DBAppender {
    private boolean includeCallerData = false;

    public void setIncludeCallerData(boolean includeCallerData) {
        this.includeCallerData = includeCallerData;
    }

    public boolean isIncludeCallerData() {
        return includeCallerData;
    }

    @Override
    protected void subAppend(ILoggingEvent event, Connection connection, PreparedStatement insertStatement) throws Throwable {
        bindLoggingEventWithInsertStatement(insertStatement, event);
        bindLoggingEventArgumentsWithPreparedStatement(insertStatement, event.getArgumentArray());
        
        if (includeCallerData) {
            bindCallerDataWithPreparedStatement(insertStatement, event.getCallerData());
        } else {
            bindCallerDataWithPreparedStatement(insertStatement, null);
        }
        
        int updateCount = insertStatement.executeUpdate();
        if (updateCount != 1) {
            addWarn("Failed to insert loggingEvent");
        }
    }

    protected void bindLoggingEventWithInsertStatement(PreparedStatement stmt, ILoggingEvent event) throws SQLException {
        stmt.setTimestamp(1, new Timestamp(event.getTimeStamp()));
        stmt.setString(2, event.getFormattedMessage());
        stmt.setString(3, event.getLoggerName());
        stmt.setString(4, event.getLevel().toString());
        stmt.setString(5, event.getThreadName());
        stmt.setShort(6, DBHelper.computeReferenceMask(event));
    }

    protected void bindLoggingEventArgumentsWithPreparedStatement(PreparedStatement stmt, Object[] argArray) throws SQLException {
        int len = (argArray != null) ? argArray.length : 0;
        for (int i = 0; i <= 3; i++) {
            if (i < len) {
                stmt.setString(7 + i, asStringTruncatedTo254(argArray[i]));
            } else {
                stmt.setString(7 + i, null);
            }
        }
    }

    protected String asStringTruncatedTo254(Object o) {
        if (o == null) return null;
        String s = o.toString();
        if (s == null) return null;
        if (s.length() <= 254) return s;
        return s.substring(0, 254);
    }

    protected void bindCallerDataWithPreparedStatement(PreparedStatement stmt, StackTraceElement[] callerDataArray) throws SQLException {
        StackTraceElement callerData = (callerDataArray != null && callerDataArray.length > 0) ? callerDataArray[0] : null;
        if (callerData != null) {
            stmt.setString(11, callerData.getFileName());
            stmt.setString(12, callerData.getClassName());
            stmt.setString(13, callerData.getMethodName());
            stmt.setString(14, Integer.toString(callerData.getLineNumber()));
        } else {
            stmt.setString(11, "?");
            stmt.setString(12, "?");
            stmt.setString(13, "?");
            stmt.setString(14, "?");
        }
    }
}

logback-spring.xmlを修正して作成したDBAppenderを使用するように設定します

logback-spring.xml

    <!-- DB appender that writes to logging_event* tables -->
    <appender name="DB" class="com.example.demo.TimestampDBAppender">
        <connectionSource class="ch.qos.logback.core.db.DriverManagerConnectionSource">
            <driverClass>${dsDriver}</driverClass>
            <url>${dsUrl}</url>
            <user>${dsUser}</user>
            <password>${dsPass}</password>
        </connectionSource>
    </appender>

また、DBAppenderが使用するテーブルのDDLは下記の通りになります

schema.sql

-- Logback DB schema for H2
-- Tables: logging_event, logging_event_property, logging_event_exception

CREATE TABLE IF NOT EXISTS logging_event
(
    timestmp           TIMESTAMP   NOT NULL,
    formatted_message  CLOB        NOT NULL,
    logger_name        VARCHAR(254) NOT NULL,
    level_string       VARCHAR(254) NOT NULL,
    thread_name        VARCHAR(254),
    reference_flag     SMALLINT,
    arg0               VARCHAR(254),
    arg1               VARCHAR(254),
    arg2               VARCHAR(254),
    arg3               VARCHAR(254),
    caller_filename    VARCHAR(254),
    caller_class       VARCHAR(254),
    caller_method      VARCHAR(254),
    caller_line        CHAR(4),
    event_id           BIGINT GENERATED BY DEFAULT AS IDENTITY PRIMARY KEY
);

CREATE TABLE IF NOT EXISTS logging_event_property
(
    event_id          BIGINT       NOT NULL,
    mapped_key        VARCHAR(254) NOT NULL,
    mapped_value      CLOB,
    PRIMARY KEY (event_id, mapped_key),
    FOREIGN KEY (event_id) REFERENCES logging_event(event_id)
);

CREATE TABLE IF NOT EXISTS logging_event_exception
(
    event_id         BIGINT  NOT NULL,
    i                SMALLINT NOT NULL,
    trace_line       CLOB    NOT NULL,
    PRIMARY KEY (event_id, i),
    FOREIGN KEY (event_id) REFERENCES logging_event(event_id)
);

実際のログ出力は下記の通りとなります