LoadAvg increases to 100% on Dimmer devices

rbswift commented 3 years ago

PROBLEM DESCRIPTION

A clear and concise description of what the problem is. On various Tasmota flashed devices using the Dimmer functionality, the LoadAvg either gradually or abruptly increases to 99% or 100%.

REQUESTED INFORMATION

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

[x] Read the Contributing Guide and Policy and the Code of Conduct
[x] Searched the problem in issues
[x] Searched the problem in discussions
[x] Searched the problem in the docs
[x] Searched the problem in the chat
[x] Device used (e.g., Sonoff Basic): MagicHome LED controller, Shelly Dimmer 1, Arlec Bulb 4W
[x] Tasmota binary firmware version number used: 9.5.0
- [x] Pre-compiled
- [ ] Self-compiled
[x] Flashing tools used: tuyaconvert, flashesp8266

[ ] Provide the output of command: Backlog Template; Module; GPIO 255:


Configuration output here:
04:41:14.821 MQT: stat/loungestep/RESULT = {"NAME":"MagicHome","GPIO":[0,0,0,0,0,0,0,0,416,0,0,0,0,0],"FLAG":0,"BASE":18}
04:41:15.022 MQT: stat/loungestep/RESULT = {"Module":{"0":"MagicHome"}}
04:41:15.235 MQT: stat/loungestep/RESULT = {"GPIO0":{"0":"None"},"GPIO1":{"0":"None"},"GPIO2":{"0":"None"},"GPIO3":{"0":"None"},"GPIO4":{"0":"None"},"GPIO5":{"0":"None"},"GPIO9":{"0":"None"},"GPIO10":{"0":"None"},"GPIO12":{"416":"PWM1"},"GPIO13":{"0":"None"},"GPIO14":{"0":"None"},"GPIO15":{"0":"None"},"GPIO16":{"0":"None"},"GPIO17":{"0":"None"}}

- [ ] If using rules, provide the output of this command: `Backlog Rule1; Rule2; Rule3`:
```lua
  Rules output here:
04:41:42.406 MQT: stat/loungestep/RESULT = {"Rule1":{"State":"OFF","Once":"OFF","StopOnError":"OFF","Length":0,"Free":511,"Rules":""}}
04:41:42.608 MQT: stat/loungestep/RESULT = {"Rule2":{"State":"OFF","Once":"OFF","StopOnError":"OFF","Length":0,"Free":511,"Rules":""}}
04:41:42.819 MQT: stat/loungestep/RESULT = {"Rule3":{"State":"OFF","Once":"OFF","StopOnError":"OFF","Length":0,"Free":511,"Rules":""}}

[ ] Provide the output of this command: Status 0:


STATUS 0 output here:
04:42:02.017 MQT: stat/loungestep/STATUS = {"Status":{"Module":0,"DeviceName":"Lounge Step","FriendlyName":["Lounge Step"],"Topic":"loungestep","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,"InfoRetain":0,"StateRetain":0}}
04:42:02.024 MQT: stat/loungestep/STATUS1 = {"StatusPRM":{"Baudrate":115200,"SerialConfig":"8N1","GroupTopic":"tasmotas","OtaUrl":"http://ota.tasmota.com/tasmota/release/tasmota.bin.gz","RestartReason":"Software/System restart","Uptime":"52T13:46:44","StartupUTC":"2021-08-14T13:55:18","Sleep":50,"CfgHolder":4617,"BootCount":40,"BCResetTime":"2020-08-28T05:22:51","SaveCount":90821,"SaveAddress":"F8000"}}
04:42:02.034 MQT: stat/loungestep/STATUS2 = {"StatusFWR":{"Version":"9.5.0(TasmoCompiler-esp8266generic)","BuildDateTime":"2021-08-10T02:04:19","Boot":7,"Core":"2_7_4_9","SDK":"2.2.2-dev(38a443e)","CpuFrequency":80,"Hardware":"ESP8266EX","CR":"442/699"}}
04:42:02.040 MQT: stat/loungestep/STATUS3 = {"StatusLOG":{"SerialLog":2,"WebLog":2,"MqttLog":0,"SysLog":0,"LogHost":"","LogPort":514,"SSId":["Teh Interwebz",""],"TelePeriod":300,"Resolution":"558180C0","SetOption":["00008009","2805C8000100060000005AFF000000000000","000000E0","00006000","00000008"]}}
04:42:02.052 MQT: stat/loungestep/STATUS4 = {"StatusMEM":{"ProgramSize":544,"Free":456,"Heap":26,"ProgramFlashSize":1024,"FlashSize":2048,"FlashChipId":"1540A1","FlashFrequency":40,"FlashMode":3,"Features":["00000809","0F806592","04260001","00000003","00000000","C000E981","00000004","00001000","00000000"],"Drivers":"1,2,4,6,8,9,10,18,19,22,24,26,27,29,30,35,37,45","Sensors":"1,2"}}
04:42:02.059 MQT: stat/loungestep/STATUS5 = {"StatusNET":{"Hostname":"loungestep","IPAddress":"192.168.188.24","Gateway":"192.168.188.1","Subnetmask":"255.255.255.0","DNSServer":"192.168.188.1","Mac":"D8:F1:5B:F6:C2:23","Webserver":2,"WifiConfig":4,"WifiPower":17.0}}
04:42:02.066 MQT: stat/loungestep/STATUS6 = {"StatusMQT":{"MqttHost":"192.168.188.12","MqttPort":1883,"MqttClientMask":"loungestep_client","MqttClient":"loungestep_client","MqttUser":"loungestep","MqttCount":19,"MAX_PACKET_SIZE":1200,"KEEPALIVE":30,"SOCKET_TIMEOUT":4}}
04:42:02.075 MQT: stat/loungestep/STATUS7 = {"StatusTIM":{"UTC":"2021-10-06T03:42:02","Local":"2021-10-06T04:42:02","StartDST":"2021-03-28T02:00:00","EndDST":"2021-10-31T03:00:00","Timezone":"+01:00","Sunrise":"06:57","Sunset":"18:18"}}
04:42:02.082 MQT: stat/loungestep/STATUS10 = {"StatusSNS":{"Time":"2021-10-06T04:42:02"}}
04:42:02.091 MQT: stat/loungestep/STATUS11 = {"StatusSTS":{"Time":"2021-10-06T04:42:02","Uptime":"52T13:46:44","UptimeSec":4542404,"Heap":26,"SleepMode":"Dynamic","Sleep":10,"LoadAvg":99,"MqttCount":19,"POWER":"ON","Dimmer":100,"Fade":"ON","Speed":10,"LedTable":"OFF","Wifi":{"AP":1,"SSId":"Teh Interwebz","BSSId":"08:96:D7:8A:94:84","Channel":1,"Mode":"11n","RSSI":100,"Signal":-45,"LinkCount":12,"Downtime":"0T00:19:23"}}}

- [ ] Set `weblog` to 4 and then, when you experience your issue, provide the output of the Console log:
```lua
  Console output here:
04:42:45.536 SRC: WebConsole from 192.168.188.35
04:42:45.539 CMD: Grp 0, Cmnd 'DIMMER', Idx 1, Len 3, Data '100'
04:42:45.544 MQT: stat/loungestep/RESULT = {"POWER":"ON","Dimmer":100}
04:43:00.837 WIF: Checking connection...
04:43:20.830 WIF: Checking connection...
04:43:40.833 WIF: Checking connection...
04:44:00.833 WIF: Checking connection...
04:44:20.832 WIF: Checking connection...
04:44:40.836 WIF: Checking connection...
04:44:54.085 MQT: tele/loungestep/STATE = {"Time":"2021-10-06T04:44:54","Uptime":"52T13:49:36","UptimeSec":4542576,"Heap":28,"SleepMode":"Dynamic","Sleep":10,"LoadAvg":99,"MqttCount":19,"POWER":"ON","Dimmer":100,"Fade":"ON","Speed":10,"LedTable":"OFF","Wifi":{"AP":1,"SSId":"Teh Interwebz","BSSId":"08:96:D7:8A:94:84","Channel":1,"Mode":"11n","RSSI":100,"Signal":-44,"LinkCount":12,"Downtime":"0T00:19:23"}}

TO REPRODUCE

Steps to reproduce the behavior: Various ESP2866 devices flashed with prebuilt Tasmota. I chart the LoadAvg using Grafana. Only the dimmable devices exhibit this problem. LoadAvg on on/off (non dimmable) devices is fine. The problem happens when the output status is on. normal LoadAvg is restored when the output is switched off. See chart below for example.

EXPECTED BEHAVIOUR

A clear and concise description of what you expected to happen. Documentation indicates "it is recommended to keep your device running at a LoadAvg value of 75 or lower"

SCREENSHOTS

If applicable, add screenshots to help explain your problem.

ADDITIONAL CONTEXT

Add any other context about the problem here. I have tried various Sleep settings but haven't found anything that resolves the problem.

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

s-hadinger commented 3 years ago

This behavior is expected and normal because pwm is done in software on esp8266. We should amend the documentation.

rbswift commented 3 years ago

@s-hadinger ah OK, Thanks for clarifying. I haven't really studied how the PWM works but is it also normal to expect this when the dimmer is at 100% i.e. full brightness? And safe to allow the ESP to run at 100% LoadAvg for an extended period? i.e. no risk of overheating or something?

sfromis commented 3 years ago

LoadAvg is not CPU utilization percent, but a "more complex" number, and does not overload the processor. And yes, it is normal also at 100% PWM.

arendst / Tasmota