Piston keeps running continuously

#1

1) Give a description of the problem
I have a simple piston I expect to run just two times a year. The schedule says it won’t run until Next March 3rd but I just happened to notice the last ran keeps updating every 3-5 seconds.

2) What is the expected behaviour?
Don’t run until it is scheduled

3) What is happening/not happening?
Seems to be running continuously based on last executed data. See quick facts and log included below. I have paused the piston for now.

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

DST
DST.png1178×557 96.4 KB

54%20PM
Screen Shot 2019-12-09 at 10.45.54 PM.png732×562 34.3 KB

5) Attach logs after turning logging level to Full

46%20PM
Screen Shot 2019-12-09 at 10.47.46 PM.png1154×296 24.7 KB

#2

The piston looks OK to me…

Although setting Logging to Full will give you more information…

#3

@WCmore Here is the log set to full. Agree the piston seems fine. Just don’t understand why it keeps running.

12/10/2019, 1:37:45 PM +603ms
+126ms ╔Stopping piston...
+546ms ╚Piston successfully stopped (421ms)
12/10/2019, 1:37:43 PM +173ms
+1ms ╔Received event [Las Vegas].time = 1583656200000 with a delay of -7642336827ms
+134ms ║RunTime Analysis CS > 23ms > PS > 64ms > PE > 46ms > CE
+136ms ║Runtime (39871 bytes) successfully initialized in 64ms (v0.3.110.20191009) (134ms)
+137ms ║╔Execution stage started
+139ms ║╚Execution stage complete. (1ms)
+140ms ║Setting up scheduled job for Sun, Mar 8 2020 @ 12:30:00 AM PST (in 7642336.687s), with 1 more job pending
+153ms ╚Event processed successfully (153ms)
12/10/2019, 1:37:40 PM +276ms
+0ms ╔Received event [Las Vegas].time = 1583656200000 with a delay of -7642339725ms
+243ms ║RunTime Analysis CS > 81ms > PS > 117ms > PE > 45ms > CE
+246ms ║Runtime (39873 bytes) successfully initialized in 117ms (v0.3.110.20191009) (245ms)
+247ms ║╔Execution stage started
+249ms ║╚Execution stage complete. (2ms)
+251ms ║Setting up scheduled job for Sun, Mar 8 2020 @ 12:30:00 AM PST (in 7642339.473s), with 1 more job pending
+260ms ╚Event processed successfully (260ms)
12/10/2019, 1:37:37 PM +111ms
+0ms ╔Received event [Las Vegas].time = 1583656200000 with a delay of -7642342890ms
+110ms ║RunTime Analysis CS > 32ms > PS > 46ms > PE > 32ms > CE
+112ms ║Runtime (39871 bytes) successfully initialized in 46ms (v0.3.110.20191009) (111ms)
+113ms ║╔Execution stage started
+114ms ║╚Execution stage complete. (1ms)
+116ms ║Setting up scheduled job for Sun, Mar 8 2020 @ 12:30:00 AM PST (in 7642342.774s), with 1 more job pending
+124ms ╚Event processed successfully (124ms)
12/10/2019, 1:37:34 PM +233ms
+1ms ╔Received event [Las Vegas].time = 1583656200000 with a delay of -7642345767ms
+141ms ║RunTime Analysis CS > 24ms > PS > 64ms > PE > 52ms > CE
+144ms ║Runtime (39871 bytes) successfully initialized in 64ms (v0.3.110.20191009) (143ms)
+146ms ║╔Execution stage started
+147ms ║╚Execution stage complete. (2ms)
+150ms ║Setting up scheduled job for Sun, Mar 8 2020 @ 12:30:00 AM PST (in 7642345.618s), with 1 more job pending
+162ms ╚Event processed successfully (162ms)
12/10/2019, 1:37:31 PM +125ms
+0ms ╔Received event [Las Vegas].time = 1583656200000 with a delay of -7642348875ms
+107ms ║RunTime Analysis CS > 35ms > PS > 44ms > PE > 28ms > CE
+110ms ║Runtime (39871 bytes) successfully initialized in 44ms (v0.3.110.20191009) (108ms)
+111ms ║╔Execution stage started
+112ms ║╚Execution stage complete. (2ms)
+113ms ║Setting up scheduled job for Sun, Mar 8 2020 @ 12:30:00 AM PST (in 7642348.762s), with 1 more job pending
+123ms ╚Event processed successfully (123ms)
12/10/2019, 1:37:28 PM +496ms
+0ms ╔Received event [Las Vegas].time = 1583656200000 with a delay of -7642351504ms
+111ms ║RunTime Analysis CS > 22ms > PS > 55ms > PE > 34ms > CE
+113ms ║Runtime (39871 bytes) successfully initialized in 55ms (v0.3.110.20191009) (112ms)
+114ms ║╔Execution stage started
+116ms ║╚Execution stage complete. (1ms)
+117ms ║Setting up scheduled job for Sun, Mar 8 2020 @ 12:30:00 AM PST (in 7642351.388s), with 1 more job pending
+124ms ╚Event processed successfully (124ms)
12/10/2019, 1:37:25 PM +239ms
+1ms ╔Received event [Las Vegas].time = 1583656200000 with a delay of -7642354761ms
+182ms ║RunTime Analysis CS > 47ms > PS > 101ms > PE > 33ms > CE
+185ms ║Runtime (39873 bytes) successfully initialized in 101ms (v0.3.110.20191009) (182ms)
+186ms ║╔Execution stage started
+188ms ║╚Execution stage complete. (2ms)
+191ms ║Setting up scheduled job for Sun, Mar 8 2020 @ 12:30:00 AM PST (in 7642354.571s), with 1 more job pending
+200ms ╚Event processed successfully (200ms)
12/10/2019, 1:37:22 PM +102ms
+0ms ╔Received event [Las Vegas].time = 1583656200000 with a delay of -7642357898ms
+259ms ║RunTime Analysis CS > 29ms > PS > 198ms > PE > 31ms > CE
+262ms ║Runtime (39873 bytes) successfully initialized in 198ms (v0.3.110.20191009) (261ms)
+263ms ║╔Execution stage started
+264ms ║╚Execution stage complete. (2ms)
+266ms ║Setting up scheduled job for Sun, Mar 8 2020 @ 12:30:00 AM PST (in 7642357.633s), with 1 more job pending
+274ms ╚Event processed successfully (274ms)
12/10/2019, 1:37:19 PM +283ms
+0ms ╔Received event [Las Vegas].time = 1583656200000 with a delay of -7642360717ms
+129ms ║RunTime Analysis CS > 35ms > PS > 60ms > PE > 34ms > CE
+131ms ║Runtime (39871 bytes) successfully initialized in 60ms (v0.3.110.20191009) (130ms)
+132ms ║╔Execution stage started
+133ms ║╚Execution stage complete. (1ms)
+135ms ║Setting up scheduled job for Sun, Mar 8 2020 @ 12:30:00 AM PST (in 7642360.583s), with 1 more job pending
+144ms ╚Event processed successfully (144ms)
12/10/2019, 1:37:16 PM +242ms
+0ms ╔Received event [Las Vegas].time = 1583656200000 with a delay of -7642363758ms
+148ms ║RunTime Analysis CS > 36ms > PS > 83ms > PE > 28ms > CE
+150ms ║Runtime (39871 bytes) successfully initialized in 83ms (v0.3.110.20191009) (149ms)
+151ms ║╔Execution stage started
+152ms ║╚Execution stage complete. (1ms)
+154ms ║Setting up scheduled job for Sun, Mar 8 2020 @ 12:30:00 AM PST (in 7642363.605s), with 1 more job pending
+163ms ╚Event processed successfully (163ms)
12/10/2019, 1:37:13 PM +188ms
+0ms ╔Received event [Las Vegas].time = 1583656200000 with a delay of -7642366812ms
+90ms ║RunTime Analysis CS > 18ms > PS > 41ms > PE > 31ms > CE
+92ms ║Runtime (39870 bytes) successfully initialized in 41ms (v0.3.110.20191009) (91ms)
+93ms ║╔Execution stage started
+95ms ║╚Execution stage complete. (1ms)
+96ms ║Setting up scheduled job for Sun, Mar 8 2020 @ 12:30:00 AM PST (in 7642366.716s), with 1 more job pending
+105ms ╚Event processed successfully (105ms)
#4

