app_timer hangs

[mrono]

Hello.

I have encountered a case where app_timer gets stuck indefinitely while processing its timer queue. I have attached a simplified version of the code that runs on the nRF52840 DK. (I actually have the nRF52840 PDK, but I doubt that it makes a difference here).

The attached main.c should replace the main.c of the PCA10056 BSP example in SDK 15.2. The code toggles leds 1-3 every time buttons 1-3 are pressed. In addition there is another app_timer that toggles led 4 every second.

Essentially my app_timer code adds long press detection to the basic button handling done by app_button. I looked at the BSP library for an example of long press detection, and implemented the code similarly as the BSP does. So a button press starts an app_timer and a release stops it. If the timer expires before a release, a long press is signaled. This works otherwise, but rapidly clicking two buttons makes the code hang. It usually doesn't take more than a dozen clicks to make it hang on the DK.

Here is the button handling part of the code: (The full, compilable code is the attached main.c)

// Timer callback when long press timeout occurs.
// Forward long press events to the button handler.
static void button_long_press_handler(void * p_context)
{
    uint8_t * p_button = (uint8_t *)p_context;
    
    // Check if we have a button combo
    uint8_t is_pushed = 0;
    bool button_1 = false;
    bool button_2 = false;
    bool button_3 = false;
    if(app_button_is_pushed(0)){is_pushed++; button_1 = true;}    // app_button_is_pushed needs the index into the buttons[] array, hence (0,1,2).
    if(app_button_is_pushed(1)){is_pushed++; button_2 = true;}
    if(app_button_is_pushed(2)){is_pushed++; button_3 = true;}

    uint8_t event_id = BUTTON_LONG_PUSH;

    if(is_pushed > 1)
    {
        if(button_1 && button_2)
            event_id = BUTTON_COMBO_1_2;
        else if(button_1 && button_3)
            event_id = BUTTON_COMBO_1_3;
        else if(button_2 && button_3)
            event_id = BUTTON_COMBO_2_3;
    }

    button_common_handler(*p_button, event_id);
}

// Button definitions
// The config values are taken from custom_board.h
static const app_button_cfg_t buttons[BUTTONS_NUMBER] =
{
    {
        .pin_no = BUTTON_1,
        .active_state = BUTTONS_ACTIVE_STATE,
        .pull_cfg = BUTTON_PULL,
        .button_handler = button_common_handler
    },

    {
        .pin_no = BUTTON_2,
        .active_state = BUTTONS_ACTIVE_STATE,
        .pull_cfg = BUTTON_PULL,
        .button_handler = button_common_handler
    },

    {
        .pin_no = BUTTON_3,
        .active_state = BUTTONS_ACTIVE_STATE,
        .pull_cfg = BUTTON_PULL,
        .button_handler = button_common_handler
    }
#if (BUTTONS_NUMBER > 3)
    ,
    {
        .pin_no = BUTTON_4,
        .active_state = BUTTONS_ACTIVE_STATE,
        .pull_cfg = BUTTON_PULL,
        .button_handler = button_common_handler
    }
#endif
};


void buttons_init(void)
{
    ret_code_t err_code;
    err_code = app_button_init(buttons, BUTTONS_NUMBER, APP_TIMER_TICKS(20));
    APP_ERROR_CHECK(err_code);
    
    err_code = app_button_enable();    
    APP_ERROR_CHECK(err_code);

    err_code = app_timer_create(&button_long_press_timer, APP_TIMER_MODE_SINGLE_SHOT, button_long_press_handler);
    APP_ERROR_CHECK(err_code);
 
}

// Common handler for button events. Detects short and long presses.
static void button_common_handler(uint8_t pin_no, uint8_t button_action)
{
    static bool suppress_next_release_event = false;
    
    if(button_action == APP_BUTTON_PUSH)
    {
        // Start long press timer on PUSH event
        ret_code_t err_code = app_timer_start(button_long_press_timer, APP_TIMER_TICKS(LONG_PRESS_TIMEOUT_MS), (void*)&current_long_push_pin_no);
        if (err_code == NRF_SUCCESS)
        {
            current_long_push_pin_no = pin_no;
        }

        suppress_next_release_event = false;
    }
    if(button_action == APP_BUTTON_RELEASE)
    {
        // Stop long press timer
		(void)app_timer_stop(button_long_press_timer);
        
        // If this was the release event after a long press, ignore it.
        if(suppress_next_release_event){return;}
        
        if(pin_no == BUTTON_1){nrf_gpio_pin_toggle(LED_1);}
        if(pin_no == BUTTON_2){nrf_gpio_pin_toggle(LED_2);}
        if(pin_no == BUTTON_3){nrf_gpio_pin_toggle(LED_3);}
        
    }
    if(button_action == BUTTON_LONG_PUSH)
    {
        // Suppress next release event
        suppress_next_release_event = true;
    }
    if(button_action == BUTTON_COMBO_1_2)
    {
        // Suppress next release event
        suppress_next_release_event = true;
    }
    if(button_action == BUTTON_COMBO_1_3)
    {
        // Suppress next release event
        suppress_next_release_event = true;
    }
    if(button_action == BUTTON_COMBO_2_3)
    {
        // Suppress next release event
        suppress_next_release_event = true;
    }
}

