GrafanaスタックによるSpring Bootアプリケーション監視の詳細（その2 Grafana + Loki編）
第2回目はGrafana + Lokiです。Lokiと言えば、時間移動して悪さをしたせいでタイムパトロールに捕まるという 大長編ドラえもんの悪役みたいな スピンオフドラマシリーズがありましたが、皆さんご覧になったでしょうか。あ、ディズニープラス限定配信のドラマなんてほとんどの人が観ないか、そっか。なかなかの野心作で面白かったですよ。展開はイマイチでしたけど。
そんなわけで今回は、ローカル環境（+ Docker）でGrafanaとLokiを使ってログの可視化を行います。
https://github.com/cero-t/spring-store-2022
ログ収集の構造
ログ収集と可視化の構造は次のようになります。
ログをファイルに出力し、それをログ収集エージェントが読み取ってログストレージに送ると、いう流れがログ収集の構造としては一般的です。ログ収集エージェントは、ここではPromtailを選んでいますが、FluentdやFilebeat、Logstashなどがよく使われています。
ただコンテナ環境においては、ログを標準出力に出力すれば、それをログエージェントが読み取ってログストレージに転送するような仕組みが一般的であるため「ログファイル」というものをあまり考えなくなります。
ずっとコンテナ環境を使っているとむしろ「ログファイルなどという前時代的なものに縛られるとは人類はいつまで経っても愚かなものよ」などと高尚な神の視点で物事を考えるようになってしまいがちになり、ログをファイル出力したくなくなってきます。
そこで今回は（参考にしたGrzejszczakさんのサンプルがそうであったように）Loki4Jの loki-logback-appender を利用することにしました。
loki-logback-appenderは、ログを直接Lokiに転送するというものです。微妙に賛否ありそうな構造ですが、ひとまずは「Lokiにログを集めたい」という事が主目的なので、手段は簡易なものを選ぶことにしました。
ちなみにspring-store-2022では、k8s上ではPromtailを使うようにしているので、その辺りは別途ブログを書きます。
Lokiでログを収集する
それではLokiを使ってログを収集する手順を説明します。
1. Spring Bootアプリケーションからログを送る
まずはSpring BootアプリケーションからLokiにログを転送できるようにします。
Spring Bootアプリケーションにloki-logback-appenderを追加
Spring Bootアプリケーションのdependencyに loki-logback-appender を追加します。
<dependency> <groupId>com.github.loki4j</groupId> <artifactId>loki-logback-appender</artifactId> <scope>runtime</scope> </dependency>
ただし loki-logback-appender は spring-boot-dependencies に含まれていないため、バージョンを自分で指定する必要があります。spring-store-2022では親のpom.xmlで指定するようにしています。
<dependencyManagement> <dependencies> <dependency> <groupId>com.github.loki4j</groupId> <artifactId>loki-logback-appender</artifactId> <version>1.3.2</version> </dependency> </dependencies> </dependencyManagement>
logback.xmlを作る
続いて、このloki-logback-appenderを使うようLogbackの設定を書きます。
<?xml version="1.0" encoding="UTF-8"?> <configuration> <include resource="org/springframework/boot/logging/logback/base.xml" /> <springProperty scope="context" name="appName" source="spring.application.name"/> <appender name="LOKI" class="com.github.loki4j.logback.Loki4jAppender"> <http> <url>http://localhost:3100/loki/api/v1/push</url> </http> <format> <label> <pattern>app=${appName},host=${HOSTNAME},traceID=%X{traceId:-NONE},level=%level</pattern> </label> <message> <pattern>${FILE_LOG_PATTERN}</pattern> </message> <sortByTime>true</sortByTime> </format> </appender> <root level="INFO"> <appender-ref ref="LOKI"/> </root>
まず url に http://localhost:3100/loki/api/v1/push を指定して、送り先のLokiのアドレスを記載します。
またタグとして app host traceId level を追加しています。このタグを使ってLoki上で検索することができるようになります。
ちなみにこのファイルを logback-spring.xml という名前にしておけば無設定で読み込まれるのですが、なんとなくこれを標準にすることに抵抗があったため、logback-loki.xml という名前にしたうえで、application.properties でファイル名を指定ししました。
logging.pattern.level=%5p [${spring.application.name:},%X{traceId:-},%X{spanId:-}]
logging.config=classpath:logback-loki.xml
なんとなく、Appenderで送ることを標準として良いのかどうなのか、まだ悩んでるんですよね。まぁその辺りの悩みはブログの最後に書きます。
また logging.pattern.level でログレベルを出す箇所に、ログレベルの後ろにアプリケーション名、トレースID、スパンIDを出しています。タグがなく、ただログを見ただけでもトレースIDなどを確認できるようにするためです。
これでSpring Bootアプリケーション側の設定は完了です。
2. Lokiを構築する
続いて、Lokiの構築を行います。Lokiはdocker-composeを使って起動します。
docker-compose.ymlのうち、Lokiの起動に関する部分のみピックアップします。
services: loki: image: grafana/loki extra_hosts: ['host.docker.internal:host-gateway'] command: [ "-config.file=/etc/loki/local-config.yaml" ] ports: - "3100:3100" # loki needs to be exposed so it receives logs environment: - JAEGER_AGENT_HOST=tempo - JAEGER_ENDPOINT=http://tempo:14268/api/traces # send traces to Tempo - JAEGER_SAMPLER_TYPE=const - JAEGER_SAMPLER_PARAM=1
environment でLoki自身のトレース情報をJaeger（実体はTempo）に送るような設定が入っているのですが、これは別になくても構いません。元のサンプルに入っていたので、そのままにしています。
また ports で 3100 番ポートを外部公開していますが、アプリケーションからAppenderを使ってLokiにログを転送するという構造上、LokiのポートはDockerの外に公開する必要があるのです。
設定はこれくらいで、特に追加の設定ファイルなどは使わずにデフォルト設定で動かしています。
3. GrafanaからLokiにアクセス
最後に、GrafanaでLokiに収集したログを表示できるようにするために、GrafanaのデータソースにLokiを追加します。これはGrafanaの datasources.yml で設定します（Grafanaの設定画面からも追加できます）
datasources: - name: Loki type: loki uid: loki access: proxy orgId: 1 url: http://loki:3100 basicAuth: false isDefault: false version: 1 editable: false apiVersion: 1 jsonData: derivedFields: - datasourceUid: tempo matcherRegex: \[.+?,(.+?), name: TraceID url: $${__value.raw}
データソースとしてLokiを指定し、url にLokiのアドレスを指定します。
jsonData.derivedFields に少し設定が入っているのですが、これを設定することで、GrafanaでLokiのログに含まれるTraceIDを使ってTempo（トレース情報）のUIを開くことができるようになります。ログを正規表現の \[.+?,(.+?), でマッチングさせて TraceID を抽出し、その値を使ってTempoを開くという設定になっています。
以前のエントリー でLokiからTempoに移動できることを紹介した時の画像を再掲します。
これを実現するための設定になります（Tempoの詳細については次のブログエントリーで紹介します）
画像内に「Detected fields」という項目がありますが、ここにGrafana自身が自動検出したフィールドと、derivedFieldsで設定したフィールドが列挙され、ここに「TraceID」がされるという形です。
この処理はLoki側ではなくGrafana側で表示する際に行っているということになります。逆に言えば、ここで抽出されている「Detected fields」はLoki側ではindexingされていないので、高速に検索できるわけではないので注意が必要です。Elasticsearch + Kibanaも同じ感じでしたけど、最初は混乱するんですよね、このUI側でのフィールド認識。
どうあれこうやって手軽にログとトレースを行き来できるというのは、GrafanaがLokiとTempoに標準対応しているという強みですね。同じことをKibanaとZipkinで実現している人もいるのですが、ナカナカにやりこみが必要です。
4. GrafanaでLokiのログを見る
ここまでの設定をすべて終えたあと、アプリケーションとGrafanaスタックを起動してGrafanaにアクセスします。
ExploreでLokiを選択し、Label filtersで絞り込み条件（たとえば app = bff）を指定すると、条件に合致したログが表示されます。
Lokiは起動に少し時間が掛かったり、アプリケーションからLokiにログを送るまでタイムラグがあるため、操作してから1〜2分くらい待たないとログが表示されないとか、Label filtersの絞り項目が表示されないことがあり、その時は少し待ってから改めて行うと良いでしょう。
ちなみにLokiはElasticsearchのようにログを単語分割したり、全項目にindexを張ったりしていないので、大量のログに対して文字列一致させるような検索はあまり早くありません。そのため、実運用で利用する際にはあるていど時間帯や対象を限定して検索することになると思いますが、問題発生時にその時間帯のログを確認したいなどという用途においてはあまり困らないと思います。
まとめ
- Javaアプリケーションに loki-logback-appender と設定ファイルを追加すればLokiにログを送れる
- GrafanaとLokiはdockerで簡単に利用できる
- Grafana上でLokiのログからTempoのトレースにジャンプするような設定ができる（Tempoの詳細は次回）
- Elasticsearchほど高機能じゃないけど軽くて手軽だよ
ところで。
ログをLokiに送る方法として、Prometailのようなエージェントを使うのが良いのか、Appenderで直接転送するのが良いのか、というのはわりと悩ましい問題です。
信頼性という意味ではログエージェントに収集させた方が確実だと思いますし、ログエージェントならログのパースや加工などのパイプライン処理ができるため、よりログを扱いやすい形に加工してLokiに送ることもできます。
一方で、Zipkinなどのトレース情報はアプリケーションから直接送るのが普通ですし、ログだって同じような形で送っても悪くないように思います。
ログについては「絶対に抜けてはいけない。信頼性が重要だ」という意見もあり、そのために信頼性の高いログエージェントに任せるべきだという意見もあるとは思いますが、実際には本当に重要な情報と、さほど重要でない情報が雑多に混ざった状態です。真に重要な情報はログではなくRDBMSなどに書くよう丁寧に設計して管理し、ログはもっと「あると嬉しい」情報に倒した方が楽だと思っています。
そんなわけでなかなかどっちが良いか決めきれないログの出力方式なのですが、いったんブログを一通り書いたあとで、改めてログ収集のあるべき形について考えたいなと思います。
