MaxPower/MaxPowerHold/MaxPowerWindow doesn't work any more (>6.6.0)

[MiGeppert]

PROBLEM DESCRIPTION

A clear and concise description of what the problem is.
MaxPower/MaxPowerHold/MaxpowerWindow does not work as expected.
Tasmota switches off one time and on one time, then never switches off (though "OFF" can be seen in the main menu)

REQUESTED INFORMATION

Make sure your have performed every step and checked the applicable boxes before submitting your issue. Thank you!

• Read the Contributing Guide and Policy and the Code of Conduct
• Searched the problem in issues
• Searched the problem in the docs
• Searched the problem in the forum
• Searched the problem in the chat
• Device used (e.g., Sonoff Basic): Blitzwolf BW-SHP6
• Tasmota binary firmware version number used: 8.1.0 (7.2.0 and 7.1.0)
  • Pre-compiled
  • Self-compiled
    • IDE / Compiler used: _____
• Flashing tools used: OTA
• Provide the output of command: Backlog Template; Module; GPIO 255:

01:31:35 RSL: RESULT = {"NAME":"Generic","GPIO":[255,255,255,255,255,255,255,255,255,255,255,255,255],"FLAG":15,"BASE":18}
01:31:35 RSL: RESULT = {"Module":{"45":"BlitzWolf SHP"}}
01:31:35 RSL: RESULT = {"GPIO0":{"56":"Led1i"},"GPIO1":{"0":"None"},"GPIO2":{"158":"LedLinki"},"GPIO3":{"0":"None"},"GPIO4":{"0":"None"},"GPIO5":{"134":"BL0937 CF"},"GPIO9":{"0":"None"},"GPIO10":{"0":"None"},"GPIO12":{"131":"HLWBL SELi"},"GPIO13":{"17":"Button1"},"GPIO14":{"132":"HLWBL CF1"},"GPIO15":{"21":"Relay1"},"GPIO16":{"0":"None"}}

• If using rules, provide the output of this command: Backlog Rule1; Rule2; Rule3:

  Rules output here:

• Provide the output of this command: Status 0:

