Jaegerを使ってN+1を潰す - GravityR
この投稿はOpenTelemetry Advent Calendar 2022の11日目の投稿です。
はじめに
ORMは便利です。
しかし、使い始めるとN+1問題が寄ってきます。
自分が書いたコードなら気づきやすいですが、他の人が書いたコードをレビューするときに見つけるのは骨が折れます。
その上、見過ごすと本番で障害となって返ってきます。
この嫌な流れを緩和するため、N+1を見つける機能をGravityRに作りました。
しかも、データベースだけでなくサービス間でのN+1も見つけられます。
この記事では、どのようにN+1を発見しているか紹介します。
JaegerとGravityR
Jaegerとは
リクエストの動作を把握するためにJaegerを使っています。
JaegerはOpenTelemetryのトレースをサポートした分散トレーシングのツールで、収集と可視化の両方に対応しています。
各処理の呼び出し順序や実行時間がわかります。
GravityRとは
GravityRは筆者が作っているツールです。
前にzennで記事を書いたときは、有効なインデックスを自動で見つけたりEXPLAINを見やすくしたりする機能を紹介しましたが、
それに加えてN+1も見つけられるようになりました。
N+1発見の内部動作
N+1はデータベースとアプリの問題ですが、マイクロサービスのように複数のサービスで処理をしていると、N+1のような問題がサービス間でも起きてしまいます。
Jaeger(OpenTelemetry)を使うとこの問題も発見できます。
なので、GravityRでは「同じサービスやデータベースに何度もアクセスしている」を発見します。
そのために、次のことをしています。
- Jaegerからトレースを取得する(gRPC)
- トレースを解釈する
- N+1を発見する
- htmlを作成する
1. Jaegerからトレースを取得する(gRPC)
JaegerにはgRPCサーバーを建てる機能があり、APIのprotoファイルがgithubにあります。
その中に、FindTracesという、実行時間や属性を条件にトレース(trace)を検索するAPIがあります。
例えば、以下のコードを使うと「bffというサービスを利用して5秒以上かかったトレース」を検索することができます
import (
"github.com/gogo/protobuf/types"
"github.com/jaegertracing/jaeger/proto-gen/api_v3"
)
func FindTraces(ctx context.Context, conn *gRPC.ClientConn) (api_v3.QueryService_FindTracesClient, error) {
now := time.Now()
req := &api_v3.FindTracesRequest{
Query: &api_v3.TraceQueryParameters{
ServiceName: "bff",
StartTimeMin: &types.Timestamp{Seconds: now.Add(-30 * time.Minute).Unix()},
StartTimeMax: &types.Timestamp{Seconds: now.Unix()},
NumTraces: 100,
DurationMin: &types.Duration{Seconds: 5},
},
}
client := api_v3.NewQueryServiceClient(conn)
return client.FindTraces(ctx, req)
}
2. トレースを解釈する
JaegerのFindTracesAPIが返すトレース情報は扱いづらいので、変換します。
- トレースのスパン(span)を配列からツリーに変換する
- 同じサービス内で発生したスパンを一つにまとめる
- データベースはスパンを送信しないので、データベース直前のスパンを基にデータベースのスパンを作成する
こうして、下のようなツリーができます
{
TraceID: 'xxxx-xxxxx',
Root: {
ServiceName: "bff",
Children: [
{
ServiceName: "user",
Children: [
{
ServiceName: "mysql"
},
{...}
],
},
{...}
]
}
}
ちなみに、データベースの直前のスパンかどうかは、db.systemという属性で判断しています。
他にもOpenTelemetryにはデータベース関連の属性が色々と定義されているので参考になります。
3. N+1を発見する
ツリー構造ができたら、締めにN+1を探します。
探したいのは、「同じサービスやデータベースに何度もアクセスしているスパン」なので、ツリーをvisitorで回って同じサービスを訪れた回数を数えればわかります。
このとき、N+1だけでなく各サービスが使った時間も調べています。
これを調べると、一番時間を使ったサービスもわかって便利です。
4. htmlを作成する
こうして見つかった、N+1があるトレースをまとめて1つのhtmlを作ります。
htmlは以下を表示します。
- トレースの一覧
- 各トレースのサービス間の関係を表すグラフ
グラフの描画には、mermaidを使っています。
終わりに
以上、Jaegerを使ったN+1の見つけ方でした。
色々なトレースの表示例もあるので、GravityRも見てみてください。
Discussion