KNX connection error in log although everything works fine

Dominik_Bernhardt · July 16, 2016, 8:19pm

I have upgraded my openhab installation a few weeks ago to openhab2 and at the same time moved from a QNAP NAS to a raspberry3. Since this upgrade the KNX binding shows the attached error messages reproducible after running for some hours. Although the error indicate it could not connect to the KNX bus everything works fine.
Once the error message is shown it will be repeated every few seconds.

I use a Weinzierl KNX IP Interface 730.

Any Ideas?

2016-07-16 19:42:06.607 [ERROR] [nx.internal.connection.KNXConnection] - Error connecting to KNX bus: error response from control endpoint /192.168.178.39:3671, could not accept new connection (maximum reached)
2016-07-16 19:42:06.716 [ERROR] [tuwien.auto.calimero ] - [Timer-148] KNXnet/IP Tunneling 192.168.178.39:3671: establishing connection failed
tuwien.auto.calimero.exception.KNXRemoteException: error response from control endpoint /192.168.178.39:3671, could not accept new connection (maximum reached)
at tuwien.auto.calimero.knxnetip.ClientConnection.connect(ClientConnection.java:174)[188:org.openhab.binding.knx:1.9.0.201607040111]
at tuwien.auto.calimero.knxnetip.KNXnetIPTunnel.(KNXnetIPTunnel.java:117)[188:org.openhab.binding.knx:1.9.0.201607040111]
at tuwien.auto.calimero.link.KNXNetworkLinkIP.(KNXNetworkLinkIP.java:180)[188:org.openhab.binding.knx:1.9.0.201607040111]
at org.openhab.binding.knx.internal.connection.KNXConnection.connectByIp(KNXConnection.java:292)[188:org.openhab.binding.knx:1.9.0.201607040111]
at org.openhab.binding.knx.internal.connection.KNXConnection.connect(KNXConnection.java:179)[188:org.openhab.binding.knx:1.9.0.201607040111]
at org.openhab.binding.knx.internal.connection.KNXConnection$ConnectTimerTask.run(KNXConnection.java:520)[188:org.openhab.binding.knx:1.9.0.201607040111]
at java.util.TimerThread.mainLoop(Timer.java:555)[:1.8.0_65]
at java.util.TimerThread.run(Timer.java:505)[:1.8.0_65]
2016-07-16 19:42:06.716 [INFO ] [nx.internal.connection.KNXConnection] - KNX link will be retried in 30 seconds
2016-07-16 19:42:08.176 [INFO ] [nx.internal.connection.KNXConnection] - Trying to (re-)connect to KNX…
2016-07-16 19:42:08.183 [ERROR] [tuwien.auto.calimero ] - [KNXnet/IP receiver] KNXnet/IP Tunneling 192.168.178.39:3671: could not accept new connection (maximum reached)
2016-07-16 19:42:08.183 [ERROR] [nx.internal.connection.KNXConnection] - Error connecting to KNX bus: error response from control endpoint /192.168.178.39:3671, could not accept new connection (maximum reached)
2016-07-16 19:42:08.185 [ERROR] [tuwien.auto.calimero ] - [Timer-152] KNXnet/IP Tunneling 192.168.178.39:3671: establishing connection failed
tuwien.auto.calimero.exception.KNXRemoteException: error response from control endpoint /192.168.178.39:3671, could not accept new connection (maximum reached)
at tuwien.auto.calimero.knxnetip.ClientConnection.connect(ClientConnection.java:174)[188:org.openhab.binding.knx:1.9.0.201607040111]
at tuwien.auto.calimero.knxnetip.KNXnetIPTunnel.(KNXnetIPTunnel.java:117)[188:org.openhab.binding.knx:1.9.0.201607040111]
at tuwien.auto.calimero.link.KNXNetworkLinkIP.(KNXNetworkLinkIP.java:180)[188:org.openhab.binding.knx:1.9.0.201607040111]
at org.openhab.binding.knx.internal.connection.KNXConnection.connectByIp(KNXConnection.java:292)[188:org.openhab.binding.knx:1.9.0.201607040111]
at org.openhab.binding.knx.internal.connection.KNXConnection.connect(KNXConnection.java:179)[188:org.openhab.binding.knx:1.9.0.201607040111]
at org.openhab.binding.knx.internal.connection.KNXConnection$ConnectTimerTask.run(KNXConnection.java:520)[188:org.openhab.binding.knx:1.9.0.201607040111]
at java.util.TimerThread.mainLoop(Timer.java:555)[:1.8.0_65]
at java.util.TimerThread.run(Timer.java:505)[:1.8.0_65]

