search

stefanbode / Sonoff-Tasmota

Provide ESP8266 based itead Sonoff with Web, MQTT and OTA firmware using Arduino IDE, enhanced with I2C options
GNU General Public License v3.0
127 stars 41 forks source link

Topic aren't sent correctly after deepsleep wake (sometimes) #124

Closed helmar74 closed 5 years ago

helmar74 commented 5 years ago

Hi,

I have a strange behaviour of this Tasmota fork. My circuit is working well and the wemos mini is waking up every 1800 s (deepsleep time).

But sometimes (every 3-5 hours) not all MQTT Topics are sent to broker. Here's an working example, where all of the Topics are sent:

tele/WemosMiniAkku_1/LWT Online cmnd/WemosMiniAkku_1/POWER (null) tele/WemosMiniAkku_1/INFO1 {"Module":"Generic","Version":"6.4.1.9 stb-1.1(sonoff)","FallbackTopic":"cmnd/WemosMiniAkku-1_fb/","GroupTopic":"sonoffAkkuGruppe"} tele/WemosMiniAkku_1/INFO2 {"WebServerMode":"Admin","Hostname":"WemosMiniAkku-1","IPAddress":"192.168.1.137"} tele/WemosMiniAkku_1/INFO3 {"RestartReason":"Deep-Sleep Wake"} stat/WemosMiniAkku_1/RESULT {"POWER":"ON"} stat/WemosMiniAkku_1/POWER ON stat/WemosMiniAkku_1/RESULT {"DeepSleep":"1800 (1800)"} tele/WemosMiniAkku_1/STATE {"Time":"2019-02-10T11:44:33","Uptime":"0T00:00:18","SleepMode":"Dynamic","Sleep":50,"LoadAvg":19,"POWER":"ON","Wifi":{"AP":2,"SSId":"hs.net_EG","BSSId":"E8:DF:70:B5:4D:0B","Channel":11,"RSSI":50},"DeepSleep":1800,"Heap":23400} tele/WemosMiniAkku_1/SENSOR {"Time":"2019-02-10T11:44:33","ANALOG":{"A0":1024},"DS18B20":{"Temperature":5.7},"SR04":{"Distanz":28.912},"TempUnit":"C"} tele/WemosMiniAkku_1/LWT Offline tele/WemosMiniAkku_1/UPTIME_S {"Time":"2019-02-10T11:44:33", "Uptime_s":13} tele/WemosMiniAkku_1/LWT Offline

Here's a non working example (tele/WemosMiniAkku_1/STATEm tele/WemosMiniAkku_1/SENSOR and tele/WemosMiniAkku_1/UPTIME_S) missing:

tele/WemosMiniAkku_1/LWT Online cmnd/WemosMiniAkku_1/POWER (null) tele/WemosMiniAkku_1/INFO1 {"Module":"Generic","Version":"6.4.1.9 stb-1.1(sonoff)","FallbackTopic":"cmnd/WemosMiniAkku-1_fb/","GroupTopic":"sonoffAkkuGruppe"} tele/WemosMiniAkku_1/INFO2 {"WebServerMode":"Admin","Hostname":"WemosMiniAkku-1","IPAddress":"192.168.1.137"} tele/WemosMiniAkku_1/INFO3 {"RestartReason":"Deep-Sleep Wake"} stat/WemosMiniAkku_1/RESULT {"POWER":"ON"} stat/WemosMiniAkku_1/POWER ON stat/WemosMiniAkku_1/RESULT {"DeepSleep":"1800 (1800)"} tele/WemosMiniAkku_1/LWT Offline

The main issue is, that the tele/WemosMiniAkku_1/SENSOR topic isn't received by mosquitto mqtt broker. So now new sensor values are collected.

