Logbackの設定をJMXで変更する

Logbackの設定って、JMXで変更できるんですね。

なるほど、知っておくと便利そうです。

有効にするには、logback.xmlに

<configuration>
  <jmxConfigurator />

  ...
</configuration>

のように、jmxConfiguratorを入れておけばよいと。

Attributesとしては

Statuses … Logbackのステータス
LoggerList … ロガーの一覧

が定義してあり、Operationとしては設定ファイルのリロードや

reloadDefaultConfiguration
reloadByFileName
reloadByURL

指定のロガーのログレベルの取得、変更ができるようです。

setLoggerLevel
getLoggerLevel
getLoggerEffectiveLevel

というわけで便利そうなのですが、アプリケーションサーバーにデプロイするような時は、LoggerContext#stopをアプリケーション停止時に呼び出さないとリークしちゃうっぽいですね。

Avoiding memory leaks

はい。

使ってみる

というわけで、せっかくなので試してみます。

以下のお題をつけて、簡単なコマンドラインツールを作ってみました。

JMX Remoteは有効にせず、ローカルから接続
Attach APIを活用してJMX接続を取得する
Logbackには依存しない

というのをやってみようかなと思ったところで、似たようなことをやっている方がいらっしゃいました。

LogbackのJMX設定インタフェースを使って設定ファイルの切り替えを行う - penultimate diary

こちらはLogbackに依存しているようでしたので、この点は異なるお題になりますね。

で、作ったのがこちら。
src/main/java/org/littlewings/logbackjmx/Cli.java

package org.littlewings.logbackjmx;

import java.io.Console;
import java.io.File;
import java.io.IOException;
import java.util.Arrays;
import java.util.Collections;
import java.util.HashSet;
import java.util.List;
import java.util.Set;
import java.util.stream.IntStream;
import javax.management.MBeanServerConnection;
import javax.management.MalformedObjectNameException;
import javax.management.ObjectName;
import javax.management.remote.JMXConnector;
import javax.management.remote.JMXConnectorFactory;
import javax.management.remote.JMXServiceURL;

import com.sun.tools.attach.AgentInitializationException;
import com.sun.tools.attach.AgentLoadException;
import com.sun.tools.attach.AttachNotSupportedException;
import com.sun.tools.attach.VirtualMachine;

public class Cli implements AutoCloseable {
    private static final String LOGBACK_DOMAIN = "ch.qos.logback.classic";
    private static final String LOGBACK_JMX_CONFIGURATOR_TYPE =
            "ch.qos.logback.classic.jmx.JMXConfigurator";
    private static final String DEFAULT_LOGBACK_NAME = "default";
    private static final Set<String> LOGBACK_JMX_CONFIGURATOR_ATTRIBUTES;

    static {
        Set<String> attributes = new HashSet<>();
        attributes.add("LoggerList");
        attributes.add("Statuses");
        LOGBACK_JMX_CONFIGURATOR_ATTRIBUTES =
                Collections.unmodifiableSet(attributes);
    }

    private static final String CONNECTOR_ADDRESS =
            "com.sun.management.jmxremote.localConnectorAddress";

    protected String name;

    protected VirtualMachine virtualMachine;
    protected JMXConnector connector;
    protected MBeanServerConnection server;

    protected ObjectName jmxConfiguratorObjectName;

    public static void main(String... args) throws Exception {
        System.out.printf("enter Logback JMX Cli.%n");

        Cli cli;
        if (args.length > 1) {
            String pid = args[0];
            String name = args[1];
            cli = Cli.attach(pid, name);
        } else {
            String pid = args[0];
            cli = Cli.attach(pid);
        }

        try {
            cli.connect();

            if (cli.lookupJmxConfigurator()) {
                System.out.printf("found Logback JMXConfiturator = %s.%n", cli.createLogbackJmxConfiguratorName());
                System.out.println();

                cli.printAttributes();
                System.out.println();
                cli.printOperations();
                System.out.println();

                cli.invokeWhile();

                System.out.printf("exit Logback JMX Cli.%n");
            } else {
                System.out.printf("Logback JMXConfigurator [%s], not found.%n", cli.createLogbackJmxConfiguratorName());
            }
        } finally {
            cli.close();
        }
    }

    Cli(VirtualMachine virtualMachine, String name) {
        this.virtualMachine = virtualMachine;
        this.name = name;
    }

    public static Cli attach(String pid) throws IOException,
            AttachNotSupportedException {
        return attach(pid, DEFAULT_LOGBACK_NAME);
    }

    public static Cli attach(String pid, String name) throws
            IOException, AttachNotSupportedException {
        System.out.printf("Attache to JavaVM = %s.%n", pid);
        return new Cli(VirtualMachine.attach(pid), name);
    }

