Stabilize recovery conflict stats checks in 031_recovery_conflict.pl

Hi,

On Wed, 2 Sept 2026 at 13:15, Fujii Masao <masao.fujii@gmail.com> wrote:

Hi,

I investigated the 031_recovery_conflict.pl test failure reported by
buildfarm member akepa [1], since it occurred just after the commit
I pushed. But that seems unrelated to that commit.

[01:46:23.473](0.028s) not ok 12 - tablespace conflict: stats show
conflict on standby
[01:46:23.474](0.001s) # Failed test 'tablespace conflict: stats
show conflict on standby'
# at
/home/buildfarm/build-farm-21/buildroot/REL_19_STABLE/pgsql/src/test/recovery/t/
031_recovery_conflict.pl
line 332.
[01:46:23.474](0.000s) # got: '0'
# expected: '1'

The test saw a recovery conflict counter of 0 when it expected 1.
Since the standby log contained the expected tablespace conflict
message, the conflict itself had already occurred. But, ISTM that
the counter in pg_stat_database_conflicts had not been updated yet
when the test checked it immediately afterward, causing the failure.
That is, there seems no guarantee that the conflict counter has been
flushed and become visible even after the conflict message has been
logged.

To fix this issue, I'd like to propose the attached patch that changes
the test to poll until the expected counter becomes visible instead of
checking it only once.

Thoughts?

Regards,

[1]
https://buildfarm.postgresql.org/cgi-bin/show_log.pl?nm=akepa&amp;dt=2026-09-02%2005%3A43%3A06

Thanks for the patch.

Polling for the exact expected value seems reasonable, since the
conflict can be logged before the canceled backend's pending stats
become visible.

Patch lgtm.

Regards,
Ayush

Hi,

Thank you for working on this!

On Wed, 2 Sept 2026 at 10:45, Fujii Masao <masao.fujii@gmail.com> wrote:

I investigated the 031_recovery_conflict.pl test failure reported by
buildfarm member akepa [1], since it occurred just after the commit
I pushed. But that seems unrelated to that commit.

I saw 031_recovery_conflict.pl failure on CI at least a couple times,
but I am not sure if they originated from the same problem, though.

[01:46:23.473](0.028s) not ok 12 - tablespace conflict: stats show
conflict on standby
[01:46:23.474](0.001s) # Failed test 'tablespace conflict: stats
show conflict on standby'
# at /home/buildfarm/build-farm-21/buildroot/REL_19_STABLE/pgsql/src/test/recovery/t/031_recovery_conflict.pl
line 332.
[01:46:23.474](0.000s) # got: '0'
# expected: '1'

The test saw a recovery conflict counter of 0 when it expected 1.
Since the standby log contained the expected tablespace conflict
message, the conflict itself had already occurred. But, ISTM that
the counter in pg_stat_database_conflicts had not been updated yet
when the test checked it immediately afterward, causing the failure.
That is, there seems no guarantee that the conflict counter has been
flushed and become visible even after the conflict message has been
logged.

I am able to reproduce your test case by adding sleep before
pgstat_report_stat(true):

```
diff --git a/src/backend/utils/activity/pgstat.c
b/src/backend/utils/activity/pgstat.c
index 4615f610106..325092008d7 100644
--- a/src/backend/utils/activity/pgstat.c
+++ b/src/backend/utils/activity/pgstat.c
@@ -659,6 +659,7 @@ pgstat_shutdown_hook(int code, Datum arg)
        if (OidIsValid(MyDatabaseId))
                pgstat_report_disconnect(MyDatabaseId);

+ pg_usleep(100000);
pgstat_report_stat(true);

/* there shouldn't be any pending changes left *
```

Then 'recovery/031_recovery_conflict' test is failed with:

```
# test failed
----------------------------------- stderr -----------------------------------
# Failed test 'snapshot conflict: stats show conflict on standby'
# at /home/nbyavuz/Desktop/projects/postgres/src/test/recovery/t/031_recovery_conflict.pl
line 332.
# got: '0'
# expected: '1'
# Failed test 'lock conflict: stats show conflict on standby'
# at /home/nbyavuz/Desktop/projects/postgres/src/test/recovery/t/031_recovery_conflict.pl
line 332.
# got: '0'
# expected: '1'
# Failed test 'tablespace conflict: stats show conflict on standby'
# at /home/nbyavuz/Desktop/projects/postgres/src/test/recovery/t/031_recovery_conflict.pl
line 332.
# got: '0'
# expected: '1'
# Failed test 'startup deadlock: stats show conflict on standby'
# at /home/nbyavuz/Desktop/projects/postgres/src/test/recovery/t/031_recovery_conflict.pl
line 332.
# got: '0'
# expected: '1'
# Looks like you failed 4 tests of 18.

(test program exited with status code 4)
```

