Sometimes when homeassistant restart zwave fails and I have to do one more reboot: I see this in the log: Z-Wave Notification DriverFailed :
what can be wrong?
You’re not providing a lot of details. So you’re likely to get a lot of guesses. Here’s something that can be checked quickly: verify that the device in /dev that was assigned to your ZWave stick has not changed.
I’ve been running HA in Docker for over a year without any problem. I’d reboot the machine, I’d restart the Docker container. No problem. Then, a few weeks ago, when I restarted HA, I found that ZWave would not start again. Upon investigation I found that the device name had changed! I must have upgraded something (Raspbian?? Docker??) that decided to behave differently than it used to. Anyway, I modified the udev configuration to give a stable name to the ZWave stick and the problem was gone. There are many many guides online explaining how to do it.
In the log, likely in the few lines before that, is information that helps answer that question 
Hi here is more info:
2019-12-26 14:44:21 WARNING (Dummy-2) [openzwave] Z-Wave Notification DriverFailed : {‘notificationType’: ‘DriverFailed’, ‘homeId’: 0, ‘nodeId’: 0}
2019-12-26 14:49:17 WARNING (MainThread) [homeassistant.components.zwave] Z-Wave not ready after 300 seconds, continuing anyway
2019-12-26 14:49:17 ERROR (MainThread) [homeassistant.core] Error doing job: Future exception was never retrieved
Traceback (most recent call last):
File “/usr/local/lib/python3.7/concurrent/futures/thread.py”, line 57, in run
result = self.fn(*self.args, **self.kwargs)
File “/usr/src/homeassistant/homeassistant/components/zwave/init.py”, line 894, in _finalize_start
poll_interval = network.get_poll_interval()
File “/usr/local/lib/python3.7/site-packages/openzwave/network.py”, line 873, in get_poll_interval
return self.manager.getPollInterval()
File “/usr/local/lib/python3.7/site-packages/openzwave/network.py”, line 564, in manager
raise ZWaveException(u"Manager not initialised")
openzwave.object.ZWaveException: ‘Zwave Generic Exception : Manager not initialised’
2019-12-26 14:44:16.579 Info, Serial port /dev/serial/by-id/usb-0658_0200-if00 opened (attempt 1)
2019-12-26 14:44:16.580 Detail, contrlr, Queuing (Command) FUNC_ID_ZW_GET_VERSION: 0x01, 0x03, 0x00, 0x15, 0xe9
2019-12-26 14:44:16.580 Detail, contrlr, Queuing (Command) FUNC_ID_ZW_MEMORY_GET_ID: 0x01, 0x03, 0x00, 0x20, 0xdc
2019-12-26 14:44:16.580 Detail, contrlr, Queuing (Command) FUNC_ID_ZW_GET_CONTROLLER_CAPABILITIES: 0x01, 0x03, 0x00, 0x05, 0xf9
2019-12-26 14:44:16.580 Detail, contrlr, Queuing (Command) FUNC_ID_SERIAL_API_GET_CAPABILITIES: 0x01, 0x03, 0x00, 0x07, 0xfb
2019-12-26 14:44:16.580 Detail, contrlr, Queuing (Command) FUNC_ID_ZW_GET_SUC_NODE_ID: 0x01, 0x03, 0x00, 0x56, 0xaa
2019-12-26 14:44:16.580 Detail,
2019-12-26 14:44:16.580 Info, contrlr, Sending (Command) message (Callback ID=0x00, Expected Reply=0x15) - FUNC_ID_ZW_GET_VERSION: 0x01, 0x03, 0x00, 0x15, 0xe9
2019-12-26 14:44:16.581 Detail, contrlr, Received: 0x01, 0x01, 0x15
2019-12-26 14:44:16.581 Warning, contrlr, WARNING: Checksum incorrect - sending NAK
2019-12-26 14:44:16.581 Warning, WARNING: Out of frame flow! (0x2e). Sending NAK.
2019-12-26 14:44:16.581 Warning, WARNING: Out of frame flow! (0x35). Sending NAK.
2019-12-26 14:44:16.581 Warning, WARNING: Out of frame flow! (0x34). Sending NAK.
2019-12-26 14:44:17.082 Warning, WARNING: 500ms passed without reading the rest of the frame…aborting frame read
2019-12-26 14:44:17.082 Detail, contrlr, Received: 0x01, 0x10, 0x01, 0x15, 0x5a, 0x2d, 0x57, 0x61, 0x76, 0x65, 0x20, 0x34, 0x2e, 0x35, 0x34, 0x00, 0x01, 0x93
2019-12-26 14:44:17.082 Detail,
2019-12-26 14:44:17.082 Info, contrlr, Received reply to FUNC_ID_ZW_GET_VERSION:
2019-12-26 14:44:17.082 Info, contrlr, Static Controller library, version Z-Wave 4.54
2019-12-26 14:44:17.082 Detail, Node045, Expected reply was received
2019-12-26 14:44:17.082 Detail, Node045, Message transaction complete
2019-12-26 14:44:17.082 Detail,
2019-12-26 14:44:17.082 Detail, contrlr, Removing current message
2019-12-26 14:44:17.082 Detail, Received: 0x01, 0x10, 0x01, 0x15, 0x5a, 0x2d, 0x57, 0x61, 0x76, 0x65, 0x20, 0x34, 0x2e, 0x35, 0x34, 0x00, 0x01, 0x93
2019-12-26 14:44:17.082 Detail,
2019-12-26 14:44:17.082 Info, Received reply to FUNC_ID_ZW_GET_VERSION:
2019-12-26 14:44:17.082 Info, Static Controller library, version Z-Wave 4.54
2019-12-26 14:44:17.582 Warning, WARNING: 500ms passed without reading the rest of the frame…aborting frame read
2019-12-26 14:44:18.083 Warning, WARNING: 500ms passed without reading the rest of the frame…aborting frame read
2019-12-26 14:44:18.083 Warning, WARNING: Out of frame flow! (0x5a). Sending NAK.
2019-12-26 14:44:18.083 Detail,
2019-12-26 14:44:18.083 Info, contrlr, Sending (Command) message (Callback ID=0x00, Expected Reply=0x20) - FUNC_ID_ZW_MEMORY_GET_ID: 0x01, 0x03, 0x00, 0x20, 0xdc
2019-12-26 14:44:18.085 Detail, Unsolicited message received while waiting for ACK.
2019-12-26 14:44:18.585 Warning, WARNING: 500ms passed without reading the rest of the frame…aborting frame read
2019-12-26 14:44:18.585 Warning, WARNING: Out of frame flow! (0x50). Sending NAK.
2019-12-26 14:44:18.585 Detail, Unsolicited message received while waiting for ACK.
2019-12-26 14:44:19.086 Warning, WARNING: 500ms passed without reading the rest of the frame…aborting frame read
2019-12-26 14:44:19.086 Detail, Unsolicited message received while waiting for ACK.
2019-12-26 14:44:19.586 Warning, WARNING: 500ms passed without reading the rest of the frame…aborting frame read
2019-12-26 14:44:19.586 Warning, WARNING: Out of frame flow! (0x50). Sending NAK.
2019-12-26 14:44:19.587 Detail, Unsolicited message received while waiting for ACK.
2019-12-26 14:44:20.087 Warning, WARNING: 500ms passed without reading the rest of the frame…aborting frame read
2019-12-26 14:44:20.087 Detail, Unsolicited message received while waiting for ACK.
2019-12-26 14:44:20.587 Warning, WARNING: 500ms passed without reading the rest of the frame…aborting frame read
2019-12-26 14:44:20.587 Warning, WARNING: Out of frame flow! (0x46). Sending NAK.
2019-12-26 14:44:21.588 Error, contrlr, ERROR: Dropping command, expected response not received after 1 attempt(s)
2019-12-26 14:44:21.588 Detail, contrlr, Removing current message
2019-12-26 14:44:21.588 Detail, contrlr, Notification: Notification - TimeOut
2019-12-26 14:44:21.589 Detail,
2019-12-26 14:44:21.589 Info, contrlr, Sending (Command) message (Callback ID=0x00, Expected Reply=0x05) - FUNC_ID_ZW_GET_CONTROLLER_CAPABILITIES: 0x01, 0x03, 0x00, 0x05, 0xf9
2019-12-26 14:44:21.590 Detail, contrlr, Received: 0x01, 0x04, 0x01, 0x05, 0x08, 0xf7
2019-12-26 14:44:21.590 Detail,
2019-12-26 14:44:21.590 Info, contrlr, Received reply to FUNC_ID_ZW_GET_CONTROLLER_CAPABILITIES:
2019-12-26 14:44:21.590 Info, contrlr, There is no SUC ID Server (SIS) in this network.
2019-12-26 14:44:21.590 Info, contrlr, The PC controller is a primary controller.
2019-12-26 14:44:21.590 Detail, Node247, Expected reply was received
2019-12-26 14:44:21.590 Detail, Node247, Message transaction complete
2019-12-26 14:44:21.590 Detail,
2019-12-26 14:44:21.590 Detail, contrlr, Removing current message
2019-12-26 14:44:21.590 Detail,
2019-12-26 14:44:21.590 Info, contrlr, Sending (Command) message (Callback ID=0x00, Expected Reply=0x07) - FUNC_ID_SERIAL_API_GET_CAPABILITIES: 0x01, 0x03, 0x00, 0x07, 0xfb
2019-12-26 14:44:21.594 Detail, contrlr, Received: 0x01, 0x2b, 0x01, 0x07, 0x01, 0x01, 0x00, 0x86, 0x00, 0x01, 0x00, 0x5a, 0xfe, 0x81, 0xff, 0x88, 0x4f, 0x1f, 0x00, 0x00, 0xfb, 0x9f, 0x7d, 0xa0, 0x67, 0x00, 0x00, 0x80, 0x00, 0x80, 0x86, 0x00, 0x00, 0x00, 0xe8, 0x73, 0x00, 0x00, 0x0e, 0x00, 0x00, 0x60, 0x00, 0x00, 0xfa
2019-12-26 14:44:21.594 Detail,
2019-12-26 14:44:21.594 Info, contrlr, Received reply to FUNC_ID_SERIAL_API_GET_CAPABILITIES
2019-12-26 14:44:21.594 Info, contrlr, Serial API Version: 1.1
2019-12-26 14:44:21.594 Info, contrlr, Manufacturer ID: 0x0086
2019-12-26 14:44:21.594 Info, contrlr, Product Type: 0x0001
2019-12-26 14:44:21.594 Info, contrlr, Product ID: 0x005a
2019-12-26 14:44:21.594 Detail, contrlr, Queuing (Command) FUNC_ID_ZW_GET_RANDOM: 0x01, 0x04, 0x00, 0x1c, 0x20, 0xc7
2019-12-26 14:44:21.594 Detail, contrlr, Queuing (Command) FUNC_ID_SERIAL_API_GET_INIT_DATA: 0x01, 0x03, 0x00, 0x02, 0xfe
2019-12-26 14:44:21.594 Detail, contrlr, Queuing (Command) FUNC_ID_SERIAL_API_SET_TIMEOUTS: 0x01, 0x05, 0x00, 0x06, 0x64, 0x0f, 0x97
2019-12-26 14:44:21.594 Detail, contrlr, Queuing (Command) FUNC_ID_SERIAL_API_APPL_NODE_INFORMATION: 0x01, 0x07, 0x00, 0x03, 0x01, 0x02, 0x01, 0x00, 0xf9
2019-12-26 14:44:21.594 Detail, Node001, Expected reply was received
2019-12-26 14:44:21.594 Detail, Node001, Message transaction complete
2019-12-26 14:44:21.594 Detail,
2019-12-26 14:44:21.594 Detail, contrlr, Removing current message
2019-12-26 14:44:21.594 Detail,
2019-12-26 14:44:21.594 Info, contrlr, Sending (Command) message (Callback ID=0x00, Expected Reply=0x56) - FUNC_ID_ZW_GET_SUC_NODE_ID: 0x01, 0x03, 0x00, 0x56, 0xaa
2019-12-26 14:44:21.595 Detail, contrlr, Received: 0x01, 0x04, 0x01, 0x56, 0x00, 0xac
2019-12-26 14:44:21.595 Detail,
2019-12-26 14:44:21.595 Info, contrlr, Received reply to GET_SUC_NODE_ID. Node ID = 0
2019-12-26 14:44:21.595 Info, Controller Does not Support SUC - Cannot Setup Controller as SUC Node
2019-12-26 14:44:21.595 Detail, Node172, Expected reply was received
2019-12-26 14:44:21.595 Detail, Node172, Message transaction complete
2019-12-26 14:44:21.595 Detail,
2019-12-26 14:44:21.595 Detail, contrlr, Removing current message
2019-12-26 14:44:21.595 Detail,
2019-12-26 14:44:21.595 Info, contrlr, Sending (Command) message (Callback ID=0x00, Expected Reply=0x1c) - FUNC_ID_ZW_GET_RANDOM: 0x01, 0x04, 0x00, 0x1c, 0x20, 0xc7
2019-12-26 14:44:21.651 Detail, contrlr, Received: 0x01, 0x25, 0x01, 0x1c, 0x01, 0x20, 0x9a, 0xe7, 0xb7, 0x67, 0xf0, 0x9f, 0x5b, 0xa6, 0xca, 0x80, 0x19, 0xc9, 0x24, 0x9e, 0x45, 0x18, 0xf3, 0xb2, 0x2e, 0xda, 0xbb, 0x3d, 0x5c, 0x0e, 0x6c, 0x6e, 0x18, 0x36, 0x8e, 0x9d, 0x8c, 0x83, 0xf5
2019-12-26 14:44:21.651 Detail,
2019-12-26 14:44:21.651 Info, contrlr, Received reply to FUNC_ID_ZW_GET_RANDOM: true
2019-12-26 14:44:21.651 Detail, Node032, Expected reply was received
2019-12-26 14:44:21.651 Detail, Node032, Message transaction complete
2019-12-26 14:44:21.651 Detail,
2019-12-26 14:44:21.651 Detail, contrlr, Removing current message
2019-12-26 14:44:21.651 Detail,
2019-12-26 14:44:21.651 Info, contrlr, Sending (Command) message (Callback ID=0x00, Expected Reply=0x02) - FUNC_ID_SERIAL_API_GET_INIT_DATA: 0x01, 0x03, 0x00, 0x02, 0xfe
2019-12-26 14:44:21.756 Detail, contrlr, Received: 0x01, 0x25, 0x01, 0x02, 0x05, 0x00, 0x1d, 0xbb, 0x1f, 0x00, 0x00, 0x00, 0x00, 0x00, 0x00, 0x00, 0x00, 0x00, 0x00, 0x00, 0x00, 0x00, 0x00, 0x00, 0x00, 0x00, 0x00, 0x00, 0x00, 0x00, 0x00, 0x00, 0x00, 0x00, 0x00, 0x00, 0x05, 0x00, 0x60
2019-12-26 14:44:21.756 Detail,
2019-12-26 14:44:21.756 Fatal, Failed to get HomeID or Controller Node ID during Init Sequence, m_homeId = 0x00000000, m_Controller_nodeId = 255
2019-12-26 14:44:21.756 Detail, Notification: DriverFailed
And environment? Hardware? which home-assistant installation?
As the docs say:
“If you see any of these messages repeated in the log then probably you’ve got something else running that’s also using the Z-Wave controller. That might mean you’ve also got the OpenZ-Wave control panel (ozwcp) running, a second instance of Home Assistant or something else. You need to stop that other process to resolve this.”
Source:
New setup on Linux Debian.
Nothing else than ha is running on the machine, so it only HA that access the stick.
Modem Manager is access it
Okey, what should I do then?
Read the troubleshooting guide that was already linked to in this thread
1 Like
That guide only tells me that something else is accessing it. Well it must be something built in to linux OS. Would be great for suggestions, where I cant start to look and solve it.
Uninstall Modem Manager
1 Like
Look here:
1 Like
Thanks guys, I think this fixed it 