ログを解析してアラート通知などに活用したい場合、
ログのフォーマットはパースしやすいことが最重要となる。
今回はSpringBootアプリケーションのログを、1ログ1行のJSON形式で出力する方法を解説する。
パースしやすいログとは
- 1ログ1行で出力され、スタックトレースなどが改行されないこと
- key-valueの形式になっていて、keyを指定することで特定の要素を抽出しやすいこと
ゴール
この記事を読むと、ログを以下の要領で出力することができる。
{"@timestamp":"2023-08-26T23:15:19.428102+09:00","@version":"1","message":"Netty started on port 8080","logger_name":"org.springframework.boot.web.embedded.netty.NettyWebServer","thread_name":"restartedMain","level":"INFO","level_value":20000}
完成形のlogback-spring.xml
最初に個人的なベストプラクティスを記載しておく。
面倒な人はこれをコピペすればなんかいい感じになるはず。
<?xml version="1.0" encoding="UTF-8" ?>
<configuration>
<!-- 標準エラー出力 -->
<appender name="STDERR" class="ch.qos.logback.core.ConsoleAppender">
<target>System.err</target>
<!-- WARN以上でフィルタ -->
<filter class="ch.qos.logback.classic.filter.ThresholdFilter">
<level>WARN</level>
</filter>
<encoder class="net.logstash.logback.encoder.LogstashEncoder" >
<throwableConverter class="net.logstash.logback.stacktrace.ShortenedThrowableConverter">
<shortenedClassNameLength>25</shortenedClassNameLength>
</throwableConverter>
</encoder>
</appender>
<!-- 標準出力 -->
<appender name="STDOUT" class="ch.qos.logback.core.ConsoleAppender">
<!-- WARNレベルは除外 -->
<filter class="ch.qos.logback.classic.filter.LevelFilter">
<level>WARN</level>
<onMatch>DENY</onMatch>
<onMismatch>NEUTRAL</onMismatch>
</filter>
<!-- ERRORレベルは除外 -->
<filter class="ch.qos.logback.classic.filter.LevelFilter">
<level>ERROR</level>
<onMatch>DENY</onMatch>
<onMismatch>NEUTRAL</onMismatch>
</filter>
<encoder class="net.logstash.logback.encoder.LogstashEncoder" />
</appender>
<!-- local用に見やすいように出力するパターン -->
<appender name="STDERR_LOCAL" class="ch.qos.logback.core.ConsoleAppender">
<target>System.err</target>
<!-- WARN以上でフィルタ -->
<filter class="ch.qos.logback.classic.filter.ThresholdFilter">
<level>WARN</level>
</filter>
<encoder class="net.logstash.logback.encoder.LogstashEncoder" >
<!-- JSONを見やすく出力 -->
<jsonGeneratorDecorator class="net.logstash.logback.decorate.PrettyPrintingJsonGeneratorDecorator"/>
<throwableConverter class="net.logstash.logback.stacktrace.ShortenedThrowableConverter">
<shortenedClassNameLength>25</shortenedClassNameLength>
</throwableConverter>
</encoder>
</appender>
<appender name="STDOUT_LOCAL" class="ch.qos.logback.core.ConsoleAppender">
<!-- WARNレベルは除外 -->
<filter class="ch.qos.logback.classic.filter.LevelFilter">
<level>WARN</level>
<onMatch>DENY</onMatch>
<onMismatch>NEUTRAL</onMismatch>
</filter>
<!-- ERRORレベルは除外 -->
<filter class="ch.qos.logback.classic.filter.LevelFilter">
<level>ERROR</level>
<onMatch>DENY</onMatch>
<onMismatch>NEUTRAL</onMismatch>
</filter>
<encoder class="net.logstash.logback.encoder.LogstashEncoder" >
<!-- JSONを見やすく出力 -->
<jsonGeneratorDecorator class="net.logstash.logback.decorate.PrettyPrintingJsonGeneratorDecorator"/>
</encoder>
</appender>
<!-- local環境以外 -->
<springProfile name="!local">
<root level="INFO">
<appender-ref ref="STDERR" />
<appender-ref ref="STDOUT" />
</root>
</springProfile>
<!-- local環境のみ -->
<springProfile name="local">
<root level="INFO">
<appender-ref ref="STDOUT_LOCAL" />
<appender-ref ref="STDERR_LOCAL" />
</root>
</springProfile>
</configuration>
手順(まずはシンプルに)
①依存関係を追加
ログをJSON形式にフォーマットしてくれるライブラリがあるので、依存関係に追加する。
gradleを利用している想定なので、maven派の人は読み替えてほしい。
dependencies {
// 省略
// https://mvnrepository.com/artifact/net.logstash.logback/logstash-logback-encoder
implementation 'net.logstash.logback:logstash-logback-encoder:7.4'
// 省略
}
②logback-spring.xmlを作成する
任意のappenderを作成して、encoderにLogstashEncoderを指定するだけで良い。
<?xml version="1.0" encoding="UTF-8" ?>
<configuration>
<!-- STDOUTという名前でappenderを作成 -->
<appender name="STDOUT" class="ch.qos.logback.core.ConsoleAppender">
<!-- logstash-logback-encoderにより、以下のエンコーダーが使えるようになる -->
<encoder class="net.logstash.logback.encoder.LogstashEncoder" />
</appender>
<root level="INFO">
<!-- 作成したappenderを利用 -->
<appender-ref ref="STDOUT" />
</root>
</configuration>
この設定を入れただけで、以下のようにログが出力されるようになる。
{"@timestamp":"2023-08-26T23:32:39.231528+09:00","@version":"1","message":"Netty started on port 8080","logger_name":"org.springframework.boot.web.embedded.netty.NettyWebServer","thread_name":"restartedMain","level":"INFO","level_value":20000}
標準出力と標準エラー出力を分ける
ここまでの設定は、エラーログも標準出力に出力されてしまう。
これを改善するため、ERROR/WARNレベルのログのみ標準エラー出力に流れるようにする。
- LevelFilter:ログレベルの一致に基づいてイベントをフィルタリング
- ThresholdFilter:指定された閾値を下回るイベントをフィルタリング
- INFOを設定すると、TRACEとDEBUGが除外される
「STDOUT」という名前のappenderで標準出力に関する設定をし、
「STDERR」という名前のappenderで標準エラー出力に関する設定を行い、
appender-refでそれらを参照している。
ついでにスタックトレースで出力されるクラス名を省略するようにし、ログサイズを少なくしている。
<?xml version="1.0" encoding="UTF-8" ?>
<configuration>
<!-- 標準エラー出力 -->
<appender name="STDERR" class="ch.qos.logback.core.ConsoleAppender">
<target>System.err</target>
<!-- WARN以上の設定をする -->
<filter class="ch.qos.logback.classic.filter.ThresholdFilter">
<level>WARN</level>
</filter>
<encoder class="net.logstash.logback.encoder.LogstashEncoder" >
<throwableConverter class="net.logstash.logback.stacktrace.ShortenedThrowableConverter">
<!-- スタックトレースのクラス名を省略する -->
<shortenedClassNameLength>25</shortenedClassNameLength>
</throwableConverter>
</encoder>
</appender>
<!-- 標準出力 -->
<appender name="STDOUT" class="ch.qos.logback.core.ConsoleAppender">
<!-- WARNレベルは除外 -->
<filter class="ch.qos.logback.classic.filter.LevelFilter">
<level>WARN</level>
<onMatch>DENY</onMatch><!-- WARNにマッチしたときは除外 -->
<onMismatch>NEUTRAL</onMismatch><!-- WARNにマッチしなかったときはそのまま -->
</filter>
<!-- ERRORレベルは除外 -->
<filter class="ch.qos.logback.classic.filter.LevelFilter">
<level>ERROR</level>
<onMatch>DENY</onMatch><!-- ERRORにマッチしたときは除外 -->
<onMismatch>NEUTRAL</onMismatch><!-- ERRORにマッチしなかったときはそのまま -->
</filter>
<encoder class="net.logstash.logback.encoder.LogstashEncoder" />
</appender>
<!-- local環境以外 -->
<root level="INFO">
<appender-ref ref="STDERR" />
<appender-ref ref="STDOUT" />
</root>
</configuration>
Profile=localのときだけ見やすく表示する
パースしやすいログになったのは良いが、その代わり人間が読みにくくなってしまった。
ローカル環境で起動する場合は、人間が見ることが多いので
「ローカル環境だけJSONを改行して見やすくする」設定を行う。
目指すべきフォーマットは、以下のようにログが出力されること。
{
"@timestamp" : "2023-08-27T13:09:22.567068+09:00",
"@version" : "1",
"message" : "The following 1 profile is active: \"local\"",
"logger_name" : "com.example.springwebfluxsample.SpringWebfluxSampleApplication",
"thread_name" : "restartedMain",
"level" : "INFO",
"level_value" : 20000
}
これを行うには、encoderに以下の設定を追加するだけでOK。
<jsonGeneratorDecorator class="net.logstash.logback.decorate.PrettyPrintingJsonGeneratorDecorator"/>
また、profileがローカルのときと、それ以外のときで場合分けを行い
「本番環境では改行なしだが、ローカル環境では改行あり」にしている。
<?xml version="1.0" encoding="UTF-8" ?>
<configuration>
<!-- 標準エラー出力 -->
<appender name="STDERR" class="ch.qos.logback.core.ConsoleAppender">
<target>System.err</target>
<!-- WARN以上でフィルタ -->
<filter class="ch.qos.logback.classic.filter.ThresholdFilter">
<level>WARN</level>
</filter>
<encoder class="net.logstash.logback.encoder.LogstashEncoder" >
<throwableConverter class="net.logstash.logback.stacktrace.ShortenedThrowableConverter">
<shortenedClassNameLength>25</shortenedClassNameLength>
</throwableConverter>
</encoder>
</appender>
<!-- 標準出力 -->
<appender name="STDOUT" class="ch.qos.logback.core.ConsoleAppender">
<!-- WARNレベルは除外 -->
<filter class="ch.qos.logback.classic.filter.LevelFilter">
<level>WARN</level>
<onMatch>DENY</onMatch>
<onMismatch>NEUTRAL</onMismatch>
</filter>
<!-- ERRORレベルは除外 -->
<filter class="ch.qos.logback.classic.filter.LevelFilter">
<level>ERROR</level>
<onMatch>DENY</onMatch>
<onMismatch>NEUTRAL</onMismatch>
</filter>
<encoder class="net.logstash.logback.encoder.LogstashEncoder" />
</appender>
<!-- local用に見やすいように出力するパターン -->
<appender name="STDERR_LOCAL" class="ch.qos.logback.core.ConsoleAppender">
<target>System.err</target>
<!-- WARN以上でフィルタ -->
<filter class="ch.qos.logback.classic.filter.ThresholdFilter">
<level>WARN</level>
</filter>
<encoder class="net.logstash.logback.encoder.LogstashEncoder" >
<!-- JSONを見やすく出力 -->
<jsonGeneratorDecorator class="net.logstash.logback.decorate.PrettyPrintingJsonGeneratorDecorator"/>
<throwableConverter class="net.logstash.logback.stacktrace.ShortenedThrowableConverter">
<shortenedClassNameLength>25</shortenedClassNameLength>
</throwableConverter>
</encoder>
</appender>
<appender name="STDOUT_LOCAL" class="ch.qos.logback.core.ConsoleAppender">
<!-- WARNレベルは除外 -->
<filter class="ch.qos.logback.classic.filter.LevelFilter">
<level>WARN</level>
<onMatch>DENY</onMatch>
<onMismatch>NEUTRAL</onMismatch>
</filter>
<!-- ERRORレベルは除外 -->
<filter class="ch.qos.logback.classic.filter.LevelFilter">
<level>ERROR</level>
<onMatch>DENY</onMatch>
<onMismatch>NEUTRAL</onMismatch>
</filter>
<encoder class="net.logstash.logback.encoder.LogstashEncoder" >
<!-- JSONを見やすく出力 -->
<jsonGeneratorDecorator class="net.logstash.logback.decorate.PrettyPrintingJsonGeneratorDecorator"/>
</encoder>
</appender>
<!-- local環境以外 -->
<springProfile name="!local">
<root level="INFO">
<appender-ref ref="STDERR" />
<appender-ref ref="STDOUT" />
</root>
</springProfile>
<!-- local環境のみ -->
<springProfile name="local">
<root level="INFO">
<appender-ref ref="STDERR_LOCAL" />
<appender-ref ref="STDOUT_LOCAL" />
</root>
</springProfile>
</configuration>
この設定を行い、プロファイルに「local」を指定して実行すると
JSONログが改行されて表示される。
$ export SPRING_PROFILES_ACTIVE=local
$ ./gradlew bootRun
まとめ
logstash-logback-encoder
を使うことで、ログをJSON化できる- appenderはログ設定の1単位のイメージ
- filterで設定対象のログをコントロール
- encoderはログのフォーマット指定
springProfile
で、プロファイルごとに設定を分けることができる