nordisk/Skidbladnir

crates/installer/nordisk-pairing/tests/stderr_reaches_the_boot_log.rs

//! **A line on fd 2 reaches the boot log** (feature `stderr-capture`).
//!
//! A product that embeds a library logging with `eprintln!` (monetize-server, in
//! holger's front, measured 2026-09-28: 87 `eprintln!` and no logger) writes the
//! serial console and NOT the boot log the installer's log door reads, so the
//! purchase, the grant and the webhook lines never reach the operator.
//! `bootlog::capture_stderr` makes fd 2 a pipe drained into the [`BootLog`] AND
//! the console it was. Proven in a CHILD process (this test re-runs itself), so
//! the harness's own fd 2 is never taken.
#![cfg(all(unix, feature = "stderr-capture"))]

use nordisk_pairing::bootlog::{self, BootLog};

static LOG: BootLog = BootLog::new(100);

const CHILD: &str = "NORDISK_PAIRING_STDERR_CHILD";

#[test]
fn an_eprintln_line_reaches_the_boot_log_and_the_console() {
    if std::env::var_os(CHILD).is_some() {
        let mut console = bootlog::capture_stderr(&LOG).expect("fd 2 taken over");
        eprintln!("monetize-server: purchase holger/bundles/2026-09-28+disk_bytes granted");
        eprint!("a partial line ");
        eprintln!("finished");
        // The tracing Tap writes the console it is handed, never fd 2 (no double line).
        use std::io::Write;
        writeln!(console, "said on the console only").unwrap();
        std::thread::sleep(std::time::Duration::from_millis(300));
        for l in LOG.since(0, 100).lines {
            println!("LOG|{l}");
        }
        return;
    }
    let out = std::process::Command::new(std::env::current_exe().unwrap())
        .args(["--exact", "an_eprintln_line_reaches_the_boot_log_and_the_console", "--nocapture", "--test-threads=1"])
        .env(CHILD, "1")
        .output()
        .unwrap();
    let (stdout, stderr) = (String::from_utf8_lossy(&out.stdout), String::from_utf8_lossy(&out.stderr));
    assert!(out.status.success(), "the child failed:\n{stdout}\n{stderr}");
    // libtest's "test … ... " shares the first stdout line: the marker is searched, not anchored.
    let logged: Vec<&str> = stdout.lines().filter_map(|l| l.split_once("LOG|").map(|x| x.1)).collect();
    assert!(logged.contains(&"monetize-server: purchase holger/bundles/2026-09-28+disk_bytes granted"), "the eprintln! line is in the boot log: {logged:?}");
    assert!(logged.contains(&"a partial line finished"), "a line is pushed whole: {logged:?}");
    assert!(!logged.iter().any(|l| l.contains("console only")), "the console handle does not feed the log twice: {logged:?}");
    assert!(stderr.contains("purchase holger/bundles") && stderr.contains("said on the console only"), "the console still shows every line: {stderr}");
}