uart: how to flush input buffer #765

manio · 2023-08-30T04:31:41Z

manio
Aug 30, 2023

Hi!
I am struggling with reading from serial, especially a stability (sync errors).
Platform: ESP32

I am using slightly modified example of embassy_serial.rs

I have a device which is sending me exact 4-bytes frames with a constant startup byte (0xff).
I know it is a good example for using uart0.set_at_cmd but for some reason it was not working for me so I am just using set_rx_fifo_full_threshold set to 4 bytes.

Generaly it is working really well. I am sending a 0x01, the device respond with the response frame.
The problem starts after some longer working - eg after some hours (or even days!) of working.

It starts with the read call giving me Ok(3): 3 bytes instead of 4. I mean this:

writing 0x01...
read call: len=4, buf=[FF, 01, DE, DE, 00, 00, 00, 00, 00, 00, 00, 00]
len == 0 (EOF)
^^^^this is perfectly OK

writing 0x01...
read call: len = 3 buf=[FF, 01, DE, 00, 00, 00, 00, 00, 00, 00, 00, 00]
READ 3 instead of 4 bytes, the last CRC byte was not received
sync problem - repairing after 5 secs delay, increasing read timeout to 10sec
^^^here I am trying to recover calling:
uart.set_rx_fifo_full_threshold(1 as u16);
to read a single missing byte only

but another read calls gives only:
read call: len = 0
read call: timeout
read call: timeout

And after this some magic is happening because when I request for another sample data from the device then whatever I will try to read I always got (one byte off in the buffer), I mean this readings:

write 0x01
read len=4 buf=[DE, FF, 01, DE, 00, 00, 00, 00, 00, 00, 00, 00]
write 0x01
read len=4 buf=[DE, FF, 01, DE, 00, 00, 00, 00, 00, 00, 00, 00]
write 0x01
read len=4 buf=[DE, FF, 01, DE, 00, 00, 00, 00, 00, 00, 00, 00]
... and so on

Calling uart.set_rx_fifo_full_threshold(1 as u16); and trying to read all data even byte-by-byte doesn't work.
Only chip reset helps.

I was trying hard to somehow solve this - even trying to call read multiple times before requesting for new data (to empty the uart input buffer) but the next read still gives me the missing "off-byte" from the previous frame.

The flushing function works only for output buffer, moreover looking at the code it looks that is not flushing anything, but only checking is_tx_idle() and returning depending on this:

esp-hal/esp-hal-common/src/uart.rs

Line 576 in 92a2cc7

