Merkwürdiges Verhalten 1 Jahr laufender Skripte...

[XxJooO]

Kurze Hilfe, debug output wo aktivieren?
Danke

[paul53]

@XxJooO sagte:

debug output wo aktivieren?

[XxJooO]

Ok, Kopf vor Stirn schlag und schäm...

[XxJooO]

Ok, es lebt... es arbeitet... es hat ein Bewusstsein entwickelt und will mich um den Verstand bringen...

javascript.0	2020-06-14 13:55:28.832	info	(2413) script.js.Rolladen.Rollladen_Test2: Fenster vorne.oeffnen getriggert: false
javascript.0	2020-06-14 13:55:28.778	info	(2413) script.js.Rolladen.Rollladen_Test2: Fenster vorne.oeffnen getriggert: true
javascript.0	2020-06-14 13:54:53.836	info	(2413) script.js.Rolladen.Rollladen_Test2: Fenster vorne.oeffnen getriggert: false
javascript.0	2020-06-14 13:54:53.788	info	(2413) script.js.Rolladen.Rollladen_Test2: Fenster vorne.oeffnen getriggert: true
javascript.0	2020-06-14 13:54:45.809	info	(2413) script.js.Rolladen.Rollladen_Test2: hoch oder runter geändert: undefined
javascript.0	2020-06-14 13:54:31.447	info	(2413) script.js.Rolladen.Rollladen_Test2: Fenster vorne.schliessen getriggert: false
javascript.0	2020-06-14 13:54:30.336	info	(2413) script.js.Rolladen.Rollladen_Test2: Fenster vorne.schliessen getriggert: true
javascript.0	2020-06-14 13:54:29.058	info	(2413) script.js.Rolladen.Rollladen_Test2: hoch oder runter geändert: undefined
javascript.0	2020-06-14 13:54:29.008	info	(2413) script.js.Rolladen.Rollladen_Test2: Fenster vorne.schliessen getriggert: false
javascript.0	2020-06-14 13:54:25.059	info	(2413) script.js.Rolladen.Rollladen_Test2: Fenster vorne.schliessen getriggert: true
javascript.0	2020-06-14 13:54:25.008	info	(2413) script.js.Rolladen.Rollladen_Test2: hoch oder runter geändert: undefined
javascript.0	2020-06-14 13:54:25.002	info	(2413) script.js.Rolladen.Rollladen_Test2: Soll-Position geändert: 100

Um 13:54:25.002 wird der Soll Wert von 0 auf 100 gestellt, die Laufzeit müsste 32 Sekunden sein.
Um 13:54:25.059 wird schliessen korrekt getriggert, aber bereits
um 13:54:29.008, also nur nach 4 Sekunden auf false getriggert und das Rollo stoppt.
Die nachfolgenden Trigger kommen, obwohl ich nichts aktiviert, sondern nur beobachtet habe...

Unfassbar... ich bin am Ende

[XxJooO]

Laufen Reste im Hintergrund, die sich überlagern? Wie kann ich das sehen?

[XxJooO]

Und es triggert immer weiter...

