Re: Stabilize recovery conflict stats checks in 031_recovery_conflict.pl

From: Nazir Bilal Yavuz <byavuz81(at)gmail(dot)com>
To: Fujii Masao <masao(dot)fujii(at)gmail(dot)com>
Cc: PostgreSQL Hackers <pgsql-hackers(at)lists(dot)postgresql(dot)org>
Subject: Re: Stabilize recovery conflict stats checks in 031_recovery_conflict.pl
Date: 2026-09-02 08:57:01
Message-ID: CAN55FZ2zC8HR+Wc6XhkGDF4VCm9sLy8zy23pd++5YwSU_UYm3g@mail.gmail.com
Views: Whole Thread | Raw Message | Download mbox | Resend email
Thread:
Lists: pgsql-hackers

Hi,

Thank you for working on this!

On Wed, 2 Sept 2026 at 10:45, Fujii Masao <masao(dot)fujii(at)gmail(dot)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

Attachment Content-Type Size
nocfbot-Stabilize-test_custom_stats-001_custom_stats-test.patch text/x-patch 2.3 KB

In response to

Browse pgsql-hackers by date

  From Date Subject
Previous Message Antonin Houska 2026-09-02 08:47:26 Re: REPACK (ANALYZE) within transaction block segfaults