Adding events one at a time is quadratic — 130× slower than batching at n=2000 #14

Closed
opened 2026-08-04 19:16:29 +00:00 by logaritmisk · 1 comment
Owner

Measured on main @ 2b5d3b1, --release, identical event sets, single time slice:

events one call per event one batched call ratio
500 46.8 ms 733 µs 64×
1000 183.8 ms 1.9 ms 96×
2000 743.0 ms 5.7 ms 130×

The incremental time quadruples for each doubling of n — textbook O(n²) — while the batched path scales linearly.

Cause

TimeSlice::add_events unconditionally re-colors the entire slice on every call (src/time_slice.rs:310):

self.iteration(from, agents);
self.recompute_color_groups();

iteration(from, …) is well-behaved: it skips to the newly-appended events (.skip(from)). recompute_color_groups (src/time_slice.rs:195-224) is not — it discards the existing partition and rebuilds from scratch over all events in the slice:

  • color_greedy walks every event and builds a fresh HashSet<Index> per event (src/color_group.rs:80),
  • then the whole Vec<Event> is drained into taken, re-ordered, and rebuilt.

Called once per appended event, that is sum(1..n) event-visits plus n full Vec<Event> teardown/rebuild cycles.

Why it matters

This is precisely the online-add workload — the case spec §5 projects at 50–500× and that #4 (dirty-bit slice skipping) is meant to accelerate. Fixing #4 without fixing this leaves the ingestion side quadratic, so incremental use stays slow no matter how well the convergence sweep skips clean slices.

It also affects the convenience API: record_winner / record_draw / event(…).commit() each ingest exactly one event, so any caller in a loop over a match feed hits the quadratic path. That is the most natural way to use the crate.

Fix

Make coloring incremental. Appending an event does not invalidate the existing partition — it only needs to find the first color disjoint from the new event's index set, or open a new one:

  • Keep the per-color HashSet<Index> member sets alive on ColorGroups instead of rebuilding them each time, so an append is O(colors × team_size).
  • Avoid the full re-order when nothing moved. The re-order exists to make each color a contiguous range for color_range; an append only ever extends one color, so an amortised scheme (or an explicit index list per color instead of a range) avoids touching the other events at all.

A batched add_events can keep the current rebuild if that turns out simpler for bulk ingest — the fix only has to make the append path not re-do the whole slice.

Second-order hot spots in the same path

Both are linear scans used as set membership, and both sit inside ingestion:

  • History::add_events_with_prior: this_agent.contains(agent) over a Vec<Index> (src/history.rs:503-510), pre-sized to a magic 1024. O(agents²) per call.
  • TimeSlice::add_events: unique.contains(idx) over a Vec (src/time_slice.rs:234-244), pre-sized to 10.

Both should be HashSet<Index> (or a scratch bitmap keyed by Index.0, which fits the dense-index design better).

color_greedy itself also degrades: members.iter().position(|m| m.is_disjoint(…)) scans every existing color per event, and a slice where one competitor appears in many events produces one color per event — so a single busy player in a slice makes coloring O(n²) even in the batched path.

Acceptance

  • Ingesting n events one at a time is within a small constant factor of ingesting them in one batch, for n up to at least 5000.
  • A benchmark covering the incremental path lands in benches/ — the current suite only measures batched construction, which is why this never showed up.
  • Color-group partition after incremental adds is identical to the partition after an equivalent batched add.

Related

  • #4 — cross-slice dirty bits; both are needed for the online-add story to work end to end.
Measured on `main` @ 2b5d3b1, `--release`, identical event sets, single time slice: | events | one call per event | one batched call | ratio | |---:|---:|---:|---:| | 500 | 46.8 ms | 733 µs | 64× | | 1000 | 183.8 ms | 1.9 ms | 96× | | 2000 | 743.0 ms | 5.7 ms | 130× | The incremental time quadruples for each doubling of `n` — textbook O(n²) — while the batched path scales linearly. ## Cause `TimeSlice::add_events` unconditionally re-colors the entire slice on every call (`src/time_slice.rs:310`): ```rust self.iteration(from, agents); self.recompute_color_groups(); ``` `iteration(from, …)` is well-behaved: it skips to the newly-appended events (`.skip(from)`). `recompute_color_groups` (`src/time_slice.rs:195-224`) is not — it discards the existing partition and rebuilds from scratch over **all** events in the slice: - `color_greedy` walks every event and builds a fresh `HashSet<Index>` per event (`src/color_group.rs:80`), - then the whole `Vec<Event>` is drained into `taken`, re-ordered, and rebuilt. Called once per appended event, that is `sum(1..n)` event-visits plus `n` full `Vec<Event>` teardown/rebuild cycles. ## Why it matters This is precisely the online-add workload — the case spec §5 projects at 50–500× and that #4 (dirty-bit slice skipping) is meant to accelerate. Fixing #4 without fixing this leaves the ingestion side quadratic, so incremental use stays slow no matter how well the convergence sweep skips clean slices. It also affects the convenience API: `record_winner` / `record_draw` / `event(…).commit()` each ingest exactly one event, so any caller in a loop over a match feed hits the quadratic path. That is the most natural way to use the crate. ## Fix Make coloring incremental. Appending an event does not invalidate the existing partition — it only needs to find the first color disjoint from the new event's index set, or open a new one: - Keep the per-color `HashSet<Index>` member sets alive on `ColorGroups` instead of rebuilding them each time, so an append is O(colors × team_size). - Avoid the full re-order when nothing moved. The re-order exists to make each color a contiguous range for `color_range`; an append only ever extends one color, so an amortised scheme (or an explicit index list per color instead of a range) avoids touching the other events at all. A batched `add_events` can keep the current rebuild if that turns out simpler for bulk ingest — the fix only has to make the append path not re-do the whole slice. ## Second-order hot spots in the same path Both are linear scans used as set membership, and both sit inside ingestion: - `History::add_events_with_prior`: `this_agent.contains(agent)` over a `Vec<Index>` (`src/history.rs:503-510`), pre-sized to a magic 1024. O(agents²) per call. - `TimeSlice::add_events`: `unique.contains(idx)` over a `Vec` (`src/time_slice.rs:234-244`), pre-sized to 10. Both should be `HashSet<Index>` (or a scratch bitmap keyed by `Index.0`, which fits the dense-index design better). `color_greedy` itself also degrades: `members.iter().position(|m| m.is_disjoint(…))` scans every existing color per event, and a slice where one competitor appears in many events produces one color *per event* — so a single busy player in a slice makes coloring O(n²) even in the batched path. ## Acceptance - Ingesting `n` events one at a time is within a small constant factor of ingesting them in one batch, for `n` up to at least 5000. - A benchmark covering the incremental path lands in `benches/` — the current suite only measures batched construction, which is why this never showed up. - Color-group partition after incremental adds is identical to the partition after an equivalent batched add. ## Related - #4 — cross-slice dirty bits; both are needed for the online-add story to work end to end.
Author
Owner

