Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Z-Wave JS failure #3234

Closed
ablyes opened this issue Sep 27, 2023 · 162 comments
Closed

Z-Wave JS failure #3234

ablyes opened this issue Sep 27, 2023 · 162 comments

Comments

@ablyes
Copy link

ablyes commented Sep 27, 2023

Describe the issue you are experiencing

Since the last version of home assitant
Home Assistant 2023.9.3
Supervisor 2023.09.2
Operating System 10.5
Interface utilisateur : 20230911.0 - latest
Z-Wave JS Current version: 0.1.93

My Z-Wave devices are not working. I have this error in the logs:

2023-09-27T16:30:01.702Z CNTRLR   [Node 026] ping failed: The node did not acknowledge the command (ZW0204)
2023-09-27T16:30:04.424Z DRIVER     no handlers registered!
2023-09-27T16:31:09.423Z CNTRLR   The controller is unresponsive
2023-09-27T16:31:09.427Z DRIVER   Attempting to recover unresponsive controller...
2023-09-27T16:31:09.518Z CNTRLR   The controller does not support soft reset or the soft reset feature has been 
                                  disabled with a config option or the ZWAVEJS_DISABLE_SOFT_RESET environment va
                                  riable.
2023-09-27T16:31:09.521Z DRIVER   Recovering unresponsive controller failed. Restarting the driver...
Error in driver ZWaveError: Recovering unresponsive controller failed. Restarting the driver... (ZW0100)
    at Driver.destroyWithMessage (/usr/src/node_modules/zwave-js/src/lib/driver/Driver.ts:2769:17)
    at fail (/usr/src/node_modules/zwave-js/src/lib/driver/Driver.ts:3484:14)
    at /usr/src/node_modules/zwave-js/src/lib/driver/Driver.ts:3533:5
    at runNextTicks (node:internal/process/task_queues:60:5)
    at processTimers (node:internal/timers:509:9) {
  code: 100,
  context: undefined,
  transactionSource: undefined
}
Shutting down
Closing server...
2023-09-27T16:31:09.541Z CNTRLR   [Node 017] Assigning SUC return route failed: Timeout while waiting for a call
                                  back from the controller (ZW0200)
Client disconnected
Code 1000: 
Server closed
[16:31:10] WARNING: Halt add-on
s6-rc: info: service legacy-services: stopping
s6-rc: info: service legacy-services successfully stopped
s6-rc: info: service legacy-cont-init: stopping
s6-rc: info: service legacy-cont-init successfully stopped
s6-rc: info: service fix-attrs: stopping
s6-rc: info: service fix-attrs successfully stopped
s6-rc: info: service s6rc-oneshot-runner: stopping
s6-rc: info: service s6rc-oneshot-runner successfully stopped

What type of installation are you running?

Home Assistant Supervised

Which operating system are you running on?

Home Assistant Operating System

Which add-on are you reporting an issue with?

Z-Wave JS

What is the version of the add-on?

0.1.93

Steps to reproduce the issue

  • start z-wave js addon
  • check the logs with errors

System Health information

Message in french : Aucune correction n'est actuellement disponible
-> no correction

Anything in the Supervisor logs that might be useful for us?

No response

Anything in the add-on logs that might be useful for us?

No response

Additional information

No response

@Gonioul
Copy link

Gonioul commented Sep 27, 2023

Seems ok now with 9.0.1

@raman325
Copy link
Collaborator

@ablyes can you set your addon logs to debug and then paste the results here?

CC @AlCalzone

@tkdrob
Copy link

tkdrob commented Sep 28, 2023

This is mine

2023-09-28T01:25:07.546Z CNTRLR   [Node 008] [~] [Binary Switch] currentValue: false => false       [Endpoint 0]
2023-09-28T01:25:07.547Z DRIVER « [Node 008] [REQ] [ApplicationCommand]
                                  └─[BinarySwitchCCReport]
                                      current value: false
2023-09-28T01:25:08.042Z SERIAL « 0x01090004000603250300d1                                            (11 bytes)
2023-09-28T01:25:08.044Z SERIAL » [ACK]                                                                   (0x06)
2023-09-28T01:25:08.045Z CNTRLR   [Node 006] [~] [Binary Switch] currentValue: false => false       [Endpoint 0]
2023-09-28T01:25:08.046Z DRIVER « [Node 006] [REQ] [ApplicationCommand]
                                  └─[BinarySwitchCCReport]
                                      current value: false
2023-09-28T01:25:08.496Z SERIAL « 0x01090004000803250300df                                            (11 bytes)
2023-09-28T01:25:08.497Z SERIAL » [ACK]                                                                   (0x06)
2023-09-28T01:25:08.497Z CNTRLR   [Node 008] [~] [Binary Switch] currentValue: false => false       [Endpoint 0]
2023-09-28T01:25:08.498Z DRIVER « [Node 008] [REQ] [ApplicationCommand]
                                  └─[BinarySwitchCCReport]
                                      current value: false
2023-09-28T01:25:09.075Z SERIAL « 0x01090004000603250300d1                                            (11 bytes)
2023-09-28T01:25:09.076Z SERIAL » [ACK]                                                                   (0x06)
2023-09-28T01:25:09.076Z CNTRLR   [Node 006] [~] [Binary Switch] currentValue: false => false       [Endpoint 0]
2023-09-28T01:25:09.076Z DRIVER « [Node 006] [REQ] [ApplicationCommand]
                                  └─[BinarySwitchCCReport]
                                      current value: false
2023-09-28T01:25:09.429Z SERIAL « 0x01090004000803250300df                                            (11 bytes)
2023-09-28T01:25:09.429Z SERIAL » [ACK]                                                                   (0x06)
2023-09-28T01:25:09.430Z CNTRLR   [Node 008] [~] [Binary Switch] currentValue: false => false       [Endpoint 0]
2023-09-28T01:25:09.430Z DRIVER « [Node 008] [REQ] [ApplicationCommand]
                                  └─[BinarySwitchCCReport]
                                      current value: false
2023-09-28T01:25:10.110Z SERIAL « 0x01090004000603250300d1                                            (11 bytes)
2023-09-28T01:25:10.112Z SERIAL » [ACK]                                                                   (0x06)
2023-09-28T01:25:10.113Z CNTRLR   [Node 006] [~] [Binary Switch] currentValue: false => false       [Endpoint 0]
2023-09-28T01:25:10.114Z DRIVER « [Node 006] [REQ] [ApplicationCommand]
                                  └─[BinarySwitchCCReport]
                                      current value: false
2023-09-28T01:25:10.363Z SERIAL « 0x01090004000803250300df                                            (11 bytes)
2023-09-28T01:25:10.363Z SERIAL » [ACK]                                                                   (0x06)
2023-09-28T01:25:10.363Z CNTRLR   [Node 008] [~] [Binary Switch] currentValue: false => false       [Endpoint 0]
2023-09-28T01:25:10.364Z DRIVER « [Node 008] [REQ] [ApplicationCommand]
                                  └─[BinarySwitchCCReport]
                                      current value: false
2023-09-28T01:25:10.511Z SERIAL « 0x010500132401cc                                                     (7 bytes)
2023-09-28T01:25:10.511Z SERIAL » [ACK]                                                                   (0x06)
2023-09-28T01:25:10.511Z DRIVER « [REQ] [SendData]
                                    callback id:     36
                                    transmit status: NoAck
