winston: [3.0.0] Error object is not parsed or printed

No really, this is unacceptable for a logging library. Maintainer should simply put a well highlighted example on docs where it is shown how to log an error, even defining custom printf format and non json format and where you can log error with something like logger.error(“something”, err) and logger.error(err) Winston seemed to be great but this issue is incredibly unacceptable

Am I missing something, or is it a complete headache (or even impossible?) to get the same output one easily gets from console.log/error/warn?

try {
   // ...
  throw new Error('foo');
} catch (e) {
  console.error('Caught error:', e);  // convenient, informative
  logger.error('Caught error:', e);  // nope, the second parameter is something else (couldn't find docs)
  logger.error(`Caught error: ${e}`);  // stack lost
  logger.error(`Caught error: ${JSON.stringify(e)}`);  // Caught error: {}
}

What is the equivalent winston code to get the same output as console.error('Caught error:', error);?

And where is the documentation for the parameters taken by the convenience methods on the logger object?

The feature is supported since winston@3.2.0

Example usage:

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

const print = format.printf((info) => {
  const log = `${info.level}: ${info.message}`;

  return info.stack
    ? `${log}\n${info.stack}`
    : log;
});

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

const error = new Error('Ooops');

logger.error(error);
logger.error('An error occurred:', error);

cc @HRK44 @the-vampiire

I switched to pino and never looked back instead of wasting so much time trying to make something work that should have been working out of the box since it’s the most common use case.

@dandv

logger.error('Caught error:', e);

This doesn’t work because, unlike console.log(), the winston’s logger.<level>(message) takes only one parameter called message. That message parameter is either an object or a string (someone correct me if I’m wrong but that’s my understanding).

Note that you can also use logger.log({level: <level>, message: <message>}). To learn more about these two functions I would recomend reading this part of the docs: Winston Docs on Log Levels. Be sure to read through Using Logging Levels

logger.error(`Caught error: ${e}`);

I can not definitively say why this does not output the stack, but I do know this is not a problem with winston. If you try console.log(`Caught error: ${e}`) it also does not include the stack. I haven’t worked with template literals much so either template literals doesn’t work well with objects, or javascript’s console.log recognizes the object as an error object and thus only outputs the the message property. That’s my best guess.

logger.error(`Caught error: ${JSON.stringify(e)}`)

This one gets to the heart of what this bug thread is about. First you must understand some technical details about javascript. Note that if you try console.log(`Caught error: ${JSON.stringify(e)}`) you also get that same output Caught error: {}. As @indexzero explained:

message and stack properties on Error are non-enumerable which causes JSON.stringify to output something that one does not expect.

Basically, because message and stack properties are non-enumerable, JSON.stringify skips over those properties which is how you end up with an empty object {}. To understand enumerability better I recommend reading this Enumerability and ownership of properties.

Luckily, because of the way winston 3.0 was designed (props to the winston team) we have a workaround for this that @indexzero gave. I’ll help explain it. First you create this function:

const enumerateErrorFormat = format(info => {
  if (info.message instanceof Error) {
    info.message = Object.assign({
      message: info.message.message,
      stack: info.message.stack
    }, info.message);
  }

  if (info instanceof Error) {
    return Object.assign({
      message: info.message,
      stack: info.stack
    }, info);
  }

  return info;
});

From the docs Streams, objectMode, and info objects the info object has two properties, info.level, and info.message. That info.message property IS the error object if that is all you passed in. So we create a new object where message.stack and message.message (Think of it as Error.stack and Error.message) are now enumerable, and we include what ever other properties that may also be attached to that error object.

Next you’ll create this logger which uses the enumerateErrorFormat() function above:

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

This will take whatever message you pass in and check if it is an error object. If it is then it will fix the enumeration problem. Then it passes message to format.json which will stringify any object (error or not). If it’s not an object then it’s a string and format.json effectivley does nothing, and you’re home free!

Still, it would be nice if we didn’t have to create that enumerateErrorFormat since error objects are commonly logged. As I understand it the winston team is working on a fix that will be released in a later version.

Some final notes. This only works if you use logger.log({level: <level>, message: <message>}) where message is the error object. Example:

try {
  throw(new Error('This should work'));
} catch (err) {
  logger.log({level: 'error', message: err});
}

There is another bug in winston where this code does not work, as I explained in my other post above:

try {
  throw(new Error('This will not work'));
} catch (err) {
  logger.error(err);
}

For some reason the info.message property is undefined when we use logger.error(err). Hopefully @indexzero can figure this one out.

