Possible bug in Openhab?

kchest · June 19, 2025, 4:54pm

I am a bit nervious about using the above title, I don’t want to cause any consternation or make any accusations, but I’m at a loss to explain the behavior of my system.

I have several javascript rules which I have created through the Main UI. Several of them include conditions. Some of these conditions are Item Event conditions, some are script conditions. At random times, a script - never the same one, will run when triggered - disregarding the conditions. If the misbehaving rule had an Item Event condition I would change it to a Script condition, thinking it was more reliable. Some time afterwards another rule with a script condition would start misbehaving in the same way - ignoring the conditions and running.

Whenever I edit the condition the rule always starts working again. It’s like the observer effect in quantum physics.

Since this happens only sporadically, with random rules, and stops once I interact with the rule, I am at a loss to troubleshoot it, or how to isolate it. I don’t think it makes sense to post a rule or increase rule logging. I mostly wanted to bring it up to the developers for their awareness, and perhaps someone might have a suggestion on how to isolate this problem.

Platform information:

Hardware: Gigabyte Brix MiniPC model GB-BXI7-5775R/MBHM87P-00 BIOS F2. 8GB RAM, 228GB HDD.
OS: Ubuntu 24.04.1 LTS
Java Runtime Environment: Zulu17.52+17-CA (build 17.0.12+7-LTS)
openHAB version: 4.3.1
Prevous discusions on this topic: Comparison in Main UI Rule not working? - #13 by kchest

hmerk · June 19, 2025, 5:00pm

We definitely need to see the rules running wiered…

kchest · June 19, 2025, 5:20pm

How exactly? The rules run with throwing any entries in the log, without errors. I’m not sure what to do.

rlkoshak · June 19, 2025, 5:42pm

Put org.openhab into DEBUG level logging, maybe even trace level logging. Capture any relevant logs related to the evaluation of the condition when a rule misbehaves.

Since these are managed rules and it happens for Item conditions it’s core that is misbehaving.

To identify the problem and possibly reproduce it will require knowing the states of all the relevant Items at the time of misbehavior (you might need to put openhab.event.ItemStateUpdatedEvent into INFO level to see Item updates in events.log for this) and what openHAB does when the rule triggers and the yaml of the rule that misbehaved assocaited with those logs.

kchest · July 2, 2025, 7:31am

Yesterday a rule started ignoring the condition script contained in the javascript rule. The rule ran several times yesterday morning and this morning as the temperature in the living room was frequently changing. Here’s some snippets from the openhablog during the times the rule ran:

