[Solved] Exec Command only Executed on Item Change

Add-ons Bindings
11

No worries, the script takes ony a few milli seconds.

Now I’ve added a new item:

String execTestOutput {channel="exec:command:execTestThing:output"}

and a new rule:

rule "rule_exec_output"
    when
        Item execTestOutput changed
    then
        logWarn("rule_exec_output", "script echo:" + execTestOutput.state)
end

When the exec argument changes the output shows the echo from the script (the script starts with an echo of the current date and time):

2019-09-08 18:43:00.029 [ome.event.ItemCommandEvent] - Item ‘execTestItem’ received command 299,222
2019-09-08 18:43:00.039 [nt.ItemStatePredictedEvent] - execTestItem predicted to become 299,222
2019-09-08 18:43:00.060 [vent.ItemStateChangedEvent] - execTestItem changed from 299,221 to 299,222
2019-09-08 18:43:00.201 [vent.ItemStateChangedEvent] - execTestOutput changed from timestamp = 08.09.2019;18:37:00 to timestamp = 08.09.2019;18:43:00

==> /var/log/openhab2/openhab.log <==
2019-09-08 18:43:00.056 [WARN ] [rthome.model.script.rule_exec_test 1] - update Logfile: 299,222
2019-09-08 18:43:00.210 [WARN ] [rthome.model.script.rule_exec_output] - script echo:timestamp = 08.09.2019;18:43:00

When the exec argument has not changed the output looks like this (the echo is missing):

2019-09-08 18:38:00.024 [ome.event.ItemCommandEvent] - Item ‘execTestItem’ received command 299,221
2019-09-08 18:38:00.029 [nt.ItemStatePredictedEvent] - execTestItem predicted to become 299,221

==> /var/log/openhab2/openhab.log <==
2019-09-08 18:38:00.025 [WARN ] [rthome.model.script.rule_exec_test 1] - update Logfile: 299,221

This looks to me like the script is not executed when the argument has not changed.

12

Not to me, you are forcing a report only on change. Try -

rule "rule_exec_output"
    when
        Item execTestOutput received update
    then
        logWarn("rule_exec_output", "script echo:" + execTestOutput.state)
end

Also make a Switch Item, linked to run channel. no rule needed as this will be visible in events.log

13

You are totally right. I changed the rule to be executed on an update. But it is not triggered when the item has not changed.

I’ve never worked with switch items so far. I don’t understand how this should look like.

14

xxx.items file

Switch myExecRun {channel="exec:command:execTestThing:run"}

You will see in the events.log (because it changes) this switch go to state ON when the script runs, then a few milliseconds later, all being well, to OFF when the script terminates (or times out).

15

The good news is that you don’t have that silly delay like me - sure it is some Windows host effect.

16

Sorry for repying just now.
Thanks a lot for showing how a switch item is added.
When the exec argument changes I now get this for the switch item:

2019-09-09 08:54:00.110 [vent.ItemStateChangedEvent] - execTestItem changed from 299,428 to 299,429
2019-09-09 08:54:00.114 [vent.ItemStateChangedEvent] - myExecRun changed from OFF to ON
2019-09-09 08:54:00.247 [vent.ItemStateChangedEvent] - myExecRun changed from ON to OFF

When the exec argument doesn’t change there’s no output about the switch item.

I’m running version 2.4.0 on a Raspberry Pi, the Exec binding has been installed using the Paper UI.

17

Okay, you are running exactly the same exec binding as me and getting different behaviour.
We’ll need a demo of that, please.

Please set up an additional test exec Thing, very simplistic and expected to “fail”

Thing exec:command:testecho [command="rubbish", autorun=true]

and associated Items

Switch testSw {channel="exec:command:testecho:run"}   // run monitor
String testString {channel="exec:command:testecho:input"}   // input command

and add a trigger to your existing rule

testSw.sendCommand("rhubarb")

Part of the idea here is to eliminate any weird hidden broken Items or things, all fresh moving parts.

Optionally, add an Item you would expect to receive the message complaining about missing filename.

String testResult {channel="exec:command:testecho:output"}

The events.log for the first and second runs would be of interest, i.e. with state changes then without.

18

rhubarb??
Now that’s random…

19

Brit thing … traditionally, speech without meaningful words is “Rhubarb rhubarb rhubarb”. :wink:

I think it’s theatrical originally - something for extras at the back of the scene to look and sound like conversation, without having any attention getting sounds. But at least among my elderly age group in ordinary use to describe politician’s speeches etc., just a version of “blah blah blah”

