Skip to content

fix: resolve trace and chain hashes without rescanning the store - #599

Merged
creatornader merged 1 commit into
mainfrom
fix/graph-node-trace-hash-oom
Jul 29, 2026
Merged

fix: resolve trace and chain hashes without rescanning the store#599
creatornader merged 1 commit into
mainfrom
fix/graph-node-trace-hash-oom

Conversation

@creatornader

Copy link
Copy Markdown
Owner

What was actually wrong

The deploy-services canary flap was a real production outage, not an impatient check.

/v1/trace and /v1/chain resolved a record_hash by rebuilding an index over the entire store on every request: getAllRecords() then canonicalRecord -> sha256 -> hexEncode for every record. The code said why that was fine:

For a busy log this would move into the store, but at current scale (low thousands of records) the per-request build is fast enough.

The log passed 112k records in July 2026, two orders of magnitude past that assumption.

Evidence

Three consecutive /v1/trace requests against production, 2026-07-29:

attempt1 status=502 total=17.474184s
attempt2 status=502 total=25.695895s
attempt3 status=502 total=24.675035s

Each one crashed the service. From flyctl logs -a atrib-graph:

Mark-Compact (reduce) 479.3 (488.5) -> 479.2 (488.5) MB, (average mu = 0.351)
FATAL ERROR: Ineffective mark-compacts near heap limit
Main child exited with signal (with signal 'SIGABRT', core dumped? false)

Mark-compact reclaiming 0.1MB of a 488MB heap, and mu = 0.35 means 65% of wall-clock in GC. The live set had filled the heap. Measured cost of one rebuild at this size: ~80MB of transient strings and >1s of CPU.

Each crash then replayed the 68MB archive (6s cold, up to 74s under pressure), extending the 502 window. The canary polls every 2s but each attempt blocked 17-25s, which is why it reported only 3-4 attempts inside its 90s deadline and exited with last_status=502.

