Skip to content
Merged
Show file tree
Hide file tree
Changes from all commits
Commits
File filter

Filter by extension

Filter by extension

Conversations
Failed to load comments.
Loading
Jump to
Jump to file
Failed to load files.
Loading
Diff view
Diff view
35 changes: 35 additions & 0 deletions CHANGELOG.md
Original file line number Diff line number Diff line change
Expand Up @@ -458,6 +458,41 @@ true until the next version shipped.

### Fixed

- `analyze_stats`' wide-table bound is derived from the run and floored, instead
of being a ratio over a 20 ms scan that was mostly process startup (#1252).

The arm read `an_ms < scan_ms * 20`. It went red on a CI runner against a
branch of five test and docs files that cannot reach the ANALYZE path, and
passed when the same jobs were re-run at the same commit.

Measured on `pgcolumnar-audit`, pg17a, five interleaved rounds, with the same
`psql_run` wrapper around `SELECT 1` as the control:

```
empty 7.8 ms insert 316.6 ms scan 20.0 ms analyze 115.2 ms
```

The scan carried about 12 ms of work above an 8 ms floor -- 1.5x its own noise
-- so the ratio measured the floor as much as the scan. The two terms did not
move together either: on the failing CI run ANALYZE was 3.1x this box while
the scan was 0.7x it.

The bound is now `max(5000, insert_ms * 20)`. The insert reads and writes the
same rows the ANALYZE samples, so it tracks the machine and the data volume;
the floor stops a future faster write path squeezing the bound into a flake,
which is how the old one arrived here -- its 20x was justified against "341 ms
against a 155 ms scan" and no machine has measured a 155 ms scan since.

The bug being defended is a hang, not a slowdown, so the bound does not need
to be tight. Measured by removal against `f82bdcd`'s parent, same fixture:
the unfixed build did not complete within 180 s, and an unbounded run was
killed at 10m52s of 99.9% CPU still running, against 206 ms fixed.

The decision is a function driven with literals, so the branch a healthy
machine never takes is judged rather than left to a box that happens to be
slow. `analyze_stats` also enters the mutation ledger for the first time:
`suites_not_covered` falls from 249 to 248.

- The hand-rebuild diagnosis can no longer be silent, which is how the first
version of it still told the 2026-09-24 nightly nothing (#1248).

Expand Down
82 changes: 72 additions & 10 deletions test/analyze_stats.sh
Original file line number Diff line number Diff line change
Expand Up @@ -302,30 +302,92 @@ check "having an index available saves the point lookup real work" \
# and on the fixed build 341 ms against a 155 ms scan, which is why the threshold
# has room. The reference is a full scan of the same table: ANALYZE reads a
# sample and must not cost multiples of reading everything.
_as_t0=$(date +%s%N)
psql_run "DROP TABLE IF EXISTS as_w;
CREATE TABLE as_w (a bigint, b int, c int, d int, e timestamptz,
f text, g text, h text) USING pgcolumnar;
INSERT INTO as_w SELECT g, g, g % 1000, g % 7,
'2020-01-01'::timestamptz + (g || ' sec')::interval,
repeat('x', 200) || g, repeat('y', 200) || g, repeat('z', 200) || g
FROM generate_series(1, ${PGC_ANALYZE_WIDE_ROWS:-40000}) g;" >/dev/null
_as_t1=$(date +%s%N)
ins_ms=$(( (_as_t1 - _as_t0) / 1000000 ))

t0=$(date +%s%N)
psql_run "ANALYZE as_w;" >/dev/null
t1=$(date +%s%N)
an_ms=$(( (t1 - t0) / 1000000 ))

t0=$(date +%s%N)
psql_run "SET pgcolumnar.enable_vectorization = off;
SELECT count(h) FROM as_w;" >/dev/null
t1=$(date +%s%N)
scan_ms=$(( (t1 - t0) / 1000000 ))

echo "-- wide-table ANALYZE ${an_ms} ms against a ${scan_ms} ms full scan"
# THE BOUND IS DERIVED FROM THE RUN AND FLOORED (#1252). It used to be
# `an_ms < scan_ms * 20`, and both halves of that were wrong.
#
# THE OLD DENOMINATOR WAS MOSTLY NOT A SCAN. `psql_run` spawns a psql process
# and connects over TCP, and the timed region includes that. Measured on
# pgcolumnar-audit, pg17a, five interleaved rounds, the same wrapper around
# `SELECT 1` as the control:
#
# empty 7.8 ms insert 316.6 ms scan 20.0 ms analyze 115.2 ms
#
# so the scan carried ~12 ms of work above an ~8 ms floor -- 1.5x its own noise
# -- while the insert carried ~309 ms, 40x it. A ratio over the scan measures the
# floor as much as the scan, which is why the same guard read 5.8 locally and
# 25.2 on a CI runner and went red there on a branch that could not reach ANALYZE.
#
# AND THE TWO TERMS DID NOT MOVE TOGETHER. On that CI run ANALYZE was 3.1x this
# box while the scan was 0.7x it. The insert reads and writes the same rows the
# ANALYZE samples, so it tracks the same hardware and the same data volume.
#
# THE FLOOR IS NOT DECORATION. A relative guard tightens silently whenever its
# baseline improves, which is exactly how the old one arrived here: the comment
# above justified 20x against "341 ms against a 155 ms scan", and no machine has
# measured a 155 ms scan since. The floor means a future faster write path
# cannot squeeze this bound into a flake.
#
# THE BUG IS A HANG, NOT A SLOWDOWN, so the bound does not need to be tight.
# Measured by removal against f82bdcd's parent, same fixture, each tree building
# its own .so: UNFIXED did not complete within 180 s (an unbounded run was killed
# at 10m52s of 99.9% CPU, still running) against 206 ms fixed. At least 3000x.
pgc_analyze_cap_ms() { # pgc_analyze_cap_ms INSERT_MS -> the ceiling for ANALYZE
local _i="${1:-0}" _d
[ "$_i" -gt 0 ] 2>/dev/null || _i=0
_d=$(( _i * 20 ))
[ "$_d" -gt 5000 ] && echo "$_d" || echo 5000
}

check "ANALYZE on a wide table is not many times a full scan of it" \
"$(awk -v a="$an_ms" -v s="$scan_ms" \
'BEGIN { print (s > 0 && a < s * 20) ? "yes" : "no (" a "ms against a " s "ms scan)" }')" \
cap_ms=$(pgc_analyze_cap_ms "$ins_ms")
echo "-- wide-table ANALYZE ${an_ms} ms against a ${cap_ms} ms cap (insert ${ins_ms} ms)"

# THE DECISION IS DRIVEN WITH LITERALS FIRST, so the branch a healthy machine
# never takes is judged here rather than only by a box that happens to be slow.
check_num "premise: the cap is exposed as a function, not written inline" \
"$([ "$(type -t pgc_analyze_cap_ms)" = function ] && echo 1 || echo 0)" "1"
check_num "a fast machine still gets the floor, not a bound that shrinks with it" \
"$(pgc_analyze_cap_ms 1)" "5000"
check_num "and a slow one gets a budget proportional to its own insert" \
"$(pgc_analyze_cap_ms 1000)" "20000"
check_num "the floor and the derived bound meet where they should" \
"$(pgc_analyze_cap_ms 250)" "5000"
check_num "and one millisecond past it the derived bound takes over" \
"$(pgc_analyze_cap_ms 251)" "5020"
check_num "a missing or zero insert time still yields the floor, not zero" \
"$(pgc_analyze_cap_ms 0)" "5000"
# THE INPUT GUARD WAS UNCOVERED UNTIL THIS ARM (#1236's taxonomy). Removing it
# reddened NOTHING on five majors, and the reason is that 0, "", "abc" and a
# negative all reach the floor anyway -- `$(( ))` reads them as 0. The one input
# it actually defends is a PARTIALLY numeric token, where bash raises an
# arithmetic syntax error and the function prints nothing at all:
#
# pgc_analyze_cap_ms 12abc with the guard 5000
# without it <arithmetic error, no output>
#
# So it is an uncovered guard rather than a redundant condition, and it is
# covered rather than deleted.
check_num "a malformed insert time yields the floor rather than an arithmetic error" \
"$(pgc_analyze_cap_ms '12abc' 2>/dev/null)" "5000"

check "ANALYZE on a wide table completes well inside its derived cap" \
"$(awk -v a="$an_ms" -v c="$cap_ms" \
'BEGIN { print (c > 0 && a < c) ? "yes" : "no (" a "ms against a " c "ms cap)" }')" \
"yes"

# --- 6. the fetch cost keeps the planner off an unclustered ordered index (#355) --
Expand Down
42 changes: 41 additions & 1 deletion test/check_ledger.tsv
Original file line number Diff line number Diff line change
@@ -1,3 +1,43 @@
analyze_stats analyze_stats ANALYZE now collects statistics at all 15;16;17;18;19 never -
analyze_stats analyze_stats ANALYZE on a wide table completes well inside its derived cap 15;16;17;18;19 never -
analyze_stats analyze_stats a fast machine still gets the floor, not a bound that shrinks with it 15;16;17;18;19 2026-09-24 the cap loses its absolute floor, so the bound shrinks with the machine it runs on;the floor moved by one, so the boundary where floor and derived bound meet is off by one
analyze_stats analyze_stats a late column's wide decode prefix costs it off the index (#363) 15;16;17;18;19 never -
analyze_stats analyze_stats a malformed insert time yields the floor rather than an arithmetic error 15;16;17;18;19 2026-09-24 the cap loses its absolute floor, so the bound shrinks with the machine it runs on;the floor moved by one, so the boundary where floor and derived bound meet is off by one;the input guard removed, so a partially numeric insert time raises an arithmetic error and the cap prints nothing
analyze_stats analyze_stats a missing or zero insert time still yields the floor, not zero 15;16;17;18;19 2026-09-24 the cap loses its absolute floor, so the bound shrinks with the machine it runs on;the floor moved by one, so the boundary where floor and derived bound meet is off by one
analyze_stats analyze_stats a point lookup on an indexed column still uses the index after ANALYZE 15;16;17;18;19 never -
analyze_stats analyze_stats a selective equality is estimated from the data, not the 0.5% default 15;16;17;18;19 never -
analyze_stats analyze_stats a small LIMIT still reaches the index through the fetch penalty (#376) 15;16;17;18;19 never -
analyze_stats analyze_stats a vacuumed columnar table can reach an index-only scan (#507) 15;16;17;18;19 never -
analyze_stats analyze_stats an early column's short decode prefix leaves it on the index (#363) 15;16;17;18;19 never -
analyze_stats analyze_stats and a slow one gets a budget proportional to its own insert 15;16;17;18;19 2026-09-24 the cap stops scaling with the run, so a slow machine gets the same budget as a fast one
analyze_stats analyze_stats and one millisecond past it the derived bound takes over 15;16;17;18;19 2026-09-24 the cap stops scaling with the run, so a slow machine gets the same budget as a fast one
analyze_stats analyze_stats correlation on an ascending column is near 1 15;16;17;18;19 never -
analyze_stats analyze_stats growth without vacuum does not inflate the all-visible saving (#507) 15;16;17;18;19 never -
analyze_stats analyze_stats having an index available saves the point lookup real work 15;16;17;18;19 never -
analyze_stats analyze_stats most_common_vals holds the same set as heap 15;16;17;18;19 never -
analyze_stats analyze_stats n_distinct on a clustered column is within 10% of the truth 15;16;17;18;19 never -
analyze_stats analyze_stats n_distinct on nullable matches heap 15;16;17;18;19 never -
analyze_stats analyze_stats n_distinct on status matches heap 15;16;17;18;19 never -
analyze_stats analyze_stats n_distinct on v matches heap 15;16;17;18;19 never -
analyze_stats analyze_stats no row is offered to the sampler twice 15;16;17;18;19 never -
analyze_stats analyze_stats null_frac matches heap within 0.02 15;16;17;18;19 never -
analyze_stats analyze_stats premise: VACUUM recorded all-visible pages to price with (#507) 15;16;17;18;19 never -
analyze_stats analyze_stats premise: both estimates were taken (#507) 15;16;17;18;19 never -
analyze_stats analyze_stats premise: the cap is exposed as a function, not written inline 15;16;17;18;19 never -
analyze_stats analyze_stats premise: the selective range has its rows (#507) 15;16;17;18;19 never -
analyze_stats analyze_stats reltuples is within 2% of the true row count 15;16;17;18;19 never -
analyze_stats analyze_stats the all-visible fraction does not hand every query to the index (#507) 15;16;17;18;19 never -
analyze_stats analyze_stats the bound does not disable the penalty for a full ordered read (#376) 15;16;17;18;19 never -
analyze_stats analyze_stats the fetch penalty leaves a clustered ORDER BY on its index (#355 must not over-fire) 15;16;17;18;19 never -
analyze_stats analyze_stats the fetch penalty leaves a selective point lookup on the index (#355 vs #171) 15;16;17;18;19 never -
analyze_stats analyze_stats the fetch penalty makes an unclustered ORDER BY sort rather than fetch per row (#355) 15;16;17;18;19 never -
analyze_stats analyze_stats the floor and the derived bound meet where they should 15;16;17;18;19 2026-09-24 the floor moved by one, so the boundary where floor and derived bound meet is off by one
analyze_stats analyze_stats the join plans as a join rather than degenerating 15;16;17;18;19 never -
analyze_stats analyze_stats the penalty is applied before the columnar path is offered, so it can still win (#362) 15;16;17;18;19 never -
analyze_stats analyze_stats the sampled tuples carry a valid item pointer 15;16;17;18;19 never -
analyze_stats analyze_stats the server survived ANALYZE 15;16;17;18;19 never -
analyze_stats analyze_stats without the fetch penalty an unclustered ORDER BY takes the index (#355 premise) 15;16;17;18;19 never -
analyze_stats analyze_stats without the penalty a selective scattered condition takes the index (#362 premise) 15;16;17;18;19 never -
base_scan_io base_scan_io a base scan is not priced from sibling projection pages 15;16;17;18;19 2026-09-21 projPages = 0 (keep whole-file pages)
base_scan_io base_scan_io premise: a covering projection exists 15;16;17;18;19 never -
base_scan_io base_scan_io premise: adding the projection enlarged the relation file 15;16;17;18;19 never -
Expand Down Expand Up @@ -1438,8 +1478,8 @@ harness_selftest 580-a-hand-rebuild-must-record a log that is not there also pro
harness_selftest 580-a-hand-rebuild-must-record a log with content produces a diagnosis to print 15;16;17;18;19 2026-09-24 rebuild.sh forced to fail after its stamp AND _hr_diagnose gutted, so the failure prints no reason
harness_selftest 580-a-hand-rebuild-must-record a rebuild that failed skips them rather than reading a stamp it did not write 15;16;17;18;19 2026-09-24 driven alone, with no forced rebuild failure, because these two arms call the gate with literals and the rebuild's status never reaches them;the gate reverted so a failed rebuild still runs the arms beneath it
harness_selftest 580-a-hand-rebuild-must-record a rebuild that succeeded runs the arms that read its stamp 15;16;17;18;19 2026-09-24 the gate always skips, so a successful rebuild runs none of the arms that read its stamp
harness_selftest 580-a-hand-rebuild-must-record and any other status skips too, rather than being read as success 15;16;17;18;19 2026-09-24 driven alone, with no forced rebuild failure, because these two arms call the gate with literals and the rebuild's status never reaches them;the gate reverted so a failed rebuild still runs the arms beneath it
harness_selftest 580-a-hand-rebuild-must-record an empty log still produces a diagnosis, because silence is the bug 15;16;17;18;19 2026-09-24 _hr_diagnose restored to its silent `[ -s ] || return 0` form, so an empty or missing rebuild.log prints nothing at all
harness_selftest 580-a-hand-rebuild-must-record and any other status skips too, rather than being read as success 15;16;17;18;19 2026-09-24 driven alone, with no forced rebuild failure, because these two arms call the gate with literals and the rebuild's status never reaches them;the gate reverted so a failed rebuild still runs the arms beneath it
harness_selftest 580-a-hand-rebuild-must-record and it distinguishes missing from empty, so the two causes do not merge 15;16;17;18;19 2026-09-24 _hr_diagnose restored to its silent `[ -s ] || return 0` form, so an empty or missing rebuild.log prints nothing at all
harness_selftest 580-a-hand-rebuild-must-record and it names the log as empty rather than printing a bare banner 15;16;17;18;19 2026-09-24 _hr_diagnose restored to its silent `[ -s ] || return 0` form, so an empty or missing rebuild.log prints nothing at all
harness_selftest 580-a-hand-rebuild-must-record and it reads a different source as stale rather than fresh 15;16;17;18;19 2026-09-23 the record call removed from rebuild.sh, so no stamp is written at all
Expand Down
47 changes: 45 additions & 2 deletions test/check_ledger_budget.txt
Original file line number Diff line number Diff line change
Expand Up @@ -15,7 +15,7 @@
#
# Adding a check to a suite that is already covered does not move it, which is
# what makes it safe to bound.
suites_not_covered 249
suites_not_covered 248
#
# checks_never_observed_red -- A CENSUS. NOT a ceiling, and it must not become
# one.
Expand Down Expand Up @@ -1050,4 +1050,47 @@ suites_not_covered 249
# The name the unguarded sweep invents for the second is `a quoted arm that only
# exists in prose` -- an arm that exists nowhere, which is worse than a
# mis-attributed real one. Only the mutation found this; the suite was green.
checks_never_observed_red 1540

# #1252: 1540 -> 1574, AND suites_not_covered 249 -> 248. THE SUITE ITSELF
# ARRIVES IN THE LEDGER, which is most of this diff and needs saying plainly.
#
# `analyze_stats` had ZERO rows on main. Recording that the new arms redden
# means merging a RUN of the suite they live in, and the tool refuses to
# attribute a mutation across partial or multiple runs -- so registering all 40
# of its checks is the mechanism, not scope added on top. Decomposed:
#
# ledger rows 1700 + 40 = 1740
# never 1540 + 34 = 1574 32 pre-existing arms + 2 of the new 8
# dated 160 + 6 = 166 the 6 arms four mutations redden
# 1574 + 166 == 1740
#
# suites_not_covered falls by exactly one, which is the direction that ceiling
# is allowed to move. 20 suites covered before, 21 now.
#
# FOUR MUTATIONS, AND A AND B ARE DISJOINT. That is worth stating because the
# last two changes I made had mutations that were not:
#
# A the floor removed 3 arms x 5 majors
# B the scaling removed 2 arms x 5 majors disjoint from A
# C the input guard removed 1 arm x 5 majors isolates what A also hits
# D the floor moved by one 4 arms x 5 majors the only one reaching the tie
#
# C REDDENED NOTHING ON ITS FIRST RUN and the guard was uncovered, not redundant.
# 0, "", "abc" and a negative all reach the floor anyway because `$(( ))` reads
# them as 0. The input it actually defends is a PARTIALLY numeric token:
#
# pgc_analyze_cap_ms 12abc with the guard 5000
# without it arithmetic error, no output
#
# So an arm was added to cover it rather than the guard deleted -- #1236's
# taxonomy, and the measurement is what chose between the two readings.
#
# TWO OF THE EIGHT NEW ARMS ARRIVE `never` AND CANNOT HONESTLY BE MUTATED HERE.
# `premise: the cap is exposed as a function` is a `type -t` check, and every
# mutation replaces a body while keeping the name. And `ANALYZE on a wide table
# completes well inside its derived cap` has a removal proof rather than a
# mutation: against f82bdcd's parent the unfixed build did not complete in 180 s
# -- an unbounded run was killed at 10m52s of 99.9% CPU -- against 206 ms fixed.
# That is a different tree, so it is not expressible as a same-tree mutation and
# the row stays `never` rather than being dated on evidence of another kind.
checks_never_observed_red 1574
Loading