Has anybody an idea, what I can do? (I'm thinking of sending the value triggered thru a rule before the teleperiod ends) Would by setting sensorretain on an option?

Thanks for help in advance

helmar

nicoderandere commented 5 years ago

hi helmar

if have the same issue right after the first wake up from deepsleep with a wemos d1 mini, it doesnt even send telemetry data i have set up as generic with no sensors just for testing.

i let u know if i have found a solution

helmar74 commented 5 years ago

Hi,

great to hear, you're welcome ;-) What I'm thinking is to implement a rule, that should be triggered after deepsleep wakeup. The rule should "only" fire a status 8 command, that would send the topic stat/sonoffWemosMini_3/STATUS8:

13:58:04 MQT: stat/sonoffWemosMini_3/STATUS8 = {"StatusSNS":{"Time":"2019-02-10T13:58:04","DS18B20":{"Temperature":7.7},"TempUnit":"C"}}

helmar74 commented 5 years ago

Just for information. The last "successful" wakeup, with sending all topics was at 12:41:35. The next (2) wakeups doesn't send "Sensor topics":

tele/WemosMiniAkku_1/UPTIME_S {"Time":"2019-02-10T12:41:35", "Uptime_s":13} tele/WemosMiniAkku_1/LWT Offline tele/WemosMiniAkku_1/LWT Online cmnd/WemosMiniAkku_1/POWER (null) tele/WemosMiniAkku_1/INFO1 {"Module":"Generic","Version":"6.4.1.9 stb-1.1(sonoff)","FallbackTopic":"cmnd/WemosMiniAkku-1_fb/","GroupTopic":"sonoffAkkuGruppe"} tele/WemosMiniAkku_1/INFO2 {"WebServerMode":"Admin","Hostname":"WemosMiniAkku-1","IPAddress":"192.168.1.137"} tele/WemosMiniAkku_1/INFO3 {"RestartReason":"Deep-Sleep Wake"} stat/WemosMiniAkku_1/RESULT {"POWER":"ON"} stat/WemosMiniAkku_1/POWER ON stat/WemosMiniAkku_1/RESULT {"DeepSleep":"1800 (1800)"} tele/WemosMiniAkku_1/LWT Offline tele/WemosMiniAkku_1/LWT Online cmnd/WemosMiniAkku_1/POWER (null) tele/WemosMiniAkku_1/INFO1 {"Module":"Generic","Version":"6.4.1.9 stb-1.1(sonoff)","FallbackTopic":"cmnd/WemosMiniAkku-1_fb/","GroupTopic":"sonoffAkkuGruppe"} tele/WemosMiniAkku_1/INFO2 {"WebServerMode":"Admin","Hostname":"WemosMiniAkku-1","IPAddress":"192.168.1.137"} tele/WemosMiniAkku_1/INFO3 {"RestartReason":"Deep-Sleep Wake"} stat/WemosMiniAkku_1/RESULT {"POWER":"ON"} stat/WemosMiniAkku_1/POWER ON stat/WemosMiniAkku_1/RESULT {"DeepSleep":"1800 (1800)"} tele/WemosMiniAkku_1/LWT Offline

I think it's a bug of this version. But maybe there's an workaround..... I'm quite sure, that the values are send at next wakeup

helmar74 commented 5 years ago

Yes I',m right, the 3rd wakeup again sent the sensor values:

tele/WemosMiniAkku_1/LWT Online cmnd/WemosMiniAkku_1/POWER (null) tele/WemosMiniAkku_1/INFO1 {"Module":"Generic","Version":"6.4.1.9 stb-1.1(sonoff)","FallbackTopic":"cmnd/WemosMiniAkku-1_fb/","GroupTopic":"sonoffAkkuGruppe"} tele/WemosMiniAkku_1/INFO2 {"WebServerMode":"Admin","Hostname":"WemosMiniAkku-1","IPAddress":"192.168.1.137"} tele/WemosMiniAkku_1/INFO3 {"RestartReason":"Deep-Sleep Wake"} stat/WemosMiniAkku_1/RESULT {"POWER":"ON"} stat/WemosMiniAkku_1/POWER ON stat/WemosMiniAkku_1/RESULT {"DeepSleep":"1800 (1800)"}

>tele/WemosMiniAkku_1/STATE {"Time":"2019-02-10T14:07:51","Uptime":"0T00:00:18","SleepMode":"Dynamic","Sleep":50,"LoadAvg":19,"POWER":"ON","Wifi":{"AP":2,"SSId":"hs.net_EG","BSSId":"E8:DF:70:B5:4D:0B","Channel":11,"RSSI":50},"DeepSleep":1800,"Heap":23400}

>tele/WemosMiniAkku_1/SENSOR {"Time":"2019-02-10T14:07:51","ANALOG":{"A0":1024},"DS18B20":{"Temperature":5.9},"SR04":{"Distanz":25.877},"TempUnit":"C"}

tele/WemosMiniAkku_1/LWT Offline tele/WemosMiniAkku_1/UPTIME_S {"Time":"2019-02-10T14:07:51", "Uptime_s":13}

as the sensor value is the last topic sent to broker before going to deepsleep: Maybe the device enters deepsleep in the same millisecond, when it "want's" send the topic to broker. Maybe a short delay 1-5 seconds would help here?

nicoderandere commented 5 years ago

might help as it always tries to send status and sensor data in the end

stefanbode commented 5 years ago

There is already a check that the data should be sent BEFORE it go to deepsleep. I updated to the recent version and I saw that arendst make again many changes to the teleperiod behavior. maybe it works better now. The problem is, that for me it very hard reproducing the problem and then able to debug what was the issue at this time.

helmar74 commented 5 years ago

Hi,

I tried your new release. Unfourtnately it doesn't solve my problem. Upgrading was a mess: OTA didn't worked. Upgrade was done, but after that the Device (Wemos Mini) was instable. Webinterfaced timed out every now and then. Then I deleted flash with esptool and did a new flash with your current version. After that the Wemos Mini was running quite well... but after 12-14 hours the same error occurs:

  1. Device wakesup from deepsleep.
  2. Device connects to wifi
  3. Device doesn't connet/send messages to MQTT Broker
  4. Device goes to deepsleep again.

So in summary: The issue isn't solved with new version.

After upgrading I also found a few things changed:

  1. MQTT Topic JSONRESULT for SR04 ultrasonic. (I'm using german GUI settings) Distanz vs. Distance: Version 6.4.1.9 : 09:59:02 MQT: tele/WemosMiniAkku_1/SENSOR = {"Time":"2019-04-07T09:59:02","ANALOG":{"A0":1024},"DS18B20":{"Temperature":9.9},"SR04":{"Distanz":90.281},"TempUnit":"C"} Version 6.5.0.3: 10:57:23 MQT: tele/WemosMiniAkku_1/SENSOR = {"Time":"2019-04-07T10:57:23","ANALOG":{"A0":1024},"DS18B20":{"Temperature":9.9},"SR04":{"Distance":90.281},"TempUnit":"C"}

  2. The Deepsleep setting is different in MQTT message is different in the versions: (In version 6.5.0.3 it is sent within the "WIFI" JSON Result) Version 6.4.1.9 : 09:59:02 MQT: tele/WemosMiniAkku_1/STATE = {"Time":"2019-04-07T09:59:02","Uptime":"0T00:00:36","SleepMode":"Dynamic","Sleep":200,"LoadAvg":13,"POWER":"ON","Wifi":{"AP":2,"SSId":"hs.net_EG","BSSId":"E8:DF:70:B5:4D:0B","Channel":6,"RSSI":34},"DeepSleep":0,"Heap":20640} Version 6.5.0.3 : 09:59:02 MQT: tele/WemosMiniAkku_1/STATE = {"Time":"2019-04-09T09:59:02","Uptime":"0T00:00:36","SleepMode":"Dynamic","Sleep":200,"LoadAvg":13,"POWER":"ON","Wifi":{"AP":2,"SSId":"hs.net_EG","BSSId":"E8:DF:70:B5:4D:0B","Channel":6,"RSSI":34,"DeepSleep":0},"Heap":20640}

As the "Topic not sent error" occurs much often in version 6.5.0.3 I went back to 6.4.1.9.... Maybe I'll give it a try another time..

helmar74 commented 5 years ago

I think I found something more.... Your Tasmotafork send the Wemos Mini to deepsleep after teleperiod expires, right?

If you have a Tasmota Device with no sensor connected, the MQTT Message after Teleperiod looks like this (Teleperiod 300): 12:15:00 MQT: tele/sonoffS20_3/STATE = {"Time":"2019-04-07T12:15:00","Uptime":"1T20:20:18","Vcc":3.464,"SleepMode":"Dynamic","Sleep":0,"LoadAvg":607,"POWER":"OFF","Wifi":{"AP":1,"SSId":"SSID","BSSId":"F0:B0:14:6F:B5:4F","Channel":1,"RSSI":78,"LinkCount":1,"Downtime":"0T00:00:06"}} 12:20:00 MQT: tele/sonoffS20_3/STATE = {"Time":"2019-04-07T12:20:00","Uptime":"1T20:25:18","Vcc":3.466,"SleepMode":"Dynamic","Sleep":0,"LoadAvg":608,"POWER":"OFF","Wifi":{"AP":1,"SSId":"SSID","BSSId":"F0:B0:14:6F:B5:4F","Channel":1,"RSSI":78,"LinkCount":1,"Downtime":"0T00:00:06"}} 12:25:00 MQT: tele/sonoffS20_3/STATE = {"Time":"2019-04-07T12:25:00","Uptime":"1T20:30:18","Vcc":3.466,"SleepMode":"Dynamic","Sleep":0,"LoadAvg":609,"POWER":"OFF","Wifi":{"AP":1,"SSId":"SSID","BSSId":"F0:B0:14:6F:B5:4F","Channel":1,"RSSI":80,"LinkCount":1,"Downtime":"0T00:00:06"}} After each teleperiod the device enters deepsleep. In the example above at 12:15:00, 12:20:00 and 12:25:00. Hopefully correct so far?

If you have sensors connected, the message which is send after teleperiod expires looks like: 12:28:40 MQT: tele/sonoffWemosMini_4/STATE = {"Time":"2019-04-07T12:28:40","Uptime":"1T03:40:17","Vcc":3.074,"SleepMode":"Dynamic","Sleep":50,"LoadAvg":19,"POWER":"OFF","Wifi":{"AP":1,"SSId":"SSID","BSSId":"F0:B0:14:6F:B5:4F","Channel":1,"RSSI":68,"LinkCount":10,"Downtime":"0T00:00:41"}} 12:28:40 MQT: tele/sonoffWemosMini_4/SENSOR = {"Time":"2019-04-07T12:28:40","Switch1":"OFF","DS18B20":{"Temperature":-19.6},"TempUnit":"C"} After Teleperiod 2 messages are sent to broker: tele/sonoffWemosMini_4/STATE and tele/sonoffWemosMini_4/SENSOR

What I'm now assuming: If your software is sending the device to deepsleep, after the first mqtt message is sent (tele/sonoffWemosMini_4/STATE) to broker, the second message isn't sent to broker anymore. This happens, when the device is "fast enough" in entering deepsleep.

In some cases the device is a little bit slower, than the second message is sent to broker and then the device enters deepsleep.... (This can also depend on sleep setting for Dynamic sleep within loop cycle)

So maybe it would help, that you wait a (configurable) time after sending tele/sonoffWemosMini_4/STATE to broker before entering deepsleep. An other option would be: You should check if sensors are connected to the device. If so, you enter deepsleep after sending tele/sonoffWemosMini_4/SENSOR

Maybe im wrong completly, but maybe it's worth to having a look on?

Thank's a lot

tinimark commented 5 years ago

Hi, Did you find any solution to this? I'm having the exact same thing with D1 mini and SR04 ultrasonic sensor. It wakes up and sends the INFO topics but then goes back to sleep before sending the sensor topic. I have tried playing around with various dynamic sleep modes and teleperiods but no luck. Would be great to make this work as it's just what i'm looking for to do Oil tank level sensor running off a battery. Thanks!

helmar74 commented 5 years ago

@tinimark : Yes and no ;-) I upgraded to the latest version of the fork and I think, the issue is occurs not as often as before.... but it is still there. As I'm using Openhab in the background I created a workaround: When the device connects to the broker the LWT topic changes to online. I created a rule in Openhab, which sends a backlog command "status 10" to the device, when the LWT topic changes to "ONLINE". As the status 10 command also sends the values of the connected sensors, I created additonal channels for the openhab thing. The channels are connected to the same items as the channels for the state topics (teleperiod)

So I get the values twice, which works for me... It's not the best solution, but the software bug can be suppressed with it for me.

tinimark commented 5 years ago

Thanks for the update. Just to let you know I found the solution using ESPeasy firmware on the board. It wakes up once per hour and reports the level of oil in the tank and is working great now.

stefanbode commented 5 years ago

I added an additional check that takes care, if the initialisation of the sensor takes more time than required. There where some situations where the teleperiod was reached and the sensor was not already ready. There was no change to overcome the issue by changing the teleperiod from 10=default to something else because the init is always called 1sek before teleperiod,

helmar74 commented 5 years ago

@stefanbode: I updated my Device (with connected SR04 and 18B20 Sensor) to you newest version (1.4). Will monitor and provide feedback in a few days (as it happens not so often, that the device isn't sending Tele topic)...

stay tuned ;-)

stefanbode commented 5 years ago

Thanks. As mentioned above this was the last remaining idea, that could explain the issue. If it still does not work additional investigation is required. Looking forward to getting feedback

arnaldob commented 5 years ago

Hi @stefanbode, I apologize, I started the discussion here: https://github.com/arendst/Sonoff-Tasmota/issues/949 I have recently started using github, I hope to learn quickly, for now it is patient. It still doesn't work for me, but I think maybe I didn't do everything right. since reading the post of @helmar74 and not understanding why it refers to the update to you newest version (1.4), I would like to explain to you what I did to get your approval or if possible the instructions of what I should do. This is your Tasmota fork: https://github.com/stefanbode/Sonoff-Tasmota/tree/master/sonoff I could not do it here, so I moved here: https://github.com/stefanbode/Sonoff-Tasmota and with the clone or download button, I downloaded the ZIP file, a later with Plaformio I first compiled the minimal version and then the IT-language version and obtained the 2 firmware.bin files I proceeded to update the devices with the OTA method. What I get are still the screens I have attached to the previous discussion. Where did I go wrong?. Thanks

stefanbode commented 5 years ago

The minimal version is only an intermediate version, if you're low of flash memory. This is not a version to use. If you cannot upgrade to a new version the way is: current version->minimal version->new version.

after you have setup your WLAN and maybe MQTT in the webinterface you have to go into the console from the webinterface to enable deepsleep. see wiki here how to do it : deepsleep 60 for 1 minute deepsleep. Additionally set TELEPERIOD 10 to ensure the measure will immedilty reported. Otherwhise the device will stay awake 300 seconds. this is the default fo TELEPERIOD. All this stuff is standard TASMOTA and you will find much more help in the main forum. I really want to focus on the add ons and changes I did. For example, that the SENSOR is not correctly reported after a deepsleep. this is my problem because the original TASMOTA do not have this feature.

helmar74 commented 5 years ago

Hi Stefan,

I still have the issue, but I'll try something: Currently I'm using 2 WLAN's for the Device. I found out, that sometimes the device tries to connect to SSID1 and also to SSID2. In this case the device doesn't connect to broker (LWP Topic doesn't change to ONLINE) and than of course no data are sent to broker. I will try to disable SSID2 and will have a look, whats happening.., Will provide feedback next week.

stefanbode commented 5 years ago

I have also one device here for regression test and no issues so far. But I assume this is really Sensor dependent. Therefore please continue to check. The number on LwT online and Sensor submitts must be equal.

arnaldob commented 5 years ago

Hi Stefan,

If there is a previous version that works, would it be possible to have the information to find the old version?

stefanbode commented 5 years ago

No, as mentioned the version should work. I have integrated a new check to overcome one possible reason for the error. If you know why it happens we can fix it. Currently, the error is not reproducible.

arnaldob commented 5 years ago

@tinimark : Yes and no ;-) I upgraded to the latest version of the fork and I think, the issue is occurs not as often as before.... but it is still there. As I'm using Openhab in the background I created a workaround: When the device connects to the broker the LWT topic changes to online. I created a rule in Openhab, which sends a backlog command "status 10" to the device, when the LWT topic changes to "ONLINE".

Hi @tinimark

I also use openhab, I can ask you if you can show me how you built the rule. Thanks

arnaldob commented 5 years ago

@tinimark : Yes and no ;-) I upgraded to the latest version of the fork and I think, the issue is occurs not as often as before.... but it is still there. As I'm using Openhab in the background I created a workaround: When the device connects to the broker the LWT topic changes to online. I created a rule in Openhab, which sends a backlog command "status 10" to the device, when the LWT topic changes to "ONLINE". As the status 10 command also sends the values of the connected sensors, I created additonal channels for the openhab thing. The channels are connected to the same items as the channels for the state topics (teleperiod)

