node-postgres: ClientRead statement_timeout

I have been observing a strange behaviour where PostgreSQL backends created by node-postgres are hanging in ClientRead state.

cinema_data_task_executor=> SHOW statement_timeout;
 statement_timeout
-------------------
 10s
(1 row)

cinema_data_task_executor=> SELECT
cinema_data_task_executor->   psa1.backend_start,
cinema_data_task_executor->   psa1.pid,
cinema_data_task_executor->   now() - psa1.query_start duration,
cinema_data_task_executor->   psa1.query,
cinema_data_task_executor->   psa1.state,
cinema_data_task_executor->   psa1.application_name,
cinema_data_task_executor->   psa1.wait_event_type,
cinema_data_task_executor->   psa1.wait_event,
cinema_data_task_executor->   psa1.usename
cinema_data_task_executor-> FROM pg_stat_activity psa1
cinema_data_task_executor-> WHERE
cinema_data_task_executor->   psa1.pid = 29342 AND
cinema_data_task_executor->   psa1.state = 'active'
cinema_data_task_executor-> ORDER BY psa1.query_start ASC;
         backend_start         |  pid  |    duration     |                                                query                                                 | state  |     application_name     | wait_event_type | wait_event |          usename
-------------------------------+-------+-----------------+------------------------------------------------------------------------------------------------------+--------+--------------------------+-----------------+------------+---------------------------
 2019-08-20 20:25:00.282386+00 | 29342 | 00:08:02.920093 | UPDATE event_seating_lookup SET last_seen_at = now() WHERE id = $1 AND ended_at IS NULL RETURNING id | active | do-event-seating-lookups | Client          | ClientRead | cinema_data_task_executor
(1 row)

In the above example you can see a backend with statement_timeout set to 10 seconds. Meanwhile, the particular query has been running for 8 minutes. From Node.js perspective, the program is just hanging after sending the query.

There appears to be a case where node-postgres is stuck in ClientRead state.

About this issue

Original URL
State: open
Created 5 years ago
Reactions: 2
Comments: 18 (14 by maintainers)

Most upvoted comments

hmmm yeah if the native driver doesn’t exhibit the behavior it’s almost certainly something we can solve on our end in the JS driver. I’m out of the country for a couple more days but as soon as I get back I’ll take a look at this in detail and see if I can get a tight reproducible case I can work on.

On Sat, Nov 9, 2019 at 9:20 PM Murukesh Sadasivan notifications@github.com wrote:

@gajus https://github.com/gajus @brianc https://github.com/brianc I am experiencing the same problem with node-postgres driver. To replicate, you can use the https://github.com/MagicStack/pgbench pointing to any postgres database.

This is how i ran mine after cloning the repo:

PGPASSWORD=** ./pgbench nodejs --concurrency-levels 50 --pghost <your hpst> --pguser <your user>

pointing the database to an AWS RDS instance. For some reason ts-postgres erred out, but pg and pg-native were able to run successfully.

This is the result from AWS enhanced monitoring which was capturing the AAS (Average Active Sessions) in a graph.

[image: Screenshot 2019-11-10 at 5 37 56 AM] https://user-images.githubusercontent.com/937228/68536700-f9343e00-037c-11ea-966b-73b9f171082e.png

The red line is when the benchmark was using pg-native driver and you can see it does not spend any time on clientRead. While the performance is slightly better for pg-native, what’s interesting is that javascript driver seems to spend a considerable time on ClientRead.

I have not seen any clientRead delays when directly running Postgres own pgbench tool (c++ driver perhaps) and that provides much better latency/throughput.

I did the benchmark after having performance issues with our production system which was not performing up to the standards reported by other AWS RDS users who were using different stacks.

This issue looks totally strange and perhaps is a bug that is avoidable.

— You are receiving this because you were mentioned. Reply to this email directly, view it on GitHub https://github.com/brianc/node-postgres/issues/1952?email_source=notifications&email_token=AAAMHIJNZOAFSOKGBDYTXDDQS5HT7A5CNFSM4IN46UWKYY3PNVWWK3TUL52HS4DFVREXG43VMVBW63LNMVXHJKTDN5WW2ZLOORPWSZGOEDUSH7Q#issuecomment-552150014, or unsubscribe https://github.com/notifications/unsubscribe-auth/AAAMHINT2EIDTRMCJ426SQ3QS5HT7ANCNFSM4IN46UWA .

brianc on Nov 10, 2019

@brianc For what it is worth, I just discovered that switching to require('pg').native makes the issue go away.

gajus on Oct 15, 2019

I’ve just come across this issue as well. The code runs fine locally, but when I deploy it to AWS Lambda the statements all just hang. With the above query on pg_stat_activity I can see that they are also sitting in the ClientRead state. My timeouts are also 10 seconds but it hangs for many minutes.

The query does actually run (in my case it’s an INSERT and the data does get inserted), just that the promise returned by query() never resolves.

However I have noticed that if I send another query to the database, that DOES cause the first one to complete. It will either return a timeout error if I’ve waited too long to send the second query, or it completes as normal if I send the second query shortly after the first.

It looks like there is definitely something causing the queries to stick, but in such a way that subsequent queries can “unstick” earlier ones.

Any ideas where to start looking to debug it?

adam-nielsen on Oct 11, 2019