When a JSR223 add-on cannot be initialized, `Rule engine started` is not logged

[dilyanpalauzov]

If a rule (JSR223 DSL Rule bundles) throws exception before Rule engine started. is logged, neither the exception, nor Rule engine started. are logged. If a rule throws exception after Rule engine started. is logged, then the exception is also logged.

• Exceptions from rule engines/JSR223 add-ons should be logged, irrespective of whether they happen before or after the Rule engine started. event.

This might be related to https://community.openhab.org/t/openhab-5-startup-problem/, which does not include Rule engine started. in the logs, both when the system runs good, and when the system has not booted correctly.

#5398 modifies DSLRuleProvider.java‎ and Rules.xtext. I apply only the change from Rules.xtext on openHAB 5.2.0 build 5203.

First Scenario

I start openHAB. It logs Rule engine started. I create a file openhab/rules/start.rules:

rule "System started"
when
    System reached start level 100
then
  logError('L', 'System reached start level 100')
end

openhab.log gets:

2026-03-02 13:09:48.421 [INFO ] [e.automation.internal.RuleEngineImpl] - Rule engine started.
2026-03-02 13:13:47.892 [INFO ] [el.core.internal.ModelRepositoryImpl] - Loading DSL model 'start.rules'
2026-03-02 13:13:49.763 [WARN ] [mmon.WrappedScheduledExecutorService] - Scheduled runnable ended with an exception: 
java.lang.NoSuchMethodError: 'org.eclipse.xtext.xbase.XBlockExpression org.openhab.core.model.rule.rules.Rule.getScript()'
	at org.openhab.core.model.rule.runtime.internal.DSLRuleProvider.toRule(DSLRuleProvider.java:275)
	at org.openhab.core.model.rule.runtime.internal.DSLRuleProvider.modelChanged(DSLRuleProvider.java:145)
	at org.openhab.core.model.core.internal.ModelRepositoryImpl.notifyListeners(ModelRepositoryImpl.java:361)
	at org.openhab.core.model.core.internal.ModelRepositoryImpl.addOrRefreshModel(ModelRepositoryImpl.java:157)
	at org.openhab.core.model.core.internal.ModelRepositoryImpl.addOrRefreshModel(ModelRepositoryImpl.java:109)
	at org.openhab.core.model.core.internal.folder.FolderObserver.checkPath(FolderObserver.java:285)
	at org.openhab.core.model.core.internal.folder.FolderObserver.processWatchEvent(FolderObserver.java:340)
	at org.openhab.core.internal.service.WatchServiceImpl$Listener.notify(WatchServiceImpl.java:293)
	at org.openhab.core.internal.service.WatchServiceImpl.lambda$6(WatchServiceImpl.java:278)
	at java.base/java.util.stream.ForEachOps$ForEachOp$OfRef.accept(ForEachOps.java:184)
	at java.base/java.util.stream.ReferencePipeline$2$1.accept(ReferencePipeline.java:179)
	at java.base/java.util.Spliterators$ArraySpliterator.forEachRemaining(Spliterators.java:1024)
	at java.base/java.util.stream.AbstractPipeline.copyInto(AbstractPipeline.java:509)
	at java.base/java.util.stream.AbstractPipeline.wrapAndCopyInto(AbstractPipeline.java:499)
	at java.base/java.util.stream.ForEachOps$ForEachOp.evaluateSequential(ForEachOps.java:151)
	at java.base/java.util.stream.ForEachOps$ForEachOp$OfRef.evaluateSequential(ForEachOps.java:174)
	at java.base/java.util.stream.AbstractPipeline.evaluate(AbstractPipeline.java:234)
	at java.base/java.util.stream.ReferencePipeline.forEach(ReferencePipeline.java:596)
	at org.openhab.core.internal.service.WatchServiceImpl.doNotify(WatchServiceImpl.java:278)
	at org.openhab.core.internal.service.WatchServiceImpl.notifyListeners(WatchServiceImpl.java:262)
	at org.openhab.core.internal.service.WatchServiceImpl.lambda$4(WatchServiceImpl.java:232)
	at java.base/java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:572)
	at java.base/java.util.concurrent.FutureTask.run(FutureTask.java:317)
	at java.base/java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.run(ScheduledThreadPoolExecutor.java:304)
	at java.base/java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1144)
	at java.base/java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:642)
	at java.base/java.lang.Thread.run(Thread.java:1583)

Second Scenario

With openhab/rules/start.rules present, I stop and start openhab. It logs:

2026-03-02 13:17:48.232 [INFO ] [el.core.internal.ModelRepositoryImpl] - Loading DSL model 'start.rules'

It does not log Rule engine started., it does not log exception from DSLRuleProvider.

[openhab-bot]

This issue has been mentioned on openHAB Community. There might be relevant details there:

https://community.openhab.org/t/openhab-5-startup-problem/168551/8