uart: uart_get_buffered_data_len() very rarely fails (IDFGH-4580)

[pillo79]

Environment

• Module or chip used: [ESP32-WROOM-32]
• IDF version: found in v4.0.1, also present in current "master" (v4.3-dev-2399-gf3adbbb8e as of 2021-01-13)

Problem Description

I am developing a project using the ESP32 port of MicroPython; the main task has to process chars from the serial port when they are available. MicroPython does not have non-blocking file I/O, but offers a select() operation that can be used to query if a stream is ready for reading; the assumption being that when so, at least a single byte can be read without blocking.

Very rarely, though, this select() was returning the UART stream as ready, even though a subsequent read operation had 0 bytes available. This caused the Python application to hang until data was actually sent to the serial port.

Tracing the issue in the Micropython and then ESP-IDF sources led to identification of an issue in the current implementation of the uart_get_buffered_data_len() API function.

Expected Behavior

• uart_get_buffered_data_len() should always fill its size parameter either with 0 or with the number of bytes available in the requested UART.

Actual Behavior

• uart_get_buffered_data_len() may return a garbage value in size if a different execution thread updates the internal state of the UART while this function is being run.

Steps / code to reproduce

I assume the following snippet for a given uart_num would eventually show the issue if left running long enough (no input is required):

    while (1) {
        size_t data_len;
        if (uart_get_buffered_data_len(uart_num, &data_len) == ESP_OK) {
            uint8_t buf;
            int ret = uart_read_bytes(uart_num, &buf, 1, 0);
            if (ret != 1) ESP32_LOGW("data_len %u but read_bytes %i?", data_len, ret);
        }
}

Proposed fix

I will shortly provide a pull request adding the missing critical section barriers; these are already present in all other functions accessing the UART state in uart.c.

[Alvin1Zhang]

Thanks for reporting.

[AxelLin]

Do you think here also needs critical section protection? (And remove ESP_LOGE or move it out of critical section)
https://github.com/espressif/esp-idf/blob/master/components/driver/uart.c#L1284-L1287

[pillo79]

Do you think here also needs critical section protection? (And remove ESP_LOGE or move it out of critical section)
https://github.com/espressif/esp-idf/blob/master/components/driver/uart.c#L1284-L1287

Right, did not check the whole file thoroughly. Definitely needed there as well, maybe the critical section below could be extended to include the sanity check you mentioned. Want me to update the merge request?

[AxelLin]

@pillo79
You probably need to tell people your PR change is based on which branch.
Your pull request is not against current master tree. (My understanding is the fix should go to master first).

[pillo79]

@AxelLin not sure I understand - the linked commit is on my repo's master branch which is exactly one commit ahead of espressif/esp-idf's master (2bfdd03 since 9 days).

[AxelLin]

@AxelLin not sure I understand - the linked commit is on my repo's master branch which is exactly one commit ahead of espressif/esp-idf's master (2bfdd03 since 9 days).

I mis-read your change (so I thought it's for different branch)
You need
UART_ENTER_CRITICAL(&(uart_context[uart_num].spinlock));
UART_EXIT_CRITICAL(&(uart_context[uart_num].spinlock));

rather than
UART_ENTER_CRITICAL(&uart_spinlock[uart_num]);
UART_EXIT_CRITICAL(&uart_spinlock[uart_num]);

Otherwise, it won't pass compilation at all.

[pillo79]

Oh right, sorry! Indeed, the patch was prepared and tested on 4.0.1, I saw it was missing on master but did not try compiling there. Will update ASAP!

EDIT: PR updated with master code; also wrapped the other access you spotted. Thanks a lot @AxelLin for your review and tips!

[AxelLin]

@Alvin1Zhang
This bug still needs fix, see #6396

[AxelLin]

@Alvin1Zhang

This issue was reported against v4.0.1 & v4.3.
It's not clear to me if your policy is to close issue once it's fixed in master
or close issue after it's closed by the impacted branches.
I observed different behaviors on different issues..
(I ask this because it's not easy to trace status with impacted branches once it's closed)

[igrr]

Thanks for raising this topic @AxelLin! Currently the process is to add "Closes #issue number" in the commit on master and all the backports. This means that the Github issue is closed when the commit to master has been merged.

However the problem is that once the issue has been closed, Github doesn't add backlinks to commits on other branches. I think it used to work in the past (when we have started using this process), although I wasn't able to find any mention of this behavior change in Github docs.

I agree in the current situation it is hard for someone outside Espressif to figure out what is the status of backports. We are considering a few options to address this:

1. Use some automation to add labels to Github issues when the fixes are merged into release branches (such as "fixed in release/v4.3", "fixed in release/v4.2")
2. Similar to the above, but let @espressif-bot leave comments on issues, pointing to the backport commits.
3. Modify the "Closes #issue number" line of the commit message to "Backport for #issue number" when creating backports. This way Github will show backlinks to these commits in the issue UI.

As a user, I would prefer option 2, since I would get notifications when fixes are merged to release branches this way. But it's also the option that is more difficult to implement, as there is usually a delay between merging the fix and deploying it to Github, and ideally the notifications shouldn't get triggered until the commit is actually available on Github.
Option 3, on the other hand, is easier to implement, but might be a bit error-prone. If the original commit didn't include the issue link for any reason, the backport commit will also not include the issue link.
We'll try to find an option (not limited to the ones I listed) that can be made to work reliably and will fit into our development workflow, while having reasonable implementation/maintenance cost.