Dominik_Bernhardt · July 16, 2016, 8:29pm

additionally I find from time to time log lines like the ones below

2016-07-16 22:13:03.551 [WARN ] [tuwien.auto.calimero ] - [KNXnet/IP receiver] KNXnet/IP Tunneling 192.168.178.39:3671: skipped tunneling request with rcv-seq 216

Dominik_Bernhardt · July 20, 2016, 7:41pm

I just observed it again. Below are the last lines before it happens. Simply resetting my raspberry every night seems to be a workaround. However not really desirable

2016-07-20 16:26:51.702 [WARN ] [tuwien.auto.calimero ] - [KNXnet/IP receiver] KNXnet/IP Tunneling 192.168.178.39:3671: skipped tunneling request with rcv-seq 37
2016-07-20 16:46:33.659 [WARN ] [tuwien.auto.calimero ] - [KNXnet/IP receiver] KNXnet/IP Tunneling 192.168.178.39:3671: skipped tunneling request with rcv-seq 71
2016-07-20 17:05:25.912 [WARN ] [tuwien.auto.calimero ] - [KNXnet/IP receiver] KNXnet/IP Tunneling 192.168.178.39:3671: skipped tunneling request with rcv-seq 40
2016-07-20 17:05:25.914 [WARN ] [tuwien.auto.calimero ] - [KNXnet/IP receiver] KNXnet/IP Tunneling 192.168.178.39:3671: skipped tunneling request with rcv-seq 60
2016-07-20 17:09:18.231 [WARN ] [nx.internal.connection.KNXConnection] - KNX link has been lost (reason: server request on object link 192.168.178.39:3671 tunneling mode (closed), TP1 hopcount 6)
2016-07-20 17:09:18.233 [WARN ] [nx.internal.connection.KNXConnection] - KNX link has been lost (reason: server request on object link 192.168.178.39:3671 tunneling mode (closed), TP1 hopcount 6)
2016-07-20 17:09:18.233 [INFO ] [nx.internal.connection.KNXConnection] - KNX link will be retried in 30 seconds
2016-07-20 17:09:18.234 [INFO ] [nx.internal.connection.KNXConnection] - KNX link will be retried in 30 seconds
2016-07-20 17:09:18.235 [WARN ] [nx.internal.connection.KNXConnection] - KNX link has been lost (reason: server request on object link 192.168.178.39:3671 tunneling mode (closed), TP1 hopcount 6)
2016-07-20 17:09:18.236 [WARN ] [nx.internal.connection.KNXConnection] - KNX link has been lost (reason: server request on object link 192.168.178.39:3671 tunneling mode (closed), TP1 hopcount 6)
2016-07-20 17:09:18.237 [INFO ] [nx.internal.connection.KNXConnection] - KNX link will be retried in 30 seconds
2016-07-20 17:09:18.235 [WARN ] [nx.internal.connection.KNXConnection] - KNX link has been lost (reason: server request on object link 192.168.178.39:3671 tunneling mode (closed), TP1 hopcount 6)
2016-07-20 17:09:18.257 [WARN ] [.binding.knx.internal.bus.KNXBinding] - Value ‘2.46’ could not be sent to the KNX bus using datapoint ‘command DP 2/1/10 S_Wind, DPT main 0 id 9.001, low priority’ - retrying one time: link closed, connection closed
2016-07-20 17:09:18.247 [INFO ] [nx.internal.connection.KNXConnection] - KNX link will be retried in 30 seconds
2016-07-20 17:09:18.243 [WARN ] [tuwien.auto.calimero ] - [KNXnet/IP receiver] KNXnet/IP Tunneling 192.168.178.39:3671: skipped tunneling request with rcv-seq 201
2016-07-20 17:09:18.258 [INFO ] [nx.internal.connection.KNXConnection] - KNX link will be retried in 30 seconds
2016-07-20 17:09:18.268 [WARN ] [tuwien.auto.calimero ] - [KNXnet/IP receiver] KNXnet/IP Tunneling 192.168.178.39:3671: skipped tunneling request with rcv-seq 201
2016-07-20 17:09:18.269 [WARN ] [tuwien.auto.calimero ] - [KNXnet/IP receiver] KNXnet/IP Tunneling 192.168.178.39:3671: skipped tunneling request with rcv-seq 201
2016-07-20 17:09:18.272 [WARN ] [tuwien.auto.calimero ] - [KNXnet/IP receiver] KNXnet/IP Tunneling 192.168.178.39:3671: skipped tunneling request with rcv-seq 201
2016-07-20 17:09:18.273 [WARN ] [tuwien.auto.calimero ] - [KNXnet/IP receiver] KNXnet/IP Tunneling 192.168.178.39:3671: skipped tunneling request with rcv-seq 220
2016-07-20 17:09:18.275 [ERROR] [tuwien.auto.calimero ] - [Thread-35] KNXnet/IP Tunneling 192.168.178.39:3671: send disconnect failed
java.net.SocketException: Socket is closed
at java.net.DatagramSocket.send(DatagramSocket.java:658)[:1.8.0_65]
at tuwien.auto.calimero.knxnetip.ConnectionBase.close(ConnectionBase.java:448)[188:org.openhab.binding.knx:1.9.0.201607040111]
at tuwien.auto.calimero.knxnetip.ConnectionBase.send(ConnectionBase.java:257)[188:org.openhab.binding.knx:1.9.0.201607040111]
at tuwien.auto.calimero.knxnetip.KNXnetIPTunnel.send(KNXnetIPTunnel.java:135)[188:org.openhab.binding.knx:1.9.0.201607040111]
at tuwien.auto.calimero.link.KNXNetworkLinkIP.doSend(KNXNetworkLinkIP.java:457)[188:org.openhab.binding.knx:1.9.0.201607040111]
at tuwien.auto.calimero.link.KNXNetworkLinkIP.send(KNXNetworkLinkIP.java:419)[188:org.openhab.binding.knx:1.9.0.201607040111]
at tuwien.auto.calimero.link.KNXNetworkLinkIP.sendRequestWait(KNXNetworkLinkIP.java:341)[188:org.openhab.binding.knx:1.9.0.201607040111]
at tuwien.auto.calimero.process.ProcessCommunicatorImpl.write(ProcessCommunicatorImpl.java:438)[188:org.openhab.binding.knx:1.9.0.201607040111]
at tuwien.auto.calimero.process.ProcessCommunicatorImpl.write(ProcessCommunicatorImpl.java:410)[188:org.openhab.binding.knx:1.9.0.201607040111]
at org.openhab.binding.knx.internal.bus.KNXBinding.writeToKNX(KNXBinding.java:143)[188:org.openhab.binding.knx:1.9.0.201607040111]
at org.openhab.binding.knx.internal.bus.KNXBinding.internalReceiveCommand(KNXBinding.java:106)[188:org.openhab.binding.knx:1.9.0.201607040111]
at org.openhab.core.binding.AbstractBinding.receiveCommand(AbstractBinding.java:97)[189:org.openhab.core.compat1x:2.0.0.201606271614]
at org.openhab.core.events.AbstractEventSubscriber.handleEvent(AbstractEventSubscriber.java:42)[189:org.openhab.core.compat1x:2.0.0.201606271614]
at org.apache.felix.eventadmin.impl.handler.EventHandlerProxy.sendEvent(EventHandlerProxy.java:415)[3:org.apache.karaf.services.eventadmin:4.0.4]
at org.apache.felix.eventadmin.impl.tasks.HandlerTask.run(HandlerTask.java:90)[3:org.apache.karaf.services.eventadmin:4.0.4]
at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:511)[:1.8.0_65]
at java.util.concurrent.FutureTask.run(FutureTask.java:266)[:1.8.0_65]
at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1142)[:1.8.0_65]
at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:617)[:1.8.0_65]
at java.lang.Thread.run(Thread.java:745)[:1.8.0_65]
2016-07-20 17:09:18.314 [INFO ] [nx.internal.connection.KNXConnection] - Established connection to KNX bus on 192.168.178.39:3671 in mode TUNNEL.
2016-07-20 17:09:18.315 [ERROR] [tuwien.auto.calimero ] - [Thread-35] link 192.168.178.39:3671: send error, closing link
tuwien.auto.calimero.knxnetip.KNXConnectionClosedException: connection closed
at tuwien.auto.calimero.knxnetip.ConnectionBase.send(ConnectionBase.java:258)[188:org.openhab.binding.knx:1.9.0.201607040111]
at tuwien.auto.calimero.knxnetip.KNXnetIPTunnel.send(KNXnetIPTunnel.java:135)[188:org.openhab.binding.knx:1.9.0.201607040111]
at tuwien.auto.calimero.link.KNXNetworkLinkIP.doSend(KNXNetworkLinkIP.java:457)[188:org.openhab.binding.knx:1.9.0.201607040111]
at tuwien.auto.calimero.link.KNXNetworkLinkIP.send(KNXNetworkLinkIP.java:419)[188:org.openhab.binding.knx:1.9.0.201607040111]
at tuwien.auto.calimero.link.KNXNetworkLinkIP.sendRequestWait(KNXNetworkLinkIP.java:341)[188:org.openhab.binding.knx:1.9.0.201607040111]
at tuwien.auto.calimero.process.ProcessCommunicatorImpl.write(ProcessCommunicatorImpl.java:438)[188:org.openhab.binding.knx:1.9.0.201607040111]
at tuwien.auto.calimero.process.ProcessCommunicatorImpl.write(ProcessCommunicatorImpl.java:410)[188:org.openhab.binding.knx:1.9.0.201607040111]
at org.openhab.binding.knx.internal.bus.KNXBinding.writeToKNX(KNXBinding.java:143)[188:org.openhab.binding.knx:1.9.0.201607040111]
at org.openhab.binding.knx.internal.bus.KNXBinding.internalReceiveCommand(KNXBinding.java:106)[188:org.openhab.binding.knx:1.9.0.201607040111]
at org.openhab.core.binding.AbstractBinding.receiveCommand(AbstractBinding.java:97)[189:org.openhab.core.compat1x:2.0.0.201606271614]
at org.openhab.core.events.AbstractEventSubscriber.handleEvent(AbstractEventSubscriber.java:42)[189:org.openhab.core.compat1x:2.0.0.201606271614]
at org.apache.felix.eventadmin.impl.handler.EventHandlerProxy.sendEvent(EventHandlerProxy.java:415)[3:org.apache.karaf.services.eventadmin:4.0.4]
at org.apache.felix.eventadmin.impl.tasks.HandlerTask.run(HandlerTask.java:90)[3:org.apache.karaf.services.eventadmin:4.0.4]
at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:511)[:1.8.0_65]
at java.util.concurrent.FutureTask.run(FutureTask.java:266)[:1.8.0_65]
at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1142)[:1.8.0_65]
at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:617)[:1.8.0_65]
at java.lang.Thread.run(Thread.java:745)[:1.8.0_65]
2016-07-20 17:09:48.238 [INFO ] [nx.internal.connection.KNXConnection] - Trying to (re-)connect to KNX…
2016-07-20 17:09:48.251 [INFO ] [nx.internal.connection.KNXConnection] - Trying to (re-)connect to KNX…
2016-07-20 17:09:48.263 [INFO ] [nx.internal.connection.KNXConnection] - Trying to (re-)connect to KNX…
2016-07-20 17:09:48.264 [INFO ] [nx.internal.connection.KNXConnection] - Established connection to KNX bus on 192.168.178.39:3671 in mode TUNNEL.
2016-07-20 17:09:48.266 [INFO ] [nx.internal.connection.KNXConnection] - Connected to KNX
2016-07-20 17:09:48.273 [INFO ] [nx.internal.connection.KNXConnection] - Trying to (re-)connect to KNX…
2016-07-20 17:09:48.273 [INFO ] [nx.internal.connection.KNXConnection] - Trying to (re-)connect to KNX…
2016-07-20 17:09:48.290 [INFO ] [nx.internal.connection.KNXConnection] - Established connection to KNX bus on 192.168.178.39:3671 in mode TUNNEL.
2016-07-20 17:09:48.292 [INFO ] [nx.internal.connection.KNXConnection] - Connected to KNX
2016-07-20 17:09:48.308 [INFO ] [nx.internal.connection.KNXConnection] - Established connection to KNX bus on 192.168.178.39:3671 in mode TUNNEL.
2016-07-20 17:09:48.310 [INFO ] [nx.internal.connection.KNXConnection] - Connected to KNX
2016-07-20 17:09:48.329 [INFO ] [nx.internal.connection.KNXConnection] - Established connection to KNX bus on 192.168.178.39:3671 in mode TUNNEL.
2016-07-20 17:09:48.331 [INFO ] [nx.internal.connection.KNXConnection] - Connected to KNX
2016-07-20 17:09:48.339 [ERROR] [tuwien.auto.calimero ] - [KNXnet/IP receiver] KNXnet/IP Tunneling 192.168.178.39:3671: could not accept new connection (maximum reached)
2016-07-20 17:09:48.342 [ERROR] [tuwien.auto.calimero ] - [Timer-376] KNXnet/IP Tunneling 192.168.178.39:3671: establishing connection failed
tuwien.auto.calimero.exception.KNXRemoteException: error response from control endpoint /192.168.178.39:3671, could not accept new connection (maximum reached)
at tuwien.auto.calimero.knxnetip.ClientConnection.connect(ClientConnection.java:174)[188:org.openhab.binding.knx:1.9.0.201607040111]
at tuwien.auto.calimero.knxnetip.KNXnetIPTunnel.(KNXnetIPTunnel.java:117)[188:org.openhab.binding.knx:1.9.0.201607040111]
at tuwien.auto.calimero.link.KNXNetworkLinkIP.(KNXNetworkLinkIP.java:180)[188:org.openhab.binding.knx:1.9.0.201607040111]
at org.openhab.binding.knx.internal.connection.KNXConnection.connectByIp(KNXConnection.java:292)[188:org.openhab.binding.knx:1.9.0.201607040111]
at org.openhab.binding.knx.internal.connection.KNXConnection.connect(KNXConnection.java:179)[188:org.openhab.binding.knx:1.9.0.201607040111]
at org.openhab.binding.knx.internal.connection.KNXConnection$ConnectTimerTask.run(KNXConnection.java:520)[188:org.openhab.binding.knx:1.9.0.201607040111]
at java.util.TimerThread.mainLoop(Timer.java:555)[:1.8.0_65]
at java.util.TimerThread.run(Timer.java:505)[:1.8.0_65]
2016-07-20 17:09:48.342 [ERROR] [nx.internal.connection.KNXConnection] - Error connecting to KNX bus: error response from control endpoint /192.168.178.39:3671, could not accept new connection (maximum reached)
2016-07-20 17:09:48.352 [INFO ] [nx.internal.connection.KNXConnection] - KNX link will be retried in 30 seconds
2016-07-20 17:09:51.278 [WARN ] [al.bus.KNXBindingDatapointReaderTask] - Autorefresh: Cannot read value for item ‘L_Kueche’ from KNX bus: no confirmation reply received: timeout
2016-07-20 17:09:51.280 [WARN ] [al.bus.KNXBindingDatapointReaderTask] - Autorefresh: Give up, could not read address ‘0/0/13’ after ‘3’ retries.
2016-07-20 17:10:18.270 [INFO ] [nx.internal.connection.KNXConnection] - Trying to (re-)connect to KNX…
2016-07-20 17:10:18.282 [ERROR] [tuwien.auto.calimero ] - [KNXnet/IP receiver] KNXnet/IP Tunneling 192.168.178.39:3671: could not accept new connection (maximum reached)
2016-07-20 17:10:18.282 [ERROR] [nx.internal.connection.KNXConnection] - Error connecting to KNX bus: error response from control endpoint /192.168.178.39:3671, could not accept new connection (maximum reached)
2016-07-20 17:10:18.283 [ERROR] [tuwien.auto.calimero ] - [Timer-376] KNXnet/IP Tunneling 192.168.178.39:3671: establishing connection failed
tuwien.auto.calimero.exception.KNXRemoteException: error response from control endpoint /192.168.178.39:3671, could not accept new connection (maximum reached)
at tuwien.auto.calimero.knxnetip.ClientConnection.connect(ClientConnection.java:174)[188:org.openhab.binding.knx:1.9.0.201607040111]
at tuwien.auto.calimero.knxnetip.KNXnetIPTunnel.(KNXnetIPTunnel.java:117)[188:org.openhab.binding.knx:1.9.0.201607040111]
at tuwien.auto.calimero.link.KNXNetworkLinkIP.(KNXNetworkLinkIP.java:180)[188:org.openhab.binding.knx:1.9.0.201607040111]
at org.openhab.binding.knx.internal.connection.KNXConnection.connectByIp(KNXConnection.java:292)[188:org.openhab.binding.knx:1.9.0.201607040111]
at org.openhab.binding.knx.internal.connection.KNXConnection.connect(KNXConnection.java:179)[188:org.openhab.binding.knx:1.9.0.201607040111]
at org.openhab.binding.knx.internal.connection.KNXConnection$ConnectTimerTask.run(KNXConnection.java:520)[188:org.openhab.binding.knx:1.9.0.201607040111]
at java.util.TimerThread.mainLoop(Timer.java:555)[:1.8.0_65]
at java.util.TimerThread.run(Timer.java:505)[:1.8.0_65]
2016-07-20 17:10:18.283 [INFO ] [nx.internal.connection.KNXConnection] - KNX link will be retried in 30 seconds
2016-07-20 17:10:34.000 [WARN ] [tuwien.auto.calimero ] - [KNXnet/IP receiver] KNXnet/IP Tunneling 192.168.178.39:3671: skipped tunneling request with rcv-seq 42
2016-07-20 17:10:34.001 [WARN ] [nx.internal.connection.KNXConnection] - KNX link has been lost (reason: server request on object link 192.168.178.39:3671 tunneling mode (closed), TP1 hopcount 6)
2016-07-20 17:10:34.002 [WARN ] [tuwien.auto.calimero ] - [KNXnet/IP receiver] KNXnet/IP Tunneling 192.168.178.39:3671: skipped tunneling request with rcv-seq 42
2016-07-20 17:10:34.002 [INFO ] [nx.internal.connection.KNXConnection] - KNX link will be retried in 30 seconds
2016-07-20 17:10:34.005 [WARN ] [nx.internal.connection.KNXConnection] - KNX link has been lost (reason: server request on object link 192.168.178.39:3671 tunneling mode (closed), TP1 hopcount 6)
2016-07-20 17:10:34.006 [WARN ] [nx.internal.connection.KNXConnection] - KNX link has been lost (reason: server request on object link 192.168.178.39:3671 tunneling mode (closed), TP1 hopcount 6)
2016-07-20 17:10:34.007 [INFO ] [nx.internal.connection.KNXConnection] - KNX link will be retried in 30 seconds
2016-07-20 17:10:34.008 [INFO ] [nx.internal.connection.KNXConnection] - KNX link will be retried in 30 seconds
2016-07-20 17:10:34.003 [WARN ] [tuwien.auto.calimero ] - [KNXnet/IP receiver] KNXnet/IP Tunneling 192.168.178.39:3671: skipped tunneling request with rcv-seq 65
2016-07-20 17:10:34.011 [WARN ] [nx.internal.connection.KNXConnection] - KNX link has been lost (reason: server request on object link 192.168.178.39:3671 tunneling mode (closed), TP1 hopcount 6)
2016-07-20 17:10:34.012 [WARN ] [.binding.knx.internal.bus.KNXBinding] - Value ‘2.48’ could not be sent to the KNX bus using datapoint ‘command DP 2/1/10 S_Wind, DPT main 0 id 9.001, low priority’ - retrying one time: link closed, connection closed
2016-07-20 17:10:34.012 [WARN ] [tuwien.auto.calimero ] - [KNXnet/IP receiver] KNXnet/IP Tunneling 192.168.178.39:3671: skipped tunneling request with rcv-seq 42
2016-07-20 17:10:34.022 [INFO ] [nx.internal.connection.KNXConnection] - KNX link will be retried in 30 seconds
2016-07-20 17:10:34.023 [WARN ] [tuwien.auto.calimero ] - [KNXnet/IP receiver] KNXnet/IP Tunneling 192.168.178.39:3671: skipped tunneling request with rcv-seq 42
2016-07-20 17:10:34.022 [WARN ] [nx.internal.connection.KNXConnection] - KNX link has been lost (reason: server request on object link 192.168.178.39:3671 tunneling mode (closed), TP1 hopcount 6)
2016-07-20 17:10:34.025 [WARN ] [tuwien.auto.calimero ] - [Thread-34] KNXnet/IP Tunneling 192.168.178.39:3671: send invoked on closed connection - aborted
2016-07-20 17:10:34.026 [INFO ] [nx.internal.connection.KNXConnection] - KNX link will be retried in 30 seconds
2016-07-20 17:10:34.026 [ERROR] [tuwien.auto.calimero ] - [Thread-34] link 192.168.178.39:3671: send error, closing link
tuwien.auto.calimero.knxnetip.KNXConnectionClosedException: connection closed
at tuwien.auto.calimero.knxnetip.ConnectionBase.send(ConnectionBase.java:192)[188:org.openhab.binding.knx:1.9.0.201607040111]
at tuwien.auto.calimero.knxnetip.KNXnetIPTunnel.send(KNXnetIPTunnel.java:135)[188:org.openhab.binding.knx:1.9.0.201607040111]
at tuwien.auto.calimero.link.KNXNetworkLinkIP.doSend(KNXNetworkLinkIP.java:457)[188:org.openhab.binding.knx:1.9.0.201607040111]
at tuwien.auto.calimero.link.KNXNetworkLinkIP.send(KNXNetworkLinkIP.java:419)[188:org.openhab.binding.knx:1.9.0.201607040111]
at tuwien.auto.calimero.link.KNXNetworkLinkIP.sendRequestWait(KNXNetworkLinkIP.java:341)[188:org.openhab.binding.knx:1.9.0.201607040111]
at tuwien.auto.calimero.process.ProcessCommunicatorImpl.write(ProcessCommunicatorImpl.java:438)[188:org.openhab.binding.knx:1.9.0.201607040111]
at tuwien.auto.calimero.process.ProcessCommunicatorImpl.write(ProcessCommunicatorImpl.java:410)[188:org.openhab.binding.knx:1.9.0.201607040111]
at org.openhab.binding.knx.internal.bus.KNXBinding.writeToKNX(KNXBinding.java:143)[188:org.openhab.binding.knx:1.9.0.201607040111]
at org.openhab.binding.knx.internal.bus.KNXBinding.internalReceiveCommand(KNXBinding.java:106)[188:org.openhab.binding.knx:1.9.0.201607040111]
at org.openhab.core.binding.AbstractBinding.receiveCommand(AbstractBinding.java:97)[189:org.openhab.core.compat1x:2.0.0.201606271614]
at org.openhab.core.events.AbstractEventSubscriber.handleEvent(AbstractEventSubscriber.java:42)[189:org.openhab.core.compat1x:2.0.0.201606271614]
at org.apache.felix.eventadmin.impl.handler.EventHandlerProxy.sendEvent(EventHandlerProxy.java:415)[3:org.apache.karaf.services.eventadmin:4.0.4]
at org.apache.felix.eventadmin.impl.tasks.HandlerTask.run(HandlerTask.java:90)[3:org.apache.karaf.services.eventadmin:4.0.4]
at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:511)[:1.8.0_65]
at java.util.concurrent.FutureTask.run(FutureTask.java:266)[:1.8.0_65]
at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1142)[:1.8.0_65]
at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:617)[:1.8.0_65]
at java.lang.Thread.run(Thread.java:745)[:1.8.0_65]

