[bug] not detecting all of lock manual state changes

[jaburges]

Version Build/Run method

• [X] Docker
• [ ] PKG
• [ ] Manually built (git clone - npm install - npm run build )

Zwave2Mqtt version: 3.0.0 (same on 2.2.0) Openzwave Version: 1.6

Describe the bug Locks in Z2M are not reporting certain manual state changes.

• Keypad lock on BE469 Schlage is being sent and IS detected by Z2M
• Manual internal lock turn (lock or unlock) is not being picked up by Z2M

Locks include BE469, Kwikset Z-wave lock

To Reproduce Steps to reproduce the behavior:

1. Turn internal lock mechanism
2. notice no change to state

Expected behavior The internal lock mechanism used to be picked up by Z2M

Additional context Debug logs do NOT show internal mechanism state change

[jaburges]

@Fishwaldo any reason why the lock would be sending some commands to Z2M but not all. (I guess a better way to ask would be, what could be the reason Z2M / OZW would be missing some commands from the lock?)

[jaburges]

turning the BE469 internal lock handle I can see the following in Z2M:

zwave/front_lock/113/1/260 = 0
zwave/front_lock/113/1/6 = "Manual Lock Operation"
zwave/front_lock/113/1/6 = "Clear"

but notice there is no update to the actual lock state.... weird?

[robertsLando]

I suggest you to enable logs on zwave settings and post the OZW_logs.txt

On 3 Mar 2020, at 20:37, jaburges notifications@github.com wrote:

 turning the BE469 internal lock handle I can see the following in Z2M:

zwave/front_lock/113/1/260 = 0 zwave/front_lock/113/1/6 = "Manual Lock Operation" zwave/front_lock/113/1/6 = "Clear" but notice there is no update to the actual lock state.... weird?

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

[jaburges]

is there anything specific to look for, the log.txt is pretty big. Also what is "Current Record Number" with locks - i'm seeing Invalid Record for Log Record

[jaburges]

ok update, i had created a new manual value for the lock under Gateway in the Settings tab. There are 2 values in 1.6 so created both Locked 98-1-0 Locked (Advanced)98-1-1

polling time = 1 verify value = true and now (apart from my MQTT being flooded with values, the lock is reporting the correct state).

So Z2M is able to pull the value from the lock, but it was my understanding that the lock would send the command to the controller (and used to) - not sure what has changed?

[Fishwaldo]

Did you check the Association groups on the lock? Controller should be in there.

[robertsLando]

@jaburges Check if the lock lifeline group has controller :)

[jaburges]

couldnt find a setting in the UI but this is in the ozwcache.xml

<CommandClass id="133" name="COMMAND_CLASS_ASSOCIATION" version="1" request_flags="4" issecured="true">
                <Instance index="1" />
                <Associations num_groups="1">
                    <Group index="1" max_associations="5" label="Lifeline" auto="true">
                        <Node id="1" />
                    </Group>
                </Associations>
            </CommandClass>

so looks like it is associated with the controller ok - any other thoughts?

[shbatm]

I noticed what I think is the same issue after a recent update to Z2M. The manual states are no longer reporting as LOCKED, but when I send a LOCK command, it will report back as LOCKED.

There was an old issue with Schlage BE469 locks not correctly updating the status because they only update the alarm control, not the lock status (I think it was actually found in the Home Assistant integration: https://github.com/home-assistant/core/pull/18737), but I thought it had been working fine recently; wondering what changed?

Here's a debug log snapshot of manual control for my two locks. Node 3 is a BE469, Node 5 is a BE469ZP.

z2m:Zwave zwave node 3: changed: 113-1-6:Access Control:Clear -> Manual Lock Operation +12s
z2m:Zwave zwave node 3: changed: 113-1-6:Access Control:Manual Lock Operation -> Clear +5s
z2m:Zwave zwave node 3: changed: 113-1-6:Access Control:Clear -> Manual Unlock Operation +12s
z2m:Zwave zwave node 3: changed: 113-1-6:Access Control:Manual Unlock Operation -> Clear +5s
z2m:Zwave zwave node 3: changed: 113-1-6:Access Control:Clear -> Manual Lock Operation +14s
z2m:Zwave zwave node 3: changed: 113-1-6:Access Control:Manual Lock Operation -> Clear +5s
z2m:Zwave zwave node 5: changed: 113-1-6:Access Control:Auto Lock -> Manual Unlock Operation +16s
z2m:Zwave zwave node 5: changed: 98-1-0:Locked:true -> false +141ms
z2m:Zwave zwave node 5: changed: 98-1-1:Locked (Advanced):Unsecure -> Unsecure +6ms
z2m:Zwave zwave node 5: changed: 113-1-6:Access Control:Manual Unlock Operation -> Manual Lock Operation +4s
z2m:Zwave zwave node 5: changed: 98-1-0:Locked:false -> true +141ms
OpenZWave Warning, Attempt to get a Invalid Index 6 on ValueList

See attached OZW_Log for the following sequence:

1. MQTT Commanded Unlock of Node 3 (BE469)
2. Auto Re-Lock of Node 3 (no status change on MQTT)
3. Manual Unlock/Lock of Node 3 (no status change on MQTT)
4. Manual Unlock/Lock of Node 5 (BE469ZP) with status change on MQTT.

OZW_Log.txt

[Fishwaldo]

There was an old issue with Schlage BE469 locks not correctly updating the status because they only update the alarm control, not the lock status

joys of non-compliant devices!

you could try adding something this to the AlarmCC Block in a config file (adjust values to suit):

    <TriggerRefreshValue Genre="user" Index="0" Instance="1">
      <RefreshClassValue CommandClass="51" Index="255" Instance="1" RequestFlags="0"/>
    </TriggerRefreshValue>

see here for a example.

[jaburges]

its already there with some commentary on the previous edit:

    <!-- These Door Locks don't send a DoorLockReport when the
        Lock Status is Changed, but instead send a Alarm Message -
        So we trigger a Refresh of the DoorLock Command Class when
        we recieve a Alarm Message Instead -->
    <TriggerRefreshValue Genre="user" Index="0" Instance="1">
      <RefreshClassValue CommandClass="98" Index="1" Instance="1" RequestFlags="0"/>
    </TriggerRefreshValue>

[Fishwaldo]

Ahhh. Ok. It’s possible that broke with some core changes we made recently. I’ll confirm it’s still working.

[jaburges]

cool, thank you :) appreciate the help

