| From: | Alexander Lakhin <exclusion(at)gmail(dot)com> |
|---|---|
| To: | pgsql-hackers <pgsql-hackers(at)postgresql(dot)org>, Michael Paquier <michael(at)paquier(dot)xyz> |
| Subject: | 007_pre_auth.pl fails if injection_points_wakeup hits unintended process |
| Date: | 2026-11-01 13:00:00 |
| Message-ID: | c984ed89-cac1-47a9-91fa-4d3287722203@gmail.com |
| Views: | Whole Thread | Raw Message | Download mbox | Resend email |
| Thread: | |
| Lists: | pgsql-hackers |
Hello hackers,
A recent failure of auth, pre_auth test produced by culicidae:
[19:20:02.147](0.003s) ok 1 - authenticating connections are recorded in pg_stat_activity
[19:20:02.147](0.000s) # issuing query 4 via background psql: SELECT injection_points_wakeup('init-pre-auth');
[19:20:02.151](0.004s) # results query 4:
# {
# 'stderr' => 'background_psql: QUERY_SEPARATOR 4:
# ',
# 'stdout' => '
# background_psql: QUERY_SEPARATOR 4:
# '
# }
[19:23:02.313](180.162s) # die: IPC::Run: timeout on timer #2 at /usr/share/perl5/IPC/Run.pm line 3361.
[19:23:02.319](0.006s) 1..1
IPC::Run: timeout on timer #2 at /usr/share/perl5/IPC/Run.pm line 3361.
indicates that the test is not bulletproof. I reproduced this locally when
running multiple tests in parallel, and with the following diagnostic
added:
@@ -753,3 +753,5 @@ InitPostgres(const char *in_dbname, Oid dboid,
pgstat_bestart_initial();
+elog(LOG, "!!!before injection_point init-pre-auth");
INJECTION_POINT("init-pre-auth", NULL);
+elog(LOG, "!!!after injection_point init-pre-auth");
}
observed:
23 t/007_pre_auth.pl (Wstat: 7424 (exited 29) Tests: 1 Failed: 0)
23 Non-zero exit status: 29
23 Files=1, Tests=1, 236 wallclock secs ( 0.07 usr 0.02 sys + 0.55 cusr 2.25 csys = 2.89 CPU)
23 Result: FAIL
23 # die: IPC::Run: timeout on timer #2 at /usr/share/perl5/IPC/Run.pm line 3361.
23 # Looks like your test exited with 29 just after 1.
23 make: *** [Makefile:21: check] Error 1
2026-11-01 11:20:41.510 UTC [478942][client backend][2/0:0] LOG: !!!before injection_point init-pre-auth
2026-11-01 11:20:41.510 UTC [478942][client backend][2/0:0] LOG: !!!after injection_point init-pre-auth
2026-11-01 11:20:44.597 UTC [478942][client backend][2/2:0] LOG: statement: SELECT
injection_points_attach('init-pre-auth', 'wait')
2026-11-01 11:20:45.539 UTC [479057][autovacuum worker][101/0:0] LOG: !!!before injection_point init-pre-auth
2026-11-01 11:20:47.346 UTC [479096][client backend][3/0:0] LOG: !!!before injection_point init-pre-auth
2026-11-01 11:20:50.028 UTC [478942][client backend][2/11:0] LOG: statement: SELECT
injection_points_wakeup('init-pre-auth');
2026-11-01 11:20:50.029 UTC [479057][autovacuum worker][101/0:0] LOG: !!!after injection_point init-pre-auth
2026-11-01 11:21:13.777 UTC [479226][autovacuum worker][102/0:0] LOG: !!!before injection_point init-pre-auth
or:
2026-11-01 07:19:21.187 UTC [426308][autovacuum launcher][100/0:0] LOG: !!!before injection_point init-pre-auth
2026-11-01 07:19:21.187 UTC [426308][autovacuum launcher][100/0:0] LOG: !!!after injection_point init-pre-auth
2026-11-01 07:19:21.244 UTC [426365][client backend][2/2:0] LOG: statement: SELECT
injection_points_attach('init-pre-auth', 'wait')
2026-11-01 07:19:21.612 UTC [426309][logical replication launcher][118/0:0] LOG: !!!before injection_point init-pre-auth
2026-11-01 07:19:23.750 UTC [426479][client backend][3/0:0] LOG: !!!before injection_point init-pre-auth
2026-11-01 07:19:25.194 UTC [426365][client backend][2/5:0] LOG: statement: SELECT injection_points_wakeup('init-pre-auth');
2026-11-01 07:19:25.232 UTC [426309][logical replication launcher][118/0:0] LOG: !!!after injection_point init-pre-auth
2026-11-01 07:19:52.568 UTC [427022][autovacuum worker][101/0:0] LOG: !!!before injection_point init-pre-auth
That is, the wakeup can hit autovacuum worker or logical replication
launcher, not the intended client backend. This test failure can be easily
reproduced with:
@@ -753,2 +753,3 @@ InitPostgres(const char *in_dbname, Oid dboid,
pgstat_bestart_initial();
+if (AmRegularBackendProcess()) pg_usleep(1000000);
INJECTION_POINT("init-pre-auth", NULL);
and
echo "autovacuum_naptime = 1s" >/tmp/temp.config
TEMP_CONFIG=/tmp/temp.config PROVE_TESTS="t/007*" make -s check -C src/test/authentication
Reproduced starting from e2080261c.
[1] https://buildfarm.postgresql.org/cgi-bin/show_log.pl?nm=culicidae&dt=2026-10-30%2018%3A10%3A12
Best regards,
Alexander
| From | Date | Subject | |
|---|---|---|---|
| Next Message | jian he | 2026-11-01 13:55:57 | Re: Use a hash table for the regexp cache |
| Previous Message | Kirill Reshke | 2026-11-01 12:13:26 | Re: Internal error codes triggered by regression tests and user queries, take 2 |