Item updated too quickly for rule to process state

jeremybd · January 27, 2020, 3:46pm

Hello,

I’m currently using the GlobalCache binding with an iTach Flex Serial to control my existing light system.
Every time I send a command, the light system respond with the state of all the scenes/items.

I then need to process all these responses and update my items accordingly.

It seems that there is too much informations sent back from my system to openhab for the rule to process all the state changes.

Here is the results on my current receiving Item on Openhab :

2020-01-27 17:29:49.238 [vent.ItemStateChangedEvent] - GC changed from LIGHTS_STAIRS_ON to LIGHTS_STAIRS_OFF
2020-01-27 17:29:49.355 [vent.ItemStateChangedEvent] - GC_RECEIVE changed from 0%2CITACH%2C63%2C0%0D to 0%2CITACH%2C1%2C0%0D
2020-01-27 17:29:49.367 [vent.ItemStateChangedEvent] - GC_RECEIVE changed from 0%2CITACH%2C1%2C0%0D to 0%2CITACH%2C2%2C0%0D
2020-01-27 17:29:49.380 [vent.ItemStateChangedEvent] - GC_RECEIVE changed from 0%2CITACH%2C2%2C0%0D to 0%2CITACH%2C3%2C0%0D
2020-01-27 17:29:49.390 [vent.ItemStateChangedEvent] - GC_RECEIVE changed from 0%2CITACH%2C3%2C0%0D to 0%2CITACH%2C4%2C0%0D
2020-01-27 17:29:49.402 [vent.ItemStateChangedEvent] - GC_RECEIVE changed from 0%2CITACH%2C4%2C0%0D to 0%2CITACH%2C5%2C0%0D
2020-01-27 17:29:49.416 [vent.ItemStateChangedEvent] - GC_RECEIVE changed from 0%2CITACH%2C5%2C0%0D to 0%2CITACH%2C9%2C0%0D
2020-01-27 17:29:49.421 [vent.ItemStateChangedEvent] - GC_RECEIVE changed from 0%2CITACH%2C9%2C0%0D to 0%2CITACH%2C10%2C0%0D
2020-01-27 17:29:49.426 [vent.ItemStateChangedEvent] - GC_RECEIVE changed from 0%2CITACH%2C10%2C0%0D to 0%2CITACH%2C11%2C0%0D
2020-01-27 17:29:49.503 [vent.ItemStateChangedEvent] - GC_RECEIVE changed from 0%2CITACH%2C11%2C0%0D to 0%2CITACH%2C13%2C0%0D
2020-01-27 17:29:49.518 [vent.ItemStateChangedEvent] - GC_RECEIVE changed from 0%2CITACH%2C13%2C0%0D to 0%2CITACH%2C17%2C0%0D
2020-01-27 17:29:49.536 [vent.ItemStateChangedEvent] - GC_RECEIVE changed from 0%2CITACH%2C17%2C0%0D to 0%2CITACH%2C18%2C0%0D
2020-01-27 17:29:49.556 [vent.ItemStateChangedEvent] - GC_RECEIVE changed from 0%2CITACH%2C18%2C0%0D to 0%2CITACH%2C19%2C0%0D
2020-01-27 17:29:49.572 [vent.ItemStateChangedEvent] - GC_RECEIVE changed from 0%2CITACH%2C19%2C0%0D to 0%2CITACH%2C20%2C0%0D
2020-01-27 17:29:49.589 [vent.ItemStateChangedEvent] - GC_RECEIVE changed from 0%2CITACH%2C20%2C0%0D to 0%2CITACH%2C21%2C0%0D
2020-01-27 17:29:49.599 [vent.ItemStateChangedEvent] - GC_RECEIVE changed from 0%2CITACH%2C21%2C0%0D to 0%2CITACH%2C22%2C0%0D
2020-01-27 17:29:49.613 [vent.ItemStateChangedEvent] - GC_RECEIVE changed from 0%2CITACH%2C22%2C0%0D to 0%2CITACH%2C23%2C0%0D
2020-01-27 17:29:49.621 [vent.ItemStateChangedEvent] - GC_RECEIVE changed from 0%2CITACH%2C23%2C0%0D to 0%2CITACH%2C24%2C0%0D
2020-01-27 17:29:49.627 [vent.ItemStateChangedEvent] - GC_RECEIVE changed from 0%2CITACH%2C24%2C0%0D to 0%2CITACH%2C26%2C0%0D
2020-01-27 17:29:49.631 [vent.ItemStateChangedEvent] - GC_RECEIVE changed from 0%2CITACH%2C26%2C0%0D to 0%2CITACH%2C27%2C0%0D
2020-01-27 17:29:49.636 [vent.ItemStateChangedEvent] - GC_RECEIVE changed from 0%2CITACH%2C27%2C0%0D to 0%2CITACH%2C28%2C0%0D
2020-01-27 17:29:49.643 [vent.ItemStateChangedEvent] - GC_RECEIVE changed from 0%2CITACH%2C28%2C0%0D to 0%2CITACH%2C29%2C0%0D
2020-01-27 17:29:49.648 [vent.ItemStateChangedEvent] - GC_RECEIVE changed from 0%2CITACH%2C29%2C0%0D to 0%2CITACH%2C33%2C0%0D
2020-01-27 17:29:49.654 [vent.ItemStateChangedEvent] - GC_RECEIVE changed from 0%2CITACH%2C33%2C0%0D to 0%2CITACH%2C34%2C0%0D
2020-01-27 17:29:49.658 [vent.ItemStateChangedEvent] - GC_RECEIVE changed from 0%2CITACH%2C34%2C0%0D to 0%2CITACH%2C39%2C0%0D
2020-01-27 17:29:49.661 [vent.ItemStateChangedEvent] - GC_RECEIVE changed from 0%2CITACH%2C39%2C0%0D to 0%2CITACH%2C40%2C0%0D
2020-01-27 17:29:49.665 [vent.ItemStateChangedEvent] - GC_RECEIVE changed from 0%2CITACH%2C40%2C0%0D to 0%2CITACH%2C45%2C0%0D
2020-01-27 17:29:49.669 [vent.ItemStateChangedEvent] - GC_RECEIVE changed from 0%2CITACH%2C45%2C0%0D to 0%2CITACH%2C50%2C0%0D
2020-01-27 17:29:49.674 [vent.ItemStateChangedEvent] - GC_RECEIVE changed from 0%2CITACH%2C50%2C0%0D to 0%2CITACH%2C51%2C0%0D
2020-01-27 17:29:49.710 [vent.ItemStateChangedEvent] - GC_RECEIVE changed from 0%2CITACH%2C51%2C0%0D to 0%2CITACH%2C52%2C0%0D
2020-01-27 17:29:49.727 [vent.ItemStateChangedEvent] - GC_RECEIVE changed from 0%2CITACH%2C52%2C0%0D to 0%2CITACH%2C53%2C0%0D
2020-01-27 17:29:49.738 [vent.ItemStateChangedEvent] - GC_RECEIVE changed from 0%2CITACH%2C53%2C0%0D to 0%2CITACH%2C60%2C0%0D
2020-01-27 17:29:49.747 [vent.ItemStateChangedEvent] - GC_RECEIVE changed from 0%2CITACH%2C60%2C0%0D to 0%2CITACH%2C61%2C0%0D
2020-01-27 17:29:49.758 [vent.ItemStateChangedEvent] - GC_RECEIVE changed from 0%2CITACH%2C61%2C0%0D to 0%2CITACH%2C62%2C0%0D
2020-01-27 17:29:49.763 [vent.ItemStateChangedEvent] - GC_RECEIVE changed from 0%2CITACH%2C62%2C0%0D to 0%2CITACH%2C63%2C0%0D

