2.3.9.193 Issue with Rule Machine nested IFs

I updated from 2.3.9.184 to 2.3.9.193 this morning (Friday, October 11, 2024). My washing is ready app started "going crazy" (it said my wash has been sitting in the washer for 1 hour 1 hour 1 hour 1 hour 1 hour 1 hour 1 hour ... which my wife and daughter at first thought was hilarious but quickly demanded that I fix).

I tracked it down to the following code:

The skipping functionality now appears to treat the first ENDIF as if it the end of the outer nested IF statement when it did not before. Here's the relevant log snipit:

I'm going to change the nested IF to an AND logic and make two IF statements, and I'm pretty sure this will fix it. But I wanted to let the developers know of the issue.

Edits: I second-guessed myself, and deleted the topic, but I do thing there's a change in Hubitat that is causing my issue. It may be the number level of nests. I'm about to flatten the logic and will report back.

3 Likes

@bravenel possibly related to the recent changes with RM nested Ifs?

1 Like

I got rid of the nested IFs and it seems to be working now.

I was working with Hubitat people on a problem with nesting IF-THENs that I noticed in the beta program and I thought it was fixed. At least, it seems to be in my current rules... But, @bravenel maybe there's still some issues going on?

Yes, I ran into another nested IF problem. I'm reverting to the older version for the time being. Let me know if I can provide anything to help with the debug.

image

Thanks. I will look into this. The handling of nested ifs was changed, and no doubt there is still some issue with it...

2 Likes

Looking at your rule actions and the logs, I don't see a problem. The first IF-THEN was false, so all within it should be skipped, and it was skipped.

Could you show logs that represent a failure?

1 Like

Hi @bravenel ,

I have a rule for my garage door for a few years now that has been working fine and after the last update, it doesn't anymore. The rule is supposed to let me know that the garage door is opened and close it automatically after 3 notifications. But now It keeps sending messages even when I see that the garage door is closed in my dashboard. This is the aforementioned rule:

Could you please take a look at it?

Thanks!

Turn on all logging in the rule and then get a screenshot of the logs when it is acting up. Thats the only way he can see what is going on exactly. Filter the log down to relevant devices only when you grab the screenshots.

1 Like

Here it goes:

app:23222024-10-12 11:30:11.118 AMinfoAction: END-IF
app:23222024-10-12 11:30:11.116 AMinfoAction: Set Private Boolean(true) True (skipped)
app:23222024-10-12 11:30:11.097 AMinfoAction: Stop Repeating Actions (skipped)
app:23222024-10-12 11:30:11.095 AMinfoAction: Cancel Delayed Actions (skipped)
app:23222024-10-12 11:30:11.092 AMinfoAction: ELSE-IF (Garage Door Tilt Sensor contact closed(T) OR
Motion Sensor Garage motion active(F) [TRUE]) THEN (skipping)
app:23222024-10-12 11:30:11.081 AMinfoAction: END-IF
app:23222024-10-12 11:30:11.027 AMinfoAction: END-REP
app:23222024-10-12 11:30:11.025 AMinfoAction: END-IF
app:23222024-10-12 11:30:11.023 AMinfoAction: Notify Cellphone One Hubitat, Cellphone Two Hubitat: 'Garage door is open!' (skipped)
app:23222024-10-12 11:30:11.020 AMinfoAction: Add 1 to Counter (skipped)
app:23222024-10-12 11:30:11.002 AMinfoAction: ELSE (skipping)
app:23222024-10-12 11:30:10.908 AMinfoAction: Notify Cellphone One Hubitat, Cellphone Two Hubitat: 'Garage door automatically closed!'
app:23222024-10-12 11:30:10.859 AMinfoAction: Close: Garage Door
app:23222024-10-12 11:30:10.795 AMinfoAction: Repetition stopped
app:23222024-10-12 11:30:10.759 AMinfoAction: Stop Repeating Actions
app:23222024-10-12 11:30:10.756 AMinfoAction: IF (Variable Counter(3) >= MaxCounter(3)(T) [TRUE]) THEN
app:23222024-10-12 11:30:10.729 AMinfoAction: Repeating Actions
app:23222024-10-12 11:27:10.700 AMinfoAction: END-REP (waiting for next)
app:23222024-10-12 11:27:10.691 AMinfoAction: END-IF
app:23222024-10-12 11:27:10.660 AMinfoAction: Notify Cellphone One Hubitat, Cellphone Two Hubitat: 'Garage door is open!'
app:23222024-10-12 11:27:10.649 AMinfoAction: Add 1 to Counter
app:23222024-10-12 11:27:10.635 AMinfoAction: ELSE (do actions)
app:23222024-10-12 11:27:10.633 AMinfoAction: Notify Cellphone One Hubitat, Cellphone Two Hubitat: 'Garage door automatically closed!' (skipped)
app:23222024-10-12 11:27:10.630 AMinfoAction: Close: Garage Door (skipped)
app:23222024-10-12 11:27:10.628 AMinfoAction: Stop Repeating Actions (skipped)
app:23222024-10-12 11:27:10.625 AMinfoAction: IF (Variable Counter(2) >= MaxCounter(3)(F) [FALSE]) THEN (skipping)
app:23222024-10-12 11:27:10.601 AMinfoAction: Repeating Actions
app:23222024-10-12 11:24:10.571 AMinfoAction: END-REP (waiting for next)
app:23222024-10-12 11:24:10.562 AMinfoAction: END-IF
app:23222024-10-12 11:24:10.536 AMinfoAction: Notify Cellphone One Hubitat, Cellphone Two Hubitat: 'Garage door is open!'
app:23222024-10-12 11:24:10.525 AMinfoAction: Add 1 to Counter
app:23222024-10-12 11:24:10.512 AMinfoAction: ELSE (do actions)
app:23222024-10-12 11:24:10.509 AMinfoAction: Notify Cellphone One Hubitat, Cellphone Two Hubitat: 'Garage door automatically closed!' (skipped)
app:23222024-10-12 11:24:10.506 AMinfoAction: Close: Garage Door (skipped)
app:23222024-10-12 11:24:10.504 AMinfoAction: Stop Repeating Actions (skipped)
app:23222024-10-12 11:24:10.502 AMinfoAction: IF (Variable Counter(1) >= MaxCounter(3)(F) [FALSE]) THEN (skipping)
app:23222024-10-12 11:24:10.478 AMinfoAction: Repeating Actions
app:23222024-10-12 11:21:10.381 AMinfoAction: END-REP (waiting for next)
app:23222024-10-12 11:21:10.372 AMinfoAction: END-IF
app:23222024-10-12 11:21:10.344 AMinfoAction: Notify Cellphone One Hubitat, Cellphone Two Hubitat: 'Garage door is open!'
app:23222024-10-12 11:21:10.332 AMinfoAction: Add 1 to Counter
app:23222024-10-12 11:21:10.319 AMinfoAction: ELSE (do actions)
app:23222024-10-12 11:21:10.317 AMinfoAction: Notify Cellphone One Hubitat, Cellphone Two Hubitat: 'Garage door automatically closed!' (skipped)
app:23222024-10-12 11:21:10.314 AMinfoAction: Close: Garage Door (skipped)
app:23222024-10-12 11:21:10.312 AMinfoAction: Stop Repeating Actions (skipped)
app:23222024-10-12 11:21:10.310 AMinfoAction: IF (Variable Counter(0) >= MaxCounter(3)(F) [FALSE]) THEN (skipping)
app:23222024-10-12 11:21:10.286 AMinfoAction: Repeating Actions
app:23222024-10-12 11:21:10.088 AMinfoDelay Over: Delay 0:03:00 (cancelable)
app:23222024-10-12 11:19:38.878 AMinfoAction: END-IF (skipped)
app:23222024-10-12 11:19:38.875 AMinfoAction: Set Private Boolean(true) True (skipped)
app:23222024-10-12 11:19:38.857 AMinfoAction: Stop Repeating Actions (skipped)
app:23222024-10-12 11:19:38.855 AMinfoAction: Cancel Delayed Actions (skipped)
app:23222024-10-12 11:19:38.852 AMinfoAction: ELSE-IF (Garage Door Tilt Sensor contact closed(T) OR
Motion Sensor Garage motion active(F) [TRUE]) THEN (skipped)
app:23222024-10-12 11:19:38.841 AMinfoAction: END-IF
app:23222024-10-12 11:19:38.782 AMinfoAction: END-REP
app:23222024-10-12 11:19:38.780 AMinfoAction: END-IF (skipped)
app:23222024-10-12 11:19:38.778 AMinfoAction: Notify Cellphone One Hubitat, Cellphone Two Hubitat: 'Garage door is open!' (skipped)
app:23222024-10-12 11:19:38.775 AMinfoAction: Add 1 to Counter (skipped)
app:23222024-10-12 11:19:38.762 AMinfoAction: ELSE (skipped)
app:23222024-10-12 11:19:38.760 AMinfoAction: Notify Cellphone One Hubitat, Cellphone Two Hubitat: 'Garage door automatically closed!' (skipped)
app:23222024-10-12 11:19:38.757 AMinfoAction: Close: Garage Door (skipped)
app:23222024-10-12 11:19:38.755 AMinfoAction: Stop Repeating Actions (skipped)
app:23222024-10-12 11:19:38.752 AMinfoAction: IF (Variable Counter(0) >= MaxCounter(3)(F) [FALSE]) THEN (skipped)
app:23222024-10-12 11:19:38.743 AMinfoAction: Repeat every 0:03:00 (stoppable) (skipped)
app:23222024-10-12 11:19:38.740 AMinfoAction: Delay 0:03:00 (cancelable) (skipped)
app:23222024-10-12 11:19:38.738 AMinfoAction: Set Counter to 0 (skipped)
app:23222024-10-12 11:19:38.723 AMinfoAction: IF (Private Boolean(true) is true(T) [TRUE]) THEN (skipped)
app:23222024-10-12 11:19:38.687 AMinfoAction: IF (Garage Door Tilt Sensor contact open(F) AND
Motion Sensor Garage motion inactive(T) [FALSE]) THEN (skipping)
app:23222024-10-12 11:19:38.660 AMinfoTriggered: Motion Sensor Garage motion *changed*
app:23222024-10-12 11:19:38.627 AMinfoEvent: Motion Sensor Garage motion inactive
app:23222024-10-12 11:19:31.693 AMinfoAction: END-IF (skipped)
app:23222024-10-12 11:19:31.691 AMinfoAction: Set Private Boolean(true) True (skipped)
app:23222024-10-12 11:19:31.675 AMinfoAction: Stop Repeating Actions (skipped)
app:23222024-10-12 11:19:31.674 AMinfoAction: Cancel Delayed Actions (skipped)
app:23222024-10-12 11:19:31.671 AMinfoAction: ELSE-IF (Garage Door Tilt Sensor contact closed(T) OR
Motion Sensor Garage motion active(T) [TRUE]) THEN (skipped)
app:23222024-10-12 11:19:31.659 AMinfoAction: END-IF
app:23222024-10-12 11:19:31.601 AMinfoAction: END-REP
app:23222024-10-12 11:19:31.599 AMinfoAction: END-IF (skipped)
app:23222024-10-12 11:19:31.597 AMinfoAction: Notify Cellphone One Hubitat, Cellphone Two Hubitat: 'Garage door is open!' (skipped)
app:23222024-10-12 11:19:31.594 AMinfoAction: Add 1 to Counter (skipped)
app:23222024-10-12 11:19:31.581 AMinfoAction: ELSE (skipped)
app:23222024-10-12 11:19:31.579 AMinfoAction: Notify Cellphone One Hubitat, Cellphone Two Hubitat: 'Garage door automatically closed!' (skipped)
app:23222024-10-12 11:19:31.576 AMinfoAction: Close: Garage Door (skipped)
app:23222024-10-12 11:19:31.573 AMinfoAction: Stop Repeating Actions (skipped)
app:23222024-10-12 11:19:31.571 AMinfoAction: IF (Variable Counter(0) >= MaxCounter(3)(F) [FALSE]) THEN (skipped)
app:23222024-10-12 11:19:31.562 AMinfoAction: Repeat every 0:03:00 (stoppable) (skipped)
app:23222024-10-12 11:19:31.559 AMinfoAction: Delay 0:03:00 (cancelable) (skipped)
app:23222024-10-12 11:19:31.490 AMinfoAction: Set Counter to 0 (skipped)
app:23222024-10-12 11:19:31.473 AMinfoAction: IF (Private Boolean(true) is true(T) [TRUE]) THEN (skipped)
app:23222024-10-12 11:19:31.438 AMinfoAction: IF (Garage Door Tilt Sensor contact open(F) AND
Motion Sensor Garage motion inactive(F) [FALSE]) THEN (skipping)
app:23222024-10-12 11:19:31.410 AMinfoTriggered: Garage Door Tilt Sensor contact *changed*
app:23222024-10-12 11:19:31.379 AMinfoEvent: Garage Door Tilt Sensor contact closed
app:23222024-10-12 11:18:51.857 AMinfoAction: END-IF (skipped)
app:23222024-10-12 11:18:51.855 AMinfoAction: Set Private Boolean(true) True (skipped)
app:23222024-10-12 11:18:51.838 AMinfoAction: Stop Repeating Actions (skipped)
app:23222024-10-12 11:18:51.836 AMinfoAction: Cancel Delayed Actions (skipped)
app:23222024-10-12 11:18:51.834 AMinfoAction: ELSE-IF (Garage Door Tilt Sensor contact closed(F) OR
Motion Sensor Garage motion active(T) [TRUE]) THEN (skipped)
app:23222024-10-12 11:18:51.818 AMinfoAction: END-IF
app:23222024-10-12 11:18:51.695 AMinfoAction: END-REP
app:23222024-10-12 11:18:51.692 AMinfoAction: END-IF (skipped)
app:23222024-10-12 11:18:51.689 AMinfoAction: Notify Cellphone One Hubitat, Cellphone Two Hubitat: 'Garage door is open!' (skipped)
app:23222024-10-12 11:18:51.686 AMinfoAction: Add 1 to Counter (skipped)
app:23222024-10-12 11:18:51.670 AMinfoAction: ELSE (skipped)
app:23222024-10-12 11:18:51.667 AMinfoAction: Notify Cellphone One Hubitat, Cellphone Two Hubitat: 'Garage door automatically closed!' (skipped)
app:23222024-10-12 11:18:51.663 AMinfoAction: Close: Garage Door (skipped)
app:23222024-10-12 11:18:51.660 AMinfoAction: Stop Repeating Actions (skipped)
app:23222024-10-12 11:18:51.658 AMinfoAction: IF (Variable Counter(0) >= MaxCounter(3)(F) [FALSE]) THEN (skipped)
app:23222024-10-12 11:18:51.642 AMinfoAction: Repeat every 0:03:00 (stoppable) (skipped)
app:23222024-10-12 11:18:51.637 AMinfoAction: Delay 0:03:00 (cancelable) (skipped)
app:23222024-10-12 11:18:51.634 AMinfoAction: Set Counter to 0 (skipped)
app:23222024-10-12 11:18:51.615 AMinfoAction: IF (Private Boolean(true) is true(T) [TRUE]) THEN (skipped)
app:23222024-10-12 11:18:51.586 AMinfoAction: IF (Garage Door Tilt Sensor contact open(T) AND
Motion Sensor Garage motion inactive(F) [FALSE]) THEN (skipping)
app:23222024-10-12 11:18:51.480 AMinfoTriggered: Motion Sensor Garage motion *changed*
app:23222024-10-12 11:18:51.446 AMinfoEvent: Motion Sensor Garage motion active
app:23222024-10-12 11:18:10.053 AMinfoAction: Delay 0:03:00 (cancelable)
app:23222024-10-12 11:18:10.039 AMinfoAction: Set Counter to 0
app:23222024-10-12 11:18:09.988 AMinfoAction: IF (Private Boolean(true) is true(T) [TRUE]) THEN
app:23222024-10-12 11:18:09.948 AMinfoAction: IF (Garage Door Tilt Sensor contact open(T) AND
Motion Sensor Garage motion inactive(T) [TRUE]) THEN
app:23222024-10-12 11:18:09.903 AMinfoTriggered: Garage Door Tilt Sensor contact *changed*
app:23222024-10-12 11:18:09.766 AMinfoEvent: Garage Door Tilt Sensor contact open

