node-zwave-js: [bug] Aeotec Smart Switch 6 - Fails to complete Interview

Version 1.0.0-alpha.2.51f715c

Build/Run method

Docker
PKG
Manually built (git clone - npm install - npm run build )

zwavejs2mqtt version: 1.0.0-alpha.2.51f715c

Describe the bug After a few hours, all my devices have reached “Complete” but the Aeotec Smart Switch 6 still never reaches “Complete”. Note: This is a case of transitioning from OZW/zwave2mqtt to zwavejs2mqtt. Note: The Smart Switch 6 has been operational with OZW/zwave2mqtt. The Smart Switch 6 reports power/energy meter updates about every 60 sec.

To Reproduce Steps to reproduce the behavior: (With “Log to file” set to on)

GUI Refresh Info (in my case the Smart Switch 6 is node 6). The following zwave-js2mqtt logs:

Logs

14:22:01.691 CNTRLR   [Node 006] Beginning interview - last completed stage: None
14:22:01.692 CNTRLR   [Node 006] new node, doing a full interview...
14:22:01.693 CNTRLR » [Node 006] querying protocol info...
14:22:01.719 CNTRLR « [Node 006] received response for protocol info:
                      basic device class:    Static Controller
                      generic device class:  Binary Switch
                      specific device class: Binary Power Switch
                      is a listening device: true
                      is frequent listening: false
                      is a routing device:   true
                      is a secure device:    unknown
                      is a beaming device:   true
                      maximum baud rate:     40000 kbps
                      version:               4
14:22:01.719 CNTRLR   [Node 006] Interview stage completed: ProtocolInfo
14:22:01.720 CNTRLR » [Node 006] pinging the node...
14:22:01.859 CNTRLR « [Node 006] ping successful
14:22:01.860 CNTRLR » [Node 006] querying node info...
14:22:02.165 CNTRLR « [Node 006] node info received
                      supported CCs:
                      · Z-Wave Plus Info
                      · Binary Switch
                      · Multilevel Switch
                      · Color Switch
                      · Configuration
                      · All Switch
                      · Meter
                      · Clock
                      · Association
                      · Association Group Information
                      · Manufacturer Specific
                      · Version
                      · Firmware Update Meta Data
                      · Powerlevel
                      controlled CCs:
                      · Device Reset Locally
                      · Hail
14:22:02.199 CNTRLR   [Node 006] Interview stage completed: NodeInfo
14:22:02.204 CNTRLR   [Node 006] ManufacturerSpecificCC: doing a complete interview...
14:22:02.204 CNTRLR » [Node 006] querying manufacturer information...
14:22:02.509 CNTRLR « [Node 006] received response for manufacturer information:
                        manufacturer: AEON Labs (0x86)
                        product type: 0x0103
                        product id:   0x60
14:22:02.510 CNTRLR   [Node 006] trying to load device config
14:22:02.511 CNTRLR   [Node 006] no device config loaded
14:22:02.540 CNTRLR   [Node 006] VersionCC: doing a complete interview...
14:22:02.541 CNTRLR » [Node 006] querying node versions...
14:22:02.860 CNTRLR « [Node 006] received response for node versions:
                        library type:      Enhanced Slave (0x03)
                        protocol version:  4.5
                        firmware versions: 1.3
14:22:02.860 CNTRLR » [Node 006] querying CC versions...
14:22:02.860 CNTRLR » [Node 006]   querying the CC version for Binary Switch...
14:22:03.205 CNTRLR   [Node 006]   supports CC Binary Switch (0x25) in version 1
14:22:03.206 CNTRLR   [Node 006]   skipping query for All Switch (0x27) because max implemented vers
                      ion is 0
14:22:03.207 CNTRLR » [Node 006]   querying the CC version for Z-Wave Plus Info...
14:22:03.555 CNTRLR   [Node 006]   supports CC Z-Wave Plus Info (0x5e) in version 2
14:22:03.556 CNTRLR » [Node 006]   querying the CC version for Multilevel Switch...
14:22:03.904 CNTRLR   [Node 006]   supports CC Multilevel Switch (0x26) in version 2
14:22:03.904 CNTRLR » [Node 006]   querying the CC version for Color Switch...
14:22:04.253 CNTRLR   [Node 006]   supports CC Color Switch (0x33) in version 1
14:22:04.253 CNTRLR » [Node 006]   querying the CC version for Configuration...
14:22:04.609 CNTRLR   [Node 006]   supports CC Configuration (0x70) in version 1
14:22:04.615 CNTRLR » [Node 006]   querying the CC version for Meter...
14:22:04.956 CNTRLR   [Node 006]   supports CC Meter (0x32) in version 3
14:22:04.957 CNTRLR   [Node 006]   skipping query for Clock (0x81) because max implemented version i
                      s 1
