mqtt broker terminates conneection when ESP32 is in light sleep [IDFGH-5439]

zhaozhaozhao
Posts: 21
Joined: Tue Apr 13, 2021 8:43 am

mqtt broker terminates conneection when ESP32 is in light sleep [IDFGH-5439]

Postby zhaozhaozhao » Mon Jun 21, 2021 8:50 pm

Hello everyone,

I want to know if there is anyway to keep mqtt connection while the board goes into light sleep mode?

I don't have question when the board goes deep sleep mode, because the wifi and mqtt need to be reassociated anyway. As well as modem sleep, which is shown in /examples/wifi/power_save template code. The modem sleep always listen up to wifi beacon and will send PINGREQ to the mqtt broker periodically so that the MQTT broker will not disconnect. (I have enabled .light_sleep_enable option in esp_pm_config but I don't understand whether it really enters light sleep mode).

However when I force the board to go to light sleep mode with esp_light_sleep_start(), the board will not send PINGREQ to the broker anymore. So after some time the brocker will terminate the connection. Moreover, the connection is not re-established because the mqtt_start() command is only called once at board reboot.

I can reconnect mqtt by calling esp_mqtt_client_reconnect() in the mqtt handler whenever MQTT_ERROR is detected. But I want something faster, like re-establlish the connection as soon as the board wakes up. Becasue there will be some time in my code between light sleep wake-up and sending out the first mqtt message. Where should I insert mqtt_reconnect() command? In light sleep mode the program could pause at anywhere.

Or is there anyway to keep MQTT connection during light sleep mode please let me know.

Best Regards
zhaozhaozhao

Alberk
Posts: 50
Joined: Sat Jun 19, 2021 1:49 am

Re: mqtt broker terminates conneection when ESP32 is in light sleep

Postby Alberk » Tue Jun 22, 2021 12:21 am

From what I know the default mqtt server timeout is 60 seconds. If you need anything longer then it has to be set at the server end.

ESP_Alvin
Posts: 195
Joined: Thu May 17, 2018 2:26 am

Re: mqtt broker terminates conneection when ESP32 is in light sleep [IDFGH-5439]

Postby ESP_Alvin » Tue Jun 22, 2021 6:31 am

Moderator's note: edit the topic title for issue tracking, thanks for reporting.

ESP_igrr
Posts: 2067
Joined: Tue Dec 01, 2015 8:37 am

Re: mqtt broker terminates conneection when ESP32 is in light sleep [IDFGH-5439]

Postby ESP_igrr » Tue Jun 22, 2021 7:41 am

Hi zhaozhaozhao,

