search

AbuNaifAlharbi / openhab

Automatically exported from code.google.com/p/openhab
GNU General Public License v3.0
0 stars 0 forks source link

Same variable declaration in different rule files results in strange behaviour #487

Closed GoogleCodeExporter closed 9 years ago

GoogleCodeExporter commented 9 years ago 
If the same variable is defined in different rule files and rules are triggered 
at the same time, the variables get the wrong value. As described in the wiki 
and as confirmed by Kai in this discussion:

https://groups.google.com/d/topic/openhab/0ubr-1mC7nY/discussion

Variables should be local to a rule file.

I can easily reproduce this issue with 1.3.1 using the two rule files shown 
below with the demo configuration (sorry file attachment does not seem to work 
=> quota exceeded):

==> rule_a.rules
import org.openhab.core.library.types.*
import org.openhab.core.persistence.*
import org.openhab.model.script.actions.*

val Number position = 0
var Number counter = 0

rule "Rule A"
when
    Item Light_FF_Bath_Ceiling changed
then
    logInfo("rule_a", "Rule A: position = " + position)
    counter = counter + 1
    logInfo("rule_a", "Rule A: counter = " + counter)
end
<==

==> rule_b.rules
import org.openhab.core.library.types.*
import org.openhab.core.persistence.*
import org.openhab.model.script.actions.*

val Number position = 1
var Number counter = 0

rule "Rule B"
when
    Item Light_FF_Bath_Ceiling changed
then
    logInfo("rule_b", "Rule B: position = " + position)
    counter = counter + 1
    logInfo("rule_b", "Rule B: counter = " + counter)
end
<==

Here is the output I get:

13:44:33.894 DEBUG o.o.m.r.i.engine.RuleEngine[:305] - Executing rule 'Rule A'
13:44:33.900 DEBUG o.o.m.r.i.engine.RuleEngine[:305] - Executing rule 'Rule B'
13:44:33.911 INFO  o.openhab.model.script.rule_a[:73] - Rule A: position = 1
13:44:33.915 INFO  o.openhab.model.script.rule_b[:73] - Rule B: position = 1
13:44:33.933 INFO  o.openhab.model.script.rule_a[:73] - Rule A: counter = 1
13:44:33.937 INFO  o.openhab.model.script.rule_b[:73] - Rule B: counter = 1
13:44:35.388 INFO  runtime.busevents[:42] - Light_FF_Bath_Ceiling received 
command OFF
13:44:35.390 DEBUG o.o.m.r.i.engine.RuleEngine[:305] - Executing rule 'Rule A'
13:44:35.390 DEBUG o.o.m.r.i.engine.RuleEngine[:305] - Executing rule 'Rule B'
13:44:35.391 INFO  o.openhab.model.script.rule_a[:73] - Rule A: position = 1
13:44:35.391 INFO  o.openhab.model.script.rule_b[:73] - Rule B: position = 1
13:44:35.392 INFO  o.openhab.model.script.rule_a[:73] - Rule A: counter = 2
13:44:35.392 INFO  o.openhab.model.script.rule_b[:73] - Rule B: counter = 3
13:44:36.884 INFO  runtime.busevents[:42] - Light_FF_Bath_Ceiling received 
command ON
13:44:36.886 DEBUG o.o.m.r.i.engine.RuleEngine[:305] - Executing rule 'Rule A'
13:44:36.887 DEBUG o.o.m.r.i.engine.RuleEngine[:305] - Executing rule 'Rule B'
13:44:36.887 INFO  o.openhab.model.script.rule_a[:73] - Rule A: position = 1
13:44:36.888 INFO  o.openhab.model.script.rule_b[:73] - Rule B: position = 1
13:44:36.888 INFO  o.openhab.model.script.rule_a[:73] - Rule A: counter = 4
13:44:36.888 INFO  o.openhab.model.script.rule_b[:73] - Rule B: counter = 5
13:44:37.637 INFO  runtime.busevents[:42] - Light_FF_Bath_Ceiling received 
command OFF
13:44:37.639 DEBUG o.o.m.r.i.engine.RuleEngine[:305] - Executing rule 'Rule A'
13:44:37.639 DEBUG o.o.m.r.i.engine.RuleEngine[:305] - Executing rule 'Rule B'
13:44:37.640 INFO  o.openhab.model.script.rule_a[:73] - Rule A: position = 1
13:44:37.640 INFO  o.openhab.model.script.rule_b[:73] - Rule B: position = 1
13:44:37.641 INFO  o.openhab.model.script.rule_a[:73] - Rule A: counter = 6
13:44:37.641 INFO  o.openhab.model.script.rule_b[:73] - Rule B: counter = 6
13:44:41.821 INFO  runtime.busevents[:42] - Light_FF_Bath_Ceiling received 
command ON
13:44:41.823 DEBUG o.o.m.r.i.engine.RuleEngine[:305] - Executing rule 'Rule A'
13:44:41.823 DEBUG o.o.m.r.i.engine.RuleEngine[:305] - Executing rule 'Rule B'
13:44:41.824 INFO  o.openhab.model.script.rule_a[:73] - Rule A: position = 1
13:44:41.824 INFO  o.openhab.model.script.rule_b[:73] - Rule B: position = 1
13:44:41.825 INFO  o.openhab.model.script.rule_a[:73] - Rule A: counter = 7
13:44:41.825 INFO  o.openhab.model.script.rule_b[:73] - Rule B: counter = 8

