Error logging is called even when handled in custom handler.

[sean-hernon]

When the error logging is enabled, it is called even when the error is handled in a custom error handler middleware.

This is unintuitive for several reasons. Consider the following case.

//Validation middleware
api.use((req, _, next) => {
    //Assume a function that validates the body and returns a boolean
    if (!validate(req.body)) {
        throw new CustomValidationError();
    }

    next();
});

/*Some routes registered here*/

//Error handling middleware
api.use((err, _, res, next) => {
    //Handle validation errors and send the response
    if (err.name === 'CustomValidationError') {
        return res.status(422).json({reason: 'Some validation reason'});
    }

    next();
});

In this case, the first thing we see in the logs is something like INFO {"level":"fatal",..."statusCode":500}.

Clearly the error is not something that we would consider to be fatal, as we handle it and return a 4XX. Also, the status code says 500, because that's the default in the handling logic and we haven't overridden it at the point at which the log is written, but it's confusing to see these things for a request which is neither fatal nor a 500.

The access log will then be printed with the correct status code, which adds further confusion.

Finally, the readme states that we can "short-circuit" the default error handler by registering a custom one, which I would expect to mean that we only get the logging if we don't register a custom handler, or we call next(), because it seems intuitive that the logging is part of the default handler.

Thank you for taking time to read.