So I get the values twice, which works for me... It's not the best solution, but the software bug can be suppressed with it for me.

Hi @helmar74

I also use openhab, I can ask you if you can show me how you built the rule. Thanks

helmar74 commented 5 years ago

@arnaldob : Of course ;-) This is the rule I implemented: // Zusätzlich noch Den Befehl Status10 an den Wemos Akku Mini 1 senden, wenn er aufwacht rule "Status 10 an Wemos Mini Akku 1 senden" when Item i_mqtt_WemosMiniAkku_1_Reachable received update then

// Befehl nur senden, wenn der Wemos Mini Online ging
if (i_mqtt_WemosMiniAkku_1_Reachable.state == "Online") {
    Thread::sleep(1000)

    sendCommand(i_mqtt_WemosMiniAkku_Backlog, "status 10")

}

end

helmar74 commented 5 years ago

I've linked additional channel (to the same item as the teleperiod channel) to the thing for receiving the Output of the status 10 command

additional channel: image

Here's the configuration of the channel:

image

helmar74 commented 5 years ago

Heres the configuration of "normal" teleperiod channel: image

image

If you have any question, just ask me....

helmar74 commented 5 years ago

@arnaldob : Of course ;-) This is the rule I implemented: // Zusätzlich noch Den Befehl Status10 an den Wemos Akku Mini 1 senden, wenn er aufwacht rule "Status 10 an Wemos Mini Akku 1 senden" when Item i_mqtt_WemosMiniAkku_1_Reachable received update then

