Collector store-writes are cancelled by the store's own CAGG refresh and compression: a lock convoy on query_store_stats

[erikdarlingdata]

Collector store-writes are being cancelled by the store's own background jobs. Every collector write error in a 7-day window falls inside a running continuous-aggregate refresh or compression window — not near one, contained within one.

The containment, joined rather than eyeballed

collect.collection_log ERROR rows joined against timescaledb_information.job_history on the SQL Server store, 40 of 40 contained:

09:01:25-09:25:18  8 errors, 5 collectors   inside CAGG refresh   08:25:10 -> 09:36:11
09:11:16           3 servers, 11 ms apart   inside CAGG refresh   09:07:03 -> 09:12:14
09:38:23-24        8 errors, 6 collectors   inside COMPRESSION    09:25:58 -> 09:39:00
10:40:43-56        5 errors                 inside CAGG refresh   10:38:59 -> 10:47:20
11:19:44-11:24:31  5 errors                 inside CAGG refresh   11:16:00 -> 11:35:25

Three different servers failing 11 ms apart cannot be a target-side coincidence — independent RDS instances do not synchronise. The only shared dependency is the service's store connection. The collector roster is also not query-path-specific: wait_stats, spinlock_stats, ag_database_replica_states and query_snapshots all appear.

The mechanism, from a live lock sample

holder  5912  Refresh Continuous Aggregate   holds AccessShareLock      running 5,507 s
waiter   392  Columnstore Policy             wants AccessExclusiveLock  blocked
waiter  5684  Refresh Continuous Aggregate   wants AccessShareLock      blocked
waiter  2768  client backend                 wants AccessShareLock      blocked

A lock convoy. The refresh holds a shared lock for 92 minutes; the compression policy queues an exclusive request behind it; and because a queued exclusive blocks every subsequent shared request, collectors and readers pile up behind it even though their shared lock is compatible with what is actually held. Convoy head is compression waiting on refresh; the tail is ordinary collector traffic.

Why the refresh is long enough for this to happen

The hourly CAGG refresh over query_store_stats runs 3,300-6,300 s — 118-175% of its own schedule interval. Because the next start is scheduled from the previous finish, an hourly job taking 55-105 minutes occupies roughly half of all wall-clock. Two days earlier it took ~2%.

15:30 ->  61s    17:32 -> 142s    19:42 ->  509s
20:50 -> 5,543s    23:23 -> 6,304s    08:25 -> 4,261s

Three CAGG jobs and one compression policy, all on query_store_stats, were Running concurrently at sample time, with three autovacuum workers on the same chunk space (one for 9,066 s). The refreshes' wait events are IO/DataFileRead and IO/DataFileWrite — they contend for disk with each other as well as blocking.

What is NOT the cause

Not ingest volume. Rows arriving into query_store_stats per hour fell over the same period — 999,101 at 19:00 down to 359,605 at 08:00 — while refresh duration rose ~8x. Run counts moved +23%. The relationship is inverse; "more rows to materialize" is falsified.

Not retention. The application-level purge runs once daily and none of its runs is near a burst; the in-database retention policies do not appear in the containment set either. The correlate is refresh and compression specifically.

Suggested direction

The convoy head is compression contending with refresh on the same hypertable, so schedule deconfliction is the narrowest lever — prevent policy_compression and the CAGG refresh policies on query_store_stats from overlapping. That is independent of collection settings and costs no throughput.

Shortening the refresh (a smaller materialization window per run, or a longer schedule interval) treats the same head from the other side. #2316 already records that query_store_stats is the store's problem child on compression ratio; it is the hypertable to look at, not the collectors.

Not verified

What made the first refresh cross its cadence is unproven. A sweep-concurrency change landed three minutes before the 509 s -> 5,543 s step, and equal volume delivered by more simultaneous writers would raise IO and lock-hold overlap without raising ingest — which fits the measurements — but that is a hypothesis and the concurrency change has since been reverted, so the natural experiment is running now rather than concluded.

Also unmeasured: whether the same convoy exists on the sibling SQL Server store, which carries a much smaller query_store_stats.

[erikdarlingdata]

Root cause found, and it is not concurrency. The issue above says "what made the first refresh cross its cadence is unproven" and floats a sweep-concurrency hypothesis. That hypothesis is wrong and can be retired.

Each hourly continuous-aggregate refresh carried start_offset = '3 days' against a hypertable with 4-day retention. So every hourly run re-materialized roughly 75% of the entire hypertable, every hour. The work per run is set by the window being re-scanned, not by the rows that arrived in it.

