nrf_delay_ms not working?

[Robin]

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\r\n", m_life_count_msec);
    nrf_delay_ms(2000);
    NRF_LOG_INFO("ID QUERY '?' SENT AT: %d\r\n", 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

[Robin]

Hello again, Kenneth, Nguyen,

So, I have made the variable "volatile"

...
static volatile uint32_t m_life_count_msec = 0;
...

I access it in a function called by the timeout handler:

...
void timeout_handler(void * context)
{
  connect_chk_count += APP_TIMER_MS_COUNT;
  board_life_chk_count += APP_TIMER_MS_COUNT;
  m_timer_msec        += APP_TIMER_MS_COUNT;
  m_counter_msec      += APP_TIMER_MS_COUNT;
  m_life_count_msec   += APP_TIMER_MS_COUNT;
  
  if (board_life_chk_count >= BOARD_LIFE_CHK_PERIOD)
  {
    board_life_chk_count = 0;
    board_life_chk();
  }
  switch (m_app_mode)
  {
    case APP_CONNECT_CHK:
      if (connect_chk_count >= 500)
      {
        connect_chk_count = 0;
        connect_check();
      }
    break;
...

I then print the variable before and after the delay using RTT Viewer:

...
void connect_check(void)
{
//    sprintf(message_buffer, "?");
//    m_send_string(message_buffer);
  static uint8_t check_count = 0;
  
  if (iphone_connect)
  {
    NRF_LOG_INFO("DELAY TEST 1: %d mSec\r\n", m_life_count_msec);
    nrf_delay_ms(2000);
    NRF_LOG_INFO("DELAY TEST 2: %d mSec\r\n", m_life_count_msec);
    NRF_LOG_INFO("IPHONE CONNECT @ %d mSec\r\n", m_life_count_msec);
    NRF_LOG_INFO("CHECK COUNT = %d\r\n", check_count);
...

Yet still, the variable is not updated while the delay is happening, (and it does appear to be happening if I manually time between the two prints:

iDrink::INFO:DELAY TEST 1: 272600 mSec
iDrink::INFO:DELAY TEST 2: 272600 mSec

So it appears that this delay function does suspend any app delay functionality while it runs.

Do you know of a way to use both functions successfully?

Thanks

Robin @ TL

[RK]

"So it appears that this delay function does suspend any app delay functionality while it runs."

No it doesn't. nrf_delay_ms() is just a dumb power wasting loop. Hence your problem lies elsewhere. 

Where are you calling connect_check() from? I'm going with Kenneth here that it's likely to be in an interrupt context, stick in a breakpoint, look at the stack, where are you, what do the CPU registers say about your context? 

[Nguyen Hoan Hoang]

does the connect_check get called from a BLE event ? If that is the case, it is likely be at higher priority or from an other event that has higher priority then your timer timeout would never get serviced during the delay.  

[Robin]

The code posted shows that connect_check() is called from the timeout_handler.  

[Nguyen Hoan Hoang]

I didn't see it.  That explained why the counter is the same.  You never exited the handler.

[Robin]

Hi Nguyen,

• Yes, the handler is exited, I only showed the case that makes the call.  Note the break followed by ...

There are several other cases below for other cases below.

Robin @ TL