New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

error stack traces are not displaying the original line when used with async/await #2500

Closed
capaj opened this Issue Feb 21, 2018 · 5 comments

Comments

Projects
None yet
4 participants
@capaj
Contributor

capaj commented Feb 21, 2018

Environment

Knex version: 0.14.4
Database + version: I think that any, I used pg
OS: any
node.js: 9.4.0

given this code:

global.Promise = require('bluebird')
Promise.longStackTraces()
const knex = require('knex')

const db = knex({
  client: 'pg',
  connection: {
    host: 'localhost',
    user: 'my_user',
    password: 'supersecret',
    database: 'my_db'
  }
})

const test = async () => {
  db('userss')
    .select()
    .then(() => {})
}

test()

and the fact that I don't have a userss table in my_db
I get this error:

capaj@capaj-i7-4771:~/git_projects/tests$ node knex.js
Unhandled rejection error: relation "userss" does not exist
    at Connection.parseE (/home/capaj/git_projects/tests/node_modules/pg/lib/connection.js:545:11)
    at Connection.parseMessage (/home/capaj/git_projects/tests/node_modules/pg/lib/connection.js:370:19)
    at Socket.<anonymous> (/home/capaj/git_projects/tests/node_modules/pg/lib/connection.js:113:22)
    at emitOne (events.js:116:13)
    at Socket.emit (events.js:211:7)
    at addChunk (_stream_readable.js:263:12)
    at readableAddChunk (_stream_readable.js:250:11)
    at Socket.Readable.push (_stream_readable.js:208:10)
    at TCP.onread (net.js:594:20)
From previous event:
    at Client_PG._query (/home/capaj/git_projects/tests/node_modules/knex/lib/dialects/postgres/index.js:287:12)
    at Client_PG.query (/home/capaj/git_projects/tests/node_modules/knex/lib/client.js:199:17)
    at Runner.<anonymous> (/home/capaj/git_projects/tests/node_modules/knex/lib/runner.js:149:36)
From previous event:
    at /home/capaj/git_projects/tests/node_modules/knex/lib/runner.js:61:21
    at runCallback (timers.js:789:20)
    at tryOnImmediate (timers.js:751:5)
    at processImmediate [as _immediateCallback] (timers.js:722:5)
From previous event:
    at Runner.run (/home/capaj/git_projects/tests/node_modules/knex/lib/runner.js:47:31)
    at Builder.Target.then (/home/capaj/git_projects/tests/node_modules/knex/lib/interface.js:35:43)
    at test (/home/capaj/git_projects/tests/knex.js:18:6)
    at Object.<anonymous> (/home/capaj/git_projects/tests/knex.js:21:1)
    at Module._compile (module.js:635:30)
    at Object.Module._extensions..js (module.js:646:10)
    at Module.load (module.js:554:32)
    at tryModuleLoad (module.js:497:12)
    at Function.Module._load (module.js:489:3)
    at Function.Module.runMain (module.js:676:10)
    at startup (bootstrap_node.js:187:16)
    at bootstrap_node.js:608:3

now let's change only the body of test function into something like this:

await db('userss').select()

now I get this error thrown:

(node:30763) UnhandledPromiseRejectionWarning: error: relation "userss" does not exist
    at Connection.parseE (/home/capaj/git_projects/tests/node_modules/pg/lib/connection.js:545:11)
    at Connection.parseMessage (/home/capaj/git_projects/tests/node_modules/pg/lib/connection.js:370:19)
    at Socket.<anonymous> (/home/capaj/git_projects/tests/node_modules/pg/lib/connection.js:113:22)
    at Socket.emit (events.js:160:13)
    at addChunk (_stream_readable.js:269:12)
    at readableAddChunk (_stream_readable.js:256:11)
    at Socket.Readable.push (_stream_readable.js:213:10)
    at TCP.onread (net.js:599:20)
From previous event:
    at Client_PG._query (/home/capaj/git_projects/tests/node_modules/knex/lib/dialects/postgres/index.js:287:12)
    at Client_PG.query (/home/capaj/git_projects/tests/node_modules/knex/lib/client.js:199:17)
    at Runner.<anonymous> (/home/capaj/git_projects/tests/node_modules/knex/lib/runner.js:149:36)
