Node-postgres: Breaking changes in 7.5.0

[vitaly-t]

I'm still peeling through all the changes in 7.5.0, trying to understand which of them are breaking.

But as it stands, I haven't been able to upgrade pg-promise to version 7.5.0 of the driver, with about 35% of all my automated tests failing to even execute correctly.

I may be the first one reporting this, as I'm trying to keep my library up to date at all times, but I won't be the last one. Expect the same to be reported from people using sequelize, knex, and other frameworks, or anybody else who relies on tests as comprehensive as within pg-promise.

[brianc]

Thanks for the heads up. There weren't supposed to be breaking changes - the only changes really around how errors are handled. Pls lemme know whenever you figure out what the issue is & we can take a look at it.

[doesdev]

I can concur, something went sideways with this version. No details on my side either, just encountered a bunch of "Client was closed and is not queryable" in prod. Rolled back now and all is well. Came from 7.4.3. Will update if I get any more helpful details. FWIW worth my (limited) tests were fine, it was when it went to prod the issue came up :/

[doesdev]

So in my case perhaps I'm doing something dumb. What I think I'm doing is this, maybe I've misunderstood something though.

Relevant code is here

• on init creating an instance of Pg.Pool
• on each call to PG function, doing the following:
  
  
  
  • call connect to obtain a client
  
  
  • execute query on client
  
  
  • listen for close event on related HTTP request, if called before query completes call end on client
  
  
  • on query promise resolution remove close listener and call release on client
  
  

Here's why I'm wondering if perhaps something in those actions is having effect beyond the singular client instance I'm attempting to operate on.

When the errors occurred I first got a "Connection terminated" error, as follows:

Error: Connection terminated
    at Connection.con.once (C:\\node_apps\\wcapi-node-too\\node_modules\\pg\\lib\\client.js:198:9)
    at Object.onceWrapper (events.js:273:13)
    at Connection.emit (events.js:187:15)
    at Connection.EventEmitter.emit (domain.js:442:20)
    at Socket.<anonymous> (C:\\node_apps\\wcapi-node-too\\node_modules\\pg\\lib\\connection.js:76:10)
    at Socket.emit (events.js:182:13)
    at Socket.EventEmitter.emit (domain.js:442:20)
    at TCP._handle.close (net.js:599:12)

Then I got a ton of the "not queryable" errors as follows:

Error: Client was closed and is not queryable
    at process.nextTick (C:\\node_apps\\wcapi-node-too\\node_modules\\pg\\lib\\client.js:437:25)
    at args.(anonymous function) (C:\\Users\\serviceuser\\AppData\\Roaming\\npm\\node_modules\\pm2\\node_modules\\event-loop-inspector\\index.js:133:29)
    at process._tickCallback (internal/process/next_tick.js:61:11)

So either I am misusing client's under the assumption that each is operating independently of each other or perhaps a change in the error handling is causing it to improperly end connections that shouldn't be ended as a result of another query's failure.

[brianc]

@doesdev can you paste an example of the code? You generally don't want to be calling end on a pooled client, but rather call client.release()

[doesdev]

It's not pretty, but here it is. The only case where end is being called is when the underlying request (HTTP request that is) is closed before the query has completed. The intent is that if there is a hung query (as an HTTP timeout or impatient end-user are the most likely causes for this) the query is ended.

const callPgFunc = (name, params, req) => {
  let q = `SELECT * FROM ${name}($1);`
  if (!pgPool) return Promise.reject(new Error('No database configured'))

  return pgPool.connect().then((client) => {
    let close = () => { if (client && client.end) client.end().catch(() => {}) }
    if (req && req.on) req.once('close', close)

    return client.query(q, [params]).then((data) => {
      if (req && req.removeListener) req.removeListener('close', close)
      client.release()
      return Promise.resolve((data.rows[0] || {})[name] || [])
    }).catch((err) => {
      if (req && req.removeListener) req.removeListener('close', close)
      client.release()
      return Promise.reject(err)
    })
  }).catch((err) => {
    try {
      err.meta = err.meta || {}
      err.meta.pgFunction = name
      let errObj = JSON.parse(err.message)
      err.message = errObj.error ? errObj.error : errObj
    } catch (ex) {}
    return Promise.reject(err)
  })
}

[brianc]

instead of calling client.end try calling client.release(true) - passing a truthy value to release will cause the pool to call .end on the client and evict it from the pool. What you're likely running into is calling .end on a client and then returning it to the pool...the next time that client is checked out from the pool it's already ended and wont run queries. I'm not sure how the code was working in the past as calling .end on a client manually and returning it to the pool will eventually fill your pool with ended clients that likely wont ever send their queries. So the change in 7.5 is surfacing an error that was already (I guess somewhat silently) happening.

also, FWIW I don't think closing a postgres connection in general will cancel a query while it's running....but I might be wrong there. But, I remember running some extremely long queries from psql in the past and closing psql hoping the query would abort but it didn't. Foggy memory at this point though.

[doesdev]

Thanks, I'll give that change a push tomorrow morning and let you know if it crops back up. Hope I didn't derail the OPs issue too badly, just thought the issues might fit together.

[joelmukuthu]

We saw some issues as well after upgrading to 7.5.0. It's hard to track down exactly what causes them but it's related to clients and connections. So far we see one of these errors crop up in one unit test and cause following tests to fail:

• deadlock detected
• This socket has been ended by the other party

Pinning to 7.4.3 makes the errors go away

[vitaly-t]

I have just updated pg-promise tests to use the freshly released pg-query-stream v1.1.2, and suddenly all the problems are gone. See #46.

As in turns out, somehow tests related to data streaming were causing total havoc within the test framework, and in such a way, I could not even diagnose it.

I am also relieved to know that there are indeed no breaking changes in node-postgres, and if you are running into any issues, it means your code wasn't valid to begin with.

@brianc Thank you for the follow up, and feel free closing the issue.

[joelmukuthu]

Right. I’m fine with having this issue closed as well. If needed, I’ll create a new issue when I find out more about our errors.

[doesdev]

To follow up on my portion that did resolve the issue I experienced. Thanks

[brianc]

Glad to know things are settling down! Thanks for the updates. @joelmukuthu LMK if/when you find out what the issue turns out to be.

[joelmukuthu]

@brianc quick question, why isn't the client.release(true) behaviour the default?

[sehrope]

Passing a truthy value to client.release(...) will evict the client from the pool. It's a way for the user of the pool to indicate that the client is somehow broken (ex: if you had some kind of connection error). It's not the default so that a valid client can be returned to the pool and reused again.

If you always pass a truthy value to client.release(...) you won't really be using a pool as every usage would close the connection and require new connections to be created.

[joelmukuthu]

thanks @sehrope, that makes sense. is it easy to identify which errors would indicate a broken client? maybe some property on the error?

[joelmukuthu]

To answer my question, from this https://github.com/brianc/node-pg-pool/blob/d7f6ed0c7cb7f546211ae3c90e6f1d50b7bcd383/index.js#L296, it looks like the answer is "any query error".

Perhaps the example in the docs should be updated to reflect that?

[sehrope]

Yes, "Any query error" is a sensible default. Alternatively, if you're managing a transaction then you can try to ROLLBACK. If it succeeds then the connection is fine to reuse. Otherwise, it's definitely broken.

[joelmukuthu]

Thanks again, going with "any query error" for now :)

In relation to this, we're getting "Client was closed and is not queryable" errors on GitLab CI with a fairly large test suite (in terms of number of queries). The CI build build uses a pool with the default max of 10 clients. No other errors show up but there are probably some connection errors to the postgres service. Any suggestions on how to debug that?