ESP32: uart.write() doesn't send long chunk via CONSOLE_USB_SERIAL_JTAG

[serg3295]

trafficstars

Expected behavior

Currently, to send a data fragment larger than 256 bytes via CONSOLE_USB_SERIAL_JTAG, a forced insertion of \n between 256-byte fragments is required.

I would like the behavior to match the behavior when sending a long sequence via UART_DEFAULT. That is, data should be sent continuously without adding \n

In the nodemcu-tool and nodemcu-tools utilities, uniterrupted sending is used to download a file from the ESP32. Forcing \n to each piece will break the exchange protocol.

Moreover, the size of the response to a request from the utility can exceed 256 bytes. And in this case, I can't even add \n

Actual behavior

When sending a chunk longer than 256 bytes, only the first 256 bytes are sent. The remaining bytes will be sent only if you add \n at the end of the chunk.

Test code

This code works

s = string.rep('a', 256)
uart.write(0, s)
uart.write(0,'\n')
uart.write(0, s)
print'\n'

This code does not work

s = string.rep('a', 256)
uart.write(0, s)
uart.write(0, s)
print'\n'

NodeMCU startup banner

Startup banner

ESP-ROM:esp32c3-api1-20210207 Build:Feb 7 2021 rst:0x3 (RTC_SW_SYS_RST),boot:0xd (SPI_FAST_FLASH_BOOT) Saved PC:0x40048b82 SPIWP:0xee mode:DIO, clock div:1 load:0x3fcd5820,len:0x1704 load:0x403cc710,len:0x938 load:0x403ce710,len:0x2ee8 entry 0x403cc710 I (24) boot: ESP-IDF v5.1.3 2nd stage bootloader I (24) boot: compile time Jul 29 2024 20:30:34 I (24) boot: chip revision: v0.4 I (27) boot.esp32c3: SPI Speed : 80MHz I (32) boot.esp32c3: SPI Mode : DIO I (36) boot.esp32c3: SPI Flash Size : 4MB I (41) boot: Enabling RNG early entropy source... I (46) boot: Partition Table: I (50) boot: ## Label Usage Type ST Offset Length I (57) boot: 0 nvs WiFi data 01 02 00009000 00006000 I (65) boot: 1 phy_init RF data 01 01 0000f000 00001000 I (72) boot: 2 factory factory app 00 00 00010000 00180000 I (80) boot: 3 lfs unknown c2 01 00190000 00010000 I (87) boot: 4 storage Unknown data 01 82 001a0000 00070000 I (95) boot: End of partition table I (99) esp_image: segment 0: paddr=00010020 vaddr=3c0e0020 size=2d748h (186184) map I (137) esp_image: segment 1: paddr=0003d770 vaddr=3fc92400 size=028a8h ( 10408) load I (139) esp_image: segment 2: paddr=00040020 vaddr=42000020 size=d19b8h (858552) map I (279) esp_image: segment 3: paddr=001119e0 vaddr=3fc94ca8 size=001ach ( 428) load I (280) esp_image: segment 4: paddr=00111b94 vaddr=40380000 size=1237ch ( 74620) load I (299) esp_image: segment 5: paddr=00123f18 vaddr=50000000 size=00018h ( 24) load I (305) boot: Loaded app from partition at offset 0x10000 I (306) boot: Disabling RNG early entropy source... I (308) cpu_start: Unicore app I (312) cpu_start: Pro cpu up. I (327) cpu_start: Pro cpu start user code I (327) cpu_start: cpu freq: 160000000 Hz I (327) cpu_start: Application information: I (330) cpu_start: Project name: nodemcu I (335) cpu_start: App version: tmr-libmain-binpatch150-888-gca I (342) cpu_start: Compile time: Jul 29 2024 20:32:43 I (348) cpu_start: ELF file SHA256: b3501ddbd7970a59... I (354) cpu_start: ESP-IDF: v5.1.3 I (359) cpu_start: Min chip rev: v0.3 I (364) cpu_start: Max chip rev: v1.99 I (369) cpu_start: Chip rev: v0.4 I (373) heap_init: Initializing. RAM available for dynamic allocation: I (381) heap_init: At 3FC997B0 len 00026850 (154 KiB): DRAM I (387) heap_init: At 3FCC0000 len 0001C710 (113 KiB): DRAM/RETENTION I (394) heap_init: At 3FCDC710 len 00002950 (10 KiB): DRAM/RETENTION/STACK I (402) heap_init: At 50000018 len 00001FD0 (7 KiB): RTCRAM I (409) spi_flash: detected chip: generic I (412) spi_flash: flash io: dio W (417) rmt(legacy): legacy driver is deprecated, please migrate to driver/rmt_tx.h and/or driver/rmt_rx.h W (427) ADC: legacy driver is deprecated, please migrate to esp_adc/adc_oneshot.h I (436) sleep: Configure to isolate all GPIO pins in sleep state I (442) sleep: Enable automatic switching of GPIO sleep configuration I (449) app_start: Starting scheduler on CPU0 I (454) main_task: Started on CPU0 I (454) main_task: Calling app_main()

