OpenTelemetry の Trace を中心としたパフォーマンス改善

Transcript

1. OpenTelemetry の Trace を中心 とした パフォーマンス改善 id:rmatsuoka Hatena Engineer Seminar #27 2023-11-16
2. 自己紹介 • id:rmatsuoka • 2023年新卒 • Mackerel チーム • アプリケーションエンジニア • 母語は Go
3. Mackerel
4. Mackerel の特徴
5. Mackerel は OpenTelemetry の Metric に対応します
6. OpenTelemetry とは？ • テレメトリー (メトリック、 トレース、ログなど) の標準 仕様を定めている • 仕様に基づいた計装ライブラ リの開発 ◦ Go, Java, PHP, … • OpenTelemetry Collector の開発
7. テレメトリーを計装するア プリケーションやミドル ウェア • 計装ライブラリをアプ リケーションに埋め込 む • 一部のミドルウェアは OpenTelemetry Collector をつかって テレメトリーを計装で きる https://opentelemetry.io/docs/ OpenTelemetry の領域
8. OpenTelemetry Collector • テレメトリーの受信、処理、送信を行うエージェント
9. テレメトリーを受信し て保存、表示するモニ タリングサービス • Prometheus (metric) • Jaeger (tracer) • AWS X-Ray (trace) • Mackerel (metric) など
10. Mackerel の Otel 対応 • OpenTelemetry が策定した Telemetry 送受信プロトコル OTLP によってメトリックを 受信 • PromQL によってメトリッ クをクエリしてグラフに描画 画面は開発中のものです
11. PromQL • Prometheus に実装されているメトリックをクエリする 言語（式） • たとえば ◦ http_request_total{job=”prometheus”} ▪ jobをキー, ”prometheus” を値に持つ属性を持った http_request_total のメトリックをすべて取得する ◦ filesystem_usage / filesystem_capacity ▪ ファイルシステムの使用率を計算する • Mackerel では今回 PromQL エンジンを独自に実装して 提供します
12. 新卒初の仕事として… OpenTelemetry 対応へ向けてコンポーネントの開発・改善 をしています • OpenTelemetry のメトリックを受信して DB へ保存 (writer) • リクエストの PromQL を評価してメトリックを取り出す (reader)
13. 開発しているのはこのコンポーネント RDB Time Series DB Otel metric Reader (ECS) Otel metric Writer (ECS) Otel Collector Web Browser Mackerel あなたの server あなた メトリックのメタデータを保存 メトリックの時系列データを保存 OTLP によってメト リックを受信 PromQL を評価 してメトリック を DB から取得
14. 今回のお話する仕事 • もともとこのコンポーネントは PoC であった ◦ 実装の方針が正しいか調べるため ◦ あまりパフォーマンスを意識した実装にはなっていなかった • 実際のサーバーからメトリックを送信してブラウザから 見ようとすると重くて使い物にならない ◦ 一つのダッシュボードを開くだけで Reader コンポーネントの CPU 使用率が 100 % になった • 「コンポーネントのパフォーマンスを改善しよう！」
15. パフォーマンス改善で大切なこと • 計測 ◦ ボトルネックを改善しなければ意味がない！ ◦ 推測するな、計測せよ • どうやってボトルネックを見つける？ ◦ ツールは色々ある
16. Trace を中心に計測してみた！ • Trace をする。さらにTrace で見つかったボトルネックを 他のツールを使うことによって掘り下げていくトップダ ウンの方法で計測 • コンポーネント Writer / Reader どちらも Trace を使っ てパフォーマンス改善したが、今回の話は Reader に焦 点をあてる • 「Trace を入れよう」とは id:lufiabb が言った ◦ 曰く「タスクとしては Trace を入れて終わるつもりだったけど、 rmatsuoka がパフォーマンス改善を進められそうだから任せた」
17. 分散トレース • ひとつのリクエストが処理される過程を追跡する方法 • マイクロサービスやミドルウェアに「分散」している処 理を横断して追跡する ◦ 今回の話では、横断はできておらず一つのコンポーネントだけ見 ています
18. 分散トレース トレースは「スパン」の木構 造で表すことができる。 Span B は Span A を親に持 ち Span C と Span D を子に 持つ Span A (例: http Handler など) Span B (use case) Span C (database access) Span D
19. Go で trace を計装するのは 3 ステップ！ 1. Tracer の initialize を追加 2. http.Handler を otelhttp でラップ 3. 計測したい関数に trace start/end の2行追加
20. 1. Tracer の initialize を追加 // main 関数あたりに trace の送り先を指定する traceExporter, err := otlptracegrpc.New(ctx, ...) ... -- nicepkg/tracer.go -- // pkg ごとに tracer を初期する var tracer = otel.Tracer("example.com/proj/nicepkg")
21. 2. http.Handler を otelhttp でラップ // リクエスト処理全体のスパンを生成してくれる。 // metric reader コンポーネントは net/http と互換性のある // github.com/go-chi/chi によって書かれている - handler := newNiceHandler() + handler := otelhttp.NewHandler(newNiceHandler(), “servername”, ...)
22. 1. 3. 計測したい関数に2行追加 // スパンを生成する func NiceFunction(ctx context.Context) { + ctx, span := tracer.Start(ctx, "SpanName") + defer span.End() + // function body }
23. モニタリングサービスへ送信 • 今回、トレーシングデータは AWS X-Ray へ送信した。 ◦ AWS Open Distro for OpenTelemetry https://aws-otel.github.io/ • ECS にあるコンポーネントのサイドカーにAWS が提供し ている ADOT Collector (AWS Distro の OpenTelemetry Collector) を立てた。
24. こんな結果が得られる！ スパン 緑の線: 実行時間
25. 結果を観察してみよう 同じ関数がループで呼 ばれている
26. N + 1 問題 • データベースへの問い合わせに発生する問題 • 取り出すメトリック一覧を取得する RDB へのアクセス を1回 • それぞれのメトリックの時系列データを Time Series DB から取り出すことをループで N 回実行 • まとめて取得をするように変更して N+1 問題は解決
27. 一度に取得できる数に上限を入れる • PoC では 検索結果の数の上限がなかった。 • 数百, 千件ものメトリックを一気に取り出そうとして CPU を食い潰していた。
28. N+1 問題は解決したが… db.Query がなぜか遅かったりする
29. DB への特定のリクエストが遅いことを 発見 • 特定の条件のリクエストだけが遅い • 大抵のリクエストはそんなに遅くない • テーブルはふたつある ◦ メトリック (Mackerel のオーガニゼーションの ID や メトリック のタイプなど) ◦ メトリックのメタデータ (メトリックの属性のテーブル、メト リックに従属している)
30. DB へのインデックスを追加 • DB の実行計画を`EXPLAIN ANALYZE` コマンドで見る • メタデータテーブルの index の貼り方がマズかったこと がわかった • 高速化のためメタデータテーブルを非正規化してオーガ ニゼーションID のカラムを追加した + ALTER TABLE <メタデータテーブル> ADD COLUMN "org_id" BIGINT; + CREATE INDEX <index_name> on <メタデータテーブル> ("org_id", ...);
31. PromQL への評価が遅い
32. クエリによっては PromQL の評価が遅い • Trace では PromQL を評価する関数が遅いことしかわか らない • Go の プロファイラー pprof を使って調査
33. (time.Time).Equal が遅い？ • 時間を表す構造体 time.Time が等しいかを調 べる関数 • CPU の使用時間を多く占め ている • この関数単体では遅くない はず
34. (time.Time).Equal を沢山呼んでいた • スライスの中から特定の時間をもつ構造体を探すとき に、ループで探していたことがわかった。 • Equal メソッドを何度も呼んでいる。 - for _, dataPoint := range metric.DataPoint { - if dataPoint.Time.Equal(at) { - ...
35. 二分探索をする • 構造体は時間でソートされていたので二分探索をするよ うにコードを変更 + idx := sort.Search(len(metric.DataPoints), func (i int) bool { + return metric.DataPoints[i].Time.Compare(at) >= 0 + })
36. メモリの確保が激しい • メモリを確保/解放する関 数mallocgc, や madvise なども CPU 使用時間を 多く占めていた • メモリのプロファイラも 調査した
37. メモリの確保を回避する 入力のバリデーションのたびに毎回正規表現をコンパイルし ていた - regexp.Match("[\x00-\x08\x0B\x0C\x0E-\x1F\x7F]", input)
38. 改善策 • 正規表現を一度だけコンパイルする ◦ 一般的な選択肢 • 正規表現を使わない ◦ 今回はこっち。制御文字がないか調べるだけなので正規表現を使 わずに済ました + strings.ContainsAny(input, invalidChars)
39. こうした改善のおかげで * 改善前の遅いリクエストと全く同じものではないので参考程度に
40. トレースを計装するときのヒント 1 トレースを自動計装してくれるミドルウェ アを使う • github.com/uptrace/opentelemetry -go-extra/otelsql ◦ DB へのクエリを保存してくれる
41. トレースを計装するときのヒント 2 // フィールドを追加する // トレースにリクエストの情報を追加して、トレースの詳細に見る時に // 参考にすることができる。 // この例ではリクエストされた PromQL をフィールドに追加している。 ctx, span := tracer.Start(ctx, "eval", trace.WithAttributes( attribute.String("query", query), attribute.Int64("start", start.Unix()), attribute.Int64("end", end.Unix()), ))
42. まとめ • アプリケーションにトレーシングを導入するのは3ステッ プでできる • タイムラインの図によってボトルネックが発見しやすい • Trace の結果から DB の実行計画や pprof などの細かい 情報を見にいくトップダウンに改善ができた
43. OpenTelemetry の Mackerel の beta 参加者募集！ • Mackerel「ラベル付きメトリック機能」ベータ版テスト お申し込みフォーム からお申し込みください ◦ ブログ記事 [ なぜ Mackerel は OpenTelemetry のラベル付きメトリックをサポートす るのか - Mackerel お知らせ #mackerelio https://mackerel.io/ja/blog/entry/why-does-mackerel-support-open-telemet ry-labeled-metrics ] からフォームに飛べます