OH2 Rules Execution

I’m seeing an issue that when a rule executes it cannot access an item’s data. I can see from the log that the data is present. Also I see that a subsequent rule can access the item data. The failing rule is one for the update of the item so maybe the rule engine is not updating the item data in the right order?

I have these items:

String mqttWeatherDataRaw “Weather Raw Data” { mqtt="<[broker:/weather:state:default]" }

These rules:

import org.openhab.core.library.types.*
import java.lang.Math.*

rule "MqttParseWeatherData"
when
Item mqttWeatherDataRaw received update
then
logInfo(“file”, ">>> changed event ")
logInfo(“file”, "
>>> data " + mqttWeatherDataRaw)
end

rule "System started"
when
System started
then {
logInfo(“file”, ">>> system started")
logInfo(“file”, "
>>> data " + mqttWeatherDataRaw)
}
end

Log entries:
09:44:23.332 [INFO ] [basic.internal.servlet.WebAppServlet] - Started Basic UI at /basicui/app
09:44:23.347 [INFO ] [assic.internal.servlet.WebAppServlet] - Started Classic UI at /classicui/app
09:44:23.977 [INFO ] [el.core.internal.ModelRepositoryImpl] - Loading model 'default.rules’
09:44:24.194 [INFO ] [el.core.internal.ModelRepositoryImpl] - Loading model 'default.items’
09:44:24.215 [DEBUG] [binding.mqtt.internal.MqttItemConfig] - Loaded MQTT config for item ‘mqttWeatherDataRaw’ : 1 subscribers, 0 publishers
09:44:24.468 [INFO ] [marthome.event.ItemStateChangedEvent] - mqttWeatherDataRaw changed from NULL to {“timestamp”:“20160613164343”,“temp”:“15.00”,“humidity”:“50.70”,“dew”:“7.73”,“pressure”:“100403.00”,“rpm”:“0.00”,“vane”:“0.00”,“rain”:“6.00”}
09:44:24.877 [INFO ] [.eclipse.smarthome.model.script.file] - **>>> changed event
09:44:24.880 [ERROR] [.script.engine.ScriptExecutionThread] - Error during the execution of rule ‘MqttParseWeatherData’: An error occured during the script execution: The name ‘mqttWeatherDataRaw’ cannot be resolved to an item or type.
09:44:28.267 [INFO ] [.eclipse.smarthome.model.script.file] - **>>> system started
09:44:28.271 [INFO ] [.eclipse.smarthome.model.script.file] - **>>> data mqttWeatherDataRaw (Type=StringItem,State={“timestamp”:“20160613164343”,“temp”:“15.00”,“humidity”:“50.70”,“dew”:“7.73”,“pressure”:“100403.00”,“rpm”:“0.00”,“vane”:“0.00”,“rain”:“6.00”}, Label=Weather Raw Data, Category=null)

OK, this problem exists specifically with items that receive MQTT data during startup from retained MQTT topics. Subsequent updates work just fine.

Since retained messages are a key feature of MQTT and commonly used it would be great is this could be fixed.

Possible?

I think the root cause is your .items files are being loaded after your rules. So what is happening is as OH parses your .items file it is subscribing to and receiving retained MQTT message and consequently triggering the rule before the rest of the .items file is done loading.

You can try putting your MQTT Items as the last thing in your .items file. I suspect that OH loads and creates the Items in sequence so if your MQTT Items are last your Raw Item will exist by the time the retained message is processed and triggers the rule.

You can also try setting it so the rules get loaded after the Items (assuming this can still be done in OH 2). In OH 1 there are some properties in openhab.cfg that start with “folder:” which set the polling period OH uses to look for changes in files. Setting “folder:rules” to something larger than “folder:items”. This will ensure that all your Items exist before any rules run. I don’t know though whether this will cause the retained message to not be processed by a rule. You will have to experiment to find out if you go down this path.

In this test there is only 1 item in the items file so it is last.

I’ll look at your suggestion of the polling period, but even so this is a bug. There is an inherent ordering problem in OH here.

If you think it is a bug or a design fault you should create an issue, I think in the Eclipse Smarthome repo.

I wonder that the system started rule works at all, since you need to access mqttWeatherDataRaw.state and not just mqttWeatherDataRaw. Does this make any difference?

Not meaning to hijack the thread but I have wondered about execution of things during startup as well.
For example, I have MapDb restoreOnStartup for many of my items, I have rules and items of course as well.
I have rules that shouldn’t be started unless the item has been restored but can’t figure out what the startup sequence is.
I have read about configuring this sequence in openhab.cfg in OH1.8 but I’m using OH2 and this doesn’t exist.
I thought that I could set up a single “on startup” rule in each rules file that would set a flag, and all rules in each rule file would check this. A timer would clear this flag after a reasonable amount of time and all rules would become active.
Could this work as long as the “on System startup” rule in each rule file is the first (at the top)?
Do all rules in a rule file startup (almost) at the same time?
Would there be a race condition here?

FWIW, I just saw this post:
https://community.openhab.org/t/rule-load-reload-and-shutdown/10280/3?u=nekmech

Seems like a workaround I may be able to implement but ideally not in a rule that needs to do something since it seems wasteful to check a timer every time it executes. Maybe to set a global var in each rule file.

Checking a timer is no different than checking a global var.