背景
約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の分散トレーシングシステムを使ってみてはいかがでしょうか。