Skip to content
Merged
Show file tree
Hide file tree
Changes from all commits
Commits
File filter

Filter by extension

Filter by extension

Conversations
Failed to load comments.
Loading
Jump to
Jump to file
Failed to load files.
Loading
Diff view
Diff view
65 changes: 65 additions & 0 deletions crates/stella-serve/src/observe/event.rs
Original file line number Diff line number Diff line change
Expand Up @@ -555,6 +555,58 @@ pub struct TurnTally {
/// operator can tell "the client is gone" from "the turn was quiet".
#[serde(default, skip_serializing_if = "is_zero_u64")]
pub frames_dropped: u64,

/// Parked waits this turn opened (`AgentEvent::TurnParked`, #1471/#1857).
///
/// This is the field that keeps [`Self::stages`] honest. A parked turn
/// stops advancing stages **on purpose** — it is probing external state on
/// the engine's own clock, with zero model calls, until the state changes
/// or the deadline expires. Without this count a host reading a
/// stages-stall cannot tell a deliberate wait from a hang, which is the
/// one question the tally exists to answer (#2006).
#[serde(default, skip_serializing_if = "is_zero_u32")]
pub parked_spans: u32,
/// Parked waits that closed with an `AgentEvent::TurnWoken`.
///
/// Deliberately counted apart from [`Self::parked_spans`] rather than
/// assumed equal to it: the engine's park loop returns early — without a
/// wake — when the turn is cancelled or a soft stop is latched
/// (`stella-core::driver::waiting`). So a turn can settle with a span
/// still open, and "ended while parked" is a different diagnosis from
/// "parked and resumed". See [`Self::ended_parked`].
#[serde(default, skip_serializing_if = "is_zero_u32")]
pub parked_spans_woken: u32,
/// Engine-side probes spent while parked, summed from
/// `AgentEvent::TurnWoken.polls_used`.
///
/// The park's own progress axis — the direct analogue of [`Self::stages`]
/// for a turn that is deliberately making no stage progress. A park whose
/// probes are climbing is working; one at zero probes woke immediately.
#[serde(default, skip_serializing_if = "is_zero_u64")]
pub parked_polls: u64,
/// Seconds this turn was *licensed* to sit still — the sum of every
/// span's `AgentEvent::TurnParked.deadline_secs`.
///
/// The duration half of the wedged-versus-waiting question, and the only
/// honest one this fold can produce: it counts, it does not read a clock,
/// so elapsed park time is not available here. A 30-minute stall under a
/// 1800s licence is the wait working as designed; the same stall with
/// this at zero is a hang.
#[serde(default, skip_serializing_if = "is_zero_u64")]
pub parked_deadline_secs: u64,
}

impl TurnTally {
/// Whether the turn settled with a parked wait still open — a span that
/// never saw its `TurnWoken` because the turn was cancelled or soft-stopped
/// out of the park.
///
/// The distinction a host wants when `stages` has not moved: `true` means
/// the turn ended *in* the wait, `false` with [`Self::parked_spans`]
/// non-zero means it waited and came back.
pub fn ended_parked(&self) -> bool {
self.parked_spans > self.parked_spans_woken
}
}

/// `skip_serializing_if` for a counter that is zero on every healthy turn —
Expand All @@ -563,6 +615,12 @@ fn is_zero_u64(n: &u64) -> bool {
*n == 0
}

/// [`is_zero_u64`]'s twin for the `u32` counters — same contract: a turn that
/// never parked serializes exactly as it did before park accounting existed.
fn is_zero_u32(n: &u32) -> bool {
*n == 0
}

