undici
undici copied to clipboard
Published
20 hours ago •
nodejs
nodejs
[HTTP/2] Aborted requests for same domain might fail unexpectedly
Bug Description
As the title, pipelined requests might fail unexpectedly if another request toward the same domain has been aborted:
node:assert:399
throw err;
^
AssertionError [ERR_ASSERTION]: The expression evaluated to a falsy value:
assert(!this.aborted)
at Request.onHeaders (/home/runner/undici-h2-promise-any/node_modules/undici/lib/core/request.js:235:5)
at ClientHttp2Stream.<anonymous> (/home/runner/undici-h2-promise-any/node_modules/undici/lib/client.js:1804:17)
at Object.onceWrapper (node:events:628:26)
at ClientHttp2Stream.emit (node:events:513:28)
at emit (node:internal/http2/core:330:3)
at process.processTicksAndRejections (node:internal/process/task_queues:85:22) {
generatedMessage: true,
code: 'ERR_ASSERTION',
actual: false,
expected: true,
operator: '=='
}
Node.js v18.16.1
Reproducible By
https://replit.com/@isukkaw/undici-h2-promise-any
const undici = require('undici');
undici.setGlobalDispatcher(new undici.Agent({
allowH2: true,
pipelining: 10
}));
const { fetch } = undici;
const fetchUbuntuXenialReleaseGpg = () => {
const controller = new AbortController();
return Promise.any(
[
'https://mirror-cdn.xtom.com/ubuntu/dists/xenial/Release.gpg',
'https://mirrors.xtom.com/ubuntu/dists/xenial/Release.gpg',
'https://mirrors.xtom.com.hk/ubuntu/dists/xenial/Release.gpg',
'https://mirrors.xtom.de/ubuntu/dists/xenial/Release.gpg',
'https://mirrors.xtom.nl/ubuntu/dists/xenial/Release.gpg',
'https://mirrors.xtom.ee/ubuntu/dists/xenial/Release.gpg',
'https://mirrors.xtom.jp/ubuntu/dists/xenial/Release.gpg',
'https://mirrors.xtom.au/ubuntu/dists/xenial/Release.gpg'
].map(async url => {
try {
const resp = await fetch(url, { signal: controller.signal });
const text = await resp.text();
// The body should have been consumed, abort the requests
controller.abort();
return text;
} catch(e) {
if (e.name !== 'AbortError') {
console.error('Request Fail:', url)
throw e;
}
}
})
);
};
const fetchDebianBookwormReleaseGpg = () => {
const controller = new AbortController();
return Promise.any(
[
'https://mirror-cdn.xtom.com/debian/dists/bookworm/Release.gpg',
'https://mirrors.xtom.com/debian/dists/bookworm/Release.gpg',
'https://mirrors.xtom.com.hk/debian/dists/bookworm/Release.gpg',
'https://mirrors.xtom.de/debian/dists/bookworm/Release.gpg',
'https://mirrors.xtom.nl/debian/dists/bookworm/Release.gpg',
'https://mirrors.xtom.ee/debian/dists/bookworm/Release.gpg',
'https://mirrors.xtom.jp/debian/dists/bookworm/Release.gpg',
'https://mirrors.xtom.au/debian/dists/bookworm/Release.gpg'
].map(async url => {
try {
const resp = await fetch(url, { signal: controller.signal });
const text = await resp.text();
// The body should have been consumed, abort the requests
controller.abort();
return text;
} catch(e) {
if (e.name !== 'AbortError') {
console.error('Request Fail:', url)
throw e;
}
}
})
);
};
(async () => {
const [ubuntu, debian] = await Promise.all([
fetchUbuntuXenialReleaseGpg(),
fetchDebianBookwormReleaseGpg()
]);
console.log({
ubuntu: ubuntu.length,
debian: debian.length
})
})();
Expected Behavior
AssertionError [ERR_ASSERTION]: The expression evaluated to a falsy value: assert(!this.aborted) should never happened.
Logs & Screenshots
(node:3251) [UNDICI-H2] Warning: H2 support is experimental, expect them to change at any time.
(Use `node --trace-warnings ...` to show where the warning was created)
node:assert:399
throw err;
^
AssertionError [ERR_ASSERTION]: The expression evaluated to a falsy value:
assert(!this.aborted)
at Request.onHeaders (/home/runner/undici-h2-promise-any/node_modules/undici/lib/core/request.js:235:5)
at ClientHttp2Stream.<anonymous> (/home/runner/undici-h2-promise-any/node_modules/undici/lib/client.js:1804:17)
at Object.onceWrapper (node:events:628:26)
at ClientHttp2Stream.emit (node:events:513:28)
at emit (node:internal/http2/core:330:3)
at process.processTicksAndRejections (node:internal/process/task_queues:85:22) {
generatedMessage: true,
code: 'ERR_ASSERTION',
actual: false,
expected: true,
operator: '=='
}
Node.js v18.16.1
Environment
Node.js 18.16.0 on Ubuntu 22.04.1
Started doing some research about, and bug is in fact quite complex; it seems that somewhere we are reusing a request instance that was already aborted to handle a second request. Haven't found the root cause yet. I'll made more research later on
The repro SukkaW provided still reproduces even with Pipelining disabled, maybe this issue should be re-titled?
Trying to swap to undici in our software, I'm able to get this stack trace, we only issue one request to a dummy /debug/stream endpoint which pushes one sse per second and abort it after a few seconds.
but we receive exactly one more chunk afterwards, resulting in this assertion failure
[10/25/2023, 6:25:20 PM] [PLATFORM_FETCH] Sending GET: https://localhost:8020/debug/stream undefined (GET /debug/stream YR+xTDLhXJa6jIE13bX3WWaFzDQx)
undici init path /debug/stream
undici SUCCESS connected {"host":"localhost:8020","hostname":"localhost","protocol":"https:","port":"8020","servername":null,"localAddress":null}
(node:3957036) [UNDICI-H2] Warning: H2 support is experimental, expect them to change at any time.
(Use `node --trace-warnings ...` to show where the warning was created)
[10/25/2023, 6:25:20 PM] [PLATFORM_FETCH] Started response (200) for request GET (https://localhost:8020/debug/stream) undefined (GET /debug/stream YR+xTDLhXJa6jIE13bX3WWaFzDQx)
data from in client /debug/stream <Buffer 7b 22 30 22 3a 22 31 36 39 38 32 37 32 37 32 31 34 39 34 22 7d 0a 0a>
data from in client /debug/stream <Buffer 7b 22 31 22 3a 22 31 36 39 38 32 37 32 37 32 32 34 39 34 22 7d 0a 0a>
data from in client /debug/stream <Buffer 7b 22 32 22 3a 22 31 36 39 38 32 37 32 37 32 33 34 39 35 22 7d 0a 0a>
aborting
undici request error This operation was aborted /debug/stream
[10/25/2023, 6:25:24 PM] [PLATFORM_FETCH] Finished response (closed stream via abort controller) for request (GET https://localhost:8020/debug/stream YR+xTDLhXJa6jIE13bX3WWaFzDQx)
data from in client /debug/stream <Buffer 7b 22 33 22 3a 22 31 36 39 38 32 37 32 37 32 34 34 39 34 22 7d 0a 0a>
Trace: Aborted! /debug/stream <Buffer 7b 22 33 22 3a 22 31 36 39 38 32 37 32 37 32 34 34 39 34 22 7d 0a 0a>
node:internal/event_target:912
process.nextTick(() => { throw err; });
^
AssertionError [ERR_ASSERTION]: The expression evaluated to a falsy value:
assert2(!this.aborted)
at Request2.onData (/nix/store/wvxs5i3mvh1lbvay44i13d24yy9rn95k-esbuild_node/depengine_worker.js:4815:9)
at ClientHttp2Stream.<anonymous> (/nix/store/wvxs5i3mvh1lbvay44i13d24yy9rn95k-esbuild_node/depengine_worker.js:7177:21)
at ClientHttp2Stream.emit (node:events:527:28)
at addChunk (node:internal/streams/readable:324:12)
at readableAddChunk (node:internal/streams/readable:297:9)
at ClientHttp2Stream.Readable.push (node:internal/streams/readable:234:10)
at Http2Stream.onStreamRead (node:internal/stream_base_commons:190:23)
Emitted 'error' event on Worker instance at:
at Worker.[kOnErrorMessage] (node:internal/worker:289:10)
at Worker.[kOnMessage] (node:internal/worker:300:37)
at MessagePort.<anonymous> (node:internal/worker:201:57)
at MessagePort.[nodejs.internal.kHybridDispatch] (node:internal/event_target:643:20)
at MessagePort.exports.emitMessage (node:internal/per_context/messageport:23:28)
Node.js v17.9.0
