rstango 0.4.0

//! Implementation of the polling of the attributes and commands of the devices of a
//! server: what reads them at their period, records what it read in their history, which
//! a read from the cache is answered with, and sends their periodic events.
//!
//! # Where a period comes from
//!
//! A device is polled for what it is given when it is initialized, see [`Dev::init`], an
//! object being given the first period found of, in that order:
//!
//! 1. the `polled_attr` or `polled_cmd` property of the device in the database, a list
//!    of names each followed by its period in milliseconds;
//! 2. the period its definition asks for, see [`AttrDef::polled`] and
//!    [`CommandDef::polled`];
//!
//! and is not polled when neither gives one. The admin device changes the polling of a
//! running device, see [`Poller::add`], and writes the property along, so that the next
//! initialization finds it. A period the definition asks for therefore comes back on the
//! next initialization once removed, there being no way for the property to say that an
//! object is not polled.
//!
//! # One thread, never blocked
//!
//! Every device of a server is polled by a single thread, which is the executor of the
//! polls rather than a caller of them: a poll is the very request a client would make, see
//! [`AnyDev::poll`], which runs on the pool of the server whatever may block in it, see
//! [`crate::pool::run`], so that the thread only ever waits for the next poll to be due or
//! for one of those in progress to be through, and never for any of them in particular. A
//! device slow to answer delays nothing but its own polls.
//!
//! # A grid, and batches
//!
//! An object is polled right away once given a period, and then on the grid of that
//! period: every multiple of it counted from the same origin, the start of the polling, see
//! [`grid_after`]. An object is only polled again once its previous poll is through, at the
//! next point of its grid: a poll late by more than a period skips the polls it missed
//! rather than running them all at once, and stays on its grid.
//!
//! The objects of a device due at the same time are polled together, see [`AnyDev::poll`]:
//! those of the same period always are, and those whose periods share multiples are
//! whenever their grids meet, which a common origin makes them do exactly. Attributes are
//! read at once, under a single lock of the model, the way a client reading several
//! attributes at once reads them; commands are executed one after the other.
//!
//! [`Dev::init`]: super::Dev
//! [`AttrDef::polled`]: super::AttrDef::polled
//! [`CommandDef::polled`]: super::CommandDef::polled

use std::time::{Duration, Instant, SystemTime};
use std::sync::{Arc, Mutex, Weak};
use std::thread::{self, Thread};
use std::task::{ready, Context, Poll};
use std::collections::HashMap;
use std::future::Future;
use std::pin::Pin;
use std::fmt::Write;

use futures::stream::{FuturesUnordered, StreamExt};
use futures::future::BoxFuture;
use tracing::{debug, warn};

use crate::error::{reason, Error, ErrorKind, Result};
use crate::name::{ArcName, Name};

use super::dev::AnyDev;


/// How many periods the latest result of a poll answers a read from the cache for, unless
/// the `poll_old_factor` property of the device says otherwise, as with cppTango.
pub const DEFAULT_VALIDITY_PERIODS: u32 = 4;

/// The shortest period an object is polled at, as with cppTango.
pub const MIN_PERIOD: Duration = Duration::from_millis(5);

/// The period of the periodic event of an attribute whose configuration gives none, as
/// with cppTango.
pub const DEFAULT_PERIODIC_EVENT_PERIOD: Duration = Duration::from_secs(1);

/// How much of the period of the periodic event is enough for a poll to send the next
/// one, so that an attribute polled at that very period, whose polls come a little early
/// or late, sends one on every poll, as with cppTango.
pub const PERIODIC_EVENT_TOLERANCE: f64 = 0.98;

/// What is polled of a device: one of its attributes, or one of its commands.
#[derive(Debug, Clone, Copy, PartialEq, Eq, PartialOrd, Ord, Hash)]
pub enum PolledKind {
    Attr,
    Command,
}

impl PolledKind {

    /// The kind of object of that name, as the admin commands name them.
    pub fn parse(name: &str) -> Result<Self> {
        if name.eq_ignore_ascii_case("attribute") {
            Ok(Self::Attr)
        } else if name.eq_ignore_ascii_case("command") {
            Ok(Self::Command)
        } else {
            Err(Error::new(ErrorKind::Reason(reason::API_NotSupported))
                .with_description(format!("Object type {name:?} cannot be polled, only an \
                    attribute or a command can")))
        }
    }

