Subject: RE: [PROPOSAL] Termination of Background Workers for ALTER/DROP DATABASE

From: "Aya Iwata (Fujitsu)" <[email-masked]>
Date: Mon, 5 Jan 2026 15:06:53 +0000

Hi 

Thank you for your comments and suggestions on the previous version patches!	
I believe this feature become much better.

I've created a v13 patch incorporating Peter-san's suggestions.

> One issue with the test as written, as of run_db_command(), is that we
> make sure that a worker is stopped by scanning the output of the logs.
> This approach may detect incorrect patterns, unfortunately.  For
> example, if the termination logic has a bug it may be possible that
> the worker found as terminated is the first one created by the test,
> which we expect to always run.  While the log is mandatory to have, I
> have a suggestion to make that even better: let's keep track in
> run_db_command() of the PIDs of the worker processes we expect to
> exist after running each database command, then make sure that the
> list of PIDs match with what we expect.  This is a bit simpler in the
> case of this test as we only expect one matching PID.

I've also reviewed the test set code comparing PIDs. I think this is acceptable.

Best Regards,
Aya Iwata

---

From: Peter Smith <[email-masked]>
Date: Tue, 6 Jan 2026 08:18:39 +1100

> I've created a v13 patch incorporating Peter-san's suggestions.

Some review comments for v13-0001.

======
src/backend/storage/ipc/procarray.c

CountOtherDBBackends:

1.
  * If there are other backends in the DB, we will wait a maximum of 5 seconds
- * for them to exit.  Autovacuum backends are encouraged to exit early by
- * sending them SIGTERM, but normal user backends are just waited for.
+ * for them to exit.  Autovacuum backends and background workers are encouraged
+ * to exit early by sending them PMSIGNAL_BACKGROUND_WORKER_CHANGE, but normal
+ * user backends are just waited for.