/// One thing the server did, at a boundary.
#[derive(Debug, Clone, PartialEq, Serialize, Deserialize)]
#[serde(tag = "event", rename_all = "snake_case")]
Expand Down Expand Up @@ -902,6 +960,13 @@ mod tests {
speculation_discarded: 1,
loop_detections: 0,
frames_dropped: 0,
// Non-zero so the round trip actually exercises the park
// counters: their `skip_serializing_if` means a zeroed
// tally would prove nothing about them.
parked_spans: 2,
parked_spans_woken: 1,
parked_polls: 37,
parked_deadline_secs: 2400,
},
},
];
Expand Down
25 changes: 25 additions & 0 deletions crates/stella-serve/src/observe/metrics.rs
Original file line number Diff line number Diff line change
Expand Up @@ -74,6 +74,15 @@ pub struct Metrics {
tools_failed_total: AtomicU64,
speculation_discarded_total: AtomicU64,
loop_detections_total: AtomicU64,
/// Parked waits opened across all settled turns (#2006). Without it a
/// scrape sees `model_calls_total` flat and `turn_duration_ms_total`
/// climbing and has no way to tell a fleet that is waiting on external
/// state from one that is stuck — the same blind spot `TurnTally` closes
/// one layer down.
parked_spans_total: AtomicU64,
/// Seconds those spans were licensed to sit still — the denominator that
/// makes a long, quiet turn defensible rather than alarming.
parked_deadline_secs_total: AtomicU64,

reverse_dispatched_provider_total: AtomicU64,
reverse_dispatched_tool_total: AtomicU64,
Expand Down Expand Up @@ -139,6 +148,8 @@ pub struct Snapshot {
pub tools_failed_total: u64,
pub speculation_discarded_total: u64,
pub loop_detections_total: u64,
pub parked_spans_total: u64,
pub parked_deadline_secs_total: u64,

pub reverse_dispatched_provider_total: u64,
pub reverse_dispatched_tool_total: u64,
Expand Down Expand Up @@ -211,6 +222,8 @@ impl Metrics {
tools_failed_total: self.tools_failed_total.load(ORDER),
speculation_discarded_total: self.speculation_discarded_total.load(ORDER),
loop_detections_total: self.loop_detections_total.load(ORDER),
parked_spans_total: self.parked_spans_total.load(ORDER),
parked_deadline_secs_total: self.parked_deadline_secs_total.load(ORDER),

reverse_dispatched_provider_total: self.reverse_dispatched_provider_total.load(ORDER),
reverse_dispatched_tool_total: self.reverse_dispatched_tool_total.load(ORDER),
Expand Down Expand Up @@ -316,6 +329,10 @@ impl Observer for Metrics {
.fetch_add(u64::from(tally.speculation_discarded), ORDER);
self.loop_detections_total
.fetch_add(u64::from(tally.loop_detections), ORDER);
self.parked_spans_total
.fetch_add(u64::from(tally.parked_spans), ORDER);
self.parked_deadline_secs_total
.fetch_add(tally.parked_deadline_secs, ORDER);
}
ServeEvent::TurnReclaimed { .. } => {
self.turns_reclaimed_total.fetch_add(1, ORDER);
Expand Down Expand Up @@ -555,6 +572,10 @@ mod tests {
speculation_discarded: 4,
loop_detections: 1,
frames_dropped: 0,
parked_spans: 2,
parked_spans_woken: 1,
parked_polls: 60,
parked_deadline_secs: 2400,
},
});
let snap = metrics.snapshot();
Expand All @@ -567,6 +588,10 @@ mod tests {
assert_eq!(snap.tools_failed_total, 1);
assert_eq!(snap.speculation_discarded_total, 4);
assert_eq!(snap.loop_detections_total, 1);
// A scrape that cannot see the parks reads this turn's quiet stretch
// as a stall (#2006).
assert_eq!(snap.parked_spans_total, 2);
assert_eq!(snap.parked_deadline_secs_total, 2400);
}

/// The registry gauge tracks occupancy, and refusals are separated by
Expand Down
106 changes: 106 additions & 0 deletions crates/stella-serve/src/observe/tally.rs
Original file line number Diff line number Diff line change
Expand Up @@ -75,6 +75,27 @@ impl TallyFold {
AgentEvent::LoopDetected { .. } => {
tally.loop_detections = tally.loop_detections.saturating_add(1);
}
// The park axis (#1471, #1857) — the one signal that keeps
// `stages` honest. A parked turn stops advancing stages on
// purpose, so a host that cannot see the park reads a deliberate
// wait as a hang; the events were on this stream and this fold
// was dropping them (#2006). `description` is tool-authored free
// text and is deliberately NOT read here: this is a counter, and
// the crate's no-content property does not get an exception.
AgentEvent::TurnParked { deadline_secs, .. } => {
tally.parked_spans = tally.parked_spans.saturating_add(1);
tally.parked_deadline_secs =
tally.parked_deadline_secs.saturating_add(*deadline_secs);
}
// Counted apart from the park rather than assumed to match it: the
// engine's park loop returns without a wake when the turn is
// cancelled or soft-stopped, so a turn can settle mid-span and
// `TurnTally::ended_parked` is what tells the two apart. `reason`
// is a closed token, but the count is all this needs.
AgentEvent::TurnWoken { polls_used, .. } => {
tally.parked_spans_woken = tally.parked_spans_woken.saturating_add(1);
tally.parked_polls = tally.parked_polls.saturating_add(*polls_used);
}
// Everything else — text, deltas, reasoning, budget ticks — is
// either payload we deliberately never record or a signal with no
// counterpart here. `AgentEvent` is forward-compatible, so an
Expand Down Expand Up @@ -188,6 +209,91 @@ mod tests {
assert_eq!(fold.finish(), TurnTally::default());
}

fn parked(description: &str, deadline_secs: u64) -> AgentEvent {
AgentEvent::TurnParked {
description: description.to_string(),
poll_interval_secs: 30,
deadline_secs,
}
}

/// The witness for #2006. A turn that parked and resumed makes no stage
/// progress *on purpose*; before park accounting existed its tally was
/// byte-identical to a turn that simply stalled, so the one question the
/// tally exists to answer had no answer.
#[test]
fn a_parked_turn_is_distinguishable_from_a_wedged_one() {
let mut wedged = TallyFold::default();
wedged.observe(&AgentEvent::Stage {
name: StageKind::Execute,
});

let mut waiting = TallyFold::default();
waiting.observe(&AgentEvent::Stage {
name: StageKind::Execute,
});
waiting.observe(&parked("CI for branch main settles", 1800));
waiting.observe(&AgentEvent::TurnWoken {
reason: "changed".to_string(),
polls_used: 41,
});

let wedged = wedged.finish();
let waiting = waiting.finish();
assert_eq!(
wedged.stages, waiting.stages,
"the premise: both turns advanced exactly one stage"
);
assert_ne!(
wedged, waiting,
"a park must leave a mark, or a deliberate wait reads as a hang"
);
assert_eq!(waiting.parked_spans, 1);
assert_eq!(waiting.parked_spans_woken, 1);
assert_eq!(waiting.parked_polls, 41);
assert_eq!(
waiting.parked_deadline_secs, 1800,
"the licence to sit still is what makes the stall defensible"
);
assert!(
!waiting.ended_parked(),
"this park closed — the turn waited and came back"
);
assert!(
!wedged.ended_parked(),
"a turn that never parked never ends parked"
);
}

/// The engine's park loop returns *without* a `TurnWoken` when the turn is
/// cancelled or a soft stop is latched, so the two counts genuinely
/// diverge and the open span is the sharper diagnosis.
#[test]
fn a_turn_that_settles_mid_park_leaves_the_span_open() {
let mut fold = TallyFold::default();
fold.observe(&parked("the deploy finishes", 600));
let tally = fold.finish();
assert_eq!(tally.parked_spans, 1);
assert_eq!(tally.parked_spans_woken, 0);
assert!(
tally.ended_parked(),
"a span with no wake means the turn ended inside the wait"
);
}

/// The park is counted, never quoted. `TurnParked.description` is
/// tool-authored free text, and the same rule that keeps `Text` out of
/// this fold keeps it out too — two parks that differ only in their prose
/// must be indistinguishable here.
#[test]
fn the_park_description_never_reaches_the_tally() {
let mut one = TallyFold::default();
one.observe(&parked("CI for branch main settles", 900));
let mut other = TallyFold::default();
other.observe(&parked("s3://bucket/customer-export.csv appears", 900));
assert_eq!(one.finish(), other.finish());
}

/// The fold must survive a turn long enough to overflow a `u32` counter
/// without panicking in a release-mode-divergent way.
#[test]
Expand Down
Loading