Node: registering `requestHandler` changes error handling behaviour

[OliverJAsh]

• Review the documentation: https://docs.sentry.io/
• Search for existing issues: https://github.com/getsentry/sentry-javascript/issues
• Use the latest release: https://github.com/getsentry/sentry-javascript/releases

Package + Version

• @sentry/browser
• @sentry/node
• raven-js
• raven-node (raven for node)
• other:

Version:

4.6.3

Description

When I enable Sentry.Handlers.requestHandler() (in Express), asynchronous errors will be:

• (expected) reported to Sentry
• (unexpected) passed on to my Express error handling middleware

It took me a very long time to understand why an async error inside a request handler would lead to different behaviour in development vs production.

In development the error would cause the process to die/exit (default behaviour in Node), whereas in production the error would be passed on to my error handling middleware, and an error response would be sent. It turned out this was because we were only enabling the request handler in production.

I would like to question whether "passing the error to error handling middleware (by calling next and passing the error )" is really the job of Sentry.Handlers.requestHandler(). Perhaps it should only report the error? After all, that's the main reason to enable Sentry in an application. This way, conditionally enabling Sentry (e.g. depending on env) would not lead to any other unexpected behaviour changes, such as the one I described above.

Alternatively, if we think it is the right thing to do, we should document it clearly, along with a suggestion for how to achieve consistent behaviour when the request handler is not enabled (e.g. by using domains like how Sentry.Handlers.requestHandler() does it).

[kamilogorek]

I would like to question whether "passing the error to error handling middleware (by calling next and passing the error )" is really the job of Sentry.Handlers.requestHandler(). Perhaps it should only report the error?

requestHandler doesn't send reports, it only creates a domain which is used in order to separate context between the requests.

It's a job of errorHandler to take that context, the error and make an event out of them which then can be sent to Sentry.

I'm not sure if I follow along with how it changes the behavior based on the environment. Can you elaborate more? Preferably with code examples? Thanks!

[OliverJAsh]

I'm not sure if I follow along with how it changes the behavior based on the environment. Can you elaborate more? Preferably with code examples? Thanks!

Does this help?

// ./index.js
const express = require('express')
const Sentry = require('@sentry/node')

const app = express();

// Comment this out to disable
app.use(Sentry.Handlers.requestHandler());

app.get('*', () => {
    setTimeout(() => {
        throw new Error('foo')
    })
})

app.listen(3000);

node ./index.js
curl localhost:3000

When the requestHandler is:

• enabled: server stays alive, curl receives response containing error
• disabled: server crashes, curl errors with "Empty reply from server"

[OliverJAsh]

My workaround for now is to always enable requestHandler, and to conditionally enable Sentry, optionally provide the Sentry DSN + enable option. This at least gives us consistent behaviour.

[HazAT]

I will close this issue for now since the specific case seems to be solved, feel free to post again.

[OliverJAsh]

@HazAT I didn't see any response to my last comment, so I don't think this is solved? If so can we re-open?

[OliverJAsh]

Currently, when the domain receives an error, we forward the error to Express' error handling middleware by calling next with the error as an argument:

sentry-javascript/packages/node/src/handlers.ts

Line 236 in 913eafc

local.on('error', next);

I think we should change this to only report the error to Sentry:

local.on('error', error => { Sentry.captureException(error); });

This will prevent the requestHandler from modifying Express' behaviour when an error occurs (which shouldn't be a concern for requestHandler), as I described in #1922 (comment).

[HazAT]

Sorry, I was skimming over some issues, I will reopen this.

[gaastonsr]

Looks like local.on('error', next) is unneeded and actually changes the behavior of Express.

[kamilogorek]

actually changes the behavior of Express

How so? What is and what should be the behavior here?

[gaastonsr]

I just tested this locally so I make sure I can repro the problem.

The issue here is that when an error is thrown in a route handler either synchronously or asynchronously, or a rejection unhandled error is raised or really any error generated inside the domain, it shouldn't be caught and passed to next by Sentry, it should bubble up as it normally would.

The issue is that local.on('error', next) is a catch-all for any error raised inside the domain and it changes the default behavior by Express.

[kamilogorek]

it shouldn't be caught and passed to next by Sentry, it should bubble up as it normally would.

As long as there's a registered error handler in express, it'll always be passed to the next call and captured by the first registered middleware that has 4 arguments.

The most basic example:

const app = express()
app.get("/", (req, res) => { throw new Error("wat"); })
app.use((err, req, res, next) => console.log("error handler called"))
app.listen(3000)

When you run the server and ping it, you'll see that the error was still passed to the handlers that were registered after the route itself.

[OliverJAsh]

@kamilogorek What's the status of this issue? Looking at my comments above it seems like the issue I described still stands, although I didn't receive any acknowledgement so I'm not sure whether my comment was clear?

To reiterate, the problem is that async errors are not usually automatically passed to the express error handler—Sentry changes that behaviour, which is unexpected.

[kamilogorek]

@OliverJAsh I tested async version now and I'm not sure if you have something else on your mind or I cannot simply reproduce it.

var app = express();
app.use(Sentry.Handlers.requestHandler());
app.get("/sync", (req, res) => {
  throw new Error("wat");
});
app.get("/async", async (req, res) => {
  throw new Error("wat");
});
app.use(Sentry.Handlers.errorHandler());
app.use((err, req, res, next) => console.log("error handler called"));
app.listen(3000);

In this configuration console.log will be called for /sync endpoint but not for /async. Error will be reported to Sentry for both endpoints.

var app = express();
app.get("/sync", (req, res) => {
  throw new Error("wat");
});
app.get("/async", async (req, res) => {
  throw new Error("wat");
});
app.use((err, req, res, next) => console.log("error handler called"));
app.listen(3000);

In this scenario it'll behave the same in terms of logging, but only /async will be reported (it bubbles to global handler) and /sync will not, as it's captured by express middleware.