Dimmer level value "stuck" when read back?

#1

1) Give a description of the problem
I have a piston in which a dimmer level seems to be stuck when read back, causing the piston to not work properly. By stuck I mean the same value is read, regardless of value I set the dimmer to.

2) What is the expected behavior?
The piston is a simple occupancy and light auto-on routine. In it, I read back the level of a dimmer to check if it is the same as it was (earlier in the piston) set to, in part to determine occupancy state. If no one has changed the dimmer level, I expect that the same level it was set to by the piston should be read-back.

3) What is happening/not happening?
The condition test in line 47 of the piston is always failing, with the level of the dimmer (“White Bulb 11”) always being read as the value 78. That value can be shown in the log at 245ms, output by the console log command that I added to check the value. Regardless of the level I set the dimmer to (current piston has 75, I’ve used several in testing) the level read back seems to be stuck at 78.

Any ideas why that might be? Or workarounds? (I"ve tried recreating the piston, and the new version exhibits the same behavior).

I’m basically trying to check that no change has been made to the dimmer’s state as part of my occupancy testing. (Yes I am aware of the room occupancy DTH, but don’t want to use that for this simple thing).
I could have used the physical vs programmatic interaction qualifier to help, but that is apparently broken in ST now.

4) Post a Green Snapshot of the pistonimage

download
download.png1178×1143 127 KB

5) Attach any logs (From ST IDE and by turning logging level to Full)
11/17/2018, 7:59:56 AM +52ms
+1ms ╔Received event [HayekHome].time = 1542470397875 with a delay of -1824ms
+198ms ║RunTime Analysis CS > 18ms > PS > 161ms > PE > 19ms > CE
+200ms ║Runtime (43668 bytes) successfully initialized in 161ms (v0.3.108.20180906) (198ms)
+202ms ║╔Execution stage started
+233ms ║║MR LIGHT LEVEL IS…
+234ms ║║Executed virtual command [Media Room Ceiling Lights].log (1ms)
+245ms ║║78
+246ms ║║Executed virtual command [Media Room Ceiling Lights].log (1ms)
+260ms ║║Comparison (integer) 78 is_equal_to (integer) 75 = false (2ms)
+262ms ║║Condition #31 evaluated false (12ms)
+264ms ║║Condition group #30 evaluated false (state did not change) (14ms)
+274ms ║║Condition #37 evaluated false (6ms)
+276ms ║║Condition group #36 evaluated false (state did not change) (8ms)
+278ms ║╚Execution stage complete. (77ms)
+280ms ╚Event processed successfully (280ms)

#2

Any time you define a variable up top in the “define” section, then that number will be written each time the piston fires. If you want the autoLevel variable to be flexible or adjustable, you need to not define it up top.

Like this

temp

#3

I understand. I don’t need that variable to be flexible, it can be defined statically in the piston.
My issue is that the level value being read back from the dimmer itself is stuck to some odd value (78), which is not what I had written to the dimmer (75 in this piston example).

#4

That is odd. I have never seen that before. My first thought is: it sounds like the Device Handler. Can you confirm that 75 is always read back as 78? If that is true, then we can easily work around your DH bug.

#5

Agree on the oddity. I am using the standard Zwave DTH for dimmers, and its a Leviton dimmer.
I have tried setting several different levels (75, 52, couple of others) and in each case the level reported back is 78. So it seems unrelated to the level that I choose to set.

The light level does actually track the level I set, i.e. 75 is brighter than 52.

I think (don’t recall for sure) that the first time I created and ran this piston I used the value of “78” for the level I set the dimmer switch to… I was thinking that somehow that value got stuck somewhere in the WC piston domain, hence my experiment to create a new/different piston… but the same 78 appeared there again.

Maybe a hard (airgap) reset of the switch? I can’t image that the value is really stuck in the physical switch device though.

#6

Definitely strange if this is a new piston. There has been times in the past where one of my variables seemed stuck at my first position. My only solution was to create a new variable with a new name to “unstick” it.

In your case, you said you wanted a static number though, so as long as the light is turning to the right level, this would not help you.

You could do a quick test on your Device Handler by importing this piston, and then hitting ‘Test’

temp

If the test is successful, you will see this in your logs afterwards:

temp

#7

Here’s the log, which shows stale value for the first level set.

11/17/2018, 12:42:06 PM +169ms
+1ms	╔Received event [HayekHome].test = 1542487326168 with a delay of 1ms
+1204ms	║78
+4237ms	║50
+7270ms	║75
+7276ms	╚Event processed successfully (7276ms)

I then did a hard (air gap) reset on the physical switch, and ran the test piston a few times…
usually the first value is wrong, others are correct… but not always.

