Jahresrückblick 2025 – unser neuer Blogbeitrag ist online! ✨

[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 :+1:

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.

[crunchip]

@XxJooO

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

Der DP wird nämlich exakt 10 Sekunden später auf false gesetzt

Damit hatte ich seit 1.01.2020 herum gekämpft. Bis ich herausgefunden hatte, warum meine Lichter nicht mehr Schalten wie sie sollen. Hatte auch hierzu schon im Forum angefragt wegen diesem Problem, jedoch ohne Erfolg.
Beispiel:
Ich schalte ein Licht ein, jedoch wird der state per Teleperiod "überschrieben". und der DP steht auf false, Lampe ist aber weiterhin an.
Habe sämtliche Tasmota Versionen rauf und runter gespielt, sämtliche sonoff Adapter Versionen ausprobiert, allerdings blieb das Problem bestehen.
Als ich jedoch meine VM, (die in Proxmox läuft) von debian stretch auf buster aktualisiert und anschliessend node v10 auf v12 angehoben hatte, funktionierte wieder alles normal.

[XxJooO]

Hallo @crunchip,

ich habe jetzt noch mal ein wenig anders experimentiert. Ich erkenne, dass der DP nach Ablauf der teleperiod-Zeit von true auf false geht. Der Schalter bleibt aber an und das wird auch korrekt im Webinterface des T2 angezeigt.

Ich vermute also eher ein Problem im Sonoff-Adapter und mache da mal ein issue auf. Möglicherweise hat sich irgendwas bei Tasmota geändert, das beim Sonoff-Adapter eingepflegt werden muss...

Buster und node 12.18 laufen bei mir schon...

[crunchip]

@XxJooO der sonoff Adapter läuft aber bereits seit 27.11.2019 mit v2.3.3.

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

Der Schalter bleibt aber an

ist richtig, war bei mir auch so, das meinte ich, deshalb hatte ich ja "überschrieben" oben erwähnt.