[Fishwaldo]

Please change

<TriggerRefreshValue Genre="user" Index="0" Instance="1">

to

<TriggerRefreshValue Genre="user" Index="6" Instance="1">

and either RefreshNodeInfo or delete ozwcache

it should work... I don't own this device so I can't test personally

[jaburges]

deleted ozwcache (and amended BE469.xml)

but weirdly ended up with 2 entries that dont match the change:

                <TriggerRefreshValue Genre="user" Instance="1" Index="0">
                    <RefreshClassValue CommandClass="98" RequestFlags="0" Instance="1" Index="1" />
                </TriggerRefreshValue>
                <TriggerRefreshValue Genre="user" Instance="1" Index="0">
                    <RefreshClassValue CommandClass="98" RequestFlags="0" Instance="1" Index="1" />
                </TriggerRefreshValue>

assuming i should amend this to the above, and only need one of them?

[jaburges]

i'm seeing this a little more wide spread to more than just the BE469 lock. Also the Kwikset lock, and garage door opener. All are securely added. Interesting in the logs I see a similar issue as you commented on here: https://github.com/OpenZWave/open-zwave/issues/1949#issuecomment-539053738

2020-03-04 21:16:54.467 Info, Node084, Encrypted Flag is 1
2020-03-04 21:16:54.467 Info, Node084, Sending (Poll) message (Callback ID=0xd2, Expected Reply=0x04) - DoorLockCmd_Get (Node=84): 0x01, 0x09, 0x00, 0x13, 0x54, 0x02, 0x62, 0x02, 0x25, 0xd2, 0x24
2020-03-04 21:16:54.476 Detail, Node084,   Received: 0x01, 0x04, 0x01, 0x13, 0x00, 0xe9
2020-03-04 21:16:54.476 Error, Node084, ERROR: ZW_SEND_DATA could not be delivered to Z-Wave stack
2020-03-04 21:16:54.571 Detail, Node084,   Received: 0x01, 0x10, 0x00, 0x04, 0x10, 0x54, 0x0a, 0x98, 0x80, 0x33, 0xce, 0x97, 0x82, 0xaf, 0xa4, 0x91, 0x88, 0x47
2020-03-04 21:16:54.571 Info, Node084, Received SecurityCmd_NonceReport from node 84

is from my Kwikset lock - so the issue isnt isolated to the BE469.

[jaburges]

what a mess. Couldn't do anything as the logs were being filled with the polling of the Kwikset lock (@robertsLando suggested to manually add the values to poll the lock - which in all fairness worked BUT spammed the system that nothing else worked. NOTE the manual entries were removed, and settings saved, but lock continued to poll). Spamming was so bad the Z2M webpage hung multiple times. so to square 1, excluded the locks and re-added = no longer polling. BUT not responding to manual locking or unlocking again.

now node93= kwikset lock, changed the same index="6" per @Fishwaldo comment. Now when i turn the lock manually, i'm seeing it appear in the logs:

