Rule to switch off Item stopped working with recent OH2 snapshot

With the recent changes in the OH2 snapshot my rule to switch off a group of Items stopped working and after viewing the logs I think that rule is working but only commands are issued and not change in state happens. Here are the facts:

  • I have one rule to switch off all lights which gets triggered and send the command off to a group: sendCommand (all_lights, OFF)
  • This creates the following output in the event log:

2017-08-19 11:59:01.580 [ome.event.ItemCommandEvent] - Item ‘all_lights’ received command OFF
2017-08-19 11:59:01.580 [ome.event.ItemCommandEvent] - Item ‘avr1Z1_Power’ received command OFF
2017-08-19 11:59:01.581 [ome.event.ItemCommandEvent] - Item ‘Light_Kitchen_Table_Dimmer’ received command OFF
2017-08-19 11:59:01.581 [ome.event.ItemCommandEvent] - Item ‘Light_Corridor_Switch1’ received command OFF
2017-08-19 11:59:01.581 [ome.event.ItemCommandEvent] - Item ‘Light_Corridor_Switch2’ received command OFF
2017-08-19 11:59:01.582 [ome.event.ItemCommandEvent] - Item ‘KitchenTableLight_Dimmer’ received command OFF
2017-08-19 11:59:01.582 [ome.event.ItemCommandEvent] - Item ‘Test_Office_light_switch’ received command OFF
2017-08-19 11:59:01.582 [ome.event.ItemCommandEvent] - Item ‘Light_Kitchen_Switch’ received command OFF

  • None of the commands is being executed - The lights are still ON.

With previous snapshots this rule was sporadically working. I have tested to use a single Item instead of a group of items but still the same behavior.

Currently I use 2.2.0-SNAPSHOT Build #1017.

Any ideas?

Please pray your group definition and the full contents of your rule.

If there is a problem, and it looks like there is, the problem is most likely with the binding.

Thanks Rich

The group definition is created trough the paper UI and I wasn’t sure if this is the best command to exact in cli/karaf the groups but here it is:

openhab> smarthome:items list |grep all_lights

KitchenLight_Switch1 (Type=SwitchItem, State=OFF, Label=Switch, Category=Switch, Groups=[all_lights])
all_lights (Type=GroupItem, BaseType=SwitchItem, Members=15, State=OFF, Label=All Lights, Category=)
Light_Kitchen_Table_Dimmer (Type=DimmerItem, State=0, Label=Dimmer, Category=Dimmer, Groups=[all_lights])
WashroomLight_Switch (Type=SwitchItem, State=OFF, Label=Switch, Category=null, Groups=[all_lights])
KitchenTableLight_Dimmer1 (Type=DimmerItem, State=0, Label=Dimmer, Category=DimmableLight, Groups=[all_lights])
Light_Corridor_Switch1 (Type=SwitchItem, State=OFF, Label=Switch, Category=null, Groups=[all_lights])
CorridorLights_Switch1 (Type=SwitchItem, State=OFF, Label=Switch, Category=Switch, Groups=[all_lights])
CorridorLights_Switch2 (Type=SwitchItem, State=OFF, Label=Switch, Category=Switch, Groups=[all_lights])
Light_Corridor_Switch2 (Type=SwitchItem, State=OFF, Label=Switch 2, Category=null, Groups=[all_lights])
Light_BathroomParents_Switch (Type=SwitchItem, State=OFF, Label=Switch, Category=null, Groups=[all_lights])
KitchenTableLight_Dimmer (Type=DimmerItem, State=0, Label=Dimmer, Category=DimmableLight, Groups=[all_lights])
zwave_device_e72dcfb3_node11_switch_binary_test (Type=SwitchItem, State=OFF, Label=light_bedroom_switch, Category=, Groups=[all_lights])
Test_Office_light_switch (Type=SwitchItem, State=OFF, Label=Switch, Category=Switch, Groups=[all_lights])
OfficeLight_Switch1 (Type=SwitchItem, State=OFF, Label=Switch, Category=Switch, Groups=[all_lights])
CellarLight_Switch1 (Type=SwitchItem, State=OFF, Label=Switch, Category=Switch, Groups=[all_lights])
Light_Kitchen_Switch (Type=SwitchItem, State=OFF, Label=Switch, Category=Switch, Groups=[all_lights])

see that couple of items are around the same purpose. Reason for this is most likely that I have tried out different configurations, but also default naming conventions by paper UI (which I think changed in the past) and also not clean handling of removing paper UI generated Items. I will try to clean up via cli.

The rule is a bit long, but it is getting triggered and clearly creates an output. Further as you can see i have next to the group of fibaro z-wave devices also one AVR which is also receiving an update from the rule (see rule definition) and that one works without problem. In my view that fully supports what you wrote: the binding might be a problem.

