Thread:Sleep apparently shutting down OH2 execution randomly

Setup, Configuration and Use Scripts & Rules
1
  • Platform information:
    • Hardware: Intel CPU
    • OS: Ubuntu 16.04
    • Java Runtime Environment: Java™ SE Runtime Environment (build 1.8.0_151-b12
    • openHAB version: 2.3.0
  • Issue of the topic:
    In a rule, I am checking the temperature of the bedroom in a loop at night to determine if a ceiling fan should be ON or OFF every minute using Thread::sleep(60000). Randomly (roughly 50% of the time), everything in the OH log appears to stop for the entire minute.

The rule is;

var Timer lightTimer = null
var Timer fanTimer = null
var Timer fanNightTimer = null
val int temperatureComfortThreshold = 72
val int timeoutMinutes = 5 // choose an appropriate value
val int fanTimeoutMinutes = 7
val int fanNightMinutes = 540 // 9 hours from 10 to 7
val LocalTime wakeupTime = new LocalTime(7, 0)  // 7am every day
val LocalTime lightsOutTime = new LocalTime(22, 0)  // 10pm every day


rule "MasterBedroomMotionLight received ON"

when

    Item MasterBedroomMotion changed from OFF to ON 

then

    logInfo("openhab", "Wake up time is {}", wakeupTime.toString)
    logInfo("openhab", "Luminance level is {}", (MasterBedroomLuminance.state as DecimalType))

    if (lightTimer === null)  {

        if (now.toLocalTime().isAfter(wakeupTime) && 
           now.toLocalTime().isBefore(lightsOutTime) && 
           ((MasterBedroomLuminance.state as DecimalType).intValue < 70) )   {
              logInfo("openhab", "Turning Front Bedroom Light On")
              MasterBedroomLightSwitch.sendCommand(ON)
              MasterBedroomDimmer.sendCommand(99)
              lightTimer = createTimer(now.plusMinutes(timeoutMinutes ), [|
                logInfo("openhab", "Timer expired, turning Master Bedroom Light Off")
                MasterBedroomLightSwitch.sendCommand(OFF)
                MasterBedroomDimmer.sendCommand(0)
                lightTimer = null
           ])
       }
    }
    else {
       logInfo("openhab", "Front Bedroom Motion Detected when Timer not yet completed")
       lightTimer.reschedule(now.plusMinutes(timeoutMinutes ))
    }
    
    // For night time fan cooling 

    // Check to see if the motion occurs after LightsOutTime
    if ((now.toLocalTime().isAfter(lightsOutTime)) && (fanNightTimer === null)) {
        // reset the fan timer in case it was on, to preclude it from interfering in the fan night timer operation
        fanTimer = null
        logInfo("openhab", "Fan Night Timer started")
        // set the all night timer, as motion will occur infrequently during sleep
	    fanNightTimer = createTimer(now.plusMinutes(fanNightMinutes ), [|
              logInfo("openhab", "Night Timer expired, turning Master Bedroom fan Off")
              MasterBedroomFanSwitch.sendCommand(OFF)
              fanNightTimer = null
        ])
        while (fanNightTimer !== null) {
           //check every 60 seconds to see if the temperature requires the fan on  
            logInfo("openhab", "Checking the bedroom temperature to see if too warm")
           if ((MasterBedroomTemperature.state as DecimalType).intValue > temperatureComfortThreshold )  {
              // It is too warm, turn the fan ON if it is not already on
              if (MasterBedroomFanSwitch.state == OFF) {
                MasterBedroomFanSwitch.sendCommand(ON)
                logInfo("openhab", "Too warm at night, turning on fan")
              }
           }
           else {
               //Since it is not too warm, if the fan is already on, turn it off
               if (MasterBedroomFanSwitch.state == ON) {
                  MasterBedroomFanSwitch.sendCommand(OFF)
                  logInfo("openhab", "Cool enough at night, turning off fan") 
               }
           }
           Thread::sleep(60000)
        }
    }
    // if not during sleeping hours, turn on for 15 minutes when motion occurs and the temperature is above the setpoint
     else {
       if ((now.toLocalTime().isAfter(wakeupTime)) && (fanTimer === null) && ((MasterBedroomTemperature.state as DecimalType).intValue > temperatureComfortThreshold )) {
              logInfo("openhab", "Turning Fan On during daytime")
              MasterBedroomFanSwitch.sendCommand(ON)
              fanTimer = createTimer(now.plusMinutes(fanTimeoutMinutes ), [|
                logInfo("openhab", "Daytime fan Timer expired, turning Master Bedroom fan Off")
                MasterBedroomFanSwitch.sendCommand(OFF)
                fanTimer = null
           ])
       }
       else {
           logInfo("openhab", "Front Bedroom Motion Detected when daytime fan Timer not yet completed")
           if ((now.toLocalTime().isAfter(wakeupTime)) && ((MasterBedroomTemperature.state as DecimalType).intValue > temperatureComfortThreshold )) {
                          logInfo("openhab", "... and temperature is above the setpoint")
               fanTimer.reschedule(now.plusMinutes(fanTimeoutMinutes ))
           }
       }
     }
end

I don’t think it is appropriate to put the entire night’s log in here, so I’ll put in snippets where it does and does not happen. Every time the rule thread wakes up, you’ll see the log entry “Checking the bedroom temperature to see if too warm”

2018-07-10 05:10:03.609 [DEBUG] [ssage.ApplicationCommandMessageClass] - NODE 2: Transaction not completed: node address inconsistent.  lastSent=2, incoming=255
2018-07-10 05:11:01.433 [INFO ] [lipse.smarthome.model.script.openhab] - Checking the bedroom temperature to see if too warm
2018-07-10 05:12:01.434 [INFO ] [lipse.smarthome.model.script.openhab] - Checking the bedroom temperature to see if too warm
2018-07-10 05:12:03.614 [DEBUG] [WaveSerialHandler$ZWaveReceiveThread] - Receive Message = 01 0E 00 04 00 0B 08 32 02 21 74 00 00 27 31 85 

2018-07-10 05:12:19.862 [DEBUG] [ocol.ZWaveController$ZWaveSendThread] - NODE 4: Response processed after 1803ms/1960ms.
2018-07-10 05:13:01.435 [INFO ] [lipse.smarthome.model.script.openhab] - Checking the bedroom temperature to see if too warm
2018-07-10 05:14:01.436 [INFO ] [lipse.smarthome.model.script.openhab] - Checking the bedroom temperature to see if too warm
2018-07-10 05:14:03.625 [DEBUG] [WaveSerialHandler$ZWaveReceiveThread] - Receive Message = 01 0E 00 04 00 0B 08 32 02 21 74 00 00 25 EE 58 
2018-07-10 05:14:03.625 [DEBUG] [ve.internal.protocol.ZWaveController] - Receive queue TAKE: Length=0

2018-07-10 05:15:00.990 [DEBUG] [ocol.ZWaveController$ZWaveSendThread] - NODE 2: Response processed after 129ms/1960ms.
2018-07-10 05:15:01.437 [INFO ] [lipse.smarthome.model.script.openhab] - Checking the bedroom temperature to see if too warm
2018-07-10 05:16:01.439 [INFO ] [lipse.smarthome.model.script.openhab] - Checking the bedroom temperature to see if too warm
2018-07-10 05:16:03.642 [DEBUG] [WaveSerialHandler$ZWaveReceiveThread] - Receive Message = 01 14 00 04 00 0B 0E 32 02 21 64 00 00 01 1C 02 58 00 00 01 1A C3

And as you can see, it doesn’t always do this;

2018-07-10 05:18:03.649 [DEBUG] [ssage.ApplicationCommandMessageClass] - NODE 2: Transaction not completed: node address inconsistent.  lastSent=2, incoming=255
2018-07-10 05:19:01.442 [INFO ] [lipse.smarthome.model.script.openhab] - Checking the bedroom temperature to see if too warm
2018-07-10 05:19:17.080 [DEBUG] [WaveSerialHandler$ZWaveReceiveThread] - Receive Message = 01 09 00 04 00 04 03 80 03 64 12

At 05:21, the CivilDawn event occurred (see event.log below), which should have shut off the BackPorchLight, but that never showed up on the OH2 log and I had to shut it off myself;

2018-07-08 05:21:00.001 [vent.ChannelTriggeredEvent] - astro:sun:local:civilDawn#event triggered START

2018-07-10 05:20:03.660 [DEBUG] [ssage.ApplicationCommandMessageClass] - NODE 2: Transaction not completed: node address inconsistent.  lastSent=2, incoming=255
2018-07-10 05:21:01.444 [INFO ] [lipse.smarthome.model.script.openhab] - Checking the bedroom temperature to see if too warm
2018-07-10 05:22:01.445 [INFO ] [lipse.smarthome.model.script.openhab] - Checking the bedroom temperature to see if too warm
2018-07-10 05:22:03.672 [DEBUG] [WaveSerialHandler$ZWaveReceiveThread] - Receive Message = 01 0E 00 04 00 0B 08 32 02 21 74 00 00 27 14 A0

Did I specify the sleep incorrectly?

2

This is a really bad idea… What is the purpose of it?

Replace:

while(condition1) {
    // do work
    Thread::sleep(iterationTime)
}

With

timer = createTimer(now.plusSeconds(iterationTime), [ |
    // do work
    if(condition1) timer.reschedule(now.plusSeconds(iterationTime))
    else timer = null
])
3

Also as of OH2.2 you need to add a space after between [ and | in the timer lambda.

4

Why is it bad? I’ve seen tutorials with Thread::Sleep used and a bug in it was fixed in 2.2 to preclude affecting other threads. What are the design constraints on using it?

Yes, I thought about using a timer, though wanted to try the Thread::Sleep.

I was not aware of that, though without the space, multiple timers are working in my OH2 2.3.0 currently, so I’m a little confused.

5

The problem is you only get 5 Rules threads. This means only five Rules can run at the same time. When you have long running rules because you are using Thread::sleep and the like then you run the risk of running out of threads. When that happens, NO new rules can run until one of those five rules can exit.

Looking at this rule I suspect what is happening is MasterBedroomMotion is going from OFF to ON more than five times so you have five copies of this Rule running, tying up all the runtime threads and starving out the rest of your Rules.

This is why Thread::sleeps longer than 500 are a bad idea, and Thread::sleeps in a while loop are a REALLY bad idea, especially if you have a Rule that can be triggered a lot.

This Rule seems really long and complex for what it does. I’d recommend splitting it up. First, I’d move the calculations for time of day to [Deprecated] Design Pattern: Time Of Day. Then I’d split up the light control and the fan control into separate sets of Rules. Then they would become something like the following (I just typed this in, there are likely typos).

var Timer lightTimer = null
val int timeoutMinutes = 5 // choose an appropriate value

var Timer fanTimer = null
var Timer fanNightTimer = null
val int temperatureComfortThreshold = 72

rule "Master Bedroom Light"
when
    Item MasterBedroomMotion changed from OFF to ON
then

    // timer already exists, reschedule it and exit the rule
    if(lightTimer !== null) {
        logInfo("openhab", "Front Bedroom Motion Detected when Timer not yet completed")
        lightTimer.reschedule(now.plusMinutes(timeoutMinutes))
        return;
    }

    // no timer exists, create the timer if the time and lighting is right
    if(vTimeOfDay.state == "DAY" && MasterBedroomLuminace.state < 70) {
        logInfo("openhab", "Turning Front Bedroom Light On")

        // Assuming MasterBedroomDimmer and MasterBedroomLightSwitch are the same light, you don't
        // need separate Items for that one light. You can send ON/OFF commands to Dimmers and sending 
        // a non-zero value will turn the light ON
        MasterBedroomDimmer.sendCommand(99)

        lightTimer = createTimer(now.plusMinutes(timeoutMinutes), [ |
            logInfo("openhab", "Timer expired, turning Master Bedroom Light Off")
            MasterBedroomDimmer.sendCommand(OFF)
            lightTimer = null
        ] )
    }
end

rule "Master Bedroom Fan"
when
    Item MasterBedroomMotion changed from OFF to ON
then

    // If the current temp is below comfort, there is nothing to do so exit
    if(MasterBedroomTemperature.state < temperatureComfortThreshold) return;

    // Night time behavior
    if(vTimeOfDay.state == "NIGHT") {
        fanTimer?.cancel // cancel the fanTimer
        logInfo("openhab", "Fan Night Timer started")

        // loop every minute for up to five minutes, stop when the temp falls below comfort
        MasterBedroomFanSwitch.sendCommand(ON)
        val startedTimer = now
        fanNightTimer = createTimer(now.plusMinutes(1), [ | 
            if(MasterBedroomTemperature.state > temperatureComfortThreshold &&
               now.minusMinutes(timeoutMinutes).isBefore(startedTimer)) {
                fanNightTimer.reschedule(now.plusMinutes(1))
            }
            else {
                MasterBedroomFanSwitch.sendCommand(OFF)
                fanNightTimer = null
            }
        ])
    }

    // Day time behavior
    else {
        fanNightTimer?.cancel // cancel the night timer

        if(fanTimer !== null) {
            fanTimer.reschedule(fanTimeoutMinutes)
        }
        else {
            MasterBedroomFanSwitch.sendCommand(ON)
            fanTimer = createTimer(now.plusMinutes(fanTimeoutMinutes), [ |
                MasterBedroomFanSwitch.sendCommand(OFF)
                fanTimer = null
            ]
        }
    }
end

I think this is more of a problem when using a lambda that takes an argument like `MyGroup.members.forEach[ i | i.sendCommand(OFF) ] . In this case, the spaces Vincent mentions are required.

In your Timers, perhaps the space is not required between [ and |, and you have a space before the ] anyway.

6

Thanks @rikoshak, there are a couple of tricks I picked up with your example.

I had left off my short requirement set in the comments at the beginning of the rule, which are;

// If motion is detected in the master bedroom during awake hours and there is not enough light, turn on the light,
// keeping it on for at least x minutes. Every time motion is detected during that period, reset the time to x minutes (lightTimer).

// If motion is detected in the master bedroom during awake hours and the temperature is above a comfort threshold, turn on the fan,
// keeping it on for at least y minutes. Every time motion is detected during that period, reset the time to y minutes (fanTimer).

// During sleep hours (from lightsOutTime to wakeUpTime), if motion is detected (e.g., we are going to bed), start a fan timer for the duration of the sleep cycle (fanNightTimer). As we go to bed a little later and get up later on the weekends, this will adjust to our schedule when going to bed later.

// If the temperature exceeds the comfort threshold, turn the fan on. If it falls below the threshold, turn it off. Check the temperature every 60 seconds

2 points about your example;

  1. It appears that the fan check at night only works when there is motion. Due to changing conditions (Use Case 1: window open, temperature dropping throughout the night, don’t want fan to make us cold when it does; Use Case 2: sometimes the A/C shuts off when outside temps drop, and the upstairs becomes much warmer around 3-4am), I want to check every minute, in case a front moves in and wind picks up, blowing much cooler air in the windows. Since I use NTP, I could use the clock updates as the trigger, and not have to loop, and I’d have to set up an Item such as SleepMode where the values would be set to Sleep or Awake and SleepStartTime would be set according to the first motion detected after lightsOutTime. Or I can just check to see if fanNightTime !== null, in which case I would just return.

  2. In the winter, night can come much earlier than bedtime, which might complicate using TimeOfDay, though I’ve only given it a cursory look, and will look a little deeper tonight. In other areas, I’ve been using astro Civil dusk and dawn for outside lights (though not getting the results I’m seeking yet).

7

As did your original rule and as your requirements in to comments state “During sleep hours…if motion is detected…”. If you want to turn on the fan based on some other event you need to add that as a trigger to the rule. If you want to fan to run all night or longer than five minutes without motion you need to adjust the fanRuntime or just continue the fanNightTimer loop until DAY.

As does my example. When we get to the point where the fanNightTimer is created we know:

  • the current temp is above the threshold
  • it is night time
  • there isn’t already a timer running

Then the fan is turned ON.

Then we create a timer for 1 minute.

In the timer we check to see if the temp is still above the target temp and if the fan has been running for less than timeoutMinutes. If both are true, we reschedule the timer for one minute. If either are false, we stop the fan and exit the timer loop.

So indeed, this code does check every minute and turns off the fan when the temp drops below the threshold.

Or a better approach would probably be to use the Time cron trigger to run a rule every minute or the like. But I don’t think that really buys you anything. The above checks every minute, but only while the fan is running which more closely matches what your original rule tries to do.

You can use any event, Astro Civil Dawn, hard coded hour and minute, or anything else that you want to specify the value of vTimeOfDay. I provide examples of both Astro and hard coded times in the DP.

You can even add some logic and use the Astro season Channels to change the start and stop events based on the season of the year. Or base it on dates. Also remember that you can create Astro Things with offsets so in the winter you can use something like Civil dusk - 30 minutes for the start of dark.

DPs are intended to just be a starting point. A rough building block. They are not complete and unalterable solutions.

8

The requirement above does not capture exactly what I was thinking (the epitome of the software stakeholder’s classic communications shortcoming) :slight_smile:

I’ll rephrase it to;

During sleep hours (from lightsOutTime to wakeUpTime), when the first motion is detected (e.g., we are going to bed), start a fan timer for the duration of the sleep cycle (fanNightTimer).

There are a number of other factors this approach was chosen, such as the varying time we go to bed, sometime each at different times. So the light doesn’t come on after lightsOutTime, to preclude a night owl from waking up the spouse, though the rule will still be checking the ComfortThreshold temp every minute once someone has tripped the motion sensor after lightsOutTime. Yes, there are times when we both go to bed late that the light doesn’t come on in the room when we walk in, and I just chalk it up as a minor inconvenience for having a complex requirement set with limited sensor capability.

Your suggestions merit inclusion, such as a cron trigger, thanks again for your thoughtful help.

9

OK, that isn’t what your original code did.

So that is easy enough to implement with one minor change:

    // Night time behavior
    if(vTimeOfDay.state == "NIGHT") {
        fanTimer?.cancel // cancel the fanTimer
        logInfo("openhab", "Fan Night Timer started")

        // loop every minute for up to five minutes, stop when the temp falls below comfort
        MasterBedroomFanSwitch.sendCommand(ON)
        fanNightTimer = createTimer(now.plusMinutes(1), [ | 
            if(MasterBedroomTemperature.state > temperatureComfortThreshold &&
               vTimeOfDay.state == "NIGHT") {
                fanNightTimer.reschedule(now.plusMinutes(1))
            }
            else {
                MasterBedroomFanSwitch.sendCommand(OFF)
                fanNightTimer = null
            }
        ])
    }

The only change to above is the removeal of the startedTimer variable and instead of checking for how long since the timer went off to determine how long the fan stays on, it checks every minute to see if it is still NIGHT and the temp is above the threshold. If it is it reschedules the timer for another minute.

If it isn’t, it turns off the fan and stops the timer.

If you want the fan to come back on at NIGHT in cases where the temp of the room went below the threshold but later on rose above the threshold that too is a simple change.

rule "Master Bedroom Fan"
when
    Item MasterBedroomMotion changed from OFF to ON
then

    if(vTimeOfDay.state == "NIGHT") {
        // cancel the day time timer if it exists
        fanTimer?.cancel // cancel any day time timers

        // turn ON/OFF the fan based on the temp
        MasterBedroomFanSwitch.sendCommand(if(MasterBedroomTemperature.state > temperatureComfortThreshold) ON else OFF)

        // Create a looping timer to check every minute all night and adjust the fan as necessary
        fanNightTimer = createTimer(now.plustMinutes(1), [ |
            // implement some hysteresis to avoid rapidly cycling the fan if the temp is right at the threshold
            // if the temp is between temperatureComfortThreshold-1 and temperatureComfortThreshold then
            // the fan will stay in whatever state it currently is in
            var fanState = "STAY"
            if(MasterBedroomTemperature.state > temperatureComfortThreshold) fanState = "ON"
            else if(MasterBedroomTemperature.state < temperatureComfortThreshold-1) fanState = "OFF"

            if(fanState != "STAY" and fanState != MasterBedroomFanSwitch.state.toString)
                MasterBedroomFanSwitch.sendCommand(fanState)

            if(vTimeOfDay.state == "NIGHT") fanNightTimer.reschedule(now.plusMinutes(1))
        ])
    }
    else {
        // Cancel the night timer if it exists
        fanNightTimer?.cancel

        // if the timer already exists, just extend it
        if(fanTimer !== null) fanTimer.reschedule(fanTimeoutMinutes)

        // turn on the fan if the temp is too high and set a timer to turn it off
        else if(MasterBedroomTemperature.state > temperatureComfortThreshold) {
            MasterBedroomFanSwitch.sendCommand(ON)
            fanTimer = createTimer(now.plusMinutes(fanTimeoutMinutes), [ |1
                MasterBedroomFanSwitch.sendCommand(OFF)
                fanTimer = null
            ])
        }
    }
end

The major changes in the above was removing the fail fast check that caused the rule to be skipped if the temp is below the threshold. Then the looping timer at night will loop as long as it is night, turning on and off the fan based on the current temp. Because we removed the fail fast check at the top of the rule, we needed to add it back in for the day time behavior clause.

Again, the advantage here is the looping/polling only takes place at night in the background which frees up rules runtime threads.

1 Like
10

Very elegant design, thank you! This could be the basis for an Example or Bedroom Fan DP.

Question: Do running timers count against the the limit of 5 rules running concurrently?

11

I’ve already plans to write a looping Timer DP which would cover this. The above code will probably be what I use as the complex example implementation.

A DP is intended to be a generic approach to solve lots of similar problems in a common way. As such it doesn’t make much sense to write a Fan Timer DP. In fact, I really regret naming the Time of Day DP that as it implies that is the only thing it is good for. But the same approach can be used to track any sort of system state which is why I use that Irrigation example for the complex example. But it is really too late to rename it now.

Stay tuned for a looping timer DP though, as that is the meat of the code above.

Running Timers do not count against the Rule thread count. That is one reason why timers are a better choice over Thread:sleep. Now, there is a Timer thread pool (I can’t remember how big it is but I think it is more than five) but one of those threads is only being use when the Timer body is actually running. For example, if you have 50 timers but only two are actually executing the code after going off, only two threads are being used. So in the above a thread will be in use for a small fraction of a second once a minute. That should not cause any problems with running out of threads. Similarly, the Rule itself will only take a fraction of a second to run so you shouldn’t run into Rules running out of threads either.

Edit: Here is part one: (OH 1.x and OH 2.x Rules DSL only] Why have my Rules stopped running? Why Thread::sleep is a bad idea

Part two (DP for the looping timers to follow).

1 Like