E (464) mmap: esp_mmu_paddr_to_vaddr(752): paddr isn't mapped LFS image loaded I (474) pp: pp rom version: 9387209 I (474) net80211: net80211 rom version: 9387209 I (484) wifi:wifi driver task: 3fca87a4, prio:23, stack:6656, core=0 I (484) wifi:wifi firmware version: 0016c4d I (484) wifi:wifi certification version: v7.0 I (484) wifi:config NVS flash: enabled I (484) wifi:config nano formating: disabled I (484) wifi:Init data frame dynamic rx buffer num: 32 I (484) wifi:Init static rx mgmt buffer num: 5 I (484) wifi:Init management short buffer num: 32 I (484) wifi:Init dynamic tx buffer num: 32 I (484) wifi:Init static tx FG buffer num: 2 I (484) wifi:Init static rx buffer size: 1600 I (484) wifi:Init static rx buffer num: 10 I (484) wifi:Init dynamic rx buffer num: 32 I (484) wifi_init: rx ba win: 6 I (494) wifi_init: tcpip mbox: 32 I (494) wifi_init: udp mbox: 6 I (494) wifi_init: tcp mbox: 6 I (494) wifi_init: tcp tx win: 5760 I (494) wifi_init: tcp rx win: 5760 I (494) wifi_init: tcp mss: 1440 I (494) wifi_init: WiFi IRAM OP enabled I (494) wifi_init: WiFi RX IRAM OP enabled

NodeMCU ESP32 build 2024-07-29 20:32 powered by Lua 5.3.5 [5.3-int32-singlefp] on IDF v5.1.3 cannot open init.lua: No such file or directory

Hardware

esp32c3 and esp32c6 via CONSOLE_USB_SERIAL_JTAG

[serg3295]

I found a workaround to the issue.

1. Upgrade to ifd v5.2.2. This is a mandatory step.
2. Change platform.c a little

void platform_uart_send_multi( unsigned id, const char *data, size_t len )
{
  size_t i;
  // if (id == CONFIG_ESP_CONSOLE_UART_NUM) {
      for( i = 0; i < len; i ++ ) {
        putchar (data[ i ]);
    }
  // } else {
    // uart_write_bytes(id, data, len);
  // }
}

void platform_uart_send( unsigned id, uint8_t data )
{
  // if (id == CONFIG_ESP_CONSOLE_UART_NUM)
    putchar (data);
  // else
    // uart_write_bytes(id, (const char *)&data, 1);
}

void platform_uart_flush( unsigned id )
{
  // if (id == CONFIG_ESP_CONSOLE_UART_NUM)
    fflush (stdout);
  // else
    // uart_tx_flush(id);
}

I don't know why it works, but it does.

[jmattsson]

