Next.jsのサーバーサイド処理をX-Rayでトレースしてみた

OpenTelemetryのSDKとaws-otel-collectorを使ってX-Rayにトレース情報を送信してみました
2023.02.27

この記事は公開されてから1年以上経過しています。情報が古い可能性がありますので、ご注意ください。

私が今関わっているプロジェクトではフロントエンドの実装にNext.jsのSSRを利用しています。この処理の中では多数の外部APIを呼び出しているため、システムのオブザーバビリティを担保するためにX-Rayを導入することにしました。このブログではNext.jsとX-Rayを連携させる手順と苦労した点などをご紹介します。

環境

今回利用した環境です

  • Node.js: v18
  • Next.js: 13.1.6
  • opentelemetry系のライブラリ
    • @opentelemetry/api: 1.4.0
    • @opentelemetry/exporter-trace-otlp-http: 0.35.1
    • @opentelemetry/id-generator-aws-xray: 1.1.1
    • @opentelemetry/instrumentation-http: 0.35.1
    • @opentelemetry/propagator-aws-xray: 1.2.0
    • @opentelemetry/resources: 1.9.1
    • @opentelemetry/sdk-node: 0.35.1
    • @opentelemetry/sdk-trace-base: 1.9.1
    • @opentelemetry/semantic-conventions: 1.9.1
  • aws-otel-collector: v0.26.0

ざっくり構成

Next.jsからX-Rayにトレース情報を送信するためにはOpenTelemetry SDK for Node.jsが利用できます。このSDKを利用してNext.jsからOpenTelemetryのCollectorに各種トレースデータを送信し、CollectorがX-Rayまでトレース情報を中継してくれる形になります。ざっくりいうと

Next.js → Collector → X-Ray

という流れになります。

やってみる

まずはNext.jsの新規プロジェクト作成です。npx create-next-appでサクッと作成しましょう。

プロジェクトが作成できたら必要なライブラリを導入します

yarn add @opentelemetry/api \
    @opentelemetry/exporter-trace-otlp-http \
    @opentelemetry/id-generator-aws-xray \
    @opentelemetry/instrumentation-http \
    @opentelemetry/propagator-aws-xray \
    @opentelemetry/resources \
    @opentelemetry/sdk-node \
    @opentelemetry/sdk-trace-base \
    @opentelemetry/semantic-conventions

インストルメンテーション処理の実装

ここからトレース情報を送信するためのインストルメンテーション処理を実装していきます。OpenTelemetry SDK for Node.jsを利用したインストルメンテーション処理はOpenTelemetryのデモ用システムのコードが参考になります。

https://github.com/open-telemetry/opentelemetry-demo/blob/d23431fcb8d2c78e14128f549ca1a56461d49b25/src/frontend/utils/telemetry/Instrumentation.js

ただし、上記のコードそのままだとX-Rayにトレース情報を送信できません。トレースIDのフォーマットなどはX-Rayの仕様に合わせて採番してやる必要があるためです。

X-Rayに合わせた微調整はAWS Distro for OpenTelemetryで公開されている以下のページが参考になります。

https://aws-otel.github.io/docs/getting-started/js-sdk/trace-manual-instr#sending-traces-to-aws-x-ray

最終的に完成したコードは以下の通りです。

instrumentation.js

const { OTLPTraceExporter } = require('@opentelemetry/exporter-trace-otlp-http')
const { AWSXRayIdGenerator } = require('@opentelemetry/id-generator-aws-xray')
const { HttpInstrumentation } = require('@opentelemetry/instrumentation-http')
const { AWSXRayPropagator } = require('@opentelemetry/propagator-aws-xray')
const { Resource } = require('@opentelemetry/resources')
const opentelemetry = require('@opentelemetry/sdk-node')
const { BatchSpanProcessor } = require('@opentelemetry/sdk-trace-base')
const {
  SemanticResourceAttributes,
} = require('@opentelemetry/semantic-conventions')