Ivar · October 21, 2016, 11:11am

Hello

I see something similar in OH 1.8.3:

2016-10-21 13:04:18.580 [WARN ] [tuwien.auto.calimero          ] - [KNXnet/IP receiver] KNXnet/IP Tunneling 192.168.1.34:3671: skipped tunneling request with rcv-seq 18
2016-10-21 13:04:18.580 [WARN ] [b.k.i.connection.KNXConnection] - KNX link has been lost (reason: server request on object link 192.168.1.34:3671 tunneling mode (closed), TP1 hopcount 6)

Edit:
Some info on my KNX interface:

EIB KNX IP Interface PoE, with up to 5 tunneling connections    
Product No.: N000401
Manufacturer: EIBMARKT
Manufacturer no.: N000401

No setup done, just plugged it in my switch (PoE) and entered IP in OH config.

Best regards
Ivar

symen_voet · November 5, 2016, 8:23pm

Hi Dominik,
I’ve exactly the same issue:
openhab 1.8.3 on raspberry pi3.
The ip bridge is a MDT IP 1

2016-11-05 20:42:46.092 [INFO ] [b.k.i.connection.KNXConnection] - Trying to (re-)connect to KNX…
2016-11-05 20:42:46.100 [ERROR] [tuwien.auto.calimero ] - [KNXnet/IP receiver] KNXnet/IP Tunneling 192.168.xxxx:3671: could not accept new connection (maximum reached)
2016-11-05 20:42:46.100 [ERROR] [b.k.i.connection.KNXConnection] - Error connecting to KNX bus: error response from control endpoint /192.168.xxxx:3671, could not accept new connection (maximum reached)
2016-11-05 20:42:46.101 [INFO ] [b.k.i.connection.KNXConnection] - KNX link will be retried in 30 seconds
2016-11-05 20:42:46.112 [ERROR] [tuwien.auto.calimero ] - [Timer-0] KNXnet/IP Tunneling 192.168.xxxxx:3671: establishing connection failed
tuwien.auto.calimero.exception.KNXRemoteException: error response from control endpoint /192.168.xxxxx:3671, could not accept new connection (maximum reached)
at tuwien.auto.calimero.knxnetip.ClientConnection.connect(ClientConnection.java:174) ~[na:na]
at tuwien.auto.calimero.knxnetip.KNXnetIPTunnel.(KNXnetIPTunnel.java:117) ~[na:na]
at tuwien.auto.calimero.link.KNXNetworkLinkIP.(KNXNetworkLinkIP.java:180) ~[na:na]
at

