GKE 上の Java アプリケーションからログを出力して Stackdriver Logging でいい感じに閲覧したい
Google Kubernetes Engine (GKE) 上で稼動させている Java アプリケーションのログをいい感じに Stackdriver Logging で閲覧できるようにするメモです。
TL; DR
- REST API を直接叩くのはライブラリ由来のハングアップ問題に遭遇しかねないので避けた方がいいよ
- アプリケーションからのログは JSON フォーマットで出力するといいよ
- ログレベルを表すフィールドは
"severity"の名前で出力しよう - タイムスタンプは
"timestampMillis"と"timestampNanos"をセットで出力しよう - Spring Boot アプリケーションなら spring-cloud-gcp-starter-logging を使うのがいいよ
はじめに
GKE を利用してコンテナ化されたアプリケーションを稼動させていると、アプリケーションの稼動状況を確認する手段の一つとして、アプリケーションから出力されたログを閲覧したり検索したくなることがよくあります 1。 Google Cloud Platform では、そのような目的に適したサービスとして Stackdriver Logging が提供されています。
このサービスは、単にアプリケーションからロガーなどを通じて標準出力 / 標準エラーにログを出力するだけでひとまず使えるようになるのですが、例外のコールスタックログを (コールスタック 1 行ごとに分割せずに) 一つのログエントリとして扱ったり、ロガーやスレッド名などでログを絞り込む、ログレベルに応じたアイコンを表示する、といった便利な使い方を実現したい場合は、Stackdriver Logging に適したフォーマットでログを出力する必要が出てきます。
今回取り上げる Java に限った話ではないですが、GKE 上のアプリケーションから出力されるログを Stackdriver Logging のコンソール上でよりいい感じに閲覧・検索できるようにするには、以下の二つのどちらかの方法をとることになります。
- 方法その 1: Stackdriver Logging が提供する REST API を利用して、アプリケーションから Stackdriver Logging に直接ログを投げつける
- 方法その 2: JSON フォーマットでログを標準出力に書き出しつつ、GKE が標準で提供している fluentd 経由で Stackdriver Logging に投げる
Java においては、どちらの方法を採用するにしても Logback や Log4j といった具体的なロガー実装や SLF4J のようなファサードライブラリの利用を前提としてログを出力することになるでしょう。
このエントリでは、それぞれの方法の比較をしつつ、Java における各種ライブラリ / ロガーの実装状況や相性・注意点なども考慮した上で、どちらの方法を採用するのが望ましいかを考えてみます。
二つの方法、どちらを採用すべきか？
その1: Stackdriver Logging API を利用する
Stackdriver Logging の REST API を利用してログを出力する場合は、
- REST API を扱うためのライブラリ
- 同ライブラリを利用した各種ロガーのアペンダーなどの実装
の二つの具体的なライブラリが必要になります。
前者については、Google Cloud Client Library for Java を構成するライブラリの一つとして google-cloud-logging (GitHub repo) が提供されています。そして後者については、Logback のアペンダー実装として Google が自ら提供している google-cloud-logging-logback (GitHub repo, docs) が存在します。
ただし、このアペンダー実装はライブラリのバージョンに alpha と銘打たれているように安定性に不安があることと、このライブラリが依存している (前者の) google-cloud-logging にハングアップしてしまう (現時点で) 未修正の不具合が存在 していることから、特にハングアップ問題の影響で Stackdriver Logging にログがまったく送出されなくなってしまうことが起こりうる という致命的な問題を抱えています。
google-cloud-logging のハングアップ問題についてはそれほど高頻度で発生するものではないのですが、Web アプリケーションなど長時間稼動し続けることを前提としたアプリケーションの場合だと唐突にログ出力が途絶える事態に陥りかねないため、基本的にこの方法でのログ出力は避けるべきだと思われます。
その2: JSON フォーマットで出力 & fluentd 経由でログを投げる
REST API を直接利用する方法に対して、GKE の fluentd 経由でログを送る方法では、その fluentd の output プラグインに適した所定の JSON フォーマットでログを出力することになります。
GKE の fluentd 周りの詳細については「GKEではStackDriver Loggingにどうやってログを送っているか」のスライドがとても参考になるのでぜひ一読していただくとして、同スライドの 19 ページ目にあるように、実際に Stackdriver Logging にログを送出するのは fluentd のプラグイン fluent-plugin-google-cloud (GitHub repo) の役割となります。
具体的な JSON フォーマットについては、ロギングエージェントの 構造化ペイロードの特殊フィールド と fluent-plugin-google-cloud の実装が参考になります。特に考慮すべきフィールドは、ログレベルを表す "severity"、ログメッセージを表す "message"、時間関連のフィールド の三つになります。2
ログレベルの具体的な値については fluent-plugin-google-cloud の 実装 にあるとおり、一般的な表現から Stackdriver Logging における表現 への変換がなされるので、お使いのロガー実装におけるログレベルそれぞれの表現に対応するマッピングが存在するかを確認するのがいいでしょう (といっても、Java のロガーの場合は特に気にすることはなさそうです)。
時間については先のリンクにあるとおり 3 つの表現方法があり、"time" フィールドの場合を除いて他はいずれも秒単位の UNIX 時間と、ナノ秒単位で表される 1 秒未満の時間の組み合わせとなります。"time" フィールドの場合は、ISO 8601 の書式で表された日時となります。このあたりの詳細は プラグインの実装 も参考にするといいでしょう。
この JSON フォーマットでログを出力する方法は、REST API の呼び出しが Java アプリケーションから切り離される (fluentd & プラグインに委ねられる) ため、先のライブラリ由来のハングアップ問題とは無縁になるメリットがあります。そのため、こちらの JSON フォーマットで出力する方法が 現時点では 有力な方法と言えるでしょう。
fluent-plugin-google-cloud フレンドリーな JSON フォーマットでログ出力する
ここからは、Java の代表的なロガー実装である Logback と Log4j それぞれにおいて、JSON フォーマットでの出力を実現する具体的な方法について見ていきます。
Logback で JSON フォーマットのログを出力する
Logback で JSON フォーマットのログを出力するには、logback-contrib のライブラリを使うのがお手軽でおすすめです。具体的には以下の 2 つのライブラリです。
- ch.qos.logback.contrib:logback-json-classic (GitHub repo)
- ch.qos.logback.contrib:logback-jackson (GitHu repo)
加えて、logback-jackson が provided スコープで依存している jackson-databind も依存に含める必要があります。
logback-json-classic ライブラリはログを JSON で出力するための具体的なレイアウトの実装を提供しており、これを logback.xml などの設定ファイルで参照することで Java の実装なしにログを JSON で出力できるようになります。
ただしこのレイアウト実装をそのまま利用すると、ログレベルを示すフィールド名が fluentd プラグインの要求する "severity" ではなく "level" で出力されることと、時間のフィールド名が "timestamp" として出力されるため、このままでは Stackdriver Logging 側でログを適切に扱えません。そのため、同レイアウト実装を例えば以下のようにクラス継承し、"level" や "timestamp" のフィールドも出力しつつ、加えて "severity" や時間関連のフィールドも一緒に出力するなどの対応が必要となります。
package me.k11i.logback.stackdriver;
import ch.qos.logback.classic.spi.ILoggingEvent;
import ch.qos.logback.contrib.json.classic.JsonLayout;
import java.util.Map;
public class StackdriverFriendlyJsonLayout extends JsonLayout {
@Override
protected void addCustomDataToJsonMap(Map<String, Object> map, ILoggingEvent event) {
long timestampMillis = event.getTimeStamp();
map.put("timestampSeconds", timestampMillis / 1000);
map.put("timestampNanos", (timestampMillis % 1000) * 1_000_000);
map.put("severity", String.valueOf(event.getLevel()));
}
}
このレイアウト実装を利用するとした場合の Logback の設定は次のようになります。
<?xml version="1.0" encoding="UTF-8"?>
<configuration>
<appender name="CONSOLE-JSON" class="ch.qos.logback.core.ConsoleAppender">
<encoder class="ch.qos.logback.core.encoder.LayoutWrappingEncoder">
<layout class="me.k11i.logback.stackdriver.StackdriverFriendlyJsonLayout">
<jsonFormatter class="ch.qos.logback.contrib.jackson.JacksonJsonFormatter"/>
<timestampFormat>yyyy-MM-dd'T'HH:mm:ss.SSSXXX</timestampFormat>
<appendLineSeparator>true</appendLineSeparator>
</layout>
</encoder>
</appender>
<root level="info">
<appender-ref ref="CONSOLE-JSON"/>
</root>
</configuration>
build.gradle 含めたサンプルコードは こちら です。
Log4j (Log4j2) を利用するケース
Log4j を利用する場合は、Logback より少し複雑になります。なおここでは Log4j2 の利用を前提とします。
Log4j2 には (log4j-core に含まれている) 標準機能として、Jackson を利用して JSON フォーマットで出力するレイアウト実装の JsonLayout クラスが備わっています。ただこの実装は試してみるとわかるとおり、Logback のそれと比較して JSON 構造的にかなり冗長な出力になりがちです。加えて、そのため、この JsonLayout (もしくは親クラスの AbstractJacksonLayout) を頑張って設定したり拡張して使うのではなく、AbstractStringLayout クラスを継承した自前のクラス、例えば以下のような実装を用意してしまった方が手短に済むことでしょう。
package me.k11i.log4j2.stackdriver;
import com.fasterxml.jackson.databind.ObjectMapper;
import org.apache.logging.log4j.core.Layout;
import org.apache.logging.log4j.core.LogEvent;
import org.apache.logging.log4j.core.config.Node;
import org.apache.logging.log4j.core.config.plugins.Plugin;
import org.apache.logging.log4j.core.config.plugins.PluginFactory;
import org.apache.logging.log4j.core.impl.ThrowableProxy;
import org.apache.logging.log4j.core.layout.AbstractStringLayout;
import org.apache.logging.log4j.core.util.StringBuilderWriter;
import java.nio.charset.Charset;
import java.nio.charset.StandardCharsets;
import java.util.LinkedHashMap;
import java.util.Map;
@Plugin(name = "StackdriverFriendlyJsonLayout", category = Node.CATEGORY, elementType = Layout.ELEMENT_TYPE)
public class StackdriverFriendlyJsonLayout extends AbstractStringLayout {
private static final ObjectMapper OBJECT_MAPPER = new ObjectMapper();
@PluginFactory
public static StackdriverFriendlyJsonLayout create() {
return new StackdriverFriendlyJsonLayout();
}
public StackdriverFriendlyJsonLayout() {
this(StandardCharsets.UTF_8);
}
protected StackdriverFriendlyJsonLayout(Charset charset) {
super(charset);
}
@Override
public String toSerializable(LogEvent event) {
Map<String, Object> map = new LinkedHashMap<>();
map.put("timestampSeconds", event.getTimeMillis() / 1000);
map.put("timestampNanos", (event.getTimeMillis() % 1000) * 1_000_000);
putIfNotNull("severity", event.getLevel().toString(), map);
putIfNotNull("thread", event.getThreadName(), map);
putIfNotNull("logger", event.getLoggerFqcn(), map);
putIfNotNull("message", event.getMessage().getFormattedMessage(), map);
putIfNotNull("exception", getThrowableAsString(event.getThrownProxy()), map);
try {
StringBuilderWriter writer = new StringBuilderWriter();
OBJECT_MAPPER.writeValue(writer, map);
writer.append('\n');
return writer.toString();
} catch (Exception e) {
LOGGER.error(e);
return null;
}
}
private String getThrowableAsString(ThrowableProxy thrownProxy) {
if (thrownProxy != null) {
return thrownProxy.getExtendedStackTraceAsString();
}
return null;
}
private void putIfNotNull(String key, String value, Map<String, Object> map) {
if (value != null) {
map.put(key, value);
}
}
}
Log4j2 の設定は、上記のレイアウト実装を利用するように記述します。特に Configuration 要素の packages 属性で、レイアウト実装が存在しうるパッケージを指定する必要があることにさえ注意すれば、他は特に難しいことはありません。
<?xml version="1.0" encoding="UTF-8"?>
<Configuration status="warn"
packages="me.k11i.log4j2">
<Appenders>
<Console name="console">
<StackdriverFriendlyJsonLayout />
</Console>
</Appenders>
<Loggers>
<Root level="info">
<AppenderRef ref="console"/>
</Root>
</Loggers>
</Configuration>
build.gradle 含めたサンプルコードは こちら です。
Spring Boot アプリケーションの場合
ここまでは具体的なロガー実装 (Logback / Log4j2) に着目して、fluent-plugin-google-cloud の fluentd プラグインに適合した JSON フォーマットになるようにレイアウト実装を自前で用意する方法を見てきました。
ところで、Spring Cloud プロジェクトの Spring Cloud GCP では spring-cloud-gcp-starter-logging というライブラリが提供されています。実はこのライブラリには、Stackdriver Logging をサポートする機能 が含まれています。
そしてこのライブラリを利用すれば、自前のレイアウト実装をする必要もなく以下のように非常にシンプルな設定を用意するだけで適切な JSON フォーマットでのログ出力ができるようになります。
<configuration>
<include resource="org/springframework/cloud/gcp/autoconfigure/logging/logback-json-appender.xml" />
<root level="INFO">
<appender-ref ref="CONSOLE_JSON" />
</root>
</configuration>
build.gradle 含めたサンプルコードは こちら です。
この spring-cloud-gcp-starter-logging を使う方法の欠点としては、前述した Logback / Log4j2 のレイアウト実装を自前で用意する方法と比較してアプリケーションの依存ライブラリが多くなってしまうことと、利用することのないライブラリまでもが依存に含まれてしまうことが挙げられます。しかし、Spring Boot などを利用してアプリケーションを開発していて、Stackdriver Logging に適したログ出力をしたいということであれば、この方法は十分考慮に値する選択肢になることでしょう。
まとめ
Java アプリケーションから Stackdriver Logging にログを送信するには (1) REST API を直接呼び出す方法と (2) GKE の fluentd 経由でログ送る方法の 2 つがありましたが、ライブラリが抱えるハングアップ問題を避けるとなると必然的に後者 (2) の選択肢を選ぶことになります。
また GKE の fluentd 経由でログを送るには、アプリケーションが出力するログが所定のフィールドを有する JSON フォーマットでなければならないという条件がありますが、これに対処するには Logback や Log4j2 のレイアウトを自前実装する必要が出てきます。ただ Spring Cloud のプロジェクトで提供されているライブラリ spring-cloud-gcp-starter-logging を使うことで、レイアウトの自前実装や複雑な設定をせずとも適切な JSON フォーマットでのログ出力が実現できるので、Spring Boot ベースのアプリケーション開発をしている場合は同ライブラリの利用も積極的に検討してみるのがいいでしょう。