Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

SC triggert Auslöser mehrfach obwohl nur einer eingestellt #35

Closed
MMeinhardt1 opened this issue Oct 21, 2020 · 35 comments
Closed

SC triggert Auslöser mehrfach obwohl nur einer eingestellt #35

MMeinhardt1 opened this issue Oct 21, 2020 · 35 comments
Assignees
Labels
bug Something isn't working please test

Comments

@MMeinhardt1
Copy link

Hallo Mic,

ich glaube ein paar Probleme mit dem Adapter zu haben.

Im ersten Bild kann man sehen das einige Auslöser mehrfach getriggert werden obwohl nur einmal angelegt.

1603212845321-json_log

Und hier im zweiten Bild Punkt 1 war es am Wochenende so das die Lichter morgens ausgegangen sind, es für mich aber doch noch etwas zu dunkel war und ich habe die Lichter mit minuvis wieder eingeschaltet und alle 2 Minuten hat SC sie wieder ausgeschaltet.
In Punkt 2 ist zu sehen das SC die Lichter mehrfach innerhalb 1 Sekunde mehrfach anschalten wollte.

1603213221455-json_log1

Anbei noch ein Upload der Config falls das helfen würde, system.adapter.smartcontrol.0.json.txt.

Gibt es jemanden unter euch der ähliche Probleme bzw. Auffälligkeiten hat?

@MMeinhardt1 MMeinhardt1 added the bug Something isn't working label Oct 21, 2020
@MMeinhardt1
Copy link
Author

Ich habe gestern ein weiteres Script in SC umgesetzt, funktioniert auch bestens.
Gestern nach der Einrichtung und erstem Lauf kam nur ein Eintrag im json, heute kamen dann vier Einträge im json an.

@MMeinhardt1
Copy link
Author

Ich habe das mal weiter beobachtet und es werden immer mehr Einträge im json Log (als wenn jeden Tag einer dazu kommen würde).

@Mic-M
Copy link
Owner

Mic-M commented Oct 25, 2020

Hi,

danke fürs berichten. Ich habe schon einen Verdacht und teste gerade einen Fix.

@MMeinhardt1
Copy link
Author

Oh das klingt sehr gut, ich da the schon es liegt an meiner Konfiguration da im Forum keiner auf meinen Beitrag geantwortet hatte.

Danke

@Mic-M
Copy link
Owner

Mic-M commented Oct 26, 2020

Testen ist leider etwas schwierig, da das erst nach und nach auftritt.
Bitte mal die vor ein paar Minuten veröffentlichte Version 0.5.7 installieren und beobachten, mach ich ebenso ;)

@MMeinhardt1
Copy link
Author

Hi, 0.5.8 ist installiert und ich werde beobachten und berichten. Heute waren es auch wieder weniger Einträge.
Danke für das schnelle fixen. Ich würde gerne etwas spenden, wohin darf das?

@Mic-M
Copy link
Owner

Mic-M commented Oct 26, 2020

@MMeinhardt1

Ich würde gerne etwas spenden, wohin darf das?

Danke :-) Ich werde demnächst eine dezente Spenden-Option im Adapter einbauen, habe ich nichts eingerichtet bisher.

@MMeinhardt1
Copy link
Author

Guten Morgen Mic,

Spendenbutton klingt gut.
Bezüglich der mehrfachen Einträge im json Log gibt es aber leider keine Verbesserung, es gibt weiterhin die mehrfachen Einträge.

Danke

@Mic-M
Copy link
Owner

Mic-M commented Oct 27, 2020

Hab ich auch festgestellt.
Ich habe in Verdacht, dass das auftritt, sobald Mitternacht überschritten wird, konnte das aber so noch nicht testen. Am selben Tag nach Adapter-Neustart läuft es jedenfalls.
Hast du das auch so festgestellt? Also dass es vor Überschreitung der Mitternacht geht (also nur jew. 1x geschaltet wird)?

Ich frage, weil solche Dinge immer schwierig zu debuggen sind....

@Mic-M Mic-M added the question Further information is requested label Oct 27, 2020
@MMeinhardt1
Copy link
Author

Hi, was ich mit Sicherheit sagen kann, ist dass die mehrfachen Einträge nur von automatisierten also zeitgesteuerten Zonen kommt.
Ich habe zwei Steckdosen die über einen Zigbee Schalter manuell geschaltet werden, da ist es nicht. Wenn die gleichen Steckdosen mittels einer zeitgesteuerten Zone geschaltet werden gibt es mehrfach Einträge.
Ich beobachte mal ob es nach einem Neustarten des Adapters weniger Einträge sind.

@Mic-M
Copy link
Owner

Mic-M commented Oct 27, 2020

danke, das hilft schon mal zum eingrenzen.