    /// The name of that kind of object, as the admin commands name them.
    pub fn as_str(self) -> &'static str {
        match self {
            Self::Attr => "attribute",
            Self::Command => "command",
        }
    }

}

/// An object a device is polled for, see [`Poller::set_dev`].
#[derive(Debug, Clone)]
pub struct Polled {
    pub kind: PolledKind,
    /// The name of the object, as its definition gives it.
    pub name: Arc<str>,
    pub period: Duration,
}

/// What an object polled is, for the polling status of its device, see
/// [`Poller::status`].
#[derive(Debug, Clone)]
pub struct PolledStatus {
    pub kind: PolledKind,
    pub name: Arc<str>,
    pub period: Duration,
    /// How long its last poll took, absent until it is through.
    pub last_duration: Option<Duration>,
}

/// What the history of a polled object holds, for the polling status of its device, see
/// [`AnyDev::polled_history`].
#[derive(Debug, Clone)]
pub struct PolledHistory {
    /// How many results the history keeps at most.
    pub depth: usize,
    /// When the latest results were recorded, oldest first.
    pub times: Vec<SystemTime>,
    /// What the latest result failed with, if it did.
    pub failure: Option<Error>,
}

/// The polling of the devices of a server, which the server owns: one thread polling them
/// all, see the [module](self), and what it is asked to poll.
#[derive(Debug, Clone)]
pub struct Poller {
    /// What is polled, which the polling thread shares.
    state: Arc<Mutex<State>>,
    /// The polling thread, unparked whenever what it polls changes, see [`Self::wake`].
    thread: Thread,
}

#[derive(Debug)]
struct State {
    /// What is polled, by device name.
    devs: HashMap<ArcName, PolledDev>,
    /// Whether nothing is polled for now, see [`Poller::pause`] and [`Poller::resume`].
    paused: bool,
    /// Set once the server is gone, which ends the polling thread.
    shutdown: bool,
    /// The identifier of the next object polled, see [`PolledEntry::id`].
    next_id: u64,
    /// What every grid counts from, see [`grid_after`].
    origin: Instant,
}

/// What a device is polled for.
#[derive(Debug)]
struct PolledDev {
    /// The device, which is only held while one of its polls runs.
    dev: Weak<dyn AnyDev>,
    /// How many periods the latest result of a poll answers a read from the cache for.
    validity_periods: u32,
    attrs: HashMap<ArcName, PolledEntry>,
    commands: HashMap<ArcName, PolledEntry>,
}

/// An object polled.
#[derive(Debug)]
struct PolledEntry {
    /// What tells this object from one polled again under the same name while a poll of it
    /// was in progress, whose end is then no longer its own.
    id: u64,
    /// The name of the object, as its definition gives it.
    name: Arc<str>,
    period: Duration,
    /// When the next poll is due.
    due: Instant,
    /// Whether a poll is in progress, which is never more than one.
    in_progress: bool,
    /// How long the last poll took.
    last_duration: Option<Duration>,
    /// When the last periodic event was sent, see [`AnyDev::poll`].
    last_periodic: Option<Instant>,
}

/// An object a poll is of, as the device is given it, see [`AnyDev::poll`].
#[derive(Debug, Clone)]
pub struct PollItem {
    /// The identifier of the entry of that object, which only the polling has any use
    /// for, see [`PolledEntry::id`].
    pub id: u64,
    /// The name of the object, as its definition gives it.
    pub name: Arc<str>,
    /// How long what the poll records answers a read from the cache for.
    pub valid_for: Duration,
    /// When the last periodic event of the attribute was sent, which the end of the poll
    /// updates, see [`PollRun`].
    pub last_periodic: Option<Instant>,
}

/// A poll to start, taken out of the state so that it is started without its lock: the
/// attributes, or the commands, of a device that are due together, see the [module](self).
struct PollStart {
    dev: Arc<dyn AnyDev>,
    kind: PolledKind,
    items: Vec<PollItem>,
}