So I suspect that somehow the context is shared during the execution of these 
rules. This may cause really strange behavior (I had a hard time debugging my 
scripts until I found the issue was in OH).

Original issue reported on code.google.com by cyril.ja...@gmail.com on 8 Oct 2013 at 11:48

GoogleCodeExporter commented 9 years ago 
I can confirm I am seeing the same thing (in 1.4.0 SNAPSHOT). See discussion 
here (https://groups.google.com/forum/#!topic/openhab/3OHBFnliUe8) for details.

Original comment by ben.jone...@gmail.com on 9 Oct 2013 at 9:33

GoogleCodeExporter commented 9 years ago 
Maybe this is related to this bug:

I have two rules which are using equally named local (randomOffset zn this 
exampe) and the same trigger in two different rules files. Whenever these rules 
are triggered I get a null pointer exception. It seems as if this exception is 
triggered by the rule loaded last.

Everything seems to be fine when the rules are in the same rules file! 

java.lang.NullPointerException: null
    at org.openhab.model.script.lib.NumberExtensions.operator_multiply(NumberExtensions.java:62)
    at sun.reflect.GeneratedMethodAccessor72.invoke(Unknown Source)
    at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
    at java.lang.reflect.Method.invoke(Method.java:606)
    at org.eclipse.xtext.xbase.interpreter.impl.XbaseInterpreter.invokeOperation(XbaseInterpreter.java:729)
    at org.eclipse.xtext.xbase.interpreter.impl.XbaseInterpreter._featureCallOperation(XbaseInterpreter.java:713)

rule "Test Random Offset A"
when
    Item Test_Offset changed from OFF to ON
then
    var int randomOffset

    randomOffset = (Math::random()*LampsTestInterval).intValue()
    logInfo("test random offset A", "Offset: " + randomOffset)

end

rule "Test Random Offset B"
when
    Item Test_Offset changed from OFF to ON
then
    var int randomOffset

    randomOffset = (Math::random()*LampsTestInterval).intValue()
    logInfo("test random offset B", "Offset: " + randomOffset)

end

Original comment by estan...@gmx.de on 12 Oct 2013 at 2:04

GoogleCodeExporter commented 9 years ago 
Migrated to https://bugs.eclipse.org/bugs/show_bug.cgi?id=423532

Original comment by kai.openhab on 8 Dec 2013 at 2:46