Skip to content

Commit 9a018cb

Browse files
fix(precompute): keep wall-clock fallback from force-closing panes still under active ingest (#536)
* fix(precompute): keep wall-clock fallback from force-closing panes still under active ingest The wall-clock fallback in flush_all() ages a pane using the wall-clock time it was first touched, never refreshed. A bulk load whose rows all share one event-time (so the event-time watermark never advances) that takes longer than window_size_ms + wall_clock_grace_period_ms to ingest therefore gets its window force-closed mid-ingest, and every sample arriving afterward is silently dropped by the (hardcoded) late-data path — a uniform undercount across every group key (#474). Refresh the pane's wall-clock bookkeeping on every touch instead of only the first, so the fallback measures idle time, not age since birth: a pane still receiving samples is never force-closed no matter how long it's been open, only a pane nothing has touched in a while is. Renamed pane_wall_clock_starts_ms -> pane_wall_clock_last_touch_ms (and its prune helper) to match, and updated the doc comments describing the old birth-time semantics. Co-Authored-By: Claude Sonnet 5 <noreply@anthropic.com> * test(precompute): correctly interleave the mid-ingest flush in the still-active-pane test wall_clock_fallback_does_not_close_a_pane_still_receiving_samples ran all 8 touches before either flush_all() call, so the "mid-ingest" check never actually sat between two touches in wall-clock terms. Restructured to do 7 touches, the mid-ingest flush check, then the 8th touch, then the final flush -- so the check genuinely exercises "still receiving samples" instead of comparing against an already-completed touch. Also documents why no absolute wall-clock ceiling is enforced on a pane's lifetime (deferred by design, not an oversight). Interleaving the flush for real exposed a second, unrelated bug in the test helper: every flush_all() call unconditionally nudges the event-time watermark forward by 1ms (the "boundary advance" that lets an idle stream make progress), independent of the wall-clock fallback. With allowed_lateness_ms=0, that 1ms of drift alone marked the 8th touch "late" and dropped it via a wholly different code path. Set to 1 -- the exact amount one intervening flush contributes, not an arbitrary buffer. Co-Authored-By: Claude Sonnet 5 <noreply@anthropic.com> --------- Co-authored-by: Claude Sonnet 5 <noreply@anthropic.com>
1 parent 6b985fe commit 9a018cb

2 files changed

Lines changed: 152 additions & 27 deletions

File tree

asap-query-engine/src/precompute_engine/config.rs

Lines changed: 7 additions & 3 deletions
Original file line numberDiff line numberDiff line change
@@ -34,9 +34,13 @@ pub struct PrecomputeEngineConfig {
3434
/// `flush_all`. When event-time stagnates (e.g. a one-shot batch where
3535
/// every record carries the same timestamp), `flush_all`'s `+1ms`
3636
/// watermark advance is a no-op and idle windows never close. The
37-
/// wall-clock fallback closes a pane whose creation has been older
38-
/// than `window_size_ms + wall_clock_grace_period_ms` of *wall-clock*
39-
/// time, regardless of where event-time is. The grace period tolerates
37+
/// wall-clock fallback closes a pane that has gone *idle* — untouched by
38+
/// a sample — for `window_size_ms + wall_clock_grace_period_ms` of
39+
/// *wall-clock* time, regardless of where event-time is. A pane still
40+
/// actively receiving samples is never force-closed this way, no matter
41+
/// how long it's been open (e.g. a bulk load whose rows all share one
42+
/// event-time and takes longer than the grace period to ingest keeps its
43+
/// window open for the duration of the load). The grace period tolerates
4044
/// late-arriving events that would otherwise be evicted as "the window
4145
/// already closed". Set to `<= 0` to opt out and keep strict
4246
/// event-time-only semantics. Default: 5000 ms (matches

asap-query-engine/src/precompute_engine/worker.rs

Lines changed: 145 additions & 24 deletions
Original file line numberDiff line numberDiff line change
@@ -29,22 +29,34 @@ struct GroupState {
2929
/// series in this group on this worker.
3030
previous_watermark_ms: i64,
3131
/// Wall-clock-time (ms since epoch) at which each currently-open pane
32-
/// was first opened. Used by `flush_all`'s wall-clock fallback to
33-
/// close panes that have been alive too long when event-time has
34-
/// stagnated. Keyed by `pane_start_ms`, mirroring `active_panes`.
35-
/// Entries are GC'd by `prune_pane_wall_clock_starts` after each
36-
/// window-close cycle so the bookkeeping doesn't leak as panes turn over.
37-
pane_wall_clock_starts_ms: BTreeMap<i64, i64>,
32+
/// was last touched by a sample. Refreshed on every touch, not just the
33+
/// first. Used by `flush_all`'s wall-clock fallback to close panes that
34+
/// have been *idle* too long when event-time has stagnated — a pane
35+
/// still receiving samples is never "too old," no matter how long it's
36+
/// been open, only a pane nothing has touched in a while is. Keyed by
37+
/// `pane_start_ms`, mirroring `active_panes`. Entries are GC'd by
38+
/// `prune_pane_wall_clock_last_touch` after each window-close cycle so
39+
/// the bookkeeping doesn't leak as panes turn over.
40+
///
41+
/// No absolute ceiling on pane lifetime is enforced here by design: a
42+
/// pane touched forever without ever going idle (e.g. a misbehaving
43+
/// source stuck emitting a stagnant timestamp at a low but nonzero rate)
44+
/// stays open, growing memory, until process shutdown force-closes it
45+
/// via `force_close_all`. Deferred rather than bolted on speculatively —
46+
/// distinct failure mode from the bulk-load case this field fixes, with
47+
/// no evidence it happens in practice. Add `now - first_touch >= max_ms`
48+
/// if it does.
49+
pane_wall_clock_last_touch_ms: BTreeMap<i64, i64>,
3850
}
3951

4052
impl GroupState {
41-
/// Drop wall-clock-start entries whose pane no longer exists in
53+
/// Drop wall-clock-last-touch entries whose pane no longer exists in
4254
/// `active_panes`. Called after window-close cycles in
4355
/// `process_group_samples` and `flush_all` so the bookkeeping doesn't
4456
/// leak as panes turn over.
45-
fn prune_pane_wall_clock_starts(&mut self) {
57+
fn prune_pane_wall_clock_last_touch(&mut self) {
4658
let active = &self.active_panes;
47-
self.pane_wall_clock_starts_ms
59+
self.pane_wall_clock_last_touch_ms
4860
.retain(|ps, _| active.contains_key(ps));
4961
}
5062
}
@@ -352,7 +364,7 @@ impl Worker {
352364
config,
353365
active_panes: BTreeMap::new(),
354366
previous_watermark_ms: i64::MIN,
355-
pane_wall_clock_starts_ms: BTreeMap::new(),
367+
pane_wall_clock_last_touch_ms: BTreeMap::new(),
356368
};
357369
self.group_states
358370
.entry(agg_id)
@@ -456,13 +468,15 @@ impl Worker {
456468
}
457469

458470
// Normal path: route sample to its single pane accumulator.
459-
// Record the pane's wall-clock birth time the first time we
460-
// touch it, so the wall-clock fallback in `flush_all` can age
461-
// it out even if event-time freezes.
471+
// Refresh the pane's last-touch wall-clock time on every touch
472+
// (not just the first) so the wall-clock fallback in `flush_all`
473+
// only ages out panes that have gone idle, never a pane still
474+
// actively receiving samples — e.g. a bulk load whose rows all
475+
// share one event-time and take longer than the grace period to
476+
// ingest must not have its window force-closed mid-ingest.
462477
state
463-
.pane_wall_clock_starts_ms
464-
.entry(pane_start)
465-
.or_insert(now_ms);
478+
.pane_wall_clock_last_touch_ms
479+
.insert(pane_start, now_ms);
466480
let updater = match state.active_panes.entry(pane_start) {
467481
std::collections::btree_map::Entry::Occupied(e) => e.into_mut(),
468482
std::collections::btree_map::Entry::Vacant(e) => {
@@ -494,7 +508,7 @@ impl Worker {
494508
}
495509

496510
state.previous_watermark_ms = current_wm;
497-
state.prune_pane_wall_clock_starts();
511+
state.prune_pane_wall_clock_last_touch();
498512

499513
// Emit to output sink
500514
if !emit_batch.is_empty() {
@@ -595,14 +609,19 @@ impl Worker {
595609
// freezes and `closed_windows(prev, prev+1)` returns empty
596610
// forever — the window never closes and the store stays empty
597611
// even though data has been ingested. Force `effective_wm`
598-
// past `pane_start + window_size_ms` for any pane older than
599-
// `window_size + grace` of WALL-CLOCK time. Set
612+
// past `pane_start + window_size_ms` for any pane that has
613+
// gone *idle* — untouched by a sample — for `window_size +
614+
// grace` of WALL-CLOCK time. This deliberately does NOT
615+
// trigger for a pane still actively receiving samples (e.g. a
616+
// bulk load taking longer than the grace period to ingest):
617+
// `pane_wall_clock_last_touch_ms` is refreshed on every touch,
618+
// so only silence, not age, ages a pane out. Set
600619
// `wall_clock_grace_period_ms <= 0` to opt out and keep strict
601620
// event-time semantics.
602621
if grace_ms > 0 {
603622
let window_size_ms = state.window_manager.window_size_ms();
604-
for (&pane_start, &pane_birth_ms) in &state.pane_wall_clock_starts_ms {
605-
if now_ms.saturating_sub(pane_birth_ms) >= window_size_ms + grace_ms {
623+
for (&pane_start, &pane_last_touch_ms) in &state.pane_wall_clock_last_touch_ms {
624+
if now_ms.saturating_sub(pane_last_touch_ms) >= window_size_ms + grace_ms {
606625
let force_to = pane_start.saturating_add(window_size_ms);
607626
if force_to > effective_wm {
608627
effective_wm = force_to;
@@ -641,7 +660,7 @@ impl Worker {
641660
state.previous_watermark_ms = effective_wm;
642661
}
643662

644-
state.prune_pane_wall_clock_starts();
663+
state.prune_pane_wall_clock_last_touch();
645664
}
646665
}
647666

@@ -720,7 +739,7 @@ impl Worker {
720739
if force_wm > state.previous_watermark_ms {
721740
state.previous_watermark_ms = force_wm;
722741
}
723-
state.prune_pane_wall_clock_starts();
742+
state.prune_pane_wall_clock_last_touch();
724743
}
725744
}
726745

@@ -2845,7 +2864,16 @@ aggregations:
28452864
arc_configs(agg_configs),
28462865
WorkerRuntimeConfig {
28472866
max_buffer_per_series: 10_000,
2848-
allowed_lateness_ms: 0,
2867+
// 1, not 0: every flush_all() call unconditionally nudges the
2868+
// event-time watermark forward by 1ms (the "+1ms boundary
2869+
// advance" that lets an idle stream make progress),
2870+
// independent of the wall-clock fallback these tests target.
2871+
// A test that calls flush_all() and then processes another
2872+
// same-timestamp touch would otherwise have that 1ms of
2873+
// drift alone mark the touch "late" and drop it via a wholly
2874+
// different code path. 1ms is the exact amount one
2875+
// intervening flush contributes, not an arbitrary buffer.
2876+
allowed_lateness_ms: 1,
28492877
pass_raw_samples: false,
28502878
raw_mode_aggregation_id: 0,
28512879
late_data_policy: LateDataPolicy::Drop,
@@ -2925,6 +2953,99 @@ aggregations:
29252953
assert_eq!(sink.len(), 0, "already-closed window must not re-emit");
29262954
}
29272955

2956+
// Regression test for issue #474: a bulk one-shot load whose rows all
2957+
// share one event-time can take longer than `window_size_ms +
2958+
// wall_clock_grace_period_ms` to ingest. Before the fix, the wall-clock
2959+
// fallback measured age since a pane was *first* touched, so it force-
2960+
// closed the window mid-ingest and every sample arriving afterward hit
2961+
// the (hardcoded-Drop) late-data path — a silent, uniform undercount.
2962+
// The fix refreshes the pane's wall-clock bookkeeping on every touch, so
2963+
// the fallback only fires once a pane has gone genuinely idle.
2964+
#[test]
2965+
fn wall_clock_fallback_does_not_close_a_pane_still_receiving_samples() {
2966+
// Production defaults: 1s tumbling window, 5s grace ⇒ old birth-time
2967+
// deadline was window_size + grace = 6s.
2968+
let cfg = make_agg_config(
2969+
7,
2970+
"netflow_bytes",
2971+
AggregationType::SingleSubpopulation,
2972+
"Sum",
2973+
1_000,
2974+
0,
2975+
vec![],
2976+
);
2977+
let agg_configs = HashMap::from([(7, cfg)]);
2978+
let sink = Arc::new(CapturingOutputSink::new());
2979+
let mut worker = make_worker_with_grace(agg_configs, sink.clone(), 5_000);
2980+
2981+
let wall_clock = Arc::new(AtomicI64::new(1_000_000));
2982+
let wc_clone = wall_clock.clone();
2983+
worker.set_now_ms_fn(Box::new(move || wc_clone.load(Ordering::Relaxed)));
2984+
2985+
// Every sample shares event-time 0 (the degenerate bulk-load case),
2986+
// but the pane is touched once per simulated wall-clock second for
2987+
// 7 seconds straight — actively receiving data the whole time.
2988+
let mut expected_sum = 0.0;
2989+
for i in 0..7 {
2990+
wall_clock.store(1_000_000 + i * 1_000, Ordering::Relaxed);
2991+
let val = 1.0 + i as f64;
2992+
expected_sum += val;
2993+
worker
2994+
.process_group_samples(7, "", group_samples("netflow_bytes", vec![(0, val)]))
2995+
.expect("ingest must accept frozen-event-time samples");
2996+
}
2997+
2998+
// Flush at wall_clock = birth(1_000_000) + 6_500ms — past the OLD
2999+
// birth-time deadline of birth + window_size + grace = 1_006_000,
3000+
// but the pane was last touched at 1_006_000 (i=6), only 500ms ago.
3001+
// A pane still this fresh must not be force-closed.
3002+
wall_clock.store(1_000_000 + 6_500, Ordering::Relaxed);
3003+
worker.flush_all().unwrap();
3004+
assert_eq!(
3005+
sink.len(),
3006+
0,
3007+
"a pane still actively receiving samples must not be force-closed \
3008+
just because it has been open longer than window_size + grace"
3009+
);
3010+
3011+
// Ingest continues past the mid-ingest check: an 8th touch lands at
3012+
// wall_clock = 1_007_000, refreshing last-touch again.
3013+
wall_clock.store(1_000_000 + 7_000, Ordering::Relaxed);
3014+
let val = 1.0 + 7_f64;
3015+
expected_sum += val;
3016+
worker
3017+
.process_group_samples(7, "", group_samples("netflow_bytes", vec![(0, val)]))
3018+
.expect("ingest must accept frozen-event-time samples");
3019+
3020+
// Ingest stops after the 8th touch (wall_clock = 1_007_000). Advance
3021+
// past last_touch + window_size + grace and flush: NOW the fallback
3022+
// must close the window, with every sample's contribution intact.
3023+
wall_clock.store(1_000_000 + 7_000 + 1_000 + 5_000 + 1, Ordering::Relaxed);
3024+
worker.flush_all().unwrap();
3025+
3026+
let captured = sink.drain();
3027+
assert_eq!(
3028+
captured.len(),
3029+
1,
3030+
"pane must close once it actually goes idle, with no data lost \
3031+
from any of the 8 touches"
3032+
);
3033+
let (output, acc) = &captured[0];
3034+
assert_eq!(output.aggregation_id, 7);
3035+
assert_eq!(output.start_timestamp, 0);
3036+
assert_eq!(output.end_timestamp, 1_000);
3037+
let sum_acc = acc
3038+
.as_any()
3039+
.downcast_ref::<SumAccumulator>()
3040+
.expect("Sum aggregation should emit a SumAccumulator");
3041+
assert!(
3042+
(sum_acc.sum - expected_sum).abs() < 1e-9,
3043+
"expected all 8 touches merged: expected {}, got {}",
3044+
expected_sum,
3045+
sum_acc.sum
3046+
);
3047+
}
3048+
29283049
#[test]
29293050
fn wall_clock_fallback_disabled_preserves_event_time_only_semantics() {
29303051
let cfg = make_agg_config(

0 commit comments

Comments
 (0)