boxmaker/crates/memoryd/tests/honcho_worker_log.rs

//! A session log the worker cannot read for now (review of M5c-1, finding 6): an I/O error other
//! than a missing file is waited out like an outage, with the same doubling wait, logged once when
//! it starts and once when it ends, and shown by `bxctl memory sync`; the turn stays waiting and
//! is sent once the log reads. A missing log or a damaged line still marks the turn failed. The
//! log is made unreadable by a directory in its place (EISDIR), which holds for root too.

#[path = "support/honcho.rs"]
mod honcho;
#[path = "support/logs.rs"]
mod logs;
#[path = "support/tmp.rs"]
mod tmp;
#[path = "support/turns.rs"]
mod turns;
#[path = "support/worker.rs"]
mod worker;

use std::time::Duration;

use honcho::FakeHoncho;
use logs::assistant;
use memoryd::honcho::ledger::{Item, Record};
use memoryd::honcho::status;
use memoryd::honcho::turns::log_path;
use memoryd::honcho::worker::Step;
use turns::{sid, spoken};
use worker::{FAST, Home};

fn turn(text: &str) -> Vec<bxcore::LogRecord> {
    vec![spoken(text, Some("kyle")), assistant(2, Some("ok"), &[])]
}

fn is_sent(records: &[Record]) -> bool {
    let item = Item::Turn {
        session: sid("mm-a"),
        turn: 1,
    };
    records
        .iter()
        .any(|r| matches!(r, Record::Sent { item: i, .. } if *i == item))
}

fn has_failed(records: &[Record]) -> bool {
    records.iter().any(|r| matches!(r, Record::Failed { .. }))
}

#[test]
fn an_unreadable_log_is_waited_out() {
    let fake = FakeHoncho::start();
    let home = Home::new("worker-log-io");
    home.log("mm-a", &[turn("hello")]);
    home.report("mm-a", 1);
    let path = log_path(&home.dir.path().join("sessions"), &sid("mm-a"));
    let kept = std::fs::read(&path).unwrap();
    std::fs::remove_file(&path).unwrap();
    std::fs::create_dir(&path).unwrap();

    let mut w = home.worker(&fake, FAST);
    assert_eq!(w.step(), Step::Backoff(Duration::from_millis(1)));
    assert_eq!(w.step(), Step::Backoff(Duration::from_millis(2)));
    assert_eq!(w.step(), Step::Backoff(Duration::from_millis(4)));
    let records = home.records();
    assert!(!has_failed(&records), "{records:?}");
    let lines = home.lines();
    assert_eq!(lines.len(), 1, "logged once: {lines:?}");
    assert!(
        lines[0].starts_with("memoryd: turn 1 of session mm-a cannot be read now ("),
        "{}",
        lines[0]
    );
    assert!(
        lines[0]
            .ends_with("); sends wait and are retried; see docs/runbook.md#session-log-damaged"),
        "{}",
        lines[0]
    );
    assert!(!lines[0].contains("hello"));
    let shared = home.sync.lock().unwrap().shared_status();
    assert!(status::read(&shared).log_unreadable_since.is_some());
    let shown = status::lines(&status::read(&shared));
    assert!(
        shown[0].starts_with("session log unreadable since "),
        "{shown:?}"
    );
    assert!(
        shown[0].ends_with(": sends wait and are retried"),
        "{shown:?}"
    );

    std::fs::remove_dir(&path).unwrap();
    std::fs::write(&path, kept).unwrap();
    assert_eq!(w.step(), Step::Done);
    assert!(is_sent(&home.records()));
    let lines = home.lines();
    assert_eq!(lines.len(), 2, "{lines:?}");
    assert_eq!(
        lines[1],
        format!(
            "memoryd: {} reads again; waiting sends go on",
            path.display()
        )
    );
    assert_eq!(status::read(&shared), status::Status::default());
}

#[test]
fn a_missing_or_damaged_log_still_fails_the_turn() {
    let fake = FakeHoncho::start();
    for damage in ["missing", "damaged"] {
        let home = Home::new("worker-log-gone");
        home.log("mm-a", &[turn("hello")]);
        home.report("mm-a", 1);
        let path = log_path(&home.dir.path().join("sessions"), &sid("mm-a"));
        match damage {
            "missing" => std::fs::remove_file(&path).unwrap(),
            _ => std::fs::write(&path, "not a record\n").unwrap(),
        }
        let mut w = home.worker(&fake, FAST);
        assert_eq!(w.step(), Step::Done, "{damage}");
        let records = home.records();
        assert!(
            records
                .iter()
                .any(|r| matches!(r, Record::Failed { kind, .. } if kind == "log")),
            "{damage}: {records:?}"
        );
    }
}