const exporterOptions = {
  url: 'http://127.0.0.1:4318/v1/traces',
}
const traceExporter = new OTLPTraceExporter(exporterOptions)
const sdk = new opentelemetry.NodeSDK({
  textMapPropagator: new AWSXRayPropagator(),
  resource: new Resource({
    [SemanticResourceAttributes.SERVICE_NAME]: 'next.js',
  }),
  traceExporter,
  instrumentations: [new HttpInstrumentation()],
})

const tracerConfig = {
  idGenerator: new AWSXRayIdGenerator(),
}
const spanProcessor = new BatchSpanProcessor(traceExporter)
sdk.configureTracerProvider(tracerConfig, spanProcessor)

sdk
  .start()
  .then(() => console.log('Tracing initialized'))
  .catch((error) => console.log('Error initializing tracing', error))

const shutdown = async () => {
  await sdk
    .shutdown()
    .then(() => console.log('Tracing terminated'))
    .catch((error) => console.log('Error terminating tracing', error))
    .finally(() => process.exit(0))
}

process.on('SIGINT', shutdown)
process.on('SIGTERM', shutdown)

ポイントをいくつか紹介しておきます。

以下の部分でCollectorのURLを指定しています。この記述に合わせて後ほどCollectorを4318ポートで起動させます。

const exporterOptions = {
  url: 'http://127.0.0.1:4318/v1/traces',
}

X-Rayに対応するためのコードが以下です。NodeSDKのインスタンスを作成する時のオプションtextMapPropagatorAWSXRayPropagator()を指定しています。

const sdk = new opentelemetry.NodeSDK({
  textMapPropagator: new AWSXRayPropagator(),
  resource: new Resource({
    [SemanticResourceAttributes.SERVICE_NAME]: 'next.js',
  }),
  traceExporter,
  instrumentations: [new HttpInstrumentation()],
})

また以下の部分でトレースIDをX-Rayの仕様に合わせて採番するように調整しています。

const tracerConfig = {
  idGenerator: new AWSXRayIdGenerator(),
}
const spanProcessor = new BatchSpanProcessor(traceExporter)
sdk.configureTracerProvider(tracerConfig, spanProcessor)

Next.jsのプロセスがシグナル(SIGINT/SIGTERM)を受け取った時の処理として以下の処理を記述しています。

const shutdown = async () => {
  await sdk
    .shutdown()
    .then(() => console.log('Tracing terminated'))
    .catch((error) => console.log('Error terminating tracing', error))
    .finally(() => process.exit(0))
}

process.on('SIGINT', shutdown)
process.on('SIGTERM', shutdown)

Shutdownに関してはOpenTelemetry specificationに以下のように記述されています

This method provides a way for provider to do any cleanup required.

Shutdown MUST be called only once for each LoggerProvider instance. After the call to Shutdown, subsequent attempts to get a Logger are not allowed. SDKs SHOULD return a valid no-op Logger for these calls, if possible.

Shutdown SHOULD provide a way to let the caller know whether it succeeded, failed or timed out.

Shutdown SHOULD complete or abort within some timeout. Shutdown MAY be implemented as a blocking API or an asynchronous API which notifies the caller via a callback or an event. OpenTelemetry SDK authors MAY decide if they want to make the shutdown timeout configurable.

Shutdown MUST be implemented at least by invoking Shutdown on all registered LogRecordProcessors.

https://github.com/open-telemetry/opentelemetry-specification/blob/8946dfc6a2302f78b0224fcc3f4dfb816a7bb1f4/specification/logs/sdk.md

SDKの内部処理まで追いかけていないですが、shutdownを呼び出さない場合、Collectorのキューに溜まったトレース情報がX-Rayに送信されないまま破棄されるといったことが想定されそうです。注意点としてこちらの一連のインストルメンテーション処理はNext.jsのサーバーが起動する前に呼び出す想定で作成しています。Next.jsのサーバーにいわゆるGracefulシャットダウンを実装したい場合は上記の実装では対応できないことに注意して下さい。今回作成しているシステムのデプロイ先はALB配下のECSサービスを想定しているため、Next.jsサーバーのGracefulシャットダウン処理に関して考慮していません。

Graceful shutdowns with ECS

package.jsonの調整