// Befehl nur senden, wenn der Wemos Mini Online ging
if (i_mqtt_WemosMiniAkku_1_Reachable.state == "Online") {
  Thread::sleep(1000)

  sendCommand(i_mqtt_WemosMiniAkku_Backlog, "status 10")

}

end

You need a item for the backlog command and also an item for the LWT (Last Will Topic) If you need an example, just ask.

arnaldob commented 5 years ago

@arnaldob : Of course ;-)

You need a item for the backlog command and also an item for the LWT (Last Will Topic) If you need an example, just ask.

WOW how much stuff. I try in the next days. Meanwhile, thank you 1000

helmar74 commented 5 years ago

@stefanbode : Just for you information. I still have "missing" MQTT Values. Here's the log. The sensor wales up every 1800 seconds. The sensor didn't woke up at about 19:30:

2019-05-30 00:26:23.022 [INFO ] [marthome.model.script.Zisterne.rules] - Abstand: 27 2019-05-30 00:55:06.281 [INFO ] [marthome.model.script.Zisterne.rules] - Abstand: 27 2019-05-30 01:23:26.078 [INFO ] [marthome.model.script.Zisterne.rules] - Abstand: 30 2019-05-30 01:51:55.507 [INFO ] [marthome.model.script.Zisterne.rules] - Abstand: 30 2019-05-30 02:20:22.471 [INFO ] [marthome.model.script.Zisterne.rules] - Abstand: 30 2019-05-30 02:49:03.403 [INFO ] [marthome.model.script.Zisterne.rules] - Abstand: 30 2019-05-30 03:17:51.269 [INFO ] [marthome.model.script.Zisterne.rules] - Abstand: 30 2019-05-30 03:46:25.321 [INFO ] [marthome.model.script.Zisterne.rules] - Abstand: 30 2019-05-30 04:14:46.797 [INFO ] [marthome.model.script.Zisterne.rules] - Abstand: 30 2019-05-30 04:43:15.753 [INFO ] [marthome.model.script.Zisterne.rules] - Abstand: 30 2019-05-30 05:11:39.492 [INFO ] [marthome.model.script.Zisterne.rules] - Abstand: 30 2019-05-30 05:40:07.480 [INFO ] [marthome.model.script.Zisterne.rules] - Abstand: 30 2019-05-30 06:08:56.443 [INFO ] [marthome.model.script.Zisterne.rules] - Abstand: 30 2019-05-30 06:37:23.758 [INFO ] [marthome.model.script.Zisterne.rules] - Abstand: 30 2019-05-30 07:05:48.635 [INFO ] [marthome.model.script.Zisterne.rules] - Abstand: 30 2019-05-30 07:34:23.835 [INFO ] [marthome.model.script.Zisterne.rules] - Abstand: 30 2019-05-30 08:02:54.418 [INFO ] [marthome.model.script.Zisterne.rules] - Abstand: 30 2019-05-30 08:31:31.002 [INFO ] [marthome.model.script.Zisterne.rules] - Abstand: 30 2019-05-30 09:28:33.589 [INFO ] [marthome.model.script.Zisterne.rules] - Abstand: 30 2019-05-30 09:56:59.342 [INFO ] [marthome.model.script.Zisterne.rules] - Abstand: 30 2019-05-30 10:25:43.298 [INFO ] [marthome.model.script.Zisterne.rules] - Abstand: 30 2019-05-30 10:54:12.779 [INFO ] [marthome.model.script.Zisterne.rules] - Abstand: 30 2019-05-30 11:23:03.174 [INFO ] [marthome.model.script.Zisterne.rules] - Abstand: 30 2019-05-30 11:51:30.156 [INFO ] [marthome.model.script.Zisterne.rules] - Abstand: 30 2019-05-30 12:20:13.258 [INFO ] [marthome.model.script.Zisterne.rules] - Abstand: 30 2019-05-30 12:48:45.909 [INFO ] [marthome.model.script.Zisterne.rules] - Abstand: 30 2019-05-30 13:17:16.370 [INFO ] [marthome.model.script.Zisterne.rules] - Abstand: 34 2019-05-30 13:45:54.951 [INFO ] [marthome.model.script.Zisterne.rules] - Abstand: 34 2019-05-30 14:14:31.521 [INFO ] [marthome.model.script.Zisterne.rules] - Abstand: 34 2019-05-30 14:43:19.801 [INFO ] [marthome.model.script.Zisterne.rules] - Abstand: 34 2019-05-30 15:11:48.832 [INFO ] [marthome.model.script.Zisterne.rules] - Abstand: 34 2019-05-30 15:40:36.823 [INFO ] [marthome.model.script.Zisterne.rules] - Abstand: 34 2019-05-30 16:09:24.212 [INFO ] [marthome.model.script.Zisterne.rules] - Abstand: 34 2019-05-30 16:37:57.430 [INFO ] [marthome.model.script.Zisterne.rules] - Abstand: 33 2019-05-30 17:06:28.627 [INFO ] [marthome.model.script.Zisterne.rules] - Abstand: 33 2019-05-30 17:35:07.224 [INFO ] [marthome.model.script.Zisterne.rules] - Abstand: 33 2019-05-30 18:03:37.455 [INFO ] [marthome.model.script.Zisterne.rules] - Abstand: 33 2019-05-30 18:32:14.099 [INFO ] [marthome.model.script.Zisterne.rules] - Abstand: 33 2019-05-30 19:00:37.510 [INFO ] [marthome.model.script.Zisterne.rules] - Abstand: 33 * MISSING ***** 2019-05-30 19:57:36.361 [INFO ] [marthome.model.script.Zisterne.rules] - Abstand: 33 2019-05-30 20:26:14.720 [INFO ] [marthome.model.script.Zisterne.rules] - Abstand: 33 2019-05-30 20:54:45.854 [INFO ] [marthome.model.script.Zisterne.rules] - Abstand: 33 2019-05-30 21:23:18.165 [INFO ] [marthome.model.script.Zisterne.rules] - Abstand: 33 2019-05-30 21:51:41.754 [INFO ] [marthome.model.script.Zisterne.rules] - Abstand: 33 2019-05-30 22:20:19.165 [INFO ] [marthome.model.script.Zisterne.rules] - Abstand: 33 2019-05-30 22:48:54.255 [INFO ] [marthome.model.script.Zisterne.rules] - Abstand: 33

