3.2.0 release. No rules starts ... (misbehaving Twinkly binding)

[OMR (Ole Morten Rønning)]

Edit:
The Karaf list helped me find the cause.
Coming to think of it, this was my first reboot after clearing away my Christmas tree.
New this year was the Twinkly add-on from the marketplace.
After disabling it, the rule engine started again, but no Items.
There were lots and lots of Resolved bundles in karaf, and after manually starting them all, all is well again.
My feeling is that when the Twinkly binding couldn’t find my disconnected (WiFi) Twinkly string, it halted the whole startup sequence … Will open a GitHub issue for that.

Help!
On 3.2.0 Release.
Edited a JSS script and saved with some errors.
After a while the java process hogged the CPU and crawled to a halt.
After a reboot, OH3 have lost all of my DSL rules, and the JSS rule does not start!

On the way up, all my rules loads (logging their loading), but does not show up in UI and non run.

2022-01-11 22:42:10.753 [INFO ] [el.core.internal.ModelRepositoryImpl] - Loading model 'keyfob.rules'
2022-01-11 22:42:11.720 [INFO ] [el.core.internal.ModelRepositoryImpl] - Loading model 'nanoleaf.rules'
2022-01-11 22:42:12.906 [INFO ] [el.core.internal.ModelRepositoryImpl] - Loading model 'fan.rules'
2022-01-11 22:42:13.490 [INFO ] [el.core.internal.ModelRepositoryImpl] - Loading model 'mi.rules'
2022-01-11 22:42:15.407 [INFO ] [el.core.internal.ModelRepositoryImpl] - Loading model 'wallSwitches.rules'
2022-01-11 22:42:18.944 [INFO ] [el.core.internal.ModelRepositoryImpl] - Loading model 'timeofday.rules'
2022-01-11 22:42:19.658 [INFO ] [el.core.internal.ModelRepositoryImpl] - Loading model 'scripts.rules'
2022-01-11 22:42:20.829 [INFO ] [el.core.internal.ModelRepositoryImpl] - Loading model 'harmony.rules'
2022-01-11 22:42:21.067 [INFO ] [el.core.internal.ModelRepositoryImpl] - Loading model 'hvac.rules'
2022-01-11 22:42:24.109 [INFO ] [el.core.internal.ModelRepositoryImpl] - Loading model 'deconz.rules'
2022-01-11 22:42:26.557 [INFO ] [el.core.internal.ModelRepositoryImpl] - Loading model 'update.rules'
2022-01-11 22:42:29.546 [INFO ] [el.core.internal.ModelRepositoryImpl] - Loading model 'ac.rules'
2022-01-11 22:42:29.829 [INFO ] [el.core.internal.ModelRepositoryImpl] - Loading model 'timer.rules'
2022-01-11 22:42:30.840 [INFO ] [el.core.internal.ModelRepositoryImpl] - Loading model 'motion.rules'

Also tried a full power cycle. Same result:

Should have been many DSL rules listed here. They are shown for 1s as greyed out before disappearing.

Can not find anything useful in the logs.

Any help on this greatly appreciated.

Edit: tried installing latest snapshot, and then downgraded to 3.2.0 again, and now all my items are Unitialized as well.
Tried restarting several times:

From Karaf, jna stuck in Starting:

