Openhab 2.3 with KNX2 Binding reacts very slow

DrCoffee · June 22, 2018, 12:21pm

Hello,

I jus installed Openhab 2.3 with KNX2 Binding in my Synology Diskstation 218+ in Docker.
This installation is a migrated one that I manually moved over from my RasPi - it used to be a OH2 with KNX1 installation that worked pretty well - but it had the KNX Telegram Echoing issue.

So now I finalized the installation in docker and everything seems to work, except for the fact that there is a significant delay (>30sec) between the pulling a switch / or a rule and the reaction in the knx Bus.

Here’s an example from the karaf console:

At the Top at 12:03:33.599 you see that I turned on my light - and at the bottom at 12:04:08.098 you see that the light finally really turned on --> after 35sec.

12:03:33.599 [INFO ] [smarthome.event.ItemCommandEvent     ] - Item 'Control_VierDimmaktor_DimOGFlur' received command 100
12:03:33.604 [INFO ] [smarthome.event.ItemStateChangedEvent] - Control_VierDimmaktor_DimOGFlur changed from 0 to 100
12:03:33.605 [INFO ] [home.event.GroupItemStateChangedEvent] - Lampen changed from OFF to ON through Control_VierDimmaktor_DimOGFlur
12:03:55.611 [INFO ] [smarthome.event.ItemStateChangedEvent] - Wetterstation_WindGeschwindigkeit changed from 4.1 to 4.75
12:03:57.717 [INFO ] [smarthome.event.ItemStateChangedEvent] - astro_moon_local_phase_ageDegree changed from 106.63 to 106.67
12:03:57.720 [INFO ] [smarthome.event.ItemStateChangedEvent] - astro_moon_local_phase_agePercent changed from 29.62 to 29.63
12:03:57.723 [INFO ] [smarthome.event.ItemStateChangedEvent] - astro_moon_local_phase_illumination changed from 71.37 to 71.40
12:03:57.730 [INFO ] [smarthome.event.ItemStateChangedEvent] - astro_moon_local_distance_date changed from 2018-06-22T13:58:57.698+0200 to 2018-06-22T14:03:57.698+0200
12:03:57.732 [INFO ] [smarthome.event.ItemStateChangedEvent] - astro_moon_local_distance_miles changed from 241189.20 to 241198.82
12:03:57.735 [INFO ] [smarthome.event.ItemStateChangedEvent] - astro_moon_local_distance_kilometer changed from 388156.40 to 388171.88
12:03:57.747 [INFO ] [smarthome.event.ItemStateChangedEvent] - astro_moon_local_position_azimuth changed from 82.60 to 83.55
12:03:57.750 [INFO ] [smarthome.event.ItemStateChangedEvent] - astro_moon_local_position_elevation changed from -14.27 to -13.50
12:03:57.806 [INFO ] [smarthome.event.ItemStateChangedEvent] - astro_sun_local_position_azimuth changed from 201.49 to 203.88
12:03:57.809 [INFO ] [smarthome.event.ItemStateChangedEvent] - astro_sun_local_position_elevation changed from 62.78 to 62.47
12:03:57.811 [INFO ] [smarthome.event.ItemStateChangedEvent] - astro_sun_local_radiation_direct changed from 643.12 to 640.21
12:03:57.814 [INFO ] [smarthome.event.ItemStateChangedEvent] - astro_sun_local_radiation_diffuse changed from 129.33 to 129.28
12:03:57.817 [INFO ] [smarthome.event.ItemStateChangedEvent] - astro_sun_local_radiation_total changed from 772.45 to 769.49
12:04:01.437 [INFO ] [smarthome.event.ItemStateChangedEvent] - ntp_ntp_local_dateTime changed from 2018-06-22T12:02:59.876+0000 to 2018-06-22T12:04:01.433+0000
12:04:01.438 [INFO ] [smarthome.event.ItemStateChangedEvent] - ntp_ntp_local_string changed from 2018-06-22 12:02:59 UTC to 2018-06-22 12:04:01 UTC
12:04:05.870 [INFO ] [smarthome.event.ItemStateChangedEvent] - Heizung_Aussen_Temperature changed from 13.199999999999999289457264239899814128875732421875 to 13.300000000000000710542735760100185871124267578125
12:04:07.163 [INFO ] [smarthome.event.ItemCommandEvent     ] - Item 'Control_VierDimmaktor_DimOGFlur' received command ON
12:04:07.172 [INFO ] [smarthome.event.ItemCommandEvent     ] - Item 'Control_VierDimmaktor_DimOGFlur' received command 90
12:04:07.174 [INFO ] [smarthome.event.ItemStateChangedEvent] - Control_VierDimmaktor_DimOGFlur changed from 100 to 90
12:04:08.088 [INFO ] [smarthome.event.ItemCommandEvent     ] - Item 'Control_VierDimmaktor_DimOGFlur' received command 100
12:04:08.098 [INFO ] [smarthome.event.ItemStateChangedEvent] - Control_VierDimmaktor_DimOGFlur changed from 90 to 100