One interesting aspect is that the code hangs in two different while() loops inside app_timer, depending on whether another app_timer (that implements a one second tick) is running. If the tick timer is running, execution hangs in timer_list_remove(), similarly as in this old thread. If I commend out the tick timer (one_sec_timer_start() in the attached code), the code hangs in timer_timeouts_check() in the following loop:

        // Expire all timers within ticks_elapsed and collect ticks_expired.
        while (p_timer != NULL)
        {
            // Do nothing if timer did not expire.
            if (ticks_elapsed < p_timer->ticks_to_expire)
            {
                break;
            }

            // Decrement ticks_elapsed and collect expired ticks.
            ticks_elapsed -= p_timer->ticks_to_expire;
            ticks_expired += p_timer->ticks_to_expire;

            // Move to next timer.
            p_previous_timer = p_timer;
            p_timer = p_timer->next;

            // Execute Task.
            if (p_previous_timer->is_running)
            {
                p_previous_timer->is_running = false;
                timeout_handler_exec(p_previous_timer);
            }
        }

When it hangs, both p_timer and p_previous_timer point to the same timer. And their next pointers also point to the same, so the loop never exits.

I suspect that the root cause is a race condition, since I am triggering starts and stops of the same timer rapidly. Yet this code uses the same principle as the BSP, and I can't get the unmodified BSP example to hang. So I must be doing something wrong. I would appreciate any advice on how to make this work.

Fullscreen main.c Download

/**
 * Copyright (c) 2014 - 2018, Nordic Semiconductor ASA
 *
 * All rights reserved.
 *
 * Redistribution and use in source and binary forms, with or without modification,
 * are permitted provided that the following conditions are met:
 *
 * 1. Redistributions of source code must retain the above copyright notice, this
 *    list of conditions and the following disclaimer.
 *
 * 2. Redistributions in binary form, except as embedded into a Nordic
 *    Semiconductor ASA integrated circuit in a product or a software update for
 *    such product, must reproduce the above copyright notice, this list of
 *    conditions and the following disclaimer in the documentation and/or other
 *    materials provided with the distribution.
 *
 * 3. Neither the name of Nordic Semiconductor ASA nor the names of its
 *    contributors may be used to endorse or promote products derived from this
 *    software without specific prior written permission.
 *
 * 4. This software, with or without modification, must only be used with a
 *    Nordic Semiconductor ASA integrated circuit.
 *
 * 5. Any software provided in binary form under this license must not be reverse
 *    engineered, decompiled, modified and/or disassembled.
 *
 * THIS SOFTWARE IS PROVIDED BY NORDIC SEMICONDUCTOR ASA "AS IS" AND ANY EXPRESS
 * OR IMPLIED WARRANTIES, INCLUDING, BUT NOT LIMITED TO, THE IMPLIED WARRANTIES
 * OF MERCHANTABILITY, NONINFRINGEMENT, AND FITNESS FOR A PARTICULAR PURPOSE ARE
 * DISCLAIMED. IN NO EVENT SHALL NORDIC SEMICONDUCTOR ASA OR CONTRIBUTORS BE
 * LIABLE FOR ANY DIRECT, INDIRECT, INCIDENTAL, SPECIAL, EXEMPLARY, OR
 * CONSEQUENTIAL DAMAGES (INCLUDING, BUT NOT LIMITED TO, PROCUREMENT OF SUBSTITUTE
 * GOODS OR SERVICES; LOSS OF USE, DATA, OR PROFITS; OR BUSINESS INTERRUPTION)
 * HOWEVER CAUSED AND ON ANY THEORY OF LIABILITY, WHETHER IN CONTRACT, STRICT
 * LIABILITY, OR TORT (INCLUDING NEGLIGENCE OR OTHERWISE) ARISING IN ANY WAY OUT
 * OF THE USE OF THIS SOFTWARE, EVEN IF ADVISED OF THE POSSIBILITY OF SUCH DAMAGE.
 *
 */