/// A poll that is through, which the state is told of.
struct PollEnd {
    dev: Arc<str>,
    kind: PolledKind,
    items: Vec<PollItem>,
    last_duration: Duration,
}

impl Poller {

    /// The polling of a server, its thread started, and nothing polled yet.
    pub fn spawn() -> Result<Self> {

        let builder = thread::Builder::new()
            .name("server-polling".to_string());

        let state = Arc::new(Mutex::new(State {
            devs: HashMap::new(),
            paused: false,
            shutdown: false,
            next_id: 0,
            origin: Instant::now(),
        }));

        let handle = {
            let state = Arc::clone(&state);
            builder.spawn(move || run_thread(&state))
                .map_err(|err| Error::new(ErrorKind::Internal)
                    .with_description(format!("Failed to start the polling thread: {err}")))?
        };

        Ok(Self {
            state,
            thread: handle.thread().clone(),
        })

    }

    /// Have the polling thread look at what it polls again.
    fn wake(&self) {
        self.thread.unpark();
    }

    /// Change what is polled under that lock, and wake the polling thread to it.
    fn change<T>(&self, func: impl FnOnce(&mut State) -> T) -> T {
        let ret = func(&mut self.state.lock().unwrap());
        self.wake();
        ret
    }

    /// Poll that device for these objects, and for nothing else, which replaces what it
    /// was polled for, under its name, a device restarted included: what a device is
    /// given when it is initialized, see the [module](self). Every object is polled right
    /// away.
    pub fn set_dev(&self, dev: &Arc<dyn AnyDev>, validity_periods: u32, polled: Vec<Polled>) {
        self.change(|state| {

            let mut polled_dev = PolledDev {
                dev: Arc::downgrade(dev),
                validity_periods,
                attrs: HashMap::new(),
                commands: HashMap::new(),
            };

            let now = Instant::now();
            for polled in polled {
                let entry = state.new_entry(polled.name, polled.period, now);
                polled_dev.entries_mut(polled.kind).insert(ArcName::from(Arc::clone(&entry.name)), entry);
            }

            state.devs.insert(ArcName::from(Arc::clone(dev.name())), polled_dev);

        });
    }

    /// Stop polling that device, if it is still the one polled under its name: what a
    /// device that is withdrawn goes through.
    pub fn remove_dev(&self, dev: &dyn AnyDev) {
        self.change(|state| {
            let name = Name::new(dev.name());
            if state.devs.get(name).is_some_and(|polled_dev| polled_dev.is(dev)) {
                state.devs.remove(name);
            }
        });
    }

    /// Poll that object of that device at that period, failing if it is already polled.
    pub fn add(&self, dev: &Arc<dyn AnyDev>, kind: PolledKind, name: Arc<str>, period: Duration) -> Result<()> {
        self.change(|state| {

            let now = Instant::now();
            let entry = state.new_entry(name, period, now);
            let polled_dev = state.devs.entry(ArcName::from(Arc::clone(dev.name())))
                .or_insert_with(|| PolledDev {
                    dev: Arc::downgrade(dev),
                    validity_periods: DEFAULT_VALIDITY_PERIODS,
                    attrs: HashMap::new(),
                    commands: HashMap::new(),
                });

            let entries = polled_dev.entries_mut(kind);
            if entries.contains_key(Name::new(&entry.name)) {
                return Err(Error::new(ErrorKind::Reason(reason::API_AlreadyPolled))
                    .with_description(format!("The {} {:?} of device {:?} is already polled",
                        kind.as_str(), entry.name, dev.name())));
            }

            entries.insert(ArcName::from(Arc::clone(&entry.name)), entry);
            Ok(())

        })
    }

    /// Poll that object of that device at another period, failing if it is not polled. It
    /// is polled right away, and at the new period from then on.
    pub fn set_period(&self, dev: &str, kind: PolledKind, name: &str, period: Duration) -> Result<()> {
        self.change(|state| {
            let entry = state.entry_mut(dev, kind, name)?;
            entry.period = period;
            entry.due = Instant::now();
            Ok(())
        })
    }