This did not seem like the correct fix for my previous review comment
[1, comment #3], because the autovacuum backends are still killed with
SIGTERM, right?

======
.../worker_spi/t/002_worker_terminate.pl

2.
+# Confirm that the non-interruptible bgworker is still running.
+my $result = $node->safe_psql(
+ "postgres", qq(
+        SELECT count(1) FROM pg_stat_activity
+ WHERE backend_type = 'worker_spi dynamic';));

The indentation of the "SELECT" still does not look correct to me. Did
you run pgperltidy on this file?

======
[1] https://www.postgresql.org/message-id/CAHut%2BPtSVYKU4vfaRev4FMdbeZ3ukvxRy4X7uK05jv_9WMYafA%40mail.gmail.com

Kind Regards,
Peter Smith.
Fujitsu Australia

---

From: Michael Paquier <[email-masked]>
Date: Tue, 6 Jan 2026 14:38:06 +0900

> [1, comment #3], because the autovacuum backends are still killed with

Yes, you are right that this creates a confusing mix.  Bgworkers have
no relationship with SIGTERM in this code.  I have added a sentence to
document the new behavior for interruptible bgworkers, after the
existing ones.  One thing that was also missing is the fact that the
wait can be shortened with the injection point.

> you run pgperltidy on this file?

perltidy is happy with that, because it considers the string within
the quoted qq() area as something fine.  At the end this is just a tab
vs whitespace issue, you are right that this should use whitespaces.

I have done a couple of test runs in the CI to be sure, and noticed no
instability in the tests, so applied.  I'll keep an eye on the CFbot
and the buildfarm for the next few days.
--
Michael

---

From: "Aya Iwata (Fujitsu)" <[email-masked]>
Date: Fri, 13 Mar 2026 11:38:51 +0000

Hi

On March 10th, the bgworker test "t/002_worker_terminate.pl" failed on the Build Farm.
https://buildfarm.postgresql.org/cgi-bin/show_log.pl?nm=jay&dt=2026-03-10%2019%3A26%3A19

We are currently attempting to reproduce this issue and are considering a fix.

According to the log, the test failed because the bgworker cannot be terminated
within the time frame (5 seconds) when ALTER DATABASE RENAME is executed.

So I suspect that there is a lock conflict.

Log of Build Farm;
2026-03-10 21:08:33.103 CET [28076:4] 002_worker_terminate.pl LOG:  statement: ALTER DATABASE testdb RENAME TO renameddb
2026-03-10 21:08:34.578 CET [28071:2] FATAL:  terminating background worker "worker_spi dynamic" due to administrator command
2026-03-10 21:08:38.109 CET [28076:5] 002_worker_terminate.pl ERROR:  database "testdb" is being accessed by other users
2026-03-10 21:08:38.109 CET [28076:6] 002_worker_terminate.pl DETAIL:  There is 1 other session using the database.
2026-03-10 21:08:38.109 CET [28076:7] 002_worker_terminate.pl STATEMENT:  ALTER DATABASE testdb RENAME TO renameddb
2026-03-10 21:08:38.229 CET [28076:8] 002_worker_terminate.pl LOG:  disconnection: session time: 0:00:05.129 user=buildfarm database=postgres host=[local]
2026-03-10 21:08:38.231 CET [28025:6] LOG:  background worker "worker_spi dynamic" (PID 28071) exited with exit code 1
2026-03-10 21:08:38.234 CET [28025:7] LOG:  received immediate shutdown request
2026-03-10 21:08:38.241 CET [28025:8] LOG:  database system is shut down

If there is a lock conflict, we will come up with a solution.

Regards,
Aya Iwata

---

From: Michael Paquier <[email-masked]>
Date: Mon, 16 Mar 2026 16:23:40 +0900

> https://buildfarm.postgresql.org/cgi-bin/show_log.pl?nm=jay&dt=2026-03-10%2019%3A26%3A19

Indeed.

> So I suspect that there is a lock conflict.

Aye, we have a timing issue here, and at first it seemed to me that
this was a bug in the backend logic.  But actually I suspect that it
is simpler than that: we don't disable autovacuum so couldn't an
autovacuum worker connect to the database "testdb" that we are trying
to rename in this query?  I cannot be 100% sure because we have
reduced the log activity for the sake of the tests, but that feels
possible to me.  We could try to disable autovacuum entirely, then see
if the situation gets better in the buildfarm.

The failure rate is so low that it is likely going to take a few weeks
to check the stability of the situation.  We could also lot more
things, of course, as a temporary solution.

What do you think?
--
Michael

---

From: Michael Paquier <[email-masked]>
Date: Tue, 17 Mar 2026 08:37:39 +0900

> things, of course, as a temporary solution.

After sleeping on it, I do not have a better idea than the attached,
so we could always get that into the tree and see if the situation
improves, even if it would take time.  Iwata-san and others, what do
you think?  Perhaps you could think of a different reason causing this
failure?
--
Michael
diff --git a/src/test/modules/worker_spi/t/002_worker_terminate.pl b/src/test/modules/worker_spi/t/002_worker_terminate.pl
index 6d3794355981..21dfb5961289 100644
--- a/src/test/modules/worker_spi/t/002_worker_terminate.pl
+++ b/src/test/modules/worker_spi/t/002_worker_terminate.pl
@@ -59,6 +59,10 @@ sub run_bgworker_interruptible_test
 
 my $node = PostgreSQL::Test::Cluster->new('mynode');
 $node->init;
+$node->append_conf(
+	"postgresql.conf", qq(
+autovacuum = off
+));
 $node->start;
 
 # Check if the extension injection_points is available, as it may be

---

From: Kuroda, Hayato/黒田 隼人<[email-masked]>
Date: Tue, 17 Mar 2026 01:55:05 +0000

Dear Michael,

> you think?  Perhaps you could think of a different reason causing this

I also had a discussion with her off-list, but I could not find neither.
Additional idea is to increase the log level to make analysis easier, but not
sure what value is appropriate. Is it enough to raise to DEBUG1?

Best regards,
Hayato Kuroda
FUJITSU LIMITED

---

From: Michael Paquier <[email-masked]>
Date: Tue, 17 Mar 2026 12:57:59 +0900

> sure what value is appropriate. Is it enough to raise to DEBUG1?

That would be an option.  Let's do that if we see another failure
after disabling autovacuum.  Another thing I have noticed is
debug_parallel_query=regress for this animal, which may encourage
parallel workers, so I have also disabled it.  Let's see first if we
get more failures after af8837a10bc7.
--
Michael

---

From: Alexander Lakhin <[email-masked]>
Date: Tue, 17 Mar 2026 08:00:00 +0200

Hello Michael and Iwata-san,

> get more failures after af8837a10bc7.

I've noticed another failure of the test from widowbird: [1]. But probably
it's not related to f1e251be8 directly, as widowbird failed with a similar
error before: [2]. I couldn't reproduce such failures yet, but keep
trying in the background...

[1] https://buildfarm.postgresql.org/cgi-bin/show_log.pl?nm=widowbird&dt=2026-03-16%2009%3A35%3A03
[2] https://buildfarm.postgresql.org/cgi-bin/show_log.pl?nm=widowbird&dt=2025-10-25%2010%3A35%3A03

Best regards,
Alexander

---

From: Michael Paquier <[email-masked]>
Date: Tue, 17 Mar 2026 17:33:25 +0900

> [2] https://buildfarm.postgresql.org/cgi-bin/show_log.pl?nm=widowbird&dt=2025-10-25%2010%3A35%3A03

Thanks.  widowbird also uses "debug_parallel_query = regress", so it
really looks like to me that this is related to a parallel worker
spawning and messing with the database being renamed.
--
Michael

---

From: Michael Paquier <[email-masked]>
Date: Thu, 19 Mar 2026 09:54:04 +0900

On Wed, Mar 18, 2026 at 03:52:02PM -0400, Tom Lane wrote:
> which makes me wonder whether the problematic session is the second or
> third bgworker.  I am not seeing entries indicating that those
> stopped, as there is for the first bgworker.

Looking at the logs produced at [1], the worker launched as number 1
would not be able to interact, it connects to the database postgres,
under PID 1616001, and is reported as exited by the postmaster.

The only interacting sessions would be:
1) The bgworker launched as number 2, connected to database testdb.
2) The session checking for pg_stat_activity, launched by
launch_bgworker().  The test was connected with the database we want
to rename, and this could interact as an extra session.  This query
could be run while connected to the database postgres to reduce the
friction and discarding this one.

