When toggling relay of ZEN16, reported currentValue ends up not being targetValue

[thespooler]

Describe the bug

When toggling a relay of a Zooz ZEN16, currentValue gets misreported at some point. It first gets the correct value then changes to the wrong value. ie. Toggling targetValue cause currentValue to toggle as expected reflecting the actual state of the relay, but will then toggle again, thus reporting currentValue incorrectly. The physical relay actually only switches once. To actually toggle the state and report the correct value, the targetValue needs to be clicked twice (without toggling, just the same value).

In attached log file,

22:15:45.027 DRIVER » [Node 010] [REQ] [SendData]
                      │ transmit options: 0x25
                      │ callback id:      86
                      └─[MultiChannelCCCommandEncapsulation]
                        │ source:      0
                        │ destination: 1
                        └─[BinarySwitchCCSet]
                            target value: true
...
22:15:45.058 CNTRLR   [Node 010] [~] [Binary Switch] currentValue: false => true        [Endpoint 1]
...
22:15:45.132 CNTRLR   [Node 010] [~] [Binary Switch] currentValue: true => true         [Endpoint 1]
...
22:15:45.135 DRIVER « [Node 010] [REQ] [ApplicationCommand]
                      └─[MultiChannelCCCommandEncapsulation]
                        │ source:      1
                        │ destination: 0
                        └─[BinarySwitchCCReport]
                            current value: true
...
22:15:46.062 DRIVER » [Node 010] [REQ] [SendData]
                      │ transmit options: 0x25
                      │ callback id:      87
                      └─[MultiChannelCCCommandEncapsulation]
                        │ source:      0
                        │ destination: 1
                        └─[BinarySwitchCCGet]
22:15:46.113 CNTRLR   [Node 010] [~] [Binary Switch] currentValue: true => false        [Endpoint 1]
...
22:15:46.117 DRIVER « [Node 010] [REQ] [ApplicationCommand]
                      └─[MultiChannelCCCommandEncapsulation]
                        │ source:      1
                        │ destination: 0
                        └─[BinarySwitchCCReport]
                            current value: false

Only one BinarySwitchCCSet is sent. Switching the relays with the physical switches do correctly report the currentValue.

Device information

Zooz ZEN16 Multirelay Node 10 This is a device with 3 relays and 3 switches, my switches are configured as [10-112-0-2] Switch Type for Relay 1 (Sw1): Toggle switch (follow switch). This did not occur with ozw.

Last Known Working Configuration

• [ ] New device

• [ ] Previously working device (node-zwave-js)

  • Which library version/docker image/adapter version?
  • Have you made any recent configuration changes to the device? Describe.

• [x] Previously working device (other platform)

  • ozw
  • Have you made any recent configuration changes to the device? No

Installation information How did you install node-zwave-js?

• [x] zwavejs2mqtt (latest) docker image
• [ ] zwavejs2mqtt (dev) docker image
• [ ] ioBroker.zwave2 adapter
• [ ] Pkg
• [ ] Manual Docker build
  • node-zwave-js branch:
  • zwavejs2mqtt branch:
• [ ] Manually built (as described in the docs)
• [ ] Other:

To Reproduce Steps to reproduce the behavior:

1. Go to 'Control Panel'
2. Select node
3. Expand Binary Switch
4. Toggle targetValue. currentValue will then report the current value, before switching a second time.

Additional context Add any other context about the problem here.

Logfile: zwavejs_1.log

[AlCalzone]

According to your log, the device first reports the correct status on its own when it reacts to the SET command. When we verify the SET change after one second, it however tells us the wrong status. If I was you, I'd report this to the manufacturer - this is clearly something the device does wrong.

Your problem however shouldn't happen anymore after https://github.com/zwave-js/node-zwave-js/issues/1532 is solved. Then, the verification with BinarySwitchCCGet won't be done, so you won't get the wrong status reported.

[GrizzlyAK]

