SystemStartlevelTrigger in javascript

1

Hello everyone,

I have a question or rather a problem with the start levels.

I want to write a rule in JavaScript that responds generically to each individual start level. While testing, I saw that event.raw contains the start level, and I thought that this would allow me to create a rule for all start levels.

I have the following rule:

rules.JSRule({
    name: "js SystemStartlevelTrigger",
    triggers: [triggers.SystemStartlevelTrigger(40),triggers.SystemStartlevelTrigger(50),triggers.SystemStartlevelTrigger(70),triggers.SystemStartlevelTrigger(80),triggers.SystemStartlevelTrigger(100)],
    execute: (event) => {
        
        const devMode = true;
        const log = devMode ? console.log : () => { };
        const now = time.ZonedDateTime.now();
        const timeStamp = now.toInstant().toEpochMilli();
        const ruleName = 'js SystemStartlevelTrigger - | '+timeStamp+' | '+event.raw;

        log(ruleName + ' start');
		log(ruleName + ' end');
    },
});

However, I get the following result:

2025-11-10 14:41:39.843 [INFO ] [automation.script.file.startlevel.js] - js SystemStartlevelTrigger - | 1762782099826 | {event=Startlevel '40' reached., startlevel=40} start
2025-11-10 14:41:39.844 [INFO ] [automation.script.file.startlevel.js] - js SystemStartlevelTrigger - | 1762782099826 | {event=Startlevel '40' reached., startlevel=40} end
2025-11-10 14:41:44.176 [INFO ] [automation.script.file.startlevel.js] - js SystemStartlevelTrigger - | 1762782104155 | {b6dfe8f4-1c3a-4978-8d06-ba00b21d9c9e.event=Startlevel '80' reached., b6dfe8f4-1c3a-4978-8d06-ba00b21d9c9e.startlevel=80, event=Startlevel '80' reached., startlevel=80, module=b6dfe8f4-1c3a-4978-8d06-ba00b21d9c9e} start
2025-11-10 14:41:44.178 [INFO ] [automation.script.file.startlevel.js] - js SystemStartlevelTrigger - | 1762782104155 | {b6dfe8f4-1c3a-4978-8d06-ba00b21d9c9e.event=Startlevel '80' reached., b6dfe8f4-1c3a-4978-8d06-ba00b21d9c9e.startlevel=80, event=Startlevel '80' reached., startlevel=80, module=b6dfe8f4-1c3a-4978-8d06-ba00b21d9c9e} end
2025-11-10 14:41:44.203 [INFO ] [automation.script.file.startlevel.js] - js SystemStartlevelTrigger - | 1762782104185 | {424ac18d-7a42-418b-a7f5-e33ee846f489.startlevel=70, event=Startlevel '80' reached., 424ac18d-7a42-418b-a7f5-e33ee846f489.event=Startlevel '80' reached., startlevel=70, module=424ac18d-7a42-418b-a7f5-e33ee846f489} start
2025-11-10 14:41:44.204 [INFO ] [automation.script.file.startlevel.js] - js SystemStartlevelTrigger - | 1762782104185 | {424ac18d-7a42-418b-a7f5-e33ee846f489.startlevel=70, event=Startlevel '80' reached., 424ac18d-7a42-418b-a7f5-e33ee846f489.event=Startlevel '80' reached., startlevel=70, module=424ac18d-7a42-418b-a7f5-e33ee846f489} end
2025-11-10 14:41:44.208 [INFO ] [automation.script.file.startlevel.js] - js SystemStartlevelTrigger - | 1762782104207 | {541bab18-1bfe-4552-b318-b195fa145a7e.startlevel=100, 541bab18-1bfe-4552-b318-b195fa145a7e.event=Startlevel '100' reached., event=Startlevel '100' reached., startlevel=100, module=541bab18-1bfe-4552-b318-b195fa145a7e} start
2025-11-10 14:41:44.209 [INFO ] [automation.script.file.startlevel.js] - js SystemStartlevelTrigger - | 1762782104207 | {541bab18-1bfe-4552-b318-b195fa145a7e.startlevel=100, 541bab18-1bfe-4552-b318-b195fa145a7e.event=Startlevel '100' reached., event=Startlevel '100' reached., startlevel=100, module=541bab18-1bfe-4552-b318-b195fa145a7e} end

This seems wrong to me, or am I thinking about it wrong?

If I write a rule with SystemStartlevelTrigger for every possible level (40, 50, 70, 80, 100) and write the start level statically in the rule, each one is reached in successionā€¦

Anyone have any ideas?

2

There are no guarantees that two events that occur really close together in OH will be processed in order.

Beyond that :person_shrugging: . Iā€™m not sure how to interpret the logs youā€™ve provided.

3

@Bloodboy Whatā€™s strange about your logs is that on the second event the text says ā€œStartlevel ā€˜80ā€™ reachedā€, but the payload is set to startlevel 70. I can also confirm this by running your rule on my System. (OpenHab 5.0.3) That has to be some kind of bug.