The timestamps of the logs tell that it takes 5 seconds for this host
to get out of the ALTER DATABASE .. RENAME TO, which implies that we
are looping inside CountOtherDBBackends() for 5 seconds.  So it really
looks like the second bgworker is the one we are waiting for here.
Now, we are sure of the following things when we try to launch the
RENAME TO:
- The worker is seen in pg_stat_activity.
- The worker is already in worker_spi_main(), per its "LOG initialized
with" entry.
- The worker is connected to the database.
- The worker can receive signals.

How would it be possible for this worker to not receive the requests?
The only thing I could think of is that the postmaster does not have
the time to process the PMSIGNAL_BACKGROUND_WORKER_CHANGE requests?

The next thing would be to gather more data, I guess.  The attached
would help in providing more information.  If it happens that we are
able to send the requests and that the postmaster does not have the
time to process them, I don't really see what we can do except:
- Drop the portion of the tests for DROP DATABASE, SET TABLESPACE and
RENAME DB, because all these scenarios involve commands that work on
the same database as the worker connected, and if the postmaster does
not have the time to process the termination requests, I don't really
see what we could do.  This could also point to a timing issue with
the feature in itself, of course.
- Revert the feature, stop playing with the buildfarm due to the end
of the release cycle, and rework it for v20.

For now I am planning for the attached to get more information from
widowbird, which should take a few days at worst.  That would make
clear if we have a timing issue with the requests sent to the
postmaster.  Launching the queries for worker_spi_launch() and
pg_stat_activity on the database postgres may also improve things, but
I don't really buy it, even if I may be wrong.

[1]: https://buildfarm.postgresql.org/cgi-bin/show_log.pl?nm=widowbird&dt=2026-03-17%2015%3A35%3A03
--
Michael
From adb474866f12a66ac48c702d9ab25ce82277abca Mon Sep 17 00:00:00 2001
From: Michael Paquier <[email-masked]>
Date: Thu, 19 Mar 2026 09:51:16 +0900
Subject: [PATCH] Add more debugging information for termination tests of
 worker_spi

---
 src/backend/postmaster/bgworker.c                     |  6 ++++++
 src/test/modules/worker_spi/t/002_worker_terminate.pl | 10 ++++++++--
 2 files changed, 14 insertions(+), 2 deletions(-)