That explains the measurement that falsified the concurrency story: refresh duration rose ~8x while ingest fell ~3x (999,101 rows/hour down to 359,605) and run counts moved only +23%. Cost was never going to track ingest, because ingest was not what the refresh was paying for. It was paying for three days of scan, and that got more expensive as the hypertable grew — which it did, roughly 2.5x in sixteen days.

It also explains why the convoy became self-sustaining rather than transient: a refresh whose cost is proportional to retained volume rather than arrival rate has no reason to come back down on its own.

Treatments applied (both operator changes on the live store, recorded here so the duration series is readable):

1. All 13 hourly CAGG refreshes narrowed from start_offset '3 days' to '1 day'.
2. The query_store_stats job family staggered rather than left coincident — the three refresh policies and the compression policy moved to distinct next-start offsets within the hour, so the exclusive-lock request that heads the convoy no longer queues behind a refresh that is already running.

Daily jobs untouched. A sweep-concurrency setting was also reverted in the same window for unrelated reasons, so attribution between the three is deliberately confounded — fixing was chosen over clean experiment ordering. What stays cleanly readable is whether the convoy stops at all, and whether per-run refresh duration steps down by an amount consistent with scanning one day instead of three.

One remedy considered and rejected on a real constraint: giving the background jobs a lock_timeout so a blocked refresh quits and retries rather than heading a convoy. It cannot be done as a role-level setting — every TimescaleDB background job runs as the same role as the collectors, so a role-level lock_timeout would cap collector sessions too. It has to be a per-job wrapper, which makes it a code change rather than a configuration one.

Credit for the start_offset/retention mismatch to the reviewer working the store-side audit; I had the symptom and the containment evidence and the wrong mechanism.

[erikdarlingdata]

The operational half is closed, at the numbers. This issue now exists for the durable half. Everything below was measured on the live store; the config changes were operator actions authorized and applied same-day, and this comment is the record the code lane should work from.

What happened, condensed

Root cause: every hourly continuous-aggregate refresh carried start_offset = '3 days' against a hypertable with 4-day retention, so each run re-materialized ~75% of the table — cost proportional to window size, not ingest (measured: refresh duration rose ~8x while rows/hour fell ~3x). As the runs stretched past their cadence, the three refresh policies and the compression policy on the same hypertable began overlapping, and the lock queue turned it into a convoy: refresh holds a shared lock, compression queues an exclusive request behind it, and every subsequent shared request — including collector store-writes — queues behind that. 40 of 40 collector write errors in the window fell inside a running refresh or compression window; at the worst sample, three servers' collectors failed 11 ms apart.

The fix, and its result

Two config changes: start_offset narrowed to '1 day' on all hourly refreshes, and the family staggered (:00 / :15 / :30 / :45, compression :52). First full staggered cycle:

job	pre-treatment	post
hourly refresh A	126–2,134 s	26 s
hourly refresh B (the heavy one)	3,301–6,330 s, i.e. 118–175% of its own cadence	864 s = 24% of cadence
hourly refresh C	137–1,165 s	140 s
compression	up to 2,679 s (queued)	background

Ungranted locks: 0 on every sample since. Service-log errors 61/hr → 3/hr; relaunch-skips 87/hr → 7/hr; collector ERROR rows for the first post-fix hour: 0.

At 24% of cadence the heavy refresh cannot outrun its own schedule anymore, so the self-sustaining overlap is structurally gone, not just currently absent.

The two changes are complements, not alternatives. The heavy refresh is still ~33x its lightest sibling even on the 1-day window; the stagger is what makes its 864 s invisible to everyone else. A fix that keeps only one of them re-opens the door.

Scope for the code lane

1. Deconfliction as shipped configuration — the stagger, expressed wherever job schedules are provisioned, not left as a hand-applied offset on one store.
2. Per-job lock_timeout wrapper so a blocked background job yields and retries instead of heading a convoy. This cannot be a role-level setting: every TimescaleDB background job runs as the same role as the collectors, so a role-level lock_timeout would cap collector sessions too. Per-job, in code.
3. The trap-shaped one: the provisioning ladder must emit the narrowed start_offset. A store rebuilt from the ladder today inherits '3 days' and silently regresses to the exact condition above, with nothing failing until the table grows into it. This is the same class as a CREATE-rung floor: the live store was fixed by hand, and only the ladder makes the fix survive a rebuild. Pin it — a laddercheck-style assertion that the generated policy config matches the constant would hold it.
4. Size everything against 864 s as the heavy refresh's steady-state cost.