/** @file
 *
 * @defgroup bsp_example_main main.c
 * @{
 * @ingroup bsp_example
 * @brief BSP Example Application main file.
 *
 */

#include <stdbool.h>
#include <stdint.h>
#include "boards.h"
#include "app_timer.h"
#include "app_button.h"
#include "nrf_gpio.h"
#include "nordic_common.h"
#include "nrf_error.h"


#include "nrf_log.h"
#include "nrf_log_ctrl.h"
#include "nrf_log_default_backends.h"


#define LONG_PRESS_TIMEOUT_MS   3000

#define BUTTON_LONG_PUSH        2
#define BUTTON_COMBO_1_2        3
#define BUTTON_COMBO_1_3        4
#define BUTTON_COMBO_2_3        5

#define ONE_SEC_TIMER_TIMEOUT     (APP_TIMER_TICKS(1000))

static volatile uint32_t one_sec_ticks;

static void button_common_handler(uint8_t pin_no, uint8_t button_action);

uint8_t current_long_push_pin_no;

// The button timer is used to detect long presses
APP_TIMER_DEF(button_long_press_timer);
APP_TIMER_DEF(one_sec_timer_id);


/**@brief Function for initializing low frequency clock.
 */
void clock_initialization()
{
    NRF_CLOCK->LFCLKSRC            = (CLOCK_LFCLKSRC_SRC_Xtal << CLOCK_LFCLKSRC_SRC_Pos);
    NRF_CLOCK->EVENTS_LFCLKSTARTED = 0;
    NRF_CLOCK->TASKS_LFCLKSTART    = 1;

    while (NRF_CLOCK->EVENTS_LFCLKSTARTED == 0)
    {
        // Do nothing.
    }
}


// This handler is called every second
void handle_one_sec_timer_tick(void *p_context)
{
    one_sec_ticks++;
    nrf_gpio_pin_toggle(LED_4);
}

/**@brief Function for the Timer initialization.
 *
 * @details Initializes the timer module. This creates and starts application timers.
 */
void one_sec_timer_init(void)
{
    // Initialize app_timer module.
    ret_code_t err_code = app_timer_init();

    // Create timers.
    err_code = app_timer_create(&one_sec_timer_id, APP_TIMER_MODE_REPEATED, &handle_one_sec_timer_tick);
    APP_ERROR_CHECK(err_code);

}

/**@brief Function for starting timers.
 */
void one_sec_timer_start(void)
{
    ret_code_t err_code;
    err_code = app_timer_start(one_sec_timer_id, ONE_SEC_TIMER_TIMEOUT, NULL);
    APP_ERROR_CHECK(err_code);
}



// Timer callback when long press timeout occurs.
// Forward long press events to the button handler.
static void button_long_press_handler(void * p_context)
{
    uint8_t * p_button = (uint8_t *)p_context;
    
    // Check if we have a button combo
    uint8_t is_pushed = 0;
    bool button_1 = false;
    bool button_2 = false;
    bool button_3 = false;
    if(app_button_is_pushed(0)){is_pushed++; button_1 = true;}    // app_button_is_pushed needs the index into the buttons[] array, hence (0,1,2).
    if(app_button_is_pushed(1)){is_pushed++; button_2 = true;}
    if(app_button_is_pushed(2)){is_pushed++; button_3 = true;}

    uint8_t event_id = BUTTON_LONG_PUSH;

    if(is_pushed > 1)
    {
        if(button_1 && button_2)
            event_id = BUTTON_COMBO_1_2;
        else if(button_1 && button_3)
            event_id = BUTTON_COMBO_1_3;
        else if(button_2 && button_3)
            event_id = BUTTON_COMBO_2_3;
    }

    button_common_handler(*p_button, event_id);
}

// Button definitions
// The config values are taken from custom_board.h
static const app_button_cfg_t buttons[BUTTONS_NUMBER] =
{
    {
        .pin_no = BUTTON_1,
        .active_state = BUTTONS_ACTIVE_STATE,
        .pull_cfg = BUTTON_PULL,
        .button_handler = button_common_handler
    },

    {
        .pin_no = BUTTON_2,
        .active_state = BUTTONS_ACTIVE_STATE,
        .pull_cfg = BUTTON_PULL,
        .button_handler = button_common_handler
    },

    {
        .pin_no = BUTTON_3,
        .active_state = BUTTONS_ACTIVE_STATE,
        .pull_cfg = BUTTON_PULL,
        .button_handler = button_common_handler
    }
#if (BUTTONS_NUMBER > 3)
    ,
    {
        .pin_no = BUTTON_4,
        .active_state = BUTTONS_ACTIVE_STATE,
        .pull_cfg = BUTTON_PULL,
        .button_handler = button_common_handler
    }
#endif
};


