はじめに
先日、Google Cloud Run で動かしている Next.js アプリで、リクエストごとにユニークなID（以降、リクエストIDと呼ぶ）をサーバーサイドのログに付与したいという話が上がりました。
リクエストIDがあれば、ログ調査の際などにどのログが同じリクエスト内で行われたものかがわかるようになり便利です。というか、無いとかなり不便です。
Next.js でこれを実現する方法を模索したところ、意外と方法がなく最終的に OpenTelemetry の導入によってこれを実現したので、ここではその話を共有します。
前提と注意事項：
- この記事のコードの検証は Next.js 16.0.7 で行いました。
- サーバーサイドのログのみを対象とします。クライアントからのログは対象外です。
- この記事の前半の説明は Google Cloud Run で動かしているサービスを対象としています。後半部分では他の環境での話も書いているので、他の環境での場合について知りたい方は（前半部分を読んだ上で）後半部分も参照してください。
- この記事では OpenTelemetry を導入してトレースIDを取得・記録するのに必要な設定のみを扱います。トレースデータの送信については扱わないので、そういった目的で OpenTelemetry の導入を考えている方にはあまり参考にならないかと思います
前置き: どんな値をリクエストIDとして使うか
まずどんな値をリクエストIDとして使うとよいかを考えます。
適当に UUID などを生成して使うのでもよいですが、Cloud Run でアプリを実行している場合はリクエストに自動で追加される traceparent ヘッダーからトレースIDを取得して、これをリクエストIDとして使うのがよさそうです。
Cloud Run のアクセスログにもこのトレースIDが含まれているため、これをアプリログに記録できれば、アプリログとアクセスログの紐付けができるようになります。
またトレースIDは1リクエストに対して1つ割り当てられ、リクエスト間でユニークです。
ということでこのトレースIDをリクエストIDとして使うことにしましょう。
前置き: どうやってリクエストIDを受け渡すか
traceparent ヘッダーは分散トレースの情報の伝搬に使われるものであり、これを扱うならある意味で OpenTelemetry を使うのが自然ではあるのですが、とはいえリクエストIDをログに付与するためだけに OpenTelemetry を導入するのは大げさな感じもします。一旦まずはそれ以外の方法で traceparent ヘッダーからトレースIDを抽出してログに付与することが可能かを検討してみます。
traceparent 自体はシンプルなフォーマットなので、ここからトレースIDを抽出することは特に難しくありません。
ただこれをログに付与する場合、その抽出したトレースIDをどうやって logger に受け渡すか、どうやってリクエスト処理中のどこからでも取得できるようにしておくか、ということを考えなければなりません。ログの出力関数はどこから呼び出されるかわかりませんから……
ただ Next.js でそれを実現するよい方法が、調べたけれどまったく見つからない……。Next.js のソースまで眺めに行ったけど見つからない……Express とかなら簡単なのに……。却下した方法を参考程度に書いておくので興味のある方は御覧ください。
却下した方法
- トレースIDをバケツリレーであらゆる関数に渡す
- => やりたくなさすぎる
-
proxy.ts（旧middleware.ts） でトレースIDをリクエストヘッダーに設定して受け渡す- => Next.js 14 まではこれでいけたらしい。ただ Next.js 15 からは
headers()関数が async になったため、ログ出力時に都度これを呼び出すのが現実的ではなくなった（ログ出力関数を async にして呼び出し箇所で都度 await するのは現実的ではないし、Fire and Forget するのも環境によってはログの欠損につながるので嬉しくない）
- => Next.js 14 まではこれでいけたらしい。ただ Next.js 15 からは
- トレースIDを
AsyncLocalStorageで配って、ログ出力時にそこから取得する- => 徹底的に調べた限り、Next.js でこれを実現するには「layout/page/Route Handler/Server Actions のすべてを手動で AsyncLocalStorage でラップする」「カスタムサーバーでリクエストハンドラーを AsyncLocalStorage でラップする」「Next.js が内部で持ってる AsyncLocalStorage にのっかる」しか手段がない
- 「layout/page/Route Handler/Server Actions のすべてを手動で AsyncLocalStorage でラップする」: できればやりたくない。自動でやりたい。
- 「カスタムサーバーでリクエストハンドラーを AsyncLocalStorage でラップする」: カスタムサーバーは現状使ってないし、このためだけにカスタムサーバーを導入するのも避けたい（公式曰くカスタムサーバーは一部のパフォーマンス最適化の恩恵を受けられなくなるため非推奨）
- 「Next.js が内部で持ってる AsyncLocalStorage にのっかる」: Next.js の内部実装に深く依存することになり、マイナーバージョンアップ等でも突如動作しなくなるリスクがあるため避けたい
- その他に
AsyncLocalStorageを仕掛けられる場所/方法がマジでない。探しまくったけどない。 -
proxy.tsでNextResponse.next()をAsyncLocalStorage.run()でラップするのは意味なし（非同期チェーンが繋がっていない）
一方で OpenTelemetry を使用すればこういった問題は解決します。
Next.js には OpenTelemetry の組み込みのサポートがあり、リクエストごとに Next.js が内部で OpenTelemetry のスパンを自動で作成してくれます（※1）。そしてスパンに割り当てられたトレースIDはそのスパンの中であればどこからでも取得可能です（※2）。これによりリクエストIDの受け渡しの問題が解決します。
OpenTelemetry を使えば traceparent ヘッダーからのトレースIDの引き継ぎ（※3）も簡単なので、こうなるともう、少し大げさには感じますが OpenTelemetry を導入してしまいましょう……。
OpenTelemetry を導入してトレースデータの送信するところまで考えるとサイドカーコンテナの導入など面倒ですが、トレースIDを取得してログに記録するだけなら簡単です。
※1 スパンとは OpenTelemetry などのトレースの文脈において、トレース対象となる処理のひとかたまりを表す単位です。複数のスパンは親子関係をなしてツリー構造をとります。そしてそのツリー全体に対して1つのトレースIDが割り当てられます。
※2 内部的には OpenTelemetry も AsyncLocalStorage を使ってこれを実現しているようです。
※3 traceparent ヘッダーはネットワークを介して複数のサービスにまたがるスパンの親子関係を作るときに使われます。traceparent ヘッダーからトレースIDと親スパンの情報を引き継ぐと、これから作成するスパンの親として、traceparent で送られたリクエスト元のスパンが設定されます。
設定手順: Google Cloud Run 環境の場合
とりあえず Next.js の公式ドキュメントに従って OpenTelemetry を導入し、トレースIDをログに含めるようにしていきます。
今回のプロジェクトでは logger に pino を使っていたので、instrumentation-pino を使ってトレースIDをログに含めるようにしました。
他の logger を使っている場合はこちらなどから対応する instrumentation を探してみてください（instrumentation を使わない場合の方法は後述）
また今回はトレースIDをリクエストIDとして使うのが目的で、トレースデータの送信は行わないので exporter は指定不要です。
リクエスト処理中にエラーがあった場合にその内容もトレースID付きで出力したいので、instrumentation.ts で onRequestError の設定も行います。
下記が最低限の設定例になるかと思います。
import type { Instrumentation } from "next"
export async function register() {
if (process.env.NEXT_RUNTIME === "nodejs") {
await import("./instrumentation.node")
}
}
export const onRequestError: Instrumentation.onRequestError = async (err) => {
// instrumentation.node の中で logger にパッチを当てているため動的importが必要
const { logger } = await import("@/path/to/logger")
logger.error(err)
}
import { TraceFlags } from "@opentelemetry/api"
import { NodeSDK } from "@opentelemetry/sdk-node"
import { PinoInstrumentation } from "@opentelemetry/instrumentation-pino"
const GCP_PROJECT_ID = "..."
new NodeSDK({
instrumentations: [
// logger に応じた Instrumentation を追加する。対応する Instrumentation がない場合は後述の logger 側での対応を行う。
new PinoInstrumentation({
logHook: (span, record) => {
const context = span.spanContext()
// トレースIDは Cloud Logging 指定のキーに入れると良い: https://docs.cloud.google.com/logging/docs/structured-logging?hl=ja#structured_logging_special_fields
// これらのキーでトレースIDをログに追加することで、
// Log Explorer 上で同じトレースIDのものを紐付けて検索したり、
// 将来的にトレースデータを送信するようにした場合にトレースとログを紐付けて表示することが可能になる
record["logging.googleapis.com/trace"] = `projects/${GCP_PROJECT_ID}/traces/${context.traceId}`
record["logging.googleapis.com/spanId"] = context.spanId
record["logging.googleapis.com/trace_sampled"] =
context.traceFlags & TraceFlags.SAMPLED ? "1" : "0"
// デフォで下記のキーにトレースIDなどの情報が追加されるが、これらは Cloud Logging 指定のものとはキーもフォーマットも異なるので削除しておく
delete record.trace_id
delete record.span_id
delete record.trace_flags
},
}),
],
// ...トレースデータの送信までする場合は他にもいくつか設定が必要...
}).start()
なお instrumentation-pino を使う場合は、next.config.ts で下記のような serverExternalPackages の設定が必要でした。他の Instrumentation でもおそらく同様になるかと思います。
import type { NextConfig } from "next";
const nextConfig: NextConfig = {
// ...
serverExternalPackages: ["@opentelemetry/instrumentation-pino", "pino"],
// ...
};
export default nextConfig;
logger に対応する instrumentation がない場合/使わない場合
下記のように logger 側でログ出力をフックしてトレースIDを含める方法もあります。
import { trace, context } from "@opentelemetry/api";
import { TraceFlags } from "@opentelemetry/api";
import { pino } from "pino";
const GCP_PROJECT_ID = "..."
export const logger = pino({
mixin() {
const currentSpan = trace.getSpan(context.active());
if (!currentSpan) {
return {};
}
const currentContext = currentSpan.spanContext();
return {
"logging.googleapis.com/trace": `projects/${GCP_PROJECT_ID}/traces/${currentContext.traceId}`,
"logging.googleapis.com/spanId": currentContext.spanId,
"logging.googleapis.com/trace_sampled":
currentContext.traceFlags & TraceFlags.SAMPLED ? "1" : "0",
};
},
});
これで設定は完了です。
この状態でアプリを動かしてログを出力し、ログにトレースIDが含まれていることを確認してください。
logger.info("This is a log message")
↓うまくいっていればこんな感じのログが出るかと思います。
{
"level": 30,
"time": 1696543200000,
"msg": "This is a log message",
"logging.googleapis.com/trace": "projects/my-gcp-project/traces/4bf92f3577b34da6a3ce929d0e0e4736",
"logging.googleapis.com/spanId": "00f067aa0ba902b7",
"logging.googleapis.com/trace_sampled": "1"
}
またこれをデプロイしてログを確認し、そのトレースID（trace）の値がアクセスログのそれと一致しているかどうか確認してください。OpenTelemetry が Next.js からリクエストヘッダーを受け取って、自動的に traceparent ヘッダーからトレースIDを引き継ぐため、特別な設定をせずともアクセスログとアプリログのトレースIDが同じになっているはずです。
せっかくならトレースデータの送信もしたい！
単にトレースIDをログに付与するだけでなく、せっかくならトレースデータの送信も行いたいという場合は、上記の他に resource や traceExporter の設定も必要です。
さらにはサイドカーコンテナの追加などが必要になる場合もあります。
詳しくは Next.js やら Cloud Trace やら OpenTelemetry やらのドキュメントを参照してください
パフォーマンス上のオーバーヘッドについて
一応、パフォーマンス上のオーバーヘッドについても簡単に計測しておきました。
トレースデータの送信等は行ってないので、ほとんど影響なかろうとは思いつつ...
下記のようなAPIエンドポイントを用意します。
import { NextResponse } from "next/server";
export async function GET() {
return NextResponse.json({ message: "ok" });
}
autocannon を使って同時接続数100で10秒間負荷をかけてみてレイテンシを確認します。
簡単のためローカル環境（M3 MacBook Air）で計測しました。
OpenTelemetry なしの場合:
$ npx autocannon -c 100 -d 10 http://localhost:3000/api/bench
Running 10s test @ http://localhost:3000/api/bench
100 connections
┌─────────┬───────┬───────┬───────┬───────┬─────────┬─────────┬────────┐
│ Stat │ 2.5% │ 50% │ 97.5% │ 99% │ Avg │ Stdev │ Max │
├─────────┼───────┼───────┼───────┼───────┼─────────┼─────────┼────────┤
│ Latency │ 10 ms │ 11 ms │ 21 ms │ 32 ms │ 12.4 ms │ 8.46 ms │ 580 ms │
└─────────┴───────┴───────┴───────┴───────┴─────────┴─────────┴────────┘
┌───────────┬─────────┬─────────┬─────────┬─────────┬──────────┬────────┬─────────┐
│ Stat │ 1% │ 2.5% │ 50% │ 97.5% │ Avg │ Stdev │ Min │
├───────────┼─────────┼─────────┼─────────┼─────────┼──────────┼────────┼─────────┤
│ Req/Sec │ 6,183 │ 6,183 │ 8,035 │ 8,623 │ 7,756.19 │ 770.97 │ 6,181 │
├───────────┼─────────┼─────────┼─────────┼─────────┼──────────┼────────┼─────────┤
│ Bytes/Sec │ 1.71 MB │ 1.71 MB │ 2.23 MB │ 2.39 MB │ 2.15 MB │ 214 kB │ 1.71 MB │
└───────────┴─────────┴─────────┴─────────┴─────────┴──────────┴────────┴─────────┘
OpenTelemetry ありの場合:
$ npx autocannon -c 100 -d 10 http://localhost:3000/api/bench
Running 10s test @ http://localhost:3000/api/bench
100 connections
┌─────────┬───────┬───────┬───────┬───────┬──────────┬──────────┬────────┐
│ Stat │ 2.5% │ 50% │ 97.5% │ 99% │ Avg │ Stdev │ Max │
├─────────┼───────┼───────┼───────┼───────┼──────────┼──────────┼────────┤
│ Latency │ 13 ms │ 15 ms │ 23 ms │ 27 ms │ 16.02 ms │ 10.26 ms │ 733 ms │
└─────────┴───────┴───────┴───────┴───────┴──────────┴──────────┴────────┘
┌───────────┬─────────┬─────────┬─────────┬─────────┬──────────┬────────┬─────────┐
│ Stat │ 1% │ 2.5% │ 50% │ 97.5% │ Avg │ Stdev │ Min │
├───────────┼─────────┼─────────┼─────────┼─────────┼──────────┼────────┼─────────┤
│ Req/Sec │ 4,375 │ 4,375 │ 6,283 │ 6,451 │ 6,051.82 │ 576.48 │ 4,374 │
├───────────┼─────────┼─────────┼─────────┼─────────┼──────────┼────────┼─────────┤
│ Bytes/Sec │ 1.21 MB │ 1.21 MB │ 1.74 MB │ 1.79 MB │ 1.68 MB │ 160 kB │ 1.21 MB │
└───────────┴─────────┴─────────┴─────────┴─────────┴──────────┴────────┴─────────┘
平均や中央値を見ると、だいたい1リクエストあたり 3〜4ms 程度のオーバーヘッドといったところでしょうか。
今回は極めてシンプルなAPIでテストを行ったので、実際のもっと複雑なAPIであれば相対的にレイテンシに占める OpenTelemetry のオーバーヘッドの割合は小さくなるでしょう。
もしこれが許容できないのであれば導入はやめておいたほうがよいかと思います。
一応、ログ出力のオーバーヘッドも見ておきます。
下記のようにログを1000回出力するエンドポイントを用意します。
import { NextResponse } from "next/server";
import pino from "pino";
export async function GET() {
const logger = pino();
for (let i = 0; i < 1000; i++) {
logger.info("called");
}
return NextResponse.json({ message: "ok" });
}
これも同様に autocannon で負荷をかけてみます。
OpenTelemetry なしの場合:
$ npx autocannon -c 100 -d 10 http://localhost:3000/api/bench-log
Running 10s test @ http://localhost:3000/api/bench-log
100 connections
┌─────────┬───────┬───────┬────────┬────────┬──────────┬──────────┬─────────┐
│ Stat │ 2.5% │ 50% │ 97.5% │ 99% │ Avg │ Stdev │ Max │
├─────────┼───────┼───────┼────────┼────────┼──────────┼──────────┼─────────┤
│ Latency │ 58 ms │ 70 ms │ 136 ms │ 196 ms │ 77.36 ms │ 54.72 ms │ 1840 ms │
└─────────┴───────┴───────┴────────┴────────┴──────────┴──────────┴─────────┘
┌───────────┬────────┬────────┬────────┬────────┬──────────┬─────────┬────────┐
│ Stat │ 1% │ 2.5% │ 50% │ 97.5% │ Avg │ Stdev │ Min │
├───────────┼────────┼────────┼────────┼────────┼──────────┼─────────┼────────┤
│ Req/Sec │ 752 │ 752 │ 1,309 │ 1,524 │ 1,270.41 │ 206.97 │ 752 │
├───────────┼────────┼────────┼────────┼────────┼──────────┼─────────┼────────┤
│ Bytes/Sec │ 208 kB │ 208 kB │ 363 kB │ 422 kB │ 352 kB │ 57.3 kB │ 208 kB │
└───────────┴────────┴────────┴────────┴────────┴──────────┴─────────┴────────┘
OpenTelemetry ありの場合:
$ npx autocannon -c 100 -d 10 http://localhost:3000/api/bench-log
Running 10s test @ http://localhost:3000/api/bench-log
100 connections
┌─────────┬────────┬────────┬────────┬────────┬───────────┬───────────┬─────────┐
│ Stat │ 2.5% │ 50% │ 97.5% │ 99% │ Avg │ Stdev │ Max │
├─────────┼────────┼────────┼────────┼────────┼───────────┼───────────┼─────────┤
│ Latency │ 165 ms │ 233 ms │ 296 ms │ 305 ms │ 265.84 ms │ 425.67 ms │ 8070 ms │
└─────────┴────────┴────────┴────────┴────────┴───────────┴───────────┴─────────┘
┌───────────┬─────────┬─────────┬────────┬────────┬────────┬─────────┬─────────┐
│ Stat │ 1% │ 2.5% │ 50% │ 97.5% │ Avg │ Stdev │ Min │
├───────────┼─────────┼─────────┼────────┼────────┼────────┼─────────┼─────────┤
│ Req/Sec │ 354 │ 354 │ 372 │ 381 │ 370.4 │ 7.45 │ 354 │
├───────────┼─────────┼─────────┼────────┼────────┼────────┼─────────┼─────────┤
│ Bytes/Sec │ 98.1 kB │ 98.1 kB │ 103 kB │ 106 kB │ 103 kB │ 2.06 kB │ 98.1 kB │
└───────────┴─────────┴─────────┴────────┴────────┴────────┴─────────┴─────────┘
1度のリクエストでログを1000回出力していますから、ログ出力1回あたりでだいたい 0.1~0.2ms 程度のオーバーヘッドですかね。
こちらはほとんど気にしなくてよさそうです。
おまけ: Google Cloud Run 以外の環境の場合
AWS など Google Cloud Run 以外の環境の場合についても調査・検証したので少し触れておきます。
なお、一応 AWS 環境で検証を行った上で書いていますが、実運用で使っているわけではないのでその点は割り引いてお読みください。
まず、基本的に他の環境でも先に述べた設定はそのまま使えます。ここまでの説明では Cloud Run 環境でリクエストに自動で traceparent ヘッダーが追加されることを前提としていましたが、トレースIDをリクエストIDとして使用するだけなら traceparent ヘッダーは必須ではありません。traceparent ヘッダーがなければ単に新しいトレースIDが生成されるだけです。
ただ、他の環境で使う場合はいくつか注意の必要な点があります。
アクセスログとの紐付けは環境によってできたりできなかったり ＆ できても追加設定が必要だったりする
アプリログとアクセスログなどの紐付けを行いたい場合は、やはり何らかの形でトレースIDを含む親スパンの情報を受け取る必要があります。
（ちなみにここでは、アプリでリクエストを受け取るよりも前の段階でなんらかの形でアクセスログが記録される前提とします）
アクセスログとアプリログを紐付けるために最低限満たしていなければならない条件は下記の3つです。
- アプリがアクセスを受け取るよりも前の段階で OpenTelemetry 互換のトレース（親スパン）が開始されている
- アクセスログにそのトレースIDが含まれている
- そのトレースIDを含む親スパンの情報が、リクエストヘッダーなどを通してアプリへ渡されている
1点目については、トレースIDでアクセスログとアプリログを紐付けようとする以上、それらよりも前の段階でトレースIDが発行されていなければならない、ということだと理解してください。ちなみに API Gateway などは OpenTelemetry に対応しています。（正確に言えば AWS の X-Ray に対応しており、その X-Ray に OpenTelemetry との互換性があります）
2点目もまあ当然ですね。API Gateway などではアクセスログのフォーマットがカスタマイズできるので、トレースIDがそこに含まれるようにしてください。
3点目について、まあ結局その親スパンの情報がアプリに送られてきていなければどうにもできないわけです。
ちなみに先に述べた traceparent ヘッダーは W3C Trace Context で定められたものなので、Google Cloud 以外の環境でもこのヘッダーを使って親スパンの情報が渡されることがあります。この場合は先の設定のままでOKです。
AWS 環境の場合は x-amzn-trace-id というヘッダーで親スパンの情報が渡されるのですが、これに対応するには追加の設定が必要です。下記のように NodeSDK の textMapPropagator という設定項目に、@opentelemetry/propagator-aws-xray パッケージの AWSXRayPropagator を使用するよう指定しておく必要があります。
import { NodeSDK } from "@opentelemetry/sdk-node"
import { AWSXRayPropagator } from "@opentelemetry/propagator-aws-xray"
new NodeSDK({
textMapPropagator: new AWSXRayPropagator(),
// ...
}).start()
ただ、ここらへんちょっとややこしいのですが、こちらで試した限り x-amzn-trace-id ヘッダーが追加されていれば必ず OpenTelemetry でトレースIDを引き継げるというわけではないようです。
X-Ray トレースを有効化した API Gateway と ALB ではどちらでも x-amzn-trace-id ヘッダーが追加されましたが、それぞれトレースIDを引き継げるかどうかは下記のように分かれました。
- API Gateway: トレースIDを引き継げる
- ALB: トレースIDを引き継げない
そのため、ALB からはトレースIDを引き継げず、結果として今回の方法だとアクセスログとアプリログとでトレースIDの不一致が生じます。
ちなみに API Gateway -> ALB -> ECS という構成であればトレースIDを引き継げました。この場合は API Gateway によって生成された x-amzn-trace-id ヘッダーを ALB がそのまま中継してくれます。
このようにトレースIDを引き継げるか引き継げないかがわかれる原因についても調査したのですが、余談となるので折りたたんでおきます。
`x-amzn-trace-id` からトレースIDを引き継げるか引き継げないかがわかれる原因
API Gateway でも ALB でも x-amzn-trace-id ヘッダーでトレースIDが送られてきているのに、どうして引き継げたり引き継げなかったりするのか。
こちらヘッダーの中身を確認してみたところ、ALB によって追加される x-amzn-trace-id には、トレースIDは含まれるものの親スパンの情報が含まれておらず、これが原因のようでした。
実際、AWSXRayPropagator の実装を確認してみると、x-amzn-trace-id に親スパンの情報が含まれていない場合は単に無視されるようになっていました。
propagator は親スパンの情報を受け取って設定するためのものなので、親スパンがなければそこからトレースIDを引き継ぐこともできないというのはさもありなんです。
また API Gateway はそれ自身で X-Ray にトレース情報を送信しますしスパンの作成も自身で行いますが、ALB は自身でトレースIDを発行するもののスパンを開始しないようなので（CloudWatch のトレース情報にも ALB は出てこない）、ALB が送ってくる x-amzn-trace-id に親スパンの情報が存在しないのもまたさもありなんではあります。
調べた限り、ALB それ自身でスパン（X-Ray の用語で言うとセグメント）を開始する方法も見つけられませんでした。
ここらへん AWS に詳しいわけではないので、いや、ALB のみでもいける方法があるよ！っていう情報をお持ちの方は教えて欲しいです。
（ちなみに無理やりやるなら AWSXRayPropagator を改造して、x-amzn-trace-id にトレースIDがあるのに親スパンの情報がないときはダミーの親スパンIDを生成するということも可能そうで、トレースIDを本当にただのリクエストIDとして使うのであればそれでもよさそうでしたが……さすがに無理やりな方法になりますし、トレースという観点ではまったく壊れたデータになるのでここでは紹介を控えておきます）
なお traceparent や x-amzn-trace-id 以外の方法で親スパンの情報が渡されている場合の設定については必要であれば検索してみてください。
proxy.ts とそれ以降の処理とでトレースIDが異なる場合がある
今書いたような親スパンの情報の受け取りを行わない/行えない場合、現状の Next.js では proxy.ts（旧 middleware.ts）とそれ以降とでトレースIDが異なる値になってしまう問題があるようです。場合によっては困りますね。
どうにも proxy.ts での処理とそれ以降の処理とで異なるスパンが生成される ＆ それらを束ねる親スパンが存在しないことが原因のようです。
なおリンク先の issue では触れられていませんが、こちらで確認した限りリクエストから親スパンの情報を受け取って textMapPropagator で適切に処理できている場合は、トレースIDが変わってしまう問題は発生しないようです。リクエスト元のスパンが proxy.ts のスパンおよびそれ以降のスパンの親となるためでしょう。
またこちら検証したところ、ワークアラウンドとして proxy.ts で次のように実装すれば proxy.ts とそれ以降とでトレースIDを揃えることが可能でした。
import { context, propagation, trace } from "@opentelemetry/api";
import { type NextRequest, NextResponse } from "next/server";
export function proxy(req: NextRequest) {
const nextHeaders = new Headers(req.headers);
const activeContext = context.active();
// propagation.inject() によって、トレース情報を引き継ぐためのヘッダーが生成される（traceparent など）
// これをリクエストヘッダーに設定しておくことで、以降のリクエスト処理のスパンを proxy.ts のスパンの子にできる
const carrier: Record<string, string> = {};
propagation.inject(activeContext, carrier);
for (const [key, value] of Object.entries(carrier)) {
nextHeaders.set(key, value);
}
return NextResponse.next({
request: {
headers: nextHeaders,
},
});
}
なおこの方法をとると、proxy.ts のスパンが終了した後で、その既に終了したはずのスパンを親とする別のスパンが開始されることになります。トレースとしてはやや歪な形かと思うので、トレースデータの送信を行う場合は注意してください（ちなみに CloudWatch ではこの場合も特に問題なくトレースの表示はできました）。単にトレースIDをリクエストIDとして使用するだけなら特に支障ないかと思います。
おわりに
以上、Next.js で OpenTelemetry のトレースIDをリクエストID代わりにサーバーログに付与する方法について説明しました。
どこかの誰かの参考になれば幸いです。
株式会社TERASSのテックブログです。TERASSでは「いい不動産取引は、いいエージェントから。を当たり前にするプラットフォームをつくる。」をミッションに、次世代不動産エージェントファーム「TERASS」や、優秀なエージェントとのマッチングプラットフォーム「Terass Offer」などを開発・運営しています。
Discussion