[Alexander Lakhin <exclusion@gmail.com>]

Hello Alvaro,

27.11.2025 14:32, Álvaro Herrera wrote:
> Thanks for reviewing.  I have pushed it now.  Looking at the next one.

I've noticed two failures from skink you could find interesting: [1], [2].
The difference from [2]:
ok 3         - syscache-update-pruned                  94198 ms
not ok 4     - index-concurrently-upsert               14008 ms
ok 5         - reindex-concurrently-upsert             14379 ms

--- /home/bf/bf-build/skink-master/HEAD/pgsql/src/test/modules/injection_points/expected/index-concurrently-upsert.out 
2025-11-27 13:38:19.513528475 +0100
+++ 
/home/bf/bf-build/skink-master/HEAD/pgsql.build/testrun/injection_points/isolation/results/index-concurrently-upsert.out 
2025-11-30 00:10:01.697938769 +0100
@@ -107,6 +107,7 @@
  (1 row)

  s1: NOTICE:  notice triggered for injection point pre-invalidate-catalog-snapshot-end
+s1: NOTICE:  notice triggered for injection point pre-invalidate-catalog-snapshot-end
  step s1_start_upsert: <... completed>
  step s2_start_upsert: <... completed>
  step s3_start_create_index: <... completed>

I've managed to reproduce something similar to this diff when running
multiple test instances under Valgrind with parallel. With the attached
patch applied:
for i in {1..40}; do cp -r src/test/modules/injection_points/ src/test/modules/injection_points_$i/; sed -i.bak 
"s|src/test/modules/injection_points|src/test/modules/injection_points_$i|" 
src/test/modules/injection_points_$i/Makefile; done
make -s check -C src/test/modules/injection_points

and/tmp/extra.config containing:
log_min_messages = INFO
backtrace_functions = 'injection_notice'

for i in {1..10}; do np=5; echo "ITERATION $i"; parallel -j40 --linebuffer --tag PROVE_TESTS="t/099*" NO_TEMP_INSTALL=1 
TEMP_CONFIG=/tmp/extra.config make -s check -C src/test/modules/injection_points_{}  ::: `seq $np` || break; done

gives me:
ITERATION 1
...
4       #   Failed test 'regression tests pass'
4       #   at t/099_isolation_regress.pl line 52.
4       #          got: '256'
4       #     expected: '0'

src/test/modules/injection_points_4/tmp_check/log/regress_log_099_isolation_regress contains:
...
ok 11        - index-concurrently-upsert                5282 ms
not ok 12    - index-concurrently-upsert                6347 ms
ok 13        - index-concurrently-upsert                5723 ms
...
--- .../src/test/modules/injection_points_4/expected/index-concurrently-upsert.out 2025-11-30 14:24:29.385133831 +0200
+++ .../src/test/modules/injection_points_4/tmp_check/results/index-concurrently-upsert.out 2025-11-30 
16:22:29.168920744 +0200
@@ -78,6 +78,7 @@

  (1 row)

+s1: NOTICE:  notice triggered for injection point pre-invalidate-catalog-snapshot-end
  step s4_wakeup_s2:
     SELECT injection_points_detach('exec-insert-before-insert-speculative');
     SELECT injection_points_wakeup('exec-insert-before-insert-speculative');
=== EOF ===

