Skip to content

fix(protocol): judge a keyed subscription family while its views subscribe, so its first write shares one evaluation - #395

Merged
jsam merged 5 commits into
mainfrom
fm/il-383-cold-start
Oct 6, 2026
Merged

jsam merged 5 commits into
mainfrom
fm/il-383-cold-start

Conversation

@jsam

@jsam jsam commented Oct 6, 2026 •

Copy link
Copy Markdown
Contributor

Intent

Fix GitHub issue #383 in inputlayer/inputlayer (production readiness, performance): "Cold-start storm: a new family of 1,000 keyed views evaluates every own query on the first write (~745 ms CPU/write, ack p99 ~690 ms); plan cache (256) thrashes on 1,000 distinct keyed texts".

Found while fixing #378 (report on the benchmark host, ~/bench/fix-keyed-regress). Same on main and the fix. Live views (milestone 9, V11 #318) removes per-view evaluation; until then, consider judging a family before evaluating every own query, and keying the plan cache by lifted text.

Deliver it as a small PR; done means merged with CI green.

Substance of the referenced report (~/bench/fix-keyed-regress on the benchmark host, the views benchmark perf-gate views at 1M edges): with 1,000 keyed subscriptions ?r1(H_k, Y) subscribed as a new family and then written to, the first write evaluates every view's own query, so the keyed phase costs about 740 ms of server CPU per write with an ack p99 of about 680 ms and a write-to-delta p99 of about 750 ms, on both main and the #378 fix (PR #385); ramping the same family up through 1, 10, 100 then 1,000 subscribers instead costs 117 ms per write with a 4.3 ms ack p99. The server log of that run shows most own evaluations compiling their plan (plan_cached=false) because the 1,000 distinct keyed query texts do not fit the 256-plan cache.

What Changed

  • A keyed subscription family now takes a view's first own evaluation as its own cost (that cost already excludes plan compilation), so the sharing probe starts while the views subscribe instead of on the first commit that refreshes them all. Family::record_own no longer skips evaluations that compiled their plan, and the plan_cached field is removed from Evaluated and QueryRows in src/protocol/subscription/reevaluate.rs.
  • A verdict reached while a family is still growing no longer lengthens its retry wait: stopped_at_bindings becomes judged_at_bindings (recorded on every verdict, sharing or not), and stop_sharing counts a failure only when the family has under twice the bindings of the previous verdict. A family with no counted failure since a round last kept sharing probes again after one commit's worth of own evaluations, rather than on every own evaluation.
  • Added unit tests for a family that is judged while subscribing, re-judged at full size, and gaining a view per commit, and updated the standing-query integration test to expect the family to be judged before the first write. The WebSocket guide's bound-constants note (and the regenerated gui/lib/docs-bundle.ts) now says a failed try after the subscriptions doubled does not lengthen the wait.

Risk Assessment

