nrfx_spim driver sometimes does not call the event handler

SDK Environment: nRF Connect SDK v1.7.1
Zephyr OS build v2.6.99-ncs1-1. This is the version that came with nRF Connect SDK v1.7.1
Target: Decawave DWM1001-DEV. This uses the nRF52832

I am using the Nordic nrfx_spim drivers in a zephyr program.

A event handler is set with nrfx_spim_init.

The same SPI transfer is repeated 1000 times with no added delay.

Occasionally after initiating a transfer with nrfx_spim_xfer the event handler is not called. I have set a very long timeout in the attached code.

The attached test program logs "SPI timeout" at random intervals. Usually within a few minutes.

/*
 * Copyright (c) 2016 Intel Corporation
 *
 * SPDX-License-Identifier: Apache-2.0
 */
/*
* Modified from nrfx_spim.zip by Håkon
* See: https://devzone.nordicsemi.com/f/nordic-q-a/61900/clarification-on-intended-driver-to-communicating-with-generic-spi-device-on-nrf52-dk-running-zephyr
*/

#include <zephyr.h>
#include <device.h>
#include <string.h>
#include <drivers/gpio.h>
#include <nrfx_spim.h>
#include <logging/log.h>

LOG_MODULE_REGISTER(main);

#define SLEEP_TIME	100		// ms
#define SPI_TIMEOUT 1000	// ms

const struct gpio_dt_spec heartbeat_led = GPIO_DT_SPEC_GET(DT_NODELABEL(led0_red), gpios);

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

#define NRFX_SPIM_SCK_PIN  16
#define NRFX_SPIM_MOSI_PIN 20
#define NRFX_SPIM_MISO_PIN 18
#define NRFX_SPIM_SS_PIN   17

#define SPI_INSTANCE  2                                           /**< SPI instance index. */
static const nrfx_spim_t spi = NRFX_SPIM_INSTANCE(SPI_INSTANCE);  /**< SPI instance. */

static volatile bool spi_xfer_done = true;  /**< Flag used to indicate that SPI instance completed the transfer. */

#define SPI_BUF_SIZE (255)
static uint8_t       m_tx_buf[SPI_BUF_SIZE];			/**< TX buffer. */
static uint8_t       m_rx_buf[SPI_BUF_SIZE];  			/**< RX buffer. */

#define ISR_PRIORITY 5

void spim_event_handler(nrfx_spim_evt_t const * p_event, void * p_context)
{
    spi_xfer_done = true;
}

void setup_spim(void)
{
    nrfx_spim_config_t spi_config = NRFX_SPIM_DEFAULT_CONFIG(NRFX_SPIM_SCK_PIN, NRFX_SPIM_MOSI_PIN,
										NRFX_SPIM_MISO_PIN, NRFX_SPIM_SS_PIN);
	spi_config.frequency = NRF_SPIM_FREQ_8M;

	uint32_t err = nrfx_spim_init(&spi, &spi_config, spim_event_handler, NULL);
	if (err != NRFX_SUCCESS) {
		printk("nrfx err: %d\n", err);
		return;
	}
	/* Zephyr IRQ wrapper, corresponds to NVIC_* functions */
	IRQ_CONNECT(NRFX_IRQ_NUMBER_GET(NRF_SPIM2), ISR_PRIORITY, nrfx_isr, nrfx_spim_2_irq_handler, 0);
}

