Why has one part of this piston stopped firing?

freddyq · 2020-12-09 17:19:51 UTC

1) Give a description of the problem
This piston is to turn on a single IKEA Tradfri GU10 I have in my hallway after sunset, if I’m home. Then, once another piston changes my location mode to Night, this piston is meant to trigger and turn off that light. The part of the piston which turns on this light fires without fail every day, no issues. However, the second part of the piston which is meant to turn off the light initially fired sometimes and now isn’t firing at all. I know the location mode is changing to ‘Night’ everyday successfully because I have a push notification configured to confirm it. So I don’t understand why this piston isn’t picking up that change and turning off the light.

2) What is the expected behaviour?
Second part of piston should trigger when my location mode changes to ‘Night’ resulting in the light being switched off.

3) What is happening/not happening?
Despite the location mode successfully changing to ‘Night’, the hallway light isn’t being turned off. I checked the logs of this piston and the only time it registers events is at sunset when the light turns on. It doesn’t seem to be registering the location mode change to ‘Night’ at all.

**4) Post a Green Snapshot of the piston![image|45x37]

5) Attach logs after turning logging level to Full

I’m pasting two days worth of logs…

12/9/2020, 4:13:59 PM +72ms
+1ms ╔Received event [Home].time = 1607530440000 with a delay of -928ms
+128ms ║RunTime Analysis CS &gt; 23ms &gt; PS &gt; 53ms &gt; PE &gt; 52ms &gt; CE
+131ms ║Runtime (40155 bytes) successfully initialized in 53ms (v0.3.110.20191009) (129ms)
+132ms ║╔Execution stage started
+164ms ║║Comparison (time) 58439209 happens_daily_at (time) 1607529180000 = true (0ms)
+165ms ║║Time restriction check passed
+167ms ║║Condition #6 evaluated true (29ms)
+168ms ║║Cancelling statement #6's schedules...
+172ms ║║Requesting time schedule wake up at Thu, Dec 10 2020 @ 4:13:00 PM GMT
+182ms ║║Comparison (long) 60929019 is_greater_than (integer) 600000 = true (2ms)
+183ms ║║Condition #22 evaluated true (9ms)
+187ms ║║Comparison (string) :d3dc195c6ea99304d142f80151ca8da2: is (string) :d3dc195c6ea99304d142f80151ca8da2: = true (1ms)
+189ms ║║Condition #26 evaluated true (4ms)
+190ms ║║Condition group #1 evaluated true (state did not change) (53ms)
+192ms ║║Cancelling statement #9's schedules...
+205ms ║║Executed physical command [Hallway Spotlight].on() (10ms)
+206ms ║║Executed [Hallway Spotlight].on (12ms)
+220ms ║║Executed physical command [Hallway Spotlight].setLevel([20]) (11ms)
+221ms ║║Executed [Hallway Spotlight].setLevel (11ms)
+232ms ║║Executed virtual command [Hallway Spotlight].sendPushNotification (8ms)
+238ms ║║Comparison (string) :d3dc195c6ea99304d142f80151ca8da2: changes_to (string) :c465aace1b0b65e0843af2bee0c2ad3e: = false (0ms)
+239ms ║║Condition #21 evaluated false (4ms)
+240ms ║║Condition group #17 evaluated false (state did not change) (5ms)
+242ms ║╚Execution stage complete. (111ms)
+243ms ║Setting up scheduled job for Thu, Dec 10 2020 @ 4:13:00 PM GMT (in 86340.685s)
+251ms ╚Event processed successfully (251ms)
12/8/2020, 4:13:59 PM +93ms
+0ms ╔Received event [Home].time = 1607444040000 with a delay of -908ms
+131ms ║RunTime Analysis CS &gt; 23ms &gt; PS &gt; 53ms &gt; PE &gt; 56ms &gt; CE
+134ms ║Runtime (40155 bytes) successfully initialized in 53ms (v0.3.110.20191009) (133ms)
+135ms ║╔Execution stage started
+171ms ║║Comparison (time) 58439233 happens_daily_at (time) 1607442840000 = true (0ms)
+173ms ║║Time restriction check passed
+174ms ║║Condition #6 evaluated true (34ms)
+175ms ║║Cancelling statement #6's schedules...
+180ms ║║Requesting time schedule wake up at Wed, Dec 9 2020 @ 4:14:00 PM GMT
+189ms ║║Comparison (long) 60940820 is_greater_than (integer) 600000 = true (1ms)
+191ms ║║Condition #22 evaluated true (8ms)
+194ms ║║Comparison (string) :d3dc195c6ea99304d142f80151ca8da2: is (string) :d3dc195c6ea99304d142f80151ca8da2: = true (1ms)
+196ms ║║Condition #26 evaluated true (4ms)
+197ms ║║Condition group #1 evaluated true (state did not change) (58ms)
+199ms ║║Cancelling statement #9's schedules...
+213ms ║║Executed physical command [Hallway Spotlight].on() (11ms)
+214ms ║║Executed [Hallway Spotlight].on (13ms)
+228ms ║║Executed physical command [Hallway Spotlight].setLevel([20]) (11ms)
+229ms ║║Executed [Hallway Spotlight].setLevel (13ms)
+243ms ║║Executed virtual command [Hallway Spotlight].sendPushNotification (10ms)
+248ms ║║Comparison (string) :d3dc195c6ea99304d142f80151ca8da2: changes_to (string) :c465aace1b0b65e0843af2bee0c2ad3e: = false (0ms)
+250ms ║║Condition #21 evaluated false (3ms)
+251ms ║║Condition group #17 evaluated false (state did not change) (5ms)
+253ms ║╚Execution stage complete. (118ms)
+254ms ║Setting up scheduled job for Wed, Dec 9 2020 @ 4:14:00 PM GMT (in 86400.653s)
+262ms ╚Event processed successfully (262ms)

