OH4: Long startup time on Win10, difficulty diagnosing

[Dave_Baldwin]

HW - Toshiba Satellite P755 laptop, core i7 4core @ 2.2 GHz, 6 GB RAM
OS - Windows 10 Home
Java version - Oracle v17.0.10
Installation/Upgrade method - original install around OH ~3.0? upgraded via batch file few times since then, most recently yesterday from 3.4.0 to 3.4.5 and then from 3.4.5 to 4.1.2

I am experiencing very long startup times on my newly-upgraded OH4.1.2 system. Specifically what I am seeing is that the startup level gets very quickly to 70, and then hangs out there for ~9 or more minutes before finally getting to 100. During this time, what I see in the Things dialog is that numerous Things are labeled NOT_YET_READY, while others are ONLINE.
Previously on exactly the same hardware, OH 3.4.0 would start up in under a minute, I believe, so this is a big difference. (I don’t have a test or pre-production system, so can’t verify)

I have reviewed several other similar topics, most importantly:

OH 4.1.1 startup takes more than an hour

No. The Usb finder and resp. the Process finder look for hardware attached to, resp. processes running on, the local PC, so their scans are fast and without LAN involvement, so we deemed it not necessary to disable them. I will check. EDIT: apparently ‘addons.cfg’ has absolutely no official doc for it. Or? So rather than just editing an existing file (which I could easily do), it would require creating a complete new page and linking it into the table of contents etc. => WDYT?

I have seen over numerous OH restarts in the openhab.log file that numerous Things take a long time to be initialized - namely handler initialization for network:pingdevice:* things can take ~15 seconds between successive handler initializations. (I have a lot of these), and individual HTTP handlers were taking a while, too. This to me seems quite suspiciously long (maybe I’m wrong), so I did the following, with results noted:

• removed Network binding → restarted OH → noted that network Things went ERROR:HANDLER → startup time did not decrease
• set all network Things to disabled → restarted OH → noted that startup time went to about 90 seconds (still longer than I’d like, but close to acceptable)
• re-installed Network binding, but left all network Things disabled → restarted OH → noted that startup time increased to about 180 seconds.
• uninstalled HTTP binding, and disabled all HTTP Things → restarted OH → no improvement in startup time, still about 3 minutes

My system is not particularly big, based on other discussions I have seen in the forum: 618 items, 182 things.

Almost all of my configuration is now UI-based, with the exception of a couple of .things text files containing Modbus bridges that seemed easier to keep in text files. The Modbus Things are not slow to come ONLINE, so this doesn’t seem to me to be a problem.

I am linking to DEBUG level logs (only org.openhab at that level for now) from a startup where the HTTP binding had been removed, and all HTTP Things were disabled. well as the output from the console ‘diag’ command during the same startup. I see numerous missing references in the diag output, but I’m not sure how to chase them down further to resolve any such issues, nor am I sure whether they really matter to OH performance or not.

Link to debug log (17 MB):

Google Drive: Sign-in

DIAG OUTPUT

openhab> diag
openHAB Core :: Bundles :: Core (154)
-------------------------------------
Status: Waiting
Declarative Services
org.openhab.core.internal.auth.AuthenticationManagerImpl (7)
org.openhab.core.internal.i18n.I18nProviderImpl (13)
org.openhab.core.internal.service.WatchServiceFactoryImpl (34)
org.openhab.core.internal.scheduler.PeriodicSchedulerImpl (28)
org.openhab.core.events.system.SystemEventFactory (6)
org.openhab.core.internal.items.ManagedMetadataProviderImpl (19)
  missing references: $000
org.openhab.core.internal.service.WatchServiceImpl (35)
org.openhab.core.internal.scheduler.DelegatedSchedulerImpl (27)
org.openhab.core.library.CoreItemFactory (38)
org.openhab.core.items.ManagedItemProvider (36)
  missing references: $000
org.openhab.core.internal.events.OSGiEventManager (11)
org.openhab.core.internal.events.OSGiEventPublisher (12)
org.openhab.core.internal.service.CommandDescriptionServiceImpl (31)
org.openhab.core.internal.auth.ManagedUserProvider (8)
  missing references: $000