Sorry to be a pain, but I will not look at any log without Trace turned on.
Please post a new green snapshot with that turned on.

#5

Nevermind… There is no reference numbers in your log here…

Pausing the piston, counting to ten, and then resuming the piston may stop the craziness…

#6

For what it’s worth, here is how I check the daylight savings…

formatDateTime($now, "z")

pic

  • {timeZone} is a string variable
  • XXX & YYY should be changed to match the results for your timezone
  • {gmtOffset} is an integer variable
  • The red question marks should be an appropriate integer.

Of course, you may use this structure to set a boolean, if you prefer…

Convert UTC / Epoch Time to Human Time
#7

WebCoRE knows it wants to schedule a wakeup for 8th March but I don’t see the usual line in the logs indicating that it has actually done so. Instead it is processing an event about three seconds or so later which it interprets as that wakeup arriving about 88 days early. I can’t interpret the piston code well enough to understand exactly what is happening. Maybe the delay is so long that it breaks a calculation and it thinks the next execution is due.

I think a different solution is certainly called for.

#8

I have seen issues in the past with schedules set very far in the future…

If (for some reason) you want to stay with your original structure, one work around is to add a tiny block to the bottom:

Every Monday at 4AM
    Do (nothing)
END EVERY

This basically ensures that the schedule is never too far in the future…

That being said, my previous post works like a charm, and is the method I will recommend.

#9

thanks @WCmore. Your solution is elegant, as usual. I thought running just twice a year would be sufficient but I guess scheduling too far in advance is a problem. Probably because it is in milliseconds. thanks!

FYI, I did pause and resume a couple times and it still kept doing this. Actually paused overnight but still kept doing this.

UPDATE: implemented this and no more repeated execution. I set to run only on Sundays since that is the only day the time changes. thanks again!

#10

If memory serves me right, I think we should add that dummy block to any piston trying to schedule more than three weeks in the future…

(I’m not sure if this is required on a “once a month” trigger)