console keeps outputting garbled characters，after esp32c3 module enter low power mode (IDFGH-5621)

zcsaoe commented 3 years ago

Environment

Development Kit: [ESP32-C3-DevKitC-02]
Kit version (DevKitC): [v1]
Module or chip used: [ESP32-C3-WROOM-02]
IDF version (run git describe --tags to find it): v4.3-302-g47b96db12d
Build System: [CMake|idf.py]
Compiler version (run xtensa-esp32-elf-gcc --version to find it): riscv32-esp-elf-gcc (crosstool-NG esp-2021r1) 8.4.0
Operating System: [Linux]
Power Supply: [USB]

Problem Description

console keeps outputting garbled characters，after esp32c3 module enter low power mode Although the console cannot be used in low power consumption mode, I don’t want garbled output. The esp8266 console cannot be used in low-power mode and will not output garbled characters

Expected Behavior

The console will not output garbled characters in low power mode

Actual Behavior

Steps to reproduce

Initialize the console on the basis of power_save.c
The module is powered on and connected to wifi, and observe the console output

Code to reproduce this issue

testdemo

Debug Logs

root@us:~/idf/apps/examples/wifi/power_save# idf.py monitor
Executing action: monitor
Running idf_monitor in directory /home/share/esp/esp-idf/apps/examples/wifi/power_save
Executing "/root/.espressif/python_env/idf4.3_py3.8_env/bin/python /home/share/esp/esp-idf/tools/idf_monitor.py -p /dev/ttyUSB0 -b 115200 --toolchain-prefix riscv32-esp-elf- --decode-panic backtrace --target esp32c3 /home/share/esp/esp-idf/apps/examples/wifi/power_save/build/power_save.elf -m '/root/.espressif/python_env/idf4.3_py3.8_env/bin/python' '/home/share/esp/esp-idf/tools/idf.py'"...
--- idf_monitor on /dev/ttyUSB0 115200 ---
--- Quit: Ctrl+] | Menu: Ctrl+T | Help: Ctrl+T followed by Ctrl+H ---
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:0x1788
load:0x403ce000,len:0x8dc
load:0x403d0000,len:0x2984
entry 0x403ce000
I (30) boot: ESP-IDF v4.3-302-g47b96db12d-dirty 2nd stage bootloader
I (30) boot: compile time 16:59:37
I (30) boot: chip revision: 3
I (34) boot.esp32c3: SPI Speed      : 80MHz
I (38) boot.esp32c3: SPI Mode       : DIO
I (43) boot.esp32c3: SPI Flash Size : 2MB
I (48) boot: Enabling RNG early entropy source...
I (53) boot: Partition Table:
I (57) boot: ## Label            Usage          Type ST Offset   Length
I (64) boot:  0 nvs              WiFi data        01 02 00009000 00006000
I (72) boot:  1 phy_init         RF data          01 01 0000f000 00001000
I (79) boot:  2 factory          factory app      00 00 00010000 00100000
I (86) boot: End of partition table
I (91) esp_image: segment 0: paddr=00010020 vaddr=3c090020 size=14fbch ( 85948) map
I (112) esp_image: segment 1: paddr=00024fe4 vaddr=3fc91400 size=03250h ( 12880) load
I (115) esp_image: segment 2: paddr=0002823c vaddr=40380000 size=07ddch ( 32220) load
I (124) esp_image: segment 3: paddr=00030020 vaddr=42000020 size=851f8h (545272) map
I (208) esp_image: segment 4: paddr=000b5220 vaddr=40387ddc size=0946ch ( 37996) load
I (215) esp_image: segment 5: paddr=000be694 vaddr=50000000 size=00010h (    16) load
I (221) boot: Loaded app from partition at offset 0x10000
I (221) boot: Disabling RNG early entropy source...
I (237) cpu_start: Pro cpu up.
I (249) cpu_start: Pro cpu start user code
I (249) cpu_start: cpu freq: 160000000
I (249) cpu_start: Application information:
I (252) cpu_start: Project name:     power_save
I (257) cpu_start: App version:      v4.3-302-g47b96db12d-dirty
I (264) cpu_start: Compile time:     Jul 29 2021 16:59:22
I (270) cpu_start: ELF file SHA256:  979e365b64e65a31...
I (276) cpu_start: ESP-IDF:          v4.3-302-g47b96db12d-dirty
I (282) heap_init: Initializing. RAM available for dynamic allocation:
I (290) heap_init: At 3FC98760 len 000278A0 (158 KiB): DRAM
I (296) heap_init: At 3FCC0000 len 0001F060 (124 KiB): STACK/DRAM
I (303) heap_init: At 50000010 len 00001FF0 (7 KiB): RTCRAM
I (309) spi_flash: detected chip: generic
I (314) spi_flash: flash io: dio
W (317) spi_flash: Detected size(4096k) larger than the size in the binary image header(2048k). Using the size in the binary image header.
I (342) sleep: Configure to isolate all GPIO pins in sleep state
I (342) cpu_start: Starting scheduler.
I (348) pm: Frequency switching config: CPU_MAX: 80, APB_MAX: 80, APB_MIN: 10, Light sleep: ENABLED
I (348) sleep: Enable automatic switching of GPIO sleep configuration
esp32c3> ▒▒▒▒▒▒▒▒▒▒▒▒▒▒▒▒▒▒▒▒▒▒▒▒▒▒▒▒▒▒▒▒▒▒▒▒▒▒▒▒▒▒▒▒▒▒▒▒▒▒▒▒▒▒▒▒▒▒▒▒▒▒▒▒▒▒▒▒▒▒▒▒▒▒▒▒▒▒▒▒▒▒▒▒▒▒▒▒▒▒▒▒▒▒▒▒▒▒▒▒▒▒▒▒▒▒▒▒▒▒▒▒▒▒▒▒▒▒▒▒▒▒▒▒▒▒▒▒▒▒▒▒▒▒▒▒▒▒▒▒▒▒▒▒▒▒▒▒▒▒▒▒▒▒▒▒▒▒▒▒▒▒▒▒▒▒▒▒▒▒▒▒▒▒▒▒▒▒▒▒▒▒▒▒▒▒▒▒▒▒▒▒▒▒▒▒▒▒▒▒▒▒▒▒▒▒▒▒▒▒▒▒▒▒▒▒▒▒▒▒▒▒▒▒▒▒▒▒▒▒▒▒▒▒▒▒▒▒▒▒▒▒▒▒▒▒▒▒▒▒▒▒▒▒▒▒▒▒▒▒▒▒▒▒▒▒▒▒▒▒▒▒▒▒▒▒▒▒▒▒▒▒▒▒▒▒▒▒▒▒▒▒▒▒▒▒▒▒▒▒▒▒▒▒▒▒▒▒▒▒▒▒▒
root@us:~/idf/apps/examples/wifi/power_save#

bbinet commented 2 years ago

I also face the same issue.

I was wondering if this is because we cannot select REF_TICK as UART clock source on esp32c3 (as we can read on the documentation that UART peripheral work normally even when the APB frequency is changing only if REF_TICK is used as a clock source).

So is there any way to make esp console work fine on esp32c3 while using the power management to reduce power consumption?

xiaojie76 commented 2 years ago

@bbinet This is not the reason for the garbled output, c3 can choose XTAL_CLK as clock source, and it will not be affected by the APB frequency change. So just using dynamic frequency scaling is no problem. But whether it is REF_CLK or XTAL_CLK, it will be powered down in light sleep mode, which cause the uart module not work normally.

bbinet commented 2 years ago

Thanks @xiaojie76 for your input here, you're right: if I set .light_sleep_enable = false, it works fine.

Is there anything we can do to fix the uartmodule when PM w/ lightsleep is enabled?

igrr commented 2 years ago

We might need to check the code which suspends UART transmission before going into light sleep. IIRC, we made it work correctly (not garble the characters) on the esp32; it is possible that the respective part of the code wasn't correctly adapted to the esp32-c3.

https://github.com/espressif/esp-idf/blob/179ea878c747519138b40f387b80f30dd72097f0/components/esp_hw_support/sleep_modes.c#L307