インストルメンテーション処理が実装できたので、Next.jsサーバー起動前にインストルメンテーション処理を読み込むようにnpmスクリプトを修正します。

   "scripts": {
-    "dev": "next dev",
+    "dev": "NODE_OPTIONS='-r ./instrumentation.js' next dev",
     "build": "next build",
-    "start": "next start",
+    "start": "NODE_OPTIONS='-r ./instrumentation.js' next start",

これでnext devnext start実行前にインストルメンテーション処理が呼び出されます。試しにyarn devもしくはnpm run devで問題なくNext.jsサーバーが起動することを確認しておきましょう。以下のようにコマンドが正常終了すればOKです。

yarn dev
yarn run v1.22.19
$ NODE_OPTIONS='-r ./instrumentation.js' next dev
Tracing initialized
Tracing initialized
ready - started server on 0.0.0.0:3000, url: http://localhost:3000
event - compiled client and server successfully in 1869 ms (163 modules)
wait  - compiling /_error (client and server)...
event - compiled client and server successfully in 109 ms (164 modules)
warn  - Fast Refresh had to perform a full reload. Read more: https://nextjs.org/docs/messages/fast-refresh-reload
wait  - compiling / (client and server)...
event - compiled client and server successfully in 371 ms (189 modules)
warn  - Fast Refresh had to perform a full reload. Read more: https://nextjs.org/docs/messages/fast-refresh-reload

Collectorの起動

ここまででNext.js側の準備が整ったので、トレース情報をX-Rayまで送信するためにCollectorを起動しましょう。aws-otel-collectorのコンテナイメージがECR Publicで公開されているので、こちらのイメージを利用します。

CollectorからX-Rayに書き込み権限が必要なので、事前にIAMロール等を用意してassume roleなりで一時クレデンシャルを取得してdocker runのオプションに渡してやって下さい。

docker run --rm -p 4318:4318 -e AWS_REGION=ap-northeast-1 -e AWS_ACCESS_KEY_ID=<アクセスキーID> -e AWS_SECRET_ACCESS_KEY=<アクセスキー> -e AWS_SESSION_TOKEN=<セッショントークン> public.ecr.aws/aws-observability/aws-otel-collector

この状態で再度Next.jsサーバーを起動してブラウザからアクセスした後X-Rayのマネコンを確認してみましょう。

無事にトレース結果が表示できました。が、favicon.icoへのアクセスなどもトレースされており、かなりノイズが多い印象です。静的コンテンツの取得までいちいちトレースしたくないので、トレース対象をうまくフィルタしたいところです。

フィルタの追加

トレース対象のフィルタにはFilter Processorが利用できます。StabilityがAlphaである点に注意が必要ですが、今回はこちらのFilter Processorを使い、アクセスされたURLに基づいてトレース対象をフィルタしてみます。と、いったものの、URLに基づいたフィルタをどのように書けば良いか分からないので、まずはフィルタの書き方にあたりをつけたいと思います。さきほどCollectorを起動した際はデフォルトの設定を利用しましたが、明示的にログ出力の設定を追加してCollectorを起動し、フィルタの書き方にあたりをつけていきます。まず以下の設定ファイルを用意して下さい。

otel-config.yaml

extensions:
  health_check:
receivers:
  otlp:
    protocols:
      http:
        endpoint: 0.0.0.0:4318
  awsxray:
    endpoint: 0.0.0.0:2000
    transport: udp

processors:
  batch/traces:
    timeout: 1s
    send_batch_size: 50

exporters:
  awsxray:
  logging:
    verbosity: detailed
    sampling_initial: 5
    sampling_thereafter: 200
service:
  pipelines:
    traces:
      receivers: [otlp,awsxray]
      processors: [filter, batch/traces]
      exporters: [logging]

  extensions: [health_check]

先程のdocker runコマンドを少し修正し、上記設定ファイルを/etc/otel-config.yamlにマウントするようにしてCollectorを起動します

docker run -v $(pwd)/otel-config.yaml:/etc/ecs/otel-config.yaml --rm -p 4318:4318 ...略 public.ecr.aws/aws-observability/aws-otel-collector

この状態でNext.jsにアクセスするとトレース情報がCollectorの標準出力に出力されます。

Span #32
    Trace ID       : 63fa0a2e66371a8a261221af7340a866
    Parent ID      :
    ID             : 070ba1a597d6e591
    Name           : HTTP GET
    Kind           : Server
    Start time     : 2023-02-25 13:16:30.14 +0000 UTC
    End time       : 2023-02-25 13:16:30.1418716 +0000 UTC
    Status code    : Unset
    Status message :
Attributes:
     -> http.url: Str(http://localhost:3000/favicon.ico)
     -> http.host: Str(localhost:3000)
     -> net.host.name: Str(localhost)
     -> http.method: Str(GET)
     -> http.scheme: Str(http)
     -> http.target: Str(/favicon.ico)
     -> http.user_agent: Str(Mozilla/5.0 (Macintosh; Intel Mac OS X 10_15_7) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/110.0.0.0 Safari/537.36)
     -> http.flavor: Str(1.1)
     -> net.transport: Str(ip_tcp)
     -> net.host.ip: Str(::1)
     -> net.host.port: Int(3000)
     -> net.peer.ip: Str(::1)
     -> net.peer.port: Int(56338)
     -> http.status_code: Int(304)
     -> http.status_text: Str(NOT MODIFIED)
	{"kind": "exporter", "data_type": "traces", "name": "logging"}

これを見る限りattributesのhttp.targetを利用すればURLでのフィルタが実現できそうですね。ということで設定ファイルを以下のように修正しましょう。

otel-config.yaml

extensions:
  health_check:
receivers:
  otlp:
    protocols:
      http:
        endpoint: 0.0.0.0:4318
  awsxray:
    endpoint: 0.0.0.0:2000
    transport: udp

processors:
  batch/traces:
    timeout: 1s
    send_batch_size: 50
  filter:
    spans:
      exclude:
        match_type: regexp
        attributes:
          - Key: http.target
            Value: ^/(favicon\.ico|_next/static/|vercel\.svg|_next/image|_next/webpack-hmr)
exporters:
  awsxray:
service:
  pipelines:
    traces:
      receivers: [otlp,awsxray]
      processors: [filter, batch/traces]
      exporters: [awsxray]

  extensions: [health_check]

Collectorを起動し直してNext.jsにアクセスすると...

トレース結果がスッキリしました!これでノイズに惑わされることはなくなりそうです。

課題

無事にNext.jsのサーバーサイド処理をX-Rayでトレースできるようになりました。これでめでたしめでたし...と言いたいのですが、実はまだ課題が残っています。インストルメンテーション処理はNext.jsの外側で実行しているため、Next.jsをスタンドアロンモードでビルドした際にインストルメンテーション処理で利用しているopentelemetry関連の諸々のライブラリが.next/standalone/node_modules/に出力されないのです。実装の参考にしたOpenTelemetry DemoのDockerfileでは.next/standalone の中身に加えてpackage-lock.jsonからインストールしたnode_modulesをCOPYすることでNext.js用のコンテナからopentelemetry関連のライブラリが利用できるようにしているようですが、この方式だとnode_modules.next/standalone/node_modulesに重複が発生してしまい、コンテナのサイズが無駄に大きくなってしまいます。

結局この問題についてはアプリ内に本来不要なopentelemetry関連ライブラリのimport処理を記述することで、opentelemetry関連ライブラリが.next/standalone/node_modulesに出力されるように調整しました。無駄な処理を入れている理由をコメントとして記述はしていますが、もう少しうまいやりかたは無いものか悩ましいところです。

もしうまいやり方をご存知の方がいれば教えて頂きたいです。

まとめ

Next.jsとX-Rayを連携させる方法についてご紹介しました。課題のところにも書いたとおり完全に納得のいく形に実装することはできませんでしたが、それでも多数の外部APIと連携する処理がトレース可能になったという点で多くのメリットが得られる対応だったと考えています。Opentelemetry関連の技術は今まさに発展中なので、今後どんどん便利になっていくことに期待したいですね。

参考