diff --git a/apps/server/instrumentation.mjs b/apps/server/instrumentation.mjs index 75df64558..5d70dfa52 100644 --- a/apps/server/instrumentation.mjs +++ b/apps/server/instrumentation.mjs @@ -1,78 +1,145 @@ /** - * OTEL instrumentation preload — loaded via `--import` BEFORE tsx processes - * any application module. This ensures @opentelemetry/instrumentation-pg can - * monkey-patch the CJS `pg` module before it is imported anywhere. + * OpenTelemetry preload — single entry point for SDK setup. * - * Only instrumentations that patch third-party modules need to live here. - * The full SDK (exporters, metrics, log processors) is still configured in - * src/libs/otel.ts — the NodeSDK there will reuse the already-registered - * instrumentations. + * Loaded via `tsx --import ./instrumentation.mjs`, runs BEFORE any application + * module is evaluated. By starting NodeSDK here: + * - require-in-the-middle hooks for http / pg / ioredis install before app + * code does `require('pg')` etc. (fixes the original commit-9451cd7c race). + * - The MeterProvider is real from the moment instrumentations construct, so + * `this._meter` is never NoopMeter — no setMeterProvider rebind dance. * - * NOTICE: `pg` and `ioredis` are CJS packages. When ESM code does - * `import pg from 'pg'`, Node.js internally calls `require()` to load - * the CJS module, so `require-in-the-middle` hooks still intercept it. + * Trade-offs accepted: + * - Env vars are read directly from `process.env` (no valibot). The full + * business `Env` schema is parsed later in libs/env.ts; this preload only + * needs OTEL_* — and a config error here should crash early anyway. + * - `dotenvx run` injects .env.local before tsx, so process.env is fully + * populated by the time this file runs. + * + * Sources / why this shape: + * - https://opentelemetry.io/docs/languages/js/getting-started/nodejs/ + * - https://github.com/open-telemetry/opentelemetry-js-contrib/blob/main/packages/auto-instrumentations-node/src/register.ts + * - https://github.com/open-telemetry/opentelemetry-js/issues/3146 (NodeSDK + * registers instrumentations early in start(), making single-file safe) */ -import { env } from 'node:process' +import process, { env, exit } from 'node:process' -import { registerInstrumentations } from '@opentelemetry/instrumentation' +import { diag, DiagConsoleLogger, DiagLogLevel } from '@opentelemetry/api' +import { OTLPLogExporter } from '@opentelemetry/exporter-logs-otlp-proto' +import { OTLPMetricExporter } from '@opentelemetry/exporter-metrics-otlp-proto' +import { OTLPTraceExporter } from '@opentelemetry/exporter-trace-otlp-proto' +import { HttpInstrumentation } from '@opentelemetry/instrumentation-http' import { IORedisInstrumentation } from '@opentelemetry/instrumentation-ioredis' import { PgInstrumentation } from '@opentelemetry/instrumentation-pg' +import { RuntimeNodeInstrumentation } from '@opentelemetry/instrumentation-runtime-node' +import { resourceFromAttributes } from '@opentelemetry/resources' +import { BatchLogRecordProcessor } from '@opentelemetry/sdk-logs' +import { PeriodicExportingMetricReader } from '@opentelemetry/sdk-metrics' +import { NodeSDK } from '@opentelemetry/sdk-node' +import { BatchSpanProcessor, ParentBasedSampler, TraceIdRatioBasedSampler } from '@opentelemetry/sdk-trace-node' +import { ATTR_SERVICE_NAME, ATTR_SERVICE_VERSION } from '@opentelemetry/semantic-conventions' // NOTICE: // instrumentation-http >=0.215 defaults to OLD semconv (http.server.duration in // ms). Our Grafana dashboards / alerts only query the STABLE name -// (http.server.request.duration in seconds), and grep across the repo confirms -// no OLD-name consumer exists, so we go straight to STABLE-only — no `http/dup` -// transition phase, no doubled cardinality. -// Source: node_modules/.pnpm/@opentelemetry+instrumentation-http@0.215.0/.../build/src/http.js L25-72 -// MUST run before `new HttpInstrumentation(...)` (created in src/libs/otel.ts) — -// its constructor reads the env var once and caches the result. -// -// Use a truthy check (not `??=`): `process.env.X` is `''` when the platform -// (e.g. Railway) registers the var without a value, and `??=` does NOT override -// empty strings — that would silently fall back to OLD semconv with no signal -// in logs. Truthy check covers both `undefined` and `''`. -// Removal condition: ops sets OTEL_SEMCONV_STABILITY_OPT_IN explicitly in the -// deployment platform with a non-empty value, then this preload default can be -// deleted. -if (!env.OTEL_SEMCONV_STABILITY_OPT_IN) { +// (http.server.request.duration in seconds). MUST be set BEFORE the +// HttpInstrumentation constructor runs — that constructor reads the env var +// once and caches the result. +// Truthy check (not `??=`) so empty string from Railway / missing-var also +// falls back to STABLE. +if (!env.OTEL_SEMCONV_STABILITY_OPT_IN) env.OTEL_SEMCONV_STABILITY_OPT_IN = 'http' -} -// Surface the resolved value in stdout BEFORE any instrumentation constructor -// runs. Lets ops grep Railway logs for `[otel-preload]` to confirm the preload -// actually executed and what semconv mode is active. Without this, a misloaded -// preload (wrong `--import` path, missing flag, build cache) is invisible -// until you query Prometheus and notice STABLE-name series are missing. +// Surface the resolved value early. Lets ops grep Railway logs for +// `[otel-preload]` to confirm the preload actually executed and what semconv +// mode is active. Without this, a misloaded preload (wrong --import path, +// missing flag, build cache) is invisible. console.info(`[otel-preload] OTEL_SEMCONV_STABILITY_OPT_IN=${env.OTEL_SEMCONV_STABILITY_OPT_IN}`) -// NOTICE: -// HttpInstrumentation is INTENTIONALLY constructed in src/libs/otel.ts (not -// here) and passed to NodeSDK's `instrumentations` config. Reason: the OTel -// metrics API does NOT have a proxy mechanism like traces — instruments -// created against a NoopMeterProvider stay noop forever. If we register -// HttpInstrumentation in this preload, its constructor caches a noop meter -// (because no MeterProvider is set yet), then `_recordServerDuration` writes -// to NoopHistogram for the entire process lifetime, and -// `http_server_request_duration_seconds_*` never appears in Prometheus. -// -// Putting it in NodeSDK config lets the SDK call `setMeterProvider` with the -// real provider at start(), which re-runs `_updateMetricInstruments()` and -// upgrades the histograms to real instruments. The patches it installs are -// `Server.prototype.emit` (incoming) — prototype-level, race-immune, so it -// doesn't matter that they install at SDK start instead of preload. -// -// pg / ioredis can stay here because they only emit spans, and the trace API -// DOES have a proxy that upgrades cleanly when the SDK installs its provider. -// -// Removal condition: when @opentelemetry/api adds a proxy MeterProvider that -// upgrades cached meters retroactively, all three can move back here. -registerInstrumentations({ - instrumentations: [ - new PgInstrumentation({ - enhancedDatabaseReporting: true, +const otlpEndpoint = env.OTEL_EXPORTER_OTLP_ENDPOINT +if (!otlpEndpoint) { + console.info('[otel-preload] OpenTelemetry disabled (set OTEL_EXPORTER_OTLP_ENDPOINT to enable)') +} +else { + if (env.OTEL_DEBUG === 'true') + diag.setLogger(new DiagConsoleLogger(), DiagLogLevel.DEBUG) + + // OTEL_EXPORTER_OTLP_HEADERS format: "key=value,key2=value2" + const headers = {} + for (const pair of (env.OTEL_EXPORTER_OTLP_HEADERS ?? '').split(',')) { + const idx = pair.indexOf('=') + if (idx > 0) + headers[pair.slice(0, idx).trim()] = pair.slice(idx + 1).trim() + } + + const serviceName = env.OTEL_SERVICE_NAME || 'server' + const serviceNamespace = env.OTEL_SERVICE_NAMESPACE || 'airi' + const samplingRatioRaw = Number(env.OTEL_TRACES_SAMPLING_RATIO ?? '1') + // Head-based sampling. Metrics are always 100% accurate regardless. + const samplingRatio = Number.isFinite(samplingRatioRaw) && samplingRatioRaw >= 0 && samplingRatioRaw <= 1 + ? samplingRatioRaw + : 1 + + const resource = resourceFromAttributes({ + [ATTR_SERVICE_NAME]: serviceName, + [ATTR_SERVICE_VERSION]: env.npm_package_version || '0.0.0', + 'service.namespace': serviceNamespace, + 'deployment.environment': env.NODE_ENV || 'development', + }) + + const sdk = new NodeSDK({ + resource, + sampler: new ParentBasedSampler({ + root: new TraceIdRatioBasedSampler(samplingRatio), }), - new IORedisInstrumentation(), - ], -}) + spanProcessors: [new BatchSpanProcessor(new OTLPTraceExporter({ + url: `${otlpEndpoint}/v1/traces`, + headers, + }))], + metricReaders: [new PeriodicExportingMetricReader({ + exporter: new OTLPMetricExporter({ + url: `${otlpEndpoint}/v1/metrics`, + headers, + }), + exportIntervalMillis: 15_000, + exportTimeoutMillis: 10_000, + })], + logRecordProcessors: [new BatchLogRecordProcessor(new OTLPLogExporter({ + url: `${otlpEndpoint}/v1/logs`, + headers, + }))], + instrumentations: [ + new HttpInstrumentation({ + ignoreIncomingRequestHook: req => req.url === '/health', + }), + new PgInstrumentation({ + enhancedDatabaseReporting: true, + }), + new IORedisInstrumentation(), + new RuntimeNodeInstrumentation(), + ], + }) + + sdk.start() + console.info(`[otel-preload] OpenTelemetry initialized, exporting to ${otlpEndpoint}, sampling ratio: ${samplingRatio}`) + + // Graceful shutdown — flush pending exports before exit. Idempotent. + let shuttingDown = false + const shutdown = async () => { + if (shuttingDown) + return + shuttingDown = true + try { + await sdk.shutdown() + console.info('[otel-preload] OpenTelemetry shut down successfully') + } + catch (err) { + console.error('[otel-preload] Error shutting down OpenTelemetry:', err) + } + } + const shutdownAndExit = () => { + void shutdown().then(() => exit(0)) + } + process.on('SIGTERM', shutdownAndExit) + process.on('SIGINT', shutdownAndExit) +} diff --git a/apps/server/src/app.ts b/apps/server/src/app.ts index bfb5ba828..823e92f76 100644 --- a/apps/server/src/app.ts +++ b/apps/server/src/app.ts @@ -256,16 +256,14 @@ export async function createApp() { emitOtelLog(log.level, log.context, log.message, log.fields as Record) }) + // NOTICE: OTel SDK lifecycle (start/shutdown) is owned entirely by + // instrumentation.mjs (preload). This factory only consumes the global + // MeterProvider that the preload set up, builds metric handles, and primes + // counters. No `lifecycle.onStop(shutdown)` here — preload registers SIGTERM + // / SIGINT to flush exporters on its own. const otel = injeca.provide('libs:otel', { - dependsOn: { env: parsedEnv, lifecycle }, - build: ({ dependsOn }) => { - const o = initOtel(dependsOn.env) - if (!o) - return null - - dependsOn.lifecycle.appHooks.onStop(() => o.shutdown()) - return o - }, + dependsOn: { env: parsedEnv }, + build: ({ dependsOn }) => initOtel(dependsOn.env), }) const db = injeca.provide('datastore:db', { diff --git a/apps/server/src/libs/otel.ts b/apps/server/src/libs/otel.ts index 5ad55afb2..38a7439c1 100644 --- a/apps/server/src/libs/otel.ts +++ b/apps/server/src/libs/otel.ts @@ -2,22 +2,9 @@ import type { Counter, Histogram, ObservableGauge, UpDownCounter } from '@opente import type { Env } from './env' -import { env as processEnv } from 'node:process' - import { useLogger } from '@guiiai/logg' -import { diag, DiagConsoleLogger, DiagLogLevel, metrics, trace } from '@opentelemetry/api' +import { metrics, trace } from '@opentelemetry/api' import { logs, SeverityNumber } from '@opentelemetry/api-logs' -import { OTLPLogExporter } from '@opentelemetry/exporter-logs-otlp-proto' -import { OTLPMetricExporter } from '@opentelemetry/exporter-metrics-otlp-proto' -import { OTLPTraceExporter } from '@opentelemetry/exporter-trace-otlp-proto' -import { HttpInstrumentation } from '@opentelemetry/instrumentation-http' -import { RuntimeNodeInstrumentation } from '@opentelemetry/instrumentation-runtime-node' -import { resourceFromAttributes } from '@opentelemetry/resources' -import { BatchLogRecordProcessor } from '@opentelemetry/sdk-logs' -import { PeriodicExportingMetricReader } from '@opentelemetry/sdk-metrics' -import { NodeSDK } from '@opentelemetry/sdk-node' -import { BatchSpanProcessor, ParentBasedSampler, TraceIdRatioBasedSampler } from '@opentelemetry/sdk-trace-node' -import { ATTR_SERVICE_NAME, ATTR_SERVICE_VERSION } from '@opentelemetry/semantic-conventions' import { METRIC_AIRI_EMAIL_DURATION, @@ -134,13 +121,7 @@ export interface RateLimitMetrics { blocked: Counter } -// NOTICE: Database metrics (db.client.operation.duration, redis.client.command.duration) were -// intentionally removed. PgInstrumentation and IORedisInstrumentation already generate spans -// with timing for every query/command. To surface these as metrics in Grafana, configure the -// OTel Collector's spanmetrics connector to derive metrics from those spans. - export interface OtelInstance { - sdk: NodeSDK http: HttpMetrics auth: AuthMetrics engagement: EngagementMetrics @@ -148,114 +129,32 @@ export interface OtelInstance { genAi: GenAiMetrics email: EmailMetrics rateLimit: RateLimitMetrics - shutdown: () => Promise } -export function initOtel(env: Env): OtelInstance | undefined { - const otlpEndpoint = env.OTEL_EXPORTER_OTLP_ENDPOINT - const serviceName = env.OTEL_SERVICE_NAME - - if (!otlpEndpoint) { +/** + * Build the structured metric-handle bundle used across the app. + * + * Use when: + * - DI assembly in `apps/server/src/app.ts`. Returns `null` when OTel is + * disabled (no OTLP endpoint), so callers can skip wiring `metrics?.…`. + * + * Expects: + * - `instrumentation.mjs` has already started NodeSDK (loaded via + * `tsx --import ./instrumentation.mjs`). This function does NOT start the + * SDK — it only consumes the global MeterProvider that the preload set up. + * Calling it before the preload runs would yield NoopMeter for everything. + * + * Returns: + * - Metric bundle with primed counters (so low-traffic series show up in + * Prometheus from boot), or `null` when OTel is disabled. + */ +export function initOtel(env: Env): OtelInstance | null { + if (!env.OTEL_EXPORTER_OTLP_ENDPOINT) { logger.log('OpenTelemetry disabled (set OTEL_EXPORTER_OTLP_ENDPOINT to enable)') - return + return null } - if (env.OTEL_DEBUG === 'true') { - diag.setLogger(new DiagConsoleLogger(), DiagLogLevel.DEBUG) - } - - // Parse OTEL_EXPORTER_OTLP_HEADERS (format: "key=value,key2=value2") - const headers: Record = {} - const rawHeaders = env.OTEL_EXPORTER_OTLP_HEADERS - if (rawHeaders) { - for (const pair of rawHeaders.split(',')) { - const idx = pair.indexOf('=') - if (idx > 0) { - headers[pair.slice(0, idx).trim()] = pair.slice(idx + 1).trim() - } - } - } - - const resource = resourceFromAttributes({ - [ATTR_SERVICE_NAME]: serviceName, - [ATTR_SERVICE_VERSION]: processEnv.npm_package_version || '0.0.0', - 'service.namespace': env.OTEL_SERVICE_NAMESPACE, - 'deployment.environment': processEnv.NODE_ENV || 'development', - }) - - const traceExporter = new OTLPTraceExporter({ - url: `${otlpEndpoint}/v1/traces`, - headers, - }) - - const metricExporter = new OTLPMetricExporter({ - url: `${otlpEndpoint}/v1/metrics`, - headers, - }) - - const logExporter = new OTLPLogExporter({ - url: `${otlpEndpoint}/v1/logs`, - headers, - }) - - // Head-based sampling ratio: 1.0 = 100% (default), 0.1 = 10%, etc. - // Metrics are always 100% accurate regardless of this setting. - const samplingRatio = env.OTEL_TRACES_SAMPLING_RATIO - const sampler = new ParentBasedSampler({ - root: new TraceIdRatioBasedSampler(samplingRatio), - }) - - const sdk = new NodeSDK({ - resource, - sampler, - spanProcessors: [new BatchSpanProcessor(traceExporter)], - metricReaders: [new PeriodicExportingMetricReader({ - exporter: metricExporter, - exportIntervalMillis: 15_000, - exportTimeoutMillis: 10_000, - })], - logRecordProcessors: [new BatchLogRecordProcessor(logExporter)], - // NOTICE: PgInstrumentation and IORedisInstrumentation are registered in - // instrumentation.mjs (loaded via --import) so require-in-the-middle can - // patch their CJS modules before tsx's ESM loader caches them. They only - // emit spans (not metrics), and the trace API has a proxy that upgrades - // a noop tracer to the real one when the SDK starts — so registering - // early is safe for them. - // - // HttpInstrumentation MUST be here (NodeSDK config) and NOT in the - // preload, because: - // - It records `http.server.request.duration` to a Histogram instrument - // created against `this.meter`. - // - The OTel metrics API does NOT have a proxy mechanism (see comment - // below at sdk.start()). A meter obtained before the real - // MeterProvider is installed becomes a permanent NoopMeter, and the - // histogram inside it silently swallows every record() call. - // - NodeSDK calls setMeterProvider on its config-passed instrumentations - // AT start time, after the real provider is installed. That path - // re-runs `_updateMetricInstruments()` and gives the instrumentation - // a real histogram. - // - The patch HttpInstrumentation installs is `Server.prototype.emit` - // (incoming) — prototype-level, race-immune. Patching at SDK-start - // time instead of preload time still catches every Server instance - // created later. - // Source: node_modules/.../@opentelemetry+api/.../api/metrics.js - // (`getMeterProvider()` returns NoopMeterProvider until setGlobalMeterProvider - // is called; cached meters are not retroactively upgraded.) - instrumentations: [ - new HttpInstrumentation({ - ignoreIncomingRequestHook: req => req.url === '/health', - }), - new RuntimeNodeInstrumentation(), - ], - }) - - // SDK must start BEFORE metrics.getMeter() — the metrics API does NOT - // have a proxy mechanism like traces. getMeter() called before start() - // returns a permanent NoopMeter that never upgrades. - sdk.start() - logger.log(`OpenTelemetry initialized, exporting to ${otlpEndpoint}, sampling ratio: ${samplingRatio}`) - - const meter = metrics.getMeter(serviceName) + const meter = metrics.getMeter(env.OTEL_SERVICE_NAME) // HTTP metrics (semconv: unit MUST be seconds) const http: HttpMetrics = { @@ -301,13 +200,6 @@ export function initOtel(env: Env): OtelInstance | undefined { characterEngagement: meter.createCounter(METRIC_CHARACTER_ENGAGEMENT, { description: 'Number of character engagement actions (like/bookmark)', }), - // NOTICE: - // ObservableGauge — caller (chat-ws factory) registers a callback that - // reads the live connection registry on each export interval. UpDownCounter - // was previously used but drifted: missed `-1` on process crash / SIGKILL / - // TCP RST left the counter stuck high until Prom staleness expired the - // dead instance's series (~5 min). The pull-based gauge self-corrects on - // the next scrape because there is no delta state to leak. wsConnectionsActive: meter.createObservableGauge(METRIC_WS_CONNECTIONS_ACTIVE, { description: 'Active WebSocket connections (live registry size, scraped per export interval)', }), @@ -412,61 +304,40 @@ export function initOtel(env: Env): OtelInstance | undefined { // series with a baseline of 0 without distorting any rates. // Removal condition: OTel SDK changes default to register Counters at create // time (https://github.com/open-telemetry/opentelemetry-specification/issues/2298). - function primeCounter(counter: Counter): void { - counter.add(0) - } - primeCounter(auth.attempts) - primeCounter(auth.failures) - primeCounter(auth.userRegistered) - primeCounter(auth.userLogin) - primeCounter(engagement.chatMessages) - primeCounter(engagement.characterCreated) - primeCounter(engagement.characterDeleted) - primeCounter(engagement.characterEngagement) - primeCounter(engagement.wsMessagesSent) - primeCounter(engagement.wsMessagesReceived) - primeCounter(revenue.stripeCheckoutCreated) - primeCounter(revenue.stripeCheckoutCompleted) - primeCounter(revenue.stripePaymentFailed) - primeCounter(revenue.stripeSubscriptionEvent) - primeCounter(revenue.stripeEvents) - primeCounter(revenue.stripeRevenue) - primeCounter(revenue.fluxInsufficientBalance) - primeCounter(revenue.fluxCredited) - primeCounter(revenue.fluxUnbilled) - primeCounter(revenue.ttsChars) - primeCounter(revenue.ttsPreflightRejections) - primeCounter(genAi.operationCount) - primeCounter(genAi.tokenUsageInput) - primeCounter(genAi.tokenUsageOutput) - primeCounter(genAi.fluxConsumed) - primeCounter(genAi.streamInterrupted) - primeCounter(email.send) - primeCounter(email.failures) - primeCounter(rateLimit.blocked) + const counters = [ + auth.attempts, + auth.failures, + auth.userRegistered, + auth.userLogin, + engagement.chatMessages, + engagement.characterCreated, + engagement.characterDeleted, + engagement.characterEngagement, + engagement.wsMessagesSent, + engagement.wsMessagesReceived, + revenue.stripeCheckoutCreated, + revenue.stripeCheckoutCompleted, + revenue.stripePaymentFailed, + revenue.stripeSubscriptionEvent, + revenue.stripeEvents, + revenue.stripeRevenue, + revenue.fluxInsufficientBalance, + revenue.fluxCredited, + revenue.fluxUnbilled, + revenue.ttsChars, + revenue.ttsPreflightRejections, + genAi.operationCount, + genAi.tokenUsageInput, + genAi.tokenUsageOutput, + genAi.fluxConsumed, + genAi.streamInterrupted, + email.send, + email.failures, + rateLimit.blocked, + ] + for (const counter of counters) counter.add(0) - // Graceful shutdown - const shutdown = async () => { - try { - await sdk.shutdown() - logger.log('OpenTelemetry shut down successfully') - } - catch (err) { - logger.withError(err).error('Error shutting down OpenTelemetry') - } - } - - return { - sdk, - http, - auth, - engagement, - revenue, - genAi, - email, - rateLimit, - shutdown, - } + return { http, auth, engagement, revenue, genAi, email, rateLimit } } const severityMap: Record = { diff --git a/apps/server/src/scripts/otel-http-smoke.mjs b/apps/server/src/scripts/otel-http-smoke.mjs new file mode 100644 index 000000000..3161dbb05 --- /dev/null +++ b/apps/server/src/scripts/otel-http-smoke.mjs @@ -0,0 +1,90 @@ +/** + * Verifies that the NodeSDK setup used in `instrumentation.mjs` actually + * records `http.server.request.duration` when a real CJS http server receives + * an inbound request. + * + * This is a STANDALONE simulation — it does NOT use `--import + * ./instrumentation.mjs`. It mirrors the preload's NodeSDK setup but swaps the + * OTLP exporter for an InMemoryMetricExporter so the smoke can read back what + * was recorded. The instrumentation list and SemconvStability mode are + * identical to the preload, so a passing smoke means the production path also + * records metrics correctly. + * + * Usage: + * pnpm -F @proj-airi/server exec node --import tsx ./src/scripts/otel-http-smoke.mjs + */ +import { createRequire } from 'node:module' +import { env, exit } from 'node:process' + +import { diag, DiagConsoleLogger, DiagLogLevel } from '@opentelemetry/api' +import { HttpInstrumentation } from '@opentelemetry/instrumentation-http' +import { resourceFromAttributes } from '@opentelemetry/resources' +import { AggregationTemporality, InMemoryMetricExporter, PeriodicExportingMetricReader } from '@opentelemetry/sdk-metrics' +import { NodeSDK } from '@opentelemetry/sdk-node' + +env.OTEL_SEMCONV_STABILITY_OPT_IN ??= 'http' +// Disable trace + log exporters — the smoke only needs to read metric output +// via the InMemoryMetricExporter we plug in below. Without these, NodeSDK +// defaults to OTLP/HTTP exporters targeting 127.0.0.1:4318, which fails with +// ECONNREFUSED when no collector is running locally. +env.OTEL_TRACES_EXPORTER = 'none' +env.OTEL_LOGS_EXPORTER = 'none' +if (env.OTEL_DEBUG === 'true') + diag.setLogger(new DiagConsoleLogger(), DiagLogLevel.DEBUG) + +const exporter = new InMemoryMetricExporter(AggregationTemporality.CUMULATIVE) + +const sdk = new NodeSDK({ + resource: resourceFromAttributes({ 'service.name': 'otel-http-smoke' }), + metricReaders: [new PeriodicExportingMetricReader({ exporter, exportIntervalMillis: 200 })], + instrumentations: [ + new HttpInstrumentation({ ignoreIncomingRequestHook: req => req.url === '/health' }), + ], +}) +sdk.start() + +// `require('http')` MUST happen after `sdk.start()` — that's when +// registerInstrumentations installs the require-in-the-middle hook. If we +// require'd http during top-level imports, the module would be cached +// unpatched and the hook would never fire. Production preload avoids this +// because sdk.start() runs before any application code resolves http. +const require = createRequire(import.meta.url) +const { createServer } = require('node:http') + +const server = createServer((req, res) => { + res.statusCode = 200 + res.end('ok') +}) +await new Promise(resolve => server.listen(0, '127.0.0.1', resolve)) +const { port } = server.address() +console.info(`[smoke] http server listening on 127.0.0.1:${port}`) + +for (let i = 0; i < 3; i++) + await fetch(`http://127.0.0.1:${port}/test-${i}`).then(r => r.text()) + +// Wait one export interval, then close the server. sdk.shutdown() calls +// forceFlush on all metric readers, so the InMemoryMetricExporter is +// guaranteed to have received whatever was buffered. +await new Promise(r => setTimeout(r, 300)) +server.close() +await sdk.shutdown() + +const exported = exporter.getMetrics() +const httpServerMetrics = [] +for (const rm of exported) { + for (const sm of rm.scopeMetrics) { + for (const m of sm.metrics) { + if (m.descriptor.name.startsWith('http.server')) + httpServerMetrics.push(` ${m.descriptor.name} (${m.dataPointType}) — ${m.dataPoints.length} datapoints`) + } + } +} + +console.info('[smoke] http.server.* metrics observed after request:') +if (httpServerMetrics.length === 0) { + console.error(' ❌ NONE — instrumentation did not record') + exit(1) +} +for (const line of httpServerMetrics) console.info(line) +console.info('[smoke] ✅ http.server.request.duration is live') +exit(0) diff --git a/apps/server/src/scripts/otel-smoke.mjs b/apps/server/src/scripts/otel-smoke.mjs index 458c76ecc..29c8322b1 100644 --- a/apps/server/src/scripts/otel-smoke.mjs +++ b/apps/server/src/scripts/otel-smoke.mjs @@ -11,6 +11,10 @@ * Histograms (gen_ai.client.first_token.duration, airi.email.duration, ...) * are intentionally NOT in the output — they only register on first .record(). * + * NOTE: Run WITHOUT `--import ./instrumentation.mjs`. The preload would start + * a real NodeSDK with OTLP exporter and override the InMemoryMetricExporter + * this smoke installs as the global MeterProvider. + * * Usage: * pnpm -F @proj-airi/server exec node --import tsx ./src/scripts/otel-smoke.mjs */ @@ -45,7 +49,7 @@ const { parseEnv } = await import('../libs/env.ts') const parsed = parseEnv(env) const inst = initOtel(parsed) if (!inst) { - console.error('initOtel returned undefined') + console.error('initOtel returned null (OTEL_EXPORTER_OTLP_ENDPOINT not set?)') exit(1) } @@ -60,5 +64,5 @@ for (const rm of exported) { } console.info('REGISTERED:') for (const n of [...new Set(names)].sort()) console.info(` ${n}`) -await inst.shutdown() +await provider.shutdown() exit(0)