spi_loopback fails on frdm_rw612 with DMA and/or cs_loopback

[fnadeau]

Describe the bug

The spi_loopback test fails running on frdm_rw612 when DMA is enabled and when cs_loopback is activated.

Regression

• This is a regression.

Steps to reproduce

On the FRDM-RW612 board, connect J1 pins 2 and 4 to enable SPI loopback. Connect J2 pins 2 and 6 to loop CS pin.
Using cdc3a52, build the test

west build -b frdm_rw612 tests/drivers/spi/spi_loopback
west flash

This works fine, no log attached.

Enabling CS loopback fails

west build -b frdm_rw612 tests/drivers/spi/spi_loopback -- -DEXTRA_DTC_OVERLAY_FILE=/workdir/deps/zephyr/tests/drivers/spi/spi_loopback/overlay-cs-loopback-gpio.overlay
west flash

Log

*** Booting Zephyr OS build v4.2.0-2732-gcdc3a5264258 ***
SPI test on buffers TX/RX 0x10044de0/0x10044dc0, frame size = 8
Polling...Running TESTSUITE spi_extra_api_features
===================================================================
START - test_spi_hold_on_cs
Expected 1 CS triggers, got 2
    Assertion failed at WEST_TOPDIR/deps/zephyr/tests/drivers/spi/spi_loopback/src/spi.c:1030: spi_extra_api_features_test_spi_hold_on_cs: (ret is true)
SPI transceive failed, code -5
 FAIL - test_spi_hold_on_cs in 0.020 seconds
===================================================================
START - test_spi_lock_release
Expected 2 CS triggers, got 1
    Assertion failed at WEST_TOPDIR/deps/zephyr/tests/drivers/spi/spi_loopback/src/spi.c:222: spi_loopback_transceive: spi_loopback_gpio_cs_loopback_check(expected_cs_count) is non-zero

 FAIL - test_spi_lock_release in 0.020 seconds
===================================================================
TESTSUITE spi_extra_api_features failed.
Running TESTSUITE spi_extra_api_features
===================================================================
START - test_spi_hold_on_cs
Expected 1 CS triggers, got 2
    Assertion failed at WEST_TOPDIR/deps/zephyr/tests/drivers/spi/spi_loopback/src/spi.c:1030: spi_extra_api_features_test_spi_hold_on_cs: (ret is true)
SPI transceive failed, code -5
 FAIL - test_spi_hold_on_cs in 0.020 seconds
===================================================================
START - test_spi_lock_release
Expected 2 CS triggers, got 1
    Assertion failed at WEST_TOPDIR/deps/zephyr/tests/drivers/spi/spi_loopback/src/spi.c:222: spi_loopback_transceive: spi_loopback_gpio_cs_loopback_check(expected_cs_count) is non-zero

 FAIL - test_spi_lock_release in 0.020 seconds
===================================================================
TESTSUITE spi_extra_api_features failed.
Running TESTSUITE spi_loopback
===================================================================
Testing loopback spec: SLOW
START - test_nop_nil_bufs
 PASS - test_nop_nil_bufs in 0.001 seconds
===================================================================
START - test_spi_async_call
 PASS - test_spi_async_call in 0.133 seconds
===================================================================
START - test_spi_complete_large_transfers
 PASS - test_spi_complete_large_transfers in 0.132 seconds
===================================================================
START - test_spi_complete_loop_mode_0
 PASS - test_spi_complete_loop_mode_0 in 0.001 seconds
===================================================================
START - test_spi_complete_loop_mode_1
 PASS - test_spi_complete_loop_mode_1 in 0.001 seconds
===================================================================
START - test_spi_complete_loop_mode_2
 PASS - test_spi_complete_loop_mode_2 in 0.001 seconds
===================================================================
START - test_spi_complete_loop_mode_3
 PASS - test_spi_complete_loop_mode_3 in 0.001 seconds
===================================================================
START - test_spi_complete_multiple
 PASS - test_spi_complete_multiple in 0.002 seconds
===================================================================
START - test_spi_complete_multiple_timed
Transfer took 924 us vs theoretical minimum 864 us
Latency measurement: 60 us
 PASS - test_spi_complete_multiple_timed in 0.009 seconds