import java.util.ArrayList
import java.util.LinkedList
import java.util.Map
import java.util.regex.Pattern
import org.eclipse.smarthome.core.library.items.SwitchItem
import org.eclipse.smarthome.model.script.actions.Timer
import org.eclipse.xtext.xbase.lib.Functions
import org.eclipse.xtext.xbase.lib.Pair
import org.eclipse.xtext.xbase.lib.Procedures
import org.joda.time.DateTime

/*
 * ======================================= Tap Pattern Detection ======================================
 * Ver. 1.000000000
 * Author: Victor Bai
 * Date: Mar 17, 2017
 *
 * Description: Function to detect switch's tapping pattern: double-tap, triple pattern, customized pattern, etc.
 */
/*
 * Data structure to hold Tap pattern states (don't edit this, or care about it):
 * {SWITCH -> [
 *              [{'ON' => '2017-03-12 12:30:10:125'}, {'ON' => '2017-03-12 12:30:11:125'}], // States Queue: LinkedList<Pair<String, DateTime>>
 *              [Pattern, Pattern, Pattern]                                                                                                     // Holder for Pattern Strings' RegEx compilation: ArrayList<Pattern>
 *              [2, 0, 1],                                                                                                                                      // Match results. ArrayList<Integer>. Same order as the input pattern. 0: no match; 1: partial match; 2: comple
te match
 *              Timer                                                                                                                                           // Timer
 *      ]
 * }
 */
val Map<SwitchItem, LinkedList<?>> tapStates = newHashMap

/*
 * Function detectUpdatePatterns.apply(SwitchItem, tapStates, patternConfig)
 *
 * Input Arguments:
 *      SwitchItem:             Switch triggering the tap pattern(s)
 *      tapStates:              rule scope predefined variable
 *      patternConfig:  ArrayList<Pair<SwitchItem, String>> pattern definition. e.g. newArrayList(V_Office_DoubleTap->'ON,ON', V_Office_TripleTap->'ON,ON,-,ON')
 *                                              "SwitchItem" here is the virtual/proxy item you want to switch ON whenever associated pattern is detected
 *                                              "String" representing pattern composed of ',' delimited states. Possible state values are:
 *                                                      "ON":   state of ON
 *                                                      "OFF":  state of OFF
 *                                                      "-":    Represent a "skipping" of a tapping. you have to time it right. if it's longer than LONG_SPAN, previous tapping will be discarded
 *                                                      "#":    Represent any DimmerSwitch state in Positive percentage
 *                                                      "0":    Represent any DimmerSwitch's OFF state
 * return:
 *      ArrayList<Integer>: list of int value indicating matching result: 0: no match; 1: partial match; 2: complete match
 *
 */