I created a rule like this one:

rule 'GC RECEIVE PROCESSOR'
when
    Item GC_RECEIVE received update
then
    var item_state = GC_RECEIVE.state.toString.replace("%2C", ",")
    switch (item_state) {
        case "0,ITACH,50,1%0D" : AC_LIVING.postUpdate(ON)
        case "0,ITACH,50,0%0D" : AC_LIVING.postUpdate(OFF)
        case "0,ITACH,51,0%0D" : AC_ROOMS.postUpdate(OFF)
        case "0,ITACH,51,1%0D" : AC_ROOMS.postUpdate(ON)
        case "0,ITACH,22,0%0D" : BOILER.postUpdate(OFF)
        case "0,ITACH,22,1%0D" : BOILER.postUpdate(ON)
        case "0,ITACH,23,0%0D" : FLOOR_HEAT_GREY_BATHROOM.postUpdate(OFF)
        case "0,ITACH,23,1%0D" : FLOOR_HEAT_GREY_BATHROOM.postUpdate(ON)
        case "0,ITACH,24,0%0D" : TOWEL_HEAT_GREY_BATHROOM.postUpdate(OFF)
        case "0,ITACH,24,1%0D" : TOWEL_HEAT_GREY_BATHROOM.postUpdate(ON)
        case "0,ITACH,27,0%0D" : FLOOR_HEAT_RED_BATHROOM.postUpdate(OFF)
        case "0,ITACH,27,1%0D" : FLOOR_HEAT_RED_BATHROOM.postUpdate(ON)
        case "0,ITACH,26,0%0D" : TOWEL_HEAT_RED_BATHROOM.postUpdate(OFF)
        case "0,ITACH,26,1%0D" : TOWEL_HEAT_RED_BATHROOM.postUpdate(ON)
        case "0,ITACH,45,0%0D" :  LIGHTS_STAIRS.postUpdate(OFF)
        case "0,ITACH,45,1%0D" :  LIGHTS_STAIRS.postUpdate(ON)
        default: logInfo("CMD","GC_RECEIVE " + item_state )
    }
