ciris-server allocator: 15 arenas at the glibc cap plus a 706 MB brk heap 91% paged out — arena cap in-process, brk composition via mallinfo2, then a measured trim trial

[emooreatx]

Continues #550 (closed by #551, which shipped the instrument) with the bridge-side composition posted on #551 and the CIRISStatus#69 A/B. Filed so the analysis lives on an issue rather than a merged PR.

What is known

Sister node (ciris-status v0.3.61, same substrate, same host): MALLOC_ARENA_MAX=2 cut committed 1458 → 611 MB (−58%), held flat 205 min, uordblks unchanged 44.3 → 44.5 MB. The entire 847 MB was allocator free-list, accumulated while processing zero traces — the churn is the loops, not data volume. keepcost 104 KB afterwards.

This node (ciris-server 0.5.198 on the canonical, 18.8 h, 2 vCPU, 2 GB limit), from smaps: committed anonymous ≈ 2.47 GB, 1.5 GB of it in host swap.

arena-class (64 MB mmap) : n=15   committed=  836 MB    ← the glibc cap: 8 × nproc(2)
large non-arena          : n=7    committed= 1371 MB    ← of which [heap] (brk) 706 MB, 91% paged out
everything else          : n=242  committed=  259 MB

So it is the same disease with a different shape: the arena cap plausibly addresses ~836 MB of 2466, and the 706 MB brk heap — reserved, touched, then cold for hours under memory pressure — is the part a cap cannot consolidate.

What 0.5.199's instrument settles first

GET /v1/node/diagnostics/memory (--diagnostics / CIRIS_DIAGNOSTICS=1, loopback-only) reports mallinfo2 from inside the process. The cold 641 MB of [heap] is one of two things and live_fraction says which:

• fordblks — freed, not returned: churn/fragmentation, allocation-side fix (fewer, reused buffers in the loops) and/or a release policy;
• uordblks — live but cold: something retains ~0.6 GB it stopped reading hours ago, a retention defect, and the more interesting one.

Recommended rollout to make that reading clean: at the 0.5.199 restart of the canonical's ciris-server container, set both CIRIS_DIAGNOSTICS=1 and MALLOC_ARENA_MAX=2. With one spare arena at most, mallinfo2.arena is essentially the brk heap plus 64 MB, so fordblks vs uordblks reads directly as the brk heap's composition — which the 15-arena default would blur. The cap's own effect is already known from status; what we do not know is the brk heap, and this measures it in one restart instead of two.

Candidate cures, in the order the reading will pick them

1. Arena cap in-process, not by deploy config. mallopt(M_ARENA_MAX, 2) at the top of run / py_main on target_env = "gnu", honouring an explicit MALLOC_ARENA_MAX if the environment set one. Every glibc node gets the −58% class of win without an operator knowing the knob exists; Android (scudo), iOS, macOS and Windows are untouched because the call does not exist there. Ready to write; waiting for the canonical reading only so the change lands with a number.
2. A trim trial, not a trim policy. If fordblks dominates: malloc_trim(0) since glibc 2.8 does NOT only cut the top chunk — it walks every arena and MADV_DONTNEEDs whole free pages inside free chunks, so keepcost (top only) understates what it would release from a fragmented brk heap. The honest test is a loopback-only POST /v1/node/diagnostics/memory/trim under the same switch, called by hand once, with mallinfo2 + RssAnon/VmSwap read before and after. Status's diag.rs deliberately does not trim; a trial door under the operator switch keeps that separation.
3. The churn source. The loops that allocate on a cadence with no traffic: per-peer replication coordinators paging rows every anti-entropy round, config reconcile (30 s), mesh-config fold, the scorer (60 s, window 500), retention (3600 s), equivocation (900 s, up to 4096 rows), health probes. Status's finding that free lists grew with zero traces says the same is likely here; finding which loop needs an allocation profile on the canonical (or the same node under the mesh harness), after 1 and 2 have taken the easy 1.3 GB off the table.

Not for 0.5.199; the instrument is in it and the first reading decides the order.

[emooreatx]

