Assertion fail in timer_fired()

ijager commented 2 years ago

I just updated a project to the latest version of the stack (commit dc6307c150744) and now I keep hitting assertion fails in timer_fired() at line 405

assert(NG(timers)[NG(next_event)].f != 0x0);

Before it crashes it seems to hang (the code seems to loop here) for quite a long time in void HAL_PWR_EnterSTOPMode(uint32_t Regulator, uint8_t STOPEntry) , specifically on the last line:

  CLEAR_BIT(SCB->SCR, SCB_SCR_SLEEPDEEP_Msk);

Some debug output before it crashes:

Program: start
measurement took 287 ms
[001] sleep (mode 1) @ 2129
[002] EXTI->PR 0
[003] wake up @ 2319
measurement took 288 ms
[004] sleep (mode 1) @ 2623
[005] EXTI->PR 0
[006] wake up @ 6960
[007] sleep (mode 1) @ 10352
[008] EXTI->PR 0
[009] wake up @ 41134
[010] sleep (mode 1) @ 41141
[011] EXTI->PR 0

Some notes:

This is a project with a relatively fast repeating measurement task @ 2Hz. Which is much faster than once per hour we did in another project. Not sure if that could be a trigger for this timer assertion.
If I do not disable the Watchdog, it keeps working for much longer (a few minutes), however in the end it still crashes at the same place

I am not really sure yet how to debug this further, any suggestions on what steps to take, or what debug output could be useful?

LOorts-Aloxy commented 2 years ago

Hi! Is this still the case with other sleep modes (changing FRAMEWORK_SCHEDULER_LP_MODE to 0, 1 or 255)? Can you also reproduce it in an independent, bare-bones application?

ijager commented 2 years ago

Changing FRAMEWORK_SCHEDULER_LP_MODE does not seem to have any effect, However I did manage to make a minimum reproduction of this issue:

#include "framework_defs.h"
#include "hwleds.h"
#include "platform.h"
#include "scheduler.h"
#include "timer.h"

// this is needed as we're not using the filesystem, also possible to remove blockdevices from platf_main.c
uint8_t d7ap_volatile_files_data[FRAMEWORK_FS_VOLATILE_STORAGE_SIZE];

static void end_flash() { led_off(0); }

void led_flash()
{
    led_on(0);
    timer_post_task_delay(&end_flash, TIMER_TICKS_PER_SEC * 0.1);
}

void repeating_task()
{
    led_toggle(0);
    printf("Repeating task\n");
}

void bootstrap()
{
    printf("Device booted at time: %ld\n", timer_get_counter_value());

    sched_register_task(&repeating_task);
    sched_register_task(&end_flash);

    led_flash();

    timer_post_task_prio(
        &repeating_task, timer_get_counter_value() + 1, DEFAULT_PRIORITY, TIMER_TICKS_PER_SEC / 2, NULL);
}

It seems that calling led_flash() which schedules a task, just before starting the repeating task causes the repeating task to only be run twice before it crashes.

The serial output is:

Device booted at time: 0
Repeating task
Repeating task
Device booted at time: 0
Repeating task
Repeating task
Device booted at time: 0
Repeating task
Repeating task

So we can see that it reboots due to the watchdog. If it wouldn't crash we would see Repeating task printed ad infinitum.

Tested on the B_L072Z_LRWAN1 platform. I just replaced simple_leds/app.c content with the code above and ran cmake ../Sub-IoT-Stack/stack -DAPP_SIMPLE_LEDS=y; make

LOorts-Aloxy commented 2 years ago

I created a pull request (https://github.com/Sub-IoT/Sub-IoT-Stack/pull/121) with a possible fix, tried it on the example, and it seems to work, could you test if it's also working for your actual application?

ijager commented 2 years ago

That's fast! Just tested it and it seems to work indeed!

LOorts-Aloxy commented 2 years ago

that's great news! Happy to help!

Sub-IoT / Sub-IoT-Stack

Assertion fail in timer_fired() #120