1use 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#[derive(Debug, Default)]
36struct Breaker {
37 consecutive: u64,
39 outcomes: VecDeque<(Instant, bool)>,
43 open_until: Option<Instant>,
44 opens: u64,
45}
46
47#[derive(Debug, Clone, Copy, PartialEq, Eq)]
49enum Admission {
50 Closed,
51 HalfOpen,
53 Rejected,
55}
56
57#[derive(Debug, Clone, Copy, PartialEq, Eq)]
61enum BreakerTransition {
62 None,
64 Opened,
66 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 let closed_a_probe = self.open_until.is_some();
91 self.consecutive = 0;
92 self.open_until = None;
93 if closed_a_probe {
94 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 } 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 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 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#[derive(Debug, Default)]
185struct TokenBucket {
186 scaled_tokens: i128,
190 last_refill_ms: u64,
192 primed: bool,
195}
196
197impl TokenBucket {
198 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; if !self.primed {
206 self.primed = true;
207 self.scaled_tokens = capacity;
208 self.last_refill_ms = elapsed_ms;
209 }
210 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 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
241const CACHE_PAYLOAD_SCHEMA: &str = "keel.cache/v1";
246
247#[derive(Serialize)]
250struct CachePayloadRef<'a> {
251 schema: &'a str,
252 payload: &'a Value,
253}
254
255#[derive(Deserialize)]
257struct CachePayloadOwned {
258 schema: String,
259 payload: Value,
260}
261
262fn 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
270fn 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#[derive(Debug)]
290enum CachePlan {
291 None,
292 Memory {
293 key: CacheKey,
294 },
295 Persistent {
296 key: JournalCacheKey,
297 ttl: DurationMs,
298 },
299}
300
301pub trait DiscoveryRecorder: Send + Sync {
305 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#[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#[derive(Debug)]
373struct AttemptOutcome {
374 result: AttemptResult,
375 timed_out_by_layer: bool,
376}
377
378fn 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
407fn 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
417fn 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
433fn 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
450fn 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
487fn 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
535struct TerminalAttemptCtx<'a> {
539 request: &'a Request,
540 attempt: u32,
541 max_attempts: u32,
542 trace: Option<&'a TraceRef>,
543 timed_out_by_layer: bool,
548}
549
550fn 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
587pub struct Engine {
593 started: Instant,
594 policy: RwLock<Policy>,
595 state: Mutex<State>,
596 journal: RwLock<JournalSlot>,
601 discovery: Option<Arc<dyn DiscoveryRecorder>>,
603 events: Option<EventSink>,
607}
608
609#[derive(Default)]
614struct JournalSlot {
615 journal: Option<Arc<dyn Journal>>,
616 backend: Option<JournalBackend>,
619}
620
621impl fmt::Debug for Engine {
622 fn fmt(&self, f: &mut fmt::Formatter<'_>) -> fmt::Result {
623 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 events: EventSink::from_env(),
653 }
654 }
655
656 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 #[must_use]
676 pub fn journal(&self) -> Option<Arc<dyn Journal>> {
677 self.current_journal()
678 }
679
680 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 pub fn attach_discovery(&mut self, discovery: impl DiscoveryRecorder + 'static) -> &mut Self {
693 self.discovery = Some(Arc::new(discovery));
694 self
695 }
696
697 pub fn attach_events(&mut self, sink: EventSink) -> &mut Self {
701 self.events = Some(sink);
702 self
703 }
704
705 #[must_use]
708 pub fn events(&self) -> Option<&EventSink> {
709 self.events.as_ref()
710 }
711
712 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 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 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 if let Some(location) = &policy.journal {
759 self.apply_journal_location(location)?;
760 }
761 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 #[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 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(()); }
816 }
817 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 #[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 #[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 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 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 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 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 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 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 if let Some(rate) = resolved.rate {
985 self.throttle(target, rate, &mut out).await;
986 }
987
988 let admission = self.admit(target, &resolved, &mut out, trace.as_ref());
990 if admission == Admission::Rejected {
991 return out;
992 }
993
994 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 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 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 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 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 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 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 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 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 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 if admission == Admission::Rejected {
1196 self.emit_event(|| EventKind::BreakerReject {
1197 call: out.trace_id.clone(),
1198 target: target.to_owned(),
1199 });
1200 }
1201 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 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 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 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 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 let not_retried = out
1342 .error
1343 .as_ref()
1344 .is_some_and(|e| e.code == ErrorCode::NonIdempotentNotRetried);
1345 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 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 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 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 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 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 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 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 #[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 #[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 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 #[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 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 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}