SPI master timings

[Sébastien Schiesser]

Hi

I modified the SPI master example to read an 16-bit ADC at 44.1 kHz.

While the HAL_TIMER achieves its ~22 microseconds quite good, the SPI driver is quite slow: the CS pin stays low for 7.5 us for a 8 MHz transfer of ca 2 us (see picture). Do I have a possibility to optimize that?

And I don't know if it's related: when I reduce the timer to 20 us, just after starting up it works fine (the toggles on the 'TIMER' channel have ca 19.9 us):

But after 28 ms it changes and I get the following shapes, as if the time did get some delay and has to catch up (total time of an ON-OFF toggle is 38.8 us):

Is the 20 us value a limit for this application?

Thanks,

Sébastien

[MartinBL]

So there are two questions here?

1. Why is the CSN chip low for so long? This is probably, at least partly, due to the SPI driver in the SDK. The CSN pin is not automatically controlled by HW, but is controlled by SW in the driver. It seems a bit weird that it would stay low that long though. 
2. You have configured the timer to generate a waveform with a period of 20us, but then it suddenly changes to 38us? Is that correct?

Is this nRF52832?
Are you using a Softdevice?
What timer are you using?
Can you upload your code so I can test it?

[Sébastien Schiesser]

That's right! Two question, but perhaps related :-) So I start with #2

Yes it's nRF52832

No Softdevice for the moment, but my next step will be adding S132 for remote purposes

I use the HAL timer (controlled by nrf_drv_timer)

Code:

#include "nrf_drv_spi.h"
#include "app_util_platform.h"
#include "nrf_gpio.h"
#include "nrf_delay.h"
#include "boards.h"
#include "app_error.h"
#include <string.h>
#include "nrf_log.h"
#include "nrf_log_ctrl.h"
#include "nrf_log_default_backends.h"
#include "nrf_drv_timer.h"

/* SPI instance for ADC device */
#define ADC_SPI_INSTANCE  		0 /**< SPI instance index. */
#define ADC_BUFFER_NUMBER		4
#define ADC_CHUNK_SIZE			512
static const 					nrf_drv_spi_t spi = NRF_DRV_SPI_INSTANCE(ADC_SPI_INSTANCE);  /**< SPI instance. */
static volatile bool 			adc_spi_xfer_done = false;  /**< Flag used to indicate that SPI instance completed the transfer. */
static uint8_t					m_tx_buf[2] = {0xFF, 0xFF};	/**< Dummy TX value to push the 2 ADC bytes. */
static uint8_t					m_rx_buf[2];
static uint8_t					m_adc_buffer[ADC_BUFFER_NUMBER][ADC_CHUNK_SIZE];
static const uint8_t			m_adc_len = 2;
static uint16_t					m_adc_sample_cnt = 0;
static uint8_t					m_adc_buffer_cnt = 0;
static uint32_t					m_adc_total_samples = 0;



/* TIMER instance for audio synchronization */
#define AUDIO_TIMER_INSTANCE	0
#define AUDIO_TIMER_CNT_US		25
const nrf_drv_timer_t 			TIMER_AUDIO = NRF_DRV_TIMER_INSTANCE(AUDIO_TIMER_INSTANCE);


/**
 * @brief SPI user event handler.
 * @param event
 */
void adc_spi_event_handler(nrf_drv_spi_evt_t const * p_event,
                       void *                    p_context)
{
    adc_spi_xfer_done = true;
}

static void audio_sync_handler(nrf_timer_event_t event_type, void *p_context)
{
//	bsp_board_led_invert(0);
	nrf_drv_spi_transfer(&spi, m_tx_buf, m_adc_len, m_rx_buf, m_adc_len);
}

static void audio_sync_init(void)
{
	uint32_t time_us = AUDIO_TIMER_CNT_US;
	uint32_t time_ticks;
    ret_code_t err_code;
	
	nrf_drv_timer_config_t timer_cfg = NRF_DRV_TIMER_DEFAULT_CONFIG;
	err_code = nrf_drv_timer_init(&TIMER_AUDIO, &timer_cfg, audio_sync_handler);
	APP_ERROR_CHECK(err_code);
	
	time_ticks = nrf_drv_timer_us_to_ticks(&TIMER_AUDIO, time_us);
	nrf_drv_timer_extended_compare(&TIMER_AUDIO, NRF_TIMER_CC_CHANNEL0, time_ticks, NRF_TIMER_SHORT_COMPARE0_CLEAR_MASK, true);
	nrf_drv_timer_enable(&TIMER_AUDIO);
}

