ESP32-C3 and ESP32-S2 do not flush serial (stdout), and there's no sys.stdout.flush() mechanism we can use

[gitcnd]

CircuitPython version

Adafruit CircuitPython 9.1.0-beta.3-48-g396aaef964-dirty on 2024-07-01; Adafruit QT Py ESP32C3 with ESP32-C3FN4

Adafruit CircuitPython 9.1.0-beta.3-49-gf77451071f on 2024-07-01; S2Mini with ESP32S2-S2FN4R2

Code/REPL

sys.stdout.flush()

Behavior

AttributeError: 'FileIO' object has no attribute 'flush'

Description

Both the serial (RS232) and the websocket are not properly responsive with delayed/buffered IO making it all but unusable.

Additional information

Fixing this might provide a workaround for this: #7716

[gitcnd]

From here:

https://docs.espressif.com/projects/esp-idf/en/stable/esp32s3/api-guides/usb-serial-jtag-console.html

Data Buffering

For data transmitted from ESP32-S3 to PC Terminal (e.g., stdout, logs), the ESP32-S3 first writes to a small internal buffer. After this buffer becomes full (for example, if no PC Terminal is connected), the ESP32-S3 does a one-time wait of 50 ms for the PC Terminal to request the data. This can appear as a very brief pause in your application.

For data transmitted from the PC Terminal to ESP32-S3 (e.g., console commands), many PC Terminals wait for the ESP32-S3 to ingest the bytes before allowing you to send more data. This is in contrast to using a USB-to-Serial (UART) bridge chip, which always ingests the bytes and sends them to a (possibly not listening) ESP32-S3.

Note

In rare cases it's possible that data sent from the ESP32-S3 to the host gets 'stuck' in host memory. Sending more data will get it 'unstuck', but if the application does not send more data, depending on the driver, this data needs to be flushed to the host manually. The non-blocking (default) driver and the VFS implementation will flush automatically after a newline. The blocking (interrupt-based) driver will automatically flush when its transmit buffer becomes empty.

This looks like the key issue: The non-blocking (default) driver and the VFS implementation will flush automatically after a newline. and suggest where we need to look to find the call we need to make to generate a hardware flush even when we're not sending a newline.

I assume hardware-flush is needed, because other ESP32 devices have no such issues, so circuitpython itself might not be to blame.

[tannewt]

We don't use the serial to jtag converter on the S2. Only on the C3.

When we do use the serial to jtag converter we do flush:

circuitpython/ports/espressif/supervisor/usb_serial_jtag.c

Line 127 in d723732

usb_serial_jtag_ll_txfifo_flush();

Please describe the error you are experiencing so that we have the context.

[gitcnd]

jtag and other hardware serial do not exhibit the problem. only boards with "emulated serial" like the C3 and S2 with the usbc connected to the mcu directly.

the issue is that python output (maybe also input? hard to tell) is buffered and delayed.

Some folks #7716 found a workaround for this by outputting copious extra ANSI junk which has the effect of "doing nothing" visibly (I've not tested this yet myself). That makes output 1600% slower of course, since every byte needs 16 extra ones to come out to be sure it gets flushed to the terminal.

[UnexpectedMaker]

jtag and other hardware serial do not exhibit the problem. only boards with "emulated serial" like the C3 and S2 with the usbc connected to the mcu directly.

the issue is that python output (maybe also input? hard to tell) is buffered and delayed.

Some folks #7716 found a workaround for this by outputting copious extra ANSI junk which has the effect of "doing nothing" visibly (I've not tested this yet myself). That makes output 1600% slower of course, since every byte needs 16 extra ones to come out to be sure it gets flushed to the terminal.

Not sure what you mean by "Emulated Serial" - It's not emulated in any way.

The C3 and C6 only have a Serial JTAG/UART peripheral. That is what is used to communicate with them when using the D+ and D- pins.

The S2 and S3 also have this Serial JTAG/UART peripheral, but also have an additional native USB peripheral that is what CP leverages to show a mass storage device.

Grouping the S2 and C3 together is incorrect here as by default, CP doesn't use the same peripheral on each of the boards unless an S2/S3 board definition is explicitly setup to not use the native USB peripheral and use the SerialJTAG/UART peripheral instead (which I can't understand why someone would do that) for CP.