Parked follow-on, deliberately not in scope

Re-raising max_concurrent_sweeps to 8 becomes a clean question again once the durable half lands: the convoy that made C=8 expensive is structurally gone, the staleness goal that motivated it is still unrealized at C=4, and duration_vs_cadence_percent on the store's background jobs is now on the watch list from day one — the instrument whose absence is why the cost went unseen last time. That is a decision, not a task; it waits for the owner to want it.

Corrections absorbed along the way, so the thread reads true

My original concurrency hypothesis for the refresh blow-up was wrong (falsified by the ingest measurement above); the start_offset/retention mismatch came from the store-side audit, not from me. And an interim claim that the alert pass had a standing ~11/hr failure residual was contaminated by the tail of the final pre-treatment run — fully quiet, the rate is ~3/hr, the pre-incident noise floor, and no standing residual exists.

[erikdarlingdata]

Closed by #3024.

Both treatments are durable in code, and the second one was the urgent half

Narrowing: TimescaleSupport.HourlyRefreshStartOffset = "1 day" plus a TimeSpan twin, applied to all 13 hourly policies. Daily untouched at 3 days, and RefreshPhaseMinutesFor throws for a daily view.

Stagger: RefreshPhaseStepMinutes = 15 and HourlyRefreshPhaseOrder emitted as initial_start — which also switches each job to a fixed schedule, and that is the half that stops finish-to-start drift.

Keyed on view identity, never a job id: the converge recovers view_name through a jobs→continuous_aggregates join, and the job id reaches alter_job only as a bound $1::integer.

Why the fixed schedule was the urgent part, measured rather than assumed

The hand-applied treatment was already eroding. Every job carried fixed_schedule = f, and within roughly two hours only 1 of 6 hourly refreshes was still on the slot it had been set to.

The drift arithmetic, confirmed live: job 1054's next start was exactly its finish + 1 hour, so the heavy refresh drifted by its own runtime every cycle — 3 to 14 minutes per hour. It laps the hour in days, not the weeks anyone had inferred from watching compression crawl. A stagger that drifts by its own runtime is not a stagger with a slow leak; it is a stagger on a countdown.

The root cause this issue's own author said their filing had wrong

QueryStoreBackfill.Horizon was RetentionTierRouter.RawMaxAge alone, which read as correct only because the refresh window happened to also be 3 days — the retention term standing in for the refresh term, so every retention increase silently bought refresh cost. Now the smaller of the two conditions (23 h), with the refresh term binding.

max_concurrent_sweeps = 4 already had a correct durable home — three code defaults at 4, no key in either sample config. No change made.

Three things the live converge test found that reading could not

1. The catalog join was wrong. timescaledb_information.jobs reports the user view, not the materialization hypertable, so the converge's read matched nothing — it would have reported a tidy zero on every store. An inert fix with a green suite, found only because a live converge test was made a merge condition.
2. add_continuous_aggregate_policy raises 22023 against a differing window; it does not return -1 like its compression and retention siblings. That moved the converge before the create. The premise had been asserted as fact in the first PR description and in doc comments.
3. Review then caught two more: the distinctness check was asserting an incidental property, and the horizon narrowing was reaching plain-PostgreSQL stores where no rollups exist — now HorizonFor(bool).

The measured outcome

Job 1054 post-treatment: 864 s against a 3,301–6,330 s pre-treatment band, and 118–175% of its cadence down to 24% — so it can no longer outrun its own schedule. First full staggered cycle: 26 s / 2 s / 864 s / 140 s. Ungranted pg_locks at 0 on every sample since. Service-log errors 61/hr → 3/hr, relaunch-skips 87/hr → 7/hr, and the store has since run two full hours at zero errors and zero yields — the cleanest state observed all day.

Not verified

The plain-PostgreSQL horizon branch is unit-pinned but not exercised live. A TimescaleDB too old to expose initial_start is untested. The 15-minute/4-slot grid is the measured configuration, not a demonstrated optimum. The daily tier keeps finish-to-start deliberately.

Compression policies still drift and are not pinned — filed as #3035. The 16:52 collision that did fire was harmless for a structural reason (the 1-day narrowing makes refresh and compression chunk sets mostly disjoint), which downgrades that issue's threat model from "convoy at alignment" to "boundary-chunk contention" rather than removing it.