The underlying issue here is that the USB-SERIAL-JTAG isn't an actual UART in the first place. In the name of backwards compatibility I've tried to hide that fact with increasing amounts of special casing in the platform code. As the IDF evolves further towards POSIXness, and the introduction of CDC-ACM consoles as well, this approach has, frankly, gotten rotten. Not only has it produced inconsistent behaviour, odd edge cases (like this), but also clearly a bunch of confusion :(

To resolve all these issues I think we have to bite the bullet and get around to moving the console device access into its own module. We've avoided it because it's a backwards compatibility breaking change, but it really looks to be the lesser evil by now. Let me see if I can cook up a PR for evaluation today.

[serg3295]

I have already rewritten the code of both utilities so that they work with the esp jtag console (on idf5.3.1) without using uart.on, uart.start, uart.stop. :-)

However, I was unable to implement sending binary data from esp to the host, in particular file dowload. uart.write is the only thing that is now necessary for the utilities to work correctly with the firmware.

[jmattsson]

I've almost finished the necessary refactoring, but I'm out of time for today. I'll try to have something tomorrow.

[jmattsson]

I've only just started the testing, but if you want to have a play early the branch is here.

Effectively, the console interaction is now via the console module, and you have console.on("data", ...) available similar to what's on the uart module. There's also console.mode(mode) to control whether console data goes to the LVM automatically or not. Hopefully the docs are good enough to describe it.

[serg3295]

Thanks, I'll test that.

[serg3295]

I tested the new firmware on esp32. I use uart.on("data", bufSize, function(d) <d is binary data to be written to a file> end, 0) for uploading file to esp.

Using new function console.mode(0) to disable passing data to Lua VM, I cannot get back to Interactive console. Is there any way to get binary data in the console.on and then return to interactive mode?

[jmattsson]

I've added an example on how to cleanly transfer potentially binary data using the console module, via a classic STX/ETX/DLE framing scheme.

[jmattsson]

In regard to the original issue, I've also tested writing a 300 byte long string using console.write() and received that fine on a USB-Serial-JTAG console.

[serg3295]

Thank you for such a detailed example! Now I figured it out.

Minor fixes in uart.md examples:

-- when 4 chars is received. uart.on("data", 4, ... end~~,0~~) -- when '\r' is received. uart.on("data", "\r", ... end~~, 0~~)

I have been testing the console module on esp32 -s3, -c3, -c6, (jtag) It works, but I notice errors in the utilities while downloading file. What is max buffer size for console.write(<buf_size_long_string?>)?

-s2 (cdc) EDIT: -s3 (cdc)

The issue is common for both idf5.3.1 and dev-console branches. Very strange behavior. If the connection is made with esp reboot (make monitor or a terminal program HTerm 0.8.5), then REPL works. When the connection is made without esp reboot (npx @serialport/terminal -b115200 -p /dev/ttyACM0 or my host utilities), there is no response to print'a'. Only node.restart() is accepted. I will investigate this in more detail.

[jmattsson]

Ah, thank for, I'll tidy up those uart examples!

There is no inherent limit to the string passed to console.write(), and I thought I did implement proper retry logic on the writes. While much of the time I can write a 4097 byte string, sometimes it's silently cut off after 257 bytes here too. I'm looking into it now.

Edit: The IDF/C library claims to have written everything, even when it's truncated. It looks like the loss is within the IDF somewhere. I'll see if I can find a workaround...

[jmattsson]

Okay, I have a workaround that seems to do the trick reliably here on my c3. See if it works for your setup too @serg3295 ?

[serg3295]

I am observing long chunks of ~4097 bytes from the ESP. Moreover, the UART console transmits data losslessly, and the JTAG console loses data randomly starting with the second long data packet. Perhaps, the IDF5.3.1 have UART errors been fixed?

[jmattsson]

@serg3295 You're still seeing losses even after my most recent workaround?! It seems reliable now across UART, USB-Serial-JTAG and CDC-ACM here for me.

[serg3295]

I apologize, I didn't pull the last changes. :-(

I have tested downloading large files from esp-s3. It's working now! I will test it more thoroughly on other chips.

[jmattsson]

