Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

[3.0.0] Error object is not parsed or printed #1338

Closed
chriswiggins opened this issue May 29, 2018 · 77 comments
Closed

[3.0.0] Error object is not parsed or printed #1338

chriswiggins opened this issue May 29, 2018 · 77 comments

Comments

@chriswiggins
Copy link

chriswiggins commented May 29, 2018

Please tell us about your environment:

  • winston version?
    • [-] winston@3.0.0-rc5
  • node -v outputs: v8.11.1
  • Operating System? (Windows, macOS, or Linux) macOS
  • Language? (all | TypeScript X.X | ES6/7 | ES5 | Dart) All

What is the problem?

Logging a node Error object results in an empty message:

Example:

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

const logger = createLogger({
  transports: [
    new transports.Console()
  ]
});

let err = new Error('this is a test');
logger.log({level: 'error', message: err});

Resulting output:

% node test.js
{"level":"error","message":{}}

Also:

logger.error(new Error('hello'))

Results in:

{"level":"error"}

What do you expect to happen instead?

I Expect the message key to have at least the error message included in it. If I try a custom formatter, info also doesn't have the error object in it so it must be stripped out somewhere?

Other information

Let me know how I can help - happy to flick a PR but I don't know my way around winston@3.0.0 enough yet to find it

@indexzero
Copy link
Member

indexzero commented May 30, 2018

We have some test coverage for this, but clearly we need more. What's going on under the covers:

  1. Your Error instance is passed along the objectMode stream pipe-chain
  2. The default format for Logger is json (see: json format code in logform)
  3. message and stack properties on Error are non-enumerable which causes JSON.stringify to output something that one does not expect.
console.log(JSON.stringify(new Error('lol nothing here')));
// '{}'

From a design perspective winston@3 introduced formats for exactly this kind of problem to increase performance. Speaking of performance, interestingly enough pino does something interesting here. Perhaps the solution is implementing something similar to asJson in the default json format.

@indexzero
Copy link
Member

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'));

@sandrocsimas
Copy link

sandrocsimas commented Jun 28, 2018

@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?

@christopher-mazaudou
Copy link

christopher-mazaudou commented Jun 29, 2018

@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

@SamuelMaddox
Copy link

SamuelMaddox commented Jun 29, 2018

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

@nvtuan305
Copy link

I have the same problem. I'm new in winston. I tried @indexzero solution but not working. Do you have any solution?

@SamuelMaddox
Copy link

SamuelMaddox commented Jul 7, 2018

@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.

@dandv
Copy link
Contributor

dandv commented Jul 8, 2018

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?

@SamuelMaddox
Copy link

SamuelMaddox commented Jul 8, 2018

@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.

@nvtuan305
Copy link

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

@inderpreet99
Copy link

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.

@DABH DABH changed the title [3.0.0-rc5] Error object is not parsed or printed [3.0.0] Error object is not parsed or printed Sep 3, 2018
@DABH
Copy link
Contributor

DABH commented Sep 3, 2018

Hey all, I'm looking into this. @indexzero : still think the best idea is to essentially add the enumerateErrorFormat functionality to the json formatter by default? Do we need to worry separately about if meta is an Error not just an object (I'm guessing people will complain if we don't also handle that case?)? Also, I'm using master, but seems like logger.error works for me with the solution by @indexzero / @SamuelMaddox17 above:

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'));

@SamuelMaddox
Copy link

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

@petrogad
Copy link

petrogad commented Sep 4, 2018

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;

@Asing1001
Copy link

The issue is caused by this bug : winstonjs/winston-transport#31

@barisusakli
Copy link

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.

@ddemydenko
Copy link

ddemydenko commented Oct 19, 2018

@SamuelMaddox17

logger.log({level: ____, message: err});

it works thx

@SamuelMaddox
Copy link

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.

@crowleym
Copy link

crowleym commented Nov 8, 2018

I created #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:

assume(info).instanceOf(Error);

Thoughts?

@giang12
Copy link

giang12 commented Nov 14, 2018

I think the problem is in this line
const info = ( msg && !(msg instanceof Error) && msg.message && msg) || {
message: msg
};
adding a check of instanceof Error seems to resolve the issue as @crowleym point out