org.openhab.core.internal.items.ItemStateConverterImpl (17)
org.openhab.core.items.events.ItemEventFactory (37)
org.openhab.core.internal.service.BundleResolverImpl (30)
org.openhab.core.internal.library.unit.CurrencyService (23)
org.openhab.core.common.ThreadPoolManager (5)
org.openhab.core.internal.auth.UserRegistryImpl (9)
org.openhab.core.internal.scheduler.SchedulerImpl (29)
org.openhab.core.internal.common.SafeCallerImpl (10)
org.openhab.core.internal.items.ExpireManager (14)
org.openhab.core.internal.library.unit.LocaleBasedCurrencyProvider (25)
org.openhab.core.internal.service.ReadyServiceImpl (32)
org.openhab.core.internal.items.MetadataCommandDescriptionProvider (20)
org.openhab.core.service.StartLevelService (40)
org.openhab.core.internal.library.unit.FixedCurrencyProvider (24)
org.openhab.core.internal.scheduler.CronSchedulerImpl (26)
org.openhab.core.internal.items.ItemUpdater (18)
org.openhab.core.internal.items.MetadataRegistryImpl (21)
org.openhab.core.internal.items.ItemBuilderFactoryImpl (15)
org.openhab.core.internal.items.ItemRegistryImpl (16)
org.openhab.core.net.NetUtil (39)
org.openhab.core.internal.items.MetadataStateDescriptionFragmentProvider (22)
org.openhab.core.internal.service.StateDescriptionServiceImpl (33)


openHAB Core :: Bundles :: Marketplace Add-on Services (156)
------------------------------------------------------------
Status: Waiting
Declarative Services
org.openhab.core.addon.marketplace.internal.community.CommunityMarketplaceAddonService (51)
  missing references: $002
org.openhab.core.addon.marketplace.internal.community.CommunityBlockLibaryAddonHandler (49)
  missing references: $000
org.openhab.core.addon.marketplace.internal.community.CommunityBundleAddonHandler (50)
org.openhab.core.addon.marketplace.internal.automation.MarketplaceRuleTemplateProvider (48)
  missing references: $000
org.openhab.core.addon.marketplace.internal.json.JsonAddonService (54)
  missing references: $001
org.openhab.core.addon.marketplace.internal.community.CommunityRuleTemplateAddonHandler (52)
  missing references: $000
org.openhab.core.addon.marketplace.internal.community.CommunityUIWidgetAddonHandler (53)
  missing references: $000


openHAB Core :: Bundles :: OAuth2Client (160)
---------------------------------------------
Status: Waiting
Declarative Services
org.openhab.core.auth.oauth2client.internal.OAuthFactoryImpl (65)
  missing references: $001
org.openhab.core.auth.oauth2client.internal.cipher.SymmetricKeyCipher (67)
org.openhab.core.auth.oauth2client.internal.OAuthStoreHandlerImpl (66)
  missing references: $000


openHAB Core :: Bundles :: Automation (161)
-------------------------------------------
Status: Waiting
Declarative Services
org.openhab.core.automation.internal.provider.AutomationResourceBundlesTracker (81)
org.openhab.core.automation.internal.module.factory.EphemerisModuleHandlerFactory (75)
org.openhab.core.automation.ManagedRuleProvider (68)
  missing references: $000
org.openhab.core.automation.internal.type.ModuleTypeRegistryImpl (88)
org.openhab.core.automation.internal.RuleEngineImpl (70)
  missing references: $002
org.openhab.core.automation.internal.commands.AutomationCommandsPluggable (73)
  missing references: $004
