Horton

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

Andres Freund <andres@anarazel.de>

View thread View on postgr.es
From: Andres Freund <andres@anarazel.de>
To: Michael Paquier <michael@paquier.xyz>
Cc: Jacob Champion <jacob.champion@enterprisedb.com>, 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-05T00:10:36Z
Lists: pgsql-hackers 
Hi,

On 2025-03-04 17:51:17 +0900, Michael Paquier wrote:
> On Mon, Mar 03, 2025 at 02:23:51PM +0900, Michael Paquier wrote:
> > This has always been set last and it's still the case in the patch, so
> > let's just remove that.
>
> This first one has been now applied as c76db55c9085.  Attached is the
> rest to add the wait events (still need to have a closer look at this
> part).

This seems to trigger a bunch of CI failures, e.g.:

https://cirrus-ci.com/task/5350341408980992
https://cirrus-ci.com/task/5537391798124544
https://cirrus-ci.com/task/4657439905153024

https://api.cirrus-ci.com/v1/artifact/task/5350341408980992/testrun/build/testrun/authentication/007_pre_auth/log/regress_log_007_pre_auth

[17:47:59.698](0.000s) ok 1 - authenticating connections are recorded in pg_stat_activity
[17:47:59.698](0.000s) # issuing query 5 via background psql: SELECT injection_points_wakeup('init-pre-auth');
[17:47:59.752](0.054s) # pump_until: process terminated unexpectedly when searching for "(?^:(^|\n)background_psql: QUERY_SEPARATOR 5:\r?\n)" with stream: ""
process ended prematurely at C:/cirrus/src/test/perl/PostgreSQL/Test/Utils.pm line 439.
# Postmaster PID for node "primary" is 6084

https://api.cirrus-ci.com/v1/artifact/task/5350341408980992/testrun/build/testrun/authentication/007_pre_auth/log/007_pre_auth_primary.log
2025-03-04 17:47:59.705 GMT [7624][client backend] [007_pre_auth.pl][2/9:0] LOG:  statement: SELECT injection_points_wakeup('init-pre-auth');
2025-03-04 17:47:59.705 GMT [7624][client backend] [007_pre_auth.pl][2/9:0] ERROR:  could not find injection point init-pre-auth to wake up
2025-03-04 17:47:59.705 GMT [7624][client backend] [007_pre_auth.pl][2/9:0] STATEMENT:  SELECT injection_points_wakeup('init-pre-auth');
2025-03-04 17:47:59.706 GMT [7624][client backend] [007_pre_auth.pl][:0] LOG:  disconnection: session time: 0:00:00.333 user=SYSTEM database=postgres host=[local]

Greetings,

Andres Freund

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