A delayed `CancelRequest` can cancel a later query in session mode

Open

apkipaopened 2mo ago

Supavisor version

v2.9.10; reproduced on main (b231926, session pool mode)

Description

Closing a partially consumed psycopg stream sends a CancelRequest and drains the old result. Through Supavisor, that cancellation can arrive at PostgreSQL after the session has started a later query and cancel it with SQLSTATE 57014. Direct PostgreSQL completes the same workload without cancelling a later query.

Supavisor handles the frontend CancelRequest by broadcasting to the owning ClientHandler and immediately stopping the cancel connection client_handler.ex:

def handle_event(:info, {_, _, Server.cancel_message(pid, key)}, _state, _) do
  Logger.debug("ClientHandler: Got cancel query for #{inspect({pid, key})}")
  :ok = Cancel.send_cancel_query(pid, key)
  {:stop, :normal}
end

The owning handler processes the broadcast later. Only then does it connect to PostgreSQL, write the real CancelRequest, and close that socket cancel.ex. The client can therefore observe the cancel connection closing and start another query before the upstream cancellation has been sent.

Reproduce

Start PostgreSQL 16 and Supavisor in session pool mode.
Install psycopg 3 and run the following with the direct and Supavisor DSNs supplied by the environment:

#!/usr/bin/env python3
import psycopg


SQL = "SELECT i, repeat('x', 2048) FROM generate_series(1, 256) AS g(i)"
ROUNDS = 2000


def run(label: str, dsn: str) -> None:
    try:
        with psycopg.connect(dsn, autocommit=True) as conn:
            for round_no in range(ROUNDS):
                try:
                    with conn.cursor() as cur:
                        stream = cur.stream(SQL, size=1)
                        next(stream)
                        next(stream)
                        stream.close()
                except psycopg.errors.QueryCanceled as exc:
                    print(f"{label}: round {round_no}: stream query: {exc.sqlstate} {exc}")
                    return

                try:
                    conn.execute("SELECT 42").fetchone()
                except psycopg.errors.QueryCanceled as exc:
                    print(f"{label}: round {round_no}: SELECT 42: {exc.sqlstate} {exc}")
                    return

        print(f"{label}: no delayed cancellation in {ROUNDS} rounds")
    except Exception as exc:
        print(f"{label}: {type(exc).__name__}: {exc}")


run("direct", DIRECT_DSN)
run("supavisor", SUPAVISOR_DSN)

Expected behavior

Closing the stream may cancel that stream's query, but the cancellation should not affect a later query after the old result has been drained.

Actual behavior

One run produced:

direct: no delayed cancellation in 2000 rounds
supavisor: round 48: SELECT 42: 57014 canceling statement due to user request

The failing round varies because the race is timing-dependent. A delayed cancellation can also reach the next iteration's stream query instead of SELECT 42.

Activity

No activity yet.