org.openhab.core.automation.internal.provider.i18n.ModuleTypeI18nServiceImpl (86)
org.openhab.core.automation.internal.module.provider.AnnotatedActionModuleTypeProvider (77)
org.openhab.core.automation.internal.module.handler.TimerModuleHandlerFactory (76)
org.openhab.core.automation.internal.provider.file.ModuleTypeFileProviderWatcher (84)
org.openhab.core.automation.events.AutomationEventFactory (69)
org.openhab.core.automation.internal.RuleEventFactory (71)
org.openhab.core.automation.internal.RuleRegistryImpl (72)
org.openhab.core.automation.internal.parser.gson.RuleGSONParser (79)
org.openhab.core.automation.internal.parser.gson.TemplateGSONParser (80)
org.openhab.core.automation.internal.module.factory.CoreModuleHandlerFactory (74)
org.openhab.core.automation.thingsupport.AnnotatedThingActionModuleTypeProvider (89)
org.openhab.core.automation.internal.parser.gson.ModuleTypeGSONParser (78)
org.openhab.core.automation.internal.provider.ModuleTypeResourceBundleProvider (82)
org.openhab.core.automation.internal.provider.file.TemplateFileProviderWatcher (85)
org.openhab.core.automation.internal.template.RuleTemplateRegistry (87)
org.openhab.core.automation.internal.provider.TemplateResourceBundleProvider (83)


openHAB Core :: Bundles :: Automation Media Modules (162)
---------------------------------------------------------
Status: Waiting
Declarative Services
org.openhab.core.automation.module.media.internal.MediaScriptScopeProvider (92)
  missing references: VoiceManager
org.openhab.core.automation.module.media.internal.MediaModuleHandlerFactory (91)
  missing references: $001
org.openhab.core.automation.module.media.internal.MediaActionTypeProvider (90)


openHAB Core :: Bundles :: Automation Script Modules (163)
----------------------------------------------------------
Status: Waiting
Declarative Services
org.openhab.core.automation.module.script.internal.factory.ScriptModuleHandlerFactory (102)
org.openhab.core.automation.module.script.internal.ScriptEngineManagerImpl (97)
org.openhab.core.automation.module.script.internal.defaultscope.DefaultScriptScopeProvider (101)
  missing references: $001
org.openhab.core.automation.module.script.internal.ScriptExtensionManager (98)
org.openhab.core.automation.module.script.internal.action.ScriptActionScriptScopeProvider (99)
org.openhab.core.automation.module.script.profile.ScriptProfileFactory (104)
org.openhab.core.automation.module.script.LifecycleScriptExtensionProvider (93)
org.openhab.core.automation.module.script.internal.action.ScriptExecutionImpl (100)
org.openhab.core.automation.module.script.internal.provider.ScriptModuleTypeProvider (103)
org.openhab.core.automation.module.script.internal.ScriptEngineFactoryBundleTracker (96)
org.openhab.core.automation.module.script.ScriptTransformationServiceFactory (95)
  missing references: $000


openHAB Core :: Bundles :: Automation REST API (165)
----------------------------------------------------
Status: Waiting
Declarative Services
org.openhab.core.automation.rest.internal.TemplateResource (114)
org.openhab.core.automation.rest.internal.ThingActionsResource (115)
org.openhab.core.automation.rest.internal.ModuleTypeResource (112)
org.openhab.core.automation.rest.internal.RuleResource (113)
  missing references: $001, $003


openHAB Core :: Bundles :: Configuration Discovery (167)
--------------------------------------------------------
Status: Waiting
Declarative Services
org.openhab.core.config.discovery.internal.AutomaticInboxProcessor (127)
  missing references: $000, $001, $002
org.openhab.core.config.discovery.internal.console.DiscoveryConsoleCommandExtension (130)
org.openhab.core.config.discovery.inbox.events.InboxEventFactory (126)
org.openhab.core.config.discovery.internal.PersistentInbox (129)
  missing references: $000, $002, $003, $004
org.openhab.core.config.discovery.internal.DiscoveryServiceRegistryImpl (128)
org.openhab.core.config.discovery.internal.console.InboxConsoleCommandExtension (131)
  missing references: $000


openHAB Core :: Bundles :: Console (174)
----------------------------------------
Status: Waiting
Declarative Services
org.openhab.core.io.console.internal.extension.SendConsoleCommandExtension (141)
org.openhab.core.io.console.internal.extension.UpdateConsoleCommandExtension (143)
org.openhab.core.io.console.internal.extension.UserConsoleCommandExtension (144)
org.openhab.core.io.console.internal.extension.ItemConsoleCommandExtension (139)
  missing references: $001