2025-07-02 06:10:59.166 [DEBUG] [pdb.internal.MapDbPersistenceService] - store called for LivingroomSensor_Temperature
2025-07-02 06:10:59.166 [DEBUG] [pdb.internal.MapDbPersistenceService] - store called for Temperatures
2025-07-02 06:10:59.167 [DEBUG] [e.automation.internal.RuleEngineImpl] - The trigger '4' of rule 'Bedroom_Temp_Control' is triggered.
2025-07-02 06:10:59.167 [DEBUG] [.monitor.internal.metrics.RuleMetric] - Rule Bedroom_Temp_Control RUNNING - updating metric.
2025-07-02 06:10:59.167 [DEBUG] [.handler.AbstractScriptModuleHandler] - Executing pre-compiled script of rule with UID 'Bedroom_Temp_Control'
2025-07-02 06:10:59.168 [DEBUG] [.internal.OpenhabGraalJSScriptEngine] - Lock released.
2025-07-02 06:10:59.168 [DEBUG] [.handler.AbstractScriptModuleHandler] - Executing pre-compiled script of rule with UID 'Bedroom_Temp_Control'
2025-07-02 06:10:59.168 [DEBUG] [or.internal.metrics.EventCountMetric] - Received event on topic openhab/items/Big_Window/command.
2025-07-02 06:10:59.169 [DEBUG] [.internal.OpenhabGraalJSScriptEngine] - Lock released.
2025-07-02 06:10:59.169 [DEBUG] [nternal.profiles.ProfileCallbackImpl] - Delegating command '100' for item 'Big_Window' to handler for channel 'homematic:HmIPW-DRBL4:3014F711A0001F9A49923603:00165BE99E5220:2#LEVEL'
2025-07-02 06:10:59.169 [DEBUG] [or.internal.metrics.EventCountMetric] - Received event on topic openhab/items/Big_Window/state.
2025-07-02 06:10:59.169 [DEBUG] [e.automation.internal.RuleEngineImpl] - The rule 'Bedroom_Temp_Control' is executed.
2025-07-02 06:10:59.169 [DEBUG] [pdb.internal.MapDbPersistenceService] - store called for Big_Window
2025-07-02 06:10:59.169 [DEBUG] [.internal.common.CombinedClassLoader] - Loaded class "org.openhab.core.thing.binding.ThingHandler" by classloader "org.eclipse.osgi.internal.loader.EquinoxClassLoader@3179035d[org.openhab.core.thing:4.3.5(id=221)]" for "[interface org.openhab.core.thing.binding.ThingHandler]"
2025-07-02 06:10:59.169 [DEBUG] [.internal.common.CombinedClassLoader] - Loaded class "org.openhab.core.thing.ChannelUID" by classloader "org.eclipse.osgi.internal.loader.EquinoxClassLoader@3179035d[org.openhab.core.thing:4.3.5(id=221)]" for "[interface org.openhab.core.thing.binding.ThingHandler]"
2025-07-02 06:10:59.169 [DEBUG] [.internal.common.CombinedClassLoader] - Loaded class "org.openhab.core.thing.Thing" by classloader "org.eclipse.osgi.internal.loader.EquinoxClassLoader@3179035d[org.openhab.core.thing:4.3.5(id=221)]" for "[interface org.openhab.core.thing.binding.ThingHandler]"
2025-07-02 06:10:59.170 [DEBUG] [.internal.common.CombinedClassLoader] - Loaded class "org.openhab.core.thing.binding.ThingHandlerCallback" by classloader "org.eclipse.osgi.internal.loader.EquinoxClassLoader@3179035d[org.openhab.core.thing:4.3.5(id=221)]" for "[interface org.openhab.core.thing.binding.ThingHandler]"
2025-07-02 06:10:59.170 [DEBUG] [.internal.common.CombinedClassLoader] - Loaded class "org.openhab.core.thing.ThingStatusInfo" by classloader "org.eclipse.osgi.internal.loader.EquinoxClassLoader@3179035d[org.openhab.core.thing:4.3.5(id=221)]" for "[interface org.openhab.core.thing.binding.ThingHandler]"
2025-07-02 06:10:59.170 [DEBUG] [nternal.common.InvocationHandlerSync] - Already in a safe-call context, executing 'ThingHandler.handleCommand()' directly on 'org.openhab.binding.homematic.internal.handler.HomematicThingHandler@27506789'.
2025-07-02 06:10:59.171 [DEBUG] [ternal.handler.HomematicThingHandler] - Received command '100' for channel 'homematic:HmIPW-DRBL4:3014F711A0001F9A49923603:00165BE99E5220:2#LEVEL'
2025-07-02 06:10:59.171 [DEBUG] [ommunicator.AbstractHomematicGateway] - Sending datapoint '00165BE99E5220:2#LEVEL' with value '0.0' to gateway with id '3014F711A0001F9A49923603' using rxMode 'DEFAULT'
2025-07-02 06:10:59.171 [DEBUG] [pdb.internal.MapDbPersistenceService] - Stored 'LR_Humidity' with state '56 %' as '{"name":"LR_Humidity","state":"org.openhab.core.library.types.QuantityType@@@56 %","timestamp":"Jul 2, 2025, 6:10:59 AM"}' in MapDB database
2025-07-02 06:10:59.179 [DEBUG] [pdb.internal.MapDbPersistenceService] - Stored 'Big_Window' with state '100' as '{"name":"Big_Window","state":"org.openhab.core.library.types.PercentType@@@100","timestamp":"Jul 2, 2025, 6:10:59 AM"}' in MapDB database

