Monday, January 9, 2017

NodeJS 7: How to Show the Correct Stack Trace in Async Functions

Leave a Comment

When I have an error in an async function, like in async or bluebird. I don't have the correct line number, which makes it hard for me to find the error.

unknownFunction("A")#show me the correct line number in the trace async.timesSeries 100,   (index, next) ->      unknownFunction("B") #show me only the line number where I catch the error  process.on 'uncaughtException', (err)->   console.log err.stack   console.trace err    throw err 

Question: How can I get the correct line number instead of the line number where the error is catched?

PS: I found and tried this so far: https://github.com/groundwater/node-stackup But it gives me a lot of unrelated line numbers.

EDIT:

This is how I init mongoose with bluebird:

Promise = require("bluebird") Promise.config({   longStackTraces: true   warnings: {     wForgottenReturn: false   } }) mongoose = require('mongoose') mongoose.Promise = Promise mongoose.set('error', true) 

Example correct:

enter image description here

  ReferenceError: unknownFunction is not defined    - patient.update.js:267  

Example incorrect:

enter image description here

somepath/.tmp/serve/server.js:294       throw err;       ^  ReferenceError: unknownFunction2 is not defined 

The error is in patient.update.js line nr 268

Longjohn

With longjohn

somepath/node_modules/longjohn/dist/longjohn.js:192         throw e;         ^  ReferenceError: unknownFunction2 is not defined 

Stack up

