Hello,
openHAB 4.1.2 running on Ubuntu pc since 1 years (through upgrades). Everything worked perfectly until 2/3 weeks ago, where I intercepted some random HANGS on KNX communications.
Seems that my KNX BUS (through aan MDT IP interface) stop sending updates towards OH (or OH doesn’t look for them…).
In the meantime, I can monitor the BUS running with ETS, and teh rest of openHAB is working.
This is openhab.log at time of one of the failures:
2024-05-04 23:42:11.676 [WARN ] [KNXnet/IP Tunneling 192.168.3.2:3671] - response timeout waiting for confirmation
tuwien.auto.calimero.KNXTimeoutException: no confirmation reply received for 0.0.0->6/3/8 L_Data.req, low priority hop count 6 repeat, tpdu 00 00
at tuwien.auto.calimero.knxnetip.ClientConnection.doExtraBlockingModes(ClientConnection.java:271) ~[?:?]
at tuwien.auto.calimero.knxnetip.ConnectionBase.send(ConnectionBase.java:268) ~[?:?]
at tuwien.auto.calimero.knxnetip.KNXnetIPTunnel.send(KNXnetIPTunnel.java:213) ~[?:?]
at tuwien.auto.calimero.link.KNXNetworkLinkIP.doSend(KNXNetworkLinkIP.java:515) ~[?:?]
at tuwien.auto.calimero.link.KNXNetworkLinkIP.onSend(KNXNetworkLinkIP.java:503) ~[?:?]
at tuwien.auto.calimero.link.AbstractLink.send(AbstractLink.java:397) ~[?:?]
at tuwien.auto.calimero.link.KNXNetworkLinkIP.sendRequestWait(KNXNetworkLinkIP.java:480) ~[?:?]
at tuwien.auto.calimero.process.ProcessCommunicatorImpl.send(ProcessCommunicatorImpl.java:494) ~[?:?]
at tuwien.auto.calimero.process.ProcessCommunicatorImpl.readFromGroup(ProcessCommunicatorImpl.java:464) ~[?:?]
at tuwien.auto.calimero.process.ProcessCommunicatorImpl.read(ProcessCommunicatorImpl.java:386) ~[?:?]
at org.openhab.binding.knx.internal.client.AbstractKNXClient.readNextQueuedDatapoint(AbstractKNXClient.java:367) ~[?:?]
at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:539) [?:?]
at java.util.concurrent.FutureTask.runAndReset(FutureTask.java:305) [?:?]
at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.run(ScheduledThreadPoolExecutor.java:305) [?:?]
at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1136) [?:?]
at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:635) [?:?]
at java.lang.Thread.run(Thread.java:840) [?:?]
2024-05-04 23:42:15.750 [WARN ] [KNXnet/IP Tunneling 192.168.3.2:3671] - response timeout waiting for confirmation
tuwien.auto.calimero.KNXTimeoutException: no confirmation reply received for 0.0.0->12/2/1 L_Data.req, low priority hop count 6 repeat, tpdu 00 00
at tuwien.auto.calimero.knxnetip.ClientConnection.doExtraBlockingModes(ClientConnection.java:271) ~[?:?]
at tuwien.auto.calimero.knxnetip.ConnectionBase.send(ConnectionBase.java:268) ~[?:?]
at tuwien.auto.calimero.knxnetip.KNXnetIPTunnel.send(KNXnetIPTunnel.java:213) ~[?:?]
at tuwien.auto.calimero.link.KNXNetworkLinkIP.doSend(KNXNetworkLinkIP.java:515) ~[?:?]
at tuwien.auto.calimero.link.KNXNetworkLinkIP.onSend(KNXNetworkLinkIP.java:503) ~[?:?]
at tuwien.auto.calimero.link.AbstractLink.send(AbstractLink.java:397) ~[?:?]
at tuwien.auto.calimero.link.KNXNetworkLinkIP.sendRequestWait(KNXNetworkLinkIP.java:480) ~[?:?]
at tuwien.auto.calimero.process.ProcessCommunicatorImpl.send(ProcessCommunicatorImpl.java:494) ~[?:?]
at tuwien.auto.calimero.process.ProcessCommunicatorImpl.readFromGroup(ProcessCommunicatorImpl.java:464) ~[?:?]
at tuwien.auto.calimero.process.ProcessCommunicatorImpl.read(ProcessCommunicatorImpl.java:386) ~[?:?]
at org.openhab.binding.knx.internal.client.AbstractKNXClient.readNextQueuedDatapoint(AbstractKNXClient.java:367) ~[?:?]
at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:539) [?:?]
at java.util.concurrent.FutureTask.runAndReset(FutureTask.java:305) [?:?]
at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.run(ScheduledThreadPoolExecutor.java:305) [?:?]
at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1136) [?:?]
at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:635) [?:?]
at java.lang.Thread.run(Thread.java:840) [?:?]
2024-05-04 23:42:19.811 [WARN ] [KNXnet/IP Tunneling 192.168.3.2:3671] - response timeout waiting for confirmation
tuwien.auto.calimero.KNXTimeoutException: no confirmation reply received for 0.0.0->6/1/11 L_Data.req, low priority hop count 6 repeat, tpdu 00 00
at tuwien.auto.calimero.knxnetip.ClientConnection.doExtraBlockingModes(ClientConnection.java:271) ~[?:?]
at tuwien.auto.calimero.knxnetip.ConnectionBase.send(ConnectionBase.java:268) ~[?:?]
at tuwien.auto.calimero.knxnetip.KNXnetIPTunnel.send(KNXnetIPTunnel.java:213) ~[?:?]
at tuwien.auto.calimero.link.KNXNetworkLinkIP.doSend(KNXNetworkLinkIP.java:515) ~[?:?]
at tuwien.auto.calimero.link.KNXNetworkLinkIP.onSend(KNXNetworkLinkIP.java:503) ~[?:?]
at tuwien.auto.calimero.link.AbstractLink.send(AbstractLink.java:397) ~[?:?]
at tuwien.auto.calimero.link.KNXNetworkLinkIP.sendRequestWait(KNXNetworkLinkIP.java:480) ~[?:?]
at tuwien.auto.calimero.process.ProcessCommunicatorImpl.send(ProcessCommunicatorImpl.java:494) ~[?:?]
at tuwien.auto.calimero.process.ProcessCommunicatorImpl.readFromGroup(ProcessCommunicatorImpl.java:464) ~[?:?]
at tuwien.auto.calimero.process.ProcessCommunicatorImpl.read(ProcessCommunicatorImpl.java:386) ~[?:?]
at org.openhab.binding.knx.internal.client.AbstractKNXClient.readNextQueuedDatapoint(AbstractKNXClient.java:367) ~[?:?]
at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:539) [?:?]
at java.util.concurrent.FutureTask.runAndReset(FutureTask.java:305) [?:?]
at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.run(ScheduledThreadPoolExecutor.java:305) [?:?]
at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1136) [?:?]
at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:635) [?:?]
at java.lang.Thread.run(Thread.java:840) [?:?]
and after some minutes I got:
2024-05-04 23:56:15.726 [WARN ] [nx.internal.client.AbstractKNXClient] - Giving up reading datapoint 6/3/8, the number of maximum retries (3) is reached.
2024-05-04 23:56:25.798 [WARN ] [nx.internal.client.AbstractKNXClient] - Giving up reading datapoint 12/2/1, the number of maximum retries (3) is reached.
2024-05-04 23:56:35.871 [WARN ] [nx.internal.client.AbstractKNXClient] - Giving up reading datapoint 6/1/11, the number of maximum retries (3) is reached.
2024-05-04 23:56:45.943 [WARN ] [nx.internal.client.AbstractKNXClient] - Giving up reading datapoint 6/3/0, the number of maximum retries (3) is reached.
2024-05-04 23:56:56.015 [WARN ] [nx.internal.client.AbstractKNXClient] - Giving up reading datapoint 6/3/12, the number of maximum retries (3) is reached.
2024-05-04 23:57:06.087 [WARN ] [nx.internal.client.AbstractKNXClient] - Giving up reading datapoint 6/2/8, the number of maximum retries (3) is reached.
2024-05-04 23:57:16.159 [WARN ] [nx.internal.client.AbstractKNXClient] - Giving up reading datapoint 6/2/12, the number of maximum retries (3) is reached.
2024-05-04 23:57:26.231 [WARN ] [nx.internal.client.AbstractKNXClient] - Giving up reading datapoint 6/1/8, the number of maximum retries (3) is reached.
2024-05-04 23:57:36.303 [WARN ] [nx.internal.client.AbstractKNXClient] - Giving up reading datapoint 6/1/9, the number of maximum retries (3) is reached.
2024-05-04 23:57:46.375 [WARN ] [nx.internal.client.AbstractKNXClient] - Giving up reading datapoint 6/1/10, the number of maximum retries (3) is reached.
2024-05-04 23:57:56.448 [WARN ] [nx.internal.client.AbstractKNXClient] - Giving up reading datapoint 6/1/12, the number of maximum retries (3) is reached.
2024-05-04 23:58:06.520 [WARN ] [nx.internal.client.AbstractKNXClient] - Giving up reading datapoint 6/3/9, the number of maximum retries (3) is reached.
2024-05-04 23:58:16.592 [WARN ] [nx.internal.client.AbstractKNXClient] - Giving up reading datapoint 6/3/10, the number of maximum retries (3) is reached.
2024-05-04 23:58:26.664 [WARN ] [nx.internal.client.AbstractKNXClient] - Giving up reading datapoint 6/2/9, the number of maximum retries (3) is reached.
2024-05-04 23:58:36.736 [WARN ] [nx.internal.client.AbstractKNXClient] - Giving up reading datapoint 6/2/10, the number of maximum retries (3) is reached.
2024-05-04 23:58:46.809 [WARN ] [nx.internal.client.AbstractKNXClient] - Giving up reading datapoint 6/3/1, the number of maximum retries (3) is reached.
2024-05-04 23:58:56.882 [WARN ] [nx.internal.client.AbstractKNXClient] - Giving up reading datapoint 6/3/4, the number of maximum retries (3) is reached.
2024-05-04 23:59:06.954 [WARN ] [nx.internal.client.AbstractKNXClient] - Giving up reading datapoint 6/2/1, the number of maximum retries (3) is reached.
2024-05-04 23:59:17.027 [WARN ] [nx.internal.client.AbstractKNXClient] - Giving up reading datapoint 6/2/4, the number of maximum retries (3) is reached.
2024-05-04 23:59:27.099 [WARN ] [nx.internal.client.AbstractKNXClient] - Giving up reading datapoint 6/1/1, the number of maximum retries (3) is reached.
2024-05-04 23:59:37.171 [WARN ] [nx.internal.client.AbstractKNXClient] - Giving up reading datapoint 6/1/2, the number of maximum retries (3) is reached.
2024-05-04 23:59:47.244 [WARN ] [nx.internal.client.AbstractKNXClient] - Giving up reading datapoint 6/1/3, the number of maximum retries (3) is reached.
2024-05-04 23:59:57.316 [WARN ] [nx.internal.client.AbstractKNXClient] - Giving up reading datapoint 6/1/4, the number of maximum retries (3) is reached.
In the graph you can see the “blackout” timeframes (horizontal lines)
Any hint?