Amazon Echo Control - Rule being executed twice if last and current command are identical

Hey guys,

so I’m currently fiddling around with starting OH rules through my Echo devices and I noticed that if the last and the new command are identical (not a common scenario though…), the rule is being executed twice. Not sure if I’m doing something wrong here or if that’s within the binding…

Here’s the output (first line is the last command that changes to “alexa”):

2020-08-02 14:57:13.701 [vent.ItemStateChangedEvent] - Echo_Kitchen_LastVoiceCommand changed from schick staubi in die küche to alexa
2020-08-02 14:57:15.398 [vent.ItemStateChangedEvent] - Echo_Kitchen_LastVoiceCommand changed from alexa to schick staubi in die küche
2020-08-02 14:57:16.301 [ome.event.ItemCommandEvent] - Item 'AlexaDoNothing' received command ON
2020-08-02 14:57:25.009 [ome.event.ItemCommandEvent] - Item 'vacuumActionCommand' received command app_zoned_clean[[32654,24967,35754,30367,1]]
2020-08-02 14:57:25.033 [ome.event.ItemCommandEvent] - Item 'vacuumActionCommand' received command app_zoned_clean[[32654,24967,35754,30367,1]]
2020-08-02 14:57:25.056 [ome.event.ItemCommandEvent] - Item 'Echo_Kitchen_TTS' received command OK, Staubi kommt gleich in die Küche. Stell das Wasserschälchen hoch.
2020-08-02 14:57:25.079 [ome.event.ItemCommandEvent] - Item 'Echo_Kitchen_TTS' received command OK, Staubi kommt gleich in die Küche. Stell das Wasserschälchen hoch.
2020-08-02 14:57:25.083 [nt.ItemStatePredictedEvent] - vacuumActionCommand predicted to become app_zoned_clean[[32654,24967,35754,30367,1]]
2020-08-02 14:57:25.110 [nt.ItemStatePredictedEvent] - vacuumActionCommand predicted to become app_zoned_clean[[32654,24967,35754,30367,1]]
2020-08-02 14:57:25.133 [nt.ItemStatePredictedEvent] - Echo_Kitchen_TTS predicted to become OK, Staubi kommt gleich in die Küche. Stell das Wasserschälchen hoch.
2020-08-02 14:57:25.148 [nt.ItemStatePredictedEvent] - Echo_Kitchen_TTS predicted to become OK, Staubi kommt gleich in die Küche. Stell das Wasserschälchen hoch.
2020-08-02 14:57:25.168 [vent.ItemStateChangedEvent] - vacuumActionCommand changed from {"result":["ok"],"id":3622} to app_zoned_clean[[32654,24967,35754,30367,1]]
2020-08-02 14:57:25.172 [vent.ItemStateChangedEvent] - Echo_Kitchen_TTS changed from  to OK, Staubi kommt gleich in die Küche. Stell das Wasserschälchen hoch.
2020-08-02 14:57:25.177 [vent.ItemStateChangedEvent] - vacuumActionCommand changed from app_zoned_clean[[32654,24967,35754,30367,1]] to {"result":["ok"],"id":5480}
2020-08-02 14:57:25.189 [vent.ItemStateChangedEvent] - vacuumActionCommand changed from {"result":["ok"],"id":5480} to {"result":["ok"],"id":5481}
2020-08-02 14:57:27.208 [vent.ItemStateChangedEvent] - Echo_Kitchen_TTS changed from OK, Staubi kommt gleich in die Küche. Stell das Wasserschälchen hoch. to 

And here’s the rule for it:

when
    Member of gEchoLastCommands changed
then
    if ((triggeringItem.state != "alexa") && (triggeringItem.state.toString.contains("staubi"))) {
        var alexaResponse =""
        var roomCoordinates = ""
        if (vacMapOrientation.state == ON)
            mapOrientation = "Vert"
        else
            mapOrientation = "Hor"
        if(triggeringItem.state.toString == "schick staubi in die küche")   {
            alexaResponse = "OK, Staubi kommt gleich in die Küche. Stell das Wasserschälchen hoch."
            roomCoordinates = transform("MAP","vacuum.map",("kueche" + mapOrientation))
            vacuumActionCommand.sendCommand("app_zoned_clean["+roomCoordinates+"]")
        }
        else if(triggeringItem.state.toString == "schick staubi ins schlafzimmer")   {
            alexaResponse = "OK, Staubi kommt gleich ins Schlafzimmer. Halt die Katzen zurück!"
            roomCoordinates = transform("MAP","vacuum.map",("schlafzimmer" + mapOrientation))
            vacuumActionCommand.sendCommand("app_zoned_clean["+roomCoordinates+"]")
        }
            if(triggeringItem.getGroupNames.contains("Alexa_Kitchen"))
                Echo_Kitchen_TTS.sendCommand(alexaResponse)
    }
end

Did you have similiar experiences?

It’s not quite clear what you expected to happen?
I guess these are your two triggering events -

and you expected two rule triggers, but you expected the one with state “alexa” to avoid performing the body of the rule?

There is a lot of lag in your system. Assuming this is a result of the rule running -

It’s come ten seconds after the rule was triggered.

I would guess this is the source of your trouble -

If there is a significant delay between the rule being triggered and looking at the state of the Item - the state may have changed since the trigger.
In fact, we know it changed away from “alexa” two seconds later.

You might have come up against either -

  • rules that have not been used for hours may take 8 or 10 secs on the next run.
  • or you have some general problem, like other rules hogging execution threads and delaying rule runs.

You forgot to mention that neither of those issues occur with the new rule engine. :wink:

OP’s rule is written in DSL rules language. It’s probably worth understanding the problem before embarking on a wholesale rewrite into a different language, that may just mask the underlying problem behind a different set of symptoms.

Thanks for your quick reply.
So the rule is sending the vacuum robot into the kitchen.
I noted that “alexa” and the command are regarded as 2 seperate commands by OH (as seen in the first 2 lines of my log), thats why I added the if statement. Is this not the expected behaviour?

I’m running OH on a Pi 3. While my CPU temperature is rather high (~75°), htop doesn’t show anything suspicious in terms of CPU or mem usage. Where would you start investigation on rules hogging execution threads?

well… probably the best place to start is looking at the rules themselves. Look for things which could keep a thread open for a long time. Most rules execute and exit in milliseconds. Thread sleeps (longer then a few milliseconds) are obviously a no no. Also look for things which send out a request and then wait for a reply.
Rich gets into it a little better here

Well, they’re state updates not openHAB commands (if they were truly commands we could deal with them better).

It’s a problem of timing. A state change triggers your rule, but that does not stop the state changing again.
You have an unexpectedly large delay, several seconds, between the rule being triggered, and your if() looking at the state. Long enough for the state to change again.

If your “real” states of interest are always preceded by “alexa”?
you could alter your rule trigger to

when
    Member of gEchoLastCommands changed from "alexa"

// or perhaps to allow first time after a reboot

when
    Member of gEchoLastCommands changed from NULL or
    Member of gEchoLastCommands changed from "alexa"

but this is a circumvention - the underlying problem is the delay.

1 Like

Thanks guys, I’ll dig into it and report back.