Skip to content

fix: refuse or stop runaway cross-product queries within their limits and release their memory - #304

Merged
jsam merged 4 commits into
mainfrom
fm/fix-runaway-query
Oct 5, 2026
Merged

jsam merged 4 commits into
mainfrom
fm/fix-runaway-query

Conversation

@jsam

@jsam jsam commented Oct 5, 2026 •

Copy link
Copy Markdown
Contributor

Intent

I want you to really hyper focus on making the symbolic engine, you know, crisp and really truly production ready. (Context: #296 and audit report section P0-5: one cartesian query on shipped defaults exhausted memory and was OOM-killed; the 30 s timeout never fired.) The P0-5 finding being fixed here: a single authenticated query such as ?a(X), b(Y) over two relations of 30,000 rows each, on shipped default configuration, drove the server process to its memory ceiling and got it OOM-killed; the 30-second query timeout never fired, and the client disconnecting did not free the memory either. Scope of this change: that P0 runaway query must be refused or cancelled within the configured limits with a typed error, and its memory released, so the server stays alive and other tenants keep answering.

What Changed

  • Stopping a query mid-step: before this change, the deadline, cancel and per-query memory limit were only checked between dataflow steps, so a cross product could run away inside a single join step. Joins, result sinks and the antijoin's negated side now check the request every 1,024 pairs or rows they produce (src/code_generator). A runaway query now stops with resource_exhausted right after it passes its memory limit, or soon after its deadline or a cancel. If the antijoin sub-dataflow fails, the query now fails too; before, the negated side was treated as empty. After a stopped computation that held more than the release threshold, the server returns the freed memory to the OS before handing the compute permit to the next query. It also logs when the computation exits, or that it is still running after 1 s.
  • Refusing before the query runs: storage.performance.max_query_cost now limits the estimated rows per join, based on relation sizes. A join on shared variables counts as its larger input; a cross product counts as the product of its inputs. Plans over the limit are estimated again using only the rows their filters keep of stored relations. The default changes from 0 to 100,000,000, so ?a(X), b(Y) over 30k × 30k is refused with validation before it runs, and the server warns at startup when the limit is set to 0. Also added:
    • An optional max_recursion_iterations setting (default 0 = off) that stops recursion that never reaches a fixpoint.
    • Both limits now apply to a graph's queries before its first write, and to session-rule queries.
    • A fix to filter pushdown: a filter can now be pushed through Distinct, and a filter moved to a join's right side now maps to the correct column, skipping the join keys.
  • Server-wide memory budget: the default all-queries budget now follows the tightest cgroup limit on the process (e.g. a systemd MemoryMax=), not just the cgroup root. A query holding less than 1/64 of the budget (at most 16 MiB) is no longer stopped when other queries fill the pool; the queries that filled it are. The config example, configuration/deployment guides and the error spec (with new "Query Too Complex" and "Recursion Did Not Reach a Fixpoint" entries) are updated, and tests/memory_limit_tests.rs adds coverage.

Risk Assessment

⚠️ Medium: The change looks correct and meets the P0-5 intent and the operator's F1/F2 decisions. It is still medium risk because it reaches deep into the engine: the default max_query_cost now refuses large cross products, every join and output sink checks the request as it runs, the negated side of an antijoin can now fail the whole query, and filters are now pushed down through Distinct. That last change already caused one wrong-result bug, which a later commit fixed.

Testing

I drove the real release server over WebSocket, plus the bundled CLI client, inside an 8 GiB memory-capped scope standing in for a container. On shipped defaults, the P0-5 cross product is refused right away with validation. With the cost guard off, it is stopped by the memory limits, the deadline, a cancel or a disconnect, each with a typed error. Memory came back to idle every time, other tenants kept answering, and there was no OOM kill. The operator's decisions on filtered queries and the off-by-default recursion ceiling hold, and the mutual-recursion fix gives the expected rows. Every scenario passed. The artifacts are CLI/WebSocket transcripts and cgroup counters in the evidence directory; there is no UI surface.

  • Live validation: ✅ go - 11 of 11 scenarios driven live against the product
Scenario Result Live Evidence
On shipped defaults, ?a(X), b(Y) over two 30k-row relations is refused before it runs with a typed validation error, and server memory stays flat ✅ pass live s_defaults.log: validation 'Query too complex ... about 900000000 rows, over the limit of 100000000' in 1 ms; RSS 48 MiB before and after
The same cross product through a persistent rule or a session rule is also refused on defaults ✅ pass live s_rules.log: ?pairs(X,Y) and ?spairs(X,Y) both return code validation; the server keeps serving
Other tenants keep answering while a runaway query is running or being stopped ✅ pass live s_defaults.log, s_runaway.log, s_recursion_defaults.log: point queries from a second connection return in ~1 ms during each runaway
With the cost guard off, the runaway cross product is stopped by the per-query memory limit with resource_exhausted, and memory is released with no OOM kill ✅ pass live s_runaway.log S4a: resource_exhausted after 8.2 s, peak RSS 4.6 GiB, then 36 MiB; cgroup-guardoff.txt: oom_kill 0, peak 5.8 GB under 8 GiB max
Two tenants running the runaway at once are stopped by the total query memory budget detected from the cgroup ✅ pass live s_runaway.log S4b: both get resource_exhausted (max_total_query_memory_bytes), RSS 36 MiB after
The deadline fires on a runaway query (timeout_ms and the default 30 s) with deadline_exceeded ✅ pass live s_runaway.log S4c: deadline_exceeded at 302 ms with timeout_ms 300; s_recursion_defaults.log: default 30 s deadline returns deadline_exceeded at 30002 ms
An explicit cancel stops a running cross product and frees its memory ✅ pass live s_runaway.log S4d: error cancelled, cancel_ack outcome=cancelled, RSS 37 MiB after; server log query_stopped_exited stop=Cancelled exit_ms=76
A client that disconnects mid-runaway has its query's memory freed ✅ pass live s_runaway.log S4e: RSS 419 MiB before the disconnect, 37 MiB 500 ms after
Filter-aware cost (operator decision F1): ?a2(X, 7), b(Y) and ?a2(X, V), V > 29998, b(Y) with one match run under default limits; ?a2(X, V), V < 20000, b(Y) is still refused ✅ pass live s_defaults.log S5a/S5b: 30000 rows each in ~60 ms; S5c: validation at about 600000000 rows; S5d: keyed join runs normally
Recursion ceiling (operator decision F2): off by default, so an unbounded counter is stopped by the deadline; with max_recursion_iterations=1000 set, it is refused with validation ✅ pass live s_recursion_defaults.log: deadline_exceeded with no iteration refusal; s_runaway.log S6b: validation 'did not reach a fixpoint within 1000 iterations'
Regression from the latest commit: the mutual binary paths example returns even_path(X, 4) = (1,4), (2,4), (3,4) through the real client ✅ pass live mutual_paths.out matches examples/iql/09_recursion/31_mutual_binary_paths.iql.out
Evidence: Shipped-defaults transcript: P0-5 refused with validation, other tenant answers, filtered queries run, wide filters refused
[0.03s] server RSS before: 48 MiB
[0.04s] S1 P0-5 cartesian: ?a(X), b(Y) (1 ms) {"type":"error","code":"validation","message":"Query execution failed: Query too complex: it joins 30000 rows with 30000 rows on no shared variable, a cross product of about 900000000 rows, over the limit of 100000000 (storage.performance.max_query_cost). Join them on a shared variable, order the rule body so each atom shares a variable with one before it, or filter a side with a constant or comparison so fewer of its rows meet"}
[0.04s] S3 other tenant during S1: ?a2(X, 7) (1 ms) {"type":"result","row_count":1,"rows":[[7,7]]}
[0.04s] server RSS after S1: 48 MiB
[0.10s] S5a filtered (1 match): ?a2(X, 7), b(Y) (63 ms) {"type":"result","row_count":30000}
[0.16s] S5b comparison (1 match): ?a2(X, V), V > 29998, b(Y) (58 ms) {"type":"result","row_count":30000}
[0.16s] S5c filter keeps 20000 rows: ?a2(X, V), V < 20000, b(Y) (1 ms) {"type":"error","code":"validation","message":"Query execution failed: Query too complex: it joins 20000 rows with 30000 rows on no shared variable, a cross product of about 600000000 rows, over the limit of 100000000 (storage.performance.max_query_cost). Join them on a shared variable, order the rule body so each atom shares a variable with one before it, or filter a side with a constant or comparison so fewer of its rows meet"}
[0.27s] S5d keyed join: ?a(X), a2(X, V), b(V) (107 ms) {"type":"result","row_count":30000}
[0.27s] server RSS end: 75 MiB
[0.27s] S3 health after: ?a2(X, 29999) (2 ms) {"type":"result","row_count":1,"rows":[[29999,29999]]}
Evidence: Cross product through persistent and session rules refused on defaults
[0.04s] S2 persistent rule: +pairs(X, Y) <- a(X), b(Y) (10 ms) {"type":"result","row_count":1,"rows":[["Rule 'pairs' registered."]]}
[0.04s] S2 query rule: ?pairs(X, Y) (1 ms) {"type":"error","code":"validation","message":"Query execution failed: Query too complex: it joins 30000 rows with 30000 rows on no shared variable, a cross product of about 900000000 rows, over the limit of 100000000 (storage.performance.max_query_cost). Join them on a shared variable, order the rule body so each atom shares a variable with one before it, or filter a side with a constant or comparison so fewer of its rows meet"}
[0.04s] S2 session rule query: spairs(X, Y) <- a(X), b(Y) (0 ms) {"type":"result","row_count":1,"rows":[["Session rule added for 'spairs'."]]}
[0.04s] S2 query session rule: ?spairs(X, Y) (1 ms) {"type":"error","code":"validation","message":"Query execution failed: Query too complex: it joins 30000 rows with 30000 rows on no shared variable, a cross product of about 900000000 rows, over the limit of 100000000 (storage.performance.max_query_cost). Join them on a shared variable, order the rule body so each atom shares a variable with one before it, or filter a side with a constant or comparison so fewer of its rows meet"}
[0.04s] S2 cleanup: .session clear (0 ms) {"type":"result","row_count":1,"rows":[["Cleared 0 session fact(s), 1 session rule(s)."]]}
[0.04s] S2 still serving: ?a(29999) (1 ms) {"type":"result","row_count":1,"rows":[[29999]]}
Evidence: Runaway with guard off: stopped by memory limit, total memory limit, deadline, cancel and disconnect, with RSS samples
[0.03s] RSS idle: 47 MiB
[1.04s] S3 other tenant during runaway: ?a2(X, 7) {} (1 ms) {"type":"result","row_count":1,"rows":[[7,7]]}
[8.26s] S4a runaway (default deadline): ?a(X), b(Y) {} (8226 ms) {"type":"error","code":"resource_exhausted","message":"Request exceeded the per-query memory limit (storage.performance.max_query_memory_bytes) before it began committing; nothing was applied. Narrow the query or bind more of its arguments"}
[8.26s] S4a peak RSS seen: 4647 MiB
[10.26s] S4a RSS 2 s after: 36 MiB
[11.27s] S3 other tenant during 2 runaways: ?a(5) {} (1 ms) {"type":"result","row_count":1,"rows":[[5]]}
[14.58s] S4b tenant1 runaway: ?a(X), b(Y) {} (4313 ms) {"type":"error","code":"resource_exhausted","message":"Request stopped: the queries running on the server hold their whole memory budget (storage.performance.max_total_query_memory_bytes); it was stopped before it began committing and nothing was applied. Retry later"}
[14.58s] S4b tenant2 runaway: ?b(Y), a(X) {} (4313 ms) {"type":"error","code":"resource_exhausted","message":"Request stopped: the queries running on the server hold their whole memory budget (storage.performance.max_total_query_memory_bytes); it was stopped before it began committing and nothing was applied. Retry later"}
[16.58s] S4b RSS after: 36 MiB
[16.89s] S4c runaway with timeout_ms 300: ?a(X), b(Y) {"timeout_ms":300} (302 ms) {"type":"error","code":"deadline_exceeded","message":"Request deadline exceeded before it began committing; nothing was applied"}
[18.89s] S4c RSS after: 37 MiB
[19.19s] S4d runaway to cancel: ?a(X), b(Y) {"id":"big"} (301 ms) {"type":"error","code":"cancelled","message":"Request cancelled before it began committing; nothing was applied"}
[19.19s] S4d cancel_ack: {"type":"cancel_ack","id":"r2","target":"big","outcome":"cancelled"}
[21.20s] S4d RSS after: 37 MiB
[21.60s] S4e RSS while running (before disconnect): 419 MiB
[21.60s] S4e client disconnected
[22.10s] S4e RSS after disconnect: 37 MiB
[22.60s] S4e RSS after disconnect: 37 MiB
[23.10s] S4e RSS after disconnect: 37 MiB
[23.60s] S4e RSS after disconnect: 37 MiB
[24.10s] S4e RSS after disconnect: 37 MiB
[24.60s] S4e RSS after disconnect: 37 MiB
[24.61s] S6b setup: +seed[(0)] {} (8 ms) {"type":"result","row_count":1,"rows":[["Inserted 1 fact(s) into 'seed'."]]}
[24.62s] S6b setup: +nat(N) <- seed(N) {} (6 ms) {"type":"result","row_count":1,"rows":[["Rule 'nat' registered."]]}
[24.63s] S6b setup: +nat(N) <- nat(M), N = M + 1 {} (6 ms) {"type":"result","row_count":1,"rows":[["Rule 'nat' registered."]]}
[24.65s] S6b counter with ceiling set: ?nat(N) {} (22 ms) {"type":"error","code":"validation","message":"Query execution failed: Recursion did not reach a fixpoint within 1000 iterations (storage.performance.max_recursion_iterations): a recursive rule keeps deriving new facts, such as a counter without an upper bound. Bound the recursion, for example with N < 1000"}
[24.65s] S6b cleanup: -nat {} (6 ms) {"type":"result","row_count":1,"rows":[["Rule 'nat' dropped."]]}
[24.65s] S3 health at end: ?a2(X, 29999) {} (1 ms) {"type":"result","row_count":1,"rows":[[29999,29999]]}
[24.65s] RSS end: 38 MiB
Evidence: Scope cgroup counters: 8 GiB max, 5.8 GB peak, oom_kill 0
memory.max=8589934592
memory.peak=5833498624
oom 0
oom_kill 0
oom_group_kill 0
Evidence: Unbounded recursion on defaults: deadline_exceeded, no iteration refusal
[0.04s] S6 setup: +seed[(0)] {} (5 ms) {"type":"result","row_count":1,"rows":[["Inserted 1 fact(s) into 'seed'."]]}
[0.05s] S6 setup: +nat(N) <- seed(N) {} (7 ms) {"type":"result","row_count":1,"rows":[["Rule 'nat' registered."]]}
[0.06s] S6 setup: +nat(N) <- nat(M), N = M + 1 {} (6 ms) {"type":"result","row_count":1,"rows":[["Rule 'nat' registered."]]}
[2.06s] RSS while running: 83 MiB
[2.06s] S6 other tenant while counter runs: ?a(123) {} (1 ms) {"type":"result","row_count":1,"rows":[[123]]}
[5.06s] S6 unbounded counter (deadline 5 s): ?nat(N) {"timeout_ms":5000} (5002 ms) {"type":"error","code":"deadline_exceeded","message":"Request deadline exceeded before it began committing; nothing was applied"}
[6.56s] RSS after: 107 MiB
[36.56s] S6 bounded counter still fine: ?nat(N), N < 3 {} (30002 ms) {"type":"error","code":"deadline_exceeded","message":"Request deadline exceeded before it began committing; nothing was applied"}
Evidence: Mutual-recursion example run through inputlayer-client (matches .iql.out)
Connecting to server at http://127.0.0.1:18471...
Connected!

Server status: healthy
Authenticated as: admin
Current knowledge graph: default

> .kg create test_mutual_paths_n09t31
Knowledge graph 'test_mutual_paths_n09t31' created.
Switched to knowledge graph: test_mutual_paths_n09t31
> .kg use test_mutual_paths_n09t31
Switched to knowledge graph: test_mutual_paths_n09t31
> +edge[(1, 2), (2, 3), (3, 1), (3, 4)]
Inserted 4 fact(s) into 'edge'.
> +odd_path(X, Y) <- edge(X, Y)
Rule 'odd_path' registered.
> +odd_path(X, Z) <- even_path(X, Y), edge(Y, Z)
Rule 'odd_path' registered.
> +even_path(X, Z) <- odd_path(X, Y), edge(Y, Z)
Rule 'even_path' registered.
> ?odd_path(1, Y)
┌───┬───┐
│ 1 │ Y │
├───┼───┤
│ 1 │ 1 │
│ 1 │ 2 │
│ 1 │ 3 │
│ 1 │ 4 │
└───┴───┘
4 rows
> ?even_path(1, Y)
┌───┬───┐
│ 1 │ Y │
├───┼───┤
│ 1 │ 1 │
│ 1 │ 2 │
│ 1 │ 3 │
│ 1 │ 4 │
└───┴───┘
4 rows
> ?even_path(X, 4)
┌───┬───┐
│ X │ 4 │
├───┼───┤
│ 1 │ 4 │
│ 2 │ 4 │
│ 3 │ 4 │
└───┴───┘
3 rows
> .kg use default
Switched to knowledge graph: default
> .kg drop test_mutual_paths_n09t31
Knowledge graph 'test_mutual_paths_n09t31' dropped.
Evidence: Server logs (defaults and guard-off runs)
Running as unit: il-test-guardoff.scope; invocation ID: cf81af253c0a4e6a8e71baaf1a3b5368
InputLayer Server
=================

WARNING: max_query_cost = 0 (unlimited). A query joining large relations without a shared variable (a cross product) runs until a deadline or memory limit stops it.
�[2m2026-10-05T12:42:30.929527Z�[0m �[32m INFO�[0m �[2minputlayer::storage_engine�[0m�[2m:�[0m data_dir_lock_acquired �[3mdata_dir�[0m�[2m=�[0m/home/sam/.no-mistakes/evidence/01M45ZWGE49MHWX7DYASWQCHBK/run/guardoff/data �[3melapsed_us�[0m�[2m=�[0m92
�[2m2026-10-05T12:42:30.936072Z�[0m �[32m INFO�[0m �[2minputlayer::storage_engine�[0m�[2m:�[0m kg_load_complete �[3mknowledge_graphs�[0m�[2m=�[0m0 �[3melapsed_ms�[0m�[2m=�[0m0
�[2m2026-10-05T12:42:30.940670Z�[0m �[32m INFO�[0m �[2minputlayer::storage_engine�[0m�[2m:�[0m save_metadata_complete �[3melapsed_ms�[0m�[2m=�[0m4
�[2m2026-10-05T12:42:30.940682Z�[0m �[32m INFO�[0m �[2minputlayer::storage_engine�[0m�[2m:�[0m kg_create_complete �[3mkg�[0m�[2m=�[0mdefault �[3melapsed_ms�[0m�[2m=�[0m4
�[2m2026-10-05T12:42:30.941168Z�[0m �[32m INFO�[0m �[2minputlayer::protocol::handler�[0m�[2m:�[0m query_memory_limits �[3mquery_memory_bytes�[0m�[2m=�[0m4294967296 �[3mtotal_query_memory_bytes�[0m�[2m=�[0m5153960754 �[3mcompute_permits�[0m�[2m=�[0m24
�[2m2026-10-05T12:42:30.943729Z�[0m �[32m INFO�[0m �[2minputlayer::storage_engine�[0m�[2m:�[0m save_metadata_complete �[3melapsed_ms�[0m�[2m=�[0m2
�[2m2026-10-05T12:42:30.943739Z�[0m �[32m INFO�[0m �[2minputlayer::storage_engine�[0m�[2m:�[0m kg_create_complete �[3mkg�[0m�[2m=�[0m_internal �[3melapsed_ms�[0m�[2m=�[0m2
�[2m2026-10-05T12:42:30.973647Z�[0m �[32m INFO�[0m �[2minputlayer::storage_engine::program_commit�[0m�[2m:�[0m program_commit_persisted �[3mkg�[0m�[2m=�[0m_internal �[3mrelations�[0m�[2m=�[0m1 �[3mstatements�[0m�[2m=�[0m1 �[3mtime�[0m�[2m=�[0m1 �[3mpersist_ms�[0m�[2m=�[0m4
�[2m2026-10-05T12:42:30.973700Z�[0m �[32m INFO�[0m �[2minputlayer::storage_engine�[0m�[2m:�[0m snapshot_publish_complete �[3mrelations�[0m�[2m=�[0m1 �[3mrules�[0m�[2m=�[0m0 �[3msnapshot_ms�[0m�[2m=�[0m0
�[2m2026-10-05T12:42:30.973717Z�[0m �[32m INFO�[0m �[2minputlayer::protocol::handler�[0m�[2m:�[0m Auth bootstrap: admin user created
�[2m2026-10-05T12:42:30.982916Z�[0m �[32m INFO�[0m �[2minputlayer::storage_engine::program_commit�[0m�[2m:�[0m program_commit_persisted �[3mkg�[0m�[2m=�[0m_internal �[3mrelations�[0m�[2m=�[0m3 �[3mstatements�[0m�[2m=�[0m1 �[3mtime�[0m�[2m=�[0m2 �[3mpersist_ms�[0m�[2m=�[0m9
�[2m2026-10-05T12:42:30.982966Z�[0m �[32m INFO�[0m �[2minputlayer::storage_engine�[0m�[2m:�[0m snapshot_publish_complete �[3mrelations�[0m�[2m=�[0m4 �[3mrules�[0m�[2m=�[0m0 �[3msnapshot_ms�[0m�[2m=�[0m0
�[2m2026-10-05T12:42:30.982979Z�[0m �[32m INFO�[0m �[2minputlayer::protocol::handler�[0m�[2m:�[0m Auth bootstrap: API key 'bootstrap' created for admin
Storage engine initialized

HTTP Server
-----------
Address: 127.0.0.1:18471

HTTP server listening on: http://127.0.0.1:18471
WebSocket API docs at: http://127.0.0.1:18471/api/ws-docs
�[2m2026-10-05T12:42:34.945896Z�[0m �[32m INFO�[0m �[2minputlayer::protocol::rest::handlers::ws�[0m�[2m:�[0m ws_connection_start �[3mkg�[0m�[2m=�[0mdefault
�[2m2026-10-05T12:42:34.950184Z�[0m �[32m INFO�[0m �[2minputlayer::protocol::handler�[0m�[2m:�[0m audit_auth_apikey_success �[3musername�[0m�[2m=�[0m"admin" �[3mcredential�[0m�[2m=�[0mapikey:bootstrap#3
�[2m2026-10-05T12:42:34.950205Z�[0m �[32m INFO�[0m �[2minputlayer::protocol::rest::handlers::ws�[0m�[2m:�[0m ws_authenticated �[3mkg�[0m�[2m=�[0mdefault �[3musername�[0m�[2m=�[0madmin �[3mrole�[0m�[2m=�[0madmin �[3mcredential�[0m�[2m=�[0mapikey:bootstrap#3
�[2m2026-10-05T12:42:34.950216Z�[0m �[32m INFO�[0m �[2minputlayer::storage_engine�[0m�[2m:�[0m kg_ensure_exists �[3mkg�[0m�[2m=�[0mdefault �[3melapsed_ms�[0m�[2m=�[0m0
�[2m2026-10-05T12:42:34.950231Z�[0m �[32m INFO�[0m �[2minputlayer::protocol::rest::handlers::ws�[0m�[2m:�[0m ws_session_created �[3mkg�[0m�[2m=�[0mdefault �[3mactive_sessions�[0m�[2m=�[0m1
�[2m2026-10-05T12:42:34.953335Z�[0m �[32m INFO�[0m �[1mws_request�[0m: �[2minputlayer::protocol::rest::handlers::ws::execute�[0m�[2m:�[0m ws_execute_start �[3mprogram_len�[0m�[2m=�[0m33893 �[3mprogram_preview�[0m�[2m=�[0m+a[(0),(1),(2),(3),(4),(5),(6),(7),(8),(9),(10),(11),(12),(13),(14),(15),(16),(1 �[2m�[3mrequest_id�[0m�[2m=�[0m1 �[3mmsg_bytes�[0m�[2m=�[0m33934�[0m
�[2m2026-10-05T12:42:34.958936Z�[0m �[32m INFO�[0m �[2minputlayer::protocol::handler�[0m�[2m:�[0m query_job_start �[3mprogram_len�[0m�[2m=�[0m33893
�[2m2026-10-05T12:42:34.958952Z�[0m �[32m INFO�[0m �[2minputlayer::storage_engine�[0m�[2m:�[0m kg_ensure_exists �[3mkg�[0m�[2m=�[0mdefault �[3melapsed_ms�[0m�[2m=�[0m0
�[2m2026-10-05T12:42:34.959024Z�[0m �[32m INFO�[0m �[2minputlayer::protocol::handler�[0m�[2m:�[0m query_parse_complete �[3mprogram_len�[0m�[2m=�[0m33893 �[3mstatements�[0m�[2m=�[0m1 �[3mparse_ms�[0m�[2m=�[0m0
�[2m2026-10-05T12:42:34.967052Z�[0m �[32m INFO�[0m �[2minputlayer::storage_engine::program_commit�[0m�[2m:�[0m program_commit_persisted �[3mkg�[0m�[2m=�[0mdefault �[3mrelations�[0m�[2m=�[0m1 �[3mstatements�[0m�[2m=�[0m1 �[3mtime�[0m�[2m=�[0m3 �[3mpersist_ms�[0m�[2m=�[0m6
�[2m2026-10-05T12:42:34.968527Z�[0m �[32m INFO�[0m �[2minputlayer::storage_engine�[0m�[2m:�[0m snapshot_publish_complete �[3mrelations�[0m�[2m=�[0m1 �[3mrules�[0m�[2m=�[0m0 �[3msnapshot_ms�[0m�[2m=�[0m0
�[2m2026-10-05T12:42:34.968747Z�[0m �[32m INFO�[0m �[2minputlayer::protocol::handler�[0m�[2m:�[0m query_statement_exec_complete �[3mprogram_len�[0m�[2m=�[0m33893 �[3mstmt_exec_ms�[0m�[2m=�[0m9 �[3msession_facts�[0m�[2m=�[0m0 �[3msession_rules�[0m�[2m=�[0m0
�[2m2026-10-05T12:42:34.968758Z�[0m �[32m INFO�[0m �[2minputlayer::protocol::handler�[0m�[2m:�[0m query_job_complete_messages �[3mprogram_len�[0m�[2m=�[0m33893 �[3mtotal_ms�[0m�[2m=�[0m9
�[2m2026-10-05T12:42:34.968826Z�[0m �[32m INFO�[0m �[1mws_request�[0m: �[2minputlayer::protocol::handler�[0m�[2m:�[0m query_complete �[3mprogram_len�[0m�[2m=�[0m33893 �[3mcompute_ms�[0m�[2m=�[0m10 �[3mok�[0m�[2m=�[0mtrue �[2m�[3mrequest_id�[0m�[2m=�[0m1 �[3mmsg_bytes�[0m�[2m=�[0m33934�[0m
�[2m2026-10-05T12:42:34.968852Z�[0m �[32m INFO�[0m �[1mws_request�[0m: �[2minputlayer::protocol::rest::handlers::ws::execute�[0m�[2m:�[0m ws_execute_end �[3mprogram_len�[0m�[2m=�[0m33893 �[3melapsed_ms�[0m�[2m=�[0m15 �[3mok�[0m�[2m=�[0mtrue �[2m�[3mrequest_id�[0m�[2m=�[0m1 �[3mmsg_bytes�[0m�[2m=�[0m33934�[0m
�[2m2026-10-05T12:42:34.970287Z�[0m �[32m INFO�[0m �[1mws_request�[0m: �[2minputlayer::protocol::rest::handlers::ws::execute�[0m�[2m:�[0m ws_execute_start �[3mprogram_len�[0m�[2m=�[0m35003 �[3mprogram_preview�[0m�[2m=�[0m+a[(5000),(5001),(5002),(5003),(5004),(5005),(5006),(5007),(5008),(5009),(5010), �[2m�[3mrequest_id�[0m�[2m=�[0m2 �[3mmsg_bytes�[0m�[2m=�[0m35044�[0m
�[2m2026-10-05T12:42:34.973967Z�[0m �[32m INFO�[0m �[2minputlayer::protocol::handler�[0m�[2m:�[0m query_job_start �[3mprogram_len�[0m�[2m=�[0m35003
�[2m2026-10-05T12:42:34.973984Z�[0m �[32m INFO�[0m �[2minputlayer::storage_engine�[0m�[2m:�[0m kg_ensure_exists �[3mkg�[0m�[2m=�[0mdefault �[3melapsed_ms�[0m�[2m=�[0m0
�[2m2026-10-05T12:42:34.974005Z�[0m �[32m INFO�[0m �[2minputlayer::protocol::handler�[0m�[2m:�[0m query_parse_complete �[3mprogram_len�[0m�[2m=�[0m35003 �[3mstatements�[0m�[2m=�[0m1 �[3mparse_ms�[0m�[2m=�[0m0
�[2m2026-10-05T12:42:34.996404Z�[0m �[32m INFO�[0m �[2minputlayer::storage_engine::program_commit�[0m�[2m:�[0m program_commit_persisted �[3mkg�[0m�[2m=�[0mdefault �[3mrelations�[0m�[2m=�[0m1 �[3mstatements�[0m�[2m=�[0m1 �[3mtime�[0m�[2m=�[0m4 �[3mpersist_ms�[0m�[2m=�[0m19
�[2m2026-10-05T12:42:34.998190Z�[0m �[32m INFO�[0m �[2minputlayer::storage_engine�[0m�[2m:�[0m snapshot_publish_complete �[3mrelations�[0m�[2m=�[0m1 �[3mrules�[0m�[2m=�[0m0 �[3msnapshot_ms�[0m�[2m=�[0m0
�[2m2026-10-05T12:42:34.998411Z�[0m �[32m INFO�[0m �[2minputlayer::protocol::handler�[0m�[2m:�[0m query_statement_exec_complete �[3mprogram_len�[0m�[2m=�[0m35003 �[3mstmt_exec_ms�[0m�[2m=�[0m24 �[3msession_facts�[0m�[2m=�[0m0 �[3msession_rules�[0m�[2m=�[0m0
�[2m2026-10-05T12:42:34.998446Z�[0m �[32m INFO�[0m �[2minputlayer::protocol::handler�[0m�[2m:�[0m query_job_complete_messages �[3mprogram_len�[0m�

... [96873 bytes truncated] ...

ompute_ms�[0m�[2m=�[0m22 �[3mok�[0m�[2m=�[0mtrue �[2m�[3mrequest_id�[0m�[2m=�[0m4 �[3mmsg_bytes�[0m�[2m=�[0m48�[0m
�[2m2026-10-05T12:43:12.955677Z�[0m �[32m INFO�[0m �[1mws_request�[0m: �[2minputlayer::protocol::rest::handlers::ws::execute�[0m�[2m:�[0m ws_execute_end �[3mprogram_len�[0m�[2m=�[0m7 �[3melapsed_ms�[0m�[2m=�[0m22 �[3mok�[0m�[2m=�[0mfalse �[2m�[3mrequest_id�[0m�[2m=�[0m4 �[3mmsg_bytes�[0m�[2m=�[0m48�[0m
�[2m2026-10-05T12:43:12.956091Z�[0m �[32m INFO�[0m �[1mws_request�[0m: �[2minputlayer::protocol::rest::handlers::ws::execute�[0m�[2m:�[0m ws_execute_start �[3mprogram_len�[0m�[2m=�[0m4 �[3mprogram_preview�[0m�[2m=�[0m-nat �[2m�[3mrequest_id�[0m�[2m=�[0m5 �[3mmsg_bytes�[0m�[2m=�[0m45�[0m
�[2m2026-10-05T12:43:12.956154Z�[0m �[32m INFO�[0m �[2minputlayer::protocol::handler�[0m�[2m:�[0m query_job_start �[3mprogram_len�[0m�[2m=�[0m4
�[2m2026-10-05T12:43:12.956182Z�[0m �[32m INFO�[0m �[2minputlayer::storage_engine�[0m�[2m:�[0m kg_ensure_exists �[3mkg�[0m�[2m=�[0mdefault �[3melapsed_ms�[0m�[2m=�[0m0
�[2m2026-10-05T12:43:12.956189Z�[0m �[32m INFO�[0m �[2minputlayer::protocol::handler�[0m�[2m:�[0m query_parse_complete �[3mprogram_len�[0m�[2m=�[0m4 �[3mstatements�[0m�[2m=�[0m1 �[3mparse_ms�[0m�[2m=�[0m0
�[2m2026-10-05T12:43:12.957447Z�[0m �[32m INFO�[0m �[2minputlayer::storage_engine::program_commit�[0m�[2m:�[0m program_commit_persisted �[3mkg�[0m�[2m=�[0mdefault �[3mrelations�[0m�[2m=�[0m0 �[3mstatements�[0m�[2m=�[0m1 �[3mtime�[0m�[2m=�[0m24 �[3mpersist_ms�[0m�[2m=�[0m1
�[2m2026-10-05T12:43:12.961078Z�[0m �[32m INFO�[0m �[2minputlayer::storage_engine�[0m�[2m:�[0m snapshot_publish_complete �[3mrelations�[0m�[2m=�[0m4 �[3mrules�[0m�[2m=�[0m0 �[3msnapshot_ms�[0m�[2m=�[0m0
�[2m2026-10-05T12:43:12.961105Z�[0m �[32m INFO�[0m �[2minputlayer::protocol::handler�[0m�[2m:�[0m query_statement_exec_complete �[3mprogram_len�[0m�[2m=�[0m4 �[3mstmt_exec_ms�[0m�[2m=�[0m4 �[3msession_facts�[0m�[2m=�[0m0 �[3msession_rules�[0m�[2m=�[0m0
�[2m2026-10-05T12:43:12.961118Z�[0m �[32m INFO�[0m �[2minputlayer::protocol::handler�[0m�[2m:�[0m query_job_complete_messages �[3mprogram_len�[0m�[2m=�[0m4 �[3mtotal_ms�[0m�[2m=�[0m4
�[2m2026-10-05T12:43:12.961170Z�[0m �[32m INFO�[0m �[1mws_request�[0m: �[2minputlayer::protocol::handler�[0m�[2m:�[0m query_complete �[3mprogram_len�[0m�[2m=�[0m4 �[3mcompute_ms�[0m�[2m=�[0m5 �[3mok�[0m�[2m=�[0mtrue �[2m�[3mrequest_id�[0m�[2m=�[0m5 �[3mmsg_bytes�[0m�[2m=�[0m45�[0m
�[2m2026-10-05T12:43:12.961184Z�[0m �[32m INFO�[0m �[1mws_request�[0m: �[2minputlayer::protocol::rest::handlers::ws::execute�[0m�[2m:�[0m ws_execute_end �[3mprogram_len�[0m�[2m=�[0m4 �[3melapsed_ms�[0m�[2m=�[0m5 �[3mok�[0m�[2m=�[0mtrue �[2m�[3mrequest_id�[0m�[2m=�[0m5 �[3mmsg_bytes�[0m�[2m=�[0m45�[0m
�[2m2026-10-05T12:43:12.961484Z�[0m �[32m INFO�[0m �[2minputlayer::protocol::rest::handlers::ws�[0m�[2m:�[0m ws_session_disconnecting �[3mactive_sessions�[0m�[2m=�[0m2
�[2m2026-10-05T12:43:12.961549Z�[0m �[32m INFO�[0m �[1mws_request�[0m: �[2minputlayer::protocol::rest::handlers::ws::execute�[0m�[2m:�[0m ws_execute_start �[3mprogram_len�[0m�[2m=�[0m13 �[3mprogram_preview�[0m�[2m=�[0m?a2(X, 29999) �[2m�[3mrequest_id�[0m�[2m=�[0m3 �[3mmsg_bytes�[0m�[2m=�[0m54�[0m
�[2m2026-10-05T12:43:12.961601Z�[0m �[32m INFO�[0m �[2minputlayer::protocol::handler�[0m�[2m:�[0m query_job_start �[3mprogram_len�[0m�[2m=�[0m13
�[2m2026-10-05T12:43:12.961610Z�[0m �[32m INFO�[0m �[2minputlayer::storage_engine�[0m�[2m:�[0m kg_ensure_exists �[3mkg�[0m�[2m=�[0mdefault �[3melapsed_ms�[0m�[2m=�[0m0
�[2m2026-10-05T12:43:12.961616Z�[0m �[32m INFO�[0m �[2minputlayer::protocol::handler�[0m�[2m:�[0m query_parse_complete �[3mprogram_len�[0m�[2m=�[0m13 �[3mstatements�[0m�[2m=�[0m1 �[3mparse_ms�[0m�[2m=�[0m0
�[2m2026-10-05T12:43:12.961652Z�[0m �[32m INFO�[0m �[2minputlayer�[0m�[2m:�[0m engine_execute_start �[3mrules�[0m�[2m=�[0m1
�[2m2026-10-05T12:43:12.961679Z�[0m �[32m INFO�[0m �[2minputlayer�[0m�[2m:�[0m engine_parse_complete �[3msource_len�[0m�[2m=�[0m1 �[3mparse_ms�[0m�[2m=�[0m0
�[2m2026-10-05T12:43:12.961690Z�[0m �[32m INFO�[0m �[2minputlayer�[0m�[2m:�[0m engine_specialize_complete �[3msource_len�[0m�[2m=�[0m1 �[3mspec_us�[0m�[2m=�[0m7
�[2m2026-10-05T12:43:12.961700Z�[0m �[32m INFO�[0m �[2minputlayer�[0m�[2m:�[0m engine_sip_complete �[3msource_len�[0m�[2m=�[0m1 �[3msip_ms�[0m�[2m=�[0m0
�[2m2026-10-05T12:43:12.961706Z�[0m �[32m INFO�[0m �[2minputlayer�[0m�[2m:�[0m engine_magic_sets_complete �[3msource_len�[0m�[2m=�[0m1 �[3mmagic_ms�[0m�[2m=�[0m0
�[2m2026-10-05T12:43:12.961719Z�[0m �[32m INFO�[0m �[2minputlayer�[0m�[2m:�[0m engine_build_ir_complete �[3msource_len�[0m�[2m=�[0m1 �[3mbuild_ms�[0m�[2m=�[0m0 �[3mir_nodes�[0m�[2m=�[0m1
�[2m2026-10-05T12:43:12.961748Z�[0m �[32m INFO�[0m �[2minputlayer�[0m�[2m:�[0m engine_optimize_complete �[3msource_len�[0m�[2m=�[0m1 �[3mopt_ms�[0m�[2m=�[0m0
�[2m2026-10-05T12:43:12.961758Z�[0m �[32m INFO�[0m �[2minputlayer�[0m�[2m:�[0m engine_shared_views_complete �[3msource_len�[0m�[2m=�[0m1 �[3mshared_ms�[0m�[2m=�[0m0 �[3mshared_views�[0m�[2m=�[0m0
�[2m2026-10-05T12:43:12.962133Z�[0m �[32m INFO�[0m �[2minputlayer�[0m�[2m:�[0m engine_rule_complete �[3msource_len�[0m�[2m=�[0m1 �[3mrule_idx�[0m�[2m=�[0m0 �[3mrule_head�[0m�[2m=�[0m__query__ �[3mrule_ms�[0m�[2m=�[0m0 �[3mrecursive�[0m�[2m=�[0mfalse �[3mworkers�[0m�[2m=�[0m1
�[2m2026-10-05T12:43:12.962146Z�[0m �[32m INFO�[0m �[2minputlayer�[0m�[2m:�[0m engine_execute_complete �[3msource_len�[0m�[2m=�[0m1 �[3mtotal_ms�[0m�[2m=�[0m0
�[2m2026-10-05T12:43:12.962150Z�[0m �[32m INFO�[0m �[2minputlayer::storage_engine::snapshot�[0m�[2m:�[0m snapshot_execute �[3mprogram_len�[0m�[2m=�[0m44 �[3mrules�[0m�[2m=�[0m1 �[3msession_facts�[0m�[2m=�[0m0 �[3melapsed_ms�[0m�[2m=�[0m0
�[2m2026-10-05T12:43:12.962160Z�[0m �[32m INFO�[0m �[2minputlayer::protocol::handler�[0m�[2m:�[0m query_engine_exec_complete �[3mprogram_len�[0m�[2m=�[0m13 �[3mkg�[0m�[2m=�[0mdefault �[3mquery_exec_ms�[0m�[2m=�[0m0 �[3mhas_session_facts�[0m�[2m=�[0mfalse
�[2m2026-10-05T12:43:12.962171Z�[0m �[32m INFO�[0m �[2minputlayer::protocol::handler�[0m�[2m:�[0m query_job_complete �[3mprogram_len�[0m�[2m=�[0m13 �[3mtotal_ms�[0m�[2m=�[0m0 �[3mrow_count�[0m�[2m=�[0m1 �[3mtotal_count�[0m�[2m=�[0m1 �[3mtruncated�[0m�[2m=�[0mfalse
�[2m2026-10-05T12:43:12.962216Z�[0m �[32m INFO�[0m �[1mws_request�[0m: �[2minputlayer::protocol::handler�[0m�[2m:�[0m query_complete �[3mprogram_len�[0m�[2m=�[0m13 �[3mcompute_ms�[0m�[2m=�[0m0 �[3mok�[0m�[2m=�[0mtrue �[2m�[3mrequest_id�[0m�[2m=�[0m3 �[3mmsg_bytes�[0m�[2m=�[0m54�[0m
�[2m2026-10-05T12:43:12.962227Z�[0m �[32m INFO�[0m �[1mws_request�[0m: �[2minputlayer::protocol::rest::handlers::ws::execute�[0m�[2m:�[0m ws_execute_end �[3mprogram_len�[0m�[2m=�[0m13 �[3melapsed_ms�[0m�[2m=�[0m0 �[3mok�[0m�[2m=�[0mtrue �[2m�[3mrequest_id�[0m�[2m=�[0m3 �[3mmsg_bytes�[0m�[2m=�[0m54�[0m
�[2m2026-10-05T12:43:12.962678Z�[0m �[32m INFO�[0m �[2minputlayer::protocol::rest::handlers::ws�[0m�[2m:�[0m ws_session_disconnecting �[3mactive_sessions�[0m�[2m=�[0m1
�[2m2026-10-05T12:43:22.498418Z�[0m �[32m INFO�[0m �[2minputlayer::protocol::rest�[0m�[2m:�[0m Received SIGTERM, shutting down...
�[2m2026-10-05T12:43:22.498540Z�[0m �[32m INFO�[0m �[2minputlayer::protocol::rest�[0m�[2m:�[0m session_reaper_shutdown
�[2m2026-10-05T12:43:22.498577Z�[0m �[32m INFO�[0m �[2minputlayer::protocol::rest�[0m�[2m:�[0m auto_compact_shutdown
�[2m2026-10-05T12:43:22.500220Z�[0m �[32m INFO�[0m �[2minputlayer::storage_engine::program_commit�[0m�[2m:�[0m program_commit_persisted �[3mkg�[0m�[2m=�[0m_internal �[3mrelations�[0m�[2m=�[0m1 �[3mstatements�[0m�[2m=�[0m1 �[3mtime�[0m�[2m=�[0m25 �[3mpersist_ms�[0m�[2m=�[0m1
�[2m2026-10-05T12:43:22.500272Z�[0m �[32m INFO�[0m �[2minputlayer::storage_engine�[0m�[2m:�[0m snapshot_publish_complete �[3mrelations�[0m�[2m=�[0m4 �[3mrules�[0m�[2m=�[0m0 �[3msnapshot_ms�[0m�[2m=�[0m0
�[2m2026-10-05T12:43:22.500292Z�[0m �[32m INFO�[0m �[2minputlayer::protocol::handler�[0m�[2m:�[0m Flushing WAL and saving metadata...
�[2m2026-10-05T12:43:22.541989Z�[0m �[32m INFO�[0m �[2minputlayer::storage_engine�[0m�[2m:�[0m save_metadata_complete �[3melapsed_ms�[0m�[2m=�[0m6
�[2m2026-10-05T12:43:22.542013Z�[0m �[32m INFO�[0m �[2minputlayer::protocol::handler�[0m�[2m:�[0m Shutdown complete.
Evidence: Key runaway outcomes
S4a ?a(X), b(Y) -> resource_exhausted after 8.2s (peak RSS 4647 MiB, 36 MiB 2s later)
S4b two tenants -> both resource_exhausted (max_total_query_memory_bytes), RSS 36 MiB after
S4c timeout_ms 300 -> deadline_exceeded in 302 ms
S4d cancel -> cancelled, cancel_ack outcome=cancelled
S4e disconnect -> RSS 419 MiB -> 37 MiB within 500 ms
Other tenant answered in ~1 ms throughout; oom_kill 0
- Outcome: 🔧 1 issue found ✅ across 2 runs (11m37s)

Pipeline

Updates from git push no-mistakes

✅ **intent** - passed

✅ No issues found.

✅ **Rebase** - passed

✅ No issues found.

⚠️ **Review** - medium risk

✅ No issues found.

✅ No issues found.

🔧 **Test** - 1 issue found ✅
  • ℹ️ docs/content/docs/guides/websocket-api.mdx:140 - The docs say a stopped query 'stops computing within milliseconds'. In a live run with both memory limits off (max_query_memory_bytes=0, max_total_query_memory_bytes=0), the deadline reply for ?a(X), b(Y) arrived at 30.00s, but the computation logged query_stopped_still_running waited_ms=1001 and only exited after 5007 ms, while freeing 19 GB. The error itself is prompt and the memory is released, so this does not violate the intent. With the default memory limits, nothing of this size builds up. The wording overstates exit latency only when the limits are disabled.
  • Live validation: ✅ go - 9 of 9 scenarios driven live against the product
Scenario Result Live Evidence
P0-5: ?a(X), b(Y) over 30k x 30k rows on shipped defaults is refused at once with typed validation, and the server stays alive ✅ pass live live_shipped_defaults.txt: both cross products refused in 0.00s with code validation, the message citing a cross product of about 900000000 rows and max_query_cost; RSS stayed at 63 MB; SERVER_ALIVE
Other tenants and the same connection keep answering after the refusal ✅ pass live live_shipped_defaults.txt: ?t(X) on KG 'other' returned 3 rows; keyed ?a(X), b(X), X < 3 returned 3 rows
Operator F1: filtered cross product with one matching row (?a(7), b(Y); ?a(X), X > 29998, b(Y)) runs under the default max_query_cost ✅ pass live live_shipped_defaults.txt: both returned 30000 rows in about 0.05s
Adversarial: cross products whose filters still keep too many rows are still refused ✅ pass live live_shipped_defaults.txt: ?a(X), X < 20000, b(Y) refused (about 600000000 rows); ?a(X), X > 5, b(Y), Y > 5 refused, both with validation
Adversarial: cross product hidden in a session rule is refused when queried ✅ pass live live_shipped_defaults.txt: rule accepted; ?cross(X, Y) refused with validation
Cost guard disabled: the runaway is stopped by the default memory limits with resource_exhausted, there is no OOM kill, memory is released, and another tenant answers throughout ✅ pass live live_guard_disabled_memory_stop.txt: refused after 7.6s, peak RSS 4189 MB in a 6G cgroup, 37 MB after; oom_kill 0; 8 queries from the other tenant answered in 1 ms each
Client disconnects mid-runaway: the computation stops and its memory is freed ✅ pass live live_client_disconnect.txt: RSS 736 MB at disconnect, 37 MB within 0.5s; other tenant answered; server alive
The default 30 s deadline fires on the runaway even with memory limits off, the error is typed, and memory is released ✅ pass live live_default_deadline.txt: deadline_exceeded at 30.00s; query_stopped_exited exit_ms=5007; RSS fell from 19.4 GB to 40 MB; other tenant answered
Operator F2: recursion that converges is not refused by default (ceiling off), while a configured ceiling refuses unbounded recursion ✅ pass live live_recursion_default_no_ceiling.txt: 100,500-iteration recursion returned its rows in 2.8s; the configured-ceiling case passed in memory_limit_tests::recursion_without_a_bound_stops_at_the_iteration…
  • cargo build --release --bin inputlayer-server (isolated CARGO_TARGET_DIR under /tmp)
  • Live: shipped-defaults server (no config file) in a systemd-run --user --scope -p MemoryMax=6G scope, driven over /ws by a throwaway Python websockets client: ?a(X), b(Y); ?a(X), b(Y), !c(Y); other-KG ?t(X); ?a(X), b(X), X < 3; ?a(7), b(Y); ?a(X), X > 29998, b(Y); ?a(X), X < 20000, b(Y); ?a(X), X > 5, b(Y), Y > 5; session rule cross(X,Y) <- a(X), b(Y) then ?cross(X,Y); converging recursion upto(N) to N < 3000
  • Live: server with INPUTLAYER_STORAGE__PERFORMANCE__MAX_QUERY_COST=0 in 6G cgroup: ?a(X), b(Y) while a second tenant queried every second, RSS sampled, cgroup memory.events checked
  • Live: cost guard and both memory limits off, 6G cgroup: client closes the socket 1 s into ?a(X), b(Y), RSS sampled for 5 s, other tenant queried
  • Live: cost guard and both memory limits off, 60G cgroup: ?a(X), b(Y) under the default 30 s deadline, RSS sampled until memory released, supervise logs captured
  • Live: defaults server, recursion running 100,500 iterations (upto(N) ... N < 100500)
  • cargo test --test memory_limit_tests (12 end-to-end /ws tests, including the new cross-product, filter-aware estimate, memory-stop, deadline-stop and iteration-ceiling tests)

✅ No issues found.

  • Live validation: ✅ go - 11 of 11 scenarios driven live against the product
Scenario Result Live Evidence
On shipped defaults, ?a(X), b(Y) over two 30k-row relations is refused before it runs with a typed validation error, and server memory stays flat ✅ pass live s_defaults.log: validation 'Query too complex ... about 900000000 rows, over the limit of 100000000' in 1 ms; RSS 48 MiB before and after
The same cross product through a persistent rule or a session rule is also refused on defaults ✅ pass live s_rules.log: ?pairs(X,Y) and ?spairs(X,Y) both return code validation; the server keeps serving
Other tenants keep answering while a runaway query is running or being stopped ✅ pass live s_defaults.log, s_runaway.log, s_recursion_defaults.log: point queries from a second connection return in ~1 ms during each runaway
With the cost guard off, the runaway cross product is stopped by the per-query memory limit with resource_exhausted, and memory is released with no OOM kill ✅ pass live s_runaway.log S4a: resource_exhausted after 8.2 s, peak RSS 4.6 GiB, then 36 MiB; cgroup-guardoff.txt: oom_kill 0, peak 5.8 GB under 8 GiB max
Two tenants running the runaway at once are stopped by the total query memory budget detected from the cgroup ✅ pass live s_runaway.log S4b: both get resource_exhausted (max_total_query_memory_bytes), RSS 36 MiB after
The deadline fires on a runaway query (timeout_ms and the default 30 s) with deadline_exceeded ✅ pass live s_runaway.log S4c: deadline_exceeded at 302 ms with timeout_ms 300; s_recursion_defaults.log: default 30 s deadline returns deadline_exceeded at 30002 ms
An explicit cancel stops a running cross product and frees its memory ✅ pass live s_runaway.log S4d: error cancelled, cancel_ack outcome=cancelled, RSS 37 MiB after; server log query_stopped_exited stop=Cancelled exit_ms=76
A client that disconnects mid-runaway has its query's memory freed ✅ pass live s_runaway.log S4e: RSS 419 MiB before the disconnect, 37 MiB 500 ms after
Filter-aware cost (operator decision F1): ?a2(X, 7), b(Y) and ?a2(X, V), V > 29998, b(Y) with one match run under default limits; ?a2(X, V), V < 20000, b(Y) is still refused ✅ pass live s_defaults.log S5a/S5b: 30000 rows each in ~60 ms; S5c: validation at about 600000000 rows; S5d: keyed join runs normally
Recursion ceiling (operator decision F2): off by default, so an unbounded counter is stopped by the deadline; with max_recursion_iterations=1000 set, it is refused with validation ✅ pass live s_recursion_defaults.log: deadline_exceeded with no iteration refusal; s_runaway.log S6b: validation 'did not reach a fixpoint within 1000 iterations'
Regression from the latest commit: the mutual binary paths example returns even_path(X, 4) = (1,4), (2,4), (3,4) through the real client ✅ pass live mutual_paths.out matches examples/iql/09_recursion/31_mutual_binary_paths.iql.out
  • cargo build --release --bin inputlayer-server --bin inputlayer-client
  • Ran start-server.sh defaults: inputlayer-server with shipped defaults in a systemd-run --user --scope -p MemoryMax=8G scope. The startup log shows total_query_memory_bytes detected from the cgroup as 60% of 8 GiB.
  • node load.mjs: loaded a, b and a2 with 30,000 rows each over WebSocket
  • node s_defaults.mjs: P0-5 cartesian query, a second tenant querying at the same time, filtered and comparison cross products (one match vs. 20,000 kept), and a keyed join
  • node s_rules.mjs: cartesian query through a persistent rule and through a session rule
  • node s_recursion.mjs on defaults: unbounded counter with timeout_ms 5000 while another tenant queries, then the default 30 s deadline
  • inputlayer-client ... examples/iql/09_recursion/31_mutual_binary_paths.iql, output diffed against the committed .iql.out
  • Ran start-server.sh guardoff guard-off.toml (max_query_cost=0, max_recursion_iterations=1000) in the same 8 GiB scope
  • node s_runaway.mjs: the query stopped by the per-query memory limit, by the total memory limit with two tenants, by timeout_ms 300, by an explicit cancel, and by a client disconnect. Server RSS was sampled throughout, and the recursion ceiling was checked with it set explicitly.
  • Read the cgroup memory.peak and memory.events (oom/oom_kill), and searched the server log for panics and query_stopped_exited
✅ **Document** - passed

✅ No issues found.

✅ No issues found.

✅ **Lint** - passed

✅ No issues found.

✅ No issues found.

✅ **Push** - passed

✅ No issues found.

✅ No issues found.

@jsam jsam changed the title fix(execution): stop runaway cross-product queries within their limits and release their memory fix: refuse or stop runaway cross-product queries within their limits and release their memory Oct 5, 2026
jsam added 4 commits October 5, 2026 12:29
…away

One cartesian query (?a(X), b(Y) over 30,000 rows each) on shipped defaults
still drove the server to its memory ceiling and was OOM-killed, even with
the per-query memory limit: differential dataflow's join emits every pair a
key matches in one step, a cross product's pairs all share one key, and the
deadline, cancel and memory limit were checked only between steps.

- Joins, result sinks and the antijoin's negated side now check the request
  every 1,024 pairs or rows they form, inside the step: a cross product is
  stopped a few KB past its memory limit (resource_exhausted) or within
  milliseconds of its deadline or cancel. The antijoin sub-dataflow checks
  between its steps too, and a failure there now fails the query instead of
  treating the negated side as empty.
- storage.performance.max_query_cost now estimates rows from relation sizes
  (a join on shared variables as its larger input, a cross product as the
  product of its inputs) and defaults to 100,000,000: an obvious cross
  product is refused with validation before it runs. A startup warning
  names max_query_cost = 0.
- storage.performance.max_recursion_iterations (default 100,000) stops
  recursion that keeps deriving new values, whatever the deadline.
- A graph loaded at startup served its queries before its first write
  without the configured max_query_cost and max_result_rows; its first
  snapshot now carries the limits.
- A stopped computation keeps its compute permit until its thread exits, as
  before; the server now logs when it exits (or that it is still running
  after a second), and a computation that held over 64 MiB returns the
  memory it freed to the operating system, so RSS falls back to baseline.
- The default budget of all queries together now follows the tightest
  cgroup limit on the process, so a systemd unit's MemoryMax= sets it (it
  read only the cgroup root, and found none). A query holding under 1/64 of
  that budget (at most 16 MiB) is no longer stopped when others fill it:
  the queries that filled it are.

Measured on a 6 GB-capped release server: the 30k x 30k cross product is
refused in 1 ms; with max_query_cost = 0 it stops at 4 GiB held (25 KB past
the limit) and RSS returns from 4.8 GB to 53 MB; six at once are each
stopped by the server budget (peak RSS 4.3 GB) while a tenant on another
graph keeps answering in 1-8 ms with no errors; a client disconnect stops
the computation and frees its memory.
…s in this PR's code. **What failed:** the differential oracle check `examples/iql/09_recursion/31_mutual_binary_paths.iql`. In the `recompute` and `subscription` adapters, `?even_path(X, 4)` returned no rows instead of (1,4), (2,4), (3,4). It reproduced locally and passed once the new Distinct pushdown was removed. **Root cause:** this PR added a filter pushdown through `Distinct` in `Optimizer::pushdown_filters`, so filters can now reach the existing Join pushdown code more often. That code moved a right-side predicate by subtracting the number of left columns. It assumed a join row is all left columns followed by all right columns. In fact the engine builds a join row as the left row followed by the right row without its key columns (`left_tuple.concat(right_tuple.excluding_indices(right_keys))` in the code generator, and `build_join` builds the output schema the same way). So in `Join(odd_path(X,Y), edge(Y,Z))` with output [X,Y,Z], the filter `Z = 4` became `edge.col0 (Y) = 4`. **Rule that must hold:** a filter moved below a join must test the same column it tested on the join's output. The left side was already correct, because a join row starts with the full left row. The right side is the only other place this applies, and it is fixed. **Fix (`src/optimizer/mod.rs`):** - A new helper, `right_input_predicate`, maps each join output column to its right-input column, skipping the key columns. It uses the existing `Predicate::adjust_for_projection`, which handles every predicate variant. If a predicate can't be mapped, it stays above the join. - `adjust_predicate_columns` and its six unit tests are removed, since nothing calls it any more. - `test_pushdown_filter_to_right` used a join layout the engine never builds (the key column listed twice). It now uses the real [x,y,z] layout and checks that `z < 100` lands on `s` column 1. The old code would have put it on column 0, so this test would have failed before the fix. **Verified:** the differential oracle test passes (5/5), the optimizer unit tests pass (52), `make unit-test` (`cargo test --workspace --all-features`) exits 0, and `cargo clippy --workspace --all-targets --all-features -- -D warnings` is clean
@jsam
jsam force-pushed the fm/fix-runaway-query branch from 36f0f15 to 803cc6e Compare October 5, 2026 12:44
@jsam
jsam merged commit 0341d8c into main Oct 5, 2026
21 checks passed
@jsam
jsam deleted the fm/fix-runaway-query branch October 5, 2026 12:54
jsam added a commit that referenced this pull request Oct 5, 2026
…saves most of the work (#378) (#385)

* fix(protocol): share keyed subscription families that save most of the work, and judge again as views join (#378)

A family of keyed subscriptions (one bound view per session, `?r1(H_k, Y)`)
shared one evaluation per write only while a round was no slower than the
views' own evaluations run in parallel on the compute permits. That compares
latency on an idle server and ignores the work: with 18 permits a family
accepted up to 18 times the CPU for equal latency, and every own evaluation
holds a permit that writes and reads wait for.

#304 made bound rule reads about five times cheaper (`?r1(400,Y)` at 100k
edges: 6.3 to 1.2 ms). Own evaluations then looked faster in parallel than a
round, so keyed families stopped sharing (logged on main at 1M edges:
`shared_us=85445 own_us=9739 bindings=100 permits=18`), and the backoff after
that verdict outlasted the 1,000 views that joined later. On the views
benchmark a write with 100 keys at 100k edges cost 154 ms of server CPU
instead of 46, and with 1,000 keys at 1M edges 11.9 s and a 643 ms ack
instead of 0.18 s and 3.8 ms.

- A round now also keeps sharing when it does at most half the views' own
  evaluations' combined work.
- A family that stopped sharing probes again as soon as it has twice the
  bindings it had when it stopped, instead of waiting out a backoff that
  grows with the bindings: a verdict reached while the first views
  subscribed no longer holds for the many that follow.

On the benchmark host (servers on 24 CPUs, 18 compute permits) the issue's
case, 1M edges with keyed 1, 10, 100 then 1,000 subscribers, now costs
117 ms of server CPU per write at 1,000 keys, with a 4.0 / 4.3 ms ack
p50/p99 and a 75 / 79 ms delta p50/p99 (main: 11,812 ms, 649 / 687 ms,
689 / 1,212 ms; before #304: 180 ms, 3.8 / 8.3 ms, 75 / 104 ms). At 100 keys
on 100k edges: 17 ms per write (main 154, before #304 46).

* test(perf-gate): gate keyed subscriptions on delta latency and server CPU per write (#378)

`delta_keyed`: 300 agents, each subscribed to its own key `?r1(H_k, Y)` of a
deployed rule over 100K edges; an open-loop writer adds one row to one key
every 20 ms. Every write refreshes all 300 views, which differ only in their
constant, so the engine must evaluate the family once per write rather than
each view's own query. Besides delta and ack latency, the fixture reports
`writes_per_server_cpu_sec`, writes per second of server CPU over the write
phase, which shows lost sharing even on a host idle enough for the deltas
to arrive in time. Its delta p50/p99, ack p99 and CPU rate join the
policy's required set, and the fixture joins the gate's default fixtures.

Six rounds on the benchmark host. Against the commit before #304
(6ac5322), every required metric passes: delta p50 10.5 ms on both, delta
p99 29.7 to 16.6 ms, ack p99 20.3 to 9.6 ms, 2.3 times less server CPU per
write. Against current main the fixture shows the trade the sharing fix
makes, which is accepted: 6 to 8 times less server CPU per write and a
better tail under load (at a write every 10 ms main's delta p99 reaches
51 ms, the fix's stays under 19 ms), for a higher idle delta p50 (5.8 to
10.2 ms), because main evaluates all 300 views in parallel at that CPU cost.

* no-mistakes(review): Cap keyed sharing at twice the parallel own latency

* no-mistakes(document): Clarify share_parameterized config comment; rustfmt keeps_sharing
jsam added a commit that referenced this pull request Oct 6, 2026
…, not after every one (#384)

Recursive reads were 9-20% slower since #304. The bisect blamed the
per-step deadline and memory checks inside recursion, but on the
benchmark host at main they cost nothing (?hot_reach(X,Y) over 100K edges:
275.7 ms with them, 275.1 ms with them stubbed). The cost is the release
of freed memory #304 added: after every computation that peaked over
64 MiB, the server purged the allocator's freed pages on the reply path,
and the next read faulted the same pages back in. With that release
stubbed the same read takes 223.5 ms (-19%), ?path(400,Y) 220.7 ms
instead of 265.4 ms.

The release now waits until no large computation has finished for one
second, then runs once on the blocking pool: a stream of large reads
keeps reusing its pages, and the memory goes back to the operating system
within a second of the last one. The stop guards are untouched, and the
memory a stream holds meanwhile is bounded as before by the limits its
computations ran under; resident memory can stay at the stream's working
size for up to a second longer than before.

The perf gate now has the case: `recursive_query`, `?hot_reach(X, Y)` of
the views benchmark's rules over the delta_keyed graph (100K edges), 25
serial reads per round, judged on p50.
jsam added a commit that referenced this pull request Oct 6, 2026
…, not after every one (#384)

Recursive reads were 9-20% slower since #304. The bisect blamed the
per-step deadline and memory checks inside recursion, but on the
benchmark host at main they cost nothing (?hot_reach(X,Y) over 100K edges:
275.7 ms with them, 275.1 ms with them stubbed). The cost is the release
of freed memory #304 added: after every computation that peaked over
64 MiB, the server purged the allocator's freed pages on the reply path,
and the next read faulted the same pages back in. With that release
stubbed the same read takes 223.5 ms (-19%), ?path(400,Y) 220.7 ms
instead of 265.4 ms.

The release now waits until no large computation has finished for one
second, then runs once on the blocking pool: a stream of large reads
keeps reusing its pages, and the memory goes back to the operating system
within a second of the last one. The stop guards are untouched, and the
memory a stream holds meanwhile is bounded as before by the limits its
computations ran under; resident memory can stay at the stream's working
size for up to a second longer than before.

The perf gate now has the case: `recursive_query`, `?hot_reach(X, Y)` of
the views benchmark's rules over the delta_keyed graph (100K edges), 25
serial reads per round, judged on p50.
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