I can see in the following stack trace for this extra notice:
2025-11-30 16:22:28.465 EET|law|isolation_regression|692c531f.bb652|NOTICE:  notice triggered for injection point 
pre-invalidate-catalog-snapshot-end
2025-11-30 16:22:28.465 EET|law|isolation_regression|692c531f.bb652|BACKTRACE:
injection_notice at injection_points.c:278:3
InjectionPointRun at injection_point.c:555:1
InvalidateCatalogSnapshot at snapmgr.c:463:3
LocalExecuteInvalidationMessage at inval.c:831:4
ReceiveSharedInvalidMessages at sinval.c:113:18
AcceptInvalidationMessages at inval.c:970:23
LockRelationOid at lmgr.c:137:3
relation_open at relation.c:58:6
table_open at table.c:44:6
SearchCatCacheMiss at catcache.c:1550:13
SearchCatCacheInternal at catcache.c:1495:9
SearchCatCache1 at catcache.c:1368:1
SearchSysCache1 at syscache.c:227:1
build_coercion_expression at parse_coerce.c:852:8
coerce_type at parse_coerce.c:433:13
coerce_to_target_type at parse_coerce.c:105:11
transformAssignedExpr at parse_target.c:580:4
transformInsertRow at analyze.c:1121:10
transformInsertStmt at analyze.c:988:14
transformStmt at analyze.c:364:13
transformOptionalSelectInto at analyze.c:317:1
transformTopLevelStmt at analyze.c:266:11
parse_analyze_fixedparams at analyze.c:134:10
pg_analyze_and_rewrite_fixedparams at postgres.c:687:10
exec_simple_query at postgres.c:1195:20
PostgresMain at postgres.c:4777:6
BackendInitialize at backend_startup.c:142:1
postmaster_child_launch at launch_backend.c:269:3
BackendStartup at postmaster.c:3598:8
ServerLoop at postmaster.c:1716:10
PostmasterMain at postmaster.c:1403:11
main at main.c:236:2

I also observed:
2025-11-30 15:33:45.746 EET|law|isolation_regression|692c47b4.675e7|NOTICE:  notice triggered for injection point 
pre-invalidate-catalog-snapshot-end
2025-11-30 15:33:45.746 EET|law|isolation_regression|692c47b4.675e7|BACKTRACE:
injection_notice at injection_points.c:278:3
InjectionPointRun at injection_point.c:555:1
InvalidateCatalogSnapshot at snapmgr.c:463:3
LocalExecuteInvalidationMessage at inval.c:831:4
ReceiveSharedInvalidMessages at sinval.c:113:18
AcceptInvalidationMessages at inval.c:970:23
LockRelationOid at lmgr.c:137:3
relation_open at relation.c:58:6
table_open at table.c:44:6
CatalogCacheInitializeCache at catcache.c:1131:13
ConditionalCatalogCacheInitializeCache at catcache.c:1092:1
SearchCatCacheInternal at catcache.c:1424:15
SearchCatCache1 at catcache.c:1368:1
SearchSysCache1 at syscache.c:227:1
check_enable_rls at rls.c:66:10
get_row_security_policies at rowsecurity.c:130:15
fireRIRrules at rewriteHandler.c:2218:3
QueryRewrite at rewriteHandler.c:4581:11
pg_rewrite_query at postgres.c:822:20
pg_analyze_and_rewrite_fixedparams at postgres.c:696:19
exec_simple_query at postgres.c:1195:20
PostgresMain at postgres.c:4777:6
BackendInitialize at backend_startup.c:142:1
postmaster_child_launch at launch_backend.c:269:3
BackendStartup at postmaster.c:3598:8
ServerLoop at postmaster.c:1716:10
PostmasterMain at postmaster.c:1403:11
main at main.c:236:2

Could you please look if this can be fixed?

[1] https://buildfarm.postgresql.org/cgi-bin/show_log.pl?nm=skink&dt=2025-11-25%2021%3A55%3A00
[2] https://buildfarm.postgresql.org/cgi-bin/show_log.pl?nm=skink&dt=2025-11-29%2021%3A51%3A13

Best regards,
Alexander

Attachments:

injection_points-tests-as-TAP.patch (text/x-patch, 3.6K) download
diff --git a/src/test/modules/injection_points/Makefile b/src/test/modules/injection_points/Makefile
index 7b3c0c4b716..46566937d81 100644
--- a/src/test/modules/injection_points/Makefile
+++ b/src/test/modules/injection_points/Makefile
@@ -11,10 +11,10 @@ EXTENSION = injection_points
 DATA = injection_points--1.0.sql
 PGFILEDESC = "injection_points - facility for injection points"
 
-REGRESS = injection_points hashagg reindex_conc vacuum
+XREGRESS = injection_points hashagg reindex_conc vacuum
 REGRESS_OPTS = --dlpath=$(top_builddir)/src/test/regress
 
