OH2 became terribly slow in recent snapshots on RPI 2

Setup, Configuration and Use Runtime
1

I am trying to use last snapshot (offline distro) and it is terribly slow. The first startup with all bundles installation took several minutes on a RPI 2 while it was I think less than 1 minute with my previous snapshot downloaded the 26th of March.

As the snapshot downloaded the 26th of March was normal, I can try to identify starting at which snapshot it became so slow.

Anyone noticed this noticeable change ?

2

I don’t find in cloudbees how to get older snapshots (I find only #242 an d#243).
Are previous snapshots not kept ?

3

I have done a new try with snapshot 256 (offline distro).
Please find an extract of my logs for a normal startup (not the initial startup that took several minutes !):

2016-04-23 12:05:13.935 [INFO ] [smarthome.event.ItemAddedEvent      ] - Item 'astro_sun_38f3d1cf' has been added.
...
2016-04-23 12:05:14.712 [INFO ] [rthome.event.ItemThingLinkAddedEvent] - Link 'rfxcom_temperaturehumidity_fdf71847_62977-rfxcom:temperaturehumidity:fdf71847:62977' has been added.
2016-04-23 12:05:14.716 [INFO ] [rthome.event.ItemThingLinkAddedEvent] - Link 'rfxcom_temperaturehumidity_fdf71847_8196-rfxcom:temperaturehumidity:fdf71847:8196' has been added.
2016-04-23 12:05:53.667 [INFO ] [arthome.ui.paper.internal.PaperUIApp] - Started Paper UI at /ui
2016-04-23 12:05:56.221 [INFO ] [.dashboard.internal.DashboardService] - Started dashboard at /start
2016-04-23 12:05:56.477 [INFO ] [me.event.ThingStatusInfoChangedEvent] - 'ntp:ntp:local' changed from UNINITIALIZED to INITIALIZING
...
2016-04-23 12:06:06.206 [INFO ] [assic.internal.servlet.WebAppServlet] - Started Classic UI at /classicui/app
2016-04-23 12:06:06.250 [INFO ] [basic.internal.servlet.WebAppServlet] - Started Basic UI at /basicui/app
2016-04-23 12:06:06.599 [INFO ] [el.core.internal.ModelRepositoryImpl] - Loading model 'maisonOH2.sitemap'
2016-04-23 12:06:07.877 [INFO ] [el.core.internal.ModelRepositoryImpl] - Loading model 'rrd4j.persist'
2016-04-23 12:06:08.257 [INFO ] [el.core.internal.ModelRepositoryImpl] - Loading model 'maison.items'
...

As you can notice, it looks like my conf (mapdb) is read quickly (first second) and then nothing happens during 40 seconds until I got the first log indicating that Paper UI is started. After that, it took around 20 seconds to have everything started and all items set. As a conclusion, the starting process on a RPI 2 took around 1 minute to complete. I previously did not mesure the starting time on RPI 2 because it was fast. I am almost certain it has been seriously increased in recent snapshots.

Why is there these 40 seconds while apparently nothing happens ?

I even noticed that the first access to ;8080 is very slow (several seconds while the browser is waiting ofr data). Then WEB access are normal.

4

I opened an issue: https://github.com/openhab/openhab-distro/issues/185

As mentioned in the issue, the initial startup took 5 minutes to complete, largely more than before.

5

As a comparison, on the same RPI 2, my production openHAB 1.8.1 needs around 40 seconds to start completely.

6

I am trying on the latest snapshot (#268) on RPI, it is still extremely slow to startup. Any fixes soon? Thanks

7

I would hope that @davy becomes available again soon, he is the expert on those matters…

8

It looks like something had gone wrong with deploying the patched jetty jar. I’ve redeployed it now. Can you try with build [#269] (https://openhab.ci.cloudbees.com/job/openHAB-Distribution/269/)?

9

@davy I tried offline distro 271 and I can confirm that it is now ok again. Thank you.
On a normal startup, I have now everything started around 26 seconds after launching. Paper UI is started after 6 seconds.

Regarding the initial startup (with all bundles installation), that is even better. My last bundle is installed after 3 min 47. But I don’t know if it is a reasonable time. My feeling is that it was faster in the past but I am not really sure. During this initial startup, the banner appears very late. I have 2 jars files put in my addons directory and what I can see in the logs is that OH tries to start them many many times with no success (because some packages are not yet installed). They are finally started with success at the end. I am just asking myself if this is not what making the first startup taking so much time and whether it is normal or not to have so frequent tries to start them ?

PS: I will try again the initial startup without these 2 jars to see if it makes a difference or not.

10

Hi,

I just pulled snapshot #273 to try out. It takes more than 15min to have all the bundles to be in “Active” state. I remember it wasn’t the case in previous builds. Thanks