fn flush_tx(&self) -> nb::Result<(), Error> {

I can see that in IDF there is: uart_flush/uart_flush_input
And in fact this is exactly what I want to do:
UART ring buffer flush. This will discard all data in the UART RX buffer.

Please help - I am out of ideas. I don't want to reset the chip in such cases, but I am trying to find some reliable "recovery" method.

Answered by bjoernQ

Sep 4, 2023

Thanks! Most probably the errata applies here. I guess an inconsistent fifo_cnt would explain the observed behavior.

View full answer

bjoernQ · 2023-08-30T06:30:55Z

bjoernQ
Aug 30, 2023
Maintainer

Hello! There is another user also having problems with UART ( esp-rs/esp-wifi-sys#214 ) ... But I think you already discovered that

The other side of the communication is a PC or another embedded device? Is there a chance to hook-up a logic analyzer to see what is happening on the wire (e.g. if the other side might just happen to send three bytes and later the next byte)

Does the behavior change by changing the baud rate?

Would it be possible to test this with non-async code?

Regarding the ESP-IDF function uart_flush_input. From what I see it mainly empties the internal buffer. What it does then is

uart_hal_rxfifo_rst - this in turn calls uart_ll_rxfifo_rst. That function will actually perform a rxfifo_rst on some targets but not ESP32: https://github.com/espressif/esp-idf/blob/82cceabc6e6a0a2d8c40e2249bc59917cc5e577a/components/hal/esp32/include/hal/uart_ll.h#L252-L275 ... it just reads from the FIFO until the fifo-count is 0 ... basically what happens in our read function
maybe re-enable interrupts

There is also https://www.espressif.com/sites/default/files/documentation/esp32_errata_en.pdf - 3.17. UART fifo_cnt is inconsistent with FIFO pointer. - maybe related to our problem

0 replies

manio · 2023-08-30T07:24:02Z

manio
Aug 30, 2023
Author

Yes, I am following the esp-rs/esp-wifi-sys#214

The device is the ultrasonic sensor which is providing the UART communication mode. I am not able to lower the baud rate as it is hardcoded in the device.

Testing in non-async code would be hard as even now I sometimes need to wait days to have this occur.

Thank you for valuable tips - I think I'll start with hooking the scope but I need to consider proper triggering and stop the execution in proper place.

0 replies

manio · 2023-09-04T04:49:50Z

manio
Sep 4, 2023
Author

Hi,
I took several days to catch this on the scope but finally I've got it:

In the same time on the ESP32:

read len = 3 buf=[FF, 01, DE, 00, 00, 00, 00, 00, 00, 00, 00, 00]
READ 3 instead of 4

So at least one thing (the device) is eliminated.

0 replies

manio · 2023-09-04T17:08:04Z

manio
Sep 4, 2023
Author

I was testing re-enabling interrupts. It also doesn't help :(
I did it like this:

hal::interrupt::disable(hal::Cpu::ProCpu, hal::peripherals::Interrupt::UART1);
hal::interrupt::enable(hal::peripherals::Interrupt::UART1, hal::interrupt::Priority::Priority1).unwrap();

@bjoernQ I hope this is what you meant?

0 replies

bjoernQ · 2023-09-04T18:05:21Z

bjoernQ
Sep 4, 2023
Maintainer

Thanks! Most probably the errata applies here. I guess an inconsistent fifo_cnt would explain the observed behavior.

0 replies

manio · 2023-09-05T07:36:04Z

manio
Sep 5, 2023
Author

OK, so according to this errata the problem is this line, right?

esp-hal/esp-hal-common/src/uart.rs

Line 592 in 7866896

if self.uart.get_rx_fifo_count() > 0 {

because it is basing on the fifo_cnt, not a FIFO pointer.

I created a simple function which is returning me this value and I am trying to confirm the problem...

pub fn get_fifo_counter(&mut self) -> u16 {
    self.uart.get_rx_fifo_count() 
}

0 replies

bjoernQ · 2023-09-05T08:01:12Z

bjoernQ
Sep 5, 2023
Maintainer

Really curious about the outcome. If we can track it down to fifo-count being incorrect we hopefully can apply a workaround for ESP32

0 replies

manio · 2023-09-07T18:06:59Z

manio
Sep 7, 2023
Author

Ok, just catch it again with my debug enabled.

Lastly I enhanced my debug function to return tuple: not only fifo_count but also a fifo.as_ptr()

    pub fn get_fifo_counter(&mut self) -> (u8,u16) {
        (self.uart.register_block().fifo.as_ptr() as u8,
        self.uart.get_rx_fifo_count())
    }

During normal run I've got:

write 0x01..., fifo_cnt=(0, 0)
read len=4, buf=[FF, 01, DE, DE, 00, 00, 00, 00, 00, 00, 00, 00], fifo_cnt=(0, 0)

but when the problem starts (I've got 3 bytes), then my debug function still returning this (0,0):

write 0x01..., fifo_cnt=(0, 0)
> buf=[FF, 01, DE, 00, 00, 00, 00, 00, 00, 00, 00, 00]
READ 3 instead of 4, fifo_cnt=(0, 0)

sync problem - repairing after 5 secs, read timeout=10
> buf=[FF, 01, DE, 00, 00, 00, 00, 00, 00, 00, 00, 00]
len == 0, continue
read timeout, fifo_cnt=(0, 0)

write 0x01..., fifo_cnt=(0, 0)
read len=4, buf=[DE, FF, 01, DE, 00, 00, 00, 00, 00, 00, 00, 00], fifo_cnt=(0, 0)
                 ^^ this byte is from previous command
                     |
                     ^^ here starts the new reply which is not complete again

The PDF is saying:
When using DPORT to read FIFO, please calculate the number of bytes according to the value of FIFO pointer.

Is the FIFO pointer the following?
(self.uart.register_block().fifo.as_ptr() as u8

0 replies

bjoernQ · 2023-09-12T07:06:15Z

bjoernQ
Sep 12, 2023
Maintainer

I think the RX FIFO pointer is this: https://github.com/espressif/esp-idf/blob/3640dc86bb4b007da0c53500d90e318f0b7543ef/components/soc/esp32/include/soc/uart_reg.h#L1116

Unfortunately it's not mentioned in the TRM at all

0 replies

manio · 2023-09-14T14:26:49Z

manio
Sep 14, 2023
Author

@bjoernQ
Thanks for your info - I was testing something different recently.

Today I created the following function:

fn get_rx_fifo_ptr(&mut self) -> u16 {
    self.register_block()
        .mem_rx_status
        .read()
        .mem_rx_rd_addr()
        .bits()
        .into()
}

And this gives me in each read() iteration from the program start:
516, 520, 524, 528, etc...
I'll leave it like this and see what happens when the problem occur.

Edit:
Those values are just wrapping: 512 + 128

0 replies

manio · 2023-09-15T13:34:12Z

manio
Sep 15, 2023
Author

@bjoernQ
Here is what I found out:
Using the above function I am debugging the mem_rx_rd_addr:

The last good call:

writing 0x01..., fifo_cnt=(0, 0, 592)
read len = 4, fifo_cnt=(0, 0, 596)
> buf=[FF, 01, DE, DE, 00, 00, 00, 00, 00, 00, 00, 00]
read len=4, buf=[FF, 01, DE, DE, 00, 00, 00, 00, 00, 00, 00, 00], fifo_cnt=(0, 0, 596)

Now I've got 3 bytes:

writing 0x01..., fifo_cnt=(0, 0, 596)
read len = 3, fifo_cnt=(0, 0, 599)
> buf=[FF, 01, DE, 00, 00, 00, 00, 00, 00, 00, 00, 00]
READ 3 instead of 4, fifo_cnt=(0, 0, 599)

The last value from fifo_cnt= is the mem_rx_rd_addr.
So it seems it just adjusted from 596 to 599 - so it is 3 bytes - correct.

But then it is something more interesting...
I've put a debug also to additionally obtain the mem_rx_wr_addr
And the results are:

writing 0x01..., fifo_cnt=(0, 0, (588, 588))
offset = 4, len = 4, fifo_cnt=(0, 0, (592, 592))
read len=4, buf=[FF, 01, DE, DE, 00, 00, 00, 00, 00, 00, 00, 00], fifo_cnt=(0, 0, (592, 592))

writing 0x01..., fifo_cnt=(0, 0, (592, 592))
read len = 3, fifo_cnt=(0, 0, (595, 596))
> buf=[FF, 01, DE, 00, 00, 00, 00, 00, 00, 00, 00, 00]
READ 3 instead of 4, fifo_cnt=(0, 0, (595, 596))

And here I can see that when everything is working ok (from the boot-up) these values are in pair.
But when the problem occur, then as you can see the mem_rx_rd_addr is one byte differ then mem_rx_wr_addr.

At the end I read additional single byte regardless of this:

esp-hal/esp-hal-common/src/uart.rs

Line 597 in 976549f

if self.uart.get_rx_fifo_count() > 0 {

I was just trying to read those missing byte anyway - no matter what the get_rx_fifo_count() was returning. Then I was trying to get back to normal reading but those "offset" problem is still there:

sync problem - repairing after 5 secs, read timeout=10
AFTER: buf=[FF, 01, DE, DE, 00, 00, 00, 00, 00, 00, 00, 00]
read() timeout

writing 0x01..., fifo_cnt=(0, 0, (597, 596))
                                  ^^^^ take a look at this - my additional read() adjusted the first value +2.
read len = 4, fifo_cnt=(0, 0, (601, 600))
read len=4, buf=[01, DE, DE, FF, 00, 00, 00, 00, 00, 00, 00, 00], fifo_cnt=(0, 0, (601, 600))
^^^ this should start from 0xff which is the startup seq

My assumption are:

The problem is detectable by comparing the mem_rx_rd_addr and mem_rx_wr_addr. If there are exact - it is probably all good, if not - there is the offset problem when reading UART fifo.
I can adjust the mem_rx_rd_addr by forcing read bytes from the UART.

Maybe I'll try to read 3 bytes instead of this one and will see ...

0 replies

manio · 2023-09-15T16:29:12Z

manio
Sep 15, 2023
Author

Ok ... I am doing some progress. I can now influence the mem_rx_rd_addr by calling the read_byte specified times.

For instance:

read len=4, buf=[FF, 01, E0, E0, 00, 00, 00, 00, 00, 00, 00, 00], fifo_cnt=(0, 0, (576, 576)) <-- this is OK
read len=3, buf=[FF, 01, E0, 00, 00, 00, 00, 00, 00, 00, 00, 00], fifo_cnt=(0, 0, (579, 580)) <-- here we have the missing byte (start of a problem)
read len=4, buf=[FF, 01, E0, E0, 00, 00, 00, 00, 00, 00, 00, 00], fifo_cnt=(0, 0, (588, 584)) <-- here I read 4 bytes ahead

I know that the buffer is now misaligned and I am probably reading the most latest data in this round buffer, but at least I can now force this somehow.
I will now try to read only one single missing byte (not two).

0 replies

manio · 2023-09-16T12:35:05Z

manio
Sep 16, 2023
Author

Ok... it seems that my approach did work :)
I was able to correct the FIFO read pointer!!!

read len=4, buf=[FF, 01, DE, DE, 00, 00, 00, 00, 00, 00, 00, 00], fifo_cnt=(0, 0, (540, 540))
read len=3, buf=[FF, 01, DE, 00, 00, 00, 00, 00, 00, 00, 00, 00], fifo_cnt=(0, 0, (543, 544))
>>> here I am making single read() call but ignoring get_rx_fifo_count()
after this i have: fifo_cnt=(0, 0, (544, 544)) which is perfectly fine
and next readings seems to be OK again and in sync... :)
read len=4, buf=[FF, 01, DE, DE, 00, 00, 00, 00, 00, 00, 00, 00], fifo_cnt=(0, 0, (548, 548))
etc...

Now I am debugging what is returning the get_rx_fifo_count() with every read() call.
When I was doing it before I always got zero because i was checking before or after read call.

Now I fixed this and I can see value of 4, which is what I expected to see...
I wonder how it will behave when the problem occur.
I also have a plan for fixing this :)
Stay tuned :)

0 replies

manio · 2023-09-20T20:16:42Z

manio
Sep 20, 2023
Author

Ok, I think it's working great, so I prepared a PR for this problem: #804
I've done the changes which I am testing for some days and today when I was re-checking the errata for preparing commit message, I can see a code example there in the errata!!!

I am pretty sure that it was not there, and in fact it wasn't:

Date	Version	Release notes
2023-09-19	v2.7	Updated Section 3.14 and 3.17 to provide more information Added Section 3.20 and 3.21

So it was added yesterday!
The funny thing is that the sample code was nearly the same as mine (including the variable names) but I had a bad handling for wr_addr == rd_addr case.
I reformatted the code to have it in pair with this example.

0 replies

manio · 2023-09-21T04:40:08Z

manio
Sep 21, 2023
Author

@bjoernQ We have it merged now, much thanks for your time on this!
It was really time-consuming debugging :)

btw: just curious: was this errata update initiated by you?
... and if we're at this:

there is a typo: fifi_cnt
and also in the code snippet (last block), the starting { char is 0xff5b instead of 0x7b ASCII (may be relevant only if someone wants to copy/paste this code)

0 replies

bjoernQ · 2023-09-21T06:24:30Z

bjoernQ
Sep 21, 2023
Maintainer

Thanks for the fix in esp-hal!

The update of the errata document was really just a coincidence - interesting timing.

Would you mind submitting your feedback to the document via the link at the bottom of each page in the pdf: Submit Documentation Feedback

Thanks again! Good job!

0 replies

manio · 2023-09-21T06:27:19Z

manio
Sep 21, 2023
Author

Sure I'll submit this, thanks!

0 replies

Provide feedback

Saved searches

Use saved searches to filter your results more quickly

uart: how to flush input buffer #765

{{title}}

Replies: 17 comments

{{title}}

{{editor}}'s edit

{{editor}}'s edit

{{title}}

{{title}}

{{title}}

{{title}}

{{title}}

{{title}}

{{title}}

{{title}}

{{title}}

{{editor}}'s edit

{{editor}}'s edit

{{title}}

{{title}}

{{title}}

{{title}}

{{title}}

{{title}}

{{title}}

Select a reply

uart: how to flush input buffer #765

manio Aug 30, 2023

Replies: 17 comments

bjoernQ Aug 30, 2023 Maintainer

manio Aug 30, 2023 Author

manio Sep 4, 2023 Author

manio Sep 4, 2023 Author

bjoernQ Sep 4, 2023 Maintainer

manio Sep 5, 2023 Author

bjoernQ Sep 5, 2023 Maintainer

manio Sep 7, 2023 Author

bjoernQ Sep 12, 2023 Maintainer

manio Sep 14, 2023 Author

manio Sep 15, 2023 Author

manio Sep 15, 2023 Author

manio Sep 16, 2023 Author

manio Sep 20, 2023 Author

manio Sep 21, 2023 Author

bjoernQ Sep 21, 2023 Maintainer

manio Sep 21, 2023 Author

manio
Aug 30, 2023

bjoernQ
Aug 30, 2023
Maintainer

manio
Aug 30, 2023
Author

manio
Sep 4, 2023
Author

manio
Sep 4, 2023
Author

bjoernQ
Sep 4, 2023
Maintainer

manio
Sep 5, 2023
Author

bjoernQ
Sep 5, 2023
Maintainer

manio
Sep 7, 2023
Author

bjoernQ
Sep 12, 2023
Maintainer

manio
Sep 14, 2023
Author

manio
Sep 15, 2023
Author

manio
Sep 15, 2023
Author

manio
Sep 16, 2023
Author

manio
Sep 20, 2023
Author

manio
Sep 21, 2023
Author

bjoernQ
Sep 21, 2023
Maintainer

manio
Sep 21, 2023
Author