This is what I mean with node-stack-up unrelated lines (same test with unknownFunction2):

    /somepath/myApp/.tmp/serve/server.js:296       throw err;       ^  ReferenceError: unknownFunction2 is not defined      ---- async ----    - glue.js:150 asyncWrap     [myApp]/[async-listener]/glue.js:150:28    - glue.js:401 wrapCallback     [myApp]/[async-listener]/glue.js:401:35    - index.js:16 process.nextTick     [myApp]/[async-listener]/index.js:16:26    - index.js:126 Kareem.execPost     [myApp]/[kareem]/index.js:126:20    - index.js:251      [myApp]/[kareem]/index.js:251:15    - query.js:1616      [myApp]/[mongoose]/lib/query.js:1616:5    - document.js:317 model.Document.init     [myApp]/[mongoose]/lib/document.js:317:5    - query.js:1609 completeOne     [myApp]/[mongoose]/lib/query.js:1609:10    - query.js:1271 Immediate.<anonymous>     [myApp]/[mongoose]/lib/query.js:1271:13    - utils.js:137 Immediate.<anonymous>     [myApp]/[mquery]/lib/utils.js:137:16    - timers.js:649 runCallback     timers.js:649:20    - timers.js:622 tryOnImmediate     timers.js:622:5    - timers.js:594 processImmediate [as _immediateCallback]     timers.js:594:5       ---- async ----    - glue.js:150 asyncWrap     [myApp]/[async-listener]/glue.js:150:28    - glue.js:401 wrapCallback     [myApp]/[async-listener]/glue.js:401:35    - index.js:16 process.nextTick     [myApp]/[async-listener]/index.js:16:26    - pool.js:454 handleOperationCallback     [myApp]/[mongoose]/[mongodb-core]/lib/connection/pool.js:454:24    - pool.js:490      [myApp]/[mongoose]/[mongodb-core]/lib/connection/pool.js:490:9    - pool.js:429 authenticateStragglers     [myApp]/[mongoose]/[mongodb-core]/lib/connection/pool.js:429:16    - pool.js:463 Connection.messageHandler     [myApp]/[mongoose]/[mongodb-core]/lib/connection/pool.js:463:5    - connection.js:309 Socket.<anonymous>     [myApp]/[mongoose]/[mongodb-core]/lib/connection/connection.js:309:     22    - events.js:96 emitOne     events.js:96:13    - events.js:188 Socket.emit     events.js:188:7    - _stream_readable.js:176 readableAddChunk     _stream_readable.js:176:18    - _stream_readable.js:134 Socket.Readable.push     _stream_readable.js:134:10    - net.js:551 TCP.onread     net.js:551:20    - glue.js:188 TCP.onread     [myApp]/[async-listener]/glue.js:188:31       ---- async ----    - glue.js:150 asyncWrap     [myApp]/[async-listener]/glue.js:150:28    - glue.js:401 wrapCallback     [myApp]/[async-listener]/glue.js:401:35    - index.js:88 Socket.connect     [myApp]/[async-listener]/index.js:88:29    - net.js:74 Object.exports.connect.exports.createConnection     net.js:74:35    - connection.js:389 Connection.connect     [myApp]/[mongoose]/[mongodb-core]/lib/connection/connection.js:389:     11    - pool.js:1059 _createConnection     [myApp]/[mongoose]/[mongodb-core]/lib/connection/pool.js:1059:14    - pool.js:1151      [myApp]/[mongoose]/[mongodb-core]/lib/connection/pool.js:1151:13    - pool.js:1082 waitForAuth     [myApp]/[mongoose]/[mongodb-core]/lib/connection/pool.js:1082:39    - pool.js:1090      [myApp]/[mongoose]/[mongodb-core]/lib/connection/pool.js:1090:5    - pool.js:957      [myApp]/[mongoose]/[mongodb-core]/lib/connection/pool.js:957:21    - glue.js:188      [myApp]/[async-listener]/glue.js:188:31    - next_tick.js:67 _combinedTickCallback     internal/process/next_tick.js:67:7    - next_tick.js:98 process._tickCallback     internal/process/next_tick.js:98:9       ---- async ----    - glue.js:150 asyncWrap     [myApp]/[async-listener]/glue.js:150:28    - glue.js:401 wrapCallback     [myApp]/[async-listener]/glue.js:401:35    - index.js:16 process.nextTick     [myApp]/[async-listener]/index.js:16:26    - pool.js:956 Pool.write     [myApp]/[mongoose]/[mongodb-core]/lib/connection/pool.js:956:13    - cursor.js:288 CommandCursor.Cursor._find     [myApp]/[mongoose]/[mongodb-core]/lib/cursor.js:288:22    - cursor.js:588 nextFunction     [myApp]/[mongoose]/[mongodb-core]/lib/cursor.js:588:10    - cursor.js:696 CommandCursor.Cursor.next [as _next]     [myApp]/[mongoose]/[mongodb-core]/lib/cursor.js:696:3    - cursor.js:849 fetchDocs     [myApp]/[mongoose]/[mongodb]/lib/cursor.js:849:10    - cursor.js:876 toArray     [myApp]/[mongoose]/[mongodb]/lib/cursor.js:876:3    - cursor.js:829 CommandCursor.Cursor.toArray     [myApp]/[mongoose]/[mongodb]/lib/cursor.js:829:44    - db.js:1662 indexInformation     [myApp]/[mongoose]/[mongodb]/lib/db.js:1662:39    - db.js:1626 Db.indexInformation     [myApp]/[mongoose]/[mongodb]/lib/db.js:1626:44    - db.js:1129 ensureIndex     [myApp]/[mongoose]/[mongodb]/lib/db.js:1129:8    - db.js:1105 Db.ensureIndex     [myApp]/[mongoose]/[mongodb]/lib/db.js:1105:44    - collection.js:1891 ensureIndex     [myApp]/[mongoose]/[mongodb]/lib/collection.js:1891:13    - collection.js:1879 Collection.ensureIndex     [myApp]/[mongoose]/[mongodb]/lib/collection.js:1879:44    - collection.js:126 NativeCollection.(anonymous function) [as ensureIndex]     [myApp]/[mongoose]/lib/drivers/node-mongodb-native/collection.js:12     6:28    - model.js:1019 create     [myApp]/[mongoose]/lib/model.js:1019:22    - model.js:1033 Immediate.<anonymous>     [myApp]/[mongoose]/lib/model.js:1033:7    - timers.js:649 runCallback     timers.js:649:20    - timers.js:622 tryOnImmediate     timers.js:622:5    - timers.js:594 processImmediate [as _immediateCallback]     timers.js:594:5       ---- async ----    - glue.js:150 asyncWrap     [myApp]/[async-listener]/glue.js:150:28    - glue.js:401 wrapCallback     [myApp]/[async-listener]/glue.js:401:35    - index.js:16 process.nextTick     [myApp]/[async-listener]/index.js:16:26    - _stream_writable.js:377 onwrite     _stream_writable.js:377:15    - _stream_writable.js:90 WritableState.onwrite     _stream_writable.js:90:5    - net.js:724 Socket._writeGeneric     net.js:724:5    - net.js:734 Socket._write     net.js:734:8    - _stream_writable.js:334 doWrite     _stream_writable.js:334:12    - _stream_writable.js:320 writeOrBuffer     _stream_writable.js:320:5    - _stream_writable.js:247 Socket.Writable.write     _stream_writable.js:247:11    - net.js:661 Socket.write     net.js:661:40    - connection.js:500 Connection.write     [myApp]/[mongoose]/[mongodb-core]/lib/connection/connection.js:500:     53    - pool.js:1137      [myApp]/[mongoose]/[mongodb-core]/lib/connection/pool.js:1137:26    - pool.js:1082 waitForAuth     [myApp]/[mongoose]/[mongodb-core]/lib/connection/pool.js:1082:39    - pool.js:1090      [myApp]/[mongoose]/[mongodb-core]/lib/connection/pool.js:1090:5    - pool.js:957      [myApp]/[mongoose]/[mongodb-core]/lib/connection/pool.js:957:21    - glue.js:188      [myApp]/[async-listener]/glue.js:188:31    - next_tick.js:67 _combinedTickCallback     internal/process/next_tick.js:67:7    - next_tick.js:98 process._tickCallback     internal/process/next_tick.js:98:9       ---- async ----    - glue.js:150 asyncWrap     [myApp]/[async-listener]/glue.js:150:28    - glue.js:401 wrapCallback     [myApp]/[async-listener]/glue.js:401:35    - index.js:16 process.nextTick     [myApp]/[async-listener]/index.js:16:26    - pool.js:956 Pool.write     [myApp]/[mongoose]/[mongodb-core]/lib/connection/pool.js:956:13    - cursor.js:288 Cursor._find     [myApp]/[mongoose]/[mongodb-core]/lib/cursor.js:288:22    - cursor.js:588 nextFunction     [myApp]/[mongoose]/[mongodb-core]/lib/cursor.js:588:10    - cursor.js:696 Cursor.next [as _next]     [myApp]/[mongoose]/[mongodb-core]/lib/cursor.js:696:3    - cursor.js:672 nextObject     [myApp]/[mongoose]/[mongodb]/lib/cursor.js:672:8    - cursor.js:262 Cursor.next     [myApp]/[mongoose]/[mongodb]/lib/cursor.js:262:12    - collection.js:1401 findOne     [myApp]/[mongoose]/[mongodb]/lib/collection.js:1401:10    - collection.js:1387 Collection.findOne     [myApp]/[mongoose]/[mongodb]/lib/collection.js:1387:44    - collection.js:126 NativeCollection.(anonymous function) [as findOne]     [myApp]/[mongoose]/lib/drivers/node-mongodb-native/collection.js:12     6:28    - node.js:38 NodeCollection.findOne     [myApp]/[mquery]/lib/collection/node.js:38:19    - mquery.js:1787 model.Query.Query.findOne     [myApp]/[mquery]/lib/mquery.js:1787:20    - query.js:1260 model.Query.Query._findOne     [myApp]/[mongoose]/lib/query.js:1260:22    - index.js:239      [myApp]/[kareem]/index.js:239:8    - index.js:18      [myApp]/[kareem]/index.js:18:7    - glue.js:188      [myApp]/[async-listener]/glue.js:188:31    - next_tick.js:67 _combinedTickCallback     internal/process/next_tick.js:67:7    - next_tick.js:98 process._tickCallback     internal/process/next_tick.js:98:9       ---- async ----    - glue.js:150 asyncWrap     [myApp]/[async-listener]/glue.js:150:28    - glue.js:401 wrapCallback     [myApp]/[async-listener]/glue.js:401:35    - index.js:16 process.nextTick     [myApp]/[async-listener]/index.js:16:26    - index.js:17 Kareem.execPre 