stefanbode commented 5 years ago

Hi @helmar74 , thanks for the log. Did you get an LWT online at 19:30 or just nothing? In this case i assume the esp did not connect to WLAN successful and therefore for battery saving go into deepsleep again. The is a function that on a timeout of the wlan connect it is better to sleep again instead of trying to reach the network all the time and suck off the battery.

helmar74 commented 5 years ago

Hi @stefanbode , yes the device has gone online at 19:28:59: 2019-05-30 18:32:12.304 [vent.ItemStateChangedEvent] - i_mqtt_WemosMiniAkku_1_Reachable changed from Offline to Online 2019-05-30 18:32:21.133 [vent.ItemStateChangedEvent] - i_mqtt_WemosMiniAkku_1_Reachable changed from Online to Offline 2019-05-30 19:00:35.716 [vent.ItemStateChangedEvent] - i_mqtt_WemosMiniAkku_1_Reachable changed from Offline to Online 2019-05-30 19:00:44.523 [vent.ItemStateChangedEvent] - i_mqtt_WemosMiniAkku_1_Reachable changed from Online to Offline ** It's gone Online at 19:28:59 *** 2019-05-30 19:28:59.649 [vent.ItemStateChangedEvent] - i_mqtt_WemosMiniAkku_1_Reachable changed from Offline to Online 2019-05-30 19:29:17.641 [vent.ItemStateChangedEvent] - i_mqtt_WemosMiniAkku_1_Reachable changed from Online to Offline 2019-05-30 19:57:34.572 [vent.ItemStateChangedEvent] - i_mqtt_WemosMiniAkku_1_Reachable changed from Offline to Online 2019-05-30 19:57:43.348 [vent.ItemStateChangedEvent] - i_mqtt_WemosMiniAkku_1_Reachable changed from Online to Offline 2019-05-30 20:26:11.344 [vent.ItemStateChangedEvent] - i_mqtt_WemosMiniAkku_1_Reachable changed from Offline to Online 2019-05-30 20:26:29.591 [vent.ItemStateChangedEvent] - i_mqtt_WemosMiniAkku_1_Reachable changed from Online to Offline 2019-05-30 20:54:43.949 [vent.ItemStateChangedEvent] - i_mqtt_WemosMiniAkku_1_Reachable changed from Offline to Online