===================================================================
START - test_spi_concurrent_transfer_different_spec
 PASS - test_spi_concurrent_transfer_different_spec in 0.003 seconds
===================================================================
START - test_spi_concurrent_transfer_same_spec
 PASS - test_spi_concurrent_transfer_same_spec in 0.003 seconds
===================================================================
START - test_spi_deinit
  zephyr,user miso-gpios or mosi-gpios are not defined
 SKIP - test_spi_deinit in 0.005 seconds
===================================================================
START - test_spi_null_rx_buf_set
 PASS - test_spi_null_rx_buf_set in 0.001 seconds
===================================================================
START - test_spi_null_tx_buf
 PASS - test_spi_null_tx_buf in 0.001 seconds
===================================================================
START - test_spi_null_tx_buf_set
 PASS - test_spi_null_tx_buf_set in 0.001 seconds
===================================================================
START - test_spi_null_tx_rx_buf_set
 PASS - test_spi_null_tx_rx_buf_set in 0.001 seconds
===================================================================
START - test_spi_rx_bigger_than_tx
Expected 2 CS triggers, got 4
    Assertion failed at WEST_TOPDIR/deps/zephyr/tests/drivers/spi/spi_loopback/src/spi.c:222: spi_loopback_transceive: spi_loopback_gpio_cs_loopback_check(expected_cs_count) is non-zero

 FAIL - test_spi_rx_bigger_than_tx in 0.020 seconds
===================================================================
START - test_spi_rx_every_4
Expected 2 CS triggers, got 4
    Assertion failed at WEST_TOPDIR/deps/zephyr/tests/drivers/spi/spi_loopback/src/spi.c:222: spi_loopback_transceive: spi_loopback_gpio_cs_loopback_check(expected_cs_count) is non-zero

 FAIL - test_spi_rx_every_4 in 0.020 seconds
===================================================================
START - test_spi_rx_half_end
Expected 2 CS triggers, got 4
    Assertion failed at WEST_TOPDIR/deps/zephyr/tests/drivers/spi/spi_loopback/src/spi.c:222: spi_loopback_transceive: spi_loopback_gpio_cs_loopback_check(expected_cs_count) is non-zero

 FAIL - test_spi_rx_half_end in 0.020 seconds
===================================================================
START - test_spi_rx_half_start
Expected 2 CS triggers, got 4
    Assertion failed at WEST_TOPDIR/deps/zephyr/tests/drivers/spi/spi_loopback/src/spi.c:222: spi_loopback_transceive: spi_loopback_gpio_cs_loopback_check(expected_cs_count) is non-zero

 FAIL - test_spi_rx_half_start in 0.020 seconds
===================================================================
START - test_spi_same_buf_cmd
 PASS - test_spi_same_buf_cmd in 0.001 seconds
===================================================================
START - test_spi_word_size_16
 PASS - test_spi_word_size_16 in 0.001 seconds
===================================================================
START - test_spi_word_size_24
E: Word size 24 is greater than 16
Spi config invalid for this controller
 SKIP - test_spi_word_size_24 in 0.007 seconds
===================================================================
START - test_spi_word_size_32
E: Word size 32 is greater than 16
Spi config invalid for this controller
 SKIP - test_spi_word_size_32 in 0.007 seconds
===================================================================
START - test_spi_word_size_7
 PASS - test_spi_word_size_7 in 0.001 seconds
===================================================================
START - test_spi_word_size_9
 PASS - test_spi_word_size_9 in 0.001 seconds
===================================================================
START - test_spi_write_back
 PASS - test_spi_write_back in 0.001 seconds
===================================================================
TESTSUITE spi_loopback failed.
Running TESTSUITE spi_loopback
===================================================================
Testing loopback spec: FAST
START - test_nop_nil_bufs
 PASS - test_nop_nil_bufs in 0.001 seconds
===================================================================
START - test_spi_async_call
 PASS - test_spi_async_call in 0.005 seconds
