Total Time from Switch


#1

1) Give a description of the problem
Hello all.

I made a piston to get the total time of my room lights is on, but sometimes I get a discrepancy of the time, not in minutes, but in hours.
As I can see on the logs, when I turn on the lights, it thinks that I turn off it and take the last time that my light was off. In my case, almost 14 hours.

2) What is the expected behavior?
Get the correct time from my rrom lights when they are on.

3) What is happening/not happening?
Get inconsistency times

4) Post a Green Snapshot of the pistonimage

5) Attach any logs (From ST IDE and by turning logging level to Full)
01/12/2017 20:09:03 +840ms
+2ms ╔Received event [Room Lights].switch = off with a delay of 603ms
+451ms ║RunTime Analysis CS > 16ms > PS > 283ms > PE > 152ms > CE
+465ms ║Piston waited at a semaphore for 262ms
+467ms ║Runtime (42073 bytes) successfully initialized in 283ms (v0.2.0ff.20171129) (465ms)
+468ms ║╔Execution stage started
+474ms ║║Comparison (enum) off changes = false (1ms)
+475ms ║║Cancelling condition #2’s schedules…
+476ms ║║Condition #2 evaluated false (3ms)
+476ms ║║Cancelling condition #1’s schedules…
+477ms ║║Condition group #1 evaluated false (state changed) (5ms)
+481ms ║║Comparison (enum) off changes_to (string) on = false (0ms)
+483ms ║║Condition #33 evaluated false (3ms)
+483ms ║║Condition group #30 evaluated false (state did not change) (4ms)
+485ms ║║Cancelling statement #22’s schedules…
+500ms ║║Calculating (long) 152564 + (long) 52814145 >> (long) 52966709
+506ms ║║Executed virtual command [Room Lights].setVariable (2ms)
+515ms ║║Calculating (string) Luz Desligada
+515ms ║║ + (string) Interruptor pressionado >> (string) Luz Desligada
+515ms ║║Interruptor pressionado
+518ms ║║Calculating (string) Luz Desligada
+518ms ║║Interruptor pressionado + (string) 171 >> (string) Luz Desligada
+518ms ║║Interruptor pressionado 171
+520ms ║║Calculating (string) Luz Desligada
+520ms ║║Interruptor pressionado 171 + (string) vezes
+520ms ║║ >> (string) Luz Desligada
+521ms ║║Interruptor pressionado 171 vezes
+522ms ║║Calculating (string) Luz Desligada
+522ms ║║Interruptor pressionado 171 vezes
+523ms ║║ + (string) 14 hours, 42 minutes, and 46 seconds >> (string) Luz Desligada
+523ms ║║Interruptor pressionado 171 vezes
+523ms ║║14 hours, 42 minutes, and 46 seconds
+525ms ║║Executed virtual command [Room Lights].setState (0ms)
+531ms ║╚Execution stage complete. (62ms)
+532ms ║Setting up scheduled job for Sun, Dec 3 2017 @ 7:00:00 PM BRST (in 168655.628s), with 1 more job pending
+551ms ╚Event processed successfully (551ms)
01/12/2017 20:09:03 +699ms
+1ms ╔Received event [Room Lights].switch = off with a delay of 639ms
+172ms ║RunTime Analysis CS > 19ms > PS > 25ms > PE > 128ms > CE
+184ms ║Runtime (42006 bytes) successfully initialized in 25ms (v0.2.0ff.20171129) (181ms)
+184ms ║╔Execution stage started
+190ms ║║Comparison (enum) off changes = true (0ms)
+191ms ║║Cancelling condition #2’s schedules…
+192ms ║║Condition #2 evaluated true (4ms)
+193ms ║║Cancelling condition #1’s schedules…
+194ms ║║Condition group #1 evaluated true (state changed) (6ms)
+196ms ║║Cancelling statement #4’s schedules…
+199ms ║║Calculating (integer) 170 + (integer) 1 >> (integer) 171
+205ms ║║Executed virtual command [Room Lights].setVariable (3ms)
+210ms ║║Comparison (enum) off changes_to (string) on = false (0ms)
+212ms ║║Condition #33 evaluated false (3ms)
+212ms ║║Condition group #30 evaluated false (state did not change) (4ms)
+214ms ║║Cancelling statement #22’s schedules…
+227ms ║║Calculating (long) 152149 + (long) 52661996 >> (long) 52814145
+230ms ║║Executed virtual command [Room Lights].setVariable (2ms)
+237ms ║║Calculating (string) Luz Desligada
+237ms ║║ + (string) Interruptor pressionado >> (string) Luz Desligada
+237ms ║║Interruptor pressionado
+240ms ║║Calculating (string) Luz Desligada
+240ms ║║Interruptor pressionado + (string) 171 >> (string) Luz Desligada
+240ms ║║Interruptor pressionado 171
+242ms ║║Calculating (string) Luz Desligada
+242ms ║║Interruptor pressionado 171 + (string) vezes
+242ms ║║ >> (string) Luz Desligada
+242ms ║║Interruptor pressionado 171 vezes
+244ms ║║Calculating (string) Luz Desligada
+244ms ║║Interruptor pressionado 171 vezes
+244ms ║║ + (string) 14 hours, 40 minutes, and 14 seconds >> (string) Luz Desligada
+244ms ║║Interruptor pressionado 171 vezes
+244ms ║║14 hours, 40 minutes, and 14 seconds
+250ms ║║Executed virtual command [Room Lights].setState (0ms)
+256ms ║╚Execution stage complete. (72ms)
+257ms ║Setting up scheduled job for Sun, Dec 3 2017 @ 7:00:00 PM BRST (in 168656.044s), with 1 more job pending
+273ms ╚Event processed successfully (273ms)
01/12/2017 20:06:32 +487ms
+1ms ╔Received event [Room Lights].switch = on with a delay of 713ms
+449ms ║RunTime Analysis CS > 15ms > PS > 285ms > PE > 149ms > CE
+458ms ║Piston waited at a semaphore for 266ms
+460ms ║Runtime (41928 bytes) successfully initialized in 285ms (v0.2.0ff.20171129) (458ms)
+461ms ║╔Execution stage started
+466ms ║║Comparison (enum) on changes = false (0ms)
+467ms ║║Cancelling condition #2’s schedules…
+468ms ║║Condition #2 evaluated false (4ms)
+469ms ║║Cancelling condition #1’s schedules…
+469ms ║║Condition group #1 evaluated false (state changed) (5ms)
+473ms ║║Comparison (enum) on changes_to (string) on = false (0ms)
+474ms ║║Cancelling condition #33’s schedules…
+475ms ║║Condition #33 evaluated false (4ms)
+476ms ║║Cancelling condition #30’s schedules…
+477ms ║║Condition group #30 evaluated false (state changed) (5ms)
+478ms ║║Cancelling statement #22’s schedules…
+489ms ║║Calculating (long) 49328477 + (long) 3333519 >> (long) 52661996
+495ms ║║Executed virtual command [Room Lights].setVariable (3ms)
+502ms ║║Calculating (string) Luz Desligada
+502ms ║║ + (string) Interruptor pressionado >> (string) Luz Desligada
+502ms ║║Interruptor pressionado
+504ms ║║Calculating (string) Luz Desligada
+504ms ║║Interruptor pressionado + (string) 170 >> (string) Luz Desligada
+504ms ║║Interruptor pressionado 170
+506ms ║║Calculating (string) Luz Desligada
+506ms ║║Interruptor pressionado 170 + (string) vezes
+506ms ║║ >> (string) Luz Desligada
+507ms ║║Interruptor pressionado 170 vezes
+508ms ║║Calculating (string) Luz Desligada
+508ms ║║Interruptor pressionado 170 vezes
+508ms ║║ + (string) 14 hours, 37 minutes, and 41 seconds >> (string) Luz Desligada
+509ms ║║Interruptor pressionado 170 vezes
+509ms ║║14 hours, 37 minutes, and 41 seconds
+510ms ║║Executed virtual command [Room Lights].setState (0ms)
+516ms ║╚Execution stage complete. (56ms)
+518ms ║Setting up scheduled job for Sun, Dec 3 2017 @ 7:00:00 PM BRST (in 168806.996s), with 1 more job pending
+534ms ╚Event processed successfully (534ms)
01/12/2017 20:06:32 +172ms
+1ms ╔Received event [Room Lights].switch = on with a delay of 589ms
+164ms ║RunTime Analysis CS > 17ms > PS > 35ms > PE > 113ms > CE
+175ms ║Runtime (41981 bytes) successfully initialized in 35ms (v0.2.0ff.20171129) (173ms)
+176ms ║╔Execution stage started
+182ms ║║Comparison (enum) on changes = true (0ms)
+183ms ║║Condition #2 evaluated true (2ms)
+183ms ║║Condition group #1 evaluated true (state did not change) (3ms)
+185ms ║║Cancelling statement #4’s schedules…
+189ms ║║Calculating (integer) 169 + (integer) 1 >> (integer) 170
+195ms ║║Executed virtual command [Room Lights].setVariable (3ms)
+201ms ║║Comparison (enum) on changes_to (string) on = true (0ms)
+202ms ║║Cancelling condition #33’s schedules…
+202ms ║║Condition #33 evaluated true (4ms)
+203ms ║║Cancelling condition #30’s schedules…
+204ms ║║Condition group #30 evaluated true (state changed) (6ms)
+206ms ║║Cancelling statement #31’s schedules…
+210ms ║║Calculating (string) :bulb: Luz Ligada
+210ms ║║ + (string) Interruptor pressionado >> (string) :bulb: Luz Ligada
+210ms ║║Interruptor pressionado
+212ms ║║Calculating (string) :bulb: Luz Ligada
+213ms ║║Interruptor pressionado + (string) 170 >> (string) :bulb: Luz Ligada
+213ms ║║Interruptor pressionado 170
+215ms ║║Calculating (string) :bulb: Luz Ligada
+215ms ║║Interruptor pressionado 170 + (string) vezes >> (string) :bulb: Luz Ligada
+215ms ║║Interruptor pressionado 170 vezes
+217ms ║║Executed virtual command [Room Lights].setState (1ms)
+223ms ║╚Execution stage complete. (48ms)
+225ms ║Setting up scheduled job for Sun, Dec 3 2017 @ 7:00:00 PM BRST (in 168807.604s), with 1 more job pending
+238ms ╚Event processed successfully (239ms)
01/12/2017 06:24:24 +650ms
+1ms ╔Received event [Room Lights].switch = off with a delay of 153ms
+155ms ║RunTime Analysis CS > 16ms > PS > 13ms > PE > 126ms > CE
+167ms ║Runtime (41861 bytes) successfully initialized in 13ms (v0.2.0ff.20171129) (165ms)
+168ms ║╔Execution stage started
+174ms ║║Comparison (enum) off changes = true (1ms)
+175ms ║║Condition #2 evaluated true (3ms)
+176ms ║║Condition group #1 evaluated true (state did not change) (4ms)
+178ms ║║Cancelling statement #4’s schedules…
+181ms ║║Calculating (integer) 168 + (integer) 1 >> (integer) 169
+186ms ║║Executed virtual command [Room Lights].setVariable (2ms)
+191ms ║║Comparison (enum) off changes_to (string) on = false (0ms)
+192ms ║║Cancelling condition #33’s schedules…
+193ms ║║Condition #33 evaluated false (4ms)
+194ms ║║Cancelling condition #30’s schedules…
+195ms ║║Condition group #30 evaluated false (state changed) (6ms)
+197ms ║║Cancelling statement #22’s schedules…
+207ms ║║Calculating (long) 72802 + (long) 3260717 >> (long) 3333519
+211ms ║║Executed virtual command [Room Lights].setVariable (3ms)
+218ms ║║Calculating (string) Luz Desligada
+218ms ║║ + (string) Interruptor pressionado >> (string) Luz Desligada
+218ms ║║Interruptor pressionado
+220ms ║║Calculating (string) Luz Desligada
+220ms ║║Interruptor pressionado + (string) 169 >> (string) Luz Desligada
+220ms ║║Interruptor pressionado 169
+222ms ║║Calculating (string) Luz Desligada
+222ms ║║Interruptor pressionado 169 + (string) vezes
+222ms ║║ >> (string) Luz Desligada
+222ms ║║Interruptor pressionado 169 vezes
+224ms ║║Calculating (string) Luz Desligada
+224ms ║║Interruptor pressionado 169 vezes
+224ms ║║ + (string) 55 minutes and 33 seconds >> (string) Luz Desligada
+224ms ║║Interruptor pressionado 169 vezes
+224ms ║║55 minutes and 33 seconds
+226ms ║║Executed virtual command [Room Lights].setState (0ms)
+232ms ║╚Execution stage complete. (64ms)
+234ms ║Setting up scheduled job for Sun, Dec 3 2017 @ 7:00:00 PM BRST (in 218135.117s), with 1 more job pending
+251ms ╚Event processed successfully (250ms)


