概要
この記事は、Jaegerを理解する第一歩目として読むことを目的に書きました。この記事の前半では、Jaegerの概要を説明し、類似OSSといくつかの観点で比較します。後半では、Jaegerを動かしながら理解を深めていきます。
この記事の執筆時点のJaegerの最新バージョンは、1.5.4です。参照する公式ドキュメントや動作確認するデモアプリケーションのバージョンも1.5.4です。
Jaegerとは
Jaegerは、分散トレーシングを実現するOSSです。分散トレーシングとは、マイクロサービスアーキテクチャーで分散されたサービス間のリクエストのフローを追跡することで、システム全体のパフォーマンスの改善とトラブルシューティングに役立てる機能です。
例えば、以下のような複数のサービスで構成されたアプリケーションの遅延の原因を特定するようなケースでJaegerは役立ちます(サービスが多ければ多いほど)。
Jaegerは、OpenTelemetryというOSSのライブラリーなどを利用してトレースデータを収集し、それを可視化、分析することで、モニタリングやデバッグを容易にします。これにより、クラウドネイティブなアプリケーションの開発、デプロイ、運用を支援します。
英語の動画を見ると、Jaegerの発音はあえてカタカナで言うとイェーガー、イエガーのように聞こえます。ドイツ語で「ハンター」や「追跡者」を意味する単語に由来しているそうです。
基本情報
- ライセンス:Apache-2.0 license
- 実装言語:Go
- 開発元:Uber Technologies社
主な機能
Jaegerの主要な機能は以下の通りです:
- 分散トレーシング:各サービス間でのリクエストのフローを追跡し、各リクエストの処理経路や遅延を可視化します。
- トレースの収集と保存:各サービス内で生成されたトレース情報を収集し、永続的なストレージに保存します。これにより、過去のトレースを分析して問題を特定することができます。
- トレースの検索とクエリ:豊富なクエリー言語でトレースデータを検索し、分析する機能を提供します。これにより、特定のリクエストパスやパフォーマンスの問題を素早く特定することができます。
- 分散コンテキストの追跡:各リクエストのコンテキスト情報(例: ユーザーID、トランザクションIDなど)をトレースに関連付けて追跡し、分散環境でのデータのフローを理解しやすくします。
- 可視化とダッシュボード:トレースデータをグラフィカルなダッシュボードやチャートで可視化し、システムの全体像を把握しやすくします。これにより、問題の特定やトレンドの分析が容易になります。
理解すべき主な用語
Jaegerを理解するために知っておくべき用語がいくつかあるので、それを紹介します。公式ドキュメントに記載されている用語の定義は以下のようになっています。
- スパン(Span):スパンは、作業名、作業開始時刻、作業期間を持つ論理的な作業単位を表します。スパンは、因果関係をモデル化するために、入れ子にしたり、順番に並べたりすることができます。
- トレース(Trace):トレースは、システムを通るデータや実行パスを表します。スパンの有向非巡回グラフと考えることができます。
引用:https://www.jaegertracing.io/docs/1.54/architecture/
が、この説明だと少しわかりづらいので、前に例示したシーケンス図でA~Eまでを表現しました。右上の図はシーケンス図の時間軸を右方向にしたものと考えられます。
大雑把に言うと、処理の開始から終了までが「スパン」で、複数のスパンが相互に関連付けられて形成される処理の全体を表したものが「トレース」といったところでしょうか。
アーキテクチャー
Jaegerのアーキテクチャーを以下に示します。
OpenTelemetry SDKを組み込んだアプリケーションが取得したトレースデータをJaeger Collectorが収集して、DBに保存し、Jaeger UIがこれをわかりやすく可視化するような構成になっているようです。デフォルトのストレージはメモリー(in-memory storage)ですが、推奨はOpenSearchまたはElasticsearchです。
類似のOSS
類似のOSSとして以下の2つがあげられます。
- Zipkin
- Apache SkyWalking
Jaeger v.s. Zipkin v.s. Apache SkyWalking
様々な観点から上記3つのOSSを比較してみましょう。
機能の比較
機能の比較については、NRI OpenStandiaのページにまとめられているので、こちらを参照してください。
GitHubのスター数推移
GitHubのスター数推移は以下のようになっています。
先駆者はZipkinで、この人気を後発の2つが抜いたというのが現状でしょうか。
GitHubのコミット数推移(過去5年)
過去5年間のGitHubのコミット数推移は以下のようになっています。
これを見ると、近年はZipkinの開発が停滞しているように見えます。
GitHubのコミット数推移(過去1年)
直近1年間であれば、Apache SkyWalkingJaegerとApache SkyWalkingは同程度に活発な開発が行われていると考えられそうです。
GitHubのコントリビュータ数
意外にも最も歴史のあるZipkinのコントリビュータ数が少ないです。
言語の構成比率
実装されているプログラミング言語の構成比率を見てみましょう。
JaegerがGoで、他の2つはJavaで実装されています。
コードの行数
コードの行数もZipkinが最も少ないです。Apache SkyWalkingのコードの行数の多さは、Java実装であることやドキュメントをプロジェクトに含めていることにも理由があるかもしれません。
ファイル数
ファイルの種類
画面の比較
リクエストのフローを可視化する画面を見比べてみましょう。
- Jaeger
- Zipkin
- Apache SkyWalking
どれもシンプルで洗練されていますが、観測するものが同じであれば見た目は似たような感じになりますね。
動かしてみよう
ここまでの説明で何となく分かりましたが、実際に動かして動作原理を確認してみましょう。この記事では、Jaeger公式ドキュメントのGetting Startedでも紹介されているデモ用のアプリケーション「Hot R.O.D」のトラフィックをJaegerで監視できる構成をDocker Composeで試してみます。Hot R.O.Dは、配車サービスのアプリのようです(Uberが提供するデモアプリなので)。
$ git clone https://github.com/jaegertracing/jaeger
$ cd jaeger/examples/hotrod
$ docker compose up
ちなみに、すでに8080ポートを使用していると、このようなエラーが出るので、ポートが競合するアプリを停止しておくか、docker-compose.yml
に記載されたポート番号を変更しておきましょう。
Attaching to hotrod-1, jaeger-1
jaeger-1 | 2024/02/06 04:27:46 maxprocs: Leaving GOMAXPROCS=4: CPU quota undefined
Gracefully stopping... (press Ctrl+C again to force)
Error response from daemon: Ports are not available: exposing port TCP 0.0.0.0:8080 -> 0.0.0.0:0: listen tcp 0.0.0.0:8080: bind: address already in use
さて、どんなコンテナができるのでしょうか?
$ docker container ls
CONTAINER ID IMAGE COMMAND CREATED STATUS PORTS NAMES
0fa4c01023fa jaegertracing/example-hotrod:latest "/go/bin/hotrod-linu…" 7 minutes ago Up 5 minutes 0.0.0.0:8080->8080/tcp, 0.0.0.0:8083->8083/tcp, 8081-8082/tcp hotrod-hotrod-1
1ac4b5d54935 jaegertracing/all-in-one:latest "/go/bin/all-in-one-…" 7 minutes ago Up 7 minutes 4317/tcp, 5775/udp, 5778/tcp, 9411/tcp, 14250/tcp, 0.0.0.0:4318->4318/tcp, 14268/tcp, 0.0.0.0:16686->16686/tcp, 6831-6832/udp hotrod-jaeger-1
あれ?2つだけです。様々なサービス間で送受信されるリクエストを監視すると思っていたので、少なくともJaeger UIの他に3つくらいはコンテナが起動すると思っていましたが...
docker-compose.yml
を見てみましょう。
version: '3.7'
# To run a specific version of Jaeger, use environment variable, e.g.:
# JAEGER_VERSION=1.52 docker compose up
services:
jaeger:
image: jaegertracing/all-in-one:${JAEGER_VERSION:-latest}
ports:
- "16686:16686"
- "4318:4318"
environment:
- LOG_LEVEL=debug
networks:
- jaeger-example
hotrod:
image: jaegertracing/example-hotrod:${JAEGER_VERSION:-latest}
# To run the latest trunk build, find the tag at Docker Hub and use the line below
# https://hub.docker.com/r/jaegertracing/example-hotrod-snapshot/tags
#image: jaegertracing/example-hotrod-snapshot:0ab8f2fcb12ff0d10830c1ee3bb52b745522db6c
ports:
- "8080:8080"
- "8083:8083"
command: ["all"]
environment:
- OTEL_EXPORTER_OTLP_ENDPOINT=http://jaeger:4318
networks:
- jaeger-example
depends_on:
- jaeger
networks:
jaeger-example:
たしかにサービスは2つだけですね。うーん。
まあ、とりあえずREADME.mdには、以下の2つのアプリにアクセスしろと書いてあるので、アクセスしてみましょう。
Access Jaeger UI at http://localhost:16686 and HotROD app at http://localhost:8080
まずはJaeger UIにアクセスしてみましょう。検索画面が表示されましたが、何もデータが収集されていないので検索結果はありません。
次にデモアプリケーション「Hot R.O.D」にアクセスしてみましょう。
4つボタンがあるので、そのうちの1つをクリックします。クリックすると、タクシーが手配されて、2分後に到着するというメッセージが表示されました。
これにより、Jaeger Collectorがトレースデータを収集し、Jaeger UIで可視化できるようになったのでしょうか?では、Jaeger UIにアクセスしてみましょう。
Hot R.O.Dに送信したリクエストとその処理時間が点で表示されています。
この点をクリックすると、リクエストの処理時間の内訳が表示されました。
これを見ると処理の大半の時間は...ん?MySQLとRedis??
サービス(Dockerコンテナ)はJaegerとHot R.O.Dだけだったはず。どのようにMySQLを利用しているのか「mysql」というキーワードでgrepしてみましょう。
$ grep -ri mysql .
./services/customer/database.go: semconv.PeerServiceKey.String("mysql"),
./services/customer/database.go: if !config.MySQLMutexDisabled {
./services/customer/database.go: delay.Sleep(config.MySQLGetDelay, config.MySQLGetDelayStdDev)
./services/customer/server.go: tracing.InitOTEL("mysql", otelExporter, metricsFactory, logger).Tracer("mysql"),
./services/customer/server.go: logger.With(zap.String("component", "mysql")),
./services/config/config.go: // MySQLGetDelay is how long retrieving a customer record takes.
./services/config/config.go: MySQLGetDelay = 300 * time.Millisecond
./services/config/config.go: // MySQLGetDelayStdDev is standard deviation
./services/config/config.go: MySQLGetDelayStdDev = MySQLGetDelay / 10
./services/config/config.go: // MySQLMutexDisabled controls whether there is a mutex guarding db query execution.
./services/config/config.go: MySQLMutexDisabled = false
./cmd/root.go: if config.MySQLGetDelay != fixDBConnDelay {
./cmd/root.go: logger.Info("fix: overriding MySQL query delay", zap.Duration("old", config.MySQLGetDelay), zap.Duration("new", fixDBConnDelay))
./cmd/root.go: config.MySQLGetDelay = fixDBConnDelay
./cmd/root.go: config.MySQLMutexDisabled = true
./cmd/flags.go: cmd.PersistentFlags().DurationVarP(&fixDBConnDelay, "fix-db-query-delay", "D", 300*time.Millisecond, "Average latency of MySQL DB query")
うーん、この結果から判断すると、MySQLに接続してSQLを発行しているようには見えませんね。delay.Sleep
というのが気になります。database.go
の実装を見てみましょう。
// simulate RPC delay
delay.Sleep(config.MySQLGetDelay, config.MySQLGetDelayStdDev)
「simulate RPC delay」。2つの引数はconfig.go
の以下の2行で
// MySQLGetDelay is how long retrieving a customer record takes.
// Using large value mostly because I cannot click the button fast enough to cause a queue.
MySQLGetDelay = 300 * time.Millisecond
// MySQLGetDelayStdDev is standard deviation
MySQLGetDelayStdDev = MySQLGetDelay / 10
この関数を呼び出しているということは、
// Sleep generates a normally distributed random delay with given mean and stdDev
// and blocks for that duration.
func Sleep(mean time.Duration, stdDev time.Duration) {
fMean := float64(mean)
fStdDev := float64(stdDev)
delay := time.Duration(math.Max(1, rand.NormFloat64()*fStdDev+fMean))
time.Sleep(delay)
}
MySQLにSQLを発行する代わりに、300ミリ秒程度の遅延を発生させているということのようです。だから、コンテナが存在しないMySQLの処理があったわけですね。
では、どのように処理時間を取得したのでしょう?Jaegerの画面を見てみると、処理の概要を示す「SQL SELECT」と表示されていますね。
おそらく、これを含むコードがあるのでしょう。grepしてみます。
$ grep "SQL SELECT" . -r
./services/customer/database.go: ctx, span := d.tracer.Start(ctx, "SQL SELECT", trace.WithSpanKind(trace.SpanKindClient))
ありました。ではdatabase.go
の実装を見てみましょう。
func (d *database) Get(ctx context.Context, customerID int) (*Customer, error) {
d.logger.For(ctx).Info("Loading customer", zap.Int("customer_id", customerID))
ctx, span := d.tracer.Start(ctx, "SQL SELECT", trace.WithSpanKind(trace.SpanKindClient))
span.SetAttributes(
semconv.PeerServiceKey.String("mysql"),
attribute.
Key("sql.query").
String(fmt.Sprintf("SELECT * FROM customer WHERE customer_id=%d", customerID)),
)
defer span.End()
if !config.MySQLMutexDisabled {
// simulate misconfigured connection pool that only gives one connection at a time
d.lock.Lock(ctx)
defer d.lock.Unlock()
}
// simulate RPC delay
delay.Sleep(config.MySQLGetDelay, config.MySQLGetDelayStdDev)
if customer, ok := d.customers[customerID]; ok {
return customer, nil
}
return nil, errors.New("invalid customer ID")
}
なるほど、ctx, span := d.tracer.Start(ctx, "SQL SELECT", trace.WithSpanKind(trace.SpanKindClient))
でスパンを開始し、この関数の処理が完了すると、defer span.End()
により、スパンも終了するということのようです。以下の"go.opentelemetry.io/otel/trace"
からわかるように、OpenTelemetryのAPIを使用して、実現しているようです。
import (
"context"
"errors"
"fmt"
"go.opentelemetry.io/otel/attribute"
semconv "go.opentelemetry.io/otel/semconv/v1.24.0"
"go.opentelemetry.io/otel/trace"
"go.uber.org/zap"
"github.com/jaegertracing/jaeger/examples/hotrod/pkg/delay"
"github.com/jaegertracing/jaeger/examples/hotrod/pkg/log"
"github.com/jaegertracing/jaeger/examples/hotrod/pkg/tracing"
"github.com/jaegertracing/jaeger/examples/hotrod/services/config"
)
// database simulates Customer repository implemented on top of an SQL database
type database struct {
tracer trace.Tracer
logger log.Factory
customers map[int]*Customer
lock *tracing.Mutex
}
MySQLの処理に対するスパンの実装方法はわかりました。その上位にある「mysql」やさらにその上の「customer」はどのようなコードで実現しているのでしょうか。
「mysql」でgrepしてみましょう。
$ grep mysql . -r
./services/customer/database.go: semconv.PeerServiceKey.String("mysql"),
./services/customer/server.go: tracing.InitOTEL("mysql", otelExporter, metricsFactory, logger).Tracer("mysql"),
./services/customer/server.go: logger.With(zap.String("component", "mysql")),
tracing.InitOTE()
でしょうか。
$ grep -ri tracing.InitOTEL .
./services/customer/server.go: tracer: tracing.InitOTEL("customer", otelExporter, metricsFactory, logger),
./services/customer/server.go: tracing.InitOTEL("mysql", otelExporter, metricsFactory, logger).Tracer("mysql"),
./services/driver/server.go: tracerProvider := tracing.InitOTEL("driver", otelExporter, metricsFactory, logger)
./services/driver/redis.go: tp := tracing.InitOTEL("redis-manual", otelExporter, metricsFactory, logger)
./cmd/route.go: tracing.InitOTEL("route", otelExporter, metricsFactory, logger),
./cmd/frontend.go: tracing.InitOTEL("frontend", otelExporter, metricsFactory, logger),
「mysql」の他に「customer」、「driver」、「redis-manual」...とあるので、このコードのようです。実装を詳しく見てみましょう。
// NewServer creates a new customer.Server
func NewServer(hostPort string, otelExporter string, metricsFactory metrics.Factory, logger log.Factory) *Server {
return &Server{
hostPort: hostPort,
tracer: tracing.InitOTEL("customer", otelExporter, metricsFactory, logger),
logger: logger,
database: newDatabase(
tracing.InitOTEL("mysql", otelExporter, metricsFactory, logger).Tracer("mysql"),
logger.With(zap.String("component", "mysql")),
),
}
}
customer
というスパンの中にmysql
のスパンがあることを定義しているようです。
以上のように、アプリケーションの中にOpenTelemetry SDKのコードを組み込んで、トレースデータを取得しているようです。実装方法の詳細についてはこの記事は触れませんが、このデモアプリケーションを動かしながら、公式ドキュメントを読み進めれば、理解が進むのではないかと思います。
なお、以下のOpenTelemetry Instrumentationを使用すれば、アプリケーションの中にコードを追加しなくても、既存アプリにバイトコードを動的に注入できるようです。
そのあたりについては、Jaegerに興味がある人が多そうであれば次回に。