diff --git a/crates/memoryd/src/honcho/ledger.rs b/crates/memoryd/src/honcho/ledger.rs index 5b399a5..f07c01b 100644 --- a/crates/memoryd/src/honcho/ledger.rs +++ b/crates/memoryd/src/honcho/ledger.rs @@ -16,7 +16,7 @@ use serde::{Deserialize, Serialize}; pub const RUNBOOK: &str = "see docs/runbook.md#honcho-ledger-damaged"; /// One of this agent's three workspaces. -#[derive(Debug, Clone, Copy, PartialEq, Eq, Hash, Serialize, Deserialize)] +#[derive(Debug, Clone, Copy, PartialEq, Eq, PartialOrd, Ord, Hash, Serialize, Deserialize)] #[serde(rename_all = "snake_case")] pub enum Workspace { Trusted, diff --git a/crates/memoryd/src/honcho/mirror.rs b/crates/memoryd/src/honcho/mirror.rs index 9fbf4b9..80ca052 100644 --- a/crates/memoryd/src/honcho/mirror.rs +++ b/crates/memoryd/src/honcho/mirror.rs @@ -9,6 +9,7 @@ use bxcore::{DataClass, SessionId, Timestamp}; use crate::files::Store; use crate::honcho::ledger::{self, Action, Item, Ledger, Record, Workspace}; use crate::honcho::report; +use crate::honcho::status::{self, Shared}; use crate::journal; use crate::notes::{self, Kind}; @@ -204,6 +205,8 @@ fn brought_back(ledger: &Ledger, action: &Action) -> bool { /// With `[honcho]`: decides each journalled edit into the ledger. pub struct Mirror { ledger: Arc>, + /// What the worker and the walk wait on, for the report; empty unless `with_status` is given. + status: Shared, agent: String, owner: String, } @@ -212,14 +215,25 @@ impl Mirror { pub fn new(ledger: Arc>, agent: &str, owner: &str) -> Mirror { Mirror { ledger, + status: Shared::default(), agent: agent.to_string(), owner: owner.to_string(), } } - /// `bxctl memory sync`'s report of the ledger, under the ledger's lock alone. + /// The same, reporting `status` too. + pub fn with_status(self, status: Shared) -> Mirror { + Mirror { status, ..self } + } + + /// `bxctl memory sync`'s report: the status copied under its lock alone, then the ledger + /// under its own. pub fn report(&self) -> String { - report::report(&self.ledger.lock().unwrap_or_else(|p| p.into_inner())) + let status = status::read(&self.status); + report::with_status( + &self.ledger.lock().unwrap_or_else(|p| p.into_inner()), + &status, + ) } /// Decide the journalled edit `id` (the latest when `None`), called under the index lock diff --git a/crates/memoryd/src/honcho/mod.rs b/crates/memoryd/src/honcho/mod.rs index 5abc1b8..edba558 100644 --- a/crates/memoryd/src/honcho/mod.rs +++ b/crates/memoryd/src/honcho/mod.rs @@ -11,5 +11,7 @@ pub mod naming; pub mod report; pub mod start; pub mod state; +pub mod status; pub mod turns; +pub mod wake; pub mod worker; diff --git a/crates/memoryd/src/honcho/report.rs b/crates/memoryd/src/honcho/report.rs index d2a8817..a056d09 100644 --- a/crates/memoryd/src/honcho/report.rs +++ b/crates/memoryd/src/honcho/report.rs @@ -1,7 +1,9 @@ -//! What `bxctl memory sync` prints (M5c spec, section 5): how many items the ledger holds in each -//! state, and every failed item, oldest first, by its label, never by its text. +//! What `bxctl memory sync` prints (M5c spec, sections 5 and 10): how many items the ledger holds +//! in each state, every failed item, oldest first, by its label, never by its text, and what the +//! worker and the walk are waiting on. use crate::honcho::ledger::{Ledger, label}; +use crate::honcho::status::{self, Status}; /// The answer without `[honcho]`: not an error. pub const NOT_CONFIGURED: &str = "honcho sync: not configured (memoryd.toml has no [honcho])"; @@ -31,3 +33,14 @@ pub fn report(ledger: &Ledger) -> String { } out } + +/// The report of `ledger`, then a line for each state in `status` that lasts (`status::lines`). +/// When all is well, the same as `report`. +pub fn with_status(ledger: &Ledger, status: &Status) -> String { + let mut out = report(ledger); + for line in status::lines(status) { + out.push('\n'); + out.push_str(&line); + } + out +} diff --git a/crates/memoryd/src/honcho/start.rs b/crates/memoryd/src/honcho/start.rs index f1ffae9..902bf12 100644 --- a/crates/memoryd/src/honcho/start.rs +++ b/crates/memoryd/src/honcho/start.rs @@ -41,12 +41,11 @@ impl Opened { /// The memory writes' side of the ledger (task 12). pub fn mirror(&self) -> Mirror { - let ledger = self - .sync - .lock() - .unwrap_or_else(|p| p.into_inner()) - .shared_ledger(); - Mirror::new(ledger, &self.agent, &self.owner) + let (ledger, status) = { + let sync = self.sync.lock().unwrap_or_else(|p| p.into_inner()); + (sync.shared_ledger(), sync.shared_status()) + }; + Mirror::new(ledger, &self.agent, &self.owner).with_status(status) } } diff --git a/crates/memoryd/src/honcho/status.rs b/crates/memoryd/src/honcho/status.rs new file mode 100644 index 0000000..8e7c7b1 --- /dev/null +++ b/crates/memoryd/src/honcho/status.rs @@ -0,0 +1,68 @@ +//! What the Honcho side is waiting on, beyond the ledger, for `bxctl memory sync` (M5c spec, +//! sections 10, 12 and 13): workspaces whose key Honcho refused, an outage of Honcho, and a +//! `brokerd` that does not answer. The worker and the walk write it; the report reads it. Its lock +//! is a leaf: nothing else is locked while it is held. + +use std::collections::BTreeMap; +use std::sync::{Arc, Mutex}; + +use bxcore::Timestamp; + +use crate::honcho::ledger::Workspace; + +#[derive(Debug, Clone, Default, PartialEq, Eq)] +pub struct Status { + /// Each workspace whose key was refused: its name and the HTTP status. Nothing more is sent + /// to it until `memoryd` restarts. + pub refused: BTreeMap, + /// When the outage of Honcho that lasts began. + pub outage_since: Option, + /// When `brokerd` stopped answering on its state socket, while it does not. + pub broker_down_since: Option, +} + +/// The status, shared between the worker, the walk and the report. +pub type Shared = Arc>; + +/// Change the shared status under its lock alone. +pub fn update(shared: &Shared, change: impl FnOnce(&mut Status)) { + change(&mut shared.lock().unwrap_or_else(|p| p.into_inner())); +} + +/// A copy of the shared status, taken under its lock alone. +pub fn read(shared: &Shared) -> Status { + shared.lock().unwrap_or_else(|p| p.into_inner()).clone() +} + +fn role(workspace: Workspace) -> &'static str { + match workspace { + Workspace::Trusted => "trusted", + Workspace::Untrusted => "untrusted", + Workspace::Fleet => "fleet", + } +} + +/// One line for each state that lasts, in this order: `brokerd` silent, Honcho unreachable, then +/// each refused key by workspace. None when all is well. +pub fn lines(status: &Status) -> Vec { + let mut out = Vec::new(); + if let Some(since) = status.broker_down_since { + out.push(format!( + "brokerd unanswered since {}: turns wait undecided", + since.to_rfc3339() + )); + } + if let Some(since) = status.outage_since { + out.push(format!( + "honcho unreachable since {}: sends wait and are retried", + since.to_rfc3339() + )); + } + for (workspace, (name, code)) in &status.refused { + out.push(format!( + "key refused (HTTP {code}): {} workspace {name}: its sends wait until memoryd restarts", + role(*workspace) + )); + } + out +} diff --git a/crates/memoryd/src/honcho/turns.rs b/crates/memoryd/src/honcho/turns.rs index 5780708..16f3437 100644 --- a/crates/memoryd/src/honcho/turns.rs +++ b/crates/memoryd/src/honcho/turns.rs @@ -12,6 +12,7 @@ use bxcore::{LogRecord, SessionId, SessionStateReply, Timestamp}; use crate::honcho::decide::{decide, turn_records, turns}; use crate::honcho::ledger::{self, Item, Ledger, Record}; use crate::honcho::state; +use crate::honcho::status::{self, Shared}; /// The ledger's file name, in `memory/`. pub const LEDGER: &str = "honcho.jsonl"; @@ -47,6 +48,8 @@ pub struct TurnSync { broker_down: bool, /// Sessions whose log last had a damaged line: logged once each. unreadable: BTreeSet, + /// What `bxctl memory sync` shows beyond the ledger, shared with the worker and the report. + status: Shared, } /// The path of `session`'s log under `sessions`: epoch 0, the only one `loopd` writes. @@ -108,6 +111,7 @@ impl TurnSync { reported: BTreeMap::new(), broker_down: false, unreadable: BTreeSet::new(), + status: Shared::default(), } } @@ -121,6 +125,11 @@ impl TurnSync { Arc::clone(&self.ledger) } + /// The status `bxctl memory sync` shows, for the worker and the report. + pub fn shared_status(&self) -> Shared { + Arc::clone(&self.status) + } + /// The directory of `loopd`'s session logs. pub fn sessions(&self) -> &Path { &self.sessions @@ -214,7 +223,7 @@ impl TurnSync { if undecided.is_empty() { return if held { Walk::Waiting } else { Walk::Done }; } - let Some(state) = self.state(session, ask, log) else { + let Some(state) = self.state(session, ask, now, log) else { return Walk::Stop; }; for turn in undecided { @@ -258,12 +267,14 @@ impl TurnSync { &mut self, session: &SessionId, ask: Ask<'_>, + now: Timestamp, log: &dyn Fn(&str), ) -> Option { match ask(session) { Ok(state) => { if self.broker_down { self.broker_down = false; + status::update(&self.status, |s| s.broker_down_since = None); log("memoryd: brokerd answers on its state socket again; turns are decided"); } Some(state) @@ -271,6 +282,7 @@ impl TurnSync { Err(e) => { if !self.broker_down { self.broker_down = true; + status::update(&self.status, |s| s.broker_down_since = Some(now)); log(&format!( "memoryd: {e}; turns wait undecided; {}", state::RUNBOOK diff --git a/crates/memoryd/src/honcho/wake.rs b/crates/memoryd/src/honcho/wake.rs new file mode 100644 index 0000000..1cfd73c --- /dev/null +++ b/crates/memoryd/src/honcho/wake.rs @@ -0,0 +1,49 @@ +//! The Honcho worker's waits (M5c spec, section 5): the doubling wait of an outage and the idle +//! sleep, and what wakes it early. + +use std::sync::{Condvar, Mutex}; +use std::time::Duration; + +/// The worker's waits. Tests shorten them. +#[derive(Debug, Clone, Copy, PartialEq, Eq)] +pub struct Tuning { + /// The first wait in an outage; each next one doubles, up to `backoff_max`. + pub backoff: Duration, + pub backoff_max: Duration, + /// How long the worker sleeps with nothing to send, unless a turn ends first. + pub idle: Duration, +} + +impl Tuning { + pub const DEFAULT: Tuning = Tuning { + backoff: Duration::from_secs(5), + backoff_max: Duration::from_secs(600), + idle: Duration::from_secs(30), + }; +} + +/// Wakes the worker from its idle sleep when a turn ends. +#[derive(Debug, Default)] +pub struct Wake { + woken: Mutex, + ready: Condvar, +} + +impl Wake { + /// Wake the worker if it sleeps, or make its next sleep return at once. + pub fn notify(&self) { + let mut woken = self.woken.lock().unwrap_or_else(|p| p.into_inner()); + *woken = true; + self.ready.notify_one(); + } + + /// Sleep until `notify`, or at most `timeout`. + pub fn wait(&self, timeout: Duration) { + let woken = self.woken.lock().unwrap_or_else(|p| p.into_inner()); + let (mut woken, _) = self + .ready + .wait_timeout_while(woken, timeout, |woken| !*woken) + .unwrap_or_else(|p| p.into_inner()); + *woken = false; + } +} diff --git a/crates/memoryd/src/honcho/worker.rs b/crates/memoryd/src/honcho/worker.rs index 19ae37a..589cb92 100644 --- a/crates/memoryd/src/honcho/worker.rs +++ b/crates/memoryd/src/honcho/worker.rs @@ -7,7 +7,7 @@ use std::collections::HashSet; use std::path::{Path, PathBuf}; -use std::sync::{Arc, Condvar, Mutex}; +use std::sync::{Arc, Mutex}; use std::time::Duration; use bxcore::sanitize::neutralise; @@ -20,10 +20,12 @@ use crate::honcho::decide::{final_reply, turn_records, user_text}; use crate::honcho::edits; use crate::honcho::ledger::{self, Action, Item, Ledger, Record, Workspace}; use crate::honcho::naming::{HonchoSession, honcho_session}; +use crate::honcho::status::{self, Shared}; use crate::honcho::turns::{TurnSync, log_path, read_log}; use crate::serve::Log; pub use crate::honcho::start::{Opened, open, spawn}; +pub use crate::honcho::wake::{Tuning, Wake}; /// The most characters Honcho takes in one message (recorded: 25,000 is taken, 25,001 refused). pub const MAX_PART: usize = 25_000; @@ -35,50 +37,6 @@ pub const SEND_REFUSED: &str = "see docs/runbook.md#honcho-send-refused"; pub const KEY_REFUSED: &str = "see docs/runbook.md#honcho-key-refused"; pub const LOG_DAMAGED: &str = "see docs/runbook.md#session-log-damaged"; -/// The worker's waits. Tests shorten them. -#[derive(Debug, Clone, Copy, PartialEq, Eq)] -pub struct Tuning { - /// The first wait in an outage; each next one doubles, up to `backoff_max`. - pub backoff: Duration, - pub backoff_max: Duration, - /// How long the worker sleeps with nothing to send, unless a turn ends first. - pub idle: Duration, -} - -impl Tuning { - pub const DEFAULT: Tuning = Tuning { - backoff: Duration::from_secs(5), - backoff_max: Duration::from_secs(600), - idle: Duration::from_secs(30), - }; -} - -/// Wakes the worker from its idle sleep when a turn ends. -#[derive(Debug, Default)] -pub struct Wake { - woken: Mutex, - ready: Condvar, -} - -impl Wake { - /// Wake the worker if it sleeps, or make its next sleep return at once. - pub fn notify(&self) { - let mut woken = self.woken.lock().unwrap_or_else(|p| p.into_inner()); - *woken = true; - self.ready.notify_one(); - } - - /// Sleep until `notify`, or at most `timeout`. - pub fn wait(&self, timeout: Duration) { - let woken = self.woken.lock().unwrap_or_else(|p| p.into_inner()); - let (mut woken, _) = self - .ready - .wait_timeout_while(woken, timeout, |woken| !*woken) - .unwrap_or_else(|p| p.into_inner()); - *woken = false; - } -} - /// What one step of the worker did, and so what the loop does next. #[derive(Debug, Clone, PartialEq, Eq)] pub enum Step { @@ -149,6 +107,8 @@ pub struct Worker { outage: Option, /// Workspaces whose key was refused: nothing more is sent to them until restart. refused: HashSet, + /// What `bxctl memory sync` shows; its lock is taken alone. + status: Shared, stopped: bool, } @@ -194,14 +154,6 @@ pub fn batch( messages } -/// An item as the log lines name it: `turn 3 of session mm-a`, `part 0 of edit 2026-09-28-0001`. -fn label(item: &Item) -> String { - match item { - Item::Turn { session, turn } => format!("turn {turn} of session {}", session.as_str()), - Item::Edit { id, part } => format!("part {part} of edit {id}"), - } -} - /// The ids of the messages Honcho made, in order. fn ids(messages: &[roncho::Message]) -> Vec { messages.iter().map(|m| m.id.clone()).collect() @@ -218,9 +170,13 @@ impl Worker { tuning: Tuning, agent: &str, ) -> Worker { - let (ledger, sessions) = { + let (ledger, sessions, status) = { let sync = sync.lock().unwrap_or_else(|p| p.into_inner()); - (sync.shared_ledger(), sync.sessions().to_path_buf()) + ( + sync.shared_ledger(), + sync.sessions().to_path_buf(), + sync.shared_status(), + ) }; Worker { sync, @@ -234,6 +190,7 @@ impl Worker { agent: agent.to_string(), outage: None, refused: HashSet::new(), + status, stopped: false, } } @@ -275,17 +232,24 @@ impl Worker { Err(Unsent::Honcho(HonchoError::KeyRefused { status })) => { self.recovered(); self.refused.insert(next.workspace); + let name = self + .clients + .client(next.workspace) + .workspace_id() + .to_string(); (self.log)(&format!( - "memoryd: Honcho refused the key of workspace {} (HTTP {status}); nothing more is sent to it until memoryd restarts; {KEY_REFUSED}", - self.clients.client(next.workspace).workspace_id() + "memoryd: Honcho refused the key of workspace {name} (HTTP {status}); nothing more is sent to it until memoryd restarts; {KEY_REFUSED}" )); + status::update(&self.status, |s| { + s.refused.insert(next.workspace, (name, status)); + }); Step::Done } Err(Unsent::Honcho(e)) => { self.recovered(); (self.log)(&format!( "memoryd: {} was not sent: {e}; it is marked failed; {SEND_REFUSED}", - label(&next.item) + ledger::label(&next.item) )); self.record(Record::Failed { time: Timestamp::now(), @@ -302,7 +266,7 @@ impl Worker { }; (self.log)(&format!( "memoryd: {} cannot be sent ({kind}); it is marked failed; {pointer}", - label(&next.item) + ledger::label(&next.item) )); self.record(Record::Failed { time: Timestamp::now(), @@ -446,6 +410,7 @@ impl Worker { (self.log)( format!("memoryd: {error}; sends wait and are retried; {UNREACHABLE}").as_str(), ); + status::update(&self.status, |s| s.outage_since = Some(Timestamp::now())); self.tuning.backoff } }; @@ -457,6 +422,7 @@ impl Worker { fn recovered(&mut self) { if self.outage.take().is_some() { (self.log)("memoryd: Honcho answers again; waiting sends go on"); + status::update(&self.status, |s| s.outage_since = None); self.retry(); } } diff --git a/crates/memoryd/tests/honcho_status.rs b/crates/memoryd/tests/honcho_status.rs new file mode 100644 index 0000000..9a6d280 --- /dev/null +++ b/crates/memoryd/tests/honcho_status.rs @@ -0,0 +1,188 @@ +//! What `bxctl memory sync` shows beyond the ledger (M5c spec, sections 10, 12 and 13; review of +//! M5c-1, finding 4): a workspace whose key was refused, an outage of Honcho and a silent +//! `brokerd`, each while it lasts, in exact lines; nothing more when all is well. The worker and +//! the walk keep the status; `memoryd` answers it. + +#[path = "support/brokerd.rs"] +mod brokerd; +#[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::os::unix::net::UnixStream; +use std::sync::{Arc, Mutex}; +use std::time::{Duration, Instant}; + +use bxcore::{ + CallId, DataClass, Envelope, MemoryAdmin, MemoryCall, MemoryCommand, Message, SessionId, + Timestamp, ToolRequest, read_frame, write_frame, +}; +use honcho::{FakeHoncho, Mode}; +use logs::assistant; +use memoryd::config::Config; +use memoryd::honcho::ledger::{Ledger, Record, Workspace}; +use memoryd::honcho::report::{report, with_status}; +use memoryd::honcho::status::Status; +use memoryd::serve; +use tmp::TempDir; +use turns::spoken; +use worker::{FAST, Home}; + +fn at(minute: u32) -> Timestamp { + Timestamp::parse(&format!("2026-09-28T10:{minute:02}:00.000Z")).unwrap() +} + +const ALL: &str = "honcho sync: 0 decided: 0 sent, 0 waiting, 0 failed, 0 skipped +brokerd unanswered since 2026-09-28T10:01:00.000Z: turns wait undecided +honcho unreachable since 2026-09-28T10:02:00.000Z: sends wait and are retried +key refused (HTTP 401): trusted workspace boxmaker0-trusted: its sends wait until memoryd restarts +key refused (HTTP 403): fleet workspace fleet: its sends wait until memoryd restarts"; + +#[test] +fn the_status_lines_are_exactly_these() { + let dir = TempDir::new("status-report"); + let mut ledger = Ledger::open(&dir.path().join("honcho.jsonl")).unwrap(); + ledger.append(Record::Began { time: at(0) }).unwrap(); + assert_eq!(with_status(&ledger, &Status::default()), report(&ledger)); + let mut status = Status { + broker_down_since: Some(at(1)), + outage_since: Some(at(2)), + ..Status::default() + }; + status + .refused + .insert(Workspace::Fleet, ("fleet".to_string(), 403)); + status + .refused + .insert(Workspace::Trusted, ("boxmaker0-trusted".to_string(), 401)); + assert_eq!(with_status(&ledger, &status), ALL); +} + +fn turn(text: &str) -> Vec { + vec![spoken(text, Some("kyle")), assistant(2, Some("ok"), &[])] +} + +fn status(home: &Home) -> Status { + let shared = home.sync.lock().unwrap().shared_status(); + memoryd::honcho::status::read(&shared) +} + +#[test] +fn the_worker_keeps_the_outage_and_the_refused_keys() { + let fake = FakeHoncho::start(); + let home = Home::new("status-worker"); + home.log("mm-a", &[turn("a")]); + home.report("mm-a", 1); + let mut w = home.worker(&fake, FAST); + fake.set(Mode::Status(503)); + let before = Timestamp::now(); + w.step(); + let since = status(&home).outage_since.expect("an outage"); + assert!(since >= before); + w.step(); + assert_eq!(status(&home).outage_since, Some(since), "from its start"); + fake.set(Mode::Fixtures); + w.step(); + assert_eq!(status(&home), Status::default(), "the outage ended"); + + home.log("mm-b", &[turn("b")]); + home.report("mm-b", 1); + fake.set(Mode::Status(401)); + w.step(); + let refused = status(&home).refused; + assert_eq!( + refused.get(&Workspace::Trusted), + Some(&("boxmaker0-trusted".to_string(), 401)) + ); + assert_eq!(refused.len(), 1); +} + +#[test] +fn the_walk_keeps_a_silent_brokerd() { + let home = Home::new("status-broker"); + home.log("mm-a", &[turn("a")]); + *home.answer.lock().unwrap() = Err("brokerd is down".to_string()); + home.report("mm-a", 1); + assert_eq!( + status(&home).broker_down_since, + Some(Timestamp::parse("2026-09-28T10:00:00.000Z").unwrap()) + ); + *home.answer.lock().unwrap() = Ok(turns::clean()); + home.report("mm-a", 1); + assert_eq!(status(&home), Status::default()); +} + +fn ask(socket: &std::path::Path, msg: Message) -> Message { + let mut stream = UnixStream::connect(socket).unwrap(); + stream + .set_read_timeout(Some(Duration::from_secs(10))) + .unwrap(); + let env = Envelope { + v: 1, + id: 1, + r#final: true, + msg, + }; + write_frame(&mut stream, &env).unwrap(); + read_frame(&mut stream).unwrap().msg +} + +#[test] +fn memoryd_shows_a_refused_key() { + let fake = FakeHoncho::start(); + fake.set(Mode::Status(401)); + let dir = TempDir::new("status-serve"); + let soul = dir.write("etc/soul.md", "You are Boxmaker.\n"); + let text = format!( + "[paths]\nhome = \"{}\"\n[memory]\nsoul_starter = \"{}\"\n[honcho]\nurl = \"{}\"\nagent = \"boxmaker0\"\nowner = \"kyle\"\ntrusted = \"boxmaker0-trusted\"\nuntrusted = \"boxmaker0-untrusted\"\nfleet = \"fleet\"\n", + dir.path().display(), + soul.display(), + fake.url + ); + let config = Config::parse(&text).unwrap(); + let log: serve::Log = Arc::new(|_: &str| {}); + let running = serve::start(config.clone(), log).unwrap(); + std::thread::spawn(move || running.run()); + let call = Message::MemoryCall(MemoryCall { + request: ToolRequest { + session: SessionId::new("mm-a").unwrap(), + call: CallId(1), + tool: "memory".to_string(), + arguments: r#"{"action":"add","file":"user","text":"Prefers UTC."}"#.to_string(), + }, + taint: DataClass::Private, + untrusted: false, + }); + ask(&config.broker_socket(), call); + let sync = || match ask( + &config.admin_socket(), + Message::MemoryAdmin(MemoryAdmin { + command: MemoryCommand::Sync, + arg: String::new(), + }), + ) { + Message::MemoryAdminReply(reply) => reply.text, + other => panic!("{other:?}"), + }; + let shown = Mutex::new(String::new()); + let deadline = Instant::now() + Duration::from_secs(10); + while Instant::now() < deadline { + *shown.lock().unwrap() = sync(); + if shown.lock().unwrap().contains("key refused") { + break; + } + std::thread::sleep(Duration::from_millis(20)); + } + assert_eq!( + *shown.lock().unwrap(), + "honcho sync: 1 decided: 0 sent, 1 waiting, 0 failed, 0 skipped\n\ + key refused (HTTP 401): trusted workspace boxmaker0-trusted: its sends wait until memoryd restarts" + ); +} diff --git a/crates/memoryd/tests/honcho_sync.rs b/crates/memoryd/tests/honcho_sync.rs index 24c3be2..46c2a73 100644 --- a/crates/memoryd/tests/honcho_sync.rs +++ b/crates/memoryd/tests/honcho_sync.rs @@ -221,11 +221,19 @@ fn memoryd_answers_with_the_report() { untrusted: false, }); ask(&config.broker_socket(), call); - // Honcho is not reachable here: the conclusion waits. + // Honcho is not reachable here: the conclusion waits. The write wakes the worker, so once it + // has tried, the report also shows the outage (review of M5c-1, findings 3 and 4). + let shown = sync(&config); + let mut lines = shown.lines(); assert_eq!( - sync(&config), - "honcho sync: 1 decided: 0 sent, 1 waiting, 0 failed, 0 skipped" + lines.next(), + Some("honcho sync: 1 decided: 0 sent, 1 waiting, 0 failed, 0 skipped") ); + if let Some(outage) = lines.next() { + assert!(outage.starts_with("honcho unreachable since "), "{shown}"); + assert!(outage.ends_with(": sends wait and are retried"), "{shown}"); + } + assert_eq!(lines.next(), None, "{shown}"); } #[test] diff --git a/docs/runbook.md b/docs/runbook.md index 2a4a4a0..0600b50 100644 --- a/docs/runbook.md +++ b/docs/runbook.md @@ -924,7 +924,8 @@ is a new peer. `agent` is this agent's own name, different on each agent; `owner the same in every agent's file. To turn Honcho off, remove `[honcho]`, its `[[honcho.read]]` tables and every `[secrets.honcho_…]`. -**Check.** `memoryd serve --config ` prints `memoryd: serving`. +**Check.** `memoryd serve --config ` prints `memoryd: serving`, and `bxctl memory sync` +answers with its `honcho sync:` line again. ## honcho-ledger-damaged @@ -937,7 +938,13 @@ memoryd: /srv/bx/memory/honcho.jsonl:12: turn 3 of session chat-1: decided alrea Or, while it runs, `memoryd: : ; see docs/runbook.md#honcho-ledger-damaged` when the ledger cannot be written (a full disk, a wrong owner). The turn waits undecided, and is decided at -a later turn's end once the ledger can be written. +a later turn's end once the ledger can be written. When the worker cannot record a send, the line +ends `the Honcho worker stops until memoryd restarts`, and nothing more is sent. + +While `memoryd` is stopped, `bxctl memory sync` cannot reach it. While it runs with a ledger it +cannot write, `bxctl memory sync` shows the counts as they were: a turn or a memory write that +could not be decided is not counted, and an item whose send could not be recorded stays +`waiting`. **Why.** The ledger is `memoryd`'s record of what it sends to Honcho: one line when a turn or a memory write is decided (where it goes, or that it goes nowhere), and one when it is sent or @@ -968,7 +975,8 @@ twice); a removed `decided` line means the item is decided again, and any later `failed` line of the same item then breaks the rules, so remove those too. Honcho cannot delete a message, so a turn sent twice stays twice. -**Check.** `memoryd` starts, and its log has no line with this entry. +**Check.** `memoryd` starts, its log has no line with this entry, and `bxctl memory sync`'s +`waiting` count falls as the worker sends. ## broker-state-unavailable @@ -985,6 +993,14 @@ The reason may instead be `No such file or directory` (nothing listens), a timeo `memoryd` logs `memoryd: brokerd answers on its state socket again; turns are decided`. Conversations are not affected. +While it lasts, `bxctl memory sync` shows, after its counts, the line + +```text +brokerd unanswered since 2026-09-28T10:00:00.000Z: turns wait undecided +``` + +The waiting turns are not in its counts: a turn is counted once it is decided. + **Why.** With `[honcho]`, `memoryd` decides where each finished turn goes in Honcho: the trusted workspace, the untrusted one, or nowhere (M5c spec, section 5). It needs `brokerd`'s record of the session's class and trust for that, and never guesses it: a guess could put a turn from a session @@ -1008,8 +1024,9 @@ log names the problem, usually `broker-state-damaged`. **Fix.** Start `brokerd` if it is stopped; make the two `[sockets] state` paths agree; or, for `brokerd`'s error, follow the entry its log names. -**Check.** At the next turn's end `memoryd` logs that `brokerd` answers again, and -`memory/honcho.jsonl` gains a `decided` line for each turn that waited. +**Check.** At the next turn's end `memoryd` logs that `brokerd` answers again, +`memory/honcho.jsonl` gains a `decided` line for each turn that waited, and `bxctl memory sync` +no longer shows the `brokerd unanswered` line. ## honcho-unreachable @@ -1024,6 +1041,12 @@ seconds to connect, or 30 without a byte), `closed`, `io`, or `server, HTTP 5xx` with a server error). When a send goes through again, `memoryd` logs `memoryd: Honcho answers again; waiting sends go on`. Conversations are not affected. +While it lasts, `bxctl memory sync` counts what waits and shows, after its counts, the line + +```text +honcho unreachable since 2026-09-28T10:00:00.000Z: sends wait and are retried +``` + **Why.** Every finished turn that is decided for Honcho waits in the ledger, `memory/honcho.jsonl`, until it is sent (M5c spec, section 5). While Honcho does not answer, `memoryd` tries the oldest waiting turn again, waiting 5 seconds, then 10, 20 and so on up to 10 @@ -1040,7 +1063,8 @@ curl -sS -m 5 "/health" **Fix.** Start Honcho, or make the network path to it work (on straylight, rift over the tailnet: `tailscale status`). If `[honcho] url` is wrong, correct it and restart `memoryd`. -**Check.** `memoryd` logs `Honcho answers again`, and `memory/honcho.jsonl` gains `sent` lines. +**Check.** `memoryd` logs `Honcho answers again`, `memory/honcho.jsonl` gains `sent` lines, and +`bxctl memory sync` no longer shows the `honcho unreachable` line; its `waiting` count falls. ## honcho-send-refused @@ -1054,6 +1078,13 @@ memoryd: turn 3 of session mm-chat-1 was not sent: Honcho refused the request (s or `memoryd: turn 3 of session mm-chat-1 cannot be sent (too-long); it is marked failed; …` for a turn whose text needs more than 100 messages of 25,000 characters. +`bxctl memory sync` counts it as `failed`, and lists each failed item under `failed, oldest +first:` with its time, its label, its kind, and its HTTP status when Honcho answered: + +```text + 2026-09-28T10:03:00.000Z turn 3 of session mm-chat-1 status (HTTP 422) +``` + **Why.** Honcho answered with a 4xx other than 401 or 403, a redirect, or a body `roncho` could not read; sending the same again would get the same answer, or could store it twice. So the turn is marked `failed` in `memory/honcho.jsonl`, with the kind and the status, and the next turn goes @@ -1082,6 +1113,13 @@ stop `memoryd`, keep a copy of the ledger, remove the turn's `failed` line (see memoryd: Honcho refused the key of workspace boxmaker0-trusted (HTTP 401); nothing more is sent to it until memoryd restarts; see docs/runbook.md#honcho-key-refused ``` +Until `memoryd` restarts, `bxctl memory sync` counts that workspace's items as `waiting` and +shows, after its counts, one line for each workspace whose key was refused: + +```text +key refused (HTTP 401): trusted workspace boxmaker0-trusted: its sends wait until memoryd restarts +``` + **Why.** Each workspace is sent to with its own key, `[secrets.honcho_trusted]`, `honcho_untrusted` or `honcho_fleet` (M5c spec, section 10), or none. A 401 or 403 means the key is wrong, expired, or missing where Honcho now wants one. Trying again would be refused again, so @@ -1097,4 +1135,5 @@ grep -n -A2 '^\[secrets\.honcho_' /etc/boxmaker/memoryd.toml **Fix.** Put the right key where `[secrets.]` points (see `secret-unavailable` for the sources), or remove the table if the workspace needs no key, then restart `memoryd`. -**Check.** After the restart the waiting turns are sent, and no line names this entry. +**Check.** After the restart the waiting turns are sent, no line names this entry, and `bxctl +memory sync` shows no `key refused` line.