Rollo beendet die Beschattung fehlerhaft (Kollision ShadingOut<>NightClose?)

[FunkOdyssey2001]

Ausgangsthread "Problem Nr. 1": https://forum.fhem.de/index.php/topic,112325.msg1067481.html#msg1067481

Hallo, ich hatte es ja bereits angekündigt, dass ich mich mit einem Debug-Log noch einmal melde.
Ich habe die unterschiedlichsten Probleme mit der Beschattung. Ein Absent-Fehler wurde ja gestern bereits behoben.
Aber ich habe auch oft, dass die Jalousien sich beim Shading Out und beim Night Close irgendwie in die Quere kommen.
Ein repräsentatives Beispiel konnte ich gestern erzeugen und als Anhang angefügt.

• Rollo war in Shading in (Pos. 50)
• Rollo ging in Shading out (Pos. 50 > Pos. 0)
• und ging dann danach fälschlicherweise hoch (Pos. 0 > Pos. 100)

25 Juni 2020, 13:23:24 Deine Frage dazu: https://forum.fhem.de/index.php/topic,112325.msg1067531.html#msg1067531
25 Juni 2020, 14:43:29 Meine Antwort darauf: https://forum.fhem.de/index.php/topic,112325.msg1067557.html#msg1067557
03 Juli 2020, 13:05:56 Dein Lösungvorschlag: https://forum.fhem.de/index.php/topic,112325.msg1069654.html#msg1069654
13 Juli 2020, 20:38:33 Meine Antwort: https://forum.fhem.de/index.php/topic,112325.msg1071726.html#msg1071726

Heute war wieder ein Sonnentage und ich konnte es wieder testen. Der ursprüngliche Zweig "devel-testing" wurde soweit ich weiß auch schon ins FHEM-SVN gemerged.

Leider waren meine Jalousien wieder alle oben.

Der Tag der Jalousie sah wie folgt aus:

2020-07-12_11:48:09 bad_jal ASC_ShuttersLastDrive: manual
2020-07-12_11:48:27 bad_jal deviceMsg: on (to VCCU)
2020-07-12_11:48:27 bad_jal level: 100
2020-07-12_11:48:27 bad_jal motor: stop:on
2020-07-12_11:48:27 bad_jal pct: 100
2020-07-12_11:48:27 bad_jal on
2020-07-12_13:52:57 bad_jal ASC_ShadingMessage: INFO: current shading status is 'in reserved' - next check in 10m
2020-07-12_14:04:55 bad_jal ASC_ShadingMessage: INFO: current shading status is 'in' - next check in 20m
2020-07-12_14:06:48 bad_jal commState: CMDs_pending
2020-07-12_14:06:48 bad_jal level: set_30
2020-07-12_14:06:48 bad_jal set_30
2020-07-12_14:06:48 bad_jal commState: CMDs_processing...
2020-07-12_14:06:48 bad_jal commState: CMDs_done
2020-07-12_14:06:48 bad_jal level: 100
2020-07-12_14:06:48 bad_jal motor: down:on
2020-07-12_14:06:48 bad_jal on
2020-07-12_14:07:03 bad_jal deviceMsg: 30 (to VCCU)
2020-07-12_14:07:03 bad_jal level: 30
2020-07-12_14:07:03 bad_jal motor: stop:30
2020-07-12_14:07:03 bad_jal pct: 30
2020-07-12_14:07:03 bad_jal 30
2020-07-12_14:07:03 bad_jal ASC_ShuttersLastDrive: shading in
2020-07-12_14:15:25 bad_jal ASC_ShadingMessage: INFO: current shading status is 'out reserved' - next check in 20m
2020-07-12_14:25:26 bad_jal ASC_ShadingMessage: INFO: current shading status is 'in reserved' - next check in 20m
2020-07-12_14:35:27 bad_jal ASC_ShadingMessage: INFO: current shading status is 'in' - next check in 20m
2020-07-12_15:12:17 bad_jal ASC_ShadingMessage: INFO: current shading status is 'out reserved' - next check in 20m
2020-07-12_15:22:18 bad_jal ASC_ShadingMessage: INFO: current shading status is 'in reserved' - next check in 20m
2020-07-12_15:32:57 bad_jal ASC_ShadingMessage: INFO: current shading status is 'in' - next check in 20m
2020-07-12_15:57:53 bad_jal ASC_ShadingMessage: INFO: current shading status is 'out reserved' - next check in 20m
2020-07-12_16:09:48 bad_jal ASC_ShadingMessage: INFO: current shading status is 'in reserved' - next check in 20m
2020-07-12_16:19:58 bad_jal ASC_ShadingMessage: INFO: current shading status is 'in' - next check in 20m
2020-07-12_17:07:04 bad_jal ASC_ShadingMessage: INFO: current shading status is 'out reserved' - next check in 20m
2020-07-12_17:17:09 bad_jal ASC_ShadingMessage: INFO: current shading status is 'in reserved' - next check in 20m
2020-07-12_17:27:14 bad_jal ASC_ShadingMessage: INFO: current shading status is 'in' - next check in 20m
2020-07-12_18:15:59 bad_jal ASC_ShadingMessage: INFO: current shading status is 'out reserved' - next check in 20m
2020-07-12_18:49:26 bad_jal ASC_ShadingMessage: INFO: current shading status is 'out' - next check in 10m
2020-07-12_19:16:47 bad_jal commState: CMDs_pending
2020-07-12_19:16:47 bad_jal level: set_100
2020-07-12_19:16:47 bad_jal set_100
2020-07-12_19:16:47 bad_jal commState: CMDs_processing...
2020-07-12_19:16:47 bad_jal commState: CMDs_done
2020-07-12_19:16:47 bad_jal level: 30
2020-07-12_19:16:47 bad_jal motor: up:30
2020-07-12_19:16:47 bad_jal 30
2020-07-12_19:17:04 bad_jal deviceMsg: on (to VCCU)
2020-07-12_19:17:04 bad_jal level: 100
2020-07-12_19:17:04 bad_jal motor: stop:on
2020-07-12_19:17:04 bad_jal pct: 100
2020-07-12_19:17:04 bad_jal on
2020-07-12_19:17:04 bad_jal ASC_ShuttersLastDrive: shading out
2020-07-12_19:18:35 bad_jal commState: CMDs_pending
2020-07-12_19:18:35 bad_jal level: set_0
2020-07-12_19:18:35 bad_jal set_0
2020-07-12_19:18:35 bad_jal commState: CMDs_processing...
2020-07-12_19:18:35 bad_jal commState: CMDs_done
2020-07-12_19:18:35 bad_jal level: 100
2020-07-12_19:18:35 bad_jal motor: down:on
2020-07-12_19:18:35 bad_jal on
2020-07-12_19:18:56 bad_jal deviceMsg: off (to VCCU)
2020-07-12_19:18:56 bad_jal level: 0
2020-07-12_19:18:56 bad_jal motor: stop:off
2020-07-12_19:18:56 bad_jal pct: 0
2020-07-12_19:18:56 bad_jal off
2020-07-12_19:19:04 bad_jal commState: CMDs_pending
2020-07-12_19:19:04 bad_jal level: set_100
2020-07-12_19:19:04 bad_jal set_100
2020-07-12_19:19:04 bad_jal commState: CMDs_processing...
2020-07-12_19:19:04 bad_jal commState: CMDs_done
2020-07-12_19:19:04 bad_jal level: 0
2020-07-12_19:19:04 bad_jal motor: up:off
2020-07-12_19:19:04 bad_jal off
2020-07-12_19:19:26 bad_jal deviceMsg: on (to VCCU)
2020-07-12_19:19:26 bad_jal level: 100
2020-07-12_19:19:26 bad_jal motor: stop:on
2020-07-12_19:19:26 bad_jal pct: 100
2020-07-12_19:19:26 bad_jal on