2020-03-04 22:43:07.240 Detail, Node093,   Received: 0x01, 0x1e, 0x00, 0x04, 0x00, 0x5d, 0x18, 0x98, 0x81, 0x44, 0x69, 0xa1, 0x90, 0xdc, 0x8f, 0x41, 0xc1, 0xc9, 0xf0, 0x9c, 0x4e, 0x25, 0x16, 0xeb, 0xd2, 0xce, 0xbc, 0x3b, 0x4d, 0x34, 0x09, 0xae
2020-03-04 22:43:07.240 Info, Raw: 0x98, 0x81, 0x44, 0x69, 0xa1, 0x90, 0xdc, 0x8f, 0x41, 0xc1, 0xc9, 0xf0, 0x9c, 0x4e, 0x25, 0x16, 0xeb, 0xd2, 0xce, 0xbc, 0x3b, 0x4d, 0x34, 0x09, 0xae
2020-03-04 22:43:07.240 Detail, Node093, Decrypted Packet: 0x00, 0x71, 0x05, 0x15, 0x01
2020-03-04 22:43:07.240 Detail, 
2020-03-04 22:43:07.240 Info, Node093, Got a AlarmCmd_Report Message.... 
2020-03-04 22:43:07.240 Info, Node093, Received Alarm report: type=21, level=1
2020-03-04 22:43:07.240 Detail, Node093, Refreshed Value: old value=22, new value=21, type=byte
2020-03-04 22:43:07.240 Detail, Node093, Changes to this value are not verified
2020-03-04 22:43:07.240 Detail, Node093, Refreshed Value: old value=1, new value=1, type=byte
2020-03-04 22:43:07.240 Detail, Node093, Changes to this value are not verified
2020-03-04 22:43:07.240 Detail, Node093, Notification: ValueChanged CC: COMMAND_CLASS_NOTIFICATION Instance: 1 Index: 512
2020-03-04 22:43:07.240 Detail, Node093, Notification: ValueChanged CC: COMMAND_CLASS_NOTIFICATION Instance: 1 Index: 513
2020-03-04 22:43:07.855 Detail, Node064,   Received: 0x01, 0x10, 0x00, 0x04, 0x00, 0x40, 0x0a, 0x32, 0x02, 0x21, 0x74, 0x00, 0x00, 0x00, 0x00, 0x00, 0x00, 0xc4

But no state change in Z2M

[robertsLando]

