search

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
21.97k stars 4.77k forks source link

Shutters: upgrade from 9.1.0 with SetOption80 create instability #10179

Closed megamarco833 closed 3 years ago

megamarco833 commented 3 years ago

PROBLEM DESCRIPTION

using esp32 and firmware version 9.2 with setOption80 enabled and module configurated with GPIOs + mqtt create instabile system. 9.1.0 version not have this issue 9.1.0.2 or above (tested 9.1.0.2 and 9.2) has this issue.

REQUESTED INFORMATION

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


22:22:35.138 CMD: Backlog Template; Module; GPIO 2F22:22:35.140 SRC: WebConsole from 192.168.0.4
22:22:35.142 CMD: Group 0, Index 1, Command "BACKLOG", Data "Template; Module; GPIO 25"
22:22:35.513 SRC: Backlog
22:22:35.514 CMD: Group 0, Index 1, Command "TEMPLATE", Data ""
22:22:35.520 MQT: stat/tasmota_esp32_giallo/RESULT = {"NAME":"BLIND32","GPIO":[1,1,167,1,166,163,1,1,1,1,261,1,165,164,161,162,0,160,263,262,0,258,259,260,0,0,0,0,256,257,1,1,1,0,0,1],"FLAG":0,"BASE":1}
22:22:38.655 SRC: Backlog
22:22:38.656 CMD: Group 0, Index 1, Command "MODULE", Data ""
22:22:38.664 MQT: stat/tasmota_esp32_giallo/RESULT = {"Module":{"0":"BLIND32"}}
22:22:38.868 SRC: Backlog
22:22:38.869 CMD: Group 0, Index 1, Command "GPIO", Data "25"
22:22:38.876 MQT: stat/tasmota_esp32_giallo/RESULT = {"GPIO0":{"0":"None"},"GPIO1":{"0":"None"},"GPIO3":{"0":"None"},"GPIO9":{"0":"None"},"GPIO10":{"0":"None"},"GPIO12":{"0":"None"},"GPIO13":{"0":"None"},"GPIO15":{"0":"None"},"GPIO34":{"0":"None"},"GPIO35":{"0":"None"},"GPIO36":{"0":"None"},"GPIO39":{"0":"None"}}}
22:22:39.716 MQT: tasmota/discovery/3C71BFF0B7F4/config = {"ip":"192.168.0.36","dn":"Tasmota","fn":["Tasmota","Tasmota2","Tasmota3","Tasmota4","Tasmota5","Tasmota6","Tasmota7","Tasmota8"],"hn":"tasmota_esp32_giallo-6132","mac":"3C71BFF0B7F4","md":"BLIND32","ty":0,"if":0,"ofln":"Offline","onln":"Online","state":["OFF","ON","TOGGLE","HOLD"],"sw":"9.2.0.1","t":"tasmota_esp32_giallo","ft":"%prefix%/%topic%/","tp":["cmnd","stat","tele"],"rl":[3,3,3,3,3,3,3,3],"swc":[-1,-1,-1,-1,-1,-1,-1,-1],"swn":[null,null,null,null,null,null,null,null],"btn":[0,0,0,0],"so":{"4":0,"11":0,"13":0,"17":0,"20":0,"30":0,"68":0,"73":0,"82":0,"114":0},"lk":1,"lt_st":0,"sho":[0,0,0,0],"ver":1} (retained)
22:22:43.807 MQT: tasmota/discovery/3C71BFF0B7F4/sensors = {"sn":{"Time":"2020-12-18T22:22:39","Switch1":"ON","Switch2":"ON","Switch3":"ON","Switch4":"ON","Switch5":"ON","Switch6":"ON","Switch7":"ON","Switch8":"ON","Shutter1":{"Position":0,"Direction":0,"Target":0},"Shutter2":{"Position":0,"Direction":0,"Target":0},"Shutter3":{"Position":0,"Direction":0,"Target":0},"Shutter4":{"Position":42,"Direction":0,"Target":42}},"ver":1} (retained)

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

not possible, after configure the module (see how to reproduce) is almost impossible to access to console due to instability

- [ ] Provide the output of the Console log output when you experience your issue; if applicable:
  _(Please use_ `weblog 4` _for more debug information)_
after many trials from console (due to instability the console not accept commands that i issued...anyway after many trial this one was accepted and the answer is:

22:15:58.762 CMD: weblog 4 22:15:58.767 RSL: stat/tasmota_esp32_giallo/RESULT = {"WebLog":4} 22:15:59.509 CFG: Saved, Count 21, Bytes 4096



### TO REPRODUCE
follow this steps:

1. flash 9.1.0.2 (patch5 ; in this case was complied by me using gitpot, without making any modification at the code) or 9.2 (in this case i just download the binary already compiled) i verify that the issue is there on both procedures, so no matter.

2. configure the module with GPIOs like this template:
`{"NAME":"BLIND32","GPIO":[1,1,167,1,166,163,1,1,1,1,261,1,165,164,161,162,0,160,263,262,0,258,259,260,0,0,0,0,256,257,1,1,1,0,0,1],"FLAG":0,"BASE":1}`
simply used to control 4 shutters: 8gpio for relay + 8gpio for switch button

3. enable the shutter and the "property of shutters":
`SetOption80 1`
`ShutterRelay1 1`
`ShutterRelay2 3`
`ShutterRelay3 5`
`ShutterRelay4 7`
`Backlog Interlock 1,2 3,4 5,6 7,8; Interlock ON`
`ShutterOpenDuration1 15`
`ShutterOpenDuration2 15`
`ShutterCloseDuration1 8`
`ShutterCloseDuration2 8`
`ShutterOpenDuration3 15`
`ShutterCloseDuration3 8`
`ShutterOpenDuration4 15`
`ShutterCloseDuration4 8`

4. configure MQTT inside webpage dedicated
5. restart module
6. try to use to verify system stability....i can not enter anymore inside console for example.
also navigation trough the webpages the response time is very slow (only after configure the module)

if i do the same procedures with version 9.1.0 it works and works also with previous version 8.5
i discovered this issue upgrading n°3 units: 2 with 30pins and 1 with 38pins
downgrading from 9.2 to 9.1 all ESPs become stable and very fast moving from webpage to another

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

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

### ADDITIONAL CONTEXT
after many try just able to get that from console:

**(Please, remember to close the issue when the problem has been addressed)**
stefanbode commented 3 years ago

@ascillato2 : I assume this is not directly shutter related. Are you aware of any changes on the RTC timer handling that might cause the issue. The rest of the code is pretty standard.

megamarco833 commented 3 years ago

hi, thanks as always for reply. i just can say that from my test it appear and can be reproduced on the steps that i mentioned. that's the way how i discovered, i can not confirm that it's the only case where it is manifested, but activation of SetOption80 1 ShutterRelay1 1 and so on....create the system unstable. at the first flash, before using steps described in "how to reproduce", the system was pretty good. another note from my side, it is more evident on esp32, that was the system where i tested more.

stefanbode commented 3 years ago

@megamarco833 : I was now able to compile the current development version onto a new ESP32 Wemos mini dev board. I defined the relay in a different order I assume. I was not able to "decompile" it from the status. Mine start at GPIO4,5,12,13,14 like the list in the GUI and then Relay 1..8. I do not see any problems here. Works perfectly

stefanbode commented 3 years ago

I had some issues with my network and the mqtt in the beginning. This causes the system to get more or less unresponsive because it tries to connect to wifi and mqtt. SETOPTION57 1 might be a good idea to force a scan for the best network during boot. Also, you should verify that the device is ONLINE in the MQTT broker.

megamarco833 commented 3 years ago

@stefanbode first of all thanks for your reply and your tests that's very strange because i tried in two ways: 1) starting from a device esp32 nodemcu that was perfectly working with 9.1.0 since many days, and i update it to 9.1.0.2 and i find the issue reported: many disconnections and also quite impossible report any message from console due to impossibility to have access at it.

2) reflash from zero the new firmware 9.1.0.2 but also 9.2 and i got the same result

I had some issues with my network and the mqtt in the beginning. This causes the system to get more or less unresponsive because it tries to connect to wifi and mqtt. SETOPTION57 1 might be a good idea to force a scan for the best network during boot. Also, you should verify that the device is ONLINE in the MQTT broker.

now i'm with 9.1 and all is working

15:34:19 CMD: SETOPTION57 
15:34:19 MQT: stat/tasmota_esp32/RESULT = {"SetOption57":"OFF"}

now i activete setoption57


00:01:05 CMD: SETOPTION57  1
00:01:05 MQT: stat/tasmota_esp32_giallo/RESULT = {"SetOption57":"ON"}
00:01:11 MQT: Attempting connection...
00:01:11 MQT: Connected
00:01:11 MQT: tele/tasmota_esp32_giallo/LWT = Online (retained)

