App Timer assert - APP_TIMER_SAFE_WINDOW

[Tom]

I have started getting an assert in my code while testing new functionality.

I am using SDK 17.1.0 and the nRF52840 DK

The assert is line 321 in app_timer2.c

        /* If assert fails it suggests that safe window should be increased. */
        ASSERT(app_timer_cnt_diff_compute(drv_rtc_counter_get(p_instance),
                                          drv_rtc_compare_get(p_instance, 0)) < APP_TIMER_SAFE_WINDOW);

Looking at the the description of APP_TIMER_SAFE_WINDOW_MS in sdk_config.h

// <o> APP_TIMER_SAFE_WINDOW_MS - Maximum possible latency (in milliseconds) of handling app_timer event.
// <i> Maximum possible timeout that can be set is reduced by safe window.
// <i> Example: RTC frequency 16384 Hz, maximum possible timeout 1024 seconds - APP_TIMER_SAFE_WINDOW_MS.
// <i> Since RTC is not stopped when processor is halted in debugging session, this value
// <i> must cover it if debugging is needed. It is possible to halt processor for APP_TIMER_SAFE_WINDOW_MS
// <i> without corrupting app_timer behavior.

#ifndef APP_TIMER_SAFE_WINDOW_MS
#define APP_TIMER_SAFE_WINDOW_MS 300000
#endif

Am I correct in thinking this means that this will assert if, for (1024-300) seconds, or ~12 minutes, the app_timer event is not handled?

If so, how do I go about debugging which timer isn't handled?

I initially saw this after leaving a board running for around 36hrs. I think I saw it again, didn't get the error log unforunately, after over 24 hours. I have tried to set up a test to replicate is and saw it withing 4-5 hours. It is still in sat in this state with the debugger attached but I don't know where to begin with working out the cause.

The debugger output is:

[03624616] <error> app: ERROR 3735928559 [Unknown error code] at nRF5_SDK_17.1.0_ddde560/components/libraries/timer/app_timer2.c:321
PC at: 0x000362B3
[03624623] <error> app: End of error report

I want to understand why this is occuring, why it isn't after a fixed period of time and whether increasing APP_TIMER_SAFE_WINDOW_MS is a fix or a bandaid.

[Susheel Nuguru]

what kind of app_timer registration are you having? probably you should have some debug logs that print when you register a timer and also some debug logs when the timer callback is called. This becomes easier if it is a APP_TIMER_MODE_SINGLE_SHOT timer. This should not have happened if you are not disabling the application timer interrupts. If you have not changed anything in the sdk_config.h file and the app_timer2 code, then it looks like this is a bug that seems to very hard to trigger and debug.

[Tom]

Thanks for getting back to me Susheel.

By registration do you mean calls to app_timer_create?

There are 4 repeated timers and 2 single shot timers. When the assert occurred 3 of the repeated timers would have been running and neither of the single shot timers should have been running (triggered by user input, but unit was left testing and wouldn't have received the correct triggers to start the single shot timers).

They are all created at boot up, once the system is initialised there are no other timers created.

All the timers have their own callback functions and both the single shot timers log that they have been called (there were no logs to indicate that the single shot timers handlers were called but I will verify this again).

Of the remaining timers, one is responsible for feeding the WDT, so seems unlikely to be the one not handled, otherwise the WDT would have kicked in. The others drive a bluetooth notification and toggling a status LED.

I will add debug logs to the create calls and the LED toggle, I will log bluetooth activity and hopefully I'll be able to narrow down which isn't being handled.

Once I can identify which isn't being handled, what would be the next steps to working out why it isn't being handled?

[Tom]

Thanks Sushell, I forgot to circle back on this one but the test was running for almost a week without any issues.

Are there plans to issue an update to the SDK to fix the issue?

[Susheel Nuguru]

Tom said:

Are there plans to issue an update to the SDK to fix the issue?

Yes, hopefully this will be fixed soon, i will send a gentle reminder to the team.

[tellg]

Any new status on this? I am using the same nrf5SDK version (17.1.0) and sometimes experience this too.

[Susheel Nuguru]

Hi,

There unfortunately be no minor fixes coming into the SDK as I have learnt there are no planned released for nRF5 SDK as of now. All resources and roadmaps are for newer nRF Connect SDK.

[tellg]

Is the suggested fix a verified fix recommended by Nordic?

[Susheel Nuguru]

It is verified by the customer and not regression tested on our end. That is a workaround that is suggested by Nordic to be used at your own risk since we do not do any production release testing on that workaround and most likely will not be able to do it in the near future on the older SDK solutions.

[Rost]

Sorry guys, I assumed initially that's a joke, but I see that quite serious suggestion.

Once a developer puts any kind of ASSERT, usually (not always) it protects from some more crucial conditions, generally protect one developer from another developer's stupidity, in common case it avoid many obvious errors in production. So smart developers try to insert such ASSERTs to show on early stage of code about wrong arguments, incorrect conditions, problems on runtime.

I caught the same error today, that's why I've been writing the message right now.I don't know a reason why it happens in my code, but what should NOT be done absolutely: to comment the ASSERT in own SDK code while you haven't get deep understanding why the timer handling goes out of the range of expected lag window.

Especially for people with such "easy fixes" approach in their head: just turn into Release mode from Debug, so you get no ASSERT macro anymore, but the assert call means you have got already an issue in your code.

[Susheel Nuguru]

Rost, 

Good thoughts, I agree to most of it. But sometimes the developer puts an assert and figures out later when the assert is hitting in a condition when the use case is genuine, then their assumption of the state machine in a particular state is wrong. In this case, the actual developer thinks that the assert is catching a lot of false positives so probably that assert should not be there. 

In General it is a good habit for a developer to put debug asserts in places where they know a condition should not occur, but sometimes (rarely), those asserts have bugs aswell.