Fixed in c088214but my root-cause analysis above was wrong, and the real cause was a correctness bug, not just a slow path.

Making the coloring lazy changed nothing. Profiling showed 1.5 ms of a 1.53 ms append sat in a full slice re-inference: add_events_with_prior advanced k past the slice it wrote when creating one, but not when appending to one, so the trailing forward-refresh loop restarted on the slice just modified.

That is not merely wasted work. The loop above it sets each agent's message to forward * likelihood for that slice, and new_forward_info then assigns skill.forward = message.forget(drift) — folding the slice's own likelihood back into its own forward prior. Converged results depended on how events had been batched: five events sharing a timestamp gave competitor a mu=7.44 sigma=3.90 batched against mu=7.99 sigma=3.10 incrementally, both runs converged.

The goldens never caught it because they all ingest in one call with a distinct timestamp per event, so the append-to-existing-slice branch is never taken. tests/ingestion_equivalence.rs covers it directly and asserts convergence before comparing — my first attempt compared at 1e-9 under the default 30-iteration cap and "found" a 1.5e-6 discrepancy that was only the convergence residual.

With the redundant pass gone:

events before after speedup
500 45.8 ms 1.1 ms 42×
1000 179.5 ms 2.8 ms 64×
2000 721.8 ms 9.9 ms 73×
4000 2.9 s 35.4 ms 82×

One-at-a-time is now 1.8× a single batched call, down from 148×.

Also landed: color groups rebuild lazily rather than per append (a real if secondary saving), benches/ingest.rs measures this path, and the linear-scan dedups in add_events_with_prior / TimeSlice::add_events were left as-is — they were never the bottleneck.

Fixed in c088214 — **but my root-cause analysis above was wrong**, and the real cause was a correctness bug, not just a slow path. Making the coloring lazy changed nothing. Profiling showed 1.5 ms of a 1.53 ms append sat in a full slice re-inference: `add_events_with_prior` advanced `k` past the slice it wrote when *creating* one, but not when *appending* to one, so the trailing forward-refresh loop restarted **on the slice just modified**. That is not merely wasted work. The loop above it sets each agent's message to `forward * likelihood` for that slice, and `new_forward_info` then assigns `skill.forward = message.forget(drift)` — folding the slice's own likelihood back into its own forward prior. Converged results depended on how events had been batched: five events sharing a timestamp gave competitor `a` mu=7.44 sigma=3.90 batched against mu=7.99 sigma=3.10 incrementally, both runs converged. The goldens never caught it because they all ingest in one call with a distinct timestamp per event, so the append-to-existing-slice branch is never taken. `tests/ingestion_equivalence.rs` covers it directly and asserts convergence before comparing — my first attempt compared at 1e-9 under the default 30-iteration cap and "found" a 1.5e-6 discrepancy that was only the convergence residual. With the redundant pass gone: | events | before | after | speedup | |---:|---:|---:|---:| | 500 | 45.8 ms | 1.1 ms | 42× | | 1000 | 179.5 ms | 2.8 ms | 64× | | 2000 | 721.8 ms | 9.9 ms | 73× | | 4000 | 2.9 s | 35.4 ms | 82× | One-at-a-time is now 1.8× a single batched call, down from 148×. Also landed: color groups rebuild lazily rather than per append (a real if secondary saving), `benches/ingest.rs` measures this path, and the linear-scan dedups in `add_events_with_prior` / `TimeSlice::add_events` were left as-is — they were never the bottleneck.
logaritmisk added the performance label 2026-09-07 13:53:14 +00:00
Sign in to join this conversation.