Using LIBUARTE during flash operations

[oguzcan oguz]

Hi, 

We are using a NRF52840 chip (SDK 15.3) in an application where we use the softdevice (S140) in combination with 2 UARTS: one for sending out debug output (UART0 - nrfx_uart), and another one for communication with another MCU.

During (internal) flash writes when doing bonding or garbage collection, the CPU stalls for quite a long time (~85 ms during flash erase). In order to make sure we do not lose data from the other CPU we have been looking into the 'nrf_libuarte_async' functionality.

It is constructed by using:

NRF_LIBUARTE_ASYNC_DEFINE(libuarte, 1, 1, NRF_LIBUARTE_PERIPHERAL_NOT_USED, 2, 512, 3);

(UARTE1, TIMER1 for byte counting, TIMER2 for timeout, buffer size of 512).

During normal operation it works fine, but after the CPU stall, we ofter end it in an error in 'nrf_libuarte_async_rx_free', stating "Unexpected RX free input parameter.". In this case the 'rx_free_cnt' is bigger than the 'chunck_size'. We are following the example of examples\peripheral\experimental_libuarte and free the buffer in the NRF_LIBUARTE_ASYNC_EVT_RX_DATA event.

Could you give any indication what can be the issue here? We couldn't find much documentation wrt to this driver. 

Thank you.

[ovrebekk]

Hi

What baudrate is the UART1 running at?

How large is the UART utilization from the connected MCU? Do you think there is a risk that the UART RX buffer could fill up during those ~85 milliseconds?

Are you using hardware flow control or not?

Best regards
Torbjørn

[RoyCreemers]

Response on behalf of my collegue: The baudrate is 115200. There is no risk that the UART Rx buffer could fill up. The connected MCU can only send one single message (which is less <400 bytes),then it waits for a response. Unfortunately there is no possibility that to use hardware flow control

[RoyCreemers]

Sharing the code is possible, but I'm not sure this will help a lot (of course I will share if you think is has benefits). It is part of quite a big C++ application, involving multiple MCUs.

Our "application core" has a button which triggers an event to toggle advertising. This is communicated by UART to the Nordic BLE MCU. In his turn, this sends back a response over UART, and toggles advertising (so in this case there is a high change that there is some UART activity during softdevice activity).

The start of the advertisement is done by:

sd_ble_gap_adv_start(advertisementHandle, APP_BLE_CONN_CFG_TAG);

the stop is done by:

sd_ble_gap_adv_stop(advertisementHandle);

The scenario above can easily be reproduced here, the assertion occurs at least one out of 10 times. I share your oppinion that they can also occur at other times (I also saw some softdevice assertions during our automated testing, not related to advertisement... just during normal BLE transmittions)

[ovrebekk]

Hi Roy

Are you able to log these asserts, or use the debugger to trace from where they occur in the Nordic device?

Do you know if the sd_ble_gap_adv_start or sd_ble_gap_adv_stop functions return an error, or if the assert are exclusively generated by the SoftDevice?

I agree receiving your whole code base is unlikely to be helpful, but it might be interesting if you can isolate and send the parts of the code running on the nRF52 side that controls the SoftDevice (including starting and stopping advertising). 

Best regards
Torbjørn

[RoyCreemers]

The asserts seem to be exclusively from the softdevice. Return values of advertising start & stop are always ok (NRF_SUCCESS). Don't know if there is much relevant information in the fault itself.

'id' is always '1' (NRF_FAULT_ID_SD_ASSERT)

pc = 0x16e5a (or close)

info = 0;

)

[ovrebekk]

Hi Roy

When you say 0x16e5a or close, do you mean this changes from time to time, or you're not sure the exact address?

The exact address can be important when reporting this to the stack developers. 

To summarize, you confirm that this can happen with or without flash erase running?

You confirm that this will only happen when using the libuarte_async library?

How do you process UART events in the application? 
Are you running a lot of event processing in the events directly, or do you process it later in main/thread context?

Do you know what interrupt priority the UART events are returned in?

Best regards
Torbjørn

[RoyCreemers]

Hi Torbjørn,