diff --git a/src/backend/postmaster/bgworker.c b/src/backend/postmaster/bgworker.c
index 0104a86b9ecd..fd678ef2596d 100644
--- a/src/backend/postmaster/bgworker.c
+++ b/src/backend/postmaster/bgworker.c
@@ -1413,6 +1413,9 @@ TerminateBackgroundWorkersForDatabase(Oid databaseId)
 {
 	bool		signal_postmaster = false;
 
+	elog(DEBUG1, "attempting worker termination for database %u",
+		 databaseId);
+
 	LWLockAcquire(BackgroundWorkerLock, LW_EXCLUSIVE);
 
 	/*
@@ -1432,6 +1435,9 @@ TerminateBackgroundWorkersForDatabase(Oid databaseId)
 			{
 				slot->terminate = true;
 				signal_postmaster = true;
+
+				elog(DEBUG1, "termination requested for worker (PID %d) on database %u",
+					 slot->pid, databaseId);
 			}
 		}
 	}
diff --git a/src/test/modules/worker_spi/t/002_worker_terminate.pl b/src/test/modules/worker_spi/t/002_worker_terminate.pl
index 6db80ffec88c..b0e6a5376d4c 100644
--- a/src/test/modules/worker_spi/t/002_worker_terminate.pl
+++ b/src/test/modules/worker_spi/t/002_worker_terminate.pl
@@ -24,7 +24,7 @@ sub launch_bgworker
 
 	# Launch a background worker on the given database.
 	my $pid = $node->safe_psql(
-		$database, qq(
+		'postgres', qq(
         SELECT worker_spi_launch($testcase, '$database'::regdatabase, 0, '{}', $interruptible);
     ));
 
@@ -32,7 +32,7 @@ sub launch_bgworker
 	$node->wait_for_log(
 		qr/LOG: .*worker_spi dynamic worker $testcase initialized with .*\..*/,
 		$offset);
-	my $result = $node->safe_psql($database,
+	my $result = $node->safe_psql('postgres',
 		"SELECT count(*) > 0 FROM pg_stat_activity WHERE pid = $pid;");
 	is($result, 't', "dynamic bgworker $testcase launched");
 
@@ -52,6 +52,11 @@ sub run_bgworker_interruptible_test
 		qr/terminating background worker \"worker_spi dynamic\" due to administrator command/,
 		$offset);
 
+	# Postmaster entry reporting the worker as exiting.
+	$node->wait_for_log(
+		qr/LOG: .*background worker \"worker_spi dynamic\" \(PID $pid\) exited with exit code/,
+		$offset);
+
 	my $result = $node->safe_psql('postgres',
 		"SELECT count(*) = 0 FROM pg_stat_activity WHERE pid = $pid;");
 	is($result, 't', "dynamic bgworker stopped for $testname");
@@ -63,6 +68,7 @@ $node->append_conf(
 	"postgresql.conf", qq(
 autovacuum = off
 debug_parallel_query = off
+log_min_messages = debug1
 ));
 $node->start;
 
-- 
2.53.0

---

From: Michael Paquier <[email-masked]>
Date: Sat, 21 Mar 2026 11:46:23 +0900

> I don't really buy it, even if I may be wrong.

A couple of days later after 79a5911fe65b, widowbird seems to have
cooled down a bit:
https://buildfarm.postgresql.org/cgi-bin/show_history.pl?nm=widowbird&br=master

The extra debugging information is proving to be useful.  For example,
looking at this one for the RENAME TO case:
https://buildfarm.postgresql.org/cgi-bin/show_stage_log.pl?nm=widowbird&dt=2026-03-19%2003%3A35%3A03&stg=module-worker_spi-check

And some problematic pattern logs:
2026-03-19 04:49:07.848 UTC [271557:4] 002_worker_terminate.pl LOG:
statement: ALTER DATABASE testdb RENAME TO renameddb  
2026-03-19 04:49:07.849 UTC [271557:5] 002_worker_terminate.pl DEBUG:
attempting worker termination for database 16413  
2026-03-19 04:49:07.849 UTC [271557:6] 002_worker_terminate.pl DEBUG:
termination requested for worker (PID 271553) on database 16413
[...]
2026-03-19 04:49:08.732 UTC [271557:19] 002_worker_terminate.pl DEBUG:
attempting worker termination for database 16413  
2026-03-19 04:49:08.732 UTC [271557:20] 002_worker_terminate.pl DEBUG:
termination requested for worker (PID 271553) on database 16413  

So we are able to send the requests to the workers, and these can take
a long time before being processed by the postmaster.  Querying
directly "postgres" for the worker_spi_launch() and pg_stat_activity
queries seems to have reduced the friction, with less requests to
send.   However, I don't think that this is the end of the story, even
after 79a5911fe65b I have spotted one case of RENAME TO where the
requests were sent for a bit more than 4s, before the postmaster had
the idea to catch up.  RENAME TO is the only one that can get slow
(really no idea why), so I guess that we could always tweak things a
bit more:
1) Extra injection point to increase the timeout (30s or 60s?) and
give the postmaster more room to proceed the requests.
2) Remove this portion of the test, but it would be sad.

I'll keep an eye for more failures, even if the situation is looking
slightly better.
--
Michael

---

From: Alexander Lakhin <[email-masked]>
Date: Tue, 31 Mar 2026 10:00:00 +0300

