Timer-Device, WebUI-Programm mit TIMER_EVENT als Trigger wird nur 1x ausgeführt

Anbindung von FS20-Komponenten, ELV-Wetterstationen, EnOcean und DMX an HomeMatic

Moderator: Co-Administratoren

Antworten
Benutzeravatar
Baxxy
Beiträge: 10826
Registriert: 18.12.2018, 15:45
System: Alternative CCU (auf Basis OCCU)
Hat sich bedankt: 607 Mal
Danksagung erhalten: 2225 Mal

Timer-Device, WebUI-Programm mit TIMER_EVENT als Trigger wird nur 1x ausgeführt

Beitrag von Baxxy » 07.04.2022, 23:13

In der CUxD-Doku wird davon abgeraten TIMER_EVENT als Programmtrigger zu nutzen.
Aktuell zu Recht, denn nach meinen Tests triggern die WebUI-Programme zwar immer korrekt, es wird aber nur genau 1x (nach Zentralenstart) das zugehörige DANN ausgeführt.

Es gibt zwar noch andere Möglichkeiten auf einen CUxD-Timer zu triggern, das TIMER_EVENT ist aber m.E. die beste Option wenn sie denn funktionieren würde.

Testsetup:
RaspberryMatic (Nightly-3.63.8.20220407-16df83-ova)
CUxD Spezial-Testversion 2.8.3

einfacher Timer (repeat alle 60s jeweils um xx:xx:25):
CUxD-TIMER_EVENT.JPG
einfaches WebUI-Programm:
CUxD-TIMER_EVENT_prg.JPG
Systemprotokoll:

Code: Alles auswählen

22:15:25	07.04.2022	CUxD-Timer-Dev:2 - EVENT	unbekannte Meldung (TIMER_EVENT=TRUE)
22:15:25	07.04.2022	Programme_loggen	TIMER_EVENT - OK! -OVA-
22:16:25	07.04.2022	CUxD-Timer-Dev:2 - EVENT	unbekannte Meldung (TIMER_EVENT=TRUE)
22:17:25	07.04.2022	CUxD-Timer-Dev:2 - EVENT	unbekannte Meldung (TIMER_EVENT=TRUE)
22:18:25	07.04.2022	CUxD-Timer-Dev:2 - EVENT	unbekannte Meldung (TIMER_EVENT=TRUE)
22:19:25	07.04.2022	CUxD-Timer-Dev:2 - EVENT	unbekannte Meldung (TIMER_EVENT=TRUE)
Nun der interessante Teil (Logikschicht "alles loggen") auf das relevante gekürzt:
A: erfolgreiche Programmausführung 22:15:25

Code: Alles auswählen