Ruled out along the way:

  • Not the triggering commit. faf69bc0 both succeeded (02:14) and failed (02:19).
  • Not a deploy race. apps/dashboard/* maps to log_node only, so those runs never deployed graph-node.
  • Not an impatient canary. The loop is deadline-bound (90s), not attempt-bound. The low attempt count is a symptom of 20s+ hangs, not a cause.

The fix

1. O(1) hash resolution. The store already hashes every record once at ingest and exposes getRecordByHash(). Both handlers now use it. Same semantics: the walks only ever did point lookups.

2. Let V8 use the RAM the machine already has. Node caps old-space near half a small machine's RAM regardless of [[vm]] memory. V8 reported heap_size_limit = 493MB on the 1024mb machine, so the 2026-05-06 bump from 256mb never reached the heap that was running out.

The canary is deliberately unchanged. It was correct.

Verification

Real server, 112k records, production's heap margin, identical conditions:

result
before FATAL ERROR: Ineffective mark-compacts near heap limit
after status=200 ms=244
  • services/graph-node: 115/115 tests pass, including the §3.4.5 trace and §3.4.6 chain conformance corpora, which pin the semantics.
  • New test/trace-hash-lookup.test.ts counts full-store scans and asserts zero. Confirmed to fail on the unfixed code (3 of 5 fail) and pass after.
  • pnpm doc-sync: 14 checks pass.

Follow-ups, not in this PR

  1. Headroom is finite. The log grows ~4k records/day at ~4KB each in heap, so ~17MB/day. A 768MB heap buys weeks. The durable fix is the disk-backed graph store already flagged in src/persistence.ts, which notes the in-memory shape is sustainable to ~10^5 records. The log passed that.
  2. Latent canary race. deploy-log-node and deploy-graph-node both depend only on changes, so they run in parallel with no ordering. A commit touching packages/mcp/* sets both, and the canary can run against a graph-node that is mid-restart. This did not cause the failures investigated here, but it will produce false failures eventually.

/v1/trace and /v1/chain resolved a record_hash by rebuilding an index over
the entire store on every request: getAllRecords() followed by
canonicalRecord -> sha256 -> hexEncode per record. That code was written
for a log holding "low thousands" of records, as its own comment said. The
log passed 112k in July 2026.

At that size each request allocated ~80MB of transient strings and burned
over a second of CPU, against a V8 heap already about 450MB full of the
resident record set. The allocation could not be satisfied, so V8 aborted
the process with "Ineffective mark-compacts near heap limit" and Fly served
the dead instance as a 502. Three consecutive trace requests against
production on 2026-07-29 produced three crashes, one per request. Each
restart then replayed the 68MB archive, 6s cold and up to 74s under memory
pressure, extending the 502 window.

That is what flapped the deploy-services graph canary at roughly 50% and
what broke the explorer trace view. The canary was reporting a real
outage, so it is unchanged here.

The store already hashes every record once at ingest and exposes
getRecordByHash(), so both handlers now do point lookups. Verified by
running the real server with 112k records under production's heap margin:
the old code reproduces the exact fatal error, the new code answers in
244ms.

Second defect, independent of the first: node caps its old-space heap near
half of a small machine's RAM regardless of the fly.toml [[vm]] setting. V8
reported heap_size_limit = 493MB on the 1024mb machine, so the 2026-05-06
bump from 256mb never reached the heap that was running out. NODE_OPTIONS
now makes that RAM usable.

Headroom stays finite. The log grows about 4k records/day, so a 768MB heap
buys weeks, not indefinitely. The durable fix remains the disk-backed graph
store already flagged in src/persistence.ts.
@creatornader
creatornader merged commit 24cc575 into main Jul 29, 2026
22 of 24 checks passed
@creatornader
creatornader deleted the fix/graph-node-trace-hash-oom branch July 29, 2026 06:52
creatornader added a commit that referenced this pull request Jul 29, 2026
* ci: run the graph canary after both deploys settle

The log-to-graph canary was the last step of deploy-log-node, which depends
only on the `changes` job. deploy-graph-node depends on `changes` too, so the
two ran in parallel with no ordering between them. A commit touching a shared
path (packages/mcp/*, package.json, pnpm-lock.yaml, pnpm-workspace.yaml,
tsconfig.base.json, .dockerignore) sets both service flags, and the canary
could then poll graph-node while its machine was restarting into the new
release. graph-node replays its whole record archive on start, so that window
serves 502s and the canary reports a failure on a system that is fine.

This did not cause the 2026-07-29 flap, which was a real graph-node OOM fixed
in #599. It is a separate latent source of false failures in the same check.

The canary now also runs when only graph-node deployed. It exercises log
submit through graph index, so a graph-node-only release is exactly the change
it should gate. Previously it ran on log-node releases only, which is why the
trace regression reached production without the canary seeing it.

deploy-log-node loses its pnpm install and workspace build: they existed only
for the canary, and check-log-smoke.mjs imports node:crypto alone.

* feat: warn on graph-node heap pressure before the ceiling

The 2026-07-29 outage gave no warning. graph-node keeps every record and
derived index in memory, so the live heap grows linearly with the log; it
reached the V8 ceiling at ~112k records and the process began aborting on
allocation, which Fly served as 502s. The service had a disk watchdog, but
disk was never the constraint: the archive was 68MB on a 1GB volume while the
heap sat at 91%.

Adds the matching watchdog for the resource that actually fails. It mirrors
the disk watchdog's shape, logs only on threshold transitions so a steady
state does not train operators to filter it out, and carries record_count so
headroom divided by records/day gives runway directly. Thresholds are 70% and
85%, below the disk watchdog's 80/95, because heap has no graceful
degradation: crossing the V8 limit aborts the process, per-request allocation
sits on top of the live set, and recovery costs a full archive replay that
serves errors throughout. One unconditional line per boot leaves a datapoint
even while healthy.

The threshold logic sits in its own module so it is unit-tested. An alerting
path that never fires reads as an all-clear, which is worse than no alert.

Files P059 for the structural question #599 did not answer. That PR removed
the trigger and raised the ceiling; it did not change the shape. At filing:
112,781 records, 439MB RSS, 780MB ceiling, ingest around 4k to 7k records/day
at ~3.4KB of heap each. That is weeks of runway, not quarters. persistence.ts
already named ~10^5 records as the boundary and the log passed it in July
2026. The watchdog's warn threshold is the intended trigger for acting on it.
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment

Labels

None yet

Projects

None yet

Development

Successfully merging this pull request may close these issues.

1 participant