Unhandled exception when DB drops

[rfshelley]

I've connected to the database, and then explicitly stop the DB, and on the next call to query the DB I get the error:

events.js:72
        throw er; // Unhandled 'error' event
              ^
error: terminating connection due to administrator command
    at Connection.parseE (.../node_modules/pg/lib/connection.js:539:11)
    at Connection.parseMessage (.../node_modules/pg/lib/connection.js:366:17)
    at Socket.Connection.attachListeners (.../node_modules/pg/lib/connection.js:105:22)
    at Socket.emit (events.js:95:17)
    at Socket.stream.pause.paused (_stream_readable.js:764:14)
    at Socket.emit (events.js:92:17)
    at emitReadable_ (_stream_readable.js:426:10)
    at emitReadable (_stream_readable.js:422:5)
    at readableAddChunk (_stream_readable.js:165:9)
    at Socket.Readable.push (_stream_readable.js:127:10)

This occurred from a simple "Client.query()" call from a pooled connection. The thrown exception kills the server and requires me to restart. Is there a better way to gracefully handle downed databases with a reconnect policy or at catch the exception?

[sehrope]

I'm able to reproduce this with pg v4.4.0 on Linux. What's interesting is that you don't even have to run a query.

Here's the sample coffee-script program I used to test it (output is below). It creates a pooled connection, runs a test query, then prints that it's still alive continuously till it dies. Per the defaults the pooled connection should remain open for 30 seconds so that's enough time to manually stop the PostgreSQL server.

pg = require 'pg'

testQuery = (cb) ->
  pg.connect process.env.DATABASE_URL, (err, client, done) ->
    if err then return cb(err)
    client.query 'SELECT 1 AS x', (err, result) ->
      done(err)
      if err then return cb(err)
      console.log '%s - Ran a test query successfully', new Date()
      return cb(null)

showAlive = () ->
  console.log "%s - Still alive", new Date()
  setTimeout showAlive, 100

testQuery (err) ->
  if err
    console.error "Gracefully received error: ", err
    process.exit(1)
  showAlive()

Running with the server offline gives (proper behavior):

Gracefully received error:  [Error: Connection terminated]

Running with the server online and then shutting it down gives (node process dies):

Fri Jul 31 2015 19:10:38 GMT-0400 (EDT) - Ran a test query successfully
Fri Jul 31 2015 19:10:38 GMT-0400 (EDT) - Still alive
Fri Jul 31 2015 19:10:38 GMT-0400 (EDT) - Still alive
Fri Jul 31 2015 19:10:38 GMT-0400 (EDT) - Still alive
Fri Jul 31 2015 19:10:39 GMT-0400 (EDT) - Still alive
Fri Jul 31 2015 19:10:39 GMT-0400 (EDT) - Still alive
Fri Jul 31 2015 19:10:39 GMT-0400 (EDT) - Still alive
Fri Jul 31 2015 19:10:39 GMT-0400 (EDT) - Still alive
Fri Jul 31 2015 19:10:39 GMT-0400 (EDT) - Still alive
Fri Jul 31 2015 19:10:39 GMT-0400 (EDT) - Still alive
Fri Jul 31 2015 19:10:39 GMT-0400 (EDT) - Still alive
Fri Jul 31 2015 19:10:39 GMT-0400 (EDT) - Still alive
Fri Jul 31 2015 19:10:39 GMT-0400 (EDT) - Still alive
Fri Jul 31 2015 19:10:39 GMT-0400 (EDT) - Still alive
Fri Jul 31 2015 19:10:40 GMT-0400 (EDT) - Still alive
Fri Jul 31 2015 19:10:40 GMT-0400 (EDT) - Still alive
Fri Jul 31 2015 19:10:40 GMT-0400 (EDT) - Still alive
Fri Jul 31 2015 19:10:40 GMT-0400 (EDT) - Still alive
Fri Jul 31 2015 19:10:40 GMT-0400 (EDT) - Still alive
Fri Jul 31 2015 19:10:40 GMT-0400 (EDT) - Still alive
Fri Jul 31 2015 19:10:40 GMT-0400 (EDT) - Still alive
Fri Jul 31 2015 19:10:40 GMT-0400 (EDT) - Still alive
Fri Jul 31 2015 19:10:40 GMT-0400 (EDT) - Still alive
Fri Jul 31 2015 19:10:40 GMT-0400 (EDT) - Still alive
Fri Jul 31 2015 19:10:41 GMT-0400 (EDT) - Still alive
Fri Jul 31 2015 19:10:41 GMT-0400 (EDT) - Still alive
Fri Jul 31 2015 19:10:41 GMT-0400 (EDT) - Still alive
Fri Jul 31 2015 19:10:41 GMT-0400 (EDT) - Still alive

events.js:72
        throw er; // Unhandled 'error' event
              ^
