nrf_delay_ms not working?

Question

Hello Nordic Pros, 
 Doing some debugging using RTT Viewer and an nRF51822 under SDK12.3. Here is the code lines of interest: 
 ...
 NRF_LOG_INFO("IPHONE 'PPM' RECEIVED @ %d mS
", m_life_count_msec);
 nrf_delay_ms(2000);
 NRF_LOG_INFO("ID QUERY '?' SENT AT: %d
", m_life_count_msec);
... 
 And here are the log messages: 
 iDrink::INFO:IPHONE 'PPM' RECEIVED @ 683250 mS iDrink::INFO:ID QUERY '?' SENT AT: 683250 
 m_life_count_msec is a copy of an app timer count in mSec that is set up to inc ~ every 50 mSec. 
 Here is the timer setup code: 
 ...
 app_timer_create(&m_app_timer_id, APP_TIMER_MODE_REPEATED, timeout_handler); //create and start timer...
 app_timer_start(m_app_timer_id, APP_TIMER_TIMEOUT_TICKS, (void*) 0);
... 
 And here is the timeout code showing the assignment to m_life_count_msec: 
 ...
void timeout_handler(void * context)
{
...
 m_life_count_msec += APP_TIMER_MS_COUNT;
...
 
 Obviously the questions is, why is there not a 2000 mSec delay between the two log messages? 
 Does nrf_delay_ms() suspend m_app_timer while it is counting? 
 Help, please! 
 Robin @ TL

RK · Accepted Answer

I'd put it slightly differently, the handler is not getting called every 50ms, the timer is raising an interrupt isevery 50ms. If the processor is running anything with lower priority, then it takes the interrupt and runs the handler, else the interrupt just pends. When the processor returns from the interrupt handler it was running, then it runs the next handler for the highest priority pended interrupt. 
 
 If the ISR doesn't return quickly, the interrupt keeps firing and firing and firing, but the processor cannot interrupt itself for something of equal or lower priority, so those interrupts just pend and coalesce into one which does get called when the first handler call finally returns. 
 In your case the first call of the handler didn't return for about 2 seconds because it was stuck in nrf_delay_ms which is basically a carefully implemented in assembler for-loop designed to keep the processor spinning for a number of milliseconds. As soon as it did return, the handler would have been called again as there were missed interrupts, 40 of them, but by then you've done both LOGs and exited and your counter has missed 2 seconds of counts.

nrf_delay_ms not working?

Top Replies