winstonjs / winston

A logger for just about everything.
http://github.com/winstonjs/winston
MIT License
22.37k stars 1.8k forks source link

[Bug]: Child logger changes Error object type to plain which cause the info object to bypass error() formatter #2381

Open maxkoretskyi opened 6 months ago

maxkoretskyi commented 6 months ago

🔎 Search Terms

Child logger

The problem

Logger defined like this:

const logger = winston.createLogger({
   format: combine(
     error({stack: true, cause: true}),
    format(info) => {
        return info.stack +  info.cause;
   ],
     transports: [
      fileRotateTransport,
      new winston.transports.Console({
          format: formatter
      })
  ],

const childLogger = logger.child({ service: 'child_meta });
childLogger .error(new Error('msg', {cause: {location: 3}}));

Error formatter uses info instanceof Error check to apply it's logic:

module.exports = format((einfo, { stack, cause }) => {
  if (einfo instanceof Error) {
    const info = Object.assign({}, einfo, {
      level: einfo.level,
      [LEVEL]: einfo[LEVEL] || einfo.level,
      message: einfo.message,
      [MESSAGE]: einfo[MESSAGE] || einfo.message
    });

    if (stack) info.stack = einfo.stack;
    if (cause) info.cause = einfo.cause;
    return info;
  }

But the child logger here changes the type:

class Logger extends Transform {
  constructor(options) {
    super({ objectMode: true });
    this.configure(options);
  }

  child(defaultRequestMetadata) {
    const logger = this;
    return Object.create(logger, {
      write: {
        value: function (info) {
          // here the type of infoClone no longer instance of Error
          const infoClone = Object.assign(
            {},
            defaultRequestMetadata,
            info
          );

so the error formatter is not applied at all.

I can workaround this by putting the error into the message property, but not sure that's how it should be done:

childLogger.error({message: new Error('some', {cause: e})});

due to this check:

  if (!(einfo.message instanceof Error)) return einfo;

What version of Winston presents the issue?

3.11.0

What version of Node are you using?

v16.20.0

If this worked in a previous version of Winston, which was it?

No response

Minimum Working Example

No response

Additional information

No response

mix4242 commented 4 months ago

I believe this is instead due to child logger doing cloning like

  child(defaultRequestMetadata) {
    const logger = this;
    return Object.create(logger, {
      write: {
        value: function (info) {
          const infoClone = Object.assign(
            {},
            defaultRequestMetadata,
            info
          );

          // Object.assign doesn't copy inherited Error
          // properties so we have to do that explicitly
          //
          // Remark (indexzero): we should remove this
          // since the errors format will handle this case.
          //
          if (info instanceof Error) {
            infoClone.stack = info.stack;
            infoClone.message = info.message;
          }

          logger.write(infoClone);
        }
      }
    });
  }

(source)

This not only doesn't add back cause property, but much worse it removes the ability to ever check for instanceof Error later on.

When using the root logger, cause is available without problem

mesmere commented 3 months ago

I think I'm running into this issue too. In my case I'm not explicitly creating a child logger, but I am throwing an exception and expecting winston's ExceptionHandler to pick it up, and something similar is happening. The errors formatter doesn't do anything because einfo isn't an Error, although einfo.error is, and einfo.message is just a string:

image

The above debugger screenshot is just what happens when I throw an uncaught exception:

} catch (e) {
  throw new Error("Blah blah", { cause: e });
}

with winston.format.errors({ stack: true, cause: true }) in my logger format and handleExceptions: true in my transport. I'm surprised more people haven't run into this.

mesmere commented 3 months ago

For now info.error.stack and info.error.cause.stack are working for me as a workaround:

winston.format.printf(info => {
  if (info.error instanceof Error && info.error.stack && info.error.cause) {
    return `${info.timestamp} ${info.level} ${info.error.stack}\nCaused by: ${info.error.cause.stack}`;
  } else if (info.error instanceof Error && info.error.stack) {
    return `${info.timestamp} ${info.level} ${info.error.stack}`;
  } else {
    return `${info.timestamp} ${info.level} ${info.message}`;
  }
})