esp-rs / esp-println

Provides print! and println! implementations various Espressif devices
Apache License 2.0
19 stars 13 forks source link

No output on serial console #9

Closed jeancf closed 2 years ago

jeancf commented 2 years ago

I try to collect traces from the execution of a program on an ESP32C3 via UART with a serial console on my PC but it does not work.

I can upload and run a minimalist blinky program without problem. I then use cargo espmonitor --chip esp32c3 /dev/ttyUSB0 and I get the println! messages ("switching LED"):

❯ cargo espmonitor --chip esp32c3 /dev/ttyUSB0
ESPMonitor 0.10.0

Commands:
    CTRL+R    Reset chip
    CTRL+C    Exit

Opening /dev/ttyUSB0 with speed 115200
WARNING: Unable to open flash image /home/jeancf/Documents/esp32-c3/barebones/target/riscv32imc-esp-espidf/debug/barebones: No such file or directory (os error 2)
Resetting device... done
ESP-ROM:esp32c3-api1-20210207
Build:Feb  7 2021
rst:0x1 (POWERON),boot:0xc (SPI_FAST_FLASH_BOOT)
SPIWP:0xee
mode:DIO, clock div:1
load:0x3fcd6100,len:0x172c
load:0x403ce000,len:0x928
load:0x403d0000,len:0x2ce0
SHA-256 comparison failed:
Calculated: f75e5faaee9719bd137d0b01302b9f3a1088de2f9e75b28595c121f9aa850912
Expected: 7060ddceb031623b32a44a14bd182ec3ffe6abf45dfcafbbd77d04f329a4974c
Attempting to boot anyway...
entry 0x403ce000
I (48) boot: ESP-IDF v4.4-dev-2825-gb63ec47238 2nd stage bootloader
I (49) boot: compile time 12:10:40
I (49) boot: chip revision: 3
I (52) boot_comm: chip revision: 3, min. bootloader chip revision: 0
I (59) boot.esp32c3: SPI Speed      : 80MHz
I (64) boot.esp32c3: SPI Mode       : DIO
I (68) boot.esp32c3: SPI Flash Size : 2MB
I (73) boot: Enabling RNG early entropy source...
I (79) boot: Partition Table:
I (82) boot: ## Label            Usage          Type ST Offset   Length
I (89) boot:  0 nvs              WiFi data        01 02 00009000 00006000
I (97) boot:  1 phy_init         RF data          01 01 0000f000 00001000
I (104) boot:  2 factory          factory app      00 00 00010000 001f0000
I (112) boot: End of partition table
I (116) boot_comm: chip revision: 3, min. application chip revision: 0
I (123) esp_image: segment 0: paddr=00010020 vaddr=3c010020 size=027e4h ( 10212) map
I (133) esp_image: segment 1: paddr=0001280c vaddr=00000000 size=0d80ch ( 55308) 
I (148) esp_image: segment 2: paddr=00020020 vaddr=42000020 size=0d670h ( 54896) map
I (157) boot: Loaded app from partition at offset 0x10000
I (157) boot: Disabling RNG early entropy source...
switching LED
switching LED
switching LED
switching LED

However, when I try to connect with a serial console (minicom -D /dev/ttyUSB0 configured with 115200 8N1) I get no output. I also notice that the execution of the program is suspended on the controller while minicom is running (LED does not blink anymore).

Is this the expected behaviour? What do I need to do to get serial output?

MabezDev commented 2 years ago

I can upload and run a minimalist blinky program without problem. I then use cargo espmonitor --chip esp32c3 /dev/ttyUSB0 and I get the println! messages ("switching LED"):

This indicates the esp is working fine. Are you sure you're configuring minicom correctly, and it has the correct permissions etc? Maybe try ressetting the board with the reset button once you have connected via minicom.

bjoernQ commented 2 years ago

When the code stops running it's maybe because mincom sets RTS which is connected to the reset pin - espmonitor doesn't do anything special

jeancf commented 2 years ago

minicom sets RTS which is connected to the reset pin

I found out over the weekend that this is indeed what is happening. The affected board is an Ai-Thinker NodeMCU Series ESP32-C3S Kit that does have the RTS line connected to the EN pin. The issue is documented here:

For some serial port wiring configurations, the serial RTS & DTR pins need to be disabled in the terminal program before the ESP32-C3 will boot and produce serial output. This depends on the hardware itself, most development boards (including all Espressif boards) do not have this issue. The issue is present if RTS & DTR are wired directly to the EN & GPIO0 pins. See the esptool documentation for more details.

I did not find how to prevent minicom from asserting RTS during a serial connection but with sterm the command is sterm -s 115200 -d -r /dev/ttyUSB0. Moserial also has the option to disable RTS.

There is one remaining issue regarding formatting of the output:

Build:Feb  7 2021
rst:0x1 (POWERON),boot:0xc (SPI_FAST_FLASH_BOOT)
SPIWP:0xee
mode:DIO, clock div:1
load:0x3fcd6100,len:0x172c
load:0x403ce000,len:0x928
load:0x403d0000,len:0x2ce0
SHA-256 comparison failed:
Calculated: f75e5faaee9719bd137d0b01302b9f3a1088de2f9e75b28595c121f9aa850912
Expected: 7060ddceb031623b32a44a14bd182ec3ffe6abf45dfcafbbd77d04f329a4974c
Attempting to boot anyway...
entry 0x403ce000
I (48) boot: ESP-IDF v4.4-dev-2825-gb63ec47238 2nd stage bootloader
I (49) boot: compile time 12:10:40
I (49) boot: chip revision: 3
I (52) boot_comm: chip revision: 3, min. bootloader chip revision: 0
I (59) boot.esp32c3: SPI Speed      : 80MHz
I (64) boot.esp32c3: SPI Mode       : DIO
I (68) boot.esp32c3: SPI Flash Size : 2MB
I (73) boot: Enabling RNG early entropy source...
I (79) boot: Partition Table:
I (82) boot: ## Label            Usage          Type ST Offset   Length
I (89) boot:  0 nvs              WiFi data        01 02 00009000 00006000
I (97) boot:  1 phy_init         RF data          01 01 0000f000 00001000
I (104) boot:  2 factory          factory app      00 00 00010000 001f0000
I (112) boot: End of partition table
I (116) boot_comm: chip revision: 3, min. application chip revision: 0
I (123) esp_image: segment 0: paddr=00010020 vaddr=3c010020 size=027d4h ( 10196) map
I (133) esp_image: segment 1: paddr=000127fc vaddr=00000000 size=0d81ch ( 55324) 
I (148) esp_image: segment 2: paddr=00020020 vaddr=42000020 size=0d674h ( 54900) map
I (157) boot: Loaded app from partition at offset 0x10000
I (157) boot: Disabling RNG early entropy source...
switching LED
             switching LED
                          switching LED
                                       switching LED

As you can see, the startup information is printed correctly but the output of the println! macro ("switching LED") is terminated by a line feed only. Looking at ASCII, the startup information lines are terminated by x0d x0a(\r\n) while the output of println! is only terminated by x0a (\n).

Surprisingly (this is on linux), \n is taken as line-feed and not carriage-return + line-feed.

Shouldn't strings output by println! be terminated by \r\n as well?

bjoernQ commented 2 years ago

I see how it's surprising that the 2nd stage bootloader uses CR/LF but println uses LF I guess if you redirect the output to a file and open it with an editor it should be fine - also espmonitor/espflash handle both cases the same.

I think we shouldn't change the default but we can add a feature to opt-in to use CR/LF

jeancf commented 2 years ago

Thanks for the clarifications.