PythonプロジェクトにOpenTelemetryを導入する

こんにちは。Quipu という原価計算システムの開発をしている山田です。

最近まで原価計算システムのバックエンドのアーキテクチャを変更するプロジェクトをチームで進めていて、その中で Python プロジェクトに導入してよかった OpenTelemetry について共有したいと思います。

原価計算システムのアーキテクチャ変更に伴うパフォーマンス懸念

原価計算システムはいくつかのマイクロサービスによって動いていました。フロントエンド、フロントエンドから GraphQL のリクエストを受ける BFF、ビジネスドメインを扱う Rust の gRPC サーバ。今回この Rust の gRPC サーバのアーキテクチャ変更により、 Python で実装された価格計算システムと「見積」を管理する Rust の gRPC サーバというドメインの境界を設けてアプリケーションを分割しています。

今まで Rust で実装されていた原価計算処理を Python で実装しなおしました。Python で実装しなおした経緯としては、新しく原価計算処理を実装する人にとっても変更がしやすい設計にしたいというのがありました。加えて、開発者のみならず実際に原価計算の中身を変更するようなメンバーでも、実際システムとして動いているアプリケーションを変更できた方が良いという結論になったので学習しやすい Python の方が適していると判断した経緯もあります。

今までは原価計算処理についても Rust で実装されたシステムが動いていたのでサービスとしても一つでしたが、これを Rust と Python との分割されたマイクロサービスに変更したことで、ネットワーク越しに計算処理を実行することになります。新しい原価計算アプリケーションを導入するにあたってのパフォーマンスのボトルネック解消をチームで行っていました。1 つのサービスをデバッガやプロファイラなどを用いてパフォーマンスチューニングすることは十分できますが、マイクロサービス間のリクエストのパフォーマンスをチェックすることは現状難しかったのです。なのでこの部分に分散トレースシステムを導入して、より良いパフォーマンスを目指すための下地を作ることになりました。

OpenTelemetry について

OpenTelemetry[1] は分散トレースを実現するためのフレームワークとそれらを提供するライブラリの名称で CNCF の incubating プロジェクトです。 OpenTracing と OpenCensus が合併して OpenTelemetry という名称で進められています。トレース情報やレイテンシなどアプリケーションの実行にまつわるデータの管理のために設計された API や SDK などのフレームワークになっていて、どんなベンダにも依存せずにデータを扱うことができるようになっています。現在僕らのチームではこれらのデータを Google が提供している Cloud Trace に送っています。 僕らのチームでは Python のアプリケーションを本格的に運用するのは初めてでしたが、Node.js で実装された BFF や見積を扱っている Rust で実装された gRPC サービスでは OpenTelemetry を導入してネットワーク間のリクエストの可視化ができていたのでその土台に Python のマイクロサービスも載せることで、一様にリクエストのレイテンシを可視化することができます。

OpenTelemetry の導入

必要になったライブラリ

今回 Python で実装された原価計算処理システムに実際導入するにあたって行ったことを紹介していきます。以降は OpenTelemetry の用語を使っているので、必要に応じて OpenTelemetry が用意している Glossary[2] を参照してください。

API や SDK 周りのライブラリ

API や SDK 周りのライブラリを導入してトレース情報として取得したい単位でアプリケーションコードにトレース情報を取得する実装ができます。これらのモジュールにより Span を作成したり、トレース情報を送信し始めることができます。実際には opentelemetry-apiopentelemetry-sdk をインストールして利用します[3]

トレース情報を任意のサービスに送信するライブラリ

トレース情報を送信するためにいくつかライブラリを導入します。開発の時にうまく送信できているかを確認するため Jaeger を開発環境で使用しているのでその exporter と、実際に本番環境などでトレース情報を送信するため、 Google Cloud Trace に export するためのライブラリ[4]を導入しています。 今回のプロジェクトでは opentelemetry-exporter-jaegeropentelemetry-exporter-gcp-trace を利用して実現します。