val Functions.Function3<
                SwitchItem,             // Switch triggering tapping
                Map<SwitchItem, LinkedList<?>>,         // Global caching variable
                ArrayList<Pair<SwitchItem, String>>,    // Pattern Configuration
                ArrayList<Integer>      // return list of int value indicating matching result.
        > detectUpdatePatterns = [
                SwitchItem light,
                Map<SwitchItem, LinkedList<?>> tapStates,
                ArrayList<Pair<SwitchItem, String>> patternConfig |
        // Pre-configured time span between tapping
        val SHORT_SPAN = 600 // 800ms, sequence of key pressing must happened within this time frame
        val LONG_SPAN = 2*SHORT_SPAN    // If time between tapping extend beyond this time, previous tapping will be ignored

        // initialize
        if (tapStates.get(light) == null)
                tapStates.put(light, newLinkedList)
        val switchState = tapStates.get(light) as LinkedList<Object>

        if (switchState.size == 0) {
                switchState.add(newLinkedList) // States queue
                switchState.add(newArrayList)   // RegEx Pattern list
                switchState.add(newArrayList) // Match results
                for (i : 0..<patternConfig.size)
                        (switchState.get(2) as ArrayList<Integer>).add(-1)
                switchState.add(null) // timer

                // generate patternString
                // var String[] patternStrings = newArrayList
                for (var i = 0; i < patternConfig.size; i++) {
                        var pattern = Pattern.compile('^' + patternConfig.get(i).value.replaceAll('\\s', '').replaceAll('#', '[1-9]\\d*'))
                        (switchState.get(1) as ArrayList<Pattern>).add(pattern)
                        logInfo(light.name, "Pattern[{}]: '{}' => '{}'", i, patternConfig.get(i).value, pattern)
                }
                logInfo(light.name, "detectUpdatePatterns initialized.")
        }

        val stateQueue = switchState.get(0) as LinkedList<Pair<String, DateTime>>
        val patterns = switchState.get(1) as ArrayList<Pattern>
        val matchResult = switchState.get(2) as ArrayList<Integer>
        var tapTimer = switchState.get(3) as Timer

        var eventTime = new DateTime
        // pushout the old state from the queue
        if (stateQueue.size > 0 && eventTime.isAfter(stateQueue.last.value.plusMillis(LONG_SPAN))) {
                //logInfo(light.name, "Pushout the old state from the queue.")
                stateQueue.clear
        }
        stateQueue.add(light.state.toString -> eventTime)

        //logInfo(light.name, "stateQueue.size = {}", stateQueue.size)

        //compose comparing string from existing queue
        var queueString = ""
        var DateTime last = null
        for (var i = 0; i < stateQueue.length; i++) {
                var state = stateQueue.get(i)
                var stateTime = state.value
                if (last != null && stateTime.isAfter(last.plusMillis(SHORT_SPAN))) {
                        queueString += ",-"
                }
                if (i > 0) queueString += ","
                queueString += state.key
                last = state.value
        }

        //logInfo(light.name, "queueString = {}", queueString)

        // matching against patterns
        var partialMatch = -1
        var completeMatch = -1
        for (i: 0..< patterns.size) {
                //logInfo(light.name, "Pattern {} = '{}'", light.name, patterns.get(i).toString)
                var matcher = patterns.get(i).matcher(queueString)
                if (matcher.matches) {
                        completeMatch = i
                        matchResult.set(i, 2)
                }
                else if (matcher.hitEnd) {
                        // Partial match found
                        matchResult.set(i, 1)
                        partialMatch = i
                }
                else
                        matchResult.set(i, 0)
                //logInfo(light.name, "matchResult[{}] = {}", i, matchResult.get(i))
        }
        val comp = completeMatch

        if (completeMatch > -1) {
                logInfo(light.name, "Complete match found for pattern: {}.", patternConfig.get(comp).value)

                tapTimer?.cancel
                tapTimer = null
                if (partialMatch > -1) {
                        logInfo(light.name, "Partial match found for pattern: {}", patternConfig.get(partialMatch).value)
                        if (patternConfig.get(comp).key != null) {
                                // schedule timer for matched pattern
                                logInfo(light.name, "Delaying triggering for complete matched pattern: {}", patternConfig.get(comp).value)
                                tapTimer?.cancel
                                tapTimer = createTimer(now.plusMillis(LONG_SPAN))[|
                                        stateQueue.clear
                                        logInfo(light.name, "Fire scheduled pattern '{}' event to Switch({})", patternConfig.get(comp).value, patternConfig.get(comp).key.name)
                                        patternConfig.get(comp).key.sendCommand(ON)
                                ]
                                switchState.set(3, tapTimer)
                        }
                        else {
                                // No switch to receive the complete match event while partial match exist
                                // Do nothing, up to caller to decide the action path based on matchResult
                        }
                }
                else {
                        stateQueue.clear
                        if (patternConfig.get(comp).key != null)
                                patternConfig.get(comp).key.sendCommand(ON)
                }
        }
        else if (partialMatch > -1) {
                // Partial match is in progress, we should stop previous delayed complete match
                tapTimer?.cancel
        }
        return matchResult
]

rule "Corridor Double Tap"
when
        Item CorridorLights_Switch1 received update
then
        var matchResult = detectUpdatePatterns.apply(CorridorLights_Switch1, tapStates, newArrayList(null->'ON,OFF', null->'OFF,ON'))
        if (matchResult.get(0) == 2 || matchResult.get(1) == 2) {
                sendCommand (all_lights, OFF)
                sendCommand (avr1Z1_Power, OFF)
        }
end

After moving to the most recent snapshot 2.2.0-SNAPSHOT Build #1019 the commands are being executed as they should. Would it make most sense to check what changed from 1017 to 1019 on the z-wave binding? At the same time as this happened in the past multiple times (working / not working after update) I assume it is a bit more than a simple change which either breaks a function or not.

A couple of comments:

  • you don’t need and should not use any of the org.eclipse.smarthome includes not should you include org.joga classes. All of these are now included by default and I don’t know if they are guaranteed to stay on the same packages.

  • it is hard too do a full review of the code on my phone but it looks way overly complex for a typical set of rules. I see a few of what I consider code shells for the Rules DSL (I’m guessing you are a C/C++, C# or the like programmer. A coffee smell isn’t necessarily wrong, but it does make me pay closer attention to the code because there is likely a cleaner approach. What sticks out to me are the excessive use of Maps and Lists, multiple lambdas, arrays, lots of calls and vars. Like I said, this may be required to do what your are but I would look for opportunities to simplify. Check out the Working with Groups in Rules Design Pattern for some ideas. Also look at the JSR223 rules. Using Python or JavaScript for this rule may be easier.

As for your last bit, you can look at the commits for the latest release but now that you mention that it is ZWave I’m wondering if the problem is your mesh network is sparse or there is interference.

Thanks for the comments on the code. It is not written by myself. Used was created by Victor Bai and posted here some time ago.

Will try to implement what you suggest but in my view it is hard to make a link on the issue to the rule code as code seems to work.

Agree on the mesh network problem. This might be the issue. What would be best to further analyze this? Debug logging on the Z-Wave binding? Will try to do this and report back if I found something meaningful.

Debug logging and the log viewer and network viewer in HABmin will help. I discovered a long time ago that for some reason only one powered nice could see the controller so all messages were being routed through it. I added a new node and my network became much more reliable.