arendst / Tasmota

Alternative firmware for ESP8266 and ESP32 based devices with easy configuration using webUI, OTA updates, automation using timers or rules, expandability and entirely local control over MQTT, HTTP, Serial or KNX. Full documentation at
https://tasmota.github.io/docs
GNU General Public License v3.0
22.2k stars 4.81k forks source link

Roller Blind Setup not working under Tasmota 8.3.1 #8721

Closed wolfpaw98 closed 4 years ago

wolfpaw98 commented 4 years ago

PROBLEM DESCRIPTION

A clear and concise description of what the problem is.

Shutters and Blinds Example Configuration appears to be broken in 8.3.1.

A roller-blind configuration setup as shown in Tasmota documentation page “Diagram Shutters and Blinds “ diagram v412 and the associated writeup works as described under Tasmota 8.2, however, the stepper motor does not rotate with the exact same hardware and software configuration flashed with Tasmota 8.3.1. I was able to reproduce this issue using Wemos D1 Mini, Wifi Witty and nodeMCU micro-controllers. In all cases, the setup using 8.2 worked, whereas the same setup using 8.3.1 did not.

REQUESTED INFORMATION

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

Under 8.2 Console output of: Backlog Template; Module; GPIO 255

13:10:23 CMD: Backlog Template; Module; GPIO 255 13:10:23 RSL: stat/tasmota_104845/RESULT = {"NAME":"Blind","GPIO":[37,0,42,0,22,29,0,0,0,0,0,0,0],"FLAG":0,"BASE":18} 13:10:23 RSL: stat/tasmota_104845/RESULT = {"Module":{"0":"Blind"}} 13:10:24 RSL: stat/tasmota_104845/RESULT = {"GPIO0":{"37":"PWM1"},"GPIO1":{"0":"None"},"GPIO2":{"42":"Counter1"},"GPIO3":{"0":"None"},"GPIO4":{"22":"Relay2"},"GPIO5":{"29":"Relay1i"},"GPIO9":{"0":"None"},"GPIO10":{"0":"None"},"GPIO12":{"0":"None"},"GPIO13":{"0":"None"},"GPIO14":{"0":"None"},"GPIO15":{"0":"None"},"GPIO16":{"0":"None"}}

Under 8.3.1

Console output of: Backlog Template; Module; GPIO 255

13:21:05 CMD: Backlog Template; Module; GPIO 255 13:21:05 RSL: stat/tasmota_104845/RESULT = {"NAME":"Blind","GPIO":[37,0,42,0,22,29,0,0,0,0,0,0,0],"FLAG":0,"BASE":18} 13:21:05 RSL: stat/tasmota_104845/RESULT = {"Module":{"0":"Blind"}} 13:21:05 RSL: stat/tasmota_104845/RESULT = {"GPIO0":{"37":"PWM1"},"GPIO1":{"0":"None"},"GPIO2":{"42":"Counter1"},"GPIO3":{"0":"None"},"GPIO4":{"22":"Relay2"},"GPIO5":{"29":"Relay1i"},"GPIO9":{"0":"None"},"GPIO10":{"0":"None"},"GPIO12":{"0":"None"},"GPIO13":{"0":"None"},"GPIO14":{"0":"None"},"GPIO15":{"0":"None"},"GPIO16":{"0":"None"}}

- [x] If using rules, provide the output of this command: `Backlog Rule1; Rule2; Rule3`:

Rules output here:

Rules are not being used.

- [x] Provide the output of this command: `Status 0`:

STATUS 0 output here:

Under 8.2

Console output of: Status 0