Bitte beobachte auch mal, ob das erst nach Mitternacht auftritt, und es vorher geht.

Bei mir scheint das so: gestern Abend vor Mitternacht den Adapter neu gestartet (zeitgesteuert als Auslöser ein Cron-Job für jede Minute), und heute nun:
image

Nach Adapter-Neustart (und Updates) wird nur jede Minute einmal ausgelöst, also so wie es sein soll:
image

@MMeinhardt1
Copy link
Author

MMeinhardt1 commented Oct 28, 2020

Guten Morgen,

ich habe die aktuellste Version noch nicht installiert, aber mit der 0.5.8 macht es anscheinend keinen Unterschied ob der Adapter neugestartet wurde oder nicht. Ich glaube vielmehr das es auch mit der Menge an zu schaltenden Geräten zusammenhängt obwohl in einer Zeile des Logs immer alle zu schaltenden Geräte aufgeführt sind.

Die aktuelle Version kommt heute Abend drauf wenn ich wieder im Lande bin.

@MMeinhardt1
Copy link
Author

Hi Mic,
ich habe das vorhin nochmals versucht das irgendwie einzugrenzen. Ich habe so wie Du auch, Testeinträge erstellt.

  • als ersten Schritt habe ich ein Test-Gerät, einen Test-Auslöser (cron *****) und eine Test-Zone erstellt
  • im zweiten Schritt habe ich ein weiteres Test-Gerät erstellt und das der Zone hinzugefügt
    Nach dem erstellen und hinzufügen des zweiten Gerätes erscheinen die Einträge auch mehrfach. Falls das Verhalten zu dem "Bug" gehört hoffe ich das Du diesem auf die Schliche kommst, falls das allerdings programmiertechnisch gewollt ist würde ich drum bitten es zu ändern.

json

Danke

@Mic-M
Copy link
Owner

Mic-M commented Oct 28, 2020

Guten Abend,

danke für deine Hilfe bei diesem Bug!
Ich sehe gerade, dass du eben oben geantwortet hast, ich beziehe hier jetzt auf deine Antwort von heute Morgen:
Version 0.5.8 vs. 0.5.9 hat sich diesbezüglich nichts am Code geändert.

Langsam hab ich das node-schedule-Modul in Verdacht. Ich überlege, hier einen Workaround einzubauen:

                    this.x.schedules[lpRow.name] = this.x.mSchedule.scheduleJob(cron, async () => {

                        const triggerName = lpRow.name;
                        const trigger = this.x.triggers[triggerName]; // Trigger class instance

                        this.log.debug(`--- Trigger [${triggerName}] was triggered per schedule (time: ${trigger.triggerTime}) ---`);

                        // First check if additional conditions are met or "never if"
                        let doContinue = await trigger.asyncAreScheduleConditionsMet(trigger.triggerTmAdditionCond, trigger.triggerTmAddCondAll);
                        if (doContinue) doContinue = await trigger.asyncAreScheduleConditionsMet(trigger.triggerTmNever, trigger.triggerTmNeverAll, true);
                        if(!doContinue) {
                            this.x.helper.logExtendedInfo(`Trigger [${triggerName}] (time: ${trigger.triggerTime}) triggered, but condition(s) not met.`);
                            return;
                        }
                        trigger.asyncSetTargetDevices();
                    });
                    counter++;

Also bei Ausführung zu prüfen, ob letzte Ausführung dieses Auslösers z.B. innerhalb der letzten 2 Sekunden war, und falls ja, dann abbrechen.
Ich bleib dran.

@Mic-M
Copy link
Owner

Mic-M commented Oct 28, 2020

ich habe das vorhin nochmals versucht das irgendwie einzugrenzen. Ich habe so wie Du auch, Testeinträge erstellt.

  • als ersten Schritt habe ich ein Test-Gerät, einen Test-Auslöser (cron *****) und eine Test-Zone erstellt
  • im zweiten Schritt habe ich ein weiteres Test-Gerät erstellt und das der Zone hinzugefügt
    Nach dem erstellen und hinzufügen des zweiten Gerätes erscheinen die Einträge auch mehrfach. Falls das Verhalten zu dem "Bug" gehört hoffe ich das Du diesem auf die Schliche kommst, falls das allerdings programmiertechnisch gewollt ist würde ich drum bitten es zu ändern.

Interessante Feststellung!
Schaue ich mir an. Bei meinem Test - siehe oben - hatte ich ja nur 1 Gerät, und dennoch kamen nach einer Weile zwei Ausführungen.

