undici icon indicating copy to clipboard operation
undici copied to clipboard

`fetch` may try to use a closed connection

Open robhogan opened this issue 1 year ago • 9 comments

Version

v22.6.0

Platform

Darwin MacBook-Pro-6.local 23.5.0 Darwin Kernel Version 23.5.0: Wed May  1 20:12:58 PDT 2024; root:xnu-10063.121.3~5/RELEASE_ARM64_T6000 arm64

Subsystem

http

What steps will reproduce the bug?

// fetch-test.js
const {createServer} = require('node:http');

const port = 8080;
const url = 'http://localhost:' + port;

const server = createServer((req, res) => res.end()).listen(port, async () => {
  await fetch(url);
  server.closeIdleConnections();

  setImmediate(async () => {
    await fetch(url); // Throws TypeError with cause UND_ERR_SOCKET or ECONNRESET
    server.close();
  });
});

How often does it reproduce? Is there a required condition?

Reproduces consistently for me but the error cause varies roughly evenly between ECONNRESET and UND_ERR_SOCKET (details below)

What is the expected behavior? Why is that the expected behavior?

fetch creates a new connection if there are none open, and the request succeeds.

What do you see instead?

node fetch-test.js
node:internal/deps/undici/undici:13178
      Error.captureStackTrace(err);
            ^

TypeError: fetch failed
    at node:internal/deps/undici/undici:13178:13
    at async Immediate.<anonymous> (/Users/robhogan/workspace/fetch-test.js:11:5) {
  [cause]: SocketError: other side closed
      at Socket.<anonymous> (node:internal/deps/undici/undici:6020:28)
      at Socket.emit (node:events:532:35)
      at endReadableNT (node:internal/streams/readable:1696:12)
      at process.processTicksAndRejections (node:internal/process/task_queues:82:21) {
    code: 'UND_ERR_SOCKET',
    socket: {
      localAddress: '::1',
      localPort: 57996,
      remoteAddress: undefined,
      remotePort: undefined,
      remoteFamily: undefined,
      timeout: undefined,
      bytesWritten: 338,
      bytesRead: 122
    }
  }
}

Node.js v22.6.0

OR

node fetch-test.js
node:internal/deps/undici/undici:13178
      Error.captureStackTrace(err);
            ^

TypeError: fetch failed
    at node:internal/deps/undici/undici:13178:13
    at async Immediate.<anonymous> (/Users/robhogan/workspace/fetch-test.js:11:5) {
  [cause]: Error: read ECONNRESET
      at TCP.onStreamRead (node:internal/stream_base_commons:218:20) {
    errno: -54,
    code: 'ECONNRESET',
    syscall: 'read'
  }
}

Node.js v22.6.0

Additional information

This seems to be quite sensitive to timing/the event loop in a way I haven't pinned down.

  • The setImmediate (or setTimeout(cb, 0)) is required to reproduce the issue.
  • Adding another setImmediate before the second fetch makes it succeed.
  • Adding {headers:{'Connection': 'close'}} to the first request succeeds.

robhogan avatar Aug 21 '24 13:08 robhogan

const {createServer} = require('node:http');

const port = 8080;
const url = 'http://localhost:' + port;

const server = createServer((req, res) => res.end()).listen(port, async () => {
  await fetch(url);
  server.closeIdleConnections();

  setImmediate(async () => {
    await fetch(url); // Throws TypeError with cause UND_ERR_SOCKET or ECONNRESET
    server.close();
  });
});
$ node repro.js
node:internal/deps/undici/undici:13178
      Error.captureStackTrace(err);
            ^

TypeError: fetch failed
    at node:internal/deps/undici/undici:13178:13
    at async Immediate.<anonymous> (/repro.js:12:5) {
  [cause]: Error: read ECONNRESET
      at TCP.onStreamRead (node:internal/stream_base_commons:218:20) {
    errno: -54,
    code: 'ECONNRESET',
    syscall: 'read'
  }
}

Node.js v22.6.0

avivkeller avatar Aug 21 '24 14:08 avivkeller

If I put following line in setImmediate then it works as expected, but other tests fail

https://github.com/nodejs/undici/blob/69cfd97591c0a1eec563590df862caeed304f1c3/lib/dispatcher/client.js#L292

Uzlopak avatar Aug 22 '24 04:08 Uzlopak

I don't think this is an undici specific issue, as same thing would happen by using native http.request in node with keepAlive.

This seems to be an limitation with keepAlive implementation. The second request is assigned to the socket that is about to destroy, as it is not aware of that.

jazelly avatar Aug 22 '24 06:08 jazelly

To extend @jazelly's point - here is a small repo with node:http

// fetch-test.js
import { createServer, request } from "node:http";

const port = 8084;
const url = new URL("http://localhost:" + port);