各種ライブラリやモジュールの自動的な設定を行うライブラリ

今回のシステムではウェブアプリケーションフレームワークとして starlette を利用しているので、送られてきた trace context を自動的に解釈してくれるライブラリとして instrumentation ライブラリ opentelemetry-instrumentation-starlette を導入します。 今回は導入しなかったですがそのほかにもさまざまなライブラリに対応した instrumentation が存在します[5]

上記のライブラリ群を導入することで Python のアプリケーションでも OpenTelemetry が利用できます。

OpenTelemetry を実際に導入する

まずは OpenTelemetry でトレースを始める部分のコードを書いてみましょう。 TracerProvider を使ってトレースを始めることができます。また、開始した TracerProvider を様々な箇所で API 経由で取得できるように trace.set_tracer_provider で設定します。

from opentelemetry import trace
from opentelemetry.sdk.trace import TracerProvider

tracer_provider = TracerProvider()

trace.set_tracer_provider(tracer_provider=tracer_provider)

トレース情報を全てのリクエストで取得する必要がないケースが存在します。例えば送られるデータ量が多くなってしまうので減らしたり、親のトレースに依存してトレース情報を取得するかどうか判断したいなどさまざまなケースでトレース情報をサンプリングできると嬉しいです。今回のアプリケーションは基本的にリクエストの末端に位置するアプリケーションになるので、サンプリングは親のトレースに任せる形にしました。その挙動がライブラリのデフォルトになっているので今回は指定しませんが、必要があれば sampler という引数を指定するか OTEL_TRACES_SAMPLER という環境変数を利用してトレースするかどうかを制御することができるようになっていました。

from opentelemetry.sdk.trace import TracerProvider
from opentelemetry.sdk.trace.samplers import TraceIdRatioBased

# 1000 回に 1 回だけトレースする
tracer_provider = TracerProvider(sampler=TraceIdRatioBased(1/1000))

アプリケーションがリクエストを受け取った地点からこの Python アプリケーションのトレース情報を取得できるように instrumentation を導入します。僕らは starlette を使っているので opentelemetry-instrumentation-starlette を導入します。このライブラリが提供する StarletteInstrumentor を利用することで自動的にトレース情報の収集ができます。

from opentelemetry.instrumentation.starlette import StarletteInstrumentor
from starlette.applications import Starlette

routes = [
  // ルーティングの定義
]

app = Starlette(routes=routes)

StarletteInstrumentor.instrument_app(app)

アプリケーションとしてトレース情報が取得できるようになったので、これを Jaeger や Google Cloud Trace に送信するための設定を行いましょう。開発環境では標準出力にトレース情報を出力したり、Jaeger にトレース情報を export しつつ、本番環境では Google Cloud Trace にトレース情報を export します。以下のサンプルコードでは基本的にデフォルトの設定値を使うようになっています。

from opentelemetry.sdk.trace.export import BatchSpanProcessor, ConsoleSpanExporter, SimpleSpanProcessor

# 標準出力にトレース情報を出力するための span processor
tracer_provider.add_span_processor(
  span_processor=SimpleSpanProcessor(span_exporter=ConsoleSpanExporter())
)

# Jaeger にトレース情報を export するための span processor
tracer_provider.add_span_processor(
  span_processor=BatchSpanProcessor(span_exporter=JaegerSpanExporter())
)

# Google Cloud Trace にトレース情報を export するための span processor
tracer_provider.add_span_processor(
  span_processor=BatchSpanProcessor(span_exporter=CloudTraceSpanExporter())
)

基本的には以上のことを行うだけで、アプリケーションに対して in-coming なリクエストがあった場合にそれがトレースされるようになります。しかしこれだけではリクエスト全体のレイテンシがわかるようになるだけで、全ての関数が自動的にトレースされるわけでも重たい処理がどこにあるかどうかなどがわかるわけでもありません。それ自体は自分でトレース情報を作成してあげる必要があります。

