Start levels higher than 70 never reached

syntacrsc · July 20, 2022, 2:24pm

Hello openhab community.

According to OH 3.3.0 documentation the system now triggers an event each time when a specific start level is reached.
See Rules | openHAB

It says (quote):

"In openHAB version 3 the System-based Trigger for startlevel had been added, values depends on the startlevel:

00 - OSGi framework has been started.
10 - OSGi application start level has been reached, i.e. bundles are activated.
20 - Model entities (items, things, links, persist config) have been loaded, both from db as well as files.
30 - Item states have been restored from persistence service, where applicable.
40 - Rules are loaded and parsed, both from db as well as dsl and script files.
50 - Rule engine has executed all “system started” rules and is active.
70 - User interface is up and running. (planned, not included yet)
80 - All things have been initialized. (planned, not included yet)
100 - Startup is fully complete.
"

Since as to my knowledge there’s no implicit variable holding the current start level I’ve implemented some rules to update an Item StartLevel each time any of the start levels listed above is reached.
What I noticed though is that the highest start level reached is 70, event “start level 100 reached” is apparently never fired.

items file:

Number		StartLevel 							"Start Level"

rules file:

rule StartLevel40
when
	System reached start level 40
then
	StartLevel.sendCommand(40)
end

rule StartLevel50
when
	System reached start level 50
then
	StartLevel.sendCommand(50)
end

rule StartLevel70
when
	System reached start level 70
then
	StartLevel.sendCommand(70)
end

rule StartLevel80
when	
	System reached start level 80
then
	StartLevel.sendCommand(80)
end

rule StartLevel100
when
	System reached start level 100
then
	StartLevel.sendCommand(100)
end

An hour after rebooting the openhab server, the item still shows start level 70:

Does any of you have an idea why the item never gets to start levels higher than 70?

Besides that the openhab system is working properly and does all it’s supposed to do, hence there’s no problem with the boot sequence itself as fas as I can tell.

Thanks and kind regards,
Ralph…

J-N-K · July 20, 2022, 2:29pm

Any things that are not initialized?

syntacrsc · July 20, 2022, 2:56pm

No, everyting is initialized, up and working…

J-N-K · July 20, 2022, 6:44pm

Do you have disabled things?

syntacrsc · July 21, 2022, 8:15am

Hi Jan.
Not knowingly, how can I check if I have disabled things?
Kind regards,
Ralph…

gorddel · July 21, 2022, 4:50pm

I just tried this on my 3.3.0 system and it appears that the start level reaches 100 but is then set back to 70…

2022-07-21 10:31:36.140 [INFO ] [openhab.event.ItemCommandEvent      ] - Item 'StartLevel' received command 40
2022-07-21 10:31:36.182 [INFO ] [openhab.event.ItemCommandEvent      ] - Item 'StartLevel' received command 50
2022-07-21 10:31:36.186 [INFO ] [openhab.event.ItemStateChangedEvent ] - Item 'StartLevel' changed from NULL to 40
2022-07-21 10:31:36.194 [INFO ] [openhab.event.ItemStateChangedEvent ] - Item 'StartLevel' changed from 40 to 50
2022-07-21 10:31:41.122 [INFO ] [openhab.event.ItemCommandEvent      ] - Item 'StartLevel' received command 70
2022-07-21 10:31:41.129 [INFO ] [openhab.event.ItemStateChangedEvent ] - Item 'StartLevel' changed from 50 to 70
2022-07-21 10:32:46.583 [INFO ] [openhab.event.ItemCommandEvent      ] - Item 'StartLevel' received command 80
2022-07-21 10:32:46.588 [INFO ] [openhab.event.ItemCommandEvent      ] - Item 'StartLevel' received command 100
2022-07-21 10:32:46.592 [INFO ] [openhab.event.ItemStateChangedEvent ] - Item 'StartLevel' changed from 70 to 80
2022-07-21 10:32:46.607 [INFO ] [openhab.event.ItemCommandEvent      ] - Item 'StartLevel' received command 70
2022-07-21 10:32:46.617 [INFO ] [openhab.event.ItemStateChangedEvent ] - Item 'StartLevel' changed from 80 to 100
2022-07-21 10:32:46.628 [INFO ] [openhab.event.ItemStateChangedEvent ] - Item 'StartLevel' changed from 100 to 70

