はじめに

OpenStandiaアドベントカレンダーも早いもので、最終日となりました。あっという間に投稿日がやってきました。

クリスマスとは何ら関係ないのですが、Spring Boot 3が最近リリースされました。お仕事では、今後の移行に向けたことを考えたりするわけですが、Spring Boot 3では、オブザーバビリティが強化されたそうで、今回はえっちらおっちら触っていきます。

Spring Boot 3.0 Release Notes

オブザーバビリティとは

オブザーバビリティとは何ぞや？という話ですが、Google先生に聞いてみると、現時点でNRIのページが一番上にヒットします。私は全く関係ないのですが、なんだかちょっと嬉しいですね。そのページ曰く以下の通りです。

「メトリクス」「ログ」「トレース」を収集し、高度に分析、可視化できるよう努めるものと受け取れますね。Spring Boot 3にもそれに向けた機能が備わったということでしょう。本稿は、オブザーバビリティ初心者である筆者が簡単なアプリケーションにオブザーバビリティを与えていこうとするものです。

今回の構成

本稿でお試しする最終的な構成は以下の通りです。

アプリケーション(クライアント/サーバ)
Spring Boot3 + JDK17 + Gradle
DB
H2DB + JDBC
メトリクス収集
Prometheus
トレース収集
OpenTelemetry + Grafana Tempo
ログ収集
Grafana Loki
分析、可視化
Grafana

筆者は、アプリケーションのみWindows環境のIDEから起動し、他のサーバをWSL2上のDockerで起動しています。本稿ではアプリケーション側の設定、実装について述べ、それによって何ができるか見ていきます。Docker側の起動や設定については詳しく触れません。ご承知おきください。

0. オブザーバビリティに乏しいアプリをつくる

オブザーバビリティを与えるアプリケーションを作ります。
「トレース」を念頭において、通信が絡むクライアント/サーバのアプリケーションを作成することとしました。

クライアントアプリケーション

5秒おきにサーバアプリケーションにリクエストを投げるだけのアプリケーションです。

