Mehrfache Telegramme auf den Bus mit KNX Anbindung

[erru]

Hallo Kai.
Das Problem mit der doppelten Ausführung von Regeln scheint zu sein, dass interne und externe Events dieselbe Bezeichnung haben. In meinem Testfall habe ich eine Lampe mit dem Namen Light_Office.
Wenn man jetzt im Browser das Licht einschaltet, wird ein "Light_Office On" Event erzeugt. Dazu wird die entsprechende Regel ausgeführt.

Nun wird der Event auf den KNX Bus geschrieben. Das erzeugt nun auch ein "Light_Office On" Event und die Regel wird nochmals ausgeführt.
Meiner laienhaften Ansicht nach müsste man die Events getrennt voneinander behandeln bzw. markieren.

Gruß
erru

[kkreuzer]

Wenn ein Command übers UI ausgelöst wird, geht es auf KNX, triggert aber kein zweites Command-Event. Damit das Event auf KNX geht, brauchst Du auch keine Regel, ist das evtl. das Problem?

Prinzipiell sollte es mit der jetzigen 1.0.0 alles ordentlich funktionieren. Wenn nicht, poste doch mal Deine Regel.

Grüße,
Kai

[erru]

Hallo Kai.
Hab das mit den Regeln nochmal ausprobiert.
Funktioniert aber leider nicht.
Ich möchte einen Timer starten der retriggerbar ist.
Der in der angegebenen Konfiguration erstellte Timer soll die Lampe 10 Sekunden nach dem Einschalten wieder ausschalten.

Das ist mein Minimal-Konfiguration:
demo.items
-----------
Dimmer Light_Office "Büro" (gOffice, Lichter, gLicht) {knx="2/0/0, 2/0/1, <2/0/3+2/0/2"}

demo.sitemap
-------------
sitemap demo label="Main Menu"
{
Frame {
Slider item=Light_Office switchSupport
}
}

demo.rules
----------
import org.openhab.core.library.types.*
import org.openhab.model.script.actions.*

var Timer timer = null

rule "Timer Demo"
when
Item Light_Office received command
then
if(receivedCommand==ON) {
if(timer==null) {
// first ON command, so create a timer to turn the light off again
timer = createTimer(now.plusSeconds(10)) [|
sendCommand(Light_Office, OFF)
]
} else {
// subsequent ON command, so reschedule the existing timer
timer.reschedule(now.plusSeconds(10))
}
} else if(receivedCommand==OFF) {
// remove any previously scheduled timer
if(timer!=null) {
timer.cancel
timer = null
}
}
end


Ich versuch mal, das Problem anhand des u.a. Log zu beschreiben.

Dieser Event wird durch das Einschalten der Lampe im Browser ausgelöst.
22:20:32.960 INFO runtime.busevents[:42] - Light_Office received command ON

Dadurch wird die nachfolgende Regel ausgeführt.
22:20:32.964 DEBUG o.o.m.r.i.engine.RuleEngine[:310] - Executing rule 'Timer Demo'
und anschließen wird das ON Kommando auf den Bus geschrieben.
22:20:33.028 DEBUG o.o.b.k.i.bus.KNXBinding[:177] - Wrote value 'ON' to datapoint 'command DP 2/0/0 Light_Office, DPT main 0 id 1.001, low priority'

Dieses Kommando wird vom Bus jetzt wieder gelesen.
22:20:33.051 INFO runtime.busevents[:42] - Light_Office received command ON
und es wird wieder die Regel ausgeführt. Allerdings ist die Variable timer im Script noch immer null, sodass ein neuer Timer erstellt wird.
Es existieren jetzt 2 Timer mit unterschiedlichen triggerKeys.
22:20:33.052 DEBUG o.o.m.r.i.engine.RuleEngine[:310] - Executing rule 'Timer Demo'

22:20:33.240 INFO runtime.busevents[:46] - Light_Office state updated to 56
22:20:33.275 DEBUG o.o.m.s.a.ScriptExecution[:121] - Scheduled code for execution at 2012-08-16T22:20:43.231+02:00
22:20:33.275 DEBUG o.o.m.s.a.ScriptExecution[:121] - Scheduled code for execution at 2012-08-16T22:20:43.230+02:00
22:20:35.547 INFO runtime.busevents[:46] - Light_Office state updated to 56
Hier soll der Timer retriggert werden.
22:20:40.636 INFO runtime.busevents[:42] - Light_Office received command ON
Die Regel wird erneut ausgeführt, retriggert aber nur einen der zuvor zwei erstellten Timer.
Die Lampe müsste also jetzt in 10 Sekunden ausgehen, d.h. um 22:20:50

