Happens Daily, doesn't

[hatallica]

1) Give a description of the problem
Piston fails to reliably execute a daily schedule. My search on “time happens daily” did not yield a conclusive solution. Not sure if using this condition is best practice.

2) What is the expected behaviour?
At the specified time, set light level and turn off. Aside from executing at a particular time, I hope to leave the lights in a known state for anyone that wishes to use the physical switch to operate.

3) What is happening/not happening?
Piston execution delays ranging from seconds to minutes create a false time comparison, causing no additional action to be taken.

4) Post a Green Snapshot of the piston

5) Attach logs after turning logging level to Full
9/22/2020, 9:07:31 PM +802ms
+3ms ╔Received event [Panorama].time = 1600833900000 with a delay of 151801ms
+2886ms ║RunTime Analysis CS > 2796ms > PS > 33ms > PE > 58ms > CE
+2889ms ║Runtime (39998 bytes) successfully initialized in 33ms (v0.3.110.20191009) (2883ms)
+2890ms ║╔Execution stage started
+2931ms ║╚Execution stage complete. (41ms)
+2996ms ║Setting up scheduled job for Tue, Sep 22 2020 @ 10:05:00 PM MST (in 3445.206s), with 1 more job pending
+3007ms ╚Event processed successfully (3007ms)
9/22/2020, 9:06:22 PM +513ms
+0ms ╔Received event [Panorama].execute = recovery with a delay of 65ms
+51ms ║RunTime Analysis CS > 20ms > PS > 10ms > PE > 21ms > CE
+53ms ║Runtime (39991 bytes) successfully initialized in 10ms (v0.3.110.20191009) (52ms)
+54ms ║╔Execution stage started
+62ms ║║Comparison (time) 75982572 happens_daily_at (time) 75900000 = false (1ms)
+64ms ║║Condition #2 evaluated false (4ms)
+65ms ║║Cancelling statement #2’s schedules…
+69ms ║║Requesting time schedule wake up at Wed, Sep 23 2020 @ 9:05:00 PM MST
+74ms ║║Comparison (time) 75982584 happens_daily_at (time) 79500000 = false (0ms)
+76ms ║║Condition #15 evaluated false (4ms)
+77ms ║║Cancelling statement #15’s schedules…
+81ms ║║Requesting time schedule wake up at Tue, Sep 22 2020 @ 10:05:00 PM MST
+83ms ║║Condition group #16 evaluated false (state did not change) (24ms)
+84ms ║║Condition group #1 evaluated false (state did not change) (26ms)
+87ms ║║Condition group #37 evaluated true (state did not change) (1ms)
+89ms ║╚Execution stage complete. (35ms)
+91ms ║Setting up scheduled job for Tue, Sep 22 2020 @ 10:05:00 PM MST (in 3517.397s), with 1 more job pending
+97ms ╚Event processed successfully (97ms)

[WCmore]

If there is too much chatter on the home network (or any connected network for that matter), a schedule may arrive a bit late. (or 82.6 seconds late, as seen above )
IE: Comparison (time) 75982572 happens_daily_at (time) 75900000 = false

There are numerous things we can do to lower that possibility, but that is a giant topic, without a simple answer.

Since this piston in particular only has two triggers, with either of them executing the THEN block beneath, you could apply a basic hack, and move the action commands outside of that main IF.

For example:

execute

   IF Time happens daily at X
      or
      Time happens daily at Y
   Then
      Log to console = "success"
   END IF

Insert lines 34-49 here (outside the Time IF)

end execute

This works identical to your piston, because a piston runs top to bottom at each and every execution.
(just don’t break it by adding an unrelated trigger)

Honestly, this does not solve the issue of latency, but even with a late recovery, the important part of the piston should still execute.

---

In reference to a snappier network / response time…
Remember that sometimes, it is out of our hands, but otherwise. this little snippet still applies:

<quote>
Recoveries are often due to congested network…
Sometimes external, but often it is commotion on the home network.

I’m not saying this is you, but common offenders in webCoRE might be:
Loops, Whiles and other poor coding choices that could be spamming the SmartHome…

If we are talking about Smart devices, the “chattiest” might be:
Power related, Lux sensors, or certain motion sensors…

Other heavy bandwidth offenders in the household might be:
Online gaming, Heavy downloading (Bittorrent), HD video streams, CCTV, etc…

In a nutshell, each one of these impacts the others.
</quote>

(I go into a bit more detail here and here)

[hatallica]

I like the idea of the work-around. That splits the issue into distinct chunks - latency and failure. The former is the tougher to resolve, but the latter is the more frustrating.

This morning’s routines were complicated by a host of failures - during a 4-minute delay to run the “lights on” piston, the hub went inactive. A reboot seems to have set the world right again (I hear my pool pump priming now, as expected).

[orangebucket]

Interesting log. The 9:05pm wake-up didn’t happen on time so a recovery event was fired which did the required job of scheduling the next run for 10:05pm and keeping the piston going. Then the 9:05pm wake-up arrived two and a half minutes late and seems to have found it wasn’t being expected any more.

[hatallica]

Public Service Announcement (not directly related to “happens daily”) - the action part of the piston doesn’t do what it is intended. I didn’t catch my error due to the time comparison issue.

