Better error reporting. Add original query and params to the thrown exception.

[davojan]

Currently db exception looks like this:

Error: column "appliedat" of relation "some_table" does not exist
    at Object.generic (...backend/node_modules/postgres/lib/types.js:200:5)
    at Object.ErrorResponse (...backend/node_modules/postgres/lib/backend.js:124:33)
    at Socket.data (...backend/node_modules/postgres/lib/connection.js:161:25)
    at Socket.emit (events.js:223:5)
    at addChunk (_stream_readable.js:309:12)
    at readableAddChunk (_stream_readable.js:290:11)
    at Socket.Readable.push (_stream_readable.js:224:10)
    at TCP.onStreamRead (internal/stream_base_commons.js:181:23) {
  severity_local: 'ERROR',
  severity: 'ERROR',
  code: '42703',
  position: '40',
  file: 'parse_target.c',
  line: '1033',
  routine: 'checkInsertTargets'
}

There are two problems here:

1. Stack trace doesn't tell anything about my own source code. Although async stack trace is enabled in node 12. May be node's socket API doesn't support async stack traces. It seems to be hard problem to solve and may be out of the scope of the library. But it should be considered.

2. There is technical information from postgres server included, but no useful info about original query and params. I would be great if the query and params will be manually injected into the Error object before thrown to the app code.

[porsager]

Yes, that's a very good point.

1. I've been meaning to explore if theres some neat way to make this work, hopefully I'll have time for it soon.

2. I'm actually just now testing a solution for this locally, but I think it needs to be opt in, as showing query + parameters might leak sensitive information in logs unexpectedly.

[Minigugus]

What about Error.captureStackTrace ? Maybe capturing the stack when the sql function is called and coping the stack property when an error is thrown could work 😄

[porsager]

Haha :) Literally just tested that, and it seems good :)

Error: syntax error at or near "selec"
    at Object.generic (/Users/rasmus/Projects/Postgres/lib/types.js:200:5)
    at Object.ErrorResponse (/Users/rasmus/Projects/Postgres/lib/backend.js:124:33)
    at Socket.data (/Users/rasmus/Projects/Postgres/lib/connection.js:178:25)
    at Socket.emit (events.js:223:5)
    at addChunk (_stream_readable.js:309:12)
    at readableAddChunk (_stream_readable.js:290:11)
    at Socket.Readable.push (_stream_readable.js:224:10)
    at TCP.onStreamRead (internal/stream_base_commons.js:181:23) {
  severity_local: 'ERROR',
  severity: 'ERROR',
  code: '42601',
  position: '1',
  file: 'scan.l',
  line: '1150',
  routine: 'scanner_yyerror',
  origin: Error
      at postgres (/Users/rasmus/Projects/Postgres/lib/index.js:62:28)
      at /Users/rasmus/Projects/Postgres/tests/index.js:51:12
      at /Users/rasmus/Projects/Postgres/tests/test.js:24:5
      at processTicksAndRejections (internal/process/task_queues.js:94:5),
  query: 'selec wat',
  parameters: []
}

[davojan]

@porsager please don't keep it to yourself :)
My team needs this changes for effective development. Do you need any help to release this enhancement?

[porsager]

Hehe, no worries @davojan ... I wouldn't, I just simply haven't had time to wrap it up and get it out.. I should manage to get this in during this week though :)

And thanks a lot for the offer to help, this one is pretty straight forward, but I'll be sure to reach out for anything I can think of.

[porsager]

Ok, it's on master now... Would be great if you could give it a shot @davojan ? :)

[davojan]

Thanks! I've tried this, works like a charm!
The only concern I have - capturing stack trace for every query may affect performance. Did you run benchmarks? May be this should be optional via configuration option 🤔

[porsager]

Ah right, I forgot to test that..

I initially thought it wouldn't be that bad because I'm not accessing the stack trace unless there's an error. I'm just attaching an Error instance. The stacktrace itself is not materialized until .stack is accessed on the error object. Unfortunately even the Error object by itself is quite heavy, and there's is a big hit (~80%)!

I just tested by caching the error using the tagged array instead, and then there's no performance hit at all, but it does mean that the stack trace will be of the code path which called the query first. That is a bit misleading, so maybe cut off the rest of the stack that can be wrong by default, and then have an option to enable full stack traces which will mean worse performance.

What do you think?

And thanks for thinking ahead ! ;)

[davojan]

I think the best and simplest thing for now is to leave stack trace capturing as is (because it's very useful) but wrap the code with if statement using cofiguration option captureOriginStackTrace defaulting to process.env.NODE_ENV === 'development'.

Next step is to investigate - why node's native async stack traces (which are now enabled by default) doesn't work with this library, and maybe modify code to fix that.

[porsager]

Ok, I've been on a little hunt, and it seems that support for async stack traces doesn't work with Promise as used in Postgres.js. There should be work underway to make it work which can be tracked here:
https://chromium-review.googlesource.com/c/v8/v8/+/1969897
nodejs/node#30822

Eg. not even something simple as this will work:

async function run() {
  await new Promise((resolve, reject) => {
    setTimeout(() =>
      reject(new Error('wat'))
    , 200)
  })
}

run().catch(console.error) // bad stack trace

I think it's still worth it to use the cached method and always include a single line from userland code since it's way better than nothing in production. Then we can add support for long stack traces through a debug flag or a stackTraceLimit option. We could even allow single queries to store long stack traces with a special method.