I also found a strange behaviour. If I change a JSScripting rule with trigger SystemStartlevelTrigger(100) the rule getā€™s triggered immediately with startlevel 40 as a payload. This is a problem because I use Typescript to generate the js files, so the files get updated every time I change something in any file. I also tested this with the new Python Scripting rules and the same thing happens there.

If I create separate DSL Rules for every system start level I get a clean result on startup and when changing something in the rule:

DSL Rulee System reached start level 20
DSL Rule: System reached start level 40
DSL Rule: System reached start level 50
DSL Rule: System reached start level 70
DSL Rule: System reached start level 80
DSL Rule: System reached start level 100

I guess I will use DSL Rules for system startup events for now until this works better in the new automation rules. I can just update an item with the current startup level in the DSL rules and then use this event to trigger the new automation rules.

4

Being immediately triggered is the expected and designed behavior. All rules will work this way.

When a rule file is changed, all the rules in that file get removed from OH. Then when the file gets loaded again all those rules are recreated anew. The system start level triggers for these new rules check to see if OH has reached that runlevel and if so, triggers the rule.

There was a lot of back and forth on this behavior and this is what the maintainers decided upon.

But the payload part is definitely not right. You or @Bloodboy should file an issue on openhab-js on the payload issue.

For a data point, Iā€™m not seeing this behavior or problem in UI rules.

5

I donā€™t think this problem is only related to openhab-js because I see the exact same behaviour in the Python Rules. Here is my Python test script and the output when starting OpenHAB:

Python rule:

from openhab import rule
from openhab.triggers import SystemStartlevelTrigger

@rule(
    triggers=[
        SystemStartlevelTrigger(20),
        SystemStartlevelTrigger(40),
        SystemStartlevelTrigger(50),
        SystemStartlevelTrigger(70),
        SystemStartlevelTrigger(80),
        SystemStartlevelTrigger(100),
    ]
)
class Test:
    def execute(self, module, input):
        for key, value in input.items():
            self.logger.error(f"{key} = {value}")

Log Output:

2025-12-03 16:40:46.888 [ERROR] [ythonscripting.systemStartLevel.Test] - event = Startlevel '40' reached.
2025-12-03 16:40:46.896 [ERROR] [ythonscripting.systemStartLevel.Test] - startlevel = 40

2025-12-03 16:41:40.471 [ERROR] [ythonscripting.systemStartLevel.Test] - bf0730dfbfb34d81a03fd4f2c5d2cb7d.startlevel = 80
2025-12-03 16:41:40.473 [ERROR] [ythonscripting.systemStartLevel.Test] - event = Startlevel '80' reached.
2025-12-03 16:41:40.474 [ERROR] [ythonscripting.systemStartLevel.Test] - bf0730dfbfb34d81a03fd4f2c5d2cb7d.event = Startlevel '80' reached.
2025-12-03 16:41:40.474 [ERROR] [ythonscripting.systemStartLevel.Test] - startlevel = 80
2025-12-03 16:41:40.475 [ERROR] [ythonscripting.systemStartLevel.Test] - module = bf0730dfbfb34d81a03fd4f2c5d2cb7d

2025-12-03 16:41:40.481 [ERROR] [ythonscripting.systemStartLevel.Test] - event = Startlevel '80' reached.
2025-12-03 16:41:40.482 [ERROR] [ythonscripting.systemStartLevel.Test] - 7215827fa0fa40cd8a34d897afd2c238.startlevel = 70
2025-12-03 16:41:40.483 [ERROR] [ythonscripting.systemStartLevel.Test] - 7215827fa0fa40cd8a34d897afd2c238.event = Startlevel '80' reached.
2025-12-03 16:41:40.483 [ERROR] [ythonscripting.systemStartLevel.Test] - startlevel = 70
2025-12-03 16:41:40.484 [ERROR] [ythonscripting.systemStartLevel.Test] - module = 7215827fa0fa40cd8a34d897afd2c238

2025-12-03 16:41:40.488 [ERROR] [ythonscripting.systemStartLevel.Test] - event = Startlevel '100' reached.
2025-12-03 16:41:40.489 [ERROR] [ythonscripting.systemStartLevel.Test] - 3d9fe59a7e7b4a63a95520b94961325b.startlevel = 100
2025-12-03 16:41:40.489 [ERROR] [ythonscripting.systemStartLevel.Test] - 3d9fe59a7e7b4a63a95520b94961325b.event = Startlevel '100' reached.
2025-12-03 16:41:40.490 [ERROR] [ythonscripting.systemStartLevel.Test] - startlevel = 100
2025-12-03 16:41:40.491 [ERROR] [ythonscripting.systemStartLevel.Test] - module = 3d9fe59a7e7b4a63a95520b94961325b

Here is also the wrong start level payload on the second event. I also get the same behaviour when changing a rule file that only an event with level 40 is triggered, even I explicitly only configured level 100. When Iā€™m using the DSL rules I get events from all levels from 40 to 100 and also in the correct order.