and after that if i update to 9.2 with tasmota32.bin it's almost impossible to see the webinterface. i wrote "almost impossible" because after 6 trial i succeed on see mainpage of webinterface, but i click in "console" and after some minutes i'm not able to see the console and a not responding web page appear . same thing if i try to go directly at console webpage: 192.168.0.55/cs (it's an update from 9.1.0 to 9.2 and i had fixed IP)

what i should do to solve this issue? or what i can report here....and how, because as i wrote it is almost impossible to get data due to unstable system and continuous reboot i do not know if it is related to GPIOs selected or of it's related to something else..but strange thing is that i have 2 nodemcu esp32 with 30 pins and 2 with 38pins and this issue il replicable in all ESPs and if i revert back to 9.1 it works like a charm

stefanbode commented 3 years ago

If you set setption80 0 it works again? Again Really hard to believe that any of the shutter functions cause the issue. Blocking Webinterface and Console is normally something that is connected to core functionality. Most often Wifi. Can you connect one of the ESp32 to serial and check if you get more info. Webinterface is many for this kind of investigations not the right thing

megamarco833 commented 3 years ago

i connected with usb and used termite enabling more debug as serial log:

11:55:02.685 MQT: tasmota/discovery/807D3AD54400/config = {"ip":"192.168.0.55","dn":"Tasmota ESP GIALLO IP55","fn":["Tasmota","Tasmota2","Tasmota3","Tasmota4","Tasmota5","Tasmota6","Tasmota7","Tasmota8"],"hn":"tasmota_esp32_giallo-1024","mac":"807D3AD54400","md":"ESP32-DevKit","ty":0,"if":0,"ofln":"Offline","onln":"Online","state":["OFF","ON","TOGGLE","HOLD"],"sw":"9.2.0.1","t":"tasmota_esp32_giallo","ft":"%prefix%/%topic%/","tp":["cmnd","stat","tele"],"rl":[3,3,3,3,3,3,3,3],"swc":[-1,-1,-1,-1,-1,-1,-1,-1],"swn":[null,null,null,null,null,null,null,null],"btn":[0,0,0,0],"so":{"4":0,"11":0,"13":0,"17":0,"20":0,"30":0,"68":0,"73":0,"82":0,"114":0},"lk":1,"lt_st":0,"sho":[0,0,0,0],"ver":1} (retained)
11:55:02.743 MQT: tasmota/discovery/807D3AD54400/sensors = {"sn":{"Time":"2020-12-29T11:55:02","Switch1":"ON","Switch2":"ON","Switch3":"ON","Switch4":"ON","Switch5":"ON","Switch6":"ON","Switch7":"ON","Switch8":"ON","Shutter1":{"Position":61,"Direction":0,"Target":61},"Shutter2":{"Position":43,"Direction":0,"Target":43},"Shutter3":{"Position":42,"Direction":0,"Target":42},"Shutter4":{"Position":31,"Direction":0,"Target":31}},"ver":1} (retained)
11:55:13.607 WIF: Checking connection...
Start 126000, Stop 144000, Dir 1, Delay 0, Rtc 0.25 [s], Freq 0, PWM 0
11:55:52.248 MQT: stat/tasmota_esp32_giallo/RESULT = {"Shutter3":{"Position":43,"Direction":1,"Target":48}}
11:55:52.252 SHT: time: 5, toBeAcc 0, current_stop_way 0,vel_cur 0, vel_max 0, act_vel_change 1000, min_runtime_ms 0, act.pos 130000, next_stop 0, target: 144000,  max_vel_change 0, dir: 1
11:55:52.320 SHT: time: 6, toBeAcc 0, current_stop_way 0,vel_cur 0, vel_max 0, act_vel_change 1000, min_runtime_ms 0, act.pos 131000, next_stop 0, target: 144000,  max_vel_change 0, dir: 1
11:55:52.327 SHT: Shutter 3 Real 131000, Start 126000, Stop 144000, Dir 1, Delay 0, Rtc 0.30 [s], Freq 0, PWM 0
11:55:52.340 MQT: stat/tasmota_esp32_giallo/RESULT = {"Shutter1":{"Position":61,"Direction":0,"Target":61},"Shutter2":{"Position":43,"Direction":0,"Target":43},"Shutter3":{"Position":44,"Direction":1,"Target":48},"Shutter4":{"Position":31,"Direction":0,"Target":31}}
11:55:52.370 SHT: time: 7, toBeAcc 0, current_stop_way 0,vel_cur 0, vel_max 0, act_vel_change 1000, min_runtime_ms 0, act.pos 132000, next_stop 0, target: 144000,  max_vel_change 0, dir: 1
11:55:52.420 SHT: time: 8, toBeAcc 0, current_stop_way 0,vel_cur 0, vel_max 0, act_vel_change 1000, min_runtime_ms 0, act.pos 133000, next_stop 0, target: 144000,  max_vel_change 0, dir: 1
11:55:52.470 SHT: time: 9, toBeAcc 0, current_stop_way 0,vel_cur 0, vel_max 0, act_vel_change 1000, min_runtime_ms 0, act.pos 134000, next_stop 0, target: 144000,  max_vel_change 0, dir: 1
11:55:52.520 SHT: time: 10, toBeAcc 0, current_stop_way 0,vel_cur 0, vel_max 0, act_vel_change 1000, min_runtime_ms 0, act.pos 135000, next_stop 0, target: 144000,  max_vel_change 0, dir: 1
11:55:52.570 SHT: time: 11, toBeAcc 0, current_stop_way 0,vel_cur 0, vel_max 0, act_vel_change 1000, min_runtime_ms 0, act.pos 136000, next_stop 0, target: 144000,  max_vel_change 0, dir: 1
11:55:52.620 SHT: time: 12, toBeAcc 0, current_stop_way 0,vel_cur 0, vel_max 0, act_vel_change 1000, min_runtime_ms 0, act.pos 137000, next_stop 0, target: 144000,  max_vel_change 0, dir: 1
11:55:52.670 SHT: time: 13, toBeAcc 0, current_stop_way 0,vel_cur 0, vel_max 0, act_vel_change 1000, min_runtime_ms 0, act.pos 138000, next_stop 0, target: 144000,  max_vel_change 0, dir: 1
11:55:52.719 SHT: time: 14, toBeAcc 0, current_stop_way 0,vel_cur 0, vel_max 0, act_vel_change 1000, min_runtime_ms 0, act.pos 139000, next_stop 0, target: 144000,  max_vel_change 0, dir: 1
11:55:52.807 CFG: Saved, Count 70, Bytes 4096
11:55:52.809 SHT: time: 16, toBeAcc 0, current_stop_way 0,vel_cur 0, vel_max 0, act_vel_change 1000, min_runtime_ms 0, act.pos 141000, next_stop 0, target: 144000,  max_vel_change 0, dir: 1
11:55:52.859 SHT: time: 17, toBeAcc 0, current_stop_way 0,vel_cur 0, vel_max 0, act_vel_change 1000, min_runtime_ms 0, act.pos 142000, next_stop 0, target: 144000,  max_vel_change 0, dir: 1
11:55:52.909 SHT: time: 18, toBeAcc 0, current_stop_way 0,vel_cur 0, vel_max 0, act_vel_change 1000, min_runtime_ms 0, act.pos 143000, next_stop 0, target: 144000,  max_vel_change 0, dir: 1
11:55:52.958 SHT: time: 19, toBeAcc 0, current_stop_way 0,vel_cur 0, vel_max 0, act_vel_change 1000, min_runtime_ms 0, act.pos 144000, next_stop 0, target: 144000,  max_vel_change 0, dir: 1
11:55:52.963 SHT: Stop Shutter 2. Switchmode 0
11:55:52.968 SRC: Shutter
11:55:52.970 SHT: Switched relay: 16 by Shutter
11:55:52.974 SHT: Shutter 1: source: Shutter, powerstate_local 0, ShutterGlobal.RelayCurrentMask 16, manual change 0
11:55:52.984 SHT: Shutter 2: source: Shutter, powerstate_local 0, ShutterGlobal.RelayCurrentMask 16, manual change 0
11:55:52.995 SHT: Shutter 3: source: Shutter, powerstate_local 0, ShutterGlobal.RelayCurrentMask 16, manual change 0
11:55:53.005 SHT: Shutter 4: source: Shutter, powerstate_local 0, ShutterGlobal.RelayCurrentMask 16, manual change 0
11:55:53.019 MQT: stat/tasmota_esp32_giallo/RESULT = {"POWER5":"OFF"}
11:55:53.025 MQT: stat/tasmota_esp32_giallo/POWER5 = OFF
11:55:53.528 SHT: Shutter 3 Real 145000, Start 145000, Stop 144000, Dir 0, Delay 0, Rtc 1.00 [s], Freq 0, PWM 0
11:55:53.533 MQT: stat/tasmota_esp32_giallo/SHUTTER3 = 48
11:55:53.538 MQT: stat/tasmota_esp32_giallo/RESULT = {"Shutter3":{"Position":48,"Direction":0,"Target":48}}
11:55:54.451 CFG: Saved, Count 71, Bytes 4096
11:55:55.552 WIF: Checking connection...
 = OFF
11:56:33.328 SRC: Shutter
11:56:33.330 SHT: Switched relay: 2 by Shutter
11:56:33.334 SHT: Shutter 1: source: Shutter, powerstate_local 0, ShutterGlobal.RelayCurrentMask 2, manual change 0
11:56:33.344 SHT: Shutter 2: source: Shutter, powerstate_local 0, ShutterGlobal.RelayCurrentMask 2, manual change 0
11:56:33.354 SHT: Shutter 3: source: Shutter, powerstate_local 0, ShutterGlobal.RelayCurrentMask 2, manual change 0
11:56:33.364 SHT: Shutter 4: source: Shutter, powerstate_local 0, ShutterGlobal.RelayCurrentMask 2, manual change 0
11:56:33.378 MQT: stat/tasmota_esp32_giallo/RESULT = {"POWER2":"OFF"}
11:56:33.384 MQT: stat/tasmota_esp32_giallo/POWER2 = OFF
11:56:33.887 SHT: Shutter 1 Real 139875, Start 139875, Stop 144000, Dir 0, Delay 0, Rtc 1.20 [s], Freq 0, PWM 0
11:56:33.890 MQT: stat/tasmota_esp32_giallo/SHUTTER1 = 47
11:56:33.895 MQT: stat/tasmota_esp32_giallo/RESULT = {"Shutter1":{"Position":47,"Direction":0,"Target":48}}
11:56:34.543 CFG: Saved, Count 73, Bytes 4096
11:57:02.467 SRC: WebGui from 192.168.0.4
11:57:02.468 CMD: Group 0, Index 4, Command "SHUTTERPOSITION", Data "53"
11:57:02.469 SHT: Pos. in: payload 53 (2), payload 53, idx 4, src 7
11:57:02.472 SHT: lastsource 7:, real 93000, target 159000, payload 53
11:57:02.478 SHT: Delay Start. var6 <99>=<>, max10s?
11:57:02.483 SHT: Delay Start. Done
11:57:02.486 SRC: Shutter
11:57:02.488 SHT: Switched relay: 0 by Shutter
11:57:02.493 SHT: Shutter 1: source: Shutter, powerstate_local 0, ShutterGlobal.RelayCurrentMask 0, manual change 0
11:57:02.503 SHT: Shutter 2: source: Shutter, powerstate_local 0, ShutterGlobal.RelayCurrentMask 0, manual change 0
11:57:02.513 SHT: Shutter 3: source: Shutter, powerstate_local 0, ShutterGlobal.RelayCurrentMask 0, manual change 0
11:57:02.523 SHT: Shutter 4: source: Shutter, powerstate_local 0, ShutterGlobal.RelayCurrentMask 0, manual change 0
11:57:02.540 MQT: stat/tasmota_esp32_giallo/RESULT = {"POWER8":"OFF"}
11:57:02.545 MQT: stat/tasmota_esp32_giallo/POWER8 = OFF
11:57:02.547 SRC: Shutter
11:57:02.547 SHT: Switched relay: 64 by Shutter
11:57:02.551 SHT: Shutter 1: source: Shutter, powerstate_local 0, ShutterGlobal.RelayCurrentMask 64, manual change 0
11:57:02.561 SHT: Shutter 2: source: Shutter, powerstate_local 0, ShutterGlobal.RelayCurrentMask 64, manual change 0
11:57:02.571 SHT: Shutter 3: source: Shutter, powerstate_local 0, ShutterGlobal.RelayCurrentMask 64, manual change 0
11:57:02.582 SHT: Shutter 4: source: Shutter, powerstate_local 1, ShutterGlobal.RelayCurrentMask 64, manual change 0
11:57:02.595 MQT: stat/tasmota_esp32_giallo/RESULT = {"POWER7":"ON"}
11:57:02.602 MQT: stat/tasmota_esp32_giallo/POWER7 = ON
11:57:02.608 MQT: stat/tasmota_esp32_giallo/RESULT = {"ShutterPosition4":53}
11:57:22.668 SHT: Shutter 4 Real 495000, Start 93000, Stop 159000, Dir 1, Delay 0, Rtc 20.15 [s], Freq 0, PWM 0
11:57:22.672 MQT: stat/tasmota_esp32_giallo/RESULT = {"Shutter4":{"Position":100,"Direction":1,"Target":53}}
11:57:22.679 SHT: time: 403, toBeAcc 0, current_stop_way 0,vel_cur 0, vel_max 0, act_vel_change 1000, min_runtime_ms 0, act.pos 495000, next_stop 0, target: 159000,  max_vel_change 0, dir: 1
11:57:22.693 SHT: Stop Shutter 3. Switchmode 0
11:57:22.697 SRC: Shutter
11:57:22.700 SHT: Switched relay: 64 by Shutter
11:57:22.704 SHT: Shutter 1: source: Shutter, powerstate_local 0, ShutterGlobal.RelayCurrentMask 64, manual change 0
11:57:22.714 SHT: Shutter 2: source: Shutter, powerstate_local 0, ShutterGlobal.RelayCurrentMask 64, manual change 0
11:57:22.724 SHT: Shutter 3: source: Shutter, powerstate_local 0, ShutterGlobal.RelayCurrentMask 64, manual change 0
11:57:22.735 SHT: Shutter 4: source: Shutter, powerstate_local 0, ShutterGlobal.RelayCurrentMask 64, manual change 0
11:57:22.749 MQT: stat/tasmota_esp32_giallo/RESULT = {"POWER7":"OFF"}
11:57:22.755 MQT: stat/tasmota_esp32_giallo/POWER7 = OFF
11:57:23.257 SHT: Shutter 4 Real 300000, Start 300000, Stop 159000, Dir 0, Delay 0, Rtc 20.25 [s], Freq 0, PWM 0
11:57:23.263 MQT: stat/tasmota_esp32_giallo/SHUTTER4 = 100
11:57:23.268 MQT: stat/tasmota_esp32_giallo/RESULT = {"Shutter4":{"Position":100,"Direction":0,"Target":53}}
11:57:23.599 HTP: Console
11:57:24.370 CFG: Saved, Count 74, Bytes 4096
11:57:44.690 MQT: Attempting connection...

this is the log, as you can see initially the ESP works well, and i triggered some times the shutter and them respond correct but after some time i click to console (seams that loading console web page is the worst case) nothing appear:

immagine

after some minutes... immagine the console appear

11:57:23.599 HTP: Console
11:57:24.370 CFG: Saved, Count 74, Bytes 4096
11:57:44.690 MQT: Attempting connection...
12:01:06.457 WIF: Checking connection...

so 

11:57:23.599 HTP: Console
11:57:24.370 CFG: Saved, Count 74, Bytes 4096
11:57:44.690 MQT: Attempting connection...
12:01:06.457 WIF: Checking connection...
12:01:58.169 SHT: time: 84, toBeAcc 0, current_stop_way 0,vel_cur 0, vel_max 0, act_vel_change 1000, min_runtime_ms 0, act.pos 144375, next_stop 0, target: 126000,  max_vel_change 0, dir: -1
12:01:58.177 SHT: Shutter 4 Real 144375, Start 300000, Stop 126000, Dir -1, Delay 0, Rtc 4.20 [s], Freq 0, PWM 0
12:01:58.190 MQT: stat/tasmota_esp32_giallo/RESULT = {"Shutter1":{"Position":47,"Direction":0,"Target":48},"Shutter2":{"Position":43,"Direction":0,"Target":43},"Shutter3":{"Position":48,"Direction":0,"Target":48},"Shutter4":{"Position":48,"Direction":-1,"Target":42}}
12:01:58.263 SHT: time: 86, toBeAcc 0, current_stop_way 0,vel_cur 0, vel_max 0, act_vel_change 1000, min_runtime_ms 0, act.pos 140625, next_stop 0, target: 126000,  max_vel_change 0, dir: -1
12:01:58.313 SHT: time: 87, toBeAcc 0, current_stop_way 0,vel_cur 0, vel_max 0, act_vel_change 1000, min_runtime_ms 0, act.pos 138750, next_stop 0, target: 126000,  max_vel_change 0, dir: -1
12:01:58.363 SHT: time: 88, toBeAcc 0, current_stop_way 0,vel_cur 0, vel_max 0, act_vel_change 1000, min_runtime_ms 0, act.pos 136875, next_stop 0, target: 126000,  max_vel_change 0, dir: -1
12:01:58.413 SHT: time: 89, toBeAcc 0, current_stop_way 0,vel_cur 0, vel_max 0, act_vel_change 1000, min_runtime_ms 0, act.pos 135000, next_stop 0, target: 126000,  max_vel_change 0, dir: -1
12:01:58.462 SHT: time: 90, toBeAcc 0, current_stop_way 0,vel_cur 0, vel_max 0, act_vel_change 1000, min_runtime_ms 0, act.pos 133125, next_stop 0, target: 126000,  max_vel_change 0, dir: -1
12:01:58.512 SHT: time: 91, toBeAcc 0, current_stop_way 0,vel_cur 0, vel_max 0, act_vel_change 1000, min_runtime_ms 0, act.pos 131250, next_stop 0, target: 126000,  max_vel_change 0, dir: -1
12:01:58.561 SHT: time: 92, toBeAcc 0, current_stop_way 0,vel_cur 0, vel_max 0, act_vel_change 1000, min_runtime_ms 0, act.pos 129375, next_stop 0, target: 126000,  max_vel_change 0, dir: -1
12:01:58.611 SHT: time: 93, toBeAcc 0, current_stop_way 0,vel_cur 0, vel_max 0, act_vel_change 1000, min_runtime_ms 0, act.pos 127500, next_stop 0, target: 126000,  max_vel_change 0, dir: -1
12:01:58.661 SHT: time: 94, toBeAcc 0, current_stop_way 0,vel_cur 0, vel_max 0, act_vel_change 1000, min_runtime_ms 0, act.pos 125625, next_stop 0, target: 126000,  max_vel_change 0, dir: -1
12:01:58.666 SHT: Stop Shutter 3. Switchmode 0
12:01:58.671 SRC: Shutter
12:01:58.673 SHT: Switched relay: 64 by Shutter
12:01:58.677 SHT: Shutter 1: source: Shutter, powerstate_local 0, ShutterGlobal.RelayCurrentMask 64, manual change 0
12:01:58.688 SHT: Shutter 2: source: Shutter, powerstate_local 0, ShutterGlobal.RelayCurrentMask 64, manual change 0
12:01:58.698 SHT: Shutter 3: source: Shutter, powerstate_local 0, ShutterGlobal.RelayCurrentMask 64, manual change 0
12:01:58.708 SHT: Shutter 4: source: Shutter, powerstate_local 2, ShutterGlobal.RelayCurrentMask 64, manual change 0
12:01:58.722 MQT: stat/tasmota_esp32_giallo/RESULT = {"POWER7":"OFF"}
12:01:58.728 MQT: stat/tasmota_esp32_giallo/POWER7 = OFF
12:01:58.730 SRC: Shutter
12:01:58.732 SHT: Switched relay: 128 by Shutter
12:01:58.736 SHT: Shutter 1: source: Shutter, powerstate_local 0, ShutterGlobal.RelayCurrentMask 128, manual change 0
12:01:58.747 SHT: Shutter 2: source: Shutter, powerstate_local 0, ShutterGlobal.RelayCurrentMask 128, manual change 0
12:01:58.757 SHT: Shutter 3: source: Shutter, powerstate_local 0, ShutterGlobal.RelayCurrentMask 128, manual change 0
12:01:58.767 SHT: Shutter 4: source: Shutter, powerstate_local 0, ShutterGlobal.RelayCurrentMask 128, manual change 0
12:01:58.781 MQT: stat/tasmota_esp32_giallo/RESULT = {"POWER8":"OFF"}
12:01:58.788 MQT: stat/tasmota_esp32_giallo/POWER8 = OFF
12:01:59.290 SHT: Shutter 4 Real 120000, Start 120000, Stop 126000, Dir 0, Delay 0, Rtc 4.85 [s], Freq 0, PWM 0
12:01:59.294 MQT: stat/tasmota_esp32_giallo/SHUTTER4 = 40
12:01:59.299 MQT: stat/tasmota_esp32_giallo/RESULT = {"Shutter4":{"Position":40,"Direction":0,"Target":42}}
12:01:59.445 CFG: Saved, Count 76, Bytes 4096
12:02:10.083 WIF: Checking connection...
12:02:30.058 WIF: Checking connection...
12:02:50.084 WIF: Checking connection...

and again immagine immagine immagine look at the time i also try to refresh the webpage and i got the not responding webpage

but without disconnect the power (never did since i beging this test) I refresh the console webpage , console this time appear (it was not responding webpage), then i go to main page and click info webpage: immagine

as you can see the ESP is alive since 10minutes...so not reported here as disconnected... last terminal report:

12:01:59.445 CFG: Saved, Count 76, Bytes 4096
12:02:10.083 WIF: Checking connection...
12:02:30.058 WIF: Checking connection...
12:02:50.084 WIF: Checking connection...
12:04:35.342 WIF: Checking connection...
12:04:41.701 HTP: Console
12:04:46.412 HTP: Main Menu

so also for me the issue is related to wifi or something similar, but wifi source AP is the same for me when i use firmware 9.1.0 or 9.1.0.2 or 9.2 or 9.2.0.1 like in this tests, but 9.1.0 it works perfectly, the system is fast and never got any issue, with 9.1.0.2 or above this is the situation

megamarco833 commented 3 years ago

i try to remove setoption80 1 a bit dificult because i need to operate with a system that is not responding.... i had to power off and then power on because when i try to enter inside console at this time also refreshing 4 times the web page i got every time not responding.

12:14:58.091 MQT: Attempting connection...
12:14:58.211 MQT: Connected
12:14:58.216 MQT: tele/tasmota_esp32_giallo/LWT = Online (retained)
12:14:58.221 MQT: cmnd/tasmota_esp32_giallo/POWER = 
12:14:58.780 MQT: tele/tasmota_esp32_giallo/STATE = {"Time":"2020-12-29T12:14:58","Uptime":"0T00:00:13","UptimeSec":13,"Heap":111,"SleepMode":"Dynamic","Sleep":50,"LoadAvg":396,"MqttCount":3,"POWER1":"OFF","POWER2":"OFF","POWER3":"OFF","POWER4":"OFF","POWER5":"OFF","POWER6":"OFF","POWER7":"OFF","POWER8":"OFF","Wifi":{"AP":1,"SSId":"NETGEAR","BSSId":"E0:3F:49:A8:C5:70","Channel":11,"RSSI":68,"Signal":-66,"LinkCount":1,"Downtime":"0T00:00:05"}}
12:14:58.820 MQT: tele/tasmota_esp32_giallo/SENSOR = {"Time":"2020-12-29T12:14:58","Switch1":"ON","Switch2":"ON","Switch3":"ON","Switch4":"ON","Switch5":"ON","Switch6":"ON","Switch7":"ON","Switch8":"ON","Shutter1":{"Position":47,"Direction":0,"Target":47},"Shutter2":{"Position":43,"Direction":0,"Target":43},"Shutter3":{"Position":48,"Direction":0,"Target":48},"Shutter4":{"Position":40,"Direction":0,"Target":40}}
12:15:04.875 CMD: setoption80 0
12:15:04.887 MQT: stat/tasmota_esp32_giallo/RESULT = {"SetOption80":"OFF"}
12:02:10.083 WIF: Checking connection...
12:02:30.058 WIF: Checking connection...
12:02:50.084 WIF: Checking connection...
12:04:35.342 WIF: Checking connection...
12:04:41.701 HTP: Console
12:04:46.412 HTP: Main Menu
12:08:45.350 WIF: Checking connection...
00:00:07.125 NTP: No reply
00:00:07.134 HTP: Web server active on tasmota_esp32_giallo-1024 with IP address 192.168.0.55
00:00:07.373 RTC: UTC 2020-12-29T11:14:52, DST 2020-03-29T02:00:00, STD 2020-10-25T03:00:00
12:14:52.413 QPC: Reset
12:14:53.174 MQT: Attempting connection...
12:14:53.610 MQT: Connected
12:14:53.615 MQT: tele/tasmota_esp32_giallo/LWT = Online (retained)
12:14:53.618 MQT: cmnd/tasmota_esp32_giallo/POWER = 
12:14:53.620 MQT: Subscribe to cmnd/tasmota_esp32_giallo/#
12:14:53.625 MQT: Subscribe to cmnd/tasmotas/#
12:14:53.631 MQT: Subscribe to cmnd/DVES_D54400_fb/#
12:14:53.633 MQT: Unsubscribe from homeassistant/status
12:14:53.640 MQT: tele/tasmota_esp32_giallo/INFO1 = {"Module":"ESP32-DevKit","Version":"9.2.0.1(tasmota)","FallbackTopic":"cmnd/DVES_D54400_fb/","GroupTopic":"cmnd/tasmotas/"}
12:14:53.652 MQT: tele/tasmota_esp32_giallo/INFO2 = {"WebServerMode":"Admin","Hostname":"tasmota_esp32_giallo-1024","IPAddress":"192.168.0.55"}
12:14:53.665 MQT: tele/tasmota_esp32_giallo/INFO3 = {"RestartReason":"Vbat power on reset"}
12:14:53.673 MQT: stat/tasmota_esp32_giallo/RESULT = {"POWER1":"OFF"}
12:14:53.679 MQT: stat/tasmota_esp32_giallo/POWER1 = OFF
12:14:53.684 MQT: stat/tasmota_esp32_giallo/RESULT = {"POWER2":"OFF"}
12:14:53.699 MQT: stat/tasmota_esp32_giallo/POWER2 = OFF
12:14:53.702 MQT: stat/tasmota_esp32_giallo/RESULT = {"POWER3":"OFF"}
12:14:53.706 MQT: stat/tasmota_esp32_giallo/POWER3 = OFF
12:14:53.710 MQT: stat/tasmota_esp32_giallo/RESULT = {"POWER4":"OFF"}
12:14:53.728 MQT: stat/tasmota_esp32_giallo/POWER4 = OFF
12:14:53.733 MQT: stat/tasmota_esp32_giallo/RESULT = {"POWER5":"OFF"}
12:14:53.737 MQT: stat/tasmota_esp32_giallo/POWER5 = OFF
12:14:53.740 MQT: stat/tasmota_esp32_giallo/RESULT = {"POWER6":"OFF"}
12:14:53.744 MQT: stat/tasmota_esp32_giallo/POWER6 = OFF
12:14:53.748 MQT: stat/tasmota_esp32_giallo/RESULT = {"POWER7":"OFF"}
12:14:53.754 MQT: stat/tasmota_esp32_giallo/POWER7 = OFF
12:14:53.759 MQT: stat/tasmota_esp32_giallo/RESULT = {"POWER8":"OFF"}
12:14:53.765 MQT: stat/tasmota_esp32_giallo/POWER8 = OFF
12:14:54.898 MQT: Attempting connection...
12:14:55.052 MQT: Connected
12:14:55.063 MQT: tele/tasmota_esp32_giallo/LWT = Online (retained)
12:14:55.067 MQT: cmnd/tasmota_esp32_giallo/POWER = 
12:14:55.069 MQT: Subscribe to cmnd/tasmota_esp32_giallo/#
12:14:55.072 MQT: Subscribe to cmnd/tasmotas/#
12:14:55.075 MQT: Subscribe to cmnd/DVES_D54400_fb/#
12:14:55.079 MQT: Unsubscribe from homeassistant/status
12:14:55.084 APP: Boot Count 19
12:14:55.095 HTP: Console
12:14:55.756 CFG: Saved, Count 77, Bytes 4096
12:15:35.156 WIF: Checking connection...
12:16:28.309 WIF: Checking connection...
12:16:54.715 MQT: Attempting connection...
12:16:55.694 MQT: Connected
12:16:55.701 MQT: tele/tasmota_esp32_giallo/LWT = Online (retained)
12:16:55.705 MQT: cmnd/tasmota_esp32_giallo/POWER = 
12:16:55.707 MQT: Subscribe to cmnd/tasmota_esp32_giallo/#
12:16:55.710 MQT: Subscribe to cmnd/tasmotas/#
12:16:55.712 MQT: Subscribe to cmnd/DVES_D54400_fb/#
12:16:55.716 MQT: Unsubscribe from homeassistant/status

it seams that nothing is going better.... ;(

now i try to remove all configuration of relay_i and switches: this is the configuration that i have:
( i pay attention and try to use the best GPIOs that can correctly used for output for raly and for input to swetches, hope that i do not make any mistake here) immagine and i select all GPIOs to NONE

12:14:55.075 MQT: Subscribe to cmnd/DVES_D54400_fb/#
12:14:55.079 MQT: Unsubscribe from homeassistant/status
12:14:55.084 APP: Boot Count 19
12:14:55.095 HTP: Console
12:14:55.756 CFG: Saved, Count 77, Bytes 4096
12:15:35.156 WIF: Checking connection...
12:16:28.309 WIF: Checking connection...
12:16:54.715 MQT: Attempting connection...
12:16:55.694 MQT: Connected
12:16:55.701 MQT: tele/tasmota_esp32_giallo/LWT = Online (retained)
12:16:55.705 MQT: cmnd/tasmota_esp32_giallo/POWER = 
12:16:55.707 MQT: Subscribe to cmnd/tasmota_esp32_giallo/#
12:16:55.710 MQT: Subscribe to cmnd/tasmotas/#
12:16:55.712 MQT: Subscribe to cmnd/DVES_D54400_fb/#
12:16:55.716 MQT: Unsubscribe from homeassistant/status
12:17:44.918 SRC: WebGui from 192.168.0.4
12:17:45.270 CFG: Saved, Count 81, Bytes 4096
12:17:46.172 APP: Restarting
ets Jun  8 2016 00:22:57

rst:0xc (SW_CPU_RESET),boot:0x13 (SPI_FAST_FLASH_BOOT)
configsip: 0, SPIWP:0xee
clk_drv:0x00,q_drv:0x00,d_drv:0x00,cs0_drv:0x00,hd_drv:0x00,wp_drv:0x00
mode:DOUT, clock div:2
load:0x3fff0018,len:4
load:0x3fff001c,len:1044
load:0x40078000,len:8896
load:0x40080400,len:5828
entry 0x400806ac

00:00:00.037 CFG: Loaded, Count 81
00:00:00.052 QPC: Count 1
00:00:00.053 CFG: CR 430/699, Busy 0
00:00:00.057 SRC: Restart
00:00:00.058 Project tasmota Tasmota ESP GIALLO IP55 Version 9.2.0.1(tasmota)-1_0_5_RC4(2020-12-28T12:17:30)
00:00:00.209 WIF: Checking connection...
00:00:00.210 WIF: Attempting connection...
00:00:00.760 WIF: Connecting to AP1 NETGEAR Channel 11 BSSId E0:3F:49:A8:C5:70 in mode 11n as tasmota_esp32_giallo-1024...
12:18:25.244 HTP: Configuration
12:18:28.016 HTP: Main Menu
12:18:43.259 WIF: Checking connection...
12:19:30.148 WIF: Checking connection...

in this case the issue seams to be disappear....now the system is responding better (not fast like in 9.1.0) after using for 4minutes i do not got any not responding web page the system seams to be responding well immagine

entering inside console (that was the menu that mainly caused crash) seems to be respond now, but a bit slow 

00:00:00.037 CFG: Loaded, Count 81
00:00:00.052 QPC: Count 1
00:00:00.058 Project tasmota Tasmota ESP GIALLO IP55 Version 9.2.0.1(tasmota)-1_0_5_RC4(2020-12-28T12:17:30)
00:00:00.760 WIF: Connecting to AP1 NETGEAR Channel 11 BSSId E0:3F:49:A8:C5:70 in mode 11n as tasmota_esp32_giallo-1024...
00:00:04.729 WIF: Connected
12:17:53.007 HTP: Web server active on tasmota_esp32_giallo-1024 with IP address 192.168.0.55
12:17:55.743 QPC: Reset
12:17:55.996 MQT: Attempting connection...
12:17:57.169 MQT: Connected
12:17:57.175 MQT: tele/tasmota_esp32_giallo/LWT = Online (retained)
12:17:57.179 MQT: cmnd/tasmota_esp32_giallo/POWER = 
12:17:57.200 MQT: tele/tasmota_esp32_giallo/INFO1 = {"Module":"ESP32-DevKit","Version":"9.2.0.1(tasmota)","FallbackTopic":"cmnd/DVES_D54400_fb/","GroupTopic":"cmnd/tasmotas/"}
12:17:57.213 MQT: tele/tasmota_esp32_giallo/INFO2 = {"WebServerMode":"Admin","Hostname":"tasmota_esp32_giallo-1024","IPAddress":"192.168.0.55"}
12:17:57.225 MQT: tele/tasmota_esp32_giallo/INFO3 = {"RestartReason":"Software reset CPU"}
12:18:01.873 MQT: tele/tasmota_esp32_giallo/STATE = {"Time":"2020-12-29T12:18:01","Uptime":"0T00:00:14","UptimeSec":14,"Heap":111,"SleepMode":"Dynamic","Sleep":50,"LoadAvg":67,"MqttCount":1,"Wifi":{"AP":1,"SSId":"NETGEAR","BSSId":"E0:3F:49:A8:C5:70","Channel":11,"RSSI":72,"Signal":-64,"LinkCount":1,"Downtime":"0T00:00:05"}}
12:23:21.663 MQT: tele/tasmota_esp32_giallo/STATE = {"Time":"2020-12-29T12:23:21","Uptime":"0T00:05:34","UptimeSec":334,"Heap":95,"SleepMode":"Dynamic","Sleep":50,"LoadAvg":19,"MqttCount":1,"Wifi":{"AP":1,"SSId":"NETGEAR","BSSId":"E0:3F:49:A8:C5:70","Channel":11,"RSSI":68,"Signal":-66,"LinkCount":1,"Downtime":"0T00:00:05"}}
12:24:16.076 WIF: Connecting to AP1 NETGEAR Channel 11 BSSId E0:3F:49:A8:C5:70 in mode 11n as tasmota_esp32_giallo-1024...
12:24:17.965 WIF: Connected
12:24:18.215 MQT: Attempting connection...
12:24:18.417 MQT: Connected
12:24:18.422 MQT: tele/tasmota_esp32_giallo/LWT = Online (retained)
12:24:18.426 MQT: cmnd/tasmota_esp32_giallo/POWER = 
12:28:35.995 APP: Serial logging disabled
12:28:56.667 MQT: tele/tasmota_esp32_giallo/STATE = {"Time":"2020-12-29T12:28:56","Uptime":"0T00:11:09","UptimeSec":669,"Heap":75,"SleepMode":"Dynamic","Sleep":50,"LoadAvg":19,"MqttCount":2,"Wifi":{"AP":1,"SSId":"NETGEAR","BSSId":"E0:3F:49:A8:C5:70","Channel":11,"RSSI":64,"Signal":-68,"LinkCount":2,"Downtime":"0T00:00:11"}}

it seams that removing GPIOs assigned improve the stability...i do not know if it really connected or not, anyway i notice that flasing brand new the esp and whitout configurating nothing it seams that no issue in fact inside the steps to reproduce i wrote to assign GPIOs like this: immagine

if i can help with other tests or log i will do.

just a note, please have a look at another ESP32 nodemcu that is currently working managing 4 shutters, same configuration of GPIOs switches and connected to same AP wifi network immagine as you can see with fw 9.1.0 is working wihout any disconnection since 10days if you need some logs from this device with 9.1.0 to compare I can of course do.

p.s. this is only connected to ESP32 i update an ESP8266 nodemcu that control 4 shutters and 8 switches (pcf8576 used to control 8 relays) is working very good with 9.2.0.1

UPDATE: after 2 hours where i not use ESP32 with 9.2.0.1 firmware, i try to get access to console web page, this time i get no access, and after a minute i got again web page not responding. i reboot the ESP32 powering off and then on and it become working.

12:18:25.244 HTP: Configuration
12:18:28.016 HTP: Main Menu
12:18:43.259 WIF: Checking connection...
12:19:30.148 WIF: Checking connection...
00:00:07.275 RTC: UTC 2020-12-29T13:42:28, DST 2020-03-29T02:00:00, STD 2020-10-25T03:00:00
14:42:28.008 HTP: Web server active on tasmota_esp32_giallo-1024 with IP address 192.168.0.55
14:42:28.019 QPC: Reset
14:42:28.509 HTP: Console
14:42:29.575 MQT: Attempting connection...
14:42:35.408 MQT: Connected
14:42:35.415 MQT: tele/tasmota_esp32_giallo/LWT = Online (retained)
14:42:35.421 MQT: cmnd/tasmota_esp32_giallo/POWER = 
14:42:35.422 MQT: Subscribe to cmnd/tasmota_esp32_giallo/#
14:42:35.425 MQT: Subscribe to cmnd/tasmotas/#
14:42:35.428 MQT: Subscribe to cmnd/DVES_D54400_fb/#
14:42:35.431 MQT: Unsubscribe from homeassistant/status
14:42:35.440 MQT: tele/tasmota_esp32_giallo/INFO1 = {"Module":"ESP32-DevKit","Version":"9.2.0.1(tasmota)","FallbackTopic":"cmnd/DVES_D54400_fb/","GroupTopic":"cmnd/tasmotas/"}
14:42:35.453 MQT: tele/tasmota_esp32_giallo/INFO2 = {"WebServerMode":"Admin","Hostname":"tasmota_esp32_giallo-1024","IPAddress":"192.168.0.55"}
14:42:35.465 MQT: tele/tasmota_esp32_giallo/INFO3 = {"RestartReason":"Vbat power on reset"}
14:42:35.471 APP: Boot Count 21
14:42:35.906 CFG: Saved, Count 83, Bytes 4096
14:43:29.196 MQT: Attempting connection...
14:43:29.592 MQT: Connected
14:43:29.599 MQT: tele/tasmota_esp32_giallo/LWT = Online (retained)
14:43:29.603 MQT: cmnd/tasmota_esp32_giallo/POWER = 
14:43:29.604 MQT: Subscribe to cmnd/tasmota_esp32_giallo/#
14:43:29.608 MQT: Subscribe to cmnd/tasmotas/#
14:43:29.610 MQT: Subscribe to cmnd/DVES_D54400_fb/#
14:43:29.615 MQT: Unsubscribe from homeassistant/status
14:43:30.532 MQT: tele/tasmota_esp32_giallo/STATE = {"Time":"2020-12-29T14:43:30","Uptime":"0T00:01:09","UptimeSec":69,"Heap":111,"SleepMode":"Dynamic","Sleep":50,"LoadAvg":1226,"MqttCount":2,"Wifi":{"AP":1,"SSId":"NETGEAR","BSSId":"E0:3F:49:A8:C5:70","Channel":11,"RSSI":62,"Signal":-69,"LinkCount":1,"Downtime":"0T00:00:06"}}
14:44:25.240 WIF: Checking connection...

i check right now the other ESP32 with fw 9.1.0 and it is still working and responding very fast withuot any disconnection. immagine of course the wifi network is the same for both and thet are also located very close to wifi and both ESPs are in same place

Bascht74 commented 3 years ago

Hi @stefanbode I am facing the same problem with the newest firmware (9.0.2), that I installed at one device. If I close the shutters, it worked every tim. But if the Position is zero and I command shutter open, the relay is only shortly "clicking" and resets the device.

00:00:00.049 CFG: aus Flash geladen am F9, zählen 50
00:00:00.054 QPC: Count 1
00:00:00.161 I2C: ADE7953 gefunden bei 0x38
00:00:00.166 Projekt tasmota Rollo.OG.Schlafzimmer Version 9.2.0.2(tasmota)-2_7_4_9(2021.01.01 16:33:51)
00:00:04.647 WIF: verbinden mit AP1 IOT-LOTZ Channel 10 BSSId E2:63:DA:33:86:8A in Modus 11n als Rollo.OG.Schlafzimmer...
00:00:06.219 QPC: Reset
00:00:06.908 WIF: verbunden
00:00:07.186 HTP: Web-Server aktiv bei Rollo.OG.Schlafzimmer mit IP-Adresse 192.168.175.86
02:36:39.128 MQT: Verbindungsversuch...
02:36:39.460 MQT: verbunden
02:36:39.464 MQT: tele/Rollo.OG.Schlafzimmer/LWT = Online (beibehalten)
02:36:39.466 MQT: cmnd/Rollo.OG.Schlafzimmer/POWER = 
02:36:39.481 MQT: tele/Rollo.OG.Schlafzimmer/INFO1 = {"Module":"Shelly 2.5","Version":"9.2.0.2(tasmota)","FallbackTopic":"cmnd/DVES_F926FB_fb/","GroupTopic":"cmnd/rollos_alle/"}
02:36:39.491 MQT: tele/Rollo.OG.Schlafzimmer/INFO2 = {"WebServerMode":"Admin","Hostname":"Rollo.OG.Schlafzimmer","IPAddress":"192.168.175.86"}
02:36:39.503 MQT: tele/Rollo.OG.Schlafzimmer/INFO3 = {"RestartReason":"External System"}
02:36:39.511 MQT: stat/Rollo.OG.Schlafzimmer/RESULT = {"POWER1":"OFF"}
02:36:39.517 MQT: stat/Rollo.OG.Schlafzimmer/POWER1 = OFF (beibehalten)
02:36:39.524 MQT: stat/Rollo.OG.Schlafzimmer/RESULT = {"POWER2":"OFF"}
02:36:39.529 MQT: stat/Rollo.OG.Schlafzimmer/POWER2 = OFF (beibehalten)
02:36:40.554 MQT: stat/Rollo.OG.Schlafzimmer/STATUS10 = {"StatusSNS":{"Time":"2021-01-02T02:36:40","Switch1":"OFF","Switch2":"OFF","ANALOG":{"Temperature":49.1},"ENERGY":{"TotalStartTime":"2020-12-09T09:59:34","Total":0.002,"Yesterday":0.001,"Today":0.001,"Power":[0,0],"ApparentPower":[0,0],"ReactivePower":[0,0],"Factor":[0.00,0.00],"Voltage":0,"Current":[0.000,0.000]},"Shutter1":{"Position":0,"Direction":0,"Target":0},"TempUnit":"C"}}
02:36:43.216 MQT: tele/Rollo.OG.Schlafzimmer/STATE = {"Time":"2021-01-02T02:36:43","Uptime":"0T00:00:14","UptimeSec":14,"Heap":28,"SleepMode":"Dynamic","Sleep":50,"LoadAvg":19,"MqttCount":1,"POWER1":"OFF","POWER2":"OFF","Wifi":{"AP":1,"SSId":"IOT-LOTZ","BSSId":"E2:63:DA:33:86:8A","Channel":10,"RSSI":76,"Signal":-62,"LinkCount":1,"Downtime":"0T00:00:08"}}
02:36:43.249 MQT: tele/Rollo.OG.Schlafzimmer/SENSOR = {"Time":"2021-01-02T02:36:43","Switch1":"OFF","Switch2":"OFF","ANALOG":{"Temperature":49.2},"ENERGY":{"TotalStartTime":"2020-12-09T09:59:34","Total":0.002,"Yesterday":0.001,"Today":0.001,"Period":0,"Power":[0,0],"ApparentPower":[0,0],"ReactivePower":[0,0],"Factor":[0.00,0.00],"Voltage":0,"Current":[0.000,0.000]},"Shutter1":{"Position":0,"Direction":0,"Target":0},"TempUnit":"C"}

If I try with setoption 80 0 the following happens:

power2 on works

02:39:14.789 CMD: power2 on 02:39:14.797 MQT: stat/Rollo.OG.Schlafzimmer/RESULT = {"POWER2":"ON"} 02:39:14.802 MQT: stat/Rollo.OG.Schlafzimmer/POWER2 = ON (beibehalten) 02:39:20.223 CMD: power2 off 02:39:20.231 MQT: stat/Rollo.OG.Schlafzimmer/RESULT = {"POWER2":"OFF"} 02:39:20.237 MQT: stat/Rollo.OG.Schlafzimmer/POWER2 = OFF (beibehalten)

'power1 on' doesn't:

If I send backlog delay 5000; power1 on it accepts the command and then, after 5 seconds, it reboots...

00:00:00.050 CFG: aus Flash geladen am FA, zählen 57 00:00:00.055 QPC: Count 1 00:00:00.162 I2C: ADE7953 gefunden bei 0x38 00:00:00.164 Projekt tasmota Rollo.OG.Schlafzimmer Version 9.2.0.2(tasmota)-2_7_4_9(2021.01.01 16:33:51) 00:00:04.626 WIF: verbinden mit AP1 IOT-LOTZ Channel 10 BSSId E2:63:DA:33:86:8A in Modus 11n als Rollo.OG.Schlafzimmer... 00:00:05.882 WIF: verbunden 00:00:06.179 HTP: Web-Server aktiv bei Rollo.OG.Schlafzimmer mit IP-Adresse 192.168.175.86 00:00:06.295 QPC: Reset 02:40:18.178 MQT: Verbindungsversuch... 02:40:18.198 MQT: verbunden 02:40:18.211 MQT: tele/Rollo.OG.Schlafzimmer/LWT = Online (beibehalten)

So, it has nothing todo (at least in my case) with the shutter code, but with the power1 on

Here is some info: 

02:42:48.553 MQT: stat/Rollo.OG.Schlafzimmer/STATUS = {"Status":{"Module":0,"DeviceName":"Rollo.OG.Schlafzimmer","FriendlyName":["Rollo.OG.Schlafzimmer","Rollo.OG.Schlafzimmer.2"],"Topic":"Rollo.OG.Schlafzimmer","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":1}}
02:42:48.588 MQT: stat/Rollo.OG.Schlafzimmer/STATUS1 = {"StatusPRM":{"Baudrate":115200,"SerialConfig":"8N1","GroupTopic":"rollos_alle","OtaUrl":"http://ota.tasmota.com/tasmota/tasmota-DE.bin","RestartReason":"External System","Uptime":"0T00:02:39","StartupUTC":"2021-01-02T01:40:09","Sleep":50,"CfgHolder":4617,"BootCount":17,"BCResetTime":"2020-12-19T12:53:45","SaveCount":60,"SaveAddress":"F7000"}}
02:42:48.624 MQT: stat/Rollo.OG.Schlafzimmer/STATUS2 = {"StatusFWR":{"Version":"9.2.0.2(tasmota)","BuildDateTime":"2021.01.01 16:33:51","Boot":31,"Core":"2_7_4_9","SDK":"2.2.2-dev(38a443e)","CpuFrequency":80,"Hardware":"ESP8266EX","CR":"577/699"}}
02:42:48.645 MQT: stat/Rollo.OG.Schlafzimmer/STATUS3 = {"StatusLOG":{"SerialLog":2,"WebLog":2,"MqttLog":0,"SysLog":0,"LogHost":"","LogPort":514,"SSId":["IOT-LOTZ",""],"TelePeriod":300,"Resolution":"558180C0","SetOption":["0000C02B","0A05C80001000600003C5A00000000000000","400000C1","00006000","00000000"]}}
02:42:48.676 MQT: stat/Rollo.OG.Schlafzimmer/STATUS4 = {"StatusMEM":{"ProgramSize":590,"Free":412,"Heap":25,"ProgramFlashSize":1024,"FlashSize":2048,"FlashChipId":"1540C8","FlashFrequency":40,"FlashMode":3,"Features":["00000407","8FDAC787","04368001","000000CF","010013C0","C000F981","00004004","00001000"],"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,45","Sensors":"1,2,3,4,5,6"}}
02:42:48.713 MQT: stat/Rollo.OG.Schlafzimmer/STATUS5 = {"StatusNET":{"Hostname":"Rollo.OG.Schlafzimmer","IPAddress":"192.168.175.86","Gateway":"192.168.175.1","Subnetmask":"255.255.255.0","DNSServer":"192.168.175.1","Mac":"68:C6:3A:F9:26:FB","Webserver":2,"WifiConfig":4,"WifiPower":17.0}}
02:42:48.734 MQT: stat/Rollo.OG.Schlafzimmer/STATUS6 = {"StatusMQT":{"MqttHost":"192.168.175.214","MqttPort":1883,"MqttClientMask":"DVES_%06X","MqttClient":"DVES_F926FB","MqttUser":"mqtt","MqttCount":1,"MAX_PACKET_SIZE":1200,"KEEPALIVE":30}}
02:42:48.758 MQT: stat/Rollo.OG.Schlafzimmer/STATUS7 = {"StatusTIM":{"UTC":"2021-01-02T01:42:48","Local":"2021-01-02T02:42:48","StartDST":"2021-03-28T02:00:00","EndDST":"2021-10-31T03:00:00","Timezone":"+01:00","Sunrise":"08:21","Sunset":"16:29"}}
02:42:48.776 MQT: stat/Rollo.OG.Schlafzimmer/STATUS9 = {"StatusPTH":{"PowerDelta":[0,0,0],"PowerLow":0,"PowerHigh":0,"VoltageLow":0,"VoltageHigh":0,"CurrentLow":0,"CurrentHigh":0}}
02:42:48.799 MQT: stat/Rollo.OG.Schlafzimmer/STATUS10 = {"StatusSNS":{"Time":"2021-01-02T02:42:48","Switch1":"OFF","Switch2":"OFF","ANALOG":{"Temperature":46.5},"ENERGY":{"TotalStartTime":"2020-12-09T09:59:34","Total":0.002,"Yesterday":0.001,"Today":0.001,"Power":[0,0],"ApparentPower":[0,0],"ReactivePower":[0,0],"Factor":[0.00,0.00],"Voltage":0,"Current":[0.000,0.000]},"TempUnit":"C"}}
02:42:48.831 MQT: stat/Rollo.OG.Schlafzimmer/STATUS11 = {"StatusSTS":{"Time":"2021-01-02T02:42:48","Uptime":"0T00:02:39","UptimeSec":159,"Heap":25,"SleepMode":"Dynamic","Sleep":50,"LoadAvg":19,"MqttCount":1,"POWER1":"OFF","POWER2":"OFF","Wifi":{"AP":1,"SSId":"IOT-LOTZ","BSSId":"E2:63:DA:33:86:8A","Channel":10,"RSSI":74,"Signal":-63,"LinkCount":1,"Downtime":"0T00:00:07"}}}
02:42:48.861 MQT: stat/Rollo.OG.Schlafzimmer/STATUS13 = {"StatusSHT":{"SHT0":{"Relay1":1,"Relay2":2,"Open":320,"Close":282,"50perc":65,"Delay":0,"Opt":"0100","Calib":[1920,448,4288,900,1000],"Mode":"0"}}}

I will try more tommorow (try another shelly 2.5). Would there be anything you want me to test?

Sebastian

P.S. Could you add the position command after shutterstop as you mentioned here: https://github.com/arendst/Tasmota/discussions/10201#discussioncomment-230062

Bascht74 commented 3 years ago

Tried quickly to install the newest firmware on another device. Here it works.

Bascht74 commented 3 years ago

I copied a configuration from another shelly over to the other device. Now opening works again, but - while movement - I am facing reboot of the device.

They look like this:

00:00:12.162 WIF: Sending Gratuitous ARP
00:00:12.209 ADE: 6253110, 4478, [1773, -8, 660, -25], [1773, 2, 660, 14]
00:00:12.211 ADE: U 6253110, C 4478, I 0 + 0 = 0, P 0 + 0 = 0
00:00:12.216 RTC: UTC 2021-01-02T02:00:23, DST 2021-03-28T02:00:00, STD 2021-10-31T03:00:00
03:00:23.001 SHT: Shutter 1 Real 1025, Start 246000, Stop 0, Dir -1, Delay 0, Rtc 12.00 [s], Freq 0, PWM 0
03:00:23.005 RSL: stat/Rollo.EG.Schlafzimmer/RESULT = {"Shutter1":{"Position":0,"Direction":-1,"Target":0}}
03:00:23.044 SHT: time: 240, toBeAcc 0, current_stop_way 0,vel_cur 0, vel_max 0, act_vel_change 1000, min_runtime_ms 0, act.pos 1025, next_stop 0, target: 0,  max_vel_change 0, dir: -1
03:00:23.095 SHT: time: 242, toBeAcc 0, current_stop_way 0,vel_cur 0, vel_max 0, act_vel_change 1000, min_runtime_ms 0, act.pos -1025, next_stop 0, target: 0,  max_vel_change 0, dir: -1
03:00:23.098 SHT: Stop Shutter 0. Switchmode 0
03:00:23.100 SRC: Shutter
03:00:23.103 SHT: Switched relay: 2 by Shutter
03:00:23.105 SHT: Shutter 1: source: Shutter, powerstate_local 0, ShutterGlobal.RelayCurrentMask 2, manual change 0
03:00:23.110 RSL: stat/Rollo.EG.Schlafzimmer/RESULT = {"POWER2":"OFF"}
03:00:23.113 RSL: stat/Rollo.EG.Schlafzimmer/POWER2 = OFF
03:00:23.617 SHT: Shutter 1 Real 0, Start 0, Stop 0, Dir 0, Delay 0, Rtc 12.10 [s], Freq 0, PWM 0
03:00:23.620 RSL: stat/Rollo.EG.Schlafzimmer/SHUTTER1 = 0
03:00:23.624 RSL: stat/Rollo.EG.Schlafzimmer/RESULT = {"Shutter1":{"Position":0,"Direction":0,"Target":0}}
03:00:24.199 CFG: in Flash gespeichert am F4, zählen 33, Bytes 4096
03:00:24.213 ADE: 6252261, 4476, [1773, -49, 660, 98], [1773, -22, 660, 5]
03:00:24.216 ADE: U 6252261, C 4476, I 0 + 0 = 0, P 0 + 0 = 0
03:00:24.639 MQT: Verbindungsversuch...
03:00:24.963 MQT: verbunden
03:00:24.969 MQT: tele/Rollo.EG.Schlafzimmer/LWT = Online (beibehalten)
03:00:24.974 MQT: cmnd/Rollo.EG.Schlafzimmer/POWER = 
03:00:24.977 MQT: abonniere cmnd/Rollo.EG.Schlafzimmer/#
03:00:24.983 MQT: abonniere cmnd/rollos_alle/#
03:00:24.988 MQT: abonniere cmnd/rollos_erdgeschoss/#
03:00:25.001 MQT: abonniere cmnd/tasmotas/#
03:00:25.006 MQT: abonniere cmnd/DVES_F926FB_fb/#
03:00:25.010 MQT: löse abo. von homeassistant/status
03:00:25.018 MQT: tele/Rollo.EG.Schlafzimmer/INFO1 = {"Module":"Shelly 2.5","Version":"9.2.0.2(tasmota)","FallbackTopic":"cmnd/DVES_F926FB_fb/","GroupTopic":"cmnd/rollos_alle/"}
03:00:25.029 MQT: tele/Rollo.EG.Schlafzimmer/INFO2 = {"WebServerMode":"Admin","Hostname":"Rollo.EG.Schlafzimmer","IPAddress":"192.168.175.86"}
03:00:25.042 MQT: tele/Rollo.EG.Schlafzimmer/INFO3 = {"RestartReason":"External System"}
03:00:25.049 MQT: stat/Rollo.EG.Schlafzimmer/RESULT = {"POWER1":"OFF"}
03:00:25.054 MQT: stat/Rollo.EG.Schlafzimmer/POWER1 = OFF (beibehalten)
03:00:25.059 MQT: stat/Rollo.EG.Schlafzimmer/RESULT = {"POWER2":"OFF"}
03:00:25.065 MQT: stat/Rollo.EG.Schlafzimmer/POWER2 = OFF (beibehalten)
03:00:25.208 ADE: 6251275, 4477, [1773, -35, 660, 54], [1773, 18, 660, 22]
03:00:25.211 ADE: U 6251275, C 4477, I 0 + 0 = 0, P 0 + 0 = 0
03:00:26.082 MQT: Datengröße 2, "cmnd/Rollo.EG.Schlafzimmer/STATUS 10"
03:00:26.085 SRC: MQTT
03:00:26.088 CMD: Gruppe 0, Index 1, Befehl "STATUS", Daten "10"
03:00:26.098 MQT: stat/Rollo.EG.Schlafzimmer/STATUS10 = {"StatusSNS":{"Time":"2021-01-02T03:00:26","Switch1":"OFF","Switch2":"OFF","ANALOG":{"Temperature":52.5},"ENERGY":{"TotalStartTime":"2020-12-09T09:59:34","Total":0.001,"Yesterday":0.001,"Today":0.001,"Power":[0,0],"ApparentPower":[0,0],"ReactivePower":[0,0],"Factor":[0.00,0.00],"Frequency":0,"Voltage":0,"Current":[0.000,0.000]},"Shutter1":{"Position":0,"Direction":0,"Target":0},"TempUnit":"C"}}
03:00:26.208 ADE: 6250725, 4477, [1773, -52, 660, -47], [1773, 7, 660, 11]
03:00:26.211 ADE: U 6250725, C 4477, I 0 + 0 = 0, P 0 + 0 = 0
03:00:27.209 ADE: 6251227, 4477, [1773, -6, 660, 40], [1773, -29, 660, 7]
03:00:27.211 ADE: U 6251227, C 4477, I 0 + 0 = 0, P 0 + 0 = 0
03:00:28.200 ADE: 6249548, 4477, [1773, 20, 660, 79], [1773, -9, 660, 9]
03:00:28.203 ADE: U 6249548, C 4477, I 0 + 0 = 0, P 0 + 0 = 0

After that, power1 on doesn't work anymore...

Could this problem be something different?

Bascht74 commented 3 years ago

The only thing I was changing the last days: I installed to switches to the shelly (to be able to control it locally) and probably faced it upside down. WIFI signal is OK (-66 dBm). I will remove the switches and see, if it changes something.

stefanbode commented 3 years ago

Regarding power1 do a reboot. This is nothing shutter related. I assume you have a problem with you DC power device that the relay1 consume to much power and you get an undervoltage that causes the reboot. Just use the same firmware without the relays connected to confirm the cause. If it works without the relay than your power supply do not have enough power for the relays.

stefanbode commented 3 years ago

you should see the same problem with shutteroption80 0 and just do switching the power 1

megamarco833 commented 3 years ago

hi @stefanbode you are reply to me or @Bascht74 ?

Bascht74 commented 3 years ago

@megamarco833 Probably me :-) As this is not related anymore and resolved I deleted the entries.

@stefanbode I checked with was Stefan said and it happens as well with setoption80 0 and power1 on. I checked the installation, that could cause the under voltage and found a fractured ("angebrochenes") cable, that might have been the cause. I re-wired "L" and now everything is fine. That never happened before, still learning :-)

stefanbode commented 3 years ago

@megamarco833 : the comment was for @Bascht74 . Your problem I still cannot reproduce. Also using the same GPIO setting did not make a change. I will share my bin file with config. Pleas try it and the we will see if it behaves differently

megamarco833 commented 3 years ago

hai @stefanbode ok, thanks if you will share your bin i will test. anyway i think that it is not related to shutter but to something applt after 9.1.0 that create system slow but it is highlighted by shutter(maybe high memory usage?) i have only two ESP32 nodemcu version, one with 38pins and one with 30pins, and the issue is on both. the strange thing is that i flash 9.1.0 both are working without any issue and any disconnection. so i can exclude wifi network that of course i not change it :-) so i think that there is something inside the firmware, that's my though

anyway if you would like to share your bin i can of course test. appreciate your help

stefanbode commented 3 years ago

please close the case