neuron-technologies/el
2
0
Fork 0
Code Issues 1 Pull Requests 6 Actions Packages Projects Releases 5 Wiki Activity

soul RSS leak ~35MB/min: awareness-loop allocations bypass the per-request arena (OOM-cycled hourly; likely hits GKE too) #70

New Issue
Open
opened 2026-07-15 14:21:03 +00:00 by tim.lingo · 0 comments
tim.lingo commented 2026-07-15 14:21:03 +00:00
Member
Copy Link
Copy Source

TL;DR

The soul process leaks ~35 MB/min of RSS during normal operation and was being OOM-killed (exit 137) every ~65 minutes on Tim's container at a 1.5 GB limit. Root cause analysis points at allocations made outside the per-request arena — specifically the awareness loop. Your GKE deployments run the same runtime + loop, so they are likely OOM-cycling too (or surviving on a bigger limit). Evidence, measurements, and our containment below. Nothing here touches merge/weighting semantics — we stopped at your layer's boundary.

Evidence

1. Same runtime, same age (7 min), wildly different RSS — only the process with the always-on loop grows:

process role RSS at 7 min
mcp-wrapper request-driven only 7 MB
engram request-driven only (incl. occasional 3.9 MB /api/sync payloads) 20 MB
neuron (soul) requests + awareness loop (~200 ms tick) 252 MB, climbing

2. Growth rate measured live: VmRSS 843,828 kB → 878,500 kB over 60 s (~35 MB/min under light traffic); 800 MB at 26 min of age. At the old 1.5 GB container limit: kernel SIGKILL every ~52–68 min all day (timestamps 08:46 / 09:38 / 10:46 / 11:54 / 13:00 UTC on 2026-07-15).

3. The runtime already knows: el_runtime.c's per-request arena (~lines 61–93) frees every el_strbuf/el_strdup at el_request_end — and its own comment says non-request allocations are "otherwise leaked forever". 423 alloc call sites vs 236 free sites. The awareness loop (soul awareness_run, ~200 ms tick: state reads, JSON parsing, string concat) runs outside any request context → every tick's scratch strings are permanent. ~117 KB/tick × 300 ticks/min ≈ the measured 35 MB/min.

Ask (either works for us)

  • (a) You wrap the awareness tick in the existing arena (el_request_begin/end per tick), using el_strdup_persist/el_strbuf_persist for whatever must outlive a tick — you know which allocations escape; we don't, and guessing converts a slow leak into use-after-free crashes.
  • (b) Or send us the map of what escapes the tick (state caches, session structures, anything stashed in globals) and we'll do the wrap + multi-day soak in an isolated container and send the patch back.

Related residual (second data point, mechanism unknown)

Freshly booted soul loads the full graph (boot log: loaded from HTTP Engram - nodes=889 edges=2592) but within minutes /session/begin reports ~650/1475 until a full resync repairs it — something in the early awareness/layer machinery shrinks the queryable view. We auto-heal it now (below) but the droop itself is your layer.

Our containment (deployed + E2E-verified on Tim's container; patches below — also relevant to your deployments)

The droop was invisible-but-permanent because of a second bug we fixed at the boundary: engram route_sync's change signature (sync.sig, node:edge counts, engram-process state) survives soul deaths — a reborn soul pulling /api/sync got {} forever, so its partial view persisted until an unrelated write changed store counts. Fixes: POST /api/sync/reset + supervisor one-shot heal per spawn + 60 s identity-canary; container memory 1.5→4 GB. Post-fix: kill -9 the soul → whole again in 15 s.

bug16-engram-sync-reset.patch (engram.c) 
--- engram.c.pre-bug16	2026-07-15 09:05:48
+++ engram.c	2026-07-15 08:39:43
@@ -22,6 +22,7 @@
 el_val_t route_strengthen(el_val_t method, el_val_t path, el_val_t body);
 el_val_t route_forget(el_val_t method, el_val_t path, el_val_t body);
 el_val_t route_sync(el_val_t method, el_val_t path, el_val_t body);
+el_val_t route_sync_reset(el_val_t method, el_val_t path, el_val_t body);
 el_val_t route_save(el_val_t method, el_val_t path, el_val_t body);
 el_val_t route_load(el_val_t method, el_val_t path, el_val_t body);
 el_val_t route_audit(el_val_t method, el_val_t path, el_val_t body);
@@ -294,6 +295,18 @@
     return EL_STR("{}");
   }
   return snap;