syntacrsc · July 21, 2022, 5:10pm

OK, I’ve changed my rules to output a message at the beginning of each rule and to use postUpdate instead of sendCommand but apparently things didn’t change. The system still does not make it to start levels higher than 70:

Here’s the new rules file:

rule StartLevel40
when
	System reached start level 40
then	
	logWarn(_fileName + "StartLevel40", "Rule for Event <System reached start level 40> started")
	StartLevel.postUpdate(40)
end

rule StartLevel50
when
	System reached start level 50
then
	logWarn(_fileName + "StartLevel50", "Rule for Event <System reached start level 50> started")
	if (StartLevel.state < 50)	{ StartLevel.postUpdate(50) }
	else { logWarn(_filename + "StartLevel50", "StartLevel decreased from " + StartLevel.state + " to 50") }
end

rule StartLevel70
when
	System reached start level 70
then
	logWarn(_fileName + "StartLevel70", "Rule for Event <System reached start level 70> started")
	if (StartLevel.state < 70)	{ StartLevel.postUpdate(70) }
	else { logWarn(_filename + "StartLevel70", "StartLevel decreased from " + StartLevel.state + " to 70") }
end

rule StartLevel80
when	
	System reached start level 80
then
	logWarn(_fileName + "StartLevel80", "Rule for Event <System reached start level 80> started")
	if (StartLevel.state < 80)	{ StartLevel.postUpdate(80) }
	else { logWarn(_filename + "StartLevel80", "StartLevel decreased from " + StartLevel.state + " to 80") }
end

rule StartLevel100
when
	System reached start level 100
then
	logWarn(_fileName + "StartLevel100", "Rule for Event <System reached start level 100> started")
	if (StartLevel.state < 100)	{ StartLevel.postUpdate(100) }
	else { logWarn(_filename + "StartLevel100", "StartLevel decreased from " + StartLevel.state + " to 100") }
end

And here’s the result (filtered on term “start”) - no mention of start levels higher than 70:

Doesn’t make much sense to me.
It appears as if start level 50 gets fired before start level 40.
And nothing higher than start level 70…

rossko57 · July 21, 2022, 6:41pm

Those commands coming from rule? This looks the same as if the UI or a rule tries to command an Item that is tightly linked to some data channel that doesn’t respond to commands. Autoupdate processes the command, and applies its predicted new state. A short time later the channel re-asserts the real data, instead of the autoupdate guesswork. Don’t think that’s quite what is going on, though.

You might get a cleaner interpretation of events by using postUpdate instead of sendCommand. If you want to update an Item state, then update it - don’t send a command invoking other processes unless you are trying to cause some external action

but

There is great risk of race conditions here. You’ve got multiple rules. If trigger conditions arrive close together (within milliseconds), you’ve got no expectation that any given rule will complete its thing before the other. In other words, results might NOT come in the same order as triggers. The business with command/autoupdate adding to the delay will not help here.

Might become clearer if the first line of each rule is a simple log, to give us a timestamp.

syntacrsc · July 21, 2022, 7:33pm

OK, I’ve changed my rules to output a message at the beginning of each rule and to use postUpdate instead of sendCommand but apparently things didn’t change. The system still does not make it to start levels higher than 70:

Here’s the new rules file:

rule StartLevel40
when
	System reached start level 40
then	
	logWarn(_fileName + "StartLevel40", "Rule for Event <System reached start level 40> started")
	StartLevel.postUpdate(40)
end

rule StartLevel50
when
	System reached start level 50
then
	logWarn(_fileName + "StartLevel50", "Rule for Event <System reached start level 50> started")
	if (StartLevel.state < 50)	{ StartLevel.postUpdate(50) }
	else { logWarn(_filename + "StartLevel50", "StartLevel decreased from " + StartLevel.state + " to 50") }
end

rule StartLevel70
when
	System reached start level 70