To fix this issue, I'd like to propose the attached patch that changes
the test to poll until the expected counter becomes visible instead of
checking it only once.

I confirm that your patch fixes the problem and LGTM.

In addition to that, 'test_custom_stats/001_custom_stats' started to
fail with similar race condition when I increased timeout from 100000
to 1000000:

```
# Failed test 'report for variable-sized data of entry1'
# at /home/nbyavuz/Desktop/projects/postgres/src/test/modules/test_custom_stats/t/001_custom_stats.pl
line 80.
# got: 'entry1|0|Test entry 1'
# expected: 'entry1|2|Test entry 1'
# Failed test 'report for variable-sized data of entry2'
# at /home/nbyavuz/Desktop/projects/postgres/src/test/modules/test_custom_stats/t/001_custom_stats.pl
line 86.
# got: 'entry2|0|Test entry 2'
# expected: 'entry2|3|Test entry 2'
# Failed test 'report for variable-sized data of entry3'
# at /home/nbyavuz/Desktop/projects/postgres/src/test/modules/test_custom_stats/t/001_custom_stats.pl
line 92.
# got: 'entry3|0|Test entry 3'
# expected: 'entry3|2|Test entry 3'
# Failed test 'report for variable-sized data of entry4'
# at /home/nbyavuz/Desktop/projects/postgres/src/test/modules/test_custom_stats/t/001_custom_stats.pl
line 98.
# got: 'entry4|0|Test entry 4'
# expected: 'entry4|3|Test entry 4'
# Looks like you failed 4 tests of 16.
```

I attached a patch for fixing this problem by using poll_query_until()
like you did. I am not sure if 'test_custom_stats/001_custom_stats' is
the real problem since you need quite a big sleep time to reproduce
it, but I wanted to mention it just in case. Renamed that patch as a
nocfbot-* so it won't affect CI.

--
Regards,
Nazir Bilal Yavuz
Microsoft

On Wed, Sep 2, 2026 at 5:57 PM Nazir Bilal Yavuz <byavuz81@gmail.com> wrote:

I confirm that your patch fixes the problem and LGTM.

Thanks Ayush and Nazir, for the test and review! I've pushed the patch.

I attached a patch for fixing this problem by using poll_query_until()
like you did. I am not sure if 'test_custom_stats/001_custom_stats' is
the real problem since you need quite a big sleep time to reproduce
it, but I wanted to mention it just in case.

As you mentioned, this doesn't seem to be causing any actual buildfarm or
CI failures at the moment. So I'm inclined to leave things as they are
and not apply the patch....

Of course, if many others think it's better to apply it proactively,
I'm ok with that, though.

Regards,

--
Fujii Masao

Hello Ayush, Nazir, and Fujii-san,

03.09.2026 07:19, Fujii Masao wrote:

Thanks Ayush and Nazir, for the test and review! I've pushed the patch.

Thank you for fixing the test!
I've been tracking this failure at:
https://wiki.postgresql.org/wiki/Known_Buildfarm_Test_Failures#031_recovery_conflict.pl_test_might_fail_due_to_late_pgstat_entries_flushing

Probably you would also find worth fixing two other issues in the same test:
https://wiki.postgresql.org/wiki/Known_Buildfarm_Test_Failures#031_recovery_conflict.pl_fails_to_detect_an_expected_lock_acquisition
https://wiki.postgresql.org/wiki/Known_Buildfarm_Test_Failures#031_recovery_conflict.pl_fails_when_a_conflict_counted_twice

Both failures were produced not long ago: [1]https://buildfarm.postgresql.org/cgi-bin/show_log.pl?nm=drongo&amp;dt=2026-07-07%2010%3A03%3A33, [2]https://buildfarm.postgresql.org/cgi-bin/show_log.pl?nm=adder&amp;dt=2026-08-20%2000%3A50%3A11.

