Errors after updating to MQTTController build 25139

[cw-kid]

Using a Vera Multistring plugin device.

I added these in the rules Reaction to send the values to the generic sensor device in Vera etc.

Just need to translate codes 200 and 620 to "On" and "Off" instead.

I could maybe delete these two expressions from the rule also.

EDIT:

I've just seen a new field called "status" maybe I can use that instead.

On = "OK"

Off = "Standby"

[toggledbits]

I had a moment to do a quick test. Duh; I'm forgetting my own code's behavior. This is actually pretty simple. When you reset the rule, all state and expression/variable values are removed, so effectively, everything is null. When the rule is then re-evaluated, expressions are evaluated first, and since ps4wakercheck is null at that point because the action has not yet run, then ps4wakerparse is also null, so the last two expressions can't dereference through null and throw an evaluation error. This is actually all expected, correct behavior.

You can probably just clear these two spurious errors (caused by the reset/no data condition at rule "boot"), as they will not happen again, typically. The only other way you would see this is if the command actually fails hard in some way and produces no parseable JSON output. Then you'll get alerts again, but that's probably good because you might want to know that.

Another way to handle it is to simply modify the last two expressions like this:

• ps4powerstatus = ps4wakerparse?.statusCode
• ps4runningapp = ps4wakerparse?["running-app-name"]