===================================================================
START - test_spi_complete_large_transfers
Expected 2 CS triggers, got 1
    Assertion failed at WEST_TOPDIR/deps/zephyr/tests/drivers/spi/spi_loopback/src/spi.c:222: spi_loopback_transceive: spi_loopback_gpio_cs_loopback_check(expected_cs_count) is non-zero

 FAIL - test_spi_complete_large_transfers in 0.024 seconds
===================================================================
START - test_spi_complete_loop_mode_0
Expected 2 CS triggers, got 1
    Assertion failed at WEST_TOPDIR/deps/zephyr/tests/drivers/spi/spi_loopback/src/spi.c:222: spi_loopback_transceive: spi_loopback_gpio_cs_loopback_check(expected_cs_count) is non-zero

 FAIL - test_spi_complete_loop_mode_0 in 0.020 seconds
===================================================================
START - test_spi_complete_loop_mode_1
Expected 2 CS triggers, got 1
    Assertion failed at WEST_TOPDIR/deps/zephyr/tests/drivers/spi/spi_loopback/src/spi.c:222: spi_loopback_transceive: spi_loopback_gpio_cs_loopback_check(expected_cs_count) is non-zero

 FAIL - test_spi_complete_loop_mode_1 in 0.020 seconds
===================================================================
START - test_spi_complete_loop_mode_2
Expected 2 CS triggers, got 1
    Assertion failed at WEST_TOPDIR/deps/zephyr/tests/drivers/spi/spi_loopback/src/spi.c:222: spi_loopback_transceive: spi_loopback_gpio_cs_loopback_check(expected_cs_count) is non-zero

 FAIL - test_spi_complete_loop_mode_2 in 0.020 seconds
===================================================================
START - test_spi_complete_loop_mode_3
Expected 2 CS triggers, got 1
    Assertion failed at WEST_TOPDIR/deps/zephyr/tests/drivers/spi/spi_loopback/src/spi.c:222: spi_loopback_transceive: spi_loopback_gpio_cs_loopback_check(expected_cs_count) is non-zero

 FAIL - test_spi_complete_loop_mode_3 in 0.020 seconds
===================================================================
START - test_spi_complete_multiple
Expected 2 CS triggers, got 1
    Assertion failed at WEST_TOPDIR/deps/zephyr/tests/drivers/spi/spi_loopback/src/spi.c:222: spi_loopback_transceive: spi_loopback_gpio_cs_loopback_check(expected_cs_count) is non-zero

 FAIL - test_spi_complete_multiple in 0.020 seconds
===================================================================
START - test_spi_complete_multiple_timed
Expected 2 CS triggers, got 1
    Assertion failed at WEST_TOPDIR/deps/zephyr/tests/drivers/spi/spi_loopback/src/spi.c:222: spi_loopback_transceive: spi_loopback_gpio_cs_loopback_check(expected_cs_count) is non-zero

 FAIL - test_spi_complete_multiple_timed in 0.020 seconds
===================================================================
START - test_spi_concurrent_transfer_different_spec
 PASS - test_spi_concurrent_transfer_different_spec in 0.001 seconds
===================================================================
START - test_spi_concurrent_transfer_same_spec
 PASS - test_spi_concurrent_transfer_same_spec in 0.001 seconds
===================================================================
START - test_spi_deinit
  zephyr,user miso-gpios or mosi-gpios are not defined
 SKIP - test_spi_deinit in 0.005 seconds
===================================================================
START - test_spi_null_rx_buf_set
Expected 2 CS triggers, got 1
    Assertion failed at WEST_TOPDIR/deps/zephyr/tests/drivers/spi/spi_loopback/src/spi.c:222: spi_loopback_transceive: spi_loopback_gpio_cs_loopback_check(expected_cs_count) is non-zero

 FAIL - test_spi_null_rx_buf_set in 0.020 seconds
===================================================================
START - test_spi_null_tx_buf
Expected 2 CS triggers, got 1
    Assertion failed at WEST_TOPDIR/deps/zephyr/tests/drivers/spi/spi_loopback/src/spi.c:222: spi_loopback_transceive: spi_loopback_gpio_cs_loopback_check(expected_cs_count) is non-zero

 FAIL - test_spi_null_tx_buf in 0.020 seconds
