Bug in nRF UARTE driver, async Rx buffer handling

[Tom Weber]

Hello!

I am stress-testing the nRF54L15 devkit by sending it random-sized chunks of data over UART at 921600 baud, which the devkit code receives using the asynchronous API in Zephyr 4.0.99.

The test always fails after some time, the symptom is that uart_rx_buf_rsp() fails with -EACCES when called from my UART_RX_BUF_REQUEST handler.

By logging the events, I usually see this pattern:

UART_RX_RDY
UART_RX_BUF_RELEASED
UART_RX_BUF_REQUEST
UART_RX_RDY
UART_RX_BUF_RELEASED
UART_RX_BUF_REQUEST
UART_RX_RDY
UART_RX_BUF_RELEASED
UART_RX_BUF_REQUEST

However, these are the last events before the failure:

UART_RX_RDY          (len=7)
UART_RX_BUF_RELEASED
UART_RX_BUF_REQUEST
UART_RX_RDY          (len=7)
UART_RX_BUF_RELEASED
UART_RX_BUF_REQUEST
UART_RX_RDY          (len=64)
UART_RX_BUF_RELEASED (No REQUEST after this one)
UART_RX_RDY          (len=1)
UART_RX_BUF_RELEASED
UART_RX_BUF_REQUEST  (Here uart_rx_buf_rsp() fails with -EACCES)

I'm new to the driver code but this is my investigation:

The driver source is uart_nrfx_uarte.c in my case, so the implementation of uart_rx_buf_rsp() is uarte_nrfx_rx_buf_rsp(), which fails with -EACCES if (async_rx->buf == NULL).

The ISR handler seems to be uarte_nrfx_isr_async(). When receiving data, it calls endrx_isr(), which issues UART_RX_RDY and UART_RX_BUF_RELEASED and then shifts the buffers:

async_rx->buf = async_rx->next_buf;
async_rx->next_buf = NULL;

Next, UART_RX_BUF_REQUEST is typically called, and uart_rx_buf_rsp() sets next_buf.

Therefore, if endrx_isr() is called twice without issuing UART_RX_BUF_REQUEST inbetween (as in my log), both buf and next_buf will be NULL, which makes uart_rx_buf_rsp() fail on the next UART_RX_BUF_REQUEST, because buf is NULL.

Why does it happen? This comment in uarte_nrfx_isr_async() seems to explain it:

/* RXSTARTED must be handled after ENDRX because it starts the RX timeout
 * and if order is swapped then ENDRX will stop this timeout.
 * Skip if ENDRX is set when RXSTARTED is set. It means that
 * ENDRX occurred after check for ENDRX in isr which may happen when
 * UARTE interrupt got preempted. Events are not cleared
 * and isr will be called again. ENDRX will be handled first.
 */
if (<RXSTARTED and not ENDRX>) {
    <issue UART_RX_BUF_REQUEST>
}

Indeed, it happened when receiving a single byte at a high baud rate, so the new ENDRX may have happened during the same ISR call, which prevents UART_RX_BUF_REQUEST from being issued, and it seems the ENDRX was still pending because the next UART_RX_RDY came a few microseconds later.

(We use an Rx timeout of 16 microseconds which is in the ballpark of a single byte. We were getting framing errors before when using a longer timeout.)

So it seems the problem with postponing UART_RX_BUF_REQUEST is that we run out of buffers. Is there some consideration preventing you from always issuing the event after a read?

We are on a tight deadline to build a prototype, so I'm also looking for workarounds. One option could be to detect the missed UART_RX_BUF_REQUEST and in that case call uart_rx_buf_rsp() from UART_RX_BUF_RELEASED instead, even if it goes against the documentation.

[BrotherBear]

I found an issue with the same root cause (NULL async_rx->buf), but a more severe manifestation — and still present in NCS v3.3.0 / Zephyr 4.3.99.