The ?. and ?[ operators, described in the docs, are special coalescing versions of the standard . and [ operators that guard null on their left-hand operands. If the left-side operand value is null, the coalescing operator will simply return null and no error will be issued. I think this also makes sense in this application. These coalescing operators are provided for exactly this kind of case, so this is a perfect example of their use, and you should familiarize yourself with them (and apply them often).

[toggledbits]

You can map a value from one to another using a simple map object, like this:

mappedStatus = ( { '200': 'On', '620': 'Off' } )?[ ps4wakerparse.statusCode ] ?? "unknown"

Here, we create an object on the fly (the ( { ... } ) part), dereference through it using the ?[ coalesce operator, which will return null if the value of statusCode doesn't match anything in the object, and then use a final ?? coalesce operator to change an unmapped/null to the word unknown

Ref: Reactor docs: Expressions

[cw-kid]

@toggledbits said in Having issues with a shell command:

The ?. and ?[ operators

That fixes it the red alerts don't appear any more when Resetting the rule.

Thanks

[cw-kid]

@toggledbits

Finished device in Vera:

Home Remote dashboard tile:

Had to just add an additional ? to this code to stop the red alert appearing again.

( { '200': 'On', '620': 'Off' } )?[ ps4wakerparse?.statusCode ] ?? "unknown"

And now the alert doesn't come back again when resetting the rule.

So I think everything is all working fine now, at least while the PS4 is turned ON.

Thanks

[cw-kid]

@toggledbits

So everything last night was working OK when the PS4 was turned ON.

I am now testing when the PS4 is OFF.

Some issues the shell command doesn't seem to be populating the ps4wakercheck variable for some reason and its null.

Vera device when PS4 is OFF

If I run the "ps4-waker check" command in terminal it outputs correctly as expected.

root@HP-Thin01:/home/stuart# ps4-waker check
{
  "type": "device",
  "statusLine": "620 Server Standby",
  "statusCode": "620",
  "status": "Standby",
  "host-id": "C863F1400EF1",
  "host-type": "PS4",
  "host-name": "PS4-806",
  "host-request-port": "997",
  "device-discovery-protocol-version": "00020020",
  "system-version": "08520011",
  "address": "192.168.0.201"
}

Log file:

2021-08-02T10:51:27.077Z <Engine:NOTICE> Starting reaction PS4 Waker Check<SET> (rule-krq612qx:S)
2021-08-02T10:51:27.077Z <Engine:5:Engine.js:1378> Engine#1 reaction rule-krq612qx:S step 1 shell command { "command": "ps4-waker check", "rule": "rule-krq612qx", "rvar": "ps4wakercheck", "ignore_exit": true }
2021-08-02T10:51:27.094Z <Engine:5:Engine.js:1105> _process_reaction_queue() task returned, new status 3; task 19
2021-08-02T10:51:27.098Z <Engine:5:Engine.js:1140> _process_reaction_queue ending with 1 in queue; none delayed/ready; waiting
2021-08-02T10:51:27.617Z <Engine:ERR> Engine#1 reaction PS4 Waker Check<SET> step 1 error executing shell `ps4-waker check': Error: Command failed: ps4-waker check

2021-08-02T10:51:27.620Z <Rule:5:Rule.js:674> Rule#rule-krq612qx rule set variable ps4wakercheck = (object) (null)
2021-08-02T10:51:27.621Z <Engine:5:Engine.js:940> Engine#1 set variable rule rule-krq612qx ps4wakercheck=(null), requesting re-eval
2021-08-02T10:51:27.624Z <Rule:5:Rule.js:962> Rule#rule-krq612qx (PS4 Waker Check) evaluate() acquiring mutex
2021-08-02T10:51:27.625Z <Engine:5:Engine.js:1140> _process_reaction_queue() wake-up!
2021-08-02T10:51:27.625Z <Rule:5:Rule.js:966> Rule#rule-krq612qx._evaluate() mutex acquired, evaluating
2021-08-02T10:51:27.626Z <Rule:5:Rule.js:970> Rule#rule-krq612qx update rate is 2/min limit 60/min
2021-08-02T10:51:27.627Z <Rule:5:Rule.js:892> Rule#rule-krq612qx evaluateExpressions() with 3 expressions
2021-08-02T10:51:27.628Z <Rule:5:Rule.js:982> Rule#rule-krq612qx._evaluate() trigger state now false (was false)
2021-08-02T10:51:27.629Z <Rule:5:Rule.js:984> Rule#rule-krq612qx._evaluate() constraints state true
2021-08-02T10:51:27.629Z <Rule:5:Rule.js:993> Rule#rule-krq612qx rule state now false, changed no
2021-08-02T10:51:27.631Z <Engine:5:Engine.js:1101> _process_reaction_queue() running task 19 { "tid": 19, "id": "rule-krq612qx:S", "rule": "rule-krq612qx", "__reaction": [RuleReaction#rule-krq612qx:S], "next_step": 2, "status": 1, "ts": 1627901487069, "parent": --null--, "__resolve": --function--, "__reject": --function--, "__promise": [object Promise], "attempts": 1 }
2021-08-02T10:51:27.632Z <Engine:NOTICE> Resuming reaction PS4 Waker Check<SET> (rule-krq612qx:S) from step 2
2021-08-02T10:51:27.632Z <Engine:NOTICE> PS4 Waker Check<SET> delaying until 1627901492632<02/08/2021, 11:51:32>
2021-08-02T10:51:27.633Z <Engine:5:Engine.js:1105> _process_reaction_queue() task returned, new status 2; task 19
2021-08-02T10:51:27.636Z <Engine:5:Engine.js:1140> _process_reaction_queue() ending with 1 in queue; waiting for 1 (next delayed task)

If I turn ON the PS4 it starts working again and the variable is populated with data via the shell command.

[toggledbits]

Make sure you restarted Reactor after installing the update. The ignore flag is in the action data (so the UI has done the right thing), but the log file content looks like an older version of the Engine running.

[toggledbits]

Any update on this?

[cw-kid]

@toggledbits

Sorry for the delay.

Yes its working now after restarting MSR.

So when the PS4 is OFF its now reporting the status correctly from the ps4-waker check variables.

So its working when its on and off now.

However I am still getting some alert errors sometimes occasionally.

This seems to happen if the shell command doesn't return any response on the first go, but maybe on the second attempt it works and then populates the variables OK.

When this happens these alerts remain in the MSR gui etc.

[toggledbits]

Use your coalesce operators on those expressions to suppress the reference errors and just yield a null result.

[cw-kid]

@toggledbits

The actions in the Reaction that send the data to the Vera MutliString device, didn't have "?" in their expressions.

I have just added them like this:

EDIT:

It doesn't like the first one " mappedstatuscode? " I've removed the question mark for that one.

[cw-kid]

I've also now added a virtual switch in Vera, this works with two new MSR rules (#3 and #4).

First rule (#4), that when the virtual switch it turned on or off manually in Vera / Home Remote app, it will send the appropriate power command to the ps4 via shell command:

ON = ps4-waker

OFF = ps4-waker standby

The second rule (#3) updates the state of the Vera virtual switch, if the PS4's power is controlled by some other outside means.
This rule monitors the "mappedstatuscode" expression variable, which will either say "On" or "Off" and then it adjusts the Vera virtual switch accordingly to match that current actual state of the PS4, so the virtual switch doesn't get out of sync.

I am still experimenting with this, but my thinking was to have an additional "switch" in Vera / Home Remote app, to be able to manually / directly control the PS4's power (outside of a Harmony activity) as a backup switch. Say if the PS4 didn't turn on when the Harmony Activity for it was started and the other MSR rule (#1) didn't work with its attempt and didn't turn on the PS4.

Although having said that, I guess some kind of test and retry (in rule #1) to attempt to turn on the PS4 power again, might be a better way of doing it, if it failed to do so initially.

So in total I currently have four rules.

1. "Lounge - Harmony PS4 Activity Start - Wake PS4 Shell Command"

Turns on PS4 when Harmony Activity is starting.

2. "PS4 Waker Check"

This is the rule with all the expressions in it for the MultiString Vera device. Displays the PS4's current status etc

3. "Playstation 4 Virtual Switch Status from PS4-Waker"

Controls the virtual switch in Vera based on the actual state of the PS4 power, info as coming from ps4-waker check and rule #2

4. "Playstation 4 Virtual Switch ON / OFF"

Sends either the on or off shell commands to the PS4 based on the virtual switch in Vera / Home Remote app being manually operated.

Home Remote tiles:

I am sure there must be better / easier ways of doing all this.

[toggledbits]

This seems to happen if the shell command doesn't return any response on the first go

Have you figured out what ps4-waker does when it doesn't get the device turned on? Does it return a particular exit code that isn't used by the on/off status result? Or does it just give an empty reply? Either way, you might write a wrapper script to detect that and retry (Reactor would then start the wrapper script instead of ps4-waker directly.

Issues like this are how you bring your shell scripting and system administration skills up a notch.

[cw-kid]

@toggledbits said in Having issues with a shell command:

Have you figured out what ps4-waker does when it doesn't get the device turned on?

I'm not sure, I will look out for when it happens again.

I think it makes MSR error when it tries to send the "ps4-waker" command to turn ON the games console but fails to connect for whatever reason.

Most times it works and the console does turn on but sometimes it doesn't.

Thanks

[cw-kid]

@toggledbits

Actually I have five MSR rules for the Playstation. I have another one that is also monitoring for the Harmony Activity starting, this rule closes the lounge blind and curtains if its daytime.

Would having two rules monitoring for the same trigger event, the Harmony Activity starting, have any affect on things?

Maybe one rule hi-jacks the other from triggering sometimes ?

[toggledbits]

@cw-kid said in Having issues with a shell command:

I'm not sure, I will look out for when it happens again.

The goal I propose is to write a script that runs ps4-waker itself, and retries if it fails to connect. MSR would then run that script instead of running ps4-waker directly. If, for example, the ps4-waker script simply returns no data (empty) result, then something like this would work:

#!/bin/sh

while true; do
    # Run command and capture its output and exit status
    output=`ps4-waker $*`
    status=$?
    # If output was produced, stop looping.
    if [ -n "$output" ]; then
        break;
    fi
    sleep 1 # slow retries down a little
done
# Echo back the command output and exit with its exit status.
echo "$output"
exit $status

Save this as ps4-wrapper.sh in the Reactor install directory (or somewhere along the path, like where ps4-waker currently is), and give it execute permissions (chmod 755 ps4-wrapper.sh).

The wrapper script can be run in place of ps4-waker, with the same arguments (e.g. ps4-wrapper.sh status). If a request fails and produces no output, it is simply re-run until output is produced (or until the command times out in Reactor, when it is killed).

[toggledbits]

@cw-kid said in Having issues with a shell command:

Maybe one rule hi-jacks the other from triggering sometimes ?

No, each rule has its own supervision of its entities of interest, etc. You'd be able to quickly confirm this by looking in the logs and seeing that the SET reactions for both rules run.

[cw-kid]

@toggledbits said in Having issues with a shell command:

The goal I propose is to write a script

Great thanks I will try this approach instead then.

But first I will leave things as is and see what happens? when it doesn't turn on the PS4 on first attempt.

It might just return no data in the response as you suggest, or it may as I seem to think, return something else, which I haven't documented here in this thread yet. But I can't remember off the top of my head what it was doing.

[cw-kid]

This isn't related to when the PS4 doesn't turn on.

When the PS4 is OFF / sleep mode, I am seeing this error alert appearing, to do with the parsing of the output to JSON.

I assume this alert occurs if the "ps4-waker check" command hasn't worked and initially pulled in the data ?

Maybe I need two wrapper scripts then, one for turning on the power and one for the check command also.

[cw-kid]

Regarding the power on issue and maybe using a wrapper script.

When I manually run the "ps4-waker" command in terminal this is the output I get back:

 WAKEUP sent to device... 192.168.0.201

I don't see any alert in MSR gui when it fails to turn on the PS4 on its first and currently only attempt to do so.

Looking in the log I can't see anything there either as to why the command didn't turn on the PS4 ?

2021-08-04T13:08:32.530Z <Rule:5:Rule.js:660> Rule#rule-krpft5eh rule set variable ps4waker = (string) 
2021-08-04T13:08:32.533Z <Engine:5:Engine.js:945> Engine#1 set variable rule rule-krpft5eh ps4waker=, requesting re-eval
2021-08-04T13:08:32.534Z <Rule:5:Rule.js:956> Rule#rule-krpft5eh (Lounge - Harmony PS4 Activity Start - Wake PS4 Shell Command) evaluate() acquiring mutex
2021-08-04T13:08:32.535Z <Engine:5:Engine.js:1145> _process_reaction_queue() wake-up!
2021-08-04T13:08:32.536Z <Rule:5:Rule.js:960> Rule#rule-krpft5eh._evaluate() mutex acquired, evaluating
2021-08-04T13:08:32.537Z <Rule:5:Rule.js:964> Rule#rule-krpft5eh update rate is 6/min limit 60/min
2021-08-04T13:08:32.537Z <Rule:5:Rule.js:887> Rule#rule-krpft5eh evaluateExpressions() with 1 expressions
2021-08-04T13:08:32.538Z <Rule:5:Rule.js:976> Rule#rule-krpft5eh._evaluate() trigger state now true (was true)
2021-08-04T13:08:32.539Z <Rule:5:Rule.js:978> Rule#rule-krpft5eh._evaluate() constraints state true
2021-08-04T13:08:32.540Z <Rule:5:Rule.js:987> Rule#rule-krpft5eh rule state now true, changed no
2021-08-04T13:08:32.541Z <Engine:5:Engine.js:1106> _process_reaction_queue() running task 2261 { "tid": 2261, "id": "rule-krpft5eh:S", "rule": "rule-krpft5eh", "__reaction": [RuleReaction#rule-krpft5eh:S], "next_step": 3, "status": 1, "ts": 1628082499978, "parent": --null--, "__resolve": --function--, "__reject": --function--, "__promise": [object Promise], "attempts": 2 }
2021-08-04T13:08:32.542Z <Engine:NOTICE> Resuming reaction Lounge - Harmony PS4 Activity Start - Wake PS4 Shell Command<SET> (rule-krpft5eh:S) from step 3
2021-08-04T13:08:32.542Z <Engine:INFO> Lounge - Harmony PS4 Activity Start - Wake PS4 Shell Command<SET> all actions completed.
2021-08-04T13:08:32.543Z <Engine:5:Engine.js:1110> _process_reaction_queue() task returned, new status -1; task 2261
2021-08-04T13:08:32.545Z <Engine:5:Engine.js:1145> _process_reaction_queue ending with 0 in queue; none delayed/ready; waiting
2021-08-04T13:08:32.832Z <Rule:5:Rule.js:748> Rule#rule-knn2os0h dependency notification entity-changed Entity#vera>device_184 from Entity#vera>device_184
2021-08-04T13:08:32.834Z <Rule:5:Rule.js:754> Rule#rule-knn2os0h requesting eval; entity-changed Entity#vera>device_184
2021-08-04T13:08:32.836Z <Rule:5:Rule.js:748> Rule#rule-klkppx0h dependency notification entity-changed Entity#vera>device_184 from Entity#vera>device_184
2021-08-04T13:08:32.837Z <Rule:5:Rule.js:754> Rule#rule-klkppx0h requesting eval; entity-changed Entity#vera>device_184
2021-08-04T13:08:32.838Z <Rule:5:Rule.js:748> Rule#rule-krpft5eh dependency notification entity-changed Entity#vera>device_184 from Entity#vera>device_184
2021-08-04T13:08:32.839Z <Rule:5:Rule.js:754> Rule#rule-krpft5eh requesting eval; entity-changed Entity#vera>device_184
2021-08-04T13:08:32.839Z <Rule:5:Rule.js:956> Rule#rule-knn2os0h (Lounge - Harmony XBOX Activity Start - Close Window Coverings (Day)) evaluate() acquiring mutex
2021-08-04T13:08:32.840Z <Rule:5:Rule.js:956> Rule#rule-klkppx0h (Lounge - Harmony Powered OFF - Turn OFF LED strips) evaluate() acquiring mutex
2021-08-04T13:08:32.841Z <Rule:5:Rule.js:956> Rule#rule-krpft5eh (Lounge - Harmony PS4 Activity Start - Wake PS4 Shell Command) evaluate() acquiring mutex
2021-08-04T13:08:32.841Z <Rule:5:Rule.js:960> Rule#rule-knn2os0h._evaluate() mutex acquired, evaluating
2021-08-04T13:08:32.842Z <Rule:5:Rule.js:964> Rule#rule-knn2os0h update rate is 6/min limit 60/min
2021-08-04T13:08:32.843Z <Rule:5:Rule.js:887> Rule#rule-knn2os0h evaluateExpressions() with 0 expressions
2021-08-04T13:08:32.844Z <Rule:5:Rule.js:976> Rule#rule-knn2os0h._evaluate() trigger state now false (was false)
2021-08-04T13:08:32.846Z <Rule:5:Rule.js:978> Rule#rule-knn2os0h._evaluate() constraints state false
2021-08-04T13:08:32.847Z <Rule:5:Rule.js:987> Rule#rule-knn2os0h rule state now false, changed no
2021-08-04T13:08:32.847Z <Rule:5:Rule.js:960> Rule#rule-klkppx0h._evaluate() mutex acquired, evaluating
2021-08-04T13:08:32.848Z <Rule:5:Rule.js:964> Rule#rule-klkppx0h update rate is 6/min limit 60/min
2021-08-04T13:08:32.848Z <Rule:5:Rule.js:887> Rule#rule-klkppx0h evaluateExpressions() with 0 expressions
2021-08-04T13:08:32.849Z <Rule:5:Rule.js:976> Rule#rule-klkppx0h._evaluate() trigger state now true (was true)
2021-08-04T13:08:32.850Z <Rule:5:Rule.js:978> Rule#rule-klkppx0h._evaluate() constraints state false
2021-08-04T13:08:32.851Z <Rule:5:Rule.js:987> Rule#rule-klkppx0h rule state now false, changed no
2021-08-04T13:08:32.851Z <Rule:5:Rule.js:960> Rule#rule-krpft5eh._evaluate() mutex acquired, evaluating
2021-08-04T13:08:32.852Z <Rule:5:Rule.js:964> Rule#rule-krpft5eh update rate is 7/min limit 60/min
2021-08-04T13:08:32.853Z <Rule:5:Rule.js:887> Rule#rule-krpft5eh evaluateExpressions() with 1 expressions
2021-08-04T13:08:32.854Z <Rule:5:Rule.js:976> Rule#rule-krpft5eh._evaluate() trigger state now true (was true)
2021-08-04T13:08:32.854Z <Rule:5:Rule.js:978> Rule#rule-krpft5eh._evaluate() constraints state true
2021-08-04T13:08:32.856Z <Rule:5:Rule.js:987> Rule#rule-krpft5eh rule state now true, changed no
2021-08-04T13:08:33.082Z <Rule:5:Rule.js:748> Rule#rule-knn2os0h dependency notification entity-changed Entity#vera>device_184 from Entity#vera>device_184
2021-08-04T13:08:33.083Z <Rule:5:Rule.js:754> Rule#rule-knn2os0h requesting eval; entity-changed Entity#vera>device_184
2021-08-04T13:08:33.084Z <Rule:5:Rule.js:748> Rule#rule-klkppx0h dependency notification entity-changed Entity#vera>device_184 from Entity#vera>device_184
2021-08-04T13:08:33.085Z <Rule:5:Rule.js:754> Rule#rule-klkppx0h requesting eval; entity-changed Entity#vera>device_184
2021-08-04T13:08:33.086Z <Rule:5:Rule.js:748> Rule#rule-krpft5eh dependency notification entity-changed Entity#vera>device_184 from Entity#vera>device_184
2021-08-04T13:08:33.087Z <Rule:5:Rule.js:754> Rule#rule-krpft5eh requesting eval; entity-changed Entity#vera>device_184
2021-08-04T13:08:33.088Z <Rule:5:Rule.js:956> Rule#rule-knn2os0h (Lounge - Harmony XBOX Activity Start - Close Window Coverings (Day)) evaluate() acquiring mutex
2021-08-04T13:08:33.089Z <Rule:5:Rule.js:956> Rule#rule-klkppx0h (Lounge - Harmony Powered OFF - Turn OFF LED strips) evaluate() acquiring mutex
2021-08-04T13:08:33.090Z <Rule:5:Rule.js:956> Rule#rule-krpft5eh (Lounge - Harmony PS4 Activity Start - Wake PS4 Shell Command) evaluate() acquiring mutex
2021-08-04T13:08:33.090Z <Rule:5:Rule.js:960> Rule#rule-knn2os0h._evaluate() mutex acquired, evaluating
2021-08-04T13:08:33.091Z <Rule:5:Rule.js:964> Rule#rule-knn2os0h update rate is 7/min limit 60/min
2021-08-04T13:08:33.091Z <Rule:5:Rule.js:887> Rule#rule-knn2os0h evaluateExpressions() with 0 expressions
2021-08-04T13:08:33.092Z <Rule:5:Rule.js:976> Rule#rule-knn2os0h._evaluate() trigger state now false (was false)
2021-08-04T13:08:33.093Z <Rule:5:Rule.js:978> Rule#rule-knn2os0h._evaluate() constraints state false
2021-08-04T13:08:33.094Z <Rule:5:Rule.js:987> Rule#rule-knn2os0h rule state now false, changed no
2021-08-04T13:08:33.095Z <Rule:5:Rule.js:960> Rule#rule-klkppx0h._evaluate() mutex acquired, evaluating
2021-08-04T13:08:33.095Z <Rule:5:Rule.js:964> Rule#rule-klkppx0h update rate is 7/min limit 60/min
2021-08-04T13:08:33.096Z <Rule:5:Rule.js:887> Rule#rule-klkppx0h evaluateExpressions() with 0 expressions
2021-08-04T13:08:33.097Z <Rule:5:Rule.js:1595> cond cond58zlosr evaluation state true->false
2021-08-04T13:08:33.098Z <Rule:5:Rule.js:1595> cond trig evaluation state true->false
2021-08-04T13:08:33.098Z <Rule:5:Rule.js:976> Rule#rule-klkppx0h._evaluate() trigger state now false (was true)
2021-08-04T13:08:33.099Z <Rule:5:Rule.js:978> Rule#rule-klkppx0h._evaluate() constraints state false
2021-08-04T13:08:33.100Z <Rule:5:Rule.js:984> Rule#rule-klkppx0h trigger conditions not met
2021-08-04T13:08:33.100Z <Rule:5:Rule.js:987> Rule#rule-klkppx0h rule state now false, changed no
2021-08-04T13:08:33.102Z <Rule:5:Rule.js:960> Rule#rule-krpft5eh._evaluate() mutex acquired, evaluating
2021-08-04T13:08:33.103Z <Rule:5:Rule.js:964> Rule#rule-krpft5eh update rate is 8/min limit 60/min
2021-08-04T13:08:33.103Z <Rule:5:Rule.js:887> Rule#rule-krpft5eh evaluateExpressions() with 1 expressions
2021-08-04T13:08:33.104Z <Rule:5:Rule.js:976> Rule#rule-krpft5eh._evaluate() trigger state now true (was true)
2021-08-04T13:08:33.105Z <Rule:5:Rule.js:978> Rule#rule-krpft5eh._evaluate() constraints state true
2021-08-04T13:08:33.105Z <Rule:5:Rule.js:987> Rule#rule-krpft5eh rule state now true, changed no

I will try and implement the script now.