CLOVER🍀

That was when it all began.

WildFlyのloggingサブシステムの設定を行う

これは、なにをしたくて書いたもの?

WildFlyのアプリケーションをデプロイしていて、そういえばログの設定をしたことがないなと思いまして。

全然やり方を把握していなかったので、メモしておくことにします。

対象のWildFlyは、32.0.1.Finalとします。

WildFly loggingサブシステム

WildFlyのログに関する設定は、loggingサブシステムで行います。loggingサブシステムのドキュメントはこちらです。

WildFly Admin Guide / Subsystem configuration / Logging Subsystem

モデルリファレンスはこちら。

WildFly Full Model Reference / subsystem=logging

前提として、WildFly上で動作するアプリケーションのログはJBoss LogManagerで一元管理されていることを知っておく必要があります。

以下のAPIを使用したログ出力は、WildFly上で管理されているJBoss LogManagerへ転送されます。

WildFlyのドキュメントには記述が見つけられませんでしたが、JBoss EAPのドキュメントにはこのことが書かれていました。

第4章 Logging Red Hat JBoss Enterprise Application Platform 7.4 | Red Hat Customer Portal

各種ロギングライブラリーからJBoss LogManagerへ転送しているのはこのあたりですね。

JBoss Loggingは、JBoss LogManagerが使える場合はそちらに転送しようとします。また、JBoss LogManagerはjava.util.loggingの
実装でもあります。

JBoss LogManager自身のGitHubリポジトリーはこちらです。

GitHub - jboss-logging/jboss-logmanager: JBoss Log Manager

というわけで、loggingサブシステムはJBoss LogManagerの設定を行っていることになります。

よくやりたくなる設定変更として、カテゴリーに対する設定追加

WildFly Admin Guide / Subsystem configuration / Logging Subsystem / How To

ログのフォーマット、

WildFly Admin Guide / Subsystem configuration / Logging Subsystem / Logging Formatters

出力先などを扱うハンドラーあたりかなと思うので、このあたりを扱ってみます。

WildFly Admin Guide / Subsystem configuration / Logging Subsystem / Handlers

それから、デプロイ対象ごとにログ設定(logging.properties)を行うこともできるようなのですが、今回はこちらはパスします。

環境

今回の環境はこちら。

$ java --version
openjdk 21.0.3 2024-04-16
OpenJDK Runtime Environment (build 21.0.3+9-Ubuntu-1ubuntu122.04.1)
OpenJDK 64-Bit Server VM (build 21.0.3+9-Ubuntu-1ubuntu122.04.1, mixed mode, sharing)


$ mvn --version
Apache Maven 3.9.7 (8b094c9513efc1b9ce2d952b3b9c8eaedaf8cbf0)
Maven home: $HOME/.sdkman/candidates/maven/current
Java version: 21.0.3, vendor: Ubuntu, runtime: /usr/lib/jvm/java-21-openjdk-amd64
Default locale: ja_JP, platform encoding: UTF-8
OS name: "linux", version: "5.15.0-112-generic", arch: "amd64", family: "unix"

WildFlyはダウンロードして展開しておきます。

$ curl -LO https://github.com/wildfly/wildfly/releases/download/32.0.1.Final/wildfly-32.0.1.Final.zip
$ unzip wildfly-32.0.1.Final.zip
$ cd wildfly-32.0.1.Final

起動はこちらで。

$ bin/standalone.sh

デフォルトのloggingサブシステムの設定を確認する

最初に、デフォルトのloggingサブシステムの設定を確認しておきましょう。対象はstandalone.xmlのみとしますが。

standalone/configuration/standalone.xml

        <subsystem xmlns="urn:jboss:domain:logging:8.0">
            <console-handler name="CONSOLE">
                <level name="INFO"/>
                <formatter>
                    <named-formatter name="COLOR-PATTERN"/>
                </formatter>
            </console-handler>
            <periodic-rotating-file-handler name="FILE" autoflush="true">
                <formatter>
                    <named-formatter name="PATTERN"/>
                </formatter>
                <file relative-to="jboss.server.log.dir" path="server.log"/>
                <suffix value=".yyyy-MM-dd"/>
                <append value="true"/>
            </periodic-rotating-file-handler>
            <logger category="com.arjuna">
                <level name="WARN"/>
            </logger>
            <logger category="com.networknt.schema">
                <level name="WARN"/>
            </logger>
            <logger category="io.jaegertracing.Configuration">
                <level name="WARN"/>
            </logger>
            <logger category="org.jboss.as.config">
                <level name="DEBUG"/>
            </logger>
            <logger category="sun.rmi">
                <level name="WARN"/>
            </logger>
            <root-logger>
                <level name="INFO"/>
                <handlers>
                    <handler name="CONSOLE"/>
                    <handler name="FILE"/>
                </handlers>
            </root-logger>
            <formatter name="PATTERN">
                <pattern-formatter pattern="%d{yyyy-MM-dd HH:mm:ss,SSS} %-5p [%c] (%t) %s%e%n"/>
            </formatter>
            <formatter name="COLOR-PATTERN">
                <pattern-formatter pattern="%K{level}%d{HH:mm:ss,SSS} %-5p [%c] (%t) %s%e%n"/>
            </formatter>
        </subsystem>

