DeepSleep not working, when building from source 2.9.2019

thomas-lentz commented 5 years ago

BUG DESCRIPTION

Setting DeepSleep via command will not set Device into DeepSleep

REQUESTED INFORMATION

[x ] Read the Contributing Guide and Policy and the Code of Conduct
[x ] Searched the problem in the forum (https://groups.google.com/d/forum/sonoffusers)
[x ] Device used (i.e. Sonoff Basic) : LOLIN D1 mini Pro V2.0.0
[x] Selfcompiled firmware version: Project sonoff Sonoff Version: 6.6.0.3 stb-1.9 (sonoff)
[x] Development IDE - Compiler / Upload tools used : Arduino / Arduino

[x] Provide the output of command status 0 :

00:00:30 CMD: status 0
00:00:30 RSL: stat/sonoff/STATUS = {"Status":{"Module":1,"FriendlyName":["Sonoff"],"Topic":"sonoff","ButtonTopic":"0","Power":1,"PowerOnState":3,"LedState":1,"LedMask":"FFFF","SaveData":1,"SaveState":1,"SwitchTopic":"0","SwitchMode":[0,0,0,0,0,0,0,0],"ButtonRetain":0,"SwitchRetain":0,"SensorRetain":0,"PowerRetain":0}}
00:00:30 RSL: stat/sonoff/STATUS1 = {"StatusPRM":{"Baudrate":115200,"GroupTopic":"sonoffs","OtaUrl":"http://thehackbox.org/tasmota/release/sonoff.bin","RestartReason":"Software/System restart","Uptime":"0T00:00:30","StartupUTC":"","Sleep":50,"CfgHolder":4617,"BootCount":1,"SaveCount":6,"SaveAddress":"3F6000"}}
00:00:30 RSL: stat/sonoff/STATUS2 = {"StatusFWR":{"Version":"6.6.0.3 stb-1.9(sonoff)","BuildDateTime":"2019-09-02T19:35:43","Boot":31,"Core":"2_5_2","SDK":"2.2.1(cfd48f3)"}}
00:00:30 RSL: stat/sonoff/STATUS3 = {"StatusLOG":{"SerialLog":2,"WebLog":2,"SysLog":0,"LogHost":"","LogPort":514,"SSId":["",""],"TelePeriod":60,"Resolution":"558180C0","SetOption":["00008009","280500000100060000005A00000000000000","00000000"]}}
00:00:30 RSL: stat/sonoff/STATUS4 = {"StatusMEM":{"ProgramSize":604,"Free":3468,"Heap":28056,"ProgramFlashSize":4096,"FlashSize":4096,"FlashChipId":"16405E","FlashMode":2,"Features":["00000809","0FDAE396","001683A0","22B617CD","01001BC0"]}}
00:00:30 RSL: stat/sonoff/STATUS5 = {"StatusNET":{"Hostname":"sonoff-2441","IPAddress":"(IP unset)","Gateway":"192.168.1.1","Subnetmask":"255.255.255.0","DNSServer":"192.168.1.1","Mac":"84:F3:EB:E3:C9:89","Webserver":2,"WifiConfig":4}}
00:00:30 RSL: stat/sonoff/STATUS6 = {"StatusMQT":{"MqttHost":"","MqttPort":1883,"MqttClientMask":"DVES_%06X","MqttClient":"DVES_E3C989","MqttUser":"DVES_USER","MqttCount":0,"MAX_PACKET_SIZE":1000,"KEEPALIVE":30}}
00:00:30 RSL: stat/sonoff/STATUS7 = {"StatusTIM":{"UTC":"Thu Jan 01 00:00:30 1970","Local":"Thu Jan 01 00:00:30 1970","StartDST":"Thu Jan 01 00:00:00 1970","EndDST":"Thu Jan 01 00:00:00 1970","Timezone":"+00:00","Sunrise":"07:43","Sunset":"16:03"}}
00:00:30 RSL: stat/sonoff/STATUS10 = {"StatusSNS":{"Time":"1970-01-01T00:00:30","Epoch":30}}
00:00:30 RSL: stat/sonoff/STATUS11 = {"StatusSTS":{"Time":"1970-01-01T00:00:30","Epoch":30,"Uptime":"0T00:00:30","UptimeSec":30,"Heap":27,"SleepMode":"Dynamic","Sleep":50,"LoadAvg":19,"MqttCount":0,"POWER":"ON","Wifi":{"AP":1,"SSId":"","BSSId":"FF:FF:FF:FF:FF:FF","Channel":1,"RSSI":100,"LinkCount":0,"Downtime":"0T00:00:00","DeepSleep":60,"Heap":28016}}}

[x] Provide the output of console when you experience your issue if apply :

CONSOLE OUTPUT HERE:
00:02:01 CMD: deepsleep
00:02:01 RSL: stat/sonoff/RESULT = {"DeepSleep":"60 (60)"}
00:02:05 CMD: teleperiod
00:02:05 RSL: stat/sonoff/RESULT = {"TelePeriod":"60"}
......... (nothing happens)

correct behaviour;

00:00:09 CMD: deepsleep
00:00:09 RSL: stat/sonoff/RESULT = {"DeepSleep":"60 (60)"}
00:00:20 CMD: teleperiod
00:00:20 RSL: stat/sonoff/RESULT = {"TelePeriod":"60"}
00:00:59 RSL: tele/sonoff/STATE = {"Time":"1970-01-01T00:00:59","Epoch":59,"Uptime":"0T00:00:59","UptimeSec":59,"Heap":27,"SleepMode":"Dynamic","Sleep":50,"LoadAvg":19,"MqttCount":0,"POWER":"ON","Wifi":{"AP":1,"SSId":"","BSSId":"FF:FF:FF:FF:FF:FF","Channel":1,"RSSI":100,"LinkCount":0,"Downtime":"0T00:00:00","DeepSleep":60,"Heap":28016}}
00:00:59 RSL: tele/sonoff/LWT = Offline
00:00:59 RSL: tele/sonoff/UPTIME_S = {"Time":"1970-01-01T00:00:59", "Uptime_s":812713}

TO REPRODUCE

Just enter DeepSleep 60 and TelePeriod 60 at console

EXPECTED BEHAVIOUR

Should go to deepsleep after some time...

ADDITIONAL CONTEXT

It is working with the Source files from 28.08.2019. No "personal" configuration has been made to both versions.

Personal guess: somebody deactivated the function for testing purposes and forgot to reactivate it, before putting it into git.

Status 0 of working complied sources 4 days ago

00:00:00 CMD: status 0
00:00:00 RSL: stat/sonoff/STATUS = {"Status":{"Module":1,"FriendlyName":["Sonoff"],"Topic":"sonoff","ButtonTopic":"0","Power":1,"PowerOnState":3,"LedState":1,"LedMask":"FFFF","SaveData":1,"SaveState":1,"SwitchTopic":"0","SwitchMode":[0,0,0,0,0,0,0,0],"ButtonRetain":0,"SwitchRetain":0,"SensorRetain":0,"PowerRetain":0}}
00:00:00 RSL: stat/sonoff/STATUS1 = {"StatusPRM":{"Baudrate":115200,"GroupTopic":"sonoffs","OtaUrl":"http://thehackbox.org/tasmota/release/sonoff.bin","RestartReason":"Deep-Sleep Wake","Uptime":"0T00:00:00","StartupUTC":"","Sleep":50,"CfgHolder":4617,"BootCount":1,"SaveCount":6,"SaveAddress":"3F6000"}}
00:00:00 RSL: stat/sonoff/STATUS2 = {"StatusFWR":{"Version":"6.6.0.3 stb-1.6(sonoff)","BuildDateTime":"2019-09-02T19:31:04","Boot":31,"Core":"2_5_2","SDK":"2.2.1(cfd48f3)"}}
00:00:00 RSL: stat/sonoff/STATUS3 = {"StatusLOG":{"SerialLog":2,"WebLog":2,"SysLog":0,"LogHost":"","LogPort":514,"SSId":["",""],"TelePeriod":60,"Resolution":"558180C0","SetOption":["00008009","280500000100060000005A00000000000000","00000000"]}}
00:00:00 RSL: stat/sonoff/STATUS4 = {"StatusMEM":{"ProgramSize":604,"Free":3468,"Heap":28056,"ProgramFlashSize":4096,"FlashSize":4096,"FlashChipId":"16405E","FlashMode":2,"Features":["00000809","0FDAE396","001683A0","22B617CD","01001BC0"]}}
00:00:00 RSL: stat/sonoff/STATUS5 = {"StatusNET":{"Hostname":"sonoff-2441","IPAddress":"(IP unset)","Gateway":"192.168.1.1","Subnetmask":"255.255.255.0","DNSServer":"192.168.1.1","Mac":"84:F3:EB:E3:C9:89","Webserver":2,"WifiConfig":4}}
00:00:00 RSL: stat/sonoff/STATUS6 = {"StatusMQT":{"MqttHost":"","MqttPort":1883,"MqttClientMask":"DVES_%06X","MqttClient":"DVES_E3C989","MqttUser":"DVES_USER","MqttCount":0,"MAX_PACKET_SIZE":1000,"KEEPALIVE":30}}
00:00:00 RSL: stat/sonoff/STATUS7 = {"StatusTIM":{"UTC":"Thu Jan 01 00:00:00 1970","Local":"Thu Jan 01 00:00:00 1970","StartDST":"Thu Jan 01 00:00:00 1970","EndDST":"Thu Jan 01 00:00:00 1970","Timezone":"+00:00","Sunrise":"07:48","Sunset":"16:07"}}
00:00:00 RSL: stat/sonoff/STATUS10 = {"StatusSNS":{"Time":"1970-01-01T00:00:00","Epoch":0}}
00:00:00 RSL: stat/sonoff/STATUS11 = {"StatusSTS":{"Time":"1970-01-01T00:00:00","Epoch":0,"Uptime":"0T00:00:00","UptimeSec":0,"Heap":27,"SleepMode":"Dynamic","Sleep":50,"LoadAvg":51,"MqttCount":0,"POWER":"ON","Wifi":{"AP":1,"SSId":"","BSSId":"FF:FF:FF:FF:FF:FF","Channel":1,"RSSI":100,"LinkCount":0,"Downtime":"0T00:00:00","DeepSleep":60,"Heap":28016}}}

stefanbode commented 5 years ago

Yes, sorry for this. Messed up with rules. Already see this on my side. Fix will come soon

stefanbode commented 5 years ago

Please check and close if fine

hermann1514 commented 5 years ago

Hi, i have a question about the deepsleep mode. How can i enable the deepsleep mode? I would like to send a temperature every 30 Minutes to my MQTT Server. I have a WEMOS D1 mini with this Tasmota Fork. I enter the following Commands in the Console for testing: DeepSleep 60 TelePeriod 60

(GPIO 16 was set to DeepSleep)

But how can i check if deepsleep working?

Ping was always answered.

i use the latest code.

Thanks for help. Regards Hermann

stefanbode commented 5 years ago

take a look on the console. also webconsole is fine. set teleperiod 10 and deepsleep 60. after teleperiod you should see that the LWT topic will immediately go offline. After restart you can see in INFO3 topic (i guess) the wakeup reason: "wakeup after deepsleep" I just fixed a bug some minutes ago. .Maybe you need to update to the current version

hermann1514 commented 5 years ago

I used the code from 15 minutes ago. Then I entered the commands. Here is the output:


21:11:31 CMD: teleperiod 10
21:11:31 MQT: SmartHome/stat/sonoff/RESULT = {"TelePeriod":"10"}
21:11:32 MQT: SmartHome/tele/sonoff/STATE = {"Time":"2019-09-02T21:11:32","Epoch":1567455092,"Uptime":"0T00:17:22","UptimeSec":1042,"Vcc":3.041,"Heap":28,"SleepMode":"Dynamic","Sleep":50,"LoadAvg":19,"MqttCount":1,"Wifi":{"AP":1,"SSId":"WLANI","BSSId":"24:65:11:C7:0B:EC","Channel":1,"RSSI":74,"LinkCount":1,"Downtime":"0T00:00:04","DeepSleep":60,"Heap":29584}}
21:11:32 MQT: SmartHome/tele/sonoff/SENSOR = {"Time":"2019-09-02T21:11:32","Epoch":1567455092,"DS18B20":{"Temperature":20.2},"TempUnit":"C"}
21:11:42 MQT: SmartHome/tele/sonoff/STATE = {"Time":"2019-09-02T21:11:42","Epoch":1567455102,"Uptime":"0T00:17:32","UptimeSec":1052,"Vcc":3.041,"Heap":28,"SleepMode":"Dynamic","Sleep":50,"LoadAvg":19,"MqttCount":1,"Wifi":{"AP":1,"SSId":"WLANI","BSSId":"24:65:11:C7:0B:EC","Channel":1,"RSSI":76,"LinkCount":1,"Downtime":"0T00:00:04","DeepSleep":60,"Heap":29632}}
21:11:42 MQT: SmartHome/tele/sonoff/SENSOR = {"Time":"2019-09-02T21:11:42","Epoch":1567455102,"DS18B20":{"Temperature":20.2},"TempUnit":"C"}
21:11:47 CMD: DeepSleep 60
21:11:47 MQT: SmartHome/stat/sonoff/RESULT = {"DeepSleep":"60 (60)"}
21:11:52 MQT: SmartHome/tele/sonoff/STATE = {"Time":"2019-09-02T21:11:52","Epoch":1567455112,"Uptime":"0T00:17:42","UptimeSec":1062,"Vcc":3.041,"Heap":28,"SleepMode":"Dynamic","Sleep":50,"LoadAvg":19,"MqttCount":1,"Wifi":{"AP":1,"SSId":"WLANI","BSSId":"24:65:11:C7:0B:EC","Channel":1,"RSSI":74,"LinkCount":1,"Downtime":"0T00:00:04","DeepSleep":60,"Heap":29632}}
21:11:52 MQT: SmartHome/tele/sonoff/SENSOR = {"Time":"2019-09-02T21:11:52","Epoch":1567455112,"DS18B20":{"Temperature":20.8},"TempUnit":"C"}
21:12:02 MQT: SmartHome/tele/sonoff/STATE = {"Time":"2019-09-02T21:12:02","Epoch":1567455122,"Uptime":"0T00:17:52","UptimeSec":1072,"Vcc":3.041,"Heap":28,"SleepMode":"Dynamic","Sleep":50,"LoadAvg":19,"MqttCount":1,"Wifi":{"AP":1,"SSId":"WLANI","BSSId":"24:65:11:C7:0B:EC","Channel":1,"RSSI":76,"LinkCount":1,"Downtime":"0T00:00:04","DeepSleep":60,"Heap":29632}}
21:12:02 MQT: SmartHome/tele/sonoff/SENSOR = {"Time":"2019-09-02T21:12:02","Epoch":1567455122,"DS18B20":{"Temperature":20.7},"TempUnit":"C"}
21:12:12 MQT: SmartHome/tele/sonoff/STATE = {"Time":"2019-09-02T21:12:12","Epoch":1567455132,"Uptime":"0T00:18:02","UptimeSec":1082,"Vcc":3.043,"Heap":28,"SleepMode":"Dynamic","Sleep":50,"LoadAvg":19,"MqttCount":1,"Wifi":{"AP":1,"SSId":"WLANI","BSSId":"24:65:11:C7:0B:EC","Channel":1,"RSSI":76,"LinkCount":1,"Downtime":"0T00:00:04","DeepSleep":60,"Heap":29632}}
21:12:12 MQT: SmartHome/tele/sonoff/SENSOR = {"Time":"2019-09-02T21:12:12","Epoch":1567455132,"DS18B20":{"Temperature":20.8},"TempUnit":"C"}
21:12:22 MQT: SmartHome/tele/sonoff/STATE = {"Time":"2019-09-02T21:12:22","Epoch":1567455142,"Uptime":"0T00:18:12","UptimeSec":1092,"Vcc":3.041,"Heap":28,"SleepMode":"Dynamic","Sleep":50,"LoadAvg":19,"MqttCount":1,"Wifi":{"AP":1,"SSId":"WLANI","BSSId":"24:65:11:C7:0B:EC","Channel":1,"RSSI":76,"LinkCount":1,"Downtime":"0T00:00:04","DeepSleep":60,"Heap":29632}}
21:12:22 MQT: SmartHome/tele/sonoff/SENSOR = {"Time":"2019-09-02T21:12:22","Epoch":1567455142,"DS18B20":{"Temperature":20.9},"TempUnit":"C"}
21:12:32 MQT: SmartHome/tele/sonoff/STATE = {"Time":"2019-09-02T21:12:32","Epoch":1567455152,"Uptime":"0T00:18:22","UptimeSec":1102,"Vcc":3.041,"Heap":28,"SleepMode":"Dynamic","Sleep":50,"LoadAvg":19,"MqttCount":1,"Wifi":{"AP":1,"SSId":"WLANI","BSSId":"24:65:11:C7:0B:EC","Channel":1,"RSSI":74,"LinkCount":1,"Downtime":"0T00:00:04","DeepSleep":60,"Heap":29632}}
21:12:32 MQT: SmartHome/tele/sonoff/SENSOR = {"Time":"2019-09-02T21:12:32","Epoch":1567455152,"DS18B20":{"Temperature":20.3},"TempUnit":"C"}
21:12:42 MQT: SmartHome/tele/sonoff/STATE = {"Time":"2019-09-02T21:12:42","Epoch":1567455162,"Uptime":"0T00:18:32","UptimeSec":1112,"Vcc":3.041,"Heap":28,"SleepMode":"Dynamic","Sleep":50,"LoadAvg":19,"MqttCount":1,"Wifi":{"AP":1,"SSId":"WLANI","BSSId":"24:65:11:C7:0B:EC","Channel":1,"RSSI":74,"LinkCount":1,"Downtime":"0T00:00:04","DeepSleep":60,"Heap":29632}}
21:12:42 MQT: SmartHome/tele/sonoff/SENSOR = {"Time":"2019-09-02T21:12:42","Epoch":1567455162,"DS18B20":{"Temperature":20.9},"TempUnit":"C"}
21:12:52 MQT: SmartHome/tele/sonoff/STATE = {"Time":"2019-09-02T21:12:52","Epoch":1567455172,"Uptime":"0T00:18:42","UptimeSec":1122,"Vcc":3.041,"Heap":28,"SleepMode":"Dynamic","Sleep":50,"LoadAvg":19,"MqttCount":1,"Wifi":{"AP":1,"SSId":"WLANI","BSSId":"24:65:11:C7:0B:EC","Channel":1,"RSSI":70,"LinkCount":1,"Downtime":"0T00:00:04","DeepSleep":60,"Heap":29632}}
21:12:52 MQT: SmartHome/tele/sonoff/SENSOR = {"Time":"2019-09-02T21:12:52","Epoch":1567455172,"DS18B20":{"Temperature":20.3},"TempUnit":"C"}
21:13:02 MQT: SmartHome/tele/sonoff/STATE = {"Time":"2019-09-02T21:13:02","Epoch":1567455182,"Uptime":"0T00:18:52","UptimeSec":1132,"Vcc":3.041,"Heap":28,"SleepMode":"Dynamic","Sleep":50,"LoadAvg":19,"MqttCount":1,"Wifi":{"AP":1,"SSId":"WLANI","BSSId":"24:65:11:C7:0B:EC","Channel":1,"RSSI":74,"LinkCount":1,"Downtime":"0T00:00:04","DeepSleep":60,"Heap":29632}}
21:13:02 MQT: SmartHome/tele/sonoff/SENSOR = {"Time":"2019-09-02T21:13:02","Epoch":1567455182,"DS18B20":{"Temperature":20.8},"TempUnit":"C"}
21:13:12 MQT: SmartHome/tele/sonoff/STATE = {"Time":"2019-09-02T21:13:12","Epoch":1567455192,"Uptime":"0T00:19:02","UptimeSec":1142,"Vcc":3.041,"Heap":28,"SleepMode":"Dynamic","Sleep":50,"LoadAvg":19,"MqttCount":1,"Wifi":{"AP":1,"SSId":"WLANI","BSSId":"24:65:11:C7:0B:EC","Channel":1,"RSSI":74,"LinkCount":1,"Downtime":"0T00:00:04","DeepSleep":60,"Heap":29632}}
21:13:12 MQT: SmartHome/tele/sonoff/SENSOR = {"Time":"2019-09-02T21:13:12","Epoch":1567455192,"DS18B20":{"Temperature":20.8},"TempUnit":"C"}
21:13:22 MQT: SmartHome/tele/sonoff/STATE = {"Time":"2019-09-02T21:13:22","Epoch":1567455202,"Uptime":"0T00:19:12","UptimeSec":1152,"Vcc":3.042,"Heap":28,"SleepMode":"Dynamic","Sleep":50,"LoadAvg":19,"MqttCount":1,"Wifi":{"AP":1,"SSId":"WLANI","BSSId":"24:65:11:C7:0B:EC","Channel":1,"RSSI":76,"LinkCount":1,"Downtime":"0T00:00:04","DeepSleep":60,"Heap":29632}}
21:13:22 MQT: SmartHome/tele/sonoff/SENSOR = {"Time":"2019-09-02T21:13:22","Epoch":1567455202,"DS18B20":{"Temperature":20.8},"TempUnit":"C"}
21:13:32 MQT: SmartHome/tele/sonoff/STATE = {"Time":"2019-09-02T21:13:32","Epoch":1567455212,"Uptime":"0T00:19:22","UptimeSec":1162,"Vcc":3.043,"Heap":28,"SleepMode":"Dynamic","Sleep":50,"LoadAvg":19,"MqttCount":1,"Wifi":{"AP":1,"SSId":"WLANI","BSSId":"24:65:11:C7:0B:EC","Channel":1,"RSSI":76,"LinkCount":1,"Downtime":"0T00:00:04","DeepSleep":60,"Heap":29632}}
21:13:32 MQT: SmartHome/tele/sonoff/SENSOR = {"Time":"2019-09-02T21:13:32","Epoch":1567455212,"DS18B20":{"Temperature":20.1},"TempUnit":"C"}
21:13:42 MQT: SmartHome/tele/sonoff/STATE = {"Time":"2019-09-02T21:13:42","Epoch":1567455222,"Uptime":"0T00:19:32","UptimeSec":1172,"Vcc":3.041,"Heap":28,"SleepMode":"Dynamic","Sleep":50,"LoadAvg":19,"MqttCount":1,"Wifi":{"AP":1,"SSId":"WLANI","BSSId":"24:65:11:C7:0B:EC","Channel":1,"RSSI":76,"LinkCount":1,"Downtime":"0T00:00:04","DeepSleep":60,"Heap":29632}}
21:13:42 MQT: SmartHome/tele/sonoff/SENSOR = {"Time":"2019-09-02T21:13:42","Epoch":1567455222,"DS18B20":{"Temperature":20.8},"TempUnit":"C"}
21:13:52 MQT: SmartHome/tele/sonoff/STATE = {"Time":"2019-09-02T21:13:52","Epoch":1567455232,"Uptime":"0T00:19:42","UptimeSec":1182,"Vcc":3.043,"Heap":28,"SleepMode":"Dynamic","Sleep":50,"LoadAvg":24,"MqttCount":1,"Wifi":{"AP":1,"SSId":"WLANI","BSSId":"24:65:11:C7:0B:EC","Channel":1,"RSSI":78,"LinkCount":1,"Downtime":"0T00:00:04","DeepSleep":60,"Heap":29632}}
21:13:52 MQT: SmartHome/tele/sonoff/SENSOR = {"Time":"2019-09-02T21:13:52","Epoch":1567455232,"DS18B20":{"Temperature":20.2},"TempUnit":"C"}
21:14:02 MQT: SmartHome/tele/sonoff/STATE = {"Time":"2019-09-02T21:14:02","Epoch":1567455242,"Uptime":"0T00:19:52","UptimeSec":1192,"Vcc":3.043,"Heap":28,"SleepMode":"Dynamic","Sleep":50,"LoadAvg":19,"MqttCount":1,"Wifi":{"AP":1,"SSId":"WLANI","BSSId":"24:65:11:C7:0B:EC","Channel":1,"RSSI":78,"LinkCount":1,"Downtime":"0T00:00:04","DeepSleep":60,"Heap":29632}}
21:14:02 MQT: SmartHome/tele/sonoff/SENSOR = {"Time":"2019-09-02T21:14:02","Epoch":1567455242,"DS18B20":{"Temperature":20.1},"TempUnit":"C"}
21:14:12 MQT: SmartHome/tele/sonoff/STATE = {"Time":"2019-09-02T21:14:12","Epoch":1567455252,"Uptime":"0T00:20:02","UptimeSec":1202,"Vcc":3.041,"Heap":28,"SleepMode":"Dynamic","Sleep":50,"LoadAvg":19,"MqttCount":1,"Wifi":{"AP":1,"SSId":"WLANI","BSSId":"24:65:11:C7:0B:EC","Channel":1,"RSSI":80,"LinkCount":1,"Downtime":"0T00:00:04","DeepSleep":60,"Heap":29632}}
21:14:12 MQT: SmartHome/tele/sonoff/SENSOR = {"Time":"2019-09-02T21:14:12","Epoch":1567455252,"DS18B20":{"Temperature":20.9},"TempUnit":"C"}
21:14:22 MQT: SmartHome/tele/sonoff/STATE = {"Time":"2019-09-02T21:14:22","Epoch":1567455262,"Uptime":"0T00:20:12","UptimeSec":1212,"Vcc":3.041,"Heap":28,"SleepMode":"Dynamic","Sleep":50,"LoadAvg":19,"MqttCount":1,"Wifi":{"AP":1,"SSId":"WLANI","BSSId":"24:65:11:C7:0B:EC","Channel":1,"RSSI":76,"LinkCount":1,"Downtime":"0T00:00:04","DeepSleep":60,"Heap":29632}}
21:14:22 MQT: SmartHome/tele/sonoff/SENSOR = {"Time":"2019-09-02T21:14:22","Epoch":1567455262,"DS18B20":{"Temperature":20.8},"TempUnit":"C"}
21:14:32 MQT: SmartHome/tele/sonoff/STATE = {"Time":"2019-09-02T21:14:32","Epoch":1567455272,"Uptime":"0T00:20:22","UptimeSec":1222,"Vcc":3.041,"Heap":28,"SleepMode":"Dynamic","Sleep":50,"LoadAvg":19,"MqttCount":1,"Wifi":{"AP":1,"SSId":"WLANI","BSSId":"24:65:11:C7:0B:EC","Channel":1,"RSSI":76,"LinkCount":1,"Downtime":"0T00:00:04","DeepSleep":60,"Heap":29632}}
21:14:32 MQT: SmartHome/tele/sonoff/SENSOR = {"Time":"2019-09-02T21:14:32","Epoch":1567455272,"DS18B20":{"Temperature":20.8},"TempUnit":"C"}
21:14:42 MQT: SmartHome/tele/sonoff/STATE = {"Time":"2019-09-02T21:14:42","Epoch":1567455282,"Uptime":"0T00:20:32","UptimeSec":1232,"Vcc":3.041,"Heap":28,"SleepMode":"Dynamic","Sleep":50,"LoadAvg":19,"MqttCount":1,"Wifi":{"AP":1,"SSId":"WLANI","BSSId":"24:65:11:C7:0B:EC","Channel":1,"RSSI":76,"LinkCount":1,"Downtime":"0T00:00:04","DeepSleep":60,"Heap":29632}}
21:14:42 MQT: SmartHome/tele/sonoff/SENSOR = {"Time":"2019-09-02T21:14:42","Epoch":1567455282,"DS18B20":{"Temperature":20.8},"TempUnit":"C"}

I can't see that the deepsleep mode was active.

Must i connect GPIO 16 with RST ? Or is it enough to put the GPIO16 on deeplseep?

stefanbode commented 5 years ago

Here is an example of how it should look like. GPIO16 and RST must be connected for the wakeup. Otherwhise your device will sleep very very long... Anyhow your problem is, that is does not go into deepsleep. Can you set seriallog 5. maybe we see more information. MQTT must be up. but this is your case.

;l␀d��|␀�$�|␃␄␌␄�␌d�␄c|ǃ␂�␛�{�c�␌b��og�l'o���␌#␜x��${l{$p�'�␘␃␄␌�␄l␄��␄␌␄c␄o�<␃l�␄␌�c��gn�␀d��d`␃�␛␒'o␌d`␃␎␃gs���o␌␄b␄�␏$␏r��g␄␌c␄�␇l�␃�␃dl�␛�d`␃��o�␃
00:00:00 CFG: Loaded from flash at 3F5, Count 87
00:00:00 SRC: Restart
00:00:00 Project sonoff Sonoff Version 6.6.0.3 stb-1.9(sonoff)-2_5_2
00:00:00 WIF: Checking connection...
00:00:00 WIF: Attempting connection...
00:00:00 WIF: Connecting to AP1 BodeNet_Keller in mode 11N as sonoff-4288...
00:00:01 WIF: Checking connection...
00:00:01 WIF: Attempting connection...
00:00:02 WIF: Checking connection...
00:00:08 WIF: Connected
00:00:08 HTP: Web server active on sonoff-4288 with IP address 192.168.178.106
22:14:53 NTP: Drift 0, (UTC) Mon Sep 02 20:14:53 2019, (DST) Sun Mar 31 02:00:00 2019, (STD) Sun Oct 27 03:00:00 2019
22:14:54 MQT: Attempting connection...
22:14:54 MQT: TLS connected in 359 ms, max ThunkStack used 2532
22:14:54 MQT: MFLN not supported by TLS server
22:14:54 MQT: Server fingerprint: 4E 8C 9C BC 6F 2D 4A B4 9D 4F 68 4C 67 FE DC EB 02 7C 4C C3
22:14:54 MQT: Connected
22:14:54 MQT: hm/status/sonoff/LWT = Online (retained)
22:14:54 MQT: hm/setting/sonoff/POWER =
22:14:54 MQT: Subscribe to hm/setting/sonoff/#
22:14:54 MQT: Subscribe to hm/setting/sonoffs/#
22:14:54 MQT: Received Topic hm/setting/sonoff/power1, Data Size 3, Data off
22:14:54 SRC: MQTT
22:14:54 CMD: Group 0, Index 1, Command "POWER", Data "off"
22:14:54 MQT: hm/status/sonoff/RESULT = {"POWER1":"OFF"}
22:14:54 MQT: hm/status/sonoff/POWER1 = OFF (retained)
22:14:54 MQT: Subscribe to cmnd/DVES_1EF0C0_fb/#
22:14:54 MQT: hm/status/sonoff/INFO1 = {"Module":"Generic","Version":"6.6.0.3 stb-1.9(sonoff)","FallbackTopic":"cmnd/DVES_1EF0C0_fb/","GroupTopic":"sonoff
s"}
22:14:54 MQT: hm/status/sonoff/INFO2 = {"WebServerMode":"Admin","Hostname":"sonoff-4288","IPAddress":"192.168.178.106"}
22:14:54 MQT: hm/status/sonoff/INFO3 = {"RestartReason":"External System"}
22:14:54 MQT: hm/status/sonoff/RESULT = {"POWER1":"OFF"}
22:14:54 MQT: hm/status/sonoff/POWER1 = OFF (retained)
22:14:54 MQT: hm/status/sonoff/RESULT = {"POWER2":"OFF"}
22:14:54 MQT: hm/status/sonoff/POWER2 = OFF (retained)
22:14:54 APP: Boot Count 24
22:14:54 CFG: Saved to flash at 3F4, Count 88, Bytes 3824
22:15:03 MQT: hm/status/sonoff/STATE = {"Time":"2019-09-02T22:15:03","Epoch":1567455303,"Uptime":"0T00:00:19","UptimeSec":19,"Heap":24,"SleepMode":"Dynamic
","Sleep":50,"LoadAvg":34,"MqttCount":1,"POWER1":"OFF","POWER2":"OFF","Wifi":{"AP":1,"SSId":"BodeNet_Keller","BSSId":"7C:FF:4D:3D:A3:5B","Channel":11,"RSSI
":84,"LinkCount":1,"Downtime":"0T00:00:08","DeepSleep":30,"Heap":25376}}
22:15:03 MQT: hm/status/sonoff/SENSOR = {"Time":"2019-09-02T22:15:03","Epoch":1567455303,"ANALOG":{"A0":8}}
22:15:03 MQT: hm/status/sonoff/LWT = Offline
22:15:03 nextwakeup 0

stefanbode commented 5 years ago

Ahh I see the mistake. DO NOT SET GPIO16 to DEEPSLEEP !!

This is for the easy wakeup.

stefanbode commented 5 years ago

The DEEPSLEEP pin (preferred GPIO16) is to PREVENT deepsleep with a small switch without reconfigure the device.

hermann1514 commented 5 years ago

But i must connect the GPIO16 with RST - right?

stefanbode commented 5 years ago

Yes. Best directly with a wire to have a wakeup. GPIO16 is sending a HIGH to RST (Reset) that then trigggers the wakeup.

hermann1514 commented 5 years ago

OK. Now i have connected the GPIO16 with RST and the deepsleep mode is working. Now i will check if mqtt is working when the device is wakeup. But one question: When i set deepsleep 60 - then the wemos goes offline after 60 seconds - go online. After which time the wemos is going offline after that?

thomas-lentz commented 5 years ago

Hi Stefan, I guess it would be time for a Wiki Page about the timing ;-)

I checked the fix. Unfortunately it didn't work. When I exchange the sonoff.ino for an old one it works...

Could it be that the prerequisites for deepsleep changed? I can see that UtcTime() is used now, does this mean there has to be a ntp sync before? I didn't want to go through all the code. Also it seems that global_state.mqtt_down is evaluated - does this version need mandatory a configured MQTT server to have deepsleep working?

thomas-lentz commented 5 years ago

@hermann1514 look at #174 - Stefan already answered this, when I had the same question.

stefanbode commented 5 years ago

Hi @thomas-lentz yes I changed some prerequisites to ensure that data is send during wakeuptime. The roundtrip through all takes between 6-10 seconds (4-8 seconds to establish wifi). I changes behavior because a measurement WITHOUT sending the data to MQTT does not make sense. Also I think it is a good advise to have a correct time sending with the data. Therefore all these checks. Please can you give it a try with the following settings: ntpserver1: ip of your local router teleperiod 5 deepsleep 30

Depending on wificonnect the online time will b something about ~7sec.

stefanbode commented 5 years ago

Updated the wiki: https://github.com/stefanbode/Sonoff-Tasmota/wiki/Deepsleep Please take a look at "General timing..."

hermann1514 commented 5 years ago

Hey Stefan, great work. Thanks for that. it works for me now.

thomas-lentz commented 5 years ago

Hi Stefan, could it be, that in when under some circumstances the device gets WLAN (after a while), but no NTP time, the device gets back to sleep and will never wake up? Here is the log:

00:00:29 MQT: Connected
00:00:29 MQT: tele/room/LWT = Online (retained)
00:00:29 MQT: cmnd/room/POWER = 
00:00:29 RSL: tele/room/INFO1 = {"Module":"WEMOS","Version":"6.6.0.3 stb-1.9(sonoff)","FallbackTopic":"cmnd/room_fb/","GroupTopic":"iot-devs"}
00:00:29 MQT: tele/room/INFO2 = {"WebServerMode":"Admin","Hostname":"mydevice","IPAddress":"192.168.0.74"}
00:00:29 MQT: tele/room/INFO3 = {"RestartReason":"Deep-Sleep Wake"}
00:00:29 MQT: stat/room/RESULT = {"POWER":"ON"}
00:00:29 MQT: stat/room/POWER = ON
00:00:47 RSL: tele/room/STATE = {"Time":"1970-01-01T00:00:47","Epoch":47,"Uptime":"0T00:00:47","UptimeSec":47,"Heap":23,"SleepMode":"Dynamic","Sleep":50,"LoadAvg":19,"MqttCount":1,"POWER":"ON","Wifi":{"AP":1,"SSId":"MyNet","BSSId":"XX:XX:XX:XX:2C:01","Channel":1,"RSSI":74,"LinkCount":1,"Downtime":"0T00:00:27","DeepSleep":40,"Heap":24448}}
00:00:47 RSL: tele/room/SENSOR = {"Time":"1970-01-01T00:00:47","Epoch":47,"DS18B20":{"Temperature":26.9},"BME280":{"Temperature":27.7,"Humidity":25.3,"Pressure":1008.4},"PressureUnit":"hPa","TempUnit":"C"}
00:00:47 MQT: stat/room/RESULT = {"POWER":"OFF"}
00:00:47 MQT: stat/room/POWER = OFF
00:00:47 MQT: tele/room/LWT = Offline

The device won't wake up after that... You can see that time is (still) set to 1970-01-01T00:00:47, when the device goes to sleep. TelePeriod: 20 DeepSleep: 40

Another idea could also be, that there is a problem when the new (absolute) Wakeuptime, after Deepsleep seconds after the previous WakeUp, falls into the "still awake" time of the this previous WakeUp period.

hermann1514 commented 5 years ago

Hi, i have the same Problem. Sometime the Device never wakes up. Power Off wait and Power On helps. But after a few hours the Device is "dead"

thomas-lentz commented 5 years ago

Okay, I'm glad I'm not the only one experiencing this problem. Reset also helps. I guess it has something to do with the absolute time now coming into play. If this is not set by NTP, it probably calculates the sleep period wrong - but that is only a guess. To analyze this, it would really take a day or two and I've got to finish the sensor before I leave for the holiday (and install it there).

stefanbode commented 5 years ago

Yes, this is correct. I got some trouble with negative values on unsigned int variables. A new current version is already in final testing.

hermann1514 commented 5 years ago

I still have the problem that the WEMOS does not wake up again.

stefanbode commented 5 years ago

this is very strange. I have no more issues at my side. D0 and RST are connected? So it wake up most times but not all times. Correct? Can you send some log files. Maybe from syslog or from serial

hermann1514 commented 5 years ago

The latest Message was: {"Time":"1970-01-01T00:00:20","Epoch":20,"DS18B20":{"Temperature":20.12},"TempUnit":"C"}

Time Problem?

stefanbode commented 5 years ago

Thanks this is a good hint. I will check what it calculates if there is no timeserver reporting a correct time

stefanbode commented 5 years ago

Yes, your guess was absolutely correct. if the time was not gathered correctly this causes the system to do a deepsleep 0 which in the end is = endless. My current assumption on the new code is that this now never can happen again.

thomas-lentz commented 5 years ago

Hi Stefan, I wanted to test your new version, but it seems that MQTT is not working anymore for the SENSOR and STATE topic:

00:00:00 CFG: Loaded from flash at FF9, Count 3
00:00:00 Project sonoff Sonoff Version 6.6.0.10 stb-1.11(sonoff)-2_5_0
00:00:00 WIF: Connecting to AP1 myWIFI in mode 11N as sonoff-7689...
00:00:01 CMD: deepsleep 0
00:00:01 RSL: stat/sonoff/RESULT = {"DeepSleep":0}
00:00:09 WIF: Connected
00:00:09 HTP: Web server active on sonoff-7689 with IP address 192.168.168.168
20:28:19 MQT: Attempting connection...
20:28:19 MQT: Connected
20:28:19 MQT: tele/sonoff/LWT = Online (retained)
20:28:19 MQT: cmnd/sonoff/POWER = 
20:28:19 RSL: tele/sonoff/INFO1 = {"Module":"Sonoff Basic","Version":"6.6.0.10 stb-1.11(sonoff)","FallbackTopic":"cmnd/DVES_475E09_fb/","GroupTopic":"sonoffs"}
20:28:19 MQT: tele/sonoff/INFO2 = {"WebServerMode":"Admin","Hostname":"sonoff-7689","IPAddress":"192.168.168.168"}
20:28:19 MQT: tele/sonoff/INFO3 = {"RestartReason":"Software/System restart"}
20:28:19 MQT: stat/sonoff/RESULT = {"POWER":"ON"}
20:28:19 MQT: stat/sonoff/POWER = ON
20:28:27 RSL: tele/sonoff/STATE = {"Time":"2019-09-08T20:28:27","Epoch":1567970907,"Uptime":"0T00:00:19","UptimeSec":19,"Heap":23,"SleepMode":"Dynamic","Sleep":50,"LoadAvg":19,"MqttCount":1,"POWER":"ON","Wifi":{"AP":1,"SSId":"myWIFI","BSSId":"18:4B:0D:63:5E:C8","Channel":7,"RSSI":48,"LinkCount":1,"Downtime":"0T00:00:09","DeepSleep":0,"Heap":24176}}
20:33:27 RSL: tele/sonoff/STATE = {"Time":"2019-09-08T20:33:27","Epoch":1567971207,"Uptime":"0T00:05:19","UptimeSec":319,"Heap":23,"SleepMode":"Dynamic","Sleep":50,"LoadAvg":19,"MqttCount":1,"POWER":"ON","Wifi":{"AP":1,"SSId":"myWIFI","BSSId":"11:22:33:44:55:66","Channel":7,"RSSI":48,"LinkCount":1,"Downtime":"0T00:00:09","DeepSleep":0,"Heap":24176}}

As you can see MQTT server is connected, everything is fine and and some data is sent via MQTT but STATE is shown as RSL. I narrowed it down for Sensordata. As long as only one Sensor date (e.g. "temperature" or "analog") is configured, it is transmitted via MQTT. The moment I configure them both it is not MQTT anymore, but RSL. Is this a length problem?

Only one sensor:

21:09:06 RSL: tele/sonoff/STATE = {"Time":"2019-09-08T21:09:06","Epoch":1567973346,"Uptime":"0T00:06:15","UptimeSec":375,"Heap":21,"SleepMode":"Dynamic","Sleep":50,"LoadAvg":19,"MqttCount":1,"Wifi":{"AP":1,"SSId":"myWIFI","BSSId":"11:22:33:44:55:66","Channel":7,"RSSI":100,"LinkCount":1,"Downtime":"0T00:00:05","DeepSleep":0,"Heap":21904}}
21:09:06 MQT: tele/sonoff/SENSOR = {"Time":"2019-09-08T21:09:06","Epoch":1567973346,"DS18B20":{"Temperature":24.2},"TempUnit":"C"}

Two Sensors:

21:10:32 RSL: tele/sonoff/STATE = {"Time":"2019-09-08T21:10:32","Epoch":1567973432,"Uptime":"0T00:00:38","UptimeSec":38,"Heap":21,"SleepMode":"Dynamic","Sleep":50,"LoadAvg":23,"MqttCount":1,"Wifi":{"AP":1,"SSId":"myWIFI","BSSId":"11:22:33:44:55:66","Channel":7,"RSSI":100,"LinkCount":1,"Downtime":"0T00:00:08","DeepSleep":0,"Heap":22288}}
21:10:32 RSL: tele/sonoff/SENSOR = {"Time":"2019-09-08T21:10:32","Epoch":1567973432,"ANALOG":{"A0":631},"DS18B20":{"Temperature":24.2},"TempUnit":"C"}

It is compiled from your newest #181 fix source (8.9.2019). I tried with core 2.5.0 & 2.5.2

stefanbode commented 5 years ago

Hmm, i do no5 see this at my devices. And my messages are for sure longer than yours. I‘m not aware on any changes that could effect this. I assume sensor is working without the deepsleep.

stefanbode commented 5 years ago

Why is your state message RSL. This is MQTT on my side. I use the TLS version, enabled in my-config, but unlikely this make a change.

stefanbode commented 5 years ago

I just went through your log and yes all messages a bit longer are RSL and not mqtt. This will give a hint to a length problem. Maybe you search in the original tasmota for hints. Because STATE is also effected like INFO1 you should not be the first one.

stefanbode commented 5 years ago

https://github.com/arendst/Sonoff-Tasmota/issues/2342

This looks very similar to yours

thomas-lentz commented 5 years ago

Yes in fact it was the same problem and I spent my night to solve it. I already posted it in the other thread, but just to not leave this "issue" here open, I repost it:

The problem is an old "PubSubClient-EspEasy". It has to be the "PubSubClient-EspEasy-2.7.12" or newer. In my case there were the correct and the older library in the path - guess which one was taken (yes, I know there have been warnings from the compiler ...).

A 128 characters are by far not enough! These are the problematic lines:

// MQTT_MAX_PACKET_SIZE : Maximum packet size
#ifndef MQTT_MAX_PACKET_SIZE
#define MQTT_MAX_PACKET_SIZE 128
#endif

So if you have the "RSL:" instead of "MQT:" check the version of your "PubSubClient-EspEasy".

stefanbode / Sonoff-Tasmota