"Every" statement not executing commands (HE only)

RosTeHea · 2021-05-08 14:08:35 UTC

1) Give a description of the problem
I have a few pistons with timers such as “every day at 12:00AM” or “every hour” and none of them are executing any tasks in the “do” section. The log shows the pistons set up schedules, but nothing actually happens. It executes at the correct time, but doesn’t actually do anything.

2) What is the expected behaviour?
In this particular one, reset the variable “vacuumedToday” at 12:00AM daily

3) What is happening/not happening?
It doesn’t reset the variable. In my other pistons with an “every” command, I have the same problem.

**4) Post a Green Snapshot of the piston

5) Attach logs after turning logging level to Full
(Note: for the log below, I changed the time to happen at 8:05 so I could get an event.)
5/8/2021, 8:05:00 AM +76ms
+3ms ╔Received event [Hubitat].time = 1620482700000 with a delay of 76ms, canQueue: true, calledMyself: false
+83ms ║RunTime initialize > 81 LockT > 1ms > rtDT > 65ms > pistonT > 64ms (first state access 15 5 76)
+91ms ║Runtime (13819 bytes) successfully initialized in 65ms (v0.3.113.20210211_HE)
+96ms ║╔Execution stage started
+123ms ║╚Execution stage complete. (29ms)
+148ms ║Setting up scheduled job for Sun, May 9 2021 @ 8:05:00 AM MDT (in 86399829ms)
+150ms ╚Event processed successfully (148ms)
5/8/2021, 8:04:43 AM +243ms
+222ms ║Subscribing to Melissa WebCoRE Presence.presence…
+230ms ║Subscribing to Michael WebCoRE Presence.presence…
+236ms ║Subscribing to Trash Bin Emptied Button.pushed.1…
+368ms ║Setting up scheduled job for Sat, May 8 2021 @ 8:05:00 AM MDT (in 16450ms)
+370ms ╔Starting piston… (v0.3.113.20210211_HE)
+372ms ╚Piston successfully started (362ms)

Pantheon · 2021-05-08 14:20:48 UTC

Sometimes, lots of things happen at the midnight hour. I would suggest you make your “every” command at 12:05 or 12:10 and see if that changes anything.

E_Sch · 2021-05-08 14:59:55 UTC

Also note every statements are like ‘mini pistons’, ie the entire piston does not execute start to finish.

If you expect the entire piston to run, you may want to use if statements instead.

RosTeHea · 2021-05-08 15:16:03 UTC

I set it to happen at 8:05AM for this log, and so I could watch it, and it ran that statement, but didn’t execute on any of the actions.

RosTeHea · 2021-05-08 15:16:55 UTC

I don’t want the entire piston to execute at this time - just this one little section. The rest of the piston works correctly (the “if presence sensor changes to away…” etc.). For some reason, it’s just the “every” statements that don’t seem to execute their specific actions.

RosTeHea · 2021-05-08 22:29:30 UTC

Update: I created a new, completely separate piston and it’s still not working. It executes the piston at the set time (according to the logs) but it doesn’t execute the actual commands (in this case, turning off the light). Any ideas? If it’s relevant, I’m running WebCoRE on a Hubitat Elevation hub.

Pantheon · 2021-05-09 01:11:20 UTC

Can you give us the log with trace turned on?

RosTeHea · 2021-05-09 02:57:17 UTC

This was for the above-posted piston - I changed the “every” to be 8:56PM my time to watch it trigger:

