CLOVER🍀

That was when it all began.

JBoss LoggingのLogger Providerを切り替える

なんとなく、JBoss Loggingのソースコードを見ていて気付いたので。

JBoss Loggingで使えるログ出力の実装は、以下の5つです。

これらのいずれか(Logger Provider)が実行時の状態で選択されるわけですが、それは以下の順番で決定されるようです。

  • システムプロパティ「org.jboss.logging.provider」で指定する
  • ServiceLoaderを使う(org.jboss.logging.LoggerProvider)
  • クラスパスに存在しているものを使う

これは、LoggerProvidersというクラスで決定されます。

https://github.com/jboss-logging/jboss-logging/blob/3.3.0.Final/src/main/java/org/jboss/logging/LoggerProviders.java#L37

では、ちょっと見ていってみます。

準備

Maven依存関係は、以下のように定義しておきます。

        <dependency>
            <groupId>org.jboss.logging</groupId>
            <artifactId>jboss-logging</artifactId>
            <version>3.3.0.Final</version>
        </dependency>

        <!-- Log4j -->
        <dependency>
            <groupId>log4j</groupId>
            <artifactId>log4j</artifactId>
            <version>1.2.17</version>
        </dependency>

        <!-- Log4j2 -->
        <dependency>
            <groupId>org.apache.logging.log4j</groupId>
            <artifactId>log4j-api</artifactId>
            <version>2.4</version>
        </dependency>
        <dependency>
            <groupId>org.apache.logging.log4j</groupId>
            <artifactId>log4j-core</artifactId>
            <version>2.4</version>
        </dependency>

        <!-- SLF4J & Logback -->
        <dependency>
            <groupId>org.slf4j</groupId>
            <artifactId>slf4j-api</artifactId>
            <version>1.7.12</version>
        </dependency>
        <dependency>
            <groupId>ch.qos.logback</groupId>
            <artifactId>logback-classic</artifactId>
            <version>1.1.3</version>
        </dependency>

とりあえず、ほぼ全部乗せました。

JBoss LogManagerはここでは対象外にします。スタンドアロンで使いますので。

サンプルコード。
src/main/java/org/littlewings/jbosslogging/JBossLoggingExample.java

package org.littlewings.jbosslogging;

import org.jboss.logging.Logger;

public class JBossLoggingExample {
    public static void main(String... args) {
        Logger logger = Logger.getLogger(JBossLoggingExample.class);
        logger.infof("Hello %s", "JBoss Logging");
    }
}

各種ログ設定ファイル。

Logback
src/main/resources/logback.xml

<?xml version="1.0" encoding="UTF-8"?>
<configuration>
    <appender name="STDOUT" class="ch.qos.logback.core.ConsoleAppender">
        <encoder>
            <pattern>%d{yyyy/MM/dd HH:mm:ss.SSS} %-5level [Slf4j &amp; Logback] - %msg%n</pattern>
        </encoder>
    </appender>

    <root level="info">
        <appender-ref ref="STDOUT"/>
    </root>
</configuration>

Log4j2。
src/main/resources/log4j2.xml

<?xml version="1.0" encoding="UTF-8"?>
<Configuration status="WARN">
    <Appenders>
        <Console name="Console" target="SYSTEM_OUT">
            <PatternLayout pattern="%d{HH:mm:ss.SSS} [%t] %-5level %logger{36} [Log4j2] - %msg%n"/>
        </Console>
    </Appenders>
    <Loggers>
        <Root level="info">
            <AppenderRef ref="Console"/>
        </Root>
    </Loggers>
</Configuration>

Log4j
src/main/resources/log4j.xml

<?xml version="1.0" encoding="UTF-8" ?>
<!DOCTYPE log4j:configuration SYSTEM "log4j.dtd">

<log4j:configuration xmlns:log4j="http://jakarta.apache.org/log4j/">
    <appender name="console" class="org.apache.log4j.ConsoleAppender">
        <param name="Target" value="System.out"/>
        <layout class="org.apache.log4j.PatternLayout">
            <param name="ConversionPattern" value="%-5p %c{1} [Log4j] - %m%n"/>
        </layout>
    </appender>

    <root>
        <priority value="info"/>
        <appender-ref ref="console"/>
    </root>
</log4j:configuration>

システムプロパティ「org.jboss.logging.provider」で指定する

まず、最も優先度が高いのは、システムプロパティ「org.jboss.logging.provider」で指定することです。

指定する値は、それぞれ以下になります。

「org.jboss.logging.provider」の値 選択されるLoggerProvider
jboss JBoss LogManager
jdk java.util.logging
log4j2 Log4j2
log4j Log4j
slf4j SLF4J

試してみます。SLF4J。

$ mvn compile exec:java -Dexec.mainClass=org.littlewings.jbosslogging.JBossLoggingExample -Dorg.jboss.logging.provider=slf4j