    /// Stop polling that object of that device, failing if it is not polled.
    pub fn remove(&self, dev: &str, kind: PolledKind, name: &str) -> Result<()> {
        self.change(|state| {
            state.entry_mut(dev, kind, name)?;
            if let Some(polled_dev) = state.devs.get_mut(Name::new(dev)) {
                polled_dev.entries_mut(kind).remove(Name::new(name));
            }
            Ok(())
        })
    }

    /// The period that object of that device is polled at, if it is.
    pub fn period(&self, dev: &str, kind: PolledKind, name: &str) -> Option<Duration> {
        let state = self.state.lock().unwrap();
        let polled_dev = state.devs.get(Name::new(dev))?;
        polled_dev.entries(kind).get(Name::new(name)).map(|entry| entry.period)
    }

    /// The names of the devices polled for anything, by name.
    pub fn polled_devs(&self) -> Vec<Arc<str>> {
        let state = self.state.lock().unwrap();
        let mut names = state.devs.iter()
            .filter(|(_, polled_dev)| !polled_dev.attrs.is_empty() || !polled_dev.commands.is_empty())
            .filter_map(|(_, polled_dev)| polled_dev.dev.upgrade().map(|dev| Arc::clone(dev.name())))
            .collect::<Vec<_>>();
        names.sort();
        names
    }

    /// What that device is polled for, the commands first, then the attributes, each by
    /// name.
    pub fn status(&self, dev: &str) -> Vec<PolledStatus> {

        let state = self.state.lock().unwrap();
        let Some(polled_dev) = state.devs.get(Name::new(dev)) else {
            return Vec::new();
        };

        let mut status = [PolledKind::Command, PolledKind::Attr].into_iter()
            .flat_map(|kind| polled_dev.entries(kind).values().map(move |entry| PolledStatus {
                kind,
                name: Arc::clone(&entry.name),
                period: entry.period,
                last_duration: entry.last_duration,
            }))
            .collect::<Vec<_>>();

        status.sort_by(|a, b| b.kind.cmp(&a.kind).then_with(|| a.name.cmp(&b.name)));
        status

    }

    /// Poll again what is polled, every object right away, after a [`Self::pause`]: what
    /// the `StartPolling` command of the admin device does.
    pub fn resume(&self) {
        self.change(|state| {
            state.paused = false;
            let now = Instant::now();
            for polled_dev in state.devs.values_mut() {
                for entry in polled_dev.attrs.values_mut().chain(polled_dev.commands.values_mut()) {
                    entry.due = now;
                }
            }
        });
    }

    /// Poll nothing until [`Self::resume`], what is polled being kept: what the
    /// `StopPolling` command of the admin device does. The polls in progress are let
    /// through.
    pub fn pause(&self) {
        self.change(|state| state.paused = true);
    }

    /// End the polling thread for good, the server being gone: the polls in progress
    /// are dropped, which does not stop what they were running on the pool.
    pub fn shutdown(&self) {
        self.change(|state| state.shutdown = true);
    }

}

impl State {

    /// A new object polled at that period, due right away.
    fn new_entry(&mut self, name: Arc<str>, period: Duration, now: Instant) -> PolledEntry {
        let id = self.next_id;
        self.next_id += 1;
        PolledEntry {
            id,
            name,
            period,
            due: now,
            in_progress: false,
            last_duration: None,
            last_periodic: None,
        }
    }

    /// The object of that device that is polled, failing if it is not.
    fn entry_mut(&mut self, dev: &str, kind: PolledKind, name: &str) -> Result<&mut PolledEntry> {
        self.devs.get_mut(Name::new(dev))
            .and_then(|polled_dev| polled_dev.entries_mut(kind).get_mut(Name::new(name)))
            .ok_or_else(|| Error::new(ErrorKind::Reason(reason::API_PollObjNotFound))
                .with_description(format!("The {} {name:?} of device {dev:?} is not polled", kind.as_str())))
    }

    /// Take out every poll that is due, marking it in progress, and give back when the next one
    /// is due, if anything is to be polled. A device that is gone is forgotten.
    fn take_due(&mut self, now: Instant) -> (Vec<PollStart>, Option<Instant>) {

        let mut starts = Vec::new();
        let mut next = None::<Instant>;

        if self.paused {
            return (starts, next);
        }

        self.devs.retain(|_, polled_dev| {

            let Some(dev) = polled_dev.dev.upgrade() else {
                return false;
            };

            let validity_periods = polled_dev.validity_periods;

            // The entry taken if it is due, or when it will be noted otherwise.
            let mut take = |entry: &mut PolledEntry| -> Option<PollItem> {

                if entry.in_progress {
                    return None;
                }

                if entry.due > now {
                    next = Some(next.map_or(entry.due, |next| next.min(entry.due)));
                    return None;
                }

                entry.in_progress = true;
                Some(PollItem {
                    id: entry.id,
                    name: Arc::clone(&entry.name),
                    valid_for: entry.period.saturating_mul(validity_periods),
                    last_periodic: entry.last_periodic,
                })

            };

            // What is due together is polled together, see the [module](self).
            for kind in [PolledKind::Attr, PolledKind::Command] {

                let items = polled_dev.entries_mut(kind)
                    .values_mut()
                    .filter_map(&mut take)
                    .collect::<Vec<_>>();

                if !items.is_empty() {
                    starts.push(PollStart {
                        dev: Arc::clone(&dev),
                        kind,
                        items,
                    });
                }

            }

            true

        });

        (starts, next)

    }

    /// Record that a poll is through, the next one of each of its objects being due at the
    /// next point of its grid, see the [module](self).
    fn finish(&mut self, end: PollEnd, now: Instant) {

        let origin = self.origin;
        let Some(polled_dev) = self.devs.get_mut(Name::new(&end.dev)) else { return };

        for item in end.items {

            let Some(entry) = polled_dev.entries_mut(end.kind).get_mut(Name::new(&item.name)) else { continue };

            // An object polled again meanwhile is another entry, which this poll is not of.
            if entry.id != item.id {
                continue;
            }

            entry.in_progress = false;
            entry.last_duration = Some(end.last_duration);
            entry.last_periodic = item.last_periodic;
            entry.due = grid_after(origin, entry.period, now);

        }

    }

}

impl PolledDev {

    /// Whether this is the polling of that very device, and not of another one under the
    /// same name.
    fn is(&self, dev: &dyn AnyDev) -> bool {
        std::ptr::addr_eq(self.dev.as_ptr(), dev as *const dyn AnyDev)
    }

    fn entries(&self, kind: PolledKind) -> &HashMap<ArcName, PolledEntry> {
        match kind {
            PolledKind::Attr => &self.attrs,
            PolledKind::Command => &self.commands,
        }
    }

    fn entries_mut(&mut self, kind: PolledKind) -> &mut HashMap<ArcName, PolledEntry> {
        match kind {
            PolledKind::Attr => &mut self.attrs,
            PolledKind::Command => &mut self.commands,
        }
    }

}

/// The first point of the grid of that period strictly after that time: the multiples of
/// the period counted from that origin, so that two grids whose periods share multiples
/// meet at exactly the same times, see the [module](self).
fn grid_after(origin: Instant, period: Duration, after: Instant) -> Instant {
    let period = period.as_nanos().max(1);
    let ticks = after.saturating_duration_since(origin).as_nanos() / period + 1;
    origin + Duration::from_nanos(u64::try_from(ticks * period).unwrap_or(u64::MAX))
}

