Undici fetch fails with sequential requests if the connection was closed

[pimterry]

Bug Description

With a server that always closes sockets immediately after a response, when Undici tries to send two requests sequentially (fully waiting for the 1st response before the 2nd request) the 2nd request always fails.

Although this fails 100% of the time with Undici's fetch implementation, the exact same code works 100% of the time in Chrome, Firefox and node-fetch, and the equivalent code works fine with Node.js's HTTP module.

Reproducible By

const http = require('http');

http.createServer((req, res) => {
    res.writeHead(200);
    res.end("Response body");
    res.socket.end(); // Close the connection immediately with every response
}).listen(8008);

fetch('http://localhost:8008') // Global Undici fetch from Node 18
.then((res1) => {
    console.log('res1 status', res1.status)
    return res1.text();
})
.then((body) => console.log('res1 body', body)) // We wait to receive the body
.then(() => fetch('http://localhost:8008')) // This always fails
.then((res2) => console.log('res2 status', res2.status))
.catch((e) => console.error('Error', e));

The second request here always fails with TypeError: fetch failed (with cause: Error: [object Object] which seems like a separate error handling bug to me - I'll file that separately in a sec) with cause: SocketError: other side closed (on Undici 5.1.1, or [object Object] in Node 18/Undici 5.0.0, seems like this is a fixed bug).

Looking at Wireshark (tcp.port == 8008) on my machine it seems like there's usually about 10ms between the FINACK from the server and Undici sending the GET request, which should be easily enough time to handle that closure correctly.

I've seen Wireshark traces where this manifests in two different ways: sometimes as a FINACK packet from the server followed by Undici making a request, then the server sending a RST packet (and Undici failing the request), and sometimes as Undici sending the request and then following up with its own FINACK (aborting its own request because its noticed the FINACK?) before the server responds. Both end up with the same result.

Expected Behavior

Servers can close connections immediately after sending a response. It would be nice if everybody did keep-alive indefinitely, but they're not obliged to and there's many reasons a socket could disconnect.

Since these are totally sequential, both requests should work successfully and every other client I've tested does handle this correctly.

This works as expected in both Chrome & Firefox with fetch, by:

• Running the above (which will error, but continue running)
• Opening localhost:8008 in a browser (which will show 'Response body' as a plain text page)
• Copying and pasting the exact same fetch chain into the dev console
• => It prints both 200 responses statuses OK

This also works with node-fetch, using the same fetch code.

This also works with Node.js's HTTP library, using equivalent non-fetch code with a keep-alive agent:

const http = require('http');
const streamConsumers = require('stream/consumers');

const keepAliveAgent = http.Agent({ keepAlive: true });
http.get('http://localhost:8008', { agent: keepAliveAgent }, async (res1) => {
    console.log('HTTP res1 status', res1.statusCode);

    await streamConsumers.text(); // Wait for the full response

    http.get('http://localhost:8008', { agent: keepAliveAgent }, (res2) => {
        console.log('HTTP res2 status', res2.statusCode);
    }).end();
});

Although this bug is inconvenient, it's not technically invalid behaviour I guess - Undici can fail here justifiably since this is a real unexpected socket closure. It's very inconvenient for portability that it works out of the box with every other fetch implementation I can find though, and I'm seeing many new real errors when upgrading to Node 18 because of this.

I suspect this is due to a subtle timing issue in Undici, where the socket is returned to the pool before all events have been handled or something, while Node etc don't do so until next tick, or doesn't allow more requests to start on the same socket until previous events were handled, or similar.

For comparison, here's a netlog export from Chrome, from running the fetch chain in the devtools:

chrome-net-export.log

You can view it by renaming to .json (GitHub doesn't allow .json attachments?) going to https://netlog-viewer.appspot.com/ and importing the data. Looking at the events section, you see two URL_REQUEST events to localhost:8008, each followed by a SOCKET event 6 lines later. Both socket events say "SOCKET_POOL_CLOSING_SOCKET" and "Connection was closed when it was returned to the pool" at the end, with the 1st socket closure timestamp 10ms before the 2nd URL_REQUEST event even starts processing.

Environment

Ubuntu 20.04, both Node.js 18.0.0 global fetch and Node.js 16.14.2 + Undici 5.1.1.

Additional context

I know I'm opening a few tricky issues at the moment! Hope these are useful - to be clear these are real problems I'm running into in real code. I'm not directly using Undici but each of these is a bug that is breaking my tests in Node 18 because many other libraries use fetch polyfills internally, and so they're all switched to Undici in Node 18, and now many of their requests fail in strange and complicated ways 😬.

Hoping that by reporting these I can help get Undici fetch behaviour to match up nicely with node-fetch/browser fetch so that all goes away soon! 👍

[pimterry]

with cause: Error: [object Object] which seems like a separate error handling bug to me - I'll file that separately in a sec

This error message issue looks like it was actually fixed already in Undici 5.1.0 - it's not an issue in the latest build with Node 16, so we can ignore that after lal (but the rest of this issue remains).

[mcollina]

Would you like to send a Pull Request to address this issue? Remember to add unit tests.

[guilhermelimak]

I'm taking a look at this issue

[guilhermelimak]

I wasn't able to fix it and will not be able to work on it anymore, so it's free to anyone looking for an issue.