helmar74 commented 5 years ago

Here's the log of my Openhab System during failure:

2019-05-30 19:28:59.649 [vent.ItemStateChangedEvent] - i_mqtt_WemosMiniAkku_1_Reachable changed from Offline to Online 2019-05-30 19:29:00.683 [ome.event.ItemCommandEvent] - Item 'i_mqtt_WemosMiniAkku_Backlog' received command status 10 2019-05-30 19:29:00.687 [nt.ItemStatePredictedEvent] - i_mqtt_WemosMiniAkku_Backlog predicted to become status 10 2019-05-30 19:29:02.504 [vent.ItemStateChangedEvent] - i_mqtt_WemosMiniAkku_1_Status changed from {"DeepSleep":"1800 (1800)"} to {"Module":"Generic","Version":"6.5.0.3 stb-1.4(sonoff)","FallbackTopic":"cmnd/WemosMiniAkku-1_fb/","GroupTopic":"sonoffAkkuGruppe"} 2019-05-30 19:29:02.523 [vent.ItemStateChangedEvent] - i_mqtt_WemosMiniAkku_1_Status changed from {"Module":"Generic","Version":"6.5.0.3 stb-1.4(sonoff)","FallbackTopic":"cmnd/WemosMiniAkku-1_fb/","GroupTopic":"sonoffAkkuGruppe"} to {"POWER":"ON"} 2019-05-30 19:29:02.813 [vent.ItemStateChangedEvent] - i_mqtt_WemosMiniAkku_1_Status changed from {"POWER":"ON"} to {"DeepSleep":"1800 (1800)"} 2019-05-30 19:29:17.641 [vent.ItemStateChangedEvent] - i_mqtt_WemosMiniAkku_1_Reachable changed from Online to Offline