-ISOLATION = basic \
+XISOLATION = basic \
 	    inplace \
 	    syscache-update-pruned \
 	    index-concurrently-upsert \
@@ -28,6 +28,9 @@ NO_INSTALLCHECK = 1
 
 export enable_injection_points
 
+REGRESS_SHLIB=$(abs_top_builddir)/src/test/regress/regress$(DLSUFFIX)
+export REGRESS_SHLIB
+
 ifdef USE_PGXS
 PG_CONFIG = pg_config
 PGXS := $(shell $(PG_CONFIG) --pgxs)
diff --git a/src/test/modules/injection_points/isolation_schedule b/src/test/modules/injection_points/isolation_schedule
new file mode 100644
index 00000000000..9b71d065309
--- /dev/null
+++ b/src/test/modules/injection_points/isolation_schedule
@@ -0,0 +1,23 @@
+test: basic
+test: inplace
+test: syscache-update-pruned
+test: index-concurrently-upsert
+test: index-concurrently-upsert
+test: index-concurrently-upsert
+test: index-concurrently-upsert
+test: index-concurrently-upsert
+test: index-concurrently-upsert
+test: index-concurrently-upsert
+test: index-concurrently-upsert
+test: index-concurrently-upsert
+test: index-concurrently-upsert
+test: reindex-concurrently-upsert
+test: reindex-concurrently-upsert
+test: reindex-concurrently-upsert
+test: reindex-concurrently-upsert
+test: reindex-concurrently-upsert
+test: reindex-concurrently-upsert
+test: reindex-concurrently-upsert
+test: reindex-concurrently-upsert
+test: reindex-concurrently-upsert
+test: reindex-concurrently-upsert
diff --git a/src/test/modules/injection_points/t/099_isolation_regress.pl b/src/test/modules/injection_points/t/099_isolation_regress.pl
new file mode 100644
index 00000000000..047530c3d6a
--- /dev/null
+++ b/src/test/modules/injection_points/t/099_isolation_regress.pl
@@ -0,0 +1,55 @@
+
+# Copyright (c) 2024, PostgreSQL Global Development Group
+
+# Run the standard regression tests with streaming replication
+use strict;
+use warnings FATAL => 'all';
+use PostgreSQL::Test::Cluster;
+use PostgreSQL::Test::Utils;
+use Test::More;
+use File::Basename;
+
+# Initialize primary node
+my $node_primary = PostgreSQL::Test::Cluster->new('primary');
+$node_primary->init();
+
+# Increase some settings that Cluster->new makes too low by default.
+$node_primary->adjust_conf('postgresql.conf', 'max_connections', '25');
+$node_primary->append_conf('postgresql.conf',
+	'max_prepared_transactions = 10');
+
+$node_primary->start;
+
+my $dlpath = dirname($ENV{REGRESS_SHLIB});
+my $outputdir = $PostgreSQL::Test::Utils::tmp_check;
+
+# Run the regression tests against the primary.
+my $extra_opts = $ENV{EXTRA_REGRESS_OPTS} || "";
+
+my $rc =
+  system( ($ENV{PG_REGRESS} =~ s/regress\/pg_regress/isolation\/pg_isolation_regress/r)
+	  . " $extra_opts "
+	  . "--dlpath=\"$dlpath\" "
+	  . "--bindir= "
+	  . "--host="
+	  . $node_primary->host . " "
+	  . "--port="
+	  . $node_primary->port . " "
+	  . "--schedule=./isolation_schedule "
+	  . "--inputdir=./ "
+	  . "--outputdir=\"$outputdir\"");
+if ($rc != 0)
+{
+	# Dump out the regression diffs file, if there is one
+	my $diffs = "$outputdir/regression.diffs";
+	if (-e $diffs)
+	{
+		print "=== dumping $diffs ===\n";
+		print slurp_file($diffs);
+		print "=== EOF ===\n";
+	}
+}
+is($rc, 0, 'regression tests pass');
+
+
+done_testing();