error position status report

[madmicio]

tested onsonoff 4ch pro + dual r2 I found the following error: only during the closing the position value is lower than the set.position.

10:19:36 Start motor in right direction -1

10:19:36 MQT: stat/salone/RESULT = {"POWER2":"ON"} 10:19:36 MQT: stat/salone/POWER2 = ON 10:19:36 MQT: stat/salone/RESULT = {"shutterposition1":68} 10:19:37 Shutter 0: Real Pos: 60380, Target 53424, source: Shutter, pos %: 84, direction: -1, rtcshutter: 13 10:19:38 Shutter 0: Real Pos: 58140, Target 53424, source: Shutter, pos %: 84, direction: -1, rtcshutter: 33 10:19:39 Shutter 0: Real Pos: 55900, Target 53424, source: Shutter, pos %: 84, direction: -1, rtcshutter: 53 10:19:40 Shutter 0: Real Pos: 53548, Target 53424, source: Shutter, pos %: 84, direction: -1, rtcshutter: 73 10:19:40 MQT: stat/salone/SHUTTER1 = 67 10:19:40 MQT: stat/salone/RESULT = {"POWER2":"OFF"}

I know it seems like a small flaw. but it's a big problem for all my automations. it is possible to fix IT

[stefanbode]

can you please provide your init setting. These are reported in the beginning of the log. I assume you have set the shutter50percent. In this case internally it still calculates with the 0..100 but reports externally the cocrrected values. Therefore if you set it to 50%, it should look like 50% report 50% but internal have a 70%. In your case: 68/67 is what you have set and internally it is 84%. The difference between 68 and 67 is because you will get the ACTUAL position and not what you have set. depending on the timing this could be +-1. Is this your issue?

[stefanbode]

Ok, I see this is a rounding issue, caused by some INT calculation. Fixing it right now and upload asap.

[madmicio]

      can you please provide your init setting. These are reported in the beginning of the log. I assume you have set the shutter50percent. In this case internally it still calculates with the 0..100 but reports externally the cocrrected values. Therefore if you set it to 50%, it should look like 50% report 50% but internal have a 70%. In your case: 68/67 is what you have set and internally it is 84%. The difference between 68 and 67 is because you will get the ACTUAL position and not what you have set. depending on the timing this could be +-1. Is this your issue?

excellent analysis. yes this is my problem.

[madmicio]

      Ok, I see this is a rounding issue, caused by some INT calculation. Fixing it right now and upload asap.

have you already solved the problem ????? so quick?

[madmicio]

Sorry, do you have this picture on your passport? you really are a genius! Thanks for your help

[madmicio]

maybe another bug: if I give the shutterposition command from console, instead of returning the position value, the shutter closes. this does not access the previous version

[stefanbode]

Can you please set loglevel to 5 and send a log from beginning you send the command. Thanks. This is a tested scenario and works on my site. More investigation is required.

[madmicio]