void buttons_init(void)
{
    ret_code_t err_code;
    err_code = app_button_init(buttons, BUTTONS_NUMBER, APP_TIMER_TICKS(20));
    APP_ERROR_CHECK(err_code);
    
    err_code = app_button_enable();    
    APP_ERROR_CHECK(err_code);

    err_code = app_timer_create(&button_long_press_timer, APP_TIMER_MODE_SINGLE_SHOT, button_long_press_handler);
    APP_ERROR_CHECK(err_code);
 
}

// Common handler for button events. Detects short and long presses.
static void button_common_handler(uint8_t pin_no, uint8_t button_action)
{
    static bool suppress_next_release_event = false;
    
    if(button_action == APP_BUTTON_PUSH)
    {
        // Start long press timer on PUSH event
        ret_code_t err_code = app_timer_start(button_long_press_timer, APP_TIMER_TICKS(LONG_PRESS_TIMEOUT_MS), (void*)&current_long_push_pin_no);
        if (err_code == NRF_SUCCESS)
        {
            current_long_push_pin_no = pin_no;
        }

        suppress_next_release_event = false;
    }
    if(button_action == APP_BUTTON_RELEASE)
    {
        // Stop long press timer
		(void)app_timer_stop(button_long_press_timer);
        
        // If this was the release event after a long press, ignore it.
        if(suppress_next_release_event){return;}
        
        if(pin_no == BUTTON_1){nrf_gpio_pin_toggle(LED_1);}
        if(pin_no == BUTTON_2){nrf_gpio_pin_toggle(LED_2);}
        if(pin_no == BUTTON_3){nrf_gpio_pin_toggle(LED_3);}
        
    }
    if(button_action == BUTTON_LONG_PUSH)
    {
        // Suppress next release event
        suppress_next_release_event = true;
    }
    if(button_action == BUTTON_COMBO_1_2)
    {
        // Suppress next release event
        suppress_next_release_event = true;
    }
    if(button_action == BUTTON_COMBO_1_3)
    {
        // Suppress next release event
        suppress_next_release_event = true;
    }
    if(button_action == BUTTON_COMBO_2_3)
    {
        // Suppress next release event
        suppress_next_release_event = true;
    }
}

/**
 * @brief Function for application main entry.
 */
int main(void)
{
    clock_initialization();

    nrf_gpio_cfg_output(LED_1);
    nrf_gpio_cfg_output(LED_2);
    nrf_gpio_cfg_output(LED_3);
    nrf_gpio_cfg_output(LED_4);

    one_sec_timer_init();
    //one_sec_timer_start();
    
    APP_ERROR_CHECK(NRF_LOG_INIT(NULL));
    NRF_LOG_DEFAULT_BACKENDS_INIT();

    NRF_LOG_INFO("BSP example started.");

    buttons_init();
    
    while (true)
    {
        NRF_LOG_FLUSH();
        __SEV();
        __WFE();
        __WFE();
        // no implementation needed
    }
}


/** @} */

[Hakon]

Hey, just wanted to tell you that I'm working on your case at the moment. I will let you know when I find the reason.

[csaller]

I just came accross the same issue:

First, you should definetly use APP_ERROR_CHECK for app_timer_start and app_timer_stop, which would had probably returned with an out of memory error.

Second, probably the timer queue is filled to quickly (or more quickly as items are removed from it). 
I cannot give you a direct solution, but maybe it is possible for you to reduce the number of stop/start actions. Or, less gracefully, you can increment APP_TIMER_OP_QUEUE_SIZE to a more fitting value (but i would not consider this a good solution)

[mrono]

Thanks csaller, I'll need to check if it really is the app_timer queue filling up. An out of memory condition shouldn't cause the code to hang though, it should just cause missed events.

Looking closer at the app_button debounce code I see that it also uses the same principle for button debouncing. I'm now beginning to see how the queue could fill up after only a few button presses.

I need to do some more testing on this. And in any case I need to find a way to process fast button presses without the code hanging. My current code hangs and the BSP example doesn't, so I'll need to check why is that. The queue sizes should be the same.

[Hakon]

It seems that it is the button_long_press_timer that causes the application to hang every time. I haven't found out why yet. Will tell when I have more information.

[mrono]

It doesn't seem to be the queue size. I increased that from 10 to 100, and got the same hang with just four button presses. Button bouncing may of course generate much more events than four, but if that was the cause of this then the unmodified BSP example should also hang very easily.

I also added checking of the return values from app_timer_start and app_timer_stop, and I'm not getting anything != NRF_SUCCESS. I used a led to indicate any errors as the hanging stops logging as well.