3 Answers

Answers 1

The node-stackup, longjohn, and Bluebird's long stack traces are the best solutions available. I'm not sure what you mean by "it gives me a lot of unrelated line numbers." It's giving you a stack trace, so unless you've written all the code and have zero dependencies then you're bound to see function calls to lines you didn't write regardless of whether the operation is asynchronous or not.

Essentially what these libraries do is just stitch detached stack traces together. Normally JavaScript stack traces won't include anything involving an asynchronous operation, only the most recent synchronous function calls. These libraries monkey patch most methods that can introduce asynchronous behavior (process.nextTick, setTimeout, EventEmitter, etc.). They add code which creates a new stack trace at each of these call sites and stores all of these until an error occurs. It will join all of the stored stack traces together so you can actually walk back through all of the asynchronous operations until you get to the original call site.

Answers 2

You can try the following tool decofun debug tool to deanomise the anonymous functions.

Complete details mentioned in the following answer written by me in this

thread

The documentation is as mentioned here

Answers 3

For any uncaughtException the server will stop in order to make the server keep on running even when there is an uncaught exception what i have done is created a separate collection for storing error, save error once an uncaught exception occurs and returns.

Collection

var ErrorSchema = new mongoose.Schema({   err_Message:{type:String},   err_Stack:{type:String},   date:{type:Date} }); 

Controller

process.on('uncaughtException', function (err) {     console.log(err);     console.error((new Date).toUTCString() + ' uncaughtException:', err.message);     console.error(err.stack);      var newError = new Error;     newError.err_Message = err.message;     newError.err_Stack = err.stack;     newError.date = moment();     newError.save(function(saveErr,errData){         if(!saveErr)             console.log('New Error is saved');         else             console.log('Error in saving error');     });     //process.exit(1) }); 

The above methods stores the uncaught exception in the Error collection and the process/server does not stops.

Reference: Already answered in Nodejs debug errors in production

Hope this helps.

If You Enjoyed This, Take 5 Seconds To Share It

0 comments:

Post a Comment