Prevent server hangs on unconsumed streams. #81

mike-marcacci · 2018-06-07T16:42:24Z

While the HTTP spec does support sending a response before the request is finished and this behavior is followed by node http and curl, every browser and at least one popular load balancer (GCP) don't support this.

This means that if the server responds before the request stream has finished, the response body will be dropped:

If, on the other hand, the server waits before for the request to finish (by dumping the incoming data), the client is able to receive the response:

The reason this effects apollo-upload-client differently than other upload solutions is twofold:

While I prefer the approach of apollo-upload-server, most other drop-in file upload middleware waits for all uploads to finish before handing off the request to downstream middleware. This makes it simple, as downstream middleware doesn't have to worry about consuming the entire stream.
The downstream middleware is always going to be a graphql server, and resolvers are unaware of Uploads from other graphql branches (you could hack around this, but it would undo all the ergonomic benefits of apollo-upload-server).

Here's my (very typical) use case:

Try to upload a large file (or use a slow/throttled connection on a smaller file).
Before processing the upload, the graphql resolver checks to see that the user is logged in and throws an error:
```
if (!session) {
  throw new Error("You must be logged in to save an image.");
}
```

Unfortunately, this is a bit challenging to test, as this is a race: if the upload is fully buffered by node http before the response is sent (small file, local network) then everything works correctly; if it isn't (most real-world cases) then it will fail.

So far I've implemented this in the koa middleware (since that's what I'm using), and will add this to express when I get a chance. I'll also add some tests, but I wanted to drop this off here before somebody else descends the rabbit hole trying to diagnose this.

Fixes MaxFileSizeUploadError can't be caught and crashes the server #45, fixes Should handle unexpected streaming errors #77, and fixes Avoid emitting error if upload was not done on closing request #83: Correctly handles stream errors.
Fixes Certain tests failing in Node.js < 10. #78: Correctly waits for the request to finish before responding on node >=8.
Fixes How reject uploading after checking mimetype #64: Allow ignoring of an upload without blocking subsequent uploads.

# Conflicts: # changelog.md

The purpose of the `build:prettier` script is cleanup the un-pretty Bablel output in `lib`, so changing the glob to `src` doesn’t make sense. The `lint:prettier` glob includes `**/` so that it searches nested directories.

- Improved comment. - More efficient noop function.

mike-marcacci · 2018-06-07T17:31:48Z

OK, I've added tests for the koa middleware. The problem with doing this in express is that we're going to need to export 2 different middlewares:

before graphql (add the uploads)
after graphql (wait to send response)

mike-marcacci · 2018-06-07T18:30:47Z

OK, so the failing tests appear to happen on master using the node v10 and v8. This is good to know, as I was planning to upgrade from v9 shortly! I'm going to look into this as well.

mike-marcacci · 2018-06-07T18:35:34Z

OK, so it looks like #80 fixes master on node v10, so I'm going to go ahead and pull that one into this branch as well.

…ponding

jaydenseric

If I'm understanding it correctly, this delays resolvers until all of the uploads have been received by the server? I don't think this is the right approach for a few reasons.

It removes the primary benefit of the latest streaming API of apollo-upload-server, shorter response times due to a reduced waterfall uploading to cloud:

If a user is uploading a lot, with the async process a disconnect partway though would result in a partial success rather than a total failure.

Waiting for the uploads to complete is a DoS risk.

If your service takes large uploads (MB, even GB) then would the RAM get smashed, since it is buffering all of the files?

One of the user stories we would like to ultimately achieve, is to allow validation of arguments in the resolvers for an early error response before all the files have uploaded. Imagine a user fills in a form for an invoice on their mobile, and attaches a 3mb photo of the invoice as one of the form fields. It turns out they had a validation typo in an email address field. Ideally they would get a near instant error payload back, so they don't have to wait 3 minutes for the upload to needlessly complete so they can try again.

The fact that some browsers don't respect the HTTP spec and have a client-side fetch error when there is an early response is not really a major concern for us. Our main concern is that the server has rock solid stability and doesn't crash. Reading through the browser bugs, it appears to be resolved with HTTP/2.

A lot of people have the JWT/auth middleware at the start of the middleware chain, so I don't think we can reasonably prevent other middleware from causing early responses. Best we can do is not crash. Besides, we need to handle the client aborting half way through an upload.