error: terminating connection due to administrator command
  at [object Object].Connection.parseE (/home/sehrope/tmp/node-pg-test/node_modules/pg/lib/connection.js:539:11)
  at [object Object].Connection.parseMessage (/home/sehrope/tmp/node-pg-test/node_modules/pg/lib/connection.js:366:17)
  at Socket.<anonymous> (/home/sehrope/tmp/node-pg-test/node_modules/pg/lib/connection.js:105:22)
  at Socket.emit (events.js:95:17)
  at Socket.<anonymous> (_stream_readable.js:765:14)
  at Socket.emit (events.js:92:17)
  at emitReadable_ (_stream_readable.js:427:10)
  at emitReadable (_stream_readable.js:423:5)
  at readableAddChunk (_stream_readable.js:166:9)
  at Socket.Readable.push (_stream_readable.js:128:10)
  at TCP.onread (net.js:529:21)

Sure enough stopping the remote PostgreSQL server while it's running kills the node process. I would have expected that further use of the pooled connection (say running a query) would return back an error which a properly written application would then evict from the pool. Eventually it'd fix itself if the server comes back online. Instead the uncaught exception kills the node process as the error is internal to the driver and there's no handler for it.

[sehrope]

I've got a reproducible test case for this in a PR: #824

It's a bit easier than manually bouncing the server as we can use pg_terminate_backend(...) to kill the connection from a separate connection.

There's a similar test case for this already (see connection-pool/error-tests.js). The difference is that the existing test leaves the pooled connection checked out while it terminates the backend. The new test (which reproduces this issue) returns the connection back to the pool prior to terminating it.

[vitaly-t]

I would think that the issue is quite obvious.

You must be using a connection pool for getting connections. Ideally, the library would be able to detect a special message from the server to clear the current connection pool, but that's not as simple as it sounds.

If you want your application to be smart enough to detect server restarts, you need to catch that error and reset the connection pool, so that the next connection is actually created.

To confirm this theory, if your app waits the timeout (poolIdleTimeout) before re-using the connection, then you will see the problem gone by itself.

[sehrope]

Yes that's definitely the issue. Question now is how to handle it gracefully. Either the connection should be evicted from the pool (probably preferred) or the error should be saved and presented to the next user of that connection from the pool (so it can be gracefully handled).

[vitaly-t]

The best I can suggest right now - call pg.end() when you get server disconnect error. That will effectively shut-down everything, which is pretty much what you need. And if the server is up and running, you will be able to acquire a new connection right after that.

[sehrope]

The best I can suggest right now - call pg.end() when you get server disconnect error.

It should only be for the pool that received the error. Calling pg.end() would close all connections for all pools. Also, it's possible to get this error for a single connection if it's manually terminated by calling pg_terminate_backend(). It's not necessarily a server shutdown that would impact all connections in the pool.

[vitaly-t]

Yes, you are right. I created a feature request where I mentioned the issue with having multiple servers connected. Like I said, this is the best answer you can get right now, because node-postgres doesn't really have any good provision/support for the server shut-down / restart handling.

[brianc]

The pg object itself emits an error anytime a client which is connected and idle in the pool receives an error. If you can, try handling the error at that level.

//somewhere in app bootstrapping code:
pg.on('error', function() {
  //do whatever you need to do to handle errors from idle clients
})

If you come up with a general purpose solution to handle this situation in all cases I'm interested definitely in pulling it in - the problem is, dealing with errors is hard and ever app has a different error handling scenario, so the best thing usually to do from library code like this is emit the error as quickly as possible & allow someone to deal with it.

[sehrope]

The pg object itself emits an error anytime a client which is connected and idle in the pool receives an error. If you can, try handling the error at that level.

That should be perfect. I just took a peek at the pool code and it includes both the error and the errant client so should be pretty easy to auto evict it.

[rfshelley]

Thanks guys... With the pg.on(...) function and some extra error handling I was able to get it to reconnect successfully.

[brianc]

Great @rfshelley glad you got it figured out!

[jotto]

For posterity: if using the pgPool, put the error handler there instead of the pg object. Here's a wrapper that is resilient through most transient db issues (I've been using it on multi-az failover on AWS RDS)

const pg = require("pg");
const promiseRetry = require("promise-retry");

class Db {
  constructor(pgPool) {
    this.pgPool = pgPool;
    this.pgPool.on("error", err => {
      // just need to catch this error, don't need to do anything
    });
  }

  static create() {
    const poolArgs = {
      user: process.env.PGUSER || "postgres",
      database: process.env.PGDATABASE || "postgres",
      host: process.env.PGHOST || "localhost",
      password: process.env.PGPASSWORD || ""
    };

    const pgPool = new pg.Pool(poolArgs);
    return new this(pgPool);
  }

  runQuery(query, args = []) {
    return promiseRetry({ retries: 15, randomize: true }, (retry, attempt) => {
      return this.pgPool
        .query(query, args)
        .then(queryResult => queryResult.rows)
        .catch(err => {
          if (err.code === "ECONNREFUSED") {
            console.log(`retrying query, attempt #${attempt}`);
            return retry(err);
          } else {
            return Promise.reject(err);
          }
        });
    });
  }
}

module.exports = Db;

Note, that's 15 retries with exponential backoff which is way more than enough time for RDS issues (probably only need 1 retry).