Zwave aeotec doesnt start and add node

Configuration
1

Hi,
I am trying to create new HA instance on rpi 3b+ after a long time, I ve didnt use it.
Last time i have used Rpi3b+ with zwave aeotec evyrything worked fine.

I ma on clean instance HassOS 4.16.
Aeotec gen 5.

Problem
Now I have problem to start the network. After I enter the screen with addon configuration I see state “network stopped”.
When I try to launch the network - nothing happendy. Log below is after the action.

My configuration.yaml part of zwave:

# ZWAVE configuration
zwave:
  usb_path: /dev/serial/by-id/usb-0658_0200-if00
  #device_config: !include zwave_device_config.yaml
  debug: true
  network_key: "0x95, 0xe1 <removed rest>"

addon configuration here:

device: /dev/serial/by-id/usb-0658_0200-if00
network_key: >-
  0x95,0xe1 <removed rest>

log file from intergration tab:

2020-11-15 22:37:39.652 Always, OpenZwave Version 1.4.3469 Starting Up
2020-11-15 22:37:48.015 Info, Setting Up Provided Network Key for Secure Communications
2020-11-15 22:37:48.016 Info, mgr,     Added driver for controller /dev/serial/by-id/usb-0658_0200-if00
2020-11-15 22:37:48.016 Info,   Opening controller /dev/serial/by-id/usb-0658_0200-if00
2020-11-15 22:37:48.017 Info, Trying to open serial port /dev/serial/by-id/usb-0658_0200-if00 (attempt 1)
2020-11-15 22:37:48.021 Info, Serial port /dev/serial/by-id/usb-0658_0200-if00 opened (attempt 1)
2020-11-15 22:37:48.022 Detail, contrlr, Queuing (Command) FUNC_ID_ZW_GET_VERSION: 0x01, 0x03, 0x00, 0x15, 0xe9
2020-11-15 22:37:48.023 Detail, contrlr, Queuing (Command) FUNC_ID_ZW_MEMORY_GET_ID: 0x01, 0x03, 0x00, 0x20, 0xdc
2020-11-15 22:37:48.023 Detail, contrlr, Queuing (Command) FUNC_ID_ZW_GET_CONTROLLER_CAPABILITIES: 0x01, 0x03, 0x00, 0x05, 0xf9
2020-11-15 22:37:48.023 Detail, contrlr, Queuing (Command) FUNC_ID_SERIAL_API_GET_CAPABILITIES: 0x01, 0x03, 0x00, 0x07, 0xfb
2020-11-15 22:37:48.023 Detail, contrlr, Queuing (Command) FUNC_ID_ZW_GET_SUC_NODE_ID: 0x01, 0x03, 0x00, 0x56, 0xaa
2020-11-15 22:37:48.023 Detail,
2020-11-15 22:37:48.023 Info, contrlr, Sending (Command) message (Callback ID=0x00, Expected Reply=0x15) - FUNC_ID_ZW_GET_VERSION: 0x01, 0x03, 0x00, 0x15, 0xe9
2020-11-15 22:37:48.029 Detail, contrlr,   Received: 0x01, 0x10, 0x01, 0x15, 0x5a, 0x2d, 0x57, 0x61, 0x76, 0x65, 0x20, 0x34, 0x2e, 0x35, 0x34, 0x93, 0x01, 0x10
2020-11-15 22:37:48.029 Warning, contrlr, WARNING: Checksum incorrect - sending NAK
2020-11-15 22:37:48.032 Detail, contrlr,   Received: 0x01, 0x10, 0x01, 0x15, 0x5a, 0x2d, 0x57, 0x61, 0x76, 0x00, 0x01, 0x93, 0x01, 0x10, 0x01, 0x15, 0x5a, 0x2d
2020-11-15 22:37:48.032 Warning, contrlr, WARNING: Checksum incorrect - sending NAK
2020-11-15 22:37:58.025 Error, contrlr, ERROR: Dropping command, expected response not received after 1 attempt(s)
2020-11-15 22:37:58.025 Detail, contrlr, Removing current message
2020-11-15 22:37:58.025 Detail, contrlr, Notification: Notification - TimeOut
2020-11-15 22:37:58.027 Detail,
2020-11-15 22:37:58.027 Info, contrlr, Sending (Command) message (Callback ID=0x00, Expected Reply=0x20) - FUNC_ID_ZW_MEMORY_GET_ID: 0x01, 0x03, 0x00, 0x20, 0xdc
2020-11-15 22:37:58.036 Detail, contrlr,   Received: 0x01, 0x04, 0x01, 0x05, 0x28, 0xd7
2020-11-15 22:37:58.036 Detail,
2020-11-15 22:37:58.036 Info, contrlr, Received reply to FUNC_ID_ZW_GET_CONTROLLER_CAPABILITIES:
2020-11-15 22:37:58.036 Info, contrlr,     There is no SUC ID Server (SIS) in this network.
2020-11-15 22:37:58.036 Info, contrlr,     The PC controller is a primary controller.
2020-11-15 22:38:08.028 Error, contrlr, ERROR: Dropping command, expected response not received after 1 attempt(s)
2020-11-15 22:38:08.029 Detail, contrlr, Removing current message
2020-11-15 22:38:08.029 Detail, contrlr, Notification: Notification - TimeOut
2020-11-15 22:38:08.030 Detail,
2020-11-15 22:38:08.031 Info, contrlr, Sending (Command) message (Callback ID=0x00, Expected Reply=0x05) - FUNC_ID_ZW_GET_CONTROLLER_CAPABILITIES: 0x01, 0x03, 0x00, 0x05, 0xf9
2020-11-15 22:38:08.042 Detail, contrlr,   Received: 0x01, 0x04, 0x01, 0x56, 0x00, 0xac
2020-11-15 22:38:08.042 Detail,
2020-11-15 22:38:08.043 Info, contrlr, Received reply to GET_SUC_NODE_ID.  Node ID = 0
2020-11-15 22:38:08.043 Info, Controller Does not Support SUC - Cannot Setup Controller as SUC Node
2020-11-15 22:38:18.032 Error, contrlr, ERROR: Dropping command, expected response not received after 1 attempt(s)
2020-11-15 22:38:18.032 Detail, contrlr, Removing current message
2020-11-15 22:38:18.033 Detail, contrlr, Notification: Notification - TimeOut
2020-11-15 22:38:18.034 Detail,
2020-11-15 22:38:18.034 Info, contrlr, Sending (Command) message (Callback ID=0x00, Expected Reply=0x07) - FUNC_ID_SERIAL_API_GET_CAPABILITIES: 0x01, 0x03, 0x00, 0x07, 0xfb
2020-11-15 22:38:18.044 Detail, contrlr,   Received: 0x01, 0x2b, 0x01, 0x01, 0x00, 0x86, 0x00, 0xfa, 0x9f, 0x7d, 0x00, 0x00, 0x80, 0x86, 0x00, 0xe8, 0x73, 0x0e, 0x00, 0x00, 0x00, 0x01, 0x2b, 0x01, 0x07, 0x01, 0x01, 0x00, 0x86, 0x00, 0x01, 0x00, 0x5a, 0xfe, 0x81, 0xff, 0x88, 0x4f, 0x00, 0xfb, 0xa0, 0x67, 0x80, 0x00, 0x00
2020-11-15 22:38:18.045 Warning, contrlr, WARNING: Checksum incorrect - sending NAK
2020-11-15 22:38:18.546 Warning, WARNING: 500ms passed without reading the rest of the frame...aborting frame read
2020-11-15 22:38:18.547 Detail, contrlr,   Received: 0x01, 0x07, 0x01, 0x01, 0x00, 0x86, 0x00, 0x01, 0x00
2020-11-15 22:38:18.547 Warning, contrlr, WARNING: Checksum incorrect - sending NAK
2020-11-15 22:38:28.035 Error, contrlr, ERROR: Dropping command, expected response not received after 1 attempt(s)
2020-11-15 22:38:28.035 Detail, contrlr, Removing current message
2020-11-15 22:38:28.036 Detail, contrlr, Notification: Notification - TimeOut
2020-11-15 22:38:28.040 Detail,
2020-11-15 22:38:28.040 Info, contrlr, Sending (Command) message (Callback ID=0x00, Expected Reply=0x56) - FUNC_ID_ZW_GET_SUC_NODE_ID: 0x01, 0x03, 0x00, 0x56, 0xaa
2020-11-15 22:38:28.043 Detail, contrlr,   Received: 0x01, 0x04, 0x01, 0x56, 0x00, 0xac
2020-11-15 22:38:28.044 Detail,
2020-11-15 22:38:28.044 Info, contrlr, Received reply to GET_SUC_NODE_ID.  Node ID = 0
2020-11-15 22:38:28.045 Info, Controller Does not Support SUC - Cannot Setup Controller as SUC Node
2020-11-15 22:38:28.045 Detail, Node172,   Expected reply was received
2020-11-15 22:38:28.046 Detail, Node172,   Message transaction complete
2020-11-15 22:38:28.046 Detail,
2020-11-15 22:38:28.047 Detail, contrlr, Removing current message

