Check and notify locks locked

Nola_BoB · 2020-07-15 17:26:33 UTC

I have a piston that is supposed to check if my doors are locked. It keeps notifying us that they are not locked, yet they are. Does anyone have any ideas?

7/15/2020, 2:13:12 AM +604ms
+11ms	╔Received event [Home].time = 1594797192415 with a delay of 189ms, canQueue: true, calledMyself: false
+182ms	║RunTime initialize > 180 LockT > 1ms > rtDataT > 3ms > pistonT > 2ms (first state access 176 12 168)
+188ms	║Runtime (8253 bytes) successfully initialized in 3ms (v0.3.110.20200210_HE)
+192ms	║╔Execution stage started
+273ms	║║Executed physical command [Lock 1].refresh() (59ms)
+275ms	║║Executed [Lock 1].refresh (63ms)
+314ms	║║Executed physical command [Lock 2].refresh() (32ms)
+315ms	║║Executed [Lock 2].refresh (36ms)
+360ms	║║Executed physical command [Lock 3].refresh() (36ms)
+362ms	║║Executed [Lock 3].refresh (39ms)
+405ms	║║Comparison (enum) unlocked is_not (string) locked = true (4ms)
+411ms	║║Comparison (enum) locked is_not (string) locked = false (4ms)
+417ms	║║Comparison (enum) unlocked is_not (string) locked = true (4ms)
+423ms	║║Condition #8 evaluated true (56ms)
+426ms	║║Condition group #7 evaluated true (state did not change) (58ms)
+434ms	║║Cancelling statement #10's schedules...
+450ms	║║Calculating (string)Lock 1 + (string) was not locked. >> (string)Lock 1 was not locked.
+958ms	║║Executed virtual command sendPushNotification (498ms)
+975ms	║║Cancelling statement #10's schedules...
+992ms	║║Calculating (string)Lock 3 + (string) was not locked. >> (string)Lock 3 was not locked.
+1144ms	║║Executed virtual command sendPushNotification (143ms)
+1152ms	║║Cancelling statement #13's schedules...
+1163ms	║╚Execution stage complete. (970ms)
+1215ms	╚Event processed successfully (1212ms)
7/15/2020, 2:12:52 AM +168ms
+14ms	╔Received event [Home].time = 1594797171748 with a delay of 420ms, canQueue: true, calledMyself: false
+186ms	║RunTime initialize > 184 LockT > 0ms > rtDataT > 4ms > pistonT > 2ms (first state access 180 14 170)
+191ms	║Runtime (8248 bytes) successfully initialized in 4ms (v0.3.110.20200210_HE)
+195ms	║╔Execution stage started
+214ms	║║Cancelling statement #15's schedules...
+243ms	║║Executed virtual command [Lock 1, Lock 2, Lock 3].wait (1ms)
+247ms	║║Requesting a wake up for Wed, Jul 15 2020 @ 2:13:12 AM CDT (in 20s)
+256ms	║╚Execution stage complete. (60ms)
+260ms	║Setting up scheduled job for Wed, Jul 15 2020 @ 2:13:12 AM CDT (in 20s)
+371ms	╚Event processed successfully (368ms)
7/15/2020, 2:09:56 AM +509ms
+72ms	╔Received event [Switch26].switch = off with a delay of 417ms, canQueue: true, calledMyself: false
+405ms	║RunTime initialize > 402 LockT > 4ms > rtDataT > 4ms > pistonT > 2ms (first state access 394 76 326)
+411ms	║Runtime (8236 bytes) successfully initialized in 4ms (v0.3.110.20200210_HE)
+414ms	║╔Execution stage started
+428ms	║║Comparison (string) :80ff8adc87cc6d0d790b1bb31708f282: changes_to (string) :db51cd17b1529242205547665623a183: = false (1ms)
+437ms	║║Condition #2 evaluated false (16ms)
+448ms	║║Comparison (enum) off changes_to (string) on = false (1ms)
+451ms	║║Cancelling condition #3's schedules...
+455ms	║║Condition #3 evaluated false (14ms)
+458ms	║║Cancelling condition #1's schedules...
+461ms	║║Condition group #1 evaluated false (state changed) (40ms)
+474ms	║╚Execution stage complete. (60ms)
+479ms	║Setting up scheduled job for Wed, Jul 15 2020 @ 2:12:51 AM CDT (in 175s)
+718ms	╚Event processed successfully (715ms)
7/15/2020, 2:09:51 AM +420ms
+13ms	╔Received event [Switch26].switch = on with a delay of 375ms, canQueue: true, calledMyself: false
+254ms	║RunTime initialize > 251 LockT > 0ms > rtDataT > 3ms > pistonT > 2ms (first state access 248 14 237)
+260ms	║Runtime (8236 bytes) successfully initialized in 3ms (v0.3.110.20200210_HE)
+262ms	║╔Execution stage started
+276ms	║║Comparison (string) :80ff8adc87cc6d0d790b1bb31708f282: changes_to (string) :db51cd17b1529242205547665623a183: = false (1ms)
+279ms	║║Condition #2 evaluated false (11ms)
+290ms	║║Comparison (enum) on changes_to (string) on = true (1ms)
+294ms	║║Cancelling condition #3's schedules...
+297ms	║║Condition #3 evaluated true (15ms)
+300ms	║║Cancelling condition #1's schedules...
+303ms	║║Condition group #1 evaluated true (state changed) (34ms)
+308ms	║║Condition group #4 evaluated true (state did not change) (2ms)
+312ms	║║Cancelling statement #5's schedules...
+323ms	║║Executed virtual command wait (2ms)
+327ms	║║Requesting a wake up for Wed, Jul 15 2020 @ 2:12:51 AM CDT (in 180s)
+345ms	║╚Execution stage complete. (83ms)
+350ms	║Setting up scheduled job for Wed, Jul 15 2020 @ 2:12:51 AM CDT (in 180s)
+686ms	╚Event processed successfully (684ms)
7/15/2020, 2:09:14 AM +457ms
+104ms	╔Received event [Switch26].switch = off with a delay of 866ms, canQueue: true, calledMyself: false
+634ms	║RunTime initialize > 631 LockT > 0ms > rtDataT > 4ms > pistonT > 2ms (first state access 627 105 526)
+661ms	║Runtime (8234 bytes) successfully initialized in 4ms (v0.3.110.20200210_HE)
+664ms	║╔Execution stage started
+698ms	║║Comparison (string) :80ff8adc87cc6d0d790b1bb31708f282: changes_to (string) :db51cd17b1529242205547665623a183: = false (1ms)
+702ms	║║Condition #2 evaluated false (27ms)
+724ms	║║Comparison (enum) off changes_to (string) on = false (1ms)
+740ms	║║Condition #3 evaluated false (36ms)
+744ms	║║Condition group #1 evaluated false (state did not change) (69ms)
+756ms	║╚Execution stage complete. (93ms)
+770ms	║Setting up scheduled job for Wed, Jul 15 2020 @ 2:12:09 AM CDT (in 174s)
+945ms	╚Event processed successfully (942ms)
7/15/2020, 2:09:10 AM +225ms
+48ms	╔Received event [Home].mode = Night with a delay of 1209ms, canQueue: true, calledMyself: false
+744ms	║RunTime initialize > 741 LockT > 0ms > rtDataT > 20ms > pistonT > 18ms (first state access 721 49 692)
+773ms	║Runtime (8217 bytes) successfully initialized in 20ms (v0.3.110.20200210_HE)
+775ms	║╔Execution stage started
+832ms	║║Comparison (string) :80ff8adc87cc6d0d790b1bb31708f282: changes_to (string) :db51cd17b1529242205547665623a183: = false (1ms)
+848ms	║║Condition #2 evaluated false (45ms)
+909ms	║║Cancelling condition #3's schedules...
+917ms	║║Condition #3 evaluated false (61ms)
+930ms	║║Cancelling condition #1's schedules...
+933ms	║║Condition group #1 evaluated false (state changed) (129ms)
+948ms	║╚Execution stage complete. (172ms)
+954ms	║Setting up scheduled job for Wed, Jul 15 2020 @ 2:12:09 AM CDT (in 178s)
+1197ms	╚Event processed successfully (1195ms)
7/15/2020, 2:09:08 AM +785ms
+20ms	╔Received event [Switch26].switch = on with a delay of 404ms, canQueue: true, calledMyself: false
+536ms	║RunTime initialize > 517 LockT > 1ms > rtDataT > 29ms > pistonT > 5ms (first state access 487 21 496)
+557ms	║Runtime (8209 bytes) successfully initialized in 29ms (v0.3.110.20200210_HE)

