Hive
kura: snapshot index reconcile costs ~5x its memory budget and runs at 100% duty cycle, driving nodes to Critical and stalling replication
GitHub issue · Open
On 2026-07-22, kura-tuist-eu-central-1-1 (production, eu-central) went from Constrained to sustained Critical memory pressure at 16:02Z and stayed there. Critical pauses the outbox worker outright, and the pod’s replication outbox went from 0 to 103,576 messages in 25 minutes.
The trigger was the action-cache snapshot index reconcile, which started at 15:55:11Z — the first snapshot fetch this process ever served. Two defects compound:
- a reconcile pass allocates roughly 5× the memory budget it reserves, and
- a pass takes longer than the freshness window it is kept fresh to, so it runs continuously rather than periodically.
Either alone would be tolerable. Together they turn a node sitting 230–330 MB under its hard limit into one pinned at Critical, and the only thing memory pressure sheds is peer replication.
Grafana links are included, but the raw series are inlined in the appendix because they age out of retention within days.
Impact
Critical ⇒ MemoryController::pause_outbox() ⇒ outbox_task_loop skips process_outbox entirely:
// kura/src/replication/mod.rs:221
let pause_outbox = state.memory.pause_outbox();
state.metrics.update_background_work_paused("outbox", pause_outbox);
if !pause_outbox && let Err(error) = process_outbox(&state).await { ... }
// kura/src/memory/mod.rs:146
pub fn pause_outbox(&self) -> bool {
self.pressure() == MemoryPressure::Critical
}
kura_background_work_paused{worker="outbox"} goes to 1 at 16:02Z and never returns to 0. The outbox climbs monotonically from there. Peer replication requests decay from 11,861 to 5,798 per 5 min while 13k–23k artifact writes per 5 min keep arriving.
This is not a lone data point — the mesh is broadly backlogged. At 16:20Z: kura-tuist-eu-central-1-0 = 913,842 outbox messages draining ~630 per 5 min, kura-tuist-scw-fr-par-0 = 64k–120k.
Timeline (UTC, 2026-07-22)
| Time | Event |
|---|---|
| ~13:10 | pod becomes Ready after its cold bootstrap (kura_ready_state 0→1); pressure has been Constrained since before 12:00 and never returns to Normal |
| 13:00–15:55 | RSS flat 1.48–1.60 GB. jemalloc_allocated flat at 356–358 MB. Outbox flat at 0 all day. No snapshot index has ever been built (zero snapshot log lines from 06:00Z on) |
| 15:55:11 | first action-cache snapshot index build started, namespaces tuist and mastodon, 225 µs apart — both cold, Serve-triggered |
| 15:56:30 | first Critical transition; RSS +310 MB in 2.5 min (1.485 → 1.795 GB) with no client write traffic yet |
| 15:57:23 | pass 1 completes: changed=100000 (the cap), cascade-deletes 30,919 entries, elapsed_ms=132303 |
| 15:58 | recovers to Constrained (RSS dips to 1.602 GB, under the 1.642 GB recovery threshold) |
| 16:00:00 | CI wave lands. Artifact writes 0–185 → 15,054 per 5 min. BatchReadBlobs 0 → 13,134 per 10 min. Outbox leaves 0 for the first time |
| 16:03:30 | outbox drains 19,502 → 6,318 — the sender is still keeping up at this point |
| 16:02:00 | Critical latches. background_work_paused{worker="outbox"} = 1. RSS 1.87–2.02 GB thereafter |
| 16:02 → 16:25 | outbox climbs monotonically to 103,576 |
Defect 1 — the build’s permit understates its real peak by ~5×
run_index_build takes a materialization permit sized:
// kura/src/reapi/mod.rs:871
let budget = SNAPSHOT_BUILD_BUDGET_BYTES
.min(state.memory.reapi_materialization_pool_bytes() / 2)
.max(1);
For this pod (soft 1,502,609,408, hard 1,824,522,240):
- pool =
clamp((hard − soft) / 2, 1, 128 MiB)=min(160,956,416, 134,217,728)= 128 MiB - budget =
min(192 MiB, 64 MiB)= 64 MiB
Measured cost of a pass:
| before 15:55 | during reconcile | |
|---|---|---|
jemalloc_allocated |
flat 356–358 MB | 476–675 MB sawtooth, peaks at pass boundaries |
jemalloc_resident |
468–492 MB | 675 → 973 MB |
| process RSS | 1.48–1.51 GB | 1.69 → 2.02 GB |
The RSS rise (+480 MB) is matched almost exactly by the jemalloc_resident rise (+480 MB), so this is heap, not page cache or mmap. rocksdb_block_cache_usage stays flat at 48–77 MB throughout and manifest_cache_bytes is 0 — neither is involved.
So a pass costs +120 to +320 MB of live heap against a 64 MiB reservation. The .min(pool / 2) adaptation shrinks the token without shrinking the work: admission control admits work it cannot cover. At 64 MiB out of a 128 MiB pool, two namespaces are admitted concurrently (which is exactly what happened — tuist and mastodon both built at 15:55:11).
The constant’s own comment says it is sized at “~1KB per entry of scan-buffer + current-map peak, with headroom” (reapi/mod.rs:2313) — that reasoning is undone by the adaptation, and by the fact that the peak also carries the node table, which the entry cap does not bound (nodes reached 477,218 for 78,842 entries).
Secondary effect: jemalloc_resident (950 MB) runs ~350 MB above allocated (~600 MB), so pages dirtied by a pass stay resident after it ends and RSS ratchets rather than returning to the pre-pass level.
Also note the build waits up to SNAPSHOT_BUILD_PERMIT_WAIT (600 s) for a permit rather than declining (reapi/mod.rs:855). That is deliberate and well-argued in the comment, but the consequence is that memory pressure cannot shed this work — the only background worker pressure can shed is the outbox.
Defect 2 — a pass outlives its freshness window, so it never stops
SNAPSHOT_RECONCILE_INTERVAL= 60 s (reapi/mod.rs:2328)SNAPSHOT_REFRESH_TICK= 15 s (reapi/mod.rs:2335)- observed
elapsed_msfor thetuistnamespace: 62 s → 217 s
The pass is stale the moment it finishes, so the next 15 s tick re-triggers it. The reconcile log shows passes back to back with no gaps from 15:55 onward: for this namespace it is a 100 % duty cycle, not a periodic job. That is what makes the transient permanent — there is no idle interval for RSS to fall back through the 1.642 GB recovery threshold, so Critical latches by hysteresis (observe(), memory/mod.rs:88: from Critical, de-escalation needs ≤ 90 % of the limit; post-16:00 RSS never drops below 1.685 GB).
It also self-worsens. Across 35 minutes:
| pass end | entries | nodes | changed | deleted | scan_ms | load_ms | gate_ms | elapsed_ms |
|---|---|---|---|---|---|---|---|---|
| 15:57:23 | 50,497 | 138,831 | 100,000 | 30,919 | 18,679 | 32,804 | 80,820 | 132,303 |
| 15:59:35 | 57,499 | 151,443 | 49,503 | 22,740 | 17,358 | 15,791 | 29,295 | 62,444 |
| 16:02:48 | 59,068 | 298,180 | 42,501 | 21,220 | 37,311 | 11,772 | 70,800 | 119,883 |
| 16:05:43 | 61,386 | 354,355 | 40,932 | 19,393 | 31,567 | 13,251 | 69,736 | 114,554 |
| 16:08:54 | 67,208 | 197,054 | 38,614 | 14,532 | 34,314 | 9,771 | 81,783 | 125,868 |
| 16:11:56 | 68,986 | 311,956 | 32,792 | 14,934 | 35,008 | 9,246 | 68,984 | 113,238 |
| 16:14:49 | 72,783 | 474,008 | 31,014 | 12,174 | 22,006 | 14,130 | 70,067 | 106,203 |
| 16:17:57 | 73,438 | 210,295 | 27,217 | 14,365 | 39,485 | 7,181 | 66,785 | 113,451 |
| 16:21:04 | 74,756 | 344,996 | 26,562 | 14,252 | 30,349 | 8,400 | 82,626 | 121,375 |
| 16:24:51 | 76,715 | 391,258 | 25,244 | 17,363 | 33,674 | 9,460 | 110,161 | 153,295 |
| 16:29:40 | 78,842 | 477,218 | 23,285 | 17,255 | 42,621 | 9,420 | 165,019 | 217,060 |
gate_ms — the presence gate, which does a store point read per node per entry (reapi/mod.rs:1073) — grows 29 s → 165 s and is the dominant and fastest-growing term. Note this is not an effect of the Critical transition: allow_manifest_cache_admission() requires Normal, and the pod had been Constrained for hours, so the manifest cache was already cold at 0 bytes before any of this. It tracks the node table growing.
Why it only started at 15:55
Included because it explains why this is latent rather than continuous, and why it will recur on every node as fleet traffic shifts.
The reconcile is demand-created: refresh_snapshot_indexes only walks indexes already in the snapshot cache (reapi/mod.rs:172 — “a node serving nothing does no work”), and an index enters that cache only via a Serve. The snapshot has no route of its own — it rides GetActionResult under the reserved action key tuist-actioncache-snapshot/v2 (reapi/mod.rs:2221), so it is invisible in route metrics.
This pod was Ready from ~13:10 and served GetActionResult from ~14:20, but a client fetches the full snapshot once per session (reapi/mod.rs:165). 15:55:11 is the first new session to land here — the leading edge of the CI wave whose full weight arrives at 16:00. From that instant the refresher has something to walk, and never stops.
(One thing the data cannot distinguish: whether 15:55 was the first new session or the first client speaking snapshot v2. The snapshot shares the GetActionResult counter.)
Directions worth considering
- Bound a pass’s actual peak to the permit it holds, or size the permit from the observed peak. Today the adaptation does neither.
- Serialize index builds per node instead of admitting one per namespace concurrently.
- Back off when a pass overruns its interval — schedule the next from the observed pass duration rather than a fixed window, so the duty cycle stays below 100 %.
- Reconsider whether the presence gate must sweep the whole index every pass. It is the dominant cost and grows with the node table, which nothing bounds.
- Emit metrics for reconcile duration, duty cycle, and overrun count. Today this is only visible by reading Loki, which is how it went unnoticed.
Related
- #11221 — GetActionResult returning hits whose output blobs were evicted. The presence gate in this reconcile is the machinery that fixes that; this issue is about what that machinery costs.
- #11955 — the same pod’s cold bootstrap, which is why it only became Ready at ~13:10.
Appendix — raw series (env=production, pod=kura-tuist-eu-central-1-1)
Grafana: kura-7c-pod, 15:50–16:15Z
Limits (constant): kura_memory_soft_limit_bytes = 1,502,609,408 · kura_memory_hard_limit_bytes = 1,824,522,240 · recovery thresholds (9/10) = 1,352,348,467 (soft) and 1,642,070,016 (hard).
kura_process_resident_memory_bytes, MB, 60 s — reconcile starts 15:55:11, writes start 16:00:
15:45 1506 | 15:46 1507 | 15:47 1507 | 15:48 1505 | 15:49 1505 | 15:50 1505 | 15:51 1505
15:52 1504 | 15:53 1504 | 15:54 1484 | 15:55 1485 | 15:56 1756 | 15:57 1795 | 15:58 1602
15:59 1688 | 16:00 1685 | 16:01 1716 | 16:02 1866 | 16:03 1874 | 16:04 1818 | 16:05 1893
16:06 1916 | 16:07 1847 | 16:08 1923 | 16:09 1937 | 16:10 1815 | 16:11 1920 | 16:12 1910
16:13 1826 | 16:14 1940 | 16:15 1946 | 16:16 1889 | 16:17 1979 | 16:18 1972 | 16:19 1832
16:20 1962 | 16:21 1954 | 16:22 1891 | 16:23 1968 | 16:24 1974 | 16:25 1982 | 16:26 1898
16:27 2009 | 16:28 2009 | 16:29 1989 | 16:30 1967 | 16:31 1990 | 16:32 2022 | 16:33 2005
16:34 2004 | 16:35 2001
(The 15:56:30 Critical transition does not appear as a >1825 sample here — the controller observes on a finer cadence than the 60 s scrape, so the peak falls between samples. The transition counter confirms it: see below.)
kura_jemalloc_allocated_bytes / kura_jemalloc_resident_bytes, MB, 150 s:
| time | allocated | resident |
|---|---|---|
| 15:30 | 356 | — |
| 15:35 | 357 | — |
| 15:40 | 356 | — |
| 15:45 | 357 | 492 |
| 15:50 | 357 | 490 |
| 15:55 | 358 | 468 |
| 15:57 | 675 | 784 |
| 16:00 | 476 | 675 |
| 16:02 | 605 | 865 |
| 16:05 | 621 | 879 |
| 16:07 | 616 | 886 |
| 16:10 | 482 | 778 |
| 16:12 | 546 | 814 |
| 16:15 | 596 | 905 |
| 16:17 | 675 | 924 |
| 16:20 | 625 | 931 |
| 16:22 | 575 | 875 |
| 16:25 | 578 | 950 |
| 16:27 | 666 | 973 |
| 16:30 | 600 | 921 |
| 16:32 | 674 | 962 |
| 16:35 | 671 | 953 |
kura_jemalloc_retained_bytes, MB, 300 s:
15:30 1344 | 15:35 1413 | 15:40 1426 | 15:45 1445 | 15:50 1447 | 15:55 1468 | 16:00 1756
16:05 1719 | 16:10 1920 | 16:15 1902 | 16:20 2047 | 16:25 2073 | 16:30 2149 | 16:35 2117
kura_memory_pressure_state, 30 s (0 normal / 1 constrained / 2 critical):
15:45–15:56:00 1
15:56:30–15:57:30 2
15:58:00–16:01:30 1
16:02:00–16:35 2 (sustained)
kura_memory_pressure_transitions_total (cumulative): constrained→critical 1 → 2 (~15:56) → 3 (~16:02); critical→constrained 1 → 2 (~15:58); normal→constrained 1 for the pod’s whole life — it never returned to Normal.
kura_background_work_paused, 30 s: worker="outbox" and worker="usage_outbox" = 0 until 15:56:30, 1 for 15:56:30–15:57:30, 0 again, then 1 from 16:02:00 onward, continuously. worker="segment_refresh" = 1 for the entire window (it requires Normal).
kura_outbox_messages, 30 s — 0 for the whole day before 16:00:
15:40 0 | 15:50 0 | 16:00:00 0 | 16:00:30 3172 | 16:01:00 7282 | 16:01:30 14262
16:02:00 16408 | 16:02:30 17924 | 16:03:00 19502 | 16:03:30 6318 | 16:04:00 7833
16:04:30 6520 | 16:05:00 5325 | 16:05:30 4597 | 16:06:00 5168 | 16:06:30 5761
16:07:00 6909 | 16:07:30 7856 | 16:08:00 9213 | 16:08:30 10202 | 16:09:00 12376
16:09:30 14749 | 16:10:00 16780 | 16:10:30 34529 | 16:11:00 40160 | 16:11:30 45585
16:12:00 51701 | 16:12:30 55442 | 16:13:00 59104 | 16:13:30 62594 | 16:14:00 64140
16:14:30 65141 | 16:15:00 66933 | 16:15:30 69200 | 16:16:00 70283 | 16:16:30 71328
16:17:00 72814 | 16:17:30 75530 | 16:18:00 74654 | 16:18:30 77355 | 16:19:00 79790
16:19:30 82182 | 16:20:00 83855 | 16:20:30 86727 | 16:21:00 89212 | 16:21:30 92482
16:22:00 95046 | 16:22:30 95667 | 16:23:00 97318 | 16:23:30 98791 | 16:24:00 100921
16:24:30 103490 | 16:25:00 103576
Mesh-wide kura_outbox_messages at 16:20Z: kura-tuist-eu-central-1-0 913,842 (draining ~630 per 5 min) · kura-tuist-scw-fr-par-0 76,690 · kura-tuist-eu-central-1-1 83,855. Every other tenant’s pods are at 0.
increase(kura_artifact_writes_total[5m]) — the enqueue side:
14:00–16:00 0 to 185 per 5 min (trickle)
16:00 15,054 | 16:05 11,571 | 16:10 23,269 | 16:15 13,161 | 16:20 14,123 | 16:25 4,903 | 16:30 1,038
increase(kura_replication_requests_total[5m]) — the drain side (sum over both targets, kura-tuist-eu-central-1-0 and kura-tuist-scw-fr-par-0, which track each other within 0.1 %):
14:00–16:00 0 to 371 per 5 min
16:00 11,861 | 16:05 8,829 | 16:10 9,702 | 16:15 7,292 | 16:20 6,400 | 16:25 6,077 | 16:30 5,798
increase(kura_public_request_latency_seconds_count[10m]) by route — the 16:00 CI wave:
| route | 14:20 | 15:00 | 16:00 | 16:10 | 16:20 | 16:30 |
|---|---|---|---|---|---|---|
ActionCache/GetActionResult |
861 | 914 | 45 | 3,447 | 3,584 | 5,666 |
ActionCache/UpdateActionResult |
99 | 95 | 29 | 2,046 | 2,428 | 2,525 |
CAS/BatchReadBlobs |
0 | 0 | 424 | 13,135 | 10,413 | 6,593 |
CAS/BatchUpdateBlobs |
0 | 0 | 0 | 1,674 | 2,395 | 1,720 |
CAS/FindMissingBlobs |
99 | 95 | 34 | 2,045 | 2,428 | 2,534 |
Other gauges at 16:20Z: rocksdb_block_cache_usage_bytes 77,123,338 (capacity 67,108,864; flat 48–77 MB all window) · manifest_cache_bytes 0 (capacity 67,108,864) · manifest_cache_evictions_total 1,810,967 · manifest_index_entries 0 · segment_evicted_artifacts_total 2,127,998 · replication_apply_results_total 8,324,429 · bootstrap_runs_total{result="ok"} 3 · bootstrap_duration_seconds_sum 53,909 s · membership_generation 3 · discovered_peer_nodes 2 · writer_lock_owned 1 · tmp_dir_bytes 912.
Loki queries used:
{env="production", namespace="kura", container="kura"} | pod="kura-tuist-eu-central-1-1" | json
| message=~"action-cache snapshot index reconciled|deleted action-cache entries whose blobs were evicted"
sum by (message) (count_over_time(
{env="production", namespace="kura", container="kura"}
| pod="kura-tuist-eu-central-1-1" | json | line_format "{{.message}}" [5m]))
Investigate, reproduce, or fix this item in an isolated repository. Each Flight preserves its outcome and agent session.
Start a Flight and preserve its objective, outcome, and session here.
No GitHub comments yet.