Posted inPython

PythonへのOpenTelemetry導入：マイクロサービス監視を実践するための勘所

Python tutorial - IT technology blog
Python tutorial - IT technology blog

深夜のマイクロサービス障害調査という悪夢

約半年前、私たちのチームはユーザーからの緊急アラートチケットの嵐に見舞われました。注文ボタンを押してもレスポンスが不安定で、2秒で完了することもあれば、14秒以上かかって最終的に504 Gateway Timeoutで切断されることもありました。当時のバックエンドは、REST APIやRedisキューを介して通信する4つのPythonサービス（FastAPIとFlask）で構成されていました。各サービスは、昔ながらのプレーンテキストログを別々のログファイルに出力している状態でした。

各サーバーにSSH接続してターミナルを開くと、毎分10万行以上のログが滝のように流れ続けていました。1つのユーザーリクエストが3〜4つのサービス間を横断しているにもかかわらず、そのリクエストを一貫して追跡できる共通IDは一切ありませんでした。決済サービスが遅延している原因がネットワークのボトルネックなのか、PostgreSQLのテーブルロックなのかすら特定できません。昔ながらのgrepによるログ調査は完全に限界を迎えていました。

この状況を打開するため、チームはPythonスタックにOpenTelemetry（OTel）を導入することを決断しました。本番環境で半年運用した結果、根本原因の特定（Root Cause Analysis）にかかる時間は45分以上から2分未満へと激減しました。今ではチーム全員がWeb UI上で、リクエストのミリ秒単位の挙動を明確に把握できるようになっています。

OpenTelemetryを正しく理解する：オブザーバビリティの3つの柱

本質的に、OpenTelemetryはCNCF（Cloud Native Computing Foundation）がホストするオープンソース標準であり、OpenTracingとOpenCensusの2大プロジェクトが統合されて誕生しました。OTel自体はデータの保存や可視化を行うツールではありません。その唯一にして最大の役割は、テレメトリデータの生成・収集・エクスポートを標準化することにあります。

この標準化のおかげで、ベンダーロックインを回避できます。今日はJaegerにデータを送信し、明日Datadog、Grafana Tempo、New Relicへと移行したくなった場合でも、環境変数を1行変更するだけで対応可能です。

OTelの監視データは、主に次の3つの要素で構成されています。

  • Traces（トレース）: 1つのリクエストの全体的な実行経路を表すマップです。その中の各処理単位はSpan（スパン）と呼ばれます（例：SQLクエリの実行、外部APIの呼び出しなど）。各スパンには実行時間、ステータスコード、任意のメタデータが含まれます。
  • Metrics（メトリクス）: メモリ使用量、1秒あたりのリクエスト数（RPS）、HTTP 5xxエラー率など、定期的に集計・計測される数値データです。
  • Logs（ログ）: タイムスタンプ付きのイベント記録ですが、トレースのコンテキストと強固に紐付けられている点が特徴です。

最大の強みはこの「相関性」にあります。あるスパンで800msの遅延が発生しているのを発見した際、同期されたtrace_idのおかげで、その800msの間に発生したピンポイントなログをワンクリックで確認できます。

実践：PythonプロジェクトへのOpenTelemetry実装

Pythonにおいて、OTelはAuto-instrumentation（自動計装・コード変更不要）とManual instrumentation（手動計装・独自ロジックの計測用コード記述）の2つのアプローチをサポートしています。ここでは両方の手法を見ていきましょう。

1. 必要なパッケージのインストール

クリーンな仮想環境を作成し、OTLP（OpenTelemetry Protocol）標準のエクスポーターとSDK一式をインストールします。

python3 -m venv venv
source venv/bin/activate

# OTel SDKと自動計装ツールのインストール
pip install opentelemetry-api opentelemetry-sdk
pip install opentelemetry-distro
pip install opentelemetry-exporter-otlp

# 既存のパッケージ（FastAPI, requests, SQLAlchemyなど）を自動検出し、対応プラグインを導入
opentelemetry-bootstrap -a install

2. Dockerを使用したJaeger All-in-Oneの起動

ローカル環境ですぐにトレースを可視化できるように、OTLPエンドポイントをネイティブでサポートしているJaegerコンテナを起動します。

docker run -d --name jaeger \
  -p 16686:16686 \
  -p 4317:4317 \
  -p 4318:4318 \
  jaegertracing/all-in-one:latest

押さえておくべき2つのポート：4317はgRPCプロトコル用（より高速かつ軽量）、4318はHTTP/Protobuf用です。

3. 方法1：Auto-instrumentation（コード変更ゼロの手法）

シンプルな注文処理を行うFastAPIのapp.pyがあると仮定します。

import time
import requests
from fastapi import FastAPI

app = FastAPI(title="Order Service")

@app.get("/orders/{order_id}")
def get_order(order_id: int):
    time.sleep(0.05)  # 内部処理のシミュレーション
    # 他のマイクロサービスや外部APIを呼び出す
    resp = requests.get("https://httpbin.org/delay/0.2")
    return {"order_id": order_id, "status": "success", "upstream_code": resp.status_code}

コードに手を加える代わりに、OpenTelemetry CLIを使ってUvicornの起動コマンドをラップします。

export OTEL_SERVICE_NAME="order-service"
export OTEL_EXPORTER_OTLP_ENDPOINT="http://localhost:4317"
export OTEL_EXPORTER_OTLP_INSECURE="true"

