porsager / porsager/postgres

Connection pool sometimes does not end properly

Open
#861 4 comments 5 reactions 0 assignees View on GitHub

Nobody has claimed this yet.

Dominant language
JavaScript
Stars
8.7k
Forks
374
Avg merge
11d 16h
Merged PRs (30d)
1

Description

Hello. I discovered race condition with sql.end().

It seems that if there are more queries queued than max pool size, something hangs.

I'm running on deno 1.43.1 with postgres.js v3.4.4

When CLOSE_POOL_TIMEOUT is around 33, there is 50/50 chance of both conditions below.
If CLOSE_POOL_TIMEOUT is much greater, process will hang.
If CLOSE_POOL_TIMEOUT is lesser, process will exit normally.

import postgres from "https://deno.land/x/postgresjs/mod.js";

const CLOSE_POOL_TIMEOUT = 33;

const sql = postgres({
  debug: true,
  max: 2,
  connect_timeout: 1,
});

const log = (str: string, ...rest: unknown[]) =>
  console.log(
    `[${(performance.now() / 1000).toFixed(3).padStart(6)}s] ${str}`,
    ...rest,
  );

const delay = (ms: number) => new Promise((r) => setTimeout(r, ms));

const longQuery = () =>
  sql`SELECT CURRENT_TIMESTAMP as ts, pg_sleep(0.05) as sleep`.execute();

let ended = false;
const parallelQueries = async () => {
  for (let i = 1; i <= 100; i++) {
    await delay(10);

    if (ended) {
      return;
    }

    const queryId = i;
    log(`${queryId} run`);
    longQuery()
      .then((r) => {
        log(`${queryId} OK:  ts: ${r?.[0]?.ts.toISOString()}`);
      })
      .catch((e) => {
        log(`${queryId} ERR:`, e.message);
      });
  }
};

parallelQueries()
  .then(() => {
    log("parallelQueries done");
  })
  .catch(() => {
    log("parallelQueries error");
  });

setTimeout(async () => {
  log("closing pool...");
  await sql.end({
    timeout: 1,
  });
  ended = true;
  log("pool closed");
}, CLOSE_POOL_TIMEOUT);

globalThis.addEventListener("unload", () => {
  log("goodbye!");
});

The output is as follows:
First run, OK, finished successfully 👍

% deno run -A postgres/client.ts
[ 0.106s] 1 run
[ 0.121s] 2 run
[ 0.130s] closing pool...
[ 0.132s] 3 run
[ 0.132s] 3 ERR: write CONNECTION_ENDED /var/run/postgresql/.s.PGSQL.5444
[ 0.143s] 4 run
[ 0.143s] 4 ERR: write CONNECTION_ENDED /var/run/postgresql/.s.PGSQL.5444
[ 0.156s] 5 run
[ 0.156s] 5 ERR: write CONNECTION_ENDED /var/run/postgresql/.s.PGSQL.5444
[ 0.167s] 6 run
[ 0.167s] 6 ERR: write CONNECTION_ENDED /var/run/postgresql/.s.PGSQL.5444
[ 0.172s] 1 OK:  ts: 2024-05-04T19:50:46.984Z
[ 0.179s] 7 run
[ 0.179s] 7 ERR: write CONNECTION_ENDED /var/run/postgresql/.s.PGSQL.5444
[ 0.181s] 2 OK:  ts: 2024-05-04T19:50:46.994Z
[ 0.181s] pool closed
[ 0.190s] parallelQueries done
[ 0.192s] goodbye!

Second run does not ternimate. 🤕

% deno run -A postgres/client.ts
[ 0.102s] 1 run
[ 0.114s] 2 run
[ 0.126s] 3 run  <-- 3rd client queued when pool max == 2
[ 0.126s] closing pool...
[ 0.138s] 4 run
[ 0.138s] 4 ERR: write CONNECTION_ENDED /var/run/postgresql/.s.PGSQL.5444
[ 0.151s] 5 run
[ 0.151s] 5 ERR: write CONNECTION_ENDED /var/run/postgresql/.s.PGSQL.5444
[ 0.162s] 6 run
[ 0.162s] 6 ERR: write CONNECTION_ENDED /var/run/postgresql/.s.PGSQL.5444
[ 0.165s] 1 OK:  ts: 2024-05-04T19:50:48.303Z
[ 0.173s] 7 run
[ 0.173s] 7 ERR: write CONNECTION_ENDED /var/run/postgresql/.s.PGSQL.5444
[ 0.175s] 2 OK:  ts: 2024-05-04T19:50:48.314Z
[ 0.176s] pool closed
[ 0.183s] parallelQueries done
[ 0.234s] 3 OK:  ts: 2024-05-04T19:50:48.372Z  <-- response after pool closed?
^C

Contributor guide

No contributing guide indexed for this repository

First steps

  1. Read the whole issue, then the project's contributing guide.
  2. Comment on the issue to say you are picking it up — it saves two people doing the same work.
  3. Fork the repository and make your change on a branch.
  4. Open a pull request that references the issue number.

Research direction

Start by running the issue's Deno reproduction with max: 2 and queued queries, then trace sql.end through the connection-pool queue in mod.js. Done means queued queries consistently settle or reject and the process exits without hanging, including when closing races with a queued query.

Written by the indexing model from the issue text.

Assessment

Tech stack
deno, javascript, postgresql
Domain
backend, database
Issue type
Bug
Difficulty
4/5
Estimated time
3-5 days
Activity status
Stale
Clarity
Mostly clear
Newbie friendliness
35/100

Get new issues in your inbox

A short digest of beginner-friendly GitHub issues.