Requests can hang with malformed JSONs; depends on error handling

[juona]

Jayden,

Great work on the library, and thanks for pushing guys @ Apollo. Your workaround works well enough so that I wouldn't care about them fixing their own dependency.

I am now using [email protected] with Express and have found this one rather small issue.

In the express middleware you have written code which (please correct me if I am wrong) is meant to delay the final response until the upload has ended:

• https://github.com/jaydenseric/graphql-upload/blob/master/src/graphqlUploadExpress.mjs#L36

• https://github.com/jaydenseric/graphql-upload/blob/master/src/graphqlUploadExpress.mjs#L32.

The issue is that the finished promise is listening for request.on("end"), which apparently doesn't happen if an error occurs while uploading. Scenario is this:

1. Send a malformed request (e.q. an invalid operations JSON).
2. Have an error handler, which uses request.send (or .json - it resolves to .send). E.g. I have this little piece:

app.use((err, _, res, __) => {
  res.status(err.status).json({
    message: httpStatus[err.status],
    stack: config.printErrorStack ? err.stack : {}
  });
});

When .json() is called, the flow goes to your middleware:

https://github.com/jaydenseric/graphql-upload/blob/master/src/graphqlUploadExpress.mjs#L36

However, in this scenario the end event is never fired on the request. Two workarounds are available:

1. Use response.end() instead of .send() or .json(). I'd like to stick with .json, however.
2. Manually emit the end event in case of an error: request.emit("end").

Questions to you:

1. Do I understand your code correctly?
2. Do you know why the end event is not firing in case of an error in the upload middleware?
3. Does emitting end manually seem like a good fix which can be applied now?
4. Would you fix this? I guess you could do this using processRequest.catch() but I am not sure what your desired outcome would be in this case.

[mike-marcacci]

Hey @juona, thanks for the super detailed report. As the original author of the offending line, I figured I should hop in and confirm:

1. Yes, you definitely read the code correctly.
2. I don't quite recall why end isn't firing: at one point I had to build a big table of all the events different versions of node were emitting in which order, under which cases... but that didn't make its was onto my new laptop. What version of node are you running here? The end event should be emitted as soon as the entirety of the request has been consumed. This suggests to me that the request stream is paused for some reason.
3. Based on exhaustive (and exhausting) testing using all sorts of configurations, I determined that sending a response before the request stream had ended can result in a broken HTTP transaction. Because of this, unless the request has ended and we just never received the event, this wouldn't work. Note that it may appear to work if the remaining contents of the request fit into the request stream's internal buffer, since from the network's perspective, the HTTP request has ended.
4. We need to figure out why the end event isn't being emitted. My initial ideas for where to look are:
   1. While we do resume the request stream on error, there may be something else putting the stream in a paused state.
   2. Perhaps the request stream ended before we started listening for the end event.
   3. Perhaps there is a bug in this particular version of node's HTTP stream.

I think the first step is definitely going to be to reproduce this in a test. I'll see if I can find some time tomorrow to poke around.

@juona - which version of node is this running on?

[juona]

Oh hey,

1. Thank you for addressing this promptly!
2. Apologies for addressing Jayden, somehow it felt like he was the one and only author. Obviously I never checked and obviously it is not the case :]
3. My Node version is 10.12.0.
4. I have just checked that indeed the end event is not firing at all. I did that by setting up a listener in the very first express middleware. As you say, this must mean that the stream is either paused or there's a problem within the stream itself, which I somehow doubt given that uploads work fine otherwise?

Question: I am not a very experienced software engineer, so would you be able to provide a bit of explanation of what a "broken HTTP transaction" would mean in this case and what the ramifications are? I guess in this case using request.end(JSON.stringify({ ... error JSON ... }) is equivalent, isn't it?

[mike-marcacci]

1. Of course!

2. No worries at all – Jayden is certainly the driving force behind this project, and the one who gets stuck with things when the rest of us bail ;-) so you were totally correct to address him.

3. Thanks!

4. I am seeing this as well. Changing this line in the test to:

   body.append('1', 'a'.repeat(70000), { filename: 'a.txt' })

   makes the payload larger than a single TCP packet and larger than the node stream's internal buffer, and ensures that the HTTP request isn't fully consumed when the error occurs. Under these conditions, I can see exactly what you are describing. I'm considering having all the tests run with a small and large payload, to help us catch these issues in advance.

   I can see that the stream is not paused when processRequest calls .resume but is paused again when the error middleware is called. This appears to share the same behavior with koa, actually, so the bug is either on our end, or there's something unexpected going on with node's http library. I'm going to dig into this right now and post back.

What I mean by "broken HTTP transaction", is that the client will attempt to send its headers and the entirety of its request body along the TCP connection (this is all assuming we aren't using the HTTP 100 [Continue] flow). If we attempt to send a response and end the request/close the connection before the body has finished being sent, all browsers and all popular reverse proxies will treat this as a network failure, and the response status and body will be abandoned. While this is fine if you're trying to prevent DOS attacks, you definitely don't want this kind of behavior for a non-malicious client.

There is the case where node has received the entire request body (so the client will now accept a response) even though our code hasn't actually read the entire body out of node's internal stream buffer. This is essentially why this bug exists – because I didn't test this case with a large enough payload. :(

EDIT: As an addendum, this last case is something to which most node developers (even very experienced ones) are oblivious. It's really easy to just use small payloads when writing tutorials or tests, and not realize that your code's behavior can be so dramatically different with just a few more bytes of data. Likewise, it's possible to make similarly detrimental omissions if you only use a large request, such as assigning listeners after an event has occurred. This is why several of our tests in this repo use multiple request sizes... and why they all probably should.

[juona]

Thank you, the explanation makes sense : ]

Come to think of it, I did notice that smaller JPEGs seemed to work differently, i.e. would sometimes return responses, but the behaviour was inconsistent and I couldn't understand what was going on, so I didn't mention it in the description.

Happy to see smart people working on packages that I use - makes me feel secure ^^

[jaydenseric]

The fix is published in [email protected], thanks all 🙌