Gonioul
commented
1 year ago Seems ok now with 9.0.1
Closed ablyes closed 10 months ago
Gonioul
commented
1 year ago Seems ok now with 9.0.1
raman325
commented
1 year ago @ablyes can you set your addon logs to debug and then paste the results here?
CC @AlCalzone
tkdrob
commented
1 year ago 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
commented
1 year ago 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
commented
1 year ago 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
commented
1 year ago Which controller do you have? Which firmware version (if 700/800 series)? Which path are you accessing it through?
Turtle-code
commented
1 year ago 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
commented
1 year ago Which path are you accessing it through? /dev/...?
ablyes
commented
1 year ago I had the same issue with this version. Here is the path i'm using : /dev/serial/by-id/usb-0658_0200-if00
mattster98
commented
1 year ago 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 stoppedWhich 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
commented
1 year ago 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
commented
1 year ago 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
commented
1 year ago According to https://github.com/hassio-addons/addon-zwave-js-ui/issues/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
commented
1 year ago We disable soft-reset if we detect a VM in the add-on.
MartinHjelmare
commented
1 year ago What's the indication that the affected users in this issue are using VMs?
AlCalzone
commented
1 year ago 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
commented
1 year ago 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
commented
1 year ago 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 stoppedStill 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
commented
1 year ago 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
commented
1 year ago 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
commented
1 year ago 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 closedRolled 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
commented
1 year ago 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
commented
1 year ago 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
commented
1 year ago Do you have more complete driver logs @jenscollin ? And which HAT is that specifically?
jenscollin
commented
1 year ago 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
commented
1 year ago 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.
NoAIbrain
commented
1 year ago 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!
I had the same problem with my Z-Stick Gen5+. Used the update you recommended and it worked. Thank you!
irgendwer112
commented
1 year ago The same here. Rollback to 0.1.90 solved the issue.
Z-Wave.Me USB Stick ZME_UZB1 on Proxmox VM.
ScottJensen18
commented
1 year ago My Z-Stick Gen5+ has also stopped working since updating. Rolling back to 0.1.90 has not helped. I did try the firmware update listed above (even though the support article mentions it only being for non 5+ versions). Prior to applying the update, I couldn't even get the Z-Wave JS add-on to start. After the update, it does at least start, but the error logs are more or less the same. The add-on does eventually stop on its own.
2023-09-29T01:03:54.866Z CNTRLR querying version info...
2023-09-29T01:03:55.171Z CNTRLR received version info:
controller type: Static Controller
library version: Z-Wave 6.07
2023-09-29T01:03:55.172Z CNTRLR querying protocol version info...
2023-09-29T01:03:55.380Z CNTRLR received protocol version info:
protocol type: Z-Wave
protocol version: 6.7.0
appl. framework build no.: 97
2023-09-29T01:03:55.382Z CNTRLR querying serial API setup capabilities...
2023-09-29T01:03:55.590Z CNTRLR supported serial API setup commands:
· GetSupportedCommands
· SetTxStatusReport
· SetPowerlevel
· GetPowerlevel
· GetMaximumPayloadSize
2023-09-29T01:03:55.591Z CNTRLR querying controller IDs...
2023-09-29T01:03:55.795Z CNTRLR received controller IDs:
home ID: 0xdbbd15da
own node ID: 1
2023-09-29T01:03:55.825Z CNTRLR Performing soft reset...
2023-09-29T01:03:56.105Z CNTRLR Waiting for the controller to reconnect...
2023-09-29T01:03:57.607Z CNTRLR Waiting for the Serial API to start...
2023-09-29T01:04:02.608Z CNTRLR Did not receive notification that Serial API has started, checking if it respo
nds...
2023-09-29T01:04:02.616Z CNTRLR Failed to execute controller command after 1/3 attempts. Scheduling next try i
n 100 ms.
2023-09-29T01:04:02.720Z CNTRLR Failed to execute controller command after 2/3 attempts. Scheduling next try i
n 1100 ms.
2023-09-29T01:04:03.825Z CNTRLR Serial API did not respond, trying again in 2 seconds...
2023-09-29T01:04:05.831Z CNTRLR Failed to execute controller command after 1/3 attempts. Scheduling next try i
n 100 ms.
2023-09-29T01:04:05.934Z CNTRLR Failed to execute controller command after 2/3 attempts. Scheduling next try i
n 1100 ms.
2023-09-29T01:04:07.038Z CNTRLR Serial API did not respond, trying again in 5 seconds...
2023-09-29T01:04:12.045Z CNTRLR Failed to execute controller command after 1/3 attempts. Scheduling next try i
n 100 ms.
2023-09-29T01:04:12.147Z CNTRLR Failed to execute controller command after 2/3 attempts. Scheduling next try i
n 1100 ms.
2023-09-29T01:04:13.251Z CNTRLR Serial API did not respond, trying again in 10 seconds...
2023-09-29T01:04:23.256Z CNTRLR Failed to execute controller command after 1/3 attempts. Scheduling next try i
n 100 ms.
2023-09-29T01:04:23.358Z CNTRLR Failed to execute controller command after 2/3 attempts. Scheduling next try i
n 1100 ms.
2023-09-29T01:04:24.461Z CNTRLR Serial API did not respond, trying again in 15 seconds...
2023-09-29T01:04:39.474Z CNTRLR Failed to execute controller command after 1/3 attempts. Scheduling next try i
n 100 ms.
2023-09-29T01:04:39.577Z CNTRLR Failed to execute controller command after 2/3 attempts. Scheduling next try i
n 1100 ms.
2023-09-29T01:04:40.681Z CNTRLR Serial API did not respond, giving up
2023-09-29T01:04:40.682Z DRIVER Failed to initialize the driver: ZWaveError: The Serial API did not respond af
ter soft-reset (ZW0100)
at Driver.softResetInternal (/usr/src/node_modules/zwave-js/src/lib/driver
/Driver.ts:2524:11)
at Driver.initializeControllerAndNodes (/usr/src/node_modules/zwave-js/src
/lib/driver/Driver.ts:1384:5)
at Immediate.<anonymous> (/usr/src/node_modules/zwave-js/src/lib/driver/Dr
iver.ts:1165:5)
Error in driver ZWaveError: Failed to initialize the driver: ZWaveError: The Serial API did not respond after soft-reset (ZW0100)
at Driver.softResetInternal (/usr/src/node_modules/zwave-js/src/lib/driver/Driver.ts:2524:11)
at Driver.initializeControllerAndNodes (/usr/src/node_modules/zwave-js/src/lib/driver/Driver.ts:1384:5)
at Immediate.<anonymous> (/usr/src/node_modules/zwave-js/src/lib/driver/Driver.ts:1165:5) (ZW0100)
at Immediate.<anonymous> (/usr/src/node_modules/zwave-js/src/lib/driver/Driver.ts:1185:6) {
code: 100,
context: undefined,
transactionSource: undefined
}
Shutting down
[01:04:40] 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
bauerpowergit
commented
1 year ago EDIT: THE GEN 5 STICK IS WORKING. I left the info below for reference. I had to untoggle the "Soft Reset" setting under Z-Wave JS UI -> Settings -> Z-Wave as others mentioned. This, combined with updating to the Gen 5+ v1.02 Firmware did the trick. Thanks to everyone who provided the Scooby Doo clues needed to help solve this mystery!
(My original Post:) I just struggled with this issue for 2 days since Zwave JS UI 2.0 dropped. Switched to my old z-stick (Aeon Labs Z-Stick S2 Model: DSA02203-ZWUS) and boom, "DRIVER READY".
I am running home assistant on a Virtualbox VM and was using the Aeotec Z-stick Gen5 (model: ZW090-A). It was running perfectly up until the update.
I tried uninstalling the add on and reinstalling, swapping USB ports, updated the firmware to the Gen5+ firmware, tried installing it on a brand new VM image of Home assistant, factory reset my stick, and NOTHING worked. I even tested my network with the Aeon Labs IMA tool and saw the Gen 5 communicating with my zwave mesh just fine. This JS UI update broke compatibility with this specific stick, at least on a VM. Hopefully an update will fix it soon. In the meantime, I'll be rebuilding my Zwave network with this old stick.
I hope this information helps solve the issue. Good luck fellow tech geeks.
bgarderhagen
commented
1 year ago 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
Hi.
This log ?
s6-rc: info: service s6rc-oneshot-runner: starting
s6-rc: info: service s6rc-oneshot-runner successfully started
s6-rc: info: service fix-attrs: starting
s6-rc: info: service fix-attrs successfully started
s6-rc: info: service legacy-cont-init: starting
cont-init: info: running /etc/cont-init.d/config.sh
[08:58:18] INFO: Both 'network_key' and 's0_legacy_key' are set and match. All ok.
[08:58:19] INFO: Virtual Machine not detected, enabling soft-reset
cont-init: info: /etc/cont-init.d/config.sh exited 0
cont-init: info: running /etc/cont-init.d/structure.sh
cont-init: info: /etc/cont-init.d/structure.sh exited 0
s6-rc: info: service legacy-cont-init successfully started
s6-rc: info: service legacy-services: starting
services-up: info: copying legacy longrun zwave_js (no readiness notification)
s6-rc: info: service legacy-services successfully started
[08:58:19] INFO: Successfully send discovery information to Home Assistant.
2023-09-29T06:58:20.094Z DRIVER ███████╗ ██╗ ██╗ █████╗ ██╗ ██╗ ███████╗ ██╗ ███████╗
╚══███╔╝ ██║ ██║ ██╔══██╗ ██║ ██║ ██╔════╝ ██║ ██╔════╝
███╔╝ ██║ █╗ ██║ ███████║ ██║ ██║ █████╗ █████╗ ██║ ███████╗
███╔╝ ██║███╗██║ ██╔══██║ ╚██╗ ██╔╝ ██╔══╝ ╚════╝ ██ ██║ ╚════██║
███████╗ ╚███╔███╔╝ ██║ ██║ ╚████╔╝ ███████╗ ╚█████╔╝ ███████║
╚══════╝ ╚══╝╚══╝ ╚═╝ ╚═╝ ╚═══╝ ╚══════╝ ╚════╝ ╚══════╝
2023-09-29T06:58:20.096Z DRIVER version 12.0.0
2023-09-29T06:58:20.097Z DRIVER
2023-09-29T06:58:20.097Z DRIVER starting driver...
2023-09-29T06:58:20.097Z DRIVER opening serial port /dev/ttyACM1
2023-09-29T06:58:20.103Z DRIVER serial port opened
2023-09-29T06:58:20.104Z SERIAL » 0x15 (1 bytes)
2023-09-29T06:58:20.107Z SERIAL « 0x01180004000812600d0100320221240000128100000000000033 (26 bytes)
2023-09-29T06:58:20.110Z SERIAL « 0x01180004000812600d0100320221240000128100000000000033 (26 bytes)
2023-09-29T06:58:20.111Z DRIVER Dropping message because the driver is not ready to handle it yet.
2023-09-29T06:58:20.111Z SERIAL » [ACK] (0x06)
2023-09-29T06:58:20.111Z DRIVER Dropping message because the driver is not ready to handle it yet.
2023-09-29T06:58:20.112Z SERIAL » [ACK] (0x06)
2023-09-29T06:58:20.113Z SERIAL « 0x01180004000812600d010001180004000812600d010032022154 (26 bytes)
2023-09-29T06:58:20.113Z SERIAL « [DISCARDED] invalid data 0x00 (1 bytes)
2023-09-29T06:58:20.113Z DRIVER Dropping message because it contains invalid data
2023-09-29T06:58:20.113Z SERIAL » [NAK] (0x15)
2023-09-29T06:58:21.111Z DRIVER loading configuration...
2023-09-29T06:58:21.119Z CONFIG Using external configuration dir /data/db
2023-09-29T06:58:21.119Z CONFIG version 12.0.0
Oniric75
commented
1 year ago i had the same issue : i'm using a VM with a gen5 zwave key.
apparently the issue is dead simple for me. i didnt try any firmware update. i just disable "soft reset" and instantly it was working again ...
you can find the setting in zwave js ui
mirkin-pixel
commented
1 year ago i had the same issue : i'm using a VM with a gen5 zwave key.
apparently the issue is dead simple for me. i didnt try any firmware update. i just disable "soft reset" and instantly it was working again ...
you can find the setting in zwave js ui
I tried the same, but didn't work for me. Any other suggestions?
AlCalzone
commented
1 year ago @mirkin-pixel you may have to re-plug the stick after changing the option.
AlCalzone
commented
1 year ago @bgarderhagen That log, yes. But it isn't complete - there's nothing wrong yet.
AlCalzone
commented
1 year ago Documentation of the issue and a list of solutions can be found here: https://github.com/zwave-js/node-zwave-js/issues/6341
bgarderhagen
commented
1 year ago @bgarderhagen That log, yes. But it isn't complete - there's nothing wrong yet.
I am only able to see one page of logs in the browser, and there is so much details. Are there any files i can find the complete logs in, or make the browser show more data ?
bgarderhagen
commented
1 year ago I have this from a brief moment:
2023-09-29T08:44:14.413Z SERIAL « 0x0114000400080e600d01003202a122091f0000000020 (22 bytes)
2023-09-29T08:44:14.415Z SERIAL » [ACK] (0x06)
2023-09-29T08:44:14.417Z CNTRLR [Node 008] [Meter] value[66561]: metadata updated [Endpoint 1]
2023-09-29T08:44:14.418Z CNTRLR [Node 008] [~] [Meter] value[66561]: 233.5 => 233.5 [Endpoint 1]
2023-09-29T08:44:14.419Z DRIVER « [Node 008] [REQ] [ApplicationCommand]
└─[MultiChannelCCCommandEncapsulation]
│ source: 1
│ destination: 0
└─[MeterCCReport]
type: Electric
scale: V
rate type: Consumed
value: 233.5
time delta: 0 seconds
2023-09-29T08:44:23.178Z CNTRLR The controller is unresponsive
2023-09-29T08:44:23.179Z DRIVER Attempting to recover unresponsive controller...
2023-09-29T08:44:23.223Z 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-29T08:44:23.224Z 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-29T08:44:23.229Z DRIVER destroying driver instance...
2023-09-29T08:44:23.230Z CNTRLR [Node 006] Assigning SUC return route failed: Timeout while waiting for a call
back from the controller (ZW0200)
Server closed
2023-09-29T08:44:23.230Z DRIVER all queues idle
2023-09-29T08:44:23.326Z DRIVER driver instance destroyed
[08:44:23] 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@mirkin-pixel you may have to re-plug the stick after changing the option.
I tried, but the same problem.
AlCalzone
commented
1 year ago Then please make a driver log, loglevel debug and attach it here as a file (drag & drop into the text field).
raman325
commented
1 year ago I've pushed a PR with an updated Z-Wave JS that has a bug fix along with a new option to force disable soft-reset. If anyone in this thread has a 500 series controller and is willing to testing the PR for me, please reach out to me in Discord (same username). I can walk you through exactly what to do but the hope is that between the two things we should be able to resolve this issue for you, just needs some testing.
raman325
commented
1 year ago OK I wrote up the instructions on Discord for someone else so I will share them here:
mkdir tmp ; cd tmp ; git clone https://github.com/raman325/addons.git ; cd addons ; git checkout bumpimage (image: homeassistant/{arch}-addon-zwave_js)mv zwave_js /root/addonszwave_js folder from /root/addonsmirkin-pixel
commented
1 year ago Then please make a driver log, loglevel
debugand attach it here as a file (drag & drop into the text field).
Here is the log: zwave-js-ui-store.1.zip
mattster98
commented
1 year ago @raman325, thanks for the instructions. I gave it a try as well and very similar results. It did take a reboot to get the other add-on to release the serial port, but it came right up after reboot. The earlier log did confirm that soft reset was disabled (it was great to finally see that switch available!)
2023-09-29T17:23:41.979Z SERIAL » [ACK] (0x06) 2023-09-29T17:23:41.981Z DRIVER « [REQ] [SendData] callback id: 10 transmit status: OK 2023-09-29T17:23:41.987Z CNTRLR [Node 016] The node is alive. 2023-09-29T17:23:41.989Z CNTRLR « [Node 016] ping successful 2023-09-29T17:23:41.989Z CNTRLR » [Node 016] querying node info... 2023-09-29T17:23:41.996Z SERIAL » 0x01080013130100250bd8 (10 bytes) 2023-09-29T17:23:41.997Z DRIVER » [Node 019] [REQ] [SendData] │ transmit options: 0x25 │ callback id: 11 └─[NoOperationCC] 2023-09-29T17:23:42.001Z SERIAL « [ACK] (0x06) 2023-09-29T17:23:42.004Z SERIAL « 0x0104011301e8 (6 bytes) 2023-09-29T17:23:42.006Z SERIAL » [ACK] (0x06) 2023-09-29T17:23:42.007Z DRIVER « [RES] [SendData] was sent: true 2023-09-29T17:23:42.142Z SERIAL « 0x010500130b00e2 (7 bytes) 2023-09-29T17:23:42.144Z SERIAL » [ACK] (0x06) 2023-09-29T17:23:42.147Z DRIVER « [REQ] [SendData] callback id: 11 transmit status: OK 2023-09-29T17:23:42.154Z CNTRLR [Node 019] The node is alive. 2023-09-29T17:23:42.157Z CNTRLR « [Node 019] ping successful 2023-09-29T17:23:42.158Z CNTRLR » [Node 019] querying node info... 2023-09-29T17:23:42.163Z SERIAL » 0x01080013140100250cd8 (10 bytes) 2023-09-29T17:23:42.164Z DRIVER » [Node 020] [REQ] [SendData] │ transmit options: 0x25 │ callback id: 12 └─[NoOperationCC] 2023-09-29T17:23:42.167Z SERIAL « [ACK] (0x06) 2023-09-29T17:23:42.173Z SERIAL « 0x0104011301e8 (6 bytes) 2023-09-29T17:23:42.173Z SERIAL » [ACK] (0x06) 2023-09-29T17:23:42.175Z DRIVER « [RES] [SendData] was sent: true 2023-09-29T17:23:42.234Z SERIAL « 0x010500130c00e5 (7 bytes) 2023-09-29T17:23:42.235Z SERIAL » [ACK] (0x06) 2023-09-29T17:23:42.237Z DRIVER « [REQ] [SendData] callback id: 12 transmit status: OK 2023-09-29T17:23:42.242Z CNTRLR [Node 020] The node is alive. 2023-09-29T17:23:42.244Z CNTRLR « [Node 020] ping successful 2023-09-29T17:23:42.245Z CNTRLR » [Node 020] querying node info... 2023-09-29T17:23:42.250Z SERIAL » 0x01080013150100250dd8 (10 bytes) 2023-09-29T17:23:42.252Z DRIVER » [Node 021] [REQ] [SendData] │ transmit options: 0x25 │ callback id: 13 └─[NoOperationCC] 2023-09-29T17:23:42.255Z SERIAL « [ACK] (0x06) 2023-09-29T17:23:52.260Z CNTRLR No response from controller after 1/3 attempts. Scheduling next try in 100 ms. 2023-09-29T17:23:52.363Z DRIVER » [Node 021] [REQ] [SendData] │ transmit options: 0x25 │ callback id: 13 └─[NoOperationCC] 2023-09-29T17:23:52.365Z SERIAL » 0x01080013150100250dd8 (10 bytes) 2023-09-29T17:23:53.370Z CNTRLR Failed to execute controller command after 2/3 attempts. Scheduling next try i n 1100 ms. 2023-09-29T17:23:54.473Z DRIVER » [Node 021] [REQ] [SendData] │ transmit options: 0x25 │ callback id: 13 └─[NoOperationCC] 2023-09-29T17:23:54.475Z SERIAL » 0x01080013150100250dd8 (10 bytes) 2023-09-29T17:23:55.486Z CNTRLR The controller is unresponsive 2023-09-29T17:23:55.488Z DRIVER Attempting to recover unresponsive controller... 2023-09-29T17:23:55.497Z 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-29T17:23:55.500Z 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-29T17:23:55.515Z DRIVER destroying driver instance... 2023-09-29T17:23:55.519Z CNTRLR [Node 021] ping failed: Timeout while waiting for an ACK from the controller ( ZW0200) 2023-09-29T17:23:55.519Z CNTRLR » [Node 021] querying node info... 2023-09-29T17:23:55.521Z CNTRLR » [Node 021] Assigning SUC return route... 2023-09-29T17:23:55.522Z CNTRLR » [Node 021] Deleting SUC return route... 2023-09-29T17:23:55.524Z CNTRLR [Node 021] Deleting SUC return route failed: The driver is not ready or has be en destroyed (ZW0103) 2023-09-29T17:23:55.526Z CNTRLR [Node 021] Assigning SUC return route failed: The driver is not ready or has b een destroyed (ZW0103) Server closed 2023-09-29T17:23:55.530Z DRIVER all queues idle 2023-09-29T17:23:55.675Z DRIVER driver instance destroyed [17:23:55] 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
raman325
commented
1 year ago so even when you disabled soft reset, there was still a crash?
mattster98
commented
1 year ago Yes, and just to be clear, this is on a Homeseer smartstick+ circa 2016.. not sure which gen/version that makes it, but it's old.
AlCalzone
commented
1 year ago In that log, Z-Wave JS pings Node 20, the controller confirms execution of that command within 10ms, and another 60ms later it tells us that the node acknowledged the ping:
2023-09-29T17:23:42.164Z DRIVER » [Node 020] [REQ] [SendData]
│ transmit options: 0x25
│ callback id: 12
└─[NoOperationCC]
2023-09-29T17:23:42.167Z SERIAL « [ACK] (0x06)
2023-09-29T17:23:42.173Z SERIAL « 0x0104011301e8 (6 bytes)
2023-09-29T17:23:42.173Z SERIAL » [ACK] (0x06)
2023-09-29T17:23:42.175Z DRIVER « [RES] [SendData]
was sent: true
2023-09-29T17:23:42.234Z SERIAL « 0x010500130c00e5 (7 bytes)
2023-09-29T17:23:42.235Z SERIAL » [ACK] (0x06)
2023-09-29T17:23:42.237Z DRIVER « [REQ] [SendData]
callback id: 12
transmit status: OKWhen pinging the next node (21), the controller does not confirm execution even after 10 seconds:
2023-09-29T17:23:42.252Z DRIVER » [Node 021] [REQ] [SendData]
│ transmit options: 0x25
│ callback id: 13
└─[NoOperationCC]
2023-09-29T17:23:42.255Z SERIAL « [ACK] (0x06)
2023-09-29T17:23:52.260Z CNTRLR No response from controller after 1/3 attempts. Scheduling next try in 100 ms.and further attempts aren't even acknowledged
2023-09-29T17:23:52.363Z DRIVER » [Node 021] [REQ] [SendData]
│ transmit options: 0x25
│ callback id: 13
└─[NoOperationCC]
2023-09-29T17:23:52.365Z SERIAL » 0x01080013150100250dd8 (10 bytes)
2023-09-29T17:23:53.370Z CNTRLR Failed to execute controller command after 2/3 attempts. Scheduling next try i
n 1100 ms.so Z-Wave JS is unable to communicate with the controller.
Previously, Z-Wave JS would just continue marking nodes as dead until the controller finally responds again, which may be never or minutes later. Now it knows that the controller is the problem and tries to restart that. Which doesn't work when soft-reset is disabled. So it raises an error with code Driver_Failed to get restarted by the application, hoping that re-opening the serial port helps.
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:
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
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