Skip to content

Commit f46a61a

Browse files
authored
perf(ledger): stream rows to disk instead of collecting them first (#155)
Scoring built the whole ledger as a `Vec<CallRecord>` and wrote it afterwards. Every resolved row carries the recorded side's full `args` and `result`, so a run with thousands of resolved calls held a second copy of its own recording in memory, alongside the parsed lookup table and record graph, before a byte reached disk. That is what OOMKilled the runner. Established by controlled comparison rather than by argument: on one 287-correlation recording, at one 16Gi limit, with one deja build, the candidate with the `imc` seam disabled COMPLETES in 1m51 while the unmodified candidate dies at 16Gi. Same 214 MB lookup table, same 100 correlations driven, same 67s seeding, same 8s driving. The only difference is what the ledger holds: 82 resolved calls against thousands, because the disabled seam makes almost every row `omitted` or `pruned_subtree` and those carry no payload. Every other explanation was eliminated by test first: table size (the passing run loads the same one), deja revision (same build), correlation count (a 427-correlation recording scores in 88s), render and scoping (3.2s, timed), the `Expected` result clone (removed in #152, still OOMs), and a hang (exit 137, the container terminated). `build_with_inconclusive` and `build_with_plan` now emit through a sink; the collecting form is kept for `build_ledger`, which the `/calls` API genuinely needs whole. `detect_and_score` streams straight into a `BufWriter`, so peak is bounded by one row rather than by the run. Flat-tier rows stream first, exactly as the collecting version ordered them. Behaviour is unchanged — 443 tests pass, including the two that assert the scorecard and the ledger classify identically, which is what would break if the row set or its order moved.
1 parent 5f18679 commit f46a61a

2 files changed

Lines changed: 100 additions & 39 deletions

File tree

crates/deja-orchestrator/src/divergence/ledger.rs

Lines changed: 73 additions & 22 deletions
Original file line numberDiff line numberDiff line change
@@ -199,6 +199,8 @@ pub fn build(
199199
)
200200
}
201201

202+
/// Collecting wrapper over [`build_with_inconclusive_into`], for callers that genuinely
203+
/// want every row in memory (the `/calls` API).
202204
pub(crate) fn build_with_inconclusive(
203205
events: &[BoundaryEvent],
204206
observed: &[ObservedCall],
@@ -207,6 +209,39 @@ pub(crate) fn build_with_inconclusive(
207209
inconclusive_race: &InconclusiveRaceEvidence,
208210
tail_gap: &TailGapEvidence,
209211
) -> Vec<CallRecord> {
212+
let mut rows = Vec::new();
213+
let _ = build_with_inconclusive_into(
214+
events,
215+
observed,
216+
table,
217+
idempotent_delete_demote,
218+
inconclusive_race,
219+
tail_gap,
220+
&mut |row| {
221+
rows.push(row);
222+
Ok(())
223+
},
224+
);
225+
rows
226+
}
227+
228+
/// Emit each ledger row to `sink` as it is produced.
229+
///
230+
/// Streaming rather than returning a `Vec<CallRecord>`: every resolved row
231+
/// carries the recorded side's full `args` and `result`, so a run with
232+
/// thousands of resolved calls held a second copy of its own recording in
233+
/// memory before a byte reached disk. That OOMKilled the runner at 16 GiB on a
234+
/// 287-correlation tape, while the SAME tape scored fine for a candidate whose
235+
/// rows were overwhelmingly payload-free — 82 resolved calls against thousands.
236+
pub(crate) fn build_with_inconclusive_into(
237+
events: &[BoundaryEvent],
238+
observed: &[ObservedCall],
239+
table: &deja::LookupTable,
240+
idempotent_delete_demote: &HashSet<u64>,
241+
inconclusive_race: &InconclusiveRaceEvidence,
242+
tail_gap: &TailGapEvidence,
243+
sink: &mut dyn FnMut(CallRecord) -> std::io::Result<()>,
244+
) -> std::io::Result<()> {
210245
let expected_seqs = &expected_sequences(table);
211246
let span_paths = &recorded_span_paths(table);
212247
let by_seq: HashMap<u64, &BoundaryEvent> =
@@ -222,7 +257,6 @@ pub(crate) fn build_with_inconclusive(
222257
})
223258
};
224259

