[KNX] Value could not be sent using datapoint

binderth · January 15, 2018, 4:07pm

I’m experiencing strange KNX-WARNings out of the blue. I didn’t change anything (items or knx.cfg) - Yesterday the KNX binding worked fine without having those strange WARNings, beginning with an reconnect at 6:11 (no incidents beforehand - and I was just in the bathroom at that time! )

2018-01-15 06:11:27.563 [WARN ] [nx.internal.connection.KNXConnection] - KNX link has been lost (reason: server request on object tunneling link link (closed) 192.168.xx.6:3671 TP1 medium, device 0.0.0, hopcount 6)
2018-01-15 06:11:27.568 [INFO ] [nx.internal.connection.KNXConnection] - KNX link will be retried in 10 seconds
2018-01-15 06:11:27.594 [WARN ] [nx.internal.connection.KNXConnection] - KNX link has been lost (reason: server request on object tunneling link link (closed) 192.168.xx.6:3671 TP1 medium, device 0.0.0, hopcount 6)
2018-01-15 06:11:27.599 [INFO ] [nx.internal.connection.KNXConnection] - KNX link will be retried in 10 seconds
2018-01-15 06:11:27.686 [ERROR] [.binding.knx.internal.bus.KNXBinding] - Received detach Event.
2018-01-15 06:11:37.579 [INFO ] [nx.internal.connection.KNXConnection] - Trying to (re-)connect to KNX...
2018-01-15 06:11:37.608 [INFO ] [nx.internal.connection.KNXConnection] - Established connection to KNX bus on 192.168.178.6:3671 in mode TUNNEL.
2018-01-15 06:11:37.631 [INFO ] [nx.internal.connection.KNXConnection] - Connected to KNX
2018-01-15 06:11:37.685 [INFO ] [nx.internal.connection.KNXConnection] - Trying to (re-)connect to KNX...
2018-01-15 06:11:37.729 [INFO ] [nx.internal.connection.KNXConnection] - Established connection to KNX bus on 192.168.178.6:3671 in mode TUNNEL.
2018-01-15 06:11:37.739 [INFO ] [nx.internal.connection.KNXConnection] - Connected to KNX
2018-01-15 06:11:40.651 [WARN ] [al.bus.KNXBindingDatapointReaderTask] - Autorefresh: Cannot read value for item 'RTR_OG_KiZiWest_setTemp' from KNX bus: no confirmation reply received for L-Data.req from 0.0.255 to 8/2/33, low priority hop count 6 repeat tpdu 00 00: timeout
2018-01-15 06:11:40.649 [WARN ] [tuwien.auto.calimero                ] - KNXnet/IP Tunneling 192.168.xxx.6:3671: response timeout waiting for confirmation
tuwien.auto.calimero.exception.KNXTimeoutException: no confirmation reply received for L-Data.req from 0.0.255 to 8/2/33, low priority hop count 6 repeat tpdu 00 00
	at tuwien.auto.calimero.knxnetip.ClientConnection.doExtraBlockingModes(ClientConnection.java:236) [218:org.openhab.binding.knx:1.11.0]
	at tuwien.auto.calimero.knxnetip.ConnectionBase.send(ConnectionBase.java:269) [218:org.openhab.binding.knx:1.11.0]
	at tuwien.auto.calimero.knxnetip.KNXnetIPTunnel.send(KNXnetIPTunnel.java:149) [218:org.openhab.binding.knx:1.11.0]
	at tuwien.auto.calimero.link.KNXNetworkLinkIP.onSend(KNXNetworkLinkIP.java:263) [218:org.openhab.binding.knx:1.11.0]
	at tuwien.auto.calimero.link.AbstractLink.send(AbstractLink.java:304) [218:org.openhab.binding.knx:1.11.0]
	at tuwien.auto.calimero.link.KNXNetworkLinkIP.sendRequestWait(KNXNetworkLinkIP.java:240) [218:org.openhab.binding.knx:1.11.0]
	at tuwien.auto.calimero.process.ProcessCommunicatorImpl.readFromGroup(ProcessCommunicatorImpl.java:486) [218:org.openhab.binding.knx:1.11.0]
	at tuwien.auto.calimero.process.ProcessCommunicatorImpl.read(ProcessCommunicatorImpl.java:422) [218:org.openhab.binding.knx:1.11.0]
	at org.openhab.binding.knx.internal.bus.KNXBindingDatapointReaderTask.readFromKNXBus(KNXBindingDatapointReaderTask.java:99) [218:org.openhab.binding.knx:1.11.0]
	at org.openhab.binding.knx.internal.bus.KNXBindingDatapointReaderTask.run(KNXBindingDatapointReaderTask.java:67) [218:org.openhab.binding.knx:1.11.0]