2025-07-02 06:20:56.652 [DEBUG] [or.internal.metrics.EventCountMetric] - Received event on topic openhab/items/LivingroomSensor_Temperature/state.
2025-07-02 06:20:56.652 [DEBUG] [pdb.internal.MapDbPersistenceService] - store called for LivingroomSensor_Temperature
2025-07-02 06:20:56.653 [DEBUG] [pdb.internal.MapDbPersistenceService] - store called for Temperatures
2025-07-02 06:20:56.653 [DEBUG] [e.automation.internal.RuleEngineImpl] - The trigger '4' of rule 'Bedroom_Temp_Control' is triggered.
2025-07-02 06:20:56.653 [DEBUG] [.monitor.internal.metrics.RuleMetric] - Rule Bedroom_Temp_Control RUNNING - updating metric.
2025-07-02 06:20:56.653 [DEBUG] [.handler.AbstractScriptModuleHandler] - Executing pre-compiled script of rule with UID 'Bedroom_Temp_Control'
2025-07-02 06:20:56.654 [DEBUG] [ui.internal.items.ItemUIRegistryImpl] - Checking value color for widget 'LR Temperature [%.0f °C]'.
2025-07-02 06:20:56.654 [DEBUG] [.internal.OpenhabGraalJSScriptEngine] - Lock released.
2025-07-02 06:20:56.655 [DEBUG] [ui.internal.items.ItemUIRegistryImpl] - value color for widget 'LR Temperature [%.0f °C]' is 'orange'.
2025-07-02 06:20:56.655 [DEBUG] [.handler.AbstractScriptModuleHandler] - Executing pre-compiled script of rule with UID 'Bedroom_Temp_Control'
2025-07-02 06:20:56.656 [DEBUG] [est.sitemap.internal.SitemapResource] - Sent sitemap event for widget 0108 to subscription 384c319b-0e47-48dd-bbc1-6c600d617a5a.
2025-07-02 06:20:56.656 [DEBUG] [or.internal.metrics.EventCountMetric] - Received event on topic openhab/items/Big_Window/command.
2025-07-02 06:20:56.656 [DEBUG] [.internal.OpenhabGraalJSScriptEngine] - Lock released.
2025-07-02 06:20:56.656 [DEBUG] [nternal.profiles.ProfileCallbackImpl] - Delegating command '100' for item 'Big_Window' to handler for channel 'homematic:HmIPW-DRBL4:3014F711A0001F9A49923603:00165BE99E5220:2#LEVEL'
2025-07-02 06:20:56.657 [DEBUG] [or.internal.metrics.EventCountMetric] - Received event on topic openhab/items/Big_Window/state.
2025-07-02 06:20:56.657 [DEBUG] [e.automation.internal.RuleEngineImpl] - The rule 'Bedroom_Temp_Control' is executed.
2025-07-02 06:20:56.657 [DEBUG] [pdb.internal.MapDbPersistenceService] - store called for Big_Window
2025-07-02 06:20:56.657 [DEBUG] [.internal.common.CombinedClassLoader] - Loaded class "org.openhab.core.thing.binding.ThingHandler" by classloader "org.eclipse.osgi.internal.loader.EquinoxClassLoader@3179035d[org.openhab.core.thing:4.3.5(id=221)]" for "[interface org.openhab.core.thing.binding.ThingHandler]"
2025-07-02 06:20:56.658 [DEBUG] [.internal.common.CombinedClassLoader] - Loaded class "org.openhab.core.thing.ChannelUID" by classloader "org.eclipse.osgi.internal.loader.EquinoxClassLoader@3179035d[org.openhab.core.thing:4.3.5(id=221)]" for "[interface org.openhab.core.thing.binding.ThingHandler]"
2025-07-02 06:20:56.658 [DEBUG] [.internal.common.CombinedClassLoader] - Loaded class "org.openhab.core.thing.Thing" by classloader "org.eclipse.osgi.internal.loader.EquinoxClassLoader@3179035d[org.openhab.core.thing:4.3.5(id=221)]" for "[interface org.openhab.core.thing.binding.ThingHandler]"
2025-07-02 06:20:56.658 [DEBUG] [.internal.common.CombinedClassLoader] - Loaded class "org.openhab.core.thing.binding.ThingHandlerCallback" by classloader "org.eclipse.osgi.internal.loader.EquinoxClassLoader@3179035d[org.openhab.core.thing:4.3.5(id=221)]" for "[interface org.openhab.core.thing.binding.ThingHandler]"
2025-07-02 06:20:56.658 [DEBUG] [.internal.common.CombinedClassLoader] - Loaded class "org.openhab.core.thing.ThingStatusInfo" by classloader "org.eclipse.osgi.internal.loader.EquinoxClassLoader@3179035d[org.openhab.core.thing:4.3.5(id=221)]" for "[interface org.openhab.core.thing.binding.ThingHandler]"
2025-07-02 06:20:56.659 [DEBUG] [nternal.common.InvocationHandlerSync] - Already in a safe-call context, executing 'ThingHandler.handleCommand()' directly on 'org.openhab.binding.homematic.internal.handler.HomematicThingHandler@27506789'.
2025-07-02 06:20:56.659 [DEBUG] [ternal.handler.HomematicThingHandler] - Received command '100' for channel 'homematic:HmIPW-DRBL4:3014F711A0001F9A49923603:00165BE99E5220:2#LEVEL'
2025-07-02 06:20:56.659 [DEBUG] [ommunicator.AbstractHomematicGateway] - Sending datapoint '00165BE99E5220:2#LEVEL' with value '0.0' to gateway with id '3014F711A0001F9A49923603' using rxMode 'DEFAULT'
2025-07-02 06:20:56.662 [DEBUG] [pdb.internal.MapDbPersistenceService] - Stored 'LivingroomSensor_Temperature' with state '25.6 °C' as '{"name":"LivingroomSensor_Temperature","state":"org.openhab.core.library.types.QuantityType@@@25.6 °C","timestamp":"Jul 2, 2025, 6:20:56 AM"}' in MapDB database
2025-07-02 06:20:56.669 [DEBUG] [pdb.internal.MapDbPersistenceService] - Stored 'Temperatures' with state '25.52857142857142857142857142857143' as '{"name":"Temperatures","state":"org.openhab.core.library.types.DecimalType@@@25.52857142857142857142857142857143","timestamp":"Jul 2, 2025, 6:20:56 AM"}' in MapDB database
2025-07-02 06:20:56.669 [DEBUG] [pdb.internal.MapDbPersistenceService] - Stored 'Big_Window' with state '100' as '{"name":"Big_Window","state":"org.openhab.core.library.types.PercentType@@@100","timestamp":"Jul 2, 2025, 6:20:56 AM"}' in MapDB database

