ITADN

TimeoutNegativeWarning, Invalid state: Controller is already closed, server gets stuck in EADDRINUSE; node and Chromium clients behave differently

#405Closedguest271314 创建于 2025-08-24
G
guest271314commented
Start `WebTransport` server. Run `WebTrasnport` client using `node` (v25.0.0-nightly202507295335c101a9). With `node` client things kind of work as expected, except for `TimeoutNegativeWarning` in the client ``` NODE_TLS_REJECT_UNAUTHORIZED=0 node --trace-warnings wt-client.js WebTransport client ready { outgoingTotalLength: 2097152 } Outgoing total length 2097152 written. 2097152 bytes written. (node:64979) TimeoutNegativeWarning: -0.009 is a negative number. Timeout duration was set to 1. at new Timeout (node:internal/timers:195:17) at setTimeout (node:timers:120:19) at globalThis.FAILSsetTimeoutAlarm (file:///home/user/bin/webtransport-echo-server/node_modules/@fails-components/webtransport-transport-http3-quiche/lib/socket.js:10:10) at Socket.<anonymous> (file:///home/user/bin/webtransport-echo-server/node_modules/@fails-components/webtransport-transport-http3-quiche/lib/clientsocket.js:52:21) at Socket.emit (node:events:507:28) at UDP.onMessage [as onmessage] (node:dgram:989:8) { incomingTotalLength: 2097152, outgoingTotalLength: 2097152 } WritableStream close [ { status: 'fulfilled', value: { closeCode: 4999, reason: 'Done streaming.' } }, { status: 'fulfilled', value: 'stream Promise' } ] ``` Notice the `stream` variable `Promise` from `pipeTo()` propagates. In the server we also get the `TimeoutNegative` warning, intermittenly ``` node --trace-warnings index.js server started Promise { <pending> } (node:64965) TimeoutNegativeWarning: -0.002 is a negative number. Timeout duration was set to 1. at new Timeout (node:internal/timers:195:17) at setTimeout (node:timers:120:19) at globalThis.FAILSsetTimeoutAlarm (file:///home/user/bin/webtransport-echo-server/node_modules/@fails-components/webtransport-transport-http3-quiche/lib/socket.js:10:10) at Socket.<anonymous> (file:///home/user/bin/webtransport-echo-server/node_modules/@fails-components/webtransport-transport-http3-quiche/lib/serversocket.js:54:38) at Socket.emit (node:events:507:28) at UDP.onMessage [as onmessage] (node:dgram:989:8) readable closed writable closed Stream 0 Session done Clients 0 Promise { <pending> } readable closed writable closed Stream 1 Session done Clients 1 ``` Now, run the same client code in Chromium (Version 141.0.7374.0 (Developer Build) (64-bit)) or Chrome and things go haywire. The server closes with `Invalid state: Controller is already closed`, then `stream` `Promise` does not propagate and is replaced with `"The session is closed"` which I didn't write, `abort()` in the `WritableStream()` piped to is called. What this looks like in the server ``` node --trace-warnings index.js server started Promise { <pending> } (node:64965) TimeoutNegativeWarning: -0.002 is a negative number. Timeout duration was set to 1. at new Timeout (node:internal/timers:195:17) at setTimeout (node:timers:120:19) at globalThis.FAILSsetTimeoutAlarm (file:///home/user/bin/webtransport-echo-server/node_modules/@fails-components/webtransport-transport-http3-quiche/lib/socket.js:10:10) at Socket.<anonymous> (file:///home/user/bin/webtransport-echo-server/node_modules/@fails-components/webtransport-transport-http3-quiche/lib/serversocket.js:54:38) at Socket.emit (node:events:507:28) at UDP.onMessage [as onmessage] (node:dgram:989:8) readable closed writable closed Stream 0 Session done Clients 0 Promise { <pending> } readable closed writable closed Stream 1 Session done Clients 1 Promise { <pending> } readable closed writable closed Stream 2 Session done Clients 2 Promise { <pending> } readable closed writable closed Stream 3 file:///home/user/bin/webtransport-echo-server/node_modules/@fails-components/webtransport-transport-http3-quiche/lib/serversocket.js:54 const haschlos = this.cobj.recvPaket({ ^ TypeError [ERR_INVALID_STATE]: Invalid state: Controller is already closed at ReadableStreamDefaultController.close (node:internal/webstreams/readablestream:1068:13) at HttpWTSession.onClose (file:///home/user/bin/webtransport-echo-server/node_modules/@fails-components/webtransport/lib/session.js:559:30) at Socket.<anonymous> (file:///home/user/bin/webtransport-echo-server/node_modules/@fails-components/webtransport-transport-http3-quiche/lib/serversocket.js:54:38) at Socket.emit (node:events:507:28) at UDP.onMessage [as onmessage] (node:dgram:989:8) { code: 'ERR_INVALID_STATE' } Node.js v25.0.0-nightly202507295335c101a9 ``` What the Chromium client looks like ``` WebTransport client ready VM2530:89 {outgoingTotalLength: 2097152} VM2530:94 Outgoing total length 2097152 written. VM2530:98 2097152 bytes written. VM2530:114 {incomingTotalLength: 2097152, outgoingTotalLength: 2097152} VM2530:125 {reason: WebTransportError: The session is closed. at Object.write (<anonymous>:116:26)} reason : WebTransportError: The session is closed. at Object.write (<anonymous>:116:26) [[Prototype]] : Object (2) [{…}, {…}] 0: status: "fulfilled" value: {closeCode: 4999, reason: 'Done streaming.'} 1: status: "fulfilled" value: "The session is closed." ``` Additionally, the server got stuck in `EADDRINUSE` after the server exited on commandline and after client closed ``` node --trace-warnings index.js node:dgram:398 const ex = new ExceptionWithHostPort(err, 'bind', ip, port); ^ Error: bind EADDRINUSE 127.0.0.1:8080 at node:dgram:398:20 at process.processTicksAndRejections (node:internal/process/task_queues:91:21) { errno: -98, code: 'EADDRINUSE', syscall: 'bind', address: '127.0.0.1', port: 8080 } Node.js v25.0.0-nightly202507295335c101a9 ``` ``` sudo ss -u -l -p | grep :8080 UNCONN 0 0 127.0.0.1:8080 0.0.0.0:* users:(("MainThread",pid=64205,fd=24)) ``` ``` sudo kill -9 64205 user@debian:~/bin/webtransport-echo-server$ sudo kill -9 64205 kill: (64205): No such process [1]+ Killed node index.js ``` The server source code ``` import { Http3Server } from "@fails-components/webtransport"; import certificates from "./cert.json" with {type:"json"}; const server = new Http3Server({ port: 8080, host: "127.0.0.1", secret: certificates[0].secret, cert: certificates[0].pem, privKey: certificates[0].privateKey }); await server.startServer(); await server.ready; const address = server.address(); const sessionStream = server.sessionStream("/"); const sessionReader = sessionStream.getReader(); console.info("server started"); let streams = 0; let clients = 0; while (true) { try { const { value: session, done } = await sessionReader.read(); if (done) { break; } console.log(session.closed); let incomingTotalLength = 0; let incomingCurrentLength = 0; const buffer = new ArrayBuffer(0, { maxByteLength: 4 }); const view = new DataView(buffer); for await (const { readable, writable } of session.incomingBidirectionalStreams) { const writer = writable.getWriter(); await readable.pipeTo(new WritableStream({ async write(value) { if (incomingTotalLength === 0 && incomingCurrentLength === 0) { buffer.resize(4); for (let i = 0;i < 4; i++) { view.setUint8(i, value[i]); } incomingTotalLength = view.getUint32(0, true); value = value.subarray(4); } await writer.ready; await writer.write(value); incomingCurrentLength += value.length; }, close() { console.log("readable closed"); } }, { preventClose: false })).then(() => console.log("writable closed")).catch((e) => console.log(e)); buffer.resize(0); incomingTotalLength = 0; incomingCurrentLength = 0; await writer.close(); await writer.closed; console.log(`Stream ${streams++}`); break; } await session.closed.then(() => console.log("Session done")).catch((e) => e.message); } catch (e) { console.log(e); } console.log(`Clients ${clients++}`); } ``` The client code ``` try { const serverCertificateHashes = [ { algorithm: "sha-256", value: Uint8Array.of(0, 1, 2, ...) } ]; if (!/Deno|Chrome|Firefox/i.test(navigator.userAgent)) { let { WebTransport, quicheLoaded } = await import("./node_modules/@fails-components/webtransport/lib/index.node.js"); await quicheLoaded; globalThis.WebTransport = WebTransport; } const client = new WebTransport(`https://127.0.0.1:8080`, { serverCertificateHashes }); await client.ready; console.log(`WebTransport client ready`); const encoder = new TextEncoder; let controller; const abortable = new AbortController; const { signal } = abortable; const { readable, writable } = await client.createBidirectionalStream(); let str = "abcdefghijklmnopqrstuvwxyz"; let data = new Uint8Array(2097152); let header = new Uint8Array(Uint32Array.from({ length: 4 }, (_, index) => data.length >> index * 8 & 255)); let view = new DataView(header.buffer); let outgoingTotalLength = view.getUint32(0, true); console.log({ outgoingTotalLength }); let incomingTotalLength = 0; const writer = writable.getWriter(); await writer.ready; await writer.write(header).then(() => console.log(`Outgoing total length ${outgoingTotalLength} written.`)); await writer.ready; await writer.write(data).then(() => console.log(`${data.length} bytes written.`)).catch((e) => console.log(e)); await writer.ready; await writer.close(); const stream = await readable.pipeThrough(new TextDecoderStream).pipeTo(new WritableStream({ start(c) { controller = c; }, async write(value, c) { incomingTotalLength += value.length; if (incomingTotalLength === outgoingTotalLength) { console.log({ incomingTotalLength, outgoingTotalLength }); await client.close({ closeCode: 4999, reason: "Done streaming." }); } }, close() { console.log("WritableStream close"); }, abort(reason) { console.log({ reason }); } }), { signal }).then(() => "stream Promise").catch((e) => e.message); if (!navigator.userAgent.includes("Deno")) { await Promise.allSettled([client.closed, stream]).then(console.log); } else { if (navigator.userAgent.includes("Deno")) { client.close(); await Promise.allSettled([client.closed, stream]).then(console.log); } } } catch (e) { console.log(e); } ```
关闭于 2025-08-25 58 条评论