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

Softdevice Assert at PC=0x15810 (S132 7.2.0) / RTC clock drift when using timeslot

I'm trying to narrow down the cause of a Softdevice assertion happening in S132 7.2.0 at PC=0x15810.

We set up a proprietary RF project which utilises parts of the SDK for Mesh (specifically, the timeslot implementation and bearer_handler) because it provides a safe base to run high performance timeslot applications on. Unfortunately I do have one device which runs into a softdevice assertion at instruction 0x15810. I feel that it is a timing issue - maybe the device is operating at the outer limits of the clock accuracy, because while the issue appears sporadically on Development Kits or other devices, this specific device does trigger it quite often.

  • What exact assertion fails when at PC=0x15810?
  • Does the Softdevice shut down TIMER0 before doing this test or after an assertion fails?
  • Are timing assertions made by the softdevice based on RTC0?
  • Is there a reason why TIMER0 in the mesh stack is running in 24-bit mode as opposed to 32-bit mode?

Any help is greatly appreciated.

EDIT: In the meantime I think I found the cause of the issue. Assuming that the timing assertions by the Softdevice are done using RTC0, there seems to be a rather large discrepancy between the RTC0 timing and TIMER0 timing. After 9'999'249us on TIMER0 pass, RTC0 has counted 10'000'732us, so they're almost 1ms apart!

The device in question is running the LFCLK from the RC oscillator and we do usually have BLE deactivated. I did assume that the softdevice takes care of adjusting for clock drift, but could it be that I have to somehow take care of this manually?

EDIT2: Note that - as we're using the nRF SDK for Mesh as a codebase - when calculating the available time on the timeslot, we should already account for clock drift per the following calculation:

(p_timeslot->length_us * (m_lfclk_ppm + HFCLOCK_PPM_WORST_CASE)) / 1000000;

EDIT3: I previously wrote that we "do usually have BLE deactivated". What I actually mean by this is that most of the time the device is neither connected nor is it currently advertising. So there is no BLE activity to schedule by the softdevice. Timeslots are always active, though.

Parents
  • Hi,

    The assert at 0x15810 is because the SoftDevice got an unexpected raio interrupt, which is typically because the application used the radio outside of the timeslot. Regarding LFCLK calibration that is handled automatically by the SoftDevice. And in any case RTC drift should not be relevant here, as there is just a single low frequency clock source in the nRF, so even if there was a significant drift, the app and SoftDevice would be drifting "together".

    Looking at your timeslot length calculation, it seems like you add the worst case drift value to the duration. Is that intentional? Should it not be subtracted?

  • Hi Einar,

    Besides the issue with the discrepancies between RTC0 time and TIMER4 time, I noticed that TIMER0 is shut down while control has not yet returned to the softdevice.

    Just to detail the setup: The issue seems to always occur at the same point in software. While a timeslot is granted, I have a timer running at highest IRQ priority, triggering a radio interrupt via software (NVIC_SetPendingIRQ(RADIO_IRQn)). This is used for frequency hopping and implemented like this for easier handling of the radio control state machine in our proprietary receiver.

    The softdevice seems to assert after this interrupt has fired. So the cause of the assert that you have given would make sense. BUT at the point the assertion occurs, the timeslot has not ended!  It was still ongoing. I added a few checks into the above IRQ handler and noticed that at the point where the assert would occur, the timeslot *should* have already ended, but for some reason TIMER0 which should be in charge of ending and cleaning up the timeslot was shutdown. I.e. the CC and INTENSET registers are cleared and when I try to manually capture the current timer value using the debuger (setting TASKS_CAPTURE[n] to 1), nothing happens. I do have no code or PPI whatsoever that would shut down TIMER0 in my software and it is only used for controlling timeslot duration - and sometimes capturing its value. So it has to be shut down by the softdevice at some point.

    Could you imagine when and why TIMER0 could get shutdown by the softdevice?

    Also, asking again; does the assert 0x15810 also fail if the timeslot during which the Radio IRQ is invoked went on for too long?

    Thanks for your help.

  • Hi Mike,

    Thank you for that input, that could be relevant. I have forwarded it to the mesh team.

    Einar

  • Hi Einar,

    It's been 10 days since I heard from you and tought I should ask if there are any new findings or estimates as to when there could be!

    The issue is somewhat urgent as it concerns a product which is running in pre-production testing and the frequent resets - all due to the described softdevice asserts - seriously impact the usability of the product.

    Thank you for your help & best regards,

    -mike

  • Hi Mike,

    I am sorry this has take some time. I have talked to the mesh team and they are looking into this. I will let you know when they make some progress or have some interesting observations to share.

    Einar

  • Hi Mike,

    The team has looked more into this but have not got to the bottom of it. They suggest that you can try to they increase TIMESLOT_END_SAFETY_MARGIN_US in steps of 100 us upto 1000 us.

    Einar

  • Hi Einar,

    I tried to subsequently increase the TIMESLOT_END_SAFETY_MARGIN_US until either not observing any Softdevice Asserts or reaching 1000us. Unfortunately, I did always observe the described softdevice assert at some point. It looks like increasing it reduces the probability of the asserts' occurence, though which is at least something.

    Still hoping for a definitive solution!

    Thank you & best regards,

    -mike

