分散トレーシングシステムのJaegerをKubernetes環境に導入する

背景

約1年前に分散トレーシングシステムの DatadogAPM (Application Performance Monitoring)を導入したのですが、高級な機能なため、先月この機能の利用をやめることにしました。
そこで代わりとなるツールの内、**Jaeger**を検証も兼ねて環境構築したので、手順などをまとめることにしました。

今回はgRPC ServerをGoで実装し、Kubernetesにデプロイします。
また、ORMのgormを使って、sqlごとにspanを記録するための実装も紹介します。

分散トレーシングとは

分散トレーシングは、マイクロサービスなどのアプリケーションの監視やトラブルシューティングなどに使用される方法です。障害が発生した場所とパフォーマンスの低下の原因を特定するのに役立ちます。

分散トレーシングには、主にTraceとSpanという概念があります。
Spanは、1回のsqlの実行や、1回の外部へのリクエストなど、各操作の開始から終了を表します。
Traceは、全体の開始から終了までのSpanの集合です。
以下の図を見ると、イメージしやすいと思います。

Architecture — Jaeger documentation

Jaegerとは

CNCF(Cloud Native Computing Foundation)のGraduatedプロジェクト。

公式には以下のように書かれています。

Jaeger, inspired by Dapper and OpenZipkin, is a distributed tracing system released as open source by Uber Technologies. It is used for monitoring and troubleshooting microservices-based distributed systems, including:
・Distributed context propagation
・Distributed transaction monitoring
・Root cause analysis
・Service dependency analysis
・Performance / latency optimization

マイクロサービスベースの分散システムの監視、トラブルシューティング、パフォーマンス/レイテンシーの最適化などに利用されているようです。Uberが開発したみたいですね。

環境

Docker for Macを用いて、以下のKubernetes環境で構築していきます。

$ kubectl version --short
Client Version: v1.17.4
Server Version: v1.18.8

インストール

公式には jaeger-kubernetes と jaeger-operator の2種類がありますが、前者はアーカイブされていて開発が止まっているので、後者を使います。

前提として、ingress-controllerがデプロイされている必要があります。

$ kubectl apply -f https://raw.githubusercontent.com/kubernetes/ingress-nginx/controller-v0.41.2/deploy/static/provider/cloud/deploy.yaml

次に、Jaeger Operatorをインストールしていきます。

$ kubectl create namespace observability
$ kubectl create -n observability -f https://raw.githubusercontent.com/jaegertracing/jaeger-operator/master/deploy/crds/jaegertracing.io_jaegers_crd.yaml
$ kubectl create -n observability -f https://raw.githubusercontent.com/jaegertracing/jaeger-operator/master/deploy/service_account.yaml
$ kubectl create -n observability -f https://raw.githubusercontent.com/jaegertracing/jaeger-operator/master/deploy/role.yaml
$ kubectl create -n observability -f https://raw.githubusercontent.com/jaegertracing/jaeger-operator/master/deploy/role_binding.yaml
$ kubectl create -n observability -f https://raw.githubusercontent.com/jaegertracing/jaeger-operator/master/deploy/operator.yaml

次に、Jaegerインスタンスを作成します。

$ kubectl apply -n observability -f - <<EOF
apiVersion: jaegertracing.io/v1
kind: Jaeger
metadata:
  name: simplest
EOF

しばらく待ってから以下のコマンドを実行し、JaegerUIのアクセス情報を取得します。

$ kubectl get -n observability ingress
NAME             CLASS    HOSTS   ADDRESS     PORTS   AGE
simplest-query   <none>   *       localhost   80      74m

これにより、http://localhost でJaegerUIにアクセスできます。

この画面が表示できたら、JaegerUIの構築は完了です。

実装

公式の サンプルコード を参考にして、Tracerを実装します。

ライブラリのインストール

$ go get -u github.com/uber/jaeger-client-go
$ go get -u github.com/grpc-ecosystem/grpc-opentracing

Tracerの初期化

package main

import (
	"io"

	"github.com/grpc-ecosystem/grpc-opentracing/go/otgrpc"
	"github.com/opentracing/opentracing-go"
	jaegercfg "github.com/uber/jaeger-client-go/config"
	jaegerlog "github.com/uber/jaeger-client-go/log"
	"github.com/uber/jaeger-lib/metrics"
	"google.golang.org/grpc"
)

