Rule engine not yet started - not executing rule

Hi There,

Iam running openhab3 on docker and configured a rule which I can run manually. But after the trigger comes Iam getting the following log message:

Rule engine not yet started - not executing rule ‘fcdb6f87c4’

Can please somebody help to find a solution?

Many Thanks,

Best regards

Konrad

restart OH?
do you see anything suspicous when running bundle:list in OH console?

No nothing special , the Rules Engines are active …

openhab> bundle:list |grep Rule
161 │ Active │ 80 │ 3.1.0 │ openHAB Core :: Bundles :: Automation Script RuleSupport
198 │ Active │ 80 │ 3.1.0 │ openHAB Core :: Bundles :: Model Rules
199 │ Active │ 80 │ 3.1.0 │ openHAB Core :: Bundles :: Model Rule IDE
200 │ Active │ 80 │ 3.1.0 │ openHAB Core :: Bundles :: Model Rules Runtime

a curios thing is that the logs shows afterwards direct a exception:

18:41:42.955 [DEBUG] [re.automation.internal.RuleEngineImpl] - Rule engine not yet started - not executing rule ‘58961ea251’,
18:41:42.956 [DEBUG] [t.core.internal.GsonMessageBodyWriter] - Failed writing HTTP response, since other side closed the connection
18:41:42.957 [DEBUG] [g.openhab.core.io.rest.SseBroadcaster] - Sending event to sink failed
org.eclipse.jetty.io.EofException: Closed
at org.eclipse.jetty.server.HttpOutput.checkWritable(HttpOutput.java:768) ~[bundleFile:9.4.40.v20210413]
at org.eclipse.jetty.server.HttpOutput.write(HttpOutput.java:792) ~[bundleFile:9.4.40.v20210413]
at java.io.OutputStream.write(OutputStream.java:122) ~[?:?]
at org.apache.cxf.jaxrs.sse.OutboundSseEventBodyWriter.writeTo(OutboundSseEventBodyWriter.java:113) ~[bundleFile:3.4.3]
at org.apache.cxf.jaxrs.sse.OutboundSseEventBodyWriter.writeTo(OutboundSseEventBodyWriter.java:40) ~[bundleFile:3.4.3]
at org.apache.cxf.jaxrs.sse.SseEventSinkImpl.dequeue(SseEventSinkImpl.java:238) ~[bundleFile:3.4.3]
at org.eclipse.jetty.server.handler.ContextHandler.handle(ContextHandler.java:1520) [bundleFile:9.4.40.v20210413]
at org.eclipse.jetty.server.AsyncContextState$1.run(AsyncContextState.java:153) [bundleFile:9.4.40.v20210413]
at org.eclipse.jetty.util.thread.QueuedThreadPool.runJob(QueuedThreadPool.java:882) [bundleFile:9.4.40.v20210413]
at org.eclipse.jetty.util.thread.QueuedThreadPool$Runner.run(QueuedThreadPool.java:1036) [bundleFile:9.4.40.v20210413]
at java.lang.Thread.run(Thread.java:829) [?:?]
18:41:42.960 [DEBUG] [g.openhab.core.io.rest.SseBroadcaster] - Closing SSE event sink
18:41:42.957 [DEBUG] [g.openhab.core.io.rest.SseBroadcaster] - Sending event to sink failed
org.eclipse.jetty.io.EofException: null

did this rule run / was triggered by item change before?

Hi Oliver,

yes the rules runs also if I run this manually. I checked the source code of the RulesEngineImpl Class and as I understood this has something todo with the startlevel but I can’t identify how I can set the startlevel of the rule.