[gitcnd]

Notwithstanding - my QtPy and s2 mini both exhibit the same issue.
They both have one USB-C socket only.
They both have one chip on them (no separate uart chip).

TTL serial does not come out of a USB socket, so the only way to get that into an esp32 chip without hardware uart in-between is "emulated serial" - right?

I don't know what you mean by "Serial JTAG/UART peripheral." - if you're talking about using a separate "usb on one side, TTL serial on the other" board (which is what the word "peripheral" means), then you're using a board which won't surface this bug.

[UnexpectedMaker]

No, not right... the external SerialUART chip that was on original ESP32? Like the CP2104? That is built into the C3/S2/S3/C6 as a HW peripheral.

It's like having an external serial UART chip in the same IC as the ESP32... it presents JUST like an external SerialUART chip would via USB connector.

The C3 ONLY has this peripheral. The S2 has that and native USB.

When you plug your S2 mini in, does it present a USB mass storage drive for you to work on?

If so, it's using a totally different peripheral (bit of HW inside the ESP32) than what the C3 is using, and therefor a completely different code path.

[gitcnd]

OK - I see the confusion - espressif switched from using the term "module" to "peripheral" in their documentation (to be fair - they're using both at once to mean the same thing, not a full switch) - I guess English is not the first language of many people building these things; pity they got that one so wrong eh? Peripheral literally means external. I'm a software engineer, so if it was my job to add OTG and Storage and UART to an MCU which already does wifi etc, to expose all that as a USB-connectable solution, I'd do it the same way the wifi was done - use MCU resources, i.e. to "bake in" the least amount (if even any!) any unnecessary extra hardware - so the concept of calling that a "peripheral" never even crossed my mind. There's a "bus" involved the manual mentions, so something extra does seem to have gone in somehow.

Anyhow, exactly how espressif exposed this seems irrelevant: circuitpython is still not flushing the (probably internal hardware 16byte fifo) buffer of it prior to any newline in there, which appears to be the cause of the problem.

When you plug your S2 mini in, does it present a USB mass storage drive for you to work on?
Yes, and also a serial port at the same time (USB\VID_303A&PID_80C3&MI_00\7&14281BFA&0&0000)

@bill88t has the same issues on their C3 as me, so it's probably the same buffer issue from the same (or very similar) on-chip component.

[dhalbert]

A "peripheral" in microcontroller parlance is a chunk of hardware that's part of the microcontroller chip that connects the CPU core to something in the outside world. So there are GPIO peripherals, PWM peripherals, I2S peripherals, USB peripherals, etc. Often, especially for USB and other more complicated peripherals, the microcontroller manufacturer will license a hardware design created by another company, and maybe pay to have it specialized slightly. The licensed design is often know as "IP", since it's licensed intellectual property. The TinyUSB library used in CircuitPython ('lib/tinyusb) has support for a number of chips, some which share the same or similar IP designs for USB peripherals.

The S2, S3, C3, and C6 have circuitry that is a self-contained USB-serial peripheral. That design may have been licensed from elsewhere. As mentioned, we don't normally use this peripheral in the S2 and S3 CircuitPython implementations, and it is not supported by TinyUSB.

The S2 and S3 also have a full USB peripheral, which I believe Espressif licensed from someone else.

Recent S2 and S3 development boards (DevKitC, etc.) have two USB connectors, exposing both peripherals. Most other boards, including ours, don't do this.

@tannewt has noted that we flush the USB-serial peripheral. Maybe something about that code is in error. But that's what we should concentrate on.

[dhalbert]

I would like to replicate this. Could you give a small specific example of the non-flushing behavior? Could be a small program or even in the REPL.

[gitcnd]

Python source is here: https://github.com/gitcnd/cpy_shell

The REPL does not seem to be affected.

Maybe related - I'm not sure - seems to be way worse after having uploaded a file using the drag-drop method (to the point of needing a hardware reset sometimes; not sure if this might be some other bug? maybe file-uploads while a python program is running cause problems?)

Video of the problem is here:
https://chrisdrake.com/vid_2024-07-04_01.32.34_45.mp4

Hard to convey intermittent when you can't see me typing, but, you can get the general idea by keeping in mind that I was not delaying when I typed, but it comes out all delayed and blocky.

Might possibly be an issue with my code - except for the fact that other people have the same problems? I've never noticed any problem on other non-S2 non-C3 ESP32s running identical code.

A basic test program in python would be to accept typing, and echo it back in real time. My sh.py does that, but with a lot of extra wrapping around things.

It might instead be an issue on the input side? maybe not noticing a character is available, when one is? I can't explain how sometimes it needs more than a few "enter" keys to get it to do what I just typed in.

[gitcnd]

Here's a minimal program exhibiting the issue:

#test S2/C3 serial buffering probmlems.

import supervisor

import sys


nbuf=''
while True:
    if supervisor.runtime.serial_bytes_available:
        nbuf += sys.stdin.read(supervisor.runtime.serial_bytes_available)
    if len(nbuf)>0:
        sys.stdout.write(nbuf)
        nbuf=""
        
# exec(open("kio.py").read())

[gitcnd]

Sorry I didn't post this before - I was planning to find and fix this myself and didn't realize others might want to help.
I did spend a few hours trying - wasn't able to work anything out.

[gitcnd]

I was testing now on my S2 (has problems). I just tried my C3 - it is working at this moment.

[jepler]

I've reproduced something similar to what you report. I modified the test program and it gives me more information.

Running on Adafruit CircuitPython 9.1.0-beta.3-48-g396aaef964 on 2024-06-26; Adafruit Metro ESP32S2 with ESP32S2

My program

# test S2/C3 serial buffering problems.

import sys

import supervisor

while True:
    n = supervisor.runtime.serial_bytes_available
    if n:
        print(n)
        print(repr(sys.stdin.read(1)))

On my system, the number of bytes reported available is usually 2, not 1:

Press any key to enter the REPL. Use CTRL-D to reload.
soft reboot

Auto-reload is on. Simply save files over USB to run them or enter REPL to disable.
code.py output:
2
'a'
1
's'
2
'd'
2
'f'

I don't know if the supervisor routine serial_bytes_available is somehow double-counting? Internally this value is treated more like a bool, with just 1 character being read at a time.

[jepler]

(I am typing just one character at a time, not 2)

[jepler]

also @gitcnd thank you for the very small reproducer script and instructions.

[gitcnd]

@jepler - brilliant idea to sleuth

Thinking about the odd behavior of that code, it matches up nicely with the idea of a boolean instead of an int coming back.
I wonder why it doesn't happen on other esp32s? weird.

https://docs.circuitpython.org/en/latest/shared-bindings/supervisor/index.html#supervisor.Runtime.serial_bytes_available

serial_bytes_available: int¶
Returns the number of bytes are available to read on the console serial input. Multiple console serial inputs may be in use at once, including USB, web workflow, BLE workflow, and/or UART.

The most striking thing I noticed, is that if I type "pwd" (which has me typing the "wd" part very fast, since the keys are beside each other and use 2 fingers) - the "d" is almost always missing.

[gitcnd]

In case this is useful to know - the following equivalent code on the same physical S2_MINI in micropython runs fine (no buffering issues):

import sys,select

nbuf = ''
while True:
    if select.select([sys.stdin], [], [], 0)[0]:
        nbuf += sys.stdin.read(1)
    if len(nbuf) > 0:
        sys.stdout.write(nbuf)
        nbuf = ""

MicroPython v1.24.0-preview.98.g4d16a9cce on 2024-07-05; LOLIN_S2_MINI with ESP32-S2FN4R2

[dhalbert]

@gitcnd So, to be clear, are you still seeing issues with builds after #9400 was merged?

[gitcnd]

@dhalbert sorry, "real work" got in the way - I've not tried that yet.

[dhalbert]

This fix is also in 9.1.0-beta.4.

[jepler]

In case this is useful to know - the following equivalent code on the same physical S2_MINI in micropython runs fine (no buffering issues):
if select.select([sys.stdin], [], [], 0)[0]:

sys.stdin is select()able in CircuitPython as well, I just checked.