213 │ Active   │  75 │ 3.2.0                 │ openHAB Core :: Bundles :: Thing XML
214 │ Active   │  80 │ 3.2.0                 │ openHAB Core :: Bundles :: Transformation Service
215 │ Active   │  80 │ 3.2.0                 │ openHAB Core :: Bundles :: UI
216 │ Active   │  80 │ 3.2.0                 │ openHAB Core :: Bundles :: UI Icon Support
217 │ Active   │  80 │ 3.2.0                 │ openHAB Core :: Bundles :: Voice
218 │ Active   │  80 │ 3.2.0                 │ openHAB UI :: Bundles :: Main UI
225 │ Active   │  80 │ 1.0.0.201802012106    │ org.osgi:org.osgi.service.jaxrs
226 │ Active   │  80 │ 1.5.0                 │ ThreeTen-Extra
227 │ Active   │  80 │ 1.27.0                │ SnakeYAML
228 │ Active   │  80 │ 2.1                   │ SI Units
229 │ Active   │  80 │ 2.1.0                 │ SI Quantities
230 │ Active   │  80 │ 4.2.1                 │ Stax2 API
231 │ Active   │  80 │ 2.1.2                 │ Units of Measurement Reference Implementation
232 │ Active   │  80 │ 2.1.0                 │ Units of Measurement Common Library for Java
233 │ Active   │  80 │ 1.4.18                │ XStream Core
234 │ Active   │  80 │ 3.2.0.202112051225    │ openHAB Add-ons :: Bundles :: TwinklyTree Binding
235 │ Starting │  80 │ 5.9.0                 │ jna
236 │ Resolved │  80 │ 5.9.0                 │ jna-platform
237 │ Resolved │  80 │ 1.6.2                 │ JavaMail API
238 │ Resolved │  80 │ 1.0.1                 │ IO.Socket Engine Client
239 │ Resolved │  80 │ 1.0.1                 │ IO.Socket Socket Client
240 │ Resolved │  80 │ 20180813.0.0          │ JSON in Java
241 │ Resolved │  80 │ 5.2.1                 │ nrjavaserial
242 │ Resolved │  80 │ 3.7.2                 │ Apache Commons Net
243 │ Resolved │  80 │ 3.8.1.1               │ Apache ServiceMix :: Bundles :: okhttp
244 │ Resolved │  80 │ 1.13.0.1              │ Apache ServiceMix :: Bundles :: okio
245 │ Resolved │  80 │ 2.0.0                 │ Californium (Cf) Core
246 │ Resolved │  80 │ 2.0.0                 │ Californium (Cf) Element Connector
247 │ Resolved │  80 │ 2.0.0                 │ Californium (Cf) OSGi
248

This is the log from when it fails:

2022-01-12 00:31:28.435 [INFO ] [.core.internal.i18n.I18nProviderImpl] - Time zone set to 'Europe/Oslo'.
2022-01-12 00:31:28.461 [INFO ] [.core.internal.i18n.I18nProviderImpl] - Location set to '59.9026989087956,10.495143905282024'.
2022-01-12 00:31:28.462 [INFO ] [.core.internal.i18n.I18nProviderImpl] - Locale set to 'en_NO'.
2022-01-12 00:31:28.465 [INFO ] [.core.internal.i18n.I18nProviderImpl] - Measurement system set to 'SI'.
2022-01-12 00:31:34.154 [WARN ] [core.karaf.internal.FeatureInstaller] - The binding add-on 'http1' does not exist - ignoring it.
2022-01-12 00:31:34.168 [WARN ] [core.karaf.internal.FeatureInstaller] - The binding add-on 'expire1' does not exist - ignoring it.
2022-01-12 00:31:34.185 [WARN ] [core.karaf.internal.FeatureInstaller] - The misc add-on 'market' does not exist - ignoring it.
2022-01-12 00:31:34.228 [WARN ] [core.karaf.internal.FeatureInstaller] - The ui add-on 'restdocs' does not exist - ignoring it.
2022-01-12 00:31:34.230 [WARN ] [core.karaf.internal.FeatureInstaller] - The ui add-on 'habmin' does not exist - ignoring it.
2022-01-12 00:31:34.232 [WARN ] [core.karaf.internal.FeatureInstaller] - The ui add-on 'paper' does not exist - ignoring it.
2022-01-12 00:31:35.274 [INFO ] [el.core.internal.ModelRepositoryImpl] - Loading model 'hue.items'
2022-01-12 00:31:36.117 [INFO ] [el.core.internal.ModelRepositoryImpl] - Loading model 'LAN.items'
2022-01-12 00:31:36.220 [INFO ] [el.core.internal.ModelRepositoryImpl] - Loading model 'Z-wave.items'
2022-01-12 00:31:36.593 [INFO ] [el.core.internal.ModelRepositoryImpl] - Loading model 'nanoleaf.items'
2022-01-12 00:31:36.617 [INFO ] [el.core.internal.ModelRepositoryImpl] - Loading model 'AC.items'
2022-01-12 00:31:36.633 [INFO ] [el.core.internal.ModelRepositoryImpl] - Loading model 'Tradfri.items'
2022-01-12 00:31:36.683 [INFO ] [el.core.internal.ModelRepositoryImpl] - Loading model 'mi.items'
2022-01-12 00:31:36.779 [INFO ] [el.core.internal.ModelRepositoryImpl] - Loading model 'Virtual.items'
2022-01-12 00:31:36.968 [INFO ] [el.core.internal.ModelRepositoryImpl] - Loading model 'deconz.items'
2022-01-12 00:31:36.990 [INFO ] [el.core.internal.ModelRepositoryImpl] - Loading model 'Squeezebox.items'
2022-01-12 00:31:37.033 [INFO ] [el.core.internal.ModelRepositoryImpl] - Loading model 'Groups.items'
2022-01-12 00:31:37.491 [INFO ] [el.core.internal.ModelRepositoryImpl] - Loading model 'influxdb.persist'
2022-01-12 00:31:37.845 [INFO ] [el.core.internal.ModelRepositoryImpl] - Loading model 'GTV7.sitemap'
2022-01-12 00:31:38.357 [INFO ] [el.core.internal.ModelRepositoryImpl] - Loading model 'nanoleaf.things'
2022-01-12 00:31:38.405 [INFO ] [el.core.internal.ModelRepositoryImpl] - Loading model 'squeeze.things'
2022-01-12 00:31:38.425 [INFO ] [el.core.internal.ModelRepositoryImpl] - Loading model 'denon.things'
2022-01-12 00:31:38.434 [INFO ] [el.core.internal.ModelRepositoryImpl] - Loading model 'deconz.things'
2022-01-12 00:31:38.442 [INFO ] [el.core.internal.ModelRepositoryImpl] - Loading model 'mail.things'
2022-01-12 00:31:38.451 [INFO ] [el.core.internal.ModelRepositoryImpl] - Loading model 'hue.things'
2022-01-12 00:31:38.459 [INFO ] [el.core.internal.ModelRepositoryImpl] - Loading model 'astro.things'
2022-01-12 00:31:40.833 [INFO ] [el.core.internal.ModelRepositoryImpl] - Loading model 'allOff.script'
2022-01-12 00:31:42.661 [INFO ] [el.core.internal.ModelRepositoryImpl] - Loading model 'masterBathOn.script'
2022-01-12 00:31:44.364 [INFO ] [el.core.internal.ModelRepositoryImpl] - Loading model 'masterBathOff.script'
2022-01-12 00:31:44.891 [INFO ] [.core.model.lsp.internal.ModelServer] - Started Language Server Protocol (LSP) service on port 5007
2022-01-12 00:31:45.038 [INFO ] [el.core.internal.ModelRepositoryImpl] - Loading model 'keyfob.rules'
2022-01-12 00:31:46.054 [INFO ] [el.core.internal.ModelRepositoryImpl] - Loading model 'nanoleaf.rules'
2022-01-12 00:31:47.176 [INFO ] [el.core.internal.ModelRepositoryImpl] - Loading model 'fan.rules'
2022-01-12 00:31:47.855 [INFO ] [el.core.internal.ModelRepositoryImpl] - Loading model 'mi.rules'
2022-01-12 00:31:49.828 [INFO ] [el.core.internal.ModelRepositoryImpl] - Loading model 'wallSwitches.rules'
2022-01-12 00:31:53.831 [INFO ] [el.core.internal.ModelRepositoryImpl] - Loading model 'timeofday.rules'
2022-01-12 00:31:54.584 [INFO ] [el.core.internal.ModelRepositoryImpl] - Loading model 'scripts.rules'
2022-01-12 00:31:55.789 [INFO ] [el.core.internal.ModelRepositoryImpl] - Loading model 'harmony.rules'
2022-01-12 00:31:56.014 [INFO ] [el.core.internal.ModelRepositoryImpl] - Loading model 'hvac.rules'
2022-01-12 00:31:59.176 [INFO ] [el.core.internal.ModelRepositoryImpl] - Loading model 'deconz.rules'
2022-01-12 00:32:01.515 [INFO ] [el.core.internal.ModelRepositoryImpl] - Loading model 'update.rules'
2022-01-12 00:32:04.374 [INFO ] [el.core.internal.ModelRepositoryImpl] - Loading model 'ac.rules'
2022-01-12 00:32:04.644 [INFO ] [el.core.internal.ModelRepositoryImpl] - Loading model 'timer.rules'
2022-01-12 00:32:05.649 [INFO ] [el.core.internal.ModelRepositoryImpl] - Loading model 'motion.rules'
2022-01-12 00:32:10.829 [WARN ] [el.core.internal.ModelRepositoryImpl] - Configuration model 'nanoleaf.things' is either empty or cannot be parsed correctly!
2022-01-12 00:32:10.839 [WARN ] [el.core.internal.ModelRepositoryImpl] - Configuration model 'denon.things' is either empty or cannot be parsed correctly!
2022-01-12 00:32:10.841 [WARN ] [el.core.internal.ModelRepositoryImpl] - Configuration model 'hue.things' is either empty or cannot be parsed correctly!
2022-01-12 00:32:13.384 [INFO ] [org.openhab.ui.internal.UIService   ] - Started UI on port 8080
2022-01-12 00:32:34.119 [WARN ] [core.karaf.internal.FeatureInstaller] - The binding add-on 'http1' does not exist - ignoring it.
2022-01-12 00:32:34.126 [WARN ] [core.karaf.internal.FeatureInstaller] - The binding add-on 'expire1' does not exist - ignoring it.
2022-01-12 00:32:34.132 [WARN ] [core.karaf.internal.FeatureInstaller] - The misc add-on 'market' does not exist - ignoring it.
2022-01-12 00:32:34.138 [WARN ] [core.karaf.internal.FeatureInstaller] - The ui add-on 'restdocs' does not exist - ignoring it.
2022-01-12 00:32:34.140 [WARN ] [core.karaf.internal.FeatureInstaller] - The ui add-on 'habmin' does not exist - ignoring it.
2022-01-12 00:32:34.141 [WARN ] [core.karaf.internal.FeatureInstaller] - The ui add-on 'paper' does not exist - ignoring it.