Info: Event="CUX2800001:2"."TIMER_EVENT"=true [execute():iseXmlRpc.cpp:321]
Verbose: call on change; id = 1051 [SetLastDPActionTime():iseDOMchn.h:288]
Verbose: call on change; id = 1037 [SetLastActionTime():iseDOMdev.h:225]
Verbose: call on change; id = 1051 [SetLastDPActionTime():iseDOMchn.h:288]
Verbose: call on change; id = 1037 [SetLastActionTime():iseDOMdev.h:225]
Verbose: UpdateValue succeeded; val = 1 [execute():iseXmlRpc.cpp:364]
Verbose: called Program ID = 1390 'CUxD_Timer_EVENT_Test' with valNew = '1' ; oidTrigger = 1056 [SetState():iseDOMPrg.cpp:483]
Verbose: DP_VALUE_CHECK_CHANGE is set, trigger dp exists  [CheckCondition2Data():iseCondition.cpp:528]
Verbose: type = 1, condition valL = 1 valR1 = 1 [Evaluate():iseCondition.cpp:392]
Verbose: sc = 0, CONDITION_TRIGGER_EXECUTE is reset. [Evaluate():iseCondition.cpp:1116]
Verbose: sc = 0, CONDITION_TRIGGER_TRUE is set. [Evaluate():iseCondition.cpp:1121]
Verbose: sc = 0, condition result = 1 [Evaluate():iseCondition.cpp:1123]
Verbose: c = 0, CONDITION_TRIGGER_EXECUTE is reset. [Evaluate():iseRule.cpp:227]
Verbose: c = 0, CONDITION_TRIGGER_TRUE is set. [Evaluate():iseRule.cpp:232]
Verbose: c = 0, condition result = 1 [Evaluate():iseRule.cpp:235]
Verbose: Rule evaluated state is TRUE by Program ID = 1390 'CUxD_Timer_EVENT_Test'; Destination ID = 1392 [SetState():iseDOMPrg.cpp:509]
Info: Program ID = 1390 'CUxD_Timer_EVENT_Test', rule's trigger flags = 4 [SetState():iseDOMPrg.cpp:524]
Verbose: execute Program ID = 1390 'CUxD_Timer_EVENT_Test'; Destination ID = 1392 [Execute():iseDOMPrg.cpp:626]
Verbose: start execute Destination within the trigger delay 0 [Execute():iseDOMPrg.cpp:630]
Info: added element id=1034; oid=1034; val=TIMER_EVENT - OK! -OVA-; time=0; oidTrigger=1056 [Add():iseRTScheduler.cpp:369]
Verbose: ExecuteDestination succeeded from Program ID = 1390 'CUxD_Timer_EVENT_Test' with valNew = '1' [Execute():iseDOMPrg.cpp:640]
Verbose: wait max timeout = 240000 [ThreadFunction():iseRTEvent.cpp:69]
Info: calling SetState on DP id = 1034 (Programme_loggen) value = TIMER_EVENT - OK! -OVA- oidTrigger = 1056 [ExecuteWriteJob():iseRTScheduler.cpp:637]
Info: SetState() succeeded for DP id = 1034 [ExecuteWriteJob():iseRTScheduler.cpp:642]
Verbose: ExecuteWriteJob: oid = 1034; ticks = 0 [Execute():iseRTScheduler.cpp:595]
Info: wait for event ms= 4294967295 [ThreadFunction():iseRTScheduler.cpp:485]
Verbose: wait max timeout = 240000 [ThreadFunction():iseRTEvent.cpp:69]
B: keine Programmausführung 22:16:25

Code: Alles auswählen

Info: Event="CUX2800001:2"."TIMER_EVENT"=true [execute():iseXmlRpc.cpp:321]
Verbose: call on change; id = 1051 [SetLastDPActionTime():iseDOMchn.h:288]
Verbose: call on change; id = 1037 [SetLastActionTime():iseDOMdev.h:225]
Verbose: call on change; id = 1051 [SetLastDPActionTime():iseDOMchn.h:288]
Verbose: call on change; id = 1037 [SetLastActionTime():iseDOMdev.h:225]
Verbose: UpdateValue succeeded; val = 1 [execute():iseXmlRpc.cpp:364]
Verbose: called Program ID = 1390 'CUxD_Timer_EVENT_Test' with valNew = '1' ; oidTrigger = 1056 [SetState():iseDOMPrg.cpp:483]
Verbose: DP_VALUE_CHECK_CHANGE is set, trigger dp exists  [CheckCondition2Data():iseCondition.cpp:528]
Verbose: type = 1, condition valL = 1 valR1 = 1 [Evaluate():iseCondition.cpp:392]
Verbose: sc = 0, CONDITION_TRIGGER_EXECUTE is reset. [Evaluate():iseCondition.cpp:1116]
Verbose: sc = 0, condition result = 1 [Evaluate():iseCondition.cpp:1123]
Verbose: c = 0, CONDITION_TRIGGER_EXECUTE is reset. [Evaluate():iseRule.cpp:227]
Verbose: c = 0, condition result = 1 [Evaluate():iseRule.cpp:235]
Verbose: Rule evaluated state is TRUE by Program ID = 1390 'CUxD_Timer_EVENT_Test'; Destination ID = 1392 [SetState():iseDOMPrg.cpp:509]
Info: break execute for Program ID = 1390 'CUxD_Timer_EVENT_Test', rule's trigger flags = 0 [SetState():iseDOMPrg.cpp:530]
Diff als Screenshot:
CUxD_TIMER_EVENT_Diff.JPG
Hinweise:
Das ist kein spezielles RaspberryMatic Problem. Bei einer CCU3 konnte ich genau das gleiche Verhalten beobachten.

Die Frage ist nun... warum wird die Ausführung des Programmes nach dem 1. erfolgreichen Durchlauf immer abgebrochen.

