Local store not respecting capture only if empty

[tagyoureit]

1) Give a description of the problem
Merry Xmas. I’ve been reading a lot of different community posts about issues with the global and local stores. What I’m seeing is that the “saveStateLocally” is being called even though the variable should have a value and is set to capture values “only if store is empty”. I am able to work around this by assigning a separate value to individual variables but I have other situations with multiple lights and trying to individually save each one will be pretty unwieldy. If I can get this working, it would be very good. Hopefully, I’m just missing something easy.

2) What is the expected behavior?
Expect the “Capture attributes xyz to local state “variable” only if store is empty” not to be updated after it has values. Value are captured during the first event (motion) but then overwritten(?) with the 2nd event (inactivity).

(BTW, yes, I could probably change lines 23 & 25 to just say ‘if motion sensor changes…’)

3) What is happening/not happening?
Per the logs below, the values appear to be saved initially when the motion is detected and then again when the motion inactive event is triggered.

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

**5) Attach any logs

12/25/2018, 10:30:38 PM +135ms
+2ms ╔Received event [Front Door Camera].motion = inactive with a delay of 79ms
+142ms ║RunTime Analysis CS > 26ms > PS > 94ms > PE > 22ms > CE
+144ms ║Runtime (40658 bytes) successfully initialized in 94ms (v0.3.109.20181207) (141ms)
+145ms ║╔Execution stage started
+175ms ║║Comparison (enum) inactive changes_to (string) active = false (1ms)
+178ms ║║Cancelling condition #2's schedules...
+180ms ║║Condition #2 evaluated false (26ms)
+309ms ║║Comparison (enum) inactive changed = false (115ms)
+339ms ║║Comparison (enum) inactive changed = true (29ms)
+342ms ║║Condition #12 evaluated true (161ms)
+343ms ║║Condition group #11 evaluated true (state did not change) (191ms)
+384ms ║║Comparison (time) 81038480 is_between (datetime) 1545785760000 .. (datetime) 1545837600000 = true (9ms)
+386ms ║║Time restriction check passed
+388ms ║║Condition #4 evaluated true (44ms)
+389ms ║║Condition group #1 evaluated true (state did not change) (238ms)
+392ms ║║Cancelling statement #5's schedules...
>>+403ms ║║Executed virtual command [Driveway Lights].saveStateLocally (3ms)<<
>>+412ms ║║Executed virtual command [Front Door Lights].saveStateLocally (5ms)<<
+418ms ║║Skipped execution of physical command [Driveway Lights].on([]) because it would make no change to the device. (4ms)
+419ms ║║Executed [Driveway Lights].on (6ms)
+424ms ║║Skipped execution of physical command [Front Door Lights].on([]) because it would make no change to the device. (2ms)
+425ms ║║Executed [Front Door Lights].on (5ms)
+430ms ║║Executed virtual command [Driveway Lights, Front Door Lights].wait (0ms)
+431ms ║║Requesting a wake up for Tue, Dec 25 2018 @ 10:31:38 PM PST (in 60.0s)
+437ms ║╚Execution stage complete. (292ms)
+439ms ║Setting up scheduled job for Tue, Dec 25 2018 @ 10:31:38 PM PST (in 59.994s)
+451ms ╚Event processed successfully (451ms)

