Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Calling res.end() twice stalls follow-up HTTP request (drain event is missing) #36620

Closed
kachkaev opened this issue Dec 24, 2020 · 2 comments
Closed
Labels
confirmed-bug Issues with confirmed bugs. http Issues or PRs related to the http subsystem.

Comments

@kachkaev
Copy link

kachkaev commented Dec 24, 2020

  • Version: 14.0.0...14.15.3 (latest lts), 15.0.0...15.5.0 (latest stable)
  • Platform: macos / ubuntu / windows
  • Subsystem: N/A

What steps will reproduce the bug?

Originally, I noticed this behaviour in a Next.js app and it took me quite a while to drill down to the bottom of it. You can find a plain MWE here: https://github.com/kachkaev/node-http-response-double-end-call-breaking-drain-event (no NPM packages involved).

Since Node version 14.0.0, calling res.end() twice in a body-less response seems to be silencing the drain event in a follow-up HTTP request if it uses the same connection. This can happen in practice when redirecting a client to a heavy page and using compression package as middleware.

I understand that calling res.end() twice is a developer mistake, however it does not seem right to have to debug such a small oversight for more than two working days 😅 When using res.redirect(...) helper method in Next.js, it’s easy to forget that it’s not only doing res.writeHead(...) for you, but also calls res.end(). Seeing res.redirect(...); res.end() does not feel too wrong initially and there is no feedback from the server or the tooling to suggest that this involves res.end() being called twice.

Here are the reproduction steps from the server POV:

  1. A client establishes a connection and requests a page that results with a redirect:

    res.writeHead(302, { Location: "/another-page" });
    res.end();
    res.end(); // called twice intentionally
  2. The same client immediately comes back with another request, which is meant to return 200 and contain some payload.

    • If the size of the payload is small enough to fit a single res.write(...), all works fine.

    • If the payload involves res.write(...) === trueres.on("drain", () => {...}), the second request is never finished because the drain event is never invoked.

You can look into how compression is using res.write(...) + res.on("drain", ...) to find a practical example: https://github.com/expressjs/compression/blob/3fea81d0eaed1eb872bf3e0405f20d9e175ab2cf/index.js#L193-L218

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

I am able to silence the drain event quite reliably on any Node version ≥14.0.0 on any OS. See the GitHub Workflow for my MWE.

What is the expected behavior?

Ideally, I would expect the second res.end() to not produce any side effects or at least to give me a warning. All works fine in Node v13.14.0 and below.

What do you see instead?

I stumbled across some magic behaviour which took more than two days to investigate 😅

Additional information

The unwanted side effect from a double call to res.end() is negated:

  • if the follow-up request does not share the connection with the first (body-less) request (i.e. curl called twice);
  • or if res.write("") is added to the first (body-less) request

Both observations are included into GitHub Workflows within the MWE repo. I also tried playing with res.end("") as a replacement for res.write(""), but it did not help.

@kachkaev kachkaev changed the title Calling res.end() twice stalls follow-up HTTP request (drain event is not called) Calling res.end() twice stalls follow-up HTTP request (drain event is missing) Dec 24, 2020
@RaisinTen RaisinTen added the http Issues or PRs related to the http subsystem. label Dec 25, 2020
@ronag
Copy link
Member

ronag commented Dec 26, 2020

Yes. This is a problem. I’ll prepare a PR.

@ronag ronag added the confirmed-bug Issues with confirmed bugs. label Dec 26, 2020
ronag added a commit to nxtedition/node that referenced this issue Dec 26, 2020
Calling .end() a second time should be a noop and not
leave the socket corked.

Fixes: nodejs#36620
@ronag
Copy link
Member

ronag commented Dec 27, 2020

#36650 has additional info

