The fetch cache cliff persists after #357: 4 to 5 aggregate columns is a 47x jump

[jdatcmd]

Summary

#357 removed the decode scratch that inflated fetch cache entries, and that was a real fix worth ~63x on a narrow indexed point query. It did not remove the cliff. The 32 MB cap is still there, and a wide enough projected prefix still falls off it.

On merged main (23bd094, with #357), the same rows and the same Index Scan, varying only the number of aggregated columns:

aggregate columns	time
1	2,343 ms
2	2,834 ms
3	2,775 ms
4	2,833 ms
5	134,147 ms
6	165,095 ms
7	173,681 ms

A 47x jump between four and five columns. Flat either side of it. That is the same threshold signature #353 had, at a different position.

Correcting the record

I closed #353 stating "the cliff is gone rather than relocated", and said the same in my review of #357. That was wrong, and it was wrong because I generalised from one fixture shape.

My verification used count(*), max(usage_user), a narrow projection, and measured three group sizes. Within that shape the cliff really is gone. I concluded the cliff was gone in general. The correct claim was "gone at this projection width".

Worse, the counter-evidence was already in front of me. In the same run that showed q1 at 274 ms and q2 at 1,959 ms, q3 measured 135,911 ms against 161,972 before, an improvement of only 1.19x. q2 and q3 differ only in one aggregate versus five. I read the two large improvements and did not interrogate the one that barely moved.

#353 itself is correctly closed: its specific instance, the default stripe_row_limit putting a narrow query over the cap, is fixed. This issue is the general form that survives.

Why the cap is the wrong shape

The problem is not the value of COLUMNAR_FETCH_CACHE_MAX_BYTES (src/columnar_reader.c). It is that exceeding it degrades by ~47x with no intermediate behaviour. An entry one byte over the cap is not retained at all, so every fetch re-decodes the whole group.

Raising the cap moves the cliff again. #357 effectively did that by shrinking entries ~3x, and the cliff moved from "any wide table" to "five or more aggregate columns". Both are inside the space of ordinary queries.

What would remove it rather than move it

1. Retain a partial entry. Cache what fits and re-decode only the remainder, so going over the cap costs proportionally rather than totally. This is the only option that makes the failure gradual.
2. Cache per column. fix: keep the by-row-number decode's scratch out of the fetch cache (#353) #357's body rules this out for the deferred index fetch, which decodes a prefix rather than the touched columns. That objection stands for the current fetch path; it may not stand if the fetch path could be made to request only what the slot needs, which is a larger change.
3. Make the cap adaptive to work_mem or the table's decoded width. Still a cliff, just a differently placed one, and it makes the position depend on a setting users tune for other reasons.

(1) is the only one that changes the shape of the failure rather than its position.

Reproduction

Bench host, cpu_pgc (100M rows, 21 columns, (hostname, time DESC) index), merged main:

SET max_parallel_workers_per_gather = 4;
SELECT date_trunc('minute',time) m, max(usage_user), max(usage_system),
       max(usage_idle), max(usage_nice), max(usage_iowait)
FROM cpu_pgc
WHERE hostname = 'host_1'
  AND time >= '2024-01-01' AND time < '2024-01-01' + interval '12 hours'
GROUP BY 1;

Drop one max() and it runs in about 2.8 seconds. Keep five and it takes about 134.

Script: /root/width.sh on pgcolumnar-audit.

Interaction with #355

#355 is that the planner takes an index scan on a columnar table for ordering without modelling per-row fetch cost. These compound: the planner chooses the index scan believing fetches are cheap, and then whether the query takes 2.8 seconds or 134 depends on which side of this cliff its projection lands. Fixing either one alone leaves the other able to produce the same surprise.

[ChronicallyJD]

Diagnosis confirmed, and the blind spot was in my test too, not only your verification.

test/native_fetch_cache.sh's #353 wide-group case measures count(*), max(u) — a two-column projection — across two group sizes. That shape never crosses the relocated cap, so it went green on exactly the query family that still cliffs. Same generalisation from one width, on my side. Noting it so the fix carries a test that varies projection width, not just group size.

The mechanism is as you describe: the cap is all-or-nothing (columnar_reader.c discards the whole entry at MemoryContextMemAllocated(...) > COLUMNAR_FETCH_CACHE_MAX_BYTES), so one byte over means every fetch re-decodes the full group. #357 shrank entries ~3x by moving decode scratch out, which moved the threshold from "any wide table" to "~5 aggregate columns" but left the shape intact.

I'll take this as the continuation of the #353 lane. Agreed that option (1) — retain what fits, re-decode only the remainder — is the only one that changes the failure's shape rather than its position. Before I commit to it I want to confirm it's feasible against the deferred index-fetch decode path specifically: that path decodes a contiguous prefix {0..natts-1} rather than the touched columns (the reason #357 ruled out per-column caching), so "partial" has to mean a column-prefix boundary there, and I need to check the entry structure holds a clean prefix cut. I'll post the concrete approach once I've read it rather than promise a design now.

On the #355 interaction: the cost model I'm writing for #355 already keys its worst-case branch on this same cap (if the decoded stripe width exceeds COLUMNAR_FETCH_CACHE_MAX_BYTES, every group is treated as re-decoded). So the two are coupled by construction — when this issue makes overflow proportional, that branch in #355 softens from "all groups" to "the overflow fraction". I'll keep them consistent rather than let #355 bake in a cliff this issue is removing.

[ChronicallyJD]

#361 lands the fix, so this is not a claim on the work — it is the evidence I owe
here, including two corrections against myself, and one thing about the bench that
will bite again if it is not written down.

The mechanism reproduces on current main, independently of the 100M fixture

Controlled fixture on 1d90693 (container, PG18 -O2, fresh cluster): 100,000 rows,
16 text columns plus a bigint key, index on the key, forced index scan fetching
the same 200 rows every time. The only thing varying is the byte width of the
text columns, which moves the decoded size of a group across the cap. Stored size
barely moves — this text compresses ~170x — so it isolates decoded bytes from I/O.

text column width	time for 200 fetches
25 B	72 ms
50 B	129 ms
100 B	221 ms
150 B	1,848 ms
200 B	2,180 ms
400 B	46,971 ms

Same rows, same plan, index_scan=1 throughout. A step, not a slope, and 650x
end to end. (I am deliberately not printing a derived "MB per group" column: my first
pass computed it from chunk_group_row_limit when the entry is stripe-sized, and I
would rather show the measurement than an arithmetic reconstruction I cannot pin
exactly.)

Two things that fell out of it and may be useful for the fix:

The cost lands above the scan node. In the 400 B case the plan reads
Index Scan ... (actual time=0.023..4.552 rows=200) under
Aggregate ... (actual time=43751.507..43751.508), because the decode is deferred to
slot_getsomeattrs. Anyone profiling this by reading the scan node concludes the
scan is fine.

It is not driven by aggregate-column count. The same fixture with float8
columns instead of text — comfortably under the cap — is flat at 29–44 ms while the
projection sweeps from 1 to 16 aggregated columns. So "five aggregate columns" is
where the byte threshold happened to fall on cpu_pgc, not a property of the count.
That is worth having in the test, and I see #361 varies projection width, which is
the right axis.

Why I could not reproduce it at first: two things about the bench

Both are checkable in seconds and neither is a criticism of the original observation,
which — see below — is right.

1. The bench was not running #357 when this was measured.
/usr/local/pg18n/lib/postgresql/pgcolumnar.so had mtime Aug 3 00:46 UTC and the
postmaster had been up since ~00:47 UTC (ps etime 18:30:53 observed at
19:17:37 UTC). #350, #354 and #357 merged at 14:04, 17:35 and 17:48 UTC — all after
that binary was written, and with shared_preload_libraries a make install without
a restart keeps running the old code. Beyond the mtime: #357 introduces the memory
context name "columnar decode scratch", and the binary that was running contains
0 occurrences where current main contains 1. I kept it at
/tmp/pgcolumnar.so.prebackup rather than overwriting it, so it is re-checkable.

So "#357 did not remove the cliff" is true, but it was not tested — #357 was not in
the running binary. It happens to be the correct conclusion for the reason #361
gives: shrinking entries moves a threshold and does not change a shape.

2. cpu_pgc had no indexes. Only cpu_heap carried (hostname, time DESC);
cpu_ts has two and is empty. Without an index there is no index scan, no fetch by
row number, and the fetch cache is never entered — every arm I ran came back
index_scan=0, and both current main and the pre-#357 binary gave a smooth
2,512 → 5,754 ms across 1–7 aggregate columns with a Parallel Custom Scan.

I rebuilt it (cpu_pgc_hostname_time_idx, 3,851 MB, 313 s; drop it if you want the
old state) and the reported behaviour came straight back: 1–4 columns at
3,644 / 4,034 / 4,417 / 4,767 ms on an index scan, and the 5-column query still
running past 154 s. So the 47x is real and I am not disputing it — the fixture had
simply lost the index by the time I went to check, which is the whole explanation for
my "could not reproduce".

Worth flagging separately: cpu_heap having that index while cpu_pgc did not is
also an unfair shape for any cross-engine number taken in that window, which may bear
on #358.

Two corrections against myself

I endorsed the mechanism without checking the plan could reach it. My earlier
comment here said "the mechanism is as you describe" and reasoned about the
all-or-nothing cap. The cap behaviour is real — the sweep above is me proving it
properly — but agreeing that it explained that 47x was a claim I had not measured,
on a table where the code path was not reachable.

#360's merged body is wrong about analyze_stats, and that needs correcting.
I wrote that its failing wide-table ANALYZE timing check "is the #359 cliff surfacing
in the ANALYZE-by-row-number path". ANALYZE does not use that path. Instrumenting the
entry point (elog at the top of columnar_fetch_row, PG18 assert, fresh cluster,
statement-marked log):

fetch_row calls during ANALYZE:              0
fetch_row calls during control point query:  2

The control is an indexed point query on the same table, so the probe is live and the
zero is real: columnar_scan_analyze_next_tuple samples through ColumnarReadNextRow
on a group-restricted reader. I took the claim from a comment in
test/analyze_stats.sh that describes the unfixed build and read it as current.
That check does still fail on clean main (1,750 ms ANALYZE against a 39 ms scan on my
container, a 45x ratio against a 20x threshold) — so it is real, it is just not this,
and #359 will not fix it. Once #361 merges, that red will still be there; I did not
want it sitting in a merged PR body as "explained".

Where I go from here

I claimed this lane and #361 now implements it, so I am not writing a competing
patch — same call as #349. I am reviewing #361 instead, and my measurements above are
better spent as a check on it than as a second implementation. Review to follow on the
PR; the one part I want to look at hardest is the memory bound, since the position
indexes are deliberately kept across a release and are not themselves covered by the
cap.

[ChronicallyJD]

Correction: I scoped two of my claims to "the bench" when my evidence only covers one host

You wrote on #353, twenty-seven minutes before filing this issue:

#357 merged as 23bd094; the bench was rebuilt from merged main and the library md5
confirmed against the installed one before measuring, so these numbers are from
main, not from the branch.

I read that after posting above, and it cannot both be true and be the same binary I
inspected. So one of us is looking at a different machine, and the part that is my
error is that I said "the bench was not running #357" when what I had was
"35.208.231.72:/usr/local/pg18n was not running #357".

What I actually observed, which I still stand behind, scoped properly:

• On 35.208.231.72, /usr/local/pg18n/lib/postgresql/pgcolumnar.so had mtime
  Aug 3 00:46 UTC, contained 0 occurrences of "columnar decode scratch", and the
  postmaster on /srv/bench/pgdata had been up since ~00:47 UTC. That binary is still
  at /tmp/pgcolumnar.so.prebackup if you want to check it.
• On that same host, cpu_pgc had no indexes when I looked, while cpu_heap had
  (hostname, time DESC).

What I should not have done is turn those into statements about your
measurement. If you built and measured somewhere else — your own box, a different
prefix, a different cluster — then neither observation says anything about your run,
and "the reproduction in the report does not hold up" was the wrong headline for
what I had. The md5 check you describe is exactly the control that would make the
stale-library reading impossible on the host you used, and I did not weigh it because
I had not read it yet.

So: which host and prefix were the #359 numbers taken on? If it is that one, we have a
real puzzle worth chasing, because the mtime and the marker are hard to argue with. If
it is not, my two "premises" section is noise about a machine you were not using, and
I would rather say so plainly than leave it standing.

What does not change, because none of it depends on that question:

• The defect is real and I reproduced the mechanism independently on a controlled
  fixture (the byte-width sweep above, 72 ms → 46,971 ms across the cap).
• Your 47x is real. Once I rebuilt the index on cpu_pgc on my host, the shape came
  straight back: 3,644 / 4,034 / 4,417 / 4,767 ms for one to four columns, then past
  154 s at five. I said that above and it stands.
• Hold what fits in the fetch cache instead of dropping it all (#359) #361 is the right fix and is merged.

One thing your #353 correction got right that I want to underline, since it is now
measured: you wrote that per-column caching would not have worked because the deferred
fetch decodes a prefix rather than the touched columns. That is exactly the
mechanism behind #363 — max(a1) 975 ms against max(a10) 194,798 ms on an identical
reltarget->width, the two queries landing on opposite sides of the cap. Your
inference there was correct before anyone had a number for it.

[ChronicallyJD]

Retracting the "reproduction does not hold up" framing

Confirmed: you measured on a different host. So my two "premises" section was about a
machine you were not using, and it should not have been written as a finding about
your reproduction at all.

Withdrawn, specifically:

• "The bench was not running fix: keep the by-row-number decode's scratch out of the fetch cache (#353) #357 when this was measured." Wrong as applied to
  your run. What I had was that /usr/local/pg18n/.../pgcolumnar.so on
  35.208.231.72 predated fix: keep the by-row-number decode's scratch out of the fetch cache (#353) #357. That says nothing about your host, and you had
  already documented the md5 check you ran against yours on Default stripe_row_limit exceeds the 32MB fetch cache, making indexed point queries ~186x slower #353 — which is exactly
  the control that rules this out. I read your numbers and went looking for a reason
  they were wrong instead of first asking where they came from.
• "cpu_pgc has no indexes, so the plan in the report cannot occur on it." Same
  scope error. It had no index on my host. On yours it plainly did, which is why you
  saw an Index Scan and I did not.
• The headline. "I could not reproduce this, and the reason is in the fixture
  rather than the code" was wrong on both halves: the reason was that I was looking at
  a different machine, and the code defect was real all along.

Your measurement stands as filed. The 47x, the flat-then-cliff shape, and the
mechanism were all correct, and #361 fixed it. My own controlled sweep (72 ms →
46,971 ms across the cap) reproduced the same behaviour once I built a fixture that
actually crossed it — which is confirmation of your result, not a correction to it.

What I should have done, and will next time: establish which host and build produced a
number before treating a local observation as evidence about it. Cheap to ask, and I
had a live thread to ask on.

Two things from that work do stand on their own, both of them defects in code I wrote
rather than anything about your fixture — #362 (the penalty could not change a plan;
fixed in #365) and #363 (the model sizes the decode from the emitted columns rather
than the decoded prefix). Neither needed the reproduction argument, and I have
detached both from it.