Zephyr async uart driver corrupts data on UARTE frame timeout

[Nick Ewalt]

Related to the issue reported here:  RE: Framing Errors seen on nRF54L15 UART. Is it super sensitive to stop bit timing? 

If the UARTE FRAMETIMEOUT fires while new data is coming in then some bits of the new data is dropped, leading to corruption and potentially framing errors.

I've attached a loopback sample app that reliably reproduces this issue within seconds on the nRF54L15 DK. Simply connect a jumper wire between pins P1.11 and P1.12 then build and flash the image for the nrf54l15dk/nrf54l15/cpuapp board.

async_uart_echo.tar.gz

[Nick Ewalt]

On my board with a frame timeout of 5000 us at 115200 baud I see that delays between 4920 us and 5430 us fail, but everything outside of that range works perfectly.

Here are the logs from the start of that failing region. Full logs attached.

[00:00:06.368,093] <dbg> app: main: testing delay of 4900 us
[00:00:06.379,810] <dbg> app: on_rx_data_ready: RX data
                              30 31 32 33 34 35 36 37  41 42 43 44 45 46 47 48 |01234567 ABCDEFGH
[00:00:06.434,494] <dbg> app: main: testing delay of 4910 us
[00:00:06.446,230] <dbg> app: on_rx_data_ready: RX data
                              30 31 32 33 34 35 36 37  41 42 43 44 45 46 47 48 |01234567 ABCDEFGH
[00:00:06.500,933] <dbg> app: main: testing delay of 4920 us
[00:00:06.507,083] <dbg> app: on_rx_data_ready: RX data
                              30 31 32 33 34 35 36 37  41 42 43 44 45          |01234567 ABCDE   
[00:00:06.512,695] <dbg> app: on_rx_data_ready: RX data
                              47 48                                            |GH               
[00:00:06.517,343] <err> app: unexpected number of bytes received: 15
[00:00:06.517,355] <err> app: test_buffer
                              30 31 32 33 34 35 36 37  41 42 43 44 45 47 48    |01234567 ABCDEGH 
[00:00:06.617,408] <dbg> app: main: testing delay of 4930 us
[00:00:06.623,544] <dbg> app: on_rx_data_ready: RX data
                              30 31 32 33 34 35 36 37  41 42 43 44 45          |01234567 ABCDE   
[00:00:06.629,226] <dbg> app: on_rx_data_ready: RX data
                              1d 21 ff                                         |.!.              
[00:00:06.633,823] <err> app: got corrupted data
[00:00:06.633,835] <err> app: test_buffer
                              30 31 32 33 34 35 36 37  41 42 43 44 45 1d 21 ff |01234567 ABCDE.!.
[00:00:06.733,886] <dbg> app: main: testing delay of 4940 us
[00:00:06.740,030] <dbg> app: on_rx_data_ready: RX data
                              30 31 32 33 34 35 36 37  41 42 43 44 45          |01234567 ABCDE   
[00:00:06.740,108] <dbg> app: on_rx_data_ready: RX data
[00:00:06.740,114] <err> app: UART framing error
[00:00:06.740,194] <dbg> app: on_rx_data_ready: RX data
[00:00:06.740,200] <err> app: UART framing error
[00:00:06.745,701] <dbg> app: on_rx_data_ready: RX data
                              fd                                               |.                
[00:00:06.750,362] <err> app: unexpected number of bytes received: 14
[00:00:06.750,377] <err> app: test_buffer
                              30 31 32 33 34 35 36 37  41 42 43 44 45 fd       |01234567 ABCDE.  

async_uart_log2.txt

[Nick Ewalt]

Note that in order to not have the driver immediately stop the peripheral on the first framing error you need to comment the call to uarte_nrfx_rx_disable(dev) in error_isr (drivers/serial/uart_nrfx_uarte.c).

[Elfving]

Hi,

Thanks for the heads-up, and the way to reproduce it. 

We're aware of the issue now and are working on it. Please talk to your RSM if you need this solved urgently and want us to prioritize this bug.

Regards,

Elfving