===================================================================
START - test_spi_null_tx_buf_set
Expected 2 CS triggers, got 1
    Assertion failed at WEST_TOPDIR/deps/zephyr/tests/drivers/spi/spi_loopback/src/spi.c:222: spi_loopback_transceive: spi_loopback_gpio_cs_loopback_check(expected_cs_count) is non-zero

 FAIL - test_spi_null_tx_buf_set in 0.020 seconds
===================================================================
START - test_spi_null_tx_rx_buf_set
 PASS - test_spi_null_tx_rx_buf_set in 0.001 seconds
===================================================================
START - test_spi_rx_bigger_than_tx
Expected 2 CS triggers, got 1
    Assertion failed at WEST_TOPDIR/deps/zephyr/tests/drivers/spi/spi_loopback/src/spi.c:222: spi_loopback_transceive: spi_loopback_gpio_cs_loopback_check(expected_cs_count) is non-zero

 FAIL - test_spi_rx_bigger_than_tx in 0.020 seconds
===================================================================
START - test_spi_rx_every_4
 PASS - test_spi_rx_every_4 in 0.001 seconds
===================================================================
START - test_spi_rx_half_end
 PASS - test_spi_rx_half_end in 0.001 seconds
===================================================================
START - test_spi_rx_half_start
Expected 2 CS triggers, got 1
    Assertion failed at WEST_TOPDIR/deps/zephyr/tests/drivers/spi/spi_loopback/src/spi.c:222: spi_loopback_transceive: spi_loopback_gpio_cs_loopback_check(expected_cs_count) is non-zero

 FAIL - test_spi_rx_half_start in 0.020 seconds
===================================================================
START - test_spi_same_buf_cmd
Expected 2 CS triggers, got 1
    Assertion failed at WEST_TOPDIR/deps/zephyr/tests/drivers/spi/spi_loopback/src/spi.c:222: spi_loopback_transceive: spi_loopback_gpio_cs_loopback_check(expected_cs_count) is non-zero

 FAIL - test_spi_same_buf_cmd in 0.020 seconds
===================================================================
START - test_spi_word_size_16
Expected 2 CS triggers, got 1
    Assertion failed at WEST_TOPDIR/deps/zephyr/tests/drivers/spi/spi_loopback/src/spi.c:222: spi_loopback_transceive: spi_loopback_gpio_cs_loopback_check(expected_cs_count) is non-zero

 FAIL - test_spi_word_size_16 in 0.020 seconds
===================================================================
START - test_spi_word_size_24
E: Word size 24 is greater than 16
Spi config invalid for this controller
 SKIP - test_spi_word_size_24 in 0.007 seconds
===================================================================
START - test_spi_word_size_32
E: Word size 32 is greater than 16
Spi config invalid for this controller
 SKIP - test_spi_word_size_32 in 0.007 seconds
===================================================================
START - test_spi_word_size_7
Expected 2 CS triggers, got 1
    Assertion failed at WEST_TOPDIR/deps/zephyr/tests/drivers/spi/spi_loopback/src/spi.c:222: spi_loopback_transceive: spi_loopback_gpio_cs_loopback_check(expected_cs_count) is non-zero

 FAIL - test_spi_word_size_7 in 0.020 seconds
===================================================================
START - test_spi_word_size_9
Expected 2 CS triggers, got 1
    Assertion failed at WEST_TOPDIR/deps/zephyr/tests/drivers/spi/spi_loopback/src/spi.c:222: spi_loopback_transceive: spi_loopback_gpio_cs_loopback_check(expected_cs_count) is non-zero

 FAIL - test_spi_word_size_9 in 0.020 seconds
===================================================================
START - test_spi_write_back
Expected 2 CS triggers, got 1
    Assertion failed at WEST_TOPDIR/deps/zephyr/tests/drivers/spi/spi_loopback/src/spi.c:222: spi_loopback_transceive: spi_loopback_gpio_cs_loopback_check(expected_cs_count) is non-zero

 FAIL - test_spi_write_back in 0.020 seconds
===================================================================
TESTSUITE spi_loopback failed.

------ TESTSUITE SUMMARY START ------

