Open31

Next.js app on Vercel でテレメトリデータを毎回ちゃんと送信するには

RindricsRindrics
  • Next.js app on Vercel に対してテレメトリを OTEL で計装している
  • 例えばある関数が呼ばれるたびに Counter.add() されるとする
  • 計装対象の関数は毎回正常終了するが、OTEL collector から o11y platform へのテレメトリデータの送信が不安定
    • 受信に成功したときは、カウンタが一気に上昇しているように見える
      • カウンタの場合には積算値としては変わらないが、途中のデータは失われていると思われる
  • 仮説: 関数が return して Vercel Function が休止状態になることによって、非同期でのテレメトリ送信がなされないのではないか
RindricsRindrics

検証対象

  • 検証 1: ふつうに計装したままでは、テレメトリが送信されたりされなかったりすることを確認する
  • 検証 2: 明示的に flush() すればテレメトリが確実に送信されることを確認する

追加で気になること

検証手順

  1. 最小限の Next.js app を Vercel にデプロイする
  2. 適当な関数を画面からボタンで呼べるようにする
  3. 関数の所要時間をロギングし、Vercel Logs から確認できるようにする
  4. Grafana Cloud をセットアップする
  5. 関数に、呼び出しごとにインクリメントするカウンタを計装する
  6. 検証 1
  7. 検証 2
RindricsRindrics

1. 最小限の Next.js app を Vercel にデプロイする

Next.js app の作成

npx create-next-app@latest research-nextjs-vercel-telemetry --use-npm
Need to install the following packages:
create-next-app@14.2.15
Ok to proceed? (y) y