I am seeing this EXACT behavior with this device right now (actually two of them I've just added to my network) on the zwave 1.4 integration which uses the OZW 1.4 library. That points to a HW issue, I would think. I will report to Zooz as well. I've a pretty good relationship with them, as I own a LOT of Zooz products.

After reading #1532 I'm not sure the solution as described will solve this particular problem, if I'm understanding what the fix does. It sounds like that you will decide NOT to do a poll if you receive an update following a set. But the problem I'm seeing with my device is a BinarySwitch report showing the CORRECT state, followed by a second BinarySwitch report showing the WRONG state, which gives the application the opposite impression of the true state. And, it appears to be random as to when I receive that spurious second report.

[AlCalzone]

I'm going to mark this as "cannot fix", since it is ultimately a misbehaving device. @thespooler That being said, you should monitor #1532 since that should resolve the problem for you, whether Zooz fixes the firmware or not.

[thespooler]

Thanks @AlCalzone, I'll do as @GirzzlyAK and get in touch with Zooz in case they can provide a FW update for this.

[GrizzlyAK]

I’m in touch with Zooz and their initial response was to try upgrading to zwavejs and see if that fixed it. Being on OZW 1.4 in HA, that’s not an easy feat for me. But I think this issue report (which I sent them) is a good indication that it doesn’t work here either. I’ve asked that their engineers assess the situation.

[GrizzlyAK]

An update: As expected, sadly, Zooz claims that it is an issue with HA since they say it works on other hubs, and they'd reach out to HA zwave team(s) to see if it could be fixed with a FW update or in HA. I've tested the ZEN16 alongside the ZEN20, which is a similar type switch (master sw, encapsulating additional endpoint sws). Looking at the logs, the traffic in OZW 1.4 is almost identical, same classes, same calls, etc., but slightly different order, and except for the random report that indicates the WRONG state for the ZEN16, they are the same. Hard for me to see how that's not a FW problem (but I'm still learning zwave). I've passed along these thoughts to them in addition to detailed logs. We'll see.

[AlCalzone]

So if they are reaching out to HA, they'll effectively end up here - let's wait 😅

I can't say I agree with the assessment.

[zwave-js-assistant[bot]]

This issue has not seen any recent activity and was marked as "cannot fix ❌". Closing for housekeeping purposes... 🧹

Feel free to reopen if the issue persists.

[blhoward2]

Looks like my ZEN16 does this too. Weird it never bothered ozw. Boo

[thespooler]

Yeah, and Zooz doesn't seem to be that bothered to help either. I've had great initial contact with their support, but nothing real except this:

It looks like this may be an issue with HA and how the associations are made and interpreted when the device is first added, since the unit displays correctly for us in other hub platforms. We'll need to consult with the HA developers here to see if this is something that can be addressed with a firmware update or on HA's side. We'll reach out with an update once we know more.

The support team is informed that this issue exists and as you see they claim they'll be in touch with HA team... aaaanytime now...

[blhoward2]

I swear this used to work fine with zwave2jsmqtt. No way my fireplace was always going out of sync. @AlCalzone could this be the result of the fix for the dimmers toggling or something?

[AlCalzone]

The difference with OZW is that OZW polled immediately (which probably also returned the old value) and then the unsolicited update reported the correct value. This might also explain why @blhoward2 is seeing this now. zwave-js used to do the same, but now polls delayed.

[blhoward2]

Can we add a compat flag to disable polling at all? It seems to report the correct state on its own immediately, right? Because it gets the right state and then loses it.

[thespooler]

That's still wrong tho. The reported state IS bad. Period. If you manually query the device state, you get the invalid state, only the first "instant" response is the correct state.

[blhoward2]

Ha, interesting. You can fix this behavior by changing the parameter to normally closed.

[blhoward2]

@thespooler Can you test this? Set the parameter for normally opened/closed (so param 21 for relay 1) to Normally closed, reports off when is on. And see if it fixes it?