My Binding is configured as follwos:

In order to make sure that this issue is not related to my Synology-Docker Setup, I installed OH2.3 with KNX1 - but here everything works fine (except for the echoing issue again)

Do you have any idea what went wrong?

havaak · October 20, 2018, 9:50am

I am seeing same behaviour, in my case with MQTT and Zwave. Not as excessive as 35 seconds, but 2 or 3 seconds. I have taken down a number of containers that are running on my DS918+ (12Gb mem) and noticed that there is less delay. Short term conclusion -> not enough resources.

kr

Han

teaserr · March 3, 2019, 12:14pm

I have the same problem. Upgraded from 2.2 to 2.4 yesterday. Also excganged the legacy KNX binding for the 2.x version and redid al my config (hours of work!). The KNX things file is about 280 lines, with about 40 things and 150-200 channels.
The performance is terrible. Indeed over 30 seconds before a command from the UI (classic or habpanel doesn’t matter) reaches the KNX bus. Often there is even no response at all. Sometimes there’s a quicker response but on average it’s dozens of seconds.
The problem is not on the KNX bus, there’s no flood of telegrams or anything. I think it’s really just a performance problem. I’m running OH on an RPI and when running ‘top’ I see the load average going over 2-3 when running ‘idle’ (that is: no abnormal activity going on). The java process is always the top cpu user. After disabling the v2.x binding and reverting to the legacy binding (yay for source control), the performance is back at crisp speed. I can see that the java process cpu usage dropped to about 1-10%.
Btw, I tried resetting the cache, this didn’t solve anything.
I assume there is loads of overhead introduced with the things and channels compared to just the bare items and that this causes performance problems on lesser hardware. Is this issue going to be addressed? Or are we supposed to resort to heavier hardware (meaning more power usage)? For the time being I’m sticking with the 1.x binding and I hope it will keep being supported until the problems are addressed.

teaserr · January 12, 2020, 1:09pm

We’re now almost a year later. Yesterday I finally powered up that RPI4 that I bought months ago. Flashed it with the lastest Raspbian, configured OpenHAB, installed the KNX binding (nothing else) and dug up my config from the last time I tried the KNX2 binding.

It’s still not workable.

I’ve been watching ‘top’ now in the linux console for a while. I see that often there is 100%+ cpu usage for the openhab process. But it also regularly drops to 0-3% for several minutes. The amount of events and cpu usage do not seem to correlate. Memory usage of openhab is around 13% constantly.

In the event log, there is a dozen to a couple of dozen events per minute. Nothing extreme I suppose. My knx.things file is about 280 lines to give an idea of the amount of things I have configured.

What’s the issue here? Is my KNX installation too large to be handled by OH? Why is the cpu usage fluctuating so much?

teaserr · December 5, 2020, 10:38am

I recently retried with OH 2.5.x. Same issue. Then I tried reorganizing my Things file. Previously I created a Thing for each physical KNX device that I own (actors, pushbuttons, presence detectors etc). Now I have grouped all similar devices under 1 Thing so I have way less Things. So now I have a Thing for all my switch actors, one for all my dimming actors, one for all my PD’s and so on. Basically I went from ~50 Things to about 10.
Result: now it is very responsive.