Scheint ggf. ein separates Problem zu sein, denn dem "Schedule" (also this.x.mSchedule.scheduleJob(cron, async () => {) ist es egal, wie viele Geräte dann geschaltet werden sollen.

Über das Debug-Log kann ich aber nachvollziehen, dass er im obigen Beispiel
image

zwei mal das Callback von this.x.mSchedule.scheduleJob(cron, async () => { aufgerufen hat, was so nicht sein kann/darf.

@MMeinhardt1
Copy link
Author

Ich weiss nicht ob Dir das hier auch helfen könnte, aber ich stelle es trotzdem mal ein.

json1

Schön das Du am Ball bleibst!

@Mic-M
Copy link
Owner

Mic-M commented Oct 28, 2020

Adapter Version 0.5.10 sollte jetzt schon mal fixen, dass das Schedule mehrere male hintereinander ausgeführt wird.

Das mit der anderen identifizierten Problematik muss ich mir noch ansehen (also mehrere Geräte).

@Mic-M
Copy link
Owner

Mic-M commented Oct 28, 2020

Adapter Version 0.5.10 sollte jetzt schon mal fixen, dass das Schedule mehrere male hintereinander ausgeführt wird.

Es wird dann ein Log ausgegeben, falls dies der Fall ist.

`Trigger [${triggerName}] Adapter Issue #35 catch: do not execute scheduled trigger multiple times`

@Mic-M
Copy link
Owner

Mic-M commented Oct 28, 2020

bitte 0.5.11 verwenden, habe noch Korrektur eingebaut.

@MMeinhardt1
Copy link
Author

MMeinhardt1 commented Oct 29, 2020

GuMo,
0.5.11 installiert und wird getestet. Heute Abend kann ich berichten.

EDIT:
Heute morgen sieht es immer noch so aus,

json2

@MMeinhardt1
Copy link
Author

Hi, es ist leider immer noch alles beim alten. Sag Bescheid wenn ich noch etwas testen kann / soll.
Danke

@Mic-M
Copy link
Owner

Mic-M commented Oct 29, 2020

danke. musste noch auf 0.5.12 gehen, um was zu beheben.
Brauchst nicht extra testen, muss mir noch das andere Problem von oben ansehen. Ich melde mich hier.

@Mic-M
Copy link
Owner

Mic-M commented Oct 29, 2020

Endlich kann ich wohl jetzt die Problematiken isolieren.
Hab grad wenig Zeit, dauert also ggf. ein paar Tage, bis ein Fix kommt.

@Mic-M
Copy link
Owner

Mic-M commented Oct 31, 2020

@MMeinhardt1
Mit Adapter Version 0.5.13 sollte das nun alles behoben sein.
Bitte testen und Feedback, danke :-)

@Mic-M Mic-M added please test and removed question Further information is requested labels Oct 31, 2020
@MMeinhardt1
Copy link
Author

Hi Mic,
das ging ja sehr schnell, danke dafür!
Ist installiert und ich werde es testen und Feedback geben.
Was mir jetzt direkt schon aufgefallen war, in dem neuen "Target Log" wird das Value nicht übergeben. Ich habe zum testen eine meiner Steckdosen über einen Zigbee Schalter aus und wieder eingeschaltet und im Log ist kein Value zu sehen. Was müsste der Programmierung nach dort erscheinen?

@MMeinhardt1
Copy link
Author

Da fällt mir gerade noch etwas ein, wäre es aus Deiner Sicht eventuell ebenfalls sinnvoll das "time" in "date" und "time" aufzusplitten und bei der Zeit dann auch gleich noch die Tausendstelsekunden weg zu nehmen?
Das würde in dem Log optisch etwas schöner aussehen.

Danke

@Mic-M
Copy link
Owner

Mic-M commented Oct 31, 2020

Was mir jetzt direkt schon aufgefallen war, in dem neuen "Target Log" wird das Value nicht übergeben. Ich habe zum testen eine meiner Steckdosen über einen Zigbee Schalter aus und wieder eingeschaltet und im Log ist kein Value zu sehen. Was müsste der Programmierung nach dort erscheinen?

Das JSON zeigt nur Einträge für Zielgeräte, die durch den Adapter getriggert werden. Und auch "value" sollte immer gefüllt sein.

	{
		"time": "2020-10-31T19:55:00.022",
		"name": "Testgerät",
		"objectId": "0_userdata.0.example_state",
		"value": true,
		"triggerName": "TEST_3_jede 55ste Min",
		"ts": 1604170500022
	},

--> bitte mache am besten ein neues Issue auf diesbezüglich und beschreibe Details am besten mit Beispiel, da ich es nicht reproduzieren kann.

@Mic-M
Copy link
Owner

Mic-M commented Oct 31, 2020

Da fällt mir gerade noch etwas ein, wäre es aus Deiner Sicht eventuell ebenfalls sinnvoll das "time" in "date" und "time" aufzusplitten und bei der Zeit dann auch gleich noch die Tausendstelsekunden weg zu nehmen?
Das würde in dem Log optisch etwas schöner aussehen.

Bitte mache gerne ein neues Issue ("Enhancement Request") auf.
Wobei ich denke, dass es schöner wäre, wenn das die JSON-Table-Widgets für VIS könnten, also:

  1. Freie Möglichkeit der Wahl der einzelnen Spalten, also z.B. Spalten: 2, 2, 7, 3.
  2. Jede gewählte Spalte individuell formatieren, wie etwa das Datum (ts)

Evtl. gibt es das auch schon? ;)

@MMeinhardt1
Copy link
Author

Bitte mache gerne ein neues Issue ("Enhancement Request") auf.
Wobei ich denke, dass es schöner wäre, wenn das die JSON-Table-Widgets für VIS könnten, also:

1. Freie Möglichkeit der Wahl der einzelnen Spalten, also z.B. Spalten: 2, 2, 7, 3.

2. Jede gewählte Spalte individuell formatieren, wie etwa das Datum (ts)

Evtl. gibt es das auch schon? ;)

Ok das klingt logisch, das machen wir so.

@MMeinhardt1
Copy link
Author

Das JSON zeigt nur Einträge für Zielgeräte, die durch den Adapter getriggert werden. Und auch "value" sollte immer gefüllt sein.

	{
		"time": "2020-10-31T19:55:00.022",
		"name": "Testgerät",
		"objectId": "0_userdata.0.example_state",
		"value": true,
		"triggerName": "TEST_3_jede 55ste Min",
		"ts": 1604170500022
	},

--> bitte mache am besten ein neues Issue auf diesbezüglich und beschreibe Details am besten mit Beispiel, da ich es nicht reproduzieren kann.

Hab es gerade nochmal getestet und das "value": true in "value": "true" geändert, damit hat es das im json-Widget von minuvis funktioniert, also auch eher etwas für minuvis.
Danke

@MMeinhardt1
Copy link
Author

Hallo Mic,
die aktuelle Version läuft jetzt nun seit erscheinen und ich kann keine mehrfachen Einträge mehr in json erkennen.
Ich danke Dir für Deinen superschnellen und spitzenmäßigen Einsatz!

Danke

@Mic-M
Copy link
Owner

Mic-M commented Nov 2, 2020

Hi,
ich danke dir für deine ausführlichen Tests etc., damit konnte ich die Issues letztendlich eingrenzen und beheben👍

@MMeinhardt1
Copy link
Author

MMeinhardt1 commented Nov 3, 2020

Hi @Mic-M,

ich bin gerne beim "erforschen" behilflich, denn ich bin schließlich der Nutznieser Deiner Arbeit und das ist dann das wenigste was ich beisteuern kann.

Ich weiß nicht genau ob es hier her gehört, aber ich wollte erstmal kein neues Thema öffnen. Beim durchschauen der json Daten habe ich wieder festgestellt das einige meiner Zonen mehrfach auslösen. Wie im ersten Post schon mal geschrieben, immer im Abstand von 2 Minuten, da sieht man dann auch die "geskippten" Targets.
Ich habe alles durchgeschaut und kann irgendwie keinen Fehler in meiner Konfiguration finden, daher die Bitte an Dich das Du Dir sowohl meine angehängte Konfig wie auch das angehängte json Log mal anschaust wenn Du die Zeit dafür findest.

mein Konfigurationsfile

json_log

HTML Datei zur Auswertung(das kannst Du wahrscheinlich viel besser)

Vielen Dank
Michael

@MMeinhardt1 MMeinhardt1 reopened this Nov 3, 2020
@MMeinhardt1
Copy link
Author

Hi @Mic-M,
hast Du schon Zeit gefunden Dir das ganze nochmals anzuschauen?

Gruß Michael

@Mic-M
Copy link
Owner

Mic-M commented Nov 10, 2020

Hi Michael,

ich bin gerne beim "erforschen" behilflich, denn ich bin schließlich der Nutznieser Deiner Arbeit und das ist dann das wenigste was ich beisteuern kann.

Vielen Dank für deine Einstellung, das ist leider nicht bei allen Anwendern so selbstverständlich, dass Entwickler möglichst zielführende Infos und Tests brauchen :-)
Danke auch für die Zurverfügungstellung als HTML zur komfortableren Prüfung, top!

Die 2 Minuten-Regelmäßigkeit ist sehr interessant.

Ich habe eben ein neues Issue aufgemacht: #43

Da geht es jetzt weiter ;)

@Mic-M Mic-M closed this as completed Nov 10, 2020
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
bug Something isn't working please test
Projects
None yet
Development

No branches or pull requests

2 participants