I verified our value to the manual but it seems to be wrong. Their description is terribly confusing, though.

[thespooler]

So, Normally closed (reports off when switch is off / on when switch is on)? Doesn't seem to work for me.

[blhoward2]

No the other one. Their description is:

1 – normally closed (relay reports off when it's open / switch is on and on when it's closed / switch is off);

Ours is:

Normally closed (reports off when is on / on when switch is off)

[thespooler]

No, I had the Normally open one. Since I figured that would be safer in case of failure.

[blhoward2]

It changes the reporting, not the state, so it has no bearing on safety. Setting this seems to fix mine. "Normally closed (reports off when is on / on when switch is off)"

Note this is the opposite of what it is reporting, so something is off.

[blhoward2]

I now get:

17:55:33.618 DRIVER » [Node 129] [REQ] [SendData]
                      │ transmit options: 0x25
                      │ callback id:      163
                      └─[MultiChannelCCCommandEncapsulation]
                        │ source:      0
                        │ destination: 1
                        └─[BinarySwitchCCSet]
                            target value: true
17:55:33.626 DRIVER « [RES] [SendData]
                        was sent: true
17:55:33.695 DRIVER « [REQ] [SendData]
                        callback id:     163
                        transmit status: OK
17:55:33.770 DRIVER « [Node 129] [REQ] [ApplicationCommand]
                      └─[BinarySwitchCCReport]
                          current value: true
17:55:33.868 DRIVER « [Node 129] [REQ] [ApplicationCommand]
                      └─[MultiChannelCCCommandEncapsulation]
                        │ source:      1
                        │ destination: 0
                        └─[BinarySwitchCCReport]
                            current value: true
17:55:34.744 DRIVER » [Node 129] [REQ] [SendData]
                      │ transmit options: 0x25
                      │ callback id:      164
                      └─[MultiChannelCCCommandEncapsulation]
                        │ source:      0
                        │ destination: 1
                        └─[BinarySwitchCCGet]
17:55:34.752 DRIVER « [RES] [SendData]
                        was sent: true
17:55:34.816 DRIVER « [REQ] [SendData]
                        callback id:     164
                        transmit status: OK
17:55:34.940 DRIVER « [Node 129] [REQ] [ApplicationCommand]
                      └─[MultiChannelCCCommandEncapsulation]
                        │ source:      1
                        │ destination: 0
                        └─[BinarySwitchCCReport]
                            current value: true

[blhoward2]

Before

17:41:31.785 DRIVER « [RES] [SendData]
                        was sent: true
17:41:31.855 DRIVER « [REQ] [SendData]
                        callback id:     142
                        transmit status: OK
17:41:31.941 DRIVER « [Node 129] [REQ] [ApplicationCommand]
                      └─[BinarySwitchCCReport]
                          current value: false
17:41:32.054 DRIVER « [Node 129] [REQ] [ApplicationCommand]
                      └─[MultiChannelCCCommandEncapsulation]
                        │ source:      1
                        │ destination: 0
                        └─[BinarySwitchCCReport]
                            current value: false

[thespooler]

You are right, it does fix the remote-controlling part of the issue, but breaks the switches. The switches are reversed, relay is closed (on) when switch is open (off). All correct according to setting, but not in line with what I want. The expected is Switch is off, relay is off (thus light is off) and reported state follow that.

[blhoward2]

@GirzzlyAK Can you update Zooz on this? It seems to point squarely to a firmware issue. And one they should be able to reproduce. We're setting value 1 for parameter 21, which fixes it. It should be value 0 (normally open). They seem to report the opposite for what the parameter calls for on remote control, but then that causes the reporting on local control to be reversed.

[AlCalzone]

Can we add a compat flag to disable polling at all?

1532 :)

The reported state IS bad. Period.

The report in the unsolicited state is correct. The one returned in response to a poll is not.

[GrizzlyAK]

I’ll try this on mine too, using the old OZW 1.4 to see if it fixes the bad reporting. If so, then for sure, it looks to be a device issue, right?

