Async-SPI on ESP32: Unexpected behavior

[bjoernQ]

(Issue originally raised on Matrix by @plaes)

Given this code

//! Connect MISO and MOSI pins
//!
//! The following wiring is assumed:
//! SCLK => GPIO0
//! MISO => GPIO2
//! MOSI => GPIO4

//% CHIPS: esp32 esp32c2 esp32c3 esp32c6 esp32h2 esp32s2 esp32s3
//% FEATURES: async embassy embassy-generic-timers embedded-hal embedded-hal-bus/async

#![no_std]
#![no_main]

use embassy_executor::Spawner;
use embassy_time::{Duration, Timer};
use embedded_hal::spi::Operation;
use embedded_hal_async::spi::SpiDevice;
use embedded_hal_bus::spi::ExclusiveDevice;
use esp_backtrace as _;
use esp_hal::{
    clock::ClockControl,
    dma::*,
    dma_descriptors,
    gpio::{Io, Level, Output},
    peripherals::Peripherals,
    prelude::*,
    spi::{
        master::{dma::SpiDma, prelude::*, Spi},
        FullDuplexMode,
        SpiMode,
    },
    system::SystemControl,
    timer::{timg::TimerGroup, ErasedTimer, OneShotTimer},
    Async,
    FlashSafeDma,
};
use esp_println::println;

// When you are okay with using a nightly compiler it's better to use https://docs.rs/static_cell/2.1.0/static_cell/macro.make_static.html
macro_rules! mk_static {
    ($t:ty,$val:expr) => {{
        static STATIC_CELL: static_cell::StaticCell<$t> = static_cell::StaticCell::new();
        #[deny(unused_attributes)]
        let x = STATIC_CELL.uninit().write(($val));
        x
    }};
}

const DMA_BUF: usize = 256;

#[cfg(not(any(feature = "esp32", feature = "esp32s2")))]
type SafeSpiDma = FlashSafeDma<
    SpiDma<'static, esp_hal::peripherals::SPI2, DmaChannel0, FullDuplexMode, Async>,
    DMA_BUF,
>;

#[cfg(any(feature = "esp32", feature = "esp32s2"))]
type SafeSpiDma = FlashSafeDma<
    SpiDma<'static, esp_hal::peripherals::SPI2, Spi2DmaChannel, FullDuplexMode, Async>,
    DMA_BUF,
>;

#[esp_hal_embassy::main]
async fn main(_spawner: Spawner) {
    esp_println::println!("Init!");
    let peripherals = Peripherals::take();
    let system = SystemControl::new(peripherals.SYSTEM);
    let clocks = ClockControl::boot_defaults(system.clock_control).freeze();

    let timg0 = TimerGroup::new(peripherals.TIMG0, &clocks);
    let timer0: ErasedTimer = timg0.timer0.into();
    let timers = [OneShotTimer::new(timer0)];
    let timers = mk_static!([OneShotTimer<ErasedTimer>; 1], timers);
    esp_hal_embassy::init(&clocks, timers);

    let io = Io::new(peripherals.GPIO, peripherals.IO_MUX);
    let sclk = io.pins.gpio0;
    let miso = io.pins.gpio2;
    let mosi = io.pins.gpio4;
    let cs = io.pins.gpio5;

    let dma = Dma::new(peripherals.DMA);

    #[cfg(any(feature = "esp32", feature = "esp32s2"))]
    let dma_channel = dma.spi2channel;
    #[cfg(not(any(feature = "esp32", feature = "esp32s2")))]
    let dma_channel = dma.channel0;

    let (descriptors, rx_descriptors) = dma_descriptors!(32000);

    let mut spi = Spi::new(peripherals.SPI2, 100.kHz(), SpiMode::Mode0, &clocks)
        .with_pins(Some(sclk), Some(mosi), Some(miso), Some(cs))
        .with_dma(
            dma_channel.configure_for_async(false, DmaPriority::Priority0),
            descriptors,
            rx_descriptors,
        );

    let cs = Output::new(io.pins.gpio18, Level::Low);

    let spi: SafeSpiDma = FlashSafeDma::new(spi);
    let mut spi_dev = ExclusiveDevice::new(spi, cs, embassy_time::Delay).unwrap();

    loop {
        let write_buf = &[1];
        let payload = &[5, 4, 3, 2, 1];

        println!("SPI 2 (write buffer)... ");
        let mut ops = [Operation::Write(write_buf), Operation::Write(payload)];
        let _ = spi_dev.transaction(&mut ops).await;

        println!("SPI 3 (read previous buffer)...");
        let mut read: [u8; 6] = [0x00u8; 6];
        let mut ops = [Operation::Read(&mut read)];
        let _ = spi_dev.transaction(&mut ops).await;
        println!("... result: {:?}", read);

        Timer::after(Duration::from_millis(1_000)).await;
    }
}

The output on ESP32 is:

SPI 2 (write buffer)...
SPI 3 (read previous buffer)...
... result: [5, 0, 0, 0, 0, 0]

Which is quite unexpected - should be result: [0, 0, 0, 0, 0, 0

On ESP32 the LA shows this:

On e.g. ESP32-C6 (and all other tested targets) the LA shows this:

So, on ESP32 the Read clocks out the previous buffer and since there is more data to clock out some garbage.
Still interesting that only the first byte makes it into the read-buffer.

The huge delay before the Read on ESP32-C6 compared to ESP32 is also interesting.

[Dominaezzz]

That's probably because the SPI driver in DMA mode doesn't disable the write side when reading is being done.

This logic here should also be done for DMA mode.

esp-hal/esp-hal/src/spi/master.rs

Lines 2997 to 3000 in 237804e

	.usr_miso()
	.bit(!is_write && !no_mosi_miso)
	.usr_mosi()
	.bit(is_write && !no_mosi_miso)

Somewhere in here.

esp-hal/esp-hal/src/spi/master.rs

Lines 2104 to 2130 in 237804e

	unsafe fn start_read_bytes_dma(
	&mut self,
	chain: &mut DescriptorChain,
	ptr: *mut u8,
	len: usize,
	rx: &mut RX,
	) -> Result<(), Error> {
	let reg_block = self.register_block();
	self.configure_datalen(len as u32 * 8);
	rx.is_done();
	self.enable_dma();
	self.update();
	reset_dma_before_load_dma_dscr(reg_block);
	self.clear_dma_interrupts();
	chain.fill_for_rx(false, ptr, len)?;
	rx.prepare_transfer_without_start(self.dma_peripheral(), chain)
	.and_then(|_| rx.start_transfer())?;
	reset_dma_before_usr_cmd(reg_block);
	reg_block.cmd().modify(|_, w| w.usr().set_bit());
	Ok(())
	}