Slow SPI performance with zephyr

[dwalton65]

SDK Environment: nRF Connect SDK v1.7.1

Target: Decawave DWM1001-DEV. This uses the nRF52832

A 5 byte SPI transfer is taking about 17us when using the nordic spim drivers and about 56us when using the zephyr spim drivers.

SPI CLK frequency = 8M

Would this be considered normal? The slow speed of the zephyr SPI drivers is causing problems in my application.

The zephyr drivers seem to be stable, but slow.

I set and clear a gpio testpin before and after the SPI transfer so I can measure the timing.

SPI timing with the nordic drivers

SPI timing with the zephyr drivers

"nrfx_spim.zip" uses the nordic drivers

"zephyr_spim.zip" uses the zephyr drivers

6763.nrfx_spim.zipzephyr_spim.zip

[dwalton65]

The following might read better than my last post:

Saleh said:

How do you set the SS signal?

I had attached the source code for the two test cases in the first post.

I am using Zephyr OS build v2.6.99-ncs1-1. This is the version that came with nRF Connect SDK v1.7.1

The following is the source code for the zephyr test:

/*
 * Copyright (c) 2016 Intel Corporation
 *
 * SPDX-License-Identifier: Apache-2.0
 */

#include <zephyr.h>
#include <device.h>
#include <string.h>
#include <drivers/gpio.h>
#include <nrfx_spim.h>
#include <device.h>
#include <drivers/spi.h>
#include <devicetree/spi.h>
#include <assert.h>

#define SLEEP_TIME    (100)        // ms
#define SPI_BUF_SIZE (255)

const struct gpio_dt_spec test_j7_pin3 = {.port = DEVICE_DT_GET(DT_NODELABEL(gpio0)), .pin = 12, .dt_flags = GPIO_ACTIVE_HIGH};

const struct device* spi = DEVICE_DT_GET(DT_PARENT(DT_NODELABEL(dw1000_dev)));

const static struct spi_config spi_config_dw1000 = SPI_CONFIG_DT(DT_NODELABEL(dw1000_dev), SPI_WORD_SET(8), 0);

uint8_t tx_buf [SPI_BUF_SIZE];
uint8_t rx_buf [SPI_BUF_SIZE];

void setup_spim(void)
{
    if (!device_is_ready(spi_config_dw1000.cs->gpio_dev))
    {
      printk("ERROR: spi gpio_dev not ready");
      for(;;);
    }

    if (!device_is_ready(spi))
    {
      printk("ERROR: failed to open spi");
      for(;;);
    }
}

/*
* Setup output test pins for external monitoring.
*/
void testPin1Set()
{
    gpio_pin_set_dt(&test_j7_pin3, 1);
}

void testPin1Clear()
{
    gpio_pin_set_dt(&test_j7_pin3, 0);
}

void testPinsSetup()
{
    gpio_pin_configure_dt(&test_j7_pin3, GPIO_OUTPUT_INACTIVE);
}

void main(void)
{
    testPinsSetup();
    setup_spim();

    printk("NRFX SPIM sample\n");
    printk("Read DW1000 DWT_DEVICE_ID\n");

    while (1)
    {
        k_msleep(SLEEP_TIME);

        testPin1Set();

        const int length = 5;
        memset(tx_buf, 0, length);
        memset(rx_buf, 0, length);

        struct spi_buf spi_buf_tx = {.buf = tx_buf, .len = length};
        struct spi_buf spi_buf_rx = {.buf = rx_buf, .len = length};

        struct spi_buf_set spi_buf_set_tx = {.buffers = &spi_buf_tx, .count = 1};
        struct spi_buf_set spi_buf_set_rx = {.buffers = &spi_buf_rx, .count = 1};

          spi_transceive(spi, &spi_config_dw1000, &spi_buf_set_tx, &spi_buf_set_rx);

        testPin1Clear();
        // Expecting DWT_DEVICE_ID   (0xDECA0130)        //!< DW1000 MP device ID
        printk("Result = %x\n", *((uint32_t*) &rx_buf[1]));
    }
}

[Saleh]

Would you please add "<your board>.overlay", "<your board>.conf" and "prj.conf" files here? then I can run the sample in order to check it on my side.

[dwalton65]

Can you not see the attachments in the first post? They show up on my end.

I will insert them into the text here as well.