SUITE FAIL -   0.00% [spi_extra_api_features]: pass = 0, fail = 2, skip = 0, total = 2 duration = 0.040 seconds
 - FAIL - [spi_extra_api_features.test_spi_hold_on_cs] duration = 0.020 seconds
 - FAIL - [spi_extra_api_features.test_spi_lock_release] duration = 0.020 seconds

SUITE FAIL -  20.83% [spi_loopback]: pass = 5, fail = 19, skip = 3, total = 27 duration = 0.652 seconds
 - PASS - [spi_loopback.test_nop_nil_bufs] duration = 0.001 seconds
 - PASS - [spi_loopback.test_spi_async_call] duration = 0.133 seconds
 - FLAKY - [spi_loopback.test_spi_complete_large_transfers] - (Failed 1 of 2 attempts) - duration = 0.132 seconds
 - FLAKY - [spi_loopback.test_spi_complete_loop_mode_0] - (Failed 1 of 2 attempts) - duration = 0.020 seconds
 - FLAKY - [spi_loopback.test_spi_complete_loop_mode_1] - (Failed 1 of 2 attempts) - duration = 0.020 seconds
 - FLAKY - [spi_loopback.test_spi_complete_loop_mode_2] - (Failed 1 of 2 attempts) - duration = 0.020 seconds
 - FLAKY - [spi_loopback.test_spi_complete_loop_mode_3] - (Failed 1 of 2 attempts) - duration = 0.020 seconds
 - FLAKY - [spi_loopback.test_spi_complete_multiple] - (Failed 1 of 2 attempts) - duration = 0.020 seconds
 - FLAKY - [spi_loopback.test_spi_complete_multiple_timed] - (Failed 1 of 2 attempts) - duration = 0.020 seconds
 - PASS - [spi_loopback.test_spi_concurrent_transfer_different_spec] duration = 0.003 seconds
 - PASS - [spi_loopback.test_spi_concurrent_transfer_same_spec] duration = 0.003 seconds
 - SKIP - [spi_loopback.test_spi_deinit] duration = 0.005 seconds
 - FLAKY - [spi_loopback.test_spi_null_rx_buf_set] - (Failed 1 of 2 attempts) - duration = 0.020 seconds
 - FLAKY - [spi_loopback.test_spi_null_tx_buf] - (Failed 1 of 2 attempts) - duration = 0.020 seconds
 - FLAKY - [spi_loopback.test_spi_null_tx_buf_set] - (Failed 1 of 2 attempts) - duration = 0.020 seconds
 - PASS - [spi_loopback.test_spi_null_tx_rx_buf_set] duration = 0.001 seconds
 - FAIL - [spi_loopback.test_spi_rx_bigger_than_tx] duration = 0.020 seconds
 - FLAKY - [spi_loopback.test_spi_rx_every_4] - (Failed 1 of 2 attempts) - duration = 0.020 seconds
 - FLAKY - [spi_loopback.test_spi_rx_half_end] - (Failed 1 of 2 attempts) - duration = 0.020 seconds
 - FAIL - [spi_loopback.test_spi_rx_half_start] duration = 0.020 seconds
 - FLAKY - [spi_loopback.test_spi_same_buf_cmd] - (Failed 1 of 2 attempts) - duration = 0.020 seconds
 - FLAKY - [spi_loopback.test_spi_word_size_16] - (Failed 1 of 2 attempts) - duration = 0.020 seconds
 - SKIP - [spi_loopback.test_spi_word_size_24] duration = 0.007 seconds
 - SKIP - [spi_loopback.test_spi_word_size_32] duration = 0.007 seconds
 - FLAKY - [spi_loopback.test_spi_word_size_7] - (Failed 1 of 2 attempts) - duration = 0.020 seconds
 - FLAKY - [spi_loopback.test_spi_word_size_9] - (Failed 1 of 2 attempts) - duration = 0.020 seconds
 - FLAKY - [spi_loopback.test_spi_write_back] - (Failed 1 of 2 attempts) - duration = 0.020 seconds

------ TESTSUITE SUMMARY END ------

===================================================================
PROJECT EXECUTION FAILED

Enabling DMA fails catastrophically