11:41:43 CMD: shutterposition 11:41:43 SRC: WebConsole from 192.168.1.165 11:41:43 RSL: Topic Ricevuto /shutterposition, Dimensione Dati 0, Dati 11:41:43 RSL: Gruppo 0, Indice 1, Comando SHUTTERPOSITION, Dati 11:41:43 lastsource 9:, realpos 32600, target 0 11:41:43 Start shutter in right direction -1 11:41:43 temp1 for mask is 3, temp2: 2, temp3 1. Bucketsize: 2, device: 2 to state 1, currentsate 0 11:41:43 imask1: 1 11:41:43 SRC: Shutter 11:41:43 Switched relay: 2 by Shutter 11:41:43 MQT: stat/finestra_emma/RESULT = {"POWER2":"ON"} 11:41:43 MQT: stat/finestra_emma/POWER2 = ON 11:41:43 MQT: stat/finestra_emma/RESULT = {"shutterposition1":0} 11:41:44 Shutter 0: Real Pos: 31760, Target 0, source: Shutter, pos %: 74, direction: -1, rtcshutter: 9 11:41:44 CFG: Salvato nella flash in F4, Conteggio 192, Bytes 3820 11:41:45 Shutter 0: Real Pos: 29660, Target 0, source: Shutter, pos %: 74, direction: -1, rtcshutter: 29 11:41:46 Shutter 0: Real Pos: 27560, Target 0, source: Shutter, pos %: 74, direction: -1, rtcshutter: 49 11:41:47 Shutter 0: Real Pos: 25460, Target 0, source: Shutter, pos %: 74, direction: -1, rtcshutter: 69 11:41:48 Shutter 0: Real Pos: 23360, Target 0, source: Shutter, pos %: 74, direction: -1, rtcshutter: 89 11:41:49 Shutter 0: Real Pos: 21260, Target 0, source: Shutter, pos %: 74, direction: -1, rtcshutter: 109 11:41:50 Shutter 0: Real Pos: 19160, Target 0, source: Shutter, pos %: 74, direction: -1, rtcshutter: 129 11:41:51 Shutter 0: Real Pos: 17060, Target 0, source: Shutter, pos %: 74, direction: -1, rtcshutter: 149 11:41:51 WIF: Controllo connessione... 11:41:51 WIF: Connesso 11:41:52 Shutter 0: Real Pos: 14960, Target 0, source: Shutter, pos %: 74, direction: -1, rtcshutter: 169 11:41:52 HTP: Menu Principale 11:41:53 Shutter 0: Real Pos: 12860, Target 0, source: Shutter, pos %: 74, direction: -1, rtcshutter: 189 11:41:54 SRC: WebGui from 192.168.1.165 11:41:54 Switched relay: 2 by I 11:41:54 Shutter 0: Switch OFF motor. Target: 10970, source: I, powerstate_local 0, switchedRelay 2, manual change 1 11:41:54 Shutter 0: Target: 10970 11:41:54 MQT: stat/finestra_emma/RESULT = {"POWER2":"OFF"} 11:41:54 MQT: stat/finestra_emma/POWER2 = OFF 11:41:54 Shutter 0: Real Pos. 10865, Stoppos: 4, relay: 1, direction -1, pulsetimer: 0, rtcshutter: 207 11:41:54 MQT: stat/finestra_emma/SHUTTER1 = 4 11:41:54 CFG: Salvato nella flash in FB, Conteggio 193, Bytes 3820 11:41:55 HTP: Console

[stefanbode]

Do you call shutterposition without any value? For me this t looks like this is called with value 0 and then operates as expected. Then at the end someone hit the OFF relay in the web interface and it immediately stops. Also as expected. What is wrong?

[madmicio]

this is given after sending the "shutterposition" command before the last bug fix.

18:17:10 CMD: shutterposition
18:17:10 MQT: stat/telo_proiezione/RESULT = {"shutterposition1":89}

sonoff simply responds with the position

after the last bug fix, if you send the shutterposition command, the cover goes to 0 position. I think that the first solution is the correct one, and even more useful. if I want to close the cover, I send the command: "shutterclose" or "shutterposition 0".

[stefanbode]

Yes this is/was a bug and is not as it should work. Now the command again will report always the actual position also when the shutter is still moving. Therefore and enhancement to before, where only the target position was reported.

[madmicio]

just a little problem: 23:51:46 CMD: shutterposition1 23:51:46 MQT: stat/salone/RESULT = {"shutterposition1":1685419113}

[stefanbode]

Uups. Hmm.

[stefanbode]

Oh what a bad programming and testing. Sorry just missed the second part of the "if-clause". This should be fixed now

[madmicio]

A new error: shutteropen, shutterstop and shutterclose command doesn't work anymore! these commands return the position. 23:00:25 CMD: shutteropen 23:00:25 MQT: stat/dual_cucina/RESULT = {"shutteropen1":85}

[stefanbode]

Yes, I urgently need a testsuite that runs all the test automatically. This manual process is so error intensive. Thanks for being patient and helping to improve the software. I found the error easily and fixed it. Please give it another try. Thanks. Crossing fingers

[madmicio]

