Friday, August 29, 2014

Valuable Logging

I was attempting to debug through an issue and ran into this line in the logs:

2014-08-29T15:14:53.648Z - info: Getting install data... 
2014-08-29T15:14:54.015Z - info: Query took 2msec 

Not having gained any additional insight or value from the message I decided to track it down to determine if it was part of my bug. It was not. Not even close.  But who would have known, except for the author of log entry, what "install data" or "query" it was referring to.

In order to be valuable, log entries should probably have a little more info.  I propose the following:

date:time - log level: file/location [function] MSG: reasonable description

eg.
2014-08-29T15:15:36.398Z - error: util/workday.js [getLinkedPerson] ERROR: TypeError: Cannot read property '68582' of undefined

If you have an error (either from a try/catch or from a promise), I would highly recommend writing out the stack like this:


try { 
 ... 

catch(err) { 
  log.error(file + ' [' + fn + '] ERROR: ' + err.stack);
}