XKNX got instable (with May-Release?)

Configuration
1

Dear community,
I´m running Home-Assistant on a raspberry pi 4 since 1,5 years. 90% of my devices are connected via KNX, which worked very well and stable, the configuration of my KNX-Bus has not changed.
Unfortunately, since some weeks (probably after 1st May-Releas of Home-Assistant?), XKNX seems to be quite unstable: I recognized this at first, when I tried to open several covers via a cover-group. They only opened with a heavy delay of several seconds (>10 seconds). Looking at the log file, I found the following errors, which occur regularly when the traffic between HASS and KNX-bus is increasing.
The relevant lines from my log file are attached. I´m using a WEINZIERL IP-Interface 731 (which didn´t cause problems so far). There is no further device accessing the KNX-bus besides my HASS.IO-raspbberry.
I´m not a developper, so I´m happy for any hint and I´m happy to provide further information if necessary!

2021-06-06 22:10:33 WARNING (MainThread) [xknx.log] Received DisconnectRequest from tunnelling sever.
2021-06-06 22:10:36 WARNING (MainThread) [xknx.log] Sending telegram failed. No active communication channel.
2021-06-06 22:10:38 WARNING (MainThread) [xknx.log] Sending telegram failed. No active communication channel.
2021-06-06 22:10:42 WARNING (MainThread) [homeassistant.components.switch] Updating adguard switch took longer than the scheduled update interval 0:00:10
2021-06-06 22:10:42 WARNING (MainThread) [homeassistant.components.media_player] Updating squeezebox media_player took longer than the scheduled update interval 0:00:10
2021-06-06 22:10:43 WARNING (MainThread) [xknx.log] Sending telegram failed. No active communication channel.
2021-06-06 22:10:50 WARNING (MainThread) [xknx.log] Sending telegram failed. No active communication channel.
2021-06-06 22:10:52 WARNING (MainThread) [homeassistant.components.switch] Updating adguard switch took longer than the scheduled update interval 0:00:10
2021-06-06 22:10:52 WARNING (MainThread) [xknx.log] Received DisconnectRequest from tunnelling sever.
2021-06-06 22:10:53 WARNING (MainThread) [homeassistant.components.sensor] Updating command_line sensor took longer than the scheduled update interval 0:00:20
2021-06-06 22:10:57 ERROR (MainThread) [homeassistant.components.hassio.handler] Timeout on /ingress/validate_session request
2021-06-06 22:10:57 ERROR (MainThread) [homeassistant.components.hassio] Failed to to call /ingress/validate_session -
2021-06-06 22:10:58 WARNING (MainThread) [xknx.log] Sending telegram failed. No active communication channel.
2021-06-06 22:10:59 WARNING (MainThread) [xknx.log] Sending telegram failed. No active communication channel.
2021-06-06 22:11:00 WARNING (MainThread) [homeassistant.components.http.ban] Login attempt or request with invalid authentication from supervisor (172.30.32.2). (Python/3.9 aiohttp/3.7.4.post0)
2

Hi!
Is this also happening with current HA 2021.6.2 ?

From the few lines you posted it seems that more integrations suffer from delays / timeouts.
Does this happen even if you disable the knx integration completely?
Is it happening when you run only the knx integration and no other?
Is it fixed by disabling any other integration that may cause this?

In xknx this could eventually lead to too slow responses resulting in the KNX/ip Interface to shut down the connection.

Received DisconnectRequest from tunnelling sever.

3

Hi! Thanks for your quick reply! What I can say right now, it´s also happening in 2021.6.2
I´ll try to disable other integrations tomorrow and post the result here!
Many thanks for helping so far!

4

Hi,

I have exactly the same problems since May … KNX connection becomes instable after a couple of hours. Currently I am on core-2021.6.6 with Home Assistant OS 6.1 on a NUC.

Mostly KNX is working, but then there are a few hours not responding …

Here are some logs from the past days.

Updating rest sensor took longer than the scheduled update interval 0:00:02
15:22:51 – (WARNUNG) Sensor - Die Nachricht ist zum ersten Mal um 2. Juli 2021, 12:32:44 aufgetreten und erscheint 10489 mal

http://10.0.0.8:8123/frontend_latest/core.7ce1f920.js:1:7688 Uncaught Error: Suspend promise not set
14:52:57 – (FEHLER) components/system_log/__init__.py - Die Nachricht ist zum ersten Mal um 3. Juli 2021, 20:02:32 aufgetreten und erscheint 2 mal

Received DisconnectRequest from tunnelling sever.
06:11:49 – (WARNUNG) /usr/local/lib/python3.8/site-packages/xknx/io/tunnel.py - Die Nachricht ist zum ersten Mal um 2. Juli 2021, 17:10:28 aufgetreten und erscheint 152 mal

Could not sync group address '30/5/7' (bwwp - State)
06:10:59 – (WARNUNG) /usr/local/lib/python3.8/site-packages/xknx/remote_value/remote_value.py - Die Nachricht ist zum ersten Mal um 2. Juli 2021, 17:10:39 aufgetreten und erscheint 556 mal

Error: KNX bus did not respond in time (2.0 secs) to GroupValueRead request for: 30/5/7
06:10:59 – (WARNUNG) /usr/local/lib/python3.8/site-packages/xknx/core/value_reader.py - Die Nachricht ist zum ersten Mal um 2. Juli 2021, 17:10:39 aufgetreten und erscheint 556 mal