in sonoff 4ch pro I set button 3 "UP" button 4 "DOWN". if I move the shutter with the software buttons of the web interface of the sonoff, everything works regularly. but if I lower the shutter with the physical button 4 the position of the slider does not update and remains at 100

14:55:46 HTP: Configurazione 14:55:47 CFG: Salvato nella flash in F9, Conteggio 35, Bytes 3820 14:55:52 HTP: Menu Principale 14:55:57 HTP: Console 14:56:05 WIF: Controllo connessione... 14:56:05 WIF: Connesso 14:56:05 APP: Pulsante4 level 1-0 14:56:05 temp1 for mask is 3, temp2: 2, temp3 1. Bucketsize: 2, device: 4 to state 2, currentsate 0 14:56:05 imask1: 4 14:56:05 SRC: Button 14:56:05 Switched relay: 8 by Button 14:56:05 Shutter 1: Target: 70000 14:56:05 MQT: stat/4cu_notte/RESULT = {"POWER4":"ON"} 14:56:05 MQT: stat/4cu_notte/POWER4 = ON 14:56:05 Shutter 1: Real Pos. 70000, Stoppos: 100, relay: 2, direction 1, pulsetimer: 0, rtcshutter: 0, operationtime 0 14:56:05 MQT: stat/4cu_notte/SHUTTER2 = 100 14:56:06 APP: Pulsante4 level 0-1 14:56:06 CFG: Salvato nella flash in F8, Conteggio 36, Bytes 3820 14:56:10 APP: Pulsante4 level 1-0 14:56:10 SRC: Button 14:56:10 Switched relay: 8 by Button 14:56:10 Shutter 1: Target: 70000 14:56:10 MQT: stat/4cu_notte/RESULT = {"POWER4":"OFF"} 14:56:10 MQT: stat/4cu_notte/POWER4 = OFF 14:56:10 Shutter 1: Real Pos. 70000, Stoppos: 100, relay: 2, direction 1, pulsetimer: 0, rtcshutter: 0, operationtime 0 14:56:10 MQT: stat/4cu_notte/SHUTTER2 = 100 14:56:10 APP: Pulsante4 level 0-1 14:56:11 CFG: Salvato nella flash in F7, Conteggio 37, Bytes 3820

[stefanbode]

Hi, two questions: 1.) Does the shutter move, if you use the physical buttons? 2.) What about the reported position in /stat and /result? Is this correct?

[stefanbode]

From the log you provided I can see that the shutter stops, because already reached the END stop. If you Click on relay8 in the web interface you should see the same behaviour

14:55:46 HTP: Configurazione 
14:55:47 CFG: Salvato nella flash in F9, Conteggio 35, Bytes 3820 
14:55:52 HTP: Menu Principale 
14:55:57 HTP: Console 
14:56:05 WIF: Controllo connessione... 
14:56:05 WIF: Connesso 
14:56:05 APP: Pulsante4 level 1-0 
14:56:05 temp1 for mask is 3, temp2: 2, temp3 1. Bucketsize: 2, device: 4 to state 2, currentsate 0 
14:56:05 imask1: 4 
14:56:05 SRC: Button 
14:56:05 Switched relay: 8 by Button 
14:56:05 Shutter 1: Target: 70000 
14:56:05 MQT: stat/4cu_notte/RESULT = {"POWER4":"ON"} 
14:56:05 MQT: stat/4cu_notte/POWER4 = ON 
14:56:05 Shutter 1: Real Pos. 70000, Stoppos: 100, relay: 2, direction 1, pulsetimer: 0, rtcshutter: 0, operationtime 0 
14:56:05 MQT: stat/4cu_notte/SHUTTER2 = 100 
14:56:06 APP: Pulsante4 level 0-1 
14:56:06 CFG: Salvato nella flash in F8, Conteggio 36, Bytes 3820 
14:56:10 APP: Pulsante4 level 1-0 
14:56:10 SRC: Button 
14:56:10 Switched relay: 8 by Button 
14:56:10 Shutter 1: Target: 70000 
14:56:10 MQT: stat/4cu_notte/RESULT = {"POWER4":"OFF"} 
14:56:10 MQT: stat/4cu_notte/POWER4 = OFF 
14:56:10 Shutter 1: Real Pos. 70000, Stoppos: 100, relay: 2, direction 1, pulsetimer: 0, rtcshutter: 0, operationtime 0 
14:56:10 MQT: stat/4cu_notte/SHUTTER2 = 100 
14:56:10 APP: Pulsante4 level 0-1 
14:56:11 CFG: Salvato nella flash in F7, Conteggio 37, Bytes 3820

