|
| 1 | +// Copyright (c) 2026 ObjectStack. Licensed under the Apache-2.0 license. |
| 2 | + |
| 3 | +/** |
| 4 | + * `kernel:listening` warns about a busy port only when a port was busy. |
| 5 | + * |
| 6 | + * Port `0` is a legal request: `listen(0)` binds whatever port the kernel hands |
| 7 | + * out, so the bound port can never equal the request and nothing was in use. |
| 8 | + * The hook used to compare the two numbers and warn whenever they differed, so |
| 9 | + * every kernel-assigned boot (`os serve --port 0`, and every CLI test that boots |
| 10 | + * that way) printed a busy-port warning under the banner's Boot diagnostics, |
| 11 | + * at the CLI's default kernel log level (`warn`) and at `info`. |
| 12 | + * |
| 13 | + * Both arms run the plugin's real `init()` / `start()`, the REAL adapter (a |
| 14 | + * real socket is bound) and the REAL core logger at the levels the CLI runs it |
| 15 | + * at. They read the records the hook emits by KIND and COUNT, never by wording: |
| 16 | + * |
| 17 | + * - a request for `0` that binds port N: no record at the default level, and |
| 18 | + * at `info` exactly one record, the one that names N; |
| 19 | + * - a non-zero request whose port is HELD: one `warn` record that names both |
| 20 | + * the requested port and the port actually bound. |
| 21 | + * |
| 22 | + * The neighbour holding the port in the second arm is a plain TCP listener on |
| 23 | + * the same wildcard address the adapter binds, so the adapter's own |
| 24 | + * EADDRINUSE walk is what moves the port. Nothing here simulates the shift. |
| 25 | + */ |
| 26 | + |
| 27 | +import { createServer, type Server } from 'node:net'; |
| 28 | +import { describe, expect, it, vi } from 'vitest'; |
| 29 | +import { createLogger } from '@objectstack/core'; |
| 30 | +import { HonoServerPlugin } from './hono-plugin'; |
| 31 | + |
| 32 | +/** The CLI's default kernel log level (`os serve --log-level`'s documented default). */ |
| 33 | +const CLI_DEFAULT_LEVEL = 'warn'; |
| 34 | + |
| 35 | +const LEVEL_RANK: Record<string, number> = { debug: 0, info: 1, warn: 2, error: 3, fatal: 4 }; |
| 36 | + |
| 37 | +interface LogRecord { |
| 38 | + level: string; |
| 39 | + msg: string; |
| 40 | + [key: string]: unknown; |
| 41 | +} |
| 42 | + |
| 43 | +interface Booted { |
| 44 | + /** The records the `kernel:listening` hook wrote, as the real logger serialised them. */ |
| 45 | + records: LogRecord[]; |
| 46 | + /** The port the adapter really bound, read from the transport itself. */ |
| 47 | + bound: number; |
| 48 | +} |
| 49 | + |
| 50 | +/** |
| 51 | + * Boot the plugin through `init()` / `start()` under a silent context, then |
| 52 | + * fire its `kernel:listening` hooks under a real core logger at `level`, |
| 53 | + * capturing exactly what that logger writes while the hooks run. |
| 54 | + */ |
| 55 | +async function listenAt(port: number, level: 'warn' | 'info'): Promise<Booted> { |
| 56 | + const plugin = new HonoServerPlugin({ port, cors: false }); |
| 57 | + const services = new Map<string, unknown>(); |
| 58 | + const listeningHooks: Array<() => unknown> = []; |
| 59 | + const silent = { debug() {}, info() {}, warn() {}, error() {}, fatal() {} }; |
| 60 | + const ctx: any = { |
| 61 | + logger: silent, |
| 62 | + getKernel: () => ({ hasPlugin: () => false, getService: () => undefined }), |
| 63 | + registerService: (name: string, service: unknown) => services.set(name, service), |
| 64 | + hook: (event: string, fn: () => unknown) => { |
| 65 | + if (event === 'kernel:listening') listeningHooks.push(fn); |
| 66 | + }, |
| 67 | + getService: () => undefined, |
| 68 | + }; |
| 69 | + |
| 70 | + await plugin.init(ctx); |
| 71 | + await plugin.start(ctx); |
| 72 | + expect(listeningHooks, 'the plugin registered no kernel:listening hook').toHaveLength(1); |
| 73 | + |
| 74 | + const server = services.get('http.server') as { getPort(): number; close(): Promise<void> }; |
| 75 | + ctx.logger = createLogger({ level, format: 'json' }); |
| 76 | + |
| 77 | + const chunks: string[] = []; |
| 78 | + const capture = ((chunk: unknown) => { |
| 79 | + chunks.push(String(chunk)); |
| 80 | + return true; |
| 81 | + }) as never; |
| 82 | + const stdout = vi.spyOn(process.stdout, 'write').mockImplementation(capture); |
| 83 | + const stderr = vi.spyOn(process.stderr, 'write').mockImplementation(capture); |
| 84 | + try { |
| 85 | + for (const fn of listeningHooks) await fn(); |
| 86 | + } finally { |
| 87 | + stdout.mockRestore(); |
| 88 | + stderr.mockRestore(); |
| 89 | + } |
| 90 | + |
| 91 | + const bound = server.getPort(); |
| 92 | + await server.close(); |
| 93 | + |
| 94 | + const records = chunks |
| 95 | + .join('') |
| 96 | + .split('\n') |
| 97 | + .filter((line) => line.trim() !== '') |
| 98 | + .map((line) => JSON.parse(line) as LogRecord); |
| 99 | + return { records, bound }; |
| 100 | +} |
| 101 | + |
| 102 | +/** Records at `warn` or above: what the default level shows. */ |
| 103 | +const warnings = (records: LogRecord[]) => |
| 104 | + records.filter((record) => (LEVEL_RANK[record.level] ?? 0) >= LEVEL_RANK.warn); |
| 105 | + |
| 106 | +/** A whole-number mention of `port` in a record's message. */ |
| 107 | +const names = (record: LogRecord, port: number) => new RegExp(`\\b${port}\\b`).test(record.msg); |
| 108 | + |
| 109 | +function holdPort(): Promise<{ port: number; release: () => Promise<void> }> { |
| 110 | + return new Promise((resolveHold, rejectHold) => { |
| 111 | + const holder: Server = createServer(); |
| 112 | + holder.on('error', rejectHold); |
| 113 | + // No host: the same wildcard address the adapter's `serve()` binds. |
| 114 | + holder.listen(0, () => { |
| 115 | + const address = holder.address(); |
| 116 | + if (address === null || typeof address === 'string') { |
| 117 | + rejectHold(new Error(`listen(0) produced no numeric address: ${String(address)}`)); |
| 118 | + return; |
| 119 | + } |
| 120 | + resolveHold({ |
| 121 | + port: address.port, |
| 122 | + release: () => new Promise<void>((done) => holder.close(() => done())), |
| 123 | + }); |
| 124 | + }); |
| 125 | + }); |
| 126 | +} |
| 127 | + |
| 128 | +describe('kernel:listening names a busy port only when one was busy', () => { |
| 129 | + it('a request for port 0 says nothing at the default level', async () => { |
| 130 | + const { records, bound } = await listenAt(0, CLI_DEFAULT_LEVEL); |
| 131 | + |
| 132 | + // The control: the kernel really assigned a port. |
| 133 | + expect(bound, 'listen(0) bound no port').toBeGreaterThan(0); |
| 134 | + expect(records, JSON.stringify(records, null, 2)).toEqual([]); |
| 135 | + }); |
| 136 | + |
| 137 | + it('a request for port 0 prints one line at info, the one naming the bound port', async () => { |
| 138 | + const { records, bound } = await listenAt(0, 'info'); |
| 139 | + const seen = JSON.stringify(records, null, 2); |
| 140 | + |
| 141 | + expect(bound, 'listen(0) bound no port').toBeGreaterThan(0); |
| 142 | + expect(warnings(records), seen).toEqual([]); |
| 143 | + // The existing started line already names the bound port, so no second |
| 144 | + // line is owed, and none may say anything about a port in use. |
| 145 | + expect(records, seen).toHaveLength(1); |
| 146 | + expect(records[0]!.level, seen).toBe('info'); |
| 147 | + expect(records[0]!.port, seen).toBe(bound); |
| 148 | + }); |
| 149 | + |
| 150 | + it('a held non-zero port still warns, naming the requested and the bound port', async () => { |
| 151 | + const neighbour = await holdPort(); |
| 152 | + try { |
| 153 | + const { records, bound } = await listenAt(neighbour.port, CLI_DEFAULT_LEVEL); |
| 154 | + const seen = JSON.stringify(records, null, 2); |
| 155 | + |
| 156 | + // The control: the port really moved, or there is nothing to announce. |
| 157 | + expect(bound, `the adapter bound the held port ${neighbour.port}${seen}`).not.toBe(neighbour.port); |
| 158 | + |
| 159 | + const warned = warnings(records); |
| 160 | + expect(warned, seen).toHaveLength(1); |
| 161 | + expect(warned[0]!.level, seen).toBe('warn'); |
| 162 | + expect(names(warned[0]!, neighbour.port), `the warning does not name the requested port${seen}`).toBe(true); |
| 163 | + expect(names(warned[0]!, bound), `the warning does not name the bound port${seen}`).toBe(true); |
| 164 | + } finally { |
| 165 | + await neighbour.release(); |
| 166 | + } |
| 167 | + }); |
| 168 | +}); |
0 commit comments