Got: Uncaught 'TimeoutError' exception

[devjerry]

Describe the bug

• Node.js version: 12.x.x (it's electron 5.0.7)
• OS & version: Windows 8.1 & 10 (both 64-bit)

I'm sporadically getting uncaught 'TimeoutError' exception that is hard to reproduce in controlled manner. Happens in production where the app is making a lot of requests and running on devices with intermitted mobile internet connection.

Actual behavior

Uncaught exception:

TimeoutError: Timeout awaiting 'request' for 10000ms
    at timeoutHandler (C:\myproject\node_modules\got\dist\source\core\utils\timed-out.js:36:25)

Expected behavior

There shouldn't be any uncaught exception.

Code to reproduce

process.on('uncaughtException', function(err) {
    console.log('UNHANDLED ERROR:', err.stack);
});

async function getResponse() {
    try {
        return await got('https://someurl.com/', { timeout: 10000, retry: 0 }).text();
    } catch (err) {
        console.log('HANDLED ERROR:', err.stack);
    }
}

When there's some timeout error, most of the time it's handled properly:

HANDLED ERROR: RequestError: Timeout awaiting 'request' for 10000ms
    at ClientRequest.<anonymous> (C:\myproject\node_modules\got\dist\source\core\index.js:934:25)
    at Object.onceWrapper (events.js:282:20)
    at ClientRequest.emit (events.js:199:15)
    at ClientRequest.EventEmitter.emit (domain.js:469:20)
    at ClientRequest.origin.emit (C:\myproject\node_modules\@szmarczak\http-timer\dist\source\index.js:39:20)
    at Socket.socketErrorListener (_http_client.js:401:9)
    at Socket.emit (events.js:194:13)
    at Socket.EventEmitter.emit (domain.js:469:20)
    at emitErrorNT (internal/streams/destroy.js:91:8)
    at emitErrorAndCloseNT (internal/streams/destroy.js:59:3)
    at processTicksAndRejections (internal/process/task_queues.js:81:17)
    at timeoutHandler (C:\myproject\node_modules\got\dist\source\core\utils\timed-out.js:36:25)

But in some rare occasions I get this unhandled exception:

UNHANDLED ERROR: TimeoutError: Timeout awaiting 'request' for 10000ms
    at timeoutHandler (C:\myproject\node_modules\got\dist\source\core\utils\timed-out.js:36:25)

Checklist

• [x] I have read the documentation.
• [ ] I have tried my code with the latest version of Node.js and Got.

[szmarczak]

Is this reproducible without Electron?

[devjerry]

I can't tell @szmarczak.

Currently I have several electron apps running in production and to get you some idea in the last 48 hrs they made around 100k - 200k of such requests with got and 7 of them ended up with this uncaught exception. So it seems like very obscure bug.

I've spend few days isolating this bug as much as I could. Previously I was using different library for requests and it was working months without single error. To rule out everything else and to observe the error I've replaced the old library with got just in one single line of code.

This is all I got for now.

[szmarczak]

Can you precisely specify your Node.js version please?

[devjerry]

Electron 5.0.7 is using Node.js 12.0.0.

I'm also updating to latest Electron so I'll see if the problem persists.

[devjerry]

Updated to latest Electron 10.1.2 (using Node.js 12.16.3) and Got 11.7.0 - the problem persists.

[devjerry]

I was able to reproduce the problem in VM with Win 10 64-bit with network's default gateway pointing to LTE router that is "frozen" (doesn't work properly, needs to be restarted).

So far I didn't figure out how to reproduce the environment without the router (maybe something else that can cause socket hang up error).

The result is that this problem happens only in Electron renderer process (not in pure Node.js). Here are the tests:

Node.js (12.16.3 & 12.18.4)

Code:
https://gist.github.com/devjerry/b51865a1c3d0a32889e80289a89aa03a
run by npm start

Output:

