Since I have installed OH2.2 with knx binding (windows 7, 64bit version), I have binding.knx.internal.bus.KNXBinding sending to the KNX bus commands twice. Events from OH (such as ON commands) as well as data coming from the KNX bus (such as brightness or temperature data value coming from sensors) are always sent back to the KNX bus, once more than needed.
This behavior is rather annoying: if OH is somewhat slower, a quick ON-OFF sequence will end up with ON1 - OFF - ON2, and the light stays ON (unwanted). It also unnecessarily activates triggers in the knx config on receipt of sensor data.
I realise in the meantime that it is a well-known error, notably addressed in this discussion thread (issue 4547),
Here are my log and config files, for the sake of documenting this behavior at length.
Openhab.log, for the ON command:
2017-12-22 13:32:48.978 [TRACE] [.binding.knx.internal.bus.KNXBinding] - Received update (item='Lampe_Cave_Bureau', state='ON')
2017-12-22 13:32:48.981 [TRACE] [g.knx.internal.dpt.KNXCoreTypeMapper] - toTypeClass looking for dptId = 1.001
2017-12-22 13:32:48.982 [TRACE] [.binding.knx.internal.bus.KNXBinding] - found 1 compatible datapoints for item Lampe_Cave_Bureau (org.openhab.core.library.types.OnOffType)
2017-12-22 13:32:48.984 [INFO ] [tuwien.auto.calimero ] - calimero.link.192.168.0.3:3671: send message to 5/3/51, wait for confirmation
2017-12-22 13:32:48.984 [DEBUG] [tuwien.auto.calimero ] - calimero.link.192.168.0.3:3671: cEMI L-Data.req from 15.15.254 to 5/3/51, low priority hop count 6 repeat tpdu 00 81
2017-12-22 13:32:49.010 [DEBUG] [tuwien.auto.calimero ] - KNXnet/IP Tunneling 192.168.0.3:3671: received cEMI L-Data.con with req 212
2017-12-22 13:32:49.010 [DEBUG] [.binding.knx.internal.bus.KNXBinding] - Wrote value 'ON' to datapoint 'command DP 5/3/51 Lampe_Cave_Bureau, DPT main 0 id 1.001, low priority'
2017-12-22 13:32:49.010 [DEBUG] [tuwien.auto.calimero ] - calimero.link.192.168.0.3:3671: confirmation of 5/3/51
2017-12-22 13:32:49.010 [DEBUG] [tuwien.auto.calimero ] - calimero.link.192.168.0.3:3671: send to 5/3/51 succeeded
2017-12-22 13:32:49.010 [DEBUG] [tuwien.auto.calimero ] - process 192.168.0.3:3671: group write to 5/3/51 succeeded
2017-12-22 13:32:49.011 [DEBUG] [tuwien.auto.calimero ] - KNXnet/IP Tunneling 192.168.0.3:3671: sending cEMI frame seq 76, wait for cEMI.con, attempt 1 (channel 44) 06 10 04 20 00 15 04 2c 4c 00 11 00 bc e0 ff fe 2b 33 01 00 81
2017-12-22 13:32:49.060 [DEBUG] [.binding.knx.internal.bus.KNXBinding] - Received groupWrite Event.
2017-12-22 13:32:49.060 [DEBUG] [.binding.knx.internal.bus.KNXBinding] - Received telegram for unknown group address 7/3/51
2017-12-22 13:32:49.061 [DEBUG] [tuwien.auto.calimero ] - calimero.link.192.168.0.3:3671: indication from 1.0.203
2017-12-22 13:32:49.061 [DEBUG] [.binding.knx.internal.bus.KNXBinding] - Wrote value 'ON' to datapoint 'command DP 5/3/51 Lampe_Cave_Bureau, DPT main 0 id 1.001, low priority'
2017-12-22 13:32:49.062 [DEBUG] [tuwien.auto.calimero ] - KNXnet/IP Tunneling 192.168.0.3:3671: received cEMI L-Data.con with req 214
2017-12-22 13:32:49.062 [DEBUG] [tuwien.auto.calimero ] - calimero.link.192.168.0.3:3671: confirmation of 5/3/51
2017-12-22 13:32:49.062 [DEBUG] [tuwien.auto.calimero ] - calimero.link.192.168.0.3:3671: send to 5/3/51 succeeded
2017-12-22 13:32:49.062 [DEBUG] [tuwien.auto.calimero ] - process 192.168.0.3:3671: group write to 5/3/51 succeeded
2017-12-22 13:33:00.457 [DEBUG] [tuwien.auto.calimero ] - KNXnet/IP Tunneling 192.168.0.3:3671: sending connection state request, attempt 1
2017-12-22 13:33:08.659 [DEBUG] [tuwien.auto.calimero ] - calimero.link.192.168.0.3:3671: indication from 1.0.51
2017-12-22 13:33:08.659 [DEBUG] [.binding.knx.internal.bus.KNXBinding] - Received groupWrite Event.
2017-12-22 13:33:08.659 [DEBUG] [.binding.knx.internal.bus.KNXBinding] - Received telegram for unknown group address 1/3/51
2017-12-22 13:34:00.058 [DEBUG] [tuwien.auto.calimero ] - calimero.link.192.168.0.3:3671: indication from 1.0.221
2017-12-22 13:34:00.058 [DEBUG] [.binding.knx.internal.bus.KNXBinding] - Received groupWrite Event.
2017-12-22 13:34:00.059 [TRACE] [g.knx.internal.dpt.KNXCoreTypeMapper] - toType datapoint DPT = 9.001
2017-12-22 13:34:00.059 [TRACE] [g.knx.internal.dpt.KNXCoreTypeMapper] - toTypeClass looking for dptId = 9.001
2017-12-22 13:34:00.059 [TRACE] [.binding.knx.internal.bus.KNXBinding] - Added event (item='Weather_Brightness', type='1105.28') to the ignore event list
ETS bus monitor:
# Time Service Flags Prio Source Address Source Name Destination Address Destination Name Rout Type DPT Info
5 2017-12-22 13:32:49.014 from bus Low 15.15.254 - 5/3/51 lampe bureau 6 Write $01 | On
6 2017-12-22 13:32:49.040 from bus Low 1.0.203 SA/S8.10.1 Switch Actuator,8-fold,10A,MDRC 7/3/51 lampe bureau 6 Write $00 | Off
7 2017-12-22 13:32:49.067 from bus Low 15.15.254 - 5/3/51 lampe bureau 6 Write $01 | On
Openhab.log, for the brightness data:
2017-12-22 13:42:59.044 [DEBUG] [.binding.knx.internal.bus.KNXBinding] - Received groupWrite Event.
2017-12-22 13:42:59.045 [TRACE] [g.knx.internal.dpt.KNXCoreTypeMapper] - toType datapoint DPT = 9.001
2017-12-22 13:42:59.045 [TRACE] [g.knx.internal.dpt.KNXCoreTypeMapper] - toTypeClass looking for dptId = 9.001
2017-12-22 13:42:59.045 [TRACE] [.binding.knx.internal.bus.KNXBinding] - Added event (item='Weather_Brightness', type='1527.04') to the ignore event list
2017-12-22 13:42:59.046 [TRACE] [.binding.knx.internal.bus.KNXBinding] - Processed event (item='Weather_Brightness', type='1527.04', destination='14/5/0')
2017-12-22 13:42:59.057 [TRACE] [.binding.knx.internal.bus.KNXBinding] - Received command (item='Weather_Brightness', command='1527.04')
2017-12-22 13:42:59.058 [TRACE] [.binding.knx.internal.bus.KNXBinding] - We received this event (item='Weather_Brightness', state='1527.04') from KNX, so we don't send it back again -> ignore!
2017-12-22 13:42:59.061 [TRACE] [.binding.knx.internal.bus.KNXBinding] - Received update (item='Weather_Brightness', state='1527.04')
2017-12-22 13:42:59.062 [TRACE] [g.knx.internal.dpt.KNXCoreTypeMapper] - toTypeClass looking for dptId = 9.001
2017-12-22 13:42:59.062 [TRACE] [.binding.knx.internal.bus.KNXBinding] - found 1 compatible datapoints for item Weather_Brightness (org.openhab.core.library.types.DecimalType)
2017-12-22 13:42:59.094 [DEBUG] [.binding.knx.internal.bus.KNXBinding] - Wrote value '1527.04' to datapoint 'command DP 14/5/0 Weather_Brightness, DPT main 0 id 9.001, low priority'
ETS bus monitor:
# Time Service Flags Prio Source Address Source Name Destination Address Destination Name Rout Type DPT Info
45 2017-12-22 13:42:59.044 from bus Low 1.0.221 Dual Sensor AP 254 14/5/0 brightness absolute value 6 Write 3C A9 | 1527,04
46 2017-12-22 13:42:59.104 from bus Low 15.15.254 - 14/5/0 brightness absolute value 6 Write 3C A9 | 1527,04
Configuration:
KNX-IP interface (not router) of GIRA (IP Schnittstelle 2168, PA 1.0.3). Java version “1.8.0_152” (Java™ SE Runtime Environment (build 1.8.0_152-b16), Java HotSpot™ 64-Bit Server VM (build 25.152-b16, mixed mode)).
openhab> config:list "(service.pid=org.openhab.knx)"
Pid: org.openhab.knx
BundleLocation: mvn:org.openhab.binding/org.openhab.binding.knx/1.11.0
Properties:
busaddr = 15.15.254
ignorelocalevents = true
ip = 192.168.0.3
localIp = 192.168.0.12
service.pid = org.openhab.knx
type = TUNNEL
file.items (i was using OH1 heavily, but now i had to reduce my configuration to a very simple form in order to test the system under OH2)
Switch Lampe_Cave_Bureau "Bureau" { knx="5/3/51" } /* { knx="5/3/51+<7/3/51" } */
Number Weather_Brightness "Clarte [%.1f Lux]" <sun_clouds> { knx="<14/5/0" }
sitemap:
sitemap tangissart label="Tangissart"
{
Frame label="Demo" {
Switch item=Lampe_Cave_Bureau icon="big_bulb"
Text item=Weather_Temperature valuecolor=[>25="orange",>15="green",<=15="blue"]
}
Frame label="Weather" {
Text item=Weather_Temperature
Text item=Weather_Brightness
}
}
I started describing the experience with OH2 for different configurations in the following Topic. It summarises my findings so far with OH2/KNX add-on.
Yves