Error logging method does not logs Error instance correctly

[nosuchip]

Please tell us about your environment:

• winston version? 3.1.0

  • winston@2
  • winston@3

• node -v outputs: v8.11.3

• Operating System? Linux

• Language? all

What is the problem?

logger.error called with Error instance doesn't use message and stack fields, instead logs test error.

Code example:

const winston = require('winston');

const alignedWithColorsAndTime = winston.format.combine(
  // winston.format.colorize({ all: true }),
  // winston.format.timestamp(),
  // winston.format.align(),
  winston.format.printf((info) => {
    const { level, message, ...args } = info;

    if (level.indexOf('error') !== -1) {
      console.log(typeof message, JSON.stringify(message));
    }

    return `[${level}]: ${message} ${Object.keys(args).length ? JSON.stringify(args, null, 2) : ''}`;
  })
);

const transports = [new winston.transports.Console({
  level: 'debug',
  format: alignedWithColorsAndTime
})];

const logger = winston.createLogger({
  level: 'debug',
  transports
});

try {
  logger.info('aaaaa');
  logger.debug('bbbb');
  logger.error('eeee');

  throw new Error('Scary error');
} catch (error) {
  logger.error(error);
}

What do you expect to happen instead?

At least actual error message logged. Ideally - with stack.

[nosuchip]

It doesn't depends on printf formatter, simple one gives the same result. Event without formatter it returns empty message.

[nosuchip]

Probably related issue #1422

[gtsec]

Had same issue, I had to implement logger.error myself:

  logger.error = err => {
      if (err instanceof Error) {
        logger.log({ level: 'error', message: `${err.stack || err}` });
      } else {
        logger.log({ level: 'error', message: err });
      }
    };

[nosuchip]

@gtsec actually I did almost the same just used new method name .exception.

[rgoupil]

This might be caused by wintson-transport, see winstonjs/winston-transport#31 for the issue and winstonjs/winston-transport#34 for the PR.

[jeremy-j-ackso]

In a sample repo where I'm testing out migrating winston-graylog2 to use winston@3x I ended up implementing the error conversion as a custom formatter.

const errorFormatter = format((info, opts) => {
  let formatted = {};

  if (info instanceof Error) {
    // An error object is not 100% like a normal object, so
    // we have to jump through hoops to get needed info out
    // of error objects for logging.
    formatted = Object.assign(formatted, info);
    formatted.message = info.stack;
  } else {
    formatted = info;
  }

  return formatted;
});

However for a consistent experience it would be beneficial if this handling was done inside of the logger's error method, rather than relying on custom formatters (inconsistent from project-to-project) or re-implementing/overwriting the library's methods (super unsafe & hacky).

[jeremy-j-ackso]

Actually, I just now noticed that the default winston format object has a handler for errors, so you just need to attach it as a formatter.

https://github.com/winstonjs/logform#errors

[kbirger]

Example?

[jeremy-j-ackso]

So, turns out I was incorrect about the error formatter. It's not in Winston yet, but it is in [email protected], and you have to use it in combination with the metadata and json formatters.

So, yeah, lots of caveats to get it going. Would be better if you could just use it standalone, but it's better than nothing.

const winston = require('winston');
const { format } = require('logform');

const logger = winston.createLogger({
  format: format.combine(
    format.errors({ stack: true }),
    format.metadata(),
    format.json(),
  ),
  transports: [ new winston.transports.Console() ],
});

logger.error(new Error(FakeError));

[kbirger]

Slick workaround @jeremy-j-ackso

[jeremy-j-ackso]

Suggesting this be closed due to #1576.

Can use the formatters.

const winston = require('winston');
const { format } = winston;

const logger = winston.createLogger({
  format: format.combine(
    format.errors({ stack: true }),
    format.metadata(),
    format.json(),
  ),
  transports: [ new winston.transports.Console() ],
});

logger.error(new Error('FakeError'));

[DABH]

Yep, Errors should finally be loggable in a nice way for people who want to turn on that functionality!

[kbirger]

While this approach mostly works, it doesn't seem to provide an easy way to log errors in a text format like simple(). It seems like a very common use case, and it would be wonderful if there was a standard, hassle free, and opinionated way of doing it.

[indexzero]

I appreciate the desire for a one-size-fits-all-do-everything-for-me-make-it-magic-dont-make-me-think format. It's an easy trap to fall into, which is how winston@2 and prior release lines had such awful performance compared to other logging libraries. It simply tried to do too much by default to meet the feature demands of a large set of users with varying opinions and tastes.

As a project winston@3 embodies a new opinion: push complex formatting into decoupled, single purpose formats and make combining those easy for users.

I will admit there is still work to do on documentation, along with high-level explainations and debugging of formats.

All that said the errors format suggested reflects the opinion of the project: Can this be implemented as a custom format?

[nosuchip]

@DABH why did you closed this issue? Using of formatter suggested by @jeremy-j-ackso does not works without format.json() formatter. It is not even workaround.

const winston = require('winston');
const { format } = winston;

const logger = winston.createLogger({
  format: format.combine(
    format.errors({ stack: true }),
    format.metadata()
  ),
  transports: [ new winston.transports.Console() ],
});


function a() {
  throw new Error('Error from "a"');
  console.log('a()');
}

function b() {
  a();

  console.log('a() called from b()');
}

function c() {
  b();

  console.log('b() called from c()');
}

function f() {
  try {
    c();

    console.log('c() called from d()');
  } catch(error) {
    logger.error(error);
  }
}

f();

$ node 1.js
Error from "a"

[nosuchip]

Tested on [email protected].

[medington]

