nrfx_spim driver sometimes does not call the event handler

Question

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