protected void runRule(String ruleUID, TriggerHandlerCallbackImpl.TriggerData td) {
        if (thCallbacks.get(ruleUID) == null) {
            // the rule was unregistered
            return;
        }
        if (!started) {
            logger.debug("Rule engine not yet started - not executing rule '{}',", ruleUID);
            return;
        }

started will be set to true here but I can’t find out how I have to configure the trigger:

private void executeRulesWithStartLevel() {
        getScheduledExecutor().submit(() -> {
            ruleRegistry.getAll().stream() //
                    .filter(r -> mustTrigger(r)) //
                    .forEach(r -> runNow(r.getUID(), true,
                            Map.of(SystemTriggerHandler.OUT_STARTLEVEL, StartLevelService.STARTLEVEL_RULES)));
            started = true;
            readyService.markReady(MARKER);
            logger.info("Rule engine started.");
        });
    }

that was an important informarion that this rule is run by startup trigger.
did you set the startlevel?
https://github.com/openhab/openhab-core/pull/1914

No I have no clue about how and where? Can you help me please?

Many Thanks,

Konrad

If you create the rule in MainUi, click
add trigger
system event
and select the start level

Hi

unfortunately it doesn’t helped. My Rules configuration maybe you can see the error…

triggers:
  - id: "1"
    configuration:
      itemName: Konrad_Anwesend
      state: ON
      startlevel: 50
      previousState: OFF
    type: core.ItemStateChangeTrigger
  - id: "3"
    configuration:
      startlevel: 50
    type: core.SystemStartlevelTrigger
conditions: []
actions:
  - inputs: {}
    id: "2"
    configuration:
      type: application/javascript
      script: >-
        var Actions = Java.type("org.openhab.core.model.script.actions.Things");

        var mailActions = Actions.getActions("mail","mail:smtp:6a99578ade");

        var aufgaben = itemRegistry.getItem('FamilienAufgaben').getState()

        mailActions.sendMail("konrad.eichstaedt@gmx.de", "Offene Aufgaben", aufgaben);
    type: script.ScriptAction

not sure, but you have to delete trigger 1 or set the startlevel to 100

based on your actions I doubt that this rule should be launched at startup.
please explain shortly what you want to achieve

I have an Item which detect my smartphone within LAN. If the Switch changed from OFF to ON I will trigger an email sending.

ok. then we misunderstood each other.

your script has nothing to do with startup rule and startlevel. delete trigger 3 and startlevel: 50 from trigger 1

ok but why can I start this rule manually but not if the item state has been changed?

maybe the current state is NULL or already ON?
go to MainUI’s Developer Tools and start API Explorer.
choose items - post and send OFF and then ON to your item.

or even better change your rule to received command ON

I tried using the API explorer and sending ON and OFF with the following result in the logfile but unfortunately without sending an email.

21:48:05.281 [DEBUG] [re.automation.internal.RuleEngineImpl] - The trigger ‘1’ of rule ‘58961ea251’ is triggered.
21:48:05.281 [DEBUG] [internal.profiles.ProfileCallbackImpl] - Delegating command ‘ON’ for item ‘Konrad_Anwesend’ to handler for channel ‘tr064:subdeviceLan:223534b017:uuid_3A75802409_2Dbccb_2D40e7_2D8e6b_2D3431C4E5430F:macOnline_24_3A18_3A1D_3A8D_3A7E_3AB5’
21:48:05.282 [DEBUG] [re.automation.internal.RuleEngineImpl] - Rule engine not yet started - not executing rule ‘58961ea251’,
21:48:05.282 [DEBUG] [e.internal.common.CombinedClassLoader] - Loaded class “org.openhab.core.thing.binding.ThingHandler” by classloader “org.eclipse.osgi.internal.loader.EquinoxClassLoader@259d669e[org.openhab.binding.tr064:3.1.0(id=242)]” for “[class org.openhab.binding.tr064.internal.Tr064SubHandler]”
21:48:05.283 [DEBUG] [e.internal.common.CombinedClassLoader] - Loaded class “org.openhab.core.thing.ThingStatusInfo” by classloader “org.eclipse.osgi.internal.loader.EquinoxClassLoader@259d669e[org.openhab.binding.tr064:3.1.0(id=242)]” for “[class org.openhab.binding.tr064.internal.Tr064SubHandler]”
21:48:05.283 [DEBUG] [e.internal.common.CombinedClassLoader] - Loaded class “org.openhab.core.thing.ChannelUID” by classloader “org.eclipse.osgi.internal.loader.EquinoxClassLoader@259d669e[org.openhab.binding.tr064:3.1.0(id=242)]” for “[class org.openhab.binding.tr064.internal.Tr064SubHandler]”
21:48:05.284 [DEBUG] [e.internal.common.CombinedClassLoader] - Loaded class “org.openhab.core.thing.binding.ThingHandlerCallback” by classloader “org.eclipse.osgi.internal.loader.EquinoxClassLoader@259d669e[org.openhab.binding.tr064:3.1.0(id=242)]” for “[class org.openhab.binding.tr064.internal.Tr064SubHandler]”
21:48:05.284 [DEBUG] [e.internal.common.CombinedClassLoader] - Loaded class “org.openhab.core.thing.Thing” by classloader “org.eclipse.osgi.internal.loader.EquinoxClassLoader@259d669e[org.openhab.binding.tr064:3.1.0(id=242)]” for “[class org.openhab.binding.tr064.internal.Tr064SubHandler]”
21:48:05.285 [DEBUG] [internal.common.InvocationHandlerSync] - Already in a safe-call context, executing ‘ThingHandler.handleCommand()’ directly on ‘org.openhab.binding.tr064.internal.Tr064SubHandler@33bd027a’.
21:48:05.285 [DEBUG] [inding.tr064.internal.Tr064SubHandler] - Discarding command ON to tr064:subdeviceLan:223534b017:uuid_3A75802409_2Dbccb_2D40e7_2D8e6b_2D3431C4E5430F:macOnline_24_3A18_3A1D_3A8D_3A7E_3AB5, read-only channel
21:48:05.299 [DEBUG] [t.core.internal.GsonMessageBodyWriter] - Failed writing HTTP response, since other side closed the connection
21:48:05.300 [DEBUG] [g.openhab.core.io.rest.SseBroadcaster] - Sending event to sink failed
org.eclipse.jetty.io.EofException: Closed
at org.eclipse.jetty.server.HttpOutput.checkWritable(HttpOutput.java:768) ~[bundleFile:9.4.40.v20210413]
at org.eclipse.jetty.server.HttpOutput.write(HttpOutput.java:792) ~[bundleFile:9.4.40.v20210413]

go to openHAB-conf/rules and create a file test.rules with the following content:

rule "Test"
when
	Item Konrad_Anwesend received command
then
	logInfo("Test","Item Konrad_Anwesend hat rule getriggert")
end

check logfile when saving. Do you see this entry?

if yes, send command ON to your item

Moin oliver,

unfortunately the rules hasn’t been triggered. Maybe the problem is that I’am running in docker. I tried several folder but failed always. Also switching to command recieved failed. The only config which show a trigger logfile was Item status changed from OFF to ON. In this case I’am getting the already known log entry of the relevant trigger.

RuleEngineImpl] - The trigger ‘3’ of rule ‘58961ea251’ is triggered.
08:48:05.051 [DEBUG] [re.automation.internal.RuleEngineImpl] - Rule engine not yet started - not executing rule ‘58961ea251’,
08:48:05.050 [DEBUG] [g.openhab.core.io.rest.SseBroadcaster] - Sending event to sink failed
org.eclipse.jetty.io.EofException: null
at org.eclipse.jetty.io.ChannelEndPoint.flush(ChannelEndPoint.java:279) ~[bundleFile:9.4.40.v20210413]

