Trigger followed by trigger misbehaving

#1

download
download.png1178×1303 262 KB

Condition group #20 is the problem here. As you can see from the log below, at 11:59:24 Multisensor Deck motion becomes active, which satisfies the first step of the condition group.

15 seconds later (the followed by time) at 11:59:39 however, the entire group mysteriously becomes true, even though the 2nd trigger (condition 21) never becomes true. I don’t see why the time event is causing the whole condition group to evaluate true.

I thought perhaps the problem was that I wasn’t subscribing to all the devices in the piston somehow, so I forced them all with Always Subscribe, but its still happening. This sure looks like a bug to me. I can’t follow the logic of it if it isn’t.

5/12/2018, 11:59:39 PM +405ms
+0ms ╔Received event [Home].time = 1526194780247 with a delay of -843ms
+246ms ║RunTime Analysis CS > 18ms > PS > 86ms > PE > 142ms > CE
+249ms ║Runtime (50262 bytes) successfully initialized in 86ms (v0.3.104.20180323) (248ms)
+250ms ║╔Execution stage started
+258ms ║║Cancelling condition #19’s schedules…
+263ms ║║Cancelling statement #20’s schedules…
+264ms ║║Condition group #20 made progress up the ladder, currently at step 2 of 2
+264ms ║║Cancelling statement #20’s schedules…
+265ms ║║Cancelling condition #20’s schedules…
+266ms ║║Condition group #20 evaluated true (state changed) (7ms)
+267ms ║║Cancelling condition #1’s schedules…
+268ms ║║Condition group #1 evaluated true (state changed) (11ms)
+285ms ║║Comparison (time) 86379676 is_between (time) 1526182260000 … (time) 1526129040000 = true (9ms)
+286ms ║║Time restriction check passed
+288ms ║║Condition #29 evaluated true (18ms)
+289ms ║║Condition group #2 evaluated true (state did not change) (18ms)
+290ms ║║Cancelling statement #2’s schedules…
+295ms ║║Skipped execution of physical command [East Rear].on([]) because it would make no change to the device. (2ms)
+296ms ║║Executed [East Rear].on (4ms)
+301ms ║║Skipped execution of physical command [Yard Lights].on([]) because it would make no change to the device. (3ms)
+301ms ║║Executed [Yard Lights].on (4ms)
+329ms ║║Executed physical command [Yard Lights].setLevel([100]) (24ms)
+330ms ║║Executed [Yard Lights].setLevel (26ms)
+333ms ║║Cancelling statement #15’s schedules…
+336ms ║║Executed virtual command setState (1ms)
+339ms ║╚Execution stage complete. (90ms)
+340ms ╚Event processed successfully (340ms)

5/12/2018, 11:59:24 PM +983ms
+1ms ╔Received event [Multisensor Deck].motion = active with a delay of 220ms
+236ms ║RunTime Analysis CS > 34ms > PS > 82ms > PE > 119ms > CE
+239ms ║Runtime (50259 bytes) successfully initialized in 82ms (v0.3.104.20180323) (237ms)
+240ms ║╔Execution stage started
+252ms ║║Condition #9 evaluated false (6ms)
+253ms ║║Cancelling statement #19’s schedules…
+254ms ║║Condition group #19 evaluated false (state did not change) (9ms)
+259ms ║║Comparison (enum) active changes_to (string) active = true (1ms)
+260ms ║║Cancelling condition #22’s schedules…
+261ms ║║Condition #22 evaluated true (5ms)
+262ms ║║Cancelling statement #20’s schedules…
+262ms ║║Condition group #20 made progress up the ladder, currently at step 1 of 2
+266ms ║║Condition group #1 evaluated false (state did not change) (21ms)
+275ms ║║Comparison (enum) active stays (string) inactive = false (2ms)
+277ms ║║Cancelling any timed trigger schedules for condition 12
+278ms ║║Cancelling statement #12’s schedules…
+279ms ║║Condition #12 evaluated false (11ms)
+279ms ║║Condition group #7 evaluated false (state did not change) (12ms)
+288ms ║║Condition #27 evaluated false (7ms)
+295ms ║║Condition #34 evaluated false (5ms)
+295ms ║║Cancelling statement #33’s schedules…
+296ms ║║Condition group #33 evaluated false (state did not change) (7ms)
+297ms ║║Condition group #23 evaluated false (state did not change) (17ms)
+300ms ║╚Execution stage complete. (60ms)
+301ms ║Setting up scheduled job for Sat, May 12 2018 @ 11:59:40 PM PDT (in 14.964s)
+310ms ╚Event processed successfully (309ms)

And just for the sake of completeness, here’s the device events showing that the contact sensor in question never opened:

46%20AM
Screen Shot 2018-05-13 at 12.09.46 AM.png1254×253 32.2 KB

Trigger "followed by" trigger misbehaving
#2

Hmm… ok do I need to set the matching method to strict? OK strict doesn’t help.

This has to be a bug. I have another piston like this that’s evaluating FALSE when both events in the followed by happen within the time frame. The thread below details many similar problems.

How do you report bugs anyway? Is there an issue tracker somewhere?

#3

What is the actual problem you are seeing? is it triggering when you don’t think it shouldn’t or not triggering when you think it should? I’m a little unclear on what your issue is. It looks correct to me. The group will be false if both conditions are not true. It will only be true if all conditions are met.

#4

Both actually. But in 2 different pistons.

I have another piston that doesn’t trigger when both conditions are true.

In this piston, the issue is that the 2nd condition never becomes true but the condition group becomes true anyway.