2023-09-28T01:25:10.512Z CNTRLR   [Node 013] The node did not respond after 1 attempts, it is presumed dead
2023-09-28T01:25:10.512Z CNTRLR   [Node 013] The node is dead.
2023-09-28T01:25:10.512Z CNTRLR   [Node 013] ping failed: The node did not acknowledge the command (ZW0204)
2023-09-28T01:25:10.512Z CNTRLR » [Node 013] querying node info...
2023-09-28T01:25:10.512Z CNTRLR » [Node 013] pinging the node...
2023-09-28T01:25:10.513Z SERIAL » 0x010800131001002525f5                                              (10 bytes)
2023-09-28T01:25:10.514Z DRIVER » [Node 016] [REQ] [SendData]
                                  │ transmit options: 0x25
                                  │ callback id:      37
                                  └─[NoOperationCC]
2023-09-28T01:25:10.515Z SERIAL « [ACK]                                                                   (0x06)
2023-09-28T01:25:20.519Z CNTRLR   No response from controller after 1/3 attempts. Scheduling next try in 100 ms.
2023-09-28T01:25:20.620Z DRIVER » [Node 016] [REQ] [SendData]
                                  │ transmit options: 0x25
                                  │ callback id:      37
                                  └─[NoOperationCC]
2023-09-28T01:25:20.621Z SERIAL » 0x010800131001002525f5                                              (10 bytes)
2023-09-28T01:25:21.623Z CNTRLR   Failed to execute controller command after 2/3 attempts. Scheduling next try i
                                  n 1100 ms.
2023-09-28T01:25:22.725Z DRIVER » [Node 016] [REQ] [SendData]
                                  │ transmit options: 0x25
                                  │ callback id:      37
                                  └─[NoOperationCC]
2023-09-28T01:25:22.725Z SERIAL » 0x010800131001002525f5                                              (10 bytes)
2023-09-28T01:25:23.726Z CNTRLR   The controller is unresponsive
2023-09-28T01:25:23.726Z DRIVER   Attempting to recover unresponsive controller...
2023-09-28T01:25:23.748Z CNTRLR   Performing soft reset...
2023-09-28T01:25:23.750Z SERIAL » 0x01030008f4                                                         (5 bytes)
2023-09-28T01:25:23.751Z DRIVER » [REQ] [SoftReset]
2023-09-28T01:25:24.753Z CNTRLR   Failed to execute controller command after 1/3 attempts. Scheduling next try i
                                  n 100 ms.
2023-09-28T01:25:24.854Z DRIVER » [REQ] [SoftReset]
2023-09-28T01:25:24.855Z SERIAL » 0x01030008f4                                                         (5 bytes)
2023-09-28T01:25:25.856Z CNTRLR   Failed to execute controller command after 2/3 attempts. Scheduling next try i
                                  n 1100 ms.
2023-09-28T01:25:26.957Z DRIVER » [REQ] [SoftReset]
2023-09-28T01:25:26.958Z SERIAL » 0x01030008f4                                                         (5 bytes)
2023-09-28T01:25:27.960Z CNTRLR   Soft reset failed: Timeout while waiting for an ACK from the controller (ZW020
                                  0)
2023-09-28T01:25:27.961Z DRIVER   Recovering unresponsive controller failed. Restarting the driver...
Error in driver ZWaveError: Recovering unresponsive controller failed. Restarting the driver... (ZW0100)
    at Driver.destroyWithMessage (/usr/src/node_modules/zwave-js/src/lib/driver/Driver.ts:2769:17)
    at fail (/usr/src/node_modules/zwave-js/src/lib/driver/Driver.ts:3484:14)
    at /usr/src/node_modules/zwave-js/src/lib/driver/Driver.ts:3533:5
    at runNextTicks (node:internal/process/task_queues:60:5)
    at processTimers (node:internal/timers:509:9) {
  code: 100,
  context: undefined,
  transactionSource: undefined
}
Shutting down
Closing server...
2023-09-28T01:25:27.970Z DRIVER   destroying driver instance...
2023-09-28T01:25:27.971Z CNTRLR   [Node 016] ping failed: Timeout while waiting for an ACK from the controller (
                                  ZW0200)
2023-09-28T01:25:27.972Z CNTRLR » [Node 016] querying node info...
2023-09-28T01:25:27.973Z CNTRLR » [Node 016] Assigning SUC return route...
2023-09-28T01:25:27.973Z CNTRLR » [Node 016] Deleting SUC return route...
2023-09-28T01:25:27.973Z CNTRLR   [Node 016] Deleting SUC return route failed: The driver is not ready or has be
                                  en destroyed (ZW0103)
2023-09-28T01:25:27.974Z CNTRLR   [Node 016] Assigning SUC return route failed: The driver is not ready or has b
                                  een destroyed (ZW0103)
2023-09-28T01:25:27.975Z DRIVER   all queues idle

@AlCalzone
Copy link
Contributor

Honestly this last log looks like the recovery mechanism is working as intended, although it isn't successful.

The controller stops responding completely and after 3 attempts of sending, followed by 3 attempts of restarting the stick without success, the driver gives up.

Afterwards zwave-js-server should restart the driver (not sure if it does here?), which reopens the serial port, hopefully causing the stick to respond again.

@Turtle-code
Copy link

Turtle-code commented Sep 28, 2023

I have the same issue after i updated to 0.1.93 this morning.
The driver seems to start, i see some z-wave nodes communicating, but then the controller seems to get unresponsive, and it tries to reboot.

