Postgres unhandled promise rejection

[richardscarrott]

We're getting unhandled promise rejections from the pg module (via postgraphile) only when the trace agent is enabled:

err: {
      "type": "Error",
      "message": "[Redacted]",
      "stack":
          [Redacted]
              at Connection.parseE (/usr/src/app/node_modules/pg/lib/connection.js:554:11)
              at Connection.parseMessage (/usr/src/app/node_modules/pg/lib/connection.js:379:19)
              at Socket.<anonymous> (/usr/src/app/node_modules/pg/lib/connection.js:119:22)
              at Socket.emit (events.js:210: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:182:23)
      "constraint": "[Redacted]",
      "file": "execMain.c",
      "line": "1762",
      "routine": "ExecConstraints"
    }

Environment details

System:

OS: Linux 4.9 Debian GNU/Linux 9 (stretch) 9 (stretch)

Binaries:

Node: 12.14.0 - /usr/local/bin/node
Yarn: 1.21.1 - /usr/local/bin/yarn
npm: 6.13.4 - /usr/local/bin/npm

Packages:

@google-cloud/trace-agent@5.1.1
pg@7.6.1

Steps to reproduce

I've not got a reduced test case but in our express server using postgraphile a DB constraint violation error on insert results in an unhandled promise rejection. Removing the trace agent prevents this from occurring so I'm guessing the promise is forked by the trace agent but not handled.

[michaelsafyan]

Hi, richardscarrott!

Thank you so much for the bug report. And sorry for the delay in getting to look into it. You said you have a reduced test case that can reproduce this. Would you be willing to share it?

[richardscarrott]

Hi @michaelsafyan Looks like I said I've not got a reduced test case unfortunately.

We were using postgraphile at the time but I expect it'd be easier to test it with the pg module.

[vincentvanderweele]

Hi @michaelsafyan!

I just spent the last 3 days debugging this issue. It never occurred to me that tracing could be the issue, so I had to chip down our application bit by bit until the culprit was found :) As a result, I have a small reproducible example to share too:

https://github.com/vincentvanderweele/cloud-trace-unhandled-promise

We run Node with the recommended flag --unhandled-rejections=strict, which causes these unhandled promises to take down the whole process, so to us this is a pretty high-impact bug. Is fixing this on your short-term roadmap?

[vincentvanderweele]

@michaelsafyan do you have any updates on this? I personally think that the priority of this bug should be reassessed, given the reproduction scenario. Basically, this tracing library cannot be used together with Postgres unless you suppress unhandled rejection promises on application level. We had to disable Postgres tracing altogether to stop our server processes from crashing.

[punya]

Hi @vincentvanderweele. Sorry for the long silence on this issue, and thanks for putting together a minimal repro. We're taking a look to see if there's a better way for this library to handle the rejected promise.

[punya]

Hi @vincentvanderweele. In your repro, you patch the trace agent to make it work on pg v8. Unfortunately, pg v8 isn't actually supported. The error doesn't reproduce with Node 12 and PG v7.

As described in #1272 (comment), please consider using @opentelemetry/instrumentation-pg instead.

[punya]

I spoke too soon - this still happens under Node v12 + PG v7. Reopening.