I've just pushed scripts/upload-file.py to that branch, as a small utility both for direct use but also as a guide for how IDEs might want to use the new console module.

Plus I updated both the uart and console docs to make mention of it.

I think this is ready for a PR? The one other thing that would be lovely is if we could add something to our lua_compat that somehow wrangles legacy uart.on() (and whatever else IDEs have been sending) into something suitable for the console module, so that older IDEs can be used if you load said lua file.

[serg3295]

I tested uploading and downloading files using console.on, console.mode and console.write and found no errors.

Also I reworked nodemcu-tools VSCode extension and NodeMCU-Tool CLI utility to support the new firmware. They now support all firmware versions, including the legacy idf3 branch (with file module), the version that uses uart.start/stop and the latest console version.

[jmattsson]

@serg3295 fabulous! I've raised the PR, let's see what the verdict is.

[serg3295]

I have one more question. ESP32-C3, jtag-console, uart module is included into firmware. I tried calling uart.setup from make monitor and got this response

NodeMCU ESP32 build 2024-10-25 08:40 powered by Lua 5.3.5 [5.3-int32-singlefp] on IDF v5.1.3
cannot open init.lua: No such file or directory
> uart.setup()
Lua error:      stdin:1: attempt to index a nil value (field 'uart')
stack traceback:
        stdin:1: in main chunk
        [C]: in ?
        [C]: in ?
> 

[jmattsson]

It looks like the uart module isn't enabled/compiled in. Check your menuconfig under Component config -> NodeMCU modules

[serg3295]

// sdkconfig

# CONFIG_NODEMCU_CMODULE_TIME is not set
CONFIG_NODEMCU_CMODULE_UART=y
# end of NodeMCU modules

[serg3295]

However, no uart module in firmware

>   for k,v in pairs(getmetatable(_G).__index) do print(k.." : "..tostring(v)) end 
console : table: 0x3c0d6130
encoder : table: 0x3c0d621c
file : table: 0x3c0d646c
gpio : table: 0x3c0d6730
http : table: 0x3c0d6d10
i2c : table: 0x3c0d7060
net : table: 0x3c0d77f0
node : table: 0x3c0d81e0
ow : table: 0x3c0d84b8
pipe : table: 0x3c0d8584
tmr : table: 0x3c0d87cc
wifi : table: 0x3c0d8c60
string : table: 0x3c0dbbb8
table : table: 0x3c0dbd3c
coroutine : table: 0x3c0da930
debug : table: 0x3c0dacc8
math : table: 0x3c0db408
utf8 : table: 0x3c0dbe54
ROM : table: 0x3fc95a6c
assert : function: 0x4201e6ba

[jmattsson]

What the... 🤯 Let me check here...

[jmattsson]

Ugh, my bad 🤦‍♀️. Fixed now. (I based the console module off the uart module, but then failed to fully update the module registration macro, leading the console module to claim to be the uart module. Remarkably silly mistake to make.)

[serg3295]

Hooray, it worked!

[serg3295]

I tested simultaneous connection via usb-jtag-console interface and via UART0 connected to FTDI adapter.

flowchart LR
host[["make monitor"]]
esp["ESP32-C3"]
ftdi[FTDI adapter]
terminal[[HTerm 0.8.5]]
host-- usb-jtag-console <-->esp<-- UART0 -->ftdi<-->terminal

Data is transferred in both directions from console to UART and vice versa.

uart.setup(0, 115200, 8, uart.PARITY_NONE, uart.STOPBITS_1, {tx=21,rx=20})
uart.start(0)
uart.on(0,"data", "\n", function(data) print(data)end)
uart.write(0, "test string\n")

[serg3295]

I'm trying to figure out the CDC console. I am unable to send a string larger than 89 bytes from the CLI utility. If the string is exceeded 89 bytes, then I get only 89 bytes in the response and the exchange with esp freezes.

When sending a command from the utility's CLI, short commands are executed correctly, a command exceeding 89 bytes suspends the exchange.

