node-postgres icon indicating copy to clipboard operation
node-postgres copied to clipboard

Question: How to calculate how long my query waited for a connection to execute it ?

Open sathishsoundharajan opened this issue 2 years ago • 7 comments

Let say i have set connectionTimeoutMillis to 0 & pg-pool count is set to 20. Now i'm getting 30 concurrent request, first 20 of them already executing by using the connection pool, but last 10 requests will wait for the some of the connection to be freed. How to calculate how long my query waited for connection from pool/to become idle, before actually executing the query for last 10 requests ?

Is this something we can calculate using some metrics exposed by node-postgres ?

sathishsoundharajan avatar Dec 18 '23 10:12 sathishsoundharajan

@brianc @charmander Can anyone provide me an insight on this metric calculation ?

sathishsoundharajan avatar Dec 23 '23 04:12 sathishsoundharajan

You would need to handle this yourself by creating your own version of pool.query(...) that uses the pool.connect(...) and tracks the time it took to retrieve a connection from the pool separately from the time it took to execute the query.

sehrope avatar Dec 28 '23 15:12 sehrope

@sehrope Is this something already done somewhere ? Like a blog post explaining things ?

sathishsoundharajan avatar Dec 28 '23 16:12 sathishsoundharajan

Here's what I ended up writing:

import * as Postgres from 'pg';
import { hrtime } from 'node:process';

const hrtimeToMs = (value: bigint) => Number(hrtime.bigint() - value) / 1000000;

// Calling this method will monkey patch the
// pool instance, and every time a client is acquired via pool.query(...) / pool.connect(...)
// invoke the passed in callback, with 3 parameters:
// - The duration it took to get a client from the pool
// - Any error that occurred during the acquisition (may be undefined)
// - The acquired client (may be undefined)
const monitorPoolConnect = (pool: Postgres.Pool, cb: (duration: number, error?: Error, client?: Postgres.PoolClient) => void) => {
  const connect = pool.connect;

  pool.connect = (...args: any[]) => {
    const start = hrtime.bigint();

    if (args.length) {
      const callback = args[0];

      args[0] = (...p: any[]) => {
        const client = p[1];

        cb(hrtimeToMs(start), p[0], client);

        callback(...p);
      };

      return connect.apply(pool, args);
    }

    const handleError = (error: Error) => {
      cb(hrtimeToMs(start), error, undefined);

      return Promise.reject(error);
    };

    const handleClient = (client: Postgres.PoolClient) => {
      cb(hrtimeToMs(start), undefined, client);

      return client;
    };

    return connect.apply(pool, null).then(handleClient, handleError);
  };
};

Example:

monitorPoolConnect(pool, (duration, error) => {
   if (!error) {
     console.log(`acquiring connection took ${duration / 1000} second(s)`)
   }
})

P.S it best to avoid calling monitorPoolConnect with the same pool more than once...

eladchen avatar Dec 29 '23 13:12 eladchen

Thank you @eladchen .. :) Came to know we are using upper level abstraction pg-promise, where we won't be able to override pool.connect method :( . I'm trying to figure out with @vitaly-t to see how we can override/monkey patch the pool method to collect this metric.

This seems like very important metric which is required & plot in graph to understand do we have increase pg-pool count or what should be average or 90th percentile for connectTimeoutMills

sathishsoundharajan avatar Dec 30 '23 07:12 sathishsoundharajan

Wouldn't it be possible to patch the pg-pool still? You should be able to patch the exported Pool class.

https://github.com/brianc/node-postgres/blob/6cd0aeb212d1672edd33499b2f4f858cf7ed9a79/packages/pg-pool/index.js#L66

You should be able to patch the above class prototype, but I agree, it would have been nice if we had a way without having to patch things.

eladchen avatar Dec 30 '23 11:12 eladchen

@sathishsoundharajan You can do whatever you want with the original pool within pg-promise library, as it is exposed as db.$pool.

vitaly-t avatar Dec 30 '23 20:12 vitaly-t