Piston Aborts Sequence Randomly


#1

I have a piston that triggers at a specific time then runs a host of sequential commands for a hue light. This sequence happens over ~60 minutes. However, this piston often randomly halts and proceeds to schedule the event for the next day without completing all the steps in the sequence. Can anyone assist in determining if this is a bug in webcore, or is come type of system limitation on the time required to complete a triggered piston.

Here is the piston:

Here are the last part of the logs showing it schedule the task agains for the next day before completing:

11/2/2017, 6:50:52 AM +344ms
+1ms â•”Received event [Home].time = 1509619853808 with a delay of -1464ms
+450ms â•‘RunTime Analysis CS > 33ms > PS > 292ms > PE > 125ms > CE
+465ms â•‘Piston waited at a semaphore for 259ms
+468ms â•‘Runtime (40236 bytes) successfully initialized in 292ms (v0.2.0fb.20171026) (466ms)
+469ms â•‘â•”Execution stage started
+470ms â•‘â•šExecution stage complete. (2ms)
+472ms â•‘Setting up scheduled job for Fri, Nov 3 2017 @ 6:30:00 AM EDT (in 85147.185s)
+501ms â•šEvent processed successfully (501ms)
11/2/2017, 6:50:52 AM +149ms
+0ms â•”Received event [Home].execute = recovery with a delay of 106ms
+153ms â•‘RunTime Analysis CS > 16ms > PS > 38ms > PE > 100ms > CE
+172ms â•‘Runtime (40159 bytes) successfully initialized in 38ms (v0.2.0fb.20171026) (171ms)
+173ms â•‘â•”Execution stage started
+182ms â•‘â•‘Comparison (time) 24652329 happens_daily_at (time) 23400000 = false (1ms)
+184ms ║║Cancelling condition #17’s schedules…
+184ms â•‘â•‘Condition #17 evaluated false (5ms)
+186ms ║║Cancelling statement #17’s schedules…
+188ms â•‘â•‘Requesting time schedule wake up at Fri, Nov 3 2017 @ 6:30:00 AM EDT
+191ms ║║Cancelling condition #1’s schedules…
+192ms â•‘â•‘Condition group #1 evaluated false (state changed) (12ms)
+203ms â•‘â•šExecution stage complete. (30ms)
+205ms â•‘Setting up scheduled job for Fri, Nov 3 2017 @ 6:30:00 AM EDT (in 85147.647s)
+246ms â•šEvent processed successfully (246ms)
11/2/2017, 6:50:45 AM +355ms
+0ms â•”Received event [Home].time/recovery = 1509619815801 with a delay of 29553ms
+172ms â•‘RunTime Analysis CS > 27ms > PS > 36ms > PE > 110ms > CE
+185ms â•‘Runtime (40172 bytes) successfully initialized in 36ms (v0.2.0fb.20171026) (184ms)
+186ms â•‘â•”Execution stage started
+333ms â•‘â•‘Executed physical command [Hue color lamp 201].off() (137ms)
+395ms â•‘â•‘Executed physical command [Hue color lamp 201].on() (50ms)
+463ms â•‘â•‘Executed physical command [Hue color lamp 201].off() (57ms)
+497ms â•‘â•‘Executed physical command [Hue color lamp 201].on() (25ms)
+530ms â•‘â•‘Executed physical command [Hue color lamp 201].off() (24ms)
+562ms â•‘â•‘Executed physical command [Hue color lamp 201].on() (25ms)
+592ms â•‘â•‘Executed physical command [Hue color lamp 201].off() (22ms)
+627ms â•‘â•‘Executed physical command [Hue color lamp 201].on() (26ms)
+657ms â•‘â•‘Executed physical command [Hue color lamp 201].off() (22ms)
+688ms â•‘â•‘Executed physical command [Hue color lamp 201].on() (23ms)
+727ms â•‘â•‘Executed physical command [Hue color lamp 201].off() (33ms)
+768ms â•‘â•‘Executed physical command [Hue color lamp 201].on() (33ms)
+806ms â•‘â•‘Executed physical command [Hue color lamp 201].off() (30ms)
+1009ms â•‘â•‘Executed physical command [Hue color lamp 201].on() (195ms)
+1051ms â•‘â•‘Executed physical command [Hue color lamp 201].off() (34ms)
+1093ms â•‘â•‘Executed physical command [Hue color lamp 201].on() (32ms)
+1098ms â•‘â•‘Fast executing schedules, waiting for 1355ms to sync up
+2488ms â•‘â•‘Executed physical command [Hue color lamp 201].off() (29ms)
+2492ms â•‘â•‘Fast executing schedules, waiting for 1960ms to sync up
+4485ms â•‘â•‘Executed physical command [Hue color lamp 201].on() (27ms)
+4487ms â•‘â•‘Fast executing schedules, waiting for 1966ms to sync up
+6504ms â•‘â•‘Executed physical command [Hue color lamp 201].off() (44ms)
+6505ms â•‘â•šExecution stage complete. (6319ms)
+6509ms â•‘Setting up scheduled job for Thu, Nov 2 2017 @ 6:50:53 AM EDT (in 1.945s), with 5 more jobs pending
+6537ms â•šEvent processed successfully (6537ms)


#2

The tasks may be cancelling because when you get deep into the actions, the time is no longer true so the tasks will cancel.
Click on the WITH and go into the settings cog.
Change Task Cancellation Policy (TCP) to never.
This way all the tasks will run.


#4

Thanks for the advice. I will try that and report back (after a few successful days) if it works, or right away tomorrow if it doesn’t.

I know I could also create numerous pistons to start at the various times, but it is much less simple to manage.


#5

When the piston is running you can click on the trace button and see the timers counting down.


#6

This piston has now run as expected 4 days in a row after the change. So this appears to have done the trick. Thanks!