2025-07-02 06:33:10.662 [DEBUG] [or.internal.metrics.EventCountMetric] - Received event on topic openhab/items/LivingroomSensor_Temperature/state.
2025-07-02 06:33:10.662 [DEBUG] [pdb.internal.MapDbPersistenceService] - store called for LivingroomSensor_Temperature
2025-07-02 06:33:10.662 [DEBUG] [pdb.internal.MapDbPersistenceService] - store called for Temperatures
2025-07-02 06:33:10.663 [DEBUG] [e.automation.internal.RuleEngineImpl] - The trigger '4' of rule 'Bedroom_Temp_Control' is triggered.
2025-07-02 06:33:10.663 [DEBUG] [.monitor.internal.metrics.RuleMetric] - Rule Bedroom_Temp_Control RUNNING - updating metric.
2025-07-02 06:33:10.663 [DEBUG] [.handler.AbstractScriptModuleHandler] - Executing pre-compiled script of rule with UID 'Bedroom_Temp_Control'
2025-07-02 06:33:10.665 [DEBUG] [.internal.OpenhabGraalJSScriptEngine] - Lock released.
2025-07-02 06:33:10.665 [DEBUG] [ui.internal.items.ItemUIRegistryImpl] - Checking value color for widget 'LR Temperature [%.0f °C]'.
2025-07-02 06:33:10.666 [DEBUG] [ui.internal.items.ItemUIRegistryImpl] - value color for widget 'LR Temperature [%.0f °C]' is 'orange'.
2025-07-02 06:33:10.666 [DEBUG] [.handler.AbstractScriptModuleHandler] - Executing pre-compiled script of rule with UID 'Bedroom_Temp_Control'
2025-07-02 06:33:10.667 [DEBUG] [or.internal.metrics.EventCountMetric] - Received event on topic openhab/items/Big_Window/command.
2025-07-02 06:33:10.667 [DEBUG] [est.sitemap.internal.SitemapResource] - Sent sitemap event for widget 0108 to subscription 3ee44cf7-504c-4ea5-8590-41b3f0eccd5b.
2025-07-02 06:33:10.667 [DEBUG] [.internal.OpenhabGraalJSScriptEngine] - Lock released.
2025-07-02 06:33:10.668 [DEBUG] [e.automation.internal.RuleEngineImpl] - The rule 'Bedroom_Temp_Control' is executed.
2025-07-02 06:33:10.668 [DEBUG] [nternal.profiles.ProfileCallbackImpl] - Delegating command '100' for item 'Big_Window' to handler for channel 'homematic:HmIPW-DRBL4:3014F711A0001F9A49923603:00165BE99E5220:2#LEVEL'
2025-07-02 06:33:10.668 [DEBUG] [or.internal.metrics.EventCountMetric] - Received event on topic openhab/items/Big_Window/state.
2025-07-02 06:33:10.669 [DEBUG] [pdb.internal.MapDbPersistenceService] - store called for Big_Window
2025-07-02 06:33:10.669 [DEBUG] [.internal.common.CombinedClassLoader] - Loaded class "org.openhab.core.thing.binding.ThingHandler" by classloader "org.eclipse.osgi.internal.loader.EquinoxClassLoader@3179035d[org.openhab.core.thing:4.3.5(id=221)]" for "[interface org.openhab.core.thing.binding.ThingHandler]"
2025-07-02 06:33:10.670 [DEBUG] [.internal.common.CombinedClassLoader] - Loaded class "org.openhab.core.thing.ChannelUID" by classloader "org.eclipse.osgi.internal.loader.EquinoxClassLoader@3179035d[org.openhab.core.thing:4.3.5(id=221)]" for "[interface org.openhab.core.thing.binding.ThingHandler]"
2025-07-02 06:33:10.670 [DEBUG] [.internal.common.CombinedClassLoader] - Loaded class "org.openhab.core.thing.Thing" by classloader "org.eclipse.osgi.internal.loader.EquinoxClassLoader@3179035d[org.openhab.core.thing:4.3.5(id=221)]" for "[interface org.openhab.core.thing.binding.ThingHandler]"