20

Well, well. I have been living in the country for 25 years now and I still learn something about the language almost everyday.

Nice one. Thanks

21

I’ve added your suggestions to the configuration files. For the “rubbish” thing I got this:

2019-09-09 13:59:35.840 [me.event.ThingUpdatedEvent] - Thing ‘exec:command:execTestThing’ has been updated.
2019-09-09 13:59:35.850 [hingStatusInfoChangedEvent] - ‘exec:command:testecho’ changed from UNINITIALIZED to INITIALIZING
2019-09-09 13:59:35.856 [hingStatusInfoChangedEvent] - ‘exec:command:testecho’ changed from INITIALIZING to ONLINE

and

==> /var/log/openhab2/openhab.log <==
2019-09-09 13:59:35.790 [INFO ] [el.core.internal.ModelRepositoryImpl] - Refreshing model ‘exec-test.things’
2019-09-09 13:59:35.855 [ERROR] [hab.binding.exec.handler.ExecHandler] - An exception occurred while executing ‘rubbish’ : ‘Cannot run program “rubbish”: error=2, Datei oder Verzeichnis nicht gefunden’

Which means file or directory not found.
Updating the items and rules didn’t result in error messages.

Now when the cron job is triggered the output shows this (no change in exec argument, script doesn’t update log file):

2019-09-09 14:07:00.048 [ome.event.ItemCommandEvent] - Item ‘execTestItem’ received command 299,518
2019-09-09 14:07:00.054 [nt.ItemStatePredictedEvent] - execTestItem predicted to become 299,518

==> /var/log/openhab2/openhab.log <==
2019-09-09 14:07:00.060 [WARN ] [rthome.model.script.actions.BusEvent] - Cannot convert ‘rhubarb’ to a command type which item ‘testSw’ accepts: [OnOffType, RefreshType].
2019-09-09 14:07:00.066 [WARN ] [rthome.model.script.rule_exec_test 1] - update Logfile: 299,518

22

Sorry, typo in instruction. You want to be sending commands to testString not testSw

I am really curious why your creation of a new thing around 13:59 should trigger an executon attempt (that fails just as we expect).
There should be nothing to trigger it at that time.

23

No problem. I changed the rule to this:

testString.sendCommand("rhubarb")

When the exec argument has changed I get this with the a new line in my log file and the echo of the script reflected here:

2019-09-09 16:14:00.054 [ome.event.ItemCommandEvent] - Item ‘execTestItem’ received command 299,549
2019-09-09 16:14:00.071 [nt.ItemStatePredictedEvent] - execTestItem predicted to become 299,549
2019-09-09 16:14:00.074 [vent.ItemStateChangedEvent] - execTestItem changed from 299,548 to 299,549
2019-09-09 16:14:00.077 [vent.ItemStateChangedEvent] - myExecRun changed from OFF to ON
2019-09-09 16:14:00.079 [ome.event.ItemCommandEvent] - Item ‘testString’ received command rhubarb
2019-09-09 16:14:00.082 [nt.ItemStatePredictedEvent] - testString predicted to become rhubarb
2019-09-09 16:14:00.206 [vent.ItemStateChangedEvent] - myExecRun changed from ON to OFF
2019-09-09 16:14:00.214 [vent.ItemStateChangedEvent] - execTestOutput changed from to timestamp = 09.09.2019;16:14:00

==> /var/log/openhab2/openhab.log <==
2019-09-09 16:14:00.077 [WARN ] [rthome.model.script.rule_exec_test 1] - update Logfile: 299,549
2019-09-09 16:14:00.221 [WARN ] [rthome.model.script.rule_exec_output] - script echo:timestamp = 09.09.2019;16:14:00

When there’s no change in the exec argument I get this:

2019-09-09 16:19:00.037 [ome.event.ItemCommandEvent] - Item ‘execTestItem’ received command 299,553
2019-09-09 16:19:00.049 [nt.ItemStatePredictedEvent] - execTestItem predicted to become 299,553
2019-09-09 16:19:00.062 [ome.event.ItemCommandEvent] - Item ‘testString’ received command rhubarb
2019-09-09 16:19:00.071 [nt.ItemStatePredictedEvent] - testString predicted to become rhubarb

==> /var/log/openhab2/openhab.log <==
2019-09-09 16:19:00.055 [WARN ] [rthome.model.script.rule_exec_test 1] - update Logfile: 299,553

I don’t understand why there is activity logged when the cron has not fired (which happens every minute):