2023-09-28 12:07:41.153 INFO Z-WAVE: [Node 015] Value added 15-50-2-value-65537 => 0
2023-09-28 12:07:41.153 INFO Z-WAVE: [Node 015] Value added 15-50-2-reset => undefined
2023-09-28 12:07:41.155 INFO Z-WAVE: [Node 015] Ready: Fibargroup - FGS223 (Double Switch 2)
2023-09-28T10:07:41.155Z CNTRLR Retrieving priority route to node 15...
2023-09-28T10:07:41.155Z CNTRLR [Node 015] The node is ready to be used
2023-09-28T10:07:41.156Z CNTRLR « [Node 015] ping successful
2023-09-28 12:07:41.666 INFO Z-WAVE-SERVER: DNS Service Discovery enabled
2023-09-28 12:07:42.752 INFO APP: GET /health/zwave 301 1.313 ms - 191
2023-09-28 12:07:53.090 INFO APP: GET /assets/BlinkIcon-b44c4502.js 304 1.701 ms - -
2023-09-28 12:08:42.963 INFO APP: GET /health/zwave 301 1.770 ms - 191
2023-09-28T10:08:46.677Z CNTRLR The controller is unresponsive
2023-09-28 12:08:46.679 INFO Z-WAVE: Controller status: Controller is unresponsive
2023-09-28T10:08:46.680Z DRIVER Attempting to recover unresponsive controller...
2023-09-28T10:08:46.680Z CNTRLR Performing soft reset...
2023-09-28T10:08:47.686Z CNTRLR Failed to execute controller command after 1/3 attempts. Scheduling next try i
n 100 ms.
2023-09-28T10:08:48.798Z CNTRLR Failed to execute controller command after 2/3 attempts. Scheduling next try i
n 1100 ms.
2023-09-28T10:08:50.906Z CNTRLR Soft reset failed: Timeout while waiting for an ACK from the controller (ZW020
0)
2023-09-28T10:08:50.908Z DRIVER Recovering unresponsive controller failed. Restarting the driver...
2023-09-28 12:08:50.909 INFO Z-WAVE: Controller status: Driver: Recovering unresponsive controller failed. Restarting the driver... (ZW0100)
2023-09-28 12:08:50.909 INFO Z-WAVE: Restarting client in 1 seconds, retry 1
2023-09-28T10:08:50.910Z CNTRLR [Node 039] ping failed: Timeout while waiting for a callback from the controll
er (ZW0200)
2023-09-28 12:08:51.920 INFO Z-WAVE-SERVER: Client disconnected
2023-09-28 12:08:51.932 INFO Z-WAVE-SERVER: Server closed
2023-09-28 12:08:51.933 INFO Z-WAVE: Client closed
2023-09-28 12:08:51.936 INFO Z-WAVE: Connecting to /dev/serial/by-id/usb-0658_0200-if00
2023-09-28 12:08:51.936 INFO Z-WAVE: Setting user callbacks
2023-09-28T10:08:51.938Z DRIVER ███████╗ ██╗ ██╗ █████╗ ██╗ ██╗ ███████╗ ██╗ ███████╗
╚══███╔╝ ██║ ██║ ██╔══██╗ ██║ ██║ ██╔════╝ ██║ ██╔════╝
███╔╝ ██║ █╗ ██║ ███████║ ██║ ██║ █████╗ █████╗ ██║ ███████╗
███╔╝ ██║███╗██║ ██╔══██║ ╚██╗ ██╔╝ ██╔══╝ ╚════╝ ██ ██║ ╚════██║
███████╗ ╚███╔███╔╝ ██║ ██║ ╚████╔╝ ███████╗ ╚█████╔╝ ███████║
╚══════╝ ╚══╝╚══╝ ╚═╝ ╚═╝ ╚═══╝ ╚══════╝ ╚════╝ ╚══════╝
2023-09-28T10:08:51.938Z DRIVER version 12.0.0
2023-09-28T10:08:51.938Z DRIVER
2023-09-28T10:08:52.948Z CONFIG version 12.0.0
2023-09-28T10:08:53.304Z CNTRLR querying Serial API capabilities...
2023-09-28T10:08:54.309Z CNTRLR Failed to execute controller command after 1/3 attempts. Scheduling next try i
n 100 ms.
2023-09-28T10:08:55.415Z CNTRLR Failed to execute controller command after 2/3 attempts. Scheduling next try i
n 1100 ms.
2023-09-28T10:08:57.524Z CNTRLR The controller is unresponsive
2023-09-28T10:08:57.525Z DRIVER Attempting to recover unresponsive controller...
2023-09-28T10:08:57.526Z CNTRLR Performing soft reset...
2023-09-28T10:08:58.531Z CNTRLR Failed to execute controller command after 1/3 attempts. Scheduling next try i
n 100 ms.
2023-09-28T10:08:59.636Z CNTRLR Failed to execute controller command after 2/3 attempts. Scheduling next try i
n 1100 ms.
2023-09-28T10:09:01.742Z CNTRLR Soft reset failed: Timeout while waiting for an ACK from the controller (ZW020
0)
2023-09-28T10:09:01.743Z DRIVER Recovering unresponsive controller failed. Restarting the driver...

After a while the driver does manage to start, but within a minute, the whole thing happens again.

@AlCalzone
Copy link
Contributor

Which controller do you have? Which firmware version (if 700/800 series)?
Which path are you accessing it through?

@Turtle-code
Copy link

Turtle-code commented Sep 28, 2023

I'm using an Aeotec Gen5, running on:
Home Assistant 2023.9.3
Supervisor 2023.09.2
Operation system: 10.5
Frontend-version: 20230911.0 - latest

Z-wave JS UI: 2.0.1
Z-wave JS: 0.1.93

@AlCalzone
Copy link
Contributor

AlCalzone commented Sep 28, 2023

Which path are you accessing it through? /dev/...?

@ablyes
Copy link
Author

ablyes commented Sep 28, 2023

I had the same issue with this version. Here is the path i'm using :
/dev/serial/by-id/usb-0658_0200-if00

image

@mattster98
Copy link

mattster98 commented Sep 28, 2023

Similar scenario here.. stopped working recently, similar logs. It all starts well and good, but then just hangs. My hardware reports Aeotec Z-Stick Gen5 (ZW090) - UZB

Device: ttyACM0 - /dev/serial/by-id/usb-0658_0200_01FFFFFF-FFFF-FFFF-FFFF-160316112940-if00, s/n: 01FFFFFF-FFFF-FFFF-FFFF-160316112940 - 0658:0200

Debug log tail:

2023-09-28T12:43:55.043Z CNTRLR   [Node 013] The node did not respond after 1 attempts, it is presumed dead
2023-09-28T12:43:55.044Z CNTRLR   [Node 013] The node is dead.
2023-09-28T12:43:55.047Z CNTRLR   [Node 013] ping failed: The node did not acknowledge the command (ZW0204)
2023-09-28T12:43:55.048Z CNTRLR » [Node 013] querying node info...
2023-09-28T12:43:55.049Z CNTRLR » [Node 013] pinging the node...
2023-09-28T12:43:55.054Z SERIAL » 0x010800131201002519cb                                              (10 bytes)
2023-09-28T12:43:55.055Z DRIVER » [Node 018] [REQ] [SendData]
                                  │ transmit options: 0x25
                                  │ callback id:      25
                                  └─[NoOperationCC]
2023-09-28T12:43:55.058Z SERIAL « [ACK]                                                                   (0x06)
2023-09-28T12:43:55.065Z SERIAL « 0x0104011301e8                                                       (6 bytes)
2023-09-28T12:43:55.066Z SERIAL » [ACK]                                                                   (0x06)
2023-09-28T12:43:55.066Z DRIVER « [RES] [SendData]
                                    was sent: true
2023-09-28T12:45:00.076Z SERIAL » 0x01030016ea                                                         (5 bytes)
2023-09-28T12:45:00.080Z DRIVER » [REQ] [SendDataAbort]
2023-09-28T12:45:00.585Z CNTRLR   The controller is unresponsive
2023-09-28T12:45:00.590Z DRIVER   Attempting to recover unresponsive controller...
2023-09-28T12:45:00.668Z CNTRLR   Performing soft reset...
2023-09-28T12:45:00.677Z SERIAL » 0x01030008f4                                                         (5 bytes)
2023-09-28T12:45:00.679Z DRIVER » [REQ] [SoftReset]
2023-09-28T12:45:01.686Z CNTRLR   Failed to execute controller command after 1/3 attempts. Scheduling next try i
                                  n 100 ms.
2023-09-28T12:45:01.788Z DRIVER » [REQ] [SoftReset]
2023-09-28T12:45:01.789Z SERIAL » 0x01030008f4                                                         (5 bytes)
2023-09-28T12:45:02.795Z CNTRLR   Failed to execute controller command after 2/3 attempts. Scheduling next try i
                                  n 1100 ms.
2023-09-28T12:45:03.899Z DRIVER » [REQ] [SoftReset]
2023-09-28T12:45:03.901Z SERIAL » 0x01030008f4                                                         (5 bytes)
2023-09-28T12:45:04.909Z CNTRLR   Soft reset failed: Timeout while waiting for an ACK from the controller (ZW020
                                  0)
2023-09-28T12:45:04.910Z DRIVER   Recovering unresponsive controller failed. Restarting the driver...
Error in driver ZWaveError: Recovering unresponsive controller failed. Restarting the driver... (ZW0100)
    at Driver.destroyWithMessage (/usr/src/node_modules/zwave-js/src/lib/driver/Driver.ts:2769:17)
    at fail (/usr/src/node_modules/zwave-js/src/lib/driver/Driver.ts:3484:14)
    at /usr/src/node_modules/zwave-js/src/lib/driver/Driver.ts:3533:5 {
  code: 100,
  context: undefined,
  transactionSource: undefined
}
Shutting down
Closing server...
2023-09-28T12:45:04.932Z DRIVER   destroying driver instance...
2023-09-28T12:45:04.938Z CNTRLR   [Node 018] ping failed: Timeout while waiting for a callback from the controll
                                  er (ZW0200)