⚠️ Medium: The probe and backoff policy change traces correctly from source (a first evaluation's cost does exclude plan compilation, the doubling rule and one-commit wait behave as the comments and tests say) and I found no new defect, but whether the 1M-edge benchmark actually improves is unmeasured and the operator-accepted limits (a write during the ramp, plan cache thrash) remain.

Testing

Drove the real release inputlayer-server with the repository's perf-gate views benchmark at 1M edges, subscribing 1,000 keyed ?r1(H_k, Y) views as one new family and then writing: once comparing baseline c3d08ae with candidate 51cebe9, and once more on the candidate alone for a second latency sample. Server CPU per write and rule evaluations per write show the fix in both samples; ack p99 shows it in the second sample only, the first being noisy under host load. The targeted keyed-subscription integration tests (5, against a real server over WebSocket) and the protocol::subscription::parameterized unit tests (33, including the growing-family and backoff cases) passed on the target commit; that run was launched by the previous timed-out attempt and finished during this one. The unit tests are in-process and do not count as live validation, so the growing-family re-judging scenario is reported as untested. No UI surface is involved, so there is no visual evidence. Benchmark data directories were removed and the worktree is clean.

  • Live validation: ✅ go - 5 of 7 scenarios driven live against the product
Scenario Result Live Evidence
Subscribe 1,000 keyed views as a new family at 1M edges, then write: each write costs about one shared evaluation of server CPU instead of evaluating every view ✅ pass live rerun-cold-1000-summary.md: P4_r1_keyed_x1000 baseline 1292.0 ms CPU/write and 102.0 rule evaluations/write, candidate 123.0 ms and 2.0. rerun2-cold-1000-candidate-summary.md: 135.5 ms and 2.0.
Same cold family: write ack and write-to-delta latency no longer carry the storm ✅ pass live rerun2-cold-1000-candidate-summary.md: ack p50/p99 6.3/10.2 ms, write-to-delta 101.0/112.6 ms over 20 writes. The first sample (rerun-cold-1000-summary.md) had candidate ack 125.8/331.2 ms under load…
Every one of the 1,000 keyed subscribers still receives its own delta for each write while the family shares one evaluation ✅ pass live Both re-runs: P4_r1_keyed_x1000 has 1001.0 frames/write and 0 late on the candidate; perf-gate exited 0 (it exits 1 if any delta is missing).
Keyed subscribers get only their own rows through mixed writes, and the family is judged before its first write (real server over WebSocket) ✅ pass live targeted-tests.log: standing_query_tests parameterized, 5 passed, including bound_subscriptions_share_one_evaluation_and_get_only_their_rows and every_subscriber_follows_its_own_query_through_mixed_…
Adversarial: sharing switched off, a single-binding family, and results over the row cap still behave as each view's own query does ✅ pass live targeted-tests.log: sharing_can_be_switched_off, a_family_of_one_binding_evaluates_on_its_own, results_over_the_row_cap_fail_as_the_views_own_query_does all ok.
Adversarial: a family too slow to share while small is re-judged as it grows, shares at full size, and a family gaining one view per commit does not probe on every commit ⏸️ untested no The prior payload did not establish a live result: it was covered only by in-process handler unit tests (cargo test --all-features --lib protocol::subscription::parameterized, 33 passed, including a…
Ramping the same family through 1, 10, 100 then 1,000 subscribers stays cheap at 1,000, as it was before the change ⏸️ untested no Not re-driven in this attempt: the previous attempt ran it live on the same commit and binary but then hit the 30-minute budget, so I spent this budget on the cold-start scenario and cite the earlier…
Evidence: Cold 1,000-view family at 1M edges, baseline vs candidate (this attempt)

| phase | subs | ack p50 / p99 ms | write->delta p50 / p99 ms | server CPU ms/write | frames/write | rule evaluations/write | late | |---|---|---|---|---|---|---|---| | baseline c3d08ae5 P4_r1_keyed_x1000 | 1000 | 144.5 / 268.3 | 238.4 / 362.1 | 1292.0 | 1001.0 | 102.0 | 0 | | candidate 51cebe99 P4_r1_keyed_x1000 | 1000 | 125.8 / 331.2 | 249.5 / 425.3 | 123.0 | 1001.0 | 2.0 | 0 | Host load average 17-30 during the run; 10 writes per phase, so p99 is the maximum.

# Views: cost of reads and writes against deployed rules

- baseline: c3d08ae5491824c3b21ba314ec9e38073845c66b (target/perf-gate/servers/c3d08ae5491824c3b21ba314ec9e38073845c66b-8dc912acd5bf/inputlayer-server)
- candidate: 51cebe996cb07dbff7a3dd866f993f94c9aa3b06 (target/release/inputlayer-server)
- host computeinstance-e00w59r9a240k9qz1e (32 CPUs, server CPUs any), load average 17.48 23.60 21.25 5/1287 3191487 -> 29.77 28.37 23.93 16/1410 3352211

## 1000000 edges (baseline)

Load: 1000002 edges, 3334 hot heads in 49865 ms (server CPU 3160 ms), RSS 188 MB. Peak RSS 1235 MB.

Registration: fillers_to_50 2538 ms, hot_reach 12 ms, path 9 ms, path_step 10 ms, r1 10 ms.

| read | rules | rows | p50 / p99 ms | server CPU ms/read | rule evaluations/read | view reads/read |
|---|---|---|---|---|---|---|
| `?edge(400,Y)` | 4 | 1 | 7.2 / 18.4 | 10.0 | 0.0 | 0.0 |
| `?r1(X,Y)` | 4 | 3334 | 66.9 / 80.3 | 70.0 | 1.0 | 0.0 |
| `?r1(400,Y)` | 4 | 1 | 7.6 / 7.9 | 10.0 | 1.0 | 0.0 |
| `?path(400,Y)` | 4 | 3 | 2925.7 / 3056.9 | 2985.0 | 1.0 | 0.0 |
| `?hot_reach(X,Y)` | 4 | 10002 | 3010.8 / 3078.6 | 3045.0 | 1.0 | 0.0 |
| `?hot_reach(400,Y)` | 4 | 3 | 3116.1 / 3193.8 | 3150.0 | 1.0 | 0.0 |
| `?r1(X,Y)` | 54 | 3414 | 72.2 / 72.6 | 75.0 | 1.0 | 0.0 |
| `?r1(400,Y)` | 54 | 6 | 11.6 / 13.7 | 10.0 | 1.0 | 0.0 |

| phase | subs | ack p50 / p99 ms | write->delta p50 / p99 ms | read during p50 ms | server CPU ms/write | frames/write | rule evaluations/write | maintenance us/write | RSS MB | late |
|---|---|---|---|---|---|---|---|---|---|---|
| P0_no_subs | 0 | 1.7 / 6.7 | - | 7.4 | 7.7 | 0.0 | 1.0 | 0.0 | 193 | 0 |
| P1_r1_unbound_x1 | 1 | 2.6 / 3.6 | 72.4 / 74.3 | 11.1 | 82.0 | 2.0 | 2.0 | 0.0 | 199 | 0 |
| P2_r1_unbound_x100 | 100 | 2.6 / 10.4 | 71.8 / 77.4 | 7.7 | 82.0 | 200.0 | 2.0 | 0.0 | 226 | 0 |
| P3_hot_reach_unbound_x1 | 1 | 190.8 / 236.9 | 3368.3 / 3615.5 | 8.2 | 3168.0 | 2.0 | 2.0 | 0.0 | 210 | 0 |
| P4_r1_keyed_x1000 | 1000 | 144.5 / 268.3 | 238.4 / 362.1 | 8.3 | 1292.0 | 1001.0 | 102.0 | 0.0 | 331 | 0 |
| P5_hot_reach_keyed_x1 | 1 | 9.7 / 332.9 | 4326.5 / 5033.8 | 22.3 | 3991.0 | 2.0 | 2.0 | 0.0 | 297 | 0 |
| P6_r1_unbound_x1_rules54 | 1 | 3.2 / 6.8 | 87.4 / 103.8 | 11.0 | 99.0 | 2.0 | 2.0 | 0.0 | 311 | 0 |

Subscribe: 1 x `?r1(X,Y)` 71 ms, 100 x `?r1(X,Y)` 221 ms, 1 x `?hot_reach(X,Y)` 3225 ms, 1000 x `?r1(0,Y)` 2231 ms, 1 x `?hot_reach(0,Y)` 3921 ms, 1 x `?r1(X,Y)` 100 ms.

## 1000000 edges (candidate)

Load: 1000002 edges, 3334 hot heads in 13828 ms (server CPU 2840 ms), RSS 195 MB. Peak RSS 1228 MB.

Registration: fillers_to_50 1160 ms, hot_reach 9 ms, path 7 ms, path_step 8 ms, r1 6 ms.

| read | rules | rows | p50 / p99 ms | server CPU ms/read | rule evaluations/read | view reads/read |
|---|---|---|---|---|---|---|
| `?edge(400,Y)` | 4 | 1 | 7.0 / 7.1 | 10.0 | 0.0 | 0.0 |
| `?r1(X,Y)` | 4 | 3334 | 101.6 / 102.0 | 100.0 | 1.0 | 0.0 |
| `?r1(400,Y)` | 4 | 1 | 11.5 / 11.7 | 10.0 | 1.0 | 0.0 |
| `?path(400,Y)` | 4 | 3 | 3043.7 / 3731.6 | 3315.0 | 1.0 | 0.0 |
| `?hot_reach(X,Y)` | 4 | 10002 | 3395.4 / 3414.1 | 3205.0 | 1.0 | 0.0 |
| `?hot_reach(400,Y)` | 4 | 3 | 4467.0 / 7613.8 | 4115.0 | 1.0 | 0.0 |
| `?r1(X,Y)` | 54 | 3414 | 68.0 / 71.2 | 70.0 | 1.0 | 0.0 |
| `?r1(400,Y)` | 54 | 6 | 8.1 / 11.7 | 10.0 | 1.0 | 0.0 |

| phase | subs | ack p50 / p99 ms | write->delta p50 / p99 ms | read during p50 ms | server CPU ms/write | frames/write | rule evaluations/write | maintenance us/write | RSS MB | late |
|---|---|---|---|---|---|---|---|---|---|---|
| P0_no_subs | 0 | 3.6 / 11.5 | - | 27.7 | 12.3 | 0.0 | 1.0 | 0.0 | 191 | 0 |
| P1_r1_unbound_x1 | 1 | 6.8 / 11.9 | 227.3 / 353.1 | 34.8 | 117.0 | 2.0 | 2.0 | 0.0 | 196 | 0 |
| P2_r1_unbound_x100 | 100 | 8.8 / 12.6 | 159.2 / 249.6 | 32.6 | 121.0 | 200.0 | 2.0 | 0.0 | 209 | 0 |
| P3_hot_reach_unbound_x1 | 1 | 2.5 / 93.2 | 3704.8 / 7282.6 | 12.1 | 3907.0 | 2.0 | 2.0 | 0.0 | 214 | 0 |
| P4_r1_keyed_x1000 | 1000 | 125.8 / 331.2 | 249.5 / 425.3 | 8.3 | 123.0 | 1001.0 | 2.0 | 0.0 | 329 | 0 |
| P5_hot_reach_keyed_x1 | 1 | 3.4 / 139.0 | 3528.8 / 4508.1 | 8.5 | 3588.0 | 2.0 | 2.0 | 0.0 | 327 | 0 |
| P6_r1_unbound_x1_rules54 | 1 | 2.6 / 10.4 | 74.6 / 102.7 | 8.5 | 88.0 | 2.0 | 2.0 | 0.0 | 344 | 0 |

Subscribe: 1 x `?r1(X,Y)` 377 ms, 100 x `?r1(X,Y)` 419 ms, 1 x `?hot_reach(X,Y)` 4794 ms, 1000 x `?r1(0,Y)` 2029 ms, 1 x `?hot_reach(0,Y)` 4326 ms, 1 x `?r1(X,Y)` 72 ms.
Evidence: Cold 1,000-view family, candidate only, second sample (this attempt)

| phase | subs | ack p50 / p99 ms | write->delta p50 / p99 ms | server CPU ms/write | frames/write | rule evaluations/write | late | |---|---|---|---|---|---|---|---| | candidate 51cebe99 P4_r1_keyed_x1000 | 1000 | 6.3 / 10.2 | 101.0 / 112.6 | 135.5 | 1001.0 | 2.0 | 0 | 20 writes; host load average 27-34.

# Views: cost of reads and writes against deployed rules

- candidate: 51cebe996cb07dbff7a3dd866f993f94c9aa3b06 (target/release/inputlayer-server)
- host computeinstance-e00w59r9a240k9qz1e (32 CPUs, server CPUs any), load average 27.13 27.86 23.86 9/1319 3358018 -> 34.64 32.97 26.76 7/1376 3464820

## 1000000 edges (candidate)

Load: 1000002 edges, 3334 hot heads in 3617 ms (server CPU 2490 ms), RSS 191 MB. Peak RSS 1226 MB.

Registration: fillers_to_50 1708 ms, hot_reach 17 ms, path 10 ms, path_step 12 ms, r1 19 ms.

| read | rules | rows | p50 / p99 ms | server CPU ms/read | rule evaluations/read | view reads/read |
|---|---|---|---|---|---|---|
| `?edge(400,Y)` | 4 | 1 | 6.7 / 6.7 | 0.0 | 0.0 | 0.0 |
| `?r1(X,Y)` | 4 | 3334 | 83.2 / 83.2 | 80.0 | 1.0 | 0.0 |
| `?r1(400,Y)` | 4 | 1 | 8.1 / 8.1 | 10.0 | 1.0 | 0.0 |
| `?path(400,Y)` | 4 | 3 | 3004.4 / 3004.4 | 3010.0 | 1.0 | 0.0 |
| `?hot_reach(X,Y)` | 4 | 10002 | 3080.7 / 3080.7 | 3070.0 | 1.0 | 0.0 |
| `?hot_reach(400,Y)` | 4 | 3 | 3019.1 / 3019.1 | 3010.0 | 1.0 | 0.0 |
| `?r1(X,Y)` | 54 | 3464 | 87.3 / 87.3 | 80.0 | 1.0 | 0.0 |
| `?r1(400,Y)` | 54 | 6 | 8.6 / 8.6 | 10.0 | 1.0 | 0.0 |

| phase | subs | ack p50 / p99 ms | write->delta p50 / p99 ms | read during p50 ms | server CPU ms/write | frames/write | rule evaluations/write | maintenance us/write | RSS MB | late |
|---|---|---|---|---|---|---|---|---|---|---|
| P0_no_subs | 0 | 1.5 / 16.3 | - | 6.9 | 7.7 | 0.0 | 1.0 | 0.0 | 186 | 0 |
| P1_r1_unbound_x1 | 1 | 2.0 / 4.5 | 75.9 / 94.0 | 8.3 | 83.0 | 2.0 | 2.0 | 0.0 | 194 | 0 |
| P2_r1_unbound_x100 | 100 | 5.0 / 269.7 | 103.8 / 388.3 | 8.8 | 91.0 | 200.0 | 2.0 | 0.0 | 218 | 0 |
| P3_hot_reach_unbound_x1 | 1 | 3.9 / 190.0 | 4116.1 / 5579.8 | 12.1 | 4164.5 | 2.0 | 2.0 | 0.0 | 212 | 0 |
| P4_r1_keyed_x1000 | 1000 | 6.3 / 10.2 | 101.0 / 112.6 | 11.8 | 135.5 | 1001.0 | 2.0 | 0.0 | 336 | 0 |
| P5_hot_reach_keyed_x1 | 1 | 4.1 / 212.2 | 4154.0 / 5369.1 | 11.7 | 4101.5 | 2.0 | 2.0 | 0.0 | 306 | 0 |
| P6_r1_unbound_x1_rules54 | 1 | 32.2 / 505.0 | 165.3 / 568.2 | 8.3 | 86.0 | 2.0 | 2.0 | 0.0 | 317 | 0 |

Subscribe: 1 x `?r1(X,Y)` 69 ms, 100 x `?r1(X,Y)` 221 ms, 1 x `?hot_reach(X,Y)` 3671 ms, 1000 x `?r1(0,Y)` 1198 ms, 1 x `?hot_reach(0,Y)` 4064 ms, 1 x `?r1(X,Y)` 93 ms.
Evidence: Re-run benchmark logs and raw results
  P0_no_subs: ack p50 1.7 ms, write->delta p50/p99 NaN/NaN ms, read p50 7.4 ms, cpu 7.7 ms/write, 0 late
  P1_r1_unbound_x1: ack p50 2.6 ms, write->delta p50/p99 72.4/74.3 ms, read p50 11.1 ms, cpu 82.0 ms/write, 0 late
  P2_r1_unbound_x100: ack p50 2.6 ms, write->delta p50/p99 71.8/77.4 ms, read p50 7.7 ms, cpu 82.0 ms/write, 0 late
  P3_hot_reach_unbound_x1: ack p50 190.8 ms, write->delta p50/p99 3368.3/3615.5 ms, read p50 8.2 ms, cpu 3168.0 ms/write, 0 late
  P4_r1_keyed_x1000: ack p50 144.5 ms, write->delta p50/p99 238.4/362.1 ms, read p50 8.3 ms, cpu 1292.0 ms/write, 0 late
  P5_hot_reach_keyed_x1: ack p50 9.7 ms, write->delta p50/p99 4326.5/5033.8 ms, read p50 22.3 ms, cpu 3991.0 ms/write, 0 late
  P6_r1_unbound_x1_rules54: ack p50 3.2 ms, write->delta p50/p99 87.4/103.8 ms, read p50 11.0 ms, cpu 99.0 ms/write, 0 late
baseline 1000000 edges: loaded in 49865 ms, 8 reads, 7 phases, peak RSS 1235 MB
  P0_no_subs: ack p50 3.6 ms, write->delta p50/p99 NaN/NaN ms, read p50 27.7 ms, cpu 12.3 ms/write, 0 late
  P1_r1_unbound_x1: ack p50 6.8 ms, write->delta p50/p99 227.3/353.1 ms, read p50 34.8 ms, cpu 117.0 ms/write, 0 late
  P2_r1_unbound_x100: ack p50 8.8 ms, write->delta p50/p99 159.2/249.6 ms, read p50 32.6 ms, cpu 121.0 ms/write, 0 late
  P3_hot_reach_unbound_x1: ack p50 2.5 ms, write->delta p50/p99 3704.8/7282.6 ms, read p50 12.1 ms, cpu 3907.0 ms/write, 0 late
  P4_r1_keyed_x1000: ack p50 125.8 ms, write->delta p50/p99 249.5/425.3 ms, read p50 8.3 ms, cpu 123.0 ms/write, 0 late
  P5_hot_reach_keyed_x1: ack p50 3.4 ms, write->delta p50/p99 3528.8/4508.1 ms, read p50 8.5 ms, cpu 3588.0 ms/write, 0 late
  P6_r1_unbound_x1_rules54: ack p50 2.6 ms, write->delta p50/p99 74.6/102.7 ms, read p50 8.5 ms, cpu 88.0 ms/write, 0 late
candidate 1000000 edges: loaded in 13828 ms, 8 reads, 7 phases, peak RSS 1228 MB
# Views: cost of reads and writes against deployed rules

- baseline: c3d08ae5491824c3b21ba314ec9e38073845c66b (target/perf-gate/servers/c3d08ae5491824c3b21ba314ec9e38073845c66b-8dc912acd5bf/inputlayer-server)
- candidate: 51cebe996cb07dbff7a3dd866f993f94c9aa3b06 (target/release/inputlayer-server)
- host computeinstance-e00w59r9a240k9qz1e (32 CPUs, server CPUs any), load average 17.48 23.60 21.25 5/1287 3191487 -> 29.77 28.37 23.93 16/1410 3352211

## 1000000 edges (baseline)

Load: 1000002 edges, 3334 hot heads in 49865 ms (server CPU 3160 ms), RSS 188 MB. Peak RSS 1235 MB.

Registration: fillers_to_50 2538 ms, hot_reach 12 ms, path 9 ms, path_step 10 ms, r1 10 ms.

| read | rules | rows | p50 / p99 ms | server CPU ms/read | rule evaluations/read | view reads/read |
|---|---|---|---|---|---|---|
| `?edge(400,Y)` | 4 | 1 | 7.2 / 18.4 | 10.0 | 0.0 | 0.0 |
| `?r1(X,Y)` | 4 | 3334 | 66.9 / 80.3 | 70.0 | 1.0 | 0.0 |
| `?r1(400,Y)` | 4 | 1 | 7.6 / 7.9 | 10.0 | 1.0 | 0.0 |
| `?path(400,Y)` | 4 | 3 | 2925.7 / 3056.9 | 2985.0 | 1.0 | 0.0 |
| `?hot_reach(X,Y)` | 4 | 10002 | 3010.8 / 3078.6 | 3045.0 | 1.0 | 0.0 |
| `?hot_reach(400,Y)` | 4 | 3 | 3116.1 / 3193.8 | 3150.0 | 1.0 | 0.0 |
| `?r1(X,Y)` | 54 | 3414 | 72.2 / 72.6 | 75.0 | 1.0 | 0.0 |
| `?r1(400,Y)` | 54 | 6 | 11.6 / 13.7 | 10.0 | 1.0 | 0.0 |

| phase | subs | ack p50 / p99 ms | write->delta p50 / p99 ms | read during p50 ms | server CPU ms/write | frames/write | rule evaluations/write | maintenance us/write | RSS MB | late |
|---|---|---|---|---|---|---|---|---|---|---|
| P0_no_subs | 0 | 1.7 / 6.7 | - | 7.4 | 7.7 | 0.0 | 1.0 | 0.0 | 193 | 0 |
| P1_r1_unbound_x1 | 1 | 2.6 / 3.6 | 72.4 / 74.3 | 11.1 | 82.0 | 2.0 | 2.0 | 0.0 | 199 | 0 |
| P2_r1_unbound_x100 | 100 | 2.6 / 10.4 | 71.8 / 77.4 | 7.7 | 82.0 | 200.0 | 2.0 | 0.0 | 226 | 0 |
| P3_hot_reach_unbound_x1 | 1 | 190.8 / 236.9 | 3368.3 / 3615.5 | 8.2 | 3168.0 | 2.0 | 2.0 | 0.0 | 210 | 0 |
| P4_r1_keyed_x1000 | 1000 | 144.5 / 268.3 | 238.4 / 362.1 | 8.3 | 1292.0 | 1001.0 | 102.0 | 0.0 | 331 | 0 |
| P5_hot_reach_keyed_x1 | 1 | 9.7 / 332.9 | 4326.5 / 5033.8 | 22.3 | 3991.0 | 2.0 | 2.0 | 0.0 | 297 | 0 |
| P6_r1_unbound_x1_rules54 | 1 | 3.2 / 6.8 | 87.4 / 103.8 | 11.0 | 99.0 | 2.0 | 2.0 | 0.0 | 311 | 0 |

Subscribe: 1 x `?r1(X,Y)` 71 ms, 100 x `?r1(X,Y)` 221 ms, 1 x `?hot_reach(X,Y)` 3225 ms, 1000 x `?r1(0,Y)` 2231 ms, 1 x `?hot_reach(0,Y)` 3921 ms, 1 x `?r1(X,Y)` 100 ms.

## 1000000 edges (candidate)

Load: 1000002 edges, 3334 hot heads in 13828 ms (server CPU 2840 ms), RSS 195 MB. Peak RSS 1228 MB.

Registration: fillers_to_50 1160 ms, hot_reach 9 ms, path 7 ms, path_step 8 ms, r1 6 ms.

| read | rules | rows | p50 / p99 ms | server CPU ms/read | rule evaluations/read | view reads/read |
|---|---|---|---|---|---|---|
| `?edge(400,Y)` | 4 | 1 | 7.0 / 7.1 | 10.0 | 0.0 | 0.0 |
| `?r1(X,Y)` | 4 | 3334 | 101.6 / 102.0 | 100.0 | 1.0 | 0.0 |
| `?r1(400,Y)` | 4 | 1 | 11.5 / 11.7 | 10.0 | 1.0 | 0.0 |
| `?path(400,Y)` | 4 | 3 | 3043.7 / 3731.6 | 3315.0 | 1.0 | 0.0 |
| `?hot_reach(X,Y)` | 4 | 10002 | 3395.4 / 3414.1 | 3205.0 | 1.0 | 0.0 |
| `?hot_reach(400,Y)` | 4 | 3 | 4467.0 / 7613.8 | 4115.0 | 1.0 | 0.0 |
| `?r1(X,Y)` | 54 | 3414 | 68.0 / 71.2 | 70.0 | 1.0 | 0.0 |
| `?r1(400,Y)` | 54 | 6 | 8.1 / 11.7 | 10.0 | 1.0 | 0.0 |

| phase | subs | ack p50 / p99 ms | write->delta p50 / p99 ms | read during p50 ms | server CPU ms/write | frames/write | rule evaluations/write | maintenance us/write | RSS MB | late |
|---|---|---|---|---|---|---|---|---|---|---|
| P0_no_subs | 0 | 3.6 / 11.5 | - | 27.7 | 12.3 | 0.0 | 1.0 | 0.0 | 191 | 0 |
| P1_r1_unbound_x1 | 1 | 6.8 / 11.9 | 227.3 / 353.1 | 34.8 | 117.0 | 2.0 | 2.0 | 0.0 | 196 | 0 |
| P2_r1_unbound_x100 | 100 | 8.8 / 12.6 | 159.2 / 249.6 | 32.6 | 121.0 | 200.0 | 2.0 | 0.0 | 209 | 0 |
| P3_hot_reach_unbound_x1 | 1 | 2.5 / 93.2 | 3704.8 / 7282.6 | 12.1 | 3907.0 | 2.0 | 2.0 | 0.0 | 214 | 0 |
| P4_r1_keyed_x1000 | 1000 | 125.8 / 331.2 | 249.5 / 425.3 | 8.3 | 123.0 | 1001.0 | 2.0 | 0.0 | 329 | 0 |
| P5_hot_reach_keyed_x1 | 1 | 3.4 / 139.0 | 3528.8 / 4508.1 | 8.5 | 3588.0 | 2.0 | 2.0 | 0.0 | 327 | 0 |
| P6_r1_unbound_x1_rules54 | 1 | 2.6 / 10.4 | 74.6 / 102.7 | 8.5 | 88.0 | 2.0 | 2.0 | 0.0 | 344 | 0 |

Subscribe: 1 x `?r1(X,Y)` 377 ms, 100 x `?r1(X,Y)` 419 ms, 1 x `?hot_reach(X,Y)` 4794 ms, 1000 x `?r1(0,Y)` 2029 ms, 1 x `?hot_reach(0,Y)` 4326 ms, 1 x `?r1(X,Y)` 72 ms.

result file: ~/.no-mistakes/evidence/01M47ATDCGNKDHA3TX4N287PH6/rerun-cold-1000-result.json
exit=0
Evidence: Raw result JSON, baseline vs candidate re-run
{"schema":"inputlayer-perf-gate/views/v1","created_unix":1791265358,"environment":{"hostname":"computeinstance-e00w59r9a240k9qz1e","kernel":"6.11.0-1016-nvidia","cpu_model":"AMD EPYC-Genoa Processor","logical_cpus":32,"mem_total_kb":131897740,"cpu_governor":"unknown","loadavg_start":"17.48 23.60 21.25 5/1287 3191487","loadavg_end":"29.77 28.37 23.93 16/1410 3352211","data_fs":"ext4","data_root":"~/.no-mistakes/worktrees/9eaf1dfa27af/01M47ATDCGNKDHA3TX4N287PH6/target/bench-views/runs/rerun-cold/servers","server_cpus":null,"build":""},"options":{"writes":30,"large_writes":10,"reads":2,"keyed":[1000],"recursive_keyed":[1,100],"large_recursive_keyed":[1],"filler_rules":[50]},"arms":[["baseline","c3d08ae5491824c3b21ba314ec9e38073845c66b (target/perf-gate/servers/c3d08ae5491824c3b21ba314ec9e38073845c66b-8dc912acd5bf/inputlayer-server)"],["candidate","51cebe996cb07dbff7a3dd866f993f94c9aa3b06 (target/release/inputlayer-server)"]],"server_overrides":{"INPUTLAYER_HTTP__GUI__ENABLED":"false (the GUI is not under test)","INPUTLAYER_HTTP__RATE_LIMIT__PER_IP_MAX_RPS":"0 (every gate client shares one loopback IP)","INPUTLAYER_HTTP__RATE_LIMIT__WS_MAX_MESSAGES_PER_SEC":"0 (per-connection message cap would bound the measured throughput)"},"server_env":["INPUTLAYER_HTTP__RATE_LIMIT__WS_MAX_PREAUTH_PER_IP=0","INPUTLAYER_HTTP__RATE_LIMIT__MAX_WS_CONNECTIONS=5000","INPUTLAYER_HTTP__RATE_LIMIT__MAX_CONNECTIONS=5000"],"runs":[{"arm":"baseline","edges":1000000,"load":{"edges":1000002,"hot_heads":3334,"ms":49865.284676999996,"server_cpu_ms":3160.0,"rss_mb":188},"registration_ms":{"fillers_to_50":2537.950157,"hot_reach":11.571821,"path":8.862617,"path_step":10.163477,"r1":10.376342000000001},"reads":[{"name":"edge_point","query":"?edge(400,Y)","rules":4,"rows":1,"truncated":false,"latency_ms":{"n":2,"p50":7.218846,"p95":18.374294,"p99":18.374294,"max":18.374294},"server_cpu_ms":10.000000000000009,"work":{"rule_evaluations":0.0,"view_reads":0.0,"view_maintenance_us":0.0}},{"name":"r1_unbound","query":"?r1(X,Y)","rules":4,"rows":3334,"truncated":false,"latency_ms":{"n":2,"p50":66.894986,"p95":80.32260099999999,"p99":80.32260099999999,"max":80.32260099999999},"server_cpu_ms":70.00000000000006,"work":{"rule_evaluations":1.0,"view_reads":0.0,"view_maintenance_us":0.0}},{"name":"r1_bound","query":"?r1(400,Y)","rules":4,"rows":1,"truncated":false,"latency_ms":{"n":2,"p50":7.635991,"p95":7.85173,"p99":7.85173,"max":7.85173},"server_cpu_ms":10.000000000000009,"work":{"rule_evaluations":1.0,"view_reads":0.0,"view_maintenance_us":0.0}},{"name":"path_bound","query":"?path(400,Y)","rules":4,"rows":3,"truncated":false,"latency_ms":{"n":2,"p50":2925.739109,"p95":3056.875958,"p99":3056.875958,"max":3056.875958},"server_cpu_ms":2985.0000000000005,"work":{"rule_evaluations":1.0,"view_reads":0.0,"view_maintenance_us":0.0}},{"name":"hot_reach_unbound","query":"?hot_reach(X,Y)","rules":4,"rows":10002,"truncated":false,"latency_ms":{"n":2,"p50":3010.803368,"p95":3078.605325,"p99":3078.605325,"max":3078.605325},"server_cpu_ms":3045.0,"work":{"rule_evaluations":1.0,"view_reads":0.0,"view_maintenance_us":0.0}},{"name":"hot_reach_bound","query":"?hot_reach(400,Y)","rules":4,"rows":3,"truncated":false,"latency_ms":{"n":2,"p50":3116.051422,"p95":3193.803779,"p99":3193.803779,"max":3193.803779},"server_cpu_ms":3149.9999999999995,"work":{"rule_evaluations":1.0,"view_reads":0.0,"view_maintenance_us":0.0}},{"name":"r1_unbound_rules54","query":"?r1(X,Y)","rules":54,"rows":3414,"truncated":false,"latency_ms":{"n":2,"p50":72.15801900000001,"p95":72.584808,"p99":72.584808,"max":72.584808},"server_cpu_ms":75.00000000000284,"work":{"rule_evaluations":1.0,"view_reads":0.0,"view_maintenance_us":0.0}},{"name":"r1_bound_rules54","query":"?r1(400,Y)","rules":54,"rows":6,"truncated":false,"latency_ms":{"n":2,"p50":11.598931,"p95":13.713769000000001,"p99":13.713769000000001,"max":13.713769000000001},"server_cpu_ms":10.000000000005116,"work":{"rule_evaluations":1.0,"view_reads":0.0,"view_maintenance_us":0.0}}],"phases":[{"name":"P0_no_subs","subscribers":0,"rules":4,"writes":30,"ack_ms":{"n":30,"p50":1.719066,"p95":2.1656050000000002,"p99":6.713946999999999,"max":6.713946999999999},"write_to_delta_ms":{"n":0,"p50":null,"p95":null,"p99":null,"max":null},"read_during_ms":{"n":30,"p50":7.391799,"p95":7.644363,"p99":8.402166000000001,"max":8.402166000000001},"late":0,"subscription_errors":0,"server_cpu_ms_per_write":7.666666666666681,"frames_per_write":0.0,"work_per_write":{"rule_evaluations":1.0,"view_reads":0.0,"view_maintenance_us":0.0},"rss_mb":193},{"name":"P1_r1_unbound_x1","subscribers":1,"rules":4,"writes":10,"ack_ms":{"n":10,"p50":2.583642,"p95":3.5917060000000003,"p99":3.5917060000000003,"max":3.5917060000000003},"write_to_delta_ms":{"n":10,"p50":72.437221,"p95":74.266174,"p99":74.266174,"max":74.266174},"read_during_ms":{"n":10,"p50":11.083907,"p95":11.911255,"p99":11.911255,"max":11.911255},"late":0,"subscription_errors":0,"server_cpu_ms_per_write":82.00000000000003,"frames_per_write":2.0,"work_per_write":{"rule_evaluations":2.0,"view_reads":0.0,"view_maintenance_us":0.0},"rss_mb":199},{"name":"P2_r1_unbound_x100","subscribers":100,"rules":4,"writes":10,"ack_ms":{"n":10,"p50":2.620678,"p95":10.411784,"p99":10.411784,"max":10.411784},"write_to_delta_ms":{"n":10,"p50":71.805109,"p95":77.357939,"p99":77.357939,"max":77.357939},"read_during_ms":{"n":10,"p50":7.743193,"p95":8.053455,"p99":8.053455,"max":8.053455},"late":0,"subscription_errors":0,"server_cpu_ms_per_write":82.00000000000003,"frames_per_write":200.0,"work_per_write":{"rule_evaluations":2.0,"view_reads":0.0,"view_maintenance_us":0.0},"rss_mb":226},{"name":"P3_hot_reach_unbound_x1","subscribers":1,"rules":4,"writes":10,"ack_ms":{"n":10,"p50":190.792225,"p95":236.85193199999998,"p99":236.85193199999998,"max":236.85193199999998},"write_to_delta_ms":{"n":10,"p50":3368.3353399999996,"p95":3615.458832,"p99":3615.458832,"max":3615.458832},"read_during_ms":{"n":10,"p50":8.235793,"p95":12.220908000000001,"p99":12.220908000000001,"max":12.220908000000001},"late":0,"subscription_errors":0,"server_cpu_ms_per_write":3168.0000000000005,"frames_per_write":2.0,"work_per_write":{"rule_evaluations":2.0,"view_reads":0.0,"view_maintenance_us":0.0},"rss_mb":210},{"name":"P4_r1_keyed_x1000","subscribers":1000,"rules":4,"writes":10,"ack_ms":{"n":10,"p50":144.488429,"p95":268.296279,"p99":268.296279,"max":268.296279},"write_to_delta_ms":{"n":10,"p50":238.366898,"p95":362.117397,"p99":362.117397,"max":362.117397},"read_during_ms":{"n":10,"p50":8.339401,"p95":1031.765978,"p99":1031.765978,"max":1031.765978},"late":0,"subscription_errors":0,"server_cpu_ms_per_write":1292.0000000000002,"frames_per_write":1001.0,"work_per_write":{"rule_evaluations":102.0,"view_reads":0.0,"view_maintenance_us":0.0},"rss_mb":331},{"name":"P5_hot_reach_keyed_x1","subscribers":1,"rules":4,"writes":10,"ack_ms":{"n":10,"p50":9.721413,"p95":332.94797900000003,"p99":332.94797900000003,"max":332.94797900000003},"write_to_delta_ms":{"n":10,"p50":4326.523086,"p95":5033.821373000001,"p99":5033.821373000001,"max":5033.821373000001},"read_during_ms":{"n":10,"p50":22.250269,"p95":70.032568,"p99":70.032568,"max":70.032568},"late":0,"subscription_errors":0,"server_cpu_ms_per_write":3991.0,"frames_per_write":2.0,"work_per_write":{"rule_evaluations":2.0,"view_reads":0.0,"view_maintenance_us":0.0},"rss_mb":297},{"name":"P6_r1_unbound_x1_rules54","subscribers":1,"rules":54,"writes":10,"ack_ms":{"n":10,"p50":3.2232250000000002,"p95":6.761279,"p99":6.761279,"max":6.761279},"write_to_delta_ms":{"n":10,"p50":87.37967300000001,"p95":103.80433699999999,"p99":103.80433699999999,"max":103.80433699999999},"read_during_ms":{"n":10,"p50":11.015624,"p95":13.811518999999999,"p99":13.811518999999999,"max":13.811518999999999},"late":0,"subscription_errors":0,"server_cpu_ms_per_write":99.00000000000091,"frames_per_write":2.0,"work_per_write":{"rule_evaluations":2.0,"view_reads":0.0,"view_maintenance_us":0.0},"rss_mb":311}],"subscribes":[{"query":"?r1(X,Y)","count":1,"ms":70.667117},{"query":"?r1(X,Y)","count":100,"ms":221.425522},{"query":"?hot_reach(X,Y)","count":1,"ms":3224.555171},{"query":"?r1(0,Y)","count":1000,"ms":2231.096552},{"query":"?hot_reach(0,Y)","count":1,"ms":3921.2850059999996},{"query":"?r1(X,Y)","count":1,"ms":100.309799}],"notes":[],"peak_rss_kb":1265500,"error":null},{"arm":"candidate","edges":1000000,"load":{"edges":1000002,"hot_heads":3334,"ms":13828.466339,"server_cpu_ms":2840.0,"rss_mb":195},"registration_ms":{"fillers_to_50":1159.92681,"hot_reach":9.39736,"path":7.012601,"path_step":7.9936039999999995,"r1":6.375191},"reads":[{"name":"edge_point","query":"?edge(400,Y)","rules":4,"rows":1,"truncated":false,"latency_ms":{"n":2,"p50":6.971148,"p95":7.132034,"p99":7.132034,"max":7.132034},"server_cpu_ms":10.000000000000009,"work":{"rule_evaluations":0.0,"view_reads":0.0,"view_maintenance_us":0.0}},{"name":"r1_unbound","query":"?r1(X,Y)","rules":4,"rows":3334,"truncated":false,"latency_ms":{"n":2,"p50":101.628986,"p95":101.955664,"p99":101.955664,"max":101.955664},"server_cpu_ms":99.99999999999987,"work":{"rule_evaluations":1.0,"view_reads":0.0,"view_maintenance_us":0.0}},{"name":"r1_bound","query":"?r1(400,Y)","rules":4,"rows":1,"truncated":false,"latency_ms":{"n":2,"p50":11.458537,"p95":11.730440999999999,"p99":11.730440999999999,"max":11.730440999999999},"server_cpu_ms":10.000000000000009,"work":{"rule_evaluations":1.0,"view_reads":0.0,"view_maintenance_us":0.0}},{"name":"path_bound","query":"?path(400,Y)","rules":4,"rows":3,"truncated":false,"latency_ms":{"n":2,"p50":3043.738109,"p95":3731.596416,"p99":3731.596416,"max":3731.596416},"server_cpu_ms":3315.0000000000005,"work":{"rule_evaluations":1.0,"view_reads":0.0,"view_maintenance_us":0.0}},{"name":"hot_reach_unbound","query":"?hot_reach(X,Y)","rules":4,"rows":10002,"truncated":false,"latency_ms":{"n":2,"p50":3395.408357,"p95":3414.064175,"p99":3414.064175,"max":3414.064175},"server_cpu_ms":3205.0,"work":{"rule_evaluations":1.0,"view_reads":0.0,"view_maintenance_us":0.0}},{"name":"hot_reach_bound","query":"?hot_reach(400,Y)","rules":4,"rows":3,"truncated":false,"latency_ms":{"n":2,"p50":4466.962324,"p95":7613.780228,"p99":7613.780228,"max":7613.780228},"server_cpu_ms":4115.0,"work":{"rule_evaluations":1.0,"view_reads":0.0,"view_maintenance_us":0.0}},{"name":"r1_unbound_rules54","query":"?r1(X,Y)","rules":54,"rows":3414,"truncated":false,"latency_ms":{"n":2,"p50":68.042085,"p95":71.24908400000001,"p99":71.24908400000001,"max":71.24908400000001},"server_cpu_ms":70.00000000000028,"work":{"rule_evaluations":1.0,"view_reads":0.0,"view_maintenance_us":0.0}},{"name":"r1_bound_rules54","query":"?r1(400,Y)","rules":54,"rows":6,"truncated":false,"latency_ms":{"n":2,"p50":8.071351,"p95":11.717039,"p99":11.717039,"max":11.717039},"server_cpu_ms":9.99999999999801,"work":{"rule_evaluations":1.0,"view_reads":0.0,"view_maintenance_us":0.0}}],"phases":[{"name":"P0_no_subs","subscribers":0,"rules":4,"writes":30,"ack_ms":{"n":30,"p50":3.557433,"p95":11.202696,"p99":11.522514,"max":11.522514},"write_to_delta_ms":{"n":0,"p50":null,"p95":null,"p99":null,"max":null},"read_during_ms":{"n":30,"p50":27.652838,"p95":52.449200000000005,"p99":61.721118999999995,"max":61.721118999999995},"late":0,"subscription_errors":0,"server_cpu_ms_per_write":12.333333333333368,"frames_per_write":0.0,"work_per_write":{"rule_evaluations":1.0,"view_reads":0.0,"view_maintenance_us":0.0},"rss_mb":191},{"name":"P1_r1_unbound_x1","subscribers":1,"rules":4,"writes":10,"ack_ms":{"n":10,"p50":6.767238,"p95":11.939366999999999,"p99":11.939366999999999,"max":11.939366999999999},"write_to_delta_ms":{"n":10,"p50":227.31159100000002,"p95":353.145669,"p99":353.145669,"max":353.145669},"read_during_ms":{"n":10,"p50":34.81029,"p95":51.021598000000004,"p99":51.021598000000004,"max":51.021598000000004},"late":0,"subscription_errors":0,"server_cpu_ms_per_write":116.99999999999982,"frames_per_write":2.0,"work_per_write":{"rule_evaluations":2.0,"view_reads":0.0,"view_maintenance_us":0.0},"rss_mb":196},{"name":"P2_r1_unbound_x100","subscribers":100,"rules":4,"writes":10,"ack_ms":{"n":10,"p50":8.844319,"p95":12.63649,"p99":12.63649,"max":12.63649},"write_to_delta_ms":{"n":10,"p50":159.23668899999998,"p95":249.618699,"p99":249.618699,"max":249.618699},"read_during_ms":{"n":10,"p50":32.582451999999996,"p95":45.104988,"p99":45.104988,"max":45.104988},"late":0,"subscription_errors":0,"server_cpu_ms_per_write":121.00000000000009,"frames_per_write":200.0,"work_per_write":{"rule_evaluations":2.0,"view_reads":0.0,"view_maintenance_us":0.0},"rss_mb":209},{"name":"P3_hot_reach_unbound_x1","subscribers":1,"rules":4,"writes":10,"ack_ms":{"n":10,"p50":2.478622,"p95":93.224645,"p99":93.224645,"max":93.224645},"write_to_delta_ms":{"n":10,"p50":3704.773805,"p95":7282.6058299999995,"p99":7282.6058299999995,"max":7282.6058299999995},"read_during_ms":{"n":10,"p50":12.110219,"p95":31.375715999999997,"p99":31.375715999999997,"max":31.375715999999997},"late":0,"subscription_errors":0,"server_cpu_ms_per_write":3906.999999999999,"frames_per_write":2.0,"work_per_write":{"rule_evaluations":2.0,"view_reads":0.0,"view_maintenance_us":0.0},"rss_mb":214},{"name":"P4_r1_keyed_x1000","subscribers":1000,"rules":4,"writes":10,"ack_ms":{"n":10,"p50":125.807945,"p95":331.213741,"p99":331.213741,"max":331.213741},"write_to_delta_ms":{"n":10,"p50":249.48200400000002,"p95":425.31491,"p99":425.31491,"max":425.31491},"read_during_ms":{"n":10,"p50":8.318508000000001,"p95":11.029542999999999,"p99":11.029542999999999,"max":11.029542999999999},"late":0,"subscription_errors":0,"server_cpu_ms_per_write":123.00000000000041,"frames_per_write":1001.0,"work_per_write":{"rule_evaluations":2.0,"view_reads":0.0,"view_maintenance_us":0.0},"rss_mb":329},{"name":"P5_hot_reach_keyed_x1","subscribers":1,"rules":4,"writes":10,"ack_ms":{"n":10,"p50":3.383398,"p95":138.983529,"p99":138.983529,"max":138.983529},"write_to_delta_ms":{"n":10,"p50":3528.771212,"p95":4508.071922,"p99":4508.071922,"max":4508.071922},"read_during_ms":{"n":10,"p50":8.541347,"p95":13.417997,"p99":13.417997,"max":13.417997},"late":0,"subscription_errors":0,"server_cpu_ms_per_write":3587.999999999999,"frames_per_write":2.0,"work_per_write":{"rule_evaluations":2.0,"view_reads":0.0,"view_maintenance_us":0.0},"rss_mb":327},{"name":"P6_r1_unbound_x1_rules54","subscribers":1,"rules":54,"writes":10,"ack_ms":{"n":10,"p50":2.607628,"p95":10.428738,"p99":10.428738,"max":10.428738},"write_to_delta_ms":{"n":10,"p50":74.597579,"p95":102.718268,"p99":102.718268,"max":102.718268},"read_during_ms":{"n":10,"p50":8.530911,"p95":11.808518000000001,"p99":11.808518000000001,"max":11.808518000000001},"late":0,"subscription_errors":0,"server_cpu_ms_per_write":88.00000000000097,"frames_per_write":2.0,"work_per_write":{"rule_evaluations":2.0,"view_reads":0.0,"view_maintenance_us":0.0},"rss_mb":344}],"subscribes":[{"query":"?r1(X,Y)","count":1,"ms":377.343741},{"query":"?r1(X,Y)","count":100,"ms":419.039535},{"query":"?hot_reach(X,Y)","count":1,"ms":4793.690914},{"query":"?r1(0,Y)","count":1000,"ms":2029.020173},{"query":"?hot_reach(0,Y)","count":1,"ms":4326.138264},{"query":"?r1(X,Y)","count":1,"ms":71.980787}],"notes":[],"peak_rss_kb":1258116,"error":null}]}
Evidence: Targeted keyed-subscription tests on 51cebe9
   Compiling inputlayer-ws-protocol v0.1.0 (~/.no-mistakes/worktrees/9eaf1dfa27af/01M47ATDCGNKDHA3TX4N287PH6/ws-protocol)
   Compiling inputlayer-ontology-client v0.1.0 (~/.no-mistakes/worktrees/9eaf1dfa27af/01M47ATDCGNKDHA3TX4N287PH6/ontology-client)
   Compiling inputlayer-testkit v0.1.0 (~/.no-mistakes/worktrees/9eaf1dfa27af/01M47ATDCGNKDHA3TX4N287PH6/testkit)
   Compiling inputlayer v0.1.0 (~/.no-mistakes/worktrees/9eaf1dfa27af/01M47ATDCGNKDHA3TX4N287PH6)
    Finished `test` profile [unoptimized + debuginfo] target(s) in 1m 38s
     Running tests/standing_query_tests/main.rs (target/debug/deps/standing_query_tests-055b42820ab2326b)

running 5 tests
test parameterized::results_over_the_row_cap_fail_as_the_views_own_query_does ... ok
test parameterized::sharing_can_be_switched_off ... ok
test parameterized::a_family_of_one_binding_evaluates_on_its_own ... ok
test parameterized::bound_subscriptions_share_one_evaluation_and_get_only_their_rows ... ok
test parameterized::every_subscriber_follows_its_own_query_through_mixed_writes ... ok

test result: ok. 5 passed; 0 failed; 0 ignored; 0 measured; 37 filtered out; finished in 23.45s

test protocol::subscription::parameterized::tests::probes_wait_a_number_of_commits_that_doubles_with_each_failed_probe ... ok
test protocol::subscription::parameterized::tests::rounds::a_family_gaining_a_view_per_commit_does_not_probe_on_every_commit ... ok
test protocol::subscription::parameterized::tests::rounds::a_family_judged_while_views_subscribe_probes_again_once_its_bindings_double ... ok
test protocol::subscription::parameterized::tests::rounds::a_family_judged_while_its_views_subscribe_shares_its_first_commit ... ok
test protocol::subscription::parameterized::tests::rounds::a_family_too_slow_to_share_while_its_views_subscribe_shares_at_full_size ... ok
test protocol::subscription::parameterized::tests::rounds::failures_while_a_family_grows_do_not_lengthen_its_wait ... ok
test result: ok. 33 passed; 0 failed; 0 ignored; 0 measured; 3332 filtered out; finished in 11.08s
  • Evidence: Earlier attempt, same commit: cold 1,000 baseline vs candidate (local file: ~/.no-mistakes/evidence/01M47ATDCGNKDHA3TX4N287PH6/views-cold-1000-summary.md)
  • Evidence: Earlier attempt, same commit: ramp 1/10/100/1,000 baseline vs candidate (local file: ~/.no-mistakes/evidence/01M47ATDCGNKDHA3TX4N287PH6/views-ramp-compare-summary.md)
  • Outcome: ⚠️ 1 info across 3 runs (1h6m5s)

Scope, measurements and known limits

Part of #383: this PR addresses the first half only, the cold-start storm, not the plan cache (MAX_CACHED_PLANS = 256, keyed by query text; a lifted-text key needs parameterised plans). Benchmark host, bench-views.sh --edges 1000000 --keyed 1000, 1,000 keyed views as a new family then 20 writes: main a649cd9 663.5 ms server CPU/write, ack p99 598.2 ms, 52 rule evaluations/write; this PR 108.0 ms, 4.1 ms, 2.0. Remaining plan-cache work: a family of more than 256 views still recompiles most plans on writes where its views evaluate their own queries: (1) after a failed probe, until it probes again; (2) when a parameter binds a recursive relation, never shared by design; (3) on the first write after a rule change. Known limit: a failed verdict is uncounted only while bindings have at least doubled since the previous verdict; a write landing mid-ramp before that counts its failure, and the family then waits the normal 256 writes to be judged again at its settled size, as main did for a family judged on its first write. Perf gate: all required metrics PASS except cheap_query.queries_per_sec INCONCLUSIVE (1.044, budget 1.05), which passes against main (0.994): not this PR's. Tables and gate reports: PR comment "Measurements and local checks".

Local checks

GitHub CI is paused (#396). Run on commit 51cebe9 (the PR head), shared devbox at load 15-56, debug info off, full suites one at a time under flock; log local-checks-51cebe99.log in the task data directory, details in the PR comment.

check command result
format make fmt-check pass
lint make lint pass
unit + integration (workspace) make unit-test fail: 3360 passed, 4 failed: sync_replication_tests::async_mode_never_tracks_or_waits, sync_replication_tests::a_write_is_acknowledged_once_a_follower_confirms_its_events, handler::tests::test_execute_program_touches_session_on_non_query, residency::tests::a_knowledge_graph_with_state_only_in_memory_stays_loaded (all 4 pass rerun alone)
snapshot specs make e2e-test pass
differential oracle make oracle-test pass
scenarios (release) make e2e-reactive fail: 36 passed, 1 failed: saturation::saturated_sessions_get_every_delta_once_in_time_and_nothing_else (delta 7.4 s > 5 s bound; same failure alone and on origin/main d5df1ba at this load)
Python SDK make python-test pass
JS SDK make js-test pass
perf-gate tool, pre-pr self-test make perf-gate-check, make pre-pr-selftest not run: their inputs are unchanged

Pipeline

Updates from git push no-mistakes

... (16 earlier update rounds omitted to keep the PR body within GitHub's 65536-char limit; full history is in the run log.)

⚠️ **Review** - 1 info

The intent words this as "consider", not as required, so this is not a contradiction, but merging will close #383 with that half open. Decide whether to keep it in scope, or split it into a follow-up issue before closing. Fixing it would extend the change (a new cache key or parameterised plans), so the remedy needs authorization rather than an auto-fix.

  • ⚠️ src/protocol/subscription/parameterized.rs:811 - Introduced by the round 1 fix: a family that fails its probes while views keep joining now evaluates its lifted query on every commit, where it used to back off 256 commits after the first failure. Traced from source, not measured.

Sequence: a non-sharing family of n views whose lifted query is too slow, with at least one new binding joining between consecutive commits (a burst of subscriptions during ongoing writes, or users connecting steadily). On each commit the n own evaluations bring own_since_stop up to wait = bindings (line 842-846), so a probe starts. It fails, and stop_sharing sees bindings > judged_at_bindings (line 811), so stops stays 0 and the wait stays one commit. This repeats for as long as growth continues, and each probe is a full lifted evaluation (about 117 ms at 1M edges per the issue). Example: 1,000 views subscribing over 5 s at 100 writes/s gives up to about 500 probes, against about 7 under the doubling rule alone.

The cost is bounded: probes run one at a time under the probe permit, no view waits for them, and the loop ends at the first commit interval with no join. The same path applies when a round errors rather than being too slow (stop_sharing calls at lines 714 and 721).

The cause is that 'still growing' is defined as any increase since the last verdict, even one binding. A narrower definition that still satisfies the operator's decision: count a failure unless bindings have at least doubled since the last verdict, the same threshold as grown at line 837. For the 9 -> 1,000 sequence, the verdicts at 9, 18, ... 576 stay uncounted, the family is judged once at 1,000 after one commit, and that failure counts. Probes during growth are then bounded by log2 of the growth plus one. This would change the last steps of failures_while_a_family_grows_do_not_lengthen_its_wait, which expects two verdicts at 1,000 before stops becomes 1.

This is a policy choice about what 'settled' means, so it needs the operator rather than an auto-fix.

  • ℹ️ src/protocol/subscription/parameterized/tests.rs:669 - Added in the round 1 fix: a_family_too_slow_to_share_while_its_views_subscribe_shares_at_full_size sets the own cost to 1/32 of one measured round, then relies on two later probe rounds landing within 8x of that measurement. The 9-view probe must take more than 4x own (round/8), and the 1,000-view probe at most 250x own (about 7.8x round). The round is a millisecond-scale query over 1,000 rows, so one scheduling stall on a loaded CI host during the measured round or the second probe can flip either assertion. The operator asked for no extreme own cost, so this is the accepted tradeoff; noted in case the test flakes in CI.

🔧 Fix applied.
5 issues (4 warnings, 1 info) still open:

  • ⚠️ src/protocol/subscription/parameterized.rs:836 - Judging a family while it is still growing can leave it not sharing at its final size, with a much longer retry backoff than before. Not measured: this is traced from source, and whether it bites depends on the round/own cost ratio on the benchmark host.

Concrete sequence (issue scenario, 1,000 views subscribed one after another, 8 compute permits): record_own now returns true on the first own evaluation with 9 bindings, so the probe is judged by keeps_sharing at 9 bindings, where a round may be at most 4x a view's own cost. A lifted ?r1(_L0, Y) over 1M edges fails that, so stop_sharing (line 798) sets stops=1, stopped_at_bindings=9. The grown rule then re-probes at roughly 18, 36, 72, 144, 288 and 576 bindings, each failure incrementing stops. No further growth probe is possible before 1,152 bindings, so the last verdict is the one at ~576, where the threshold is 144x own cost; at 1,000 bindings it would be 250x. A family whose round costs between those two is left not sharing, although it would share if judged at full size.

Once stuck, the next probe needs probe_after(1000, 7) = 256 * 1000 * 64 own evaluations, about 16,384 writes each evaluating all 1,000 views (the #383 storm). Before this change, a family subscribed in one go was first judged on its first write at full size with stops == 0, and a failure there backed off 256 writes. The issue's own numbers (about 117 ms per shared write against sub-millisecond own evaluations) put the ratio in the low hundreds, near this band.

Same class, other sites: stop_sharing at line 798 counts subscribe-time failures like steady-state ones; stops is only reset on a successful round (line 742) or a rule change (line 612). The new unit test a_family_judged_while_its_views_subscribe_shares_its_first_commit forces own_cost_us to 1 s, so it does not exercise a failing subscribe-time probe followed by growth.

The remedy is a policy choice, so it needs the author: for example, not counting a failure (or not growing the backoff) for a verdict reached while the family is still growing, or re-judging once bindings settle. Benchmark confirmation on perf-gate views at 1M edges would settle whether the band is hit in practice.

  • ⚠️ src/storage_engine/snapshot.rs:123 - The change addresses only the first of the two things the issue names. The intent's title includes "plan cache (256) thrashes on 1,000 distinct keyed texts" and suggests to "consider ... keying the plan cache by lifted text"; the diff leaves MAX_CACHED_PLANS = 256 and the per-text plan key (src/protocol/handler.rs:3729-3736) untouched.

The thrash stays reachable whenever a family of more than 256 keyed views evaluates its own queries on a write: when its probe fails (see the other finding), when a parameter binds a recursive relation (never shared, by design), and on the first write after a rule change, which resets sharing and empties the plan map. In those cases most of the 1,000 own evaluations still compile their plan on every write.

The intent words this as "consider", not as required, so this is not a contradiction, but merging will close #383 with that half open. Decide whether to keep it in scope, or split it into a follow-up issue before closing. Fixing it would extend the change (a new cache key or parameterised plans), so the remedy needs authorization rather than an auto-fix.

  • ⚠️ src/protocol/subscription/parameterized.rs:811 - Introduced by the round 1 fix: a family that fails its probes while views keep joining now evaluates its lifted query on every commit, where it used to back off 256 commits after the first failure. Traced from source, not measured.

Sequence: a non-sharing family of n views whose lifted query is too slow, with at least one new binding joining between consecutive commits (a burst of subscriptions during ongoing writes, or users connecting steadily). On each commit the n own evaluations bring own_since_stop up to wait = bindings (line 842-846), so a probe starts. It fails, and stop_sharing sees bindings > judged_at_bindings (line 811), so stops stays 0 and the wait stays one commit. This repeats for as long as growth continues, and each probe is a full lifted evaluation (about 117 ms at 1M edges per the issue). Example: 1,000 views subscribing over 5 s at 100 writes/s gives up to about 500 probes, against about 7 under the doubling rule alone.

The cost is bounded: probes run one at a time under the probe permit, no view waits for them, and the loop ends at the first commit interval with no join. The same path applies when a round errors rather than being too slow (stop_sharing calls at lines 714 and 721).

The cause is that 'still growing' is defined as any increase since the last verdict, even one binding. A narrower definition that still satisfies the operator's decision: count a failure unless bindings have at least doubled since the last verdict, the same threshold as grown at line 837. For the 9 -> 1,000 sequence, the verdicts at 9, 18, ... 576 stay uncounted, the family is judged once at 1,000 after one commit, and that failure counts. Probes during growth are then bounded by log2 of the growth plus one. This would change the last steps of failures_while_a_family_grows_do_not_lengthen_its_wait, which expects two verdicts at 1,000 before stops becomes 1.

This is a policy choice about what 'settled' means, so it needs the operator rather than an auto-fix.

  • ℹ️ src/protocol/subscription/parameterized/tests.rs:669 - Added in the round 1 fix: a_family_too_slow_to_share_while_its_views_subscribe_shares_at_full_size sets the own cost to 1/32 of one measured round, then relies on two later probe rounds landing within 8x of that measurement. The 9-view probe must take more than 4x own (round/8), and the 1,000-view probe at most 250x own (about 7.8x round). The round is a millisecond-scale query over 1,000 rows, so one scheduling stall on a loaded CI host during the measured round or the second probe can flip either assertion. The operator asked for no extreme own cost, so this is the accepted tradeoff; noted in case the test flakes in CI.
  • ⚠️ src/protocol/subscription/parameterized.rs:812 - In the round 2 fix: an uncounted verdict keeps an earlier counted failure, so a family that receives one write while its views are still subscribing is not re-judged after one commit at its settled size. Traced from source, not measured.

Sequence (8 permits, lifted query too slow for small sizes): the probe at 9 bindings fails uncounted (stops=0, judged_at_bindings=9). Three more views subscribe, then a write lands at 12 bindings: its 12 own evaluations bring own_since_stop to 15 >= wait (12, line 843-847), a probe starts and fails, and 12 < 18 so it counts (stops=1). Growth continues: the verdicts at 24, 48, ... 768 are uncounted but leave stops at 1. At 1,000 bindings grown is false (needs 1,536) and wait is probe_after(1000, 1) = 256,000 own evaluations, i.e. 256 writes each evaluating all 1,000 views. The last verdict was at 768 bindings (round allowed 192x own cost) where 1,000 allows 250x.

This contradicts the operator's round 2 decision ("a family is judged for the record after one commit at its settled size") and the comments that state it unconditionally: module doc lines 62-65 ("a family that stopped with at least twice the bindings of its previous verdict probes again after one commit") and the record_own doc at lines 818-823. It only holds when no failure was counted earlier. Without a write during the ramp the behaviour is as decided.

This is a narrower remainder of the ignored finding subscribe-time-probe-failures-accumulate, left behind by the round 2 fix; it is no worse than base for a family that also fails at full size (base also waited 256 writes). Both new tests (failures_while_a_family_grows_do_not_lengthen_its_wait, a_family_gaining_a_view_per_commit_does_not_probe_on_every_commit) pass with it: neither has a commit between doublings followed by further doubling.

Possible remedy: an uncounted stop also resets stops to 0 (line 812-814), so the one-commit wait applies after every doubling; probes during growth are then bounded by about 2 per doubling. Alternatively keep the behaviour and correct the two comments. This is a policy choice about the backoff, so it needs the operator.

🔧 Fix applied.
2 issues (1 warning, 1 info) still open:

  • ⚠️ src/storage_engine/snapshot.rs:123 - The change addresses only the first of the two things the issue names. The intent's title includes "plan cache (256) thrashes on 1,000 distinct keyed texts" and suggests to "consider ... keying the plan cache by lifted text"; the diff leaves MAX_CACHED_PLANS = 256 and the per-text plan key (src/protocol/handler.rs:3729-3736) untouched.

The thrash stays reachable whenever a family of more than 256 keyed views evaluates its own queries on a write: when its probe fails (see the other finding), when a parameter binds a recursive relation (never shared, by design), and on the first write after a rule change, which resets sharing and empties the plan map. In those cases most of the 1,000 own evaluations still compile their plan on every write.

The intent words this as "consider", not as required, so this is not a contradiction, but merging will close #383 with that half open. Decide whether to keep it in scope, or split it into a follow-up issue before closing. Fixing it would extend the change (a new cache key or parameterised plans), so the remedy needs authorization rather than an auto-fix.

  • ℹ️ src/protocol/subscription/parameterized/tests.rs:669 - Added in the round 1 fix: a_family_too_slow_to_share_while_its_views_subscribe_shares_at_full_size sets the own cost to 1/32 of one measured round, then relies on two later probe rounds landing within 8x of that measurement. The 9-view probe must take more than 4x own (round/8), and the 1,000-view probe at most 250x own (about 7.8x round). The round is a millisecond-scale query over 1,000 rows, so one scheduling stall on a loaded CI host during the measured round or the second probe can flip either assertion. The operator asked for no extreme own cost, so this is the accepted tradeoff; noted in case the test flakes in CI.

  • ℹ️ gui/lib/docs-bundle.ts:1 - The regenerated docs bundle (commit 51cebe9) also picks up replication-guide text unrelated to this change (the 64 MiB follower buffer, follower pings, removal of the Warm standby: follower must keep reading the stream while it reconciles a large graph #356 known limit). The bundle was stale at the base commit: the new text matches docs/content/docs/guides/replication.mdx at HEAD, so the regeneration is faithful and nothing is wrong in it. Noted only so the extra lines in the PR diff are not a surprise.

⚠️ **Test** - 1 info

✅ No issues found.

  • Live validation: ✅ go - 5 of 7 scenarios driven live against the product
Scenario Result Live Evidence
Subscribe 1,000 keyed views ?r1(H_k, Y) as a new family on a 1M-edge graph, then write: the writes cost one shared evaluation instead of 1,000 own evaluations ✅ pass live scripts/bench-views.sh --baseline-rev 00565385 --edges 1000000 --keyed 1000 ... (cold-1000-summary.md). Phase P4_r1_keyed_x1000: base 689.5 ms CPU/write, ack p50/p99 266.4/564.5 ms, write-to-delta p…
During that cold-start run the target server no longer compiles a plan for most own evaluations on each write ✅ pass live Server logs of the same run (cold-1000-server-baseline.txt, cold-1000-server-candidate.txt), snapshot_execute_cached lines over the whole run: base 2,125 executions of which 1,752 compiled a plan; t…
Ramp the same family up through 1, 10, 100, 300 then 1,000 subscribers: the write cost stays where it was before the change ✅ pass live scripts/bench-views.sh --baseline-rev 00565385 --edges 100000,1000000 --keyed 1,10,100,300,1000 ... (ramp-summary.md). At 1M edges and 1,000 subscribers: base 118.0 ms CPU/write, ack p99 6.8 ms; tar…
Adversarial: 100 keyed views of the recursive view ?hot_reach(H_k, Y) (more views than compute permits) are never served by a lifted evaluation and still get every delta ✅ pass live Same ramp run, phase P5_hot_reach_keyed_x100 at 100K edges: 101.0 rule evaluations/write on base and 100.5 on target (one per view plus the ad-hoc read, no shared round), 0 late, 0 subscription errors…
Adversarial: views subscribe in batches while a writer inserts and retracts edges, so the family is judged while it grows; every view ends with exactly its own rows ✅ pass live Disposable driver against the target release server (ramp-writes-candidate.txt, source in ramp-writes-driver.rs). Run 1: 1,000 views on 300K edges, 172 writes committed during the 5.4 s ramp and 40 af…
Keyed subscriptions over a real server share the first write after subscribing and each receive only their own rows ⏸️ untested no The prior payload did not establish a live result for this scenario: it was covered only by the integration tests cargo test --test standing_query_tests parameterized (5 passed, including `bound_sub…
Backoff policy from the review decisions: a failed verdict counts only when bindings have not doubled, and a family gaining one view per commit does not probe on every commit ⏸️ untested no The prior payload did not establish a live result for this scenario: it was covered only by unit tests, cargo test --lib protocol::subscription::parameterized (33 passed, including `failures_while_a…
  • cargo test --lib protocol::subscription::parameterized (33 passed)

  • cargo test --test standing_query_tests parameterized (5 passed)

  • scripts/bench-views.sh --baseline-rev 0056538513506df1f691369e28737e5ff6534436 --edges 1000000 --keyed 1000 --large-recursive-keyed 1 --reads 1 --filler-rules 0 (cold start, both servers, exit 0)

  • scripts/bench-views.sh --baseline-rev 0056538513506df1f691369e28737e5ff6534436 --edges 100000,1000000 --keyed 1,10,100,300,1000 --recursive-keyed 100 --large-recursive-keyed 1 --reads 1 --filler-rules 0 (ramp-up and recursive keyed, both servers, exit 0)

  • Counted snapshot_execute_cached lines with plan_cached=true/false in both servers' logs from the cold-start run

  • Disposable Rust driver reusing perf-gate/src/client.rs and server.rs against target/release/inputlayer-server: 1,000 views on 300K edges and 200 views on 60K edges subscribing while a writer inserts and retracts, each view checked against an ad-hoc read and the writer's record

  • Removed the driver, the base build and the benchmark outputs from target/; git status is clean and no server I started is left running

  • ⚠️ The Test agent did not finish within its invocation budget. Reported: agent run tests timed out after 30m0s: agent last produced output 2s ago (78 observed); agent reported: claude parse events: context deadline exceeded. This is a budget or provider-slowness cut, not a code failure. Re-running the same request costs another full budget, so no further attempt is made automatically. If this repository's targeted tests or evidence gathering routinely approach the default 30m0s, raise test_agent_timeout in global config. Respond with fix to spend another budget: a repair turn runs only for selected findings other than this budget cut, then validation re-runs. Or abort and retry after raising the budget.

🔧 No changes applied.
1 info still open:

  • ℹ️ Ack latency for the cold 1,000-view phase varied between samples on this host: 3.9/7.6 ms and 6.3/10.2 ms (p50/p99) in two candidate runs, 125.8/331.2 ms in a third. The host was at load average 27-34 from other jobs, and the same spikes appear in unrelated phases and on the baseline (for example baseline P3 ack p50 190.8 ms in the same run). Server CPU per write (123-136 ms) and rule evaluations per write (2.0) were stable in every run. A run on the dedicated benchmark host (make bench-views-remote) would give clean latency numbers if they are wanted for the PR.
  • Live validation: ✅ go - 5 of 7 scenarios driven live against the product
Scenario Result Live Evidence
Subscribe 1,000 keyed views as a new family at 1M edges, then write: each write costs about one shared evaluation of server CPU instead of evaluating every view ✅ pass live rerun-cold-1000-summary.md: P4_r1_keyed_x1000 baseline 1292.0 ms CPU/write and 102.0 rule evaluations/write, candidate 123.0 ms and 2.0. rerun2-cold-1000-candidate-summary.md: 135.5 ms and 2.0.
Same cold family: write ack and write-to-delta latency no longer carry the storm ✅ pass live rerun2-cold-1000-candidate-summary.md: ack p50/p99 6.3/10.2 ms, write-to-delta 101.0/112.6 ms over 20 writes. The first sample (rerun-cold-1000-summary.md) had candidate ack 125.8/331.2 ms under load…
Every one of the 1,000 keyed subscribers still receives its own delta for each write while the family shares one evaluation ✅ pass live Both re-runs: P4_r1_keyed_x1000 has 1001.0 frames/write and 0 late on the candidate; perf-gate exited 0 (it exits 1 if any delta is missing).
Keyed subscribers get only their own rows through mixed writes, and the family is judged before its first write (real server over WebSocket) ✅ pass live targeted-tests.log: standing_query_tests parameterized, 5 passed, including bound_subscriptions_share_one_evaluation_and_get_only_their_rows and every_subscriber_follows_its_own_query_through_mixed_…
Adversarial: sharing switched off, a single-binding family, and results over the row cap still behave as each view's own query does ✅ pass live targeted-tests.log: sharing_can_be_switched_off, a_family_of_one_binding_evaluates_on_its_own, results_over_the_row_cap_fail_as_the_views_own_query_does all ok.
Adversarial: a family too slow to share while small is re-judged as it grows, shares at full size, and a family gaining one view per commit does not probe on every commit ⏸️ untested no The prior payload did not establish a live result: it was covered only by in-process handler unit tests (cargo test --all-features --lib protocol::subscription::parameterized, 33 passed, including a…
Ramping the same family through 1, 10, 100 then 1,000 subscribers stays cheap at 1,000, as it was before the change ⏸️ untested no Not re-driven in this attempt: the previous attempt ran it live on the same commit and binary but then hit the 30-minute budget, so I spent this budget on the cold-start scenario and cite the earlier…
  • target/release/perf-gate views --server target/release/inputlayer-server --compare target/perf-gate/servers/c3d08ae5…/inputlayer-server --edges 1000000 --keyed 1000 --large-writes 10 --reads 2 --large-recursive-keyed 1 --filler-rules 50 (baseline vs candidate, exit 0)
  • target/release/perf-gate views --server target/release/inputlayer-server --edges 1000000 --keyed 1000 --large-writes 20 --reads 1 --large-recursive-keyed 1 --filler-rules 50 (candidate only, second sample, exit 0)
  • cargo test --all-features --test standing_query_tests parameterized (5 passed)
  • cargo test --all-features --lib protocol::subscription::parameterized (33 passed)
  • Read the earlier evidence from this step on the same commit (views-cold-1000-summary.md, views-ramp-compare-summary.md) for the ramp comparison; not re-driven in this attempt
✅ **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 added 5 commits October 6, 2026 05:01
…cribe, so its first write shares one evaluation (#383)

A family of keyed subscriptions (one bound view per session, `?r1(H_k, Y)`)
decides whether to share one evaluation per write by comparing a round of
its lifted query with a view's own evaluation. A view's own cost counted
only when its evaluation reused a compiled plan. Every view's text is
distinct, so each first evaluation compiles its own plan, and a rule set
keeps 256 plans: a family of 1,000 views that had only subscribed had no
own cost, was never judged, and on its first write every view evaluated
its own query, most of them compiling their plan again. On the views
benchmark at 1M edges the issue's report measured about 740 ms of server
CPU per write over the phase and an ack p99 of 680 ms.

The cost of an evaluation has left out compiling its plan since rounds
were judged that way (`CachedRun::executing`), so the restriction no
longer protects the comparison. A view's own cost now counts every own
evaluation: the family probes as soon as it has more bindings than
compute permits, while its views subscribe, and its first write reads
one round. Samples taken while sharing count too, so a family larger
than the plan cache keeps its own cost current.

Answers do not change: which evaluation a view reads was already a
timing decision, and every view still evaluates its own query when it
starts and after a rule change.
@jsam
jsam force-pushed the fm/il-383-cold-start branch from edd9a33 to 51cebe9 Compare October 6, 2026 05:49
@jsam
jsam merged commit be62ddb into main Oct 6, 2026
@jsam

jsam commented Oct 6, 2026

Copy link
Copy Markdown
Contributor Author

Measurements and local checks

Companion to the PR description's "Scope, measurements and known limits" and "Local checks" sections (the description is near GitHub's size limit, so the detail lives here).

Benchmark host (sam-dev-benchmarks, 32 CPUs, servers on CPUs 8-31, each run alone under the host lock)

scripts/bench-views.sh --edges 1000000 --keyed 1000 --recursive-keyed 1000000 --large-recursive-keyed 1000000 --filler-rules 0 --reads 3, phase P4_r1_keyed_x1000: 1,000 keyed views ?r1(k, Y) subscribed as a new family on 1M edges, then 20 writes.

main a649cd9 (20261005T230652Z) PR edd9a33 (20261006T014703Z)
server CPU per write 663.5 ms 108.0 ms
ack p50 / p99 3.9 / 598.2 ms 3.9 / 4.1 ms
write -> delta p50 / p99 73.3 / 667.3 ms 70.7 / 73.7 ms
rule evaluations per write 52.0 2.0
subscribe 1,000 views 991 ms 989 ms

edd9a33 is the pre-rebase head; the current head 51cebe9 carries the same change rebased onto main (patch-ids identical in src/ and tests/, only gui/lib/docs-bundle.ts was re-merged). The remaining ~100 ms per write is one shared evaluation of ?r1(_L0, Y) at 1M edges (the unbound ?r1(X, Y) view in phase P2 costs 76 ms per write on the same runs): the floor until live views (#318). The issue's own report measured 740 ms per write and a 680 ms ack p99 for this case.

Perf gate

  • perf-gate-remote, 20 rounds, candidate edd9a33 vs the approved baseline e732cd5 (run 20261006T015147Z): every required metric PASS except cheap_query.queries_per_sec, INCONCLUSIVE at cost ratio 1.044 (interval 1.026..1.051, budget 1.05). delta_keyed improves 10 to 100x (ack p99 1051.7 -> 9.1 ms, delta p99 1065.7 -> 14.4 ms, 19x more writes per server CPU second).
  • cheap_query only, 20 rounds, edd9a33 vs main 0056538 (run 20261006T040259Z): every metric PASS, queries_per_sec 0.994 (0.986..1.001), p50 1.001, p99 0.992. The gap against the approved baseline predates this PR.
  • An A/B of the same against main a649cd9 failed to build that baseline on the host (missing field code in ServerFrame: the archived baseline compiles against the current ws-protocol); perf-gate tooling follow-up, not this PR.

Local checks on 51cebe9 (GitHub CI is paused, #396)

Shared devbox, CARGO_PROFILE_DEV_DEBUG=0 CARGO_PROFILE_TEST_DEBUG=0 CARGO_INCREMENTAL=0, each full suite alone under flock; machine load 15-56 (other lanes' suites were running unlocked). Log: fm-home/data/il-383-cold-start/local-checks-51cebe99.log (plus -targeted-rerun.log, saturation-on-main.log).

check command result load at start
format make fmt-check pass 41
lint make lint pass 41
unit + integration (workspace) make unit-test fail: 3360 passed, 4 failed (below) 56
snapshot specs make e2e-test pass 48
differential oracle make oracle-test pass 32
scenarios, release make e2e-reactive fail: 36 passed, 1 failed (below) 15
Python SDK make python-test pass 18
JS SDK make js-test pass 54
make perf-gate-check, make pre-pr-selftest — not run: perf-gate/, Makefile, scripts/ unchanged —

Failures, as they happened:

  1. protocol::handler::sync_replication_tests::async_mode_never_tracks_or_waits and ...::a_write_is_acknowledged_once_a_follower_confirms_its_events: assertion failed: started.elapsed() < SYNC_TIMEOUT_MS (wall-clock bounds).
  2. protocol::handler::tests::test_execute_program_touches_session_on_non_query: session reaped after a 2 s sleep plus an execute (wall-clock session TTL).
  3. storage_engine::residency::tests::a_knowledge_graph_with_state_only_in_memory_stays_loaded: revision 28311640 is above a bound that cannot be raised: I/O error: No such file or directory at src/storage_engine/revisions.rs:87 (code from fix(storage_engine): never reissue revisions across restarts so a stale expect_revision is refused #390, merged tonight; not touched by this PR).
  4. All four pass when run alone in one process (2 s, load 49).
  5. saturation::saturated_sessions_get_every_delta_once_in_time_and_nothing_else (release scenario, 1,024 sessions each with its own bound query, so it does exercise the keyed-family path): probe delta 7.4 s after its ack, bound 5 s. Rerun alone: fails again (8.5 s, load 54). The same scenario on origin/main d5df1ba at the same load fails the same way (8.0 s), so the failure follows machine load, not this change.

None of these is retried until green; they are reported as they are.

@jsam
jsam deleted the fm/il-383-cold-start branch October 6, 2026 06:30
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.

Cold-start storm: a new family of 1,000 keyed views evaluates every own query on the first write (~745 ms CPU/write, ack p99 ~690 ms); plan cache (256) thrashes on 1,000 distinct keyed texts

1 participant