From 62e51637f996fdfcb600601eb7a6c26adf57052b Mon Sep 17 00:00:00 2001 From: Denis Silva Date: Thu, 16 Jul 2026 17:22:35 -0300 Subject: [PATCH 1/5] docs: spec for aggregating prom-client metrics across cluster workers Specification only (no implementation) for fixing per-worker Prometheus registry interleaving on /metrics via prom-client AggregatorRegistry. Internal task id: task-58ee1acb (bean) --- ...-prom-client-metrics-across-cluster-wor.md | 284 ++++++++++++++++++ 1 file changed, 284 insertions(+) create mode 100644 specs/aggregate-prom-client-metrics-across-cluster-wor.md diff --git a/specs/aggregate-prom-client-metrics-across-cluster-wor.md b/specs/aggregate-prom-client-metrics-across-cluster-wor.md new file mode 100644 index 000000000..99fc21d84 --- /dev/null +++ b/specs/aggregate-prom-client-metrics-across-cluster-wor.md @@ -0,0 +1,284 @@ +# Spec: Aggregate prom-client metrics across cluster workers for `/metrics` + +Internal task id: task-58ee1acb (bean) +Branch: `night/aggregate-prom-client-metrics-across-cluster-wor` + +> **Status: specification only.** This document describes the planned change. No +> implementation is included in this PR yet. + +--- + +## Context & problem + +VTEX IO runtimes run as a Node.js `cluster`: the master (`src/service/master.ts`) +forks `min(cpus, MAX_WORKERS=4)` workers (`src/service/loaders.ts` `getWorkers`, +`src/constants.ts` `MAX_WORKERS`), each worker listening on the same shared port +(`HTTP_SERVER_PORT`, `src/service/index.ts`). Every worker keeps its **own** +prom-client default registry (`register` from `prom-client`): the request +counters are created per-worker in +`src/service/metrics/requestMetricsMiddleware.ts` via +`src/service/tracing/metrics/instruments.ts` (`new Counter(REQUESTS_TOTAL)` etc.), +and `collectDefaultMetrics()` is called per-worker in +`src/service/worker/runtime/builtIn/middlewares.ts`. + +The `/metrics` endpoint is served by `prometheusLoggerMiddleware` +(`src/service/worker/runtime/builtIn/middlewares.ts:24-42`). It answers with +`register.metrics()` — i.e. **only the local registry of whichever worker the OS +round-robin handed the scrape connection to**. Because Node's keep-alive socket +timeout (5s) is shorter than the Prometheus scrape interval, almost every scrape +lands on a *different* worker. + +Consequence: Prometheus sees, under a single `instance` label, an interleaved +braid of 4 independent monotonic counters. Each time a scrape hits a worker whose +local count is lower than the previously scraped worker's, Prometheus treats the +drop as a **counter reset**, so `rate()` / `increase()` over `runtime_*` counters +(notably `runtime_http_requests_total{handler,status_code}`) are inflated by +orders of magnitude (~×40 measured on a live pod). Full analysis: +`metrics-discrepancy-report.html`, sections 3 and 9.1; this task is +recommendation 1 in section 9. + +The pinned `prom-client@^14.2.0` ships `AggregatorRegistry` and a cluster +IPC protocol precisely for this: workers report their registry to the master over +`cluster` messaging, and the master merges them into a single monotonic view. + +### Relevant existing facts (verified in-repo) + +- `prom-client@14.2.0` exports `AggregatorRegistry` with: + - instance method `clusterMetrics(): Promise` (master-side; requests + every connected worker's registry-as-JSON, aggregates, returns exposition + text). + - static `AggregatorRegistry.aggregate(metricsArr)` and `setRegistries(regs)`. + - The constructor calls `addListeners()`, which is **idempotent** and installs: + - in the **master**: a `cluster.on('message')` listener collecting + `prom-client:getMetricsRes` responses. + - in a **worker**: a `process.on('message')` listener that answers + `prom-client:getMetricsReq` with `registries.map(r => r.getMetricsAsJSON())`. + - Default `registries = [globalRegistry]`, which is exactly the `register` our + instruments and `collectDefaultMetrics()` write to — so **no** `setRegistries` + call is needed. +- `clusterMetrics()` is only useful in the **master** (it iterates + `cluster.workers`). But `/metrics` is served **inside a worker** (Koa + middleware). So the answering worker must obtain the aggregate from the master + over IPC. +- Existing IPC message plumbing to mirror: + - Master → worker and worker → master string/tagged messages already exist: + `UP_SIGNAL` (`src/constants.ts`), `statusTrack` / `broadcastStatusTrack` + (`src/service/worker/runtime/statusTrack.ts`), routed by `onMessage` in + `src/service/master.ts` and `onMessage(serviceJSON)` in + `src/service/worker/index.ts`. + - Both `onMessage` handlers currently `logger.warn(...)` on any unrecognized + message. prom-client's own `getMetricsReq`/`getMetricsRes` messages and our + new aggregate messages will also reach these handlers, so both must be taught + to ignore messages they don't own instead of warning. +- Scrapes of `/metrics` are excluded from request counters today because + `prometheusLoggerMiddleware` runs **before** the counting middlewares in the + Koa chain (`src/service/worker/index.ts`) and returns without calling `next()` + for the `/metrics` path. This must be preserved. +- Single-worker mode: `getWorkers()` returns `1` when `LINKED` + (`src/service/loaders.ts`). `serviceJSON.workers` carries the resolved count. + +--- + +## Proposed approach + +**Serve `/metrics` from an aggregate that the master builds from all workers, +requested by the answering worker over the existing cluster IPC.** + +Flow (multi-worker mode, `serviceJSON.workers > 1`): + +1. Master, at `startMaster`, constructs a single `AggregatorRegistry` + (`new AggregatorRegistry()`), enabling both prom-client's master-side + collector listener and our own request handler. +2. Each worker, at `startWorker`, constructs an `AggregatorRegistry` too, so + prom-client's worker-side `getMetricsReq` responder is installed in every + worker. (Its own registry is still the default `register`.) +3. When a worker receives `GET /metrics`, instead of returning + `register.metrics()`, it sends a tagged IPC request to the master + (`process.send({ type: AGG_METRICS_REQ, id })`) and awaits a matching + `AGG_METRICS_RES` (correlation id + a bounded timeout), then serves the + returned exposition string with `Content-Type: register.contentType`. +4. The master, on `AGG_METRICS_REQ`, calls `aggregatorRegistry.clusterMetrics()`. + prom-client fans `getMetricsReq` out to **all** connected workers (including + the one that asked), collects each worker's registry JSON, merges with the + per-metric aggregators, and resolves to a single exposition string. The master + replies to the requesting worker only: + `worker.send({ type: AGG_METRICS_RES, id, body })` (or `{ id, error }`). + +Because the merge is produced from every worker's registry gathered in one pass, +the answering worker is **not** double-counted (it is one of the N sources, not a +source plus a separate local merge). + +Single-worker mode (`serviceJSON.workers === 1`, includes `LINKED`): the +middleware keeps its **current** behavior exactly — `await eventLoopLagMeasurer +.updateInstrumentsAndReset()` then `ctx.body = await register.metrics()`. No IPC, +no aggregation. This keeps LINKED/dev and the `workers:1` production case +unchanged and avoids IPC overhead when there is nothing to aggregate. + +Robustness: if the IPC round-trip errors or times out (prom-client's +`clusterMetrics` has its own 5s timeout; we add a slightly larger guard), the +worker falls back to serving its **local** `register.metrics()` so `/metrics` +never returns empty/500. This is logged, not fatal. + +### New/changed module boundaries + +A small dedicated module (proposed `src/service/metrics/clusterMetricsAggregator.ts`) +owns: +- message-type constants (`AGG_METRICS_REQ`, `AGG_METRICS_RES`) and their type + guards; +- master setup: lazily create the singleton `AggregatorRegistry`, expose + `handleWorkerMetricsRequest(worker, message)` that calls `clusterMetrics()` and + replies; +- worker setup: `ensureWorkerAggregatorRegistry()` (constructs the registry so the + prom-client responder is installed) and `requestAggregatedMetrics(): Promise` + (send + await correlated response, with timeout + fallback), plus + `handleMasterMetricsResponse(message)` to resolve pending promises. + +Keeping this in one module keeps `master.ts`, `worker/index.ts` and +`middlewares.ts` changes minimal and testable in isolation with IPC mocks. + +--- + +## Files / components to change + +| File | Change | +| --- | --- | +| `src/service/metrics/clusterMetricsAggregator.ts` *(new)* | Message constants + guards; master-side `AggregatorRegistry` singleton + request handler; worker-side request/response correlation, timeout, and local fallback. | +| `src/service/master.ts` | In `startMaster`, initialize the aggregator (construct `AggregatorRegistry`). In `onMessage`, route `AGG_METRICS_REQ` to `handleWorkerMetricsRequest`; ignore prom-client's `getMetricsRes`/`getMetricsReq` messages instead of `logger.warn`. | +| `src/service/worker/index.ts` | In `startWorker`, call `ensureWorkerAggregatorRegistry()`. In `onMessage(serviceJSON)`, route `AGG_METRICS_RES` to `handleMasterMetricsResponse`; ignore prom-client's `getMetricsReq` messages instead of `logger.warn`. | +| `src/service/worker/runtime/builtIn/middlewares.ts` | In `prometheusLoggerMiddleware`, when `serviceJSON.workers > 1` request the aggregate via IPC and serve it; when `== 1` keep current local-registry path. Needs access to the worker count (pass `serviceJSON`/`workers` into the middleware factory — it is constructed in `startWorker` which already has `serviceJSON`). Keep the early-return-before-counting behavior and the `COLOSSUS_ROUTE_ID` guard. | +| `src/constants.ts` *(maybe)* | Add message-type string constants if we prefer them centralized next to `UP_SIGNAL`; otherwise they live in the new module. | +| Test files under `__tests__/` *(new)* | See Test plan. | + +No changes to metric names, labels, help text, buckets, or the set of collected +metrics. `runtime_http_requests_total{handler,status_code}` and all other +`runtime_*` / `io_*` series keep identical identity. + +--- + +## How each `AC:` line will be satisfied + +1. **Two consecutive scrapes never show a decreasing `runtime_http_requests_total` + series (monotonic regardless of which worker answers).** + After the change every scrape is served from the *same* aggregate (sum over all + workers) instead of one arbitrary worker's local subset. A Jest test drives the + aggregation with IPC mocks / fake worker registries: it simulates the scrape + being answered by worker A then worker B, asserts both responses are the merged + view, and asserts no series value decreases between the two scrapes. + +2. **`/metrics` equals the sum across workers (a counter incremented once per + worker in N workers reports N).** + `AggregatorRegistry.aggregate` sums counter samples with matching labels across + registries. Test: build N registries, `inc()` the same + `runtime_http_requests_total{handler,status_code}` once in each, run them through + the aggregation, assert the merged output reports exactly `N` for that series. + +3. **`workers === 1` (LINKED) serves the default registry content unchanged.** + The middleware branches on `serviceJSON.workers`: for `1` it executes the + existing code path (`updateInstrumentsAndReset()` + `register.metrics()`) with no + IPC. Test: invoke `prometheusLoggerMiddleware` built with `workers: 1` against a + mock `/metrics` ctx and assert the body equals `register.metrics()` and no IPC + send occurred. + +4. **Default process metrics (`collectDefaultMetrics`) remain present.** + `collectDefaultMetrics()` still runs per worker into the default registry, which + is what each worker reports to the aggregator; the aggregate therefore includes + them (e.g. `process_cpu_seconds_total`, `nodejs_*`). Test asserts a known + default-metric name appears in the aggregated output, and (single-worker path) in + the local output. + +5. **`yarn test` passes.** New tests are added; existing tests remain green + (message-routing guards keep `onMessage` behavior for known messages). + +6. **`yarn lint` passes.** New code follows `tslint-config-vtex` + (alphabetized object literals, import order) as in surrounding files. + +7. **`yarn build` passes.** Types: use `AggregatorRegistry` and message + interfaces; `clusterMetrics()` returns `Promise`; middleware factory + signature updated to receive the worker count. + +--- + +## Risks & alternatives considered + +**Assumptions (no human available to confirm):** +- The default global registry (`register`) is the only registry we need to + aggregate. Verified: instruments and `collectDefaultMetrics` all target the + default registry, so `AggregatorRegistry`'s default `registries=[globalRegistry]` + is correct and `setRegistries` is unnecessary. +- `serviceJSON.workers` is the reliable multi/single switch (it already resolves + `LINKED → 1` and caps at `MAX_WORKERS`). Chosen over reading `LINKED` directly so + a real `workers:1` production config also takes the unchanged path. +- Serving `/metrics` from the worker (proxying to master over IPC) is preferred + over moving the endpoint to the master, because the master is not a Koa HTTP + server and does not listen on `HTTP_SERVER_PORT`; relocating the endpoint would + be a much larger, riskier change. + +**Risks & mitigations:** +- *IPC handler collisions / log noise.* prom-client adds its own + `process.on('message')` / `cluster.on('message')` listeners; these fire + alongside our `onMessage` handlers, which today `warn` on unknown messages. Both + handlers will be updated to silently ignore messages they don't own + (prom-client's `getMetricsReq`/`getMetricsRes` and unmatched aggregate ids). Risk + of behavioral drift on existing known messages is avoided by only adding + branches, not altering existing ones. +- *Latency / timeout.* `clusterMetrics()` has a built-in 5s timeout. A slow/dead + worker could delay a scrape. Mitigation: bounded wait on the worker side plus + fallback to local `register.metrics()` so `/metrics` still returns 200 promptly; + the fallback is logged. Prometheus scrape timeout is typically ≥10s. +- *Event-loop-lag gauges.* `eventLoopLagMeasurer.updateInstrumentsAndReset()` is + called only on the answering worker and lag is a **gauge**; + `AggregatorRegistry` sums gauges across workers by default, which is not a + meaningful aggregation for lag, and non-answering workers won't have refreshed + their lag gauge at scrape time. This is a pre-existing per-worker artifact and is + **out of scope** for this task (which targets `runtime_*` counters). Documented + here so it is a conscious decision; a follow-up could set a custom aggregator + (`max`/`average`) or `omit` for these gauges. The answering worker still calls + `updateInstrumentsAndReset()` in both paths to preserve current behavior. +- *Ordering.* Master must have its `AggregatorRegistry` before workers ask. + Guaranteed: it is created in `startMaster` before any worker can accept traffic. +- *`io_http_requests_current` gauge* is also summed across workers; that is + arguably the desired "current concurrent requests across the replica" and matches + or improves current behavior; noted, not changed. + +**Alternatives considered:** +- *Move `/metrics` to the master process* (separate tiny HTTP listener): + cleanest conceptually but adds a new listener/port and process responsibilities; + rejected as too invasive for this fix. +- *Shared memory / external store for counters*: over-engineered; prom-client + already provides the IPC aggregation protocol. +- *Sticky-session the scrape to one worker*: doesn't fix the underlying + per-worker split (still under-reports 3/4 of traffic). + +--- + +## Test plan + +Framework: existing Jest + ts-jest. New specs under `__tests__/` next to the +touched code (e.g. `src/service/metrics/__tests__/clusterMetricsAggregator.test.ts` +and a middleware test alongside `builtIn/`). + +1. **Monotonic across which-worker-answers (AC 1).** Construct several in-memory + registries with differing `runtime_http_requests_total{handler,status_code}` + values. Exercise the aggregation twice, simulating the scrape being answered by + different workers each time (IPC mocked). Assert every series in scrape #2 is + `>=` the same series in scrape #1 (no decrease). +2. **Sum across workers (AC 2).** N registries, each `inc()` the same series once; + assert merged output reports `N` for that series and that per-worker distinct + label sets are all present and summed correctly. +3. **Single-worker unchanged (AC 3).** Call `prometheusLoggerMiddleware` built with + `workers: 1`; mock a `/metrics` ctx; assert body === `register.metrics()`, + `Content-Type` set to `register.contentType`, and that no `process.send` IPC + occurred. Also assert non-`/metrics` and `COLOSSUS_ROUTE_ID` requests still call + `next()` and are not counted. +4. **Default metrics present (AC 4).** Assert a known `collectDefaultMetrics` + series name (e.g. `process_cpu_seconds_total` / a `nodejs_` metric) appears in + both the aggregated output and the single-worker output. +5. **IPC request/response correlation + timeout fallback.** Mock master/worker + `send`/`on('message')`: assert a worker `AGG_METRICS_REQ` gets a correlated + `AGG_METRICS_RES`, the pending promise resolves with the body, and that on + timeout/error the middleware falls back to local `register.metrics()`. +6. **Message routing guards.** Assert master `onMessage` and worker `onMessage` + route the new messages correctly and no longer `warn` on prom-client's + `getMetricsReq`/`getMetricsRes`, while still handling `UP_SIGNAL` / + `statusTrack` as before. +7. **Gates.** `yarn test`, `yarn lint`, `yarn build` all pass (AC 5–7). From 6911aaffad8dce9e5612b87265ddd13a36bf70e4 Mon Sep 17 00:00:00 2001 From: Denis Silva Date: Fri, 17 Jul 2026 11:11:18 -0300 Subject: [PATCH 2/5] feat(metrics): aggregate prom-client metrics across cluster workers Multi-worker runtimes kept a per-worker prom-client registry, so /metrics answered from whichever worker the shared-port round-robin picked. Because keep-alive (5s) is shorter than the scrape interval, Prometheus stored an interleaved braid of independent counters under one instance label, treating every downward sample as a counter reset and inflating rate()/increase() on runtime_* counters by orders of magnitude. Aggregate across workers with prom-client's AggregatorRegistry: the master builds a single merged, monotonic view over the existing cluster IPC and the worker answering the scrape serves that aggregate. Single-worker / LINKED mode keeps serving the local default registry unchanged. - src/service/metrics/clusterMetricsAggregator.ts: IPC request/response protocol, master aggregator, worker responder, timeout fallback to local registry. - master.ts / worker/index.ts: wire the tagged IPC messages and set up the aggregator only when workers > 1. - builtIn/middlewares.ts: prometheusLoggerMiddleware serves the aggregate in multi-worker mode, local registry otherwise; /metrics still excluded from request counters. Includes unit tests proving cross-worker sum, monotonicity, single-worker behavior, and default-metric presence. Co-authored-by: Cursor --- metrics-discrepancy-report.html | 1227 +++++++++++++++++ src/service/master.ts | 16 + .../clusterMetricsAggregator.test.ts | 199 +++ .../metrics/clusterMetricsAggregator.ts | 194 +++ src/service/worker/index.ts | 19 +- .../builtIn/__tests__/middlewares.test.ts | 98 ++ .../worker/runtime/builtIn/middlewares.ts | 10 +- 7 files changed, 1760 insertions(+), 3 deletions(-) create mode 100644 metrics-discrepancy-report.html create mode 100644 src/service/metrics/__tests__/clusterMetricsAggregator.test.ts create mode 100644 src/service/metrics/clusterMetricsAggregator.ts create mode 100644 src/service/worker/runtime/builtIn/__tests__/middlewares.test.ts diff --git a/metrics-discrepancy-report.html b/metrics-discrepancy-report.html new file mode 100644 index 000000000..5b4421b13 --- /dev/null +++ b/metrics-discrepancy-report.html @@ -0,0 +1,1227 @@ + + + + + +Why runtime_http_requests_total disagrees: Prometheus vs Diagnostics — investigation report + + + +
+ +

Investigation report · July 14, 2026 · field-validated July 16, 2026

+

Why runtime_http_requests_total shows ~10× more in Prometheus than in Diagnostics

+

+ Scope: node-vtex-api (master @ 8c09aad4), @vtex/diagnostics-nodejs 0.1.8-io, + @opentelemetry/sdk-metrics 1.30.1, ClickHouse telemetry.metrics_distributed. + Example workload: vtex.admin-cms-graphql-rc@1.42.0. + Single-worker control (§8): vtex.render-server@8.180.1. +

+ +
+

Summary of the error — silent metrics data-loss at ClickHouse. The diagnostics pipeline is +permanently losing metrics datapoints without reporting any failure. Root cause is two independent facts +that compound:

+
    +
  • Trigger (active incident). The replicated tables otel_metrics_sum and + otel_metrics_histogram are read-only (is_readonly=1, + is_session_expired=1, 0 active replicas — expired ClickHouse-Keeper session). otel_metrics_gauge + and otel_logs are healthy, so only Sum/Histogram metrics are affected — and + runtime_http_requests_total is a Sum.
    • +
  • Amplifier (design). The metrics consumer writes to ClickHouse + fire-and-forget (async_insert=1&wait_for_async_insert=0) and commits the Kafka offset on + hand-off (message_marking.after=true). So a failed flush is never retried and never surfaces: + otelcol_exporter_send_failed stays 0 while the data is gone. A second latent copy of the anti-pattern sits + upstream (producer Kafka required_acks: 0, retry_on_failure: false).
    • +
+

Measured impact: cluster-wide, system.asynchronous_insert_log shows the metrics tables +failing 81–91% of flushes for 8+ straight hours — recorded as +Code: 159 … Timeout exceeded: maximum: 24000 ms: while pushing to view otel.metrics_sum_view — with +10 of 12 replica instances read-only. The ~15% flush-success share matches the ~15% coverage / +×7 under-count measured live for vtex.render-server@8.180.1 exactly (§8). Because the write path hides +the failure, collector dashboards look healthy throughout. Fix: restore the read-only replicas / Keeper +sessions (and the MV-push timeout), and set wait_for_async_insert=1 (or commit offsets only after a durable +insert) so losses become visible and reprocessable. Full evidence and error samples in §8; remediation in §9.

+
+ + +

1. Executive summary

+
+

+Both counters are incremented by adjacent middlewares in the same Koa pipeline +(src/service/worker/index.ts:228–229), exactly once per request each. The divergence is therefore +not created at increment time — it is created downstream, in how each pipeline exports and how each side is queried. +The investigation found four mechanisms, all pushing in the observed direction (Prometheus bigger): +