jaydenseric · 2018-06-08T01:44:49Z

src/middleware.mjs

+        return new Promise(resolve => {
+          upload.file.stream.on('end', resolve)
+          upload.file.stream.on('error', resolve)
+          if (!upload.file.stream.readableFlowing) upload.file.stream.resume()


This looks tricky, what is it for?

We don't want to interfere with any streams that are being consumed, but we do want to run through the rest. Using readableFlowing let's us know what state the stream is in.

jaydenseric · 2018-06-08T01:46:32Z

src/test.mjs

@@ -101,6 +102,66 @@ t.test('Single file.', async t => {
  })
 })

+t.test('Early response.', async t => {
+  t.jobs = 1


t.jobs is only necessary when there are multiple subtests. Parallelism is default for top level tests, but child tests a sync unless you set t.jobs > 1.

Great to know! (I'm new to tap.)

jaydenseric · 2018-06-08T01:51:17Z

src/test.mjs

+
+    const data = fs.readFileSync(TEST_FILE_PATH)
+
+    var requestHasFinished = false


Better to use let. You probably don't even need the = false.

Sounds good; not to get side-tracked, but is there a benefit to let over var for top-level function-scoped variables, other than stylistic consistency?

jaydenseric · 2018-06-08T01:53:56Z

src/test.mjs

+    var requestHasFinished = false
+    const stream = new Readable()
+    stream.path = TEST_FILE_PATH
+    stream._read = () => {}


What is this about? The _ appears to indicate a private method.

This is the old, but still-supported way of implementing streams in node (for Streams 2, which is still the current implementation).

jaydenseric · 2018-06-08T01:55:16Z

src/test.mjs

+      stream.push(null)
+    }, 10)
+
+    return promise


I prefer await to return here, as it makes it clear the value isn't used back up the chain somehow.

Sounds good!

jaydenseric · 2018-06-08T01:57:32Z

src/test.mjs

+        )
+      },
+      err => {
+        throw err


Would this promise block would be more elegant as an await with no surrounding try/catch, since we throw on error anyway?

jaydenseric · 2018-06-08T01:59:34Z

package.json

@@ -65,9 +65,9 @@
    "build:clean": "rm -r lib; mkdir lib",
    "build:mjs": "BABEL_ESM=1 babel src -d lib --keep-file-extension",
    "build:js": "babel src -d lib",
-    "build:prettier": "prettier 'lib/**/*.{mjs,js}' --write",
+    "build:prettier": "prettier 'src/**/*.{mjs,js}' --write && prettier '*.{json,md}' --write",


Please undo all these script changes; for an explanation see 8928ce0.

Apologies! Will fix.

jaydenseric · 2018-06-08T02:11:02Z

src/middleware.mjs

@@ -94,7 +94,7 @@ export const processRequest = (
              operationsPath.set(path, map.get(fieldName).promise)
          }

-          resolve(operations)
+          resolve({ operations, map })


This is a breaking change to the API. A fair few people such as Apollo use processRequest directly.

That's a good point; I will change how this works.

jaydenseric · 2018-06-08T02:11:54Z

package.json

    "lint:eslint": "eslint . --ext mjs,js",
-    "lint:prettier": "prettier '**/*.{json,md}' -l",
+    "lint:prettier": "prettier '*.{json,md}' -l",


Ditto, undo.

…ponding

jaydenseric · 2018-06-08T04:10:53Z

I've just fixed a bug with the tests in master branch (528216f), might want to rebase.

mike-marcacci

Thanks SO much for the super thorough (and incredibly prompt) response! I've gone through your review and left comments where appropriate. I'm going to go ahead and make all the suggested changes shortly.

I did want to correct one thing that I wasn't entirely clear about: this suggested change does not delay resolvers. Rather, it makes sure that the incoming request is complete before sending the response. It doesn't interfere with streams that are currently being consumed, but does resume those that aren't. Nothing is buffered in memory differently than it was, so this doesn't add that kind of DOS vector, although it would potentially allow an attacker to occupy the network for longer.

I completely agree with you that this is something that should be fixed in browsers... but I tested the exact same behavior in Chrome, Firefox, and Safari on mac, and Safari on iOS. At the end of the day, I just needed to be able to send responses back to the client :-/

Your comment about HTTP2 is very encouraging, and it's the next thing I'll try. If that behaves correctly in modern browsers, then I'll gladly replace this PR with a doc change suggesting users use HTTP2 if possible :)

mike-marcacci · 2018-06-08T04:19:41Z

src/middleware.mjs

+        return new Promise(resolve => {
+          upload.file.stream.on('end', resolve)
+          upload.file.stream.on('error', resolve)
+          if (!upload.file.stream.readableFlowing) upload.file.stream.resume()


We don't want to interfere with any streams that are being consumed, but we do want to run through the rest. Using readableFlowing let's us know what state the stream is in.

mike-marcacci · 2018-06-08T04:19:45Z

src/middleware.mjs

@@ -94,7 +94,7 @@ export const processRequest = (
              operationsPath.set(path, map.get(fieldName).promise)
          }

-          resolve(operations)
+          resolve({ operations, map })


That's a good point; I will change how this works.

mike-marcacci · 2018-06-08T04:19:52Z

package.json

@@ -65,9 +65,9 @@
    "build:clean": "rm -r lib; mkdir lib",
    "build:mjs": "BABEL_ESM=1 babel src -d lib --keep-file-extension",
    "build:js": "babel src -d lib",
-    "build:prettier": "prettier 'lib/**/*.{mjs,js}' --write",
+    "build:prettier": "prettier 'src/**/*.{mjs,js}' --write && prettier '*.{json,md}' --write",


Apologies! Will fix.

mike-marcacci · 2018-06-08T04:20:30Z

src/test.mjs

@@ -101,6 +102,66 @@ t.test('Single file.', async t => {
  })
 })

+t.test('Early response.', async t => {
+  t.jobs = 1


Great to know! (I'm new to tap.)

mike-marcacci · 2018-06-08T04:22:28Z

src/test.mjs

+
+    const data = fs.readFileSync(TEST_FILE_PATH)
+
+    var requestHasFinished = false


Sounds good; not to get side-tracked, but is there a benefit to let over var for top-level function-scoped variables, other than stylistic consistency?

mike-marcacci · 2018-06-08T04:23:25Z

src/test.mjs

+    var requestHasFinished = false
+    const stream = new Readable()
+    stream.path = TEST_FILE_PATH
+    stream._read = () => {}


This is the old, but still-supported way of implementing streams in node (for Streams 2, which is still the current implementation).

mike-marcacci · 2018-06-08T04:24:41Z

src/test.mjs

+        )
+      },
+      err => {
+        throw err


mike-marcacci · 2018-06-08T04:25:56Z

src/test.mjs

+      stream.push(null)
+    }, 10)
+
+    return promise


Sounds good!

jaydenseric · 2018-06-08T04:46:08Z

@mike-marcacci really appreciate your help 👏

I'm on the Apollo slack (and I can see you're on there too), so feel free to chat about any of this stuff, either publicly in the #uploads channel or via DM. My timezone is Melbourne, Australia.