HANDLED ERROR: RequestError: Timeout awaiting 'request' for 5000ms
    at ClientRequest.<anonymous> (C:\got-error-nodejs\node_modules\got\dist\source\core\index.js:954:25)
    at Object.onceWrapper (events.js:422:26)
    at ClientRequest.emit (events.js:327:22)
    at ClientRequest.origin.emit (C:\got-error-nodejs\node_modules\@szmarczak\http-timer\dist\source\index.js:39:20)
    at TLSSocket.socketErrorListener (_http_client.js:426:9)
    at TLSSocket.emit (events.js:315:20)
    at emitErrorNT (internal/streams/destroy.js:92:8)
    at emitErrorAndCloseNT (internal/streams/destroy.js:60:3)
    at processTicksAndRejections (internal/process/task_queues.js:84:21)
    at Timeout.timeoutHandler [as _onTimeout] (C:\got-error-nodejs\node_modules\got\dist\source\core\utils\timed-out.js:36:25)
    at listOnTimeout (internal/timers.js:551:17)
    at processTimers (internal/timers.js:492:7)

DONE

Everything OK as expected.

Electron (10.1.2 using Node.js 12.16.3) - main process

Code:
https://gist.github.com/devjerry/15098f375d55416454cb9e234c275162
run by npm start

Output:
exactly the same as for Node.js test

Everything OK as expected.

Electron (10.1.2 using Node.js 12.16.3) - renderer process

Code:
https://gist.github.com/devjerry/f3311821fc563f483c95bf6790dde9e6
run by npm start

Output:

Uncaught TimeoutError: Timeout awaiting 'request' for 5000ms
    at timeoutHandler (C:\got-error-electron-renderer\node_modules\got\dist\source\core\utils\timed-out.js:36:25)

HANDLED ERROR: RequestError: socket hang up
    at ClientRequest.<anonymous> (C:\got-error-electron-renderer\node_modules\got\dist\source\core\index.js:957:25)
    at Object.onceWrapper (events.js:417:26)
    at ClientRequest.emit (events.js:322:22)
    at ClientRequest.origin.emit (C:\got-error-electron-renderer\node_modules\@szmarczak\http-timer\dist\source\index.js:39:20)
    at TLSSocket.socketCloseListener (_http_client.js:400:11)
    at TLSSocket.emit (events.js:322:22)
    at net.js:672:12
    at connResetException (internal/errors.js:608:14)
    at TLSSocket.socketCloseListener (_http_client.js:400:25)
    at TLSSocket.emit (events.js:322:22)
    at net.js:672:12
    at TCP.done (_tls_wrap.js:565:7)

DONE

And here's the problem. First Got throws uncaught exception and then another one that is handled.

[szmarczak]

So it's caused by https://github.com/nodejs/node/issues/33335

I guess we will have to patch Node.js native destroy implementation to fix this.

[szmarczak]

@sindresorhus Should we go with

const applyDestroyPatch = stream => {
    const kDestroy = Symbol('destroy');

    if (process.versions.node.split('.')[0] >= 14) {
        return;
    }

    stream[kDestroy] = stream.destroy;
    stream.destroy = (...args) => {
        if (!stream.destroyed) {
            return stream[kDestroy](...args);
        }
    };
};

applyDestroyPatch(everyStreamGotCreates);

or patch the native stream module on require('got')? The latter could potentially create some issues in other NPM packages.

[sindresorhus]

Let's go with applyDestroyPatch.

[yovanoc]

I've got this error too on node 14.12 but in a different manner i guess. Each time this timeout error is handled it follow by this unhandled error:

The onCancel handler was attached after the promise settled

[szmarczak]

@yovanoc can you open another issue for this?

[Kikobeats]

I'm experimenting the same issue.

https://sentry.io/share/issue/eba599be6c0b4016b3b365a29172b176/

Node version: v14.15.0
got version: v11.8.1

[Giotino]

@Kikobeats I don't think yours is a issue, it's a common TimeoutError and it was handled (as reported by sentry: handled true)

[Kikobeats]

the handled on sentry context has a different meaning.

I'm sure this is related because every time this happens, the process exit abruptly

(note how to the http server respawn again)

and yes, I have try/catch, but it doesn't matter because the nodejs process itself crashed

[Kikobeats]

experimented the same issue at Node v15.5.1

[szmarczak]

Hmm weird as it shouldn't happen on Node.js 15

[larssn]

Just to confirm, we're seeing this (rarely) in Google Cloud Functions which is Node 12.

[sindresorhus]

If someone wants to see this fixed soon, there's already a test case and patch provided in this thread, so someone just needs to put them together and write a test.

[szmarczak]

Fixed in 31d80efaabdc6b0fc9ae5195ce8db623aceb9c13

[Kikobeats]

Looks like the patch is only targeting node v14 or lower while I experimented with the error on node v15 🤔

but let's see. Glad to be able to test it in the next got version and to be able to report feedback