From 1d605f50c9da1612ad06bdae86c9f762aa98c926 Mon Sep 17 00:00:00 2001 From: iximeow Date: Mon, 27 Oct 2025 16:46:12 +0000 Subject: [PATCH 1/7] Rudimentary NVMe emulation fuzzer This tries doing a bunch of random operations against an NVMe device and checks the operations against a limited model of what the results of those operations should be. The initial stab at this is what caught https://github.com/oxidecomputer/propolis/pull/965, and it caught a bug in an intermediate state of #953 (which other phd tests did notice anyway). This fuzzing would probably be best with actual I/O operations mixed in, and I think that *should* be relatively straightforward to add from here., but as-is it's useful! This would probably be best phrased as a `cargo-fuzz` test to at least get coverage-guided fuzzing. Because of the statefulness of NVMe I think either way we'd want the model of expected device state and a pick-actions-then-run execution to further guide `cargo-fuzz` into useful parts of the device state. The initial approach at this allowed for device reset and migration at arbitrary times via a separate thread. When that required synchronizing the model of device state it was effectively interleaved with "guest" operations on the device, and in practice admin commands are serialized by the `NvmeCtrl` state lock anyway. It may be more interesting to revisit with concurrent I/O operations on submission/completion queues. --- Cargo.lock | 11 + Cargo.toml | 1 + lib/propolis/Cargo.toml | 2 + lib/propolis/src/hw/nvme/mod.rs | 3 + lib/propolis/src/hw/nvme/test.rs | 644 +++++++++++++++++++++++++++++++ 5 files changed, 661 insertions(+) create mode 100644 lib/propolis/src/hw/nvme/test.rs diff --git a/Cargo.lock b/Cargo.lock index 0eebdbc5e..f8b096820 100644 --- a/Cargo.lock +++ b/Cargo.lock @@ -5341,8 +5341,10 @@ dependencies = [ "pin-project-lite", "propolis_types", "rand 0.9.2", + "rand_pcg", "rfb", "rgb_frame", + "ron", "serde", "serde_arrays", "serde_json", @@ -5807,6 +5809,15 @@ dependencies = [ "getrandom 0.3.2", ] +[[package]] +name = "rand_pcg" +version = "0.9.0" +source = "registry+https://github.com/rust-lang/crates.io-index" +checksum = "b48ac3f7ffaab7fac4d2376632268aa5f89abdb55f7ebf8f4d11fffccb2320f7" +dependencies = [ + "rand_core 0.9.3", +] + [[package]] name = "rand_xorshift" version = "0.3.0" diff --git a/Cargo.toml b/Cargo.toml index 6fefc83e0..3e2e2dddc 100644 --- a/Cargo.toml +++ b/Cargo.toml @@ -146,6 +146,7 @@ progenitor-client = "0.10.0" proptest = "1.5.0" quote = "1.0" rand = "0.9.1" +rand_pcg = "0.9.0" reqwest = { version = "0.12.0", default-features = false } ring = "0.17" ron = "0.8" diff --git a/lib/propolis/Cargo.toml b/lib/propolis/Cargo.toml index 88a04558a..c5c36c604 100644 --- a/lib/propolis/Cargo.toml +++ b/lib/propolis/Cargo.toml @@ -52,6 +52,8 @@ tempfile.workspace = true slog-term.workspace = true slog-async.workspace = true rand.workspace = true +rand_pcg.workspace = true +ron.workspace = true [features] default = [] diff --git a/lib/propolis/src/hw/nvme/mod.rs b/lib/propolis/src/hw/nvme/mod.rs index ef21266a2..98e6afb2e 100644 --- a/lib/propolis/src/hw/nvme/mod.rs +++ b/lib/propolis/src/hw/nvme/mod.rs @@ -26,6 +26,9 @@ mod cmds; mod queue; mod requests; +#[cfg(test)] +mod test; + use bits::*; use queue::{CompQueue, Permit, QueueId, SubQueue}; diff --git a/lib/propolis/src/hw/nvme/test.rs b/lib/propolis/src/hw/nvme/test.rs new file mode 100644 index 000000000..68676ed81 --- /dev/null +++ b/lib/propolis/src/hw/nvme/test.rs @@ -0,0 +1,644 @@ +// This Source Code Form is subject to the terms of the Mozilla Public +// License, v. 2.0. If a copy of the MPL was not distributed with this +// file, You can obtain one at https://mozilla.org/MPL/2.0/. + +use crate::accessors::MemAccessor; +use crate::block::{self, Backend, BackendOpts, InMemoryBackend}; +use crate::hw::pci::{test::Scaffold, Bus, BusLocation, Endpoint}; +use crate::migrate::{ + MigrateCtx, MigrateMulti, PayloadOffer, PayloadOffers, PayloadOutputs, +}; +use std::num::NonZeroUsize; +use std::sync::Arc; + +use crate::hw::nvme::{ + bits, AdminQueueAttrs, Configuration, CtrlrReg, GuestAddr, NvmeError, + PciNvme, SubmissionQueueEntry, WriteOp, +}; + +use crate::vmm::PhysMap; + +use crate::lifecycle::Lifecycle; + +use rand::{Rng, SeedableRng}; +use rand_pcg::Pcg64; +use slog::{Discard, Logger}; + +const MB: usize = 1024 * 1024; + +/// A test harness and primitive driver for some kinds of fuzz testing of +/// `PciNvme`. +/// +/// `PciNvme` (and other drivers) is stateful enough that naive "feed random +/// inputs", or even coverage-guided fuzzing, isn't *incredibly* interesting. +/// Additionally, `PciNvme` is explicitly allowed to be operated on +/// concurrently. A sampling of operations that can reasonably be concurrent: +/// * Reads from or writes to the PCI BAR (maybe concurrent!) +/// * Writes to admin or I/O submission queues (also concurrent!) +/// * Device resets (downstream of VM reboot, typically) +/// * Bonus: VM migration +/// +/// `FuzzCtx` intends to bundle state to support and operate `PciNvme`, without +/// imposing on possible tests. Tests will probably find it useful to maintain a +/// state machine where operations on `FuzzCtx` transition between states and +/// allowable successor states. One hope is for `FuzzCtx` and corresponding test +/// state machine to adaptable to `cargo-fuzz`, even with the limitations of +/// coverage-guided fuzzing. +/// +/// `FuzzCtx` is too high-level for some tests. Because it manages shared state +/// to drive the emulated device, `FuzzCtx` does not allow arbitrary resets at +/// any point as `PciNvme` technically does. (In practice, reset immediately +/// locks the inner `NvmeCtrl` to do the reset, for administrative options it is +/// effectively serialized anyway.) +struct FuzzCtx { + // The star of the show, this is the NVMe device that we'll hammer on. + nvme: Arc, + + // The rest of the "system" around the emulated device. This is here + // because we've gotta hold it somewhere, and some parts (`bus`) are + // swapped out when we replace `nvme` during migrations. + log: Logger, + scaffold: Scaffold, + bus: Bus, + + // This test aims to exercise NVMe emulation and its relationship to + // backends generally. So use `InMemoryBackend` as it requires the least + // plumbing to do its part of the job. + backend: Arc, + + /// The next CID to use when enqueuing an admin command. + available_cid: u16, + /// The next index in the admin submission queue at which an SQE should + /// be written. + available_sqe_idx: u16, +} + +impl FuzzCtx { + /// Arbitrary 20-byte serial. + const TEST_SERIAL: &'static [u8; 20] = b"11112222333344445555"; + // Bus location doesn't matter all that much, we'll happen to poke the + // NVMe device via `ctrl_reg_write` directly anyway. + const TEST_NVME_LOCATION: BusLocation = BusLocation::new(0, 0).unwrap(); + + const SQE_SIZE: usize = std::mem::size_of::(); + + const ADMIN_SQ_ENTRIES: u16 = 1024; + const ADMIN_SQ_BASE: GuestAddr = GuestAddr(1 * MB as u64); + const ADMIN_SQ_SIZE: usize = + Self::ADMIN_SQ_ENTRIES as usize * Self::SQE_SIZE; + + const ADMIN_CQ_ENTRIES: u16 = 1024; + const ADMIN_CQ_BASE: GuestAddr = + GuestAddr(Self::ADMIN_SQ_BASE.0 + Self::ADMIN_SQ_SIZE as u64); + + // Place I/O queues arbitrarily at the end of memory. + const IO_QUEUES_BASE: usize = 2 * MB - (256 * 1024); + // We won't do much with the queues, so they don't need to be deep. + const IO_QUEUE_ENTRIES: u16 = 64; + // And SQEs are larger than CQEs, so we'll just use the larger size for + // all I/O queues. + const IO_QUEUE_SIZE: usize = + Self::SQE_SIZE * (Self::IO_QUEUE_ENTRIES as usize); + + fn new(log: &Logger) -> Self { + let mut scaffold = Scaffold::new(); + + // Scaffold sets up an orphan acc_mem. Swap it with a more-real + // memory mapping, which we'll use for admin queue operations later. + let mut map = PhysMap::new_test(2 * MB); + // Test RAM starts at 1 MB and is 1 MB large. + map.add_test_mem("test-ram".to_string(), MB, MB) + .expect("can create test memory region"); + scaffold.acc_mem = MemAccessor::new(map.memctx()); + + let bus = scaffold.create_bus(); + + // 64 MB feels like a reasonable (but very tiny!) size for a test + // disk. + // + // TODO: actually perform reads/writes against the test disk. At + // that point it probably makes sense to have more than one worker + // as well. + let backend = InMemoryBackend::create( + vec![0; 64 * MB], + BackendOpts { + block_size: Some(512), + read_only: Some(false), + skip_flush: Some(false), + }, + NonZeroUsize::new(1).unwrap(), + ) + .unwrap(); + + let nvme = PciNvme::create(Self::TEST_SERIAL, None, log.clone()); + + block::attach( + Arc::clone(&nvme) as Arc, + Arc::clone(&backend) as Arc, + ) + .unwrap(); + bus.attach( + Self::TEST_NVME_LOCATION, + Arc::clone(&nvme) as Arc, + None, + ); + + Self { + nvme, + + log: log.clone(), + scaffold, + bus, + + backend, + + available_cid: 0, + available_sqe_idx: 0, + } + } + + // I/O submission/completion queues are interleaved (for fun more than + // anything else). With 256kb of memory for queues we can have + // up to 64 I/O queues in the form of 32 submission and completion + // queues. + fn io_sq_address(i: u16) -> GuestAddr { + assert!(i < 32, "invalid I/O submission queue id"); + GuestAddr( + (Self::IO_QUEUES_BASE + i as usize * 2 * Self::IO_QUEUE_SIZE) + as u64, + ) + } + + fn io_cq_address(i: u16) -> GuestAddr { + assert!(i < 32, "invalid I/O completion queue id"); + GuestAddr( + (Self::IO_QUEUES_BASE + (i as usize * 2 + 1) * Self::IO_QUEUE_SIZE) + as u64, + ) + } + + // TODO: this is a wildly insufficient means for picking command IDs. + // This probably should be a list of available IDs with IDs picked off + // the front and returned when the operation completes. + fn next_cid(&mut self) -> u16 { + let result = self.available_cid; + + self.available_cid = self.available_cid + 1; + + // Wrap here; the highest value we should give out is 0xfffe. + // + // In the section `Submission Queue Entry`, the NVMe base + // specification suggests not using CID=FFFFh as that is the value + // used by the Error Information log page to indicate that an error + // is not associated with a particular command. + if self.available_cid == 0xffff { + self.available_cid = 0; + } + + result + } + + // TODO: also wildly insufficient queue management. This assumes there + // is exactly one admin queue operation in flight at a time, so we'll + // never run over the tail of the admin submission queue. + fn next_sqe_idx(&mut self) -> u16 { + let result = self.available_sqe_idx; + + self.available_sqe_idx = self.available_sqe_idx.wrapping_add(1); + + result + } + + // Do the steps to initialize the controller and set it running. + fn init_controller(&mut self) -> Result<(), NvmeError> { + let aqa = AdminQueueAttrs(0) + .with_asqs(Self::ADMIN_SQ_ENTRIES) + .with_acqs(Self::ADMIN_CQ_ENTRIES) + .0 + .to_le_bytes(); + + self.nvme.reg_ctrl_write( + &CtrlrReg::AdminQueueAttr, + &mut WriteOp::from_buf(0, &aqa), + )?; + + // `Machine::new_test` puts RAM at 1MB..2MB, so we'll put the submission queue at + // 1MB and the completion queue at 1Mib + 64KiB + self.nvme.reg_ctrl_write( + &CtrlrReg::AdminSubQAddr, + &mut WriteOp::from_buf(0, &Self::ADMIN_SQ_BASE.0.to_le_bytes()), + )?; + + self.nvme.reg_ctrl_write( + &CtrlrReg::AdminCompQAddr, + &mut WriteOp::from_buf(0, &Self::ADMIN_CQ_BASE.0.to_le_bytes()), + )?; + + let cfg = Configuration(0) + .with_enabled(true) + .with_iosqes(6) + .with_iocqes(4) + .0 + .to_le_bytes(); + + self.nvme.reg_ctrl_write( + &CtrlrReg::CtrlrCfg, + &mut WriteOp::from_buf(0, &cfg), + )?; + + self.available_cid = 0; + self.available_sqe_idx = 0; + + Ok(()) + } + + /// Write the provided `SubmissionQueueEntry` into the NVMe device's + /// admin SQ and ring the doorbell to force the SQE's evaluation. + fn drive_admin_sqe( + &mut self, + mut sqe: SubmissionQueueEntry, + ) -> Result<(), NvmeError> { + let cid = self.next_cid(); + let sq_idx = self.next_sqe_idx(); + + sqe.cdw0 |= (cid as u32) << 16; + + self.scaffold.acc_mem.access().unwrap().write( + Self::ADMIN_SQ_BASE + Self::SQE_SIZE * (sq_idx as usize), + &sqe, + ); + + // TODO: most accurately we should wait for a corresponding admin CQ + // entry with phase tag set. We might even wait to check that until + // an interrupt is fired. In practice, `reg_ctrl_write` evalues the + // admin command synchronously, so returning is sufficient to know + // processing is done. + let res = self.nvme.reg_ctrl_write( + &CtrlrReg::DoorBellAdminSQ, + &mut WriteOp::from_buf(0, &(sq_idx as u32 + 1).to_le_bytes()), + ); + + res + } + + fn create_cq(&mut self, cqid: u16) -> Result<(), NvmeError> { + let create_completion_queue = SubmissionQueueEntry { + cdw0: bits::ADMIN_OPC_CREATE_IO_CQ as u32, + cdw10: (Self::IO_QUEUE_ENTRIES as u32 - 1) << 16 | cqid as u32, + // IV 2, interrupts enabled, is physically contiguous + cdw11: 0x0002_0003, + prp1: Self::io_cq_address(cqid).0, + ..Default::default() + }; + + self.drive_admin_sqe(create_completion_queue) + } + + fn create_sq(&mut self, sqid: u16) -> Result<(), NvmeError> { + let create_submission_queue = SubmissionQueueEntry { + cdw0: bits::ADMIN_OPC_CREATE_IO_SQ as u32, + cdw10: (Self::IO_QUEUE_ENTRIES as u32 - 1) << 16 | sqid as u32, + // completions go to same-ID CQ, is physically contiguous + cdw11: ((sqid as u32) << 16) | 0x0001, + prp1: Self::io_sq_address(sqid).0, + ..Default::default() + }; + + self.drive_admin_sqe(create_submission_queue) + } + + fn delete_sq(&mut self, sqid: u16) -> Result<(), NvmeError> { + let delete_submission_queue = SubmissionQueueEntry { + cdw0: bits::ADMIN_OPC_DELETE_IO_SQ as u32, + cdw10: sqid as u32, + ..Default::default() + }; + + self.drive_admin_sqe(delete_submission_queue) + } + + fn delete_cq(&mut self, cqid: u16) -> Result<(), NvmeError> { + let delete_submission_queue = SubmissionQueueEntry { + cdw0: bits::ADMIN_OPC_DELETE_IO_CQ as u32, + cdw10: cqid as u32, + ..Default::default() + }; + + self.drive_admin_sqe(delete_submission_queue) + } + + /// Reset this fuzzing context to the start of the state machine: a + /// fresh device and at the start of the fuzzing state machine. + fn reset(&mut self) { + self.nvme.reset(); + self.available_cid = 0; + self.available_sqe_idx = 0; + } + + /// Migrate the emulated NVMe device. + /// + /// Concurrent operations on the device are blocked during "migration". + /// It is not possible to operate on a device whose state has been + /// exported, nor a fresh replacement device before state has been + /// imported. This is consistent with practical uses of devices, where + /// vCPUs are stopped while migrating out. + fn nvme_migrate(&mut self) { + let mut payload_outputs = PayloadOutputs::new(); + let acc_mem = self.scaffold.acc_mem.access().unwrap(); + let migrate_ctx = MigrateCtx { mem: &acc_mem }; + + self.nvme + .export(&mut payload_outputs, &migrate_ctx) + .expect("can export"); + + let mut data = Vec::new(); + let payload_outputs = payload_outputs.into_iter().collect::>(); + let mut desers: Vec = + Vec::with_capacity(payload_outputs.len()); + let mut metadata: Vec<(&str, u32)> = + Vec::with_capacity(payload_outputs.len()); + + let mut payload_offers = { + for payload in payload_outputs.iter() { + data.push( + ron::ser::to_string(&payload.payload) + .expect("can serialize"), + ); + } + for (payload, data) in payload_outputs.iter().zip(data.iter()) { + desers.push( + ron::Deserializer::from_str(data).expect("can deserialize"), + ); + metadata.push((&payload.kind, payload.version)); + } + let offer_iter = + metadata.iter().zip(desers.iter_mut()).map(|(meta, deser)| { + PayloadOffer { + kind: meta.0, + version: meta.1, + payload: Box::new( + ::erase(deser), + ), + } + }); + PayloadOffers::new(offer_iter) + }; + + self.nvme = PciNvme::create(Self::TEST_SERIAL, None, self.log.clone()); + + // TODO: we don't have a way to detach the exported NVMe device from + // the bus, so we'll replace the whole bus and attach the new NVMe + // device to the new bus. + self.bus = self.scaffold.create_bus(); + + self.backend.attachment().detach().unwrap(); + block::attach( + Arc::clone(&self.nvme) as Arc, + Arc::clone(&self.backend) as Arc, + ) + .unwrap(); + + self.bus.attach( + Self::TEST_NVME_LOCATION, + Arc::clone(&self.nvme) as Arc, + None, + ); + + self.nvme + .import(&mut payload_offers, &migrate_ctx) + .expect("can import"); + } +} + +// Probably-insufficient enum describing what we should expect for a given +// operation. +// +// It might be nice to include enough information to assert on specifics about +// what was ok, or what kind of error occurred. This is expected to be part of +// whatever function processes `TestAction`, below. +#[derive(Copy, Clone, Debug, PartialEq)] +enum Expected { + Ok, + Err, +} + +impl Expected { + fn check(&self, res: &Result<(), NvmeError>) { + match (self, res) { + (Expected::Ok, Ok(_)) | (Expected::Err, Err(_)) => { + // As expected, we can continue on. + } + (_, Ok(_)) => { + // This is rather unfortunate. If an admin command completed + // with an error in `process_admin_queue`, the error itself + // isn't propagated outward. We may have gotten an `Ok(())` even + // if the command was not successfully processed; we can't tell + // if it was the expected result or not. + } + (expected, actual) => { + panic!( + "Unexpected result: got {:?}, wanted {:?}", + actual, expected + ); + } + } + } +} + +impl TestAction { + fn ok(op: TestOperation) -> Self { + TestAction { op, result: Expected::Ok } + } + + // TODO: might be nice to test for specific kinds of error? Since + // different operations might error in different ways, this probably + // isn't sufficient for that kind of detail. + fn err(op: TestOperation) -> Self { + TestAction { op, result: Expected::Err } + } +} + +#[derive(Copy, Clone, Debug)] +enum TestOperation { + Reset, + Migrate, + Init, + CreateSQ(u16), + CreateCQ(u16), + DeleteSQ(u16), + DeleteCQ(u16), +} + +#[derive(Copy, Clone, Debug)] +struct TestAction { + op: TestOperation, + result: Expected, +} + +#[test] +fn fuzzy() -> Result<(), NvmeError> { + let log = Logger::root(Discard, slog::o!()); + + let mut fuzz_ctx = FuzzCtx::new(&log); + + /// Track expected device state so we take mostly-legal actions (and can + /// tell when we take illegal actions) + /// + /// This explicit split of "pick test actions" -> "execute test actions" + /// might be over-built. Hopefully makes it a little easier to plug into + /// cargo-fuzz and debug interesting execution. + struct TestState { + initialized: bool, + // Submission and completion queue arrays are 17 entries, but only 16 + // should ever be used. Queue ID 0 is for admin queues, and is fully + // unused here. + submission_queues: [bool; 17], + completion_queues: [bool; 17], + } + + impl TestState { + fn new() -> Self { + Self { + initialized: false, + submission_queues: [false; 17], + completion_queues: [false; 17], + } + } + + fn apply(&mut self, fuzz_ctx: &mut FuzzCtx, action: TestAction) { + match action.op { + TestOperation::Init => { + let res = fuzz_ctx.init_controller(); + + action.result.check(&res); + + if action.result == Expected::Ok { + self.initialized = true; + } + } + TestOperation::Migrate => { + fuzz_ctx.nvme_migrate(); + } + TestOperation::Reset => { + fuzz_ctx.reset(); + *self = TestState::new(); + } + TestOperation::CreateCQ(qid) => { + let res = fuzz_ctx.create_cq(qid); + + action.result.check(&res); + + if action.result == Expected::Ok { + self.completion_queues[qid as usize] = true; + } + } + TestOperation::CreateSQ(qid) => { + let res = fuzz_ctx.create_sq(qid); + + action.result.check(&res); + + if action.result == Expected::Ok { + self.submission_queues[qid as usize] = true; + } + } + TestOperation::DeleteCQ(qid) => { + let res = fuzz_ctx.delete_cq(qid); + + action.result.check(&res); + + if action.result == Expected::Ok { + self.completion_queues[qid as usize] = false; + } + } + TestOperation::DeleteSQ(qid) => { + let res = fuzz_ctx.delete_sq(qid); + + action.result.check(&res); + + if action.result == Expected::Ok { + self.submission_queues[qid as usize] = false; + } + } + } + } + + fn options(&self, rng: &mut impl Rng) -> Vec { + use TestOperation::*; + + // A migration is always allowed, and should never change device + // state. + let mut res = vec![TestAction::ok(Migrate)]; + + if rng.random_ratio(1, 10) { + // Reset is always allowed, at the cost of device state. Give + // this a relatively low chance so we have an opportunity to + // explore more interesting paths. + res.push(TestAction::ok(Reset)); + } + + // Pick an operation on one I/O queue pair because the 16 * 4 + // options across the whole slate deflates the odds we pick a valid + // action. + let qpid = rng.random_range(1..17); + + if !self.initialized { + // If we haven't initialized the controller yet, we can either + // do that or see operations on queues all fail. + res.push(TestAction::ok(Init)); + res.push(TestAction::err(CreateSQ(qpid))); + res.push(TestAction::err(CreateCQ(qpid))); + res.push(TestAction::err(DeleteSQ(qpid))); + res.push(TestAction::err(DeleteCQ(qpid))); + + return res; + } + + match ( + self.completion_queues[qpid as usize], + self.submission_queues[qpid as usize], + ) { + (false, false) => { + // Neither CQ nor SQ is created yet. Creating an SQ here + // will fail (for using an invalid CQ), creating a CQ + // here should succeed. + res.push(TestAction::ok(CreateCQ(qpid))); + res.push(TestAction::err(CreateSQ(qpid))); + res.push(TestAction::err(DeleteCQ(qpid))); + res.push(TestAction::err(DeleteSQ(qpid))); + } + (true, false) => { + res.push(TestAction::err(CreateCQ(qpid))); + res.push(TestAction::ok(CreateSQ(qpid))); + res.push(TestAction::ok(DeleteCQ(qpid))); + res.push(TestAction::err(DeleteSQ(qpid))); + } + (true, true) => { + res.push(TestAction::err(CreateCQ(qpid))); + res.push(TestAction::err(CreateSQ(qpid))); + res.push(TestAction::err(DeleteCQ(qpid))); + res.push(TestAction::ok(DeleteSQ(qpid))); + } + (false, true) => { + panic!("sq {} exists but cq does not?", qpid); + } + } + + res + } + } + + let mut test_state = TestState::new(); + + let seed = rand::random::(); + eprintln!("fuzzing nvme from seed {:#016x}", seed); + + let mut rng = Pcg64::seed_from_u64(seed); + + for _ in 0..1_000 { + let options = test_state.options(&mut rng); + let next = options[rng.random_range(0..options.len())]; + test_state.apply(&mut fuzz_ctx, next); + } + + Ok(()) +} From cb63659598794066af3a2420e3e4316752de8f50 Mon Sep 17 00:00:00 2001 From: iximeow Date: Tue, 28 Oct 2025 18:41:34 +0000 Subject: [PATCH 2/7] clippy... --- lib/propolis/src/hw/nvme/test.rs | 2 +- 1 file changed, 1 insertion(+), 1 deletion(-) diff --git a/lib/propolis/src/hw/nvme/test.rs b/lib/propolis/src/hw/nvme/test.rs index 68676ed81..ad2bbfc9a 100644 --- a/lib/propolis/src/hw/nvme/test.rs +++ b/lib/propolis/src/hw/nvme/test.rs @@ -83,7 +83,7 @@ impl FuzzCtx { const SQE_SIZE: usize = std::mem::size_of::(); const ADMIN_SQ_ENTRIES: u16 = 1024; - const ADMIN_SQ_BASE: GuestAddr = GuestAddr(1 * MB as u64); + const ADMIN_SQ_BASE: GuestAddr = GuestAddr(MB as u64); const ADMIN_SQ_SIZE: usize = Self::ADMIN_SQ_ENTRIES as usize * Self::SQE_SIZE; From 86c3c109f788d58ffc9c7750a52369f64c3b026e Mon Sep 17 00:00:00 2001 From: iximeow Date: Thu, 10 Sep 2026 18:47:23 +0000 Subject: [PATCH 3/7] temp --- lib/propolis/src/hw/nvme/test.rs | 4 ++++ 1 file changed, 4 insertions(+) diff --git a/lib/propolis/src/hw/nvme/test.rs b/lib/propolis/src/hw/nvme/test.rs index ad2bbfc9a..08b653904 100644 --- a/lib/propolis/src/hw/nvme/test.rs +++ b/lib/propolis/src/hw/nvme/test.rs @@ -467,6 +467,8 @@ enum TestOperation { CreateCQ(u16), DeleteSQ(u16), DeleteCQ(u16), + SubmitRead { queue: u16 }, + SubmitWrite { queue: u16 }, } #[derive(Copy, Clone, Debug)] @@ -493,6 +495,8 @@ fn fuzzy() -> Result<(), NvmeError> { // should ever be used. Queue ID 0 is for admin queues, and is fully // unused here. submission_queues: [bool; 17], + avail_ids: [Vec; 17], + outstanding_ids: [Bitmap<1024>; 17], completion_queues: [bool; 17], } From fb3fdfed8fca8a67d8795ff6d48d6cb6657b9f3e Mon Sep 17 00:00:00 2001 From: iximeow Date: Wed, 16 Sep 2026 16:44:36 +0000 Subject: [PATCH 4/7] close to nvme i/o submissions in fuzzer... --- lib/propolis/src/hw/nvme/test.rs | 232 +++++++++++++++++++++++++++---- 1 file changed, 202 insertions(+), 30 deletions(-) diff --git a/lib/propolis/src/hw/nvme/test.rs b/lib/propolis/src/hw/nvme/test.rs index 2ff2172ab..0c505eac2 100644 --- a/lib/propolis/src/hw/nvme/test.rs +++ b/lib/propolis/src/hw/nvme/test.rs @@ -8,12 +8,15 @@ use crate::hw::pci::{test::Scaffold, Bus, BusLocation, Endpoint}; use crate::migrate::{ MigrateCtx, MigrateMulti, PayloadOffer, PayloadOffers, PayloadOutputs, }; +use std::collection::HashMap; use std::num::NonZeroUsize; use std::sync::Arc; +use std::time::{Duration, SystemTime}; use crate::hw::nvme::{ + self, bits, AdminQueueAttrs, Configuration, CtrlrReg, GuestAddr, NvmeError, - PciNvme, SubmissionQueueEntry, WriteOp, + PciNvme, SubmissionQueueEntry, CompletionQueueEntry, WriteOp, }; use crate::vmm::PhysMap; @@ -327,6 +330,9 @@ impl FuzzCtx { self.drive_admin_sqe(delete_submission_queue) } + fn poll_cq(&mut self, cqid: u16) -> Result, NvmeError> { + } + /// Reset this fuzzing context to the start of the state machine: a /// fresh device and at the start of the fuzzing state machine. fn reset(&mut self) { @@ -467,8 +473,9 @@ enum TestOperation { CreateCQ(u16), DeleteSQ(u16), DeleteCQ(u16), - SubmitRead { queue: u16 }, - SubmitWrite { queue: u16 }, + SubmitRead { queue: u16, lba: u64, memptr: u64, size: u64, fresh_cid: bool }, + SubmitWrite { queue: u16, lba: u64, memptr: u64, size: u64, fresh_cid: bool }, + WaitIO { queue: u16, cid: u16 }, } #[derive(Copy, Clone, Debug)] @@ -492,6 +499,75 @@ fn fuzzy() -> Result<(), NvmeError> { let mut fuzz_ctx = FuzzCtx::new(&log); + struct TestIO { + /// The operation which resulted in this I/O + op: TestOperation, + /// The test device's corresponding CQE, to compare against the + /// requested operation and device state. + /// + /// If this is `None`, the test driver hasn't seen a completion from the + /// device yet. If this is `Some`, the test driver saw a completion and + /// stashed it here, but a specific WaitIO for this TestIO hasn't been + /// seen yet. + completion: Option, + } + + struct SqState { + avail_ids: Vec, + /// All I/Os which have been written to this submission queue and not + /// yet validated by the test driver yet. + /// + /// An I/O may have been written without ringing the submission queue's + /// doorbell, so the device may not even be aware of it yet. Conversely, + /// the I/O may have been completed by the device and that completion + /// even observed by the test driver, without removing the TestIO from + /// this map. + /// + /// I/Os are only "validated" at a WaitIO for that I/O, or at device + /// reset. + outstanding_ios: HashMap, + } + + impl SqState { + fn new() -> Self { + let mut avail_ids = Vec::new(); + // We don't include 0xffff here in deference to NVMe Base + // Specification (at least 2.0e), which says: + // + // > The value of FFFFh should not be used as the Error Information + // > log page (refer to section 5.16.1.2) uses this value to + // > indicate an error is not associated with a particular command. + for i in 0..=0xfffe { + avail_ids.push(i); + } + Self { + avail_ids, + outstanding_ios: HashMap::new() + } + } + } + + struct CqState { + /// The status of the Phase Tag to be seen in new completions written to + /// this queue. + phase: bool, + /// The last index we saw a completion on this completion queue. + next_cqe_idx: u16, + } + + impl CqState { + fn new() -> Self { + Self { + // > When .. an I/O Completion Queue for the first time after + // > the Create I/O Completion Queue command completed for that + // > queue, the Phase Tag bit for that completion queue entry is + // > set to 1 + phase: true, + next_cqe_idx: 0, + } + } + } + /// Track expected device state so we take mostly-legal actions (and can /// tell when we take illegal actions) /// @@ -500,22 +576,39 @@ fn fuzzy() -> Result<(), NvmeError> { /// cargo-fuzz and debug interesting execution. struct TestState { initialized: bool, - // Submission and completion queue arrays are 17 entries, but only 16 - // should ever be used. Queue ID 0 is for admin queues, and is fully - // unused here. - submission_queues: [bool; 17], - avail_ids: [Vec; 17], - outstanding_ids: [Bitmap<1024>; 17], - completion_queues: [bool; 17], + /// Submission and completion queue arrays are 17 entries, but only 16 + /// should ever be used. Queue ID 0 is for admin queues, and is fully + /// unused here. + submission_queues: Vec>, + completion_queues: Vec>, + /// The maximum number of queues the device supports (matching the size + /// of the Vecs, above) + max_queues: usize, + /// The number of bytes in the device's first namespace. This corresponds + /// to `IdentifyNamespace`'s `NUSE` times the namespace's LBA size. + ns_size: u64, } impl TestState { fn new() -> Self { - Self { + let mut this = Self { initialized: false, - submission_queues: [false; 17], - completion_queues: [false; 17], - } + submission_queues: Vec::new(), + completion_queues: Vec::new(), + // TODO: This should be read from the device under test, but + // just using the constant will do for now. + max_queues: nvme::MAX_NUM_QUEUES, + // TODO: Should read this from `IdentifyNamespace`, but the test + // backend is made right up there and it's a fixed size.. + ns_size: 64 * MB as u64, + }; + + // TODO: as with `max_queues` above, this should be read from the + // device under test, but it's all constants today. + this.submission_queues.resize_with(this.max_queues, || None); + this.completion_queues.resize_with(this.max_queues, || None); + + this } fn apply(&mut self, fuzz_ctx: &mut FuzzCtx, action: TestAction) { @@ -542,7 +635,7 @@ fn fuzzy() -> Result<(), NvmeError> { action.result.check(&res); if action.result == Expected::Ok { - self.completion_queues[qid as usize] = true; + self.completion_queues[qid as usize] = Some(CqState::new()); } } TestOperation::CreateSQ(qid) => { @@ -551,7 +644,7 @@ fn fuzzy() -> Result<(), NvmeError> { action.result.check(&res); if action.result == Expected::Ok { - self.submission_queues[qid as usize] = true; + self.submission_queues[qid as usize] = Some(SqState::new()); } } TestOperation::DeleteCQ(qid) => { @@ -560,7 +653,7 @@ fn fuzzy() -> Result<(), NvmeError> { action.result.check(&res); if action.result == Expected::Ok { - self.completion_queues[qid as usize] = false; + self.completion_queues[qid as usize] = None; } } TestOperation::DeleteSQ(qid) => { @@ -569,12 +662,78 @@ fn fuzzy() -> Result<(), NvmeError> { action.result.check(&res); if action.result == Expected::Ok { - self.submission_queues[qid as usize] = false; + self.submission_queues[qid as usize] = None; + } + } + TestOperation::SubmitRead { queue, lba, memptr, size, fresh_cid } => { + let command_id = if fresh_cid { + self.submission_queues[queue as usize].acquire_cid() + } else { + self.submission_queues[queue as usize].reuse_cid() + }; + let res = fuzz_ctx.submit_read(queue, lba, memptr, size, command_id); + + action.result.check(&res); + + if action.result != Expected::Ok { + self.submission_queues[queue as usize].release_cid(command_id); + } + } + TestOperation::SubmitWrite { queue, lba, memptr, size, fresh_cid } => { + let command_id = if fresh_cid { + self.submission_queues[queue as usize].acquire_cid() + } else { + self.submission_queues[queue as usize].reuse_cid() + }; + let res = fuzz_ctx.submit_write(queue, lba, memptr, size, command_id); + + action.result.check(&res); + + if action.result != Expected::Ok { + self.submission_queues[queue as usize].release_cid(command_id); + } + } + TestOperation::WaitIO { queue, cid } => { + let sq = self.submission_queues[queue as usize].as_mut() + .expect("WaitIO only issued for I/O queues that are fully established"); + // It is a fuzz harness error for a WaitIO to be issued for + // qid/cid that is not actually in flight. The I/O may have + // been completed, though, in which case there is a + // completion which we're about to process. + assert!(sq.outstanding_ios.contains_key(cid)); + + let deadline = SystemTime::now().checked_add(Duration::from_secs(1)) + .expect("time can go forward"); + + loop { + if let Some(completion) = sq.outstanding_ios[cid].completion.as_ref() { + // TODO: verify the I/O completion somehow? + action.result.check(&res); + sq.outstanding_ios.remove(cid); + } + + std::thread::sleep(Duration::from_millis(10)); + + for completion in fuzz_ctx.poll_cq(queue)? { + self.handle_completion(completion); + } } } } } + fn handle_completion(&mut self, completion: CompletionQueueEntry) { + let sq = &mut self.submission_queues[completion.sqid as usize]; + let io = sq.outstanding_ios[completion.cid].as_mut() + .expect("there is a submission for the completion");; + let prior_completion = io.completion.replace(completion); + + // If we've seen a completion for an I/O, we .. should not have seen + // that I/O be completed before! We won't submit a new SQE with this + // CID until we've WaitIO'd on the existing one. + assert!(prior_completion.is_none()); + } + fn options(&self, rng: &mut impl Rng) -> Vec { use TestOperation::*; @@ -582,7 +741,7 @@ fn fuzzy() -> Result<(), NvmeError> { // state. let mut res = vec![TestAction::ok(Migrate)]; - if rng.random_ratio(1, 10) { + if rng.random_ratio(1, 100) { // Reset is always allowed, at the cost of device state. Give // this a relatively low chance so we have an opportunity to // explore more interesting paths. @@ -592,7 +751,7 @@ fn fuzzy() -> Result<(), NvmeError> { // Pick an operation on one I/O queue pair because the 16 * 4 // options across the whole slate deflates the odds we pick a valid // action. - let qpid = rng.random_range(1..17); + let qpid = rng.random_range(1..self.max_queues as u16); if !self.initialized { // If we haven't initialized the controller yet, we can either @@ -607,10 +766,10 @@ fn fuzzy() -> Result<(), NvmeError> { } match ( - self.completion_queues[qpid as usize], - self.submission_queues[qpid as usize], + self.completion_queues[qpid as usize].as_ref(), + self.submission_queues[qpid as usize].as_ref(), ) { - (false, false) => { + (None, None) => { // Neither CQ nor SQ is created yet. Creating an SQ here // will fail (for using an invalid CQ), creating a CQ // here should succeed. @@ -619,19 +778,32 @@ fn fuzzy() -> Result<(), NvmeError> { res.push(TestAction::err(DeleteCQ(qpid))); res.push(TestAction::err(DeleteSQ(qpid))); } - (true, false) => { + (Some(_cq), None) => { res.push(TestAction::err(CreateCQ(qpid))); res.push(TestAction::ok(CreateSQ(qpid))); res.push(TestAction::ok(DeleteCQ(qpid))); res.push(TestAction::err(DeleteSQ(qpid))); } - (true, true) => { - res.push(TestAction::err(CreateCQ(qpid))); - res.push(TestAction::err(CreateSQ(qpid))); - res.push(TestAction::err(DeleteCQ(qpid))); - res.push(TestAction::ok(DeleteSQ(qpid))); + (Some(_cq), Some(_sq)) => { + if rng.random_ratio(2, 100) { + res.push(TestAction::err(CreateCQ(qpid))); + res.push(TestAction::err(CreateSQ(qpid))); + res.push(TestAction::err(DeleteCQ(qpid))); + res.push(TestAction::ok(DeleteSQ(qpid))); + } + + if rng.random_ratio(90, 10) { + // Post an I/O of some sort. + // .. the details are TODO: + /* + res.push(TestAction::ok( + SubmitRead { queue: u16, lba: u64, memptr: u64, size: u64, fresh_cid: bool }, + SubmitWrite { queue: u16, lba: u64, memptr: u64, size: u64, fresh_cid: bool }, + WaitIO { queue: u16, cid: u16 }, + */ + } } - (false, true) => { + (None, Some(_sq)) => { panic!("sq {} exists but cq does not?", qpid); } } From fd26034ac4544efc6f1f3cc792b0440f97e9088a Mon Sep 17 00:00:00 2001 From: iximeow Date: Sun, 20 Sep 2026 21:43:30 +0000 Subject: [PATCH 5/7] my terrible child comes to life i/os get processed, but for some reason it sometimes indicates too many sqes available, and cqes are incorrectly read twice? --- lib/propolis/src/hw/nvme/bits.rs | 4 +- lib/propolis/src/hw/nvme/mod.rs | 4 + lib/propolis/src/hw/nvme/queue.rs | 7 + lib/propolis/src/hw/nvme/test.rs | 467 ++++++++++++++++++++++-------- lib/propolis/src/util/bitmap.rs | 2 + 5 files changed, 362 insertions(+), 122 deletions(-) diff --git a/lib/propolis/src/hw/nvme/bits.rs b/lib/propolis/src/hw/nvme/bits.rs index 4860c969b..0f7f8efc9 100644 --- a/lib/propolis/src/hw/nvme/bits.rs +++ b/lib/propolis/src/hw/nvme/bits.rs @@ -11,7 +11,7 @@ use zerocopy::{FromBytes, IntoBytes}; /// A Submission Queue Entry as represented in memory. /// /// See NVMe 1.0e Section 4.2 Submission Queue Entry - Command Format -#[derive(Debug, Default, Copy, Clone, FromBytes)] +#[derive(Debug, Default, Copy, Clone, FromBytes, IntoBytes)] #[repr(C, packed(1))] pub struct SubmissionQueueEntry { /// Command Dword 0 (CDW0) @@ -106,7 +106,7 @@ impl SubmissionQueueEntry { /// A Completion Queue Entry as represented in memory. /// /// See NVMe 1.0e Section 4.5 Completion Queue Entry -#[derive(Debug, Default, Copy, Clone, IntoBytes)] +#[derive(Debug, Default, Copy, Clone, IntoBytes, FromBytes)] #[repr(C, packed(1))] pub struct CompletionQueueEntry { /// Dword 0 (DW0) diff --git a/lib/propolis/src/hw/nvme/mod.rs b/lib/propolis/src/hw/nvme/mod.rs index 31690e113..42809e6de 100644 --- a/lib/propolis/src/hw/nvme/mod.rs +++ b/lib/propolis/src/hw/nvme/mod.rs @@ -995,6 +995,7 @@ impl PciNvme { // Set CC.EN=1 and CSTS.RDY=1 state.ctrl.cc.set_enabled(true); state.ctrl.csts.set_ready(true); + eprintln!("controller enabled"); self.is_enabled.store(true, Ordering::Release); } } else if !new.enabled() && cur.enabled() { @@ -1196,6 +1197,7 @@ impl PciNvme { // Mix in the device ID for probe purposes let devq_id = devq_id(self.device_id, qid); + eprintln!("DEVICE: doorbell rung: {} (cq? {}) val={}", qid, is_cq, val); probes::nvme_doorbell!(|| ( off as u64, devq_id, @@ -1221,6 +1223,7 @@ impl PciNvme { self.log, "Doorbell write while controller is disabled" ); + eprintln!("how did it get disabled"); return Err(if is_cq { NvmeError::InvalidCompQueue(qid) } else { @@ -1461,6 +1464,7 @@ impl MigrateMulti for PciNvme { let mut ctrl = self.state.lock().unwrap(); ctrl.import(input, self)?; + self.is_enabled.store(ctrl.ctrl.cc.enabled(), Ordering::Release); drop(ctrl); MigrateMulti::import(&self.pci_state, offer, ctx)?; diff --git a/lib/propolis/src/hw/nvme/queue.rs b/lib/propolis/src/hw/nvme/queue.rs index 07ef2a005..532fa77b4 100644 --- a/lib/propolis/src/hw/nvme/queue.rs +++ b/lib/propolis/src/hw/nvme/queue.rs @@ -676,6 +676,9 @@ impl SubQueue { let devq_id = self.devq_id(); state.db_buf_write(devq_id, &mem); state.db_buf_read(devq_id, &mem); + if self.id != 0 { + eprintln!("DEVICE sqid={} got sqe: idx = {}", self.id, idx); + } return Some((ent, permit.promote(ent.cid()), idx)); } // TODO: set error state on queue/ctrl if we cannot read entry @@ -901,6 +904,10 @@ impl CompQueue { // TODO: mark the queue/controller in error state? return; }; + if self.id != 0 { + eprintln!("DEVICE cqid={}: writing cqe: idx = {}, cid = {}, addr={:x}", self.id, idx, cid, addr.0); + } + let mem = mem.view(); cqe.set_phase(!phase); mem.write(addr, &cqe); diff --git a/lib/propolis/src/hw/nvme/test.rs b/lib/propolis/src/hw/nvme/test.rs index 0c505eac2..5f68447cb 100644 --- a/lib/propolis/src/hw/nvme/test.rs +++ b/lib/propolis/src/hw/nvme/test.rs @@ -3,12 +3,12 @@ // file, You can obtain one at https://mozilla.org/MPL/2.0/. use crate::accessors::MemAccessor; -use crate::block::{self, Backend, BackendOpts, InMemoryBackend}; +use crate::block::{self, Backend, BackendOpts, Device, InMemoryBackend}; use crate::hw::pci::{test::Scaffold, Bus, BusLocation, Endpoint}; use crate::migrate::{ MigrateCtx, MigrateMulti, PayloadOffer, PayloadOffers, PayloadOutputs, }; -use std::collection::HashMap; +use std::collections::HashMap; use std::num::NonZeroUsize; use std::sync::Arc; use std::time::{Duration, SystemTime}; @@ -26,6 +26,7 @@ use crate::lifecycle::Lifecycle; use rand::{Rng, SeedableRng}; use rand_pcg::Pcg64; use slog::{Discard, Logger}; +use tokio::runtime; const MB: usize = 1024 * 1024; @@ -76,6 +77,153 @@ struct FuzzCtx { available_sqe_idx: u16, } +struct SqState { + size: u16, + next_id: u16, + base_addr: GuestAddr, + // TODO: phase tag on sqe too? I forget + + avail_ids: Vec, + /// All I/Os which have been written to this submission queue and not + /// yet validated by the test driver yet. + /// + /// An I/O may have been written without ringing the submission queue's + /// doorbell, so the device may not even be aware of it yet. Conversely, + /// the I/O may have been completed by the device and that completion + /// even observed by the test driver, without removing the TestIO from + /// this map. + /// + /// I/Os are only "validated" at a WaitIO for that I/O, or at device + /// reset. + outstanding_ios: HashMap, +} + +impl SqState { + fn new(base_addr: GuestAddr) -> Self { + let mut avail_ids = Vec::new(); + // We don't include 0xffff here in deference to NVMe Base + // Specification (at least 2.0e), which says: + // + // > The value of FFFFh should not be used as the Error Information + // > log page (refer to section 5.16.1.2) uses this value to + // > indicate an error is not associated with a particular command. + for i in 0..=0xfffe { + avail_ids.push(i); + } + Self { + size: FuzzCtx::IO_QUEUE_ENTRIES, + next_id: 0, + base_addr, + avail_ids, + outstanding_ios: HashMap::new() + } + } + + fn write_sqe(&mut self, sqe: SubmissionQueueEntry, acc_mem: &MemAccessor) { + let sqe_size = std::mem::size_of::(); + let next_addr = GuestAddr(self.base_addr.0 + self.next_id as u64 * sqe_size as u64); + eprintln!("writing sqe to sq slot {}, addr {:x}", self.next_id, next_addr.0); + + acc_mem.access().unwrap().write( + next_addr, + &sqe, + ); + + self.next_id += 1; + if self.next_id == self.size { + self.next_id = 0; + } + } + + fn curr_idx(&self) -> u16 { + if self.next_id == 0 { + 0xffff + } else { + self.next_id - 1 + } + } + + fn full(&self) -> bool { + self.outstanding_ios.len() as u16 == self.size + } + + fn empty(&self) -> bool { + self.outstanding_ios.len() as u16 == 0 + } + + fn acquire_cid(&mut self) -> Option { + self.avail_ids.pop() + } + fn outstanding_cid(&self) -> Option { + self.outstanding_ios.keys().next().copied() + } + fn release_cid(&mut self, id: u16) { + self.outstanding_ios.remove(&id); + } +} + +struct CqState { + base_addr: GuestAddr, + size: u16, + /// The status of the Phase Tag to be seen in new completions written to + /// this queue. + phase: bool, + /// The last index we saw a completion on this completion queue. + next_id: u16, +} + +impl CqState { + fn new(base_addr: GuestAddr) -> Self { + Self { + base_addr, + size: FuzzCtx::IO_QUEUE_ENTRIES, + // > When .. an I/O Completion Queue for the first time after + // > the Create I/O Completion Queue command completed for that + // > queue, the Phase Tag bit for that completion queue entry is + // > set to 1 + phase: true, + next_id: 0, + } + } + + fn poll_cqe(&mut self, acc_mem: &MemAccessor) -> Option { + let cqe_size = std::mem::size_of::(); + let next_addr = GuestAddr(self.base_addr.0 + self.next_id as u64 * cqe_size as u64); + eprintln!("reading cqe from cq slot {}, addr {:x}", self.next_id, next_addr.0); + + let cqe = acc_mem.access().unwrap().read::( + next_addr, + ).expect("can read cqe address"); + + let cqe_phase = cqe.status_phase & 1 == 1; + eprintln!("got cqe: {:?}", *cqe); + if cqe_phase != self.phase { + return None; + } + + self.next_id += 1; + if self.next_id == self.size { + self.next_id = 0; + self.phase = !self.phase; + } + + Some(*cqe) + } +} + +struct TestIO { + /// The operation which resulted in this I/O + op: TestOperation, + /// The test device's corresponding CQE, to compare against the + /// requested operation and device state. + /// + /// If this is `None`, the test driver hasn't seen a completion from the + /// device yet. If this is `Some`, the test driver saw a completion and + /// stashed it here, but a specific WaitIO for this TestIO hasn't been + /// seen yet. + completion: Option, +} + impl FuzzCtx { /// Arbitrary 20-byte serial. const TEST_SERIAL: &'static [u8; 20] = b"11112222333344445555"; @@ -103,6 +251,9 @@ impl FuzzCtx { const IO_QUEUE_SIZE: usize = Self::SQE_SIZE * (Self::IO_QUEUE_ENTRIES as usize); + const IO_MEM_BASE: usize = 1 * MB; + const IO_MEM_END: usize = 1 * MB + 512 * 1024; + fn new(log: &Logger) -> Self { let mut scaffold = Scaffold::new(); @@ -112,7 +263,7 @@ impl FuzzCtx { // Test RAM starts at 1 MB and is 1 MB large. map.add_test_mem("test-ram".to_string(), MB, MB) .expect("can create test memory region"); - scaffold.acc_mem = MemAccessor::new(map.memctx()); + scaffold.acc_mem = map.finalize(); let bus = scaffold.create_bus(); @@ -133,11 +284,11 @@ impl FuzzCtx { ) .unwrap(); - let nvme = PciNvme::create(Self::TEST_SERIAL, None, log.clone()); + let nvme = PciNvme::create(Self::TEST_SERIAL, None, true, log.clone()); block::attach( - Arc::clone(&nvme) as Arc, - Arc::clone(&backend) as Arc, + nvme.attachment(), + backend.attachment(), ) .unwrap(); bus.attach( @@ -146,6 +297,11 @@ impl FuzzCtx { None, ); + nvme.start().unwrap(); + use tokio::runtime; + let rt = runtime::Builder::new_current_thread().build().unwrap(); + rt.block_on(&mut (backend.clone() as Arc).start()).unwrap(); + Self { nvme, @@ -249,6 +405,14 @@ impl FuzzCtx { &mut WriteOp::from_buf(0, &cfg), )?; + use crate::hw::nvme::ReadOp; + use crate::hw::nvme::CtrlrReg; + let mut buf = [0; 4]; + let mut read_op = ReadOp::from_buf(0, &mut buf); + self.nvme.reg_ctrl_read(&CtrlrReg::CtrlrStatus, &mut read_op)?; + eprintln!("{:x?}", buf); + assert!(buf[0] & 2 == 0); + self.available_cid = 0; self.available_sqe_idx = 0; @@ -330,7 +494,62 @@ impl FuzzCtx { self.drive_admin_sqe(delete_submission_queue) } - fn poll_cq(&mut self, cqid: u16) -> Result, NvmeError> { + fn doorbell(&mut self, qid: u16, sq_idx: u16) -> Result<(), NvmeError> { + let doorbell_addr = 0x1000 + ((qid as usize) << 3); + eprintln!("doorbell! to {:x}, val={}", qid, sq_idx); + let res = self.nvme.reg_ctrl_write( + &CtrlrReg::IOQueueDoorBells, + &mut WriteOp::from_buf(doorbell_addr, &(sq_idx as u32 + 1).to_le_bytes()), + ); + res + } + + fn submit_read(&mut self, sq: &mut SqState, lba: u64, memptr: usize, len: u64, cid: u16) -> Result<(), NvmeError> { + let lba_lo = lba as u32; + let lba_hi = (lba >> 32) as u32; + let nlb = len / 4096; + let cdw0 = (bits::NVM_OPC_READ as u32) | ((cid as u32) << 16); + let sqe = SubmissionQueueEntry { + cdw0, + cdw10: lba_lo, + cdw11: lba_hi, + cdw12: nlb as u32 - 1, + prp1: memptr as u64, + prp2: 0, + ..Default::default() + }; + + sq.write_sqe(sqe, &self.scaffold.acc_mem); + + Ok(()) + } + + fn submit_write(&mut self, sq: &mut SqState, lba: u64, memptr: usize, len: u64, cid: u16) -> Result<(), NvmeError> { + let lba_lo = lba as u32; + let lba_hi = (lba >> 32) as u32; + let nlb = len / 4096; + let cdw0 = (bits::NVM_OPC_WRITE as u32) | ((cid as u32) << 16); + let sqe = SubmissionQueueEntry { + cdw0, + cdw10: lba_lo, + cdw11: lba_hi, + cdw12: nlb as u32 - 1, + prp1: memptr as u64, + prp2: 0, + ..Default::default() + }; + + sq.write_sqe(sqe, &self.scaffold.acc_mem); + + Ok(()) + } + + fn poll_cq(&mut self, cq: &mut CqState) -> Result, NvmeError> { + let mut cqes = Vec::new(); + if let Some(cqe) = cq.poll_cqe(&self.scaffold.acc_mem) { + cqes.push(cqe) + } + Ok(cqes) } /// Reset this fuzzing context to the start of the state machine: a @@ -349,6 +568,10 @@ impl FuzzCtx { /// imported. This is consistent with practical uses of devices, where /// vCPUs are stopped while migrating out. fn nvme_migrate(&mut self) { + self.nvme.pause(); + let rt = runtime::Builder::new_current_thread().build().unwrap(); + rt.block_on(&mut (self.backend.clone() as Arc).stop()); + let mut payload_outputs = PayloadOutputs::new(); let acc_mem = self.scaffold.acc_mem.access().unwrap(); let migrate_ctx = MigrateCtx { mem: &acc_mem }; @@ -390,17 +613,17 @@ impl FuzzCtx { PayloadOffers::new(offer_iter) }; - self.nvme = PciNvme::create(Self::TEST_SERIAL, None, self.log.clone()); + self.nvme = PciNvme::create(Self::TEST_SERIAL, None, true, self.log.clone()); // TODO: we don't have a way to detach the exported NVMe device from // the bus, so we'll replace the whole bus and attach the new NVMe // device to the new bus. self.bus = self.scaffold.create_bus(); - self.backend.attachment().detach().unwrap(); + self.backend.attachment().detach(); block::attach( - Arc::clone(&self.nvme) as Arc, - Arc::clone(&self.backend) as Arc, + self.nvme.attachment(), + self.backend.attachment(), ) .unwrap(); @@ -413,6 +636,10 @@ impl FuzzCtx { self.nvme .import(&mut payload_offers, &migrate_ctx) .expect("can import"); + + self.nvme.start().unwrap(); + let rt = runtime::Builder::new_current_thread().build().unwrap(); + rt.block_on(&mut (self.backend.clone() as Arc).start()).unwrap(); } } @@ -473,8 +700,9 @@ enum TestOperation { CreateCQ(u16), DeleteSQ(u16), DeleteCQ(u16), - SubmitRead { queue: u16, lba: u64, memptr: u64, size: u64, fresh_cid: bool }, - SubmitWrite { queue: u16, lba: u64, memptr: u64, size: u64, fresh_cid: bool }, + Doorbell(u16), + SubmitRead { queue: u16, lba: u64, memptr: usize, size: u64, fresh_cid: bool }, + SubmitWrite { queue: u16, lba: u64, memptr: usize, size: u64, fresh_cid: bool }, WaitIO { queue: u16, cid: u16 }, } @@ -484,90 +712,12 @@ struct TestAction { result: Expected, } -/// The bitmap of outstanding requests on an NVMe submission queue. -/// -/// Each bit corresponds to possible Command IDs used in SQEs for submitted -/// operations, hence the map is sized for at least 65536 bits. -// -// `GenericBitmap` is parameterized on a number of u64 bitmap words, hence -// `65536 / 64 == 1024` as the parameter here. -struct CidBitmap(GenericBitmap<1024>); - #[test] fn fuzzy() -> Result<(), NvmeError> { let log = Logger::root(Discard, slog::o!()); let mut fuzz_ctx = FuzzCtx::new(&log); - struct TestIO { - /// The operation which resulted in this I/O - op: TestOperation, - /// The test device's corresponding CQE, to compare against the - /// requested operation and device state. - /// - /// If this is `None`, the test driver hasn't seen a completion from the - /// device yet. If this is `Some`, the test driver saw a completion and - /// stashed it here, but a specific WaitIO for this TestIO hasn't been - /// seen yet. - completion: Option, - } - - struct SqState { - avail_ids: Vec, - /// All I/Os which have been written to this submission queue and not - /// yet validated by the test driver yet. - /// - /// An I/O may have been written without ringing the submission queue's - /// doorbell, so the device may not even be aware of it yet. Conversely, - /// the I/O may have been completed by the device and that completion - /// even observed by the test driver, without removing the TestIO from - /// this map. - /// - /// I/Os are only "validated" at a WaitIO for that I/O, or at device - /// reset. - outstanding_ios: HashMap, - } - - impl SqState { - fn new() -> Self { - let mut avail_ids = Vec::new(); - // We don't include 0xffff here in deference to NVMe Base - // Specification (at least 2.0e), which says: - // - // > The value of FFFFh should not be used as the Error Information - // > log page (refer to section 5.16.1.2) uses this value to - // > indicate an error is not associated with a particular command. - for i in 0..=0xfffe { - avail_ids.push(i); - } - Self { - avail_ids, - outstanding_ios: HashMap::new() - } - } - } - - struct CqState { - /// The status of the Phase Tag to be seen in new completions written to - /// this queue. - phase: bool, - /// The last index we saw a completion on this completion queue. - next_cqe_idx: u16, - } - - impl CqState { - fn new() -> Self { - Self { - // > When .. an I/O Completion Queue for the first time after - // > the Create I/O Completion Queue command completed for that - // > queue, the Phase Tag bit for that completion queue entry is - // > set to 1 - phase: true, - next_cqe_idx: 0, - } - } - } - /// Track expected device state so we take mostly-legal actions (and can /// tell when we take illegal actions) /// @@ -597,7 +747,7 @@ fn fuzzy() -> Result<(), NvmeError> { completion_queues: Vec::new(), // TODO: This should be read from the device under test, but // just using the constant will do for now. - max_queues: nvme::MAX_NUM_QUEUES, + max_queues: 2, //nvme::MAX_NUM_QUEUES, // TODO: Should read this from `IdentifyNamespace`, but the test // backend is made right up there and it's a fixed size.. ns_size: 64 * MB as u64, @@ -614,6 +764,7 @@ fn fuzzy() -> Result<(), NvmeError> { fn apply(&mut self, fuzz_ctx: &mut FuzzCtx, action: TestAction) { match action.op { TestOperation::Init => { + eprintln!("doing init!"); let res = fuzz_ctx.init_controller(); action.result.check(&res); @@ -627,6 +778,7 @@ fn fuzzy() -> Result<(), NvmeError> { } TestOperation::Reset => { fuzz_ctx.reset(); + eprintln!("TestOperation::Reset"); *self = TestState::new(); } TestOperation::CreateCQ(qid) => { @@ -635,7 +787,9 @@ fn fuzzy() -> Result<(), NvmeError> { action.result.check(&res); if action.result == Expected::Ok { - self.completion_queues[qid as usize] = Some(CqState::new()); + let cq_addr = FuzzCtx::io_cq_address(qid); + + self.completion_queues[qid as usize] = Some(CqState::new(cq_addr)); } } TestOperation::CreateSQ(qid) => { @@ -644,7 +798,9 @@ fn fuzzy() -> Result<(), NvmeError> { action.result.check(&res); if action.result == Expected::Ok { - self.submission_queues[qid as usize] = Some(SqState::new()); + let sq_addr = FuzzCtx::io_sq_address(qid); + + self.submission_queues[qid as usize] = Some(SqState::new(sq_addr)); } } TestOperation::DeleteCQ(qid) => { @@ -665,56 +821,105 @@ fn fuzzy() -> Result<(), NvmeError> { self.submission_queues[qid as usize] = None; } } + TestOperation::Doorbell(qid) => { + let sq = self.submission_queues[qid as usize].as_ref() + .expect("only ringing doorbell on queues that exist"); + + assert!(self.initialized); + + let res = fuzz_ctx.doorbell(qid, sq.curr_idx()); + + action.result.check(&res); + + if action.result == Expected::Ok { + self.submission_queues[qid as usize] = None; + } + } TestOperation::SubmitRead { queue, lba, memptr, size, fresh_cid } => { + let sq = self.submission_queues[queue as usize].as_mut() + .expect("sq exists when we submit writes"); let command_id = if fresh_cid { - self.submission_queues[queue as usize].acquire_cid() + sq.acquire_cid() + .expect("planner made sure a CID is available to acquire") } else { - self.submission_queues[queue as usize].reuse_cid() + sq.outstanding_cid() + .expect("planner made sure a CID is present to reuse") }; - let res = fuzz_ctx.submit_read(queue, lba, memptr, size, command_id); + eprintln!("submitting read {} q={}, mem={:x} lba={}", queue, command_id, memptr, lba); + let res = fuzz_ctx.submit_read(sq, lba, memptr, size, command_id); + + sq.outstanding_ios.insert(command_id, TestIO { op: action.op, completion: None }); action.result.check(&res); if action.result != Expected::Ok { - self.submission_queues[queue as usize].release_cid(command_id); + let sq = self.submission_queues[queue as usize].as_mut() + .expect("sqid exists to release unused cid"); + sq.release_cid(command_id); } } TestOperation::SubmitWrite { queue, lba, memptr, size, fresh_cid } => { + let sq = self.submission_queues[queue as usize].as_mut() + .expect("sq exists when we submit writes"); let command_id = if fresh_cid { - self.submission_queues[queue as usize].acquire_cid() + sq.acquire_cid() + .expect("planner made sure a CID is available to acquire") } else { - self.submission_queues[queue as usize].reuse_cid() + sq.outstanding_cid() + .expect("planner made sure a CID is present to reuse") }; - let res = fuzz_ctx.submit_write(queue, lba, memptr, size, command_id); + eprintln!("submitting write {} q={}, mem={:x} lba={}", queue, command_id, memptr, lba); + let res = fuzz_ctx.submit_write(sq, lba, memptr, size, command_id); + + sq.outstanding_ios.insert(command_id, TestIO { op: action.op, completion: None }); action.result.check(&res); if action.result != Expected::Ok { - self.submission_queues[queue as usize].release_cid(command_id); + let sq = self.submission_queues[queue as usize].as_mut() + .expect("sqid exists to release unused cid"); + sq.release_cid(command_id); } } TestOperation::WaitIO { queue, cid } => { let sq = self.submission_queues[queue as usize].as_mut() .expect("WaitIO only issued for I/O queues that are fully established"); + // It is a fuzz harness error for a WaitIO to be issued for // qid/cid that is not actually in flight. The I/O may have // been completed, though, in which case there is a // completion which we're about to process. - assert!(sq.outstanding_ios.contains_key(cid)); + assert!(sq.outstanding_ios.contains_key(&cid)); + + fuzz_ctx.doorbell(queue, sq.curr_idx()) + .expect("doorbell"); let deadline = SystemTime::now().checked_add(Duration::from_secs(1)) .expect("time can go forward"); loop { - if let Some(completion) = sq.outstanding_ios[cid].completion.as_ref() { + let sq = self.submission_queues[queue as usize].as_mut() + .expect("WaitIO only issued for I/O queues that are fully established"); + + if let Some(completion) = sq.outstanding_ios[&cid].completion.as_ref() { // TODO: verify the I/O completion somehow? - action.result.check(&res); - sq.outstanding_ios.remove(cid); + action.result.check(&Ok(())); + eprintln!("DONE with I/O {} on queue {}", cid, queue); + sq.outstanding_ios.remove(&cid); + break; } std::thread::sleep(Duration::from_millis(10)); - for completion in fuzz_ctx.poll_cq(queue)? { + if SystemTime::now() > deadline { + panic!("i/o never happened"); + } + + let cq = self.completion_queues[queue as usize].as_mut() + .expect("WaitIO only issued for I/O queues that are fully established"); + + for completion in fuzz_ctx.poll_cq(cq).expect("can poll cq") { + eprintln!("new completion: {:?}", completion); self.handle_completion(completion); } } @@ -723,9 +928,11 @@ fn fuzzy() -> Result<(), NvmeError> { } fn handle_completion(&mut self, completion: CompletionQueueEntry) { - let sq = &mut self.submission_queues[completion.sqid as usize]; - let io = sq.outstanding_ios[completion.cid].as_mut() - .expect("there is a submission for the completion");; + let sq = self.submission_queues[completion.sqid as usize] + .as_mut().expect("completion implies there is an sq"); + let cid = completion.cid; + let io = sq.outstanding_ios.get_mut(&cid) + .expect("there is a submission for the completion"); let prior_completion = io.completion.replace(completion); // If we've seen a completion for an I/O, we .. should not have seen @@ -784,7 +991,7 @@ fn fuzzy() -> Result<(), NvmeError> { res.push(TestAction::ok(DeleteCQ(qpid))); res.push(TestAction::err(DeleteSQ(qpid))); } - (Some(_cq), Some(_sq)) => { + (Some(_cq), Some(sq)) => { if rng.random_ratio(2, 100) { res.push(TestAction::err(CreateCQ(qpid))); res.push(TestAction::err(CreateSQ(qpid))); @@ -792,15 +999,34 @@ fn fuzzy() -> Result<(), NvmeError> { res.push(TestAction::ok(DeleteSQ(qpid))); } - if rng.random_ratio(90, 10) { - // Post an I/O of some sort. - // .. the details are TODO: - /* - res.push(TestAction::ok( - SubmitRead { queue: u16, lba: u64, memptr: u64, size: u64, fresh_cid: bool }, - SubmitWrite { queue: u16, lba: u64, memptr: u64, size: u64, fresh_cid: bool }, - WaitIO { queue: u16, cid: u16 }, - */ + if rng.random_ratio(90, 100) { + let lba = rng.random_range(0..self.ns_size) / 4096; + let io_addr = FuzzCtx::IO_MEM_BASE + rng.random_range(0..128usize) * 4096; + + if !sq.full() { + // TODO: different I/O sizes + res.push(TestAction::ok(SubmitRead { + queue: qpid, + lba, + memptr: io_addr, + size: 4096, + fresh_cid: true, + })); + res.push(TestAction::ok(SubmitWrite { + queue: qpid, + lba, + memptr: io_addr, + size: 4096, + fresh_cid: true, + })); + } + if let Some(pending_cid) = sq.outstanding_cid() { + res.push(TestAction::ok(WaitIO { queue: qpid, cid: pending_cid })); + } + } + + if !sq.empty() { + res.push(TestAction::ok(Doorbell(qpid))); } } (None, Some(_sq)) => { @@ -822,6 +1048,7 @@ fn fuzzy() -> Result<(), NvmeError> { for _ in 0..1_000 { let options = test_state.options(&mut rng); let next = options[rng.random_range(0..options.len())]; +// eprintln!("operation: {:?}", next); test_state.apply(&mut fuzz_ctx, next); } diff --git a/lib/propolis/src/util/bitmap.rs b/lib/propolis/src/util/bitmap.rs index 1949b5c81..c6af766d3 100644 --- a/lib/propolis/src/util/bitmap.rs +++ b/lib/propolis/src/util/bitmap.rs @@ -2,6 +2,8 @@ // License, v. 2.0. If a copy of the MPL was not distributed with this // file, You can obtain one at https://mozilla.org/MPL/2.0/. +#![allow(dead_code)] + impl Default for Bitmap { fn default() -> Self { Bitmap(GenericBitmap([0u64; 1])) From 9556ec3177188216217b528d1ecb51b33449c736 Mon Sep 17 00:00:00 2001 From: iximeow Date: Tue, 22 Sep 2026 04:33:50 +0000 Subject: [PATCH 6/7] now that's a bogus bit of code --- lib/propolis/src/hw/nvme/test.rs | 4 ---- 1 file changed, 4 deletions(-) diff --git a/lib/propolis/src/hw/nvme/test.rs b/lib/propolis/src/hw/nvme/test.rs index 5f68447cb..e755aec5e 100644 --- a/lib/propolis/src/hw/nvme/test.rs +++ b/lib/propolis/src/hw/nvme/test.rs @@ -830,10 +830,6 @@ fn fuzzy() -> Result<(), NvmeError> { let res = fuzz_ctx.doorbell(qid, sq.curr_idx()); action.result.check(&res); - - if action.result == Expected::Ok { - self.submission_queues[qid as usize] = None; - } } TestOperation::SubmitRead { queue, lba, memptr, size, fresh_cid } => { let sq = self.submission_queues[queue as usize].as_mut() From d688559485159cd2184942cb6ec01cefa625c947 Mon Sep 17 00:00:00 2001 From: iximeow Date: Tue, 22 Sep 2026 22:41:10 +0000 Subject: [PATCH 7/7] omg it finds the bug! --- lib/propolis/src/hw/nvme/mod.rs | 2 +- lib/propolis/src/hw/nvme/queue.rs | 4 +- lib/propolis/src/hw/nvme/test.rs | 102 ++++++++++++++++++++++-------- 3 files changed, 80 insertions(+), 28 deletions(-) diff --git a/lib/propolis/src/hw/nvme/mod.rs b/lib/propolis/src/hw/nvme/mod.rs index 42809e6de..b5afae6df 100644 --- a/lib/propolis/src/hw/nvme/mod.rs +++ b/lib/propolis/src/hw/nvme/mod.rs @@ -1197,7 +1197,7 @@ impl PciNvme { // Mix in the device ID for probe purposes let devq_id = devq_id(self.device_id, qid); - eprintln!("DEVICE: doorbell rung: {} (cq? {}) val={}", qid, is_cq, val); +// eprintln!("DEVICE: doorbell rung: {} (cq? {}) val={}", qid, is_cq, val); probes::nvme_doorbell!(|| ( off as u64, devq_id, diff --git a/lib/propolis/src/hw/nvme/queue.rs b/lib/propolis/src/hw/nvme/queue.rs index 532fa77b4..6434c5403 100644 --- a/lib/propolis/src/hw/nvme/queue.rs +++ b/lib/propolis/src/hw/nvme/queue.rs @@ -677,7 +677,7 @@ impl SubQueue { state.db_buf_write(devq_id, &mem); state.db_buf_read(devq_id, &mem); if self.id != 0 { - eprintln!("DEVICE sqid={} got sqe: idx = {}", self.id, idx); +// eprintln!("DEVICE sqid={} got sqe: idx = {}", self.id, idx); } return Some((ent, permit.promote(ent.cid()), idx)); } @@ -905,7 +905,7 @@ impl CompQueue { return; }; if self.id != 0 { - eprintln!("DEVICE cqid={}: writing cqe: idx = {}, cid = {}, addr={:x}", self.id, idx, cid, addr.0); +// eprintln!("DEVICE cqid={}: writing cqe: idx = {}, cid = {}, addr={:x}", self.id, idx, cid, addr.0); } let mem = mem.view(); diff --git a/lib/propolis/src/hw/nvme/test.rs b/lib/propolis/src/hw/nvme/test.rs index e755aec5e..2e6b6b719 100644 --- a/lib/propolis/src/hw/nvme/test.rs +++ b/lib/propolis/src/hw/nvme/test.rs @@ -8,7 +8,7 @@ use crate::hw::pci::{test::Scaffold, Bus, BusLocation, Endpoint}; use crate::migrate::{ MigrateCtx, MigrateMulti, PayloadOffer, PayloadOffers, PayloadOutputs, }; -use std::collections::HashMap; +use std::collections::BTreeMap; use std::num::NonZeroUsize; use std::sync::Arc; use std::time::{Duration, SystemTime}; @@ -95,7 +95,7 @@ struct SqState { /// /// I/Os are only "validated" at a WaitIO for that I/O, or at device /// reset. - outstanding_ios: HashMap, + outstanding_ios: BTreeMap, } impl SqState { @@ -115,14 +115,14 @@ impl SqState { next_id: 0, base_addr, avail_ids, - outstanding_ios: HashMap::new() + outstanding_ios: BTreeMap::new() } } fn write_sqe(&mut self, sqe: SubmissionQueueEntry, acc_mem: &MemAccessor) { let sqe_size = std::mem::size_of::(); let next_addr = GuestAddr(self.base_addr.0 + self.next_id as u64 * sqe_size as u64); - eprintln!("writing sqe to sq slot {}, addr {:x}", self.next_id, next_addr.0); +// eprintln!("writing sqe to sq slot {}, addr {:x}", self.next_id, next_addr.0); acc_mem.access().unwrap().write( next_addr, @@ -163,6 +163,7 @@ impl SqState { } struct CqState { + qid: u16, base_addr: GuestAddr, size: u16, /// The status of the Phase Tag to be seen in new completions written to @@ -173,8 +174,9 @@ struct CqState { } impl CqState { - fn new(base_addr: GuestAddr) -> Self { + fn new(qid: u16, base_addr: GuestAddr) -> Self { Self { + qid, base_addr, size: FuzzCtx::IO_QUEUE_ENTRIES, // > When .. an I/O Completion Queue for the first time after @@ -280,7 +282,7 @@ impl FuzzCtx { read_only: Some(false), skip_flush: Some(false), }, - NonZeroUsize::new(1).unwrap(), + NonZeroUsize::new(16).unwrap(), ) .unwrap(); @@ -445,6 +447,8 @@ impl FuzzCtx { &mut WriteOp::from_buf(0, &(sq_idx as u32 + 1).to_le_bytes()), ); +// eprintln!("driving admin op (id = {}), res={:?}", sq_idx, res); + res } @@ -471,6 +475,8 @@ impl FuzzCtx { ..Default::default() }; + eprintln!("creating sq {}", sqid); + self.drive_admin_sqe(create_submission_queue) } @@ -494,9 +500,9 @@ impl FuzzCtx { self.drive_admin_sqe(delete_submission_queue) } - fn doorbell(&mut self, qid: u16, sq_idx: u16) -> Result<(), NvmeError> { + fn sq_doorbell(&mut self, qid: u16, sq_idx: u16) -> Result<(), NvmeError> { let doorbell_addr = 0x1000 + ((qid as usize) << 3); - eprintln!("doorbell! to {:x}, val={}", qid, sq_idx); +// eprintln!("sq doorbell! to {:x}, val={}", qid, sq_idx); let res = self.nvme.reg_ctrl_write( &CtrlrReg::IOQueueDoorBells, &mut WriteOp::from_buf(doorbell_addr, &(sq_idx as u32 + 1).to_le_bytes()), @@ -504,6 +510,16 @@ impl FuzzCtx { res } + fn cq_doorbell(&mut self, qid: u16, cq_idx: u16) -> Result<(), NvmeError> { + let doorbell_addr = 0x1000 + ((qid as usize) << 3) + 4; +// eprintln!("cq doorbell! to {:x}, val={}", qid, cq_idx); + let res = self.nvme.reg_ctrl_write( + &CtrlrReg::IOQueueDoorBells, + &mut WriteOp::from_buf(doorbell_addr, &(cq_idx as u32 + 1).to_le_bytes()), + ); + res + } + fn submit_read(&mut self, sq: &mut SqState, lba: u64, memptr: usize, len: u64, cid: u16) -> Result<(), NvmeError> { let lba_lo = lba as u32; let lba_hi = (lba >> 32) as u32; @@ -547,6 +563,7 @@ impl FuzzCtx { fn poll_cq(&mut self, cq: &mut CqState) -> Result, NvmeError> { let mut cqes = Vec::new(); if let Some(cqe) = cq.poll_cqe(&self.scaffold.acc_mem) { + self.cq_doorbell(cq.qid, cq.next_id); cqes.push(cqe) } Ok(cqes) @@ -737,6 +754,8 @@ fn fuzzy() -> Result<(), NvmeError> { /// The number of bytes in the device's first namespace. This corresponds /// to `IdentifyNamespace`'s `NUSE` times the namespace's LBA size. ns_size: u64, + + orphaned_ios: BTreeMap<(u16, u16), usize>, } impl TestState { @@ -747,10 +766,11 @@ fn fuzzy() -> Result<(), NvmeError> { completion_queues: Vec::new(), // TODO: This should be read from the device under test, but // just using the constant will do for now. - max_queues: 2, //nvme::MAX_NUM_QUEUES, + max_queues: 17, // nvme::MAX_NUM_QUEUES, // TODO: Should read this from `IdentifyNamespace`, but the test // backend is made right up there and it's a fixed size.. ns_size: 64 * MB as u64, + orphaned_ios: BTreeMap::new(), }; // TODO: as with `max_queues` above, this should be read from the @@ -762,6 +782,7 @@ fn fuzzy() -> Result<(), NvmeError> { } fn apply(&mut self, fuzz_ctx: &mut FuzzCtx, action: TestAction) { + eprintln!("operation: {:?}", action); match action.op { TestOperation::Init => { eprintln!("doing init!"); @@ -789,7 +810,7 @@ fn fuzzy() -> Result<(), NvmeError> { if action.result == Expected::Ok { let cq_addr = FuzzCtx::io_cq_address(qid); - self.completion_queues[qid as usize] = Some(CqState::new(cq_addr)); + self.completion_queues[qid as usize] = Some(CqState::new(qid as u16, cq_addr)); } } TestOperation::CreateSQ(qid) => { @@ -800,6 +821,7 @@ fn fuzzy() -> Result<(), NvmeError> { if action.result == Expected::Ok { let sq_addr = FuzzCtx::io_sq_address(qid); + assert!(self.submission_queues[qid as usize].is_none()); self.submission_queues[qid as usize] = Some(SqState::new(sq_addr)); } } @@ -818,7 +840,18 @@ fn fuzzy() -> Result<(), NvmeError> { action.result.check(&res); if action.result == Expected::Ok { - self.submission_queues[qid as usize] = None; + eprintln!("well, the sq ({}) is gone now...", qid); + let mut old_sq = std::mem::replace( + &mut self.submission_queues[qid as usize], + None + ).unwrap(); + let keys: Vec = old_sq.outstanding_ios.keys().cloned().collect(); + for cid in keys.iter() { + let _io = old_sq.outstanding_ios.remove(&cid).unwrap(); + self.add_orphaned_io(qid, *cid); + } + } else { + eprintln!("sq ({}) lives another day", qid); } } TestOperation::Doorbell(qid) => { @@ -827,7 +860,7 @@ fn fuzzy() -> Result<(), NvmeError> { assert!(self.initialized); - let res = fuzz_ctx.doorbell(qid, sq.curr_idx()); + let res = fuzz_ctx.sq_doorbell(qid, sq.curr_idx()); action.result.check(&res); } @@ -841,7 +874,7 @@ fn fuzzy() -> Result<(), NvmeError> { sq.outstanding_cid() .expect("planner made sure a CID is present to reuse") }; - eprintln!("submitting read {} q={}, mem={:x} lba={}", queue, command_id, memptr, lba); +// eprintln!("submitting read {} q={}, mem={:x} lba={}", queue, command_id, memptr, lba); let res = fuzz_ctx.submit_read(sq, lba, memptr, size, command_id); sq.outstanding_ios.insert(command_id, TestIO { op: action.op, completion: None }); @@ -864,7 +897,7 @@ fn fuzzy() -> Result<(), NvmeError> { sq.outstanding_cid() .expect("planner made sure a CID is present to reuse") }; - eprintln!("submitting write {} q={}, mem={:x} lba={}", queue, command_id, memptr, lba); +// eprintln!("submitting write {} q={}, mem={:x} lba={}", queue, command_id, memptr, lba); let res = fuzz_ctx.submit_write(sq, lba, memptr, size, command_id); sq.outstanding_ios.insert(command_id, TestIO { op: action.op, completion: None }); @@ -887,7 +920,7 @@ fn fuzzy() -> Result<(), NvmeError> { // completion which we're about to process. assert!(sq.outstanding_ios.contains_key(&cid)); - fuzz_ctx.doorbell(queue, sq.curr_idx()) + fuzz_ctx.sq_doorbell(queue, sq.curr_idx()) .expect("doorbell"); let deadline = SystemTime::now().checked_add(Duration::from_secs(1)) @@ -915,7 +948,6 @@ fn fuzzy() -> Result<(), NvmeError> { .expect("WaitIO only issued for I/O queues that are fully established"); for completion in fuzz_ctx.poll_cq(cq).expect("can poll cq") { - eprintln!("new completion: {:?}", completion); self.handle_completion(completion); } } @@ -923,18 +955,37 @@ fn fuzzy() -> Result<(), NvmeError> { } } + fn add_orphaned_io(&mut self, qid: u16, cid: u16) { + let count = self.orphaned_ios.entry((qid, cid)).or_insert(0); + *count += 1; + } + + fn clear_orphaned_io(&mut self, qid: u16, cid: u16) { + let count = self.orphaned_ios.entry((qid, cid)).or_insert(0); + assert!(*count > 0); + *count -= 1; + } + + fn orphaned_io(&mut self, qid: u16, cid: u16) -> bool { + let count = self.orphaned_ios.entry((qid, cid)).or_insert(0); + *count > 0 + } + fn handle_completion(&mut self, completion: CompletionQueueEntry) { let sq = self.submission_queues[completion.sqid as usize] .as_mut().expect("completion implies there is an sq"); let cid = completion.cid; - let io = sq.outstanding_ios.get_mut(&cid) - .expect("there is a submission for the completion"); - let prior_completion = io.completion.replace(completion); - - // If we've seen a completion for an I/O, we .. should not have seen - // that I/O be completed before! We won't submit a new SQE with this - // CID until we've WaitIO'd on the existing one. - assert!(prior_completion.is_none()); + if let Some(io) = sq.outstanding_ios.get_mut(&cid) { + let prior_completion = io.completion.replace(completion); + + // If we've seen a completion for an I/O, we .. should not have seen + // that I/O be completed before! We won't submit a new SQE with this + // CID until we've WaitIO'd on the existing one. + assert!(prior_completion.is_none()); + } else { + assert!(self.orphaned_io(completion.sqid, cid)); + self.clear_orphaned_io(completion.sqid, cid); + } } fn options(&self, rng: &mut impl Rng) -> Vec { @@ -1040,8 +1091,9 @@ fn fuzzy() -> Result<(), NvmeError> { eprintln!("fuzzing nvme from seed {:#016x}", seed); let mut rng = Pcg64::seed_from_u64(seed); +// let mut rng = Pcg64::seed_from_u64(0xcef8328bd81ff955); - for _ in 0..1_000 { + for _ in 0..100_000 { let options = test_state.options(&mut rng); let next = options[rng.random_range(0..options.len())]; // eprintln!("operation: {:?}", next);