Re: Eliminating SPI / SQL from some RI triggers - take 3

From: Daniel Gustafsson <daniel(at)yesql(dot)se>
To: Amit Langote <amitlangote09(at)gmail(dot)com>
Cc: Junwang Zhao <zhjwpku(at)gmail(dot)com>, Chao Li <li(dot)evan(dot)chao(at)gmail(dot)com>, Haibo Yan <tristan(dot)yim(at)gmail(dot)com>, Pavel Stehule <pavel(dot)stehule(at)gmail(dot)com>, PostgreSQL Hackers <pgsql-hackers(at)postgresql(dot)org>, Tomas Vondra <tomas(at)vondra(dot)me>
Subject: Re: Eliminating SPI / SQL from some RI triggers - take 3
Date: 2026-03-31 11:35:33
Message-ID: F0A892CA-B2AE-42CF-A0D5-5C3B23A07F72@yesql.se
Views: Whole Thread | Raw Message | Download mbox | Resend email
Thread:
Lists: pgsql-hackers

> On 31 Mar 2026, at 13:26, Amit Langote <amitlangote09(at)gmail(dot)com> wrote:
>
> On Tue, Mar 31, 2026 at 8:22 PM Daniel Gustafsson <daniel(at)yesql(dot)se> wrote:
>>> On 31 Mar 2026, at 12:57, Junwang Zhao <zhjwpku(at)gmail(dot)com> wrote:
>>
>>> prion is happy now, the fix works, thanks.
>>
>> The widowbird failure seems to be SPI related as well, relevant portion of log
>> below. Is that the same or another error?
>
> prion was unhappy about something else, which I've fixed:
> https://www.postgresql.org/message-id/E1w7U6V-002H6n-0o%40gemulon.postgresql.org
>
> Though, I'm not sure if or why the fix is now the reason for
> widowbird's failure.
>
>> echo "# +++ tap install-check in src/test/modules/worker_spi +++" && rm -rf '/mnt/data/buildfarm/buildroot/HEAD/pgsql.build/src/test/modules/worker_spi'/tmp_check && /usr/bin/mkdir -p '/mnt/data/buildfarm/buildroot/HEAD/pgsql.build/src/test/modules/worker_spi'/tmp_check && cd . && TESTLOGDIR='/mnt/data/buildfarm/buildroot/HEAD/pgsql.build/src/test/modules/worker_spi/tmp_check/log' TESTDATADIR='/mnt/data/buildfarm/buildroot/HEAD/pgsql.build/src/test/modules/worker_spi/tmp_check' PATH="/mnt/data/buildfarm/buildroot/HEAD/inst/bin:/mnt/data/buildfarm/buildroot/HEAD/pgsql.build/src/test/modules/worker_spi:$PATH" PGPORT='65678' top_builddir='/mnt/data/buildfarm/buildroot/HEAD/pgsql.build/src/test/modules/worker_spi/../../../..' PG_REGRESS='/mnt/data/buildfarm/buildroot/HEAD/pgsql.build/src/test/modules/worker_spi/../../../../src/test/regress/pg_regress' share_contrib_dir='/mnt/data/buildfarm/buildroot/HEAD/inst/share/postgresql/extension' /usr/bin/prove -I ../../../../src/test/perl/ -I . t/*.pl
>> # +++ tap install-check in src/test/modules/worker_spi +++
>> t/001_worker_spi.pl ........ ok
>> # Tests were run but no plan was declared and done_testing() was not seen.
>> # Looks like your test exited with 29 just after 8.
>> t/002_worker_terminate.pl ..
>> Dubious, test returned 29 (wstat 7424, 0x1d00)
>> All 8 subtests passed
>>
>> Test Summary Report
>> -------------------
>> t/002_worker_terminate.pl (Wstat: 7424 (exited 29) Tests: 8 Failed: 0)
>> Non-zero exit status: 29
>> Parse errors: No plan found in TAP output
>> Files=2, Tests=16, 28 wallclock secs ( 0.08 usr 0.01 sys + 6.63 cusr 2.93 csys = 9.65 CPU)
>> Result: FAIL
>> make[1]: *** [../../../../src/makefiles/pgxs.mk:439: installcheck] Error 1
>> make[1]: Leaving directory '/mnt/data/buildfarm/buildroot/HEAD/pgsql.build/src/test/modules/worker_spi'
>> make: *** [Makefile:87: installcheck-worker_spi-recurse] Error 2
>> log files for step testmodules-install-check-en_GB.UTF-8:
>
> Not sure what's going on here or how it's related to 68a8601ee.

Not sure either, I just saw SPI when digging and wanted to check, but I agree
that it doesn't seem related. More log excerpts:

[11:15:49.966](3.762s) ok 1 - dynamic bgworker 0 launched
[11:15:50.372](0.407s) ok 2 - background worker blocked the database creation
[11:15:50.413](0.041s) ok 3 - background worker is still running after CREATE DATABASE WITH TEMPLATE
[11:15:50.663](0.250s) ok 4 - dynamic bgworker 1 launched
[11:15:51.085](0.421s) ok 5 - dynamic bgworker stopped for CREATE DATABASE WITH TEMPLATE
[11:15:51.264](0.179s) ok 6 - dynamic bgworker 2 launched
[11:15:51.438](0.175s) ok 7 - dynamic bgworker stopped for ALTER DATABASE RENAME
[11:15:51.655](0.216s) ok 8 - dynamic bgworker 3 launched
error running SQL: 'psql:<stdin>:1: ERROR: database "renameddb" is being accessed by other users
DETAIL: There is 1 other session using the database.'
while running 'psql --no-psqlrc --no-align --tuples-only --quiet --dbname port=17048 host=/mnt/data/buildfarm/buildroot/tmp/Li3aVcqeUa dbname='postgres' --file - --variable ON_ERROR_STOP=1' with sql 'ALTER DATABASE renameddb SET TABLESPACE test_tablespace' at /mnt/data/buildfarm/buildroot/HEAD/pgsql.build/src/test/modules/worker_spi/../../../../src/test/perl/PostgreSQL/Test/Cluster.pm line 2335.
# Postmaster PID for node "mynode" is 792281
### Stopping node "mynode" using mode immediate
# Running: pg_ctl --pgdata /mnt/data/buildfarm/buildroot/HEAD/pgsql.build/src/test/modules/worker_spi/tmp_check/t_002_worker_terminate_mynode_data/pgdata --mode immediate stop
waiting for server to shut down...... done
server stopped
# No postmaster PID for node "mynode"
[11:16:02.658](11.003s) # Tests were run but no plan was declared and done_testing() was not seen.
[11:16:02.659](0.001s) # Looks like your test exited with 29 just after 8.

2026-03-31 11:15:51.686 UTC [792340:4] 002_worker_terminate.pl LOG: statement: ALTER DATABASE renameddb SET TABLESPACE test_tablespace
2026-03-31 11:15:51.687 UTC [792340:5] 002_worker_terminate.pl DEBUG: attempting worker termination for database 16413
2026-03-31 11:15:51.687 UTC [792340:6] 002_worker_terminate.pl DEBUG: termination requested for worker (PID 792336) on database 16413
2026-03-31 11:15:51.787 UTC [792340:7] 002_worker_terminate.pl DEBUG: attempting worker termination for database 16413
2026-03-31 11:15:51.787 UTC [792340:8] 002_worker_terminate.pl DEBUG: termination requested for worker (PID 792336) on database 16413
2026-03-31 11:15:51.887 UTC [792340:9] 002_worker_terminate.pl DEBUG: attempting worker termination for database 16413
2026-03-31 11:15:51.887 UTC [792340:10] 002_worker_terminate.pl DEBUG: termination requested for worker (PID 792336) on database 16413
<-- snip -->
2026-03-31 11:15:57.088 UTC [792340:102] 002_worker_terminate.pl DEBUG: termination requested for worker (PID 792336) on database 16413
2026-03-31 11:15:57.188 UTC [792340:103] 002_worker_terminate.pl DEBUG: attempting worker termination for database 16413
2026-03-31 11:15:57.188 UTC [792340:104] 002_worker_terminate.pl DEBUG: termination requested for worker (PID 792336) on database 16413
2026-03-31 11:15:57.288 UTC [792340:105] 002_worker_terminate.pl ERROR: database "renameddb" is being accessed by other users
2026-03-31 11:15:57.288 UTC [792340:106] 002_worker_terminate.pl DETAIL: There is 1 other session using the database.
2026-03-31 11:15:57.288 UTC [792340:107] 002_worker_terminate.pl STATEMENT: ALTER DATABASE renameddb SET TABLESPACE test_tablespace
2026-03-31 11:15:57.289 UTC [792340:108] 002_worker_terminate.pl LOG: disconnection: session time: 0:00:05.611 user=buildfarm database=postgres host=[local]
2026-03-31 11:15:57.300 UTC [792281:23] LOG: received immediate shutdown request
2026-03-31 11:15:57.300 UTC [792281:24] DEBUG: updating PMState from PM_RUN to PM_WAIT_BACKENDS
2026-03-31 11:16:02.309 UTC [792281:25] LOG: issuing SIGKILL to recalcitrant children
2026-03-31 11:16:02.547 UTC [792281:26] DEBUG: updating PMState from PM_WAIT_BACKENDS to PM_WAIT_DEAD_END
2026-03-31 11:16:02.547 UTC [792281:27] DEBUG: updating PMState from PM_WAIT_DEAD_END to PM_NO_CHILDREN
2026-03-31 11:16:02.574 UTC [792281:28] LOG: database system is shut down

--
Daniel Gustafsson

In response to

Responses

Browse pgsql-hackers by date

  From Date Subject
Next Message Hayato Kuroda (Fujitsu) 2026-03-31 11:39:01 RE: Initial COPY of Logical Replication is too slow
Previous Message Amit Langote 2026-03-31 11:26:35 Re: Eliminating SPI / SQL from some RI triggers - take 3