javascript.0	2020-06-14 14:02:13.382	info	(2413) script.js.Rolladen.Rollladen_Test2: Fenster vorne.schliessen getriggert: false
javascript.0	2020-06-14 14:02:08.996	info	(2413) script.js.Rolladen.Rollladen_Test2: Fenster vorne.schliessen getriggert: true
javascript.0	2020-06-14 14:01:16.749	info	(2413) script.js.Rolladen.Rollladen_Test2: Fenster vorne.schliessen getriggert: false
javascript.0	2020-06-14 14:01:10.957	info	(2413) script.js.Rolladen.Rollladen_Test2: Fenster vorne.schliessen getriggert: true
javascript.0	2020-06-14 14:00:28.820	info	(2413) script.js.Rolladen.Rollladen_Test2: Fenster vorne.oeffnen getriggert: false
javascript.0	2020-06-14 14:00:28.720	info	(2413) script.js.Rolladen.Rollladen_Test2: Fenster vorne.oeffnen getriggert: true
javascript.0	2020-06-14 13:59:34.504	info	(2413) script.js.Rolladen.Rollladen_Test2: Fenster vorne.schliessen getriggert: false
javascript.0	2020-06-14 13:59:33.567	info	(2413) script.js.Rolladen.Rollladen_Test2: Fenster vorne.schliessen getriggert: true
javascript.0	2020-06-14 13:58:09.669	info	(2413) script.js.Rolladen.Rollladen_Test2: Fenster vorne.schliessen getriggert: false
javascript.0	2020-06-14 13:58:06.511	info	(2413) script.js.Rolladen.Rollladen_Test2: Fenster vorne.schliessen getriggert: true
javascript.0	2020-06-14 13:55:28.832	info	(2413) script.js.Rolladen.Rollladen_Test2: Fenster vorne.oeffnen getriggert: false
javascript.0	2020-06-14 13:55:28.778	info	(2413) script.js.Rolladen.Rollladen_Test2: Fenster vorne.oeffnen getriggert: true
javascript.0	2020-06-14 13:54:53.836	info	(2413) script.js.Rolladen.Rollladen_Test2: Fenster vorne.oeffnen getriggert: false
javascript.0	2020-06-14 13:54:53.788	info	(2413) script.js.Rolladen.Rollladen_Test2: Fenster vorne.oeffnen getriggert: true
javascript.0	2020-06-14 13:54:45.809	info	(2413) script.js.Rolladen.Rollladen_Test2: hoch oder runter geändert: undefined
javascript.0	2020-06-14 13:54:31.447	info	(2413) script.js.Rolladen.Rollladen_Test2: Fenster vorne.schliessen getriggert: false
javascript.0	2020-06-14 13:54:30.336	info	(2413) script.js.Rolladen.Rollladen_Test2: Fenster vorne.schliessen getriggert: true
javascript.0	2020-06-14 13:54:29.058	info	(2413) script.js.Rolladen.Rollladen_Test2: hoch oder runter geändert: undefined
javascript.0	2020-06-14 13:54:29.008	info	(2413) script.js.Rolladen.Rollladen_Test2: Fenster vorne.schliessen getriggert: false
javascript.0	2020-06-14 13:54:25.059	info	(2413) script.js.Rolladen.Rollladen_Test2: Fenster vorne.schliessen getriggert: true
javascript.0	2020-06-14 13:54:25.008	info	(2413) script.js.Rolladen.Rollladen_Test2: hoch oder runter geändert: undefined
javascript.0	2020-06-14 13:54:25.002	info	(2413) script.js.Rolladen.Rollladen_Test2: Soll-Position geändert: 100

[paul53]

@XxJooO sagte:

nur nach 4 Sekunden auf false getriggert und das Rollo stoppt.

Da laufen mehrere Intervalle parallel. Starte mal die Instanz neu.

@XxJooO sagte in Merkwürdiges Verhalten 1 Jahr laufender Skripte...:

hoch oder runter geändert: undefined

Weshalb undefined ? Welcher Wert wird geloggt ?

[XxJooO]

Ich glaube, es kommt von diesem debug

Was sollte "value" denn hier ausgeben?

[XxJooO]

Instanz und ioBroker habe ich unterwegs schon zigfach neu gestartet. Habe auch schon neue Instanzen angelegt und versucht, das in einer weiteren auszuführen. Immer gleiches Verhalten...

[paul53]

@XxJooO sagte:

es kommt von diesem debug

Dort gibt es die lokale Variable value nicht. Wenn zwei Datenpunkte triggern, sollte man im Debug den Namen und den Wert ausgeben.

Weshalb Trigger auf "wurde aktualisiert" ?

[XxJooO]

Ok, werde ich versuchen und neu schauen.

aktualisiert hat ja ein Jahr funktioniert. Würde hier aktualisiert und geändert einen Unterschied machen? Ich würde in diesem Fall ja erwarten, dass wenn sich aktualisiert hat, der DP sich auch geändert hat.

[XxJooO]

Ich habe in meinem Test jetzt "Name" und "Wert" unter Variablen angelegt. Offensichtlich ist das nicht richtig, denn die Ausgabe ist

[paul53]

@XxJooO sagte:

dass wenn sich aktualisiert hat, der DP sich auch geändert hat.

Der DP (Zeitstempel) schon, aber nicht unbedingt der Wert.

[paul53]

@XxJooO sagte:

Offensichtlich ist das nicht richtig, denn die Ausgabe ist

Name und Wert sind unter "Trigger" entnommen ?

[XxJooO]

@paul53 sagte in Merkwürdiges Verhalten 1 Jahr laufender Skripte...:

@XxJooO sagte:

dass wenn sich aktualisiert hat, der DP sich auch geändert hat.

Der DP (Zeitstempel) schon, aber nicht unbedingt der Wert.