見ているとなんとなく構造はわかる気がしますが、ここに変更や追加をしていきます。

変更は管理CLIで行います。

サンプルアプリケーションを作成する

お題を考えると、サンプルアプリケーションがあった方がよいと思うので簡単なJakarta RESTful Web Services(JAX-RS)のみを
使ったものを作りました。

Maven依存関係など。

    <properties>
        <maven.compiler.release>21</maven.compiler.release>
        <project.build.sourceEncoding>UTF-8</project.build.sourceEncoding>
        <project.reporting.outputEncoding>UTF-8</project.reporting.outputEncoding>
        <failOnMissingWebXml>false</failOnMissingWebXml>
    </properties>

    <dependencies>
        <dependency>
            <groupId>jakarta.platform</groupId>
            <artifactId>jakarta.jakartaee-web-api</artifactId>
            <version>10.0.0</version>
            <scope>provided</scope>
        </dependency>

        <dependency>
            <groupId>org.slf4j</groupId>
            <artifactId>slf4j-api</artifactId>
            <version>2.0.13</version>
        </dependency>
    </dependencies>

    <build>
        <finalName>ROOT</finalName>
    </build>

JAX-RSリソースクラス。ログ出力も行うのですが、ここではSLF4JのAPIを使うことにします。

src/main/java/org/littlewings/wildfly/logging/HelloResource.java

package org.littlewings.wildfly.logging;

import jakarta.ws.rs.GET;
import jakarta.ws.rs.Path;
import jakarta.ws.rs.Produces;
import jakarta.ws.rs.core.MediaType;
import org.slf4j.Logger;
import org.slf4j.LoggerFactory;

@Path("/hello")
public class HelloResource {
    private Logger logger = LoggerFactory.getLogger(HelloResource.class);

    @GET
    @Produces(MediaType.TEXT_PLAIN)
    public String message() {
        logger.info("logger class name = {}", logger.getClass().getName());

        logger.trace("trace message in resource");
        logger.debug("debug message in resource");
        logger.info("info message in resource");
        logger.warn("warn message in resource");
        logger.error("error message in resource");

        return "Hello World!!";
    }
}

ログレベルはTRACE〜ERRORまでひととおり揃えておきました。

JAX-RSの有効化。

src/main/java/org/littlewings/wildfly/logging/RestApplication.java

package org.littlewings.wildfly.logging;

import jakarta.ws.rs.ApplicationPath;
import jakarta.ws.rs.core.Application;

@ApplicationPath("")
public class RestApplication extends Application {
}

パッケージングしてデプロイ。

$ cp target/ROOT.war /path/to/wildfly-32.0.1.Final/standalone/deployments

アクセスして確認。

$ curl localhost:8080/hello
Hello World!!

この時、WildFlyのコンソールにはこんなログが出力されます。

23:52:23,581 INFO  [org.littlewings.wildfly.logging.HelloResource] (default task-1) logger class name = org.slf4j.impl.Slf4jLogger
23:52:23,581 INFO  [org.littlewings.wildfly.logging.HelloResource] (default task-1) info message in resource
23:52:23,582 WARN  [org.littlewings.wildfly.logging.HelloResource] (default task-1) warn message in resource
23:52:23,582 ERROR [org.littlewings.wildfly.logging.HelloResource] (default task-1) error message in resource

INFOレベル以上のログが出力されています。

ついでということでSLF4JのLoggerのクラス名も出力しているのですが、org.slf4j.impl.Slf4jLoggerというのはslf4j-apiに含まれている
クラスではありません。SLF4J Binding to JBoss Loggingに含まれているSLF4Jのふりをするクラスですね。

