self-review 2026-07-19: close silent sync-starvation hole + heartbeat deltas

- engram refresh URL now resolves env -> state -> localhost:8742, same
  hardening ise_post got after the boot-4 blackout. Previously a corrupted/
  empty soul_engram_url state key silently disabled sync forever while
  heartbeats kept flowing — WM starves of Knowledge nodes with no outward
  sign.
- heartbeat ISE: node_delta, edge_delta (growth vs stall vs flood is now
  one field, not cross-ISE forensics), sync_age_ms from a new
  soul.last_sync_ok_ts stamp (-1 = never; >> SOUL_REFRESH_MS = refresh
  path broken). Verified live: pulse 1 sync_age_ms=-1, sync fired +1.6s,
  age counts up between syncs.
This commit is contained in:
2026-07-19 08:47:00 -05:00
parent 1011d8e5be
commit 50cf67bd66
4 changed files with 272 additions and 131 deletions
+125 -34
View File
@@ -17,19 +17,23 @@ fn idle_reset() -> Void {
}
// ise_post write an InternalStateEvent to the authoritative Engram HTTP backend.
// Reads SOUL_ISE_URL from env (or falls back to soul_engram_url state key).
// Falls back to local engram_node_full if neither is set.
// Reads SOUL_ISE_URL from env, then the soul_engram_url state key, then a
// compile-time default of http://localhost:8742.
//
// ROUTING HARDENING (2026-07-15 self-review): the old "URL empty → write to
// in-process store" fallback silently swallowed the entire ISE stream when
// state_get("soul_engram_url") started returning "" mid-uptime (observed at
// boot 4, ~16h in, on the post-arena-leak-fix binary: 1234 heartbeats landed
// in the local snapshot while the authoritative store went dark for hours
// indistinguishable from a dead loop from the outside). The authoritative
// address is a well-known localhost constant; never let a corruptible state
// read decide where telemetry goes. The in-process write remains only as a
// last resort when the HTTP POST itself fails, and is tagged ise-fallback-local
// so misrouting is visible in the stream instead of silent.
fn ise_post(content: String) -> Void {
let ise_url: String = env("SOUL_ISE_URL")
let engram_url: String = if str_eq(ise_url, "") { state_get("soul_engram_url") } else { ise_url }
if str_eq(engram_url, "") {
let discard: String = engram_node_full(
content, "InternalStateEvent", "state-event",
el_from_float(0.3), el_from_float(0.3), el_from_float(0.8),
"Episodic", "[\"internal-state\",\"InternalStateEvent\"]"
)
return ""
}
let state_url: String = if str_eq(ise_url, "") { state_get("soul_engram_url") } else { ise_url }
let engram_url: String = if str_eq(state_url, "") { "http://localhost:8742" } else { state_url }
// Proper JSON string escaping: backslashes first, then quotes, then control chars.
// Previously only escaped " — this caused ise_post to produce malformed JSON when
// content contained \n (backslash-n) from wm_top label escaping: the HTTP Engram
@@ -40,7 +44,23 @@ fn ise_post(content: String) -> Void {
let safe3: String = str_replace(safe2, "\n", "\\n")
let safe4: String = str_replace(safe3, "\r", "\\r")
let body: String = "{\"content\":\"" + safe4 + "\"}"
let discard: String = http_post_json(engram_url + "/api/neuron/state-events", body)
let resp: String = http_post_json(engram_url + "/api/neuron/state-events", body)
if str_eq(resp, "") {
// HTTP Engram unreachable — keep the ISE locally rather than lose it,
// tagged so the misroute is observable when the snapshot is inspected.
// Count every failure: the tally surfaces in the heartbeat payload as
// ise_fail, so a silently-failing POST path is visible in the stream
// itself instead of only via snapshot forensics. (2026-07-16 self-review)
let fail_raw: String = state_get("soul.ise_fail_count")
let fail_n: Int = if str_eq(fail_raw, "") { 0 } else { str_to_int(fail_raw) }
state_set("soul.ise_fail_count", int_to_str(fail_n + 1))
let discard: String = engram_node_full(
content, "InternalStateEvent", "state-event",
el_from_float(0.3), el_from_float(0.3), el_from_float(0.8),
"Episodic", "[\"internal-state\",\"InternalStateEvent\",\"ise-fallback-local\"]"
)
return ""
}
return ""
}
@@ -123,7 +143,44 @@ fn emit_heartbeat() -> Void {
let up_ms: Int = elapsed_ms()
let up_human: String = elapsed_human()
let emb_ok: Int = embed_ok()
let payload: String = "{\"event\":\"heartbeat\",\"pulse\":" + pulse + ",\"boot\":" + boot + ",\"idle\":" + idle + ",\"node_count\":" + int_to_str(nc) + ",\"edge_count\":" + int_to_str(ec) + ",\"wm_active\":" + int_to_str(wmc) + ",\"wm_avg_weight\":" + wm_avg_str + ",\"wm_top\":" + wm_top + ",\"ts\":" + int_to_str(ts) + ",\"uptime_ms\":" + int_to_str(up_ms) + ",\"uptime\":\"" + up_human + "\",\"embed_ok\":" + int_to_str(emb_ok) + "}"
// ise_fail: cumulative count of ise_post HTTP failures this boot (each one
// fell back to a local in-process node). Nonzero and climbing = the HTTP
// Engram is unreachable and telemetry is silently diverging into the soul's
// local store. (2026-07-16 self-review)
let fail_raw: String = state_get("soul.ise_fail_count")
let fail_str: String = if str_eq(fail_raw, "") { "0" } else { fail_raw }
// tick: same counter as pulse — pulse now increments once per loop tick
// (see awareness_run), so it is a true liveness signal. Emitted under both
// names during the transition so dashboards keyed on either keep working.
// sync_added_total: cumulative nodes merged in by engram sync this boot.
// wm_delta: wm_active change since the previous heartbeat (state-tracked).
let sat_raw: String = state_get("soul.sync_added_total")
let sat_str: String = if str_eq(sat_raw, "") { "0" } else { sat_raw }
let prev_wm_raw: String = state_get("soul.prev_wm_active")
let prev_wm: Int = if str_eq(prev_wm_raw, "") { 0 } else { str_to_int(prev_wm_raw) }
let wm_delta: Int = wmc - prev_wm
state_set("soul.prev_wm_active", int_to_str(wmc))
// node_delta/edge_delta: growth since previous heartbeat (state-tracked, same
// mechanism as wm_delta). Absolute counts alone can't distinguish "healthy
// steady growth" from "stalled ingestion" or "runaway ISE flood" without
// diffing across the ISE stream by hand. (2026-07-19 self-review)
let prev_nc_raw: String = state_get("soul.prev_node_count")
let prev_nc: Int = if str_eq(prev_nc_raw, "") { nc } else { str_to_int(prev_nc_raw) }
let node_delta: Int = nc - prev_nc
state_set("soul.prev_node_count", int_to_str(nc))
let prev_ec_raw: String = state_get("soul.prev_edge_count")
let prev_ec: Int = if str_eq(prev_ec_raw, "") { ec } else { str_to_int(prev_ec_raw) }
let edge_delta: Int = ec - prev_ec
state_set("soul.prev_edge_count", int_to_str(ec))
// sync_age_ms: wall-clock ms since the last SUCCESSFUL engram sync merge
// (-1 = never synced this boot). sync_added_total alone can't show that
// sync stopped happening — a stale running total looks identical to a
// quiet-but-healthy sync. Age makes overdue-ness directly observable:
// sync_age_ms >> SOUL_REFRESH_MS means the refresh path is broken.
// (2026-07-19 self-review)
let sync_ok_raw: String = state_get("soul.last_sync_ok_ts")
let sync_age: Int = if str_eq(sync_ok_raw, "") { 0 - 1 } else { ts - str_to_int(sync_ok_raw) }
let payload: String = "{\"event\":\"heartbeat\",\"pulse\":" + pulse + ",\"tick\":" + pulse + ",\"boot\":" + boot + ",\"idle\":" + idle + ",\"node_count\":" + int_to_str(nc) + ",\"edge_count\":" + int_to_str(ec) + ",\"node_delta\":" + int_to_str(node_delta) + ",\"edge_delta\":" + int_to_str(edge_delta) + ",\"wm_active\":" + int_to_str(wmc) + ",\"wm_delta\":" + int_to_str(wm_delta) + ",\"sync_added_total\":" + sat_str + ",\"sync_age_ms\":" + int_to_str(sync_age) + ",\"wm_avg_weight\":" + wm_avg_str + ",\"wm_top\":" + wm_top + ",\"ts\":" + int_to_str(ts) + ",\"uptime_ms\":" + int_to_str(up_ms) + ",\"uptime\":\"" + up_human + "\",\"embed_ok\":" + int_to_str(emb_ok) + ",\"ise_fail\":" + fail_str + "}"
ise_post(payload)
}
@@ -131,11 +188,11 @@ fn emit_heartbeat() -> Void {
// during idle periods. Rotates through 4 domain sets on a wall-clock minute
// cycle so no single topic dominates WM between heartbeats.
//
// KEY DESIGN: each seed set is split into INDIVIDUAL words and activated
// separately. engram_activate uses istr_contains (substring matching) for
// seed finding, so a multi-word phrase like "memory knowledge context" only
// finds nodes that contain that EXACT phrase. Activating each word separately
// hits hundreds of nodes per word, giving the graph a genuine WM workout.
// KEY DESIGN (revised 2026-07-17): the seed set is activated ONCE as the full
// phrase. engram_activate uses istr_contains (substring matching), so the
// phrase matches few nodes — that is intentional: the old per-word split hit
// hundreds of generic nodes per word and flooded the graph with activation
// every scan. The top result is strengthened so the read feeds back.
//
// Unlike perceive(), this intentionally calls engram_activate_json to build
// up WM weights. It only fires when the inbox is empty (no real work to do),
@@ -216,11 +273,12 @@ fn proactive_curiosity() -> Bool {
let curiosity_term_b: String = state_get("cseed_b")
let curiosity_term_c: String = state_get("cseed_c")
// Activate each term independently so substring seed-finding hits many nodes.
// hops=1 (not 2): the in-process Engram has grown to 165K+ nodes. hops=2 BFS
// visits far more nodes and returns much larger JSON blobs. On a graph this
// large, hops=1 still activates all directly-related nodes, giving broad
// working-memory coverage without the quadratic blowup of hops=2.
// Activate the FULL seed phrase once (2026-07-17 self-review): the old
// per-word activation ("memory", "self", "context"... each fired separately)
// hit hundreds of generic nodes per word and flooded the graph every 30s,
// while the results were consumed only by json_array_len — a write-only
// loop. A single phrase activation matches few (often zero) nodes lexically;
// small counts here are the point, not a regression. hops=1 as before.
//
// NOTE: a semantic seed supplement (cosine sim ≥ 0.70 scan over embedded nodes)
// was planned alongside hops=1 but is NOT yet implemented — embed_ok in
@@ -228,13 +286,16 @@ fn proactive_curiosity() -> Bool {
// activation. The seed-finding loop in el_runtime.c uses istr_contains only.
// (2026-06-30 self-review: corrected stale comment)
let curiosity_seed: String = curiosity_term_a + " " + curiosity_term_b + " " + curiosity_term_c
let results_a: String = engram_activate_json(curiosity_term_a, 1)
let results_b: String = engram_activate_json(curiosity_term_b, 1)
let results_c: String = engram_activate_json(curiosity_term_c, 1)
let found_a: Int = json_array_len(results_a)
let found_b: Int = json_array_len(results_b)
let found_c: Int = json_array_len(results_c)
let found: Int = found_a + found_b + found_c
let results_all: String = engram_activate_json(curiosity_seed, 1)
let found: Int = json_array_len(results_all)
// Close the loop: strengthen the top activation result so curiosity reads
// feed back into salience instead of being discarded. Same id-extraction
// pattern as attend(): json_array_get element 0, json_get its "id".
let top_entry: String = json_array_get(results_all, 0)
let top_id: String = json_get(top_entry, "id")
if !str_eq(top_id, "") {
engram_strengthen(top_id)
}
// WM-autobiographical 4th seed: scan top-10 WM nodes for the highest-ranked
// non-Knowledge node. Extract its first word as an additional curiosity term.
@@ -491,7 +552,6 @@ fn one_cycle() -> Bool {
let outcome: String = respond(action)
record(outcome)
pulse_inc()
return true
}
@@ -551,8 +611,16 @@ fn awareness_run() -> Void {
return ""
}
let did_work: Bool = one_cycle()
// Liveness pulse: increment once per loop tick unconditionally, so the
// heartbeat's pulse field is a real tick counter — a frozen pulse now
// means a frozen loop, not merely an empty inbox. (Previously pulse_inc
// only fired on non-noop inbox actions inside one_cycle.)
pulse_inc()
// Maintain idle counter for observability (reported in heartbeat ISE).
let did_work = if did_work { idle_reset() } else { did_work }
// The old `let did_work = if did_work { idle_reset() } else { did_work }`
// rebound did_work to Void and never called idle_inc at all.
if did_work { idle_reset() }
if !did_work { idle_inc() }
let now_ts: Int = time_now()
// Heartbeat: wall-clock based. Fires every beat_ms regardless of idle
@@ -595,7 +663,17 @@ fn awareness_run() -> Void {
let refresh_elapsed: Int = now_ts - last_refresh_ts
let should_refresh: Bool = refresh_elapsed >= refresh_ms
if should_refresh {
let engram_url: String = state_get("soul_engram_url")
// URL resolution mirrors ise_post: env -> state -> well-known localhost
// constant. Previously this path gated on state_get("soul_engram_url")
// alone with NO fallback — the exact corruptible-state failure mode the
// ISE write path was hardened against (boot 4: state key went "" mid-
// uptime). A "" state key here meant sync silently never ran while
// heartbeats kept flowing: WM starves of Knowledge/Memory nodes with no
// outward sign. Never let a corruptible state read decide whether the
// in-process store gets refreshed. (2026-07-19 self-review)
let sync_env_url: String = env("SOUL_ISE_URL")
let sync_state_url: String = if str_eq(sync_env_url, "") { state_get("soul_engram_url") } else { sync_env_url }
let engram_url: String = if str_eq(sync_state_url, "") { "http://localhost:8742" } else { sync_state_url }
if !str_eq(engram_url, "") {
let sync_json: String = http_get(engram_url + "/api/sync")
if !str_eq(sync_json, "") && !str_eq(sync_json, "{}") {
@@ -603,8 +681,21 @@ fn awareness_run() -> Void {
let tmp: String = "/tmp/soul-sync-" + cgi_id + ".json"
fs_write(tmp, sync_json)
let added: Int = engram_load_merge(tmp)
// Backflow control: the merged snapshot carries ISE telemetry
// from the HTTP store. Prune anything older than 48h — same
// horizon the HTTP store itself uses (server.el ISE insert).
let pruned_sync: Int = engram_prune_telemetry(172800000)
// Running total of merged-in nodes this boot, surfaced in the
// heartbeat ISE as sync_added_total (same state mechanism as
// the pulse counter).
let sat_raw: String = state_get("soul.sync_added_total")
let sat_n: Int = if str_eq(sat_raw, "") { 0 } else { str_to_int(sat_raw) }
state_set("soul.sync_added_total", int_to_str(sat_n + added))
let ts2: Int = time_now()
ise_post("{\"event\":\"engram_sync\",\"added\":" + int_to_str(added) + ",\"ts\":" + int_to_str(ts2) + "}")
// Stamp last successful sync — surfaced in the heartbeat as
// sync_age_ms so overdue syncs are visible. (2026-07-19)
state_set("soul.last_sync_ok_ts", int_to_str(ts2))
ise_post("{\"event\":\"engram_sync\",\"added\":" + int_to_str(added) + ",\"pruned\":" + int_to_str(pruned_sync) + ",\"ts\":" + int_to_str(ts2) + "}")
}
}
state_set("soul.last_refresh_ts", int_to_str(now_ts))