[bug] Can't remove failed node: Timeout while waiting for an ACK

[SeraphimSerapis]

Before submitting a bug please read: https://zwave-js.github.io/zwavejs2mqtt/#/troubleshooting/bug_report

Version

Build/Run method

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

zwavejs2mqtt version: 1.1.1 zwavejs version: 6.2.0

Describe the bug

I have one single dead node that I seem to fail from my Z-Wave network. I tried marking it as failed and whenever I then go through the procedure of removing the failed node, I get the below error message (Timeout while waiting for an ACK from the controller).

To Reproduce

Steps to reproduce the behavior:

1. Open the control panel
2. Select the dead node (in my case Node 45)
3. Mark the node as failed
4. Wait 5-10s
5. Select remove failed node
6. Error message appears as a toast

Expected behavior

The node should be removed from my network. Marking the node as failed hides it but restarting the app brings it back. This also causes an empty entity in Home Assistant, since the network still seems to believe this device exists.

Additional context

2021-02-23 09:29:37.280 INFO ZWAVE: Calling api removeFailedNode with args: [ 45, [length]: 1 ]
2021-02-23 09:29:47.232 INFO ZWAVE: Timeout while waiting for an ACK from the controller removeFailedNode {
success: false,
message: 'Timeout while waiting for an ACK from the controller'
}

[robertsLando]

@SeraphimSerapis Please add logs file

[SeraphimSerapis]

@robertsLando Thanks for the swift response. Here we go -- please let me know if these are the logs you are looking for:

Taken from zwavejs_1.log

09:52:02.314 CNTRLR » [Node 045] pinging the node...
09:52:03.929 CNTRLR   No response from controller after 1/3 attempts. Scheduling next try in 100 ms.
09:52:04.884 DRIVER   unexpected response, discarding...
09:52:04.914 CNTRLR   Failed to execute controller command after 2/3 attempts. Scheduling next try i
                      n 1100 ms.
09:52:07.022 CNTRLR   [Node 045] ping failed: Timeout while waiting for an ACK from the controller
09:52:09.557 CNTRLR   No response from controller after 1/3 attempts. Scheduling next try in 100 ms.
09:52:10.114 DRIVER   unexpected response, discarding...
09:52:10.127 CNTRLR   Failed to execute controller command after 2/3 attempts. Scheduling next try i
                      n 1100 ms.
09:52:13.636 DRIVER   unexpected response, discarding...
09:52:13.640 DRIVER     no handlers registered!
09:52:24.456 DRIVER     no handlers registered!
09:52:25.608 DRIVER     no handlers registered!

Taken from zwavejs2mqtt.log

2021-02-23 09:54:04.690 INFO ZWAVE: Node 27: value updated: 50-1-deltaTime-66049 0 => 0
2021-02-23 09:54:06.298 INFO ZWAVE: Calling api isFailedNode with args: [ 45, [length]: 1 ]
2021-02-23 09:54:06.313 INFO ZWAVE: Success zwave api call isFailedNode { success: true, message: 'Success zwave api call', result: true }
2021-02-23 09:54:12.263 INFO ZWAVE: Node 24: value updated: 50-1-value-66049 0.5 => 0
2021-02-23 09:54:12.264 INFO ZWAVE: Node 24: value updated: 50-1-deltaTime-66049 0 => 0
2021-02-23 09:54:13.384 INFO ZWAVE: Calling api removeFailedNode with args: [ 45, [length]: 1 ]
2021-02-23 09:54:15.850 INFO ZWAVE: Node 27: value updated: 50-1-value-66049 0.5 => 0
2021-02-23 09:54:15.850 INFO ZWAVE: Node 27: value updated: 50-1-deltaTime-66049 0 => 0
2021-02-23 09:54:23.432 INFO ZWAVE: Timeout while waiting for an ACK from the controller removeFailedNode {
  success: false,
  message: 'Timeout while waiting for an ACK from the controller'
}
2021-02-23 09:54:24.876 INFO ZWAVE: Node 24: value updated: 50-1-value-66049 0 => 0.5

[robertsLando]

Is zwavejs log level set to debug? Please follow https://zwave-js.github.io/zwavejs2mqtt/#/troubleshooting/bug_report

BTW this colud be a communication issue with the device

[SeraphimSerapis]

I pulled the node's JSON for you and set the logging to debug:

{
  "id": 45,
  "deviceId": null,
  "manufacturer": null,
  "manufacturerId": null,
  "productType": null,
  "productId": null,
  "name": "",
  "loc": "",
  "values": [],
  "groups": [],
  "neighbors": [],
  "ready": false,
  "available": false,
  "hassDevices": {},
  "failed": false,
  "lastActive": null,
  "interviewCompleted": false,
  "firmwareVersion": null,
  "isBeaming": false,
  "isSecure": false,
  "keepAwake": false,
  "maxBaudRate": null,
  "isRouting": null,
  "isFrequentListening": false,
  "isListening": false,
  "status": "Unknown",
  "interviewStage": "ProtocolInfo",
  "_name": "NodeID_45"
}

zwavejs.log

To be honest: I don't think this is an actual device -- rather something I replaced/removed while using OZW with Home Assistant's "old" Z-Wave integration.

[robertsLando]

I just saw that you are using an old version (1.1.1) could you try to update to latest please?

[SeraphimSerapis]

Done! It seems while I used :latest, for some reason my compose setup didn't bother updating the container. The node is now correctly showing as "removed". Thank you for your help!