core: Z-Wave network starts, but all entities are 'Unavailable'. No control over them. All nodes stay 'Undefined'

The problem

Today I updated HA from 0.104.3 to 0.107.1. This caused Z-Wave to stop working. In the Z-Wave panel I can see that the network is started, but all z-wave entities are shown as Unavailable.

Restarted multiple times - didn’t help.

Environment

Home Assistant release with the issue: 0.107.1
Last working Home Assistant release (if known): 0.104.3
Operating environment (Hass.io/Docker/Windows/etc.): Docker on a Synology NAS
Integration causing this issue: Z-Wave
Link to integration documentation on our website: https://www.home-assistant.io/integrations/zwave/

Problem-relevant `configuration.yaml`

No YAML. Z-Wave setup with a config entry in GUI

Traceback/Error logs

When I first started HA 0.107 I got error

Z-Wave not ready after 300 seconds, continuing anyway

This never happened so far and I run HA in Docker on Synology for over a year now. So a bit suspicious. After several restarts I’m getting different errors in the HA log screen in Dev Tools

Source: components/zwave/__init__.py:475
Z-Wave node 15 not ready after 30 seconds, continuing anyway
Z-Wave node 16 not ready after 30 seconds, continuing anyway
Z-Wave node 17 not ready after 30 seconds, continuing anyway
Z-Wave node 18 not ready after 30 seconds, continuing anyway
Z-Wave node 19 not ready after 30 seconds, continuing anyway

Z-Wave entity Unknown Node 4 Switch (node_id: 4) not ready after 30 seconds, continuing anyway

The OZW log shows 1 suspicious issue at the start ERROR: Cannot get exclusive lock for serial port /zwaveusbstick. Error code 11, but afterwards shows no major issues like it worked. But it doesn’t. I have no other software running on my NAS which utilizes Z-Wave. There should be no conflict. This must be either HA or OZW related issue.

