[HWCDC] Missing data via USB Serial on C3/C6/S3 #9378
Comments
P-R-O-C-H-Y
added
Area: Peripherals API
|
@SuGlider Can you please take a look? |
|
I disabled this line and I don't see any bytes missing anymore: arduino-esp32/cores/esp32/HWCDC.cpp Line 384 in 0a26a8c N.B. this was with testing writing 1 byte at a time. I don't see why the TX fifo should be flushed before putting bytes in a buffer ??? Edit: Consider this code where the first attempt to write data to the buffer was successful and you end up in the else... (line 380) Also arduino-esp32/cores/esp32/HWCDC.cpp Lines 372 to 402 in 0a26a8c Then you will never end up in the while loop and thus This is probably what I'm seeing when sending in chunks of >1 bytes. (tested with chunks of upto 16 bytes now) |
|
@TD-er - Thanks for the report! |
|
@Jason2866 made a build for me to use with PlatformIO. This is the latest commit he included for that build. It is "build 2189" taken from here I do think it boils down to the |
|
I need to be able to reproduce the issue. I'll try to create something based on your report. |
|
To summarize:
|
|
Just to have some code to print in chunks: size_t SerialWriteBuffer_t::write(Stream& stream, size_t nrBytesToWrite)
{
size_t bytesWritten = 0;
const size_t bufferSize = _buffer.size();
if (bufferSize == 0) {
return bytesWritten;
}
if (nrBytesToWrite > 0) {
// FIXME TD-er: Work-around for bug in HWCDC when writing exactly the amount of free bytes in the buffer.
// --nrBytesToWrite;
if (nrBytesToWrite > bufferSize) {
nrBytesToWrite = bufferSize;
}
while (nrBytesToWrite > 0 && !_buffer.empty()) {
uint8_t tmpBuffer[1]{};
size_t tmpBufferUsed = 0;
auto it = _buffer.begin();
bool done = false;
for (; tmpBufferUsed < sizeof(tmpBuffer) &&
!done &&
it != _buffer.end(); ) {
tmpBuffer[tmpBufferUsed] = (uint8_t)(*it);
if (*it == '\n' ||
tmpBufferUsed >= nrBytesToWrite) {
done = true;
}
++tmpBufferUsed;
++it;
}
const size_t written = (tmpBufferUsed == 0) ? 0 : stream.write(tmpBuffer, tmpBufferUsed);
if (written < tmpBufferUsed) {
done = true;
}
for (size_t i = 0; i < written; ++i) {
_buffer.pop_front();
--nrBytesToWrite;
++bytesWritten;
}
if (done) {
return bytesWritten;
}
}
}
return bytesWritten;
}My buffer here is a The function is called with This way I simply could change the size of |
|
Is your project running within a multitasking environment that could preempt this function at any time and write something else while it is still sending previous chunks of bytes to the CDC? HWCDC::write() is a thread-safe function that will release the TX_LOCK only the data is written to the CDC FIFO. |
|
I wonder why you need the |
Not that I'm aware of, I call everything from the |
size_t HWCDC::write(const uint8_t *buffer, size_t size)
{
uint32_t tx_timeout_ms = 0;
if(buffer == NULL || size == 0 || tx_ring_buf == NULL || tx_lock == NULL){
return 0;
}
if(HWCDC::isCDC_Connected()) {
tx_timeout_ms = requested_tx_timeout_ms;
} else {
connected = false;
}
if(xSemaphoreTake(tx_lock, tx_timeout_ms / portTICK_PERIOD_MS) != pdPASS){
return 0;
}
size_t max_size = xRingbufferGetMaxItemSize(tx_ring_buf);
size_t space = xRingbufferGetCurFreeSize(tx_ring_buf);
size_t to_send = size, so_far = 0;
if(space > size){
space = size;
}
// Non-Blocking method, Sending data to ringbuffer, and handle the data in ISR.
if(xRingbufferSend(tx_ring_buf, (void*) (buffer), space, 0) != pdTRUE){
size = 0;
} else {
to_send -= space;
so_far += space;
// Now trigger the ISR to read data from the ring buffer.
// usb_serial_jtag_ll_txfifo_flush();
if(connected) usb_serial_jtag_ll_ena_intr_mask(USB_SERIAL_JTAG_INTR_SERIAL_IN_EMPTY);
while(to_send){
space = xRingbufferGetCurFreeSize(tx_ring_buf);
if(space > to_send){
space = to_send;
}
// Blocking method, Sending data to ringbuffer, and handle the data in ISR.
if(xRingbufferSend(tx_ring_buf, (void*) (buffer+so_far), space, tx_timeout_ms / portTICK_PERIOD_MS) != pdTRUE){
size = so_far;
break;
}
so_far += space;
to_send -= space;
// Now trigger the ISR to read data from the ring buffer.
// usb_serial_jtag_ll_txfifo_flush();
if(connected) usb_serial_jtag_ll_ena_intr_mask(USB_SERIAL_JTAG_INTR_SERIAL_IN_EMPTY);
}
}
// CDC is diconnected ==> flush all data from TX buffer
if(to_send && !usb_serial_jtag_ll_txfifo_writable()) {
connected = false;
flushTXBuffer();
}
xSemaphoreGive(tx_lock);
return size;
}This does seem to fix this issue when using larger chunks (tested with chunks of upto 16 bytes) |
|
Oh and I do use VS code 's monitor function. |
|
Even when writting byte by byte, it should work. Let me investigate it. |
|
Still why should you call |
As far as I know, it is because the CDC FIFO has 64 bytes. If it is not full, bytes are not immediately sent. |
|
Also found this discussion: And if you still are writing a larger sequence, then there is no need to send out multiple chunks right? And since it is split into chunks based on the available room (at least the first call), it doesn't make sense to immediately call to flush as you did try to fill up-to the available space and thus must have filled it to the max. |
|
An issue, with commenting out I need to test it and investigate it further... |
|
I think this is also an interesting comment to keep in mind: So you might want to stop at 63 bytes then? |
|
Not sure... I'll run some testing. |
|
@TD-er - I can't reproduce the issue using the master banch... This is the code I'm using to test it: Please let me know your thoughts about it. // ESP32-C3 using HW Serial CDC on Boot enabled
#define DATA_CHUNK_LEN 12
// 32 Bytes to send to UART0: 012345678901234567890123456789!#
String chunk32bytes = "012345678901234567890123456789!#";
String chunk64bytes = chunk32bytes + chunk32bytes;
String chunk128bytes = chunk64bytes + chunk64bytes;
String chunk256bytes = chunk128bytes + chunk128bytes;
void testCase1(String data) {
Serial0.println("TEST CASE1: sending byte by byte.");
size_t receivedLen = data.length();
size_t sendLen = 0;
while (sendLen < receivedLen) {
Serial.write(data[sendLen++]);
}
Serial.println("\r\n=============");
if (sendLen != receivedLen) Serial0.printf("\r\n ===> Error: didn't send all data [%d of %d]\r\n", sendLen, receivedLen);
else Serial0.println("Testing byte by byte OK.");
}
void testCase2(String data) {
Serial0.printf("TEST CASE2: sending chunk of %d bytes.\r\n", DATA_CHUNK_LEN);
size_t receivedLen = data.length();
size_t sentLen = 0;
while (sentLen < receivedLen) {
size_t toSend = receivedLen - sentLen;
toSend = toSend > DATA_CHUNK_LEN ? DATA_CHUNK_LEN : toSend;
size_t sent = Serial.write(data.c_str() + sentLen, toSend);
Serial0.printf("-->Sent chunk with %d bytes.\r\n", sent);
sentLen += sent;
}
Serial.println("\r\n=============");
if (sentLen != receivedLen) Serial0.printf("\r\n ===> Error: didn't send all data [%d of %d]\r\n\r\n", sentLen, receivedLen);
else Serial0.println("Testing chunk sent OK.");
}
void testCase3(String data) {
size_t receivedLen = data.length();
Serial0.printf("TEST CASE3: sending all at once : %d bytes.\r\n", receivedLen);
size_t sent = Serial.write(data.c_str(), receivedLen);
Serial0.printf("-->Sent all at once with %d bytes.\r\n", sent);
Serial.println("\r\n=============");
if (sent != receivedLen) Serial0.printf("\r\n ===> Error: didn't send all data [%d of %d]\r\n\r\n", sent, receivedLen);
else Serial0.println("Testing all at once CDC writing OK.");
}
void UART0_OnReceive() {
String data = "";
while (Serial0.available()) {
data += (char)Serial0.read();
delay(1); // gives UART0 IDF driver the chance to move FIFO to RX Buffer still while in this loop...
}
Serial0.printf("UART0 received %d bytes that will be sent to CDC.\r\n", data.length());
Serial0.printf("TEST1 ==> Byte by Byte : Len = %d\r\n", data.length());
testCase1(data);
Serial0.printf("TEST2 ==> Sending Chunks of %d bytes : Len = %d\r\n", DATA_CHUNK_LEN, data.length());
testCase2(data);
Serial0.printf("TEST3 ==> Sending all in a single write(%d bytes) : Len = %d\r\n", DATA_CHUNK_LEN, data.length());
testCase3(data);
Serial0.printf("END of TESTING.\r\n\r\n");
}
void setup() {
Serial0.setRxBufferSize(1024);
Serial0.begin(115200);
Serial.begin();
Serial0.println("\r\nStarting... open Serial Monitor with CDC port.");
while (!Serial) delay(100);
Serial.println("\r\nCDC Started.");
testCase1("0123456789");
testCase2("0123456789");
testCase3("0123456789");
testCase1(chunk32bytes);
testCase1(chunk64bytes);
testCase1(chunk128bytes);
testCase1(chunk256bytes);
testCase2(chunk32bytes);
testCase2(chunk64bytes);
testCase2(chunk128bytes);
testCase2(chunk256bytes);
testCase3(chunk32bytes);
testCase3(chunk64bytes);
testCase3(chunk128bytes);
testCase3(chunk256bytes);
Serial0.println("\r\nNow use the Serial Monitor to send data to the UART0, then it will be sent to the CDC.");
Serial0.onReceive(UART0_OnReceive);
Serial.println("\r\nSetup is done\r\n");
}
void loop() {}
|
|
This is the UART0 (reporting) output: This the respective CDC output: |
|
@TD-er - Note: I have edited the 2 messages above. I added a 3rd test case (writing all data in a single Everything seems to work fine. |
SuGlider
added
Resolution: Unable to reproduce
|
@TD-er - Just to check the testing scripts, I confirm that using the proposed Sketch + Python, it always fails at some random time. |
|
Thanks, I will have a look at the proposed fix and will let you know asap. |
|
Nope, not working.... And when I comment out both lines with |
|
@TD-er @Jason2866 Keeping the Please test it with the Arduino IDE using the Core 3.0.0 and the modifications to Given that we get oposite results, I only can think that or the test case isn't good enough or we are running different frameworks. I need a test case to prove that removing I can't use ESPEasy to test it, because it is a full project and the failure may happen due to other reasons. |
|
The PR #9401 targets the master branch, Arduino Core 3.0.0 using IDF 5.1. |
|
@SuGlider The framework used for the test from @TD-er is based on latest IDF 5.1 branch https://github.com/espressif/esp-idf/tree/release/v5.1 and Arduino latest branch master. |
|
In that case I ask you guys to bring a Test Case, based on a minimum Arduino Sketch, that can demonstrate/reproduce the issue and be used for testing. This is necessary for applying any patch. |
|
I am now running your test code with PlatformIO and the same libraries/platform builds etc. as I was using for ESPEasy. Also if I comment-out the So at least that sounds the same as you experienced. I will now try to reproduce the ESPEasy behavior in a simple test program. |
|
So far I have not yet been able to reproduce the odd behavior as seen in ESPEasy with a small sketch, but hopefully I can find some more time tomorrow to test. |
|
Thanks @TD-er. I hope you have success replicating the issue with a small sketch. |
VojtechBartoska
moved this from In Progress
to In Review
in Arduino ESP32 Core Project Roadmap
|
Well in the very few hours I had in the last few days to test, I was not (yet...) able to reproduce the same loss of data as seen with ESPEasy, in a simple program. Since it does fix the bug as shown in the test program presented by @SuGlider , I think his PR should be merged. |
|
Is it possible that ESPEasy has multiple tasks writing to the CDC? This may explain why removing CDC Flush helps. Flushing makes whatever is the CDC FIFO be sent to the host as soon as it asks for. It could "tear" the messages. Although the write() muted should prevent it... |
|
It is not called from multiple tasks, as they are all being called from the But that shouldn't make any difference, does it? I also have set larger TX/RX buffers. Maybe flushing of those extra buffers is done from a different task? |
|
Just FYI, I have been running into quite a lot of issues with ESPEasy clearly related to the HWCDC code (Maybe also USBCDC, which I only use on ESP32-S2) I have to look into this later, but right now it is hard to proceed with this now the networking code has been merged. Anyway, I am convinced this is something in ESPEasy itself until I can prove otherwise. I also tried again using your clean test program on the ESP32-C6 and that one is working just fine.... |
|
Ah I did make it loose bytes, but not sure how realistic this is... void setup() {
Serial0.begin(115200);
_hwcdc_serial->setTxTimeoutMs(0);
_hwcdc_serial->begin();It also stalls completely, which seems to be what I also see when connecting to WiFi... Edit: So maybe the issue here is that when Edit2: So maybe more like this to be sure ?? int HWCDC::availableForWrite(void)
{
uint32_t tx_timeout_ms = 0;
if(tx_ring_buf == NULL || tx_lock == NULL){
return 0;
}
if(HWCDC::isCDC_Connected()) {
tx_timeout_ms = requested_tx_timeout_ms;
}
size_t a = 0;
if(xSemaphoreTake(tx_lock, tx_timeout_ms / portTICK_PERIOD_MS) == pdPASS){
a = xRingbufferGetCurFreeSize(tx_ring_buf);
}
xSemaphoreGive(tx_lock);
return a;
} |
|
I just pushed the commit to my MCVE which makes the ESP32-C6 stall and mess up the output. if(xSemaphoreTake(tx_lock, tx_timeout_ms / portTICK_PERIOD_MS) != pdPASS){
xSemaphoreGive(tx_lock);
return 0;
}It still manages to mess up the output, but less often. Changing the TX buffer also changes behavior. _hwcdc_serial->setTxBufferSize(2560);This still outputs way too long lines every now and then but it doesn't seem to stall anymore. N.B. The ESP32-C3 and -S3 show similar behavior |
|
OK, sorry for all the confusion and it looks like I have wasted at least 3 mornings on this... Looks like I lost track of which platform build to use with your fix included while switching between working on ESPEasy and trying out the MCVE builds. Apparently I have been using the wrong code or even partial sets of code as PlatformIO is not always acting nicely when not performing a full clean between switching platform packages. Now at least the MCVE is no longer failing and I will try it with ESPEasy to see if that also fixes my crashes, hangs, etc. |
|
I've been working on a fix for the C6/H2 along this week. I'm working on a potential fix for it. I'll keep you posted. |
|
Can this also cause bootloops on the C6 when nothing is connected via HWCDC? |
I have not seen it... could you please post a simple sketch that causes the bootloops? |
|
Nope, not yet.... I really don't have a clue where it might crash as I don't really get proper output on the serial port. Only every now and then a very odd decoded stack which I don't really understand: |
|
Hmm seems like you can't change 'stuff' like setting buffer size after calling But we're out of the bootloop right now. |
|
OK, here's what's strange...
For each of these I have some port classes and in the constructor of the port class I was calling to set the RX/TX buffer size and call However I had a typo in my code and was calling to set the RX buffer size twice instead of RX/TX. So now I only call to set the RX/TX buffer size in the begin() function of this port class and then Now it is working again without stalls, no bootloops etc. N.B. this is with your pending PR to fix the lost data for HWCDC, so this can be merged if you like to. (tested on ESP32-C3/-C6/-S3) I do have the idea that the connected state of the HWCDC port may not always be correct as you already mentioned. |
github-project-automation
bot
moved this from In Review
to Done
in Arduino ESP32 Core Project Roadmap
Board
ESP32-C3 / ESP32-S3
Device Description
This also happens on ESP32-C3 but happens way more often on ESP32-S3
Hardware Configuration
ESP32-S3 with USB-HWCDC used as serial port.
Version
latest master (checkout manually)
IDE Name
PlatformIO
Operating System
Windows 11
Flash frequency
40MHz
PSRAM enabled
yes
Upload speed
115200
Description
I have a console running on HWCDC in my project (ESPEasy) and have seen with the latest Arduino commits that there is some data lost.
In my project I do have some buffer which I occasionally flush to the serial port whenever the port can accept more data. (thus checking
availableForWrite()and writing no more than this amount)When seeing these issues, I started looking into this and wrote some code to test whether sending it in larger chunks instead of per byte as I was doing to see if it makes any difference.
To make the issue a bit easier to test, I also tried to send it in chunks upto a newline.
To illustrate the issue:
This is when calling
writeon the serial port per byte.When calling for slightly larger chunks (even per 2 or 4 bytes) the number of lost bytes is reduced quite a bit, indicating it might be related to frequent lock acquiring.
Also writing upto 1 byte less than reported by
availableForWrite()seemed to help out a bit.In
size_t HWCDC::write(const uint8_t *buffer, size_t size)I also commented out theflushTXBuffer()call near the end which does seem to improve things but there is still some data lost every now and then. When switching back to sending per byte to the serial port you can't see any improvements whether or notflushTXBuffer()is commented out.N.B. I also included the latest HWCDC commits while testing.
Sketch
Debug Message
Other Steps to Reproduce
No response
I have checked existing issues, online documentation and the Troubleshooting Guide
The text was updated successfully, but these errors were encountered: