Task Cancellation Logic

[sumya]

1) Give a description of the problem
Even though task cancellation policy is set to never cancel task, task is still cancelled.

2) What is the expected behavior?
I want it to wait for 4 mins and then send a command to speaker (even though motion has stopped)

3) What is happening/not happening?

Once motion is inactive, task gets cancelled.

4) Post a Green Snapshot of the piston
(UPLOAD YOUR IMAGE HERE)

5) Attach any logs (From ST IDE and by turning logging level to Full)
(PASTE YOUR LOGS HERE BETWEEN THE MARKS)

REMOVE BELOW AFTER READING
If a solution is found for your question then please mark the post as the solution.

[c1arkbar]

There is no way to help without supplying full logs. I’m sorry.

[bobbles]

What happens if you get rid of the never in the WITH.
It’s not doing anything.

[sumya]

This was only half part of the piston hence did not post the logs. Will post the logs tonight.
Also will try to get rid of never in the with and see if it makes any difference.

[sumya]

Piston:

Logs
1/10/2018, 9:58:24 PM +248ms
+1ms ╔Received event [LRoom Motion Sensor L].motion = inactive with a delay of 197ms
+141ms ║RunTime Analysis CS > 36ms > PS > 35ms > PE > 69ms > CE
+143ms ║Runtime (36836 bytes) successfully initialized in 35ms (v0.2.101.20171227) (141ms)
+144ms ║╔Execution stage started
+151ms ║║Comparison (enum) inactive changes_to (string) active = false (1ms)
+152ms ║║Cancelling condition #5’s schedules…
+153ms ║║Condition #5 evaluated false (5ms)
+154ms ║║Cancelling condition #1’s schedules…
+154ms ║║Condition group #1 evaluated false (state changed) (6ms)
+157ms ║╚Execution stage complete. (14ms)
+158ms ║Setting up scheduled job for Wed, Jan 10 2018 @ 10:01:21 PM CST (in 177.088s)
+170ms ╚Event processed successfully (170ms)
1/10/2018, 9:57:21 PM +302ms
+2ms ╔Received event [LRoom Motion Sensor L].motion = active with a delay of 262ms
+169ms ║RunTime Analysis CS > 46ms > PS > 47ms > PE > 76ms > CE
+171ms ║Runtime (36841 bytes) successfully initialized in 47ms (v0.2.101.20171227) (168ms)
+172ms ║╔Execution stage started
+179ms ║║Comparison (enum) active changes_to (string) active = true (1ms)
+181ms ║║Cancelling condition #5’s schedules…
+181ms ║║Condition #5 evaluated true (5ms)
+182ms ║║Cancelling condition #1’s schedules…
+183ms ║║Condition group #1 evaluated true (state changed) (7ms)
+186ms ║║Cancelling statement #2’s schedules…
+191ms ║║Executed virtual command [TV Room Speaker].wait (0ms)
+192ms ║║Requesting a wake up for Wed, Jan 10 2018 @ 10:01:21 PM CST (in 240.0s)
+196ms ║╚Execution stage complete. (24ms)
+197ms ║Setting up scheduled job for Wed, Jan 10 2018 @ 10:01:21 PM CST (in 239.995s)
+208ms ╚Event processed successfully (208ms)
1/10/2018, 9:56:27 PM +86ms
+1ms ╔Received event [LRoom Motion Sensor L].motion = inactive with a delay of 188ms
+144ms ║RunTime Analysis CS > 38ms > PS > 35ms > PE > 70ms > CE
+146ms ║Runtime (36836 bytes) successfully initialized in 35ms (v0.2.101.20171227) (145ms)
+147ms ║╔Execution stage started
+153ms ║║Comparison (enum) inactive changes_to (string) active = false (0ms)
+154ms ║║Cancelling condition #5’s schedules…
+155ms ║║Condition #5 evaluated false (4ms)
+156ms ║║Cancelling condition #1’s schedules…
+157ms ║║Condition group #1 evaluated false (state changed) (6ms)
+159ms ║╚Execution stage complete. (13ms)
+160ms ║Setting up scheduled job for Wed, Jan 10 2018 @ 9:59:55 PM CST (in 208.669s)
+170ms ╚Event processed successfully (170ms)
1/10/2018, 9:55:55 PM +720ms
+1ms ╔Received event [LRoom Motion Sensor L].motion = active with a delay of 298ms
+174ms ║RunTime Analysis CS > 45ms > PS > 56ms > PE > 73ms > CE
+176ms ║Runtime (36841 bytes) successfully initialized in 56ms (v0.2.101.20171227) (174ms)
+177ms ║╔Execution stage started
+183ms ║║Comparison (enum) active changes_to (string) active = true (1ms)
+184ms ║║Cancelling condition #5’s schedules…
+185ms ║║Condition #5 evaluated true (4ms)
+186ms ║║Cancelling condition #1’s schedules…
+186ms ║║Condition group #1 evaluated true (state changed) (6ms)
+188ms ║║Cancelling statement #2’s schedules…
+193ms ║║Executed virtual command [TV Room Speaker].wait (0ms)
+194ms ║║Requesting a wake up for Wed, Jan 10 2018 @ 9:59:55 PM CST (in 240.0s)
+198ms ║╚Execution stage complete. (22ms)
+199ms ║Setting up scheduled job for Wed, Jan 10 2018 @ 9:59:55 PM CST (in 239.997s)
+212ms ╚Event processed successfully (212ms)
1/10/2018, 9:55:36 PM +398ms
+0ms ╔Received event [LRoom Motion Sensor L].motion = inactive with a delay of 184ms
+123ms ║RunTime Analysis CS > 20ms > PS > 33ms > PE > 71ms > CE
+126ms ║Runtime (36836 bytes) successfully initialized in 33ms (v0.2.101.20171227) (124ms)
+126ms ║╔Execution stage started
+133ms ║║Comparison (enum) inactive changes_to (string) active = false (0ms)
+134ms ║║Cancelling condition #5’s schedules…
+135ms ║║Condition #5 evaluated false (4ms)
+136ms ║║Cancelling condition #1’s schedules…
+137ms ║║Condition group #1 evaluated false (state changed) (7ms)
+139ms ║╚Execution stage complete. (13ms)
+141ms ║Setting up scheduled job for Wed, Jan 10 2018 @ 9:58:32 PM CST (in 176.353s)
+151ms ╚Event processed successfully (151ms)
1/10/2018, 9:54:32 PM +732ms
+1ms ╔Received event [LRoom Motion Sensor L].motion = active with a delay of 184ms
+138ms ║RunTime Analysis CS > 35ms > PS > 36ms > PE > 67ms > CE
+140ms ║Runtime (36841 bytes) successfully initialized in 36ms (v0.2.101.20171227) (138ms)
+141ms ║╔Execution stage started
+148ms ║║Comparison (enum) active changes_to (string) active = true (0ms)
+149ms ║║Cancelling condition #5’s schedules…
+150ms ║║Condition #5 evaluated true (4ms)
+151ms ║║Cancelling condition #1’s schedules…
+152ms ║║Condition group #1 evaluated true (state changed) (6ms)
+153ms ║║Cancelling statement #2’s schedules…
+157ms ║║Executed virtual command [TV Room Speaker].wait (0ms)
+158ms ║║Requesting a wake up for Wed, Jan 10 2018 @ 9:58:32 PM CST (in 240.0s)
+162ms ║╚Execution stage complete. (21ms)
+163ms ║Setting up scheduled job for Wed, Jan 10 2018 @ 9:58:32 PM CST (in 239.996s)
+172ms ╚Event processed successfully (172ms)
1/10/2018, 9:39:45 PM +501ms
+0ms ╔Received event [Home].time = 1515641986822 with a delay of -1322ms
+200ms ║RunTime Analysis CS > 53ms > PS > 57ms > PE > 90ms > CE
+202ms ║Runtime (36831 bytes) successfully initialized in 57ms (v0.2.101.20171227) (201ms)
+203ms ║╔Execution stage started
+731ms ║║Executed physical command [TV Room Speaker].speak([Test Test Test]) (512ms)
+732ms ║║Executed [TV Room Speaker].speak (513ms)
+734ms ║╚Execution stage complete. (531ms)
+736ms ╚Event processed successfully (735ms)
1/10/2018, 9:36:20 PM +792ms
+1ms ╔Received event [LRoom Motion Sensor L].motion = inactive with a delay of 882ms
+176ms ║RunTime Analysis CS > 45ms > PS > 54ms > PE > 78ms > CE
+179ms ║Runtime (36836 bytes) successfully initialized in 54ms (v0.2.101.20171227) (176ms)
+179ms ║╔Execution stage started
+186ms ║║Comparison (enum) inactive changes_to (string) active = false (0ms)
+188ms ║║Cancelling condition #5’s schedules…
+188ms ║║Condition #5 evaluated false (4ms)
+189ms ║║Cancelling condition #1’s schedules…
+190ms ║║Condition group #1 evaluated false (state changed) (7ms)
+192ms ║╚Execution stage complete. (13ms)
+194ms ║Setting up scheduled job for Wed, Jan 10 2018 @ 9:39:46 PM CST (in 205.837s)
+207ms ╚Event processed successfully (207ms)
1/10/2018, 9:35:46 PM +627ms
+2ms ╔Received event [LRoom Motion Sensor L].motion = active with a delay of 1294ms
+171ms ║RunTime Analysis CS > 45ms > PS > 53ms > PE > 73ms > CE
+173ms ║Runtime (36842 bytes) successfully initialized in 53ms (v0.2.101.20171227) (171ms)
+174ms ║╔Execution stage started
+182ms ║║Comparison (enum) active changes_to (string) active = true (1ms)
+183ms ║║Cancelling condition #5’s schedules…
+184ms ║║Condition #5 evaluated true (5ms)
+185ms ║║Cancelling condition #1’s schedules…
+186ms ║║Condition group #1 evaluated true (state changed) (7ms)
+188ms ║║Cancelling statement #2’s schedules…
+193ms ║║Executed virtual command [TV Room Speaker].wait (0ms)
+194ms ║║Requesting a wake up for Wed, Jan 10 2018 @ 9:39:46 PM CST (in 240.0s)
+198ms ║╚Execution stage complete. (24ms)
+200ms ║Setting up scheduled job for Wed, Jan 10 2018 @ 9:39:46 PM CST (in 239.996s)
+211ms ╚Event processed successfully (211ms)
1/10/2018, 9:33:48 PM +502ms
+2ms ╔Received event [LRoom Motion Sensor L].motion = inactive with a delay of 841ms
+159ms ║RunTime Analysis CS > 24ms > PS > 64ms > PE > 71ms > CE
+161ms ║Runtime (36836 bytes) successfully initialized in 64ms (v0.2.101.20171227) (159ms)
+162ms ║╔Execution stage started
+168ms ║║Comparison (enum) inactive changes_to (string) active = false (0ms)
+170ms ║║Cancelling condition #5’s schedules…
+170ms ║║Condition #5 evaluated false (4ms)
+171ms ║║Cancelling condition #1’s schedules…
+172ms ║║Condition group #1 evaluated false (state changed) (6ms)
+174ms ║╚Execution stage complete. (12ms)
+175ms ║Setting up scheduled job for Wed, Jan 10 2018 @ 9:37:09 PM CST (in 200.387s)
+186ms ╚Event processed successfully (186ms)
1/10/2018, 9:33:08 PM +875ms
+1ms ╔Received event [LRoom Motion Sensor L].motion = active with a delay of 857ms
+166ms ║RunTime Analysis CS > 43ms > PS > 47ms > PE > 76ms > CE
+168ms ║Runtime (36841 bytes) successfully initialized in 47ms (v0.2.101.20171227) (166ms)
+169ms ║╔Execution stage started
+177ms ║║Comparison (enum) active changes_to (string) active = true (1ms)
+178ms ║║Cancelling condition #5’s schedules…
+179ms ║║Condition #5 evaluated true (5ms)
+180ms ║║Cancelling condition #1’s schedules…
+180ms ║║Condition group #1 evaluated true (state changed) (7ms)
+182ms ║║Cancelling statement #2’s schedules…
+187ms ║║Executed virtual command [TV Room Speaker].wait (0ms)
+189ms ║║Requesting a wake up for Wed, Jan 10 2018 @ 9:37:09 PM CST (in 240.0s)
+193ms ║╚Execution stage complete. (24ms)
+194ms ║Setting up scheduled job for Wed, Jan 10 2018 @ 9:37:09 PM CST (in 239.995s)
+231ms ╚Event processed successfully (230ms)
1/10/2018, 9:30:17 PM +222ms
+1ms ╔Received event [LRoom Motion Sensor L].motion = inactive with a delay of 814ms
+120ms ║RunTime Analysis CS > 19ms > PS > 34ms > PE > 67ms > CE
+122ms ║Runtime (36836 bytes) successfully initialized in 34ms (v0.2.101.20171227) (121ms)
+122ms ║╔Execution stage started
+129ms ║║Comparison (enum) inactive changes_to (string) active = false (0ms)
+130ms ║║Cancelling condition #5’s schedules…
+131ms ║║Condition #5 evaluated false (4ms)
+132ms ║║Cancelling condition #1’s schedules…
+132ms ║║Condition group #1 evaluated false (state changed) (6ms)
+135ms ║╚Execution stage complete. (13ms)
+136ms ║Setting up scheduled job for Wed, Jan 10 2018 @ 9:33:46 PM CST (in 208.668s)
+149ms ╚Event processed successfully (149ms)
1/10/2018, 9:29:45 PM +690ms
+2ms ╔Received event [LRoom Motion Sensor L].motion = active with a delay of 871ms
+314ms ║RunTime Analysis CS > 44ms > PS > 199ms > PE > 71ms > CE
+316ms ║Runtime (36843 bytes) successfully initialized in 199ms (v0.2.101.20171227) (313ms)
+317ms ║╔Execution stage started
+324ms ║║Comparison (enum) active changes_to (string) active = true (0ms)
+325ms ║║Cancelling condition #5’s schedules…
+326ms ║║Condition #5 evaluated true (4ms)
+326ms ║║Cancelling condition #1’s schedules…
+327ms ║║Condition group #1 evaluated true (state changed) (6ms)
+329ms ║║Cancelling statement #2’s schedules…
+334ms ║║Executed virtual command [TV Room Speaker].wait (1ms)
+335ms ║║Requesting a wake up for Wed, Jan 10 2018 @ 9:33:46 PM CST (in 240.0s)
+338ms ║╚Execution stage complete. (21ms)
+340ms ║Setting up scheduled job for Wed, Jan 10 2018 @ 9:33:46 PM CST (in 239.996s)
+348ms ╚Event processed successfully (348ms)
1/10/2018, 9:28:39 PM +541ms
+0ms ╔Received event [Home].time = 1515641319506 with a delay of 34ms
+171ms ║RunTime Analysis CS > 28ms > PS > 55ms > PE > 88ms > CE
+173ms ║Runtime (36828 bytes) successfully initialized in 55ms (v0.2.101.20171227) (172ms)
+174ms ║╔Execution stage started
+399ms ║║Executed physical command [TV Room Speaker].speak([Test Test Test]) (210ms)
+400ms ║║Executed [TV Room Speaker].speak (211ms)
+403ms ║╚Execution stage complete. (229ms)
+404ms ╚Event processed successfully (404ms)
1/10/2018, 9:25:49 PM +957ms
+1ms ╔Received event [LRoom Motion Sensor L].motion = inactive with a delay of 817ms
+168ms ║RunTime Analysis CS > 42ms > PS > 55ms > PE > 72ms > CE
+170ms ║Runtime (36836 bytes) successfully initialized in 55ms (v0.2.101.20171227) (168ms)
+171ms ║╔Execution stage started
+178ms ║║Comparison (enum) inactive changes_to (string) active = false (1ms)
+179ms ║║Cancelling condition #5’s schedules…
+180ms ║║Condition #5 evaluated false (4ms)
+180ms ║║Cancelling condition #1’s schedules…
+181ms ║║Condition group #1 evaluated false (state changed) (6ms)
+183ms ║╚Execution stage complete. (12ms)
+185ms ║Setting up scheduled job for Wed, Jan 10 2018 @ 9:28:39 PM CST (in 169.365s)
+197ms ╚Event processed successfully (196ms)
1/10/2018, 9:24:39 PM +321ms
+2ms ╔Received event [LRoom Motion Sensor L].motion = active with a delay of 785ms
+164ms ║RunTime Analysis CS > 45ms > PS > 48ms > PE > 71ms > CE
+167ms ║Runtime (36841 bytes) successfully initialized in 48ms (v0.2.101.20171227) (164ms)
+167ms ║╔Execution stage started
+174ms ║║Comparison (enum) active changes_to (string) active = true (1ms)
+175ms ║║Cancelling condition #5’s schedules…
+176ms ║║Condition #5 evaluated true (5ms)
+177ms ║║Cancelling condition #1’s schedules…
+177ms ║║Condition group #1 evaluated true (state changed) (6ms)
+179ms ║║Cancelling statement #2’s schedules…
+184ms ║║Executed virtual command [TV Room Speaker].wait (1ms)
+185ms ║║Requesting a wake up for Wed, Jan 10 2018 @ 9:28:39 PM CST (in 240.0s)
+189ms ║╚Execution stage complete. (21ms)
+190ms ║Setting up scheduled job for Wed, Jan 10 2018 @ 9:28:39 PM CST (in 239.996s)
+204ms ╚Event processed successfully (204ms)

[bobbles]

Get rid of the never against the IF.

[c1arkbar]

According to the logs the command was issued several times to speak.

Instead of speak text try using speak text and restore or speak text and resume

[sumya]

You are correct. I decreased the wait time and I did hear the command from speaker. I think I was making a dumb mistake. I was only clicking on Test and waiting to see if the timer starts. Timer use to start but once motion was inactive, timer use to stop on the trace. So I used to assume that it is not working and change/update the piston. Need to be more patient with these things