Winston: It looks like 3.0 is logging {} for Error objects

Created on 19 Mar 2018 · 12Comments · Source: winstonjs/winston

Hi All
I am having some hassle with winston 3.0 logging empty error objects when it is using a json format.

module.exports = winston.createLogger({
  format: format.combine(
    format.label({ label: 'my label'}),
    format.timestamp(),
    format.prettyPrint()
  ),
  transports: [
    new (winston.transports.Console)({
      level: error
    })
  ]
});

logs the expected

 {error: [stack trace here] }
 ```

 while

module.exports = winston.createLogger({
format: format.combine(
format.label({ label: 'my label'}),
format.timestamp(),
format.json()
),
transports: [
new (winston.transports.Console)({
level: error
})
]
});

logs the erroneous

{error: {} }

when it is passed

logger.log({
error: new Error('my error message')
});

Manually creating a format with

winston.format.printf
````
also returned the erroneous result.

Does anybody know of a workaround for this?

Source

evertpieterse

👍16

Most helpful comment

More concise version:

function format() {
  const replaceError = ({ label, level, message, stack }) => ({ label, level, message, stack });
  const replacer = (key, value) => value instanceof Error ? replaceError(value) : value;
  return combine(label({ label: 'ssr server log' }), format.json({ replacer }));
}

const logger = createLogger({
  format: format(),
});

But this is what I actually do to have pretty logs locally and JSON errors in production:

function prodFormat() {
  const replaceError = ({ label, level, message, stack }) => ({ label, level, message, stack });
  const replacer = (key, value) => value instanceof Error ? replaceError(value) : value;
  return combine(label({ label: 'ssr server log' }), format.json({ replacer }));
}

function devFormat() {
  const formatMessage = info => `${info.level} ${info.message}`;
  const formatError = info => `${info.level} ${info.message}\n\n${info.stack}\n`;
  const format = info => info instanceof Error ? formatError(info) : formatMessage(info);
  return combine(colorize(), printf(format))
}

const logger = createLogger({
  level: process.env.LOG_LEVEL || 'info',
  exitOnError: false,
  transports: [new transports.Console()],
  format: isProd ? prodFormat() : devFormat(),
});

which gives me this in production

bildschirmfoto 2018-09-21 um 16 46 35

and this in development

bildschirmfoto 2018-09-21 um 16 47 04

LukasBombach on 21 Sep 2018

👍25 ❤9

All 12 comments

A workaround:

function errorReplacer(key, value) {
  if (value instanceof Error) {
    return { message: value.message, stack: value.stack };
  }
  return value;
}

const logFormat = winston.format.printf((info) => {
  return `${JSON.stringify(info, errorReplacer)}`;
});

module.exports = winston.createLogger({
  format: format.combine(
    format.label({ label: 'my label' }),
    format.timestamp(),
    logFormat
  ), ...

Hope it helps.

evertpieterse on 19 Mar 2018

👍3

Workaround didn't work for me (info.message is getting lost somewhere)

Variant workaround:

const winston = require('winston')
const MESSAGE = Symbol.for('message')

/*
 * function replacer (key, value)
 * Handles proper stringification of Buffer output.
 */
const replacer = function (key, value) {
  return value instanceof Buffer
    ? value.toString('base64')
    : value
}

var json_log = winston.format(function (info, opts) {
  var display = info
  if (info._error) {
    display = Object.assign({}, info, { message: info._error })
    delete display._error
  }
  info[MESSAGE] = JSON.stringify(display, opts.replacer || replacer, opts.space)
  return info
})

var preserve_error_message = format(function (info, opts) {
  if (_.isError(info)) {
    info._error = info.message
  }
  return info
})

const logger = winston.createLogger({
  levels: ...,
  format: format.combine(format.timestamp(), preserve_error_message()),
  transports: [
    new transports.Console({
    level: this.config.console.level,
    format: json_log({ space: 2 })
  })
]

That doesn't seem particularly elegant, so an official to preserve info.message when info is an Error would be ideal (it works when info is a regular Object)

pcothenet on 26 Mar 2018

👍2

I'm running into this as well. Shouldn't winston handle this out of the box? @indexzero what do you think about this?

dhensen on 26 Mar 2018

👍11

After looking at the logform json implementation I now see how the opts.replacer is supposed to be used and I came up with another solution when combining this stackoverflow post with the existing Buffer stringification:

'use strict';

const winston = require('../');

const logger = winston.createLogger({
    format: winston.format.combine(
        winston.format.json({ replacer: replaceErrors })
    ),
    transports: [
        new winston.transports.Console(),
    ]
});

function replaceErrors(key, value) {
    if (value instanceof Buffer) {
        return value.toString('base64');
    } else if (value instanceof Error) {
        var error = {};

        Object.getOwnPropertyNames(value).forEach(function (key) {
            error[key] = value[key];
        });

        return error;
    }

    return value;
}


var error = new Error('foooo');
error.my_custom_stuff = 'bar';

logger.log('error', 'Hello, this is a raw logging event', { error });

which prints:

{"error":{"stack":"Error: foooo\n    at Object.<anonymous> (/home/dino/work/winston/examples/json.js:31:13)\n    at Module._compile (module.js:662:30)\n    at Object.Module._extensions..js (module.js:673:10)\n    at Module.load (module.js:575:32)\n    at tryModuleLoad (module.js:515:12)\n    at Function.Module._load (module.js:507:3)\n    at Function.Module.runMain (module.js:703:10)\n    at startup (bootstrap_node.js:193:16)\n    at bootstrap_node.js:660:3","message":"foooo","my_custom_stuff":"bar"},"level":"error","message":"Hello, this is a raw logging event"}

I no longer think this should be handled outside the box, because I think a logging library should not determine how your error should be serialized into a log message, you define that yourself.

dhensen on 27 Mar 2018

👍3 🚀1

Not sure of your exact use case but why aren't you logging errors directly:

logger.log(new Error('my error message'));

(That works as of https://github.com/winstonjs/winston/pull/1234).

If you do need the error object inside a larger object you're logging, then it's worth noting Node.js Errors are not JSON objects, but there are things like https://www.npmjs.com/package/utils-error-to-json or perhaps doing a parse(stringify(error)) that would make this work with the JSON formatter. It seems like that's what @dhensen 's solution does, converting the Error to JSON -- so you could do something like that, use a package, etc., but this generally shouldn't be the winston json formatter's concern, because who knows what kind of custom types you might be passing to the json formatter :)

DABH on 1 Apr 2018

👍2

Going to go ahead and mark this closed, feel free to re-open or make a new issue if new problems/questions arise! Thanks!

DABH on 5 Apr 2018

Not even parse(stringify(error)) works as you then still lose the stack trace.
I managed to make this work by creating a custom formatter like this one:

const formatErrorConverter = winston.format(
    info =>
        info instanceof Error
            ? Object.assign({ level: info.level, message: info.message, stack: info.stack }, info)
            : info,
);

And it works quite well!

lzambarda on 8 Aug 2018

instance of Error works only for top-level formatter. It does NOT work for transport-level formatters. Can anyone explain why?

mir3z on 21 Sep 2018

👍6