Repository navigation
Tightening plan_content_retention_days permanently stops retention on query_plan_dim (one-day slice exceeds the 300s delete timeout) #2386
Description
Setting plan_content_retention_days to a value that creates a backlog turns retention off on query_plan_dim — permanently, silently, and on the largest table in the store. Making the horizon stricter is what breaks it.
Found on the use2 dogfood store by a prediction I registered in advance on #2316 and which did not come true.
Evidence
The knob went from its default 21 to 14 at 2026-08-19 11:25, moving the cutoff back seven days. Every purge since has failed on the same table:
08-19 11:11 58 table(s), 407167 row(s) deleted, 19 chunk(s), 0 failed, 150097ms <- knob still 21
08-19 17:42 57 table(s), 0 row(s) deleted, 0 chunk(s), 1 FAILED, 301057ms
08-19 18:27 57 table(s), 0 row(s) deleted, 0 chunk(s), 1 FAILED, 301463ms
08-19 20:13 57 table(s), 0 row(s) deleted, 0 chunk(s), 1 FAILED, 600253ms
08-19 20:58 57 table(s), 0 row(s) deleted, 0 chunk(s), 1 FAILED, 301238ms
Retention purge failed for query_plan_dim: Exception while reading from stream
301057ms and 301463ms are not workload variance — that is DeleteTimeoutSeconds (300 s) expiring on the command.
The dimension has not moved in a day, and normal ingest has already refilled the one dip:
| day | plan_dim | rows |
|---|---|---|
| 08-18 | 129.0 GB | 12,359,332 |
| 08-19 | 132.6 GB | 11,850,329 |
| 08-20 | 132.6 GB | 12,380,713 |
The 08-19 dip is the 11:11 sweep, which ran while the knob was still 21. Everything after it deleted nothing.
Mechanism
TimeSlicedDeleteSql deletes the oldest one-day slice per statement, and that width is the work bound: "one day of arrival volume per statement — exactly what a steady-state daily purge deletes in total".
That reasoning holds for a narrow fact row. It does not hold for this table. query_plan_dim rows average ~9.5 KB (gzipped plan XML, measured), and the table takes ~740 k rows/day, so one day-slice is ~7 GB of TOAST deletion in a single statement. That does not finish in 300 s, the command times out, the transaction rolls back, and zero rows are deleted. The next sweep retries the identical doomed slice.
So the failure is self-perpetuating and gets more certain over time: the table grows ~500 k rows/day while the slice it can never delete stays just as large.
Why only one box is affected, and why that is the worrying part
use2 plan_dim 132.6 GB oldest last_seen 07-28 1 failed, 301s
use1 plan_dim 25 GB oldest last_seen 08-17 0 failed, 160ms
vm3 plan_dim 24 kB - 0 failed, 116ms
use1 has the same knob (14) and the same code, and is fine — its dimension is small enough that nothing predates the cutoff, so there is no slice to delete. This does not bite until the table is large enough that one day of it cannot be removed in 300 s. use2 has crossed that line; any store that grows past it crosses too.
The feature that exists to bound this table's growth is exactly the feature that stops working once the table is big. And it fails in the direction that makes the problem worse.
Severity
This is in shipped 3.5.0 (V75, #2316). An operator who turns the knob down on an established store gets a silent, permanent retention failure on their biggest table. The only evidence is one [WARN] line per sweep and a 1 failed count in an INFO summary — nothing surfaces it.
Also note the shape: use2 was fine at 21 (small residual slice, 150 s, succeeded). Tightening the horizon is what broke it. That is the opposite of what an operator expects from a retention setting, and it means the natural response to "my store is too big" makes the store grow.
Fix directions
- Bound the slice by ROWS, not only by time. The row-capped
ctididiom was abandoned (Gated live-pg suite: two purge tests count globally in the shared store — order-dependent flakes (TimescaleSupport chunk-drop, DarlingRetention row-delete) #1564) because readingctidthrough TimescaleDB's transparent decompression is unsupported on compressed chunks — butquery_plan_dimis a plain table, not a hypertable, so that constraint does not apply to it. A row cap bounds the work regardless of how wide the rows are, which is the property the day-slice was standing in for. - Or make the slice width adaptive — sub-day slices when mean row width is large.
- Raising
DeleteTimeoutSecondsonly moves the wall further out; the table keeps growing into it. - Independently of the fix: a repeated failure on the same table must escalate. Four consecutive identical failures on the store's largest table should not be a WARN that scrolls past. [TEST FLAKE] Two live-store tests fail on unrelated diffs and pass on re-run (scale-test noise floor, and a database-state heal race) #2266 added transition-logging for exactly this class of silent skip; the same treatment belongs here, and arguably a self-alert.
Immediate mitigation for this store
Setting the knob back to 21 restores a slice small enough to complete, at the cost of the seven days of content the tighter horizon was meant to reclaim. I have not changed it — flagging first.
Activity
erikdarlingdata commentedon Aug 20, 2026
Measured the actual slice arithmetic. Two corrections, and the second raises the severity.
1. "0 row(s) deleted" is wrong — work IS happening, and the count is thrown away
min(last_seen)has advanced from 07-28 11:09 to 07-29 11:09 across the four "failed" purges. EachExecuteNonQueryAsyncin the drain loop autocommits, so an early slice commits and a later one times out — thenPurgeOneAsynccatches the exception and returnsnull, soDrainBatchesAsync's running total is discarded andtotalRowsDeletednever sees it.So the summary line reports
0 row(s) deleted, 1 failedfor a sweep that actually deleted ~755 k rows before hitting the wall. An operator reading the log concludes nothing is happening; the truth is one slice per sweep lands and the rest is lost. Returning the partial count instead ofnullon timeout would fix the reporting half.2. The steady state is marginal at ANY knob — this is not just a tightening problem
The slice is bounded by
min + 1 dayAND by the cutoff, whichever is tighter. That is why knob 21 works right now: it caps the slice at 260 k rows, which completes.But once that drains,
mintracks the cutoff, and both advance one day per day. Every subsequent sweep then faces exactly one day of arrival volume — ~755 k rows at ~9.5 KB each, ~7 GB of TOAST in one statement. That is the size that has been timing out.So use2 gets stuck again within a day or two at knob 21, and would at 20, 19, or any other value. The tightening did not create the problem; it just arrived at it seven days early. Any store whose daily plan-content volume cannot be deleted in 300 s has permanently broken retention on its largest table, and the table only grows.
This also means a step-down strategy (drop the knob one day, let it prune, repeat) does not work: each step exposes a full day-slice, which is precisely the thing that fails. The slice width has to come down, not the horizon.
What that means for the fix
The row cap is not a nice-to-have.
TimeSlicedDeleteSql's comment justifies the one-day width as "exactly what a steady-state daily purge deletes in total" — true, and that is the problem: for this table a steady-state daily purge is more than one statement can do inside the timeout.query_plan_dimis a plain table, not a hypertable, so thectid-based row cap abandoned in #1564 for compressed-chunk reasons is available here. A cap of ~100 k rows would put each statement at roughly a gigabyte and well inside the budget, and the drain loop already handles "keep going until a batch clears nothing".Interim, for this store: knob is back to 21 (
config_version108 → 109 so the reload beacon applies it without a restart). That clears the immediate 5.5 M-row backlog attempt and lets the 260 k drain. It is a reprieve, not a fix — expect the1 failedto return once normal aging produces full-day slices again.erikdarlingdata commentedon Aug 20, 2026
Ran the experiment on the live store rather than guessing constants. Three results, one of which corrects something I said earlier in this issue.
1. The
min()subqueries are free — the delete is the whole cost0.364 ms, 5 buffers. Running it three times per statement costs nothing. All of the 300 s is spent removing rows whose TOAST payload averages ~9.5 KB, plus maintenance on two indexes.
2. Throughput is ~1,000 rows/sec, and linear
Then a full drain of the remaining backlog, four batches at cap 50,000:
So the current one-day slice of 755,764 rows needs ~755 s against a 300 s timeout — 2.5x over, not borderline. No choice of horizon avoids it, which is why the step-down idea fails: every step exposes a full day.
Cap 50,000 is the recommendation. At the worst observed rate that is 60 s, ~5x margin under the timeout — the margin matters because a loaded box will be slower than an idle one. 100,000 would run ~97 s nominal, but a 3x slowdown puts it at ~291 s, against the wall. A full day then drains in ~16 batches, roughly 13 minutes of background work, which is simply what removing 7 GB of TOAST costs.
A row cap also restores the original
DrainBatchesAsynccontract. The time-sliced version had to passbatchSize: 1because "the time-sliced statement has no row cap, so 'fewer than the cap' degenerates to 'deleted zero rows'". With a real cap,deleted < capis again the natural terminator — and the run above shows it working: 30,477 < 50,000 ended the loop, and the stray 208 rows that aged in mid-drain were picked up by the next pass rather than ending it early.3. Correction: this does NOT reclaim disk
I said earlier this path would reclaim ~40 GB. That was wrong.
180,477 rows and ~1.7 GB of TOAST deleted, and both figures are unchanged.
DELETEmarks tuples dead; autovacuum makes the space reusable inside the existing file, it does not return it to the filesystem. OnlyVACUUM FULLdoes that, and it rewrites the whole table under an exclusive lock — not something to do automatically to a 133 GB table.So the correct promise for this whole line of work is retention caps growth, not "the store shrinks". #2316's framing should say so too: a working horizon means plan_dim plateaus at roughly
daily volume x horizon, with the on-disk figure staying at its high-water mark. Anyone expecting the number to fall after a fix will think it is still broken.State of this store
Backlog drained to zero by hand at the knob-21 horizon; oldest
last_seennow tracks the cutoff at 07-29 19:41. The1 failedshould stop until normal aging produces the next full-day slice, at which point it returns — that is the bug, and the row cap is the fix.Cap the plan dimension's purge by rows instead of by a time slice (#2388
erikdarlingdata commentedon Aug 20, 2026
#2388 is on the use2 store and the plan dimension is purging again. First run under it:
58 tables, not 57 —
query_plan_dimis back in the successful set for the first time since the knob change yesterday. Against the four preceding sweeps that each read57 table(s) purged, 0 row(s) deleted, 1 failed, ~301000ms.Verified in the store rather than taken from the log line:
MIN(last_seen)The floor advanced to within a minute of the cutoff and the backlog drained to the 822 rows that aged in during the sweep itself.
What this does and does not prove
Does: the row-capped statement executes correctly in situ — bare table name resolving through
search_path,$1binding, oldest-first ordering advancing the floor, and the drain loop terminating on a short batch.Does not: exercise the multi-batch drain. 22,857 rows is well under the 50,000 cap, so this was one batch plus the terminator. The real test is the next scheduled purge (~20:28 UTC tomorrow), when a full day — ~755 k rows — has aged past the cutoff. That is the exact case that failed every time for the previous day, and it should take ~16 batches and roughly 13 minutes.
Leaving this open until that run lands. Closing on a single-batch pass would be claiming more than the evidence supports.
plandim_sizeis unchanged at 133 GB, as expected — deleting rows does not return space to the filesystem. The store's 208 → 207 GB move is other tables' chunk drops, not this. See the framing correction on #2316.erikdarlingdata commentedon Aug 21, 2026
Measured on
prod-sql-use2-monitor-01this morning. The box is on 3.5.0.0 (built 2026-08-20 20:15), so #2388's row cap is not deployed — this is the unfixed behavior, and it is worse than "retention stops."The store right now
What the purge log shows
The 407k sweep is #2316's knob change landing. Then four consecutive runs die on
query_plan_dimat ~301s — the 300s delete timeout, surfacing as Npgsql'sException while reading from stream. Each of those deleted zero rows: the statement is unbounded, so a timeout rolls back everything it had done.The part I had wrong, and the part that matters
I have been treating this as "retention stops, then recovers." The 08-20 run recovering to
0 failedlooked like recovery. It is not — put the log next to the row series and the two disagree:The 08-20 purge reported success while
query_plan_dimgrew by 366k rows that day. It succeeded by peeling a thin time slice, not by draining the backlog — exactly the mechanism I measured when the 21→20→19 step-down idea fell over: slice width is set by the data at the old end, not by how far behind retention is.So the steady state is not "stopped." It is retention deleting roughly 6% of what crosses the horizon each day. Ingest puts ~380k rows/day past the 21-day line; the purge removes ~23k. It falls behind ~360k rows/day, forever, and reports
0 failedwhile doing it. That is the worst of the three possible failure modes, because nothing alerts on it.The 1,158,464 rows currently past the horizon are the accumulated shortfall.
Why the file size looked reassuring
total_byteshas been pinned at 142.44 GB since 08-19 while rows climbed 630k. That is not retention winning — it is the 407k-row sweep having freed space inside the file that new inserts are now refilling.DELETEmarks tuples dead and the space is reusable, not returned. Once the reclaimed space is consumed the file resumes growing, and there is nothing left to absorb it.This confirms #2388 is the right fix
The row cap turns the one statement that must finish inside 300s into batches of 50k that each finish easily, looping until the slice is drained. Against the numbers above it clears the 1.16M backlog in ~24 batches instead of timing out at zero.
Two things follow.
#2386 is confirmed, and 3.5.0 ships it. Any 3.5.0 store whose
query_plan_dimdelete exceeds the statement timeout gets a purge that silently accomplishes nothing, and any store where it does not gets a purge that quietly falls behind ingest. Recommending 3.5.1 carrying #2388 and #2390 — this is a data-growth bug with no user-visible signal, which is the kind that gets discovered as a full disk.Keep the knob at 21. The 08-20
updated_bynote is right for 3.5.0 and wrong after #2388 deploys: 14 was rejected because the first slice exceeded the timeout, which is precisely what the cap removes. Retightening is a post-deploy decision, and it should be made from the row counts above rather than stepped blindly.erikdarlingdata commentedon Aug 21, 2026
Deployed current
dev(which carries #2388) toprod-sql-use2-monitor-01and watched the restart-triggered purge run against the real table. The fix works. And in measuring it properly I found that part of my analysis this morning was wrong — that half first, because it is the part that would mislead someone.The fix, verified
Caught mid-run, the statement executing was exactly the new form, at ~12–16 s per batch against a 300 s statement timeout:
And it drained rather than peeled — the whole point of the change:
Note the total run took 340 s, longer than the single-statement timeout that used to kill it. That is the argument for bounding by rows rather than by time in one sentence: the work was always going to take ~6 minutes, and the only question was whether it happened as one statement that dies at 300 s having accomplished nothing, or as batches that each finish in 16 s and commit.
What I got wrong
I wrote this morning that retention was "deleting roughly 6% of what crosses the horizon" and "falling ~360k rows/day behind." That is not what the numbers showed, and the error was mine.
I measured the backlog as
last_seen < now() - interval '21 days', using the knob value. The purge's actual cutoff is the knob plus a one-day margin — 22 days — for the hourlylast_seenrefresh guard. So a large share of what I counted as an unpurgeable backlog was simply not eligible yet. Measured against the real cutoff:The second mistake compounded it. I compared rows deleted per day against total row-count growth per day and called the difference "falling behind." Those are not comparable: almost all of that growth is rows too young to be eligible for another 22 days. A dimension table younger than its own retention window grows by construction, and that is not retention failing — it is the window filling.
So the 2026-08-20 purge deleting 22,857 rows while the table grew 366k was not a silent partial failure. On that day the data span had barely crossed the cutoff, so a small eligible set is exactly what a correct purge deletes. I read a correct run as a broken one.
What was genuinely broken, and still is worth the release
The four consecutive failures on 08-19 are real and unaffected by any of the above:
Zero rows deleted, four times, because an unbounded DELETE that hits the statement timeout rolls back everything it had done. That is the defect, that is what #2388 fixes, and today's run is the proof: the same table, the same horizon, 451,644 rows removed with
0 failed.A falsifiable prediction to check tomorrow
The table now holds exactly its retention window — oldest
last_seenis 22.0 days old against a 22-day cutoff — so it has reached the point where daily purge should approximately equal daily inflow. Total is 12,078,418 rows (down from 12,480,070).If my corrected reading is right, the row count plateaus near 12.1 M from here rather than continuing to climb ~300k/day. If it keeps climbing at that rate, my correction is itself wrong and the original "falling behind" reading deserves another look. Recording it now so tomorrow's number settles it either way rather than being interpreted after the fact.
devis also deployed toprod-sql-use1-monitor-01andprod-sql-use1-pgmonitor-01for the same soak. #2390 gets its real exercise on use1, which holds the live Query Store data.erikdarlingdata commentedon Aug 21, 2026
Closing: fixed by #2388, covered by a live test in #2397, and verified against the real failure state today.
devwas deployed toprod-sql-use2-monitor-01— the box in the exact condition this issue describes — and the restart-triggered purge was caught mid-run:Afterwards: 0 rows past 23 days, 7,400 past the 22-day cutoff (all of which aged in during the 340 s run), oldest surviving
last_seenexactly 22.0 days old. Against four consecutive runs on 08-19 that hit ~301 s and deleted zero rows each.The detail that justifies the whole approach: the run took 340 s, longer than the statement timeout that used to kill it. The work always needed ~6 minutes. The only question was whether that happened as one statement that dies at 300 s having committed nothing, or as batches that each finish in ~16 s and commit as they go.
Two corrections to what I wrote on this issue
The backlog figure was measured against the wrong cutoff. I used
now() - interval '21 days', taking the retention knob at face value.ComputeDimensionCutoffsubtracts the knob plus a one-day margin for the hourlylast_seenrefresh, so the real cutoff is 22 days. The difference is not marginal:And "retention is deleting 6% of what expires, falling 360k rows/day behind" was a category error. I compared rows-deleted-per-day against total row-count growth per day. Those are not comparable — nearly all of that growth is rows too young to be eligible for another 22 days. A dimension table younger than its own retention window grows by construction; that is the window filling, not retention failing. So the 08-20 purge that deleted 22,857 rows while the table grew 366k was a correct run that I read as a broken one.
What survives untouched is the defect itself: four consecutive purges deleting zero rows because an unbounded DELETE that hits the statement timeout rolls back everything it had done.
Follow-ups already split out
ORDER BYearns its cost needs measuring against a real backlog.Prove the row-capped drain actually drains, against real PostgreSQL (e…
The purge log says which cutoff it used and whether it drained (erikd…