Reply
  • Hi Einar,

    I tried to subsequently increase the TIMESLOT_END_SAFETY_MARGIN_US until either not observing any Softdevice Asserts or reaching 1000us. Unfortunately, I did always observe the described softdevice assert at some point. It looks like increasing it reduces the probability of the asserts' occurence, though which is at least something.

    Still hoping for a definitive solution!

    Thank you & best regards,

    -mike

Children
  • Hi Mike,

    This is a tricky one it seems. I cannot promise anything at this point but I have forwarded this to the team. I will let you know if they make any progress.

    Einar

  • Hi Einar,

    While trying to reproduce another timeslot-related issue (Softdevice event handler continuously called with NRF_EVT_RADIO_BLOCKED), I found another angle by which I seem to be able to reproduce the same basic issue.

    Hung Bui, the support engineer in the linked devzone entry, convinced me to try to reproduce the other issue based on his nRF52 BLE - ESB Timeslot example. Doing this, I managed to reproduce this issue here, wehere the softdevice event handler unexpectedly gets called with NRF_EVT_RADIO_SESSION_IDLE on an nRF52DK (PCA10040).

    Steps to reproduce with his example:

    1. Get the linked example to run as per its instructions.
    2. Attach the patch attached to this comment
    3. Run the example
    4. Connect a BLE central to the peripheral (advertising as "Nordic_UART").

    This will result in NRF_EVT_RADIO_SESSION_IDLE being invoked within a few milliseconds after establishing the BLE connection.

    The patch contains the following changes:

    • Added and enabled GPIOs for debugging:
      • P0.03 - Signals whether device is in timeslot
      • P0.04 - High while in radio callback (signal ID is indicated by repeated toggles)
      • P0.28 - Set when callback_action set to NRF_RADIO_SIGNAL_CALLBACK_ACTION_EXTEND, cleared on EXTEND_SUCCEEDED or EXTEND_FAILED
      • P0.29 - High while serving SIGNAL_TYPE_TIMER0
      • P0.30 - High while in softdevice signal handler (signal ID is indicated by repeated toggles)
      • P0.31 - High while serving TIMER0 interrupt where timeslot is ended.
      • P0.25 - Indicates EXTEND_SUCCEEDED.
    • Reduced the length_us parameter in the radio request to 3800 in case a timeslot is BLOCKED or CANCELED.

    example-uart-esb-timeslot.patch

    So, the issue occurs immediately if the length_us of the requested timeslot is reduced from 5000 to 3800. I did not play around with the values any further!

    I hope this may help you in getting to the cause of this issue! In the meantime, I'll see if increasing the minimum length requested may resolve it in may application!

    Best regards,

    -mike

  • Hi Mike,

    Thanks for the update. I will forward the information to the team.

  • Hi Einar,

    Thanks. Just for the sake of completeness, I also attached the Saleae Logic 2 traces I screenshotted further up. The first one is from our application, the second one from the mesh example.

    softdevice_assert_logic_traces.zip

    Additionally, I'd like to ask what the Softdevice assert at PC=0x24f24 indicates? I assume this is the one that gets raised when the timeslot was ended too late? I very rarely see this one (as opposed to the "regular" one at PC=0x15810) and assume it can be averted by the workaround suggested above, increasing TIMESLOT_END_SAFETY_MARGIN_US.

    Looking forward to the results of the team & thanks for your support!

    -mike

  • Hi Mike,

    Thanks for the traces.

    Regarding the assert at PC=0x24f24 that can happen if the application used too much time in the callback handler as the SoftDevice timing may be thrown off.

    Einar

Related