The light_sleep example produces incorrect output. (IDFGH-8008)

[jcassette]

Environment

• Development Kit: none
• Kit version: none
• Module or chip used: ESP32-C3-MINI-1-N4
• IDF version: v4.4.2
• Build System: idf.py
• Compiler version: riscv32-esp-elf-gcc (crosstool-NG esp-2021r2-patch3) 8.4.0
• Operating System: Linux
• Using an IDE: No
• Power Supply: USB

Problem Description

The light_sleep example produces incorrect output.

Expected Behavior

The following message should be printed every 2 seconds, with XXXXX being incremented by 2000 each time:

Entering light sleep
Returned from light sleep, reason: timer, t=XXXXX ms, slept for 2000 ms

Actual Behavior

Some lines are not printed at all, some lines are printed incomplete.

Steps to reproduce

1. idf.py build erase-flash flash monitor

Code to reproduce this issue

See the light_sleep example and/or the files attached.

Debug Logs

Waiting for GPIO4 to go high...
Entering light sleep
Returned from light sleep, reason: timer, t=3772 ms, slept for 2000 ms
Entering light sleep
000 ms
Entering light sleep
Returned from light sleep, reason: timer, t=7861 ms, slept for 2000 ms
Entering light sleep
Entering light sleep
Entering light sleep
2000 ms
Entering light sleep
Returned from light sleep, reason: timer, t=81353 ms, slept for 2000 ms
Entering light sleep
2000 ms
Entering light sleep
Returned from light sleep, reason: timer, t=85449 ms, slept for 2000 ms
Entering light sleep
2000 ms
Entering light sleep
Returned from light sleep, reason: timer, t=89549 ms, slept for 2000 ms
Entering light sleep
2000 ms
Entering light sleep
Returned from light sleep, reason: timer, t=93646 ms, slept for 2000 ms
Entering light sleep
2000 ms
Entering light sleep
Returned from light sleep, reason: timer, t=97744 ms, slept for 2000 ms
Entering light sleep
2000 ms
Entering light sleep
Returned from light sleep, reason: timer, t=101841 ms, slept for 2000 ms
Entering light sleep
 2000 ms
Entering light sleep
Returned from light sleep, reason: timer, t=105940 ms, slept for 2000 ms
Entering light sleep
 2000 ms
Entering light sleep
Returned from light sleep, reason: timer, t=110038 ms, slept for 2000 ms
Entering light sleep
Entering light sleep
 2000 ms
Entering light sleep

Other items if possible

• sdkconfig file (attach the sdkconfig file from your project folder)
• elf file in the build folder (note this may contain all the code details and symbols of your project.)
• coredump (This provides stacks of tasks.)

light_sleep.zip

[Dazza0]

@jcassette Apologies for the late follow up. The reason some your output is truncated is because your example uses the USB Serial JTAG (USJ) peripheral for serial output, and the USJ output isn't flushed before entering light sleep (as opposed to using UART for serail output which is automatically flushed before light sleep begins).

Unfortunately, there are a few reasons why flushing the USJ serial output can't be achieved.

• USJ is a USB device. Thus, transmitting any serial data requires the USB Host (i.e., the PC) to request it via a USB BULK IN transfer. Most USB Host CDC drivers in typical PCs poll at a rate of 10s to 100s of milliseconds. If we were flush the USJ TX by waiting for the USB Host to request all the pending data, it could delay light sleep entry leading to increased power consumption.
• USJ cannot operate during light sleep on the ESP32-C3 as the entire peripheral is clock gated. In some cases, this can lead to some Host PCs detecting a disconnection of the ESP32-C3 serial port (again, depends on the poll rate).

Thus, the USJ can't be effectively used if light/deep sleep is involved (see #12628 for more details).

Unfortunately, I don't think there's not much we can do in this case. If you need a constantly connected serial port that persists over sleep, using UART would be the better option.