If anyone is looking for a quick work-around you can include enumerateErrorFormat in your logger’s format for now. We will hopefully have a fix for this out before 3.0.0 next week (or shortly after in 3.0.1)

const winston = require('../');
const { createLogger, format, transports } = winston;

const enumerateErrorFormat = format(info => {
  if (info.message instanceof Error) {
    info.message = Object.assign({
      message: info.message.message,
      stack: info.message.stack
    }, info.message);
  }

  if (info instanceof Error) {
    return Object.assign({
      message: info.message,
      stack: info.stack
    }, info);
  }

  return info;
});

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

// Error as message
console.log('Run FIRST test...');
logger.log({ level: 'error', message: new Error('FIRST test error') });

// Error as info (one argument)
console.log('\nRun SECOND test...');
const err = new Error('SECOND test error');
err.level = 'info';
logger.info(err);

// Error as info (two arguments);
console.log('\nRun THIRD test...');
logger.log('info', new Error('THIRD test error'));

Can this please get fixed for logger.error, etc?

It is cumbersome and verbose to use logger.log, especially since with logger.error you can easily add multiple arguments.

@will093 same here. Been on that issue again and don’t get it why my console.log is nice and clean and winston format is shit.

using @tiagonapoli and @will093’s solution of adding it to just the parent seems to be the easiest way to support directly logging errors and still logging messages – here’s a full example of a minimal setup w/ timestamps:

const createLogger = () => {
  const logFormatter = winston.format.printf(info => {
    let { timestamp, level, code, stack, message } = info;

    // print out http error code w/ a space if we have one
    code = code ? ` ${code}` : '';
    // print the stack if we have it, message otherwise.
    message = stack || message;

    return `${timestamp} ${level}${code}: ${message}`;
  });

  return winston.createLogger({
    level: 'info',
    // put the errors formatter in the parent for some reason, only needed there:
    format: winston.format.errors({ stack: true }),
    transports: new winston.transports.Console({
      format: winston.format.combine(
        winston.format.timestamp(),
        logFormatter
      ),
  });
};

works with a stack when called with an error like: logger.error(error), works with a string when called like logger.error('a regular message'), looks like this in my logs:

2020-09-23T20:05:30.30Z info: Feathers application started on http://localhost:3030
2020-09-23T20:05:35.40Z info: job queue - redis ready, registering queues...
2020-09-23T20:05:40.25Z error 401: NotAuthenticated: invalid authorization header
    at new NotAuthenticated (/path/to/server/node_modules/@feathersjs/errors/lib/index.js:94:17)
    at Object.<anonymous> (/path/to/server/src/hooks/authentication.js:123:456)
    at /path/to/server/node_modules/@feathersjs/commons/lib/hooks.js:116:46

this does not attempt to solve winston’s logger.error('message here', error)-incompatibility w/ console.log, which @tiagonapoli’s more involved solution seems to do.

Also, if you like json logs you can drop the logFormatter here and use winston.format.json() in its place, which will still include the stack – but it isn’t pretty.

Update: because there are still issues with this I have been doing the following for a while and its been working great

// Grab the default winston logger
const winston = require('winston');

const { format } = winston;
const { combine, timestamp } = format;

// Custom format function that will look for an error object and log out the stack and if 
// its not production, the error itself
const myFormat = format.printf((info) => {
  const { timestamp: tmsmp, level, message, error, ...rest } = info;
  let log = `${tmsmp} - ${level}:\t${message}`;
  // Only if there is an error
  if ( error ) {
    if ( error.stack) log = `${log}\n${error.stack}`;
    if (process.env.NODE_ENV !== 'production') log = `${log}\n${JSON.stringify(error, null, 2)}`;
  }
  // Check if rest is object
  if ( !( Object.keys(rest).length === 0 && rest.constructor === Object ) ) {
    log = `${log}\n${JSON.stringify(rest, null, 2)}`;
  }
  return log;
});

 winston.configure({
    transports: [
      new winston.transports.Console({
        level: 'debug',
        timestamp: true,
        handleExceptions: true
    }),
  ];
    format: combine(
      trace(),
      timestamp(),
      myFormat
    ),
  });


// Finally you log like this
logger.error('An error occurred!!!', { error } );

I’m not a committer but I’m probably correct to say that this is not going to be “fixed” because it’s not broken. Winston is worth using. You just need to configure it - the best advice for me is above at https://github.com/winstonjs/winston/issues/1338#issuecomment-506354691

@OBrown92 I have faced the same issue today. I can confirm, that it works, if format.errors({ stack: true }), is applied to logger, not to transport. In this case it’s possible to use both logger.error(error); and logger.error('Something went wrong', error). However, there is a problem, when I try to apply format.errors({ stack: true }) to chosen transport. In this case I get undefined for logger.error(error);, but logger.error('Something went wrong', error) works properly.

I’m not sure if it’s expected behavior or it’s a bug, but I spent a lot of time to find the cause, so please fix it or mention about that somewhere in your documentation. It would be really helpul.

Anyway, I am very grateful for your work on this great project.

Yeah this gave me enough headaches that Winston started to seem like way more trouble than it was worth for my relatively simple use case… I ended up just writing my own small logger class, and I’d recommend others do the same unless Winston provides something you REALLY need.

Until a fix is published I use the following workaround:

logger.error = item => {
  logger.log({ level: 'error', message: item instanceof Error ? item.stack : item });
};

So this is still not fixed after 1year? Do I have to hack winston logger code to make it work?

This is my take on how to log errors using Winston. It’s not unique, a lot of peeps above have working solutions based around the same concepts too.

Background I’m using @jsdevtools/ono to wrap arbitrary object types into custom errors, but regardless, this solution still seems to work fine on native node errors (e.g. fs eperm errors), and custom error classes.

Explanation Basically, I rely on format.errors({stack:true}) and format.metadata(). As mentioned by https://github.com/winstonjs/winston/issues/1338#issuecomment-532327143, this has to be in the parent formatter.

Metadata helps to shift all the error object’s custom properties to info.metadata.

I wanted to print 3 types of information: the error message, the stacktrace, and the error object’s properties. The error message was already plaintext. I pretty-printed the stack info.metadata.stack using the pretty-error module. For the error object’s properties, I didn’t want the stacktrace to appear again, so I cloned the object, and deleted the stacktrace property. I then pretty-printed the error object using fast-safe-stringify, which is the same stringify module that winston relies on.

    const lodash = require("lodash");
    const path = require("path");
    const winston = require("winston");
    const { default: stringify } = require("fast-safe-stringify");
    const logDir = "D:/temp/logs";

    // pretty formatting
    const PrettyError = require("pretty-error");
    const pe = new PrettyError();
    pe.withoutColors()
        .appendStyle({
            'pretty-error > trace':
            {
                display: 'inline'
            },
            'pretty-error > trace > item':
            {
                marginBottom: 0,
                bullet: '"*"'
            }
        })
        // @ts-ignore
        .alias(/.*[\\\/]CelebrityQuery/i, "<project>")
        .alias(/\[CelebrityQuery\][\\\/]?/i, "")
        .skip(/** @type {(_:any) => boolean} */ (traceline => {
            if (traceline && traceline.dir) {
                return traceline.dir.toString().startsWith("internal");
            }
            return false;
        }))
        .skipNodeFiles();

    const consoleFormat = winston.format.combine(
        winston.format.colorize(),
        winston.format.timestamp({
            format: 'DD MMM HH:mm:ss'
        }),
        winston.format.printf(info => {
            if (!lodash.isEmpty(info.metadata) && info.metadata.hasOwnProperty("stack")) {
                let dup = lodash.clone(info.metadata);
                delete dup.stack;
                const errBody = stringify(dup, undefined, 4);
                const stack = pe.render({ stack: info.metadata.stack });
                return `${info.timestamp} ${info.level} ${info.message}${errBody}\n${stack}`;
            } else if (lodash.isString(info.message)) {
                return `${info.timestamp} ${info.level} ${info.message}`;
            } else {
                return `${info.timestamp} ${info.level} ${stringify(info.message, undefined, 4)}`;
            }
        })
    );
    const logFormat = winston.format.combine(winston.format.timestamp(), winston.format.json());
    return winston.createLogger({
        level: 'debug',
        format: winston.format.combine(
            winston.format.errors({ stack: true }),
            winston.format.metadata()
        ),
        transports: [
            new winston.transports.Console({
                format: consoleFormat,
                level: 'info',
            }),
            new winston.transports.File({
                filename: path.join(logDir, "stdout.json"),
                format: logFormat,
                level: 'debug',
                maxsize: 1000000,
                tailable: true
            })
        ]
    });

PS: I also find the solution mentioned in https://github.com/winstonjs/winston/issues/1338#issuecomment-506354691 to be a good alternative. I.e. using logger.warn("Oh no", { error: new Error() }), then referencing info.error in your custom formatter.

I found two solutions, the first one is to use format.errors, mentioned on logform in the parent logger, then create a messageFormatter using format.printf and conditionally add a stack field extracted from info (format.errors({ stack: true}) will add that).

The other solution, that I preferred was hack into winston level loggers:

const addArgs = format((info) => {
  const args: any[] = info[Symbol.for('splat')]
  info.args = args ? [...args] : []
  return info
})

const messageFormatter = format.printf(info => {
  const { timestamp: timeString = '', message, args = [] } = info
  const formattedMsgWithArgs = util.formatWithOptions({ colors: true }, message, ...args)
  const msg = `${timeString} - ${info.level}: ${formattedMsgWithArgs}`
  return msg
})

const logger = createLogger({
  format: format.combine(
    addArgs(),
    format.timestamp({ format: 'HH:mm:ss.SSS' })
  ),

  transports: [
    new transports.Console({
      format: format.combine(format.colorize(), messageFormatter),
    }),
  ],
})

const levels = ['debug', 'info', 'error']
levels.forEach((level) => {
  logger[level] = (msg: any, ...remains: any) => {
    if(typeof msg != "string") {
      return logger.log(level, '', msg, ...remains)
    }

    logger.log(level, msg, ...remains)
  }  
})

It seems this way I can get error logging similar to console.log

We definitely used this form in winston2.x with no problems. winston.err('some message', err); along with winston.error(err) the above enumerateErrorFormat fixes winston.error(err) but not the use case with err as second parameter.

I use winston with a 3rd party transport (@google-cloud/logging-winston) so I have a little less control over the syntax. Plus I find this just more intuitive:

const error = new Error('something bad happened');
logger.error('was doing this and', error);

When logging to the console I concatenate the stack onto the message. But the result is something like this:

ERROR was doing this andsomething bad happened Error: something bad happened <rest of the stack.>

Since winston concatenates meta.message onto the original message, there is the weird andsomething and the duplicate message that is also printed in the stack. This is described in #1660 .

It looks like #1664 is trying to fix this. In the meantime, I wrote a formatter that “undos” that concatenation: https://github.com/winstonjs/winston/issues/1660#issuecomment-512226578

Guys, really? this is frustrating…

Update on this folks:

• Started writing some end-to-end integration tests for the errors format in logform with winston: https://github.com/winstonjs/winston/compare/gh-1338
• That showed that the API in the original PR was not correct, so I started hacking that towards correctness: https://github.com/winstonjs/logform/compare/winston-1338

Hoping to get this sewn up and shipped in the next couple of days. It is the next to last issue in our winston@3.2.0 tracker

Okay, I discovered something. My comment from September 3rd is wrong. This isn’t a problem with the default logger. This is a problem with where you define level and/or format. @DABH here is your old code:

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

const enumerateErrorFormat = format(info => {
  if (info.message instanceof Error) {
    info.message = Object.assign({
      message: info.message.message,
      stack: info.message.stack
    }, info.message);
  }

  if (info instanceof Error) {
    return Object.assign({
      message: info.message,
      stack: info.stack
    }, info);
  }

  return info;
});

const logger = winston.createLogger({
  level: 'debug',
  format: format.combine(
    enumerateErrorFormat(),
    format.json()
  ),
  transports: [
    new winston.transports.Console(),
  ],
});

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

If you remove this:

const logger = winston.createLogger({
  level: 'debug',
  format: format.combine(
    enumerateErrorFormat(),
    format.json()
  ),
  transports: [
    new winston.transports.Console(),
  ],
});

And replace it with this:

const logger = winston.createLogger({
  transports: [
    new winston.transports.Console({
      level: 'debug',
      format: format.combine(
        enumerateErrorFormat(),
        format.json()
      ),
    }),
  ],
});

Then the info.message === undefined problem shows up. I believe it should be okay to specify level and format for each transport; and I’m almost certain this was allowed in Winston 2.0.

Here is your code sample with my code change so you can easily run and test:

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

const enumerateErrorFormat = format(info => {
  if (info.message instanceof Error) {
    info.message = Object.assign({
      message: info.message.message,
      stack: info.message.stack
    }, info.message);
  }

  if (info instanceof Error) {
    return Object.assign({
      message: info.message,
      stack: info.stack
    }, info);
  }

  return info;
});

const logger = winston.createLogger({
  transports: [
    new winston.transports.Console({
      level: 'debug',
      format: format.combine(
        enumerateErrorFormat(),
        format.json()
      ),
    }),
  ],
});

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

Hopefully this helps get to the root of the problem.

I also still running into the issue. When i call the error like logger.error(error); I get only undefined. Only if I call it like logger.error('Something went wrong', error) I get the complete error and can parse it.

Still having this issue, lost bunch of time to figure this out, solution from @the-vampiire works well.

Why is this ticket closed?

@sandrocsimas I noticed that you need to give the enumerateErrorFormat function to the default formatter of the logger in order to make it work.

Formatter

const consoleLogger = winston.createLogger({
  level,
  format: winston.format.combine(
    winston.format.timestamp(),
    enumerateErrorFormat()
  ),
  transports: [
    new winston.transports.Console({
      format: winston.format.combine(
        winston.format.colorize(),
        printFormat,
      ),
    }),
  ],
});

I still don’t understand why tho

^^ That is the expected usage. Since mere mortals will never figure this out, it should be documented.

Doesn’t work

My 2¢

// Enable console logging when not in production
if (process.env.NODE_ENV !== "production") {
	logger.add(new transports.Console({
		format: format.combine(
			format.colorize(),
			format.simple(),
			format.printf(info => {
				const { level, ...rest } = info;
				let rtn = "";
				// rtn += info.timestamp;
				rtn += "[" + info.level + "] ";
				if (rest.stack) {
					rtn += rest.message.replace(rest.stack.split("\n")[0].substr(7),"");
					rtn += "\n";
					rtn += "[" + level + "] ";
					rtn += rest.stack.replace(/\n/g, `\n[${level}]\t`);
				} else {
					rtn += rest.message;
				}
				return rtn;
			}),
		),
	}));
}

Example for logger.error("Error during schema stitching", e);

@tiagonapoli your solution about using format.errors on the parent logger worked for me:

const logger = createLogger({
  transports: loggerTransports,
});

logger.format = format.errors({ stack: true });

It is fairly painful configuring this logger… Could it not just behave like console.log out the box?

I can verify that @tiagonapoli 's comment about how format.errors has to be on the parent logger is accurate. When I do something like this:

winston.loggers.add("default");
const log = winston.loggers.get("default");
/* get a `transportOptions` object and a `transportType` */
transportOptions.format = logform.format.combine(
  logform.format.errors({ stack: true }),
  logform.format.timestamp(),
  logform.format.printf(myFormatter)
);
log.add(new winston.transports[transportType](transportOptions);

Handling of Error object is does as if they were a string. However, if I do something like this:

winston.loggers.add("default");
const log = winston.loggers.get("default");
log.format = logform.format.errors({ stack: true });
/* get a `transportOptions` object and a `transportType` */
transportOptions.format = logform.format.combine(
  logform.format.timestamp(),
  logform.format.printf(myFormatter)
);
log.add(new winston.transports[transportType](transportOptions);

Handling of Error object works correctly.

It seems to me that the bug here is that there should be no difference in behavior.

This is still an issue? I’m still having problems with this:

const { createLogger, format, transports } = require('winston')

const { combine } = format

const errorFormatter = format((info) => {
  console.log(info)
  return info
})


const consoleTransport = new transports.Console({
  format: combine(errorFormatter()),
})

const logger = createLogger({
  transports: [
    consoleTransport,
  ],
})

try {
  throw new Error('Error message')
} catch(err) {
  logger.error(err) // info doesnt have the error object
  logger.error('', err) // info have the error object
}

same problem here…

after looking the source code, i can see what params it accepts:

interface LeveledLogMethod { (message: string, callback: LogCallback): Logger; (message: string, meta: any, callback: LogCallback): Logger; (message: string, …meta: any[]): Logger; (infoObject: object): Logger; }

so if you pass the error object as first param, it will only take the message of the error because it only understands strings, and if you pass the error in the second param then you can access the stack trace in info.stack

btw i couldn’t find this anywhere in the docs

For anyone that is still dealing with this, this is the workaround formatter I’ve managed to come up with (snippet of my logger.js module):

const { format, transports, createLogger }     = require("winston");
const { combine, timestamp, colorize, printf } = format;

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

    return combine(timestamp(), printf(format));
}

For some reason logger.error(new Error("hello")) only works if you define the formatter globally in winston.createLogger 🤔 and then you get the Error object in info in the formatter.

If you define a formatter per transport then you have to use logger.log({level: "error", message: new Error("FAILED")}) and handle the Error object via info.message instead of info to access the Error object.

I’d guess there’s a bug when setting the format field in the transport options?

Those are just my 2 cents and what worked for me, I’m new to Winston and not seasoned in JavaScript so don’t quote me on anything.

@nvtuan305, did you try @indexzero’s solution exactly or did you edit it a bit? If so could you provide sample code? His code should work if you’re using logger.log({level: ____, message: err}); It won’t work if you’re doing logger.info, logger.error, or any other flavor of logger.<level>. I’m almost certain that is a bug as I specified above and it should be fixed in a later release.

Update: because there are still issues with this I have been doing the following for a while and its been working great

// Grab the default winston logger
const winston = require('winston');

const { format } = winston;
const { combine, timestamp } = format;

// Custom format function that will look for an error object and log out the stack and if 
// its not production, the error itself
const myFormat = format.printf((info) => {
  const { timestamp: tmsmp, level, message, error, ...rest } = info;
  let log = `${tmsmp} - ${level}:\t${message}`;
  // Only if there is an error
  if ( error ) {
    if ( error.stack) log = `${log}\n${error.stack}`;
    if (process.env.NODE_ENV !== 'production') log = `${log}\n${JSON.stringify(error, null, 2)}`;
  }
  // Check if rest is object
  if ( !( Object.keys(rest).length === 0 && rest.constructor === Object ) ) {
    log = `${log}\n${JSON.stringify(rest, null, 2)}`;
  }
  return log;
});

 winston.configure({
    transports: [
      new winston.transports.Console({
        level: 'debug',
        timestamp: true,
        handleExceptions: true
    }),
  ];
    format: combine(
      trace(),
      timestamp(),
      myFormat
    ),
  });


// Finally you log like this
logger.error('An error occurred!!!', { error } );

where does the trace come from?

The issue is caused by this bug : https://github.com/winstonjs/winston-transport/issues/31

@SamuelMaddox17 @indexzero Thank you! I tried using logger.log({level: 'error', message: err}); and it works

I think I’m experiencing the same bug as @sandrocsimas.

Here is my logger config:

logger.js

const winston = require('winston');
const {configure, format} = winston;
const {combine, colorize, timestamp, printf} = format;

const enumerateErrorFormat = format(info => {
  if (info.message instanceof Error) {
    info.message = Object.assign({
      message: info.message.message,
      stack: info.message.stack
    }, info.message);
  }

  if (info instanceof Error) {
    return Object.assign({
      message: info.message,
      stack: info.stack
    }, info);
  }

  return info;
});

const myConsoleFormat = printf(info => {
  console.log('** Info Object: **');
  console.log(info);
  console.log('** Winston Output: **');
  return `${info.level}: ${info.message}`;
});

winston.configure({
  transports: [
    new winston.transports.Console({
      format: combine(
        colorize(),
        enumerateErrorFormat(),
        myConsoleFormat
      ),
    })
  ]
});

If I test it with this block of code:

Test A

const logger = require('winston');
try {
  throw(new Error());
} catch (err) {
  logger.error(err);
}

where new Error() doesn’t contain a message value, I get this output:

Output A

** Info Object: **
{ message: 
   { message: '',
     stack: 'Error\n    at Object.<anonymous> (app.js:21:9)\n    at Module._compile (module.js:652:30)\n    at Object.Module._extensions..js (module.js:663:10)\n    at Module.load (module.js:565:32)\n    at tryModuleLoad (module.js:505:12)\n    at Function.Module._load (module.js:497:3)\n    at Module.require (module.js:596:17)\n    at require (internal/module.js:11:18)\n    at Object.<anonymous> (server.js:11:13)\n    at Module._compile (module.js:652:30)' },
  level: '\u001b[31merror\u001b[39m',
  [Symbol(level)]: 'error',
  [Symbol(message)]: '{"message":{},"level":"error"}' }
** Winston Output: **
error: [object Object]

Where error: [object Object] is exactly what I expected

However, if I test it with this block of code:

Test B

const logger = require('winston');
try {
  throw(new Error('This causes error: undefined'));
} catch (err) {
  logger.error(err);
}

Where new Error() does contain a message value, I get this output:

Output B

** Info Object: **
{ level: '\u001b[31merror\u001b[39m',
  [Symbol(level)]: 'error',
  [Symbol(message)]: '{"level":"error"}' }
** Winston Output: **
error: undefined

As you can see I get the same error: undefined that @sandrocsimas gets. I expected to get error: [object Object]

Note, if I try this block of code:

Test C

const logger = require('winston');
try {
  throw(new Error('This should work'));
} catch (err) {
  logger.log({level: 'error', message: err});
}

Where I use logger.log instead of logger.error I get the same output as Output A above

@indexzero, I tried to follow your workaround, but it’s not working. Do you know why?

Formatter:

const level = settings.debug ? 'debug' : 'info';
const printFormat = winston.format.printf(info => `${info.timestamp} - ${info.level}: ${info.message}`);
const enumerateErrorFormat = winston.format(info => {
  if (info.message instanceof Error) {
    info.message = Object.assign({
      message: info.message.message,
      stack: info.message.stack,
    }, info.message);
  }
  if (info instanceof Error) {
    return Object.assign({
      message: info.message,
      stack: info.stack,
    }, info);
  }
  return info;
});

const consoleLogger = winston.createLogger({
  level,
  format: winston.format.timestamp(),
  transports: [
    new winston.transports.Console({
      format: winston.format.combine(
        winston.format.colorize(),
        enumerateErrorFormat(),
        printFormat,
      ),
    }),
  ],
});

Code:

try {
 // Some code throwing error
} catch (err) {
  logger.error(err);
}

Output:

2018-06-28T21:17:25.140Z - error: undefined

Info object:

{ level: '\u001b[31merror\u001b[39m', timestamp: '2018-06-28T21:17:25.140Z', [Symbol(level)]: 'error' }

Where is the message attribute in the error log?

This is still an issue? I’m still having problems with this:

const { createLogger, format, transports } = require('winston')

const { combine } = format

const errorFormatter = format((info) => {
  console.log(info)
  return info
})


const consoleTransport = new transports.Console({
  format: combine(errorFormatter()),
})

const logger = createLogger({
  transports: [
    consoleTransport,
  ],
})

try {
  throw new Error('Error message')
} catch(err) {
  logger.error(err) // info doesnt have the error object
  logger.error('', err) // info have the error object
}

@dandv

logger.error('Caught error:', e);

This doesn’t work because, unlike console.log(), the winston’s logger.<level>(message) takes only one parameter called message. That message parameter is either an object or a string (someone correct me if I’m wrong but that’s my understanding).

Note that you can also use logger.log({level: <level>, message: <message>}). To learn more about these two functions I would recomend reading this part of the docs: Winston Docs on Log Levels. Be sure to read through Using Logging Levels

logger.error(`Caught error: ${e}`);

I can not definitively say why this does not output the stack, but I do know this is not a problem with winston. If you try console.log(`Caught error: ${e}`) it also does not include the stack. I haven’t worked with template literals much so either template literals doesn’t work well with objects, or javascript’s console.log recognizes the object as an error object and thus only outputs the the message property. That’s my best guess.

logger.error(`Caught error: ${JSON.stringify(e)}`)

This one gets to the heart of what this bug thread is about. First you must understand some technical details about javascript. Note that if you try console.log(`Caught error: ${JSON.stringify(e)}`) you also get that same output Caught error: {}. As @indexzero explained:

message and stack properties on Error are non-enumerable which causes JSON.stringify to output something that one does not expect.

Basically, because message and stack properties are non-enumerable, JSON.stringify skips over those properties which is how you end up with an empty object {}. To understand enumerability better I recommend reading this Enumerability and ownership of properties.

Luckily, because of the way winston 3.0 was designed (props to the winston team) we have a workaround for this that @indexzero gave. I’ll help explain it. First you create this function:

const enumerateErrorFormat = format(info => {
  if (info.message instanceof Error) {
    info.message = Object.assign({
      message: info.message.message,
      stack: info.message.stack
    }, info.message);
  }

  if (info instanceof Error) {
    return Object.assign({
      message: info.message,
      stack: info.stack
    }, info);
  }

  return info;
});

From the docs Streams, objectMode, and info objects the info object has two properties, info.level, and info.message. That info.message property IS the error object if that is all you passed in. So we create a new object where message.stack and message.message (Think of it as Error.stack and Error.message) are now enumerable, and we include what ever other properties that may also be attached to that error object.

Next you’ll create this logger which uses the enumerateErrorFormat() function above:

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

This will take whatever message you pass in and check if it is an error object. If it is then it will fix the enumeration problem. Then it passes message to format.json which will stringify any object (error or not). If it’s not an object then it’s a string and format.json effectivley does nothing, and you’re home free!

Still, it would be nice if we didn’t have to create that enumerateErrorFormat since error objects are commonly logged. As I understand it the winston team is working on a fix that will be released in a later version.

Some final notes. This only works if you use logger.log({level: <level>, message: <message>}) where message is the error object. Example:

try {
  throw(new Error('This should work'));
} catch (err) {
  logger.log({level: 'error', message: err});
}

There is another bug in winston where this code does not work, as I explained in my other post above:

try {
  throw(new Error('This will not work'));
} catch (err) {
  logger.error(err);
}

For some reason the info.message property is undefined when we use logger.error(err). Hopefully @indexzero can figure this one out.

Very good explanation, I just want to add that with logger.error(Caught error: ${e}); you lose the stack because of the way that string literal works in javascript, `${e}` is exactly the same as e.toString(), so printing only the error message is the expected behavior.

format.errors is not a function … well that’s a surprise.

I am on the latest winston (3.2.1) and am still getting undefined when passing an error to logger.error

@ezze had a great solution but the stack trace is forced onto a new line. here is a slightly modified version that puts it in one line (so its caught by simple grep of log files)

logger.error = item => {
  const message = item instanceof Error
    ? item.stack.replace('\n', '').replace('    ', ' - trace: ')
    : item;
  logger.log({ level: 'error', message });
};

with output <Error message> - trace: <stack trace>

if there is an easier way to do this with the latest winston please let me know @indexzero. i am new to the library and was following the docs

This might be caused by wintson-transport, see https://github.com/winstonjs/winston-transport/issues/31 for the issue and https://github.com/winstonjs/winston-transport/pull/34 for a PR.

I created https://github.com/winstonjs/winston/pull/1527

This covers all options. However some tests fail so I have closed it for now. The failures are expected given the fix, but I don’t believe I am in a position to make the call to amend/delete the tests.

Failing build is here https://travis-ci.org/winstonjs/winston/jobs/453012141 and its obvious why the tests now fail when you read the test code: https://github.com/winstonjs/winston/blob/c42ab7fdc51b88db180a7dd90c52ce04ddd4e054/test/logger.test.js#L668

Thoughts?

FYI this is where I’ve gotten to after playing with this a bit:

import winston from 'winston';
const format = winston.format;

const printNice = format.printf(info => {
	const {level, message} = info;
	return `Logging Level: ${level} - Logging Message: ${message}`;
});

const enumerateErrorFormat = format(info => {
	if (info.message instanceof Error) {
		info.message = Object.assign({
			message: `${info.message.message}\n============\n${info.message.stack}`
		}, info.message);
	}

	if (info instanceof Error) {
		return Object.assign({
			message: `${info.message}\n============\n${info.stack}`
		}, info);
	}

	return info;
});

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

export default logger;

Upon further investigation it seems that the logger.error problem I explained above is only a problem when using the default logger. @DABH, I tried out your code and it does work for me, but when I switch it to the default logger it does not work:

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

const enumerateErrorFormat = format(info => {
  if (info.message instanceof Error) {
    info.message = Object.assign({
      message: info.message.message,
      stack: info.message.stack
    }, info.message);
  }

  if (info instanceof Error) {
    return Object.assign({
      message: info.message,
      stack: info.stack
    }, info);
  }

  return info;
});

winston.configure({
  transports: [
    new winston.transports.Console({
      level: 'debug',
      format: format.combine(
        enumerateErrorFormat(),
        format.json()
      ),
    })
  ]
});

winston.error(new Error('whatever'));

Second, I agree that enumerateErrorFormat should be added to the json format; and you’re probably right about meta as well.

Finally, I’d like to note the code example given by @DABH causes the stack to not “print pretty” if you will; at least on my machine running macOS High Sierra. This is what it looks like for me:

{"message":"whatever","stack":"Error: whatever\n    at Object.<anonymous> (/Users/samuelmaddox/Desktop/winston-test/index.js:33:14)\n    at Module._compile (internal/modules/cjs/loader.js:689:30)\n    at Object.Module._extensions..js (internal/modules/cjs/loader.js:700:10)\n    at Module.load (internal/modules/cjs/loader.js:599:32)\n    at tryModuleLoad (internal/modules/cjs/loader.js:538:12)\n    at Function.Module._load (internal/modules/cjs/loader.js:530:3)\n    at Function.Module.runMain (internal/modules/cjs/loader.js:742:12)\n    at startup (internal/bootstrap/node.js:266:19)\n    at bootstrapNodeJSCore (internal/bootstrap/node.js:596:3)","level":"error"}

As you can see, when outputting the error with a to JSON function the newline characters \n do not create actual new lines. This is expected behavior when taking an object and converting it to JSON, but is probably not the behavior we’d actually want from a logger, at least when logging to console.

Thank you for looking more into this @DABH