12/25/2018, 10:30:08 PM +486ms
+1ms ╔Received event [Front Door Camera].motion = active with a delay of 78ms
+130ms ║RunTime Analysis CS &gt; 17ms &gt; PS &gt; 78ms &gt; PE &gt; 36ms &gt; CE
+133ms ║Runtime (40659 bytes) successfully initialized in 78ms (v0.3.109.20181207) (131ms)
+134ms ║╔Execution stage started
+158ms ║║Comparison (enum) active changes_to (string) active = true (1ms)
+161ms ║║Cancelling condition #2's schedules...
+162ms ║║Condition #2 evaluated true (22ms)
+163ms ║║Condition group #11 evaluated true (state did not change) (23ms)
+199ms ║║Comparison (time) 81008650 is_between (datetime) 1545785760000 .. (datetime) 1545837600000 = true (9ms)
+200ms ║║Time restriction check passed
+202ms ║║Condition #4 evaluated true (38ms)
+204ms ║║Condition group #1 evaluated true (state did not change) (64ms)
+206ms ║║Cancelling statement #5's schedules...
>>+218ms ║║Executed virtual command [Driveway Lights].saveStateLocally (4ms)<<
>>+223ms ║║Executed virtual command [Front Door Lights].saveStateLocally (3ms)<<
+236ms ║║Executed physical command [Driveway Lights].on() (9ms)
+237ms ║║Executed [Driveway Lights].on (11ms)
+747ms ║║Executed physical command [Front Door Lights].on() (508ms)
+748ms ║║Executed [Front Door Lights].on (511ms)
+752ms ║║Executed virtual command [Driveway Lights, Front Door Lights].wait (1ms)
+754ms ║║Requesting a wake up for Tue, Dec 25 2018 @ 10:31:09 PM PST (in 60.0s)
+759ms ║╚Execution stage complete. (625ms)
+760ms ║Setting up scheduled job for Tue, Dec 25 2018 @ 10:31:09 PM PST (in 59.994s)
+779ms ╚Event processed successfully (780ms)

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

[guxdude]

Since you have a one minute wait and look for one minute of inactivity, is the one minute of inactivity just close enough that it triggers the event a second time before the wait is over? Perhaps change to 2 minutes of inactivity? Another option, you could create a separate Boolean variable to say if data is in the store and should not be overwritten.

[tagyoureit]

@guxdude Yes, thanks. Good thoughts. I simplified my code to eliminate the possibility of any second(ary) trigger.

And these are the resulting logs:

12/25/2018, 11:41:37 PM +135ms
+1ms ╔Received event [Home Hub].time = 1545810098292 with a delay of -1158ms
+185ms ║RunTime Analysis CS > 41ms > PS > 111ms > PE > 34ms > CE
+188ms ║Runtime (40210 bytes) successfully initialized in 111ms (v0.3.109.20181207) (186ms)
+190ms ║╔Execution stage started
+224ms ║║Restoring attribute 'switch' to value 'on' using command on()
+230ms ║║Skipped execution of physical command [Driveway Lights].on([]) because it would make no change to the device. (4ms)
+231ms ║║Executed virtual command [Driveway Lights].loadStateLocally (12ms)
+241ms ║║Restoring attribute 'switch' to value 'on' using command on()
+247ms ║║Skipped execution of physical command [Front Door Lights].on([]) because it would make no change to the device. (4ms)
+249ms ║║Executed virtual command [Front Door Lights].loadStateLocally (15ms)
+253ms ║╚Execution stage complete. (63ms)
+255ms ╚Event processed successfully (255ms)

12/25/2018, 11:40:38 PM +84ms
+1ms ╔Received event [Front Door Camera].motion = inactive with a delay of 59ms
+91ms ║RunTime Analysis CS > 13ms > PS > 57ms > PE > 21ms > CE
+94ms ║Runtime (40209 bytes) successfully initialized in 57ms (v0.3.109.20181207) (92ms)
+95ms ║╔Execution stage started
+119ms ║║Comparison (enum) inactive changes = true (1ms)
+122ms ║║Condition #2 evaluated true (20ms)
+123ms ║║Condition group #11 evaluated true (state did not change) (21ms)
+160ms ║║Comparison (time) 85238209 is_between (datetime) 1545785760000 .. (datetime) 1545837600000 = true (11ms)
+162ms ║║Time restriction check passed
+164ms ║║Condition #4 evaluated true (40ms)
+166ms ║║Condition group #1 evaluated true (state did not change) (65ms)
+170ms ║║Cancelling statement #5's schedules...
+181ms ║║Executed virtual command [Driveway Lights].saveStateLocally (4ms)
+188ms ║║Executed virtual command [Front Door Lights].saveStateLocally (4ms)
+193ms ║║Skipped execution of physical command [Driveway Lights].on([]) because it would make no change to the device. (3ms)
+195ms ║║Executed [Driveway Lights].on (5ms)
+200ms ║║Skipped execution of physical command [Front Door Lights].on([]) because it would make no change to the device. (2ms)
+201ms ║║Executed [Front Door Lights].on (5ms)
+205ms ║║Executed virtual command [Driveway Lights, Front Door Lights].wait (1ms)
+207ms ║║Requesting a wake up for Tue, Dec 25 2018 @ 11:41:38 PM PST (in 60.0s)
+213ms ║╚Execution stage complete. (118ms)
+215ms ║Setting up scheduled job for Tue, Dec 25 2018 @ 11:41:38 PM PST (in 59.994s)
+225ms ╚Event processed successfully (225ms)