225-
let mut rows: Vec<CallRecord> = Vec::new();
226260
let mut consumed: HashSet<u64> = HashSet::new();
227261

228262
// Args-free pairing of recorded twins for execute-mode write consequences:
@@ -274,7 +308,7 @@ pub(crate) fn build_with_inconclusive(
274308
} else {
275309
("value_diverged".to_owned(), true)
276310
};
277-
rows.push(CallRecord {
311+
sink(CallRecord {
278312
correlation_id: obs.correlation_id.clone(),
279313
source_event_global_sequence: obs.source_event_global_sequence,
280314
served_event_global_sequence: None,
@@ -287,7 +321,7 @@ pub(crate) fn build_with_inconclusive(
287321
resolved_rank: obs.resolved_rank,
288322
recorded,
289323
observed: observed_side(obs).or_none(),
290-
});
324+
})?;
291325
continue;
292326
}
293327

@@ -366,7 +400,7 @@ pub(crate) fn build_with_inconclusive(
366400
}
367401
_ => None,
368402
});
369-
rows.push(CallRecord {
403+
sink(CallRecord {
370404
correlation_id: obs.correlation_id.clone(),
371405
source_event_global_sequence: Some(twin_seq),
372406
served_event_global_sequence: None,
@@ -384,7 +418,7 @@ pub(crate) fn build_with_inconclusive(
384418
resolved_rank: obs.resolved_rank,
385419
recorded,
386420
observed: observed.or_none(),
387-
});
421+
})?;
388422
continue;
389423
}
390424
}
@@ -423,7 +457,7 @@ pub(crate) fn build_with_inconclusive(
423457
.source_event_global_sequence
424458
.and_then(recorded_for)
425459
.and_then(CallSide::or_none);
426-
rows.push(CallRecord {
460+
sink(CallRecord {
427461
correlation_id: obs.correlation_id.clone(),
428462
source_event_global_sequence: obs.source_event_global_sequence,
429463
served_event_global_sequence: None,
@@ -436,7 +470,7 @@ pub(crate) fn build_with_inconclusive(
436470
resolved_rank: obs.resolved_rank,
437471
recorded,
438472
observed: observed_side(obs).or_none(),
439-
});
473+
})?;
440474
}
441475

442476
// --- omitted: expected (table-covered) recorded events never consumed ----
@@ -452,7 +486,7 @@ pub(crate) fn build_with_inconclusive(
452486
&ev.boundary,
453487
ev.role.as_deref(),
454488
);
455-
rows.push(CallRecord {
489+
sink(CallRecord {
456490
correlation_id: ev.correlation_id.clone(),
457491
source_event_global_sequence: Some(ev.global_sequence),
458492
served_event_global_sequence: None,
@@ -465,25 +499,38 @@ pub(crate) fn build_with_inconclusive(
465499
resolved_rank: None,
466500
recorded: recorded_for(ev.global_sequence),
467501
observed: None,
468-
});
502+
})?;
469503
}
470504

471-
rows
505+
Ok(())
472506
}
473507

