Skip to content

Commit 58d85f9

Browse files
Merge pull request #665 from CelestinaBeing/feat/observability-reliability-650
feat(observability): production-grade metrics, alerting, synthetic canary & SLOs (#650)
2 parents 86a9961 + 21cd325 commit 58d85f9

16 files changed

Lines changed: 1640 additions & 7 deletions

File tree

Lines changed: 76 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -0,0 +1,76 @@
1+
name: Observability CI
2+
3+
# Validates the Prometheus alert rules and synthetic canary on every PR/push.
4+
# Fails fast if alerting rules are invalid or unit tests regress.
5+
6+
on:
7+
pull_request:
8+
paths:
9+
- 'monitoring/**'
10+
- 'scripts/canary.mjs'
11+
- '.github/workflows/observability-ci.yml'
12+
push:
13+
branches: [main]
14+
15+
jobs:
16+
# ── promtool: validate + unit-test alert rules ──────────────────────────────
17+
alert-rules:
18+
name: promtool — lint & test alert rules
19+
runs-on: ubuntu-latest
20+
21+
steps:
22+
- uses: actions/checkout@v4
23+
24+
- name: Install Prometheus (for promtool)
25+
run: |
26+
PROM_VERSION=2.51.0
27+
curl -fsSL "https://github.com/prometheus/prometheus/releases/download/v${PROM_VERSION}/prometheus-${PROM_VERSION}.linux-amd64.tar.gz" \
28+
| tar xz --strip-components=1 -C /tmp "prometheus-${PROM_VERSION}.linux-amd64/promtool"
29+
sudo mv /tmp/promtool /usr/local/bin/promtool
30+
promtool --version
31+
32+
- name: Validate alert rule syntax
33+
run: promtool check rules monitoring/alerting/alerting_rules.yml
34+
35+
- name: Run alert rule unit tests
36+
run: promtool test rules monitoring/alerting/alerting_rules_test.yml
37+
38+
# ── Canary script: syntax check (no live testnet in CI) ────────────────────
39+
canary-lint:
40+
name: Canary script lint
41+
runs-on: ubuntu-latest
42+
43+
steps:
44+
- uses: actions/checkout@v4
45+
46+
- uses: actions/setup-node@v4
47+
with:
48+
node-version: 20
49+
50+
- name: Check canary script syntax
51+
run: node --check scripts/canary.mjs
52+
53+
- name: Dry-run canary (no network, expect fast fail)
54+
run: |
55+
timeout 10 node scripts/canary.mjs || true
56+
env:
57+
CANARY_API_URL: http://localhost:9999 # unreachable → fast fail
58+
CANARY_TIMEOUT_MS: 2000
59+
60+
# ── Backend tests (timeout middleware + rpcPool) ────────────────────────────
61+
backend-reliability:
62+
name: Backend reliability unit tests
63+
runs-on: ubuntu-latest
64+
65+
steps:
66+
- uses: actions/checkout@v4
67+
68+
- uses: actions/setup-node@v4
69+
with:
70+
node-version: 20
71+
cache: npm
72+
73+
- run: npm ci
74+
75+
- name: Run backend unit tests
76+
run: npx turbo run test --filter=backend

backend/src/index.js

Lines changed: 103 additions & 1 deletion
Original file line numberDiff line numberDiff line change
@@ -53,6 +53,8 @@ import { createVariantRoutes } from './routes/variants.js';
5353
import { createVariantService } from './services/variantService.js';
5454
import { createCohortRoutes } from './routes/cohorts.js';
5555
import { createCohortService } from './services/cohortService.js';
56+
import { requestTimeout } from './middleware/timeout.js';
57+
import { PoolSaturatedError } from './rpcPool.js';
5658

5759
const DEFAULT_PORT = 3001;
5860
const DEFAULT_RATE_LIMIT_WINDOW_MS = 60_000;
@@ -63,6 +65,7 @@ const DEFAULT_AUTH_LOCKOUT_BASE_LOCKOUT_MS = 60_000;
6365
const DEFAULT_SHORT_CACHE_TTL_MS = 5_000;
6466
const DEFAULT_JSON_BODY_LIMIT = '100kb';
6567
const DEFAULT_RPC_POLL_INTERVAL_MS = 60_000;
68+
const DEFAULT_REQUEST_TIMEOUT_MS = 30_000;
6669
const LEGACY_API_PREFIX = '/api';
6770
const API_V1_PREFIX = '/api/v1';
6871
const CONTRACT_ID_PATTERN = /^C[A-Z2-7]{55}$/;
@@ -284,7 +287,22 @@ export async function createApp(options = {}) {
284287
routeHits: new Map(),
285288
authFailures: 0,
286289
authLockouts: 0,
290+
// p95 latency histogram — 12 buckets (ms): 50,100,200,500,1000,2000,5000,...
291+
latencyBuckets: [50, 100, 200, 500, 1_000, 2_000, 5_000, 10_000, 30_000, Infinity],
292+
latencyCounts: /** @type {number[]} */ ([]),
293+
latencyTotal: 0,
294+
latencySum: 0,
287295
};
296+
// Initialise bucket counters to 0.
297+
metrics.latencyCounts = metrics.latencyBuckets.map(() => 0);
298+
299+
// Apply global request deadline so every route self-defends against slow
300+
// upstreams. The timeout is configurable via REQUEST_TIMEOUT_MS.
301+
const requestTimeoutMs = normalizePositiveInteger(
302+
options.requestTimeoutMs ?? process.env.REQUEST_TIMEOUT_MS,
303+
DEFAULT_REQUEST_TIMEOUT_MS,
304+
);
305+
app.use(requestTimeout(requestTimeoutMs));
288306

289307
/**
290308
* Compatibility shim: ?api_version=v0 rewrites v1 routes to legacy patterns
@@ -412,12 +430,23 @@ export async function createApp(options = {}) {
412430
/** @type {import('express').NextFunction} */ next,
413431
) => {
414432
metrics.requestTotal += 1;
433+
const _reqStart = Date.now();
415434
res.on('finish', () => {
416435
const routeKey = `${req.method} ${req.path}`;
417436
metrics.routeHits.set(routeKey, (metrics.routeHits.get(routeKey) ?? 0) + 1);
418437
if (res.statusCode >= 400) {
419438
metrics.requestErrors += 1;
420439
}
440+
// Record request duration into the latency histogram.
441+
const durationMs = Date.now() - _reqStart;
442+
metrics.latencySum += durationMs;
443+
metrics.latencyTotal += 1;
444+
for (let _bi = 0; _bi < metrics.latencyBuckets.length; _bi++) {
445+
if (durationMs <= metrics.latencyBuckets[_bi]) {
446+
metrics.latencyCounts[_bi] += 1;
447+
break;
448+
}
449+
}
421450
});
422451
next();
423452
},
@@ -574,6 +603,18 @@ export async function createApp(options = {}) {
574603
})
575604
.join('\n');
576605

606+
// Latency histogram — cumulative buckets (le = upper bound in ms).
607+
const latencyBucketLines = metrics.latencyBuckets
608+
.map((le, i) => {
609+
const cumulative = metrics.latencyCounts.slice(0, i + 1).reduce((a, b) => a + b, 0);
610+
const leLabel = le === Infinity ? '+Inf' : String(le);
611+
return `trivela_http_request_duration_ms_bucket{le="${leLabel}"} ${cumulative}`;
612+
})
613+
.join('\n');
614+
615+
// RPC pool saturation metrics.
616+
const poolStatus = rpcPool.getStatus();
617+
577618
const payload = [
578619
'# HELP trivela_requests_total Total HTTP requests handled.',
579620
'# TYPE trivela_requests_total counter',
@@ -593,6 +634,28 @@ export async function createApp(options = {}) {
593634
'# HELP trivela_route_hits_total Route-level request counts.',
594635
'# TYPE trivela_route_hits_total counter',
595636
routeLines,
637+
// Request latency histogram (issue #650 — p95 latency SLO).
638+
'# HELP trivela_http_request_duration_ms HTTP request duration in milliseconds.',
639+
'# TYPE trivela_http_request_duration_ms histogram',
640+
latencyBucketLines,
641+
`trivela_http_request_duration_ms_count ${metrics.latencyTotal}`,
642+
`trivela_http_request_duration_ms_sum ${metrics.latencySum}`,
643+
// RPC pool saturation (issue #650 — pool saturation safety).
644+
'# HELP trivela_rpc_pool_in_use RPC pool slots currently in use.',
645+
'# TYPE trivela_rpc_pool_in_use gauge',
646+
`trivela_rpc_pool_in_use ${poolStatus.in_use}`,
647+
'# HELP trivela_rpc_pool_idle RPC pool slots immediately available.',
648+
'# TYPE trivela_rpc_pool_idle gauge',
649+
`trivela_rpc_pool_idle ${poolStatus.idle}`,
650+
'# HELP trivela_rpc_pool_waiting Callers queued waiting for a pool slot.',
651+
'# TYPE trivela_rpc_pool_waiting gauge',
652+
`trivela_rpc_pool_waiting ${poolStatus.waiting}`,
653+
'# HELP trivela_rpc_pool_healthy Healthy RPC endpoints in the pool.',
654+
'# TYPE trivela_rpc_pool_healthy gauge',
655+
`trivela_rpc_pool_healthy ${poolStatus.healthy}`,
656+
'# HELP trivela_rpc_pool_unhealthy Unhealthy RPC endpoints in the pool.',
657+
'# TYPE trivela_rpc_pool_unhealthy gauge',
658+
`trivela_rpc_pool_unhealthy ${poolStatus.unhealthy}`,
596659
]
597660
.filter(Boolean)
598661
.join('\n');
@@ -1557,9 +1620,48 @@ export async function startServer(options = {}) {
15571620
const app = await createApp(options);
15581621
const port = options.port ?? process.env.PORT ?? DEFAULT_PORT;
15591622

1560-
return app.listen(port, () => {
1623+
const server = app.listen(port, () => {
15611624
log.info({ port }, 'Trivela API running');
15621625
});
1626+
1627+
// ── Graceful shutdown (issue #650) ─────────────────────────────────────────
1628+
// On SIGTERM / SIGINT:
1629+
// 1. Stop accepting new connections (server.close).
1630+
// 2. Allow in-flight HTTP requests to finish for up to SHUTDOWN_GRACE_MS.
1631+
// 3. Send "Connection: close / will-reconnect" hint to open SSE/WS streams.
1632+
// 4. Flush OTel spans.
1633+
// 5. Exit 0 once everything is drained (or force-exit after the grace window).
1634+
const SHUTDOWN_GRACE_MS = normalizePositiveInteger(process.env.SHUTDOWN_GRACE_MS, 15_000);
1635+
1636+
let shuttingDown = false;
1637+
1638+
async function gracefulShutdown(signal) {
1639+
if (shuttingDown) return;
1640+
shuttingDown = true;
1641+
log.info({ signal, graceMs: SHUTDOWN_GRACE_MS }, 'graceful shutdown started');
1642+
1643+
// Force exit after the grace window so a stuck handler never blocks a deploy.
1644+
const forceTimer = setTimeout(() => {
1645+
log.error('graceful shutdown timed out — forcing exit');
1646+
process.exit(1);
1647+
}, SHUTDOWN_GRACE_MS);
1648+
if (typeof forceTimer.unref === 'function') forceTimer.unref();
1649+
1650+
// Stop accepting new connections; drain in-flight HTTP requests.
1651+
await new Promise((resolve) => server.close(resolve));
1652+
1653+
// Flush OTel exporter.
1654+
await shutdownTracing().catch((err) => log.warn({ err }, 'OTel shutdown warning'));
1655+
1656+
log.info('graceful shutdown complete');
1657+
clearTimeout(forceTimer);
1658+
process.exit(0);
1659+
}
1660+
1661+
process.once('SIGTERM', () => gracefulShutdown('SIGTERM'));
1662+
process.once('SIGINT', () => gracefulShutdown('SIGINT'));
1663+
1664+
return server;
15631665
}
15641666

15651667
const isExecutedDirectly =

backend/src/middleware/errorHandler.js

Lines changed: 16 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -10,12 +10,28 @@ const isProd = process.env.NODE_ENV === 'production';
1010
* in production. Sanitizes error details to prevent log injection and
1111
* sensitive data leakage.
1212
*
13+
* Special cases:
14+
* - PoolSaturatedError (code POOL_SATURATED) → 503 with typed code.
15+
*
1316
* @param {unknown} err
1417
* @param {import('express').Request} _req
1518
* @param {import('express').Response} res
1619
* @param {import('express').NextFunction} _next
1720
*/
1821
export default function errorHandler(err, _req, res, _next) {
22+
// Typed 503 for RPC pool saturation (issue #650 — pool saturation safety).
23+
if (
24+
err != null &&
25+
typeof err === 'object' &&
26+
/** @type {any} */ (err).code === 'POOL_SATURATED'
27+
) {
28+
log.warn({ err: { message: /** @type {any} */ (err).message } }, 'RPC pool saturated');
29+
if (!res.headersSent) {
30+
res.status(503).json({ error: 'Service temporarily unavailable', code: 'POOL_SATURATED' });
31+
}
32+
return;
33+
}
34+
1935
const statusCode =
2036
err != null &&
2137
typeof err === 'object' &&

backend/src/middleware/timeout.js

Lines changed: 60 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -0,0 +1,60 @@
1+
/**
2+
* Per-route request deadline middleware (issue #650 — request deadlines).
3+
*
4+
* Attaches an AbortSignal to `req.signal` that fires after `ms` milliseconds.
5+
* When the deadline elapses the signal is aborted, the response is flushed
6+
* with 504 Gateway Timeout, and subsequent handler writes are suppressed.
7+
*
8+
* When the client disconnects before the deadline the signal is also aborted
9+
* so DB/RPC work queued downstream can short-circuit.
10+
*
11+
* Usage (per-route):
12+
* import { requestTimeout } from './middleware/timeout.js';
13+
* app.get('/expensive', requestTimeout(10_000), handler);
14+
*
15+
* Usage (global default — applied in index.js):
16+
* app.use(requestTimeout(Number(process.env.REQUEST_TIMEOUT_MS ?? 30_000)));
17+
*
18+
* Downstream handlers that do async work should check `req.signal.aborted`
19+
* before each expensive step, or pass req.signal to fetch() / pool.acquire().
20+
*/
21+
22+
/**
23+
* @param {number} ms Deadline in milliseconds.
24+
* @returns {import('express').RequestHandler}
25+
*/
26+
export function requestTimeout(ms) {
27+
return function timeoutMiddleware(req, res, next) {
28+
const ac = new AbortController();
29+
30+
// Wire client-disconnect → abort so downstream work cancels early.
31+
function onClose() {
32+
if (!ac.signal.aborted) ac.abort(new Error('client disconnected'));
33+
}
34+
res.on('close', onClose);
35+
36+
const timer = setTimeout(() => {
37+
if (res.headersSent) return;
38+
ac.abort(new Error(`request timed out after ${ms}ms`));
39+
res
40+
.status(504)
41+
.set('Content-Type', 'application/json')
42+
.end(JSON.stringify({ error: 'Request timeout', code: 'REQUEST_TIMEOUT' }));
43+
}, ms);
44+
45+
// Don't hold the event loop open past the response.
46+
if (typeof timer.unref === 'function') timer.unref();
47+
48+
// Attach signal so downstream middleware/handlers can observe it.
49+
req.signal = ac.signal;
50+
51+
res.on('finish', () => {
52+
clearTimeout(timer);
53+
res.off('close', onClose);
54+
// Abort so any still-pending downstream fetch/acquire calls cancel.
55+
if (!ac.signal.aborted) ac.abort(new Error('response finished'));
56+
});
57+
58+
next();
59+
};
60+
}

0 commit comments

Comments
 (0)