then
	logWarn(_fileName + "StartLevel70", "Rule for Event <System reached start level 70> started")
	if (StartLevel.state < 70)	{ StartLevel.postUpdate(70) }
	else { logWarn(_filename + "StartLevel70", "StartLevel decreased from " + StartLevel.state + " to 70") }
end

rule StartLevel80
when	
	System reached start level 80
then
	logWarn(_fileName + "StartLevel80", "Rule for Event <System reached start level 80> started")
	if (StartLevel.state < 80)	{ StartLevel.postUpdate(80) }
	else { logWarn(_filename + "StartLevel80", "StartLevel decreased from " + StartLevel.state + " to 80") }
end

rule StartLevel100
when
	System reached start level 100
then
	logWarn(_fileName + "StartLevel100", "Rule for Event <System reached start level 100> started")
	if (StartLevel.state < 100)	{ StartLevel.postUpdate(100) }
	else { logWarn(_filename + "StartLevel100", "StartLevel decreased from " + StartLevel.state + " to 100") }
end

And here’s the result (filtered on term “start”) - no mention of start levels higher than 70:

Doesn’t make much sense to me.
It appears as if start level 50 gets fired before start level 40.
And nothing higher than start level 70…

J-N-K · July 22, 2022, 9:37am

Please use the openHAB console (openhab-cli console) and type things list. Please post the output.

syntacrsc · July 22, 2022, 9:55am

Sure, here’s the output…


   ___   ___   ___   ___  | | | |   / \   | __ )
  / _ \ / _ \ / _ \ / _ \ | |_| |  / _ \  |  _ \
 | (_) | (_) |  __/| | | ||  _  | / ___ \ | |_) )
  \___/|  __/ \___/|_| |_||_| |_|/_/   \_\|____/
       |_|       3.3.0 - 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> things list
