Closed46

Spring Boot Actuator と Grafana Stack が連携できるように設定する

kazokmrkazokmr

これは何?

監視とかObservabilityのことが気になっていたので、Spring Boot Actuator + Grafana Stack を自分のローカルで動かして試してみる

試してみたいこと

  1. Spring Boot アプリで Actuator を使えるようにする
  2. Prometheus で アプリのメトリクスを収集する
  3. Loki + Promtail で アプリのログを収集する
  4. Tempo で アプリのトレースを収集する
  5. Grafana で可視化する
  6. 設定を変えて結果を確認してみる
  7. DBやRedisのメトリクスやトレースなども収集してみる

対象アプリはlocalのDockerコンテナで動かす

  • Spring Boot 3.0.5
  • Java 19
  • PostgreSQL
  • Redis

Grafana Stack と Prometheus も local のDockerコンテナで動かす

ソースコード

キリのいい所で mainブランチにマージを行っている最中

https://github.com/kazokmr/book-manager

kazokmrkazokmr

Spring Boot アプリで spring-boot-actuator を利用できるようにする

Spring Boot Actuator の Reference に従って、spring-boot-actuator を依存関係に追加した

build.gradle.kts
...
dependencies {
    implementation("org.springframework.boot:spring-boot-starter-actuator")
}
...

ローカルで起動して、 ブラウザから http://localhost:8080/autuator/health にアクセスしたところ 401エラーが出た。

そこでSpring Security の authorizeHttpRequests で アクセスを許可した

SecurityConfig.kt
@Configuration
@EnableWebSecurity
class SecurityConfig {
    @Bean
    fun securityFilterChain(http: HttpSecurity): SecurityFilterChain {

        http.authorizeHttpRequests {
            it.requestMatchers("/csrf_token", "/actuator/**").permitAll()
            it.requestMatchers("/admin/**").hasAuthority(RoleType.ADMIN.toString())
            it.anyRequest().authenticated()
       }
       ....
}

再起動して http://localhost:8080/autuator/health にアクセスしたら {"status":"UP"} が返ってきた。

実際の本番環境なら /actuator はアクセスするエージェントやクライアント のIPだけを制限する使い方がいいのだろうな

kazokmrkazokmr

ReferenceのSecurity セクションを読んだら、Actuatorが提供する EndpointRequest.toAnyEndpoint() を使ってActuatorのエンドポイントへのアクセスを制御するのが良さそう。
今回は専用のロールは使わないので、以下のように変えてみた