22:20:40.638 DEBUG o.o.m.r.i.engine.RuleEngine[:310] - Executing rule 'Timer Demo'
22:20:40.639 DEBUG o.o.b.k.i.bus.KNXBinding[:177] - Wrote value 'ON' to datapoint 'command DP 2/0/0 Light_Office, DPT main 0 id 1.001, low priority'
22:20:40.653 INFO runtime.busevents[:42] - Light_Office received command ON
22:20:40.654 DEBUG o.o.m.r.i.engine.RuleEngine[:310] - Executing rule 'Timer Demo'
22:20:43.154 INFO runtime.busevents[:46] - Light_Office state updated to 56
22:20:43.234 DEBUG o.o.m.s.i.a.TimerExecutionJob[:59] - Executing timer 'DEFAULT.2012-08-16T22:20:43.231+02:00: Proxy for org.eclipse.xtext.xbase.lib.Procedures$Procedure0: org.eclipse.xtext.xbase.impl.XClosureImplCustom@1c b50a7 (explicitSyntax: true)'

Hier löst jetzt der Timer aus, der beim ersten Mal gestartet wurde und dann nicht retriggert werden konnte.
22:20:43.257 INFO runtime.busevents[:42] - Light_Office received command OFF
22:20:43.258 DEBUG o.o.m.r.i.engine.RuleEngine[:310] - Executing rule 'Timer Demo'
22:20:43.259 DEBUG o.o.b.k.i.bus.KNXBinding[:177] - Wrote value 'OFF' to datapoint 'command DP 2/0/0 Light_Office, DPT main 0 id 1.001, low priority'
22:20:43.281 INFO runtime.busevents[:42] - Light_Office received command OFF
22:20:43.292 DEBUG o.o.m.r.i.engine.RuleEngine[:310] - Executing rule 'Timer Demo'
22:20:43.475 INFO runtime.busevents[:46] - Light_Office state updated to 0
22:20:45.536 INFO runtime.busevents[:46] - Light_Office state updated to 0

Ist etwas kompliziert, aber ich hoffe das Problem einigermaßen beschrieben zu haben.

Gruß
erru

[teichsta]

Hi,

die Beschreibung ist schon gut ...

Erste Nachfrage: sind die GAs für den Prozentwert (letzten beiden) in der Reihenfolge wirklich richtig? Die mit '+' markierte GA darf nur die ListeningGA sein, als die Statusrückmeldung.

Gruß,

Thomas E.-E.