    public void connect() throws IOException, AgentLoadException,
            AgentInitializationException {
        String connectorAddress =
                virtualMachine.getAgentProperties().getProperty(CONNECTOR_ADDRESS);

        if (connectorAddress == null) {
            System.out.printf("Load to Agent library.%n");

            String agent =
                    virtualMachine.getSystemProperties().getProperty("java.home") +
                            File.separator + "lib" + File.separator +
                            "management-agent.jar";
            virtualMachine.loadAgent(agent);

            System.out.println("Agent loaded.");

            connectorAddress =
                    virtualMachine.getAgentProperties().getProperty(CONNECTOR_ADDRESS);
        }

        System.out.printf("Detach JavaVM.%n");

        // VMからデタッチ
        virtualMachine.detach();
        virtualMachine = null;

        JMXServiceURL url = new JMXServiceURL(connectorAddress);
        connector = JMXConnectorFactory.connect(url);
        server = connector.getMBeanServerConnection();

        System.out.printf("Connected.%n");
    }

    String createLogbackJmxConfiguratorName() {
        return String.format("%s:Name=%s,Type=%s", LOGBACK_DOMAIN, name,
                LOGBACK_JMX_CONFIGURATOR_TYPE);
    }

    boolean lookupJmxConfigurator() throws MalformedObjectNameException,
            IOException {
        String logbackObjectName = createLogbackJmxConfiguratorName();

        ObjectName objectName = new ObjectName(logbackObjectName);
        Set<ObjectName> objectNames = server.queryNames(objectName,
                null);

        if (objectNames.isEmpty()) {
            return false;
        }

        jmxConfiguratorObjectName = objectNames.toArray(new
                ObjectName[objectNames.size()])[0];

        return true;
    }

    void printAttributes() {
        System.out.printf("Logback JMXConfigurator attributes:%n");
        LOGBACK_JMX_CONFIGURATOR_ATTRIBUTES.forEach(attribute ->
                System.out.printf("  %s%n", attribute));
    }

    void printOperations() {
        List<String> operations = Arrays.asList(
                "void reloadDefaultConfiguration()",
                // "void reloadByURL(java.net.URL url)",
                "void reloadByFileName(String fileName)",
                "void setLoggerLevel(String loggerName, String levelStr)",
                "String getLoggerLevel(String loggerName)",
                "String getLoggerEffectiveLevel(String loggerName)");

        System.out.printf("Logback JMXConfigurator operations:%n");
        operations.forEach(operation -> System.out.printf("  %s%n",
                operation));
    }

    void invokeWhile() {
        Console console = System.console();

        while (true) {
            String line = console.readLine("> ");

            if (line == null || line.isEmpty()) {
                continue;
            }

            line = line.trim();

            if (line.equals("exit")) {
                break;
            }

            if (line.equals("help")) {
                printAttributes();
                System.out.println();
                printOperations();
                System.out.println();
                continue;
            }

            try {
                if (LOGBACK_JMX_CONFIGURATOR_ATTRIBUTES.contains(line)) {
                    String attribute = line;
                    Object returnValue =
                            server.getAttribute(jmxConfiguratorObjectName, attribute);

                    if (returnValue instanceof List) {
                        System.out.printf("attribute [%s] invoked.%n", attribute);

                        List<?> attributes = (List<?>) returnValue;
                        attributes.forEach(attr -> System.out.printf("%s.%n", attr));
                    } else {
                        System.out.printf("attribute [%s] invoked, return=%s.%n", attribute, returnValue);
                    }

                    continue;
                }

                String[] operationAndParams = line.split("\\s+");

                String operation = operationAndParams[0];
                Object[] params;
                String[] signature;
                if (operationAndParams.length > 1) {
                    params = Arrays.copyOfRange(operationAndParams, 1,
                            operationAndParams.length);

                    signature = IntStream.range(1,
                            operationAndParams.length)
                            .mapToObj(i -> String.class.getName())
                            .toArray(String[]::new);
                } else {
                    params = null;
                    signature = null;
                }

                Object returnValue =
                        server.invoke(jmxConfiguratorObjectName, operation, params, signature);

                if (returnValue != null) {
                    System.out.printf("operation [%s] invoked, return = %s.%n", line, returnValue);
                } else {
                    System.out.printf("operation [%s] invoked.%n", line);
                }
            } catch (Exception e) {
                System.out.printf("operation [%s] error, Catch: %s%n", line, e.getMessage());
                continue;
            }
        }
    }

    @Override
    public void close() throws Exception {
        if (virtualMachine != null) {
            virtualMachine.detach();
        }

        if (connector != null) {
            connector.close();
        }
    }
}