amazonechocontrol:echo:account1:EchoDotRalph (Type=Thing, Status=ONLINE, Label=Alexa Ralph, Bridge=amazonechocontrol:account:account1)
shelly:shellydimmer2:Stagelight (Type=Thing, Status=ONLINE, Label=Stagelight, Bridge=null)
astro:moon:Frechen (Type=Thing, Status=ONLINE, Label=Astro Moon Data, Bridge=null)
mqtt:topic:MQTTMosquittoBridge:MobilThermometer (Type=Thing, Status=ONLINE, Label=Mobiles Thermometer, Bridge=mqtt:broker:MQTTMosquittoBridge)
knx:device:bridge:SprinklerAktor (Type=Thing, Status=ONLINE, Label=MDT JAL-0810M.02 Universal-Aktor, Bridge=knx:ip:bridge)
icalendar:calendar:googleRalph (Type=Bridge, Status=ONLINE, Label=Kommando-Kalendar, Bridge=null)
gpstracker:tracker:CellPhoneChristine (Type=Thing, Status=ONLINE, Label=Mobiltelefon Christine, Bridge=null)
gpstracker:tracker:CellPhoneRalph (Type=Thing, Status=ONLINE, Label=Mobiltelefon Ralph, Bridge=null)
astro:sun:Frechen (Type=Thing, Status=ONLINE, Label=Astro Sun Data, Bridge=null)
coronastats:country:stats:coronaGermany (Type=Thing, Status=ONLINE, Label=Corona Stats Germany, Bridge=coronastats:world:stats)
amazonechocontrol:account:account1 (Type=Bridge, Status=ONLINE, Label=Amazon Account, Bridge=null)
openweathermap:onecall:bridge:local (Type=Thing, Status=ONLINE, Label=OneCall API, Bridge=openweathermap:weather-api:bridge)
shelly:shelly1:Lobbybodenlicht (Type=Thing, Status=ONLINE, Label=Licht, Bridge=null)
mqtt:topic:MQTTMosquittoBridge:RfIdReader (Type=Thing, Status=ONLINE, Label=RF-ID Reader, Bridge=mqtt:broker:MQTTMosquittoBridge)
http:url:AgentDVR (Type=Thing, Status=ONLINE, Label=AgentDVR Service, Bridge=null)
coronastats:country:stats:coronaUk (Type=Thing, Status=ONLINE, Label=Corona Stats United Kingdom, Bridge=coronastats:world:stats)
http:url:powerfox (Type=Thing, Status=ONLINE, Label=Powerfox, Bridge=null)
mqtt:topic:MQTTMosquittoBridge:MySensorsGateway (Type=Thing, Status=ONLINE, Label=MySensors MQTT Gateway, Bridge=mqtt:broker:MQTTMosquittoBridge)
gpstracker:tracker:CellPhoneNicklas (Type=Thing, Status=ONLINE, Label=Mobiltelefon Nicklas, Bridge=null)
network:pingdevice:MobilTelAnja_Name (Type=Thing, Status=ONLINE, Label=Mobiltelefon Anja, Bridge=null)
openweathermap:weather-api:bridge (Type=Bridge, Status=ONLINE, Label=OWM Bridge, Bridge=null)
shelly:shelly1:Kaninchenstall (Type=Thing, Status=ONLINE, Label=Licht Kaninchen, Bridge=null)
network:pingdevice:TV_Schlafzimmer (Type=Thing, Status=ONLINE, Label=Fernseher, Bridge=null)
amazonechocontrol:echo:account1:AlexaSonosBuero (Type=Thing, Status=ONLINE, Label=Alexa Ralph Sonos, Bridge=amazonechocontrol:account:account1)
coronastats:country:stats:coronaSpain (Type=Thing, Status=ONLINE, Label=Corona Stats Spain, Bridge=coronastats:world:stats)
amazonechocontrol:echo:account1:AlexaSonosWohnzimmer (Type=Thing, Status=ONLINE, Label=Alexa Sonos Wohnzimmer, Bridge=amazonechocontrol:account:account1)
mqtt:topic:MQTTMosquittoBridge:ThermostatNebenkueche (Type=Thing, Status=ONLINE, Label=Thermostat Nebenküche, Bridge=mqtt:broker:MQTTMosquittoBridge)
benqprojector:projector-tcp:hometheater (Type=Thing, Status=ONLINE, Label=Projektor, Bridge=null)
mqtt:topic:MQTTMosquittoBridge:ThermostatBuero2 (Type=Thing, Status=ONLINE, Label=Thermostat Büro 2, Bridge=mqtt:broker:MQTTMosquittoBridge)
shelly:shellyht:GaestebadHT (Type=Thing, Status=UNKNOWN (CONFIGURATION_PENDING): Initializing or device in sleep mode., Label=HT, Bridge=null)
knx:device:bridge:JalousieAktorOG (Type=Thing, Status=ONLINE, Label=MDT JAL-0810M.02 Jalousieaktor, Bridge=knx:ip:bridge)
mqtt:topic:MQTTMosquittoBridge:HeizungssteuerungEG (Type=Thing, Status=ONLINE, Label=Heizungssteuerung EG, Bridge=mqtt:broker:MQTTMosquittoBridge)
exec:command:RestartOpenHAB (Type=Thing, Status=ONLINE, Label=Command, Bridge=null)
coronastats:country:stats:coronaUsa (Type=Thing, Status=ONLINE, Label=Corona Stats USA, Bridge=coronastats:world:stats)
avmfritz:FRITZ_Powerline_546E_Solo:PowerLine (Type=Bridge, Status=ONLINE, Label=FRITZ!Powerline 546E UG, Bridge=null)
mqtt:topic:MQTTMosquittoBridge:ThermostatBuero1 (Type=Thing, Status=ONLINE, Label=Thermostat Büro 1, Bridge=mqtt:broker:MQTTMosquittoBridge)
mqtt:topic:MQTTMosquittoBridge:ThermostatLobby (Type=Thing, Status=ONLINE, Label=Thermostat Lobby, Bridge=mqtt:broker:MQTTMosquittoBridge)
shelly:shellydimmer2:Dartslight (Type=Thing, Status=ONLINE, Label=Dartslicht, Bridge=null)
openuv:uvreport:local:Frechen (Type=Thing, Status=UNINITIALIZED (HANDLER_CONFIGURATION_PENDING): {index=The data type of the value (class java.math.BigDecimal) does not match with the type declaration (TEXT) in the configuration description.}, Label=Frechen, Bridge=openuv:openuvapi:local)
coronastats:country:stats:coronaItaly (Type=Thing, Status=ONLINE, Label=Corona Stats Italy, Bridge=coronastats:world:stats)
icalendar:eventfilter:NaechsteAbfuhren (Type=Thing, Status=ONLINE, Label=Nächste Müllabfuhren, Bridge=icalendar:calendar:MuellKalender)
mqtt:topic:MQTTMosquittoBridge:SpielzimmerShellyPlusI4 (Type=Thing, Status=ONLINE, Label=Shelly Plus i4 Spielzimmer, Bridge=mqtt:broker:MQTTMosquittoBridge)
network:pingdevice:MobilTelChristine_IP1 (Type=Thing, Status=ONLINE, Label=Mobiltelefon Christine, Bridge=null)
amazonechocontrol:echo:account1:EchoSonosBadezimmer (Type=Thing, Status=ONLINE, Label=Alexa Badezimmer, Bridge=amazonechocontrol:account:account1)
shelly:shellydimmer2:Esszimmerlicht (Type=Thing, Status=ONLINE, Label=Licht, Bridge=null)
icalendar:calendar:MuellKalender (Type=Bridge, Status=ONLINE, Label=Muellkalendar, Bridge=null)
coronastats:country:stats:coronaCroatia (Type=Thing, Status=ONLINE, Label=Corona Stats Croatia, Bridge=coronastats:world:stats)
shelly:shelly1:Terrassenlicht (Type=Thing, Status=ONLINE, Label=Terrassenlicht, Bridge=null)
mqtt:broker:MQTTMosquittoBridge (Type=Bridge, Status=ONLINE, Label=MQTT Mosquitto Bridge, Bridge=null)
network:pingdevice:MobilTelUrsula_IP1 (Type=Thing, Status=ONLINE, Label=Mobiltelefon Ursula, Bridge=null)
shelly:shelly25-roller:Gaestebad (Type=Thing, Status=ONLINE, Label=Fenster, Bridge=null)
dwdunwetter:dwdwarnings:cologne (Type=Thing, Status=ONLINE, Label=Wetterwarnung Stadt Köln, Bridge=null)
network:pingdevice:TV_Wohnzimmer (Type=Thing, Status=ONLINE, Label=Fernseher, Bridge=null)
sonos:PLAY1:Buero (Type=Thing, Status=ONLINE, Label=Sonos Büro Ralph, Bridge=null)
mqtt:topic:MQTTMosquittoBridge:ThermostatKueche (Type=Thing, Status=ONLINE, Label=Thermostat Küche, Bridge=mqtt:broker:MQTTMosquittoBridge)
bosesoundtouch:device:Hobbyraum (Type=Thing, Status=ONLINE, Label=Bose SoundTouch Device, Bridge=null)
knx:device:bridge:JalousieAktorEG (Type=Thing, Status=ONLINE, Label=MDT JAL-0810M.02 Jalousieaktor, Bridge=knx:ip:bridge)
mqtt:topic:MQTTMosquittoBridge:ThermostatBadezimmerOG (Type=Thing, Status=ONLINE, Label=Thermostat Badezimmer OG, Bridge=mqtt:broker:MQTTMosquittoBridge)
network:pingdevice:MobilTelRalph_Name (Type=Thing, Status=ONLINE, Label=Mobiltelefon Ralph, Bridge=null)
amazonechocontrol:echo:account1:AlexaMobilTelRalph (Type=Thing, Status=OFFLINE, Label=Alexa MobilTel Ralph, Bridge=amazonechocontrol:account:account1)
openweathermap:weather-api:api (Type=Bridge, Status=ONLINE, Label=OpenWeatherMap Account, Bridge=null)
mqtt:topic:MQTTMosquittoBridge:Poolsteuerung (Type=Thing, Status=ONLINE, Label=Poolsteuerung, Bridge=mqtt:broker:MQTTMosquittoBridge)
dwdunwetter:dwdwarnings:frechen (Type=Thing, Status=ONLINE, Label=Wetterwarnung Frechen, Bridge=null)
network:speedtest:local (Type=Thing, Status=ONLINE, Label=SpeedTest 50Mo, Bridge=null)
exec:command:logsetinfo (Type=Thing, Status=ONLINE, Label=Command, Bridge=null)
network:pingdevice:MobilTelAnja_IP1 (Type=Thing, Status=ONLINE, Label=Mobiltelefon Anja, Bridge=null)
network:pingdevice:MobilTelUrsula_Name (Type=Thing, Status=ONLINE, Label=Mobiltelefon Ursula, Bridge=null)
openweathermap:weather-and-forecast:bridge:local (Type=Thing, Status=ONLINE, Label=Wetter in Frechen, Bridge=openweathermap:weather-api:bridge)
mqtt:topic:MQTTMosquittoBridge:HeizungssteuerungOG (Type=Thing, Status=ONLINE, Label=Heizungssteuerung OG, Bridge=mqtt:broker:MQTTMosquittoBridge)
mqtt:topic:MQTTMosquittoBridge:ThermostatEsszimmer (Type=Thing, Status=ONLINE, Label=Thermostat Esszimmer, Bridge=mqtt:broker:MQTTMosquittoBridge)
shelly:shellydimmer2:Barlight (Type=Thing, Status=ONLINE, Label=Barlicht Kino, Bridge=null)
tr064:fritzbox:Fritz7490 (Type=Bridge, Status=ONLINE, Label=FritzBox 7490 Bridge, Bridge=null)
shelly:shellydimmer2:Lobbywandlicht (Type=Thing, Status=UNKNOWN (CONFIGURATION_PENDING): Initializing or device in sleep mode., Label=Licht, Bridge=null)
amazonechocontrol:echo:account1:AlexaSamsungWohnzimmer (Type=Thing, Status=OFFLINE, Label=Alexa Wohnzimmer, Bridge=amazonechocontrol:account:account1)
sonos:CONNECTAMP:Pool (Type=Thing, Status=ONLINE, Label=Sonos Pool, Bridge=null)
network:pingdevice:MobilTelChristine_Name (Type=Thing, Status=ONLINE, Label=Mobiltelefon Christine, Bridge=null)
shelly:shelly25-roller:KinoLeinwand (Type=Thing, Status=ONLINE, Label=Leinwand, Bridge=null)
tr064:subdevice:Fritz7490:FritzBox7490WANconnect (Type=Thing, Status=ONLINE, Label=Fritz!Box 7490 WANconnect, Bridge=tr064:fritzbox:Fritz7490)
shelly:shellydimmer2:Kuechenlicht (Type=Thing, Status=ONLINE, Label=Licht, Bridge=null)
tr064:subdeviceLan:Fritz7490:FritzBox7490LAN (Type=Thing, Status=ONLINE, Label=Fritz!Box 7490 LAN, Bridge=tr064:fritzbox:Fritz7490)
sonos:One:Badezimmer (Type=Thing, Status=ONLINE, Label=Sonos Badezimmer, Bridge=null)
hpprinter:printer:HPLJM477fdw (Type=Thing, Status=OFFLINE: java.net.UnknownHostException: hpljm477fdw.fritz.box: Name or service not known, Label=HP LaserJet M477fdw, Bridge=null)
mqtt:topic:MQTTMosquittoBridge:KinoShellyFlood (Type=Thing, Status=ONLINE, Label=Shelly Flood Kino, Bridge=mqtt:broker:MQTTMosquittoBridge)
openuv:openuvapi:local (Type=Bridge, Status=ONLINE, Label=OpenUV API, Bridge=null)
amazonechocontrol:echo:account1:AlexaSonosBadezimmer (Type=Thing, Status=ONLINE, Label=Alexa Sonos Badezimmer, Bridge=amazonechocontrol:account:account1)
dwdpollenflug:region:dwd:region41 (Type=Thing, Status=ONLINE, Label=DWD Pollen-Warnregion, Bridge=dwdpollenflug:bridge:dwd)
avmfritz:FRITZ_DECT_Repeater_100:Router:DectRepeater (Type=Thing, Status=ONLINE, Label=Fritz DECT Repeater, Bridge=avmfritz:fritzbox:Router)
shelly:shellyflood:KinoFlutsensor (Type=Thing, Status=ONLINE, Label=Flutsensor, Bridge=null)
shelly:shellydimmer2:Wohnzimmerlicht (Type=Thing, Status=UNKNOWN (CONFIGURATION_PENDING): Initializing or device in sleep mode., Label=Licht, Bridge=null)
mqtt:topic:MQTTMosquittoBridge:ThermostatSpielzimmer (Type=Thing, Status=ONLINE, Label=Thermostat Spielzimmer, Bridge=mqtt:broker:MQTTMosquittoBridge)
dwdpollenflug:bridge:dwd (Type=Bridge, Status=ONLINE, Label=DWD pollen count Bridge, Bridge=null)
shelly:shelly1:Badezimmerlicht (Type=Thing, Status=ONLINE, Label=Licht, Bridge=null)
openweathermap:uvindex:api:local (Type=Thing, Status=ONLINE, Label=UV Index in Frechen, Bridge=openweathermap:weather-api:api)
systeminfo:computer:raspberryPi4b (Type=Thing, Status=ONLINE, Label=Systeminfo, Bridge=null)
coronastats:world:stats (Type=Bridge, Status=ONLINE, Label=Corona Stats World, Bridge=null)
dwdunwetter:dwdwarnings:erftkreis (Type=Thing, Status=ONLINE, Label=Wetterwarnung Erftkreis, Bridge=null)
knx:ip:bridge (Type=Bridge, Status=ONLINE, Label=KNX/IP Gateway, Bridge=null)
network:pingdevice:MobilTelRalph_IP1 (Type=Thing, Status=ONLINE, Label=Mobiltelefon Ralph, Bridge=null)
tr064:subdevice:Fritz7490:FritzBox7490WAN (Type=Thing, Status=ONLINE, Label=Fritz!Box 7490 WAN, Bridge=tr064:fritzbox:Fritz7490)
sonos:PLAYBAR:Wohnzimmer (Type=Thing, Status=ONLINE, Label=Sonos Wohnzimmer, Bridge=null)
avmfritz:fritzbox:Router (Type=Bridge, Status=ONLINE, Label=FRITZ!Box 7490, Bridge=null)
amazonechocontrol:echo:account1:EchoDotNicklas (Type=Thing, Status=ONLINE, Label=Alexa Nicklas, Bridge=amazonechocontrol:account:account1)
amazonechocontrol:echo:account1:AlexaSonosPool (Type=Thing, Status=ONLINE, Label=Alexa Sonos Pool, Bridge=amazonechocontrol:account:account1)
knx:device:bridge:Busspannungsversorgung (Type=Thing, Status=ONLINE, Label=MDT STC 640.01 Busspannungsversorgung, Bridge=knx:ip:bridge)
amazonechocontrol:echoshow:account1:EchoShowKueche (Type=Thing, Status=ONLINE, Label=Alexa Küche, Bridge=amazonechocontrol:account:account1)
shelly:shellydimmer2:Kuechenwandlicht (Type=Thing, Status=ONLINE, Label=Licht, Bridge=null)
coronastats:country:stats:coronaAustria (Type=Thing, Status=ONLINE, Label=Corona Stats Austria, Bridge=coronastats:world:stats)
mqtt:topic:MQTTMosquittoBridge:HabPanelTreppenhaus (Type=Thing, Status=ONLINE, Label=Generic MQTT Thing, Bridge=mqtt:broker:MQTTMosquittoBridge)
shelly:shelly1pm:Buero1Licht (Type=Thing, Status=ONLINE, Label=Licht, Bridge=null)
shelly:shelly1pm:Lueftungsanlage (Type=Thing, Status=ONLINE, Label=Lüftungsanlage, Bridge=null)
openweathermap:weather-and-forecast:api:local (Type=Thing, Status=ONLINE, Label=Wetter in Frechen, Bridge=openweathermap:weather-api:api)
mqtt:topic:MQTTMosquittoBridge:Solarsteuerung (Type=Thing, Status=ONLINE, Label=Solarsteuerung, Bridge=mqtt:broker:MQTTMosquittoBridge)
ipcamera:onvif:Kaninchenkamera (Type=Thing, Status=ONLINE, Label=Kaninchenkamera, Bridge=null)
mqtt:topic:MQTTMosquittoBridge:AgentDVR (Type=Thing, Status=ONLINE, Label=Generic MQTT Thing, Bridge=mqtt:broker:MQTTMosquittoBridge)
exec:command:RestartRaspberryPi4b (Type=Thing, Status=ONLINE, Label=Command, Bridge=null)
avmfritz:FRITZ_DECT_301:Router:KinoHeizung1 (Type=Thing, Status=OFFLINE: Device not present, Label=Heizung 1, Bridge=avmfritz:fritzbox:Router)
avmfritz:FRITZ_DECT_301:Router:KinoHeizung2 (Type=Thing, Status=OFFLINE: Device not present, Label=Heizung 2, Bridge=avmfritz:fritzbox:Router)
shelly:shellydimmer2:Audiencelight (Type=Thing, Status=ONLINE, Label=Licht Kino, Bridge=null)
exec:command:logsetwarn (Type=Thing, Status=ONLINE, Label=Command, Bridge=null)
shelly:shelly25-roller:Wohnzimmer (Type=Thing, Status=ONLINE, Label=Fenster, Bridge=null)
ipcamera:onvif:Einfahrtkamera (Type=Thing, Status=ONLINE, Label=Einfahrtkamera, Bridge=null)