OpenTelemetry の API としてトレース情報を自分で作成して紐づける方法があるのでそれを利用して処理のトレース情報を増やしていきましょう。tracer オブジェクトを取得して、その start_as_current_span メソッドを利用してトレース情報を作成します。このメソッドは @contextmanager デコレータが利用されているため with 文で使います。 例えば以下のようにして実際の処理のトレース情報を作成することができます。

from opentelemetry import trace

tracer = trace.get_tracer_provider().get_tracer(__name__)

def very_expensive_my_function() -> None:
  with tracer.start_as_current_span('foo'):
    # foo span が生成される

  with tracer.start_as_current_span('bar'):
    # foo span と同じレベルの bar span が生成される

    with tracerr.start_as_current_span('baz'):
      # bar span の子要素として baz span が生成される

上記のような方法でトレースできることがわかりました。実際トレースしたい箇所で毎回 tracer オブジェクトを生成していくのは少し大変なのと、ここまで詳細に処理を span として分割したいというよりもある関数全体でどれくらいのレイテンシなのかがわかるだけで十分なことが多いです。そこで関数のデコレータを用意して、そのデコレータが付与された関数は自動的に全体がトレースされるというようなものを作ってみましょう。ここでは @instrument というようなデコレータを作成します。

from functools import wraps
from opentelemetry import trace

tracer = trace.get_tracer_provider().get_tracer(__name__)

def instrument(fn=None):
  def decorator(fn):
    @wraps(fn)
    def wrapper(*args, **kwargs):
      # デコレータを付与する関数名・メソッド名の qualified name
      name = fn.__qualname__

      # デコレータが付与された関数名を span の名前として指定する
      with tracer.start_as_current_span(name=name):
        return fn(*args, **kwargs)

    return wrapper

  # @instrument でも @instrument() でも使えるようにするため
  if fn is None:
    return decorator

  return decorator(fn)

@instrument
def very_expensive_my_function() -> None:
  # 何らかの処理

この定義した @instrument デコレータを用いて大まかに関数全体のレイテンシを計測することができるようになりました。これを各種関数やクラスのメソッドに適用することでレイテンシが計測できていなかったもう少し詳しい部分までトレースできるようになりました。

OpenTelemetry を導入した結果

今回原価計算システムを Rust から Python に書き直したことでプロダクション環境に大きなパフォーマンス劣化の懸念が存在していました。今回 OpenTelemetry を導入して、 UI から発行されるリクエストベースで原価計算システムのトレース情報を取得することができるようになりました。これによりプロダクション環境に今回の変更を入れることでパフォーマンスにどう影響があるかが可視化されました。

Google Cloud Trace で可視化した結果

当初実装していた API ではパフォーマンスに大きな劣化が生じてしまうことが事前にわかり、それを解決するために API の設計を変更し API の粒度を小さくして並列に API を呼び出すように変更しました。非同期で複数の計算結果を処理する形になり、結果としてパフォーマンスは小さな影響だけで済む形でリリース可能だと判断することができました。また Google Cloud Trace ではトレース情報をもとに日次や週次でレポートを作成することができるので、パフォーマンス改善を行ったときに前と比べてベースラインがどのように変化しているのかということも確認できるようになったのが導入した利点として大きかったです。

おわりに

Python のプロジェクトで OpenTelemetry の導入をしてみましたが、しっかりライブラリ群は作り込まれていて自分達が利用しているライブラリのトレース情報を自動的に取れるようなライブラリもコミュニティで開発されていたこともありスムーズに導入が完了できました。

僕たちのチームでは Node.js や Rust でも OpenTelemetry が導入されていた背景もあり、サービス全体で分散トレーシングができるようになりました。発行されたリクエスト一つをとってみてシステム全体でどのような処理が行われているのかが確認できるようになったので、これらの資産を活かして開発効率を向上させていければと思っています。

OpenTelemetry の specification が v1.0 になってまだ 1 年です。これからもっと発展させていけるようにコミュニティに還元できることがないか利用しながら調査を進めていければと思っています。


参考