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

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

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

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

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

![Screen Shot 2020-12-04 at 6.31.47.png](https://qiita-image-store.s3.ap-northeast-1.amazonaws.com/0/112715/75ac4742-3f75-2157-9071-fc71b37f8ea7.png)
[Architecture — Jaeger documentation](https://www.jaegertracing.io/docs/1.8/architecture/#span)


# Jaegerとは
![jaeger-logo.png](https://qiita-image-store.s3.ap-northeast-1.amazonaws.com/0/112715/dc27bd1c-822e-09d1-3719-aa5db3005040.png)

[CNCF(Cloud Native Computing Foundation)](https://www.cncf.io/projects/)の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環境で構築していきます。

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

# インストール
公式には [jaeger-kubernetes](https://github.com/jaegertracing/jaeger-kubernetes) と [jaeger-operator](https://github.com/jaegertracing/jaeger-operator) の2種類がありますが、前者はアーカイブされていて開発が止まっているので、後者を使います。

前提として、[ingress-controller](https://kubernetes.github.io/ingress-nginx/deploy/#docker-for-mac)がデプロイされている必要があります。

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

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

```terminal
$ 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インスタンスを作成します。

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

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

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

これにより、http://localhost でJaegerUIにアクセスできます。
![screencapture-localhost-search-2020-12-03-15_58_58.png](https://qiita-image-store.s3.ap-northeast-1.amazonaws.com/0/112715/6b88bae6-6230-e3b1-a786-9b645e262d85.png)

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

# 実装
公式の [サンプルコード](https://github.com/jaegertracing/jaeger-client-go/blob/master/config/example_test.go) を参考にして、Tracerを実装します。

### ライブラリのインストール
```terminal
$ go get -u github.com/uber/jaeger-client-go
$ go get -u github.com/grpc-ecosystem/grpc-opentracing
```

### Tracerの初期化
```go
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のコールバックを実装します。


```go
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接続時に実行します。


```go
// 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**として記録されるようになります。

```go
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](https://github.com/jaegertracing/jaeger-client-go#initialization)によると、以下の3つの環境変数を使用するようです。

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

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

```go
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`は適切な値を設定する必要があります。
何を設定すべきか、調べてみましょう。

```terminal
$ 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を作成することにします。

```terminal
$ 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が表示されました。

![screencapture-localhost-trace-2b466f13c0967956-2020-12-04-06_05_33.png](https://qiita-image-store.s3.ap-northeast-1.amazonaws.com/0/112715/83f07d07-2141-bf6a-046d-6bba1074400d.png)


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