Queries stuck in `ClientRead`

[nwjsmith]

We're experiencing database server performance issues caused by sessions spending the vast majority of time in the ClientRead state. A few other similar issues have been opened: #1774, #1993, #1952.

To reproduce:

var pg = require("pg"); // or require("pg").native
var client = new pg.Client({
  connectionString: "postgres://postgres@localhost/postgres"
});
client.connect();
client.query("SELECT 1", function(_error, _rows) {
  while (true) {}
});

Run the above, it will hang in the while loop. In another terminal run:

$ psql --username postgres --command "SELECT * FROM pg_stat_activity WHERE wait_event = 'ClientRead' AND query = 'SELECT 1'"

We can see the query stuck in ClientRead.

The problem here is that node-postgres is executing the response callback before the session is out of the ClientRead state. This is isn't optimal: any CPU time spent in the callback prevents the PostgreSQL server from executing the query.

Would it be possible for node-postgres to execute the callback only after the server is able to execute the query?

Thanks in advance! We get a tremendous amount of value from node-postgres.

[charmander]

Hm, which state do you expect it to be in? Which query’s execution is being prevented? I thought idle ClientRead (showing the last completed query) was the normal state – it’s waiting for the connected client to send the next message, e.g. the next query. This seems to match up with the entry for an idle psql.

[brianc]

The problem here is that node-postgres is executing the response callback before the session is out of the ClientRead state. This is isn't optimal: any CPU time spent in the callback prevents the PostgreSQL server from executing the query.

Hmmm I'm pretty sure the callback is executed after the query is entirely complete and the backend is ready for another query. Here is where the readyForQuery backend message is handled...it's the final message the backend sends before stopping & waiting for another query to be submitted...so I don't think this is blocking things. Always interesting though to see stuff like this...there might be some weird places where messages could be responded to faster. I'm slowly peeling the onion and trying to optimize these message interactions internally on some local experimental stuff...hoping to speed things up.

You can try PG_FAST_CONNECTION=true environment variable to use a faster parser & slightly tweaked messaging timings. I'm about to flip that on for everyone as it's 100% backwards compatible...not sure if it will help in this particular instance, but I am sure it will make some queries ~30% faster.

[nwjsmith]

Thanks to you both for your help. My reproduction case here is incorrect, so I'll be closing this issue. We've opted into the performance improvements, although our issue with ClientRead remains. Our current theory is that CPU usage in the application processes is blocking them from sending queries quickly to the database server, keeping the sessions jammed in active ClientRead state.

[boromisp]

Isn't the issue, that the callback of a query could block the query queue?

var pg = require("pg"); // or require("pg").native
var client = new pg.Client({
  connectionString: "postgres://postgres@localhost/postgres"
});
client.connect();
client.query("SELECT 1", function(_error, _rows) {
  while (true) {}
});
client.query("SELECT 2", function(_error, _rows) {});

It might be worth investigating if the callback can be deferred until the next query is in flight.

The user could also do this selectively:

client.query("SELECT 1", function(_error, _rows) {
  setTimeout(function () { while (true) {} }, 0);
});

Could the ClientReady also indicate higher latency?

[nwjsmith]

@boromisp ClientRead can indicate high latency, yes, but we've investigated and ruled out network latency. Our current guess is similar to your suggestion here about the query queue blocking. Unfortunately, our application is nowhere near as simple as the example, so we're going to have to do some in-depth profiling to figure out where the queue might be getting blocked.

Thanks for the suggestions!