use std::future::Future;
use std::pin::Pin;
use std::sync::atomic::{AtomicU64, Ordering};
use std::sync::Arc;
use std::task::Poll;
use std::time::{Duration, Instant as WallInstant};
use crate::{StorageError, StorageResult};
const SEARCH_PHASES: [SearchPhase; 25] = [
SearchPhase::Authorization,
SearchPhase::TextSearch,
SearchPhase::VectorSearch,
SearchPhase::VectorEmbedding,
SearchPhase::Fusion,
SearchPhase::EntityHydration,
SearchPhase::NoteHydration,
SearchPhase::SupersededFilter,
SearchPhase::MailboxScopeHydration,
SearchPhase::MailboxAuthorization,
SearchPhase::TextReaderAdmission,
SearchPhase::TextReaderCheckout,
SearchPhase::TextBlockingRead,
SearchPhase::VectorReaderAdmission,
SearchPhase::VectorReaderCheckout,
SearchPhase::VectorBlockingRead,
SearchPhase::EntityReaderAdmission,
SearchPhase::EntityReaderCheckout,
SearchPhase::EntityBlockingRead,
SearchPhase::NoteReaderAdmission,
SearchPhase::NoteReaderCheckout,
SearchPhase::NoteBlockingRead,
SearchPhase::GraphReaderAdmission,
SearchPhase::GraphReaderCheckout,
SearchPhase::GraphBlockingRead,
];
#[derive(Clone, Copy, Debug, Eq, PartialEq)]
#[repr(usize)]
pub enum SearchPhase {
Authorization,
TextSearch,
VectorSearch,
VectorEmbedding,
Fusion,
EntityHydration,
NoteHydration,
SupersededFilter,
MailboxScopeHydration,
MailboxAuthorization,
TextReaderAdmission,
TextReaderCheckout,
TextBlockingRead,
VectorReaderAdmission,
VectorReaderCheckout,
VectorBlockingRead,
EntityReaderAdmission,
EntityReaderCheckout,
EntityBlockingRead,
NoteReaderAdmission,
NoteReaderCheckout,
NoteBlockingRead,
GraphReaderAdmission,
GraphReaderCheckout,
GraphBlockingRead,
}
impl SearchPhase {
pub fn as_str(self) -> &'static str {
match self {
Self::Authorization => "authorization",
Self::TextSearch => "text_search",
Self::VectorSearch => "vector_search",
Self::VectorEmbedding => "vector_embedding",
Self::Fusion => "fusion",
Self::EntityHydration => "entity_hydration",
Self::NoteHydration => "note_hydration",
Self::SupersededFilter => "superseded_filter",
Self::MailboxScopeHydration => "mailbox_scope_hydration",
Self::MailboxAuthorization => "mailbox_authorization",
Self::TextReaderAdmission => "text_reader_admission",
Self::TextReaderCheckout => "text_reader_checkout",
Self::TextBlockingRead => "text_blocking_read",
Self::VectorReaderAdmission => "vector_reader_admission",
Self::VectorReaderCheckout => "vector_reader_checkout",
Self::VectorBlockingRead => "vector_blocking_read",
Self::EntityReaderAdmission => "entity_reader_admission",
Self::EntityReaderCheckout => "entity_reader_checkout",
Self::EntityBlockingRead => "entity_blocking_read",
Self::NoteReaderAdmission => "note_reader_admission",
Self::NoteReaderCheckout => "note_reader_checkout",
Self::NoteBlockingRead => "note_blocking_read",
Self::GraphReaderAdmission => "graph_reader_admission",
Self::GraphReaderCheckout => "graph_reader_checkout",
Self::GraphBlockingRead => "graph_blocking_read",
}
}
}
struct SearchPhaseTraceInner {
origin: std::time::Instant,
active_since_ns: [AtomicU64; SEARCH_PHASES.len()],
completed_ns: [AtomicU64; SEARCH_PHASES.len()],
completed_order: [AtomicU64; SEARCH_PHASES.len()],
entered: AtomicU64,
next_completion: AtomicU64,
}
#[derive(Clone)]
pub struct SearchPhaseTrace(Arc<SearchPhaseTraceInner>);
pub struct SearchPhaseGuard {
trace: SearchPhaseTrace,
phase: SearchPhase,
started_ns: u64,
}
#[derive(Clone)]
pub struct SearchPhaseSnapshot {
pub in_flight_phase: String,
pub phase_elapsed_ms: u64,
pub active_phases: String,
pub completed_phases: String,
}
tokio::task_local! {
static SEARCH_PHASE_TRACE: SearchPhaseTrace;
}
impl SearchPhaseTrace {
pub fn new() -> Self {
Self(Arc::new(SearchPhaseTraceInner {
origin: std::time::Instant::now(),
active_since_ns: std::array::from_fn(|_| AtomicU64::new(0)),
completed_ns: std::array::from_fn(|_| AtomicU64::new(0)),
completed_order: std::array::from_fn(|_| AtomicU64::new(0)),
entered: AtomicU64::new(0),
next_completion: AtomicU64::new(0),
}))
}
pub fn enter(&self, phase: SearchPhase) -> SearchPhaseGuard {
let started_ns = self.elapsed_ns();
let index = phase as usize;
self.0.active_since_ns[index].store(started_ns.saturating_add(1), Ordering::Release);
self.0.entered.fetch_or(1u64 << index, Ordering::Relaxed);
SearchPhaseGuard {
trace: self.clone(),
phase,
started_ns,
}
}
pub fn snapshot(&self) -> SearchPhaseSnapshot {
let now_ns = self.elapsed_ns();
let mut active = Vec::new();
let mut completed = Vec::new();
for phase in SEARCH_PHASES {
let index = phase as usize;
let active_since = self.0.active_since_ns[index].load(Ordering::Acquire);
if active_since != 0 {
active.push((active_since - 1, phase));
}
let order = self.0.completed_order[index].load(Ordering::Acquire);
if order != 0 {
completed.push((
order,
phase,
self.0.completed_ns[index].load(Ordering::Relaxed),
));
}
}
active.sort_unstable_by_key(|(started_ns, _)| *started_ns);
completed.sort_unstable_by_key(|(order, _, _)| *order);
let (in_flight_phase, phase_elapsed_ms) = match active.last() {
Some((started_ns, phase)) => (
phase.as_str().to_string(),
nanos_to_millis(now_ns.saturating_sub(*started_ns)),
),
None if self.0.entered.load(Ordering::Relaxed) == 0 => ("not_entered".into(), 0),
None => ("between_phases".into(), 0),
};
let active_phases = if active.is_empty() {
"none".to_string()
} else {
active
.iter()
.map(|(started_ns, phase)| {
format!(
"{}={}ms",
phase.as_str(),
nanos_to_millis(now_ns.saturating_sub(*started_ns))
)
})
.collect::<Vec<_>>()
.join(",")
};
let completed_phases = if completed.is_empty() {
"none".to_string()
} else {
completed
.iter()
.map(|(_, phase, elapsed_ns)| {
format!("{}={}ms", phase.as_str(), nanos_to_millis(*elapsed_ns))
})
.collect::<Vec<_>>()
.join(",")
};
SearchPhaseSnapshot {
in_flight_phase,
phase_elapsed_ms,
active_phases,
completed_phases,
}
}
fn elapsed_ns(&self) -> u64 {
u64::try_from(self.0.origin.elapsed().as_nanos()).unwrap_or(u64::MAX)
}
}
impl Default for SearchPhaseTrace {
fn default() -> Self {
Self::new()
}
}
impl Drop for SearchPhaseGuard {
fn drop(&mut self) {
let index = self.phase as usize;
let elapsed_ns = self.trace.elapsed_ns().saturating_sub(self.started_ns);
self.trace.0.completed_ns[index].fetch_add(elapsed_ns, Ordering::Relaxed);
let order = self.trace.0.next_completion.fetch_add(1, Ordering::Relaxed) + 1;
self.trace.0.completed_order[index].store(order, Ordering::Release);
self.trace.0.active_since_ns[index].store(0, Ordering::Release);
}
}
fn nanos_to_millis(nanos: u64) -> u64 {
nanos / 1_000_000
}
pub async fn scope_search_phase_trace<F: Future>(trace: SearchPhaseTrace, future: F) -> F::Output {
SEARCH_PHASE_TRACE.scope(trace, future).await
}
pub fn enter_search_phase(phase: SearchPhase) -> Option<SearchPhaseGuard> {
SEARCH_PHASE_TRACE.try_with(|trace| trace.enter(phase)).ok()
}
pub fn capture_search_phase_trace() -> Option<SearchPhaseTrace> {
SEARCH_PHASE_TRACE.try_with(Clone::clone).ok()
}
pub const DEFAULT_REQUEST_READ_TIMEOUT_SECS: u64 = 30;
pub const MAX_REQUEST_READ_TIMEOUT_SECS: u64 = 86_400;
pub fn request_read_timeout_from_env() -> Duration {
let raw = std::env::var("KHIVE_REQUEST_READ_TIMEOUT_SECS").ok();
let (seconds, correction) = resolve_request_read_timeout_secs(raw.as_deref());
if let Some(correction) = correction {
static WARNED: std::sync::Once = std::sync::Once::new();
WARNED.call_once(|| {
tracing::warn!(
value = raw.as_deref().unwrap_or_default(),
ceiling_secs = seconds,
max_secs = MAX_REQUEST_READ_TIMEOUT_SECS,
"KHIVE_REQUEST_READ_TIMEOUT_SECS {correction}"
);
});
}
Duration::from_secs(seconds)
}
fn resolve_request_read_timeout_secs(raw: Option<&str>) -> (u64, Option<&'static str>) {
let Some(raw) = raw else {
return (DEFAULT_REQUEST_READ_TIMEOUT_SECS, None);
};
match raw.trim().parse::<u64>() {
Ok(seconds) if (1..=MAX_REQUEST_READ_TIMEOUT_SECS).contains(&seconds) => (seconds, None),
Ok(seconds) if seconds > MAX_REQUEST_READ_TIMEOUT_SECS => (
MAX_REQUEST_READ_TIMEOUT_SECS,
Some("is above the maximum; clamped to the maximum"),
),
_ => (
DEFAULT_REQUEST_READ_TIMEOUT_SECS,
Some("is not a whole number of seconds from 1 to the maximum; using the default"),
),
}
}
#[derive(Clone, Copy, Debug)]
pub struct RequestReadDeadline {
async_at: tokio::time::Instant,
blocking_at: WallInstant,
}
impl RequestReadDeadline {
pub fn after(duration: Duration) -> Self {
Self {
async_at: tokio::time::Instant::now() + duration,
blocking_at: WallInstant::now() + duration,
}
}
pub fn async_at(self) -> tokio::time::Instant {
self.async_at
}
pub fn blocking_at(self) -> WallInstant {
self.blocking_at
}
fn earlier(self, other: Self) -> Self {
if self.async_at <= other.async_at {
self
} else {
other
}
}
}
#[derive(Clone, Copy, Debug, Eq, PartialEq)]
pub enum RequestReadStopReason {
Cancelled,
Deadline,
}
#[derive(Clone, Default)]
pub struct RequestReadContext {
cancellations: Arc<[tokio::sync::watch::Receiver<bool>]>,
deadline: Option<RequestReadDeadline>,
store_acquisition_operation: Option<&'static str>,
}
impl RequestReadContext {
pub fn scope_store_acquisition<T>(
mut self,
operation: &'static str,
work: impl FnOnce() -> T,
) -> T {
self.store_acquisition_operation = Some(operation);
REQUEST_READ_CONTEXT.sync_scope(self, work)
}
pub fn store_acquisition_operation(&self) -> Option<&'static str> {
self.store_acquisition_operation
}
pub fn blocking_stop_reason(&self) -> Option<RequestReadStopReason> {
if self.cancellations.iter().any(receiver_cancelled) {
Some(RequestReadStopReason::Cancelled)
} else if self
.deadline
.is_some_and(|deadline| WallInstant::now() >= deadline.blocking_at)
{
Some(RequestReadStopReason::Deadline)
} else {
None
}
}
pub fn deadline(&self) -> Option<RequestReadDeadline> {
self.deadline
}
pub fn stop_reason(&self) -> Option<RequestReadStopReason> {
if self.cancellations.iter().any(receiver_cancelled) {
Some(RequestReadStopReason::Cancelled)
} else if self
.deadline
.is_some_and(|deadline| tokio::time::Instant::now() >= deadline.async_at)
{
Some(RequestReadStopReason::Deadline)
} else {
None
}
}
pub async fn wait_for_stop(self) -> RequestReadStopReason {
let cancellation_receivers = self.cancellations;
let request_deadline = self.deadline;
let cancellation = async move {
match cancellation_receivers.len() {
0 => std::future::pending::<()>().await,
1 => wait_for_receiver_cancellation(cancellation_receivers[0].clone()).await,
2 => {
tokio::select! {
_ = wait_for_receiver_cancellation(cancellation_receivers[0].clone()) => {},
_ = wait_for_receiver_cancellation(cancellation_receivers[1].clone()) => {},
}
}
_ => wait_for_receiver_set(cancellation_receivers).await,
}
};
let deadline = async move {
match request_deadline {
Some(deadline) => tokio::time::sleep_until(deadline.async_at).await,
None => std::future::pending::<()>().await,
}
};
tokio::select! {
_ = cancellation => RequestReadStopReason::Cancelled,
_ = deadline => RequestReadStopReason::Deadline,
}
}
}
tokio::task_local! {
static REQUEST_READ_CONTEXT: RequestReadContext;
}
pub fn capture_request_read_context() -> RequestReadContext {
REQUEST_READ_CONTEXT
.try_with(Clone::clone)
.unwrap_or_default()
}
pub fn effective_request_read_deadline(candidate: RequestReadDeadline) -> RequestReadDeadline {
capture_request_read_context()
.deadline
.map_or(candidate, |existing| existing.earlier(candidate))
}
pub async fn scope_request_read_cancellation<F>(
cancellation: tokio::sync::watch::Receiver<bool>,
future: F,
) -> F::Output
where
F: Future,
{
let mut context = capture_request_read_context();
let mut cancellations = Vec::with_capacity(context.cancellations.len() + 1);
cancellations.extend(context.cancellations.iter().cloned());
cancellations.push(cancellation);
context.cancellations = cancellations.into();
REQUEST_READ_CONTEXT.scope(context, future).await
}
pub async fn scope_request_read_deadline<F>(duration: Duration, future: F) -> F::Output
where
F: Future,
{
scope_request_read_deadline_at(RequestReadDeadline::after(duration), future).await
}
pub async fn scope_request_read_deadline_at<F>(
deadline: RequestReadDeadline,
future: F,
) -> F::Output
where
F: Future,
{
let mut context = capture_request_read_context();
context.deadline = Some(match context.deadline {
Some(existing) => existing.earlier(deadline),
None => deadline,
});
REQUEST_READ_CONTEXT.scope(context, future).await
}
pub fn inherit_request_read_context<F>(future: F) -> impl Future<Output = F::Output> + Send
where
F: Future + Send,
{
let inherited = REQUEST_READ_CONTEXT.try_with(Clone::clone).ok();
async move {
match inherited {
Some(context) => REQUEST_READ_CONTEXT.scope(context, future).await,
None => future.await,
}
}
}
pub fn inherit_request_read_cancellation<F>(future: F) -> impl Future<Output = F::Output> + Send
where
F: Future + Send,
{
inherit_request_read_context(future)
}
pub fn request_read_is_cancelled() -> bool {
capture_request_read_context().stop_reason().is_some()
}
pub fn ensure_request_read_active(operation: &'static str) -> StorageResult<()> {
if request_read_is_cancelled() {
Err(StorageError::Timeout {
operation: operation.into(),
})
} else {
Ok(())
}
}
pub async fn wait_for_request_read_cancellation() {
let _ = capture_request_read_context().wait_for_stop().await;
}
pub async fn await_request_read_phase<F>(
operation: &'static str,
future: F,
) -> StorageResult<F::Output>
where
F: Future,
{
ensure_request_read_active(operation)?;
tokio::pin!(future);
tokio::select! {
biased;
_ = wait_for_request_read_cancellation() => Err(StorageError::Timeout {
operation: operation.into(),
}),
output = &mut future => {
ensure_request_read_active(operation)?;
Ok(output)
}
}
}
fn receiver_cancelled(receiver: &tokio::sync::watch::Receiver<bool>) -> bool {
*receiver.borrow() || receiver.has_changed().is_err()
}
async fn wait_for_receiver_cancellation(mut receiver: tokio::sync::watch::Receiver<bool>) {
loop {
if *receiver.borrow_and_update() {
return;
}
if receiver.changed().await.is_err() {
return;
}
}
}
async fn wait_for_receiver_set(receivers: Arc<[tokio::sync::watch::Receiver<bool>]>) {
let mut waits: Vec<Pin<Box<dyn Future<Output = ()> + Send>>> = receivers
.iter()
.cloned()
.map(|receiver| {
Box::pin(wait_for_receiver_cancellation(receiver))
as Pin<Box<dyn Future<Output = ()> + Send>>
})
.collect();
std::future::poll_fn(move |cx| {
if waits
.iter_mut()
.any(|wait| wait.as_mut().poll(cx).is_ready())
{
Poll::Ready(())
} else {
Poll::Pending
}
})
.await;
}
#[cfg(test)]
#[path = "request_context/tests.rs"]
mod tests;