2015/10/10 01:55:38.519 INFO  [Slf4j & Logback] - Hello JBoss Logging

Log4j2。

$ mvn compile exec:java -Dexec.mainClass=org.littlewings.jbosslogging.JBossLoggingExample -Dorg.jboss.logging.provider=log4j2

01:56:06.317 [org.littlewings.jbosslogging.JBossLoggingExample.main()] INFO  org.littlewings.jbosslogging.JBossLoggingExample [Log4j2] - Hello JBoss Logging

Log4j

$ mvn compile exec:java -Dexec.mainClass=org.littlewings.jbosslogging.JBossLoggingExample -Dorg.jboss.logging.provider=log4j

INFO  JBossLoggingExample [Log4j] - Hello JBoss Logging

java.util.logging。

$ mvn compile exec:java -Dexec.mainClass=org.littlewings.jbosslogging.JBossLoggingExample -Dorg.jboss.logging.provider=jdk

10 10, 2015 1:57:36 午前 org.littlewings.jbosslogging.JBossLoggingExample main
INFO: Hello JBoss Logging

設定したログフォーマットが、微妙にバラバラでした…。

なお、このシステムプロパティで指定した値が変だったり、実際には使えなかったりすると次のServiceLoaderによるログ実装取得に移ります。

ServiceLoaderを使う(org.jboss.logging.LoggerProvider)

JBoss Logging 3.2.0.Finalから、使用できるようになった方法みたいです。

このケースでは、以下のファイルを用意します。

src/main/resources/META-INF/services/org.jboss.logging.LoggerProvider

ここにorg.jboss.logging.LoggerProviderインターフェースの実装の名前を書く…と。

で、JBoss Loggingで使える各種ログ実装に対するLoggerProviderの実装をここに書けばよいのかなと思ったのですが、どうもそういうわけではないようです。

例えば、SLF4J用のLoggerProviderを書いて、かつSLF4JおよびLogbackを依存関係に追加しても
src/main/resources/META-INF/services/org.jboss.logging.LoggerProvider

org.jboss.logging.Slf4jLoggerProvider

華麗に無視されます。

これは、JBoss Loggingで用意されている各種ログ実装向けのLoggerProvider(Slf4jLoggerProvider、Log4j2LoggerProvider.javaなど)の可視性がパッケージプライベートになっていることが理由みたいです。

で、issueもあるのですが、ライブラリ利用者側はシステムプロパティで指定するか、自分でLoggerProviderとLoggerの実装を用意してね、ってスタンスみたいです。

[JBLOGGING-111] LoggerProvider configured with new ServiceLoader crash - JBoss Issue Tracker

というわけで、用意してみました。対象は、SLF4Jとしています。あ、最低限の実装ですから…。
src/main/java/org/littlewings/jbosslogging/MySlf4jLoggerProvider.java

package org.littlewings.jbosslogging;

import java.util.Map;

import org.jboss.logging.Logger;
import org.jboss.logging.LoggerProvider;
import org.slf4j.LoggerFactory;

public class MySlf4jLoggerProvider implements LoggerProvider {
    @Override
    public Logger getLogger(String name) {
        org.slf4j.Logger nativeLogger = LoggerFactory.getLogger(name);
        return new MySlf4jLogger(name, nativeLogger);
    }

    @Override
    public void clearMdc() {
        // no-op
    }

    @Override
    public Object putMdc(String key, Object value) {
        // no-op
        return null;
    }

    @Override
    public Object getMdc(String key) {
        // no-op
        return null;
    }

    @Override
    public void removeMdc(String key) {
        // no-op
    }

    @Override
    public Map<String, Object> getMdcMap() {
        // no-op
        return null;
    }

    @Override
    public void clearNdc() {
        // no-op
    }

    @Override
    public String getNdc() {
        // no-op
        return null;
    }

    @Override
    public int getNdcDepth() {
        // no-op
        return 0;
    }

    @Override
    public String popNdc() {
        // no-op
        return null;
    }

    @Override
    public String peekNdc() {
        // no-op
        return null;
    }

    @Override
    public void pushNdc(String message) {
        // no-op
    }

    @Override
    public void setNdcMaxDepth(int maxDepth) {
        // no-op
    }
}

src/main/java/org/littlewings/jbosslogging/MySlf4jLogger.java

package org.littlewings.jbosslogging;

import java.text.MessageFormat;

import org.jboss.logging.Logger;

public class MySlf4jLogger extends Logger {
    private org.slf4j.Logger nativeLogger;

    public MySlf4jLogger(String name, org.slf4j.Logger nativeLogger) {
        super(name);
        this.nativeLogger = nativeLogger;
    }