#2

See if this works like you’re expecting. I also changed the Count to increment only when switched on.


#3

Thanks a lot!

I’m goign to test during this week.


#4

Still getting the same problem.

The logs shows that when I turn on the switch, it also runs the turn off event at the same time.

05/12/2017 20:22:24 +629ms
+1ms ╔Received event [Room Lights].switch = off with a delay of 438ms
+103ms ║RunTime Analysis CS > 11ms > PS > 21ms > PE > 71ms > CE
+122ms ║Runtime (41387 bytes) successfully initialized in 21ms (v0.2.0ff.20171129) (119ms)
+122ms ║╔Execution stage started
+128ms ║║Comparison (enum) off changes_to (string) on = false (0ms)
+129ms ║║Condition #33 evaluated false (2ms)
+129ms ║║Condition group #30 evaluated false (state did not change) (4ms)
+131ms ║║Cancelling statement #22’s schedules…
+135ms ║║Executed virtual command [Room Lights].setVariable (2ms)
+139ms ║║Calculating (long) 1512512544761 - (long) 1512462315340 >> (long) 50229421
+141ms ║║Calculating (long) 3679632 + (long) 50229421 >> (long) 53909053
+144ms ║║Executed virtual command [Room Lights].setVariable (2ms)
+153ms ║║Calculating (string) Luz Desligada
+153ms ║║ + (string) Interruptor pressionado >> (string) Luz Desligada
+153ms ║║Interruptor pressionado
+155ms ║║Calculating (string) Luz Desligada
+155ms ║║Interruptor pressionado + (string) 10 >> (string) Luz Desligada
+155ms ║║Interruptor pressionado 10
+156ms ║║Calculating (string) Luz Desligada
+156ms ║║Interruptor pressionado 10 + (string) vezes
+157ms ║║ >> (string) Luz Desligada
+157ms ║║Interruptor pressionado 10 vezes
+158ms ║║Calculating (string) Luz Desligada
+158ms ║║Interruptor pressionado 10 vezes
+158ms ║║ + (string) 14 hours, 58 minutes, and 29 seconds >> (string) Luz Desligada
+158ms ║║Interruptor pressionado 10 vezes
+158ms ║║14 hours, 58 minutes, and 29 seconds
+160ms ║║Executed virtual command [Room Lights].setState (1ms)
+165ms ║╚Execution stage complete. (43ms)
+166ms ║Setting up scheduled job for Sun, Dec 10 2017 @ 7:00:00 PM BRST (in 427055.205s), with 1 more job pending
+181ms ╚Event processed successfully (181ms)
05/12/2017 20:19:24 +605ms
+2ms ╔Received event [Room Lights].switch = on with a delay of 661ms
+391ms ║RunTime Analysis CS > 16ms > PS > 281ms > PE > 93ms > CE
+401ms ║Piston waited at a semaphore for 255ms
+403ms ║Runtime (41320 bytes) successfully initialized in 281ms (v0.2.0ff.20171129) (401ms)
+404ms ║╔Execution stage started
+409ms ║║Comparison (enum) on changes_to (string) on = false (0ms)
+410ms ║║Cancelling condition #33’s schedules…
+411ms ║║Condition #33 evaluated false (4ms)
+412ms ║║Cancelling condition #30’s schedules…
+412ms ║║Condition group #30 evaluated false (state changed) (5ms)
+414ms ║║Cancelling statement #22’s schedules…
+421ms ║║Executed virtual command [Room Lights].setVariable (3ms)
+424ms ║║Calculating (long) 1512512365020 - (long) 1512512364571 >> (long) 449
+426ms ║║Calculating (long) 3679183 + (long) 449 >> (long) 3679632
+430ms ║║Executed virtual command [Room Lights].setVariable (3ms)
+439ms ║║Calculating (string) Luz Desligada
+439ms ║║ + (string) Interruptor pressionado >> (string) Luz Desligada
+439ms ║║Interruptor pressionado
+441ms ║║Calculating (string) Luz Desligada
+441ms ║║Interruptor pressionado + (string) 11 >> (string) Luz Desligada
+441ms ║║Interruptor pressionado 11
+442ms ║║Calculating (string) Luz Desligada
+442ms ║║Interruptor pressionado 11 + (string) vezes
+443ms ║║ >> (string) Luz Desligada
+443ms ║║Interruptor pressionado 11 vezes
+444ms ║║Calculating (string) Luz Desligada
+444ms ║║Interruptor pressionado 11 vezes
+444ms ║║ + (string) 1 hour, 1 minute, and 19 seconds >> (string) Luz Desligada
+444ms ║║Interruptor pressionado 11 vezes
+444ms ║║1 hour, 1 minute, and 19 seconds
+446ms ║║Executed virtual command [Room Lights].setState (1ms)
+451ms ║╚Execution stage complete. (47ms)
+453ms ║Setting up scheduled job for Sun, Dec 10 2017 @ 7:00:00 PM BRST (in 427234.943s), with 1 more job pending
+475ms ╚Event processed successfully (475ms)
05/12/2017 20:19:24 +443ms
+1ms ╔Received event [Room Lights].switch = on with a delay of 600ms
+104ms ║RunTime Analysis CS > 17ms > PS > 12ms > PE > 75ms > CE
+115ms ║Runtime (41387 bytes) successfully initialized in 12ms (v0.2.0ff.20171129) (113ms)
+116ms ║╔Execution stage started
+122ms ║║Comparison (enum) on changes_to (string) on = true (1ms)
+123ms ║║Cancelling condition #33’s schedules…
+124ms ║║Condition #33 evaluated true (3ms)
+124ms ║║Cancelling condition #30’s schedules…
+125ms ║║Condition group #30 evaluated true (state changed) (6ms)
+126ms ║║Cancelling statement #31’s schedules…
+133ms ║║Executed virtual command [Room Lights].setVariable (2ms)
+138ms ║║Calculating (integer) 10 + (integer) 1 >> (integer) 11
+142ms ║║Executed virtual command [Room Lights].setVariable (2ms)
+148ms ║║Calculating (string) :bulb: Luz Ligada
+148ms ║║ + (string) Interruptor pressionado >> (string) :bulb: Luz Ligada
+148ms ║║Interruptor pressionado
+151ms ║║Calculating (string) :bulb: Luz Ligada
+151ms ║║Interruptor pressionado + (string) 11 >> (string) :bulb: Luz Ligada
+151ms ║║Interruptor pressionado 11
+154ms ║║Calculating (string) :bulb: Luz Ligada
+154ms ║║Interruptor pressionado 11 + (string) vezes >> (string) :bulb: Luz Ligada
+154ms ║║Interruptor pressionado 11 vezes
+157ms ║║Executed virtual command [Room Lights].setState (1ms)
+166ms ║╚Execution stage complete. (49ms)
+168ms ║Setting up scheduled job for Sun, Dec 10 2017 @ 7:00:00 PM BRST (in 427235.39s), with 1 more job pending
+183ms ╚Event processed successfully (182ms)
05/12/2017 06:25:40 +30ms
+1ms ╔Received event [Room Lights].switch = off with a delay of 194ms
+102ms ║RunTime Analysis CS > 11ms > PS > 18ms > PE > 72ms > CE
+111ms ║Runtime (41253 bytes) successfully initialized in 18ms (v0.2.0ff.20171129) (109ms)
+112ms ║╔Execution stage started
+118ms ║║Comparison (enum) off changes_to (string) on = false (0ms)
+120ms ║║Cancelling condition #33’s schedules…
+120ms ║║Condition #33 evaluated false (4ms)
+121ms ║║Cancelling condition #30’s schedules…
+122ms ║║Condition group #30 evaluated false (state changed) (6ms)
+123ms ║║Cancelling statement #22’s schedules…
+128ms ║║Executed virtual command [Room Lights].setVariable (2ms)
+133ms ║║Calculating (long) 1512462340155 - (long) 1512462315340 >> (long) 24815
+135ms ║║Calculating (long) 3654368 + (long) 24815 >> (long) 3679183
+139ms ║║Executed virtual command [Room Lights].setVariable (3ms)
+146ms ║║Calculating (string) Luz Desligada
+146ms ║║ + (string) Interruptor pressionado >> (string) Luz Desligada
+146ms ║║Interruptor pressionado
+149ms ║║Calculating (string) Luz Desligada
+149ms ║║Interruptor pressionado + (string) 10 >> (string) Luz Desligada
+149ms ║║Interruptor pressionado 10
+151ms ║║Calculating (string) Luz Desligada
+151ms ║║Interruptor pressionado 10 + (string) vezes
+151ms ║║ >> (string) Luz Desligada
+151ms ║║Interruptor pressionado 10 vezes
+153ms ║║Calculating (string) Luz Desligada
+153ms ║║Interruptor pressionado 10 vezes
+153ms ║║ + (string) 1 hour, 1 minute, and 19 seconds >> (string) Luz Desligada
+153ms ║║Interruptor pressionado 10 vezes
+153ms ║║1 hour, 1 minute, and 19 seconds
+155ms ║║Executed virtual command [Room Lights].setState (1ms)
+161ms ║╚Execution stage complete. (49ms)
+163ms ║Setting up scheduled job for Sun, Dec 10 2017 @ 7:00:00 PM BRST (in 477259.808s), with 1 more job pending
+176ms ╚Event processed successfully (176ms)