Can someone please help to troubleshoot?

2

I’d start by removing the everything from your z-wave config except for zwave:

This is now configured via the Integrations GUI

3

do you mean from configuration.yaml or addon configuration?

4

if a leace only zwave: in configuration i get errors:

Logger: homeassistant.config_entries
Source: components/zwave/__init__.py:368
First occurred: 23:40:16 (1 occurrences)
Last logged: 23:40:16

Error setting up entry Z-Wave (import from configuration.yaml) for zwave
Traceback (most recent call last):
  File "/usr/local/lib/python3.8/site-packages/openzwave/option.py", line 78, in __init__
    raise ZWaveException(u"Can't find device %s : %s" % (device, traceback.format_exception(*sys.exc_info())))
openzwave.object.ZWaveException: "Zwave Generic Exception : Can't find device /dev/ttyACM0 : ['NoneType: None\\n']"

During handling of the above exception, another exception occurred:

Traceback (most recent call last):
  File "/usr/src/homeassistant/homeassistant/config_entries.py", line 234, in async_setup
    result = await component.async_setup_entry(hass, self)  # type: ignore
  File "/usr/src/homeassistant/homeassistant/components/zwave/__init__.py", line 368, in async_setup_entry
    options = ZWaveOption(
  File "/usr/local/lib/python3.8/site-packages/openzwave/option.py", line 81, in __init__
    raise ZWaveException(u"Error when retrieving device %s : %s" % (device, traceback.format_exception(*sys.exc_info())))
openzwave.object.ZWaveException: 'Zwave Generic Exception : Error when retrieving device /dev/ttyACM0 : [\'Traceback (most recent call last):\\n\', \'  File "/usr/local/lib/python3.8/site-packages/openzwave/option.py", line 78, in __init__\\n    raise ZWaveException(u"Can\\\'t find device %s : %s" % (device, traceback.format_exception(*sys.exc_info())))\\n\', \'openzwave.object.ZWaveException: "Zwave Generic Exception : Can\\\'t find device /dev/ttyACM0 : [\\\'NoneType: None\\\\\\\\n\\\']"\\n\']'

edit:
if I leave in configuration.yaml only: ¨

# ZWAVE configuration
zwave:
  usb_path: /dev/serial/by-id/usb-0658_0200-if00

The network still not start, but log is clear of all connected inputs.
Then in OpenZwave log I get:

[20201115 23:46:00.472 CET] [default] [debug]: QVariant(int, 0) 
[20201115 23:46:00.473 CET] [default] [debug]: QVariant(QString, "Generic 0x00") 
[20201115 23:46:00.473 CET] [default] [debug]: QVariant(int, 0) 
[20201115 23:46:00.473 CET] [default] [debug]: QVariant(QString, "Specific 0x00") 
[20201115 23:46:00.473 CET] [default] [debug]: QVariant(int, 0) 
[20201115 23:46:00.473 CET] [default] [debug]: QVariant(Invalid) 
[20201115 23:46:00.473 CET] [default] [debug]: QVariant(Invalid) 
[20201115 23:46:00.473 CET] [default] [debug]: QVariant(Invalid) 
[20201115 23:46:00.473 CET] [default] [debug]: QVariant(Invalid) 
[20201115 23:46:00.473 CET] [default] [debug]: QVariant(Invalid) 
[20201115 23:46:00.473 CET] [default] [debug]: QVariant(Invalid) 
[20201115 23:46:00.474 CET] [default] [debug]: QVariant(QString, "Neighbors") 
[20201115 23:46:00.474 CET] [default] [debug]: QVariant(QString, "0x0000") 
[20201115 23:46:00.474 CET] [default] [debug]: QVariant(QString, "0x0000") 
[20201115 23:46:00.474 CET] [default] [debug]: QVariant(QString, "0x0000") 
[20201115 23:46:00.474 CET] [default] [debug]: QVariant(uint, 0) 
[20201115 23:46:00.474 CET] [default] [debug]: QVariant(int, 0) 
[20201115 23:46:00.474 CET] [default] [debug]: QVariant(int, 0) 
[20201115 23:46:00.474 CET] [default] [debug]: QVariant(QBitArray, QBitArray(1000 0001 0)) 
[20201115 23:46:00.475 CET] [ozw.mqtt.publisher] [debug]: Publishing Event nodeEssentialNodeQueriesComplete: 1 
[20201115 23:46:00.475 CET] [ozw.notifications] [debug]: Notification pvt_valueAdded: 31227923 Thread:  0x76f0c558 
[20201115 23:46:00.476 CET] [ozw.mqtt.publisher] [debug]: Publishing Event valueAdded: 31227923 
[20201115 23:46:00.476 CET] [ozw.notifications] [debug]: Notification pvt_valueAdded: 281475007938579 Thread:  0x76f0c558 
[20201115 23:46:00.477 CET] [ozw.mqtt.publisher] [debug]: Publishing Event valueAdded: 281475007938579 
[20201115 23:46:00.477 CET] [ozw.notifications] [debug]: Notification pvt_valueAdded: 562949984649235 Thread:  0x76f0c558 
[20201115 23:46:00.478 CET] [ozw.mqtt.publisher] [debug]: Publishing Event valueAdded: 562949984649235 
[20201115 23:46:10.449 CET] [ozw.library] [critical]: Error - Node: 1 ERROR: Dropping command, expected response not received after 1 attempt(s). Command: "Get Routing Info (Node=1): 0x01, 0x07, 0x00, 0x80, 0x01, 0x00, 0x00, 0x03, 0x7a" 
[20201115 23:46:10.449 CET] [ozw.library] [debug]: Detail - Node: 1 Removing current message 
[20201115 23:46:10.450 CET] [ozw.library] [debug]: Detail - Node: 1 Notification: Notification - TimeOut 
[20201115 23:46:10.450 CET] [ozw.library] [debug]: Detail - Node: 1 Query Stage Complete (Neighbors) 
[20201115 23:46:10.450 CET] [ozw.notifications] [debug]: Notification pvt_ozwNotification NotificationTypes::Notification_Code_MsgTimeout Thread:  0x76f0c558 
[20201115 23:46:10.450 CET] [ozw.library] [debug]: Detail - Node: 1 AdvanceQueries queryPending=0 queryRetries=0 queryStage=Session live=1 
[20201115 23:46:10.450 CET] [ozw.library] [debug]: Detail - Node: 1 QueryStage_Session 
[20201115 23:46:10.451 CET] [ozw.mqtt.publisher] [debug]: Publishing Event ozwNotification 
[20201115 23:46:10.451 CET] [ozw.library] [debug]: Detail - Node: 1 QueryStage_Dynamic 
[20201115 23:46:10.451 CET] [ozw.library] [debug]: Detail - Node: 1 QueryStage_Configuration 
[20201115 23:46:10.451 CET] [ozw.library] [debug]: Detail - Node: 1 QueryStage_Complete 
[20201115 23:46:10.452 CET] [ozw.library] [warning]: Warning - Node: 0 CheckCompletedNodeQueries m_allNodesQueried=0 m_awakeNodesQueried=0 
[20201115 23:46:10.452 CET] [ozw.library] [warning]: Warning - Node: 0 CheckCompletedNodeQueries all=1, deadFound=0 sleepingOnly=1 
[20201115 23:46:10.452 CET] [ozw.library] [info]: Info - Node: 0          Node query processing complete. 
[20201115 23:46:10.452 CET] [ozw.library] [info]: Info - Node: 0 Saving Cache 
[20201115 23:46:10.453 CET] [ozw.library] [info]: Info - Node: 1 Cache Save for Node 1 as its QueryStage_CacheLoad 
[20201115 23:46:10.456 CET] [ozw.library] [debug]: Detail - Node: 1 Notification: NodeQueriesComplete 
[20201115 23:46:10.456 CET] [ozw.library] [debug]: Detail - Node: 255 Notification: AllNodesQueried 
[20201115 23:46:10.456 CET] [ozw.notifications] [debug]: Notification pvt_nodeQueriesComplete  1 Thread:  0x76f0c558 
[20201115 23:46:10.456 CET] [ozw.nodes] [debug]: setNodeData  1 :  QTOZW_Nodes::NodeDeviceType : QVariant(int, 0)  Transaction: true 
[20201115 23:46:10.457 CET] [ozw.nodes] [debug]: setNodeData  1 :  QTOZW_Nodes::NodeDeviceTypeString : QVariant(QString, "Unknown Type (0x0000)")  Transaction: true 
[20201115 23:46:10.457 CET] [ozw.nodes] [debug]: setNodeData  1 :  QTOZW_Nodes::NodeRole : QVariant(int, 0)  Transaction: true 
[20201115 23:46:10.457 CET] [ozw.nodes] [debug]: setNodeData  1 :  QTOZW_Nodes::NodeRoleString : QVariant(QString, "Central Controller")  Transaction: true 
[20201115 23:46:10.457 CET] [ozw.nodes] [debug]: setNodeData  1 :  QTOZW_Nodes::NodePlusType : QVariant(int, 0)  Transaction: true 
[20201115 23:46:10.458 CET] [ozw.nodes] [debug]: setNodeData  1 :  QTOZW_Nodes::NodePlusTypeString : QVariant(QString, "Z-Wave+ node")  Transaction: true 
[20201115 23:46:10.458 CET] [ozw.nodes] [debug]: setNodeData  1 :  QTOZW_Nodes::NodeQueryStage : QVariant(QString, "Complete")  Transaction: true 
[20201115 23:46:10.459 CET] [default] [debug]: QVariant(int, 1) 
[20201115 23:46:10.459 CET] [default] [debug]: QVariant(Invalid) 
[20201115 23:46:10.459 CET] [default] [debug]: QVariant(Invalid) 
[20201115 23:46:10.459 CET] [default] [debug]: QVariant(QString, "Unknown: id=0000") 
[20201115 23:46:10.460 CET] [default] [debug]: QVariant(QString, "Unknown: type=0000, id=0000") 
[20201115 23:46:10.460 CET] [default] [debug]: QVariant(QString, "Unknown") 
[20201115 23:46:10.460 CET] [default] [debug]: QVariant(int, 0) 
[20201115 23:46:10.460 CET] [default] [debug]: QVariant(QString, "Generic 0x00") 
[20201115 23:46:10.461 CET] [default] [debug]: QVariant(int, 0) 
[20201115 23:46:10.461 CET] [default] [debug]: QVariant(QString, "Specific 0x00") 
[20201115 23:46:10.461 CET] [default] [debug]: QVariant(int, 0) 
[20201115 23:46:10.462 CET] [default] [debug]: QVariant(QString, "Unknown Type (0x0000)") 
[20201115 23:46:10.462 CET] [default] [debug]: QVariant(int, 0) 
[20201115 23:46:10.462 CET] [default] [debug]: QVariant(int, 0) 
[20201115 23:46:10.462 CET] [default] [debug]: QVariant(QString, "Central Controller") 
[20201115 23:46:10.463 CET] [default] [debug]: QVariant(int, 0) 
[20201115 23:46:10.463 CET] [default] [debug]: QVariant(QString, "Z-Wave+ node") 
[20201115 23:46:10.463 CET] [default] [debug]: QVariant(QString, "Complete") 
[20201115 23:46:10.463 CET] [default] [debug]: QVariant(QString, "0x0000") 
[20201115 23:46:10.464 CET] [default] [debug]: QVariant(QString, "0x0000") 
[20201115 23:46:10.464 CET] [default] [debug]: QVariant(QString, "0x0000") 
[20201115 23:46:10.464 CET] [default] [debug]: QVariant(uint, 0) 
[20201115 23:46:10.464 CET] [default] [debug]: QVariant(int, 0) 
[20201115 23:46:10.465 CET] [default] [debug]: QVariant(int, 0) 
[20201115 23:46:10.465 CET] [default] [debug]: QVariant(QBitArray, QBitArray(1000 0001 0)) 
[20201115 23:46:10.466 CET] [ozw.mqtt.publisher] [debug]: Publishing Event nodeQueriesComplete: 1 
[20201115 23:46:10.466 CET] [ozw.notifications] [debug]: Notification pvt_driverAllNodesQueried Thread:  0x76f0c558 
[20201115 23:46:10.466 CET] [ozw.mqtt.publisher] [debug]: Publishing Event driverAllNodesQueried: 
[20201115 23:46:20.783 CET] [default] [debug]: QVariant(int, 1) 
[20201115 23:46:23.775 CET] [ozw.mqtt.publisher] [debug]: "Sun Nov 15 23:46:23 2020 PingResponse\n" 
[20201115 23:46:50.799 CET] [default] [debug]: QVariant(int, 1) 
[20201115 23:47:20.772 CET] [default] [debug]: QVariant(int, 1) 
[20201115 23:47:23.775 CET] [ozw.mqtt.publisher] [debug]: "Sun Nov 15 23:47:23 2020 PingResponse\n" 
[20201115 23:47:50.774 CET] [default] [debug]: QVariant(int, 1) 
[20201115 23:48:20.802 CET] [default] [debug]: QVariant(int, 1) 
[20201115 23:48:23.776 CET] [ozw.mqtt.publisher] [debug]: "Sun Nov 15 23:48:23 2020 PingResponse\n" 
[20201115 23:48:50.792 CET] [default] [debug]: QVariant(int, 1) 
[20201115 23:49:20.802 CET] [default] [debug]: QVariant(int, 1) 
[20201115 23:49:23.776 CET] [ozw.mqtt.publisher] [debug]: "Sun Nov 15 23:49:23 2020 PingResponse\n" 
[20201115 23:49:50.782 CET] [default] [debug]: QVariant(int, 1) 
[20201115 23:50:20.773 CET] [default] [debug]: QVariant(int, 1) 
[20201115 23:50:23.776 CET] [ozw.mqtt.publisher] [debug]: "Sun Nov 15 23:50:23 2020 PingResponse\n" 
[20201115 23:50:50.773 CET] [default] [debug]: QVariant(int, 1) 
[20201115 23:51:20.802 CET] [default] [debug]: QVariant(int, 1) 
[20201115 23:51:23.776 CET] [ozw.mqtt.publisher] [debug]: "Sun Nov 15 23:51:23 2020 PingResponse\n" 
[20201115 23:51:50.799 CET] [default] [debug]: QVariant(int, 1) 
[20201115 23:52:20.780 CET] [default] [debug]: QVariant(int, 1) 
[20201115 23:52:23.773 CET] [ozw.mqtt.publisher] [debug]: "Sun Nov 15 23:52:23 2020 PingResponse\n"
5

You can’t use the zwave integration and the openzwave addon + integration at the same time. They conflict with each other. Pick only one.

6

Thats it! Thank you. I never realize, that those are two different things/solution.
I didnt remebered from back then and now, when there is few things different I didnt noticed.

But anyway. Network is up and running, but no device from multiple vendors (standard zwave plus devices) cannot be discovered.

I get errors in log:

Logger: openzwave
Source: /usr/local/lib/python3.8/site-packages/openzwave/controller.py:694
First occurred: 0:43:35 (10 occurrences)
Last logged: 0:57:12

Can't lock controller for command : add_node

any ideas please?