Benutzeravatar
uwe111
Beiträge: 4820
Registriert: 26.02.2011, 22:22
Hat sich bedankt: 3 Mal
Danksagung erhalten: 246 Mal
Kontaktdaten:

Re: Timer-Device, WebUI-Programm mit TIMER_EVENT als Trigger wird nur 1x ausgeführt

Beitrag von uwe111 » 08.04.2022, 13:16

Baxxy hat geschrieben:
07.04.2022, 23:13
Das ist kein spezielles RaspberryMatic Problem. Bei einer CCU3 konnte ich genau das gleiche Verhalten beobachten.
Auf meiner CCU2 auch!
Baxxy hat geschrieben:
07.04.2022, 23:13
Die Frage ist nun... warum wird die Ausführung des Programmes nach dem 1. erfolgreichen Durchlauf immer abgebrochen.
Ich vermute, der BUG liegt in der Auswertung der Auslösebedingungen der Programmverknüpfung durch die ReGa bzw. deren Speicherung durch die WebUI.

Da der TIMER_EVENT Datenpunkt vom Typ ACTION ist, wird hier jedes Mal nur der Status TRUE empfangen. Intern scheint der Trigger aber auf Änderungen des Wertes zu warten.

Bei den Taster-Datenpunkten PRESS_SHORT und PRESS_LONG vom Typ ACTION funktioniert das problemlos. Wahrscheinlich ist in diesem Fall eine Ausnahme in der ReGa/WebUI implementiert.

Folgendermaßen konnte ich bei mir die Triggerung der nachfolgenden Events aktivieren:
  1. Wenn... Bedingung in der Programmverknüpfung von "bei TIMER_EVENT" in "bei Schaltzustand Ein" "bei Aktualisierung auslösen" ändern
  2. dann sofort zurück auf "bei TIMER_EVENT" setzen
  3. jetzt die Programmverknüpfung speichern und erneut testen
Gleichermaßen konnte ich die Triggerung der nachfolgenden Events wieder deaktivieren:
  1. Wenn... Bedingung in der Programmverknüpfung von "bei TIMER_EVENT" in "bei Schaltzustand Ein" "bei Änderung auslösen" bzw. "nur prüfen" ändern
  2. dann sofort zurück auf "bei TIMER_EVENT" setzen
  3. jetzt die Programmverknüpfung speichern und erneut testen
Diese Abhängigkeit ist mir damals schon auf der CCU1 aufgefallen und dürfte m.E. so nicht sein!

Viele Grüße

Uwe
Alle sagten: Das geht nicht. Dann kam einer, der wußte das nicht und hat's einfach gemacht.
SPENDEN :wink: Download: CUxD 2.11, SSH KeyDir

Benutzeravatar
Baxxy
Beiträge: 10826
Registriert: 18.12.2018, 15:45
System: Alternative CCU (auf Basis OCCU)
Hat sich bedankt: 607 Mal
Danksagung erhalten: 2225 Mal

Re: Timer-Device, WebUI-Programm mit TIMER_EVENT als Trigger wird nur 1x ausgeführt

Beitrag von Baxxy » 08.04.2022, 15:16

Hallo Uwe,
nach ein paar Versuchen hat der "Workaround" auch bei mir funktioniert.

Jetzt wird munter auf TIMER_EVENT getriggert und auch das DANN ausgeführt.
Das Testprogramm funktioniert auch nach einem Reboot noch korrekt.

Ich werde die Thematik bei Gelegenheit @jmaus vorlegen, vielleicht findet er heraus warum das so ist. Und kann ggf. das Problem beheben.

Grüße, Baxxy

Benutzeravatar
Baxxy
Beiträge: 10826
Registriert: 18.12.2018, 15:45
System: Alternative CCU (auf Basis OCCU)
Hat sich bedankt: 607 Mal
Danksagung erhalten: 2225 Mal

Re: Timer-Device, WebUI-Programm mit TIMER_EVENT als Trigger wird nur 1x ausgeführt

Beitrag von Baxxy » 08.04.2022, 15:49

Interessanterweise sieht das Log für das per Workaround korrigierte Programm nun etwas anders (im Gegensatz zu A aus Post 1) aus.
C: per Uwe's Workaround funktionsfähig gemachtes Programm:

Code: Alles auswählen

