MongoDB Sender loses information in provided context

[arggh]

MongoDB sender seems to be losing information on the logged error on the way to the database.

How to reproduce

// /server/index.js
try {
   throw new Error('Oops!');
} catch (e) {
   logger.error('Oops!', { error: e });
}

If we have enabled a console logger, the output would be:

W20170108-15:30:08.526(2)? (STDERR) Error Error happened { error: [Error: Oops!],
W20170108-15:30:08.527(2)? (STDERR)   meteor: 
W20170108-15:30:08.527(2)? (STDERR)    { platform: 'server',
.
.
.

but in the MongoDB, the created document for this error would look like this:

{
    "_id" : "zfrwTgNoFnNtBZ6tr",
    "level" : 3,
    "message" : "Error happened",
    "context" : {
        "error" : {}, <--- missing!
        "meteor" : {

[fgm]

This looks like the issue fixed in the yet-unmerged #23 issue. Can you check if you still have the problem with the version in that branch ? Note that configuration/initialization changes to address this.

[fgm]

Actually, this is a case of not reading the doc myself before answering... the way to capture errors is like this:

try {
   throw new Error('Oops!');
} catch (e) {
   logger.tk.report(e);
}

Example:

function space() {
  function outer(o) {
    function inner(i) {
      console.log('In inner, i = ', i);
      try {
        throw new Error('Oops!');
      } catch (e) {
        // logger.error('Oops!', { error: e });
        logger.tk.report(e);
      }
    }

    console.log('Calling inner, o = ', o);
    inner('foo');
  }
  outer('bar');
}
space();

Document in MongoDB:

{  
   "_id":"vHsEzhKxhWR9AsKdi",
   "level":3,
   "message":"Oops!",
   "context":{  
      "timestamp":{  
         "log":1.484307090253E12,
         "store":1.484307090262E12
      },
      "meteor":{  
         "platform":"client",
         "user":null
      },
      "serialized":"{\"mode\":\"callers\",\"name\":\"Error\",\"message\":\"Oops!\",\"stack\":[{\"url\":null,\"func\":\"outer\",\"args\":[],\"line\":null,\"column\":null},{\"url\":null,\"func\":\"space\",\"args\":[],\"line\":null,\"column\":null}],\"incomplete\":true,\"routing\":{\"location\":{\"hash\":\"\",\"search\":\"\",\"pathname\":\"/\",\"port\":\"3000\",\"hostname\":\"somewhere\",\"host\":\"somewhere:3000\",\"protocol\":\"http:\",\"origin\":\"http://somewhere:3000\",\"href\":\"http://somewhere:3000/\",\"ancestorOrigins\":{}}},\"requestHeaders\":{\"x-forwarded-proto\":\"http\",\"x-forwarded-port\":\"3000\",\"x-forwarded-for\":\"127.0.0.1\",\"cookie\":\"<removed>\",\"accept-language\":\"fr,fr-FR;q=0.8,fr-CA;q=0.6,en-US;q=0.4,en;q=0.2,en-GB;q=0.2,de;q=0.2\",\"accept-encoding\":\"gzip, deflate\",\"referer\":\"http://somewhere:3000/\",\"accept\":\"*/*\",\"content-type\":\"application/json\",\"user-agent\":\"Mozilla/5.0 (X11; Linux x86_64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/54.0.2840.59 Safari/537.36\",\"origin\":\"http://somewhere:3000\",\"cache-control\":\"no-cache\",\"pragma\":\"no-cache\",\"content-length\":\"588\",\"connection\":\"keep-alive\",\"host\":\"somewhere:3000\"}}"
   }
}

When unserializing doc.context.serialized with JSON.parse(), the complete Error becomes available:

{  
   "mode":"callers",
   "name":"Error",
   "message":"Oops!",
   "stack":[  
      {  
         "url":null,
         "func":"outer",
         "args":[  

         ],
         "line":null,
         "column":null
      },
      {  
         "url":null,
         "func":"space",
         "args":[  

         ],
         "line":null,
         "column":null
      }
   ],
   "incomplete":true,
   "routing":{  
      "location":{  
         "hash":"",
         "search":"",
         "pathname":"/",
         "port":"3000",
         "hostname":"somewhere",
         "host":"somewhere:3000",
         "protocol":"http:",
         "origin":"http://somewhere:3000",
         "href":"http://somewhere:3000/",
         "ancestorOrigins":{  

         }
      }
   },
   "requestHeaders":{  
      "x-forwarded-proto":"http",
      "x-forwarded-port":"3000",
      "x-forwarded-for":"127.0.0.1",
      "cookie":"<removed>",
      "accept-language":"fr,fr-FR;q=0.8,fr-CA;q=0.6,en-US;q=0.4,en;q=0.2,en-GB;q=0.2,de;q=0.2",
      "accept-encoding":"gzip, deflate",
      "referer":"http://somewhere:3000/",
      "accept":"*/*",
      "content-type":"application/json",
      "user-agent":"Mozilla/5.0 (X11; Linux x86_64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/54.0.2840.59 Safari/537.36",
      "origin":"http://somewhere:3000",
      "cache-control":"no-cache",
      "pragma":"no-cache",
      "content-length":"588",
      "connection":"keep-alive",
      "host":"somewhere:3000"
   }
}

(this is the new branch 23 format, with a "serialized" key for raw data, to avoid breakage with mongodb not being able to store documents containing dots in keys, which can happen (and actually happened in our case).

This is needed to ensure TraceKit can correctly handle the various ways different browsers obtain call stack information. See https://github.com/csnover/TraceKit for details.

I don't like it much, but don't really see a better way to do it: if we chose to support the syntax you used, I think the log() method would have to notice it is invoked within an exception handler (no idea how ?) and perform the TraceKit call itself.

Do you have any suggestion how to do it more elegantly ? Otherwise, I'll mark this as a doc issue needing to document how to log errors.