Nothing more happens ...

Last good startup:

2022-01-03 20:07:30.687 [INFO ] [.core.internal.i18n.I18nProviderImpl] - Time zone set to 'Europe/Oslo'.
2022-01-03 20:07:30.714 [INFO ] [.core.internal.i18n.I18nProviderImpl] - Location set to '59.9026989087956,10.495143905282024'.
2022-01-03 20:07:30.715 [INFO ] [.core.internal.i18n.I18nProviderImpl] - Locale set to 'en_NO'.
2022-01-03 20:07:30.717 [INFO ] [.core.internal.i18n.I18nProviderImpl] - Measurement system set to 'SI'.
2022-01-03 20:07:35.653 [WARN ] [.transport.servlet.ServletController] - Can't find the request for http://localhost:8080/rest/items/GTV7PowerConsumption's Observer
2022-01-03 20:07:36.296 [WARN ] [core.karaf.internal.FeatureInstaller] - The binding add-on 'http1' does not exist - ignoring it.
2022-01-03 20:07:36.346 [WARN ] [core.karaf.internal.FeatureInstaller] - The binding add-on 'expire1' does not exist - ignoring it.
2022-01-03 20:07:36.375 [WARN ] [core.karaf.internal.FeatureInstaller] - The misc add-on 'market' does not exist - ignoring it.
2022-01-03 20:07:36.411 [WARN ] [core.karaf.internal.FeatureInstaller] - The ui add-on 'restdocs' does not exist - ignoring it.
2022-01-03 20:07:36.414 [WARN ] [core.karaf.internal.FeatureInstaller] - The ui add-on 'habmin' does not exist - ignoring it.
2022-01-03 20:07:36.421 [WARN ] [core.karaf.internal.FeatureInstaller] - The ui add-on 'paper' does not exist - ignoring it.
2022-01-03 20:07:37.514 [INFO ] [el.core.internal.ModelRepositoryImpl] - Loading model 'hue.items'
2022-01-03 20:07:38.297 [INFO ] [el.core.internal.ModelRepositoryImpl] - Loading model 'LAN.items'
2022-01-03 20:07:38.416 [INFO ] [el.core.internal.ModelRepositoryImpl] - Loading model 'Z-wave.items'
2022-01-03 20:07:38.882 [INFO ] [el.core.internal.ModelRepositoryImpl] - Loading model 'nanoleaf.items'
2022-01-03 20:07:38.929 [INFO ] [el.core.internal.ModelRepositoryImpl] - Loading model 'AC.items'
2022-01-03 20:07:38.983 [INFO ] [el.core.internal.ModelRepositoryImpl] - Loading model 'Tradfri.items'
2022-01-03 20:07:39.073 [INFO ] [el.core.internal.ModelRepositoryImpl] - Loading model 'mi.items'
2022-01-03 20:07:39.158 [INFO ] [el.core.internal.ModelRepositoryImpl] - Loading model 'Virtual.items'
2022-01-03 20:07:39.325 [INFO ] [el.core.internal.ModelRepositoryImpl] - Loading model 'deconz.items'
2022-01-03 20:07:39.344 [INFO ] [el.core.internal.ModelRepositoryImpl] - Loading model 'Squeezebox.items'
2022-01-03 20:07:39.378 [INFO ] [el.core.internal.ModelRepositoryImpl] - Loading model 'Groups.items'
2022-01-03 20:07:39.650 [INFO ] [el.core.internal.ModelRepositoryImpl] - Loading model 'influxdb.persist'
2022-01-03 20:07:40.001 [INFO ] [el.core.internal.ModelRepositoryImpl] - Loading model 'GTV7.sitemap'
2022-01-03 20:07:40.465 [INFO ] [el.core.internal.ModelRepositoryImpl] - Loading model 'nanoleaf.things'
2022-01-03 20:07:40.503 [INFO ] [el.core.internal.ModelRepositoryImpl] - Loading model 'squeeze.things'
2022-01-03 20:07:40.526 [INFO ] [el.core.internal.ModelRepositoryImpl] - Loading model 'denon.things'
2022-01-03 20:07:40.530 [INFO ] [el.core.internal.ModelRepositoryImpl] - Loading model 'deconz.things'
2022-01-03 20:07:40.540 [INFO ] [el.core.internal.ModelRepositoryImpl] - Loading model 'mail.things'
2022-01-03 20:07:40.550 [INFO ] [el.core.internal.ModelRepositoryImpl] - Loading model 'hue.things'
2022-01-03 20:07:40.557 [INFO ] [el.core.internal.ModelRepositoryImpl] - Loading model 'astro.things'
2022-01-03 20:07:43.307 [INFO ] [el.core.internal.ModelRepositoryImpl] - Loading model 'allOff.script'
2022-01-03 20:07:45.040 [INFO ] [el.core.internal.ModelRepositoryImpl] - Loading model 'masterBathOn.script'
2022-01-03 20:07:46.286 [INFO ] [el.core.internal.ModelRepositoryImpl] - Loading model 'masterBathOff.script'
2022-01-03 20:07:47.292 [INFO ] [.core.model.lsp.internal.ModelServer] - Started Language Server Protocol (LSP) service on port 5007
2022-01-03 20:07:47.528 [INFO ] [el.core.internal.ModelRepositoryImpl] - Loading model 'keyfob.rules'
2022-01-03 20:07:48.409 [INFO ] [el.core.internal.ModelRepositoryImpl] - Loading model 'nanoleaf.rules'
2022-01-03 20:07:49.462 [INFO ] [el.core.internal.ModelRepositoryImpl] - Loading model 'fan.rules'
2022-01-03 20:07:50.022 [INFO ] [el.core.internal.ModelRepositoryImpl] - Loading model 'mi.rules'
2022-01-03 20:07:51.867 [INFO ] [el.core.internal.ModelRepositoryImpl] - Loading model 'wallSwitches.rules'
2022-01-03 20:07:56.306 [INFO ] [el.core.internal.ModelRepositoryImpl] - Loading model 'timeofday.rules'
2022-01-03 20:07:57.130 [INFO ] [el.core.internal.ModelRepositoryImpl] - Loading model 'scripts.rules'
2022-01-03 20:07:58.283 [INFO ] [el.core.internal.ModelRepositoryImpl] - Loading model 'harmony.rules'
2022-01-03 20:07:58.549 [INFO ] [el.core.internal.ModelRepositoryImpl] - Loading model 'hvac.rules'
2022-01-03 20:08:01.744 [INFO ] [el.core.internal.ModelRepositoryImpl] - Loading model 'deconz.rules'
2022-01-03 20:08:04.253 [INFO ] [el.core.internal.ModelRepositoryImpl] - Loading model 'update.rules'
2022-01-03 20:08:07.263 [INFO ] [el.core.internal.ModelRepositoryImpl] - Loading model 'ac.rules'
2022-01-03 20:08:07.546 [INFO ] [el.core.internal.ModelRepositoryImpl] - Loading model 'timer.rules'
2022-01-03 20:08:08.581 [INFO ] [el.core.internal.ModelRepositoryImpl] - Loading model 'motion.rules'
2022-01-03 20:08:13.797 [WARN ] [el.core.internal.ModelRepositoryImpl] - Configuration model 'nanoleaf.things' is either empty or cannot be parsed correctly!
2022-01-03 20:08:13.806 [WARN ] [el.core.internal.ModelRepositoryImpl] - Configuration model 'denon.things' is either empty or cannot be parsed correctly!
2022-01-03 20:08:13.817 [WARN ] [el.core.internal.ModelRepositoryImpl] - Configuration model 'hue.things' is either empty or cannot be parsed correctly!
2022-01-03 20:08:16.093 [WARN ] [.transport.servlet.ServletController] - Can't find the request for http://localhost:8080/rest/items/GTV7PowerConsumption's Observer
2022-01-03 20:08:16.442 [INFO ] [org.openhab.ui.internal.UIService   ] - Started UI on port 8080
2022-01-03 20:08:18.203 [WARN ] [ty.util.ssl.SslContextFactory.config] - Trusting all certificates configured for Client@36d413c3[provider=null,keyStore=null,trustStore=null]
2022-01-03 20:08:18.204 [WARN ] [ty.util.ssl.SslContextFactory.config] - No Client EndPointIdentificationAlgorithm configured for Client@36d413c3[provider=null,keyStore=null,trustStore=null]
2022-01-03 20:08:20.494 [INFO ] [ternal.dhcp.DHCPPacketListenerServer] - DHCP request packet listener online
2022-01-03 20:08:23.113 [INFO ] [g.discovery.internal.PersistentInbox] - Added new thing 'squeezebox:squeezeboxserver:DC536DCE-16D6-415B-A214-2239E4DDAA68' to inbox.
2022-01-03 20:08:24.083 [INFO ] [.onkyo.internal.handler.OnkyoHandler] - Using configuration: ipAddress = 192.168.1.30, port = 60128, udn = 15b0ac73-adac-73b9-7ba5-7309adb9a41d, refreshInterval = 0, volumeLimit = 100, volumeScale = 1.0
2022-01-03 20:08:24.207 [INFO ] [rnal.service.RemoteControllerService] - Using WebSocket interface
2022-01-03 20:08:24.322 [INFO ] [rnal.service.RemoteControllerService] - Using SecureWebSocket interface
2022-01-03 20:08:26.402 [INFO ] [io.openhabcloud.internal.CloudClient] - Connected to the openHAB Cloud service (UUID = 39a3b62f-b1a7-4fb1-a78b-2d866ac0c046, base URL = http://localhost:8080)
2022-01-03 20:08:28.853 [INFO ] [ab.ui.habpanel.internal.HABPanelTile] - Started HABPanel at /habpanel
2022-01-03 20:08:32.391 [INFO ] [zwave.handler.ZWaveControllerHandler] - Attempting to add listener when controller is null
2022-01-03 20:08:36.252 [WARN ] [core.karaf.internal.FeatureInstaller] - The binding add-on 'http1' does not exist - ignoring it.
2022-01-03 20:08:36.257 [WARN ] [core.karaf.internal.FeatureInstaller] - The binding add-on 'expire1' does not exist - ignoring it.
2022-01-03 20:08:36.272 [WARN ] [core.karaf.internal.FeatureInstaller] - The misc add-on 'market' does not exist - ignoring it.
2022-01-03 20:08:36.279 [WARN ] [core.karaf.internal.FeatureInstaller] - The ui add-on 'restdocs' does not exist - ignoring it.
2022-01-03 20:08:36.282 [WARN ] [core.karaf.internal.FeatureInstaller] - The ui add-on 'habmin' does not exist - ignoring it.
2022-01-03 20:08:36.283 [WARN ] [core.karaf.internal.FeatureInstaller] - The ui add-on 'paper' does not exist - ignoring it.
2022-01-03 20:08:37.821 [INFO ] [ve.internal.protocol.ZWaveController] - Starting ZWave controller
2022-01-03 20:08:37.822 [INFO ] [ve.internal.protocol.ZWaveController] - ZWave timeout is set to 5000ms. Soft reset is false.
2022-01-03 20:08:40.754 [WARN ] [nal.protocol.ZWaveTransactionManager] - NODE 94: Not initialized (ie node unknown), ignoring message.
2022-01-03 20:08:40.820 [WARN ] [nal.protocol.ZWaveTransactionManager] - NODE 94: Not initialized (ie node unknown), ignoring message.
2022-01-03 20:08:41.375 [WARN ] [nal.protocol.ZWaveTransactionManager] - NODE 94: Not initialized (ie node unknown), ignoring message.
2022-01-03 20:08:41.383 [WARN ] [nal.protocol.ZWaveTransactionManager] - NODE 94: Not initialized (ie node unknown), ignoring message.
2022-01-03 20:08:41.384 [WARN ] [nal.protocol.ZWaveTransactionManager] - NODE 94: Not initialized (ie node unknown), ignoring message.
2022-01-03 20:08:41.447 [WARN ] [nal.protocol.ZWaveTransactionManager] - NODE 94: Not initialized (ie node unknown), ignoring message.
2022-01-03 20:08:41.467 [WARN ] [nal.protocol.ZWaveTransactionManager] - NODE 94: Not initialized (ie node unknown), ignoring message.
2022-01-03 20:08:41.983 [WARN ] [nal.protocol.ZWaveTransactionManager] - NODE 100: Not initialized (ie node unknown), ignoring message.
2022-01-03 20:09:45.195 [INFO ] [openhab.model.script.Rules.TimeOfDay] - Today is a default day.
2022-01-03 20:09:46.533 [INFO ] [org.openhab.core.model.script.System] - (update.rules) System started (or a rule changed)
2022-01-03 20:09:46.555 [INFO ] [e.automation.internal.RuleEngineImpl] - Rule engine started.
2022-01-03 20:09:46.586 [INFO ] [g.openhab.core.model.script.SoundVol] - SqueezeBoxTouchVolume State=18
2022-01-03 20:09:46.592 [INFO ] [g.openhab.core.model.script.SoundVol] - SqueezeBoxTouchVolume State=18
2022-01-03 20:09:50.471 [WARN ] [.internal.OpenhabGraalJSScriptEngine] - Failed to retrieve script script dependency listener from engine bindings. Script dependency tracking will be disabled.
2022-01-03 20:09:54.096 [INFO ] [org.openhab.automation.script       ] - Rule starting
2022-01-03 20:09:57.992 [INFO ] [org.openhab.core.model.script.motion] - StairsMovement State=ON
2022-01-03 20:09:57.996 [INFO ] [org.openhab.core.model.script.Motion] - StairsMovement.state=ON
2022-01-03 20:10:07.738 [WARN ] [nal.protocol.ZWaveTransactionManager] - NODE 84: Not initialized (ie node unknown), ignoring message.
2022-01-03 20:10:09.085 [INFO ] [org.openhab.core.model.script.motion] - ServerRoomMovement State=ON
2022-01-03 20:10:09.093 [INFO ] [org.openhab.core.model.script.Motion] - ServerRoomMovement.state=ON
2022-01-03 20:10:09.196 [INFO ] [org.openhab.core.model.script.motion] - DenMovement State=ON
2022-01-03 20:10:09.202 [INFO ] [org.openhab.core.model.script.Motion] - DenMovement.state=ON
2022-01-03 20:10:09.207 [INFO ] [org.openhab.core.model.script.Motion] - House guests. Do nothing
2022-01-03 20:10:15.872 [INFO ] [openhab.model.script.Rules.TimeOfDay] - The current time of day is EVENING
2022-01-03 20:10:47.231 [INFO ] [org.openhab.core.model.script.timers] - vWatchDogTimer  OFF
2022-01-03 20:10:47.258 [WARN ] [o.internal.handler.AstroThingHandler] - The Astro-Binding is a read-only binding and can not handle commands
2022-01-03 20:10:47.288 [WARN ] [o.internal.handler.AstroThingHandler] - The Astro-Binding is a read-only binding and can not handle commands
2022-01-03 20:10:47.371 [INFO ] [openhab.model.script.Rules.TimeOfDay] - Today is a default day.
2022-01-03 20:10:47.527 [INFO ] [openhab.model.script.Rules.TimeOfDay] - Moved Default_Morning to today.
2022-01-03 20:10:47.551 [INFO ] [openhab.model.script.Rules.TimeOfDay] - Moved Default_Day to today.
2022-01-03 20:10:47.553 [INFO ] [openhab.model.script.Rules.TimeOfDay] - Moved Default_Evening to today.
2022-01-03 20:10:47.557 [INFO ] [openhab.model.script.Rules.TimeOfDay] - Moved Default_Night to today.
2022-01-03 20:10:47.560 [INFO ] [openhab.model.script.Rules.TimeOfDay] - Moved Default_Bed to today.
2022-01-03 20:11:17.665 [INFO ] [openhab.model.script.Rules.TimeOfDay] - The current time of day is EVENING

[rossko57]

@OMR

2022-01-03 20:07:36.296 [WARN ] [core.karaf.internal.FeatureInstaller] - The binding add-on 'http1' does not exist - ignoring it.

You’ve got some legacy install options inherited from OH2, probably in your addons.cfg file. This is probably giving you a performance hit every so often, as it tries to install things that can’t be installed.
I doubt it relates to your rule no-go directly, but it might make it worse by the performance hit.

@OMR

2022-01-03 20:09:57.992 [INFO ] [org.openhab.core.model.script.motion] - StairsMovement State=ON
2022-01-03 20:09:57.996 [INFO ] [org.openhab.core.model.script.Motion] - StairsMovement.state=ON

This looks a bit like near-duplicate rules.
Agan, I doubt it relates to your rule no-go, but it might

@OMR

2022-01-03 20:10:47.258 [WARN ] [o.internal.handler.AstroThingHandler] - The Astro-Binding is a read-only binding and can not handle commands

Something is sending commands to some Item linked to Astro, which is a weird thing to do, but harmless.

@OMR

Edited a JSS script and saved with some errors.
After a while the java process hogged the CPU and crawled to a halt.

This is being seen by others

JSscripting: Error message "Java.lang.OutOfMemoryError: Java heap space"

@jpg0 after a while when testing new JSscripting rules, OH is running out of memory and CPU load for openhab goes up to 100% Error messages: 2021-12-29 22:12:59.868 [WARN ] [org.eclipse.jetty.server.HttpChannel] - /rest/rules/SystemReadLog java.lang.OutOfMemoryError: Java heap space 2021-12-29 22:14:35.128 [WARN ] [ab.core.internal.events.EventHandler] - Dispatching event to subscriber 'org.openhab.core.io.monitor.internal.EventLogger@16f740b' takes more than 5000ms. 2021-12-29 22:19:26.790…

@OMR

After a reboot, OH3 have lost all of my DSL rules, and the JSS rule does not start!

But this is unique to you. Did you reboot by power off/on? I’m thinking corrupted filestore.

Have you many JSS rules? I’m thinking about removal of all JSS JSONDB

[OMR (Ole Morten Rønning)]

Thanks for helping! Figured it out and edited the issue …

[rossko57]

You do have lots of other tidying up to do, I wouldn’t let that slide if I were you.
Might help-

[Solved] OH3: How to get rid of old bindings?

Hi everyone, I migrated vom OH2.5 to OH3 via openHABian - and so far most of the things work fine. But I discovered these lines in the logs: 2020-12-23 17:12:59.430 [WARN ] [core.karaf.internal.FeatureInstaller] - The binding add-on 'exec1' does not exist - ignoring it. 2020-12-23 17:12:59.438 [WARN ] [core.karaf.internal.FeatureInstaller] - The binding add-on 'http1' does not exist - ignoring it. 2020-12-23 17:12:59.461 [WARN ] [core.karaf.internal.FeatureInstaller] - The binding add-on 's…

[OMR (Ole Morten Rønning)]

Sure. Got inspired to do that cleanup tonight.
Thanks again for helping out. Sorry you wasted some time, but I posted back as soon as I could.

[rossko57]

@OMR

Sorry you wasted some time

Not at all! I wouldn’t have guessed at a binding culprit, and if you have found something amiss with it that will benefit others.

It is just possible that the HTTP requests for non-existing addons waiting for a long timeout would have a knock-on effect, like clag up a binding using WiFi as well …

[OMR (Ole Morten Rønning)]

Indeed.
And lesson learned from this:

When panic strikes and the cold sweat starts running:

• do a karaf list and check what is Active (running), stuck in Starting and Resolved (=not started)
  In this case the offending binding/add-on was the last one Active.