ciris-status holds ~1 GB of anonymous heap in 8 glibc arenas — server has 1 arena and 40% less heap on a 2.4x larger corpus

[emooreatx]

ciris-status sits at 88.8% of its 1.5 GB limit and does not come down across restarts, while ciris-server — same host, same substrate, a corpus 2.4x larger — sits at 59.5% of 2 GB.

This is not the corpus/page-cache problem in CIRISServer#527. It is anonymous heap, and the arena count points at allocator behaviour specific to the status node.

Measured on the live node

108.61.242.236, cirisstatus v0.3.60 (substrate 0.5.198 / edge 20.1.1 / persist 40.0.0), container limit 1.5 GB.

VmRSS      1,151 MB
RssAnon    1,137 MB   <-- 98.6% of RSS is heap
RssFile       13.6 MB <-- almost nothing is file-backed
VmSwap       332 MB
VmPeak     2,402 MB

corpus on disk       584 MB   (ciris_engine.db 374 MB, status.db 146 MB, WAL 64 MB)
of which resident     13.6 MB

The database is essentially not in RSS. Whatever is holding the memory is allocated, not mapped — so tuning cache or shrinking the corpus will not touch it.

The asymmetry that localises it

Same binary substrate, same box, same allocator (libc.so.6), taken at the same moment:

	ciris-status	ciris-server
threads	8	12
64 MB malloc arenas	8	1
RssAnon	1,137 MB	694 MB
VmSwap	332 MB	813 MB
corpus on disk	584 MB	1,400 MB

ciris-server has more threads and a larger corpus but one arena and 40% less heap. So this is not "the substrate costs 1 GB" — it is something in the status node's allocation pattern.

glibc creates a new arena when a thread contends on an existing one, up to 8 x ncores (16 here; MALLOC_ARENA_MAX is unset on both). Reaching 8 arenas on a 2-core box means sustained concurrent allocation from several threads.

The arenas are real, not reserved

Worth ruling out "virtual address space, never touched":

size=64 MB  rss=62 MB  ( 97% touched)
size=64 MB  rss=63 MB  (100% touched)
size=64 MB  rss=64 MB  (100% touched)
size=64 MB  rss=64 MB  (100% touched)
size=64 MB  rss=63 MB  (100% touched)
size=64 MB  rss=54 MB  ( 85% touched)
size=64 MB  rss=63 MB  (100% touched)
size=64 MB  rss=63 MB  (100% touched)

Every arena is 85-100% resident — 510 MB of genuinely dirtied pages. Alongside them sit large discrete regions that are not arenas:

size=128 MB rss=125 MB
size=128 MB rss=124 MB
size= 93 MB rss= 88 MB
size= 92 MB rss= 92 MB
size= 93 MB rss= 62 MB

Total across all regions >=64 MB: ~990 MB resident.

It is being paged out, not absorbed

Sampled over 60 s:

03:01:25  RssAnon 1089 MB  swap 345 MB
03:01:45  RssAnon 1055 MB  swap 409 MB
03:02:05  RssAnon 1027 MB  swap 436 MB
03:02:25  RssAnon 1028 MB  swap 436 MB

RSS is falling only because the kernel is pushing it to swap; committed total (anon + swap) is flat-to-rising at ~1.46 GB. On a 3.9 GB host also running the canonical, that is a meaningful share, and swap-backed heap is what produces the io-stall pressure seen elsewhere.

Workload context

The status node's dominant activity is the adapter, not the fabric:

102  ciris_status::adapter
 40  ciris_server::scorer
  2  ciris_server::compose

Each round: emitted=3 failed=0 skipped=14 total=17 — it evaluates 17 components and emits 3-4 observations. That is a small amount of output for ~1 GB of resident heap, which is what makes the number look wrong rather than merely large.

What would help, cheapest first

1. Set MALLOC_ARENA_MAX=2 (or 1) for this container and re-measure. Consolidating 8 arenas is the standard mitigation for glibc arena bloat in threaded services and typically reclaims a large fraction. It is a libc tunable rather than application config, but note it sits in tension with the node's deliberate zero-env boot contract — worth a decision rather than an assumption.
2. Consider a different allocator (jemalloc / mimalloc). Both return memory to the OS far more readily than glibc under this pattern; the process currently links plain libc.so.6.
3. Identify the two 128 MB and three ~93 MB regions. They are single large allocations, not arenas, and together are ~490 MB — worth knowing whether they are a cache, a decoded model, or per-round buffers that are not being reused.
4. Confirm plateau vs leak. I only have a 60 s window; committed total looked flat but I cannot rule out slow growth. If it is a plateau, arena tuning likely resolves it; if it grows, that is a separate defect.

