SpringBootでlog4j2を利用した際に終了処理の出力でハマった話

この記事の対象

Spring Boot 2.3.6
spring-boot-starter-log4j2 2.3.6

概要

SpringBootアプリケーションの終了処理(@PreDestroyアノテーション使用)で、ログ出力を行いたかったわけです。
終了処理後に特定のメッセージコードを含むログを出力し、それをAWS CloudWatch上のイベントトリガーにしたかったためです。

なぜハマったのか？

終了処理が呼び出される時点で、Loggerのインスタンスが非同期で自動開放されるようである。
このため終了処理でログが出力されるか否かは、自動終了処理に左右される。

解決方法

これを防止するためには、log4j2.xmlのConfigurationタグにshutdownHookパラメータ設定を追加し、自動開放しないようにする。

log4j2.xml抜粋

<Configuration shutdownHook="disable">

その上でアプリケーションの終了処理でLoggerの終了処理を追加する

SampleApp.java

import org.apache.logging.log4j.core.config.Configurator;
import org.apache.logging.log4j.LogManager;
import org.apache.logging.log4j.Logger;
...

@SpringBootApplication
public class SampleApp {
    public static Logger logger = LogManager.getLogger(this.getClass());
    ...

    @PreDestroy
    public void shutdownHook() {

        /**
         *  アプリケーション終了処理を記載
         **/

        logger.info("ここでログがだしたかったんだけど、出力されなかったんです");

        // Logger終了処理
        Configurator.shutdown((LoggerContext)LogManager.getContext());
    }

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