[1]: https://buildfarm.postgresql.org/cgi-bin/show_log.pl?nm=drongo&amp;dt=2026-07-07%2010%3A03%3A33
[2]: https://buildfarm.postgresql.org/cgi-bin/show_log.pl?nm=adder&amp;dt=2026-08-20%2000%3A50%3A11

Best regards,
Alexander

Hi,

On Fri, 4 Sept 2026 at 00:30, Alexander Lakhin <exclusion@gmail.com> wrote:

Hello Ayush, Nazir, and Fujii-san,

03.09.2026 07:19, Fujii Masao wrote:

Thanks Ayush and Nazir, for the test and review! I've pushed the patch.

Thank you for fixing the test!
I've been tracking this failure at:

https://wiki.postgresql.org/wiki/Known_Buildfarm_Test_Failures#031_recovery_conflict.pl_test_might_fail_due_to_late_pgstat_entries_flushing

Probably you would also find worth fixing two other issues in the same

test:

https://wiki.postgresql.org/wiki/Known_Buildfarm_Test_Failures#031_recovery_conflict.pl_fails_to_detect_an_expected_lock_acquisition

https://wiki.postgresql.org/wiki/Known_Buildfarm_Test_Failures#031_recovery_conflict.pl_fails_when_a_conflict_counted_twice

Both failures were produced not long ago: [1], [2].

[1]

https://buildfarm.postgresql.org/cgi-bin/show_log.pl?nm=drongo&amp;dt=2026-07-07%2010%3A03%3A33

[2]

https://buildfarm.postgresql.org/cgi-bin/show_log.pl?nm=adder&amp;dt=2026-08-20%2000%3A50%3A11

Thanks a lot for the buildfarm links and logs!

I looked into the failures, and ISTM the exact stats checks are the main
problem. The startup process can signal the same backend more than once
while it is handling a recovery-conflict FATAL, so a counter can advance
from 0 to 2 and leave the test waiting for 1 indefinitely. Patch 0001
changes the per-conflict checks to > 0 and checks that
pg_stat_database.conflicts is at least the expected total. I think that
should fix the stats-polling failure.

I'm less certain about the autovacuum part, so I kept it in a separate
patch. Autovacuum could prune the dead tuples before the explicit VACUUM
FREEZE emits the WAL needed by the recovery deadlock test. Patch 0002
disables autovacuum only on the recreated table. Does that seem like the
right scope? Although split for review, I think both patches should be
applied together.

Thoughts?

Regards,
Ayush

On Fri, Sep 4, 2026 at 6:48 AM Ayush Tiwari <ayushtiwari.slg01@gmail.com> wrote:

Thoughts?

Thanks for the patches! They look good to me.

Although split for review, I think both patches should be
applied together.

+1

Backpatch-through: 17

Is this because the test exists in v15 and v16 but is skipped there?

Regards,

--
Fujii Masao

Hello Ayush and Fujii-san,

04.09.2026 06:07, Fujii Masao wrote:

On Fri, Sep 4, 2026 at 6:48 AM Ayush Tiwari <ayushtiwari.slg01@gmail.com> wrote:

Thoughts?

Thanks for the patches! They look good to me.

Thank you for paying attention to my reports!

I'm not sure about the autovacuum fix -- I've found that I tried the same
targeted autovacuum = false as Melanie proposed back then ([1]/messages/by-id/714729ea-f536-0faf-353b-cbd5c8f241ea@gmail.com) and the
test still failed. Please let me recheck carefully if it's still an issue.

Regarding v1-0001, I've tested it with the repro.patch applied and
confirmed it works. Thank you!

[1]: /messages/by-id/714729ea-f536-0faf-353b-cbd5c8f241ea@gmail.com

Best regards,
Alexander

Hi,

On Fri, 4 Sept 2026 at 09:30, Alexander Lakhin <exclusion@gmail.com> wrote:

Hello Ayush and Fujii-san,

04.09.2026 06:07, Fujii Masao wrote:

On Fri, Sep 4, 2026 at 6:48 AM Ayush Tiwari <ayushtiwari.slg01@gmail.com>

wrote:

Thoughts?

Thanks for the patches! They look good to me.

Thank you for paying attention to my reports!

