Rule not responding to virtual switch changes mid-rule

[demillerusn]

@bravenel

Within several of my rules, I use virtual switches as logic indicators to control the flow of the rule, and to trigger other rules.

The triggers work fine, however I recently noticed that the main rule is only responding to the setting of the switch when the rule is triggered. It doesn't follow any changes which happen within the rule itself.

Example:
Set VIRTUAL SWITCH OFF
IF (condition) TRUE, then set VIRTUAL SWITCH ON
(later)
IF VIRTUAL SWITCH ON, then do XXX

The second check of the virtual switch, the switch is still showing in the rule as OFF, even though it was set ON previously in the rule. I've verified this through several logs.

I'm fairly certain this was not operating in this manner previously, but I can't identify when it first started happening. I don't believe it is supposed to work this way, I may change to use global logic variables instead, but will have to recreate the routines.

Running firmware 2.3.6.146

I will try to create a simple test example later and post an update with examples, my current app is complex and difficult to follow the error.

[bravenel]

@demillerusn

The triggers work fine, however I recently noticed that the main rule is only responding to the setting of the switch when the rule is triggered. It doesn't follow any changes which happen within the rule itself.

That's because the entire rule runs almost in an instant. You may be looking for Wait for Event or Wait for Condition if you want the rule to effectively pause waiting for some change to happen.

[demillerusn]

Thanks, I see it happens very quickly. However the log and timestamps show that the events follow the order of how the rule is written, and previously the rule was working properly.

Here are the applicable entries (bottom to top):

Log

app:463 2023-10-30 05:40:36.652 PMinfoAction: IF (VSWITCH2, VSWITCH3 (on, off) any is on TRUE) THEN

app:465 2023-10-30 05:40:36.517 PMinfoTriggered: VSWITCH2 switch on

app:465 2023-10-30 05:40:36.514 PMinfoEvent: VSWITCH2 switch on

app:481 2023-10-30 05:40:36.322 PMinfoAction: IF (VSWITCH2(off) is off(T) [TRUE]) THEN

dev:339 2023-10-30 05:40:35.737 PMinfoVSWITCH2 was turned on

dev:582 2023-10-30 05:40:35.692 PMinfoVSWITCH1 was turned on

app:481 2023-10-30 05:40:35.685 PMinfoAction: On: VSWITCH1, VSWITCH2

App commands 2 virtual switches on at time 35.685, switches both report on at time 35.692 and 35.737.

Time 36.322, VSWITCH2 is polled (IF/THEN) still showing OFF
Time 36.514, external app is triggered by VSWITCH2 turning ON

Time 36.652, VSWITCH2 is polled correctly (another IF/THEN) showing ON (EDIT: It's in a child rule triggered by the switch change)

So .585 secs after the virtual switch changes, it is still showing as off.

When I add a wait event and re-run the routine, the switch is already showing ON when the wait event is triggered. The WAIT is immediately following the command to change the switch.

LOG 2

app:481 2023-10-30 08:16:46.764 PMinfoAction: Wait for event: VSWITCH2 (on) turns on

app:465 2023-10-30 08:16:46.747 PMinfoTriggered: VSWITCH2 switch on

app:465 2023-10-30 08:16:46.745 PMinfoEvent: VSWITCH2 switch on

app:477 2023-10-30 08:16:46.724 PMinfoTriggered: VSWITCH1 switch on

dev:339 2023-10-30 08:16:46.701 PMinfoVSWITCH2 was turned on

dev:582 2023-10-30 08:16:46.687 PMinfoVSWITCH1 was turned on

app:481 2023-10-30 08:16:46.680 PMinfoAction: On: VSWITCH1, VSWITCH2

In this case, since the switch is already ON, the wait event doesn't register the change and the rule effectively stops. Of note, the wait event is logged .019 seconds after the switch changes, and it properly registers the switch as ON.

I realize I can add a time-out on the wait event, or just put in a 1 second WAIT.

It appears that an IF / THEN query isn't properly recording the switch position until after it is polled. Somewhere the polling (or external event trigger) updates the condition, and subsequent queries are accurate. WAIT doesn't have this issue and the switch is polled as it should be.

[pseudonym]

@demillerusn

the wait event doesn't register the change and the rule effectively stops

Use Wait for Expression

[demillerusn]

So I tried Wait for Expression.

If I use Wait for Expression - it registers the switch as OFF, it never updates to ON, and therefore doesn't pass the wait/for. However if I use Wait for Event, it properly registers the switch as ON, doesn't register a change, and therefore also doesn't pass the wait-for function.

It appears that an IF/THEN evaluates the switch as an EXPRESSION (current state) which doesn't pick up the change.

I threw in a REFRESH to see if that would trigger the update, no luck. Didn't expect that to do much since it is a virtual switch and not an actual device.

ALSO - I figured out why the later IF/THEN was properly evaluated in the first log, that was a different rule triggered by the switch change in the main rule. I overlooked that when I was going through it.

I'm probably going to change everything to boolean variables instead of virtual switches and see if that works. That's a job for tomorrow (or later today!)...

[demillerusn]

Switched everything over to boolean global variables which is working as it should. Left virtual switches in which call other child-rules, through triggers, which works fine. Basically anything that required a conditional based on a switch position that changes mid-rule, I switched over to a global variable. There were only 2, but I had to update throughout several different rules.

Overall runs much smoother, but still think there is an issue with evaluating expressions based on a virtual switch, as detailed.

[johnwill1]

I think that in order for someone to diagnose whether there is a bug; rather than an explanation/example of a rule that isn't working as expected, you should:

• Post a screenshot of the entire rule that's not working
• Post a screenshot (not copy and paste) of the logs when it fails (events, triggers, actions enabled for logging in the rule)

From that, if anything looks wrong you may also be asked to click the gear icon for the rule and screenshot part of the 'app details and settings' information for the rule.

[pseudonym]

I believe I just captured the same issue with this rule. I'm currently on 2.3.6.144

You can see in the logs that Light Porch turns on at 09:56:00.932 but when it's used in the two conditions at 01.086 and 01.107 it is seen as off. I guess 150 ms is too fast for the condition to update and I'll need to add a little delay.

I added a 200 ms delay and that seems to be enough for the condition to be updated.

[demillerusn]

@pseudonym
It appears similar, but in my case it is a virtual switch that is commanded ON within the same rule. As an event, it is captured immediately (within .019 seconds). However as an expression, it was never captured, even after .585 seconds. The 'condition' was never changed while the event was immediately changed.

To answer @johnwill1, I'll create a simple routine which captures the problem more clearly and post it all here. I'll also try adding the delay you suggest to see if that helps. I'm pretty sure the information I provided was sufficient to recreate the problem, but if not, then Mea culpa!

I've been using rule machine for fairly complex coding, I like that it is intuitively simple to follow. To be fair, I really should be coding my own app for what I'm doing, but I haven't done any serious coding in over 30 years since college, and that was well before object oriented code. While I've attempted it a little, mainly by modifying others, I haven't really had the time to devote to become proficient. Rule Machine works great and Bruce provides outstanding support. He's helped me many times in the past correct issues that are relatively obscure.

If you are interested in the rules where I identified the problem, they are fully documented here: Remote Cable Modem Reset

As I stated above, I've since changed the virtual switches (specifically for MODEM DOWN and INTERNET DOWN) to hub variables and made a few associated minor tweaks. It is flowing as it should and much cleaner.

[johnwill1]

@demillerusn

To answer @johnwill1, I'll create a simple routine which captures the problem more clearly and post it all here. I'll also try adding the delay you suggest to see if that helps. I'm pretty sure the information I provided was sufficient to recreate the problem, but if not, then Mea culpa!

The comment I posted regarding screenshots of the entire rule and also of the logs was just to highlight what tends to be asked for and expected by the staff. I'm fairly sure they'll not try to recreate the problem you're seeing, until they can see (from your rule and logs) that there's a possible bug, rather than an incorrectly constructed rule.

[demillerusn]

@johnwill1

rather than an incorrectly constructed rule.

Completely understand, I work to avoid that at all costs. I'll also note that my initial post was definitely not sufficient to recreate the error.

In this case it appears to be just as Bruce stated at the top, a timing problem.

Despite what the logs and timestamps show, the virtual switch condition is not fully updated by the time the condition is checked.

The final rule and full logs are posted below where I was able to recreate the error.
@pseudonym 's recommendation to add a .2 sec delay did correct it in this case. There was more going on in my previous set of 3 rules, I suspect a longer delay would have been required there.

TEST 1: 3 virtual switches: Virtual Switch Trigger (500ms reset off), Virtual Switch 1, Virtual Switch 2. When Triggered, rule sets Virtual Switch 1 ON, then conditional checks if switch 1 ON, set Virtual Switch 2 ON. With all switches OFF, when triggered, both Switch 1 and 2 come on as expected.

TEST 2: Same setup as above, except this time I used a conditional to turn on Virtual Switch1. Since my original rule was a network test, I used the PING check to turn on the switch. Same results as test 1, both switches turn on as expected.

TEST 3: This adds a 4th virtual switch: Virtual TestDown. This switch simulates a Ping failure and sets up the conditional to set Virtual Switch 1 ON.

It also adds a repeat loop at 10 second intervals to run 3 sets of PING checks. Each check tests if the PING is successful, and if so it exits the repeat loop.
Upon exiting, it checks the final result and if it failed, it sets Virtual Switch 1 ON.

At the end it does the final check to set Virtual Switch 2 ON.

Rule

Test run 1 is with the Virtual TestDown switch OFF to show what a successful run looks like.

Test 1 Logs

Test run 2 turns the TestDown switch ON to simulate a failed network test. This is where the conditional fails.

Test 2 Logs

Adding a .2 Sec delay (shown in the rule above, but not in the rule when test log 2 was executed) after setting Virtual Switch 1 ON fixes the problem.

I'm not planning to change my initial routines back to virtual switches, as they are running smoothly and more efficient with hub variables. I suspect the addition of switches that triggered other rules (3 linked in total) exacerbated the timing problem, and therefore would have required a longer delay to correct.

Appreciate everyone's assistance!