千株式会社でエンジニアをしている@MegataYutoです
今回は、オブザーバビリティ向上に対する取り組みを行ったので記事にしました
早速ですが、自分自身が運用しているサービスの内部をどれだけ理解できていますか?
どんな時にレスポンスが遅くなる?とか特定のリクエストに対してどれだけのクエリが投げられている?とか答えられる人は限られていると思います。
自分自身、オブザーバビリティ向上の取り組みをするまでは全くと言って良いほどシステム内部でどんな事が起きているか説明できていない状況でした。
オブザーバビリティ向上に取り組むことで、自分が関わるシステムの内部でどんな事が起きているか可視化することができました。
これによって、システムのトラブルやパフォーマンス改善に取り組む際に、内部でどんな事が起きているのかを簡単に理解できるようになりました。
この記事では、オブザーバビリティについてや、導入することのメリット・デメリットなどについて共有できればと思います。
本記事では、技術仕様やツールの詳細には触れません。その代わり、以下のポイントに絞って説明していきます。
- オブザーバビリティの概要
- 導入の背景
- 実際の取り組み内容と得られた効果
オブザーバビリティとは
まず最初にオブザーバビリティとはどんな意味か軽く触れておきます
システム内部がどれだけ可視化されているかを示すもの
「オブザーバビリティがある」ということはシステム内部でどんなことが起きているか説明できる状態ということになります。
従来の監視は、アラート設定やダッシュボード化によって既知の問題を検出するものでしたが、オブザーバビリティは監視で起きた問題の根本原因にたどり着いたり、予知しない問題にもたどり着けるようになるものです。
なぜオブザーバビリティが必要?
元々システムを運用する上で色々な困り事がありました。
- 何か全体的にレスポンスタイムが遅くなっているけどなんで?
- エラーが出ているが原因が特定できない
- エラーログは出していてもどのリクエストの処理でエラーが出ているかわからないことが多い
- 社歴の長い人しか対応できない
- エラーログは出していてもどのリクエストの処理でエラーが出ているかわからないことが多い
- 結果、システムに長く関わっている=社歴の長い社員にしか対応できないエラーが多く、エラーの解決までに時間がかかる
挙げた例は一部ですが、システム内部でどんな事が起きているか分からないのですぐに原因特定して対応することが困難な状況が色々なところで起きていました。
そこでオブザーバビリティを向上させて、誰でもシステム内部の処理やデータの流れを追えるようにする活動を行うことにしました。
実際に取り組んんだ内容を話す前に押さえておきたい用語の説明をします
トレースとは
リクエストあたりの処理の全体を表すもの
スパンとは
トレース内に含まれる処理の単位
実際に取り組んだ内容
取り組んだ内容は大きく以下の4つです - OpenTelemetryを活用 - トレースを取得 - ログにトレースIDの付与 - Grafanaを導入してトレースとログを可視化
トレースを取得
ここから実際にどのようにトレースを取得したかを軽く説明します。
OpenTelemetryを活用して自動計装と手動計装の両方を実施しました。
サーバーが複数台あり、PHPのバージョンが自動計装に対応しているアプリは自動軽装、自動計装に対応していないバージョンのアプリには手動計装を入れました。
対象の処理は、DBへの負荷がトラブルやパフォーマンス劣化の原因になっていることが多いため、SQLを発行している部分に絞って計装しています。
ログにトレースIDを仕込む
トレースとログを紐づけて可観測性を高めたかったので、
OpenTelemetryのSDKを使ってロガーにトレースIDを付与する処理を付け加えました。
ログにトレースとスパンIDを埋め込む例
class CustomLogger { public function __invoke($logger) { foreach ($logger->getHandlers() as $handler) { $handler->setFormatter(new class extends LineFormatter { public function format($record): string { // 現在のスパンから context を取得 $span = Span::getCurrent(); $context = $span->getContext(); // trace_id, span_id をログのコンテキストに追加 $record['context']['trace_id'] = $context->getTraceId(); $record['context']['span_id'] = $context->getSpanId(); return parent::format($record); } }); } } }
Grafanaによる可視化
今まではモニタリングツールの導入はしていなかったので今回はGrafanaを導入しました。
トレースデータはTempo、ログデータはLokiで管理しています。
ツールの詳しい話は今回はしません
TempoとLokiについての詳細は割愛します
詳しく知りたい方は公式ドキュメント等で確認できます
データの流れ
以下の画像がざっくりとしたデータの流れの説明です
アプリーケーションサーバーからOpentelemetry Collector経由でトレースとログデータをLokiとTempoに送っています
LokiとTempoに送られたデータはS3に保管されています。
Grafanaから参照するときはLoki,Tempoに問い合わせてLoki,TempoがS3のデータを参照する流れです
実際にトレースデータを見てみる
Grafanaでとある機能のトレースの例です。
手動計装で取得していて、⭕️の58spansが1トレースに対するspanの数になります
今回トレースを埋め込んだ処理が基本的にクエリを発行した処理になるので1リクエストで50個ほどの処理が投げられている事がわかりました。
画像ではお見せできないのですが、spanの詳細画面にはクエリの詳細、実行された関数、どのユーザーのリクエストなのかなど計装時に明示的に埋め込んだ情報が確認できます
見ての通り、どの処理に対してクエリがどれぐらい投げられたかトレースを検索するとすぐに分かるようになりました
実際にトレース情報から得た効果
トレースを見る事でどれだけクエリを投げられているか、どこの処理が走っているかなどコードを追わなくても分かるようになりました。
結果、導入してからまだ少ししか時間が経っていませんが色々な効果がありました。
得られた効果をざっと箇条書きで並べています
- 調査時間が大幅に短縮された
- リクエスト対してどんな処理が行われたか一目で分かるようになった
- ログにトレースIDがついているのでどのリクエストで出たログなのか分かるようになった
- 今まで気づけていなかったことに気づけるようになった
- 思いもよらないところでクエリが大量に投げられていた
- パフォーマンスチューニングを実施
- パフォーマンスの遅い処理が内部ごと可視化されたことでどこをチューニングすれば良いか当たりをつけやすくなった
実際に障害の原因特定やクエリが多い処理をチューニングしてレスポンスタイムが1/4に短縮できた事例など多くの効果が出ました
導入に際しての注意事項
これまではトレースを入れてよかったことだけを並べていましたが、導入に際して注意した方がいい事も挙げます
- 導入まで必要な作業の多さ
- モニタリングツールの導入、計装の実施など1から必要な場合は負担も多くなります
- ツールの選定や学習コストなど
- 負荷の増加
- トレースの計装により少し負荷が増える事もあります(感覚値ですが)。リクエストが増えると少し重くなる事もあります。
- サンプリングを実施することで対処ができそうです
手動計装のclose忘れでアプリケーションサーバのメモリを過剰に消費する
- リリース前にclose漏れに気づいて対応しましたがリスクはあります
モニタリングツールの管理コストが発生
- 元々モニタリングツールがなく自前でGrafanaを建てました。サーバーの管理やデータの期限設定など管理する項目が以前より増えました
総括
今回、オブザーバビリティ向上の取り組みとして、OpenTelemetryを活用したトレースの取得、トレースIDのログ付与、Grafanaによるデータの可視化を行いました。
初めての試みで導入には多くの課題がありましたが、それ以上に大きな成果を得ることができたと思っています。
システム内部の可視性が向上したことで、問題の特定と対応が格段にスピードアップしました。
また、これまで見過ごしていたクエリのボトルネックやパフォーマンスの問題に気づき、実際に改善へとつなげることができました。
導入に伴うコストや運用負荷や技術的な課題もありますが、それ以上に得られる効果はあります。
特に、メンバーの社歴が短い人が多く、システム内部の理解度が高くないプロダクトにはより効果的になるかと思います。
今回、OpenTelemetryの導入からモニタリングツールの導入まで初めての試みで大変で時間がかかりましたが取り組んで良かったと思います。
今後、オブザーバビリティ向上に取り組む方にとって、この記事が少しでも参考になれば幸いです。