spring boot 2 + logback

今の状況

これまで Spring Boot 2 + log4j1 の構成でログを管理してきたが、
流石にlog4j1は古過ぎて(メンテナンスも終わっている)、移行することにした。
しかし、log4j1からlog4j2はリリース20年の差が大き過ぎて
単純バージョンアップではなかった。

どうせlog4j2は変更点も多いし、spring bootらしい開発にするため、
内蔵ライブラリのlogbackに移行する事になった。

要求事項

① コンソール出力（infoレベル）、ファイル出力（ALLレベル）、両方したい。
② ファイル出力は毎日ローテート。
③ カスタムパターン（レイアウト）使いたい。

少しみてみると、あ〜appenderとloggerは二つ必要だね〜
カスタムパターンはクラス作成が必要だね〜とかが予想できる。

変更点４つ

１．ライブラリー
２．ログ設定ファイル
３．カスタムパターン（レイアウト）ファイル
４．格ファイルでの出力方法

変更点１．ライブラリー

元々は以下のように log4j1 の core ライブラリを使っていた：build.grade

implementation ('org.springframework.boot:spring-boot-starter-web'){
    exclude group: 'org.springframework.boot', module: 'spring-boot-starter-logging'
}
implementation 'log4j:log4j:1.2.17'

logback に移行する場合、Spring Boot に元々含まれているため、追加の設定は基本不要。

implementation 'org.springframework.boot:spring-boot-starter-web'

ここで以下の設定も削除（理由は後述。変更点３と関連がある。）
developmentOnly("org.springframework.boot:spring-boot-devtools")

変更点２．ログ設定ファイル

元々ログ設定ファイルはlog4j.propertiesだったが、logback-spring.xmlに変更。
要求事項を満たすための内容を記載する。

<configuration>
    <conversionRule conversionWord="U" converterClass="com.example.logging.UserConverter" />
    <appender name="Console" class="ch.qos.logback.core.ConsoleAppender">
        <encoder>
            <pattern>任意のパターン１</pattern>
        </encoder>
    </appender>

    <appender name="LogFile" class="ch.qos.logback.core.rolling.RollingFileAppender">
        <file>logs/debug.log</file>
        <rollingPolicy class="ch.qos.logback.core.rolling.TimeBasedRollingPolicy">
            <fileNamePattern>logs/debug.%d{yyyy-MM-dd}.log</fileNamePattern>
        </rollingPolicy>
        <encoder>
            <pattern>任意のパターン２</pattern>
        </encoder>
    </appender>

    <!-- ルートロガー -->
    <root level="INFO">
        <appender-ref ref="Console"/>
    </root>
    <logger name="対象パッケージ" level="ALL">
        <appender-ref ref="LogFile"/>
    </logger>
    
</configuration>

① コンソール出力（infoレベル）ファイル出力（ALLレベル）、両方したい。
Console、LogFile、二つのappenderを格loggerに設定。

② ファイル出力は毎日ローテート。
特に設定タグとかはなくて、fileNamePatternに記載する%d{yyyy-MM-dd}から決められている。
%d{yyyy-MM-dd-HH-mm}にすると1分ずつファイルがセーブされる。

③ カスタムパターン（レイアウト）使いたい。
任意のパターンに、ユーザ情報も出力したい問いことで「%U」とかも記載する。
例えば

%d{yyyy-MM-dd HH:mm:ss} [%thread] <%U> %-5level %logger - %msg%n

変更点３．カスタムパターン（レイアウト）ファイル

%Uのようなカスタム変換子は、
log4j1ではorg.apache.log4j.PatternLayoutを継承したが、
logbackではClassicConverterを継承して自作する必要がある。

@Converter(name = "U", type = ConversionType.class)
public class UserConverter extends ClassicConverter {

    //@autowired
    //UserDto userdto;
    
    @Override
    public String convert(ILoggingEvent event) {
        HttpServletRequest request = ((ServletRequestAttributes) RequestContextHolder
            .getRequestAttributes()).getRequest();

        UserDto user = (UserDto)request.getSession().getAttribute("USER_ID");
        return user.getXX(); // ユーザ情報
    }
}

本当は Springの@Autowiredを使ってセッション管理用のDTOなどを注入したかったが、
ClassicConverterはSpring管理下のBeanではないためDIが効かない。
そのため、RequestContextHolder を使って直接セッションから値を取得するようにした。
例えば、セッションに"USER_ID"を格納しておけば、その値をログに出力できる。

補足：
Sessionからユーザー情報（Object）を取得して、
カスタムConverter内で（UserDto）でキャストしようとしたところ、ClassCastExceptionが発生した。

原因は Spring Boot DevToolsによるクラスローダーの分離。
DevToolsは再起動用のクラスローダーを使用するため、
同じクラス（UserDto）でも異なるクラスローダーで読み込まれた結果、「同じ名前なのに別物」として扱われ、キャストに失敗した。
この問題を回避するため、build.gradle から DevToolsの依存を削除した。

変更点４．格ファイルでの出力方法

import org.apache.logging.log4j.Logger;
Logger log = Logger.getLogger(MyClass);

↓

import org.slf4j.LoggerFactory;
import org.slf4j.Logger;
Logger log = LoggerFactory.getLogger(MyClass);

終わりに

Log4j2は機能が豊富でパフォーマンスも良いが、Spring Bootとの相性やメンテナンス性を考えると、logbackの方が楽というのが今回の感想。