So what ? I have also another user expecting some strange crash :(

[jaburges]

note - i dont see the BE469 manual lock turn appear in the OZW logs - just the kwikset.

I do now see the following for the Kwikset in MQTT - but NOT for Locked or Locked (Advanced) 98/1/0

turned to lock: zwave/back_lock/113/1/512 = 21 zwave/back_lock/113/1/513 = 1

turned to unlock: zwave/back_lock/113/1/512 = 22 zwave/back_lock/113/1/513 = 1

The Kwikset lock is reporting as Touchpad Electronic Deadbolt (Kwikset (Spectrum Brands))

seems like Alarm is not being passed to DoorLock?

[robertsLando]

@Fishwaldo

[jaburges]

in more testing (as locks are important and I need my house to be secure)

If I use the Z2M console it will lock and unlock the lock using the toggle Locked (NodeID-98-1-0) this produces: zwave/back_lock/113/1/512 locked = 24 unlocked = 25

However i'm unable to send a command via MQTT to the lock zwave/back_lock/98/1/0 or zwave/back_lock/98/1/0/set

HA therefore is not able to send lock/unlock - but is listening to the 98/1/0 topic so is reporting the state correctly when sent from Z2M.

Any more thoughts on this?

[robertsLando]

Try to check in your broker if on startup z2m subscribes to the topic you wrote with “/set” at the end, than also when you publish something you should see a log on z2m if he receives the message

Daniel

On 7 Mar 2020, at 05:52, jaburges notifications@github.com wrote:

 in more testing (as locks are important and I need my house to be secure)

If I use the Z2M console it will lock and unlock the lock using the toggle Locked (NodeID-98-1-0) this produces: zwave/back_lock/113/1/512 locked = 24 unlocked = 25

However i'm unable to send a command via MQTT to the lock zwave/back_lock/98/1/0 or zwave/back_lock/98/1/0/set

HA therefore is not able to send lock/unlock - but is listening to the 98/1/0 topic so is reporting the state correctly when sent from Z2M.

Any more thoughts on this?

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

[jaburges]

Yes ‘/set’ does now work. It was a different issue preventing the node from receiving messages. Z2M still has the old node ID number so I was sending to 93/98/1/0 and the node was still thinking it was 36/98/1/0. I’ve fixed that, but the initial bug still remains.

No locks are responding to manual turns. My current work around is to listen to 113/5/12 (in node-red via an MQTT in node, but could also be done via an automation) and send the 98/1/0/set ‘true’ or ‘false’ appropriately to ensure the state is updated.

This temporary workaround however does NOT work for the BE469 as I’m not seeing anything in the logs or MQTT for this lock.

[brgaulin]

Very timely find this thread is. I'm also having this issue.

Kwikset ZWave 914 Deadbolt Lock: https://github.com/OpenZWave/open-zwave/blob/master/config/kwikset/914c.xml#L65-L73

Latest ZWave MQTT code and such. OZW 1.6.

It looks like the same lock, or similar situation as @jaburges . The lock doesn't update the locked true/false on its own, so when Command Class 113 is reported, we need to poll for 98-1-0(Locked Status).

It sounds like the ZWave MQTT app is ignoring the TriggerRefreshValue directive in the XML for that node.

[robertsLando]

It sounds like the ZWave MQTT app is ignoring the TriggerRefreshValue directive in the XML for that node

Zwave2Mqtt uses openzwave-shared to use OZW. And I think that once the configuration of a device is loaded it should work as the configuration tells, I should not handle that. I think that this is something on OZW side not something wrong with Z2M

@jaburges

2020-03-04 22:43:07.240 Detail, Node093, Notification: ValueChanged CC: COMMAND_CLASS_NOTIFICATION Instance: 1 Index: 512 2020-03-04 22:43:07.240 Detail, Node093, Notification: ValueChanged CC: COMMAND_CLASS_NOTIFICATION Instance: 1 Index: 513

Notification: ValueChanged I am subscribed to those changes, if you receive all others updates you should get that too

https://github.com/OpenZWave/Zwave2Mqtt/blob/master/lib/ZwaveClient.js#L67 https://github.com/OpenZWave/Zwave2Mqtt/blob/master/lib/ZwaveClient.js#L69

https://github.com/OpenZWave/Zwave2Mqtt/blob/master/lib/ZwaveClient.js#L447

The only reason why you could not get the updates is if the node is not ready

That event is coming from here: https://github.com/OpenZWave/node-openzwave-shared/blob/master/src/callbacks.cc#L212

[jaburges]

@robertsLando i'm not sure i understand your comments? i am getting updates to MQTT on /113/1/512 & 113/1/513 but NOT /98/1/0 (which is the "Locked" state) for a manual lock turn. I can still lock/unlock when I send true or false to 98/1/0/set - which then the lock confirms its new state at /98/1/0 .

As above it seems like there were some edits made to the devices to grab/poll the state of the lock at the time the alarm level is triggered (as that wasn't happening normally). Beyond this point anything I add is likely to complicate things (as i'm not a zwave specialist).

[robertsLando]

@jaburges My comment was mainly for @Fishwaldo to show him how things are from my side, I really think it is something on OZW side and I have no power with that

[Fishwaldo]

Has anyone actually tried my suggestion to change the config?

These devices are not compliant with the specifications. The Config change works around that.

[jaburges]

@Fishwaldo yep about 5 days ago after your comment. Sadly didn’t resolve the issue :-(

[Fishwaldo]

Logs please. After removing ozwcache

[jaburges]

removed ozwcache last restart. Here is the log: https://1drv.ms/u/s!At3XmrQSJ2NJs5EsTxjIauM3WPa0JQ?e=3AnSwi

Let me know if you want me to restart and just lock/unlock the locks. Node 92 & 93 are Kwikset Locks Node 78 is the BE469

[jaburges]

@Fishwaldo let me know if you need any more info and what thoughts you have on resolving this.

[Fishwaldo]

2020-03-06 21:20:40.681 Info, Node078, Value Refresh triggered by CommandClass: COMMAND_CLASS_NOTIFICATION, Genre: 1, Instance: 1, Index: 0 for:
2020-03-06 21:20:40.681 Info, Node078,     CommandClass: COMMAND_CLASS_DOOR_LOCK, RequestFlags: 0, Instance: 1, Index: 1

Node 78 Does not have the changes I recommended above (change Index to 6). Hence:

2020-03-07 14:16:29.828 Info, Node078, Got a AlarmCmd_Report Message.... 
2020-03-07 14:16:29.828 Info, Node078, Received Notification report (>v1): Type: Access Control (6) Event: Manual Unlock Operation (2) Status: true, Param Length: 0
2020-03-07 14:16:29.828 Detail, Node078, Initial read of value
2020-03-07 14:16:29.828 Info, Node078, Automatically Clearing Alarm in 5000ms
2020-03-07 14:16:29.828 Info, Timer: adding event in 5000 ms
2020-03-07 14:16:29.828 Detail, Timer: waiting with timeout 5000 ms
2020-03-07 14:16:29.828 Detail, Node078, Notification: ValueChanged CC: COMMAND_CLASS_NOTIFICATION Instance: 1 Index: 6

Does not trigger OZW to refresh the DoorLock Status

Node92:

2020-03-06 21:20:40.716 Info, Node092, Value Refresh triggered by CommandClass: COMMAND_CLASS_NOTIFICATION, Genre: 1, Instance: 1, Index: 0 for:
2020-03-06 21:20:40.716 Info, Node092,     CommandClass: COMMAND_CLASS_DOOR_LOCK, RequestFlags: 0, Instance: 1, Index: 1

Also does not have the changes (index 6) but it does not seem to expose a Access Control (index 6) Alarm Message type:

2020-03-06 21:20:40.870 Detail, Node092, Notification: ValueAdded CC: COMMAND_CLASS_NOTIFICATION Instance: 1 Index: 512
2020-03-06 21:20:40.870 Detail, Node092, Notification: ValueAdded CC: COMMAND_CLASS_NOTIFICATION Instance: 1 Index: 513
2020-03-06 21:20:40.871 Detail, Node092, Notification: ValueAdded CC: COMMAND_CLASS_NOTIFICATION Instance: 1 Index: 514

hence we get:

2020-03-06 23:00:53.820 Info, Node092, Got a AlarmCmd_Report Message.... 
2020-03-06 23:00:53.820 Info, Node092, Received Alarm report: type=24, level=1
2020-03-06 23:00:53.820 Detail, Node092, Initial read of value
2020-03-06 23:00:53.820 Detail, Node092, Initial read of value
2020-03-06 23:00:53.820 Detail, Node092, Notification: ValueChanged CC: COMMAND_CLASS_NOTIFICATION Instance: 1 Index: 512
2020-03-06 23:00:53.820 Detail, Node092, Notification: ValueChanged CC: COMMAND_CLASS_NOTIFICATION Instance: 1 Index: 513

So you probably have to change index from 0 to 512 or 513 for the Kwikset locks

Also, There is one bug that I've fixed (but nothing todo with reporting) and I also see Node078 is really acting strange, occasionally flooding the Network With Nonce_Get Messages very very quickly (see 21:01:09:643 - Resolved at at 21:01:24:38 and at 15:57:14:886 we get into another Nonce Flood, Finally resolved at 15:58:47:478)

If you fix the RefreshValue blocks for each device, hopefully it will refresh the door lock status when opened/closed locally. (from the logs, it works when you do it remotely)

Hate to say it (I may already have said it) but both these locks are not compliant with the Z-Wave specifications. They would not pass certification today. I do recall that some Locks were bundled with a alarm.com package (or something similar) and it appears that interoperability was not a concern to them.

In Particular, Node78 is probably causing other issues with its flooding of the Network, sometimes in excess of 1 minute - which means any other reports are probably not getting through...

[jaburges]

Thanks for the response, I’ll take another look and make sure the changes stick.

Can’t understand why it would happen in an update though. I’ve had these locks for 4 years and have been working fine. I understand they may not be compliant but that shouldn’t suddenly stop them working - unless there was a change made that aligns to Compliance and these then don’t fall in line?

[Fishwaldo]

I suspect its a case of transition from OZW 1.4 to OZW 1.6 - The Alarm (now called Notification) CC was rewritten to support Version 11 (it previously supported version 4?). With that re-write, the index numbers changed - hence why the config file was pointing at the wrong index's

I can't possibly test all the devices (I own a LOT but not everything!) hence, why a lot of config files are maintained by the "Community"

And yes - we did a lot of work on OZW 1.6 to be more compliant... but that wasn't the source of your problem... the RefreshValue config option was created for "non-compliant" devices even in 1.4 days

[jaburges]

Cool, I’ll do my best to test these and report back today :-)

[jaburges]

every step forward is another 2 backward. So removed ozwcache and it rebuilt the Kwikset locks correctly, now responding to manual commands.

However, now the door sensors are reporting as dead. and I removed node on the BE469 and its still showing :-/

is there a limit to how many nodes you can have, as I feel like there seems to be some kind of limit on the zwave network before issues occur. Its been solid until this lock issue, and excluding and re-adding them (with the edit) is the only fix that has worked.

[jaburges]

@robertsLando dead nodes or excluded nodes arent removing from the list and show up as:

Unknown: type=0000, id=0000 (Unknown: id=0000)

Even after restart

now the BE469 is in some limbo state. The lock thinks its removed, but Z2M is still showing entries in the log for that node. The node (78) that is removed is also not showing in ozwcache either? Is there some DB that Z2M is using that stores this information?

[robertsLando]

dead nodes or excluded nodes arent removing from the list and show up as:

This is not handled by Z2M

Is there some DB that Z2M is using that stores this information

I only store nodes name and locations in a file in store named nodes.json but that doesn't do anything against OZW. I only take those info if nodes are coming from OZW events notifications

[jaburges]

There is definitely something off, as I excluded the BE469 lock. I then reset the lock (full factory reset, no working codes etc etc). On re-adding the lock, it was assigned its previous node (node 78) - every other device is assigned a new node.

[jaburges]

i've now repaired 99% of my zwave network except for a strips back door sensor (WIP). However the Kwikset locks are not reporting their state from a manual lock turn as originally raised. CONFIRMED for both Kwikset locks:

            <CommandClass id="113" name="COMMAND_CLASS_NOTIFICATION">
                <Compatibility />
                <State>
                    <CCVersion>1</CCVersion>
                    <Encrypted>true</Encrypted>
                    <StaticRequests>2</StaticRequests>
                </State>
                <Instance index="1" />
                <Value type="byte" genre="user" instance="1" index="512" label="Alarm Type" units="" read_only="true" write_only="false" verify_changes="false" poll_intensity="0" min="0" max="255" value="22">
                    <Help>Alarm Type Received</Help>
                </Value>
                <Value type="byte" genre="user" instance="1" index="513" label="Alarm Level" units="" read_only="true" write_only="false" verify_changes="false" poll_intensity="0" min="0" max="255" value="1">
                    <Help>Alarm Level Received</Help>
                </Value>
                <Value type="int" genre="config" instance="1" index="514" label="Automatically Clear Events" units="ms" read_only="false" write_only="false" verify_changes="false" poll_intensity="0" min="-2147483648" max="2147483647" value="5000">
                    <Help>Automatically Clear Events sent by a device after a number of Milliseconds</Help>
                </Value>
                <TriggerRefreshValue Genre="user" Instance="1" Index="6">
                    <RefreshClassValue CommandClass="98" RequestFlags="0" Instance="1" Index="1" />
                </TriggerRefreshValue>
                <TriggerRefreshValue Genre="user" Instance="1" Index="6">
                    <RefreshClassValue CommandClass="98" RequestFlags="0" Instance="1" Index="1" />
                </TriggerRefreshValue>
            </CommandClass>

HOWEVER - 1 lock works (eventually) node 92 but there is a LOT of traffic and issues in the logs before it registers the change. Node 93 the other Kwikset lock shows nothing in the logs here

This is getting really tiresome chasing these gremlins, especially as there seems to be no consistency to the issues. Could really do with some direction as now i have excluded and re-included (after a factory reset).

[Fishwaldo]

Unfortunately the TriggerRefreshValue Block isn't correct. Maybe let me explain so you can understand what its doing:

                <TriggerRefreshValue Genre="user" Instance="1" Index="6">

This says - if we see a ValueID, whois Genre is user, its instance is 1, and the Index is 6, then we are going to refresh a ValueID in another class:

                    <RefreshClassValue CommandClass="98" RequestFlags="0" Instance="1" Index="1" />

So this is the ValueID we are going to refresh - In this case CommandClass 98 (doorlock), RequestFlags is advanced and can be left at 0, Instance 1, Index 1 - which corresponds to the DoorLock Status ValueID

Now technically, you look at the DoorLock CC - there are two ValueID's that relevant, (Lock - Index 0 and Lock_Mode - Index 1) but we only need to refresh one of them, and the other will update, hence we don't need to have two RefreshClassValue blocks as refreshing one will automatically refresh the other)

