Error while executing lambda

Setup, Configuration and Use Scripts & Rules
1

I implemented a lambda expression for filtering and calibration of temprature/humidity sensor data. The expression is working like expected - however, I get repedately the following error message in the logfile:

2017-12-19 21:17:09.754 [ERROR] [.script.engine.ScriptExecutionThread] - Rule 'Filter_Temperatur_Kueche': null

Do you have any idea?

Thanks a lot
Karsten

The corresponding rule looks like this:


import java.util.Map
import org.eclipse.xtext.xbase.lib.Functions

//constants

val Map<String, Double> DHT22_Temprature_limits = newHashMap(
        "min"       ->  -2.0,     //minimal temperature in C
        "max"       ->  50.0,     //maximal temperature in C
        "max_delta" ->  0.5)      //maximum difference between two temprature measurements in C
        
val Map<String, Double> DHT22_Humidity_limits = newHashMap(
        "min"       ->    0.0,    //minimal humidity in %
        "max"       ->  100.0,    //maximal humidity in %
        "max_delta" ->  2.0)      //maximum difference between two humidity   measurements in %
        


/// calibration parameter


val double Temperatur_Kueche_Offset     =-0.1
val double Temperatur_Flur_Offset       =-0.4

val double Luftfeuchtigkeit_Kueche_Offset = 0.0
val double Luftfeuchtigkeit_Flur_Offset   =-3.0


///////////////////////////////////////////////////////////////////////////////

//filter algorithm
val Map<String, Double> Last_Values = newHashMap

val Functions$Function5<GenericItem,GenericItem,Map<String, Double>,Double,Map<String, Double>, Boolean> dht22_filter= [ 
    raw_item,
    filtered_item,
    limits,
    offset,
    last_values |
    
    val String key=raw_item.name
    
    // get states variables
    var double last_value=0.0
    if(last_values.containsKey(key)) last_value=last_values.get(key)
    else                             last_values.put(key,last_value)
    
    if(raw_item.state!=NULL)
    {
        //get constants
        val double min       = limits.get("min")
        val double max       = limits.get("max")
        val double max_delta = limits.get("max_delta")
        
       //offset compensation 
       val double raw_value=(raw_item.state as Number).doubleValue-offset
       
 //      logInfo("dht22-filter","name: "+ key+" raw: " +raw_item.state.toString+ " compensated: "+raw_value.toString+
 //      	" min " + min.toString + " max " + max.toString + " max_delta " + max_delta.toString +
 //      	" last: " + last_value.toString
 //      )
       
       //ignore values outside range
       if( (raw_value >= min) && (raw_value <= max) )
       {
          //if the new value derives more than max_delta from the last
          //its may errornous -> ignore, however store for the next time 
          if(Math::abs(last_value -  raw_value) < max_delta)
          {
               filtered_item.postUpdate(raw_value)
          }

          last_value=raw_value
       }
    }
    
    //store state
    last_values.put(key,last_value)
 
     true
    ]



rule "Filter_Temperatur_Kueche"
when
   Item Temperatur_Kueche_Raw received update
then
    dht22_filter.apply(
        Temperatur_Kueche_Raw,
        Temperatur_Kueche,
        DHT22_Temprature_limits,
        Temperatur_Kueche_Offset,
        Last_Values
    )
end

The item definition in an item file looks like this:

Number Temperatur_Kueche "Küche [%.1f °C] " <temperature> (Raumtemperatur) 
Number Temperatur_Kueche_Raw "Küche Raw[%.1f °C] " <temperature> (Raumtemperatur_Raw) 
{
  mqtt="<[mosquitto:/home/arduino2/dht_sensors/temperature/3:state:default]"
}
2

Add logging to your rule, at the beginning and scattered throughout your lambda to find the line that it is failing on. That should give you a clue as to what the problem is.

3

Thanks a lot for the quick answer. The lambda executes to the end - I had the last log before the true statement.

I had a couple of messages - flow was like expected.

The error does not happen always - ca. every 10th. rule activation gives this error - there seems to be no difference between a sucessful and one with a null error message afterwards.

4

I did some further investigations:

  • The exception happens in less than 1% of the rule activations - so principally the rules using the lambda working as expected
  • There are multiple rules with a lot of activations which are using the lambda
  • The error occurs also, if I comment out the whole content of the lambda (except the true for the return value)
  • The lambda runs always to the end - I used log messages - and I saw the message in the lambda and the next message was the error message - so the exception occurs while the lambda returns
  • I used try-catch inside the lambda - there was never a catch
  • I used try-catch in all rules (around the lambda call) and I catched the exceptions - thus this could be a not statisfying solution to remove the exceptions from the log
  • I experimented with a sleep at different locations and with different values, it seems not to have an influence

Thus, for me it looks like the lambda crashes sproradically while it returns. I can’t see any dependency when such a crash happens - there are executed a lot of rules in parallel, which are using the same lambda, however, there is no parallel execution of the same rule.
Could it be a problem, if a lambda is used by many rules at the same time?