/// The loop of the polling thread, which drives every poll at once, see the
/// [module](self): it starts the polls that are due, polls those in progress, and parks
/// until the next one is due or one in progress wakes it, which a change of what is polled does too.
fn run_thread(state: &Mutex<State>) {

    /// Waking a poll is unparking the polling thread, the way [`crate::future::block_on_timeout`]
    /// is woken.
    struct ThreadWaker(Thread);

    impl futures::task::ArcWake for ThreadWaker {
        fn wake_by_ref(arc_self: &Arc<Self>) {
            arc_self.0.unpark();
        }
    }

    let waker = futures::task::waker(Arc::new(ThreadWaker(thread::current())));
    let mut cx = Context::from_waker(&waker);
    let mut polls = FuturesUnordered::<PollRun>::new();

    debug!("Started the polling thread");

    loop {

        let (starts, next) = {
            let mut state = state.lock().unwrap();
            if state.shutdown {
                break;
            }
            state.take_due(Instant::now())
        };

        // Started without the lock, a device being free to change what it is polled for
        // as it is asked to.
        for start in starts {
            polls.push(PollRun::new(start));
        }

        // A poll through is a poll due again, possibly already, so the state is looked at
        // again before parking whenever one is.
        let mut finished = false;
        while let Poll::Ready(Some(end)) = polls.poll_next_unpin(&mut cx) {
            state.lock().unwrap().finish(end, Instant::now());
            finished = true;
        }

        if finished {
            continue;
        }

        // A park can come back without anything having woken it, which only makes the
        // state looked at once more.
        match next {
            Some(next) => thread::park_timeout(next.saturating_duration_since(Instant::now())),
            None => thread::park(),
        }

    }

    debug!("Ended the polling thread");

}

/// A poll in progress, which gives how it ended once through: the future of the device,
/// see [`AnyDev::poll`], along with what its end is about, so that a poll only allocates
/// that future.
struct PollRun {
    fut: BoxFuture<'static, Result<Vec<Option<Instant>>>>,
    /// The end of that poll, completed and taken once it is through.
    end: Option<PollEnd>,
    started: Instant,
}

impl PollRun {

    /// Start that poll.
    fn new(start: PollStart) -> Self {

        let fut = start.dev.poll(start.kind, &start.items);

        Self {
            fut,
            end: Some(PollEnd {
                dev: Arc::clone(start.dev.name()),
                kind: start.kind,
                items: start.items,
                last_duration: Duration::ZERO,
            }),
            started: Instant::now(),
        }

    }

}

impl Future for PollRun {

    type Output = PollEnd;

    /// A poll the pool dropped keeps when the last periodic events were sent, see
    /// [`AnyDev::poll`].
    fn poll(self: Pin<&mut Self>, cx: &mut Context<'_>) -> Poll<Self::Output> {

        let this = self.get_mut();
        let res = ready!(this.fut.as_mut().poll(cx));
        let mut end = this.end.take().expect("a poll is through only once");

        end.last_duration = this.started.elapsed();
        match res {
            Ok(last_periodics) => {
                for (item, last_periodic) in end.items.iter_mut().zip(last_periodics) {
                    item.last_periodic = last_periodic;
                }
            }
            Err(err) => debug!(dev = %end.dev, %err, "Failed to run the poll"),
        }

        Poll::Ready(end)

    }

}

/// Parse a `polled_attr` or `polled_cmd` property of a device, each name being followed
/// by its period in milliseconds. A malformed entry is left out with a warning, the others
/// being polled all the same, and so is a period of zero, which cppTango takes for a
/// polling that the device triggers itself, which is not supported.
pub fn parse_periods<'a>(dev: &str, prop: &str, values: impl IntoIterator<Item = &'a str>) -> Vec<(&'a str, Duration)> {

    let mut periods = Vec::new();
    let mut values = values.into_iter();

    while let Some(name) = values.next() {

        let Some(period) = values.next() else {
            warn!(%dev, %prop, %name, "Ignored a polled object with no period");
            break;
        };

        match period.trim().parse::<u64>() {
            Ok(0) => warn!(%dev, %prop, %name, "Ignored a polled object triggered by the device, which is not supported"),
            Ok(ms) => periods.push((name, Duration::from_millis(ms).max(MIN_PERIOD))),
            Err(_) => warn!(%dev, %prop, %name, %period, "Ignored a polled object with an invalid period"),
        }

    }

    periods

}

/// Parse a `attr_poll_ring_depth` or `cmd_poll_ring_depth` property of a device, each
/// name being followed by its depth, a malformed entry being left out with a warning.
pub fn parse_depths<'a>(dev: &str, prop: &str, values: impl IntoIterator<Item = &'a str>) -> Vec<(&'a str, usize)> {

    let mut depths = Vec::new();
    let mut values = values.into_iter();

    while let (Some(name), Some(depth)) = (values.next(), values.next()) {
        match depth.trim().parse::<usize>() {
            Ok(depth) => depths.push((name, depth)),
            Err(_) => warn!(%dev, %prop, %name, %depth, "Ignored an invalid polling ring depth"),
        }
    }

    depths

}

