OpenZWave won't connect to MQTT

DeltaNu1142 · January 25, 2021, 5:30pm

I’ve just successfully got my Z-wave network up & running with the OpenZWave add-in with MQTT and ozwdaemon rolled in with the help in this thread… and now the network will not come back up. I’ve restarted HA server, restarted the add-on, but the integration simply will not connect. Here is the information from the logs following a restart of the add-on:

[20210125 12:19:47.131 EST] [ozw.mqtt.commands] [debug]: Subscription Setup for  QMqttTopicFilter("OpenZWave/1/command/requestnodestate/") 
[20210125 12:19:47.131 EST] [ozw.mqtt.commands] [debug]: Creating Subscription for  "sendnodeinformation" 
[20210125 12:19:47.131 EST] [ozw.mqtt.commands] [debug]: Subscription Setup for  QMqttTopicFilter("OpenZWave/1/command/sendnodeinformation/") 
[20210125 12:19:47.131 EST] [ozw.mqtt.commands] [debug]: Creating Subscription for  "setpollinterval" 
[20210125 12:19:47.131 EST] [ozw.mqtt.commands] [debug]: Subscription Setup for  QMqttTopicFilter("OpenZWave/1/command/setpollinterval/") 
[20210125 12:19:47.135 EST] [ozw.mqtt.commands] [debug]: Creating Subscription for  "setvalue" 
[20210125 12:19:47.136 EST] [ozw.mqtt.commands] [debug]: Subscription Setup for  QMqttTopicFilter("OpenZWave/1/command/setvalue/") 
[20210125 12:19:47.136 EST] [ozw.mqtt.commands] [debug]: Creating Subscription for  "softresetcontroller" 
[20210125 12:19:47.136 EST] [ozw.mqtt.commands] [debug]: Subscription Setup for  QMqttTopicFilter("OpenZWave/1/command/softresetcontroller/") 
[20210125 12:19:47.136 EST] [ozw.mqtt.commands] [debug]: Creating Subscription for  "syncronisenodeneighbors" 
[20210125 12:19:47.136 EST] [ozw.mqtt.commands] [debug]: Subscription Setup for  QMqttTopicFilter("OpenZWave/1/command/syncronisenodeneighbors/") 
[20210125 12:19:47.136 EST] [ozw.mqtt.commands] [debug]: Creating Subscription for  "testnetwork" 
[20210125 12:19:47.136 EST] [ozw.mqtt.commands] [debug]: Subscription Setup for  QMqttTopicFilter("OpenZWave/1/command/testnetwork/") 
[20210125 12:19:47.136 EST] [ozw.mqtt.commands] [debug]: Creating Subscription for  "testnetworknode" 
[20210125 12:19:47.136 EST] [ozw.mqtt.commands] [debug]: Subscription Setup for  QMqttTopicFilter("OpenZWave/1/command/testnetworknode/") 
[20210125 12:19:47.139 EST] [ozw.mqtt.publisher] [debug]: Topics:  "OpenZWave/1/status/" 
[20210125 12:19:47.461 EST] [ozw.library] [info]: Info - Node: 0 Lookup for mfs.db.openzwave.com returned 151 
ozwadmin: Settings Path:  "/root/.config/OpenZWave/ozw-admin.conf"
ozwadmin: Using Saved Network Cache Size: 1000
QT_MESSAGE_PATTERN: %{backtrace} is not supported by this Qt build
[20210125 12:19:47.710 EST] [ozwadmin] [info]: OZWCore Initilized QTOpenZwave(0x7f82224c20) QTOZWManager(0x55a39b4ac0) 
[20210125 12:19:47.817 EST] [default] [warning]: QVncServer created on port 5900 
[20210125 12:19:49.870 EST] [ozw.library] [info]: Info - Node: 0 Queuing download for http://download.db.openzwave.com/images/shenzen_neo/nas-sc03ze.jpg (Node 0) 
[20210125 12:19:49.871 EST] [ozw.library] [info]: Info - Node: 0 Missing Picture /data/ozw/config/images/shenzen_neo/nas-sc03ze.jpg - Starting Download 
[20210125 12:19:49.872 EST] [ozw.library] [debug]: Debug - Node: 0 Download Starting for http://download.db.openzwave.com/images/shenzen_neo/nas-sc03ze.jpg (/data/ozw/config/images/shenzen_neo/nas-sc03ze.jpg) 
[20210125 12:19:50.394 EST] [ozw.library] [info]: Info - Node: 0 Queuing download for http://download.db.openzwave.com/images/namron/4512714.jpg (Node 0) 
[20210125 12:19:50.395 EST] [ozw.library] [info]: Info - Node: 0 Missing Picture /data/ozw/config/images/namron/4512714.jpg - Starting Download 
[20210125 12:19:50.395 EST] [ozw.library] [debug]: Debug - Node: 0 Download Starting for http://download.db.openzwave.com/images/namron/4512714.jpg (/data/ozw/config/images/namron/4512714.jpg) 
[20210125 12:19:50.453 EST] [ozw.library] [debug]: Debug - Node: 0 Downloads Remaining: 2 
[20210125 12:19:50.454 EST] [ozw.library] [warning]: Warning - Node: 0 Download of http://download.db.openzwave.com/images/shenzen_neo/nas-sc03ze.jpg Failed (Node: 0) 
[20210125 12:19:50.454 EST] [ozw.library] [debug]: Debug - Node: 0 Downloads Remaining: 1 
[20210125 12:19:50.454 EST] [ozw.library] [debug]: Detail - Node: 0 Notification: A Config File Failed to download 
[20210125 12:19:50.455 EST] [ozw.notifications] [debug]: Notification pvt_ozwUserAlert NotificationTypes::Notification_User_ConfigFileDownloadFailed Thread:  0x7fae2dfe38 
[20210125 12:19:50.455 EST] [ozw.mqtt.publisher] [debug]: Publishing Event ozwUserAlert 
[20210125 12:19:50.468 EST] [ozw.library] [warning]: Warning - Node: 0 Download of http://download.db.openzwave.com/images/namron/4512714.jpg Failed (Node: 0) 
[20210125 12:19:50.468 EST] [ozw.library] [debug]: Debug - Node: 0 Downloads Remaining: 0 
[20210125 12:19:50.468 EST] [ozw.library] [info]: Info - Node: 0 ManufacturerSpecificDB Initialized 
[20210125 12:19:50.469 EST] [ozw.library] [debug]: Detail - Node: 0 Notification: A Config File Failed to download 
[20210125 12:19:50.469 EST] [ozw.library] [debug]: Detail - Node: 0 Notification: ManufacturerSpecificDB Ready 
[20210125 12:19:50.469 EST] [ozw.notifications] [debug]: Notification pvt_ozwUserAlert NotificationTypes::Notification_User_ConfigFileDownloadFailed Thread:  0x7fae2dfe38 
[20210125 12:19:50.469 EST] [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 
[20210125 12:19:50.470 EST] [ozw.library] [info]: Info - Node: 255 Encrypted Flag is 0 
[20210125 12:19:50.470 EST] [ozw.mqtt.publisher] [debug]: Publishing Event ozwUserAlert 
[20210125 12:19:50.470 EST] [ozw.notifications] [debug]: Notification pvt_manufacturerSpecificDBReady Thread:  0x7fae2dfe38 
[20210125 12:19:50.470 EST] [ozw.mqtt.publisher] [debug]: Publishing Event manufacturerSpecificDBReady 
1611595190: New connection from 172.30.32.1 on port 1883.
1611595190: New client connected from 172.30.32.1 as 3tp5gYZqX6e97OAle9uWhE (p2, c1, k60, u'homeassistant').
WebSocket server settings:
  - Listen on :8099
  - Web server. Web root: /usr/share/novnc
  - No SSL/TLS support (no cert file)
  - proxying from :8099 to 127.0.0.1:5900
[20210125 12:20:00.468 EST] [ozw.library] [info]: Info - Node: 0 HttpThread Exiting. No Transfers in timeout period 
[20210125 12:20:00.471 EST] [ozw.library] [critical]: Error - Node: 255 ERROR: Dropping command, expected response not received after 1 attempt(s). Command: "FUNC_ID_ZW_GET_VERSION: 0x01, 0x03, 0x00, 0x15, 0xe9" 
[20210125 12:20:00.471 EST] [ozw.library] [debug]: Detail - Node: 255 Removing current message 
[20210125 12:20:00.471 EST] [ozw.library] [debug]: Detail - Node: 255 Notification: Notification - TimeOut 
[20210125 12:20:00.472 EST] [ozw.notifications] [debug]: Notification pvt_ozwNotification NotificationTypes::Notification_Code_MsgTimeout Thread:  0x7fae2dfe38 
[20210125 12:20:00.473 EST] [ozw.mqtt.publisher] [debug]: Publishing Event ozwNotification 
[20210125 12:20:47.404 EST] [ozw.mqtt.publisher] [debug]: "Mon Jan 25 12:20:47 2021 PingResponse\n" 
[20210125 12:21:47.287 EST] [ozw.mqtt.publisher] [debug]: "Mon Jan 25 12:21:47 2021 PingResponse\n" 
[20210125 12:22:47.252 EST] [ozw.mqtt.publisher] [debug]: "Mon Jan 25 12:22:47 2021 PingResponse\n" 
[20210125 12:23:47.294 EST] [ozw.mqtt.publisher] [debug]: "Mon Jan 25 12:23:47 2021 PingResponse\n" 
[20210125 12:24:47.295 EST] [ozw.mqtt.publisher] [debug]: "Mon Jan 25 12:24:47 2021 PingResponse\n" 
[20210125 12:25:47.242 EST] [ozw.mqtt.publisher] [debug]: "Mon Jan 25 12:25:47 2021 PingResponse\n" 
[20210125 12:26:47.295 EST] [ozw.mqtt.publisher] [debug]: "Mon Jan 25 12:26:47 2021 PingResponse\n" 
[20210125 12:27:47.253 EST] [ozw.mqtt.publisher] [debug]: "Mon Jan 25 12:27:47 2021 PingResponse\n" 
In exit
[20210125 12:28:36.454 EST] [ozw.daemon] [info]: Recieved SIGTERM: Shutting down ozwdaemon 
1611595716: mosquitto version 1.6.8 terminating
1611595716: Saving in-memory database to /data/mosquitto.db.
[20210125 12:28:36.646 EST] [ozw.library] [debug]: Detail - Node: 0 Notification: DriverRemoved 
[20210125 12:28:36.713 EST] [ozw.notifications] [debug]: Notification pvt_driverRemoved  0 Thread:  0x7fae2dfe38 
[20210125 12:28:36.798 EST] [ozw.mqtt.publisher] [debug]: Publishing Event stopped 
[20210125 12:28:36.817 EST] [ozw.mqtt.publisher] [debug]: Publishing Event driverRemoved: 0 
[20210125 12:28:36.857 EST] [ozw.mqtt.publisher] [debug]: MQTT State Change "Disconnected" 
[20210125 12:28:36.857 EST] [ozw.mqtt.publisher] [warning]: Exiting on Failure 
[20210125 12:28:36.857 EST] [ozw.mqtt.publisher] [warning]: MQTT Client Disconnnected 
[20210125 12:28:36.857 EST] [ozw.mqtt.publisher] [warning]: MQTT Client Error "Transport Invalid" 
[20210125 12:28:36.858 EST] [ozw.library] [debug]: Always - Node: 0 *************************************************************************** 
[20210125 12:28:36.858 EST] [ozw.library] [debug]: Always - Node: 0 *********************  Cumulative Network Statistics  ********************* 
[20210125 12:28:36.858 EST] [ozw.library] [debug]: Always - Node: 0 *** General 
[20210125 12:28:36.858 EST] [ozw.library] [debug]: Always - Node: 0 Driver run time: . .  . 0 days, 0 hours, 8 minutes 
[20210125 12:28:36.858 EST] [ozw.library] [debug]: Always - Node: 0 Frames processed: . . . . . . . . . . . . . . . . . . . . 0 
[20210125 12:28:36.858 EST] [ozw.library] [debug]: Always - Node: 0 Total messages successfully received: . . . . . . . . . . 0 
[20210125 12:28:36.858 EST] [ozw.library] [debug]: Always - Node: 0 Total Messages successfully sent: . . . . . . . . . . . . 1 
[20210125 12:28:36.858 EST] [ozw.library] [debug]: Always - Node: 0 ACKs received from controller:  . . . . . . . . . . . . . 1 
[20210125 12:28:36.858 EST] [ozw.library] [debug]: Always - Node: 0 *** Errors 
[20210125 12:28:36.858 EST] [ozw.library] [debug]: Always - Node: 0 Unsolicited messages received while waiting for ACK:  . . 0 
[20210125 12:28:36.859 EST] [ozw.library] [debug]: Always - Node: 0 Reads aborted due to timeouts:  . . . . . . . . . . . . . 0 
[20210125 12:28:36.859 EST] [ozw.library] [debug]: Always - Node: 0 Bad checksum errors:  . . . . . . . . . . . . . . . . . . 0 
[20210125 12:28:36.859 EST] [ozw.library] [debug]: Always - Node: 0 CANs received from controller:  . . . . . . . . . . . . . 0 
[20210125 12:28:36.859 EST] [ozw.library] [debug]: Always - Node: 0 NAKs received from controller:  . . . . . . . . . . . . . 0 
[20210125 12:28:36.859 EST] [ozw.library] [debug]: Always - Node: 0 Out of frame data flow errors:  . . . . . . . . . . . . . 0 
[20210125 12:28:36.859 EST] [ozw.library] [debug]: Always - Node: 0 Messages retransmitted: . . . . . . . . . . . . . . . . . 0 
[20210125 12:28:36.859 EST] [ozw.library] [debug]: Always - Node: 0 Messages dropped and not delivered: . . . . . . . . . . . 1 
[20210125 12:28:36.859 EST] [ozw.library] [debug]: Always - Node: 0 *************************************************************************** 
[20210125 12:28:36.864 EST] [ozw.library] [warning]: Warning - Node: 0 WARNING: Tried to write driver config with no home ID set 
[20210125 12:28:36.896 EST] [ozw.library] [info]: Info - Node: 0 Stopping DNSThread 
[cont-finish.d] executing container finish scripts...
[cont-finish.d] mqtt.sh: executing... 
[12:28:56] INFO: Connected to internal MQTT service
[cont-init.d] mqtt.sh: exited 0.
[cont-init.d] network_key.sh: executing... 
[cont-init.d] network_key.sh: exited 0.
[cont-init.d] novnc.sh: executing... 
[cont-init.d] novnc.sh: exited 0.
[cont-init.d] structure.sh: executing... 
[cont-init.d] structure.sh: exited 0.
[cont-init.d] done.
[services.d] starting services
[services.d] done.
[12:28:58] INFO: Starting internal MQTT broker...
1611595738: mosquitto version 1.6.8 starting
1611595738: Config loaded from /etc/mosquitto.conf.
1611595738: Opening ipv4 listen socket on port 1883.
1611595738: Opening ipv6 listen socket on port 1883.
1611595738: Warning: Mosquitto should not be run as root/administrator.
1611595738: Connecting bridge main-mqtt (core-mosquitto:1883)
[20210125 12:29:07.839 EST] [ozw.mqtt.commands] [debug]: Subscription Setup for  QMqttTopicFilter("OpenZWave/1/command/close/") 
[20210125 12:29:07.839 EST] [ozw.mqtt.commands] [debug]: Creating Subscription for  "deleteallreturnroute" 
[20210125 12:29:07.839 EST] [ozw.mqtt.commands] [debug]: Subscription Setup for  QMqttTopicFilter("OpenZWave/1/command/deleteallreturnroute/") 
[20210125 12:29:07.839 EST] [ozw.mqtt.commands] [debug]: Creating Subscription for  "disablepoll" 
[20210125 12:29:07.840 EST] [ozw.mqtt.commands] [debug]: Subscription Setup for  QMqttTopicFilter("OpenZWave/1/command/disablepoll/") 
[20210125 12:29:07.840 EST] [ozw.mqtt.commands] [debug]: Creating Subscription for  "downloadlatestconfigfilerevision" 
[20210125 12:29:07.840 EST] [ozw.mqtt.commands] [debug]: Subscription Setup for  QMqttTopicFilter("OpenZWave/1/command/downloadlatestconfigfilerevision/") 
[20210125 12:29:07.840 EST] [ozw.mqtt.commands] [debug]: Creating Subscription for  "downloadlatestmfsrevision" 
[20210125 12:29:07.840 EST] [ozw.mqtt.commands] [debug]: Subscription Setup for  QMqttTopicFilter("OpenZWave/1/command/downloadlatestmfsrevision/") 
[20210125 12:29:07.840 EST] [ozw.mqtt.commands] [debug]: Creating Subscription for  "enablepoll" 
[20210125 12:29:07.840 EST] [ozw.mqtt.commands] [debug]: Subscription Setup for  QMqttTopicFilter("OpenZWave/1/command/enablepoll/") 
[20210125 12:29:07.840 EST] [ozw.mqtt.commands] [debug]: Creating Subscription for  "getpollinterval" 
[20210125 12:29:07.840 EST] [ozw.mqtt.commands] [debug]: Subscription Setup for  QMqttTopicFilter("OpenZWave/1/command/getpollinterval/") 
[20210125 12:29:07.840 EST] [ozw.mqtt.commands] [debug]: Creating Subscription for  "hardresetcontroller" 
[20210125 12:29:07.840 EST] [ozw.mqtt.commands] [debug]: Subscription Setup for  QMqttTopicFilter("OpenZWave/1/command/hardresetcontroller/") 
[20210125 12:29:07.841 EST] [ozw.mqtt.commands] [debug]: Creating Subscription for  "hasnodefailed" 
[20210125 12:29:07.841 EST] [ozw.mqtt.commands] [debug]: Subscription Setup for  QMqttTopicFilter("OpenZWave/1/command/hasnodefailed/") 
[20210125 12:29:07.841 EST] [ozw.mqtt.commands] [debug]: Creating Subscription for  "healnetwork" 
[20210125 12:29:07.841 EST] [ozw.mqtt.commands] [debug]: Subscription Setup for  QMqttTopicFilter("OpenZWave/1/command/healnetwork/") 
[20210125 12:29:07.841 EST] [ozw.mqtt.commands] [debug]: Creating Subscription for  "healnetworknode" 
[20210125 12:29:07.841 EST] [ozw.mqtt.commands] [debug]: Subscription Setup for  QMqttTopicFilter("OpenZWave/1/command/healnetworknode/") 
[20210125 12:29:07.841 EST] [ozw.mqtt.commands] [debug]: Creating Subscription for  "isnodefailed" 
[20210125 12:29:07.841 EST] [ozw.mqtt.commands] [debug]: Subscription Setup for  QMqttTopicFilter("OpenZWave/1/command/isnodefailed/") 
[20210125 12:29:07.841 EST] [ozw.mqtt.commands] [debug]: Creating Subscription for  "open" 
[20210125 12:29:07.841 EST] [ozw.mqtt.commands] [debug]: Subscription Setup for  QMqttTopicFilter("OpenZWave/1/command/open/") 
[20210125 12:29:07.841 EST] [ozw.mqtt.commands] [debug]: Creating Subscription for  "ping" 
[20210125 12:29:07.842 EST] [ozw.mqtt.commands] [debug]: Subscription Setup for  QMqttTopicFilter("OpenZWave/1/command/ping/") 
[20210125 12:29:07.842 EST] [ozw.mqtt.commands] [debug]: Creating Subscription for  "refreshnodeinfo" 
[20210125 12:29:07.842 EST] [ozw.mqtt.commands] [debug]: Subscription Setup for  QMqttTopicFilter("OpenZWave/1/command/refreshnodeinfo/") 
[20210125 12:29:07.842 EST] [ozw.mqtt.commands] [debug]: Creating Subscription for  "refreshvalue" 
[20210125 12:29:07.842 EST] [ozw.mqtt.commands] [debug]: Subscription Setup for  QMqttTopicFilter("OpenZWave/1/command/refreshvalue/") 
[20210125 12:29:07.842 EST] [ozw.mqtt.commands] [debug]: Creating Subscription for  "removeassociation" 
[20210125 12:29:07.842 EST] [ozw.mqtt.commands] [debug]: Subscription Setup for  QMqttTopicFilter("OpenZWave/1/command/removeassociation/") 
[20210125 12:29:07.842 EST] [ozw.mqtt.commands] [debug]: Creating Subscription for  "removefailednode" 
[20210125 12:29:07.842 EST] [ozw.mqtt.commands] [debug]: Subscription Setup for  QMqttTopicFilter("OpenZWave/1/command/removefailednode/") 
[20210125 12:29:07.842 EST] [ozw.mqtt.commands] [debug]: Creating Subscription for  "removenode" 
[20210125 12:29:07.842 EST] [ozw.mqtt.commands] [debug]: Subscription Setup for  QMqttTopicFilter("OpenZWave/1/command/removenode/") 
[20210125 12:29:07.843 EST] [ozw.mqtt.commands] [debug]: Creating Subscription for  "replacefailednode" 
[20210125 12:29:07.843 EST] [ozw.mqtt.commands] [debug]: Subscription Setup for  QMqttTopicFilter("OpenZWave/1/command/replacefailednode/") 
[20210125 12:29:07.843 EST] [ozw.mqtt.commands] [debug]: Creating Subscription for  "requestallconfigparam" 
[20210125 12:29:07.843 EST] [ozw.mqtt.commands] [debug]: Subscription Setup for  QMqttTopicFilter("OpenZWave/1/command/requestallconfigparam/") 
[20210125 12:29:07.843 EST] [ozw.mqtt.commands] [debug]: Creating Subscription for  "requestconfigparam" 
[20210125 12:29:07.843 EST] [ozw.mqtt.commands] [debug]: Subscription Setup for  QMqttTopicFilter("OpenZWave/1/command/requestconfigparam/") 
[20210125 12:29:07.843 EST] [ozw.mqtt.commands] [debug]: Creating Subscription for  "requestnetworkupdate" 
[20210125 12:29:07.843 EST] [ozw.mqtt.commands] [debug]: Subscription Setup for  QMqttTopicFilter("OpenZWave/1/command/requestnetworkupdate/") 
[20210125 12:29:07.843 EST] [ozw.mqtt.commands] [debug]: Creating Subscription for  "requestnodedynamic" 
[20210125 12:29:07.843 EST] [ozw.mqtt.commands] [debug]: Subscription Setup for  QMqttTopicFilter("OpenZWave/1/command/requestnodedynamic/") 
[20210125 12:29:07.843 EST] [ozw.mqtt.commands] [debug]: Creating Subscription for  "requestnodeneighborupdate" 
[20210125 12:29:07.843 EST] [ozw.mqtt.commands] [debug]: Subscription Setup for  QMqttTopicFilter("OpenZWave/1/command/requestnodeneighborupdate/") 
[20210125 12:29:07.843 EST] [ozw.mqtt.commands] [debug]: Creating Subscription for  "requestnodestate" 
[20210125 12:29:07.844 EST] [ozw.mqtt.commands] [debug]: Subscription Setup for  QMqttTopicFilter("OpenZWave/1/command/requestnodestate/") 
[20210125 12:29:07.844 EST] [ozw.mqtt.commands] [debug]: Creating Subscription for  "sendnodeinformation" 
[20210125 12:29:07.844 EST] [ozw.mqtt.commands] [debug]: Subscription Setup for  QMqttTopicFilter("OpenZWave/1/command/sendnodeinformation/") 
[20210125 12:29:07.844 EST] [ozw.mqtt.commands] [debug]: Creating Subscription for  "setpollinterval" 
[20210125 12:29:07.844 EST] [ozw.mqtt.commands] [debug]: Subscription Setup for  QMqttTopicFilter("OpenZWave/1/command/setpollinterval/") 
[20210125 12:29:07.844 EST] [ozw.mqtt.commands] [debug]: Creating Subscription for  "setvalue" 
[20210125 12:29:07.844 EST] [ozw.mqtt.commands] [debug]: Subscription Setup for  QMqttTopicFilter("OpenZWave/1/command/setvalue/") 
[20210125 12:29:07.844 EST] [ozw.mqtt.commands] [debug]: Creating Subscription for  "softresetcontroller" 
[20210125 12:29:07.844 EST] [ozw.mqtt.commands] [debug]: Subscription Setup for  QMqttTopicFilter("OpenZWave/1/command/softresetcontroller/") 
[20210125 12:29:07.844 EST] [ozw.mqtt.commands] [debug]: Creating Subscription for  "syncronisenodeneighbors" 
[20210125 12:29:07.845 EST] [ozw.mqtt.commands] [debug]: Subscription Setup for  QMqttTopicFilter("OpenZWave/1/command/syncronisenodeneighbors/") 
[20210125 12:29:07.845 EST] [ozw.mqtt.commands] [debug]: Creating Subscription for  "testnetwork" 
[20210125 12:29:07.845 EST] [ozw.mqtt.commands] [debug]: Subscription Setup for  QMqttTopicFilter("OpenZWave/1/command/testnetwork/") 
[20210125 12:29:07.845 EST] [ozw.mqtt.commands] [debug]: Creating Subscription for  "testnetworknode" 
[20210125 12:29:07.845 EST] [ozw.mqtt.commands] [debug]: Subscription Setup for  QMqttTopicFilter("OpenZWave/1/command/testnetworknode/") 
[20210125 12:29:07.846 EST] [ozw.mqtt.publisher] [debug]: Topics:  "OpenZWave/1/status/" 
[20210125 12:29:07.900 EST] [ozw.library] [info]: Info - Node: 0 Lookup for mfs.db.openzwave.com returned 151 
ozwadmin: Settings Path:  "/root/.config/OpenZWave/ozw-admin.conf"
ozwadmin: Using Saved Network Cache Size: 1000
QT_MESSAGE_PATTERN: %{backtrace} is not supported by this Qt build
[20210125 12:29:08.209 EST] [ozwadmin] [info]: OZWCore Initilized QTOpenZwave(0x7fad84ec20) QTOZWManager(0x55c3182b40) 
[20210125 12:29:08.319 EST] [default] [warning]: QVncServer created on port 5900 
[20210125 12:29:10.966 EST] [ozw.library] [info]: Info - Node: 0 Queuing download for http://download.db.openzwave.com/images/shenzen_neo/nas-sc03ze.jpg (Node 0) 
[20210125 12:29:10.968 EST] [ozw.library] [info]: Info - Node: 0 Missing Picture /data/ozw/config/images/shenzen_neo/nas-sc03ze.jpg - Starting Download 
[20210125 12:29:10.969 EST] [ozw.library] [debug]: Debug - Node: 0 Download Starting for http://download.db.openzwave.com/images/shenzen_neo/nas-sc03ze.jpg (/data/ozw/config/images/shenzen_neo/nas-sc03ze.jpg) 
WebSocket server settings:
  - Listen on :8099
  - Web server. Web root: /usr/share/novnc
  - No SSL/TLS support (no cert file)
  - proxying from :8099 to 127.0.0.1:5900
[20210125 12:29:11.504 EST] [ozw.library] [info]: Info - Node: 0 Queuing download for http://download.db.openzwave.com/images/namron/4512714.jpg (Node 0) 
[20210125 12:29:11.505 EST] [ozw.library] [info]: Info - Node: 0 Missing Picture /data/ozw/config/images/namron/4512714.jpg - Starting Download 
[20210125 12:29:11.505 EST] [ozw.library] [debug]: Debug - Node: 0 Download Starting for http://download.db.openzwave.com/images/namron/4512714.jpg (/data/ozw/config/images/namron/4512714.jpg) 
[20210125 12:29:11.658 EST] [ozw.library] [debug]: Debug - Node: 0 Downloads Remaining: 2 
[20210125 12:29:11.659 EST] [ozw.library] [warning]: Warning - Node: 0 Download of http://download.db.openzwave.com/images/shenzen_neo/nas-sc03ze.jpg Failed (Node: 0) 
[20210125 12:29:11.659 EST] [ozw.library] [debug]: Debug - Node: 0 Downloads Remaining: 1 
[20210125 12:29:11.685 EST] [ozw.library] [debug]: Detail - Node: 0 Notification: A Config File Failed to download 
[20210125 12:29:11.735 EST] [ozw.library] [warning]: Warning - Node: 0 Download of http://download.db.openzwave.com/images/namron/4512714.jpg Failed (Node: 0) 
[20210125 12:29:11.735 EST] [ozw.library] [debug]: Debug - Node: 0 Downloads Remaining: 0 
[20210125 12:29:11.736 EST] [ozw.library] [info]: Info - Node: 0 ManufacturerSpecificDB Initialized 
[20210125 12:29:11.736 EST] [ozw.library] [debug]: Detail - Node: 0 Notification: A Config File Failed to download 
[20210125 12:29:11.736 EST] [ozw.library] [debug]: Detail - Node: 0 Notification: ManufacturerSpecificDB Ready 
[20210125 12:29:11.737 EST] [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 
[20210125 12:29:11.737 EST] [ozw.library] [info]: Info - Node: 255 Encrypted Flag is 0 
[20210125 12:29:11.763 EST] [ozw.notifications] [debug]: Notification pvt_ozwUserAlert NotificationTypes::Notification_User_ConfigFileDownloadFailed Thread:  0x7fb8fa1e38 
[20210125 12:29:11.830 EST] [ozw.mqtt.publisher] [debug]: Publishing Event ozwUserAlert 
[20210125 12:29:11.831 EST] [ozw.notifications] [debug]: Notification pvt_ozwUserAlert NotificationTypes::Notification_User_ConfigFileDownloadFailed Thread:  0x7fb8fa1e38 
[20210125 12:29:11.832 EST] [ozw.mqtt.publisher] [debug]: Publishing Event ozwUserAlert 
[20210125 12:29:11.832 EST] [ozw.notifications] [debug]: Notification pvt_manufacturerSpecificDBReady Thread:  0x7fb8fa1e38 
[20210125 12:29:11.832 EST] [ozw.mqtt.publisher] [debug]: Publishing Event manufacturerSpecificDBReady 
[20210125 12:30:08.258 EST] [ozw.mqtt.publisher] [debug]: "Mon Jan 25 12:30:08 2021 PingResponse\n"

What’s gone wrong now? Thanks for looking.

petro · January 25, 2021, 5:40pm

This is a known bug from what I understand. Personally, I’ve never ran into it. I’m not using this method though. I set up a middle man MQTT server independent of the ozw beta. If my hypothesis is correct, a way to get around this bug for good is to add the middle man.

Turn off the openzwave container. Add the Mosquitto Broker addon. Then turn the openzwave add on back on. It should now start using the middle man and it won’t rely on starting up it’s own MQTT broker.

DeltaNu1142 · January 25, 2021, 5:54pm

Thanks petro, for your help in the other thread.

The thing is, I’d already had the Mosquitto broker add-on installed and running when I installed OpenZWave. So if this bug is getting me now, it’s only after a successful run of OpenZWave… which doesn’t make any sense.

I just uninstalled the OpenZwave add-on/integration, restarted HA, stopped the Mosquitto broker add-on, restarted it, then reinstalled OpenZWave. The Z-wave network seems to be reinitializing… yes. It’s back up.

Thanks. I don’t know why this has happened. Here’s hoping I don’t have to keep doing this to keep my Z-wave network running.

johnflorin · March 11, 2021, 3:14pm

I got this same problem after an update to this month’s HA OS & Supervisor. What DeltaNu1142 said above did not work for me, still getting that PingResponse\n stuff even after reinstalling all the components.

Am now restoring from yesterday’s snapshot, hopefully it will bring things back to working order, but honestly, given the unbelievable amount of problems I’ve had with ZWave in the past nearly 5 years with Vera & HA, it’s time to rip it all out and replace it with WiFi Shellys.

I can’t even go to the JS version, because window covers are not yet supported.

I honestly can’t understand how a standard like ZWave got to be so popular…maybe because it was relatively early to market and WiFi was not low-power enough at the time, but it is shockingly fragile to any change or restart in HA and just plain unreliable in Vera.

In Vera, due to nightly healing or whatever the hell that thing was doing behind the scenes, my front door sensor worked less than 100% of the time. I realize it’s not an official alarm system, but when battery, range & configuration are OK there is 0 excuse for not working every single time and Vera’s forums acknowledged it as a known issue, yay for them.