end

But the logInfo is always logging the latest state of the item (in my case 0%2CITACH%2C63%2C0%0D) for each of the values that are not defined in a case. Also every time my item GC_RECEIVE it seems to randomly drop (at last not process) some of the status changes.

I wonder if there a way to make my receiving item fast enough ?

Currently the “state” received by my global cache item is broken down into the different scene by the globalcache binding using the end of message Delimitier.

My lighting system sends a huge message with all the scenes, the global cache binding splits it into different message and update the item of each of these messages.

I might be able to remove the end of message delimiter from the globalcache rule, and split the message directly in the rule so that the item is updated only once when something changes instead of once for every scene in my lighting system.

Does someone have an idea to keep the current message delimiter and make my rule/OH process these state changes faster?

Thanks a lot

H102 · January 27, 2020, 4:00pm

I’m not familiar with this binding but would using switch true so only the item that’s changed will be posted work? Also does the item not post the state after a change automatically?

jeremybd · January 27, 2020, 4:06pm

my GC_RECEIVE item will aways receive 31 update in less than 1 second, every time I turn on / off a light in my house either from OpenHab or from the wall switches.

Ffrom my understanding the item state always change as the latest update is for zone 63 and the first one from zone 1. So every time the item has been updated as it circle through all the zones.

I’m not sure I understand your second question, I tried to replace the case by a log to display the state of the item, but it will print 31 times the serial code for Zone 63 even if the item is updated from zone 1 to 2, zone 2 to 3 … to zone 63 at the the end.

H102 · January 27, 2020, 4:15pm

That’s what the rule is doing, just posting an update of everything. Is that necessary and does the binding support auto-update on the item itself?

jeremybd · January 27, 2020, 4:22pm

Well I would love to only have an update for the updated items, but my lightning system won’t allow me to do that. And the Globalcache binding, only let me update one false item (the receiving item) and add a rule to process these updates.

I’m pretty sure the binding support auto-update on the item itself. I only use the binding as a gateway between lots of ‘fake items’ on OH and my items on the light system.

rossko57 · January 27, 2020, 4:33pm

In latest OH versions, implicit variable newState is provided for just this purpose.

mhilbush · January 27, 2020, 8:55pm

And if you want the detail behind the change, here’s the link to the original issue. IIRC, I believe you need to use changed versus received update in your rule’s when clause.

jeremybd · January 27, 2020, 9:07pm

Thanks @rossko57 and @mhilbush for the help. newState is the solution in my case. I read the PR and the documentation and implemented it successfully. It’s working as expected and I don’t have anymore update that goes unprocessed/skipped.

I did not changed the received update part any reason why changed would be better vs received update?

@mhilbush as usual thanks for the help. You are always here when I have an issue with your globalcache binding I’m still trying to figure out that broken pipe issue but at least everything else is working and now the Receiving part is also working.

Thanks

rossko57 · January 27, 2020, 9:49pm

I believe it is oldState that does not exist (makes no sense) unless you have a changed trigger. If it works with updated, it works.

Note, there is no guarantee that your rules will process a flurry of updates in the order in which they arrive. I do not think that matters for you.

Note also that a rapid-fire flurry can result in several versions of the same rule running in parallel at various stages. Again I do not think that matters for you with this relatively simple rule, but if it were more complex you might have to guard against concurrency.

mhilbush · January 27, 2020, 10:33pm

Only because I knew it was tested with changed. I figured received update would work, but I was SURE changed would work.

Yes that’s right. Thanks for clarifying!

jeremybd · January 28, 2020, 10:36am

Thanks for the details, I currently don’t really care about the process order of the received command so that should work for now. I’ll investigate the concurrency part it’s always interesting to learn

Thanks everyone for your help!

rossko57 · January 28, 2020, 11:05am

I think rules are reasonably thread safe. In your original case, you have one variable created and populated within the rule. I think each version of the rule that starts off makes its own copy of that.
(Otherwise the risk would be that one rule halfway through finds a later rule altering the shared variable.)

You’re only going to get into trouble where the rule interacts with things outside of its scope.
Example, you’ve another Item counting how many times the rule is run. You increment that by reading the existing value and writing back with +1.
There’s a hole there - you might read a value, another rule can update the Item independently, you write back “your” +1 and destroy the other rule’s data.

Event driven rules in a multi-threading environment are head spinning. In the vast majority of cases though, we are only getting one event at a time and need not worry.