Phoenix アプリケーションのローカル環境でのトレースを OpenTelemetry + Jaeger で気軽に可視化する

オブザーバビリティ高めて開発してますか？

昨今AIが台頭してきていて、開発の複雑度がより高まってきています。特にAIアプリの開発においては非決定的な振る舞いをすることが多いため、より「実際の動作」に基づいたデバック・開発が重要になります。

そこで今回は Phoenix アプリケーションで開発するときに Open Telemetry 形式でトレースを出し、Jaeger (イェーガー）で可視化してみます。

OpenTelemetry（OTel）は、アプリやサービスのログ・メトリクス・トレースを統一的に収集し、オブザーバビリティを実現するための標準仕様＋OSSツール群です。

Jaeger はマイクロサービス間のリクエストを追跡する 分散トレーシング の OSS です。
トレース可視化や性能分析、ボトルネック特定などを行うことが出来ます。
ローカルでは Docker だけで簡単に動かせ、直感的にトレーシング挙動をデバッグできるのが強みです。

これらを活用することでローカル環境で高いオブザーバビリティが実現でき、より詳細なローカルデバッグが可能になります。

バージョン

- Elixir 1.19.4
- Phoenix 1.8.2

Phoenix app の準備

Phoenix アプリを起動して API モードで users API を生やします。この時 DB を使用することとします。

mix phx.new otel_sample --no-html --no-assets
mix setup
mix phx.gen.json Accounts User users name:string
# resources "/users", UserController, except: [:new, :edit] を router.ex に追加
mix ecto.migrate

1000件ユーザーを作成

priv/repo/seeds.exs

alias OtelSample.Repo
alias OtelSample.Accounts.User

# Create 1000 users
for i <- 1..1000 do
  Repo.insert!(%User{
    name: "User #{i}"
  })
end

IO.puts("Created 1000 users")

mix run priv/repo/seeds.exs

動作確認

docker compose up -d
$ curl -s localhost:4000/api/users | cut -c 1-100
{"data":[{"id":1,"name":"User 1"},{"id":2,"name":"User 2"},{"id":3,"name":"User 3"},{"id":4,"name":"

動きました！これを計測していきます。

Open Telemetry のセットアップ

Open Telemetry 形式のトレースを出すためのライブラリを入れていきます。

この辺りを参考に。

ちなみに Phoenix 1.8 から Cowboy ではなく Bandit が HTTP サーバーとして採用されているので、 opentelemetry_cowboy は不要です。

mix.exs

      {:opentelemetry_exporter, "~> 1.7"},
      {:opentelemetry, "~> 1.4"},
      {:opentelemetry_api, "~> 1.3"},
      {:opentelemetry_phoenix, "~> 1.2"},
      {:opentelemetry_ecto, "~> 1.2"}

mix deps.get

必要な設定をします。

config/dev.exs

config :opentelemetry,
  resource: [
    service: [
      name: System.get_env("OTEL_SERVICE_NAME", "otel_sample")
    ]
  ]

config :opentelemetry_exporter,
  otlp_protocol: :http_protobuf,
  otlp_endpoint: System.get_env("OTEL_EXPORTER_OTLP_ENDPOINT", "http://localhost:4318")

lib/otel_sample/application.ex

    # Setup OpenTelemetry handlers
    OpentelemetryPhoenix.setup()
    OpentelemetryEcto.setup([:otel_sample, :repo])

Jaeger の設定

jaeger のコンテナ設定と jaeger に送るための環境変数設定をします。今回はアプリケーションやDBもDocker上で立てましたが、jaeger だけコンテナにしてその他はホストマシンに直接立てる構成でもいいです。

compose.yml

services:
  web:
    build:
      context: .
      # Mac ユーザーなど、ホストとコンテナのユーザー情報を合わせたくない場合は以下不要です
      args:
        - host_user_name=${host_user_name}
        - host_group_name=${host_group_name}
        - host_uid=${host_uid}
        - host_gid=${host_gid}
    command: mix phx.server
    environment:
      DB_HOST: db
      OTEL_EXPORTER_OTLP_ENDPOINT: http://jaeger:4318
      OTEL_SERVICE_NAME: otel_sample
    depends_on:
      - db
      - jaeger
    ports:
      - 4000:4000
    volumes:
      - .:/work
    working_dir: /work
  db:
    image: postgres:17-alpine
    environment:
      POSTGRES_PASSWORD: postgres
    ports:
      - 5432:5432
    volumes:
      - dbdata:/var/lib/postgresql/data
  jaeger:
    image: jaegertracing/jaeger:2.13.0
    ports:
      - 16686:16686  # Jaeger UI
      - 4318:4318    # OTLP HTTP receiver
volumes:
  dbdata:

トレースをみてみる

では実際にリクエストを流してみましょう。

$ curl -s localhost:4000/api/users | cut -c 1-100
{"data":[{"id":1,"name":"User 1"},{"id":2,"name":"User 2"},{"id":3,"name":"User 3"},{"id":4,"name":"

http://localhost:16686 にアクセスすると Jaeger ダッシュボードが出ます！

対象を指定して Find Trace を押すことで可視化できます。
このようにどこでどのくらい時間がかかっているかが一目で分かるようになっています！

k6 で大量のリクエストを投げてみる。

k6 は、開発者向けのスクリプトベースの負荷テストツールです。
JavaScript でシナリオを書き、API・Webサービスへ負荷をかけて性能を測定できます。
これを使ってさらにリクエストを投げてトレースをみてみます。

k6-script.js

import http from 'k6/http';
import { check, sleep } from 'k6';

export const options = {
  iterations: 10,
};

export default function () {
  const baseUrl = 'http://web:4000/api/users';

  // GET /api/users - List all users
  let res = http.get(baseUrl);
  check(res, {
    'GET /api/users status is 200': (r) => r.status === 200,
  });
  sleep(0.1);

  // POST /api/users - Create a user
  const payload = JSON.stringify({
    user: {
      name: `K6 User ${Date.now()}`,
    },
  });
  res = http.post(baseUrl, payload, {
    headers: { 'Content-Type': 'application/json' },
  });
  check(res, {
    'POST /api/users status is 201': (r) => r.status === 201,
  });

  const userId = res.json('data.id');
  sleep(0.1);

  if (userId) {
    // GET /api/users/:id - Show a user
    res = http.get(`${baseUrl}/${userId}`);
    check(res, {
      'GET /api/users/:id status is 200': (r) => r.status === 200,
    });
    sleep(0.1);

    // PUT /api/users/:id - Update a user
    const updatePayload = JSON.stringify({
      user: {
        name: `Updated User ${Date.now()}`,
      },
    });
    res = http.put(`${baseUrl}/${userId}`, updatePayload, {
      headers: { 'Content-Type': 'application/json' },
    });
    check(res, {
      'PUT /api/users/:id status is 200': (r) => r.status === 200,
    });
    sleep(0.1);

    // DELETE /api/users/:id - Delete a user
    res = http.del(`${baseUrl}/${userId}`);
    check(res, {
      'DELETE /api/users/:id status is 204': (r) => r.status === 204,
    });
    sleep(0.1);
  }
}

$ docker run --rm -i --network otel_sample_default -v "$PWD/k6-script.js:/k6-script.js" grafana/k6 run /k6-script.js

         /\      Grafana   /‾‾/  
    /\  /  \     |\  __   /  /   
   /  \/    \    | |/ /  /   ‾‾\ 
  /          \   |   (  |  (‾)  |
 / __________ \  |_|\_\  \_____/ 

     execution: local
        script: /k6-script.js
        output: -

     scenarios: (100.00%) 1 scenario, 1 max VUs, 10m30s max duration (incl. graceful stop):
              * default: 10 iterations shared among 1 VUs (maxDuration: 10m0s, gracefulStop: 30s)


running (00m01.0s), 1/1 VUs, 0 complete and 0 interrupted iterations
default   [   0% ] 1 VUs  00m01.0s/10m0s  00/10 shared iters

running (00m02.0s), 1/1 VUs, 2 complete and 0 interrupted iterations
default   [  20% ] 1 VUs  00m02.0s/10m0s  02/10 shared iters

running (00m03.0s), 1/1 VUs, 3 complete and 0 interrupted iterations
default   [  30% ] 1 VUs  00m03.0s/10m0s  03/10 shared iters

running (00m04.0s), 1/1 VUs, 4 complete and 0 interrupted iterations
default   [  40% ] 1 VUs  00m04.0s/10m0s  04/10 shared iters

running (00m05.0s), 1/1 VUs, 5 complete and 0 interrupted iterations
default   [  50% ] 1 VUs  00m05.0s/10m0s  05/10 shared iters

running (00m06.0s), 1/1 VUs, 6 complete and 0 interrupted iterations
default   [  60% ] 1 VUs  00m06.0s/10m0s  06/10 shared iters

running (00m07.0s), 1/1 VUs, 7 complete and 0 interrupted iterations
default   [  70% ] 1 VUs  00m07.0s/10m0s  07/10 shared iters

running (00m08.0s), 1/1 VUs, 8 complete and 0 interrupted iterations
default   [  80% ] 1 VUs  00m08.0s/10m0s  08/10 shared iters

running (00m09.0s), 1/1 VUs, 9 complete and 0 interrupted iterations
default   [  90% ] 1 VUs  00m09.0s/10m0s  09/10 shared iters


  █ TOTAL RESULTS 

    checks_total.......: 50      5.274873/s
    checks_succeeded...: 100.00% 50 out of 50
    checks_failed......: 0.00%   0 out of 50

    ✓ GET /api/users status is 200
    ✓ POST /api/users status is 201
    ✓ GET /api/users/:id status is 200
    ✓ PUT /api/users/:id status is 200
    ✓ DELETE /api/users/:id status is 204

    HTTP
    http_req_duration..............: avg=88.31ms min=61.83ms  med=90.36ms  max=119.75ms p(90)=106.45ms p(95)=108.35ms
      { expected_response:true }...: avg=88.31ms min=61.83ms  med=90.36ms  max=119.75ms p(90)=106.45ms p(95)=108.35ms
    http_req_failed................: 0.00%  0 out of 50
    http_reqs......................: 50     5.274873/s

    EXECUTION
    iteration_duration.............: avg=947.8ms min=878.61ms med=950.49ms max=1s       p(90)=992.69ms p(95)=999.72ms
    iterations.....................: 10     1.054975/s
    vus............................: 1      min=1       max=1
    vus_max........................: 1      min=1       max=1

    NETWORK
    data_received..................: 301 kB 32 kB/s
    data_sent......................: 5.8 kB 607 B/s




running (00m09.5s), 0/1 VUs, 10 complete and 0 interrupted iterations
default ✓ [ 100% ] 1 VUs  00m09.5s/10m0s  10/10 shared iters

複数のリクエストでもいい感じに表示できています。

カスタムメトリクスを入れてみる。

ローカルデバッグのためにピンポイントでトレースを入れたいことがあります。これをすることで任意の箇所でトレースを出すことができ、より詳細にどこが遅いのかを測定できます。

  def create(conn, %{"user" => user_params}) do
    Tracer.with_span "UserController.create" do
      Tracer.set_attributes([{"controller.action", "create"}, {"user.name", user_params["name"]}])

      result =
        Tracer.with_span "Accounts.create_user" do
          Tracer.set_attributes([{"attrs.name", user_params["name"]}])
          Accounts.create_user(user_params)
        end

      with {:ok, %User{} = user} <- result do
        Tracer.set_attributes([{"user.id", user.id}, {"result", "success"}])

        conn
        |> put_status(:created)
        |> put_resp_header("location", ~p"/api/users/#{user}")
        |> render(:show, user: user)
      end
    end
  end

改めてk6でリクエストを実行します。

docker run --rm -i --network otel_sample_default -v "$PWD/k6-script.js:/k6-script.js" 
grafana/k6 run /k6-script.js

このようにより詳細なトレースを見ることができるようになりました。

LiveDashboard と併用するとさらに強力！

Phoenix はデフォルトで LiveDashboard があります。
Phoenix LiveDashboard は、Phoenix アプリの状態（メトリクス、Erlang VM の情報、プロセス、ログなど）をリアルタイムで可視化する管理ダッシュボードです。
dev/dashboard にアクセスするだけでメトリクスを見ることができます。

LiveDashboard と Jaeger は似ていますが、それぞれメトリクスか分散トレーシングかで役割が違います。そのため、これらを併用することで、よりデバッグが捗ります。

• LiveDashboard
  • Phoenix／Elixir アプリの 内部状態のリアルタイム監視
  • 例：Erlang VM、プロセス、メトリクス、IEx 情報など
• Jaeger
  • 分散トレーシングの可視化ツール
  • 例：リクエストがマイクロサービス間をどう流れたか、遅い箇所はどこか

永続化する

現状では Jaeger に流したデータは永続化されないので、コンテナを再起動したら消滅します。
永続化したい場合は以下のように設定を追加してください。

compose.yml

+    volumes:
+      - jaeger-badger:/badger
+      - ./jaeger-config.yaml:/etc/jaeger/config.yaml
+    user: root
+    command:
+      - "--config=/etc/jaeger/config.yaml"
volumes:
  dbdata:
+  jaeger-badger:

jarger-config.yaml

service:
  extensions: [jaeger_storage, jaeger_query]
  pipelines:
    traces:
      receivers: [otlp]
      exporters: [jaeger_storage_exporter]

extensions:
  jaeger_storage:
    backends:
      app_storage:
        badger:
          ephemeral: false
          directories:
            keys: /badger/key
            values: /badger/data

  jaeger_query:
    storage:
      traces: app_storage

receivers:
  otlp:
    protocols:
      grpc:
        endpoint: 0.0.0.0:4317
      http:
        endpoint: 0.0.0.0:4318

exporters:
  jaeger_storage_exporter:
    trace_storage: app_storage

オブザーバビリティの高い開発ライフを！

今回の記事で使用したサンプルアプリケーションは以下に置いているので、参考にしてみてください。

Phoenix はライブラリを入れるだけで簡単に OTel 対応できるのが非常に良いですね。
良きオブザーバビリティライフを！