Problem with UART receiving timeout

[beal_hms]

Hi!

We are using an ESP32-WROVER together with ESP-IDF 5.3, and the problem is we are loosing some messages in a stress test due to a non-desired frame splitting, where it seems clear the ESP-IDF function is not respecting the desired RX timeout. What we do:

1) Check if the UART has some available bytes to be read, using the "uart_get_buffered_data_len"
2) If so, we call the "uart_read_bytes" with a timeout. The length is set to 256, which is our maximum frame (but this issue happens when receiving just 8 bytes), and the timeout is set to 3.5 times the byte time. For example: at 115200bps -> byte time with 11 bits = 95us -> 3.5 times = 334us.

It works fine almost all the time, but if we run a stress test, we can reproduce this issue with less than a minute. The problem comes when the "uart_read_bytes" function returns WHILE bytes are still being received. Here an oscilloscope capture where I set a pin high just after the "uart_read_bytes" returns:

image-20250716-110351.png (13.73 KiB) Viewed 612 times

In the previous case, the function returns the first 5 bytes. If just after that we call the function again, we get the rest of the 3 bytes.

Is this a known issue? Right now we solved it by adding a sched_yield() after the "uart_read_bytes", then checking again if there is some extra available byte, and keep calling the "uart_read_bytes" until no more bytes are available (although it never happened more than once in one same frame). But we prefer to rely on the UART driver to do so.

Thank you in advance!

[MicroController]

Not sure if I'd call it an 'issue', but generally, relying on receiving staying in-sync with the hardware's and driver's RX buffers can be fragile, because it relies on certain inner workings of the UART and driver as well as timing.
To work around that, you can use variations of while(!receivedEnoughBytes()) { uart_read_bytes(..., numBytesRemaining, timeout); }, possibly in conjunction with this: viewtopic.php?t=45650#p147896

[beal_hms]

Thanks for your fast response

Seeing this:

b) wait for exactly that length and only timeout if that couldn't be accomplished, returning whatever it has received?
Yes, b) is how it works.

I'm not sure if you understood exactly our problem. The previous quoted case is not our case, we are not expecting a fixed number of bytes because we don't know how many bytes we will receive beforehand. Our length is set to 256 because we NEVER reach 256, we will always rely on the timeout. Furthermore, we are not using UART events, we just have our thread, exactly like you suggested here:

When you don't need the non-data UART events, you just call uart_read_bytes(...) from any regular task; it will block until data has been received or it timed out.

So, we only call "uart_read_bytes(...)" when we know there is at least 1 byte available (using the "uart_get_buffered_data_len"). And despite this, the function returns BEFORE all bytes are received, like I showed in the oscilloscope capture.


I wouldn't consider it an issue, I would directly consider it a bug. ESP-IDF offers a timeout feature that is not respected, if that function doesn't perform well, or if you say that "it's fragile", then maybe that feature should be removed from ESP-IDF so that we can implement our own way to do what is expected. That being said, if someone can perform well that should be the driver, which is the lowest level, not functions called from freeRTOS, which adds non well controlled delays due to the scheduler and their priorities.

Our case seems a pretty common situation, we are not doing anything special here. What maybe we only did different is stress it by sending lots of messages, but it's something possible in our current product.

Thank you!

[beal_hms]

More info: I found out that the function "uart_read_bytes" also returns when there is some UART error. I know the UART data is OK because as seen in the oscilloscope capture, the data is correctly parsed. But just to make sure it was not the case, I added this code:

Code: Select all

		uart_read_bytes(static_cast<uart_port_t>(m_uart_device.uartInstance), m_rx_buff, m_frame_size, m_interFrame_tout_ticks);

		uart_event_t event;
		while (xQueueReceive(m_uart_queue, &event, 0))  // Non-blocking poll
		{
		    switch (event.type)
		    {
		    case UART_FRAME_ERR:
		    case UART_PARITY_ERR:
		    case UART_BREAK:
		    case UART_BUFFER_FULL:
		    case UART_FIFO_OVF:
				gpio_set_level(GPIO_NUM_26, 1);
		        break;
		    default:
		        break;
		    }
		}

But when the initial described problem happens, the pin is not set high either. Just to discard this case.

Thanks!

[MicroController]

By the way: The timeout for uart_read_bytes() is given in ticks, which by default is 10ms per tick. 1 tick is the shortest timeout possible; anything less than that is equivalent to a 0 timeout, i.e. no waiting at all.
Also, if you care about low latency, make sure to set the UART's RX full and RX timeout thresholds accordingly.

[beal_hms]

Hi!

Our tick rate is 1000Hz:

Code: Select all

#define CONFIG_FREERTOS_HZ	1000
#define configTICK_RATE_HZ	CONFIG_FREERTOS_HZ
#define portTICK_PERIOD_MS	( ( TickType_t ) 1000 / configTICK_RATE_HZ )

And we have your "0" case into account in here:

Code: Select all

    timeout_in_ticks = (timeout_us) / (portTICK_PERIOD_MS * 1000);
    if (((timeout_us) % (portTICK_PERIOD_MS * 1000)) != 0)
    {
        timeout_in_ticks += 1;
    }

Which is clearing working when seeing the console output:

(11:06:51.797) UART#1: 'timeout_us':334, 'timeout_in_ticks':1

Despite this, we don't reconfigure the UART, we just do it once at the beginning. If the "0" timeout was the problem, it would be always failing.

Do you think there is any possibility of solving this? Don't you see it as a problem?

Thank you!

[beal_hms]

I think I found the issue, I'd say it's a tick boundary race condition due to timing granularity. I send 60 frames per second, so the probability of getting this issue over 1 minute is high, but this could happen to anyone when "ticks_to_wait == 1" in the uart_read_bytes function, like in our case. This "solves" the issue:

Code: Select all

	if (ticks_to_wait == 1)
	{
		ticks_to_wait = 2;		
	}

I guess that with this fix, now the function will eventually return after 1 tick instead of 2 ticks. The difference is that before it eventually returned instantly (0 tick) instead of 1 tick. Do you agree?

Thanks!

[MicroController]

Do you agree?

No. Haven't seen any code, or your UART interrupt config, so the actual problem could be anywhere and still exist.

[beal_hms]

Ok, what exactly do you need to agree with me? What it's clear is that, sending about 60 frames per second of 8-byte each, this fails once before one minute:

Code: Select all

    timeout_ticks = 1;
    int32_t rx_cnt = uart_read_bytes(m_uart_device.uartInstance, m_rx_buff, 256, timeout_ticks);

And without ANY other change in the code, this doesn't fail anymore:

Code: Select all

    timeout_ticks = 2;
    int32_t rx_cnt = uart_read_bytes(m_uart_device.uartInstance, m_rx_buff, 256, timeout_ticks);

It seems clear to me it's an ESP-IDF issue. Which wrong config could trigger this behaviour according to you?

Thanks!

[beal_hms]

Hi,

Some news on this bug?

Thanks!