Skip to content

Instantly share code, notes, and snippets.

@wreulicke
Last active October 17, 2024 05:39
Show Gist options
  • Save wreulicke/e236203a466d8947be7a39b7a78e3e84 to your computer and use it in GitHub Desktop.
Save wreulicke/e236203a466d8947be7a39b7a78e3e84 to your computer and use it in GitHub Desktop.
2024-10-17 現在のJavaのロギング構成についてメモ書き

Javaでログのライブラリ、何を使ってますか? 今自分は、slf4j + logback を使っています。 ざっくばらんにログに関してまとめておこうと思います。

この記事ではロギングでどう出力すれば良いログになるかについては、話しません。

Spring Bootの構造化ロギングの話

自分が採用したログのライブラリの話をする前に、Spring Bootの構造化ロギングの話を少ししておきます。 Spring Boot 3.4では、Spring Boot標準で構造化ロギングの実装されており Spring Bootへの依存を許すのであれば、以下のブログの機能を使っても良いと思います。

https://spring.io/blog/2024/08/23/structured-logging-in-spring-boot-3-4

一方で、この構造化ロギングですが、ライブラリとしては、spring-boot に実装されており、Spring及びSpring Bootにべったり依存しています。 そのため、バッチ処理などで、Springを使わないワークロードがある場合には適さない可能性があります。 全部Spring/Spring Bootで実装すればええやんけ!という考え方もありますが、一応この点だけは認識しておくと良さそうです。

ただ、Spring Bootを使う上では、非常に便利なので、利用を検討する価値はあると思っています。

前提

ログのライブラリの構成をする前に、いくつかログの出力しているアプリケーションについて軽く説明しておきます。

色々なアレがあり、現在いる自分の環境では、Spring Bootの利用が限定的でした。 また、Spring Bootの構造化ロギングが出たのも最近ということもあり、Spring Bootの構造化ロギングを利用していません。 なお、Spring Bootを使っていないアプリケーションでは、Armeriaを使っています。

また、インフラとしては、Google Cloudの上で、Kubernetes(GKE) 及び Cloud Runのコンテナを利用したワークロードを念頭においています。

ログの保存先としては、GKE/Cloud Run標準で使われる、Cloud Loggingを利用しています。 ログの検索等もそちらを念頭において考えています。

まとめると、以下の3つを踏まえた構成になります。

  • Spring Bootを使っていないアプリケーションがある
  • アプリケーションはKubernetes/Cloud Runなどの根底なGoogle Cloudの上で動く
  • ログの保存先は Cloud Logging を利用している

どういうログを出力したかったか

まずどういうログを出力したかったかを書いておきます。

  • Cloud Loggingやログを取り込むfluent-bitに合わせて、構造化ログ(JSON)でログ出力が出来る
  • Cloud Loggingに合わせたログフィールド名が利用出来る、あるいは、ログフィールド名を柔軟に変更できる
  • ログ出力時にコンテキスト情報をその場で付与することが出来る
  • JSONには文字列以外の数値やオブジェクトなども出力出来る
  • 時間のタイムゾーンを固定できる

そのうえで、これらの要件を満たすことが出来るものを選びました。

ログの出力形式として構造化ログ(JSON)が出力できる

改めて言うことではないかもしれませんが、今回は、アプリケーションからは、 構造化ログとして、ログでJSONを出力することにしています。

その理由としては、以下の文脈での利便性を考慮したためです。

  • アドホックなログの検索
  • 特定のログ出力時のアラート
  • 分析
    • 集計
    • 頻度
    • メトリクス化

また、非構造化ログフォーマットでは、以下のようなことが発生するため、これを避けたかったのもあります・

  • 非構造化ログフォーマットを機械的に処理するためのプログラム・正規表現等の作成の必要がある
  • ログフォーマットの変更すると他システムへの影響が発生する
  • ログフォーマットへの知識がないと読めない