func main() {
	closer, err := startJaegerTracer()
	if err != nil {
		panic(err)
	}
	defer closer.Close()

	s := grpc.NewServer(
		grpc.UnaryInterceptor(
			otgrpc.OpenTracingServerInterceptor(opentracing.GlobalTracer()),
		),
	)

	// continue main()
}

func startJaegerTracer() (io.Closer, error) {
	cfg, err := jaegercfg.FromEnv()
	if err != nil {
		return nil, err
	}

	tracer, closer, err := cfg.NewTracer(jaegercfg.Logger(jaegerlog.StdLogger), jaegercfg.Metrics(metrics.NullFactory))
	if err != nil {
		return nil, err
	}

	opentracing.SetGlobalTracer(tracer)
	return closer, nil
}

環境変数から必要な値を取得し、Tracerを初期化します。opentracing.SetGlobalTracerに渡すことで、シングルトンとして保持できます。
また、grpc.UnaryInterceptorに、Spanを開始するための関数を渡します。

gormの実装

各sqlの開始と終了でSpanが記録されるようにする必要があるので、gormのコールバックを実装します。

package database

import (
	"strings"

	"github.com/jinzhu/gorm"
	"github.com/opentracing/opentracing-go"
	"github.com/opentracing/opentracing-go/ext"
)

const (
	parentSpanGormKey = "opentracingParentSpan"
	spanGormKey       = "opentracingSpan"
)

func WithCallbacks(db *gorm.DB) {
	afterFunc := func(operation string) func(*gorm.Scope) {
		return func(scope *gorm.Scope) {
			after(scope, operation)
		}
	}

	db.Callback().Create().Before("gorm:create").Register("tracing:create_before", before)
	db.Callback().Create().After("gorm:create").Register("tracing:create_after", afterFunc("gorm.create"))
	db.Callback().Update().Before("gorm:update").Register("tracing:update_before", before)
	db.Callback().Update().After("gorm:update").Register("tracing:update_after", afterFunc("gorm.update"))
	db.Callback().Delete().Before("gorm:delete").Register("tracing:delete_before", before)
	db.Callback().Delete().After("gorm:delete").Register("tracing:delete_after", afterFunc("gorm.delete"))
	db.Callback().Query().Before("gorm:query").Register("tracing:query_before", before)
	db.Callback().Query().After("gorm:query").Register("tracing:query_after", afterFunc("gorm.query"))
	db.Callback().RowQuery().Before("gorm:row_query").Register("tracing:row_query_before", before)
	db.Callback().RowQuery().After("gorm:row_query").Register("tracing:row_query_after", afterFunc("gorm.row_query"))
}

func before(scope *gorm.Scope) {
	v, ok := scope.Get(parentSpanGormKey)
	if !ok {
		return
	}
	parentSpan := v.(opentracing.Span)
	tr := parentSpan.Tracer()
	sp := tr.StartSpan("sql", opentracing.ChildOf(parentSpan.Context()))
	ext.DBType.Set(sp, "sql")
	scope.Set(spanGormKey, sp)
}

func after(scope *gorm.Scope, operation string) {
	v, ok := scope.Get(spanGormKey)
	if !ok {
		return
	}
	sp := v.(opentracing.Span)
	if operation == "" {
		operation = strings.ToUpper(strings.Split(scope.SQL, " ")[0])
	}
	ext.Error.Set(sp, scope.HasError())
	ext.DBStatement.Set(sp, scope.SQL)
	sp.SetTag("db.table", scope.TableName())
	sp.SetTag("db.method", operation)
	sp.SetTag("db.err", scope.HasError())
	sp.SetTag("db.count", scope.DB().RowsAffected)
	sp.Finish()
}

この WithCallbacksをDB接続時に実行します。

// ConnectDB connects to mysql.
func ConnectDB() *gorm.DB {
	db, err := gorm.Open("mysql", "root:password@tcp(db)/innovators?charset=utf8mb4&parseTime=True&loc=UTC")
	if err != nil {
		panic(err.Error())
	}

	database.WithCallbacks(db)

	return db
}

最後に、各APIでgormのDBインスタンスに親のSpanをセットします。
親のSpanは、先ほどのgRPCのInterceptorで、コンテキストから取得できるようになっています。
これによって、クエリ1つ1つが子のSpanとして記録されるようになります。

package database

func SetSpan(ctx context.Context, db *gorm.DB) *gorm.DB {
	if ctx == nil {
		return db
	}

	parentSpan := opentracing.SpanFromContext(ctx)
	if parentSpan == nil {
		return db
	}

	return db.Set(parentSpanGormKey, parentSpan)
}

