use std::sync::{Arc, Condvar, Mutex};
use std::time::{Duration, Instant};
use crate::runtime::background::facility::{recover, run_isolated};
use crate::runtime::task::{MandatoryThread, StackSizeClass, ThreadPriority};
use crate::runtime::taskwd::{CheckIn, TASKWD_DELAY, taskwd_insert};
use crate::server::database::PvDatabase;
use crate::server::record::ScanType;
struct ScanScheduler {
db: Arc<PvDatabase>,
driver: TickDriver,
}
pub(crate) fn periodic_scans() -> Vec<ScanType> {
let menu = crate::server::record::menu_scan();
(0..menu.n_periodic())
.map(|ind| ScanType::Menu(ind as u16 + crate::server::record::SCAN_1ST_PERIODIC))
.collect()
}
const FACILITY: &str = "periodic scan";
fn periodic_priority(ind: usize) -> ThreadPriority {
ThreadPriority::Custom(ThreadPriority::ScanLow.value() + ind as u8)
}
fn periodic_thread_name(period: Duration) -> String {
format!("scan-{}", period.as_secs_f64())
}
struct ScanStop {
stopped: Mutex<bool>,
wake: Condvar,
}
struct ScanStopGuard(Arc<ScanStop>);
impl Drop for ScanStopGuard {
fn drop(&mut self) {
*recover(FACILITY, self.0.stopped.lock()) = true;
self.0.wake.notify_all();
}
}
#[derive(Clone, Copy, PartialEq, Eq, Debug)]
pub enum ScanCtl {
Run,
Pause,
Exit,
}
static SCAN_CTL: std::sync::atomic::AtomicU8 = std::sync::atomic::AtomicU8::new(SCAN_CTL_RUN);
const SCAN_CTL_RUN: u8 = 1;
const SCAN_CTL_PAUSE: u8 = 2;
const SCAN_CTL_EXIT: u8 = 3;
pub fn scan_ctl() -> ScanCtl {
match SCAN_CTL.load(std::sync::atomic::Ordering::Acquire) {
SCAN_CTL_PAUSE => ScanCtl::Pause,
SCAN_CTL_EXIT => ScanCtl::Exit,
_ => ScanCtl::Run,
}
}
pub fn scan_is_running() -> bool {
scan_ctl() == ScanCtl::Run
}
pub fn scan_run() {
SCAN_CTL.store(SCAN_CTL_RUN, std::sync::atomic::Ordering::Release);
crate::runtime::interrupt_accept::set_interrupts_accepted(true);
}
pub fn scan_pause() {
SCAN_CTL.store(SCAN_CTL_PAUSE, std::sync::atomic::Ordering::Release);
crate::runtime::interrupt_accept::set_interrupts_accepted(false);
}
pub fn scan_stop() {
SCAN_CTL.store(SCAN_CTL_EXIT, std::sync::atomic::Ordering::Release);
crate::runtime::interrupt_accept::set_interrupts_accepted(false);
}
#[derive(Clone)]
struct TickDriver {
#[cfg(tokio_backend)]
handle: tokio::runtime::Handle,
}
impl TickDriver {
fn capture() -> Self {
Self {
#[cfg(tokio_backend)]
handle: tokio::runtime::Handle::try_current().expect(
"ScanOwner::start on the tokio backend must be called inside a tokio runtime",
),
}
}
fn drive<F: Future>(&self, fut: F) -> F::Output {
#[cfg(tokio_backend)]
{
self.handle.block_on(fut)
}
#[cfg(exec_backend)]
{
match crate::runtime::task::block_on_sync(fut) {
Ok(out) => out,
Err(e) => unreachable!("a periodic scan thread is blockable: {e}"),
}
}
}
}
const OVERRUN_REPORT_DELAY: f64 = 10.0;
const OVERRUN_REPORT_MAX: f64 = 3600.0;
struct TickOutcome {
overran: bool,
warning: Option<String>,
}
struct OverrunTracker {
scan: ScanType,
period: Duration,
penalty: Duration,
consecutive: u32,
overtime: f64,
over_min: f64,
over_max: f64,
report_delay: f64,
reported: Instant,
}
impl OverrunTracker {
fn penalty_for(period: Duration) -> Duration {
if period >= Duration::from_secs(2) {
Duration::from_secs(1)
} else {
period / 2
}
}
fn new(scan: ScanType, period: Duration, start: Instant) -> Self {
Self {
scan,
period,
penalty: Self::penalty_for(period),
consecutive: 0,
overtime: 0.0,
over_min: 0.0,
over_max: 0.0,
report_delay: OVERRUN_REPORT_DELAY,
reported: start,
}
}
fn after_scan(&mut self, next: &mut Instant, now: Instant) -> TickOutcome {
*next += self.period;
if now < *next {
self.consecutive = 0;
self.report_delay = OVERRUN_REPORT_DELAY;
self.overtime = 0.0;
return TickOutcome {
overran: false,
warning: None,
};
}
let over = (now - *next).as_secs_f64();
if self.overtime == 0.0 {
self.overtime = over;
self.over_min = over;
self.over_max = over;
} else {
self.overtime += over;
self.over_min = self.over_min.min(over);
self.over_max = self.over_max.max(over);
}
*next = now + self.penalty;
self.consecutive += 1;
let warning =
if self.consecutive >= 10 && (now - self.reported).as_secs_f64() > self.report_delay {
let period = self.period.as_secs_f64();
let scan = self.scan;
let msg = format!(
"\ndbScan {} from '{scan}' scan thread:\n\tScan processing \
averages {:.3} seconds ({:.3} .. {:.3}).\n\tOver-runs have now \
happened {} times in a row.\n\tTo fix this, move some records \
to a slower scan rate.\n",
crate::runtime::log::erl_warning(),
period + self.overtime / f64::from(self.consecutive),
period + self.over_min,
period + self.over_max,
self.consecutive,
);
self.reported = now;
if self.report_delay < OVERRUN_REPORT_MAX / 2.0 {
self.report_delay *= 2.0;
} else {
self.report_delay = OVERRUN_REPORT_MAX;
}
Some(msg)
} else {
None
};
TickOutcome {
overran: true,
warning,
}
}
}
fn periodic_loop(
db: Arc<PvDatabase>,
scan_type: ScanType,
period: Duration,
stop: Arc<ScanStop>,
driver: TickDriver,
) {
let watched = taskwd_insert(
periodic_thread_name(period),
CheckIn::Every(period * 2 + TASKWD_DELAY),
None,
);
let mut next = Instant::now() + period;
let mut overrun = OverrunTracker::new(scan_type, period, Instant::now());
loop {
watched.check_in();
let mut stopped = recover(FACILITY, stop.stopped.lock());
loop {
if *stopped || scan_ctl() == ScanCtl::Exit {
return;
}
let now = Instant::now();
if now >= next {
break;
}
let (guard, _timeout) = recover(FACILITY, stop.wake.wait_timeout(stopped, next - now));
stopped = guard;
}
drop(stopped);
if scan_is_running() {
run_isolated(FACILITY, || {
driver.drive(async {
if let Some(list) = scan_type.scan_list() {
db.scan_list_once(list).await;
}
});
});
}
let outcome = overrun.after_scan(&mut next, Instant::now());
if outcome.overran {
db.record_scan_overrun(scan_type);
}
if let Some(warning) = outcome.warning {
crate::runtime::log::errlog_printf(&warning);
}
}
}
impl ScanScheduler {
fn new(db: Arc<PvDatabase>, driver: TickDriver) -> Self {
Self { db, driver }
}
async fn run(&self) {
let is_first = self.db.try_claim_scan_start();
if !is_first {
std::future::pending::<()>().await;
return;
}
let scans = periodic_scans();
crate::runtime::task::background_scan_once_start();
if !self.db.pini_done() {
self.db
.pini_process(crate::server::record::PiniMode::Yes)
.await;
}
self.db.mark_pini_done();
let stop = Arc::new(ScanStop {
stopped: Mutex::new(false),
wake: Condvar::new(),
});
let guard = ScanStopGuard(Arc::clone(&stop));
let driver = &self.driver;
for (ind, scan_type) in scans.into_iter().enumerate() {
if let Some(period) = scan_type.interval() {
let db = Arc::clone(&self.db);
let stop = Arc::clone(&stop);
let driver = driver.clone();
MandatoryThread::new(
periodic_thread_name(period),
periodic_priority(ind),
StackSizeClass::Big,
)
.spawn(move || {
periodic_loop(db, scan_type, period, stop, driver);
});
}
}
let _guard = guard;
std::future::pending::<()>().await;
}
}
pub struct ScanOwner {
stop: Option<crate::runtime::sync::oneshot::Sender<()>>,
join: Option<std::thread::JoinHandle<()>>,
}
impl ScanOwner {
pub fn start(db: Arc<PvDatabase>) -> Self {
crate::server::ioc_app::note_scan_owner_started();
let (stop_tx, stop_rx) = crate::runtime::sync::oneshot::channel::<()>();
let driver = TickDriver::capture();
let join = MandatoryThread::new(
"scan-owner",
ThreadPriority::Low,
StackSizeClass::Medium,
)
.spawn(move || {
let scheduler = ScanScheduler::new(db, driver.clone());
let owner = async move {
tokio::select! {
_ = scheduler.run() => {}
_ = stop_rx => {}
}
};
driver.drive(owner);
});
Self {
stop: Some(stop_tx),
join: Some(join),
}
}
}
impl Drop for ScanOwner {
fn drop(&mut self) {
scan_stop();
if let Some(tx) = self.stop.take() {
let _ = tx.send(());
}
if let Some(join) = self.join.take() {
let _ = join.join();
}
}
}
#[cfg(test)]
mod overrun_tests {
use super::*;
fn run(period: Duration, sweep: Duration, ticks: u32, base: Instant) -> Vec<String> {
let mut next = base + period;
let mut tracker = OverrunTracker::new(ScanType::SEC1, period, base);
let mut warnings = Vec::new();
for i in 1..=ticks {
let now = base + sweep * i;
if let Some(w) = tracker.after_scan(&mut next, now).warning {
warnings.push(w);
}
}
warnings
}
#[test]
fn the_penalty_branches_at_a_two_second_period() {
assert_eq!(
OverrunTracker::penalty_for(Duration::from_secs(10)),
Duration::from_secs(1)
);
assert_eq!(
OverrunTracker::penalty_for(Duration::from_secs(2)),
Duration::from_secs(1)
);
assert_eq!(
OverrunTracker::penalty_for(Duration::from_millis(1999)),
Duration::from_micros(999_500)
);
assert_eq!(
OverrunTracker::penalty_for(Duration::from_millis(100)),
Duration::from_millis(50)
);
}
#[test]
fn an_on_time_sweep_advances_the_deadline_by_one_period() {
let base = Instant::now();
let period = Duration::from_secs(10);
let mut next = base + period;
let mut tracker = OverrunTracker::new(ScanType::SEC10, period, base);
let outcome = tracker.after_scan(&mut next, base + Duration::from_secs(3));
assert!(!outcome.overran);
assert!(outcome.warning.is_none());
assert_eq!(next, base + Duration::from_secs(20));
}
#[test]
fn an_over_run_retries_after_the_penalty_not_a_whole_period() {
let base = Instant::now();
let period = Duration::from_secs(10);
let mut next = base + period;
let mut tracker = OverrunTracker::new(ScanType::SEC10, period, base);
let now = base + Duration::from_secs(21);
let outcome = tracker.after_scan(&mut next, now);
assert!(outcome.overran);
assert_eq!(
next,
base + Duration::from_secs(22),
"C `dbScan.c:826-830`: delay = penalty, next = now + delay"
);
}
#[test]
fn a_sweep_that_lands_exactly_on_the_deadline_is_an_over_run() {
let base = Instant::now();
let period = Duration::from_secs(1);
let mut next = base + period;
let mut tracker = OverrunTracker::new(ScanType::SEC1, period, base);
let now = base + Duration::from_secs(2);
assert!(tracker.after_scan(&mut next, now).overran);
assert_eq!(next, now + Duration::from_millis(500));
}
#[test]
fn the_report_fires_on_the_tenth_consecutive_over_run() {
let base = Instant::now();
let period = Duration::from_secs(1);
let sweep = Duration::from_secs(2);
assert!(
run(period, sweep, 9, base).is_empty(),
"the ninth consecutive over-run is still silent"
);
let warnings = run(period, sweep, 10, base);
assert_eq!(warnings.len(), 1, "the tenth reports");
let w = &warnings[0];
assert!(w.contains("from '1 second' scan thread"), "{w}");
assert!(w.contains("10 times in a row"), "{w}");
assert!(w.contains("move some records to a slower scan rate"), "{w}");
}
#[test]
fn the_report_interval_doubles_after_each_report() {
let base = Instant::now();
let warnings = run(Duration::from_secs(1), Duration::from_secs(2), 21, base);
assert_eq!(warnings.len(), 2, "reports at tick 10 and tick 21");
assert!(warnings[1].contains("21 times in a row"), "{}", warnings[1]);
}
#[test]
fn an_on_time_sweep_resets_the_consecutive_run() {
let base = Instant::now();
let period = Duration::from_secs(1);
let mut next = base + period;
let mut tracker = OverrunTracker::new(ScanType::SEC1, period, base);
for i in 1..=9u32 {
tracker.after_scan(&mut next, base + Duration::from_secs(2) * i);
}
assert_eq!(tracker.consecutive, 9);
next = base + Duration::from_secs(100);
tracker.after_scan(&mut next, base + Duration::from_secs(100));
assert_eq!(tracker.consecutive, 0);
assert_eq!(tracker.report_delay, OVERRUN_REPORT_DELAY);
}
}
#[cfg(test)]
mod tests {
use super::*;
#[test]
fn periodic_ladder_matches_dbscan() {
let expected: &[(ScanType, u8, &str)] = &[
(ScanType::SEC10, 60, "scan-10"),
(ScanType::SEC5, 61, "scan-5"),
(ScanType::SEC2, 62, "scan-2"),
(ScanType::SEC1, 63, "scan-1"),
(ScanType::SEC05, 64, "scan-0.5"),
(ScanType::SEC02, 65, "scan-0.2"),
(ScanType::SEC01, 66, "scan-0.1"),
];
let rates = periodic_scans();
assert_eq!(rates.len(), expected.len());
for (ind, &(scan_type, prio, name)) in expected.iter().enumerate() {
assert_eq!(rates[ind], scan_type, "order is load-bearing");
assert_eq!(periodic_priority(ind).value(), prio);
let period = scan_type.interval().expect("periodic rate has a period");
assert_eq!(periodic_thread_name(period), name);
}
}
#[test]
fn periodic_ladder_stays_inside_the_scan_band() {
for ind in 0..periodic_scans().len() {
let v = periodic_priority(ind).value();
assert!(v >= ThreadPriority::ScanLow.value());
assert!(v < ThreadPriority::ScanHigh.value());
assert!(v > ThreadPriority::CaServerHigh.value());
}
}
#[tokio::test(flavor = "multi_thread", worker_threads = 2)]
async fn cancelling_the_scheduler_stops_the_scan_threads() {
let db = Arc::new(PvDatabase::new());
let scheduler = ScanScheduler::new(Arc::clone(&db), TickDriver::capture());
let task = tokio::spawn(async move { scheduler.run().await });
let deadline = Instant::now() + Duration::from_secs(10);
while Arc::strong_count(&db) < 2 + periodic_scans().len() {
assert!(Instant::now() < deadline, "scan threads never started");
tokio::time::sleep(Duration::from_millis(10)).await;
}
task.abort();
let _ = task.await;
let deadline = Instant::now() + Duration::from_secs(10);
while Arc::strong_count(&db) > 1 {
assert!(
Instant::now() < deadline,
"scan threads still alive after cancellation: {} Arc holders",
Arc::strong_count(&db)
);
tokio::time::sleep(Duration::from_millis(10)).await;
}
}
#[tokio::test(flavor = "multi_thread", worker_threads = 2)]
async fn a_periodic_tick_processes_on_its_own_banded_scan_thread() {
use crate::error::CaResult;
use crate::server::record::{FieldDesc, ProcessOutcome, Record};
use crate::types::EpicsValue;
struct ThreadProbe(Arc<Mutex<Option<String>>>);
impl Record for ThreadProbe {
fn record_type(&self) -> &'static str {
"scan_thread_probe"
}
fn process(&mut self) -> CaResult<ProcessOutcome> {
let name = std::thread::current().name().map(str::to_string);
*self.0.lock().expect("probe mutex") = name;
Ok(ProcessOutcome::complete())
}
fn get_field(&self, name: &str) -> Option<EpicsValue> {
match name {
"VAL" => Some(EpicsValue::Double(0.0)),
_ => None,
}
}
fn put_field(&mut self, _name: &str, _value: EpicsValue) -> CaResult<()> {
Ok(())
}
fn declared_fields(&self) -> &'static [FieldDesc] {
&[]
}
}
let seen = Arc::new(Mutex::new(None::<String>));
let db = Arc::new(PvDatabase::new());
db.add_record("SCAN:THREAD", Box::new(ThreadProbe(Arc::clone(&seen))))
.await
.unwrap();
{
let rec = db.get_record("SCAN:THREAD").unwrap();
rec.write().common.scan = ScanType::SEC01;
}
db.update_scan_index("SCAN:THREAD", ScanType::Passive, ScanType::SEC01, 0, 0);
let owner = ScanOwner::start(Arc::clone(&db));
let deadline = Instant::now() + Duration::from_secs(10);
let name = loop {
if let Some(n) = seen.lock().expect("probe mutex").clone() {
break n;
}
assert!(Instant::now() < deadline, "the record was never scanned");
tokio::time::sleep(Duration::from_millis(10)).await;
};
drop(owner);
let expected = periodic_thread_name(ScanType::SEC01.interval().unwrap());
assert_eq!(
name, expected,
"the .1 second tick processed on `{name}`, not on its own \
banded `{expected}` thread — periodic scan is back on a \
shared pool"
);
}
#[tokio::test(flavor = "multi_thread", worker_threads = 2)]
async fn a_running_scan_thread_is_listed_by_the_task_watchdog() {
fn table() -> String {
let out = std::cell::RefCell::new(String::new());
crate::runtime::taskwd::taskwd_show(1, &|line| {
out.borrow_mut().push_str(line);
out.borrow_mut().push('\n');
});
out.into_inner()
}
let wanted = periodic_thread_name(ScanType::SEC01.interval().unwrap());
assert!(
!table().contains(&wanted),
"`{wanted}` was registered before any scan thread started"
);
let db = Arc::new(PvDatabase::new());
let owner = ScanOwner::start(Arc::clone(&db));
let deadline = Instant::now() + Duration::from_secs(10);
while !table().contains(&wanted) {
assert!(
Instant::now() < deadline,
"`{wanted}` never reached the watchdog table:\n{}",
table()
);
tokio::time::sleep(Duration::from_millis(10)).await;
}
drop(owner);
let deadline = Instant::now() + Duration::from_secs(10);
while table().contains(&wanted) {
assert!(
Instant::now() < deadline,
"`{wanted}` stayed registered after its thread exited:\n{}",
table()
);
tokio::time::sleep(Duration::from_millis(10)).await;
}
}
#[tokio::test(flavor = "multi_thread", worker_threads = 2)]
async fn starting_the_scan_owner_creates_the_scan_once_worker() {
fn table() -> String {
let out = std::cell::RefCell::new(String::new());
crate::runtime::taskwd::taskwd_show(1, &|line| {
out.borrow_mut().push_str(line);
out.borrow_mut().push('\n');
});
out.into_inner()
}
assert!(
!table().contains("scanOnce"),
"the one-shot worker existed before any scan owner started"
);
let db = Arc::new(PvDatabase::new());
let _owner = ScanOwner::start(Arc::clone(&db));
let deadline = Instant::now() + Duration::from_secs(10);
while !table().contains("scanOnce") {
assert!(
Instant::now() < deadline,
"`scanOnce` never reached the watchdog table:\n{}",
table()
);
tokio::time::sleep(Duration::from_millis(10)).await;
}
}
async fn wait_for_count(db: &Arc<PvDatabase>, what: &str, pred: impl Fn(usize) -> bool) {
let deadline = Instant::now() + Duration::from_secs(10);
while !pred(Arc::strong_count(db)) {
assert!(
Instant::now() < deadline,
"{what}: {} Arc holders",
Arc::strong_count(db)
);
tokio::time::sleep(Duration::from_millis(10)).await;
}
}
#[tokio::test(flavor = "multi_thread", worker_threads = 2)]
async fn dropping_the_scan_owner_stops_the_scan_threads() {
let db = Arc::new(PvDatabase::new());
let owner = ScanOwner::start(Arc::clone(&db));
wait_for_count(&db, "scan threads never started", |n| {
n >= 2 + periodic_scans().len()
})
.await;
drop(owner);
wait_for_count(&db, "scan threads still alive after ScanOwner drop", |n| {
n == 1
})
.await;
}
#[tokio::test(flavor = "multi_thread", worker_threads = 2)]
async fn the_owner_skips_pini_when_the_init_path_already_ran_it() {
use crate::server::record::PiniMode;
use crate::server::records::ai::AiRecord;
use crate::types::EpicsValue;
let db = Arc::new(PvDatabase::new());
db.add_record("PINI:ONCE", Box::new(AiRecord::new(1.5)))
.await
.unwrap();
{
let rec = db.get_record("PINI:ONCE").unwrap();
let mut inst = rec.write();
inst.put_common_field("PINI", EpicsValue::String("YES".into()))
.unwrap();
inst.common.udf = 0;
}
db.pini_process(PiniMode::Yes).await;
db.mark_pini_done();
let t_init = db.get_record("PINI:ONCE").unwrap().read().common.time;
let owner = ScanOwner::start(Arc::clone(&db));
wait_for_count(&db, "scan threads never started", |n| {
n >= 2 + periodic_scans().len()
})
.await;
let t_owner = db.get_record("PINI:ONCE").unwrap().read().common.time;
assert_eq!(
t_owner, t_init,
"the owner re-ran the PINI=YES pass the init path already ran"
);
drop(owner);
}
#[tokio::test(flavor = "multi_thread", worker_threads = 2)]
async fn the_owner_runs_pini_when_nothing_pre_ran_it() {
use crate::server::records::ai::AiRecord;
use crate::types::EpicsValue;
let db = Arc::new(PvDatabase::new());
db.add_record("PINI:OWNED", Box::new(AiRecord::new(2.5)))
.await
.unwrap();
let t_unprocessed = {
let rec = db.get_record("PINI:OWNED").unwrap();
let mut inst = rec.write();
inst.put_common_field("PINI", EpicsValue::String("YES".into()))
.unwrap();
inst.common.udf = 0;
inst.common.time
};
let owner = ScanOwner::start(Arc::clone(&db));
wait_for_count(&db, "scan threads never started", |n| {
n >= 2 + periodic_scans().len()
})
.await;
let t_owner = db.get_record("PINI:OWNED").unwrap().read().common.time;
assert!(
t_owner > t_unprocessed,
"the owner must run the PINI=YES pass when the init path did not"
);
drop(owner);
}
#[tokio::test(flavor = "multi_thread", worker_threads = 2)]
async fn a_redundant_scan_owner_parks_and_its_drop_is_harmless() {
let db = Arc::new(PvDatabase::new());
let first = ScanOwner::start(Arc::clone(&db));
wait_for_count(&db, "scan threads never started", |n| {
n >= 2 + periodic_scans().len()
})
.await;
let with_first = Arc::strong_count(&db) - 1;
let second = ScanOwner::start(Arc::clone(&db));
drop(second);
wait_for_count(&db, "second owner's drop leaked or killed holders", |n| {
n == with_first + 1
})
.await;
drop(first);
wait_for_count(
&db,
"scan threads still alive after first owner drop",
|n| n == 1,
)
.await;
}
}