Sent from my iPhone

On Feb 21, 2021, at 2:01 PM, blhoward2 notifications@github.com wrote:

 Can you update Zooz on this? It seems to point squarely to a firmware issue.

— You are receiving this because you were mentioned. Reply to this email directly, view it on GitHub, or unsubscribe.

[blhoward2]

Yes, I just reported in detail to Zooz what is going on as I thought that may be easier. Please do verify. The reporting for zwave and manual control seem to go out of sync when you set the Normally Open/Closed state. I can't test that part as I don't have a physical switch installed and this is under my fireplace so not easy to access.

[GrizzlyAK]

If this problem was consistent, i.e., it always reported the wrong state (mine doesn’t) then I’d say it could be related to momentary vs latched in the FW. Still could be a bug related to which state value is being returned in response to a poll in the FW tho (if there is more than one stored for some reason) - or a timing issue, e.g., sending the expected new state vs the actual state variable that hasn’t been set yet, but sends it after the poll.

[GrizzlyAK]

OK, so I tested this on mine in ozw 1.4 and the ONLY setting that works consistently is the middle setting for Normally Open/Closed parameter - normally closed (relay reports off when it's open / switch is on and on when it's closed / switch is off) . The Normally Open and the OTHER Normally Closed setting both randomly return the wrong state after the switch first indicates the change, that is, the final state was opposite what was expected (it flipped back). Hmm… That should be easy to track down for someone on the Zooz team.

[blhoward2]

Can one of you with a switch verify it's actually reversed reporting for those with it normally closed? If it's just their manual is wrong we can fix our label for the values, but we need someone to figure out which is which.

If it actually makes them out of sync with the actual switch then we can't do anything without Zooz. Please make sure that your switch type is set to follow switch and not toggle (as that makes up or down irrelevant on the physical switch.)

[thespooler]

I did, it works exactly as it should. That is an ON switch turns the relay OFF.

[thespooler]

I did a bit more testing.

When the relays are set to Normally Open:

1. Switch is physically OFF
2. Relay and light is OFF
3. ZWave reported state is OFF
4. Turned ON via ZWave
5. Lights turn ON
6. Reports ON via ZWave
7. ZWave requests state
8. Device reports state OFF
9. Turn ON (again) via ZWave
10. Lights / Relay stays ON
11. ZWave requests state
12. Device reports state ON

1. Switch is physically OFF
2. Relay and light is OFF
3. ZWave reported state is OFF
4. Turned ON via ZWave
5. Lights turn ON
6. Reports ON via ZWave
7. ZWave requests state
8. Device reports state OFF
9. Flip the Switch ON
10. Light turns OFF
11. No change reported via ZWave
12. Flip switch OFF 
13. Light turns ON
14. Reports ON via ZWave
15a. All further switching of physical switch is thus reversed, but does report a state change on zwave, albeit inverted
15b. All further switching via ZWave shows original behaviour, that is toggling the state of the relay requires TWO toggling

When the relays are set to Normally closed (reports off when is on / on when switch is off) and Toggle switch (change state on toggle):

1. Switch is physically OFF
2. Relay and light is ON
3. ZWave reported state is ON
4. Turned OFF via ZWave
5. Relay and light is OFF
6. ZWave reported state is OFF
6a. ZWave now always correctly toggles the relay and state is correctly reported, no need to toggle twice
7. Turned ON via ZWave
8. Relay and light is ON
9. ZWave reported state is ON
9a. Toggling the switch (physical) is now reversed until switched once again from ZWave. but otherwise, state changes are appropriately reported

When the relays are set to Normally closed (reports off when is on / on when switch is off) and Toggle switch (follow switch):