また、実際にクラウドでログ出力先として利用されるサービスでは、JSONによるログの取り込みをサポートしており、ログの分析などが可能になっています。

また、上記2つのサービスでは、percentileやcountなどの集計も行えるため、数値変換処理を行わずに、ログに数値として情報を出力したいと考えました。

Cloud Loggingで特別扱いされる構造化ログ内のフィールド名

Cloud LoggingではいくつかのJSONのフィールド名が特別扱いされるものがあります。 そのため、以下のようなフィールド名に合わせてログのフィールド名を出力する必要があります。

  • severity: ログの重大度
  • httpRequest: HTTPリクエストの情報
  • timestamp: 時間

特に、severityは大きな例で、従来はlog_levelだったりlevelだったりするんですが コンソール上の表示の問題や、Error Reportingでの取り扱いのために、ログレベルのフィールド名を変える必要がありました。

では実際にどういうライブラリを採用したか

こうなりました

  • slf4j
  • logback
  • logstash-logback-encoder

それぞれ選んだ理由をざっくり書いておきます。 ロギングファサードとして、slf4j を選択したのは、他のツールへの移行の余地を残しておきたかったからです。 一方で、logstash-logback-encoderはそれと矛盾する選択ではあるのですが・・・。

logback + logstash-logback-encoderを選んだ理由としては、logging libraryを自前でコードを書いてカスタマイズを必要とせず 柔軟なログ出力が出来ることでした。また、logstash-logback-encoderには、AsyncAppenderが含まれており、 ログ出力のパフォーマンス面で困ったらこれ使えばええかみたいな気持ちになったのもあります。

では柔軟なログ出力、とはどういうことかというと。 大体以下のものです。

  • Cloud Loggingに合わせたログフィールド名が利用出来る、あるいは、ログフィールド名を柔軟に変更できる
  • ログ出力時にコンテキスト情報をその場で付与することが出来る
  • JSONには文字列以外の数値やオブジェクトなども出力出来る
  • 時間のタイムゾーンを固定できる

なお、log4j2は選びませんでした。 ログ出力時にコンテキスト情報をその場で付与することが出来る の点で難があり この場合、必ず sl4j v2 の fluent APIを使う必要があります。

また、log4j2のデフォルトのJSONエンコーダでは、柔軟なログ出力が出来ません。 具体的には、JSONには文字列以外の数値やオブジェクトなども出力出来る の点で引っかかりました。

log4j2では、コンテキスト情報をログに付与する場合、以下のようなコードになるのですが addKeyValueのインターフェースでは、Objectを受け取れるにも関わらず ObjectはtoStringされた結果が出力されることになります。intなどを渡しても同様です。 そのため、デフォルトのJSONロギングのエンコーダでは、JSONにおける数値やオブジェクトの出力が困難なため 利用を諦めました。

3rd partyのライブラリでも、String以外の出力は難しく、log4j2のロギングイベントになる瞬間にStringになった記憶があるので 別途parseしてjsonとして解釈しなおすような処理が必要になると思っています。 この辺は詳しく調べていないので、もう少し良い方法があるなら教えて下さい。 log4j2 使ってみたかったんですけど、これで断念しました。

logger.atInfo().addKeyValue(key, /* String */, value /* Object */)

実際のログ設定

前述の通り、armeriaを使っています。そのため、logbackの設定では、以下のようなものになりました。

Cloud Loggingに突っ込むために、fieldの名前を変えたり、timezone固定したり、サービスの名前やversion情報をログに付与したりしています。 また、Armeriaのlogbackとのインテグレーションでいくつか情報を付与したりしています。