+ + + + + + + + + + + + + + + + + + + + + + + + + + + + + + +
#MechanismDirectionStatusPlausible size
1Prometheus rate/increase inflation from per-worker registries. Each of the 4 cluster workers keeps a private + prom-client registry; /metrics on the shared port is answered by one arbitrary worker per scrape. + The sampled series interleaves 4 independent counters, and every downward sample is treated by PromQL as a counter + reset that adds the full new value.Prom ↑confirmed in code observed live (§3)Unbounded; grows with worker uptime — measured ~×40 on one live window
2Diagnostics coverage gaps. Any pod where VTEX_DIAGNOSTICS_TELEMETRY_ENABLED ≠ 'true' runs a + no-op metrics client; any pod where OTel instruments fail to initialize serves traffic uncounted. Those pods + contribute to Prometheus only. And fleet-wide: both o11y collectors run a + filter/temporality that drops every non-delta datapoint — apps built on + pre-Dec-2025 @vtex/api (before 65e50da7) export cumulative, so their counters and + histograms never reach ClickHouse at all.Diag ↓confirmed in collector config size needs checkPer-app all-or-nothing: old-SDK apps are 100% invisible in diagnostics; this app reports (5 pods seen)
3Cardinality overflow on the diagnostics counter. The OTel counter carries + vtex.account.name (Prometheus’ doesn’t). The SDK caps each instrument at + 2000 attribute-sets per 60 s window per worker; the excess is folded into a single + otel.metric.overflow="true" series with no handler, no status, no account. + In your query those rows surface as Status: | Handler: None — or vanish if any stage drops them.Diag ↓ (per-handler views)confirmed in code measured: zero for this app (§7 step 3)Ruled out for this app — overflow = 0 over 24 h; stays latent for higher-cardinality apps
4Delta export is lossy on failure. Since the switch to delta temporality (commit 65e50da7, + 2025-12-16), a failed/timed-out 60 s OTLP export loses that window permanently (cumulative would self-correct). + Interval/timeout were already raised 5 s→60 s (d122a999, #623) under export pressure.Diag ↓confirmed in code size needs checkDepends on export error rate
+

+There is also a comparison-methodology layer that can produce clean constant factors on its own and must be +ruled out first: unit mismatch (delta points are “requests per 60 s per worker”, not a rate), exact-version pinning +(app = '…@1.42.0' vs. an unpinned Grafana selector), and asymmetric handler filters +(builtin:healthcheck is excluded in the ClickHouse query — is it excluded on the Prometheus panel? +for an admin app, healthchecks are often the majority of requests). See §5. +

+

+A stable, smooth “~10×” most resembles #2 + methodology; an erratic, uptime-correlated gap most resembles +#1. §6 weighs the two sources and concludes that the diagnostics → ClickHouse number is the one +closer to reality today: its errors only under-count and are measurable, while PromQL over multi-worker pods is +unrecoverable by construction. §7 gives a 30-minute playbook that tells the mechanisms apart, and §8 runs it +live against a single-worker control (vtex.render-server): with Mechanism #1 switched off the counter is +provably monotonic, yet ClickHouse still under-reports the 1,384-pod fleet ~7× — root-caused (§8) to silent write-loss +in the o11y pipeline (read-only otel_metrics_sum/histogram replicas + wait_for_async_insert=0 +fire-and-forget writes), not per-worker inflation. +

+
+ + +

2. One request, two counters, two pipelines

+

+Every inbound request traverses both middlewares back-to-back — same scope, same +finally-block increment semantics, including healthchecks and events. Scrapes of /metrics are excluded +from both (the Prometheus responder returns before either middleware runs). The pipelines only diverge after the increment: +

+ +
+ HTTP request → Koa pipeline → both counters +1 + + (requestMetricsMiddleware.ts:43 · otelRequestMetricsMiddleware.ts:64 — mounted at worker/index.ts:228–229) +
+ +
+
+ PULL · PROMETHEUS +
prom-client counter {handler, status_code} in the default registry — one per worker process (×4) + src/service/metrics/requestMetricsMiddleware.ts:43
+
↓
+
/metrics served on the shared port 5000 — each scrape is answered by + one arbitrary worker (Node cluster round-robin; default 5 s keep-alive < scrape interval ⇒ new + connection, likely a different worker, every scrape) + builtIn/middlewares.ts:24 · service/master.ts:89 · loaders.ts:19 (workers = min(cpus, 4))
+
↓
+
Prometheus/Grafana rate()/increase() — interleaved counters look like + constant counter resets → systematic over-count (see §3)
+
+
+ PUSH · DIAGNOSTICS +
OTel counter {handler, status_code, vtex.account.name} — one SDK per worker + src/service/metrics/otelRequestMetricsMiddleware.ts:64
+
↓
+
SDK aggregation: delta temporality, 60 s interval; cardinality cap + 2000 attribute-sets/instrument/cycle → excess folded into otel.metric.overflow="true"; + failed export = window lost + telemetry/client.ts:61–69 · sdk-metrics DeltaMetricProcessor.js:36–45
+
↓
+
OTLP gRPC → collector → ClickHouse telemetry.metrics_distributed + resource: service.instance.id = client-hostname-pod (no per-worker component)
+
↓
+
sumMerge(Sum) — aggregate states are additive, so the 4 workers’ deltas sum + correctly even with identical stream identity (unlike any PromQL-style consumer)
+
+
+ +

+Timeline that shaped the current state: d122a999 (2025-12-04) export interval/timeout 5 s→60 s · +3f65ab73 (2025-12-16) vtex.account.name added to the OTel request metrics · +65e50da7 (2025-12-16) exporter switched cumulative→delta. +

+ + +

3. Mechanism #1 — what Prometheus actually sees

+

+prom-client counters live in per-process memory. With workers: min(cpus, 4) forked by +startMaster and all listening on the same port, a scrape of /metrics reaches exactly one worker — +and because Node’s default HTTP keep-alive (5 s) is shorter than any scrape interval, each scrape opens a fresh +connection and round-robin hands it to a different worker. Under one instance label, Prometheus +stores a braid of four independent counters: +

+ +
+
+ Per-worker counters (4 processes, each monotonic) + Series Prometheus samples at /metrics + ▼ sample below its predecessor → PromQL counts a “counter reset” +
+ + + + + + + + + + + + + + 9,000 + 9,500 + 10,000 + 10,500 + 11,000 + 11,500 + 12,000 + + + 0 min + 2 + 4 + 6 + 8 + 10 min + + + + + + + + + + + w3 + w1 + w4 + w2 + + + + + + + + t=0:00 · worker 1 answers · 10,000 + t=0:30 · worker 2 answers · 9,351 — lower than 10,000 → PromQL adds +9,351 as a “reset” + t=1:00 · worker 3 answers · 10,896 + t=1:30 · worker 4 answers · 10,058 → +10,058 as “reset” + t=2:00 · worker 1 answers · 10,216 + t=2:30 · worker 2 answers · 9,555 → +9,555 as “reset” + t=3:00 · worker 3 answers · 11,088 + t=3:30 · worker 4 answers · 10,268 → +10,268 as “reset” + t=4:00 · worker 1 answers · 10,432 + t=4:30 · worker 2 answers · 9,759 → +9,759 as “reset” + t=5:00 · worker 3 answers · 11,280 + t=5:30 · worker 4 answers · 10,478 → +10,478 as “reset” + t=6:00 · worker 1 answers · 10,648 + t=6:30 · worker 2 answers · 9,963 → +9,963 as “reset” + t=7:00 · worker 3 answers · 11,472 + t=7:30 · worker 4 answers · 10,688 → +10,688 as “reset” + t=8:00 · worker 1 answers · 10,864 + t=8:30 · worker 2 answers · 10,167 → +10,167 as “reset” + t=9:00 · worker 3 answers · 11,664 + t=9:30 · worker 4 answers · 10,898 → +10,898 as “reset” + t=10:00 · worker 1 answers · 11,080 + + + +
+
+
Real requests served in the window
+
4,110
+
sum of all four workers’ actual growth
+
+
+
What increase() computes
+
109,640
+
10 “resets” × ~10k each, plus real deltas
+
+
+
Inflation in this example
+
×26.7 artifact
+
grows with counter age; shrinks if scrapes pin one worker
+
+
+ +

+ Synthetic but honestly computed: 4 workers at ~1.6–1.8 req/s each, scraped every 30 s in rotation. PromQL’s reset + rule — “a decrease means the counter restarted at zero, so the whole new value is new traffic” — fires on every + worker switch that lands lower. If keep-alive happens to pin the scraper to one worker instead, the same setup + under-counts (you see ~¼ of pod traffic) until the connection rotates and produces a giant spike. + Either way, PromQL over these series is not measuring traffic. +

+ +
+ Table view — the 21 samples behind the chart + + + + + + + + + + + + + + + + + + + + + + + +
ScrapeWorker answeringCounter valuePromQL interpretation
0:00w110,000—
0:30w29,351reset → +9,351
1:00w310,896+1,545
1:30w410,058reset → +10,058
2:00w110,216+158
2:30w29,555reset → +9,555
3:00w311,088+1,533
3:30w410,268reset → +10,268
4:00w110,432+164
4:30w29,759reset → +9,759
5:00w311,280+1,521
5:30w410,478reset → +10,478
6:00w110,648+170
6:30w29,963reset → +9,963
7:00w311,472+1,509
7:30w410,688reset → +10,688
8:00w110,864+176
8:30w210,167reset → +10,167
9:00w311,664+1,497
9:30w410,898reset → +10,898
10:00w111,080+182
+
+ +

Field result — mechanism observed on a live pod confirmed live

+

+ Six consecutive /metrics scrapes of one production pod, 16 s apart (2026-07-14), reading + runtime_http_requests_total{handler="builtin:healthcheck",status_code="200"}: +

+ 
1580   1580   1548   1550   1593   1596
+ + + + + + + +
TransitionRaw deltaPromQL interpretation
1580 → 15800+0
1580 → 1548−32“counter reset” → +1,548 (full value counted as new traffic)
1548 → 1550+2+2 — the only plausibly same-worker pair; implies ~0.5 req/s pod-wide
1550 → 1593+43+43 — an inter-worker offset masquerading as traffic
1593 → 1596+3+3
+

+ A single counter can never decrease, so the 1580 → 1548 drop proves consecutive scrapes are answered by + different workers — at least three are visible (≈1548–1550, ≈1580, ≈1593–1596). Over these 80 s, + increase() computes 1,596 requests (~20 req/s) for this one low-traffic series, against a + real rate on the order of ~0.5 req/s — roughly ×40 inflation in this window (≥×7 under the most + generous reading). It also confirms scrape connections rotate workers in this environment (keep-alive does not pin), + so the artifact fires continuously in production. +

+
+ + +

4. Mechanisms #2–4 — where the diagnostics side loses counts

+ +

4.1 Coverage: pods that only exist in Prometheus needs data check

+

+VTEX_DIAGNOSTICS_TELEMETRY_ENABLED !== 'true' swaps in a no-op metrics client +(telemetry/client.ts:95, no-op factory in the library) — the middleware happily “counts” into a void. +Separately, if instruments aren’t ready within 500 ms on a request, that request passes through uncounted +(otelRequestMetricsMiddleware.ts:29–34); if the OTLP endpoint is misconfigured for a pod, all its +requests do. Every such pod still serves traffic and still reports to Prometheus. If, say, coverage is 1-in-10 replicas, +you get a clean, stable 10× gap — the shape you described. +

+

+Confirmed at the platform layer (2026-07-14, o11y-platform repo): the full path is +app SDK → producer collector → Kafka → consumer collector → otel.otel_metrics_sum → MV → +telemetry.metrics, and both collectors run a filter/temporality processor that drops +every Sum/Histogram datapoint whose temporality isn’t delta +(provisioning/vtex-io/collectors/producer.yaml:221, consumer-metrics.yaml:234; no +cumulativetodelta conversion in either pipeline — gauges pass through). Consequence: any app built with +@vtex/api older than the delta switch (65e50da7, 2025-12-16) exports cumulative and is +100% invisible in diagnostics dashboards while fully visible in Prometheus. For cross-app or fleet-level +comparisons this is very plausibly the dominant term of the gap; per app it is all-or-nothing (this report’s example app +reports, so it is on a delta-enabled version). The aggressive consumer memory_limiter +(85%/3% spike) is a secondary loss channel under load. +

+ +

4.2 Cardinality overflow at 2000 attribute-sets confirmed in code

+

+@opentelemetry/sdk-metrics@1.30.1 enforces a default aggregationCardinalityLimit of 2000 — +per instrument, per worker, per 60 s collection cycle (DeltaMetricProcessor.js:36–45; the active-window +storage is swapped at each collect). The OTel counter’s attribute space is +handler × status_code × vtex.account.name — the account dimension (added 2025-12-16) makes this explode for +multi-tenant apps. Everything past 1,999 unique combinations in a window is recorded only as +{"otel.metric.overflow": "true"}: no handler, no status, no account. +

+

In your ClickHouse query those rows are not filtered out — they surface as the series +Status: | Handler: None (empty status, handler folded to “None”). Two consequences:

+
    +
  • Any panel that groups or filters by handler/status/account silently under-reports total traffic.
    • +
  • Your “None” series is a mixture of overflow and requests that genuinely resolved no handler — distinguish them with the otel.metric.overflow key (query in §7).
    • +
+

+Field result (2026-07-14): the §7 step 3 query returned overflow_requests = 0 for every hour of +the last day on vtex.admin-cms-graphql-rc@1.42.0 — this app stays under the 2000-set cap, so +overflow contributes nothing to its gap, and its “None” series is genuinely handler-less traffic. +The mechanism remains latent for apps with more accounts×handlers×statuses per minute. (The measurement is sound +end-to-end: the materialized view passes metric attributes through untouched except device and +process.pid — 3-metrics.sql:259–262 — so overflow rows do reach the aggregated table when they occur.) +

+ +

4.3 Delta export drops are permanent confirmed in code

+

+The exporter runs OTLP/gRPC with interval: 60 s, timeout: 60 s, delta temporality +(telemetry/client.ts:61–69). With delta, a window that fails to export is gone — there is no cumulative value +for the next successful export to restore. The history (interval/timeout already raised from 5 s under pressure, +then account-attribute payload growth) makes periodic export failures a realistic, compounding loss. +

+ +

4.4 Worker identity collision — mitigated by ClickHouse, but fragile confirmed in code

+

+service.instance.id = clientName-hostname(-podName) with no per-process component +(resource-discovery.js:167–179), so all 4 workers of a pod emit byte-identical metric streams. Because your +backend stores additive aggregate states and you read with sumMerge, concurrent deltas on the same +identity sum correctly — this is why the delta switch fixed ClickHouse readings where cumulative could not work. +But it remains a latent defect: any consumer that dedupes same-identity points or converts delta→cumulative +(a Prometheus-compatible sink, a collector processor) will silently drop up to ¾ of the data. Worth one confirmation +with the pipeline owners that no dedup stage sits before ClickHouse. +

+Confirmed from production data (2026-07-14): a live row’s resource shows +service.instance.id = node-vtex-api-<pod-name> and host.name = <pod-name> — pod-level +only, no worker component, exactly as the code predicts. +

+ + +

5. Your comparison itself — three asymmetries to rule out first

+
+
    +
  1. + Units. Each diagnostics data point is “requests in one worker’s 60 s window”, stamped at export time; + the materialized view truncates TimestampTime to the minute (3-metrics.sql:230), so each + bucket in your query is requests-per-minute-ish (workers’ 60 s windows straddle minute boundaries). + A Grafana Prometheus panel typically shows rate() (req/s) or + increase() over $__rate_interval. Unless both sides are normalized to the same bucket + (req/min is the natural one), a constant factor is guaranteed. A 10-minute prom window vs. per-minute delta sums is + exactly ×10. +
    2. +
  2. + Scope. ClickHouse pins app = 'vtex.admin-cms-graphql-rc@1.42.0' (one exact build) plus + production='true', workspace='master', tenant='vtex'. If the Prometheus selector + matches the whole workload — all patch versions during rollouts, all workspaces, canaries — Prometheus counts strictly more. + Live anomaly (2026-07-14), derivation now confirmed: a pod on workspace master reported + vtex_io.workspace.type='development' — the SDK derives that value from VTEX_PRODUCTION + (constants.ts:182), and the materialized view derives the production column from exactly this + attribute (3-metrics.sql:246–250: workspace.type == 'production' ? 'true' : 'false'). Any pod + missing that env var is tagged production='false' and its entire traffic is silently dropped by the + production='true' panel filter. Audit query in §7 step 2a. +
    3. +
  3. + Handler filters. The ClickHouse query excludes builtin:healthcheck and restricts to an + explicit handler list. For an admin GraphQL app, platform healthchecks are frequently the single biggest handler. + If the Prometheus panel has no matching exclusion, the gap is largely healthchecks. +
    4. +
+
+ + +

6. Which source reflects reality more closely today?

+
+

+Verdict: for any app running more than one worker — effectively every production app, since +workers = min(cpus, 4) resolves to 4 on production nodes — the diagnostics → ClickHouse pipeline is the +closer-to-reality source today. Its failure modes only ever lose requests, the losses are bounded and +measurable, and the volume hidden by the cardinality cap is still present in the table (in the overflow bucket). +The Prometheus counter read through rate()/increase() on a multi-worker pod is not a distorted +measurement — it is not a measurement at all: the scraped samples interleave four independent counters under one +instance label, which destroys the information needed to reconstruct traffic in either direction. +

+ + + + + + + + + + + + + + + + + + + + + + + + + + + + + + + + + + + +
Failure propertyPULL · PROMETHEUSPUSH · DIAGNOSTICS → CLICKHOUSE
Direction of errorBoth directions: inflation from phantom resets (§3), deflation to ~¼ of traffic when keep-alive pins one workerOne direction only: under-count. The pipeline never invents a request
Size of errorUnbounded — every phantom reset adds an entire counter value, so the artifact grows with worker uptimeBounded — lost 60 s windows (export failures) plus attribution, not volume, lost past 2000 attribute-sets
Recoverable at query time?No — samples carry no worker label; the interleaving cannot be undone by any PromQLLargely — totals stay correct if the otel.metric.overflow bucket is included; only per-handler/account detail beyond the cap is gone
Detectable?Only indirectly (resets() > 0 without pod restarts)Directly: overflow attribute, pods-reporting count, exporter error logs (§7 steps 2–3)
Recording reliabilityPerfect — synchronous, in-memory, no flags, no exportsNear-perfect — no-op when the telemetry flag is off; ≤500 ms instrument race at pod start
Duplication riskNone at recording time, but rate() effectively duplicates counts at every phantom resetNone — the gRPC exporter does not retry, so failures only lose data, never double-count
+ +

Why the errors are not symmetrical

+
    +
  • The ClickHouse number is a floor on reality: true traffic ≥ sumMerge(Sum) with the overflow + bucket included. Every delta point that reaches the table is a true count of requests one worker actually served in one + 60 s window, and sumMerge is exact addition. You can reason with a floor.
    • +
  • The Prometheus rate is neither a floor nor a ceiling. Depending on how scrape connections happen to + land, the same pod can read 10× real traffic or ¼ of it, and flip between the two when a connection re-establishes. + Each stored sample is individually true, but the series they form is collectively meaningless.
    • +
  • Diagnostics’ residual risks are operational and checkable in minutes (flag coverage across replicas, + export error rate — §7 steps 2–3). The Prometheus defect is architectural: no query hygiene or dashboard fix can + recover it; only the AggregatorRegistry change (§9.1) can.
    • +
+ +

Practical guidance — which number for which job

+ + + + + + + + + + + + +
Question being answeredSource to trust today
How much traffic did this app/handler actually serve? (SLO denominators, capacity, accounting)ClickHouse, overflow bucket included — treat as a lower bound
Per-account traffic breakdownClickHouse only (the prom counter has no account label); mind the overflow cap at peak traffic
Is the pod alive / is traffic flowing at all right now?Either — Prometheus is fine for liveness and shape, just not for magnitude
Anything computed with rate()/increase() on a multi-worker appNeither — fix the export first (§9.1); until then these panels are artifacts
Ground-truth calibration of both pipelinesA workers: 1 app or router/edge logs (§7 step 4)
+ +

+The one setup where the ranking flips: workers: 1 (and linked development, where +LINKED forces a single worker). With one process there is one registry, the scraped series is monotonic, and +the prom path has no export or coverage dependency — there it is the gold standard, which is exactly what makes it the +arbitration tool in §7 step 4. confirmed live (§8) A single-worker app +(vtex.render-server, cpu limit 1) shows a provably monotonic counter — but there ClickHouse under-reports the +real 1,384-pod fleet by ~7× (coverage/pipeline loss), so for this case Prometheus is the closer-to-reality source. +

+

+This verdict is conditional on the two §7 checks passing: (a) all replicas report to ClickHouse (telemetry flag on +everywhere) and (b) export failures are rare. If step 2 shows only a fraction of pods reporting, the ClickHouse number is +still honest about what it saw — but it tracks reality only after coverage is fixed. The same reasoning applies to the +sibling instruments (runtime_http_requests_duration_milliseconds, runtime_http_response_size_bytes, +runtime_http_aborted_requests_total), which share both pipelines. +

+
+ + +

7. Verification playbook (~30 minutes)

+ +

Step 1 — prove/measure the Prometheus artifact

+
# A healthy counter under one instance label never decreases. Any non-restart resets ⇒ interleaving.
+resets(runtime_http_requests_total{app="vtex-admin-cms-graphql-rc"}[1h])
+
+# Or from inside the pod: consecutive scrapes answered by different workers show jumping values
+for i in 1 2 3 4 5 6; do
+  curl -s localhost:5000/metrics | grep 'runtime_http_requests_total{status_code="200"' | head -2
+  sleep 16   # longer than the 5s keep-alive so each request opens a new connection
+done
+

+✔ Run on 2026-07-14 against a live pod: samples decreased between scrapes (1580 → 1548), proving worker +interleaving — full arithmetic in the §3 field result. +

+ +

Step 2 — measure diagnostics coverage

+

+✔ Resolved 2026-07-14: the resource map does carry pod identity. A live row ships +host.name (= pod name), service.instance.id (= node-vtex-api-<pod> — +note: no per-worker component, confirming §4.4 from production data), plus +vtex_io.app.id, vtex_io.workspace.name/type, vendor, version, +application.id. (deployment.environment and service.version arrive as +'unknown' — their env vars aren’t set.) +

+

2a. Count pods reporting, and audit the workspace-type tagging. +Schema resolved 2026-07-14: pod identity survives only on the raw layer, +otel.otel_metrics_sum_distributed (standard OTel exporter schema, delta Value per point, +ServiceName = IO app id). The aggregated telemetry.metrics_distributed has no +ResourceAttributes column and no host.name in Attributes — beware: +uniqExact(Attributes['missing-key']) returns 1, not an error.

+
-- PREFERRED (3-day retention): the MV stores Count = sumState(1) per raw datapoint
+-- (3-metrics.sql:265), and each worker emits one delta point per active series per 60 s,
+-- so for the always-active healthcheck series: datapoints/min ÷ 4 workers ≈ pods reporting.
+SELECT toStartOfHour(TimestampTime) AS h,
+       round(sumMerge(Count) / 60 / 4, 1) AS avg_pods_reporting,
+       sumMerge(`Sum`)                    AS hc_requests
+FROM telemetry.metrics_distributed
+WHERE app = 'vtex.admin-cms-graphql-rc@1.42.0'
+  AND MetricName = 'runtime_http_requests_total'
+  AND Attributes['handler'] = 'builtin:healthcheck'
+  AND Attributes['status_code'] = '200'
+  AND TimestampTime >= now() - INTERVAL 24 HOUR
+GROUP BY h ORDER BY h;
+
+-- pods reporting per hour on the RAW layer (short retention — see caveat below)
+SELECT toStartOfHour(TimeUnix) AS h,
+       uniqExact(ResourceAttributes['host.name']) AS pods_reporting,
+       sum(Value)                                 AS requests      -- valid: delta points
+FROM otel.otel_metrics_sum_distributed
+WHERE ServiceName = 'vtex.admin-cms-graphql-rc@1.42.0'
+  AND MetricName = 'runtime_http_requests_total'
+  AND TimeUnix >= now() - INTERVAL 6 HOUR
+GROUP BY h ORDER BY h;
+
+-- pod list, to diff against kubectl
+SELECT DISTINCT ResourceAttributes['host.name'] AS pod
+FROM otel.otel_metrics_sum_distributed
+WHERE ServiceName = 'vtex.admin-cms-graphql-rc@1.42.0'
+  AND MetricName = 'runtime_http_requests_total'
+  AND TimeUnix >= now() - INTERVAL 1 HOUR
+ORDER BY pod;
+
+-- ⚠ observed on one app: workspace.name='master' with workspace.type='development'.
+-- The SDK sets workspace.type from VTEX_PRODUCTION (constants.ts:182 → telemetry/client.ts:92);
+-- if the aggregated table's 'production' column derives from it, a production='true' filter
+-- silently drops every pod where that env var is missing.
+SELECT ResourceAttributes['vtex_io.workspace.type'] AS wtype,
+       uniqExact(ResourceAttributes['host.name'])   AS pods,
+       sum(Value)                                   AS requests
+FROM otel.otel_metrics_sum_distributed
+WHERE ServiceName = 'vtex.admin-cms-graphql-rc@1.42.0'
+  AND MetricName = 'runtime_http_requests_total'
+  AND TimeUnix >= now() - INTERVAL 6 HOUR
+GROUP BY wtype;
+
+-- worker-level coverage: healthchecks keep every worker's series active, and each worker
+-- emits one delta point per active series per 60 s → points/min ≈ pods × 4 workers
+SELECT toStartOfMinute(TimeUnix) AS m,
+       count()                                    AS points,
+       uniqExact(ResourceAttributes['host.name']) AS pods
+FROM otel.otel_metrics_sum_distributed
+WHERE ServiceName = 'vtex.admin-cms-graphql-rc@1.42.0'
+  AND MetricName = 'runtime_http_requests_total'
+  AND Attributes['handler'] = 'builtin:healthcheck'
+  AND Attributes['status_code'] = '200'
+  AND TimeUnix >= now() - INTERVAL 10 MINUTE
+GROUP BY m ORDER BY m;
+
+-- pipeline-loss check: raw layer vs aggregated layer must match, minute by minute
+SELECT toStartOfMinute(TimeUnix) AS m, sum(Value) AS raw_requests
+FROM otel.otel_metrics_sum_distributed
+WHERE ServiceName = 'vtex.admin-cms-graphql-rc@1.42.0'
+  AND MetricName = 'runtime_http_requests_total'
+  AND TimeUnix >= now() - INTERVAL 15 MINUTE
+GROUP BY m ORDER BY m;
+-- compare with:  SELECT toStartOfMinute(TimestampTime), sumMerge(`Sum`) FROM telemetry.metrics_distributed WHERE app = '…' …
+

+⚠ Raw-table caveat (observed 2026-07-14, explained by the schema): the raw tables’ TTL is +toDate(TimeUnix) + toIntervalHour(6) (3-metrics.sql:81) — i.e. 06:00 of the point’s calendar +day, not a rolling 6 h, so any point written after 06:00 is born expired and survives only until the next TTL +merge sweep. That is why a 6-hour query returned a single partial hourly bucket. Run raw-layer checks over the last +10–15 minutes and compare with kubectl at the same moment — or use the Count-based query above, which has 3-day +retention. If a rolling window was intended, the TTL should be toDateTime(TimeUnix) + INTERVAL 6 HOUR +(flag to the o11y-platform team). Field result: 5 pods reporting at 20:00 (kubectl diff pending). +

+

2b. Cross-check coverage at the source — the flag and endpoint are env vars, so the +deployment spec answers the question without ClickHouse:

+
kubectl -n <ns> exec <one-pod> -- env | grep -E 'VTEX_DIAGNOSTICS_TELEMETRY_ENABLED|OTEL_EXPORTER_OTLP_ENDPOINT'
+# if these come from the deployment template, coverage is all-or-nothing per app;
+# check whether the rollout that sets them reached every app/cluster being compared
+

2c. Calibrate with the healthcheck series — probes hit every pod at a uniform rate, so +coverage ≈ ClickHouse healthchecks/min ÷ (pod count × per-pod probe rate):

+
-- diagnostics-side healthcheck volume per minute
+SELECT toStartOfMinute(TimestampTime) AS m, sumMerge(`Sum`) AS hc_per_min
+FROM telemetry.metrics_distributed
+WHERE app = 'vtex.admin-cms-graphql-rc@1.42.0'
+  AND MetricName = 'runtime_http_requests_total'
+  AND Attributes['handler'] = 'builtin:healthcheck'
+  AND production = 'true' AND workspace = 'master'
+  AND TimestampTime >= now() - INTERVAL 30 MINUTE
+GROUP BY m ORDER BY m;
+
# per-pod probe rate, measured on one pod: force Connection: close so round-robin
+# cycles through all 4 workers — the 4 distinct values summed = pod-level counter now
+for i in $(seq 1 8); do
+  curl -s -H 'Connection: close' localhost:5050/metrics \
+    | grep 'runtime_http_requests_total{handler="builtin:healthcheck",status_code="200"}'
+done | sort -u
+# repeat after 5 minutes; (sum_now − sum_before) / 5 = healthchecks/min/pod
+# coverage = hc_per_min ÷ (kubectl-pod-count × healthchecks/min/pod)
+

+Note the calibration query drops the tenant/account filters on purpose: healthcheck requests have no account +(the middleware records 'unknown'), so account-scoped filters could exclude them. +

+ +

Step 3 — measure cardinality overflow

+
-- share of traffic hidden in the overflow bucket (invisible to per-handler panels)
+SELECT toStartOfHour(TimestampTime) AS h,
+       sumMergeIf(`Sum`, Attributes['otel.metric.overflow'] = 'true') AS overflow_requests,
+       sumMerge(`Sum`)                                                AS all_requests
+FROM telemetry.metrics_distributed
+WHERE app = 'vtex.admin-cms-graphql-rc@1.42.0'
+  AND MetricName = 'runtime_http_requests_total'
+  AND TimestampTime >= now() - INTERVAL 1 DAY
+GROUP BY h ORDER BY h;
+

+✔ Run on 2026-07-14: overflow_requests = 0 for all 24 hourly buckets — cardinality overflow ruled out for +this app (see §4.2). +

+ +

Step 4 — like-for-like totals, then arbitrate with a third source

+
-- ClickHouse: total requests per minute, NO handler/status/account filters
+SELECT toStartOfMinute(TimestampTime) AS m, sumMerge(`Sum`) AS req_per_min
+FROM telemetry.metrics_distributed
+WHERE app = 'vtex.admin-cms-graphql-rc@1.42.0'
+  AND MetricName = 'runtime_http_requests_total'
+  AND TimestampTime BETWEEN {from} AND {to}
+GROUP BY m ORDER BY m;
+
+# Prometheus: same window, same scope, per minute — but remember §3 makes this number suspect
+sum(increase(runtime_http_requests_total{app="..."}[1m]))
+

+Because both sides are distorted, arbitrate with an independent count for one hour of one app: router/edge access +logs (VictoriaLogs request count for the app) or a workers: 1 test app — with one worker the Prometheus path is +trustworthy, so whatever gap remains there is pure diagnostics-side loss. +

+ + +

8. Field validation — a single-worker control (vtex.render-server)

+
+

+On 2026-07-16 the §7 playbook was run end-to-end against a second app, +vtex.render-server@8.180.1, chosen because it is provisioned at +VTEX_SELF_CPU_LIMIT = 1. Since workers = min(cpus, 4), that resolves to +a single worker per pod — the one configuration where §6 predicts multi-worker interleaving +(Mechanism #1) is absent. It is therefore a control: it lets us switch Mechanism #1 off and see what is +left. Two independent results came out of it — one clean confirmation, and one large gap that turned out to be +coverage/pipeline loss, not the app. +

+ +

Correction to an earlier draft. A first pass compared ClickHouse +(which ingests all us-east-1 IO clusters) against the pod count of a single cluster +(…-m4t, ~250 pods) and reported “~94% agreement.” That denominator was wrong. +render-server@8.180.1 actually runs across 7 clusters / 1,384 pods. Re-based on the true +fleet, ClickHouse holds only ~15% of the traffic. The lesson is itself a finding: the aggregated table has +no cluster/region column (see §7 step 2a), so it is easy to mismatch a cluster-scoped numerator with a +fleet-wide denominator.

+ +
+
Workers per pod
1
min(cpus,4), cpu limit = 1 → Mechanism #1 absent
+
Fleet
1,384
pods across 7 clusters
+
ClickHouse coverage
~15%
≈ ×7 under-count — root cause: readonly metrics tables + fire-and-forget writes
+
+ +

Prometheus side — the counter is monotonic (Mechanism #1 confirmed absent)

+

+Eight consecutive scrapes of one pod’s shared /metrics (port 5050), 16 s apart — longer than the 5 s +keep-alive, so each is a fresh connection — on +runtime_http_requests_total{handler="public-handler:render",status_code="200"}: +

+
10391  10415  10436  10439  10465  10478  10495  10526
+

+Strictly increasing, zero drops. Contrast the multi-worker node-vtex-api field result in §3 +(1580 → 1548, a decrease PromQL scores as a full-value reset). With one registry there is nothing to interleave, +so rate()/increase() over these series is trustworthy — the §6 gold standard. So whatever gap +remains for render-server is not a Prometheus artifact; it is real divergence between a correct Prometheus number +and the diagnostics pipeline. +

+ +

Diagnostics side — a ~7× under-count, calibrated with the healthcheck series

+

+Healthchecks hit every pod at a uniform rate (~30/min/pod, verified on pods in two different clusters: 30.24 in +…-m4t, 29.67 in …-k5a), so expected fleet healthchecks = pods × per-pod rate and +coverage = ClickHouse healthchecks ÷ expected (§7 step 2c). The ClickHouse figure is steady-state, not lag +(~5,100/min three hours earlier, ~5,900/min now): +

+ + + + + + + +
QuantityValue
Running pods, all clusters (kubectl: k5a 235 · p8c 207 · m4t 219 · r5p 247 · f3t 224 · s9b 227 · qua 25)1,384
Per-pod healthcheck rate (scraped, 2 clusters)~30 /min/pod
Expected fleet healthcheck~41,500 /min
ClickHouse fleet healthcheck (sumMerge(Sum), steady-state)~6,000 /min
Coverage~15% → ×7 under-count
+

+The non-healthcheck handlers the dashboard actually plots (public-handler:render/:redirect) lose +traffic through the same pipeline, so the ~7× factor applies to them too: a correct Prometheus panel summed over all 1,384 +pods sits roughly 7× above the ClickHouse total. This is the same direction as the report’s +headline (Prom > Diag) but a different mechanism — coverage/pipeline loss (§4.1, §4.3), not the +per-worker inflation of §3. +

+ +

Root cause — silent write-loss at ClickHouse confirmed in o11y-platform + live

+

+The obvious suspect — telemetry disabled on most pods (Mechanism #2) — is ruled out: on pods sampled +across five clusters VTEX_DIAGNOSTICS_TELEMETRY_ENABLED=true with a uniform OTLP endpoint +(grpc-vtex-io-o11y-platform…:3333). The collector counters are also clean — producer and consumer both report +receiver_refused = 0, send_failed = 0, no memory-limiter refusals, consumer queue depth 1/100000. +A pipeline shedding 85% would scream in those counters. It doesn’t — because the loss happens at two +fire-and-forget stages that never report failure, then reading the o11y-platform config and ClickHouse +system tables pinned the exact stage: +

+
    +
  • Consumer → ClickHouse is fire-and-forget. The consumer writes with + async_insert=1&wait_for_async_insert=0 and commits the Kafka offset + after handing off (message_marking.after=true). ClickHouse acknowledges receipt into its async + buffer before the buffer is flushed to the table, so a later flush failure is invisible to the exporter + (send_failed stays 0) and the offset is already gone — no reprocessing, permanent loss. + (consumer-metrics.yaml exporter endpoint + message_marking.)
    • +
  • The metrics tables are read-only across the cluster. + clusterAllReplicas('cluster', system.replicas) shows 10 of 12 replica instances of + otel_metrics_sum/otel_metrics_histogram with is_readonly=1 (two of them with + is_session_expired=1 — ClickHouse-Keeper session loss), spread over all 6 nodes; + otel_metrics_gauge and otel_logs are healthy. runtime_http_requests_total + is a Sum → otel_metrics_sum → affected.
    • +
  • The recorded error — the flush log carries the exact exception. 100% of the FlushErrors in the last + 3 h are TIMEOUT_EXCEEDED (code 159); zero read-only-flavored exceptions surface in the flush log + because the failure manifests as the insert timing out while cascading into the materialized views + (which is where the per-minute aggregate telemetry.metrics is populated — 3-metrics.sql).
    • +
+ +

Sample error messages (from system.asynchronous_insert_log.exception, 2026-07-16 — these are +what to chase when fixing):

+
-- otel_metrics_sum (305,419 occurrences in 8h, cluster-wide)
+Code: 159. DB::Exception: Timeout exceeded: maximum: 24000 ms:
+  while pushing to view otel.metrics_sum_view. (TIMEOUT_EXCEEDED) (version 25.7.1.3997)
+
+-- otel_metrics_histogram (294,088 occurrences)
+Code: 159. DB::Exception: Timeout exceeded: maximum: 24000 ms:
+  while pushing to view otel.metrics_histogram_view. (TIMEOUT_EXCEEDED) (version 25.7.1.3997)
+
+-- minority variant (plain flush timeout, no MV named)
+Code: 159. DB::Exception: Timeout exceeded: elapsed 30902.79 ms, maximum: 24000 ms. (TIMEOUT_EXCEEDED)
+

Reproduce with:

+
SELECT table, substring(replace(exception,'\n',' '),1,300) AS exc, count() AS n, max(event_time) AS last_seen
+FROM clusterAllReplicas('cluster', system.asynchronous_insert_log)
+WHERE database='otel' AND status='FlushError' AND event_time >= now() - INTERVAL 2 HOUR
+GROUP BY table, exc ORDER BY n DESC;
+ +

The failure rate predicts the render-server gap exactly

+

+Cluster-wide flush outcomes for otel_metrics_sum by hour — the Ok share is ~13–17% for at least +8 straight hours, which is precisely the ~15% coverage measured for render-server in the +healthcheck calibration above (×7 under-count ≈ 1/0.15): +

+ + + + + + + + + + + +
Hour (2026-07-16)OkFlushErrorError %
06:002,97128,56390.6
07:0044,823301,92687.1
08:0046,536306,64586.8
09:0044,445327,60988.1
10:0070,235345,76783.1
11:0082,495404,23483.1
12:00105,065464,93281.6
13:00105,948538,90783.6
14:0096,541520,22884.3
+

+Cross-check passed: average flush success ≈ 15% ⇔ measured ClickHouse coverage ≈ 15% ⇔ observed ×7 +gap. The render-server scenario is fully explained by this failure, with no residual unexplained loss. (Earlier +single-node reads of these tables understated the picture — system.* tables are per-node; always query via +clusterAllReplicas.) +

+ +

Anatomy of the silent failure — why "OK" is returned before the data is stored

+

+The crucial detail is ordering: the failure does not happen when the insert “hits” a readonly replica — +ClickHouse does not check replica writability when accepting rows into the async-insert buffer. The acknowledgment fires +before the step that fails: +

+
+
Kafka consumer issues INSERT → LB (clickhouse-…-ch service) picks 1 of 6 nodes round-robin + consumer-metrics.yaml · exporter endpoint
+
↓
+
Async-insert buffer accepts the rows → “OK” is returned here. + With wait_for_async_insert=0, “OK” means buffered, not stored — even on a node whose + replica has been readonly for months.
+
↓  both durability signals fire NOW, before the write is attempted:
+
otelcol_exporter_sent_metric_points++ ✅  ·  Kafka offset committed ✅ + message_marking.after=true — the data can no longer be reprocessed
+
↓  ~200 ms later, server-side background flush
+
Real INSERT into otel_metrics_sum (+ MV push to telemetry.metrics). + On a readonly replica: commitPart → error 242 “Table is in readonly mode” → retried 20× with + backoff → burns the 24 s budget → FlushError (TIMEOUT_EXCEEDED) + text_log: ZooKeeperRetriesControl: commitPart: will retry due to error … retry_count=N/20
+
↓
+
Rows discarded — permanently. The failure is recorded only in + system.asynchronous_insert_log and the server text_log. Upstream, everything reads as success: + send_failed = 0, queue empty, offsets advancing.
+
+

+This ordering is the entire incident in miniature: with wait_for_async_insert=1, the very same error 242 would +travel back through the INSERT call → the exporter would see a real failure → its retry (already enabled, 120 s +budget) would re-send — likely landing on the writable node via the LB — and on exhaustion the Kafka offset would +not be committed, so the data would be redelivered instead of forgotten. One query-string flag separates +“self-healing” from “silent 85% loss”. (Note the measured loss is ~85%, not exactly 5/6 ≈ 83%: during the storm, +flushes on the writable node also partially failed, since one replica absorbed the whole cluster’s writes plus +the retry traffic.) +

+ +

+So the gap is not app-side coverage and not per-worker inflation: it is a +Keeper-session/read-only incident on the replicated metrics tables, turned into permanent data loss by a +fire-and-forget write path. The upstream producer adds a second latent instance of the same anti-pattern — Kafka +required_acks: 0 with retry_on_failure: false (producer.yaml) — where broker-side loss +would likewise never be counted. Both are invisible by construction, which is why the earlier “counters look clean” reading +was misleading. +

+ +

What this does to the §6 verdict

+

+It sharpens it rather than contradicting it. §6 already carves out workers: 1 as the case +where Prometheus is the gold standard; render-server is exactly that case, and here Prometheus is the +closer-to-reality source while ClickHouse under-reports ~7×. The general claim “diagnostics is the floor” still +holds — ClickHouse never invented traffic, it lost it — but this shows the floor can sit far below reality when +the pipeline drops data, so “ClickHouse is closer to reality” is only safe after a coverage check like this one. +For multi-worker apps both effects stack: Prometheus inflates (§3) and ClickHouse under-counts. +

+ +

+Method: clickhouse-client → telemetry.metrics_distributed (read-api user, obs-cluster +port-forward) for the diagnostics side; kubectl port-forward to live 8.180.1 pods’ /metrics:5050 +for the Prometheus side (port 5000 serves the Go process runtime metrics). Single-worker confirmed from the pod spec +(VTEX_SELF_CPU_LIMIT=1) and the monotonic counter. Like-for-like scope note: the render-server panel query +handler!~"builtin:.*|undefined" already excludes healthchecks and undefined, so the matching +ClickHouse query keeps None/public-handler:render/public-handler:redirect and drops +builtin:healthcheck. +

+
+ + +

9. Recommendations

+
+
    +
  1. Fix the Prometheus export (root cause #1): aggregate across workers with prom-client’s + AggregatorRegistry — workers push to the master over the existing cluster IPC, the master serves a single + merged, monotonic /metrics. Until then, treat PromQL over these counters as unreliable for + workers > 1.
    2. +
  2. Make worker identity explicit in diagnostics: add a per-process component + (cluster.worker.id or PID) to service.instance.id / resource attributes in + @vtex/diagnostics-nodejs. ClickHouse tolerates the collision today; nothing else will.
    3. +
  3. Control the cardinality budget: either raise aggregationCardinalityLimit deliberately via a + View for the request instruments, or move vtex.account.name off the hot counter (log-based accounting, or a + bounded top-N attribute). Alert on otel.metric.overflow="true" volume so silent truncation becomes visible.
    4. +
  4. Track fleet delta-adoption: the collectors drop all non-delta datapoints + (filter/temporality), so every app on a pre-65e50da7 @vtex/api is invisible in + diagnostics. Publish the list of apps present in telemetry.metrics vs. apps serving traffic, and drive + upgrades — until then, cross-app diagnostics dashboards under-report by construction. Also fix the raw tables’ TTL + expression (toDate(TimeUnix) + 6h → rolling window) if raw-layer debugging is meant to be possible.
    5. +
  5. Watch delta export health: surface exporter failures (SDK diag logs) as a metric/alert; with delta + temporality every failure is permanent data loss.
    6. +
  6. Close the fire-and-forget write path (root cause of the §8 gap): the metrics consumer writes with + async_insert=1&wait_for_async_insert=0 and commits Kafka offsets after hand-off + (message_marking.after=true), so any ClickHouse flush failure is silent and permanent. Set + wait_for_async_insert=1 (or only commit offsets after a durable insert) so failures surface in + otelcol_exporter_send_failed_metric_points and get retried/reprocessed. Likewise reconsider producer Kafka + required_acks: 0 + retry_on_failure: false. Alert on system.replicas.is_readonly + and asynchronous_insert_log FlushError rate for otel_metrics_sum/histogram + — a Keeper-session/read-only incident there currently drops 100% of Sum/Histogram inserts while gauges and logs are fine.
    7. +
  7. Standardize the comparison: a shared dashboard with per-minute buckets, identical scope + (app version, workspace, production) and identical handler exclusions on both sides — including the overflow bucket in + the ClickHouse total.
    8. +
+ +

9.1a — ClickHouse remediation runbook for the 2026-07-16 incident diagnosis verified live

+

Verified failure topology (2026-07-16, clusterAllReplicas): the MV target +telemetry.metrics is healthy on all 6 nodes; the raw tables are read-only on 10 of 12 replica +instances, leaving exactly one writable replica per table cluster-wide +(otel_metrics_sum: only 0-2-0; otel_metrics_histogram: only 1-2-0). +Every readonly replica shows absolute_delay ≈ epoch (never re-attached since the cluster restart ~5.7 days +ago), while node-level Keeper sessions are healthy and the table znodes are intact +(/clickhouse/tables/{shard}/otel/otel_metrics_sum/replicas lists all 3 replicas). Mechanics of the errors:

+
    +
  • Inserts hitting a readonly node fail instantly → the TABLE_IS_READ_ONLY ≈ 1.94M in system.errors; + the collector’s retry eventually lands on the single writable replica.
    • +
  • That one node absorbs the entire cluster’s metrics insert load; the MV’s heavy per-insert + GROUP BY+mapFilter+sumState then exceeds the 24 s flush budget → the + Timeout exceeded … while pushing to view otel.metrics_sum_view FlushErrors (~85%).
    • +
  • Side effect: readonly replicas can’t merge, so TTL cleanup stopped — e.g. 845M stale rows parked in + otel_metrics_sum on 0-0-0/0-1-0 vs ~552k on the healthy replica.
    • +
+ + +

Baseline snapshots — captured 2026-07-16, before remediation

+
+ Grafana panel: HTTP Requests Total per Handler for vtex.render-server@8.180.1, last hour. The 200/public-handler:render series swings wildly between roughly 5K and 53K req/m instead of a stable rate. +
+ Diagnostics dashboard during the incident — “HTTP Requests Total per Handler” + (vtex.render-server@8.180.1, last hour). The ClickHouse-fed series swings ~5K–53K req/m minute-to-minute: + the visible average is the ~15% of flushes that survive (§8), and the jitter is flush success coming and going in + bursts — not real traffic shape. Expected steady total after the fix: ~25–30K req/m for the 200/render series alone. +
+
+
+ ClickHouse query UI: clusterAllReplicas query over system.replicas listing otel_metrics tables; histogram and sum rows show is_readonly=1 with absolute_delay 1784215619 highlighted, gauge rows healthy. +
+ Pre-remediation replica state — the §9.1a Step 2 verification query, run against + clickhouse-vtex-io.vtex.systems: all otel_metrics_gauge replicas healthy, while + otel_metrics_histogram and otel_metrics_sum show 10× is_readonly=1 with + absolute_delay = 1784215619 (≈ epoch “now” — never synced). This is the baseline the recreate + procedure (Step 1b) must clear: the same query should return is_readonly=0, absolute_delay≈0 + on all 18 rows. +
+
+ +
+ ClickHouse UI: 36-row replica health matrix from clusterAllReplicas over system.replicas with derived status column. otel_logs, otel_metrics_gauge, telemetry.logs and telemetry.metrics replicas all show running; otel_metrics_histogram and otel_metrics_sum show five readonly replicas each (init failed or session expired) with delay 1784216763, one running replica per table. +
+ Full replica-health matrix, pre-remediation — the health query with derived + status verdict, run in the ClickHouse UI (36 rows, all replicated tables). Healthy across the board + (otel_logs, otel_metrics_gauge, telemetry.logs, telemetry.metrics: + 6/6 running) — except the two victim tables: otel_metrics_histogram running only on + …1-2-0, otel_metrics_sum only on …0-2-0, each with 5 replicas readonly + (mix of init failed = intersecting parts, and session expired = never re-attached), + delay_s = 1784216763 (≈ epoch “now”, i.e. never synced). Success criterion after Step 1b: all 36 rows + running. +
+
+ + +

Step 1 — restore write capacity. tried 2026-07-16 15:11 — insufficient +The first attempt was SYSTEM RESTART REPLICA on each readonly node:

+
SYSTEM RESTART REPLICA otel.otel_metrics_sum;
+SYSTEM RESTART REPLICA otel.otel_metrics_histogram;
+

Validation showed it does not stick: the commands completed cleanly (system.query_log: +QueryFinish, no exception) but the replicas re-entered readonly immediately. The attach thread logs the real +blocker — intersecting data parts, i.e. local part corruption that predates the incident by months:

+
-- text_log, chi-…-1-0-0, 15:11:04 (otel_metrics_sum — partition 2026-03-06!)
+Initialization failed, table will remain readonly. Error: Code: 49. DB::Exception:
+Part 20260306_693980_694637_21 intersects part 20260306_693981_694478_67.
+It is a bug or a result of manual intervention in the ZooKeeper data. (LOGICAL_ERROR)
+
+-- text_log, chi-…-0-2-0, 15:13:00 (otel_metrics_histogram — partition 2026-04-17)
+Part 20260417_189038_288174_35 intersects part 20260417_275192_276314_212.
+

The partition names (March/April 2026) prove these replicas have been broken — and not merging/TTL-cleaning — for +months; the 845M stale rows are the debris. SYSTEM RESTORE REPLICA does not apply (Keeper metadata is intact); +detaching intersecting parts one-by-one is impractical (2,079 “unexpected parts” on one replica alone).

+ +

Step 1b — recreate each broken replica (deterministic, and cheap: the raw tables hold only ~6 h by +design — the durable store is telemetry.metrics, which is healthy). One replica at a time:

+
-- 0. capture the authoritative DDL once, from a healthy node:
+SHOW CREATE TABLE otel.otel_metrics_sum;   -- uses {shard}/{replica} macros
+
+-- 1. on the BROKEN node: drop local data + this replica's znode
+DROP TABLE otel.otel_metrics_sum SYNC;
+
+--    (only if the znode survives the drop, clean it from a healthy node:)
+SYSTEM DROP REPLICA 'chi-clickhouse-vtex-io-ch-cluster-1-0' FROM TABLE otel.otel_metrics_sum;
+
+-- 2. on the BROKEN node: recreate with the captured DDL — WITHOUT "ON CLUSTER"
+CREATE TABLE otel.otel_metrics_sum ( … ) ENGINE = ReplicatedMergeTree( … ) … ;
+--    macros resolve per node → registers as a fresh replica → fetches only the recent ~6h
+
+-- 3. verify before moving to the next replica:
+SELECT is_readonly, absolute_delay FROM system.replicas WHERE table='otel_metrics_sum';
+

Notes: keep the currently-writable replica (0-2-0 for sum, 1-2-0 for histogram) untouched until +last; the MV dependency survives the recreate (it binds by name); expect the recreated replica to start near-empty — that +is correct for a 6 h-TTL raw table.

+ +

Step 2 — verify recovery (should show 12/12 writable, then FlushError → ~0 within minutes). Also watch +for the Keeper ensemble health — during the incident all three Keeper nodes showed degraded latency +(avg ~270–300 ms, max 7–14 s vs the ~1 ms norm), consistent with the insert retry storms; it should normalize once +inserts stop hammering readonly replicas:

+
-- replica-health matrix with verdict (the query shown in the baseline screenshot)
+SELECT hostName() AS host, database, table, is_readonly, is_session_expired,
+       active_replicas, total_replicas,
+       if(absolute_delay > 4e9, 'never', toString(absolute_delay)) AS delay_s,
+       queue_size,
+       multiIf(is_readonly = 0 AND absolute_delay < 60, 'running',
+               is_readonly = 0,                         'attached, lagging',
+               is_session_expired = 1,                  'readonly (session expired)',
+                                                        'readonly (init failed)') AS status
+FROM clusterAllReplicas('cluster', system.replicas)
+ORDER BY database, table, host;
+
+-- one-line summary per table — watch during the procedure (goal: readonly = 0 everywhere)
+SELECT database, table, countIf(is_readonly = 0) AS running, countIf(is_readonly = 1) AS readonly
+FROM clusterAllReplicas('cluster', system.replicas)
+GROUP BY database, table ORDER BY readonly DESC;
+
+SELECT toStartOfFiveMinutes(event_time) b, status, count()
+FROM clusterAllReplicas('cluster', system.asynchronous_insert_log)
+WHERE database='otel' AND table='otel_metrics_sum' AND event_time > now() - INTERVAL 30 MINUTE
+GROUP BY b, status ORDER BY b;
+

Expect merges/TTL to resume on the recovered replicas (the 845M stale raw rows should drain), and diagnostics coverage +to climb from ~15% back toward ~100% — re-run the §8 healthcheck calibration to confirm +(expected fleet hc/min ≈ pods × 30).

+ +

Step 3 — stop the silent-loss pattern (config, o11y-platform repo):

+
# provisioning/vtex-io/collectors/consumer-metrics.yaml — clickhouse exporter endpoint
+-  …&async_insert=1&wait_for_async_insert=0&async_insert_busy_timeout_ms=200
++  …&async_insert=1&wait_for_async_insert=1&async_insert_busy_timeout_ms=200
+#  → flush failures now fail the INSERT → exporter retries (already enabled) → Kafka offset
+#    NOT committed (message_marking.on_error=false) → data reprocessed instead of lost.
+#    Consider timeout: 20s → 35s so the exporter outlives the 24s MV-push budget.
+
+# provisioning/vtex-io/collectors/producer.yaml — kafka/metrics exporter
+-  producer: { required_acks: 0 }   retry_on_failure: { enabled: false }
++  producer: { required_acks: 1 }   retry_on_failure: { enabled: true }
+ +

Step 4 — alerts so this cannot run silent for 8 hours again:

+
    +
  • max(is_readonly) over clusterAllReplicas('cluster', system.replicas) > 0 for 5 min → page.
    • +
  • FlushError / (Ok+FlushError) from system.asynchronous_insert_log (metrics tables) > 1% for 15 min → page.
    • +
  • absolute_delay > 300 s on any otel replica → warn.
    • +
  • Watch the MV-push duration headroom: if Timeout exceeded … pushing to view reappears with all replicas + writable, the MV itself is the bottleneck — then consider parallel_view_processing=1 for the insert user, + a larger flush budget, or trimming the MV’s mapFilter/GROUP BY width.
    • +
+
+ + +

Appendix — evidence index

+ + + + + + + + + + + + + + + + + + + + + + + + + + +
FactWhere
Both middlewares mounted adjacently; increments in finally, once per requestsrc/service/worker/index.ts:228–229 · requestMetricsMiddleware.ts:43 · otelRequestMetricsMiddleware.ts:64
Master forks min(cpus, 4) workers sharing port 5000; no cross-worker registry aggregationsrc/service/master.ts:89 · src/service/loaders.ts:19–28 · src/constants.ts:164 · src/service/index.ts:31
/metrics serves the per-process default prom-client registrysrc/service/worker/runtime/builtIn/middlewares.ts:24–44
OTel exporter: OTLP gRPC, delta temporality, 60 s interval/timeoutsrc/service/telemetry/client.ts:61–69 · @vtex/diagnostics-nodejs dist/exporters/otlp.js:51–72
Default cardinality limit 2000 with otel.metric.overflow fold-in@opentelemetry/sdk-metrics@1.30.1 build/src/state/DeltaMetricProcessor.js:35–45
service.instance.id has no per-worker component@vtex/diagnostics-nodejs dist/discovery/resource-discovery.js:167–179
No-op client when telemetry flag is off; 500 ms instrument race skips countingsrc/service/telemetry/client.ts:95 · src/service/metrics/otelRequestMetricsMiddleware.ts:6,29–34
Account attribute only on the OTel counter, not the prom counterotelRequestMetricsMiddleware.ts:69 vs tracing/metrics/MetricNames.ts:30–35
Timeline: interval bump / account attribute / delta switchcommits d122a999 (2025-12-04) · 3f65ab73 (2025-12-16) · 65e50da7 (2025-12-16)
ClickHouse schema: raw OTel tables (TTL toDate(TimeUnix)+6h), per-minute MV, + production derived from workspace.type, Count = sumState(1) per datapoint, + Attributes passed through minus device/process.pido11y-platform read-api/clickhouse-sql/schemas/3-metrics.sql:81,229–279
Collectors drop all non-delta datapoints (no cumulativetodelta in pipeline); aggressive consumer + memory_limitero11y-platform provisioning/vtex-io/collectors/producer.yaml:221,263 · + consumer-metrics.yaml:234,323–332
Field validation (§8): single-worker app (VTEX_SELF_CPU_LIMIT=1 ⇒ 1 worker) has a monotonic + /metrics counter (Mechanism #1 absent) yet ClickHouse under-reports the 1,384-pod / 7-cluster fleet + ~7× via healthcheck calibration (~30/min/pod × 1,384 ≈ 41.5k/min expected vs ~6k/min in ClickHouse); telemetry flag + on and OTLP endpoint uniform across clusters → loss is downstream. Root-caused: otel_metrics_sum/ + otel_metrics_histogram replicas is_readonly=1/session_expired (0 active replicas) + and consumer writes fire-and-forget (wait_for_async_insert=0, offset committed on hand-off) → 100% + metrics FlushError in system.asynchronous_insert_log (last 3h, 544,705 attempts), silent to collector countersvtex.render-server@8.180.1 · pods /metrics:5050 (7 iostore clusters, us-east-1) · + telemetry.metrics_distributed (read-api) (2026-07-16)
+ +

+Generated as part of the metrics-discrepancy investigation on the node-vtex-api repository. +The §3 chart uses synthetic data (parameters stated inline) to illustrate a mechanism verified in code; all +production-magnitude claims are marked “needs data check” with the exact query to run. +

+ +
+ + diff --git a/src/service/master.ts b/src/service/master.ts index 84f7f6603..2e21c891d 100644 --- a/src/service/master.ts +++ b/src/service/master.ts @@ -3,6 +3,12 @@ import { constants } from 'os' import { INSPECT_DEBUGGER_PORT, LINKED, UP_SIGNAL } from '../constants' import { isLog, logOnceToDevConsole } from './logger' +import { + handleWorkerMetricsRequest, + initMasterAggregatorRegistry, + isAggMetricsRequest, + isPromClientMessage, +} from './metrics/clusterMetricsAggregator' import { logger } from './worker/listeners' import { broadcastStatusTrack, isStatusTrackBroadcast, trackStatus } from './worker/runtime/statusTrack' import { ServiceJSON } from './worker/runtime/typings' @@ -15,6 +21,10 @@ const onMessage = (worker: Worker, message: any) => { } else if (isStatusTrackBroadcast(message)) { trackStatus() broadcastStatusTrack() + } else if (isAggMetricsRequest(message)) { + handleWorkerMetricsRequest(worker, message) + } else if (isPromClientMessage(message)) { + // Handled by prom-client's own cluster listener; ignore here. } else { logger.warn({ content: message, @@ -77,6 +87,12 @@ export const startMaster = (service: ServiceJSON) => { process.env.DETERMINISTIC_VARY = 'true' } + // Set up the master-side Prometheus aggregator so workers can request a + // merged, monotonic /metrics view across the whole cluster over IPC. + if (numWorkers > 1) { + initMasterAggregatorRegistry() + } + // Setup dubugger if (LINKED) { cluster.setupMaster({ inspectPort: INSPECT_DEBUGGER_PORT }) diff --git a/src/service/metrics/__tests__/clusterMetricsAggregator.test.ts b/src/service/metrics/__tests__/clusterMetricsAggregator.test.ts new file mode 100644 index 000000000..4cf1cf792 --- /dev/null +++ b/src/service/metrics/__tests__/clusterMetricsAggregator.test.ts @@ -0,0 +1,199 @@ +import { AggregatorRegistry, Counter, Registry } from 'prom-client' + +import { + __resetForTests, + AGG_METRICS_REQ, + AGG_METRICS_RES, + AggMetricsResMessage, + handleMasterMetricsResponse, + handleWorkerMetricsRequest, + isAggMetricsRequest, + isAggMetricsResponse, + isPromClientMessage, + requestAggregatedMetrics, +} from '../clusterMetricsAggregator' + +const REQUESTS_TOTAL = { + help: 'The total number of HTTP requests.', + labelNames: ['status_code', 'handler'], + name: 'runtime_http_requests_total', +} + +// Build an isolated registry that mimics one worker's default registry with a +// runtime_http_requests_total counter incremented `count` times. +const buildWorkerRegistry = (count: number, labels = { handler: 'render', status_code: '200' }) => { + const registry = new Registry() + const counter = new Counter({ ...REQUESTS_TOTAL, registers: [registry] }) + for (let i = 0; i < count; i++) { + counter.inc(labels) + } + return registry +} + +// Parse `runtime_http_requests_total{...} ` samples out of exposition text. +const parseSeries = (text: string, metric: string): Record => { + const out: Record = {} + text + .split('\n') + .filter((line) => line.startsWith(metric) && !line.startsWith('# ')) + .forEach((line) => { + const match = line.match(/^(\S+)\s+([\d.eE+-]+)$/) + if (match) { + out[match[1]] = Number(match[2]) + } + }) + return out +} + +const aggregateRegistries = async (registries: Array): Promise => { + const jsons = await Promise.all(registries.map((r) => r.getMetricsAsJSON())) + const merged = AggregatorRegistry.aggregate(jsons) + return merged.metrics() +} + +describe('clusterMetricsAggregator', () => { + afterEach(() => { + __resetForTests() + jest.useRealTimers() + delete (process as any).send + }) + + describe('message guards', () => { + it('recognizes aggregate request/response and prom-client messages', () => { + expect(isAggMetricsRequest({ id: 1, type: AGG_METRICS_REQ })).toBe(true) + expect(isAggMetricsRequest({ type: AGG_METRICS_REQ })).toBe(false) + expect(isAggMetricsResponse({ body: 'x', id: 1, type: AGG_METRICS_RES })).toBe(true) + expect(isAggMetricsResponse('UP')).toBe(false) + expect(isPromClientMessage({ type: 'prom-client:getMetricsReq' })).toBe(true) + expect(isPromClientMessage({ type: 'prom-client:getMetricsRes' })).toBe(true) + expect(isPromClientMessage('UP')).toBe(false) + expect(isPromClientMessage({ statusTrack: true })).toBe(false) + }) + }) + + describe('aggregation across workers', () => { + // AC2: a counter incremented once per worker in N workers reports N. + it('sums a series across N workers', async () => { + const N = 4 + const registries = Array.from({ length: N }, () => buildWorkerRegistry(1)) + const output = await aggregateRegistries(registries) + const series = parseSeries(output, 'runtime_http_requests_total') + const key = Object.keys(series).find((k) => k.includes('runtime_http_requests_total'))! + expect(series[key]).toBe(N) + }) + + it('sums differing per-worker counts', async () => { + const registries = [buildWorkerRegistry(5), buildWorkerRegistry(10), buildWorkerRegistry(2), buildWorkerRegistry(8)] + const output = await aggregateRegistries(registries) + const series = parseSeries(output, 'runtime_http_requests_total') + const key = Object.keys(series).find((k) => k.includes('runtime_http_requests_total'))! + expect(series[key]).toBe(25) + }) + + it('preserves and sums distinct label sets from different workers', async () => { + const registries = [ + buildWorkerRegistry(3, { handler: 'render', status_code: '200' }), + buildWorkerRegistry(4, { handler: 'render', status_code: '500' }), + buildWorkerRegistry(1, { handler: 'render', status_code: '200' }), + ] + const output = await aggregateRegistries(registries) + const series = parseSeries(output, 'runtime_http_requests_total') + const ok = Object.keys(series).find((k) => k.includes('status_code="200"'))! + const err = Object.keys(series).find((k) => k.includes('status_code="500"'))! + expect(series[ok]).toBe(4) + expect(series[err]).toBe(4) + }) + + // AC1: two consecutive scrapes never show a decreasing value, regardless of + // which worker answers (the merge is the same aggregate either way). + it('never decreases across two consecutive scrapes', async () => { + const workerCounts = [5, 10, 2, 8] + const registriesScrape1 = workerCounts.map((c) => buildWorkerRegistry(c)) + const scrape1 = parseSeries(await aggregateRegistries(registriesScrape1), 'runtime_http_requests_total') + + // Between scrapes each worker serves more traffic; counters only grow. + const registriesScrape2 = workerCounts.map((c, i) => buildWorkerRegistry(c + i + 1)) + const scrape2 = parseSeries(await aggregateRegistries(registriesScrape2), 'runtime_http_requests_total') + + Object.keys(scrape1).forEach((key) => { + expect(scrape2[key]).toBeGreaterThanOrEqual(scrape1[key]) + }) + }) + + // AC4: default process metrics remain present in the aggregated output. + it('includes default process metrics collected per worker', async () => { + const registryWithDefaults = new Registry() + // Emulate a default metric present in a worker registry. + const cpu = new Counter({ + help: 'Total user and system CPU time spent in seconds.', + name: 'process_cpu_seconds_total', + registers: [registryWithDefaults], + }) + cpu.inc(1) + const output = await aggregateRegistries([registryWithDefaults, buildWorkerRegistry(1)]) + expect(output).toContain('process_cpu_seconds_total') + }) + }) + + describe('worker IPC request/response', () => { + it('sends AGG_METRICS_REQ and resolves with the master body', async () => { + const sent: any[] = [] + ;(process as any).send = (msg: any) => sent.push(msg) + + const promise = requestAggregatedMetrics() + + expect(sent).toHaveLength(1) + expect(sent[0].type).toBe(AGG_METRICS_REQ) + const { id } = sent[0] + + handleMasterMetricsResponse({ body: 'AGGREGATED_BODY', id, type: AGG_METRICS_RES }) + await expect(promise).resolves.toBe('AGGREGATED_BODY') + }) + + it('falls back to the local registry on timeout', async () => { + jest.useFakeTimers() + ;(process as any).send = () => undefined + + const promise = requestAggregatedMetrics() + jest.advanceTimersByTime(6000) + const body = await promise + // Local register.metrics() output; just assert it is a (possibly empty) string. + expect(typeof body).toBe('string') + }) + + it('falls back to the local registry when the master replies with an error', async () => { + const sent: any[] = [] + ;(process as any).send = (msg: any) => sent.push(msg) + + const promise = requestAggregatedMetrics() + const { id } = sent[0] + const errorMsg: AggMetricsResMessage = { error: 'boom', id, type: AGG_METRICS_RES } + handleMasterMetricsResponse(errorMsg) + const body = await promise + expect(typeof body).toBe('string') + }) + + it('ignores responses with unknown correlation ids', () => { + expect(() => handleMasterMetricsResponse({ body: 'x', id: 9999, type: AGG_METRICS_RES })).not.toThrow() + }) + + it('serves local metrics when process.send is unavailable', async () => { + delete (process as any).send + const body = await requestAggregatedMetrics() + expect(typeof body).toBe('string') + }) + }) + + describe('master request handler', () => { + it('replies to the requesting worker with a body', async () => { + const worker: any = { send: jest.fn() } + await handleWorkerMetricsRequest(worker, { id: 7, type: AGG_METRICS_REQ }) + expect(worker.send).toHaveBeenCalledTimes(1) + const reply = worker.send.mock.calls[0][0] + expect(reply.type).toBe(AGG_METRICS_RES) + expect(reply.id).toBe(7) + // No cluster workers in the test process → prom-client aggregates to ''. + expect(typeof reply.body).toBe('string') + }) + }) +}) diff --git a/src/service/metrics/clusterMetricsAggregator.ts b/src/service/metrics/clusterMetricsAggregator.ts new file mode 100644 index 000000000..f0ea0528b --- /dev/null +++ b/src/service/metrics/clusterMetricsAggregator.ts @@ -0,0 +1,194 @@ +import { Worker } from 'cluster' +import { AggregatorRegistry, register } from 'prom-client' + +import { logger } from '../worker/listeners' + +/** + * Cluster-wide Prometheus metrics aggregation. + * + * In multi-worker mode each cluster worker keeps its own prom-client default + * registry. Serving `/metrics` from a single (round-robin selected) worker + * therefore exposes only that worker's local counters, which makes Prometheus + * treat the per-scrape braid of independent counters as counter resets and + * inflates `rate()`/`increase()` by orders of magnitude. + * + * This module uses prom-client's `AggregatorRegistry` cluster IPC protocol so + * that the worker answering a scrape asks the master for a merged, monotonic + * view built from every worker's registry in one pass (no double-counting of + * the answering worker). + */ + +/** Tagged IPC message: worker -> master, "please build the cluster aggregate". */ +export const AGG_METRICS_REQ = 'vtex-api:aggMetricsReq' +/** Tagged IPC message: master -> worker, carries the aggregate (or an error). */ +export const AGG_METRICS_RES = 'vtex-api:aggMetricsRes' + +/** + * Upper bound for a worker waiting on the master aggregate. prom-client's own + * `clusterMetrics()` has a 5s timeout collecting worker registries; we guard + * slightly above that and fall back to the local registry on expiry so that + * `/metrics` never hangs or returns empty. + */ +const AGG_METRICS_TIMEOUT_MS = 6000 + +export interface AggMetricsReqMessage { + type: typeof AGG_METRICS_REQ + id: number +} + +export interface AggMetricsResMessage { + type: typeof AGG_METRICS_RES + id: number + body?: string + error?: string +} + +export const isAggMetricsRequest = (message: any): message is AggMetricsReqMessage => + message != null && message.type === AGG_METRICS_REQ && typeof message.id === 'number' + +export const isAggMetricsResponse = (message: any): message is AggMetricsResMessage => + message != null && message.type === AGG_METRICS_RES && typeof message.id === 'number' + +/** + * prom-client's cluster protocol emits its own tagged IPC messages + * (`prom-client:getMetricsReq` / `prom-client:getMetricsRes`). They are handled + * by prom-client's own cluster listeners, so our `onMessage` handlers must + * ignore them instead of warning about "unknown" messages. + */ +export const isPromClientMessage = (message: any): boolean => + message != null && typeof message.type === 'string' && message.type.startsWith('prom-client:') + +// --------------------------------------------------------------------------- +// Master side +// --------------------------------------------------------------------------- + +let masterAggregatorRegistry: AggregatorRegistry | undefined + +/** + * Constructs the master-side `AggregatorRegistry` (idempotent). Its constructor + * installs prom-client's master `cluster.on('message')` collector, which is + * what makes `clusterMetrics()` work. Must be called in the master before any + * worker can answer a scrape. + */ +export const initMasterAggregatorRegistry = (): AggregatorRegistry => { + if (!masterAggregatorRegistry) { + masterAggregatorRegistry = new AggregatorRegistry() + } + return masterAggregatorRegistry +} + +/** + * Handles an `AGG_METRICS_REQ` from a worker: builds the cluster aggregate and + * replies to that worker only. prom-client fans the request out to *all* + * connected workers (including the requester), so the requester is one of the N + * merged sources and is never double-counted. + */ +export const handleWorkerMetricsRequest = async (worker: Worker, message: AggMetricsReqMessage): Promise => { + const aggregator = initMasterAggregatorRegistry() + try { + const body = await aggregator.clusterMetrics() + worker.send({ type: AGG_METRICS_RES, id: message.id, body }) + } catch (err) { + worker.send({ type: AGG_METRICS_RES, id: message.id, error: (err as Error)?.message ?? String(err) }) + } +} + +// --------------------------------------------------------------------------- +// Worker side +// --------------------------------------------------------------------------- + +let workerAggregatorRegistry: AggregatorRegistry | undefined + +interface PendingRequest { + resolve: (body: string) => void + timer: NodeJS.Timeout +} + +const pendingRequests = new Map() +let requestCounter = 0 + +/** + * Constructs the worker-side `AggregatorRegistry` (idempotent). Its constructor + * installs prom-client's worker `process.on('message')` responder that answers + * the master's `getMetricsReq` with this worker's registry JSON. + */ +export const ensureWorkerAggregatorRegistry = (): AggregatorRegistry => { + if (!workerAggregatorRegistry) { + workerAggregatorRegistry = new AggregatorRegistry() + } + return workerAggregatorRegistry +} + +/** + * Requests the cluster aggregate from the master over IPC and resolves with the + * merged exposition string. On timeout or any error it falls back to this + * worker's local `register.metrics()` so `/metrics` always answers promptly. + */ +export const requestAggregatedMetrics = async (): Promise => { + if (typeof process.send !== 'function') { + return register.metrics() + } + + const id = requestCounter++ + + return new Promise((resolve) => { + const timer = setTimeout(() => { + pendingRequests.delete(id) + logger.warn({ + message: 'Timed out waiting for aggregated cluster metrics; falling back to local registry', + pid: process.pid, + }) + register.metrics().then(resolve).catch(() => resolve('')) + }, AGG_METRICS_TIMEOUT_MS) + + pendingRequests.set(id, { resolve, timer }) + + try { + process.send!({ type: AGG_METRICS_REQ, id }) + } catch (err) { + clearTimeout(timer) + pendingRequests.delete(id) + logger.warn({ + content: (err as Error)?.message ?? String(err), + message: 'Failed to request aggregated cluster metrics; falling back to local registry', + pid: process.pid, + }) + register.metrics().then(resolve).catch(() => resolve('')) + } + }) +} + +/** + * Resolves the pending `requestAggregatedMetrics` promise correlated by id when + * the master replies. On error it falls back to the local registry. + */ +export const handleMasterMetricsResponse = (message: AggMetricsResMessage): void => { + const pending = pendingRequests.get(message.id) + if (!pending) { + return + } + + pendingRequests.delete(message.id) + clearTimeout(pending.timer) + + if (message.error != null || message.body == null) { + logger.warn({ + content: message.error, + message: 'Master failed to aggregate cluster metrics; falling back to local registry', + pid: process.pid, + }) + register.metrics().then(pending.resolve).catch(() => pending.resolve('')) + return + } + + pending.resolve(message.body) +} + +/** Test-only helper to reset module state between test cases. */ +export const __resetForTests = () => { + masterAggregatorRegistry = undefined + workerAggregatorRegistry = undefined + pendingRequests.forEach((p) => clearTimeout(p.timer)) + pendingRequests.clear() + requestCounter = 0 +} diff --git a/src/service/worker/index.ts b/src/service/worker/index.ts index 7fd861dbf..1de57eff9 100644 --- a/src/service/worker/index.ts +++ b/src/service/worker/index.ts @@ -13,6 +13,12 @@ import { MetricsAccumulator } from '../../metrics/MetricsAccumulator' import { getService } from '../loaders' import { logOnceToDevConsole } from '../logger/console' import { LogLevel } from '../logger/loggerTypes' +import { + ensureWorkerAggregatorRegistry, + handleMasterMetricsResponse, + isAggMetricsResponse, + isPromClientMessage, +} from '../metrics/clusterMetricsAggregator' import { addOtelRequestMetricsMiddleware } from '../metrics/otelRequestMetricsMiddleware' import { addRequestMetricsMiddleware } from '../metrics/requestMetricsMiddleware' import { TracerSingleton } from '../tracing/TracerSingleton' @@ -78,6 +84,10 @@ const onMessage = (service: ServiceJSON) => (message: any) => { logAvailableRoutes(service) } else if (isStatusTrack(message)) { trackStatus() + } else if (isAggMetricsResponse(message)) { + handleMasterMetricsResponse(message) + } else if (isPromClientMessage(message)) { + // Handled by prom-client's own worker listener; ignore here. } else { logger.warn({ content: message, @@ -218,12 +228,19 @@ export const startWorker = (serviceJSON: ServiceJSON) => { addProcessListeners() const tracer = TracerSingleton.getTracer() + + // In multi-worker mode install prom-client's worker-side cluster responder so + // the master can collect this worker's registry for the aggregated /metrics. + if (serviceJSON.workers > 1) { + ensureWorkerAggregatorRegistry() + } + const app = new Koa() app.proxy = true app .use(error) .use(Instrumentation.Middlewares.ContextMiddlewares.Koa.ContextPropagationMiddleware()) - .use(prometheusLoggerMiddleware()) + .use(prometheusLoggerMiddleware(serviceJSON.workers)) .use(addTracingMiddleware(tracer)) .use(addRequestMetricsMiddleware()) .use(addOtelRequestMetricsMiddleware()) diff --git a/src/service/worker/runtime/builtIn/__tests__/middlewares.test.ts b/src/service/worker/runtime/builtIn/__tests__/middlewares.test.ts new file mode 100644 index 000000000..f8208a37e --- /dev/null +++ b/src/service/worker/runtime/builtIn/__tests__/middlewares.test.ts @@ -0,0 +1,98 @@ +import { register } from 'prom-client' + +import * as clusterMetricsAggregator from '../../../../metrics/clusterMetricsAggregator' +import { prometheusLoggerMiddleware } from '../middlewares' + +const buildCtx = (path: string, headers: Record = {}) => { + const setHeaders: Record = {} + return { + body: undefined as any, + get: (key: string) => headers[key] ?? '', + request: { path }, + set: (key: string, value: string) => { + setHeaders[key] = value + }, + setHeaders, + status: undefined as any, + } +} + +describe('prometheusLoggerMiddleware', () => { + beforeEach(() => { + // collectDefaultMetrics() and the lag measurer register into the default + // registry on every middleware construction; clear it between cases. + register.clear() + }) + + afterEach(() => { + jest.restoreAllMocks() + }) + + // AC3: workers=1 (LINKED) serves the default registry content unchanged. + it('serves the local default registry in single-worker mode without IPC', async () => { + const sendSpy = jest.fn() + ;(process as any).send = sendSpy + const aggSpy = jest.spyOn(clusterMetricsAggregator, 'requestAggregatedMetrics') + const localMetricsSpy = jest.spyOn(register, 'metrics').mockResolvedValue('LOCAL_REGISTRY') + + const middleware = prometheusLoggerMiddleware(1) + const ctx: any = buildCtx('/metrics') + const next = jest.fn() + + await middleware(ctx, next) + + expect(localMetricsSpy).toHaveBeenCalledTimes(1) + expect(ctx.body).toBe('LOCAL_REGISTRY') + expect(ctx.status).toBe(200) + expect(ctx.setHeaders['Content-Type']).toBe(register.contentType) + expect(aggSpy).not.toHaveBeenCalled() + expect(sendSpy).not.toHaveBeenCalled() + expect(next).not.toHaveBeenCalled() + + delete (process as any).send + }) + + // AC4: default process metrics are present in the single-worker output. + it('includes default process metrics in single-worker output', async () => { + const middleware = prometheusLoggerMiddleware(1) + const ctx: any = buildCtx('/metrics') + await middleware(ctx, () => Promise.resolve()) + expect(ctx.body).toContain('process_cpu_seconds_total') + }) + + it('requests the cluster aggregate in multi-worker mode', async () => { + const aggSpy = jest + .spyOn(clusterMetricsAggregator, 'requestAggregatedMetrics') + .mockResolvedValue('AGGREGATED') + + const middleware = prometheusLoggerMiddleware(4) + const ctx: any = buildCtx('/metrics') + + await middleware(ctx, () => Promise.resolve()) + + expect(aggSpy).toHaveBeenCalledTimes(1) + expect(ctx.body).toBe('AGGREGATED') + expect(ctx.status).toBe(200) + expect(ctx.setHeaders['Content-Type']).toBe(register.contentType) + }) + + it('does not count /metrics scrapes and passes through other routes', async () => { + const aggSpy = jest.spyOn(clusterMetricsAggregator, 'requestAggregatedMetrics') + const middleware = prometheusLoggerMiddleware(4) + + const nonMetricsCtx: any = buildCtx('/some-route') + const next1 = jest.fn().mockResolvedValue(undefined) + await middleware(nonMetricsCtx, next1) + expect(next1).toHaveBeenCalledTimes(1) + expect(nonMetricsCtx.body).toBeUndefined() + + // Requests carrying a colossus route id must pass through, not be answered. + const routedCtx: any = buildCtx('/metrics', { 'x-colossus-route-id': 'my-route' }) + const next2 = jest.fn().mockResolvedValue(undefined) + await middleware(routedCtx, next2) + expect(next2).toHaveBeenCalledTimes(1) + expect(routedCtx.body).toBeUndefined() + + expect(aggSpy).not.toHaveBeenCalled() + }) +}) diff --git a/src/service/worker/runtime/builtIn/middlewares.ts b/src/service/worker/runtime/builtIn/middlewares.ts index 6c0561a54..be530cca4 100644 --- a/src/service/worker/runtime/builtIn/middlewares.ts +++ b/src/service/worker/runtime/builtIn/middlewares.ts @@ -1,6 +1,7 @@ import { collectDefaultMetrics, register } from 'prom-client' import { HeaderKeys } from '../../../../constants' import { MetricsLogger } from '../../../logger/metricsLogger' +import { requestAggregatedMetrics } from '../../../metrics/clusterMetricsAggregator' import { EventLoopLagMeasurer } from '../../../tracing/metrics/measurers/EventLoopLagMeasurer' import { ServiceContext } from '../typings' import { Recorder } from '../utils/recorder' @@ -21,11 +22,16 @@ export const addMetricsLoggerMiddleware = () => { } } -export const prometheusLoggerMiddleware = () => { +export const prometheusLoggerMiddleware = (workers = 1) => { collectDefaultMetrics() const eventLoopLagMeasurer = new EventLoopLagMeasurer() eventLoopLagMeasurer.start() + // In multi-worker mode each worker holds only its own registry, so /metrics + // must serve the cluster-wide aggregate requested from the master over IPC. + // In single-worker mode (LINKED / workers:1) the local registry is complete. + const isMultiWorker = workers > 1 + return async (ctx: ServiceContext, next: () => Promise) => { if (ctx.request.path !== '/metrics') { return next() @@ -38,7 +44,7 @@ export const prometheusLoggerMiddleware = () => { await eventLoopLagMeasurer.updateInstrumentsAndReset() ctx.set('Content-Type', register.contentType) - ctx.body = await register.metrics() + ctx.body = isMultiWorker ? await requestAggregatedMetrics() : await register.metrics() ctx.status = 200 } } From d803fa9d4bcb4d166399e39d597e9a54546d8553 Mon Sep 17 00:00:00 2001 From: Denis Silva Date: Fri, 17 Jul 2026 11:57:53 -0300 Subject: [PATCH 3/5] chore(metrics): remove metrics-discrepancy-report.html This analysis artifact belongs to a separate investigation and was included in this PR by mistake. Co-authored-by: Cursor --- metrics-discrepancy-report.html | 1227 ------------------------------- 1 file changed, 1227 deletions(-) delete mode 100644 metrics-discrepancy-report.html diff --git a/metrics-discrepancy-report.html b/metrics-discrepancy-report.html deleted file mode 100644 index 5b4421b13..000000000 --- a/metrics-discrepancy-report.html +++ /dev/null @@ -1,1227 +0,0 @@ - - - - - -Why runtime_http_requests_total disagrees: Prometheus vs Diagnostics — investigation report - - - -
- -

Investigation report · July 14, 2026 · field-validated July 16, 2026

-

Why runtime_http_requests_total shows ~10× more in Prometheus than in Diagnostics

-

- Scope: node-vtex-api (master @ 8c09aad4), @vtex/diagnostics-nodejs 0.1.8-io, - @opentelemetry/sdk-metrics 1.30.1, ClickHouse telemetry.metrics_distributed. - Example workload: vtex.admin-cms-graphql-rc@1.42.0. - Single-worker control (§8): vtex.render-server@8.180.1. -

- -
-

Summary of the error — silent metrics data-loss at ClickHouse. The diagnostics pipeline is -permanently losing metrics datapoints without reporting any failure. Root cause is two independent facts -that compound:

-
    -
  • Trigger (active incident). The replicated tables otel_metrics_sum and - otel_metrics_histogram are read-only (is_readonly=1, - is_session_expired=1, 0 active replicas — expired ClickHouse-Keeper session). otel_metrics_gauge - and otel_logs are healthy, so only Sum/Histogram metrics are affected — and - runtime_http_requests_total is a Sum.
    • -
  • Amplifier (design). The metrics consumer writes to ClickHouse - fire-and-forget (async_insert=1&wait_for_async_insert=0) and commits the Kafka offset on - hand-off (message_marking.after=true). So a failed flush is never retried and never surfaces: - otelcol_exporter_send_failed stays 0 while the data is gone. A second latent copy of the anti-pattern sits - upstream (producer Kafka required_acks: 0, retry_on_failure: false).
    • -
-

Measured impact: cluster-wide, system.asynchronous_insert_log shows the metrics tables -failing 81–91% of flushes for 8+ straight hours — recorded as -Code: 159 … Timeout exceeded: maximum: 24000 ms: while pushing to view otel.metrics_sum_view — with -10 of 12 replica instances read-only. The ~15% flush-success share matches the ~15% coverage / -×7 under-count measured live for vtex.render-server@8.180.1 exactly (§8). Because the write path hides -the failure, collector dashboards look healthy throughout. Fix: restore the read-only replicas / Keeper -sessions (and the MV-push timeout), and set wait_for_async_insert=1 (or commit offsets only after a durable -insert) so losses become visible and reprocessable. Full evidence and error samples in §8; remediation in §9.

-
- - -

1. Executive summary

-
-

-Both counters are incremented by adjacent middlewares in the same Koa pipeline -(src/service/worker/index.ts:228–229), exactly once per request each. The divergence is therefore -not created at increment time — it is created downstream, in how each pipeline exports and how each side is queried. -The investigation found four mechanisms, all pushing in the observed direction (Prometheus bigger): -

- - - - - - - - - - - - - - - - - - - - - - - - - - - - - - -
#MechanismDirectionStatusPlausible size
1Prometheus rate/increase inflation from per-worker registries. Each of the 4 cluster workers keeps a private - prom-client registry; /metrics on the shared port is answered by one arbitrary worker per scrape. - The sampled series interleaves 4 independent counters, and every downward sample is treated by PromQL as a counter - reset that adds the full new value.Prom ↑confirmed in code observed live (§3)Unbounded; grows with worker uptime — measured ~×40 on one live window
2Diagnostics coverage gaps. Any pod where VTEX_DIAGNOSTICS_TELEMETRY_ENABLED ≠ 'true' runs a - no-op metrics client; any pod where OTel instruments fail to initialize serves traffic uncounted. Those pods - contribute to Prometheus only. And fleet-wide: both o11y collectors run a - filter/temporality that drops every non-delta datapoint — apps built on - pre-Dec-2025 @vtex/api (before 65e50da7) export cumulative, so their counters and - histograms never reach ClickHouse at all.Diag ↓confirmed in collector config size needs checkPer-app all-or-nothing: old-SDK apps are 100% invisible in diagnostics; this app reports (5 pods seen)
3Cardinality overflow on the diagnostics counter. The OTel counter carries - vtex.account.name (Prometheus’ doesn’t). The SDK caps each instrument at - 2000 attribute-sets per 60 s window per worker; the excess is folded into a single - otel.metric.overflow="true" series with no handler, no status, no account. - In your query those rows surface as Status: | Handler: None — or vanish if any stage drops them.Diag ↓ (per-handler views)confirmed in code measured: zero for this app (§7 step 3)Ruled out for this app — overflow = 0 over 24 h; stays latent for higher-cardinality apps
4Delta export is lossy on failure. Since the switch to delta temporality (commit 65e50da7, - 2025-12-16), a failed/timed-out 60 s OTLP export loses that window permanently (cumulative would self-correct). - Interval/timeout were already raised 5 s→60 s (d122a999, #623) under export pressure.Diag ↓confirmed in code size needs checkDepends on export error rate
-

-There is also a comparison-methodology layer that can produce clean constant factors on its own and must be -ruled out first: unit mismatch (delta points are “requests per 60 s per worker”, not a rate), exact-version pinning -(app = '…@1.42.0' vs. an unpinned Grafana selector), and asymmetric handler filters -(builtin:healthcheck is excluded in the ClickHouse query — is it excluded on the Prometheus panel? -for an admin app, healthchecks are often the majority of requests). See §5. -

-

-A stable, smooth “~10×” most resembles #2 + methodology; an erratic, uptime-correlated gap most resembles -#1. §6 weighs the two sources and concludes that the diagnostics → ClickHouse number is the one -closer to reality today: its errors only under-count and are measurable, while PromQL over multi-worker pods is -unrecoverable by construction. §7 gives a 30-minute playbook that tells the mechanisms apart, and §8 runs it -live against a single-worker control (vtex.render-server): with Mechanism #1 switched off the counter is -provably monotonic, yet ClickHouse still under-reports the 1,384-pod fleet ~7× — root-caused (§8) to silent write-loss -in the o11y pipeline (read-only otel_metrics_sum/histogram replicas + wait_for_async_insert=0 -fire-and-forget writes), not per-worker inflation. -

-
- - -

2. One request, two counters, two pipelines

-

-Every inbound request traverses both middlewares back-to-back — same scope, same -finally-block increment semantics, including healthchecks and events. Scrapes of /metrics are excluded -from both (the Prometheus responder returns before either middleware runs). The pipelines only diverge after the increment: -

- -
- HTTP request → Koa pipeline → both counters +1 - - (requestMetricsMiddleware.ts:43 · otelRequestMetricsMiddleware.ts:64 — mounted at worker/index.ts:228–229) -
- -
-
- PULL · PROMETHEUS -
prom-client counter {handler, status_code} in the default registry — one per worker process (×4) - src/service/metrics/requestMetricsMiddleware.ts:43
-
↓
-
/metrics served on the shared port 5000 — each scrape is answered by - one arbitrary worker (Node cluster round-robin; default 5 s keep-alive < scrape interval ⇒ new - connection, likely a different worker, every scrape) - builtIn/middlewares.ts:24 · service/master.ts:89 · loaders.ts:19 (workers = min(cpus, 4))
-
↓
-
Prometheus/Grafana rate()/increase() — interleaved counters look like - constant counter resets → systematic over-count (see §3)
-
-
- PUSH · DIAGNOSTICS -
OTel counter {handler, status_code, vtex.account.name} — one SDK per worker - src/service/metrics/otelRequestMetricsMiddleware.ts:64
-
↓
-
SDK aggregation: delta temporality, 60 s interval; cardinality cap - 2000 attribute-sets/instrument/cycle → excess folded into otel.metric.overflow="true"; - failed export = window lost - telemetry/client.ts:61–69 · sdk-metrics DeltaMetricProcessor.js:36–45
-
↓
-
OTLP gRPC → collector → ClickHouse telemetry.metrics_distributed - resource: service.instance.id = client-hostname-pod (no per-worker component)
-
↓
-
sumMerge(Sum) — aggregate states are additive, so the 4 workers’ deltas sum - correctly even with identical stream identity (unlike any PromQL-style consumer)
-
-
- -

-Timeline that shaped the current state: d122a999 (2025-12-04) export interval/timeout 5 s→60 s · -3f65ab73 (2025-12-16) vtex.account.name added to the OTel request metrics · -65e50da7 (2025-12-16) exporter switched cumulative→delta. -

- - -

3. Mechanism #1 — what Prometheus actually sees

-

-prom-client counters live in per-process memory. With workers: min(cpus, 4) forked by -startMaster and all listening on the same port, a scrape of /metrics reaches exactly one worker — -and because Node’s default HTTP keep-alive (5 s) is shorter than any scrape interval, each scrape opens a fresh -connection and round-robin hands it to a different worker. Under one instance label, Prometheus -stores a braid of four independent counters: -

- -
-
- Per-worker counters (4 processes, each monotonic) - Series Prometheus samples at /metrics - ▼ sample below its predecessor → PromQL counts a “counter reset” -
- - - - - - - - - - - - - - 9,000 - 9,500 - 10,000 - 10,500 - 11,000 - 11,500 - 12,000 - - - 0 min - 2 - 4 - 6 - 8 - 10 min - - - - - - - - - - - w3 - w1 - w4 - w2 - - - - - - - - t=0:00 · worker 1 answers · 10,000 - t=0:30 · worker 2 answers · 9,351 — lower than 10,000 → PromQL adds +9,351 as a “reset” - t=1:00 · worker 3 answers · 10,896 - t=1:30 · worker 4 answers · 10,058 → +10,058 as “reset” - t=2:00 · worker 1 answers · 10,216 - t=2:30 · worker 2 answers · 9,555 → +9,555 as “reset” - t=3:00 · worker 3 answers · 11,088 - t=3:30 · worker 4 answers · 10,268 → +10,268 as “reset” - t=4:00 · worker 1 answers · 10,432 - t=4:30 · worker 2 answers · 9,759 → +9,759 as “reset” - t=5:00 · worker 3 answers · 11,280 - t=5:30 · worker 4 answers · 10,478 → +10,478 as “reset” - t=6:00 · worker 1 answers · 10,648 - t=6:30 · worker 2 answers · 9,963 → +9,963 as “reset” - t=7:00 · worker 3 answers · 11,472 - t=7:30 · worker 4 answers · 10,688 → +10,688 as “reset” - t=8:00 · worker 1 answers · 10,864 - t=8:30 · worker 2 answers · 10,167 → +10,167 as “reset” - t=9:00 · worker 3 answers · 11,664 - t=9:30 · worker 4 answers · 10,898 → +10,898 as “reset” - t=10:00 · worker 1 answers · 11,080 - - - -
-
-
Real requests served in the window
-
4,110
-
sum of all four workers’ actual growth
-
-
-
What increase() computes
-
109,640
-
10 “resets” × ~10k each, plus real deltas
-
-
-
Inflation in this example
-
×26.7 artifact
-
grows with counter age; shrinks if scrapes pin one worker
-
-
- -

- Synthetic but honestly computed: 4 workers at ~1.6–1.8 req/s each, scraped every 30 s in rotation. PromQL’s reset - rule — “a decrease means the counter restarted at zero, so the whole new value is new traffic” — fires on every - worker switch that lands lower. If keep-alive happens to pin the scraper to one worker instead, the same setup - under-counts (you see ~¼ of pod traffic) until the connection rotates and produces a giant spike. - Either way, PromQL over these series is not measuring traffic. -

- -
- Table view — the 21 samples behind the chart - - - - - - - - - - - - - - - - - - - - - - - -
ScrapeWorker answeringCounter valuePromQL interpretation
0:00w110,000—
0:30w29,351reset → +9,351
1:00w310,896+1,545
1:30w410,058reset → +10,058
2:00w110,216+158
2:30w29,555reset → +9,555
3:00w311,088+1,533
3:30w410,268reset → +10,268
4:00w110,432+164
4:30w29,759reset → +9,759
5:00w311,280+1,521
5:30w410,478reset → +10,478
6:00w110,648+170
6:30w29,963reset → +9,963
7:00w311,472+1,509
7:30w410,688reset → +10,688
8:00w110,864+176
8:30w210,167reset → +10,167
9:00w311,664+1,497
9:30w410,898reset → +10,898
10:00w111,080+182
-
- -

Field result — mechanism observed on a live pod confirmed live

-

- Six consecutive /metrics scrapes of one production pod, 16 s apart (2026-07-14), reading - runtime_http_requests_total{handler="builtin:healthcheck",status_code="200"}: -

- 
1580   1580   1548   1550   1593   1596
- - - - - - - -
TransitionRaw deltaPromQL interpretation
1580 → 15800+0
1580 → 1548−32“counter reset” → +1,548 (full value counted as new traffic)
1548 → 1550+2+2 — the only plausibly same-worker pair; implies ~0.5 req/s pod-wide
1550 → 1593+43+43 — an inter-worker offset masquerading as traffic
1593 → 1596+3+3
-

- A single counter can never decrease, so the 1580 → 1548 drop proves consecutive scrapes are answered by - different workers — at least three are visible (≈1548–1550, ≈1580, ≈1593–1596). Over these 80 s, - increase() computes 1,596 requests (~20 req/s) for this one low-traffic series, against a - real rate on the order of ~0.5 req/s — roughly ×40 inflation in this window (≥×7 under the most - generous reading). It also confirms scrape connections rotate workers in this environment (keep-alive does not pin), - so the artifact fires continuously in production. -

-
- - -

4. Mechanisms #2–4 — where the diagnostics side loses counts

- -

4.1 Coverage: pods that only exist in Prometheus needs data check

-

-VTEX_DIAGNOSTICS_TELEMETRY_ENABLED !== 'true' swaps in a no-op metrics client -(telemetry/client.ts:95, no-op factory in the library) — the middleware happily “counts” into a void. -Separately, if instruments aren’t ready within 500 ms on a request, that request passes through uncounted -(otelRequestMetricsMiddleware.ts:29–34); if the OTLP endpoint is misconfigured for a pod, all its -requests do. Every such pod still serves traffic and still reports to Prometheus. If, say, coverage is 1-in-10 replicas, -you get a clean, stable 10× gap — the shape you described. -

-

-Confirmed at the platform layer (2026-07-14, o11y-platform repo): the full path is -app SDK → producer collector → Kafka → consumer collector → otel.otel_metrics_sum → MV → -telemetry.metrics, and both collectors run a filter/temporality processor that drops -every Sum/Histogram datapoint whose temporality isn’t delta -(provisioning/vtex-io/collectors/producer.yaml:221, consumer-metrics.yaml:234; no -cumulativetodelta conversion in either pipeline — gauges pass through). Consequence: any app built with -@vtex/api older than the delta switch (65e50da7, 2025-12-16) exports cumulative and is -100% invisible in diagnostics dashboards while fully visible in Prometheus. For cross-app or fleet-level -comparisons this is very plausibly the dominant term of the gap; per app it is all-or-nothing (this report’s example app -reports, so it is on a delta-enabled version). The aggressive consumer memory_limiter -(85%/3% spike) is a secondary loss channel under load. -

- -

4.2 Cardinality overflow at 2000 attribute-sets confirmed in code

-

-@opentelemetry/sdk-metrics@1.30.1 enforces a default aggregationCardinalityLimit of 2000 — -per instrument, per worker, per 60 s collection cycle (DeltaMetricProcessor.js:36–45; the active-window -storage is swapped at each collect). The OTel counter’s attribute space is -handler × status_code × vtex.account.name — the account dimension (added 2025-12-16) makes this explode for -multi-tenant apps. Everything past 1,999 unique combinations in a window is recorded only as -{"otel.metric.overflow": "true"}: no handler, no status, no account. -

-

In your ClickHouse query those rows are not filtered out — they surface as the series -Status: | Handler: None (empty status, handler folded to “None”). Two consequences:

-
    -
  • Any panel that groups or filters by handler/status/account silently under-reports total traffic.
    • -
  • Your “None” series is a mixture of overflow and requests that genuinely resolved no handler — distinguish them with the otel.metric.overflow key (query in §7).
    • -
-

-Field result (2026-07-14): the §7 step 3 query returned overflow_requests = 0 for every hour of -the last day on vtex.admin-cms-graphql-rc@1.42.0 — this app stays under the 2000-set cap, so -overflow contributes nothing to its gap, and its “None” series is genuinely handler-less traffic. -The mechanism remains latent for apps with more accounts×handlers×statuses per minute. (The measurement is sound -end-to-end: the materialized view passes metric attributes through untouched except device and -process.pid — 3-metrics.sql:259–262 — so overflow rows do reach the aggregated table when they occur.) -

- -

4.3 Delta export drops are permanent confirmed in code

-

-The exporter runs OTLP/gRPC with interval: 60 s, timeout: 60 s, delta temporality -(telemetry/client.ts:61–69). With delta, a window that fails to export is gone — there is no cumulative value -for the next successful export to restore. The history (interval/timeout already raised from 5 s under pressure, -then account-attribute payload growth) makes periodic export failures a realistic, compounding loss. -

- -

4.4 Worker identity collision — mitigated by ClickHouse, but fragile confirmed in code

-

-service.instance.id = clientName-hostname(-podName) with no per-process component -(resource-discovery.js:167–179), so all 4 workers of a pod emit byte-identical metric streams. Because your -backend stores additive aggregate states and you read with sumMerge, concurrent deltas on the same -identity sum correctly — this is why the delta switch fixed ClickHouse readings where cumulative could not work. -But it remains a latent defect: any consumer that dedupes same-identity points or converts delta→cumulative -(a Prometheus-compatible sink, a collector processor) will silently drop up to ¾ of the data. Worth one confirmation -with the pipeline owners that no dedup stage sits before ClickHouse. -

-Confirmed from production data (2026-07-14): a live row’s resource shows -service.instance.id = node-vtex-api-<pod-name> and host.name = <pod-name> — pod-level -only, no worker component, exactly as the code predicts. -

- - -

5. Your comparison itself — three asymmetries to rule out first

-
-
    -
  1. - Units. Each diagnostics data point is “requests in one worker’s 60 s window”, stamped at export time; - the materialized view truncates TimestampTime to the minute (3-metrics.sql:230), so each - bucket in your query is requests-per-minute-ish (workers’ 60 s windows straddle minute boundaries). - A Grafana Prometheus panel typically shows rate() (req/s) or - increase() over $__rate_interval. Unless both sides are normalized to the same bucket - (req/min is the natural one), a constant factor is guaranteed. A 10-minute prom window vs. per-minute delta sums is - exactly ×10. -
    2. -
  2. - Scope. ClickHouse pins app = 'vtex.admin-cms-graphql-rc@1.42.0' (one exact build) plus - production='true', workspace='master', tenant='vtex'. If the Prometheus selector - matches the whole workload — all patch versions during rollouts, all workspaces, canaries — Prometheus counts strictly more. - Live anomaly (2026-07-14), derivation now confirmed: a pod on workspace master reported - vtex_io.workspace.type='development' — the SDK derives that value from VTEX_PRODUCTION - (constants.ts:182), and the materialized view derives the production column from exactly this - attribute (3-metrics.sql:246–250: workspace.type == 'production' ? 'true' : 'false'). Any pod - missing that env var is tagged production='false' and its entire traffic is silently dropped by the - production='true' panel filter. Audit query in §7 step 2a. -
    3. -
  3. - Handler filters. The ClickHouse query excludes builtin:healthcheck and restricts to an - explicit handler list. For an admin GraphQL app, platform healthchecks are frequently the single biggest handler. - If the Prometheus panel has no matching exclusion, the gap is largely healthchecks. -
    4. -
-
- - -

6. Which source reflects reality more closely today?

-
-

-Verdict: for any app running more than one worker — effectively every production app, since -workers = min(cpus, 4) resolves to 4 on production nodes — the diagnostics → ClickHouse pipeline is the -closer-to-reality source today. Its failure modes only ever lose requests, the losses are bounded and -measurable, and the volume hidden by the cardinality cap is still present in the table (in the overflow bucket). -The Prometheus counter read through rate()/increase() on a multi-worker pod is not a distorted -measurement — it is not a measurement at all: the scraped samples interleave four independent counters under one -instance label, which destroys the information needed to reconstruct traffic in either direction. -

- - - - - - - - - - - - - - - - - - - - - - - - - - - - - - - - - - - -
Failure propertyPULL · PROMETHEUSPUSH · DIAGNOSTICS → CLICKHOUSE
Direction of errorBoth directions: inflation from phantom resets (§3), deflation to ~¼ of traffic when keep-alive pins one workerOne direction only: under-count. The pipeline never invents a request
Size of errorUnbounded — every phantom reset adds an entire counter value, so the artifact grows with worker uptimeBounded — lost 60 s windows (export failures) plus attribution, not volume, lost past 2000 attribute-sets
Recoverable at query time?No — samples carry no worker label; the interleaving cannot be undone by any PromQLLargely — totals stay correct if the otel.metric.overflow bucket is included; only per-handler/account detail beyond the cap is gone
Detectable?Only indirectly (resets() > 0 without pod restarts)Directly: overflow attribute, pods-reporting count, exporter error logs (§7 steps 2–3)
Recording reliabilityPerfect — synchronous, in-memory, no flags, no exportsNear-perfect — no-op when the telemetry flag is off; ≤500 ms instrument race at pod start
Duplication riskNone at recording time, but rate() effectively duplicates counts at every phantom resetNone — the gRPC exporter does not retry, so failures only lose data, never double-count
- -

Why the errors are not symmetrical

-
    -
  • The ClickHouse number is a floor on reality: true traffic ≥ sumMerge(Sum) with the overflow - bucket included. Every delta point that reaches the table is a true count of requests one worker actually served in one - 60 s window, and sumMerge is exact addition. You can reason with a floor.
    • -
  • The Prometheus rate is neither a floor nor a ceiling. Depending on how scrape connections happen to - land, the same pod can read 10× real traffic or ¼ of it, and flip between the two when a connection re-establishes. - Each stored sample is individually true, but the series they form is collectively meaningless.
    • -
  • Diagnostics’ residual risks are operational and checkable in minutes (flag coverage across replicas, - export error rate — §7 steps 2–3). The Prometheus defect is architectural: no query hygiene or dashboard fix can - recover it; only the AggregatorRegistry change (§9.1) can.
    • -
- -

Practical guidance — which number for which job

- - - - - - - - - - - - -
Question being answeredSource to trust today
How much traffic did this app/handler actually serve? (SLO denominators, capacity, accounting)ClickHouse, overflow bucket included — treat as a lower bound
Per-account traffic breakdownClickHouse only (the prom counter has no account label); mind the overflow cap at peak traffic
Is the pod alive / is traffic flowing at all right now?Either — Prometheus is fine for liveness and shape, just not for magnitude
Anything computed with rate()/increase() on a multi-worker appNeither — fix the export first (§9.1); until then these panels are artifacts
Ground-truth calibration of both pipelinesA workers: 1 app or router/edge logs (§7 step 4)
- -

-The one setup where the ranking flips: workers: 1 (and linked development, where -LINKED forces a single worker). With one process there is one registry, the scraped series is monotonic, and -the prom path has no export or coverage dependency — there it is the gold standard, which is exactly what makes it the -arbitration tool in §7 step 4. confirmed live (§8) A single-worker app -(vtex.render-server, cpu limit 1) shows a provably monotonic counter — but there ClickHouse under-reports the -real 1,384-pod fleet by ~7× (coverage/pipeline loss), so for this case Prometheus is the closer-to-reality source. -

-

-This verdict is conditional on the two §7 checks passing: (a) all replicas report to ClickHouse (telemetry flag on -everywhere) and (b) export failures are rare. If step 2 shows only a fraction of pods reporting, the ClickHouse number is -still honest about what it saw — but it tracks reality only after coverage is fixed. The same reasoning applies to the -sibling instruments (runtime_http_requests_duration_milliseconds, runtime_http_response_size_bytes, -runtime_http_aborted_requests_total), which share both pipelines. -

-
- - -

7. Verification playbook (~30 minutes)

- -

Step 1 — prove/measure the Prometheus artifact

-
# A healthy counter under one instance label never decreases. Any non-restart resets ⇒ interleaving.
-resets(runtime_http_requests_total{app="vtex-admin-cms-graphql-rc"}[1h])
-
-# Or from inside the pod: consecutive scrapes answered by different workers show jumping values
-for i in 1 2 3 4 5 6; do
-  curl -s localhost:5000/metrics | grep 'runtime_http_requests_total{status_code="200"' | head -2
-  sleep 16   # longer than the 5s keep-alive so each request opens a new connection
-done
-

-✔ Run on 2026-07-14 against a live pod: samples decreased between scrapes (1580 → 1548), proving worker -interleaving — full arithmetic in the §3 field result. -

- -

Step 2 — measure diagnostics coverage

-

-✔ Resolved 2026-07-14: the resource map does carry pod identity. A live row ships -host.name (= pod name), service.instance.id (= node-vtex-api-<pod> — -note: no per-worker component, confirming §4.4 from production data), plus -vtex_io.app.id, vtex_io.workspace.name/type, vendor, version, -application.id. (deployment.environment and service.version arrive as -'unknown' — their env vars aren’t set.) -

-

2a. Count pods reporting, and audit the workspace-type tagging. -Schema resolved 2026-07-14: pod identity survives only on the raw layer, -otel.otel_metrics_sum_distributed (standard OTel exporter schema, delta Value per point, -ServiceName = IO app id). The aggregated telemetry.metrics_distributed has no -ResourceAttributes column and no host.name in Attributes — beware: -uniqExact(Attributes['missing-key']) returns 1, not an error.

-
-- PREFERRED (3-day retention): the MV stores Count = sumState(1) per raw datapoint
--- (3-metrics.sql:265), and each worker emits one delta point per active series per 60 s,
--- so for the always-active healthcheck series: datapoints/min ÷ 4 workers ≈ pods reporting.
-SELECT toStartOfHour(TimestampTime) AS h,
-       round(sumMerge(Count) / 60 / 4, 1) AS avg_pods_reporting,
-       sumMerge(`Sum`)                    AS hc_requests
-FROM telemetry.metrics_distributed
-WHERE app = 'vtex.admin-cms-graphql-rc@1.42.0'
-  AND MetricName = 'runtime_http_requests_total'
-  AND Attributes['handler'] = 'builtin:healthcheck'
-  AND Attributes['status_code'] = '200'
-  AND TimestampTime >= now() - INTERVAL 24 HOUR
-GROUP BY h ORDER BY h;
-
--- pods reporting per hour on the RAW layer (short retention — see caveat below)
-SELECT toStartOfHour(TimeUnix) AS h,
-       uniqExact(ResourceAttributes['host.name']) AS pods_reporting,
-       sum(Value)                                 AS requests      -- valid: delta points
-FROM otel.otel_metrics_sum_distributed
-WHERE ServiceName = 'vtex.admin-cms-graphql-rc@1.42.0'
-  AND MetricName = 'runtime_http_requests_total'
-  AND TimeUnix >= now() - INTERVAL 6 HOUR
-GROUP BY h ORDER BY h;
-
--- pod list, to diff against kubectl
-SELECT DISTINCT ResourceAttributes['host.name'] AS pod
-FROM otel.otel_metrics_sum_distributed
-WHERE ServiceName = 'vtex.admin-cms-graphql-rc@1.42.0'
-  AND MetricName = 'runtime_http_requests_total'
-  AND TimeUnix >= now() - INTERVAL 1 HOUR
-ORDER BY pod;
-
--- ⚠ observed on one app: workspace.name='master' with workspace.type='development'.
--- The SDK sets workspace.type from VTEX_PRODUCTION (constants.ts:182 → telemetry/client.ts:92);
--- if the aggregated table's 'production' column derives from it, a production='true' filter
--- silently drops every pod where that env var is missing.
-SELECT ResourceAttributes['vtex_io.workspace.type'] AS wtype,
-       uniqExact(ResourceAttributes['host.name'])   AS pods,
-       sum(Value)                                   AS requests
-FROM otel.otel_metrics_sum_distributed
-WHERE ServiceName = 'vtex.admin-cms-graphql-rc@1.42.0'
-  AND MetricName = 'runtime_http_requests_total'
-  AND TimeUnix >= now() - INTERVAL 6 HOUR
-GROUP BY wtype;
-
--- worker-level coverage: healthchecks keep every worker's series active, and each worker
--- emits one delta point per active series per 60 s → points/min ≈ pods × 4 workers
-SELECT toStartOfMinute(TimeUnix) AS m,
-       count()                                    AS points,
-       uniqExact(ResourceAttributes['host.name']) AS pods
-FROM otel.otel_metrics_sum_distributed
-WHERE ServiceName = 'vtex.admin-cms-graphql-rc@1.42.0'
-  AND MetricName = 'runtime_http_requests_total'
-  AND Attributes['handler'] = 'builtin:healthcheck'
-  AND Attributes['status_code'] = '200'
-  AND TimeUnix >= now() - INTERVAL 10 MINUTE
-GROUP BY m ORDER BY m;
-
--- pipeline-loss check: raw layer vs aggregated layer must match, minute by minute
-SELECT toStartOfMinute(TimeUnix) AS m, sum(Value) AS raw_requests
-FROM otel.otel_metrics_sum_distributed
-WHERE ServiceName = 'vtex.admin-cms-graphql-rc@1.42.0'
-  AND MetricName = 'runtime_http_requests_total'
-  AND TimeUnix >= now() - INTERVAL 15 MINUTE
-GROUP BY m ORDER BY m;
--- compare with:  SELECT toStartOfMinute(TimestampTime), sumMerge(`Sum`) FROM telemetry.metrics_distributed WHERE app = '…' …
-

-⚠ Raw-table caveat (observed 2026-07-14, explained by the schema): the raw tables’ TTL is -toDate(TimeUnix) + toIntervalHour(6) (3-metrics.sql:81) — i.e. 06:00 of the point’s calendar -day, not a rolling 6 h, so any point written after 06:00 is born expired and survives only until the next TTL -merge sweep. That is why a 6-hour query returned a single partial hourly bucket. Run raw-layer checks over the last -10–15 minutes and compare with kubectl at the same moment — or use the Count-based query above, which has 3-day -retention. If a rolling window was intended, the TTL should be toDateTime(TimeUnix) + INTERVAL 6 HOUR -(flag to the o11y-platform team). Field result: 5 pods reporting at 20:00 (kubectl diff pending). -

-

2b. Cross-check coverage at the source — the flag and endpoint are env vars, so the -deployment spec answers the question without ClickHouse:

-
kubectl -n <ns> exec <one-pod> -- env | grep -E 'VTEX_DIAGNOSTICS_TELEMETRY_ENABLED|OTEL_EXPORTER_OTLP_ENDPOINT'
-# if these come from the deployment template, coverage is all-or-nothing per app;
-# check whether the rollout that sets them reached every app/cluster being compared
-

2c. Calibrate with the healthcheck series — probes hit every pod at a uniform rate, so -coverage ≈ ClickHouse healthchecks/min ÷ (pod count × per-pod probe rate):

-
-- diagnostics-side healthcheck volume per minute
-SELECT toStartOfMinute(TimestampTime) AS m, sumMerge(`Sum`) AS hc_per_min
-FROM telemetry.metrics_distributed
-WHERE app = 'vtex.admin-cms-graphql-rc@1.42.0'
-  AND MetricName = 'runtime_http_requests_total'
-  AND Attributes['handler'] = 'builtin:healthcheck'
-  AND production = 'true' AND workspace = 'master'
-  AND TimestampTime >= now() - INTERVAL 30 MINUTE
-GROUP BY m ORDER BY m;
-
# per-pod probe rate, measured on one pod: force Connection: close so round-robin
-# cycles through all 4 workers — the 4 distinct values summed = pod-level counter now
-for i in $(seq 1 8); do
-  curl -s -H 'Connection: close' localhost:5050/metrics \
-    | grep 'runtime_http_requests_total{handler="builtin:healthcheck",status_code="200"}'
-done | sort -u
-# repeat after 5 minutes; (sum_now − sum_before) / 5 = healthchecks/min/pod
-# coverage = hc_per_min ÷ (kubectl-pod-count × healthchecks/min/pod)
-

-Note the calibration query drops the tenant/account filters on purpose: healthcheck requests have no account -(the middleware records 'unknown'), so account-scoped filters could exclude them. -

- -

Step 3 — measure cardinality overflow

-
-- share of traffic hidden in the overflow bucket (invisible to per-handler panels)
-SELECT toStartOfHour(TimestampTime) AS h,
-       sumMergeIf(`Sum`, Attributes['otel.metric.overflow'] = 'true') AS overflow_requests,
-       sumMerge(`Sum`)                                                AS all_requests
-FROM telemetry.metrics_distributed
-WHERE app = 'vtex.admin-cms-graphql-rc@1.42.0'
-  AND MetricName = 'runtime_http_requests_total'
-  AND TimestampTime >= now() - INTERVAL 1 DAY
-GROUP BY h ORDER BY h;
-

-✔ Run on 2026-07-14: overflow_requests = 0 for all 24 hourly buckets — cardinality overflow ruled out for -this app (see §4.2). -

- -

Step 4 — like-for-like totals, then arbitrate with a third source

-
-- ClickHouse: total requests per minute, NO handler/status/account filters
-SELECT toStartOfMinute(TimestampTime) AS m, sumMerge(`Sum`) AS req_per_min
-FROM telemetry.metrics_distributed
-WHERE app = 'vtex.admin-cms-graphql-rc@1.42.0'
-  AND MetricName = 'runtime_http_requests_total'
-  AND TimestampTime BETWEEN {from} AND {to}
-GROUP BY m ORDER BY m;
-
-# Prometheus: same window, same scope, per minute — but remember §3 makes this number suspect
-sum(increase(runtime_http_requests_total{app="..."}[1m]))
-

-Because both sides are distorted, arbitrate with an independent count for one hour of one app: router/edge access -logs (VictoriaLogs request count for the app) or a workers: 1 test app — with one worker the Prometheus path is -trustworthy, so whatever gap remains there is pure diagnostics-side loss. -

- - -

8. Field validation — a single-worker control (vtex.render-server)

-
-

-On 2026-07-16 the §7 playbook was run end-to-end against a second app, -vtex.render-server@8.180.1, chosen because it is provisioned at -VTEX_SELF_CPU_LIMIT = 1. Since workers = min(cpus, 4), that resolves to -a single worker per pod — the one configuration where §6 predicts multi-worker interleaving -(Mechanism #1) is absent. It is therefore a control: it lets us switch Mechanism #1 off and see what is -left. Two independent results came out of it — one clean confirmation, and one large gap that turned out to be -coverage/pipeline loss, not the app. -

- -

Correction to an earlier draft. A first pass compared ClickHouse -(which ingests all us-east-1 IO clusters) against the pod count of a single cluster -(…-m4t, ~250 pods) and reported “~94% agreement.” That denominator was wrong. -render-server@8.180.1 actually runs across 7 clusters / 1,384 pods. Re-based on the true -fleet, ClickHouse holds only ~15% of the traffic. The lesson is itself a finding: the aggregated table has -no cluster/region column (see §7 step 2a), so it is easy to mismatch a cluster-scoped numerator with a -fleet-wide denominator.

- -
-
Workers per pod
1
min(cpus,4), cpu limit = 1 → Mechanism #1 absent
-
Fleet
1,384
pods across 7 clusters
-
ClickHouse coverage
~15%
≈ ×7 under-count — root cause: readonly metrics tables + fire-and-forget writes
-
- -

Prometheus side — the counter is monotonic (Mechanism #1 confirmed absent)

-

-Eight consecutive scrapes of one pod’s shared /metrics (port 5050), 16 s apart — longer than the 5 s -keep-alive, so each is a fresh connection — on -runtime_http_requests_total{handler="public-handler:render",status_code="200"}: -

-
10391  10415  10436  10439  10465  10478  10495  10526
-

-Strictly increasing, zero drops. Contrast the multi-worker node-vtex-api field result in §3 -(1580 → 1548, a decrease PromQL scores as a full-value reset). With one registry there is nothing to interleave, -so rate()/increase() over these series is trustworthy — the §6 gold standard. So whatever gap -remains for render-server is not a Prometheus artifact; it is real divergence between a correct Prometheus number -and the diagnostics pipeline. -

- -

Diagnostics side — a ~7× under-count, calibrated with the healthcheck series

-

-Healthchecks hit every pod at a uniform rate (~30/min/pod, verified on pods in two different clusters: 30.24 in -…-m4t, 29.67 in …-k5a), so expected fleet healthchecks = pods × per-pod rate and -coverage = ClickHouse healthchecks ÷ expected (§7 step 2c). The ClickHouse figure is steady-state, not lag -(~5,100/min three hours earlier, ~5,900/min now): -

- - - - - - - -
QuantityValue
Running pods, all clusters (kubectl: k5a 235 · p8c 207 · m4t 219 · r5p 247 · f3t 224 · s9b 227 · qua 25)1,384
Per-pod healthcheck rate (scraped, 2 clusters)~30 /min/pod
Expected fleet healthcheck~41,500 /min
ClickHouse fleet healthcheck (sumMerge(Sum), steady-state)~6,000 /min
Coverage~15% → ×7 under-count
-

-The non-healthcheck handlers the dashboard actually plots (public-handler:render/:redirect) lose -traffic through the same pipeline, so the ~7× factor applies to them too: a correct Prometheus panel summed over all 1,384 -pods sits roughly 7× above the ClickHouse total. This is the same direction as the report’s -headline (Prom > Diag) but a different mechanism — coverage/pipeline loss (§4.1, §4.3), not the -per-worker inflation of §3. -

- -

Root cause — silent write-loss at ClickHouse confirmed in o11y-platform + live

-

-The obvious suspect — telemetry disabled on most pods (Mechanism #2) — is ruled out: on pods sampled -across five clusters VTEX_DIAGNOSTICS_TELEMETRY_ENABLED=true with a uniform OTLP endpoint -(grpc-vtex-io-o11y-platform…:3333). The collector counters are also clean — producer and consumer both report -receiver_refused = 0, send_failed = 0, no memory-limiter refusals, consumer queue depth 1/100000. -A pipeline shedding 85% would scream in those counters. It doesn’t — because the loss happens at two -fire-and-forget stages that never report failure, then reading the o11y-platform config and ClickHouse -system tables pinned the exact stage: -

-
    -
  • Consumer → ClickHouse is fire-and-forget. The consumer writes with - async_insert=1&wait_for_async_insert=0 and commits the Kafka offset - after handing off (message_marking.after=true). ClickHouse acknowledges receipt into its async - buffer before the buffer is flushed to the table, so a later flush failure is invisible to the exporter - (send_failed stays 0) and the offset is already gone — no reprocessing, permanent loss. - (consumer-metrics.yaml exporter endpoint + message_marking.)
    • -
  • The metrics tables are read-only across the cluster. - clusterAllReplicas('cluster', system.replicas) shows 10 of 12 replica instances of - otel_metrics_sum/otel_metrics_histogram with is_readonly=1 (two of them with - is_session_expired=1 — ClickHouse-Keeper session loss), spread over all 6 nodes; - otel_metrics_gauge and otel_logs are healthy. runtime_http_requests_total - is a Sum → otel_metrics_sum → affected.
    • -
  • The recorded error — the flush log carries the exact exception. 100% of the FlushErrors in the last - 3 h are TIMEOUT_EXCEEDED (code 159); zero read-only-flavored exceptions surface in the flush log - because the failure manifests as the insert timing out while cascading into the materialized views - (which is where the per-minute aggregate telemetry.metrics is populated — 3-metrics.sql).
    • -
- -

Sample error messages (from system.asynchronous_insert_log.exception, 2026-07-16 — these are -what to chase when fixing):

-
-- otel_metrics_sum (305,419 occurrences in 8h, cluster-wide)
-Code: 159. DB::Exception: Timeout exceeded: maximum: 24000 ms:
-  while pushing to view otel.metrics_sum_view. (TIMEOUT_EXCEEDED) (version 25.7.1.3997)
-
--- otel_metrics_histogram (294,088 occurrences)
-Code: 159. DB::Exception: Timeout exceeded: maximum: 24000 ms:
-  while pushing to view otel.metrics_histogram_view. (TIMEOUT_EXCEEDED) (version 25.7.1.3997)
-
--- minority variant (plain flush timeout, no MV named)
-Code: 159. DB::Exception: Timeout exceeded: elapsed 30902.79 ms, maximum: 24000 ms. (TIMEOUT_EXCEEDED)
-

Reproduce with:

-
SELECT table, substring(replace(exception,'\n',' '),1,300) AS exc, count() AS n, max(event_time) AS last_seen
-FROM clusterAllReplicas('cluster', system.asynchronous_insert_log)
-WHERE database='otel' AND status='FlushError' AND event_time >= now() - INTERVAL 2 HOUR
-GROUP BY table, exc ORDER BY n DESC;
- -

The failure rate predicts the render-server gap exactly

-

-Cluster-wide flush outcomes for otel_metrics_sum by hour — the Ok share is ~13–17% for at least -8 straight hours, which is precisely the ~15% coverage measured for render-server in the -healthcheck calibration above (×7 under-count ≈ 1/0.15): -

- - - - - - - - - - - -
Hour (2026-07-16)OkFlushErrorError %
06:002,97128,56390.6
07:0044,823301,92687.1
08:0046,536306,64586.8
09:0044,445327,60988.1
10:0070,235345,76783.1
11:0082,495404,23483.1
12:00105,065464,93281.6
13:00105,948538,90783.6
14:0096,541520,22884.3
-

-Cross-check passed: average flush success ≈ 15% ⇔ measured ClickHouse coverage ≈ 15% ⇔ observed ×7 -gap. The render-server scenario is fully explained by this failure, with no residual unexplained loss. (Earlier -single-node reads of these tables understated the picture — system.* tables are per-node; always query via -clusterAllReplicas.) -

- -

Anatomy of the silent failure — why "OK" is returned before the data is stored

-

-The crucial detail is ordering: the failure does not happen when the insert “hits” a readonly replica — -ClickHouse does not check replica writability when accepting rows into the async-insert buffer. The acknowledgment fires -before the step that fails: -

-
-
Kafka consumer issues INSERT → LB (clickhouse-…-ch service) picks 1 of 6 nodes round-robin - consumer-metrics.yaml · exporter endpoint
-
↓
-
Async-insert buffer accepts the rows → “OK” is returned here. - With wait_for_async_insert=0, “OK” means buffered, not stored — even on a node whose - replica has been readonly for months.
-
↓  both durability signals fire NOW, before the write is attempted:
-
otelcol_exporter_sent_metric_points++ ✅  ·  Kafka offset committed ✅ - message_marking.after=true — the data can no longer be reprocessed
-
↓  ~200 ms later, server-side background flush
-
Real INSERT into otel_metrics_sum (+ MV push to telemetry.metrics). - On a readonly replica: commitPart → error 242 “Table is in readonly mode” → retried 20× with - backoff → burns the 24 s budget → FlushError (TIMEOUT_EXCEEDED) - text_log: ZooKeeperRetriesControl: commitPart: will retry due to error … retry_count=N/20
-
↓
-
Rows discarded — permanently. The failure is recorded only in - system.asynchronous_insert_log and the server text_log. Upstream, everything reads as success: - send_failed = 0, queue empty, offsets advancing.
-
-

-This ordering is the entire incident in miniature: with wait_for_async_insert=1, the very same error 242 would -travel back through the INSERT call → the exporter would see a real failure → its retry (already enabled, 120 s -budget) would re-send — likely landing on the writable node via the LB — and on exhaustion the Kafka offset would -not be committed, so the data would be redelivered instead of forgotten. One query-string flag separates -“self-healing” from “silent 85% loss”. (Note the measured loss is ~85%, not exactly 5/6 ≈ 83%: during the storm, -flushes on the writable node also partially failed, since one replica absorbed the whole cluster’s writes plus -the retry traffic.) -

- -

-So the gap is not app-side coverage and not per-worker inflation: it is a -Keeper-session/read-only incident on the replicated metrics tables, turned into permanent data loss by a -fire-and-forget write path. The upstream producer adds a second latent instance of the same anti-pattern — Kafka -required_acks: 0 with retry_on_failure: false (producer.yaml) — where broker-side loss -would likewise never be counted. Both are invisible by construction, which is why the earlier “counters look clean” reading -was misleading. -

- -

What this does to the §6 verdict

-

-It sharpens it rather than contradicting it. §6 already carves out workers: 1 as the case -where Prometheus is the gold standard; render-server is exactly that case, and here Prometheus is the -closer-to-reality source while ClickHouse under-reports ~7×. The general claim “diagnostics is the floor” still -holds — ClickHouse never invented traffic, it lost it — but this shows the floor can sit far below reality when -the pipeline drops data, so “ClickHouse is closer to reality” is only safe after a coverage check like this one. -For multi-worker apps both effects stack: Prometheus inflates (§3) and ClickHouse under-counts. -

- -

-Method: clickhouse-client → telemetry.metrics_distributed (read-api user, obs-cluster -port-forward) for the diagnostics side; kubectl port-forward to live 8.180.1 pods’ /metrics:5050 -for the Prometheus side (port 5000 serves the Go process runtime metrics). Single-worker confirmed from the pod spec -(VTEX_SELF_CPU_LIMIT=1) and the monotonic counter. Like-for-like scope note: the render-server panel query -handler!~"builtin:.*|undefined" already excludes healthchecks and undefined, so the matching -ClickHouse query keeps None/public-handler:render/public-handler:redirect and drops -builtin:healthcheck. -

-
- - -

9. Recommendations

-
-
    -
  1. Fix the Prometheus export (root cause #1): aggregate across workers with prom-client’s - AggregatorRegistry — workers push to the master over the existing cluster IPC, the master serves a single - merged, monotonic /metrics. Until then, treat PromQL over these counters as unreliable for - workers > 1.
    2. -
  2. Make worker identity explicit in diagnostics: add a per-process component - (cluster.worker.id or PID) to service.instance.id / resource attributes in - @vtex/diagnostics-nodejs. ClickHouse tolerates the collision today; nothing else will.
    3. -
  3. Control the cardinality budget: either raise aggregationCardinalityLimit deliberately via a - View for the request instruments, or move vtex.account.name off the hot counter (log-based accounting, or a - bounded top-N attribute). Alert on otel.metric.overflow="true" volume so silent truncation becomes visible.
    4. -
  4. Track fleet delta-adoption: the collectors drop all non-delta datapoints - (filter/temporality), so every app on a pre-65e50da7 @vtex/api is invisible in - diagnostics. Publish the list of apps present in telemetry.metrics vs. apps serving traffic, and drive - upgrades — until then, cross-app diagnostics dashboards under-report by construction. Also fix the raw tables’ TTL - expression (toDate(TimeUnix) + 6h → rolling window) if raw-layer debugging is meant to be possible.
    5. -
  5. Watch delta export health: surface exporter failures (SDK diag logs) as a metric/alert; with delta - temporality every failure is permanent data loss.
    6. -
  6. Close the fire-and-forget write path (root cause of the §8 gap): the metrics consumer writes with - async_insert=1&wait_for_async_insert=0 and commits Kafka offsets after hand-off - (message_marking.after=true), so any ClickHouse flush failure is silent and permanent. Set - wait_for_async_insert=1 (or only commit offsets after a durable insert) so failures surface in - otelcol_exporter_send_failed_metric_points and get retried/reprocessed. Likewise reconsider producer Kafka - required_acks: 0 + retry_on_failure: false. Alert on system.replicas.is_readonly - and asynchronous_insert_log FlushError rate for otel_metrics_sum/histogram - — a Keeper-session/read-only incident there currently drops 100% of Sum/Histogram inserts while gauges and logs are fine.
    7. -
  7. Standardize the comparison: a shared dashboard with per-minute buckets, identical scope - (app version, workspace, production) and identical handler exclusions on both sides — including the overflow bucket in - the ClickHouse total.
    8. -
- -

9.1a — ClickHouse remediation runbook for the 2026-07-16 incident diagnosis verified live

-

Verified failure topology (2026-07-16, clusterAllReplicas): the MV target -telemetry.metrics is healthy on all 6 nodes; the raw tables are read-only on 10 of 12 replica -instances, leaving exactly one writable replica per table cluster-wide -(otel_metrics_sum: only 0-2-0; otel_metrics_histogram: only 1-2-0). -Every readonly replica shows absolute_delay ≈ epoch (never re-attached since the cluster restart ~5.7 days -ago), while node-level Keeper sessions are healthy and the table znodes are intact -(/clickhouse/tables/{shard}/otel/otel_metrics_sum/replicas lists all 3 replicas). Mechanics of the errors:

-
    -
  • Inserts hitting a readonly node fail instantly → the TABLE_IS_READ_ONLY ≈ 1.94M in system.errors; - the collector’s retry eventually lands on the single writable replica.
    • -
  • That one node absorbs the entire cluster’s metrics insert load; the MV’s heavy per-insert - GROUP BY+mapFilter+sumState then exceeds the 24 s flush budget → the - Timeout exceeded … while pushing to view otel.metrics_sum_view FlushErrors (~85%).
    • -
  • Side effect: readonly replicas can’t merge, so TTL cleanup stopped — e.g. 845M stale rows parked in - otel_metrics_sum on 0-0-0/0-1-0 vs ~552k on the healthy replica.
    • -
- - -

Baseline snapshots — captured 2026-07-16, before remediation

-
- Grafana panel: HTTP Requests Total per Handler for vtex.render-server@8.180.1, last hour. The 200/public-handler:render series swings wildly between roughly 5K and 53K req/m instead of a stable rate. -
- Diagnostics dashboard during the incident — “HTTP Requests Total per Handler” - (vtex.render-server@8.180.1, last hour). The ClickHouse-fed series swings ~5K–53K req/m minute-to-minute: - the visible average is the ~15% of flushes that survive (§8), and the jitter is flush success coming and going in - bursts — not real traffic shape. Expected steady total after the fix: ~25–30K req/m for the 200/render series alone. -
-
-
- ClickHouse query UI: clusterAllReplicas query over system.replicas listing otel_metrics tables; histogram and sum rows show is_readonly=1 with absolute_delay 1784215619 highlighted, gauge rows healthy. -
- Pre-remediation replica state — the §9.1a Step 2 verification query, run against - clickhouse-vtex-io.vtex.systems: all otel_metrics_gauge replicas healthy, while - otel_metrics_histogram and otel_metrics_sum show 10× is_readonly=1 with - absolute_delay = 1784215619 (≈ epoch “now” — never synced). This is the baseline the recreate - procedure (Step 1b) must clear: the same query should return is_readonly=0, absolute_delay≈0 - on all 18 rows. -
-
- -
- ClickHouse UI: 36-row replica health matrix from clusterAllReplicas over system.replicas with derived status column. otel_logs, otel_metrics_gauge, telemetry.logs and telemetry.metrics replicas all show running; otel_metrics_histogram and otel_metrics_sum show five readonly replicas each (init failed or session expired) with delay 1784216763, one running replica per table. -
- Full replica-health matrix, pre-remediation — the health query with derived - status verdict, run in the ClickHouse UI (36 rows, all replicated tables). Healthy across the board - (otel_logs, otel_metrics_gauge, telemetry.logs, telemetry.metrics: - 6/6 running) — except the two victim tables: otel_metrics_histogram running only on - …1-2-0, otel_metrics_sum only on …0-2-0, each with 5 replicas readonly - (mix of init failed = intersecting parts, and session expired = never re-attached), - delay_s = 1784216763 (≈ epoch “now”, i.e. never synced). Success criterion after Step 1b: all 36 rows - running. -
-
- - -

Step 1 — restore write capacity. tried 2026-07-16 15:11 — insufficient -The first attempt was SYSTEM RESTART REPLICA on each readonly node:

-
SYSTEM RESTART REPLICA otel.otel_metrics_sum;
-SYSTEM RESTART REPLICA otel.otel_metrics_histogram;
-

Validation showed it does not stick: the commands completed cleanly (system.query_log: -QueryFinish, no exception) but the replicas re-entered readonly immediately. The attach thread logs the real -blocker — intersecting data parts, i.e. local part corruption that predates the incident by months:

-
-- text_log, chi-…-1-0-0, 15:11:04 (otel_metrics_sum — partition 2026-03-06!)
-Initialization failed, table will remain readonly. Error: Code: 49. DB::Exception:
-Part 20260306_693980_694637_21 intersects part 20260306_693981_694478_67.
-It is a bug or a result of manual intervention in the ZooKeeper data. (LOGICAL_ERROR)
-
--- text_log, chi-…-0-2-0, 15:13:00 (otel_metrics_histogram — partition 2026-04-17)
-Part 20260417_189038_288174_35 intersects part 20260417_275192_276314_212.
-

The partition names (March/April 2026) prove these replicas have been broken — and not merging/TTL-cleaning — for -months; the 845M stale rows are the debris. SYSTEM RESTORE REPLICA does not apply (Keeper metadata is intact); -detaching intersecting parts one-by-one is impractical (2,079 “unexpected parts” on one replica alone).

- -

Step 1b — recreate each broken replica (deterministic, and cheap: the raw tables hold only ~6 h by -design — the durable store is telemetry.metrics, which is healthy). One replica at a time:

-
-- 0. capture the authoritative DDL once, from a healthy node:
-SHOW CREATE TABLE otel.otel_metrics_sum;   -- uses {shard}/{replica} macros
-
--- 1. on the BROKEN node: drop local data + this replica's znode
-DROP TABLE otel.otel_metrics_sum SYNC;
-
---    (only if the znode survives the drop, clean it from a healthy node:)
-SYSTEM DROP REPLICA 'chi-clickhouse-vtex-io-ch-cluster-1-0' FROM TABLE otel.otel_metrics_sum;
-
--- 2. on the BROKEN node: recreate with the captured DDL — WITHOUT "ON CLUSTER"
-CREATE TABLE otel.otel_metrics_sum ( … ) ENGINE = ReplicatedMergeTree( … ) … ;
---    macros resolve per node → registers as a fresh replica → fetches only the recent ~6h
-
--- 3. verify before moving to the next replica:
-SELECT is_readonly, absolute_delay FROM system.replicas WHERE table='otel_metrics_sum';
-

Notes: keep the currently-writable replica (0-2-0 for sum, 1-2-0 for histogram) untouched until -last; the MV dependency survives the recreate (it binds by name); expect the recreated replica to start near-empty — that -is correct for a 6 h-TTL raw table.

- -

Step 2 — verify recovery (should show 12/12 writable, then FlushError → ~0 within minutes). Also watch -for the Keeper ensemble health — during the incident all three Keeper nodes showed degraded latency -(avg ~270–300 ms, max 7–14 s vs the ~1 ms norm), consistent with the insert retry storms; it should normalize once -inserts stop hammering readonly replicas:

-
-- replica-health matrix with verdict (the query shown in the baseline screenshot)
-SELECT hostName() AS host, database, table, is_readonly, is_session_expired,
-       active_replicas, total_replicas,
-       if(absolute_delay > 4e9, 'never', toString(absolute_delay)) AS delay_s,
-       queue_size,
-       multiIf(is_readonly = 0 AND absolute_delay < 60, 'running',
-               is_readonly = 0,                         'attached, lagging',
-               is_session_expired = 1,                  'readonly (session expired)',
-                                                        'readonly (init failed)') AS status
-FROM clusterAllReplicas('cluster', system.replicas)
-ORDER BY database, table, host;
-
--- one-line summary per table — watch during the procedure (goal: readonly = 0 everywhere)
-SELECT database, table, countIf(is_readonly = 0) AS running, countIf(is_readonly = 1) AS readonly
-FROM clusterAllReplicas('cluster', system.replicas)
-GROUP BY database, table ORDER BY readonly DESC;
-
-SELECT toStartOfFiveMinutes(event_time) b, status, count()
-FROM clusterAllReplicas('cluster', system.asynchronous_insert_log)
-WHERE database='otel' AND table='otel_metrics_sum' AND event_time > now() - INTERVAL 30 MINUTE
-GROUP BY b, status ORDER BY b;
-

Expect merges/TTL to resume on the recovered replicas (the 845M stale raw rows should drain), and diagnostics coverage -to climb from ~15% back toward ~100% — re-run the §8 healthcheck calibration to confirm -(expected fleet hc/min ≈ pods × 30).

- -

Step 3 — stop the silent-loss pattern (config, o11y-platform repo):

-
# provisioning/vtex-io/collectors/consumer-metrics.yaml — clickhouse exporter endpoint
--  …&async_insert=1&wait_for_async_insert=0&async_insert_busy_timeout_ms=200
-+  …&async_insert=1&wait_for_async_insert=1&async_insert_busy_timeout_ms=200
-#  → flush failures now fail the INSERT → exporter retries (already enabled) → Kafka offset
-#    NOT committed (message_marking.on_error=false) → data reprocessed instead of lost.
-#    Consider timeout: 20s → 35s so the exporter outlives the 24s MV-push budget.
-
-# provisioning/vtex-io/collectors/producer.yaml — kafka/metrics exporter
--  producer: { required_acks: 0 }   retry_on_failure: { enabled: false }
-+  producer: { required_acks: 1 }   retry_on_failure: { enabled: true }
- -

Step 4 — alerts so this cannot run silent for 8 hours again:

-
    -
  • max(is_readonly) over clusterAllReplicas('cluster', system.replicas) > 0 for 5 min → page.
    • -
  • FlushError / (Ok+FlushError) from system.asynchronous_insert_log (metrics tables) > 1% for 15 min → page.
    • -
  • absolute_delay > 300 s on any otel replica → warn.
    • -
  • Watch the MV-push duration headroom: if Timeout exceeded … pushing to view reappears with all replicas - writable, the MV itself is the bottleneck — then consider parallel_view_processing=1 for the insert user, - a larger flush budget, or trimming the MV’s mapFilter/GROUP BY width.
    • -
-
- - -

Appendix — evidence index

- - - - - - - - - - - - - - - - - - - - - - - - - - -
FactWhere
Both middlewares mounted adjacently; increments in finally, once per requestsrc/service/worker/index.ts:228–229 · requestMetricsMiddleware.ts:43 · otelRequestMetricsMiddleware.ts:64
Master forks min(cpus, 4) workers sharing port 5000; no cross-worker registry aggregationsrc/service/master.ts:89 · src/service/loaders.ts:19–28 · src/constants.ts:164 · src/service/index.ts:31
/metrics serves the per-process default prom-client registrysrc/service/worker/runtime/builtIn/middlewares.ts:24–44
OTel exporter: OTLP gRPC, delta temporality, 60 s interval/timeoutsrc/service/telemetry/client.ts:61–69 · @vtex/diagnostics-nodejs dist/exporters/otlp.js:51–72
Default cardinality limit 2000 with otel.metric.overflow fold-in@opentelemetry/sdk-metrics@1.30.1 build/src/state/DeltaMetricProcessor.js:35–45
service.instance.id has no per-worker component@vtex/diagnostics-nodejs dist/discovery/resource-discovery.js:167–179
No-op client when telemetry flag is off; 500 ms instrument race skips countingsrc/service/telemetry/client.ts:95 · src/service/metrics/otelRequestMetricsMiddleware.ts:6,29–34
Account attribute only on the OTel counter, not the prom counterotelRequestMetricsMiddleware.ts:69 vs tracing/metrics/MetricNames.ts:30–35
Timeline: interval bump / account attribute / delta switchcommits d122a999 (2025-12-04) · 3f65ab73 (2025-12-16) · 65e50da7 (2025-12-16)
ClickHouse schema: raw OTel tables (TTL toDate(TimeUnix)+6h), per-minute MV, - production derived from workspace.type, Count = sumState(1) per datapoint, - Attributes passed through minus device/process.pido11y-platform read-api/clickhouse-sql/schemas/3-metrics.sql:81,229–279
Collectors drop all non-delta datapoints (no cumulativetodelta in pipeline); aggressive consumer - memory_limitero11y-platform provisioning/vtex-io/collectors/producer.yaml:221,263 · - consumer-metrics.yaml:234,323–332
Field validation (§8): single-worker app (VTEX_SELF_CPU_LIMIT=1 ⇒ 1 worker) has a monotonic - /metrics counter (Mechanism #1 absent) yet ClickHouse under-reports the 1,384-pod / 7-cluster fleet - ~7× via healthcheck calibration (~30/min/pod × 1,384 ≈ 41.5k/min expected vs ~6k/min in ClickHouse); telemetry flag - on and OTLP endpoint uniform across clusters → loss is downstream. Root-caused: otel_metrics_sum/ - otel_metrics_histogram replicas is_readonly=1/session_expired (0 active replicas) - and consumer writes fire-and-forget (wait_for_async_insert=0, offset committed on hand-off) → 100% - metrics FlushError in system.asynchronous_insert_log (last 3h, 544,705 attempts), silent to collector countersvtex.render-server@8.180.1 · pods /metrics:5050 (7 iostore clusters, us-east-1) · - telemetry.metrics_distributed (read-api) (2026-07-16)
- -

-Generated as part of the metrics-discrepancy investigation on the node-vtex-api repository. -The §3 chart uses synthetic data (parameters stated inline) to illustrate a mechanism verified in code; all -production-magnitude claims are marked “needs data check” with the exact query to run. -

- -
- - From 5d952ae4b5ca82ddcaef1267a3079d0d79bad1e3 Mon Sep 17 00:00:00 2001 From: Denis Silva Date: Wed, 22 Jul 2026 16:35:15 -0300 Subject: [PATCH 4/5] chore(metrics): address PR review feedback and fix SonarQube gate Review comments: - spec: drop redundant task-id/branch metadata lines; mark Status accepted now that the implementation ships in this PR - clusterMetricsAggregator: use optional chaining in the message type guards - worker/index: pass an explicit callback and initial value to .reduce() instead of the bare mergeDeepRight function SonarQube quality gate: - raise new-code coverage: clusterMetricsAggregator.ts to 100% (registry lifecycle + error/fallback paths) and cover the new master/worker IPC onMessage branches via exported handlers Co-authored-by: Cursor --- ...-prom-client-metrics-across-cluster-wor.md | 7 +-- src/service/__tests__/master.test.ts | 30 +++++++++++++ src/service/master.ts | 2 +- .../clusterMetricsAggregator.test.ts | 44 +++++++++++++++++++ .../metrics/clusterMetricsAggregator.ts | 6 +-- .../worker/__tests__/onMessage.test.ts | 28 ++++++++++++ src/service/worker/index.ts | 4 +- 7 files changed, 110 insertions(+), 11 deletions(-) create mode 100644 src/service/__tests__/master.test.ts create mode 100644 src/service/worker/__tests__/onMessage.test.ts diff --git a/specs/aggregate-prom-client-metrics-across-cluster-wor.md b/specs/aggregate-prom-client-metrics-across-cluster-wor.md index 99fc21d84..f4f93297a 100644 --- a/specs/aggregate-prom-client-metrics-across-cluster-wor.md +++ b/specs/aggregate-prom-client-metrics-across-cluster-wor.md @@ -1,10 +1,7 @@ # Spec: Aggregate prom-client metrics across cluster workers for `/metrics` -Internal task id: task-58ee1acb (bean) -Branch: `night/aggregate-prom-client-metrics-across-cluster-wor` - -> **Status: specification only.** This document describes the planned change. No -> implementation is included in this PR yet. +> **Status: accepted.** This document describes the change, which is implemented +> in this PR. --- diff --git a/src/service/__tests__/master.test.ts b/src/service/__tests__/master.test.ts new file mode 100644 index 000000000..08afe4978 --- /dev/null +++ b/src/service/__tests__/master.test.ts @@ -0,0 +1,30 @@ +import { Worker } from 'cluster' + +import * as aggregator from '../metrics/clusterMetricsAggregator' +import { AGG_METRICS_REQ } from '../metrics/clusterMetricsAggregator' +import { onMessage } from '../master' + +describe('master onMessage', () => { + const worker = { process: { pid: 123 }, send: jest.fn() } as unknown as Worker + + afterEach(() => { + jest.restoreAllMocks() + }) + + it('routes aggregate metric requests from workers to the aggregation handler', () => { + const spy = jest.spyOn(aggregator, 'handleWorkerMetricsRequest').mockResolvedValue(undefined) + const message = { id: 1, type: AGG_METRICS_REQ } + + onMessage(worker, message) + + expect(spy).toHaveBeenCalledTimes(1) + expect(spy).toHaveBeenCalledWith(worker, message) + }) + + it('ignores prom-client cluster protocol messages without invoking the handler', () => { + const spy = jest.spyOn(aggregator, 'handleWorkerMetricsRequest') + + expect(() => onMessage(worker, { type: 'prom-client:getMetricsReq' })).not.toThrow() + expect(spy).not.toHaveBeenCalled() + }) +}) diff --git a/src/service/master.ts b/src/service/master.ts index 2e21c891d..cf195ff34 100644 --- a/src/service/master.ts +++ b/src/service/master.ts @@ -15,7 +15,7 @@ import { ServiceJSON } from './worker/runtime/typings' let handledSignal: NodeJS.Signals | undefined -const onMessage = (worker: Worker, message: any) => { +export const onMessage = (worker: Worker, message: any) => { if (isLog(message)) { logOnceToDevConsole(message.message, message.level) } else if (isStatusTrackBroadcast(message)) { diff --git a/src/service/metrics/__tests__/clusterMetricsAggregator.test.ts b/src/service/metrics/__tests__/clusterMetricsAggregator.test.ts index 4cf1cf792..b20c51163 100644 --- a/src/service/metrics/__tests__/clusterMetricsAggregator.test.ts +++ b/src/service/metrics/__tests__/clusterMetricsAggregator.test.ts @@ -5,8 +5,10 @@ import { AGG_METRICS_REQ, AGG_METRICS_RES, AggMetricsResMessage, + ensureWorkerAggregatorRegistry, handleMasterMetricsResponse, handleWorkerMetricsRequest, + initMasterAggregatorRegistry, isAggMetricsRequest, isAggMetricsResponse, isPromClientMessage, @@ -58,6 +60,22 @@ describe('clusterMetricsAggregator', () => { delete (process as any).send }) + describe('registry lifecycle', () => { + it('creates the master aggregator registry once (idempotent)', () => { + const first = initMasterAggregatorRegistry() + const second = initMasterAggregatorRegistry() + expect(first).toBeInstanceOf(AggregatorRegistry) + expect(second).toBe(first) + }) + + it('creates the worker aggregator registry once (idempotent)', () => { + const first = ensureWorkerAggregatorRegistry() + const second = ensureWorkerAggregatorRegistry() + expect(first).toBeInstanceOf(AggregatorRegistry) + expect(second).toBe(first) + }) + }) + describe('message guards', () => { it('recognizes aggregate request/response and prom-client messages', () => { expect(isAggMetricsRequest({ id: 1, type: AGG_METRICS_REQ })).toBe(true) @@ -182,6 +200,14 @@ describe('clusterMetricsAggregator', () => { const body = await requestAggregatedMetrics() expect(typeof body).toBe('string') }) + + it('falls back to the local registry when process.send throws', async () => { + ;(process as any).send = () => { + throw new Error('ipc channel closed') + } + const body = await requestAggregatedMetrics() + expect(typeof body).toBe('string') + }) }) describe('master request handler', () => { @@ -195,5 +221,23 @@ describe('clusterMetricsAggregator', () => { // No cluster workers in the test process → prom-client aggregates to ''. expect(typeof reply.body).toBe('string') }) + + it('replies with an error when the cluster aggregation fails', async () => { + const clusterMetricsSpy = jest + .spyOn(AggregatorRegistry.prototype, 'clusterMetrics') + .mockRejectedValue(new Error('collection failed')) + const worker: any = { send: jest.fn() } + + await handleWorkerMetricsRequest(worker, { id: 3, type: AGG_METRICS_REQ }) + + expect(clusterMetricsSpy).toHaveBeenCalledTimes(1) + const reply = worker.send.mock.calls[0][0] + expect(reply.type).toBe(AGG_METRICS_RES) + expect(reply.id).toBe(3) + expect(reply.error).toBe('collection failed') + expect(reply.body).toBeUndefined() + + clusterMetricsSpy.mockRestore() + }) }) }) diff --git a/src/service/metrics/clusterMetricsAggregator.ts b/src/service/metrics/clusterMetricsAggregator.ts index f0ea0528b..c479e4bb6 100644 --- a/src/service/metrics/clusterMetricsAggregator.ts +++ b/src/service/metrics/clusterMetricsAggregator.ts @@ -44,10 +44,10 @@ export interface AggMetricsResMessage { } export const isAggMetricsRequest = (message: any): message is AggMetricsReqMessage => - message != null && message.type === AGG_METRICS_REQ && typeof message.id === 'number' + message?.type === AGG_METRICS_REQ && typeof message?.id === 'number' export const isAggMetricsResponse = (message: any): message is AggMetricsResMessage => - message != null && message.type === AGG_METRICS_RES && typeof message.id === 'number' + message?.type === AGG_METRICS_RES && typeof message?.id === 'number' /** * prom-client's cluster protocol emits its own tagged IPC messages @@ -56,7 +56,7 @@ export const isAggMetricsResponse = (message: any): message is AggMetricsResMess * ignore them instead of warning about "unknown" messages. */ export const isPromClientMessage = (message: any): boolean => - message != null && typeof message.type === 'string' && message.type.startsWith('prom-client:') + typeof message?.type === 'string' && message.type.startsWith('prom-client:') // --------------------------------------------------------------------------- // Master side diff --git a/src/service/worker/__tests__/onMessage.test.ts b/src/service/worker/__tests__/onMessage.test.ts new file mode 100644 index 000000000..33621afb5 --- /dev/null +++ b/src/service/worker/__tests__/onMessage.test.ts @@ -0,0 +1,28 @@ +import * as aggregator from '../../metrics/clusterMetricsAggregator' +import { AGG_METRICS_RES } from '../../metrics/clusterMetricsAggregator' +import { onMessage } from '../index' + +describe('worker onMessage', () => { + const handle = onMessage({} as any) + + afterEach(() => { + jest.restoreAllMocks() + }) + + it('routes aggregate metric responses from the master to the aggregation handler', () => { + const spy = jest.spyOn(aggregator, 'handleMasterMetricsResponse').mockReturnValue(undefined) + const message = { body: 'AGGREGATED', id: 1, type: AGG_METRICS_RES } + + handle(message) + + expect(spy).toHaveBeenCalledTimes(1) + expect(spy).toHaveBeenCalledWith(message) + }) + + it('ignores prom-client cluster protocol messages without invoking the handler', () => { + const spy = jest.spyOn(aggregator, 'handleMasterMetricsResponse') + + expect(() => handle({ type: 'prom-client:getMetricsRes' })).not.toThrow() + expect(spy).not.toHaveBeenCalled() + }) +}) diff --git a/src/service/worker/index.ts b/src/service/worker/index.ts index 1de57eff9..51218b60e 100644 --- a/src/service/worker/index.ts +++ b/src/service/worker/index.ts @@ -78,7 +78,7 @@ const upSignal = () => { const isUpSignal = (message: any): message is typeof UP_SIGNAL => message === UP_SIGNAL -const onMessage = (service: ServiceJSON) => (message: any) => { +export const onMessage = (service: ServiceJSON) => (message: any) => { if (isUpSignal(message)) { upSignal() logAvailableRoutes(service) @@ -268,7 +268,7 @@ export const startWorker = (serviceJSON: ServiceJSON) => { ] .filter(x => x != null) // TODO: Fix ramda typings. Apparently there was an update that broke things - .reduce(mergeDeepRight as any) + .reduce((acc, handler) => mergeDeepRight(acc, handler!), {}) if (httpHandlers?.pub) { const publicHandlersRouter = routerFromPublicHttpHandlers(httpHandlers.pub) From 80f6c374b03374322b246084019b2a55b110f384 Mon Sep 17 00:00:00 2001 From: Denis Silva Date: Wed, 22 Jul 2026 17:21:10 -0300 Subject: [PATCH 5/5] Bump package.json --- package.json | 2 +- 1 file changed, 1 insertion(+), 1 deletion(-) diff --git a/package.json b/package.json index 829761a1e..9fa1bded3 100644 --- a/package.json +++ b/package.json @@ -1,6 +1,6 @@ { "name": "@vtex/api", - "version": "7.4.0", + "version": "7.4.1-beta.1", "description": "VTEX I/O API client", "main": "lib/index.js", "typings": "lib/index.d.ts",