The onCancel handler was attached after the promise settled

[yovanoc]

Describe the bug

• Node.js version: 14.13
• OS & version: MacOS Catalina

The onCancel handler was attached after the promise settled

Actual behavior

This unhandled exception is not catch by a try/catch, but I see that it happen after a timeout error like this issue #1460

Checklist

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

[szmarczak]

Can you please post some code?

[bkarlson]

Node.js version: 15.1.0 OS & version: Windows 10

Just encountered the same, very hard to repro, looks like a race-condition, I will try to dig deeper, but is there any way to catch such exception and just keep running?

Stack:

error: unhandledRejection: The `onCancel` handler was attached after the promise settled.
Error: The `onCancel` handler was attached after the promise settled.
    at onCancel (scripts\node_modules\p-cancelable\index.js:46:12)
    at makeRequest (scripts\node_modules\got\dist\source\as-promise\index.js:38:13)
    at Request.<anonymous> (scripts\node_modules\got\dist\source\as-promise\index.js:143:17)
    at Object.onceWrapper (node:events:434:26)
    at Request.emit (node:events:327:20)
    at Timeout.retry (scripts\node_modules\got\dist\source\core\index.js:1261:30)
    at listOnTimeout (node:internal/timers:555:17)
    at processTimers (node:internal/timers:498:7) 

[szmarczak]

Thanks for the report @bkarlson. Just to confirm - are you running Got 11.8.0?

[bkarlson]

Yes, 11.8.0, and the issue seems to be related to retry logic, because if I disable it (retry: 0) the error never happens. If I have retry: 3 with other retry options set to default, Got will throw this exception at some point.

[Giotino]

An easy fix would be using if (!thePromise._isPending) before setting the onCancel handlers, but it's undocumented.

I'm still investigating on the root cause.

[Kikobeats]

This is still happening.

Here my error trace: https://sentry.io/share/issue/6f578a2a936943cca5afe367e6732995/

[szmarczak]

@yovanoc @Kikobeats @bkarlson Can you try again? The p-cancelable package has received a neat fix that could potentially fix this error. Make sure to update the npm dependencies.

[Kikobeats]

@szmarczak I'm still experimenting the error

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

node version is: v14.16.0 got version is: 11.8.2 p-cancelable: 2.1.0

[szmarczak]

@Kikobeats Can you show the line(s) where you call got? Do you pass any hooks? Do you attach any event handlers?

[szmarczak]

@Kikobeats can you replace dist/as-promise/index.js with https://gist.github.com/szmarczak/310ee80c1085bdacd042c64fd992ef76 ? I made some changes so it logs what happened.

[szmarczak]

@bkarlson @yovanoc Can you too try the above?

[Kikobeats]

@szmarczak In my case is hard to say since there are a couple of dependencies using got and the stack trace is not revealing the details about which the origin of the problem.

Also, since this is running a production environment, I can't replace it in an easy way.

Maybe can you release a got RC version so I can force to be used?

[szmarczak]

~~I have an idea how to reproduce this. request.destroy() may be called, the promise may be canceled, but request hasn't been emitted yet and there is no check if it has been destroyed. Will check this.~~

[szmarczak]

Actually no because it's destroyed here https://github.com/sindresorhus/got/blob/4cce4de19ed577f481ba45a023b395a29cadce86/source/core/index.ts#L1469-L1472

[szmarczak]

~~I think I finally may be able to reproduce this.~~ Actually I can't figure this out :( This is definitely not via afterResponse hook. This must be related to timeouts.

[szmarczak]

@Kikobeats What is the timeout event? Is it request event? It'd be best if you shared the entire timeout error, including timeoutError.timings.

[szmarczak]

Also can you do npm ls got and show me which versions are being used?

[szmarczak]

@Kikobeats @bkarlson @yovanoc If your project uses Got directly you can try

const isResponseOk = response => {
	const {statusCode} = response;
	const limitStatusCode = response.request.options.followRedirect ? 299 : 399;

	return (statusCode >= 200 && statusCode <= limitStatusCode) || statusCode === 304;
};

const instance = got.extend({
    hooks: {
        afterResponse: [
            response => {
                if (isResponseOk(response)) {
                    response.request.destroy();
                }
            
                return response;
            }
        ]
    }
});

If so, please let me know if that fixes the issue.

[Kikobeats]

Hey @szmarczak, I'm running your code snippet on my production servers since yesterday and I didn't experiment errors until now (maybe it needs a bit of extra time)

[CvBlixen]

If so, please let me know if that fixes the issue.

That one fixed the issue for me as well. Thank you very much @szmarczak ! 🙏🏻

I am running got as part of generating a fake environment with lots of pictures. I have a feeling many uploads in quick succession are causing this.

[szmarczak]

@CvBlixen Yes! If you have set the response timeout and the request payload has been fully written after the response event has been emitted, this bug can occur.

It can also happen with a read timeout, when the response (not the request) emits an error.

[szmarczak]

