diff --git a/.changeset/24387-port-zero-busy-warning.md b/.changeset/24387-port-zero-busy-warning.md new file mode 100644 index 00000000000..24e84855300 --- /dev/null +++ b/.changeset/24387-port-zero-busy-warning.md @@ -0,0 +1,10 @@ +--- +'@objectstack/plugin-hono-server': patch +--- + +fix(plugin-hono-server): a request for port 0 no longer warns that port 0 is in use + +Clause-②: no (no export, option or type moves: a log line stops firing for a legal request) + +- **What changed.** `HonoServerPlugin`'s `kernel:listening` hook compared the requested port with the bound one and warned `Port 0 is in use, using port N instead` whenever they differed. Port `0` asks for a kernel-assigned port, so the two can never match and nothing was in use. Every `os serve --port 0` boot printed that warning under the banner's Boot diagnostics, at the default log level and at `info`. The warning now fires only for a non-zero request that the adapter moved to another port. +- **Unchanged.** A kernel-assigned boot prints the existing `HTTP server started successfully` line, which already names the bound port, and nothing else. A non-zero request whose port is held still warns, naming the requested and the bound port. diff --git a/packages/cli/test/released-port-production-spawn.pin.test.ts b/packages/cli/test/released-port-production-spawn.pin.test.ts index a807d4f80d1..f5a67e3bdfd 100644 --- a/packages/cli/test/released-port-production-spawn.pin.test.ts +++ b/packages/cli/test/released-port-production-spawn.pin.test.ts @@ -86,8 +86,7 @@ const RELEASED_DRAW_LEDGER: Readonly = { debug: 0, info: 1, warn: 2, error: 3, fatal: 4 }; + +interface LogRecord { + level: string; + msg: string; + [key: string]: unknown; +} + +interface Booted { + /** The records the `kernel:listening` hook wrote, as the real logger serialised them. */ + records: LogRecord[]; + /** The port the adapter really bound, read from the transport itself. */ + bound: number; +} + +/** + * Boot the plugin through `init()` / `start()` under a silent context, then + * fire its `kernel:listening` hooks under a real core logger at `level`, + * capturing exactly what that logger writes while the hooks run. + */ +async function listenAt(port: number, level: 'warn' | 'info'): Promise { + const plugin = new HonoServerPlugin({ port, cors: false }); + const services = new Map(); + const listeningHooks: Array<() => unknown> = []; + const silent = { debug() {}, info() {}, warn() {}, error() {}, fatal() {} }; + const ctx: any = { + logger: silent, + getKernel: () => ({ hasPlugin: () => false, getService: () => undefined }), + registerService: (name: string, service: unknown) => services.set(name, service), + hook: (event: string, fn: () => unknown) => { + if (event === 'kernel:listening') listeningHooks.push(fn); + }, + getService: () => undefined, + }; + + await plugin.init(ctx); + await plugin.start(ctx); + expect(listeningHooks, 'the plugin registered no kernel:listening hook').toHaveLength(1); + + const server = services.get('http.server') as { getPort(): number; close(): Promise }; + ctx.logger = createLogger({ level, format: 'json' }); + + const chunks: string[] = []; + const capture = ((chunk: unknown) => { + chunks.push(String(chunk)); + return true; + }) as never; + const stdout = vi.spyOn(process.stdout, 'write').mockImplementation(capture); + const stderr = vi.spyOn(process.stderr, 'write').mockImplementation(capture); + try { + for (const fn of listeningHooks) await fn(); + } finally { + stdout.mockRestore(); + stderr.mockRestore(); + } + + const bound = server.getPort(); + await server.close(); + + const records = chunks + .join('') + .split('\n') + .filter((line) => line.trim() !== '') + .map((line) => JSON.parse(line) as LogRecord); + return { records, bound }; +} + +/** Records at `warn` or above: what the default level shows. */ +const warnings = (records: LogRecord[]) => + records.filter((record) => (LEVEL_RANK[record.level] ?? 0) >= LEVEL_RANK.warn); + +/** A whole-number mention of `port` in a record's message. */ +const names = (record: LogRecord, port: number) => new RegExp(`\\b${port}\\b`).test(record.msg); + +function holdPort(): Promise<{ port: number; release: () => Promise }> { + return new Promise((resolveHold, rejectHold) => { + const holder: Server = createServer(); + holder.on('error', rejectHold); + // No host: the same wildcard address the adapter's `serve()` binds. + holder.listen(0, () => { + const address = holder.address(); + if (address === null || typeof address === 'string') { + rejectHold(new Error(`listen(0) produced no numeric address: ${String(address)}`)); + return; + } + resolveHold({ + port: address.port, + release: () => new Promise((done) => holder.close(() => done())), + }); + }); + }); +} + +describe('kernel:listening names a busy port only when one was busy', () => { + it('a request for port 0 says nothing at the default level', async () => { + const { records, bound } = await listenAt(0, CLI_DEFAULT_LEVEL); + + // The control: the kernel really assigned a port. + expect(bound, 'listen(0) bound no port').toBeGreaterThan(0); + expect(records, JSON.stringify(records, null, 2)).toEqual([]); + }); + + it('a request for port 0 prints one line at info, the one naming the bound port', async () => { + const { records, bound } = await listenAt(0, 'info'); + const seen = JSON.stringify(records, null, 2); + + expect(bound, 'listen(0) bound no port').toBeGreaterThan(0); + expect(warnings(records), seen).toEqual([]); + // The existing started line already names the bound port, so no second + // line is owed, and none may say anything about a port in use. + expect(records, seen).toHaveLength(1); + expect(records[0]!.level, seen).toBe('info'); + expect(records[0]!.port, seen).toBe(bound); + }); + + it('a held non-zero port still warns, naming the requested and the bound port', async () => { + const neighbour = await holdPort(); + try { + const { records, bound } = await listenAt(neighbour.port, CLI_DEFAULT_LEVEL); + const seen = JSON.stringify(records, null, 2); + + // The control: the port really moved, or there is nothing to announce. + expect(bound, `the adapter bound the held port ${neighbour.port}${seen}`).not.toBe(neighbour.port); + + const warned = warnings(records); + expect(warned, seen).toHaveLength(1); + expect(warned[0]!.level, seen).toBe('warn'); + expect(names(warned[0]!, neighbour.port), `the warning does not name the requested port${seen}`).toBe(true); + expect(names(warned[0]!, bound), `the warning does not name the bound port${seen}`).toBe(true); + } finally { + await neighbour.release(); + } + }); +});