So in the dump you posted above, we will only Refresh the DoorLock if we get a change on a Notification CC with Index 6 (Access Control), but in your case, the device doesn't expose a "Access Control" Notification type. Only Alarm Type (index 512) and Alarm Level (index 513). So you need to pick one (either one is fine) and update your TriggerRefreshValue index with 512 or 513 (I did post that above).

Other Devices, like your BE469 did expose Index 6 (Access Control) so that block probably would work for it.

This is getting really tiresome chasing these gremlins, especially as there seems to be no consistency to the issues.

Your working with some pretty old devices here, welcome to my world!

[Fishwaldo]

There is definitely something off, as I excluded the BE469 lock. I then reset the lock (full factory reset, no working codes etc etc). On re-adding the lock, it was assigned its previous node (node 78) - every other device is assigned a new node.

Sounds like the Exclusion didn't "stick" on the Controller. I assume you did a "RemoveNode" then did whatever button dance on the lock to actually trigger the Node Removal?

[Fishwaldo]

btw, when you get it finally "refreshing" there is a fix to the Lock_Mode value. @robertsLando needs to pull the latest version to get it... but we can continue to diagnose instead of having to wait for him.

[Fishwaldo]

is there a limit to how many nodes you can have, as I feel like there seems to be some kind of limit on the zwave network before issues occur. Its been solid until this lock issue, and excluding and re-adding them (with the edit) is the only fix that has worked.

