GoのEchoでJaegerを使ってボトルネックを調査する

この記事は1960文字で約5分で読めます

Goの勉強をしておかないと社内でニートになってしまうので、お勉強を兼ねてGoのWebフレームワークのEchoを使ったアプリケーションを作成中です。

そのなかでボトルネック調査をする必要があったので、Opentracing形式のトレースアプリケーションであるJaegerをローカル環境で使ってみたいと思います。

そもそもEchoとは？
- はやい
- 公式ドキュメントが優秀
jaegerとは？
jaeger tracing
child spanを記録する
jaegerで結果を見る
結論

そもそもEchoとは？

EchoとはGoのWAF(Web Framework)です。

特徴として公式によると、High performanceでextensibleでminimalistな Go web frameworkだそうです。

よくわかりませんね。ちょっと特徴を洗い出してみます。

はやい

Goのなかでもパフォーマンスがいいと言われているGinに比べても十分な速度がでていることが公式のGitHubにのってました。

Ginより早いならEcho使っておけばええんや！と思いますが、

GitHubレポジトリのスター数はEchoは16.1k, Ginは34.4kとGinの方が人気なのは間違いありませんので、プロジェクトによって見極める必要はありそうです。

また、Goの場合は標準のnet/httpライブラリがそこそこ優秀なので簡単なAPI作成であればWAF不要論もあります。

公式ドキュメントが優秀

Echoの場合、Ginに比べて公式のドキュメントが充実しているような気がしました。気のせいかもしれません。

Ginの方はドキュメントにDISQUSのコメント欄があります。これはいいアイディアですね。

Echoの公式ドキュメント

Ginの公式ドキュメント

さて、Echoがいいという話はこんなところにして早速jaegerの実装してみます。

jaegerとは？

jeagerはUber Technologies Inc.がOSSとして公開した分散トレーシングシステムです。

マイクロサービスなアーキテクチャを横串で監視できる強みとGo, Java, Node, Python, C++ でクライアントが提供されていることが魅力です。

また、トレーシングの結果収集もOpenTracingとしてドキュメントがありますので、別言語にも移植できそうです。

(Nimに移植しますかね・・・。)

ともかく、かっこいいですね。今回はマイクロサービスな作り方をしていないので、そこまでかっこよくはなりませんが、さっそく使っていきましょう!

jaeger tracing

Jaegerの実装と関係ないコードは省いてます。

まずは、main.go エントリーポイントから、

// main.go

package main

import (
	"github.com/labstack/echo/v4"
	"github.com/tubone24/what-is-your-color/handler"
	"github.com/labstack/echo-contrib/jaegertracing"
)

func main() {
	e := echo.New()
	c := jaegertracing.New(e, nil)
	defer c.Close()

	e.GET("/get/:username", handler.GetColor())

	log.Fatal(e.Start(":9090"))
}

echo.New()したあとに、echo-contribで提供されているjaegerteacingを呼びます。

これだけで、各APIの呼び出しをrouterごとに記録できるようになっています。簡単ですね！便利ですね！

child spanを記録する

さらにAPI内部の動き、例えばDBの書き込みスピードなどを計測する場合にはchild spanという機能を使うことで実現できます。

/get/:usernameというAPIのハンドラーを見てみます。

package handler

import (
	"github.com/labstack/echo-contrib/jaegertracing"
	"github.com/labstack/echo/v4"
	"net/http"

	"github.com/tubone24/what-is-your-color/api"
)

func GetColor() echo.HandlerFunc {
	return func(c echo.Context) error {
		username := c.Param("username")
		github := &api.GitHub{Client: &api.GithubClientImpl{}}
		sp := jaegertracing.CreateChildSpan(c, "Call API")
		defer sp.Finish()
		sp.SetBaggageItem("Func", "GetColor")
		sp.SetTag("Func", "GetColor")
		err, langs := github.DoGetColor(username)
		if err != nil {
			return echo.NewHTTPError(http.StatusInternalServerError, "Internal Error")
		}
		return c.JSON(http.StatusOK, langs)
	}
}

このコード例では、GitHubのAPIからの結果をgithub.DoGetColor(username) で取得していますが、手前でCreateChildSpan でchildspanを指定してます。

jaegerで結果を見る

jaegerを起動します。起動には公式ドキュメントにのっているall-in-one dockerを使います。(あらかじめDockerコンテナが動く環境を作っておきます。)

docker run -d --name jaeger \
  -e COLLECTOR_ZIPKIN_HTTP_PORT=9411 \
  -p 5775:5775/udp \
  -p 6831:6831/udp \
  -p 6832:6832/udp \
  -p 5778:5778 \
  -p 16686:16686 \
  -p 14268:14268 \
  -p 9411:9411 \
  jaegertracing/all-in-one:1.9

~~不要な開放ポートがありますが、めんどくさいのでドキュメントそのままです。~~

起動すると、jaegerUIがhttp://localhost:16686/で立ち上がります。

さきほど作ったEchoサーバーも立ち上げます。

go run main.go

APIをコールしてみるとTracingされているのがわかります。

/get/:usernameというAPIのコールも出ています。

こまかく見ていきますと、:usernameはpath parameterなのですが、APIコール時にtubone24というユーザー名を設定しコールしたことがわかります。

1.04sかかってますね・・・。

また、childspanも無事記録してます。

どうやらバックエンド(GitHub)へのコールはそこまで0.48msとそこまで遅くはないみたいです。

別のところにボトルネックがあるんですかね・・。

結論

jaegerでトレーシングが簡単にできましたが、ボトルネック発見は難しいということがよくわかりました。

tubone24にラーメンを食べさせよう！

ぽちっとな↓

2019-11-26 Go Lambda AWS GraphQL GitHub

GoのEchoでJaegerを使ってボトルネックを調査する

tubone

Table of Contents