Has someone an idea, which further tests I can perform?

Thanks a lot

5

This is very odd behavior. Are these lambdas called a lot? Is it likely that you have more than one instance of the lambda being called at a time? One thing I’ve noticed is that there is that lambdas are not thread safe and even worse, because the lambda is a single object, I think that if you have two calls to it at the same time the two can interact with each other in strange ways. Though I wouldn’t expect the behavior you are seeing.

The only thing you haven’t experimented with is using a ReentrantLock to make the call to the lambda thread safe (i.e. no two calls to it will process at the same time). That is worth trying.

Since you are not using the return value for anything, try using a Procedure. The only changes necessary is to import Procedures instead of Functions, change to Procedures$Procedure5, remove the Boolean from the argument Types and remove that last true line.

Next, I would try to come up with some sort of test harness that you can run to exercise the lambda and reproduce the error so that the maintainers have some code they can run to generate the error and start to debug the problem. This can be as simple as a Rule that you trigger with a dummy Item with a loop that calls a simple lambda over and over and catches the exception. With this submit an issue over at Eclipse Smarthome and hope for the best.

6

Thanks a lot. Changing Function to Procedure solved the problem.
It’s true, that this lambdas called a lot - in my test case, I had 12 rules which used the lambda and the rules updated approx. every 9 seconds abd the 12 updates receive nearly at the same time. So most probably the same lambda executes at the same time in parallel.

Is there anywhere a description how to create a test harness and how to contribute it?

Thanks a again a lot

7

I run into the similar problem.

I tried ReentrantLock but this does not fix it. If I use an easy rule all works fine. Only if the rule is a little bit more complex it is not working well.

I will try to migrate it to a procedure. maybe this will fix it. But as Rich wrote, looks like not thread save and timers inside do also have strange behaviour.

8

I was really just referring to writing a rule that pounds on the lambda with fake data until the error occurs. Nothing any more complex or involved than that.

Others have written scripts that run outside of OH and send commands/updates to Item through the REST API to drive tests, but I don’t think that would be necessary in this case.

9

I have now a trival test. Is the github:


the right repository for reporting the issue and uploding the two files?

Anyway this is the code, which generates at my raspberry pi 3 with openhabian ( openHAB 2.2.0-1 (Release Build)) sporadically approx. every 10 updates an exception.

Number in1 "in1 [%.1f °C] " <temperature> 
Number out1 "out1 [%.1f °C] " <temperature> 

Number in2 "in2 [%.1f °C] " <temperature> 
Number out2 "out2 [%.1f °C] " <temperature> 

Number in3 "in3 [%.1f °C] " <temperature> 
Number out3 "out3 [%.1f °C] " <temperature> 

Number in4 "in4 [%.1f °C] " <temperature> 
Number out4 "out4 [%.1f °C] " <temperature> 

Number in5 "in5 [%.1f °C] " <temperature> 
Number out5 "out5 [%.1f °C] " <temperature> 

Number in6 "in6 [%.1f °C] " <temperature> 
Number out6 "out6 [%.1f °C] " <temperature> 

Number in7 "in7 [%.1f °C] " <temperature> 
Number out7 "out7 [%.1f °C] " <temperature> 

Number in8 "in8 [%.1f °C] " <temperature> 
Number out8 "out8 [%.1f °C] " <temperature> 

Switch trigger  "trigger"
{expire = "9s, command=OFF"}

val Functions$Function2<GenericItem,GenericItem,Boolean > bug_test_lambda= [ 
    in_item,
    out_item |
        true
        
        ]

        
var double cnt=0.0


rule "initialize"
when 
    System started
then
trigger.postUpdate(ON)
end


rule "stimuli"
when
  Item trigger changed from ON to OFF
then
   in1.postUpdate(cnt)
   in2.postUpdate(cnt+1)
   in3.postUpdate(cnt+2)
   in4.postUpdate(cnt+3)
   in5.postUpdate(cnt+4)
   in6.postUpdate(cnt+5)
   in7.postUpdate(cnt+6)
   in8.postUpdate(cnt+7)
   cnt=cnt+8
   trigger.postUpdate(ON)
   
   logInfo("bug-test","Update trigger")
end
   
   
rule "t1"
when
   Item in1 received update
then
   bug_test_lambda.apply(in1,out1)
end

rule "t2"
when
   Item in2 received update
then
   bug_test_lambda.apply(in2,out2)
end


rule "t3"
when
   Item in3 received update
then
   bug_test_lambda.apply(in3,out3)
end

rule "t4"
when
   Item in4 received update
then
   bug_test_lambda.apply(in4,out4)
end

rule "t5"
when
   Item in5 received update
then
   bug_test_lambda.apply(in5,out5)
end


rule "t6"
when
   Item in1 received update
then
   bug_test_lambda.apply(in6,out6)
end

rule "t7"
when
   Item in1 received update
then
   bug_test_lambda.apply(in7,out7)
end

rule "t8"
when
   Item in8 received update
then
   bug_test_lambda.apply(in8,out8)
end