From bf6f492c497c8f94b2f5a3b5b89daaf4983e2c6d Mon Sep 17 00:00:00 2001 From: Robin Mueller Date: Mon, 4 May 2026 16:05:39 +0200 Subject: [PATCH 1/2] update asynch logger, simplify it --- firmware/examples/embassy/Cargo.toml | 2 + .../embassy/src/bin/logger-non-blocking.rs | 42 +++++++-- .../zedboard/src/bin/l3gd20h-spi-mio.rs | 22 +++-- firmware/zynq7000-hal/CHANGELOG.md | 2 + firmware/zynq7000-hal/Cargo.toml | 1 - firmware/zynq7000-hal/src/log.rs | 93 ++++++++----------- 6 files changed, 92 insertions(+), 70 deletions(-) diff --git a/firmware/examples/embassy/Cargo.toml b/firmware/examples/embassy/Cargo.toml index 55a1cda..3688d9f 100644 --- a/firmware/examples/embassy/Cargo.toml +++ b/firmware/examples/embassy/Cargo.toml @@ -17,6 +17,8 @@ zynq7000 = { path = "../../zynq7000" } zynq7000-hal = { path = "../../zynq7000-hal" } zynq7000-embassy = { path = "../../zynq7000-embassy" } dht-sensor = { git = "https://github.com/michaelbeaumont/dht-sensor.git", rev = "10319bdeae9ace3bb0fc79a15da2869c5bf50f52", features = ["async"] } +embedded-hal-async = "1" +embassy-sync = "0.8" static_cell = "2" critical-section = "1" heapless = "0.9" diff --git a/firmware/examples/embassy/src/bin/logger-non-blocking.rs b/firmware/examples/embassy/src/bin/logger-non-blocking.rs index a9ad799..7526d58 100644 --- a/firmware/examples/embassy/src/bin/logger-non-blocking.rs +++ b/firmware/examples/embassy/src/bin/logger-non-blocking.rs @@ -5,8 +5,10 @@ use aarch32_cpu::asm::nop; use core::panic::PanicInfo; use embassy_executor::Spawner; +use embassy_sync::blocking_mutex::raw::CriticalSectionRawMutex; use embassy_time::{Duration, Ticker}; use embedded_hal::digital::StatefulOutputPin; +use embedded_hal_async::delay::DelayNs as _; use embedded_io::Write; use log::{error, info}; use zynq7000::Peripherals; @@ -66,32 +68,60 @@ async fn main(spawner: Spawner) -> ! { uart.write_all(b"-- Zynq 7000 Logging example --\n\r") .unwrap(); uart.flush().unwrap(); + // Small delay to avoid logging glitches when creating an async UART. + embassy_time::Delay.delay_us(500).await; let (tx, _rx) = uart.split(); let mut logger = TxAsync::new(tx); - zynq7000_hal::log::rb::init(log::LevelFilter::Trace); + static LOG_PIPE: static_cell::ConstStaticCell< + embassy_sync::pipe::Pipe, + > = static_cell::ConstStaticCell::new(embassy_sync::pipe::Pipe::new()); + let (log_reader, log_writer) = LOG_PIPE.take().split(); + zynq7000_hal::log::asynch::init(log::LevelFilter::Trace, log_writer); let boot_mode = BootMode::new_from_regs(); info!("Boot mode: {:?}", boot_mode); let led = Output::new_for_mio(mio_pins.mio7, PinState::Low); spawner.spawn(led_task(led).unwrap()); + spawner.spawn(hello_task().unwrap()); + let mut log_buf: [u8; 2048] = [0; 2048]; - let frame_queue = zynq7000_hal::log::rb::get_frame_queue(); loop { - let next_frame_len = frame_queue.receive().await; - zynq7000_hal::log::rb::read_next_frame(next_frame_len, &mut log_buf); - logger.write(&log_buf[0..next_frame_len]).await; + let read_bytes = log_reader.read(&mut log_buf).await; + if read_bytes > 0 { + logger.write(&log_buf[0..read_bytes]).await; + } } } #[embassy_executor::task] async fn led_task(mut mio_led: Output) { + static ATOMIC_COUNTER: core::sync::atomic::AtomicUsize = + core::sync::atomic::AtomicUsize::new(0); + let mut ticker = Ticker::every(Duration::from_millis(1000)); loop { mio_led.toggle().unwrap(); - info!("Toggling LED"); + info!( + "Toggling LED ({})", + ATOMIC_COUNTER.fetch_add(1, core::sync::atomic::Ordering::Relaxed) + ); + ticker.next().await; + } +} +#[embassy_executor::task] +async fn hello_task() { + static ATOMIC_COUNTER: core::sync::atomic::AtomicUsize = + core::sync::atomic::AtomicUsize::new(0); + + let mut ticker = Ticker::every(Duration::from_millis(1000)); + loop { + info!( + "Hello from another task ({})", + ATOMIC_COUNTER.fetch_add(1, core::sync::atomic::Ordering::Relaxed) + ); ticker.next().await; } } diff --git a/firmware/examples/zedboard/src/bin/l3gd20h-spi-mio.rs b/firmware/examples/zedboard/src/bin/l3gd20h-spi-mio.rs index 47bac0a..ec6f514 100644 --- a/firmware/examples/zedboard/src/bin/l3gd20h-spi-mio.rs +++ b/firmware/examples/zedboard/src/bin/l3gd20h-spi-mio.rs @@ -12,6 +12,7 @@ use aarch32_cpu::asm::nop; use core::panic::PanicInfo; use embassy_executor::Spawner; +use embassy_sync::blocking_mutex::raw::CriticalSectionRawMutex; use embassy_time::{Delay, Duration, Ticker}; use embedded_hal::digital::StatefulOutputPin; use embedded_hal_async::delay::DelayNs; @@ -90,7 +91,13 @@ async fn main(spawner: Spawner) -> ! { .unwrap(); uart.write_all(b"-- Zynq 7000 Zedboard SPI L3GD20H example --\n\r") .unwrap(); - zynq7000_hal::log::rb::init(log::LevelFilter::Trace); + + static LOG_PIPE: static_cell::ConstStaticCell< + embassy_sync::pipe::Pipe, + > = static_cell::ConstStaticCell::new(embassy_sync::pipe::Pipe::new()); + let (log_reader, log_writer) = LOG_PIPE.take().split(); + + zynq7000_hal::log::asynch::init(log::LevelFilter::Trace, log_writer); let boot_mode = BootMode::new_from_regs(); info!("Boot mode: {:?}", boot_mode); @@ -155,7 +162,7 @@ async fn main(spawner: Spawner) -> ! { } } - spawner.spawn(logger_task(uart).unwrap()); + spawner.spawn(logger_task(uart, log_reader).unwrap()); if BLOCKING { blocking_application(mio_led, emio_leds, spi).await; } else { @@ -164,15 +171,16 @@ async fn main(spawner: Spawner) -> ! { } #[embassy_executor::task] -pub async fn logger_task(uart: uart::Uart) { +pub async fn logger_task( + uart: uart::Uart, + reader: embassy_sync::pipe::Reader<'static, CriticalSectionRawMutex, 4096>, +) -> ! { let (tx, _) = uart.split(); let mut tx_async = TxAsync::new(tx); - let frame_queue = zynq7000_hal::log::rb::get_frame_queue(); let mut log_buf: [u8; 2048] = [0; 2048]; loop { - let next_frame_len = frame_queue.receive().await; - zynq7000_hal::log::rb::read_next_frame(next_frame_len, &mut log_buf); - tx_async.write(&log_buf[0..next_frame_len]).await; + let read_bytes = reader.read(&mut log_buf).await; + tx_async.write(&log_buf[0..read_bytes]).await; } } diff --git a/firmware/zynq7000-hal/CHANGELOG.md b/firmware/zynq7000-hal/CHANGELOG.md index e982da6..8602112 100644 --- a/firmware/zynq7000-hal/CHANGELOG.md +++ b/firmware/zynq7000-hal/CHANGELOG.md @@ -23,6 +23,8 @@ and this project adheres to [Semantic Versioning](http://semver.org/). - Added division by zero check in gtc frequency_to_ticks to avoid runtime panic - Increased UART type safety by providing dedicated MIO constructors for UART 0 and UART 1 respectively. +- `log::rb` module replaced by `log::asynch` module which uses an asynchronous embassy pipe + for logging. ## Added diff --git a/firmware/zynq7000-hal/Cargo.toml b/firmware/zynq7000-hal/Cargo.toml index b73d98b..e2d47a3 100644 --- a/firmware/zynq7000-hal/Cargo.toml +++ b/firmware/zynq7000-hal/Cargo.toml @@ -20,7 +20,6 @@ arbitrary-int = "2" thiserror = { version = "2", default-features = false } num_enum = { version = "0.7", default-features = false } bitflags = "2" -ringbuf = { version = "0.4.8", default-features = false } embedded-hal-nb = "1" embedded-io = "0.7" embedded-hal = "1" diff --git a/firmware/zynq7000-hal/src/log.rs b/firmware/zynq7000-hal/src/log.rs index d6db008..d5fc8d0 100644 --- a/firmware/zynq7000-hal/src/log.rs +++ b/firmware/zynq7000-hal/src/log.rs @@ -165,36 +165,31 @@ pub mod uart_blocking { } } -/// Logger module which logs into a ring buffer to allow asynchronous logging handling. -pub mod rb { - use core::cell::RefCell; +/// Logger module which logs into a pipe to allow asynchronous logging handling. +pub mod asynch { use core::fmt::Write as _; use embassy_sync::blocking_mutex::raw::CriticalSectionRawMutex; use log::{LevelFilter, set_logger, set_max_level}; - use ringbuf::{ - StaticRb, - traits::{Consumer, Producer}, - }; /// Logger implementation which logs frames via a ring buffer and sends the frame sizes /// as messages. /// - /// The logger does not require allocation and reserved a generous amount of 4096 bytes for - /// both data buffer and ring buffer. This should be sufficient for most logging needs. + /// The logger does not require allocation and reserves a generous amount of 4096 bytes for + /// log data. This should be sufficient for most logging needs. pub struct Logger { - frame_queue: embassy_sync::channel::Channel, - data_buf: critical_section::Mutex>>, - ring_buf: critical_section::Mutex>>>, + pipe: core::cell::RefCell< + Option>, + >, + buf: critical_section::Mutex>>, } unsafe impl Send for Logger {} unsafe impl Sync for Logger {} - static LOGGER_RB: Logger = Logger { - frame_queue: embassy_sync::channel::Channel::new(), - data_buf: critical_section::Mutex::new(RefCell::new(heapless::String::new())), - ring_buf: critical_section::Mutex::new(RefCell::new(None)), + static LOGGER_PIPE: Logger = Logger { + pipe: core::cell::RefCell::new(None), + buf: critical_section::Mutex::new(core::cell::RefCell::new(heapless::String::new())), }; impl log::Log for Logger { @@ -203,58 +198,44 @@ pub mod rb { } fn log(&self, record: &log::Record) { + if self.pipe.borrow().is_none() { + return; + } critical_section::with(|cs| { - let ref_buf = self.data_buf.borrow(cs); - let mut buf = ref_buf.borrow_mut(); + let mut buf = self.buf.borrow(cs).borrow_mut(); buf.clear(); let _ = writeln!(buf, "{} - {}\r", record.level(), record.args()); - let rb_ref = self.ring_buf.borrow(cs); - let mut rb_opt = rb_ref.borrow_mut(); - if rb_opt.is_none() { - panic!("log call on uninitialized logger"); + + let mut written = 0; + + let pipe_writer_ref = self.pipe.borrow(); + let pipe_writer = pipe_writer_ref.as_ref().unwrap(); + loop { + match pipe_writer.try_write(&buf.as_bytes()[written..]) { + Ok(written_in_this_call) => { + written += written_in_this_call; + if written >= buf.len() { + break; + } + } + Err(_) => break, + } } - rb_opt.as_mut().unwrap().push_slice(buf.as_bytes()); - let _ = self.frame_queue.try_send(buf.len()); }); } - fn flush(&self) { - while !self.frame_queue().is_empty() {} - } + fn flush(&self) {} } - impl Logger { - pub fn frame_queue( - &self, - ) -> &embassy_sync::channel::Channel { - &self.frame_queue - } - } - - pub fn init(level: LevelFilter) { + pub fn init( + level: LevelFilter, + writer: embassy_sync::pipe::Writer<'static, CriticalSectionRawMutex, 4096>, + ) { if super::LOGGER_INIT_DONE.swap(true, core::sync::atomic::Ordering::Relaxed) { return; } - critical_section::with(|cs| { - let rb = StaticRb::::default(); - let rb_ref = LOGGER_RB.ring_buf.borrow(cs); - rb_ref.borrow_mut().replace(rb); - }); - set_logger(&LOGGER_RB).unwrap(); + LOGGER_PIPE.pipe.borrow_mut().replace(writer); + set_logger(&LOGGER_PIPE).unwrap(); set_max_level(level); // Adjust as needed } - - pub fn read_next_frame(frame_len: usize, buf: &mut [u8]) { - let read_len = core::cmp::min(frame_len, buf.len()); - critical_section::with(|cs| { - let rb_ref = LOGGER_RB.ring_buf.borrow(cs); - let mut rb = rb_ref.borrow_mut(); - rb.as_mut().unwrap().pop_slice(&mut buf[0..read_len]); - }) - } - - pub fn get_frame_queue() - -> &'static embassy_sync::channel::Channel { - LOGGER_RB.frame_queue() - } } From 8215eec0cfc5dc3ed650aec31d1613541c895f27 Mon Sep 17 00:00:00 2001 From: Robin Mueller Date: Mon, 4 May 2026 17:54:44 +0200 Subject: [PATCH 2/2] clippy fix --- firmware/zynq7000-hal/src/log.rs | 15 ++++++--------- 1 file changed, 6 insertions(+), 9 deletions(-) diff --git a/firmware/zynq7000-hal/src/log.rs b/firmware/zynq7000-hal/src/log.rs index d5fc8d0..6b9777d 100644 --- a/firmware/zynq7000-hal/src/log.rs +++ b/firmware/zynq7000-hal/src/log.rs @@ -210,15 +210,12 @@ pub mod asynch { let pipe_writer_ref = self.pipe.borrow(); let pipe_writer = pipe_writer_ref.as_ref().unwrap(); - loop { - match pipe_writer.try_write(&buf.as_bytes()[written..]) { - Ok(written_in_this_call) => { - written += written_in_this_call; - if written >= buf.len() { - break; - } - } - Err(_) => break, + while let Ok(written_in_this_call) = + pipe_writer.try_write(&buf.as_bytes()[written..]) + { + written += written_in_this_call; + if written >= buf.len() { + break; } } });