11/17/2018, 12:46:20 PM +800ms
+0ms	╔Received event [HayekHome].test = 1542487580799 with a delay of 0ms
+1202ms	║78
+4234ms	║50
+7267ms	║75
+7273ms	╚Event processed successfully (7274ms)
11/17/2018, 12:45:56 PM +187ms
+1ms	╔Received event [HayekHome].test = 1542487556187 with a delay of 0ms
+1194ms	║78
+4227ms	║78
+7259ms	║78
+7262ms	╚Event processed successfully (7262ms)
11/17/2018, 12:45:20 PM +460ms
+1ms	╔Received event [HayekHome].test = 1542487520460 with a delay of 0ms
+1196ms	║34
+4229ms	║50
+7260ms	║75
+7264ms	╚Event processed successfully (7264ms)

Next I changed the test piston to use a different dimmer switch of the same type, and retested… value of 75 was always reported as 1st level… (log below). So the problem doesn’t seem related to the physical switch itself.

11/17/2018, 1:14:01 PM +972ms
+1ms	╔Received event [HayekHome].test = 1542489241971 with a delay of 1ms
+1174ms	║75
+4205ms	║50
+7238ms	║75
+7244ms	╚Event processed successfully (7244ms)
1    1/17/2018, 1:13:29 PM +425ms
    +1ms	╔Received event [HayekHome].test = 1542489209424 with a delay of 0ms
+1164ms	║75
+4199ms	║50
+7231ms	║75
+7234ms	╚Event processed successfully (7234ms)
11/17/2018, 1:13:16 PM +515ms
+1ms	╔Received event [HayekHome].test = 1542489196515 with a delay of 0ms
+1172ms	║75
+4202ms	║50
+7233ms	║75
+7239ms	╚Event processed successfully (7238ms)
#8

I have a few thoughts…

(1) It might be your DH takes a few moments to register the new level.
(this could explain the first number being innacurate.)
You could increase the waits to test this theory

(2) Is there a possibility that another piston is setting the level to 78?
(although this would not explain the 34 in your 12:45:20 test)

(3) Great idea to test this with another dimmer! Do you have a third dimmer that is not Leviton to test again?

With all the info I have so far, my hunch is #1 above, but #2 would also cause issues.

#9

It really sounds like a Device Handler issue…

Is there anyone else around willing to throw some ideas out?

#10

I tried a non-Leviton dimmer – same odd behavior resulted.

I then played with the wait values, and if I increase them to 10sec before reading the level, the levels are correct. So it appears the DH takes an unexpectedly long tie to register the values.

But that doesn’t really explain the problem in my original piston, since I had a ~1minute wait from the time I set the dimmer level until the read back (during conditional test) happened… 1minute could not be from just a settling time delay in the DH.

I am using the stock Zwave dimmer DH.

#11

Just to clarify, the 1 minute wait does not even begin until your device has turned inactive. Depending on your motion sensor, this could be up to 4 minutes after you’ve left the room.

I usually code your lines 36-45 this way:

IF Motion Sensor's motion stays inactive for 1 minute
    Then with Location, Log to console
END IF

The logic is:
Both the Wait & Log to console commands are built-in, so there’s no need to use a specific device for those commands. (I am trying to rule out all possibilities) Also, this method drops the wait entirely, since the 1 minute is built into the IF statement.

#12

Appreciate the coding tips. This particular motion sensor takes less than a minute to turn inactive.

I tried changing the DH from the “Z-Wave Dimmer Switch Generic” to the “dimmer switch” DH (both standard ST ones) on the non-Leviton dimmer. BOTH exhibited the buggy level read-back behavior. When I increased the delay to about 6s I could get a fairly reliable read-back of the value. So if there is a DH bug, it is not specific to the one DH (of course one may’ve been the starting point to the other DH, propagating any bug present in the original).

But I’m still puzzled of why my original piston shows the problem given it had a minute wait prior to the read-back.

Any other ideas for tests? If there is DH problem, do you happen to know where I submit a bug report to ST?

Thanks!

#13

I have a hunch if the wait was removed, the issue would go away.
Essentially, change lines 36-45 from your first post to this:

IF Motion Sensor's motion stays inactive for 1 minute
    Then with Location, Log to console
END IF

Notice I also changed
With White Bulb 11
to
With Location

#14

Your hunch was right. Below is the version that now seems to work correctly, at least in terms of reading back the expected level that was set. Not clear that I tripped on a bug or just odd behavior, at least if anyone else runs into it this might help them. Thanks for the assistance!

download
download.png1178×1088 209 KB

#15

I am working on a house right now, and when we set a global, followed by a wait, it was not setting the global properly. (so it’s not just you)