2018-01-15 06:11:40.685 [WARN ] [al.bus.KNXBindingDatapointReaderTask] - Autorefresh: Remaining retries for address '8/2/33' = '2'
2018-01-15 06:11:40.964 [ERROR] [nternal.connection.OneWireConnection] - Writing -3.7800000000000002 to path 26.E1CD92010000/temperature attempt 1 threw an exception
org.owfs.jowfsclient.OwfsException: Error -95
	at org.owfs.jowfsclient.internal.OwfsConnectionImpl.readPacket(OwfsConnectionImpl.java:264) [231:org.openhab.binding.onewire:1.11.0]
	at org.owfs.jowfsclient.internal.OwfsConnectionImpl.write(OwfsConnectionImpl.java:150) [231:org.openhab.binding.onewire:1.11.0]
	at org.openhab.binding.onewire.internal.connection.OneWireConnection.writeToOneWire(OneWireConnection.java:348) [231:org.openhab.binding.onewire:1.11.0]
	at org.openhab.binding.onewire.internal.OneWireBinding.internalReceiveCommand(OneWireBinding.java:134) [231:org.openhab.binding.onewire:1.11.0]
	at org.openhab.core.binding.AbstractBinding.receiveCommand(AbstractBinding.java:94) [200:org.openhab.core.compat1x:2.2.0]
	at org.openhab.core.events.AbstractEventSubscriber.handleEvent(AbstractEventSubscriber.java:45) [200:org.openhab.core.compat1x:2.2.0]
	at org.apache.felix.eventadmin.impl.handler.EventHandlerProxy.sendEvent(EventHandlerProxy.java:415) [3:org.apache.karaf.services.eventadmin:4.1.3]
	at org.apache.felix.eventadmin.impl.tasks.HandlerTask.runWithoutBlacklistTiming(HandlerTask.java:82) [3:org.apache.karaf.services.eventadmin:4.1.3]
	at org.apache.felix.eventadmin.impl.tasks.SyncDeliverTasks.execute(SyncDeliverTasks.java:104) [3:org.apache.karaf.services.eventadmin:4.1.3]
	at org.apache.felix.eventadmin.impl.tasks.AsyncDeliverTasks$TaskExecuter.run(AsyncDeliverTasks.java:166) [3:org.apache.karaf.services.eventadmin:4.1.3]
	at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:511) [?:?]
	at java.util.concurrent.FutureTask.run(FutureTask.java:266) [?:?]
	at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149) [?:?]
	at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624) [?:?]
	at java.lang.Thread.run(Thread.java:748) [?:?]
2018-01-15 06:11:40.977 [INFO ] [nternal.connection.OneWireConnection] - Trying to reconnect to owserver...
2018-01-15 06:11:41.197 [INFO ] [nternal.connection.OneWireConnection] - Connected to owserver [IP '127.0.0.1' Port '4304']
2018-01-15 06:11:41.313 [ERROR] [nternal.connection.OneWireConnection] - Writing -3.7800000000000002 to path 26.E1CD92010000/temperature attempt 2 threw an exception
org.owfs.jowfsclient.OwfsException: Error -95
	at org.owfs.jowfsclient.internal.OwfsConnectionImpl.readPacket(OwfsConnectionImpl.java:264) [231:org.openhab.binding.onewire:1.11.0]
	at org.owfs.jowfsclient.internal.OwfsConnectionImpl.write(OwfsConnectionImpl.java:150) [231:org.openhab.binding.onewire:1.11.0]
	at org.openhab.binding.onewire.internal.connection.OneWireConnection.writeToOneWire(OneWireConnection.java:348) [231:org.openhab.binding.onewire:1.11.0]
	at org.openhab.binding.onewire.internal.OneWireBinding.internalReceiveCommand(OneWireBinding.java:134) [231:org.openhab.binding.onewire:1.11.0]
	at org.openhab.core.binding.AbstractBinding.receiveCommand(AbstractBinding.java:94) [200:org.openhab.core.compat1x:2.2.0]
	at org.openhab.core.events.AbstractEventSubscriber.handleEvent(AbstractEventSubscriber.java:45) [200:org.openhab.core.compat1x:2.2.0]
	at org.apache.felix.eventadmin.impl.handler.EventHandlerProxy.sendEvent(EventHandlerProxy.java:415) [3:org.apache.karaf.services.eventadmin:4.1.3]
	at org.apache.felix.eventadmin.impl.tasks.HandlerTask.runWithoutBlacklistTiming(HandlerTask.java:82) [3:org.apache.karaf.services.eventadmin:4.1.3]
	at org.apache.felix.eventadmin.impl.tasks.SyncDeliverTasks.execute(SyncDeliverTasks.java:104) [3:org.apache.karaf.services.eventadmin:4.1.3]
	at org.apache.felix.eventadmin.impl.tasks.AsyncDeliverTasks$TaskExecuter.run(AsyncDeliverTasks.java:166) [3:org.apache.karaf.services.eventadmin:4.1.3]
	at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:511) [?:?]
	at java.util.concurrent.FutureTask.run(FutureTask.java:266) [?:?]
	at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149) [?:?]
	at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624) [?:?]
	at java.lang.Thread.run(Thread.java:748) [?:?]

hint: one item gets updated via onewire - and sends it’s content to KNX, I don’t know, why openHAB wanted to write to the onewire?

then it goes on and on:

2018-01-15 14:39:04.302 [WARN ] [.binding.knx.internal.bus.KNXBinding] - Value '4.5' could not be sent to the KNX bus using datapoint 'command DP 0/3/1 Sensoren_OktTemp_OutN, DPT main 0 id 9.001, low priority' - retrying one time: no confirmation reply received for L-Data.req from 0.0.255 to 0/3/1, low priority hop count 6 repeat tpdu 00 80 01 c2

the item in this WARNing is (gets updated via MQTT-eventbus):

Number Sensoren_OktTemp_OutN	"Temperatur Nord [%.1f °C]" 	(gOktopusTemp, UG_Oktopus)	{ expire="5m", knx="9.001:0/3/1" }

binderth · January 15, 2018, 4:56pm

OK - false Alarm. at least Kind of.

What did I do: I played around a bit with “knx.cfg” yesterday (bundle:restarted the KNX binding afterwards) and at one time I accidentially typed in the wrong GA. After reverting it (and restarting) I thought, everything was good. Yeah - until today at 6:11 the KNX detached and reconnected - using somehow the old configuration. I just saw in /var/lib/openhab2/config/org/openhab/knx.config the old GA-value.

stopped openhab
deleted config (and Cache am tmp while at it)
restarted openhab

now it works again. - Except having my wife coming home from running finding herself in the cold without the use of our fingerprint sensor. Had to open the door via VPN for her. there goes the WAF.