Horton

Re: [PATCH] pg_stat_activity: make slow/hanging authentication more visible

Jacob Champion <jacob.champion@enterprisedb.com>

View thread View on postgr.es
From: Jacob Champion <jacob.champion@enterprisedb.com>
To: Michael Paquier <michael@paquier.xyz>
Cc: Andres Freund <andres@anarazel.de>, Robert Haas <robertmhaas@gmail.com>, Noah Misch <noah@leadboat.com>, Andrew Dunstan <andrew@dunslane.net>, PostgreSQL Hackers <pgsql-hackers@postgresql.org>, Euler Taveira <euler.taveira@enterprisedb.com>, Daniel Gustafsson <daniel@yesql.se>
Date: 2025-03-06T22:25:07Z
Lists: pgsql-hackers 
On Wed, Mar 5, 2025 at 8:08 PM Michael Paquier <michael@paquier.xyz> wrote:
> Honestly, I don't see a reason not to introduce that, like in the
> attached.

This new code races against the session timeout. I see this on timer expiration:

    [14:19:55.224](0.000s) # issuing query 34 via background psql:
SELECT state FROM pg_stat_activity WHERE pid = ;
    [14:19:55.228](0.004s) # pump_until: process terminated
unexpectedly when searching for "(?^:(^|\n)background_psql:
QUERY_SEPARATOR 34:\r?\n)" with stream: ""
    process ended prematurely at
/home/jacob/src/postgres/src/test/perl/PostgreSQL/Test/Utils.pm line
439.

Which makes it seem like some sort of crash, IMO. I don't find that as
easily debuggable as the previous log message, which was

    [14:21:33.104](0.001s) # issuing query 32 via background psql:
SELECT pid FROM pg_stat_activity
    #   WHERE state = 'starting' and wait_event = 'init-pre-auth';
    IPC::Run: timeout on timer #1 at
/home/jacob/perl5/lib/perl5/IPC/Run.pm line 3007.

> +  WHERE state = 'starting' and wait_event = 'init-pre-auth';});

Did you have thoughts on expanding the check to backend_type [1]?

> + # Give up.  The output of the last attempt is logged by query(),
> + # so no need to do anything here.
> + return 0;

One of my primary complaints about the poll_query_until()
implementation is that "giving up" in this case means continuing to
run pieces of the test that have no business running after a timeout,
and increasing the log noise after a failure. I'm not sure how loudly
to complain in this particular case, since I know we use it
elsewhere...

Thanks!
--Jacob

[1] https://postgr.es/m/CAOYmi%2BnxNCQcTQE-tQ7Lwpe4cYc1u-yxwEe5kt2AVN%2BDXXVVbQ%40mail.gmail.com

Commits

  1. Fix race condition in TAP test 007_pre_auth

  2. Split pgstat_bestart() into three different routines

  3. backport: Extend background_psql() to be able to start asynchronously

  4. backport: Improve handling of empty query results in BackgroundPsql

  5. Improve handling of empty query results in BackgroundPsql::query()

  6. Extend Cluster.pm's background_psql() to be able to start asynchronously

  7. dblink: Replace WAIT_EVENT_EXTENSION with custom wait events