12/25/2018, 11:40:09 PM +41ms
+1ms ╔Received event [Front Door Camera].motion = active with a delay of 85ms
+136ms ║RunTime Analysis CS > 18ms > PS > 78ms > PE > 40ms > CE
+138ms ║Runtime (40212 bytes) successfully initialized in 78ms (v0.3.109.20181207) (136ms)
+139ms ║╔Execution stage started
+165ms ║║Comparison (enum) active changes = true (1ms)
+167ms ║║Cancelling condition #2's schedules...
+168ms ║║Condition #2 evaluated true (22ms)
+170ms ║║Cancelling condition #11's schedules...
+171ms ║║Condition group #11 evaluated true (state changed) (26ms)
+210ms ║║Comparison (time) 85209213 is_between (datetime) 1545785760000 .. (datetime) 1545837600000 = true (8ms)
+211ms ║║Time restriction check passed
+213ms ║║Condition #4 evaluated true (41ms)
+215ms ║║Cancelling condition #1's schedules...
+216ms ║║Condition group #1 evaluated true (state changed) (70ms)
+218ms ║║Cancelling statement #5's schedules...
+230ms ║║Executed virtual command [Driveway Lights].saveStateLocally (3ms)
+236ms ║║Executed virtual command [Front Door Lights].saveStateLocally (3ms)
+243ms ║║Skipped execution of physical command [Driveway Lights].on([]) because it would make no change to the device. (4ms)
+244ms ║║Executed [Driveway Lights].on (6ms)
+335ms ║║Executed physical command [Front Door Lights].on() (89ms)
+336ms ║║Executed [Front Door Lights].on (91ms)
+341ms ║║Executed virtual command [Driveway Lights, Front Door Lights].wait (0ms)
+342ms ║║Requesting a wake up for Tue, Dec 25 2018 @ 11:41:09 PM PST (in 60.0s)
+348ms ║╚Execution stage complete. (209ms)
+350ms ║Setting up scheduled job for Tue, Dec 25 2018 @ 11:41:09 PM PST (in 59.994s)
+363ms ╚Event processed successfully (363ms) 

Essentially,
a) I don’t care about the exact timing of the light going off. I’m trying to find a situation where a piston can run multiple times and still store the original state. (Think about multiple motion sensors all going off and triggering this same type of flow).
b) The flow reads (to me) like this:

1. Motion: Run the piston and save the state
2. Inactivity (cancel previous execution): Run the piston and save the state
   2a. Wait 1 minute and then restore state

Per your second suggestion, this does work. Code/logs below. It is good to know that the save/restore states will work in some applications. However, the code will become pretty hard to get the right logic and debug with many devices in a more complex scenario. This small example goes from 1 variable and 7 lines of code in 2 blocks (just above) to 2 variables in 13 lines of code in 3 blocks. This is an improvement upon the 1 variable for each device but confirms (I think?) that there is a bug with the “only if state is empty” part of the application.

12/26/2018, 12:07:15 AM +126ms
+1ms ╔Received event [Home Hub].time = 1545811636431 with a delay of -1305ms
+173ms ║RunTime Analysis CS > 23ms > PS > 106ms > PE > 44ms > CE
+176ms ║Runtime (41971 bytes) successfully initialized in 106ms (v0.3.109.20181207) (174ms)
+177ms ║╔Execution stage started
+217ms ║║Restoring attribute 'switch' to value 'on' using command on()
+223ms ║║Skipped execution of physical command [Driveway Lights].on([]) because it would make no change to the device. (3ms)
+225ms ║║Executed virtual command [Driveway Lights].loadStateLocally (14ms)
+236ms ║║Restoring attribute 'switch' to value 'off' using command off()
+1918ms ║║Executed physical command [Front Door Lights].off() (1679ms)
+1919ms ║║Executed virtual command [Front Door Lights].loadStateLocally (1690ms)
+1928ms ║║Executed virtual command [Driveway Lights, Front Door Lights].setVariable (4ms)
+1933ms ║╚Execution stage complete. (1755ms)
+1935ms ╚Event processed successfully (1935ms)