2023-09-28T12:45:04.939Z CNTRLR » [Node 018] querying node info...
2023-09-28T12:45:04.943Z CNTRLR » [Node 018] Assigning SUC return route...
2023-09-28T12:45:04.944Z CNTRLR » [Node 018] Deleting SUC return route...
2023-09-28T12:45:04.946Z CNTRLR   [Node 018] Deleting SUC return route failed: The driver is not ready or has be
                                  en destroyed (ZW0103)
2023-09-28T12:45:04.948Z CNTRLR   [Node 018] Assigning SUC return route failed: The driver is not ready or has b
                                  een destroyed (ZW0103)
2023-09-28T12:45:04.956Z DRIVER   all queues idle
Client disconnected
Code 1000: 
Server closed
2023-09-28T12:45:05.105Z DRIVER   driver instance destroyed
[12:45:05] WARNING: Halt add-on
s6-rc: info: service legacy-services: stopping
s6-rc: info: service legacy-services successfully stopped
s6-rc: info: service legacy-cont-init: stopping
s6-rc: info: service legacy-cont-init successfully stopped
s6-rc: info: service fix-attrs: stopping
s6-rc: info: service fix-attrs successfully stopped
s6-rc: info: service s6rc-oneshot-runner: stopping
s6-rc: info: service s6rc-oneshot-runner successfully stopped

@Turtle-code
Copy link

Which path are you accessing it through? /dev/...?

I'm connecting trough: /dev/serial/by-id/usb-0658_0200-if00

My aeotec Gen5 stick is the old regular version (not Gen5+), running on v1.1.

I found there was a firmware update at aeotec: https://aeotec.freshdesk.com/support/solutions/articles/6000252294-z-stick-gen5-v1-02-firmware-update
It's quite a tricky upgrade, it can brick the stick, so no warranty's on this one.

I upgraded my stick 10 minutes ago via my Windows machine (it was quite a hassle to get the driver and the upgrade working). but since then no crashes yet... fingers crossed!

@ablyes
Copy link
Author

ablyes commented Sep 28, 2023

This company is doing bullshit, not devices.
How can they bring a new firmware, and ask people to update their own products without any garantie ?
"7. Use the firmware update at your own risk, warranty is void if the Z-Stick Gen5 is bricked by the firmware update."
-> They are just stupid.

@MartinHjelmare
Copy link
Member

MartinHjelmare commented Sep 28, 2023

I'm using an Aeotec Gen5, running on: Home Assistant 2023.9.3 Supervisor 2023.09.2 Operation system: 10.5 Frontend-version: 20230911.0 - latest

Z-wave JS UI: 2.0.1 Z-wave JS: 0.1.93

The Z-Wave JS UI add-on and the Z-Wave JS official add-on are not compatible to be run at the same time. If you run both at the same time they will compete for the serial port and problems may arise.

@AlCalzone
Copy link
Contributor

AlCalzone commented Sep 28, 2023

According to hassio-addons/addon-zwave-js-ui#584 this is likely to be an issue with VMs. Some 500 series controllers reconnect to USB when being restarted (soft-reset). Some VMs require specific configuration to be able to handle this, otherwise the connection to the controller gets lost.

The proper solution would be to configure the VM correctly (whatever correct is), the easy solution is disabling soft-reset.

Previous versions tried to auto-detect whether a controller would come back after soft-resetting and remember this info, but this feature had false negatives, so it was removed in node-zwave-js v12.

@MartinHjelmare
Copy link
Member

We disable soft-reset if we detect a VM in the add-on.

@MartinHjelmare
Copy link
Member

What's the indication that the affected users in this issue are using VMs?

@AlCalzone
Copy link
Contributor

What's the indication that the affected users in this issue are using VMs?

Not 100% sure but the lack of ACK from the controller after the SoftReset command might be one:

2023-09-28T12:45:00.668Z CNTRLR Performing soft reset...
2023-09-28T12:45:00.677Z SERIAL » 0x01030008f4 (5 bytes)
2023-09-28T12:45:00.679Z DRIVER » [REQ] [SoftReset]
2023-09-28T12:45:01.686Z CNTRLR Failed to execute controller command after 1/3 attempts. Scheduling next try i
n 100 ms.
2023-09-28T12:45:01.788Z DRIVER » [REQ] [SoftReset]
2023-09-28T12:45:01.789Z SERIAL » 0x01030008f4 (5 bytes)
2023-09-28T12:45:02.795Z CNTRLR Failed to execute controller command after 2/3 attempts. Scheduling next try i
n 1100 ms.
2023-09-28T12:45:03.899Z DRIVER » [REQ] [SoftReset]
2023-09-28T12:45:03.901Z SERIAL » 0x01030008f4 (5 bytes)
2023-09-28T12:45:04.909Z CNTRLR Soft reset failed: Timeout while waiting for an ACK from the controller (ZW020
0)

If the controller did receive and handle the SoftReset, it may have disconnected the USB for a short time, severing the connection to Z-Wave JS.

That and the users in the linked issue having very similar problems with soft-reset.

@Turtle-code
Copy link

According to hassio-addons/addon-zwave-js-ui#584 this is likely to be an issue with VMs. Some 500 series controllers reconnect to USB when being restarted (soft-reset). Some VMs require specific configuration to be able to handle this, otherwise the connection to the controller gets lost.

The proper solution would be to configure the VM correctly (whatever correct is), the easy solution is disabling soft-reset.

Previous versions tried to auto-detect whether a controller would come back after soft-resetting and remember this info, but this feature had false negatives, so it was removed in node-zwave-js v12.

I found that post, but disabling the soft-reset didn't work. (for me at least)
I'm running my Home assistant on a NUC, no virtual layer between home assistant and the NUC.

I'm using an Aeotec Gen5, running on: Home Assistant 2023.9.3 Supervisor 2023.09.2 Operation system: 10.5 Frontend-version: 20230911.0 - latest
Z-wave JS UI: 2.0.1 Z-wave JS: 0.1.93

The Z-Wave JS UI add-on and the Z-Wave JS official add-on are not compatible to be run at the same time. If you run both at the same time they will compete for the serial port and problems may arise.

A bit later i found out that i had Z-Wave JS not running; so i am only using Z-Wave JS UI.
(But with Z-Wave JS UI stopped, i had the same issue in Z-Wave JS)

For me the firmware upgrade to v1.2 did the trick, it's still up and running.

@mattster98
Copy link

mattster98 commented Sep 28, 2023

I'm running HAOS. I'm pretty sure that means it's all running in VMs.

Still seeing a soft reset in my logs.