I can't see from your logs (as we had ozwcache present) details about your Network, so this is just generic advice...

1) Pre ZWave+ devices operate at 40K bandwidth... Z-Wave+ devices operate at 100K bandwidth... so if you have lots of traffic, obviously old devices are going to limit your available bandwidth

2) On a large network, its good to have a decent amount of Mains powered devices. These are the only type of devices that "particpate" in creating a mesh. Battery devices will not "strengthen" your mesh.

I saw a LOT of motion events in your log files. I'm assuming these are battery powered. This is really chatty. If you have a lot of pre-zwave+ devices this is consuming your bandwidth, introducing latency. You may want to evaluate the "retrigger time" (if available) for the motion sensors here - its a trade off - Frequent updates, versus latency. you need to decide if the latency is worth it.

Also - the Network Graph/Neighbors only displays around 1/4 of the actual routing table a device has. Honestly, its pretty much next to useless, as what you see are basically the "last resort" as far as how a mesh is setup/configured.

When Adding/Removing or Physically moving a mains powered node (not battery) you should run HealNetwork - It will run in the background and could take anywhere from minutes to hours. Unfortunately there is no feedback from the stick when it completes :( Also - During that time, pretty much 100% of bandwidth is consumed, so any testing etc during that time is going to be affected

Heal Network is most beneficial to Non-ZWave+ devices. (as they dont have a feature called Explorer Frames that auto discover the Network paths etc). If you have all + devices, then its pretty much redundant.

Finally - There are some really crappy devices out there (especially older devices prior to the Z-Wave Alliance improving the certification process). A lot of code in OZW is to deal with these crappy implementations. Unfortunately your dealing with 2 models that are in that category, hence there is some trial and error needed to get them functional. I'm pretty sure if you had models that were very recently released (and certified) then you wouldn't be facing these issues.

[jaburges]

thanks for the informative reply! super useful. i'll explore what options there are to replace the locks - little frustrating as they weren't cheap. I wonder what recourse there is for scenarios like this from the manufacturer.

I have a lot of powered devices (all my light switches are permanently wired creating a pretty solid mesh throughout the house) - although most of these are GE and not z-wave plus. The motion sensors are Dome and certified z-wave plus.

The thing I can't get my head around is WHY this suddenly happened, and why excluding and re-adding the device has fixed things.

I'm also seeing a lot of the NONCES to the garage door opener (so basically the 4 devices out of all of them having issues - mostly different manufacturers and not all locks) were the ones securely added. Is it possible that during an update, or a recent change the security/trust broke leaving these devices as only partly communicating with the controller?

[robertsLando]

There is no reason to wait for me to build a new release just for “testing”. Instead there are 2 options to this (that are lot recommended): first one is to git clone this project compile it and start it hsing nodejs, the second one would be to follow Zwave2Mqtt-docker repo readme and compile a custom docker image (it’s just one command).

On 15 Mar 2020, at 07:33, jaburges notifications@github.com wrote:

 thanks for the informative reply! super useful. i'll explore what options there are to replace the locks - little frustrating as they weren't cheap. I wonder what recourse there is for scenarios like this from the manufacturer.

I have a lot of powered devices (all my light switches are permanently wired creating a pretty solid mesh throughout the house) - although most of these are GE and not z-wave plus. The motion sensors are Dome and certified z-wave plus.

The thing I can't get my head around is WHY this suddenly happened, and why excluding and re-adding the device has fixed things.

I'm also seeing a lot of the NONCES to the garage door opener (so basically the 4 devices out of all of them having issues - mostly different manufacturers and not all locks) were the ones securely added. Is it possible that during an update, or a recent change the security/trust broke leaving these devices as only partly communicating with the controller?

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

[Fishwaldo]

i'll explore what options there are to replace the locks - little frustrating as they weren't cheap. I wonder what recourse there is for scenarios like this from the manufacturer.

Well if we get this TriggerRefreshValue right - then I think you will be able to use them....

Is it possible that during an update, or a recent change the security/trust broke leaving these devices as only partly communicating with the controller?

In general, it either works or doesn't work. Not often you will get a partially works, and if you do, its more than likely a RF/Mesh issue than a security issue.

[jaburges]

ok update. I have pulled the latest docker of Zwave2MQTT which includes the latest OZW build (1.6.1061 (latest from master) Removed ozwcache (and nodes.json from Z2M) - renamed and ensured all devices are 'Alive' and talking to the controller.

BE469 and Kwikset locks STILL dont report their manual state to the controller. Issue 1: BE469 isn't reporting the correct device type (not sure how to force it). Refresh Node Info doesnt help. Issue 2: (Related to issue 1 is the ozwcache entry for that node does NOT include the changes mentioned by @Fishwaldo as that requires it to recognize the device type) Issue 3: Again supplemental to issue 1 as the device does not contain the Lifeline association to the controller.

Kwikset DOES have the additions made above, and the LifeLine association to the controller but is currently NOT reporting manual state/lock changes, although is reporting 512 & 513

Here is the Kwikset Node logs:

2020-03-17 19:41:49.238 Detail, Node093,   Received: 0x01, 0x08, 0x00, 0x04, 0x00, 0x5d, 0x02, 0x98, 0x40, 0x74
2020-03-17 19:41:49.238 Info, Node093, Received SecurityCmd_NonceGet from node 93
2020-03-17 19:41:49.238 Info, NONCES: 0xeb, 0x56, 0xa1, 0x29, 0xac, 0x3d, 0xfb, 0x6c
2020-03-17 19:41:49.238 Info, NONCES: 0x63, 0x73, 0x8a, 0x5b, 0xb0, 0x01, 0x6c, 0x81
2020-03-17 19:41:49.239 Info, NONCES: 0x61, 0x51, 0xf3, 0xa4, 0x46, 0x94, 0x90, 0x9b
2020-03-17 19:41:49.239 Info, NONCES: 0xdb, 0xeb, 0x5a, 0x5b, 0xfd, 0xb6, 0xd9, 0x95
2020-03-17 19:41:49.239 Info, NONCES: 0xef, 0xf8, 0xa4, 0xad, 0xa4, 0x4b, 0xea, 0x6f
2020-03-17 19:41:49.239 Info, NONCES: 0x4a, 0x41, 0x8f, 0x3c, 0xa4, 0x96, 0x66, 0x91
2020-03-17 19:41:49.239 Info, NONCES: 0xab, 0x80, 0x09, 0x98, 0x28, 0x91, 0x10, 0xe8
2020-03-17 19:41:49.239 Info, NONCES: 0xea, 0x91, 0xef, 0x93, 0x21, 0xf0, 0xf9, 0xe1
2020-03-17 19:41:49.239 Info, Node093, Sending (Send) message (Callback ID=0x01, Expected Reply=0x00) - Nonce_Report - 0x01, 0x11, 0x00, 0x13, 0x5d, 0x0a, 0x98, 0x80, 0xea, 0x91, 0xef, 0x93, 0x21, 0xf0, 0xf9, 0xe1, 0x05, 0x01, 0x78:
2020-03-17 19:41:49.253 Detail,   Received: 0x01, 0x04, 0x01, 0x13, 0x01, 0xe8
2020-03-17 19:41:49.253 Detail,   ZW_SEND_DATA delivered to Z-Wave stack
2020-03-17 19:41:49.359 Detail,   Received: 0x01, 0x07, 0x00, 0x13, 0x01, 0x00, 0x00, 0x0b, 0xe1
2020-03-17 19:41:49.359 Detail,   ZW_SEND_DATA Request with callback ID 0x01 received (expected 0x01)
2020-03-17 19:41:49.426 Detail, Node093,   Received: 0x01, 0x1e, 0x00, 0x04, 0x00, 0x5d, 0x18, 0x98, 0x81, 0x29, 0x54, 0xb6, 0x06, 0x01, 0x7c, 0x08, 0xda, 0x7f, 0xc0, 0x8e, 0xa2, 0xc3, 0xea, 0x5d, 0x0d, 0xd2, 0xc0, 0xe7, 0x6b, 0x22, 0x36, 0xbb
2020-03-17 19:41:49.426 Info, Raw: 0x98, 0x81, 0x29, 0x54, 0xb6, 0x06, 0x01, 0x7c, 0x08, 0xda, 0x7f, 0xc0, 0x8e, 0xa2, 0xc3, 0xea, 0x5d, 0x0d, 0xd2, 0xc0, 0xe7, 0x6b, 0x22, 0x36, 0xbb
2020-03-17 19:41:49.426 Detail, Node093, Decrypted Packet: 0x00, 0x71, 0x05, 0x16, 0x01
2020-03-17 19:41:49.426 Detail, 
2020-03-17 19:41:49.426 Info, Node093, Got a AlarmCmd_Report Message.... 
2020-03-17 19:41:49.426 Info, Node093, Received Alarm report: type=22, level=1
2020-03-17 19:41:49.426 Detail, Node093, Refreshed Value: old value=21, new value=22, type=byte
2020-03-17 19:41:49.426 Detail, Node093, Changes to this value are not verified
2020-03-17 19:41:49.426 Detail, Node093, Refreshed Value: old value=1, new value=1, type=byte
2020-03-17 19:41:49.426 Detail, Node093, Changes to this value are not verified
2020-03-17 19:41:49.426 Detail, Node093, Notification: ValueChanged CC: COMMAND_CLASS_NOTIFICATION Instance: 1 Index: 512
2020-03-17 19:41:49.427 Detail, Node093, Notification: ValueChanged CC: COMMAND_CLASS_NOTIFICATION Instance: 1 Index: 513
  z2m:Zwave zwave node 93: changed: 113-1-512:Alarm Type:21 -> 22 +514ms
  z2m:Zwave zwave node 93: changed: 113-1-513:Alarm Level:1 -> 1 +0ms

[jaburges]

In the spirit of being thorough I excluded the BE469 and then paired it. This time a new node number was issued, however still the wrong device is being reported. Log of the inclusion is here: https://pastebin.com/kgs9QRrt

EDIT: Where does it get this from:

2020-03-18 09:09:45.387 Info, Node096,   Basic device class    (0x04) - Routing Slave
2020-03-18 09:09:45.388 Info, Node096,   Generic device Class  (0x40) - Entry Control
2020-03-18 09:09:45.388 Info, Node096,   Specific device class (0x03) - Secure Keypad Door Lock