Datadog 09・14・15

ログとトレースの相関 — 一つの遅いリクエストを、最後まで追う

トレースを送るだけでは、特定ユーザーだけで起きる遅延や失敗を説明しきれません。request contextに相関情報を載せ、構造化ログとスパンを同じIDで結びます。

TL;DR

  1. trace ID/span IDをログに持たせると、ログとトレースを相互に移動できる。
  2. Goではmiddlewareがrequest contextへtracerとloggerを注入し、下流で引き継ぐ。
  3. サービスをまたぐときはトレースコンテキストを伝搬し、一本の分散トレースにする。

01ログの条件と、トレースの時間軸を同じリクエストへ結び付ける。

個別条件を持つログと、処理時間を持つトレースを同じ一回へ結ぶ。

ログの条件と、トレースの時間軸を同じリクエストへ結び付ける。
中央の共通IDが、左のJSONログと右のwaterfallを一対一で往復可能にする。

user_id=42の遅延ログからtrace_idを開き、DB spanだけが長いと確認できれば、特定データ量に依存する遅延を調べられる。

user_idや時刻だけの近似検索では、並行リクエストを取り違える。リクエスト単位のIDをログへ確実に含める。

02入口で作り、handlerからDBアクセスまで一貫して渡す。

入口で作った観測情報を、処理の全レイヤーへ同じcontextで渡す。

入口で作り、handlerからDBアクセスまで一貫して渡す。
middlewareからhandler、usecase、infraへ流れる箱が、同じリクエストの文脈を表す。

DB問い合わせ時は受け取ったcontextから子spanを作り、同じcontext由来のloggerでquery名や対象IDを構造化出力する。

contextを新規作成して親を捨てると、子spanが別traceになり、キャンセルやdeadlineの伝搬も切れる。

03次のサービスに親子関係を伝え、分散トレースをつなぐ。

ネットワーク境界を越えても、親リクエストとの関係を保つ。

次のサービスに親子関係を伝え、分散トレースをつなぐ。
Service AからBへ渡るヘッダーと、両サービスを貫く一本のtrace lineに注目する。

Service Aがtrace contextをHTTPヘッダーへ注入し、Service Bが抽出して子spanを開始すると、一つの分散トレースとして見える。

RESTでは伝搬処理の実装・middleware設定を確認する。送信側か受信側のどちらかが欠けると、traceは境界で分断される。

結論

  1. ログとトレースは共通のtrace ID/span IDで結ぶ。
  2. Goのcontextはリクエスト単位の相関情報を渡す器。
  3. サービス境界でコンテキストを伝搬して、分散トレースを一本に保つ。