<configuration>
    <!-- gradle-git-properties から生成されるファイルを読み込んでいる -->
    <property resource="git.properties" />
    <statusListener class="ch.qos.logback.core.status.NopStatusListener" />
    <appender name="STDOUT" class="ch.qos.logback.core.ConsoleAppender">
        <encoder class="net.logstash.logback.encoder.LogstashEncoder">
            <!-- server の timezoneなどに影響されるべきではないのと、保存先のことを考えてUTCに固定 -->
            <timeZone>UTC</timeZone> 
            <fieldNames>
                <!-- Cloud Loggingの構造化ログ対応フォーマットでロギングするために、ログレベルのフィールド名にはlevelではなくseverityを使用すること
                https://cloud.google.com/logging/docs/structured-logging?hl=ja#special-payload-fields -->
                <level>severity</level>
                <!-- 標準で `@timestamp` と出力されるので `@` を削除する -->
                <timestamp>timestamp</timestamp>
            </fieldNames>
            <customFields>{"service": "service_name", "version": "${git.commit.id.describe}"}</customFields>
        </encoder>
    </appender>

    <!-- armeria-logback12/13/14 を使って、armeriaのcontext情報をログに付与している -->
    <appender name="RCEA" class="com.linecorp.armeria.common.logback.RequestContextExportingAppender">
        <appender-ref ref="STDOUT" />
        <export>req.headers.user-agent</export>
        <export>req.id</export>
        <export>req.path</export>
        <export>req.method</export>
    </appender>

    <root level="${LOG_LEVEL:-info}">
        <appender-ref ref="RCEA" />
    </root>
</configuration>

ビルド設定

また、ビルド設定についても説明しておきます。 不要なログライブラリを依存に入れないために、以下の設定をgradleでしています。 意図せず利用していないロギングライブラリが依存に入ってしまい、問題が発生するのを避けるためにこうしています。

configurations.configureEach {
    // inspired by https://qiita.com/kazuki-ma/items/13c426e4dccf5cc4d843
    exclude group: "log4j"  // = Old Log4j (1.x) implementation. Replaced by log4j-over-slf4j.
    exclude module: "slf4j-log4j12" // = SLF4J -> Log4J Implementation by SLF4J. Not used (or cyclic dependencies lol).
    exclude module: "slf4j-jdk14" // = SLF4J -> JDK14 Binding. Not used.
    exclude module: "slf4j-jcl" // = SLF4J -> Commons Logging. Not used.
    exclude module: "commons-logging" // Because bridged by org.slf4j:jcl-over-slf4j.
    exclude module: "commons-logging-api" // Replaced by org.slf4j:jcl-over-slf4j.
    exclude group: "org.apache.logging.log4j", module: "log4j-core"
}

Linter

ログの出力のためにはLinterも必要ですよね。 今は、errorproneを利用しているため、errorprone-slf4j を使っています。

spotbugsを使っているなら、同じ作者の方が作っている、findbugs-slf4j の利用ができるかもしれませんが spotbugsを使っていないので、自分は使っていません。

また、errorprone-slf4j ですが、logstash-logback-encoderを利用する上で不便なのが placeholderの検査です。 具体的には、Slf4jPlaceholderMismatch というルールがあるのですが logstash-logback-encoderで、StructuredArgumentsを利用して、ログ出力にその場のコンテキスト情報を付与する際に必ずエラーになります。

具体的には以下のコードです。

logger.info("no placeholder", StructuredArguments.keyValue("key", "value"))

StructuredArguments.keyValue("key", "value") が messageのformatにplaceholderがないので必ず、Slf4jPlaceholderMismatch のエラーが出ます。 今は Slf4jPlaceholderMismatch をSuppressWarningsすることで対応していますが 拙作の errorprone-logstash-logback-encoder を合わせて使えば Slf4jPlaceholderMismatch 互換のルールを実装しているので、errorprone-slf4j 側のルールは無効化できるかもしれません。

まとめ

ログ出力の前提からおさらいし、現在使っているログ構成について書いてみました。 logbackの設定から、ビルド設定、Linterの話まで少し書いておきました。 誰かの役に立つとよいのですが。 logback-tylerでログ設定のコード化をしても良いかなとちょっと思っていますがまだ試せていません。

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment