From 9430cad3a8eca3b3d2682137b324c09f1ec8c85e Mon Sep 17 00:00:00 2001 From: James Braid Date: Thu, 12 Nov 2026 14:24:43 -0700 Subject: [PATCH 1/2] o2: hold a status read until every queued MTE transfer is done On a busy host the O2 now and then stopped at the PROM's serial loader prompt, SL-9600-8E>, with nothing before it, where a good boot prints "Running power-on diagnostics" and reaches its menu. It happened once in the boot test on a macOS arm64 CI runner, never on an idle host. PROM 4.18 clears 32 KB at the base of RAM with the MTE (0xbfc061f0), reads the rendering engine's status once and goes on whatever it says: its wait at 0xbfc06400 tests a value that can never be negative. It then stores sp at 0xa0001008 as a cookie, copies its POST code to 0xa0004000, runs it, and drops into the serial loader if the cookie has changed. The engine runs on the CRIME-RE host thread, and a status read waited for it at most 100 us. When the host kept that thread off a processor for longer, the clear ran after the cookie store and zeroed it. Later still, it zeroed the POST code and the CPU hung at 0xbfc003a0 on a reserved instruction, printing nothing. With a sleep injected before each transfer (not committed), on a Linux host, release build with lightning and jitv2, phase A only: up to 1300 us the menu came up; 1400 and 1500 us gave SL-9600-8E> byte for byte as in CI, with physical 0x1008 reading 0; 1600 us and more hung in POST. With no injected delay, the CRIME-RE thread at SCHED_IDLE on a core running a busy loop hung 3 boots of 7. Stopping the whole process never reproduced it, as that stalls the CPU along with the engine. The engine now counts transfers queued and carried out, and a status read answers BUS_BUSY until they match, so the CPU retries it and cannot get past a transfer it started. After the change the same delays from 1300 us to 20 ms all reach the menu, as did 3 of 3 starved boots. The test queues a clear, starts the engine 200 ms later and fails before the change: the read answered with the memory still unwritten. The bounded wait now holds for primitives only, so a driver that only checks for room while drawing still overlaps the engine. MTE transfers do not. IRIX's MTE copy path reads the status for room right after starting a transfer, so a copy longer than 100 us now holds the CPU until it is done. Before, the read gave up after 100 us and reported a busy level. A synthetic back-to-back 8 KB clear plus status read took about 10.0 us per pair, against 8.6 us without the guard (release build, 20,000 pairs, best of 7, three runs each). That is an upper bound for the micro-pattern, not an X or GL cost. No X or GL benchmark exists in the tree to measure the real cost. --- clanker/INDEX.md | 1 + ...o2-prom-does-not-wait-for-its-mte-clear.md | 25 +++++ docs/graphics/o2.md | 7 +- src/dev/o2gfx.rs | 91 ++++++++++++++++++- 4 files changed, 121 insertions(+), 3 deletions(-) create mode 100644 clanker/devices/o2-prom-does-not-wait-for-its-mte-clear.md diff --git a/clanker/INDEX.md b/clanker/INDEX.md index b3e55f016..8cc4c996e 100644 --- a/clanker/INDEX.md +++ b/clanker/INDEX.md @@ -124,6 +124,7 @@ Non-graphics devices: MC/MEMCFG and RAM banks, HPC3, VDMA, EEPROMs and NVRAM, PS | [o2-readback-transfer-registers.md](devices/o2-readback-transfer-registers.md) | rule | O2 glReadPixels: the frame-buffer-to-linear transfer, GL vertices, edge type, src steps and linStride as IRIX uses them | | [ip32-o2-bringup-log.md](devices/ip32-o2-bringup-log.md) | history | The O2 (IP32) bring-up log: PROM, POST, CRIME/MACE/GBE, SCSI, PCI, the OSes | | [ip32-headless-irix-panics.md](devices/ip32-headless-irix-panics.md) | rule | O2 TLBMISS at 0xff800000 in early boot was `crmFifoWait` timing out on our host-thread RE; status polls now wait for the engine (fixed) | +| [o2-prom-does-not-wait-for-its-mte-clear.md](devices/o2-prom-does-not-wait-for-its-mte-clear.md) | rule | O2 PROM 4.18 clears low memory with the MTE and reads RE status once without waiting; a late engine thread wiped its cookie (`SL-9600-8E>`) or its POST code. A status read now answers busy until every queued transfer is done | | [ip30-octane-bringup.md](devices/ip30-octane-bringup.md) | rule | What the Octane's PROM insists on (memory sizing, the Bridge status bit, empty slots, IOC3 bits, the one-wire parts' formats, its device tree) and what booting it through to IRIX added (cached flash lines, low-memory JIT counters, the ISP stall, HQ4 before a context switch) | | [ip30-memory-past-4gb-takes-a-16gb-window.md](devices/ip30-memory-past-4gb-takes-a-16gb-window.md) | design | Octane past 4 GB: 16 GB window, 256 MB per bitmap bit, per-machine shift | | [ip30-module-name-must-match-active-cpus.md](devices/ip30-module-name-must-match-active-cpus.md) | rule | Octane: the module record must say PM10 for one CPU and PM20 for two, or the PROM fails its NIC diagnostic | diff --git a/clanker/devices/o2-prom-does-not-wait-for-its-mte-clear.md b/clanker/devices/o2-prom-does-not-wait-for-its-mte-clear.md new file mode 100644 index 000000000..9e2511bc6 --- /dev/null +++ b/clanker/devices/o2-prom-does-not-wait-for-its-mte-clear.md @@ -0,0 +1,25 @@ +# The O2 PROM does not wait for its MTE clear: a status read must + +Status: fixed (2026-11-12). + +**Symptom.** On a busy host the O2 now and then sat at `SL-9600-8E>` on +serial with nothing before it, instead of reaching the PROM menu. A later +form of the same race prints nothing and parks the CPU at `0xbfc003a0` on a +reserved instruction. + +**Cause.** PROM 4.18 clears 32 KB at RAM base with the MTE (`0xbfc061f0`), +reads RE status once without acting on it (`0xbfc06400`), stores a cookie at +`0xa000_1008` and copies its POST code to `0xa000_4000`. It checks the cookie +after POST (`0xbfc044f4`) and drops to the serial loader if it changed. The MTE +runs on the CRIME-RE host thread, and a status read waited at most 100 us. +When the host kept that thread off a processor longer, the clear ran late and +zeroed the cookie, or later still the POST code. + +**Rule.** A status read answers `BUS_BUSY` until every MTE transfer queued +before it is done (`transfers_queued` against `transfers_done` in `CrimeRe`). +Primitives keep the bounded wait. MTE copies longer than 100 us lose their +overlap with the CPU. Software that reuses memory a transfer wrote without +reading the status word still races the engine. The same race exists for +primitives, whose frame buffers are main memory: a read-back with no idle wait +could see pixels not yet drawn. It is left uncovered on purpose, as no known +guest does that and holding primitives would cost drawing overlap. diff --git a/docs/graphics/o2.md b/docs/graphics/o2.md index 62e958a34..c52d054a5 100644 --- a/docs/graphics/o2.md +++ b/docs/graphics/o2.md @@ -68,7 +68,12 @@ only setting the register. Page `0x2000` starts a primitive (`pixel_pipe`). Page A read of the engine's registers while it is busy answers `BUS_BUSY` (`read_reg`). The status word reports the buffer level as CRIME's own FIFO would show it (`read_reg_now`). A status read first waits up to 100 us for the engine to go idle, -or 20 ms when the previous poll found it busy. +or 20 ms when the previous poll found it busy. A memory transfer (MTE) is not +left behind that way: until every transfer queued before it is done, a status +read answers `BUS_BUSY` and the CPU retries it. The O2's PROM clears memory with +the MTE, reads the status word once without acting on it, and uses that memory +straight after. An MTE copy longer than 100 us therefore no longer overlaps +the CPU's next status read. GBE's registers are written in place (`Gbe::write_reg`). A write to a shadowed register goes to a pending list with the frame number. The pending writes are diff --git a/src/dev/o2gfx.rs b/src/dev/o2gfx.rs index 276341ee2..7024b551f 100644 --- a/src/dev/o2gfx.rs +++ b/src/dev/o2gfx.rs @@ -1179,6 +1179,12 @@ pub struct CrimeRe { /// nothing since: a further status read is a guest waiting in a loop. /// Host pacing only, not CRIME state, so a snapshot does not keep it. polled_busy: std::sync::atomic::AtomicBool, + /// MTE transfers the CPU has queued, and those the engine has carried + /// out: a status read answers only once the second has caught up (see + /// `read_reg_now`). Host pacing too. `done` can lead for a moment, as the + /// count is raised after the push, and the `>=` test absorbs that. + transfers_queued: std::sync::atomic::AtomicU64, + transfers_done: std::sync::atomic::AtomicU64, asleep: std::sync::atomic::AtomicBool, started: std::sync::atomic::AtomicBool, /// Set by [`Self::stop`]: the engine's thread ends once the buffer is @@ -1283,6 +1289,8 @@ impl CrimeRe { ib: unsafe { Box::::new_zeroed().assume_init() }, busy: std::sync::atomic::AtomicBool::new(false), polled_busy: std::sync::atomic::AtomicBool::new(false), + transfers_queued: std::sync::atomic::AtomicU64::new(0), + transfers_done: std::sync::atomic::AtomicU64::new(0), asleep: std::sync::atomic::AtomicBool::new(false), started: std::sync::atomic::AtomicBool::new(false), quit: std::sync::atomic::AtomicBool::new(false), @@ -1439,6 +1447,25 @@ impl CrimeRe { true } + /// Wait up to `limit` for the engine to carry out every MTE transfer + /// queued so far. + fn transfers_caught_up(&self, limit: std::time::Duration) -> bool { + use std::sync::atomic::Ordering::Acquire; + let caught_up = || self.transfers_done.load(Acquire) >= self.transfers_queued.load(Acquire); + if caught_up() { + return true; + } + let until = std::time::Instant::now() + limit; + let backoff = crossbeam_utils::Backoff::new(); + while !caught_up() { + if std::time::Instant::now() >= until { + return false; + } + backoff.snooze(); + } + true + } + /// Wait until the engine is idle (tests and replays; the CPU retries). #[cfg(test)] fn wait_idle(&self) { @@ -1528,6 +1555,9 @@ impl CrimeRe { return BUS_BUSY; } crate::pf_value!(self.pf_level, crate::perfetto::events::RE_IB_LEVEL, self.ib.len()); + if off & 0xf800 == 0x3800 { + self.transfers_queued.fetch_add(1, std::sync::atomic::Ordering::Release); + } self.polled_busy.store(false, std::sync::atomic::Ordering::Relaxed); self.record(off, val, width); self.wake(); @@ -1591,6 +1621,16 @@ impl CrimeRe { // queued while that fits, one entry past it, so software that // waits for room (the kernel's MTE copies wait for 64 - level) // always finds some and the CPU runs ahead of the engine. + // + // That holds for primitives only: while an MTE transfer is + // outstanding the read answers busy (the CPU retries) until it is + // done. The O2's PROM clears memory with the MTE, reads this word + // once and reuses that memory, which a late engine thread wiped. MTE + // copies longer than 100 us lose their overlap with the CPU. + // Primitives draw into main memory too, so software that reads + // pixels back without an idle wait could race the same way. No + // known guest does, and holding there would cost drawing overlap. + STATUS | 0x4004 if !self.transfers_caught_up(RE_STATUS_POLL_WAIT) => None, STATUS | 0x4004 => Some(if self.idle() || self.drain(self.status_wait()) { self.polled_busy.store(false, std::sync::atomic::Ordering::Relaxed); RE_STATUS_IDLE @@ -1623,7 +1663,7 @@ impl CrimeRe { if page == 0x2000 { self.pixel_pipe(); } else { - self.mte(); + self.transfer(); } } } @@ -2785,6 +2825,13 @@ impl CrimeRe { } } + /// Carry out an MTE transfer, and count it done for a status read + /// waiting on it. + fn transfer(&self) { + self.mte(); + self.transfers_done.fetch_add(1, std::sync::atomic::Ordering::Release); + } + fn mte(&self) { crate::pf_scope!(crate::perfetto::events::RE_MTE, self.drawn.load(std::sync::atomic::Ordering::Relaxed)); self.drawn.fetch_add(1, std::sync::atomic::Ordering::Relaxed); @@ -2958,7 +3005,7 @@ impl CrimeRe { if page == 0x2000 { self.pixel_pipe(); } else { - self.mte(); + self.transfer(); } } } @@ -3999,6 +4046,46 @@ mod tests { assert_eq!(re.read32((0x1500_0000 + FG) as u64).data, 1000); } + /// The O2's PROM clears the bottom 32 KB of memory with the MTE, reads + /// the status word once and goes on storing into that memory without + /// looking at what it read. Its clear has to be done by the time the + /// read answers, however late the engine's thread gets to run. A clear + /// that lands later wipes what the PROM stored since: on a busy host + /// the PROM stopped at its serial loader prompt, `SL-9600-8E>`. + #[test] + fn a_status_read_answers_only_once_a_queued_transfer_is_done() { + let ram = Arc::new(O2Memory::single(32 << 20)); + let addr = 0x0011_4000u32; + ram.write(addr as usize, &[0x55; 0x2000]); + let re = Arc::new(CrimeRe::new(ram.clone())); + let reg = |off: u32| (0x1500_0000 + off) as u64; + let page = addr >> 12; + let pair = ((1u64 << 31 | page as u64) << 32) | (1u64 << 31 | (page + 1) as u64); + assert_eq!(re.write64(reg(TLB_LINEAR_A + 8 * ((page & 31) >> 1)), pair), BUS_OK); + for (off, val) in [(MTE_DST0, addr), (MTE_DST1, addr + 0x1fff), (MTE_FG, 0), (MTE_BYTEMASK, 0xffff_ffff), (MTE_MODE | 0x800, 0x11)] { + assert_eq!(re.write32(reg(off), val), BUS_OK); + } + // The engine's thread starts 200 ms from now, far past the status + // read's own wait. + let late = re.clone(); + let starter = std::thread::spawn(move || { + std::thread::sleep(std::time::Duration::from_millis(200)); + late.start(late.clone(), |r| r); + }); + // The PROM's one read, retried while it answers busy as the CPU + // retries it. + let status = loop { + let r = re.read32(reg(STATUS)); + if r.status != BUS_BUSY { + break r.data; + } + }; + let cleared = ram.bytes(addr as usize, 0x2000).iter().all(|&b| b == 0); + starter.join().unwrap(); + assert!(cleared, "the read answered before the clear was done"); + assert_eq!(status, RE_STATUS_IDLE); + } + /// A full interface buffer holds the CPU's write back (BUS_BUSY) with /// nothing lost, and the status word shows the level as CRIME's 64 /// entries would: what is queued below that, one entry past it. From 7cf5cf0822cf2f816d2df56d32155cf569db75fe Mon Sep 17 00:00:00 2001 From: James Braid Date: Thu, 12 Nov 2026 14:24:51 -0700 Subject: [PATCH 2/2] iris-ci: keep the serial output and CPU state of a stuck phase A When the O2 PROM stopped at its serial loader in CI, boot-test left an empty phase-a.log and serial.log held only SL-9600-8E>. Nothing said where the PROM was parked, so the failure could not be told from a POST hang or a missed menu, and it took a local reproduction to find the cause. phase-a.log was empty because a wait that times out takes none of the output. On a phase A failure the test now drains what the PROM printed into phase-a.log, stops the CPU through the monitor and writes its registers to phase-a-cpu.log. On the O2 it also dumps the words at physical 0x1000 and 0x4000, where the PROM keeps its stack cookie and POST code: zeros there point at a memory clear that landed late, intact words at some other route into the serial loader. Both files match the artifact upload's *.log pattern. Checked with a PROM whose firmware segment fails its checksum: the serial loader prompt landed in phase-a.log and the PC, 0xbfc013ac, in phase-a-cpu.log. The same PROM parked at the prompt shows the cookie intact (0xffffffff80000fa8 at 0x1008) and POST's first instruction at 0x4000, so the dump tells that route from a late clear. --- TESTING.md | 5 +- clanker/testing/ci-unattended-irix-boot.md | 10 +++ src/iris_ci_boot.rs | 94 +++++++++++++++++++++- 3 files changed, 104 insertions(+), 5 deletions(-) diff --git a/TESTING.md b/TESTING.md index e37d75498..7cfcd85e5 100644 --- a/TESTING.md +++ b/TESTING.md @@ -515,7 +515,10 @@ console on the graphics board and a screenshot to match. It reads the seeded NVRAM back from the PROM and from the booted guest, and checks that iris quits cleanly. What it seeds and checks is `tests/irix/boot.toml`. Each check is a JUnit case, so a failed run is annotated with the check that failed, and the run -keeps the logs. [clanker/testing/ci-unattended-irix-boot.md](clanker/testing/ci-unattended-irix-boot.md) +keeps the logs. When the headless run never reaches the PROM's menu or a prompt, +`phase-a.log` holds everything the PROM printed and `phase-a-cpu.log` the CPU's +registers where it stopped (on the O2, also the words at physical 0x1000 and +0x4000). [clanker/testing/ci-unattended-irix-boot.md](clanker/testing/ci-unattended-irix-boot.md) has the details. ## Disk persistence on exit diff --git a/clanker/testing/ci-unattended-irix-boot.md b/clanker/testing/ci-unattended-irix-boot.md index 5cff9a8a2..7cbb0e8e9 100644 --- a/clanker/testing/ci-unattended-irix-boot.md +++ b/clanker/testing/ci-unattended-irix-boot.md @@ -45,6 +45,16 @@ The serial boot stays alongside the graphics one: it is cheap, and when a boot fails its transcript shows how far it got, which a screenshot does not. The PROM lists a seeded `AutoLoad` as `Yes` and the guest's `nvram` as `Y`, so only the PROM's listing is checked. The test then seeds NVRAM again with `console g` and boots a second time. + +When the headless pass gets stuck (no `Option?`, no Command Monitor prompt) the +test keeps what the PROM printed that no wait took in `phase-a.log`, stops the +CPU through the monitor (`stop`, `regs`) and writes the registers to +`phase-a-cpu.log`. On the O2 it adds `mem 0xa0001000 4 w` and +`mem 0xa0004000 4 w`: zeros at the PROM's stack cookie (0x1008) or POST code +(0x4000) mean a late MTE clear, as in +[o2-prom-does-not-wait-for-its-mte-clear.md](../devices/o2-prom-does-not-wait-for-its-mte-clear.md). Both are in the job's artifact. The O2 PROM's own +failures say little on serial (`SL-9600-8E>` and nothing else is common), so +the PC is what tells a parked serial loader from a POST hang. The login is drawn on the framebuffer, so `iris-ci screen-wait` polls screenshots until one matches `scripts/boot-goldens/indy-irix53.png`. Serial is not silent on every disk: the stock disk has a getty on `ttyd1`, so `IRIS diff --git a/src/iris_ci_boot.rs b/src/iris_ci_boot.rs index c3c8400d5..84f5cb2cf 100644 --- a/src/iris_ci_boot.rs +++ b/src/iris_ci_boot.rs @@ -117,7 +117,7 @@ pub fn run(args: Args) -> Result<()> { } let out = abs(&args.out)?; std::fs::create_dir_all(&out).map_err(|e| local(&out, e))?; - for f in ["nvram.bin", "serial.log", "phase-a.log", "boot-test.xml"] { + for f in ["nvram.bin", "serial.log", "phase-a.log", "phase-a-cpu.log", "boot-test.xml"] { let _ = std::fs::remove_file(out.join(f)); } @@ -130,6 +130,7 @@ pub fn run(args: Args) -> Result<()> { opts: Opts { socket: PathBuf::from(socket), json: false, quiet: true }, child: None, prompt: monitor_prompt(machine), + stuck: stuck_commands(machine), check: String::new(), cases: Vec::new(), failed: false, @@ -168,6 +169,18 @@ fn monitor_prompt(machine: iris::config::MachineProfile) -> &'static str { if machine == iris::config::MachineProfile::O2Ip32 { "> " } else { ">> " } } +/// What the monitor is asked when phase A is stuck: the registers, and on +/// the O2 the words at physical 0x1000 and 0x4000. The O2 PROM keeps a stack +/// cookie at 0x1008 and its POST code at 0x4000. Zeros there mean a memory +/// clear landed after the PROM had stored them. +fn stuck_commands(machine: iris::config::MachineProfile) -> &'static [&'static str] { + if machine == iris::config::MachineProfile::O2Ip32 { + &["stop", "regs", "mem 0xa0001000 4 w", "mem 0xa0004000 4 w"] + } else { + &["stop", "regs"] + } +} + /// The CI socket: TCP on Windows, and elsewhere a Unix socket in the host's /// temporary directory, as iris's own default is. A path under the output /// directory could pass macOS's 104-byte limit on a Unix socket path. @@ -204,6 +217,27 @@ fn config(disk: &Path, socket: &str, machine: &str) -> String { format!("# Written by iris-ci boot-test.\n{}", toml::to_string(&t).expect("a table of plain values")) } +/// Run `cmds` on iris's monitor at `addr` and return what it printed. The +/// monitor hangs up after `quit`, so the reply is everything up to then. +fn monitor_run(addr: &str, cmds: &[&str]) -> std::io::Result { + use std::io::Read; + let to = std::time::Duration::from_secs(10); + let addr: std::net::SocketAddr = addr.parse().map_err(|e| std::io::Error::new(std::io::ErrorKind::InvalidInput, e))?; + let mut s = std::net::TcpStream::connect_timeout(&addr, to)?; + s.set_read_timeout(Some(to))?; + s.write_all(format!("{}\nquit\n", cmds.join("\n")).as_bytes())?; + // Keep what came before a read that timed out. + let mut out = Vec::new(); + if let Err(e) = s.read_to_end(&mut out) { + if out.is_empty() { + return Err(e); + } + } + // From the first prompt on: before it is the monitor's banner. + let text = String::from_utf8_lossy(&out).replace("\r\n", "\n"); + Ok(text.find("> ").map_or(text.as_str(), |i| &text[i..]).to_string()) +} + fn log(msg: &str) { let day = std::time::SystemTime::now() .duration_since(std::time::UNIX_EPOCH).map_or(0, |d| d.as_secs()) % 86400; @@ -245,6 +279,8 @@ struct Test { child: Option, /// What the PROM's Command Monitor prints when it wants a line. prompt: &'static str, + /// Monitor commands that say where a stuck phase A stopped. + stuck: &'static [&'static str], /// The case a failure that ends the test is filed under. check: String, cases: Vec, @@ -363,6 +399,30 @@ impl Test { ok.then_some(text) } + /// Phase A is stuck: keep what the PROM printed that no wait took, and + /// where the CPU is (with `stuck`'s memory words), in phase-a.log and + /// phase-a-cpu.log, and print both. + /// The serial output is often a single prompt, and the registers say + /// which loop the PROM is parked in. + fn prom_stopped(&self) { + let serial = self.out.join("phase-a.log"); + if let Ok(Value::String(rest)) = send(&self.opts, "serial-read", json!({})) { + if let Ok(mut f) = std::fs::OpenOptions::new().append(true).create(true).open(&serial) { + let _ = f.write_all(rest.as_bytes()); + } + } + self.dump(&serial); + let cpu = self.out.join("phase-a-cpu.log"); + let regs = send(&self.opts, "status", json!({})).ok() + .and_then(|s| s.get("monitor_addr").and_then(Value::as_str).map(str::to_string)) + .ok_or_else(|| "no monitor address".to_string()) + .and_then(|addr| monitor_run(&addr, self.stuck).map_err(|e| format!("monitor {addr}: {e}"))); + let text = regs.unwrap_or_else(|e| format!("CPU state not read: {e}\n")); + let _ = std::fs::write(&cpu, &text); + log(&format!("CPU state, also in {}:", cpu.display())); + print!("{text}"); + } + /// Type a Command Monitor line and wait for the prompt. What the monitor /// printed comes back. fn monitor(&mut self, line: &str) -> Step { @@ -370,7 +430,7 @@ impl Test { match sent.is_ok().then(|| self.prom_wait(self.prompt, PROMPT_WAIT)).flatten() { Some(text) => Ok(text), None => { - self.dump(&self.out.join("phase-a.log")); + self.prom_stopped(); Err(self.abort(format!("phase A: '{line}' got no prompt back"))) } } @@ -389,13 +449,13 @@ impl Test { self.start_iris(&format!("iris-seed-{console}.log"), &["--headless"])?; let _ = send(&self.opts, "start", json!({})); if self.prom_wait("Option?", MENU_WAIT).is_none() { - self.dump(&self.out.join("phase-a.log")); + self.prom_stopped(); return Err(self.abort("phase A: PROM menu never appeared on serial".into())); } // Enter Command Monitor. let _ = send(&self.opts, "serial-send", json!({"data": "5\r"})); if self.prom_wait(self.prompt, PROMPT_WAIT).is_none() { - self.dump(&self.out.join("phase-a.log")); + self.prom_stopped(); return Err(self.abort("phase A: no Command Monitor prompt".into())); } for (k, v) in seeded(vars, console, false) { @@ -578,6 +638,7 @@ mod tests { opts: Opts { socket: PathBuf::new(), json: false, quiet: true }, child: None, prompt: ">> ", + stuck: &["stop", "regs"], check: String::new(), cases: Vec::new(), failed: false, @@ -633,6 +694,31 @@ mod tests { assert!(sock.len() - std::env::temp_dir().as_os_str().len() < 40); } + /// The CPU dump of a stuck phase A: each command's answer, without the + /// monitor's banner, read until the monitor hangs up after `quit`. + #[test] + fn the_monitor_answers_come_back_without_its_banner() { + use std::io::{BufRead, BufReader}; + let l = std::net::TcpListener::bind("127.0.0.1:0").unwrap(); + let addr = l.local_addr().unwrap().to_string(); + let server = std::thread::spawn(move || { + let (s, _) = l.accept().unwrap(); + let mut w = s.try_clone().unwrap(); + w.write_all(b" ## \r\nMonitor\r\n> ").unwrap(); + for line in BufReader::new(s).lines() { + match line.unwrap().as_str() { + "quit" => break, + "stop" => w.write_all(b"CPU stopped\r\n> ").unwrap(), + "regs" => w.write_all(b"PC: 0xffffffffbfc013ac\r\n> ").unwrap(), + _ => w.write_all(b"Unknown command.\r\n> ").unwrap(), + } + } + }); + let got = monitor_run(&addr, &["stop", "regs"]).unwrap(); + server.join().unwrap(); + assert_eq!(got, "> CPU stopped\n> PC: 0xffffffffbfc013ac\n> "); + } + #[test] fn the_config_names_the_disk_whatever_its_path_holds() { let disk = Path::new("C:\\a \"b\"\\irix.chd");