13:11:38 CMD: Status 0 13:11:38 RSL: stat/tasmota_104845/STATUS = {"Status":{"Module":0,"FriendlyName":["Tasmota","Tasmota2","Tasmota3"],"Topic":"tasmota_104845","ButtonTopic":"0","Power":0,"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}} 13:11:38 RSL: stat/tasmota_104845/STATUS1 = {"StatusPRM":{"Baudrate":115200,"SerialConfig":"8N1","GroupTopic":"tasmotas","OtaUrl":"http://thehackbox.org/tasmota/release/tasmota.bin","RestartReason":"External System","Uptime":"0T00:03:37","StartupUTC":"2020-06-18T12:08:01","Sleep":50,"CfgHolder":4617,"BootCount":10,"BCResetTime":"2020-06-17T23:19:33","SaveCount":26,"SaveAddress":"FA000"}} 13:11:38 RSL: stat/tasmota_104845/STATUS2 = {"StatusFWR":{"Version":"8.2.0(tasmota)","BuildDateTime":"2020-06-17T18:17:50","Boot":31,"Core":"STAGE","SDK":"2.2.2-dev(38a443e)","Hardware":"ESP8266EX","CR":"358/699"}} 13:11:38 RSL: stat/tasmota_104845/STATUS3 = {"StatusLOG":{"SerialLog":2,"WebLog":2,"MqttLog":0,"SysLog":0,"LogHost":"","LogPort":514,"SSId":["Amigo","wireless"],"TelePeriod":300,"Resolution":"558180C0","SetOption":["00008009","2805C8000100060000005A00000000000000","40000000","00000000"]}} 13:11:38 RSL: stat/tasmota_104845/STATUS4 = {"StatusMEM":{"ProgramSize":577,"Free":424,"Heap":26,"ProgramFlashSize":4096,"FlashSize":4096,"FlashChipId":"1640E0","FlashMode":3,"Features":["00000809","8FDAE397","043683A0","000000CD","010013C0","C000F981","00000004"],"Drivers":"1,2,3,4,5,6,7,8,9,10,12,16,18,19,20,21,22,24,26,27,29,30,35,37","Sensors":"1,2,3,4,5,6"}} 13:11:38 RSL: stat/tasmota_104845/STATUS5 = {"StatusNET":{"Hostname":"tasmota_104845-2117","IPAddress":"192.168.99.59","Gateway":"192.168.99.1","Subnetmask":"255.255.255.0","DNSServer":"192.168.99.1","Mac":"5C:CF:7F:10:48:45","Webserver":2,"WifiConfig":4,"WifiPower":17.0}} 13:11:38 RSL: stat/tasmota104845/STATUS6 = {"StatusMQT":{"MqttHost":"","MqttPort":1883,"MqttClientMask":"DVES%06X","MqttClient":"DVES_104845","MqttUser":"DVES_USER","MqttCount":0,"MAX_PACKET_SIZE":1200,"KEEPALIVE":30}} 13:11:38 RSL: stat/tasmota_104845/STATUS7 = {"StatusTIM":{"UTC":"2020-06-18T12:11:38","Local":"2020-06-18T13:11:38","StartDST":"2020-03-29T02:00:00","EndDST":"2020-10-25T03:00:00","Timezone":"+01:00","Sunrise":"04:46","Sunset":"20:56"}} 13:11:38 RSL: stat/tasmota_104845/STATUS10 = {"StatusSNS":{"Time":"2020-06-18T13:11:38","COUNTER":{"C1":17052},"Shutter1":{"Position":0,"Direction":0,"Target":0}}} 13:11:38 RSL: stat/tasmota_104845/STATUS11 = {"StatusSTS":{"Time":"2020-06-18T13:11:38","Uptime":"0T00:03:37","UptimeSec":217,"Heap":26,"SleepMode":"Dynamic","Sleep":50,"LoadAvg":19,"MqttCount":0,"POWER1":"OFF","POWER2":"OFF","POWER3":"OFF","Dimmer":10,"Fade":"OFF","Speed":1,"LedTable":"ON","Wifi":{"AP":1,"SSId":"Amigo","BSSId":"CE:40:D0:6A:21:22","Channel":11,"RSSI":38,"Signal":-81,"LinkCount":1,"Downtime":"0T00:00:06"}}}

Under 8.3.1

13:22:04 CMD: Status 0 13:22:04 RSL: stat/tasmota_104845/STATUS = {"Status":{"Module":0,"DeviceName":"Tasmota","FriendlyName":["Tasmota","Tasmota2","Tasmota3"],"Topic":"tasmota_104845","ButtonTopic":"0","Power":0,"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}} 13:22:04 RSL: stat/tasmota_104845/STATUS1 = {"StatusPRM":{"Baudrate":115200,"SerialConfig":"8N1","GroupTopic":"tasmotas","OtaUrl":"http://thehackbox.org/tasmota/release/tasmota.bin","RestartReason":"Software/System restart","Uptime":"0T00:01:55","StartupUTC":"2020-06-18T12:20:09","Sleep":50,"CfgHolder":4617,"BootCount":5,"BCResetTime":"2020-06-18T13:18:07","SaveCount":14,"SaveAddress":"F6000"}} 13:22:04 RSL: stat/tasmota_104845/STATUS2 = {"StatusFWR":{"Version":"8.3.1(tasmota)","BuildDateTime":"2020-06-18T08:16:25","Boot":31,"Core":"2_7_1","SDK":"2.2.2-dev(38a443e)","Hardware":"ESP8266EX","CR":"376/699"}} 13:22:04 RSL: stat/tasmota_104845/STATUS3 = {"StatusLOG":{"SerialLog":2,"WebLog":2,"MqttLog":0,"SysLog":0,"LogHost":"","LogPort":514,"SSId":["Amigo","wireless"],"TelePeriod":300,"Resolution":"558180C0","SetOption":["00008009","2805C8000100060000005A00000000000000","40000000","00000000"]}} 13:22:04 RSL: stat/tasmota_104845/STATUS4 = {"StatusMEM":{"ProgramSize":587,"Free":416,"Heap":26,"ProgramFlashSize":4096,"FlashSize":4096,"FlashChipId":"1640E0","FlashMode":3,"Features":["00000809","8FDAE797","043683A1","000000CD","010013C0","C000F981","00000024"],"Drivers":"1,2,3,4,5,6,7,8,9,10,12,16,18,19,20,21,22,24,26,27,29,30,35,37","Sensors":"1,2,3,4,5,6"}} 13:22:04 RSL: stat/tasmota_104845/STATUS5 = {"StatusNET":{"Hostname":"tasmota_104845-2117","IPAddress":"192.168.99.59","Gateway":"192.168.99.1","Subnetmask":"255.255.255.0","DNSServer":"192.168.99.1","Mac":"5C:CF:7F:10:48:45","Webserver":2,"WifiConfig":4,"WifiPower":17.0}} 13:22:04 RSL: stat/tasmota104845/STATUS6 = {"StatusMQT":{"MqttHost":"","MqttPort":1883,"MqttClientMask":"DVES%06X","MqttClient":"DVES_104845","MqttUser":"DVES_USER","MqttCount":0,"MAX_PACKET_SIZE":1200,"KEEPALIVE":30}} 13:22:04 RSL: stat/tasmota_104845/STATUS7 = {"StatusTIM":{"UTC":"2020-06-18T12:22:04","Local":"2020-06-18T13:22:04","StartDST":"2020-03-29T02:00:00","EndDST":"2020-10-25T03:00:00","Timezone":"+01:00","Sunrise":"04:46","Sunset":"20:56"}} 13:22:04 RSL: stat/tasmota_104845/STATUS10 = {"StatusSNS":{"Time":"2020-06-18T13:22:04","COUNTER":{"C1":17052},"Shutter1":{"Position":0,"Direction":0,"Target":0}}} 13:22:04 RSL: stat/tasmota_104845/STATUS11 = {"StatusSTS":{"Time":"2020-06-18T13:22:04","Uptime":"0T00:01:55","UptimeSec":115,"Heap":26,"SleepMode":"Dynamic","Sleep":50,"LoadAvg":20,"MqttCount":0,"POWER1":"OFF","POWER2":"OFF","POWER3":"OFF","Dimmer":10,"Fade":"OFF","Speed":1,"LedTable":"ON","Wifi":{"AP":1,"SSId":"Amigo","BSSId":"CE:40:D0:6A:21:22","Channel":11,"RSSI":28,"Signal":-86,"LinkCount":1,"Downtime":"0T00:00:04"}}}

- [ ] Provide the output of the Console log output when you experience your issue; if applicable:
  _(Please use_ `weblog 4` _for more debug information)_

Console output here:



### TO REPRODUCE
_Steps to reproduce the behavior:_

Roller-blind hardware configuration setup as shown in Diagram v412 on “Shutters and Blinds” v412. Hardware configuration uses 12V input, MP1584 DC to DC converter set to output 3.3V. ESP-12F based micro-controller (have tried NodeMCU development board, Wifi Witty board, and Wemos D1 Mini board, all exhibit same response), A4988 stepper motor controller (set to full step MS1, MS2 and MS3 are all low), and 28BYJ-48 motor (5V motor modified for bi-polar operation, current limited by A4988).

Software configuration set up as described in the associated writeup in “Shutters and Blinds”.

When micro-controller is flashed with Tasmota 8.2, stepper motor rotates as expected. Both directions work. Counter1 shown in web interface counts up or down as expected.

Exact same hardware setup flashed with Tasmota 8.3.1, the stepper motor does not rotate. A slight vibration is noticed at start and stop, but that is all. Counter1 in web interface counts as expected.

I was able to reproduce this issue using three different micro-controllers: Wemos D1 Mini, Wifi Witty and NodeMCU development board. In all cases, the hardware setup was identical. The setups using 8.2 worked, whereas the same setups using 8.3.1 did not.

### EXPECTED BEHAVIOUR
_A clear and concise description of what you expected to happen._

I expected this setup to work under 8.3.1. I did not expect a firmware upgrade to break the setup.

### SCREENSHOTS
_If applicable, add screenshots to help explain your problem._

### ADDITIONAL CONTEXT
_Add any other context about the problem here._

**(Please, remember to close the issue when the problem has been addressed)**
TrDA-hab commented 4 years ago

@wolfpaw98 "MP1584 DC to DC converter set to output 3.3V" - This is mistake? Must be 5 volts! I will test and write later...

image

TrDA-hab commented 4 years ago

Tasmota 8.2.0 - works fine, no errors.

Tasmota 8.3.1.6 - it works poorly, there are errors:

wolfpaw98 commented 4 years ago

Thank you very much for looking at this. I increased the voltage from 3.3V to 5V and have results similar to yours. The reason I was using 3.3V was that I would like to reduce the footprint of the electronics as much as possible and want to use an ESP-12F chip with some resistors rather than the larger development boards. The ESP runs on 3.3V, not 5V and the A4988 is 3.3V compliant, so I didn't think that voltage (3.3V vs 5V) would make a difference. It appears that your test and mine would confirm that this is not a voltage issue. Thanks again for looking into this.

Jason2866 commented 4 years ago

@stefanbode or/and @to-scho can you take a look? Thx!

stefanbode commented 4 years ago

I'm quite busy over the weekend. Can someone provide a logfile of the crazy movement with maximum loglevel? I assume there is no change in the code but maybe a change in the ESP core. The Stepper relies on sharp usage of the counter with a pwm signal. There is a lot you can break in the core.

stefanbode commented 4 years ago

@ctc : You made some changes to the shutterposition calculation and removed this out from an IF statement. Can you explain what was the reason for this change? Counter based position is normally only supported for PWM.

TrDA-hab commented 4 years ago

@stefanbode - logfile of the crazy movement with maximum loglevel.

00:00:02 SHT: time: 38, velocity 100, minstopway 50,cur_freq 1000, max_frequency 1000, act_freq_change 0, min_runtime_ms 50, act.pos 5462, next_stop 5512, target: 20000 00:00:02 SHT: time: 39, velocity 100, minstopway 50,cur_freq 1000, max_frequency 1000, act_freq_change 0, min_runtime_ms 50, act.pos 5564, next_stop 5614, target: 20000 00:00:02 SHT: time: 40, velocity 100, minstopway 50,cur_freq 1000, max_frequency 1000, act_freq_change 0, min_runtime_ms 50, act.pos 5668, next_stop 5718, target: 20000 00:00:02 SHT: Shutter1 Real 5668, Start 0, Stop 20000, Dir 1, Delay 0, Rtc 2.00 [s], Freq 1000 00:00:02 RSL: stat/tasmota_6E2392/RESULT = {"Shutter1":{"Position":28,"Direction":1,"Target":100}} 00:00:02 SHT: time: 41, velocity 100, minstopway 50,cur_freq 1000, max_frequency 1000, act_freq_change 0, min_runtime_ms 50, act.pos 5774, next_stop 5824, target: 20000 00:00:02 SHT: time: 42, velocity 100, minstopway 50,cur_freq 1000, max_frequency 1000, act_freq_change 0, min_runtime_ms 50, act.pos 5878, next_stop 5928, target: 20000 00:00:02 SHT: time: 43, velocity 100, minstopway 50,cur_freq 1000, max_frequency 1000, act_freq_change 0, min_runtime_ms 50, act.pos 5980, next_stop 6030, target: 20000 00:00:02 SHT: time: 44, velocity 100, minstopway 50,cur_freq 1000, max_frequency 1000, act_freq_change 0, min_runtime_ms 50, act.pos 6084, next_stop 6134, target: 20000 00:00:02 SHT: time: 45, velocity 100, minstopway 50,cur_freq 1000, max_frequency 1000, act_freq_change 0, min_runtime_ms 50, act.pos 6188, next_stop 6238, target: 20000 00:00:02 SHT: time: 46, velocity 100, minstopway 50,cur_freq 1000, max_frequency 1000, act_freq_change 0, min_runtime_ms 50, act.pos 6292, next_stop 6342, target: 20000 00:00:02 SHT: time: 47, velocity 100, minstopway 50,cur_freq 1000, max_frequency 1000, act_freq_change 0, min_runtime_ms 50, act.pos 6398, next_stop 6448, target: 20000 00:00:02 SHT: time: 48, velocity 100, minstopway 50,cur_freq 1000, max_frequency 1000, act_freq_change 0, min_runtime_ms 50, act.pos 6502, next_stop 6552, target: 20000 00:00:02 WIF: Checking connection... 00:00:02 WIF: Connected 00:00:02 SHT: time: 49, velocity 100, minstopway 50,cur_freq 1000, max_frequency 1000, act_freq_change 0, min_runtime_ms 50, act.pos 6604, next_stop 6654, target: 20000 00:00:02 SHT: time: 50, velocity 100, minstopway 50,cur_freq 1000, max_frequency 1000, act_freq_change 0, min_runtime_ms 50, act.pos 6708, next_stop 6758, target: 20000 00:00:02 SHT: time: 51, velocity 100, minstopway 50,cur_freq 1000, max_frequency 1000, act_freq_change 0, min_runtime_ms 50, act.pos 6812, next_stop 6862, target: 20000 00:00:03 SHT: time: 52, velocity 100, minstopway 50,cur_freq 1000, max_frequency 1000, act_freq_change 0, min_runtime_ms 50, act.pos 6916, next_stop 6966, target: 20000 00:00:03 SHT: time: 53, velocity 100, minstopway 50,cur_freq 1000, max_frequency 1000, act_freq_change 0, min_runtime_ms 50, act.pos 7020, next_stop 7070, target: 20000 00:00:03 HTP: Web server active on tasmota_6E2392-0914 with IP address 192.168.1.50 00:00:03 SHT: time: 54, velocity 100, minstopway 50,cur_freq 1000, max_frequency 1000, act_freq_change 0, min_runtime_ms 50, act.pos 7124, next_stop 7174, target: 20000 00:00:03 SHT: time: 55, velocity 100, minstopway 50,cur_freq 1000, max_frequency 1000, act_freq_change 0, min_runtime_ms 50, act.pos 7226, next_stop 7276, target: 20000 00:00:03 SHT: time: 56, velocity 100, minstopway 50,cur_freq 1000, max_frequency 1000, act_freq_change 0, min_runtime_ms 50, act.pos 7328, next_stop 7378, target: 20000 00:00:03 SHT: time: 57, velocity 100, minstopway 50,cur_freq 1000, max_frequency 1000, act_freq_change 0, min_runtime_ms 50, act.pos 7430, next_stop 7480, target: 20000 00:00:03 SHT: time: 58, velocity 100, minstopway 50,cur_freq 1000, max_frequency 1000, act_freq_change 0, min_runtime_ms 50, act.pos 7540, next_stop 7590, target: 20000 00:00:03 SHT: time: 64, velocity 100, minstopway 50,cur_freq 1000, max_frequency 1000, act_freq_change 0, min_runtime_ms 50, act.pos 8098, next_stop 8148, target: 20000 00:00:03 SHT: Shutter1 Real 8098, Start 0, Stop 20000, Dir 1, Delay 0, Rtc 3.20 [s], Freq 1000 00:00:03 RSL: stat/tasmota_6E2392/RESULT = {"Shutter1":{"Position":40,"Direction":1,"Target":100}} 00:00:03 SHT: time: 65, velocity 100, minstopway 50,cur_freq 1000, max_frequency 1000, act_freq_change 0, min_runtime_ms 50, act.pos 8236, next_stop 8286, target: 20000 00:00:03 SHT: time: 66, velocity 100, minstopway 50,cur_freq 1000, max_frequency 1000, act_freq_change 0, min_runtime_ms 50, act.pos 8344, next_stop 8394, target: 20000 00:00:03 SHT: time: 67, velocity 100, minstopway 50,cur_freq 1000, max_frequency 1000, act_freq_change 0, min_runtime_ms 50, act.pos 8446, next_stop 8496, target: 20000 00:00:03 SHT: time: 68, velocity 100, minstopway 50,cur_freq 1000, max_frequency 1000, act_freq_change 0, min_runtime_ms 50, act.pos 8552, next_stop 8602, target: 20000 00:00:03 SHT: time: 70, velocity 100, minstopway 50,cur_freq 1000, max_frequency 1000, act_freq_change 0, min_runtime_ms 50, act.pos 8654, next_stop 8704, target: 20000 00:00:03 SHT: time: 71, velocity 100, minstopway 50,cur_freq 1000, max_frequency 1000, act_freq_change 0, min_runtime_ms 50, act.pos 8756, next_stop 8806, target: 20000 00:00:04 SHT: time: 72, velocity 100, minstopway 50,cur_freq 1000, max_frequency 1000, act_freq_change 0, min_runtime_ms 50, act.pos 8860, next_stop 8910, target: 20000 00:00:04 SHT: time: 73, velocity 100, minstopway 50,cur_freq 1000, max_frequency 1000, act_freq_change 0, min_runtime_ms 50, act.pos 8962, next_stop 9012, target: 20000 00:00:04 SHT: time: 74, velocity 100, minstopway 50,cur_freq 1000, max_frequency 1000, act_freq_change 0, min_runtime_ms 50, act.pos 9064, next_stop 9114, target: 20000 00:00:04 RSL: tele/tasmota_6E2392/INFO1 = {"Module":"Generic","Version":"8.3.1.6(tasmota)","FallbackTopic":"cmnd/DVES_6E2392_fb/","GroupTopic":"cmnd/tasmotas/"} 00:00:04 RSL: tele/tasmota_6E2392/INFO2 = {"WebServerMode":"Admin","Hostname":"tasmota_6E2392-0914","IPAddress":"192.168.1.50"} 00:00:04 RSL: tele/tasmota_6E2392/INFO3 = {"RestartReason":{"Exception":4,"Reason":"Software Watchdog","EPC":["40100510","00000000","402446dd"],"EXCVADDR":"00000000","DEPC":"00000000","CallChain":["402185b5","40218500","402185b5","4022a7eb","401005a8","40203dc0","4021b8cc","402260f3","40228cb0","40100640","4000050c","40100944","40203d80","4023fd46","4023fd92","40229c63","4022dfa6","4020e7dd","4022db94","40244804","40100ff5"]}} 00:00:04 RSL: stat/tasmota_6E2392/RESULT = {"POWER1":"ON"} 00:00:04 RSL: stat/tasmota_6E2392/POWER1 = ON 00:00:04 RSL: stat/tasmota_6E2392/RESULT = {"POWER2":"OFF"} 00:00:04 RSL: stat/tasmota_6E2392/POWER2 = OFF 00:00:04 RSL: stat/tasmota_6E2392/RESULT = {"POWER3":"OFF"} 00:00:04 RSL: stat/tasmota_6E2392/POWER3 = OFF 00:00:04 SHT: time: 75, velocity 100, minstopway 50,cur_freq 1000, max_frequency 1000, act_freq_change 0, min_runtime_ms 50, act.pos 9242, next_stop 9292, target: 20000 00:00:04 SHT: time: 76, velocity 100, minstopway 50,cur_freq 1000, max_frequency 1000, act_freq_change 0, min_runtime_ms 50, act.pos 9346, next_stop 9396, target: 20000 00:00:04 SHT: time: 77, velocity 100, minstopway 50,cur_freq 1000, max_frequency 1000, act_freq_change 0, min_runtime_ms 50, act.pos 9448, next_stop 9498, target: 20000 00:00:04 SHT: time: 79, velocity 100, minstopway 50,cur_freq 1000, max_frequency 1000, act_freq_change 0, min_runtime_ms 50, act.pos 9554, next_stop 9604, target: 20000 00:00:04 SHT: time: 80, velocity 100, minstopway 50,cur_freq 1000, max_frequency 1000, act_freq_change 0, min_runtime_ms 50, act.pos 9658, next_stop 9708, target: 20000 00:00:04 SHT: Shutter1 Real 9658, Start 0, Stop 20000, Dir 1, Delay 0, Rtc 4.00 [s], Freq 1000 00:00:04 RSL: stat/tasmota_6E2392/RESULT = {"Shutter1":{"Position":48,"Direction":1,"Target":100}} 00:00:05 SHT: time: 107, velocity 100, minstopway 50,cur_freq 1000, max_frequency 1000, act_freq_change 0, min_runtime_ms 50, act.pos 12372, next_stop 12422, target: 20000 00:00:05 SHT: time: 108, velocity 100, minstopway 50,cur_freq 1000, max_frequency 1000, act_freq_change 0, min_runtime_ms 50, act.pos 12474, next_stop 12524, target: 20000 00:00:05 SHT: time: 109, velocity 100, minstopway 50,cur_freq 1000, max_frequency 1000, act_freq_change 0, min_runtime_ms 50, act.pos 12578, next_stop 12628, target: 20000 00:00:05 SHT: time: 110, velocity 100, minstopway 50,cur_freq 1000, max_frequency 1000, act_freq_change 0, min_runtime_ms 50, act.pos 12680, next_stop 12730, target: 20000 00:00:05 SHT: time: 111, velocity 100, minstopway 50,cur_freq 1000, max_frequency 1000, act_freq_change 0, min_runtime_ms 50, act.pos 12784, next_stop 12834, target: 20000 00:00:06 SHT: time: 112, velocity 100, minstopway 50,cur_freq 1000, max_frequency 1000, act_freq_change 0, min_runtime_ms 50, act.pos 12886, next_stop 12936, target: 20000 00:00:06 SHT: time: 113, velocity 100, minstopway 50,cur_freq 1000, max_frequency 1000, act_freq_change 0, min_runtime_ms 50, act.pos 12988, next_stop 13038, target: 20000 00:00:06 SHT: time: 114, velocity 100, minstopway 50,cur_freq 1000, max_frequency 1000, act_freq_change 0, min_runtime_ms 50, act.pos 13092, next_stop 13142, target: 20000 00:00:06 SHT: time: 115, velocity 100, minstopway 50,cur_freq 1000, max_frequency 1000, act_freq_change 0, min_runtime_ms 50, act.pos 13194, next_stop 13244, target: 20000 00:00:06 SHT: time: 116, velocity 100, minstopway 50,cur_freq 1000, max_frequency 1000, act_freq_change 0, min_runtime_ms 50, act.pos 13296, next_stop 13346, target: 20000 00:00:06 SHT: time: 117, velocity 100, minstopway 50,cur_freq 1000, max_frequency 1000, act_freq_change 0, min_runtime_ms 50, act.pos 13400, next_stop 13450, target: 20000 00:00:06 SHT: time: 118, velocity 100, minstopway 50,cur_freq 1000, max_frequency 1000, act_freq_change 0, min_runtime_ms 50, act.pos 13502, next_stop 13552, target: 20000 00:00:06 SHT: time: 119, velocity 100, minstopway 50,cur_freq 1000, max_frequency 1000, act_freq_change 0, min_runtime_ms 50, act.pos 13604, next_stop 13654, target: 20000 00:00:06 QPC: Reset 00:00:06 SHT: Shutter1 Real 13604, Start 0, Stop 20000, Dir 1, Delay 0, Rtc 5.95 [s], Freq 1000 00:00:06 RSL: stat/tasmota_6E2392/RESULT = {"Shutter1":{"Position":68,"Direction":1,"Target":100}} 00:00:06 SHT: time: 120, velocity 100, minstopway 50,cur_freq 1000, max_frequency 1000, act_freq_change 0, min_runtime_ms 50, act.pos 13722, next_stop 13772, target: 20000 00:00:06 SHT: time: 121, velocity 100, minstopway 50,cur_freq 1000, max_frequency 1000, act_freq_change 0, min_runtime_ms 50, act.pos 13828, next_stop 13878, target: 20000 00:00:06 SHT: time: 122, velocity 100, minstopway 50,cur_freq 1000, max_frequency 1000, act_freq_change 0, min_runtime_ms 50, act.pos 13930, next_stop 13980, target: 20000 00:00:06 SHT: time: 123, velocity 100, minstopway 50,cur_freq 1000, max_frequency 1000, act_freq_change 0, min_runtime_ms 50, act.pos 14034, next_stop 14084, target: 20000 00:00:06 SHT: time: 124, velocity 100, minstopway 50,cur_freq 1000, max_frequency 1000, act_freq_change 0, min_runtime_ms 50, act.pos 14136, next_stop 14186, target: 20000 00:00:06 SHT: time: 125, velocity 100, minstopway 50,cur_freq 1000, max_frequency 1000, act_freq_change 0, min_runtime_ms 50, act.pos 14240, next_stop 14290, target: 20000 00:00:06 SHT: time: 126, velocity 100, minstopway 50,cur_freq 1000, max_frequency 1000, act_freq_change 0, min_runtime_ms 50, act.pos 14348, next_stop 14398, target: 20000 00:00:06 SHT: time: 127, velocity 100, minstopway 50,cur_freq 1000, max_frequency 1000, act_freq_change 0, min_runtime_ms 50, act.pos 14448, next_stop 14498, target: 20000 00:00:08 SHT: time: 155, velocity 100, minstopway 50,cur_freq 1000, max_frequency 1000, act_freq_change 0, min_runtime_ms 50, act.pos 17220, next_stop 17270, target: 20000 00:00:08 SHT: time: 156, velocity 100, minstopway 50,cur_freq 1000, max_frequency 1000, act_freq_change 0, min_runtime_ms 50, act.pos 17326, next_stop 17376, target: 20000 00:00:08 SHT: time: 157, velocity 100, minstopway 50,cur_freq 1000, max_frequency 1000, act_freq_change 0, min_runtime_ms 50, act.pos 17428, next_stop 17478, target: 20000 00:00:08 SHT: time: 158, velocity 100, minstopway 50,cur_freq 1000, max_frequency 1000, act_freq_change 0, min_runtime_ms 50, act.pos 17530, next_stop 17580, target: 20000 00:00:08 SHT: time: 159, velocity 100, minstopway 50,cur_freq 1000, max_frequency 1000, act_freq_change 0, min_runtime_ms 50, act.pos 17632, next_stop 17682, target: 20000 00:00:08 APP: Boot Count 31 00:00:08 RSL: tele/tasmota_6E2392/STATE = {"Time":"1970-01-01T00:00:08","Uptime":"0T00:00:10","UptimeSec":10,"Heap":27,"SleepMode":"Dynamic","Sleep":50,"LoadAvg":19,"MqttCount":0,"POWER1":"ON","POWER2":"OFF","POWER3":"OFF","Dimmer":10,"Fade":"OFF","Speed":1,"LedTable":"ON","Wifi":{"AP":1,"SSId":"Cisco-3G","BSSId":"58:6D:8F:83:AC:94","Channel":11,"RSSI":86,"Signal":-57,"LinkCount":1,"Downtime":"0T00:00:04"}} 00:00:08 RSL: tele/tasmota_6E2392/SENSOR = {"Time":"1970-01-01T00:00:08","COUNTER":{"C1":8854},"Shutter1":{"Position":0,"Direction":1,"Target":100}} 00:00:08 SHT: Shutter1 Real 17632, Start 0, Stop 20000, Dir 1, Delay 0, Rtc 8.00 [s], Freq 1000 00:00:08 RSL: stat/tasmota_6E2392/RESULT = {"Shutter1":{"Position":88,"Direction":1,"Target":100}} 00:00:08 SHT: time: 161, velocity 100, minstopway 50,cur_freq 1000, max_frequency 1000, act_freq_change 0, min_runtime_ms 50, act.pos 17768, next_stop 17818, target: 20000 00:00:08 SHT: time: 162, velocity 100, minstopway 50,cur_freq 1000, max_frequency 1000, act_freq_change 0, min_runtime_ms 50, act.pos 17870, next_stop 17920, target: 20000 00:00:08 SHT: time: 163, velocity 100, minstopway 50,cur_freq 1000, max_frequency 1000, act_freq_change 0, min_runtime_ms 50, act.pos 17976, next_stop 18026, target: 20000 00:00:08 CFG: Saved to flash at FB, Count 49, Bytes 4096 00:00:08 SHT: time: 164, velocity 100, minstopway 50,cur_freq 1000, max_frequency 1000, act_freq_change 0, min_runtime_ms 50, act.pos 18114, next_stop 18164, target: 20000 00:00:08 SHT: time: 165, velocity 100, minstopway 50,cur_freq 1000, max_frequency 1000, act_freq_change 0, min_runtime_ms 50, act.pos 18216, next_stop 18266, target: 20000 00:00:08 SHT: time: 166, velocity 100, minstopway 50,cur_freq 1000, max_frequency 1000, act_freq_change 0, min_runtime_ms 50, act.pos 18318, next_stop 18368, target: 20000 00:00:08 SHT: time: 167, velocity 100, minstopway 50,cur_freq 1000, max_frequency 1000, act_freq_change 0, min_runtime_ms 50, act.pos 18420, next_stop 18470, target: 20000 00:00:08 SHT: time: 168, velocity 100, minstopway 50,cur_freq 1000, max_frequency 1000, act_freq_change 0, min_runtime_ms 50, act.pos 18524, next_stop 18574, target: 20000 00:00:08 SHT: time: 169, velocity 100, minstopway 50,cur_freq 1000, max_frequency 1000, act_freq_change 0, min_runtime_ms 50, act.pos 18624, next_stop 18674, target: 20000 00:00:08 SHT: time: 170, velocity 100, minstopway 50,cur_freq 1000, max_frequency 1000, act_freq_change 0, min_runtime_ms 50, act.pos 18730, next_stop 18780, target: 20000 00:00:08 SHT: time: 171, velocity 100, minstopway 50,cur_freq 1000, max_frequency 1000, act_freq_change 0, min_runtime_ms 50, act.pos 18832, next_stop 18882, target: 20000 00:00:09 SHT: time: 172, velocity 100, minstopway 50,cur_freq 1000, max_frequency 1000, act_freq_change 0, min_runtime_ms 50, act.pos 18936, next_stop 18986, target: 20000 00:00:09 SHT: time: 173, velocity 100, minstopway 50,cur_freq 1000, max_frequency 1000, act_freq_change 0, min_runtime_ms 50, act.pos 19038, next_stop 19088, target: 20000

TrDA-hab commented 4 years ago

Nema-17 and A4988 - very hot 70-80C, I lost two A4988.

stefanbode commented 4 years ago

@arendst : I see that the Software Watchdog EPC was executed and booted the device during operation. Is this something new? What is the trigger for this watchdog and how can we tell him everything is ok?

arendst commented 4 years ago

The watch dogs triggers due to bad loop programming. If a loop takes too long without using a yield() it will break. It needs the yield to handle wifi and other basic code.

As Tasmota always ran fine with the default watchdog settings (changes would need to be done on SDK level) I suggest to find out why the watchdog triggers in your situation.

stefanbode commented 4 years ago

I upgraded to the latest release and able to reproduce the error. It is indeed the watchdog that bites, if I want to stop the relays. Even a yield() before the Command does not help. It looks like the Standard: ExecuteCommandPower is causing the issue....

Its line 369ff:

            AddLog_P2(LOG_LEVEL_DEBUG, PSTR("SHT: Real %d, pulsecount %d, start %d"), Shutter.real_position[i],RtcSettings.pulse_counter[i], Shutter.start_position[i]);

            if ((1 << (Settings.shutter_startrelay[i]-1)) & power) {
              AddLog_P2(LOG_LEVEL_DEBUG, PSTR("SHT: stop rel1"));
              yield();
              ExecuteCommandPower(Settings.shutter_startrelay[i], 0, SRC_SHUTTER);
              yield();
              AddLog_P2(LOG_LEVEL_DEBUG, PSTR("SHT: stop rel2"));
              ExecuteCommandPower(Settings.shutter_startrelay[i]+1, 0, SRC_SHUTTER);
19:02:37 SHT: Remain steps 33, counter 2667, freq 1000
19:02:38 SHT: Real 9400, pulsecount 2700, start 14800
19:02:38 SHT: stop rel1
19:02:38 SRC: Shutter
19:02:38 SHT: Switched relay: 1 by Shutter

Soft WDT reset

>>>stack>>>

ctx: cont
sp: 3ffffb90 end: 3fffffc0 offset: 01a0

How it should be:

19:10:04 SHT: Remain steps 0, counter 7400, freq 0
19:10:04 SHT: Real -2, pulsecount 7401, start 14800
19:10:04 SHT: stop rel1
19:10:04 SRC: Shutter
19:10:04 SHT: Switched relay: 1 by Shutter
19:10:04 MQT: hm/status/ESP_33A054/RESULT = {"POWER1":"OFF"}
19:10:04 MQT: hm/status/ESP_33A054/POWER1 = OFF (retained)
19:10:04 SHT: stop rel2
19:10:04 SRC: Shutter
19:10:04 SHT: Switched relay: 2 by Shutter
19:10:04 MQT: hm/status/ESP_33A054/RESULT = {"POWER2":"OFF"}
19:10:04 MQT: hm/status/ESP_33A054/POWER2 = OFF (retained)
stefanbode commented 4 years ago

I additionally checked the MQTT and disables it. No change. The crash just happens at the same place

stefanbode commented 4 years ago

4988.

You should LOWER your current to the minimum needed. High Current is bad for the motor AND the driver.

stefanbode commented 4 years ago

@arendst : To reproduce:

No Hardware required. restart 1

stefanbode commented 4 years ago

There is a "workaround". I tried to get more info and enables the DEBUG_THEO option. Now the error is gone. Anyhow agree that THIS is not a solution....

TrDA-hab commented 4 years ago

You should LOWER your current to the minimum needed. High Current is bad for the motor AND the driver.

Not. This is mistake. I do not change the driver current. I just change Wemos D1 mini (and have two different). The first one has Tasmota 8.2.0 firmware - it does not heat up. The second has Tasmota 8.3.1.6 firmware - it gets very hot.

TrDA-hab commented 4 years ago

restart 1

I could not get. This command does not work. Nothing happens.

TrDA-hab commented 4 years ago

setoption80 1 interlock off

.... perhaps you forgot: Backlog PulseTime1 0; PulseTime2 0

... and D1 = Relay1i

ctc commented 4 years ago

@ctc : You made some changes to the shutterposition calculation and removed this out from an IF statement. Can you explain what was the reason for this change? Counter based position is normally only supported for PWM.

The rules for venetian blinds needs the shutter position to store the previous blind position of "virtual" shutter 2. https://tasmota.github.io/docs/Blinds-and-Shutters/

Rule1 on Shutter2#Position DO mem1 %value% ENDON on Shutter1#Position DO var2 %value% ENDON on Shutter1#Direction!=0 DO var1 %value% ENDON on Shutter1#Direction=0 DO IF (var1==1) var1 0; IF (var2!=100) ShutterSetOpen2; shutterposition2 %mem1% ENDIF ENDIF ENDON on Shutter1#Direction=0 DO IF (var1==-1) var1 0; IF (var2!=0) ShutterSetClose2; shutterposition2 %mem1% ENDIF ENDIF ENDON

stefanbode commented 4 years ago

Gentlemen, can we agree on fixing the Repeated reboots because of Software Watchdog FIRST and then we can take into consideration of overheat and so on. I need additional ideas why after slowing down the PWM frequency to 0 the command to Switch OFF the relay result in a Watchdog. And on all other cases the same command works fine. Again here the source code and the last messages before the reboot:

            AddLog_P2(LOG_LEVEL_DEBUG, PSTR("SHT: Real %d, pulsecount %d, start %d"), Shutter.real_position[i],RtcSettings.pulse_counter[i], Shutter.start_position[i]);

            if ((1 << (Settings.shutter_startrelay[i]-1)) & power) {
              AddLog_P2(LOG_LEVEL_DEBUG, PSTR("SHT: stop rel1"));
              yield();
              ExecuteCommandPower(Settings.shutter_startrelay[i], 0, SRC_SHUTTER);
              yield();
              AddLog_P2(LOG_LEVEL_DEBUG, PSTR("SHT: stop rel2"));
              ExecuteCommandPower(Settings.shutter_startrelay[i]+1, 0, SRC_SHUTTER);
19:02:37 SHT: Remain steps 33, counter 2667, freq 1000
19:02:38 SHT: Real 9400, pulsecount 2700, start 14800
19:02:38 SHT: stop rel1
19:02:38 SRC: Shutter
19:02:38 SHT: Switched relay: 1 by Shutter

Soft WDT reset

>>>stack>>>

ctx: cont
sp: 3ffffb90 end: 3fffffc0 offset: 01a0

Any idea is welcome. In parallel I will do some testing do dig into the root cause.

stefanbode commented 4 years ago

There was no code change in shutter between 8.2 and 8.3. Therefore we can exclude a direct impact of changed source code. The Software Watchdog is executed because of OTHER changes in code/SDK or whatever. @arendst : Do you have a chance to help with debug?

arendst commented 4 years ago

I'll have a look using the "no hardware needed" procedure (as I simply don't have shutters)

arendst commented 4 years ago

Do you expect the analogWriteFreq to go below 40? If so it will never be zero as can be seen here:

extern void __analogWriteFreq(uint32_t freq) {
  if (freq < 40) {
    freq = 40;
  } else if (freq > 60000) {
    freq = 60000;
  } else {
    freq = freq;
  }
  _setPWMFreq(freq);
}

this seems to be a change from 8.2.0 where it could be zero:

extern void __analogWriteFreq(uint32_t freq)
{
    pwm_freq = freq;
    prep_pwm_steps();
}

There were a lot of changes in the PWM code to accomodate light anomalies.

stefanbode commented 4 years ago

Yes, this points into the right direction. To stop the shutter I set the frequency to 0. This is faster than switching off the power relay. Let me try it with 40 and switch it off. This new information also helps me to understand the current anomalies.... :-)

stefanbode commented 4 years ago

I do have now a working version. Need some more testing because of the changes behaviour with now 40Hz minimum speed. But very optimistic :-)

stefanbode commented 4 years ago

Hi @arendst : With Setoption68 1 I can split the different PWM into different "lights" How Do I get in the code the NUMBER of the corresponding relay If I start with Pin(GPIO_PWM1, I) and "i" is my shutter number. In general, is looks like the PWM Relays are AFTER the last normal really... but you never know.

arendst commented 4 years ago

I don't know PWM relays. All I know is relays and lights. Lights will be numbered AFTER numbering relays.

In your case a PWM will be numbered after a relay.

stefanbode commented 4 years ago

ok, I took a different approach and force setoption15 1. In this case I can execute "pwm1 0" or "pwm2 100" and so on without the need to know a relay. Anyhow the relay is gone with setoption15. Looks promising so far...

stefanbode commented 4 years ago

@arendst : For me it looks like there is something seriously broken. I made some changes and during startup I call already create the error if PWM's are defined and set. Here the code and where it crashes. Without the PWM Frequency set the LOG loop through all 4 relays.:

support_tasmota.ino line 229f

  else
  {
    AddLog_P2(LOG_LEVEL_DEBUG_MORE, PSTR("SHT: SetDevicePower, before FOR"));
    for (uint32_t i = 0; i < devices_present; i++) {
      power_t state = rpower &1;
      if (i < MAX_RELAYS) {
        AddLog_P2(LOG_LEVEL_DEBUG_MORE, PSTR("SHT: SetDevicePower, before DigitalWrite %d"),i);
        DigitalWrite(GPIO_REL1, i, bitRead(rel_inverted, i) ? !state : state);
      }
      rpower >>= 1;
    }
  }
00:00:00 SRC: Restart
00:00:00 SHT: Switched relay: 0 by Restart
00:00:00 SHT: FUNC_SET_DEVICE_POWER, Skip: 0
00:00:00 SHT: SetDevicePower, before FOR
00:00:00 SHT: SetDevicePower, before DigitalWrite 0

Soft WDT reset

>>>stack>>>

ctx: cont
sp: 3ffffd10 end: 3fffffc0 offset: 01a0
3ffffeb0:  3fffff20 3fffff10 00000008 4021f669
3ffffec0:  3ffefe13 00000000 00000000 4024da10
3ffffed0:  3ffffe80 3ffffe50 001e83e0 001b8841
3ffffee0:  00000000 3fff1a26 3ffffe90 4024f767
3ffffef0:  00000004 ffffffff ffffffff 47092add
3fffff00:  00000000 3fffff10 00000008 3ffe8deb
3fffff10:  fffffffb 00000000 00000005 4010054c
3fffff20:  00000000 00000015 00000000 4020a5bc
3fffff30:  00000000 00000000 00000000 40223178
3fffff40:  4023cb9b 00000000 3fff17dc 3ffe8deb
3fffff50:  3fff1c98 3fff1823 3fff1998 402231d5
3fffff60:  3fff17dc 3fff1998 3fff179a 3ffe8deb
3fffff70:  3fff17dc 3fff17bb 3fff179a 40234a93
3fffff80:  3fff1a20 feefeffe feefeffe feefeffe
3fffff90:  feefeffe feefeffe feefeffe 3fff2d90
3fffffa0:  3fffdad0 00000000 3fff2d50 402478c4
3fffffb0:  feefeffe feefeffe 3ffe869c 40100d09
<<<stack<<<
stefanbode commented 4 years ago

I can cleary isolate the problem in ShutterInit(void). As soon as I skip line 288: analogWriteFreq(Shutter.accelerator[i]);

everything is ok. It looks like the change of the frequency has an impact later on on the digital write to cause the reset.

stefanbode commented 4 years ago

@s-hadinger : Can you take a look here. There where recent changes on PWM and I use the PWM frequency change to control stepper motors speed during acceleration and deceleration. It looks like we have problem AFTER a frequency change to do a digitalWrite . Having reproduceable Software Watchdog bites after calling digitalWrite.

arendst commented 4 years ago

What happens if you move your shutterinit from FUNC_PRE_INIT to FUNC_INIT?

After a restart the analogWriteFreq is adjusted to the stored Settings.pwm_frequency to accomodate light.

The current implementation cannot work reliably simply because it starts using peripherals before they are restored by Tasmota; the poweronstate process has not been completed while you already start setting shutter relays.

The FUNC_PRE_INIT is there to setup simple start conditions. FUNC_INIT can be used if all of Tasmota has been initialized.

stefanbode commented 4 years ago

Changed; but this makes no difference. Also got the error after movement when decelerating the shutter.

arendst commented 4 years ago

@arendst : For me it looks like there is something seriously broken. I made some changes and during startup I call already create the error if PWM's are defined and set. Here the code and where it crashes. Without the PWM Frequency set the LOG loop through all 4 relays.:

support_tasmota.ino line 229f

  else
  {
    AddLog_P2(LOG_LEVEL_DEBUG_MORE, PSTR("SHT: SetDevicePower, before FOR"));
    for (uint32_t i = 0; i < devices_present; i++) {
      power_t state = rpower &1;
      if (i < MAX_RELAYS) {
        AddLog_P2(LOG_LEVEL_DEBUG_MORE, PSTR("SHT: SetDevicePower, before DigitalWrite %d"),i);
        DigitalWrite(GPIO_REL1, i, bitRead(rel_inverted, i) ? !state : state);
      }
      rpower >>= 1;
    }
  }
00:00:00 SRC: Restart
00:00:00 SHT: Switched relay: 0 by Restart
00:00:00 SHT: FUNC_SET_DEVICE_POWER, Skip: 0
00:00:00 SHT: SetDevicePower, before FOR
00:00:00 SHT: SetDevicePower, before DigitalWrite 0

Soft WDT reset

>>>stack>>>

ctx: cont
sp: 3ffffd10 end: 3fffffc0 offset: 01a0
3ffffeb0:  3fffff20 3fffff10 00000008 4021f669
3ffffec0:  3ffefe13 00000000 00000000 4024da10
3ffffed0:  3ffffe80 3ffffe50 001e83e0 001b8841
3ffffee0:  00000000 3fff1a26 3ffffe90 4024f767
3ffffef0:  00000004 ffffffff ffffffff 47092add
3fffff00:  00000000 3fffff10 00000008 3ffe8deb
3fffff10:  fffffffb 00000000 00000005 4010054c
3fffff20:  00000000 00000015 00000000 4020a5bc
3fffff30:  00000000 00000000 00000000 40223178
3fffff40:  4023cb9b 00000000 3fff17dc 3ffe8deb
3fffff50:  3fff1c98 3fff1823 3fff1998 402231d5
3fffff60:  3fff17dc 3fff1998 3fff179a 3ffe8deb
3fffff70:  3fff17dc 3fff17bb 3fff179a 40234a93
3fffff80:  3fff1a20 feefeffe feefeffe feefeffe
3fffff90:  feefeffe feefeffe feefeffe 3fff2d90
3fffffa0:  3fffdad0 00000000 3fff2d50 402478c4
3fffffb0:  feefeffe feefeffe 3ffe869c 40100d09
<<<stack<<<

I think what is serious wrong is the assumption of having three relays where you only have two relays and one PWM. The above code fails probably on the call for GPIO_REL1 + 2 which is not present. What you want is control power of PWM channel 1. That has to be done using FUNC_SET_DEVICE_POWER in your shutter driver. There is no default PWM power control available as can be seen in the light driver which handles PWM power control itselves.

arendst commented 4 years ago

In addition to the above I think I found the location where digitalWrite starts to hang and Software Watchdogs. It's in core_esp8266_wiring_digital.cpp line 95:

extern void ICACHE_RAM_ATTR __digitalWrite(uint8_t pin, uint8_t val) {
  stopWaveform(pin); // Disable any tone
  _stopPWM(pin);     // ...and any analogWrite
  if(pin < 16){
    if(val) GPOS = (1 << pin);
    else GPOC = (1 << pin);
  } else if(pin == 16){
    if(val) GP16O |= 1;
    else GP16O &= ~1;
  }
}

Changing line

  _stopPWM(pin);     // ...and any analogWrite

into

//  _stopPWM(pin);     // ...and any analogWrite

at least makes a normal digitalWrite functional again without Watchdog.

I'll investigate what happens here.

arendst commented 4 years ago

Pls try again with the latest fixes.

stefanbode commented 4 years ago

I think what is serious wrong is the assumption of having three relays where you only have two relays and one PWM. The above code fails probably on the call for GPIO_REL1 + 2 which is not present. What you want is control power of PWM channel 1. That has to be done using FUNC_SET_DEVICE_POWER in your shutter driver. There is no default PWM power control available as can be seen in the light driver which handles PWM power control itselves.

I would disagree.:With setoptio15 ON there is a relay 3 and it does not work either. In the case, I send there is only relay1+2 and PWM1 with no relay. The reset already happens at relay1. Therefore your assumption could be wrong. Anyhow your SECOND finding is very interesting and looks like a possible root cause. Maybe @s-hadinger has an idea. The stopWaveform(pin) seems to have a problem if executed on PIN 1 when a PWM is defined on PIN 2.

stefanbode commented 4 years ago

The change of the core_esp8266_wiring_digital.cpp make the deal. !!!

Jason2866 commented 4 years ago

I would suggest to try https://github.com/esp8266/Arduino/pull/7022/files This PR has great results (better as the one we use now) for PWM and maybe it does not generate software watchdogs with shutter I have done a core with for my builds. You can try https://github.com/Jason2866/platform-espressif8266/releases/download/2.8.0/esp8266-2.8.0.zip

Jason2866 commented 4 years ago

For testing you can use this platformio_override.ini file https://github.com/Jason2866/Merge/blob/master/platformio_override.ini Delete the pwm related core files in Tasmota folder!!!

stefanbode commented 4 years ago

@s-hadinger was deeply involved in fixing the PWM jitter in core arduino. The files we have here in TASMOTA are a preresult of this engagement. Therfore we have very new files already. It just look like there is a small bug under some circumstances.

Jason2866 commented 4 years ago

@stefanbode i know. If you read the conversation of the PR 7022. @s-hadinger do recommend to use this one 👍☺ Stephans comment is here https://github.com/esp8266/Arduino/pull/7022#issuecomment-636346466

stefanbode commented 4 years ago

For whatever reason, the WHILE is executed on a normal pin without PWM defined.... and die..

// Stops a waveform on a pin
int ICACHE_RAM_ATTR stopWaveform(uint8_t pin) {
  // Can't possibly need to stop anything if there is no timer active
  if (!timerRunning) {
    return false;
  }
  // If user sends in a pin >16 but <32, this will always point to a 0 bit
  // If they send >=32, then the shift will result in 0 and it will also return false
  uint32_t mask = 1<<pin;
  if (wvfState.waveformEnabled & mask) {
    wvfState.waveformToDisable = mask;
    // Cancel any pending updates for this waveform, too.
    if (wvfState.waveformToChange & mask) {
        wvfState.waveformToChange = 0;
    }
    forceTimerInterrupt();
    while (wvfState.waveformToDisable) {
      MEMBARRIER(); // If it wasn't written yet, it has to be by now
      /* no-op */ // Can't delay() since stopWaveform may be called from an IRQ
    }
  }
  disableIdleTimer();
  return true;
}
Jason2866 commented 4 years ago

@stefanbode you can try this branch (fork). It uses PR7022 and the new extensa build chain gcc10.1 Maybe it solves the problem https://github.com/Jason2866/Tasmota/tree/Gcc10.1

stefanbode commented 4 years ago

@Jason2866 : I agree that also changing to the latest core as you described fixed the problem, too.

changes made: -delete 3 core files cpp for PWM

Jason2866 commented 4 years ago

@arendst considering to use files from PR#7022 ? Better PWM results and fixing shutter issues. So would be a win win change.

wolfpaw98 commented 4 years ago

Thank you so much to the whole team working on this fix. I am completely blown away by the rapid response and dedication shown by this community. I am in awe!

arendst commented 4 years ago

Agree

Jason2866 commented 4 years ago

Will do a PR later this evening.

wolfpaw98 commented 4 years ago

Thank you so much for this! Confirmed working now! You guys are AWESOME!