2025-07-02 06:48:40.405 [DEBUG] [ommunicator.AbstractHomematicGateway] - Received new (Double) value '25.0' for '000EA0C99DCC2D:1#ACTUAL_TEMPERATURE' from gateway with id '3014F711A0001F9A49923603'
2025-07-02 06:48:40.405 [DEBUG] [converter.type.AbstractTypeConverter] - Converting datapoint '000EA0C99DCC2D:1#ACTUAL_TEMPERATURE' (dpType='FLOAT', dpUnit='°C', dpValue='25.0') with QuantityTypeConverter
2025-07-02 06:48:40.405 [DEBUG] [or.internal.metrics.EventCountMetric] - Received event on topic openhab/items/LivingroomSensor_Temperature/state.
2025-07-02 06:48:40.405 [DEBUG] [pdb.internal.MapDbPersistenceService] - store called for LivingroomSensor_Temperature
2025-07-02 06:48:40.406 [DEBUG] [pdb.internal.MapDbPersistenceService] - store called for Temperatures
2025-07-02 06:48:40.406 [DEBUG] [e.automation.internal.RuleEngineImpl] - The trigger '4' of rule 'Bedroom_Temp_Control' is triggered.
2025-07-02 06:48:40.406 [DEBUG] [.monitor.internal.metrics.RuleMetric] - Rule Bedroom_Temp_Control RUNNING - updating metric.
2025-07-02 06:48:40.406 [DEBUG] [.handler.AbstractScriptModuleHandler] - Executing pre-compiled script of rule with UID 'Bedroom_Temp_Control'
2025-07-02 06:48:40.407 [DEBUG] [.internal.OpenhabGraalJSScriptEngine] - Lock released.
2025-07-02 06:48:40.407 [DEBUG] [.handler.AbstractScriptModuleHandler] - Executing pre-compiled script of rule with UID 'Bedroom_Temp_Control'
2025-07-02 06:48:40.408 [DEBUG] [or.internal.metrics.EventCountMetric] - Received event on topic openhab/items/Big_Window/command.
2025-07-02 06:48:40.408 [DEBUG] [.internal.OpenhabGraalJSScriptEngine] - Lock released.
2025-07-02 06:48:40.408 [DEBUG] [e.automation.internal.RuleEngineImpl] - The rule 'Bedroom_Temp_Control' is executed.
2025-07-02 06:48:40.409 [DEBUG] [or.internal.metrics.EventCountMetric] - Received event on topic openhab/items/Big_Window/state.
2025-07-02 06:48:40.409 [DEBUG] [nternal.profiles.ProfileCallbackImpl] - Delegating command '100' for item 'Big_Window' to handler for channel 'homematic:HmIPW-DRBL4:3014F711A0001F9A49923603:00165BE99E5220:2#LEVEL'
2025-07-02 06:48:40.409 [DEBUG] [pdb.internal.MapDbPersistenceService] - store called for Big_Window
2025-07-02 06:48:40.409 [DEBUG] [.internal.common.CombinedClassLoader] - Loaded class "org.openhab.core.thing.binding.ThingHandler" by classloader "org.eclipse.osgi.internal.loader.EquinoxClassLoader@3179035d[org.openhab.core.thing:4.3.5(id=221)]" for "[interface org.openhab.core.thing.binding.ThingHandler]"
2025-07-02 06:48:40.409 [DEBUG] [.internal.common.CombinedClassLoader] - Loaded class "org.openhab.core.thing.ChannelUID" by classloader "org.eclipse.osgi.internal.loader.EquinoxClassLoader@3179035d[org.openhab.core.thing:4.3.5(id=221)]" for "[interface org.openhab.core.thing.binding.ThingHandler]"
2025-07-02 06:48:40.409 [DEBUG] [.internal.common.CombinedClassLoader] - Loaded class "org.openhab.core.thing.Thing" by classloader "org.eclipse.osgi.internal.loader.EquinoxClassLoader@3179035d[org.openhab.core.thing:4.3.5(id=221)]" for "[interface org.openhab.core.thing.binding.ThingHandler]"
2025-07-02 06:48:40.410 [DEBUG] [.internal.common.CombinedClassLoader] - Loaded class "org.openhab.core.thing.binding.ThingHandlerCallback" by classloader "org.eclipse.osgi.internal.loader.EquinoxClassLoader@3179035d[org.openhab.core.thing:4.3.5(id=221)]" for "[interface org.openhab.core.thing.binding.ThingHandler]"
2025-07-02 06:48:40.410 [DEBUG] [.internal.common.CombinedClassLoader] - Loaded class "org.openhab.core.thing.ThingStatusInfo" by classloader "org.eclipse.osgi.internal.loader.EquinoxClassLoader@3179035d[org.openhab.core.thing:4.3.5(id=221)]" for "[interface org.openhab.core.thing.binding.ThingHandler]"
2025-07-02 06:48:40.411 [DEBUG] [nternal.common.InvocationHandlerSync] - Already in a safe-call context, executing 'ThingHandler.handleCommand()' directly on 'org.openhab.binding.homematic.internal.handler.HomematicThingHandler@27506789'.
2025-07-02 06:48:40.412 [DEBUG] [ternal.handler.HomematicThingHandler] - Received command '100' for channel 'homematic:HmIPW-DRBL4:3014F711A0001F9A49923603:00165BE99E5220:2#LEVEL'
2025-07-02 06:48:40.412 [DEBUG] [ommunicator.AbstractHomematicGateway] - Sending datapoint '00165BE99E5220:2#LEVEL' with value '0.0' to gateway with id '3014F711A0001F9A49923603' using rxMode 'DEFAULT'
2025-07-02 06:48:40.415 [DEBUG] [pdb.internal.MapDbPersistenceService] - Stored 'LivingroomSensor_Temperature' with state '25 °C' as '{"name":"LivingroomSensor_Temperature","state":"org.openhab.core.library.types.QuantityType@@@25 °C","timestamp":"Jul 2, 2025, 6:48:40 AM"}' in MapDB database
2025-07-02 06:48:40.426 [DEBUG] [pdb.internal.MapDbPersistenceService] - Stored 'Temperatures' with state '25.32857142857142857142857142857143' as '{"name":"Temperatures","state":"org.openhab.core.library.types.DecimalType@@@25.32857142857142857142857142857143","timestamp":"Jul 2, 2025, 6:48:40 AM"}' in MapDB database
2025-07-02 06:48:40.426 [DEBUG] [pdb.internal.MapDbPersistenceService] - Stored 'Big_Window' with state '100' as '{"name":"Big_Window","state":"org.openhab.core.library.types.PercentType@@@100","timestamp":"Jul 2, 2025, 6:48:40 AM"}' in MapDB database
2025-07-02 06:48:40.559 [DEBUG] [ommunicator.AbstractHomematicGateway] - Received new (Boolean) value 'false' for '00179BE9937DF3:0#CONFIG_PENDING' from gateway with id '3014F711A0001F9A49923603'
2025-07-02 06:48:40.560 [DEBUG] [ommunicator.AbstractHomematicGateway] - Received new (Boolean) value 'false' for '00179BE9937DF3:0#UNREACH' from gateway with id '3014F711A0001F9A49923603'
2025-07-02 06:48:40.560 [DEBUG] [ommunicator.AbstractHomematicGateway] - Received new (String) value '10.10.7.7' for '00179BE9937DF3:0#IP_ADDRESS' from gateway with id '3014F711A0001F9A49923603'
2025-07-02 06:48:40.564 [DEBUG] [ommunicator.AbstractHomematicGateway] - Received new (Boolean) value 'false' for '00165BE99E5220:0#CONFIG_PENDING' from gateway with id '3014F711A0001F9A49923603'
2025-07-02 06:48:40.565 [DEBUG] [ommunicator.AbstractHomematicGateway] - Received new (Boolean) value 'false' for '00165BE99E5220:0#UNREACH' from gateway with id '3014F711A0001F9A49923603'
2025-07-02 06:48:40.570 [DEBUG] [ommunicator.AbstractHomematicGateway] - Received new (Integer) value '0' for '00165BE99E5220:2#SECTION_STATUS' from gateway with id '3014F711A0001F9A49923603'
2025-07-02 06:48:40.570 [DEBUG] [ommunicator.AbstractHomematicGateway] - Received new (Integer) value '1' for '00165BE99E5220:2#LEVEL_2_STATUS' from gateway with id '3014F711A0001F9A49923603'
2025-07-02 06:48:40.571 [DEBUG] [ommunicator.AbstractHomematicGateway] - Received new (String) value '' for '00165BE99E5220:2#LEVEL_2' from gateway with id '3014F711A0001F9A49923603'
2025-07-02 06:48:40.571 [DEBUG] [ommunicator.AbstractHomematicGateway] - Received new (Integer) value '0' for '00165BE99E5220:2#LEVEL_STATUS' from gateway with id '3014F711A0001F9A49923603'
2025-07-02 06:48:40.571 [DEBUG] [ommunicator.AbstractHomematicGateway] - Received new (Integer) value '1' for '00165BE99E5220:2#PROCESS' from gateway with id '3014F711A0001F9A49923603'
2025-07-02 06:48:40.571 [DEBUG] [ommunicator.AbstractHomematicGateway] - Received new (Double) value '1.0' for '00165BE99E5220:2#LEVEL' from gateway with id '3014F711A0001F9A49923603'
2025-07-02 06:48:40.572 [DEBUG] [ommunicator.AbstractHomematicGateway] - Received new (Integer) value '2' for '00165BE99E5220:2#SECTION' from gateway with id '3014F711A0001F9A49923603'
2025-07-02 06:48:40.572 [DEBUG] [or.internal.metrics.EventCountMetric] - Received event on topic openhab/items/Big_Window/state.
2025-07-02 06:48:40.572 [DEBUG] [ommunicator.AbstractHomematicGateway] - Received new (Integer) value '2' for '00165BE99E5220:2#ACTIVITY_STATE' from gateway with id '3014F711A0001F9A49923603'
2025-07-02 06:48:40.572 [DEBUG] [d4j.internal.RRD4jPersistenceService] - Discarding value 1.0 for item Big_Window with timestamp 1751431720 because a new value (0.0) arrived with the same timestamp.
2025-07-02 06:48:40.572 [DEBUG] [pdb.internal.MapDbPersistenceService] - store called for GF_Rolladen
2025-07-02 06:48:40.572 [DEBUG] [pdb.internal.MapDbPersistenceService] - store called for Big_Window
2025-07-02 06:48:40.594 [DEBUG] [pdb.internal.MapDbPersistenceService] - Stored 'GF_Rolladen' with state '0' as '{"name":"GF_Rolladen","state":"org.openhab.core.library.types.PercentType@@@0","timestamp":"Jul 2, 2025, 6:48:40 AM"}' in MapDB database
2025-07-02 06:48:40.594 [DEBUG] [pdb.internal.MapDbPersistenceService] - Stored 'Big_Window' with state '0' as '{"name":"Big_Window","state":"org.openhab.core.library.types.PercentType@@@0","timestamp":"Jul 2, 2025, 6:48:40 AM"}' in MapDB database

