Repository: chipsalliance/caliptra-sw
Pull request #124 (2023-03-30 22:52:31)

Improvements to HWModel
* Always write output to stdout, with "UART:" prefix
* Replace the slow mpsc hack with a shared buffer
* Add HwModel::ready_for_fw()


Patch:
diff --git a/hw-model/src/lib.rs b/hw-model/src/lib.rs
index 44823219..3501beef 100644
--- a/hw-model/src/lib.rs
+++ b/hw-model/src/lib.rs
@@ -1,6 +1,9 @@
 // Licensed under the Apache-2.0 license
 
-use std::{error::Error, io::ErrorKind};
+use std::{
+    error::Error,
+    io::{stdout, ErrorKind},
+};
 
 use caliptra_emu_bus::Bus;
 
@@ -43,7 +46,6 @@ pub fn create(params: InitParams) -> Result<ModelVerilated, Box<dyn Error>> {
     ModelVerilated::init(params)
 }
 
-#[derive(Default)]
 pub struct InitParams<'a> {
     // The contents of the boot ROM
     pub rom: &'a [u8],
@@ -53,8 +55,21 @@ pub struct InitParams<'a> {
 
     // The initial contents of the ICCM SRAM
     pub iccm: &'a [u8],
+
+    pub log_writer: Box<dyn std::io::Write>,
+}
+impl<'a> Default for InitParams<'a> {
+    fn default() -> Self {
+        Self {
+            rom: Default::default(),
+            dccm: Default::default(),
+            iccm: Default::default(),
+            log_writer: Box::new(stdout()),
+        }
+    }
 }
 
+#[derive(Debug)]
 pub enum ModelError {
     MailboxErr,
     NotReadyForFwErr,
@@ -94,6 +109,12 @@ pub trait HwModel {
         }
     }
 