I'm not sure about the autovacuum fix -- I've found that I tried the same
targeted autovacuum = false as Melanie proposed back then ([1]) and the
test still failed. Please let me recheck carefully if it's still an issue.

Regarding v1-0001, I've tested it with the repro.patch applied and
confirmed it works. Thank you!

[1]

/messages/by-id/714729ea-f536-0faf-353b-cbd5c8f241ea@gmail.com

Thanks for testing and confirming 0001.

One detail I noticed in [1] is that the posted change sets
autovacuum_enabled=false on the initial table. That table is later dropped
and recreated for the recovery deadlock test, so the reloption does not
carry over. 0002 sets it on the recreated table instead.

However, if you tested that placement as well, there may be another race.

Regards,
Ayush

Hi,

On Fri, 4 Sept 2026 at 07:56, Ayush Tiwari <ayushtiwari.slg01@gmail.com> wrote:

On Fri, 4 Sept 2026 at 09:30, Alexander Lakhin <exclusion@gmail.com> wrote:

Hello Ayush and Fujii-san,

04.09.2026 06:07, Fujii Masao wrote:

On Fri, Sep 4, 2026 at 6:48 AM Ayush Tiwari <ayushtiwari.slg01@gmail.com> wrote:

Thoughts?

Thanks for the patches! They look good to me.

Thank you for paying attention to my reports!

I'm not sure about the autovacuum fix -- I've found that I tried the same
targeted autovacuum = false as Melanie proposed back then ([1]) and the
test still failed. Please let me recheck carefully if it's still an issue.

Regarding v1-0001, I've tested it with the repro.patch applied and
confirmed it works. Thank you!

[1] /messages/by-id/714729ea-f536-0faf-353b-cbd5c8f241ea@gmail.com

Thanks for testing and confirming 0001.

I confirm that the bug is reproducible with repro.patch and 0001 fixes it.

One detail I noticed in [1] is that the posted change sets
autovacuum_enabled=false on the initial table. That table is later dropped
and recreated for the recovery deadlock test, so the reloption does not
carry over. 0002 sets it on the recreated table instead.

I generated the attached reproducer with help from an LLM, and I
confirm that your 0002 fixes the problem and Alexander's change on the
[1]: fails because of the reason you mentioned.

Both patches LGTM.

--
Regards,
Nazir Bilal Yavuz
Microsoft

Hello Nazir and Ayush,

04.09.2026 11:40, Nazir Bilal Yavuz wrote:

I'm not sure about the autovacuum fix -- I've found that I tried the same
targeted autovacuum = false as Melanie proposed back then ([1]) and the
test still failed. Please let me recheck carefully if it's still an issue.

Regarding v1-0001, I've tested it with the repro.patch applied and
confirmed it works. Thank you!

[1]/messages/by-id/714729ea-f536-0faf-353b-cbd5c8f241ea@gmail.com

Thanks for testing and confirming 0001.

I confirm that the bug is reproducible with repro.patch and 0001 fixes it.

One detail I noticed in [1] is that the posted change sets
autovacuum_enabled=false on the initial table. That table is later dropped
and recreated for the recovery deadlock test, so the reloption does not
carry over. 0002 sets it on the recreated table instead.

I generated the attached reproducer with help from an LLM, and I
confirm that your 0002 fixes the problem and Alexander's change on the
[1] fails because of the reason you mentioned.

Both patches LGTM.

Yes, I've tested both on my side -- no single run (of thousands) failed.
Also checked with LLM all the failures of 031_recovery_conflict registered
on wiki -- they all should be ruled out now.

Thank you for spending time on this!

Best regards,
Alexander

04.09.2026 19:00, Alexander Lakhin wrote:

Yes, I've tested both on my side -- no single run (of thousands) failed.
Also checked with LLM all the failures of 031_recovery_conflict registered
on wiki -- they all should be ruled out now.

Having tried a bit harder (running the test on a relatively slow riscv64
device), I've discovered one more instability. It can be reproduced
reliably on an ordinary machine with:
/tmp/temp.config
autovacuum_naptime = 1
autovacuum_analyze_threshold = 1

