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

• I have read the documentation.
• 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

got/source/core/index.ts

Lines 1469 to 1472 in 4cce4de

	if (this.destroyed) {
	this[kRequest]?.destroy();
	return;
	}

[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]

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

[szmarczak]

I wonder if this check

got/source/core/utils/timed-out.ts

Line 135 in 4cce4de

if (error === null) {

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?

[BouweCeunen]

Just an FYI I also got the same issue very suddenly, reading through this thread to see what I can do. Using version v11.8.5 of got. Will try to update to the latest got version.

[LucCADORET]

I am having this issue a lot with the version v11.8.5, and node 16. I am trying to upgrade to 12.1.0, but since it's pure esm, it's honestly very tedious to perform the migration of a whole project for this one bug.

[yacineblr]

Any news about this ?

[lukelafountaine]

@szmarczak Could the fix for this be applied to v11.x? My project is currently using CommonJS modules so we aren't able to upgrade to the latest version right now due to v12.x being pure ESM. I see there's a workaround above but we use got extensively in our projects and I'd prefer not to strew this workaround throughout our codebase unnecessarily. Also, as @LucCADORET mentions above, it's not practical to migrate our entire project to use ESM to fix this one bug.

[szmarczak]

The bug is not fixed in Got v12 either, I haven't got the time to inspect it in much detail yet

[shlomo-artlist]

I also recently started to see this error often in our services. We use got with shared custom extensions in all of our micro services, and it worked just fine, until we upgraded from Node 14 to Node 16.
We also can't just upgrade all of our services and modules to ESM.
If this cannot be fixed for CommonJS versions, please let us know.
If that's the case, I'm afraid we might need to switch to another library.

[jthomerson]

I have the same situation @lukelafountaine describes. It's unclear to me from the tagging of this issue if any of the core developers are going to work on this? Or if you're needing a community contribution?

[nduthoit]

Like @shlomo-artlist we've started seeing this error after upgrading from Node 12 to Node 16 (got v11.8.5) in requests with retries.

{
    "errorType": "Runtime.UnhandledPromiseRejection",
    "errorMessage": "Error: The `onCancel` handler was attached after the promise settled.",
    "reason": {
        "errorType": "Error",
        "errorMessage": "The `onCancel` handler was attached after the promise settled.",
        "stack": [
        "Error: The `onCancel` handler was attached after the promise settled.",
        "    at onCancel (/var/task/node_modules/p-cancelable/index.js:48:12)",
        "    at makeRequest (/var/task/node_modules/got/dist/source/as-promise/index.js:38:13)",
        "    at Request.<anonymous> (/var/task/node_modules/got/dist/source/as-promise/index.js:143:17)",
        "    at Object.onceWrapper (node:events:642:26)",
        "    at Request.emit (node:events:527:28)",
        "    at Request.emit (node:domain:475:12)",
        "    at Timeout.retry (/var/task/node_modules/got/dist/source/core/index.js:1278:30)",
        "    at listOnTimeout (node:internal/timers:559:17)",
        "    at processTimers (node:internal/timers:502:7)"
        ]
    },
    "promise": {},
    "stack": [
        "Runtime.UnhandledPromiseRejection: Error: The `onCancel` handler was attached after the promise settled.",
        "    at process.<anonymous> (file:///var/runtime/index.mjs:1131:17)",
        "    at process.emit (node:events:527:28)",
        "    at process.emit (node:domain:475:12)",
        "    at process.emit (/var/task/node_modules/source-map-support/source-map-support.js:516:21)",
        "    at emit (node:internal/process/promises:140:20)",
        "    at processPromiseRejections (node:internal/process/promises:274:27)",
        "    at processTicksAndRejections (node:internal/process/task_queues:97:32)"
    ]
}

@szmarczak could it be related to the change to use autoDestroy: true in incoming message introduced in Node 16 #33035?

I've been working on creating a test case to reproduce it. I'll report back if I'm successful.

[szmarczak]

No, it has to do with the retry mechanism. If you disable retries then the issue is gone.

[michael42]

No, it has to do with the retry mechanism. If you disable retries then the issue is gone.

Unfortunately, we still hit the issue even with got({ retry: 0 }) and a hand-written for-loop for retries (using got 11.8.5).

edit:
Interestingly, the stack trace still mentions retry:

Error: The `onCancel` handler was attached after the promise settled.
    at onCancel (node_modules/got/node_modules/p-cancelable/index.js:48:12)
    at makeRequest (node_modules/got/dist/source/as-promise/index.js:38:13)
    at Request.<anonymous> (node_modules/got/dist/source/as-promise/index.js:143:17)
    at Object.onceWrapper (node:events:628:26)
    at Request.emit (node:events:513:28)
    at Request.emit (node:domain:489:12)
    at Timeout.retry (node_modules/got/dist/source/core/index.js:1278:30)
    at listOnTimeout (node:internal/timers:559:17)
    at processTimers (node:internal/timers:502:7)

edit2:
My bad, our code does not always use the global got wrapper and did actually make request with retry enabled. Sorry for the noise.

[nduthoit]

@szmarczak after doing some troubleshooting we figured out that in our case the error is caused by an ECONNRESET error being triggered on the request after a successful response has been received and processed. The ECONNRESET triggers got's retry mechanism but by then the promise has already been resolved by the successful response.

A colleague was able to create a reproducible test case. It triggers the error with got v11.8.5 but not with got v12.5.0 (using node 16.15.0 in both cases). It does that by resetting the TCP connection on the server side shortly after sending the response. The code and sample output is available on this gist.

[spacecakes]

@szmarczak after doing some troubleshooting we figured out that in our case the error is caused by an ECONNRESET error being triggered on the request after a successful response has been received and processed. The ECONNRESET triggers got's retry mechanism but by then the promise has already resolved by the successful response.

I discovered this too recently. At least in our case it seems to be a race condition only happening on fast connections. As weird as it sounds, a workaround is to connect to a slower Internet connection (in my case through my phone). This has completely solved my team's issues with this error that we saw when downloading Chromium.

Your mileage may vary depending on where you see this error, but hopefully this might help someone.

[nduthoit]

@spacecakes wow, I wouldn't have expected that as a workaround...

I'm assuming you don't have control of got in this case? If you do (but can't upgrade to v12+) you could do the following to abort the retry when it's triggered by an ECONNRESET after a successful response:

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

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

const instance = got.extend({
    retry: {
        calculateDelay: (retryObject) => {
            const error = retryObject.error,
                  response = error.response;

            // Abort the retry (by returning a delay of 0) if we have an ECONNRESET
            // error after a successful response.
            if (error.code === 'ECONNRESET' && response && isResponseOk(response)) {
                try {
                    console.info(JSON.stringify({
                        evt: 'got-abort-late-econnreset-retry',
                        error: error,
                        response: {
                            statusCode: response.statusCode,
                            statusMessage: response.statusMessage,
                            complete: response.complete,
                        },
                    }));
                } catch(err) {
                    console.error(err);
                }

                return 0;
            }

            return retryObject.computedValue;
        },
    }
});

[spacecakes]

@spacecakes wow, I wouldn't have expected that as a workaround...

You can imagine it took some time and trial and error to figure this out. 😅

We don't have control no. It's a peer dependency in our test suite that downloads Chromium, which in turn uses got. Me and Swedish college were the only ones in our team experiencing it, and the only ones on fast fiber connections.

It doesn't make any sense to me either, but we've been able to repeat it; if fails consistently on 250MB+ connections and works consistently on lesser ones. Fortunately once installed we don't have to run it again for a long time.

[EdgarHarutyunyan02]

I am having this issue with got v11.8.6 and Node 20 when I have http2 enabled. With http1.1 I don't have issues.

Snippet of my code below.

got.get(`https://www.google.com`,
  {
    timeout: { request: 100 }, // Made the timeout small so it's retried.
    http2: true,
    dnsCache: true,
    retry: 3,
  },
)