helmar74 commented 5 years ago

... and here a log of an "working" example: 2019-05-30 20:26:11.344 [vent.ItemStateChangedEvent] - i_mqtt_WemosMiniAkku_1_Reachable changed from Offline to Online 2019-05-30 20:26:11.430 [vent.ItemStateChangedEvent] - i_mqtt_WemosMiniAkku_1_Status changed from {"DeepSleep":"1800 (1800)"} to {"Module":"Generic","Version":"6.5.0.3 stb-1.4(sonoff)","FallbackTopic":"cmnd/WemosMiniAkku-1_fb/","GroupTopic":"sonoffAkkuGruppe"} 2019-05-30 20:26:11.436 [vent.ItemStateChangedEvent] - i_mqtt_WemosMiniAkku_1_Status changed from {"Module":"Generic","Version":"6.5.0.3 stb-1.4(sonoff)","FallbackTopic":"cmnd/WemosMiniAkku-1_fb/","GroupTopic":"sonoffAkkuGruppe"} to {"POWER":"ON"} 2019-05-30 20:26:12.371 [ome.event.ItemCommandEvent] - Item 'i_mqtt_WemosMiniAkku_Backlog' received command status 10 2019-05-30 20:26:12.386 [nt.ItemStatePredictedEvent] - i_mqtt_WemosMiniAkku_Backlog predicted to become status 10 2019-05-30 20:26:14.620 [vent.ItemStateChangedEvent] - i_mqtt_WemosMiniAkku_1_Status changed from {"POWER":"ON"} to {"DeepSleep":"1800 (1800)"} 2019-05-30 20:26:14.690 [vent.ItemStateChangedEvent] - i_mqtt_WemosMiniAkku_1_Temperatur changed from 15.1 to 15.0 2019-05-30 20:26:14.699 [vent.ItemStateChangedEvent] - i_mqtt_WemosMiniAkku_1_Volt changed from 1002 to 1003 2019-05-30 20:26:29.591 [vent.ItemStateChangedEvent] - i_mqtt_WemosMiniAkku_1_Reachable changed from Online to Offline

stefanbode commented 5 years ago

Unbelievable... It really looks like everything is ok and connected. just the Temperature did not arrive. Also the MQTT seems still working because you get the OFFLINE after all. Otherwise, the OFFLINE must be a timed out. All in all really strange. Let me dig into the code and check If I can imagine what happens.

helmar74 commented 5 years ago

Thank you! Just for information, the following "sensors" are connected: Tasmota_Wemos_Mini_Akku_1_GPIOs

... And a analog value of the battery is measured on ADC0

stefanbode commented 5 years ago

The sensor cannot be the issue. It seems to have something to do with teleperiod and the initialization. I added one additional check and uploaded. maybe you can give it a try. just a minor change. I now additionally check before deepsleep, that the prep was called and that the sensor send was executed. Worst thing that could happen is that I break the deepsleep and the device stay awake in some situations.

stefanbode commented 5 years ago

Anyhow the issue is complicated because it seems to have its oot cause in special timing conditions that might relate how fast it connects to the WLAN and get the correct time from the NTP server.

helmar74 commented 5 years ago

Got an compile error: image