5/8/2021, 8:56:00 PM +75ms
+4ms ╔Received event [Hubitat].time = 1620528960000 with a delay of 75ms, canQueue: true, calledMyself: false
+20ms ║RunTime initialize &gt; 20 LockT &gt; 1ms &gt; rtDT &gt; 1ms &gt; pistonT &gt; 0ms (first state access 18 5 15)
+22ms ║Runtime (5320 bytes) successfully initialized in 1ms (v0.3.113.20210211_HE)
+25ms ║╔Execution stage started
+44ms ║╚Execution stage complete. (19ms)
+74ms ║Setting up scheduled job for Sun, May 9 2021 @ 8:56:00 PM MDT (in 86399910ms),with 1 more job pending
+76ms ╚Event processed successfully (74ms)
5/8/2021, 8:55:12 PM +704ms
+3ms ╔Received event [Hubitat].test = 1620528912704 with a delay of 0ms, canQueue: true, calledMyself: false
+25ms ║RunTime initialize &gt; 24 LockT &gt; 1ms &gt; rtDT &gt; 15ms &gt; pistonT &gt; 14ms (first state access 8 4 20)
+27ms ║Runtime (5393 bytes) successfully initialized in 15ms (v0.3.113.20210211_HE)
+28ms ║╔Execution stage started
+40ms ║╚Execution stage complete. (11ms)
+109ms ║Setting up scheduled job for Sat, May 8 2021 @ 8:56:00 PM MDT (in 47284ms),with 1 more job pending
+111ms ╚Event processed successfully (109ms)
5/8/2021, 8:55:04 PM +470ms
+9ms ╔Subscribing to devices...
+90ms ║Device missing from piston. Loading all from parent (79ms)
+94ms ║Piston controls Office Shade...
+105ms ╚Finished subscribing (98ms)
+144ms ║Setting up scheduled job for Sat, May 8 2021 @ 8:56:00 PM MDT (in 55440ms)
+146ms ╔Starting piston... (v0.3.113.20210211_HE)
+147ms ╚Piston successfully started (142ms)

eibyer · 2021-05-09 04:56:49 UTC

Did the pistons with the every statements used to work? I had to restore a database backup of my hub yesterday due to some weirdness in my pistons that were triggering but not executing tasks (not every). I’m not sure if the 2.6 or 2.7 platform hosed it for me but I went back to a known good 2.5 database backup.

RosTeHea · 2021-05-09 05:45:09 UTC

Interesting. My daily timers to turn exterior lights off and on still work (“every day at $sunset do…”)…but those are the only ones. I don’t think other timers have worked for me, at least since I rebuilt everything in Hubitat (about 2 weeks). I’ll restore to some earlier backups and see if that changes anything. I also just saw that there’s a Hubitat update; not sure if that could have any effect but I’ll give it a go as well.

Gabbbers · 2021-05-10 00:24:24 UTC

I’m seeing the same behavior on my install. I just set up a new HE hub and it appears to only happen when I create an every on my Hubitat instance. If I create a timer on ST and use a backup code to import it into HE, it works correctly.

E_Sch · 2021-05-10 00:39:54 UTC

Try setting the setVariable to be using location as the device rather than a real device

ie

with location
setvariable
end

with device
turnoff
end

RosTeHea · 2021-05-10 01:02:04 UTC

That is very helpful, thank you. Biggest downside…I literally JUST deleted my SmartThings install and wiped my hub. That would have been a good workaround for the time being. But that’s very helpful troubleshooting, because the one “every” statement I use was, indeed, originally written on a SmartThings WebCore install and imported into my Hubitat one…

RosTeHea · 2021-05-10 01:03:07 UTC

Still no dice.

RosTeHea · 2021-05-10 01:09:50 UTC

If this is a bug in WebCore for Hubitat, who do I contact? Do I just recategorize this into the “bug reports” topic?

E_Sch · 2021-05-10 04:46:47 UTC

I have pushed a fix to webcore for HE, please update to latest release and test again.

Gabbbers · 2021-05-10 05:27:08 UTC

Thank you @E_Sch! It’s working correctly for me now after the update.

RosTeHea · 2021-05-10 14:41:14 UTC

Aha! That did it. (Version v1.0.33). Thank you!

Alexjcgdf · 2021-10-18 12:36:47 UTC

Taking in advantage of this topic and also considering that is an “every” and also on HE environment. I think that after some updates on HE platform the pistons that starts with an “Every” doesnt executes by default after a HUB reboot. you have to "test"it to force it to start working and counting. Is that the expected behavior?

E_Sch · 2021-10-18 19:15:31 UTC

It should (or it does for me).

Few suggestions:
a) make sure you webcore is up to date. (HPM repair on webcore if you use HPM)
b) make sure you hub firmware is up to date
c) if you have from above rebooted, reboot you hub politely. (HE console -> Settings -> reboot)