echo "CONFIG_SPI_MCUX_FLEXCOMM_DMA=y" > /workdir/deps/zephyr/tests/drivers/spi/spi_loopback/overlay-mcux-flexcomm-spi-dma.conf
west build -b frdm_rw612 tests/drivers/spi/spi_loopback -- -DEXTRA_CONF_FILE=/workdir/deps/zephyr/tests/drivers/spi/spi_loopback/overlay-mcux-flexcomm-spi-dma.conf
west flash

Log

*** Booting Zephyr OS build v4.2.0-2732-gcdc3a5264258 ***
SPI test on buffers TX/RX 0x100458a0/0x10045880, frame size = 8, DMA enabled (without CONFIG_NOCACHE_MEMORY)
Polling...Running TESTSUITE spi_extra_api_features
===================================================================
START - test_spi_hold_on_cs
 PASS - test_spi_hold_on_cs in 0.002 seconds
===================================================================
START - test_spi_lock_release
 PASS - test_spi_lock_release in 0.001 seconds
===================================================================
TESTSUITE spi_extra_api_features succeeded
Running TESTSUITE spi_extra_api_features
===================================================================
START - test_spi_hold_on_cs
 PASS - test_spi_hold_on_cs in 0.002 seconds
===================================================================
START - test_spi_lock_release
 PASS - test_spi_lock_release in 0.001 seconds
===================================================================
TESTSUITE spi_extra_api_features succeeded
Running TESTSUITE spi_loopback
===================================================================
Testing loopback spec: SLOW
START - test_nop_nil_bufs
ASSERTION FAIL [0] @ WEST_TOPDIR/deps/zephyr/lib/libc/picolibc/assert.c:27
E: r0/a1:  0x00000004  r1/a2:  0x0000001b  r2/a3:  0x00000006
E: r3/a4:  0x00000004 r12/ip:  0x00000000 r14/lr:  0x180049d1
E:  xpsr:  0x21000000
E: Faulting instruction address (r15/pc): 0x1800a84a
E: >>> ZEPHYR FATAL ERROR 4: Kernel panic on CPU 0
E: Current thread: 0x10048280 (test_nop_nil_bufs)
E: Halting system

Relevant log output

Impact

Functional Limitation – Some features not working as expected, but system usable.

Environment

• OS: Linux
• zephyr-sdk-0.17.4
• cdc3a52

Additional Context

transceive_dma doesn't seem to like having no buffer at all to transfer. This patch fix the zephyr assert.