@Component
  public class ScheduledTask {
    private final RestTemplate restTemplate;

    public ScheduledTask(RestTemplateBuilder restTemplateBuilder) {
      this.restTemplate = restTemplateBuilder.build();
    }

    @Scheduled(fixedRate = 5000) // 5秒ごとに実行
    public void performTask() {
      String resourceUrl = "http://localhost:8080/data";
      restTemplate.getForObject(resourceUrl, MyEntity[].class);
    }

    @Data
    private static class MyEntity {
      private Long id;
      private String data;
}

サーバアプリケーション

クライアントのリクエストを受けて、DBをSELECTした結果を返却します。

@RestController
  @RequiredArgsConstructor
  public class MyController {
      private final MyEntityService myEntityService;

      @GetMapping("/data")
      public List<MyEntity> getData() {
          return myEntityService.findAll();
      }
  }

@Service
  @RequiredArgsConstructor
  public class MyEntityService {
      private final JdbcTemplate jdbcTemplate;

      public List<MyEntity> findAll() {
          return jdbcTemplate.query("SELECT * FROM my_entity", (rs, rowNum) -> new MyEntity(rs.getLong("id"), rs.getString("data")));
      }
  }

1. メトリクス

メトリクスはアプリケーションの状態を監視するための情報です。
継続的にメトリクスを収集し、分析することで、アプリケーションが健全に動作し続けられるようになると期待されますね。コンテナ時代のアプリケーションではリソースの割り当て設計なども精度よく行わなければいけないので重要ですね。

Micrometer + Prometheusでメトリクスを収集する

今日では、デファクトといえるPrometheusにメトリクスを収集してもらいます。Prometheusは基本的に指定されたエンドポイントに定期的にポーリングすることで、メトリクスを収集します。
エンドポイントはSpring Boot ActuatorによってPrometheus向けのエンドポイントを提供します。

Prometheus向けのメトリクスを扱うため、クライアント/サーバアプリケーションに以下の依存を追加します。

dependencies {
  implementation 'org.springframework.boot:spring-boot-starter-web'
  +	implementation 'org.springframework.boot:spring-boot-starter-actuator'
  +	implementation 'io.micrometer:micrometer-registry-prometheus'
  // 以下略
}

Spring Boot Actuatorが/actuator配下のパスで、エンドポイント（Prometheus向けを含む）を公開できるようになりました。
次にMicrometerが公開するエンドポイントを指定します。application.propertiesに以下の設定を追加します。

management.endpoints.web.exposure.include：Actuatorが提供できるエンドポイントの識別子を指定します。*が指定された場合、すべてのエンドポイントが公開されます。

+ management.endpoints.web.exposure.include=*

これによってPrometheus向けのエンドポイントが公開されるようになりました。PrometheusのTargetsにクライアント/サーバアプリケーションを含めて起動しましょう。Prometheusがメトリクスを収集し始めます。

+ scrape_configs:
+   - job_name: 'client_app'
+     metrics_path: '/actuator/prometheus'
+     static_configs:
+       - targets : ['172.22.128.1:8081']
+   - job_name: 'server_app'
+     metrics_path: '/actuator/prometheus'
+     static_configs:
+       - targets : ['172.22.128.1:8080']

Grafanaで可視化

Prometheusにもブラウザから確認できるGUIがありますが、あまりリッチなIFではない為、Grafanaで可視化するのが通例のようです。Grafanaのデータソースとして、Prometheusを追加して可視化させていきます。

以下は公開されているボードJVM (Micrometer)で可視化したものです。

他にも多くのメトリクスパターンに対応したボードが公開されており、分析を助けてくれます。まじまじと見るのは初めてですが、手軽にいろいろな切り口の分析ができてとてもよいですね。

2. トレース

トレースとは、リクエストに起因する一連のリクエストやトランザクション処理の経路や経過を記録するものです。これを監視することで、パフォーマンスのボトルネックを特定したり、エラーの発生個所や原因の特定に役立てられます。

Micrometer Tracing + OpenTelemetryトレーサによるトレース

トレーサとは、トレース情報（トレースIDやスパン（リクエスト処理の一部の区間））の作成や伝搬、管理を行うものです。Micrometer TracingではOpenTelemetryおよびZipkinのトレーサに対応しており、本稿では前者を用います。

クライアント/サーバアプリケーションに以下の依存を追加します。

dependencies {
  implementation 'org.springframework.boot:spring-boot-starter-web'
  implementation 'org.springframework.boot:spring-boot-starter-actuator'
  implementation 'io.micrometer:micrometer-registry-prometheus'
+ implementation 'io.micrometer:micrometer-tracing-bridge-otel'
  // 以下略
}

これによって、RestTemplateの通信時に以下のようなトレース情報が付与され、通信前後で伝搬できるようになります。このトレース情報はOpenTelemetryが対応するトレース情報の伝搬に関する企画であるW3Cに準拠しており、トレースIDと、通信先で作成されるスパンの親となるスパン情報を持ちます。

traceparent: 00-eb80255d5af6ce42d1466b18497daab0-f486e8dd9a538527-01

OpenTelemetryエクスポーターでGrafana Tempoに集積

OpenTelemetryトレーサによって付与されたトレース情報を外部に集積する仕組みとして、OpenTelemetryにはエクスポーターという実装があります。Javaではいくつかの実装がありますが、ここではOpentelemetry Protocolを使います。

クライアント/サーバアプリケーションに以下の依存を追加します。

dependencies {
	implementation 'org.springframework.boot:spring-boot-starter-web'
	implementation 'org.springframework.boot:spring-boot-starter-actuator'
	implementation 'io.micrometer:micrometer-registry-prometheus'
  implementation 'io.micrometer:micrometer-tracing-bridge-otel'
+ implementation 'io.opentelemetry:opentelemetry-exporter-otlp'
  // 以下略
}

次にエクスポーターがトレース情報を蓄積する宛先を用意します。ここではGrafana Tempoを利用します。

Grafana Tempoを起動後、application.propertiesに設定を追加します。

management.tracing.sampling.probability: トレーシング情報を収集するレートです。ここはお試しなので100%としていますが、通信量が莫大なアプリケーションなら下げても監視には支障ないのではないでしょうか。
management.otlp.tracing.endpoint: トレーシング情報の送付先です。ホスト名やポート番号については、実際のTempoの起動環境に合わせてください。

+ management.tracing.sampling.probability=1.0
+ management.otlp.tracing.endpoint=http://localhost:4318/v1/traces

Grafanaで可視化

Grafanaのデータソースとして、Tempoを追加して可視化させます。Grafanaファミリーというだけあって、ダッシュボードを用意せずとも、Tempoに蓄積したトレース情報を可視化、分析するためのUIが提供されています。トレースIDを指定して絞り込むと以下のような結果を表示してくれます。

スパン毎の前後、親子関係や、かかった時間がわかりやすく表示されます。ボトルネックなどがあればはっきり表示されそうですね。また、マイクロサービス時代では、このノードグラフが視覚化されると通信負荷の高いところとかわかりやすくでてきそうですね。

スパンを追加する

上記に示される図ではSpring Boot 3が自動で設定するスパンのみが示されていますが、実体としては、開発者が任意の処理に対してスパンを設定したくなりますよね。

@Observedによるスパンの追加

Observedアノテーションメソッドに付与することで、メソッド処理をスパンとして設定することが可能になります。

クライアント/サーバアプリケーションに依存を追加します。（すでに追加されているケースも多そうですが。）

dependencies {
  implementation 'org.springframework.boot:spring-boot-starter-web'
  implementation 'org.springframework.boot:spring-boot-starter-actuator'
  implementation 'io.micrometer:micrometer-registry-prometheus'
  implementation 'io.micrometer:micrometer-tracing-bridge-otel'
  implementation 'io.opentelemetry:opentelemetry-exporter-otlp'
+ implementation 'org.springframework.boot:spring-boot-starter-aop'
  // 以下略
}

Observedアノテーションを動作させるには、ObservedAspectのBeanが必要です。

@Configuration
  public class ObservabilityConfig {
    @Bean
    ObservedAspect observedAspect(ObservationRegistry observationRegistry) {
      return new ObservedAspect(observationRegistry);
    }
}

サーバ側のサービスにObservedアノテーションを付与します。

@Service
  @RequiredArgsConstructor
  public class MyEntityService {
      private final JdbcTemplate jdbcTemplate;
  
  +   @Observed
      public List<MyEntity> findAll() {
          return jdbcTemplate.query("SELECT * FROM my_entity", (rs, rowNum) -> new MyEntity(rs.getLong("id"), rs.getString("data")));
      }
}

Grafanaに見に行くと、サービスのメソッド名からなるスパンが追加されています。

JDBC処理に対するスパンの追加

JDBCの処理に対してトレーシングを行う方法についてSpring Bootのドキュメントにて案内されているdatasource-micrometerを用います。これによって、JDBC処理へのMicrometerのトレーシングが対応するとともに、Spring Boot 3向けの自動構成が提供されます。

サーバアプリケーションに依存を追加します（クライアントはJDBC使わないので不要です。）。Mavenのセントラルリポジトリには存在しない為、リポジトリも追加しています。

repositories {
  mavenCentral()
+  maven {
+    url 'https://oss.sonatype.org/content/repositories/snapshots'
+  }
  }

  dependencies {
    implementation 'org.springframework.boot:spring-boot-starter-web'
    implementation 'org.springframework.boot:spring-boot-starter-actuator'
    implementation 'io.micrometer:micrometer-registry-prometheus'
    implementation 'io.micrometer:micrometer-tracing-bridge-otel'
    implementation 'io.opentelemetry:opentelemetry-exporter-otlp'
    implementation 'org.springframework.boot:spring-boot-starter-aop'
+   implementation 'net.ttddyy.observation:datasource-micrometer-spring-boot:1.0.2'
    // 以下略
}

Grafanaに見に行くと、JDBC処理に応じたスパンが追加されています。

3. ログ

最近はコンテナで動くシステムが多いので、ログ収集は大切ですよね。あちこちにSSHしてログをみて回るのは大変です。そもそもコンテナから出してやらないと、いざコンテナが落ちてログが必要な時に見つからない。なんてことになります。

Grafana Lokiでログ集積

ログの収集というと、Fluentdなどでサーバ毎のログをElasticSearchに送ったりすることで多いのかなと思いますが、ここではGrafana Lokiを用います。なお、例によって、可視化、分析はGrafanaが担います。

Loki4jによるログ転送

裏でLokiにログを送信してくれるLogbackのappenderを提供するライブラリとして、Loki4jがあります。洒落のきいた名前ですね。コミュニティ主導で開発されているようです。他にプロセスを用意する必要もなく便利そうなのでこちらを使っていきます。

クライアント/サーバアプリケーションに以下の依存を追加します。

dependencies {
  implementation 'org.springframework.boot:spring-boot-starter-web'
  implementation 'org.springframework.boot:spring-boot-starter-actuator'
  implementation 'io.micrometer:micrometer-registry-prometheus'
  implementation 'io.micrometer:micrometer-tracing-bridge-otel'
  implementation 'io.opentelemetry:opentelemetry-exporter-otlp'
  implementation 'org.springframework.boot:spring-boot-starter-aop'
  implementation 'net.ttddyy.observation:datasource-micrometer-spring-boot:1.0.2'
+ implementation 'com.github.loki4j:loki-logback-appender:1.4.2'
  // 以下略
}

logback.xmlにloki4jのappenderを設定します。

<http><url>：Lokiのエンドポイントを設定します。ホスト名やポート番号については、実際のTempoの起動環境に合わせてください。
<label><pattern>：キーバリューでインデックスが張られるため、Grafanaで絞り込みたいキーを与えるようにしてください。

<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>

次にapplication.propertiesに以下の設定を追加します。

logging.pattern.correlation：ログに共通で出力する内容を定義します。
logging.config：logbackの設定ファイルを指定しています。

+ logging.pattern.correlation=[${spring.application.name:},%X{traceId:-},%X{spanId:-}]
+ logging.config=classpath:logback.xml

これにて、Loggerから出力する情報はLokiに送信されるようになりました。

シンプルなJavaの開発なので、割愛しますが、現時点でアプリは全くログを出さないので、クライアントのRestTemplateの上り下りや、サーバのフィルタ層でログを出力するようファイルを追加しました。また、JDBCのログレベルをDEBUGも下げておきました。

Grafanaで可視化

Grafanaのデータソースとして、Lokiを追加して可視化させます。Tempoと同様にダッシュボードを用意せずとも、Lokiに蓄積したログ情報を可視化、分析するためのUIが提供されています。appenderでセットしたキーであるtraceIDを指定して絞り込むと以下のような結果を表示してくれます。

サーバやログの出力箇所をまたいで、まとめてログを表示してくれていますね。大規模なログファイルを複数手元にあつめて複数窓で検索していたことを考えると、めちゃくちゃ便利だなぁと感じました。

4. Grafanaのデータソース間の連携

Prometheusに蓄積したメトリクスや、Lokiに蓄積したログはTempoのトレース情報と紐づけが可能です。Grafanaの設定によってトレースIDを介した情報の連携が可能です。

Tempoのボタンが表示されているかと思います。ここではTraceIDで連携する設定を入れているため、クリックすると、TraceIDで絞り込んだトレース情報が表示されます。Grafana外のプロダクトのデータソースとの連携も可能なようですが、この辺はLokiやTempoが親和性に優れている部分なのだろうと感じます。すごいですね現代の運用は。

終わりに

あれこれやってきたのですが、Spring Boot 3でサポートされた。ということもあって、シンプルな定義の追加でオブザーバビリティを高めることができたのではないかと感じます。自動構成されると、どこで何が動くかわからないからという理由で忌避されることもあったように思いますが、開発者体験としては素晴らしいですね。

オブザーバビリティの向上は、障害復旧に向けた速度や、負担を大きく軽減してくれる可能性があるな。と過去の障害調査を振り返ると感じます。これまであまり触れてこなかった規格やツールに触れる機会となり大変勉強になりました。未来の自分の幸せのためにも今後とも調査、活用を進めていく所存です。ここまで読んでいただき、ありがとうございました。