use crate::ServerError;
use audio2face3d::logging::integration::LogScope;
use std::{
future::Future,
pin::Pin,
sync::atomic::{AtomicU64, Ordering},
task::{Context, Poll},
time::Duration,
};
use tokio::sync::oneshot;
use tokio_util::sync::CancellationToken;
#[derive(Clone, Copy, Debug, Default, PartialEq, Eq)]
pub struct ShutdownReport {
pub inference_requests: u64,
pub health_requests: u64,
pub authentication_rejections: u64,
pub inference_workers_started: u64,
pub inference_workers_finished: u64,
}
#[derive(Default)]
pub(crate) struct Metrics {
pub inference_requests: AtomicU64,
pub health_requests: AtomicU64,
pub authentication_rejections: AtomicU64,
pub inference_workers_started: AtomicU64,
pub inference_workers_finished: AtomicU64,
}
impl Metrics {
pub fn snapshot(&self) -> ShutdownReport {
ShutdownReport {
inference_requests: self.inference_requests.load(Ordering::Relaxed),
health_requests: self.health_requests.load(Ordering::Relaxed),
authentication_rejections: self.authentication_rejections.load(Ordering::Relaxed),
inference_workers_started: self.inference_workers_started.load(Ordering::Relaxed),
inference_workers_finished: self.inference_workers_finished.load(Ordering::Relaxed),
}
}
}
#[derive(Clone, Copy, Debug, PartialEq, Eq)]
pub enum CleanupStage {
Prepare,
Transport,
Workers,
PreparedResources,
}
#[derive(Clone, Copy, Debug)]
pub(crate) struct Overdue {
pub stage: CleanupStage,
pub unfinished: usize,
}
pub struct CleanupCompletion {
receiver: oneshot::Receiver<Result<ShutdownReport, ServerError>>,
}
impl std::fmt::Debug for CleanupCompletion {
fn fmt(&self, f: &mut std::fmt::Formatter<'_>) -> std::fmt::Result {
f.write_str("CleanupCompletion { .. }")
}
}
impl Future for CleanupCompletion {
type Output = Result<ShutdownReport, ServerError>;
fn poll(mut self: Pin<&mut Self>, cx: &mut Context<'_>) -> Poll<Self::Output> {
Pin::new(&mut self.receiver)
.poll(cx)
.map(|r| r.unwrap_or(Err(ServerError::SupervisorStopped)))
}
}
struct StopOnDrop(CancellationToken);
impl Drop for StopOnDrop {
fn drop(&mut self) {
self.0.cancel();
}
}
pub(crate) async fn supervise<F, Fut>(
stop: impl Future<Output = ()> + Send,
run: F,
) -> Result<ShutdownReport, ServerError>
where
F: FnOnce(CancellationToken, oneshot::Sender<Overdue>) -> Fut,
Fut: Future<Output = Result<ShutdownReport, ServerError>> + Send + 'static,
{
let shutdown = CancellationToken::new();
let _guard = StopOnDrop(shutdown.clone());
let (complete_tx, receiver) = oneshot::channel();
let (overdue_tx, mut overdue_rx) = oneshot::channel();
let task = run(shutdown.clone(), overdue_tx);
let scope = LogScope::capture();
tokio::spawn(scope.wrap_future(async move {
let _ = complete_tx.send(task.await);
}));
let mut completion = CleanupCompletion { receiver };
tokio::pin!(stop);
let mut stopping = false;
let mut notified = false;
loop {
tokio::select! {
biased;
result = &mut completion => return result,
notice = &mut overdue_rx, if !notified => {
notified = true;
if let Ok(notice) = notice {
return Err(ServerError::ShutdownTimeout { stage: notice.stage, unfinished: notice.unfinished, completion });
}
}
_ = &mut stop, if !stopping => { stopping = true; shutdown.cancel(); }
}
}
}
pub(crate) fn notify(
sender: &mut Option<oneshot::Sender<Overdue>>,
stage: CleanupStage,
unfinished: usize,
) {
audio2face3d::logging::integration::log(audio2face3d::logging::LogLevel::Warn, || {
audio2face3d::logging::LogRecord::new("server cleanup stage timed out")
.field("source", module_path!())
.field("stage", format!("{stage:?}"))
.field("unfinished", unfinished as u64)
});
if let Some(sender) = sender.take() {
let _ = sender.send(Overdue { stage, unfinished });
}
}
pub(crate) async fn finish_stage<T>(
future: impl Future<Output = T>,
timeout: Duration,
sender: &mut Option<oneshot::Sender<Overdue>>,
stage: CleanupStage,
unfinished: usize,
) -> T {
tokio::pin!(future);
match tokio::time::timeout(timeout, &mut future).await {
Ok(result) => result,
Err(_) => {
notify(sender, stage, unfinished);
future.await
}
}
}
#[cfg(test)]
mod tests {
use super::*;
use std::sync::Arc;
use std::sync::atomic::AtomicUsize;
#[tokio::test]
async fn timeout_handle_and_dropped_waiter_preserve_exactly_once_cleanup() {
for drop_handle in [false, true] {
let complete = Arc::new(AtomicUsize::new(0));
let counter = complete.clone();
let result = supervise(std::future::ready(()), move |stop, sender| async move {
stop.cancelled().await;
let mut sender = Some(sender);
finish_stage(
async {
tokio::time::sleep(Duration::from_millis(40)).await;
counter.fetch_add(1, Ordering::SeqCst);
},
Duration::from_millis(5),
&mut sender,
CleanupStage::Workers,
1,
)
.await;
Ok(ShutdownReport::default())
})
.await;
let Err(ServerError::ShutdownTimeout {
completion,
stage: CleanupStage::Workers,
unfinished: 1,
}) = result
else {
panic!("missing completion handle")
};
assert_eq!(complete.load(Ordering::SeqCst), 0);
if drop_handle {
drop(completion);
tokio::time::sleep(Duration::from_millis(60)).await;
} else {
completion.await.unwrap();
}
assert_eq!(complete.load(Ordering::SeqCst), 1);
}
}
#[tokio::test]
async fn dropping_serve_notifies_supervisor_without_blocking_drop() {
let complete = Arc::new(AtomicUsize::new(0));
let counter = complete.clone();
let task = tokio::spawn(supervise(
std::future::pending(),
move |stop, _| async move {
stop.cancelled().await;
counter.fetch_add(1, Ordering::SeqCst);
Ok(ShutdownReport::default())
},
));
tokio::task::yield_now().await;
task.abort();
let _ = task.await;
tokio::time::timeout(Duration::from_secs(1), async {
while complete.load(Ordering::SeqCst) == 0 {
tokio::task::yield_now().await;
}
})
.await
.unwrap();
}
}
#[cfg(test)]
mod logging_tests {
use super::*;
use audio2face3d::{
Audio2Face3DContext,
logging::{LogLevel, LogRecord, Logger},
};
use std::sync::{Arc, Mutex};
#[derive(Default)]
struct Sink(Mutex<Vec<(LogLevel, LogRecord)>>);
impl Logger for Sink {
fn log_level(&self) -> LogLevel {
LogLevel::Trace
}
fn write_log(&self, level: LogLevel, record: LogRecord) {
self.0.lock().unwrap().push((level, record));
}
}
#[tokio::test]
async fn overdue_stage_logs_but_still_waits_for_cleanup() {
let sink = Arc::new(Sink::default());
let scope = LogScope::new(Audio2Face3DContext::builder().logger(sink.clone()).build());
let (tx, rx) = oneshot::channel();
let mut tx = Some(tx);
let (release, complete) = oneshot::channel();
let waiting = scope.wrap_future(finish_stage(
async { complete.await.unwrap() },
Duration::from_millis(1),
&mut tx,
CleanupStage::Workers,
3,
));
let (value, notice) = tokio::time::timeout(Duration::from_secs(5), async {
tokio::join!(waiting, async {
let notice = rx.await.unwrap();
release.send(42).unwrap();
notice
})
})
.await
.unwrap();
assert_eq!(value, 42);
assert_eq!(notice.unfinished, 3);
let logs = sink.0.lock().unwrap();
assert_eq!(logs.len(), 1);
assert_eq!(logs[0].0, LogLevel::Warn);
assert!(
logs[0]
.1
.fields
.contains(&("stage".into(), "Workers".into()))
);
assert!(
logs[0]
.1
.fields
.contains(&("unfinished".into(), 3_u64.into()))
);
}
}