2020-03-20 16:11:08.021 Always, OpenZwave Version 1.4.3467 Starting Up
2020-03-20 16:11:29.225 Info, Setting Up Provided Network Key for Secure Communications
2020-03-20 16:11:29.226 Info, mgr,     Added driver for controller /zwaveusbstick
2020-03-20 16:11:29.226 Info,   Opening controller /zwaveusbstick
2020-03-20 16:11:29.226 Info, Trying to open serial port /zwaveusbstick (attempt 1)
2020-03-20 16:11:29.226 Error, ERROR: Cannot get exclusive lock for serial port /zwaveusbstick. Error code 11
2020-03-20 16:11:29.227 Info, Serial port /zwaveusbstick opened (attempt 1)
2020-03-20 16:11:29.227 Detail, contrlr, Queuing (Command) FUNC_ID_ZW_GET_VERSION: 0x01, 0x03, 0x00, 0x15, 0xe9
2020-03-20 16:11:29.227 Detail, contrlr, Queuing (Command) FUNC_ID_ZW_MEMORY_GET_ID: 0x01, 0x03, 0x00, 0x20, 0xdc
2020-03-20 16:11:29.227 Detail, contrlr, Queuing (Command) FUNC_ID_ZW_GET_CONTROLLER_CAPABILITIES: 0x01, 0x03, 0x00, 0x05, 0xf9
2020-03-20 16:11:29.227 Detail, contrlr, Queuing (Command) FUNC_ID_SERIAL_API_GET_CAPABILITIES: 0x01, 0x03, 0x00, 0x07, 0xfb
2020-03-20 16:11:29.227 Detail, contrlr, Queuing (Command) FUNC_ID_ZW_GET_SUC_NODE_ID: 0x01, 0x03, 0x00, 0x56, 0xaa
2020-03-20 16:11:29.227 Detail, 
2020-03-20 16:11:29.227 Info, contrlr, Sending (Command) message (Callback ID=0x00, Expected Reply=0x15) - FUNC_ID_ZW_GET_VERSION: 0x01, 0x03, 0x00, 0x15, 0xe9
2020-03-20 16:11:29.234 Detail, contrlr,   Received: 0x01, 0x10, 0x01, 0x15, 0x5a, 0x2d, 0x57, 0x61, 0x76, 0x65, 0x20, 0x34, 0x2e, 0x35, 0x34, 0x00, 0x01, 0x93
2020-03-20 16:11:29.235 Detail, 
2020-03-20 16:11:29.235 Info, contrlr, Received reply to FUNC_ID_ZW_GET_VERSION:
2020-03-20 16:11:29.235 Info, contrlr,     Static Controller library, version Z-Wave 4.54
2020-03-20 16:11:29.235 Detail, Node045,   Expected reply was received
2020-03-20 16:11:29.235 Detail, Node045,   Message transaction complete
2020-03-20 16:11:29.235 Detail, 
2020-03-20 16:11:29.235 Detail, contrlr, Removing current message
2020-03-20 16:11:29.235 Detail, 
2020-03-20 16:11:29.235 Info, contrlr, Sending (Command) message (Callback ID=0x00, Expected Reply=0x20) - FUNC_ID_ZW_MEMORY_GET_ID: 0x01, 0x03, 0x00, 0x20, 0xdc
2020-03-20 16:11:30.235 Error, contrlr, ERROR: Dropping command, expected response not received after 1 attempt(s)
2020-03-20 16:11:30.236 Detail, contrlr, Removing current message
2020-03-20 16:11:30.236 Detail, contrlr, Notification: Notification - TimeOut
2020-03-20 16:11:30.241 Detail, 
2020-03-20 16:11:30.241 Info, contrlr, Sending (Command) message (Callback ID=0x00, Expected Reply=0x05) - FUNC_ID_ZW_GET_CONTROLLER_CAPABILITIES: 0x01, 0x03, 0x00, 0x05, 0xf9
2020-03-20 16:11:30.742 Warning, WARNING: 500ms passed without reading the rest of the frame...aborting frame read
2020-03-20 16:11:30.743 Detail, contrlr,   Received: 0x01, 0x01, 0x04
2020-03-20 16:11:30.743 Warning, contrlr, WARNING: Checksum incorrect - sending NAK
2020-03-20 16:11:30.745 Detail, contrlr,   Received: 0x01, 0x05, 0x08, 0xf7, 0x01, 0x04, 0x01
2020-03-20 16:11:30.745 Warning, contrlr, WARNING: Checksum incorrect - sending NAK
2020-03-20 16:11:30.808 Detail, contrlr,   Received: 0x01, 0x01, 0x07
2020-03-20 16:11:30.809 Warning, contrlr, WARNING: Checksum incorrect - sending NAK
2020-03-20 16:11:30.810 Detail, contrlr,   Received: 0x01, 0x03, 0x3e, 0xdc, 0x01
2020-03-20 16:11:30.811 Warning, contrlr, WARNING: Checksum incorrect - sending NAK
2020-03-20 16:11:31.311 Warning, WARNING: 500ms passed without reading the rest of the frame...aborting frame read
2020-03-20 16:11:31.312 Warning, WARNING: Out of frame flow! (0x3e).  Sending NAK.
2020-03-20 16:11:32.508 Detail, contrlr,   Received: 0x01, 0x09, 0x01, 0x41, 0x53, 0x9c, 0x01, 0x04, 0x07, 0x01, 0x7a
2020-03-20 16:11:32.508 Detail, 
2020-03-20 16:11:32.508 Info, contrlr, Received reply to FUNC_ID_ZW_GET_NODE_PROTOCOL_INFO
2020-03-20 16:11:34.143 Warning, WARNING: 500ms passed without reading the rest of the frame...aborting frame read
2020-03-20 16:11:34.644 Warning, WARNING: 500ms passed without reading the rest of the frame...aborting frame read
2020-03-20 16:11:40.242 Error, contrlr, ERROR: Dropping command, expected response not received after 1 attempt(s)
2020-03-20 16:11:40.242 Detail, contrlr, Removing current message
2020-03-20 16:11:40.242 Detail, contrlr, Notification: Notification - TimeOut
2020-03-20 16:11:40.246 Detail, 
2020-03-20 16:11:40.246 Info, contrlr, Sending (Command) message (Callback ID=0x00, Expected Reply=0x07) - FUNC_ID_SERIAL_API_GET_CAPABILITIES: 0x01, 0x03, 0x00, 0x07, 0xfb

Additional information

I noticed a different OZW version. 0.104.6 had 1.4.3452 and 0.107.1 has 1.4.3467. Perhaps that’s causing this. I think this should be treated as high prio as z-wave is very popular and it stopped working with this new HA release.

About this issue

Original URL
State: closed
Created 4 years ago
Comments: 25 (2 by maintainers)

Most upvoted comments

I have the exact same problem, Zwave is down, same messages. I also run Home Assistant in Docker on Synology.

RockMonkey on Mar 20, 2020

All - what @kpine wrote is the key thing here! If they changed the command how the container starts - it broke the existing startup procedure in Synology Docker. I used a customized version of Docker container configuration to avoid running it with high priviledges and have the USB stick visible under HA. However - when I now launched a new container without forwarding the USB port to HA under /zwaveusbstick and enabled high priviledges (which means one has to change the path to /dev/ttyACM0 in HA Z-Wave config) it worked!!! 😀 The entities are alive and the nodes came back to normal status. Everything’s working fine now!👍 Please try the same thing and it should solve your problem.

NOTE: I recommend to restore your last HA config backup prior doing this as the broken container resulting in 2 HA instances runniing in parallel messed up someones’ entity registry and states db. So it’s safer to start with a correct config to avoid further errors

Thanks all for your input! And good luck with getting this resolved!

dgtal1 on Mar 21, 2020