AWS の分散トレーシングサービスである X-Ray の導入に関して、弊社内における活用や課題などの事例をご紹介します。
あいさつ
本記事は、プロダクト開発において検討される様々な監視機能の 1 つとして AWS X-Ray を選択するケースに着目し、弊社内で実際に X-Ray を採択したプロダクトを取り上げて事例をご紹介するものです。
プロダクトの需要に合わせているため必ずしも X-Ray 特有の機能を優先しているわけではなく、「X-Ray を使わずとも通常のロギング戦略で実現できる領域に対して X-Ray を活用することで付加価値を得られた」という解釈に近い点のみご了承ください。
プロダクトの監視や X-Ray に関心をお持ちの方にとって有益な例となれば幸いです。
一般的なマイクロサービスに限らない X-Ray の活用
AWS X-Ray とは分散トレーシングを実現するマネージドサービスであり、 X-Ray が価値を発揮する状況としてよく目にするのは、マイクロサービスアーキテクチャでのリクエスト追跡とパフォーマンス測定かと思います。つまり、「受け取ったリクエストはどのプロダクトから始まってどのプロダクトを通過してきたか」、「数多くのプロダクトを通過する中で、最も処理に時間のかかっているプロダクトはどこか・どんなリクエストパターンだったのか」といった運用上の疑問を解消したいとき、 X-Ray は大きな役割を果たします。
一方、弊社内で X-Ray が導入されたプロダクト周辺は必ずしも「大規模プロダクト群」とまでは呼べず、送り出されたリクエストが通過するプロダクト数も 2 〜 3 個を超えることは稀だといえます。運用上の課題の多くを通常のロギング戦略で解決できる状況下で X-Ray を導入した動機は深刻な内容ではなく、単純に「監視上便利だと思ったから導入した」というものでした。導入プロダクトは アムズ API と Edikari です。
※それぞれのプロダクトについて下記記事でも取り上げていますので、ぜひご一読ください。
プロダクトの位置づけや特徴についてはそれぞれの紹介記事に任せますが、これらのプロダクトへの X-Ray 導入によって得られた成果としては概ね以下の 3 点です。
- 多サービス連携でのエラープロダクト特定
- GraphQL の多層リゾルバーとDBアクセスの追跡
- バックエンド向けプロダクトの利用者特定
多サービス連携でのエラープロダクト特定
主に Edikari で活躍した内容です。組織内でマイクロサービスの意識が比較的高かった時期のプロダクトということもあり「5 個を超える他プロダクトとの連携を前提とした機能」をもつ Edikari において、開発中のエラー箇所特定速度は関心の大きなテーマの 1 つでした。
処理の起点がほとんど Edikari であることは判明している一方で、 Edikari と他プロダクトが通信するタイミングでのエラーについては直ちに切り分けることが難しいことも多く、「他プロダクトへ通信する直前のパラメータ構築中にエラーが発生したのか」、「他プロダクト側でエラーが発生したのか」、「他プロダクトから正常に返されたレスポンスを加工する段階でエラーが発生したのか」といった一次調査で X-Ray が価値を発揮しました。 CloudWatch Logs に蓄積された大量のログを時間帯とログレベルで絞り込んで探す手間も省け、必要に応じて X-Ray トレース ID から「そのリクエストに関するログ」だけに絞り込んで詳細調査することも可能でした。
Edikari は基本的にはアムズ API ともうひとつ別のサービスにアクセスする通信パターンが多いですが、複数プロダクトとのやり取りが連なるケースとしてはたとえば「Edikari での処理結果をもとに、連携しているタスク依頼管理ツールからタスク依頼を行う機能」があります。開発当時、そのケースでのプロダクト連携は以下のように行われていました。各プロダクトへの通信を X-Ray サブセグメントで区切っているので、どのタイミングでエラーが発生したかは AWS コンソール上で視覚的に把握できます。
- フロントエンドから受け取ったパラメータをもとに外部アカウント情報をアムズ API へ問い合わせ、特定可能な ID を取得する
- CreativeDrive へ問い合わせるための準備として認証する
- フロントエンドから受け取ったパラメータをもとに画像・動画に関連するデータを CreativeDrive へ問い合わせて取得する
- これまでに取得した情報をもとにタスク依頼の初期内容を組み立てて、タスク依頼管理ツール TaskDriver へ送る
GraphQL の多層リゾルバー処理とDBアクセスの追跡
アムズ API で活躍した内容です。 GraphQL の特徴を活用して各プロダクトが様々な起点から目的のデータを取得できるように GraphQL スキーマを設計している影響で、従来であれば単純な 1 回の DB アクセスで済んでいたケースで GraphQL リゾルバを介した複数回の DB アクセスを要していたアムズ API では、リゾルバ単位・ DB アクセス単位でのエラー箇所特定とパフォーマンス計測が (他プロダクトとの関わりがなくアムズ API 内部に閉じている状況下であっても) プロダクト改善に大きく役立ちました。
多層リゾルバーと DB アクセスの関係について具体例を示します。たとえばアムズ API の実際のデータモデルと類似する以下のような 3 層の GraphQL オブジェクト構造を仮定します。 DB 側もこれらの GraphQL オブジェクトごとにテーブルを持って紐づけ情報も管理し、どのリゾルバ処理においても DB アクセスがあると想定します。
# CategoryGroup : Category は N : N の関係 # Category : CategoryCondition は N : N の関係 type CategoryGroup { id: Int! name: String! # 子要素として紐づいている Category categories(): [Category!]! } type Category { id: Int! name: String! # 親要素として紐づいている CategoryGroup category_groups(): [CategoryGroup!]! # 子要素として紐づいている CategoryCondition category_conditions(): [CategoryCondition!]! } type CategoryCondition { id: Int! name: String! # 親要素として紐づいている Category categories(): [Category!]! }
これらのデータを利用するプロダクトのユースケースとして以下の 3 パターンを仮定したとき、 GraphQL でない従来のアプローチならばどのパターンも 1 回の DB アクセス (1 個の SQL) で目的を達成できる状態でした。
- 全ての CategoryGroup (リスト) を起点に、紐づく Category と CategoryCondition を全取得
- 1 つの Category を起点に、紐づく CategoryGroup と CategoryCondition を全取得
- 1 つの CategoryCondition を起点に、紐づく Category と CategoryGroup を全取得
一方、アムズ API の GraphQL によるアプローチでは最低でもおよそ 3 回、基本的には N + 1 問題に該当するレベルの DB アクセスが発生します。
もしとある CategoryCondition (仮に "Awesome" と呼びます) が 1 つの Category に紐づいていて、その Category が 1 つの CategoryGroup と紐づいていた場合、パターン C のユースケースで CategoryCondition "Awesome" を起点に CategoryGroup まで全取得した場合の DB アクセスは以下の SQL で合計 3 回です。
- CategoryCondition "Awesome" を取得するための SQL
- CategoryCondition "Awesome" と紐づく Category を取得するための SQL
- 「CategoryCondition "Awesome" に紐づいている Category 」と紐づく CategoryGroup を取得するための SQL
もし紐づく Category や CategoryGroup の数が多かった場合、 DB アクセス数も増えていきます。この特徴はアムズ API が DataLoader を導入した動機にもなっています (cf. Clojure で GraphQL の DataLoader を実現する superlifter の紹介（前編）, Clojure で GraphQL の DataLoader を実現する superlifter の紹介（後編） ) 。
パターン C を取りあげてみると、アムズ API のトレーシングではおおよそ以下のような X-Ray トレース表現となります (実際には、それぞれの行で所要時間もわかります) 。
- `ams-api` (セグメント)
- `NestedSeriesFromCondition` (サブセグメント: operation name)
- `category_condition_by_id` (サブセグメント: queryからのリゾルバ)
- `ams-api-db` (サブセグメント: DB アクセス)
- `CategoryByCategoryCondition` (サブセグメント: ネストしたリゾルバ)
- `ams-api-db` (サブセグメント: DB アクセス)
- `CategoryGroupByCategory` (サブセグメント: ネストしたリゾルバ)
- `ams-api-db` (サブセグメント: DB アクセス)
具体例では 3 層リゾルバを仮定しましたが、実際にアムズ API で活発に利用されるケースは 1 〜 7 層程度です。 GraphQL では 3 層以上ネストするような取得方法に課題感を持たれることも少なくない中、通常利用の範疇で 7 層ものリゾルバ処理が発生することから「どのリゾルバ処理、どの DB アクセスで多くの時間を使っているか」といった観点でのパフォーマンス改善が繰り返され、そのきっかけとして X-Ray トレースが貢献しました。
バックエンド向けプロダクトの利用者特定
アムズ API で活躍した内容です。アムズ API はサービス間通信の連鎖こそ少ないものの利用者・利用プロダクトのパターンが多岐にわたるため、開発チーム側でエラーを検知しても「誰がどんな目的でどのプロダクト経由で送ったリクエストなのか」を推し量ることが難しい場面もありました。アムズ API が広く利用され始めてからは CloudWatch Logs へ記録されるログの頻度と量も急増し、ロードマップ上の機能開発を進めながらエラー調査も完遂するためにはログの絞り込み検索だけでは厳しい側面もありました。 X-Ray が貢献したのはこの利用者特定の領域です。
アムズ API のトレーシングでは、付加情報として 注釈 (annotation) と メタデータ (metadata) をトレースへ含めています。 注釈 にはユーザー名や利用プロダクト名を、 メタデータ には GraphQL Query 文や Variables を記録しているため、エラー時やパフォーマンス調査時に疑わしいトレースを発見した場合は速やかにリクエスト元を特定し、必要に応じてヒアリング調査などへつなげることも可能でした。
特に 注釈 として記録した内容は AWS コンソール上で X-Ray トレースを検索するときの絞り込み条件としても使えるため、たとえば「最近のエラーでリクエスト元だったこのプロダクトは普段どのくらいの頻度でどんなリクエストを送っているか」といった能動的調査にも活用されています。
X-Ray 運用における課題
X-Ray の導入と運用は、通常であれば各種サービス統合や SDK によって低コストで行える印象があります。一方で、弊社内での X-Ray 導入は思っていたほど簡単なわけでもなかったという事情もありました。また、導入後の運用面にも注意点がありました。大きなテーマとしてはこちらの 3 つです。
- Java 以外の JVM 言語で動くプロダクトへの実装
- WebSocket 通信のトレーシング
- 中長期単位での過去分トレース内容の確認
Java 以外の JVM 言語で動くプロダクトへの実装
Edikari のバックエンドサーバーは Scala で実装されており、アムズ API は Clojure で実装されています。どちらも JVM 言語なので Java の機能を活用可能で、 X-Ray 導入も AWS X-Ray SDK for Java を組み込んで実現しています。一方、 X-Ray SDK for Java 導入時の強みの 1 つである「サーブレットフィルタと連携して最小限の設定のみで組み込み完了し、後は放置するだけ」という部分で少なくない課題を抱える状態でもありました (ECS Fargate コンテナで稼働させるプロダクト状況に合わせて X-Ray デーモンをサイドカー構成で組み込むなどのインフラ事情については割愛します) 。
まず、 Edikari サーバーが利用している HTTP 通信の仕組みの影響で X-Ray 処理の一部を Edikari 内に再実装する必要がありました。 Edikari サーバーで HTTP 通信に用いられていた Akka HTTP はどうやらパフォーマンスのために Java サーブレットフィルタとは異なる独自実装を採用しているらしく、 X-Ray SDK for Java が前提としているサーブレットフィルタの仕組みを適用すること自体が困難でした。結論としては、 X-Ray SDK for Java がサーブレットフィルタで行っているような「サンプリングルールを考慮した preFilter や postFilter などのトレース処理」を Edikari サーバー内に Scala コードで再現できるよう実装し、そちらを使って手動で X-Ray のセグメント作成からトレース送信まで行いました。
またアムズ API は機能開発の過程で、マルチスレッド処理中のセグメント追跡が度々失敗する場面に遭遇しました。マルチスレッド処理や非同期プログラミングにおける X-Ray セグメントコンテキストの受け渡し事情については ドキュメント でも既に紹介されており、初期導入の時点で setTraceEntity によるセグメントの維持を実現していましたが、リゾルバや DataLoader などトレースにも関係のある基幹部分あるいは X-Ray トレース処理自体の改修が進む中で context missing exception と対峙した回数は決して少ないものではありませんでした。 X-Ray に関連する各種エラーを目視で追えなくなったとある 3 ヶ月の期間では、計測された API 内エラー総数が 3 万個を超えたこともありました。
WebSocket 通信のトレーシング
アムズ API の一部の機能は GraphQL Subscription で提供されています。 HTTP 通信においては大きな価値を発揮する X-Ray ですが、 Subscription が利用する WebSocket 通信との相性は必ずしも良いとはいえず、苦戦する場面がありました。
アムズ API は Jetty サーバーのサーブレットフィルタに X-Ray を組み込んでいるため、通常の HTTP リクエストに対してはトレース用のセグメントが自動的に開始されます。そのセグメント配下では、主に Query のリゾルバ単位でサブセグメントを開始しています。一方、アムズ API が提供する Subscription 系の API の内容は「アムズ API 内部で GraphQL Query を使用し、既存のリゾルバ処理に任せて特定のデータを全取得する」となっており、 Subscription 実行中に Query のリゾルバが活用されています。
このとき、 Subscription を実行すると (HTTP 通信ではない故なのか) サーブレットフィルタ処理が行われないことでセグメントが開始せず、セグメントが開始していないのにリゾルバ処理でサブセグメントを開始しようとして SegmentNotFoundException と邂逅する問題があります。アムズ API の対応としては、 GraphQL サーバライブラリ Lacinia の Streamer 実行タイミングで明示的にセグメントを開始・終了させるように実装を挟み込んでいます。
また、 (幸いにもアムズ API はこの問題から逃れ続けられていますが、) トレースへ含める 注釈 のデータ源が Web API 基盤ライブラリ Pedestal のインターセプター内で Context Map へ保持された内容だった場合も課題があります。通常の HTTP ルート組み込みの要領で設定するようなインターセプター処理は Query や Mutation の実行時には通過しますが Subscription 実行時には通過しないため、欲しいデータをトレースに記録できないケースがあります。 lacinia-pedestal を利用しているアムズ API がこのようなデータをトレースへ含めたい場合、方法の 1 つとしては HTTP ルート用のインターセプターで行っている処理を Subscription 用インターセプター (たとえば com.walmartlabs.lacinia.pedestal.subscriptions/default-subscription-interceptors で定義されているようなもの) としても組み込む必要があります。
中長期単位での過去分トレース内容の確認
エラー発生時の調査や負荷試験の検証に X-Ray が大きく貢献する一方で、トレースを過去の事例として参照する使い方に対しては必ずしも最適とはいえない事情もあります。実際にアムズ API ではエラーやパフォーマンス問題の過去事例として GitHub の Issue や Pull Request に記載されたトレース情報を見返すことも多いですが、 AWS コンソール上でトレースを閲覧できる期間が過去 30 日までという制限があるようで、詳細を全く追えなくなってしまった幻のトレース URL が多く生み出されました。苦渋の決断としてトレース表示のスクリーンショット画像を保持することもありましたが、手間の観点からは 注釈 なども含めた全ての画面を保持するわけにもいかず厳しい日々を送っているケースもあるかと思います。
トレース検索時の時間絞り込みに 6 時間という強力な制約があることも、後からのトレース参照において重要なテーマの 1 つとなっています。たとえばアムズ API では数週間から 1 ヶ月間のレベルで CloudWatch Logs のログを絞り込み探索することもありますが、同様の探索を X-Ray トレースに対して行う場合は 6 時間単位の枠を手動でずらしながら行う必要がありました。 URL のクエリパラメータをうまく使うという手段もありますが、結局のところ 6 時間ずつしかトレースを検索できない現状はアムズ API にとって課題も多く、かつてはプロダクト運用における調査を全て X-Ray で賄う夢も話題にあがっていたものの現在も X-Ray 主軸というよりは X-Ray と CloudWatch Logs の組み合わせによって真価を発揮しています。
まとめ
AWS X-Ray の導入と運用について、一般的なマイクロサービスに限らない活用や課題について事例を紹介しました。
一言にマイクロサービスアーキテクチャといっても、その意識具合がサービス間設計へどのように反映されているかはそれぞれ多様な世界があるかと思います。
弊社プロダクトでの事例が皆様の糧となることを心よりお祈り申し上げます。
いつもの
Opt Technologies ではエンジニアを募集中です。カジュアル面談も可能ですので、下記リンク先よりお気軽にご応募ください。