+    fn ready_for_fw(&self) -> bool;
+
+    fn step_until_exit_success(&mut self) -> std::io::Result<()> {
+        self.copy_output_until_exit_success(std::io::Sink::default())
+    }
+
     fn copy_output_until_exit_success(
         &mut self,
         mut w: impl std::io::Write,
diff --git a/hw-model/src/model_emulated.rs b/hw-model/src/model_emulated.rs
index 7b60d2f7..e5f7a177 100644
--- a/hw-model/src/model_emulated.rs
+++ b/hw-model/src/model_emulated.rs
@@ -1,5 +1,6 @@
 // Licensed under the Apache-2.0 license
 
+use std::cell::Cell;
 use std::cell::RefCell;
 use std::env;
 use std::error::Error;
@@ -8,11 +9,11 @@ use std::io::BufWriter;
 use std::io::Write;
 use std::path::Path;
 use std::rc::Rc;
-use std::sync::mpsc;
 
 use caliptra_emu_bus::Clock;
 use caliptra_emu_cpu::Cpu;
 use caliptra_emu_cpu::InstrTracer;
+use caliptra_emu_periph::ReadyForFwCb;
 use caliptra_emu_periph::{CaliptraRootBus, CaliptraRootBusArgs, TbServicesCb};
 use caliptra_emu_types::{RvAddr, RvData, RvSize};
 
@@ -151,8 +152,8 @@ impl<TBus: Bus> Bus for BusLogger<TBus> {
 pub struct ModelEmulated {
     cpu: Cpu<BusLogger<CaliptraRootBus>>,
     output: Output,
-    generic_load_rx: mpsc::Receiver<u8>,
     trace_fn: Option<Box<InstrTracer<'static>>>,
+    ready_for_fw: Rc<Cell<bool>>,
 }
 
 impl crate::HwModel for ModelEmulated {
@@ -162,12 +163,22 @@ impl crate::HwModel for ModelEmulated {
     where
         Self: Sized,
     {
-        let (generic_load_tx, generic_load_rx) = mpsc::channel();
         let clock = Clock::new();
+
+        let ready_for_fw = Rc::new(Cell::new(false));
+        let ready_for_fw_clone = ready_for_fw.clone();
+
+        let output = Output::new(params.log_writer);
+
+        let output_sink = output.sink().clone();
+
         let bus_args = CaliptraRootBusArgs {
             rom: params.rom.into(),
             tb_services_cb: TbServicesCb(Box::new(move |ch| {
-                let _ = generic_load_tx.send(ch);
+                output_sink.push_uart_char(ch);
+            })),
+            ready_for_fw_cb: ReadyForFwCb(Box::new(move |_| {
+                ready_for_fw_clone.set(true);
             })),
             ..CaliptraRootBusArgs::default()
         };
@@ -177,16 +188,20 @@ impl crate::HwModel for ModelEmulated {
         );
 
         let mut m = ModelEmulated {
-            generic_load_rx,
-            output: Output::new(),
+            output,
             cpu,
             trace_fn: None,
+            ready_for_fw,
         };
         // Turn tracing on if CPTRA_TRACE_PATH environment variable is set
         m.tracing_hint(true);
 
         Ok(m)
     }
+
+    fn ready_for_fw(&self) -> bool {
+        self.ready_for_fw.get()
+    }
     fn apb_bus(&mut self) -> Self::TBus<'_> {
         EmulatedApbBus { model: self }
     }
@@ -196,10 +211,6 @@ impl crate::HwModel for ModelEmulated {
     }
 
     fn output(&mut self) -> &mut Output {
-        // Make sure output contains all the latest generic loads from the verilator model
-        while let Ok(ch) = self.generic_load_rx.try_recv() {
-            self.output.process_generic_load(ch)
-        }
         &mut self.output
     }
 
diff --git a/hw-model/src/model_verilated.rs b/hw-model/src/model_verilated.rs
index 020968d2..5920a78e 100644
--- a/hw-model/src/model_verilated.rs
+++ b/hw-model/src/model_verilated.rs
@@ -1,7 +1,5 @@
 // Licensed under the Apache-2.0 license
 
-use std::sync::mpsc;
-
 use caliptra_emu_bus::Bus;
 use caliptra_emu_types::{RvAddr, RvData, RvSize};
 use caliptra_verilated::CaliptraVerilated;
@@ -43,7 +41,6 @@ impl<'a> Bus for VerilatedApbBus<'a> {
 pub struct ModelVerilated {
     v: CaliptraVerilated,
 
-    generic_load_rx: mpsc::Receiver<u8>,
     output: Output,
     trace_enabled: bool,
 }
@@ -64,9 +61,11 @@ impl crate::HwModel for ModelVerilated {
     where
         Self: Sized,
     {
-        let (generic_load_tx, generic_load_rx) = mpsc::channel();
+        let output = Output::new(params.log_writer);
+
+        let output_sink = output.sink().clone();
         let generic_load_cb = Box::new(move |ch| {
-            let _ = generic_load_tx.send(ch);
+            output_sink.push_uart_char(ch);
         });
         let mut v = CaliptraVerilated::with_generic_load_cb(generic_load_cb);
 
@@ -74,8 +73,7 @@ impl crate::HwModel for ModelVerilated {
 
         let mut m = ModelVerilated {
             v,
-            generic_load_rx,
-            output: Output::new(),
+            output,
             trace_enabled: false,
         };
 
@@ -109,14 +107,13 @@ impl crate::HwModel for ModelVerilated {
     }
 
     fn output(&mut self) -> &mut crate::Output {
-        // Make sure output contains all the latest generic loads from the verilator model
-        while let Ok(ch) = self.generic_load_rx.try_recv() {
-            self.output.process_generic_load(ch)
-        }
-
         &mut self.output
     }
 
+    fn ready_for_fw(&self) -> bool {
+        self.v.output.ready_for_fw_push
+    }
+
     fn tracing_hint(&mut self, enable: bool) {
         if self.trace_enabled != enable {
             self.trace_enabled = enable;
diff --git a/hw-model/src/output.rs b/hw-model/src/output.rs
index 3a5313fb..bf41383a 100644
--- a/hw-model/src/output.rs
+++ b/hw-model/src/output.rs
@@ -1,55 +1,124 @@
 // Licensed under the Apache-2.0 license
 
-#[derive(Clone, Copy)]
+use std::io::LineWriter;
+use std::{
+    cell::{Cell, RefCell},
+    io::Write,
+    rc::Rc,
+};
+
+#[derive(Clone, Copy, Debug, Eq, PartialEq)]
 pub enum ExitStatus {
     Passed,
     Failed,
 }
 
-#[derive(Default)]
-pub struct Output {
-    output: String,
-    exit_status: Option<ExitStatus>,
+struct OutputSinkImpl {
+    exit_status: Cell<Option<ExitStatus>>,
+    new_uart_output: Cell<String>,
+    log_writer: RefCell<LineWriter<Box<dyn std::io::Write>>>,
+    at_start_of_line: Cell<bool>,
 }
-impl Output {
-    pub fn new() -> Self {
-        Self::default()
-    }
-    #[allow(dead_code)]
-    pub(crate) fn process_generic_load(&mut self, ch: u8) {
-        // For a complete list of special characters:
-        // https://github.com/Project-Caliptra/rtl-caliptra/blob/884240d062c44b4aced96b7d58f33683687743f7/src/integration/tb/caliptra_top_tb_services.sv#L141
+
+#[derive(Clone)]
+pub struct OutputSink(Rc<OutputSinkImpl>);
+impl OutputSink {
+    pub fn push_uart_char(&self, ch: u8) {
+        const UART_LOG_PREFIX: &[u8] = b"UART: ";
+
         const TESTCASE_FAILED: u8 = 0x01;
         const TESTCASE_PASSED: u8 = 0xff;
 
         match ch {
             TESTCASE_PASSED => {
                 // This is the same string as printed by the verilog test-bench
-                self.output.push_str("* TESTCASE PASSED\n");
-                self.exit_status = Some(ExitStatus::Passed);
+                self.0
+                    .log_writer
+                    .borrow_mut()
+                    .write_all(b"* TESTCASE PASSED\n")
+                    .unwrap();
+                self.0.exit_status.set(Some(ExitStatus::Passed));
             }
             TESTCASE_FAILED => {
                 // This is the same string as printed by the verilog test-bench
-                self.output.push_str("* TESTCASE FAILED\n");
-                self.exit_status = Some(ExitStatus::Failed);
+                self.0
+                    .log_writer
+                    .borrow_mut()
+                    .write_all(b"* TESTCASE FAILED\n")
+                    .unwrap();
+                self.0.exit_status.set(Some(ExitStatus::Failed));
             }
             0x20..=0x7f | b'\r' | b'\n' | b'\t' => {
-                self.output.push(ch as char);
+                let mut s = self.0.new_uart_output.take();
+                s.push(ch as char);
+                self.0.new_uart_output.set(s);
+
+                let log_writer = &mut self.0.log_writer.borrow_mut();
+                if self.0.at_start_of_line.get() {
+                    log_writer.flush().unwrap();
+                    log_writer.write_all(UART_LOG_PREFIX).unwrap();
+                    self.0.at_start_of_line.set(false);
+                }
+                log_writer.write_all(&[ch]).unwrap();
+                if ch == b'\n' {
+                    self.0.at_start_of_line.set(true);
+                }
             }
             _ => {
-                self.output
-                    .push_str(&format!("Unknown generic load 0x{ch:02x}\n"));
+                writeln!(
+                    self.0.log_writer.borrow_mut(),
+                    "Unknown generic load 0x{ch:02x}"
+                )
+                .unwrap();
             }
         }
     }
+}
+impl std::io::Write for &OutputSink {
+    fn write(&mut self, buf: &[u8]) -> std::io::Result<usize> {
+        self.0.log_writer.borrow_mut().write(buf)
+    }
+
+    fn flush(&mut self) -> std::io::Result<()> {
+        self.0.log_writer.borrow_mut().flush()
+    }
+}
+
+pub struct Output {
+    output: String,
+    sink: OutputSink,
+}
+impl Output {
+    pub fn new(log_writer: impl std::io::Write + 'static) -> Self {
+        Self::new_internal(Box::new(log_writer))
+    }
+    fn new_internal(log_writer: Box<dyn std::io::Write>) -> Self {
+        Self {
+            output: "".into(),
+            sink: OutputSink(Rc::new(OutputSinkImpl {
+                new_uart_output: Default::default(),
+                log_writer: RefCell::new(LineWriter::new(log_writer)),
+                exit_status: Cell::new(None),
+                at_start_of_line: Cell::new(true),
+            })),
+        }
+    }
+    pub fn sink(&self) -> &OutputSink {
+        &self.sink
+    }
+    pub fn logger(&self) -> impl std::io::Write + '_ {
+        &self.sink
+    }
 
     /// Peek at all the output captured so far
-    pub fn peek(&self) -> &str {
+    pub fn peek(&mut self) -> &str {
+        self.process_new_data();
         &self.output
     }
 
     /// Take at most `limit` characters from the output
     pub fn take(&mut self, limit: usize) -> String {
+        self.process_new_data();
         if self.output.len() <= limit {
             std::mem::take(&mut self.output)
         } else {
@@ -60,59 +129,130 @@ impl Output {
         }
     }
 
+    fn process_new_data(&mut self) {
+        let new_data = self.sink.0.new_uart_output.take();
+        if self.output.is_empty() {
+            self.output = new_data;
+        } else {
+            self.output.push_str(&new_data);
+        }
+    }
+
     /// Returns true if the caliptra microcontroller has signalled that it wants to exit
     /// (this only makes sense when running test cases on the microcontroller)
     pub fn exit_requested(&self) -> bool {
-        self.exit_status.is_some()
+        self.exit_status().is_some()
     }
 
     pub fn exit_status(&self) -> Option<ExitStatus> {
-        self.exit_status
+        self.sink.0.exit_status.get()
     }
 }
 
 #[cfg(test)]
 mod tests {
+
+    use std::io::Sink;
+
     use super::*;
 
+    #[derive(Clone)]
+    pub struct Log {
+        log: Rc<RefCell<Vec<u8>>>,
+    }
+    impl Log {
+        /// Construct an empty `Log`.
+        pub fn new() -> Self {
+            Self {
+                log: Rc::new(RefCell::new(vec![])),
+            }
+        }
+        fn into_string(self) -> String {
+            String::from_utf8(self.log.take()).unwrap()
+        }
+    }
+    impl Default for Log {
+        fn default() -> Self {
+            Self::new()
+        }
+    }
+    impl std::io::Write for Log {
+        fn write(&mut self, buf: &[u8]) -> std::io::Result<usize> {
+            std::io::Write::write(&mut *self.log.borrow_mut(), buf)
+        }
+
+        fn flush(&mut self) -> std::io::Result<()> {
+            std::io::Write::flush(&mut *self.log.borrow_mut())
+        }
+    }
+
     #[test]
     fn test_take() {
-        let mut out = Output::new();
+        let log = Log::new();
+        let mut out = Output::new(log.clone());
+
+        out.sink().push_uart_char(b'h');
+        out.sink().push_uart_char(b'i');
+        out.sink().push_uart_char(b'!');
+        out.sink().push_uart_char(b'\n');
 
-        out.process_generic_load(b'h');
-        out.process_generic_load(b'i');
-        out.process_generic_load(b'!');
         assert_eq!(&out.take(2), "hi");
-        assert_eq!(&out.take(10), "!");
+        assert_eq!(&out.take(10), "!\n");
         assert_eq!(&out.take(10), "");
+
+        assert_eq!(log.into_string(), "UART: hi!\n");
     }
 
     #[test]
     fn test_peek() {
-        let mut out = Output::new();
+        let mut out = Output::new(Sink::default());
 
-        out.process_generic_load(b'h');
-        out.process_generic_load(b'i');
+        out.sink().push_uart_char(b'h');
+        out.sink().push_uart_char(b'i');
         assert_eq!(out.peek(), "hi");
-        out.process_generic_load(b'!');
+        out.sink().push_uart_char(b'!');
         assert_eq!(out.peek(), "hi!");
     }
 
     #[test]
-    fn test_generic_loads() {
-        let mut out = Output::new();
+    fn test_passed() {
+        let log = Log::new();
+        let mut out = Output::new(log.clone());
 
-        out.process_generic_load(b'h');
-        out.process_generic_load(b'i');
-        assert_eq!(&out.take(10), "hi");
+        out.sink().push_uart_char(b'h');
+        out.sink().push_uart_char(b'i');
+        out.sink().push_uart_char(b'\n');
+        assert_eq!(&out.take(10), "hi\n");
 
-        out.process_generic_load(0xff);
-        assert_eq!(&out.take(20), "* TESTCASE PASSED\n");
+        out.sink().push_uart_char(0xff);
+        assert_eq!(out.exit_status(), Some(ExitStatus::Passed));
+        assert_eq!(&out.take(10), "");
+
+        assert_eq!(log.into_string(), "UART: hi\n* TESTCASE PASSED\n");
+    }
 
-        out.process_generic_load(0x01);
-        assert_eq!(&out.take(20), "* TESTCASE FAILED\n");
+    #[test]
+    fn test_failed() {
+        let log = Log::new();
+        let mut out = Output::new(log.clone());
+
+        out.sink().push_uart_char(b'h');
+        out.sink().push_uart_char(b'i');
+        out.sink().push_uart_char(b'\n');
+        out.sink().push_uart_char(0x01);
+        assert_eq!(out.exit_status(), Some(ExitStatus::Failed));
+        assert_eq!(&out.take(10), "hi\n");
+
+        assert_eq!(log.into_string(), "UART: hi\n* TESTCASE FAILED\n");
+    }
+
+    #[test]
+    fn test_unknown_generic_load() {
+        let log = Log::new();
+        let mut out = Output::new(log.clone());
+        out.sink().push_uart_char(0xd3);
 
-        out.process_generic_load(0xd3);
-        assert_eq!(&out.take(30), "Unknown generic load 0xd3\n");
+        assert_eq!(&out.take(30), "");
+        assert_eq!(log.into_string(), "Unknown generic load 0xd3\n");
     }
 }


Test patch:
diff --git a/drivers/tests/integration_tests.rs b/drivers/tests/integration_tests.rs
index 035b41d7..595d6c99 100644
--- a/drivers/tests/integration_tests.rs
+++ b/drivers/tests/integration_tests.rs
@@ -1,7 +1,5 @@
 // Licensed under the Apache-2.0 license
 
-use std::io::{stdout, LineWriter};
-
 use caliptra_hw_model::{HwModel, InitParams};
 
 fn run_driver_test(test_bin_name: &str) {
@@ -14,9 +12,7 @@ fn run_driver_test(test_bin_name: &str) {
     .unwrap();
 
     // Wrap in a line-writer so output from different test threads doesn't multiplex within a line.
-    model
-        .copy_output_until_exit_success(LineWriter::new(stdout()))
-        .unwrap();
+    model.step_until_exit_success().unwrap();
 }
 
 #[test]