2025-07-02 08:32:26.385 [DEBUG] [ommunicator.AbstractHomematicGateway] - Received new (Boolean) value 'false' for '000EA0C99DCC2D:1#BOOST_MODE' from gateway with id '3014F711A0001F9A49923603'
2025-07-02 08:32:26.385 [DEBUG] [or.internal.metrics.EventCountMetric] - Received event on topic openhab/items/LivingroomSensor_Temperature/state.
2025-07-02 08:32:26.386 [DEBUG] [pdb.internal.MapDbPersistenceService] - store called for LivingroomSensor_Temperature
2025-07-02 08:32:26.386 [DEBUG] [e.automation.internal.RuleEngineImpl] - The trigger '4' of rule 'Bedroom_Temp_Control' is triggered.
2025-07-02 08:32:26.386 [DEBUG] [pdb.internal.MapDbPersistenceService] - store called for Temperatures
2025-07-02 08:32:26.387 [DEBUG] [.monitor.internal.metrics.RuleMetric] - Rule Bedroom_Temp_Control RUNNING - updating metric.
2025-07-02 08:32:26.387 [DEBUG] [.handler.AbstractScriptModuleHandler] - Executing pre-compiled script of rule with UID 'Bedroom_Temp_Control'
2025-07-02 08:32:26.387 [DEBUG] [.internal.OpenhabGraalJSScriptEngine] - Lock released.
2025-07-02 08:32:26.387 [DEBUG] [.handler.AbstractScriptModuleHandler] - Executing pre-compiled script of rule with UID 'Bedroom_Temp_Control'
2025-07-02 08:32:26.388 [DEBUG] [or.internal.metrics.EventCountMetric] - Received event on topic openhab/items/Big_Window/command.
2025-07-02 08:32:26.389 [DEBUG] [.internal.OpenhabGraalJSScriptEngine] - Lock released.
2025-07-02 08:32:26.389 [DEBUG] [nternal.profiles.ProfileCallbackImpl] - Delegating command '100' for item 'Big_Window' to handler for channel 'homematic:HmIPW-DRBL4:3014F711A0001F9A49923603:00165BE99E5220:2#LEVEL'
2025-07-02 08:32:26.389 [DEBUG] [or.internal.metrics.EventCountMetric] - Received event on topic openhab/items/Big_Window/state.
2025-07-02 08:32:26.389 [DEBUG] [e.automation.internal.RuleEngineImpl] - The rule 'Bedroom_Temp_Control' is executed.
2025-07-02 08:32:26.389 [DEBUG] [pdb.internal.MapDbPersistenceService] - store called for Big_Window
2025-07-02 08:32:26.389 [DEBUG] [.internal.common.CombinedClassLoader] - Loaded class "org.openhab.core.thing.binding.ThingHandler" by classloader "org.eclipse.osgi.internal.loader.EquinoxClassLoader@3179035d[org.openhab.core.thing:4.3.5(id=221)]" for "[interface org.openhab.core.thing.binding.ThingHandler]"
2025-07-02 08:32:26.390 [DEBUG] [.internal.common.CombinedClassLoader] - Loaded class "org.openhab.core.thing.ChannelUID" by classloader "org.eclipse.osgi.internal.loader.EquinoxClassLoader@3179035d[org.openhab.core.thing:4.3.5(id=221)]" for "[interface org.openhab.core.thing.binding.ThingHandler]"
2025-07-02 08:32:26.390 [DEBUG] [.internal.common.CombinedClassLoader] - Loaded class "org.openhab.core.thing.Thing" by classloader "org.eclipse.osgi.internal.loader.EquinoxClassLoader@3179035d[org.openhab.core.thing:4.3.5(id=221)]" for "[interface org.openhab.core.thing.binding.ThingHandler]"
2025-07-02 08:32:26.390 [DEBUG] [.internal.common.CombinedClassLoader] - Loaded class "org.openhab.core.thing.binding.ThingHandlerCallback" by classloader "org.eclipse.osgi.internal.loader.EquinoxClassLoader@3179035d[org.openhab.core.thing:4.3.5(id=221)]" for "[interface org.openhab.core.thing.binding.ThingHandler]"
2025-07-02 08:32:26.390 [DEBUG] [est.sitemap.internal.SitemapResource] - Sent sitemap event for widget 010500 to subscription 382e722d-e5f6-4c43-961b-ec0633d4bc73.
2025-07-02 08:32:26.390 [DEBUG] [.internal.common.CombinedClassLoader] - Loaded class "org.openhab.core.thing.ThingStatusInfo" by classloader "org.eclipse.osgi.internal.loader.EquinoxClassLoader@3179035d[org.openhab.core.thing:4.3.5(id=221)]" for "[interface org.openhab.core.thing.binding.ThingHandler]"
2025-07-02 08:32:26.390 [DEBUG] [est.sitemap.internal.SitemapResource] - Sent sitemap event for widget 010500 to subscription 382e722d-e5f6-4c43-961b-ec0633d4bc73.
2025-07-02 08:32:26.391 [DEBUG] [nternal.common.InvocationHandlerSync] - Already in a safe-call context, executing 'ThingHandler.handleCommand()' directly on 'org.openhab.binding.homematic.internal.handler.HomematicThingHandler@27506789'.
2025-07-02 08:32:26.391 [DEBUG] [ternal.handler.HomematicThingHandler] - Received command '100' for channel 'homematic:HmIPW-DRBL4:3014F711A0001F9A49923603:00165BE99E5220:2#LEVEL'
2025-07-02 08:32:26.391 [DEBUG] [ommunicator.AbstractHomematicGateway] - Sending datapoint '00165BE99E5220:2#LEVEL' with value '0.0' to gateway with id '3014F711A0001F9A49923603' using rxMode 'DEFAULT'
2025-07-02 08:32:26.396 [DEBUG] [pdb.internal.MapDbPersistenceService] - Stored 'LivingroomSensor_Temperature' with state '25.3 °C' as '{"name":"LivingroomSensor_Temperature","state":"org.openhab.core.library.types.QuantityType@@@25.3 °C","timestamp":"Jul 2, 2025, 8:32:26 AM"}' in MapDB database
2025-07-02 08:32:26.403 [DEBUG] [pdb.internal.MapDbPersistenceService] - Stored 'Big_Window' with state '100' as '{"name":"Big_Window","state":"org.openhab.core.library.types.PercentType@@@100","timestamp":"Jul 2, 2025, 8:32:26 AM"}' in MapDB database
2025-07-02 08:32:26.403 [DEBUG] [pdb.internal.MapDbPersistenceService] - Stored 'Temperatures' with state '25.14285714285714285714285714285714' as