14:22:04.957 CNTRLR » [Node 006]   querying the CC version for Association...
14:22:05.309 CNTRLR   [Node 006]   supports CC Association (0x85) in version 2
14:22:05.310 CNTRLR » [Node 006]   querying the CC version for Association Group Information...
14:22:05.655 CNTRLR   [Node 006]   supports CC Association Group Information (0x59) in version 1
14:22:05.655 CNTRLR » [Node 006]   querying the CC version for Manufacturer Specific...
14:22:06.008 CNTRLR   [Node 006]   supports CC Manufacturer Specific (0x72) in version 2
14:22:06.009 CNTRLR » [Node 006]   querying the CC version for Version...
14:22:06.357 CNTRLR   [Node 006]   supports CC Version (0x86) in version 2
14:22:06.358 CNTRLR » [Node 006]   querying the CC version for Firmware Update Meta Data...
14:22:06.717 CNTRLR   [Node 006]   supports CC Firmware Update Meta Data (0x7a) in version 2
14:22:06.718 CNTRLR   [Node 006]   skipping query for Powerlevel (0x73) because max implemented vers
                      ion is 0
14:22:06.718 CNTRLR   [Node 006]   skipping query for Device Reset Locally (0x5a) because max implem
                      ented version is 1
14:22:06.719 CNTRLR   [Node 006]   skipping query for Hail (0x82) because max implemented version is
                       1
14:22:06.720 CNTRLR   [Node 006] trying to load device config
14:22:06.738 CNTRLR   [Node 006] device config loaded
14:22:06.755 CNTRLR   [Node 006] ZWavePlusCC: doing a complete interview...
14:22:06.756 CNTRLR » [Node 006] querying Z-Wave+ information...
14:22:16.960 CNTRLR   [Node 006] Interview attempt 1/5 failed, retrying in 5000 ms...
14:22:21.961 CNTRLR   [Node 006] Beginning interview - last completed stage: NodeInfo
14:22:21.967 CNTRLR   [Node 006] ManufacturerSpecificCC: doing a partial interview...
14:22:21.968 CNTRLR   [Node 006] trying to load device config
14:22:21.970 CNTRLR   [Node 006] no device config loaded
14:22:21.996 CNTRLR   [Node 006] VersionCC: doing a partial interview...
14:22:21.997 CNTRLR   [Node 006] trying to load device config
14:22:22.011 CNTRLR   [Node 006] device config loaded
14:22:22.012 CNTRLR   [Node 006] ZWavePlusCC: doing a complete interview...
14:22:22.013 CNTRLR » [Node 006] querying Z-Wave+ information...
14:22:32.158 CNTRLR   [Node 006] Interview attempt 2/5 failed, retrying in 10000 ms...
14:22:42.160 CNTRLR   [Node 006] Beginning interview - last completed stage: NodeInfo
14:22:42.165 CNTRLR   [Node 006] ManufacturerSpecificCC: doing a partial interview...
14:22:42.166 CNTRLR   [Node 006] trying to load device config
14:22:42.167 CNTRLR   [Node 006] no device config loaded
14:22:42.191 CNTRLR   [Node 006] VersionCC: doing a partial interview...
14:22:42.192 CNTRLR   [Node 006] trying to load device config
14:22:42.203 CNTRLR   [Node 006] device config loaded
14:22:42.204 CNTRLR   [Node 006] ZWavePlusCC: doing a complete interview...
14:22:42.204 CNTRLR » [Node 006] querying Z-Wave+ information...
14:22:52.353 CNTRLR   [Node 006] Interview attempt 3/5 failed, retrying in 15000 ms...
14:23:07.354 CNTRLR   [Node 006] Beginning interview - last completed stage: NodeInfo
14:23:07.360 CNTRLR   [Node 006] ManufacturerSpecificCC: doing a partial interview...
14:23:07.361 CNTRLR   [Node 006] trying to load device config
14:23:07.362 CNTRLR   [Node 006] no device config loaded
14:23:07.386 CNTRLR   [Node 006] VersionCC: doing a partial interview...
14:23:07.387 CNTRLR   [Node 006] trying to load device config
14:23:07.403 CNTRLR   [Node 006] device config loaded
14:23:07.404 CNTRLR   [Node 006] ZWavePlusCC: doing a complete interview...
14:23:07.405 CNTRLR » [Node 006] querying Z-Wave+ information...
14:23:17.555 CNTRLR   [Node 006] Interview attempt 4/5 failed, retrying in 20000 ms...
14:23:37.556 CNTRLR   [Node 006] Beginning interview - last completed stage: NodeInfo
14:23:37.562 CNTRLR   [Node 006] ManufacturerSpecificCC: doing a partial interview...
14:23:37.564 CNTRLR   [Node 006] trying to load device config
14:23:37.565 CNTRLR   [Node 006] no device config loaded
14:23:37.587 CNTRLR   [Node 006] VersionCC: doing a partial interview...
14:23:37.588 CNTRLR   [Node 006] trying to load device config
14:23:37.599 CNTRLR   [Node 006] device config loaded
14:23:37.600 CNTRLR   [Node 006] ZWavePlusCC: doing a complete interview...
14:23:37.600 CNTRLR » [Node 006] querying Z-Wave+ information...
14:23:47.745 CNTRLR   [Node 006] Failed all interview attempts, giving up.