ian_boje · 2020-12-09 19:04:20 UTC

Did you use that async if because you were having trouble? Does the standard ‘if’ statement work?

I’d consider adding a timer statement to verify that the “Location Mode” is actually flipping as you expect. Something like:

Do you have other pistons that use the “Location Mode”?

freddyq · 2020-12-09 20:07:03 UTC

Yes if I remember correctly that async wasn’t in my original Piston but I added it after I had issues. It obviously worked for a while but now isn’t. I’ll change it back to a normal if and see what happens.

I’ll also add that timer with logging.

Yes I have another Piston to turn my drive lights on at sunset and off when location mode changes to Night and that works without fail every night. The code to turn off those lights is exactly the same as the code to turn off the hallway light so it’s really strange why one works and the other doesn’t.

ian_boje · 2020-12-09 20:26:29 UTC

Last thought: Is there some other piston or rule that is turning the light back on? If you check the portal, you should get a list of things that use your bulb, similar to this:

One time, I had an issue where some automation was still running on a device, even though that automation didn’t exist anymore (a button push would power on a light). The automation previously existed and was assigned to that button, but I moved stuff around and changed it. The only work around I could find was to delete + re-add the light bulb. I never did find the cause of that one. EDIT: Found the post about that one Ghost controlled lights

jkp · 2020-12-09 20:47:23 UTC

One problem is you do not have “and store in messages” enabled for the send push notification

But I can’t explain the light part. Have you checked to make sure mode is changing to night?

freddyq · 2020-12-09 23:17:12 UTC

Update: I don’t really understand why but changing the async if to a normal if seems to have fixed it. The light was turned off when location mode changed to night. I didn’t get the push notification though but as @jkp pointed out, I didn’t have “store in messages” enabled so I’ve done that now and will test it tomorrow.

WCmore · 2020-12-10 03:25:14 UTC

This could be the issue. Ideally, we only want a single piston executing at any moment.

When multiple pistons try to run simultaneously,
(IE: when Location mode changes)
then ST’s reliability drops significantly.

freddyq · 2020-12-10 12:56:02 UTC

Ahh makes sense. Ok I’ll create a combined Piston for all actions I want triggered after location mode changes to night.