Skip to content

Commit c18c1ff

Browse files
committed
test(plugin-hono-server): pin kernel:listening's busy-port warning to a real busy port
A request for port 0 that binds port N must print no busy-port line at the CLI's default level or at info; a held non-zero port must still warn, naming the requested and the bound port. Red on this commit: the fix follows. Claude-Session: https://claude.ai/code/session_01SYEJqDL3NXxrJRBVqaMu9T Co-authored-by: Claude <noreply@anthropic.com>
1 parent db4618b commit c18c1ff

1 file changed

Lines changed: 168 additions & 0 deletions

File tree

Lines changed: 168 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -0,0 +1,168 @@
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

Comments
 (0)