[madmicio]

      Hi, two questions:

1.) Does the shutter move, if you use the physical buttons? 2.) What about the reported position in /stat and /result? Is this correct?

1 yes! the problem occur only with the physical button 2 stat/4cu_notte/SHUTTER2 = 100 (real posizion 0)

the problem occur only with the SHUTTERRELAY2. SHUTTERRELAY1 woks fine

[stefanbode]

Last comment is the interesting one. For shutter2 you switches must be switch3 and switch4 correct?

[madmicio]

From the log you provided I can see that the shutter stops, because already reached the END stop. If you Click on relay8 in the web interface you should see the same behaviour

no. did not reach for the end position, but I pressed button 4 again to stop it.

I did the test you asked me, but if I start with the physical button and stop with the software button, I have the same site .... 100

15:46:42 imask1: 4 15:46:42 SRC: Button 15:46:42 Switched relay: 8 by Button 15:46:42 Shutter 1: Target: 70000 15:46:42 MQT: stat/4cu_notte/RESULT = {"POWER4":"ON"} 15:46:42 MQT: stat/4cu_notte/POWER4 = ON 15:46:42 Shutter 1: Real Pos. 70000, Stoppos: 100, relay: 2, direction 1, pulsetimer: 0, rtcshutter: 1, operationtime 0 15:46:42 MQT: stat/4cu_notte/SHUTTER2 = 100 15:46:43 APP: Pulsante4 level 0-1 15:46:43 CFG: Salvato nella flash in F7, Conteggio 53, Bytes 3820 15:46:43 WIF: Controllo connessione... 15:46:43 WIF: Connesso 15:46:51 SRC: WebGui from 192.168.1.227 15:46:51 Switched relay: 8 by I 15:46:51 Shutter 1: Target: 70000 15:46:51 MQT: stat/4cu_notte/RESULT = {"POWER4":"OFF"} 15:46:51 MQT: stat/4cu_notte/POWER4 = OFF 15:46:51 Shutter 1: Real Pos. 70000, Stoppos: 100, relay: 2, direction 1, pulsetimer: 0, rtcshutter: 0, operationtime 0 15:46:51 MQT: stat/4cu_notte/SHUTTER2 = 100

[stefanbode]

Can you do the same for shutter1 so I can compare LOg files . I do see that the shutter moves but internally the movement is not executed. Strange.

[madmicio]

For shutter2 you switches must be switch3 and switch4 correct?

NO. I simply put the physical buttons on the wall in parallel with the physical sonoff buttons. so it is as if physically I had to press button 3 and 4 of the sonoff

[stefanbode]

Ok this should also work as long as number 3 and 4 for shutter 2. the error is in the software for sure.

[madmicio]

ok. same operation for shutter1. I pressed the down button. when the shutter reached about 60% I pressed the down button again and the shutter stopped