Info: Event="CUX2800001:2"."TIMER_EVENT"=true [execute():iseXmlRpc.cpp:321]
Verbose: call on change; id = 1051 [SetLastDPActionTime():iseDOMchn.h:288]
Verbose: call on change; id = 1037 [SetLastActionTime():iseDOMdev.h:225]
Verbose: call on change; id = 1051 [SetLastDPActionTime():iseDOMchn.h:288]
Verbose: called Program ID = 1390 'CUxD_Timer_EVENT_Test' with valNew = '1' ; oidTrigger = 1056 [SetState():iseDOMPrg.cpp:483]
Verbose: DP_VALUE_CHECK_UPDATE is set, trigger dp exists  [CheckCondition2Data():iseCondition.cpp:504]
Verbose: DP_VALUE_CHECK_UPDATE is set, condition = 1 [CheckCondition2Data():iseCondition.cpp:510]
Verbose: type = 1, condition valL = 1 valR1 = 1 [Evaluate():iseCondition.cpp:392]
Verbose: sc = 0, CONDITION_TRIGGER_TRUE is set. [Evaluate():iseCondition.cpp:1121]
Verbose: sc = 0, condition result = 1 [Evaluate():iseCondition.cpp:1123]
Verbose: c = 0, CONDITION_TRIGGER_TRUE is set. [Evaluate():iseRule.cpp:232]
Verbose: c = 0, condition result = 1 [Evaluate():iseRule.cpp:235]
Verbose: Rule evaluated state is TRUE by Program ID = 1390 'CUxD_Timer_EVENT_Test'; Destination ID = 1392 [SetState():iseDOMPrg.cpp:509]
Info: Program ID = 1390 'CUxD_Timer_EVENT_Test', rule's trigger flags = 6 [SetState():iseDOMPrg.cpp:524]
Verbose: execute Program ID = 1390 'CUxD_Timer_EVENT_Test'; Destination ID = 1392 [Execute():iseDOMPrg.cpp:626]
Verbose: start execute Destination within the trigger delay 0 [Execute():iseDOMPrg.cpp:630]
Info: added element id=1034; oid=1034; val=TIMER_EVENT - OK! -OVA-; time=0; oidTrigger=1056 [Add():iseRTScheduler.cpp:369]
Verbose: ExecuteDestination succeeded from Program ID = 1390 'CUxD_Timer_EVENT_Test' with valNew = '1' [Execute():iseDOMPrg.cpp:640]
Verbose: wait max timeout = 240000 [ThreadFunction():iseRTEvent.cpp:69]
Verbose: call on change; id = 1037 [SetLastActionTime():iseDOMdev.h:225]
Verbose: UpdateValue succeeded; val = 1 [execute():iseXmlRpc.cpp:364]
Info: calling SetState on DP id = 1034 (Programme_loggen) value = TIMER_EVENT - OK! -OVA- oidTrigger = 1056 [ExecuteWriteJob():iseRTScheduler.cpp:637]
Info: SetState() succeeded for DP id = 1034 [ExecuteWriteJob():iseRTScheduler.cpp:642]
Verbose: ExecuteWriteJob: oid = 1034; ticks = 0 [Execute():iseRTScheduler.cpp:595]
Info: wait for event ms= 4294967295 [ThreadFunction():iseRTScheduler.cpp:485]
Diff als Screenshot (A <-> C):
CUxD_TIMER_EVENT_Diff_A-C.JPG
Man kann erkennen das A & B auf Änderung (CHANGE) prüfen. Das funktioniert bei A noch, bei B dann nicht mehr denn es ist nur ein unveränderliches EVENT.

Code: Alles auswählen

Verbose: DP_VALUE_CHECK_CHANGE is set, trigger dp exists  [CheckCondition2Data():iseCondition.cpp:528]
C hingegen prüft auf Aktualisierung (UPDATE), was korrekt ist und entsprechend auch funktioniert.

Code: Alles auswählen

Verbose: DP_VALUE_CHECK_UPDATE is set, trigger dp exists  [CheckCondition2Data():iseCondition.cpp:504]
Demzufolge sieht es für mich danach aus als würde die CONDITION (CHANGE / UPDATE) beim Anlegen des Programmes falsch erzeugt.

Grüße, Baxxy

Antworten

Zurück zu „CUxD“