diff --git a/backend/.env.example b/backend/.env.example index 6777ff34..9f29ead8 100644 --- a/backend/.env.example +++ b/backend/.env.example @@ -121,6 +121,12 @@ SANDBOX_ALLOW_QUERY_PARAM=true # Header name used to trigger sandbox mode (default: X-Sandbox-Mode) SANDBOX_HEADER_NAME=X-Sandbox-Mode +# ─── Health Check ───────────────────────────────────────────────────────────── +# Upper bound in milliseconds for each dependency probe in GET /health (DB, +# Redis, Soroban RPC). Probes run in parallel, so this is roughly the worst-case +# response time. Keep it below your orchestrator's probe timeout (default: 800) +HEALTHCHECK_TIMEOUT_MS=800 + # ─── Observability ──────────────────────────────────────────────────────────── # Prometheus scrape endpoint (GET /metrics). # Deny-by-default in production: the endpoint returns 404 unless at least one of diff --git a/backend/src/config/swagger.ts b/backend/src/config/swagger.ts index 7832fc29..cf9ac79e 100644 --- a/backend/src/config/swagger.ts +++ b/backend/src/config/swagger.ts @@ -444,8 +444,19 @@ See [Sandbox Mode Documentation](../docs/SANDBOX_MODE.md) for details.`, type: 'object', required: ['status', 'db', 'indexerEnabled', 'uptime', 'checks'], properties: { - status: { type: 'string', enum: ['ok', 'degraded'], example: 'ok' }, + status: { + type: 'string', + enum: ['ok', 'degraded'], + example: 'ok', + description: '`degraded` with HTTP 503 when a liveness check fails; `degraded` with HTTP 200 when only Redis is unavailable or timed out', + }, db: { type: 'string', enum: ['connected', 'disconnected'], example: 'connected' }, + redis: { + type: 'string', + enum: ['ok', 'unavailable', 'timeout', 'not_configured'], + example: 'ok', + description: 'Same as checks.redis.status', + }, indexerEnabled: { type: 'boolean', description: 'Whether the event indexer is configured' }, indexerLag: { type: 'integer', nullable: true, description: 'Seconds since last indexer update, or null when no state row exists yet' }, eventsProcessed: { type: 'integer', description: 'Lifetime count of successfully processed indexer events' }, @@ -459,7 +470,7 @@ See [Sandbox Mode Documentation](../docs/SANDBOX_MODE.md) for details.`, properties: { database: { type: 'object', - properties: { status: { type: 'string', enum: ['ok', 'down'] } }, + properties: { status: { type: 'string', enum: ['ok', 'down', 'timeout'] } }, }, indexer: { type: 'object', @@ -471,7 +482,7 @@ See [Sandbox Mode Documentation](../docs/SANDBOX_MODE.md) for details.`, }, redis: { type: 'object', - properties: { status: { type: 'string', enum: ['ok', 'unavailable', 'not_configured'] } }, + properties: { status: { type: 'string', enum: ['ok', 'unavailable', 'timeout', 'not_configured'] } }, }, sorobanRpc: { type: 'object', diff --git a/backend/src/lib/with-timeout.ts b/backend/src/lib/with-timeout.ts new file mode 100644 index 00000000..d982f144 --- /dev/null +++ b/backend/src/lib/with-timeout.ts @@ -0,0 +1,41 @@ +/** + * Generic promise timeout helper. + * + * `withTimeout` races a promise against a timer and rejects with a + * `TimeoutError` if the timer wins. It only stops *waiting*: the underlying + * operation keeps running, so callers should still configure their own client + * timeouts where the library supports them. + */ +export class TimeoutError extends Error { + readonly label: string; + readonly timeoutMs: number; + + constructor(label: string, timeoutMs: number) { + super(`${label} timed out after ${timeoutMs}ms`); + this.name = 'TimeoutError'; + this.label = label; + this.timeoutMs = timeoutMs; + } +} + +export async function withTimeout( + operation: PromiseLike, + timeoutMs: number, + label = 'operation', +): Promise { + const pending = Promise.resolve(operation); + // If the timer wins, `pending` may still reject later. Attach a no-op + // handler so that late rejection is never reported as unhandled. + pending.catch(() => undefined); + + let timer: ReturnType | undefined; + const timedOut = new Promise((_, reject) => { + timer = setTimeout(() => reject(new TimeoutError(label, timeoutMs)), timeoutMs); + }); + + try { + return await Promise.race([pending, timedOut]); + } finally { + clearTimeout(timer); + } +} diff --git a/backend/src/routes/health.routes.ts b/backend/src/routes/health.routes.ts index 7986457d..a2da3775 100644 --- a/backend/src/routes/health.routes.ts +++ b/backend/src/routes/health.routes.ts @@ -2,12 +2,105 @@ import { Router, type Request, type Response } from 'express'; import { prisma } from '../lib/prisma.js'; import { INDEXER_STATE_ID } from '../lib/indexer-state.js'; import { setIndexerLedgers } from '../lib/metrics.js'; -import { isRedisAvailable } from '../lib/redis.js'; -import { checkRpcHealth } from '../services/sorobanService.js'; +import { getPublisher } from '../lib/redis.js'; +import { TimeoutError, withTimeout } from '../lib/with-timeout.js'; +import { checkRpcHealth, getLatestLedger } from '../services/sorobanService.js'; import { sorobanEventWorker } from '../workers/soroban-event-worker.js'; +import logger from '../logger.js'; const router = Router(); +/** + * Upper bound for each dependency probe. Probes run in parallel, so the whole + * response takes roughly this long in the worst case. Kept below 1,000 ms to + * leave headroom for request handling and JSON serialisation (Issue #1492). + */ +export const DEFAULT_HEALTHCHECK_TIMEOUT_MS = 800; + +function getHealthcheckTimeoutMs(): number { + const parsed = Number(process.env.HEALTHCHECK_TIMEOUT_MS); + return Number.isInteger(parsed) && parsed > 0 ? parsed : DEFAULT_HEALTHCHECK_TIMEOUT_MS; +} + +type DatabaseStatus = 'ok' | 'down' | 'timeout'; +type RedisStatus = 'ok' | 'unavailable' | 'timeout' | 'not_configured'; +type IndexerState = Awaited>; + +// Last reported status per component, so failures are logged once when they +// start (and once on recovery) instead of on every probe. +const lastStatus = new Map(); + +function reportStatus(component: string, status: string, healthy: boolean): void { + const previous = lastStatus.get(component); + lastStatus.set(component, status); + if (previous === status || (previous === undefined && healthy)) return; + + if (healthy) { + logger.info(`[Health] ${component} recovered`, { status, previous }); + } else { + logger.warn(`[Health] ${component} check failing`, { status, previous: previous ?? null }); + } +} + +function errorMessage(err: unknown): string { + return err instanceof Error ? err.message : String(err); +} + +async function checkDatabase(timeoutMs: number): Promise { + try { + await withTimeout(prisma.$queryRaw`SELECT 1`, timeoutMs, 'database ping'); + return 'ok'; + } catch (err) { + logger.debug('[Health] database ping failed', { error: errorMessage(err) }); + return err instanceof TimeoutError ? 'timeout' : 'down'; + } +} + +async function checkRedis(timeoutMs: number): Promise { + // Redis is optional: without REDIS_URL the SSE layer runs in single-instance mode. + if (!process.env.REDIS_URL) return 'not_configured'; + + // Fast path: a client that is not connected cannot answer, so don't wait on it. + const client = getPublisher(); + if (!client || client.status !== 'ready') return 'unavailable'; + + try { + await withTimeout(client.ping(), timeoutMs, 'redis ping'); + return 'ok'; + } catch (err) { + logger.debug('[Health] redis ping failed', { error: errorMessage(err) }); + return err instanceof TimeoutError ? 'timeout' : 'unavailable'; + } +} + +async function readIndexerState(timeoutMs: number): Promise { + try { + return await withTimeout( + prisma.indexerState.findUnique({ where: { id: INDEXER_STATE_ID } }), + timeoutMs, + 'indexer state lookup', + ); + } catch { + return null; + } +} + +async function checkSorobanRpc(timeoutMs: number): Promise { + try { + return await withTimeout(checkRpcHealth(timeoutMs), timeoutMs, 'soroban rpc health'); + } catch { + return false; + } +} + +async function readNetworkLedger(timeoutMs: number): Promise { + try { + return await withTimeout(getLatestLedger(), timeoutMs, 'latest ledger lookup'); + } catch { + return 0; + } +} + /** * @openapi * /health: @@ -28,9 +121,15 @@ const router = Router(); * enabled and recent per-event failures spike (≥50% of attempts in the * last 5 minutes, with ≥3 samples), the endpoint returns 503 even if * lag looks healthy (the IndexerState upsert bumps updatedAt every poll). + * **Redis** is optional. When it is configured but unavailable or does not + * answer a ping in time, `status` is `degraded` but the response stays + * 200, so a Redis outage does not fail liveness probes. + * Every dependency probe runs in parallel and is bounded by + * `HEALTHCHECK_TIMEOUT_MS` (default 800 ms), so the endpoint answers in + * under a second even when a dependency hangs. * responses: * 200: - * description: Service is healthy + * description: Service is healthy (Redis may still be degraded) * content: * application/json: * schema: @@ -43,91 +142,72 @@ const router = Router(); * $ref: '#/components/schemas/HealthResponse' */ router.get('/', async (_req: Request, res: Response) => { - let dbStatus = 'connected'; - try { - await prisma.$queryRaw`SELECT 1`; - } catch { - dbStatus = 'disconnected'; - } + const timeoutMs = getHealthcheckTimeoutMs(); // Whether the event-indexer is configured (STREAM_CONTRACT_ID must be set for it to run). const indexerEnabled = !!process.env.STREAM_CONTRACT_ID; - let indexerLag = -1; - let state: Awaited> = null; - try { - state = await prisma.indexerState.findUnique({ where: { id: INDEXER_STATE_ID } }); - if (state) { - const now = Math.floor(Date.now() / 1000); - const updatedAt = Math.floor(state.updatedAt.getTime() / 1000); - indexerLag = Math.max(0, now - updatedAt); - } - // indexerLag === -1 means no state row yet (cold start) — not an error. - } catch { - indexerLag = -1; - } + // Probes are independent, so run them together: total time is bounded by + // the slowest probe (at most timeoutMs), not the sum. None of them reject. + const [database, state, redisStatus, sorobanRpcOk, networkLedger] = await Promise.all([ + checkDatabase(timeoutMs), + readIndexerState(timeoutMs), + checkRedis(timeoutMs), + checkSorobanRpc(timeoutMs), + // Resolve the network tip so ledger lag is reportable without waiting for + // the next indexer poll. Failure is non-fatal: lag degrades to null. + indexerEnabled ? readNetworkLedger(timeoutMs) : Promise.resolve(0), + ]); - // Resolve the network tip so ledger lag is reportable without waiting for the - // next indexer poll. Failure is non-fatal: lag degrades to null. - let networkLedger = 0; - if (indexerEnabled) { - try { - const { getLatestLedger } = await import('../services/sorobanService.js'); - networkLedger = await getLatestLedger(); - } catch { - networkLedger = 0; - } - } + const dbStatus = database === 'ok' ? 'connected' : 'disconnected'; + + // indexerLag === -1 means no state row yet (cold start) — not an error. + const indexerLag = state + ? Math.max(0, Math.floor(Date.now() / 1000) - Math.floor(state.updatedAt.getTime() / 1000)) + : -1; - // 503 only when: DB is down, OR the indexer is enabled and its state row is - // stale (lag > 60). A missing state row (lag === -1) is a cold-start - // condition, not a failure, even when the indexer is enabled. const eventCounters = sorobanEventWorker.getEventCounters(); - // 503 when: DB is down, OR the indexer is enabled and its state row is stale - // (lag > 60), OR recent event-processing failures are spiking. A missing state - // row (lag === -1) is a cold-start condition, not a failure, even when the - // indexer is enabled. + // 503 when: DB is down, OR the indexer is enabled and its state row is + // stale (lag > 60), OR recent event-processing failures are spiking. + // A missing state row (lag === -1) is a cold-start condition, not a failure, + // even when the indexer is enabled. const indexerLagDegraded = indexerEnabled && indexerLag > 60; const indexerFailureDegraded = indexerEnabled && eventCounters.degraded; - const isHealthy = - dbStatus === 'connected' && !indexerLagDegraded && !indexerFailureDegraded; - const status = isHealthy ? 'ok' : 'degraded'; - - // Redis is optional (single-instance SSE mode falls back gracefully when it's - // absent), so its status never affects the top-level `isHealthy` verdict. - const redisConfigured = !!process.env.REDIS_URL; - const redisStatus = !redisConfigured - ? 'not_configured' - : isRedisAvailable() - ? 'ok' - : 'unavailable'; - - // Soroban RPC reachability is reported for observability only — it does not - // gate liveness, since a transient RPC blip shouldn't take the service down. - const sorobanRpcOk = await checkRpcHealth(); + const isHealthy = database === 'ok' && !indexerLagDegraded && !indexerFailureDegraded; + + // Redis never affects the HTTP status (it is optional, and failing liveness + // on a Redis outage would restart every instance), but a configured Redis + // that is down or unresponsive is surfaced as a degraded status. + const redisDegraded = redisStatus === 'unavailable' || redisStatus === 'timeout'; + const status = isHealthy && !redisDegraded ? 'ok' : 'degraded'; + + reportStatus('database', database, database === 'ok'); + reportStatus('redis', redisStatus, !redisDegraded); // Keep the Prometheus gauges in step with what /health reports, so a scrape // taken between poll cycles still reflects the ledger the indexer reached. setIndexerLedgers(state?.lastLedger ?? 0, networkLedger); + res.set('Cache-Control', 'no-store'); res.status(isHealthy ? 200 : 503).json({ status, db: dbStatus, + redis: redisStatus, indexerEnabled, indexerLag: indexerLag === -1 ? null : indexerLag, - eventsProcessed: eventCounters.eventsProcessed, - eventsFailed: eventCounters.eventsFailed, - lastErrorAt: eventCounters.lastErrorAt, - indexerDegraded: eventCounters.degraded, // Ledger-level lag, which is what `flowfi_indexer_lag_ledgers` tracks. // Null when the network tip could not be resolved. indexerLedgerLag: networkLedger > 0 ? Math.max(0, networkLedger - (state?.lastLedger ?? 0)) : null, + eventsProcessed: eventCounters.eventsProcessed, + eventsFailed: eventCounters.eventsFailed, + lastErrorAt: eventCounters.lastErrorAt, + indexerDegraded: eventCounters.degraded, uptime: process.uptime(), checks: { database: { - status: dbStatus === 'connected' ? 'ok' : 'down', + status: database, }, indexer: { status: !indexerEnabled ? 'disabled' : indexerFailureDegraded || indexerLagDegraded ? 'degraded' : 'ok', diff --git a/backend/swagger/flowfi.openapi.json b/backend/swagger/flowfi.openapi.json index f5a23d69..1ea96c26 100644 --- a/backend/swagger/flowfi.openapi.json +++ b/backend/swagger/flowfi.openapi.json @@ -722,7 +722,8 @@ "ok", "degraded" ], - "example": "ok" + "example": "ok", + "description": "`degraded` with HTTP 503 when a liveness check fails; `degraded` with HTTP 200 when only Redis is unavailable or timed out" }, "db": { "type": "string", @@ -732,6 +733,17 @@ ], "example": "connected" }, + "redis": { + "type": "string", + "enum": [ + "ok", + "unavailable", + "timeout", + "not_configured" + ], + "example": "ok", + "description": "Same as checks.redis.status" + }, "indexerEnabled": { "type": "boolean", "description": "Whether the event indexer is configured" @@ -774,7 +786,8 @@ "type": "string", "enum": [ "ok", - "down" + "down", + "timeout" ] } } @@ -807,6 +820,7 @@ "enum": [ "ok", "unavailable", + "timeout", "not_configured" ] } @@ -910,10 +924,10 @@ "Health" ], "summary": "Detailed health check", - "description": "Returns liveness and readiness information.\n**Liveness** (200 vs 503) is determined by DB reachability alone.\n**Indexer lag** is reported in the body for observability but only\nforces a 503 when the indexer is actually enabled\n(`STREAM_CONTRACT_ID` env var set) and its state row is stale\n(lag > 60 s). A cold-started instance with no state row yet, or a\ndeployment with the indexer intentionally disabled, always returns 200\nas long as the DB is reachable.\n**Event-processing failures** are also reported. When the indexer is\nenabled and recent per-event failures spike (≥50% of attempts in the\nlast 5 minutes, with ≥3 samples), the endpoint returns 503 even if\nlag looks healthy (the IndexerState upsert bumps updatedAt every poll).\n", + "description": "Returns liveness and readiness information.\n**Liveness** (200 vs 503) is determined by DB reachability alone.\n**Indexer lag** is reported in the body for observability but only\nforces a 503 when the indexer is actually enabled\n(`STREAM_CONTRACT_ID` env var set) and its state row is stale\n(lag > 60 s). A cold-started instance with no state row yet, or a\ndeployment with the indexer intentionally disabled, always returns 200\nas long as the DB is reachable.\n**Event-processing failures** are also reported. When the indexer is\nenabled and recent per-event failures spike (≥50% of attempts in the\nlast 5 minutes, with ≥3 samples), the endpoint returns 503 even if\nlag looks healthy (the IndexerState upsert bumps updatedAt every poll).\n**Redis** is optional. When it is configured but unavailable or does not\nanswer a ping in time, `status` is `degraded` but the response stays\n200, so a Redis outage does not fail liveness probes.\nEvery dependency probe runs in parallel and is bounded by\n`HEALTHCHECK_TIMEOUT_MS` (default 800 ms), so the endpoint answers in\nunder a second even when a dependency hangs.\n", "responses": { "200": { - "description": "Service is healthy", + "description": "Service is healthy (Redis may still be degraded)", "content": { "application/json": { "schema": { diff --git a/backend/tests/health.test.ts b/backend/tests/health.test.ts index c30c814b..eeda7163 100644 --- a/backend/tests/health.test.ts +++ b/backend/tests/health.test.ts @@ -29,7 +29,24 @@ vi.mock('../src/workers/soroban-event-worker.js', () => ({ SorobanEventWorker: vi.fn(), })); +// Redis client — replaced per test; null means "never connected". +vi.mock('../src/lib/redis.js', async (importOriginal) => ({ + ...(await importOriginal()), + getPublisher: vi.fn(() => null), +})); + +// Keep the health route off the network: no real Soroban RPC calls. +vi.mock('../src/services/sorobanService.js', async (importOriginal) => ({ + ...(await importOriginal()), + checkRpcHealth: vi.fn(async () => true), + getLatestLedger: vi.fn(async () => 0), +})); + +import type { Redis } from 'ioredis'; import app from '../src/app.js'; +import logger from '../src/logger.js'; +import { getPublisher } from '../src/lib/redis.js'; +import { checkRpcHealth } from '../src/services/sorobanService.js'; import { sorobanEventWorker } from '../src/workers/soroban-event-worker.js'; function makeState(lagSeconds: number) { @@ -37,9 +54,48 @@ function makeState(lagSeconds: number) { return { id: 'singleton', updatedAt }; } +const never = () => new Promise(() => undefined); + +/** A Redis client stub exposing only what the health route uses. */ +function mockRedis(ping: () => Promise, status = 'ready') { + const client = { status, ping: vi.fn(ping) }; + vi.mocked(getPublisher).mockReturnValue(client as unknown as Redis); + return client; +} + +/** + * Send GET /health while driving a fake clock (only setTimeout is faked) in + * 10 ms steps, yielding real event-loop turns in between so socket I/O makes + * progress. Returns the response and how much simulated time it needed. + */ +async function getHealthWithFakeClock() { + const stepMs = 10; + let done = false; + const pending = request(app) + .get('/health') + .then((res) => { + done = true; + return res; + }); + + let elapsedMs = 0; + while (!done) { + await new Promise((resolve) => setImmediate(resolve)); + if (done) break; + await vi.advanceTimersByTimeAsync(stepMs); + elapsedMs += stepMs; + if (elapsedMs > 5_000) throw new Error('/health did not respond within 5 s of simulated time'); + } + + return { res: await pending, elapsedMs }; +} + describe('GET /health', () => { beforeEach(() => { vi.unstubAllEnvs(); + vi.stubEnv('REDIS_URL', ''); + vi.mocked(getPublisher).mockReturnValue(null); + vi.mocked(checkRpcHealth).mockResolvedValue(true); prismaMock.$queryRaw.mockResolvedValue([{ '?column?': 1n }]); prismaMock.indexerState.findUnique.mockResolvedValue(null); vi.mocked(sorobanEventWorker.getEventCounters).mockReturnValue({ @@ -177,3 +233,232 @@ describe('GET /health', () => { expect(res.body.checks.indexer.status).toBe('degraded'); }); }); + +describe('GET /health dependency timeouts (#1492)', () => { + beforeEach(() => { + vi.unstubAllEnvs(); + vi.stubEnv('STREAM_CONTRACT_ID', ''); + vi.stubEnv('REDIS_URL', 'redis://redis.internal:6379'); + vi.mocked(getPublisher).mockReturnValue(null); + vi.mocked(checkRpcHealth).mockResolvedValue(true); + prismaMock.$queryRaw.mockResolvedValue([{ '?column?': 1n }]); + prismaMock.indexerState.findUnique.mockResolvedValue(null); + vi.mocked(sorobanEventWorker.getEventCounters).mockReturnValue({ + eventsProcessed: 0, + eventsFailed: 0, + lastErrorAt: null, + degraded: false, + }); + }); + + afterEach(() => { + vi.useRealTimers(); + vi.restoreAllMocks(); + }); + + describe('with a fake clock', () => { + beforeEach(() => { + vi.useFakeTimers({ toFake: ['setTimeout', 'clearTimeout'] }); + }); + + it('answers at the timeout with redis "timeout" when the ping never resolves', async () => { + mockRedis(never); + + const { res, elapsedMs } = await getHealthWithFakeClock(); + + expect(elapsedMs).toBeGreaterThanOrEqual(800); + expect(elapsedMs).toBeLessThan(900); + // Redis is optional: liveness stays 200, the body reports the degradation. + expect(res.status).toBe(200); + expect(res.body.status).toBe('degraded'); + expect(res.body.redis).toBe('timeout'); + expect(res.body.checks.redis.status).toBe('timeout'); + expect(res.body.db).toBe('connected'); + expect(res.body.checks.database.status).toBe('ok'); + }); + + it('honours HEALTHCHECK_TIMEOUT_MS', async () => { + vi.stubEnv('HEALTHCHECK_TIMEOUT_MS', '300'); + mockRedis(never); + + const { res, elapsedMs } = await getHealthWithFakeClock(); + + expect(elapsedMs).toBeGreaterThanOrEqual(300); + expect(elapsedMs).toBeLessThan(400); + expect(res.body.redis).toBe('timeout'); + }); + + it('returns 503 with database "timeout" when the DB query hangs and Redis is fine', async () => { + prismaMock.$queryRaw.mockImplementation(never); + mockRedis(async () => 'PONG'); + + const { res, elapsedMs } = await getHealthWithFakeClock(); + + expect(elapsedMs).toBeLessThan(900); + expect(res.status).toBe(503); + expect(res.body.status).toBe('degraded'); + expect(res.body.db).toBe('disconnected'); + expect(res.body.checks.database.status).toBe('timeout'); + expect(res.body.redis).toBe('ok'); + }); + + it('runs the checks in parallel: two 700 ms probes take ~700 ms, not 1400 ms', async () => { + const slow = (value: T) => () => new Promise((resolve) => setTimeout(() => resolve(value), 700)); + prismaMock.$queryRaw.mockImplementation(slow([{ '?column?': 1n }])); + prismaMock.indexerState.findUnique.mockImplementation(slow(null)); + vi.mocked(checkRpcHealth).mockImplementation(slow(true)); + mockRedis(slow('PONG')); + + const { res, elapsedMs } = await getHealthWithFakeClock(); + + expect(elapsedMs).toBeGreaterThanOrEqual(700); + expect(elapsedMs).toBeLessThan(800); + expect(res.status).toBe(200); + expect(res.body.status).toBe('ok'); + expect(res.body.redis).toBe('ok'); + }); + + it('does not wait on a hanging Soroban RPC health check', async () => { + vi.mocked(checkRpcHealth).mockImplementation(never); + mockRedis(async () => 'PONG'); + + const { res, elapsedMs } = await getHealthWithFakeClock(); + + expect(elapsedMs).toBeLessThan(900); + expect(res.status).toBe(200); + expect(res.body.status).toBe('ok'); + expect(res.body.checks.sorobanRpc.status).toBe('down'); + }); + }); + + it('responds in under 1,000 ms of real time when Redis never answers', async () => { + mockRedis(never); + + const started = performance.now(); + const res = await request(app).get('/health'); + const elapsedMs = performance.now() - started; + + expect(elapsedMs).toBeLessThan(1000); + expect(elapsedMs).toBeGreaterThanOrEqual(750); + expect(res.status).toBe(200); + expect(res.body.redis).toBe('timeout'); + }); + + it('reports redis "unavailable" when the ping is rejected', async () => { + mockRedis(async () => { + throw new Error('Connection is closed.'); + }); + + const res = await request(app).get('/health'); + + expect(res.status).toBe(200); + expect(res.body.status).toBe('degraded'); + expect(res.body.redis).toBe('unavailable'); + expect(res.body.checks.redis.status).toBe('unavailable'); + }); + + it.each(['reconnecting', 'connecting', 'end', 'close'])( + 'reports redis "unavailable" without pinging when the client is %s', + async (clientStatus) => { + const client = mockRedis(async () => 'PONG', clientStatus); + + const res = await request(app).get('/health'); + + expect(res.body.redis).toBe('unavailable'); + expect(client.ping).not.toHaveBeenCalled(); + }, + ); + + it('reports redis "unavailable" when REDIS_URL is set but no client connected', async () => { + const res = await request(app).get('/health'); + + expect(res.status).toBe(200); + expect(res.body.status).toBe('degraded'); + expect(res.body.redis).toBe('unavailable'); + }); + + it('reports redis "not_configured" and stays ok when REDIS_URL is unset', async () => { + vi.stubEnv('REDIS_URL', ''); + + const res = await request(app).get('/health'); + + expect(res.status).toBe(200); + expect(res.body.status).toBe('ok'); + expect(res.body.redis).toBe('not_configured'); + }); + + it('returns 503 with database "down" when the DB query fails and Redis is fine', async () => { + prismaMock.$queryRaw.mockRejectedValue(new Error('DB connection refused')); + mockRedis(async () => 'PONG'); + + const res = await request(app).get('/health'); + + expect(res.status).toBe(503); + expect(res.body.status).toBe('degraded'); + expect(res.body.db).toBe('disconnected'); + expect(res.body.checks.database.status).toBe('down'); + expect(res.body.redis).toBe('ok'); + }); + + it('reports both failures when the DB and Redis are down', async () => { + prismaMock.$queryRaw.mockRejectedValue(new Error('DB connection refused')); + mockRedis(async () => { + throw new Error('Connection is closed.'); + }); + + const res = await request(app).get('/health'); + + expect(res.status).toBe(503); + expect(res.body.status).toBe('degraded'); + expect(res.body.checks.database.status).toBe('down'); + expect(res.body.checks.redis.status).toBe('unavailable'); + }); + + it('returns 200 "ok" with no-store caching when the DB and Redis are healthy', async () => { + const client = mockRedis(async () => 'PONG'); + + const res = await request(app).get('/health'); + + expect(res.status).toBe(200); + expect(res.body.status).toBe('ok'); + expect(res.body.db).toBe('connected'); + expect(res.body.redis).toBe('ok'); + expect(res.body.checks.database.status).toBe('ok'); + expect(res.body.checks.redis.status).toBe('ok'); + expect(res.headers['cache-control']).toBe('no-store'); + expect(client.ping).toHaveBeenCalledTimes(1); + }); + + it('never leaks error messages or connection details in the response', async () => { + prismaMock.$queryRaw.mockRejectedValue( + new Error('connect ECONNREFUSED 10.0.0.5:5432 postgresql://flowfi:s3cret@db.internal/flowfi'), + ); + mockRedis(async () => { + throw new Error('connect ECONNREFUSED redis://:s3cret@redis.internal:6379'); + }); + + const res = await request(app).get('/health'); + const body = JSON.stringify(res.body); + + for (const secret of ['ECONNREFUSED', 's3cret', 'internal', '10.0.0.5', 'postgresql://', 'redis://']) { + expect(body).not.toContain(secret); + } + }); + + it('logs a failing component once, not on every probe', async () => { + const warn = vi.spyOn(logger, 'warn'); + + mockRedis(async () => 'PONG'); + await request(app).get('/health'); + + mockRedis(async () => { + throw new Error('Connection is closed.'); + }); + await request(app).get('/health'); + await request(app).get('/health'); + + const messages = warn.mock.calls.map((call) => String(call[0])); + const redisWarnings = messages.filter((message) => message === '[Health] redis check failing'); + expect(redisWarnings).toHaveLength(1); + }); +}); diff --git a/backend/tests/with-timeout.test.ts b/backend/tests/with-timeout.test.ts new file mode 100644 index 00000000..b5b9417e --- /dev/null +++ b/backend/tests/with-timeout.test.ts @@ -0,0 +1,107 @@ +import { describe, it, expect, vi, beforeEach, afterEach } from 'vitest'; +import { withTimeout, TimeoutError } from '../src/lib/with-timeout.js'; + +/** Let pending promise callbacks and process-level events run (setImmediate is not faked). */ +const flush = () => new Promise((resolve) => setImmediate(resolve)); + +function deferred() { + let resolve!: (value: T) => void; + let reject!: (reason: unknown) => void; + const promise = new Promise((res, rej) => { + resolve = res; + reject = rej; + }); + return { promise, resolve, reject }; +} + +describe('withTimeout', () => { + beforeEach(() => { + vi.useFakeTimers({ toFake: ['setTimeout', 'clearTimeout'] }); + }); + + afterEach(() => { + vi.useRealTimers(); + }); + + it('resolves with the value when the operation settles before the timeout', async () => { + const op = deferred(); + const result = withTimeout(op.promise, 1000, 'fast op'); + + await vi.advanceTimersByTimeAsync(500); + op.resolve('pong'); + + await expect(result).resolves.toBe('pong'); + // The timeout timer was cleared, so nothing is left scheduled. + expect(vi.getTimerCount()).toBe(0); + }); + + it('propagates the original rejection when the operation fails before the timeout', async () => { + const op = deferred(); + const result = withTimeout(op.promise, 1000, 'failing op'); + + op.reject(new Error('connection refused')); + + await expect(result).rejects.toThrow('connection refused'); + expect(vi.getTimerCount()).toBe(0); + }); + + it('rejects with a TimeoutError once the timeout elapses', async () => { + const result = withTimeout(new Promise(() => undefined), 800, 'redis ping'); + const assertion = expect(result).rejects.toMatchObject({ + name: 'TimeoutError', + label: 'redis ping', + timeoutMs: 800, + message: 'redis ping timed out after 800ms', + }); + + await vi.advanceTimersByTimeAsync(799); + expect(vi.getTimerCount()).toBe(1); + await vi.advanceTimersByTimeAsync(1); + + await assertion; + await expect(result).rejects.toBeInstanceOf(TimeoutError); + expect(vi.getTimerCount()).toBe(0); + }); + + it('does not surface a late rejection as an unhandled rejection', async () => { + const unhandled = vi.fn(); + process.on('unhandledRejection', unhandled); + try { + const op = deferred(); + const result = withTimeout(op.promise, 100, 'slow op'); + const assertion = expect(result).rejects.toBeInstanceOf(TimeoutError); + + await vi.advanceTimersByTimeAsync(100); + await assertion; + + // The abandoned operation fails after the caller has already given up. + op.reject(new Error('late failure')); + await flush(); + await flush(); + + expect(unhandled).not.toHaveBeenCalled(); + } finally { + process.off('unhandledRejection', unhandled); + } + }); + + it('ignores a late resolution after the timeout', async () => { + const op = deferred(); + const result = withTimeout(op.promise, 100, 'slow op'); + const assertion = expect(result).rejects.toBeInstanceOf(TimeoutError); + + await vi.advanceTimersByTimeAsync(100); + op.resolve('too late'); + + await assertion; + }); + + it('accepts thenables such as Prisma queries', async () => { + const thenable: PromiseLike = { + then: (onFulfilled, onRejected) => Promise.resolve(1).then(onFulfilled, onRejected), + }; + + await expect(withTimeout(thenable, 100)).resolves.toBe(1); + expect(vi.getTimerCount()).toBe(0); + }); +}); diff --git a/frontend/src/lib/api-types.generated.ts b/frontend/src/lib/api-types.generated.ts index de782284..a375894a 100644 --- a/frontend/src/lib/api-types.generated.ts +++ b/frontend/src/lib/api-types.generated.ts @@ -119,6 +119,12 @@ export interface paths { * enabled and recent per-event failures spike (≥50% of attempts in the * last 5 minutes, with ≥3 samples), the endpoint returns 503 even if * lag looks healthy (the IndexerState upsert bumps updatedAt every poll). + * **Redis** is optional. When it is configured but unavailable or does not + * answer a ping in time, `status` is `degraded` but the response stays + * 200, so a Redis outage does not fail liveness probes. + * Every dependency probe runs in parallel and is bounded by + * `HEALTHCHECK_TIMEOUT_MS` (default 800 ms), so the endpoint answers in + * under a second even when a dependency hangs. */ get: { parameters: { @@ -129,7 +135,7 @@ export interface paths { }; requestBody?: never; responses: { - /** @description Service is healthy */ + /** @description Service is healthy (Redis may still be degraded) */ 200: { headers: { [name: string]: unknown; @@ -3234,6 +3240,7 @@ export interface components { }; HealthResponse: { /** + * @description `degraded` with HTTP 503 when a liveness check fails; `degraded` with HTTP 200 when only Redis is unavailable or timed out * @example ok * @enum {string} */ @@ -3243,6 +3250,12 @@ export interface components { * @enum {string} */ db: "connected" | "disconnected"; + /** + * @description Same as checks.redis.status + * @example ok + * @enum {string} + */ + redis?: "ok" | "unavailable" | "timeout" | "not_configured"; /** @description Whether the event indexer is configured */ indexerEnabled: boolean; /** @description Seconds since last indexer update, or null when no state row exists yet */ @@ -3264,7 +3277,7 @@ export interface components { checks: { database?: { /** @enum {string} */ - status?: "ok" | "down"; + status?: "ok" | "down" | "timeout"; }; indexer?: { /** @enum {string} */ @@ -3274,7 +3287,7 @@ export interface components { }; redis?: { /** @enum {string} */ - status?: "ok" | "unavailable" | "not_configured"; + status?: "ok" | "unavailable" | "timeout" | "not_configured"; }; sorobanRpc?: { /** @enum {string} */