Problem with spi_master driver and two mixed-duplex devices (IDFGH-2555)

[alemariusnexus]

Environment

• Development Kit: Adafruit HUZZAH32
• Module or chip used: ESP32-WROOM-32
• IDF version: v4.0-beta2
• Build System: CMake
• Compiler version: 8.2.0
• Operating System: Linux
• Using an IDE?: Yes: Eclipse with Espressif IDF Plugins
• Power Supply: USB

Problem Description

When using the spi_master driver with two devices on the same bus - one half-duplex and one full-duplex - the driver seems to drive the SPI device for longer than expected: When sending a first transaction to the half-duplex device and then sending a second transaction to the full-duplex device, the driver holds SCK low for longer than expected on the second transaction: It seems like it treats the second transaction as half-duplex, even though the device is configured as full-duplex.

To reproduce the issue, no actual SPI device has to be connected to the bus, since it is reproducible without any external device interaction.

I reported this before on the forums, but got no response.

Expected Behavior

The second transaction should be treated as a proper full-duplex one. In the code below, the second transaction should only last for a length of three bytes: one address byte and two data bytes (t.length = 16).

Actual Behavior

The second transaction looks like a half-duplex one. In the code below, it lasts for 5 bytes: One address byte, two bytes of proper data, and (presumably) the extra two bytes for the response (t.rxlength = 16).

The following shows the two transactions on the bus from the example code below on a logic analyzer:

Steps to reproduce

1. Change the TEST_*_PIN defines in the example code below to match the board config.
2. Compile and flash the minimal example code below.
3. (No actual SPI devices need to be connected to reproduce the behavior.)
4. Watch the SCK and MOSI lines on the SPI bus.

Code to reproduce this issue

Minimal example here

Debug Logs

I (28) boot: ESP-IDF v4.0-beta2-dirty 2nd stage bootloader
I (29) boot: compile time 18:44:54
I (29) boot: Enabling RNG early entropy source...
I (34) boot: SPI Speed : 40MHz
I (38) boot: SPI Mode : DIO
I (42) boot: SPI Flash Size : 2MB
I (46) boot: Partition Table:
I (50) boot: ## Label Usage Type ST Offset Length
I (57) boot: 0 nvs WiFi data 01 02 00009000 00006000
I (65) boot: 1 phy_init RF data 01 01 0000f000 00001000
I (72) boot: 2 factory factory app 00 00 00010000 00100000
I (80) boot: End of partition table
I (84) esp_image: segment 0: paddr=0x00010020 vaddr=0x3f400020 size=0x0717c ( 29052) map
I (103) esp_image: segment 1: paddr=0x000171a4 vaddr=0x3ffb0000 size=0x0207c ( 8316) load
I (107) esp_image: segment 2: paddr=0x00019228 vaddr=0x40080000 size=0x00400 ( 1024) load
0x40080000: _WindowOverflow4 at /opt/esp-idf/components/freertos/xtensa_vectors.S:1778

I (111) esp_image: segment 3: paddr=0x00019630 vaddr=0x40080400 size=0x069e0 ( 27104) load
I (131) esp_image: segment 4: paddr=0x00020018 vaddr=0x400d0018 size=0x14640 ( 83520) map
0x400d0018: _stext at ??:?

I (161) esp_image: segment 5: paddr=0x00034660 vaddr=0x40086de0 size=0x03aa0 ( 15008) load
0x40086de0: rtc_clk_cpu_freq_get_config at /opt/esp-idf/components/soc/esp32/rtc_clk.c:650

I (174) boot: Loaded app from partition at offset 0x10000
I (174) boot: Disabling RNG early entropy source...
I (175) cpu_start: Pro cpu up.
I (178) cpu_start: Application information:
I (183) cpu_start: Project name: app-template
I (189) cpu_start: App version: 1
I (193) cpu_start: Compile time: Jan 4 2020 18:44:43
I (199) cpu_start: ELF file SHA256: 78fef31c0db07f90...
I (205) cpu_start: ESP-IDF: v4.0-beta2-dirty
I (211) cpu_start: Starting app cpu, entry point is 0x400810a0
0x400810a0: call_start_cpu1 at /opt/esp-idf/components/esp32/cpu_start.c:272

I (0) cpu_start: App cpu up.
I (221) heap_init: Initializing. RAM available for dynamic allocation:
I (228) heap_init: At 3FFAE6E0 len 00001920 (6 KiB): DRAM
I (234) heap_init: At 3FFB30A8 len 0002CF58 (179 KiB): DRAM
I (240) heap_init: At 3FFE0440 len 00003AE0 (14 KiB): D/IRAM
I (247) heap_init: At 3FFE4350 len 0001BCB0 (111 KiB): D/IRAM
I (253) heap_init: At 4008A880 len 00015780 (85 KiB): IRAM
I (259) cpu_start: Pro cpu start user code
I (277) spi_flash: detected chip: generic
I (278) spi_flash: flash io: dio
W (278) spi_flash: Detected size(4096k) larger than the size in the binary image header(2048k). Using the size in the binary image header.
I (289) cpu_start: Chip Revision: 1
W (293) cpu_start: Chip revision is higher than the one configured in menuconfig. Suggest to upgrade it.
I (303) cpu_start: Starting scheduler on PRO CPU.
I (0) cpu_start: Starting scheduler on APP CPU.
Starting in 2s...

No further logs are generated. In particular, there are no errors or warnings about the SPI transactions.

[Wielebny666]

I found solution.
master_cs_pol must be initialized when adding the device to the spi bus.

file: spi_master.c
in spi_bus_add_device method

    //Set CS pin, CS options
    if (dev_config->spics_io_num >= 0) {
        spicommon_cs_initialize(host, dev_config->spics_io_num, freecs, !(spihost[host]->flags&SPICOMMON_BUSFLAG_IOMUX_PINS));
        hal->positive_cs = dev_config->flags & SPI_DEVICE_POSITIVE_CS ? 1 : 0;
        spi_ll_master_set_pos_cs(hal->hw, freecs, hal->positive_cs);
    }

in spi_setup_device

hal->positive_cs = dev->cfg.flags & SPI_DEVICE_POSITIVE_CS ? 1 : 0;

file: spi_ll.h

static inline void spi_ll_master_set_pos_cs(spi_dev_t *hw, int cs, uint32_t pos_cs)
{
    if (pos_cs) {
        hw->pin.master_cs_pol |= (1 << cs);
    } else {
        hw->pin.master_cs_pol &= ~(1 << cs);
    }
}

Important!!
All devices must be added to the same spi line before use.
Tested on 4.0.1

[Wielebny666]

I think, that problem is in 3.3.2
~ missing

    if (dev_config->flags&SPI_DEVICE_CLK_AS_CS) {
        spihost[host]->hw->pin.master_ck_sel |= (1<<freecs);
    } else {
        spihost[host]->hw->pin.master_ck_sel &= ~(1<<freecs);
    }
    if (dev_config->flags&SPI_DEVICE_POSITIVE_CS) {
        spihost[host]->hw->pin.master_cs_pol |= (1<<freecs);
    } else {
        spihost[host]->hw->pin.master_cs_pol &= ~(1<<freecs);
    }

[Wielebny666]

Anyone repair this error?

[Wielebny666]

The problem still exists in v4.0 :-(

[ginkgm]

related to: #5490