@will093
Copy link

will093 commented May 27, 2020

@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?

@OBrown92
Copy link

@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.

Mizumaki pushed a commit to Mizumaki/winston that referenced this issue Jun 11, 2020
…s). Fixes winstonjs#1338, winstonjs#1486 (winstonjs#1562)

* [tiny dist] Whitespace. package-lock.json

* [test] Add E2E integration tests with logform `errors` format.

* [test] 5:00pm. Press return.

* [fix test] More E2E errors coverage.

* [test] Test custom error properties.

* [tiny doc] Make note of duplicate coverage in `logger`. Update minor formatting.

* [test] All E2E tests work except for one...

* [fix test doc] All 14 variations of handling `new Error()` now work as most folks expect.

* [tiny] Fix up file header.

* [dist] Bump to `logform@2.1.0`

* [fix tiny] Whitespace.

* s/req_id/requestId/

* [fix test] Address PR comments. Add test coverage for defaultMeta over .child(additionalMeta)
@TeamDman
Copy link

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);

image

@wcarss
Copy link

wcarss commented Sep 23, 2020

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.

@rathernetwork
Copy link

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 is trace() definition?

@rathernetwork
Copy link

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?

any answer on this?

@hpl002
Copy link

hpl002 commented May 19, 2021

quick and dirty, but lacking proper formatting on errors. Still better than nothing..

const winston = require('winston');

const logger = winston.createLogger({
  level: 'debug',
  transports: [
    new winston.transports.File({ filename: 'error.log', level: 'error' }),
    new winston.transports.File({ filename: 'combined.log' }),
    new winston.transports.Console({ format: winston.format.json() })
  ],
});

logger.format = winston.format.combine(
  winston.format.errors({ stack: true }),
)

@alolis
Copy link

alolis commented May 19, 2021

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.

bmaupin added a commit to bmaupin/graylog-syslog-examples that referenced this issue Sep 28, 2021
format.errors({ stack: true }) doesn't seem to work when using a different formatter per transport (winstonjs/winston#1338 (comment))
@b4ti1c
Copy link

b4ti1c commented Jan 30, 2022

To leave my bits I have put together the following winston configuration to accommodate both errors and multiple parameters in the logs.

const winston = require('winston');
const util = require('util');


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 logger = winston.createLogger({
    level: 'silly',
    format: winston.format.combine(
        enumerateErrorFormat(),
        {
            transform: (info) => {
                const args = [info.message, ...(info[Symbol.for('splat')] || [])];
                info.message = args;

                const msg = args.map(arg => {
                    if (typeof arg == 'object')
                        return util.inspect(arg, {compact: true, depth: Infinity});
                    return arg;
                }).join(' ');

                info[Symbol.for('message')] = `${info[Symbol.for('level')]}: ${msg}${info.stack ? ' ' + info.stack : ''}`;

                return info;
            }
        }
    )
});

logger.add(new winston.transports.Console())
logger.add(new winston.transports.File({filename: './logs.txt.'}));

logger.silly('hello silly', 1234, 'my condolence', {ahmet:1, meh:[{ahmet:1, meh:'alo'},{ahmet:1, meh:'alo'}]}, [{ahmet:1, meh:'alo'},{ahmet:1, meh:'alo'}]);
logger.debug('hello debug', () => console.log(1+2));
logger.info('hello info');
logger.warn('hello warn');
logger.error('hello error');
logger.error(new Error('error 1'), 123, new Error('error 2'));

@MatthiasGwiozda
Copy link

MatthiasGwiozda commented Apr 18, 2022

You can define a simple ConsoleLogger to show complete Error - objects.
It doesn't fix the weird behavior of the inbuilt winston - logger but it does exactly what console.log would do because we use it in the ConsoleLogger.

IMHO the amount of code to get the result is okay for the purpose.

const { createLogger } = require('winston');
const Transport = require('winston-transport');

/**
 * The simple "custom" console - logger,
 * which logs the complete Error - object.
 */
class ConsoleLogger extends Transport {
    constructor(opts) {
        super(opts);
    }

    log(info, callback) {
        console.log(info);
        callback();
    }
};