rossko57 · July 22, 2022, 9:55am

I think you’re looking at a race here.
openHAB is multithreaded and there really is a lot of stuff thrashing around in competition at startup - which is why a reliable start level “would be nice”.

There’s a whopping clue about the asynchronous behaviour of rules and logging - you’re getting “rule triggered” logs before “rule engine started”.

So levels 40, 50, probably occur long before rules are even loaded. I expect as the rules for those load, they fire immediately. And of course race and compete to see who gets to do anything first.

I’ve been trying to think of a workaround here - something like incrementing a value, instead of just updating it, so that you somehow get the maximum left at the end. Trouble is that any attempt to read/updatean Item is subject to the asynchronous issues.
I don’t think there’s a viable way to do that, short of having a channel feeding us system start level, or a system variable we can ask, a single source of truth.

syntacrsc · July 22, 2022, 10:00am

Yes, that makes sense for 40 and 50.
But the question for levels 80 and 100 never firing still remains - right?

rossko57 · July 22, 2022, 10:06am

Well, one’s easy -

and @gorddel sees level 100

so @J-N-K is trying to help you pin your system’s problem.

I’m just not sure the idea of a single Item to capture start level is going to work out.

Best I can suggest is a separate Item for each rule, i.e. an Item representing each level you are interested in. You could put those in a Group and use the MAX group state … that way it does not matter which order various levels get reported in.

syntacrsc · July 22, 2022, 10:19am

Thanks for your help @rossko57!
I’ll give that a shot (seperate items and a group w/ MAX)…

J-N-K · July 22, 2022, 4:10pm

If you look at the output: there are several things UNINITIALIZED or CONFIGURATION_PENDING. Fix those and you’ll reach startlevel 100.

syntacrsc · July 22, 2022, 5:06pm

Hi Jan.

Thanks for your help - I was able to identify and fix the issues with unititialized things (guess with 100+ things it’s inevitable to have some orphaned entries in things files).
Monitoring the start level seems to be a (one) good way to identify this issue.

With my things files fixed I now finally see start level 100

I also see start level 80 has been fired which according to OH 3.3.0 docu is “planned, not included yet” - interesting!

Thanks again and kind regards,
Ralph…

rossko57 · July 23, 2022, 9:31am

I think the way it works is that to get to 100 it must pass through ALL of 1 to 99 as well.
But 99 doesn’t indicate anything different from 98 or 100, etc.