--- a/src/backend/commands/analyze.c
+++ b/src/backend/commands/analyze.c
@@ -132,4 +132,5 @@ analyze_rel(Oid relid, RangeVar *relation,
      CHECK_FOR_INTERRUPTS();

+if (AmAutoVacuumWorkerProcess()) pg_usleep(1000000);
      /*
       * Open the relation, getting ShareUpdateExclusiveLock to ensure that two
--- a/src/test/recovery/t/031_recovery_conflict.pl
+++ b/src/test/recovery/t/031_recovery_conflict.pl
@@ -132,4 +132,5 @@ $node_primary->safe_psql($test_db,
  $node_primary->wait_for_replay_catchup($node_standby);

+sleep(1);
 # DECLARE and FETCH from cursor on the standby
 $res = $psql_standby->query_safe(

TEMP_CONFIG=/tmp/temp.config make -s check -C src/test/recovery PROVE_TESTS="t/031*"
t/031_recovery_conflict.pl .. 4/? # die: timed out waiting for file
.../src/test/recovery/tmp_check/log/031_recovery_conflict_standby.log contents to match: (?^:User query might have
needed to see row versions that must be removed) at t/031_recovery_conflict.pl line 324.
# Looks like your test exited with 255 just after 4.
t/031_recovery_conflict.pl .. Dubious, test returned 255 (wstat 65280, 0xff00)
All 4 subtests passed

Test Summary Report
-------------------
t/031_recovery_conflict.pl (Wstat: 65280 (exited 255) Tests: 4 Failed: 0)
  Non-zero exit status: 255
Files=1, Tests=4, 183 wallclock secs ( 0.00 usr  0.00 sys +  0.17 cusr  0.24 csys =  0.41 CPU)

(Originally, the test failed for me without extra autovacuum-related
settings and sleeps.)

Best regards,
Alexander

Hi,

On Sun, 6 Sept 2026 at 13:30, Alexander Lakhin <exclusion@gmail.com> wrote:

04.09.2026 19:00, Alexander Lakhin wrote:

Yes, I've tested both on my side -- no single run (of thousands) failed.
Also checked with LLM all the failures of 031_recovery_conflict registered
on wiki -- they all should be ruled out now.

Having tried a bit harder (running the test on a relatively slow riscv64
device), I've discovered one more instability. It can be reproduced
reliably on an ordinary machine with:
/tmp/temp.config
autovacuum_naptime = 1
autovacuum_analyze_threshold = 1

Thanks for the report.

--- a/src/backend/commands/analyze.c
+++ b/src/backend/commands/analyze.c
@@ -132,4 +132,5 @@ analyze_rel(Oid relid, RangeVar *relation,
CHECK_FOR_INTERRUPTS();

+if (AmAutoVacuumWorkerProcess()) pg_usleep(1000000);
/*
* Open the relation, getting ShareUpdateExclusiveLock to ensure that two
--- a/src/test/recovery/t/031_recovery_conflict.pl
+++ b/src/test/recovery/t/031_recovery_conflict.pl
@@ -132,4 +132,5 @@ $node_primary->safe_psql($test_db,
$node_primary->wait_for_replay_catchup($node_standby);

+sleep(1);
# DECLARE and FETCH from cursor on the standby
$res = $psql_standby->query_safe(

TEMP_CONFIG=/tmp/temp.config make -s check -C src/test/recovery PROVE_TESTS="t/031*"
t/031_recovery_conflict.pl .. 4/? # die: timed out waiting for file
.../src/test/recovery/tmp_check/log/031_recovery_conflict_standby.log contents to match: (?^:User query might have
needed to see row versions that must be removed) at t/031_recovery_conflict.pl line 324.
# Looks like your test exited with 255 just after 4.
t/031_recovery_conflict.pl .. Dubious, test returned 255 (wstat 65280, 0xff00)
All 4 subtests passed

Test Summary Report
-------------------
t/031_recovery_conflict.pl (Wstat: 65280 (exited 255) Tests: 4 Failed: 0)
Non-zero exit status: 255
Files=1, Tests=4, 183 wallclock secs ( 0.00 usr 0.00 sys + 0.17 cusr 0.24 csys = 0.41 CPU)

(Originally, the test failed for me without extra autovacuum-related
settings and sleeps.)

Hmm, I think we can just disable the autovacuum completely.

I revised 0002 to disable autovacuum for the test node instead. With your
reproducer, the revised patch passes all 18 tests. The regular test passes
as well.

Thoughts?

Regards,
Ayush