12/26/2018, 12:06:16 AM +169ms
+2ms ╔Received event [Front Door Camera].motion = inactive with a delay of 83ms
+152ms ║RunTime Analysis CS > 21ms > PS > 97ms > PE > 34ms > CE
+154ms ║Runtime (41973 bytes) successfully initialized in 97ms (v0.3.109.20181207) (151ms)
+156ms ║╔Execution stage started
+181ms ║║Comparison (enum) inactive changes = true (1ms)
+184ms ║║Condition #2 evaluated true (20ms)
+185ms ║║Condition group #11 evaluated true (state did not change) (23ms)
+230ms ║║Comparison (time) 376355 is_between (datetime) 1545872220000 .. (datetime) 1545837600000 = true (9ms)
+231ms ║║Time restriction check passed
+234ms ║║Condition #4 evaluated true (47ms)
+235ms ║║Condition group #1 evaluated true (state did not change) (73ms)
+243ms ║║Comparison (dynamic) set is_not (string) set = false (2ms)
+245ms ║║Cancelling condition #24's schedules...
+246ms ║║Condition #24 evaluated false (8ms)
+247ms ║║Cancelling condition #23's schedules...
+249ms ║║Condition group #23 evaluated false (state changed) (11ms)
+252ms ║║Cancelling statement #25's schedules...
+259ms ║║Executed virtual command [Driveway Lights, Front Door Lights].wait (1ms)
+261ms ║║Requesting a wake up for Wed, Dec 26 2018 @ 12:07:16 AM PST (in 60.0s)
+268ms ║╚Execution stage complete. (112ms)
+270ms ║Setting up scheduled job for Wed, Dec 26 2018 @ 12:07:16 AM PST (in 59.993s)
+281ms ╚Event processed successfully (281ms)

12/26/2018, 12:05:46 AM +591ms
+2ms ╔Received event [Front Door Camera].motion = active with a delay of 81ms
+147ms ║RunTime Analysis CS > 17ms > PS > 82ms > PE > 48ms > CE
+150ms ║Runtime (41980 bytes) successfully initialized in 82ms (v0.3.109.20181207) (147ms)
+151ms ║╔Execution stage started
+178ms ║║Comparison (enum) active changes = true (1ms)
+180ms ║║Cancelling condition #2's schedules...
+182ms ║║Condition #2 evaluated true (23ms)
+183ms ║║Cancelling condition #11's schedules...
+184ms ║║Condition group #11 evaluated true (state changed) (27ms)
+225ms ║║Comparison (time) 346777 is_between (datetime) 1545872220000 .. (datetime) 1545837600000 = true (9ms)
+227ms ║║Time restriction check passed
+229ms ║║Condition #4 evaluated true (43ms)
+230ms ║║Cancelling condition #1's schedules...
+231ms ║║Condition group #1 evaluated true (state changed) (74ms)
+239ms ║║Comparison (dynamic) 'notset' is_not (string) set = true (2ms)
+241ms ║║Condition #24 evaluated true (7ms)
+242ms ║║Condition group #23 evaluated true (state did not change) (8ms)
+245ms ║║Cancelling statement #5's schedules...
+255ms ║║Executed virtual command [Driveway Lights, Front Door Lights].setVariable (4ms)
+264ms ║║Executed virtual command [Driveway Lights].saveStateLocally (4ms)
+270ms ║║Executed virtual command [Front Door Lights].saveStateLocally (3ms)
+276ms ║║Skipped execution of physical command [Driveway Lights].on([]) because it would make no change to the device. (2ms)
+277ms ║║Executed [Driveway Lights].on (4ms)
+297ms ║║Executed physical command [Front Door Lights].on() (18ms)
+298ms ║║Executed [Front Door Lights].on (20ms)
+303ms ║║Executed virtual command [Driveway Lights, Front Door Lights].wait (1ms)
+305ms ║║Requesting a wake up for Wed, Dec 26 2018 @ 12:06:46 AM PST (in 60.0s)
+311ms ║╚Execution stage complete. (160ms)
+313ms ║Setting up scheduled job for Wed, Dec 26 2018 @ 12:06:46 AM PST (in 59.994s)
+322ms ╚Event processed successfully (322ms)