esp_light_sleep_start function forces the system to enter light sleep mode, and Wi-Fi connection is not maintained. Please see https://docs.espressif.com/projects/esp ... l#overview, quote:
In deep sleep and light sleep modes, wireless peripherals are powered down. Before entering deep sleep or light sleep modes, applications must disable WiFi and BT using appropriate calls (esp_bluedroid_disable(), esp_bt_controller_disable(), esp_wifi_stop()). WiFi and BT connections will not be maintained in deep sleep or light sleep, even if these functions are not called.
If WiFi connection needs to be maintained, enable WiFi modem sleep, and enable automatic light sleep feature (see Power Management APIs). This will allow the system to wake up from sleep automatically when required by WiFi driver, thereby maintaining connection to the AP.
examples/wifi/power_save example demonstrates the use of automatic light sleep (https://docs.espressif.com/projects/esp ... ement.html), where Wi-Fi connection and higher level protocol connections are maintained.

I have enabled .light_sleep_enable option in esp_pm_config but I don't understand whether it really enters light sleep mode
There is an API you can use to check this: esp_pm_dump_locks (https://docs.espressif.com/projects/esp ... ocksP4FILE).
If you enable CONFIG_PM_PROFILING option in menuconfig and then call esp_pm_dump_locks(stdout) after some time, it will print, among other things, the percentage of time spent in each sleep mode, similar to this:

Code: Select all

Time: 40107239
Lock stats:
force_wakeup    NO_LIGHT_SLEEP    0    0          0          0    0%
rtos1             CPU_FREQ_MAX    0    0         16       9417    1%
rtos0             CPU_FREQ_MAX    0    1          5     137239    1%
Mode stats:
   SLEEP   80M     39872429  99%
 APB_MIN   80M            0   0%
 APB_MAX   80M            0   0%
 CPU_MAX  160M       146894   0%
Here the last column in "mode stats" shows the system spending 99% of time in sleep mode.

zhaozhaozhao
Posts: 21
Joined: Tue Apr 13, 2021 8:43 am

Re: mqtt broker terminates conneection when ESP32 is in light sleep [IDFGH-5439]

Postby zhaozhaozhao » Tue Jun 22, 2021 11:46 am

Thank you all for the quick reply. If the automatic light sleep maintains the wifi and higher level protocols, will it consumes more power than normal light sleep? Where can I find more details about the implementation of automatic light sleep?

For the sake of saving more power, it is acceptable for me to reconecct wifi as well as mqtt when the board resumes from light sleep. Altough it is stated in the document that Wifi and Bluetooth will not be maintained during light sleep, I find that the board is still able to send out MQTT message when it wakes up (with QoS=1, message reception confirmed on mqtt broker as well as subscriber client). Please see the following console log.

Code: Select all

gpio interrupt on pin 25, val 1
I (5516) MQTT: published, msg_id=53553
gpio interrupt on pin 25, val 0
I (5906) MQTT: published, msg_id=64302
Time: 10267949
Lock stats:
wifi            APB_FREQ_MAX    0    0         98    1806508  rtos1           CPU_FREQ_MAX    0    0       1595     108226  rtos0           CPU_FREQ_MAX    0    1       1451     660791  Mode stats:
 APB_MIN  160M      8164192  79%
 APB_MAX  160M      1400492  13%
 CPU_MAX  160M       693928   6%
I (10896) sleep mode: go to sleep

W (11006) wifi:Next TBTT incorrect! next beacon:20840681, beacon interval:102400, now:25626367
I (11006) wifi:bcn_timout,ap_probe_send_start
gpio interrupt on pin 25, val 1
I (11026) MQTT: published, msg_id=61721
gpio interrupt on pin 25, val 1
I (13266) MQTT: published, msg_id=22305
Time: 32865174
Lock stats:
wifi            APB_FREQ_MAX    0    0        172    2405614  rtos1           CPU_FREQ_MAX    0    0       2344     123023  rtos0           CPU_FREQ_MAX    0    1       2355   16134824  Mode stats:
 APB_MIN  160M     14805588  45%
 APB_MAX  160M      1868610   5%
 CPU_MAX  160M     16181639  49%
I (18256) sleep mode: go to sleep
Except for the incorrect TBTT warning, I still receive the message on the subscriber. I did not even call esp_wifi_start(). Probably my home router maintains device information for a long time? The problem seems to only happen whenever the mqtt broker disconnect the client. Exactly after the disconnection message from the broker side, the board is not able to send out message anymore.
message from mosquitto broker:

Code: Select all

1624362205: Client ESP32:-1703935193 has exceeded timeout, disconnecting.
1624362205: Socket error on client ESP32:-1703935193, disconnecting.
1624362206: Received PINGREQ from noderedtest
1624362206: Sending PINGRESP to noderedtest
Message when trying sending message after broker disconnection.

Code: Select all

W (19166) wifi:Next TBTT incorrect! next beacon:31571240, beacon interval:102400, now:225342982
I (19166) wifi:bcn_timout,ap_probe_send_start
gpio interrupt on pin 25, val 1
E (19436) MQTT_CLIENT: mqtt_message_receive: transport_read() error: errno=128
I (19436) MQTT: MQTT_EVENT_ERROR
I (19436) MQTT_CLIENT: Client force reconnect requested
E (19436) MQTT_CLIENT: mqtt_process_receive: mqtt_message_receive() returned -1
I (19446) MQTT: MQTT_EVENT_DISCONNECTED
Therefore I am wondering whether there is way to disconnect network and only resume them when the board wakes up from light sleep mode. Which would probably save more battery power

ESP_igrr
Posts: 2067
Joined: Tue Dec 01, 2015 8:37 am

Re: mqtt broker terminates conneection when ESP32 is in light sleep [IDFGH-5439]

Postby ESP_igrr » Tue Jun 22, 2021 12:52 pm

The fact that the Wi-Fi driver keeps working somehow after esp_light_sleep_start is by coincidence more than by design, in part probably because your Wi-Fi router remembers the non-responsive station for a while. It might stop working in the future, I wouldn't recommend relying on that.

You can of course stop Wi-Fi before entering light sleep, and start it again afterwards; then ask MQTT client to reconnect. Depending on how much time the board spends in sleep mode and how much it spends in active, it might be more battery-efficient than using automatic light sleep.

As a rule of thumb, in automatic light sleep mode the system is active between 1-5% of time, depending on how accurate the router beacon interval is, and how much the channel is utilized. The less accurate the beacon interval and the more congested the channel is, the more time the ESP will spend in active state. If your desired ratio of active time to sleep time is less than 1%, then doing a forced light sleep (with stopping and starting Wi-Fi) may be more efficient. For an order of magnitude lower active ratios, even deep sleep might be suitable.

If you decide to take the forced sleep approach, you do need to factor in the time spent to get an IP address from DHCP on wakeup. To speed this process up, you can enable CONFIG_LWIP_DHCP_RESTORE_LAST_IP option in menuconfig (https://docs.espressif.com/projects/esp ... re-last-ip).
zhaozhaozhao wrote: Where can I find more details about the implementation of automatic light sleep?
The documentation page I linked (https://docs.espressif.com/projects/esp ... ement.html) contains the high level overview of the power management logic: the power management locks and the algorithm used to implement frequency switching. The specific implementation of this logic on the ESP32 is a bit more involved, but in a nutshell the system will enter light sleep when the next task wakeup or next esp_timer expiry event is at least CONFIG_FREERTOS_IDLE_TIME_BEFORE_SLEEP ticks away from now.

Looking at your log, it seems that automatic light sleep is not actually enabled:

Code: Select all

 APB_MIN  160M      8164192  79%
 APB_MAX  160M      1400492  13%
 CPU_MAX  160M       693928   6%
Please check that CONFIG_FREERTOS_USE_TICKLESS_IDLE is enabled in menuconfig, and light_sleep_enable member of esp_pm_config_esp32_t is set to true. Also please check the return code of esp_pm_configure() to ensure the call is successful.
If you do all the above, you should see "SLEEP" line in the stats, like in the sample in my previous comment.

zhaozhaozhao
Posts: 21
Joined: Tue Apr 13, 2021 8:43 am

Re: mqtt broker terminates conneection when ESP32 is in light sleep [IDFGH-5439]

Postby zhaozhaozhao » Tue Jun 22, 2021 2:51 pm

Thanks for the information. Now I understand that what does automatical light sleep mean. It will only clock-gate the CPU using a feature offered by FreeRTOS and will not power off network as normal light sleep does. And the power-consumption is merely 1%~5% of normal active mode, depending on the network quality.

Forcing normal light sleep mode requires disconnecting/ reconnecting WIFI, which may even consume more power than auto light sleep. Moreover, it takes time to resume wifi/mqtt connection so it is not suiltable for a quick publish demand. Using deep sleep mode with periodical wakeup may be more appropriate in these cases.

And finally I have tested esp_pm_dump_locks() function with the /examples/system/light_sleep example, it seems that normal light sleep will not leave a trace in the log, is that correct? I have enabled power-management log profile and FreeRTOS tickless idle feature, but I disabled light_sleep_enable in pm_config deliberately, because I want to check if normal light sleep will also be tracked in the log. I guess this is becasue normal esp_light_sleep_start() function do not call esp_pm_lock so the power-management module do not know the board has slept?

Anyway I feel the automatic light sleep meets my demand. I could investigate how to force light sleep later and update here.

Who is online

Users browsing this forum: icyTwist and 110 guests