2023-09-28T13:21:14.598Z CNTRLR « [Node 038] ping successful
2023-09-28T13:21:15.878Z CNTRLR   [Node 026] The node is alive.
2023-09-28T13:21:15.881Z CNTRLR   [Node 026] The node is ready to be used
2023-09-28T13:21:15.884Z CNTRLR « [Node 026] ping successful
2023-09-28T13:21:22.675Z CNTRLR   [Node 002] The node did not respond after 1 attempts, it is presumed dead
2023-09-28T13:21:22.679Z CNTRLR   [Node 002] The node is dead.
2023-09-28T13:21:22.683Z CNTRLR   [Node 002] ping failed: The node did not acknowledge the command (ZW0204)
2023-09-28T13:21:22.684Z CNTRLR » [Node 002] querying node info...
2023-09-28T13:21:22.684Z CNTRLR » [Node 002] pinging the node...
2023-09-28T13:21:26.834Z CNTRLR   [Node 013] The node did not respond after 1 attempts, it is presumed dead
2023-09-28T13:21:26.836Z CNTRLR   [Node 013] The node is dead.
2023-09-28T13:21:26.839Z CNTRLR   [Node 013] ping failed: The node did not acknowledge the command (ZW0204)
2023-09-28T13:21:26.840Z CNTRLR » [Node 013] querying node info...
2023-09-28T13:21:26.841Z CNTRLR » [Node 013] pinging the node...
New client
Z-Wave JS no longer supports enabling error reporting. If you are using an application that integrates with Z-Wave JS and you receive this error, you may need to update the application.
2023-09-28T13:22:32.373Z CNTRLR   The controller is unresponsive
2023-09-28T13:22:32.378Z DRIVER   Attempting to recover unresponsive controller...
**2023-09-28T13:22:32.390Z CNTRLR   Performing soft reset...**
2023-09-28T13:22:33.404Z CNTRLR   Failed to execute controller command after 1/3 attempts. Scheduling next try i
                                  n 100 ms.
2023-09-28T13:22:34.512Z CNTRLR   Failed to execute controller command after 2/3 attempts. Scheduling next try i
                                  n 1100 ms.
2023-09-28T13:22:36.626Z CNTRLR   Soft reset failed: Timeout while waiting for an ACK from the controller (ZW020
                                  0)
2023-09-28T13:22:36.628Z DRIVER   Recovering unresponsive controller failed. Restarting the driver...
Error in driver ZWaveError: Recovering unresponsive controller failed. Restarting the driver... (ZW0100)
    at Driver.destroyWithMessage (/usr/src/node_modules/zwave-js/src/lib/driver/Driver.ts:2769:17)
    at fail (/usr/src/node_modules/zwave-js/src/lib/driver/Driver.ts:3484:14)
    at /usr/src/node_modules/zwave-js/src/lib/driver/Driver.ts:3533:5 {
  code: 100,
  context: undefined,
  transactionSource: undefined
}
Shutting down
Closing server...
2023-09-28T13:22:36.653Z CNTRLR   [Node 018] ping failed: Timeout while waiting for a callback from the controll
                                  er (ZW0200)
2023-09-28T13:22:36.654Z CNTRLR » [Node 018] querying node info...
2023-09-28T13:22:36.659Z CNTRLR » [Node 018] Assigning SUC return route...
2023-09-28T13:22:36.660Z CNTRLR » [Node 018] Deleting SUC return route...
2023-09-28T13:22:36.662Z CNTRLR   [Node 018] Deleting SUC return route failed: The driver is not ready or has be
                                  en destroyed (ZW0103)
2023-09-28T13:22:36.664Z CNTRLR   [Node 018] Assigning SUC return route failed: The driver is not ready or has b
                                  een destroyed (ZW0103)
Client disconnected
Code 1000: 
Server closed
[13:22:36] WARNING: Halt add-on
s6-rc: info: service legacy-services: stopping
s6-rc: info: service legacy-services successfully stopped
s6-rc: info: service legacy-cont-init: stopping
s6-rc: info: service legacy-cont-init successfully stopped
s6-rc: info: service fix-attrs: stopping
s6-rc: info: service fix-attrs successfully stopped
s6-rc: info: service s6rc-oneshot-runner: stopping
s6-rc: info: service s6rc-oneshot-runner successfully stopped

@AlCalzone
Copy link
Contributor

Still seeing a soft reset in my logs.

I double-checked - that codepath only gets executed if soft-reset is not disabled (or if you are using a 700+ series controller)

@mattster98
Copy link

Was able to see earlier in the log where it talks about detecting VMs..

[09:59:35] INFO: Both 'network_key' and 's0_legacy_key' are set and match. All ok.
[09:59:38] INFO: Virtual Machine not detected, enabling soft-reset

I'm unable to find a place to disable soft-reset.. I'm not using Z-Wave JS UI, just the zwave_js integration along with the core_zwave_js add-on.