Parameter wie im Ausgangspost. Die Jalousie hätte eigentlich um 19:15 Uhr zzgl. Delay herunterfahren müssen. Ansonsten fahre ich per Brightness. Im Sommer zieht aber eher die Zeit.

Ich leider sagen, dass es vermutlich der folgende Commit es scheinbar schlimmer gemacht hat. Er fährt nun noch öfters hoch und runter. https://git.cooltux.net/FHEM/mod-AutoShuttersControl/commit/924363fe18c6f4d30787c471336424ec504a5cd3

[CoolTuxNet]

Sollte mit der aktuellen Version nicht mehr so sein. Bitte beobachten

[FunkOdyssey2001]

In der Realität konnte ich merken, dass sich etwas verbessert hat.
In FHEM war ich noch irritiert, wenn ich auf das LastDrive-Reading schaue.

Das Verhalten ist unterschiedlich:

ASC_Shading_Pos (30) > ASC_Closed_Pos (0)

Das Reading ASC_ShuttersLastDrive wechselt von shading in zu shading out.
Vielleicht wäre es schöner, wenn hier eigentlich night close stehen würde.

2020-07-31_14:11:39 bad_jal ASC_ShuttersLastDrive: shading in
2020-07-31_19:05:14 bad_jal ASC_ShadingMessage: INFO: current shading status is 'out reserved' - next check in 20m
2020-07-31_19:15:21 bad_jal ASC_ShadingMessage: INFO: current shading status is 'out' - next check in 10m
2020-07-31_19:16:32 bad_jal commState: CMDs_pending
2020-07-31_19:16:32 bad_jal level: set_0
2020-07-31_19:16:32 bad_jal set_0
2020-07-31_19:16:32 bad_jal commState: CMDs_processing...
2020-07-31_19:16:32 bad_jal commState: CMDs_done
2020-07-31_19:16:32 bad_jal level: 30
2020-07-31_19:16:32 bad_jal motor: down:30
2020-07-31_19:16:32 bad_jal 30
2020-07-31_19:16:41 bad_jal deviceMsg: off (to VCCU)
2020-07-31_19:16:41 bad_jal level: 0
2020-07-31_19:16:41 bad_jal motor: stop:off
2020-07-31_19:16:41 bad_jal pct: 0
2020-07-31_19:16:41 bad_jal off
2020-07-31_19:16:42 bad_jal ASC_ShuttersLastDrive: shading out

ASC_Shading_Pos (10) < ASC_Sleep_Pos (20) - (ASC_Closed_Pos wäre 0)

Wenn die Beschattungsposition kleiner als die nächtliche Endposition ist, dann wird keine Fahrt ausgelöst. Dies mag ja auch korrekt sein. Das Rollo verbleibt die Nacht über dann aber im Status shading in.
Schöner wäre hier ein Statuswechsel. Vor allem auch, weil am morgen darauf unverhofft ein shading out folgt. Und das bei einer Konfiguration, in der das Rollo überhaupt nicht eigenständig öffnen sollte (ASC_Mode_Up: absent).

