Thread
-
Re: Issues with ON CONFLICT UPDATE and REINDEX CONCURRENTLY
Alexander Lakhin <exclusion@gmail.com> — 2025-11-30T17:00:01Z
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