We hit what looks like the same underlying defect described in this thread — async_rx->buf becoming NULL while the RX machinery still runs — but on the count-bytes-with-timer (cbwt) path and with a worse outcome. Instead of uart_rx_buf_rsp() returning -EACCES, the driver dereferences the NULL buffer and takes a precise bus fault.

Environment

• nRF54L15, NCS v3.3.0 (Zephyr 4.3.99)
• CONFIG_UART_ASYNC_API=y, cbwt path active (CONFIG_UARTE_NRFX_UARTE_COUNT_BYTES_WITH_TIMER — DT node has a timer property + frame-timeout support)
• 9600 8N1, no hardware flow control; the attached device begins streaming bytes at power-up
• Low-power RX off; RX enabled once and left running; two ping-pong buffers handed back via uart_rx_buf_rsp() from UART_RX_BUF_REQUEST

Trigger (different from the high-baud / short-timeout case in this thread): we hit it when uart_rx_enable() is called on a line that is already receiving bytes (a peripheral that streams immediately at power-up). It is intermittent — only a minority of resets. Delaying RX-enable until the line is idle hides it, consistent with the NULL-buffer window being entered when the first buffer completes almost immediately at enable.

Fault (captured against the exact flashed ELF)

***** BUS FAULT *****
  Precise data bus error
  BFAR Address: 0x2
r0/a1:  0x00000002   ...   r14/lr: 0x00011403
EXC_RETURN: 0xfffffff1        (fault taken in handler / ISR mode)
Faulting instruction address (r15/pc): 0x00024b56
FATAL: reason 25 (K_ERR_ARM_BUS_PRECISE_DATA_BUS)

addr2line against the flashed ELF:

$ arm-zephyr-eabi-addr2line -f -i -e zephyr.elf 0x24b56 0x11402
memcpy
??:?
fill_usr_buf
zephyr/drivers/serial/uart_nrfx_uarte.c:1113

So the PC is the memcpy byte-copy store, called from fill_usr_buf(), and the memcpy destination register is 0x2, i.e. &async_rx->buf[usr_wr_off] with async_rx->buf == NULL and usr_wr_off == 2 (hence BFAR = 0x2). The fault is taken in ISR context (EXC_RETURN 0x...f1).

Root cause (cbwt path)

fill_usr_buf() copies into the user buffer with no NULL check:

/* uart_nrfx_uarte.c:1106 */
memcpy(&async_rx->buf[cbwt_data->usr_wr_off], &buf[cbwt_data->bounce_off], cpy_len);

async_rx->buf can be NULL here for exactly the reason described in this thread — notify_rx_rdy() shifts async_rx->buf = async_rx->next_buf (uart_nrfx_uarte.c:1010), which is NULL if no next buffer was supplied in time. The drain paths that reach update_usr_buf() → fill_usr_buf() (the timer byte-count ISR and the RX timeout) do not guard against a NULL async_rx->buf; only cbwt_rxto_isr() does (if (async_rx->buf), uart_nrfx_uarte.c:1441 and :1445).

In other words, the -EACCES from uart_rx_buf_rsp() reported here and this bus fault look like two faces of the same NULL-buffer window: the buf_rsp path returns an error, but the cbwt drain path dereferences the NULL instead.

Suggested fix

Mirror the guard cbwt_rxto_isr() already has: bail out of update_usr_buf() / fill_usr_buf() (skip the memcpy and the buffer-full handling) when async_rx->buf == NULL, so a drain event that lands in the "buffer released, next not yet supplied" window is a no-op instead of a NULL dereference.

Happy to share the full ESF dump and a minimal reproducer. I've also opened a Zephyr GitHub issue for the driver fix: github.com/.../113812.

[Kazi Afroza Sultana]

Hello,

Thanks for sharing the fix of this bus fault issue.

I will report and let relevant team to know about this.

By the way, the github link does not show any information.

BR
Kazi