2019-09-09 16:18:39.271 [vent.ItemStateChangedEvent] - testSw changed from OFF to ON

==> /var/log/openhab2/openhab.log <==
2019-09-09 16:18:39.270 [ERROR] [hab.binding.exec.handler.ExecHandler] - An exception occurred while executing ‘rubbish’ : ‘Cannot run program “rubbish”: error=2, Datei oder Verzeichnis nicht gefunden’

Again, the message here means something like file or directory not found.
Is that a similar behaviout that you pointed out befor at 13:59?

24

The behaviour being described by Markus is correct, Exec’s autorun feature won’t repeat an execution if the command being received on the input channel is the same as previously executed. The reason the test performed by @rossko57 was working is because they never set the “interval” parameter to 0, and so by default the command repeated every 60 seconds (conveniently the same as the cron rule).

You could get around this by making sure the command is unique every time, for example by appending the current time in milliseconds:

execTestItem.sendCommand(execArgument + " " + now.millis.toString)

Your script might need to be changed to ignore the last parameter.

1 Like
25

Or actually, maybe even simpler… turn OFF autorun and instead use

execTestItem.sendCommand(execArgument)
testSw.sendCommand(ON)
26

Spot on, this came to me this afternoon, with a big “duh” moment! :crazy_face:

Yes, verified under various circumstances. In my view, that’s a deficiency. (not least because it is inconsistent with autorun behaviour - which executes whether anything changed or not).

27

I led myself and others right up the garden path here. Totally convinced I’d previously had autorun working with repeated same command, but clearly I imagined that.
Sorry it’s taken so long to get to a fix because I doubted your findings, @Automark

Actually, this won’t work.
There would be a timing race risk that the asynchronous update had not completed before the run took effect. (Tiny risk)
But more importantly, the exec binding simply ignores the input channel state and only uses commands sent to input channel. (Pretty much how all bindings work.)

I’ve just been testing in detail (while paying more attention) and have submitted some clarifications for the docs.
Part of that was working up a reliable means to execute on demand, while overcoming the limitation of autorun ignoring duplicate commands.

Abandon autorun (and of course set interval 0 as well!), to leave the exec Thing purely under switch control.

Thing exec:command:execTestThing "execThing" [command="sudo /etc/openhab2/scripts/execTestScript.sh %2$s", interval=0, autorun=false, timeout=5, transform="REGEX((.*?))"]

Add an Item for a Go switch, note suppression of autoupdate means we can send commands but only the binding will update state to reflect run status.

String execTestItem {channel="exec:command:execTestThing:input"}
Switch execRun {channel="exec:command:execTestThing:run", autoupdate="false"}

Now an additional little rule to control the action. The separate ‘run’ rule is preferred to guarantee the correct order of parameter-then-execute.

rule "rule_exec_test"
   when
      Time cron "0 * * * * ?"                // every minute
   then
      var Number reading = (nWaterMeterReading.state as DecimalType).floatValue
      var String execArgument = String::format("%1$.3f", reading)
      execTestItem.sendCommand(execArgument)
      logWarn("rule_exec_test", "update exec parameter: " + execArgument)
end

rule "rule_exec_run"
   when
      Item execTestItem received command // new or same parameters
   then
      if (execRun.state != ON {   // busy check
         execRun.sendCommand(ON) // trigger script
      } else {
         logWarn("rule_exec_run", "script busy, skipping execution")
      }
end

Now I’ll show you a magic trick :wink:

String execTestItem {channel="exec:command:execTestThing:input", channel="exec:command:execTestThing:output", autoupdate="false"}

We can suppress autoupdate messing with the Item state, and add a second link to exec output string channel.
You can send a command to this Item, and get the response/results back in the same Item state.
A rule can listen for received update on this shared Item if anything needs to be done with results.

1 Like
28

fricking Bravo Rossko!!!
:+1: :beers:

29

Hello,
first I’d like to thank you all for clearing this up! So this is not a bug but a known behaviour.

To be honest, I don’t understand all the suggsted solutions like turning autorun off or the quite elaborate one by Rossko. I’ll need a quiet hour to read and test all this.

For now I’ve only added the current time to the exec argument which works well. But I’ll also look into the other solutions as they might be more elegant.

30

Not to undermine the work figuring out the exec binding, but if you are looking for a solution to controlling GPIO with openHAB you could try MQTTany. It won’t do the processing that your script is doing to give you a value, but perhaps that could be moved to a rule.