Recently, my z-wave network stopped working correctly.
Hardware: Home Assistant Blue (ODROID-N2+)
Z-Wave: Zooz 800 Series Z-Wave Long Range S2 USB Stick ZST39 LR, plugged in directly into USB slot.
Core: 2024.6.1, Supervisor: 2024.06.0, Operating System 12.3
Z-Wave JS UI: 3.7.2
Zooz Firmware: SDK 7.21.3
After a full reboot Z-Wave works for about an hour, but after that it becomes unresponsive. The logs show the following messages:
2024-06-11 00:09:09.654 DEBUG SOCKET: User disconnected from 5VV1R7w-um66RCSTAAGX: ping timeout
2024-06-11 00:09:09.655 INFO Z-WAVE: Removing user callbacks
2024-06-11T04:09:10.032Z CNTRLR The controller is unresponsive
2024-06-11 00:09:10.033 INFO Z-WAVE: Controller status: Controller is unresponsive
2024-06-11T04:09:10.034Z DRIVER Attempting to recover unresponsive controller by restarting it...
2024-06-11T04:09:10.034Z CNTRLR Performing soft reset...
2024-06-11T04:09:11.038Z CNTRLR Failed to execute controller command after 1/3 attempts. Scheduling next try i
n 100 ms.
2024-06-11T04:09:12.140Z CNTRLR Failed to execute controller command after 2/3 attempts. Scheduling next try i
n 1100 ms.
2024-06-11T04:09:14.243Z CNTRLR Soft reset failed: Timeout while waiting for an ACK from the controller (ZW020
0)
2024-06-11T04:09:14.244Z DRIVER Attempting to recover unresponsive controller by reopening the serial port...
2024-06-11T04:09:15.248Z DRIVER Serial port reopened. Returning to normal operation and hoping for the best...
2024-06-11T04:09:15.248Z CNTRLR The controller is no longer unresponsive
2024-06-11 00:09:15.248 INFO Z-WAVE: Controller status: Controller is Ready
2024-06-11 00:09:33.494 INFO APP: GET /health/zwave 301 0.817 ms - 191
2024-06-11T04:09:36.828Z CNTRLR Failed to execute controller command after 1/3 attempts. Scheduling next try i
n 100 ms.
2024-06-11T04:09:37.931Z CNTRLR Failed to execute controller command after 2/3 attempts. Scheduling next try i
n 1100 ms.
2024-06-11T04:09:40.033Z CNTRLR The controller is unresponsive
2024-06-11 00:09:40.034 INFO Z-WAVE: Controller status: Controller is unresponsive
2024-06-11T04:09:40.035Z DRIVER Attempting to recover unresponsive controller by restarting it...
2024-06-11T04:09:40.035Z CNTRLR Performing soft reset...
2024-06-11T04:09:41.040Z CNTRLR Failed to execute controller command after 1/3 attempts. Scheduling next try i
n 100 ms.
2024-06-11T04:09:42.142Z CNTRLR Failed to execute controller command after 2/3 attempts. Scheduling next try i
n 1100 ms.
2024-06-11T04:09:44.246Z CNTRLR Soft reset failed: Timeout while waiting for an ACK from the controller (ZW020
0)
2024-06-11T04:09:44.246Z DRIVER Attempting to recover unresponsive controller by reopening the serial port...
2024-06-11T04:09:45.250Z DRIVER Serial port reopened. Returning to normal operation and hoping for the best...
2024-06-11T04:09:45.250Z CNTRLR The controller is no longer unresponsive
2024-06-11 00:09:45.251 INFO Z-WAVE: Controller status: Controller is Ready
2024-06-11 00:10:03.571 INFO APP: GET /health/zwave 301 0.839 ms - 191
2024-06-11T04:10:06.827Z CNTRLR Failed to execute controller command after 1/3 attempts. Scheduling next try i
n 100 ms.
2024-06-11T04:10:07.930Z CNTRLR Failed to execute controller command after 2/3 attempts. Scheduling next try i
n 1100 ms.
2024-06-11T04:10:10.032Z CNTRLR The controller is unresponsive
2024-06-11 00:10:10.033 INFO Z-WAVE: Controller status: Controller is unresponsive
2024-06-11T04:10:10.034Z DRIVER Attempting to recover unresponsive controller by restarting it...
2024-06-11T04:10:10.034Z CNTRLR Performing soft reset...
2024-06-11T04:10:11.041Z CNTRLR Failed to execute controller command after 1/3 attempts. Scheduling next try i
n 100 ms.
2024-06-11T04:10:12.144Z CNTRLR Failed to execute controller command after 2/3 attempts. Scheduling next try i
n 1100 ms.
The logs in store: z-ui_2024-06-10.log.gz, contain the following data at the end right before the first error:
2024-06-10 23:24:24.061 INFO Z-WAVE: [Node 060] Value updated: 50-0-value-65537 426.482 => 426.488
2024-06-10 23:25:53.713 INFO Z-WAVE: [Node 060] Metadata updated: 50-0-value-66049
2024-06-10 23:25:53.716 INFO Z-WAVE: [Node 060] Value updated: 50-0-value-66049 81.6 => 80.5
2024-06-10 23:25:56.806 INFO Z-WAVE: [Node 060] Metadata updated: 50-0-value-66817
2024-06-10 23:25:56.808 INFO Z-WAVE: [Node 060] Value updated: 50-0-value-66817 0.89 => 0.87
2024-06-10 23:26:41.900 INFO Z-WAVE: [Node 060] Metadata updated: 50-0-value-66049
2024-06-10 23:26:41.902 INFO Z-WAVE: [Node 060] Value updated: 50-0-value-66049 80.5 => 105.1
2024-06-10 23:26:42.397 INFO Z-WAVE: [Node 060] Metadata updated: 50-0-value-66049
2024-06-10 23:26:42.400 INFO Z-WAVE: [Node 060] Value updated: 50-0-value-66049 105.1 => 80.2
2024-06-10 23:28:08.721 INFO Z-WAVE: [Node 020] Metadata updated: 50-0-value-65537
2024-06-10 23:28:08.723 INFO Z-WAVE: [Node 020] Value updated: 50-0-value-65537 2.739 => 2.739
2024-06-10 23:28:08.817 INFO Z-WAVE: [Node 020] Metadata updated: 50-0-value-66049
2024-06-10 23:28:08.821 INFO Z-WAVE: [Node 020] Value updated: 50-0-value-66049 0 => 0
2024-06-10 23:28:36.690 INFO Z-WAVE: [Node 059] Metadata updated: 50-0-value-66561
2024-06-10 23:28:36.692 INFO Z-WAVE: [Node 059] Value updated: 50-0-value-66561 120.35 => 120.24
2024-06-10 23:28:46.445 INFO Z-WAVE: [Node 019] Metadata updated: 50-0-value-65537
2024-06-10 23:28:46.447 INFO Z-WAVE: [Node 019] Value updated: 50-0-value-65537 1.772 => 1.772
2024-06-10 23:28:46.544 INFO Z-WAVE: [Node 019] Metadata updated: 50-0-value-66049
2024-06-10 23:28:46.548 INFO Z-WAVE: [Node 019] Value updated: 50-0-value-66049 0 => 0
2024-06-10 23:28:46.975 INFO Z-WAVE: [Node 059] Metadata updated: 50-0-value-66817
2024-06-10 23:28:46.979 INFO Z-WAVE: [Node 059] Value updated: 50-0-value-66817 0 => 0
2024-06-10 23:28:57.258 INFO Z-WAVE: [Node 059] Metadata updated: 50-0-value-66049
2024-06-10 23:28:57.262 INFO Z-WAVE: [Node 059] Value updated: 50-0-value-66049 0 => 0
2024-06-10 23:29:07.447 INFO Z-WAVE: [Node 060] Metadata updated: 50-0-value-66561
2024-06-10 23:29:07.449 INFO Z-WAVE: [Node 060] Value updated: 50-0-value-66561 120.43 => 120.68
2024-06-10 23:29:07.538 INFO Z-WAVE: [Node 059] Metadata updated: 50-0-value-65537
2024-06-10 23:29:07.540 INFO Z-WAVE: [Node 059] Value updated: 50-0-value-65537 0.021 => 0.021
2024-06-10 23:29:33.221 INFO Z-WAVE: [Node 060] Metadata updated: 50-0-value-65537
2024-06-10 23:29:33.225 INFO Z-WAVE: [Node 060] Value updated: 50-0-value-65537 426.488 => 426.496
2024-06-10 23:30:00.375 INFO Z-WAVE: [Node 019] Value updated: 37-0-targetValue false => false
2024-06-10 23:30:00.378 INFO Z-WAVE: [Node 019] Value updated: 37-0-currentValue false => false
2024-06-10 23:30:00.547 INFO Z-WAVE: [Node 019] Value updated: 37-0-currentValue false => false
2024-06-10 23:30:00.633 INFO Z-WAVE: [Node 019] Value updated: 37-0-currentValue false => false
2024-06-10 23:30:00.680 INFO Z-WAVE: [Node 019] Value updated: 37-0-currentValue false => false
2024-06-10 23:30:00.731 INFO Z-WAVE: [Node 019] Value updated: 37-0-currentValue false => false
2024-06-10 23:30:00.739 INFO Z-WAVE: [Node 019] Value updated: 37-0-currentValue false => false
2024-06-10 23:30:00.772 INFO Z-WAVE: [Node 020] Value updated: 37-0-targetValue false => false
2024-06-10 23:30:00.774 INFO Z-WAVE: [Node 020] Value updated: 37-0-currentValue false => false
2024-06-10 23:30:00.809 INFO Z-WAVE: [Node 019] Value updated: 37-0-currentValue false => false
2024-06-10 23:30:00.927 INFO Z-WAVE: [Node 019] Value updated: 37-0-currentValue false => false
2024-06-10 23:30:09.992 INFO Z-WAVE: Controller status: Controller is unresponsive
2024-06-10 23:30:15.216 INFO Z-WAVE: Controller status: Controller is Ready
2024-06-10 23:30:39.990 INFO Z-WAVE: Controller status: Controller is unresponsive
2024-06-10 23:30:45.208 INFO Z-WAVE: Controller status: Controller is Ready
2024-06-10 23:31:09.990 INFO Z-WAVE: Controller status: Controller is unresponsive
2024-06-10 23:31:14.222 INFO Z-WAVE: Setting user callbacks
2024-06-10 23:31:14.533 INFO Z-WAVE: Removing user callbacks
2024-06-10 23:31:15.241 INFO Z-WAVE: Controller status: Controller is Ready
2024-06-10 23:31:15.733 INFO Z-WAVE: Setting user callbacks
2024-06-10 23:31:39.995 INFO Z-WAVE: Controller status: Controller is unresponsive
2024-06-10 23:31:45.219 INFO Z-WAVE: Controller status: Controller is Ready