Test tidscan,sql is not immune to autovacuum in v14
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.
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:t253495psql -h localhost -U postgresBuilt from patchset v3 (message #3), August 20, 2026 at 01:22 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 t253495_3 https://github.com/hackorum-dev/postgres.gitIn a checkout you already have, add the fork once:
git remote add hackorum https://github.com/hackorum-dev/postgres.gitthen, for this patchset and every later one:
git fetch hackorum t253495_3 && git checkout t253495_3Patchset v3 (message #3) is on t253495_3
Hello hackers,
I spotted a very rare test failure (a single one in two years, at least)
generated by basilisk:
tidscan ... FAILED 34 ms
...
diff -U3 /mnt/build/REL_14_STABLE/pgsql.build/../pgsql/src/test/regress/expected/tidscan.out
/mnt/build/REL_14_STABLE/pgsql.build/src/test/regress/results/tidscan.out
--- /mnt/build/REL_14_STABLE/pgsql.build/../pgsql/src/test/regress/expected/tidscan.out
+++ /mnt/build/REL_14_STABLE/pgsql.build/src/test/regress/results/tidscan.out
@@ -242,10 +242,10 @@
----------------------------------------
Aggregate
-> Hash Join
- Hash Cond: (t1.ctid = t2.ctid)
- -> Seq Scan on tenk1 t1
+ Hash Cond: (t2.ctid = t1.ctid)
+ -> Seq Scan on tenk1 t2
-> Hash
- -> Seq Scan on tenk1 t2
+ -> Seq Scan on tenk1 t1
(6 rows)
SELECT count(*) FROM tenk1 t1 JOIN tenk1 t2 ON t1.ctid = t2.ctid;
and was intrigued enough to find a reliable reproducer for it.
With the following modification:
--- a/src/backend/optimizer/util/plancat.c
+++ b/src/backend/optimizer/util/plancat.c
@@ -188,6 +188,7 @@ get_relation_info(PlannerInfo *root, Oid relationObjectId, bool inhparent,
estimate_rel_size(relation, rel->attr_widths - rel->min_attr,
&rel->pages, &rel->tuples, &rel->allvisfrac);
+char *name = get_rel_name(relationObjectId); if (name != NULL && strcmp(name, "tenk1") == 0) pg_usleep(100000);
/* Retrieve the parallel_workers reloption, or -1 if not set. */
rel->rel_parallel_workers = RelationGetParallelWorkers(relation, -1);
and
test: tidscan analyze
in parallel_schedule (the full patch is attached), I get:
parallel group (2 tests): analyze tidscan
tidscan ... FAILED 900 ms
analyze ... ok 63 ms
(The basilisk's log contain no autovacuum messages, but I guess it was
automatic analyze that processed tenk1 in the very lucky moment.)
Given the current statistics, we won't see failures of this ilk anymore,
because it is not reproduced in REL_15_STABLE..master, due to 74388a1ac +
4496020e6, which resulted in a different reltuples value returned for tenk1
during sanity_check/VACUUM and that indirectly affected the plan change.
[1]: https://buildfarm.postgresql.org/cgi-bin/show_log.pl?nm=basilisk&dt=2026-06-15%2006%3A07%3A09
Best regards,
Alexander
Attachments:
repro-tidscan-failure.patchtext/x-patch; charset=UTF-8; name=repro-tidscan-failure.patchDownload+6-1
On Thu, 20 Aug 2026 at 08:00, Alexander Lakhin <exclusion@gmail.com> wrote:
I spotted a very rare test failure (a single one in two years, at least) generated by basilisk: tidscan ... FAILED 34 ms ... diff -U3 /mnt/build/REL_14_STABLE/pgsql.build/../pgsql/src/test/regress/expected/tidscan.out /mnt/build/REL_14_STABLE/pgsql.build/src/test/regress/results/tidscan.out --- /mnt/build/REL_14_STABLE/pgsql.build/../pgsql/src/test/regress/expected/tidscan.out +++ /mnt/build/REL_14_STABLE/pgsql.build/src/test/regress/results/tidscan.out @@ -242,10 +242,10 @@ ---------------------------------------- Aggregate -> Hash Join - Hash Cond: (t1.ctid = t2.ctid) - -> Seq Scan on tenk1 t1 + Hash Cond: (t2.ctid = t1.ctid) + -> Seq Scan on tenk1 t2 -> Hash - -> Seq Scan on tenk1 t2 + -> Seq Scan on tenk1 t1 (6 rows)SELECT count(*) FROM tenk1 t1 JOIN tenk1 t2 ON t1.ctid = t2.ctid;
I experimented, and I see the costs come out quite different if that
were changed to:
SELECT count(*) FROM tenk1 WHERE ctid IN (SELECT DISTINCT ctid FROM tenk1);
The winning plan is;
QUERY PLAN
-------------------------------------------------------------------------------------------
Aggregate (cost=1191.26..1191.27 rows=1 width=8)
-> Hash Join (cost=695.00..1166.26 rows=10000 width=0)
Hash Cond: (tenk1.ctid = tenk1_1.ctid)
-> Seq Scan on tenk1 (cost=0.00..445.00 rows=10000 width=6)
-> Hash (cost=570.00..570.00 rows=10000 width=6)
-> HashAggregate (cost=470.00..570.00 rows=10000 width=6)
Group Key: tenk1_1.ctid
-> Seq Scan on tenk1 tenk1_1 (cost=0.00..445.00
rows=10000 width=6)
(8 rows)
and if I force the other Hash Join option via the debugger, I get:
QUERY PLAN
-------------------------------------------------------------------------------------
Aggregate (cost=1302.50..1302.51 rows=1 width=8)
-> Hash Join (cost=1040.00..1277.50 rows=10000 width=0)
Hash Cond: (tenk1_1.ctid = tenk1.ctid)
-> HashAggregate (cost=470.00..570.00 rows=10000 width=6)
Group Key: tenk1_1.ctid
-> Seq Scan on tenk1 tenk1_1 (cost=0.00..445.00
rows=10000 width=6)
-> Hash (cost=445.00..445.00 rows=10000 width=6)
-> Seq Scan on tenk1 (cost=0.00..445.00 rows=10000 width=6)
(8 rows)
There's probably also some argument to the distinct semi-join query
giving the code a bit more exercise due to the Hash Agg.
Naturally, the current INNER JOIN query produces the same cost for
each join order, under normal circumstances.
This makes me wonder how significant the estimates varied in the two
calls to estimate_rel_size() in the problem case you saw?
I tried to figure this out by recreating this for myself using your
code on v14, but didn't manage to get the correct timing for a failure
to occur. I can get the plan to flip by adjusting the rel->tuples
after the estimate_rel_size() call by adding 1.0 to rel on the hash
side of the join. That's due to the two Paths comparing fuzzily the
same and the tie-break ending up deferring to:
else if (new_path->rows < old_path->rows)
remove_old = true; /* new dominates old */
else if (new_path->rows > old_path->rows)
accept_new = false; /* old dominates new */
So, I suspect you're seeing a very small variation in tuple estimates
and the DISTINCT semi-join query I proposed above would be enough to
solve it.
Given the current statistics, we won't see failures of this ilk anymore,
because it is not reproduced in REL_15_STABLE..master, due to 74388a1ac +
4496020e6, which resulted in a different reltuples value returned for tenk1
during sanity_check/VACUUM and that indirectly affected the plan change.
I had also thought that it might not be worth troubling over given
that v14 has less than 3 months to live, but I believe it's generally
bad practice to have queries in tests where multiple plans are so
close together in cost. They're just too prone to very subtle changes
that can result in rare plan changes (as per what you're reporting).
David
On Thu, 20 Aug 2026 at 12:32, David Rowley <dgrowleyml@gmail.com> wrote:
On Thu, 20 Aug 2026 at 08:00, Alexander Lakhin <exclusion@gmail.com> wrote:
I spotted a very rare test failure (a single one in two years, at least) generated by basilisk: tidscan ... FAILED 34 ms ... diff -U3 /mnt/build/REL_14_STABLE/pgsql.build/../pgsql/src/test/regress/expected/tidscan.out /mnt/build/REL_14_STABLE/pgsql.build/src/test/regress/results/tidscan.out --- /mnt/build/REL_14_STABLE/pgsql.build/../pgsql/src/test/regress/expected/tidscan.out +++ /mnt/build/REL_14_STABLE/pgsql.build/src/test/regress/results/tidscan.out @@ -242,10 +242,10 @@ ---------------------------------------- Aggregate -> Hash Join - Hash Cond: (t1.ctid = t2.ctid) - -> Seq Scan on tenk1 t1 + Hash Cond: (t2.ctid = t1.ctid) + -> Seq Scan on tenk1 t2 -> Hash - -> Seq Scan on tenk1 t2 + -> Seq Scan on tenk1 t1 (6 rows)SELECT count(*) FROM tenk1 t1 JOIN tenk1 t2 ON t1.ctid = t2.ctid;
I experimented, and I see the costs come out quite different if that
were changed to:SELECT count(*) FROM tenk1 WHERE ctid IN (SELECT DISTINCT ctid FROM tenk1);
Here's that patchified.
David
David Rowley <dgrowleyml@gmail.com> writes:
Here's that patchified.
I don't really like this proposal. I think the only reason these
test cases exist at all is to remind us that we aren't very smart
about joins on ctid. In the event that somebody fixes that, these
plans would change --- except that it's really unlikely that
such an optimization could "see through" the DISTINCT you propose
to add. So I think this change basically makes these tests unfit
for any purpose.
I think the reasonable choices are
(1) Remove these test cases completely in all branches. The
argument for this is that we're expending test cycles for pretty
nearly no benefit, and if someone did fix the case then the
tests could be put back with new expected output.
(2) Fix only in v14, to ensure that we don't see another of
these failures.
(3) Do nothing, reasoning that we probably won't see another
such failure in v14's remaining lifespan anyway.
I'm kind of leaning to (1), but (3) is plausible too.
I'm not seeing a lot of point in (2).
regards, tom lane
On Thu, 20 Aug 2026 at 14:50, Tom Lane <tgl@sss.pgh.pa.us> wrote:
I don't really like this proposal. I think the only reason these
test cases exist at all is to remind us that we aren't very smart
about joins on ctid. In the event that somebody fixes that, these
plans would change --- except that it's really unlikely that
such an optimization could "see through" the DISTINCT you propose
to add. So I think this change basically makes these tests unfit
for any purpose.
This surprised me. When I looked at the commit message for 0a6ea4001,
I expected that you added these tests to exercise the newly added
hashtid() functions. It makes sense to me that you added the query
with and without EXPLAIN as you wanted to verify all 10k rows were
found and also that the chosen plan was a Hash Join. If the plan had
flipped to a Merge Join or Nested Loop, then it wouldn't be doing a
very good job of exercising hashtid().
Are you sure that's not the reason?
I think the reasonable choices are
(1) Remove these test cases completely in all branches. The
argument for this is that we're expending test cycles for pretty
nearly no benefit, and if someone did fix the case then the
tests could be put back with new expected output.(2) Fix only in v14, to ensure that we don't see another of
these failures.(3) Do nothing, reasoning that we probably won't see another
such failure in v14's remaining lifespan anyway.I'm kind of leaning to (1), but (3) is plausible too.
I'm not seeing a lot of point in (2).
I'm not for #2 either. IMO, #1 reduces the coverage for hashing of
tids, though we probably don't need that done on a 10k-row table. I
thought about #3, but it still leaves a query in our tests that we're
looking at the EXPLAIN for that has two equally cheap lowest-cost
plans. I thought it was best to do something before another reason
appears that introduces something new to make that fail randomly.
Another way to make the alternative join order less favourable would
be with something like:
select count(*) from tenk1 t1 inner join tenk1 t2 on t1.ctid = t2.ctid
where t2.ten = 0;
I make that:
-> Hash Join (cost=482.50..975.00 rows=1000 width=0)
and with the join order swapped to put the filtering on the probe
side, the costs are:
-> Hash Join (cost=570.00..1053.75 rows=1000 width=0)
Which is likely a large enough difference to stop any future random failures.
David
David Rowley <dgrowleyml@gmail.com> writes:
Another way to make the alternative join order less favourable would
be with something like:
select count(*) from tenk1 t1 inner join tenk1 t2 on t1.ctid = t2.ctid
where t2.ten = 0;
Sure, that'd work for me.
regards, tom lane
Hello David and Tom,
20.08.2026 03:32, David Rowley wrote:
I experimented, and I see the costs come out quite different if that
were changed to:SELECT count(*) FROM tenk1 WHERE ctid IN (SELECT DISTINCT ctid FROM tenk1);
The winning plan is;
QUERY PLAN
-------------------------------------------------------------------------------------------
Aggregate (cost=1191.26..1191.27 rows=1 width=8)
-> Hash Join (cost=695.00..1166.26 rows=10000 width=0)
Hash Cond: (tenk1.ctid = tenk1_1.ctid)
-> Seq Scan on tenk1 (cost=0.00..445.00 rows=10000 width=6)
-> Hash (cost=570.00..570.00 rows=10000 width=6)
-> HashAggregate (cost=470.00..570.00 rows=10000 width=6)
Group Key: tenk1_1.ctid
-> Seq Scan on tenk1 tenk1_1 (cost=0.00..445.00
rows=10000 width=6)
(8 rows)
My "good" plan in REL_14_STABLE is:
EXPLAIN (VERBOSE)
SELECT count(*) FROM tenk1 t1 JOIN tenk1 t2 ON t1.ctid = t2.ctid;
QUERY PLAN
--------------------------------------------------------------------------------------
Aggregate (cost=1177.26..1177.27 rows=1 width=8)
Output: count(*)
-> Hash Join (cost=569.89..1152.27 rows=9995 width=0)
Hash Cond: (t1.ctid = t2.ctid)
-> Seq Scan on public.tenk1 t1 (cost=0.00..444.95 rows=9995 width=6)
Output: t1.ctid
-> Hash (cost=444.95..444.95 rows=9995 width=6)
Output: t2.ctid
-> Seq Scan on public.tenk1 t2 (cost=0.00..444.95 rows=9995 width=6)
Output: t2.ctid
(10 rows)
versus "bad":
EXPLAIN (VERBOSE)
SELECT count(*) FROM tenk1 t1 JOIN tenk1 t2 ON t1.ctid = t2.ctid;
QUERY PLAN
--------------------------------------------------------------------------------------
Aggregate (cost=1177.33..1177.34 rows=1 width=8)
Output: count(*)
-> Hash Join (cost=569.89..1152.34 rows=9995 width=0)
Hash Cond: (t2.ctid = t1.ctid)
-> Seq Scan on public.tenk1 t2 (cost=0.00..445.00 rows=10000 width=6)
Output: t2.ctid
-> Hash (cost=444.95..444.95 rows=9995 width=6)
Output: t1.ctid
-> Seq Scan on public.tenk1 t1 (cost=0.00..444.95 rows=9995 width=6)
Output: t1.ctid
(10 rows)
and if I force the other Hash Join option via the debugger, I get:
QUERY PLAN
-------------------------------------------------------------------------------------
Aggregate (cost=1302.50..1302.51 rows=1 width=8)
-> Hash Join (cost=1040.00..1277.50 rows=10000 width=0)
Hash Cond: (tenk1_1.ctid = tenk1.ctid)
-> HashAggregate (cost=470.00..570.00 rows=10000 width=6)
Group Key: tenk1_1.ctid
-> Seq Scan on tenk1 tenk1_1 (cost=0.00..445.00
rows=10000 width=6)
-> Hash (cost=445.00..445.00 rows=10000 width=6)
-> Seq Scan on tenk1 (cost=0.00..445.00 rows=10000 width=6)
(8 rows)There's probably also some argument to the distinct semi-join query
giving the code a bit more exercise due to the Hash Agg.Naturally, the current INNER JOIN query produces the same cost for
each join order, under normal circumstances.This makes me wonder how significant the estimates varied in the two
calls to estimate_rel_size() in the problem case you saw?
At the commit 74388a1ac, with this logging added:
--- a/src/backend/commands/vacuum.c
+++ b/src/backend/commands/vacuum.c
@@ -60,2 +60,3 @@
#include "utils/syscache.h"
+#include "utils/lsyscache.h"
@@ -1255,5 +1256,9 @@ vac_estimate_reltuples(Relation relation,
*/
+char *rel_name = get_rel_name(relation->rd_id);
if (old_rel_pages == total_pages &&
scanned_pages < (double) total_pages * 0.02)
+{
+elog(LOG, "!!!vac_estimate_reltuples| rel_name: %s, old_rel_tuples: %lf", rel_name, old_rel_tuples);
return old_rel_tuples;
+}
@@ -1275,2 +1280,3 @@ vac_estimate_reltuples(Relation relation,
total_tuples = old_density * unscanned_pages + scanned_tuples;
+elog(LOG, "!!!vac_estimate_reltuples| rel_name: %s, floor(total_tuples + 0.5): %lf", rel_name, floor(total_tuples + 0.5));
return floor(total_tuples + 0.5);
I can see the following:
2026-08-20 04:23:48.978 EDT client backend[672080] pg_regress/sanity_check LOG: !!!vac_estimate_reltuples| rel_name:
tenk1, old_rel_tuples: 10000.000000
2026-08-20 04:23:48.978 EDT client backend[672080] pg_regress/sanity_check CONTEXT: while scanning relation "public.tenk1"
2026-08-20 04:23:48.978 EDT client backend[672080] pg_regress/sanity_check STATEMENT: VACUUM;
when the plan is expected, versus
2026-08-20 04:27:53.033 EDT client backend[674543] pg_regress/sanity_check LOG: !!!vac_estimate_reltuples| rel_name:
tenk1, floor(total_tuples + 0.5): 9995.000000
2026-08-20 04:27:53.033 EDT client backend[674543] pg_regress/sanity_check CONTEXT: while scanning relation "public.tenk1"
2026-08-20 04:27:53.033 EDT client backend[674543] pg_regress/sanity_check STATEMENT: VACUUM;
at 74388a1ac~1 (with the "bad" plan).
Given the current statistics, we won't see failures of this ilk anymore,
because it is not reproduced in REL_15_STABLE..master, due to 74388a1ac +
4496020e6, which resulted in a different reltuples value returned for tenk1
during sanity_check/VACUUM and that indirectly affected the plan change.I had also thought that it might not be worth troubling over given
that v14 has less than 3 months to live, but I believe it's generally
bad practice to have queries in tests where multiple plans are so
close together in cost. They're just too prone to very subtle changes
that can result in rare plan changes (as per what you're reporting).
I absolutely agree with your and Tom's points -- the worthwhile thing here
to me is the evidence how (auto)vacuum/analyze can affect the planner's
decisions transiently (in a very small window). I remember a similar story
when tenk2's reltuples drifted 10000 ->9995 [1]/messages/by-id/66eb9a6e-fc67-a230-c5b1-2a741e8b88c6@gmail.com, but in that case it
affected sensitive queries that followed the drift.
Thank you for your attention to this anomaly!
[1]: /messages/by-id/66eb9a6e-fc67-a230-c5b1-2a741e8b88c6@gmail.com
Best regards,
Alexander
On Thu, 20 Aug 2026 at 16:43, Tom Lane <tgl@sss.pgh.pa.us> wrote:
David Rowley <dgrowleyml@gmail.com> writes:
Another way to make the alternative join order less favourable would
be with something like:select count(*) from tenk1 t1 inner join tenk1 t2 on t1.ctid = t2.ctid
where t2.ten = 0;Sure, that'd work for me.
Thanks. I pushed that to all supported versions.
David