>
[NodeMCU-Tool]~ Connected 
[device]      ~ Model: esp32s2 | Version: 0.0.undefined | ChipID: 0x_unknown | FlashID: 0x204016 
[serialport]  ~ TX: print(file.fsinfo())
[serialport]  ~ RX: pri
[serialport]  ~ RX: nt(fil
[serialport]  ~ RX: e.fsinfo())
[serialport]  ~ RX: 413899      502     414401
[serialport]  ~ RX: >
[serialport]  ~ TX: local l={}for k,v in pairs(file.list())do l[#l+1]=("%s:%d"):format(k,v)end;print(table.concat(l,";"))
[serialport]  ~ RX: lo
[serialport]  ~ RX: cal l=
[serialport]  ~ RX: {}for k,v in p
[serialport]  ~ RX: airs(file.list
[serialport]  ~ RX: ())do l
[serialport]  ~ RX: [#l+1]
[serialport]  ~ RX: =("%s:
[serialport]  ~ RX: %d"):
[serialport]  ~ RX: format
[serialport]  ~ RX: (k,v)
[serialport]  ~ RX: end;print(table
[serialport]  ~ RX: .conca

We're stuck here

Having tested the example upload-file.py I found that the maximum size of the uploaded file also cannot exceed 89 bytes. If the file size is exceeded 89 bytes, a zero size file is written to disk. I haven't looked at the receiver function code yet, but I guess the reason is not in the code upload-file.py

file: a.txt ; length=89 byte

12345678901234567890123456789012345678901234567890123456789012345678901234567890123456789

the file was successfully written

I (344) wifi_init: WiFi RX IRAM OP enabled
> local l={}for k,v in pairs(file.list())do l[#l+1]=("%s:%d"):format(k,v)end;print(table.concat(l,";"))
a.txt:89
> 

file: a.txt ; length=90 bytes a.txt:0

[serg3295]

I increased size of USB CDC RX buffer to 512 bytes and both the utilities and upload-file.py worked.

CONFIG_ESP_CONSOLE_USB_CDC_RX_BUF_SIZE=512

But I'm not sure that this solution was right. Maybe I broke something 😐

[serg3295]

esp32s2, CDC console.

A console utility (both nodemcu-tool and upload-file.py ) can only be performed once. When trying to execute the utility a second time, there is no response from the esp. An esp reboot is required. :cry:

Steps to reproduce:

file a.txt

1
1234567890
12345678901234567890
123456789012345678901234567890
12345678901234567890123456789012345678901234567890
123456789012345678901234567890123456789012345678901234567890
1234567890123456789012345678901234567890123456789012345678901234567890
12345678901234567890123456789012345678901234567890123456789012345678901234567890
123456789012345678901234567890123456789012345678901234567890123456789012345678901234567890
1234567890123456789012345678901234567890123456789012345678901234567890123456789012345678901234567890

upload-file.py

We are trying to upload a file using upload-file.py

❯ python ./upload-file.py -p /dev/ttyACM0 a.txt
Synchronising serial...
Uploading "a.txt" as "a.txt"
Sending loader...
Sending file contents...
Done.
❯ python ./upload-file.py -p /dev/ttyACM0 a.txt
Synchronising serial...
...
We're stuck here. CTRL+C
...
^CTraceback (most recent call last):
File "/home/serg/Projects/python/nodemcu/./upload-file.py", line 170, in <module>
  if not sync(ser):
         ^^^^^^^^^
File "/home/serg/Projects/python/nodemcu/./upload-file.py", line 124, in sync
  line = ser.readline()
         ^^^^^^^^^^^^^^
File "/usr/lib/python3/dist-packages/serial/serialposix.py", line 565, in read
  ready, _, _ = select.select([self.fd, self.pipe_abort_read_r], [], [], timeout.time_left())
                ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
KeyboardInterrupt

Perform hardware reset GOTO begin

[jmattsson]

Can confirm weirdness on my S2 CDC-ACM. I have started looking into it, and I keep finding more weirdness 😩