Can you get a screenshot? Staff usually will not look at logs in text format like that, its very hard to read.

2 Likes

Tied up this weekend. Will try to get something in the next couple of days.

1 Like

Here it goes:





Please identify exactly what you believe the failure is in those logs...

Well I can talk about the symptoms. I'm getting 3 notifications on my phone about the garage door being opened (even when it's already closed) and a fourth notification saying that's going to close the garage door. After that no new notifications. This cycle is happening every time I open the garage door. Before the update, everything was working fine and I didn't change anything (I didn't add new devices or made any other change besides the firmware update).

I'd like to help, but you have all of the details. I need you to identify which part of the rule is not right very specifically, down to a specific action that is not what you expect. Your description isn't adequate to know what is going on or what should be going on. There were bugs in prior releases with respect to ELSE and ELSE-IF not being honored. I can't tell what this rule is supposed to do, as it's complicated, and there is no way to know from these logs which part isn't as expected.

2 Likes

The problematic part is the ELSE-IF that's not being executed when the garage door is closed:
image

It should have cancelled any delayed actions and stopped any repeating actions. This is the part where it should happen:


Thanks for taking a look at it.

misinterpreted log - original comment removed

Yeah I can see it. With your more detailed explanation, I was able to go thru the longer log post from above and see the issue.

If the first IF statement is FALSE, it should skip all the actions and go straight to the ELSE-IF. Instead, it looks like its counting a previous END-IF incorrectly (that particular END-IF should be struck out if my counting is correct), and therefore it is skipping the ELSE-IF as it thinks it executed part of the previous IF. If it thinks it's executed the previous IF, naturally it would cause it to skip the ELSE statement. Dang I just noticed that sounds redundant.

3 Likes

Thanks. I will investigate further and report back...

4 Likes