Here is the yaml of the rule in question:

configuration: {}
triggers:
  - id: "4"
    configuration:
      itemName: LivingroomSensor_Temperature
    type: core.ItemStateChangeTrigger
conditions:
  - inputs: {}
    id: "1"
    configuration:
      type: application/javascript
      script: |-
        items.LivingroomSensor_Temperature.state > 24 ;
        items.Sun_Position.state > 180;
        items.Sun_Position.state < 185;
        items.Current_Cloudiness.state < 0.5;
    type: script.ScriptCondition
actions:
  - inputs: {}
    id: "3"
    configuration:
      type: application/javascript;version=ECMAScript-2021
      script: >
        items.getItem("Bedroom_Shutters").sendCommandIfDifferent("20");

        items.getItem("Big_Window").sendCommandIfDifferent(100)

        setTimeout(()=> {items.getItem("BigWindow_Stop").sendCommand("ON");},
        21000)
    type: script.ScriptAction

Other rules are running as well and the conditions are being checked.

rlkoshak · July 2, 2025, 2:40pm

I’ve never looked at logs from this part of the system before but it looks like it’s executing two scripts per rule trigger as I would expect. I at least see two lock releases.

Add some logging to both your script action and your condition.

Note that most of the code of your condition is meaningless. As written the condition is only letting the rule run when the Current_Cloudiness < 0.5. All the other conditions are not being used.

