From 4f0863843a32ae68f6978b748fa8919995f6150c Mon Sep 17 00:00:00 2001 From: Claude Date: Fri, 21 Aug 2026 19:22:28 +0000 Subject: [PATCH] Fix records/query auth mismatch and add bounded shutdown (#49) POST /records/query required auth while docs said Optional; align to GET /records's anonymous-friendly behavior (it's a superset of the same query surface) and pin it with a test. shutdown() previously waited on server.close() indefinitely, so a client holding a keep-alive connection open could block it forever. Add a configurable SHUTDOWN_TIMEOUT_MS deadline, after which open connections are forced closed so cleanup still runs, and flush the stack on the fatal-startup-error path too. The shutdown sequence is extracted into its own module so it's unit-testable without invoking process.exit. Co-Authored-By: Claude Sonnet 5 Claude-Session: https://claude.ai/code/session_01RgFKoffjrpKGCdEYX551LY --- .env.example | 5 ++ README.md | 1 + docs/deployment.md | 4 +- src/config.ts | 15 +++++ src/index.ts | 41 +++++++------ src/routes/records.ts | 7 ++- src/shutdown.ts | 51 +++++++++++++++++ tests/config.test.ts | 16 ++++++ tests/routes/records.test.ts | 17 ++++++ tests/setup.ts | 1 + tests/shutdown.test.ts | 108 +++++++++++++++++++++++++++++++++++ 11 files changed, 246 insertions(+), 20 deletions(-) create mode 100644 src/shutdown.ts create mode 100644 tests/shutdown.test.ts diff --git a/.env.example b/.env.example index 337e499..8dcfcc6 100644 --- a/.env.example +++ b/.env.example @@ -74,5 +74,10 @@ QUERY_WORKER_POOL_SIZE=2 # See docs/deployment.md#bounding-query-cost. QUERY_QUEUE_LIMIT=64 +# How long shutdown waits (in milliseconds) for open/keep-alive connections +# to drain on server.close() before forcing them closed and finishing the +# flush/close sequence anyway (default: 10000 = 10s). +SHUTDOWN_TIMEOUT_MS=10000 + # See docs/deployment.md for production deployment guidance (TLS, CORS, # rate limiting, and public endpoint exposure). diff --git a/README.md b/README.md index 2a3cde1..4c628f4 100644 --- a/README.md +++ b/README.md @@ -59,6 +59,7 @@ All configuration is via environment variables. See `.env.example` for the full | `QUERY_TIMEOUT_MS` | No | `10000` (10s) | Execution deadline for a `GET /records` or `POST /records/query` search, timed from when it reaches a worker. Exceeding it answers `503` (code `timeout`). See [Deployment: bounding query cost](./docs/deployment.md#bounding-query-cost). | | `QUERY_WORKER_POOL_SIZE` | No | `2` | Number of worker threads a slow search can run on without blocking other requests (max 32). See [Deployment: bounding query cost](./docs/deployment.md#bounding-query-cost). | | `QUERY_QUEUE_LIMIT` | No | `64` | Searches allowed to queue for a worker before the server sheds load with `503` (code `timeout`). See [Deployment: bounding query cost](./docs/deployment.md#bounding-query-cost). | +| `SHUTDOWN_TIMEOUT_MS` | No | `10000` (10s) | How long shutdown waits for open connections to drain before forcing them closed and finishing cleanup anyway. | --- diff --git a/docs/deployment.md b/docs/deployment.md index 39cb935..bf2671c 100644 --- a/docs/deployment.md +++ b/docs/deployment.md @@ -164,7 +164,7 @@ Every other route (`GET /records/:id`, `POST /records`, `PATCH /records/:id`, et Raise `QUERY_TIMEOUT_MS` if your store is large enough that legitimate searches routinely take longer than the default, and raise `QUERY_WORKER_POOL_SIZE` if concurrent searches should run in parallel rather than queue behind each other — each pool worker is a full second (or third, ...) connection to the database, so size it against expected concurrent search load, not total request volume. Raise `QUERY_QUEUE_LIMIT` only if you would rather hold bursts than shed them; lower it to fail fast under overload. -Note that `GET /records` is reachable without authentication, so anonymous callers can occupy pool workers. The deadline caps what any one of them can hold (a slot for at most `QUERY_TIMEOUT_MS`), but a public deployment expecting hostile traffic should rate-limit the query routes at the reverse proxy as well, alongside the other exposure considerations in [Public endpoints](#public-endpoints). +Note that `GET /records` and `POST /records/query` are both reachable without authentication, so anonymous callers can occupy pool workers. The deadline caps what any one of them can hold (a slot for at most `QUERY_TIMEOUT_MS`), but a public deployment expecting hostile traffic should rate-limit the query routes at the reverse proxy as well, alongside the other exposure considerations in [Public endpoints](#public-endpoints). --- @@ -199,7 +199,7 @@ Two consequences worth being deliberate about: - **A grant with no grantee is a grant to the public.** `grant(null, ...)` resolves for any authenticated entity, and with the handshake open that is anyone at all. See [Access Control](./api.md#access-control). Named grants (`grant(, ...)`) are unaffected — those are the vouching mechanism. - **Rate limiting matters more than it used to.** A stranger's handshake writes a token row with a 7-day expiry. Expired rows are reclaimed, but live ones are bounded only by issuance rate × TTL, so the proxy-level rate limit configured above is what actually caps the table. The reverse-proxy examples in this guide already cover `/auth/*`; if you write your own, do not exempt it. -Read access is unaffected either way: `GET /records`, `GET /records/:id` and `GET /types` already serve anonymous requests, subject to record-level permissions, and a token changes nothing about what they return. +Read access is unaffected either way: `GET /records`, `POST /records/query`, `GET /records/:id` and `GET /types` already serve anonymous requests, subject to record-level permissions, and a token changes nothing about what they return. ## Public endpoints diff --git a/src/config.ts b/src/config.ts index da7a01c..5ef93cd 100644 --- a/src/config.ts +++ b/src/config.ts @@ -4,6 +4,7 @@ import { authOriginFromUrl } from '@haverstack/core/wire'; const DEFAULT_MAX_ATTACHMENT_BYTES = 50 * 1024 * 1024; // 50 MB const DEFAULT_MAX_CONTENT_BYTES = 1 * 1024 * 1024; // 1 MB const DEFAULT_QUERY_TIMEOUT_MS = 10_000; +const DEFAULT_SHUTDOWN_TIMEOUT_MS = 10_000; const DEFAULT_QUERY_WORKER_POOL_SIZE = 2; // Each worker is a thread plus its own SQLite connection to the same file, // so an accidental extra zero here is expensive in a way the other limits @@ -38,6 +39,7 @@ export type Config = { queryTimeoutMs: number; queryWorkerPoolSize: number; queryQueueLimit: number; + shutdownTimeoutMs: number; }; export function loadConfig(): Config { @@ -121,6 +123,18 @@ export function loadConfig(): Config { ); } + // Bounds how long shutdown() waits for in-flight/keep-alive connections to + // drain on server.close() before forcing them closed with + // closeAllConnections() and finishing the flush/close sequence anyway. See + // #49. + const shutdownTimeoutMs = parseInt( + optional('SHUTDOWN_TIMEOUT_MS', String(DEFAULT_SHUTDOWN_TIMEOUT_MS)), + 10, + ); + if (isNaN(shutdownTimeoutMs) || shutdownTimeoutMs < 1) { + throw new Error(`Invalid SHUTDOWN_TIMEOUT_MS: ${process.env['SHUTDOWN_TIMEOUT_MS']}`); + } + // Required, not auto-detected: the DID challenge-response handshake signs // a payload scoped to this server's own public origin, and that origin // must come from configuration rather than a client-controlled request @@ -155,5 +169,6 @@ export function loadConfig(): Config { queryTimeoutMs, queryWorkerPoolSize, queryQueueLimit, + shutdownTimeoutMs, }; } diff --git a/src/index.ts b/src/index.ts index da52c4c..4c6193b 100644 --- a/src/index.ts +++ b/src/index.ts @@ -1,8 +1,9 @@ import { serve } from '@hono/node-server'; import pino from 'pino'; import { loadConfig } from './config.js'; -import { initStack } from './stack.js'; +import { initStack, type StackContext } from './stack.js'; import { createApp } from './app.js'; +import { createShutdownHandler } from './shutdown.js'; const logger = pino({ level: process.env['LOG_LEVEL'] ?? 'info', @@ -12,9 +13,15 @@ const logger = pino({ : undefined, }); +// Set once initStack() resolves, so the fatal-error handler below can flush +// even when the crash happens after startup (e.g. mid-request). Left +// undefined for a crash during startup itself, since there's nothing to +// flush yet. +let ctx: StackContext | undefined; + async function main() { const config = loadConfig(); - const ctx = await initStack(config, logger); + ctx = await initStack(config, logger); const app = createApp(ctx, config, logger); logger.info({ dbPath: config.dbPath }, 'Stack initialized'); @@ -23,24 +30,26 @@ async function main() { logger.info({ port: info.port }, 'Server listening'); }); - const shutdown = async (signal: string) => { - logger.info({ signal }, 'Shutting down'); - server.close(async () => { - await ctx.queryWorker.close(); - await ctx.stack.flush(); - await ctx.stack.close(); - await ctx.tokens.close(); - ctx.nonces.close(); - logger.info('Clean shutdown complete'); - process.exit(0); - }); + const shutdown = createShutdownHandler(server, ctx, logger, config.shutdownTimeoutMs); + const onSignal = (signal: string) => { + shutdown(signal) + .then(() => process.exit(0)) + .catch((err) => { + logger.error({ err }, 'Error during shutdown'); + process.exit(1); + }); }; - process.on('SIGTERM', () => shutdown('SIGTERM')); - process.on('SIGINT', () => shutdown('SIGINT')); + process.on('SIGTERM', () => onSignal('SIGTERM')); + process.on('SIGINT', () => onSignal('SIGINT')); } -main().catch((err) => { +main().catch(async (err) => { logger.error({ err }, 'Fatal startup error'); + if (ctx) { + await ctx.stack.flush().catch((flushErr) => { + logger.error({ err: flushErr }, 'Failed to flush during fatal-error shutdown'); + }); + } process.exit(1); }); diff --git a/src/routes/records.ts b/src/routes/records.ts index f3d1d98..7a6d3c5 100644 --- a/src/routes/records.ts +++ b/src/routes/records.ts @@ -39,9 +39,12 @@ export function recordRoutes(ctx: StackContext, queryTimeoutMs: number): Hono { + app.post('/query', async (c) => { const auth = c.get('auth'); const query = parseQueryBody(await readJson(c)); const result = await queryWorker.query(auth, query, queryTimeoutMs); diff --git a/src/shutdown.ts b/src/shutdown.ts new file mode 100644 index 0000000..fd1fbb3 --- /dev/null +++ b/src/shutdown.ts @@ -0,0 +1,51 @@ +import type { Logger } from 'pino'; +import type { StackContext } from './stack.js'; + +/** + * The subset of node-server's return value shutdown() needs. `close()` + * mirrors Node's http.Server: it stops accepting new connections and waits + * for open ones to end before invoking the callback. `closeAllConnections()` + * (Node >=18.2) destroys every open connection immediately, which is what + * makes a pending close() callback fire once the grace period expires. + * Optional because node-server's `ServerType` also covers Http2Server, whose + * @types/node surface omits it even though the app only ever serves HTTP/1. + */ +export type ShutdownServer = { + close(callback: () => void): void; + closeAllConnections?(): void; +}; + +/** + * Builds the shutdown sequence: stop the server (bounded by `timeoutMs` so a + * client holding a keep-alive connection open can't block it indefinitely), + * then release the stack's resources. Does not call process.exit — callers + * decide the exit code so this stays unit-testable. + */ +export function createShutdownHandler( + server: ShutdownServer, + ctx: StackContext, + logger: Logger, + timeoutMs: number, +): (signal: string) => Promise { + return async (signal: string) => { + logger.info({ signal }, 'Shutting down'); + + await new Promise((resolve) => { + const timer = setTimeout(() => { + logger.warn({ timeoutMs }, 'Shutdown grace period exceeded; forcing connections closed'); + server.closeAllConnections?.(); + }, timeoutMs); + server.close(() => { + clearTimeout(timer); + resolve(); + }); + }); + + await ctx.queryWorker.close(); + await ctx.stack.flush(); + await ctx.stack.close(); + await ctx.tokens.close(); + ctx.nonces.close(); + logger.info('Clean shutdown complete'); + }; +} diff --git a/tests/config.test.ts b/tests/config.test.ts index c75c76e..7b0c086 100644 --- a/tests/config.test.ts +++ b/tests/config.test.ts @@ -93,4 +93,20 @@ describe('loadConfig', () => { expect(config.baseUrl).toBe('https://stack.example.com/some/path'); expect(config.authOrigin).toBe('https://stack.example.com'); }); + + it('defaults shutdownTimeoutMs to 10s', () => { + const config = loadConfig(); + expect(config.shutdownTimeoutMs).toBe(10_000); + }); + + it('reads SHUTDOWN_TIMEOUT_MS when set', () => { + process.env['SHUTDOWN_TIMEOUT_MS'] = '5000'; + const config = loadConfig(); + expect(config.shutdownTimeoutMs).toBe(5000); + }); + + it('rejects an invalid SHUTDOWN_TIMEOUT_MS', () => { + process.env['SHUTDOWN_TIMEOUT_MS'] = 'not-a-number'; + expect(() => loadConfig()).toThrow(/Invalid SHUTDOWN_TIMEOUT_MS/); + }); }); diff --git a/tests/routes/records.test.ts b/tests/routes/records.test.ts index fd477c2..b88f4a0 100644 --- a/tests/routes/records.test.ts +++ b/tests/routes/records.test.ts @@ -262,6 +262,23 @@ describe('Records', () => { expect(d.records).toHaveLength(1); expect(d.total).toBeNull(); }); + + it('anonymous query returns only public records', async () => { + await seedRecord(t.ctx, { body: 'private' }); + await t.ctx.stack.create( + NOTE_TYPE_ID, + { body: 'public' }, + { permissions: [{ access: 'public' }] }, + ); + const { status, data } = await req(t.app, 'POST', '/records/query', { + body: { filter: { typeId: NOTE_TYPE_ID } }, + }); + expect(status).toBe(200); + const d = data as { records: Array<{ content: { body: string } }>; total: null }; + expect(d.total).toBeNull(); + expect(d.records).toHaveLength(1); + expect(d.records[0].content.body).toBe('public'); + }); }); describe('PATCH /records/:id', () => { diff --git a/tests/setup.ts b/tests/setup.ts index b1bbcfa..e21f05c 100644 --- a/tests/setup.ts +++ b/tests/setup.ts @@ -83,6 +83,7 @@ export function testConfig(dbPath: string, opts: TestContextOpts = { timezone: ' queryTimeoutMs: 10_000, queryWorkerPoolSize: 1, queryQueueLimit: 64, + shutdownTimeoutMs: 10_000, }; } diff --git a/tests/shutdown.test.ts b/tests/shutdown.test.ts new file mode 100644 index 0000000..34b1c40 --- /dev/null +++ b/tests/shutdown.test.ts @@ -0,0 +1,108 @@ +import { describe, it, expect, vi, beforeEach, afterEach } from 'vitest'; +import type { Logger } from 'pino'; +import type { StackContext } from '../src/stack.js'; +import { createShutdownHandler, type ShutdownServer } from '../src/shutdown.js'; + +function fakeLogger(): Logger { + return { info: vi.fn(), warn: vi.fn(), error: vi.fn(), debug: vi.fn() } as unknown as Logger; +} + +function fakeCtx(): StackContext { + return { + adapter: {} as StackContext['adapter'], + stack: { + flush: vi.fn().mockResolvedValue(undefined), + close: vi.fn().mockResolvedValue(undefined), + } as unknown as StackContext['stack'], + tokens: { close: vi.fn().mockResolvedValue(undefined) } as unknown as StackContext['tokens'], + nonces: { close: vi.fn() } as unknown as StackContext['nonces'], + queryWorker: { + close: vi.fn().mockResolvedValue(undefined), + } as unknown as StackContext['queryWorker'], + }; +} + +describe('createShutdownHandler', () => { + beforeEach(() => { + vi.useFakeTimers(); + }); + + afterEach(() => { + vi.useRealTimers(); + }); + + it('runs the full cleanup sequence once close() finishes on its own', async () => { + const closeAllConnections = vi.fn(); + const server: ShutdownServer = { close: (cb) => cb(), closeAllConnections }; + const ctx = fakeCtx(); + + await createShutdownHandler(server, ctx, fakeLogger(), 10_000)('SIGTERM'); + + expect(closeAllConnections).not.toHaveBeenCalled(); + expect(ctx.queryWorker.close).toHaveBeenCalled(); + expect(ctx.stack.flush).toHaveBeenCalled(); + expect(ctx.stack.close).toHaveBeenCalled(); + expect(ctx.tokens.close).toHaveBeenCalled(); + expect(ctx.nonces.close).toHaveBeenCalled(); + }); + + it('does not force connections closed if close() finishes just under the deadline', async () => { + const closeAllConnections = vi.fn(); + let closeCallback: (() => void) | undefined; + const server: ShutdownServer = { + close: (cb) => { + closeCallback = cb; + }, + closeAllConnections, + }; + const ctx = fakeCtx(); + + const done = createShutdownHandler(server, ctx, fakeLogger(), 10_000)('SIGTERM'); + closeCallback?.(); + await done; + + expect(closeAllConnections).not.toHaveBeenCalled(); + expect(ctx.queryWorker.close).toHaveBeenCalled(); + }); + + it('forces connections closed once the deadline elapses, then still finishes cleanup', async () => { + // Simulates a real server: destroying the sockets is what lets the + // pending close() callback finally fire. + let closeCallback: (() => void) | undefined; + const closeAllConnections = vi.fn(() => closeCallback?.()); + const server: ShutdownServer = { + close: (cb) => { + closeCallback = cb; + }, + closeAllConnections, + }; + const ctx = fakeCtx(); + const logger = fakeLogger(); + + const done = createShutdownHandler(server, ctx, logger, 10_000)('SIGTERM'); + await vi.advanceTimersByTimeAsync(10_000); + await done; + + expect(closeAllConnections).toHaveBeenCalledTimes(1); + expect(logger.warn).toHaveBeenCalled(); + expect(ctx.queryWorker.close).toHaveBeenCalled(); + expect(ctx.stack.flush).toHaveBeenCalled(); + }); + + it('tolerates a server with no closeAllConnections (e.g. Http2Server typings)', async () => { + let closeCallback: (() => void) | undefined; + const server: ShutdownServer = { + close: (cb) => { + closeCallback = cb; + }, + }; + const ctx = fakeCtx(); + + const done = createShutdownHandler(server, ctx, fakeLogger(), 10_000)('SIGTERM'); + await vi.advanceTimersByTimeAsync(10_000); + closeCallback?.(); + await done; + + expect(ctx.queryWorker.close).toHaveBeenCalled(); + }); +});