✔ Would you like to use TypeScript? … No / Yes
✔ Would you like to use ESLint? … No / Yes
✔ Would you like to use Tailwind CSS? … No / Yes
✔ Would you like to use `src/` directory? … No / Yes
✔ Would you like to use App Router? (recommended) … No / Yes
✔ Would you like to customize the default import alias (@/*)? … No / Yes
✔ What import alias would you like configured? … @/*
Creating a new Next.js app in /Users/ahayashi/dev/research-nextjs-vercel-telemetry.

Using npm.

Initializing project with template: app-tw


Installing dependencies:
- react
- react-dom
- next

Installing devDependencies:
- typescript
- @types/node
- @types/react
- @types/react-dom
- postcss
- tailwindcss


added 138 packages, and audited 139 packages in 18s

31 packages are looking for funding
  run `npm fund` for details

found 0 vulnerabilities
Initialized a git repository.

Success! Created research-nextjs-vercel-telemetry at /Users/ahayashi/dev/research-nextjs-vercel-telemetry

npm notice
npm notice New minor version of npm available! 10.7.0 -> 10.9.0
npm notice Changelog: https://github.com/npm/cli/releases/tag/v10.9.0
npm notice To update run: npm install -g npm@10.9.0
npm notice

npm run dev でたった

Vercel にデプロイ

できた

RindricsRindrics

2. 適当な関数を画面からボタンで呼べるようにする

検証 1検証 2 に備えて下記 2 つの関数を作る

  • async_log_export()
  • force_flush()

ひとまずログだけ出すようにした
https://github.com/Rindrics/research-nextjs-vercel-telemetry/commit/62a0b44f8d34861b341093f5c2d5e0bffcccb448

それぞれを呼ぶボタンを画面に追加

それぞれの関数からのログを Vercel で確認できた

RindricsRindrics

3. 関数の所要時間をロギングし、Vercel Logs から確認できるようにする も完了

RindricsRindrics

検証 1: ふつうに計装したままでは、テレメトリが送信されたりされなかったりすることを確認する

ローカルからは届くことを確認できた、つまり最低限の計装は完了しているはずだが、production の async_counter() 用ボタンを押しても、Grafana Cloud には届かない

いや、なんかとれてしまったな

検証 1 の時点で、事前に別環境(業務)で確認していた挙動と違ってしまった。

もっともそちらの環境は下記のようにいくつか違いがあるのだが、、

  • Next.js のバージョンが canary 系の新しいものを使っている
    - なので nextConfig に experimental.instrumentationHook がない
  • Sentry SDK を使っている

今はもっとまずいものを見つけたのでそちらを調べる

RindricsRindrics

今はもっとまずいものを見つけたのでそちらを調べる

Counter メトリクスのくせに値が減少している

ここのところ(青線)

青線は production (Vercel)環境なので、Function に利用されているコンテナが途中で変わったんだろうか。
とにかくこれは counter メトリクスとしての利用を想定している場合、重大なバグにつながる恐れがある。

カウンタはある意味ステートフルなメトリクスだが、Function ベースのアーキテクチャにおいてステートフルなメトリクスを使うのは危険かもしれない。

カウンタを使いたい局面ではゲージを使っておき、分析環境側で cumsum する方法を検討する。

RindricsRindrics

ちなみに Vercel 環境はしばらく触らずに放置しておくと値が Null になる

再び触ってみたが、このケースでは値を忘れていた

そして、値は届いているものの、やはり挙動が不安定。
このケースでは 10 回程度関数を呼んだが、メトリクスは 2 つしか確認できなかった

RindricsRindrics

instrumentation.js にいまいち不安があるので追ってみる

利用する Next.js は現時点の最新ということで v15.0.0-rc.1

instrumentation.js を使うライブラリとしては、はセットアップウィザードがついてる Setry を使ってみる。
バージョンは8.34.0

RindricsRindrics

OTEL による計装もこの感じで動いてほしいので Sentry SDK による instrumentation.js まわりの利用を見てみる

RindricsRindrics

なお利用している Next.js は 15 系なので next.configinstrumentationHook はない

RindricsRindrics

もろもろ調査して挙動がわかったので先にまとめだけ貼っておく

コード: https://github.com/Rindrics/research-nextjs-vercel-telemetry/tree/v0.0.3 https://github.com/Rindrics/research-nextjs-vercel-telemetry/tree/v0.0.4

単純に計装した場合

  • テレメトリが計装部あるいはコレクタに溜まってしまう
    • 起きること: 関数呼び出し時にテレメトリが生成されるが、それがコレクタによって送信される前に Lambda 関数が休止してしまうため、そのテレメトリは次回の呼び出し時にテレメトリバックエンドに送信される

forceFlush()waitUntil() した場合

  • 意図通りに呼び出しごとにテレメトリが届く
RindricsRindrics
RindricsRindrics

📝 collector はテレメトリをどのように export しているか

→ metricReader に委譲してる

MeterProvider の shutdown() では MeterProvider が保持している collector 全ての shutdown() について Promise 解決を待つ

実際に shutdown() しているのは metricReader
https://github.com/open-telemetry/opentelemetry-js/blob/6f4f3fcefd8e453f0516ba15fe0c2580442dd06a/packages/sdk-metrics/src/state/MetricCollector.ts#L82C1-L84C4

PeriodicExportingMetricReader from "@opentelemetry/sdk-metrics を使った場合には
https://github.com/Rindrics/research-nextjs-vercel-telemetry/blob/cf32113b1050f455df7449ed5deb3472b56c469c/instrumentation.node.ts#L35

PeriodicExportingMetricReader は基本的に MetricReader なのでまずそちらを見る
https://github.com/open-telemetry/opentelemetry-js/blob/6f4f3fcefd8e453f0516ba15fe0c2580442dd06a/packages/sdk-metrics/src/export/PeriodicExportingMetricReader.ts#L57

MetricReadershutdown() は実際には onShutdown() を実行している
https://github.com/open-telemetry/opentelemetry-js/blob/6f4f3fcefd8e453f0516ba15fe0c2580442dd06a/packages/sdk-metrics/src/export/MetricReader.ts#L205

MetricReaderonShutdown() には実装が入っていないので
https://github.com/open-telemetry/opentelemetry-js/blob/6f4f3fcefd8e453f0516ba15fe0c2580442dd06a/packages/sdk-metrics/src/export/MetricReader.ts#L133

PeriodicExportingMetricReaderonShutdown() は shutdown しかしていない
https://github.com/open-telemetry/opentelemetry-js/blob/6f4f3fcefd8e453f0516ba15fe0c2580442dd06a/packages/sdk-metrics/src/export/PeriodicExportingMetricReader.ts#L166-L171

メトリクスを実際に export しているのは doExport() だが、これは private メソッドである _doRun() の中の関数なので外からは呼べない
https://github.com/open-telemetry/opentelemetry-js/blob/6f4f3fcefd8e453f0516ba15fe0c2580442dd06a/packages/sdk-metrics/src/export/PeriodicExportingMetricReader.ts#L130-L131

外からは呼べない

いや、forceFlush()_runOnce() 経由で呼べるか
https://github.com/open-telemetry/opentelemetry-js/blob/6f4f3fcefd8e453f0516ba15fe0c2580442dd06a/packages/sdk-metrics/src/export/PeriodicExportingMetricReader.ts#L161-L162

RindricsRindrics

ほんとだ、forceFlush() を waitUntil() するだけで届いた

ここまではふつうにレスポンス返す server action だったので streaming 使う server action の場合の動作を見ていく

RindricsRindrics
RindricsRindrics
RindricsRindrics

OTLPMetricExporterBasethis._otlpExporter.export() を見る
https://github.com/open-telemetry/opentelemetry-js/blob/6f4f3fcefd8e453f0516ba15fe0c2580442dd06a/experimental/packages/opentelemetry-exporter-metrics-otlp-http/src/OTLPMetricExporterBase.ts#L136-L141

this._otlpExporter とは
https://github.com/open-telemetry/opentelemetry-js/blob/6f4f3fcefd8e453f0516ba15fe0c2580442dd06a/experimental/packages/opentelemetry-exporter-metrics-otlp-http/src/OTLPMetricExporterBase.ts#L129C5-L129C34

T で受けたものが入る
https://github.com/open-telemetry/opentelemetry-js/blob/6f4f3fcefd8e453f0516ba15fe0c2580442dd06a/experimental/packages/opentelemetry-exporter-metrics-otlp-http/src/OTLPMetricExporterBase.ts#L128-L129

OTLPExporterNodeProxy に継承されてるが そっちには export() はない
https://github.com/open-telemetry/opentelemetry-js/blob/6f4f3fcefd8e453f0516ba15fe0c2580442dd06a/experimental/packages/opentelemetry-exporter-metrics-otlp-http/src/platform/node/OTLPMetricExporter.ts#L34

OTLPExporterBase にあった
https://github.com/open-telemetry/opentelemetry-js/blob/6f4f3fcefd8e453f0516ba15fe0c2580442dd06a/experimental/packages/otlp-exporter-base/src/OTLPExporterBase.ts#L58-L85

export() の中でテレメトリ送信を定義しているのは send()
https://github.com/open-telemetry/opentelemetry-js/blob/6f4f3fcefd8e453f0516ba15fe0c2580442dd06a/experimental/packages/otlp-exporter-base/src/OTLPExporterBase.ts#L91

send() の実装:
https://github.com/open-telemetry/opentelemetry-js/blob/6f4f3fcefd8e453f0516ba15fe0c2580442dd06a/experimental/packages/otlp-exporter-base/src/platform/node/OTLPExporterNodeBase.ts#L82-L86

と思いきや this._transport に委譲されてる
https://github.com/open-telemetry/opentelemetry-js/blob/6f4f3fcefd8e453f0516ba15fe0c2580442dd06a/experimental/packages/otlp-exporter-base/src/platform/node/OTLPExporterNodeBase.ts#L99-L100

this._transport とは
https://github.com/open-telemetry/opentelemetry-js/blob/6f4f3fcefd8e453f0516ba15fe0c2580442dd06a/experimental/packages/otlp-exporter-base/src/platform/node/OTLPExporterNodeBase.ts#L72-L77

new RetryingTransport
https://github.com/open-telemetry/opentelemetry-js/blob/6f4f3fcefd8e453f0516ba15fe0c2580442dd06a/experimental/packages/otlp-exporter-base/src/retrying-transport.ts#L85-L89

RetryingTransport とは
https://github.com/open-telemetry/opentelemetry-js/blob/6f4f3fcefd8e453f0516ba15fe0c2580442dd06a/experimental/packages/otlp-exporter-base/src/retrying-transport.ts#L33-L34

実際に呼ばれている send() はこれ
https://github.com/open-telemetry/opentelemetry-js/blob/6f4f3fcefd8e453f0516ba15fe0c2580442dd06a/experimental/packages/otlp-exporter-base/src/retrying-transport.ts#L48

RindricsRindrics

いま waitUntil() している内容で RetryingTransport.send() が実行されているか確認するために、spentelemetry-js をパッチしてみる

RindricsRindrics
RindricsRindrics

:memo:

  • registerOTel() 使える
    • カスタムエクスポータ渡せばオーバーライドされるので Pro plan でも Vercel Collector が勝手に使われることはない
  • テレメトリは明示的にflush() しない
    • どのみち SDK は registerOTel() の中にあり、provider の制御を持てないため
    • そのかわり Vercel Function のタイムアウトぶん waitUntil(テレメトリ関連のもろもろ操作) する