I also tested this with UI rules and got the same result as with the files. Are you already testing this on OpenHab 5.1? In this case this problem was maybe fixed in the meantime. But if not I think this will be a deeper problem somewhere in the base of the automation code because JSScripting and Python Scripting has the same behaviour.

6

Iā€™m on 5.1 M3. But Iā€™ve not and probably will not have time to do a thorough test anytime soon. I may have missed something. I just restarted OH and observed that that system startlevel rules I have triggered when they were supposed to and the payload was correct.

If itā€™s both, the issue probably belongs on openhab-core.

7

I just tested this on my local computer with OpenHab 5.0 and 5.1. The Problem from @Bloodboy with the different startlevels in the same event seems to be fixed with 5.1.

But the problem that when I save a js file with trigger level 100 and get an event with level 40 still exists in 5.1. I have this problem also when saving a rule in the UI.

Here is a test script with all log levels you can load in the UI:

configuration: {}
triggers:
  - id: "1"
    configuration:
      startlevel: 20
    type: core.SystemStartlevelTrigger
  - id: "2"
    configuration:
      startlevel: 40
    type: core.SystemStartlevelTrigger
  - id: "3"
    configuration:
      startlevel: 50
    type: core.SystemStartlevelTrigger
  - id: "4"
    configuration:
      startlevel: 70
    type: core.SystemStartlevelTrigger
  - id: "5"
    configuration:
      startlevel: 80
    type: core.SystemStartlevelTrigger
  - id: "6"
    configuration:
      startlevel: 100
    type: core.SystemStartlevelTrigger
conditions: []
actions:
  - inputs: {}
    id: "7"
    configuration:
      type: application/javascript
      script: >-
        var strLevel = "";

        switch (startlevel.toString()) {
          case '20':
            strLevel = "(System Started)";
            break;
          case '40':
            strLevel = "(Rules are loaded)";
            break;
          case '50':
            strLevel = "(Rules Engine active)";
            break;
          case '70':
            strLevel = "(UI is active)";
            break;
          case '80':
            strLevel = "(All things initialized)";
            break;
          case '100':
            strLevel = "(Startup complete)";
        } 

        console.error("System Start
        Level:",startlevel.toString(),strLevel,event);
    type: script.ScriptAction

When I change this rule in the UI I only get a log entry for level 40.

8

When you restart do you see them all or just 40?
Do you actually ever see 20? It probably wonā€™t actually run until after 40, but I suppose it might trigger anyway. You can only set a start level of 20 on a rule in the UI by using the code tab I think.

This might be expected behavior. I donā€™t know. I could see the devs deciding that when a rule is loaded after a start level has passed, it only triggers the rule for one of them even if the same rule has triggers for more than one.

Iā€™d still file an issue though. That feels like a needless restriction.

9

There are some ā€œinconsistenciesā€ in the triggering code, I started to look at it a while ago in relation to this PR:

I was distracted by something else, and never got anywhere, other than that I remember that the logic didnā€™t look sound to me.

(unless my memory tricks me, I think the precompilation of scripts complicated the matter when it was introduced)

1 Like
10

I only see the startlevel 40 event after changing the rule. It does not matter if only one trigger for level 100 is configured, or if a trigger for every runlevel is configured. I will try to see if I can find the source of this in the code in a develompment installation to see if this is intentional or just a bug. This would also make things much easier for the developers.

The level 20 event is only triggered in the DSL rules. I guess the DSL rule get loaded earlier than the new automation rules. I even remember reading this in the JSScripting documentation somewhere.

11

Sadly I was not able to debug this in a developent environment. I could not get the jsscripting bundle to work for some reason. I guess this needs a lot more configuration to get it to work because of the GraalJs dependencies.

I now just created an Issue for this in the openhab-core repository: [automation] Startlevel payload in automation rules always set to level 40 after saving rule. Ā· Issue #5177 Ā· openhab/openhab-core Ā· GitHub

12

GraalJS add-ons donā€™t work in the development environment. But, I donā€™t think you need JS to debug it, Iā€™m pretty sure that the problem is the same in any other scripting language. Ruby will work, although it can be quite ā€œmoodyā€. Groovy and Jython works as well.

13

@Nadahar Thanks for the hint. It was also not easy, but I got Jython to run in the development environment and I think I found the problem.

When the automation rule is saved the code below this line getā€™s executed: openhab-core/bundles/org.openhab.core.automation/src/main/java/org/openhab/core/automation/internal/RuleEngineImpl.java at b3e583867ebbda437f54dae0e449a75373c3662b Ā· openhab/openhab-core Ā· GitHub

First there is a check if the rule contains a start level trigger that is below or equal to the current start level. If this is true it always sends the StartLevelService.STARTLEVEL_RULES level, which is the level 40.

I will ask on GitHub whatā€™s the reason behind this logic.

1 Like
14

Donā€™t be too sure there is one, or that you get the answer :wink:

It seems to come from this PR:

Maybe itā€™s simply a mistake, and the ā€œtriggeringā€ startlevel instead of the actual startlevel is sent. In most situations they will be the same, so itā€™s not necessarily something you easily pick up on.

15

(post deleted by author)