Skip to content
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

fix stack traces of query() to include the async context (#1762) #2983

Merged
merged 5 commits into from
May 31, 2023

Conversation

phiresky
Copy link
Contributor

This PR replaces the stack trace of errors in pool.query() and client.query() with a more useful stack trace including the callsite:

The following code:

async function innerFunction() {
	const pool = new pg.Pool();
	await pool.query("SELECT test from nonexistent");
}

async function outerFunction() {
	await innerFunction();
}

outerFunction();

Throws this with the current version of pg:

error: relation "nonexistent" does not exist
    at Parser.parseErrorMessage (.../node_modules/pg-protocol/dist/parser.js:287:98)
    at Parser.handlePacket (.../node_modules/pg-protocol/dist/parser.js:126:29)
    at Parser.parse (.../node_modules/pg-protocol/dist/parser.js:39:38)
    at Socket.<anonymous> (.../node_modules/pg-protocol/dist/index.js:11:42)
    at Socket.emit (node:events:511:28)
    at addChunk (node:internal/streams/readable:332:12)
    at readableAddChunk (node:internal/streams/readable:305:9)
    at Readable.push (node:internal/streams/readable:242:10)
    at TCP.onStreamRead (node:internal/stream_base_commons:190:23)

With this PR, it throws this much more useful error:

error: relation "nonexistent" does not exist
    at .../node_modules/pg-pool/index.js:45:11
    at process.processTicksAndRejections (node:internal/process/task_queues:95:5)
    at async innerFunction (my-own-code.js:10:3)
    at async outerFunction (my-own-code.js:14:3)

Why

For larger code-bases it has been a long-standing issue of not being able to find out which query or code a PG error comes from. I have years of logs with errors like error: invalid input syntax for type bigint: "NaN" or error: could not serialize access due to concurrent update with no way to know where they are coming from. This should fix that by directly linking the calling functions in the stack trace.

How it works

Since Node 16, Node has included stack tracing for async functions. The reason these don't work out of the box in node-pg is that the response to a query comes from a different stack resulting from the message received via TCP, and this stack is not linked anywhere to the calling stack. As far as I know there's no way to directly do this, there's an API to do this for the async_context API (https://nodejs.org/api/async_context.html#static-method-asyncresourcebindfn-type-thisarg) that AFAIK uses the same technology as the zero-cost async stack traces, but it doesn't work for the integrated Error stack tracing.

Instead, the solution is to simply replace the Error stack at the first point where the async execution context is the "correct" one by catching and rethrowing the error. This should come at no cost for the happy path.

Limitations

  • This only works for promise-based code. I'm not sure if it works for mixes of async functions with .then(), .catch() style calls but it definitely doesn't work for purely callback-based code. (this doesn't break anything, worst case you just won't get useful error traces as before)
  • This code fully replaces the stack trace, losing the original "parseErrorMessage" stack. I've never found that part useful so I didn't preserve it. It would be neatly possible though e.g. through the error.cause property: ...catch(e => {e.cause = Object.assign(Object.create(Error.prototype), { stack: e.stack }); Error.captureStackTrace(e); throw e});
  • I didn't implement it for pg-native though the same thing should work?

Compatibility

This code really only uses the Error.captureStackTrace function which has been there since Node 8. So this should be compatible starting with node 8+ and useful starting with Node 14 (with --async-stack-traces) and Node 16 (out of the box).

References

@phiresky
Copy link
Contributor Author

Something's wrong, the tests should be failing on Node 10 and 12 and succeeding on 16+

@phiresky
Copy link
Contributor Author

The tests weren't run because I didn't name the test file *-tests.js. They should run now hopefully.

@brianc
Copy link
Owner

brianc commented May 31, 2023

This is pretty fantastic! I'll get this merged up and released today. 😄 Thanks a bunch!!

@brianc brianc merged commit d59cd15 into brianc:master May 31, 2023
thijs pushed a commit to thijs/node-postgres that referenced this pull request Aug 1, 2023
brianc#2983)

* fix stack traces of query() to include the async context (brianc#1762)

* rename tests so they are actually run

* conditionally only run async stack trace tests on node 16+

* add stack trace to pg-native

---------

Co-authored-by: Charmander <~@charmander.me>
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Projects
None yet
3 participants