Logback（＋Logstash Logback Encoder）でログ内の文字列を置換する

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

Logbackを使ってログ出力をする時に、ログメッセージを置換する方法はないかな？ということで調べてみました。

以下の方法がありそうです。

replace変換指定子を使う
自分でConverterを作成する
MaskingJsonGeneratorDecoratorを使う（Logstash Logback Encoder）

これを、通常のLogbackをLogstash Logback Encoderを使った時それぞれで調べてみました。

ログ出力する際に文字列置換する

Logbackでログ出力する際には、replace変換指定子（Conversion specifier）を使うのが良さそうです。

Layouts / PatternLayout

こちらですね。

Layouts / PatternLayout / replace

こちらに使い方の例が載っています。

Layouts / Conversion word options

%replaceの()内に対象の文字列を、{}内に正規表現と置換後の文字列を与えるようです。

<pattern>%-5level - %replace(%msg){'\d{14,16}', 'XXXX'}%n</pattern>

今まであんまり気にしていなかったのですが、そもそも%msgのようなものを「Conversion word」と呼ぶみたいですね。

PatternLayoutの箇所にConversion wordの一覧が載っています。

Layouts / PatternLayout

そして、変換指定子は自分でも作成することができます。

Layouts / Evaluators / Creating a custom conversion specifier

ドキュメントには、ClassicConverterクラスを継承して作成する例が書かれています。

ClassicConverter (Logback-Parent 1.3.0 API)

他にも、CompositeConverterクラスを継承して作成する方法もあります。

CompositeConverter (Logback-Parent 1.3.0 API)

Conversion wordは、オプションを取ることができます。スタックトレースを表現する%ex{short}などがいい例ですよね。
これはClassicConverterクラスのサブクラスとして実現されています。

replace変換指定子は、さらに()で対象の文字列を指定することができます。こんな感じで。

`%replace(%msg){'\d{14,16}', 'XXXX'}`

これはCompositeConverterクラスのサブクラスとして実現されています。

Mask Sensitive Data in Logs With Logback | Baeldung

たとえば%msgの実体はこちらです。

https://github.com/qos-ch/logback/blob/v_1.4.7/logback-classic/src/main/java/ch/qos/logback/classic/pattern/MessageConverter.java

replace変換指定子の実体はこちらです。

https://github.com/qos-ch/logback/blob/v_1.4.7/logback-core/src/main/java/ch/qos/logback/core/pattern/ReplacingCompositeConverter.java

このあたりの指定子は、以下のパッケージを見るとよいでしょう。

https://github.com/qos-ch/logback/tree/v_1.4.7/logback-core/src/main/java/ch/qos/logback/core/pattern

https://github.com/qos-ch/logback/tree/v_1.4.7/logback-classic/src/main/java/ch/qos/logback/classic/pattern

PatternLayoutには、これらがデフォルトで登録されているので各種指定子が使える、ということになります。

https://github.com/qos-ch/logback/blob/v_1.4.7/logback-classic/src/main/java/ch/qos/logback/classic/PatternLayout.java#L52-L162

https://github.com/qos-ch/logback/blob/v_1.4.7/logback-core/src/main/java/ch/qos/logback/core/pattern/parser/Parser.java#L47-L53

変換指定子を自分で作成した場合は、以下のようにconversionRuleで登録します。

<configuration>

  <conversionRule conversionWord="nanos"
                  converterClass="layouts.MySampleConverter" />

  <appender name="STDOUT" class="ch.qos.logback.;core.ConsoleAppender">
    <encoder>
      <pattern>%-6nanos [%thread] -%kvp -%msg%n</pattern>
    </encoder>
  </appender>

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

Layouts / Evaluators / Creating a custom conversion specifier

Spring Bootでも使われているようですね。

https://github.com/spring-projects/spring-boot/blob/v3.0.6/spring-boot-project/spring-boot/src/main/resources/org/springframework/boot/logging/logback/defaults.xml

まずはこのあたりを試してみましょう。
※Logstash Logback Encoderは後で扱います

環境

今回の環境は、こちら。

$ java --version
openjdk 17.0.6 2023-01-17
OpenJDK Runtime Environment (build 17.0.6+10-Ubuntu-0ubuntu122.04)
OpenJDK 64-Bit Server VM (build 17.0.6+10-Ubuntu-0ubuntu122.04, mixed mode, sharing)


$ mvn --version
Apache Maven 3.9.1 (2e178502fcdbffc201671fb2537d0cb4b4cc58f8)
Maven home: $HOME/.sdkman/candidates/maven/current
Java version: 17.0.6, vendor: Private Build, runtime: /usr/lib/jvm/java-17-openjdk-amd64
Default locale: ja_JP, platform encoding: UTF-8
OS name: "linux", version: "5.15.0-70-generic", arch: "amd64", family: "unix"

準備

Maven依存関係など。

    <properties>
        <maven.compiler.source>17</maven.compiler.source>
        <maven.compiler.target>17</maven.compiler.target>
        <project.build.sourceEncoding>UTF-8</project.build.sourceEncoding>
        <project.reporting.outputEncoding>UTF-8</project.reporting.outputEncoding>
    </properties>

    <dependencies>
        <dependency>
            <groupId>org.slf4j</groupId>
            <artifactId>slf4j-api</artifactId>
            <version>2.0.7</version>
        </dependency>
        <dependency>
            <groupId>ch.qos.logback</groupId>
            <artifactId>logback-classic</artifactId>
            <version>1.4.7</version>
        </dependency>
    </dependencies>

まずはSLF4Jとlogback-classicを依存関係に加えます。

なお、SLF4JとLogbackのバージョン関係は以下のようです。必要なJavaのバージョンや、Java EE／Jakarta EEのサポートにも
差がありますね。Logback 1.3と1.4の差はそれくらいのようです。

News

お題

文字列置換ということで、今回はログメッセージ内にメールアドレスが出現したら別の文字列に置き換える、というお題で考えたいと
思います。

サンプルプログラム

サンプルプログラムとしては、以下のようなものを用意。

sc/main/java/org/littlewings/logback/App.java

package org.littlewings.logback;

import org.slf4j.Logger;
import org.slf4j.LoggerFactory;

public class App {
    public static void main(String... args) {
        Logger logger = LoggerFactory.getLogger(App.class);

        logger.info("Hello World!!");
        logger.info("Hello, isono@example.com, namino@example.com !!");
        logger.info("Hello, {}, {} !!", "isono@example.com", "namino@example.net");

        try {
            throwException("Oops!! namino@example.net");
        } catch (RuntimeException e) {
            logger.info("Hello, {} !!", "isono@example.com", new RuntimeException(e));
        }
    }

    static void throwException(String message) {
        throw new RuntimeException(message);
    }
}

ログ中にメールアドレスが入ったり、置換文字列（{}）内にメールアドレスを入れてみたり、例外メッセージにメールアドレスを
入れてみたり。

最初のlogback.xmlは、こんな感じでいきます。

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} [%thread] %-5level %logger{36} - %msg%n</pattern>
    </encoder>
  </appender>

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

実行結果。

2023-04-23 16:13:09.923 [main] INFO  org.littlewings.logback.App - Hello World!!
2023-04-23 16:13:09.925 [main] INFO  org.littlewings.logback.App - Hello, isono@example.com, namino@example.com !!
2023-04-23 16:13:09.925 [main] INFO  org.littlewings.logback.App - Hello, isono@example.com, namino@example.net !!
2023-04-23 16:13:09.926 [main] INFO  org.littlewings.logback.App - Hello, isono@example.com !!
java.lang.RuntimeException: java.lang.RuntimeException: Oops!! namino@example.net
    at org.littlewings.logback.App.main(App.java:17)
Caused by: java.lang.RuntimeException: Oops!! namino@example.net
    at org.littlewings.logback.App.throwException(App.java:22)
    at org.littlewings.logback.App.main(App.java:15)

ここからいろいろ変えていこうと思います。

Logbackでログ内の文字列を置換する

replace変換指定子を使う

最初に使うのは、replace変換指定子。

Layouts / PatternLayout / replace

logback.xmlは、以下のように変更。

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} [%thread] %-5level %logger{36} - %replace(%msg){'\w+@\w+\.\w+', 'xxxxx@xxxxx'}%n</pattern>
    </encoder>
  </appender>

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

%msg変換指定子を%replace(){'正規表現', '置換後の文字列}で囲みます。

%replace(%msg){'\w+@\w+\.\w+', 'xxxxx@xxxxx'}

結果。

2023-04-23 16:17:22.211 [org.littlewings.logback.App.main()] INFO  org.littlewings.logback.App - Hello World!!
2023-04-23 16:17:22.213 [org.littlewings.logback.App.main()] INFO  org.littlewings.logback.App - Hello, xxxxx@xxxxx, xxxxx@xxxxx !!
2023-04-23 16:17:22.213 [org.littlewings.logback.App.main()] INFO  org.littlewings.logback.App - Hello, xxxxx@xxxxx, xxxxx@xxxxx !!
2023-04-23 16:17:22.214 [org.littlewings.logback.App.main()] INFO  org.littlewings.logback.App - Hello, xxxxx@xxxxx !!
java.lang.RuntimeException: java.lang.RuntimeException: Oops!! namino@example.net
        at org.littlewings.logback.App.main(App.java:17)
        at org.codehaus.mojo.exec.ExecJavaMojo$1.run(ExecJavaMojo.java:279)
        at java.base/java.lang.Thread.run(Thread.java:833)
Caused by: java.lang.RuntimeException: Oops!! namino@example.net
        at org.littlewings.logback.App.throwException(App.java:22)
        at org.littlewings.logback.App.main(App.java:15)
        ... 2 common frames omitted

例外の部分が変わっていませんね。では、こうしてみましょう。

      <pattern>%d{yyyy-MM-dd HH:mm:ss.SSS} [%thread] %-5level %logger{36} - %replace(%msg){'\w+@\w+\.\w+', 'xxxxx@xxxxx'}%n%replace(%ex){'\w+@\w+\.\w+', 'xxxxx@xxxxx'}</pattern>

%exを明示的に追加して、こちらを置換するようにしてみました。

今度はうまくいきます。

2023-04-23 16:18:28.674 [org.littlewings.logback.App.main()] INFO  org.littlewings.logback.App - Hello World!!
2023-04-23 16:18:28.676 [org.littlewings.logback.App.main()] INFO  org.littlewings.logback.App - Hello, xxxxx@xxxxx, xxxxx@xxxxx !!
2023-04-23 16:18:28.676 [org.littlewings.logback.App.main()] INFO  org.littlewings.logback.App - Hello, xxxxx@xxxxx, xxxxx@xxxxx !!
2023-04-23 16:18:28.677 [org.littlewings.logback.App.main()] INFO  org.littlewings.logback.App - Hello, xxxxx@xxxxx !!
java.lang.RuntimeException: java.lang.RuntimeException: Oops!! xxxxx@xxxxx
        at org.littlewings.logback.App.main(App.java:17)
        at org.codehaus.mojo.exec.ExecJavaMojo$1.run(ExecJavaMojo.java:279)
        at java.base/java.lang.Thread.run(Thread.java:833)
Caused by: java.lang.RuntimeException: Oops!! xxxxx@xxxxx
        at org.littlewings.logback.App.throwException(App.java:22)
        at org.littlewings.logback.App.main(App.java:15)
        ... 2 common frames omitted

ただ、この方法だと正規表現を設定ファイル内に書くことになります。今回のように簡単な正規表現であればよいですが、たとえば
WHATWGの定義する正規表現のようなものだったりするとちょっと面倒な感じがします。

The following JavaScript- and Perl-compatible regular expression is an implementation of the above definition.

/^[a-zA-Z0-9.!#$%&'+\/=?^_`{|}~-]+@a-zA-Z0-9?(?:.a-zA-Z0-9?)$/

HTML / The elements of HTML / Forms / The input element / States of the type attribute / Email state / valid email address

変換内容をJavaコード側で表現できたらよいな、ということで、別の仕組みも試してみます。

ClassicConverterを使う

次は、ClassicConverterを使ってみましょう。

ClassicConverter (Logback-Parent 1.3.0 API)

ClassicConverterを使うということは、変換指定子を自作するということですね。

Layouts / Evaluators / Creating a custom conversion specifier

ドキュメントの例では、%nanosという変換指定子を作成しています。

今回は、以下のようなClassicConverterのサブクラスを作成。

src/main/java/org/littlewings/logback/MyMessageConverter.java

package org.littlewings.logback;

import ch.qos.logback.classic.pattern.ClassicConverter;
import ch.qos.logback.classic.spi.ILoggingEvent;

import java.util.regex.Matcher;
import java.util.regex.Pattern;

public class MyMessageConverter extends ClassicConverter {
    private static final Pattern EMAIL_PATTERN = Pattern.compile(
            "[a-zA-Z0-9.!#$%&'*+\\/=?^_`{|}~-]+@[a-zA-Z0-9](?:[a-zA-Z0-9-]{0,61}[a-zA-Z0-9])?(?:\\.[a-zA-Z0-9](?:[a-zA-Z0-9-]{0,61}[a-zA-Z0-9])?)*"
    );

    @Override
    public String convert(ILoggingEvent event) {
        //String message = event.getMessage();  // {}のまま
        String message = event.getFormattedMessage();  // {}を解決した後

        Matcher matcher = EMAIL_PATTERN.matcher(message);

        if (matcher.find()) {
            return matcher.replaceAll("[xxxxx]");
        }

        return message;
    }
}

ILoggingEventから取得できるメッセージを正規表現で置換してみます。

これを%mymsgとしてconversionRuleに登録。

src/main/resources/logback.xml

<?xml version="1.0" encoding="UTF-8"?>
<configuration>
  <conversionRule conversionWord="mymsg" converterClass="org.littlewings.logback.MyMessageConverter" />

  <appender name="STDOUT" class="ch.qos.logback.core.ConsoleAppender">
    <encoder>
      <pattern>%d{yyyy-MM-dd HH:mm:ss.SSS} [%thread] %-5level %logger{36} - %mymsg%n</pattern>
    </encoder>
  </appender>

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

pattern内で使ってみます。

      <pattern>%d{yyyy-MM-dd HH:mm:ss.SSS} [%thread] %-5level %logger{36} - %mymsg%n</pattern>

結果。

2023-04-23 16:31:26.018 [org.littlewings.logback.App.main()] INFO  org.littlewings.logback.App - Hello World!!
2023-04-23 16:31:26.021 [org.littlewings.logback.App.main()] INFO  org.littlewings.logback.App - Hello, [xxxxx], [xxxxx] !!
2023-04-23 16:31:26.021 [org.littlewings.logback.App.main()] INFO  org.littlewings.logback.App - Hello, [xxxxx], [xxxxx] !!
2023-04-23 16:31:26.022 [org.littlewings.logback.App.main()] INFO  org.littlewings.logback.App - Hello, [xxxxx] !!
java.lang.RuntimeException: java.lang.RuntimeException: Oops!! namino@example.net
        at org.littlewings.logback.App.main(App.java:17)
        at org.codehaus.mojo.exec.ExecJavaMojo$1.run(ExecJavaMojo.java:279)
        at java.base/java.lang.Thread.run(Thread.java:833)
Caused by: java.lang.RuntimeException: Oops!! namino@example.net
        at org.littlewings.logback.App.throwException(App.java:22)
        at org.littlewings.logback.App.main(App.java:15)
        ... 2 common frames omitted

あくまでメッセージを置換しているだけなので、この方法だと例外メッセージは手が出ませんね…。

ちなみに、以下の部分を入れ替えると{}を評価する前のメッセージを扱うことになるので

    @Override
    public String convert(ILoggingEvent event) {
        String message = event.getMessage();  // {}のまま
        //String message = event.getFormattedMessage();  // {}を解決した後

結果がこうなります。

2023-04-23 16:32:24.751 [org.littlewings.logback.App.main()] INFO  org.littlewings.logback.App - Hello World!!
2023-04-23 16:32:24.754 [org.littlewings.logback.App.main()] INFO  org.littlewings.logback.App - Hello, [xxxxx], [xxxxx] !!
2023-04-23 16:32:24.754 [org.littlewings.logback.App.main()] INFO  org.littlewings.logback.App - Hello, {}, {} !!
2023-04-23 16:32:24.755 [org.littlewings.logback.App.main()] INFO  org.littlewings.logback.App - Hello, {} !!
java.lang.RuntimeException: java.lang.RuntimeException: Oops!! namino@example.net
        at org.littlewings.logback.App.main(App.java:17)
        at org.codehaus.mojo.exec.ExecJavaMojo$1.run(ExecJavaMojo.java:279)
        at java.base/java.lang.Thread.run(Thread.java:833)
Caused by: java.lang.RuntimeException: Oops!! namino@example.net
        at org.littlewings.logback.App.throwException(App.java:22)
        at org.littlewings.logback.App.main(App.java:15)
        ... 2 common frames omitted

こんな使い方はしないとは思いますが…。

CompositeConverterを使う

次は、CompositeConverterクラスを使ってみます。こちらはドキュメントには記載がありませんが、%replace変換指定子はこちらで
実装されています。

CompositeConverter (Logback-Parent 1.3.0 API)

ClassicConverterとの違いは、別の変換指定子などを入力にできることですね。

たとえば、先ほど%replaceを使って例ではこんな感じで%msgを引数にしていました。

%replace(%msg){'\w+@\w+\.\w+', 'xxxxx@xxxxx'}

ちなみにClassicConverterでも{}は使えます（先ほどのサンプルでは扱いませんでした）。

こう考えると、以下のようなものもClassicConverterにオプションとして渡していることがわかります。

%logger{36}
%X{user}

MDCも変換指定子で実現されています。

で、今回はこんなCompositeConverterを作成。

src/main/java/org/littlewings/logback/EmailReplaceConverter.java

package org.littlewings.logback;

import ch.qos.logback.classic.spi.ILoggingEvent;
import ch.qos.logback.core.pattern.CompositeConverter;

import java.util.regex.Matcher;
import java.util.regex.Pattern;

public class EmailReplaceConverter extends CompositeConverter<ILoggingEvent> {
    private static final Pattern EMAIL_PATTERN = Pattern.compile(
            "[a-zA-Z0-9.!#$%&'*+\\/=?^_`{|}~-]+@[a-zA-Z0-9](?:[a-zA-Z0-9-]{0,61}[a-zA-Z0-9])?(?:\\.[a-zA-Z0-9](?:[a-zA-Z0-9-]{0,61}[a-zA-Z0-9])?)*"
    );

    String replacement;

    @Override
    public void start() {
        replacement = getFirstOption() != null ? getFirstOption() : "[xxxxx]";
    }

    @Override
    protected String transform(ILoggingEvent event, String in) {
        Matcher matcher = EMAIL_PATTERN.matcher(in);

        if (matcher.find()) {
            return matcher.replaceAll(replacement);
        }

        return in;
    }
}

transformメソッドの第2引数に、()で指定した値が渡ってきます。

オプションも与え、指定されていなかったら[xxxxx]とするようにしてみました。
※この記述はClassicConverterでも可能です

    @Override
    public void start() {
        replacement = getFirstOption() != null ? getFirstOption() : "[xxxxx]";
    }

これをconversionRuleに%emailで変換指定子として扱えるように登録。

src/main/resources/logback.xml

<?xml version="1.0" encoding="UTF-8"?>
<configuration>
  <conversionRule conversionWord="email" converterClass="org.littlewings.logback.EmailReplaceConverter" />

  <appender name="STDOUT" class="ch.qos.logback.core.ConsoleAppender">
    <encoder>
      <pattern>%d{yyyy-MM-dd HH:mm:ss.SSS} [%thread] %-5level %logger{36} - %email(%msg){}%n%email(%ex){}</pattern>
    </encoder>
  </appender>

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

メッセージとスタックトレースを変換できるようにしました。

      <pattern>%d{yyyy-MM-dd HH:mm:ss.SSS} [%thread] %-5level %logger{36} - %email(%msg){}%n%email(%ex){}</pattern>

結果。

機能しているようです。

2023-04-23 16:44:51.020 [org.littlewings.logback.App.main()] INFO  org.littlewings.logback.App - Hello World!!
2023-04-23 16:44:51.022 [org.littlewings.logback.App.main()] INFO  org.littlewings.logback.App - Hello, [xxxxx], [xxxxx] !!
2023-04-23 16:44:51.022 [org.littlewings.logback.App.main()] INFO  org.littlewings.logback.App - Hello, [xxxxx], [xxxxx] !!
2023-04-23 16:44:51.024 [org.littlewings.logback.App.main()] INFO  org.littlewings.logback.App - Hello, [xxxxx] !!
java.lang.RuntimeException: java.lang.RuntimeException: Oops!! [xxxxx]
        at org.littlewings.logback.App.main(App.java:17)
        at org.codehaus.mojo.exec.ExecJavaMojo$1.run(ExecJavaMojo.java:279)
        at java.base/java.lang.Thread.run(Thread.java:833)
Caused by: java.lang.RuntimeException: Oops!! [xxxxx]
        at org.littlewings.logback.App.throwException(App.java:22)
        at org.littlewings.logback.App.main(App.java:15)
        ... 2 common frames omitted

オプションを指定してみましょう。

      <pattern>%d{yyyy-MM-dd HH:mm:ss.SSS} [%thread] %-5level %logger{36} - %email(%msg){'[zzzzz]'}%n%email(%ex){'[zzzzz]'}</pattern>

反映されましたね。

2023-04-23 16:46:42.657 [org.littlewings.logback.App.main()] INFO  org.littlewings.logback.App - Hello World!!
2023-04-23 16:46:42.659 [org.littlewings.logback.App.main()] INFO  org.littlewings.logback.App - Hello, [zzzzz], [zzzzz] !!
2023-04-23 16:46:42.659 [org.littlewings.logback.App.main()] INFO  org.littlewings.logback.App - Hello, [zzzzz], [zzzzz] !!
2023-04-23 16:46:42.661 [org.littlewings.logback.App.main()] INFO  org.littlewings.logback.App - Hello, [zzzzz] !!
java.lang.RuntimeException: java.lang.RuntimeException: Oops!! [zzzzz]
        at org.littlewings.logback.App.main(App.java:17)
        at org.codehaus.mojo.exec.ExecJavaMojo$1.run(ExecJavaMojo.java:279)
        at java.base/java.lang.Thread.run(Thread.java:833)
Caused by: java.lang.RuntimeException: Oops!! [zzzzz]
        at org.littlewings.logback.App.throwException(App.java:22)
        at org.littlewings.logback.App.main(App.java:15)
        ... 2 common frames omitted

Logback単体だとこんなところでしょうか。

Logstash Logback Encoderを使う

続いては、Logstash Logback Encoderを使った場合をテーマにします。

ここから先は、依存関係にlogstash-logback-encoderを加えているものとします。

    <dependencies>
        <dependency>
            <groupId>org.slf4j</groupId>
            <artifactId>slf4j-api</artifactId>
            <version>2.0.7</version>
        </dependency>
        <dependency>
            <groupId>ch.qos.logback</groupId>
            <artifactId>logback-classic</artifactId>
            <version>1.4.7</version>
        </dependency>
        <dependency>
            <groupId>net.logstash.logback</groupId>
            <artifactId>logstash-logback-encoder</artifactId>
            <version>7.3</version>
        </dependency>
    </dependencies>

また、以下のソースコードは特に変更しません。

src/main/java/org/littlewings/logback/App.java

package org.littlewings.logback;

import org.slf4j.Logger;
import org.slf4j.LoggerFactory;

public class App {
    public static void main(String... args) {
        Logger logger = LoggerFactory.getLogger(App.class);

        logger.info("Hello World!!");
        logger.info("Hello, isono@example.com, namino@example.com !!");
        logger.info("Hello, {}, {} !!", "isono@example.com", "namino@example.net");

        try {
            throwException("Oops!! namino@example.net");
        } catch (RuntimeException e) {
            logger.info("Hello, {} !!", "isono@example.com", new RuntimeException(e));
        }
    }

    static void throwException(String message) {
        throw new RuntimeException(message);
    }
}

Masking

Logstash Logback Encoderにはマスキングの機能があります。

Logstash Logback Encoder / Masking

用途としては、個人情報や機密情報のマスキングに使うことを想定されているようです。

The MaskingJsonGeneratorDecorator can be used to mask sensitive values (e.g. personally identifiable information (PII) or financial data).

マスキングの機能を使うと、特定のパス（フィールド）をマスキングしたり、値を正規表現でマスキングすることができるようになります。

まずはこちらを使ってみます。

簡単に設定。

src/main/resources/logback.xml

<?xml version="1.0" encoding="UTF-8"?>
<configuration>
  <appender name="STDOUT" class="ch.qos.logback.core.ConsoleAppender">
    <encoder class="net.logstash.logback.encoder.LogstashEncoder">
      <jsonGeneratorDecorator class="net.logstash.logback.mask.MaskingJsonGeneratorDecorator">
        <defaultMask>****</defaultMask>

        <path>message</path>
        <path>logger_name</path>
      </jsonGeneratorDecorator>
    </encoder>
  </appender>

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

MaskingJsonGeneratorDecoratorを使います。

defaultMaskでマスキングした時のデフォルト値を指定できますが、これを省略すると****を指定したことになります。

        <defaultMask>****</defaultMask>

最初はmessageとstack_traceを指定。

        <path>message</path>
        <path>logger_name</path>

結果。指定したフィールドがマスキングされました。

{"@timestamp":"2023-04-23T17:01:27.002749969+09:00","@version":"1","message":"****","logger_name":"****","thread_name":"org.littlewings.logback.App.main()","level":"INFO","level_value":20000}
{"@timestamp":"2023-04-23T17:01:27.015472912+09:00","@version":"1","message":"****","logger_name":"****","thread_name":"org.littlewings.logback.App.main()","level":"INFO","level_value":20000}
{"@timestamp":"2023-04-23T17:01:27.015804802+09:00","@version":"1","message":"****","logger_name":"****","thread_name":"org.littlewings.logback.App.main()","level":"INFO","level_value":20000}
{"@timestamp":"2023-04-23T17:01:27.016798701+09:00","@version":"1","message":"****","logger_name":"****","thread_name":"org.littlewings.logback.App.main()","level":"INFO","level_value":20000,"stack_trace":"java.lang.RuntimeException: java.lang.RuntimeException: Oops!! namino@example.net\n\tat org.littlewings.logback.App.main(App.java:17)\n\tat org.codehaus.mojo.exec.ExecJavaMojo$1.run(ExecJavaMojo.java:279)\n\tat java.base/java.lang.Thread.run(Thread.java:833)\nCaused by: java.lang.RuntimeException: Oops!! namino@example.net\n\tat org.littlewings.logback.App.throwException(App.java:22)\n\tat org.littlewings.logback.App.main(App.java:15)\n\t... 2 common frames omitted\n"}

他にもパスでの指定方法は種類があるので、詳しくはドキュメントを参照。

Logstash Logback Encoder / Masking / dentifying field values to mask by path

次は、値でマスキングしてみます。

Identifying field values to mask by value

ログ内に出現する値を正規表現でマスキングできますが、パス指定のマスキングよりも実行コストがかかることが注意点です。

Identifying data to mask by value is much more expensive than identifying data to mask by path. Therefore, prefer identifying data to mask by path.

また、値のマスキングは定義された数だけ順次実行されていきますが、この評価順には依存すべきではないことが書かれています。

The value to mask is passed through every value masker, with the output of one masker passed as input to the next masker. This allows each masker to mask specific substrings within the value. The order in which the maskers are executed is not defined, and should not be relied upon.

今回は、シンプルに設定。

src/main/resources/logback.xml

<?xml version="1.0" encoding="UTF-8"?>
<configuration>
  <appender name="STDOUT" class="ch.qos.logback.core.ConsoleAppender">
    <encoder class="net.logstash.logback.encoder.LogstashEncoder">
      <jsonGeneratorDecorator class="net.logstash.logback.mask.MaskingJsonGeneratorDecorator">
        <defaultMask>****</defaultMask>

        <value>\w+@\w+\.\w+</value>
      </jsonGeneratorDecorator>
    </encoder>
  </appender>

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

結果。

{"@timestamp":"2023-04-23T17:07:54.178933736+09:00","@version":"1","message":"Hello World!!","logger_name":"org.littlewings.logback.App","thread_name":"org.littlewings.logback.App.main()","level":"INFO","level_value":20000}
{"@timestamp":"2023-04-23T17:07:54.187134752+09:00","@version":"1","message":"Hello, ****, **** !!","logger_name":"org.littlewings.logback.App","thread_name":"org.littlewings.logback.App.main()","level":"INFO","level_value":20000}
{"@timestamp":"2023-04-23T17:07:54.189851624+09:00","@version":"1","message":"Hello, ****, **** !!","logger_name":"org.littlewings.logback.App","thread_name":"org.littlewings.logback.App.main()","level":"INFO","level_value":20000}
{"@timestamp":"2023-04-23T17:07:54.191020147+09:00","@version":"1","message":"Hello, **** !!","logger_name":"org.littlewings.logback.App","thread_name":"org.littlewings.logback.App.main()","level":"INFO","level_value":20000,"stack_trace":"java.lang.RuntimeException: java.lang.RuntimeException: Oops!! ****\n\tat org.littlewings.logback.App.main(App.java:17)\n\tat org.codehaus.mojo.exec.ExecJavaMojo$1.run(ExecJavaMojo.java:279)\n\tat java.base/java.lang.Thread.run(Thread.java:833)\nCaused by: java.lang.RuntimeException: Oops!! ****\n\tat org.littlewings.logback.App.throwException(App.java:22)\n\tat org.littlewings.logback.App.main(App.java:15)\n\t... 2 common frames omitted\n"}

メールアドレスの部分がマスキングされました。

マスキング処理をクラスでも実装することができます。ValueMaskerというインターフェースを実装します。

src/main/java/org/littlewings/logback/EmailValueMasker.java

package org.littlewings.logback;

import com.fasterxml.jackson.core.JsonStreamContext;
import net.logstash.logback.mask.ValueMasker;

import java.util.regex.Matcher;
import java.util.regex.Pattern;

public class EmailValueMasker implements ValueMasker {
    private static final Pattern EMAIL_PATTERN = Pattern.compile(
                "[a-zA-Z0-9.!#$%&'*+\\/=?^_`{|}~-]+@[a-zA-Z0-9](?:[a-zA-Z0-9-]{0,61}[a-zA-Z0-9])?(?:\\.[a-zA-Z0-9](?:[a-zA-Z0-9-]{0,61}[a-zA-Z0-9])?)*"
        );

    @Override
    public Object mask(JsonStreamContext context, Object value) {
        if (value instanceof String in) {
            Matcher matcher = EMAIL_PATTERN.matcher(in);

            if (matcher.find()) {
                return matcher.replaceAll("[*****]");
            }
        }

        return null;
    }
}

作成したクラスは、valueMaskerで設定。

src/main/resources/logback.xml

<?xml version="1.0" encoding="UTF-8"?>
<configuration>
  <appender name="STDOUT" class="ch.qos.logback.core.ConsoleAppender">
    <encoder class="net.logstash.logback.encoder.LogstashEncoder">
      <jsonGeneratorDecorator class="net.logstash.logback.mask.MaskingJsonGeneratorDecorator">
        <defaultMask>****</defaultMask>

        <valueMasker class="org.littlewings.logback.EmailValueMasker" />
      </jsonGeneratorDecorator>
    </encoder>
  </appender>

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

結果。

{"@timestamp":"2023-04-23T17:16:09.271622188+09:00","@version":"1","message":"Hello World!!","logger_name":"org.littlewings.logback.App","thread_name":"org.littlewings.logback.App.main()","level":"INFO","level_value":20000}
{"@timestamp":"2023-04-23T17:16:09.280521883+09:00","@version":"1","message":"Hello, [*****], [*****] !!","logger_name":"org.littlewings.logback.App","thread_name":"org.littlewings.logback.App.main()","level":"INFO","level_value":20000}
{"@timestamp":"2023-04-23T17:16:09.283502453+09:00","@version":"1","message":"Hello, [*****], [*****] !!","logger_name":"org.littlewings.logback.App","thread_name":"org.littlewings.logback.App.main()","level":"INFO","level_value":20000}
{"@timestamp":"2023-04-23T17:16:09.284884527+09:00","@version":"1","message":"Hello, [*****] !!","logger_name":"org.littlewings.logback.App","thread_name":"org.littlewings.logback.App.main()","level":"INFO","level_value":20000,"stack_trace":"java.lang.RuntimeException: java.lang.RuntimeException: Oops!! [*****]\n\tat org.littlewings.logback.App.main(App.java:17)\n\tat org.codehaus.mojo.exec.ExecJavaMojo$1.run(ExecJavaMojo.java:279)\n\tat java.base/java.lang.Thread.run(Thread.java:833)\nCaused by: java.lang.RuntimeException: Oops!! [*****]\n\tat org.littlewings.logback.App.throwException(App.java:22)\n\tat org.littlewings.logback.App.main(App.java:15)\n\t... 2 common frames omitted\n"}

OKですね。

値でのマスキングの指定方法は、他にもいくつかありますが詳しくはドキュメントを参照、ということで。

Identifying field values to mask by value

変換指定子を使う

Logstash Logback Encoderでも変換指定子を使うことができます。

ただ、指定方法がちょっとプリミティブになります。

これまでencoderにLogstashEncoderを指定していました。

    <encoder class="net.logstash.logback.encoder.LogstashEncoder">

今回はLoggingEventCompositeJsonEncoderを指定することになります。

    <encoder class="net.logstash.logback.encoder.LoggingEventCompositeJsonEncoder">

LoggingEventCompositeJsonEncoderは、LogstashEncoderの親クラスです。
LogstashEncoderはProviderと呼ばれる出力要素をデフォルトで設定したものであり、LoggingEventCompositeJsonEncoderを使うと
デフォルト設定はなくなりますが、その代わりに柔軟なカスタマイズができるようになります。

Logstash Logback Encoder / Composite Encoder/Layout

たとえば、encoderにLoggingEventCompositeJsonEncoderのみを設定してみます。

src/main/resources/logback.xml

<?xml version="1.0" encoding="UTF-8"?>
<configuration>
  <appender name="STDOUT" class="ch.qos.logback.core.ConsoleAppender">
    <encoder class="net.logstash.logback.encoder.LoggingEventCompositeJsonEncoder">
    </encoder>
  </appender>

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

すると、ログになにも含まれなくなります。

{}
{}
{}
{}

この時、Logstash Logback EncoderからはProviderが設定されていないとERRORが出ていたりします。

22:42:26,570 |-ERROR in net.logstash.logback.encoder.LoggingEventCompositeJsonEncoder@7f977055 - No providers configured

LogstashEncoder相当の設定をしようとすると、このくらいでしょうか。

src/main/resources/logback.xml

<?xml version="1.0" encoding="UTF-8"?>
<configuration>
  <appender name="STDOUT" class="ch.qos.logback.core.ConsoleAppender">
    <encoder class="net.logstash.logback.encoder.LoggingEventCompositeJsonEncoder">
      <providers>
        <timestamp/>
        <version/>
        <message />
        <loggerName />
        <threadName />
        <logLevel />
        <stackTrace />
        <context />
        <mdc/>
        <tags />
        <arguments />
      </providers>
    </encoder>
  </appender>

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

https://github.com/logfellow/logstash-logback-encoder/blob/logstash-logback-encoder-7.3/src/main/java/net/logstash/logback/encoder/LogstashEncoder.java#L33

https://github.com/logfellow/logstash-logback-encoder/blob/logstash-logback-encoder-7.3/src/main/java/net/logstash/logback/LogstashFormatter.java#L115-L129

結果。

{"@timestamp":"2023-04-23T22:46:39.340368538+09:00","@version":"1","message":"Hello World!!","logger_name":"org.littlewings.logback.App","thread_name":"org.littlewings.logback.App.main()","level":"INFO"}
{"@timestamp":"2023-04-23T22:46:39.346415333+09:00","@version":"1","message":"Hello, isono@example.com, namino@example.com !!","logger_name":"org.littlewings.logback.App","thread_name":"org.littlewings.logback.App.main()","level":"INFO"}
{"@timestamp":"2023-04-23T22:46:39.346623562+09:00","@version":"1","message":"Hello, isono@example.com, namino@example.net !!","logger_name":"org.littlewings.logback.App","thread_name":"org.littlewings.logback.App.main()","level":"INFO"}
{"@timestamp":"2023-04-23T22:46:39.347528225+09:00","@version":"1","message":"Hello, isono@example.com !!","logger_name":"org.littlewings.logback.App","thread_name":"org.littlewings.logback.App.main()","level":"INFO","stack_trace":"java.lang.RuntimeException: java.lang.RuntimeException: Oops!! namino@example.net\n\tat org.littlewings.logback.App.main(App.java:17)\n\tat org.codehaus.mojo.exec.ExecJavaMojo$1.run(ExecJavaMojo.java:279)\n\tat java.base/java.lang.Thread.run(Thread.java:833)\nCaused by: java.lang.RuntimeException: Oops!! namino@example.net\n\tat org.littlewings.logback.App.throwException(App.java:22)\n\tat org.littlewings.logback.App.main(App.java:15)\n\t... 2 common frames omitted\n"}

このように、Providerを追加するにしたがってログに出力される項目が増えていきます。

指定できるProviderは、このあたりに記載があります。

Logstash Logback Encoder / Composite Encoder/Layout / Providers common to LoggingEvents and AccessEvents

Logstash Logback Encoder / Composite Encoder/Layout / Providers for LoggingEvents

ここにさらにpattern／patternを加えることで、出力するログに項目を「追加」できます。

src/main/resources/logback.xml

<?xml version="1.0" encoding="UTF-8"?>
<configuration>
  <appender name="STDOUT" class="ch.qos.logback.core.ConsoleAppender">
    <encoder class="net.logstash.logback.encoder.LoggingEventCompositeJsonEncoder">
      <providers>
        <timestamp/>
        <version/>
        <!-- <message /> -->
        <loggerName />
        <threadName />
        <logLevel />
        <!-- <stackTrace /> -->
        <context />
        <mdc/>
        <tags />
        <arguments />
        <pattern>
          <pattern>
            {
              "message": "%msg",
              "stack_trace": "%ex"
            }
          </pattern>
        </pattern>
      </providers>
    </encoder>
  </appender>

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

今回はmessageとstack_traceを追加したので、Providerの方はコメントアウトしています。これを残したままにすると、同じ内容が
二重に追加されることになります。

ではここで、%replace変換指定子を追加してみます。

src/main/resources/logback.xml

<?xml version="1.0" encoding="UTF-8"?>
<configuration>
  <appender name="STDOUT" class="ch.qos.logback.core.ConsoleAppender">
    <encoder class="net.logstash.logback.encoder.LoggingEventCompositeJsonEncoder">
      <providers>
        <timestamp/>
        <version/>
        <!-- <message /> -->
        <loggerName />
        <threadName />
        <logLevel />
        <!-- <stackTrace /> -->
        <context />
        <mdc/>
        <tags />
        <arguments />
        <pattern>
          <pattern>
            {
              "message": "%replace(%msg){'\\w+@\\w+\\.\\w+', 'xxxxx@xxxxx'}",
              "stack_trace": "%replace(%ex){'\\w+@\\w+\\.\\w+', 'xxxxx@xxxxx'}"
            }
          </pattern>
        </pattern>
      </providers>
    </encoder>
  </appender>

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

ちょっとエスケープが面倒ですね…。

結果。

{"@timestamp":"2023-04-23T23:00:54.515349092+09:00","@version":"1","logger_name":"org.littlewings.logback.App","thread_name":"org.littlewings.logback.App.main()","level":"INFO","message":"Hello World!!","stack_trace":""}
{"@timestamp":"2023-04-23T23:00:54.520224038+09:00","@version":"1","logger_name":"org.littlewings.logback.App","thread_name":"org.littlewings.logback.App.main()","level":"INFO","message":"Hello, xxxxx@xxxxx, xxxxx@xxxxx !!","stack_trace":""}
{"@timestamp":"2023-04-23T23:00:54.520538823+09:00","@version":"1","logger_name":"org.littlewings.logback.App","thread_name":"org.littlewings.logback.App.main()","level":"INFO","message":"Hello, xxxxx@xxxxx, xxxxx@xxxxx !!","stack_trace":""}
{"@timestamp":"2023-04-23T23:00:54.521686038+09:00","@version":"1","logger_name":"org.littlewings.logback.App","thread_name":"org.littlewings.logback.App.main()","level":"INFO","message":"Hello, xxxxx@xxxxx !!","stack_trace":"java.lang.RuntimeException: java.lang.RuntimeException: Oops!! xxxxx@xxxxx\n\tat org.littlewings.logback.App.main(App.java:17)\n\tat org.codehaus.mojo.exec.ExecJavaMojo$1.run(ExecJavaMojo.java:279)\n\tat java.base/java.lang.Thread.run(Thread.java:833)\nCaused by: java.lang.RuntimeException: Oops!! xxxxx@xxxxx\n\tat org.littlewings.logback.App.throwException(App.java:22)\n\tat org.littlewings.logback.App.main(App.java:15)\n\t... 2 common frames omitted\n"}

自作の変換指定子を使うのもいいかもですね。

src/main/resources/logback.xml

<?xml version="1.0" encoding="UTF-8"?>
<configuration>
  <conversionRule conversionWord="email" converterClass="org.littlewings.logback.EmailReplaceConverter" />

  <appender name="STDOUT" class="ch.qos.logback.core.ConsoleAppender">
    <encoder class="net.logstash.logback.encoder.LoggingEventCompositeJsonEncoder">
      <providers>
        <timestamp/>
        <version/>
        <!-- <message /> -->
        <loggerName />
        <threadName />
        <logLevel />
        <!-- <stackTrace /> -->
        <context />
        <mdc/>
        <tags />
        <arguments />
        <pattern>
          <pattern>
            {
              "message": "%email(%msg)",
              "stack_trace": "%email(%ex)"
            }
          </pattern>
        </pattern>
      </providers>
    </encoder>
  </appender>

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

結果。

{"@timestamp":"2023-04-23T23:14:47.362809176+09:00","@version":"1","logger_name":"org.littlewings.logback.App","thread_name":"org.littlewings.logback.App.main()","level":"INFO","message":"Hello World!!","stack_trace":""}
{"@timestamp":"2023-04-23T23:14:47.368164723+09:00","@version":"1","logger_name":"org.littlewings.logback.App","thread_name":"org.littlewings.logback.App.main()","level":"INFO","message":"Hello, [xxxxx], [xxxxx] !!","stack_trace":""}
{"@timestamp":"2023-04-23T23:14:47.36849854+09:00","@version":"1","logger_name":"org.littlewings.logback.App","thread_name":"org.littlewings.logback.App.main()","level":"INFO","message":"Hello, [xxxxx], [xxxxx] !!","stack_trace":""}
{"@timestamp":"2023-04-23T23:14:47.36955851+09:00","@version":"1","logger_name":"org.littlewings.logback.App","thread_name":"org.littlewings.logback.App.main()","level":"INFO","message":"Hello, [xxxxx] !!","stack_trace":"java.lang.RuntimeException: java.lang.RuntimeException: Oops!! [xxxxx]\n\tat org.littlewings.logback.App.main(App.java:17)\n\tat org.codehaus.mojo.exec.ExecJavaMojo$1.run(ExecJavaMojo.java:279)\n\tat java.base/java.lang.Thread.run(Thread.java:833)\nCaused by: java.lang.RuntimeException: Oops!! [xxxxx]\n\tat org.littlewings.logback.App.throwException(App.java:22)\n\tat org.littlewings.logback.App.main(App.java:15)\n\t... 2 common frames omitted\n"}

MaskingJsonGeneratorDecoratorを使ったマスキングと比べると、対象のフィールドを絞れる分だけ効率的ではないのかなと
思うのですが、どうなのでしょう。

とりあえず、Logstash Logback Encoderを使った場合はこんなところでしょうか。

まとめ

LogbackおよびLogstash Logback Encoderを使って、文字列置換を行う方法をいろいろ調べてみました。

いろいろ方法があるんですね。また変換指定子に関する知識の見直しになったという意味でも、ちゃんと見ておいてよかったです。

CLOVER🍀

That was when it all began.

Logback（＋Logstash Logback Encoder）でログ内の文字列を置換する

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

ログ出力する際に文字列置換する

環境

準備

お題

サンプルプログラム

Logbackでログ内の文字列を置換する

replace変換指定子を使う

ClassicConverterを使う

CompositeConverterを使う

Logstash Logback Encoderを使う

Masking

変換指定子を使う

まとめ