diff --git a/drivers/spi/spi_mcux_flexcomm.c b/drivers/spi/spi_mcux_flexcomm.c
index 8a9875243db..5d3fa4662d1 100644
--- a/drivers/spi/spi_mcux_flexcomm.c
+++ b/drivers/spi/spi_mcux_flexcomm.c
@@ -657,6 +657,14 @@ static int transceive_dma(const struct device *dev,
        pm_policy_device_power_lock_get(dev);
 
        spi_context_lock(&data->ctx, asynchronous, cb, userdata, spi_cfg);
+
+       spi_context_buffers_setup(&data->ctx, tx_bufs, rx_bufs, 1);
+
+       if (data->ctx.tx_count == 0 && data->ctx.rx_count == 0)
+       {
+               ret = 0; // Not an actual error, no data to transfer
+               goto out;
+       }
 
        data->word_size_bits = word_size;
        data->word_size_bytes = (word_size > 8) ? (sizeof(uint16_t)) : (sizeof(uint8_t));
@@ -665,8 +673,6 @@ static int transceive_dma(const struct device *dev,
                goto out;
        }
 
-       spi_context_buffers_setup(&data->ctx, tx_bufs, rx_bufs, 1);
-
        spi_context_cs_control(&data->ctx, true);
 
        /* Clear FIFOs and any previous errors before transfer */

------ TESTSUITE SUMMARY START ------

SUITE PASS - 100.00% [spi_extra_api_features]: pass = 2, fail = 0, skip = 0, total = 2 duration = 0.003 seconds
 - PASS - [spi_extra_api_features.test_spi_hold_on_cs] duration = 0.002 seconds
 - PASS - [spi_extra_api_features.test_spi_lock_release] duration = 0.001 seconds

SUITE FAIL -  91.67% [spi_loopback]: pass = 22, fail = 2, skip = 3, total = 27 duration = 0.358 seconds
 - PASS - [spi_loopback.test_nop_nil_bufs] duration = 0.001 seconds
 - PASS - [spi_loopback.test_spi_async_call] duration = 0.133 seconds
 - PASS - [spi_loopback.test_spi_complete_large_transfers] duration = 0.132 seconds
 - PASS - [spi_loopback.test_spi_complete_loop_mode_0] duration = 0.001 seconds
 - PASS - [spi_loopback.test_spi_complete_loop_mode_1] duration = 0.001 seconds
 - PASS - [spi_loopback.test_spi_complete_loop_mode_2] duration = 0.001 seconds
 - PASS - [spi_loopback.test_spi_complete_loop_mode_3] duration = 0.001 seconds
 - PASS - [spi_loopback.test_spi_complete_multiple] duration = 0.002 seconds
 - PASS - [spi_loopback.test_spi_complete_multiple_timed] duration = 0.009 seconds
 - PASS - [spi_loopback.test_spi_concurrent_transfer_different_spec] duration = 0.003 seconds
 - PASS - [spi_loopback.test_spi_concurrent_transfer_same_spec] duration = 0.003 seconds
 - SKIP - [spi_loopback.test_spi_deinit] duration = 0.005 seconds
 - PASS - [spi_loopback.test_spi_null_rx_buf_set] duration = 0.001 seconds
 - PASS - [spi_loopback.test_spi_null_tx_buf] duration = 0.001 seconds
 - PASS - [spi_loopback.test_spi_null_tx_buf_set] duration = 0.001 seconds
 - PASS - [spi_loopback.test_spi_null_tx_rx_buf_set] duration = 0.001 seconds
 - PASS - [spi_loopback.test_spi_rx_bigger_than_tx] duration = 0.001 seconds
 - PASS - [spi_loopback.test_spi_rx_every_4] duration = 0.001 seconds
 - PASS - [spi_loopback.test_spi_rx_half_end] duration = 0.001 seconds
 - PASS - [spi_loopback.test_spi_rx_half_start] duration = 0.001 seconds
 - PASS - [spi_loopback.test_spi_same_buf_cmd] duration = 0.001 seconds
 - FAIL - [spi_loopback.test_spi_word_size_16] duration = 0.021 seconds
 - SKIP - [spi_loopback.test_spi_word_size_24] duration = 0.007 seconds
 - SKIP - [spi_loopback.test_spi_word_size_32] duration = 0.007 seconds
 - PASS - [spi_loopback.test_spi_word_size_7] duration = 0.001 seconds
 - FAIL - [spi_loopback.test_spi_word_size_9] duration = 0.020 seconds
 - PASS - [spi_loopback.test_spi_write_back] duration = 0.001 seconds

------ TESTSUITE SUMMARY END ------

===================================================================
PROJECT EXECUTION FAILED

test_spi_word_size_16 fails in memcmp(), buffer_tx_16 and buffer_rx_16 are identical except for buffer_rx_16[11] (last one) which is 0 rather than 0x5a5a. Same for test_spi_word_size_9, fails in memcmp() on last byte, 0 rather than 0x5a.

[decsny]

Hi, first of all I will point out that this platform is not enabled to run this test, in fact, there are currently only two platforms in zephyr that are enabled to run this testcase (frdm_mcxn947 and mimxrt1050_evk).

With that said, we probably ultimately want this testcase to run on this platform and others.

When I run this case with the reproduce steps provided (including adding the mentioned patch), I do indeed see the first case (no cs loopback overlay added) does pass. But adding the cs loopback case overlay does cause failures. But I do not see the same set of failures as reported in this issue. This is the test summary output I get:

------ TESTSUITE SUMMARY START ------

SUITE FAIL -   0.00% [spi_extra_api_features]: pass = 0, fail = 2, skip = 0, total = 2 duration = 0.040 s
econds
 - FAIL - [spi_extra_api_features.test_spi_hold_on_cs] duration = 0.020 seconds
 - FAIL - [spi_extra_api_features.test_spi_lock_release] duration = 0.020 seconds

SUITE FAIL -  25.00% [spi_loopback]: pass = 6, fail = 18, skip = 3, total = 27 duration = 0.625 seconds
 - PASS - [spi_loopback.test_nop_nil_bufs] duration = 0.001 seconds
 - PASS - [spi_loopback.test_spi_async_call] duration = 0.133 seconds
 - FLAKY - [spi_loopback.test_spi_complete_large_transfers] - (Failed 1 of 2 attempts) - duration = 0.132
 seconds
 - FLAKY - [spi_loopback.test_spi_complete_loop_mode_0] - (Failed 1 of 2 attempts) - duration = 0.020 sec
onds
 - FLAKY - [spi_loopback.test_spi_complete_loop_mode_1] - (Failed 1 of 2 attempts) - duration = 0.019 sec
onds
 - FLAKY - [spi_loopback.test_spi_complete_loop_mode_2] - (Failed 1 of 2 attempts) - duration = 0.020 sec
onds
 - FLAKY - [spi_loopback.test_spi_complete_loop_mode_3] - (Failed 1 of 2 attempts) - duration = 0.019 sec
onds
 - FLAKY - [spi_loopback.test_spi_complete_multiple] - (Failed 1 of 2 attempts) - duration = 0.020 second
s
 - FLAKY - [spi_loopback.test_spi_complete_multiple_timed] - (Failed 1 of 2 attempts) - duration = 0.019
seconds
 - PASS - [spi_loopback.test_spi_concurrent_transfer_different_spec] duration = 0.003 seconds
 - PASS - [spi_loopback.test_spi_concurrent_transfer_same_spec] duration = 0.003 seconds
 - SKIP - [spi_loopback.test_spi_deinit] duration = 0.005 seconds
 - FLAKY - [spi_loopback.test_spi_null_rx_buf_set] - (Failed 1 of 2 attempts) - duration = 0.019 seconds
 - FLAKY - [spi_loopback.test_spi_null_tx_buf] - (Failed 1 of 2 attempts) - duration = 0.019 seconds
 - FLAKY - [spi_loopback.test_spi_null_tx_buf_set] - (Failed 1 of 2 attempts) - duration = 0.019 seconds
 - PASS - [spi_loopback.test_spi_null_tx_rx_buf_set] duration = 0.001 seconds
 - FAIL - [spi_loopback.test_spi_rx_bigger_than_tx] duration = 0.020 seconds
 - FLAKY - [spi_loopback.test_spi_rx_every_4] - (Failed 1 of 2 attempts) - duration = 0.020 seconds
 - FLAKY - [spi_loopback.test_spi_rx_half_end] - (Failed 1 of 2 attempts) - duration = 0.020 seconds
 - FAIL - [spi_loopback.test_spi_rx_half_start] duration = 0.020 seconds
 - PASS - [spi_loopback.test_spi_same_buf_cmd] duration = 0.001 seconds
 - FLAKY - [spi_loopback.test_spi_word_size_16] - (Failed 1 of 2 attempts) - duration = 0.019 seconds
 - SKIP - [spi_loopback.test_spi_word_size_24] duration = 0.007 seconds
 - SKIP - [spi_loopback.test_spi_word_size_32] duration = 0.007 seconds
 - FLAKY - [spi_loopback.test_spi_word_size_7] - (Failed 1 of 2 attempts) - duration = 0.020 seconds
 - FLAKY - [spi_loopback.test_spi_word_size_9] - (Failed 1 of 2 attempts) - duration = 0.020 seconds
 - FLAKY - [spi_loopback.test_spi_write_back] - (Failed 1 of 2 attempts) - duration = 0.019 seconds

------ TESTSUITE SUMMARY END ------

In fact, many other test case fail including the hold_on_cs and lock cases, whereas the failing ones you saw, did pass some of the time (on the slower frequency run). I got this same log on the commit you specified as well as latest main (since 4.3 rc1)

Did you make any other modification to the board or configurations to see the specific results?

[decsny]

I linked a PR which fixes most of the failures I was seeing and also gets the two specific cases mentioned in the original post of this ticket to completely pass instead of how I saw them being flaky.