Yeah, I agree with @nosuchip - there doesn't seem to be a good solution if you want to use the simple() format. We actually need both to work in a project I have. I ended up creating a custom formatter which works but is a bit of a hack. This code gives me a stack in json when using that format and a stack in raw text when using simple format:

const displayStack = winston.format((info) => {
  info.message = info.stack ? info.stack : info.message
  return info
})

const consoleDebugFormat = winston.format.combine(
  displayStack(),
  winston.format.simple()
)

const jsonFormat = winston.format.combine(
  winston.format.errors({ stack: true }),
  winston.format.json()
)

const activeFormat = process.env.LOG_FORMAT === 'simple' ? consoleDebugFormat : jsonFormat

const loggerConsole = new winston.transports.Console()
const logger = winston.createLogger({
  transports: [loggerConsole],
  format: activeFormat,
  exitOnError: false
})

[kgrozdanovski]

So there is still not a solution to this issue?

[nosuchip]

@cogscape unfortunately no. Just tested latest winston and no one solution found over internet gave in output error message and stack. Except custom method, of course.

[nosuchip]

For TypeScript I am using following snippet to avoid typing warnings:

... 
// standard transports and format initialization

export interface BetterLogger extends winston.Logger {
    exception: (error: Error, prefix?: string) => BetterLogger;
}

const logger: BetterLogger = winston.createLogger({
    level: config.logLevel,
    transports,
}) as BetterLogger;

// Monkey patching Winston because it incorrectly logs `Error` instances even in 2020
// Related issue: https://github.com/winstonjs/winston/issues/1498
logger.exception = function (error, prefix?) {
    const message = error.message || error.toString();
    const stack = error.stack;
    prefix = prefix ? `${prefix} ` : '';

    return this.error(`${prefix}${message}, stack ${stack}`) as BetterLogger;
};

export default logger;

It works with any other formatters.

Reason: attempt to implement current formatter always ends with fail as info passed to formatter never instanceof Error.

[rattkin]

I can't log any meaningful error:

import winston from 'winston';
const consoleTransport = new winston.transports.Console({
    format: winston.format.combine(
        winston.format.errors({ stack: true }),
        winston.format.metadata(),
        winston.format.json(),
    )
});
export const logger = winston.createLogger({
    transports: [
        consoleTransport,
    ]
});

It only logs this sad bit:
{"level":"error","metadata":{}}

just using simple is almost better as it produces double the information:
error: undefined

What I need:

TypeError: Cannot read property 'check' of undefined
    at Object.updateSession (U:\Users\muj\endpoint\src\services\cookieService.ts:88:23)

is there a way to get via winston the information that node print automatically when it catches unhandled error?

[shrinktofit]

Any updates?

[shrinktofit]

I noticed that the reason is Object.assign({}, info) does not copy the stack property at:

https://github.com/shrinktofit/editor-3d/blob/5afb36943c4f4fd9a145d82cd4bd44cd6b188242/app/node_modules/winston-transport/index.js#L91

[aniketmore311]

so basically, if I want the stack trace I have to either

1. use errors formatter with json and meta formatters and get back a json formatter log
2. or implement my own custom formatter to give me simple text log output
   I am correct or am I missing anything ??

[xnko]

It's 2021 and still didn't work for Error instances. I'm stopped using this.

[Raphyyy]

This is an up, as I think this should be taking account.
I upgraded winston from 2 to 3, but I am now downgrading to 2 because of this.
Please @DABH re-open this issue
Thank you for your work though

[kasvith]

This is a very critical issue for our app, we use winston and when errors occur there is no way to see the stack without tinkering the .error

[phaalonso]

This is a very critical issue for our app, we use winston and when errors occur there is no way to see the stack without tinkering the .error

I have the same problem

[Ayzrian]

Hey, guys!
I made a fix for that one in errors format.
winstonjs/logform#118

[GuyMograbi]

I expect this to work out of the box without a formatter.
Can we get someone to merge @Ayzrian's fix please?

[ghost]

+1,, would really like to see a fix merged for this issue. Error handling with stack trace option seems relatively worthless if you can't create a log that contains an error message and stack trace.

[BrennerSpear]

My fix for now, pretty ridiculous:
const logger = isProdEnv ? winstonLogger : console;

[amolpukale26]

logger.error("Hi")
logger.error("Hello")
This is printing only first line in error file by using winston. Why?
Whereas logger.info prints all logs.

[wbt]

I think this is a duplicate of #1338 where a workaround is posted. To future commenters, please post here only if you are distinguishing the two.

[cyrilchapon]

See my comment here : winstonjs/logform#100

This is an internal bug inside base Transport class, that needs to be adressed.

[fpmanuel]

Just in case I'm using metadata to log errors, not ideal but it works.

[sundayz]

in 2023 the most popular node.js logging library with 10 million weekly downloads can't log Error instances by default? I'm not even getting a message, just "undefined", nice

[kbirger]

in 2023 the most popular node.js logging library with 10 million weekly downloads can't log Error instances by default? I'm not even getting a message, just "undefined", nice

It is open source... You could contribute!

[cyrilchapon]

Here's my workaround :

import { Logger } from 'winston'

export const logError = (logger: Logger) => (err: unknown) => {
  if (!(err instanceof Error)) {
    logger.error(JSON.stringify(err))
    return
  }

  // eslint-disable-next-line @typescript-eslint/no-unused-vars
  const { name, message, cause, stack, ...metadata } = err

  let _message = stack != null ? stack : `${name}: ${message}`

  if (metadata != null) {
    _message = `${_message}
    ${JSON.stringify(metadata)}`
  }

  logger.error(_message)
}

catch (err: unknown) {
  logError(logger)(err)
}

[ryanClaimocity]

Any update on this?