1. Switch is physically OFF
2. Relay and light is ON
3. ZWave reported state is ON
4. Turned OFF via ZWave
5. Relay and light is OFF
6. Switch is physically ON
7. Nothing
8. Switch is physically OFF
9. Relay and light is ON
10. ZWave reported state is ON
10. Toggling light switch OFF always turn lights ON and reports ON
11. Toggling light switch ON always turn lights OFF and reports OFF
12. Toggling via ZWave toggles the lights and correctly reports
13. Toggling the switch from a state correctly representing the current state to the inverted (ie. switch is turned from off to on when light is initially off or vice-versa) will do nothing. Here, the switch will be turned ON, the lights will stay OFF and be reported via ZWave as OFF

zwavejs_1(3).log

Edit: Wait, I just realized I did a factory reset earlier, so I'm no longer on following switches. I need to redo some of those tests. Fixed. Added mentions of switch mode.

[blhoward2]

Thanks please do as that's exactly what they'd need to see.

[GrizzlyAK]

Just an FYI on my comments. I am NOT using the input switches with physical switches. I only have connections to the relays and I control them ONLY through ZWave. Does anybody see how this behavior could be caused by anything BUT the FW?

[blhoward2]

Seems like either firmware or a misprint in the manual to me, that's why I asked about the physical switches. I assume it's a FW issue.

We assume the currentValue is the targetValue to prevent the switch from flipping back off initially in HA. Then we poll and revert it if there is no response. So the initial true may not be coming from the device though I defer to @AlCalzone on that. I haven't studied the logs posted.

Here there is a response, but it says it's off. That makes some sense if the reporting is told to treat it as normally closed and the reporting parameter is disconnected from the actual state, though I'm not sure it should be disconnected like that.

I discovered this because I got to a point with the third option where my fireplace was the exact opposite of the state, like it was on when off as the description for #2 says it should be.

[GrizzlyAK]

OZW 1.4 HA - I've run some more tests, including some changes to the switch type and whether switch control is enabled or disabled.

The 3 relevant parameters as Parameter : Setting TEST #1 (Use Case? 3-way switch) 2: Toggle, 12: Enabled, 21: Normally Closed #1 - zwave and switch work like a 3-way switch correctly 2: Toggle, 12: Enabled, 21: Normally Closed #2 - weird, unexpected behavior 2: Toggle, 12: Enabled, 21: Normally Open - zwave and switch work like a 3-way switch correctly

TEST #2 (Use Case? yeah, not sure, states get confused) 2: On/Off, 12: Enabled, 21: Normally Closed #1 - zwave always toggles state and state follows switch (changes or not) 2: On/Off, 12: Enabled, 21: Normally Closed #2 - weird, unexpected behavior 2: On/Off, 12 :Enabled, 21: Normally Open - zwave always toggles state and state follows switch (changes or not)

TEST #3 (Use Case? Control only zwave, middle case is only one that works correctly) 2: On/Off, 12: Disabled, 21: Normally Closed #1 - zwave always toggles state (and sometimes flips back to wrong state) 2: On/Off, 12: Disabled, 21: Normally Closed #2 - zwave always toggles state and maintains it correctly 2: On/Off, 12 :Disabled, 21: Normally Open -zwave always toggles state (and sometimes flips back to wrong state)

TEST #4 (Use Case? yeah, not sure, states get confused) 2: On/Off, 12: Disabled On/Off Reports, 21: Normally Closed #1 - same as TEST #3, but switch really screws state machine 2: On/Off, 12: Disabled On/Off Reports, 21: Normally Closed #2 - same as TEST #3, but switch really screws state machine 2: On/Off, 12 :Disabled On/Off Reports, 21: Normally Open -same as TEST #3, but switch really screws state machine

My manual only shows parameters through #20, not the Normal Open/Close parameters (21-24), so perhaps this feature to disconnect the switches and relays is new and the logic is flawed. No other similar device I know of (e.g., Fortrezz MIMOs) allows this kind of disconnect, and maybe this is why.

If one wants to use only Zwave to control the relays, it appears that the middle case of TEST #3 will work correctly to turn them On/Off.

[blhoward2]