org.openhab.core.io.console.internal.extension.MetadataConsoleCommandExtension (140)
org.openhab.core.io.console.internal.extension.StatusConsoleCommandExtension (142)


openHAB Core :: Bundles :: Monitor (179)
----------------------------------------
Status: Waiting
Declarative Services
org.openhab.core.io.monitor.internal.EventLogger (154)
org.openhab.core.io.monitor.internal.DefaultMetricsRegistration (153)
  missing references: $002


openHAB Core :: Bundles :: REST Interface :: Core (184)
-------------------------------------------------------
Status: Waiting
Declarative Services
org.openhab.core.io.rest.core.internal.thing.ThingResource (184)
  missing references: $001, $004, $005, $006, $010, $011, $012, $013, $014, $015, $016
org.openhab.core.io.rest.core.internal.link.ItemChannelLinkResource (179)
  missing references: $001, $002, $003, $004, $005
org.openhab.core.io.rest.core.internal.MediaTypeExtension (171)
org.openhab.core.io.rest.core.internal.JSONResponseExceptionMapper (170)
org.openhab.core.io.rest.core.internal.item.MetadataSelectorMatcher (178)
org.openhab.core.io.rest.core.internal.channel.ChannelTypeResource (173)
  missing references: $000, $003
org.openhab.core.io.rest.core.internal.service.ConfigurableServiceResource (182)
org.openhab.core.io.rest.core.config.ConfigurationService (169)
org.openhab.core.io.rest.core.internal.thing.ThingTypeResource (185)
  missing references: $000, $001, $004
org.openhab.core.io.rest.core.internal.tag.TagResource (183)
  missing references: $001, $002
org.openhab.core.io.rest.core.internal.profile.ProfileTypeResource (181)
  missing references: $000, $002
org.openhab.core.io.rest.core.internal.discovery.DiscoveryResource (175)
org.openhab.core.io.rest.core.internal.discovery.InboxResource (176)
  missing references: $000
org.openhab.core.io.rest.core.internal.addons.AddonResource (172)
org.openhab.core.io.rest.core.internal.persistence.PersistenceResource (180)
  missing references: $002, $003, $004
org.openhab.core.io.rest.core.internal.config.ConfigDescriptionResource (174)
org.openhab.core.io.rest.core.internal.item.ItemResource (177)
  missing references: $005, $008


openHAB Core :: Bundles :: REST mDNS Announcer (185)
----------------------------------------------------
Status: Waiting
Declarative Services
org.openhab.core.io.rest.mdns.internal.MDNSAnnouncer (186)
  missing references: MDNSService


openHAB Core :: Bundles :: Sitemap REST Interface (186)
-------------------------------------------------------
Status: Waiting
Declarative Services
org.openhab.core.io.rest.sitemap.SitemapSubscriptionService (187)
  missing references: $001
org.openhab.core.io.rest.sitemap.internal.SitemapResource (188)
  missing references: $000, $002


openHAB Core :: Bundles :: Transformation REST Interface (189)
--------------------------------------------------------------
Status: Waiting
Declarative Services
org.openhab.core.io.rest.transform.internal.TransformationResource (193)
  missing references: $000, $001


openHAB Core :: Bundles :: UI REST Interface (190)
--------------------------------------------------
Status: Waiting
Declarative Services
org.openhab.core.io.rest.ui.internal.UIResource (194)
  missing references: $000, $001


openHAB Core :: Bundles :: Voice REST Interface (191)
-----------------------------------------------------
Status: Waiting
Declarative Services
org.openhab.core.io.rest.voice.internal.VoiceResource (195)
  missing references: $002


openHAB Add-ons :: Bundles :: Transformation Service :: Map (322)
-----------------------------------------------------------------
Status: Waiting
Declarative Services
org.openhab.transform.map.internal.profiles.MapTransformationProfileFactory (4)
  missing references: TransformationService
org.openhab.transform.map.internal.MapTransformationService (3)
  missing references: $000

Any help in diagnosing these slow startup issues would really be appreciated!