The issue can also occur when a send timeout is set and the connection fails. socket.writable check is missing in https://github.com/sindresorhus/got/blob/4cce4de19ed577f481ba45a023b395a29cadce86/source/core/utils/timed-out.ts#L157

Actually no, because request is destroyed on error.

[szmarczak]

Also the secureConnect timeout should not run if rejectUnauthorized is set to false.

[szmarczak]

I wonder if this check https://github.com/sindresorhus/got/blob/4cce4de19ed577f481ba45a023b395a29cadce86/source/core/utils/timed-out.ts#L135 can be replaced with socket.connecting.

[szmarczak]

request timeout can also cause this. For example when the error is emitted on response instead. Another possibility could be that request.response is already defined when addTimeout is ran.

[szmarczak]

@CvBlixen @bkarlson Before you applied the fix, were you getting TimeoutErrors as well? If so, can you share the stack trace along with the message please?

[tsightler]

I'm not sure if this will help, but I think I'm seeing this. I've been attempting to troubleshoot why a network interruption causes my code (which uses ring-client-api which uses got) stops updating even after the network connection is reestablished, but only when using http2. I modified ring-client-api to set the timeout to 10 seconds, and then I interrupt the network connection to create the timeout but I get this which I can't seem to trap:

(node:69900) UnhandledPromiseRejectionWarning: Error: The `onCancel` handler was attached after the promise settled.
    at onCancel (/opt/ring-mqtt/node_modules/ring-client-api/node_modules/p-cancelable/index.js:48:12)
    at makeRequest (/opt/ring-mqtt/node_modules/ring-client-api/node_modules/got/dist/source/as-promise/index.js:38:13)
    at Request.<anonymous> (/opt/ring-mqtt/node_modules/ring-client-api/node_modules/got/dist/source/as-promise/index.js:143:17)
    at Object.onceWrapper (events.js:422:26)
    at Request.emit (events.js:315:20)
    at Timeout.retry (/opt/ring-mqtt/node_modules/ring-client-api/node_modules/got/dist/source/core/index.js:1264:30)
    at listOnTimeout (internal/timers.js:554:17)
    at processTimers (internal/timers.js:497:7)
(Use `node --trace-warnings ...` to show where the warning was created)
(node:69900) UnhandledPromiseRejectionWarning: Unhandled promise rejection. This error originated either by throwing inside of an async function without a catch block, or by rejecting a promise which was not handled with .catch(). To terminate the node process on unhandled promise rejection, use the CLI flag `--unhandled-rejections=strict` (see https://nodejs.org/api/cli.html#cli_unhandled_rejections_mode). (rejection id: 1)
(node:69900) [DEP0018] DeprecationWarning: Unhandled promise rejections are deprecated. In the future, promise rejections that are not handled will terminate the Node.js process with a non-zero exit code.
events.js:292
      throw er; // Unhandled 'error' event
      ^

TimeoutError: Timeout awaiting 'request' for 10000ms
    at Timeout.timeoutHandler [as _onTimeout] (/opt/ring-mqtt/node_modules/ring-client-api/node_modules/got/dist/source/core/utils/timed-out.js:36:25)
    at listOnTimeout (internal/timers.js:556:17)
    at processTimers (internal/timers.js:497:7)
Emitted 'error' event on Request instance at:
    at emitErrorNT (internal/streams/destroy.js:106:8)
    at errorOrDestroy (internal/streams/destroy.js:168:7)
    at internal/streams/writable.js:613:7
    at /opt/ring-mqtt/node_modules/ring-client-api/node_modules/got/dist/source/core/index.js:1348:17
    at ClientRequest.onerror (internal/streams/writable.js:680:5)
    at ClientRequest.emit (events.js:327:22)
    at ClientRequest.origin.emit (/opt/ring-mqtt/node_modules/ring-client-api/node_modules/@szmarczak/http-timer/dist/source/index.js:39:20)
    at emitErrorNT (internal/streams/destroy.js:106:8)
    at emitErrorCloseNT (internal/streams/destroy.js:74:3)
    at processTicksAndRejections (internal/process/task_queues.js:80:21) {
  event: 'request',
  code: 'ETIMEDOUT'
}

Any help would be appreciated.

[szmarczak]

@tsightler So... are you able to reproduce this?

[tsightler]

Yes, 100% reproducible if I have an active HTTP2 session with a configured timeout and then block the internet connection to simulate a communication failure. This produces a request timeout as shown above. I can somewhat overcome the issue if I set retry: 0, as this seems to suppress the error, although then I get a different error from http2-wrapper, although that one doesn't crash the process so I'm thinking I may be able to work around it.

I'm admittedly super new to all of this as normally the underlying interactions with HTTP are below the code I maintain. The API I use recently switched to using HTTP2 by default for the connection to the servers, and this has introduced the issue of failure to reconnect. I did notice that you say that HTTP2 is only supported for Node 15, so that's interesting, although I did try Node 15, but the timeout error above persisted.

[Allain55]

Got this bug today after migrating to esm. Not sure if it's related but this code's worked for months