xiaojie76 commented 2 years ago

@igrr, I reproduced this issue on esp32 and esp32s2, both output garbled characters.

bbinet commented 2 years ago

@xiaojie76, @igrr, any news about this issue?

I now need to use the uart to communicate with a bg95-m3 modem using esp_modem, but this issue prevents me from using PM with light_sleep enabled and so it draws too much current...

ginkgm commented 2 years ago

I think this issue is caused by:

When both SOC_GPIO_SUPPORT_SLP_SWITCH=1 and CONFIG_PM_SLP_DISABLE_GPIO=y, the system will enable SLP_SEL for all GPIOs. In this case, GPIOs will use different IE (SLP_IE) in sleep modes.
When IE is 0, the input signal will be tied to 0, so that UART may receive 0 as input

To workaround this issue, you may turn off CONFIG_PM_SLP_DISABLE_GPIO (in this case, power consumption may be a bit higher), or call gpio_sleep_sel_dis to avoid the switch.

We are considering improving the driver to avoid this issue.

bbinet commented 2 years ago

Thank you @ginkgm for your comment, but I can't disable CONFIG_PM_SLP_DISABLE_GPIO on my side as it is checked by default in idf.py menuconfig:

(Top) → Component config → Power Management
                         Espressif IoT Development Framework Configuration
[*] Support for power management
[*]     Enable dynamic frequency scaling (DFS) at startup
[ ]     Enable profiling counters for PM locks
[ ]     Enable debug tracing of PM using GPIOs
[*] Put lightsleep related codes in internal RAM
[*] Put RTOS IDLE related codes in internal RAM
-*- Disable all GPIO when chip at sleep
[*] Power down CPU in light sleep

I think this is because ESP_SLEEP_GPIO_RESET_WORKAROUND is selected by default on esp32c3.

I also tried to call gpio_sleep_sel_dis on my uart tx and rx gpios but it does not seem to work.

Any other idea?

songruo commented 2 years ago

Hello @bbinet,

Yes, you are right. If you want to disable CONFIG_PM_SLP_DISABLE_GPIO, you will have to disable ESP_SLEEP_GPIO_RESET_WORKAROUND first.

For the second option, you don't need to call gpio_sleep_sel_dis on tx pin, it is only required for the rx pin. So if for ESP32C3 and with the default uart console gpio pins, it will be gpio_sleep_sel_dis(20). Are you sure this does not work?

A third way is to set gpio sleep configuration by: gpio_sleep_set_direction(20, GPIO_MODE_INPUT); gpio_sleep_set_pull_mode(20, GPIO_PULLUP_ONLY);

The general idea is the same. The rx pin needs IE = 1, PU = 1 during sleep to not receive undesired data.

bbinet commented 2 years ago

Hello @songruo.

I confirm that gpio_sleep_sel_dis(20) does not work for me.

But the other workaround do work fine:

gpio_sleep_set_direction(20, GPIO_MODE_INPUT);
gpio_sleep_set_pull_mode(20, GPIO_PULLUP_ONLY);

And de-configuring both CONFIG_PM_SLP_DISABLE_GPIO and ESP_SLEEP_GPIO_RESET_WORKAROUND also works.

I still have another annoying issue though: I'm using the console component to run various commands on my esp32c3, but when I enter keys on my keyboard, those are not always echoed on the console, some chars are missed. I think this is because the esp32c3 is sometimes light sleeping when those chars are received. Is there a way to force the esp32c3 to wake up when a char is received on uart rx line?

