Node: v14.10.0 changes behavior of existing code (got)

[benjamincburns]

• Version: v14.10.0
• Platform: All
• Subsystem: Uncertain

What steps will reproduce the bug?

[email protected] hangs when running under v14.10.0. Works fine under earlier versions, including v14.9.0. See sindresorhus/got#1441 for more details.

As v14.10.0 was a minor version bump, I wouldn't expect it to break existing code.

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

Every time.

What is the expected behavior?

got can make a request successfully

What do you see instead?

got hangs indefinitely (promise doesn't resolve - not sure why)

Additional information

got has over 12 million weekly downloads. This issue should probably be addressed quickly.

[targos]

Reproduction:

require('got')('https://www.google.com').then(console.log, console.log)

This logs the response in Node.js 14.9.0 and exits without any logs in Node.js 14.10.0

[targos]

I'm bisecting...

[targos]

4bb40078da9ff51372459ff187b74866d73c3fb2 is the first bad commit
Author: Robert Nagy @ronag
Date: Tue Jun 23 23:08:14 2020 +0200

stream: simpler and faster Readable async iterator

Reimplement as an async generator instead of a custom
iterator class.

Backport-PR-URL: https://github.com/nodejs/node/pull/34887
PR-URL: https://github.com/nodejs/node/pull/34035
Refs: https://github.com/nodejs/node/issues/34680
Reviewed-By: Matteo Collina <[email protected]>
Reviewed-By: Benjamin Gruenbaum <[email protected]>
Reviewed-By: James M Snell <[email protected]>

[ronag]

Would someone mind to dig into this a bit a look exactly where in got the problem occurs? I'm a bit swamped today but might be able to take a look if I know more specifically where e.g. async generators come into play?

[ronag]

Should got be added to CITGM?

[targos]

Got was disabled in CITGM because there were issues with ESLint that made it always fail: https://github.com/nodejs/citgm/issues/825, https://github.com/nodejs/citgm/pull/795

[targos]

This happens because got treats calls to Stream#_destroy as error cases:

https://github.com/sindresorhus/got/blob/408e22aed99300afd4af49a4eb50963665d8a144/source/core/index.ts#L2666-L2691

The promise never resolves because _isAboutToError is checked to return early here:

https://github.com/sindresorhus/got/blob/1f132e88b4e9b295631637757d64307032a4e56e/source/as-promise/index.ts#L63-L65

The _destroy method is called from here:

https://github.com/nodejs/node/blob/1204400d6411694d08bde0c3c197c9a72b72f570/lib/_stream_readable.js#L1117-L1119

[ronag]

Seems like a bug in got. However, we should probably try to avoid breaking in a semver minor.

As far as I can see the old implementation also did destroy but with a slightly different timing. Might be enough to wrap the destroy in a nextTick.

[ronag]

Ok, this might actually be an error in the PR. We should not call destroy before end has been emitted.

I'll try to prepare a PR tonight.

If someone wants to work on it asap something like this should fix it:

  try {
    const state = stream._readableState;
    while (true) {
      const chunk = stream.read();
      if (chunk !== null) {
        yield chunk;
      } else if (state.errored) {
        throw state.errored;
      } else if (state.endEmitted) {
        break;
      } else if (state.closed) {
        // TODO(ronag): ERR_PREMATURE_CLOSE?
        break;
      } else {
        await new Promise(next);
      }
    }
  } catch (err) {
    destroyImpl.destroyer(stream, err);
    throw err;
  } finally {
    destroyImpl.destroyer(stream, null);
  }

i.e. change state.ended to state.endEmitted.

[ronag]

I'm not sure whether the above will resolve the referenced issue though.

[richardlau]

I'm not sure whether the above will resolve the referenced issue though.

I've just tested it and it does not 😞.

Got was disabled in CITGM because there were issues with ESLint that made it always fail: nodejs/citgm#825, nodejs/citgm#795

We should unskip it in the lookup if we can. FWIW you can run "citgm got" instead of "citgm-all" to still test the module, e.g. against the current master branch: https://ci.nodejs.org/job/citgm-smoker/2461/

Edit: CI contains lint warnings similar to nodejs/citgm#795 but the test is also timed out.

[richardlau]

Unfortunately it looks like got still times out with https://github.com/nodejs/node/pull/35120. It's not clear to me if this is thought to be an issue with got itself (https://github.com/nodejs/node/issues/35116#issuecomment-689420916) or is something we need to push a new release for (cc @nodejs/streams).

If we do need to push a new release we should aim to do that by tomorrow (Thursday 10th September) at the latest since:

• There are security releases due out next Tuesday and one of the vulnerabilities being addressed in v14.x is rated as critical severity. We should aim to not block people from picking up the security release if it's going to break them.
• We have a policy of not releasing on a Friday.

I can push out a new release if required. Questions:

• Is a new release required?
• If so, can the issue be fixed by a PR by tomorrow? Unfortunately https://github.com/nodejs/node/pull/35120 in its current form does not fix this issue.
• If not, should we revert https://github.com/nodejs/node/commit/4bb40078da9ff51372459ff187b74866d73c3fb2?

cc @nodejs/releasers @nodejs/tsc

[ronag]

I think I've managed to figure out the problem. The old async iterator didn't destroy on success and got assumes destroy is an error.

I will try to sort out a PR.

[szmarczak]

@targos is right. The _isAboutToError check is done on the response event after the body has been read. If ~ClientRequest~ Got stream has autoDestroy set to true, then it will hang because it assumes it's an error. I'll fix this in a few hours.

[szmarczak]

So @ronag is also right. Node.js 14.10.0 broke autoDestroy. ~But since it is highly recommend that it is set to true, I will fix this on Got side anyway.~ Unfortunately it has to remain as false. The fix is quite complicated and we would need to release a breaking major change.

[richardlau]

I've opened a proposal for a v14.10.1 (https://github.com/nodejs/node/pull/35137) that reverts https://github.com/nodejs/node/commit/4bb40078da9ff51372459ff187b74866d73c3fb2. It sounds like we'll need more time to address the issues being seen, and reverting the commit gets the got tests passing with CITGM on at least some platforms (before it was failing across the board).

[MylesBorins]

@richardlau should we be reverting from master as well?

[joaopaulobdac]

I just spent like 6 hours trying to figure out why I was getting (failed)net::ERR_EMPTY_RESPONSE errors when fetching my http server.

async function getParsedBody(request) {
    let body = ''

    for await (const chunk of request) {
        body += chunk
    }

    try {
        return JSON.parse(body)
    } catch {
        return {}
    }
}

When I remove the for await of loop the server is able to handle requests normally again. This was pretty confusing to debug because node does not inform that the request was destroyed prematurely. I thought it was some problem with the browser haha

[mcollina]

it will hang because it assumes it's an error. I'll fix this in a few hours.

@szmarczak note that this is a bug on got side. .destroy() is not an error-generating scenario, .destroy(err) is.

---

@MylesBorins it should be reverted in v14 and then fixed on master and v15.

[ronag]

@joaopaulobdac would you mind providing a complete example? Are you also using got?

[joaopaulobdac]

I'm not using got or anything. Sorry for throwing that code example at you out of nowhere! It's just that I have a raw node http server and I call getParsedBody when a request comes in. After I found out that that for await of loop was causing the response to end I wanted to open an issue.

I downgraded node to 14.9.0 and the server handles requests normally again.

[szmarczak]

@szmarczak note that this is a bug on got side. .destroy() is not an error-generating scenario, .destroy(err) is.

Why is it so? autoDestroy is false so it shouldn't call .destroy(), therefore _isAboutToError would return false. I'm fully aware that Got incorrectly throws even after the Got stream is destroyed. To use autoDestroy it needs to be a breaking major release for Got (unless I find some other way to do stuff)

[ronag]

@joaopaulobdac That's great information! Any chance you could share a minimal reproducible example?

[ronag]

@szmarczak We are reverting the change. There is a problem with got but as you said we should not cause such a breaking change in semver-minor. I'm sorry for the inconvenience this has caused. Did not consider this.

That being said I'd very much appreciate if you could continue helping with a fix in v15 and making got pass in CITGM.

[szmarczak]

There is a problem with got but as you said we should not cause such a breaking change in semver-minor.

I meant that if Got was to use autoDestroy: true then we should do a major release at Got.

I'm sorry for the inconvenience this has caused. Did not consider this.

No problem. I'm glad that we see this "bug" sooner than later :D

That being said I'd very much appreciate if you could continue helping with a fix in v15 and making got pass in CITGM.

I've been actually debugging for ~10 mins and have no thoughts to stop. I'm continuing :)

[joaopaulobdac]

@ronag Here you go:

const http = require('http')

async function getParsedBody(request) {
    let body = ''

    for await (const chunk of request) {
        body += chunk
    }

    try {
        return JSON.parse(body)
    } catch {
        return {}
    }
}

const server = http.createServer(async (request, response) => {
    const body = await getParsedBody(request)

    response.statusCode = 200
    response.end(JSON.stringify(body))
})

server.listen(3000)

$ node -v
v14.9.0

$ http POST http://localhost:3000/ test=testing
HTTP/1.1 200 OK
Connection: keep-alive
Content-Length: 18
Date: Thu, 10 Sep 2020 08:15:17 GMT
Keep-Alive: timeout=5

{"test":"testing"}

$ node -v
v14.10.0

$ http POST http://localhost:3000/ test=testing
http: error: ConnectionError: ('Connection aborted.', RemoteDisconnected('Remote end closed connection without response')) while doing a POST request to URL: http://localhost:3000/

[ronag]

I believe this has been resolved in latest 14.x.