/// The status of an object polled, as the `DevPollStatus` command of the admin device
/// gives it, which is the text cppTango gives and the one its clients parse, see
/// [`crate::dev::DevProxy::attr_poll_period`].
pub fn format_status(status: &PolledStatus, record: Option<&PolledHistory>) -> String {

    let (noun, action) = match status.kind {
        PolledKind::Attr => ("attribute", "attribute reading"),
        PolledKind::Command => ("command", "command execution"),
    };

    let mut text = String::new();
    let _ = write!(text, "Polled {noun} name = {}", status.name);
    let _ = write!(text, "\nPolling period (mS) = {}", status.period.as_millis());

    let Some(record) = record else {
        return text;
    };

    let _ = write!(text, "\nPolling ring buffer depth = {}", record.depth);

    if let Some(last_duration) = status.last_duration {
        let _ = write!(text, "\nTime needed for the last {action} (mS) = {:.3}", last_duration.as_secs_f64() * 1000.0);
    }

    if let Some(last) = record.times.last() {
        let since = SystemTime::now().duration_since(*last).unwrap_or_default();
        if since.as_secs() == 0 {
            let _ = write!(text, "\nData not updated since {} mS", since.as_millis());
        } else {
            let _ = write!(text, "\nData not updated since {} S and {} mS", since.as_secs(), since.subsec_millis());
        }
    }

    if record.times.len() > 1 {
        let deltas = record.times.windows(2)
            .map(|pair| pair[1].duration_since(pair[0]).unwrap_or_default().as_millis().to_string())
            .collect::<Vec<_>>();
        let _ = write!(text, "\nDelta between last records (in mS) = {}", deltas.join(", "));
    }

    if let Some(err) = &record.failure {
        let what = match status.kind {
            PolledKind::Attr => "attribute read",
            PolledKind::Command => "command execution",
        };
        let _ = write!(text, "\nLast {what} FAILED :\n\tReason = {}\n\tDesc = {}\n\tOrigin = {}",
            err.reason(), err.description(), err.origin());
    }

    text

}

#[cfg(test)]
mod tests {

    use crate::dev::status_period;

    use super::*;

    #[test]
    fn polled_prop() {
        let values = ["a", "1000", "b", "0", "c", "x", "d", "1", "e"];
        assert_eq!(parse_periods("x/y/z", "polled_attr", values), [
            ("a", Duration::from_millis(1000)),
            ("d", MIN_PERIOD),
        ]);
    }

    /// Grids of periods sharing multiples meet at exactly the same times, a late time
    /// skipping to the next point.
    #[test]
    fn grid() {

        let origin = Instant::now();
        let at = |ms| origin + Duration::from_millis(ms);
        let (state, status) = (Duration::from_secs(2), Duration::from_secs(3));

        assert_eq!(grid_after(origin, state, at(4000)), at(6000));
        assert_eq!(grid_after(origin, status, at(3500)), at(6000));
        assert_eq!(grid_after(origin, state, at(3999)), at(4000));
        assert_eq!(grid_after(origin, status, at(10_100)), at(12_000));
        assert_eq!(grid_after(origin, state, origin - Duration::from_secs(1)), at(2000));

    }

    #[test]
    fn status_round_trip() {

        let status = PolledStatus {
            kind: PolledKind::Attr,
            name: Arc::from("Position"),
            period: Duration::from_millis(250),
            last_duration: Some(Duration::from_micros(1500)),
        };

        let record = PolledHistory {
            depth: 10,
            times: vec![SystemTime::now() - Duration::from_millis(250), SystemTime::now()],
            failure: None,
        };

        let texts = [format_status(&status, Some(&record))];
        assert_eq!(status_period(&texts, "attribute", "position"), Some(Duration::from_millis(250)));
        assert_eq!(status_period(&texts, "command", "position"), None);
        assert_eq!(status_period(&texts, "attribute", "speed"), None);

    }

}