This post is older than 2 years and might not be relevant anymore
More Info: Consider searching for newer posts

Missing APP_TIMER interrupts?

I am using nRF5 SDK 16 on a Rigado BMD-300 (nRF52832) series evaluation kit.  The application receives button presses and releases from a peripheral (characteristic change notifications).  I'm using an app timer to process button timing (e.g. single clicks, double clicks, long holds, etc).  Button activity is then sent to a host through the UART (using a FIFO).  Without the timer interrupt, there is no button activity and no UART activity.

The timer calls a routine in my button module:

static void buttons_timer_callback(void* p_context)
{
  if (buttons_data.timer_callback) buttons_data.timer_callback();
}

which calls a callback set when the button processing module is initialized.  It's never set again.

The callback just sets the flag:

void button_timer_callback(void)
{
  main_event_flags.do_buttons = true;
}

So short of the redirection of the callback, I'm doing just about the absolute minimum in the timer interrupt.

The problem is that the app timer seems to stop after a few seconds of activity and it's not consistent when it stops.  Sometimes it stops for up to 100 ms and when it resumes, it misses more than it makes.

In the app timer callback, I'm setting a global flag and processing the buttons in the main idle loop so it spends very little time in the interrupt.  The timer is set for 5 ms.  Here is my sdk_config.h setup;

/ <e> APP_TIMER_ENABLED - app_timer - Application timer functionality
//==========================================================
#ifndef APP_TIMER_ENABLED
#define APP_TIMER_ENABLED 1
#endif
// <o> APP_TIMER_CONFIG_RTC_FREQUENCY  - Configure RTC prescaler.
 
// <0=> 32768 Hz 
// <1=> 16384 Hz 
// <3=> 8192 Hz 
// <7=> 4096 Hz 
// <15=> 2048 Hz 
// <31=> 1024 Hz 