WCmore · 2020-07-15 17:41:43 UTC

Let’s see what we have here:

2:09:51 AM = [Switch26].switch = on (Requesting a wake up for 2:12:51 AM (in 180s))
2:09:56 AM = [Switch26].switch = off (nothing happened, as expected)
2:12:52 AM = [Home].time (nothing happened, Requesting a wake up for 2:13:12 AM (in 20s))
2:13:12 AM = [Home].time (a split sec after the Refresh, Lock 1 & Lock 3 was seen as not locked)

I think the main thing is, you’ll want to move the 20 sec wait after the Refresh command.
(this (hopefully) allows for enough time for the slow locks to update)

Side Note:

I am very surprised that this logic has not given you any problem:

(how can an empty IF be true?)

guxdude · 2020-07-15 18:06:19 UTC

That is interesting. If trace was turned on it would be interesting to see which evaluation group that was. The empty if must always evaluate true somehow.

Nola_BoB · 2020-07-15 18:21:36 UTC

Thanks! i didn’t see that. I cleaned it up and re-arranged the refresh. The problem is my door locks, but the device never says locked…grr August locks!

WCmore · 2020-07-15 19:15:58 UTC

Unfortunately, this is common with most brands of locks…
(I suspect it is due to the safety checks in place)

For example, if the lock pushes in 99% of the way, the DH will often say it is unlocked, since technically, it has not fully seated itself.

Personally, if I had to choose between which false alarm is best, I would rather be told:

Door is unlocked (when it isn’t)… instead of:
Door is locked (when it isn’t)

From a safety standpoint, it makes sense for door locks to error on the side of caution…
(although I suspect their motivation was to prevent litigation)