Hello,
what is wrong with this transformation?
DateTime date_actualntptimestamp "Date [SCRIPT:graaljs:timetotimestamp.script:%s]" <time> {channel="ntp:ntp:smarthome:dateTime"}
timetotimestamp.script
(function(i) {
var date = new Date(i);
var response = date.getTime();
return response.toString();
}) (input)
there is no error but it’s not correctly transformed
this is the result
SCRIPT:graaljs:timetotimestamp.script:2023-05-25T23:06:26.595+02:00
DateTime date_actualntptimestamp "Date [JS(timetotimestamp.script):%s]" <time> {channel="ntp:ntp:smarthome:dateTime"}
My fault.
Now the output is
JS:timetotimestamp.script:2023-05-25T23:08:31.920+02:00
See my edit.
Found it out 
You can (and probably should) also rename the file to .js
Thanks for clarifying, than indeed I misinterpreted the documentation.
I think the easiest solution for me would be using a Number item without unit, as I did in the past. But a profile is also a good idea.
M3 did not turn out well for me …
No rules were executed! Tried rebooting several times. Could control items, but no rules triggered.
Downgraded to M2 and all was well again.
omr@shs2:~$ uname -a
Linux shs2 5.15.0-72-generic #79-Ubuntu SMP Wed Apr 19 08:22:18 UTC 2023 x86_64 x86_64 x86_64 GNU/Linux
omr@shs2:~$ java --version
openjdk 17.0.7 2023-04-18
OpenJDK Runtime Environment (build 17.0.7+7-Ubuntu-0ubuntu122.04.2)
OpenJDK 64-Bit Server VM (build 17.0.7+7-Ubuntu-0ubuntu122.04.2, mixed mode, sharing)
Thanks @hmerk, I’ll look into it because the behaviour you expected is the way it should have worked.
For now: Even though it says downgrade it will still perform the correct steps.
what rules language? How many rules, how triggered?? UI rules or file?
more info please
Files only. DSL and js.
Will dig up logs over the weekend.
After converting from M2 to M3 I have these WARN’s in the log
2023-05-25 12:25:29.910 [WARN ] [d4j.internal.RRD4jPersistenceService] - Could not persist 'Videoporteiro__Silenciar_campainha_Running' to rrd4j database: Bad sample time: 1685013929. Last update time was 1685013929, at least one second step is required
2023-05-25 14:37:06.196 [WARN ] [d4j.internal.RRD4jPersistenceService] - Could not persist 'Sensormovimentopiso1_Occupancy' to rrd4j database: Bad sample time: 1685021821. Last update time was 1685021822, at least one second step is required
2023-05-25 20:47:06.428 [WARN ] [d4j.internal.RRD4jPersistenceService] - Could not persist 'Sensorhumidadeetemperaturacave_Temperature' to rrd4j database: Bad sample time: 1685044021. Last update time was 1685044023, at least one second step is required
Should I care about this ?
Updated to M3 and now “myStrom” binding updates an item from a thing every defined refresh interval, so log will be spammed, although state of this item never changes. Here a sample, refresh interval is 10s default. Until M1 it worked correctly:
2023-05-26 22:37:07.081 [INFO ] [openhab.event.ItemStateUpdatedEvent ] - Item 'Ladegeraet' updated to OFF
2023-05-26 22:37:17.103 [INFO ] [openhab.event.ItemStateUpdatedEvent ] - Item 'Ladegeraet' updated to OFF
2023-05-26 22:37:27.127 [INFO ] [openhab.event.ItemStateUpdatedEvent ] - Item 'Ladegeraet' updated to OFF
2023-05-26 22:37:37.158 [INFO ] [openhab.event.ItemStateUpdatedEvent ] - Item 'Ladegeraet' updated to OFF
2023-05-26 22:37:47.184 [INFO ] [openhab.event.ItemStateUpdatedEvent ] - Item 'Ladegeraet' updated to OFF
2023-05-26 22:37:57.207 [INFO ] [openhab.event.ItemStateUpdatedEvent ] - Item 'Ladegeraet' updated to OFF
2023-05-26 22:38:07.234 [INFO ] [openhab.event.ItemStateUpdatedEvent ] - Item 'Ladegeraet' updated to OFF
2023-05-26 22:38:17.262 [INFO ] [openhab.event.ItemStateUpdatedEvent ] - Item 'Ladegeraet' updated to OFF
2023-05-26 22:38:27.286 [INFO ] [openhab.event.ItemStateUpdatedEvent ] - Item 'Ladegeraet' updated to OFF
2023-05-26 22:38:37.316 [INFO ] [openhab.event.ItemStateUpdatedEvent ] - Item 'Ladegeraet' updated to OFF
2023-05-26 22:38:47.348 [INFO ] [openhab.event.ItemStateUpdatedEvent ] - Item 'Ladegeraet' updated to OFF
2023-05-26 22:38:57.368 [INFO ] [openhab.event.ItemStateUpdatedEvent ] - Item 'Ladegeraet' updated to OFF
2023-05-26 22:39:07.397 [INFO ] [openhab.event.ItemStateUpdatedEvent ] - Item 'Ladegeraet' updated to OFF
Set the suitable logger log level to ERROR. Log in to the Karaf Console, then
_ _ _ ____
___ ___ ___ ___ | | | | / \ | __ )
/ _ \ / _ \ / _ \ / _ \ | |_| | / _ \ | _ \
| (_) | (_) | __/| | | || _ | / ___ \ | |_) )
\___/| __/ \___/|_| |_||_| |_|/_/ \_\|____/
|_| 3.4.4 - Release Build
Use '<tab>' for a list of available commands
and '[cmd] --help' for help on a specific command.
To exit, use '<ctrl-d>' or 'logout'.
openhab> log:set ERROR openhab.event.ItemStateUpdatedEvent
(Version here is the stable, too lazy to do it with the stopped test system )
Hello everyone,
I’m having the same issue OMR described.
After upgrading to OH4 M3, rules are no longer triggered. I’m using file based Rules DSL only.
uname output and java version are equal to those OMR already posted.
EDIT: I just noticed, that CPU consumption heavily increased after the upgrade. It seems to me, that one of the OH threads is looping infinitely. My OH instance is running inside a proxmox VM having 8 CPU threads.
But what is in the logs? Without logs it‘s nearly impossible to find out what is wrong.
please find the openhab.log contents below.
2023-05-27 08:44:08.770 [INFO ] [org.openhab.core.Activator ] - Starting openHAB 4.0.0.M3 (build Milestone Build)
2023-05-27 08:44:09.085 [INFO ] [.core.internal.i18n.I18nProviderImpl] - Time zone set to 'Europe/Berlin'.
2023-05-27 08:44:09.086 [INFO ] [.core.internal.i18n.I18nProviderImpl] - Locale set to 'de_DE'.
2023-05-27 08:44:09.086 [INFO ] [.core.internal.i18n.I18nProviderImpl] - Measurement system set to 'SI'.
2023-05-27 08:44:09.374 [WARN ] [.transport.servlet.ServletController] - Can't find the request for http://openhab1....:8080/rest/events's Observer
2023-05-27 08:44:09.981 [WARN ] [emeris.internal.EphemerisManagerImpl] - Erroneous day set definition dayset-school: No enum constant java.time.DayOfWeek.
2023-05-27 08:44:09.982 [WARN ] [emeris.internal.EphemerisManagerImpl] - Erroneous day set definition dayset-weekend: No enum constant java.time.DayOfWeek.
2023-05-27 08:44:11.071 [WARN ] [core.karaf.internal.FeatureInstaller] - The binding add-on 'darksky' does not exist - ignoring it.
2023-05-27 08:44:11.085 [WARN ] [core.karaf.internal.FeatureInstaller] - The transformation add-on 'javascript' does not exist - ignoring it.
2023-05-27 08:44:11.090 [WARN ] [.transport.servlet.ServletController] - Can't find the request for http://192.168.81.4:8080/rest/events/states/4772f652-702e-4859-80ba-9ee84108115b's Observer
2023-05-27 08:44:12.208 [INFO ] [el.core.internal.ModelRepositoryImpl] - Loading model 'opnsense.items'
2023-05-27 08:44:12.427 [INFO ] [el.core.internal.ModelRepositoryImpl] - Loading model 'knx.items'
2023-05-27 08:44:15.017 [INFO ] [el.core.internal.ModelRepositoryImpl] - Loading model 'idm_terra_swm.items'
2023-05-27 08:44:15.113 [INFO ] [el.core.internal.ModelRepositoryImpl] - Loading model 'telegram.items'
2023-05-27 08:44:15.128 [INFO ] [el.core.internal.ModelRepositoryImpl] - Loading model 'astro.items'
2023-05-27 08:44:15.149 [INFO ] [el.core.internal.ModelRepositoryImpl] - Loading model 'pollen.items'
2023-05-27 08:44:15.238 [INFO ] [el.core.internal.ModelRepositoryImpl] - Loading model 'ntp.items'
2023-05-27 08:44:15.244 [INFO ] [el.core.internal.ModelRepositoryImpl] - Loading model 'walltablets.items'
2023-05-27 08:44:15.514 [INFO ] [el.core.internal.ModelRepositoryImpl] - Loading model 'weather.items'
2023-05-27 08:44:15.546 [INFO ] [el.core.internal.ModelRepositoryImpl] - Loading model 'waermepumpenzaehler.items'
2023-05-27 08:44:15.596 [INFO ] [el.core.internal.ModelRepositoryImpl] - Loading model 'komfovent.items'
2023-05-27 08:44:15.689 [INFO ] [el.core.internal.ModelRepositoryImpl] - Loading model 'nad_receiver.items'
2023-05-27 08:44:15.703 [INFO ] [el.core.internal.ModelRepositoryImpl] - Loading model 'energymgmt.items'
2023-05-27 08:44:15.733 [INFO ] [el.core.internal.ModelRepositoryImpl] - Loading model 'onewire_base.items'
2023-05-27 08:44:15.998 [INFO ] [el.core.internal.ModelRepositoryImpl] - Loading model 'renault.items'
2023-05-27 08:44:16.013 [INFO ] [el.core.internal.ModelRepositoryImpl] - Loading model 'openWB.items'
2023-05-27 08:44:16.040 [INFO ] [el.core.internal.ModelRepositoryImpl] - Loading model 'Wall-E.items'
2023-05-27 08:44:16.044 [INFO ] [el.core.internal.ModelRepositoryImpl] - Loading model 'APC_SmartUPS.items'
2023-05-27 08:44:16.063 [INFO ] [el.core.internal.ModelRepositoryImpl] - Loading model 'touch1.items'
2023-05-27 08:44:16.068 [INFO ] [el.core.internal.ModelRepositoryImpl] - Loading model 'kodi.items'
2023-05-27 08:44:16.087 [INFO ] [el.core.internal.ModelRepositoryImpl] - Loading model 'fronius.items'
2023-05-27 08:44:16.177 [INFO ] [el.core.internal.ModelRepositoryImpl] - Loading model 'dwdPVforcast.items'
2023-05-27 08:44:16.321 [INFO ] [el.core.internal.ModelRepositoryImpl] - Loading model 'homeconnect.items'
2023-05-27 08:44:16.367 [INFO ] [el.core.internal.ModelRepositoryImpl] - Loading model '0_semantic_model.items'
2023-05-27 08:44:16.475 [INFO ] [el.core.internal.ModelRepositoryImpl] - Loading model 'knx_manual.items'
2023-05-27 08:44:16.565 [INFO ] [el.core.internal.ModelRepositoryImpl] - Loading model 'hcl.items'
2023-05-27 08:44:16.590 [INFO ] [el.core.internal.ModelRepositoryImpl] - Loading model 'lueftungStudio.items'
2023-05-27 08:44:16.607 [INFO ] [el.core.internal.ModelRepositoryImpl] - Loading model '0_generic_groups.items'
2023-05-27 08:44:16.625 [INFO ] [el.core.internal.ModelRepositoryImpl] - Loading model 'caldav.items'
2023-05-27 08:44:16.790 [INFO ] [el.core.internal.ModelRepositoryImpl] - Loading model 'influxdb.persist'
2023-05-27 08:44:17.277 [INFO ] [el.core.internal.ModelRepositoryImpl] - Loading model 'mobotix.things'
2023-05-27 08:44:17.287 [INFO ] [el.core.internal.ModelRepositoryImpl] - Loading model 'renault.things'
2023-05-27 08:44:17.294 [INFO ] [el.core.internal.ModelRepositoryImpl] - Loading model 'mqtt.things'
2023-05-27 08:44:17.317 [INFO ] [el.core.internal.ModelRepositoryImpl] - Loading model 'onewire_base_hwif_og1.things'
2023-05-27 08:44:17.322 [INFO ] [el.core.internal.ModelRepositoryImpl] - Loading model 'dwd_pollen.things'
2023-05-27 08:44:17.325 [INFO ] [el.core.internal.ModelRepositoryImpl] - Loading model 'homeconnect.things'
2023-05-27 08:44:17.328 [INFO ] [el.core.internal.ModelRepositoryImpl] - Loading model 'touch1.things'
2023-05-27 08:44:17.330 [INFO ] [el.core.internal.ModelRepositoryImpl] - Loading model 'darksky.things'
2023-05-27 08:44:17.334 [INFO ] [el.core.internal.ModelRepositoryImpl] - Loading model 'ntp.things'
2023-05-27 08:44:17.336 [INFO ] [el.core.internal.ModelRepositoryImpl] - Loading model 'opnsense.things'
2023-05-27 08:44:17.339 [INFO ] [el.core.internal.ModelRepositoryImpl] - Loading model 'komfovent.things'
2023-05-27 08:44:17.350 [INFO ] [el.core.internal.ModelRepositoryImpl] - Loading model 'walltablet.things'
2023-05-27 08:44:17.358 [INFO ] [el.core.internal.ModelRepositoryImpl] - Loading model 'fronius.things'
2023-05-27 08:44:17.363 [INFO ] [el.core.internal.ModelRepositoryImpl] - Loading model 'telegram.things'
2023-05-27 08:44:17.365 [INFO ] [el.core.internal.ModelRepositoryImpl] - Loading model 'onewire_base_hwif_kg.things'
2023-05-27 08:44:17.373 [INFO ] [el.core.internal.ModelRepositoryImpl] - Loading model 'astro.things'
2023-05-27 08:44:17.375 [INFO ] [el.core.internal.ModelRepositoryImpl] - Loading model 'knx.things'
2023-05-27 08:44:17.522 [INFO ] [el.core.internal.ModelRepositoryImpl] - Loading model 'idm_terra_swm.things'
2023-05-27 08:44:17.529 [INFO ] [el.core.internal.ModelRepositoryImpl] - Loading model 'onewire_base_hwif_og1-garage.things'
2023-05-27 08:44:17.533 [INFO ] [el.core.internal.ModelRepositoryImpl] - Loading model 'kodi.things'
2023-05-27 08:44:21.600 [INFO ] [.core.model.lsp.internal.ModelServer] - Started Language Server Protocol (LSP) service on port 5007
2023-05-27 08:44:21.726 [INFO ] [el.core.internal.ModelRepositoryImpl] - Loading model 'nad_receiver.rules'
2023-05-27 08:44:22.851 [INFO ] [el.core.internal.ModelRepositoryImpl] - Loading model 'komfovent.rules'
2023-05-27 08:44:23.980 [INFO ] [el.core.internal.ModelRepositoryImpl] - Loading model 'knx.rules'
2023-05-27 08:44:25.977 [INFO ] [el.core.internal.ModelRepositoryImpl] - Loading model 'cyclicRead.rules'
2023-05-27 08:44:26.374 [INFO ] [el.core.internal.ModelRepositoryImpl] - Loading model 'fronius.rules'
2023-05-27 08:44:28.021 [INFO ] [el.core.internal.ModelRepositoryImpl] - Loading model 'energymgmt.rules'
2023-05-27 08:44:28.661 [INFO ] [el.core.internal.ModelRepositoryImpl] - Loading model 'walltablet.rules'
2023-05-27 08:44:29.498 [INFO ] [el.core.internal.ModelRepositoryImpl] - Loading model 'opnsense.rules'
2023-05-27 08:44:29.790 [INFO ] [el.core.internal.ModelRepositoryImpl] - Loading model 'hcl.rules'
2023-05-27 08:44:30.914 [INFO ] [el.core.internal.ModelRepositoryImpl] - Loading model 'risk.rules'
2023-05-27 08:44:31.225 [INFO ] [el.core.internal.ModelRepositoryImpl] - Loading model 'dwdPVforcast.rules'
2023-05-27 08:44:31.572 [INFO ] [el.core.internal.ModelRepositoryImpl] - Loading model 'jalousie.rules'
2023-05-27 08:44:31.993 [INFO ] [el.core.internal.ModelRepositoryImpl] - Loading model 'taupunkt.rules'
2023-05-27 08:44:31.999 [INFO ] [el.core.internal.ModelRepositoryImpl] - Loading model 'vsbmlw.rules'
2023-05-27 08:44:32.284 [INFO ] [el.core.internal.ModelRepositoryImpl] - Loading model 'idm_terra_swm.rules'
2023-05-27 08:44:32.622 [INFO ] [el.core.internal.ModelRepositoryImpl] - Loading model 'pollen.rules'
2023-05-27 08:44:33.051 [INFO ] [el.core.internal.ModelRepositoryImpl] - Loading model 'heating.rules'
2023-05-27 08:44:33.443 [INFO ] [el.core.internal.ModelRepositoryImpl] - Loading model 'onewire.rules'
2023-05-27 08:44:33.444 [INFO ] [el.core.internal.ModelRepositoryImpl] - Loading model 'telegram.rules'
2023-05-27 08:44:33.618 [INFO ] [el.core.internal.ModelRepositoryImpl] - Loading model 'touch1.rules'
2023-05-27 08:44:33.619 [INFO ] [el.core.internal.ModelRepositoryImpl] - Loading model 'lueftungStudio.rules'
2023-05-27 08:44:36.338 [INFO ] [o.internal.handler.AstroThingHandler] - Scheduled Positional job astro:sun:home every 60 seconds
2023-05-27 08:44:37.012 [INFO ] [rt.modbus.internal.ModbusManagerImpl] - Modbus manager activated
2023-05-27 08:44:37.319 [INFO ] [.transport.mqtt.MqttBrokerConnection] - Starting MQTT broker connection to 'localhost' with clientid 073ecb0a-0646-4c57-9344-e9cf9f2d4b4a
2023-05-27 08:44:38.591 [INFO ] [.influxdb.InfluxDBPersistenceService] - InfluxDB persistence service started.
2023-05-27 08:44:38.759 [INFO ] [ab.ui.habpanel.internal.HABPanelTile] - Started HABPanel at /habpanel
2023-05-27 08:44:48.933 [WARN ] [el.core.internal.ModelRepositoryImpl] - Configuration model 'taupunkt.rules' is either empty or cannot be parsed correctly!
2023-05-27 08:44:50.252 [WARN ] [el.core.internal.ModelRepositoryImpl] - Configuration model 'onewire.rules' is either empty or cannot be parsed correctly!
2023-05-27 08:44:50.525 [WARN ] [el.core.internal.ModelRepositoryImpl] - Configuration model 'touch1.rules' is either empty or cannot be parsed correctly!
2023-05-27 08:44:54.827 [WARN ] [sistence.internal.PersistenceManager] - Querying persistence service 'influxdb' takes more than 5000ms.
after some more digging it seems to be some kind of intermittent problem.
I restarted OH about 10 times. In two out of ten cases, the rules engine came up fine and rules were processed as expected.
Please find the beginning of the openhab.log of the last successful start below:
2023-05-27 09:19:38.430 [INFO ] [org.openhab.core.Activator ] - Starting openHAB 4.0.0.M3 (build Milestone Build)
2023-05-27 09:19:38.665 [INFO ] [.core.internal.i18n.I18nProviderImpl] - Time zone set to 'Europe/Berlin'.
2023-05-27 09:19:38.666 [INFO ] [.core.internal.i18n.I18nProviderImpl] - Locale set to 'de_DE'.
2023-05-27 09:19:38.667 [INFO ] [.core.internal.i18n.I18nProviderImpl] - Measurement system set to 'SI'.
2023-05-27 09:19:39.394 [WARN ] [emeris.internal.EphemerisManagerImpl] - Erroneous day set definition dayset-school: No enum constant java.time.DayOfWeek.
2023-05-27 09:19:39.396 [WARN ] [emeris.internal.EphemerisManagerImpl] - Erroneous day set definition dayset-weekend: No enum constant java.time.DayOfWeek.
2023-05-27 09:19:39.442 [WARN ] [.transport.servlet.ServletController] - Can't find the request for http://openhab1....:8080/rest/events's Observer
2023-05-27 09:19:40.409 [WARN ] [.transport.servlet.ServletController] - Can't find the request for http://192.168.81.4:8080/rest/events/states/f9bfc959-3599-48a2-af97-629e97bab988's Observer
2023-05-27 09:19:40.433 [WARN ] [core.karaf.internal.FeatureInstaller] - The binding add-on 'darksky' does not exist - ignoring it.
2023-05-27 09:19:40.438 [WARN ] [.transport.servlet.ServletController] - Can't find the request for http://192.168.81.4:8080/rest/events/states/ce7df01d-d4d8-4699-828f-606d0ab220b8's Observer
2023-05-27 09:19:40.452 [WARN ] [core.karaf.internal.FeatureInstaller] - The transformation add-on 'javascript' does not exist - ignoring it.
2023-05-27 09:19:41.156 [INFO ] [el.core.internal.ModelRepositoryImpl] - Loading model 'opnsense.items'
2023-05-27 09:19:41.364 [INFO ] [el.core.internal.ModelRepositoryImpl] - Loading model 'knx.items'
2023-05-27 09:19:44.210 [INFO ] [el.core.internal.ModelRepositoryImpl] - Loading model 'idm_terra_swm.items'
2023-05-27 09:19:44.304 [INFO ] [el.core.internal.ModelRepositoryImpl] - Loading model 'telegram.items'
2023-05-27 09:19:44.320 [INFO ] [el.core.internal.ModelRepositoryImpl] - Loading model 'astro.items'
2023-05-27 09:19:44.341 [INFO ] [el.core.internal.ModelRepositoryImpl] - Loading model 'pollen.items'
2023-05-27 09:19:44.435 [INFO ] [el.core.internal.ModelRepositoryImpl] - Loading model 'ntp.items'
2023-05-27 09:19:44.441 [INFO ] [el.core.internal.ModelRepositoryImpl] - Loading model 'walltablets.items'
2023-05-27 09:19:44.710 [INFO ] [el.core.internal.ModelRepositoryImpl] - Loading model 'weather.items'
2023-05-27 09:19:44.755 [INFO ] [el.core.internal.ModelRepositoryImpl] - Loading model 'waermepumpenzaehler.items'
2023-05-27 09:19:44.827 [INFO ] [el.core.internal.ModelRepositoryImpl] - Loading model 'komfovent.items'
2023-05-27 09:19:44.962 [INFO ] [el.core.internal.ModelRepositoryImpl] - Loading model 'nad_receiver.items'
2023-05-27 09:19:44.980 [INFO ] [el.core.internal.ModelRepositoryImpl] - Loading model 'energymgmt.items'
2023-05-27 09:19:45.018 [INFO ] [el.core.internal.ModelRepositoryImpl] - Loading model 'onewire_base.items'
2023-05-27 09:19:45.250 [INFO ] [el.core.internal.ModelRepositoryImpl] - Loading model 'renault.items'
2023-05-27 09:19:45.265 [INFO ] [el.core.internal.ModelRepositoryImpl] - Loading model 'openWB.items'
2023-05-27 09:19:45.292 [INFO ] [el.core.internal.ModelRepositoryImpl] - Loading model 'Wall-E.items'
2023-05-27 09:19:45.296 [INFO ] [el.core.internal.ModelRepositoryImpl] - Loading model 'APC_SmartUPS.items'
2023-05-27 09:19:45.314 [INFO ] [el.core.internal.ModelRepositoryImpl] - Loading model 'touch1.items'
2023-05-27 09:19:45.319 [INFO ] [el.core.internal.ModelRepositoryImpl] - Loading model 'kodi.items'
2023-05-27 09:19:45.336 [INFO ] [el.core.internal.ModelRepositoryImpl] - Loading model 'fronius.items'
2023-05-27 09:19:45.424 [INFO ] [el.core.internal.ModelRepositoryImpl] - Loading model 'dwdPVforcast.items'
2023-05-27 09:19:45.570 [INFO ] [el.core.internal.ModelRepositoryImpl] - Loading model 'homeconnect.items'
2023-05-27 09:19:45.618 [INFO ] [el.core.internal.ModelRepositoryImpl] - Loading model '0_semantic_model.items'
2023-05-27 09:19:45.739 [INFO ] [el.core.internal.ModelRepositoryImpl] - Loading model 'knx_manual.items'
2023-05-27 09:19:45.838 [INFO ] [el.core.internal.ModelRepositoryImpl] - Loading model 'hcl.items'
2023-05-27 09:19:45.864 [INFO ] [el.core.internal.ModelRepositoryImpl] - Loading model 'lueftungStudio.items'
2023-05-27 09:19:45.881 [INFO ] [el.core.internal.ModelRepositoryImpl] - Loading model '0_generic_groups.items'
2023-05-27 09:19:45.899 [INFO ] [el.core.internal.ModelRepositoryImpl] - Loading model 'caldav.items'
2023-05-27 09:19:46.048 [INFO ] [el.core.internal.ModelRepositoryImpl] - Loading model 'influxdb.persist'
2023-05-27 09:19:46.249 [INFO ] [el.core.internal.ModelRepositoryImpl] - Loading model 'all.sitemap'
2023-05-27 09:19:46.558 [INFO ] [el.core.internal.ModelRepositoryImpl] - Loading model 'mobotix.things'
2023-05-27 09:19:46.574 [INFO ] [el.core.internal.ModelRepositoryImpl] - Loading model 'renault.things'
2023-05-27 09:19:46.586 [INFO ] [el.core.internal.ModelRepositoryImpl] - Loading model 'mqtt.things'
2023-05-27 09:19:46.636 [INFO ] [el.core.internal.ModelRepositoryImpl] - Loading model 'onewire_base_hwif_og1.things'
2023-05-27 09:19:46.645 [INFO ] [el.core.internal.ModelRepositoryImpl] - Loading model 'dwd_pollen.things'
2023-05-27 09:19:46.650 [INFO ] [el.core.internal.ModelRepositoryImpl] - Loading model 'homeconnect.things'
2023-05-27 09:19:46.654 [INFO ] [el.core.internal.ModelRepositoryImpl] - Loading model 'touch1.things'
2023-05-27 09:19:46.658 [INFO ] [el.core.internal.ModelRepositoryImpl] - Loading model 'darksky.things'
2023-05-27 09:19:46.663 [INFO ] [el.core.internal.ModelRepositoryImpl] - Loading model 'ntp.things'
2023-05-27 09:19:46.666 [INFO ] [el.core.internal.ModelRepositoryImpl] - Loading model 'opnsense.things'
2023-05-27 09:19:46.670 [INFO ] [el.core.internal.ModelRepositoryImpl] - Loading model 'komfovent.things'
2023-05-27 09:19:46.684 [INFO ] [el.core.internal.ModelRepositoryImpl] - Loading model 'walltablet.things'
2023-05-27 09:19:46.693 [INFO ] [el.core.internal.ModelRepositoryImpl] - Loading model 'fronius.things'
2023-05-27 09:19:46.701 [INFO ] [el.core.internal.ModelRepositoryImpl] - Loading model 'telegram.things'
2023-05-27 09:19:46.705 [INFO ] [el.core.internal.ModelRepositoryImpl] - Loading model 'onewire_base_hwif_kg.things'
2023-05-27 09:19:46.714 [INFO ] [el.core.internal.ModelRepositoryImpl] - Loading model 'astro.things'
2023-05-27 09:19:46.718 [INFO ] [el.core.internal.ModelRepositoryImpl] - Loading model 'knx.things'
2023-05-27 09:19:46.906 [INFO ] [el.core.internal.ModelRepositoryImpl] - Loading model 'idm_terra_swm.things'
2023-05-27 09:19:46.914 [INFO ] [el.core.internal.ModelRepositoryImpl] - Loading model 'onewire_base_hwif_og1-garage.things'
2023-05-27 09:19:46.918 [INFO ] [el.core.internal.ModelRepositoryImpl] - Loading model 'kodi.things'
2023-05-27 09:19:49.074 [INFO ] [.core.model.lsp.internal.ModelServer] - Started Language Server Protocol (LSP) service on port 5007
2023-05-27 09:19:49.176 [INFO ] [el.core.internal.ModelRepositoryImpl] - Loading model 'nad_receiver.rules'
2023-05-27 09:19:50.376 [INFO ] [el.core.internal.ModelRepositoryImpl] - Loading model 'komfovent.rules'
2023-05-27 09:19:51.694 [INFO ] [el.core.internal.ModelRepositoryImpl] - Loading model 'knx.rules'
2023-05-27 09:19:53.746 [INFO ] [el.core.internal.ModelRepositoryImpl] - Loading model 'cyclicRead.rules'
2023-05-27 09:19:54.174 [INFO ] [el.core.internal.ModelRepositoryImpl] - Loading model 'fronius.rules'
2023-05-27 09:19:56.091 [INFO ] [el.core.internal.ModelRepositoryImpl] - Loading model 'energymgmt.rules'
2023-05-27 09:19:56.790 [INFO ] [el.core.internal.ModelRepositoryImpl] - Loading model 'walltablet.rules'
2023-05-27 09:19:57.653 [INFO ] [el.core.internal.ModelRepositoryImpl] - Loading model 'opnsense.rules'
2023-05-27 09:19:57.946 [INFO ] [el.core.internal.ModelRepositoryImpl] - Loading model 'hcl.rules'
2023-05-27 09:19:59.056 [INFO ] [el.core.internal.ModelRepositoryImpl] - Loading model 'risk.rules'
2023-05-27 09:19:59.389 [INFO ] [el.core.internal.ModelRepositoryImpl] - Loading model 'dwdPVforcast.rules'
2023-05-27 09:19:59.730 [INFO ] [el.core.internal.ModelRepositoryImpl] - Loading model 'jalousie.rules'
2023-05-27 09:20:00.177 [INFO ] [el.core.internal.ModelRepositoryImpl] - Loading model 'vsbmlw.rules'
2023-05-27 09:20:00.378 [INFO ] [el.core.internal.ModelRepositoryImpl] - Loading model 'idm_terra_swm.rules'
2023-05-27 09:20:00.771 [INFO ] [el.core.internal.ModelRepositoryImpl] - Loading model 'pollen.rules'
2023-05-27 09:20:01.251 [INFO ] [el.core.internal.ModelRepositoryImpl] - Loading model 'heating.rules'
2023-05-27 09:20:01.726 [INFO ] [el.core.internal.ModelRepositoryImpl] - Loading model 'telegram.rules'
2023-05-27 09:20:01.951 [INFO ] [el.core.internal.ModelRepositoryImpl] - Loading model 'lueftungStudio.rules'
2023-05-27 09:20:02.599 [WARN ] [el.core.internal.ModelRepositoryImpl] - Configuration model 'mobotix.things' is either empty or cannot be parsed correctly!
2023-05-27 09:20:04.785 [INFO ] [o.internal.handler.AstroThingHandler] - Scheduled Positional job astro:sun:home every 60 seconds
2023-05-27 09:20:05.475 [INFO ] [rt.modbus.internal.ModbusManagerImpl] - Modbus manager activated
2023-05-27 09:20:05.620 [INFO ] [.transport.mqtt.MqttBrokerConnection] - Starting MQTT broker connection to 'localhost' with clientid c3ea9c62-55ee-44a9-8976-c386555911ef
2023-05-27 09:20:05.629 [INFO ] [.transport.mqtt.MqttBrokerConnection] - Starting MQTT broker connection to '192.168.82.41' with clientid 4dd0283a-cb5c-491c-af3f-99b8e7b613a5
2023-05-27 09:20:06.909 [INFO ] [.influxdb.InfluxDBPersistenceService] - InfluxDB persistence service started.
2023-05-27 09:20:07.105 [INFO ] [ab.ui.habpanel.internal.HABPanelTile] - Started HABPanel at /habpanel
2023-05-27 09:20:29.720 [INFO ] [enhab.core.model.script.NAD Receiver] - rule has been triggered. Scheduling Timer to run actual initialization process...
2023-05-27 09:20:29.722 [INFO ] [ript.KNX initialize control channels] - rule has been triggered. Scheduling Timer to run actual initialization process...
2023-05-27 09:20:29.723 [INFO ] [e.automation.internal.RuleEngineImpl] - Rule engine started.
I started to prepare for OH4 and encountered the same issue also with a clean install of openhabian on a rpi4 with Java17, OH 4.0.0.M3 and Enocean USB300 and nothing else but the Enocean binding.
The same settings work fine with OH 3.4.4.
Any ideas or help would be highly appreciated.
Just in case anyone else trips up over this issue, In APT upgrade on Ubuntu, Ctrl-C didn’t seem to be an option to halt the process (maybe was spawned?).
Connect to the server via a separate SSH session and:
user@server:~$ sudo ps -ef |grep openhab
### Following list shortened for clarity
root 804149 804144 0 18:12 pts/2 00:00:00 /bin/sh /var/lib/dpkg/info/openhab.postinst configure 4.0.0~M2-1
root 804218 804149 0 18:12 pts/2 00:00:00 java -jar /usr/share/openhab/runtime/bin/upgradetool.jar
user@server:~$ sudo kill 804218
Obviously replacing the Process ID with the actual one (on the LH side column) of the upgradetool.jar process
Back over on the session where the APT upgrade running, the bottom 3 lines (below section) will then appear, and things will carry on.
Setting up openhab (4.0.0~M3-1) ...
[openHAB] Running JSON Database upgrade tool (${OPENHAB_RUNTIME}/bin/upgradetool.jar).
[main] INFO org.openhab.core.tools.internal.Upgrader - Copying item unit from state description to metadata in database '/var/lib/openhab/jsondb/org.openhab.core.items.Item.json'
Exception in thread "main" java.lang.NullPointerException: Cannot invoke "String.contains(java.lang.CharSequence)" because "pattern" is null
at org.openhab.core.tools.internal.Upgrader.lambda$0(Upgrader.java:104)
at java.base/java.util.concurrent.ConcurrentHashMap$KeySetView.forEach(ConcurrentHashMap.java:4706)
at org.openhab.core.tools.internal.Upgrader.itemCopyUnitToMetadata(Upgrader.java:93)
at org.openhab.core.tools.UpgradeTool.main(UpgradeTool.java:79)
[openHAB] WARNING: internal database upgrade tool failed.
[openHAB] please check the openHAB website (www.openhab.org) for upgrade requirements.
Setting up openhab-addons (4.0.0~M3-1) ...
After that, rebooted the system (but a service restart would be fine), and left plenty of time for OpenHAB to start, as I usually see some funky stuff after any upgrade, which comes right after a while.
Seem to be running ok on 4.0.0-M3 now after the above intervention.