Das verstehe ich schon soweit. Aber der DP in diesem speziellen Fall würde ja nur aktualisiert, wenn er sich auch geändert hat. Bzw. hilft mir das nicht herauszufinden, was ihn geändert oder aktualisiert hat...

[XxJooO]

@paul53 sagte in Merkwürdiges Verhalten 1 Jahr laufender Skripte...:

@XxJooO sagte:

Offensichtlich ist das nicht richtig, denn die Ausgabe ist

Name und Wert sind unter "Trigger" entnommen ?

Nein, aber habe es jetzt gefunden und etwas sehr essenzielles gelernt!

[XxJooO]

Vielen Dank für die Hinweise. Mit diesem debug bin ich einen gehörigen Schritt weiter:

javascript.0	2020-06-14 14:53:58.092	info	(2413) script.js.Rolladen.Rollladen_Test2: Rolladen-Jo-vorne.runter: false
javascript.0	2020-06-14 14:53:41.944	info	(2413) script.js.Rolladen.Rollladen_Test2: Fenster vorne.oeffnen getriggert: false
javascript.0	2020-06-14 14:53:40.351	info	(2413) script.js.Rolladen.Rollladen_Test2: Fenster vorne.oeffnen getriggert: true
javascript.0	2020-06-14 14:53:38.299	info	(2413) script.js.Rolladen.Rollladen_Test2: Rolladen-Jo-vorne.runter: false
javascript.0	2020-06-14 14:53:38.295	info	(2413) script.js.Rolladen.Rollladen_Test2: Fenster vorne.schliessen getriggert: false
javascript.0	2020-06-14 14:53:28.839	info	(2413) script.js.Rolladen.Rollladen_Test2: Fenster vorne.schliessen getriggert: true
javascript.0	2020-06-14 14:53:28.791	info	(2413) script.js.Rolladen.Rollladen_Test2: Rolladen-Jo-vorne.runter: true
javascript.0	2020-06-14 14:53:28.788	info	(2413) script.js.Rolladen.Rollladen_Test2: Verzögerung für runter: 29300
javascript.0	2020-06-14 14:53:28.788	info	(2413) script.js.Rolladen.Rollladen_Test2: Soll-Position geändert: 100

Soll wird von 0 auf 100 gestellt
Die Laufzeit sind 29300 Hunderstel Sekunden
Rolladen-Jo-vorne.runter wird auf true gesetzt
Fenster vorne.schliessen wird auf true gesetzt, das ist der alias für den Sonoff-Schalter
jetzt!!!
Fenster vorne.schliessen (der alias des Schalters) wird 10 Sekunden später auf false gesetzt

Was danach kommt ist mir noch nicht ganz klar.
Bei 14:53:58.092 aber, also am Ende der Laufzeit von 29300 Hunderstel Sekunden wird Rolladen-Jo-vorne.runter korrekt auf false gesetzt.

Da ich mir die Änderung von "Fenster vorne.schliessen (der alias des Schalters) wird 10 Sekunden später auf false gesetzt" nicht anders erklären kann, da das Skript ja nichts triggert, frage ich mich, ob hier der Schalter nicht den Trigger auslöst. Somit wäre das ein Problem der Tasmota Firmware. Jetzt brauch ich nochmal einige Zeit um das zu loggen...

[Homoran]

@XxJooO sagte in Merkwürdiges Verhalten 1 Jahr laufender Skripte...:

Die Laufzeit sind 29300 Hunderstel Sekunden

nicht ganz
Das sind Tausendstel = Millisekunden

[XxJooO]

@Homoran

hast Recht, das erklärt aber leider nichts vom Verhalten...

[XxJooO]

!!!Ok, ich habe den Fehler endlich gefunden!!!

Es liegt an der Tasmota. Wenn ich Power1 für abwärts auf true setze, dann wird als Rückmeldung der DP 10 Sekunden später auf false gesetzt.
Der Schalter bleibt aber an... Das Skript aber registriert die Änderung des DP auf false und wird in Rückmeldung falsch getriggert.

Es hat wahrscheinlich was damit zu tun, dass ich teleperiod von 300 auf 100 gesetzt habe. Der DP wird nämlich exakt 10 Sekunden später auf false gesetzt. Ich werde mal ein issue aufmachen. Vielen dank an Alle, die sich an der Fehlersuche beteiligt haben!!! Ich setze für den Moment mal auf gelöst.