Conditional unhandled 'error' event when http.request with `.lookup`

[loynoir]

Version

20.4.0

Platform

Docker ArchLinux 6.1.35-1-lts

Subsystem

No response

What steps will reproduce the bug?

https://github.com/loynoir/reproduce-node-48771

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

• ip blackhole like behavior

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

Make it possible to catch error, and exit with 0.

What do you see instead?

Error is not caught, and exit with 1.

Additional information

No response

[bnoordhuis]

I'm not able to reproduce. Let's try to reduce the test case. What happens when you run this?

const lookup = (_0, _1, cb) => cb(null, [{address:"192.168.144.2", family:4}])
const s = require("net").connect({host:"example.com", port:80, lookup})
s.on("error", console.log) // reached?

[loynoir]

// @ts-nocheck
const lookup = (_0, _1, cb) => cb(null, [{ address: "192.168.144.2", family: 4 }])
const s = require("net").connect({ host: "example.com", port: 80, lookup })
s.on("error", (err) => {
  console.log({ err })
})

$ sudo ip route del blackhole 192.168.144.2
$ curl -s 192.168.144.2 >/dev/null && echo OK
OK
$ node ./src/extra/reproduce.cjs && echo OK
^C
$ sudo ip route add blackhole 192.168.144.2
$ node ./src/extra/reproduce.cjs && echo OK
{
  err: Error: connect EINVAL 192.168.144.2:80 - Local (0.0.0.0:0)
      at internalConnect (node:net:1087:16)
      at defaultTriggerAsyncIdScope (node:internal/async_hooks:464:18)
      at emitLookup (node:net:1478:9)
      at lookup (/workspaces/loynoir/repo/reproduce-node-48771/src/extra/reproduce.cjs:2:32)
      at emitLookup (node:net:1402:5)
      at defaultTriggerAsyncIdScope (node:internal/async_hooks:464:18)
      at lookupAndConnectMultiple (node:net:1401:3)
      at node:net:1347:7
      at defaultTriggerAsyncIdScope (node:internal/async_hooks:464:18)
      at lookupAndConnect (node:net:1346:5) {
    errno: -22,
    code: 'EINVAL',
    syscall: 'connect',
    address: '192.168.144.2',
    port: 80
  }
}
OK

[bnoordhuis]

Okay, so that works for you as well. Please try expanding the test until you have a minimal reproducer.

[loynoir]

@bnoordhuis

https://github.com/loynoir/reproduce-node-48771

I think this is the minimal reproduce.

I guess, some node code is not wrap with process.nextTick.

So, if user not use