01:33:15 RSL: STATUS = {"Status":{"Module":45,"FriendlyName":["Blitzwolf_2"],"Topic":"sonoff","ButtonTopic":"0","Power":0,"PowerOnState":3,"LedState":0,"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}}
01:33:15 RSL: STATUS1 = {"StatusPRM":{"Baudrate":115200,"GroupTopic":"sonoffs","OtaUrl":"http://thehackbox.org/tasmota/release/tasmota-DE.bin","RestartReason":"Software/System restart","Uptime":"0T01:33:16","StartupUTC":"","Sleep":50,"CfgHolder":4617,"BootCount":3,"SaveCount":27,"SaveAddress":"F9000"}}
01:33:15 RSL: STATUS2 = {"StatusFWR":{"Version":"7.1.0(tasmota)","BuildDateTime":"2019.11.29 15:44:57","Boot":31,"Core":"2_6_1","SDK":"2.2.2-dev(38a443e)","Hardware":"ESP8266EX"}}
01:33:15 RSL: STATUS3 = {"StatusLOG":{"SerialLog":2,"WebLog":2,"MqttLog":0,"SysLog":0,"LogHost":"","LogPort":514,"SSId":["SaHiCo2","SaHiCo"],"TelePeriod":300,"Resolution":"558180C0","SetOption":["00008001","280AC8000100060000005AFF000000000000","00000000","00000000"]}}
01:33:15 RSL: STATUS4 = {"StatusMEM":{"ProgramSize":563,"Free":440,"Heap":28,"ProgramFlashSize":1024,"FlashSize":1024,"FlashChipId":"144068","FlashMode":3,"Features":["00000407","8FDAE397","043683A0","22B617CD","01001BC0","00007881"],"Drivers":"1,2,3,4,5,6,7,8,9,10,12,16,18,19,20,21,22,24,26,29","Sensors":"1,2,3,4,5,6,7,8,9,10,14,15,17,18,20,22,26,34"}}
01:33:15 RSL: STATUS5 = {"StatusNET":{"Hostname":"Blitzwolf_2","IPAddress":"192.168.2.124","Gateway":"192.168.2.252","Subnetmask":"255.255.255.0","DNSServer":"192.168.2.4","Mac":"CC:50:E3:37:65:68","Webserver":2,"WifiConfig":4}}
01:33:15 RSL: STATUS7 = {"StatusTIM":{"UTC":"Thu Jan 01 01:33:15 1970","Local":"Thu Jan 01 01:33:15 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"}}
01:33:15 RSL: STATUS9 = {"StatusPTH":{"PowerDelta":0,"PowerLow":0,"PowerHigh":0,"VoltageLow":0,"VoltageHigh":0,"CurrentLow":0,"CurrentHigh":0}}
01:33:15 RSL: STATUS10 = {"StatusSNS":{"Time":"1970-01-01T01:33:15","ENERGY":{"TotalStartTime":"2019-08-16T14:31:47","Total":0.043,"Yesterday":0.009,"Today":0.043,"Power":0,"ApparentPower":0,"ReactivePower":0,"Factor":0.00,"Voltage":0,"Current":0.000}}}
01:33:15 RSL: STATUS11 = {"StatusSTS":{"Time":"1970-01-01T01:33:15","Uptime":"0T01:33:16","UptimeSec":5596,"Heap":28,"SleepMode":"Dynamic","Sleep":50,"LoadAvg":19,"MqttCount":0,"POWER":"OFF","Wifi":{"AP":1,"SSId":"SaHiCo2","BSSId":"DC:39:6F:DF:23:1E","Channel":11,"RSSI":64,"LinkCount":1,"Downtime":"0T00:00:06"}}}

• Provide the output of the Console log output when you experience your issue; if applicable:
  (Please use weblog 4 for more debug information)

01:39:45 RSL: RESULT = {"POWER":"ON"}
01:39:45 RSL: POWER = ON
01:39:45 CFG: in Flash gespeichert am F4, zählen 32, Bytes 4096
01:39:47 HTP: Konsole
01:39:50 WIF: Prüfe Verbindung...
01:39:50 WIF: verbunden
01:39:50 RSL: WARNING = {"Time":"1970-01-01T01:39:50","MaxPowerReached":39}
01:39:50 RSL: SENSOR = {"Time":"1970-01-01T01:39:50","ENERGY":{"TotalStartTime":"2019-08-16T14:31:47","Total":0.048,"Yesterday":0.009,"Today":0.048,"Power":39,"ApparentPower":41,"ReactivePower":12,"Factor":0.95,"Voltage":233,"Current":0.176}}
01:39:50 SRC: MaxPower
01:39:50 RSL: RESULT = {"POWER":"OFF"}
01:39:50 RSL: POWER = OFF
01:39:50 CFG: in Flash gespeichert am FB, zählen 33, Bytes 4096
01:39:56 RSL: RESULT = {"Time":"1970-01-01T01:39:56","PowerMonitor":"ON"}
01:39:56 SRC: MaxPower
01:39:56 RSL: RESULT = {"POWER":"OFF"}
01:39:56 RSL: POWER = OFF
01:39:59 RSL: RESULT = {"Time":"1970-01-01T01:39:59","PowerMonitor":"ON"}
01:39:59 SRC: MaxPower
01:39:59 RSL: RESULT = {"POWER":"OFF"}
01:39:59 RSL: POWER = OFF
01:40:02 RSL: RESULT = {"Time":"1970-01-01T01:40:02","PowerMonitor":"ON"}
01:40:02 SRC: MaxPower
01:40:02 RSL: RESULT = {"POWER":"OFF"}
01:40:02 RSL: POWER = OFF
01:40:05 RSL: WARNING = {"Time":"1970-01-01T01:40:05","MaxPowerReachedRetry":"OFF"}
01:40:05 RSL: SENSOR = {"Time":"1970-01-01T01:40:05","ENERGY":{"TotalStartTime":"2019-08-16T14:31:47","Total":0.048,"Yesterday":0.009,"Today":0.048,"Power":0,"ApparentPower":0,"ReactivePower":0,"Factor":0.00,"Voltage":0,"Current":0.000}}
01:40:09 RSL: STATE = {"Time":"1970-01-01T01:40:09","Uptime":"0T01:40:11","UptimeSec":6011,"Heap":28,"SleepMode":"Dynamic","Sleep":50,"LoadAvg":34,"MqttCount":0,"POWER":"OFF","Wifi":{"AP":1,"SSId":"SaHiCo2","BSSId":"DC:39:6F:DF:23:1E","Channel":11,"RSSI":66,"LinkCount":1,"Downtime":"0T00:00:06"}}
01:40:09 RSL: SENSOR = {"Time":"1970-01-01T01:40:09","ENERGY":{"TotalStartTime":"2019-08-16T14:31:47","Total":0.048,"Yesterday":0.009,"Today":0.048,"Period":3,"Power":0,"ApparentPower":0,"ReactivePower":0,"Factor":0.00,"Voltage":0,"Current":0.000}}
01:40:10 WIF: Prüfe Verbindung...
01:40:10 WIF: verbunden

TO REPRODUCE

Steps to reproduce the behavior:
MaxPower 20 (e.g. for test with 40W bulb)
MaxPowerHold 3
MaxPowerWindows 4
(SetOption33 3) (also tried with "10")
(by the way: description of SetOption33 is wrong in description https://github.com/arendst/Tasmota/wiki/commands#SetOption33, isn't it?)

EXPECTED BEHAVIOUR

A clear and concise description of what you expected to happen.
Light on - after 3 seconds: light off - after 4 seconds: light on - after 3 seconds: light off - ...
(and so on - "SetOption33" times)

SCREENSHOTS

If applicable, add screenshots to help explain your problem.

ADDITIONAL CONTEXT

Add any other context about the problem here.
Found the problem in 8.1.0, then downgraded to 7.2.0 and 7.1.0, problem persists.
I'm afraid of downgrading any further :-)

(Please, remember to close the issue when the problem has been addressed)

[Jason2866]

You need a correct time and date. Without many functions in Tasmota dont work.

[MiGeppert]

Yes, you are right - there is a time "mismatch"!
I tried for one hour to get NTP working - without success. I have no idea what's going wrong.
Nevertheless - with "time 1580674958" I managed to set current time/date on the device.

But the problem still persists!

Note: I made my tests on my "backup Blitzwolf", the "productive one" is attached to a pump (which hangs from time to time). There the time is set "almost" correct, it differs for about 2.5 minutes, and has the same problem.
I never needed to deal with time/date setting on my Tasmota-devices, all worked out of the box, except of this Blitzwolf device.

[MiGeppert]

I found a (bad) workaround - works in my case, but isn't really good:
If I use "SetOption21 1" (Energy monitoring when power is off), the device will switch off again (and on later), but then there is an endless loop (MaxPowerReachedRetry is ignored).

[dhottinger]

I've observed the same thing in v6.7.1 (correct time). I think the problem is that RestorePower()1 does not update power. It just turns the relay back on. From that point on power and the relay are out of sync. Tasmota keeps trying to switch on power (despite the relay being on) until retries are exceeded.

Also when max retries are reached 2 Tasmota only publishes an MQTT message (because the code block is executed only if !power. It might be better to explicitly turn off power again (fail safe).

[MiGeppert]

Small update:
I dared to downgrade to 6.6.0 (from 7.1.0) via OTA - bad mistake!

DON'T DO THAT!!!!!

The internal website was not available any more, no chance to (re)flash, update, reset to factory.
So I needed to flash/reset via wired connection.

Now, 6.6.0 is working again, and there, the problem does not exist!

I will not go any further to 6.6.0+ (as long as nobody wants it) and wait for version >8.1.0 with correction.

[Jason2866]

@MiGeppert yes, there is a upgrade way for Tasmota. Downgrade was never supported.

[MiGeppert]

@Jason2866: correct, but to test at which version it works I had to downgrade. And I knew it worked prior to my "big upgrade" to 8.1.0.
Anyway, the downgrade worked fine from 8.1.0 to 7.2.0 to 7.1.0.

[Jason2866]

Reason for is SetOptions do change. Doing upgrades this changed SetOptions are "translated" to the
new format or way it is done. With downgrading you have unexpected values for.
Could work, but strange issues or errors can occur. So it seems! to work.
Anyway i will do a test setup the next days for for the described case.

[ascillato]

@MiGeppert

Hi, can you test latest Tasmota version, please? A fix has been added by Theo to the latest codebase. Thanks

[MiGeppert]

Hi

I compiled version 8.1.0.6 with Gitpod (thank you very much for the good and foolproof documentation!!!)

MaxPower feature works now as expected!

Thank you very much for the fast support/repair and the brilliant Tasmota software!!!!!

Best regards
MiGeppert

[dhottinger]

Confirmed working. MQTT logs below. Thanks for the quick fix!

$ mosquitto_sub -h mqtt -v -F '%I [q:%q r:%r] \e[92m%t \e[96m%p\e[0m' -t '+/compressor/+'
2020-02-10T18:57:19+0100 [q:0 r:1] tele/compressor/LWT Online
2020-02-10T18:57:21+0100 [q:0 r:0] cmnd/compressor/Power toggle
2020-02-10T18:57:21+0100 [q:0 r:0] stat/compressor/RESULT {"POWER":"ON"}
2020-02-10T18:57:21+0100 [q:0 r:0] stat/compressor/POWER ON
2020-02-10T18:57:34+0100 [q:0 r:0] stat/compressor/WARNING {"Time":"2020-02-10T18:57:33","MaxPowerReached":434}
2020-02-10T18:57:34+0100 [q:0 r:0] tele/compressor/SENSOR {"Time":"2020-02-10T18:57:33","ENERGY":{"TotalStartTime":"2019-12-13T13:36:58","Total":0.006,"Yesterday":0.000,"Today":0.006,"Power":435,"ApparentPower":536,"ReactivePower":314,"Factor":0.81,"Voltage":234,"Current":2.288}}
2020-02-10T18:57:34+0100 [q:0 r:0] stat/compressor/RESULT {"POWER":"OFF"}
2020-02-10T18:57:34+0100 [q:0 r:0] stat/compressor/POWER OFF
2020-02-10T18:58:06+0100 [q:0 r:0] stat/compressor/RESULT {"Time":"2020-02-10T18:58:05","PowerMonitor":"ON"}
2020-02-10T18:58:06+0100 [q:0 r:0] stat/compressor/RESULT {"POWER":"ON"}
2020-02-10T18:58:06+0100 [q:0 r:0] stat/compressor/POWER ON
2020-02-10T18:58:19+0100 [q:0 r:0] stat/compressor/WARNING {"Time":"2020-02-10T18:58:18","MaxPowerReached":432}
2020-02-10T18:58:19+0100 [q:0 r:0] tele/compressor/SENSOR {"Time":"2020-02-10T18:58:18","ENERGY":{"TotalStartTime":"2019-12-13T13:36:58","Total":0.008,"Yesterday":0.000,"Today":0.008,"Power":432,"ApparentPower":533,"ReactivePower":311,"Factor":0.81,"Voltage":234,"Current":2.280}}
2020-02-10T18:58:19+0100 [q:0 r:0] stat/compressor/RESULT {"POWER":"OFF"}
2020-02-10T18:58:19+0100 [q:0 r:0] stat/compressor/POWER OFF
2020-02-10T18:58:51+0100 [q:0 r:0] stat/compressor/RESULT {"Time":"2020-02-10T18:58:50","PowerMonitor":"ON"}
2020-02-10T18:58:51+0100 [q:0 r:0] stat/compressor/RESULT {"POWER":"ON"}
2020-02-10T18:58:51+0100 [q:0 r:0] stat/compressor/POWER ON
2020-02-10T18:59:04+0100 [q:0 r:0] stat/compressor/WARNING {"Time":"2020-02-10T18:59:03","MaxPowerReached":430}
2020-02-10T18:59:04+0100 [q:0 r:0] tele/compressor/SENSOR {"Time":"2020-02-10T18:59:03","ENERGY":{"TotalStartTime":"2019-12-13T13:36:58","Total":0.010,"Yesterday":0.000,"Today":0.010,"Power":430,"ApparentPower":534,"ReactivePower":316,"Factor":0.81,"Voltage":235,"Current":2.275}}
2020-02-10T18:59:04+0100 [q:0 r:0] stat/compressor/RESULT {"POWER":"OFF"}
2020-02-10T18:59:04+0100 [q:0 r:0] stat/compressor/POWER OFF
2020-02-10T18:59:36+0100 [q:0 r:0] stat/compressor/RESULT {"Time":"2020-02-10T18:59:35","PowerMonitor":"ON"}
2020-02-10T18:59:36+0100 [q:0 r:0] stat/compressor/RESULT {"POWER":"ON"}
2020-02-10T18:59:36+0100 [q:0 r:0] stat/compressor/POWER ON
2020-02-10T18:59:49+0100 [q:0 r:0] stat/compressor/WARNING {"Time":"2020-02-10T18:59:48","MaxPowerReached":428}
2020-02-10T18:59:49+0100 [q:0 r:0] tele/compressor/SENSOR {"Time":"2020-02-10T18:59:48","ENERGY":{"TotalStartTime":"2019-12-13T13:36:58","Total":0.012,"Yesterday":0.000,"Today":0.012,"Power":429,"ApparentPower":532,"ReactivePower":314,"Factor":0.81,"Voltage":234,"Current":2.269}}
2020-02-10T18:59:49+0100 [q:0 r:0] stat/compressor/RESULT {"POWER":"OFF"}
2020-02-10T18:59:49+0100 [q:0 r:0] stat/compressor/POWER OFF
2020-02-10T19:00:21+0100 [q:0 r:0] stat/compressor/RESULT {"Time":"2020-02-10T19:00:20","PowerMonitor":"ON"}
2020-02-10T19:00:21+0100 [q:0 r:0] stat/compressor/RESULT {"POWER":"ON"}
2020-02-10T19:00:21+0100 [q:0 r:0] stat/compressor/POWER ON
2020-02-10T19:00:34+0100 [q:0 r:0] stat/compressor/WARNING {"Time":"2020-02-10T19:00:33","MaxPowerReached":428}
2020-02-10T19:00:34+0100 [q:0 r:0] tele/compressor/SENSOR {"Time":"2020-02-10T19:00:33","ENERGY":{"TotalStartTime":"2019-12-13T13:36:58","Total":0.014,"Yesterday":0.000,"Today":0.014,"Power":429,"ApparentPower":534,"ReactivePower":318,"Factor":0.80,"Voltage":234,"Current":2.278}}
2020-02-10T19:00:34+0100 [q:0 r:0] stat/compressor/RESULT {"POWER":"OFF"}
2020-02-10T19:00:34+0100 [q:0 r:0] stat/compressor/POWER OFF
2020-02-10T19:01:06+0100 [q:0 r:0] stat/compressor/RESULT {"Time":"2020-02-10T19:01:05","PowerMonitor":"ON"}
2020-02-10T19:01:06+0100 [q:0 r:0] stat/compressor/RESULT {"POWER":"ON"}
2020-02-10T19:01:06+0100 [q:0 r:0] stat/compressor/POWER ON
2020-02-10T19:01:19+0100 [q:0 r:0] stat/compressor/WARNING {"Time":"2020-02-10T19:01:18","MaxPowerReached":427}
2020-02-10T19:01:19+0100 [q:0 r:0] tele/compressor/SENSOR {"Time":"2020-02-10T19:01:18","ENERGY":{"TotalStartTime":"2019-12-13T13:36:58","Total":0.016,"Yesterday":0.000,"Today":0.016,"Power":428,"ApparentPower":529,"ReactivePower":311,"Factor":0.81,"Voltage":233,"Current":2.267}}
2020-02-10T19:01:19+0100 [q:0 r:0] stat/compressor/RESULT {"POWER":"OFF"}
2020-02-10T19:01:19+0100 [q:0 r:0] stat/compressor/POWER OFF
2020-02-10T19:01:51+0100 [q:0 r:0] stat/compressor/WARNING {"Time":"2020-02-10T19:01:50","MaxPowerReachedRetry":"OFF"}
2020-02-10T19:01:51+0100 [q:0 r:0] tele/compressor/SENSOR {"Time":"2020-02-10T19:01:50","ENERGY":{"TotalStartTime":"2019-12-13T13:36:58","Total":0.016,"Yesterday":0.000,"Today":0.016,"Power":0,"ApparentPower":0,"ReactivePower":0,"Factor":0.00,"Voltage":0,"Current":0.000}}
2020-02-10T19:01:51+0100 [q:0 r:0] stat/compressor/RESULT {"POWER":"OFF"}
2020-02-10T19:01:51+0100 [q:0 r:0] stat/compressor/POWER OFF
2020-02-10T19:01:55+0100 [q:0 r:0] tele/compressor/STATE [...]
2020-02-10T19:01:55+0100 [q:0 r:0] tele/compressor/SENSOR {"Time":"2020-02-10T19:01:54","ENERGY":{"TotalStartTime":"2019-12-13T13:36:58","Total":0.016,"Yesterday":0.000,"Today":0.016,"Period":12,"Power":0,"ApparentPower":0,"ReactivePower":0,"Factor":0.00,"Voltage":0,"Current":0.000}}