OH2 timer.createTimer has a time lag?

  • Platform information:
    • Hardware: x86/8GB/60GB
    • OS: debian 10
    • openHAB version: 2.5.12

Hello together,
I used this weekend to look at a issue in my dimmer configuration and I have found the issue. Question is: Is this a bug or is this by design?

Configuration:
Item:
Switch Test

Rule (simplified):

rule "Test Lightstripe AUS"
when
    Item Test received command OFF
then 
    tTest?.cancel
    tTest = null  
end 

rule "Test Lightstripe EIN"
when
    Item Test received command ON
then 
    var Number iFoo = 0 

    if (tTest === null)
		tTest = createTimer(now, [ |  
            iFoo = iFoo + 1 
            logInfo("Test", "Number: " + iFoo)
			
            if (iFoo < 10) 
				tTest?.reschedule(now.plusMillis(200)) 
            else                
                tTest=null
    ])
end 

Now, most of the time the code works, that means if the Item “Test” is switched ON, the Number iFoo will count from 1->10. If I switch the Item earlier to OFF, the Number stops. However, sometimes (20%) iFoo will only count only till 1 and stops. Why? Because tTest is null and won’t be rescheduled. I thought I cancel the timer somewhere else, but that we not the case.

Here is my “fix”:

rule "Test Lightstripe EIN"
when
    Item Test received command ON
then 
    var Number iFoo = 0 

    if (tTest === null)
		tTest = createTimer(now, [ |  
             Thread::sleep(2)
				
            iFoo = iFoo + 1 
            logInfo("Test", "Number: " + iFoo)
			
            if (iFoo < 10) 
				tTest?.reschedule(now.plusMillis(200)) 
            else                
                tTest=null
    ])
end 

As you can see, I added a sleep operation for 2ms (1ms is not always enough). Now tTest never was null again at the time I rescheduled the timer. Can somebody explain me why the reference of the timer is not always available and if there is another solution for this example?

Thanks.

Your better alternative is to have your initial createTimer call for now,plusMillis(2)or whatever.

We have seen this before, depending on host performance.
Scheduling a timer for 'now’is essentially a dumb thing to do; the timer has to be created and scheduled before the reference is returned to your variable tTest.
So as “now” has already passed even before the timer is created, it executes immediately. Depending on host thread management etc. the timer code may get well along executing before tTest is populated.

Wouldn’t you be wanting to declare iFoo outside of the rule, as a global, too?

I doubt the rule works as intended at all, because iFoo is a local var that doesn’t exist inside the timer. For counting the loop you have to define the var as a global var.

-by the way: you don’t need to use two rules:

var Number iFoo = 0 

rule "Test Lightstripe EIN"
when
    Item Test received command
then 
    if(receivedCommand == ON) {
        if(tTest === null)
            iFoo = 0
            tTest = createTimer(now, [ |  
                iFoo = iFoo + 1 
                logInfo("Test", "Number: " + iFoo)
                if (iFoo < 10) 
                    tTest?.reschedule(now.plusMillis(200)) 
                else
                    tTest=null
            ])
        }
    } else {
        tTest?.cancel
        tTest = null  
    }
end 

Thanks for the feedback. That means, that this is no synchron process in the background.
now.plusMillis(2) had the same problem, but now.plusMillis(10) was enough :slight_smile:

btw: iFoo is not global. Since it’s declared before the timer, you don’t have to do it :wink:

Thanks, but since iFoo was declared before the timer, you don’t have to use a global var. As far as I know it gets copied inside the timer.
And you are right. You don’t have to write two rules.

No, that is not correct. The rule is executed when the command is received, the var is defined, the timer is defined (and that is a new context), the rule ends, var is gone.

In fact VSCode is complaining about a non existent var, at least for me.

Well, are you on OH3? Maybe this has been changed, but in OH2 it’s working and VSCode is not complaining - at least on my end :slight_smile:
And it works, because the lambda gets a copy of iFoo and because we are rescheduling it instead of recreating it iFoo + 1 gets preserved until the next run of the Timer.

see Design Pattern: Recursive Timers - #11 by rlkoshak for more information.

No, I’m still on OH2.5

Hmm… very strange. I can confirm that you are right. But I’ve seen the error message many times… I have to investigate…

When you create a lambda, the lambda gets a copy by reference of all the variables that exist up to the point that the lambda is created. That’s why code like the following works:

   val StringBuilder message = new StringBuilder()
   MyGroup.members.forEach[ i | message.append(i.state + ", ") ]

The variable message is declared as a variable local to the rule. The lambda is still able to see it and interact with it because the lambda got a pointer to message when it was created. I’ve sometimes called this “inheriting the context”.

So when we have a timer’s lambda, it gets a pointer to all the rule local variables creates up to that point (and the globals too of course). When the lambda goes off to timer land where it seems to be running out side of the rule, in fact it’s keeping all those variables that are defined by that rule alive and interacting with them even after the rule exits.

What I don’t know is if a subsequent run of the rule will be using that same iFoo variable, or if it gets a different iFoo variable. One can probable devise a test where the timer is kicked off and counts up iFoo but trigger the rule again and var iFoo = 0 again but don’t mess with the existing timer. If iFoo doesn’t reset in the timer we know that the timer gets a copy of the variable at some point, or the second run of the rule creates a whole new iFoo variable that is separate from the iFoo variable inside the timer’s lambda.

Note though that these variables are still tied to the rule somehow because you will get an exception in the logs when you reload that rule if there is an active timer scheduled.

It’s all very much magic and it’s one of my biggest complaint about Rules DSL. Too much of this magic is not consistent nor is it always intuitive.

1 Like