nordisk-pairing 0.5.27

//! **The app's boot narration: a STAGE line at every boundary and a TICK a minute** (lane
//! B3, A9 row 4). Here, in nordisk-pairing, and not in nordisk-narrate: a RELEASE build links
//! no `nordisk_narrate` symbol at all (holger-recipe `tests/dev_narrate_symbols.rs`), and this
//! narrator says its lines locally, never over the wire. Product-neutral: the product names where a line goes (its [`Sink`]: the
//! in-RAM boot log the installer's log door and DEV-NARRATE read, and the console), and
//! nothing here passes through the product's log filter, so a box whose logger says only
//! WARN still says every stage it crosses.
//!
//! Gunnar's `narrate.rs` is the pattern (2026-09-23: everything that mattered happened after
//! the last datagram): a line at each boundary with a monotonic stamp, and a short tick a
//! minute with the current stage and the uptime, so silence means dead rather than idle.
//!
//! The spellings are shared with the installer's ear, which says a line with `STAGE ` in it
//! out loud the moment it arrives:
//!
//! ```text
//! STAGE <token> +<ms>ms <detail>
//! TICK stage=<token> up=<s>s
//! ```

use std::sync::{Arc, Mutex};
use std::time::{Duration, Instant};

/// The marker every stage line begins with.
pub const STAGE_MARKER: &str = "STAGE";
/// The marker every tick begins with.
pub const TICK_MARKER: &str = "TICK";
/// How often a narrator ticks ([`start_ticks`]).
pub const TICK_EVERY: Duration = Duration::from_secs(60);

/// Where a narrator's lines go: the product's boot log and its console. Never fatal.
pub type Sink = Box<dyn Fn(&str) + Send + Sync>;

/// Pure: **one boundary, as a line**: `STAGE <token> +<ms>ms <detail>`, one line whatever the
/// detail holds.
pub fn stage_line(token: &str, monotonic_ms: u128, detail: &str) -> String {
    let detail = detail.replace(['\r', '\n'], " ");
    let detail = detail.trim();
    if detail.is_empty() {
        format!("{STAGE_MARKER} {token} +{monotonic_ms}ms")
    } else {
        format!("{STAGE_MARKER} {token} +{monotonic_ms}ms {detail}")
    }
}

/// Pure: **one tick**: `TICK stage=<token> up=<s>s`.
pub fn tick_line(token: &str, uptime_s: u64) -> String {
    format!("{TICK_MARKER} stage={token} up={uptime_s}s")
}

/// **A narrator**: its zero (the exec), the last stage crossed, and its sink.
pub struct Narrator {
    t0: Instant,
    stage: Mutex<&'static str>,
    sink: Sink,
}

impl Narrator {
    /// A narrator starting now at stage `exec`, saying every line through `sink`.
    pub fn new(sink: impl Fn(&str) + Send + Sync + 'static) -> Narrator {
        Narrator { t0: Instant::now(), stage: Mutex::new("exec"), sink: Box::new(sink) }
    }

    /// Milliseconds since the narrator started.
    pub fn monotonic_ms(&self) -> u128 {
        self.t0.elapsed().as_millis()
    }

    /// The last stage crossed.
    pub fn stage(&self) -> &'static str {
        *self.stage.lock().unwrap_or_else(|p| p.into_inner())
    }

    /// **Cross a boundary** (a token: one lower-case word) and say it. Answers the line.
    pub fn at(&self, stage: &'static str, detail: &str) -> String {
        *self.stage.lock().unwrap_or_else(|p| p.into_inner()) = stage;
        let line = stage_line(stage, self.monotonic_ms(), detail);
        (self.sink)(&line);
        line
    }

    /// **One tick**: the current stage and the narrator's uptime, said. Answers the line.
    pub fn tick(&self) -> String {
        let line = tick_line(self.stage(), self.t0.elapsed().as_secs());
        (self.sink)(&line);
        line
    }

    /// Say one line through the sink, unchanged (a fault line, an operator's sentence).
    pub fn say(&self, line: &str) {
        (self.sink)(line);
    }
}

/// The duty that ticks ([`start_ticks`], A28 M18).
pub const TICK_DUTY: &str = "narrate-tick";

/// **Tick every [`TICK_EVERY`]** on a thread of its own for the life of the process. Answers
/// whether the thread started (diagnostics: a box without its tick still serves).
pub fn start_ticks(n: Arc<Narrator>) -> bool {
    start_ticks_every(n, TICK_EVERY)
}

/// [`start_ticks`] with its period (a test's seam).
pub fn start_ticks_every(n: Arc<Narrator>, every: Duration) -> bool {
    // A duty (A28 M18): listed, a panicked tick said and the ticks go on, stopped at the stop.
    // The first round only waits: the first tick comes after `every`, as it always did.
    let mut first = true;
    let say: crate::duty::Say = Arc::new(|l: &str| eprintln!("{l}"));
    crate::duty::start(TICK_DUTY, every, say, move || {
        if !std::mem::take(&mut first) {
            n.tick();
        }
        crate::duty::Round::Again
    })
    .is_ok()
}

#[cfg(test)]
mod tests {
    use super::*;

    /// ★ **The ticks are a listed duty** (A28 M18), stopped at the box's stop.
    #[test]
    fn the_ticks_are_a_listed_duty() {
        let _one = crate::duty::tests::ONE.lock().unwrap_or_else(|p| p.into_inner());
        let (_, n) = collecting();
        assert!(start_ticks_every(Arc::new(n), Duration::from_millis(5)));
        let d = crate::duty::find(TICK_DUTY).expect("the ticks are a running duty");
        assert!(d.stop(Duration::from_secs(5)));
    }

    fn collecting() -> (Arc<Mutex<Vec<String>>>, Narrator) {
        let lines = Arc::new(Mutex::new(Vec::new()));
        let l = Arc::clone(&lines);
        (lines, Narrator::new(move |s: &str| l.lock().unwrap().push(s.to_string())))
    }

    /// ★ **Every stage and tick reaches the sink, whatever the logger filters** (lane B3, A9
    /// row 4): the stage line carries its stamp and one line only; a tick names the stage last
    /// crossed; the ticker thread ticks on its own.
    #[test]
    fn stages_and_ticks_reach_the_sink_in_the_shared_spelling() {
        let (lines, n) = collecting();
        let l = n.at("pairing", "the installer's listener serves\nsecond");
        assert!(l.starts_with("STAGE pairing +") && l.contains("ms the installer's listener serves second"), "{l}");
        assert_eq!(n.stage(), "pairing");
        assert_eq!(n.tick(), "TICK stage=pairing up=0s");
        assert_eq!(stage_line("exec", 7, " "), "STAGE exec +7ms");
        assert_eq!(lines.lock().unwrap().len(), 2);
        let (lines, n) = collecting();
        n.at("serving", "");
        assert!(start_ticks_every(Arc::new(n), Duration::from_millis(20)));
        std::thread::sleep(Duration::from_millis(200));
        assert!(lines.lock().unwrap().iter().any(|l| l == "TICK stage=serving up=0s"), "{:?}", lines.lock().unwrap());
    }
}