PyPI has ciris-server 0.5.199, 9/9 files as of 21:40 UTC (the publish gate's first attempt lost to the CIRISConformance#97 port race; the rerun passed). The canonical deploy described on #551 — Dockerfile pin → 0.5.199, CIRIS_DIAGNOSTICS=1 + MALLOC_ARENA_MAX=2 on the ciris-server container, restart, first sample immediately — is unblocked from the server side; timing is Eric's.

[emooreatx]

Runbook for the bridge team — rolling ciris-server 0.5.199 on the canonical

Everything below is /opt/ciris/server on 108.61.242.236 unless said otherwise. One restart of ciris-server; ciris-status is a separate tag bump. Do not start until Eric has said when — the restart ends the #550 soak.

0. Before the restart (evidence that dies with it)

• Take the last external samples of the running 0.5.198 process the way the ciris-server committed-memory floor rises +91 MB over 165 min while ciris-status stays pinned — leak-shaped, distinct from the allocator churn in CIRISStatus#69 #550 CSV was taken (RssAnon / VmSwap / arena-count from smaps), plus docker inspect -f '{{.State.StartedAt}} restarts={{.RestartCount}}' ciris-server and the last 200 lines of docker logs ciris-server. That is the "before" column.

1. Pin the wheel

Dockerfile: pip install --no-cache-dir ciris-server==0.5.198 → ==0.5.199. (PyPI has 9/9 files as of 21:40 UTC.)

2. Two environment variables on ciris-server in docker-compose.yml

    image: ciris-server:0.5.199          # was 0.5.198 — keep the tag honest
    environment:
      CIRIS_ENVIRONMENT: "production"
      # Operator diagnostics (CIRISServer#549/#550): loopback-only
      # GET /v1/node/diagnostics/memory + boot marks. Off unless set. 1|true|yes.
      CIRIS_DIAGNOSTICS: "1"
      # glibc arena cap — the same setting ciris-status runs with (CIRISStatus#69,
      # −58% committed, live unchanged). Not node config; an allocator knob.
      MALLOC_ARENA_MAX: "2"

The comment in that file saying CIRIS_ENVIRONMENT is "the only one" should be updated: the zero-env policy is about node CONFIG (that is still config:* CEG); these two are operator/runtime switches, which 0.5.199 made a runtime gate on purpose (see src/diag.rs for why not a cargo feature). Leave mem_limit: 2048m alone for now — measure first, lower later.

3. Rebuild and recreate

cd /opt/ciris/server
docker compose build ciris-server
docker compose up -d ciris-server        # recreates the container; the volume is untouched

4. Verify the boot (first two minutes)

docker logs ciris-server 2>&1 | grep -E 'diagnostics ON|compose phase|compose mark|read API up|compose complete'

Expect, in this order: diagnostics ON — loopback-only memory report mounted… near the top; the phases with read_api_bind → read_api_serving BEFORE edge_run / replication_loop / config_reconcile_loop (that is #549; on 0.5.198 the three loops came first); three compose mark lines inside the bind phase — provision_built, router_built, listener_bound — each with wall_ms, thread_cpu_ms, process_cpu_ms; then compose complete … total_ms=. On 0.5.198 this box took 56 s to the first /health answer with 23 s in read_api_bind; post whatever 0.5.199 does, the three marks are the point.

From the host, the published port works for health (it is not loopback-gated):

curl -s http://127.0.0.1:4243/health | python3 -m json.tool | grep -E '"version"|"standing"|"instance_id"'

Expect "version": "0.5.199", "standing": "identified".

5. Read the memory report — from INSIDE the container's network namespace

The route is loopback-only, and a request through the published port arrives from the docker bridge gateway, not loopback, so it is refused (403). The image has no curl/wget, but it has python3:

docker exec ciris-server python3 -c 'import urllib.request,json; print(json.dumps(json.load(urllib.request.urlopen("http://127.0.0.1:4243/v1/node/diagnostics/memory", timeout=5)), indent=1))'

or from the host with nsenter -t $(docker inspect -f '{{.State.Pid}}' ciris-server) -n curl -s http://127.0.0.1:4243/v1/node/diagnostics/memory.

What is in it: mallinfo2.{uordblks,fordblks,arena,hblkhd,hblks,keepcost,ordblks}, live_fraction, proc.{VmRSS,RssAnon,RssFile,VmSwap,VmPeak,VmSize,Threads} (kB strings, same as /proc), node.{instance_id,started_at,…}, compose.{history,detail}.

6. Sample it like the CSV

Every 3 minutes, for at least the 165 minutes the #550 series ran (the floor step only showed after ~120):

while :; do printf '%s ' "$(date -u +%FT%TZ)"; docker exec ciris-server python3 -c 'import urllib.request,json; r=json.load(urllib.request.urlopen("http://127.0.0.1:4243/v1/node/diagnostics/memory",timeout=5)); m=r["mallinfo2"]; p=r["proc"]; print(json.dumps({"live_fraction":r.get("live_fraction"),"uordblks":m["uordblks"],"fordblks":m["fordblks"],"arena":m["arena"],"hblkhd":m["hblkhd"],"keepcost":m["keepcost"],"RssAnon":p.get("RssAnon"),"VmSwap":p.get("VmSwap"),"Threads":p.get("Threads")}))'; sleep 180; done | tee -a /root/ciris-server-0.5.199-mem.jsonl

7. How to read it (the reason for the two env vars at one restart)

• live_fraction = uordblks / (uordblks + fordblks). Near 0 with fordblks climbing = the same allocator-churn story as status, just in the brk heap: allocation-side fix / release policy (ciris-server allocator: 15 arenas at the glibc cap plus a 706 MB brk heap 91% paged out — arena cap in-process, brk composition via mallinfo2, then a measured trim trial #552 candidates 1–2). uordblks climbing = genuinely retained memory: a retention defect, and the interesting one.
• With MALLOC_ARENA_MAX=2 there is at most one 64 MB thread heap, so mallinfo2.arena ≈ the brk [heap] plus ≤ 64 MB. That is what makes fordblks vs uordblks read as the brk heap's composition; under the 15-arena default it would be blurred across arenas.
• hblkhd is direct-mmapped large chunks (not touched by a trim); keepcost is only the top of the brk heap — it does NOT bound what malloc_trim(0) would release, because since glibc 2.8 trim also MADV_DONTNEEDs whole free pages inside free chunks of every arena. No trim door exists in 0.5.199; ciris-server allocator: 15 arenas at the glibc cap plus a 706 MB brk heap 91% paged out — arena cap in-process, brk composition via mallinfo2, then a measured trim trial #552 candidate 2 adds a measured one if fordblks dominates.
• First hour = the arenas filling under the cap (the status curve). The number that matters is the floor after that, in the same table shape as CIRISStatus#69: committed (RssAnon+VmSwap), live (uordblks), fordblks, arena, swap, threads.

8. ciris-status

Wherever it is composed (it is not in this file): image ghcr.io/cirisai/cirisstatus:v0.3.61 → :v0.3.62, docker compose pull + up -d. It already runs MALLOC_ARENA_MAX=2; nothing else changes. 0.3.62 embeds server 0.5.199 on the unchanged substrate.

9. Rollback

Dockerfile pin back to ==0.5.198, image: ciris-server:0.5.198, docker compose build ciris-server && docker compose up -d ciris-server. The two env vars are harmless to leave in place (0.5.198 ignores CIRIS_DIAGNOSTICS; the arena cap is glibc's).

Report back on #552

The boot lines from step 4, the first sample and the floor after ~2 h from step 6, and the smaps three-bucket table (arena-class / large non-arena / rest) beside them, so the before and after are the same instrument.

[emooreatx]

0.5.199 is live on the canonical, deployed through the bridge Ansible role rather than by hand, so /opt/ciris/server matches IaC. ciris-status is on v0.3.62. Identity is byte-identical — key_id = ciris-canonical-1-d7bdeu223k, no re-key.

Reporting steps 4 and 5 now; the step-6 floor needs ~2 h and follows.

Step 4 — the boot. #549 is the headline.

0.5.198   56 s to first answer, 23 s of it in read_api_bind
0.5.199   compose complete total_ms=13616, read API answering ~10 s after start

4.1× faster to serving, and the bind phase went 23 s → 895 ms.

Phase order is exactly the contract — bind and serve before the three loops:

16. peering                9323 ms
17. holonomic               388 ms
18. read_api_bind           895 ms
19. read_api_serving          0 ms
20. edge_run                  0 ms
21. replication_loop          0 ms
22. config_reconcile_loop     8 ms

The three marks:

phase="read_api_bind" mark="provision_built"  wall_ms=154  thread_cpu_ms=136  process_cpu_ms=148
phase="read_api_bind" mark="router_built"     wall_ms=740  thread_cpu_ms=672  process_cpu_ms=673
phase="read_api_bind" mark="listener_bound"   wall_ms=0    thread_cpu_ms=0    process_cpu_ms=0

router_built is the one that used to cost 23 s and now costs 740 ms. Worth noting what the marks say about why: wall_ms 740 vs thread_cpu_ms 672 means it is ~91% on-CPU — real compute, not waiting. On 0.5.198 the same work was competing with the three loops' first ticks on two workers, so the wall time was mostly not-being-scheduled. That is the #549 thesis, now measured rather than argued.

peering at 9323 ms is now 68% of boot — it is the whole remaining cost. Not a regression (it was there before, hidden behind the bind), but it is where the next second comes from if boot time matters. This was a warm restart with primed peers; a cold start is presumably worse.

diagnostics ON line present. Health: "version": "0.5.199", "standing": "identified", instance_id ed33882d-….

Step 5 — the route, and the gate works

docker exec  → 200
http://127.0.0.1:4243/... from the host (docker bridge gateway) → 403

Loopback-only behaves exactly as designed. Reading it with docker exec python3, per the runbook.

The arena cap did what you predicted to the composition

This is the part that makes fordblks readable:

                         0.5.198 (19.5 h, no cap)      0.5.199 (+cap, first minutes)
arena-class (64 MB)      n=15   committed 836 MB       n=0    committed 0 MB
large non-arena          n=7    committed 1307 MB      n=1    committed 715 MB
everything else          n=242  committed 264 MB       n=~240 committed 80–101 MB

15 thread arenas → 0. The brk [heap] is now the sole large region, and mallinfo2.arena (807 MB) ≈ that 715 MB region plus change — so fordblks vs uordblks now reads as the brk heap's composition, exactly as §7 said it would.

First two samples (3 min apart, minutes 8 and 11):

21:59:22  live_fraction 0.0688  uordblks  55.0 MB  fordblks 744.8 MB  arena 799.9 MB  RssAnon 777.7 MB  VmSwap  12.4 MB
22:02:23  live_fraction 0.0868  uordblks  70.1 MB  fordblks 737.4 MB  arena 807.5 MB  RssAnon 473.9 MB  VmSwap 323.2 MB

I am explicitly not calling the result yet. Two samples at 8 and 11 minutes prove nothing — §7 says the first hour is the arenas filling, and I have been wrong before by reading a plateau off a short window. What I will say is that fordblks is already ~740 MB at minute 8, and committed (RssAnon+VmSwap) is sitting near 790 MB rather than climbing, so the shape is there early.

One early observation for whoever reads the floor: between those two samples RssAnon fell 304 MB while VmSwap rose 311 MB — committed flat. The kernel is paging this heap out within minutes of boot, on a host with 1.5 GB available. That is the same swap-churn signature the status node had before its cap, and it is why RssAnon alone will mislead anyone reading docker stats.

Sampling

Every 180 s to /root/ciris-server-0.5.199-mem.jsonl, each line carrying the diagnostics report and the host-side smaps three-bucket table, so before and after are the same instrument. Runs under a PID file rather than pgrep -f (a -f match also matches the ssh invocation that starts it — learned that the hard way).

I will post the floor in the CIRISStatus#69 table shape once it has ~2 h, and re-run the smaps buckets beside it.

Unrelated, found while verifying — filed as CIRISStatus#73

ciris-status's GET /api/v1/debug/memory answers unauthenticated on the published port, including over public HTTPS. Same class of data your route gates to loopback. No keys/identity/PII, but unauthenticated it is a live feedback oracle for a memory-exhaustion attempt. Bridge has 404'd the Caddy path already; the direct :4253 path needs the image, since that port must stay open for delegation claims. Suggested there that it match 0.5.199's gate.

[emooreatx]

The floor, at 2 h — and §7's question has an answer: allocator churn, not retention

39 samples, 21:59 → 23:53 UTC, ciris-server:0.5.199, RestartCount=0, CIRIS_DIAGNOSTICS=1 + MALLOC_ARENA_MAX=2.

The decision tree in §7 turns on whether uordblks or fordblks is the one climbing. Split into thirds:

	live (uordblks)	fordblks
first third	68.9 MB	739.9 MB
middle third	68.6 MB	865.6 MB
last third	71.8 MB	890.4 MB

Live is flat. fordblks gained ~150 MB. That is the churn answer, not the retention one — nothing is being held onto, the free lists are growing. #552 candidates 1–2 (allocation-side / release policy), not a retention defect.

The shape is a step, not a ramp

mallinfo2.arena, printed only when it moves:

21:59:22   762.8 MB          brk=715 MB
22:02:23   770.1 MB  (+7.3)
22:14:25   777.4 MB  (+3.3)
22:29:27   955.2 MB  (+177.8)   brk=779 MB   <-- the step
22:32:27   910.2 MB  (-45.0)
22:59:32   962.2 MB  (+52.0)
[pinned at 962.2 through 23:53]

One 178 MB step at t+32 min, taking the brk heap 715 → 779 MB (+64 MB), some settling, then pinned at 962.2 MB for 55 minutes. Committed (RssAnon+VmSwap) tracks it: 771 → 969 MB, and 968–969 for the last half hour.

That matches the step-change shape you found on #550 rather than a leak. 55 minutes is not proof it will not step again — the first step took 32 minutes to arrive, and I have been wrong reading plateaus off short windows before. Treat 969 MB as "the floor after two hours", not "the floor".

Live allocation is spiky, which is probably the point

Across the run uordblks ranges 49.5 → 235.4 MB. Most samples sit near 69 MB, with periodic excursions to ~235 MB that free straight back. So this is not steady churn — it is a repeating ~180 MB allocate/free cycle, and fordblks looks like glibc retaining that cycle's high-water mark. If that is right, the lever is the size or reuse of whatever allocates in that spike, more than the release policy.

Composition, before vs now

                     0.5.198 (19.5 h, no cap)     0.5.199 (+cap, 2 h)
arena-class 64 MB    n=15  committed 836 MB       n=0   committed 0 MB
large non-arena      n=7   committed 1307 MB      n=1   committed 779 MB
committed total            ~2407 MB                     969 MB

Not a matched-uptime comparison — 2 h against 19.5 h — so I am not claiming −1438 MB. What is solid: the 15 thread arenas are gone, mallinfo2.arena now tracks the single brk heap, and that is what made the fordblks/uordblks split readable at all.

Host-level effect, which was the actual goal

PSI memory  some avg60   8.73  ->  0.03
PSI io      some avg60   7.18  ->  0.05
host swap used           2643 MB -> 1486 MB

The swap thrashing is gone. That was the io-stall source, and it is worth more operationally than the headline MB.

No CPU cost on this node

ciris-server sits at 2.26% CPU. Whatever throughput the arena cap costs in principle, it is not visible here — worth stating because "2 arenas, 17 threads" sounds like it should hurt. (The sister node is a different story; raising that on CIRISStatus#69, not here.)

Sampler is still running at 180 s; I will flag it if the arena steps again.

[emooreatx]

First mallinfo2 reading from inside the canonical's ciris-server, 0.5.199, CIRIS_DIAGNOSTICS=1 + MALLOC_ARENA_MAX=2, ~3.5 h after the 21:57:51 restart (GET 127.0.0.1:4243/v1/node/diagnostics/memory from inside the netns):

live_fraction  0.1202
uordblks        121,291,760  (121 MB live)
fordblks        887,680,016  (888 MB freed, still held)
arena         1,008,971,776  (1009 MB — with the cap this is the brk heap + ≤64 MB)
hblkhd              995,328  (1 MB direct-mmapped)
RssAnon  508,960 kB   VmSwap  484,072 kB   Threads 20

Committed anonymous (RssAnon + VmSwap) ≈ 993 MB ≈ arena: the brk heap IS the process now. And the question #550 asked is answered: the cold heap is fordblks, not uordblks — 88% of the arena is free lists, 12% is live. Same disease as status (live_fraction 0.034 there), the brk-heap variant. Not a retention defect.

Two consequences:

1. The arena cap did what the status A/B predicted for the mmap'd arenas — committed fell from ~2.47 GB (15 arenas, 0.5.198) to ~1.0 GB — and it cannot touch the remaining 888 MB, which sits in the one heap a cap does not consolidate. So candidate 1 (in-process mallopt) stays worth shipping for every glibc node, and candidate 2 moves to the front: a measured malloc_trim(0) trial. 888 MB of free chunks is exactly what interior-page trimming exists for; how much of it is in whole free pages (vs. interleaved with the 121 MB live) is the only unknown, and one call answers it. The loopback trim door under the same switch, read mallinfo2 + RssAnon/VmSwap before and after, is the next server change.
2. Candidate 3 is the real fix: something allocates and frees ~900 MB worth of churn through the brk heap while the node processes essentially nothing. The 15-minute passes from Read API stalls every 15 min, phase-locked to boot: the equivocation pass and trace_plane_watch's storage_summary fire in the same second — log per-pass cost, de-phase, take the scan off the 15-minute path (#506) #553 are the first suspects to profile (the equivocation pass pages 4096 attestation rows and canonicalizes every one; storage_summary aggregates six tables), because they are the only periodic work on this node that touches the corpus at volume.

Bridge team: keep the 3-minute series going; the floor of fordblks over the next hours says whether the free lists are still growing under the cap or have plateaued, which decides whether a one-shot trim or a periodic one is the right shape.

[emooreatx]

Churn source, first candidate confirmed by measurement (details on #553): the equivocation pass materialises 4,096 parsed serde_json::Value envelopes (54 MiB raw, 10.6 KiB average) every 15 minutes, ~200–300 MB of transient heap freed back into the brk arena — a per-pass high-water mark, which is what an 888 MB fordblks beside 121 MB live looks like. The storage summary is not it (0.6 s, negligible allocation). So the order on this issue becomes: (1) stream the pass page-by-page (#553) — removes most of the transient at the source; (2) mallopt(M_ARENA_MAX, 2) in-process; (3) the measured trim door, now expected to matter less once (1) lands, but still the right instrument for whatever high-water mark remains. The 2-hour fordblks series running now says whether the free lists plateau under the cap (one-shot trim) or creep (trim after each pass).

[emooreatx]

The mmap-threshold ratchet test comes back negative — hblkhd is flat across the step

Ran the discriminator on the existing series, no restart needed. The criterion was explicit: hblkhd should fall as arena rises if the ratchet fired, and if it is flat across the step the mechanism is something else.

It is flat. Perfectly flat.

     time   arena_MB   hblkhd_KB  keepcost_KB    ford_MB   live_MB
 22:11:24      774.1       972.0       3768.0      724.1      50.0
 22:14:25      777.4       972.0       3768.0      541.9     235.4
 22:26:27      777.4       972.0       3768.0      723.7      53.7
 22:29:27      955.2       972.0       3768.0      900.3      54.8  <== STEP +178 MB
 22:32:27      910.2       972.0       3768.0      853.9      56.3
 ...
 02:54:09      962.2       972.0       3768.0      845.6     116.7

Across 99 samples spanning 5 hours, hblkhd has exactly one distinct value: 995328 bytes. It does not move at the step, before it, or after it. So the +178 MB did not come from allocations migrating out of mmap into the brk heap — nothing migrated. All of the growth is brk extension, and the dynamic threshold never adjusted.

By your own stated criterion, the ratchet is not the mechanism here. Worth having eliminated cleanly — it was a specific, falsifiable hypothesis and the data already on disk could answer it, which is more than most candidates manage.

keepcost is equally frozen at 3768.0 KB throughout. That is odd in its own right: the top-of-heap releasable chunk never changes size while the heap grows 762 → 962 MB.

But your malloc_trim point stands, and it points the other way from ours

You flagged that keepcost should be read on this node before dismissing trim, because it does not bound what trim returns — since glibc 2.8 it also MADV_DONTNEEDs whole free pages inside free chunks throughout the arena.

That is exactly the situation here. keepcost is 3.86 MB, but fordblks sits at ~888 MB. If even a modest fraction of that is page-aligned free space inside the heap, a trim could return far more than keepcost suggests. This is the opposite of the status node, where keepcost of 104 KB against fragmented free lists made trim pointless.

So: trim is worth measuring here and was not worth measuring there. Same instrument, opposite conclusion, which is a good sign the instrument is doing work.

Correcting myself: the "repeating spike" was one event, not a cycle

In my earlier comment I wrote that live allocation runs in "periodic ~180 MB spikes" and speculated fordblks was retaining that cycle's high-water mark. That was over-read from two samples.

With 99 samples: live exceeds 150 MB in exactly 1 of them (max 235.4 MB at 22:14). It is a single excursion, not a repeating cycle. Live is otherwise flat — quartile averages 67.9 / 73.4 / 83.7 / 73.7 MB.

The single spike does sit 15 minutes before the step, which is suggestive, but one instance is a coincidence until it happens again. I should not have generalised it.

The plateau is now firm

arena pinned at 962.2 MB for the last 79 samples (237 minutes)

quartile   live_avg   ford_avg   commit_avg
   q1        67.9      796.1        871
   q2        73.4      888.8        969
   q3        83.7      878.5        969
   q4        73.7      888.5        970

One step in q1, then four hours flat. When I reported this at 55 minutes I said to treat 969 MB as "the floor after two hours, not the floor". At 237 minutes pinned I am comfortable calling it a plateau — with the caveat that the first step took 32 minutes to arrive, so a second could still be waiting on a trigger I have not seen.

Live flat + fordblks risen-then-flat + hblkhd untouched = a one-off brk extension that never came back, not accumulation.

Unrelated but ongoing: the 15-minute read-API beat holds

01:28:16  01:43:28  01:58:43  02:13:26  ...  02:43:19

Still exactly 15 minutes apart, still coinciding with leviculum retry-queue drop bursts. Detail on #506; the offer there to capture a forensics bundle on a transient stall (capture-only at consecutive=2, no restart) stands and would take about 15 minutes to catch one.

[emooreatx]

The "before" for the fresh soak — two hours of the 0.5.199 process on the canonical (CIRIS_DIAGNOSTICS=1, MALLOC_ARENA_MAX=2), sampled every 3 minutes from inside the netns, 39 samples 01:35 → 03:32 UTC:

uordblks     70.7 →  73.2 MB   (min  70.2  max 260.3)
fordblks    891.5 → 889.0 MB   (min 701.9  max 892.0)
arena       962.2 → 962.2 MB   (flat)
committed   969.5 → 970.3 MB   (RssAnon + VmSwap; min 969.5 max 970.7)
largest fordblks steps:  +189.7 MB @01:47:10   +174.5 MB @02:02:11   +44.1 MB @03:26:40

Three readings:

1. Under the arena cap the process is bounded. arena did not move a byte in two hours and committed drifted +0.8 MB. The +91 MB floor step ciris-server committed-memory floor rises +91 MB over 165 min while ciris-status stays pinned — leak-shaped, distinct from the allocator churn in CIRISStatus#69 #550 saw on 0.5.198 was the 15-arena default, not a leak; with one arena there is nothing left to creep.
2. The 15-minute sawtooth is the equivocation pass, sized. Live memory swings 70 → 260 MB and back — a ~190 MB transient — and fordblks steps up by the same amount three minutes later, at 01:47 and 02:02, fifteen minutes apart, right after the :43:12 / :58:12 ticks. That is the 4,096 parsed envelopes being allocated and freed, measured from inside. 0.5.200's streaming pass (Read API stalls every 15 min, phase-locked to boot: the equivocation pass and trace_plane_watch's storage_summary fire in the same second — log per-pass cost, de-phase, take the scan off the 15-minute path (#506) #553) removes exactly that transient; on the new soak uordblks should stay near 70 MB with no 15-minute spike and fordblks should stop stepping.
3. ~890 MB of free list is the standing high-water mark. It is what the old pass needed once and glibc kept. It will not shrink on its own under 0.5.200 (nothing frees it, nothing needs it); one measured call on the trim door (POST 127.0.0.1:4243/v1/node/diagnostics/memory/trim, loopback, after the new process has settled) is the number that says whether a trim after each big pass belongs in 0.5.201 or whether the fresh process simply never builds the free list in the first place — the second is what the streaming design predicts, and the fresh soak's first two hours will say.