This is the crux of the problem right here:

+266ms ║║Condition group #20 evaluated true (state changed) (7ms)

Condition group #20 evaluates to true even though condition #21 never becomes true.

#5

Where do you see condition 21 becoming true? There is no condition 21.

#6

Condition #21 NEVER becomes true. Condition group #20 shouldn’t become true if condition #21 doesn’t become true but it (group #20) does. That’s the bug. It looks like expiration of the “followed by” time is causing the condition group to erroneously evaluate to true? That’s a guess but that seems to be how its behaving.

Condition #21
Contact Sensor 23’s contact changes to open

@Ryan780 do you have admin privs to delete the duplicate thread in bug reports, I don’t.

#7

Can you list for me what condition 21 is? When I look through your log, I don’t see condition 21 at all.

Also, as a side note, what exactly are you trying to accomplish with this piston on the larger scale? There might be an easier way of doing this rather than the followed by. Followed by requires a very precise sequence. If there are any other events for any other subscribed device, the piston won’t fire correctly.

#8

Condition #21 is in the piston snapshot at the top of the message, it’s the 2nd part of a followed by conditional group. I don’t see it in the logs either, which is odd. I don’t see how condition group (#20) can become true without it, which is why I think this is a bug.

I have a yard area with 2 entrances to it, and a beam sensor on each entrance. There are also several motions sensors, one basically on either “side” of each beam.

What I’m trying to do is infer direction of travel through the beam by the motion events on either side of it, and take action accordingly. So if motionA becomes active followed by beam trip I can infer the direction of travel is from “zone” A to B. But if motion B becomes active followed by beam trip, I can infer that direction of travel is from zone B to A.

Why don’t I just use the motion sensors to trigger the lights, you might ask? Again this is an outside area so while they’re ok for inferring occupancy, they’re too sensitive to actually control the lights due to too many false positives, which is why I’m using the beam sensors.

#9

I still don’t understand. Why are you saying that condition 21 is false when there is no condition 21???

Also, your last statement is going to rarely work because of the timing. The last part is the motion sensor staying inactive for 45 seconds but that has to happen within 2 minutes. So, you really only have a 1:15 for it to go inactive. You do realize that with followed by if the sequence is different it won’t work, correct?

#10

There is a condition #21. Look at the piston at the top of this thread. Condition #21 exists, it is part of the piston but it is not in the logs. That’s the bug.

That last piece was still in flux. The idea behind it is to shut the light off in the room that was just left. I can mess with the timing a bit with that. The idea is that to ensure the “room” is empty before shutting off the lights.

#11

I did… I don’t see 21. What line number? What is the condition?

#12

It is on line 31

Contact sensor 23’s contact changes to open

#13

I thought I could move this topic for you, but turns out I can’t (or can’t figure out how). There is a specific area for tracking bugs, called Meta - and from in there you can select bug report:

https://community.webcore.co/c/Meta/Bugs
#14

It’s evaluated as true when the whole group, group 20 is evaluated as True. I don’t think there’s a bug here. How can the group be true if the individual components aren’t also true?

#15

That’s exactly what @wgmcg is trying to sort out. Let’s stick to condition numbers rather than line numbers to avoid confusion. The way his piston is written is this:

Condition 20:
IF condition 22
Followed within 15 seconds by condition 21

What the logs show (assuming we have the entire log and not a snippet of them?):

Condition 22 is met, piston sets a wake-up timer for 15 seconds in the future
15 seconds later the piston wakes up and condition 20 is evaluated as true

At no point in the logs does condition 21 (the “followed within 15 seconds” bit) become true. So condition 20 should have evaluated false and the ELSE section of the code should run.

So there’s one of two possibilities:

  1. There’s a bug in the followed-by code
  2. There’s a misunderstanding of the trigger-followed-by-a-trigger execution of webCoRE

Seeing if any of the @webCoRE_Minions can lend a hand here.

#16

Regarding whether this is a snippet or not, It’s been about 2 weeks so I actually don’t remember. I spent about 2.5 hours debugging this and I’m fairly certain this is a bug.

I can recreate if we need some fresh logs. My point is that I don’t ever see conditon #21 become true so condition group #20 should never become true but it does. I noticed this because my yard lights kept coming on without the beam being tripped. I verified in the ST console that the beam never tripped. Absent a beam event the lights shouldn’t come one.

I think its the same bug as this one fwiw:

#17

It’s also possible that it is logging the group, 20, as true knowing that everything within the group must also be true. If the piston is functioning correctly but just not being logged the way you like it, that’s not a bug. That’s a feature request. If the group is evaluating true, then what’s the issue here?

#18

Sticking to the piston and the logs in this thread (not the linked one), because group 20 should not evaluate true. The 2nd condition isn’t shown as being met (there should be a trigger for the piston to execute before the ‘.time’ executes it).

#19

That’s only true if the second thing didn’t actually happen, which isn’t clear. If this is a logging issue, like I said, the group being true means the components were true. If you don’t like that, that’s a feature request.
Now, if the second trigger didn’t actually happen, then this would be a bug. But the logs say that it is evaluated as true.
So, did the trigger happen? If it did, then your “bug” is the way its being logged?

#20

There’s no event in the logs showing the 2nd condition was met. There should have been a [contact sensor].contact trigger somewhere between the motion sensor and the .time trigger.

The fact the OP took the time to post a thread, said his lights regularly turn on when they shouldn’t, and posted a log that doesn’t show the 2nd condition occurring is about as close to proving a negative as one can get.