#ifndef APP_TIMER_CONFIG_RTC_FREQUENCY
#define APP_TIMER_CONFIG_RTC_FREQUENCY 1
#endif
[

In app_timer_start(), timeout_ticks is 82.  I calculate that to be 5ms.

  NRF_LOG_DEBUG("Starting button timer, ticks = %d", ticks);
  (void)app_timer_start(zrf_buttons_timer_id, ticks, NULL);

Here is the log message:

<debug> app: Starting button timer, ticks = 82

My question is, is there anything about processing app timer events/interrupts that you have to be careful of?  I saw a 6 year old post about using the app scheduler, to process app timer events, but don't see how that can be done -- does that still apply?  Could this be an interrupt priority issue?  If so, that would imply I'm doing a bunch of stuff in interrupts and I just don't see that.  Any suggestions on what to check?

  • Can you try to replicate the issue in a stripped down example, then? Or one of the examples in the SDK that you modify to replicate the issue on a DK? It isn't really much I can do with the information that I already have. 

    But I guess I can try a few more shots in the dark:

    • Is there anything else using the app_timer?
    • What is your APP_TIMER_CONFIG_USE_SCHEDULER?
    • What is your APP_TIMER_KEEPS_RTC_ACTIVE? Can you try to set it to true?
    • Is there something else happening right before you start loosing the app_timer events? Does the log give any hints?

    BR,

    Edvin

  • There is a second app_timer instance used in the central's UART connection to the host.  It is used as a single shot timer to guard against partial messages (if it times out, it resets the receive state machine).  This is currently commented out so I could see if this is the problem.  It didn't make any difference.

    I don't know of any way to really do a stripped down version.  You have to have a connection to the peripheral so I need BLE, scanning, peer manager, discovery, etc.

    APP_TIMER_CONFIG_USE_SCHEDULER is 0.

    APP_TIMER_KEEPS_RTS_ACTIVE is 0.  I set this to 1 and it didn't make any difference.

    For the log messages, I get a message when I see the peripheral state change - that always happens.  When the state of the peripheral buttons change, I call a simple routine in the button module to set the new states and the new states are set the current states at the end of the button processing.  Since the button processing is kicked off by the timer, what I see is log messages for getting the new states and no log messages for setting the new states:

    <debug> app: Got new button states: 0010
    <info> app: Updating button states...
    <debug> nrf_ble_gq: Processing the request queue...
    <debug> app: Got new button states: 0000
    <info> app: Updating button states...
    <debug> nrf_ble_gq: Processing the request queue...
    <debug> app: Got new button states: 0010
    <debug> nrf_ble_gq: Processing the request queue...
    <debug> app: Got new button states: 0000
    <debug> nrf_ble_gq: Processing the request queue...
    <debug> app: Got new button states: 0010
    <debug> nrf_ble_gq: Processing the request queue...
    <debug> app: Got new button states: 0000
    <debug> nrf_ble_gq: Processing the request queue...
    <debug> app: Got new button states: 0010
    <debug> nrf_ble_gq: Processing the request queue...
    <debug> app: Got new button states: 0000
    <debug> nrf_ble_gq: Processing the request queue...
    <debug> app: Got new button states: 0010
    <info> app: Updating button states...
    <debug> nrf_ble_gq: Processing the request queue...
    <debug> app: Got new button states: 0000
    <info> app: Updating button states...

    You can see the two messages, "Got new button states" that is the result of a BLE GATTC event from me pushing and releasing the button on the remote.  The four digit hex value is the up/down state of all buttons.  It calls a routine that looks like this:

      NRF_LOG_DEBUG("Got new button states: %04X", new_button_states);
      buttons_data.new_button_states = new_button_states;

    That's all it does is save the new states to global data.

    When the timer interrupt happens, it sets a processing flag and the main idle loop calls a routine to process the button events when that flag is set.  At the end of that routine I set the new states to the current states.  I do it like this to make sure the states don't change in the middle of button processing:

      /* If it's changed, set it here.  This way we get every state and it doesn't change in 
         the middle of button processing */
      if (buttons_data.button_states != buttons_data.new_button_states)
      {
        NRF_LOG_INFO("Updating button states...");
        buttons_data.button_states = buttons_data.new_button_states;
      }

    So when the timer interrupts stop, the "Updating button states" message starts to disappear (there are no exits from that routine - if it starts, it has to finish).  It was the same as when I was processing button events in the APP_TIMER interrupt.

    I have put a log message at the beginning of the button processing routine and it isn't received either when the problem starts.  I don't keep that message in there because you get a bunch of them when it's running.

  • If you add an app_timer with 5ms timeout in the ble_app_blinky_c example, does it behave the same?

    Many examples use the app_timer together with BLE without this issue, so I am not sure why it happens, and it is difficult to tell whats going on without being able to reproduce it. Remember that I have no idea what your project looks like. Is it based on the examples? Do you use an RTOS? (FreeRTOS)

    Do you use an IDE to debug? Do you see anything particular when this occurs? Have you tried breaking when it isn't hit? 

  • I haven't tried ble_app_blinky_c.  The timer doesn't behave this way in my peripheral code.  It works fine there.  Neither central or peripheral use a RTOS.

    I'm sure it probably is something in my code.  I can't believe I've found an issue with the APP_TIMER after this long.

    Yes, Segger IDE. There isn't much to see in the debugger on the app_timer that I know of.  My button data looks like it should when breaking.

  • Here's another log message snippet.  The "Processing button states" is logged after the 5 ms timer sets the processing flag.  It's logged from the main idle loop.  The "Got new button states..." messages are from the ble_evt_handler, BLE_GATTC_EVT_HVX event.  Because of the way the remote does debouncing, the two "Got new button states..." messages are at least 20 ms apart.

    <debug> app: Processing buttons states
    <debug> app: Processing buttons states
    <debug> app: Processing buttons states
    <debug> nrf_ble_gq: Processing the request queue...
    <debug> app: Got new button states: 0000
    <debug> nrf_ble_gq: Processing the request queue...
    <debug> app: Got new button states: 0010
    <debug> app: Processing buttons states
    <debug> app: Processing buttons states
    <debug> app: Processing buttons states
    <debug> app: Processing buttons states
    

    Note the lack of "Processing button states" log entries between the two.  I would expect at least three would have to be there.  Typically many more as I can't physically do a 20 ms button press and release.

    The BLE_GATTC_EVT_HVX event calls a routine that does this:

      // Check if the event is on the link for this instance.
      if (m_conn_handle != evt->conn_handle) return;
    
      // Button characteristic is 16 bits - two bytes
      if (2 == evt->params.hvx.len)
      {
        uint16_t data = (evt->params.hvx.data[0] << 8) | (evt->params.hvx.data[1]);
        if (evt->params.hvx.handle == m_events_char_handle) buttons_set_new_button_states(data);
      }

    The function buttons_set_new_button_states(data) just logs the message "Got new button states..." and writes the new button states to a global variable and then returns.  I think I posted this above.

    Is there any reason the ble_evt_handler() would stop timer interrupts?

Related