const logger = createLogger({
    transports: [
        // use the ConsoleLogger instead of the winston "cOnSoLEtRaNSpOrt"
        new ConsoleLogger()
    ]
});

let err = new Error('this is a test');
logger.log({ level: 'error', message: err });

@wbt
Copy link
Contributor

wbt commented Apr 28, 2022

It appears that the original issue this thread was supposed to be about was solved a while ago and it continues on in closed state because a second issue brought up still requires a workaround. This comment from a project founder may shed some light on why that is likely to remain the case for a while.

rrg92 added a commit to rrg92/wiki that referenced this issue Sep 16, 2022
This will enhance the logging of error messages in catch blocks (the javascript Error object).

Due to a problem on wiston, when logging an error object, the winston just prints the messages, and all important details (like error line, etc,) is hidden.
Details: winstonjs/winston#1338

For example, if I'm developing a module or something fails with an Error, this is what is printed in the wiki.js log:


2022-09-16T02:31:41.383Z [MASTER] info: =======================================
2022-09-16T02:31:41.385Z [MASTER] info: = Wiki.js 2.5.286 =====================
2022-09-16T02:31:41.385Z [MASTER] info: =======================================
2022-09-16T02:31:41.386Z [MASTER] info: Initializing...
2022-09-16T02:31:42.334Z [MASTER] info: Using database driver pg for postgres [ OK ]
2022-09-16T02:31:42.337Z [MASTER] info: Connecting to database...
2022-09-16T02:31:42.501Z [MASTER] info: Database Connection Successful [ OK ]
2022-09-16T02:31:43.507Z [MASTER] warn: Mail is not setup! Please set the configuration in the administration area!
2022-09-16T02:31:43.675Z [MASTER] info: Loading GraphQL Schema...
2022-09-16T02:31:45.155Z [MASTER] info: GraphQL Schema: [ OK ]
2022-09-16T02:31:45.437Z [MASTER] error: SOME_ERROR is not defined




After this fix, the error is printed with more info:


Loading configuration from T:\powerdocs\wikijs\config.yml... OK
2022-09-16T02:32:08.650Z [MASTER] info: =======================================
2022-09-16T02:32:08.652Z [MASTER] info: = Wiki.js 2.5.286 =====================
2022-09-16T02:32:08.653Z [MASTER] info: =======================================
2022-09-16T02:32:08.653Z [MASTER] info: Initializing...
2022-09-16T02:32:09.627Z [MASTER] info: Using database driver pg for postgres [ OK ]
2022-09-16T02:32:09.632Z [MASTER] info: Connecting to database...
2022-09-16T02:32:09.897Z [MASTER] info: Database Connection Successful [ OK ]
2022-09-16T02:32:10.932Z [MASTER] warn: Mail is not setup! Please set the configuration in the administration area!
2022-09-16T02:32:11.116Z [MASTER] info: Loading GraphQL Schema...
2022-09-16T02:32:12.949Z [MASTER] info: GraphQL Schema: [ OK ]
2022-09-16T02:32:13.276Z [MASTER] error: ReferenceError: SOME_ERROR is not defined
    at module.exports (T:\wikijs\server\master.js:172:3)
    at processTicksAndRejections (node:internal/process/task_queues:96:5)
    at async Object.bootMaster (T:\wikijs\server\core\kernel.js:60:9)
@mayeaux
Copy link

mayeaux commented Feb 21, 2023

Doesn't work

@teadrinker2015
Copy link

teadrinker2015 commented Mar 23, 2023

I searched for node logger in youtube and can only find this package. All I want is just log to file (may be a little prettify), otherwise I have to implement myself.
Could someone suggest me some user-friendly, or work out-of-box logging package?

@cyrilchapon
Copy link

See my comment here : winstonjs/logform#100

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

@chuckbakwi
Copy link

Long running issue given the above answers.

  1. is this FIXED in the latest release? If fixed, specify release please.
  2. if not fixed, then can someone summarize maybe the TOP TWO workaround solutions with some explanation of what they do and and what they do NOT support?
    There are other alternatives out there, but I invested my time into getting this to work and just need this last piece of the puzzle.

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Projects
No open projects
winston@3.2.0
  
Done
Development

No branches or pull requests