nextTick(() => {
  ...
  callback(...

In some situation, there is unhandled 'error' event within http.request, and leads to

• Within script, like https://github.com/loynoir/reproduce-node-48771, http.request throw an un-catch-able error

• Within worker, like error caught, but exitCode is not zero #48756, http.request throw an error, although error is caught, but worker exitCode is not zero.

[ShogunPanda]

FYI I tested if my network family autoselection was involved into this. Apparently is not: if you change lines 19 and 23 in `` in your repro repo to this:

if (_options.all) {
  callback(null, [{ address: opt.ip, family: 4 }]);
} else {
  callback(null, opt.ip, 4);
}

to accomodate for both single and multiple DNS lookup, then the problem will happen even if you use --no-network-family-autoselection.

In macOS in order to reproduce the problem you can route that IP to something unreachable. For instance:

sudo route add 192.168.144.2 10.3.0.1

(10.3.0.1 is unreachable from my system, you might have to use another IP).

With the unreachable IP setup, I tried the narrow down example in #48771 (comment) and it worked, so it seems like the problem is not on the net module but rather in http which is not setting the error listener fast enough.

@mcollina Any thoughts on this?

[mcollina]

It looks like a bug, unfortunately, I don't have time to dig deep on how to fix it. I've never seen this problem happen in practice, but I guess it can happen if the kernel is really fast in responding.

A quick code review spotted the problem: when a socket is assigned to a ClientRequest, we defer to the next tick setting an error handler:

node/lib/_http_client.js

Lines 860 to 900 in a2fc4a3

	ClientRequest.prototype.onSocket = function onSocket(socket, err) {
	// TODO(ronag): Between here and onSocketNT the socket
	// has no 'error' handler.
	process.nextTick(onSocketNT, this, socket, err);
	};
	function onSocketNT(req, socket, err) {
	if (req.destroyed || err) {
	req.destroyed = true;
	function _destroy(req, err) {
	if (!req.aborted && !err) {
	err = connResetException('socket hang up');
	}
	if (err) {
	req.emit('error', err);
	}
	req._closed = true;
	req.emit('close');
	}
	if (socket) {
	if (!err && req.agent && !socket.destroyed) {
	socket.emit('free');
	} else {
	finished(socket.destroy(err || req[kError]), (er) => {
	if (er?.code === 'ERR_STREAM_PREMATURE_CLOSE') {
	er = null;
	}
	_destroy(req, er || err);
	});
	return;
	}
	}
	_destroy(req, err || req[kError]);
	} else {
	tickOnSocket(req, socket);
	req._flush();
	}
	}

The 'error' handler is set in tickOnSocket:

node/lib/_http_client.js

Line 822 in a2fc4a3

socket.on('error', socketErrorListener);

Deferring by a nextTick is fine for every I/O but not a synchronous DNS error:

node/lib/net.js

Lines 1414 to 1418 in a2fc4a3

	// net.createConnection() creates a net.Socket object and immediately
	// calls net.Socket.connect() on it (that's us). There are no event
	// listeners registered yet so defer the error event to the next tick.
	process.nextTick(connectErrorNT, self, err);
	return;

.

Can that happen?

---

As a side note, I'd recommend you to use undici as it should better handle this case (and be easier to fix).

[loynoir]

@mcollina

I've never seen this problem happen in practice

Can that happen?

When I use .lookup without nextTick, I did see node.js http.request throw un-catch-able error.

Although I cannot reproduce same error, I found ip-blackhole may also let http.request throw un-catch-able error.

[ShogunPanda]

@mcollina I think the only way to fix this is to defer the error emitting (self.destroy(ex)) in internalConnect and internalConnectMultiple via nextTick. WDYT?

[loynoir]

As a side note, I'd recommend you to use undici as it should better handle this case (and be easier to fix).

Verified undici don't have this bug.

Error is caught within undici.

$ sudo ip route add blackhole 192.168.144.4
$ cat reproduce.mjs 
import { Agent } from 'undici'

try {
    await fetch('http://example.com', {
        dispatcher: new Agent({
            connect: {
                lookup: (hostname, options, callback) => {
                    // node <20
                    // callback(null, '192.168.144.4', 4)
                    // node 20
                    callback(null, [{ address: '192.168.144.4', family: 4 }])
                }
            }
        })
    })
} catch (caught) {
    console.warn({ caught })
}
$ node reproduce.mjs
{
  caught: TypeError: fetch failed
      at Object.fetch (node:internal/deps/undici/undici:11576:11)
      at process.processTicksAndRejections (node:internal/process/task_queues:95:5)
      at async file:///tmp/tmp.ogEc9I0rez/reproduce.mjs:4:5 {
    cause: Error: connect EINVAL 192.168.144.4:80 - Local (0.0.0.0:0)
        at internalConnect (node:net:1087:16)
        at defaultTriggerAsyncIdScope (node:internal/async_hooks:464:18)
        at emitLookup (node:net:1478:9)
        at lookup (file:///tmp/tmp.ogEc9I0rez/reproduce.mjs:11:21)
        at emitLookup (node:net:1402:5)
        at defaultTriggerAsyncIdScope (node:internal/async_hooks:464:18)
        at lookupAndConnectMultiple (node:net:1401:3)
        at node:net:1347:7
        at defaultTriggerAsyncIdScope (node:internal/async_hooks:464:18)
        at lookupAndConnect (node:net:1346:5) {
      errno: -22,
      code: 'EINVAL',
      syscall: 'connect',
      address: '192.168.144.4',
      port: 80
    }
  }
}

[mcollina]

@mcollina I think the only way to fix this is to defer the error emitting (self.destroy(ex)) in internalConnect and internalConnectMultiple via nextTick. WDYT?

@ShogunPanda yes