Prometheusだけでは障害診断に不十分な場合
PrometheusとGrafanaは何か問題が起きていることを教えてくれる——レイテンシの急増、エラーレートの上昇。しかし8〜10個のサービスが連携しているシステムでは、より難しい問いが生まれる:問題はどのサービスで、リクエストのどのステップで発生しているのか?
以前、4秒かかる遅いリクエストのデバッグに3時間近く費やしたことがある。各サービスのログは正常で、メトリクスも異常なし。最終的にN+1クエリでデータベースを呼び出しているサービスを発見したが、5つのサービスを手動でgrepして探し出すはめになった。その経験からdistributed tracingを調べ始めた。
OpenTelemetry + Jaegerはまさにこの問題を解決する。ログを手動でgrepする代わりに、複数のサービスをまたぐリクエストの全行程をタイムライン形式で確認できる——各ステップがミリ秒単位で計測され、どのステップが遅いのか、どれだけ遅いのかが一目瞭然だ。
JaegerとOpenTelemetry Collectorのセットアップ
Docker Composeでスタックを構築する。アーキテクチャは:アプリケーションがtraceをOTel Collectorに送り、CollectorがそれをJaegerに転送する。Collectorを挟むのは冗長に見えるかもしれないが、Jaegerに送る前にspanをバッチ処理できるため、特にトラフィックが多い場合にJaegerの負荷を大幅に軽減できる。
docker-compose.ymlの作成
version: '3.8'
services:
jaeger:
image: jaegertracing/all-in-one:1.57
ports:
- "16686:16686" # Jaeger UI
- "14250:14250" # CollectorからtraceをgRPCで受信
environment:
- COLLECTOR_OTLP_ENABLED=true
otel-collector:
image: otel/opentelemetry-collector-contrib:0.99.0
volumes:
- ./otel-collector-config.yaml:/etc/otelcol-contrib/config.yaml
ports:
- "4317:4317" # OTLP gRPC
- "4318:4318" # OTLP HTTP
depends_on:
- jaeger
OpenTelemetry Collectorの設定
otel-collector-config.yamlファイルを作成する:
receivers:
otlp:
protocols:
grpc:
endpoint: 0.0.0.0:4317
http:
endpoint: 0.0.0.0:4318
processors:
batch:
timeout: 1s
send_batch_size: 1024
exporters:
otlp/jaeger:
endpoint: jaeger:14250
tls:
insecure: true
service:
pipelines:
traces:
receivers: [otlp]
processors: [batch]
exporters: [otlp/jaeger]
スタックを起動する:
docker compose up -d
# Jaeger UIを http://localhost:16686 で確認
OpenTelemetryでPythonアプリケーションをInstrumentする
以下の例では、order-serviceとして機能するFlask APIを使う——クライアントからリクエストを受け取り、inventory-serviceとpricing-serviceにリクエストを転送する。必要なライブラリをインストールする:
pip install opentelemetry-sdk \
opentelemetry-exporter-otlp-proto-grpc \
opentelemetry-instrumentation-flask \
opentelemetry-instrumentation-requests
アプリケーションでtracerを初期化する
# tracing.py
from opentelemetry import trace
from opentelemetry.sdk.trace import TracerProvider
from opentelemetry.sdk.trace.export import BatchSpanProcessor
from opentelemetry.exporter.otlp.proto.grpc.trace_exporter import OTLPSpanExporter
from opentelemetry.sdk.resources import Resource
def setup_tracing(service_name: str):
resource = Resource.create({"service.name": service_name})
provider = TracerProvider(resource=resource)
exporter = OTLPSpanExporter(
endpoint="http://localhost:4317",
insecure=True
)
provider.add_span_processor(BatchSpanProcessor(exporter))
trace.set_tracer_provider(provider)
return trace.get_tracer(service_name)
FlaskアプリケーションへのInstrument組み込み
# app.py
from flask import Flask, jsonify
from opentelemetry.instrumentation.flask import FlaskInstrumentor
from opentelemetry.instrumentation.requests import RequestsInstrumentor
from tracing import setup_tracing
import requests
app = Flask(__name__)
tracer = setup_tracing("order-service")
# FlaskとrequestsライブラリをAuto-instrument
FlaskInstrumentor().instrument_app(app)
RequestsInstrumentor().instrument()
@app.route("/order/<int:order_id>")
def get_order(order_id):
with tracer.start_as_current_span("fetch-order-details") as span:
span.set_attribute("order.id", order_id)
# 子span:inventory serviceを呼び出す
with tracer.start_as_current_span("check-inventory"):
inventory = requests.get(
f"http://inventory-service/stock/{order_id}"
).json()
# 子span:pricing serviceを呼び出す
with tracer.start_as_current_span("calculate-price"):
price = requests.get(
f"http://pricing-service/price/{order_id}"
).json()
span.set_attribute("order.total", price.get("total", 0))
return jsonify({"order": order_id, "inventory": inventory, "price": price})
if __name__ == "__main__":
app.run(port=5000)
重要なポイント:order-serviceがHTTP経由で他のサービスを呼び出す際、RequestsInstrumentorが自動的にtrace IDとspan IDをヘッダー(traceparent)に付与する。リクエストを受け取ったサービスはそのヘッダーを読み取り、traceを正しいチェーンに連結する。そのため、システム内のすべてのサービスをinstrumentする必要がある——1つのサービスを見落とすだけでそこでtraceのチェーンが途切れる。
Jaeger UIでtraceを読む
APIに10〜20件のリクエストを送り、その後http://localhost:16686を開く。
リクエストのtraceを検索する
- Serviceを選択:
order-service - Find Tracesをクリック
- 分析するためにdurationが高いtraceを選択する
Jaegerはウォーターフォール形式のタイムラインを表示する。これを見れば、どのspanが最も時間を消費しているかが一目でわかる——例えばcheck-inventoryが合計1秒中800msを占めているなら、まずそこを確認すべきだ。推測もgrepも不要だ。
デバッグを容易にするattributeの追加
カスタムattributeを使うとビジネスロジックのコンテキストをspanに付与できる——特定のユーザーやオーダーのtraceを検索する際に非常に役立つ:
with tracer.start_as_current_span("query-database") as span:
span.set_attribute("db.query", sql_query)
span.set_attribute("db.rows_returned", len(results))
span.set_attribute("user.id", user_id)
# エラーが発生した場合:
span.record_exception(exception)
span.set_status(trace.Status(trace.StatusCode.ERROR))
条件によるtraceのフィルタリング
Jaegerはtagによるtrace検索をサポートしている。例えばユーザー12345のすべてのリクエストを検索したり、エラーのあるtraceをフィルタリングできる:
# Jaeger UIのTagsセクションで:
user.id=12345
# またはエラーのあるtraceを検索:
error=true
実運用から得た教訓
最初にセットアップした際、サンプリングレートを100%に設定した——つまりすべてのリクエストをtraceする。テスト時は問題なく動作した。しかし〜500 req/sの本番環境に投入すると、Jaeger UIがラグし始め、Collectorがspanをdropし始めた。最初からサンプリングレートを制限しておくべきだった:
from opentelemetry.sdk.trace.sampling import TraceIdRatioBased
# リクエストの10%だけtraceする
sampler = TraceIdRatioBased(0.1)
provider = TracerProvider(resource=resource, sampler=sampler)
アラートの設定も同様だった。500msを超えるすべてのspanにアラートを設定した結果、Telegramが1時間に数十件のアラートを受け取り、最終的に通知をオフにするはめになった。意味のある閾値にたどり着くまで何度も調整が必要だった。より良いアプローチ:個々のspanではなく、trace全体のエンドツーエンドレイテンシに基づいてアラートを設定すること。600msかかるspanが1つあっても、リクエスト全体が1秒以内に収まっていれば問題ではない場合もある。
もう一つ、小さいけれど多くの時間を節約できること:spanの名前を動詞-名詞のパターンで付けること。例えばfetch-user-profile、insert-order-db、send-notification-emailなど。50個のspanがあるtraceでは、processやhandlerのような曖昧な名前と比べて、明確な名前があればウォーターフォールチャートをずっと速く読み解ける。
Prometheusとの連携(オプション)
OTel CollectorはPrometheusにメトリクスをexportすることもできる——tracesとmetricsの両方を単一のパイプラインで処理できる:
# otel-collector-config.yamlに追加
exporters:
prometheus:
endpoint: "0.0.0.0:8889"
service:
pipelines:
metrics:
receivers: [otlp]
processors: [batch]
exporters: [prometheus]
インシデント発生時のワークフロー:GrafanaでレイテンシスパイクをKhám phá → 発生時刻を確認 → Jaegerでその時間帯のtraceをフィルタリング → 異常なdurationのtraceを特定 → 各spanをドリルダウン。アラートからroot causeの特定まで、以前のように3時間かけてログをgrepする代わりに、5分以内で完了することがほとんどだ。