May last rule config:

triggers:
  - id: "3"
    configuration:
      itemName: Konrad_Anwesend
      state: ON
      previousState: OFF
    type: core.ItemStateChangeTrigger
conditions: []
actions:
  - inputs: {}
    id: "2"
    configuration:
      type: application/javascript
      script: >-
        var Actions = Java.type("org.openhab.core.model.script.actions.Things");

        var mailActions = Actions.getActions("mail","mail:smtp:6a99578ade");

        var aufgaben = itemRegistry.getItem('FamilienAufgaben').getState()

        mailActions.sendMail("konrad.eichstaedt@gmx.de", "Offene Aufgaben", aufgaben);
    type: script.ScriptAction

Have you any experience with docker maybe this is the problem? Because the rule which I created with UI I haven’t found any rules file in the openhab subdirectory?

Was this a clean install or did you do an update - from which version?
did you install any additional scripting modules? if yes, deinstall and use the built-in scripting language.
and maybe try to install a milestone build. just in case a file got corrupted.

If you are using MainUI for creating rules, then the rules folder is empty because MainUI uses a json file for storing rules. I prefer .rules files because when you save a rule you see a syntax check in the log. MainUI does not do this.

It was a clean installation of a docker container with openhab 3.1.0 with no special adjustments. I have none additional scripting language installed but I use javascript instead of DSL because I won’t using an installed SMTP Server addon to send E-Mail. Do you know where I have to put a rules file within docker?