Logback でログが出力されなくなる時の対処法

結論
Logback の LogbackServletContainerInitializer
自動登録の無効化
ロガーの終了
まとめ

結論

Logback は自動的に ServletContextListener を登録しており、サーブレットのシャットダウンやアンデプロイにより contextDestroyed() イベントでロガーを stop する(1.1.10〜)。

ServletContextListener の登録順序により、アプリケーションの終了時のログが出力されなくなったり、Webアプリケーションのアンデプロイ以降のログが出力されなくなることがある。

web.xml の初期化パラメータで以下のようにすればロガーを stop するリスナーの登録が抑止される。

<web-app>
    <context-param>
        <param-name>logbackDisableServletContainerInitializer</param-name>
        <param-value>true</param-value>
    </context-param>
    .... 
</web-app>

または、システムプロパティで以下のように設定することもできる。

System.setProperty("logbackDisableServletContainerInitializer", "true");

Java の起動パラメータでももちろん可能。

ただしシャットダウン時には、後述する、他の方法でロガーの stop を行っておくべき

Logback の LogbackServletContainerInitializer

logback-classic の Jar には META-INF/services/javax.servlet.ServletContainerInitializer が含まれており、以下の内容になっている。

ch.qos.logback.classic.servlet.LogbackServletContainerInitializer

LogbackServletContainerInitializer は以下のような実装になっている。

public class LogbackServletContainerInitializer implements ServletContainerInitializer {

    @Override
    public void onStartup(Set<Class<?>> c, ServletContext ctx) throws ServletException {
        if (isDisabledByConfiguration(ctx)) {
            // ...
            return;
        }
        // ...
        LogbackServletContextListener lscl = new LogbackServletContextListener();
        ctx.addListener(lscl);
    }

LogbackServletContainerInitializer は ServletContainerInitializer を実装している。

ServletContainerInitializer の JavaDoc は以下のように記載されており、サーブレットコンテナによりリスナーが自動登録される

このインターフェースの実装はJARファイル内のMETA-INF/servicesディレクトリにあるこのインターフェースの完全修飾クラス名の名前が付けられたリソースによって宣言され、ランタイムのサービスプロバイダルックアップメカニズムまたはそれと意味的に同等のコンテナ固有のメカニズムを使用して検出されます。

自動登録の無効化

前述の LogbackServletContainerInitializer.isDisabledByConfiguration() は以下のようになっている。

boolean isDisabledByConfiguration(ServletContext ctx) {

    String disableAttributeStr = null;

    Object disableAttribute = ctx.getInitParameter("logbackDisableServletContainerInitializer");
    if (disableAttribute instanceof String) {
        disableAttributeStr = (String) disableAttribute;
    }

    if (OptionHelper.isEmpty(disableAttributeStr)) {
        disableAttributeStr = OptionHelper.getSystemProperty("logbackDisableServletContainerInitializer");
    }

    if (OptionHelper.isEmpty(disableAttributeStr)) {
        disableAttributeStr = OptionHelper.getEnv("logbackDisableServletContainerInitializer");
    }

    if (OptionHelper.isEmpty(disableAttributeStr))
        return false;
    return disableAttributeStr.equalsIgnoreCase("true");
}

初期化パラメータ -> システムプロパティ -> 環境変数の順で logbackDisableServletContainerInitializer の値を見て無効判断している。

そのため、web.xml で以下のように初期化パラメータを渡したり、

<web-app>
    <context-param>
        <param-name>logbackDisableServletContainerInitializer</param-name>
        <param-value>true</param-value>
    </context-param>
    .... 
</web-app>

システムプロパティを設定したり、

System.setProperty("logbackDisableServletContainerInitializer", "true");

java -DlogbackDisableServletContainerInitializer=true -jar xxx.jar

システムの環境変数で設定することで無効化できる。

ロガーの終了

logbackDisableServletContainerInitializer でリスナー登録を無効化した場合、アプリケーションの終了時に何らかの方法でロガーを stop しておくことが望ましい。

単一アプリケーションの場合、logback.xml に以下のような <shutdownHook/> 要素を入れることで遅延してシャットダウンを行うことができる。

<configuration>
    <shutdownHook class="ch.qos.logback.core.hook.DelayingShutdownHook">
        <delay>100</delay>
    </shutdownHook>
</configuration>

DelayingShutdownHook は以下の実装になっている。

public class DelayingShutdownHook extends ShutdownHookBase {
    // ...
    public void run() {
        addInfo("Sleeping for "+delay);
        try {
            Thread.sleep(delay.getMilliseconds());
        } catch (InterruptedException e) {
        }
        super.stop();
    }
}

ShutdownHookBase.stop() は以下。

public abstract class ShutdownHookBase extends ContextAwareBase implements ShutdownHook {
    protected void stop() {
        addInfo("Logback context being closed via shutdown hook");
        Context hookContext = getContext();
        if (hookContext instanceof ContextBase) {
            ContextBase context = (ContextBase) hookContext;
            context.stop();
        }
    }
}

まはた、自力で停止させることもできる。

Runtime.getRuntime().addShutdownHook(new Thread(() -> {
    try {
        ILoggerFactory iLoggerFactory = LoggerFactory.getILoggerFactory();
        if (iLoggerFactory instanceof LoggerContext) {
            LoggerContext loggerContext = (LoggerContext) iLoggerFactory;
            loggerContext.stop();
        }
    } catch (Exception e) {
        log.warn(e.getMessage());
    }
}));

シャットダウン時のリスナーの順序を調整する場合は web.xml へ手動でリスナーを(順序を考慮して)構成することもできる。

<listener>
    <listener-class>ch.qos.logback.classic.servlet.LogbackServletContextListener</listener-class>
</listener>
<listener>
    <listener-class>org.springframework.web.context.ContextLoaderListener</listener-class>
</listener>