So a word of advice. When you change the normally open/close setting, your auto off time becomes auto on. Found out the hard way with my fireplace. Fortunately it is rated as a furnace and to run unattended, but man is my living room hot.

[blhoward2]

My manual only shows parameters through #20, not the Normal Open/Close parameters (21-24), so perhaps this feature to disconnect the switches and relays is new and the logic is flawed. No other similar device I know of (e.g., Fortrezz MIMOs) allows this kind of disconnect, and maybe this is why.

They were added in the version 1.3 firmware. They aren't in the older manual. https://www.support.getzooz.com/kb/article/471-zen16-multirelay-ver-1-03-advanced-settings/

[GrizzlyAK]

Also, The nomenclature used in Parameters 21-23 is confusing (if not wrong). The parameter name is “Normally open/close for Relay X”, but in reality the Normal state being set tracks with the SWITCH, not the relay. For example, as far as the relays are concerned, the last two state options Normally Closed and Normally Open are the same in regard to the actual state of the Relay (i.e., relay reports off when it's open), which is the Normally Open state of the Relay.

I think they have too many parameters, some combinations of which are mutually exclusive in terms of logical functionality. I've sent them my test results as well.

[blhoward2]

In the meantime, I haven't tested this but an automation to send a second targetValue on after it switches on, and the same for off, would seem to workaround this for now based on my preliminary testing. The second targetValue seemed to make the state stick.

[blhoward2]

I may just try downgrading to 1.2: https://www.getzooz.com/firmware/ZEN16-V1.02-OTA.otz

[GrizzlyAK]

I'd be interested to see if that changes anything. Let us know. Are you trying to use both a switch and zwave to control something? If so, would not my TEST #1 configuration work OK for you? It seems that two of the options worked OK, as a 3-way. That seems to be the only way I see such a combination of functionality working reliably. And thanks for the link!

[blhoward2]

I'm using zwave only. Changing the normally close/open works fine but it reverses the auto on/off behavior and I'm not sure what else. Less than ideal on a fireplace.

[GrizzlyAK]

I think I'm may give up on these... I've got two of these things, same FW version, one works flawlessly as stated above (except occasionally the ALL switch flips erroneously, I don't use it anyway). The second unit though, still exhibits the behavior we started with, even with the exact same parameter settings. I've checked them multiple times. Thought maybe it was because one was slightly (10 feet) further from the hub, so I put it right next to the other. No difference. ARGH!

[blhoward2]

Rolling back to v1.2 worked fine, and the issue appears to be gone. I did have to factory reset after upgrading it, though. I'll note that Zooz has already emailed me back and they are looking into this. Can you provide the comparable logs from both devices showing the different behavior?

[GrizzlyAK]

Sure. It'll probably be tomorrow if that's OK. Dinner time here.

What did you lose, if anything, in v1.02?

[blhoward2]

Everything after parameter 20. The normally opened/close, DC motor setting.

Do you, or does someone else, have access to an OZW-based install still? It would help to diagnose this if we could confirm that a subsequent refreshDynamic values or poll erroneously returned false after a few seconds. That would confirm it isn't us but is instead because we poll after a few seconds and not immediately like ozw.

[GrizzlyAK]

I do not. The OP mentioned it did NOT occur in OZW. He may still have access to test. I may downgrade one of mine to test the v1.02. Do you have a link to the v1.03 by chance if I need to convert back?

[blhoward2]

I think that I do. I was able to guess it from the one I had. I imagine they'd provide a new link anyway as Zooz is pretty good about providing upgrades. If you can hold off for a few days until we know more, they seem pretty responsive so far and I think we've given them a pretty good lead. They offered to change whatever we needed so long as it doesn't break another integration.

[GrizzlyAK]

OK, I'm an idiot... plus it was late. I had set the first Normally Closed option in the Parameters instead of the SECOND one which I had found to work. Now, both units DO WORK CORRECTLY with that combination as I described earlier. Whew!