P.S.: um noch mehr Infos zu bekommen, kannst Du noch ein paar Logstatements (mit logDebug("demo.rules", "blablabla") einbauen bzw. direkt auf sysout mit println("blablabla").

[teichsta]

und drehe bitte mal das logging des KNXBinding in der logback_debug.xml auf "TRACE" hoch ...

[erru]

Hallo Thomas.
Also erstmal die GAs.

2/0/0: Licht schalten
2/0/1: Licht dimmen
2/0/2: Helligkeitswert Rückmeldung
2/0/3: Helligkeitswert setzen

Müsste gut aussehen.?

Werde gleich die Test mit den TRACE Einstellungen durchführen.

Gruß
erru

[erru]

Hallo,
hier jetzt das Log mit einigen weiteren Informationen.
Die Ausgaben aus dem Skript habe ich eingefärbt.
Ganz unten habe ich auch nocnmal das Skript angehängt.

08:59:36.757 DEBUG o.o.m.r.i.engine.RuleEngine[:310] - Executing rule 'Timer Demo'
08:59:36.821 INFO runtime.busevents[:42] - Light_Office received command ON
08:59:36.935 TRACE o.o.b.k.i.bus.KNXBinding[:234] - Added event (item='Light_Office', type='ON') to the ignore event list
08:59:36.935 TRACE o.o.b.k.i.bus.KNXBinding[:244] - Processed event (item='Light_Office', type='ON', destination='2/0/0')
08:59:36.935 TRACE o.o.b.k.i.bus.KNXBinding[:137] - Received command (item='Light_Office', command='ON')
08:59:36.936 TRACE o.o.b.k.i.bus.KNXBinding[:158] - We received this event (item='Light_Office', state='ON') from KNX, so we don't send it back again -> ignore!
08:59:36.939 DEBUG o.o.m.r.i.engine.RuleEngine[:310] - Executing rule 'Timer Demo'
08:59:36.939 INFO runtime.busevents[:42] - Light_Office received command ON
08:59:36.971 TRACE o.o.b.k.i.bus.KNXBinding[:234] - Added event (item='Light_Office', type='56') to the ignore event list
08:59:36.971 TRACE o.o.b.k.i.bus.KNXBinding[:244] - Processed event (item='Light_Office', type='56', destination='2/0/2')
08:59:36.972 TRACE o.o.b.k.i.bus.KNXBinding[:148] - Received update (item='Light_Office', state='56')
08:59:36.972 TRACE o.o.b.k.i.bus.KNXBinding[:158] - We received this event (item='Light_Office', state='56') from KNX, so we don't send it back again -> ignore!
08:59:36.972 INFO runtime.busevents[:46] - Light_Office state updated to 56
receivedCommand=ON; timer==null; createTimer
receivedCommand=ON; timer==null; createTimer
08:59:37.090 DEBUG o.o.m.s.a.ScriptExecution[:121] - Scheduled code for execution at 2012-08-17T08:59:47.042+02:00
08:59:37.090 DEBUG o.o.m.s.a.ScriptExecution[:121] - Scheduled code for execution at 2012-08-17T08:59:47.043+02:00
08:59:37.677 TRACE o.o.p.d.i.Db4oPersistenceService[:284] - successfully commited db4o transaction in 681ms
08:59:39.280 TRACE o.o.b.k.i.bus.KNXBinding[:234] - Added event (item='Light_Office', type='56') to the ignore event list
08:59:39.280 TRACE o.o.b.k.i.bus.KNXBinding[:244] - Processed event (item='Light_Office', type='56', destination='2/0/2')
08:59:39.280 TRACE o.o.b.k.i.bus.KNXBinding[:148] - Received update (item='Light_Office', state='56')
08:59:39.280 TRACE o.o.b.k.i.bus.KNXBinding[:158] - We received this event (item='Light_Office', state='56') from KNX, so we don't send it back again -> ignore!
08:59:39.281 INFO runtime.busevents[:46] - Light_Office state updated to 56
08:59:40.477 TRACE o.o.i.g.i.p.GCalPresenceSimulation[:197] - going to upload 0 calendar entries to Google now ...
08:59:40.654 TRACE o.o.b.k.i.bus.KNXBinding[:137] - Received command (item='Light_Office', command='ON')
08:59:40.739 DEBUG o.o.b.k.i.bus.KNXBinding[:177] - Wrote value 'ON' to datapoint 'command DP 2/0/0 Light_Office, DPT main 0 id 1.001, low priority'
08:59:40.740 DEBUG o.o.m.r.i.engine.RuleEngine[:310] - Executing rule 'Timer Demo'
08:59:40.740 INFO runtime.busevents[:42] - Light_Office received command ON
receivedCommand=ON; timer!=null; reschedule
08:59:40.779 TRACE o.o.b.k.i.bus.KNXBinding[:234] - Added event (item='Light_Office', type='ON') to the ignore event list
08:59:40.780 TRACE o.o.b.k.i.bus.KNXBinding[:244] - Processed event (item='Light_Office', type='ON', destination='2/0/0')
08:59:40.780 TRACE o.o.b.k.i.bus.KNXBinding[:137] - Received command (item='Light_Office', command='ON')
08:59:40.780 TRACE o.o.b.k.i.bus.KNXBinding[:158] - We received this event (item='Light_Office', state='ON') from KNX, so we don't send it back again -> ignore!
08:59:40.781 DEBUG o.o.m.r.i.engine.RuleEngine[:310] - Executing rule 'Timer Demo'
08:59:40.781 INFO runtime.busevents[:42] - Light_Office received command ON
receivedCommand=ON; timer!=null; reschedule
08:59:42.568 TRACE o.o.p.d.i.Db4oPersistenceService[:284] - successfully commited db4o transaction in 575ms
08:59:43.282 TRACE o.o.b.k.i.bus.KNXBinding[:234] - Added event (item='Light_Office', type='56') to the ignore event list
08:59:43.283 TRACE o.o.b.k.i.bus.KNXBinding[:244] - Processed event (item='Light_Office', type='56', destination='2/0/2')
08:59:43.283 TRACE o.o.b.k.i.bus.KNXBinding[:148] - Received update (item='Light_Office', state='56')
08:59:43.283 TRACE o.o.b.k.i.bus.KNXBinding[:158] - We received this event (item='Light_Office', state='56') from KNX, so we don't send it back again -> ignore!
08:59:43.283 INFO runtime.busevents[:46] - Light_Office state updated to 56
08:59:47.047 DEBUG o.o.m.s.i.a.TimerExecutionJob[:59] - Executing timer 'DEFAULT.2012-08-17T08:59:47.042+02:00: Proxy for org.eclipse.xtext.xbase.lib.Procedures$Procedure0: org.eclipse.xtext.xbase.impl.XClosureImplCustom@14 6961d (explicitSyntax: true)'
08:59:47.094 TRACE o.o.b.k.i.bus.KNXBinding[:137] - Received command (item='Light_Office', command='OFF')
08:59:49.300 DEBUG o.o.m.r.i.engine.RuleEngine[:310] - Executing rule 'Timer Demo'
08:59:49.301 INFO runtime.busevents[:42] - Light_Office received command OFF
receivedCommand=OFF; timer!=null; cancel
08:59:49.369 TRACE o.o.b.k.i.bus.KNXBinding[:234] - Added event (item='Light_Office', type='OFF') to the ignore event list
08:59:49.370 TRACE o.o.b.k.i.bus.KNXBinding[:244] - Processed event (item='Light_Office', type='OFF', destination='2/0/0')
08:59:49.370 TRACE o.o.b.k.i.bus.KNXBinding[:137] - Received command (item='Light_Office', command='OFF')
08:59:49.370 TRACE o.o.b.k.i.bus.KNXBinding[:158] - We received this event (item='Light_Office', state='OFF') from KNX, so we don't send it back again -> ignore!
08:59:49.371 DEBUG o.o.m.r.i.engine.RuleEngine[:310] - Executing rule 'Timer Demo'
08:59:49.371 INFO runtime.busevents[:42] - Light_Office received command OFF
receivedCommand=OFF; timer==null
08:59:49.405 TRACE o.o.b.k.i.bus.KNXBinding[:234] - Added event (item='Light_Office', type='0') to the ignore event list
08:59:49.406 TRACE o.o.b.k.i.bus.KNXBinding[:244] - Processed event (item='Light_Office', type='0', destination='2/0/2')
08:59:49.406 TRACE o.o.b.k.i.bus.KNXBinding[:148] - Received update (item='Light_Office', state='0')
08:59:49.406 TRACE o.o.b.k.i.bus.KNXBinding[:158] - We received this event (item='Light_Office', state='0') from KNX, so we don't send it back again -> ignore!
08:59:49.407 INFO runtime.busevents[:46] - Light_Office state updated to 0


// demo.rules
import org.openhab.core.library.types.*
import org.openhab.model.script.actions.*

var Timer timer = null

rule "Timer Demo"
when
Item Light_Office received command
then
if(receivedCommand==ON) {
if(timer==null) {
println("receivedCommand=ON; timer==null; createTimer");
// first ON command, so create a timer to turn the light off again
timer = createTimer(now.plusSeconds(10)) [|
sendCommand(Light_Office, OFF)
]
} else {
println("receivedCommand=ON; timer!=null; reschedule");
// subsequent ON command, so reschedule the existing timer
timer.reschedule(now.plusSeconds(10))
}
} else if(receivedCommand==OFF) {
// remove any previously scheduled timer
if(timer!=null) {
println("receivedCommand=OFF; timer!=null; cancel");
timer.cancel
timer = null
}
else {
println("receivedCommand=OFF; timer==null");
}
end


Gruß
erru

[teichsta]

Hi erru,

aaaaaaaaahhh jetzt wird's klar!

Das Problem ist folgendes:

Das DimmerItem akzeptiert sowohl OnOff-Commands als auch Percent-Commands. Intern arbeitet es mit Prozentwerten. Wenn ein On geschickt wird, wird das intern nach 100% gewandelt, ein Off analog zu 0%.

In unserem Fall kommt zunächst das OnOff über die 2/0/0 und danach der Prozentwert über die 2/0/2, der dann intern aber auch in ein OnOff gewandelt wird (warum genau das so ist, müßte ich nochmal eruieren), was zum zweiten OnOff und damit zum zweiten Trigger führt.

Jetzt bliebe noch die Frage, warum timer beim zweiten Aufruf noch null ist? Vielleicht weil createTimer() vom ersten Aufruf noch nicht zurück ist? Immerhin wird jede Regel ja in einem eigenen Thread ausgeführt ...

Da muss ich nochmal tiefer einsteigen!

Danke für die Analyse-Daten!

Gruß,

Thomas E.-E.

[erru]

Hallo Thomas.
Ich habe mal zum Test thread.start() durch thread.run() ersetzt.
Dann laufen die Regeln richtig ab.
Man müsste also zuerst prüfen, ob diese Regel bereits läuft und dann erst auf deren Beendigung warten, bevor der neue Thread für dieselbe Regel gestartet wird.
Das Problem taucht natürlich nur auf, wenn die Threads zeitlich ziemlich nah aneinander gestartet werden.
Allerdings weiß ich nicht, ob es auch Regeln gibt, die nicht zurückkehren; also selber eine Schleife innerhalb des Skriptes ausführen.

Mal etwas anderes:
Ich möchte den Heizwert in % abfragen.
Dazu habe ich folgendes item definiert:
String Heizen_Office "Heizen [%s]" <heating> (Temperature, gOffice, gTemperatur) { knx="5.001:<2/0/80"}

Damit das funktioniert, musste ich folgende Änderung in KNXCoreTypeMapper.java vornehmen.

static public Class<? extends Type> toTypeClass(String dptId) {
/*
* DecimalType is by default associated to 9.001, so for 12.001
* or 17.001, we need to do exceptional handling
*/
if ("12.001".equals(dptId)) {
return DecimalType.class;
}
else if ("5.001".equals(dptId)) {
return StringType.class;
}
else if (DPTXlatorScene.DPT_SCENE_NUMBER.getID().equals(dp tId)) {
return DecimalType.class;
} else {
return dptTypeMap.get(dptId);
}
}

Ist das so korrekt und wenn ja, kannst du das dann bitte comitten?

Vielen Dank
Gruß
erru

[kkreuzer]

Warum benutzt Du ein String Item hier?
Es sollte eigentlich ein Number Item sein. Da Dein DPT ein Prozentwert ist, würde sich sogar ein Item anbieten, welches PercentType unterstützt - da käme im Moment nur der Dimmer in Frage... Allerdings mappen wir Prozentwerte auf 5.004, nicht auf 5.001.

Grüße,
Kai

[erru]

Hallo Kai
ich hatte es mit dem Number Item probiert.

*.Items:

Number Heizen_OfficeNr "Heizen" <heating> (Temperature, gOffice, gTemperatur) { knx="5.004:<2/0/80"}

bekomme ich in der Console die Meldung:

17:46:16.773 INFO runtime.busevents[:42] - Heizen_OfficeNr received command 0
17:46:16.773 DEBUG o.o.c.a.i.AutoUpdateBinding[:115] - Received update of a not accepted type (PercentType) for item Heizen_OfficeNr

Gruß
erru

[kkreuzer]

Genau, weil Number Items keine PercentTypes akzeptieren. Kannst Du daher mal ein Dimmer Item probieren? Das entspricht einem Decimal Item mit dem Unterschied, dass es auf Prozentwerte ausgelegt ist. Benutze ich z.B. auch für meine Lautstärkeregelung.

Grüße,
Kai

[erru]

Hallo Kai.
Ja, mit dem Dimmer geht es. Dann muss man allerdings das Prozent Zeichen noch anhängen. Wenn man den 5.001 benutzt liefert calimero die Einheit % gleich mit.

Ok, vielen Dank Kai.

Gruß
erru

[thoweiss]

Ich häng mich mal kurz mit rein...

Gibt es irgendwo eine Liste welche Items verfügbar sind und welche Eigenschaften diese dann haben? Ich habe darüber irgendwie nix gefunden...

[kkreuzer]

Die immer aktuellste Liste dazu (besser als jede Doku ;-)) ist der Sourcecode:

/bundles/ - openhab - empowering the smart home - Google Project Hosting