songruo commented 2 years ago

@bbinet Yes, esp32c3 supports uart wakeup. You can check examples/system/light_sleep, where uart is used as one of the wakeup sources. But please be aware that, the first byte which is used to wakeup the chip can not be stored, which means the first character will always be lost.

bbinet commented 2 years ago

Thank you @songruo, but this will be an issue for me: if we loose the first char, we won't be able to parse the response from the LTE modem which is connected to uart.

chegewara commented 1 year ago

Hi, i dont want to open new issue, but in my case instead of garbage esp_console basic example, and other examples, just stop working after printing prompt line:

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:0x3fcd5820,len:0x11b8
load:0x403cc710,len:0x780
load:0x403ce710,len:0x2c50
entry 0x403cc710
I (174) cpu_start: Pro cpu up.
I (183) cpu_start: Pro cpu start user code
I (183) cpu_start: cpu freq: 160000000 Hz
I (183) cpu_start: Application information:
I (186) cpu_start: Project name:     console
I (191) cpu_start: App version:      v5.1-dev-3213-gd29e53dc0c-dirty
I (198) cpu_start: Compile time:     Feb  6 2023 04:59:35
I (204) cpu_start: ELF file SHA256:  1449827010b31940...
I (210) cpu_start: ESP-IDF:          v5.1-dev-3213-gd29e53dc0c-dirty
I (217) cpu_start: Min chip rev:     v0.3
I (222) cpu_start: Max chip rev:     v0.99 
I (227) cpu_start: Chip rev:         v0.3
I (232) heap_init: Initializing. RAM available for dynamic allocation:
I (239) heap_init: At 3FC99AB0 len 00042C60 (267 KiB): DRAM
I (245) heap_init: At 3FCDC710 len 00002950 (10 KiB): STACK/DRAM
I (252) heap_init: At 50000028 len 00001FD8 (7 KiB): RTCRAM
I (259) spi_flash: detected chip: generic
I (263) spi_flash: flash io: dio
I (267) sleep: Configure to isolate all GPIO pins in sleep state
I (273) sleep: Enable automatic switching of GPIO sleep configuration
I (280) app_start: Starting scheduler on CPU0
I (285) main_task: Started on CPU0
I (285) main_task: Calling app_main()
I (295) example: Command history enabled

Type 'help' to get the list of commands.
Use UP/DOWN arrows to navigate through command history.
Press TAB when typing command name to auto-complete.

Your terminal application does not support escape sequences.

Line editing and history features are disabled.

On Windows, try using Putty instead.
esp32c3> I (655) main_task: Returned from app_main()

I have connected USB to UART converter to RX/TX pins.

Thanks

songruo commented 1 year ago

Hi @chegewara, this doesn't seem to be the same problem as the post was discussing. However, I think maybe your problem is because you are using CMD on Windows? As you can see, the log says

Your terminal application does not support escape sequences.

Can you try with another terminal, putty or powershell?

chegewara commented 1 year ago

i am working on linux, not the windows
exactly the same example, wifi/ftm is working fine with S2 and S3 and fail with C3, so i dont think its the problem with console
if you think i should open new issue, i will do
i would rather focus on this logs, why app_main returned on C3 and does not return on S2 and S3
```
esp32c3> I (655) main_task: Returned from app_main()
```

songruo commented 1 year ago

@chegewara

I (655) main_task: Returned from app_main()

This line exists for every target. The main task returns, but task "console_repl" is still running.

I was not able to reproduce the problem.

Are you sure that you can't type anything and there is no response on the console for ESP32C3? If so, I would suggest you open a new issue to discuss it.

chegewara commented 1 year ago

Im pretty sure there is no way to type in console. I am using vs code and command line to build esp-idf apps, but i also tested with putty on ubuntu 20.04.

Maybe that line exist for all targets, but the only C3 is printing it and stop working.

espressif / esp-idf