From previous event:
    at /home/capaj/git_projects/tests/node_modules/knex/lib/runner.js:61:21
    at runCallback (timers.js:756:18)
    at tryOnImmediate (timers.js:717:5)
    at processImmediate [as _immediateCallback] (timers.js:697:5)
From previous event:
    at Runner.run (/home/capaj/git_projects/tests/node_modules/knex/lib/runner.js:47:31)
    at Builder.Target.then (/home/capaj/git_projects/tests/node_modules/knex/lib/interface.js:35:43)
    at process._tickCallback (internal/process/next_tick.js:160:7)
    at Function.Module.runMain (module.js:703:11)
    at startup (bootstrap_node.js:193:16)
    at bootstrap_node.js:617:3

My original file with test function:

at Object.<anonymous> (/home/capaj/git_projects/tests/knex.js:21:1)

is nowhere in the stacktrace when called with await and that should be fixed IMHO.
I did a little bit of googling and found out this issue: nodejs/node#11865
Which is still opened to this day. IMHO it should be possible to hack it even without the support in node.js. In NODE_ENV=development knex could remember the stacktrace to the last called querybuilder and put that in the thrown error. It is far from ideal solution, but it would certainly help me a ton.
In this discussion someone else proposed similar solution for pupeteer: GoogleChrome/puppeteer#979 (comment)

In the current state it's quite hard to debug any async/await code because developer simply always have to guess where the exception might have been thrown.

@tgriesser

This comment has been minimized.

Owner

tgriesser commented Feb 21, 2018

I agree, there could be a better developer experience here. I'll take a look into what it'd take to capture the stack trace at the time of execution to give a better trace.

@elhigu

This comment has been minimized.

Collaborator

elhigu commented Feb 21, 2018

I have also been thinking of storing information already since the last time when this issue was reported last year.

To me the solution where one would store stacktrace of the place where query builder was initially created (or even every place where it was modified) to the query builder when in debug mode could be enough.

Would definitely make debugging easier.

@wubzz

This comment has been minimized.

Collaborator

wubzz commented Feb 21, 2018

I don't like the idea that that useful stacktraces would be dependant upon debug: true tbh. Would expect useful stacks in production logs where debug is never enabled.

Not sure on the performance impact of Error.captureStackTrace but adding it to the knex constructors allows that stack to be used where the error is actually thrown via runner.builder.stack.

At the end of the day I feel it boils down to a Node issue..

@elhigu

This comment has been minimized.

Collaborator

elhigu commented Feb 21, 2018

Of course if it doesn't cause big performance / memory consumption hit it could be enabled as default. Maybe separate configuration parameter for this one could be used instead of relaying on debug: true.

@capaj

This comment has been minimized.

Contributor

capaj commented Feb 21, 2018

@elhigu I'd opt in for a separate config param as well. Something like: asyncStackTraces. I'd default it to true if the performance penalty of making a query would be under 20% to current version. If more, I'd default to false

capaj added a commit to capaj/knex that referenced this issue Feb 21, 2018

Hackfix for tgriesser#2500
a very nasty way of getting better error stacks when using async/await

@capaj capaj referenced this issue Feb 21, 2018

Merged

fix for #2500 #2505

capaj added a commit to capaj/knex that referenced this issue Feb 21, 2018

Hackfix for tgriesser#2500
a very nasty way of getting better error stacks when using async/await

capaj added a commit to capaj/knex that referenced this issue Feb 22, 2018

Hackfix for tgriesser#2500
a very nasty way of getting better error stacks when using async/await

capaj added a commit to capaj/knex that referenced this issue Mar 20, 2018

capaj added a commit to capaj/knex that referenced this issue Mar 20, 2018

capaj added a commit to capaj/knex that referenced this issue Mar 20, 2018

capaj added a commit to capaj/knex that referenced this issue Mar 20, 2018

capaj added a commit to capaj/knex that referenced this issue Mar 21, 2018

capaj added a commit to capaj/knex that referenced this issue Apr 17, 2018

@elhigu elhigu closed this in e086427 Apr 25, 2018

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment