use std::collections::HashMap;
use std::sync::atomic::{AtomicU64, Ordering};
use std::sync::{Arc, Mutex, OnceLock};
use std::time::{Instant, SystemTime, UNIX_EPOCH};
static TRACE_SEQ: AtomicU64 = AtomicU64::new(0);
fn monotonic_origin() -> &'static Instant {
static ORIGIN: OnceLock<Instant> = OnceLock::new();
ORIGIN.get_or_init(Instant::now)
}
use async_trait::async_trait;
use futures::{Stream, StreamExt};
use std::pin::Pin;
use std::task::{Context, Poll};
use crate::error::AiMuxError;
use crate::language_model::LanguageModel;
use crate::options::CallOptions;
use crate::result::{GenerateResult, StreamResult};
use crate::stream_part::StreamPart;
use crate::types::Usage;
use super::fingerprint::{BlockChainFingerprint, Chain, Fingerprint, denoise};
use super::hash;
use super::record::{TraceRecord, UsageSnapshot};
use super::store::{LcpResult, RingTraceStore, TraceSink};
use super::verdict::{
JudgmentInput, LcpInput, SessionStats, Verdict, judge as rule_judge, matrix as verdict_matrix,
};
pub trait CacheAuditor: Send + Sync {
fn judge(&self, input: &JudgmentInput) -> Verdict;
}
pub struct RuleAuditor;
impl CacheAuditor for RuleAuditor {
fn judge(&self, input: &JudgmentInput) -> Verdict {
rule_judge(input)
}
}
#[derive(Default)]
struct SessionTracker {
rounds: u32,
prev_body_len: u64,
}
pub struct TraceLayer {
inner: Arc<dyn LanguageModel>,
sink: Arc<dyn TraceSink>,
auditor: Option<Arc<dyn CacheAuditor>>,
strict: bool,
default_session: Option<String>,
scope_salt: u64,
session_tracker: Arc<Mutex<HashMap<String, SessionTracker>>>,
}
struct RequestCtx {
session_id: Option<String>,
scope_key: u64,
sent_at_unix_ms: i64,
monotonic_ms: u64,
}
struct RecordCtx {
provider: String,
model: String,
sink: Arc<dyn TraceSink>,
auditor: Option<Arc<dyn CacheAuditor>>,
strict: bool,
scope_salt: u64,
session_tracker: Arc<Mutex<HashMap<String, SessionTracker>>>,
ctx: RequestCtx,
call_id: Option<String>,
request_body: Option<serde_json::Value>,
response_headers: Option<HashMap<String, String>>,
ttft_ms: Arc<AtomicU64>,
}
impl TraceLayer {
pub fn new(inner: Arc<dyn LanguageModel>, sink: Arc<dyn TraceSink>) -> Self {
Self {
inner,
sink,
auditor: None,
strict: false,
default_session: None,
scope_salt: hash::mix(0x5eed_5eed ^ std::process::id() as u64),
session_tracker: Arc::new(Mutex::new(HashMap::new())),
}
}
#[must_use]
pub fn with_default_session(mut self, session_id: String, key: [u8; 32]) -> Self {
self.default_session = Some(session_id);
let mut acc = 0x9e37_79b9_7f4a_7c15u64;
for chunk in key.chunks(8) {
let mut w = 0u64;
for (i, b) in chunk.iter().enumerate() {
w ^= (*b as u64) << (8 * i);
}
acc = hash::mix(acc ^ w);
}
self.scope_salt = acc;
self
}
#[must_use]
pub fn with_auditor(mut self, auditor: Arc<dyn CacheAuditor>) -> Self {
self.auditor = Some(auditor);
self
}
#[must_use]
pub fn with_rules_auditor(mut self, strict: bool) -> Self {
self.strict = strict;
self.auditor = Some(Arc::new(RuleAuditor));
self
}
fn make_record_ctx(
&self,
options: &CallOptions,
request_body: Option<serde_json::Value>,
response_headers: Option<HashMap<String, String>>,
ttft_ms: Arc<AtomicU64>,
) -> RecordCtx {
let session_id = options
.session_id
.clone()
.or_else(|| self.default_session.clone());
let provider = self.inner.provider();
let model_id = self.inner.model_id();
let base_url = self.inner.config_snapshot().base_url;
let mut scope_bytes = Vec::with_capacity(
provider.len() + model_id.len() + base_url.as_deref().map_or(0, str::len),
);
scope_bytes.extend_from_slice(provider.as_bytes());
scope_bytes.extend_from_slice(model_id.as_bytes());
if let Some(b) = &base_url {
scope_bytes.extend_from_slice(b.as_bytes());
}
let scope_key = hash::hash64(self.scope_salt, &scope_bytes);
let sent_at_unix_ms = SystemTime::now()
.duration_since(UNIX_EPOCH)
.map(|d| d.as_millis() as i64)
.unwrap_or(0);
let monotonic_ms = monotonic_origin().elapsed().as_millis() as u64;
RecordCtx {
provider: provider.to_string(),
model: model_id.to_string(),
sink: self.sink.clone(),
auditor: self.auditor.clone(),
strict: self.strict,
scope_salt: self.scope_salt,
session_tracker: self.session_tracker.clone(),
call_id: options.call_id.clone(),
ctx: RequestCtx {
session_id,
scope_key,
sent_at_unix_ms,
monotonic_ms,
},
request_body,
response_headers,
ttft_ms,
}
}
}
impl RecordCtx {
fn denoised_bytes(&self) -> Option<Vec<u8>> {
let body = self.request_body.as_ref()?;
serde_json::to_vec(&denoise(body)).ok()
}
fn usage_snapshot(usage: &Usage) -> UsageSnapshot {
UsageSnapshot {
input_total: usage.input_tokens.total.map(u64::from),
input_no_cache: usage.input_tokens.no_cache.map(u64::from),
cache_read: usage.input_tokens.cache_read.map(u64::from),
cache_write: usage.input_tokens.cache_write.map(u64::from),
output_total: usage.output_tokens.total.map(u64::from),
output_text: usage.output_tokens.text.map(u64::from),
output_reasoning: usage.output_tokens.reasoning.map(u64::from),
raw: usage.raw.clone(),
}
}
fn session_stats_for(&self, sid: &str, lcp_bytes: u64, body_len: u64) -> SessionStats {
let mut map = self.session_tracker.lock().unwrap();
let t = map.entry(sid.to_string()).or_default();
let rounds = t.rounds + 1;
let stable = t.prev_body_len > 0 && lcp_bytes * 100 >= t.prev_body_len * 95;
t.rounds = rounds;
t.prev_body_len = body_len;
SessionStats {
same_session_rounds: rounds,
prefix_stable: stable,
lcp_gt_1024: lcp_bytes / 4 > 1024,
}
}
fn ring_store(&self) -> Option<&RingTraceStore> {
self.sink.as_any().downcast_ref::<RingTraceStore>()
}
fn lookup_lcp(&self, chain: &Chain, ttl_ms: u64) -> (Option<LcpInput>, u64, u64, bool) {
let Some(store) = self.ring_store() else {
return (None, 0, 0, false);
};
let now_mono = monotonic_origin().elapsed().as_millis() as u64;
let lcp: LcpResult = store.lookup(self.ctx.scope_key, chain, now_mono, ttl_ms);
let same_session = lcp
.matched
.as_ref()
.map(|m| m.session.as_deref() == self.ctx.session_id.as_deref())
.unwrap_or(false);
let upper = if lcp.matched.is_some() {
(lcp.matched_blocks as u64 + 1) * chain.block_size as u64
} else {
0
};
let input = lcp.matched.map(|_| LcpInput {
lcp_bytes: lcp.lcp_bytes,
lcp_upper_bytes: upper,
same_session,
matched_exists: true,
});
(input, lcp.lcp_bytes, upper, lcp.candidate_expired)
}
fn record(&self, usage: &Usage, error: Option<String>, request_id: Option<String>) {
let spec = verdict_matrix::for_provider(&self.provider, &self.model);
let fp =
BlockChainFingerprint::new(super::fingerprint::DEFAULT_BLOCK_SIZE, self.scope_salt);
let (fingerprint, chain) = match self.denoised_bytes() {
Some(bytes) => {
let c = fp.compute(&bytes);
(Fingerprint::from(&c), c)
}
None => (
Fingerprint {
body_hash: String::new(),
len_bytes: 0,
block_size: 0,
block_hashes: Vec::new(),
token_estimate: 0,
},
Chain {
body_hash: 0,
len_bytes: 0,
block_size: super::fingerprint::DEFAULT_BLOCK_SIZE,
block_hashes: Vec::new(),
},
),
};
let (lcp_input, lcp_bytes, lcp_upper_bytes, candidate_expired) =
if error.is_none() && !chain.block_hashes.is_empty() {
let (li, lb, lu, ce) = self.lookup_lcp(&chain, spec.ttl_ms);
(li, lb, lu, ce)
} else {
(None, 0, 0, false)
};
let sid = self
.ctx
.session_id
.clone()
.unwrap_or_else(|| format!("<scope:{}>", self.ctx.scope_key));
let session_stats = self.session_stats_for(&sid, lcp_bytes, fingerprint.len_bytes);
let verdict = if let Some(auditor) = &self.auditor {
let usage_present = usage.input_tokens.total.is_some();
let prompt_tokens = usage.input_tokens.total.unwrap_or(0) as u64;
let claimed = usage.input_tokens.cache_read.unwrap_or(0) as u64;
let inp = JudgmentInput {
spec,
strict: self.strict,
input_no_cache: usage.input_tokens.no_cache.map(u64::from),
input_cache_read: usage.input_tokens.cache_read.map(u64::from),
input_cache_write: usage.input_tokens.cache_write.map(u64::from),
first: self
.ring_store()
.map(|s| s.records_in_scope(self.ctx.scope_key) == 0)
.unwrap_or(true),
prompt_tokens,
prompt_bytes: fingerprint.len_bytes,
claimed,
write: usage.input_tokens.cache_write.map(u64::from),
no_cache: usage.input_tokens.no_cache.map(u64::from),
hit: usage
.raw
.as_ref()
.and_then(|r| r.get("prompt_cache_hit_tokens"))
.and_then(serde_json::Value::as_u64),
miss: usage
.raw
.as_ref()
.and_then(|r| r.get("prompt_cache_miss_tokens"))
.and_then(serde_json::Value::as_u64),
usage_present,
response_cache_header_hit: self
.response_headers
.as_ref()
.map(|h| {
h.iter().any(|(k, v)| {
k.to_ascii_lowercase().contains("cache-status")
&& v.to_ascii_uppercase().contains("HIT")
})
})
.unwrap_or(false),
candidate_expired,
byte_proxy: true, route_affinity_known: false,
lcp: lcp_input,
system_tokens: 0, session_stats: Some(session_stats),
};
Some(auditor.judge(&inp))
} else {
None
};
let ttft_ms = self.ttft_ms.load(Ordering::Relaxed);
let ttft_ms = if ttft_ms == u64::MAX {
None
} else {
Some(ttft_ms)
};
let lcp_token_upper = if lcp_upper_bytes > 0 {
Some(
(lcp_upper_bytes.min(fingerprint.len_bytes) / 4)
.min(usage.input_tokens.total.unwrap_or(0) as u64),
)
} else {
None
};
let rec = TraceRecord {
provider: self.provider.clone(),
model: self.model.clone(),
request_id,
session_id: self.ctx.session_id.clone(),
call_id: self.call_id.clone().unwrap_or_else(|| {
format!(
"trace-{}-{}-{}",
std::process::id(),
self.ctx.monotonic_ms,
TRACE_SEQ.fetch_add(1, Ordering::Relaxed)
)
}),
sent_at_unix_ms: self.ctx.sent_at_unix_ms,
monotonic_sent_ms: self.ctx.monotonic_ms,
lcp_token_upper,
ttft_ms,
fingerprint,
usage: Self::usage_snapshot(usage),
response_cache_headers: self.response_headers.clone(),
request_cache_hints: None,
verdict,
error,
scope_key: self.ctx.scope_key,
};
self.sink.record(rec);
}
}
struct TraceRecordingStream<S> {
inner: S,
rec_ctx: Option<Arc<RecordCtx>>,
usage: Usage,
error: Option<String>,
recorded: bool,
}
impl<S> TraceRecordingStream<S> {
fn record_now(&mut self, usage: Usage, error: Option<String>) {
if self.recorded {
return;
}
self.recorded = true;
if let Some(ctx) = self.rec_ctx.take() {
ctx.record(&usage, error, None);
}
}
}
impl<S> Stream for TraceRecordingStream<S>
where
S: Stream<Item = Result<StreamPart, AiMuxError>> + Unpin,
{
type Item = Result<StreamPart, AiMuxError>;
fn poll_next(self: Pin<&mut Self>, cx: &mut Context<'_>) -> Poll<Option<Self::Item>> {
let this = self.get_mut();
match Pin::new(&mut this.inner).poll_next(cx) {
Poll::Ready(Some(Ok(part))) => {
match &part {
StreamPart::Finish { usage: u, .. } => this.usage = u.clone(),
StreamPart::Error { error: e } => {
this.error.get_or_insert_with(|| e.to_string());
}
_ => {}
}
Poll::Ready(Some(Ok(part)))
}
Poll::Ready(Some(Err(e))) => {
this.error.get_or_insert_with(|| e.to_string());
Poll::Ready(Some(Err(e)))
}
Poll::Ready(None) => {
let usage = std::mem::take(&mut this.usage);
let error = this.error.take();
this.record_now(usage, error);
Poll::Ready(None)
}
Poll::Pending => Poll::Pending,
}
}
}
impl<S> Drop for TraceRecordingStream<S> {
fn drop(&mut self) {
if !self.recorded {
let usage = std::mem::take(&mut self.usage);
let error = self
.error
.take()
.or_else(|| Some("stream dropped before completion".into()));
self.record_now(usage, error);
}
}
}
#[async_trait]
impl LanguageModel for TraceLayer {
fn specification_version(&self) -> &'static str {
"v4"
}
fn provider(&self) -> &str {
self.inner.provider()
}
fn model_id(&self) -> &str {
self.inner.model_id()
}
fn retry_config(&self) -> crate::retry::RetryConfig {
self.inner.retry_config()
}
fn config_snapshot(&self) -> crate::recording::ProviderRecord {
self.inner.config_snapshot()
}
async fn do_generate(&self, options: &CallOptions) -> Result<GenerateResult, AiMuxError> {
let ctx = self.make_record_ctx(options, None, None, Arc::new(AtomicU64::new(u64::MAX)));
match self.inner.do_generate(options).await {
Ok(result) => {
let request_id = result.response.id.clone();
let mut rec_ctx = ctx;
rec_ctx.request_body = result.request_body.clone();
rec_ctx.response_headers = result.response_headers.clone();
rec_ctx.record(&result.usage, None, request_id);
Ok(result)
}
Err(e) => {
ctx.record(&Usage::default(), Some(e.to_string()), None);
Err(e)
}
}
}
async fn do_stream(&self, options: &CallOptions) -> Result<StreamResult, AiMuxError> {
let ttft = Arc::new(AtomicU64::new(u64::MAX));
let ctx = self.make_record_ctx(options, None, None, ttft.clone());
let result = match self.inner.do_stream(options).await {
Ok(r) => r,
Err(e) => {
ctx.record(&Usage::default(), Some(e.to_string()), None);
return Err(e);
}
};
let rec_ctx = Arc::new(RecordCtx {
request_body: result.request_body.clone(),
response_headers: result.response_headers.clone(),
..ctx
});
let ttft_obs = ttft.clone();
let started = Instant::now();
let observed = result.stream.map(move |item| {
if ttft_obs.load(Ordering::Relaxed) == u64::MAX {
let is_model_output = matches!(
&item,
Ok(StreamPart::TextDelta { .. })
| Ok(StreamPart::ReasoningDelta { .. })
| Ok(StreamPart::ToolCall { .. })
);
if is_model_output {
ttft_obs.store(started.elapsed().as_millis() as u64, Ordering::Relaxed);
}
}
item
});
let guarded = TraceRecordingStream {
inner: observed,
rec_ctx: Some(rec_ctx),
usage: Usage::default(),
error: None,
recorded: false,
};
Ok(StreamResult {
stream: Box::pin(guarded),
request_body: result.request_body,
response_headers: result.response_headers,
})
}
}