sematext / winston-logsene

Winston Transport for Logsene
http://sematext.com/logsene
Apache License 2.0
13 stars 6 forks source link

Can't log exception instances #7

Closed johnpeb closed 8 years ago

johnpeb commented 8 years ago

Using the winston console logger one can do log.error(new Error()) and the exception including stack will be printed to the console. However the same in winston-logsene results in an empty message and the error is lost.

johnpeb commented 8 years ago

Also, all exceptions in the meta are silently ignored.

megastef commented 8 years ago

Confirmed, this is strange normally winston framework passes the message as second argument (see below argument 1:'') to the log function. A debug output shows the error is passed as 3rd agument (meta) of the log function:

{ '0': 'error',
  '1': '',
  '2': 
   Error: ups
       at Context.<anonymous> (/Users/stefan/sematext/winston-logsene/test/test.js:18:22)
       at callFnAsync (/usr/local/lib/node_modules/mocha/lib/runnable.js:309:8)
       at Test.Runnable.run (/usr/local/lib/node_modules/mocha/lib/runnable.js:264:7)
       at Runner.runTest (/usr/local/lib/node_modules/mocha/lib/runner.js:419:10)
       at /usr/local/lib/node_modules/mocha/lib/runner.js:526:12
       at next (/usr/local/lib/node_modules/mocha/lib/runner.js:340:14)
       at /usr/local/lib/node_modules/mocha/lib/runner.js:350:7
       at next (/usr/local/lib/node_modules/mocha/lib/runner.js:283:14)
       at Immediate._onImmediate (/usr/local/lib/node_modules/mocha/lib/runner.js:318:5)
       at tryOnImmediate (timers.js:543:15)
       at processImmediate [as _immediateCallback] (timers.js:523:5),
  '3': [Function] }```
megastef commented 8 years ago

Fixed in + winston-logsene@1.1.3 by https://github.com/sematext/winston-logsene/commit/a140f6be4340054abb1cfee9790a129441bd5a84

johnpeb commented 8 years ago

@megastef what about log.error("Operation failed", err) and log.error("Operation failed", {reason: err}).

Also your fix will result in the message being duplicated in many cases. err.stack || err.toString() is a good compromise but rarely there will be an error that doesn't have the message in the stack so the perfect fix is looking for substring of the message in the stack and printing the message if necessary. That said I haven't looked at the source of other transports and maybe they have better fixes.

megastef commented 8 years ago

Thanks for reporting, I will have a look into it.

BTW. I think the correct API call would be logger.error(error.message, error) // msg string + meta data object

megastef commented 8 years ago

I think the fix is good. If no message is given, and meta data is an Error object it generates a message including stack trace. If the user specifies an error message, this conversion is not done. The meta data will log the error as json object to logsene, and right this would duplicates error.message. But if the user don't want a duplicate, he could simply use logger.error(error), right? I can imagine the typical use case is to customize error messages like

logger.error('Error in myFunctiion() doing something: ' + error.message, error)
johnpeb commented 8 years ago

I'm not seeing the error in logsene if I do logger.error("any text", error)

Do I need to turn on the json option? By the way the JSON format is not user friendly. It would be nice if there were a human readable format for errors too.

megastef commented 8 years ago

Interesting, it looks JSON.stringify() fails to convert an error into a JSON string (needed to log to Elasticsearch/Logsene) see this in node console:

> var err = new Error('ups')
> JSON.stringify(err)
'{}'
> err.toString()
'Error: ups'

A fix on the way ...

megastef commented 8 years ago

Fix in https://github.com/sematext/winston-logsene/commit/e1afde2721be170f0bfd6d5dc934ed567a91fd28 , winston-logsene@1.1.4

logger.error("any text", error) See screenshot: bildschirmfoto 2016-06-25 um 18 46 27

In addtion, when no message is set, only the error object is passed to winston-logsene. The message field content is then meta.stack || meta.message. It avoids the mentioned https://github.com/sematext/winston-logsene/issues/7#issuecomment-228547691 duplication of the error message part (included in the stack property).

But having the error object as a nested property in metadata would not work, becaue JSON stringify would render the Error as empty object {} - I think this is an issue to open in node/nodejs repository . Example logger.error("any text", {meta_error: error}) // will not work because of JSON.stringify()

johnpeb commented 8 years ago

Thanks! I very much appreciate it.

I wonder if the JSON.stringify replacer function (optional 2nd param) could be used to format the Error instance. That said, I noticed the winston console transport doesn't support that either.

megastef commented 8 years ago

@johnpep thank you very much for the JSON.stringify hint - added toJSON to Error class. https://github.com/sematext/winston-logsene/commit/1cb56b3f6e70307d0e9c006001fc74632affbc89

So Errors, which are nested into the meta data object will be rendered to JSON.
Please try winston-logsene@1.1.5