static void adc_spi_init(void)
{
    nrf_drv_spi_config_t spi_config = NRF_DRV_SPI_DEFAULT_CONFIG;
    spi_config.ss_pin   = SPI0_SS_PIN;
    spi_config.miso_pin = SPI0_MISO_PIN;
    spi_config.mosi_pin = SPI0_MOSI_PIN;
    spi_config.sck_pin  = SPI0_SCK_PIN;
	spi_config.frequency = NRF_DRV_SPI_FREQ_8M;
	spi_config.irq_priority = SPI0_IRQ_PRIORITY;
    APP_ERROR_CHECK(nrf_drv_spi_init(&spi, &spi_config, adc_spi_event_handler, NULL));
}

int main(void)
{
    APP_ERROR_CHECK(NRF_LOG_INIT(NULL));
    NRF_LOG_DEFAULT_BACKENDS_INIT();
    
    NRF_LOG_INFO("Sounding Soil, version 0.1");

    bsp_board_leds_init();
	adc_spi_init();
	audio_sync_init();
	
    while (1)
    {
		if(adc_spi_xfer_done) {
//			bsp_board_led_invert(1);
			m_adc_buffer[m_adc_buffer_cnt][m_adc_sample_cnt++] = m_rx_buf[0];
			m_adc_buffer[m_adc_buffer_cnt][m_adc_sample_cnt++] = m_rx_buf[1];
			if(m_adc_sample_cnt >= ADC_CHUNK_SIZE) {
				m_adc_total_samples += m_adc_sample_cnt;
				m_adc_sample_cnt = 0;
				m_adc_buffer_cnt = (m_adc_buffer_cnt >= (ADC_BUFFER_NUMBER - 1)) ? 0 : m_adc_buffer_cnt + 1;
			}
			adc_spi_xfer_done = false;
//			bsp_board_led_invert(1);
		}
		else {
		__WFE();
		}
    }
}

Hope it works... Thanks in advance.

Sébastien

[MartinBL]

Hi, I just thought I'd let you know I'm still working on this. It's a very weird issue, and I need to involve some experts. 

[MartinBL]

Here are a few more findings btw:

One more peculiar thing that I have noticed: On a power-on-reset or pin-reset the issue occurs immediately after system startup.

 

It is only right after programming the chip that it seems to work fine for ~50ms and then it starts misbehaving. Furthermore, if I use nrfjprog and perform a soft reset it seems to work as intended for about 0.5 seconds after I send the reset command. Then, after the reset, it immediately starts misbehaving again.

Maybe you can confirm whether you experience the same behaviour?

 

 

Here is some stripped down code I use to reproduce it:

#include "boards.h"

#define SPI_BUFFER_SIZE 2
static uint8_t m_tx_buf[SPI_BUFFER_SIZE] = {0x0F, 0xF0};	/**< Dummy TX value to push the 2 ADC bytes. */

#define SPI0_SS_PIN 3
#define SPI0_MISO_PIN 4
#define SPI0_MOSI_PIN 28
#define SPI0_SCK_PIN 29

#define SLEEP_EVENT 0
#define SLEEP_TEST_PIN 30

void setup_sleep_mode_test(void)
{
    NRF_GPIOTE->CONFIG[SLEEP_EVENT] = ((GPIOTE_CONFIG_MODE_Task   << GPIOTE_CONFIG_MODE_Pos) |    
                                        (SLEEP_TEST_PIN                << GPIOTE_CONFIG_PSEL_Pos) | 
                                        (GPIOTE_CONFIG_POLARITY_None<< GPIOTE_CONFIG_POLARITY_Pos));
    
    NRF_PPI->CH[10].EEP = (uint32_t)&NRF_POWER->EVENTS_SLEEPEXIT;
    NRF_PPI->CH[10].TEP = (uint32_t)&NRF_GPIOTE->TASKS_SET[SLEEP_EVENT];
    
    NRF_PPI->CH[11].EEP = (uint32_t)&NRF_POWER->EVENTS_SLEEPENTER;
    NRF_PPI->CH[11].TEP = (uint32_t)&NRF_GPIOTE->TASKS_CLR[SLEEP_EVENT];
    
    NRF_PPI->CHEN |= (1<<10) | (1<<11);
}


void TIMER0_IRQHandler()
{
    nrf_gpio_pin_set(LED_1);
    nrf_gpio_pin_clear(LED_1);
    
    NRF_TIMER0->EVENTS_COMPARE[0] = 0;
    NRF_SPIM2->TASKS_START = 1;
}


void SPIM2_SPIS2_SPI2_IRQHandler()
{
    nrf_gpio_pin_set(LED_2);
    nrf_gpio_pin_clear(LED_2);
    
    NRF_SPIM2->EVENTS_END = 0;
}


static void setup_timer(void)
{
    NRF_TIMER0->CC[0] = 25;
    NRF_TIMER0->INTENSET = (TIMER_INTENSET_COMPARE0_Enabled << TIMER_INTENSET_COMPARE0_Pos);
    NRF_TIMER0->SHORTS = (TIMER_SHORTS_COMPARE0_CLEAR_Enabled << TIMER_SHORTS_COMPARE0_CLEAR_Pos);

    NVIC_SetPriority(TIMER0_IRQn, 7);
    NVIC_EnableIRQ(TIMER0_IRQn);
    
    NRF_TIMER0->TASKS_START = 1;
}


static void setup_spi(void)
{
    NRF_SPIM2->TXD.MAXCNT = SPI_BUFFER_SIZE;
    NRF_SPIM2->TXD.PTR = (uint32_t)&m_tx_buf;    
    NRF_SPIM2->FREQUENCY = SPIM_FREQUENCY_FREQUENCY_M8;
    NRF_SPIM2->PSEL.MISO = SPI0_MISO_PIN;
    NRF_SPIM2->PSEL.MOSI = SPI0_MOSI_PIN;
    NRF_SPIM2->PSEL.SCK = SPI0_SCK_PIN;
    NRF_SPIM2->ENABLE = SPIM_ENABLE_ENABLE_Enabled << SPIM_ENABLE_ENABLE_Pos;
    NRF_SPIM2->INTENSET = (SPIM_INTENSET_END_Enabled << SPIM_INTENSET_END_Pos);
    
    NVIC_SetPriority(SPIM2_SPIS2_SPI2_IRQn, 7);
    NVIC_EnableIRQ(SPIM2_SPIS2_SPI2_IRQn);
}


int main(void)
{
    LEDS_CONFIGURE(LEDS_MASK);
    LEDS_OFF(LEDS_MASK);
    
//    NRF_CLOCK->TASKS_HFCLKSTART = 1;
//    while(NRF_CLOCK->EVENTS_HFCLKSTARTED != 1)
//        ;
//    NRF_CLOCK->EVENTS_HFCLKSTARTED = 0;
    
    setup_sleep_mode_test();
	setup_spi();
	setup_timer();
    	
    while (1)
    {
        // Make sure any pending events are cleared
        __SEV();
        __WFE();
        // Enter System ON sleep mode
        __WFE();   
    }
}

[Sébastien Schiesser]

Hi Martin,

Finally managed to test your setup. Result: I can reproduce your results with two exception:

1. instead of 0.5s between soft reset sending and occurence, I have changing times (measured between 50 and 300 ms).
2. After the softreset occurence, I (sometimes? always?) get a correct behaviour for some ms

Startup after download (note: since I have a slow logic analyzer, I had to toggle the IRQs):

Behaviour change after ~30 ms:

Startup after power cycle:

nrfjprog reset:

softreset before/after:

Best,

Sébastien

[MartinBL]

Hi,

I'm sorry this has taken so long. Unfortunately I'll be traveling the rest of the week, so I won't be able to look more into it before after the weekend. 

Martin

[MartinBL]

Hi,

I have done some more testing and removed all the SPI related code. The issue with the prolonged CPU awake time is still there. After about 40 ms (+- 10ms) the CPU awake time is suddenly 10 times longer than before. It goes from 1.242 us to 12.43 us. 

Furthermore, there seems to be a difference in behavior dependent on how the application starts:

• Soft reset: This works as explained above. Everything seems normal for ~40 ms (+- 10 ms), then the CPU awake time is suddenly 10 times longer.
• Pin reset or Power on Reset: The CPU awake time is longer from the very beginning of the application.

I'm still not sure what the problem is. Fair enough, there is an inevitable latency between an interrupt is being triggered and until the code in the ISR is being executed, but it should only be 10 or 12 clock cycles on the Cortex M4 if I remember correctly. Not close 10 microseconds as we see in the logic trace. And it is strange that the latency seems to change after some milliseconds. It could be that the debugger is playing tricks on us. I'll keep asking around.

Unfortunately I'm going out of office again, but I'll see if someone can look into it while I'm gone.