Any pointers? I'm coming up empty on my search. Is it possible because of the state I'm in (things won't start all the way), that UI isn't available?

@bgarderhagen
Copy link

Hi.

Same issue with dying Z-wave.

Home Assistant 2023.9.3
Supervisor 2023.09.2
Operating System 10.5
Interface utilisateur : 20230911.0 - latest
Z-Wave JS Current version: 0.1.93

UZB
by Z-Wave.Me
Firmware: 5.7

@mirkin-pixel
Copy link

mirkin-pixel commented Sep 28, 2023

I have the same issue..

s6-rc: info: service s6rc-oneshot-runner: starting
s6-rc: info: service s6rc-oneshot-runner successfully started
s6-rc: info: service base-addon-banner: starting
-----------------------------------------------------------
 Add-on: Z-Wave JS UI
 Fully configurable Z-Wave JS gateway and control panel
-----------------------------------------------------------
 Add-on version: 2.0.1
 You are running the latest version of this add-on.
 System: Home Assistant OS 10.5  (amd64 / qemux86-64)
 Home Assistant Core: 2023.9.3
 Home Assistant Supervisor: 2023.09.2
-----------------------------------------------------------
 Please, share the above information when looking for help
 or support in, e.g., GitHub, forums or the Discord chat.
-----------------------------------------------------------
s6-rc: info: service base-addon-banner successfully started
s6-rc: info: service fix-attrs: starting
s6-rc: info: service base-addon-log-level: starting
s6-rc: info: service fix-attrs successfully started
s6-rc: info: service base-addon-log-level successfully started
s6-rc: info: service legacy-cont-init: starting
s6-rc: info: service legacy-cont-init successfully started
s6-rc: info: service init-zwave-js-ui: starting
s6-rc: info: service init-nginx: starting
s6-rc: info: service init-zwave-js-ui successfully started
s6-rc: info: service zwave-js-ui: starting
s6-rc: info: service zwave-js-ui successfully started
s6-rc: info: service discovery: starting
[17:13:48] INFO: Starting the Z-Wave JS UI...
s6-rc: info: service init-nginx successfully started
s6-rc: info: service nginx: starting
s6-rc: info: service nginx successfully started
2023-09-28 17:13:49.292 INFO APP: Version: 9.0.1
2023-09-28 17:13:49.294 INFO APP: Application path:/opt
  ______  __          __                      _  _____     _    _ _____ 
 |___  /  \ \        / /                     | |/ ____|   | |  | |_   _|
    / /____\ \  /\  / /_ ___   _____         | | (___     | |  | | | |  
   / /______\ \/  \/ / _' \ \ / / _ \    _   | |\___ \    | |  | | | |  
  / /__      \  /\  / (_| |\ V /  __/   | |__| |____) |   | |__| |_| |_ 
 /_____|      \/  \/ \__,_| \_/ \___|    \____/|_____/     \____/|_____|
2023-09-28 17:13:49.302 WARN STORE: scenes.json not found
[17:13:49] INFO: Starting NGinx...
2023-09-28 17:13:51.524 INFO Z-WAVE-SERVER: ZwaveJS server listening on 0.0.0.0:3000
2023-09-28 17:13:52.446 INFO Z-WAVE-SERVER: DNS Service Discovery enabled
[17:14:02] INFO: Successfully send discovery information to Home Assistant.
s6-rc: info: service discovery successfully started
s6-rc: info: service legacy-services: starting
s6-rc: info: service legacy-services successfully started
2023-09-28T15:14:05.981Z CNTRLR   [Node 014] The node did not respond after 1 attempts, it is presumed dead
2023-09-28T15:14:09.119Z DRIVER     no handlers registered!
ValidationError: The 'X-Forwarded-For' header is set but the Express 'trust proxy' setting is false (default). This could indicate a misconfiguration which would prevent express-rate-limit from accurately identifying users. See https://express-rate-limit.github.io/ERR_ERL_UNEXPECTED_X_FORWARDED_FOR/ for more information.
    at _Validations.<anonymous> (/opt/node_modules/express-rate-limit/dist/index.cjs:180:15)
    at _Validations.wrap (/opt/node_modules/express-rate-limit/dist/index.cjs:313:18)
    at _Validations.xForwardedForHeader (/opt/node_modules/express-rate-limit/dist/index.cjs:178:10)
    at Object.keyGenerator (/opt/node_modules/express-rate-limit/dist/index.cjs:542:19)
    at /opt/node_modules/express-rate-limit/dist/index.cjs:595:32
    at /opt/node_modules/express-rate-limit/dist/index.cjs:576:5 {
  code: 'ERR_ERL_UNEXPECTED_X_FORWARDED_FOR',
  help: 'https://express-rate-limit.github.io/ERR_ERL_UNEXPECTED_X_FORWARDED_FOR/'
}
2023-09-28T15:15:14.117Z CNTRLR   The controller is unresponsive
2023-09-28T15:15:14.117Z DRIVER   Attempting to recover unresponsive controller...
2023-09-28T15:15:14.133Z CNTRLR   The controller does not support soft reset or the soft reset feature has been 
                                  disabled with a config option or the ZWAVEJS_DISABLE_SOFT_RESET environment va
                                  riable.
2023-09-28T15:15:14.134Z DRIVER   Recovering unresponsive controller failed. Restarting the driver...
2023-09-28T15:15:14.135Z CNTRLR   [Node 016] Assigning SUC return route failed: Timeout while waiting for a call
                                  back from the controller (ZW0200)
2023-09-28 17:15:15.138 INFO Z-WAVE-SERVER: Client disconnected
2023-09-28 17:15:15.142 INFO Z-WAVE-SERVER: Server closed

@mattster98
Copy link

Rolled back to 0.1.92 to see if that helped. It did not. Rolled back to 0.1.90 (the next backup I had) and it is working again.

Looks like a long list of changes in 0.1.91.. two sound like they could be the culprit here. I'm guessing these releases came in rapid succession which is why I didn't get 0.1.91 installed automatically.

@AlCalzone
Copy link
Contributor

AlCalzone commented Sep 28, 2023

UZB

by Z-Wave.Me

Firmware: 5.7

Do you have driver logs? That stick should be on the list of sticks that are never soft-reset.

@bgarderhagen

@jenscollin
Copy link

jenscollin commented Sep 28, 2023

Same issue here. RPI with Z-wave HAT.
Upgraded from Home Assistant 2023.6.3 and Z-Wave JS version: 0.1.84 at the same time to
Home Assistant 2023.9.3 and Z-Wave JS version: 0.1.93.
Z-wave started up but kept on restarting after a couple of "Failed to execute controller command after 1/3 attempts."

Reverted to HA 2023.6.3 + 0.1.93 still problem.
Revered to HA 2023.6.3 + 0.1.84 works again.

Sorry if the HA version is irrelevant here, noob here. Just thought I could chip in some info that the same happened with a HAT that isn't USB-connected.

@AlCalzone
Copy link
Contributor

AlCalzone commented Sep 28, 2023

Do you have more complete driver logs @jenscollin ?
And which HAT is that specifically?

@jenscollin
Copy link

jenscollin commented Sep 28, 2023

Just updated the HA Core again thinking that it had nothing to do with it. However the combo 2023.9.3 and 0.1.84 it still fails over and over again. I'm thinking that HA Core is more involved than I though.

A load of these... then suddenly, "New client" and all hell breaks loose.

2023-09-28T19:28:46.516Z CNTRLR « [Node 010] ping successful
2023-09-28T19:28:46.622Z CNTRLR   [Node 009] The node is alive.
2023-09-28T19:28:46.624Z CNTRLR   [Node 009] The node is ready to be used
2023-09-28T19:28:46.627Z CNTRLR « [Node 009] ping successful
2023-09-28T19:28:46.705Z CNTRLR   [Node 004] The node is alive.
2023-09-28T19:28:46.707Z CNTRLR   [Node 004] The node is ready to be used
2023-09-28T19:28:46.709Z CNTRLR « [Node 004] ping successful
New client
Z-Wave JS no longer supports enabling error reporting. If you are using an application that integrates with Z-Wave JS and you receive this error, you may need to update the application.

Then it starts over after a few minutes.
It was a long time since I bought it, but I'm pretty sure it's a RaZberry pi board. Using ttyAMA0.

How do I download the whole log, I just get partials that I understand are hard to make something by.

@AlCalzone
Copy link
Contributor

AlCalzone commented Sep 28, 2023

How do I download the whole log

https://www.home-assistant.io/integrations/zwave_js#how-to-access-the-z-wave-logs - keep the window open.
Or use Z-Wave JS UI and enable logging to file. https://zwave-js.github.io/zwave-js-ui/#/troubleshooting/generating-logs?id=driver-logs - That has the advantage that you can log across driver restarts.

RaZberry pi board

That should support soft-reset. At least my 2016 variant does.

@irgendwer112
Copy link

Issue is solved for me with Version 0.1.97 and Home Assistant 2023.10.3.

Z-Wave.Me USB Stick ZME_UZB1 on Proxmox VM.

@snicker
Copy link

snicker commented Oct 15, 2023

@snicker Please make a driver log of A startup that's failing, loglevel debug and attach it here as a file (drag & drop into the text field). Doing this is easiest with Z-Wave JS UI.

so I noticed that there is a trend where this is happening to users with dead nodes, so I thought to install PC Controller 5 and see if I could manually wipe some of these nodes out. I found something odd on my zwave stick in that two nodes (51 and 55) are neighbors of each other, but neither can be marked as failed, and if I attempt to poll them for information, either one will lock up the stick and make it unresponsive, even in PC Controller 5. I have no idea how to force these nodes to go away but I think that would clear up my issues. It's also strange to me that this only became a problem after upgrading from 0.1.87 to 0.1.97.

after deleting a few dead nodes, the behavior ends up the same though, Zwave JS just reboots repeatedly.

oops* uploaded wrong log. this is the correct one:
zwavejs_2023-10-15.log

@AlCalzone
Copy link
Contributor

It's also strange to me that this only became a problem after upgrading from 0.1.87 to 0.1.97.

Because your controller is becoming unresponsive and Z-Wave JS now tries to handle this by restarting it, instead of just continuing and risking a few more nodes to be incorrectly marked as "dead".
What I didn't consider is that there is almost no Z-Wave controller firmware that isn't broken in some way that triggers this feature unnecessarily.

The latest update increased the timeout for this from 10 to 30 seconds - seems this is still not enough.

@snicker
Copy link

snicker commented Oct 16, 2023

It's also strange to me that this only became a problem after upgrading from 0.1.87 to 0.1.97.

Because your controller is becoming unresponsive and Z-Wave JS now tries to handle this by restarting it, instead of just continuing and risking a few more nodes to be incorrectly marked as "dead". What I didn't consider is that there is almost no Z-Wave controller firmware that isn't broken in some way that triggers this feature unnecessarily.

The latest update increased the timeout for this from 10 to 30 seconds - seems this is still not enough.

i haven't tried to see how long it takes for the stick to recover, but can check.

is there a way to force the client to ignore nodes? eg a setting to "never poll nodes [51,55]

@di9ze
Copy link

di9ze commented Oct 16, 2023

I ran into a same issue, after upgrading firmware on USB controller & issue went away. Here is the Aeotec link
https://aeotec.freshdesk.com/support/solutions/articles/6000252294-z-stick-gen5-v1-02-firmware-update
I wish there was some kind of notification or heads up instead of breaking Z-Wave network

@snicker
Copy link

snicker commented Oct 16, 2023

I ran into a same issue, after upgrading firmware on USB controller & issue went away. Here is the Aeotec link https://aeotec.freshdesk.com/support/solutions/articles/6000252294-z-stick-gen5-v1-02-firmware-update I wish there was some kind of notification or heads up instead of breaking Z-Wave network

I'd love to try this but for some reason the instructions on this page do not work on my system. the firmware upgrade software cannot find the com port for the device (despite it working for backing up the stick in another application also from Aeotec), thus I cannot upgrade the firmware. I'm trying to get my hands on another windows PC to attempt but have not found one yet.

I also filed a support request with Aeotec for this but not sure that will be fruitful

@AlCalzone
Copy link
Contributor

I wish there was some kind of notification or heads up instead of breaking Z-Wave network

Well... let's just say this wasn't supposed to break anything, aside from users having to disable soft-reset. But I didn't anticipate just how broken almost all Z-Wave controller firmwares are.

@snicker
Copy link

snicker commented Oct 17, 2023

I ran into a same issue, after upgrading firmware on USB controller & issue went away. Here is the Aeotec link https://aeotec.freshdesk.com/support/solutions/articles/6000252294-z-stick-gen5-v1-02-firmware-update I wish there was some kind of notification or heads up instead of breaking Z-Wave network

so, great news, I borrowed a windows machine for 15 minutes today, updated the firmware on my stick, and then things are working swimmingly again. 1.02 on the Gen5 Aeotec stick seems to make this problem disappear

specifically on
image

@pachiclana
Copy link

Today I FINALLY managed top upgrade the firmware from my Gen5 Stick. With all the latest software / versions / etc, it seems to work!

Hurray... But Aeotec does an exeptional good job in hiding this tool (at least for me)|

@everybody that still has the problem: I used this tool @AlCalzone : Thanks for your work and effort @ChristopherGerdes : Thanks for the tip, although i'm stuck at the "Add virtual device", my Gen 5 panel doesn't show this button.

This worked for me as well. Thanks for the tip!

Environment:

  • Raspberry Pi 4 v.Raspbian 10
  • Aeotec Stick Gen 5 (with latest firmware, check the link on the quoted comment) => Connected to the Rpi4 via a hub
  • Home Assistant v.2023.10.3 (Supervised installation)
  • Home Assistant Supervisor v.2023.10.0
  • Home Assistant Frontend v.20231005.0
  • Z-Wave JS UI Add-on v.2.1.2

@AlCalzone
Copy link
Contributor

FYI, before everyone moves away from the Gen5 stick - I released another driver version yesterday which should help with the remaining issues: https://github.com/zwave-js/node-zwave-js/releases/tag/v12.2.0
Z-Wave JS UI (Standalone) has already picked it up, the HA addons should follow soon.

@pachiclana
Copy link

I have updated to latest version of Z-Wave JS UI and it stopped working now. The Aeotec Stick Gen 5 is not recognized nor the entities in it. As stated in my previous comment, I have the latest firmware installed following this tutorial

image

After the update of the add-on, are there any recommended steps for those who have updated the firmware in the Aeotec Stick Gen 5?

@sofa74surfer
Copy link

Here you find some logs of a Zwave 7gen Stick of aeotec with firmware 7.19.4. Accessing serial port by id doesn't work at all (Zwave JS and Zwave JS UI). Forwarding serial port with ser2net seams to work at the beginning, until it ends up in the same problem.

Testet this morning with all the latest versions available.

zwavejs_2023-10-19 - using ser2net.log
zwavejs_2023-10-19 - using usb by id.log
core_zwave_js_2023-10-19T07-40-38.322Z.log

@AlCalzone
Copy link
Contributor

@pachiclana unplug and replug the stick, disable soft-reset in the options, make sure you have the correct port selected.

@AlCalzone
Copy link
Contributor

@sofa74surfer Like the last time I looked at the logs, your stick suddenly stops communicating without any indication why. Here's where it happens in the ser2net logs:

# "normal" communication at first:
2023-10-19T07:47:03.629Z DRIVER « [Node 003] [REQ] [BridgeApplicationCommand]
                                  │ RSSI: -86 dBm
                                  └─[Security2CCMessageEncapsulation] [INVALID]
                                      error: No security class granted
2023-10-19T07:47:03.630Z SERIAL » [ACK]                                                                   (0x06)

# then random garbage is received 20 seconds later:
2023-10-19T07:47:22.564Z SERIAL « [DISCARDED] invalid data 0x8005c4800547ff800547ff80528780dc4a80984a (40 bytes)
                                  80984a80dc4a809cd6809cd08081d0809cec800a
2023-10-19T07:47:24.091Z SERIAL « [DISCARDED] invalid data 0x89800a                                    (3 bytes)

# then no response at all anymore
2023-10-19T07:47:30.617Z SERIAL » 0x0103003bc7                                                         (5 bytes)
2023-10-19T07:47:30.618Z DRIVER » [REQ] [GetBackgroundRSSI]
2023-10-19T07:47:31.624Z CNTRLR   Failed to execute controller command after 1/3 attempts. Scheduling next try i
                                  n 100 ms.
2023-10-19T07:47:31.726Z DRIVER » [REQ] [GetBackgroundRSSI]
2023-10-19T07:47:31.727Z SERIAL » 0x0103003bc7                                                         (5 bytes)
2023-10-19T07:47:32.731Z CNTRLR   Failed to execute controller command after 2/3 attempts. Scheduling next try i
                                  n 1100 ms.
2023-10-19T07:47:33.832Z DRIVER » [REQ] [GetBackgroundRSSI]
2023-10-19T07:47:33.833Z SERIAL » 0x0103003bc7                                                         (5 bytes)
2023-10-19T07:47:34.841Z CNTRLR   The controller is unresponsive
...

I suspect there's either

  • something wrong with the stick
  • or the stick's connection to the computer
  • or something is interfering with the communication, another process maybe

As far as I can see, this is not related to the Z-Wave JS updates, as the problem happens randomly without Z-Wave JS interfering. Or does it work if you roll back?

@pachiclana
Copy link

@AlCalzone, it works now. I just disabled the soft-reset option, restarted the add-on and it worked. Thanks for the advice!

@Preferred69
Copy link

Preferred69 commented Oct 20, 2023

Same here, Have HA on a VMWARE esxi 6.7 u3 with passthrough USB and with the soft reset on it did not connect to the bus, The stick i have is a Aeotec Zwave Gen5 ZW090 firmware v1.2 After disabling the soft reset function it started working again.
Updated from HA 9.3 to 10.3

@ablyes
Copy link
Author

ablyes commented Oct 20, 2023

I may have a stupid question :
What kind of changes were required to do all those changes ?
I thought z-wave was like a almost a dead protocol ?

@Preferred69
Copy link

Preferred69 commented Oct 20, 2023

I may have a stupid question : What kind of changes were required to do all those changes ? I thought z-wave was like a almost a dead protocol ?

Well only thing i did was update everything go into the zwave JS UI click the cogwheel (settings) open the Z-Wave options and disable Soft reset there and save, Restart Z-Wave JS and it should be fine.

@di9ze
Copy link

di9ze commented Oct 21, 2023

after upgrade to 2.2.3, ZWAVE stopped working, changed the ZWAVE integration to point from ws:https://core-zwave-js:3000 to ws:https://a0d7b954-zwavejs2mqtt:3000 and its working one. Before 10/14 ws:https://localhost:3000 was working fine

How can I know what is correct setting for ZWAVE integration?

@cadwizzard
Copy link

I may have a stupid question : What kind of changes were required to do all those changes ? I thought z-wave was like a almost a dead protocol ?

Z-Wave is hardly dead. Although it is true that some technology is being pushed noisily out to general less tech savvy consumers, like ZigBee, Wi-Fi and promises they will all work together because of things like Matter.

@ryanrdetzel
Copy link

Upgrading my controller (gen5) and then grabbed the latest of zwave-js-ui and hass and it's been fixed for me (so far).

I tried everything before upgrading the firmware and the system would eventually crash but after taking the plunge and upgrading it yesterday (took 10 minutes) everything has been smooth since then.

For more context, i did have four dead nodes which I've since removed, that will probably help the system run better too and prevent future problems.

Copy link

This issue has been automatically marked as stale because it has not had recent activity. It will be closed if no further activity occurs. Thank you for your contributions.

@github-actions github-actions bot added the stale label Dec 17, 2023
@github-actions github-actions bot closed this as not planned Won't fix, can't repro, duplicate, stale Dec 24, 2023
@sofa74surfer
Copy link

This Issue isn't resolved for my Aeotec Z-Stick 7. it's dead since over 3 month, i buyed a new one, but it also din't work. Tried id on a second machine and it doesn't work at all. Downgraded the Stick, but this also not works. Same Issue "Failed to execute controller command after 1/3 attempts." all the time. It stopped working somewhere in September 23 with a update of HA or Zwave.

@ScottJensen18
Copy link

Same here on my Aeotec Z-Stick 5. I haven’t been able to update HA or Zwave since September. None of the fixes listed have helped. Anytime a new update comes out, I update to see if it has been resolved, but end up having to revert to a backup.

what info can I provide to help with this?

@cadwizzard
Copy link

cadwizzard commented Dec 29, 2023

For completeness, i'm still seeing recovery fail occasionally (Aeotec Gen5+ on HA Yellow and latest versions of HA). I'm running Zwave JS UI now but the controller recovery is sounding similar.
I posted here, but no responses: hassio-addons/addon-zwave-js-ui#620

I last saw this on the 27th December in the middle of the night.
Worth noting its always a Eurotronic CometZ node (147 in this last case) that is involved before the crash for me.

But the controller tries to soft reset. The main problem being it then thinks its responsive again. It isnt. All zwave reporting and control just ceases yet appears fine (i.e not dead in the status etc. Its like everything is just frozen).

If i then change something like the inclusion timeout in JSUI and hit save, the controller immediately comes back to life and the trafffic goes crazy while all the nodes on the network update their parameters etc - like you would expect if soft restart was successful.

Latest snippet (sorry, debug wasnt on as i thought this was related to interview/cometz, but /i think its wider now)

2023-12-27T03:29:30.926Z CNTRLR   [Node 080] The node is now awake.
2023-12-27T03:29:30.933Z CNTRLR » [Node 080] Multilevel Sensor CC values may be stale, refreshing...
2023-12-27T03:29:30.934Z CNTRLR » [Node 080] querying Air temperature sensor reading...
2023-12-27T03:29:30.939Z CNTRLR   [Node 080] No scale preference for sensor type 1, using the last-used scale 0
2023-12-27T03:29:31.156Z CNTRLR « [Node 080] received current Air temperature sensor reading: 4 °C
2023-12-27T03:29:31.409Z CNTRLR » [Node 080] Sending node back to sleep...
2023-12-27T03:29:31.438Z CNTRLR   [Node 080] The node is now asleep.
2023-12-27T03:33:01.689Z CNTRLR » [Node 143] Meter CC values may be stale, refreshing...            [Endpoint 3]
2023-12-27T03:43:31.969Z CNTRLR « [Node 081] received wakeup notification
2023-12-27T03:43:31.977Z CNTRLR   [Node 081] The node is now awake.
2023-12-27T03:43:32.236Z CNTRLR » [Node 081] Sending node back to sleep...
2023-12-27T03:43:32.264Z CNTRLR   [Node 081] The node is now asleep.
2023-12-27T03:49:22.110Z CNTRLR « [Node 012] received wakeup notification
2023-12-27T04:00:45.777Z CNTRLR » [Node 147] Notification CC values may be stale, refreshing...
2023-12-27T04:00:45.781Z CNTRLR » [Node 147] querying notification status for Power Management...
2023-12-27T04:00:48.809Z DRIVER   Dropping message with invalid payload
2023-12-27T04:00:48.883Z DRIVER   Dropping message with invalid payload
2023-12-27T04:00:49.005Z DRIVER   Dropping message with invalid payload
2023-12-27T04:00:49.033Z DRIVER   Dropping message with invalid payload
2023-12-27T04:00:49.116Z DRIVER   Dropping message with invalid payload
2023-12-27T04:00:52.972Z DRIVER   Dropping message with invalid payload
2023-12-27T04:01:15.808Z CNTRLR   The controller is unresponsive
2023-12-27T04:01:15.813Z DRIVER   Controller missed Send Data callback. Attempting to recover...
2023-12-27T04:01:15.818Z CNTRLR   Performing soft reset...
2023-12-27T04:01:16.830Z CNTRLR   Failed to execute controller command after 1/3 attempts. Scheduling next try i
                                  n 100 ms.
2023-12-27T04:01:17.056Z CNTRLR   Failed to execute controller command after 2/3 attempts. Scheduling next try i
                                  n 1100 ms.
2023-12-27T04:01:19.163Z CNTRLR   Soft reset failed: Timeout while waiting for an ACK from the controller (ZW020
                                  0)
2023-12-27T04:01:19.164Z DRIVER   Automatic controller recovery failed. Returning to normal operation and hoping
                                   for the best.
2023-12-27T04:01:19.165Z CNTRLR   The controller is no longer unresponsive
2023-12-27T04:01:19.168Z CNTRLR   [Node 147] failed to refresh values for Notification CC: Timeout while waiting
                                   for a callback from the controller (ZW0200)
2023-12-27T04:01:54.189Z CNTRLR   Failed to execute controller command after 1/3 attempts. Scheduling next try i
                                  n 100 ms.
2023-12-27T04:01:54.293Z CNTRLR   Failed to execute controller command after 2/3 attempts. Scheduling next try i
                                  n 1100 ms.
2023-12-27T04:02:24.191Z CNTRLR   Failed to execute controller command after 1/3 attempts. Scheduling next try i
                                  n 100 ms.
2023-12-27T04:02:24.295Z CNTRLR   Failed to execute controller command after 2/3 attempts. Scheduling next try i
                                  n 1100 ms.

This will go on forever until I manually take action. The last time it happened above, it was 4AM - at least 5 hours later I noticed my 60 node network was not functioning. The nodes dont show as unavailable in timeline/logbook, their temp etc readings just stay the same and flatlined.

@AlCalzone
Copy link
Contributor

@cadwizzard AFAIK you need a newer version of node-zwave-js, but the latest addon version doesn't come with that yet.

@raman325
Copy link
Collaborator

Which addon are you referring to? Latest official addon is up to date: #3351

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Projects
None yet
Development

No branches or pull requests