Here's the error: Arduino: 1.8.9 (Windows 10), Board: "Generic ESP8266 Module, 80 MHz, Flash, Disabled, ck, 26 MHz, 40MHz, DOUT (compatible), 1M (no SPIFFS), 2, v2 Higher Bandwidth (no features), Disabled, None, Only Sketch, 115200"

c:\temp\13_SONOFF_Tasmota\04_SonoffAkku\sonoffAkku\sonoffAkku.ino: In function 'void PerformEverySecond()':

sonoffAkku:2004:114: error: lvalue required as left operand of assignment

   if (Settings.deepsleep > 10 && Settings.deepsleep < 4294967295 && !disbale_deepsleep_switch && tele_period = 0 && prep_called == 1 ) {

                                                                                                              ^

c:\temp\13_SONOFF_Tasmota\04_SonoffAkku\sonoffAkku\settings.ino: In function 'void SettingsDefaultSet2()':

settings:703:22: error: 'APP_LEDMASK' was not declared in this scope

Settings.ledmask = APP_LEDMASK;

                  ^

c:\temp\13_SONOFF_Tasmota\04_SonoffAkku\sonoffAkku\settings.ino: In function 'void SettingsDelta()':

settings:1175:26: error: 'APP_LEDMASK' was not declared in this scope

   Settings.ledmask = APP_LEDMASK;

                      ^

Mehrere Bibliotheken wurden für "TasmotaSerial.h" gefunden Benutzt: D:\Users\USER\Desktop\arduino-1.8.9_Tasmota_250_Akku_250\portable\sketchbook\libraries\TasmotaSerial-2.3.1 Nicht benutzt: D:\Users\USER\Desktop\arduino-1.8.9_Tasmota_250_Akku_250\portable\sketchbook\libraries\TasmotaSerial-2.3.0 Nicht benutzt: D:\Users\USER\Desktop\arduino-1.8.9_Tasmota_250_Akku_250\portable\sketchbook\libraries\TasmotaSerial-2.2.0 Mehrere Bibliotheken wurden für "Adafruit_SGP30.h" gefunden Benutzt: D:\Users\USER\Desktop\arduino-1.8.9_Tasmota_250_Akku_250\portable\sketchbook\libraries\Adafruit_SGP30-1.0.3 Nicht benutzt: D:\Users\USER\Desktop\arduino-1.8.9_Tasmota_250_Akku_250\portable\sketchbook\libraries\Adafruit_SGP30-1.0.0.13 Mehrere Bibliotheken wurden für "ArduinoJson.h" gefunden Benutzt: D:\Users\USER\Desktop\arduino-1.8.9_Tasmota_250_Akku_250\portable\sketchbook\libraries\ArduinoJson-5.13.4 Nicht benutzt: D:\Users\USER\Desktop\arduino-1.8.9_Tasmota_250_Akku_250\portable\sketchbook\libraries\ArduinoJson-5.11.2 exit status 1 lvalue required as left operand of assignment

Dieser Bericht wäre detaillierter, wenn die Option "Ausführliche Ausgabe während der Kompilierung" in Datei -> Voreinstellungen aktiviert wäre.

stefanbode commented 5 years ago

All fine, just a copy&paste error. IF statement always with == and not =

helmar74 commented 5 years ago

I changed line 2004 in sonoff.ino to: && tele_period == 0 && prep_called == 1

(double == after tele_period).

Now I "only" get this error: Arduino: 1.8.9 (Windows 10), Board: "Generic ESP8266 Module, 80 MHz, Flash, Disabled, ck, 26 MHz, 40MHz, DOUT (compatible), 1M (no SPIFFS), 2, v2 Higher Bandwidth (no features), Disabled, None, Only Sketch, 115200"

c:\temp\13_SONOFF_Tasmota\04_SonoffAkku\sonoffAkku\settings.ino: In function 'void SettingsDefaultSet2()':

settings:703:22: error: 'APP_LEDMASK' was not declared in this scope

Settings.ledmask = APP_LEDMASK;

                  ^

c:\temp\13_SONOFF_Tasmota\04_SonoffAkku\sonoffAkku\settings.ino: In function 'void SettingsDelta()':

settings:1175:26: error: 'APP_LEDMASK' was not declared in this scope

   Settings.ledmask = APP_LEDMASK;

                      ^

exit status 1 'APP_LEDMASK' was not declared in this scope

Dieser Bericht wäre detaillierter, wenn die Option "Ausführliche Ausgabe während der Kompilierung" in Datei -> Voreinstellungen aktiviert wäre.

stefanbode commented 5 years ago

Maybe you just download the actual version. It compiles great at my side. I assume you accidentally delete something

helmar74 commented 5 years ago

Worked for me also, I accidentally used a my_user_config.h from "older" version

helmar74 commented 5 years ago

I upgraded to Version 6.6.0.1 (with Core 2.5.2) Will paste results after running a few days. What I found out so far: My SR04 Ultrasonic sensor reported about 20cm with old version (6.5.0.3-stb-1.4). Now the distance is reported 2cm, which is wrong...

stefanbode commented 5 years ago

Can you do me a favor and open this in the main TASMOTA branch because I do not own this code anymore and therefore feel not responsible for any changes.