`GitHub - jboss-logging/slf4j-jboss-logmanager: SLF4J Backend for JBoss LogManager

root-loggerのログレベルを変更する

まずはloggingサブシステム全体の親となるロガーである、root-loggerの設定を変更してみます。

管理CLIで接続。

$ bin/jboss-cli.sh -c

root-loggerの内容を確認してみます。

[standalone@localhost:9990 /] /subsystem=logging/root-logger=ROOT:read-resource
{
    "outcome" => "success",
    "result" => {
        "filter-spec" => undefined,
        "handlers" => [
            "CONSOLE",
            "FILE"
        ],
        "level" => "INFO"
    }
}

では、root-loggerのログレベルをDEBUGに変更してみましょう。

[standalone@localhost:9990 /] /subsystem=logging/root-logger=ROOT:write-attribute(name=level,value=DEBUG)

確認。

[standalone@localhost:9990 /] /subsystem=logging/root-logger=ROOT:read-resource
{
    "outcome" => "success",
    "result" => {
        "filter-spec" => undefined,
        "handlers" => [
            "CONSOLE",
            "FILE"
        ],
        "level" => "DEBUG"
    }
}

この状態で、アプリケーションへアクセスしてみます。

$ curl localhost:8080/hello
Hello World!!

コンソールにはDEBUGレベル以上のログが…出力されません。

00:02:18,630 INFO  [org.littlewings.wildfly.logging.HelloResource] (default task-1) logger class name = org.slf4j.impl.Slf4jLogger
00:02:18,630 INFO  [org.littlewings.wildfly.logging.HelloResource] (default task-1) info message in resource
00:02:18,631 WARN  [org.littlewings.wildfly.logging.HelloResource] (default task-1) warn message in resource
00:02:18,631 ERROR [org.littlewings.wildfly.logging.HelloResource] (default task-1) error message in resource

standalone/log/server.logを確認してみます。

2024-06-11 00:02:18,630 INFO  [org.littlewings.wildfly.logging.HelloResource] (default task-1) logger class name = org.slf4j.impl.Slf4jLogger
2024-06-11 00:02:18,630 DEBUG [org.littlewings.wildfly.logging.HelloResource] (default task-1) debug message in resource
2024-06-11 00:02:18,630 INFO  [org.littlewings.wildfly.logging.HelloResource] (default task-1) info message in resource
2024-06-11 00:02:18,631 WARN  [org.littlewings.wildfly.logging.HelloResource] (default task-1) warn message in resource
2024-06-11 00:02:18,631 ERROR [org.littlewings.wildfly.logging.HelloResource] (default task-1) error message in resource

こちらにはDEBUGレベル以上のログが出力されています。
他のログも軒並みDEBUGレベル以上のものが出力されているので、量が大変なことになっていますが。

どうしてコンソールの方にはDEBUGログが出力されなかったのでしょうか?

これはハンドラーに設定されているログレベルが関係しています。

ハンドラーはロガーにぶら下がる形になっています。なので、まずロガーに設定されたログレベルでログがハンドラーに渡されるか
どうかが決定され、ハンドラーは設定内容に応じた出力を行います。

つまり、ロガーに設定されたログレベルがハンドラーに設定されたログレベルより高い場合はハンドラーはロガーに設定されたログレベルより
低いログレベルのメッセージは扱えません。たとえばロガーはINFO、ハンドラーはDEBUGの場合、ハンドラーへはINFOレベル以上の
ログしか渡されないことになります。

逆にロガーに設定されたログレベルがハンドラーに設定されたログレベルよりも低い場合は、ハンドラー側で出力するログレベルを
フィルタリングできることになります。

この視点でroot-loggerに設定されたハンドラーを確認してみます。

こうでしたね。

[standalone@localhost:9990 /] /subsystem=logging/root-logger=ROOT:read-resource
{
    "outcome" => "success",
    "result" => {
        "filter-spec" => undefined,
        "handlers" => [
            "CONSOLE",
            "FILE"
        ],
        "level" => "INFO"
    }
}

CONSOLEとFILEという名前のハンドラーが紐付いています。

CONSOLEハンドラーを確認してみます。

[standalone@localhost:9990 /] /subsystem=logging/console-handler=CONSOLE:read-resource
{
    "outcome" => "success",
    "result" => {
        "autoflush" => true,
        "enabled" => true,
        "encoding" => undefined,
        "filter-spec" => undefined,
        "formatter" => "%d{HH:mm:ss,SSS} %-5p [%c] (%t) %s%e%n",
        "level" => "INFO",
        "name" => "CONSOLE",
        "named-formatter" => "COLOR-PATTERN",
        "target" => "System.out"
    }
}

ログレベルがINFOに設定されています。このため、INFOレベル以上のログのみが出力されたわけですね。

次に。FILEというハンドラーを確認してみましょう。こちらは日付パターンに応じてローテーションするperiodic-rotating-file-handlerという
ハンドラーです。

[standalone@localhost:9990 /] /subsystem=logging/periodic-rotating-file-handler=FILE:read-resource
{
    "outcome" => "success",
    "result" => {
        "append" => true,
        "autoflush" => true,
        "enabled" => true,
        "encoding" => undefined,
        "file" => {
            "relative-to" => "jboss.server.log.dir",
            "path" => "server.log"
        },
        "filter-spec" => undefined,
        "formatter" => "%d{HH:mm:ss,SSS} %-5p [%c] (%t) %s%e%n",
        "level" => "ALL",
        "name" => "FILE",
        "named-formatter" => "PATTERN",
        "suffix" => ".yyyy-MM-dd"
    }
}

こちらはログレベルがALLになっているので、ハンドラーに渡されたすべてのレベルのログが出力されたことになります。

では、CONSOLEハンドラーのログレベルをDEBUGに変更してみましょう。

[standalone@localhost:9990 /] /subsystem=logging/console-handler=CONSOLE:write-attribute(name=level,value=DEBUG)

これで、コンソールに出力されるログもDEBUGレベルになりました。

00:10:00,812 INFO  [org.littlewings.wildfly.logging.HelloResource] (default task-1) logger class name = org.slf4j.impl.Slf4jLogger
00:10:00,812 DEBUG [org.littlewings.wildfly.logging.HelloResource] (default task-1) debug message in resource
00:10:00,812 INFO  [org.littlewings.wildfly.logging.HelloResource] (default task-1) info message in resource
00:10:00,812 WARN  [org.littlewings.wildfly.logging.HelloResource] (default task-1) warn message in resource
00:10:00,813 ERROR [org.littlewings.wildfly.logging.HelloResource] (default task-1) error message in resource

ハンドラーの一覧はこちらに書かれています。

WildFly Admin Guide / Subsystem configuration / Logging Subsystem / Handlers

カテゴリーを設定する

次に、カテゴリーを設定してみましょう。

WildFly Admin Guide / Subsystem configuration / Logging Subsystem / How To

WildFlyの設定は最初の状態に戻しておきます。

管理CLIで接続。

$ bin/jboss-cli.sh -c

今回はログファイルの出力先をserver.logとは別にしようと思うので、アプリケーション用のperiodic-rotating-file-handlerを追加します。

[standalone@localhost:9990 /] /subsystem=logging/periodic-rotating-file-handler=APP_FILE:add(append=true,autoflush=true,file={relative-to="jboss.server.log.dir",path="app.log"},suffix=".yyyy-MM-dd",encoding=UTF-8)

relative-toにjboss.server.log.dirと指定していますが、これはstandalone/logからの相対パスであることを指定しています。
ログファイル名はapp.logとしました。

カテゴリーに今回作成したサンプルアプリケーションのパッケージ名を指定して、カテゴリーを追加します。ログレベルはDEBUGに
しました。

[standalone@localhost:9990 /] /subsystem=logging/logger=org.littlewings.wildfly.logging:add(level=DEBUG,handlers=[APP_FILE,CONSOLE],use-parent-handlers=false)

この時にハンドラーを指定します。コンソールへの出力は、root-loggerと同じものを使います。

またデフォルトでは親のカテゴリーのハンドラーを引き継ぐようなので、use-parent-handlersはfalseに指定しました。

確認。

[standalone@localhost:9990 /] /subsystem=logging/logger=org.littlewings.wildfly.logging:read-resource
{
    "outcome" => "success",
    "result" => {
        "category" => "org.littlewings.wildfly.logging",
        "filter-spec" => undefined,
        "handlers" => [
            "APP_FILE",
            "CONSOLE"
        ],
        "level" => "DEBUG",
        "use-parent-handlers" => false
    }
}

では、アプリケーションをデプロイしてアクセスしてみます。

追加したstandalone/log/app.logの内容を確認してみます。

00:18:04,083 INFO  [org.littlewings.wildfly.logging.HelloResource] (default task-1) logger class name = org.slf4j.impl.Slf4jLogger
00:18:04,083 DEBUG [org.littlewings.wildfly.logging.HelloResource] (default task-1) debug message in resource
00:18:04,083 INFO  [org.littlewings.wildfly.logging.HelloResource] (default task-1) info message in resource
00:18:04,084 WARN  [org.littlewings.wildfly.logging.HelloResource] (default task-1) warn message in resource
00:18:04,084 ERROR [org.littlewings.wildfly.logging.HelloResource] (default task-1) error message in resource

OKですね。

次に、ログファイルのフォーマットを変更してみましょう。今回はJSONフォーマットにしてみます。

フォーマッターを定義。

[standalone@localhost:9990 /] /subsystem=logging/json-formatter=APP_JSON_FORMATTER:add

このフォーマッターを、先ほど作成したAPP_FILEハンドラーに指定します。

[standalone@localhost:9990 /] /subsystem=logging/periodic-rotating-file-handler=APP_FILE:write-attribute(name=named-formatter,value=APP_JSON_FORMATTER)

確認。

[standalone@localhost:9990 /] /subsystem=logging/periodic-rotating-file-handler=APP_FILE:read-resource
{
    "outcome" => "success",
    "result" => {
        "append" => true,
        "autoflush" => true,
        "enabled" => true,
        "encoding" => "UTF-8",
        "file" => {
            "relative-to" => "jboss.server.log.dir",
            "path" => "app.log"
        },
        "filter-spec" => undefined,
        "formatter" => "%d{HH:mm:ss,SSS} %-5p [%c] (%t) %s%e%n",
        "level" => "ALL",
        "name" => "APP_FILE",
        "named-formatter" => "APP_JSON_FORMATTER",
        "suffix" => ".yyyy-MM-dd"
    }
}

アプリケーションへアクセス。

$ curl localhost:8080/hello
Hello World!!

ログファイル(standalone/log/app.log)の内容を確認。

{"timestamp":"2024-06-11T00:22:01.156+09:00","sequence":61,"loggerClassName":"org.slf4j.impl.Slf4jLogger","loggerName":"org.littlewings.wildfly.logging.HelloResource","level":"INFO","message":"logger class name = org.slf4j.impl.Slf4jLogger","threadName":"default task-1","threadId":161,"mdc":{},"ndc":"","hostName":"ikaruga","processName":"jboss-modules.jar","processId":22283}
{"timestamp":"2024-06-11T00:22:01.16+09:00","sequence":62,"loggerClassName":"org.slf4j.impl.Slf4jLogger","loggerName":"org.littlewings.wildfly.logging.HelloResource","level":"DEBUG","message":"debug message in resource","threadName":"default task-1","threadId":161,"mdc":{},"ndc":"","hostName":"ikaruga","processName":"jboss-modules.jar","processId":22283}
{"timestamp":"2024-06-11T00:22:01.16+09:00","sequence":63,"loggerClassName":"org.slf4j.impl.Slf4jLogger","loggerName":"org.littlewings.wildfly.logging.HelloResource","level":"INFO","message":"info message in resource","threadName":"default task-1","threadId":161,"mdc":{},"ndc":"","hostName":"ikaruga","processName":"jboss-modules.jar","processId":22283}
{"timestamp":"2024-06-11T00:22:01.16+09:00","sequence":64,"loggerClassName":"org.slf4j.impl.Slf4jLogger","loggerName":"org.littlewings.wildfly.logging.HelloResource","level":"WARN","message":"warn message in resource","threadName":"default task-1","threadId":161,"mdc":{},"ndc":"","hostName":"ikaruga","processName":"jboss-modules.jar","processId":22283}
{"timestamp":"2024-06-11T00:22:01.16+09:00","sequence":65,"loggerClassName":"org.slf4j.impl.Slf4jLogger","loggerName":"org.littlewings.wildfly.logging.HelloResource","level":"ERROR","message":"error message in resource","threadName":"default task-1","threadId":161,"mdc":{},"ndc":"","hostName":"ikaruga","processName":"jboss-modules.jar","processId":22283}

JSONフォーマットになりました。OKですね。

フォーマッターの一覧はこちらに書かれています。

WildFly Admin Guide / Subsystem configuration / Logging Subsystem / Logging Formatters

また、loggingサブシステムの各要素に設定できる内容はモデルリファレンスを見て確認するのがよいと思います。

WildFly Full Model Reference / subsystem=logging

おわりに

WildFlyのloggingサブシステムの設定を見てみました。

今まであんまり気にしていなかったのでちょっと大変でしたが、管理CLIでの設定方法がわかればあとはなんとかなりそうですね。