Only the last line executed of the condition is returned. So the first three lines of the condition as written are meaningless. It’s the equivalent of:


items.LivingroomSensor_Temperature.state > 24 ;
items.Sun_Position.state > 180;
items.Sun_Position.state < 185;
if(items.Current_Cloudiness.state < 0.5) {
  items.getItem("Bedroom_Shutters").sendCommandIfDifferent("20");
  ...
}

Obviously that’s not what you want. You want to include all of those conditions so you need to combine them all on one line same as you would to combine them all on one if() statement.

items.LivingroomSensor_Temperature.state > 24 
&& items.Sun_Position.state > 180
&& items.Sun_Position.state < 185
&& items.Current_Cloudiness.state < 0.5;

Furthermore, what types of Items are these? In JS an Item’s state is always a String so if items.LivingroomSensor_Temperature’s state is “3”, > 24 will return true becuase “3” comes before “24” alphabetically. You need to be using the numeric states of the Items at a minimum. If these are Items with units you should be using the quantity state.

items.LivingroomSensor_Temperature.quantityState.greaterThan("24 °C")
&& items.Sun_Position.quantityState.greaterThan("180 °")
&& items.Sun_Position.quantityState.lessThan("185 °")
&& items.Current_Cloudiness.quantityState.lessThan("50 %");

or

items.LivingroomSensor_Temperature.numericState > 24
&& items.Sun_Position.numericState > 180
&& items.Sun_Position.numericState < 185
&& items.Current_Cloudiness.numericState < 0.5;

The advantage of using quantity types is that it doesn’t matter what unit the Item is actually holding (e.g. it looks lie your cloudiness is holding a unit of one instead of %), we can still do the math using the units we choose in the rule. Conversion between compatable units happens automatically.

I don’t think this is a bug. I think your condition is not working like you think it is.

kchest · July 2, 2025, 4:02pm

Thanks Rich, it seems, once again, that my lack of understanding with JS has come back to bite me in the behind. Thanks for clearing this up. I have had other rules act up in the past, but now I know better what to look for. Thanks for the insight.