Hello Michael,

> I'll keep an eye for more failures, even if the situation is looking

Having reproduced this locally (running 3 tests in parallel with
ALTER DATABASE RENAME repeated 200 times, on a slow riscv64 machine), I
discovered that in the bad case the worker doesn't reach the main loop in
time (and CHECK_FOR_INTERRUPTS() inside it), because it doesn't get out of
initialize_worker_spi() -> CommitTransactionCommand().

With this modification:
--- a/src/backend/storage/ipc/procarray.c
+++ b/src/backend/storage/ipc/procarray.c
@@ -3752,3 +3752,3 @@ CountOtherDBBackends(Oid databaseId, int *nbackends, int *nprepared)
          */
-       int                     ntries = 50;
+       int                     ntries = 500;

@@ -3798,3 +3798,6 @@ CountOtherDBBackends(Oid databaseId, int *nbackends, int *nprepared)
                 if (!found)
+{
+elog(LOG, "!!!CountOtherDBBackends| found no backends, try %d", tries);
                         return false;           /* no conflicting backends, so done */
+}

I can see the following:
... !!!CountOtherDBBackends| found no backends, try 1
# most of the calls (200 of 201) succeeded with try 1, but there are also:
... !!!CountOtherDBBackends| found no backends, try 7
... !!!CountOtherDBBackends| found no backends, try 51
... !!!CountOtherDBBackends| found no backends, try 74
... !!!CountOtherDBBackends| found no backends, try 84

So the backend is not completely stuck, but CommitTransactionCommand()
may take more than 5 seconds under some circumstances (maybe it's worth
investigating which exactly).

Best regards,
Alexander

---

From: Michael Paquier <[email-masked]>
Date: Tue, 31 Mar 2026 19:54:30 +0900

> investigating which exactly).

One could blame slow hardware, difficult to say, and I'm puzzled by
these periodic bumps that don't seem to happen elsewhere.  There is at
least one alternative that I can think here to make the test more
stable and make sure that worker_spi reaches its main loop before
attempting the database commands.  We could add a wait_for_event() at
the end of launch_bgworker() based on WorkerSpiMain, and enlarge
worker_spi_naptime to an insanely larger value, to make sure that we
remain on the WaitLatch() until the worker is interrupted and that we
don't attempt a new transaction.
--
Michael

---

From: Alexander Lakhin <[email-masked]>
Date: Tue, 31 Mar 2026 20:00:00 +0300

31.03.2026 13:54, Michael Paquier wrote:
> these periodic bumps that don't seem to happen elsewhere.

I managed to get the backtrace of such a sluggish backend:
Using host libthread_db library "/lib/riscv64-linux-gnu/libthread_db.so.1".
0x0000003fb1f4cc26 in posix_fadvise64 () from /lib/riscv64-linux-gnu/libc.so.6
   Id   Target Id                                   Frame
* 1    Thread 0x3fb2a4c620 (LWP 564194) "postgres" 0x0000003fb1f4cc26 in posix_fadvise64 () from 
/lib/riscv64-linux-gnu/libc.so.6
#0  0x0000003fb1f4cc26 in posix_fadvise64 () from /lib/riscv64-linux-gnu/libc.so.6
#1  0x0000002abef79444 in XLogFileClose () at xlog.c:3672
#2  0x0000002abef7cc66 in XLogWrite (WriteRqst=..., tli=tli@entry=1, flexible=flexible@entry=false) at xlog.c:2356
#3  0x0000002abef7dbfc in XLogFlush (record=33561688) at xlog.c:2892
#4  0x0000002abef77976 in RecordTransactionCommit () at xact.c:1516
#5  CommitTransaction () at xact.c:2379
#6  0x0000002abef78938 in CommitTransactionCommandInternal () at xact.c:3224
#7  0x0000002abef78acc in CommitTransactionCommand () at xact.c:3185
#8  0x0000003fb2a3ed88 in initialize_worker_spi (table=0x2abf8bf358) at worker_spi.c:132
#9  worker_spi_main (main_arg=<optimized out>) at worker_spi.c:181
....
(Three test runs produced the same stack trace.)

I think this can explain slow CommitTransactionCommand() and why it
happens not every time. Regarding other animals, I guess they can
experience the same bumps but not exceeding 5 seconds (50 tries). Thus,
from my understanding, for the failure to happen, we need to have slow
storage and initialize_worker_spi() -> CommitTransactionCommand() reaching
XLogFileClose().

Best regards,
Alexander