環境変数

Jaeger Client Go Initializationによると、以下の3つの環境変数を使用するようです。

変数名	説明
JAEGER_SERVICE_NAME	サービス名
JAEGER_AGENT_HOST	JaegerAgentのホスト名。デフォルトlocalhost
JAEGER_AGENT_PORT	JaegerAgentのポート。デフォルト6831

また、jaegercfg.FromEnv()の実装を見ると、これらの環境変数を読み込むようになっています。

const (
	// environment variable names
	envServiceName                         = "JAEGER_SERVICE_NAME"
	envAgentHost                           = "JAEGER_AGENT_HOST"
	envAgentPort                           = "JAEGER_AGENT_PORT"
)

// FromEnv uses environment variables and overrides existing tracer's Configuration
func (c *Configuration) FromEnv() (*Configuration, error) {
	if e := os.Getenv(envServiceName); e != "" {
		c.ServiceName = e
	}

	// 省略

	if r, err := c.Reporter.reporterConfigFromEnv(); err == nil {
		c.Reporter = r
	} else {
		return nil, errors.Wrap(err, "cannot obtain reporter config from env")
	}

	// 省略
}

// reporterConfigFromEnv creates a new ReporterConfig based on the environment variables
func (rc *ReporterConfig) reporterConfigFromEnv() (*ReporterConfig, error) {
	// 省略

	useEnv := false
	host := jaeger.DefaultUDPSpanServerHost
	if e := os.Getenv(envAgentHost); e != "" {
		host = e
		useEnv = true
	}

	port := jaeger.DefaultUDPSpanServerPort
	if e := os.Getenv(envAgentPort); e != "" {
		if value, err := strconv.ParseInt(e, 10, 0); err == nil {
			port = int(value)
			useEnv = true
		} else {
			return nil, errors.Wrapf(err, "cannot parse env var %s=%s", envAgentPort, e)
		}
	}
	if useEnv || rc.LocalAgentHostPort == "" {
		rc.LocalAgentHostPort = fmt.Sprintf("%s:%d", host, port)
	}

	// 省略
}

というわけで、環境変数を設定していきます。
JAEGER_SERVICE_NAMEは何でも構いません。私が所属しているプロジェクトは VISITS innovatorsという名前なので、これを設定します。

JAEGER_AGENT_HOST と JAEGER_AGENT_PORTは適切な値を設定する必要があります。
何を設定すべきか、調べてみましょう。

$ kubectl get svc -n observability
NAME                          TYPE        CLUSTER-IP       EXTERNAL-IP   PORT(S)                                  AGE
jaeger-operator-metrics       ClusterIP   10.106.87.188    <none>        8383/TCP,8686/TCP                        115m
simplest-agent                ClusterIP   None             <none>        5775/UDP,5778/TCP,6831/UDP,6832/UDP      115m
simplest-collector            ClusterIP   10.107.219.132   <none>        9411/TCP,14250/TCP,14267/TCP,14268/TCP   115m
simplest-collector-headless   ClusterIP   None             <none>        9411/TCP,14250/TCP,14267/TCP,14268/TCP   115m
simplest-query                ClusterIP   10.105.33.225    <none>        16686/TCP                                115m

simplest-agent がJaeger Agent用のServiceです。
ただし、アプリケーションのPodとは別のNamespaceなので、JAEGER_AGENT_HOST は simplest-agent.observabilityになります。
ポートはデフォルトのまま(6831)で問題ありません。

アプリケーションの都合上、Secretを作成することにします。

$ kubectl create secret generic env-secret \
    --from-literal=JAEGER_SERVICE_NAME='VISITS innovators' \
    --from-literal=JAEGER_AGENT_HOST='simplest-agent.observability' \
    --from-literal=JAEGER_AGENT_PORT=6831

動作確認

アプリケーションを起動し、適当にAPIを叩いてみました。
すると、JaegerUIでは以下のように、TraceやSpanが表示されました。

まとめ

あるAPIのレイテンシが長いとき、どこに原因があるのか特定するために、分散トレーシングシステムは有効と言えるでしょう。実際、私のプロジェクトでも、パフォーマンスの悪いクエリが実行され、異様に長いSpanが記録されたことで、原因の特定および修正を迅速に行えた実績があります。
Jaegerは公式ドキュメントも充実していますし、導入コストも割と低い気がします。
いきなり有料のツールを使うのではなく、まずはJaegerのようなOSSの分散トレーシングシステムを使ってみてはいかがでしょうか。