15:57:49 APP: Pulsante2 level 1-0 15:57:49 temp1 for mask is 3, temp2: 2, temp3 1. Bucketsize: 2, device: 2 to state 2, currentsate 0 15:57:49 imask1: 1 15:57:49 SRC: Button 15:57:49 Switched relay: 2 by Button 15:57:49 Shutter 0: Target: 0 15:57:49 MQT: stat/4cu_notte/RESULT = {"POWER2":"ON"} 15:57:49 MQT: stat/4cu_notte/POWER2 = ON 15:57:49 APP: Pulsante2 level 0-1 15:57:50 Shutter 0: Real Pos: 37000, Target 0, source: Shutter, pos %: 100, direction: -1, rtcshutter: 11 15:57:50 CFG: Salvato nella flash in F7, Conteggio 61, Bytes 3820 15:57:51 Shutter 0: Real Pos: 35000, Target 0, source: Shutter, pos %: 100, direction: -1, rtcshutter: 31 15:57:52 Shutter 0: Real Pos: 33000, Target 0, source: Shutter, pos %: 100, direction: -1, rtcshutter: 51 15:57:53 Shutter 0: Real Pos: 31000, Target 0, source: Shutter, pos %: 100, direction: -1, rtcshutter: 71 15:57:54 Shutter 0: Real Pos: 29000, Target 0, source: Shutter, pos %: 100, direction: -1, rtcshutter: 91 15:57:55 Shutter 0: Real Pos: 27000, Target 0, source: Shutter, pos %: 100, direction: -1, rtcshutter: 111 15:57:55 APP: Pulsante2 level 1-0 15:57:55 SRC: Button 15:57:55 Switched relay: 2 by Button 15:57:55 Shutter 0: Switch OFF motor. Target: 25800, source: Button, powerstate_local 0, switchedRelay 2, manual change 1 15:57:55 Shutter 0: Target: 25800 15:57:55 MQT: stat/4cu_notte/RESULT = {"POWER2":"OFF"} 15:57:55 MQT: stat/4cu_notte/POWER2 = OFF 15:57:55 Shutter 0: Real Pos. 25600, Stoppos: 54, relay: 1, direction -1, pulsetimer: 0, rtcshutter: 124, operationtime 1 15:57:55 MQT: stat/4cu_notte/SHUTTER1 = 54 15:57:56 APP: Pulsante2 level 0-1 15:57:56 CFG: Salvato nella flash in F6, Conteggio 62, Bytes 3820 15:58:08 WIF: Controllo connessione... 15:58:08 WIF: Connesso 15:58:18 MQT: tele/4cu_notte/STATE = {"Time":"2018-10-16T15:58:18","Uptime":"0T00:15:19","Vcc":3.464,"POWER1":"OFF","POWER2":"OFF","POWER3":"OFF","POWER4":"OFF", "Wifi":{"AP ":1, "SSId ":"Fast-Arci", "BSSId ":"10:13:31:F8:D3:43", "Channel":1, "RSSI":32}, "DeepSleep":0, "Heap":20896} 15:58:18 MQT: tele/4cu_notte/SENSOR = {"Time":"2018-10-16T15:58:18","SHUTTER-1":54,"SHUTTER-2":100}

[stefanbode]

Yes, there is always room for bugs and improvements. Again a small mistake in binary operations fixed. See new uploaded version

[B1G1]

Hi Stefan, I updated one of my Sonoff dual r2 with to this new version, and I loose it. I flashed a new sonoff and when I restored the configuration saved from another sonoff, I loose it. I can't connect to them anymore.

[stefanbode]

Worst case it went back to default settings. Please check if you see an access point

[B1G1]

No access point and it doesn’t connect to my Wifi. The other sonoff newly flashed connets to the wifi for some seconds. In these seconds i can see the webapp and reset it to the default settings, now it works normally.

[madmicio]

Dear Stephan, I installed the new firmware, I will do an intense test in the coming days. I must ask for one last effort. reverse so fast the shutter direction is not a good idea for the shutter motors. if the shutter is particularly heavy, a sudden change in direction could cause serious damage to the motors. is it possible insert a delay of 1 second when it reverses the open/close direction?

[stefanbode]

Hi, I agree that this is a problem, if you go down and then suddenly go up. The other way it should be no problem because gravity is your friend. 1 second is quite a lot. But something in the 0.3s area is a good idea in this case. Might a bit tricky because of all the different motor types.

[stefanbode]

I checked the code and there are more limitations than you like. As long as you change the shutter through mqtt with shutteropen, shutterclose, shutterposition everything is fine. This can be fixed easily. If you operate the shutter with buttons or by directly changing the relay I have no chance. The relay is switched and the motor started BEFORE I get noticed by tasmota.