o2: finish queued MTE transfers before a status read answers

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

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 |

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.

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

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

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::<IntfBuf>::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.