opentelemetry-instrument \
    --traces_exporter otlp \
    --metrics_exporter otlp \
    --logs_exporter otlp \
    uvicorn app:app --port 8000

curl http://localhost:8000/orders/402 でいくつかリクエストを送信してみます。ブラウザで http://localhost:16686 を開くと、きれいなウォーターフォール（waterfall）図が表示されます。FastAPI内部で50ms消費され、外部へのアウトバウンドHTTPリクエストに210msかかっていることが一目瞭然で分かります。

4. 方法2：Manual instrumentation（ビジネスロジックの手動計装）

自動計装は境界領域（HTTP通信やDBクエリ）の監視には非常に優れています。しかし、決済ロジック、クーポン割引計算、不正検知アルゴリズムといった内部処理を深く監視したい場合は、手動でスパンを生成する必要があります。

以下のコード例では、メインスレッドの処理速度を低下させないよう、TracerProviderにBatchSpanProcessorを設定して初期化しています。

import time
from opentelemetry import trace
from opentelemetry.sdk.trace import TracerProvider
from opentelemetry.sdk.trace.export import BatchSpanProcessor
from opentelemetry.sdk.resources import Resource, SERVICE_NAME
from opentelemetry.exporter.otlp.proto.grpc.trace_exporter import OTLPSpanExporter

# サービス識別子の初期化
resource = Resource(attributes={
    SERVICE_NAME: "payment-service",
    "deployment.environment": "production"
})

provider = TracerProvider(resource=resource)
# BatchSpanProcessorを使用してバッチ非同期送信を行い、CPUオーバーヘッドを1.5%未満に抑制
processor = BatchSpanProcessor(OTLPSpanExporter(endpoint="http://localhost:4317", insecure=True))
provider.add_span_processor(processor)
trace.set_tracer_provider(provider)

tracer = trace.get_tracer("payment.checker")

def process_payment(customer_id: str, amount: float):
    with tracer.start_as_current_span("process_payment_flow") as parent_span:
        parent_span.set_attribute("customer.id", customer_id)
        parent_span.set_attribute("payment.amount", amount)
        
        # 入力バリデーション処理の計測
        with tracer.start_as_current_span("validate_account") as val_span:
            if not customer_id.startswith("CUST_"):
                val_span.record_exception(ValueError("Invalid customer ID"))
                val_span.set_status(trace.StatusCode.ERROR, "顧客IDの形式が不正です")
                return False
            val_span.set_attribute("validation.passed", True)
            
        # ウォレット残高の引き落とし処理の計測
        with tracer.start_as_current_span("deduct_balance"):
            time.sleep(0.08)  # DBクエリ処理のシミュレーション
            
        return True

if __name__ == "__main__":
    process_payment("CUST_9912", 350000.0)

入力データのバリデーションロジック（顧客IDやトークンの形式チェックなど）を実装する際、正規表現（Regex）を頻繁に利用することになります。複雑な正規表現をコードに組み込む前に素早く検証したい場合は、toolcraft.app/ja/tools/developer/regex-tester のRegex Testerツールが役立ちます。ブラウザ上の直感的なUIでパターンマッチの成否を即座に確認できるため、手動でログを出力してデバッグする手間を省けます。

5. ログへのTrace ID自動注入

トレースコンテキストのないログは、その価値が半減してしまいます。出力されるすべてのログ行にtrace_idとspan_idを自動付与するには、公式ライブラリのフックを1行追加するだけで完了します。

import logging
from opentelemetry.instrumentation.logging import LoggingInstrumentor

# ログフォーマットへtrace_idとspan_idを自動注入
LoggingInstrumentor().instrument(set_logging_format=True)

logger = logging.getLogger("checkout")
logging.basicConfig(level=logging.INFO)

with tracer.start_as_current_span("create_invoice"):
    logger.info("請求書を発行中")
    # 実際の出力: [trace_id=4bf92f3577b34da6a3ce929d0e0e4736 span_id=00f067aa0ba902b7] 請求書を発行中

Grafana LokiやOpenSearchにログを集約している場合、オンコール担当のエンジニアはログに含まれるTrace IDをコピーしてJaegerに貼り付けるだけで、エラー発生時の全体コンテキストを一瞬で把握できます。当て推量による原因究明作業はもう不要です。

本番環境運用のための最適化ノウハウ

OTelを本番環境で実践運用するにあたり、押さえておくべき2つの重要ポイントがあります。

第1に、SimpleSpanProcessorではなく、必ずBatchSpanProcessorを使用することです。バッチプロセッサはスパンを取りまとめ、バックグラウンドスレッドで非同期送信するため、アプリケーションのレイテンシにほとんど影響を与えません（リクエストあたりのオーバーヘッドは通常2ms未満です）。

第2に、サンプリングレート（Sampling Rate）を適切に設定することです。システムが毎秒数千リクエスト規模に達すると、全トレースを100%記録することはネットワーク帯域とストレージ容量を激しく消費します。環境変数にOTEL_TRACES_SAMPLER=parentbased_traceidratioおよびOTEL_TRACES_SAMPLER_ARG=0.1を設定することで、正常なトレースは10%のみサンプリングしつつ、エラーを含むトレースは漏れなく記録できます。

最も実践的な導入ロードマップは、まずopentelemetry-instrumentによる自動計装から始めてネットワークやデータベースアクセスの全体像を掴むことです。仕組みに慣れてきた段階で、重要なビジネスロジック関数に対して手動スパンを追加していくのが確実です。

Share:
Tags: