diff --git a/.github/workflows/smoke-test.yml b/.github/workflows/smoke-test.yml index 5fc320b7f..ea31b1d61 100644 --- a/.github/workflows/smoke-test.yml +++ b/.github/workflows/smoke-test.yml @@ -137,7 +137,16 @@ jobs: if: failure() run: | kubectl get pods -n commonly-local - kubectl describe pods -n commonly-local | tail -80 + echo "=== backend logs (why readiness never passed) ===" + kubectl logs -n commonly-local deploy/backend --tail=120 --prefix || true + echo "=== backend pod events ===" + kubectl describe pod -n commonly-local -l app=backend | sed -n '/Events:/,$p' || true + echo "=== readiness from inside the cluster ===" + kubectl run ready-probe --rm -i --restart=Never --image=curlimages/curl:8.10.1 \ + -n commonly-local -- curl -s -m 5 -o /dev/stdout -w '\nHTTP %{http_code}\n' \ + http://backend:5000/api/health/ready || true + echo "=== describe (tail) ===" + kubectl describe pods -n commonly-local | tail -40 - name: Delete kind cluster if: always() diff --git a/backend/.env.example b/backend/.env.example index 215f2f28a..1bb33d675 100644 --- a/backend/.env.example +++ b/backend/.env.example @@ -12,6 +12,12 @@ PG_HOST=postgres PG_PORT=5432 PG_DATABASE=commonly PG_SSL_CA_PATH=/app/ca.pem +# Local Postgres (docker compose, or this backend run from source) has no TLS. +# Leave SSL off unless PG points at an external server that requires a CA: with +# this unset AND a CA path set, config/db-pg keeps TLS required, so a CA path +# with no CA behind it fails the connect loudly instead of being read as "the +# operator did not want encryption". +PG_SSL_ENABLED=false # =========================== # ✅ Backend Configuration diff --git a/backend/__tests__/unit/config/db-pg.ssl.test.js b/backend/__tests__/unit/config/db-pg.ssl.test.js new file mode 100644 index 000000000..528e6249b --- /dev/null +++ b/backend/__tests__/unit/config/db-pg.ssl.test.js @@ -0,0 +1,204 @@ +/** + * The SSL decision in config/db-pg.ts — TASK-168. + * + * WHY THIS FILE EXISTS. On 2026-09-25 the new readiness gate made the kind smoke + * test fail on the deploy step: the backend pod stayed 0/1 while every other pod + * was Ready. The pod was not slow — it was in a state it could never leave. + * `PG_SSL_ENABLED` was set to "false" by the chart and ignored by the code, so + * the pool went into SSL mode against an in-cluster Postgres with no TLS, and the + * connect failed with "The server does not support SSL connections". Before this + * row, nothing reported that: the pod served Mongo-fallback chat and passed + * readiness, so main's green smoke never proved PG was mounted at all. + * + * The empty-CA case is the sharper half, and it has two halves of its own. A + * zero-byte `ca.pem` (which is exactly what the local chart mounts, and what any + * instance gets if its CA secret materializes empty) used to count as a + * configured CA, because `fs.existsSync` was the entire test — so it both forced + * TLS and handed Node nothing to verify with. The first fix for that disabled + * SSL, which turned a loud failed handshake into a successful PLAINTEXT + * connection: a security direction change in the file whose whole job is + * transport security (sprint-review, 74244). What is asserted now is the middle: + * a configured CA path with an unusable file keeps TLS ON with no custom CA, so + * the connect fails loudly and readiness reports it. Only an absent CA path (the + * pre-existing behaviour) or an explicit `PG_SSL_ENABLED=false` reaches plaintext + * — and a present-but-BLANK path is not absent (sprint-review, 74253). + * + * The level is asserted too: a missing CA file warned on main and an info line is + * what this row exists to kill (sprint-review, 74245). + */ +jest.mock('fs'); + +const { resolvePgSsl } = require('../../../config/db-pg'); + +const ca = (content) => ({ exists: true, content }); +const missing = () => ({ exists: false, content: '' }); + +// "unusable CA" = TLS stays required, verified against the system store. The +// reason string is asserted too, so the test pins WHY each branch ran and not +// just that no CA was attached. +const expectTlsKept = (d, why) => { + expect(d.ssl).toEqual({ rejectUnauthorized: true }); + expect(d.reason).toContain(why); + expect(d.reason).toContain('instead of downgrading to plaintext'); + // An explicit TLS intent that failed is not routine config (sprint-review, + // 74245). Main warned for a missing CA file; the assertion is here so the + // level cannot quietly drop back to info. + expect(d.level).toBe('warn'); +}; + +describe('resolvePgSsl — PG_SSL_ENABLED is read, not inferred (TASK-168)', () => { + it('disables SSL when PG_SSL_ENABLED=false, even with a real CA present', () => { + // The smoke cluster's shape: a real path, SSL explicitly off. + const d = resolvePgSsl( + { PG_SSL_ENABLED: 'false', PG_SSL_CA_PATH: '/app/certs/ca.pem' }, + () => ca('-----BEGIN CERTIFICATE-----\nMIIB\n-----END CERTIFICATE-----'), + ); + expect(d.ssl).toBe(false); + expect(d.reason).toContain('PG_SSL_ENABLED=false'); + }); + + it('keeps TLS on, with no custom CA, for a blank CA file rather than going plaintext', () => { + // The exact local placeholder: PG_SSL_CA_PATH set, file exists, zero bytes. + // With PG_SSL_ENABLED unset, TLS was asked for by configuring a CA path — a + // zero-byte secret is a misconfiguration, not a request for plaintext. + const d = resolvePgSsl({ PG_SSL_CA_PATH: '/app/certs/ca.pem' }, () => ca('')); + expectTlsKept(d, 'is empty'); + }); + + it('keeps TLS on for a whitespace-only CA file too', () => { + const d = resolvePgSsl({ PG_SSL_CA_PATH: '/app/certs/ca.pem' }, () => ca(' \n\t')); + expectTlsKept(d, 'is empty'); + }); + + it('keeps TLS on even when PG_SSL_ENABLED=true and the CA file is unusable', () => { + // The shape a dev/prod pod lands in if the CA secret materializes empty: + // SSL explicitly requested + nothing to verify with. Fails the handshake, + // which readiness surfaces — it does NOT fall back to an unencrypted chat + // connection because a secret was momentarily empty. + const d = resolvePgSsl( + { PG_SSL_ENABLED: 'true', PG_SSL_CA_PATH: '/app/certs/ca.pem' }, + () => ca(''), + ); + expectTlsKept(d, 'is empty'); + }); + + it('disables SSL when no CA path is configured', () => { + const d = resolvePgSsl({}, () => ca('anything')); + expect(d.ssl).toBe(false); + expect(d.reason).toContain('PG_SSL_CA_PATH'); + expect(d.level).toBe('info'); + }); + + it('sends a present-but-blank CA path to keepTls, not to the unset branch', () => { + // Measured by sprint-review (74253): the first cut decided "unset" on the + // TRIMMED value, so a whitespace-only path downgraded to plaintext one line + // below the empty-FILE case that correctly failed closed. The key is what + // separates "not configured" from "configured wrong". + const d = resolvePgSsl({ PG_SSL_CA_PATH: ' ' }, () => ca('cert')); + expectTlsKept(d, 'is blank'); + }); + + it('treats an empty-string CA path as blank too, but an absent key as unset', () => { + // `''` is how a chart renders "not provided", and it is still a CA path this + // process was handed: present-but-blank. Only a missing key is unset. + const emptyString = resolvePgSsl({ PG_SSL_CA_PATH: '' }, () => ca('cert')); + const absent = resolvePgSsl({}, () => ca('cert')); + expect(emptyString.level).toBe('warn'); + expect(emptyString.ssl).toEqual({ rejectUnauthorized: true }); + expect(absent.ssl).toBe(false); + expect(absent.level).toBe('info'); + }); + + it('covers all five configuration shapes, and only two of them are plaintext', () => { + // The table sprint-review drove (74252) — kept as one assertion so a change + // to any single shape is visible against the others, not just in isolation. + const shapes = { + 'CA file empty': resolvePgSsl({ PG_SSL_CA_PATH: '/ca.pem' }, () => ca('')), + 'CA file missing': resolvePgSsl({ PG_SSL_CA_PATH: '/ca.pem' }, missing), + 'CA path whitespace-only': resolvePgSsl({ PG_SSL_CA_PATH: ' ' }, () => ca('cert')), + 'CA path unset': resolvePgSsl({}, () => ca('cert')), + 'SSL explicitly off': resolvePgSsl({ PG_SSL_ENABLED: 'false' }, () => ca('cert')), + }; + const plaintext = Object.entries(shapes) + .filter(([, d]) => d.ssl === false) + .map(([name]) => name); + expect(plaintext).toEqual(['CA path unset', 'SSL explicitly off']); + expect(shapes['CA path whitespace-only'].level).toBe('warn'); + }); + + it('keeps TLS on, without throwing, when the CA path does not exist', () => { + const d = resolvePgSsl({ PG_SSL_CA_PATH: '/app/certs/ca.pem' }, missing); + expectTlsKept(d, 'not found'); + }); + + it('keeps TLS on, without throwing, when reading the CA throws', () => { + const d = resolvePgSsl({ PG_SSL_CA_PATH: '/app/certs/ca.pem' }, () => { + throw new Error('EACCES: permission denied'); + }); + expectTlsKept(d, 'EACCES'); + }); + + it('is the ONLY pairing that yields plaintext: explicit off, or no CA path at all', () => { + // Guards the direction of the fix. Plaintext has exactly two doors, both of + // them deliberate, and neither of them is "a CA path we could not use". + const explicitOff = resolvePgSsl( + { PG_SSL_ENABLED: 'false', PG_SSL_CA_PATH: '/app/certs/ca.pem' }, + () => ca('cert'), + ); + const noPath = resolvePgSsl({}, () => ca('cert')); + const emptyCa = resolvePgSsl({ PG_SSL_CA_PATH: '/app/certs/ca.pem' }, () => ca('')); + const blankPath = resolvePgSsl({ PG_SSL_CA_PATH: ' ' }, () => ca('cert')); + expect(explicitOff.ssl).toBe(false); + expect(noPath.ssl).toBe(false); + expect(emptyCa.ssl).not.toBe(false); + expect(blankPath.ssl).not.toBe(false); + }); + + it('enables SSL with the CA when SSL is on by default and the CA is real', () => { + // Dev and prod: PG_SSL_ENABLED="true", a real Aiven CA. Unchanged behaviour. + const pem = '-----BEGIN CERTIFICATE-----\nMIIB\n-----END CERTIFICATE-----'; + const d = resolvePgSsl({ PG_SSL_CA_PATH: '/app/certs/ca.pem' }, () => ca(pem)); + expect(d.ssl).toEqual({ rejectUnauthorized: true, ca: pem }); + }); + + it('treats PG_SSL_ENABLED="true" explicitly as enabled (not just unset)', () => { + const pem = 'cert'; + const enabled = resolvePgSsl( + { PG_SSL_ENABLED: 'true', PG_SSL_CA_PATH: '/app/certs/ca.pem' }, + () => ca(pem), + ); + const unset = resolvePgSsl({ PG_SSL_CA_PATH: '/app/certs/ca.pem' }, () => ca(pem)); + expect(enabled.ssl).toEqual(unset.ssl); + expect(enabled.ssl).not.toBe(false); + }); + + it('accepts any casing/spacing of "false"', () => { + ['FALSE', 'False', ' false '].forEach((v) => { + const d = resolvePgSsl( + { PG_SSL_ENABLED: v, PG_SSL_CA_PATH: '/app/certs/ca.pem' }, + () => ca('cert'), + ); + expect(d.ssl).toBe(false); + }); + }); +}); + +describe('the module reads the same decision it exports', () => { + it('wires resolvePgSsl into the pool config rather than deciding inline', () => { + // A second copy of the rule is how the first one drifted from the chart's + // documented intent. The module must call the exported function. + // jest.mock('fs') at the top of this file auto-mocks readFileSync, so the + // real one has to be asked for by name — otherwise this assertion reads + // `undefined` and compares it against a string (a red for the wrong reason). + const realFs = jest.requireActual('fs'); + const source = realFs.readFileSync( + require('path').join(__dirname, '../../../config/db-pg.ts'), + 'utf8', + ); + expect(source).toContain('const sslDecision = resolvePgSsl(process.env'); + expect(source).toContain('pgConfig.ssl = sslDecision.ssl'); + // The level travels with the decision, so the caller cannot flatten a failed + // TLS intent back into an info line (sprint-review, 74245). + expect(source).toContain("sslDecision.level === 'warn' ? console.warn : console.log"); + }); +}); diff --git a/backend/__tests__/unit/routes/health.ready.test.js b/backend/__tests__/unit/routes/health.ready.test.js index 156a0f9b8..ab080597f 100644 --- a/backend/__tests__/unit/routes/health.ready.test.js +++ b/backend/__tests__/unit/routes/health.ready.test.js @@ -15,6 +15,14 @@ jest.mock('mongoose', () => mockMongoose); jest.mock('redis', () => ({ createClient: mockCreateClient })); jest.mock('../../../config/db-pg', () => ({ pool: mockPool })); +// TASK-168: readiness asserts the PG mount from the route table. Default is +// mounted here so the three cases below stay about Mongo and the live probe; +// the mount gate has its own cases. +const mockPgRoutesAreMounted = jest.fn().mockReturnValue(true); +jest.mock('../../../services/pgBootService', () => ({ + pgRoutesAreMounted: (...args) => mockPgRoutesAreMounted(...args), +})); + const originalPgHost = process.env.PG_HOST; const originalK8sMode = process.env.AGENT_PROVISIONER_K8S; process.env.PG_HOST = process.env.PG_HOST || 'localhost-test'; @@ -35,6 +43,7 @@ describe('GET /api/health/ready', () => { beforeEach(() => { mockMongoose.connection.readyState = 1; mockPool.query.mockResolvedValue({ rows: [{ ok: 1 }] }); + mockPgRoutesAreMounted.mockReturnValue(true); }); afterAll(() => { @@ -79,4 +88,49 @@ describe('GET /api/health/ready', () => { ); expect(mockCreateClient).not.toHaveBeenCalled(); }); + + it('returns not ready while the PostgreSQL routes are not mounted (TASK-168)', async () => { + // The 2026-09-25 production defect: the boot connect timed out, the PG + // routes were never mounted, chat history 404'd — and this handler answered + // 200 because it only asked whether a live PG query worked, which the + // lazily-created pool said yes to the moment the transient passed. + mockPgRoutesAreMounted.mockReturnValue(false); + + const res = await request(buildApp()).get('/api/health/ready').expect(503); + + expect(res.body).toEqual(expect.objectContaining({ + status: 'not_ready', + reason: 'PostgreSQL routes are not mounted on this pod', + })); + // The mount is the whole answer, and it is taken before any live probe: + // asking PG how it is feeling is what made this miss the outage. + expect(mockPool.query).not.toHaveBeenCalled(); + }); + + it('goes ready once the mount lands, with no restart (TASK-168)', async () => { + // The retry mounts the routes in-place, so the same pod must flip ready + // without being restarted — the half that made the incident need a human. + mockPgRoutesAreMounted.mockReturnValue(false); + await request(buildApp()).get('/api/health/ready').expect(503); + + mockPgRoutesAreMounted.mockReturnValue(true); + const res = await request(buildApp()).get('/api/health/ready').expect(200); + + expect(res.body.status).toBe('ready'); + expect(mockPgRoutesAreMounted).toHaveBeenCalledTimes(2); + }); + + it('ignores the mount gate when PostgreSQL is not configured', async () => { + // PG_HOST unset is a supported configuration, not a degraded pod: there is + // no PG contract to have failed, so the gate must not apply. + const saved = process.env.PG_HOST; + delete process.env.PG_HOST; + mockPgRoutesAreMounted.mockReturnValue(false); + try { + const res = await request(buildApp()).get('/api/health/ready').expect(200); + expect(res.body.status).toBe('ready'); + } finally { + process.env.PG_HOST = saved; + } + }); }); diff --git a/backend/__tests__/unit/server.test.js b/backend/__tests__/unit/server.test.js index 0bae80238..40e6c2e11 100644 --- a/backend/__tests__/unit/server.test.js +++ b/backend/__tests__/unit/server.test.js @@ -45,81 +45,116 @@ jest.mock('../../routes/pg-status', () => { }); jest.mock('../../routes/pg-messages', () => { const ex = require('express'); - return ex.Router(); + const r = ex.Router(); + r.get('/', (req, res) => res.json({ mounted: true })); + return r; }); -// The PG-status route is mounted inside the `connectPG().then` chain in -// server.ts, so its arrival is asynchronous. Waiting a fixed number of turns -// encodes that chain's current shape instead of the thing under assertion: one -// macrotask turn is enough while every step of the chain is a microtask, and it -// stops being enough the moment the chain awaits anything that actually yields -// (a retry delay, a real client, one added setImmediate). Await the mount. -const pgStatus = async (app) => { - const deadline = Date.now() + 2000; - for (let attempt = 0; Date.now() < deadline && attempt < 200; attempt += 1) { - // eslint-disable-next-line no-await-in-loop - const res = await request(app).get('/api/pg/status'); - if (res.status !== 404) return res; - // eslint-disable-next-line no-await-in-loop - await new Promise((resolve) => { setImmediate(resolve); }); - } - // Never mounted: request it once more so the assertion below reports what the - // route really answers instead of a loop artifact. - return request(app).get('/api/pg/status'); -}; - -describe('server pg status route', () => { +/** + * TASK-168. The production failure being pinned here: one timed-out connect at + * boot used to decide PostgreSQL's fate for the pod's whole life, so on + * 2026-09-25 the only replica served without chat history (`/api/pg/messages` + * 404, pg-retention and installation-cleanup never started) until a human did a + * rollout restart, on an image that was fine and against a PG that answered a + * probe in 331ms. + * + * What server.ts owns is the WIRING: retry, and mount the message routes only + * once connect AND schema initialization have both succeeded. What the routes + * themselves answer is mocked here on purpose — the point is which router, if + * any, is on the path. + */ +describe('server pg boot routes', () => { + // Every case here re-requires server.ts (`jest.resetModules` between them, + // because PG_HOST decides the boot path), and that module loads ~50 routers, + // mongoose, socket.io and Sentry. Alone that is ~6s; inside a full parallel + // run — 451 suites on a loaded machine — it went past jest's 30s default and + // reported a timeout, not a failure. The budget is explicit rather than + // inherited so a genuine hang still shows up as a timeout, at 2x the headroom + // the loaded case needed. + jest.setTimeout(60000); + afterEach(() => { jest.resetModules(); jest.clearAllMocks(); delete process.env.PG_HOST; + delete process.env.PG_BOOT_RETRY_BASE_DELAY_MS; }); - it('returns available:false when PG not configured', async () => { + it('mounts the real status router even when PG is not configured', async () => { delete process.env.PG_HOST; // eslint-disable-next-line global-require, import/no-unresolved, import/extensions const { app } = require('../../server'); const res = await request(app).get('/api/pg/status'); - expect(res.body).toEqual({ available: false }); + + // This mocked router can only ever answer available:true, so getting its + // answer back is the proof that the real router is what serves this path. + // The placeholder `{ available: false }` handlers it replaces would win + // instead, because Express serves the first registered match — and those + // placeholders could never tell the truth after a late mount anyway. + expect(res.body).toEqual({ available: true }); }); - it('returns available:true when PG initialized', async () => { + it('leaves the message routes unmounted while the boot connect keeps failing', async () => { process.env.PG_HOST = 'x'; - mockConnectPG.mockResolvedValue({}); - mockInitPGDB.mockResolvedValue(true); + process.env.PG_BOOT_RETRY_BASE_DELAY_MS = '1'; + mockConnectPG.mockResolvedValue(null); // eslint-disable-next-line global-require, import/no-unresolved, import/extensions const { app } = require('../../server'); - const res = await pgStatus(app); - expect(res.body).toEqual({ available: true }); + await new Promise((resolve) => { setTimeout(resolve, 30); }); + + await request(app).get('/api/pg/messages').expect(404); + // What readiness reads: server.ts wires the probe to the route table, so + // this is the assertion that the gate is wired to the truth rather than to + // the boot block's own bookkeeping (TASK-168 acceptance 2). + // eslint-disable-next-line global-require, import/no-unresolved, import/extensions + expect(require('../../services/pgBootService').pgRoutesAreMounted()).toBe(false); }); - it('returns available:false when PG connection fails', async () => { + it('retries the boot connect and mounts the message routes when a later attempt succeeds', async () => { process.env.PG_HOST = 'x'; - mockConnectPG.mockResolvedValue(null); + process.env.PG_BOOT_RETRY_BASE_DELAY_MS = '1'; + mockConnectPG + .mockRejectedValueOnce(new Error('Connection terminated due to connection timeout')) + .mockResolvedValue({}); + mockInitPGDB.mockResolvedValue(true); // eslint-disable-next-line global-require, import/no-unresolved, import/extensions const { app } = require('../../server'); - const res = await pgStatus(app); - expect(res.body).toEqual({ available: false }); + await new Promise((resolve) => { setTimeout(resolve, 30); }); + + await request(app).get('/api/pg/messages').expect(200); + expect(mockConnectPG).toHaveBeenCalledTimes(2); + expect(mockInitPGDB).toHaveBeenCalledTimes(1); + // The same probe the readiness gate calls, after the mount: a pod that + // recovers must flip without a restart, which is the half of the incident + // that needed a human. + // eslint-disable-next-line global-require, import/no-unresolved, import/extensions + expect(require('../../services/pgBootService').pgRoutesAreMounted()).toBe(true); }); - it('returns available:false when PG init fails', async () => { + it('does not mount the message routes when the schema initialization fails', async () => { process.env.PG_HOST = 'x'; + process.env.PG_BOOT_RETRY_BASE_DELAY_MS = '1'; mockConnectPG.mockResolvedValue({}); mockInitPGDB.mockResolvedValue(false); // eslint-disable-next-line global-require, import/no-unresolved, import/extensions const { app } = require('../../server'); - const res = await pgStatus(app); - expect(res.body).toEqual({ available: false }); + await new Promise((resolve) => { setTimeout(resolve, 30); }); + + await request(app).get('/api/pg/messages').expect(404); }); - it('returns available:false when PG init throws', async () => { - process.env.PG_HOST = 'x'; - mockConnectPG.mockResolvedValue({}); - mockInitPGDB.mockRejectedValue(new Error('fail')); + it('wires the readiness probe to the route table, not to the boot flag (TASK-168)', () => { + // The states reachable in this file cannot tell the two apart — when PG is + // missing, the flag and the route table are both false; when it works, both + // are true. The distinction lily demanded ("readiness must not reuse that + // block's outcome as its own evidence; assert the mount") therefore needs a + // structural read: a rewiring to `pgAvailable` would keep every case above + // green while restoring exactly the blindness that caused the outage, since + // `/api/health` already said postgresql: healthy while /api/pg/messages 404'd. // eslint-disable-next-line global-require, import/no-unresolved, import/extensions - const { app } = require('../../server'); - const res = await pgStatus(app); - expect(res.body).toEqual({ available: false }); + const serverSource = require('fs').readFileSync(require('path').join(__dirname, '../../server.ts'), 'utf8'); + expect(serverSource).toContain('setPgMountProbe(() => routerIsMounted(app, pgMessageRoutes))'); + expect(serverSource).not.toMatch(/setPgMountProbe\(\s*\(\)\s*=>\s*(pgAvailable|pgBootState)/); }); }); diff --git a/backend/__tests__/unit/services/pgBootService.test.js b/backend/__tests__/unit/services/pgBootService.test.js new file mode 100644 index 000000000..8fe138bee --- /dev/null +++ b/backend/__tests__/unit/services/pgBootService.test.js @@ -0,0 +1,252 @@ +/** + * TASK-168 — the boot-time PG connect must not be decided once. + * + * The production failure this covers: a transient connect timeout at startup + * left the pod without the PG routes for its whole life, and nothing retried. + * Every one of these cases therefore turns on the same question — does a + * FAILED early attempt still lead to a mounted route later, and does a + * successful one mount exactly once. + * + * The clock, the scheduler, the connector and the initializer are all injected, + * so these run in milliseconds and assert the retry SHAPE (how many attempts, + * what delay between them) rather than just the end state. + */ +const { + createPgBoot, routerIsMounted, setPgMountProbe, pgRoutesAreMounted, +} = require('../../../services/pgBootService'); + +const makeState = () => ({ + mounted: false, + attempts: 0, + fellBack: false, + lastError: null, + mountedAt: null, +}); + +const silentLog = { info: jest.fn(), warn: jest.fn(), error: jest.fn() }; + +const build = (overrides = {}) => { + const state = overrides.state || makeState(); + const mountRoutes = overrides.mountRoutes || jest.fn(); + const sleep = overrides.sleep || jest.fn().mockResolvedValue(undefined); + const scheduled = []; + const schedule = overrides.schedule || jest.fn((fn, ms) => { + scheduled.push({ fn, ms }); + return jest.fn(); + }); + const boot = createPgBoot({ + mountRoutes, + connect: overrides.connect || jest.fn().mockResolvedValue({ pool: true }), + initialize: overrides.initialize || jest.fn().mockResolvedValue(true), + onMounted: overrides.onMounted, + sleep, + schedule, + log: silentLog, + state, + attempts: overrides.attempts || 3, + baseDelayMs: overrides.baseDelayMs || 100, + maxDelayMs: overrides.maxDelayMs || 250, + backgroundIntervalMs: overrides.backgroundIntervalMs || 30000, + }); + return { boot, state, mountRoutes, sleep, schedule, scheduled }; +}; + +describe('pgBootService — boot connect retries (TASK-168)', () => { + afterEach(() => jest.clearAllMocks()); + + it('makes the first connect time out and mounts the routes on the second attempt', async () => { + const connect = jest.fn() + .mockRejectedValueOnce(new Error('Connection terminated due to connection timeout')) + .mockResolvedValueOnce({ pool: true }); + const initialize = jest.fn().mockResolvedValue(true); + const { boot, state, mountRoutes, sleep, schedule } = build({ connect, initialize }); + + const mounted = await boot.start(); + + expect(mounted).toBe(true); + expect(state.attempts).toBe(2); + expect(state.mounted).toBe(true); + expect(mountRoutes).toHaveBeenCalledTimes(1); + // The timeout is a failed attempt, not a reason to give up: one backoff, + // no background fallback. + expect(sleep).toHaveBeenCalledTimes(1); + expect(sleep).toHaveBeenCalledWith(100); + expect(schedule).not.toHaveBeenCalled(); + expect(state.fellBack).toBe(false); + expect(state.lastError).toBeNull(); + }); + + it('mounts nothing when every boot attempt fails, then mounts on a background retry', async () => { + const connect = jest.fn().mockResolvedValue(null); + const { boot, state, mountRoutes, scheduled } = build({ connect, attempts: 3 }); + + const mounted = await boot.start(); + + expect(mounted).toBe(false); + expect(state.attempts).toBe(3); + expect(state.mounted).toBe(false); + expect(mountRoutes).not.toHaveBeenCalled(); + expect(state.fellBack).toBe(true); + expect(state.lastError).toBe('connect returned no pool'); + expect(scheduled).toHaveLength(1); + expect(scheduled[0].ms).toBe(30000); + + // PG comes back. This is the half that was missing in production: the pod + // must register the routes without a restart. + connect.mockResolvedValue({ pool: true }); + scheduled[0].fn(); + await new Promise((resolve) => { setImmediate(resolve); }); + + expect(state.mounted).toBe(true); + expect(mountRoutes).toHaveBeenCalledTimes(1); + expect(state.attempts).toBe(4); + expect(state.lastError).toBeNull(); + }); + + it('does not mount the routes until the schema has been applied', async () => { + const initialize = jest.fn() + .mockResolvedValueOnce(false) + .mockResolvedValueOnce(true); + const { boot, state, mountRoutes } = build({ initialize, attempts: 2 }); + + await boot.start(); + + expect(mountRoutes).toHaveBeenCalledTimes(1); + expect(state.mounted).toBe(true); + expect(state.attempts).toBe(2); + }); + + it('backs off exponentially and caps the wait at maxDelayMs', async () => { + const { boot, sleep } = build({ + connect: jest.fn().mockResolvedValue(null), + attempts: 4, + baseDelayMs: 100, + maxDelayMs: 250, + }); + + await boot.start(); + + expect(sleep.mock.calls.map((c) => c[0])).toEqual([100, 200, 250]); + }); + + it('mounts exactly once when a background retry succeeds more than once', async () => { + const connect = jest.fn().mockResolvedValue(null); + const { boot, state, mountRoutes, scheduled } = build({ connect, attempts: 1 }); + + await boot.start(); + connect.mockResolvedValue({ pool: true }); + + scheduled[0].fn(); + await new Promise((resolve) => { setImmediate(resolve); }); + const mountedAt = state.mountedAt; + + scheduled[0].fn(); + await new Promise((resolve) => { setImmediate(resolve); }); + + expect(mountRoutes).toHaveBeenCalledTimes(1); + expect(state.attempts).toBe(3); + expect(state.mountedAt).toBe(mountedAt); + }); + + it('treats a throwing connector as a failed attempt rather than a boot crash', async () => { + const connect = jest.fn().mockRejectedValue(new Error('ECONNRESET')); + const { boot, state } = build({ connect, attempts: 2 }); + + await expect(boot.start()).resolves.toBe(false); + + expect(state.attempts).toBe(2); + expect(state.lastError).toBe('connect threw: ECONNRESET'); + expect(state.mounted).toBe(false); + }); + + it('runs the post-mount work only on a successful mount', async () => { + const onMounted = jest.fn(); + const failed = build({ connect: jest.fn().mockResolvedValue(null), attempts: 1, onMounted }); + await failed.boot.start(); + expect(onMounted).not.toHaveBeenCalled(); + + const ok = build({ onMounted }); + await ok.boot.start(); + expect(onMounted).toHaveBeenCalledTimes(1); + }); + + it('stops the background retry timer once the connection succeeds', async () => { + const cancel = jest.fn(); + const connect = jest.fn().mockResolvedValue(null); + const { boot, scheduled } = build({ + connect, + attempts: 1, + schedule: jest.fn((fn, ms) => { scheduled.push({ fn, ms }); return cancel; }), + }); + + await boot.start(); + connect.mockResolvedValue({ pool: true }); + scheduled[0].fn(); + await new Promise((resolve) => { setImmediate(resolve); }); + + expect(cancel).toHaveBeenCalledTimes(1); + }); +}); + +/** + * The readiness gate reads the route table, not the boot block's own flag + * (TASK-168 acceptance 2, lily's 20:57Z scope note). These cases use fake + * Express shapes — a Layer is `{ regexp, handle }` or `{ route: { path } }` — + * because what is under test is the walk, not Express. + */ +describe('pgBootService — the route-table probe (TASK-168)', () => { + const layer = (handle) => ({ handle }); + const appWith = (...layers) => ({ _router: { stack: layers } }); + + it('finds the mounted router in the app stack', () => { + const pgMessages = { name: 'pg-messages' }; + expect(routerIsMounted(appWith(layer(pgMessages)), pgMessages)).toBe(true); + }); + + it('returns false when that router is absent, which is the incident', () => { + const pgMessages = { name: 'pg-messages' }; + const pgStatus = { name: 'pg-status' }; + expect(routerIsMounted(appWith(layer({ stack: [layer(pgStatus)] })), pgMessages)).toBe(false); + expect(routerIsMounted({}, pgMessages)).toBe(false); + expect(routerIsMounted(null, pgMessages)).toBe(false); + // Not a path question: a router with the same shapes but a different + // identity is not this router. + expect(routerIsMounted(appWith(layer({ name: 'pg-messages' })), pgMessages)).toBe(false); + }); + + it('finds a router mounted inside another router', () => { + const pgMessages = { name: 'pg-messages' }; + expect(routerIsMounted(appWith(layer({ stack: [layer(pgMessages)] })), pgMessages)).toBe(true); + }); + + it('answers from the live table, so a late mount flips it without a restart', () => { + const pgMessages = { name: 'pg-messages' }; + const app = appWith(layer({ name: 'health' })); + setPgMountProbe(() => routerIsMounted(app, pgMessages)); + expect(pgRoutesAreMounted()).toBe(false); + + // The retry mounts the same router object into the same app. + app._router.stack.push(layer(pgMessages)); + expect(pgRoutesAreMounted()).toBe(true); + setPgMountProbe(() => false); + }); + + it('does not accept a boot flag as evidence of the mount', () => { + // lily, TASK-168: "readiness must not reuse that block's outcome as its own + // evidence; assert the mount." A pod whose boot block believes it is fine + // while the route table disagrees is exactly the 2026-09-25 shape — + // /api/health said postgresql: healthy while /api/pg/messages 404'd — so the + // probe's answer must not move when the flag does. + const pgMessages = { name: 'pg-messages' }; + const app = appWith(layer({ name: 'health' })); + const state = makeState(); + state.mounted = true; + setPgMountProbe(() => routerIsMounted(app, pgMessages)); + + expect(pgRoutesAreMounted()).toBe(false); + + app._router.stack.push(layer(pgMessages)); + expect(pgRoutesAreMounted()).toBe(true); + setPgMountProbe(() => false); + }); +}); diff --git a/backend/config/db-pg.ts b/backend/config/db-pg.ts index e5e20832e..e704e7d31 100644 --- a/backend/config/db-pg.ts +++ b/backend/config/db-pg.ts @@ -11,7 +11,7 @@ interface PgConfig { host: string | undefined; port: number | string; database: string | undefined; - ssl?: { rejectUnauthorized: boolean; ca: string } | false; + ssl?: { rejectUnauthorized: boolean; ca?: string } | false; // Pool sizing — see #454 (2026-05-26 incident). pg.Pool defaults to // max=10 and connectionTimeoutMillis=0 (wait forever). On any traffic // surge — e.g. the hourly summarizer fanning out 60 summary.request @@ -48,29 +48,126 @@ const pgConfig: PgConfig = { connectionTimeoutMillis: parsePoolInt(process.env.PG_POOL_CONNECT_TIMEOUT_MS, 5000), }; -if (process.env.PG_SSL_CA_PATH) { +/** + * Decide the pool's SSL configuration from the environment. + * + * THREE THINGS THIS USED TO GET WRONG, all in the same direction — SSL on for + * a server that has none, which fails the connect where the failure is + * permanent and silent (TASK-168, 2026-09-25): + * + * 1. `PG_SSL_ENABLED` was never read. The chart sets it (`false` locally, `true` + * in dev/prod) and the local secrets file even carries the comment "Empty + * cert — not used when PG_SSL_ENABLED=false", but the decision was made by + * the presence of the PATH alone. So the kind smoke cluster — which mounts + * the local placeholder secret and disables SSL on purpose — put the pool in + * SSL mode against an in-cluster Postgres without TLS. It never connected, + * which nothing noticed until the readiness gate started reporting it. + * 2. An EMPTY CA file counted as a CA. `fs.existsSync` was the whole test, and + * the local placeholder secret is a zero-byte `ca.pem` under a real path, so + * `{ ca: '' }` was "configured". That is not a local-only shape: any instance + * whose CA secret materializes empty lands here, and the mode it lands in + * both forces TLS and gives Node nothing to verify against. + * + * Unset `PG_SSL_ENABLED` keeps the old default (on), so dev and prod — which set + * it to "true" and mount a real CA — behave exactly as before. + * + * UNUSABLE CA DOES NOT MEAN NO TLS (sprint-review, msg 74244 on #1901 — their + * point, and correct). The first cut of this function returned `ssl: false` for + * a missing / empty / unreadable CA, which fixed the kind cluster by turning a + * loud failed handshake into a successful PLAINTEXT connection — a security + * direction change, in the file whose whole job is transport security. A + * configured `PG_SSL_CA_PATH` with an unusable file is a misconfiguration, not + * a request for plaintext: TLS stays required with no custom CA, so the + * handshake fails and readiness reports it. An ABSENT `PG_SSL_CA_PATH` is the one + * plaintext path, matching the pre-existing behaviour, and `PG_SSL_ENABLED` + * remains the explicit way to ask for it. + * + * PRESENT-BUT-BLANK IS NOT ABSENT (sprint-review, msg 74253 — they drove this + * function over all five shapes and found a third one). The first cut decided + * "unset" on `(env.PG_SSL_CA_PATH || '').trim()`, so a whitespace-only PATH took + * the unset branch and downgraded to plaintext, one line below the empty-FILE + * case that correctly fails closed. The distinction is the KEY: absent is "not + * configured", anything present but unusable is "configured wrong". + * + * THE LEVEL IS THE DECISION (sprint-review, msg 74245). Main warned for a + * missing CA file (`console.warn`, with `console.error` for an unreadable one); + * flattening all of it into one `SSL disabled — …` line at `console.log` would + * have reported a failed TLS intent as routine config — the silent-config-failure + * shape this row exists to kill, reintroduced by its own fix. `level` is part of + * the returned decision so the caller cannot lose it, and the module logs with + * it: deliberate config is info, a failed explicit intent is warn. + * + * WHAT THIS COSTS, stated because it is not free: every environment that + * declares a CA path without providing a CA now fails its connect instead of + * quietly going unencrypted. The chart already said which it wanted + * (`values-local.yaml: pgSslEnabled: "false"`, and the kinds/CI workflows set + * `PG_SSL_ENABLED=false`); docker-compose and the backend example env file + * declared a path the image does not contain and relied on the silent downgrade, + * so both now state the flag too. That is the intended trade: a misconfiguration + * that a human reads in a log beats chat that is quietly cleartext. + */ +export const resolvePgSsl = ( + // `Record` rather than a narrow object type: + // `process.env` is a `ProcessEnv`, which shares no properties with a literal + // shape under this tsconfig (TS2559), and the two keys this reads are the + // whole contract anyway. + env: Record, + readCaFile: (p: string) => { exists: boolean; content: string }, +): { + ssl: false | { rejectUnauthorized: boolean; ca?: string }; + reason: string; + level: 'info' | 'warn'; +} => { + const enabled = String(env.PG_SSL_ENABLED ?? 'true').trim().toLowerCase() !== 'false'; + if (!enabled) { + return { ssl: false, reason: 'PG_SSL_ENABLED=false', level: 'info' }; + } + // Absent key only — NOT "blank after trimming". A present-but-blank path is a + // misconfiguration like an empty file, and goes to keepTls with the rest. + if (env.PG_SSL_CA_PATH === undefined || env.PG_SSL_CA_PATH === null) { + return { ssl: false, reason: 'no PG_SSL_CA_PATH', level: 'info' }; + } + const caPath = env.PG_SSL_CA_PATH.trim(); + // The CA path is configured, so TLS was asked for; an unusable file is the + // misconfiguration, never a reason to go plaintext. Verified against the + // system store instead of a custom CA: a public CA still connects, anything + // else fails loudly here rather than reading chat in the clear. `warn` + // because every branch below is the failure of an explicit intent. + const keepTls = (why: string) => ({ + ssl: { rejectUnauthorized: true }, + reason: `${why} — keeping TLS on with no custom CA instead of downgrading to plaintext`, + level: 'warn' as const, + }); + if (!caPath) { + return keepTls('PG_SSL_CA_PATH is blank'); + } + let ca: { exists: boolean; content: string }; try { - const caPath = process.env.PG_SSL_CA_PATH; - console.log(`Using CA certificate from: ${caPath}`); - if (fs.existsSync(caPath)) { - pgConfig.ssl = { - rejectUnauthorized: true, - ca: fs.readFileSync(caPath).toString() as string, - }; - console.log('SSL configuration added with CA certificate'); - } else { - console.warn(`CA certificate file not found at: ${caPath}`); - pgConfig.ssl = false; - } + ca = readCaFile(caPath); } catch (err) { const e = err as { message?: string }; - console.error('Error loading CA certificate:', e.message); - pgConfig.ssl = false; + return keepTls(`CA file unreadable at ${caPath}: ${e.message}`); } -} else { - console.log('No CA certificate path provided, SSL disabled'); - pgConfig.ssl = false; -} + if (!ca.exists) { + return keepTls(`CA file not found at ${caPath}`); + } + if (!ca.content.trim()) { + return keepTls(`CA file at ${caPath} is empty`); + } + return { + ssl: { rejectUnauthorized: true, ca: ca.content }, + reason: `CA loaded from ${caPath}`, + level: 'info', + }; +}; + +const sslDecision = resolvePgSsl(process.env, (caPath) => { + if (!fs.existsSync(caPath)) return { exists: false, content: '' }; + return { exists: true, content: fs.readFileSync(caPath).toString() }; +}); +pgConfig.ssl = sslDecision.ssl; +const logSslDecision = sslDecision.level === 'warn' ? console.warn : console.log; +logSslDecision(`SSL ${sslDecision.ssl ? 'enabled' : 'disabled'} — ${sslDecision.reason}`); const pool: unknown = pgConfig.host ? new Pool(pgConfig) : null; @@ -140,6 +237,6 @@ const connectPG = async (): Promise => { } }; -module.exports = { pool, connectPG }; +module.exports = { pool, connectPG, resolvePgSsl }; export {}; diff --git a/backend/routes/health.ts b/backend/routes/health.ts index 1f271be61..d0de3d6f8 100644 --- a/backend/routes/health.ts +++ b/backend/routes/health.ts @@ -4,6 +4,10 @@ const express = require('express'); const mongoose = require('mongoose'); // eslint-disable-next-line global-require const { pool: pgPool } = require('../config/db-pg'); +// The mount probe, not the boot block's flag — see pgBootService.routerIsMounted +// for why those are two different facts (TASK-168). +// eslint-disable-next-line global-require +const { pgRoutesAreMounted } = require('../services/pgBootService'); interface Res { status: (n: number) => Res; @@ -167,6 +171,27 @@ router.get('/ready', async (_req: unknown, res: Res) => { return res.status(503).json({ status: 'not_ready', reason: 'MongoDB not connected' }); } + // The gate that was missing on 2026-09-25 (TASK-168). A pod whose boot + // connect timed out has no PG routes at all: /api/pg/messages 404s, so chat + // history cannot load and socket writes fall to Mongo. It used to answer + // ready anyway (this handler returned 200 for a PG probe failure), so during + // a rollout it took 100% of the traffic while the pod it replaced was + // healthy. Readiness now fails until the routes are actually mounted, which + // is a fact about the route table rather than about a connection attempt — + // and it stops failing the moment the retry mounts them, with no restart. + // + // What it deliberately does NOT gate: PG's liveness after a successful + // mount. A blip then leaves the pod ready and degraded on purpose, because + // failing every pod's readiness would turn partial degradation into a full + // API outage (values.yaml, readinessProbe). + if (process.env.PG_HOST && !pgRoutesAreMounted()) { + return res.status(503).json({ + status: 'not_ready', + reason: 'PostgreSQL routes are not mounted on this pod', + timestamp: new Date().toISOString(), + }); + } + if (process.env.PG_HOST && pgPool) { try { await (pgPool as { query: (q: string) => Promise }).query('SELECT 1'); diff --git a/backend/server.ts b/backend/server.ts index eeaa5e234..dd489d409 100644 --- a/backend/server.ts +++ b/backend/server.ts @@ -41,6 +41,7 @@ const gatewayRoutes = require('./routes/gateways'); const skillsRoutes = require('./routes/skills'); const devRoutes = require('./routes/dev'); const healthRoutes = require('./routes/health'); +const pgStatusRoutes = require('./routes/pg-status'); const statsRoutes = require('./routes/stats'); const emailRoutes = require('./routes/email'); const showcaseRoutes = require('./routes/showcase'); @@ -52,22 +53,26 @@ const agentEventsAdminRoutes = require('./routes/admin/agentEvents'); const adminUsersRoutes = require('./routes/admin/users'); const adminAnalyticsRoutes = require('./routes/admin/analytics'); const adminInstallableRoutes = require('./routes/admin/installables'); -// Conditionally load PostgreSQL routes and models +// Conditionally load the PostgreSQL message routes and models. `/api/pg/status` +// is deliberately NOT in here: it is mounted for every configuration, +// including PG_HOST unset, where its own `!pool` branch answers +// available:false — so keeping it conditional would only re-introduce the +// placeholder handlers the mount site below deletes (TASK-168). let pgMessageRoutes: any; -let pgStatusRoutes: any; let PGMessage: any; let _PGPod; const Message = require('./models/Message'); const Pod = require('./models/Pod'); const User = require('./models/User'); const AgentMentionService = require('./services/agentMentionService'); +const { createPgBoot } = require('./services/pgBootService'); +const { setPgMountProbe, routerIsMounted } = require('./services/pgBootService'); // Global flag to track PostgreSQL availability let pgAvailable = false; if (process.env.PG_HOST) { pgMessageRoutes = require('./routes/pg-messages'); - pgStatusRoutes = require('./routes/pg-status'); PGMessage = require('./models/pg/Message'); _PGPod = require('./models/pg/Pod'); } @@ -374,102 +379,82 @@ if (process.env.NODE_ENV !== 'test') { } } -// Connect to PostgreSQL if configured (for chat functionality) +// PostgreSQL status is mounted unconditionally, and NOT as a placeholder: +// checkStatus reads the pool and the schema itself, so it answers +// available:false while PG is unreachable or schema.sql has not been applied +// yet, and true once it has — correct in every state this pod can be in, +// including the mount-retry window below. It replaces five copies of a dummy +// `{ available: false }` handler, one per failure branch, none of which could +// tell the truth after a late mount. Its POST /sync-user is only ever called +// by the frontend after a GET said available:true (SocketContext.tsx:45-49), +// i.e. only when the pool is up. +app.use('/api/pg/status', pgStatusRoutes); + +// Connect to PostgreSQL if configured (for chat functionality). +// +// A boot-time connect failure used to be permanent: `connectPG()` ran once, a +// null result disabled every PG-backed route for the pod's whole life, and +// nothing gated traffic on it. On 2026-09-25 that reached production — a +// transient PG connect timeout at boot left the only replica serving without +// chat history, /api/pg/messages 404ing, socket writes going to Mongo and the +// retention + cleanup crons never started, until a human did a rollout +// restart. PG itself was healthy (331ms from that same pod). The retry with +// backoff, the late mount and the state the health route reads all live in +// services/pgBootService.ts (TASK-168). if (process.env.PG_HOST) { - console.log('Attempting to connect to PostgreSQL for chat functionality...'); - connectPG() - .then((pgPool: any) => { - if (pgPool) { - // Initialize PostgreSQL database - initializePGDB() - .then((success: any) => { - if (success) { - // Set global flag that PostgreSQL is available - pgAvailable = true; - // Register PostgreSQL routes for chat functionality - // '/api/pg/pods' is deliberately NOT mounted. It exposed an - // unauthorized shadow copy of the pod API: getAllPods returned - // every pod on the instance with no membership filter, joinPod - // had no join-policy check at all (a non-member could join a - // private pod and get a 200), and deletePod gated on a - // created_by value that the sync path let a requester claim. - // It had zero callers anywhere in the repo — the frontend uses - // /api/pods, and only /api/pg/messages + /api/pg/status are live - // (ChatRoom, SocketContext). Removed rather than patched. - app.use('/api/pg/messages', pgMessageRoutes); - app.use('/api/pg/status', pgStatusRoutes); - console.log( - 'PostgreSQL routes registered for chat functionality', - ); - // Kick off the daily 30-day message retention cron. Kept out - // of schedulerService.ts on purpose so other tracks can edit - // that file without stomping on this cron. - if (process.env.NODE_ENV !== 'test') { - try { - const { initPgRetention } = require('./services/pgRetentionService'); - initPgRetention(); - } catch (retentionErr: any) { - console.error( - '[pg-retention] failed to initialize:', - retentionErr?.message || retentionErr, - ); - } - try { - require('./services/agentInstallationCleanupService').initInstallationCleanup(); - } catch (cleanupErr: any) { - console.error( - '[installation-cleanup] failed to initialize:', - cleanupErr?.message || cleanupErr, - ); - } - } - } else { - pgAvailable = false; - console.warn( - 'PostgreSQL database initialization failed, chat functionality will use MongoDB', - ); - // Register a dummy status endpoint to indicate PostgreSQL is not available - app.use('/api/pg/status', (req: any, res: any) => { - res.json({ available: false }); - }); - } - }) - .catch((err: any) => { - pgAvailable = false; - console.error('Error initializing PostgreSQL database:', err); - // Register a dummy status endpoint to indicate PostgreSQL is not available - app.use('/api/pg/status', (req: any, res: any) => { - res.json({ available: false }); - }); - }); - } else { - pgAvailable = false; - console.warn( - 'PostgreSQL connection failed, chat functionality will use MongoDB', - ); - // Register a dummy status endpoint to indicate PostgreSQL is not available - app.use('/api/pg/status', (req: any, res: any) => { - res.json({ available: false }); - }); + // Readiness asks the route table, not this block's own bookkeeping (TASK-168): + // it checks that this very router is on the app, so a pod that mounts PG late + // starts passing its readiness probe without being restarted. + setPgMountProbe(() => routerIsMounted(app, pgMessageRoutes)); + createPgBoot({ + // Mounted only after a connect AND a schema initialization both succeed. + // Until then the route is absent rather than present-and-500ing, which is + // the honest answer: the capability really is absent, and a caller that + // gets 404 must not be told the pod is fine. + mountRoutes: () => { + app.use('/api/pg/messages', pgMessageRoutes); + }, + connect: connectPG, + initialize: initializePGDB, + onMounted: () => { + pgAvailable = true; + // Kick off the daily 30-day message retention cron. Kept out + // of schedulerService.ts on purpose so other tracks can edit + // that file without stomping on this cron. + if (process.env.NODE_ENV !== 'test') { + try { + const { initPgRetention } = require('./services/pgRetentionService'); + initPgRetention(); + } catch (retentionErr: any) { + console.error( + '[pg-retention] failed to initialize:', + retentionErr?.message || retentionErr, + ); + } + try { + require('./services/agentInstallationCleanupService').initInstallationCleanup(); + } catch (cleanupErr: any) { + console.error( + '[installation-cleanup] failed to initialize:', + cleanupErr?.message || cleanupErr, + ); + } } - }) + }, + }) + .start() .catch((err: any) => { - pgAvailable = false; - console.error('Error connecting to PostgreSQL:', err); - // Register a dummy status endpoint to indicate PostgreSQL is not available - app.use('/api/pg/status', (req: any, res: any) => { - res.json({ available: false }); - }); + // start() does not reject by construction — it converts every failure + // into state + a scheduled retry. This catch exists so a future edit + // that breaks that property degrades into a logged warning instead of + // an unhandled rejection at boot. + console.error('Error starting the PostgreSQL boot retry:', err?.message || err); }); } else { pgAvailable = false; console.log( 'PostgreSQL connection not configured. Chat functionality will use MongoDB.', ); - // Register a dummy status endpoint to indicate PostgreSQL is not available - app.use('/api/pg/status', (req: any, res: any) => { - res.json({ available: false }); - }); } // Sentry's Express error handler must be registered after application routes. diff --git a/backend/services/pgBootService.ts b/backend/services/pgBootService.ts new file mode 100644 index 000000000..23b1c4be3 --- /dev/null +++ b/backend/services/pgBootService.ts @@ -0,0 +1,284 @@ +/** + * Boot-time PostgreSQL connection, with retries (TASK-168). + * + * WHY THIS EXISTS. On 2026-09-25 a production pod's startup PG connect timed + * out ("Connection terminated due to connection timeout"). `server.ts` called + * `connectPG()` once, treated a null result as "PostgreSQL is not available on + * this pod, forever", and never tried again. That pod then: + * + * - reported `/api/pg/status` → `available:false` for its whole life, + * - 404'd `/api/pg/messages` (the routes were never mounted), so chat + * history would not load, + * - sent socket chat writes to Mongo, + * - never started pg-retention or installation-cleanup, + * + * while PG itself was healthy — a probe from the same pod connected in 331ms. + * A rollout restart on the same image fixed it, i.e. the only recovery was a + * human noticing. + * + * A transient connect failure at boot is not a property of the deployment, so + * it must not be decided once. This retries with exponential backoff, and if + * the synchronous attempts are exhausted it keeps retrying in the background + * and mounts the PG routes the moment the connection succeeds — so a pod that + * booted during a blip heals itself instead of serving without chat until + * someone restarts it. + * + * WHAT IT DOES NOT DO. It never throws, and it never mounts a route it has not + * proven: the routes go up only after a connect AND a successful schema + * initialization. `pgBootState.mounted` is the observable result — the health + * route reads it to decide whether this pod is safe to serve (the boot-scoped + * readiness gate), so a pod that never mounted PG does not take traffic + * during a rollout. + * + * WHY A FACTORY. The retry loop is the part worth testing, and testing it + * against the real pool would mean waiting out real backoff intervals and real + * connect timeouts. Everything the loop touches — the clock, the connector, + * the schema initializer, the route mount, the background scheduler — is + * injected, so the test can make the FIRST connect time out and prove the + * SECOND attempt mounts the routes (TASK-168 acceptance 3) without a database. + */ + +export interface PgBootState { + /** True once connect + initialize succeeded and the routes are mounted. */ + mounted: boolean; + /** Total connect attempts made, synchronous and background. */ + attempts: number; + /** True once the synchronous attempts ran out and the background loop took over. */ + fellBack: boolean; + /** Why the most recent attempt failed, for logs and `/api/pg/status` diagnostics. */ + lastError: string | null; + /** ISO timestamp of the successful mount, null while unmounted. */ + mountedAt: string | null; +} + +/** + * Module-level so the health route can read it without importing server.ts + * (which would be a cycle: server.ts mounts the health route). + */ +export const pgBootState: PgBootState = { + mounted: false, + attempts: 0, + fellBack: false, + lastError: null, + mountedAt: null, +}; + +export type LogFn = (message: string, error?: unknown) => void; + +export interface PgBootDeps { + /** Mounts the PG message routes. Called exactly once, only after a proven connection. */ + mountRoutes: () => void; + /** `connectPG` — resolves the pool, or null when the attempt failed. */ + connect: () => Promise; + /** `initializePGDB` — applies schema.sql; false means the schema is not there. */ + initialize: () => Promise; + /** Started once, after the mount (retention + installation-cleanup crons). */ + onMounted?: () => void; + /** Injected for tests; defaults to a real timer. */ + sleep?: (ms: number) => Promise; + /** Injected for tests; defaults to an unref'd setInterval. Returns a canceller. */ + schedule?: (fn: () => void, ms: number) => () => void; + log?: { info: LogFn; warn: LogFn; error: LogFn }; + state?: PgBootState; + /** Overrides; each falls back to its env var, then to the default. */ + attempts?: number; + baseDelayMs?: number; + maxDelayMs?: number; + backgroundIntervalMs?: number; +} + +export interface PgBootHandle { + start: () => Promise; + stopBackground: () => void; + state: PgBootState; +} + +const readPositiveInt = (raw: unknown, fallback: number): number => { + const n = Number(raw); + return Number.isFinite(n) && n > 0 ? Math.floor(n) : fallback; +}; + +const messageOf = (error: unknown): string => { + const e = error as { message?: string }; + return e?.message || String(error); +}; + +/** The route the readiness gate is about: absent means this pod has no chat. */ +export const PG_MESSAGE_PATH = '/api/pg/messages'; + +/** + * Is this exact router on the app's route table, right now? + * + * This is deliberately NOT `pgBootState.mounted`. The boot block and the route + * table are two different facts, and on 2026-09-25 they disagreed in the way + * that matters: `/api/health` reported `postgresql: healthy` during the outage + * because the lazily-created pool answered `SELECT 1` the moment the transient + * passed, while `/api/pg/messages` stayed unmounted and chat history 404'd. + * Readiness has to assert the route it depends on, from the route table, rather + * than trust a flag set by the code that was supposed to mount it (lily, + * TASK-168, 20:57Z: "readiness must not reuse that block's outcome as its own + * evidence; assert the mount"). + * + * Identity rather than a path string, on purpose: matching a mount prefix means + * parsing Express's Layer regexp back into a path, which is the kind of + * archaeology that silently mis-reads when the router moves. The router object + * IS the thing being mounted, so asking whether that object is in the stack is + * the same question with no translation step — and it stays correct if the path + * ever changes. + */ +export const routerIsMounted = (app: unknown, router: unknown): boolean => { + if (!router) return false; + const walk = (candidate: any): boolean => { + const stack = (candidate && candidate.stack) || []; + return stack.some((layer: any) => { + if (layer.handle === router) return true; + return Boolean(layer.handle && layer.handle.stack) && walk(layer.handle); + }); + }; + const root = (app as { _router?: unknown; router?: unknown })?._router + || (app as { router?: unknown })?.router; + return walk(root); +}; + +// The probe is installed by server.ts, which owns the app. Kept as a function +// rather than a snapshot so it answers from the live route table every time the +// readiness probe asks — a pod that mounts PG later starts answering true. +let mountProbe: (() => boolean) | null = null; + +export const setPgMountProbe = (fn: () => boolean): void => { + mountProbe = fn; +}; + +export const pgRoutesAreMounted = (): boolean => (mountProbe ? mountProbe() : false); + +export const createPgBoot = (deps: PgBootDeps): PgBootHandle => { + const state = deps.state || pgBootState; + const defaultLog = (level: 'info' | 'warn' | 'error'): LogFn => (message, error) => { + const suffix = error === undefined ? '' : ` ${messageOf(error)}`; + if (level === 'error') console.error(message + suffix); + else if (level === 'warn') console.warn(message + suffix); + else console.log(message + suffix); + }; + const log = { + info: deps.log?.info || defaultLog('info'), + warn: deps.log?.warn || defaultLog('warn'), + error: deps.log?.error || defaultLog('error'), + }; + + const attempts = readPositiveInt( + deps.attempts ?? process.env.PG_BOOT_RETRY_ATTEMPTS, + 5, + ); + const baseDelayMs = readPositiveInt( + deps.baseDelayMs ?? process.env.PG_BOOT_RETRY_BASE_DELAY_MS, + 500, + ); + const maxDelayMs = readPositiveInt( + deps.maxDelayMs ?? process.env.PG_BOOT_RETRY_MAX_DELAY_MS, + 30000, + ); + const backgroundIntervalMs = readPositiveInt( + deps.backgroundIntervalMs ?? process.env.PG_BOOT_RETRY_INTERVAL_MS, + 30000, + ); + const sleep = deps.sleep || ((ms: number) => new Promise((resolve) => { + setTimeout(resolve, ms); + })); + const schedule = deps.schedule || ((fn: () => void, ms: number) => { + const timer = setInterval(fn, ms); + // An unmounted-pod retry loop must not hold the process open; the HTTP + // server does that already. + if (typeof timer.unref === 'function') timer.unref(); + return () => clearInterval(timer); + }); + + let cancelBackground: (() => void) | null = null; + + const mount = (): void => { + if (state.mounted) return; + deps.mountRoutes(); + state.mounted = true; + state.mountedAt = new Date().toISOString(); + log.info('PostgreSQL routes registered for chat functionality'); + if (deps.onMounted) deps.onMounted(); + }; + + const attemptOnce = async (): Promise => { + state.attempts += 1; + let pool: unknown = null; + try { + pool = await deps.connect(); + } catch (err) { + state.lastError = `connect threw: ${messageOf(err)}`; + return false; + } + if (!pool) { + state.lastError = 'connect returned no pool'; + return false; + } + let initialized = false; + try { + initialized = await deps.initialize(); + } catch (err) { + state.lastError = `initialize threw: ${messageOf(err)}`; + return false; + } + if (!initialized) { + state.lastError = 'schema initialization failed'; + return false; + } + state.lastError = null; + mount(); + return true; + }; + + const stopBackground = (): void => { + if (cancelBackground) { + cancelBackground(); + cancelBackground = null; + } + }; + + const backgroundAttempt = (): void => { + attemptOnce() + .then((mounted) => { + if (mounted) stopBackground(); + else log.warn(`PostgreSQL still unavailable after ${state.attempts} attempts; will retry`); + }) + .catch((err) => { + // attemptOnce swallows its own failures; this is the belt-and-braces + // path so a rejection can never become an unhandled rejection that + // takes the process down. + log.error('PostgreSQL background retry failed:', err); + }); + }; + + const start = async (): Promise => { + for (let i = 0; i < attempts; i += 1) { + // eslint-disable-next-line no-await-in-loop + if (await attemptOnce()) return true; + if (i < attempts - 1) { + const wait = Math.min(baseDelayMs * (2 ** i), maxDelayMs); + log.warn( + `PostgreSQL connection attempt ${state.attempts} failed (${state.lastError}); retrying in ${wait}ms`, + ); + // eslint-disable-next-line no-await-in-loop + await sleep(wait); + } + } + + state.fellBack = true; + log.error( + `PostgreSQL not available after ${state.attempts} boot attempts (${state.lastError}). ` + + `Chat functionality will use MongoDB until it connects; retrying every ${backgroundIntervalMs}ms ` + + 'and the PG routes mount as soon as it does.', + ); + stopBackground(); + cancelBackground = schedule(backgroundAttempt, backgroundIntervalMs); + return false; + }; + + return { start, stopBackground, state }; +}; + +export {}; diff --git a/docker-compose.yml b/docker-compose.yml index ca8e8170f..e9b65e7c2 100644 --- a/docker-compose.yml +++ b/docker-compose.yml @@ -49,6 +49,13 @@ services: - PG_HOST=${PG_HOST} - PG_PORT=${PG_PORT} - PG_DATABASE=${PG_DATABASE} + # Local Postgres has no TLS, so this compose file states that intent + # explicitly — the same thing the chart does for local (values-local.yaml: + # pgSslEnabled: "false"). Without it, PG_SSL_CA_PATH below is a declared CA + # path with no CA behind it (the backend image contains no /app/ca.pem) and + # db-pg keeps TLS required, which fails the connect instead of silently + # sending chat in the clear. Override in .env to reach an external PG. + - PG_SSL_ENABLED=${PG_SSL_ENABLED:-false} - PG_SSL_CA_PATH=/app/ca.pem # Authentication diff --git a/k8s/helm/commonly/values.yaml b/k8s/helm/commonly/values.yaml index 178859a16..4665ef137 100644 --- a/k8s/helm/commonly/values.yaml +++ b/k8s/helm/commonly/values.yaml @@ -77,10 +77,18 @@ backend: path: /api/health/live initialDelaySeconds: 30 periodSeconds: 10 - # Readiness gates only this pod's Mongo connection. PG and Redis are shared, - # deliberately non-fatal dependencies: the app falls back to Mongo/in-memory, - # and failing every pod's readiness would turn partial degradation into a - # full API outage. + # Readiness gates this pod's Mongo connection AND whether its PostgreSQL + # routes are mounted. PG's liveness is still NOT gated: PG and Redis are + # shared, deliberately non-fatal dependencies, the app falls back to + # Mongo/in-memory, and failing every pod's readiness would turn partial + # degradation into a full API outage. + # + # The mount half is TASK-168 (2026-09-25): a pod whose boot connect timed out + # had NO PG routes at all — /api/pg/messages 404'd, so chat history could not + # load — and still passed readiness, so a rollout sent it 100% of the traffic + # while the pod it replaced was healthy. That pod is permanently missing a + # capability, which is a fact it can report; a PG blip after a successful + # mount is not. readinessProbe: enabled: true path: /api/health/ready