  http.authorizeHttpRequests {
            it.requestMatchers("/csrf_token").permitAll()
            it.requestMatchers("/admin/**").hasAuthority(RoleType.ADMIN.toString())
            it.requestMatchers(EndpointRequest.toAnyEndpoint()).permitAll()
            it.anyRequest().authenticated()
kazokmrkazokmr

management.endpoint.health.show-details の 値を always にして /actuator/health にアクセスすると、接続しているdbやredis のstatus も確認できるんだね

{
    "status": "UP",
    "components": {
        "db": {
            "status": "UP",
            "details": {
                "database": "PostgreSQL",
                "validationQuery": "isValid()"
            }
        },
        "diskSpace": {
            "status": "UP",
            "details": {
                "total": 494384795648,
                "free": 351801266176,
                "threshold": 10485760,
                "path": "/Users/kazokmr/IdeaProjects/book-manager/.",
                "exists": true
            }
        },
        "grpc": {
            "status": "UP",
            "components": {
                "com.book.manager.greeter.Greeter": {
                    "status": "UP"
                }
            }
        },
        "ping": {
            "status": "UP"
        },
        "redis": {
            "status": "UP",
            "details": {
                "version": "7.0.2"
            }
        }
    }
}
kazokmrkazokmr

ActuatorのHTTP設定 も変更できる。

以後は、actuator へのアクセスだけ、ポート番号を8081にしてアプリケーションと分けておく。

management:
  server:
    port: 8081
kazokmrkazokmr

メトリクスを収集できるようにする

次にSpring Boot アプリケーションのMetrics を Prometheus で集計するため、アプリケーションの専用のエンドポイントを公開する。
Spring Boot Actuator には Prometheus には専用のEndpointが用意されているのでそれを公開する。

management:
  endpoints:
    web:
      exposure:
        include:
          - health
          - prometheus

これで、 http://localhost:8081/actuator/prometheus にアクセスできるようになるが、これだけではメトリクスとして何も出力されない。
Spring Boot Actuatorでは Micrometerを利用してアプリのメトリクスを収集するので出力先のモニタリングサービスに対応したregistryを登録する。

https://docs.spring.io/spring-boot/docs/current/reference/html/actuator.html#actuator.metrics

つまり Prometheus用の micrometer-registry-prometheus を依存関係に追加すれば良い

dependencies {
    runtimeOnly("io.micrometer:micrometer-registry-prometheus")
}

https://micrometer.io/docs/registry/prometheus

アプリケーションを再起動し http://localhost:8081/actuator/prometheus にアクセスすると メトリクスが返ってきた

# HELP application_ready_time_seconds Time taken (ms) for the application to be ready to service requests
# TYPE application_ready_time_seconds gauge
application_ready_time_seconds{main_application_class="com.book.manager.BookManagerApplicationKt",} 2.416
# HELP jvm_gc_max_data_size_bytes Max size of long-lived heap memory pool
# TYPE jvm_gc_max_data_size_bytes gauge
jvm_gc_max_data_size_bytes 8.589934592E9
# HELP jvm_classes_unloaded_classes_total The total number of classes unloaded since the Java virtual machine has started execution
# TYPE jvm_classes_unloaded_classes_total counter
jvm_classes_unloaded_classes_total 0.0
# HELP jvm_memory_usage_after_gc_percent The percentage of long-lived heap pool used after the last GC event, in the range [0..1]
# TYPE jvm_memory_usage_after_gc_percent gauge
jvm_memory_usage_after_gc_percent{area="heap",pool="long-lived",} 0.005299091339111328
# HELP tomcat_sessions_created_sessions_total  
# TYPE tomcat_sessions_created_sessions_total counter
tomcat_sessions_created_sessions_total 0.0
# HELP jvm_buffer_total_capacity_bytes An estimate of the total capacity of the buffers in this pool
# TYPE jvm_buffer_total_capacity_bytes gauge
jvm_buffer_total_capacity_bytes{id="mapped - 'non-volatile memory'",} 0.0
jvm_buffer_total_capacity_bytes{id="mapped",} 0.0
jvm_buffer_total_capacity_bytes{id="direct",} 16384.0
kazokmrkazokmr

スクラップの後半で改めて書く予定だけど備忘録

Session情報として使っているRedisのクライアントLettuceが出力する メトリクス lettuce.command.firstrespoince.*lettuce.command.completion.* を Prometheusで取得するために、元の RedisConnectionFactory Beanに MeterRegistryを次のように設定を変更した

HttpSessionConfig.kt
    @Bean
    fun redisConnectionFactory(meterRegistry: MeterRegistry): LettuceConnectionFactory {
        val configuration = RedisStandaloneConfiguration(redisHostName, redisPort)
        val clientResources: ClientResources = ClientResources.builder()
            .commandLatencyRecorder(MicrometerCommandLatencyRecorder(meterRegistry, MicrometerOptions.create()))
            .build()
        val lettuceClientConfiguration: LettuceClientConfiguration = LettuceClientConfiguration.builder()
            .clientResources(clientResources)
            .build()
        return LettuceConnectionFactory(configuration, lettuceClientConfiguration)
    }
kazokmrkazokmr

Prometheus を立ち上げる

PrometheusをローカルのDockerで起動してSpring-boot-actuator からメトリクスを取得する。

先にPrometheusの設定ファイルを用意する。以下が最小限の設定の模様

prometheus.uml
global:
  # 15secごとにメトリクスを取得しにいく
  scrape_interval: 15s
scrape_configs:
  - job_name: "spring-actuator"
    metrics_path: "/actuator/prometheus"
    static_configs:
      - targets: [ 'host.docker.internal:8081' ]

scrape_configs で、収集元を定義する。
static_configs には収集元サーバーのホストを定義する。上記は localで起動しているspring-bootアプリにdockerコンテナ上のPrometheusからアクセスするので、コンテナからホストにアクセスする際の host.docker.internal でホストを指定している。

metrics_path には メトリクスを収集するパスを指定するので、actuatorが公開している /actuator/prometheus を指定している。

作成した設定ファイルはPrometheusのDockerコンテナをビルドするときにマウントする。

compose.yml
services:
  prometheus:
    image: prom/prometheus
    ports:
      - "9090:9090"
    volumes:
      - "./config/prometheus.yml:/etc/prometheus/prometheus.yml"

prometheusコンテナを起動したらブラウザで http://localhost:9090 にアクセスするとPrometheusの画面が表示される。
アプリを立ち上げた後、PrometheusのStatus > Targets を表示すると、アプリのエンドポイントにアクセスできていることがわかる

targets

Graphメニューから、任意のメトリクスを指定して Executeすることでメトリクスが表示される

process_cpu_usage

kazokmrkazokmr

Grafanaを立ち上げてメトリクスを可視化する

DockerコンテナでGrafanaを起動する

compose.yml に次のように追加した。データ永続化のためにVolumeも定義している

compose.yml
services:
  prometheus:
    image: prom/prometheus
    container_name: prometheus
    ports:
      - "9090:9090"
    volumes:
      - ./config/prometheus.yml:/etc/prometheus/prometheus.yml
  grafana:
    image: grafana/grafana
    container_name: grafana
    ports:
      - "3000:3000"
    volumes:
      - grafana-storage:/var/lib/grafana
volumes:
  grafana-storage:

Grafanaにログインする

ブラウザから http://localhost:3000 にアクセスすると、Grafanaのログイン画面が表示されるので、user/pass 共に admin を入力する。(その後、パスワードの変更が求められるがSkipも可能)

Data Source に Prometheus を追加する

ログインしたら左側のメニューから Configuration > Data Sources を選択し"Add new data source" をクリックする。 data source type の選択画面で ”Prometheus” を選択し、設定画面に入る

設定画面ではDefault値から以下を追加・変更し、"Save & test" した。

  • HTTP
    • URL : http://prometheus:9090 PrometheusのURL。今回はDocker Compose内のコンテナにあるので、service名をホストで指定している
  • Type and version
    • Prometheus type: Prometheus
    • Prometheus version: > 2.40.x

Grafana でメトリクスを可視化する

Exploreで選択したメトリクスを出力したり、Dashboadを用意したり、Aleartを設定したりする。
Grafana自体の使い方はまた今度調べる

kazokmrkazokmr

トレースデータを収集・管理・集計する

次にアプリからトレースデータを収集してGrafanaで可視化できるようにする

アプリ側のトレーシング設定

Sprinng-boot-actuate の Reference を元に 次の2つの依存関係を追加した

build.gradle.kts
dependencies {
    runtimeOnly("io.micrometer:micrometer-tracing-bridge-otel")
    runtimeOnly("io.opentelemetry:opentelemetry-exporter-zipkin")
}

次に 全てのリクエストに対してトレースを送信するように設定を変更した。(Defaultはリクエストの10%のトレースだけを送信する模様)

application.yml
management:
  ...
  tracing:
    sampling:
      probability: 1.0

アプリを起動しクライアントから何かしらのリクエストを行ったところ、アプリ側のコンソールに Caused by: java.net.ConnectException: Failed to connect to localhost/[0:0:0:0:0:0:0:1]:9411 エラーが出力されるようになった。

エラーの原因

アプリから localhost:9411 にアクセスしようとして繋がらなかったことが原因。
Zipkinは トレースデータを管理・集計するツールで localhost:9411 はZipkinへのデフォルトURLとなっていて、そこにアクセスしようとしていたがZipkinをインストールしていないためエラーになったと推測する。

今回はZpikinの代わりにZipkinのAPIと互換性があるTempoを立ち上げトレースデータを収集分析できれば良い。

補足:追加した依存関係について

今回のことから、追加した2つの依存関係のそれぞれの役割は次のとおりと考えている。

  • io.micrometer:micrometer-tracing-bridge-otel
    • micrometer-tracing で生成したアプリのトレースデータをOpenTelemetryで収集する?
  • io.opentelemetry:opentelemetry-exporter-zipkin
    • OpenTelemetry に収集されたトレースデータを Zipkinに転送し保存・可視化する?

※OpenTelemetry と Micrometer-tracing のことがまだよくわかっていないのでうまく言語化できていないけど、こんなイメージだと思う。

kazokmrkazokmr

動作は未確認だけど、アプリケーションの全てのテレメトリーデータは、 Grafana Agent に集めて、Grafana Stack あるいは Grafana Cloud と連携した方が良さそうな気がしてきたので最後に調査して変えてみる。

ちなみに アプリケーション側のTraceデータ送信先もZipkinサーバからGrafana Agentに変える必要用があるが、それは以下のようにすれば良さそう

  • Grafana Agent コンテナを 起動する。
    • ポート番号などを設定して、アプリケーションからアクセスできるようにする
    • 例えば、service名を agent 、 公開ポート番号を 4317 にする
    • agent の tracing 設定で、receiverに Zipkin を指定すれば、Zipkin API互換で集計できそう
  • アプリケーション側のZipkin Exporterのパスを上記のGrafana Agent に変える
    • mangement.ziipkin.tracing.endpoint のURLを 例えば http://agent:4317 にする
  • 参考資料
kazokmrkazokmr

io.micrometer:micrometer-tracing-bridge-otel の最新版 v1.0.3 で、メトリクスデータに exemplar が付与されず トレースIDが取得できない不具合があるので、OpenTelemetryではなく OpenZipkin Brave を利用してトレースデータを取得するように変更した。

build.gradle.kts
//    runtimeOnly("io.micrometer:micrometer-tracing-bridge-otel")
//    runtimeOnly("io.opentelemetry:opentelemetry-exporter-zipkin")
runtimeOnly("io.micrometer:micrometer-tracing-bridge-brave")
runtimeOnly("io.zipkin.reporter2:zipkin-reporter-brave")

https://github.com/micrometer-metrics/tracing/issues/207

exemplar については後述するがメトリクスにトレースIDなどのサンプルデータを付けることにより、Grafanaで メトリクスとトレースの関連付けを行うことができるようになる。

なお、上記の不具合は 1.0.4で改善する見込み。

kazokmrkazokmr

現時点では以下の認識

  • Spring Boot Actuator の Tracingは Micrometerを利用している
  • Micrometerでは TraceID や SpanID を初めとしたコンテキストを生成し、トレーシングの計装やコンテキストの伝播を行う
  • 他にTraceIDやSpanIDをログに出力しやすくするための MDCへのPut/Remove 管理も行なってくれてい模様
    • ここまでが org.springframework.boot:spring-boot-starter-actuator でできること
  • Micrometer によるトレーシングの計装や伝播は OpenTelemetry形式 あるいは OpenZipkin Brave 形式 で行うことができる
    • io.micrometer:micrometer-tracing-bridge-otel または io.micrometer:micrometer-tracing-bridge-brave を利用することで実現される
  • 変換した TraceデータをZipkinなどのTraceシステムにエクスポートする
    • これが io.opentelemetry:opentelemetry-exporter-zipkin などのエクスポーターの役割

https://micrometer.io/docs/tracing
https://opentelemetry.io/docs/concepts/signals/traces/

トレーシングにおける Micrometer (Spring boot Actuator) と OpenTelemetry の関係について、こちらの資料に書かれていた 「(Micrometerは) SLF4Jみたいなオブザバビリティ版」という説明で イメージしやすくなった。
Micrometer が Facade、OpenTelemetryが 実装(計装) ってイメージ

https://docs.google.com/presentation/d/18awKAmhkylwvVcBXqvyDZRs_EeQrXlusg34ZebD-gs0/edit#slide=id.g26071e892d4_0_120

kazokmrkazokmr

Tempo を起動してGrafanaでトレースデータを可視化する

Docker Compose に Tempoの設定を追加する

公式の exampleコード を参考に定義した

compose.yml
services:
  tempo:
    image: grafana/tempo
    container_name: tempo
    command: [ "-config.file=/etc/tempo.yml" ]
    volumes:
      - ./config/tempo.yml:/etc/tempo.yml
      - tempo-data:/tmp/tempo
    ports:
      - "3200:3200"   # tempo
      - "9411:9411"   # zipkin
volumes:
  tempo-data:

config.fileについては後述する
トレースデータの保存先を永続化する
ポート番号については、tempo自身の3200 に加えて、アプリケーションからZipkin互換のAPIを受信する 9411を公開している。

Config file を作成する

前述のサンプルコードと 公式ページと の設定内容を参考に作成した

tempo.yml
server:
  http_listen_port: 3200  # tempoサーバーの公開ポート

distributor:
  receivers:
    zipkin:   # トレースのレシーバーとしてZipkin互換のAPIを利用するための設定

storage:
  trace:
    backend: local  # tempoのデータストレージはサーバーローカルとする
    local:
      path: /tmp/tempo/blocks  # ローカルストレージの保存先

上記でDockerコンテナを起動するとTempoコンテナがアプリのトレースデータを受信するので、アプリケーション側のコネクションエラーが出力されなくなる

Grafana で可視化する

メトリクス(Prometheus)と同じように DatasourceからTempoを選択して必要な情報を設定していく

設定内容の詳細は 公式ページ を参照。
今回は設定した箇所だけ抜粋

  • HTTP
  • Service Graph
    • Data source: Prometheus
  • Node Graph
    • Enable Node Graph: ON (enabled)

まずはこれだけだが、logデータとの連携設定があるので 後でLokiを導入したときに改めての設定が必要になると思われる

Traceデータが可視化されることを確認する

Exploreから DataSourceに Tempoを選択すると、アプリから収集したトレースデータがIDごとに検出される。トレースIDをクリックすると 「Trace View」に詳細が表示される

Data Source設定で Node Graphを有効にしているとこのようなGraph構造でも確認できる

細かい使い方などは調査する必要はあるが、アプリのトレースデータも収集・管理ができるようになった

kazokmrkazokmr

ログの収集準備

ログの収集については悩ましいことが2つ発生した

  1. ログにアプリのサービス名やトレースIDを付ける方法が、log4j2とlogback で若干異なっていた
  2. コンソールに出力したログを収集したかったが設定方法が分からなかったので、ログファイルを出力して収集する方法にする

ログにアプリ名やトレースIDをつける

1 については Spring actuator の 公式リファレンス に以下のように記載があったので application.yml に設定したのだが、アプリケーション名もtraceId/spanId どれも出力されなかった

You can include the current trace and span id in the logs by setting the logging.pattern.level property to %5p [${spring.application.name:},%X{traceId:-},%X{spanId:-}]

原因は次の2つで、いずれもログ出力に log4j2 を利用していたためだった

  1. logging.pattern.level プロパティは、logback専用のため log4j2 を使っていると読み取らない
  • logging.pattern.level
  • log4j2 の場合は ログ出力設定ファイル log4j2-spring.xmlPatternLayout で定義する
  1. 変数として定義していた ${spring.application.name:} %X{traceId:-} %X{spanId:-} がどれも log4j2 では認識されない記法だった
  • このため以下のように定義した
    • ${spring.application.name:} -> ${spring:spring.application.name}
      • springのプロパティを参照したいときは、${spring:<propertyKey>} とする。SpringLookup
    • %X{traceId:-} -> %X{traceId}
    • %X{spanId:-} -> %X{spanId}
      • log4j2のMDC変数を参照する時に logbackのような :-<defaultValue> 指定はできない

と言うわけで log4j2のPatternLayout設定は次のようにしている

application.yml
logging:
  level:
    root: info
  pattern:
    console: "%d{yyyy-MM-dd HH:mm:ss.SSS} %highlight{%-5level}[${spring.application.name:},%X{traceId},%X{spanId}] [%style{%t}{bright,blue}] %style{%C}{bright,yellow}: %m%n"
log4j2-spring.xml
<?xml version="1.0" encoding="UTF-8"?>
<configuration>
    <Appenders>
        <Console name="Console" target="SYSTEM_OUT">
            <PatternLayout pattern="${spring:logging.pattern.console}"/>-->
        </Console>
    </Appenders>
    <Loggers>
        <Root level="${spring:logging.level.root}">
            <AppenderRef ref="Console"/>
        </Root>
    </Loggers>
</configuration>

ログの出力先をどうするか

2つ目の出力先については、背景として以下のようなことを考えた結果、アプリからログファイルを出力し、Promtailで収集しLokiに転送することにした

  • promtail で ログファイルではなくコンソールからログを取得する方法が公式を探しても見つからなかった
  • 先々は Grafana Agentを使うつもりだが、基本的な設定は promtailと同じになる
  • 実際の運用を考えた場合、本番のデプロイ先環境によってログの出力方法も変わるはず(AWS、k8s、コンテナなどなど
  • Appenderでアプリから直接ログをlokiに転送する方法もあるが、今回はAgentを使った収集と転送を試したかった
  • 今回の目的はログを収集してGrafanaで可視化とObservabilityを体験することだったので、ログの出力先がファイルでもコンソールでも変わらないから
kazokmrkazokmr

Systemプロパティを参照する場合は、プロパティの前に sys: を指定する必要があるとか、
Springプロパティを参照したい場合は、設定ファイルの名称を log4j2-spring.xml にしないと参照してくれないとか。
他の人のブログやサンプルコードはlogbackが多いので、この辺りのことを理解するのに少し時間がかかった

kazokmrkazokmr

MDCのことを正しく理解していなかったので補足
MDC (Mapped Diagnostic Context) によって、アプリケーションの任意の情報を専用のMapに格納することができる。そしてロガーではMapのKeyを指定することでその任意の情報をログに出力することができる。
MDCは ThreadLocal上に保持されるので Webアプリにおける 一つのリクエストに対するスレッド上でMDCに格納した情報を共有することができるので、MDCにTraceIDやSpanIDをPutすることでログへトレーシングのコンテキスト情報を出力することを容易にすることができる。

MDCのPutとRemoveは一般的に Servlet Filter の先頭で行い、リクエスト受付時にPutし レスポンス返却時にRemoveするFilterを明示的に用意する必要があるが、Spring Boot Actuator を利用してトレーシングを有効にしていると MDCへの TraceIDとSpanID のPutとRemoveをいい感じに行ってくれているようなので、LogbackやLog4J2などのロギングの設定側で MDCから情報を取得する定義を追加すれば良い。

https://logback.qos.ch/manual/mdc.html
https://www.slf4j.org/api/org/slf4j/MDC.html
https://logging.apache.org/log4j/2.x/manual/thread-context.html
https://www.baeldung.com/mdc-in-log4j-2-logback

kazokmrkazokmr

ログファイルの仕様

下記の通りに設定することで、log4j2で意図通りの出力ができたのでこれで進める。

主な方針としては以下の通り

  • ロギングライブラリは log4j2を使うが、設定値はできる限り application.yml に書いて log4j2固有の設定は使わないようにする
    • 今回だとRollingFileのパターンのみプロパティが無いのでlog4j2の設定に直接書いている
  • consoleとfile で同じ出力フォーマットにする。ただしファイル出力の方はスタイリングしない
  • Dateフォーマットは RFC3339 に準拠させておく
    • 理由は Lokiのtimestamp が ISO8601 に対応していないので正しく読み取れない可能性があったため - Loki(Promtail) の timestamp
    • log4j2 には RFC3330と互換性のある %d{ISO8601_OFFSET_DATE_TIME_HHCMM} でフォーマット指定が行えるが、logback でも対応できるようにフォーマットを定義した。
    • ちなみに logbackのデフォルトフォーマットは ISO8601 yyyy-MM-dd'T'HH:mm:ss.SSSZZ でタイムゾーンの時刻表記にコロンがつかないパターンなので、 XXX でコロンが付くパターンとしている。
application.yml
logging:
  level:
    root: info
  pattern:
    console: "%d{${logging.pattern.dateformat}} %highlight{${logging.pattern.level}} [%style{%t}{bright,blue}] %style{%C}{bright,yellow}: %m%n"
    file: "%d{${logging.pattern.dateformat}} ${logging.pattern.level} [%t] %C: %m%n"
    level: "%5p [${spring.application.name:},%X{traceId:-},%X{spanId:-}]"
    dateformat: yyyy-MM-dd'T'HH:mm:ss.SSSXXX
  file:
    path: ./logs
    name: app.log
log4j2-spring.xml
<?xml version="1.0" encoding="UTF-8"?>
<configuration>
    <Appenders>
        <Console name="Console" target="SYSTEM_OUT">
            <PatternLayout>
                <pattern>${sys:CONSOLE_LOG_PATTERN}</pattern>
            </PatternLayout>
        </Console>
        <RollingFile name="RollingFile"
                     fileName="${sys:LOG_PATH}/${sys:LOG_FILE}"
                     filePattern="${sys:LOG_PATH}/$${date:yyyy-MM}/${sys:LOG_FILE}-%d{yyyy-MM-dd}-%i.gz">
            <PatternLayout>
                <pattern>${sys:FILE_LOG_PATTERN}</pattern>
            </PatternLayout>
            <Policies>
                <SizeBasedTriggeringPolicy size="10 MB"/>
                <TimeBasedTriggeringPolicy/>
            </Policies>
        </RollingFile>
    </Appenders>
    <Loggers>
        <Root level="${spring:logging.level.root}">
            <AppenderRef ref="Console"/>
            <AppenderRef ref="RollingFile"/>
        </Root>
    </Loggers>
</configuration>
kazokmrkazokmr

Loki を起動する

PromtailなどのAgentの転送先になるLokiを先にDockerコンテナで構築する

grafana-stack/compose.yml
services:
  loki:
    image: grafana/loki
    container_name: loki
    command: [ "-config.file=/etc/config/loki-config.yml" ]
    environment:
      TZ: Asia/Tokyo
    volumes:
      - ./config/loki-config.yml:/etc/config/loki-config.yml
    networks:
      - datasource
    ports:
      - "3100:3100"
  grafana:
    image: grafana/grafana
    container_name: grafana
    environment:
      TZ: Asia/Tokyo
    volumes:
      - grafana-storage:/var/lib/grafana
    networks:
      - grafana
      - datasource
    ports:
      - "3000:3000"
volumes:
  grafana-storage:
  tempo-data:
networks:
  # Grafanaのネットワーク
  grafana:
    driver: bridge
    internal: false
    name: grafana_network
  # GrafanaのDataSources(Prometheus, Tempo, Loki)のネットワーク。SpringBootActuator と GrafanaAgentからアクセスするために公開
  datasource:
    driver: bridge
    internal: false
    name: datasources_network

LokiのConfigファイルの設定

loki-config.yml
auth_enabled: false

server:
  http_listen_port: 3100
  grpc_listen_port: 9096

common:
  instance_addr: 127.0.0.1
  path_prefix: /tmp/loki
  storage:
    filesystem:
      chunks_directory: /tmp/loki/chunks
      rules_directory: /tmp/loki/rules
  replication_factor: 1
  ring:
    kvstore:
      store: inmemory

query_range:
  results_cache:
    cache:
      embedded_cache:
        enabled: true
        max_size_mb: 100

schema_config:
  configs:
    - from: 2020-10-24
      store: boltdb-shipper
      object_store: filesystem
      schema: v11
      index:
        prefix: index_
        period: 24h

ruler:
  alertmanager_url: http://localhost:9093

上記の設定はGithubの公式リポジトリの ファイル を参照しただけなので内容は理解できていないので後で 確認 したいとは思っている

AgentからLokiにアクセスするためのネットワークを設定

Promtailアプリ側のサイドカーとして構築するため、LokiにアクセスできるようにするためNetworkを明示しアプリ側のDocker Composeのコンテナから参照する。
アプリ側は PrometheusやTempoとも接続するし、後で Grafana Agentを使う際にもこのネットワーク定義が必要になる

kazokmrkazokmr

Promtailを立ち上げて アプリのログを収集しLokiに転送する

PromtailのDockerコンテナは前述の通りアプリ側のDocker Composeに定義した
ちなみにPostgreSQLとRedisはさらに別のDocker Composeで定義しNetworkを共有している

backend/compose.yml
services:
  backend:
    build:
      context: ../../
      dockerfile: ./docker/backend/app/Dockerfile
    container_name: backend
    hostname: backend.app
    environment:
      TZ: Asia/Tokyo
    volumes:
      - app-logs:/app/logs
    networks:
      - app
      - db_external
      - redis_external
      - datasources_external  # otel-exporter-zipkin で Tempoにアクセスするため
    ports:
      - "8080:8080"
      - "8081:8081"
  promtail:
    image: grafana/promtail
    container_name: promtail
    command: [ "-config.file=/etc/promtail.yml" ]
    environment:
      TZ: Asia/Tokyo
    volumes:
      - ./config/promtail.yml:/etc/promtail.yml
      - app-logs:/var/logs
    networks:
      - agent
      - app
      - datasources_external
    ports:
      - "9080:9080"
volumes:
  app-logs:
    driver: local
networks:
  # アプリのネットワーク。ホストから http:localhost:8080 にアクセスするため公開
  app:
    driver: bridge
    internal: false
    name: app_network
  # DBとRedisのネットワーク
  db_external:
    external: true
    name: db_network
  redis_external:
    external: true
    name: redis_network
  # Grafana Agent のネットワーク
  agent:
    driver: bridge
    internal: true
    name: agent_network
  # GrafanaのDataSourceネットワークに接続定義
  datasources_external:
    external: true
    name: datasources_network

Promtailからアプリのログを参照できるようにする

appコンテナの /app/logs/app.log ファイルからログを収集する必要があるため、Promtailコンテナとこのディレクトリを共有化した。

具体的には Volume に app-ligs という共有Volumeを用意して、appコンテナ側からは /app/logs、promtailコンテナ側からは /var/logs にマウントする形で ログファイルを参照できるようにしている

Promtailの設定ファイル

下記の設定は、アプリのログファイルを収集してLokiに転送しているだけ。実際には集計用にログの特定項目にlabel付けするなどの設定が必要になるが、それは後でやる。

promtail.yml
server:
  http_listen_port: 9080
  grpc_listen_port: 0

positions:
  filename: /tmp/positions.yml

clients:
  - url: http://loki:3100/loki/api/v1/push

scrape_configs:
  - job_name: app
    pipeline_stages:
    static_configs:
      - targets:
          - localhost
        labels:
          job: app
          host: app
          __path__: /var/logs/*.log

設定内容の概要

  • server.http_listen_port: ブラウザから http://localhost:{ポート番号} で Promtailのコンソールを表示し状態を確認することができる
  • positions.filename: Promtailがログファイルをどこまで収集したかを記録しておくファイルのパスを指定する
  • clients.url: Lokiの転送先URLを定義する
  • scrape_configs: 収集するログファイルのスクレイプ設定を定義する
    • 現時点では アプリケーションログ全体のlabelとして、job=apphost=app を設定している
    • Lokiでこのjobラベルまたはhostラベルを使って、特定のアプリケーションログだけを抽出できる
      • 例えばappコンテナをクラスタ化している場合は、全てのappコンテナ に job=app をつけ コンテナごとに host=app1 とか host=app2 とラベル付けを行うことで、jobラベルで全appサービスのログを集計したり、hostラベルで特定のappコンテナだけに絞ってログを抽出したりできる
    • __path__ には promtailコンテナ内からアクセスできるアプリケーションログの場所を指定する。ここで先ほどの compose.yml で定義した Volumeによるディレクトリ共有が活きてくる。

Promtailの動作確認

あとは全てのDockerコンテナを起動したあと http://localhost:9080 にアクセスすると、Promtailが正常にログファイルを取得していると次のような画面になる

kazokmrkazokmr

Grafanaでログを可視化する

メトリクスとトレースの時と同様、DatasourceからLokiを選択して接続設定を行う。
とりあえずは HTTP.URL に LokiのURLを設定するだけで Lokiに格納されたログデータを可視化してみた。

Datasourceに追加したあと、Exploreから次のようにログを確認することができる

このあとは

これで アプリケーションの メトリクス・トレース・ログ を収集してGrafanaで可視化できるようになった。
ただこれだけでは、テレメトリーデータをGrafanaにまとめているだけなので、Observability が確保されてると言える状態ではないので、取得したテレメトリーデータの活用を考えてみることにする

kazokmrkazokmr

ログメッセージにラベルを付ける

ここまではログファイル全体に対する jobhost の2つのラベルを用意した。今回はログファイルの個々のメッセージを分解しラベル付けを行う。具体的には、メッセージから level , app , trace_id , span_id の4つのラベルを用意しメッセージから値を抽出する。

ラベル付けは Promtailの pipeline_stages で行う。 パイプライン では、 ステージ と呼ばれるログメッセージに対する処理を順番に行うことで、ログメッセージから情報を抽出したり形式を変えるなどして 目的に応じたデータ収集・分析を行いやすくする。

今回は regex ステージで 正規表現を使ってメッセージを特定の情報ごとに分類し、 そこからラベル付けしたい情報を labels ステージで指定している。

promtai.yml
scrape_configs:
  - job_name: app
    pipeline_stages:
      - regex:
          expression: "^(?P<timestamp>\\d{4}-\\d{2}-\\d{2}T\\d{2}:\\d{2}:\\d{2}.\\d{3}\\+\\d{2}:\\d{2})\\s+(?P<level>\\w+)\\s+\\[(?P<app>[\\w-]+),(?P<trace_id>[\\w-]*),(?P<span_id>[\\w-]*)\\]\\s+\\[(?P<thread>[\\w-]+)\\]\\s+(?P<classname>[\\w.-]*):\\s+(?P<message>.*)$"
      - labels:
          level:
          app:
          trace_id:
          span_id:
  • regexステージの正規表現は Googleの RE2 を利用して、正規表現で抽出した各項目に (?P<name>re) でパラメータを付与することができる。
    • 正規表現の書き方に何度も失敗して Promtail でエラーになった。
    • promtail.yml の server.log_level パラメータを DEBUG にすることで正規表現が間違っていることを確認しながらトライアンドエラーで進めた
    • loki4j の Appenderでログを転送している場合は、ラベルとその値をアプリの変数で指定するだけなので、ラベル付けの点では間違いなくAppenderの方が楽だと感じた
  • labelsステージでラベル付けしたいパラメータを指定する
    • name: alias とすることで、パラメータとは別の名称でラベル付けもできる
    • ラベルは Lokiでインデックスとして使われるので、Lokiで分析・検索に使うパラメータだけに限定して、ラベルを用意した方が、検索パフォーマンスも良い
  • ラベル付けができると、Lokiの検索画面でラベルとその値でログの絞り込みが行えるようになる。

この設定でログメッセージの trace_idspan_id が抽出できるようになり、この値でトレースデータとの関連付けができるようになる

kazokmrkazokmr

クラスやメソッド単位にSpanIDを付与してトレースする

これまでは、HTTPリクエストやgRPCでの通信単位に Spanデータを取得してトレーシングを行った。ここでは更にメソッドの処理ごとにSpanデータを取れるようにして より問題を特定しやすくしてみる。

具体的には、Micrometerが @Observed で AOPで観測対象が管理できる Observation API を提供しておりこれを活用する。

https://www.baeldung.com/spring-boot-3-observability#3-aop

依存関係を追加する

org.springframework.boot:spring-boot-starter-aop を追加してAOPが利用できるようにする。

ObservedAspect Beanを追加する

横断的にデータを収集するための ObservedAspect インスタンスをSpring Bean に登録する。

import io.micrometer.observation.ObservationRegistry
import io.micrometer.observation.aop.ObservedAspect
import org.springframework.context.annotation.Bean
import org.springframework.context.annotation.Configuration

@Configuration
class ObservationConfiguration {

    @Bean
    fun observedAspect(registry: ObservationRegistry) = ObservedAspect(registry)
}

Spanデータを登録したい箇所に @Observed を付ける

観測対象としたいクラスまたはメソッドに @Observed を付ければ トレースデータを収集することができる。
クラスにアノテーションを付ければ、そのクラス内のメソッドが全てトレーシング対象になる(privateクラスは取れるか未確認)

今回は全ての controllerクラス、serviceクラス、repositoryクラス をトレーシング対象としたが、実運用ではどのクラスを対象とするかは検討した方が良いと思う。

Microservice Observation API は メトリクスにも関係するので、例えば後述する Mybatisによるクエリ実行メトリクスを観測対象にすると、Mybatisのクエリ実行部分だけをトレーシングできるようにもなる

kazokmrkazokmr

これまでは、HTTPリクエストやgRPCでの通信単位に Spanデータを取得してトレーシングを行った。

Spring boot actuator(Micrometer)の標準設定として アプリケーションに対する 一つのリクエスト/レスポンスごとに一つのSpanを形成してくれる認識。多分、マイクロサービスなどのサービスごとの分散トレーシングが前提になっているのかなと考えている

ここでは更にメソッドの処理ごとにSpanデータを取れるようにして より問題を特定しやすくしてみる。

観測対象をアプリケーション内のクラスやメソッド単位に指定すれば、その処理単位にSpanも分解することができ細部の処理時間などを計測することが可能になる。
とはいえメソッドレベルでObservationの登録処理を記述するのは大変なので Micrometerでは AOPを利用した仕組みが提供されている

kazokmrkazokmr

Mybatis と Lettuce のメトリクスを収集する

これはLINEさんのブログを参考に(というか丸々コピー)対応した

https://engineering.linecorp.com/ja/blog/metrics-capture-spring

MyBatis のメトリクス取得

MicrometerInterceptor で行っていることは、Executor インターフェースの次の3つのメソッドが実行された時に Micrometerがメトリクスを観測するよう設定を行っている。これらを観測することで Mybatisを利用したCRUD操作をカバーすることができる。

  • update​(MappedStatement ms, Object parameter)
  • query​(MappedStatement ms, Object parameter, RowBounds rowBounds, ResultHandler resultHandler, CacheKey cacheKey, BoundSql boundSql)
  • query​(MappedStatement ms, Object parameter, RowBounds rowBounds, ResultHandler resultHandler)

https://javadoc.io/doc/org.mybatis/mybatis/latest/org/apache/ibatis/executor/Executor.html

またMybatisのメトリクスを取得すると、前述の ObservedAspect によって この3つのメソッドに対するトレースデータも取得できるようになる

Lettuce のメトリクス取得

こちらの Lettuceの リファレンス だけだとよくわからなかったけど、RedisClientインスタンスを生成する際に MicrometerRegistryを利用してメトリクスの観測対象とすれば良さそう。

今回は Session情報登録用の LettuceConnectionFactory Bean内で設定するようにした

@Bean
    fun redisConnectionFactory(meterRegistry: MeterRegistry): LettuceConnectionFactory {
        val configuration = RedisStandaloneConfiguration(redisHostName, redisPort)
        val clientResources: ClientResources = ClientResources.builder()
            .commandLatencyRecorder(MicrometerCommandLatencyRecorder(meterRegistry, MicrometerOptions.create()))
            .build()
        val lettuceClientConfiguration: LettuceClientConfiguration = LettuceClientConfiguration.builder()
            .clientResources(clientResources)
            .build()
        return LettuceConnectionFactory(configuration, lettuceClientConfiguration)
    }
kazokmrkazokmr

またMybatisのメトリクスを取得すると、前述の ObservedAspect によって この3つのメソッドに対するトレースデータも取得できるようになる

(確認すればいいんだけど、) ObservedAspect Beanが無くても、MybatisのIntercepter Bean内で Observeしているのでこれだけでメトリクスが収集できるような気がしている

kazokmrkazokmr

メトリクス収集時にexemplar も取得する

Exemplar とは メトリクスに収集期間中に発生したトレースデータの一部をサンプルとして付与したものである。exemplarを用いてある時点のメトリクスからその時のトレース情報やログ情報を抽出できるので問題の特定や分析がしやすくなる。

メトリクスにExemplarを付与するには、Micrometer Tracing の機能を利用する。これによって Exemplarとして サンプルトレースの trace_idspan_id が自動で付与される。

Metricsデータに percentiles-histogram.http.server.requests を追加する

exemplarが付与されるメトリクスデータは決まっており http_server_requests_seconds_bucket が必要になる。このメトリクスを出力するために application.yml で、 management.metics.distribution.percentiles-histogram.http.server.requests の 値を true にする。

また、exemplarは必ず付与されるわけではないので、 management.tracing.sampling.probability1.0 (100%) にするなどして、トレースデータを収集しやすくすると良さそう。

Tracer を Zipkin Brave に変える

ここまで、OpenTelemetryでトレースを収集していたのだが、io.micrometer:micrometer-tracing-bridge-otel の最新版 1.0.3 の不具合で exemplarが付与されなかった。(正確には1.0.1から発生していた)

https://github.com/micrometer-metrics/tracing/issues/207

次回の1.0.4で修正されるようだが、今回は取り急ぎ Zipking Brave に依存関係を変えることで対処した

build.gradle.kts
//    runtimeOnly("io.micrometer:micrometer-tracing-bridge-otel")
//    runtimeOnly("io.opentelemetry:opentelemetry-exporter-zipkin")
    runtimeOnly("io.micrometer:micrometer-tracing-bridge-brave")
    runtimeOnly("io.zipkin.reporter2:zipkin-reporter-brave")

Prometheus の exemplar専用ストレージを有効にする

Prometheusコンテナを起動するときに exempler-storage を有効にすることで収集したexemplar専用のストレージが確保される

docker compose.yml
services:
  prometheus:
    image: prom/prometheus
    container_name: prometheus
    command:
      - --enable-feature=exemplar-storage
      - --config.file=/etc/prometheus/prometheus.yml
    environment:
      TZ: Asia/Tokyo
    volumes:
      - ./config/prometheus.yml:/etc/prometheus/prometheus.yml:ro
    networks:
      - datasource
    ports:
      - "9090:9090"

サーバにリクエストを送信して Exemplarを収集する

あとは、サーバーに対してリクエストを送信することで、http_server_requests_seconds_bucket メトリクスに exemplar として サンプルデータとして収集した trace_idspan_id が付与され、Prometheusで収集・保管する。

Grafanaで可視化する

http_server_requests_seconds_bucket を表示すると、通常の線グラフから外れた点がいくつか表示される。これが Exemplarである。(このグラフだと 横軸の時間軸上に3個ほど出力されている)

Exemplarにカーソルを当てると対象のサンプルデータがホバー表示され、さらに連携設定を行えば trace_id に該当するトレースデータに遷移することができる。

今回の画像だと分かりづらいと思うが実際の運用では メトリクスを見て負荷が高い所やレスポンス時間が遅くなっている情報の周辺にあるExemplarに含まれるTraceIDからトレースおよびログを確認することで原因や問題を特定しやすくできると思う。

kazokmrkazokmr

尚、Metricsを収集するEndpoint /actuator/prometheus にアクセスするポートがサービスと同じ場合だと、このリクエストに対するexemplarも収集される。

kazokmrkazokmr

spring-boot 3.0.6 がリリースされ、Micrometer Tracing が 1.0.4 になったので、依存関係を元に戻して確認したところ、Exemplarが収集されるようになった

kazokmrkazokmr

Grafana で メトリクス x トレース x ログ を関連付ける

アプリから収集したメトリクスとトレースとログにそれぞれ trace_idspan_id をセットすることができたのでこれをキーに各データを行き来することができるようになる。

メトリクス から トレース

メトリクスのExemplarのトレースIDから トレースデータを参照しにいくことができる。

  1. Datasources > Prometheus を選択する
  2. Exemplarsを追加し、以下の情報を設定する
  • Internal link: 有効
  • Data source: Tempo
  • URL Label: (未入力)
  • Label name: trace_id (exemplarに付与された トレースIDの Key)

これを設定することで exemplar の画面上の trace_id に 「Query with Tempo」ボタンが表示され Tempoの当該traceID画面に遷移できる

トレース から ログ

トレース情報に含まれる各スパン情報から トレースIDあるいはスパンIDが一致するログが抽出できる。
今回はトレースIDだけをキーに遷移できるリンクを用意してみた。

  1. Datasources > Tempo を選択する
  2. Trace to logs を次のように設定する
  • Data source: Loki
  • Span start time shift: -1h
  • Span end time shift: 1h
    • Span time shift はログの検索期間をトレース取得日時を基準に指定することができる。
    • これはログの出力時刻とズレがあるとトレースIDが一致しても検索されなくなるため適切な範囲を決めると良い
  • Tags: "traceId" as "trace_id"
    • これは検索条件となるラベル名称を定義している。左が Tempoにおけるラベル名称をセットする。Loki側のKey名が同じではない場合、 as 以降に Lokiでのラベル名称を入力する。
    • つまりサンプルアプリだとトレースIDのラベルは、Tempoが ”traceId” で Lokiが "trace_id" となっている
    • スパンIDで関連付けたい場合は "spanId" as "span_id" とすれば良い
  • Filter by trace ID: 有効
  • Filter by span ID: 無効
    • 検索対象がトレースIDとスパンIDのどちらか、または両方かを指定する。
    • 今回はトレースIDだけで関連づける
  • Use custom query: 無効
    • ここまでの設定では検索できない条件を指定したい場合はここで設定する

上記の設定は 実際にTempoからLokiに遷移した時に Lokiの検索条件として出力されているので これを確認しながら調整していけば良い。

設定ができると、Tempoのトレースの スパン情報に 「」ボタンが表示され、Lokiで該当トレースIDが含まれるログメッセージが一覧表示される。

ログからトレース

ログのトレースIDからトレース情報を表示することもできる。設定は次の通り

  1. Datasources > Loki を選択する
  2. Derived fields に フィールドを追加する
  3. 以下のようにログメッセージから トレースIDを抽出してトレース情報と紐付ける
  • Name: TraceID
  • Regex: '[[\w=]+,(\w*),'
    • Promtailの regexステージと同じように ログメッセージから トレースIDが取得できるような正規表現で定義する
  • Query: ${__value.raw}
    • Tempoの TraceQLに入力するクエリを書く。上記は Regexで取得した値をそのまま利用するという意味
  • URL Label: 未入力
  • Internal Link: Tempo

設定すると ログ情報の詳細に TraceIDと「Tempo」ボタンが表示され、Tempoでトレース情報が表示される

kazokmrkazokmr

トレースからメトリクス、ログからメトリクスの遷移は出来なさそう。
というのも メトリクスのQuery条件にトレースIDやトレースおよびログの出力時間が指定できそうにないため。

kazokmrkazokmr

Grafa Detasourceの設定をYAMLで書く

ここまでの設定を datasource.yml に記載した。
なお、 editable=false としているので取り込んだDatasourceはGrafanaの画面上では編集できなくなる。

datasource.yml
apiVersion: 1

datasources:
  - name: Prometheus
    type: prometheus
    access: proxy
    url: http://host.docker.internal:9090
    editable: false
    jsonData:
      httpMethod: POST
      manageAlerts: true
      prometheusType: Prometheus
      prometheusVersion: 2.43.0
      exemplarTraceIdDestinations:
        - datasourceUid: Tempo
          name: trace_id
  - name: Tempo
    type: tempo
    access: proxy
    url: http://host.docker.internal:3200
    editable: false
    jsonData:
      httpMethod: GET
      tracesToLogs:
        datasourceUid: 'Loki'
        tags: [ 'job', 'instance', 'pod', 'namespace' ]
        mappedTags: [ { key: 'traceId', value: 'trace_id' } ]
        mapTagNamesEnabled: true
        spanStartTimeShift: '-1h'
        spanEndTimeShift: '1h'
        filterByTraceID: true
        filterBYSpanID: false
      serviceMap:
        datasourceUid: 'Prometheus'
      search:
        hide: false
      nodeGraph:
        enabled: true
      lokiSearch:
        datasourceUid: 'Loki'
  - name: Loki
    type: loki
    access: proxy
    url: http://host.docker.internal:3100
    editable: false
    jsonData:
      maxLines: 1000
      derivedFields:
        - datasourceUid: Tempo
          matcherRegex: "\\[[\\w-]+,(\\w*),"
          name: TraceID
          url: "$${__value.raw}"

作成した datasource.yml はDokcr起動時にファイルを指定することで自動で設定される

compose.yml
  grafana:
    image: grafana/grafana
    container_name: grafana
    environment:
      TZ: Asia/Tokyo
    volumes:
      - grafana-storage:/var/lib/grafana
      - ./grafana/provisioning/datasources:/etc/grafana/provisioning/datasources:ro
    networks:
      - grafana
      - datasource
    ports:
      - "3000:3000"
kazokmrkazokmr

アプリケーションのテレメトリデータのスクレイプを Grafana Agentで行う

ここまでアプリのテレメトリデータのスクレイプは次のように行っていた

  • Metrics: Prometheus/actuator/prometehus にアクセスしてスクレイプする
  • Trace: アプリから Zipkin Braveのexporter 機能を使って Tempo に転送する
    • Traceデータの生成は アプリ側の Micrometer Tracing + OpenTelemetry or Zipkin Brave で行っている
  • Log: Promtailが アプリが出力したログファイル からスクレイプして Loki に転送する

ここからは Grafana Agent を使ってアプリのテレメトリーデータのスクレイプを行い、Prometheus / Tempo / Loki に転送する仕組みとする

kazokmrkazokmr

Grafana Agent の セットアップ

Grafana Agentはバックエンドアプリのサイドカー的な役割として配置する。

Compose.yml と Configファイルである agent.yml は次の通り。詳細は後ほど

backend/compose.yml
services:
  app:
    build:
      context: ../../
      dockerfile: ./docker/backend/app/Dockerfile
    container_name: backend
    hostname: backend.app
    environment:
      TZ: Asia/Tokyo
    volumes:
      - app-logs:/app/logs
    networks:
      - app
      - db_external
      - redis_external
    ports:
      - "8080:8080"
      - "8081:8081"
  grafana-agent:
    image: grafana/agent
    container_name: grafana-agent
    command:
      - --config.file=/etc/agent/agent.yml
    environment:
      TZ: Asia/Tokyo
    volumes:
      - ./agent/agent.yml:/etc/agent/agent.yml:lo
      - agent-store:/etc/agent/data
      - app-logs:/var/logs
    networks:
      - agent
      - app
      - db_external
      - redis_external
      - datasources_external
    ports:
      - "12345:12345"
      - "9411"     # zipkin receiver for Backend
volumes:
  app-logs:
    driver: local
  agent-store:
networks:
  app:
    driver: bridge
    internal: false
    name: app_network
  # DBとRedisのネットワーク
  db_external:
    external: true
    name: db_network
  redis_external:
    external: true
    name: redis_network
  # Grafana Agent のネットワーク
  agent:
    driver: bridge
    internal: true
    name: agent_network
  # GrafanaのDataSourceネットワークに接続定義
  datasources_external:
    external: true
    name: datasources_network
agent.yml
server:
  log_level: info

metrics:
  wal_directory: /etc/agent/data
  global:
    scrape_interval: 2s
  configs:
    - name: default
      scrape_configs:
        - job_name: "spring-actuator"
          metrics_path: "/actuator/prometheus"
          static_configs:
            - targets: [ "app:8081" ]
      remote_write:
        - url: http://mimir:9009/api/v1/push
          send_exemplars: true

traces:
  configs:
    - name: default
      receivers:
        zipkin:
      remote_write:
        - endpoint: "tempo:4317"
          insecure: true

logs:
  configs:
    - name: default
      positions:
        filename: /tmp/positions.yml
      scrape_configs:
        - job_name: app
          pipeline_stages:
            - regex:
                expression: "^(?P<timestamp>\\d{4}-\\d{2}-\\d{2}T\\d{2}:\\d{2}:\\d{2}.\\d{3}\\+\\d{2}:\\d{2})\\s+(?P<level>\\w+)\\s+\\[(?P<app>[\\w-]+),(?P<trace_id>[\\w-]*),(?P<span_id>[\\w-]*)\\]\\s+\\[(?P<thread>[\\w-]+)\\]\\s+(?P<classname>[\\w.-]*):\\s+(?P<message>.*)$"
            - labels:
                level:
                app:
                trace_id:
                span_id:
          static_configs:
            - targets:
                - localhost
              labels:
                job: app
                host: app
                __path__: /var/logs/*.log
      clients:
        - url: http://loki:3100/loki/api/v1/push
kazokmrkazokmr

MetricsをAgentでスクレイプし Remote Writeする

Grafana Agentに変えることで構成が最も変わるのがメトリクスで、これまでPrometehusサーバだけでスクレイピングと保管の両方を行っていたがそれを分けることになるためである。

スクレイピングは Grafana Agent で行う

Grafana Agent はPrometheusの収集機能(サービスディスカバリとスクレイピング)および転送機能だけに特化したソフトウェアだそう。ちなみにこれをPrometheusに逆輸入したものがAgent Modeらしい。

https://grafana.com/docs/agent/latest/#metrics

https://prometheus.io/blog/2021/11/16/agent/

なので Grafana Agentではスクレイプしたメトリクスは、Remote Write 外部ストレージへ転送するまでを行う。

保管はRemote Writeに対応しているストレージを利用する

調べたところPrometheusサーバー自体をストレージに使うことはあまりなく、Remote Write (および Read) に対応したストレージソフトやサービスを利用することが一般的だった。

https://prometheus.io/docs/operating/integrations/#remote-endpoints-and-storage

そこで今回は Grafana Mimir (ミーミル or ミミル) を使うことにした。

https://grafana.com/docs/mimir/latest/operators-guide/get-started/

Grafana Mimir を立ち上げ、Grafana Agentでスクレイプしたメトリクスを管理する

Grafana Mimir コンテナを用意する

Grafana Stack 側の Docker compose の PrometehusコンテナをMimirコンテナに変更した

grafana/compose.yml
services:
  mimir:
    image: grafana/mimir
    container_name: mimir
    command: [ "-config.file=/etc/mimir.yml" ]
    environment:
      TZ: Asia/Tokyo
    volumes:
      - ./config/mimir.yml:/etc/mimir.yml:ro
      - mimir-storage:/tmp/mimir
    networks:
      - datasource
    ports:
      - "9009:9009"

Mimirの設定については 公式ドキュメント通り

mimir.yml
multitenancy_enabled: false

limits:
  max_global_exemplars_per_user: 100000

blocks_storage:
  backend: filesystem
  bucket_store:
    sync_dir: /tmp/mimir/tsdb-sync
  filesystem:
    dir: /tmp/mimir/data/tsdb
  tsdb:
    dir: /tmp/mimir/tsdb

compactor:
  data_dir: /tmp/mimir/compactor
  sharding_ring:
    kvstore:
      store: memberlist

distributor:
  ring:
    instance_addr: 127.0.0.1
    kvstore:
      store: memberlist

ingester:
  ring:
    instance_addr: 127.0.0.1
    kvstore:
      store: memberlist
    replication_factor: 1

ruler_storage:
  backend: filesystem
  filesystem:
    dir: /tmp/mimir/rules

server:
  http_listen_port: 9009
  log_level: info

store_gateway:
  sharding_ring:
    replication_factor: 1

GrafanaのPrometheus Datasourceの設定を変更する

Mimir は Prometheus互換なのでDatasourceの設定はPrometheuサーバーの時のものを流用できるが urlprometheusType を変更する必要がある

datasource.yml
datasources:
  - name: Prometheus(Mimir)
    type: prometheus
    access: proxy
    url: http://host.docker.internal:9009/prometheus
    editable: false
    jsonData:
      httpMethod: POST
      manageAlerts: true
      prometheusType: Mimir
      prometheusVersion: 2.7.x
      exemplarTraceIdDestinations:
        - datasourceUid: Tempo
          name: trace_id

Grafana Agent を設定する

スクレイピングの設定は prometheus.yml の内容をほぼ流用でいける。追加でMimirに転送するための設定を remote_write プロパティで 行う。 send_exemplars: true で exemplarも転送できるようにすること

agent.yml
metrics:
  wal_directory: /etc/agent/data
  global:
    scrape_interval: 2s
  configs:
    - name: default
      scrape_configs:
        - job_name: "spring-actuator"
          metrics_path: "/actuator/prometheus"
          static_configs:
            - targets: [ "app:8081" ]
      remote_write:
        - url: http://mimir:9009/api/v1/push
          send_exemplars: true
kazokmrkazokmr

アーキテクチャ的には Prometheus が無くなりGrafana製品に置き換わったが、Grafana Agent も Mimir も内部的にはPrometheusが動いているので、メトリクスの管理は Prometheusで行っていることは変わらないかなと考えている

kazokmrkazokmr

Trace を Agentを経由して Tempoに転送する

元々TraceデータはSpring Boot アプリでハンドリングして Tempoに送信していたので、送信先を Grafana Agentに変える。

Grafana Agentは OpenTelemetry Collector を利用したトレースデータのパイプライン処理が行うことができる。RecieverにZipkinも選択できるので、Spring Bootアプリからトレースの送信先をTempoからGrafana Agentに変更し、Grafana Agent側では受信したトレースデータをTempoに転送することができる。

https://grafana.com/docs/agent/latest/#traces

https://grafana.com/docs/tempo/latest/grafana-agent/

この構成は "アプリ と Tempoで直接行える送受信処理" にAgentを割り込んでいるようで無駄なようにも思えた。だが下記リンク先の内容を読んで、Agentを入れることでデータ転送のバッファリングや送信失敗時のリトライといった送信処理の責務を委譲できるので、アプリに掛かるリソースを軽減できることがメリットの一つであると理解した。

https://grafana.com/docs/tempo/latest/getting-started/#pipeline-grafana-agent

Tempoの設定変更

ReceiverをZipkinからOpenTelemetry (OTLP)に変更した

tempo.yml
server:
  http_listen_port: 3200

distributor:
  receivers:
    otlp:
      protocols:
        grpc:

storage:
  trace:
    backend: local
    local:
      path: /tmp/tempo/blocks

またトレースデータの受信用に開放するポートを Zipkinの 9411 から OTLP via gRPC の 4317 に変更した

grafana/compose.yml
  tempo:
    image: grafana/tempo
    container_name: tempo
    command: [ "-config.file=/etc/tempo.yml" ]
    environment:
      TZ: Asia/Tokyo
    volumes:
      - ./config/tempo.yml:/etc/tempo.yml:ro
      - tempo-data:/tmp/tempo
    networks:
      - datasource
    ports:
      - "3200:3200"   # tempo
      - "4317:4317"   # for Grafana Agent exports via gRPC using OTLP

OTLPは Tempoのデフォルト設定らしく config.file で指定しなくても以下のような設定値となっている模様。なのでconfig.file に明示しなくても良さそうだがOTLPをgRPCプロトコルで利用することは明示している。

  • プロトコル: gRPC
  • TLS: 有効
  • ポート: 4317

なお、デフォルト値であることは明示されては 実際に動作確認をした上での個人の見解である。

https://github.com/open-telemetry/opentelemetry-collector/blob/main/receiver/otlpreceiver/README.md

Grafana Agent の 設定

Spring Bootアプリから送信されるトレースのReciverとなるためZipkinを指定する。Exporter(転送先)の設定は、remote_write機能を利用し、前述のTempoのデフォルト設定に合わせて OTLP + gRPC(4317) + TLS で転送させた。

agent.yml
traces:
  configs:
    - name: default
      receivers:
        zipkin:
      remote_write:
        - endpoint: "tempo:4317"
          insecure: true

その他、Spring Bootからトレースデータを受信するポートとしてZipkinの9411を開放した。(これは外部に公開する必要はないので、Dockerのネットワーク内でアプリからアクセスできるようにする)

Spring Bootアプリケーションの設定変更

トレースデータの送信先が Tempoから Grafana Agent に変わるので management.zipkin.tracing.endpoint で指定するエンドポイントを Grafana AgentのZipkin Receiverに変える。

kazokmrkazokmr

Log を Grafana Agentでスクレイプし Lokiに転送する

ログは元々 Promtail をAgentしてアプリのログファイルをスクレイプして、Lokiに転送していた。
Grafana Agent の ログのスクレイプ機能は Promtailがベースになっているため、コンテナの設定およびAgentの設定自体も Promtailの設定内容を移行する形で行えるので、メトリクスやトレースに比べると比較的簡単に変更できた

https://grafana.com/docs/grafana-cloud/data-configuration/logs/collect-logs-with-agent/?pg=hp&plcmt=lt-box-traces

Dockerコンテナの設定

Promtailコンテナを削除し、Grafana Agentコンテナでアプリ側のログファイルの格納先ボリュームを共有する

backend/compose.yml
  grafana-agent:
    image: grafana/agent
    container_name: grafana-agent
    command:
      - --config.file=/etc/agent/agent.yml
    environment:
      TZ: Asia/Tokyo
    volumes:
      - ./agent/agent.yml:/etc/agent/agent.yml:lo
      - agent-store:/etc/agent/data
      - app-logs:/var/logs
    networks:
      - agent
      - app
      - db_external
      - redis_external
      - datasources_external
    ports:
      - "12345:12345"
      - "9411"     # zipkin receiver for Backend

Grafana Agentのログ設定は promtail.yml の設定をコピペする。一部、フィールド定義が異なる箇所はあるので注意する

https://grafana.com/docs/agent/latest/configuration/create-config-file/#loki-configmigrating-from-promtail

agent.yml
logs:
  configs:
    - name: default
      positions:
        filename: /tmp/positions.yml
      scrape_configs:
        - job_name: app
          pipeline_stages:
            - regex:
                expression: "^(?P<timestamp>\\d{4}-\\d{2}-\\d{2}T\\d{2}:\\d{2}:\\d{2}.\\d{3}\\+\\d{2}:\\d{2})\\s+(?P<level>\\w+)\\s+\\[(?P<app>[\\w-]+),(?P<trace_id>[\\w-]*),(?P<span_id>[\\w-]*)\\]\\s+\\[(?P<thread>[\\w-]+)\\]\\s+(?P<classname>[\\w.-]*):\\s+(?P<message>.*)$"
            - labels:
                level:
                app:
                trace_id:
                span_id:
          static_configs:
            - targets:
                - localhost
              labels:
                job: app
                host: app
                __path__: /var/logs/*.log
      clients:
        - url: http://loki:3100/loki/api/v1/push
kazokmrkazokmr

Grafana Agent の動作確認

ここまでの設定でこれまで通りのアプリのテレメトリデータをGrafanaで可視化できることを確認した。
Grafana Agentを使うことで、アプリとGrafana Stackを直接繋がることがなくなり、全てGrafana Agent
を介して データのスクレイピングと転送が行えるようになった。

kazokmrkazokmr

Grafana Agentで PostgreSQLサーバ と Redisサーバ のメトリクスを収集する

Prometheusには exporter と呼ばれる 様々なミドルウェアやハードウェア、OSのメトリクスをスクレイプしPrometheusで管理するためのライブラリが存在する。

https://prometheus.io/docs/instrumenting/exporters/

今回のサンプルアプリで利用している、PostgreSQLサーバーとRedisサーバーのメトリクスをスクレイプできるExporterがある。

そして Grafana Agentでは よく利用されうExporterが幾つか搭載されており、PostgreSQLとRedisも含まれているので、すぐにメトリクスのスクレイピングが出来そうだったので試してみた

Exporterの設定は agent設定ファイルの integrations_config セクションで行う

このセクションで、利用したいExporter を 有効にし接続設定など必要な設定を行う。
メトリクスの転送は Integrations共有の prometheus_remote_write プロパティで行う。

今回は アプリと同じMimirに転送する

agent.yml
integrations:
  prometheus_remote_write:
    - url: http://mimir:9009/api/v1/push

https://grafana.com/docs/agent/latest/configuration/integrations/

PostgreSQLサーバーのメトリクスをスクレイプする

https://grafana.com/docs/agent/latest/configuration/integrations/postgres-exporter-config/

必要最低限の設定は以下の通り

agent.yml
integrations:
  postgres_exporter:
    enabled: true
    data_source_names:
      - "postgresql://<usre>:<password>@<host>:<port>/<database_name>?sslmode=disable"

実運用では、メトリクス収集用のロールを持った専用Userを用意してアクセスすると良さそう

https://github.com/prometheus-community/postgres_exporter#running-as-non-superuser

Redisサーバのメトリクスをスクレイプする

https://grafana.com/docs/agent/latest/configuration/integrations/redis-exporter-config/

考え方がは PostgreSQL と同じ

agent.yml
integrations:
  redis_exporter:
    enabled: true
    redis_addr: "<host>:<port>"

https://github.com/oliver006/redis_exporter#authenticating-with-redis

Agent から DBサーバへアクセスできるようにする

Grafana Agentが、PostgreSQLサーバーとRedisサーバーへ接続できるようにネットワークを設定すれば、あとはアプリと同じようにメトリクスをスクレイプしMimirへ転送、Grafanaで可視化できるようになる

kazokmrkazokmr

今後試してみたいこと

当初の目的は達成できたのでこれでクローズとするが、実際に触ってみて次のことも今後試してみたくなった

クライアントサイド(フロントエンドアプリ)のテレメトリデータ収集

Grafana faro を利用すれば、クライアント側のログの収集や ブラウザからのHTTPリクエストにトレースIDを付与して、バックエンド側のアプリに伝搬させてトレースデータを可視化できそう

https://grafana.com/docs/grafana-cloud/faro-web-sdk/?pg=oss-faro&plcmt=hero-btn-3

Grafana のダッシュボード作成

今回はアプリとGrafana Stackを連携してデータを取得する作業がメインだったので、取得したデータを実際にどのように活用するかまでは理解できていない。

この辺は、監視運用技術と合わせて学んでいきたい所存

https://www.oreilly.co.jp/books/9784873118642/

https://www.oreilly.co.jp/books/9784814400126/

kazokmrkazokmr

まとめ

Spring Boot 3 の Actuator と Grafana Stack + Prometheus を触ることで、オブザーバビリティのことや分散トレーシングの概要が理解できたし、Spring Bootアプリを使う案件ならプロジェクトの初期から Grafana Stackと連携したり、オブザーバビリティを意識した設計・開発も始められる自信がついたので良かった。

参考資料

最後に今回の調査にあたり参考にさせて頂いた資料のリンク

https://docs.spring.io/spring-boot/docs/current/reference/html/actuator.html

https://spring.io/blog/2022/10/12/observability-with-spring-boot-3

https://grafana.com/docs/

https://prometheus.io/docs/introduction/overview/

https://micrometer.io/

https://cero-t.hatenadiary.jp/entry/2023/01/10/163547

https://engineering.linecorp.com/ja/blog/metrics-capture-spring

このスクラップは2023/04/04にクローズされました