I do not have a board overlay as I copied the board definition to the project and edited that. The only change to the board "decawave_dwm1001_dev" was to add a node label to the line dw1000_dev: dw1000@0 {

"decawave_dwm1001_dev2.dts" all the other board files are the same as in "v1.7.1\zephyr\boards\arm\decawave_dwm1001_dev"

/*
 * Copyright (c) 2019 Stéphane D'Alu
 *
 * SPDX-License-Identifier: Apache-2.0
 */

/dts-v1/;
#include <nordic/nrf52832_qfaa.dtsi>

/ {
	model = "Decawave DWM1001-DEV2";
	compatible = "decawave,dwm1001";

	chosen {
		zephyr,console        = &uart0;
		zephyr,shell-uart     = &uart0;
		zephyr,uart-mcumgr    = &uart0;
		zephyr,bt-mon-uart    = &uart0;
		zephyr,bt-c2h-uart    = &uart0;
		zephyr,sram           = &sram0;
		zephyr,flash          = &flash0;
		zephyr,code-partition = &slot0_partition;
	};

	leds {
		compatible = "gpio-leds";
		led0_red: led_0 {
			gpios = <&gpio0 14 GPIO_ACTIVE_LOW>;
			label = "Red LED 0";
		};
		led1_green: led_1 {
			gpios = <&gpio0 30 GPIO_ACTIVE_LOW>;
			label = "Green LED 1";
		};
		led2_red: led_2 {
			gpios = <&gpio0 22 GPIO_ACTIVE_LOW>;
			label = "Red LED 2";
		};
		led3_blue: led_3 {
			gpios = <&gpio0 31 GPIO_ACTIVE_LOW>;
			label = "Blue LED 3";
		};
	};

	pwmleds {
		compatible = "pwm-leds";
		pwm_led0_red: pwm_led_0 {
			pwms = <&pwm0 22>;
			label = "Red PWM LED";
		};
	};

	buttons {
		compatible = "gpio-keys";
		button0: button_0 {
			gpios = <&gpio0 2 (GPIO_PULL_UP | GPIO_ACTIVE_LOW)>;
			label = "Push button switch 0";
		};
	};

	/* These aliases are provided for compatibility with samples */
	aliases {
		sw0        = &button0;
		led0       = &led0_red;
		led1       = &led1_green;
		led2       = &led2_red;
		led3       = &led3_blue;
		led0-red   = &led0_red;
		led1-green = &led1_green;
		led2-red   = &led2_red;
		led3-blue  = &led3_blue;
		pwm-led0   = &pwm_led0_red;
	};
};

&adc {
	status = "okay";
};

&gpiote {
	status = "okay";
};

&gpio0 {
	status = "okay";
};

&uart0 {
	status = "okay";
	compatible = "nordic,nrf-uart";
	current-speed = <115200>;
	tx-pin  = <5>;
	rx-pin  = <11>;
};

&i2c0 {
	compatible = "nordic,nrf-twim";
	status = "okay";
	clock-frequency = <I2C_BITRATE_FAST>;
	sda-pin = <29>;
	scl-pin = <28>;

	lis2dh12: lis2dh12@19 {
		compatible = "st,lis2dh12", "st,lis2dh";
		reg = <0x19>;
		irq-gpios = <&gpio0 25 GPIO_ACTIVE_HIGH>;
		label = "LIS2DH12-ACCEL";
	};
};

&spi1 {
	compatible = "nordic,nrf-spi";
	status = "okay";
	sck-pin  = <4>;
	mosi-pin = <6>;
	miso-pin = <7>;
	cs-gpios = <&gpio0 3 0>;
};

&spi2 {
	compatible = "nordic,nrf-spim";
	status = "okay";
	sck-pin  = <16>;	
	mosi-pin = <20>;
	miso-pin = <18>;
	cs-gpios = <&gpio0 17 GPIO_ACTIVE_LOW>;

	dw1000_dev: dw1000@0 {
		compatible = "decawave,dw1000";
		spi-max-frequency = <8000000>;
		int-gpios = <&gpio0 19 GPIO_ACTIVE_HIGH>;	/* P0.19 */
		reset-gpios = <&gpio0 24 GPIO_ACTIVE_LOW>;	/* P0.24 */
		status = "okay";
		label = "DW1000";
		reg = <0>;
	};
};

&pwm0 {
	status = "okay";
	ch0-pin = <22>;
	ch0-inverted;
};

&flash0 {

	partitions {
		compatible = "fixed-partitions";
		#address-cells = <1>;
		#size-cells = <1>;

		boot_partition: partition@0 {
			label = "mcuboot";
			reg = <0x00000000 0xc000>;
		};
		slot0_partition: partition@c000 {
			label = "image-0";
			reg = <0x0000C000 0x32000>;
		};
		slot1_partition: partition@3e000 {
			label = "image-1";
			reg = <0x0003E000 0x32000>;
		};
		scratch_partition: partition@70000 {
			label = "image-scratch";
			reg = <0x00070000 0xa000>;
		};
		storage_partition: partition@7a000 {
			label = "storage";
			reg = <0x0007a000 0x00006000>;
		};
	};
};

"prj.conf"

CONFIG_SOC_NRF52832_ALLOW_SPIM_DESPITE_PAN_58=y

To build the project

west build -b decawave_dwm1001_dev2 -d build2 -- -DBOARD_ROOT=\ncs\myapps\zephyr_spim -DCONFIG_DEBUG_OPTIMIZATIONS="y" -DCONFIG_OPENOCD_SUPPORT="y"

[dwalton65]

Any thoughts on this?

I would rather use the zephyr drivers as I am having occasional reliability problems with my use of the Nordic drivers.  See nrfx_spim-driver-sometimes-does-not-call-the-event-handler

[Saleh]

Hi Again

Sorry for the late reply, I have tested the sample project, using the original branch of Zephyr project (https://github.com/zephyrproject-rtos/zephyr), which is usually ahead of the mirror of Zephyr which is used in the nordic sdk. So I can say the last modification of Zephyr has been considered.

Because only I had access to nrf52833dk, then I have made some minor changes in order to run the sample on my hardware, And here you can find the result:

The time between when Chip selector is enabled until when SPI-CLK starts, is about 5us, and the time between when SPI-CLK stops until when the chip selector has disabled, is about 17us, so very close to what you have seen before. I can say it is the normal operation of last Zephyr driver and maybe it could be improved. You can report the problem into the Zephyr's github page.

Also I tried to disable the "chip selector" functionality of Zephyr's driver by setting the pointer to NULL and trying to toggle the corresponding pin manually, but the result was similar. Actually "spi_transceive" function returns after a delay, despite of the "chip select" functionality.

------------------------------------------------------

PS: to measure the time of running a function or some line of the code, you can use the built-in api of Zephyr instead of toggling a gipo and measuring by the external tools. You can find more information here:

https://docs.zephyrproject.org/latest/reference/timing_functions/index.html

Regards,

Saleh