Logo Questions Linux Laravel Mysql Ubuntu Git Menu
 

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

When I have an error in mongoose promises with 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
like image 862
Andi Giga Avatar asked Dec 08 '16 14:12

Andi Giga


People also ask

What is async stack traces?

Asynchronous stack traces allow you to inspect function calls beyond the current event loop. This is particularly useful because you can examine the scope of previously executed frames that are no longer on the event loop. This feature is currently an experiment and needs to be enabled.

How to use promises in mongoose?

process = function ( r, callback ) { var promise = new mongoose. Promise; if(callback) promise. addBack(callback); Content. find( {route : r }, function (err, docs) { promise.

Does mongoose query return a promise?

Mongoose async operations, like . save() and queries, return Promises/A+ conformant promises. This means that you can do things like MyModel.

Does Mongoose support async await?

The connect() method provided by the Mongoose supports both JavaScript promises and async-await syntax. Read this article to learn more about setting up a MongoDB connection in Node. js.


1 Answers

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.

like image 58
idbehold Avatar answered Oct 08 '22 06:10

idbehold