OpenZWave Beta Issues

pfinnigan · July 14, 2020, 5:56pm

I am having a few issues with the OpenZWave Beta. I had version 0.4.4 working but my zwave configuration needed altering with the minor changes to the sensors in the beta version. I liked the beta 0.4.4 version so much I decided to bite the bullet an go for broke. I cleared down my controller, I find that easier than removing each individual node. Resetting each node to factory values just before adding is no trouble, removing them followed by adding them all is twice as long.

I first noted the new version of the Beta (0.5.0) so I upgraded then reset my zwave controller (Z-Wave.me UZB1). All devices were gone, as expected. However the Z-Wave.me controller failed to display as a Z-Wave+ device. I thought it showed as a Z-Wave+ device before. All attempts to add devices have failed.

I suffered from the problems of needing to clear out the MQTT topics between restarting, or using another instance. I was not unhappy with this, it had been reported and the software was beta.

I then upgraded to 0.5.1, in a vain attempt to get devices to add. Still no luck. However clearing out the MQTT topics nolonger works. The topics appear to get restored by OpenZWave addon. The only solution is to increment the instance number, I am currently running on instance 7.

I have tried to remove the topics, using MQTT explorer (I have tried mqtt_pub and the hassio mqtt_publish service as well). I have even deleted every message using the delete retained message button. If I restart the MQTT server the topics are still not there. However as soon as I restart all my topics are restored, for all instances. This is true even if I remove the Zwave integration and just runn the add-on, suggsting that OpenZWave is performing some form of restore. How do I delete the topics?

I still cannot add devices. I have tried a battery device and a mains powered device to no avail. I have tried different types. Any ideas will be considered. I did consider going back to the current stable ZWave integration just to do the configuration, but that would defeat the purpose of a beta test.

What I am trying to do is clear out my controller. Then add all my devices back in, one at a time, using the new OpenZWave integration.

If it helps my start up log shows the Z-Wave.me device as zwave+ node:

[20200713 22:18:37.884 BST] [ozw.library] [debug]: Debug - Node: 0 Downloads Remaining: 0 
[20200713 22:18:37.885 BST] [ozw.library] [info]: Info - Node: 0 ManufacturerSpecificDB Initialized 
[20200713 22:18:37.885 BST] [ozw.library] [debug]: Detail - Node: 0 Notification: ManufacturerSpecificDB Ready 
[20200713 22:18:37.886 BST] [ozw.library] [info]: Info - Node: 255 Sending (Command) message (Callback ID=0x00, Expected Reply=0x15) - FUNC_ID_ZW_GET_VERSION: 0x01, 0x03, 0x00, 0x15, 0xe9 
[20200713 22:18:37.886 BST] [ozw.notifications] [debug]: Notification pvt_manufacturerSpecificDBReady Thread:  0xb6f03558 
[20200713 22:18:37.886 BST] [ozw.library] [info]: Info - Node: 255 Encrypted Flag is 0 
[20200713 22:18:37.886 BST] [ozw.mqtt.publisher] [debug]: Publishing Event manufacturerSpecificDBReady 
[20200713 22:18:37.889 BST] [ozw.library] [debug]: Detail - Node: 255   Received: 0x01, 0x10, 0x01, 0x15, 0x5a, 0x2d, 0x57, 0x61, 0x76, 0x65, 0x20, 0x34, 0x2e, 0x36, 0x31, 0x00, 0x01, 0x95 
[20200713 22:18:37.889 BST] [ozw.library] [info]: Info - Node: 255 Received reply to FUNC_ID_ZW_GET_VERSION: 
[20200713 22:18:37.889 BST] [ozw.library] [info]: Info - Node: 255     Static Controller library, version Z-Wave 4.61 
[20200713 22:18:37.890 BST] [ozw.library] [debug]: Detail - Node: 255 Queuing (Command) FUNC_ID_ZW_MEMORY_GET_ID: 0x01, 0x03, 0x00, 0x20, 0xdc 
[20200713 22:18:37.890 BST] [ozw.library] [debug]: Detail - Node: 255   Expected reply was received 
[20200713 22:18:37.890 BST] [ozw.library] [debug]: Detail - Node: 255   Message transaction complete 
[20200713 22:18:37.891 BST] [ozw.library] [debug]: Detail - Node: 255 Removing current message 
[20200713 22:18:37.891 BST] [ozw.library] [info]: Info - Node: 255 Sending (Command) message (Callback ID=0x00, Expected Reply=0x20) - FUNC_ID_ZW_MEMORY_GET_ID: 0x01, 0x03, 0x00, 0x20, 0xdc 
[20200713 22:18:37.891 BST] [ozw.library] [info]: Info - Node: 255 Encrypted Flag is 0 
[20200713 22:18:37.896 BST] [ozw.library] [debug]: Detail - Node: 255   Received: 0x01, 0x08, 0x01, 0x20, 0xdb, 0xd1, 0xf6, 0xb5, 0x01, 0x9e 
[20200713 22:18:37.897 BST] [ozw.library] [info]: Info - Node: 255 Received reply to FUNC_ID_ZW_MEMORY_GET_ID. Home ID = 0xdbd1f6b5.  Our node ID = 1 
[20200713 22:18:37.897 BST] [ozw.library] [debug]: Detail - Node: 255 Queuing (Command) FUNC_ID_ZW_GET_CONTROLLER_CAPABILITIES: 0x01, 0x03, 0x00, 0x05, 0xf9 
[20200713 22:18:37.898 BST] [ozw.library] [debug]: Detail - Node: 255   Expected reply was received 
[20200713 22:18:37.898 BST] [ozw.library] [debug]: Detail - Node: 255   Message transaction complete 
[20200713 22:18:37.899 BST] [ozw.library] [debug]: Detail - Node: 255 Removing current message 
[20200713 22:18:37.899 BST] [ozw.library] [info]: Info - Node: 255 Sending (Command) message (Callback ID=0x00, Expected Reply=0x05) - FUNC_ID_ZW_GET_CONTROLLER_CAPABILITIES: 0x01, 0x03, 0x00, 0x05, 0xf9 
[20200713 22:18:37.900 BST] [ozw.library] [info]: Info - Node: 255 Encrypted Flag is 0 
[20200713 22:18:37.902 BST] [ozw.library] [debug]: Detail - Node: 255   Received: 0x01, 0x04, 0x01, 0x05, 0x28, 0xd7 
[20200713 22:18:37.902 BST] [ozw.library] [info]: Info - Node: 255 Received reply to FUNC_ID_ZW_GET_CONTROLLER_CAPABILITIES: 
[20200713 22:18:37.903 BST] [ozw.library] [info]: Info - Node: 255     There is no SUC ID Server (SIS) in this network. 
[20200713 22:18:37.903 BST] [ozw.library] [info]: Info - Node: 255     The PC controller is a primary controller. 
[20200713 22:18:37.904 BST] [ozw.library] [debug]: Detail - Node: 255 Queuing (Command) FUNC_ID_ZW_GET_SUC_NODE_ID: 0x01, 0x03, 0x00, 0x56, 0xaa 
[20200713 22:18:37.904 BST] [ozw.library] [debug]: Detail - Node: 255   Expected reply was received 
[20200713 22:18:37.904 BST] [ozw.library] [debug]: Detail - Node: 255   Message transaction complete 
[20200713 22:18:37.905 BST] [ozw.library] [debug]: Detail - Node: 255 Removing current message 
[20200713 22:18:37.905 BST] [ozw.library] [info]: Info - Node: 255 Sending (Command) message (Callback ID=0x00, Expected Reply=0x56) - FUNC_ID_ZW_GET_SUC_NODE_ID: 0x01, 0x03, 0x00, 0x56, 0xaa 
[20200713 22:18:37.907 BST] [ozw.library] [info]: Info - Node: 255 Encrypted Flag is 0 
[20200713 22:18:37.910 BST] [ozw.library] [debug]: Detail - Node: 255   Received: 0x01, 0x04, 0x01, 0x56, 0x00, 0xac 
[20200713 22:18:37.910 BST] [ozw.library] [info]: Info - Node: 255 Received reply to GET_SUC_NODE_ID.  Node ID = 0 
[20200713 22:18:37.911 BST] [ozw.library] [info]: Info - Node: 0 Controller Does not Support SUC - Cannot Setup Controller as SUC Node 
[20200713 22:18:37.911 BST] [ozw.library] [debug]: Detail - Node: 255 Queuing (Command) FUNC_ID_SERIAL_API_GET_CAPABILITIES: 0x01, 0x03, 0x00, 0x07, 0xfb 
[20200713 22:18:37.912 BST] [ozw.library] [debug]: Detail - Node: 255   Expected reply was received 
[20200713 22:18:37.912 BST] [ozw.library] [debug]: Detail - Node: 255   Message transaction complete 
[20200713 22:18:37.912 BST] [ozw.library] [debug]: Detail - Node: 255 Removing current message 
[20200713 22:18:37.913 BST] [ozw.library] [info]: Info - Node: 255 Sending (Command) message (Callback ID=0x00, Expected Reply=0x07) - FUNC_ID_SERIAL_API_GET_CAPABILITIES: 0x01, 0x03, 0x00, 0x07, 0xfb 
[20200713 22:18:37.913 BST] [ozw.library] [info]: Info - Node: 255 Encrypted Flag is 0 
[20200713 22:18:37.918 BST] [ozw.library] [debug]: Detail - Node: 255   Received: 0x01, 0x2b, 0x01, 0x07, 0x05, 0x1b, 0x01, 0x15, 0x04, 0x00, 0x00, 0x01, 0xfe, 0x87, 0x7f, 0x88, 0xcf, 0x3f, 0xc0, 0x47, 0xfb, 0xdf, 0xfd, 0xe0, 0x67, 0x00, 0x80, 0x80, 0x00, 0x80, 0x86, 0x00, 0x00, 0x00, 0xe8, 0x73, 0x00, 0x80, 0x0f, 0x00, 0x00, 0x60, 0x5a, 0x00, 0x52 
[20200713 22:18:37.918 BST] [ozw.library] [info]: Info - Node: 255  Received reply to FUNC_ID_SERIAL_API_GET_CAPABILITIES 
[20200713 22:18:37.919 BST] [ozw.library] [info]: Info - Node: 255     Serial API Version:   5.27 
[20200713 22:18:37.921 BST] [ozw.library] [info]: Info - Node: 255     Manufacturer ID:      0x0115 
[20200713 22:18:37.922 BST] [ozw.library] [info]: Info - Node: 255     Product Type:         0x0400 
[20200713 22:18:37.922 BST] [ozw.library] [info]: Info - Node: 255     Product ID:           0x0001 
[20200713 22:18:37.923 BST] [ozw.library] [debug]: Detail - Node: 255 Queuing (Command) FUNC_ID_ZW_GET_RANDOM: 0x01, 0x04, 0x00, 0x1c, 0x20, 0xc7 
[20200713 22:18:37.923 BST] [ozw.library] [debug]: Detail - Node: 255 Queuing (Command) FUNC_ID_SERIAL_API_SETUP: 0x01, 0x05, 0x00, 0x0b, 0x02, 0x01, 0xf2 
[20200713 22:18:37.924 BST] [ozw.library] [debug]: Detail - Node: 255 Queuing (Command) FUNC_ID_SERIAL_API_GET_INIT_DATA: 0x01, 0x03, 0x00, 0x02, 0xfe 
[20200713 22:18:37.924 BST] [ozw.library] [debug]: Detail - Node: 255 Queuing (Command) FUNC_ID_SERIAL_API_SET_TIMEOUTS: 0x01, 0x05, 0x00, 0x06, 0x64, 0x0f, 0x97 
[20200713 22:18:37.925 BST] [ozw.library] [debug]: Detail - Node: 255 Queuing (Command) FUNC_ID_SERIAL_API_APPL_NODE_INFORMATION: 0x01, 0x08, 0x00, 0x03, 0x01, 0x02, 0x01, 0x01, 0x5e, 0xa9 
[20200713 22:18:37.925 BST] [ozw.library] [debug]: Detail - Node: 255   Expected reply was received 
[20200713 22:18:37.926 BST] [ozw.library] [debug]: Detail - Node: 255   Message transaction complete 
[20200713 22:18:37.926 BST] [ozw.library] [debug]: Detail - Node: 255 Removing current message 
[20200713 22:18:37.927 BST] [ozw.library] [info]: Info - Node: 255 Sending (Command) message (Callback ID=0x00, Expected Reply=0x1c) - FUNC_ID_ZW_GET_RANDOM: 0x01, 0x04, 0x00, 0x1c, 0x20, 0xc7 
[20200713 22:18:37.927 BST] [ozw.library] [info]: Info - Node: 255 Encrypted Flag is 0 
[20200713 22:18:37.985 BST] [ozw.library] [debug]: Detail - Node: 255   Received: 0x01, 0x25, 0x01, 0x1c, 0x01, 0x20, 0x2c, 0x01, 0x74, 0x70, 0xd8, 0xc1, 0xae, 0x51, 0xe6, 0xf1, 0xd0, 0x92, 0xa6, 0xab, 0x22, 0xe8, 0x8f, 0xc2, 0x35, 0xe7, 0x22, 0x4e, 0xd1, 0xd9, 0x6f, 0x71, 0x0c, 0x3f, 0x1b, 0x75, 0x89, 0xd1, 0x5b 
[20200713 22:18:37.985 BST] [ozw.library] [info]: Info - Node: 0 Received reply to FUNC_ID_ZW_GET_RANDOM: true 
[20200713 22:18:37.986 BST] [ozw.library] [debug]: Detail - Node: 255   Expected reply was received 
[20200713 22:18:37.986 BST] [ozw.library] [debug]: Detail - Node: 255   Message transaction complete 
[20200713 22:18:37.987 BST] [ozw.library] [debug]: Detail - Node: 255 Removing current message 
[20200713 22:18:37.987 BST] [ozw.library] [info]: Info - Node: 255 Sending (Command) message (Callback ID=0x00, Expected Reply=0x0b) - FUNC_ID_SERIAL_API_SETUP: 0x01, 0x05, 0x00, 0x0b, 0x02, 0x01, 0xf2 
[20200713 22:18:37.988 BST] [ozw.library] [info]: Info - Node: 255 Encrypted Flag is 0 
[20200713 22:18:37.991 BST] [ozw.library] [debug]: Detail - Node: 255   Received: 0x01, 0x05, 0x01, 0x0b, 0x02, 0x01, 0xf3 
[20200713 22:18:37.992 BST] [ozw.library] [info]: Info - Node: 0 Received reply to FUNC_ID_SERIAL_API_SETUP 
[20200713 22:18:37.992 BST] [ozw.library] [info]: Info - Node: 0 Successfully enabled extended txStatusReport. 
[20200713 22:18:37.993 BST] [ozw.library] [debug]: Detail - Node: 255   Expected reply was received 
[20200713 22:18:37.993 BST] [ozw.library] [debug]: Detail - Node: 255   Message transaction complete 
[20200713 22:18:37.993 BST] [ozw.library] [debug]: Detail - Node: 255 Removing current message 
[20200713 22:18:37.994 BST] [ozw.library] [info]: Info - Node: 255 Sending (Command) message (Callback ID=0x00, Expected Reply=0x02) - FUNC_ID_SERIAL_API_GET_INIT_DATA: 0x01, 0x03, 0x00, 0x02, 0xfe 
[20200713 22:18:37.994 BST] [ozw.library] [info]: Info - Node: 255 Encrypted Flag is 0 
QStandardPaths: XDG_RUNTIME_DIR not set, defaulting to '/tmp/runtime-root'
ozwadmin: Settings Path is at  "/root/.config/OpenZWave/ozw-admin.conf"
ozwadmin: Checking  "/data/ozw/config"  for manufacturer_specific.xml
ozwadmin: Checking  "/data/ozw/config"  for options.xml
ozwadmin: DBPath:  "/data/ozw/config/"
ozwadmin: userPath:  "/data/ozw/config/"
[20200713 22:18:38.094 BST] [ozw.library] [debug]: Detail - Node: 255   Received: 0x01, 0x25, 0x01, 0x02, 0x06, 0x00, 0x1d, 0x01, 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, 0x00, 0x05, 0x00, 0xc6 
[20200713 22:18:38.095 BST] [ozw.library] [info]: Info - Node: 0 mgr,     Driver with Home ID of 0xdbd1f6b5 is now ready. 
[20200713 22:18:38.097 BST] [ozw.library] [info]: Info - Node: 1 (32 - COMMAND_CLASS_BASIC) - Compatibility Flags: 
[20200713 22:18:38.097 BST] [ozw.library] [info]: Info - Node: 1 (32 - COMMAND_CLASS_BASIC) - State Flags: 
[20200713 22:18:38.098 BST] [ozw.library] [info]: Info - Node: 1 	 AfterMark: true 
[20200713 22:18:38.098 BST] [ozw.library] [warning]: Warning - Node: 0 Localization::ReadXMLVIDHelp: Error in /data/ozw/config/ozwcache_0xdbd1f6b5.xml at line 21 - No Help Entry for CommandClass 32, ValueID: 1 (-1):  (null) (Lang: ) 
[20200713 22:18:38.099 BST] [ozw.library] [warning]: Warning - Node: 0 Localization::ReadXMLVIDHelp: Error in /data/ozw/config/ozwcache_0xdbd1f6b5.xml at line 24 - No Help Entry for CommandClass 32, ValueID: 2 (-1):  (null) (Lang: ) 
[20200713 22:18:38.099 BST] [ozw.library] [info]: Info - Node: 1 (114 - COMMAND_CLASS_MANUFACTURER_SPECIFIC) - Compatibility Flags: 
[20200713 22:18:38.100 BST] [ozw.library] [info]: Info - Node: 1 (114 - COMMAND_CLASS_MANUFACTURER_SPECIFIC) - State Flags: 
[20200713 22:18:38.100 BST] [ozw.library] [info]: Info - Node: 1 	 StaticRequests: 2 
[20200713 22:18:38.101 BST] [ozw.library] [info]: Info - Node: 255 Received reply to FUNC_ID_SERIAL_API_GET_INIT_DATA: 
[20200713 22:18:38.101 BST] [ozw.library] [info]: Info - Node: 255     Node 001 - Known 
[20200713 22:18:38.102 BST] [ozw.library] [debug]: Detail - Node: 1 AdvanceQueries queryPending=0 queryRetries=0 queryStage=CacheLoad live=1 
[20200713 22:18:38.102 BST] [ozw.library] [debug]: Detail - Node: 1 QueryStage_CacheLoad 
[20200713 22:18:38.102 BST] [ozw.library] [info]: Info - Node: 1 Loading Cache for node 1: Manufacturer=Z-Wave.Me, Product=ZME_UZB1 USB Stick 
[20200713 22:18:38.103 BST] [ozw.library] [info]: Info - Node: 1 Node Identity Codes: 0115:0400:0001 
[20200713 22:18:38.103 BST] [ozw.library] [debug]: Detail - Node: 1 QueryStage_Associations 
[20200713 22:18:38.104 BST] [ozw.library] [debug]: Detail - Node: 1 QueryStage_Neighbors 
[20200713 22:18:38.104 BST] [ozw.library] [debug]: Detail - Node: 255 Requesting routing info (neighbor list) for Node 1 
[20200713 22:18:38.105 BST] [ozw.library] [debug]: Detail - Node: 1 Queuing (Command) Get Routing Info (Node=1): 0x01, 0x07, 0x00, 0x80, 0x01, 0x00, 0x00, 0x03, 0x7a 
[20200713 22:18:38.105 BST] [ozw.library] [debug]: Detail - Node: 1 Queuing (Query) Query Stage Complete (Neighbors) 
[20200713 22:18:38.106 BST] [ozw.library] [debug]: Detail - Node: 255   Expected reply was received 
[20200713 22:18:38.106 BST] [ozw.library] [debug]: Detail - Node: 255   Message transaction complete 
[20200713 22:18:38.107 BST] [ozw.library] [debug]: Detail - Node: 255 Removing current message 
[20200713 22:18:38.107 BST] [ozw.library] [debug]: Detail - Node: 1 Notification: DriverReady 
[20200713 22:18:38.107 BST] [ozw.notifications] [debug]: Notification pvt_driverRead  3687970485 Thread:  0xb6f03558 
[20200713 22:18:38.108 BST] [ozw.mqtt.publisher] [debug]: Publishing Event started 
[20200713 22:18:38.108 BST] [ozw.manager] [debug]: setStarted 
[20200713 22:18:38.109 BST] [ozw.mqtt.publisher] [debug]: Publishing Event driverReady: 3687970485 
[20200713 22:18:38.109 BST] [ozw.library] [debug]: Detail - Node: 1 Notification: NodeAdded 
[20200713 22:18:38.112 BST] [ozw.notifications] [debug]: Notification pvt_nodeAdded  1 Thread:  0xb6f03558 
[20200713 22:18:38.113 BST] [ozw.nodes] [info]: Adding Node  1 At Row  0 
[20200713 22:18:38.113 BST] [ozw.nodes] [debug]: setNodeData  1 :  QTOZW_Nodes::NodeQueryStage : QVariant(QString, "Neighbors")  Transaction: true 
[20200713 22:18:38.113 BST] [default] [debug]: QVariant(int, 1) 
[20200713 22:18:38.114 BST] [default] [debug]: QVariant(Invalid) 
[20200713 22:18:38.114 BST] [default] [debug]: QVariant(Invalid) 
[20200713 22:18:38.114 BST] [default] [debug]: QVariant(Invalid) 
[20200713 22:18:38.114 BST] [default] [debug]: QVariant(Invalid) 
[20200713 22:18:38.115 BST] [default] [debug]: QVariant(Invalid) 
[20200713 22:18:38.115 BST] [default] [debug]: QVariant(Invalid) 
[20200713 22:18:38.115 BST] [default] [debug]: QVariant(Invalid) 
[20200713 22:18:38.115 BST] [default] [debug]: QVariant(Invalid) 
[20200713 22:18:38.115 BST] [default] [debug]: QVariant(Invalid) 
[20200713 22:18:38.116 BST] [default] [debug]: QVariant(Invalid) 
[20200713 22:18:38.116 BST] [default] [debug]: QVariant(Invalid) 
[20200713 22:18:38.116 BST] [default] [debug]: QVariant(Invalid) 
[20200713 22:18:38.116 BST] [default] [debug]: QVariant(Invalid) 
[20200713 22:18:38.117 BST] [default] [debug]: QVariant(Invalid) 
[20200713 22:18:38.117 BST] [default] [debug]: QVariant(Invalid) 
[20200713 22:18:38.117 BST] [default] [debug]: QVariant(Invalid) 
[20200713 22:18:38.117 BST] [default] [debug]: QVariant(QString, "Neighbors") 
[20200713 22:18:38.118 BST] [default] [debug]: QVariant(Invalid) 
[20200713 22:18:38.118 BST] [default] [debug]: QVariant(Invalid) 
[20200713 22:18:38.118 BST] [default] [debug]: QVariant(Invalid) 
[20200713 22:18:38.118 BST] [default] [debug]: QVariant(Invalid) 
[20200713 22:18:38.118 BST] [default] [debug]: QVariant(Invalid) 
[20200713 22:18:38.119 BST] [default] [debug]: QVariant(Invalid) 
[20200713 22:18:38.119 BST] [default] [debug]: QVariant(QBitArray, QBitArray(0000 0011 0)) 
[20200713 22:18:38.119 BST] [ozw.manager] [debug]: ProductPic Path:  "/data/ozw/config/" 
[20200713 22:18:38.120 BST] [ozw.mqtt.publisher] [debug]: Publishing Event NodeAdded: 1 
[20200713 22:18:38.120 BST] [ozw.library] [debug]: Detail - Node: 1 Notification: NodeProtocolInfo 
[20200713 22:18:38.122 BST] [ozw.library] [debug]: Detail - Node: 1 Notification: EssentialNodeQueriesComplete 
[20200713 22:18:38.123 BST] [ozw.notifications] [debug]: Notification pvt_nodeProtocolInfo  1 Thread:  0xb6f03558 
[20200713 22:18:38.123 BST] [ozw.nodes] [debug]: setNodeData  1 :  QTOZW_Nodes::NodeProductName : QVariant(QString, "ZME_UZB1 USB Stick")  Transaction: true 
[20200713 22:18:38.123 BST] [ozw.nodes] [debug]: setNodeData  1 :  QTOZW_Nodes::NodeManufacturerName : QVariant(QString, "Z-Wave.Me")  Transaction: true 
[20200713 22:18:38.123 BST] [ozw.nodes] [debug]: setNodeData  1 :  QTOZW_Nodes::NodeManufacturerID : QVariant(QString, "0x0115")  Transaction: true 
[20200713 22:18:38.124 BST] [ozw.nodes] [debug]: setNodeData  1 :  QTOZW_Nodes::NodeProductID : QVariant(QString, "0x0001")  Transaction: true 
[20200713 22:18:38.124 BST] [ozw.library] [debug]: Detail - Node: 1 Notification: ValueAdded CC: COMMAND_CLASS_BASIC Instance: 1 Index: 0 
[20200713 22:18:38.126 BST] [ozw.library] [debug]: Detail - Node: 1 Notification: ValueAdded CC: COMMAND_CLASS_BASIC Instance: 1 Index: 1 
[20200713 22:18:38.125 BST] [ozw.nodes] [debug]: setNodeData  1 :  QTOZW_Nodes::NodeProductType : QVariant(QString, "0x0400")  Transaction: true 
[20200713 22:18:38.136 BST] [ozw.library] [debug]: Detail - Node: 1 Notification: ValueAdded CC: COMMAND_CLASS_BASIC Instance: 1 Index: 2 
[20200713 22:18:38.137 BST] [ozw.library] [debug]: Detail - Node: 1 Notification: ValueAdded CC: COMMAND_CLASS_MANUFACTURER_SPECIFIC Instance: 1 Index: 0 
[20200713 22:18:38.137 BST] [ozw.library] [debug]: Detail - Node: 1 Notification: ValueAdded CC: COMMAND_CLASS_MANUFACTURER_SPECIFIC Instance: 1 Index: 1 
[20200713 22:18:38.138 BST] [ozw.library] [debug]: Detail - Node: 1 Notification: ValueAdded CC: COMMAND_CLASS_MANUFACTURER_SPECIFIC Instance: 1 Index: 2 
[20200713 22:18:38.138 BST] [ozw.library] [debug]: Detail - Node: 1 Notification: NodeNaming 
[20200713 22:18:38.144 BST] [ozw.nodes] [debug]: setNodeData  1 :  QTOZW_Nodes::NodeBasicString : QVariant(QString, "Static Controller")  Transaction: true 
[20200713 22:18:38.145 BST] [ozw.library] [info]: Info - Node: 255 Sending (Command) message (Callback ID=0x00, Expected Reply=0x06) - FUNC_ID_SERIAL_API_SET_TIMEOUTS: 0x01, 0x05, 0x00, 0x06, 0x64, 0x0f, 0x97 
[20200713 22:18:38.146 BST] [ozw.library] [info]: Info - Node: 255 Encrypted Flag is 0 
[20200713 22:18:38.146 BST] [ozw.nodes] [debug]: setNodeData  1 :  QTOZW_Nodes::NodeBasic : QVariant(int, 2)  Transaction: true 
[20200713 22:18:38.147 BST] [ozw.nodes] [debug]: setNodeData  1 :  QTOZW_Nodes::NodeGenericString : QVariant(QString, "Static Controller")  Transaction: true 
[20200713 22:18:38.148 BST] [ozw.library] [debug]: Detail - Node: 255   Received: 0x01, 0x05, 0x01, 0x06, 0x64, 0x0f, 0x96 
[20200713 22:18:38.149 BST] [ozw.nodes] [debug]: setNodeData  1 :  QTOZW_Nodes::NodeGeneric : QVariant(int, 2)  Transaction: true 
[20200713 22:18:38.156 BST] [ozw.library] [info]: Info - Node: 255 Received reply to FUNC_ID_SERIAL_API_SET_TIMEOUTS 
[20200713 22:18:38.157 BST] [ozw.library] [debug]: Detail - Node: 255   Expected reply was received 
[20200713 22:18:38.157 BST] [ozw.library] [debug]: Detail - Node: 255   Message transaction complete 
[20200713 22:18:38.157 BST] [ozw.nodes] [debug]: setNodeData  1 :  QTOZW_Nodes::NodeSpecific : QVariant(int, 1)  Transaction: true 
[20200713 22:18:38.157 BST] [ozw.library] [debug]: Detail - Node: 255 Removing current message 
[20200713 22:18:38.158 BST] [ozw.nodes] [debug]: setNodeData  1 :  QTOZW_Nodes::NodeSpecificString : QVariant(QString, "Static PC Controller")  Transaction: true 
[20200713 22:18:38.158 BST] [ozw.library] [info]: Info - Node: 255 Sending (Command) message (Callback ID=0x00, Expected Reply=0x00) - FUNC_ID_SERIAL_API_APPL_NODE_INFORMATION: 0x01, 0x08, 0x00, 0x03, 0x01, 0x02, 0x01, 0x01, 0x5e, 0xa9 
[20200713 22:18:38.159 BST] [ozw.library] [info]: Info - Node: 255 Encrypted Flag is 0 
[20200713 22:18:38.159 BST] [ozw.nodes] [debug]: setNodeData  1 :  QTOZW_Nodes::NodeBaudRate : QVariant(uint, 100000)  Transaction: true 
[20200713 22:18:38.160 BST] [ozw.nodes] [debug]: setNodeData  1 :  QTOZW_Nodes::NodeVersion : QVariant(int, 4)  Transaction: true 
[20200713 22:18:38.160 BST] [ozw.library] [debug]: Detail - Node: 255 Removing current message 
[20200713 22:18:38.161 BST] [default] [debug]: QVariant(int, 1) 
[20200713 22:18:38.161 BST] [ozw.library] [info]: Info - Node: 1 Sending (Command) message (Callback ID=0x00, Expected Reply=0x80) - Get Routing Info (Node=1): 0x01, 0x07, 0x00, 0x80, 0x01, 0x00, 0x00, 0x03, 0x7a 
[20200713 22:18:38.161 BST] [ozw.library] [info]: Info - Node: 1 Encrypted Flag is 0