symen_voet · November 8, 2016, 7:54pm

I noticed two things:
-the problem starts after a rule executes (and uses the knx binding)
-I get multiple sets of error messages, marked with [timer-0],[timer-1],[timer-3]

I have the impression the knx binding ignores the “numberOfThreads=1” setting when executing rules. Is this possible?

symen_voet · November 8, 2016, 9:00pm

When running the following rule each minute, the problem is NOT reproduced. However in DEBUG mode the code seems to get into an infinite loop:
rule "Thermostat - TEST"
when
Time cron "0 * 21 ? * MON-FRI"
then
logInfo(“thermostat”, “Setting all thermostats to 16”) sendCommand(Thermostat, 16)
end

When running this rule, the problem IS reproduced:

rule "Thermostat - morning"
when
Time cron “0 * 21 ? * MON-FRI”
//Time cron "0 30 6 * * ?"
then
logInfo(“thermostat”, “Setting all thermostats to morning regime”)
sendCommand(Thermostat_SF_Bath, 21)
Thread::sleep(2000)
sendCommand(Thermostat_FF_Office, 19)
Thread::sleep(2000)
sendCommand(Thermostat_FF_Bed, 19)
Thread::sleep(2000)
sendCommand(Thermostat_GF_Kitchen,20)
Thread::sleep(2000)
end

Running only this second rule, doesn’t cause any issues. But running it after the first rule has run, makes the code hit race conditions.
I circumvented the issue by calling all items separately and not calling groups or forEach loops over group members.