[v3] there is already a transaction in progress and there is no transaction in progress

[mohe2015]

Currently I don't have a minimally reproducible example but I may be able to provide one in a few days if needed (please just tell me then).

I strongly suspect the following code is at fault:

export const sql = postgres(process.env["DATABASE_URL"], {
  host: process.env["DATABASE_HOST"],
  debug: (conn, query, params) => {
    console.log(conn, query, params);
  },
});

export async function retryableBegin(
  options: string,
  cb: (
    tsql: TransactionSql<Record<string, never>>
  ) =>
    | postgres.RowList<postgres.Row[]>
    | Promise<postgres.RowList<postgres.Row[]>>
): Promise<postgres.RowList<postgres.Row[]>> {
  for (;;) {
    try {
      return await sql.begin(options, cb);
    } catch (error) {
      if (error instanceof postgres.PostgresError && error.code === "40001") {
        console.log("SERIALIZATION FAILURE - RETRYING");
      } else {
        throw error;
      }
    }
  }
}


await retryableBegin("READ WRITE", async (sql) => {
  return await sql`UPDATE sessions SET updated_at = CURRENT_TIMESTAMP FROM users WHERE users.id = sessions.user_id AND session_id = ${session_id_} AND CURRENT_TIMESTAMP < updated_at + interval '24 hours' RETURNING users.id, users.type, users.username, users.group, users.age`;
})

If this is executed in parallel it seems that some transactions are not managed properly. I don't understand yet whether my code is at fault or not.

Also I think the error handling part is never reached because I misconfigured my local development postgresql instance (didn't enable that level of transaction isolation) so maybe it's just the amount of concurrent requests.

Using apache bench I found out this happens at
11 concurrent requests with very low probability and the further you go away from 10 (which I think is the default number of concurrent connections in the postgresql pool) the more likely they get.

ab -n 10000 -c 11 -T 'text/json' -m GET -k -H 'x-csrf-protection: projektwahl' -H 'Cookie: strict_id=f0774391c90792730a0f374bd0609d9b3e0c7c48c9227eefcdc10104f961b16a; lax_id=f0774391c90792730a0f374bd0609d9b3e0c7c48c9227eefcdc10104f961b16a; username=admin' https://localhost:8443/api/v1/users

created just really few (1-2) of these notices.

[porsager]

Would be great with a reproducible example for this one if you can create one. Thanks.

[mohe2015]

@porsager
I can reproduce with

import postgres from "postgres"

export const sql = postgres("postgres://moritz@localhost/moritz", {
  host: "/run/postgresql"
})

await Promise.all(Array.from({length: 100}, () => sql.begin(async (tsql) => await tsql`SELECT 1`)))

await sql.end()

You may need to adjust the count (and the database connection url of course). This almost always prints the following:

{
  severity_local: 'WARNING',
  severity: 'WARNING',
  code: '25001',
  message: 'there is already a transaction in progress',
  file: 'xact.c',
  line: '3687',
  routine: 'BeginTransactionBlock'
}
{
  severity_local: 'WARNING',
  severity: 'WARNING',
  code: '25P01',
  message: 'there is no transaction in progress',
  file: 'xact.c',
  line: '3885',
  routine: 'EndTransactionBlock'
}

several times and sometimes it even hangs at the end.

[mohe2015]

For me it works breaks more or less reliably with 12.

[mohe2015]

This could (depending on root cause) be (considered) a security issue but now it's too late anyways.

[mohe2015]

If you need help finding the bug (if you can even reproduce) feel free to ask me. I don't know the code but maybe I can still help.

[porsager]

Hi @mohe2015 .. Thanks a lot!!! I've been too busy to check into this until now, but your repro is good, I'll look closer now.

[porsager]

@mohe2015 Thanks a lot for finding and helping on this. That was an important fix, and great to get in before release!
I found the issue to be a race condition when a transaction was the first query on a newly opened connection.

Would you mind testing 3a8efe7 (current rewrite branch)?

Thank you

[mohe2015]

Can confirm. Thank you very much.