Rule triggert erst nach ca. 15 Sekunden

[netzlaff]

Hallo Leute,

ich habe meine vorherige manuell installierte OpenHAB 2.0 Installation durch ein frisches OpenHABian 2.2 ersetzt. Alle Rules, Items, etc. habe ich mit übernommen. Funktioniert soweit auch alles super. Nur habe ich aktuell das Problem, das mache Rules extrem zeitversetzt getriggert werden. Beispielsweise habe ich ein paar Rules, welche auf geschaltete Lichter reagieren. Quasi wenn Licht 1 ausgeschaltet wird, soll Licht 2 mit aus gehen, oder etwas anderes aktiviert/deaktiviert werden. Ich habe hier eine KNX Installation für Licht und Rollladen. OpenHAB erledigt meine Komfort-/Logik-Funktionen. OpenHAB läuft eine RPi 3 und ist mittels Pigator und knxd 0.14 an den KNX-Bus angeschlossen. Cron-Rules, welche die Rollladen hoch oder runter fahren lassen, fahren auf die Sekunde genau.
Wie gesagt, mit der alten Installation hat es sehr gut und vor allem schnell funktioniert.

Wo könnte man mit dem Debugging ansetzen?

Danke für eure Hilfe.

[udo1toni]

Die Frage ist: sind es immer die gleichen Rules, die zu spät laufen? Was passiert drum herum? Nutzt Du Thread:sleep() in einigen Rules?

[netzlaff]

Ja, es sind immer die gleichen. Manchmal dauert es 10, mal 20 oder gar 30 Sekunden, nachdem ein Licht den Status geändert hat und erst dann ein Trigger auslöst. Mal klappt es auch sofort. In ein paar Rules nutze ich Sleep. Aber auch in Rules, welche sofort getriggert werden. Die meisten Rules, welche diese Verzögerungen ausweist, befinden sich in einer Datei. Welche aber nach dem Upgrade nicht geändert wurde und nach dem Upgrade zuerst auch schon ordentlich funktioniert hat.

[udo1toni]

Wie lang sind die Thread::sleep() Wartezeiten?

Hintergrund meiner Frage: openHAB nutzt einen Threadpool für die Ausführung der Rules. Default sind das 5 Threads, das bedeutet, wenn eine 6. Rule zeitgleich laufen soll, wartet openHAB mit der Ausführung, bis wieder ein Thread frei ist.

[misa]

Ich würde empfehlen mit timern und nicht mit sleep zu arbeiten.

[udo1toni]

Ja, kommt halt darauf an, um welche Zeiträume es geht. Weniger als 500mSec ist als sleep vollkommen ok (wenn nicht gerade 10 Stück hintereinander in der Rule stehen).

[netzlaff]

Ich nutze mehrere Sleeps mit deutlich längeren Zeiträumen. Abgefangen von 15 bis auch 30 und 45 Sekunden. War zumindest mit der 2.0er OH2 kein Problem. Aber wenn das mit der neuen 2.2 nicht mehr empfohlen wird, muss ich das irgendwie ändern.

Betrifft das vermutlich auch Rules welch ohne Sleep laufen und sofort triggern soll? Die quasi durch andere Sleeps/Rules geblockt werden?

[udo1toni]

Das war noch nie empfohlen

Thread::sleep() sollte nur verwendet werden, wenn es um eine kurze Verzögerung geht, z.B. um dem Persistence Service Zeit zu geben, den Zustand eines Trigger-Items zu speichern, damit man mit der Persistence zuverlässig auf dieses Item zugreifen kann. Das sind dann vielleicht 100mSec.

Wenn es darum geht, z.B. eine Lampe nach 15 Sekunden wieder auszuschalten, sollte man einen Timer nutzen, alternativ das Expire Binding.

Grob gesagt besteht hier der Unterschied darin, dass man beim Expire Binding nur ein statisches Verhalten vorgeben kann, während der Timer beliebig komplexe Abläufe dynamisch planen kann. Dafür ist das Expire Binding einfacher in der Handhabung:

Switch MySwitch "Mein Schalter" {expire="15s,command=OFF"}

Wenn es einen ON-Befehl gibt, wechselt der Switch nach 15 Sekunden zurück auf OFF. Das ist retriggerbar, heißt, wenn man alle 14 Sekunden einen ON-Befehl schickt, wechselt der Switch erst bei Ausbleiben des On-Befehls auf OFF (Prima um z.B. einen Watchdog zu steuern)
das Ganze per Rule:

var Timer MyTimer = null

val Int iTimerDuration = 15

rule "My Timer Rule"
when
    Item MySwitchItem received command ON
then
    if(MyTimer !== null)
        MyTimer = createTimer(now.plusSeconds(iTimerDuration), [|
            MySwitchItem.sendCommand(OFF)
            MyTimer = null
        ])
    else
        MyTimer.reschedule(now.plusSeconds(iTimerDuration))
end

Vorteil dieser Variante: Die Zeit muss nicht zwingend statisch sein, man kann einen Retrigger ignorieren oder anders darauf reagieren, Bei Ablauf des Timers können beliebig viele Befehle ausgeführt werden - man könnte z.B. auch weitere Timer starten.

Das Lambda (Der Teil innerhalb der [ ] Klammern) wird zur späteren Verwendung gespeichert, ein Zeiger auf den Code wird eingerichtet, im Scheduler wird für den Zeitpunkt der Zeiger hinterlegt. Wenn die Rule hier zuende ist, ist damit der Thread wieder frei. Der Scheduler führt dann zum festgelegten Zeitpunkt den Code aus.