kodiakhq bot pushed a commit to vercel/next.js that referenced this issue Jan 4, 2021
… case (#20461)

This PR is a small follow-up to #14705. It saves Next.js users from falling into a [pretty nasty trap](nodejs/node#36620) in which I ended up last Friday. It took more than two days to investigate what was going on, so I hope I'm the last person who’s doing it 😅

Next.js-specific MWE: https://github.com/kachkaev/hanging-response-in-next-via-redirect-plus-compression (needs to be ran locally using Node 14.0.0+).

> <img width="521" alt="Screenshot 2020-12-24 at 20 50 00" src="https://user-images.githubusercontent.com/608862/103105989-a9b8dc00-4629-11eb-9be3-5108755604bf.png">

To reproduce the bug I’m fixing:

1. Pick a large http body size (64 or 128 KB)
1. Check _Call res.end() after res.redirect() in /api/redirect_
1. Navigate to a heavy page or an api handler via redirect
1. Observe that the http response is never finished.

If you set `compress` to `false` in `next.config.js` or pick a small payload size (< `zlib.Z_DEFAULT_CHUNK` after compression), the bug will not be observed. This is explained by the use of `res.on("drain", ...)` [by the `compression` package](https://github.com/expressjs/compression/blob/3fea81d0eaed1eb872bf3e0405f20d9e175ab2cf/index.js#L193-L218). The package itself is not the reason for an issue though, it seems to be in the Node’s built-in `http` package.

I’m happy to provide more info or GitHub CI to the MWE if needed. I was also thinking of adding some Next.js-specific testing, but could not come up with a compact and clear test plan. Happy to do this if there are any ideas.

cc @botv (author of #14705)
ronag added a commit to nxtedition/node that referenced this issue Jan 12, 2021
Calling .end() a second time should be a noop and not
leave the socket corked.

Fixes: nodejs#36620
@ronag ronag closed this as completed in 1b669b2 Jan 12, 2021
ronag pushed a commit that referenced this issue Jan 12, 2021
PR-URL: #36633
Fixes: #36620
Reviewed-By: Matteo Collina <[email protected]>
Reviewed-By: Benjamin Gruenbaum <[email protected]>
Reviewed-By: Danielle Adams <[email protected]>
danielleadams pushed a commit that referenced this issue Jan 12, 2021
Calling .end() a second time should be a noop and not
leave the socket corked.

Fixes: #36620

PR-URL: #36633
Reviewed-By: Matteo Collina <[email protected]>
Reviewed-By: Benjamin Gruenbaum <[email protected]>
Reviewed-By: Danielle Adams <[email protected]>
danielleadams pushed a commit that referenced this issue Jan 12, 2021
PR-URL: #36633
Fixes: #36620
Reviewed-By: Matteo Collina <[email protected]>
Reviewed-By: Benjamin Gruenbaum <[email protected]>
Reviewed-By: Danielle Adams <[email protected]>
mitsos1os added a commit to mitsos1os/node that referenced this issue Jan 15, 2021
PR-URL: nodejs#36633
Fixes: nodejs#36620
Reviewed-By: Matteo Collina <[email protected]>
Reviewed-By: Benjamin Gruenbaum <[email protected]>
Reviewed-By: Danielle Adams <[email protected]>
(cherry picked from commit ec794f9)
BethGriggs pushed a commit that referenced this issue Jan 26, 2021
PR-URL: #36633
Backport-PR-URL: #36940
Fixes: #36620
Reviewed-By: Matteo Collina <[email protected]>
Reviewed-By: Benjamin Gruenbaum <[email protected]>
Reviewed-By: Danielle Adams <[email protected]>
BethGriggs pushed a commit that referenced this issue Jan 26, 2021
PR-URL: #36633
Backport-PR-URL: #36940
Fixes: #36620
Reviewed-By: Matteo Collina <[email protected]>
Reviewed-By: Benjamin Gruenbaum <[email protected]>
Reviewed-By: Danielle Adams <[email protected]>
BethGriggs pushed a commit that referenced this issue Jan 28, 2021
PR-URL: #36633
Backport-PR-URL: #36940
Fixes: #36620
Reviewed-By: Matteo Collina <[email protected]>
Reviewed-By: Benjamin Gruenbaum <[email protected]>
Reviewed-By: Danielle Adams <[email protected]>
BethGriggs pushed a commit that referenced this issue Jan 28, 2021
PR-URL: #36633
Backport-PR-URL: #36940
Fixes: #36620
Reviewed-By: Matteo Collina <[email protected]>
Reviewed-By: Benjamin Gruenbaum <[email protected]>
Reviewed-By: Danielle Adams <[email protected]>
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
confirmed-bug Issues with confirmed bugs. http Issues or PRs related to the http subsystem.
Projects
None yet
Development

Successfully merging a pull request may close this issue.

3 participants