The loading of rules from files (*.rules) is repeated twice when the system starts

[yndtrud]

OH: 4.3.0-4.3.5 JAVA: Zulu v17.58.21 CA-JDK v17.0.15 x64 OS: Windows Server 2022 Std Latest HW: ASUSPN41/IntelPentiumSilverN6000@2100/8GB_DDR4-2666/256GB_SSD-WD-GREEN

I noticed that my rules are executed several times when the system starts!!! It seems to me that it has been for a long time, in all versions of 4.3.X, and it seems to me even earlier.

I added to some files with rules the output to the log (logInfo("filename_rules", "Initialization 'filename.rules'");) when the system reaches 100% startup. You can pay attention to the Initialization 'filename.rules' entries - they are duplicated.

In fact, the code is executed twice. Pay attention to openhab.rules with an error. When sending a message via telegram for the first time, an error occurs (it is not clear why), and when openhab.rules is executed again (it is also not clear why the repeated execution occurs), the message is sent normally.

There is an error in the log about compiling javascript rules at system startup, so I created a separate ticket for this issue.

val Integer		system_start_wait = 15 // minutes

val Long			tg_channel_private	= 12345678L
val String			tg_thing			= "telegram:telegramBot:madhomebot"

val String			openhab_rules_start_source 	= "openhab_rules_start"

// openhab-1
rule "OpenHAB: Startup"
when
	System reached start level 100
then	
	if (system_start_wait < (java.lang.management.ManagementFactory.getRuntimeMXBean.getUptime / (1000 * 60)).intValue) return;
	logInfo("openhab_rules", "Initialization 'openhab.rules'");

	try{
		val _tg = getActions("telegram", tg_thing);	
		val _tg_status = getThingStatusInfo(tg_thing);

		if((null !== _tg) && (null !== _tg_status) && ("ONLINE" == _tg_status.getStatus().toString()))
			_tg.sendTelegram(tg_channel_private, "🏁 OpenHAB Ready.");
	}
	catch(Throwable t) {
		logError(openhab_rules_start_source, "telegram send failed: " + t.toString())
	}
end

2025-05-16 16:00:59.752 [INFO ] [org.openhab.core.Activator          ] - Starting openHAB 4.3.5 (Release Build)
2025-05-16 16:01:11.719 [INFO ] [el.core.internal.ModelRepositoryImpl] - Loading model 'debug_sensor_climat_voltage.items'
2025-05-16 16:01:13.127 [INFO ] [el.core.internal.ModelRepositoryImpl] - Loading model 'jdbc.persist'
2025-05-16 16:01:21.758 [INFO ] [.core.model.lsp.internal.ModelServer] - Started Language Server Protocol (LSP) service on port 5007
2025-05-16 16:01:22.163 [INFO ] [el.core.internal.ModelRepositoryImpl] - Loading model 'openhab.rules'
2025-05-16 16:01:27.845 [INFO ] [el.core.internal.ModelRepositoryImpl] - Loading model 'intercom.rules'
2025-05-16 16:01:28.875 [INFO ] [el.core.internal.ModelRepositoryImpl] - Loading model 'rflnk.rules'
2025-05-16 16:01:29.458 [WARN ] [rg.openhab.core.io.net.exec.ExecUtil] - Timeout occurred when executing commandLine '[r:\servers\openhab\userdata\bin\arp-ping.exe, --help]'
2025-05-16 16:01:29.722 [WARN ] [rg.openhab.core.io.net.exec.ExecUtil] - Failed to execute commandLine '[arping, --help]'
2025-05-12 14:58:00.527 [WARN ] [.discovery.sddp.SddpDiscoveryService] - listenActiveScanUnicast() error 'Invalid argument: setsockopt'
2025-05-16 16:01:36.443 [INFO ] [el.core.internal.ModelRepositoryImpl] - Loading model 'socketplug.rules'
2025-05-16 16:01:40.488 [INFO ] [persistence.jdbc.internal.JdbcMapper] - JDBC::openConnection: Driver is available::Yank setupDataSource
2025-05-16 16:01:41.966 [INFO ] [el.core.internal.ModelRepositoryImpl] - Loading model 'bluetooth.rules'
2025-05-16 16:01:42.947 [INFO ] [ab.ui.habpanel.internal.HABPanelTile] - Started HABPanel at /habpanel
2025-05-16 16:01:44.353 [INFO ] [el.core.internal.ModelRepositoryImpl] - Loading model 'lightbulb.rules'
2025-05-16 16:01:49.509 [INFO ] [el.core.internal.ModelRepositoryImpl] - Loading model 'relay.rules'
2025-05-16 16:01:51.404 [INFO ] [el.core.internal.ModelRepositoryImpl] - Loading model 'debug.rules'
2025-05-16 16:01:53.689 [INFO ] [el.core.internal.ModelRepositoryImpl] - Loading model 'siren.rules'
2025-05-16 16:01:56.693 [INFO ] [el.core.internal.ModelRepositoryImpl] - Loading model 'weather.rules'
2025-05-16 16:01:57.365 [INFO ] [el.core.internal.ModelRepositoryImpl] - Loading model 'intrusion.rules'
2025-05-16 16:02:05.893 [ERROR] [b.automation.script.javascript.stack] - Failed to execute script: Error: Failed to get any services of type(s): org.openhab.core.thing.link.ItemChannelLinkRegistry
        at <js>.getService(@openhab-globals.js:2)
        at <js>.236(@openhab-globals.js:2)
        at <js>.o(@openhab-globals.js:2)
        at <js>.605(@openhab-globals.js:2)
        at <js>.o(@openhab-globals.js:2)
        ... 28 more
2025-05-16 16:02:06.236 [ERROR] [b.automation.script.javascript.stack] - Failed to execute script: Error: Failed to get any services of type(s): org.openhab.core.thing.link.ItemChannelLinkRegistry
        at <js>.getService(@openhab-globals.js:2)
        at <js>.236(@openhab-globals.js:2)
        at <js>.o(@openhab-globals.js:2)
        at <js>.605(@openhab-globals.js:2)
        at <js>.o(@openhab-globals.js:2)
        ... 28 more
2025-05-16 16:02:06.632 [ERROR] [b.automation.script.javascript.stack] - Failed to execute script: Error: Failed to get any services of type(s): org.openhab.core.thing.link.ItemChannelLinkRegistry
        at <js>.getService(@openhab-globals.js:2)
        at <js>.236(@openhab-globals.js:2)
        at <js>.o(@openhab-globals.js:2)
        at <js>.605(@openhab-globals.js:2)
        at <js>.o(@openhab-globals.js:2)
        ... 28 more
2025-05-16 16:02:07.455 [INFO ] [el.core.internal.ModelRepositoryImpl] - Loading model 'alarms.rules'
2025-05-16 16:02:21.664 [INFO ] [el.core.internal.ModelRepositoryImpl] - Loading model 'voice.rules'
2025-05-16 16:02:34.310 [INFO ] [el.core.internal.ModelRepositoryImpl] - Loading model 'network.rules'
2025-05-16 16:02:36.968 [INFO ] [el.core.internal.ModelRepositoryImpl] - Loading model 'scenes.rules'
2025-05-16 16:03:09.590 [INFO ] [ternal.dhcp.DHCPPacketListenerServer] - DHCP request packet listener online
2025-05-16 16:03:14.299 [INFO ] [.transport.mqtt.MqttBrokerConnection] - Starting MQTT broker connection to '127.0.0.1' with clientid openhab
2025-05-16 16:03:32.604 [ERROR] [e.automation.internal.RuleEngineImpl] - Failed to compile rule ‘telegrambot' with status 'UNINITIALIZED'
2025-05-16 16:03:32.608 [ERROR] [e.automation.internal.RuleEngineImpl] - Failed to compile rule ‘mobilesmsbot' with status 'UNINITIALIZED'
2025-05-16 16:03:32.614 [ERROR] [e.automation.internal.RuleEngineImpl] - Failed to compile rule ‘javascript' with status 'UNINITIALIZED'
2025-05-16 16:03:32.621 [INFO ] [e.automation.internal.RuleEngineImpl] - Rule engine started.
2025-05-16 16:03:37.605 [INFO ] [ab.core.model.script.bluetooth_rules] - Initialization 'bluetooth.rules'
2025-05-16 16:03:37.607 [INFO ] [penhab.core.model.script.voice_rules] - Initialization 'voice.rules'
2025-05-16 16:03:37.612 [INFO ] [b.core.model.script.socketplug_rules] - Initialization 'socketplug.rules'
2025-05-16 16:03:37.621 [INFO ] [ab.core.model.script.lightbulb_rules] - Initialization 'lightbulb.rules'
2025-05-16 16:03:37.627 [INFO ] [enhab.core.model.script.scenes_rules] - Initialization 'scenes.rules'
2025-05-16 16:03:37.642 [INFO ] [enhab.core.model.script.rflink_rules] - Initialization 'rflink.rules'
2025-05-16 16:03:37.675 [INFO ] [nhab.core.model.script.network_rules] - Initialization 'network.rules'
2025-05-16 16:03:37.706 [INFO ] [nhab.core.model.script.openhab_rules] - Initialization 'openhab.rules'
2025-05-16 16:03:37.715 [ERROR] [.handler.AbstractScriptModuleHandler] - Script execution of rule with UID 'openhab-1' failed: 'sendTelegram' is not a member of 'org.openhab.core.thing.binding.ThingActions'; line 20, column 4, length 70 in openhab
2025-05-16 16:03:37.725 [INFO ] [penhab.core.model.script.debug_rules] - Initialization 'debug.rules'
2025-05-16 16:03:37.732 [INFO ] [enhab.core.model.script.alarms_rules] - Initialization 'alarms.rules'
2025-05-16 16:03:37.738 [INFO ] [penhab.core.model.script.siren_rules] - Initialization 'siren.rules'
2025-05-16 16:03:37.746 [INFO ] [ab.core.model.script.intrusion_rules] - Initialization 'intrusion.rules'
2025-05-16 16:03:37.775 [INFO ] [core.model.script.network_rules] - state initialized
2025-05-16 16:03:37.798 [INFO ] [core.model.script.rflink_rules] - state initialized
2025-05-16 16:03:58.283 [INFO ] [nhab.core.model.script.openhab_rules] - Initialization 'openhab.rules'
2025-05-16 16:04:00.499 [INFO ] [enhab.core.model.script.rflink_rules] - Initialization 'rflink.rules'
2025-05-16 16:04:02.927 [INFO ] [b.core.model.script.socketplug_rules] - Initialization 'socketplug.rules'
2025-05-16 16:04:03.939 [INFO ] [ab.core.model.script.bluetooth_rules] - Initialization 'bluetooth.rules'
2025-05-16 16:04:05.819 [INFO ] [ab.core.model.script.lightbulb_rules] - Initialization 'lightbulb.rules'
2025-05-16 16:04:07.367 [INFO ] [penhab.core.model.script.debug_rules] - Initialization 'debug.rules'
2025-05-16 16:04:08.588 [INFO ] [penhab.core.model.script.siren_rules] - Initialization 'siren.rules'
2025-05-16 16:04:10.355 [INFO ] [ab.core.model.script.intrusion_rules] - Initialization 'intrusion.rules'
2025-05-16 16:04:14.049 [INFO ] [enhab.core.model.script.alarms_rules] - Initialization 'alarms.rules'
2025-05-16 16:04:17.356 [INFO ] [penhab.core.model.script.voice_rules] - Initialization 'voice.rules'
2025-05-16 16:04:18.728 [INFO ] [nhab.core.model.script.network_rules] - Initialization 'network.rules'
2025-05-16 16:04:19.079 [INFO ] [enhab.core.model.script.scenes_rules] - Initialization 'scenes.rules'

[dilyanpalauzov]

Similar to https://github.com/openhab/openhab-core/issues/4395.