From 3d266df9deaa4991fc47584381cd8d116f4459e0 Mon Sep 17 00:00:00 2001 From: "K. Isom" Date: Mon, 28 Sep 2026 14:11:31 -0700 Subject: [PATCH] review: bxctl memory sync shows what the Honcho side waits on A shared status, kept by the worker and the walk and read by the report under its own leaf lock, holds the workspaces whose key was refused, when an outage of Honcho began, and when brokerd stopped answering. The report adds a line for each while it lasts, and is unchanged when all is well. The runbook's Honcho entries and broker-state-unavailable now say what sync shows. Tuning and Wake move to honcho/wake.rs (re-exported from worker) to keep worker.rs under 500 lines. honcho_sync.rs's serve test now allows the outage line: the write wakes the worker, which finds Honcho unreachable. Co-Authored-By: Claude Opus 5.5 (1M context) --- crates/memoryd/src/honcho/ledger.rs | 2 +- crates/memoryd/src/honcho/mirror.rs | 18 ++- crates/memoryd/src/honcho/mod.rs | 2 + crates/memoryd/src/honcho/report.rs | 17 ++- crates/memoryd/src/honcho/start.rs | 11 +- crates/memoryd/src/honcho/status.rs | 68 ++++++++++ crates/memoryd/src/honcho/turns.rs | 14 +- crates/memoryd/src/honcho/wake.rs | 49 +++++++ crates/memoryd/src/honcho/worker.rs | 84 ++++-------- crates/memoryd/tests/honcho_status.rs | 188 ++++++++++++++++++++++++++ crates/memoryd/tests/honcho_sync.rs | 14 +- docs/runbook.md | 53 +++++++- 12 files changed, 439 insertions(+), 81 deletions(-) create mode 100644 crates/memoryd/src/honcho/status.rs create mode 100644 crates/memoryd/src/honcho/wake.rs create mode 100644 crates/memoryd/tests/honcho_status.rs 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.