引数には、PIDを与えます。また、LogbackにContextNameを指定した場合は、それを第2引数に与えることができます。

JMX接続確立後は、対話的にAttributesおよびOperationを利用することができます。

ちょっとしたJMX APIを使う練習ですね。

テスト対象

確認には、Logbackを使うアプリケーションがないと始まりません。

ここは簡単に、Spring Boot CLIを使いましょう。

64. Using the CLI

ドキュメントのまんまですが…。
hello.groovy

@RestController
class WebApplication {

    @RequestMapping("/")
    String home() {
        "Hello World!"
    }
}

Logbackの設定は、こんな感じで用意。
logback.xml

<?xml version="1.0" encoding="UTF-8"?>
<configuration>
    <jmxConfigurator />

    <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>

    <logger name="org.springframework.web" level="DEBUG"/>
</configuration>

jmxConfiguratorを定義し、「org.springframework.web」のログレベルを指定しています。

SDKMANでSpring Boot CLIをインストールして

$ sdk install springboot

起動。

$ spring run hello.groovy

ちょっとログ多めのアプリケーションが起動します。

確認

それでは、作ったアプリケーションを試してみます。

$ java -cp ${JAVA_HOME}/lib/tools.jar:target/classes org.littlewings.logbackjmx.Cli 55562
enter Logback JMX Cli.
Attache to JavaVM = 55562.
Detach JavaVM.
Connected.
found Logback JMXConfiturator = ch.qos.logback.classic:Name=default,Type=ch.qos.logback.classic.jmx.JMXConfigurator.

Logback JMXConfigurator attributes:
  Statuses
  LoggerList

Logback JMXConfigurator operations:
  void reloadDefaultConfiguration()
  void reloadByFileName(String fileName)
  void setLoggerLevel(String loggerName, String levelStr)
  String getLoggerLevel(String loggerName)
  String getLoggerEffectiveLevel(String loggerName)

>

こんな感じで出力されます。

ロガーの一覧。

> LoggerList
attribute [LoggerList] invoked.
ROOT.
org.
org.apache.
org.apache.catalina.
org.apache.catalina.core.
org.apache.catalina.core.ContainerBase.
org.apache.catalina.core.ContainerBase.[Tomcat].
org.apache.catalina.core.ContainerBase.[Tomcat].[localhost].
org.apache.catalina.core.ContainerBase.[Tomcat].[localhost].[/].
org.apache.catalina.core.StandardEngine.
org.apache.catalina.core.StandardService.
org.apache.catalina.loader.
org.apache.catalina.loader.WebappLoader.
org.apache.coyote.
org.apache.coyote.http11.
org.apache.coyote.http11.Http11NioProtocol.
org.apache.tomcat.
org.apache.tomcat.util.
org.apache.tomcat.util.net.
org.apache.tomcat.util.net.NioSelectorPool.
org.hibernate.
org.hibernate.validator.
org.hibernate.validator.internal.
org.hibernate.validator.internal.engine.
org.hibernate.validator.internal.engine.ConfigurationImpl.
org.hibernate.validator.internal.engine.ValidationContext.
org.hibernate.validator.internal.engine.ValidatorFactoryImpl.
org.hibernate.validator.internal.engine.ValidatorImpl.

〜省略〜

…ものすごい量のロガーが出力されます。

ログレベルを取得してみます。

> getLoggerLevel org.springframework.web
operation [getLoggerLevel org.springframework.web] invoked, return = DEBUG.

DEBUGですね。

これを、INFOに変更してみます。

> setLoggerLevel org.springframework.web INFO
operation [setLoggerLevel org.springframework.web INFO] invoked.

確認。

> getLoggerLevel org.springframework.web
operation [getLoggerLevel org.springframework.web] invoked, return = INFO.

ちゃんと変わったようです。

設定ファイルの再読み込み。

> reloadDefaultConfiguration
operation [reloadDefaultConfiguration] invoked.

ロガーが元のレベルに戻りました。

> getLoggerLevel org.springframework.web
operation [getLoggerLevel org.springframework.web] invoked, return = DEBUG.

なんとなく、helpも。

> help
Logback JMXConfigurator attributes:
  Statuses
  LoggerList

Logback JMXConfigurator operations:
  void reloadDefaultConfiguration()
  void reloadByFileName(String fileName)
  void setLoggerLevel(String loggerName, String levelStr)
  String getLoggerLevel(String loggerName)
  String getLoggerEffectiveLevel(String loggerName)

おしまい。

> exit
exit Logback JMX Cli.

とりあえず、確認したいこと、遊んでみたいことはできた感じです。

CLOVER🍀

That was when it all began.

Logbackの設定をJMXで変更する

使ってみる

テスト対象

確認