2020-07-31_12:05:32 jal_test level: set_10
2020-07-31_12:05:32 jal_test set_10
2020-07-31_12:05:32 jal_test commState: CMDs_processing...
2020-07-31_12:05:33 jal_test commState: CMDs_done
2020-07-31_12:05:33 jal_test level: 100
2020-07-31_12:05:33 jal_test motor: down:on
2020-07-31_12:05:33 jal_test on
2020-07-31_12:05:52 jal_test deviceMsg: 10 (to VCCU)
2020-07-31_12:05:52 jal_test level: 10
2020-07-31_12:05:52 jal_test motor: stop:10
2020-07-31_12:05:52 jal_test pct: 10
2020-07-31_12:05:52 jal_test 10
2020-07-31_12:05:52 jal_test pctRound: 10
2020-07-31_12:05:53 jal_test ASC_ShuttersLastDrive: shading in
2020-07-31_19:09:04 jal_test ASC_ShadingMessage: INFO: current shading status is 'out' - next check in 10m
NÄCHSTER TAG
2020-08-01_08:33:34 jal_test commState: CMDs_pending
2020-08-01_08:33:34 jal_test level: set_100
2020-08-01_08:33:34 jal_test set_100
2020-08-01_08:33:34 jal_test commState: CMDs_processing...
2020-08-01_08:33:34 jal_test commState: CMDs_done
2020-08-01_08:33:34 jal_test level: 10
2020-08-01_08:33:34 jal_test motor: up:10
2020-08-01_08:33:34 jal_test 10
2020-08-01_08:33:56 jal_test deviceMsg: on (to VCCU)
2020-08-01_08:33:56 jal_test level: 100
2020-08-01_08:33:56 jal_test motor: stop:on
2020-08-01_08:33:56 jal_test pct: 100
2020-08-01_08:33:56 jal_test on
2020-08-01_08:33:56 jal_test pctRound: 100
2020-08-01_08:33:56 jal_test ASC_ShuttersLastDrive: shading out

Hier ist also noch ein Fehler vorhanden. Könntest du das Ticket bitte wieder öffnen? Danke.

[CoolTuxNet]

ASC_Shading_Pos (30) > ASC_Closed_Pos (0)

Eigentlich dürfte beim Shading Out keine Fahrt in die Closed Pos passieren, es sei denn die Closed Pos war auch die LastPos vor der Shading Fahrt

[FunkOdyssey2001]

ASC_Shading_Pos (30) > ASC_Closed_Pos (0)

Eigentlich dürfte beim Shading Out keine Fahrt in die Closed Pos passieren, es sei denn die Closed Pos war auch die LastPos vor der Shading Fahrt

Ich verstehe deine Aussage nicht so ganz.
Wie hattest du das denn programmiert in diesem Fall? Soll ein Night Close ausgeführt werden? Oder ein Shading Out?
Die Fahrt ist eigentlich in diesem Fall korrekt, aber das LastDrive-Reading halt falsch.
Oder hätte nach deiner Programmierung eigentlich gar kein Shading Out, sondern ein Night Close ausgeführt werden müssen?
Dann ist das noch ein Bug.

[CoolTuxNet]

Das ShadingDrive ist so programmiert das er entweder in Open oder LastPos fährt. Niemals in Closed.
Das Closed kommt wenn dann ausschließlich aus dem Astro, oder Timer oder Brightness.

[FunkOdyssey2001]

Stellt sich dann nicht die Frage, warum überhaupt ein Shading Out exakt zum Zeitpunkt des Night Close durchgeführt wurde? Ich denke nicht, dass dies ein Zufall von Sonnenstand und Uhrzeit ist. Nicht über mehrere Wochen bei den gleichen Jalousien.

Es hätte eine Down-Fahrt auf Basis des Timers durchgeführt werden müssen.
Zwar habe ich auch überall den Brightness-Modus aktiv, aber das macht sich nicht im Sommer bemerkbar.

[FunkOdyssey2001]

Die aktuelle Version scheint dieses Verhalten zu korrigieren.
Dürfte Commit d1b04fc gewesen sein.

Ich bin dir sehr dankbar.

[FunkOdyssey2001]

Vielleicht zu früh geschlossen, aber wir lassen das erst einmal so.
Ich weiß nämlich noch nicht, ob die Rollos sich nun morgen mit Shading Out wieder öffnen. Ich gehe aber nicht davon aus, da die Rollos ja nun im Status NightClose sind.

[FunkOdyssey2001]

Ich weiß nicht wieso, aber heute hatte ich anstatt Night Close wieder ein Shading Out.

[CoolTuxNet]

Und wo ist er hin gefahren beim Shading out? In die geschlossen oder in die offen Position?