Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Additional error logging when using setErrorHandler #4048

Closed
koanplaned opened this issue Jun 13, 2022 · 10 comments · Fixed by #4061
Closed

Additional error logging when using setErrorHandler #4048

koanplaned opened this issue Jun 13, 2022 · 10 comments · Fixed by #4061
Assignees
Labels
bug Confirmed bug good first issue Good for newcomers

Comments

@koanplaned
Copy link

Hi all,

I recently upgraded from fastify version 3.26.0 to 4.0.1 and now have an issue with the setErrorHandler method.

My setErrorHandler is implemented like this

fastify.setErrorHandler(function (error, request, reply) {

  // some custom logging operations

  reply.send(error);
}

In the previous version 3.26.0, the application did just my custom-defined logging and then returned a well-formed json like this:

{
  "message": "Error intentionally triggered",
  "error": "Internal Server Error",
  "statusCode": 500
}

Since the 4.0.1 version, there is now an additional error logging done by fastify, which I can not turn off. I narrowed the issue down to following statement:

// Problematic part in the code
reply.send(error);
# Excerpt of the additional logging
 err: {
      "type": "Error",
      "message": "The error message",
      "stack":
          Error: The error message
...

My observation: If I send the "complete" error object, the additional logging occurs, but when I just send parts of the error (e.g. the error message) the additional logging is gone:

reply.send(error.message);

Is there a way to turn off the additional logging, when returning the "full" error object?

I want to use the "full" object, since I also need the statusCode and the error in the reply message like this:

{
  "message": "Error intentionally triggered",
  "error": "Internal Server Error",
  "statusCode": 500
}

As a workaround, I tried to construct this object myself, but I don't understand, how I can access the actual error statusCode to send it back, for example like this:

reply.send({
  "message": error.message
  "error": error.error
  "statusCode": error.statusCode
})

The property "error.statusCode" is undefined on the error object, so I guess there must be another way to access it somehow.

Help would be really appreciated here :-)

@mcollina
Copy link
Member

The error system in Fastify v4 has been refactored.

If you want to customize things, you must do:

fastify.setErrorHandler(function (error, request, reply) {

  // some custom logging operations

  const toSend = {
    "message": error.message
    "error": error.error
    "statusCode": error.statusCode || 500 // default status code
  }

  reply.core(toSend.statusCode).send(toSend);
}

Fastify will only set the http status code in the default error handler, which is not customizable.

@mcollina mcollina added help wanted Help the community by contributing to this issue good first issue Good for newcomers labels Jun 13, 2022
@mcollina
Copy link
Member

@koanplaned
Copy link
Author

Hi @mcollina,

thanks for the feedback. I tried the described approach, but still have some troubles.

But first the good news: the additional logging is gone, as soon as I switched to the reply.code().send() statement 👍

fastify.setErrorHandler(function (error, request, reply) {
    
  // some custom logging operations

  const errorResponse = {
    message: error.message,
    error: error.error, // still missing in response json
    statusCode: error.statusCode || 500
  };

  reply.code(errorResponse.statusCode).send(errorResponse);
});

I tested the setErrorHandler by setting up a route, that validates an incoming request header with the help of a JSON schema. The JSON schema defines a mandatory header property "Client-Locale".

// JSON Schema for mandatory header property 'Client-Locale'
{
    type: 'object',
    required: ['Client-Locale'],
    properties: {
      'Client-Locale': {type: 'string'}
    }
}

In the prior fastify version, the setErrorHandler returned with a status code 400 as well as the error.error property "Bad Request", when the Client-Locale property was not present in the request header.

Now the setErrorHandler returns the status code 500 and the "error"-property with the value "Bad Request" is missing.

// Error object with fastify 3.26.0
// HTTP status code in header: 400
{
    "message": "headers should have required property 'client-locale'",
    "error": "Bad Request"
    "statusCode": 400
}

// Error object with fastify 4.0.1
// HTTP status code in header: 500
{
  "message": "headers must have required property 'client-locale'",
  "statusCode": 500
}

Is there anything else I have to consider for validation errors?
Thanks again for your help!

@mcollina
Copy link
Member

Can you provide steps to reproduce? We often need a reproducible example, e.g. some code that allows someone else to recreate your problem by just copying and pasting it. If it involves more than a couple of different file, create a new repository on GitHub and add a link to that.

@koanplaned
Copy link
Author

Hi @mcollina,

sure, I prepared a GitHub repo to demonstrate the issue: https://github.com/koanplaned/fastify-error-handler-issue

It includes two fastify sample applications, which are the same except for the setErrorHandler implementation.

Hope you find it useful to reproduce the issue.

@mcollina
Copy link
Member

In the v4 example, you have to change

handler: async function (request, reply) {
            reply.send({ hello: 'world' });
        }

into

handler: async function (request, reply) {
            reply.send({ hello: 'world' });
     return reply
        }

or

handler: function (request, reply) {
            reply.send({ hello: 'world' });
        }

@koanplaned
Copy link
Author

Hi @mcollina,

I tried both options, but this didn't change the result. The error handler still returns with error code 500 instead of 400 and with missing error.error property for both options.

// Result with updated route handler implementation

HTTP/1.1 500 Internal Server Error
content-type: application/json; charset=utf-8
content-length: 82
Date: Sat, 18 Jun 2022 12:36:20 GMT
Connection: close

{
  "message": "headers must have required property 'client-locale'",
  "statusCode": 500
}

I also played around with the setErrorHandler function a little bit more, e.g.

fastify.setErrorHandler(function (error, request, reply) {
    reply.send(error);
}

// or 

fastify.setErrorHandler(async function (error, request, reply) {
    reply.send(error);
    return reply;
}

With these tweaks, the error response was correct - but the additional error logging happened again.

I added a new folder v4-2 and updated the code with the route handler adjustments: https://github.com/koanplaned/fastify-error-handler-issue/tree/master/v4-2

Please note:
The previous /test-route is now split up into two routes in the v4-2 implementation:

GET /tests/option-1 -> async route handler with additional return statement
GET /tests/option-2 -> route handler without async option and without return statement

@mcollina
Copy link
Member

I finally understood the problem you are facing.

we are not setting error.statuCode to 400 on errors when failing headers validation.
This actually a bug.

@mcollina mcollina added bug Confirmed bug and removed help wanted Help the community by contributing to this issue labels Jun 18, 2022
@koanplaned
Copy link
Author

Yes, and it seems the same applies for error.error

@mcollina
Copy link
Member

Would you like to send a Pull Request to address this issue? Remember to add unit tests.

The function to update is likely

function wrapValidationError (result, dataVar, schemaErrorFormatter) {
.

@Eomm Eomm transferred this issue from fastify/help Jun 19, 2022
@mcollina mcollina self-assigned this Jun 21, 2022
mcollina added a commit that referenced this issue Jun 21, 2022
As part of the error handling refactoring of #3261, we should
not be setting a custom status code for validation routes.
We should rely only on the error.statusCode property instead and
leave the user full customization capabilities. Unfortunately
a change was missed.

Fixes: #4048
Ref: #3261
Signed-off-by: Matteo Collina <hello@matteocollina.com>
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
bug Confirmed bug good first issue Good for newcomers
Projects
None yet
Development

Successfully merging a pull request may close this issue.

2 participants