474508
/// Build a ledger through the same per-correlation graph/flat seam as the
475509
/// scorecard. The all-flat arm delegates directly to the legacy builder; mixed
476510
/// runs remove graph correlations before doing so, so args-free pairing cannot
477511
/// claim an event owned by graph alignment.
478-
pub(crate) fn build_with_plan(
512+
/// Emit each ledger row to `sink` as it is produced.
513+
///
514+
/// Streaming rather than returning a `Vec<CallRecord>`: every resolved row
515+
/// carries the recorded side's full `args` and `result`, so a run with
516+
/// thousands of resolved calls held a second copy of its own recording in
517+
/// memory before a byte reached disk. That OOMKilled the runner at 16 GiB on a
518+
/// 287-correlation tape, while the SAME tape scored fine for a candidate whose
519+
/// rows were overwhelmingly payload-free — 82 resolved calls against thousands.
520+
// Eight because the sink is an eighth parameter on a function that already took
521+
// seven; bundling them into a struct would be a larger change than the one being
522+
// made and would obscure that this is the same function, streaming.
523+
#[allow(clippy::too_many_arguments)]
524+
pub(crate) fn build_with_plan_into(
479525
events: &[BoundaryEvent],
480526
observed: &[ObservedCall],
481527
table: &deja::LookupTable,
482528
idempotent_delete_demote: &HashSet<u64>,
483529
inconclusive_race: &InconclusiveRaceEvidence,
484530
tail_gap: &TailGapEvidence,
485531
plan: &GraphScoringPlan,
486-
) -> Vec<CallRecord> {
532+
sink: &mut dyn FnMut(CallRecord) -> std::io::Result<()>,
533+
) -> std::io::Result<()> {
487534
let graph_correlations: BTreeSet<&str> = events
488535
.iter()
489536
.filter_map(|event| event.correlation_id.as_deref())
@@ -496,13 +543,14 @@ pub(crate) fn build_with_plan(
496543
.collect();
497544

498545
if graph_correlations.is_empty() {
499-
return build_with_inconclusive(
546+
return build_with_inconclusive_into(
500547
events,
501548
observed,
502549
table,
503550
idempotent_delete_demote,
504551
inconclusive_race,
505552
tail_gap,
553+
sink,
506554
);
507555
}
508556
let by_seq: HashMap<u64, &BoundaryEvent> = events
@@ -581,14 +629,17 @@ pub(crate) fn build_with_plan(
581629
.entries
582630
.retain(|entry| !graph_sequence.contains(&entry.source_event_global_sequence));
583631

584-
let mut rows = build_with_inconclusive(
632+
// Flat-tier rows stream through the same sink, and FIRST — preserving the
633+
// order the collecting version produced (flat rows, then graph rows).
634+
build_with_inconclusive_into(
585635
&flat_events,
586636
&flat_observed,
587637
&flat_table,
588638
idempotent_delete_demote,
589639
inconclusive_race,
590640
&flat_tail_gap,
591-
);
641+
sink,
642+
)?;
592643
let span_paths = recorded_span_paths(table);
593644

594645
for correlation_id in graph_correlations {
@@ -607,7 +658,7 @@ pub(crate) fn build_with_plan(
607658
let event = by_seq[&sequence];
608659
let mut side = recorded_side(event);
609660
side.span_path = span_paths.get(&sequence).cloned();
610-
rows.push(CallRecord {
661+
sink(CallRecord {
611662
correlation_id: event.correlation_id.clone(),
612663
source_event_global_sequence: Some(sequence),
613664
served_event_global_sequence: None,
@@ -624,7 +675,7 @@ pub(crate) fn build_with_plan(
624675
resolved_rank: None,
625676
recorded: side.or_none(),
626677
observed: None,
627-
});
678+
})?;
628679
}
629680
}
630681
NodeOutcome::NovelSubtree { events_below } => {
@@ -636,7 +687,7 @@ pub(crate) fn build_with_plan(
636687
// space the evidence was measured in — no remap here.
637688
let unrecorded_tail =
638689
tail_gap.covers(call.correlation_id.as_deref(), index);
639-
rows.push(CallRecord {
690+
sink(CallRecord {
640691
correlation_id: call.correlation_id.clone(),
641692
source_event_global_sequence: None,
642693
served_event_global_sequence: None,
@@ -655,7 +706,7 @@ pub(crate) fn build_with_plan(
655706
resolved_rank: call.resolved_rank,
656707
recorded: None,
657708
observed: observed_side(call).or_none(),
658-
});
709+
})?;
659710
}
660711
}
661712
outcome => {
@@ -792,7 +843,7 @@ pub(crate) fn build_with_plan(
792843
)
793844
};
794845

795-
rows.push(CallRecord {
846+
sink(CallRecord {
796847
correlation_id: call.correlation_id.clone(),
797848
source_event_global_sequence: aligned_sequence,
798849
served_event_global_sequence: served_sequence,
@@ -805,13 +856,13 @@ pub(crate) fn build_with_plan(
805856
resolved_rank: call.resolved_rank,
806857
recorded: recorded.and_then(CallSide::or_none),
807858
observed: observed.or_none(),
808-
});
859+
})?;
809860
}
810861
}
811862
}
812863
}
813864

814-
rows
865+
Ok(())
815866
}
816867

817868
/// The set of `global_sequence`s the lookup table covers (so http_incoming and

crates/deja-orchestrator/src/divergence/mod.rs

Lines changed: 27 additions & 17 deletions
Original file line numberDiff line numberDiff line change
@@ -5632,13 +5632,11 @@ pub fn detect_and_score(root: &HarnessRoot, run_id: &str) -> io::Result<Scorecar
56325632
crate::write_json(&path, &card)?;
56335633

56345634
// Ledger: the per-call detail the scorecard summary drops. Best-effort.
5635-
match build_ledger_with_plan(&art, &graph_plan) {
5636-
Ok(rows) => {
5637-
if let Err(e) = write_ledger(&root.call_ledger_path(run_id), &rows) {
5638-
eprintln!("divergence: ledger write failed for {run_id}: {e}");
5639-
}
5640-
}
5641-
Err(e) => eprintln!("divergence: ledger build failed for {run_id}: {e}"),
5635+
// Streamed straight to the file. Collecting first held every resolved row —
5636+
// each carrying the recorded side's full `args` and `result` — alongside the
5637+
// parsed table and graph, which is what OOMKilled the runner on a dense tape.
5638+
if let Err(e) = stream_ledger(&root.call_ledger_path(run_id), &art, &graph_plan) {
5639+
eprintln!("divergence: ledger stream failed for {run_id}: {e}");
56425640
}
56435641
Ok(card)
56445642
}
@@ -5654,13 +5652,19 @@ pub fn detect_and_score(root: &HarnessRoot, run_id: &str) -> io::Result<Scorecar
56545652
/// drove attached to its ledger rows.
56555653
pub fn build_ledger(art: &RunArtifacts) -> io::Result<Vec<CallRecord>> {
56565654
let graph_plan = GraphScoringPlan::build(art);
5657-
build_ledger_with_plan(art, &graph_plan)
5655+
let mut rows = Vec::new();
5656+
build_ledger_into(art, &graph_plan, &mut |row| {
5657+
rows.push(row);
5658+
Ok(())
5659+
})?;
5660+
Ok(rows)
56585661
}
56595662

5660-
pub(crate) fn build_ledger_with_plan(
5663+
pub(crate) fn build_ledger_into(
56615664
art: &RunArtifacts,
56625665
graph_plan: &GraphScoringPlan,
5663-
) -> io::Result<Vec<CallRecord>> {
5666+
sink: &mut dyn FnMut(CallRecord) -> io::Result<()>,
5667+
) -> io::Result<()> {
56645668
let events = &art.events;
56655669
let span_paths = ledger::recorded_span_paths(&art.table);
56665670
// Mirror scorecard classification: discover race evidence under status-clean
@@ -5705,15 +5709,16 @@ pub(crate) fn build_ledger_with_plan(
57055709
&document_clauses_for(&art.reply_canons, "http_incoming"),
57065710
),
57075711
);
5708-
Ok(ledger::build_with_plan(
5712+
ledger::build_with_plan_into(
57095713
events,
57105714
&art.observed,
57115715
&art.table,
57125716
&idempotent_delete,
57135717
&inconclusive_race,
57145718
&tail_gap,
57155719
graph_plan,
5716-
))
5720+
sink,
5721+
)
57175722
}
57185723

57195724
/// Read-through ledger for `GET /runs/{id}/calls` (recomputes from artifacts;
@@ -5723,17 +5728,22 @@ pub fn call_ledger(root: &HarnessRoot, run_id: &str) -> io::Result<Vec<CallRecor
57235728
build_ledger(&art)
57245729
}
57255730

5726-
fn write_ledger(path: &std::path::Path, rows: &[CallRecord]) -> io::Result<()> {
5731+
/// Build and write the ledger without ever holding it whole.
5732+
fn stream_ledger(
5733+
path: &std::path::Path,
5734+
art: &RunArtifacts,
5735+
graph_plan: &GraphScoringPlan,
5736+
) -> io::Result<()> {
57275737
use std::io::Write as _;
57285738
if let Some(parent) = path.parent() {
57295739
std::fs::create_dir_all(parent)?;
57305740
}
57315741
let mut out = std::io::BufWriter::new(std::fs::File::create(path)?);
5732-
for row in rows {
5733-
let line = serde_json::to_vec(row).map_err(io::Error::other)?;
5742+
build_ledger_into(art, graph_plan, &mut |row| {
5743+
let line = serde_json::to_vec(&row).map_err(io::Error::other)?;
57345744
out.write_all(&line)?;
5735-
out.write_all(b"\n")?;
5736-
}
5745+
out.write_all(b"\n")
5746+
})?;
57375747
out.flush()
57385748
}
57395749

0 commit comments

Comments
 (0)