const server = createServer((req, res) => res.end()).listen(port, async () => {
  function httpRequestPromise(reqOptions) {
    return new Promise((resolve, reject) => {
      const req = request(reqOptions, (res) => {
        console.log(`STATUS: ${res.statusCode}`);
        res.setEncoding("utf8");
        res.on("data", () => {});
        res.on("end", () => {
          resolve();
        });
      });

      req.on("error", (error) => {
        console.error(`Request error: ${error.message}`);
        reject(error);
      });
      req.end();
    });
  }

  await httpRequestPromise({
    headers: {
      // 'Content-Type': 'application/json',
      Connection: "keep-alive",
    },
    hostname: url.hostname,
    port: url.port,
    path: url.pathname,
  });

  server.closeIdleConnections();
  console.log("idle connections should have closed...");

  setImmediate(async () => {
    await httpRequestPromise({
      hostname: url.hostname,
      port: url.port,
      path: url.pathname,
    });
    server.close();
  });
});

when run this you should see:

idle connections should have closed...
Request error: read ECONNRESET
node:internal/process/promises:394
    triggerUncaughtException(err, true /* fromPromise */);
    ^

Error: read ECONNRESET
    at TCP.onStreamRead (node:internal/stream_base_commons:218:20) {
  errno: -54,
  code: 'ECONNRESET',
  syscall: 'read'
}

or

idle connections should have closed...
Request error: socket hang up
node:_http_client:530
    emitErrorEvent(req, new ConnResetException('socket hang up'));
                        ^

Error: socket hang up
    at Socket.socketOnEnd (node:_http_client:530:25)
    at Socket.emit (node:events:532:35)
    at endReadableNT (node:internal/streams/readable:1696:12)
    at process.processTicksAndRejections (node:internal/process/task_queues:90:21) {
  code: 'ECONNRESET'
}

if we have NODE_DEBUG=net then we can see:

Details
NET 49784: setupListenHandle null 8084 4 0 undefined
NET 49784: setupListenHandle: create a handle
NET 49784: bind to ::
NET 49784: createConnection [
  [Object: null prototype] {
    headers: { Connection: 'keep-alive' },
    hostname: 'localhost',
    port: '8084',
    path: null,
    host: 'localhost',
    keepAlive: true,
    scheduling: 'lifo',
    timeout: 5000,
    noDelay: true,
    servername: 'localhost',
    _agentKey: 'localhost:8084:',
    encoding: null,
    keepAliveInitialDelay: 1000
  },
  [Function (anonymous)],
  [Symbol(normalizedArgs)]: true
]
NET 49784: pipe false null
NET 49784: connect: find host localhost
NET 49784: connect: dns options { family: undefined, hints: 1024 }
NET 49784: connect: autodetecting
NET 49784: _read - n 16384 isConnecting? true hasHandle? true
NET 49784: _read wait for connection
NET 49784: connect/multiple: only one address found, switching back to single connection
NET 49784: connect: attempting to connect to 127.0.0.1:8084 (addressType: 4)
NET 49784: afterConnect
NET 49784: _read - n 16384 isConnecting? false hasHandle? true
NET 49784: Socket._handle.readStart
NET 49784: onconnection
NET 49784: _read - n 16384 isConnecting? false hasHandle? true
NET 49784: Socket._handle.readStart
STATUS: 200
NET 49784: _read - n 16384 isConnecting? false hasHandle? true
NET 49784: destroy
NET 49784: close
NET 49784: close handle
NET 49784: has server
NET 49784: SERVER _emitCloseIfDrained
NET 49784: SERVER handle? true   connections? 0
idle connections should have closed...
NET 49784: emit close
NET 49784: destroy
NET 49784: close
NET 49784: close handle
Request error: read ECONNRESET
node:internal/process/promises:391
    triggerUncaughtException(err, true /* fromPromise */);
    ^

Error: read ECONNRESET
    at TCP.onStreamRead (node:internal/stream_base_commons:218:20) {
  errno: -54,
  code: 'ECONNRESET',
  syscall: 'read'
}

Close event was emitted after closeIdleConnections

NET 39667: SERVER _emitCloseIfDrained
NET 39667: SERVER handle? true   connections? 0
idle connections should have closed...  <------------- this is the console log after closeIdleConnections
NET 39667: emit close
NET 39667: destroy
NET 39667: close
NET 39667: close handle

jakecastelli avatar Aug 22 '24 11:08 jakecastelli

@nodejs/http

KhafraDev avatar Aug 22 '24 16:08 KhafraDev

There are is only one thing to do: always retry the request if the other side is closed. This would mean configuring the retry interceptor by default for fetch also for POST etc in case of a network error.

mcollina avatar Aug 23 '24 15:08 mcollina

If this issue isn't specific to undici, is there a better place to file this issue?

neoncube2 avatar Apr 30 '25 15:04 neoncube2

Hey got the same error i don't know why... is anyone as a a fix?

takefy-dev avatar May 08 '25 06:05 takefy-dev

This should be relevant https://github.com/nodejs/node/issues/52649

Fix to reduce likelyhood of the race condition happening is released in V23 https://github.com/nodejs/node/commit/05ad94789916563664acb666a7ac367fd8b2cc8b

RasmusKard avatar Jul 14 '25 14:07 RasmusKard