node-zwave-js icon indicating copy to clipboard operation
node-zwave-js copied to clipboard

Schlage Connect BE469ZP varying in reported metadata between devices in z-wave network

Open Berzerker opened this issue 3 years ago • 14 comments

Is your problem within Home Assistant (Core or Z-Wave JS Integration)?

YES, BUT a Home Assistant developer has told me to come here

Is your problem within ZWaveJS2MQTT?

YES, BUT a ZWaveJS2MQTT developer has told me to come here

Checklist

Describe the bug

What causes the bug?

Re-interviewing the device

What do you observe?

Every re-interview gives me a varying amount of metadata from the lock. The original entities that were added when I first enrolled the device in May 2021 are no longer available, even after attempting to refresh the metadata within the device configuration in Z-Wave JS. Sometimes

What did you expect to happen?

I expect a full set of metadata to be populated in each entry including, but not limited to, battery level, intrusion status, and low battery indication

Steps to reproduce the behavior:

  1. Re-interview the device
  2. Metadata will sometimes populate correctly, most of the data entries are "undefined"

Other notes:

  • Lock/unlock status is not affected, nor is sending commands and the UI updates correctly when the lock status is changed both remotely and manually.
  • I've attempted to add a 2000ms timeout to the config but this actually seemed to make the problem more consistent.

Device information

Manufacturer: Schlage Connect Model name: BE469ZP Node ID in your network: 9, 10, and 11

How are you using node-zwave-js?

  • [ ] zwavejs2mqtt Docker image (latest)
  • [ ] zwavejs2mqtt Docker image (dev)
  • [ ] zwavejs2mqtt Docker manually built (please specify branches)
  • [ ] ioBroker.zwave2 adapter (please specify version)
  • [X] HomeAssistant zwave_js integration (please specify version)
  • [ ] pkg
  • [ ] node-red-contrib-zwave-js (please specify version, double click node to find out)
  • [ ] Manually built from GitHub (please specify branch)
  • [ ] Other (please describe)

Which branches or versions?

version: 2022.8.4 node-zwave-js branch: 9.6.2 zwavejs2mqtt branch: 6.15.2

Did you change anything?

no

If yes, what did you change?

No response

Did this work before?

Yes (please describe)

If yes, where did it work?

Worked without issue when first installing, I do not have an exact timeframe of when it no longer worked, but I noticed the lovelace UI not updating with lock status and the remote commands not working in August 2022. Re-interviewing the devices fixed those issues, but presented with missing metadata afterwards.

Attach Driver Logfile

zwavejs2mqtt_2022-08-15.log

Berzerker avatar Aug 15 '22 16:08 Berzerker

👋 Hey @Berzerker!

It looks like you attached a logfile, but its filename doesn't look like it a driver log that came from Z-Wave JS. Please make sure you upload the correct one.

zwave-js-bot avatar Aug 15 '22 16:08 zwave-js-bot

zwavejs_2022-08-15.log zwavejs2mqtt_2022-08-15.log

Uploaded correct files

Berzerker avatar Aug 15 '22 16:08 Berzerker

This looks suspiciously like the other issue you commented in, at least to some degree. Node 9 has 27 timeouts during the interview alone. I don't know if you tried to up the response timeout but if you did, it didn't take.

What bothers me a bit is that the lock almost instantly requests a nonce which it needs to send an encrypted response, but the actual response never comes, not even delayed. When it does respond, the response comes within 100-200ms.

This could just be a connectivity issue, since the round-trip-times are fluctuating quite a bit.

Just to be sure: did you follow this guide? Normally I'd recommend checking the network health but it doesn't seem like your controller supports reporting this information, so that won't be a lot of help.

AlCalzone avatar Aug 15 '22 18:08 AlCalzone

I did try adding the timeout, but I didn't try upping it, I'll try maybe 5000 or 10000. Just to be sure, in my settings.json, I currently have this:

{"port":"/dev/ttyACM0","commandsTimeout":30,"logLevel":"info","logEnabled":true,"securityKeys":

I would then change it to the following:

{"port":"/dev/ttyACM0","options":{"timeouts":{"report":5000}},"commandsTimeout":30,"logLevel":"info","logEnabled":true,"securityKeys":

I would hesitate to put the blame on connectivity issues since my house is relatively small, and I've had no issues with the locks for the better part of a year. Like I said, I'm not exactly sure when the issue started, but IIRC there was some major change to Z-WaveJS a few months ago that maybe was when I started having issues? Not 100% sure.

Just to make sure, I did replace batteries in all locks.

Berzerker avatar Aug 15 '22 18:08 Berzerker

I did change the default report timeout from 10000 ms to 1000 ms a while ago, to be in line with what the specs recommend. So far the only devices I've seen have issues with this are the Schlage locks, and they have contributed some straaange issues over the years.

Anyways, if you switch back to 10000ms, you should have exactly the same behavior as previously. If there are still timeouts, then it is not the driver change.

AlCalzone avatar Aug 15 '22 18:08 AlCalzone

I had a similar issue with this lock (2 of them actually), and solved it by temporarily increasing the timeout to 10,000ms during the interview. I still had one time out during the interview, I think, but I think it was for a value of a config parameter, or something else that I could easily query after the interview finished. As best as I can tell, the lock sometimes just gets cranky and takes 5 seconds to respond, or decides not to respond at all.

mattstocum avatar Aug 16 '22 18:08 mattstocum

Well, unless I'm not actually changing the timeout report to 10000 properly, that's still not solving my issues. The lock/unlock does work, but like I said, not much to no metadata is coming through during the interview process.

Berzerker avatar Aug 16 '22 19:08 Berzerker

Well, unless I'm not actually changing the timeout report to 10000 properly, that's still not solving my issues. The lock/unlock does work, but like I said, not much to no metadata is coming through during the interview process.

I have a copy of the config that worked for me (minus security keys) here: https://github.com/zwave-js/node-zwave-js/issues/4746#issuecomment-1167360075

mattstocum avatar Aug 16 '22 23:08 mattstocum

I'm seeing re-interviews of BE469ZPs fail to complete more often than not, even with the timeout bumped up. Here are 5 (out of 5) attempts failing with unsupported command errors, despite having the re-interview just prior to these 5 complete successfully.

does not support the command SupportedGet
2022-09-06T18:43:49.159Z DRIVER « [Node 093] [REQ] [BridgeApplicationCommand]
                                  │ RSSI: -68 dBm
                                  └─[SecurityCCCommandEncapsulation]
                                    │ sequenced: false
                                    └─[FirmwareUpdateMetaDataCCMetaDataReport]
                                        manufacturer id:         59
                                        firmware id:             18064
                                        checksum:                0
                                        firmware upgradable:     true
                                        max fragment size:       20
                                        additional firmware IDs: [18065]
                                        hardware version:        undefined
                                        continues to function:   unknown
                                        supports activation:     unknown
2022-09-06T18:43:49.164Z CNTRLR « [Node 093] Received firmware update capabilities:
                                    firmware targets:      0, 18065
                                    continues to function: unknown
                                    supports activation:   unknown
2022-09-06T18:43:49.165Z CNTRLR   [Node 093] [+] [Firmware Update Meta Data] interviewCo [Endpoint 0] [internal]
                                  mplete: true
2022-09-06T18:43:49.166Z CNTRLR   [Node 093] Root device interview: Device Reset Locally
2022-09-06T18:43:49.167Z CNTRLR   [Node 093] Root device interview: Powerlevel
2022-09-06T18:43:49.167Z CNTRLR   [Node 093] Root device interview: Indicator
2022-09-06T18:43:49.169Z CNTRLR   [Node 093] Interviewing Indicator...
2022-09-06T18:43:49.170Z CNTRLR » [Node 093] scanning supported indicator IDs...
2022-09-06T18:43:49.175Z CNTRLR   [Node 093] Error during node interview: Node #93 does not support the command 
                                  SupportedGet! (ZW0302)
does not support the command HealthGet
2022-09-06T18:48:37.413Z DRIVER « [Node 093] [REQ] [BridgeApplicationCommand]
                                  │ RSSI: -67 dBm
                                  └─[SecurityCCCommandEncapsulation]
                                    │ sequenced: false
                                    └─[BatteryCCReport]
                                        level:  97
                                        is low: false
2022-09-06T18:48:37.418Z CNTRLR « [Node 093] received response for battery information:
                                  level:                           97
                                  status:                          undefined
                                  rechargeable:                    undefined
                                  is backup:                       undefined
                                  is overheating:                  undefined
                                  fluid is low:                    undefined
                                  needs to be replaced or charged: undefined
                                  is low temperature               undefined
                                  is disconnected:                 undefined
2022-09-06T18:48:37.419Z CNTRLR » [Node 093] querying battery health...
2022-09-06T18:48:37.422Z CNTRLR   [Node 093] Error during node interview: Node #93 does not support the command 
                                  HealthGet! (ZW0302)
does not support the command SupportedGet

2022-09-06T18:52:11.895Z DRIVER « [Node 093] [REQ] [BridgeApplicationCommand]
                                  │ RSSI: -68 dBm
                                  └─[SecurityCCCommandEncapsulation]
                                    │ sequenced: false
                                    └─[FirmwareUpdateMetaDataCCMetaDataReport]
                                        manufacturer id:         59
                                        firmware id:             18064
                                        checksum:                0
                                        firmware upgradable:     true
                                        max fragment size:       20
                                        additional firmware IDs: [18065]
                                        hardware version:        undefined
                                        continues to function:   unknown
                                        supports activation:     unknown
2022-09-06T18:52:11.897Z CNTRLR « [Node 093] Received firmware update capabilities:
                                    firmware targets:      0, 18065
                                    continues to function: unknown
                                    supports activation:   unknown
2022-09-06T18:52:11.898Z CNTRLR   [Node 093] [+] [Firmware Update Meta Data] interviewCo [Endpoint 0] [internal]
                                  mplete: true
2022-09-06T18:52:11.898Z CNTRLR   [Node 093] Root device interview: Device Reset Locally
2022-09-06T18:52:11.899Z CNTRLR   [Node 093] Root device interview: Powerlevel
2022-09-06T18:52:11.899Z CNTRLR   [Node 093] Root device interview: Indicator
2022-09-06T18:52:11.901Z CNTRLR   [Node 093] Interviewing Indicator...
2022-09-06T18:52:11.901Z CNTRLR » [Node 093] scanning supported indicator IDs...
2022-09-06T18:52:11.906Z CNTRLR   [Node 093] Error during node interview: Node #93 does not support the command 
                                  SupportedGet! (ZW0302)
does not support the command SupportedGet
2022-09-06T18:54:34.591Z DRIVER « [Node 093] [REQ] [BridgeApplicationCommand]
                                  │ RSSI: -68 dBm
                                  └─[SecurityCCCommandEncapsulation]
                                    │ sequenced: false
                                    └─[FirmwareUpdateMetaDataCCMetaDataReport]
                                        manufacturer id:         59
                                        firmware id:             18064
                                        checksum:                0
                                        firmware upgradable:     true
                                        max fragment size:       20
                                        additional firmware IDs: [18065]
                                        hardware version:        undefined
                                        continues to function:   unknown
                                        supports activation:     unknown
2022-09-06T18:54:34.596Z CNTRLR « [Node 093] Received firmware update capabilities:
                                    firmware targets:      0, 18065
                                    continues to function: unknown
                                    supports activation:   unknown
2022-09-06T18:54:34.597Z CNTRLR   [Node 093] [+] [Firmware Update Meta Data] interviewCo [Endpoint 0] [internal]
                                  mplete: true
2022-09-06T18:54:34.598Z CNTRLR   [Node 093] Root device interview: Device Reset Locally
2022-09-06T18:54:34.598Z CNTRLR   [Node 093] Root device interview: Powerlevel
2022-09-06T18:54:34.599Z CNTRLR   [Node 093] Root device interview: Indicator
2022-09-06T18:54:34.601Z CNTRLR   [Node 093] Interviewing Indicator...
2022-09-06T18:54:34.601Z CNTRLR » [Node 093] scanning supported indicator IDs...
2022-09-06T18:54:34.606Z CNTRLR   [Node 093] Error during node interview: Node #93 does not support the command 
                                  SupportedGet! (ZW0302)
does not support the command HealthGet
2022-09-06T18:57:23.547Z DRIVER « [Node 093] [REQ] [BridgeApplicationCommand]
                                  │ RSSI: -68 dBm
                                  └─[SecurityCCCommandEncapsulation]
                                    │ sequenced: false
                                    └─[BatteryCCReport]
                                        level:  96
                                        is low: false
2022-09-06T18:57:23.562Z CNTRLR « [Node 093] received response for battery information:
                                  level:                           96
                                  status:                          undefined
                                  rechargeable:                    undefined
                                  is backup:                       undefined
                                  is overheating:                  undefined
                                  fluid is low:                    undefined
                                  needs to be replaced or charged: undefined
                                  is low temperature               undefined
                                  is disconnected:                 undefined
2022-09-06T18:57:23.562Z CNTRLR » [Node 093] querying battery health...
2022-09-06T18:57:23.565Z CNTRLR   [Node 093] Error during node interview: Node #93 does not support the command 
                                  HealthGet! (ZW0302)

doug-hoffman avatar Sep 06 '22 19:09 doug-hoffman

@doug-hoffman that was fixed today in https://github.com/zwave-js/node-zwave-js/pull/5015, version 10.0.4 (HA addon 0.1.70, z2m 7.1.0)

AlCalzone avatar Sep 06 '22 19:09 AlCalzone

that was fixed today in #5015, version 10.0.4 (HA addon 0.1.70, z2m 7.1.0)

Excellent! Wasn't certain any of those fixes were related. I've already done a PR to bump the zwavejs2mqtt addon to 7.1.0. Just waiting for it to get released.

doug-hoffman avatar Sep 06 '22 20:09 doug-hoffman

Is there any special configuration I'd need with this new version? I upgraded to 0.46.1 w/ 7.1.0 and 10.0.7 and my interviews are still failing to pick up any metadata even with a 10s timeout.

Berzerker avatar Sep 06 '22 23:09 Berzerker

Please share a driver log of the interview attempt

AlCalzone avatar Sep 07 '22 07:09 AlCalzone

Still seeing issues on 7.1.0, as well. Downgraded to 6.15.2 and the situation is much better. Gotta take a few nights off from messing with z-wave stuff and give attention to other things. I'll collect logs once I have some time to spare.

doug-hoffman avatar Sep 07 '22 12:09 doug-hoffman

So I've solved my issue. Since I had set these up quite a while ago, they were still using S0 legacy "security"

I unenrolled all the locks, generated S2 keys, restarted HA, and reenrolled everything (also replacing batteries in all locks) and everything is back up and running with all expected metadata in-tact.

One thing I also did was I use an Aeotec Gen5 stick, which reportedly has problems when connected to USB 3.0 ports (even though it's USB 2.0 itself) due to some funky signal probing it does on connect. I purchased a short USB 2.0 extension to force it always at USB 2.0.

Not sure which one of these things specifically solved my issues, but my locks are all back up and running again.

Thanks to all for the pointers.

Berzerker avatar Oct 12 '22 02:10 Berzerker

Not sure which one of these things specifically solved my issues

The USB extension definitely played a big part in this

AlCalzone avatar Oct 12 '22 05:10 AlCalzone