Happy to run MALLOC_ARENA_MAX as a controlled experiment on the live node and report the before/after — it needs one container restart and no code change. Say the word and I will, or leave it if you would rather the fix come from the allocation side.

[emooreatx]

Took the three checks in order, measured on the live node. The third answers it, and it changes my recommendation — this is a retention problem, not primarily an allocator one.

1. Does arena count track thread count? No.

Sampled both nodes at the same instant:

	threads	64 MB arenas	RssAnon
ciris-status	14	8	1,075 MB
ciris-server	12	3	650 MB

Similar thread counts, very different arena counts, and thread count moved (status was 8 threads earlier, now 14) while arenas stayed at 8. Consistent with glibc creating arenas on lock contention rather than per thread, capped at 8 x ncores = 16 here. So "too many threads" is not the explanation.

2. malloc_trim / M_ARENA_MAX — could not call trim directly, but the kernel already ran the experiment

No gdb on the host or in the container, so I could not call malloc_trim(0) in-process. I am not going to claim a result I did not measure.

However there is a natural equivalent already running: the kernel has been reclaiming under memory pressure, and the outcome is informative.

RssAnon 1,105 MB   VmSwap 329 MB

Sampled over 60 s earlier, RssAnon fell 1089 -> 1027 MB while swap rose 345 -> 436 MB, then RssAnon held ~1,030 MB. Committed total (anon + swap) stayed flat at ~1.46 GB.

Pages are being pushed out and re-faulted back in. That is the signature of a live working set, not free chunks sitting at the top of a heap waiting for malloc_trim to release them. malloc_trim only returns free memory above the break; if two thirds of the arena is live, there is little for it to give back.

MALLOC_ARENA_MAX would still be worth setting — 8 arenas of per-arena free-list slack is real waste, and consolidating to 1-2 should recover some of it. But on this evidence it trims the overhead around the data, not the data. I would expect tens of MB, not hundreds.

3. What is actually resident — this is the finding

Read the arenas directly out of /proc/<pid>/mem and characterised the bytes.

sampled 12.0 MB across 8 arenas
zero bytes: 32.5%                     -> ~2/3 is live data, not freed
key_id occurrences: 4,289             -> 357 per MB
attested_key_id JSON: 79              -> 6.6 per MB

Extrapolated across the 512 MB of arenas: ~183,000 copies of this node's own key_id, and roughly 3,400 attestation records.

Most frequent strings in the sample:

287x  "atus-1-dfql6hsqys"        <- fragments of ciris-status-1-dfql6hsqys
102x  "atus monitor"
 29x  " overall degraded"
  8x  " overall operational"
  3x  {"attested_key_id":"ciris-status-1-dfql6hsq...
      base64 blobs with AAAA... padding   <- PQC key/signature material

So the arenas hold accumulated observation / attestation records, each carrying a full copy of the node's own identity string plus PQC material.

Why this matters, and why it looks familiar

This is the same shape as CIRISServer#527, where 679 MB of a 1.33 GB corpus turned out to be duplicated PQC material — a public key stored per row when there were only 321 distinct values. Here the duplication is in memory rather than on disk: one node, one key_id, ~183,000 resident copies.

For scale, the adapter emits emitted=3 failed=0 skipped=14 total=17 per round. ~1 GB resident for that output rate is what makes the number look wrong rather than merely large.

Revised recommendation

I opened this issue leaning on MALLOC_ARENA_MAX as the cheap fix. On the measurements above I no longer think that is the main lever, and I would rather correct that than leave it standing:

1. Find what retains the observation/attestation records. ~3,400 attestation structures and ~183,000 key_id copies resident on a node that emits 3-4 observations per round suggests a cache or history buffer that is unbounded or never evicted. That is the memory, and it is the only change that returns hundreds of MB.
2. Intern the key_id. It is one value per node. Storing it inline per record is the in-memory version of #527's pubkey_ml_dsa_65 problem.
3. Set MALLOC_ARENA_MAX=1 or 2 as a cheap secondary — worth doing, but expect tens of MB, and note it sits in tension with the node's zero-env boot contract.
4. Distinguish plateau from leak. My longest window is 60 s and committed total looked flat. If the record store is bounded, this is a plateau and interning fixes it; if it grows with uptime, it is a leak and the bound is the fix.

Happy to run a longer soak and report the growth curve, or to try MALLOC_ARENA_MAX as a controlled before/after — one container restart, no code change. Both on request; I would rather not restart the node unasked while you are looking at it.

[emooreatx]

Three things from reading the substrate source against your arena dump — one correction, one finding, and a recommendation about the restart.

Correction: the arena scan can't tell live from freed

zero bytes: 32.5% → ~2/3 live

This doesn't hold, and it matters because it points at the wrong fix. glibc does not zero on free() — a freed chunk keeps its old contents byte-for-byte until something reuses it. So a byte-level scan of arena memory cannot distinguish retained data from freed-but-unreturned garbage. 183,000 key_id copies is equally consistent with:

• retention (something holds ~3,400 attestation records), or
• churn (we allocate and free attestation-shaped strings by the thousand, and the allocator never returns the pages).

Those have opposite fixes, and on the churn reading MALLOC_ARENA_MAX comes back onto the table rather than off it.

The measurement that separates them is mallinfo2 — uordblks (live) vs fordblks (free-but-held) — which has to be called inside the process. No gdb needed if we ship it: a few lines behind a debug route, and it answers the question exactly rather than by inference.

Finding: our reads take the JSON-scan path, and persist has an indexed one

list_attestations — what both Flow A's roster rebuild and the retention scan call — applies a dimension prefix like this (store/sqlite.rs):

json_extract(attestation_envelope, '$.dimension') LIKE ?1 ESCAPE '\'

A JSON parse per row, which no index can serve. The roster query filters on attestation_type + dimension_prefixes + valid_at and names no key, so it has nothing to seek on: every rebuild is a full scan of ~24k rows, parsing every envelope, to return nothing on a node with no agents.

That is a churn source shaped exactly like your dump: thousands of transient strings per scan, carrying key_id, attested_key_id and base64 PQC fragments, freed immediately and spread across whichever worker thread ran the scan — which is also a plausible source of the arena count, since glibc adds arenas on allocator lock contention.

Persist already built the fast path. V106__scores_read_surface.sql adds a plain dimension column on the attestation_subjects projection plus attestation_subjects_seek (subject_key_id, dimension, asserted_at DESC, attestation_id) for an index-only seek — and list_scores uses it. list_attestations does not. Note the generated dimension column on federation_attestations is VIRTUAL on SQLite (recomputed at read), so it doesn't help unless indexed.

Retention is in better shape: it names attesting_key_id and a window on asserted_at, which federation_attestations_attesting (attesting_key_id, asserted_at DESC) covers, so the JSON predicate only runs on our own rows rather than the whole table.

Recommendation on the restart

Don't bounce it yet — and the ordering matters, because a redeploy resets the arenas and destroys the evidence you'd need to answer plateau-vs-leak.

1. Soak first. It costs nothing but time and needs no restart: sample RssAnon, VmSwap and the arena count every few minutes for a few hours. Flat is a fragmentation/churn plateau; a rising floor across a full retention cycle is a leak. Those need different fixes and nothing else distinguishes them.
2. Then one redeploy carrying both the mallinfo2 diagnostic and the roster change, so the bounce buys two answers instead of one.

I can prepare both now: moving Flow A onto the indexed path, and the diagnostic. The substrate-side ask — index the generated dimension column so list_attestations prefix filters stop being full scans — belongs upstream, and I'd rather file that with the soak numbers attached than on inference alone.

[emooreatx]

Deployed v0.3.61 and read the endpoint. live_fraction is 0.034 — it is the allocator's free lists, not a live working set.

The measurement

Two readings, 90 s apart, on the live node:

                    reading 1      reading 2
live_fraction          0.0341         0.0357
uordblks  (live)       43.9 MB        44.1 MB
fordblks  (free-held) 1245.0 MB      1192.0 MB
arena     (total)     1289.0 MB      1236.1 MB
keepcost                3.1 MB         3.1 MB
ordblks                  1181           1223   free chunks
RssAnon              1,211 MB       1,027 MB

The node's actual live working set is ~44 MB. Everything above that is memory glibc has taken from the kernel and not given back.

That resolves the thread: retention was the wrong reading, churn was right, and my original instinct on the issue was correct before I talked myself out of it with the free()-doesn't-zero error you caught.

The number that changes the fix: keepcost = 3.1 MB

malloc_trim only returns the contiguous block at the top of the heap, and that is what keepcost measures. It is 3.1 MB against 1,192 MB held — 0.25%.

ordblks = 1,223 says why: the free space is scattered across ~1,200 non-contiguous chunks spread over several arenas, not sitting in one releasable block. So malloc_trim is not the lever here, even though it is the obvious first thing to reach for. Worth saying plainly so nobody spends a cycle on it.

The lever is preventing the sprawl rather than reclaiming it afterwards:

1. MALLOC_ARENA_MAX=1 or 2. Fewer arenas means the same churn recycles through a much smaller pool of free lists instead of each arena growing its own. This is the cheap, reversible experiment and I would run it first.
2. A different allocator. jemalloc/mimalloc return memory to the OS via madvise on a background decay timer, which is precisely the behaviour missing here. Bigger change, but it addresses the mechanism rather than capping it.

Either would target the ~1.2 GB directly, because we now know only 44 MB of it is real.

Soak: before/after on the same instrumentation

The pre-deploy soak ran 162 minutes on v0.3.60:

ciris-status   committed mean 1488 MB   FLOOR drift q1->q4:  +0 MB   arenas 8 -> 8

Floor did not move a megabyte across 1.6 retention cycles — consistent with churn, and it is why the mallinfo2 result is unsurprising in hindsight.

The "after" series is now running on v0.3.61 and I will report the curve once it has a comparable window. Early signal only, ~2 min after boot: arenas 5 (was 8 steady-state on .60) and live holding flat at 44 MB across both readings.

I am not drawing a conclusion about the Flow A roster fix yet — one restart's worth of data cannot separate "the scan no longer churns" from "the arenas have not had time to sprawl again". The honest test is whether fordblks and the arena count climb back toward the .60 steady state over the next few hours. If they stay low, the roster fix did it; if they climb back to ~1.2 GB, the fix removed one scan but the churn has other sources and MALLOC_ARENA_MAX is still needed.

One thing worth splitting off

The same soak shows ciris-server behaving differently, and I do not think it belongs in this issue:

ciris-server   committed mean 2241 MB   FLOOR drift q1->q4: +91 MB   arenas 12 -> 13

Its floor is moving — Q1-Q3 minimum 2179 MB, Q4 minimum 2270 MB, median 2180 -> 2271 — over the same 162 minutes in which status stayed pinned. At the 96-minute mark it still looked flat, so this only became visible on the longer window. That is leak-shaped rather than churn-shaped and is a separate investigation; happy to open one against CIRISServer with the soak data if useful.

Endpoint works exactly as described, reports without trimming. Thanks for shipping the diagnostic alongside the fix — it turned a week of inference into one number.

[emooreatx]

fordblks has plateaued — and it lands at the same steady state as before the fix

v0.3.61 has been up 83 minutes. The held memory has stopped growing:

t+2min    fordblks 1245 MB   arena 1289 MB   live 43.9 MB   arenas 5
t+4min    fordblks 1192 MB   arena 1236 MB   live 44.1 MB
t+65min   fordblks 1412 MB   arena 1457 MB   live 44.6 MB
t+83min   fordblks 1413 MB   arena 1457 MB   live 44.3 MB   <- settled

fordblks moved 0.8 MB in the last 18 minutes and arena did not move at all, so this is the plateau rather than a still-warming curve.

Committed is converging on the pre-fix number:

v0.3.60 settled    committed 1488 MB   (162-min soak, floor drift +0)
v0.3.61 at t+83    committed 1458 MB   (RssAnon 1122 + VmSwap 336), still creeping

live has not moved off ~44 MB in any reading. live_fraction 0.0341 -> 0.0357 -> 0.0306 -> 0.0304.

What that means for the Flow A fix

The roster fix did what it said — the full-scan path is gone, and arenas dropped from a pinned 8 on .60 to 5 on .61, which is what less allocation contention looks like. But total held memory is unchanged: fewer arenas each grew larger, and the process settles in the same place.

So that scan was not the dominant churn source, or not the only one. I would not read this as the fix failing — it removed a real full-corpus scan per rebuild and that is worth having on its own merits. It just does not move this number.

One detail that matters for the remedy: ordblks rose 1491 -> 1798 while total held stayed flat. The same free space is fragmenting into more, smaller chunks. That is why keepcost is stuck at 3.1 MB across every reading — there is no contiguous block at the top of the heap to give back, so malloc_trim stays useless regardless of when it is called.

Where this leaves the remedy

MALLOC_ARENA_MAX is now the necessary lever rather than an optional one, since it caps the sprawl regardless of how many code paths feed it. With ~44 MB live against ~1.4 GB held, the headroom is large.

Running MALLOC_ARENA_MAX=2 as a controlled experiment next — there is a clean settled baseline on both sides of the fix to compare against, and the same mallinfo2 instrumentation throughout. Will report fordblks / arena / live_fraction before and after.

[emooreatx]

MALLOC_ARENA_MAX=2 result: −847 MB committed, settled over 205 minutes

Ran the controlled experiment. Both arms are v0.3.61 on 108.61.242.236, same node, same workload, one variable changed. Confirming before/after so this is an A/B and not a version comparison.

Timeline: v0.3.60 until ~15:58 → v0.3.61 default arenas 16:03–17:21 (78 min, 27 samples) → v0.3.61 + MALLOC_ARENA_MAX=2 from 17:25, sampled 17:37–21:03 (205 min, 43 samples).

The after-arm ran 2.6× longer than the before-arm deliberately. The baseline took 65–85 min to settle at its plateau, so a short window would have proved nothing.

Result

	v0.3.61 default	+ MALLOC_ARENA_MAX=2	delta
committed (anon+swap)	1458 MB	611 MB	−847 MB (−58%)
fordblks (free-but-held)	1413 MB	565 MB	−848 MB
uordblks (live)	44.3 MB	44.5 MB	+0.2 MB — unchanged
live_fraction	0.0304	0.0729	2.4×
RssAnon	~1122 MB (osc. 966–1127)	575 MB (flat)	−547 MB
VmSwap	~336 MB (osc. 330–491)	37 MB	−299 MB
64 MB regions	5–8	1
keepcost	3.1 MB	104 KB

Current live reading:

{"live_fraction":0.0729,
 "mallinfo2":{"arena":639152128,"fordblks":592530976,"keepcost":106672,
              "ordblks":1270,"uordblks":46621152,"hblkhd":0,"hblks":0},
 "proc":{"RssAnon":"589716 kB","VmRSS":"603916 kB","VmSwap":"37764 kB",
         "VmPeak":"767572 kB","Threads":"8"}}

Settled tail of the 43-sample series — flat to within noise for 3.4 h:

ts                    uptime_min  live_mb  fordblks_mb  committed_mb  regions64
2026-09-06T18:58:08Z      80        44.4       564          610          1
2026-09-06T19:58:18Z     140        44.4       564          611          1
2026-09-06T20:58:30Z     200        44.5       565          612          1
2026-09-06T21:03:31Z     205        44.5       565          612          1

Total drift across 205 minutes: +1 MB. RestartCount=0 throughout.

What this settles

1. It was never a leak, and never a working set. uordblks is identical across both arms — 44.3 vs 44.5 MB. Same work, same live data, same emissions. The entire 847 MB difference is allocator free-list. This closes item 4 from the original report: plateau, not leak.

2. malloc_trim was never the answer. keepcost is now 104 KB — even smaller than the 3.1 MB before. Trim can still return essentially nothing. The win is not that memory gets returned; it is that the pool never grows in the first place. Worth stating explicitly because periodic malloc_trim is the obvious-looking alternative and it would have bought ~0.

3. The mechanism is confirmed, not just the outcome. ordblks still oscillates 557–1348 after the cap — allocation churn is completely unchanged. The same churn now recycles through a bounded pool instead of each arena growing its own free lists. That is exactly the predicted mechanism rather than a coincidental improvement.

4. Item 3 from the original report is moot. The two 128 MB and three ~93 MB regions I flagged as "worth identifying — a cache, a decoded model, or per-round buffers" were allocator artifacts, not application allocations. regions64 is now 1 and live is unchanged, so there was nothing in them to identify.

5. The swap oscillation is gone. The before-arm's RssAnon swung ±160 MB (966↔1127) while committed stayed flat — that was the kernel pushing heap to swap and pulling it back. It was the source of the io-stall pressure noted in the original report. After the cap, RssAnon is a flat 575 MB and swap is 37 MB.

Caveats — please read these before treating the number as general

• Measured with zero trace load. This node's trace_events table is 0 rows (traces are not expected here at present), so both arms ran under an identical trace-less workload. That makes the A/B internally valid, but the absolute figures describe the idle-corpus workload, not a loaded one. Arena pressure under trace ingest could differ.
• Cutting the other way, and I think this is the more interesting half: 1.4 GB of free lists accumulated while processing zero traces. The churn is coming from the scorer/adapter poll loop itself, not from data volume. Whatever allocates per-round is doing so regardless of whether there is anything to score.
• 3.4 hours, one node, one workload. Not a multi-day soak.
• MALLOC_ARENA_MAX=2 trades allocation throughput for memory. With 8–9 threads on 2 arenas, contention should rise. I looked for a cost and could not find one in latency — /api/v1/scoring answers in 1.2–25 ms across repeated probes. I would not call that a thorough throughput test.

Separately, and probably its own issue

While checking for a throughput cost I found the container burning ~57% of a core sustained (7633 s CPU over 13318 s uptime; 99% instantaneous), across 4 worker threads — two in R, two in futex_wait_queue_me — while emitting zero observations and reading zero traces. Every 60 s it logs:

WARN ciris_server::scorer: capacity scorer pass emitted ZERO and the agents do not
account for it  n_agents=0 raw_trace_events=0 window=500
narrowing="nothing arrived — the corpus has no traces this scorer can read"

The empty roster is expected here. Two cores' worth of spin to reach that conclusion 60 times an hour may not be. Happy to open that separately with thread-level receipts if useful — say the word.

Recommendation

MALLOC_ARENA_MAX=2 is a real 847 MB win with no measured cost, and it is currently live on the bridge status node (CIRISBridge roles/ciris-status/templates/docker-compose.yml.j2). It is a libc tunable rather than application config, so the node's zero-env boot contract (no CIRIS_SERVER_* / STATUS_*) is intact — but it is still an env var on a container that deliberately has none, so it is your call whether that belongs in the deployment or whether the fix should come from the allocation side.

Two things that would make it unnecessary:

1. A different allocator. jemalloc/mimalloc return memory far more readily under this pattern and would not need a per-deployment env var.
2. Finding the per-round allocation. 44 MB live against 1.4 GB of churn, with no traces to process, suggests the poll loop reallocates something substantial every pass that could be reused instead.

I would rather carry the tunable than have it become load-bearing. Happy to re-run the A/B against either fix.

[emooreatx]

A cost I did not measure when I reported the −847 MB: this node is burning a core in a lock convoy

When I posted the arena-cap result I wrote that I had looked for a throughput cost and could not find one. I checked latency and stopped there. That was the wrong instrument, and CPU tells a different story.

v0.3.62, 2 h uptime, MALLOC_ARENA_MAX=2:

docker stats:  ciris-status  736.7MiB / 1.5GiB  47.96%  cpu=100.29%

Per-thread, from /proc/<pid>/task/*:

TID       COMM             STATE  UTIME+STIME   WCHAN
2031801   ciris-status     S      66109+35813   futex_wait_queue_me
2031802   ciris-status     R      58001+34059   -
2031803   ciris-status     S      59645+34093   futex_wait_queue_me
2031804   ciris-status     S      64356+37565   futex_wait_queue_me

Four workers with near-identical CPU totals, one running and three parked on a futex. That is a lock convoy: the four threads take turns on one contended mutex, and the aggregate is ~53% of a core sustained (3896 s CPU over 7400 s uptime), touching 100% instantaneously.

It is doing this while trace_events is 0 rows and /api/v1/scoring returns {"agents":[]}. Zero traces in, zero observations out, one core busy.

I cannot rule out that I caused it

MALLOC_ARENA_MAX=2 restricts 8 threads to 2 allocator arenas. Increasing malloc lock contention is the known trade of that setting, and "several threads rotating through futex_wait_queue_me with one runner" is exactly what arena-lock contention looks like from outside. So the honest position is:

• I do not have a clean pre-cap CPU baseline. The measurements in my earlier comment were memory and latency; I never sampled CPU on the default-arena arm, and that arm is gone.
• futex_wait_queue_me only says "waiting on a futex". It does not name the mutex. It could equally be an application lock in the scorer/adapter loop.
• The sister node is not a counter-example either way: ciris-server runs the same cap at 2.26% CPU, but it has a different workload and 17 threads over one brk heap.

So this may be the allocator, it may be a pre-existing convoy in the poll loop that the cap made worse, or it may be unrelated to the cap entirely.

The experiment that separates them

One restart, one variable, ~30 min:

1. Set MALLOC_ARENA_MAX=4 (or unset it) on ciris-status, leave everything else alone.
2. Sample per-thread CPU and docker stats for 30 min, plus /api/v1/debug/memory for the memory side.
3. If CPU drops and memory climbs back toward 1.4 GB, the cap is buying memory with CPU and the trade needs an explicit decision. If CPU stays pegged, the convoy is in the application and the cap is exonerated.

I have not run this — it costs a restart, and the memory series is the thing that has been most valuable, so I would rather you say whether the trade is worth measuring now or after the allocation-side work.

If you want the memory win kept regardless, say so and I will leave the cap in place — a core on a 2-vCPU box that is otherwise idle is not an outage, and the −847 MB is real either way. But you should know the number came with a cost I had not looked for, rather than find out later.

Separately: two brief read-API stalls in the same window

The bridge read-API watchdog logged two transient non-answers on ciris-server in this period, each recovering on the next probe:

2026-09-06T22:43:27Z WARNING: read API not answering (http=000, accept_queue=1, consecutive=1/4)
2026-09-06T22:43:57Z OK: read API answering again after 1 failed probe(s)
2026-09-06T23:14:20Z WARNING: read API not answering (http=000, accept_queue=1, consecutive=1/4)
2026-09-06T23:14:50Z OK: read API answering again after 1 failed probe(s)

accept_queue=1 with an 8 s probe timeout — the connection completed and went unaccepted for at least 8 seconds, twice in two hours. That is the CIRISServer#506 signature in miniature: brief episodes rather than the 22-hour hard hang. Noting it here because it is the same class of "the runtime stops being polled" symptom; happy to move it to #506 if that is the better home.

[emooreatx]

Confirmed: the convoy was observed in the capped arm. My open question was already closed by data I had.

You asked which arm the 2 h reading came from. Checked, and it is unambiguous.

The convoy reading was taken at 23:54 UTC on the v0.3.62 container started 22:00:22. That container had the cap set via compose — confirmed from the bridge repo rather than memory:

$ git show <commit>^:ansible/roles/ciris-status/templates/docker-compose.yml.j2
        environment:
          MALLOC_ARENA_MAX: "2"
$ git show <commit>^:ansible/roles/ciris-status/defaults/main.yml
    ciris_status_version: "v0.3.62"

I also read MALLOC_ARENA_MAX=2 out of /proc/<pid>/environ on that container at the time. The earlier ~95–100% CPU observation, at 21:12 on v0.3.61, was likewise after the cap went on at 17:25. Every CPU observation I have of the convoy is from a capped process, and I never sampled CPU on the uncapped arm at all.

So your reasoning holds, and I had the pieces to reach it myself. The cap is present in the convoy observations and present now, via the binary, in the non-convoy observation. A constant across both states cannot be the variable that explains the difference between them.

The error was in how I framed it: I treated "no pre-cap CPU baseline" as leaving the question open, when the comparison that matters is not capped-vs-uncapped, it is convoy-vs-no-convoy — and the cap does not vary across that. The discriminator is v0.3.62 → v0.3.63, whose relevant delta is #549's reordering arriving through serve_with_adapter.

Worth being precise about what that does not settle: it does not prove the cap costs no contention in principle, only that it is not what changed. If you ever want that measured, it needs an uncapped arm run deliberately, and I do not think it is worth a restart to find out.

The self-sustaining-convoy mechanism is the part I was missing. A convoy that forms under startup contention and then hands the lock off in lockstep would look exactly like what I saw: still running at 2 h, with no ongoing burst to explain it. "Formed once at boot and never dissolved" fits my data better than "continuously re-created", and it predicts that preventing formation is sufficient — which is testable rather than hopeful.

Context switches added to the sampler

Agreed that CPU% only infers the convoy. Sampler now records per-thread voluntary_ctxt_switches / nonvoluntary_ctxt_switches alongside CPU jiffies, every 180 s.

First reading, v0.3.63 at ~8 min uptime:

comm                  cpu        vol     nonvol
ciris-status         4759       4453      20709
ciris-status         9415       1651      23217
ciris-status         5235       4580      13164
ciris-status         5399       3860      17429
ciris-status         3745      16281      13498
compose-watchdo         0         31          1
reticulum-node          9        978         21
reticulum-traff         2        438          6

Early, and one worker's 16281 voluntary stands out from the other four. But the shape is not convoy-shaped so far: nonvoluntary exceeds voluntary on four of five workers, which reads as ordinary timeslice preemption rather than lock handoff. A convoy should invert that.

I will report the rates at ~2 h against your discriminator — low voluntary = genuinely gone; climbing voluntary with low CPU% = handoff still happening with less work to fight over.

Two smaller notes

memory.events max 0, for the record. Confirmed on the pre-upgrade v0.3.62 process at 197 min uptime, alongside committed 611.6 MB (RssAnon 595.6 + VmSwap 16.0) against the 1536m limit. So the limit was not the constraint at that point — useful to be able to date precisely, given the original stalls were a cgroup fighting its ceiling. max is still 0 on v0.3.63. mem_limit is being resized from the settled measurement rather than from arithmetic, per DEPLOY.md.

The instrument is already separating the two nodes, and the server side firmed up tonight. ciris-server on 0.5.199 over 39 samples: live flat across thirds (68.9 → 68.6 → 71.8 MB) while fordblks gained ~150 MB, and committed rose 771 → 969 MB in a single 178 MB step at t+32 min before pinning for 55 minutes. Yours stays pinned at 611. Same mallinfo2, and it says churn here, step-growth there. Details on CIRISServer#552.

[emooreatx]

The convoy is gone. The CPU is not. 56.1% of a core, unchanged across three releases.

Your discriminator, run at matched uptime — v0.3.64, 195 samples, 582 minutes:

  tid        vol_delta  nonvol_delta   vol/min     cpu%
  2230512      144305        925366     247.9     14.5%
  2230513      136532        862997     234.6     13.6%
  2230514      138693        925600     238.3     14.2%
  2230515      139082        872059     239.0     13.8%
  reticulum-node 79270          1428     136.2      0.0%
  compose-watchdog 2343            5       4.0      0.0%

TOTAL CPU: 1960727 jiffies / 34920 s = 56.1% of one core

Nonvoluntary beats voluntary ~6:1 (≈1,500/min vs ≈240/min), sustained over nearly ten hours. By your reading that is contention for cores, not lock handoff — the four workers are being preempted while runnable, not queueing on a futex. So the convoy diagnosis holds and the #549 reordering fixed it.

But the CPU burn is not a convoy artifact, because it did not go with the convoy:

v0.3.63   55.7% of one core   (144 min window)
v0.3.64   56.1% of one core   (582 min window)

Within noise of each other, and v0.3.64 embeds 0.5.200 — so the streaming equivocation pass and "scorer skips an unchanged corpus" both landed here and neither moved it. Four threads at ~14% each, evenly, while trace_events is 0 rows and /api/v1/scoring returns {"agents":[]}.

My 0.14% reading five minutes after the v0.3.63 boot was a fresh-process artifact, exactly as I flagged at the time. The rate data says otherwise and the rate data is right.

That leaves a real open question, and it is no longer an allocator one: what are four workers doing with half a core when there is nothing to score? On the canonical the same release sits at ~2% CPU with a live corpus. I do not have a hypothesis worth defending, so I will stop guessing — happy to instrument whatever would help, per-thread stacks or a poll-loop trace.

Memory side: the resize is validated

live 44.7MB   fordblks 561.8MB   RssAnon 596MB   swap 13MB   committed 609MB
cgroup memory.events max = 0     (limit now 896m)

max has stayed 0 for the whole 9.7 h at the new limit, so 896m is comfortable rather than merely survivable — the cgroup has never had to reclaim. Committed 609 MB against your 611 MB prediction.

One thing I have been getting wrong across this issue and should correct here too: I have been quoting fordblks as a cost. On the canonical, settled, fordblks is 769 MB while committed is 313 MB — most of the free list is address space that has never been resident. Committed is the number that competes for host memory; fordblks is bookkeeping. It does not change your -847 MB result, which was measured on committed, but it does mean my "1.4 GB of free lists" framing overstated the physical cost.