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

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