About this issue

Original URL
State: closed
Created 3 years ago
Comments: 39 (24 by maintainers)

Most upvoted comments

It took a while to get the install procedure worked out, and I am happy to say, that node-zwavejs v6.1.1 solved this problem and my Smartswitch 6 completed the interview process!! Thanks 😃

tommyjlong on Jan 31, 2021

As a reference/FYI, when I do the same thing in zwave2mqtt using OZW, OZW also does not get a response on zwaveplus info, but seems to keep on going; getting to what I think is its final state of “Complete”:

.....
2021-01-14 14:26:10.215 Detail, Node006, AdvanceQueries queryPending=0 queryRetries=0 queryStage=NodePlusInfo live=1
2021-01-14 14:26:10.215 Detail, Node006, QueryStage_NodePlusInfo
2021-01-14 14:26:10.216 Detail, Node006, Queuing (Query) ZWavePlusInfoCmd_Get (Node=6): 0x01, 0x09, 0x00, 0x13, 0x06, 0x02, 0x5e, 0x01, 0x25, 0xde, 0x45
2021-01-14 14:26:10.216 Detail, Node006, Queuing (Query) Query Stage Complete (NodePlusInfo)
2021-01-14 14:26:10.217 Detail, 
2021-01-14 14:26:10.217 Info, Node006, Sending (Query) message (Callback ID=0xde, Expected Reply=0x04) - ZWavePlusInfoCmd_Get (Node=6): 0x01, 0x09, 0x00, 0x13, 0x06, 0x02, 0x5e, 0x01, 0x25, 0xde, 0x45
2021-01-14 14:26:10.217 Info, Node006, Encrypted Flag is 0
2021-01-14 14:26:10.244 Detail, Node006,   Received: 0x01, 0x04, 0x01, 0x13, 0x01, 0xe8
2021-01-14 14:26:10.245 Detail, Node006,   ZW_SEND_DATA delivered to Z-Wave stack
2021-01-14 14:26:10.426 Detail, Node006,   Received: 0x01, 0x07, 0x00, 0x13, 0xde, 0x00, 0x00, 0x14, 0x21
2021-01-14 14:26:10.428 Detail, Node006,   ZW_SEND_DATA Request with callback ID 0xde received (expected 0xde)
2021-01-14 14:26:10.430 Info, Node006, Request RTT 212 Average Request RTT 170
2021-01-14 14:26:10.432 Detail, Node006,   Expected callbackId was received
2021-01-14 14:26:20.218 Error, Node006, ERROR: Dropping command, expected response not received after 1 attempt(s). Command: "ZWavePlusInfoCmd_Get (Node=6): 0x01, 0x09, 0x00, 0x13, 0x06, 0x02, 0x5e, 0x01, 0x25, 0xde, 0x45"
2021-01-14 14:26:20.218 Detail, Node006, Removing current message
2021-01-14 14:26:20.218 Detail, Node006, Notification: Notification - TimeOut
2021-01-14 14:26:20.219 Detail, Node006, Query Stage Complete (NodePlusInfo)
.....
2021-01-14 14:27:07.653 Detail, Node006, Query Stage Complete (Dynamic)
2021-01-14 14:27:07.653 Detail, Node006, AdvanceQueries queryPending=0 queryRetries=0 queryStage=Configuration live=1
2021-01-14 14:27:07.653 Detail, Node006, QueryStage_Configuration
2021-01-14 14:27:07.653 Detail, Node006, QueryStage_Complete
2021-01-14 14:27:07.653 Warning, CheckCompletedNodeQueries m_allNodesQueried=0 m_awakeNodesQueried=1
2021-01-14 14:27:07.653 Warning, CheckCompletedNodeQueries all=0, deadFound=0 sleepingOnly=1
2021-01-14 14:27:07.654 Info, Saving Cache
..
2021-01-14 14:27:07.661 Info, Node006, Cache Save for Node 6 as its QueryStage_CacheLoad
..
2021-01-14 14:27:07.684 Detail, Node006, Notification: NodeQueriesComplete

tommyjlong on Jan 14, 2021