Strange errors in the log file when starting the system

Setup, Configuration and Use Runtime
1

I don’t know what has changed. I don’t even knwo where to begin…
I was running 2.0.something which I now bumped up to the snapshot release from today and now my *.rules aren’t working as they should.
Java isn’t exact my forte but everything was working just fine before.
Running Ubuntu 16.04 on an Odroid C1+

The behavior differs depending on if I power cycle the board or if I do a

$ sudo systemctl stop openhab2.service

followed by a

$ sudo systemctl start openhab2.service

I’m getting a few errors from

java.util.concurrent.locks.ReentrantLock

when power cycling the unit.

This is just a snippet from the *.rules file

import java.util.concurrent.locks.ReentrantLock
var ReentrantLock lock2 = new ReentrantLock()

openhab.log file

2018-12-05 19:49:45.175 [WARN ] [me.internal.engine.RuleContextHelper] - Variable 'lock2' on rule file 'homeAuto.rules' cannot be initialized with value 'org.eclipse.xtext.xbase.impl.XConstructorCallImplCustom@358822 (invalidFeatureIssueCode: null, validFeature: false, explicitConstructorCall: true, anonymousClassConstructorCall: false)': An error occurred during the script execution: null

Get an similar error from all locks created (and wherever they are used it crashes the rule).

This does not happen when I run a start/stop systemctl…
Tried a few times and it appears to be repetative.

With both types of starts I have several errors/problems similar to this one
openhab.log

2018-12-05 19:49:45.523 [ERROR] [ntime.internal.engine.RuleEngineImpl] - Rule 'device_4_tmpStat': The name 'device_4_tmpStat' cannot be resolved to an item or type; line 968, column 7, length 16

*.items

Switch    device_4_tmpStat        "Device_4 - Tmp Status [%s]"          <button>                  (stat)                { channel="network:pingdevice:4:online" }

*.rules

rule "System start"
when
    System started
then
  postUpdate(device_1_tmpStat, OFF)
  ...
end

rule "device_4_tmpStat"
when
  Item device_4_tmpStat changed
then
  if (device_4_tmpStat.state == ON)
  {
    ...
  }
end

the if (device_4_tmpStat.state == ON) is line 968 in the *.rules file.

So there exists an item.
The item is initialiced in the “System started” rule.
The item is detected as changed and the rule activated but when I’m trying to compare the state of the item then it canno be resolved into an item or type.

Ideas as to what might be wroing or what I can try?

2

This is a known bug. OH parses the Items and Rules in parallel when OH starts up. This Rule gets triggered before everything is ready. The part of OH that updates the Items knows about the Item existing and triggers the Rule but the Rule isn’t ready yet and doesn’t know about the Item.

This error will appear only during startup.

3

My question is, why are you using lock?
Do you really have to? They are not the best way to write rules.

1 Like
4

I guess this is a slightly different manifestation than Rick describes, where the rules file parser has tried to create a new lock before the import of lock class has completed. Same underlying cause, lots going on in parallel.
Can’t think of a solution for that, you can’t create a global var in a delayed rule. Maybe some time wasting like doing another (pointless) import in between would do.

Of course if the lock isn’t created properly any rule trying to use it later messes up.

Locks do have their place, but yes, think hard about if needed.

It might be worth raising this as an issue - it’s dopey not to have the rules parser waiting for import to complete before moving on.

5

But how is it possible that the rule is triggered when the item isn’t initilized?!? Even crappy startup procedures shouldn’t be able to accomplish that…

6

Think they are needed but I’ll explore that in another thread. Maybe there is a better way to do it. It just feels very, very strange that you can’t start the system in a predictable manner…

7

If we knew the how the problem would be fixed. All I know, during startup, Rules can start triggering before the file is fully loaded and parsed so ANY symbol has the potential to throw no such symbol errors. I’ve seen it complaining about constants like NULL and ON.

But in this case, the part of OH that triggers the Rule (Event Bus) gets loaded before the Rule does. And the Rule gets registered before the Rule is done being parsed (apparently). So while part of OH will know about the Item and the Rule, the Rules Engine may not yet. It’s a big timing mess since (apparently) the existence of the Rule gets registered before the Rule is able to run.

Hence the open issues:

8

Thx for the information