    public boolean isEnabled(final Level level) {
        if (level != null) switch (level) {
            case FATAL:
                return nativeLogger.isErrorEnabled();
            case ERROR:
                return nativeLogger.isErrorEnabled();
            case WARN:
                return nativeLogger.isWarnEnabled();
            case INFO:
                return nativeLogger.isInfoEnabled();
            case DEBUG:
                return nativeLogger.isDebugEnabled();
            case TRACE:
                return nativeLogger.isTraceEnabled();
        }
        return true;
    }

    protected void doLog(final Level level, final String loggerClassName, final Object message, final Object[] parameters, final Throwable thrown) {
        if (isEnabled(level)) try {
            final String text = parameters == null || parameters.length == 0 ? String.valueOf(message) : MessageFormat.format(String.valueOf(message), parameters);
            switch (level) {
                case FATAL:
                case ERROR:
                    nativeLogger.error(text, thrown);
                    return;
                case WARN:
                    nativeLogger.warn(text, thrown);
                    return;
                case INFO:
                    nativeLogger.info(text, thrown);
                    return;
                case DEBUG:
                    nativeLogger.debug(text, thrown);
                    return;
                case TRACE:
                    nativeLogger.trace(text, thrown);
                    return;
            }
        } catch (Throwable ignored) {
        }
    }

    protected void doLogf(final Level level, final String loggerClassName, final String format, final Object[] parameters, final Throwable thrown) {
        if (isEnabled(level)) try {
            final String text = parameters == null ? String.format(format) : String.format(format, parameters);
            switch (level) {
                case FATAL:
                case ERROR:
                    nativeLogger.error(text, thrown);
                    return;
                case WARN:
                    nativeLogger.warn(text, thrown);
                    return;
                case INFO:
                    nativeLogger.info(text, thrown);
                    return;
                case DEBUG:
                    nativeLogger.debug(text, thrown);
                    return;
                case TRACE:
                    nativeLogger.trace(text, thrown);
                    return;
            }
        } catch (Throwable ignored) {
        }
    }
}

このクラスを設定すると
src/main/resources/META-INF/services/org.jboss.logging.LoggerProvider

org.littlewings.jbosslogging.MySlf4jLoggerProvider

ちゃんと作成したLoggerProvider、Loggerが使われますよ、っと。

2015/10/10 11:23:01.262 INFO  [Slf4j & Logback] - Hello JBoss Logging

実際のLoggerProviderおよびLoggerの作り方は、すでにある実装を参考にするとよいと思います。

https://github.com/jboss-logging/jboss-logging/blob/3.3.0.Final/src/main/java/org/jboss/logging/Slf4jLoggerProvider.java
https://github.com/jboss-logging/jboss-logging/blob/3.3.0.Final/src/main/java/org/jboss/logging/Slf4jLogger.java
https://github.com/jboss-logging/jboss-logging/blob/3.3.0.Final/src/main/java/org/jboss/logging/Slf4jLocationAwareLogger.java

https://github.com/jboss-logging/jboss-logging/blob/3.3.0.Final/src/main/java/org/jboss/logging/Log4j2LoggerProvider.java
https://github.com/jboss-logging/jboss-logging/blob/3.3.0.Final/src/main/java/org/jboss/logging/Log4j2Logger.java

ここで指定したLoggerProviderが無効だった場合は、クラスパスに存在しているものを使う、という方針に切り替わります。

クラスパスに存在しているものを使う

最後は、デフォルト(?)の挙動ですね。

JBoss LoggingのLoggerProvidersで、以下の順番でクラスパスに存在し、かつ利用可能なものを選択します。

  • JBoss LogManager
  • Log4j2 ※JBoss Logging 3.2.0.Final以降
  • Log4j
  • SLF4J ※Logbackがクラスパス上にある場合のみ
  • java.util.logging

いずれもクラスパスに存在しない場合は、java.util.loggingが使用される、と。

なお、このケースでSLF4Jを使うためには、Logbackもクラスパス上に存在する必要があります。それ以外のシステムプロパティによる指定や、ServiceLoaderを使って解決する方法でSLF4Jを使う場合、Logbackは必須ではありません。

実際に探索しているところは、ここです。
https://github.com/jboss-logging/jboss-logging/blob/3.3.0.Final/src/main/java/org/jboss/logging/LoggerProviders.java#L83

WildFly上で使う時以外は、Log4j2からjava.util.loggingのいずれかで使うことになるのかと思いますが。

まとめ

JBoss Logging 3.2.0.Final以降での、ログ実装の選択方法を調べてみました。

最初、JBoss Loggingが用意しているデフォルトの各種ログ実装向けのLoggerProvider向けの実装を、ServiceLoaderで指定できないと思っていなかったので、ちょっとハマりましたが…。

とりあえず、ログ実装の切り替え型はわかった感じですね。