getsentry/raven-node

`requestHandler` calls `next` multiple times but only logs the first error

Closed this issue · 7 comments

What is the current behavior?

If Express middleware throws multiple asynchronous errors, Raven's requestHandler will attempt to forward them all to next, but only the first one will reach errorHandler. Affects Raven 0.12.3 as well as Raven 1.2.1.

https://github.com/wearhere/raven-node-multiple-errors provides a test case. I can't tell from Express' source exactly why the second call to next doesn't have an effect (neither calling the downstream middleware nor causing any sort of error). It doesn't look like the second call is a pure no-op though, which is probably not good.

What is the expected behavior?

Every asynchronous error should be logged—I don't see why the first one to fire should be privileged.

If Express forwarded all the errors through the middleware stack I would say that's fine. But changing Express' behavior is probably wayy out of scope.

So requestHandler and errorHandler are going to have to communicate some other way. Or perhaps requestHandler could just log the errors itself? requestHandler basically calls errorHandler via next anyway, you could simplify your docs by only requiring requestHandler.

The documentation should also be updated to note that fall-through error handlers are not guaranteed to be run on "secondary errors", unless you want to figure out how to make them run.

I would recommend not having them run though, both to avoid messing with Express and also because if the developer has a fall-through handler that terminates the request

app.use((err, req, res, next) => {
  // Simplified; you wouldn't want to send down error messages in production, for instance.
  res.status(500).send(err.message);
});

that would not cope well being run multiple times.

Even though your title alone was clear enough to me to know what the situation/issue was, I have to give props for the repro test case. Thanks for taking the time to provide such a nice demonstration of the issue you're describing. I agree this is a problem.

We definitely can't get rid of the errorHandler middleware entirely, because we want to record any errors passed down express's error handling stack; many apps follow a policy along the lines of "if we encounter an operational error that will prevent us from completing the request, just call next(err) and let our 500-page-error-handler deal with it", and we want to capture those errors.

But the key insight here is that we don't have to use express's error handling and the errorHandler middleware to report asynchronous exceptions caught by the domain from the requestHandler middleware. Currently we do, partially because we can and it's easy, and partially to have asynchronous errors we capture still result in the user's express app serving its 500 page or whatever else it might do.

I think the right thing to do here is have the requestHandler capture all errors caught in the domain error handler, but only call next(err) for the first such error. Then we just have to make sure the errorHandler will not re-capture an error that has already been captured by the requestHandler; a flag on either the domain or the error object should solve that. We should also be fine in the case where a next(err) has already been called somewhere else first (synchronous or not), and then requestHandler tries to call next(err) from its first-encountered asynchronous error; express just won't run the error handlers multiple times.

Let me know if this sounds reasonable to you or if you have a scenario where this wouldn't work well.

That all sounds reasonable to me!

The only thing I'm a little wary of is

We should also be fine in the case where a next(err) has already been called somewhere else first (synchronous or not), and then requestHandler tries to call it from an asynchronous error; express just won't run the error handlers multiple times.

since I'm not sure that that is totally fine; as I describe up top, calling next a second time doesn't appear to cause an error but at the same time doesn't appear (per a cursory scan of Express' source) to be a pure no-op. Here's where I'm looking at.

But I don't know how the requestHandler would know that next had been called by someone else. So having it make sure that it only calls next once would close this bug as far as I'm concerned.

I'm not sure that that is totally fine; as I describe up top, calling next a second time doesn't appear to cause an error but at the same time doesn't appear (per a cursory scan of Express' source) to be a pure no-op.

Yea, I'm not 100% sure on this point either tbh - I also gave the express source a quick look and wasn't able to become sure one way or the other without more digging. I'll have to experiment with it a bit. It's definitely an edge case, but I think it's worth making sure we get it right.

So having it make sure that it only calls next once would close this bug as far as I'm concerned.

Sure, agreed, that would be a strict improvement regardless of the above uncertainty.

Ran into this again today in reworking how our domain error handling exit conditions work. I think we need a slight tweak to this plan. Notably, any error caught by the requestHandler middleware's domain would, in the absence of Raven or the middleware, be a fatal exception that results in exiting the process. I want to preserve that behavior by default.

I think the existing plan here to capture straight from the requestHandler middleware instead of relying on the errorHandler middleware to capture is still sound, but we'll need to stop doing next(err) in the requestHandler by default.

We could have an option for the requestHandler middleware to enable passing to the error handler so any express error handling + 500-page-serving can happen, but it's not obvious how that should work or whether there's any value to it. It might be correct to instead just have the requestHandler and errorHandler middlewares be completely independent: requestHandler catches domain errors, captures them, and then initiates fatal error shutdown etc, while errorHandler sees express next(err) errors and just captures them and carries on.

I'm probably going to end up making this change as part of #308.

any error caught by the requestHandler middleware's domain would, in the absence of Raven or the middleware, be a fatal exception that results in exiting the process. I want to preserve that behavior by default.

This actually sounds fine to me. It would be consistent with how I was planning to handle promises as part of #265 (comment) —I'll be able to forward exceptions at the top-level of middleware onward via the patch I link (consistent with how express handles synchronous exceptions), but since there's nothing like domains for promises, any lower-level rejections will be reported as unhandled, in response to which I was going to shut down the process.

So don't worry about "an option for the requestHandler middleware to enable passing to the error handler" on my behalf, your proposal to

instead just have the requestHandler and errorHandler middlewares be completely independent: requestHandler catches domain errors, captures them, and then initiates fatal error shutdown etc, while errorHandler sees express next(err) errors and just captures them and carries on.

sgtm.

Awesome, thanks for the feedback; I haven't thought too much about how promises work with express, so I'm glad that fits into your thinking.

I've pushed this change in part of #308 (specifically b8d9c97), should land soon.

Closed in #308.