Skip to main content

keelrun_core/
engine.rs

1//! The engine: per-target state machines on real (tokio) time, orchestrating
2//! the fixed layer chain cache → rate → breaker → timeout → retry.
3//! Normative semantics: `conformance/README.md`; envelope types:
4//! `contracts/core_api.rs`.
5
6use core::fmt;
7use std::collections::{BTreeMap, HashMap, VecDeque};
8use std::sync::{Arc, Mutex, MutexGuard, RwLock};
9use std::time::Duration;
10
11use keel_core_api::policy::{
12    BreakerMode, BreakerPolicy, CacheScope, DurationMs, JournalLocation, NondeterminismResponse,
13    Policy, Rate, ResolvedPolicy, RetryPolicy,
14};
15use keel_core_api::{
16    AttemptResult, BreakerState, ENVELOPE_VERSION, ErrorClass, ErrorCode, KeelError, Outcome,
17    OutcomeError, Request,
18};
19use keel_journal::{
20    CacheKey as JournalCacheKey, CallObservation, CallResult, Clock, DiscoveryStore, Journal,
21    ObservedError,
22};
23use serde::{Deserialize, Serialize};
24use serde_json::Value;
25use tokio::time::Instant;
26use tracing::{Instrument, debug, warn};
27
28use crate::events::{CacheStore, EventKind, EventSink, TraceRef};
29use crate::journal_backend::{self, JournalBackend};
30
31/// Circuit breaker in count mode (consecutive terminal failures) or rate mode
32/// (failure rate over a sliding window; `BreakerPolicy::mode` selects).
33/// Observes post-retry call outcomes — layer order puts it outside the retry
34/// loop. Normative semantics: conformance/README.md §4.
35#[derive(Debug, Default)]
36struct Breaker {
37    /// Count mode: consecutive terminal failures.
38    consecutive: u64,
39    /// Rate mode: post-retry outcomes `(completed_at, failed)` inside the
40    /// trailing window, oldest first. Pruned on every observation; cleared
41    /// when the breaker opens or a probe closes it.
42    outcomes: VecDeque<(Instant, bool)>,
43    open_until: Option<Instant>,
44    opens: u64,
45}
46
47/// What the breaker decided before a call was attempted.
48#[derive(Debug, Clone, Copy, PartialEq, Eq)]
49enum Admission {
50    Closed,
51    /// Cooldown elapsed: exactly one probe is admitted.
52    HalfOpen,
53    /// Still open: fail fast, do not invoke the effect.
54    Rejected,
55}
56
57/// A breaker state change worth surfacing as a telemetry event. Pure
58/// observability — the value never influences an outcome or the report; it
59/// exists only so the caller can emit a `tracing` event off the state lock.
60#[derive(Debug, Clone, Copy, PartialEq, Eq)]
61enum BreakerTransition {
62    /// No edge was crossed by this call.
63    None,
64    /// The breaker tripped OPEN (threshold reached, or a probe failed).
65    Opened,
66    /// A successful probe closed a previously-open breaker.
67    Closed,
68}
69
70impl Breaker {
71    fn admit(&self, now: Instant) -> Admission {
72        match self.open_until {
73            Some(until) if now < until => Admission::Rejected,
74            Some(_) => Admission::HalfOpen,
75            None => Admission::Closed,
76        }
77    }
78
79    fn state_at(&self, now: Instant) -> BreakerState {
80        match self.admit(now) {
81            Admission::Rejected => BreakerState::Open,
82            Admission::Closed | Admission::HalfOpen => BreakerState::Closed,
83        }
84    }
85
86    fn on_success(&mut self, now: Instant, config: &BreakerPolicy) -> BreakerTransition {
87        // A live success is only reached while closed or half-open; an open
88        // breaker fails fast (never runs the effect). So `open_until.is_some()`
89        // here means a probe just closed the breaker.
90        let closed_a_probe = self.open_until.is_some();
91        self.consecutive = 0;
92        self.open_until = None;
93        if closed_a_probe {
94            // A closing probe resets the window: the pre-open failure history
95            // must not instantly re-trip a freshly-recovered target.
96            self.outcomes.clear();
97            return BreakerTransition::Closed;
98        }
99        if let BreakerMode::Rate { window, .. } = config.mode() {
100            self.observe(now, window, false);
101        }
102        BreakerTransition::None
103    }
104
105    fn on_terminal_failure(
106        &mut self,
107        now: Instant,
108        config: &BreakerPolicy,
109        admission: Admission,
110    ) -> BreakerTransition {
111        let should_trip = if admission == Admission::HalfOpen {
112            true // failed probe: re-open for another full cooldown
113        } else {
114            match config.mode() {
115                BreakerMode::Count { failures } => {
116                    self.consecutive += 1;
117                    self.consecutive >= failures.get()
118                }
119                BreakerMode::Rate {
120                    window,
121                    failure_rate,
122                    min_calls,
123                } => {
124                    self.observe(now, window, true);
125                    self.window_rate_reached(failure_rate, min_calls)
126                }
127            }
128        };
129        if should_trip {
130            self.open_until = Some(now + Duration::from_millis(config.cooldown.0));
131            self.opens += 1;
132            self.consecutive = 0;
133            self.outcomes.clear();
134            BreakerTransition::Opened
135        } else {
136            BreakerTransition::None
137        }
138    }
139
140    /// Rate mode: prune outcomes that aged out of the window (strictly: an
141    /// outcome exactly `window` old is evicted, per conformance/README.md §4),
142    /// then record this one.
143    fn observe(&mut self, now: Instant, window: DurationMs, failed: bool) {
144        let window = Duration::from_millis(window.0);
145        while let Some(&(at, _)) = self.outcomes.front() {
146            if now.duration_since(at) >= window {
147                self.outcomes.pop_front();
148            } else {
149                break;
150            }
151        }
152        self.outcomes.push_back((now, failed));
153    }
154
155    /// Rate mode's trip condition over the (already-pruned) window.
156    fn window_rate_reached(&self, failure_rate: f64, min_calls: core::num::NonZeroU32) -> bool {
157        let total = self.outcomes.len();
158        if (total as u64) < u64::from(min_calls.get()) {
159            return false;
160        }
161        let failed = self.outcomes.iter().filter(|&&(_, f)| f).count();
162        #[expect(
163            clippy::cast_precision_loss,
164            reason = "window counts are bounded by the calls observed within one \
165                      breaker window — far below f64's 2^53 exact-integer range"
166        )]
167        let rate = failed as f64 / total as f64;
168        rate >= failure_rate
169    }
170}
171
172/// Token-bucket rate limiter over engine-elapsed milliseconds (dx-spec §4.1
173/// promises token-bucket rate limiting), bit-identical to every stub (parity
174/// rule — `crates/keel-core-stub`, `python/keel-core-stub`,
175/// `node/keel-core-stub`). Burst capacity is the rate's `limit`; refill is
176/// continuous at `limit` per `window`. Exceeding the rate delays the call
177/// (`throttled`), never fails it.
178///
179/// All arithmetic is integer fixed-point — token amounts are scaled by
180/// `window_ms`, so one token is `window_ms` scaled units and refill is exactly
181/// `limit` scaled units per elapsed millisecond. No float drift: identical
182/// call timings plan identical waits, so conformance scenarios may assert the
183/// exact `throttle_wait_ms` (conformance/README.md §3).
184#[derive(Debug, Default)]
185struct TokenBucket {
186    /// Tokens in scaled units (1 token = `window_ms` units). Negative means
187    /// admissions were already booked ahead of refill — queued waiters, each
188    /// spaced `window/limit` apart.
189    scaled_tokens: i128,
190    /// Engine-elapsed ms of the last refill.
191    last_refill_ms: u64,
192    /// Whether the bucket has been filled to burst on first use (a `Default`
193    /// bucket cannot know the rate yet).
194    primed: bool,
195}
196
197impl TokenBucket {
198    /// Plans one admission at `elapsed_ms`, pre-booking the token the call
199    /// will consume after sleeping. Returns the wait (0 = immediate): the time
200    /// until continuous refill covers this booking's deficit.
201    fn plan_admit(&mut self, elapsed_ms: u64, rate: Rate) -> u64 {
202        let limit = i128::from(rate.limit.get());
203        let window = i128::from(rate.window_ms);
204        let capacity = limit * window; // burst = `limit` whole tokens
205        if !self.primed {
206            self.primed = true;
207            self.scaled_tokens = capacity;
208            self.last_refill_ms = elapsed_ms;
209        }
210        // Concurrent planners may observe `elapsed_ms` before taking the state
211        // lock, so a reading older than the last refill credits nothing.
212        let elapsed = i128::from(elapsed_ms.saturating_sub(self.last_refill_ms));
213        self.last_refill_ms = self.last_refill_ms.max(elapsed_ms);
214        self.scaled_tokens = capacity.min(
215            self.scaled_tokens
216                .saturating_add(elapsed.saturating_mul(limit)),
217        );
218        self.scaled_tokens -= window;
219        if self.scaled_tokens >= 0 {
220            0
221        } else {
222            // ceil(deficit / refill-per-ms)
223            let deficit = -self.scaled_tokens;
224            u64::try_from((deficit + limit - 1) / limit).unwrap_or(u64::MAX)
225        }
226    }
227}
228
229#[derive(Debug, Clone, PartialEq, Eq, Hash)]
230struct CacheKey {
231    target: String,
232    args_hash: String,
233}
234
235#[derive(Debug, Clone)]
236struct CacheEntry {
237    expires_at: Instant,
238    payload: Value,
239}
240
241/// Self-describing tag stamped into every persistent cache payload, so a future
242/// reader (`keel trace`, a schema migration, a foreign tool) can tell the
243/// encoding and its version apart from a bare value — journal.sql specifies the
244/// `cache.value` blob as "MessagePack, schema-tagged".
245const CACHE_PAYLOAD_SCHEMA: &str = "keel.cache/v1";
246
247/// The schema-tagged envelope the persistent cache stores. Written by reference
248/// so the payload is never cloned on the hot write path.
249#[derive(Serialize)]
250struct CachePayloadRef<'a> {
251    schema: &'a str,
252    payload: &'a Value,
253}
254
255/// The owned form read back from the journal, before its tag is verified.
256#[derive(Deserialize)]
257struct CachePayloadOwned {
258    schema: String,
259    payload: Value,
260}
261
262/// MessagePack-encode a cache payload with its schema tag.
263fn encode_cache_payload(payload: &Value) -> Result<Vec<u8>, rmp_serde::encode::Error> {
264    rmp_serde::to_vec_named(&CachePayloadRef {
265        schema: CACHE_PAYLOAD_SCHEMA,
266        payload,
267    })
268}
269
270/// Decode a schema-tagged cache payload. A codec failure or an unrecognized tag
271/// returns a reason string, so the read path can degrade to a miss rather than
272/// surfacing a poisoned entry to the caller.
273fn decode_cache_payload(bytes: &[u8]) -> Result<Value, String> {
274    let envelope: CachePayloadOwned =
275        rmp_serde::from_slice(bytes).map_err(|e| format!("messagepack decode failed: {e}"))?;
276    if envelope.schema != CACHE_PAYLOAD_SCHEMA {
277        return Err(format!(
278            "unrecognized cache payload schema {:?}",
279            envelope.schema
280        ));
281    }
282    Ok(envelope.payload)
283}
284
285/// Which cache backend serves a call, decided once per `execute`. `Persistent`
286/// is chosen only when the policy asks for it *and* a journal is attached;
287/// otherwise the in-memory `Memory` path keeps the engine fully functional
288/// un-journaled.
289#[derive(Debug)]
290enum CachePlan {
291    None,
292    Memory {
293        key: CacheKey,
294    },
295    Persistent {
296        key: JournalCacheKey,
297        ttl: DurationMs,
298    },
299}
300
301/// The discovery-recording surface the engine depends on: a single method, so
302/// the engine can hold a [`DiscoveryStore`] type-erased regardless of the
303/// [`Clock`] it was opened with. Implemented for every `DiscoveryStore<C>`.
304pub trait DiscoveryRecorder: Send + Sync {
305    /// Fold one observed call into the store; the error is the journal's own.
306    fn record(&self, observation: &CallObservation) -> keel_journal::Result<()>;
307}
308
309impl<C: Clock> DiscoveryRecorder for DiscoveryStore<C> {
310    fn record(&self, observation: &CallObservation) -> keel_journal::Result<()> {
311        DiscoveryStore::record(self, observation)
312    }
313}
314
315#[derive(Debug, Default)]
316struct TargetMetrics {
317    calls: u64,
318    attempts: u64,
319    retries: u64,
320    successes: u64,
321    failures: u64,
322    cache_hits: u64,
323    throttled: u64,
324}
325
326/// One target's row in the `keel_report` document (frozen report contract;
327/// `successes` includes cache hits, `failures` includes breaker rejections).
328#[derive(Debug, Serialize)]
329struct TargetReport {
330    attempts: u64,
331    breaker_opens: u64,
332    breaker_state: BreakerState,
333    cache_hits: u64,
334    calls: u64,
335    failures: u64,
336    retries: u64,
337    successes: u64,
338    throttled: u64,
339}
340
341#[derive(Debug, Serialize)]
342struct Report<'a> {
343    v: u32,
344    clock_ms: u64,
345    targets: BTreeMap<&'a str, TargetReport>,
346}
347
348#[derive(Debug, Default)]
349struct State {
350    trace_seq: u64,
351    breakers: HashMap<String, Breaker>,
352    rate_buckets: HashMap<String, TokenBucket>,
353    cache: HashMap<CacheKey, CacheEntry>,
354    metrics: BTreeMap<String, TargetMetrics>,
355}
356
357impl State {
358    fn metrics_for(&mut self, target: &str) -> &mut TargetMetrics {
359        self.metrics.entry(target.to_owned()).or_default()
360    }
361
362    fn breaker_state(&self, target: &str, now: Instant) -> BreakerState {
363        self.breakers
364            .get(target)
365            .map_or(BreakerState::Closed, |b| b.state_at(now))
366    }
367}
368
369/// The result of one attempt, tagged with whether the policy timeout layer
370/// (not the adapter) produced the failure — that origin is what turns a
371/// terminal outcome into `KEEL-E011`.
372#[derive(Debug)]
373struct AttemptOutcome {
374    result: AttemptResult,
375    timed_out_by_layer: bool,
376}
377
378/// Why a failed attempt ended the call, per the normative decision order
379/// (conformance/README.md §5).
380fn terminal_code(
381    retryable: bool,
382    attempt: u32,
383    max_attempts: u32,
384    idempotent: bool,
385) -> Option<ErrorCode> {
386    if !retryable {
387        Some(ErrorCode::NonRetryableError)
388    } else if attempt == max_attempts {
389        Some(ErrorCode::AttemptsExhausted)
390    } else if !idempotent {
391        Some(ErrorCode::NonIdempotentNotRetried)
392    } else {
393        None
394    }
395}
396
397fn class_str(class: ErrorClass) -> &'static str {
398    match class {
399        ErrorClass::Conn => "conn",
400        ErrorClass::Timeout => "timeout",
401        ErrorClass::Http => "http",
402        ErrorClass::Cancelled => "cancelled",
403        ErrorClass::Other => "other",
404    }
405}
406
407/// Static label for a breaker state, matching its `snake_case` serialized form,
408/// so a span field reads the same as the report/journal.
409fn breaker_str(state: BreakerState) -> &'static str {
410    match state {
411        BreakerState::Closed => "closed",
412        BreakerState::Open => "open",
413        BreakerState::HalfOpen => "half_open",
414    }
415}
416
417/// Stamps the terminal outcome onto the `keel.call` span. Every field was
418/// declared `Empty` at span open, so on a disabled span each `record` is a
419/// no-op and the trivial accessors below cost effectively nothing — the
420/// disabled-callsite fast path telemetry must not perturb.
421fn record_call_fields(span: &tracing::Span, out: &Outcome) {
422    span.record("trace_id", out.trace_id.as_str());
423    span.record("result", out.result.as_str());
424    if let Some(error) = out.error.as_ref() {
425        span.record("error_code", error.code.as_str());
426    }
427    span.record("attempts", out.attempts);
428    span.record("from_cache", out.from_cache);
429    span.record("throttled", out.throttled);
430    span.record("breaker", breaker_str(out.breaker));
431}
432
433/// Emits a breaker state change at debug level and as a
434/// `keel.breaker.transitions` metric (architecture spec §4.5). Called off the
435/// state lock; a no-op when nothing changed.
436fn emit_breaker_transition(target: &str, transition: BreakerTransition) {
437    match transition {
438        BreakerTransition::Opened => {
439            debug!(target = %target, transition = "opened", "breaker transition");
440            crate::metrics::record_breaker_transition(target, "opened");
441        }
442        BreakerTransition::Closed => {
443            debug!(target = %target, transition = "closed", "breaker transition");
444            crate::metrics::record_breaker_transition(target, "closed");
445        }
446        BreakerTransition::None => {}
447    }
448}
449
450/// Warn (once per offending table) when a breaker sets `failures` alongside
451/// rate-mode knobs: the frozen schema's "setting `failures` selects count
452/// mode" makes window/failure_rate/min_calls inert, and inert config must be
453/// loud (the same rule `configure` applies to `journal`/`telemetry`).
454fn warn_inert_breaker_knobs(policy: &Policy) {
455    let defaults = &policy.defaults;
456    let tables = defaults
457        .outbound
458        .iter()
459        .map(|t| (String::from("defaults.outbound"), t))
460        .chain(
461            defaults
462                .llm
463                .iter()
464                .map(|t| (String::from("defaults.llm"), t)),
465        )
466        .chain(
467            policy
468                .target
469                .iter()
470                .map(|(name, t)| (format!("target.\"{name}\""), t)),
471        );
472    for (path, table) in tables {
473        if table
474            .breaker
475            .as_ref()
476            .is_some_and(BreakerPolicy::has_inert_rate_knobs)
477        {
478            warn!(
479                "policy {path}.breaker sets `failures` (count mode) alongside rate-mode knobs \
480                 (window/failure_rate/min_calls), which are inert in count mode. Remove \
481                 `failures` to select rate mode."
482            );
483        }
484    }
485}
486
487/// Append the dx-invariant-4 trace reference (`… trace: keel trace <ref>`) to
488/// a terminal failure message. `trace` is `Some` only while a live event sink
489/// minted a ref for this call, so without a sink — the conformance condition —
490/// every implementation stays message-identical (parity rule).
491fn with_trace_ref(message: String, trace: Option<&TraceRef>) -> String {
492    match trace {
493        Some(t) => {
494            let sep = if message.ends_with('.') { "" } else { "." };
495            format!("{message}{sep} trace: keel trace {t}")
496        }
497        None => message,
498    }
499}
500
501fn terminal_message(
502    code: ErrorCode,
503    request: &Request,
504    attempt: u32,
505    max_attempts: u32,
506    class: ErrorClass,
507    http_status: Option<u16>,
508    message: &str,
509) -> String {
510    let detail = match http_status {
511        Some(status) => format!("{} {status}", class_str(class)),
512        None => class_str(class).to_owned(),
513    };
514    let text = match code {
515        ErrorCode::Timeout => format!(
516            "{} exceeded its policy timeout on attempt {attempt}/{max_attempts}. {message}",
517            request.op
518        ),
519        ErrorCode::AttemptsExhausted => format!(
520            "{} failed {attempt}/{max_attempts} attempts (last: {detail}). {message}",
521            request.op
522        ),
523        ErrorCode::NonIdempotentNotRetried => format!(
524            "{} failed ({detail}). Not retried: call is not idempotent — observed, not retried. {message}",
525            request.op
526        ),
527        _ => format!(
528            "{} failed ({detail}); error class is not retryable per policy. {message}",
529            request.op
530        ),
531    };
532    text.trim_end().to_owned()
533}
534
535/// Per-attempt context [`terminal_attempt_error`] needs but that never
536/// changes across the retry loop's calls to it — bundled so the helper stays
537/// under clippy's argument-count ceiling.
538struct TerminalAttemptCtx<'a> {
539    request: &'a Request,
540    attempt: u32,
541    max_attempts: u32,
542    trace: Option<&'a TraceRef>,
543    /// Whether THIS attempt was cut off by the policy timeout layer (distinct
544    /// from the retryable-class check): a policy-layer timeout is the more
545    /// precise diagnosis than "exhausted"/"non-retryable" — except the Level 0
546    /// non-idempotent rule, which callers must always see verbatim.
547    timed_out_by_layer: bool,
548}
549
550/// Builds the terminal `OutcomeError` once `run_attempts` has decided this
551/// failed attempt is not retried — folds the timeout-diagnosis override and
552/// the dx-invariant-4 trace ref into one place so the retry loop itself stays
553/// under clippy's line-count ceiling.
554fn terminal_attempt_error(
555    ctx: &TerminalAttemptCtx<'_>,
556    code: ErrorCode,
557    class: ErrorClass,
558    http_status: Option<u16>,
559    message: &str,
560    original: Option<Value>,
561) -> OutcomeError {
562    let code = if ctx.timed_out_by_layer && code != ErrorCode::NonIdempotentNotRetried {
563        ErrorCode::Timeout
564    } else {
565        code
566    };
567    OutcomeError {
568        code,
569        class,
570        http_status,
571        message: with_trace_ref(
572            terminal_message(
573                code,
574                ctx.request,
575                ctx.attempt,
576                ctx.max_attempts,
577                class,
578                http_status,
579                message,
580            ),
581            ctx.trace,
582        ),
583        original,
584    }
585}
586
587/// The Keel kernel, Tier 1 scope. One per process; `&self`-concurrent.
588///
589/// A journal and/or discovery store are optional attachments: the engine is
590/// fully functional without either, and neither can change a call's outcome —
591/// their I/O failures degrade to a `warn!` (resilience first, honest reporting).
592pub struct Engine {
593    started: Instant,
594    policy: RwLock<Policy>,
595    state: Mutex<State>,
596    /// Persistence for the `scope = persistent` cache and Tier 2 flows. Behind
597    /// a lock because `configure` honors `policy.journal` by (re)attaching the
598    /// selected backend; readers clone the `Arc` out, so the lock is never held
599    /// across journal I/O (let alone an await).
600    journal: RwLock<JournalSlot>,
601    /// Traffic ledger fed one observation per `execute`, for `keel init`/`status`.
602    discovery: Option<Arc<dyn DiscoveryRecorder>>,
603    /// Live NDJSON event feed for `keel tail`/`keel trace` ([`crate::events`]).
604    /// `None` (the zero-cost path) unless the environment activates it or a
605    /// sink is attached; like journal/discovery it can never change an outcome.
606    events: Option<EventSink>,
607}
608
609/// The engine's journal attachment plus, when policy selected it, the resolved
610/// backend it was opened from — so reapplying an unchanged policy (whether a
611/// `file:` path or the same `postgres://` location) is a no-op instead of a
612/// re-open/re-connect.
613#[derive(Default)]
614struct JournalSlot {
615    journal: Option<Arc<dyn Journal>>,
616    /// `Some` only for a policy-selected attachment; construction-time
617    /// attachments have no location the engine could compare against.
618    backend: Option<JournalBackend>,
619}
620
621impl fmt::Debug for Engine {
622    fn fmt(&self, f: &mut fmt::Formatter<'_>) -> fmt::Result {
623        // The trait-object attachments aren't `Debug`; report their presence.
624        f.debug_struct("Engine")
625            .field("policy", &self.policy)
626            .field("state", &self.state)
627            .field("journal_attached", &self.current_journal().is_some())
628            .field("discovery_attached", &self.discovery.is_some())
629            .field("events_attached", &self.events.is_some())
630            .finish_non_exhaustive()
631    }
632}
633
634impl Default for Engine {
635    fn default() -> Self {
636        Self::new()
637    }
638}
639
640impl Engine {
641    #[must_use]
642    pub fn new() -> Self {
643        Self {
644            started: Instant::now(),
645            policy: RwLock::new(Policy::default()),
646            state: Mutex::new(State::default()),
647            journal: RwLock::new(JournalSlot::default()),
648            discovery: None,
649            // Live events activate from the environment (KEEL_EVENTS / an
650            // existing ./.keel dir — see `crate::events`), so every embedding
651            // — FFI, PyO3, napi, CLI — inherits the feed with no plumbing.
652            events: EventSink::from_env(),
653        }
654    }
655
656    /// Attach a journal at construction time, enabling the persistent cache
657    /// scope. Optional; set at setup, before the engine is shared for
658    /// concurrent `execute`. A later [`configure`](Self::configure) whose
659    /// policy carries a `journal` key replaces this attachment — the effective
660    /// policy is authoritative (spec §4.2).
661    pub fn attach_journal(&mut self, journal: impl Journal + 'static) -> &mut Self {
662        let slot = self.journal.get_mut().expect("journal lock poisoned");
663        slot.journal = Some(Arc::new(journal));
664        slot.backend = None;
665        self
666    }
667
668    /// The attached journal, if any — shared (`Arc`) so a [`FlowManager`] can run
669    /// its Tier 2 steps over the *same* store the engine caches through. `None`
670    /// for an in-memory engine (Tier 2 requires a durable journal). Live: a
671    /// `configure` whose policy selects a `journal` location changes what this
672    /// returns, so Tier 2 wiring should read it after the engine is configured.
673    ///
674    /// [`FlowManager`]: crate::FlowManager
675    #[must_use]
676    pub fn journal(&self) -> Option<Arc<dyn Journal>> {
677        self.current_journal()
678    }
679
680    /// Clone the current journal out of its slot (the lock never outlives the
681    /// statement, so it is never held across journal I/O or an await).
682    fn current_journal(&self) -> Option<Arc<dyn Journal>> {
683        self.journal
684            .read()
685            .expect("journal lock poisoned")
686            .journal
687            .clone()
688    }
689
690    /// Attach a discovery store; each `execute` then records one observation.
691    /// Optional and failure-isolated — recording never affects an outcome.
692    pub fn attach_discovery(&mut self, discovery: impl DiscoveryRecorder + 'static) -> &mut Self {
693        self.discovery = Some(Arc::new(discovery));
694        self
695    }
696
697    /// Attach (or replace) a live event sink. [`Engine::new`] already resolves
698    /// one from the environment (see [`crate::events`]); this override exists
699    /// for tests and embedders that place the feed elsewhere.
700    pub fn attach_events(&mut self, sink: EventSink) -> &mut Self {
701        self.events = Some(sink);
702        self
703    }
704
705    /// The active event sink, if any — its run id anchors this engine's trace
706    /// refs, and `flush()` makes the feed current for a same-process reader.
707    #[must_use]
708    pub fn events(&self) -> Option<&EventSink> {
709        self.events.as_ref()
710    }
711
712    /// Emit one live event, stamped with engine-elapsed (virtual-clock-safe)
713    /// milliseconds. The closure defers construction — and its string clones —
714    /// to the active-sink case, so the disabled path costs one branch.
715    fn emit_event(&self, kind: impl FnOnce() -> EventKind) {
716        if let Some(sink) = self.events.as_ref() {
717            sink.emit(self.elapsed_ms(), kind());
718        }
719    }
720
721    /// Feed event for a consulted cache: hit (the call is served) or miss
722    /// (the call proceeds live). Not emitted when no cache plan exists.
723    fn emit_cache(&self, out: &Outcome, target: &str, scope: CacheStore, hit: bool) {
724        self.emit_event(|| {
725            let call = out.trace_id.clone();
726            let target = target.to_owned();
727            if hit {
728                EventKind::CacheHit {
729                    call,
730                    target,
731                    scope,
732                }
733            } else {
734                EventKind::CacheMiss {
735                    call,
736                    target,
737                    scope,
738                }
739            }
740        });
741    }
742
743    /// Apply a policy document (keel.toml as JSON, per
744    /// contracts/policy.schema.json), replacing the previous one atomically.
745    /// Rejections are `KEEL-E001` with the exact offending field path;
746    /// a valid policy naming a journal backend this build cannot provide is
747    /// `KEEL-E005` (and the previous policy stays in force).
748    pub fn configure(&self, policy_json: &Value) -> Result<(), KeelError> {
749        let policy: Policy =
750            serde_path_to_error::deserialize(policy_json).map_err(|e| KeelError {
751                code: ErrorCode::PolicyInvalid,
752                message: format!("policy invalid at {}: {}", e.path(), e.inner()),
753            })?;
754        // `journal` selects the backing store (spec §4.2 — "that override is
755        // the entire laptop→enterprise migration"), so it must take effect or
756        // fail loudly, never warn-and-ignore. Applied before the policy swap so
757        // a rejected location leaves the previous configuration fully in force.
758        if let Some(location) = &policy.journal {
759            self.apply_journal_location(location)?;
760        }
761        // `telemetry.otlp_endpoint` IS honored: native front ends built with the
762        // `otel` feature read it back via `telemetry_otlp_endpoint` (below) and
763        // pass it to `otel::init_otlp` (env still wins — see `otel::export_enabled`
764        // / `otel::resolve_endpoint`). `telemetry.console` (the local
765        // pretty-console-summary switch, architecture spec §4.5) is validated and
766        // carried but has no consumer yet; warn on an explicit non-default value
767        // rather than silently ignoring the user's intent.
768        if let Some(telemetry) = &policy.telemetry
769            && !telemetry.console
770        {
771            warn!(
772                "policy `telemetry.console = false` is validated but not yet wired: v0.1 always \
773                 uses the default local summary. `telemetry.otlp_endpoint` IS honored by front \
774                 ends built with the `otel` feature."
775            );
776        }
777        warn_inert_breaker_knobs(&policy);
778        *self.policy.write().expect("policy lock poisoned") = policy;
779        Ok(())
780    }
781
782    /// The effective `telemetry.otlp_endpoint` (`None` if `[telemetry]` is
783    /// absent or the key unset), read live so a reconfigure is honored. Native
784    /// front ends built with the `otel` feature read this after `configure` and
785    /// pass it to [`crate::otel::export_enabled`] / [`crate::otel::resolve_endpoint`]
786    /// to decide whether/where to export (env vars still take precedence).
787    #[must_use]
788    pub fn telemetry_otlp_endpoint(&self) -> Option<String> {
789        self.policy
790            .read()
791            .expect("policy lock poisoned")
792            .telemetry
793            .as_ref()
794            .and_then(|t| t.otlp_endpoint.clone())
795    }
796
797    /// Honor `policy.journal`: open and attach the backend it names, replacing
798    /// any construction-time attachment — the effective policy is
799    /// authoritative. (Front ends that want an environment escape hatch such as
800    /// `KEEL_JOURNAL` compose it into the effective policy *before* calling
801    /// `configure`, per the effective-policy contract.) Reapplying an unchanged
802    /// location — the same `file:` path, or the same `postgres://` URL — is a
803    /// no-op, so reconfigure loops never re-open the store, re-open a fresh
804    /// Postgres connection pool, or drop either's connection state.
805    ///
806    /// # Errors
807    /// - `KEEL-E040` when the selected SQLite file, or the selected Postgres
808    ///   database, cannot be opened/connected to.
809    fn apply_journal_location(&self, location: &JournalLocation) -> Result<(), KeelError> {
810        let backend = JournalBackend::select(location);
811        {
812            let slot = self.journal.read().expect("journal lock poisoned");
813            if slot.backend.as_ref() == Some(&backend) {
814                return Ok(()); // unchanged location: keep the open store
815            }
816        }
817        // Open OFF the lock (filesystem/network I/O); the brief write below
818        // only swaps pointers. Two racing configures both open, last writer
819        // wins — the loser's store (and, for Postgres, its connection pool)
820        // is just dropped.
821        let journal = journal_backend::open(&backend)?;
822        if let JournalBackend::File(path) = &backend {
823            debug!(path = %path.display(), "journal selected by policy");
824        }
825        let mut slot = self.journal.write().expect("journal lock poisoned");
826        slot.journal = Some(journal);
827        slot.backend = Some(backend);
828        Ok(())
829    }
830
831    /// The target's resolved `idempotency = { header }` knob, read live so a
832    /// reconfigure is honored. This is the engine surface of the injection
833    /// contract (contracts/adapter-pack.md "Idempotency-key injection"):
834    /// adapters/bindings consult it to mint and inject an idempotency key on
835    /// unsafe-method calls — the engine itself never injects, and the flipped
836    /// judgment reaches it as `Request.idempotent = true`.
837    #[must_use]
838    pub fn idempotency_header(&self, target: &str) -> Option<String> {
839        self.policy
840            .read()
841            .expect("policy lock poisoned")
842            .resolve(target)
843            .idempotency
844            .map(|i| i.header)
845    }
846
847    /// The configured Tier 2 `flows.on_nondeterminism` response (default
848    /// [`NondeterminismResponse::Fail`]), read live so a reconfigure is honored.
849    /// The flow manager consults this when a replay `(seq, step_key)` diverges.
850    #[must_use]
851    pub fn nondeterminism_response(&self) -> NondeterminismResponse {
852        self.policy
853            .read()
854            .expect("policy lock poisoned")
855            .flows
856            .as_ref()
857            .map_or(NondeterminismResponse::default(), |f| f.on_nondeterminism)
858    }
859
860    fn state(&self) -> MutexGuard<'_, State> {
861        self.state.lock().expect("state lock poisoned")
862    }
863
864    fn elapsed_ms(&self) -> u64 {
865        u64::try_from(self.started.elapsed().as_millis()).unwrap_or(u64::MAX)
866    }
867
868    /// Run one intercepted call through the target's layer chain, then record it
869    /// for discovery. `effect` performs a single attempt (1-based attempt
870    /// numbers). Always returns an `Outcome` — policy failures are outcomes, not
871    /// panics, and neither journal nor discovery I/O can change what's returned.
872    pub async fn execute<F>(&self, request: &Request, mut effect: F) -> Outcome
873    where
874        F: AsyncFnMut(u32) -> AttemptResult,
875    {
876        let started = Instant::now();
877        // One span per wrapped call (architecture spec §4.5). Terminal fields
878        // are declared `Empty` and recorded from the finished outcome; the
879        // per-attempt child spans are opened inside the instrumented chain.
880        // `%request.target`/`%request.op` are only formatted when a subscriber
881        // is active — the disabled callsite evaluates nothing.
882        let span = tracing::info_span!(
883            "keel.call",
884            target = %request.target,
885            op = %request.op,
886            trace_id = tracing::field::Empty,
887            result = tracing::field::Empty,
888            error_code = tracing::field::Empty,
889            attempts = tracing::field::Empty,
890            from_cache = tracing::field::Empty,
891            throttled = tracing::field::Empty,
892            breaker = tracing::field::Empty,
893        );
894        let out = self
895            .run_chain(request, &mut effect)
896            .instrument(span.clone())
897            .await;
898        record_call_fields(&span, &out);
899        self.observe(request, &out, started);
900        // Every call's last feed event, on all paths (cache hit, breaker
901        // reject, envelope error, live attempt).
902        self.emit_event(|| EventKind::CallEnd {
903            call: out.trace_id.clone(),
904            target: request.target.clone(),
905            result: out.result.clone(),
906            code: out.error.as_ref().map(|e| e.code),
907            attempts: out.attempts,
908        });
909        out
910    }
911
912    /// The layer chain proper — cache → rate → breaker → timeout → retry —
913    /// unchanged in semantics from the journal-free engine. The persistent cache
914    /// scope simply swaps the in-memory map for the journal's `cache` table when
915    /// a journal is attached; every other layer is byte-for-byte as before.
916    async fn run_chain<F>(&self, request: &Request, effect: &mut F) -> Outcome
917    where
918        F: AsyncFnMut(u32) -> AttemptResult,
919    {
920        let target = request.target.as_str();
921        let mut out = self.begin_call(target);
922
923        // Every call's first feed event; its seq anchors the trace ref that
924        // failure messages carry (`None` without a sink — the parity path).
925        let trace = self.events.as_ref().map(|sink| {
926            let seq = sink.emit(
927                self.elapsed_ms(),
928                EventKind::CallStart {
929                    call: out.trace_id.clone(),
930                    target: target.to_owned(),
931                    op: request.op.clone(),
932                },
933            );
934            TraceRef {
935                run: sink.run_id().to_owned(),
936                seq,
937            }
938        });
939
940        if request.v != ENVELOPE_VERSION {
941            out.error = Some(OutcomeError {
942                code: ErrorCode::EnvelopeVersion,
943                class: ErrorClass::Other,
944                http_status: None,
945                message: format!("unsupported envelope version {}", request.v),
946                original: None,
947            });
948            self.state().metrics_for(target).failures += 1;
949            return out;
950        }
951
952        let resolved = self
953            .policy
954            .read()
955            .expect("policy lock poisoned")
956            .resolve(target);
957
958        // cache (outermost layer); every planned lookup is one
959        // `keel.cache.requests` datapoint (hit ratio, spec §4.5)
960        let cache_plan = self.plan_cache(target, &resolved, request);
961        match &cache_plan {
962            CachePlan::Memory { key } => {
963                if self.serve_from_cache(key, &mut out) {
964                    crate::metrics::record_cache_request(target, true);
965                    self.emit_cache(&out, target, CacheStore::Memory, true);
966                    return out;
967                }
968                crate::metrics::record_cache_request(target, false);
969                self.emit_cache(&out, target, CacheStore::Memory, false);
970            }
971            CachePlan::Persistent { key, .. } => {
972                if self.serve_from_persistent(target, key, &mut out) {
973                    crate::metrics::record_cache_request(target, true);
974                    self.emit_cache(&out, target, CacheStore::Persistent, true);
975                    return out;
976                }
977                crate::metrics::record_cache_request(target, false);
978                self.emit_cache(&out, target, CacheStore::Persistent, false);
979            }
980            CachePlan::None => {}
981        }
982
983        // rate limiter (lock never held across the sleep)
984        if let Some(rate) = resolved.rate {
985            self.throttle(target, rate, &mut out).await;
986        }
987
988        // breaker admission (observes post-retry call outcomes)
989        let admission = self.admit(target, &resolved, &mut out, trace.as_ref());
990        if admission == Admission::Rejected {
991            return out;
992        }
993
994        // timeout + retry (innermost layers)
995        let retry = resolved.retry.clone().unwrap_or_else(|| RetryPolicy {
996            attempts: core::num::NonZeroU32::MIN,
997            ..RetryPolicy::default()
998        });
999        let result = self
1000            .run_attempts(request, &resolved, &retry, effect, &mut out, trace.as_ref())
1001            .await;
1002        // Only the memory scope writes through under the state lock; the
1003        // persistent scope writes after the lock drops (journal I/O off-lock).
1004        let memory_key = match &cache_plan {
1005            CachePlan::Memory { key } => Some(key.clone()),
1006            _ => None,
1007        };
1008        self.settle(target, &resolved, admission, memory_key, result, &mut out);
1009
1010        if let CachePlan::Persistent { key, ttl } = &cache_plan
1011            && out.result == "ok"
1012            && let Some(payload) = &out.payload
1013        {
1014            self.write_persistent(target, key, payload, *ttl);
1015        }
1016        out
1017    }
1018
1019    /// Decide which cache backend (if any) serves this call. Persistent scope
1020    /// without a journal falls back to the in-memory map — the engine stays
1021    /// fully functional un-journaled rather than silently dropping caching.
1022    fn plan_cache(&self, target: &str, resolved: &ResolvedPolicy, request: &Request) -> CachePlan {
1023        let (Some(cache), Some(hash)) = (resolved.cache.as_ref(), request.args_hash.as_ref())
1024        else {
1025            return CachePlan::None;
1026        };
1027        let Some(ttl) = cache.ttl else {
1028            return CachePlan::None;
1029        };
1030        match cache.scope {
1031            CacheScope::Persistent if self.current_journal().is_some() => CachePlan::Persistent {
1032                key: JournalCacheKey::new(format!("{target}#{hash}")),
1033                ttl,
1034            },
1035            _ => CachePlan::Memory {
1036                key: CacheKey {
1037                    target: target.to_owned(),
1038                    args_hash: hash.clone(),
1039                },
1040            },
1041        }
1042    }
1043
1044    /// Registers the call and mints its outcome envelope + trace id.
1045    fn begin_call(&self, target: &str) -> Outcome {
1046        let mut state = self.state();
1047        state.metrics_for(target).calls += 1;
1048        state.trace_seq += 1;
1049        Outcome {
1050            v: ENVELOPE_VERSION,
1051            result: String::from("error"),
1052            payload: None,
1053            error: None,
1054            attempts: 0,
1055            from_cache: false,
1056            waits_ms: Vec::new(),
1057            throttled: false,
1058            throttle_wait_ms: 0,
1059            breaker: BreakerState::Closed,
1060            trace_id: format!("t-{:06}", state.trace_seq),
1061        }
1062    }
1063
1064    /// Serves a fresh cached payload, if any (attempts stays 0). An entry found
1065    /// expired is *removed* here, not just skipped — combined with the sweep on
1066    /// write ([`settle`](Self::settle)) this bounds the in-memory map to the live
1067    /// working set rather than every distinct key ever cached.
1068    fn serve_from_cache(&self, key: &CacheKey, out: &mut Outcome) -> bool {
1069        let now = Instant::now();
1070        let mut state = self.state();
1071        let payload = match state.cache.get(key) {
1072            Some(entry) if now < entry.expires_at => entry.payload.clone(),
1073            Some(_) => {
1074                // Expired: evict so a per-call-varying key set cannot grow the
1075                // map without bound for the life of the process.
1076                state.cache.remove(key);
1077                return false;
1078            }
1079            None => return false,
1080        };
1081        out.result = String::from("ok");
1082        out.payload = Some(payload);
1083        out.from_cache = true;
1084        let metrics = state.metrics_for(&key.target);
1085        metrics.cache_hits += 1;
1086        metrics.successes += 1;
1087        out.breaker = state.breaker_state(&key.target, now);
1088        debug!(target = %key.target, scope = "memory", "cache hit");
1089        true
1090    }
1091
1092    /// Serves a fresh persistent cache payload from the journal, if any (attempts
1093    /// stays 0). The journal owns TTL expiry against its own clock (identical
1094    /// semantics to the in-memory scope). Any journal or codec failure degrades
1095    /// to a miss + `warn!`, so the call proceeds to a live attempt — a broken
1096    /// journal never fails the call. The journal read runs *before* the state
1097    /// lock is taken, so no lock is held across journal I/O.
1098    fn serve_from_persistent(
1099        &self,
1100        target: &str,
1101        key: &JournalCacheKey,
1102        out: &mut Outcome,
1103    ) -> bool {
1104        let Some(journal) = self.current_journal() else {
1105            return false;
1106        };
1107        let bytes = match journal.get_cache(key) {
1108            Ok(Some(bytes)) => bytes,
1109            Ok(None) => return false,
1110            Err(error) => {
1111                warn!(target = %target, error = %error, "persistent cache read failed; serving live");
1112                return false;
1113            }
1114        };
1115        let payload = match decode_cache_payload(&bytes) {
1116            Ok(payload) => payload,
1117            Err(reason) => {
1118                warn!(target = %target, reason = %reason, "persistent cache entry undecodable; serving live");
1119                return false;
1120            }
1121        };
1122        let now = Instant::now();
1123        let mut state = self.state();
1124        out.result = String::from("ok");
1125        out.payload = Some(payload);
1126        out.from_cache = true;
1127        let metrics = state.metrics_for(target);
1128        metrics.cache_hits += 1;
1129        metrics.successes += 1;
1130        out.breaker = state.breaker_state(target, now);
1131        debug!(target = %target, scope = "persistent", "cache hit");
1132        true
1133    }
1134
1135    /// Delays the call when the target's rate is exhausted (never fails it).
1136    async fn throttle(&self, target: &str, rate: Rate, out: &mut Outcome) {
1137        let wait_ms = {
1138            let elapsed = self.elapsed_ms();
1139            let mut state = self.state();
1140            let bucket = state.rate_buckets.entry(target.to_owned()).or_default();
1141            bucket.plan_admit(elapsed, rate)
1142        };
1143        if wait_ms > 0 {
1144            out.throttled = true;
1145            out.throttle_wait_ms = wait_ms;
1146            self.state().metrics_for(target).throttled += 1;
1147            crate::metrics::record_throttled(target, wait_ms);
1148            // Emitted before the wait so a live tail shows the queueing now.
1149            self.emit_event(|| EventKind::Throttle {
1150                call: out.trace_id.clone(),
1151                target: target.to_owned(),
1152                wait_ms,
1153            });
1154            tokio::time::sleep(Duration::from_millis(wait_ms)).await;
1155        }
1156    }
1157
1158    /// Consults the target's breaker; on rejection, fills the fail-fast
1159    /// KEEL-E012 outcome (the effect is never invoked).
1160    fn admit(
1161        &self,
1162        target: &str,
1163        resolved: &ResolvedPolicy,
1164        out: &mut Outcome,
1165        trace: Option<&TraceRef>,
1166    ) -> Admission {
1167        if resolved.breaker.is_none() {
1168            return Admission::Closed;
1169        }
1170        let now = Instant::now();
1171        let admission = {
1172            let mut state = self.state();
1173            let admission = state
1174                .breakers
1175                .entry(target.to_owned())
1176                .or_default()
1177                .admit(now);
1178            if admission == Admission::Rejected {
1179                out.error = Some(OutcomeError {
1180                    code: ErrorCode::BreakerOpen,
1181                    class: ErrorClass::Other,
1182                    http_status: None,
1183                    message: with_trace_ref(
1184                        format!("breaker OPEN for {target}: failed fast, call not attempted"),
1185                        trace,
1186                    ),
1187                    original: None,
1188                });
1189                out.breaker = BreakerState::Open;
1190                state.metrics_for(target).failures += 1;
1191            }
1192            admission
1193        };
1194        // Both feed events run off the state lock, like the debug! below.
1195        if admission == Admission::Rejected {
1196            self.emit_event(|| EventKind::BreakerReject {
1197                call: out.trace_id.clone(),
1198                target: target.to_owned(),
1199            });
1200        }
1201        // Admitting a probe is an OPEN → HALF-OPEN transition (spec §4.5).
1202        if admission == Admission::HalfOpen {
1203            debug!(target = %target, transition = "half_open", "breaker transition");
1204            crate::metrics::record_breaker_transition(target, "half_open");
1205            self.emit_event(|| EventKind::BreakerHalfOpen {
1206                call: out.trace_id.clone(),
1207                target: target.to_owned(),
1208            });
1209        }
1210        admission
1211    }
1212
1213    /// Books the call's terminal result: metrics, breaker transition, cache
1214    /// write, and the outcome's payload/error/breaker fields.
1215    fn settle(
1216        &self,
1217        target: &str,
1218        resolved: &ResolvedPolicy,
1219        admission: Admission,
1220        cache_key: Option<CacheKey>,
1221        result: Result<Value, OutcomeError>,
1222        out: &mut Outcome,
1223    ) {
1224        let now = Instant::now();
1225        let transition = {
1226            let mut state = self.state();
1227            let transition = match result {
1228                Ok(payload) => {
1229                    state.metrics_for(target).successes += 1;
1230                    let mut transition = BreakerTransition::None;
1231                    if let Some(config) = &resolved.breaker
1232                        && let Some(breaker) = state.breakers.get_mut(target)
1233                    {
1234                        transition = breaker.on_success(now, config);
1235                    }
1236                    if let (Some(key), Some(cache)) = (cache_key, &resolved.cache)
1237                        && let Some(ttl) = cache.ttl
1238                    {
1239                        // Sweep expired entries before inserting so the map is
1240                        // bounded by the live working set, not the total distinct
1241                        // keys ever seen. O(n) in current entries per cacheable
1242                        // write — cheap for the small working sets caching targets
1243                        // in practice, and it keeps a long-lived process from
1244                        // leaking every payload it ever cached (no LRU/size cap in
1245                        // v0.1; a `keel fsck`-style bound is future work).
1246                        state.cache.retain(|_, entry| entry.expires_at > now);
1247                        state.cache.insert(
1248                            key,
1249                            CacheEntry {
1250                                expires_at: now + Duration::from_millis(ttl.0),
1251                                payload: payload.clone(),
1252                            },
1253                        );
1254                    }
1255                    out.result = String::from("ok");
1256                    out.payload = Some(payload);
1257                    transition
1258                }
1259                Err(error) => {
1260                    state.metrics_for(target).failures += 1;
1261                    let mut transition = BreakerTransition::None;
1262                    if let Some(config) = &resolved.breaker
1263                        && let Some(breaker) = state.breakers.get_mut(target)
1264                    {
1265                        transition = breaker.on_terminal_failure(now, config, admission);
1266                    }
1267                    out.error = Some(error);
1268                    transition
1269                }
1270            };
1271            out.breaker = state.breaker_state(target, now);
1272            transition
1273        };
1274        emit_breaker_transition(target, transition);
1275        match transition {
1276            BreakerTransition::Opened => self.emit_event(|| EventKind::BreakerOpen {
1277                call: out.trace_id.clone(),
1278                target: target.to_owned(),
1279                cooldown_ms: resolved.breaker.as_ref().map_or(0, |b| b.cooldown.0),
1280            }),
1281            BreakerTransition::Closed => self.emit_event(|| EventKind::BreakerClose {
1282                call: out.trace_id.clone(),
1283                target: target.to_owned(),
1284            }),
1285            BreakerTransition::None => {}
1286        }
1287    }
1288
1289    /// Writes a live success into the journal's persistent cache (called after
1290    /// the state lock is dropped, so journal I/O is never under the engine
1291    /// mutex). Encoding or journal failure degrades to a `warn!`; the outcome the
1292    /// caller already holds is unaffected.
1293    fn write_persistent(
1294        &self,
1295        target: &str,
1296        key: &JournalCacheKey,
1297        payload: &Value,
1298        ttl: DurationMs,
1299    ) {
1300        let Some(journal) = self.current_journal() else {
1301            return;
1302        };
1303        let bytes = match encode_cache_payload(payload) {
1304            Ok(bytes) => bytes,
1305            Err(error) => {
1306                warn!(target = %target, error = %error, "persistent cache encode failed; entry not stored");
1307                return;
1308            }
1309        };
1310        if let Err(error) = journal.put_cache(key, &bytes, Duration::from_millis(ttl.0)) {
1311            warn!(target = %target, error = %error, "persistent cache write failed; entry not stored");
1312        }
1313    }
1314
1315    /// Records one observation of a completed call into the discovery store, if
1316    /// attached. Runs off the state lock, from data already in the `Outcome`.
1317    /// Failure degrades to a `warn!` — discovery is evidence, never on the
1318    /// call's critical path.
1319    fn observe(&self, request: &Request, out: &Outcome, started: Instant) {
1320        let Some(discovery) = self.discovery.as_ref() else {
1321            return;
1322        };
1323        let latency_ms = i64::try_from(started.elapsed().as_millis()).unwrap_or(i64::MAX);
1324        let result = if out.from_cache {
1325            CallResult::CacheHit
1326        } else if out.result == "ok" {
1327            CallResult::Success
1328        } else {
1329            CallResult::Failure
1330        };
1331        let error = out.error.as_ref().map(|e| ObservedError {
1332            class: e.class,
1333            http_status: e.http_status,
1334        });
1335        let breaker_opened = out
1336            .error
1337            .as_ref()
1338            .is_some_and(|e| e.code == ErrorCode::BreakerOpen);
1339        // "Observed, not retried" (dx-spec §1 Level 0 hard rule): the call
1340        // failed and the retry layer refused to re-send it (KEEL-E014).
1341        let not_retried = out
1342            .error
1343            .as_ref()
1344            .is_some_and(|e| e.code == ErrorCode::NonIdempotentNotRetried);
1345        // Coverage: the front end resolves globs to the exact policy-table key
1346        // before `execute`, so an exact lookup answers "did an explicit
1347        // [target."…"] entry apply?" — defaults-only calls count as unwrapped.
1348        let wrapped = self
1349            .policy
1350            .read()
1351            .expect("policy lock poisoned")
1352            .target
1353            .contains_key(&request.target);
1354        let observation = CallObservation {
1355            target: request.target.clone(),
1356            result,
1357            attempts: out.attempts,
1358            latency_ms,
1359            throttled: out.throttled,
1360            breaker_opened,
1361            not_retried,
1362            wrapped,
1363            error,
1364        };
1365        if let Err(error) = discovery.record(&observation) {
1366            warn!(target = %request.target, error = %error, "discovery record failed; observation dropped");
1367        }
1368    }
1369
1370    /// Runs a single effect invocation through the timeout layer, tagging the
1371    /// origin of a failure (adapter vs. policy timeout). The effect future is
1372    /// instrumented with `attempt_span`, so any tracing it emits nests under the
1373    /// attempt; the timeout branch synthesizes the same `KEEL-E011`-class error
1374    /// the retry loop diagnoses.
1375    ///
1376    /// `timeout` is the effective per-attempt wall-clock deadline, already gated
1377    /// by the caller: it is `None` for a non-idempotent request (Level 0 hard
1378    /// rule — never inject a synthetic failure into a call that may already have
1379    /// committed server-side; the front ends make the same judgment). Note that
1380    /// on the synchronous bindings (keel-py/keel-ffi/keel-node sync `execute`) a
1381    /// blocking effect completes within a single poll, so this timer cannot
1382    /// preempt it — sync callers get their HTTP client's adapter timeout, not the
1383    /// policy layer's. The policy per-attempt timeout is effective on the async
1384    /// path (and in-core futures) where the effect actually awaits.
1385    async fn run_one_attempt<F>(
1386        &self,
1387        timeout: Option<DurationMs>,
1388        effect: &mut F,
1389        attempt: u32,
1390        attempt_span: &tracing::Span,
1391    ) -> AttemptOutcome
1392    where
1393        F: AsyncFnMut(u32) -> AttemptResult,
1394    {
1395        match timeout {
1396            Some(limit) => {
1397                match tokio::time::timeout(
1398                    Duration::from_millis(limit.0),
1399                    effect(attempt).instrument(attempt_span.clone()),
1400                )
1401                .await
1402                {
1403                    Ok(result) => AttemptOutcome {
1404                        result,
1405                        timed_out_by_layer: false,
1406                    },
1407                    Err(_elapsed) => AttemptOutcome {
1408                        result: AttemptResult::Error {
1409                            class: ErrorClass::Timeout,
1410                            http_status: None,
1411                            retry_after_ms: None,
1412                            message: format!("no response within {}ms", limit.0),
1413                            original: None,
1414                        },
1415                        timed_out_by_layer: true,
1416                    },
1417                }
1418            }
1419            None => AttemptOutcome {
1420                result: effect(attempt).instrument(attempt_span.clone()).await,
1421                timed_out_by_layer: false,
1422            },
1423        }
1424    }
1425
1426    /// The timeout-wrapped retry loop. `Ok(payload)` or the terminal error
1427    /// (whose message carries the call's trace ref when a sink is live).
1428    async fn run_attempts<F>(
1429        &self,
1430        request: &Request,
1431        resolved: &ResolvedPolicy,
1432        retry: &RetryPolicy,
1433        effect: &mut F,
1434        out: &mut Outcome,
1435        trace: Option<&TraceRef>,
1436    ) -> Result<Value, OutcomeError>
1437    where
1438        F: AsyncFnMut(u32) -> AttemptResult,
1439    {
1440        let target = request.target.as_str();
1441        let max_attempts = retry.attempts.get();
1442        // Level 0: never arm the per-attempt wall-clock timeout on a
1443        // non-idempotent request. Firing it would drop the in-flight effect
1444        // future while the underlying POST may still commit server-side, then
1445        // hand the caller a synthetic timeout for a call that actually
1446        // succeeded. The front ends refuse to impose a deadline here for the
1447        // same reason; the core must not defeat that guard.
1448        let attempt_timeout = resolved.timeout.filter(|_| request.idempotent);
1449        for attempt in 1..=max_attempts {
1450            out.attempts = attempt;
1451            self.state().metrics_for(target).attempts += 1;
1452            crate::metrics::record_attempt(target);
1453            self.emit_event(|| EventKind::AttemptStart {
1454                call: out.trace_id.clone(),
1455                target: target.to_owned(),
1456                attempt,
1457            });
1458
1459            // Child span per attempt (spec §4.5): `class`/`http_status`/`wait_ms`
1460            // are filled in below once the attempt resolves. The effect future
1461            // runs inside this span so any adapter tracing nests correctly.
1462            let attempt_span = tracing::debug_span!(
1463                "keel.attempt",
1464                attempt,
1465                result = tracing::field::Empty,
1466                class = tracing::field::Empty,
1467                http_status = tracing::field::Empty,
1468                wait_ms = tracing::field::Empty,
1469            );
1470
1471            let attempt_outcome = self
1472                .run_one_attempt(attempt_timeout, effect, attempt, &attempt_span)
1473                .await;
1474
1475            match attempt_outcome.result {
1476                AttemptResult::Ok { payload } => {
1477                    attempt_span.record("result", "ok");
1478                    return Ok(payload);
1479                }
1480                AttemptResult::Error {
1481                    class,
1482                    http_status,
1483                    retry_after_ms,
1484                    message,
1485                    original,
1486                } => {
1487                    attempt_span.record("result", "error");
1488                    attempt_span.record("class", class_str(class));
1489                    if let Some(status) = http_status {
1490                        attempt_span.record("http_status", status);
1491                    }
1492                    self.emit_event(|| EventKind::AttemptError {
1493                        call: out.trace_id.clone(),
1494                        target: target.to_owned(),
1495                        attempt,
1496                        class,
1497                        http_status,
1498                    });
1499                    let retryable = retry.is_retryable(class, http_status);
1500                    if let Some(code) =
1501                        terminal_code(retryable, attempt, max_attempts, request.idempotent)
1502                    {
1503                        let ctx = TerminalAttemptCtx {
1504                            request,
1505                            attempt,
1506                            max_attempts,
1507                            trace,
1508                            timed_out_by_layer: attempt_outcome.timed_out_by_layer,
1509                        };
1510                        return Err(terminal_attempt_error(
1511                            &ctx,
1512                            code,
1513                            class,
1514                            http_status,
1515                            &message,
1516                            original,
1517                        ));
1518                    }
1519                    // Jitter is the emitting segment's flag (schedules can
1520                    // compose via `upTo`/`andThen`; the walk is pure in the
1521                    // attempt number, so jitter never shifts handoff points).
1522                    let (mut wait, jitter) = retry.schedule.wait_and_jitter(attempt);
1523                    if jitter && wait > 0 {
1524                        wait = fastrand::u64(wait / 2..=wait);
1525                    }
1526                    if let Some(server_says) = retry_after_ms {
1527                        wait = wait.max(server_says);
1528                    }
1529                    attempt_span.record("wait_ms", wait);
1530                    out.waits_ms.push(wait);
1531                    self.state().metrics_for(target).retries += 1;
1532                    crate::metrics::record_retry(target, wait);
1533                    // Emitted before the wait so a live tail shows it now.
1534                    self.emit_event(|| EventKind::Backoff {
1535                        call: out.trace_id.clone(),
1536                        target: target.to_owned(),
1537                        attempt,
1538                        wait_ms: wait,
1539                    });
1540                    tokio::time::sleep(Duration::from_millis(wait)).await;
1541                }
1542            }
1543        }
1544        unreachable!("loop always returns by the final attempt");
1545    }
1546
1547    /// Deterministic metrics/discovery report (sorted keys, no wall-clock
1548    /// timestamps): the same shape `keel_report` freezes in core-ffi.h.
1549    pub fn report(&self) -> Value {
1550        let now = Instant::now();
1551        let state = self.state();
1552        let targets = state
1553            .metrics
1554            .iter()
1555            .map(|(name, m)| {
1556                let breaker = state.breakers.get(name);
1557                let row = TargetReport {
1558                    attempts: m.attempts,
1559                    breaker_opens: breaker.map_or(0, |b| b.opens),
1560                    breaker_state: state.breaker_state(name, now),
1561                    cache_hits: m.cache_hits,
1562                    calls: m.calls,
1563                    failures: m.failures,
1564                    retries: m.retries,
1565                    successes: m.successes,
1566                    throttled: m.throttled,
1567                };
1568                (name.as_str(), row)
1569            })
1570            .collect();
1571        serde_json::to_value(Report {
1572            v: 1,
1573            clock_ms: self.elapsed_ms(),
1574            targets,
1575        })
1576        .expect("report serialization is infallible")
1577    }
1578}
1579
1580#[cfg(test)]
1581mod tests {
1582    use super::{
1583        Admission, AttemptResult, Breaker, BreakerTransition, ENVELOPE_VERSION, Engine, Instant,
1584        Request, TokenBucket,
1585    };
1586    use core::num::NonZeroU32;
1587    use core::time::Duration;
1588    use keel_core_api::policy::{BreakerPolicy, DurationMs, Rate};
1589    use serde_json::json;
1590
1591    /// A failure recorded far enough in the past to have aged out of the
1592    /// window must not count towards a later trip decision: without eviction,
1593    /// this exact two-failure sequence (11s apart, `window: 10s`) would trip
1594    /// at `min_calls: 2` (rate 1.0); with eviction the first failure is gone
1595    /// by the time the second arrives, so the window only ever holds one.
1596    #[test]
1597    fn breaker_rate_mode_evicts_outcomes_older_than_the_window() {
1598        let config = BreakerPolicy {
1599            failures: None,
1600            cooldown: DurationMs(15_000),
1601            window: Some(DurationMs(10_000)),
1602            failure_rate: Some(0.5),
1603            min_calls: Some(NonZeroU32::new(2).unwrap()),
1604        };
1605        let mut breaker = Breaker::default();
1606        let t0 = Instant::now();
1607
1608        assert_eq!(
1609            breaker.on_terminal_failure(t0, &config, Admission::Closed),
1610            BreakerTransition::None,
1611            "one failure is below min_calls"
1612        );
1613        let t_11s = t0 + Duration::from_secs(11);
1614        assert_eq!(
1615            breaker.on_terminal_failure(t_11s, &config, Admission::Closed),
1616            BreakerTransition::None,
1617            "the stale failure must have aged out of the 10s window"
1618        );
1619    }
1620
1621    /// Burst capacity is `limit` tokens, never more — an idle gap refills the
1622    /// bucket but is clamped at capacity, so it cannot bank unlimited tokens
1623    /// for a future burst larger than the configured `limit`.
1624    #[test]
1625    fn token_bucket_caps_refill_at_burst_capacity() {
1626        let rate = Rate {
1627            limit: core::num::NonZeroU64::new(2).unwrap(),
1628            window_ms: 1000,
1629        };
1630        let mut bucket = TokenBucket::default();
1631
1632        assert_eq!(bucket.plan_admit(0, rate), 0, "burst covers the first call");
1633        assert_eq!(
1634            bucket.plan_admit(0, rate),
1635            0,
1636            "burst covers the second call"
1637        );
1638        assert_eq!(
1639            bucket.plan_admit(0, rate),
1640            500,
1641            "burst drained: paced at window/limit = 500ms"
1642        );
1643
1644        // A long idle gap (50s, enough to "earn" 100 tokens at this rate) must
1645        // not accrue more than the 2-token burst cap.
1646        assert_eq!(
1647            bucket.plan_admit(50_000, rate),
1648            0,
1649            "capacity refilled to burst"
1650        );
1651        assert_eq!(
1652            bucket.plan_admit(50_000, rate),
1653            0,
1654            "both burst tokens available"
1655        );
1656        assert_eq!(
1657            bucket.plan_admit(50_000, rate),
1658            500,
1659            "capacity clamp: idle time cannot bank more than `limit` tokens"
1660        );
1661    }
1662
1663    fn req(target: &str, args_hash: &str) -> Request {
1664        Request {
1665            v: ENVELOPE_VERSION,
1666            target: target.to_owned(),
1667            op: format!("GET {target}"),
1668            idempotent: true,
1669            args_hash: Some(args_hash.to_owned()),
1670        }
1671    }
1672
1673    /// The in-memory cache does not grow without bound: an expired entry is
1674    /// swept when the next cacheable success writes, so a per-call-varying key
1675    /// set leaves only the live working set behind (finding: unbounded growth).
1676    #[tokio::test(start_paused = true)]
1677    async fn in_memory_cache_evicts_expired_entries() {
1678        let engine = Engine::new();
1679        engine
1680            .configure(&json!({
1681                "target": { "api.catalog.internal": { "cache": { "ttl": "60s" } } }
1682            }))
1683            .expect("valid policy");
1684
1685        engine
1686            .execute(&req("api.catalog.internal", "k1"), async |_a| {
1687                AttemptResult::Ok { payload: json!(1) }
1688            })
1689            .await;
1690        assert_eq!(engine.state().cache.len(), 1, "k1 cached");
1691
1692        // Past k1's 60s TTL: the write for a NEW key sweeps the expired k1.
1693        tokio::time::advance(Duration::from_secs(61)).await;
1694        engine
1695            .execute(&req("api.catalog.internal", "k2"), async |_a| {
1696                AttemptResult::Ok { payload: json!(2) }
1697            })
1698            .await;
1699        assert_eq!(
1700            engine.state().cache.len(),
1701            1,
1702            "expired k1 evicted on write; only the live k2 remains"
1703        );
1704
1705        // A read of the now-swept k1 is a miss (re-runs live), and reading an
1706        // expired key also evicts it on the read path.
1707        let out = engine
1708            .execute(&req("api.catalog.internal", "k1"), async |_a| {
1709                AttemptResult::Ok { payload: json!(3) }
1710            })
1711            .await;
1712        assert!(!out.from_cache, "expired/evicted key re-runs live");
1713    }
1714}