search

letscontrolit / ESPEasy

Easy MultiSensor device based on ESP8266/ESP32
http://www.espeasy.com
Other
3.28k stars 2.22k forks source link

After Deepsleep MQTT publish failed #1097

Closed DittelHome closed 6 years ago

DittelHome commented 6 years ago

Steps to reproduce

How can we trigger this problem? Define at least 4 tasks, which report there values via MQTT to the broker. After Deepsleep some values cannot be published to the broker.

Does the problem persists after powering off and on? (just resetting isn't enough sometimes) Yes

Expected behavior

Tell us what should happen? After Deepsleep all values from all defined/configured task should be published to the broker.

Actual behavior

Tell us what happens instead? Some values cannot be published (humidity from DHT22 and WLAN-RSSI form system) syslog wiht deepsleep:

Mar 16 05:50:36 Heizoeltank EspEasy: NTP  : NTP send to 12.167.151.1
Mar 16 05:50:36 Heizoeltank EspEasy: NTP  : NTP replied: 109 mSec
Mar 16 05:50:36 Heizoeltank EspEasy: Current Time Zone:  DST time start: 2018-03-25 02:00:00 offset: 120 minSTD time start: 2018-10-28 03:00:00 offset: 60 min
Mar 16 05:50:36 Heizoeltank EspEasy: WIFI : Connected! IP: 192.168.1.12 (Heizoeltank_2)
Mar 16 05:50:36 Heizoeltank EspEasy: NTP  : NTP send to 12.167.151.1
Mar 16 05:50:36 Heizoeltank EspEasy: NTP  : NTP replied: 107 mSec
Mar 16 05:50:36 Heizoeltank EspEasy: Memtrace#0120: lowest: 14392  CPluginCallADD (9)-> 17336 CPluginCallADD (10)-> 17304 CPluginCallADD (11)-> 17288 CPluginCallADD (12)-> 17272 addLog-> 17640 PluginCall_s (12)-> 14432 PluginCall_s (1)-> 14432 PluginCall_s (4)-> 14432 Pl
Mar 16 05:50:36 Heizoeltank EspEasy: 1: lowest: 14432  CPluginCallADD (2)-> 17640 CPluginCallADD (3)-> 17592 CPluginCallADD (4)-> 17560 CPluginCallADD (5)-> 17512 CPluginCallADD (6)-> 17480 CPluginCallADD (7)-> 17432 CPluginCallADD (8)-> 17384 CPluginCallADD (9)-> 173
Mar 16 05:50:36 Heizoeltank EspEasy: 2: lowest: 14432  CPluginCallADD (0)-> 17704 CPluginCallADD (1)-> 17672 CPluginCallADD (2)-> 17640 CPluginCallADD (3)-> 17592 CPluginCallADD (4)-> 17560 CPluginCallADD (5)-> 17512 CPluginCallADD (6)-> 17480 CPluginCallADD (7)-> 174
Mar 16 05:50:36 Heizoeltank EspEasy: WD   : Uptime 0 ConnectFailures 0 FreeMem 13632
Mar 16 05:50:36 Heizoeltank EspEasy: MQTT : Intentional reconnect
Mar 16 05:50:36 Heizoeltank EspEasy: MQTT : Connected to broker with client ID: ESPClient_5C:CF:7F:1B:A9:89
Mar 16 05:50:36 Heizoeltank EspEasy: Subscribed to: /Tankraum/#
Mar 16 05:50:36 Heizoeltank EspEasy: SR04 : Distance: 82.45
Mar 16 05:50:36 Heizoeltank EspEasy: ADC  : Analog value: 697
Mar 16 05:50:38 Heizoeltank EspEasy: DHT  : Temperature: 14.20
Mar 16 05:50:38 Heizoeltank EspEasy: DHT  : Humidity: 56.30
Mar 16 05:50:44 Heizoeltank EspEasy: MQTT : publish failed
Mar 16 05:50:49 Heizoeltank EspEasy: MQTT : publish failed
Mar 16 05:50:49 Heizoeltank EspEasy: SYS  : -82.00
Mar 16 05:50:56 Heizoeltank EspEasy: MQTT : publish failed
Mar 16 05:50:56 Heizoeltank EspEasy: Memtrace#0120: lowest: 10944  LoadTaskSettings-> 14120 LoadTaskSettings-> 14456 LoadControllerSettings-> 14456 LoadFromFile-> 14472 addLog-> 12768 addLog-> 11168 PluginCall_s (12)-> 10968 PluginCall_s (1)-> 10968 PluginCall_s (4)-> 10
Mar 16 05:50:56 Heizoeltank EspEasy: 1: lowest: 10928  LoadTaskSettings-> 14456 LoadControllerSettings-> 14456 LoadFromFile-> 14472 addLog-> 12768 addLog-> 11168 PluginCall_s (12)-> 10968 PluginCall_s (1)-> 10968 PluginCall_s (4)-> 10968 PluginCall_s (25)-> 10968 Sens
Mar 16 05:50:56 Heizoeltank EspEasy: 2: lowest: 10968  PluginCall_s (25)-> 14336 SensorSendTask-> 14544 LoadTaskSettings-> 14528 LoadFromFile-> 14520 PluginCall_init (4)-> 14336 Calculate-> 14064 Calculate2-> 14064 sendData-> 14136 LoadTaskSettings-> 14120 LoadTaskSet
Mar 16 05:50:56 Heizoeltank EspEasy: WD   : Uptime 1 ConnectFailures 0 FreeMem 10240
Mar 16 05:50:56 Heizoeltank EspEasy: SR04 : Distance: 82.45
Mar 16 05:51:02 Heizoeltank EspEasy: MQTT : publish failed
Mar 16 05:51:02 Heizoeltank EspEasy: ADC  : Analog value: 690
Mar 16 05:51:09 Heizoeltank EspEasy: MQTT : publish failed
Mar 16 05:51:09 Heizoeltank EspEasy: DHT  : Temperature: 14.20
Mar 16 05:51:09 Heizoeltank EspEasy: DHT  : Humidity: 56.30
Mar 16 05:51:15 Heizoeltank EspEasy: MQTT : publish failed
Mar 16 05:51:20 Heizoeltank EspEasy: MQTT : publish failed
Mar 16 05:51:20 Heizoeltank EspEasy: SYS  : -83.00
Mar 16 05:51:27 Heizoeltank EspEasy: MQTT : publish failed
Mar 16 05:51:27 Heizoeltank EspEasy: Memtrace#0120: lowest: 10000  PluginCall_s (25)-> 11040 PluginCall_s (12)-> 11040 PluginCall_s (1)-> 11040 PluginCall_s (4)-> 11040 PluginCall_s (25)-> 11040 PluginCall_s (12)-> 11040 PluginCall_s (1)-> 11040 PluginCall_s (4)-> 11040 
Mar 16 05:51:27 Heizoeltank EspEasy: 1: lowest: 10008  PluginCall_s (4)-> 11040 PluginCall_s (25)-> 11040 PluginCall_s (12)-> 11040 PluginCall_s (1)-> 11040 PluginCall_s (4)-> 11040 PluginCall_s (25)-> 11040 PluginCall_s (12)-> 11040 PluginCall_s (1)-> 11040 PluginCal
Mar 16 05:51:27 Heizoeltank EspEasy: 2: lowest: 10024  PluginCall_s (12)-> 11040 PluginCall_s (1)-> 11040 PluginCall_s (4)-> 11040 PluginCall_s (25)-> 11040 PluginCall_s (12)-> 11040 PluginCall_s (1)-> 11040 PluginCall_s (4)-> 11040 PluginCall_s (25)-> 11040 PluginCal
Mar 16 05:51:27 Heizoeltank EspEasy: WD   : Uptime 1 ConnectFailures 0 FreeMem 10240
Mar 16 05:51:27 Heizoeltank EspEasy: SR04 : Distance: 82.41
Mar 16 05:51:33 Heizoeltank EspEasy: MQTT : publish failed
Mar 16 05:51:33 Heizoeltank EspEasy: ADC  : Analog value: 688
Mar 16 05:51:40 Heizoeltank EspEasy: MQTT : publish failed
Mar 16 05:51:40 Heizoeltank EspEasy: DHT  : Temperature: 14.20
Mar 16 05:51:40 Heizoeltank EspEasy: DHT  : Humidity: 56.30
Mar 16 05:51:46 Heizoeltank EspEasy: MQTT : publish failed
Mar 16 05:51:51 Heizoeltank EspEasy: MQTT : publish failed
Mar 16 05:51:51 Heizoeltank EspEasy: SYS  : -83.00
Mar 16 05:51:58 Heizoeltank EspEasy: MQTT : publish failed
Mar 16 05:51:58 Heizoeltank EspEasy: Memtrace#0120: lowest: 10000  PluginCall_s (25)-> 11040 PluginCall_s (12)-> 11040 PluginCall_s (1)-> 11040 PluginCall_s (4)-> 11040 PluginCall_s (25)-> 11040 PluginCall_s (12)-> 11040 PluginCall_s (1)-> 11040 PluginCall_s (4)-> 11040 
Mar 16 05:51:58 Heizoeltank EspEasy: 1: lowest: 10008  PluginCall_s (4)-> 11040 PluginCall_s (25)-> 11040 PluginCall_s (12)-> 11040 PluginCall_s (1)-> 11040 PluginCall_s (4)-> 11040 PluginCall_s (25)-> 11040 PluginCall_s (12)-> 11040 PluginCall_s (1)-> 11040 PluginCal
Mar 16 05:51:58 Heizoeltank EspEasy: 2: lowest: 10024  PluginCall_s (12)-> 11040 PluginCall_s (1)-> 11040 PluginCall_s (4)-> 11040 PluginCall_s (25)-> 11040 PluginCall_s (12)-> 11040 PluginCall_s (1)-> 11040 PluginCall_s (4)-> 11040 PluginCall_s (25)-> 11040 PluginCal
Mar 16 05:51:58 Heizoeltank EspEasy: WD   : Uptime 2 ConnectFailures 0 FreeMem 10240
Mar 16 05:51:58 Heizoeltank EspEasy: SR04 : Distance: 82.41
Mar 16 05:52:04 Heizoeltank EspEasy: MQTT : publish failed
Mar 16 05:52:04 Heizoeltank EspEasy: ADC  : Analog value: 693
Mar 16 05:52:11 Heizoeltank EspEasy: MQTT : publish failed
Mar 16 05:52:11 Heizoeltank EspEasy: DHT  : Temperature: 14.20
Mar 16 05:52:11 Heizoeltank EspEasy: DHT  : Humidity: 56.30
Mar 16 05:52:17 Heizoeltank EspEasy: MQTT : publish failed
Mar 16 05:52:22 Heizoeltank EspEasy: MQTT : publish failed
Mar 16 05:52:22 Heizoeltank EspEasy: SYS  : -83.00
Mar 16 05:52:29 Heizoeltank EspEasy: MQTT : publish failed
Mar 16 05:52:29 Heizoeltank EspEasy: Memtrace#0120: lowest: 10000  PluginCall_s (25)-> 11040 PluginCall_s (12)-> 11040 PluginCall_s (1)-> 11040 PluginCall_s (4)-> 11040 PluginCall_s (25)-> 11040 PluginCall_s (12)-> 11040 PluginCall_s (1)-> 11040 PluginCall_s (4)-> 11040 
Mar 16 05:52:29 Heizoeltank EspEasy: 1: lowest: 10000  PluginCall_s (25)-> 11040 PluginCall_s (12)-> 11208 PluginCall_s (1)-> 11208 PluginCall_s (4)-> 11208 PluginCall_s (25)-> 11208 PluginCall_s (12)-> 11208 PluginCall_s (1)-> 11208 PluginCall_s (4)-> 11208 PluginCal
Mar 16 05:52:29 Heizoeltank EspEasy: 2: lowest: 10008  PluginCall_s (4)-> 11040 PluginCall_s (25)-> 11040 PluginCall_s (12)-> 11208 PluginCall_s (1)-> 11208 PluginCall_s (4)-> 11208 PluginCall_s (25)-> 11208 PluginCall_s (12)-> 11208 PluginCall_s (1)-> 11208 PluginCal
Mar 16 05:52:29 Heizoeltank EspEasy: WD   : Uptime 2 ConnectFailures 0 FreeMem 10240
Mar 16 05:52:29 Heizoeltank EspEasy: SR04 : Distance: 82.02
Mar 16 05:52:36 Heizoeltank EspEasy: MQTT : publish failed
Mar 16 05:52:36 Heizoeltank EspEasy: ADC  : Analog value: 691
Mar 16 05:52:42 Heizoeltank EspEasy: MQTT : publish failed
Mar 16 05:52:42 Heizoeltank EspEasy: DHT  : Temperature: 14.20
Mar 16 05:52:42 Heizoeltank EspEasy: DHT  : Humidity: 56.30
Mar 16 05:52:49 Heizoeltank EspEasy: MQTT : publish failed
Mar 16 05:52:54 Heizoeltank EspEasy: MQTT : publish failed
Mar 16 05:52:54 Heizoeltank EspEasy: SYS  : -83.00
Mar 16 05:53:00 Heizoeltank EspEasy: MQTT : publish failed

If i start the ESP without deepsleep, all values will be published. syslog without deepsleep:

Mar 16 06:13:37 Heizoeltank EspEasy: NTP  : NTP send to 118.140.184.98
Mar 16 06:13:38 Heizoeltank EspEasy: NTP  : NTP replied: 508 mSec
Mar 16 06:13:38 Heizoeltank EspEasy: Memtrace#0120: lowest: 10944  LoadTaskSettings-> 14120 LoadTaskSettings-> 14456 LoadControllerSettings-> 14456 LoadFromFile-> 14472 addLog-> 12768 addLog-> 11168 PluginCall_s (12)-> 10968 PluginCall_s (1)-> 10968 PluginCall_s (4)-> 10
Mar 16 06:13:38 Heizoeltank EspEasy: 1: lowest: 10928  LoadTaskSettings-> 14456 LoadControllerSettings-> 14456 LoadFromFile-> 14472 addLog-> 12768 addLog-> 11168 PluginCall_s (12)-> 10968 PluginCall_s (1)-> 10968 PluginCall_s (4)-> 10968 PluginCall_s (25)-> 10968 Sens
Mar 16 06:13:38 Heizoeltank EspEasy: 2: lowest: 10968  PluginCall_s (25)-> 14336 SensorSendTask-> 14544 LoadTaskSettings-> 14528 LoadFromFile-> 14520 PluginCall_init (4)-> 14336 Calculate-> 14064 Calculate2-> 14064 sendData-> 14136 LoadTaskSettings-> 14120 LoadTaskSet
Mar 16 06:13:38 Heizoeltank EspEasy: WD   : Uptime 1 ConnectFailures 1 FreeMem 13304
Mar 16 06:13:38 Heizoeltank EspEasy: SR04 : Distance: 82.43
Mar 16 06:13:38 Heizoeltank EspEasy: ADC  : Analog value: 694
Mar 16 06:13:40 Heizoeltank EspEasy: DHT  : Temperature: 14.30
Mar 16 06:13:40 Heizoeltank EspEasy: DHT  : Humidity: 56.20
Mar 16 06:13:41 Heizoeltank EspEasy: MQTT : Topic: /Tankraum/Distance
Mar 16 06:13:41 Heizoeltank EspEasy: MQTT : Payload: 82
Mar 16 06:13:41 Heizoeltank EspEasy: MQTT : Topic: /Tankraum/Voltage
Mar 16 06:13:41 Heizoeltank EspEasy: MQTT : Payload: 5.25
Mar 16 06:13:42 Heizoeltank EspEasy: MQTT : Topic: /Tankraum/Temperature
Mar 16 06:13:42 Heizoeltank EspEasy: MQTT : Payload: 14.30
Mar 16 06:13:42 Heizoeltank EspEasy: MQTT : Topic: /Tankraum/Humidity
Mar 16 06:13:42 Heizoeltank EspEasy: MQTT : Payload: 53.50
Mar 16 06:13:51 Heizoeltank EspEasy: SYS  : -76.00
Mar 16 06:13:51 Heizoeltank EspEasy: MQTT : Topic: /Tankraum/RSSI
Mar 16 06:13:51 Heizoeltank EspEasy: MQTT : Payload: -76.00
Mar 16 06:14:08 Heizoeltank EspEasy: Memtrace#0120: lowest: 10944  LoadTaskSettings-> 14120 LoadTaskSettings-> 14456 LoadControllerSettings-> 14456 LoadFromFile-> 14472 addLog-> 12768 addLog-> 11168 PluginCall_s (12)-> 10968 PluginCall_s (1)-> 10968 PluginCall_s (4)-> 10
Mar 16 06:14:08 Heizoeltank EspEasy: 1: lowest: 10928  LoadTaskSettings-> 14456 LoadControllerSettings-> 14456 LoadFromFile-> 14472 addLog-> 12768 addLog-> 11168 PluginCall_s (12)-> 10968 PluginCall_s (1)-> 10968 PluginCall_s (4)-> 10968 PluginCall_s (25)-> 10968 Sens
Mar 16 06:14:08 Heizoeltank EspEasy: 2: lowest: 10968  PluginCall_s (25)-> 14336 SensorSendTask-> 14544 LoadTaskSettings-> 14528 LoadFromFile-> 14520 PluginCall_init (4)-> 14336 Calculate-> 14064 Calculate2-> 14064 sendData-> 14136 LoadTaskSettings-> 14120 LoadTaskSet
Mar 16 06:14:08 Heizoeltank EspEasy: WD   : Uptime 2 ConnectFailures 0 FreeMem 13400

At the moment, it is not possible to reach the esp after power off/on. I have to temporary disable Deep Sleep via jumper setting.

System configuration

Hardware: WEMOS mini Four Tasks:

Software or git version: ESPEasy_mega-20180315

TD-er commented 6 years ago

Are these published values done via rules? If so, can you post the rules? Perhaps also just enable the rules, then some events will be logged to see whether connection to MQTT etc is successful

DittelHome commented 6 years ago

Are these published values done via rules?

No, only checkbox "send to controller" is enabled.

Perhaps also just enable the rules, then some events will be logged to see whether connection to MQTT etc is successful

OK, i will report with enabled rules...

DittelHome commented 6 years ago

Ok, syslog with rules enabled:

Mar 16 07:43:55 Heizoeltank EspEasy: SLEEP: Entering deep sleep in 30 seconds.
Mar 16 07:44:25 Heizoeltank EspEasy: EVENT: System#Sleep
Mar 16 07:44:25 Heizoeltank EspEasy: EVENT: System#Sleep Processing time:1 milliSeconds
Mar 16 07:44:25 Heizoeltank EspEasy: SLEEP: Powering down to deepsleep...
Mar 16 07:49:06 Heizoeltank EspEasy: NTP  : NTP send to 129.250.35.251
Mar 16 07:49:06 Heizoeltank EspEasy: NTP  : NTP replied: 21 mSec
Mar 16 07:49:06 Heizoeltank EspEasy: EVENT: Time#Initialized
Mar 16 07:49:06 Heizoeltank EspEasy: EVENT: Time#Initialized Processing time:0 milliSeconds
Mar 16 07:49:06 Heizoeltank EspEasy: Current Time Zone:  DST time start: 2018-03-25 02:00:00 offset: 120 minSTD time start: 2018-10-28 03:00:00 offset: 60 min
Mar 16 07:49:06 Heizoeltank EspEasy: WIFI : Connected! IP: 192.168.1.12 (Heizoeltank_2)
Mar 16 07:49:06 Heizoeltank EspEasy: EVENT: WiFi#Connected
Mar 16 07:49:06 Heizoeltank EspEasy: EVENT: WiFi#Connected Processing time:1 milliSeconds
Mar 16 07:49:06 Heizoeltank EspEasy: NTP  : NTP send to 129.250.35.251
Mar 16 07:49:06 Heizoeltank EspEasy: NTP  : NTP replied: 13 mSec
Mar 16 07:49:06 Heizoeltank EspEasy: EVENT: Time#Set
Mar 16 07:49:06 Heizoeltank EspEasy: EVENT: Time#Set Processing time:1 milliSeconds
Mar 16 07:49:06 Heizoeltank EspEasy: EVENT: System#Boot
Mar 16 07:49:06 Heizoeltank EspEasy: EVENT: System#Boot Processing time:1 milliSeconds
Mar 16 07:49:06 Heizoeltank EspEasy: Memtrace#0120: lowest: 13792  addLog-> 17640 rulesProcessing-> 16920 rulesProcessing-> 16168 rulesProcessing-> 14592 rulesProcessing-> 14240 PluginCall_s (12)-> 13832 PluginCall_s (1)-> 13832 PluginCall_s (4)-> 13832 PluginCall_s (25)
Mar 16 07:49:06 Heizoeltank EspEasy: 1: lowest: 13832  CPluginCallADD (6)-> 17480 CPluginCallADD (7)-> 17432 CPluginCallADD (8)-> 17384 CPluginCallADD (9)-> 17336 CPluginCallADD (10)-> 17304 CPluginCallADD (11)-> 17288 CPluginCallADD (12)-> 17272 rulesProcessing-> 173
Mar 16 07:49:06 Heizoeltank EspEasy: 2: lowest: 13832  CPluginCallADD (7)-> 17432 CPluginCallADD (8)-> 17384 CPluginCallADD (9)-> 17336 CPluginCallADD (10)-> 17304 CPluginCallADD (11)-> 17288 CPluginCallADD (12)-> 17272 rulesProcessing-> 17352 addLog-> 17640 rulesProc
Mar 16 07:49:06 Heizoeltank EspEasy: MQTT : Connected to broker with client ID: ESPClient_5C:CF:7F:1B:A9:89
Mar 16 07:49:06 Heizoeltank EspEasy: Subscribed to: /Tankraum/#
Mar 16 07:49:06 Heizoeltank EspEasy: EVENT: MQTT#Connected
Mar 16 07:49:06 Heizoeltank EspEasy: EVENT: MQTT#Connected Processing time:1 milliSeconds
Mar 16 07:49:07 Heizoeltank EspEasy: SR04 : Distance: 82.43
Mar 16 07:49:07 Heizoeltank EspEasy: EVENT: Distance#Distance=82.43
Mar 16 07:49:07 Heizoeltank EspEasy: EVENT: Distance#Distance=82.43 Processing time:0 milliSeconds
Mar 16 07:49:07 Heizoeltank EspEasy: ADC  : Analog value: 697
Mar 16 07:49:07 Heizoeltank EspEasy: EVENT: Voltage#Voltage=5.27
Mar 16 07:49:07 Heizoeltank EspEasy: EVENT: Voltage#Voltage=5.27 Processing time:1 milliSeconds
Mar 16 07:49:08 Heizoeltank EspEasy: DHT  : Temperature: 14.60
Mar 16 07:49:08 Heizoeltank EspEasy: DHT  : Humidity: 55.40
Mar 16 07:49:08 Heizoeltank EspEasy: EVENT: T&H#Temperature=14.60
Mar 16 07:49:08 Heizoeltank EspEasy: EVENT: T&H#Temperature=14.60 Processing time:0 milliSeconds
Mar 16 07:49:08 Heizoeltank EspEasy: EVENT: T&H#Humidity=52.70
Mar 16 07:49:08 Heizoeltank EspEasy: EVENT: T&H#Humidity=52.70 Processing time:1 milliSeconds
Mar 16 07:49:15 Heizoeltank EspEasy: MQTT : publish failed
Mar 16 07:49:20 Heizoeltank EspEasy: MQTT : publish failed
Mar 16 07:49:20 Heizoeltank EspEasy: SYS  : -76.00
Mar 16 07:49:20 Heizoeltank EspEasy: EVENT: RSSI#RSSI=-76.00
Mar 16 07:49:20 Heizoeltank EspEasy: EVENT: RSSI#RSSI=-76.00 Processing time:1 milliSeconds
Mar 16 07:49:26 Heizoeltank EspEasy: MQTT : publish failed
Mar 16 07:49:26 Heizoeltank EspEasy: EVENT: Clock#Time=Fri,07:49
Mar 16 07:49:26 Heizoeltank EspEasy: EVENT: Clock#Time=Fri,07:49 Processing time:0 milliSeconds
Mar 16 07:49:26 Heizoeltank EspEasy: EVENT: System#Sleep
Mar 16 07:49:26 Heizoeltank EspEasy: EVENT: System#Sleep Processing time:1 milliSeconds
Mar 16 07:49:26 Heizoeltank EspEasy: Memtrace#0120: lowest: 10384  PluginCall_s (12)-> 10776 PluginCall_s (1)-> 10776 PluginCall_s (4)-> 10776 PluginCall_s (25)-> 10776 rulesProcessing-> 10888 PluginCall_s (12)-> 10424 PluginCall_s (1)-> 10424 PluginCall_s (4)-> 10424 Pl
Mar 16 07:49:26 Heizoeltank EspEasy: 1: lowest: 10424  SensorSendTask-> 11280 SensorSendTask-> 11280 SensorSendTask-> 11280 PluginCall_s (12)-> 11144 PluginCall_s (1)-> 11144 PluginCall_s (4)-> 11144 PluginCall_s (25)-> 11144 rulesProcessing-> 11240 PluginCall_s (12)-
Mar 16 07:49:26 Heizoeltank EspEasy: 2: lowest: 10424  SensorSendTask-> 11280 SensorSendTask-> 11280 PluginCall_s (12)-> 11144 PluginCall_s (1)-> 11144 PluginCall_s (4)-> 11144 PluginCall_s (25)-> 11144 rulesProcessing-> 11240 PluginCall_s (12)-> 10776 PluginCall_s (1
Mar 16 07:49:26 Heizoeltank EspEasy: WD   : Uptime 1 ConnectFailures 0 FreeMem 10344
Mar 16 07:49:26 Heizoeltank EspEasy: SR04 : Distance: 82.40
Mar 16 07:49:26 Heizoeltank EspEasy: EVENT: Distance#Distance=82.40
Mar 16 07:49:26 Heizoeltank EspEasy: EVENT: Distance#Distance=82.40 Processing time:1 milliSeconds
Mar 16 07:49:33 Heizoeltank EspEasy: MQTT : publish failed
Mar 16 07:49:33 Heizoeltank EspEasy: ADC  : Analog value: 692
Mar 16 07:49:33 Heizoeltank EspEasy: EVENT: Voltage#Voltage=5.23
Mar 16 07:49:33 Heizoeltank EspEasy: EVENT: Voltage#Voltage=5.23 Processing time:1 milliSeconds
Mar 16 07:49:39 Heizoeltank EspEasy: MQTT : publish failed
Mar 16 07:49:39 Heizoeltank EspEasy: DHT  : Temperature: 14.60
Mar 16 07:49:39 Heizoeltank EspEasy: DHT  : Humidity: 55.40
Mar 16 07:49:39 Heizoeltank EspEasy: EVENT: T&H#Temperature=14.60
Mar 16 07:49:39 Heizoeltank EspEasy: EVENT: T&H#Temperature=14.60 Processing time:1 milliSeconds
Mar 16 07:49:39 Heizoeltank EspEasy: EVENT: T&H#Humidity=52.70
Mar 16 07:49:39 Heizoeltank EspEasy: EVENT: T&H#Humidity=52.70 Processing time:0 milliSeconds
Mar 16 07:49:46 Heizoeltank EspEasy: MQTT : publish failed
Mar 16 07:49:51 Heizoeltank EspEasy: MQTT : publish failed
Mar 16 07:49:51 Heizoeltank EspEasy: SYS  : -76.00
Mar 16 07:49:51 Heizoeltank EspEasy: EVENT: RSSI#RSSI=-76.00
Mar 16 07:49:51 Heizoeltank EspEasy: EVENT: RSSI#RSSI=-76.00 Processing time:0 milliSeconds
Mar 16 07:49:57 Heizoeltank EspEasy: MQTT : publish failed
Mar 16 07:49:57 Heizoeltank EspEasy: EVENT: System#Sleep
Mar 16 07:49:57 Heizoeltank EspEasy: EVENT: System#Sleep Processing time:1 milliSeconds
Mar 16 07:49:57 Heizoeltank EspEasy: Memtrace#0120: lowest: 10112  PluginCall_s (25)-> 10776 rulesProcessing-> 10888 PluginCall_s (12)-> 10424 PluginCall_s (1)-> 10424 PluginCall_s (4)-> 10424 PluginCall_s (25)-> 10424 PluginCall_s (12)-> 10424 PluginCall_s (1)-> 10424 P
Mar 16 07:49:57 Heizoeltank EspEasy: 1: lowest: 10104  rulesProcessing-> 10888 PluginCall_s (12)-> 10424 PluginCall_s (1)-> 10424 PluginCall_s (4)-> 10424 PluginCall_s (25)-> 10424 PluginCall_s (12)-> 10424 PluginCall_s (1)-> 10424 PluginCall_s (4)-> 10424 PluginCall_
Mar 16 07:49:57 Heizoeltank EspEasy: 2: lowest: 10128  PluginCall_s (4)-> 10776 PluginCall_s (25)-> 10776 rulesProcessing-> 10888 PluginCall_s (12)-> 10424 PluginCall_s (1)-> 10424 PluginCall_s (4)-> 10424 PluginCall_s (25)-> 10424 PluginCall_s (12)-> 10424 PluginCall
Mar 16 07:49:57 Heizoeltank EspEasy: WD   : Uptime 1 ConnectFailures 0 FreeMem 10344
Mar 16 07:49:57 Heizoeltank EspEasy: SR04 : Distance: 82.02
Mar 16 07:49:57 Heizoeltank EspEasy: EVENT: Distance#Distance=82.02
Mar 16 07:49:57 Heizoeltank EspEasy: EVENT: Distance#Distance=82.02 Processing time:1 milliSeconds
Mar 16 07:50:04 Heizoeltank EspEasy: MQTT : publish failed
Mar 16 07:50:04 Heizoeltank EspEasy: ADC  : Analog value: 691
Mar 16 07:50:04 Heizoeltank EspEasy: EVENT: Voltage#Voltage=5.22
Mar 16 07:50:04 Heizoeltank EspEasy: EVENT: Voltage#Voltage=5.22 Processing time:0 milliSeconds
Mar 16 07:50:10 Heizoeltank EspEasy: MQTT : publish failed
Mar 16 07:50:10 Heizoeltank EspEasy: DHT  : Temperature: 14.60
Mar 16 07:50:10 Heizoeltank EspEasy: DHT  : Humidity: 55.40
Mar 16 07:50:10 Heizoeltank EspEasy: EVENT: T&H#Temperature=14.60
Mar 16 07:50:10 Heizoeltank EspEasy: EVENT: T&H#Temperature=14.60 Processing time:1 milliSeconds
Mar 16 07:50:10 Heizoeltank EspEasy: EVENT: T&H#Humidity=52.70
Mar 16 07:50:10 Heizoeltank EspEasy: EVENT: T&H#Humidity=52.70 Processing time:0 milliSeconds
Mar 16 07:50:17 Heizoeltank EspEasy: MQTT : publish failed
Mar 16 07:50:22 Heizoeltank EspEasy: SYS  : -76.00
Mar 16 07:50:22 Heizoeltank EspEasy: EVENT: RSSI#RSSI=-76.00
Mar 16 07:50:22 Heizoeltank EspEasy: EVENT: RSSI#RSSI=-76.00 Processing time:0 milliSeconds
Mar 16 07:50:28 Heizoeltank EspEasy: MQTT : publish failed
Mar 16 07:50:28 Heizoeltank EspEasy: EVENT: Clock#Time=Fri,07:50
Mar 16 07:50:28 Heizoeltank EspEasy: EVENT: Clock#Time=Fri,07:50 Processing time:0 milliSeconds
Mar 16 07:50:28 Heizoeltank EspEasy: EVENT: System#Sleep
Mar 16 07:50:28 Heizoeltank EspEasy: EVENT: System#Sleep Processing time:0 milliSeconds
Mar 16 07:50:28 Heizoeltank EspEasy: EVENT: System#Sleep
Mar 16 07:50:28 Heizoeltank EspEasy: EVENT: System#Sleep Processing time:1 milliSeconds
Mar 16 07:50:28 Heizoeltank EspEasy: SLEEP: Powering down to deepsleep...
DittelHome commented 6 years ago

Interesting is, that the last two values Humidity and RSSI are not published. The other values will be successfully published. Maybe it is useful... It seems, that the ESP can only publish 3 values during wake time.

DittelHome commented 6 years ago

After I transfer only the essential values (for me distance, temperature and humidity) to the broker it works first, more than three values are not possible in deepsleep. (Hopefully in the future, in past it was possible)

TD-er commented 6 years ago

You can now extend the 'awake' time (same place where you activate the sleep time) per second. It is also possible to force sleep again from within the rules, so you could set the wake time to some 'worst-case' value like 30 seconds and enter sleep earlier when all tasks are completed.

DittelHome commented 6 years ago

Thanks for the hint. ;) I set the awake time to 3 minutes, no way. I get only three values...

Kasu80 commented 6 years ago

I have the same issue. Only the first three values get over mqtt whit enabled Deepsleep.

DittelHome commented 6 years ago

Sorry, with the last update from 03/19/2018 nothing is published after deep sleep. ESP8266 goes into a bootloop:

rst cause: 2  boot mode : (3,6)
soft wdt reset
TD-er commented 6 years ago

Hmm that's not good at all. Could you remove the MQTTConnect part in the deep sleep related part of the main loop and test again? https://github.com/letscontrolit/ESPEasy/blob/89df0932c55dfee38dd989e49fa4af0bded93d13/src/ESPEasy.ino#L320-L323

DittelHome commented 6 years ago

I haven't still installed the development stuff. Are able to send me the modified *.bin for testing (4Mbyte) version ?

TD-er commented 6 years ago

Maybe some of the other devs, I'm not able to build it right now.

TD-er commented 6 years ago

Should be fixed right now. I made some silly mistake in the WiFi code to "connect-and-wait" due to a last-minute change for the 'non-deepsleep' mode. There wasn't enough time for background tasks and thus the watchdog timer kicks in and resets the board.

DittelHome commented 6 years ago

Today, i have tested with ESPEasy_mega-20180323. Bad news, still, only three values ...

TD-er commented 6 years ago

Should be fixed right now (see PR #1161), although I haven't tested it myself. I should prepare a unit here rigged for deepsleep.

Micha-he commented 6 years ago

Maybe I'm wrong in this issue, but with the lastest/current source the following occurs:

After a reboot no states (from my two devices) are publish to the MQTT-controller, if

Should I open a new issue ?

TD-er commented 6 years ago

I will have a look at it.

TD-er commented 6 years ago

I've been testing here a bit and with delay of 0 I get no output indeed. With delay set to 1, I get almost every second an update, but it seems to be running against some limit. With delay of 3 and higher works fine.

Not sure where the limit is, but it may be the MQTT buffer is filling up. Currently the MQTT loop is being called at most 4x per second. That may be set lower.

I guess you could set the delay to 1 second and increase the awake time during sleep. Then if the message is sent like you want, you can trigger a rule to set the ESP into sleep again.

DittelHome commented 6 years ago

Today, i tested again. Here are my results:

Distance | 84 | 2018-03-24 08:14:04
Humidity | 50.60 | 2018-03-24 08:14:06
RSSI | -69 | 2018-03-24 07:44:59
Temperature | 14.40 | 2018-03-24 08:14:06
Voltage | 5.27 | 2018-03-24 07:45:02
transmission-state | incoming publish received | 2018-03-24 08:14:06

RSSI and Voltage is still missing. The ESP wakes up every 1800 seconds. The timestamp 07:4x:xx was while the ESP wasn't in deep sleep.

TD-er commented 6 years ago

Could it be those two values can only be read after minimum uptime?

Micha-he commented 6 years ago

I thought it was a bug !? With delay 0 I had expected a one-time publish and not a suspension of publishing values.

Me current solution is, a timeout of 15s until deepsleep and a device-delay of 10s. This seems a safe publish, while a minimum wake time. But it's only a crutch...

DittelHome commented 6 years ago

Could it be those two values can only be read after minimum uptime?

Only the first three tasks will be reported, If a change the sequence then other values are missing. Only Task 1-3 will report to mqtt. Task 4 until 12 will fail to publish, it doesnt matter what kind of values/devices.

Grovkillen commented 6 years ago

Status on this ?

TD-er commented 6 years ago

I would be surprised if it is fixed now. It will be a pleasant surprise though :)

DittelHome commented 6 years ago

I cannot really test. After migrate to core 2.4.0 version (normal), I get no response from ESP. Tried clean install etc. At least this two version, doesn't work for me: ESP_Easy_mega-20180417_normal_ESP8266_4096.bin ESP_Easy_mega-20180416_normal_ESP8266_4096.bin

This version works, exept deep sleep and MQTT: ESP_Easy_mega-20180407_normal_ESP8266_4096.bin

See also #1255

TD-er commented 6 years ago

Hmm that's strange. Is that with existing settings, or clean install?

DittelHome commented 6 years ago

Thats what i try to figure out in the moment. Definitly a can say, when i do a clean install , then change only ip,wifissid,unit, and wifikey with followed maunal wifidisconnect (via serial) i get a response (ping and gui). Wtihout manual wifidisconnect, no ip response. 

84 : INIT : Warm boot #9
86 : FS   : Mounting...
110 : FS   : Mount successful, used 75802 bytes of 957314
398 : CRC  : program checksum       ...OK
403 : CRC  : Settings CRC           ...FAIL
431 : CRC  : SecuritySettings CRC   ...OK 
537 : INIT : Free RAM:20584
538 : INIT : I2C
538 : INIT : SPI not enabled
552 : INFO : Plugins: 47 [Normal] (core 2_4_0)
552 : WIFI : Connecting im6shop attempt #0
561 : WD   : Uptime 0 ConnectFailures 0 FreeMem 17536
3601 : WIFI : Connected! AP: im6shop (30:B5:C2:EB:DB:7D) Ch: 9 Duration: 3048 ms
3601 : IP   : Static IP : 192.168.1.17 GW: 0.0.0.0 SN: 0.0.0.0 DNS: 0.0.0.0
3604 : WIFI : Static IP: 192.168.1.17 (ESP-Easy-6) GW: 0.0.0.0 SN: 255.255.255.0
30561 : WD   : Uptime 1 ConnectFailures 0 FreeMem 16800
60561 : WD   : Uptime 1 ConnectFailures 0 FreeMem 16800
90561 : WD   : Uptime 2 ConnectFailures 0 FreeMem 16800
==> until now, no connection
>wifidisconnect
Ok
97835 : WIFI : Disconnected! Reason: 'Assoc leave' Connected for 1 m 34 s
97836 : WIFI : Connecting im6shop attempt #0
100088 : WIFI : Connected! AP: im6shop (30:B5:C2:EB:DB:7D) Ch: 9 Duration: 2251 ms
100089 : IP   : Static IP : 192.168.1.17 GW: 0.0.0.0 SN: 0.0.0.0 DNS: 0.0.0.0
100092 : WIFI : Static IP: 192.168.1.17 (ESP-Easy-6) GW: 0.0.0.0 SN: 255.255.255.0
==> now, device is reachable
Oxyandy commented 6 years ago

Why no Gateway, Subnet or DNS is set ? 100089 : IP : Static IP : 192.168.1.17 GW: 0.0.0.0 SN: 0.0.0.0 DNS: 0.0.0.0 Or is that a fault in the logs ?

DittelHome commented 6 years ago

After clean install i set always only ip over serial. Then i connect via webgui and set GW DNS and subnet mask. It was never a problem. I have also tried with GW DNS SUBNET, static IP does not work at the moment, without manual wifidisconnect.

koochyrat commented 6 years ago

Hi I am also facing this problem, but with the stable release v2. Only 3 publishes before it fails, even with dummy sensors. I am getting a 'LmacRxBlk: 1' message in the serial monitor with debug on, which I think is related to receive buffers. Wireshark is showing multiple TCP retransmissions before the connection gets terminated. I am investigating further. I could not test on the mega branch because I am also facing issues getting static ip working there.

connected with Kchn, channel 6
ip:192.168.1.30,mask:255.255.0.0,gw:192.168.1.1
WIFI : WiFi connect attempt took: 3066 ms
WIFI : Connected! IP: 192.168.1.30 (kchsensor1-1) AP: Kchn AP BSSID: C4:E9:84:7B:56:72
WD   : Uptime 0 ConnectFailures 0 FreeMem 19688
MQTT : Intentional reconnect
MQTT : Connected to broker with client ID: ESPClient_5C:CF:7F:6E:32:42
Subscribed to: kchsensor1/#
Dummy: value 1: 30.22
Dummy: value 2: 66.76
Dummy: value 3: 1012.77
Dummy: value 4: 0.00
MQTT : kchsensor1/bme280/temperature 30.22
MQTT : kchsensor1/bme280/humidity 66.76
LmacRxBlk:1
LmacRxBlk:1
LmacRxBlk:1
LmacRxBlk:1
MQTT : publish failed
MQTT : kchsensor1/bme280/pressure 1012.77
LmacRxBlk:1
ADC  : Analog value: 99
LmacRxBlk:1
LmacRxBlk:1
LmacRxBlk:1
LmacRxBlk:1
pm open,type:2 0
LmacRxBlk:1
LmacRxBlk:1
MQTT : publish failed
MQTT : kchsensor1/battery/voltage 99
SYS  : -77.00
LmacRxBlk:1
LmacRxBlk:1
LmacRxBlk:1
LmacRxBlk:1
LmacRxBlk:1
LmacRxBlk:1
MQTT : publish failed
MQTT : kchsensor1/rssi/ -77.00
LmacRxBlk:1
LmacRxBlk:1
LmacRxBlk:1
LmacRxBlk:1
LmacRxBlk:1
EVENT: System#Sleep
EVENT: System#Sleep Processing time:66 milliSeconds
SLEEP: Powering down to deepsleep...
state: 5 -> 0 (0)
rm 0
pm close 7
del if0
usl
koochyrat commented 6 years ago

Ok, I managed to hack a workaround. I'm not sure of the cause but it seems that on awaking from deep sleep, sensor data is sent too soon before the MQTT %sysname%/status/LWT is published. Adding a initial 10s sensor delay seems to work. My SleepDelay = 300s, SleepAwake=20s, MessageDelay=0.

ESPEasy.ino:

//They should also check if we returned from deep sleep so that they can skip the delay in that case.
for (byte x = 0; x < TASKS_MAX; x++)
if (Settings.TaskDeviceTimer[x] !=0)
timerSensor[x] = millis() + (x * Settings.MessageDelay) + 10000;
void checkSensors()
{
bool isDeepSleep = false; //isDeepSleepEnabled();

Serial:

connected with Kchn, channel 6
ip:192.168.1.30,mask:255.255.0.0,gw:192.168.1.1
WIFI : WiFi connect attempt took: 3117 ms
WIFI : Connected! IP: 192.168.1.30 (kchsensor1-1) AP: Kchn AP BSSID: C4:E9:84:7B:56:72
MQTT : Connected to broker with client ID: ESPClient_5C:CF:7F:6E:32:42
Subscribed to: kchsensor1/#
WD   : Uptime 0 ConnectFailures 0 FreeMem 19392
MQTT : Topic: kchsensor1/status/LWT
MQTT : Payload: Connection Lost
MQTT : Topic: kchsensor1/status/LWT
MQTT : Payload: Connected
BME  : Address: 0x76
BME  : Temperature: 29.22
BME  : Humidity: 54.94
BME  : Barometric Pressure: 1009.09
MQTT : kchsensor1/bme280/temperature 29.22
MQTT : kchsensor1/bme280/humidity 54.94
MQTT : kchsensor1/bme280/pressure 1009.09
ADC  : Analog value: 87
MQTT : kchsensor1/battery/voltage 87
SYS  : -79.00
MQTT : kchsensor1/rssi/ -79.00
MQTT : Topic: kchsensor1/bme280/temperature
MQTT : Payload: 29.22
MQTT : Topic: kchsensor1/bme280/humidity
MQTT : Payload: 54.94
MQTT : Topic: kchsensor1/bme280/pressure
MQTT : Payload: 1009.09
MQTT : Topic: kchsensor1/battery/voltage
MQTT : Payload: 87
MQTT : Topic: kchsensor1/rssi/
MQTT : Payload: -79.00
pm open,type:2 0
EVENT: System#Sleep
EVENT: System#Sleep Processing time:65 milliSeconds
SLEEP: Powering down to deepsleep...
state: 5 -> 0 (0)
rm 0
pm close 7
del if0
usl
DittelHome commented 6 years ago

Surprise, surpise... Now it is working, tested with ESP_Easy_mega-20180501_normal_ESP8266_4096.bin.

howardweng commented 5 years ago

I spent a lot of time to solve this, this is my working sketch for your reference. please see DELAY part, that is important

///////////////////////////////////////////////////////////
#include <ESP8266WiFi.h>
#include <PubSubClient.h>

// Update these with values suitable for your network.

const char* ssid = "frrut";
const char* password =  "ccccccccccc";
const char* mqtt_server = "ccccccccccccc";

WiFiClient espClient;
PubSubClient client(espClient);
long lastMsg = 0;
char msg[50];
int value = 0;

void setup_wifi() {

  delay(10);
  // We start by connecting to a WiFi network
  Serial.println();
  Serial.print("Connecting to ");
  Serial.println(ssid);

  WiFi.begin(ssid, password);

  while (WiFi.status() != WL_CONNECTED) {
    delay(500);
    Serial.print(".");
  }

  randomSeed(micros());

  Serial.println("");
  Serial.println("WiFi connected");
  Serial.println("IP address: ");
  Serial.println(WiFi.localIP());
}

//void callback(char* topic, byte* payload, unsigned int length) {
//  Serial.print("Message arrived [");
//  Serial.print(topic);
//  Serial.print("] ");
//  for (int i = 0; i < length; i++) {
//    Serial.print((char)payload[i]);
//  }
//  Serial.println();
//
//  // Switch on the LED if an 1 was received as first character
//  if ((char)payload[0] == '1') {
//    digitalWrite(BUILTIN_LED, LOW);   // Turn the LED on (Note that LOW is the voltage level
//    // but actually the LED is on; this is because
//    // it is active low on the ESP-01)
//  } else {
//    digitalWrite(BUILTIN_LED, HIGH);  // Turn the LED off by making the voltage HIGH
//  }
//
//}

void reconnect() {
  // Loop until we're reconnected
  while (!client.connected()) {
    Serial.print("Attempting MQTT connection...");

    String clientId = "ESP8266Client-";
    clientId += String(random(0xffff), HEX);

    if (client.connect(clientId.c_str())) {
      Serial.println("connected");

    client.subscribe("frrutmqtt/lab2");

   Serial.print("client.state :");
   Serial.println(client.state());

   String stringmsg = "hello 8927489378893478953489";
   Serial.println("print" + stringmsg );   

  String data = stringmsg;
  int length = data.length();
  char msgBuffer[length];
  data.toCharArray(msgBuffer,length+1);
  Serial.println(msgBuffer); 

 client.publish("frrutmqtt/lab2", msgBuffer);

    } else {
      Serial.print("failed, rc=");
      Serial.print(client.state());
      Serial.println(" try again in 5 seconds");
      // Wait 5 seconds before retrying
      delay(1000);
    }
  }
}

void setup() {
 // pinMode(BUILTIN_LED, OUTPUT);     // Initialize the BUILTIN_LED pin as an output
  Serial.begin(115200);
  setup_wifi();
  client.setServer(mqtt_server, 1883);

 // client.setCallback(callback);

}

void loop() {

   Serial.print("client.state :");
   Serial.println(client.state());

// reconnect(); 

///////////////////

  // Loop until we're reconnected
  while (!client.connected()) {
    Serial.print("Attempting MQTT connection...");

    String clientId = "ESP8266Client-";
    clientId += String(random(0xffff), HEX);

    if (client.connect(clientId.c_str())) {
      Serial.println("connected");

    client.subscribe("frrutmqtt/lab2");

   Serial.print("client.state :");
   Serial.println(client.state());

   String stringmsg = "hello 8927489378893478953489";
   Serial.println("print" + stringmsg );   

  String data = stringmsg;
  int length = data.length();
  char msgBuffer[length];
  data.toCharArray(msgBuffer,length+1);
  Serial.println(msgBuffer); 

 client.publish("frrutmqtt/lab2", msgBuffer);

    } else {
      Serial.print("failed, rc=");
      Serial.print(client.state());
      Serial.println(" try again in 5 seconds");
      // Wait 5 seconds before retrying
      delay(1000);
    }
  }

  //////////////////////////////////

 ////////////very important////////////

 delay(1000);

 ////////////without this NOT working////////////

       // Sleep
  Serial.println("ESP8266 in sleep mode");
  ESP.deepSleep(5 * 1000000);

}
TD-er commented 5 years ago

So in short, you have to make sure the data is actually flushed to the MQTT broker before going to sleep again?

howardweng commented 5 years ago

that is right. if no delay for a while, then it goes to sleep too quick before completing MQTT msg.