My overall goal is to set the light level and then turn off. That way, when the wife manually switches a light, she does not get an overly dim setting leftover from an automation. I found that “set level” and “turn off” were in a race condition, and sometimes the device would execute them in the reverse order.

The idea was to make sure that the device acknowledged being at the proper setting, and then send “turn off”. However, that part of the piston ran without delay and failed. I will go back to the drawing board, using the work-around from @WCmore to at least make sure that the trigger performs the actions.

[WCmore]

For the record, there may be something going on at ST’s side…

My hourly piston is as simple as it gets.

… yet I just caught it 9m 19s late.

I was asleep… The house was empty… No devices were on… No other piston runs at that time.

So any latency was definitely not on my end.

[WCmore]

My overall goal is to set the light level and then turn off … I found that “set level” and “turn off” were in a race condition, and sometimes the device would execute them in the reverse order.

I do this with a simple block:

With Dimmer 6
    Set level to 50
    Wait 1 sec
    Turn off
END WITH

---

Pro Tip:

In the evening (before bed), I do the opposite, with a very low number:

With Dimmer 6
    Set level to 5
    Wait 1 sec
    Turn off
END WITH

This sets the light to a low level, so I am not blasted with light during over night bathroom breaks.

[hatallica]

I do this with a simple block:

With Dimmer 6
    Set level to 50
    Wait 1 sec
    Turn off
END WITH

This works well for me in a couple of pistons, but I am escalating wait times up to 30 seconds for others. This part is not a webCoRE issue. In the ST IDE, I can see that a varying delay happens between APP_COMMAND and the DEVICE action. If “set level” takes 1.5 seconds and “turn off” takes 0.5 seconds - as it did this morning - then the race is on.

My evening routine is the opposite. Bathroom light (manual dimmer) stays at the lowest level all night, so my wife doesn’t trip over the dog on the way to the bathroom. The hallway has a cheap, plug-in LED motion light. If I need to turn on any other lights in the middle of the night, then it better be an emergency that requires full brightness!

[WCmore]

wait times up to 30 seconds

If commands are consistently taking longer than one second to respond, there are definitely larger issues at play here…

[hatallica]

The first of 3 pistons that I have which use this basic structure worked as expected. The others failed the time comparison.

I still intend to move the actions outside of the IF/THEN, just didn’t get to it tonight.

[WCmore]

I still intend to move the actions outside of the IF/THEN

Make sure to place at least “something” inside the now empty THEN block.
Preferably something that is not critical, such as:

Log to console = "success"

You may think I’m joking, but I have seen occasions where a totally empty IF caused the piston to rebel…
(almost as if becoming self-aware… “You woke me up for this?!?”)

[hatallica]

All 3 of my evening “happens daily” pistons ran without a hitch last night. In fact, the one with actions outside the if/then block ran twice, since it has two triggers. For now, I will chalk this up to some transient condition.

[WCmore]

the one with actions outside the if/then block ran twice, since it has two triggers

I have not seen your latest version…
Any idea why two triggers are excuting back to back?

[hatallica]

Same triggers as the green shot, just different times for different days. The piston runs at both times, with one evaluating true and the other false. With actions outside of the conditional block, it runs for both.

I was not awake for the second one, but noticed it as an event that my cameras captured overnight. This morning, I just split them into separate pistons.

[WCmore]

piston runs at both times, with one evaluating true and the other false. With actions outside of the conditional block, it runs for both.

Ahh yes… You changed the logic from your first post.

My original advice was because:

(both triggers in your original piston will execute) the THEN block beneath, so you could apply a basic hack, and move the action commands outside of that main IF.

Adding an "unrelated trigger" will break that logic.

(although you could always add extra conditional checks in the lower part of the code)

[hatallica]

(although you could always add extra conditional checks in the lower part of the code)

I expected that it would trigger twice. After having it not execute at all, having an extra execution was an upgrade. I briefly debated adding more conditions, but it is so darn easy to duplicate a piston and delete one line from both versions.

I am still feeling out webCoRE, so this will get built-up and reorganized a few more times yet. All the more reason that I wanted to get this super-basic trigger resolved.

[WCmore]

it is so darn easy to duplicate a piston and delete one line from both versions.

Wise choice. I try to limit each piston to a single trigger, if possible.
(which also allows for much more complex actions)

[hatallica]

Except I realized that both will still trigger … Looks like I will be adding those extra conditions after all.

[hatallica]

Or … I found this little gem:

Using multiple TRIGGERS in single IF

Ahh, then perhaps using the Timer is the solution for those blocks as well… I cannot remember the last time I put a time statement as a trigger in an IF block. I usually do this instead: [temp] (although I may place conditions in the next line or two)

This has an elegant simplicity. I already converted my times global variables, so running tests mid-morning requires only a small tweak. In the ST IDE, I am still seeing devices taking over 1 second to respond to an APP_COMMAND, but that debacle might be a whole separate thread. Final (for now) version below.

[WCmore]

Lookin’ good…

You may already be aware, but two thoughts come to mind:

(1) “Every Day at X” blocks stay in that block. (they do not run top to bottom as most triggers do)

(2) If the global @timeShutdownWeekend ever changes, it will still fire at the old time at least one more time, before correcting itself.