8000 CDPProxy.start() resolves with port 9222 when it bound nothing: exhausting 9222-9230 is indistinguishable from a successful fallback (the cdp-proxy.test.ts failure from #153) · Issue #157 · amirlehmam/wmux · GitHub
[go: up one dir, main page]

Skip to content

CDPProxy.start() resolves with port 9222 when it bound nothing: exhausting 9222-9230 is indistinguishable from a successful fallback (the cdp-proxy.test.ts failure from #153) #157

Closed

Description

@capad-xyz

Filing this separately as you suggested in the #153 merge comment, where the full suite was green on your machine and tests/unit/cdp-proxy.test.ts > falls back to a free port instead of raising an uncaught error had failed on mine.

What I can and cannot claim

Verified live: the mechanism below, with a deterministic repro and the exact assertion message I originally saw.

Not verified: that this was the precise machine state during the #153 run. The suite is green here today (77 files / 881 tests) on 8122b69, and I could not get the failure to recur spontaneously. So I am reporting the mechanism I could force, not a claim about what held those ports two days ago. Source and test are byte-identical between the branch I ran then and master now, so it is environmental, not a code change.

The mechanism

start() treats "I bound nothing" as a success:

private port = DEFAULT_PORT;          // src/main/cdp-proxy.ts:58
...
for (let p = DEFAULT_PORT; p <= MAX_PORT; p++) {   // :208
  try { await ...listen(p, '127.0.0.1', ...); this.port = p; return; }
  catch { continue; }
}
console.warn('[wmux] CDP proxy: all ports 9222-9230 busy');   // :228

When every port in the range is unavailable the loop falls through, the warning is logged, and start() resolves. this.port is never assigned, so it keeps its initialiser: DEFAULT_PORT. getPort() then returns 9222, a port the proxy does not own and never bound.

That is what the test reads, and it is why the assertion is ambiguous:

const port = proxy.getPort();
expect(port).not.toBe(DEFAULT_PORT);

port === 9222 has two entirely different causes, and the test cannot tell them apart:

  1. the fallback did not happen (the bug the test was written for), or
  2. the fallback ran to exhaustion and gave up, leaving the optimistic default in place.

On your machine the range is free, so the test's own blocker takes 9222, the proxy lands on 9223, and case 2 never arises.

Deterministic repro

Occupy the whole range, then run the file:

// hold 9222-9230 on 127.0.0.1
for (let p = 9222; p <= 9230; p++) require('net').createServer().listen(p, '127.0.0.1');
stderr | [wmux] CDP proxy: all ports 9222-9230 busy

 FAIL  tests/unit/cdp-proxy.test.ts > falls back to a free port instead of raising an uncaught error
AssertionError: expected 9222 not to be 9222 // Object.is equality
 > 89|       expect(port).not.toBe(DEFAULT_PORT);

Byte-identical to the failure I hit during #153.

Worth noting how easily one of those nine goes: a wmux instance running while its own suite runs holds 9222 already. I confirmed that on this machine, pid 28680 = wmux.exe listening on 127.0.0.1:9222, which is the normal state for anyone developing wmux with wmux. That alone still passes (the proxy just lands on 9223); it takes the rest of the range as well to produce the failure. This machine also carries WinNAT/Hyper-V dynamic port reservations, which are re-randomised per boot and today sit at 6532-6631 and 11102-11201, i.e. on both sides of the range. A boot where one block covers 9222-9230 would produce exactly this, and would explain both the original failure and why it will not recur on demand. That last part is inference, not something I observed.

The test's precondition is unenforced

The comment reads:

// Occupy the default port to reproduce the second-instance condition. If it
// is already taken (a real wmux is running), that serves the same purpose.

Correct about 9222 either way. What is never established is the other half of the precondition: that at least one port in 9223-9230 is free. Without that, the test is asserting on a scenario it did not manage to set up, and reports it as a fallback failure.

Secondary, same loop, much smaller

The failing run also prints:

MaxListenersExceededWarning: Possible EventEmitter memory leak detected.
11 listening listeners added to [Server]. MaxListeners is 10.

server.listen(port, host, cb) registers cb via once('listening'). A failed attempt rejects through the 'error' path, so its 'listening' callback is never consumed and stays attached. Nine probes leave nine of them.

They are not inert. Verified with a standalone probe against a busy port then a free one:

  probe 19222 failed; 'listening' listeners now: 1
callbacks that fired: [19222, 19223]
actually bound to: 19223

The stale callback for a port that was never bound fires when a later port succeeds, and in start() that callback body is this.port = p; resolve();. It is harmless today purely because listeners fire in registration order and the successful probe registers last, so its assignment lands last. It is one removeListener('listening', ...) from being harmless by construction instead of by accident, and it would also silence the warning in the exact scenario the loop exists for.

Options

Design call, so I would rather ask than send a PR:

  1. Make exhaustion observable in the source. this.port = null (or an isListening()) when nothing bound, so "port" means "port I hold". src/main/index.ts:582 already calls cdpProxy.start().catch(() => {}) with the comment "CDP proxy is optional", so rejecting instead is also open without changing the call site. getPort() has no consumer in src/ today, so the blast radius is the class and the test.
  2. Fix it in the test only. Assert against internals.server.address().port and server.listening rather than the class's own field, so an unbound proxy can never present as a bound one, and establish the missing precondition (skip with a message when no port in 9223-9230 can be taken).
  3. Both.

I lean 3, with 1 shaped as null rather than a rejection: the current call site deliberately swallows failure because the proxy is optional, and a rejection there would be caught and discarded anyway, so the state is what needs to be truthful rather than the control flow. 2 alone would make the suite stop lying about a machine, but would leave the invariant "getPort() is a port I bound" false.

Happy to send whichever you pick.

Activity

  1. amirlehmam commented on Aug 14, 2026

    @amirlehmam
    Owner

    Fixed in 1.0.0. I took option 3, with option 1 shaped as null exactly as you argued for.

    Your diagnosis was right, including the part you were careful not to claim

    You separated "the mechanism I could force" from "what held those ports two days ago", and only claimed the first. That distinction is what made this actionable: I don't need to know what your machine's WinNAT reservations were doing on the 11th, because the mechanism is a defect on its own and reproduces on demand.

    The core of it, restated so it's in the issue thread as well as the source: private port = DEFAULT_PORT is an optimistic initialiser. It asserts a port before anything is bound, and start() resolves even when the whole range is busy — so getPort() returning 9222 had two entirely different causes and no reader could tell them apart. Not just the test. Any reader.

    What shipped

    port is number | null, seeded null, assigned only on a successful bind, and reset to null in stop(). isListening() sits alongside it. So "the port I hold" now means the port it holds.

    start() still resolves rather than rejecting, for the reason you gave: index.ts:582 calls it as cdpProxy.start().catch(() => {}) because the proxy is optional, and a rejection there would be caught and discarded anyway. It is the state that had to become truthful, not the control flow. The exhaustion warning now also says what the user loses ("browser automation is unavailable") rather than just naming the port range.

    The stale 'listening' listeners are gone. You were right that they are not inert, and I want to record why, because the current behaviour is more alarming than the warning suggests:

    probe 19222 failed; 'listening' listeners now: 1
    callbacks that fired: [19222, 19223]
    actually bound to: 19223
    

    Every failed probe's callback fires on the eventual successful bind, and in start() that callback body is this.port = p; resolve(). Nine of them assigning nine different ports. It comes out right only because listeners run in registration order and the winner registers last — which is to say the correct port was being produced by accident. The error path now removes its own 'listening' listener, which makes it correct by construction and silences the MaxListenersExceededWarning in the same stroke.

    The test

    Both halves of your point 2, and one thing you didn't ask for.

    • Asserts against the socket, not the field. internals.server.address().port and server.listening, with getPort() checked against them. An unbound proxy can no longer present as a bound one to the assertion either.
    • Establishes the precondition it was missing. It now checks that something in 9223–9230 is actually free and skips with a message when it isn't, instead of reporting an unstageable environment as a fallback failure.
    • A new test for the case that had no name. Whole range busy → getPort() is null, isListening() false, start() still resolves. That case was previously inexpressible.

    The extra thing: staging now treats "someone else holds this port" as equivalent to "I took this port". Your test helper gave up when it couldn't take 9222 itself — which, as you pointed out, is the normal state on a machine developing wmux with wmux. My first version of the exhaustion test skipped silently on this machine for exactly that reason, which would have made it decorative. Busy is busy, whoever holds it. It runs and passes here now, with a live wmux on 9222.

    getPort() having no consumer

    Still true, and I've left it public rather than deleting it. It is the honest accessor for a piece of state the class has to track anyway, and isListening() is the one I'd expect a future caller to want. If the CDP port ever stops being hard-coded at 9222 in the chrome-devtools-mcp entry — which is the obvious next thing here — getPort() is what that would read.

    Thank you for filing it separately as I asked, and for the deterministic repro. "The suite is green here today and I could not get it to recur spontaneously, so here is the mechanism I can force" is a much more useful bug report than a flake ticket.

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment

Metadata

Metadata

Assignees

No one assigned

    Labels

    No labels
    No labels

    Projects

    No projects

      Milestone

      No milestone

      Relationships

      None yet

      Development

      No branches or pull requests

      Issue actions

      0