はじめに
最近Kubernetes上に自作のアプリケーションをデプロイすることが多いのですが、思ったよりパフォーマンスが出なくてボトルネックを調査しようとした時に、サーバにsshで入ってプロファイラを起動して遅い処理を特定するといったことが気軽にできず困ったことがありました。
またVMでアプリケーション開発をしているときよりもサービスのコンポーネントも細かく別れているので、今までのようなアプローチではボトルネックの調査に時間がかかってしまうと思います。
細かくわかれたサービス全体の振る舞いを把握したり、パフォーマンス分析するための分散トレーシングのOSSがいくつか出ているので、そちらを利用してKubernetes上にデプロイしたGoのアプリケーションの分析してみたいと思います。
環境
アプリケーション
https://github.com/amber-lamp/opencensus-sample
実行環境
Docker for MacのKubernetes連携の機能を利用して構築したローカルのKubernetesクラスタ
トレーシングツール
今回はCNCFでホストされているJaegerを使います。
Jaegerとは
概要
Dapperと OpenZipkinに影響を受けてUber Technologiesで開発されたOSSの分散トレーシングシステムです。
マイクロサービスのモニタリングやトラブルシューティングに利用されます。
具体的には下記のようなことができるようです。
- 分散コンテキストの伝播
- 分散トランザクションの監視
- 根本原因の分析
- サービス依存関係の分析
- パフォーマンス/レイテンシの最適化
OpenTracingというプロジェクトで標準仕様が定められており、それに準拠する形で各言語のclientライブラリが用意されています。Goの場合はjaeger-client-goというライブラリを使えばよさそうです。
一方でOpenCensusという「サービスのメトリクスと分散トレースを取得するためのライブラリ群」も存在していて、OpenCensusにもJaegerにトレース情報を送るためのexporterが存在しています。
この２つのプロジェクトは統合されるようですし、Jaeger以外のバックエンド(例えばDatadogとかStackdriver等)のexporterも用意されていて、複数のバックエンドへの送信や切り替えも簡単そうですので今回はOpenCensusのJaeger用のexpoterを使ってJaegerにデータを送信するようにしてみたいと思います。
アーキテクチャ
Jaegerのアーキテクチャの全体は下記のようになっています。
参考：https://www.jaegertracing.io/docs/1.12/architecture/
アーキテクチャの説明の前に用語の説明をしたいと思います。
分散トレーシングではSpanという処理の開始時間と終了時間をもつ論理的な単位と、関係するSpanの集合の最初から最後までの集合であるTraceというものがあります。
SpanとTraceの関係については下記の図がわかりやすいと思います。
参考：https://www.jaegertracing.io/docs/1.8/architecture/#terminology
ではアーキテクチャの各コンポーネントについて見ていきたいと思います。
jaeger-agent
Spanの情報を定期的にjaeger-collectorに送るためのデーモンです。
情報を収集するすべてのホストにデプロイされるようになっており、送信先であるjaeger-collectorを見つけて情報を送信する部分を抽象化してくれます。
jaeger-collector
jaeger-agentから送られてきた情報にindexをつけるなどの変換処理をしてデータストアに保存するためのコンポーネントです。
jaeger-query
データストアに保存されているTrace情報を取得してUIに表示させるためのコンポーネントです。
やってみる
Jaegerの構築
では実際に環境を構築してみたいと思います。
今回はローカルのKubernetesクラスタを使うので、jaeger-kubernetesというKubernetes上でJaegerを構築するためのKubernetesのマニフェストファイルを利用します。
上記とは別にKubernetes Operatorも用意されているので、Kubernetes上に環境を構築するハードルは低そうです。
jaeger-collectorとjaeger-queryが更新/参照するためのデータストアが必要なので、KubernetesのマニフェストファイルとしてCassandraとElasticsearch用のマニフェストが用意されています。
Cassandra用
$ kubectl create -f https://raw.githubusercontent.com/jaegertracing/jaeger-kubernetes/master/production/configmap.yml
$ kubectl create -f https://raw.githubusercontent.com/jaegertracing/jaeger-kubernetes/master/production/cassandra.yml
Elasticsearch用
$ kubectl create -f https://raw.githubusercontent.com/jaegertracing/jaeger-kubernetes/master/production-elasticsearch/configmap.yml
$ kubectl create -f https://raw.githubusercontent.com/jaegertracing/jaeger-kubernetes/master/production-elasticsearch/elasticsearch.yml
テストや開発用としてデータをインメモリに保存するall-in-one-templateというマニフェストファイルも用意されています。今回は検証用として、こちらを利用してみたいと思います。
$ kubectl create -f https://raw.githubusercontent.com/jaegertracing/jaeger-kubernetes/master/all-in-one/jaeger-all-in-one-template.yml
上記のall-in-one-templateをKubernetesクラスタ上にデプロイすると下記の通りリソースが作成されます。
deployment.extensions/jaeger created
service/jaeger-query created
service/jaeger-collector created
service/jaeger-agent created
service/zipkin created
all-in-one-templateのマニフェストを元に作成されたKubernetesのServiceを確認してみます。
TYPEの列がLoadBalancerとなっているjaeger-queryというServiceがあるのでこちらに対してブラウザでアクセスしてみます。
$ kubectl get service
NAME TYPE CLUSTER-IP EXTERNAL-IP PORT(S) AGE
jaeger-agent ClusterIP None <none> 5775/UDP,6831/UDP,6832/UDP,5778/TCP 32m
jaeger-collector ClusterIP 10.100.80.4 <none> 14267/TCP,14268/TCP,9411/TCP 32m
jaeger-query LoadBalancer 10.99.72.71 localhost 80:30762/TCP 32m
zipkin ClusterIP None <none> 9411/TCP 32m
ブラウザからhttp://localhost:80にアクセスすると下記の通りJaegerのUIが表示されることが確認できます。
jaeger-agent,jaeger-collector,jaeger-query,UIなどの各コンポーネントがKubernetesクラスタ上でどのような構成になっているかというと、全て１つのDeploymentにまとまっているようです。
$ kubectl get deployment
NAME DESIRED CURRENT UP-TO-DATE AVAILABLE AGE
jaeger 1 1 1 1 10m
参考：https://www.jaegertracing.io/docs/1.8/getting-started/#all-in-one
all-in-one-templateをKubernetesクラスタ上にデプロイするだけで、準備が整いましたので、あとはアプリケーションのトレース情報をjaeger-agentに送れば上記のUIで確認することができそうです。
アプリケーション側の設定
設定はopencensus-go-exporter-jaegerのexampleを参考に行います。
ソースコードの全体はgithubにpushしてありますので、下記のレポジトリを適宜参照してください。
https://github.com/amber-lamp/opencensus-sample
最初に下記の２つのパッケージをimportしてください。
import (
~~省略~~
"contrib.go.opencensus.io/exporter/jaeger"
"go.opencensus.io/trace"
)
main関数でexporterとsamplerの設定をしています。
jaeger.OptionsのAgentEndpointにjaeger-agentのKubernetesのService名とportを指定しています。
また、trace.ApplyConfigの部分でDefaultSamplerにtrace.AlwaysSample()を設定しています。今回は検証のためアクセスした情報を全てサンプルとして取得してUIに表示する設定にしています。
func main() {
exporter, err := jaeger.NewExporter(jaeger.Options{
AgentEndpoint: "jaeger-agent:6831",
Process: jaeger.Process{
ServiceName: "demo",
},
})
if err != nil {
log.Fatal(err)
}
defer exporter.Flush()
trace.RegisterExporter(exporter)
trace.ApplyConfig(trace.Config{DefaultSampler: trace.AlwaysSample()})
log.Println("Start demo server...")
http.HandleFunc("/", handler)
log.Fatal(http.ListenAndServe(":8080", nil))
}
handler関数の中でSpanを開始しています。第１引数にcontextを第２引数にSpanを識別する文字を入れています。
func handler(w http.ResponseWriter, r *http.Request) {
ctx, span := trace.StartSpan(context.Background(), "/handler")
defer span.End()
omikuji := omikuji(ctx)
fmt.Fprintf(w, "運勢は[%s]です", omikuji)
}
最後にhandler関数呼ばれているomikuji関数を見てみます。
trace.StartSpanの第１引数にhandler関数でSpanを開始したときの戻り値のcontextを設定しています。
このようにすることでJaegerのUIで見たときにomikuji関数で開始したSpanがhandlerのSpanの子Spanのように表示されます。
また関数の下の方にchildSpan.Annotateとありますが、これでSpanにアノテーションを付けることができます。
omikuji関数をよく見ると"凶"のときだけ1秒スリープしていて処理時間が長くなっているのですが、おみくじの結果と結果に対応するメッセージをアノテーション情報として付与することで、どの条件の時に処理が遅いのか、JaegerのUI上で見た時に判断をすることができるようになります。
func omikuji(ctx context.Context) string{
_, childSpan := trace.StartSpan(ctx, "/omikuji")
defer childSpan.End()
t := time.Now()
var omikuji string
var msg string
if (t.Month() == 1 && t.Day() >= 1 && t.Day() <= 3){
omikuji = "大吉"
msg = "お正月は大吉"
} else {
t := t.UnixNano()
rand.Seed(t)
s := rand.Intn(6)
switch s + 1 {
case 1:
omikuji = "凶"
msg = "残念でした"
time.Sleep(time.Second)
case 2, 3:
omikuji = "吉"
msg = "そこそこでした"
case 4, 5:
omikuji = "中吉"
msg = "まあまあでした"
case 6:
omikuji = "大吉"
msg = "いいですね"
}
}
childSpan.Annotate([]trace.Attribute{
trace.StringAttribute("omikuji", omikuji),
}, msg)
return omikuji
}
では作成したアプリケーションをKubernetes上にデプロイしてどのようになるか見てみます。
作成したGoのアプリケーションはDockerHubにpushしてありますので、ローカルのKubernetesクラスタにデプロイします。
本来はKubernetesのマニフェストファイルからデプロイした方が良いですが、ここではkubectl runコマンドでデプロイを実施します。
$ kubectl run opencensus-sample --image=yuuyamad/opencensus-sample:latest
kubectl get podsコマンドでデプロイしたPodが起動していることを確認します。
全てRunningになっているので上手く行っているようです。
$ kubectl get pods
NAME READY STATUS RESTARTS AGE
jaeger-796dcb98cb-xjj26 1/1 Running 0 7m
opencensus-sample-6996b4f94b-pfskk 1/1 Running 0 39s
Kubernetesクラスタ上にデプロイされたアプリケーションにアクセスするにはServiceやIngress等のLBの機能を利用してクラスタの外部からアクセスするのが普通ではありますが、ここではPortForwardをして直接Podにアクセスして確認を行います。
$ kubectl port-forward deployment/opencensus-sample 8080 8080
上記のコマンドでPodの8080番ポートにlocalhostの8080番ポートからPortForwardした状態でlocalhost:8080にアクセスすると今回サンプルで作成したおみくじアプリケーションが動いていることが確認できるかと思います。
では何度かアプリケーションにアクセスしてからJaegerのUIを確認してみましょう。
ServiceのプルダウンでdemoというServiceが選べるようになるので選択して「Find Traces」ボタンを押してください。下記のような画面が確認できると思います。
表示された検索結果の中から１つを選んでクリックすると下記のような画面が表示されます。
/handlerと/omikujiのSpanが表示されています。/omikujiのSpanを展開してLogsを部分を見ると、omikuji関数で設定したアノテーションの情報を見ることができるので、おみくじの結果が凶の時に処理に1秒かかっていることを確認することができます。
まとめ
分散トレーシングのOSSのJaegerを使ってGoのアプリケーションを分析してみました。
今回は1つのサービスのトレーシングをしただけではありますが、複数のサービスにまたがるような場合も同様にトレーシングを行えるようなので、Microservicesアーキテクチャで構築されたシステムを運用していく上では必須の技術なのではと感じました。