pfinnigan · July 16, 2020, 6:26pm

Some more information.

I am back on instnace 1. What I did. Bear in mind that I have NOT got the integration installed.

Stop the addon, clear the MQTT queues, uninstall the addon, clear down my controller, reboot the host system, check the MQTT queues still clear, install the addon, reconfigure (using instance 1).

It starts first time. However the controller does not look correct adding a device and healing the network show nothing:

[20200716 19:10:22.841 BST] [default] [debug]: QVariant(int, 1) 
[20200716 19:10:24.966 BST] [ozw.library] [debug]: Detail - Node: 0 Queuing (Controller) Add Device 
[20200716 19:10:24.966 BST] [ozw.library] [info]: Info - Node: 0 Add Device 
[20200716 19:10:24.967 BST] [ozw.library] [debug]: Detail - Node: 255 Queuing (Command) ControllerCommand_AddDevice: 0x01, 0x05, 0x00, 0x4a, 0xc1, 0x0c, 0x7d 
[20200716 19:10:24.967 BST] [ozw.library] [debug]: Detail - Node: 0 Notification: AddDevice ControllerCommand - Starting 
[20200716 19:10:24.968 BST] [ozw.library] [info]: Info - Node: 255 Sending (Command) message (Callback ID=0x0c, Expected Reply=0x4a) - ControllerCommand_AddDevice: 0x01, 0x05, 0x00, 0x4a, 0xc1, 0x0c, 0x7d 
[20200716 19:10:24.968 BST] [ozw.library] [info]: Info - Node: 255 Encrypted Flag is 0 
[20200716 19:10:24.969 BST] [ozw.notifications] [debug]: Notification pvt_controllerCommand  1 1 0 Thread:  0xb6f48558 
[20200716 19:10:24.972 BST] [ozw.mqtt.publisher] [debug]: Publishing Event controllerCommand 0 NotificationTypes::Ctrl_Cmd_AddNode NotificationTypes::Ctrl_State_Starting NotificationTypes::Ctrl_Error_None 
[20200716 19:10:24.973 BST] [ozw.library] [debug]: Detail - Node: 255   Received: 0x01, 0x07, 0x00, 0x4a, 0x0c, 0x01, 0x00, 0x00, 0xbf 
[20200716 19:10:24.975 BST] [ozw.library] [info]: Info - Node: 255 FUNC_ID_ZW_ADD_NODE_TO_NETWORK: 
[20200716 19:10:24.976 BST] [ozw.library] [info]: Info - Node: 255 ADD_NODE_STATUS_LEARN_READY 
[20200716 19:10:24.976 BST] [ozw.library] [debug]: Detail - Node: 255   Expected callbackId was received 
[20200716 19:10:24.977 BST] [ozw.library] [debug]: Detail - Node: 255   Expected reply was received 
[20200716 19:10:24.977 BST] [ozw.library] [debug]: Detail - Node: 255   Message transaction complete 
[20200716 19:10:24.978 BST] [ozw.library] [debug]: Detail - Node: 255 Removing current message 
[20200716 19:10:24.981 BST] [ozw.library] [debug]: Detail - Node: 0 Notification: AddDevice ControllerCommand - Waiting 
[20200716 19:10:24.982 BST] [ozw.library] [info]: Info - Node: 0 WriteNextMsg Controller nothing to do 
[20200716 19:10:24.983 BST] [ozw.notifications] [debug]: Notification pvt_controllerCommand  1 4 0 Thread:  0xb6f48558 
[20200716 19:10:24.984 BST] [ozw.mqtt.publisher] [debug]: Publishing Event controllerCommand 0 NotificationTypes::Ctrl_Cmd_AddNode NotificationTypes::Ctrl_State_Waiting NotificationTypes::Ctrl_Error_None 
[20200716 19:10:25.002 BST] [ozwadmin] [debug]: ControllerCommandNotification:  0 NotificationTypes::Ctrl_Cmd_AddNode NotificationTypes::Ctrl_State_Starting NotificationTypes::Ctrl_Error_None 
[20200716 19:10:25.010 BST] [ozwadmin] [debug]: ControllerCommandNotification:  0 NotificationTypes::Ctrl_Cmd_AddNode NotificationTypes::Ctrl_State_Waiting NotificationTypes::Ctrl_Error_None 
[20200716 19:10:47.841 BST] [ozw.mqtt.publisher] [debug]: "Thu Jul 16 19:10:47 2020 PingResponse\n" 
[20200716 19:10:52.841 BST] [default] [debug]: QVariant(int, 1) 
[20200716 19:11:22.841 BST] [default] [debug]: QVariant(int, 1) 
[20200716 19:11:47.841 BST] [ozw.mqtt.publisher] [debug]: "Thu Jul 16 19:11:47 2020 PingResponse\n" 
[20200716 19:11:52.841 BST] [default] [debug]: QVariant(int, 1) 
[20200716 19:12:22.840 BST] [default] [debug]: QVariant(int, 1) 
[20200716 19:12:47.841 BST] [ozw.mqtt.publisher] [debug]: "Thu Jul 16 19:12:47 2020 PingResponse\n" 
[20200716 19:12:52.841 BST] [default] [debug]: QVariant(int, 1) 
[20200716 19:13:22.841 BST] [default] [debug]: QVariant(int, 1) 
172.30.32.2 - - [16/Jul/2020 19:13:37] 172.30.32.2: Plain non-SSL (ws://) WebSocket connection
172.30.32.2 - - [16/Jul/2020 19:13:37] 172.30.32.2: Path: '/websockify'
172.30.32.2 - - [16/Jul/2020 19:13:37] connecting to: 127.0.0.1:5900
[20200716 19:13:44.052 BST] [ozw.library] [info]: Info - Node: 0 Cancel Add Node 
[20200716 19:13:44.053 BST] [ozw.library] [debug]: Detail - Node: 255 Queuing (Command) Add Node Stop: 0x01, 0x04, 0x00, 0x4a, 0x05, 0xb4 
[20200716 19:13:44.053 BST] [ozw.library] [debug]: Detail - Node: 255 Notification: AddDevice ControllerCommand - Canceled 
[20200716 19:13:44.053 BST] [ozw.library] [info]: Info - Node: 255 Sending (Command) message (Callback ID=0x00, Expected Reply=0x4a) - Add Node Stop: 0x01, 0x04, 0x00, 0x4a, 0x05, 0xb4 
[20200716 19:13:44.054 BST] [ozw.library] [info]: Info - Node: 255 Encrypted Flag is 0 
[20200716 19:13:44.054 BST] [ozw.notifications] [debug]: Notification pvt_controllerCommand  1 2 0 Thread:  0xb6f48558 
[20200716 19:13:44.054 BST] [ozw.mqtt.publisher] [debug]: Publishing Event controllerCommand 255 NotificationTypes::Ctrl_Cmd_AddNode NotificationTypes::Ctrl_State_Cancel NotificationTypes::Ctrl_Error_None 
[20200716 19:13:44.090 BST] [ozwadmin] [debug]: ControllerCommandNotification:  255 NotificationTypes::Ctrl_Cmd_AddNode NotificationTypes::Ctrl_State_Cancel NotificationTypes::Ctrl_Error_None 
[20200716 19:13:44.106 BST] [ozw.library] [debug]: Detail - Node: 255   Received: 0x01, 0x07, 0x00, 0x4a, 0x0c, 0x06, 0x00, 0x00, 0xb8 
[20200716 19:13:44.107 BST] [ozw.library] [info]: Info - Node: 255 FUNC_ID_ZW_ADD_NODE_TO_NETWORK: 
[20200716 19:13:44.107 BST] [ozw.library] [info]: Info - Node: 255 ADD_NODE_STATUS_DONE 
[20200716 19:13:44.107 BST] [ozw.library] [debug]: Detail - Node: 255   Expected reply was received 
[20200716 19:13:44.107 BST] [ozw.library] [debug]: Detail - Node: 255   Message transaction complete 
[20200716 19:13:44.107 BST] [ozw.library] [debug]: Detail - Node: 255 Removing current message 
[20200716 19:13:44.108 BST] [ozw.library] [debug]: Detail - Node: 255 Notification: AddDevice ControllerCommand - Completed 
[20200716 19:13:44.108 BST] [ozw.notifications] [debug]: Notification pvt_controllerCommand  1 7 0 Thread:  0xb6f48558 
[20200716 19:13:44.109 BST] [ozw.mqtt.publisher] [debug]: Publishing Event controllerCommand 255 NotificationTypes::Ctrl_Cmd_AddNode NotificationTypes::Ctrl_State_Completed NotificationTypes::Ctrl_Error_None 
[20200716 19:13:44.122 BST] [ozwadmin] [debug]: ControllerCommandNotification:  255 NotificationTypes::Ctrl_Cmd_AddNode NotificationTypes::Ctrl_State_Completed NotificationTypes::Ctrl_Error_None 
[20200716 19:13:47.841 BST] [ozw.mqtt.publisher] [debug]: "Thu Jul 16 19:13:47 2020 PingResponse\n" 
[20200716 19:13:48.478 BST] [ozwadmin] [debug]: Opening Window 
[20200716 19:13:52.841 BST] [default] [debug]: QVariant(int, 1) 
[20200716 19:14:02.527 BST] [ozw.library] [debug]: Detail - Node: 1 Queuing (Controller) Request Node Neighbor Update 
[20200716 19:14:02.527 BST] [ozw.library] [info]: Info - Node: 0 Requesting Neighbor Update for node 1 
[20200716 19:14:02.527 BST] [ozw.library] [debug]: Detail - Node: 1 Queuing (Command) ControllerCommand_RequestNodeNeighborUpdate (Node=1): 0x01, 0x05, 0x00, 0x48, 0x01, 0x0d, 0xbe 
[20200716 19:14:02.528 BST] [ozw.library] [debug]: Detail - Node: 1 Notification: RequestNodeNeighborUpdate ControllerCommand - Starting 
[20200716 19:14:02.528 BST] [ozw.library] [info]: Info - Node: 1 Sending (Command) message (Callback ID=0x0d, Expected Reply=0x48) - ControllerCommand_RequestNodeNeighborUpdate (Node=1): 0x01, 0x05, 0x00, 0x48, 0x01, 0x0d, 0xbe 
[20200716 19:14:02.528 BST] [ozw.notifications] [debug]: Notification pvt_controllerCommand  10 1 0 Thread:  0xb6f48558 
[20200716 19:14:02.528 BST] [ozw.library] [info]: Info - Node: 1 Encrypted Flag is 0 
[20200716 19:14:02.529 BST] [ozw.mqtt.publisher] [debug]: Publishing Event controllerCommand 1 NotificationTypes::Ctrl_Cmd_RequestNodeNeighborUpdate NotificationTypes::Ctrl_State_Starting NotificationTypes::Ctrl_Error_None 
[20200716 19:14:02.537 BST] [ozwadmin] [debug]: ControllerCommandNotification:  1 NotificationTypes::Ctrl_Cmd_RequestNodeNeighborUpdate NotificationTypes::Ctrl_State_Starting NotificationTypes::Ctrl_Error_None 
[20200716 19:14:02.549 BST] [ozw.library] [debug]: Detail - Node: 1   Received: 0x01, 0x05, 0x00, 0x48, 0x0d, 0x23, 0x9c 
[20200716 19:14:02.549 BST] [ozw.library] [warning]: Warning - Node: 1 WARNING: REQUEST_NEIGHBOR_UPDATE_FAILED 
[20200716 19:14:02.550 BST] [ozw.library] [debug]: Detail - Node: 1   Expected callbackId was received 
[20200716 19:14:02.550 BST] [ozw.library] [debug]: Detail - Node: 1   Expected reply was received 
[20200716 19:14:02.550 BST] [ozw.library] [debug]: Detail - Node: 1   Message transaction complete 
[20200716 19:14:02.550 BST] [ozw.library] [debug]: Detail - Node: 1 Removing current message 
[20200716 19:14:02.550 BST] [ozw.library] [debug]: Detail - Node: 1 Notification: RequestNodeNeighborUpdate ControllerCommand - Failed 
[20200716 19:14:02.551 BST] [ozw.notifications] [debug]: Notification pvt_controllerCommand  10 8 0 Thread:  0xb6f48558 
[20200716 19:14:02.552 BST] [ozw.mqtt.publisher] [debug]: Publishing Event controllerCommand 1 NotificationTypes::Ctrl_Cmd_RequestNodeNeighborUpdate NotificationTypes::Ctrl_State_Failed NotificationTypes::Ctrl_Error_None 
[20200716 19:14:02.616 BST] [ozwadmin] [debug]: ControllerCommandNotification:  1 NotificationTypes::Ctrl_Cmd_RequestNodeNeighborUpdate NotificationTypes::Ctrl_State_Failed NotificationTypes::Ctrl_Error_None 
[20200716 19:14:22.841 BST] [default] [debug]: QVariant(int, 1) 
[20200716 19:14:47.842 BST] [ozw.mqtt.publisher] [debug]: "Thu Jul 16 19:14:47 2020 PingResponse\n" 
[20200716 19:14:52.841 BST] [default] [debug]: QVariant(int, 1) 
[20200716 19:15:22.841 BST] [default] [debug]: QVariant(int, 1) 
[20200716 19:15:47.841 BST] [ozw.mqtt.publisher] [debug]: "Thu Jul 16 19:15:47 2020 PingResponse\n" 
[20200716 19:15:52.841 BST] [default] [debug]: QVariant(int, 1) 
[20200716 19:16:22.841 BST] [default] [debug]: QVariant(int, 1) 
1594923402: Saving in-memory database to /data/mosquitto.db.
[20200716 19:16:47.842 BST] [ozw.mqtt.publisher] [debug]: "Thu Jul 16 19:16:47 2020 PingResponse\n" 
[20200716 19:16:52.841 BST] [default] [debug]: QVariant(int, 1) 
[20200716 19:17:22.841 BST] [default] [debug]: QVariant(int, 1)

Still at a loss. Has anyone got any ideas?

pfinnigan · July 22, 2020, 7:01pm

I have found my problem. It was my ZWave.me USB stick.I replace it after I tried to upgrade its firmware and managed to brick it. Luckily I had a AEON Labs ZW090 stick available. This worked first time. There are issues but this is beta s/w. I can now at least add devices and see them.

The moral is not to blame the software immediately.

MwC-Trexx · September 25, 2020, 2:11pm

I had a bad zwave.me stick from Amazon (3rd party seller) and the issue turned out to be wrong region (EU). Replaced with a new one from a trusted eBay seller (US Region) and has been working fine (at least for the limited time I have been testing it).