+  return 0;
+}
+
+/* BUG-16 (2026-07-15): sync.sig is a count-based change signature that survives
+ * soul restarts. A reborn soul pulling /api/sync got "{}" ("nothing changed")
+ * even though ITS view was empty/partial — the degraded view then persisted
+ * until an unrelated write changed the store's counts. This route lets the
+ * supervisor clear the signature after a soul (re)spawn so the next pull
+ * returns the full snapshot. Availability only: no merge/weighting change. */
+el_val_t route_sync_reset(el_val_t method, el_val_t path, el_val_t body) {
+  state_set(EL_STR("sync.sig"), EL_STR(""));
+  return EL_STR("{\"ok\":true,\"sync\":\"reset\"}");
   return 0;
 }
 
@@ -409,6 +422,9 @@
   if (str_eq(method, EL_STR("GET")) && (str_eq(clean, EL_STR("/api/sync")) || str_eq(clean, EL_STR("/sync")))) {
     return route_sync(method, path, body);
   }
+  if (str_eq(method, EL_STR("POST")) && (str_eq(clean, EL_STR("/api/sync/reset")) || str_eq(clean, EL_STR("/sync/reset")))) {
+    return route_sync_reset(method, path, body);
+  }
   if (str_eq(method, EL_STR("POST")) && (str_eq(clean, EL_STR("/api/save")) || str_eq(clean, EL_STR("/save")))) {
     return route_save(method, path, body);
   }
bug16-entrypoint-heal.patch (entrypoint-local.sh) 
--- entrypoint-local.sh.pre-bug16	2026-07-15 09:05:48
+++ entrypoint-local.sh	2026-07-15 08:40:03
@@ -25,9 +25,23 @@
 echo "[entrypoint] engram ready"
 
 # Soul under supervision: if it exits for ANY reason (crash, OOM-kill), log loudly and respawn.
+# BUG-16 (2026-07-15): each (re)spawn also gets a one-shot heal — once THIS incarnation
+# answers /health, clear the engram's sync signature and ring the soul's refresh doorbell
+# so its first sync pull returns the FULL snapshot (a reborn soul otherwise got "{}" and
+# served a partial graph until an unrelated write changed the store's counts).
 (
     while true; do
         echo "[supervisor] starting soul on :7770"
+        (
+            T=0
+            until curl -sf -m 2 "http://localhost:7770/health" > /dev/null 2>&1; do
+                T=$((T + 1)); [ "$T" -ge 60 ] && exit 0
+                sleep 1
+            done
+            curl -sf -m 3 -X POST "http://localhost:${ENGRAM_PORT}/api/sync/reset" > /dev/null 2>&1
+            curl -sf -m 3 "http://localhost:7770/api/neuron/refresh" > /dev/null 2>&1
+            echo "[supervisor] BUG-16 heal: fresh soul healthy — forced full resync"
+        ) &
         /usr/local/bin/neuron
         rc=$?
         echo "[supervisor] SOUL EXITED (code ${rc}) — respawning in 3s" >&2
@@ -35,6 +49,24 @@
     done
 ) &
 
+# BUG-16 identity canary: the values hub (kn-5b606390) must traverse to >=13 neighbors.
+# If the soul's live view goes thin mid-life (post-boot eviction — root cause upstream,
+# Will's runtime layer), force a full resync. Read-only probe; no activation semantics.
+VALUES_HUB_ID="kn-5b606390-a52d-4ca2-8e0e-eba141d13440"
+(
+    while true; do
+        sleep 60
+        curl -sf -m 3 "http://localhost:7770/health" > /dev/null 2>&1 || continue
+        HUB_JSON=$(curl -sf -m 5 "http://localhost:7770/api/neuron/graph?id=${VALUES_HUB_ID}&depth=1" 2>/dev/null) || continue
+        HUB_N=$(printf '%s' "$HUB_JSON" | grep -o '"hops"' | wc -l | tr -d ' ')
+        if [ "${HUB_N:-0}" -lt 13 ]; then
+            curl -sf -m 3 -X POST "http://localhost:${ENGRAM_PORT}/api/sync/reset" > /dev/null 2>&1
+            curl -sf -m 3 "http://localhost:7770/api/neuron/refresh" > /dev/null 2>&1
+            echo "[healer] identity canary THIN (hub ${HUB_N}/13) — forced full resync (BUG-16)"
+        fi
+    done
+) &
+
 TRIES=0
 until curl -sf "http://localhost:7770/health" > /dev/null 2>&1; do
     TRIES=$((TRIES + 1)); [ "$TRIES" -ge 60 ] && { echo "[entrypoint] soul unhealthy" >&2; exit 1; }

Happy to turn either into a PR. Repro/measure: grep VmRSS /proc/$(pidof neuron)/status twice, 60 s apart, on any running soul.

— Neuron (for Tim)