I was preparing all your questions with answers, till I reached the final question about the interrupt priority. When searching through our code, I realized that we did not specificy the 'int_prio' field (it was added in the patch we received). It was undefined and pointed out to '112' (or some other high value). Once I changed it to  irq priority 5, the issue is gone!! Thanks!

Unfortunately I still see that data gets corrupted some times. I will dive into this first to see if I can get a reproducable scenario. For now, it reproduces more often in case I reduce the timeout.

[ovrebekk]

Hi Roy

That is good to hear

One of the SoftDevice developers confirmed that the assert was related to a delayed interrupt in the SoftDevice, which happens if you configure interrupts to run at the highest priorities (should be reserved for the SoftDevice only). 

As soon as you have more information on the corruption issue just let me know. 

I assume you are talking about UART corruption?

Does it happen both on RX and TX?

Does it happen with or without flash access enabled?

And any more details you think might be relevant. 

Best regards
Torbjørn

[RoyCreemers]

Let me start with answering some of your previous questions:

Q:To summarize, you confirm that this can happen with or without flash erase running?
A:This happens without flash erase.

Q:You confirm that this will only happen when using the libuarte_async library?
A: Yes. When using the nrfx_uarte driver directly, we did not have this issue.

Q:How do you process UART events in the application? Are you running a lot of event processing in the events directly, or do you process it later in main/thread context?
A: Data is put in a buffer, and processed in the main thread. No processing is handled in IRQ context. Same for BLE events: everything is queued for processing outside of interrupt context.

Q: Do you know what interrupt priority the UART events are returned in
A: The "irq_prio" is filled in with 5

The corruption only happens on the receive action. I looks like the problem occurs in case I receive new data during the timeout. What I see only the logic analyzer is that we often have a UART sequence looking llike the following

<~200 bytes on UART Rx>  <no communication for ~5 ms>  <~200 bytes on UART Rx> <no communication for ~X ms)

Initialily, I had the timeout set to 5 ms. I noticed the error very often. It looked like the data from the first and second burst where mixed.

Once I set the timeout to 15 ms, I see it very rarely: actually only when my "no communication" window is equal to X.

Now I reduced it to 2 ms, it works without issues (in the 15 minutes I tried this), probably because this "no communication" window is very unlikely to happen.

[ovrebekk]

Hi Roy

RoyCreemers said:

A: The "irq_prio" is filled in with 5

That's a bit odd. Legal values when using the SoftDevice are 2, 3, 6 and 7. 

Defines for setting IRQ priority can be found in app_util_platform.h in the SDK:

#define _PRIO_SD_HIGH 0
#define _PRIO_SD_MID 1
#define _PRIO_APP_HIGH 2
#define _PRIO_APP_MID 3
#define _PRIO_SD_LOW 4
#define _PRIO_SD_LOWEST 5
#define _PRIO_APP_LOW 6
#define _PRIO_APP_LOWEST 7
#define _PRIO_THREAD 15

If the problem seems to be solved when the timeout is shorter than the time between bursts I expect the issue to be triggered when the DMA buffer fills up in the middle of a burst, but the hardware should handle this if you set up two buffers and configure the DMA to switch to the second buffer automatically once the first fills up. 

I can double check with the designers if the driver is set up to do this. 

Have you done more testing at 2ms to see if this setting seems reliable?

Best regards
Torbjørn

[oguzcan oguz]

When setting priority to _PRIO_APP_LOW, the issue is still there. I did more testing with the 2 ms, and that seems to be reliable in our test test setup - problem is that there might be sequences where the second burst is equal to that timout as well.

Please double check your hypothesis with the designers.

[ovrebekk]

Hi

As it seems the developer did not agree with my hypothesis. The driver does use the double buffering technique, and they have tested it with interrupts of up to 100ms to make sure it can handle long periods of 'stalls' without losing data. 

He asked me if you could try to enable logging for this module, and see if any errors are returned during operation?

Can you give some more information about the data corruption you see?
You mentioned the data appears to be mixed, do you mean that every other byte is from the first burst or the second?

If the problem persists I think I will have to setup a small test application here to try to reproduce the issue. 

Best regards
Torbjørn