From 79a5911fe65be80d4a4cb6ca6f90ae7d2cc6e9bc Mon Sep 17 00:00:00 2001 From: Michael Paquier Date: Thu, 19 Mar 2026 11:39:31 +0900 Subject: [PATCH] Add more debugging information for bgworker termination tests of worker_spi widowbird has failed again after af8837a10bc7, with the same symptoms of a backend still lying around when attempting a database rename with a bgworker connected to the database being renamed. We are still not sure yet how the failure can be reached, if this is a timing issue in the test or an actual bug in the logic used for interruptible bgworkers. This commit adds more debugging information in the backend to help with the analysis as a temporary measure. Another thing I have noticed is that the queries launching the dynamic bgworkers or checking pg_stat_activity would connect to the database renamed. These are switched to use 'postgres'. That will hopefully remove some of the friction of the test, but I doubt that this is the end of the story. Discussion: https://postgr.es/m/abtJLEAsf1HZXWdR@paquier.xyz --- 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 0104a86b9ec..d1fe3cc71ce 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", + (int) 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 6db80ffec88..b0e6a5376d4 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;