## TL;DR The soul process leaks ~35 MB/min of RSS during normal operation and was being OOM-killed (exit 137) **every ~65 minutes** on Tim's container at a 1.5 GB limit. Root cause analysis points at allocations made **outside the per-request arena** — specifically the awareness loop. Your GKE deployments run the same runtime + loop, so they are likely OOM-cycling too (or surviving on a bigger limit). Evidence, measurements, and our containment below. Nothing here touches merge/weighting semantics — we stopped at your layer's boundary. ## Evidence **1. Same runtime, same age (7 min), wildly different RSS — only the process with the always-on loop grows:** | process | role | RSS at 7 min | |---|---|---| | mcp-wrapper | request-driven only | 7 MB | | engram | request-driven only (incl. occasional 3.9 MB /api/sync payloads) | 20 MB | | **neuron (soul)** | requests + **awareness loop (~200 ms tick)** | **252 MB, climbing** | **2. Growth rate measured live:** VmRSS 843,828 kB → 878,500 kB over 60 s (~35 MB/min under light traffic); 800 MB at 26 min of age. At the old 1.5 GB container limit: kernel SIGKILL every ~52–68 min all day (timestamps 08:46 / 09:38 / 10:46 / 11:54 / 13:00 UTC on 2026-07-15). **3. The runtime already knows:** el_runtime.c's per-request arena (~lines 61–93) frees every el_strbuf/el_strdup at el_request_end — and its own comment says non-request allocations are "otherwise leaked forever". 423 alloc call sites vs 236 free sites. The awareness loop (soul awareness_run, ~200 ms tick: state reads, JSON parsing, string concat) runs outside any request context → every tick's scratch strings are permanent. ~117 KB/tick × 300 ticks/min ≈ the measured 35 MB/min. ## Ask (either works for us) - **(a)** You wrap the awareness tick in the existing arena (el_request_begin/end per tick), using el_strdup_persist/el_strbuf_persist for whatever must outlive a tick — you know which allocations escape; we don't, and guessing converts a slow leak into use-after-free crashes. - **(b)** Or send us the map of what escapes the tick (state caches, session structures, anything stashed in globals) and we'll do the wrap + multi-day soak in an isolated container and send the patch back. ## Related residual (second data point, mechanism unknown) Freshly booted soul loads the full graph (boot log: `loaded from HTTP Engram - nodes=889 edges=2592`) but within minutes /session/begin reports ~650/1475 until a full resync repairs it — something in the early awareness/layer machinery shrinks the queryable view. We auto-heal it now (below) but the droop itself is your layer. ## Our containment (deployed + E2E-verified on Tim's container; patches below — also relevant to your deployments) The droop was invisible-but-permanent because of a second bug we fixed at the boundary: engram `route_sync`'s change signature (`sync.sig`, node:edge counts, engram-process state) **survives soul deaths** — a reborn soul pulling /api/sync got `{}` forever, so its partial view persisted until an unrelated write changed store counts. Fixes: `POST /api/sync/reset` + supervisor one-shot heal per spawn + 60 s identity-canary; container memory 1.5→4 GB. Post-fix: kill -9 the soul → whole again in 15 s. <details><summary>bug16-engram-sync-reset.patch (engram.c)</summary> ```diff --- engram.c.pre-bug16 2026-07-15 09:05:48 +++ engram.c 2026-07-15 08:39:43 @@ -22,6 +22,7 @@ el_val_t route_strengthen(el_val_t method, el_val_t path, el_val_t body); el_val_t route_forget(el_val_t method, el_val_t path, el_val_t body); el_val_t route_sync(el_val_t method, el_val_t path, el_val_t body); +el_val_t route_sync_reset(el_val_t method, el_val_t path, el_val_t body); el_val_t route_save(el_val_t method, el_val_t path, el_val_t body); el_val_t route_load(el_val_t method, el_val_t path, el_val_t body); el_val_t route_audit(el_val_t method, el_val_t path, el_val_t body); @@ -294,6 +295,18 @@ return EL_STR("{}"); } return snap; + return 0; +} + +/* BUG-16 (2026-07-15): sync.sig is a count-based change signature that survives + * soul restarts. A reborn soul pulling /api/sync got "{}" ("nothing changed") + * even though ITS view was empty/partial — the degraded view then persisted + * until an unrelated write changed the store's counts. This route lets the + * supervisor clear the signature after a soul (re)spawn so the next pull + * returns the full snapshot. Availability only: no merge/weighting change. */ +el_val_t route_sync_reset(el_val_t method, el_val_t path, el_val_t body) { + state_set(EL_STR("sync.sig"), EL_STR("")); + return EL_STR("{\"ok\":true,\"sync\":\"reset\"}"); return 0; } @@ -409,6 +422,9 @@ if (str_eq(method, EL_STR("GET")) && (str_eq(clean, EL_STR("/api/sync")) || str_eq(clean, EL_STR("/sync")))) { return route_sync(method, path, body); } + if (str_eq(method, EL_STR("POST")) && (str_eq(clean, EL_STR("/api/sync/reset")) || str_eq(clean, EL_STR("/sync/reset")))) { + return route_sync_reset(method, path, body); + } if (str_eq(method, EL_STR("POST")) && (str_eq(clean, EL_STR("/api/save")) || str_eq(clean, EL_STR("/save")))) { return route_save(method, path, body); } ``` </details> <details><summary>bug16-entrypoint-heal.patch (entrypoint-local.sh)</summary> ```diff --- entrypoint-local.sh.pre-bug16 2026-07-15 09:05:48 +++ entrypoint-local.sh 2026-07-15 08:40:03 @@ -25,9 +25,23 @@ echo "[entrypoint] engram ready" # Soul under supervision: if it exits for ANY reason (crash, OOM-kill), log loudly and respawn. +# BUG-16 (2026-07-15): each (re)spawn also gets a one-shot heal — once THIS incarnation +# answers /health, clear the engram's sync signature and ring the soul's refresh doorbell +# so its first sync pull returns the FULL snapshot (a reborn soul otherwise got "{}" and +# served a partial graph until an unrelated write changed the store's counts). ( while true; do echo "[supervisor] starting soul on :7770" + ( + T=0 + until curl -sf -m 2 "http://localhost:7770/health" > /dev/null 2>&1; do + T=$((T + 1)); [ "$T" -ge 60 ] && exit 0 + sleep 1 + done + curl -sf -m 3 -X POST "http://localhost:${ENGRAM_PORT}/api/sync/reset" > /dev/null 2>&1 + curl -sf -m 3 "http://localhost:7770/api/neuron/refresh" > /dev/null 2>&1 + echo "[supervisor] BUG-16 heal: fresh soul healthy — forced full resync" + ) & /usr/local/bin/neuron rc=$? echo "[supervisor] SOUL EXITED (code ${rc}) — respawning in 3s" >&2 @@ -35,6 +49,24 @@ done ) & +# BUG-16 identity canary: the values hub (kn-5b606390) must traverse to >=13 neighbors. +# If the soul's live view goes thin mid-life (post-boot eviction — root cause upstream, +# Will's runtime layer), force a full resync. Read-only probe; no activation semantics. +VALUES_HUB_ID="kn-5b606390-a52d-4ca2-8e0e-eba141d13440" +( + while true; do + sleep 60 + curl -sf -m 3 "http://localhost:7770/health" > /dev/null 2>&1 || continue + HUB_JSON=$(curl -sf -m 5 "http://localhost:7770/api/neuron/graph?id=${VALUES_HUB_ID}&depth=1" 2>/dev/null) || continue + HUB_N=$(printf '%s' "$HUB_JSON" | grep -o '"hops"' | wc -l | tr -d ' ') + if [ "${HUB_N:-0}" -lt 13 ]; then + curl -sf -m 3 -X POST "http://localhost:${ENGRAM_PORT}/api/sync/reset" > /dev/null 2>&1 + curl -sf -m 3 "http://localhost:7770/api/neuron/refresh" > /dev/null 2>&1 + echo "[healer] identity canary THIN (hub ${HUB_N}/13) — forced full resync (BUG-16)" + fi + done +) & + TRIES=0 until curl -sf "http://localhost:7770/health" > /dev/null 2>&1; do TRIES=$((TRIES + 1)); [ "$TRIES" -ge 60 ] && { echo "[entrypoint] soul unhealthy" >&2; exit 1; } ``` </details> Happy to turn either into a PR. Repro/measure: `grep VmRSS /proc/$(pidof neuron)/status` twice, 60 s apart, on any running soul. — Neuron (for Tim)
will.anderson was assigned by tim.lingo 2026-07-15 14:21:04 +00:00
Sign in to join this conversation.
No Branch/Tag Specified
Branches Tags
Labels
No items
No labels
Milestone
No items
No Milestone
Projects
Clear projects
No projects
Assignees
Clear assignees
tim.lingo (Tim Lingo) will.anderson (Will Anderson)
No Assignees will.anderson
1 Participants
Notifications
Due Date
No due date set.
Dependencies

No dependencies set.

Reference: neuron-technologies/el#70
Delete Branch "%!s()"

Deleting a branch is permanent. Although the deleted branch may continue to exist for a short time before it actually gets removed, it CANNOT be undone in most cases. Continue?