Random 038_walsnd_shutdown_timeout.pl failure on goldfish

Started by Hayato Kuroda (Fujitsu)17 days ago6 messageshackers
Beta feature

Hackorum builds and tests every patch posted to the lists, not only commitfest submissions. This is Hackorum's own CI rather than the PostgreSQL project's, and it is still under testing - please report anything that looks wrong.

won't retrysuccessCI history

This thread has been committed, so CI has stopped here. Anything below is the last result it produced.

You can run a PostgreSQL built from this patch straight from Docker, with no checkout and no build:

docker run --rm -p 5432:5432 ghcr.io/hackorum-dev/postgres-patch:t253342
psql -h localhost -U postgres

Built from patchset v1 (message #1), August 11, 2026 at 08:27 AM.

Every patchset is also pushed to a branch of our PostgreSQL fork, so you can check out the same tree CI built. Without a PostgreSQL checkout:

git clone --branch t253342_1 https://github.com/hackorum-dev/postgres.git

In a checkout you already have, add the fork once:

git remote add hackorum https://github.com/hackorum-dev/postgres.git

then, for this patchset and every later one:

git fetch hackorum t253342_1 && git checkout t253342_1

Patchset v1 (message #1) is on t253342_1

Jump to latest
#1Hayato Kuroda (Fujitsu)
kuroda.hayato@fujitsu.com

Hi hackers,

An animal goldfish failed subscription/038_walsnd_shutdown_timeout [1]https://buildfarm.postgresql.org/cgi-bin/show_log.pl?nm=goldfish&dt=2026-07-31%2018%3A15%3A06.

IIUC, this failure occurs because the timeout associated with the background psql
session $sub_session expires. The failure can be reproduced by adding a long sleep
after the background session has been created but before it is used again, for
example:

```diff
--- a/src/test/subscription/t/038_walsnd_shutdown_timeout.pl
+++ b/src/test/subscription/t/038_walsnd_shutdown_timeout.pl
@@ -152,6 +152,8 @@ $node_publisher->backup(
                'dbname=postgres', '--write-recovery-conf'
        ]);
+sleep(180);
+
```

BackgroundPsql uses an IPC::Run::Timer [2]https://metacpan.org/pod/IPC::Run::Timer to implement a timeout. The timer is
passed to IPC::Run::start() when the background psql process is launched, and
the default timeout interval is 180 seconds. Unless explicitly restarted,
the timer continues to run for the lifetime of the background session, rather
than starting for each query.

According to the test code and logs, $sub_session had already been created before
a new backup was taken from the publisher. The base backup itself took about
100 seconds, and approximately 172 seconds elapsed between two uses of
$sub_session->query_safe(). As a result, by the time the later query was issued,
almost all of the background session's timeout interval had already been consumed,
and IPC::Run reported a timeout shortly afterwards.

I have not determined why the base backup took unusually long on this machine,
but I don't think the duration of unrelated operations should consume the timeout
budget of a later background query.

BackgroundPsql::set_query_timer_restart() causes the timer to be restarted before
each query. The attached patch uses it for $sub_session, so that each background
query gets a fresh timeout interval.

How do you feel?

[1]: https://buildfarm.postgresql.org/cgi-bin/show_log.pl?nm=goldfish&dt=2026-07-31%2018%3A15%3A06
[2]: https://metacpan.org/pod/IPC::Run::Timer

Best regards,
Hayato Kuroda
FUJITSU LIMITED

Attachments:

t253342_1
0001-Stablize-038_walsnd_shutdown_timeout.patchapplication/octet-stream; name=0001-Stablize-038_walsnd_shutdown_timeout.patchDownload+1-1
#2Daniel Gustafsson
daniel@yesql.se
In reply to: Hayato Kuroda (Fujitsu) (#1)
Re: Random 038_walsnd_shutdown_timeout.pl failure on goldfish

On 7 Aug 2026, at 11:07, Hayato Kuroda (Fujitsu) <kuroda.hayato@fujitsu.com> wrote:

BackgroundPsql::set_query_timer_restart() causes the timer to be restarted before
each query. The attached patch uses it for $sub_session, so that each background
query gets a fresh timeout interval.

Given that there is a backup involved, that seems like a reasonable fix.

--
Daniel Gustafsson

#3Hayato Kuroda (Fujitsu)
kuroda.hayato@fujitsu.com
In reply to: Daniel Gustafsson (#2)
RE: Random 038_walsnd_shutdown_timeout.pl failure on goldfish

Dear Daniel,

Given that there is a backup involved, that seems like a reasonable fix.

Thanks for the confirmation!

Forgot to say: this test was added by a8f45de, must be backpatched for REL_19_STABLE.

Best regards,
Hayato Kuroda
FUJITSU LIMITED

#4Bertrand Drouvot
bertranddrouvot.pg@gmail.com
In reply to: Hayato Kuroda (Fujitsu) (#3)
Re: Random 038_walsnd_shutdown_timeout.pl failure on goldfish

Hi,

On Fri, Aug 07, 2026 at 10:03:27AM +0000, Hayato Kuroda (Fujitsu) wrote:

Dear Daniel,

Given that there is a backup involved, that seems like a reasonable fix.

Thanks for the confirmation!

Forgot to say: this test was added by a8f45de, must be backpatched for REL_19_STABLE.

FWIW, goldfish was slow at that time. It's now fixed, but +1 for the patch.

Regards,

--
Bertrand Drouvot
PostgreSQL Contributors Team
RDS Open Source Databases
Amazon Web Services: https://aws.amazon.com

#5Daniel Gustafsson
daniel@yesql.se
In reply to: Bertrand Drouvot (#4)
Re: Random 038_walsnd_shutdown_timeout.pl failure on goldfish

On 8 Aug 2026, at 15:11, Bertrand Drouvot <bertranddrouvot.pg@gmail.com> wrote:

FWIW, goldfish was slow at that time. It's now fixed,

Thanks for confirming.

but +1 for the patch.

Agreed, a temporarily slow/overloaded etc buildfarm machine shouldn't cause
this failure so I will go ahead with the patch during next week.

--
Daniel Gustafsson

#6Fujii Masao
masao.fujii@gmail.com
In reply to: Daniel Gustafsson (#5)
Re: Random 038_walsnd_shutdown_timeout.pl failure on goldfish

On Sun, Aug 9, 2026 at 4:27 AM Daniel Gustafsson <daniel@yesql.se> wrote:

but +1 for the patch.

Agreed, a temporarily slow/overloaded etc buildfarm machine shouldn't cause
this failure

+1

so I will go ahead with the patch during next week.

Thanks!

Regards,

--
Fujii Masao