openHAB 2.3 Snapshot Boot speed

I have seen significant improvement (>20%) on the startup times of the OH2 service on my system lately and I wanted to check if anyone else is seeing the same.

Maybe the latest Snapshot builds have included some (better) way to optimize service startup? :slight_smile:

Using:
HW Platform: Mid-ranged laptop (Intel CPU i5-6200U, 8GB RAM, 1TB HDD)
SW Platform: Linux Debian Jessie (8), Oracle Java build 1.8.0_171-b11, OH 2.3.0-Snapshot Build #1272
Addons:
Bindings: knx1,mqtt1,weather1,samsungtv,astro,ntp,wol1,networkupstools1, unifi, zwave (refactored)
UIs = basic,paper,habpanel,habmin
Persistence = mapdb,influxdb
Actions = mail,pushover
Transformations = map,regex,jsonpath
Misc = restdocs,homekit

400k bytes worth of *.items, *.things, *.rules etc files in /etc/openhab2/ directory

openHAB 2.3.0 Snapshot Build #1272 Service startup time: 24 secs, 51 msecs

openhab.log:

2018-05-07 08:21:24.447 [INFO ] [.core.internal.i18n.I18nProviderImpl] - Location set to 'xx.xxx,yy.yyy'.
2018-05-07 08:21:24.557 [INFO ] [.dashboard.internal.DashboardService] - Started Dashboard at http://172.16.13.100:8081
2018-05-07 08:21:24.559 [INFO ] [.dashboard.internal.DashboardService] - Started Dashboard at https://172.16.13.100:8444
2018-05-07 08:21:29.420 [INFO ] [el.core.internal.ModelRepositoryImpl] - Loading model 'KNX.items'
2018-05-07 08:21:29.497 [INFO ] [el.core.internal.ModelRepositoryImpl] - Loading model 'Simulation.items'
2018-05-07 08:21:29.510 [INFO ] [el.core.internal.ModelRepositoryImpl] - Loading model 'Unifi.items'
2018-05-07 08:21:29.543 [INFO ] [el.core.internal.ModelRepositoryImpl] - Loading model 'Paradox.items'
2018-05-07 08:21:29.562 [INFO ] [el.core.internal.ModelRepositoryImpl] - Loading model 'Astro.items'
2018-05-07 08:21:29.576 [INFO ] [el.core.internal.ModelRepositoryImpl] - Loading model 'UPS.items'
2018-05-07 08:21:29.587 [INFO ] [el.core.internal.ModelRepositoryImpl] - Loading model 'ESP.items'
2018-05-07 08:21:29.609 [INFO ] [el.core.internal.ModelRepositoryImpl] - Loading model 'ZWave.items'
2018-05-07 08:21:29.646 [INFO ] [el.core.internal.ModelRepositoryImpl] - Loading model 'WoL.items'
2018-05-07 08:21:29.659 [INFO ] [el.core.internal.ModelRepositoryImpl] - Loading model 'Weather.items'
2018-05-07 08:21:29.705 [INFO ] [el.core.internal.ModelRepositoryImpl] - Loading model 'Groups.items'
2018-05-07 08:21:30.247 [INFO ] [el.core.internal.ModelRepositoryImpl] - Loading model 'mPower.items'
2018-05-07 08:21:30.289 [INFO ] [el.core.internal.ModelRepositoryImpl] - Loading model 'ntp.items'
2018-05-07 08:21:30.296 [INFO ] [el.core.internal.ModelRepositoryImpl] - Loading model 'SamsungTV.items'
2018-05-07 08:21:30.464 [INFO ] [el.core.internal.ModelRepositoryImpl] - Loading model 'mapdb.persist'
2018-05-07 08:21:30.475 [INFO ] [el.core.internal.ModelRepositoryImpl] - Loading model 'influxdb.persist'
2018-05-07 08:21:32.131 [INFO ] [el.core.internal.ModelRepositoryImpl] - Loading model 'Sun.rules'
2018-05-07 08:21:32.235 [INFO ] [el.core.internal.ModelRepositoryImpl] - Loading model 'Master_Lights.rules'
2018-05-07 08:21:32.282 [INFO ] [el.core.internal.ModelRepositoryImpl] - Loading model 'UPS.rules'
2018-05-07 08:21:33.020 [INFO ] [el.core.internal.ModelRepositoryImpl] - Loading model 'Fib_Eyes.rules'
2018-05-07 08:21:33.128 [INFO ] [el.core.internal.ModelRepositoryImpl] - Loading model 'Email.rules'
2018-05-07 08:21:33.287 [INFO ] [el.core.internal.ModelRepositoryImpl] - Loading model 'Fib_Buttons.rules'
2018-05-07 08:21:33.341 [INFO ] [el.core.internal.ModelRepositoryImpl] - Loading model 'Paradox.rules'
2018-05-07 08:21:33.370 [INFO ] [el.core.internal.ModelRepositoryImpl] - Loading model 'Home.rules'
2018-05-07 08:21:39.497 [INFO ] [el.core.internal.ModelRepositoryImpl] - Loading model 'Unifi.rules'
2018-05-07 08:21:39.718 [INFO ] [thome.model.lsp.internal.ModelServer] - Started Language Server Protocol (LSP) service on port 5007
2018-05-07 08:21:39.871 [INFO ] [el.core.internal.ModelRepositoryImpl] - Loading model 'Ana.sitemap'
2018-05-07 08:21:39.891 [INFO ] [el.core.internal.ModelRepositoryImpl] - Loading model 'HomeR.sitemap'
2018-05-07 08:21:40.011 [INFO ] [el.core.internal.ModelRepositoryImpl] - Loading model 'Astro.things'
2018-05-07 08:21:40.109 [INFO ] [el.core.internal.ModelRepositoryImpl] - Loading model 'ntp.things'
2018-05-07 08:21:40.114 [INFO ] [el.core.internal.ModelRepositoryImpl] - Loading model 'SamsungTV.things'
2018-05-07 08:21:40.121 [INFO ] [el.core.internal.ModelRepositoryImpl] - Loading model 'Unifi.things'
2018-05-07 08:21:40.186 [WARN ] [mon.registry.AbstractManagedProvider] - Could not update element with key astro:sun:local in ManagedThingProvider
, because it does not exists.
2018-05-07 08:21:40.188 [WARN ] [mon.registry.AbstractManagedProvider] - Could not update element with key astro:moon:local in ManagedThingProvide
r, because it does not exists.
2018-05-07 08:21:40.344 [INFO ] [ing.zwave.handler.ZWaveSerialHandler] - Connecting to serial port '/dev/ttyACM0'
2018-05-07 08:21:40.449 [INFO ] [ing.zwave.handler.ZWaveSerialHandler] - Serial port is initialized
2018-05-07 08:21:40.488 [INFO ] [ve.internal.protocol.ZWaveController] - Starting ZWave controller
2018-05-07 08:21:40.489 [INFO ] [ve.internal.protocol.ZWaveController] - ZWave timeout is set to 5000ms. Soft reset is false.
2018-05-07 08:21:40.704 [INFO ] [thome.binding.astro.internal.job.Job] - Scheduled Astro event-jobs for thing astro:sun:local
2018-05-07 08:21:40.733 [INFO ] [ding.astro.handler.AstroThingHandler] - Scheduled Positional job astro:sun:local every 60 seconds
2018-05-07 08:21:40.774 [INFO ] [thome.binding.astro.internal.job.Job] - Scheduled Astro event-jobs for thing astro:moon:local
2018-05-07 08:21:40.786 [INFO ] [ding.astro.handler.AstroThingHandler] - Scheduled Positional job astro:moon:local every 60 seconds
2018-05-07 08:21:42.232 [INFO ] [penhab.io.transport.mqtt.MqttService] - MQTT Service initialization completed.
2018-05-07 08:21:42.233 [INFO ] [t.mqtt.internal.MqttBrokerConnection] - Starting MQTT broker connection 'homer'
2018-05-07 08:21:42.429 [INFO ] [nx.internal.connection.KNXConnection] - Established connection to KNX bus on 224.0.23.12:3671 in mode ROUTER.
2018-05-07 08:21:42.585 [INFO ] [basic.internal.servlet.WebAppServlet] - Started Basic UI at /basicui/app
2018-05-07 08:21:42.612 [INFO ] [arthome.ui.paper.internal.PaperUIApp] - Started Paper UI at /paperui
2018-05-07 08:21:43.645 [INFO ] [age.SerialApiGetInitDataMessageClass] - NODE 1: Node found
2018-05-07 08:21:43.645 [INFO ] [age.SerialApiGetInitDataMessageClass] - NODE 2: Node found
2018-05-07 08:21:43.645 [INFO ] [age.SerialApiGetInitDataMessageClass] - NODE 3: Node found
2018-05-07 08:21:43.646 [INFO ] [age.SerialApiGetInitDataMessageClass] - NODE 4: Node found
2018-05-07 08:21:43.646 [INFO ] [age.SerialApiGetInitDataMessageClass] - NODE 6: Node found
2018-05-07 08:21:43.646 [INFO ] [age.SerialApiGetInitDataMessageClass] - NODE 8: Node found
2018-05-07 08:21:43.647 [INFO ] [age.SerialApiGetInitDataMessageClass] - NODE 9: Node found
2018-05-07 08:21:43.647 [INFO ] [age.SerialApiGetInitDataMessageClass] - NODE 10: Node found
2018-05-07 08:21:43.647 [INFO ] [age.SerialApiGetInitDataMessageClass] - ZWave Controller using Controller API
2018-05-07 08:21:43.648 [INFO ] [age.SerialApiGetInitDataMessageClass] - ZWave Controller is Primary Controller
2018-05-07 08:21:43.648 [INFO ] [age.SerialApiGetInitDataMessageClass] - ------------Number of Nodes Found Registered to ZWave Controller---------
---
2018-05-07 08:21:43.651 [INFO ] [age.SerialApiGetInitDataMessageClass] - # Nodes = 8
2018-05-07 08:21:43.652 [INFO ] [age.SerialApiGetInitDataMessageClass] - -------------------------------------------------------------------------
---
2018-05-07 08:21:45.238 [INFO ] [b.core.service.AbstractActiveService] - NetworkUpsTools Refresh Service has been started
2018-05-07 08:21:45.414 [INFO ] [eather.internal.common.WeatherConfig] - ProviderConfig[providerName=WUNDERGROUND,apiKey=xxxx]
2018-05-07 08:21:45.415 [INFO ] [eather.internal.common.WeatherConfig] - LocationConfig[providerName=WUNDERGROUND,language=en,updateInterval=10,la
titude=xx.xxx,longitude=yy.yyy,woeid=<null>,locationId=HomeR,name=HomeR]
2018-05-07 08:21:46.114 [INFO ] [ui.habmin.internal.servlet.HABminApp] - Started HABmin servlet at /habmin
2018-05-07 08:21:46.133 [INFO ] [panel.internal.HABPanelDashboardTile] - Started HABPanel at /habpanel
2018-05-07 08:21:48.498 [INFO ] [ternal.scheduler.WeatherJobScheduler] - Starting and scheduling weatherJob-HomeR with interval of 10 minutes

There were at least one recent circular reference fixed. In the past, such fix boosted the startup speed. It could be the same today.
That is a good news. I have not yet installed this snapshot.

1 Like

It might also be due to this change.
In any case, this is good news, because I had the impression that startup got a lot worse in the past months actually.

1 Like