[netzlaff]

Gut, dann werde ich meine Rules alle umbauen und schauen, ob dann alles wieder ordentlich funktioniert.

Danke erstmal, melde mich dann hier im Thread nochmal.

[netzlaff]

Das Komische ist aber, auch wenn lange Zeit keine Rules mehr laufen und dann eine ohne Sleep aktiviert wird, wird diese teilweise bis zu 60 später erst ausgeführt. Das kann dann meine ich nicht an den Sleeps liegen.

Nach gut 24 Stunden muss ich OH2 neu starten, weil dann fast nichts mehr funktioniert...

[udo1toni]

Kann auch gut sein, dass Du irgendwas hast, was mit der Zeit immer mehr Speicher und Prozessorzeit frisst. Da ich weder Deine Rules noch Deine genaue Konfiguration kenne, ist das etwas schwierig zu errraten.

[netzlaff]

Habe jetzt alle Sleeps entfernt und durch Timer ersetzt, außer kleine mit 150 oder 200msec.

Leider scheint dies aber absolut keine Besserung zu bringen, hier ein Auszug aus meinen Logs:

==> /var/log/openhab2/events.log <==
2018-03-05 16:08:26.859 [vent.ItemStateChangedEvent] - Cam1_Flur_EG changed from ON to OFF

==> /var/log/openhab2/openhab.log <==
2018-03-05 16:08:43.406 [INFO ] [.smarthome.model.script.motion.rules] - MOTION: Flur EG beendet

Die Rule, welche auf Cam1_Flur_EG triggert, wird fast 30 Sekunden später ausgeführt!

Hier die Rule:

rule "MOTION: Flur EG Bewegung beendet"
when
        Item Cam1_Flur_EG changed to OFF
then
    logInfo("motion.rules", "MOTION: Flur EG beendet" )
    ...
end

...und anders herum auch:

2018-03-05 17:30:28.520 [vent.ItemStateChangedEvent] - Cam1_Flur_EG changed from OFF to ON
2018-03-05 17:30:30.000 [vent.ItemStateChangedEvent] - HeatPump_Temperature_4 changed from 40 to 40.2999999999999971578290569595992565155029296875
2018-03-05 17:30:30.021 [vent.ItemStateChangedEvent] - HeatPump_Temperature_2 changed from 31 to 31.300000000000000710542735760100185871124267578125
2018-03-05 17:30:30.040 [vent.ItemStateChangedEvent] - HeatPump_Hot_Gas changed from 68.5 to 69.2999999999999971578290569595992565155029296875

==> /var/log/openhab2/openhab.log <==
2018-03-05 17:30:43.527 [INFO ] [.smarthome.model.script.motion.rules] - MOTION: Bewegung Flur EG erkannt

--> wieder ~15 Sekunden Verzögerung

[zaphood]

Hab ich auch schon mehrfach beobachtet. An manchen Tagen laufen die Rules sofort, an anderen hatte ich 5-20s Verzögerung. Am Ende hat dann immer nur eine komplette Neuinstallation des RPi geholfen. Hab auch schon mehrfach die Installation mit dem Openhabianpi Image durchgeführt und am Ende ist ständig was hängen geblieben, nicht sauber gestartet oder war extrem lahm. Keep going und wenn schliesslich eine Installation mal sauber läuft, dann sind auch die Verzögerungen weitgehend weg (wobei etliche kurze Rules schon mal mit 1-3s Verzögerung laufen, so richtig schnell war das noch nie bei mir).

Hatte auch schon den Effekt, das geclonte SD Card Images immer langsamer wurden. Dazu gibt es zwar ein par Threads im Web, aber nichts belastbares; bei mir war der Effekt aber definitiv spürbar (nach dem Clone vom Clone war alles wie Gummi...unbedienbar)

Vlt also mal am WE einfach die Konfig sichern und das Ding kurz neu aufsetzen, bevor du zu viel Zeit ins Debugging steckst. Denk dran, EDV = Erfolg durch versuchen :-)

[netzlaff]

Meine SD ist eine neue Class 10, mit ganz sauberen Image drauf. Seit dieser Installation habe ich die Verzögerungen, Systemauslastung liegt immer so bei 30%. Vorher lief ein OH 2.0 mit selbiges Rules komplett ohne Verzögerungen.

[zaphood]

Na das passt doch zu meinen Erfahrungen :-) Wobei ich dir da zustimme, seit 2.2 ist das alles generell etwas zäher, auch bei mir. Aber aktuell (!) rennen alle meine Rules ohne nennenswerte Verzögerung (1-2s sehe ich noch nicht als wesentlich an)

Warum auch immer, manche Installationen lahmen bei mir genau auf die selbe Weise wie bei dir. Neu aufgesetzt und meistens ging's dann magisch (trotz kopierter Konfigs) wieder. Aktuell liegt die Systemlast bei <5% im Durchschnitt bei mir.

Eine logische Erklärung hab ich leider nicht gefunden, aber das sind eben meine Erfahrungen. Ich habe zwei Freunde die auch mit OH2 arbeiten, bei denen tritt das nie auf. Nur bei mir :-( ...und auch bei verschiedenen SD Cards sowie verschiedenen RPI's, sogar schon mit verschiedenen PC das Image geschrieben, völlig egal. Ohne Systematik immer mal wieder die Bremse drin...

Das Beispiel mit der geclonten Karte ist dann nicht relevant bei dir, wollte nur diese Erfahrung auch sharen

Aber wer weiss, vlt. ist das bei mir was persönliches zwischen OH2 und mir :-D