OH3.4 KNX binding 3.4.4 problem "close connection (server request)"

Hi All,

I’m here again for KNX binding problem.

I’m using:

  • MiniPC i5, 16Gb RAM
  • Linux Ubuntu 22.04.2 LTS
  • OpenJDK Runtime Environment Zulu11.60+19-CA (build 11.0.17+8-LTS)
  • openHAB : 3.4.4 Release Build
  • org.openhab.binding.knx : 3.4.4
  • MDT IP Router (SCN-IP100.03)

My knx bridge config:

Bridge knx:ip:bridge [
    type="TUNNEL",   
    ipAddress="192.168.7.225",
    portNumber=3671,
    autoReconnectPeriod=30 
]

What is happening:

  1. From openHAB startup the knx binding work without issue
  2. at some point no more knx item are updated, neither commands to knx reach the bus (this situation last about 2 minutes) (I can’t see anything obvious in the log related to this, other than the knx binding logs)
  3. then the log show “close connection (server request)”
  4. after 30 seconds connection is restablished
  5. after the fist disconnection, the following happens after 15 minutes, and so on.

I have this problem since I migrated to 3.3/3.4, before I used openHAB 1.8.3 and knx was almost perfect, never had a problem.

If I look at the Router web page I can see only 1 link, I never saw more than 1 link opened by openhab.

Here relevant part of my log:

...
2023-05-15 15:09:03.946 [TRACE] [nx.internal.client.AbstractKNXClient] - Received a Group Write telegram from '0.1.25' to '0/2/7' with value '[0, 37]'
2023-05-15 15:09:03.946 [DEBUG] [.internal.handler.DeviceThingHandler] - onGroupWrite Thing 'knx:device:bridge:POWER_GENERALE' received a GroupValueWrite telegram from '0.1.25' for destination '0/2/7'
2023-05-15 15:09:03.946 [TRACE] [.internal.handler.DeviceThingHandler] - onGroupWrite Thing 'knx:device:bridge:POWER_GENERALE' processes a GroupValueWrite telegram for destination '0/2/7' for channel 'knx:device:bridge:POWER_GENERALE:Consumo_Generale_Ist'
2023-05-15 15:09:03.947 [TRACE] [g.knx.internal.dpt.KNXCoreTypeMapper] - toType datapoint DPT = 9.001
2023-05-15 15:11:04.882 [INFO ] [Xnet/IP Tunneling 192.168.7.225:3671] - close connection - server request
2023-05-15 15:11:04.884 [INFO ] [ess.communication 192.168.7.225:3671] - attached link was closed (server request)
2023-05-15 15:11:04.885 [DEBUG] [nx.internal.client.AbstractKNXClient] - The KNX network link was detached from the process communicator
2023-05-15 15:11:04.887 [DEBUG] [nx.internal.client.AbstractKNXClient] - KNX link has been lost (reason: server request on object tunneling link (closed) 192.168.7.225:3671 TP1 medium, device 0.0.0, hopcount 6)
2023-05-15 15:11:04.889 [DEBUG] [nx.internal.client.AbstractKNXClient] - Bridge knx:ip:bridge scheduling connect in 30s
2023-05-15 15:11:34.890 [DEBUG] [nx.internal.client.AbstractKNXClient] - Bridge knx:ip:bridge is disconnecting from KNX bus
2023-05-15 15:11:34.893 [TRACE] [nx.internal.client.AbstractKNXClient] - Bridge knx:ip:bridge disconnected from KNX bus
2023-05-15 15:11:35.894 [DEBUG] [nx.internal.client.AbstractKNXClient] - Bridge knx:ip:bridge is connecting to KNX bus
2023-05-15 15:11:35.894 [DEBUG] [binding.knx.internal.client.IPClient] - Establishing connection to KNX bus on 192.168.7.225:3671 in mode TUNNEL.
2023-05-15 15:11:35.897 [INFO ] [Xnet/IP Tunneling 192.168.7.225:3671] - connection established (data endpoint 192.168.7.225:3671, channel 16, tunneling address 15.15.241)
2023-05-15 15:11:35.898 [INFO ] [nx.internal.client.AbstractKNXClient] - Bridge knx:ip:bridge connected to KNX bus
2023-05-15 15:11:35.899 [TRACE] [nx.internal.client.AbstractKNXClient] - Sending a Group Read Request telegram for 1/6/1
2023-05-15 15:11:37.821 [TRACE] [nx.internal.client.AbstractKNXClient] - Received a Group Write telegram from '0.1.66' to '6/2/14' with value '[62, 109, -111, 104]'
2023-05-15 15:11:37.822 [DEBUG] [.internal.handler.DeviceThingHandler] - onGroupWrite Thing 'knx:device:bridge:POWER_PRESE' received a GroupValueWrite telegram from '0.1.66' for destination '6/2/14'
2023-05-15 15:11:37.824 [TRACE] [.internal.handler.DeviceThingHandler] - onGroupWrite Thing 'knx:device:bridge:POWER_PRESE' processes a GroupValueWrite telegram for destination '6/2/14' for channel 'knx:device:bridge:POWER_PRESE:Prese_Cameretta_SxDxCircuito1_Corrente'
2023-05-15 15:11:37.825 [TRACE] [g.knx.internal.dpt.KNXCoreTypeMapper] - toType datapoint DPT = 14.019
...

As you can see last knx thing update is at 15:09:03.3947.
After 2 minutes (15:11:04.882) the is the log entry for “close connection - server request”
After 30 seconds (as configured) the connection is restablished again, and knx things are updated again

The log entry for “close connection - server request” is marked as [INFO], so I suppose there is something that binding consider as normal, not an error as I see in other discussions (disconnection request from router ??)

I’m very frustrated, and I’m about to give up…
All my house is wired with knx, so this way openHAB is not reliable…

Someone have suggestions ?
I’m thinking to setup a 1.x instance of openHAB running only the knx binding and make communicate this one with the main openHAB 3.4 instance via rest api…
Or maybe I could try to update to 4.0 since there should be an updated version of calimero library, which maybe solves the problem?

Thanks

Check your configuration for things do you have empty channels with no configuration etc. Openhab 3.4 introduced some checks. Clear cache and restart operating system. Reboot you Knx IP.

I checked, no empty channels, etc.
Yestrday I cleared cache and rebooted everything 2 times: for now no more knx “close connection” events.
Let’s cross fingers !

Thanks @stamate_viorel