Heartbeat to KNX bus failed. No answer from tunneling server.
06:09:24 – (WARNUNG) /usr/local/lib/python3.8/site-packages/xknx/io/tunnel.py - Die Nachricht ist zum ersten Mal um 2. Juli 2021, 17:14:49 aufgetreten und erscheint 83 mal

Pymodbus: Modbus Error: [Input/Output] Modbus Error: [Invalid Message] No response received, expected at least 8 bytes (0 received)
06:09:10 – (FEHLER) Modbus - Die Nachricht ist zum ersten Mal um 2. Juli 2021, 17:10:24 aufgetreten und erscheint 583 mal

TemplateError('UndefinedError: None has no element 0') while processing template 'Template("{{ state_attr('sensor.umg604_rest', '_P_SUM3')[0] | round(0) }}")' for attribute '_state' in entity 'sensor.haupt'
06:07:43 – (FEHLER) Template - Die Nachricht ist zum ersten Mal um 2. Juli 2021, 17:11:42 aufgetreten und erscheint 845 mal

Update of sensor.umg604_rest is taking over 10 seconds
06:07:43 – (WARNUNG) helpers/entity.py - Die Nachricht ist zum ersten Mal um 2. Juli 2021, 17:11:42 aufgetreten und erscheint 282 mal

Sending telegram failed. No active communication channel.
06:03:23 – (WARNUNG) /usr/local/lib/python3.8/site-packages/xknx/core/telegram_queue.py - Die Nachricht ist zum ersten Mal um 2. Juli 2021, 17:10:37 aufgetreten und erscheint 439 mal
5

Hi!
Same questions as above apply. I think it is something else blocking the main EventLoop leading to timing problems in the KNX library.

6

Hi!

Another problem with KNX Integration here…

core-2021.6.4

2021-07-04 20:29:18 ERROR (MainThread) [homeassistant] Error doing job: Exception in callback _SelectorDatagramTransport._read_ready()
Traceback (most recent call last):
  File "/usr/local/lib/python3.8/asyncio/events.py", line 81, in _run
    self._context.run(self._callback, *self._args)
  File "/usr/local/lib/python3.8/asyncio/selector_events.py", line 1021, in _read_ready
    self._protocol.datagram_received(data, addr)
  File "/usr/local/lib/python3.8/site-packages/xknx/io/udp_client.py", line 70, in datagram_received
    self.data_received_callback(data)
  File "/usr/local/lib/python3.8/site-packages/xknx/io/udp_client.py", line 105, in data_received_callback
    knxipframe.from_knx(raw)
  File "/usr/local/lib/python3.8/site-packages/xknx/knxip/knxip.py", line 88, in from_knx
    pos += self.init(self.header.service_type_ident).from_knx(data[pos:])
  File "/usr/local/lib/python3.8/site-packages/xknx/knxip/tunnelling_request.py", line 68, in from_knx
    pos += self.cemi.from_knx(raw[pos:])
  File "/usr/local/lib/python3.8/site-packages/xknx/knxip/cemi_frame.py", line 133, in from_knx
    return self.from_knx_data_link_layer(raw)
  File "/usr/local/lib/python3.8/site-packages/xknx/knxip/cemi_frame.py", line 181, in from_knx_data_link_layer
    self.payload.from_knx(apdu)
  File "/usr/local/lib/python3.8/site-packages/xknx/telegram/apci.py", line 436, in from_knx
    channel, self.count = struct.unpack("!BB", raw[1:])
struct.error: unpack requires a buffer of 2 bytes
2021-07-04 20:29:19 ERROR (MainThread) [homeassistant] Error doing job: Exception in callback _SelectorDatagramTransport._read_ready()
Traceback (most recent call last):
  File "/usr/local/lib/python3.8/asyncio/events.py", line 81, in _run
    self._context.run(self._callback, *self._args)
  File "/usr/local/lib/python3.8/asyncio/selector_events.py", line 1021, in _read_ready
    self._protocol.datagram_received(data, addr)
  File "/usr/local/lib/python3.8/site-packages/xknx/io/udp_client.py", line 70, in datagram_received
    self.data_received_callback(data)
  File "/usr/local/lib/python3.8/site-packages/xknx/io/udp_client.py", line 105, in data_received_callback
    knxipframe.from_knx(raw)
  File "/usr/local/lib/python3.8/site-packages/xknx/knxip/knxip.py", line 88, in from_knx
    pos += self.init(self.header.service_type_ident).from_knx(data[pos:])
  File "/usr/local/lib/python3.8/site-packages/xknx/knxip/tunnelling_request.py", line 68, in from_knx
    pos += self.cemi.from_knx(raw[pos:])
  File "/usr/local/lib/python3.8/site-packages/xknx/knxip/cemi_frame.py", line 133, in from_knx
    return self.from_knx_data_link_layer(raw)
  File "/usr/local/lib/python3.8/site-packages/xknx/knxip/cemi_frame.py", line 181, in from_knx_data_link_layer
    self.payload.from_knx(apdu)
  File "/usr/local/lib/python3.8/site-packages/xknx/telegram/apci.py", line 436, in from_knx
    channel, self.count = struct.unpack("!BB", raw[1:])
struct.error: unpack requires a buffer of 2 bytes
2021-07-04 20:29:20 WARNING (MainThread) [xknx.log] Received DisconnectRequest from tunnelling sever.
7

Thats a quite different problem. (Maybe open an issue at GitHub - XKNX/xknx: XKNX - A KNX library written in Python).

  • Can you reproduce this? If you can enable debug logging for xknx or do a wireshark capture of the knx communication. xknx logs
  • Which interface are you using?
8

I installed 2021.7.0 yesterday morning and till now no more KNX errors …