/*
* 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_thread(void)
{
	testPinsSetup();
	setup_spim();

	LOG_INF("NRFX SPIM sample");
	LOG_INF("Read DW1000 DWT_DEVICE_ID");

	while (1)
	{
		k_msleep(SLEEP_TIME);

		for (int i = 0; i < 1000; i++)
		{
			const int m_length = 5;
			memset(m_tx_buf, 0, m_length);
			memset(m_rx_buf, 0, m_length);

			nrfx_spim_xfer_desc_t xfer_desc = NRFX_SPIM_XFER_TRX(m_tx_buf, m_length, m_rx_buf, m_length);
			uint32_t ret = nrfx_spim_xfer(&spi, &xfer_desc, 0);
			if (ret == NRFX_SUCCESS)
			{
				spi_xfer_done = false;
				testPin1Set();
  				int64_t timeOutTime = k_uptime_get() + SPI_TIMEOUT;
				while (!spi_xfer_done)
				{
					k_yield();
					if (k_uptime_get() > timeOutTime)
					{
						LOG_INF("SPI timeout");
						break;
					}
				}
				testPin1Clear();
			}
			else
			{
				LOG_INF("nrfx_spim_xfer returned %i", ret);
			}
		}

		// Expecting DWT_DEVICE_ID   (0xDECA0130)        //!< DW1000 MP device ID
		LOG_INF("Result = %x", *((uint32_t*) &m_rx_buf[1]));
	}
}

void heartbeat_thread(void)
{
	bool ledState = false;
	gpio_pin_configure_dt(&heartbeat_led, GPIO_OUTPUT);

    for (;;)
    {
        k_msleep(500);
		LOG_INF("toggle LED");
        gpio_pin_set_dt(&heartbeat_led, ledState);
        ledState = !ledState;
    }
}


K_THREAD_DEFINE(main_thread_id, 4000, main_thread, NULL, NULL, NULL,
		7, 0, 0);

K_THREAD_DEFINE(heartbeat_thread_id, 1024, heartbeat_thread, NULL, NULL, NULL,
		7, 0, 0);

testPin1Set and testPin1Clear are for time profiling.

I have attached the complete project source code.

log_nrfx_spim.zip

Parents
  • Hi,

    I stripped away parts of your code to make it build for nrf52dk_nrf52832, for my reference:

    /*
     * Copyright (c) 2016 Intel Corporation
     *
     * SPDX-License-Identifier: Apache-2.0
     */
    /*
    * Based on nrfx_spim.zip by Håkon
    * See: https://devzone.nordicsemi.com/f/nordic-q-a/61900/clarification-on-intended-driver-to-communicating-with-generic-spi-device-on-nrf52-dk-running-zephyr
    */
    
    #include <zephyr.h>
    #include <device.h>
    #include <string.h>
    #include <drivers/gpio.h>
    #include <nrfx_spim.h>
    #include <logging/log.h>
    
    LOG_MODULE_REGISTER(main);
    
    #define SLEEP_TIME	100		// ms
    #define SPI_TIMEOUT 1000	// ms
    
    
    
    #define NRFX_SPIM_SCK_PIN  16
    #define NRFX_SPIM_MOSI_PIN 20
    #define NRFX_SPIM_MISO_PIN 18
    #define NRFX_SPIM_SS_PIN   17
    
    #define SPI_INSTANCE  2                                           /**< SPI instance index. */
    static const nrfx_spim_t spi = NRFX_SPIM_INSTANCE(SPI_INSTANCE);  /**< SPI instance. */
    
    static volatile bool spi_xfer_done = true;  /**< Flag used to indicate that SPI instance completed the transfer. */
    
    #define SPI_BUF_SIZE (255)
    static uint8_t       m_tx_buf[SPI_BUF_SIZE];			/**< TX buffer. */
    static uint8_t       m_rx_buf[SPI_BUF_SIZE];  			/**< RX buffer. */
    
    #define ISR_PRIORITY 5
    
    void spim_event_handler(nrfx_spim_evt_t const * p_event, void * p_context)
    {
        spi_xfer_done = true;
    }
    
    void setup_spim(void)
    {
        nrfx_spim_config_t spi_config = NRFX_SPIM_DEFAULT_CONFIG(NRFX_SPIM_SCK_PIN, NRFX_SPIM_MOSI_PIN,
    										NRFX_SPIM_MISO_PIN, NRFX_SPIM_SS_PIN);
    	spi_config.frequency = NRF_SPIM_FREQ_8M;
    
    	uint32_t err = nrfx_spim_init(&spi, &spi_config, spim_event_handler, NULL);
    	if (err != NRFX_SUCCESS) {
    		printk("nrfx err: %d\n", err);
    		return;
    	}
    	/* Zephyr IRQ wrapper, corresponds to NVIC_* functions */
    	IRQ_CONNECT(NRFX_IRQ_NUMBER_GET(NRF_SPIM2), ISR_PRIORITY, nrfx_isr, nrfx_spim_2_irq_handler, 0);
    }
    
    
    
    void main_thread(void)
    {
    	setup_spim();
    
    	LOG_INF("NRFX SPIM sample");
    	LOG_INF("Read DW1000 DWT_DEVICE_ID");
    
    	while (1)
    	{
    		k_msleep(SLEEP_TIME);
    
    		for (int i = 0; i < 1000; i++)
    		{
    			const int m_length = 5;
    			memset(m_tx_buf, 0, m_length);
    			memset(m_rx_buf, 0, m_length);
    
    			nrfx_spim_xfer_desc_t xfer_desc = NRFX_SPIM_XFER_TRX(m_tx_buf, m_length, m_rx_buf, m_length);
    			uint32_t ret = nrfx_spim_xfer(&spi, &xfer_desc, 0);
    			if (ret == NRFX_SUCCESS)
    			{
    				spi_xfer_done = false;
      				int64_t timeOutTime = k_uptime_get() + SPI_TIMEOUT;
    				while (!spi_xfer_done)
    				{
    					k_yield();
    					if (k_uptime_get() > timeOutTime)
    					{
    						LOG_INF("SPI timeout");
    						break;
    					}
    				}
    			}
    			else
    			{
    				LOG_INF("nrfx_spim_xfer returned %i", ret);
    			}
    		}
    
    		// Expecting DWT_DEVICE_ID   (0xDECA0130)        //!< DW1000 MP device ID
    		LOG_INF("Result = %x", *((uint32_t*) &m_rx_buf[1]));
    	}
    }
    
    
    K_THREAD_DEFINE(main_thread_id, 4000, main_thread, NULL, NULL, NULL,
    		7, 0, 0);
    

    With this I saw this once, but not frequently. I did not get a chance to test for a long time but a length of 5 is very short when you do it back to back, so this interrupt would be going off constantly. When something else is also happening it could be that you miss an interrupt, if they are not processed in time. What happens if yo use a significantly longer length?

  • I tried 20 bytes, and still got timeouts. I then tried 100 bytes and did not get any timeouts after 41 minutes.

Reply Children
No Data
Related