CODEWITHSUNDEEP
node.jsexpresshttppinojs
Julio Martínez
Julio Martínez

Reputation: 131

How to log a customized error message with pino-http and express?

We are using pino-http with express for logging the REST API requests we receive in our application.

When there are errors, we log the error object which provides information about what went wrong.

However, when pino-http logs the info for the failed HTTP request, the error message is set to "failed with status code 500", which is too generic and provides no useful information. It does not log the message from the error object.

The setup is

// pino.ts
import pino, { type LoggerOptions } from 'pino';
import http from 'pino-http';

const options: LoggerOptions = {
};

options.timestamp = () => `,"time":"${new Date(Date.now()).toISOString()}"`;
options.formatters = {
    level: (label) => {
        return { level : label.toUpperCase() };
    },
};

const logger = pino(options);

const httpLogger = http({
    logger,
    },
    serializers: {
        // Do not include extensive error message in log output
        err: (err) => err.message
    },
    customErrorMessage: (_req, _res, err) => err.message,
});
export { httpLogger };

//express.ts
import express from 'express';
import { httpLogger } from './pino';
const app = express();
app.use(httpLogger);
...

I expect that pino-http logs the message from the error object rather than 'failed with status code 500'

Is this possible, or is it a limitation with pino-http ?

Upvotes: 1

Views: 686

Answers (2)

Skulaurun Mrusal
Skulaurun Mrusal

Reputation: 2847

I've encountered a similar issue and fixed it by specifying custom express error handler and setting res.err to the error object.

This is how pino-http decides the error object to serialize to the log:

// from pino-http logger.js (inside function onResFinished)
const error = err || res.err || new Error('failed with status code ' + res.statusCode)

So what is happening is that the err object passed to onResFinished(res, logger, err) by an express callback is undefined and the same goes for res.err, resulting in the "failed with status code" message.

The solution is to either use res.emit("error", err) as pino-http listens to events emitted by the response, or set res.err.

Custom express error handler:

app.use((err: Error, req: Request, res: Response, next: NextFunction) => {
  // set error for pino-http to log
  res.err = err;
  // let express default error handler handle the error (optional)
  next(err);
});

To integrate into your code:

// express.ts
import express, { Request, Response, NextFunction } from 'express';
import { httpLogger } from './pino';
const app = express();
app.use(httpLogger);
...
// middlewares and routes
app.use(someMiddleware())
app.use(someRouter())
app.get("/test", (req, res) => {
  // test if error handling is working
  throw new Error("this is bad...");
});
...
// put the custom error handler as last app.use() call
app.use((err: Error, req: Request, res: Response, next: NextFunction) => {
  // set error for pino-http to log
  res.err = err;
  // let express default error handler handle the error (optional)
  next(err);
});
// start the server
app.listen(...)

Sources:

Upvotes: 0

Adam Jones
Adam Jones

Reputation: 721

I had a similar issue when I used a custom error handler. I logged the error in my error handler and returned a JSON response with a 500 status. pino-http created a log entry for the request and since the status was a 500 it logged an error but the Error object was generated by pino-http with the message "failed with status code 500". Setting customErrorObject in the logger config allows you to specify the Error object that gets logged, and customErrorMessage allows you to specify the message.

In my case since I already processed the original error in my custom error handler it made more sense for the request log to simply note the 500 status and not log the error object. In your case if you haven't specified a custom error handler, the original error is probably getting processed by the Express default error handler. Creating a custom error handler and logging the error object from there is probably your best bet.

Upvotes: 1

Related Questions