mike-marcacci · 2018-06-08T16:31:41Z

OK, well, as an update, I wasn't able to get any success with http2, but my real world use case is complex (reverse proxies, etc) so I thought I should go back to first principles. I created a test to try against the browsers on my laptop:

https://gist.github.com/mike-marcacci/5c7f435d51240feb8a871ab348a00dfd

And I can't seem to reproduce the issue on http, https or http2, so I've got to keep digging. I'll post back when I find something.

jaydenseric · 2018-07-06T05:08:12Z

src/middleware.mjs

@@ -22,25 +25,30 @@ class Upload {
          this.done = true


It looks like this is not used anywhere anymore?

Yep, that's correct! Removed.

ForsakenHarmony · 2018-07-10T20:42:23Z

I need this 👀

jaydenseric

🙌

koresar · 2018-07-12T01:24:42Z

package.json

@@ -38,6 +38,7 @@
  },
  "dependencies": {


No more @babel/runtime! Yeah! This will remove 3MB from my production docker containers. Thanks!

terion-name · 2018-07-12T07:15:33Z

HURRAY! @jaydenseric when to expect this to be tagged on npm?

jaydenseric · 2018-07-12T07:21:15Z

@terion-name I have a few minor things to sneak in, then publish hopefully within the next day. The new version will likely be a semver major, due to the raised min Node.js version. If you use a recent Node.js version it should be a painless upgrade.

jaydenseric · 2018-07-13T06:54:28Z

src/middleware.mjs

+
+  const finished = new Promise(resolve => request.on('end', resolve))
+  const { send } = response
+  response.send = (...args) => {


Is this monkey patching the send method for all following express middleware? This seems pretty cheeky.

Ya, this a really ugly thing to do, but it’s the only way I know to “wrap” child middleware in express/connect without requiring them to be aware of the parent middleware... I’ve reluctantly used this pattern in the past and haven’t really run into issues, but if you know of any other way to do this, I’d love to learn!

Of the top of my head it might break res.write(): https://stackoverflow.com/questions/44692048/what-is-the-difference-between-res-send-and-res-write-in-express

But I don't know any existing code bases (out of dozens I overview or maintain) which use res.write() with express.js.

@koresar you're definitely correct that calling res.write() could break some assumptions, and also that doing so is a kind of escape hatch from express. In fact, calling ctx.req.write() would have unintended results in koa as well.

jaydenseric · 2018-07-13T07:06:18Z

@mike-marcacci do you know what might be causing these errors? https://travis-ci.org/jaydenseric/apollo-upload-server/jobs/402915414#L2165

mike-marcacci · 2018-07-13T07:17:18Z

I’m going to assume you’re referring to the “Parse Error” in the logs (Travis line links are apparently messed up on mobile). I don’t know off the top of my head, but I suspect those are a case where we’re testing an aborted request, and we propagate our custom events while busboy emits a parse error. I’m not sure how those would get in the logs, but I assume there’s something special going on with Tap. I’ll look at these tomorrow.

ForsakenHarmony · 2018-07-17T19:02:34Z

when are you gonna release this?

jaydenseric · 2018-07-17T23:35:42Z

@ForsakenHarmony A few unanticipated issues have popped up. Once we know what is causing the errors mentioned above, and once #89 (comment) is fixed and merged we can publish v6.0.0-alpha.1.

Help resolving these blockers is the fastest path to a release, otherwise it is mostly up to @mike-marcacci's availability. If there is no movement this week I will try to take a day or more off from project work to see what more I can do.

Earlier versions had a simpler (although less efficient) approach using formidable and temp files. I would love to have more Node.js stream experts come on to the project as collaborators.

mike-marcacci · 2018-07-18T01:31:11Z

@ForsakenHarmony @jaydenseric you're in luck, I've got some time here today :) we didn't have as great cell coverage in our last locations as we had expected. Stay tuned!

jaydenseric · 2018-07-21T05:11:45Z

Published in v6.0.0-alpha.1 🎉

ForsakenHarmony · 2018-07-23T16:59:00Z

seems like you published it as a normal release on npm not alpha/beta, just as a heads up

mike-marcacci · 2018-07-23T17:40:19Z

Thanks for the heads-up @ForsakenHarmony. You're right: it looks like @jaydenseric will need to update npm's "latest" tag to point back at 5.0.0.

jaydenseric · 2018-07-24T01:42:15Z

Thats deliberate actually; v6.0.0-alpha.1 is more stable than v5.0.0 and everyone who can (given the few breaking changes) is advised to update.

mike-marcacci · 2018-07-24T04:09:58Z

Aah I see. Good strategy!

…

On Jul 23, 2018, at 19:42, Jayden Seric ***@***.***> wrote: Thats deliberate actually; v6.0.0-alpha.1 is more stable than v5.0.0 and everyone who can (given the few breaking changes) is advised to update. — You are receiving this because you were mentioned. Reply to this email directly, view it on GitHub, or mute the thread.

mike-marcacci and others added 16 commits June 6, 2018 12:38

prevent app crash on error event

97874e2

fix lint issues

f1d0553

more fixes for linter

d4ef915

Merge branch 'master' into fix/prevent-crashes

e5090ac

# Conflicts: # changelog.md

Undo package script changes.

8928ce0

The purpose of the `build:prettier` script is cleanup the un-pretty Bablel output in `lib`, so changing the glob to `src` doesn’t make sense. The `lint:prettier` glob includes `**/` so that it searches nested directories.

Minor tidy.

2cbbf2d

- Improved comment. - More efficient noop function.

prevent app crash on error event

493a617

fix lint issues

148cfde

more fixes for linter

0ec1085

add a noop handler for parser error

3c5ce98

koa: finish request before responding

65f78f6

fix lint issues

9094cf9

more fixes for linter

ab36717

unbreak express

232cfe9

add test for early return

b03ce1d

add better test failure message

b8a0798

Merge branch 'fix/prevent-crashes' into fix/finish-request-before-res…

10f0839

…ponding

jaydenseric previously requested changes Jun 8, 2018

View reviewed changes

Merge branch 'fix/prevent-crashes' into fix/finish-request-before-res…

d473973

…ponding

mike-marcacci commented Jun 8, 2018

View reviewed changes

mike-marcacci added 4 commits June 8, 2018 10:38

Merge branch 'master' into fix/prevent-crashes

6b5d625

add tests for abort, refactor to destroy streams

7599006

make sure not to destroy an upload stream twice

1aa7e67

remove .finally() for node v8 support

2ba4713

mike-marcacci added 4 commits July 5, 2018 22:11

test actual file contents

8c3e51a

fix inadvertant changes

4f7e2fd

remove errorHandler config option

5afbd4b

fix typo

04d56bc

jaydenseric reviewed Jul 6, 2018

View reviewed changes

mike-marcacci added 2 commits July 5, 2018 23:10

Remove callback arg from processRequest

531c6aa

remove unused code

77bafbc

jaydenseric approved these changes Jul 12, 2018

View reviewed changes

jaydenseric merged commit c7567ea into jaydenseric:master Jul 12, 2018

koresar reviewed Jul 12, 2018

View reviewed changes

jaydenseric mentioned this pull request Jul 13, 2018

Added pause of emitter error until a listener for manage this was setted #85

Closed

jaydenseric reviewed Jul 13, 2018

View reviewed changes

mike-marcacci mentioned this pull request Jul 23, 2018

Allow the same data to be shared by multiple Upload scalars #92

Merged

loremaps mentioned this pull request Jul 26, 2018

File size #30

Closed

dohomi mentioned this pull request Aug 8, 2018

FileStreamDisconnectUploadError on v5.0.0 and v6.0.0.alpha #100

Closed

This was referenced Feb 20, 2023

Request hangs using @fastify/multipart plugin fastify/fastify#4588

Closed

client hangs after failed upload mercurius-js/mercurius-upload#13

Closed


		const data = fs.readFileSync(TEST_FILE_PATH)

		var requestHasFinished = false

Prevent server hangs on unconsumed streams. #81

Prevent server hangs on unconsumed streams. #81

Conversation

mike-marcacci commented Jun 7, 2018 • edited by jaydenseric Loading

mike-marcacci commented Jun 7, 2018

mike-marcacci commented Jun 7, 2018 • edited Loading

mike-marcacci commented Jun 7, 2018

jaydenseric left a comment • edited Loading

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

jaydenseric commented Jun 8, 2018

mike-marcacci left a comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

jaydenseric commented Jun 8, 2018

mike-marcacci commented Jun 8, 2018

Choose a reason for hiding this comment

Choose a reason for hiding this comment

ForsakenHarmony commented Jul 10, 2018

jaydenseric left a comment

Choose a reason for hiding this comment

koresar Jul 12, 2018 • edited Loading

Choose a reason for hiding this comment

terion-name commented Jul 12, 2018

jaydenseric commented Jul 12, 2018

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

mike-marcacci Jul 18, 2018 • edited Loading

Choose a reason for hiding this comment

jaydenseric commented Jul 13, 2018

mike-marcacci commented Jul 13, 2018 • edited Loading

ForsakenHarmony commented Jul 17, 2018

jaydenseric commented Jul 17, 2018

mike-marcacci commented Jul 18, 2018

jaydenseric commented Jul 21, 2018

ForsakenHarmony commented Jul 23, 2018

mike-marcacci commented Jul 23, 2018

jaydenseric commented Jul 24, 2018

mike-marcacci commented Jul 24, 2018 via email

mike-marcacci commented Jun 7, 2018 •

edited by jaydenseric

Loading

mike-marcacci commented Jun 7, 2018 •

edited

Loading

jaydenseric left a comment •

edited

Loading

koresar Jul 12, 2018 •

edited

Loading

mike-marcacci Jul 18, 2018 •

edited

Loading

mike-marcacci commented Jul 13, 2018 •

edited

Loading